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@195.70.1.200] db_postgres [km_res.c:251]: [172][1] Column[contact]=[sip:222333444@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@sipxsip.cz] db_postgres [km_res.c:251]: [172][4] Column[callid]=[0fc6692b6570aaac04b3c85a3b9496c0@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@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@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@195.70.1.200' AND callid='0fc6692b6570aaac04b3c85a3b9496c0@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