[SR-Users] Usrloc reload problem

Jan Klepal jan at klepal.cz
Fri Sep 17 15:27:08 CEST 2010


Hello,

I run kamailio 3.0.3 with location table stored in database (PostgreSQL 8.4.2) 
with db_mode 2 (write-back) and upon kamailio restart some contacts from 
database are loaded incorrectly. Messages for those contacts are routed to 
invalid IP addresses.

After some debugging I figured out that it happens only for contacts which  
"received" column value is null. For those contacts value is filled from 
previously loaded contact having non-null value in "received" column.

Here is sample debug, which shows contact (row #97 in result set) with IP 
10.3.71.1 is later used for contact without "received" value (row #172):

db_postgres [km_dbase.c:149]: 0x888e00 PQsendQuery(select 
username,contact,expires,q,callid,cseq,flags,cflags,user_agent,received,path,socket,methods,last_modified 
from location )
...
db_postgres [km_res.c:242]: PQgetvalue(0x888e00,79,9)=[sip:10.3.71.1:5060]
db_postgres [km_res.c:251]: [79][9] Column[received]=[sip:10.3.71.1:5060]
...
db_postgres [km_res.c:242]: PQgetvalue(0x888e00,172,9)=[]                                                                                                                                                                   
...
db_postgres [km_res.c:242]: PQgetvalue(0x888e00,172,0)=[222333444]                                                                                                                                                          
db_postgres [km_res.c:251]: [172][0] Column[username]=[222333444]                                                                                                                                                           
db_postgres [km_res.c:242]: 
PQgetvalue(0x888e00,172,1)=[sip:222333444 at 195.70.1.200]                                                                                                                                         
db_postgres [km_res.c:251]: [172][1] 
Column[contact]=[sip:222333444 at 195.70.1.200]                                                                                                                                           
db_postgres [km_res.c:242]: PQgetvalue(0x888e00,172,2)=[2010-09-16 00:21:04]                                                                                                                                                
db_postgres [km_res.c:251]: [172][2] Column[expires]=[2010-09-16 00:21:04]                                                                                                                                                  
db_postgres [km_res.c:242]: PQgetvalue(0x888e00,172,3)=[-1]                                                                                                                                                                 
db_postgres [km_res.c:251]: [172][3] Column[q]=[-1]                                                                                                                                                                         
db_postgres [km_res.c:242]: 
PQgetvalue(0x888e00,172,4)=[0fc6692b6570aaac04b3c85a3b9496c0 at sipxsip.cz]                                                                                                                        
db_postgres [km_res.c:251]: [172][4] 
Column[callid]=[0fc6692b6570aaac04b3c85a3b9496c0 at sipxsip.cz]                                                                                                                           
db_postgres [km_res.c:242]: PQgetvalue(0x888e00,172,5)=[397]                                                                                                                                                                
db_postgres [km_res.c:251]: [172][5] Column[cseq]=[397]                                                                                                                                                                     
db_postgres [km_res.c:242]: PQgetvalue(0x888e00,172,6)=[0]                                                                                                                                                                  
db_postgres [km_res.c:251]: [172][6] Column[flags]=[0]                                                                                                                                                                      
db_postgres [km_res.c:242]: PQgetvalue(0x888e00,172,7)=[0]                                                                                                                                                                  
db_postgres [km_res.c:251]: [172][7] Column[cflags]=[0]                                                                                                                                                                     
db_postgres [km_res.c:242]: PQgetvalue(0x888e00,172,8)=[Asterisk SIPXSIP]                                                                                                                                                   
db_postgres [km_res.c:251]: [172][8] Column[user_agent]=[Asterisk SIPXSIP]                                                                                                                                                  
db_postgres [km_res.c:242]: PQgetvalue(0x888e00,172,9)=[]                                                                                                                                                                   
db_postgres [km_res.c:242]: PQgetvalue(0x888e00,172,10)=[]                                                                                                                                                                  
db_postgres [km_res.c:242]: 
PQgetvalue(0x888e00,172,11)=[udp:80.200.1.100:5060]                                                                                                                                             
db_postgres [km_res.c:251]: [172][11] Column[socket]=[udp:80.200.1.100:5060]                                                                                                                                                
db_postgres [km_res.c:242]: PQgetvalue(0x888e00,172,12)=[]                                                                                                                                                                  
db_postgres [km_res.c:242]: PQgetvalue(0x888e00,172,13)=[2010-09-16 00:11:04]                                                                                                                                               
db_postgres [km_res.c:251]: [172][13] Column[last_modified]=[2010-09-16 
00:11:04]                                                                                                                                           
<core> [db_row.c:119]: allocate 448 bytes for row values at 0x998120                                                                                                                                                        
<core> [db_val.c:117]: converting STRING [222333444]                                                                                                                                                                        
<core> [db_val.c:127]: allocate 10 bytes memory for STRING at 0x944008                                                                                                                                                      
<core> [db_val.c:117]: converting STRING [sip:222333444 at 195.70.1.200]                                                                                                                                                       
<core> [db_val.c:127]: allocate 27 bytes memory for STRING at 0x9378d8                                                                                                                                                      
<core> [db_val.c:157]: converting DATETIME [2010-09-16 00:21:04]                                                                                                                                                            
<core> [db_val.c:106]: converting DOUBLE [-1]                                                                                                                                                                               
<core> [db_val.c:117]: converting STRING 
[0fc6692b6570aaac04b3c85a3b9496c0 at sipxsip.cz]                                                                                                                                      
<core> [db_val.c:127]: allocate 44 bytes memory for STRING at 0x925cd8                                                                                                                                                      
<core> [db_val.c:73]: converting INT [397]                                                                                                                                                                                  
<core> [db_val.c:73]: converting INT [0]                                                                                                                                                                                    
<core> [db_val.c:73]: converting INT [0]                                                                                                                                                                                    
<core> [db_val.c:117]: converting STRING [Asterisk SIPXSIP]                                                                                                                                                                 
<core> [db_val.c:127]: allocate 17 bytes memory for STRING at 0x9061e8                                                                                                                                                      
<core> [db_val.c:117]: converting STRING [sip:10.3.71.1:5060]                                                                                                                                                               
<core> [db_val.c:127]: allocate 19 bytes memory for STRING at 0x905fc8                                                                                                                                                      
<core> [db_val.c:56]: converting NULL value                                                                                                                                                                                 
<core> [db_val.c:117]: converting STRING [udp:80.200.1.100:5060]                                                                                                                                                            
<core> [db_val.c:127]: allocate 22 bytes memory for STRING at 0x905da8                                                                                                                                                      
<core> [db_val.c:73]: converting INT [4767]                                                                                                                                                                                 
<core> [db_val.c:157]: converting DATETIME [2010-09-16 00:11:04]              

To make things clear, all rows after row #97 had "received" value null, and 
row #172 was UA I ran tests on... in the other words contact with null 
"received" value is filled with previous non-null value as long next non-null 
row is fetched from DB and following null contacts are filled with its value 
and so on.

When the contact having invalid "registered" re-register it will overwrite 
value in memory and calls are routed to proper IP address. This query is sent 
to database then:

db_postgres [km_dbase.c:149]: 0x888e00 PQsendQuery(update location set 
expires='2010-09-16 00:30:58',q=-1.00     
,cseq=103,flags=0,cflags=0,user_agent='Asterisk 
SIPXSIP',received=NULL,path=NULL,socket='udp:80.200.1.100:5
060',methods=NULL,last_modified='2010-09-16 00:20:58' where 
username='222333444' AND contact='sip:222333444 at 195.70.1.200' AND 
callid='0fc6692b6570aaac04b3c85a3b9496c0 at sipxsip.cz')

I've also checked status of this record in usrloc by "kamctl ul show"... both 
before and after kamailio restart state was CS_SYNC.

Is this bug or should I somehow force kamailio to store "received" into 
database?

Kind Regards,
Jan Klepal



More information about the sr-users mailing list