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(a)sipxsip.cz]
db_postgres [km_res.c:251]: [172][4]
Column[callid]=[0fc6692b6570aaac04b3c85a3b9496c0(a)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(a)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(a)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