Hello, it seems that the fileds inside the object are deleted, not the entire object. The match was done on username and ruid for deletion, both of them are missing. I will look at the mongo api to see if something was set wrong there for the delete command. Cheers, Daniel On Fri, Jan 30, 2015 at 9:54 AM, Mickael Marrache &lt;mickaelmarrache(a)gmail.com -- Daniel-Constantin Mierla - http://www.asipto.com http://twitter.com/#!/miconda - http://www.linkedin.com/in/micond <http://www.linkedin.com/in/miconda>

Hi, The log entries are all of the form: DEBUG: db_mongodb [mongodb_dbase.c:948]: db_mongodb_delete(): delete filter document: { "expires" : { "$date" : 1422728781000 }, "expires" : { "$date" : 0 } } Mickael From: sr-users [mailto:sr-users-bounces@lists.sip-router.org] On Behalf Of Daniel-Constantin Mierla Sent: Friday, January 30, 2015 4:28 PM To: Kamailio (SER) - Users Mailing List Subject: Re: [SR-Users] Wrong location entries when using usrloc with Mongo I checked quickly the code and mongo c api, it looks ok. Can you see a debug message with content like: ... delete filter document: ... when running with debug=3? If yes, can you send it over to check if is correct? Cheers, Daniel On Fri, Jan 30, 2015 at 10:45 AM, Daniel-Constantin Mierla &lt;miconda(a)gmail.com&gt; wrote: Hello, it seems that the fileds inside the object are deleted, not the entire object. The match was done on username and ruid for deletion, both of them are missing. I will look at the mongo api to see if something was set wrong there for the delete command. Cheers, Daniel On Fri, Jan 30, 2015 at 9:54 AM, Mickael Marrache &lt;mickaelmarrache(a)gmail.com&gt; wrote: I forgot to precise that I allow only one contact per AOR. modparam("registrar", "max_contacts", 1) save("location", "0x04") From: Mickael Marrache [mailto:mickaelmarrache@gmail.com] Sent: Friday, January 30, 2015 10:51 AM To: sr-users(a)lists.sip-router.org Subject: Wrong location entries when using usrloc with Mongo Hi, I start with no location nor in Mongo, nor in memory. My UA registers successfully and I can see the location entry in Mongo. Then, I close my UA which unregisters (by setting Expires header to 0). Then, I open the app again and a new registration is made. The entry after first registration. Looks okay. { "_id" : ObjectId("54cb38f684e58133783f2b42"), "username" : "A", "contact" : "sip:A@192.168.1.3:54217;rinstance=DFAEBBC7;transport=tcp", "expires" : ISODate("2015-01-30T08:55:34Z"), "q" : -1, "callid" : "297EC55073A07BF78F0C05822A6CCDFB47E48705", "cseq" : 8809, "flags" : 0, "cflags" : 0, "user_agent" : "Acrobits Softphone Business/3.1", "received" : "sip:XXXXXXXXXXX:54217;transport=tcp", "path" : "<sip:XXXXXXXXXX;lr;received=sip:XXXXXXXXXXX:54217%3Btransport%3Dtcp>", "socket" : "udp:XXXXXXXXX:5060", "methods" : 4751, "last_modified" : ISODate("2015-01-30T07:55:34Z"), "ruid" : "uloc-54cb38df-3378-2", "instance" : null, "reg_id" : 0 } The same entry after un register (Expires 0). Note that the username field is missing. In any case, I expected the entry to be deleted. { "_id" : ObjectId("54cb38f684e58133783f2b42"), "expires" : ISODate("2015-01-30T08:56:51Z"), "q" : -1, "cseq" : 8811, "flags" : 0, "cflags" : 0, "user_agent" : "Acrobits Softphone Business/3.1", "received" : "sip: XXXXXXXXX:54217;transport=tcp", "path" : "<sip: XXXXXXXXX;lr;received=sip: XXXXXXXXX:54217%3Btransport%3Dtcp>", "socket" : "udp: XXXXXXXXX:5060", "methods" : 4751, "last_modified" : ISODate("2015-01-30T07:56:51Z"), "callid" : "297EC55073A07BF78F0C05822A6CCDFB47E48705", "instance" : null, "reg_id" : 0, "contact" : "sip:A@192.168.1.3:54217;rinstance=DFAEBBC7;transport=tcp" } The entries after second registration. The new entry looks okay. But, the old entry is still here. { "_id" : ObjectId("54cb38f684e58133783f2b42"), "expires" : ISODate("2015-01-30T08:56:51Z"), "q" : -1, "cseq" : 8811, "flags" : 0, "cflags" : 0, "user_agent" : "Acrobits Softphone Business/3.1", "received" : "sip: XXXXXXXXX:54217;transport=tcp", "path" : "<sip: XXXXXXXXX;lr;received=sip: XXXXXXXXX:54217%3Btransport%3Dtcp>", "socket" : "udp: XXXXXXXXX:5060", "methods" : 4751, "last_modified" : ISODate("2015-01-30T07:56:51Z"), "callid" : "297EC55073A07BF78F0C05822A6CCDFB47E48705", "instance" : null, "reg_id" : 0, "contact" : "sip:A@192.168.1.3:54217;rinstance=DFAEBBC7;transport=tcp" } { "_id" : ObjectId("54cb3a7884e581337a25b895"), "username" : "A", "contact" : "sip:A@192.168.1.3:54217;rinstance=DFAEBBC7;transport=tcp", "expires" : ISODate("2015-01-30T09:02:00Z"), "q" : -1, "callid" : "297EC55073A07BF78F0C05822A6CCDFB47E48705", "cseq" : 8813, "flags" : 0, "cflags" : 0, "user_agent" : "Acrobits Softphone Business/3.1", "received" : "sip: XXXXXXXXX:54217;transport=tcp", "path" : "<sip: XXXXXXXXX;lr;received=sip: XXXXXXXXX:54217%3Btransport%3Dtcp>", "socket" : "udp: XXXXXXXXX:5060", "methods" : 4751, "last_modified" : ISODate("2015-01-30T08:02:00Z"), "ruid" : "uloc-54cb38df-337a-1", "instance" : null, "reg_id" : 0 } The issue is the entry is not deleted after un registering. I precise that registrations are dispatched over multiple registrars with all accesses the same Mongo cluster. Thanks, Mickael _______________________________________________ SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list sr-users(a)lists.sip-router.org http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users -- Daniel-Constantin Mierla - http://www.asipto.com http://twitter.com/#!/miconda - http://www.linkedin.com/in/micond <http://www.linkedin.com/in/miconda> -- Daniel-Constantin Mierla - http://www.asipto.com http://twitter.com/#!/miconda - http://www.linkedin.com/in/micond <http://www.linkedin.com/in/miconda>

I haven't had time to look at it, being traveling to Fosdem in the past days. It is on my short term agenda. Cheers, Daniel On 02/02/15 12:38, Mickael Marrache wrote: -- Daniel-Constantin Mierla http://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda

Hi, Sorry for the late reply, I had to reinstall my whole Kamailio + Mongo environment. The issue is still present with the last changes. When reproducing the issue, I see the following log: [31723]: DEBUG: db_mongodb [mongodb_dbase.c:851]: db_mongodb_query(): query to collection [location] [31723]: DEBUG: db_mongodb [mongodb_dbase.c:885]: db_mongodb_query(): query filter: { "username" : "u1" } [31723]: DEBUG: db_mongodb [mongodb_dbase.c:904]: db_mongodb_query(): columns filter: { "contact" : 1, "expires" : 1, "q" : 1, "callid" : 1, "cseq" : 1, "flags" : 1, "cflags" : 1, "user_agent" : 1, "received" : 1, "path" : 1, "socket" : 1, "methods" : 1, "last_modified" : 1, "ruid" : 1, "instance" : 1, "reg_id" : 1 } [31723]: DEBUG: <core> [db_res.c:116]: db_new_result(): allocate 56 bytes for result set at 0x7f548558aae0 [31723]: DEBUG: db_mongodb [mongodb_dbase.c:349]: db_mongodb_get_columns(): 16 columns returned from the query [31723]: DEBUG: <core> [db_res.c:154]: db_allocate_columns(): allocate 128 bytes for result names at 0x7f548559cf08 [31723]: DEBUG: <core> [db_res.c:165]: db_allocate_columns(): allocate 64 bytes for result types at 0x7f54855a0c48 [31723]: DEBUG: db_mongodb [mongodb_dbase.c:377]: db_mongodb_get_columns(): Found a field[0] named: contact [31723]: DEBUG: db_mongodb [mongodb_dbase.c:396]: db_mongodb_get_columns(): allocate 16 bytes for RES_NAMES[0] at 0x7f5485596db0 [31723]: DEBUG: db_mongodb [mongodb_dbase.c:431]: db_mongodb_get_columns(): use DB1_STRING result type [31723]: DEBUG: db_mongodb [mongodb_dbase.c:460]: db_mongodb_get_columns(): RES_NAMES(0x7f5485596db0)[0]=[contact] (2) [31723]: DEBUG: db_mongodb [mongodb_dbase.c:377]: db_mongodb_get_columns(): Found a field[1] named: expires [31723]: DEBUG: db_mongodb [mongodb_dbase.c:396]: db_mongodb_get_columns(): allocate 16 bytes for RES_NAMES[1] at 0x7f54855a0cc0 [31723]: DEBUG: db_mongodb [mongodb_dbase.c:421]: db_mongodb_get_columns(): use DB1_DATETIME result type [31723]: DEBUG: db_mongodb [mongodb_dbase.c:460]: db_mongodb_get_columns(): RES_NAMES(0x7f54855a0cc0)[1]=[expires] (9) [31723]: DEBUG: db_mongodb [mongodb_dbase.c:377]: db_mongodb_get_columns(): Found a field[2] named: q [31723]: DEBUG: db_mongodb [mongodb_dbase.c:396]: db_mongodb_get_columns(): allocate 16 bytes for RES_NAMES[2] at 0x7f54855a0c00 [31723]: DEBUG: db_mongodb [mongodb_dbase.c:416]: db_mongodb_get_columns(): use DB1_DOUBLE result type [31723]: DEBUG: db_mongodb [mongodb_dbase.c:460]: db_mongodb_get_columns(): RES_NAMES(0x7f54855a0c00)[2]=[q] (1) [31723]: DEBUG: db_mongodb [mongodb_dbase.c:377]: db_mongodb_get_columns(): Found a field[3] named: callid [31723]: DEBUG: db_mongodb [mongodb_dbase.c:396]: db_mongodb_get_columns(): allocate 16 bytes for RES_NAMES[3] at 0x7f548559d038 [31723]: DEBUG: db_mongodb [mongodb_dbase.c:431]: db_mongodb_get_columns(): use DB1_STRING result type [31723]: DEBUG: db_mongodb [mongodb_dbase.c:460]: db_mongodb_get_columns(): RES_NAMES(0x7f548559d038)[3]=[callid] (2) [31723]: DEBUG: db_mongodb [mongodb_dbase.c:377]: db_mongodb_get_columns(): Found a field[4] named: cseq [31723]: DEBUG: db_mongodb [mongodb_dbase.c:396]: db_mongodb_get_columns(): allocate 16 bytes for RES_NAMES[4] at 0x7f548559d080 [31723]: DEBUG: db_mongodb [mongodb_dbase.c:406]: db_mongodb_get_columns(): use DB1_INT result type [31723]: DEBUG: db_mongodb [mongodb_dbase.c:460]: db_mongodb_get_columns(): RES_NAMES(0x7f548559d080)[4]=[cseq] (16) [31723]: DEBUG: db_mongodb [mongodb_dbase.c:377]: db_mongodb_get_columns(): Found a field[5] named: flags [31723]: DEBUG: db_mongodb [mongodb_dbase.c:396]: db_mongodb_get_columns(): allocate 16 bytes for RES_NAMES[5] at 0x7f5485599308 [31723]: DEBUG: db_mongodb [mongodb_dbase.c:406]: db_mongodb_get_columns(): use DB1_INT result type [31723]: DEBUG: db_mongodb [mongodb_dbase.c:460]: db_mongodb_get_columns(): RES_NAMES(0x7f5485599308)[5]=[flags] (16) [31723]: DEBUG: db_mongodb [mongodb_dbase.c:377]: db_mongodb_get_columns(): Found a field[6] named: cflags [31723]: DEBUG: db_mongodb [mongodb_dbase.c:396]: db_mongodb_get_columns(): allocate 16 bytes for RES_NAMES[6] at 0x7f5485599350 [31723]: DEBUG: db_mongodb [mongodb_dbase.c:406]: db_mongodb_get_columns(): use DB1_INT result type [31723]: DEBUG: db_mongodb [mongodb_dbase.c:460]: db_mongodb_get_columns(): RES_NAMES(0x7f5485599350)[6]=[cflags] (16) [31723]: DEBUG: db_mongodb [mongodb_dbase.c:377]: db_mongodb_get_columns(): Found a field[7] named: user_agent [31723]: DEBUG: db_mongodb [mongodb_dbase.c:396]: db_mongodb_get_columns(): allocate 16 bytes for RES_NAMES[7] at 0x7f5485599398 [31723]: DEBUG: db_mongodb [mongodb_dbase.c:431]: db_mongodb_get_columns(): use DB1_STRING result type [31723]: DEBUG: db_mongodb [mongodb_dbase.c:460]: db_mongodb_get_columns(): RES_NAMES(0x7f5485599398)[7]=[user_agent] (2) [31723]: DEBUG: db_mongodb [mongodb_dbase.c:377]: db_mongodb_get_columns(): Found a field[8] named: received [31723]: DEBUG: db_mongodb [mongodb_dbase.c:396]: db_mongodb_get_columns(): allocate 16 bytes for RES_NAMES[8] at 0x7f54855993e0 [31723]: DEBUG: db_mongodb [mongodb_dbase.c:431]: db_mongodb_get_columns(): use DB1_STRING result type [31723]: DEBUG: db_mongodb [mongodb_dbase.c:460]: db_mongodb_get_columns(): RES_NAMES(0x7f54855993e0)[8]=[received] (2) [31723]: DEBUG: db_mongodb [mongodb_dbase.c:377]: db_mongodb_get_columns(): Found a field[9] named: path [31723]: DEBUG: db_mongodb [mongodb_dbase.c:396]: db_mongodb_get_columns(): allocate 16 bytes for RES_NAMES[9] at 0x7f5485599428 [31723]: DEBUG: db_mongodb [mongodb_dbase.c:431]: db_mongodb_get_columns(): use DB1_STRING result type [31723]: DEBUG: db_mongodb [mongodb_dbase.c:460]: db_mongodb_get_columns(): RES_NAMES(0x7f5485599428)[9]=[path] (2) [31723]: DEBUG: db_mongodb [mongodb_dbase.c:377]: db_mongodb_get_columns(): Found a field[10] named: socket [31723]: DEBUG: db_mongodb [mongodb_dbase.c:396]: db_mongodb_get_columns(): allocate 16 bytes for RES_NAMES[10] at 0x7f5485599470 [31723]: DEBUG: db_mongodb [mongodb_dbase.c:431]: db_mongodb_get_columns(): use DB1_STRING result type [31723]: DEBUG: db_mongodb [mongodb_dbase.c:460]: db_mongodb_get_columns(): RES_NAMES(0x7f5485599470)[10]=[socket] (2) [31723]: DEBUG: db_mongodb [mongodb_dbase.c:377]: db_mongodb_get_columns(): Found a field[11] named: methods [31723]: DEBUG: db_mongodb [mongodb_dbase.c:396]: db_mongodb_get_columns(): allocate 16 bytes for RES_NAMES[11] at 0x7f54855994b8 [31723]: DEBUG: db_mongodb [mongodb_dbase.c:406]: db_mongodb_get_columns(): use DB1_INT result type [31723]: DEBUG: db_mongodb [mongodb_dbase.c:460]: db_mongodb_get_columns(): RES_NAMES(0x7f54855994b8)[11]=[methods] (16) [31723]: DEBUG: db_mongodb [mongodb_dbase.c:377]: db_mongodb_get_columns(): Found a field[12] named: last_modified [31723]: DEBUG: db_mongodb [mongodb_dbase.c:396]: db_mongodb_get_columns(): allocate 16 bytes for RES_NAMES[12] at 0x7f5485599500 [31723]: DEBUG: db_mongodb [mongodb_dbase.c:421]: db_mongodb_get_columns(): use DB1_DATETIME result type [31723]: DEBUG: db_mongodb [mongodb_dbase.c:460]: db_mongodb_get_columns(): RES_NAMES(0x7f5485599500)[12]=[last_modified] (9) [31723]: DEBUG: db_mongodb [mongodb_dbase.c:377]: db_mongodb_get_columns(): Found a field[13] named: ruid [31723]: DEBUG: db_mongodb [mongodb_dbase.c:396]: db_mongodb_get_columns(): allocate 16 bytes for RES_NAMES[13] at 0x7f5485599548 [31723]: DEBUG: db_mongodb [mongodb_dbase.c:431]: db_mongodb_get_columns(): use DB1_STRING result type [31723]: DEBUG: db_mongodb [mongodb_dbase.c:460]: db_mongodb_get_columns(): RES_NAMES(0x7f5485599548)[13]=[ruid] (2) [31723]: DEBUG: db_mongodb [mongodb_dbase.c:377]: db_mongodb_get_columns(): Found a field[14] named: instance [31723]: DEBUG: db_mongodb [mongodb_dbase.c:396]: db_mongodb_get_columns(): allocate 16 bytes for RES_NAMES[14] at 0x7f5485599590 [31723]: WARNING: db_mongodb [mongodb_dbase.c:454]: db_mongodb_get_columns(): unhandled data type column (instance) type id (10), use DB1_STRING as default [31723]: DEBUG: db_mongodb [mongodb_dbase.c:460]: db_mongodb_get_columns(): RES_NAMES(0x7f5485599590)[14]=[instance] (10) [31723]: DEBUG: db_mongodb [mongodb_dbase.c:377]: db_mongodb_get_columns(): Found a field[15] named: reg_id [31723]: DEBUG: db_mongodb [mongodb_dbase.c:396]: db_mongodb_get_columns(): allocate 16 bytes for RES_NAMES[15] at 0x7f54855995d8 [31723]: DEBUG: db_mongodb [mongodb_dbase.c:406]: db_mongodb_get_columns(): use DB1_INT result type [31723]: DEBUG: db_mongodb [mongodb_dbase.c:460]: db_mongodb_get_columns(): RES_NAMES(0x7f54855995d8)[15]=[reg_id] (16) [31723]: DEBUG: <core> [db_res.c:184]: db_allocate_rows(): allocate 16000 bytes for rows at 0x7f54855c0578 [31723]: DEBUG: db_mongodb [mongodb_dbase.c:671]: db_mongdob_convert_result(): selected document: { "_id" : { "$oid" : "54da12e1381d0b7be91653e1" }, "contact" : "sip:u1@xxxxxxxxxxx;rinstance=2786DE56", "expires" : { "$date" : 1423581425000 }, "q" : -1.000000, "callid" : "5D2740435DA6C7EBE42F0C3822F922C6861246B3", "cseq" : 9714, "flags" : 0, "cflags" : 0, "user_agent" : "Acrobits Softphone Business\/3.1", "received" : "sip:xxxxxxxxxx", "path" : "<sip:xxxxxxxxx:5080;lr;received=sip:xxxxxxxxxxx>", "socket" : "udp:xxxxxxxxxxxxx", "methods" : 4751, "last_modified" : { "$date" : 1423577825000 }, "ruid" : "uloc-54d9e708-7be9-c1", "instance" : null, "reg_id" : 0 } [31723]: DEBUG: <core> [db_row.c:117]: db_allocate_row(): allocate 512 bytes for row values at 0x7f5485539e80 [31723]: DEBUG: db_mongodb [mongodb_dbase.c:522]: db_mongdob_convert_bson(): looking for field[0] named: contact [31723]: DEBUG: db_mongodb [mongodb_dbase.c:610]: db_mongdob_convert_bson(): RES_NAMES(0x7f5485596db0)[0]=[contact] (2) [31723]: DEBUG: db_mongodb [mongodb_dbase.c:522]: db_mongdob_convert_bson(): looking for field[1] named: expires [31723]: DEBUG: db_mongodb [mongodb_dbase.c:610]: db_mongdob_convert_bson(): RES_NAMES(0x7f54855a0cc0)[1]=[expires] (9) [31723]: DEBUG: db_mongodb [mongodb_dbase.c:522]: db_mongdob_convert_bson(): looking for field[2] named: q [31723]: DEBUG: db_mongodb [mongodb_dbase.c:610]: db_mongdob_convert_bson(): RES_NAMES(0x7f54855a0c00)[2]=[q] (1) [31723]: DEBUG: db_mongodb [mongodb_dbase.c:522]: db_mongdob_convert_bson(): looking for field[3] named: callid [31723]: DEBUG: db_mongodb [mongodb_dbase.c:610]: db_mongdob_convert_bson(): RES_NAMES(0x7f548559d038)[3]=[callid] (2) [31723]: DEBUG: db_mongodb [mongodb_dbase.c:522]: db_mongdob_convert_bson(): looking for field[4] named: cseq [31723]: DEBUG: db_mongodb [mongodb_dbase.c:610]: db_mongdob_convert_bson(): RES_NAMES(0x7f548559d080)[4]=[cseq] (16) [31723]: DEBUG: db_mongodb [mongodb_dbase.c:522]: db_mongdob_convert_bson(): looking for field[5] named: flags [31723]: DEBUG: db_mongodb [mongodb_dbase.c:610]: db_mongdob_convert_bson(): RES_NAMES(0x7f5485599308)[5]=[flags] (16) [31723]: DEBUG: db_mongodb [mongodb_dbase.c:522]: db_mongdob_convert_bson(): looking for field[6] named: cflags [31723]: DEBUG: db_mongodb [mongodb_dbase.c:610]: db_mongdob_convert_bson(): RES_NAMES(0x7f5485599350)[6]=[cflags] (16) [31723]: DEBUG: db_mongodb [mongodb_dbase.c:522]: db_mongdob_convert_bson(): looking for field[7] named: user_agent [31723]: DEBUG: db_mongodb [mongodb_dbase.c:610]: db_mongdob_convert_bson(): RES_NAMES(0x7f5485599398)[7]=[user_agent] (2) [31723]: DEBUG: db_mongodb [mongodb_dbase.c:522]: db_mongdob_convert_bson(): looking for field[8] named: received [31723]: DEBUG: db_mongodb [mongodb_dbase.c:610]: db_mongdob_convert_bson(): RES_NAMES(0x7f54855993e0)[8]=[received] (2) [31723]: DEBUG: db_mongodb [mongodb_dbase.c:522]: db_mongdob_convert_bson(): looking for field[9] named: path [31723]: DEBUG: db_mongodb [mongodb_dbase.c:610]: db_mongdob_convert_bson(): RES_NAMES(0x7f5485599428)[9]=[path] (2) [31723]: DEBUG: db_mongodb [mongodb_dbase.c:522]: db_mongdob_convert_bson(): looking for field[10] named: socket [31723]: DEBUG: db_mongodb [mongodb_dbase.c:610]: db_mongdob_convert_bson(): RES_NAMES(0x7f5485599470)[10]=[socket] (2) [31723]: DEBUG: db_mongodb [mongodb_dbase.c:522]: db_mongdob_convert_bson(): looking for field[11] named: methods [31723]: DEBUG: db_mongodb [mongodb_dbase.c:610]: db_mongdob_convert_bson(): RES_NAMES(0x7f54855994b8)[11]=[methods] (16) [31723]: DEBUG: db_mongodb [mongodb_dbase.c:522]: db_mongdob_convert_bson(): looking for field[12] named: last_modified [31723]: DEBUG: db_mongodb [mongodb_dbase.c:610]: db_mongdob_convert_bson(): RES_NAMES(0x7f5485599500)[12]=[last_modified] (9) [31723]: DEBUG: db_mongodb [mongodb_dbase.c:522]: db_mongdob_convert_bson(): looking for field[13] named: ruid [31723]: DEBUG: db_mongodb [mongodb_dbase.c:610]: db_mongdob_convert_bson(): RES_NAMES(0x7f5485599548)[13]=[ruid] (2) [31723]: DEBUG: db_mongodb [mongodb_dbase.c:522]: db_mongdob_convert_bson(): looking for field[14] named: instance [31723]: DEBUG: db_mongodb [mongodb_dbase.c:610]: db_mongdob_convert_bson(): RES_NAMES(0x7f5485599590)[14]=[instance] (10) [31723]: DEBUG: db_mongodb [mongodb_dbase.c:522]: db_mongdob_convert_bson(): looking for field[15] named: reg_id [31723]: DEBUG: db_mongodb [mongodb_dbase.c:610]: db_mongdob_convert_bson(): RES_NAMES(0x7f54855995d8)[15]=[reg_id] (16) [31723]: DEBUG: db_mongodb [mongodb_dbase.c:682]: db_mongdob_convert_result(): retrieved number of rows: 1 [31723]: DEBUG: <core> [socket_info.c:563]: grep_sock_info(): checking if host==us: 14==14 && [xxxxxx] == [xxxxxxxxx] [31723]: DEBUG: <core> [socket_info.c:566]: grep_sock_info(): checking if port 5080 (advertise 0) matches port 5080 [31723]: DEBUG: <core> [db_res.c:79]: db_free_columns(): freeing 16 columns [31723]: DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[0] at 0x7f5485596db0 [31723]: DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[1] at 0x7f54855a0cc0 [31723]: DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[2] at 0x7f54855a0c00 [31723]: DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[3] at 0x7f548559d038 [31723]: DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[4] at 0x7f548559d080 [31723]: DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[5] at 0x7f5485599308 [31723]: DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[6] at 0x7f5485599350 [31723]: DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[7] at 0x7f5485599398 [31723]: DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[8] at 0x7f54855993e0 [31723]: DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[9] at 0x7f5485599428 [31723]: DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[10] at 0x7f5485599470 [31723]: DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[11] at 0x7f54855994b8 [31723]: DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[12] at 0x7f5485599500 [31723]: DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[13] at 0x7f5485599548 [31723]: DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[14] at 0x7f5485599590 [31723]: DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[15] at 0x7f54855995d8 [31723]: DEBUG: <core> [db_res.c:92]: db_free_columns(): freeing result names at 0x7f548559cf08 [31723]: DEBUG: <core> [db_res.c:97]: db_free_columns(): freeing result types at 0x7f54855a0c48 [31723]: DEBUG: <core> [db_res.c:52]: db_free_rows(): freeing 1 rows [31723]: DEBUG: <core> [db_row.c:95]: db_free_row(): freeing row values at 0x7f5485539e80 [31723]: DEBUG: <core> [db_res.c:60]: db_free_rows(): freeing rows at 0x7f54855c0578 [31723]: DEBUG: <core> [db_res.c:134]: db_free_result(): freeing result set at 0x7f548558aae0 [31723]: DEBUG: <core> [strcommon.c:212]: unescape_user(): unescaped string is <sip:xxxxxxxxxxxxxx> [31723]: DEBUG: registrar [path.c:110]: build_path_vector(): received is <sip:xxxxxxxxxxxxxx> [31723]: DEBUG: registrar [path.c:118]: build_path_vector(): path is <<sip:xxxxxxxxx;lr;received=sip:xxxxxxxxxxx>> [31723]: DEBUG: <core> [sruid.c:183]: sruid_next(): new sruid is [uloc-54d9e708-7beb-d1] (29 / 21) [31723]: DEBUG: registrar [save.c:409]: pack_ci(): generated ruid is: uloc-54d9e708-7beb-d1 [31723]: DEBUG: usrloc [ucontact.c:948]: db_update_ucontact_ruid(): ruid:uloc-54d9e708-7be9-c1 [31723]: DEBUG: usrloc [ucontact.c:1059]: db_update_ucontact_ruid(): contact:sip:u1@xxxxxxxxxxx;rinstance=2786DE56 [31723]: DEBUG: registrar [reply.c:374]: build_contact(): created Contact HF: Contact: <sip:u1@xxxxxxxxxx;rinstance=2786DE56>;expires=3600;received="sip:xxxxxxxxxx"#015#012 [31723]: DEBUG: sl [sl.c:280]: send_reply(): reply in stateless mode (sl) [31723]: DEBUG: <core> [msg_translator.c:158]: check_via_address(): (xxxxxxxxx,xxxxxxxxx, 0) [31723]: DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list 0x7f547e87e188 [31723]: DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil) [31723]: DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil) [31723]: DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil) [31723]: DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil) [31723]: DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil) [31723]: DEBUG: <core> [xavp.c:446]: xavp_destroy_list(): destroying xavp list (nil) [31723]: DEBUG: <core> [receive.c:278]: receive_msg(): cleaning up Thanks, Mickael From: Daniel-Constantin Mierla [mailto:miconda@gmail.com] Sent: Tuesday, February 03, 2015 9:43 PM To: Mickael Marrache; sr-users(a)lists.sip-router.org Subject: Re: [SR-Users] Wrong location entries when using usrloc with Mongo I pushed a patch on git master branch for this issue, can you try it and report the results? I tested a bit with usrloc and DB_ONLY mode, it seemed fine here. Cheers, Daniel On 03/02/15 12:36, Daniel-Constantin Mierla wrote: I haven't had time to look at it, being traveling to Fosdem in the past days. It is on my short term agenda. Cheers, Daniel On 02/02/15 12:38, Mickael Marrache wrote: Any news regarding this issue? I don't think { "expires" : { "$date" : 1422728781000 }, "expires" : { "$date" : 0 } } is a valid query… Is the intent to remove entries where expires = 1422728781000 or expires = 0? If yes, I think the logical operator $or should be used for that? Let me know how I can help you to figure out what the issue is. Thanks, Mickael From: Mickael Marrache [mailto:mickaelmarrache@gmail.com] Sent: Saturday, January 31, 2015 8:32 PM To: 'Kamailio (SER) - Users Mailing List' Subject: RE: [SR-Users] Wrong location entries when using usrloc with Mongo Hi, The log entries are all of the form: DEBUG: db_mongodb [mongodb_dbase.c:948]: db_mongodb_delete(): delete filter document: { "expires" : { "$date" : 1422728781000 }, "expires" : { "$date" : 0 } } Mickael From: sr-users [mailto:sr-users-bounces@lists.sip-router.org] On Behalf Of Daniel-Constantin Mierla Sent: Friday, January 30, 2015 4:28 PM To: Kamailio (SER) - Users Mailing List Subject: Re: [SR-Users] Wrong location entries when using usrloc with Mongo I checked quickly the code and mongo c api, it looks ok. Can you see a debug message with content like: ... delete filter document: ... when running with debug=3? If yes, can you send it over to check if is correct? Cheers, Daniel On Fri, Jan 30, 2015 at 10:45 AM, Daniel-Constantin Mierla &lt;miconda(a)gmail.com&gt; wrote: Hello, it seems that the fileds inside the object are deleted, not the entire object. The match was done on username and ruid for deletion, both of them are missing. I will look at the mongo api to see if something was set wrong there for the delete command. Cheers, Daniel On Fri, Jan 30, 2015 at 9:54 AM, Mickael Marrache &lt;mickaelmarrache(a)gmail.com&gt; wrote: I forgot to precise that I allow only one contact per AOR. modparam("registrar", "max_contacts", 1) save("location", "0x04") From: Mickael Marrache [mailto:mickaelmarrache@gmail.com] Sent: Friday, January 30, 2015 10:51 AM To: sr-users(a)lists.sip-router.org Subject: Wrong location entries when using usrloc with Mongo Hi, I start with no location nor in Mongo, nor in memory. My UA registers successfully and I can see the location entry in Mongo. Then, I close my UA which unregisters (by setting Expires header to 0). Then, I open the app again and a new registration is made. The entry after first registration. Looks okay. { "_id" : ObjectId("54cb38f684e58133783f2b42"), "username" : "A", "contact" : "sip:A@192.168.1.3:54217;rinstance=DFAEBBC7;transport=tcp", "expires" : ISODate("2015-01-30T08:55:34Z"), "q" : -1, "callid" : "297EC55073A07BF78F0C05822A6CCDFB47E48705", "cseq" : 8809, "flags" : 0, "cflags" : 0, "user_agent" : "Acrobits Softphone Business/3.1", "received" : "sip:XXXXXXXXXXX:54217;transport=tcp", "path" : "<sip:XXXXXXXXXX;lr;received=sip:XXXXXXXXXXX:54217%3Btransport%3Dtcp>", "socket" : "udp:XXXXXXXXX:5060", "methods" : 4751, "last_modified" : ISODate("2015-01-30T07:55:34Z"), "ruid" : "uloc-54cb38df-3378-2", "instance" : null, "reg_id" : 0 } The same entry after un register (Expires 0). Note that the username field is missing. In any case, I expected the entry to be deleted. { "_id" : ObjectId("54cb38f684e58133783f2b42"), "expires" : ISODate("2015-01-30T08:56:51Z"), "q" : -1, "cseq" : 8811, "flags" : 0, "cflags" : 0, "user_agent" : "Acrobits Softphone Business/3.1", "received" : <sip:XXXXXXXXX:54217;transport=tcp> "sip: XXXXXXXXX:54217;transport=tcp", "path" : " <sip:XXXXXXXXX;lr;received=sip:XXXXXXXXX:54217%3Btransport%3Dtcp> <sip: XXXXXXXXX;lr;received=sip: XXXXXXXXX:54217%3Btransport%3Dtcp>", "socket" : "udp: XXXXXXXXX:5060", "methods" : 4751, "last_modified" : ISODate("2015-01-30T07:56:51Z"), "callid" : "297EC55073A07BF78F0C05822A6CCDFB47E48705", "instance" : null, "reg_id" : 0, "contact" : "sip:A@192.168.1.3:54217;rinstance=DFAEBBC7;transport=tcp" } The entries after second registration. The new entry looks okay. But, the old entry is still here. { "_id" : ObjectId("54cb38f684e58133783f2b42"), "expires" : ISODate("2015-01-30T08:56:51Z"), "q" : -1, "cseq" : 8811, "flags" : 0, "cflags" : 0, "user_agent" : "Acrobits Softphone Business/3.1", "received" : <sip:XXXXXXXXX:54217;transport=tcp> "sip: XXXXXXXXX:54217;transport=tcp", "path" : " <sip:XXXXXXXXX;lr;received=sip:XXXXXXXXX:54217%3Btransport%3Dtcp> <sip: XXXXXXXXX;lr;received=sip: XXXXXXXXX:54217%3Btransport%3Dtcp>", "socket" : "udp: XXXXXXXXX:5060", "methods" : 4751, "last_modified" : ISODate("2015-01-30T07:56:51Z"), "callid" : "297EC55073A07BF78F0C05822A6CCDFB47E48705", "instance" : null, "reg_id" : 0, "contact" : "sip:A@192.168.1.3:54217;rinstance=DFAEBBC7;transport=tcp" } { "_id" : ObjectId("54cb3a7884e581337a25b895"), "username" : "A", "contact" : "sip:A@192.168.1.3:54217;rinstance=DFAEBBC7;transport=tcp", "expires" : ISODate("2015-01-30T09:02:00Z"), "q" : -1, "callid" : "297EC55073A07BF78F0C05822A6CCDFB47E48705", "cseq" : 8813, "flags" : 0, "cflags" : 0, "user_agent" : "Acrobits Softphone Business/3.1", "received" : <sip:XXXXXXXXX:54217;transport=tcp> "sip: XXXXXXXXX:54217;transport=tcp", "path" : " <sip:XXXXXXXXX;lr;received=sip:XXXXXXXXX:54217%3Btransport%3Dtcp> <sip: XXXXXXXXX;lr;received=sip: XXXXXXXXX:54217%3Btransport%3Dtcp>", "socket" : "udp: XXXXXXXXX:5060", "methods" : 4751, "last_modified" : ISODate("2015-01-30T08:02:00Z"), "ruid" : "uloc-54cb38df-337a-1", "instance" : null, "reg_id" : 0 } The issue is the entry is not deleted after un registering. I precise that registrations are dispatched over multiple registrars with all accesses the same Mongo cluster. Thanks, Mickael _______________________________________________ SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list sr-users(a)lists.sip-router.org http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users -- Daniel-Constantin Mierla - http://www.asipto.com http://twitter.com/#!/miconda <http://twitter.com/#%21/miconda> - http://www.linkedin.com/in/micond <http://www.linkedin.com/in/miconda> -- Daniel-Constantin Mierla - http://www.asipto.com http://twitter.com/#!/miconda <http://twitter.com/#%21/miconda> - http://www.linkedin.com/in/micond <http://www.linkedin.com/in/miconda> -- Daniel-Constantin Mierla http://twitter.com/#!/miconda <http://twitter.com/#%21/miconda> - http://www.linkedin.com/in/miconda -- Daniel-Constantin Mierla http://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda