Re: [SR-Users] db_cluster together with the registrar module = signal 11

On 2012-08-29 at 07:38, Daniel-Constantin Mierla wrote: Now with "db_check_update" enabled. I've deleted the row for username 2549619 in the voip_location table from the secondary server between then re-registration. I think the problem is that the check is done using only one of the "read table" connections, and not done for each of the "write table" connections. Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_cluster [dbcl_api.c:436]: use table (voip_location) - cluster [data2] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_cluster [dbcl_api.c:455]: set write table (voip_location) - cluster [data2] (9/0) Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_cluster [dbcl_api.c:455]: set write table (voip_location) - cluster [data2] (9/1) Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_cluster [dbcl_api.c:445]: set read table (voip_location) - cluster [data2] (8/0) Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_cluster [dbcl_api.c:445]: set read table (voip_location) - cluster [data2] (7/0) Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_cluster [dbcl_api.c:299]: executing db cluster query command Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_cluster [dbcl_api.c:300]: serial operation - cluster [data2] (8/0) Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_val.c:163]: PQescapeStringConn: in: 7 chars, out: 7 chars Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_val.c:163]: PQescapeStringConn: in: 20 chars, out: 20 chars Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_dbase.c:224]: sending query ok: 0xb7c9dfd0 (7) - [select contact,expires,q,callid,cseq,flags,cflags,user_agent,received,path,socket,methods,last_modified,ruid,instance,reg_id from voip_location where username='2549619' AND domain='hometest.voip.uio.no' or der by q] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_res.c:118]: allocate 28 bytes for result set at 0xb7cd2d90 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_dbase.c:494]: 0xb7c9dfd0 PQresultStatus(PGRES_TUPLES_OK) PQgetResult(0x9058e78) Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:108]: 16 columns returned from the query Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_res.c:155]: allocate 64 bytes for result names at 0xb7cd2db8 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_res.c:165]: allocate 64 bytes for result types at 0xb7cd2e00 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:126]: allocate 8 bytes for RES_NAMES[0] at 0xb7ca14d0 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:133]: RES_NAMES(0xb7ca14d0)[0]=[contact] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:166]: use DB1_STRING result type Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:126]: allocate 8 bytes for RES_NAMES[1] at 0xb7ca16e8 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:133]: RES_NAMES(0xb7ca16e8)[1]=[expires] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:158]: use DB1_DATETIME result type Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:126]: allocate 8 bytes for RES_NAMES[2] at 0xb7ca15d0 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:133]: RES_NAMES(0xb7ca15d0)[2]=[q] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:151]: use DB1_DOUBLE result type Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:126]: allocate 8 bytes for RES_NAMES[3] at 0xb7ca1530 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:133]: RES_NAMES(0xb7ca1530)[3]=[callid] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:166]: use DB1_STRING result type Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:126]: allocate 8 bytes for RES_NAMES[4] at 0xb7ca14a0 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:133]: RES_NAMES(0xb7ca14a0)[4]=[cseq] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:140]: use DB1_INT result type Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:126]: allocate 8 bytes for RES_NAMES[5] at 0xb7ca14e0 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:133]: RES_NAMES(0xb7ca14e0)[5]=[flags] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:140]: use DB1_INT result type Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:126]: allocate 8 bytes for RES_NAMES[6] at 0xb7ca16a8 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:133]: RES_NAMES(0xb7ca16a8)[6]=[cflags] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:140]: use DB1_INT result type Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:126]: allocate 8 bytes for RES_NAMES[7] at 0xb7ca14b0 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:133]: RES_NAMES(0xb7ca14b0)[7]=[user_agent] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:166]: use DB1_STRING result type Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:126]: allocate 8 bytes for RES_NAMES[8] at 0xb7ca14c0 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:133]: RES_NAMES(0xb7ca14c0)[8]=[received] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:166]: use DB1_STRING result type Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:126]: allocate 8 bytes for RES_NAMES[9] at 0xb7ca14f0 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:133]: RES_NAMES(0xb7ca14f0)[9]=[path] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:166]: use DB1_STRING result type Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:126]: allocate 8 bytes for RES_NAMES[10] at 0xb7cd3098 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:133]: RES_NAMES(0xb7cd3098)[10]=[socket] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:166]: use DB1_STRING result type Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:126]: allocate 8 bytes for RES_NAMES[11] at 0xb7cd30a8 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:133]: RES_NAMES(0xb7cd30a8)[11]=[methods] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:140]: use DB1_INT result type Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:126]: allocate 8 bytes for RES_NAMES[12] at 0xb7cd30b8 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:133]: RES_NAMES(0xb7cd30b8)[12]=[last_modified] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:158]: use DB1_DATETIME result type Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:126]: allocate 8 bytes for RES_NAMES[13] at 0xb7cd30c8 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:133]: RES_NAMES(0xb7cd30c8)[13]=[ruid] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:166]: use DB1_STRING result type Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:126]: allocate 8 bytes for RES_NAMES[14] at 0xb7cd30d8 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:133]: RES_NAMES(0xb7cd30d8)[14]=[instance] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:166]: use DB1_STRING result type Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:126]: allocate 8 bytes for RES_NAMES[15] at 0xb7cd30e8 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:133]: RES_NAMES(0xb7cd30e8)[15]=[reg_id] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:140]: use DB1_INT result type Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:222]: allocate for 16 columns 64 bytes in row buffer at 0xb7cd30f8 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_res.c:184]: allocate 8 bytes for rows at 0xb7cd3140 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:243]: PQgetvalue(0xb7c9dfd0,0,0)=[sip:2549619@193.157.149.56] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:252]: [0][0] Column[contact]=[sip:2549619@193.157.149.56] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:243]: PQgetvalue(0xb7c9dfd0,0,1)=[2012-08-29 13:20:11] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:252]: [0][1] Column[expires]=[2012-08-29 13:20:11] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:243]: PQgetvalue(0xb7c9dfd0,0,2)=[-1] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:252]: [0][2] Column[q]=[-1] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:243]: PQgetvalue(0xb7c9dfd0,0,3)=[94f2f534-e3cc629f-5bd8343e(a)193.157.149.56] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:252]: [0][3] Column[callid]=[94f2f534-e3cc629f-5bd8343e(a)193.157.149.56] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:243]: PQgetvalue(0xb7c9dfd0,0,4)=[14] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:252]: [0][4] Column[cseq]=[14] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:243]: PQgetvalue(0xb7c9dfd0,0,5)=[0] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:252]: [0][5] Column[flags]=[0] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:243]: PQgetvalue(0xb7c9dfd0,0,6)=[0] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:252]: [0][6] Column[cflags]=[0] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:243]: PQgetvalue(0xb7c9dfd0,0,7)=[PolycomSoundPointIP-SPIP_331-UA/3.2.1.0054] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:252]: [0][7] Column[user_agent]=[PolycomSoundPointIP-SPIP_331-UA/3.2.1.0054] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:243]: PQgetvalue(0xb7c9dfd0,0,8)=[] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:243]: PQgetvalue(0xb7c9dfd0,0,9)=[] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:243]: PQgetvalue(0xb7c9dfd0,0,10)=[udp:129.240.253.197:5060] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:252]: [0][10] Column[socket]=[udp:129.240.253.197:5060] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:243]: PQgetvalue(0xb7c9dfd0,0,11)=[8159] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:252]: [0][11] Column[methods]=[8159] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:243]: PQgetvalue(0xb7c9dfd0,0,12)=[2012-08-29 13:18:11] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:252]: [0][12] Column[last_modified]=[2012-08-29 13:18:11] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:243]: PQgetvalue(0xb7c9dfd0,0,13)=[uloc-503dfa6f-7959-1] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:252]: [0][13] Column[ruid]=[uloc-503dfa6f-7959-1] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:243]: PQgetvalue(0xb7c9dfd0,0,14)=[] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:243]: PQgetvalue(0xb7c9dfd0,0,15)=[0] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:252]: [0][15] Column[reg_id]=[0] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_row.c:119]: allocate 320 bytes for row values at 0xb7cd3150 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_val.c:117]: converting STRING [sip:2549619@193.157.149.56] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_val.c:127]: allocate 27 bytes memory for STRING at 0xb7cd32b0 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_val.c:157]: converting DATETIME [2012-08-29 13:20:11] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_val.c:106]: converting DOUBLE [-1] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_val.c:117]: converting STRING [94f2f534-e3cc629f-5bd8343e(a)193.157.149.56] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_val.c:127]: allocate 42 bytes memory for STRING at 0xb7cd32d8 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_val.c:73]: converting INT [14] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_val.c:73]: converting INT [0] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_val.c:73]: converting INT [0] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_val.c:117]: converting STRING [PolycomSoundPointIP-SPIP_331-UA/3.2.1.0054] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_val.c:127]: allocate 43 bytes memory for STRING at 0xb7cd3310 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_val.c:56]: converting NULL value Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_val.c:56]: converting NULL value Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_val.c:117]: converting STRING [udp:129.240.253.197:5060] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_val.c:127]: allocate 25 bytes memory for STRING at 0xb7cd3348 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_val.c:73]: converting INT [8159] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_val.c:157]: converting DATETIME [2012-08-29 13:18:11] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_val.c:117]: converting STRING [uloc-503dfa6f-7959-1] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_val.c:127]: allocate 21 bytes memory for STRING at 0xb7cd3370 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_val.c:56]: converting NULL value Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_val.c:73]: converting INT [0] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_res.c:267]: freeing row buffer at 0xb7cd30f8 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_dbase.c:393]: PQclear(0x9058e78) result set Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [socket_info.c:583]: grep_sock_info - checking if host==us: 15==9 && [129.240.253.197] == [127.0.0.1] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [socket_info.c:587]: grep_sock_info - checking if port 5060 (advertise 0) matches port 5060 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [socket_info.c:583]: grep_sock_info - checking if host==us: 15==15 && [129.240.253.197] == [129.240.253.197] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [socket_info.c:587]: grep_sock_info - checking if port 5060 (advertise 0) matches port 5060 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_cluster [dbcl_api.c:284]: executing db cluster free-result command Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_res.c:81]: freeing 16 columns Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_res.c:85]: freeing RES_NAMES[0] at 0xb7ca14d0 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_res.c:85]: freeing RES_NAMES[1] at 0xb7ca16e8 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_res.c:85]: freeing RES_NAMES[2] at 0xb7ca15d0 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_res.c:85]: freeing RES_NAMES[3] at 0xb7ca1530 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_res.c:85]: freeing RES_NAMES[4] at 0xb7ca14a0 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_res.c:85]: freeing RES_NAMES[5] at 0xb7ca14e0 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_res.c:85]: freeing RES_NAMES[6] at 0xb7ca16a8 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_res.c:85]: freeing RES_NAMES[7] at 0xb7ca14b0 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_res.c:85]: freeing RES_NAMES[8] at 0xb7ca14c0 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_res.c:85]: freeing RES_NAMES[9] at 0xb7ca14f0 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_res.c:85]: freeing RES_NAMES[10] at 0xb7cd3098 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_res.c:85]: freeing RES_NAMES[11] at 0xb7cd30a8 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_res.c:85]: freeing RES_NAMES[12] at 0xb7cd30b8 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_res.c:85]: freeing RES_NAMES[13] at 0xb7cd30c8 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_res.c:85]: freeing RES_NAMES[14] at 0xb7cd30d8 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_res.c:85]: freeing RES_NAMES[15] at 0xb7cd30e8 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_res.c:94]: freeing result names at 0xb7cd2db8 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_res.c:99]: freeing result types at 0xb7cd2e00 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_res.c:54]: freeing 1 rows Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_row.c:68]: free VAL_STRING[0] 'sip:2549619@193.157.149.56' at 0xb7cd32b0 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_row.c:68]: free VAL_STRING[3] &#39;94f2f534-e3cc629f-5bd8343e(a)193.157.149.56&#39; at 0xb7cd32d8 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_row.c:68]: free VAL_STRING[7] 'PolycomSoundPointIP-SPIP_331-UA/3.2.1.0054' at 0xb7cd3310 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_row.c:68]: free VAL_STRING[10] 'udp:129.240.253.197:5060' at 0xb7cd3348 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_row.c:68]: free VAL_STRING[13] 'uloc-503dfa6f-7959-1' at 0xb7cd3370 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_row.c:97]: freeing row values at 0xb7cd3150 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_res.c:62]: freeing rows at 0xb7cd3140 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_res.c:136]: freeing result set at 0xb7cd2d90 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: registrar [save.c:564]: 1 valid contacts Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: registrar [save.c:586]: 1 contacts after commit Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [sruid.c:176]: new sruid is [uloc-503dfa6f-795c-1] (1 / 20) Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_cluster [dbcl_api.c:436]: use table (voip_location) - cluster [data2] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_cluster [dbcl_api.c:455]: set write table (voip_location) - cluster [data2] (9/0) Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_cluster [dbcl_api.c:455]: set write table (voip_location) - cluster [data2] (9/1) Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_cluster [dbcl_api.c:445]: set read table (voip_location) - cluster [data2] (8/0) Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_cluster [dbcl_api.c:445]: set read table (voip_location) - cluster [data2] (7/0) Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_cluster [dbcl_api.c:356]: executing db cluster update command Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_cluster [dbcl_api.c:357]: parallel operation - cluster [data2] (9/0) Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_val.c:163]: PQescapeStringConn: in: 42 chars, out: 42 chars Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_val.c:163]: PQescapeStringConn: in: 24 chars, out: 24 chars Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_val.c:163]: PQescapeStringConn: in: 20 chars, out: 20 chars Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_val.c:163]: PQescapeStringConn: in: 7 chars, out: 7 chars Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_val.c:163]: PQescapeStringConn: in: 26 chars, out: 26 chars Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_val.c:163]: PQescapeStringConn: in: 41 chars, out: 41 chars Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_val.c:163]: PQescapeStringConn: in: 20 chars, out: 20 chars Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_dbase.c:224]: sending query ok: 0xb7c9df08 (7) - [update voip_location set expires='2012-08-29 13:21:11',q=-1.00 ,cseq=15,flags=0,cflags=0,user_agent='PolycomSoundPointIP-SPIP_331-UA/3.2.1.0054',received=NULL,path=NULL,socket='udp:129.240.253.197:5060',methods=8159,last_modified='2012-08-29 13:19:11',ruid='uloc-503dfa6f-7959-1',instance=NULL,reg_id=0 where username='2549619' AND contact='sip:2549619@193.157.149.56' AND callid=&#39;94f2f534-e3cc629f-5bd8343e(a)193.157.149.56&#39; AND domain='hometest.voip.uio.no'] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_res.c:118]: allocate 28 bytes for result set at 0xb7cd2d90 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_dbase.c:494]: 0xb7c9df08 PQresultStatus(PGRES_COMMAND_OK) PQgetResult(0x9058e78) Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_dbase.c:393]: PQclear(0x9058e78) result set Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_res.c:81]: freeing 0 columns Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_res.c:136]: freeing result set at 0xb7cd2d90 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_cluster [dbcl_api.c:357]: parallel operation - cluster [data2] (9/1) Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_val.c:163]: PQescapeStringConn: in: 42 chars, out: 42 chars Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_val.c:163]: PQescapeStringConn: in: 24 chars, out: 24 chars Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_val.c:163]: PQescapeStringConn: in: 20 chars, out: 20 chars Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_val.c:163]: PQescapeStringConn: in: 7 chars, out: 7 chars Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_val.c:163]: PQescapeStringConn: in: 26 chars, out: 26 chars Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_val.c:163]: PQescapeStringConn: in: 41 chars, out: 41 chars Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_val.c:163]: PQescapeStringConn: in: 20 chars, out: 20 chars Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_dbase.c:224]: sending query ok: 0xb7c9dfd0 (7) - [update voip_location set expires='2012-08-29 13:21:11',q=-1.00 ,cseq=15,flags=0,cflags=0,user_agent='PolycomSoundPointIP-SPIP_331-UA/3.2.1.0054',received=NULL,path=NULL,socket='udp:129.240.253.197:5060',methods=8159,last_modified='2012-08-29 13:19:11',ruid='uloc-503dfa6f-7959-1',instance=NULL,reg_id=0 where username='2549619' AND contact='sip:2549619@193.157.149.56' AND callid=&#39;94f2f534-e3cc629f-5bd8343e(a)193.157.149.56&#39; AND domain='hometest.voip.uio.no'] Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_res.c:118]: allocate 28 bytes for result set at 0xb7cd2d90 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_dbase.c:494]: 0xb7c9dfd0 PQresultStatus(PGRES_COMMAND_OK) PQgetResult(0x9058e78) Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_postgres [km_dbase.c:393]: PQclear(0x9058e78) result set Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_res.c:81]: freeing 0 columns Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [db_res.c:136]: freeing result set at 0xb7cd2d90 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: db_cluster [dbcl_api.c:391]: executing db cluster affected-rows command Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: registrar [reply.c:368]: created Contact HF: Contact: <sip:2549619@193.157.149.56>;expires=120 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: sl [sl.c:278]: reply in stateless mode (sl) Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [msg_translator.c:206]: check_via_address(193.157.149.56, 193.157.149.56, 0) Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list 0xb5d23220 Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil) Aug 29 13:19:11 voipt1-edge1 last message repeated 4 times Aug 29 13:19:11 voipt1-edge1 /nett/kamailio/current/sbin/kamailio[31068]: DEBUG: <core> [xavp.c:365]: destroying xavp list (nil) -- Øyvind Kolbu