<div dir="ltr">Hello,<div><br></div><div>Now after kamailio startup seems that presence module is not working correctly when receives a  publish message, seems that is missing  needed fields for presence module</div><div><br></div><div><br></div><div>LOG debug=3</div><div><br></div><div><br></div><div><div> 3(3749) DEBUG: <core> [parser/msg_parser.c:606]: parse_msg(): SIP Request:</div><div> 3(3749) DEBUG: <core> [parser/msg_parser.c:608]: parse_msg():  method:  <PUBLISH></div><div> 3(3749) DEBUG: <core> [parser/msg_parser.c:610]: parse_msg():  uri:     <<a href="mailto:sip%3A301@teste.teste.com.pt">sip:301@teste.teste.com.pt</a>></div><div> 3(3749) DEBUG: <core> [parser/msg_parser.c:612]: parse_msg():  version: <SIP/2.0></div><div> 3(3749) DEBUG: <core> [parser/parse_via.c:1254]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK99ab.a0494a80806f1126d231ac6412d25d86.0>; state=16</div><div> 3(3749) DEBUG: <core> [parser/parse_via.c:2642]: parse_via(): end of header reached, state=5</div><div> 3(3749) DEBUG: <core> [parser/msg_parser.c:496]: parse_headers(): parse_headers: Via found, flags=2</div><div> 3(3749) DEBUG: <core> [parser/msg_parser.c:498]: parse_headers(): parse_headers: this is the first via</div><div> 3(3749) DEBUG: <core> [receive.c:134]: receive_msg(): After parse_msg...</div><div> 3(3749) DEBUG: <core> [receive.c:177]: receive_msg(): preparing to run routing scripts...</div><div> 3(3749) DEBUG: <core> [parser/parse_via.c:1254]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK99ab.dcb79f00000000000000000000000000.0>; state=16</div><div> 3(3749) DEBUG: <core> [parser/parse_via.c:2642]: parse_via(): end of header reached, state=5</div><div> 3(3749) DEBUG: <core> [parser/msg_parser.c:496]: parse_headers(): parse_headers: Via found, flags=100</div><div> 3(3749) DEBUG: <core> [parser/msg_parser.c:509]: parse_headers(): parse_headers: this is the second via</div><div> 3(3749) DEBUG: <core> [parser/parse_addr_spec.c:894]: parse_addr_spec(): end of header reached, state=10</div><div> 3(3749) DEBUG: <core> [parser/msg_parser.c:173]: get_hdr_field(): DEBUG: get_hdr_field: <To> [33]; uri=[<a href="mailto:sip%3A301@teste.teste.com.pt">sip:301@teste.teste.com.pt</a>] </div><div> 3(3749) DEBUG: <core> [parser/msg_parser.c:175]: get_hdr_field(): DEBUG: to body [<<a href="mailto:sip%3A301@teste.teste.com.pt">sip:301@teste.teste.com.pt</a>></div><div>]</div><div> 3(3749) DEBUG: <core> [parser/msg_parser.c:153]: get_hdr_field(): get_hdr_field: cseq <CSeq>: <10> <PUBLISH></div><div> 3(3749) DEBUG: <core> [parser/msg_parser.c:187]: get_hdr_field(): DEBUG: get_hdr_body : content_length=624</div><div> 3(3749) DEBUG: maxfwd [mf_funcs.c:85]: is_maxfwd_present(): value = 69 </div><div> 3(3749) DEBUG: tm [t_lookup.c:1312]: t_newtran(): DEBUG: t_newtran: msg id=5 , global msg id=4 , T on entrance=0xffffffffffffffff</div><div> 3(3749) DEBUG: <core> [parser/msg_parser.c:89]: get_hdr_field(): found end of header</div><div> 3(3749) DEBUG: tm [t_lookup.c:466]: t_lookup_request(): t_lookup_request: start searching: hash=47769, isACK=0</div><div> 3(3749) DEBUG: tm [t_lookup.c:424]: matching_3261(): DEBUG: RFC3261 transaction matching failed</div><div> 3(3749) DEBUG: tm [t_lookup.c:648]: t_lookup_request(): DEBUG: t_lookup_request: no transaction found</div><div> 3(3749) DEBUG: <core> [md5utils.c:67]: MD5StringArray(): MD5 calculated: 6eb163b7ddd8b77ec80bdb2c6b73fe41</div><div> 3(3749) INFO: <script>: Handling publish request -  R=<a href="mailto:sip%3A301@teste.teste.com.pt">sip:301@teste.teste.com.pt</a> ID=<a href="mailto:6869437916cdc134-3693@10.0.20.100">6869437916cdc134-3693@10.0.20.100</a></div><div> 3(3749) DEBUG: presence [event_list.c:348]: search_event(): start event= [dialog/5]</div><div> 3(3749) DEBUG: presence [publish.c:316]: handle_publish(): SIP-If-Match header not found</div><div> 3(3749) DEBUG: presence [presentity.c:87]: generate_ETag(): etag= a.1439906263.3749.5.0 / 21</div><div>  3(3749) DEBUG: presence [publish.c:325]: handle_publish(): new etag  = a.1439906263.3749.5.0 </div><div> 3(3749) DEBUG: presence [publish.c:350]: handle_publish(): Expires header found, value= 241</div><div> 3(3749) DEBUG: presence [presentity.c:429]: update_presentity(): inserting 9 cols into table</div><div> 3(3749) DEBUG: db_mongodb [mongodb_dbase.c:1030]: db_mongodb_insert(): insert document: { "domain" : "<a href="http://teste.teste.com.pt">teste.teste.com.pt</a>", "username" : "301", "event" : "dialog", "etag" : "a.1439906263.3749.5.0", "sender" : "", "body" : { "$type" : "00", "$binary" : "PD94bWwgdmVyc2lvbj0iMS4wIj8+CjxkaWFsb2ctaW5mbyB4bWxucz0idXJuOmlldGY6cGFyYW1zOnhtbDpuczpkaWFsb2ctaW5mbyIgdmVyc2lvbj0iMCIgc3RhdGU9ImZ1bGwiIGVudGl0eT0ic2lwOjMwMUB0ZXN0ZS5pdGNlbnRlci5jb20ucHQiPgogIDxkaWFsb2cgaWQ9IjMxMzQzMzM5MzkzMDM2MzIzNzM0MzQzMjMwMzkzMS02bnZ1eDRpYWZrenIiIGNhbGwtaWQ9IjMxMzQzMzM5MzkzMDM2MzIzNzM0MzQzMjMwMzkzMS02bnZ1eDRpYWZrenIiIGRpcmVjdGlvbj0iaW5pdGlhdG9yIj4KICAgIDxzdGF0ZT5Ucnlpbmc8L3N0YXRlPgogICAgPHJlbW90ZT4KICAgICAgPGlkZW50aXR5PnNpcDozMDJAdGVzdGUuaXRjZW50ZXIuY29tLnB0O3VzZXI9cGhvbmU8L2lkZW50aXR5PgogICAgICA8dGFyZ2V0IHVyaT0ic2lwOjMwMkB0ZXN0ZS5pdGNlbnRlci5jb20ucHQ7dXNlcj1waG9uZSIvPgogICAgPC9yZW1vdGU+CiAgICA8bG9jYWw+CiAgICAgIDxpZGVudGl0eT5zaXA6MzAxQHRlc3RlLml0Y2VudGVyLmNvbS5wdDwvaWRlbnRpdHk+CiAgICAgIDx0YXJnZXQgdXJpPSJzaXA6MzAxQHRlc3RlLml0Y2VudGVyLmNvbS5wdCIvPgogICAgPC9sb2NhbD4KICA8L2RpYWxvZz4KPC9kaWFsb2ctaW5mbz4K" }, "received_time" : 1439906398, "priority" : 0, "expires" : 1439906639 }</div><div> 3(3749) DEBUG: presence [presentity.c:104]: publ_send200ok(): send 200OK reply</div><div> 3(3749) DEBUG: presence [presentity.c:105]: publ_send200ok(): etag= a.1439906263.3749.5.0 - len= 21</div><div> 3(3749) DEBUG: tm [t_lookup.c:1011]: t_check_msg(): DEBUG: t_check_msg: msg id=5 global id=5 T start=0x7fee3ac83c58</div><div> 3(3749) DEBUG: tm [t_lookup.c:1083]: t_check_msg(): DEBUG: t_check_msg: T already found!</div><div> 3(3749) DEBUG: <core> [msg_translator.c:158]: check_via_address(): (10.0.20.100, 10.0.20.100, 0)</div><div> 3(3749) DEBUG: <core> [mem/shm_mem.c:101]: _shm_resize(): WARNING:vqm_resize: resize(0) called</div><div> 3(3749) DEBUG: tm [t_reply.c:1589]: cleanup_uac_timers(): DEBUG: cleanup_uac_timers: RETR/FR timers reset</div><div> 3(3749) DEBUG: tm [t_reply.c:647]: _reply_light(): DEBUG: reply sent out. buf=0x7fee4d90d450: SIP/2.0 200 OK</div><div>Reco..., shmem=0x7fee3ac83920: SIP/2.0 200 OK</div><div>Reco</div><div> 3(3749) DEBUG: tm [t_reply.c:657]: _reply_light(): DEBUG: _reply_light: finished</div><div> 3(3749) DEBUG: sl [sl.c:272]: send_reply(): reply in stateful mode (tm)</div><div> 3(3749) DEBUG: presence [notify.c:1007]: get_subs_db(): querying database table = active_watchers</div><div> 3(3749) DEBUG: db_mongodb [mongodb_dbase.c:851]: db_mongodb_query(): query to collection [active_watchers]</div><div> 3(3749) DEBUG: db_mongodb [mongodb_dbase.c:885]: db_mongodb_query(): query filter: { "presentity_uri" : "<a href="mailto:sip%3A301@teste.teste.com.pt">sip:301@teste.teste.com.pt</a>", "event" : "dialog", "status" : 1, "contact" : { "$ne" : "" } }</div><div> 3(3749) DEBUG: db_mongodb [mongodb_dbase.c:904]: db_mongodb_query(): columns filter: { "to_user" : 1, "to_domain" : 1, "from_user" : 1, "from_domain" : 1, "watcher_username" : 1, "watcher_domain" : 1, "event_id" : 1, "from_tag" : 1, "to_tag" : 1, "callid" : 1, "local_cseq" : 1, "record_route" : 1, "contact" : 1, "expires" : 1, "reason" : 1, "socket_info" : 1, "local_contact" : 1, "version" : 1 }</div><div> 3(3749) DEBUG: <core> [db_res.c:116]: db_new_result(): allocate 56 bytes for result set at 0x7fee4d90cda8</div><div> 3(3749) DEBUG: db_mongodb [mongodb_dbase.c:349]: db_mongodb_get_columns(): 18 columns returned from the query</div><div> 3(3749) DEBUG: <core> [db_res.c:154]: db_allocate_columns(): allocate 144 bytes for result names at 0x7fee4d8fbe38</div><div> 3(3749) DEBUG: <core> [db_res.c:165]: db_allocate_columns(): allocate 72 bytes for result types at 0x7fee4d90d3c8</div><div> 3(3749) DEBUG: db_mongodb [mongodb_dbase.c:377]: db_mongodb_get_columns(): Found a field[0] named: to_user</div><div> 3(3749) DEBUG: db_mongodb [mongodb_dbase.c:396]: db_mongodb_get_columns(): allocate 16 bytes for RES_NAMES[0] at 0x7fee4d90cfd0</div><div> 3(3749) DEBUG: db_mongodb [mongodb_dbase.c:431]: db_mongodb_get_columns(): use DB1_STRING result type</div><div> 3(3749) DEBUG: db_mongodb [mongodb_dbase.c:460]: db_mongodb_get_columns(): RES_NAMES(0x7fee4d90cfd0)[0]=[to_user] (2)</div><div> 3(3749) DEBUG: db_mongodb [mongodb_dbase.c:377]: db_mongodb_get_columns(): Found a field[1] named: to_domain</div><div> 3(3749) DEBUG: db_mongodb [mongodb_dbase.c:396]: db_mongodb_get_columns(): allocate 16 bytes for RES_NAMES[1] at 0x7fee4d90d018</div><div> 3(3749) DEBUG: db_mongodb [mongodb_dbase.c:431]: db_mongodb_get_columns(): use DB1_STRING result type</div><div> 3(3749) DEBUG: db_mongodb [mongodb_dbase.c:460]: db_mongodb_get_columns(): RES_NAMES(0x7fee4d90d018)[1]=[to_domain] (2)</div><div> 3(3749) DEBUG: db_mongodb [mongodb_dbase.c:377]: db_mongodb_get_columns(): Found a field[2] named: from_user</div><div> 3(3749) DEBUG: db_mongodb [mongodb_dbase.c:396]: db_mongodb_get_columns(): allocate 16 bytes for RES_NAMES[2] at 0x7fee4d90ccc0</div><div> 3(3749) DEBUG: db_mongodb [mongodb_dbase.c:431]: db_mongodb_get_columns(): use DB1_STRING result type</div><div> 3(3749) DEBUG: db_mongodb [mongodb_dbase.c:460]: db_mongodb_get_columns(): RES_NAMES(0x7fee4d90ccc0)[2]=[from_user] (2)</div><div> 3(3749) DEBUG: db_mongodb [mongodb_dbase.c:377]: db_mongodb_get_columns(): Found a field[3] named: from_domain</div><div> 3(3749) DEBUG: db_mongodb [mongodb_dbase.c:396]: db_mongodb_get_columns(): allocate 16 bytes for RES_NAMES[3] at 0x7fee4d8fba08</div><div> 3(3749) DEBUG: db_mongodb [mongodb_dbase.c:431]: db_mongodb_get_columns(): use DB1_STRING result type</div><div> 3(3749) DEBUG: db_mongodb [mongodb_dbase.c:460]: db_mongodb_get_columns(): RES_NAMES(0x7fee4d8fba08)[3]=[from_domain] (2)</div><div> 3(3749) DEBUG: db_mongodb [mongodb_dbase.c:377]: db_mongodb_get_columns(): Found a field[4] named: watcher_username</div><div> 3(3749) DEBUG: db_mongodb [mongodb_dbase.c:396]: db_mongodb_get_columns(): allocate 16 bytes for RES_NAMES[4] at 0x7fee4d90c430</div><div> 3(3749) DEBUG: db_mongodb [mongodb_dbase.c:431]: db_mongodb_get_columns(): use DB1_STRING result type</div><div> 3(3749) DEBUG: db_mongodb [mongodb_dbase.c:460]: db_mongodb_get_columns(): RES_NAMES(0x7fee4d90c430)[4]=[watcher_username] (2)</div><div> 3(3749) DEBUG: db_mongodb [mongodb_dbase.c:377]: db_mongodb_get_columns(): Found a field[5] named: watcher_domain</div><div> 3(3749) DEBUG: db_mongodb [mongodb_dbase.c:396]: db_mongodb_get_columns(): allocate 16 bytes for RES_NAMES[5] at 0x7fee4d90c260</div><div> 3(3749) DEBUG: db_mongodb [mongodb_dbase.c:431]: db_mongodb_get_columns(): use DB1_STRING result type</div><div> 3(3749) DEBUG: db_mongodb [mongodb_dbase.c:460]: db_mongodb_get_columns(): RES_NAMES(0x7fee4d90c260)[5]=[watcher_domain] (2)</div><div> 3(3749) DEBUG: db_mongodb [mongodb_dbase.c:377]: db_mongodb_get_columns(): Found a field[6] named: event_id</div><div> 3(3749) DEBUG: db_mongodb [mongodb_dbase.c:396]: db_mongodb_get_columns(): allocate 16 bytes for RES_NAMES[6] at 0x7fee4d90c340</div><div> 3(3749) INFO: db_mongodb [mongodb_dbase.c:454]: db_mongodb_get_columns(): unhandled data type column (event_id) type id (10), use DB1_STRING as default</div><div> 3(3749) DEBUG: db_mongodb [mongodb_dbase.c:460]: db_mongodb_get_columns(): RES_NAMES(0x7fee4d90c340)[6]=[event_id] (10)</div><div> 3(3749) DEBUG: db_mongodb [mongodb_dbase.c:377]: db_mongodb_get_columns(): Found a field[7] named: from_tag</div><div> 3(3749) ERROR: db_mongodb [mongodb_dbase.c:381]: db_mongodb_get_columns(): field [from_tag] not found in result iterator</div><div> 3(3749) ERROR: db_mongodb [mongodb_dbase.c:739]: db_mongodb_store_result(): failed to set the columns</div><div> 3(3749) ERROR: db_mongodb [mongodb_dbase.c:918]: db_mongodb_query(): failed to store result</div><div> 3(3749) ERROR: db_mongodb [mongodb_dbase.c:927]: db_mongodb_query(): failed to do the query</div><div> 3(3749) DEBUG: <core> [db_res.c:79]: db_free_columns(): freeing 18 columns</div><div> 3(3749) DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[0] at 0x7fee4d90cfd0</div><div> 3(3749) DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[1] at 0x7fee4d90d018</div><div> 3(3749) DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[2] at 0x7fee4d90ccc0</div><div> 3(3749) DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[3] at 0x7fee4d8fba08</div><div> 3(3749) DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[4] at 0x7fee4d90c430</div><div> 3(3749) DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[5] at 0x7fee4d90c260</div><div> 3(3749) DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[6] at 0x7fee4d90c340</div><div> 3(3749) DEBUG: <core> [db_res.c:92]: db_free_columns(): freeing result names at 0x7fee4d8fbe38</div><div> 3(3749) DEBUG: <core> [db_res.c:97]: db_free_columns(): freeing result types at 0x7fee4d90d3c8</div><div> 3(3749) DEBUG: <core> [db_res.c:134]: db_free_result(): freeing result set at 0x7fee4d90cda8</div><div> 3(3749) ERROR: presence [notify.c:1065]: get_subs_db(): while querying database</div><div> 3(3749) ERROR: presence [notify.c:1191]: get_subs_dialog(): getting dialogs from database</div><div> 3(3749) DEBUG: presence [notify.c:1252]: publ_notify(): Could not find subs_dialog</div><div> 3(3749) DEBUG: tm [t_lookup.c:1011]: t_check_msg(): DEBUG: t_check_msg: msg id=5 global id=5 T start=0x7fee3ac83c58</div><div> 3(3749) DEBUG: tm [t_lookup.c:1083]: t_check_msg(): DEBUG: t_check_msg: T already found!</div><div> 3(3749) DEBUG: tm [t_reply.c:1589]: cleanup_uac_timers(): DEBUG: cleanup_uac_timers: RETR/FR timers reset</div><div> 3(3749) DEBUG: <core> [timer.c:574]: timer_add_safe(): timer_add called on an active timer 0x7fee3ac83cd8 (0x7fee3aa24918, 0x7fee3aa24918), flags 201</div><div> 3(3749) DEBUG: tm [t_funcs.c:148]: put_on_wait(): tm: put_on_wait: transaction 0x7fee3ac83c58 already on wait</div><div> 3(3749) DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil)</div><div> 3(3749) DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil)</div><div> 3(3749) DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil)</div><div> 3(3749) DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil)</div><div> 3(3749) DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil)</div><div> 3(3749) DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil)</div><div> 3(3749) DEBUG: <core> [xavp.c:446]: xavp_destroy_list(): destroying xavp list (nil)</div><div> 3(3749) DEBUG: <core> [receive.c:278]: receive_msg(): cleaning up</div><div> 1(3747) DEBUG: <core> [parser/msg_parser.c:606]: parse_msg(): SIP Request:</div><div> 1(3747) DEBUG: <core> [parser/msg_parser.c:608]: parse_msg():  method:  <PUBLISH></div><div> 1(3747) DEBUG: <core> [parser/msg_parser.c:610]: parse_msg():  uri:     <<a href="mailto:sip%3A301@teste.teste.com.pt">sip:301@teste.teste.com.pt</a>></div><div> 1(3747) DEBUG: <core> [parser/msg_parser.c:612]: parse_msg():  version: <SIP/2.0></div><div> 1(3747) DEBUG: <core> [parser/parse_via.c:1254]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK3a88.de19bf4f6bc602f9afbe64d352aaa48f.0>; state=16</div><div> 1(3747) DEBUG: <core> [parser/parse_via.c:2642]: parse_via(): end of header reached, state=5</div><div> 1(3747) DEBUG: <core> [parser/msg_parser.c:496]: parse_headers(): parse_headers: Via found, flags=2</div><div> 1(3747) DEBUG: <core> [parser/msg_parser.c:498]: parse_headers(): parse_headers: this is the first via</div><div> 1(3747) DEBUG: <core> [receive.c:134]: receive_msg(): After parse_msg...</div><div> 1(3747) DEBUG: <core> [receive.c:177]: receive_msg(): preparing to run routing scripts...</div><div> 1(3747) DEBUG: <core> [parser/parse_via.c:1254]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK3a88.b5fae090000000000000000000000000.0>; state=16</div><div> 1(3747) DEBUG: <core> [parser/parse_via.c:2642]: parse_via(): end of header reached, state=5</div><div> 1(3747) DEBUG: <core> [parser/msg_parser.c:496]: parse_headers(): parse_headers: Via found, flags=100</div><div> 1(3747) DEBUG: <core> [parser/msg_parser.c:509]: parse_headers(): parse_headers: this is the second via</div><div> 1(3747) DEBUG: <core> [parser/parse_addr_spec.c:894]: parse_addr_spec(): end of header reached, state=10</div><div> 1(3747) DEBUG: <core> [parser/msg_parser.c:173]: get_hdr_field(): DEBUG: get_hdr_field: <To> [33]; uri=[<a href="mailto:sip%3A301@teste.teste.com.pt">sip:301@teste.teste.com.pt</a>] </div><div> 1(3747) DEBUG: <core> [parser/msg_parser.c:175]: get_hdr_field(): DEBUG: to body [<<a href="mailto:sip%3A301@teste.teste.com.pt">sip:301@teste.teste.com.pt</a>></div><div>]</div><div> 1(3747) DEBUG: <core> [parser/msg_parser.c:153]: get_hdr_field(): get_hdr_field: cseq <CSeq>: <10> <PUBLISH></div><div> 1(3747) DEBUG: <core> [parser/msg_parser.c:187]: get_hdr_field(): DEBUG: get_hdr_body : content_length=741</div><div> 1(3747) DEBUG: maxfwd [mf_funcs.c:85]: is_maxfwd_present(): value = 69 </div><div> 1(3747) DEBUG: tm [t_lookup.c:1312]: t_newtran(): DEBUG: t_newtran: msg id=5 , global msg id=4 , T on entrance=0xffffffffffffffff</div><div> 1(3747) DEBUG: <core> [parser/parse_hname2.c:177]: parse_hname2(): beginning of SIP-If-Match: yet=0x2d706973</div><div> 1(3747) DEBUG: <core> [parser/parse_hname2.c:177]: parse_hname2(): middle of SIP-If-Match: yet=0x6d2d6669</div><div> 1(3747) DEBUG: <core> [parser/parse_hname2.c:177]: parse_hname2(): end of SIP-If-Match</div><div> 1(3747) DEBUG: <core> [parser/msg_parser.c:89]: get_hdr_field(): found end of header</div><div> 1(3747) DEBUG: tm [t_lookup.c:466]: t_lookup_request(): t_lookup_request: start searching: hash=34979, isACK=0</div><div> 1(3747) DEBUG: tm [t_lookup.c:424]: matching_3261(): DEBUG: RFC3261 transaction matching failed</div><div> 1(3747) DEBUG: tm [t_lookup.c:648]: t_lookup_request(): DEBUG: t_lookup_request: no transaction found</div><div> 1(3747) DEBUG: <core> [md5utils.c:67]: MD5StringArray(): MD5 calculated: 9b1f4e306422fb9d9098596b86d0b3e0</div><div> 1(3747) INFO: <script>: Handling publish request -  R=<a href="mailto:sip%3A301@teste.teste.com.pt">sip:301@teste.teste.com.pt</a> ID=<a href="mailto:6869437916cdc139-3695@10.0.20.100">6869437916cdc139-3695@10.0.20.100</a></div><div> 1(3747) DEBUG: presence [event_list.c:348]: search_event(): start event= [dialog/5]</div><div> 1(3747) DEBUG: presence [publish.c:329]: handle_publish(): SIP-If-Match header found</div><div> 1(3747) DEBUG: presence [publish.c:338]: handle_publish(): existing etag  = a.1439906263.3749.5.0 </div><div> 1(3747) DEBUG: presence [publish.c:350]: handle_publish(): Expires header found, value= 241</div><div> 1(3747) DEBUG: presence [presentity.c:87]: generate_ETag(): etag= a.1439906263.3747.5.1 / 21</div><div>  1(3747) DEBUG: db_mongodb [mongodb_dbase.c:851]: db_mongodb_query(): query to collection [presentity]</div><div> 1(3747) DEBUG: db_mongodb [mongodb_dbase.c:885]: db_mongodb_query(): query filter: { "domain" : "<a href="http://teste.teste.com.pt">teste.teste.com.pt</a>", "username" : "301", "event" : "dialog", "etag" : "a.1439906263.3749.5.0" }</div><div> 1(3747) DEBUG: db_mongodb [mongodb_dbase.c:904]: db_mongodb_query(): columns filter: { "body" : 1, "sender" : 1 }</div><div> 1(3747) DEBUG: <core> [db_res.c:116]: db_new_result(): allocate 56 bytes for result set at 0x7fee4d90bd48</div><div> 1(3747) DEBUG: db_mongodb [mongodb_dbase.c:349]: db_mongodb_get_columns(): 2 columns returned from the query</div><div> 1(3747) DEBUG: <core> [db_res.c:154]: db_allocate_columns(): allocate 16 bytes for result names at 0x7fee4d90cc88</div><div> 1(3747) DEBUG: <core> [db_res.c:165]: db_allocate_columns(): allocate 8 bytes for result types at 0x7fee4d8f4270</div><div> 1(3747) DEBUG: db_mongodb [mongodb_dbase.c:377]: db_mongodb_get_columns(): Found a field[0] named: body</div><div> 1(3747) DEBUG: db_mongodb [mongodb_dbase.c:396]: db_mongodb_get_columns(): allocate 16 bytes for RES_NAMES[0] at 0x7fee4d8fbd80</div><div> 1(3747) DEBUG: db_mongodb [mongodb_dbase.c:426]: db_mongodb_get_columns(): use DB1_BLOB result type</div><div> 1(3747) DEBUG: db_mongodb [mongodb_dbase.c:460]: db_mongodb_get_columns(): RES_NAMES(0x7fee4d8fbd80)[0]=[body] (5)</div><div> 1(3747) DEBUG: db_mongodb [mongodb_dbase.c:377]: db_mongodb_get_columns(): Found a field[1] named: sender</div><div> 1(3747) ERROR: db_mongodb [mongodb_dbase.c:381]: db_mongodb_get_columns(): field [sender] not found in result iterator</div><div> 1(3747) ERROR: db_mongodb [mongodb_dbase.c:739]: db_mongodb_store_result(): failed to set the columns</div><div> 1(3747) ERROR: db_mongodb [mongodb_dbase.c:918]: db_mongodb_query(): failed to store result</div><div> 1(3747) ERROR: db_mongodb [mongodb_dbase.c:927]: db_mongodb_query(): failed to do the query</div><div> 1(3747) DEBUG: <core> [db_res.c:79]: db_free_columns(): freeing 2 columns</div><div> 1(3747) DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[0] at 0x7fee4d8fbd80</div><div> 1(3747) DEBUG: <core> [db_res.c:92]: db_free_columns(): freeing result names at 0x7fee4d90cc88</div><div> 1(3747) DEBUG: <core> [db_res.c:97]: db_free_columns(): freeing result types at 0x7fee4d8f4270</div><div> 1(3747) DEBUG: <core> [db_res.c:134]: db_free_result(): freeing result set at 0x7fee4d90bd48</div><div> 1(3747) ERROR: presence [presentity.c:757]: update_presentity(): unsuccessful sql query</div><div> 1(3747) ERROR: presence [publish.c:462]: handle_publish(): when updating presentity</div><div> 1(3747) DEBUG: tm [t_lookup.c:1011]: t_check_msg(): DEBUG: t_check_msg: msg id=5 global id=5 T start=0x7fee3ac80ed0</div><div> 1(3747) DEBUG: tm [t_lookup.c:1083]: t_check_msg(): DEBUG: t_check_msg: T already found!</div><div> 1(3747) DEBUG: <core> [msg_translator.c:158]: check_via_address(): (10.0.20.100, 10.0.20.100, 0)</div><div> 1(3747) DEBUG: <core> [mem/shm_mem.c:101]: _shm_resize(): WARNING:vqm_resize: resize(0) called</div><div> 1(3747) DEBUG: tm [t_reply.c:1589]: cleanup_uac_timers(): DEBUG: cleanup_uac_timers: RETR/FR timers reset</div><div> 1(3747) DEBUG: tm [t_reply.c:647]: _reply_light(): DEBUG: reply sent out. buf=0x7fee4d90d2c0: SIP/2.0 500 Server I..., shmem=0x7fee3ac86738: SIP/2.0 500 Server I</div><div> 1(3747) DEBUG: tm [t_reply.c:657]: _reply_light(): DEBUG: _reply_light: finished</div><div> 1(3747) DEBUG: sl [sl.c:272]: send_reply(): reply in stateful mode (tm)</div><div> 1(3747) ERROR: <script>: Failed to handle publish request - R=<a href="mailto:sip%3A301@teste.teste.com.pt">sip:301@teste.teste.com.pt</a> ID=<a href="mailto:6869437916cdc139-3695@10.0.20.100">6869437916cdc139-3695@10.0.20.100</a></div><div> 1(3747) DEBUG: tm [t_lookup.c:1011]: t_check_msg(): DEBUG: t_check_msg: msg id=5 global id=5 T start=0x7fee3ac80ed0</div><div> 1(3747) DEBUG: tm [t_lookup.c:1083]: t_check_msg(): DEBUG: t_check_msg: T already found!</div><div> 1(3747) DEBUG: tm [t_reply.c:1589]: cleanup_uac_timers(): DEBUG: cleanup_uac_timers: RETR/FR timers reset</div><div> 1(3747) DEBUG: <core> [timer.c:574]: timer_add_safe(): timer_add called on an active timer 0x7fee3ac80f50 (0x7fee3aa24948, 0x7fee3aa24948), flags 201</div><div> 1(3747) DEBUG: tm [t_funcs.c:148]: put_on_wait(): tm: put_on_wait: transaction 0x7fee3ac80ed0 already on wait</div><div> 1(3747) DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil)</div><div> 1(3747) DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil)</div><div> 1(3747) DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil)</div><div> 1(3747) DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil)</div><div> 1(3747) DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil)</div><div> 1(3747) DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil)</div><div> 1(3747) DEBUG: <core> [xavp.c:446]: xavp_destroy_list(): destroying xavp list (nil)</div><div> 1(3747) DEBUG: <core> [receive.c:278]: receive_msg(): cleaning up</div><div> 2(3748) DEBUG: <core> [parser/msg_parser.c:606]: parse_msg(): SIP Request:</div><div> 2(3748) DEBUG: <core> [parser/msg_parser.c:608]: parse_msg():  method:  <PUBLISH></div><div> 2(3748) DEBUG: <core> [parser/msg_parser.c:610]: parse_msg():  uri:     <<a href="mailto:sip%3A302@teste.teste.com.pt">sip:302@teste.teste.com.pt</a>;user=phone></div><div> 2(3748) DEBUG: <core> [parser/msg_parser.c:612]: parse_msg():  version: <SIP/2.0></div><div> 2(3748) DEBUG: <core> [parser/parse_via.c:1254]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK2588.ae99aa97588f074549be2c16f8abf305.0>; state=16</div><div> 2(3748) DEBUG: <core> [parser/parse_via.c:2642]: parse_via(): end of header reached, state=5</div><div> 2(3748) DEBUG: <core> [parser/msg_parser.c:496]: parse_headers(): parse_headers: Via found, flags=2</div><div> 2(3748) DEBUG: <core> [parser/msg_parser.c:498]: parse_headers(): parse_headers: this is the first via</div><div> 2(3748) DEBUG: <core> [receive.c:134]: receive_msg(): After parse_msg...</div><div> 2(3748) DEBUG: <core> [receive.c:177]: receive_msg(): preparing to run routing scripts...</div><div> 2(3748) DEBUG: <core> [parser/parse_via.c:1254]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK2588.8dca50b0000000000000000000000000.0>; state=16</div><div> 2(3748) DEBUG: <core> [parser/parse_via.c:2642]: parse_via(): end of header reached, state=5</div><div> 2(3748) DEBUG: <core> [parser/msg_parser.c:496]: parse_headers(): parse_headers: Via found, flags=100</div><div> 2(3748) DEBUG: <core> [parser/msg_parser.c:509]: parse_headers(): parse_headers: this is the second via</div><div> 2(3748) DEBUG: <core> [parser/parse_addr_spec.c:894]: parse_addr_spec(): end of header reached, state=10</div><div> 2(3748) DEBUG: <core> [parser/msg_parser.c:173]: get_hdr_field(): DEBUG: get_hdr_field: <To> [44]; uri=[<a href="mailto:sip%3A302@teste.teste.com.pt">sip:302@teste.teste.com.pt</a>;user=phone] </div><div> 2(3748) DEBUG: <core> [parser/msg_parser.c:175]: get_hdr_field(): DEBUG: to body [<<a href="mailto:sip%3A302@teste.teste.com.pt">sip:302@teste.teste.com.pt</a>;user=phone></div><div>]</div><div> 2(3748) DEBUG: <core> [parser/msg_parser.c:153]: get_hdr_field(): get_hdr_field: cseq <CSeq>: <10> <PUBLISH></div><div> 2(3748) DEBUG: <core> [parser/msg_parser.c:187]: get_hdr_field(): DEBUG: get_hdr_body : content_length=752</div><div> 2(3748) DEBUG: maxfwd [mf_funcs.c:85]: is_maxfwd_present(): value = 69 </div><div> 2(3748) DEBUG: tm [t_lookup.c:1312]: t_newtran(): DEBUG: t_newtran: msg id=6 , global msg id=5 , T on entrance=0xffffffffffffffff</div><div> 2(3748) DEBUG: <core> [parser/msg_parser.c:89]: get_hdr_field(): found end of header</div><div> 2(3748) DEBUG: tm [t_lookup.c:466]: t_lookup_request(): t_lookup_request: start searching: hash=34898, isACK=0</div><div> 2(3748) DEBUG: tm [t_lookup.c:424]: matching_3261(): DEBUG: RFC3261 transaction matching failed</div><div> 2(3748) DEBUG: tm [t_lookup.c:648]: t_lookup_request(): DEBUG: t_lookup_request: no transaction found</div><div> 2(3748) DEBUG: <core> [md5utils.c:67]: MD5StringArray(): MD5 calculated: 6714bd30c1ad49bd6097d6f162964f6b</div><div> 2(3748) INFO: <script>: Handling publish request -  R=<a href="mailto:sip%3A302@teste.teste.com.pt">sip:302@teste.teste.com.pt</a>;user=phone ID=<a href="mailto:6869437916cdc13a-3695@10.0.20.100">6869437916cdc13a-3695@10.0.20.100</a></div><div> 2(3748) DEBUG: presence [event_list.c:348]: search_event(): start event= [dialog/5]</div><div> 2(3748) DEBUG: presence [publish.c:316]: handle_publish(): SIP-If-Match header not found</div><div> 2(3748) DEBUG: presence [presentity.c:87]: generate_ETag(): etag= a.1439906263.3748.6.0 / 21</div><div>  2(3748) DEBUG: presence [publish.c:325]: handle_publish(): new etag  = a.1439906263.3748.6.0 </div><div> 2(3748) DEBUG: presence [publish.c:350]: handle_publish(): Expires header found, value= 241</div><div> 2(3748) DEBUG: presence [presentity.c:429]: update_presentity(): inserting 9 cols into table</div><div> 2(3748) DEBUG: db_mongodb [mongodb_dbase.c:1030]: db_mongodb_insert(): insert document: { "domain" : "<a href="http://teste.teste.com.pt">teste.teste.com.pt</a>", "username" : "302", "event" : "dialog", "etag" : "a.1439906263.3748.6.0", "sender" : "", "body" : { "$type" : "00", "$binary" : "PD94bWwgdmVyc2lvbj0iMS4wIj8+CjxkaWFsb2ctaW5mbyB4bWxucz0idXJuOmlldGY6cGFyYW1zOnhtbDpuczpkaWFsb2ctaW5mbyIgdmVyc2lvbj0iMCIgc3RhdGU9ImZ1bGwiIGVudGl0eT0ic2lwOjMwMkB0ZXN0ZS5pdGNlbnRlci5jb20ucHQ7dXNlcj1waG9uZSI+CiAgPGRpYWxvZyBpZD0iMzEzNDMzMzkzOTMwMzYzMjM3MzQzNDMyMzAzOTMxLTZudnV4NGlhZmt6ciIgY2FsbC1pZD0iMzEzNDMzMzkzOTMwMzYzMjM3MzQzNDMyMzAzOTMxLTZudnV4NGlhZmt6ciIgbG9jYWwtdGFnPSJ4ZHc3ZjF2dmZ1IiByZW1vdGUtdGFnPSJxbHV6Njhvc2d0IiBkaXJlY3Rpb249InJlY2lwaWVudCI+CiAgICA8c3RhdGU+ZWFybHk8L3N0YXRlPgogICAgPHJlbW90ZT4KICAgICAgPGlkZW50aXR5PnNpcDozMDFAdGVzdGUuaXRjZW50ZXIuY29tLnB0PC9pZGVudGl0eT4KICAgICAgPHRhcmdldCB1cmk9InNpcDozMDFAMTkyLjE2OC4zMC4xMDc6NTA2MDthbGlhcz0xMDAuNjQuMjUwLjI1NH41NjcxMH4xO2xpbmU9OWFqdjU0MzkiLz4KICAgIDwvcmVtb3RlPgogICAgPGxvY2FsPgogICAgICA8aWRlbnRpdHk+c2lwOjMwMkB0ZXN0ZS5pdGNlbnRlci5jb20ucHQ7dXNlcj1waG9uZTwvaWRlbnRpdHk+CiAgICAgIDx0YXJnZXQgdXJpPSJzaXA6MzAyQDE5Mi4xNjguMzAuMTI1OjUwNjA7YWxpYXM9MTAwLjY0LjI1MC4yNTR+NTg0MDV+MTtsaW5lPW8yMDdkZXFtIi8+CiAgICA8L2xvY2FsPgogIDwvZGlhbG9nPgo8L2RpYWxvZy1pbmZvPgo=" }, "received_time" : 1439906398, "priority" : 0, "expires" : 1439906639 }</div><div> 2(3748) DEBUG: presence [presentity.c:104]: publ_send200ok(): send 200OK reply</div><div> 2(3748) DEBUG: presence [presentity.c:105]: publ_send200ok(): etag= a.1439906263.3748.6.0 - len= 21</div><div> 2(3748) DEBUG: tm [t_lookup.c:1011]: t_check_msg(): DEBUG: t_check_msg: msg id=6 global id=6 T start=0x7fee3ac77d88</div><div> 2(3748) DEBUG: tm [t_lookup.c:1083]: t_check_msg(): DEBUG: t_check_msg: T already found!</div><div> 2(3748) DEBUG: <core> [msg_translator.c:158]: check_via_address(): (10.0.20.100, 10.0.20.100, 0)</div><div> 2(3748) DEBUG: <core> [mem/shm_mem.c:101]: _shm_resize(): WARNING:vqm_resize: resize(0) called</div><div> 2(3748) DEBUG: tm [t_reply.c:1589]: cleanup_uac_timers(): DEBUG: cleanup_uac_timers: RETR/FR timers reset</div><div> 2(3748) DEBUG: tm [t_reply.c:647]: _reply_light(): DEBUG: reply sent out. buf=0x7fee4d90d2c0: SIP/2.0 200 OK</div><div>Reco..., shmem=0x7fee3ac7da48: SIP/2.0 200 OK</div><div>Reco</div><div> 2(3748) DEBUG: tm [t_reply.c:657]: _reply_light(): DEBUG: _reply_light: finished</div><div> 2(3748) DEBUG: sl [sl.c:272]: send_reply(): reply in stateful mode (tm)</div><div> 2(3748) DEBUG: presence [notify.c:1007]: get_subs_db(): querying database table = active_watchers</div><div> 2(3748) DEBUG: db_mongodb [mongodb_dbase.c:851]: db_mongodb_query(): query to collection [active_watchers]</div><div> 2(3748) DEBUG: db_mongodb [mongodb_dbase.c:885]: db_mongodb_query(): query filter: { "presentity_uri" : "<a href="mailto:sip%3A302@teste.teste.com.pt">sip:302@teste.teste.com.pt</a>", "event" : "dialog", "status" : 1, "contact" : { "$ne" : "" } }</div><div> 2(3748) DEBUG: db_mongodb [mongodb_dbase.c:904]: db_mongodb_query(): columns filter: { "to_user" : 1, "to_domain" : 1, "from_user" : 1, "from_domain" : 1, "watcher_username" : 1, "watcher_domain" : 1, "event_id" : 1, "from_tag" : 1, "to_tag" : 1, "callid" : 1, "local_cseq" : 1, "record_route" : 1, "contact" : 1, "expires" : 1, "reason" : 1, "socket_info" : 1, "local_contact" : 1, "version" : 1 }</div><div> 2(3748) DEBUG: <core> [db_res.c:116]: db_new_result(): allocate 56 bytes for result set at 0x7fee4d90c5d8</div><div> 2(3748) DEBUG: db_mongodb [mongodb_dbase.c:349]: db_mongodb_get_columns(): 18 columns returned from the query</div><div> 2(3748) DEBUG: <core> [db_res.c:154]: db_allocate_columns(): allocate 144 bytes for result names at 0x7fee4d8fbbe8</div><div> 2(3748) DEBUG: <core> [db_res.c:165]: db_allocate_columns(): allocate 72 bytes for result types at 0x7fee4d90cee0</div><div> 2(3748) DEBUG: db_mongodb [mongodb_dbase.c:377]: db_mongodb_get_columns(): Found a field[0] named: to_user</div><div> 2(3748) DEBUG: db_mongodb [mongodb_dbase.c:396]: db_mongodb_get_columns(): allocate 16 bytes for RES_NAMES[0] at 0x7fee4d90cc88</div><div> 2(3748) DEBUG: db_mongodb [mongodb_dbase.c:431]: db_mongodb_get_columns(): use DB1_STRING result type</div><div> 2(3748) DEBUG: db_mongodb [mongodb_dbase.c:460]: db_mongodb_get_columns(): RES_NAMES(0x7fee4d90cc88)[0]=[to_user] (2)</div><div> 2(3748) DEBUG: db_mongodb [mongodb_dbase.c:377]: db_mongodb_get_columns(): Found a field[1] named: to_domain</div><div> 2(3748) DEBUG: db_mongodb [mongodb_dbase.c:396]: db_mongodb_get_columns(): allocate 16 bytes for RES_NAMES[1] at 0x7fee4d90d048</div><div> 2(3748) DEBUG: db_mongodb [mongodb_dbase.c:431]: db_mongodb_get_columns(): use DB1_STRING result type</div><div> 2(3748) DEBUG: db_mongodb [mongodb_dbase.c:460]: db_mongodb_get_columns(): RES_NAMES(0x7fee4d90d048)[1]=[to_domain] (2)</div><div> 2(3748) DEBUG: db_mongodb [mongodb_dbase.c:377]: db_mongodb_get_columns(): Found a field[2] named: from_user</div><div> 2(3748) DEBUG: db_mongodb [mongodb_dbase.c:396]: db_mongodb_get_columns(): allocate 16 bytes for RES_NAMES[2] at 0x7fee4d8fbdf8</div><div> 2(3748) DEBUG: db_mongodb [mongodb_dbase.c:431]: db_mongodb_get_columns(): use DB1_STRING result type</div><div> 2(3748) DEBUG: db_mongodb [mongodb_dbase.c:460]: db_mongodb_get_columns(): RES_NAMES(0x7fee4d8fbdf8)[2]=[from_user] (2)</div><div> 2(3748) DEBUG: db_mongodb [mongodb_dbase.c:377]: db_mongodb_get_columns(): Found a field[3] named: from_domain</div><div> 2(3748) DEBUG: db_mongodb [mongodb_dbase.c:396]: db_mongodb_get_columns(): allocate 16 bytes for RES_NAMES[3] at 0x7fee4d8fbb70</div><div> 2(3748) DEBUG: db_mongodb [mongodb_dbase.c:431]: db_mongodb_get_columns(): use DB1_STRING result type</div><div> 2(3748) DEBUG: db_mongodb [mongodb_dbase.c:460]: db_mongodb_get_columns(): RES_NAMES(0x7fee4d8fbb70)[3]=[from_domain] (2)</div><div> 2(3748) DEBUG: db_mongodb [mongodb_dbase.c:377]: db_mongodb_get_columns(): Found a field[4] named: watcher_username</div><div> 2(3748) DEBUG: db_mongodb [mongodb_dbase.c:396]: db_mongodb_get_columns(): allocate 16 bytes for RES_NAMES[4] at 0x7fee4d90d0f8</div><div> 2(3748) DEBUG: db_mongodb [mongodb_dbase.c:431]: db_mongodb_get_columns(): use DB1_STRING result type</div><div> 2(3748) DEBUG: db_mongodb [mongodb_dbase.c:460]: db_mongodb_get_columns(): RES_NAMES(0x7fee4d90d0f8)[4]=[watcher_username] (2)</div><div> 2(3748) DEBUG: db_mongodb [mongodb_dbase.c:377]: db_mongodb_get_columns(): Found a field[5] named: watcher_domain</div><div> 2(3748) DEBUG: db_mongodb [mongodb_dbase.c:396]: db_mongodb_get_columns(): allocate 16 bytes for RES_NAMES[5] at 0x7fee4d90bdc0</div><div> 2(3748) DEBUG: db_mongodb [mongodb_dbase.c:431]: db_mongodb_get_columns(): use DB1_STRING result type</div><div> 2(3748) DEBUG: db_mongodb [mongodb_dbase.c:460]: db_mongodb_get_columns(): RES_NAMES(0x7fee4d90bdc0)[5]=[watcher_domain] (2)</div><div> 2(3748) DEBUG: db_mongodb [mongodb_dbase.c:377]: db_mongodb_get_columns(): Found a field[6] named: event_id</div><div> 2(3748) DEBUG: db_mongodb [mongodb_dbase.c:396]: db_mongodb_get_columns(): allocate 16 bytes for RES_NAMES[6] at 0x7fee4d90bd48</div><div> 2(3748) INFO: db_mongodb [mongodb_dbase.c:454]: db_mongodb_get_columns(): unhandled data type column (event_id) type id (10), use DB1_STRING as default</div><div> 2(3748) DEBUG: db_mongodb [mongodb_dbase.c:460]: db_mongodb_get_columns(): RES_NAMES(0x7fee4d90bd48)[6]=[event_id] (10)</div><div> 2(3748) DEBUG: db_mongodb [mongodb_dbase.c:377]: db_mongodb_get_columns(): Found a field[7] named: from_tag</div><div> 2(3748) ERROR: db_mongodb [mongodb_dbase.c:381]: db_mongodb_get_columns(): field [from_tag] not found in result iterator</div><div> 2(3748) ERROR: db_mongodb [mongodb_dbase.c:739]: db_mongodb_store_result(): failed to set the columns</div><div> 2(3748) ERROR: db_mongodb [mongodb_dbase.c:918]: db_mongodb_query(): failed to store result</div><div> 2(3748) ERROR: db_mongodb [mongodb_dbase.c:927]: db_mongodb_query(): failed to do the query</div><div> 2(3748) DEBUG: <core> [db_res.c:79]: db_free_columns(): freeing 18 columns</div><div> 2(3748) DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[0] at 0x7fee4d90cc88</div><div> 2(3748) DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[1] at 0x7fee4d90d048</div><div> 2(3748) DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[2] at 0x7fee4d8fbdf8</div><div> 2(3748) DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[3] at 0x7fee4d8fbb70</div><div> 2(3748) DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[4] at 0x7fee4d90d0f8</div><div> 2(3748) DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[5] at 0x7fee4d90bdc0</div><div> 2(3748) DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[6] at 0x7fee4d90bd48</div><div> 2(3748) DEBUG: <core> [db_res.c:92]: db_free_columns(): freeing result names at 0x7fee4d8fbbe8</div><div> 2(3748) DEBUG: <core> [db_res.c:97]: db_free_columns(): freeing result types at 0x7fee4d90cee0</div><div> 2(3748) DEBUG: <core> [db_res.c:134]: db_free_result(): freeing result set at 0x7fee4d90c5d8</div><div> 2(3748) ERROR: presence [notify.c:1065]: get_subs_db(): while querying database</div><div> 2(3748) ERROR: presence [notify.c:1191]: get_subs_dialog(): getting dialogs from database</div><div> 2(3748) DEBUG: presence [notify.c:1252]: publ_notify(): Could not find subs_dialog</div><div> 2(3748) DEBUG: tm [t_lookup.c:1011]: t_check_msg(): DEBUG: t_check_msg: msg id=6 global id=6 T start=0x7fee3ac77d88</div><div> 2(3748) DEBUG: tm [t_lookup.c:1083]: t_check_msg(): DEBUG: t_check_msg: T already found!</div><div> 2(3748) DEBUG: tm [t_reply.c:1589]: cleanup_uac_timers(): DEBUG: cleanup_uac_timers: RETR/FR timers reset</div><div> 2(3748) DEBUG: <core> [timer.c:574]: timer_add_safe(): timer_add called on an active timer 0x7fee3ac77e08 (0x7fee3aa24948, 0x7fee3ac80f50), flags 201</div><div> 2(3748) DEBUG: tm [t_funcs.c:148]: put_on_wait(): tm: put_on_wait: transaction 0x7fee3ac77d88 already on wait</div><div> 2(3748) DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil)</div><div> 2(3748) DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil)</div><div> 2(3748) DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil)</div><div> 2(3748) DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil)</div><div> 2(3748) DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil)</div><div> 2(3748) DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil)</div><div> 2(3748) DEBUG: <core> [xavp.c:446]: xavp_destroy_list(): destroying xavp list (nil)</div><div> 2(3748) DEBUG: <core> [receive.c:278]: receive_msg(): cleaning up</div><div> 4(3750) DEBUG: <core> [parser/msg_parser.c:606]: parse_msg(): SIP Request:</div><div> 4(3750) DEBUG: <core> [parser/msg_parser.c:608]: parse_msg():  method:  <PUBLISH></div><div> 4(3750) DEBUG: <core> [parser/msg_parser.c:610]: parse_msg():  uri:     <<a href="mailto:sip%3A301@teste.teste.com.pt">sip:301@teste.teste.com.pt</a>></div><div> 4(3750) DEBUG: <core> [parser/msg_parser.c:612]: parse_msg():  version: <SIP/2.0></div><div> 4(3750) DEBUG: <core> [parser/parse_via.c:1254]: parse_via_param(): Found param type 232, <branch> = <z9hG4bKe6c5.0f136ca6be0f5c28b3a23e84bd6bb28b.0>; state=16</div><div> 4(3750) DEBUG: <core> [parser/parse_via.c:2642]: parse_via(): end of header reached, state=5</div><div> 4(3750) DEBUG: <core> [parser/msg_parser.c:496]: parse_headers(): parse_headers: Via found, flags=2</div><div> 4(3750) DEBUG: <core> [parser/msg_parser.c:498]: parse_headers(): parse_headers: this is the first via</div><div> 4(3750) DEBUG: <core> [receive.c:134]: receive_msg(): After parse_msg...</div><div> 4(3750) DEBUG: <core> [receive.c:177]: receive_msg(): preparing to run routing scripts...</div><div> 4(3750) DEBUG: <core> [parser/parse_via.c:1254]: parse_via_param(): Found param type 232, <branch> = <z9hG4bKe6c5.cdc87860000000000000000000000000.0>; state=16</div><div> 4(3750) DEBUG: <core> [parser/parse_via.c:2642]: parse_via(): end of header reached, state=5</div><div> 4(3750) DEBUG: <core> [parser/msg_parser.c:496]: parse_headers(): parse_headers: Via found, flags=100</div><div> 4(3750) DEBUG: <core> [parser/msg_parser.c:509]: parse_headers(): parse_headers: this is the second via</div><div> 4(3750) DEBUG: <core> [parser/parse_addr_spec.c:894]: parse_addr_spec(): end of header reached, state=10</div><div> 4(3750) DEBUG: <core> [parser/msg_parser.c:173]: get_hdr_field(): DEBUG: get_hdr_field: <To> [33]; uri=[<a href="mailto:sip%3A301@teste.teste.com.pt">sip:301@teste.teste.com.pt</a>] </div><div> 4(3750) DEBUG: <core> [parser/msg_parser.c:175]: get_hdr_field(): DEBUG: to body [<<a href="mailto:sip%3A301@teste.teste.com.pt">sip:301@teste.teste.com.pt</a>></div><div>]</div><div> 4(3750) DEBUG: <core> [parser/msg_parser.c:153]: get_hdr_field(): get_hdr_field: cseq <CSeq>: <10> <PUBLISH></div><div> 4(3750) DEBUG: <core> [parser/msg_parser.c:187]: get_hdr_field(): DEBUG: get_hdr_body : content_length=669</div><div> 4(3750) DEBUG: maxfwd [mf_funcs.c:85]: is_maxfwd_present(): value = 69 </div><div> 4(3750) DEBUG: tm [t_lookup.c:1312]: t_newtran(): DEBUG: t_newtran: msg id=6 , global msg id=5 , T on entrance=0xffffffffffffffff</div><div> 4(3750) DEBUG: <core> [parser/msg_parser.c:89]: get_hdr_field(): found end of header</div><div> 4(3750) DEBUG: tm [t_lookup.c:466]: t_lookup_request(): t_lookup_request: start searching: hash=23662, isACK=0</div><div> 4(3750) DEBUG: tm [t_lookup.c:424]: matching_3261(): DEBUG: RFC3261 transaction matching failed</div><div> 4(3750) DEBUG: tm [t_lookup.c:648]: t_lookup_request(): DEBUG: t_lookup_request: no transaction found</div><div> 4(3750) DEBUG: <core> [md5utils.c:67]: MD5StringArray(): MD5 calculated: c18f689913606b0287299bd41281c5e5</div><div> 4(3750) INFO: <script>: Handling publish request -  R=<a href="mailto:sip%3A301@teste.teste.com.pt">sip:301@teste.teste.com.pt</a> ID=<a href="mailto:6869437916cdc134-3714@10.0.20.100">6869437916cdc134-3714@10.0.20.100</a></div><div> 4(3750) DEBUG: presence [event_list.c:348]: search_event(): start event= [dialog/5]</div><div> 4(3750) DEBUG: presence [publish.c:316]: handle_publish(): SIP-If-Match header not found</div><div> 4(3750) DEBUG: presence [presentity.c:87]: generate_ETag(): etag= a.1439906263.3750.6.0 / 21</div><div>  4(3750) DEBUG: presence [publish.c:325]: handle_publish(): new etag  = a.1439906263.3750.6.0 </div><div> 4(3750) DEBUG: presence [publish.c:350]: handle_publish(): Expires header found, value= 11</div><div> 4(3750) DEBUG: presence [presentity.c:429]: update_presentity(): inserting 9 cols into table</div><div> 4(3750) DEBUG: db_mongodb [mongodb_dbase.c:1030]: db_mongodb_insert(): insert document: { "domain" : "<a href="http://teste.teste.com.pt">teste.teste.com.pt</a>", "username" : "301", "event" : "dialog", "etag" : "a.1439906263.3750.6.0", "sender" : "", "body" : { "$type" : "00", "$binary" : "PD94bWwgdmVyc2lvbj0iMS4wIj8+CjxkaWFsb2ctaW5mbyB4bWxucz0idXJuOmlldGY6cGFyYW1zOnhtbDpuczpkaWFsb2ctaW5mbyIgdmVyc2lvbj0iMCIgc3RhdGU9ImZ1bGwiIGVudGl0eT0ic2lwOjMwMUB0ZXN0ZS5pdGNlbnRlci5jb20ucHQiPgogIDxkaWFsb2cgaWQ9IjMxMzQzMzM5MzkzMDM2MzIzNzM0MzQzMjMwMzkzMS02bnZ1eDRpYWZrenIiIGNhbGwtaWQ9IjMxMzQzMzM5MzkzMDM2MzIzNzM0MzQzMjMwMzkzMS02bnZ1eDRpYWZrenIiIGRpcmVjdGlvbj0iaW5pdGlhdG9yIj4KICAgIDxzdGF0ZT50ZXJtaW5hdGVkPC9zdGF0ZT4KICAgIDxyZW1vdGU+CiAgICAgIDxpZGVudGl0eT5zaXA6MzAyQHRlc3RlLml0Y2VudGVyLmNvbS5wdDt1c2VyPXBob25lPC9pZGVudGl0eT4KICAgICAgPHRhcmdldCB1cmk9InNpcDozMDJAdGVzdGUuaXRjZW50ZXIuY29tLnB0O3VzZXI9cGhvbmUiLz4KICAgIDwvcmVtb3RlPgogICAgPGxvY2FsPgogICAgICA8aWRlbnRpdHk+c2lwOjMwMUB0ZXN0ZS5pdGNlbnRlci5jb20ucHQ8L2lkZW50aXR5PgogICAgICA8dGFyZ2V0IHVyaT0ic2lwOjMwMUAxOTIuMTY4LjMwLjEwNzo1MDYwO2FsaWFzPTEwMC42NC4yNTAuMjU0fjU2NzEwfjE7bGluZT05YWp2NTQzOSIvPgogICAgPC9sb2NhbD4KICA8L2RpYWxvZz4KPC9kaWFsb2ctaW5mbz4K" }, "received_time" : 1439906400, "priority" : 0, "expires" : 1439906411 }</div><div> 4(3750) DEBUG: presence [presentity.c:104]: publ_send200ok(): send 200OK reply</div><div> 4(3750) DEBUG: presence [presentity.c:105]: publ_send200ok(): etag= a.1439906263.3750.6.0 - len= 21</div><div> 4(3750) DEBUG: tm [t_lookup.c:1011]: t_check_msg(): DEBUG: t_check_msg: msg id=6 global id=6 T start=0x7fee3ac7de60</div><div> 4(3750) DEBUG: tm [t_lookup.c:1083]: t_check_msg(): DEBUG: t_check_msg: T already found!</div><div> 4(3750) DEBUG: <core> [msg_translator.c:158]: check_via_address(): (10.0.20.100, 10.0.20.100, 0)</div><div> 4(3750) DEBUG: <core> [mem/shm_mem.c:101]: _shm_resize(): WARNING:vqm_resize: resize(0) called</div><div> 4(3750) DEBUG: tm [t_reply.c:1589]: cleanup_uac_timers(): DEBUG: cleanup_uac_timers: RETR/FR timers reset</div><div> 4(3750) DEBUG: tm [t_reply.c:647]: _reply_light(): DEBUG: reply sent out. buf=0x7fee4d90c7f0: SIP/2.0 200 OK</div><div>Reco..., shmem=0x7fee3ac7a9d8: SIP/2.0 200 OK</div><div>Reco</div><div> 4(3750) DEBUG: tm [t_reply.c:657]: _reply_light(): DEBUG: _reply_light: finished</div><div> 4(3750) DEBUG: sl [sl.c:272]: send_reply(): reply in stateful mode (tm)</div><div> 4(3750) DEBUG: presence [notify.c:1007]: get_subs_db(): querying database table = active_watchers</div><div> 4(3750) DEBUG: db_mongodb [mongodb_dbase.c:851]: db_mongodb_query(): query to collection [active_watchers]</div><div> 4(3750) DEBUG: db_mongodb [mongodb_dbase.c:885]: db_mongodb_query(): query filter: { "presentity_uri" : "<a href="mailto:sip%3A301@teste.teste.com.pt">sip:301@teste.teste.com.pt</a>", "event" : "dialog", "status" : 1, "contact" : { "$ne" : "" } }</div><div> 4(3750) DEBUG: db_mongodb [mongodb_dbase.c:904]: db_mongodb_query(): columns filter: { "to_user" : 1, "to_domain" : 1, "from_user" : 1, "from_domain" : 1, "watcher_username" : 1, "watcher_domain" : 1, "event_id" : 1, "from_tag" : 1, "to_tag" : 1, "callid" : 1, "local_cseq" : 1, "record_route" : 1, "contact" : 1, "expires" : 1, "reason" : 1, "socket_info" : 1, "local_contact" : 1, "version" : 1 }</div><div> 4(3750) DEBUG: <core> [db_res.c:116]: db_new_result(): allocate 56 bytes for result set at 0x7fee4d90cda8</div><div> 4(3750) DEBUG: db_mongodb [mongodb_dbase.c:349]: db_mongodb_get_columns(): 18 columns returned from the query</div><div> 4(3750) DEBUG: <core> [db_res.c:154]: db_allocate_columns(): allocate 144 bytes for result names at 0x7fee4d8fbe38</div><div> 4(3750) DEBUG: <core> [db_res.c:165]: db_allocate_columns(): allocate 72 bytes for result types at 0x7fee4d90cd08</div><div> 4(3750) DEBUG: db_mongodb [mongodb_dbase.c:377]: db_mongodb_get_columns(): Found a field[0] named: to_user</div><div> 4(3750) DEBUG: db_mongodb [mongodb_dbase.c:396]: db_mongodb_get_columns(): allocate 16 bytes for RES_NAMES[0] at 0x7fee4d90cfd0</div><div> 4(3750) DEBUG: db_mongodb [mongodb_dbase.c:431]: db_mongodb_get_columns(): use DB1_STRING result type</div><div> 4(3750) DEBUG: db_mongodb [mongodb_dbase.c:460]: db_mongodb_get_columns(): RES_NAMES(0x7fee4d90cfd0)[0]=[to_user] (2)</div><div> 4(3750) DEBUG: db_mongodb [mongodb_dbase.c:377]: db_mongodb_get_columns(): Found a field[1] named: to_domain</div><div> 4(3750) DEBUG: db_mongodb [mongodb_dbase.c:396]: db_mongodb_get_columns(): allocate 16 bytes for RES_NAMES[1] at 0x7fee4d90d018</div><div> 4(3750) DEBUG: db_mongodb [mongodb_dbase.c:431]: db_mongodb_get_columns(): use DB1_STRING result type</div><div> 4(3750) DEBUG: db_mongodb [mongodb_dbase.c:460]: db_mongodb_get_columns(): RES_NAMES(0x7fee4d90d018)[1]=[to_domain] (2)</div><div> 4(3750) DEBUG: db_mongodb [mongodb_dbase.c:377]: db_mongodb_get_columns(): Found a field[2] named: from_user</div><div> 4(3750) DEBUG: db_mongodb [mongodb_dbase.c:396]: db_mongodb_get_columns(): allocate 16 bytes for RES_NAMES[2] at 0x7fee4d90ccc0</div><div> 4(3750) DEBUG: db_mongodb [mongodb_dbase.c:431]: db_mongodb_get_columns(): use DB1_STRING result type</div><div> 4(3750) DEBUG: db_mongodb [mongodb_dbase.c:460]: db_mongodb_get_columns(): RES_NAMES(0x7fee4d90ccc0)[2]=[from_user] (2)</div><div> 4(3750) DEBUG: db_mongodb [mongodb_dbase.c:377]: db_mongodb_get_columns(): Found a field[3] named: from_domain</div><div> 4(3750) DEBUG: db_mongodb [mongodb_dbase.c:396]: db_mongodb_get_columns(): allocate 16 bytes for RES_NAMES[3] at 0x7fee4d90ce18</div><div> 4(3750) DEBUG: db_mongodb [mongodb_dbase.c:431]: db_mongodb_get_columns(): use DB1_STRING result type</div><div> 4(3750) DEBUG: db_mongodb [mongodb_dbase.c:460]: db_mongodb_get_columns(): RES_NAMES(0x7fee4d90ce18)[3]=[from_domain] (2)</div><div> 4(3750) DEBUG: db_mongodb [mongodb_dbase.c:377]: db_mongodb_get_columns(): Found a field[4] named: watcher_username</div><div> 4(3750) DEBUG: db_mongodb [mongodb_dbase.c:396]: db_mongodb_get_columns(): allocate 16 bytes for RES_NAMES[4] at 0x7fee4d90bb80</div><div> 4(3750) DEBUG: db_mongodb [mongodb_dbase.c:431]: db_mongodb_get_columns(): use DB1_STRING result type</div><div> 4(3750) DEBUG: db_mongodb [mongodb_dbase.c:460]: db_mongodb_get_columns(): RES_NAMES(0x7fee4d90bb80)[4]=[watcher_username] (2)</div><div> 4(3750) DEBUG: db_mongodb [mongodb_dbase.c:377]: db_mongodb_get_columns(): Found a field[5] named: watcher_domain</div><div> 4(3750) DEBUG: db_mongodb [mongodb_dbase.c:396]: db_mongodb_get_columns(): allocate 16 bytes for RES_NAMES[5] at 0x7fee4d90bd90</div><div> 4(3750) DEBUG: db_mongodb [mongodb_dbase.c:431]: db_mongodb_get_columns(): use DB1_STRING result type</div><div> 4(3750) DEBUG: db_mongodb [mongodb_dbase.c:460]: db_mongodb_get_columns(): RES_NAMES(0x7fee4d90bd90)[5]=[watcher_domain] (2)</div><div> 4(3750) DEBUG: db_mongodb [mongodb_dbase.c:377]: db_mongodb_get_columns(): Found a field[6] named: event_id</div><div> 4(3750) DEBUG: db_mongodb [mongodb_dbase.c:396]: db_mongodb_get_columns(): allocate 16 bytes for RES_NAMES[6] at 0x7fee4d90be08</div><div> 4(3750) INFO: db_mongodb [mongodb_dbase.c:454]: db_mongodb_get_columns(): unhandled data type column (event_id) type id (10), use DB1_STRING as default</div><div> 4(3750) DEBUG: db_mongodb [mongodb_dbase.c:460]: db_mongodb_get_columns(): RES_NAMES(0x7fee4d90be08)[6]=[event_id] (10)</div><div> 4(3750) DEBUG: db_mongodb [mongodb_dbase.c:377]: db_mongodb_get_columns(): Found a field[7] named: from_tag</div><div> 4(3750) ERROR: db_mongodb [mongodb_dbase.c:381]: db_mongodb_get_columns(): field [from_tag] not found in result iterator</div><div> 4(3750) ERROR: db_mongodb [mongodb_dbase.c:739]: db_mongodb_store_result(): failed to set the columns</div><div> 4(3750) ERROR: db_mongodb [mongodb_dbase.c:918]: db_mongodb_query(): failed to store result</div><div> 4(3750) ERROR: db_mongodb [mongodb_dbase.c:927]: db_mongodb_query(): failed to do the query</div><div> 4(3750) DEBUG: <core> [db_res.c:79]: db_free_columns(): freeing 18 columns</div><div> 4(3750) DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[0] at 0x7fee4d90cfd0</div><div> 4(3750) DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[1] at 0x7fee4d90d018</div><div> 4(3750) DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[2] at 0x7fee4d90ccc0</div><div> 4(3750) DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[3] at 0x7fee4d90ce18</div><div> 4(3750) DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[4] at 0x7fee4d90bb80</div><div> 4(3750) DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[5] at 0x7fee4d90bd90</div><div> 4(3750) DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[6] at 0x7fee4d90be08</div><div> 4(3750) DEBUG: <core> [db_res.c:92]: db_free_columns(): freeing result names at 0x7fee4d8fbe38</div><div> 4(3750) DEBUG: <core> [db_res.c:97]: db_free_columns(): freeing result types at 0x7fee4d90cd08</div><div> 4(3750) DEBUG: <core> [db_res.c:134]: db_free_result(): freeing result set at 0x7fee4d90cda8</div><div> 4(3750) ERROR: presence [notify.c:1065]: get_subs_db(): while querying database</div><div> 4(3750) ERROR: presence [notify.c:1191]: get_subs_dialog(): getting dialogs from database</div><div> 4(3750) DEBUG: presence [notify.c:1252]: publ_notify(): Could not find subs_dialog</div><div> 4(3750) DEBUG: tm [t_lookup.c:1011]: t_check_msg(): DEBUG: t_check_msg: msg id=6 global id=6 T start=0x7fee3ac7de60</div><div> 4(3750) DEBUG: tm [t_lookup.c:1083]: t_check_msg(): DEBUG: t_check_msg: T already found!</div><div> 4(3750) DEBUG: tm [t_reply.c:1589]: cleanup_uac_timers(): DEBUG: cleanup_uac_timers: RETR/FR timers reset</div><div> 4(3750) DEBUG: <core> [timer.c:574]: timer_add_safe(): timer_add called on an active timer 0x7fee3ac7dee0 (0x7fee3aa24bb8, 0x7fee3aa24bb8), flags 201</div><div> 4(3750) DEBUG: tm [t_funcs.c:148]: put_on_wait(): tm: put_on_wait: transaction 0x7fee3ac7de60 already on wait</div><div> 4(3750) DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil)</div><div> 4(3750) DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil)</div><div> 4(3750) DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil)</div><div> 4(3750) DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil)</div><div> 4(3750) DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil)</div><div> 4(3750) DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil)</div><div> 4(3750) DEBUG: <core> [xavp.c:446]: xavp_destroy_list(): destroying xavp list (nil)</div><div> 4(3750) DEBUG: <core> [receive.c:278]: receive_msg(): cleaning up</div><div> 3(3749) DEBUG: <core> [parser/msg_parser.c:606]: parse_msg(): SIP Request:</div><div> 3(3749) DEBUG: <core> [parser/msg_parser.c:608]: parse_msg():  method:  <PUBLISH></div><div> 3(3749) DEBUG: <core> [parser/msg_parser.c:610]: parse_msg():  uri:     <<a href="mailto:sip%3A302@teste.teste.com.pt">sip:302@teste.teste.com.pt</a>;user=phone></div><div> 3(3749) DEBUG: <core> [parser/msg_parser.c:612]: parse_msg():  version: <SIP/2.0></div><div> 3(3749) DEBUG: <core> [parser/parse_via.c:1254]: parse_via_param(): Found param type 232, <branch> = <z9hG4bKf6c5.0bdcb68b39d9eb5935258276fd47d068.0>; state=16</div><div> 3(3749) DEBUG: <core> [parser/parse_via.c:2642]: parse_via(): end of header reached, state=5</div><div> 3(3749) DEBUG: <core> [parser/msg_parser.c:496]: parse_headers(): parse_headers: Via found, flags=2</div><div> 3(3749) DEBUG: <core> [parser/msg_parser.c:498]: parse_headers(): parse_headers: this is the first via</div><div> 3(3749) DEBUG: <core> [receive.c:134]: receive_msg(): After parse_msg...</div><div> 3(3749) DEBUG: <core> [receive.c:177]: receive_msg(): preparing to run routing scripts...</div><div> 3(3749) DEBUG: <core> [parser/parse_via.c:1254]: parse_via_param(): Found param type 232, <branch> = <z9hG4bKf6c5.26f01f40000000000000000000000000.0>; state=16</div><div> 3(3749) DEBUG: <core> [parser/parse_via.c:2642]: parse_via(): end of header reached, state=5</div><div> 3(3749) DEBUG: <core> [parser/msg_parser.c:496]: parse_headers(): parse_headers: Via found, flags=100</div><div> 3(3749) DEBUG: <core> [parser/msg_parser.c:509]: parse_headers(): parse_headers: this is the second via</div><div> 3(3749) DEBUG: <core> [parser/parse_addr_spec.c:894]: parse_addr_spec(): end of header reached, state=10</div><div> 3(3749) DEBUG: <core> [parser/msg_parser.c:173]: get_hdr_field(): DEBUG: get_hdr_field: <To> [44]; uri=[<a href="mailto:sip%3A302@teste.teste.com.pt">sip:302@teste.teste.com.pt</a>;user=phone] </div><div> 3(3749) DEBUG: <core> [parser/msg_parser.c:175]: get_hdr_field(): DEBUG: to body [<<a href="mailto:sip%3A302@teste.teste.com.pt">sip:302@teste.teste.com.pt</a>;user=phone></div><div>]</div><div> 3(3749) DEBUG: <core> [parser/msg_parser.c:153]: get_hdr_field(): get_hdr_field: cseq <CSeq>: <10> <PUBLISH></div><div> 3(3749) DEBUG: <core> [parser/msg_parser.c:187]: get_hdr_field(): DEBUG: get_hdr_body : content_length=680</div><div> 3(3749) DEBUG: maxfwd [mf_funcs.c:85]: is_maxfwd_present(): value = 69 </div><div> 3(3749) DEBUG: tm [t_lookup.c:1312]: t_newtran(): DEBUG: t_newtran: msg id=6 , global msg id=5 , T on entrance=0xffffffffffffffff</div><div> 3(3749) DEBUG: <core> [parser/parse_hname2.c:177]: parse_hname2(): beginning of SIP-If-Match: yet=0x2d706973</div><div> 3(3749) DEBUG: <core> [parser/parse_hname2.c:177]: parse_hname2(): middle of SIP-If-Match: yet=0x6d2d6669</div><div> 3(3749) DEBUG: <core> [parser/parse_hname2.c:177]: parse_hname2(): end of SIP-If-Match</div><div> 3(3749) DEBUG: <core> [parser/msg_parser.c:89]: get_hdr_field(): found end of header</div><div> 3(3749) DEBUG: tm [t_lookup.c:466]: t_lookup_request(): t_lookup_request: start searching: hash=23663, isACK=0</div><div> 3(3749) DEBUG: tm [t_lookup.c:424]: matching_3261(): DEBUG: RFC3261 transaction matching failed</div><div> 3(3749) DEBUG: tm [t_lookup.c:648]: t_lookup_request(): DEBUG: t_lookup_request: no transaction found</div><div> 3(3749) DEBUG: <core> [md5utils.c:67]: MD5StringArray(): MD5 calculated: 5cfad5206cd64562ba87bb365d5c370a</div><div> 3(3749) INFO: <script>: Handling publish request -  R=<a href="mailto:sip%3A302@teste.teste.com.pt">sip:302@teste.teste.com.pt</a>;user=phone ID=<a href="mailto:6869437916cdc135-3714@10.0.20.100">6869437916cdc135-3714@10.0.20.100</a></div><div> 3(3749) DEBUG: presence [event_list.c:348]: search_event(): start event= [dialog/5]</div><div> 3(3749) DEBUG: presence [publish.c:329]: handle_publish(): SIP-If-Match header found</div><div> 3(3749) DEBUG: presence [publish.c:338]: handle_publish(): existing etag  = a.1439906263.3748.6.0 </div><div> 3(3749) DEBUG: presence [publish.c:350]: handle_publish(): Expires header found, value= 11</div><div> 3(3749) DEBUG: presence [presentity.c:87]: generate_ETag(): etag= a.1439906263.3749.6.1 / 21</div><div>  3(3749) DEBUG: db_mongodb [mongodb_dbase.c:851]: db_mongodb_query(): query to collection [presentity]</div><div> 3(3749) DEBUG: db_mongodb [mongodb_dbase.c:885]: db_mongodb_query(): query filter: { "domain" : "<a href="http://teste.teste.com.pt">teste.teste.com.pt</a>", "username" : "302", "event" : "dialog", "etag" : "a.1439906263.3748.6.0" }</div><div> 3(3749) DEBUG: db_mongodb [mongodb_dbase.c:904]: db_mongodb_query(): columns filter: { "body" : 1, "sender" : 1 }</div><div> 3(3749) DEBUG: <core> [db_res.c:116]: db_new_result(): allocate 56 bytes for result set at 0x7fee4d90cda8</div><div> 3(3749) DEBUG: db_mongodb [mongodb_dbase.c:349]: db_mongodb_get_columns(): 2 columns returned from the query</div><div> 3(3749) DEBUG: <core> [db_res.c:154]: db_allocate_columns(): allocate 16 bytes for result names at 0x7fee4d90ccc0</div><div> 3(3749) DEBUG: <core> [db_res.c:165]: db_allocate_columns(): allocate 8 bytes for result types at 0x7fee4d8f4270</div><div> 3(3749) DEBUG: db_mongodb [mongodb_dbase.c:377]: db_mongodb_get_columns(): Found a field[0] named: body</div><div> 3(3749) DEBUG: db_mongodb [mongodb_dbase.c:396]: db_mongodb_get_columns(): allocate 16 bytes for RES_NAMES[0] at 0x7fee4d90d018</div><div> 3(3749) DEBUG: db_mongodb [mongodb_dbase.c:426]: db_mongodb_get_columns(): use DB1_BLOB result type</div><div> 3(3749) DEBUG: db_mongodb [mongodb_dbase.c:460]: db_mongodb_get_columns(): RES_NAMES(0x7fee4d90d018)[0]=[body] (5)</div><div> 3(3749) DEBUG: db_mongodb [mongodb_dbase.c:377]: db_mongodb_get_columns(): Found a field[1] named: sender</div><div> 3(3749) ERROR: db_mongodb [mongodb_dbase.c:381]: db_mongodb_get_columns(): field [sender] not found in result iterator</div><div> 3(3749) ERROR: db_mongodb [mongodb_dbase.c:739]: db_mongodb_store_result(): failed to set the columns</div><div> 3(3749) ERROR: db_mongodb [mongodb_dbase.c:918]: db_mongodb_query(): failed to store result</div><div> 3(3749) ERROR: db_mongodb [mongodb_dbase.c:927]: db_mongodb_query(): failed to do the query</div><div> 3(3749) DEBUG: <core> [db_res.c:79]: db_free_columns(): freeing 2 columns</div><div> 3(3749) DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[0] at 0x7fee4d90d018</div><div> 3(3749) DEBUG: <core> [db_res.c:92]: db_free_columns(): freeing result names at 0x7fee4d90ccc0</div><div> 3(3749) DEBUG: <core> [db_res.c:97]: db_free_columns(): freeing result types at 0x7fee4d8f4270</div><div> 3(3749) DEBUG: <core> [db_res.c:134]: db_free_result(): freeing result set at 0x7fee4d90cda8</div><div> 3(3749) ERROR: presence [presentity.c:757]: update_presentity(): unsuccessful sql query</div><div> 3(3749) ERROR: presence [publish.c:462]: handle_publish(): when updating presentity</div><div> 3(3749) DEBUG: tm [t_lookup.c:1011]: t_check_msg(): DEBUG: t_check_msg: msg id=6 global id=6 T start=0x7fee3ac7adf8</div><div> 3(3749) DEBUG: tm [t_lookup.c:1083]: t_check_msg(): DEBUG: t_check_msg: T already found!</div><div> 3(3749) DEBUG: <core> [msg_translator.c:158]: check_via_address(): (10.0.20.100, 10.0.20.100, 0)</div><div> 3(3749) DEBUG: <core> [mem/shm_mem.c:101]: _shm_resize(): WARNING:vqm_resize: resize(0) called</div><div> 3(3749) DEBUG: tm [t_reply.c:1589]: cleanup_uac_timers(): DEBUG: cleanup_uac_timers: RETR/FR timers reset</div><div> 3(3749) DEBUG: tm [t_reply.c:647]: _reply_light(): DEBUG: reply sent out. buf=0x7fee4d90d450: SIP/2.0 500 Server I..., shmem=0x7fee3ac80ab0: SIP/2.0 500 Server I</div><div> 3(3749) DEBUG: tm [t_reply.c:657]: _reply_light(): DEBUG: _reply_light: finished</div><div> 3(3749) DEBUG: sl [sl.c:272]: send_reply(): reply in stateful mode (tm)</div><div> 3(3749) ERROR: <script>: Failed to handle publish request - R=<a href="mailto:sip%3A302@teste.teste.com.pt">sip:302@teste.teste.com.pt</a>;user=phone ID=<a href="mailto:6869437916cdc135-3714@10.0.20.100">6869437916cdc135-3714@10.0.20.100</a></div><div> 3(3749) DEBUG: tm [t_lookup.c:1011]: t_check_msg(): DEBUG: t_check_msg: msg id=6 global id=6 T start=0x7fee3ac7adf8</div></div><div><br></div><div><br></div><div><br></div><div>Best Regards</div><div>José Seabra</div></div><div class="gmail_extra"><br><div class="gmail_quote">2015-08-18 14:26 GMT+01:00 José Seabra <span dir="ltr"><<a href="mailto:joseseabra4@gmail.com" target="_blank">joseseabra4@gmail.com</a>></span>:<br><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"><div dir="ltr"><div>Hello,<br></div><div><br></div><div>It is working now, so summarizing  about what we need to do in mongodb to kamailio starts up is:</div><div><br></div><div>Access to Mongodb cli</div><div><br></div><div>Create databases kamailio</div><div><br></div><div><span class=""><div style="font-size:12.8000001907349px"><div>> use kamailio</div><div><span style="font-size:12.8000001907349px">switched to db kamailio</span><br></div><div><span style="font-size:12.8000001907349px">> </span><br></div></div><div style="font-size:12.8000001907349px">> db<br></div></span><div style="font-size:12.8000001907349px"><div>kamailio</div><div><br></div><div><br></div><div><span style="font-size:12.8000001907349px">create collection named version</span><br></div><span class=""><div><br></div><div>> db.createCollection("version")<br></div><div><span style="font-size:12.8000001907349px">> show collections</span><br></div></span></div><div style="font-size:12.8000001907349px"><div>system.indexes</div><div>version</div><div>> </div><div><br></div><div><span style="font-size:12.8000001907349px">Add the records for the tables version</span><br></div><div><br></div></div><div style="font-size:12.8000001907349px">> db.getCollection("version").insert({table_name: "presentity", table_version: NumberInt(4) })<br></div><div style="font-size:12.8000001907349px">WriteResult({ "nInserted" : 1 })<br></div><div style="font-size:12.8000001907349px"><br></div></div><div><span style="font-size:12.8000001907349px">> db.getCollection("version").insert({table_name: "watchers", table_version: NumberInt(3) })</span><br></div><div><span style="font-size:12.8000001907349px">WriteResult({ "nInserted" : 1 })</span><br></div><div><span style="font-size:12.8000001907349px"><br></span></div><div><span style="font-size:12.8000001907349px">db.getCollection("version").insert({table_name: "active_watchers", table_version: NumberInt(11) })</span><br></div><div><span style="font-size:12.8000001907349px">WriteResult({ "nInserted" : 1 })</span><span style="font-size:12.8000001907349px"><br></span></div><div><br></div><div>Thank you for your help</div><div>Best Regards</div><div>José Seabra</div></div><div class="gmail_extra"><div><div class="h5"><br><div class="gmail_quote">2015-08-18 13:10 GMT+01:00 Daniel-Constantin Mierla <span dir="ltr"><<a href="mailto:miconda@gmail.com" target="_blank">miconda@gmail.com</a>></span>:<br><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex">
  
    
  
  <div bgcolor="#FFFFFF" text="#000000">
    Hello,<br>
    <br>
    if I remember correctly, the default type for numbers is
    float/double. You have to use a special form/function in mongo
    client when inserting a record to force the type of the value to be
    integer.<br>
    <br>
    Perhaps searching on the web of how to insert an integer value in
    mongodb will give you the proper hings.<span><br>
    <br>
    Cheers,<br>
    Daniel<br>
    <br>
    <div>On 18/08/15 13:17, José Seabra wrote:<br>
    </div>
    </span><div><div><blockquote type="cite">
      <div dir="ltr">Hi,
        <div>Well i didn't noticed before, but after create a document
          in mongodb the error that kamailio gives now is different but
          it still  related with table version check.</div>
        <div><br>
        </div>
        <div>Seems that kamailio can query the document successfully and
          get the table_version field.</div>
        <div><br>
        </div>
        <div>
          <div> 0(3068) DEBUG: db_mongodb [mongodb_dbase.c:671]:
            db_mongodb_convert_result(): selected document: { "_id" : {
            "$oid" : "55d2fc84b04c015195aee4b2" }, "table_version" : 4 }</div>
          <div> 0(3068) DEBUG: <core> [db_row.c:117]:
            db_allocate_row(): allocate 32 bytes for row values at
            0x7fe6fee76390</div>
          <div> 0(3068) DEBUG: db_mongodb [mongodb_dbase.c:522]:
            db_mongodb_convert_bson(): looking for field[0] named:
            table_version</div>
          <div> 0(3068) DEBUG: db_mongodb [mongodb_dbase.c:610]:
            db_mongodb_convert_bson():
            RES_NAMES(0x7fe6fee72490)[0]=[table_version] (1)</div>
          <div> 0(3068) DEBUG: db_mongodb [mongodb_dbase.c:682]:
            db_mongodb_convert_result(): retrieved number of rows: 1</div>
          <div> <b>0(3068) ERROR: <core> [db.c:414]:
              db_table_version(): invalid type (2) or nul (0) version
              columns for presentity</b></div>
        </div>
        <div><br>
        </div>
        <div><br>
        </div>
        <div><br>
        </div>
        <div>ALL Log:</div>
        <div><br>
        </div>
        <div>
          <div>Listening on </div>
          <div>             udp: <a href="http://10.0.20.100:5080" target="_blank">10.0.20.100:5080</a></div>
          <div>Aliases: </div>
          <div><br>
          </div>
          <div> 0(3066) DEBUG: <core> [cfg/cfg.c:176]:
            cfg_declare(): DEBUG: register_cfg_def(): new config group
            has been registered: 'core' (num=50, size=200)</div>
          <div> 0(3066) DEBUG: <core> [cfg/cfg.c:176]:
            cfg_declare(): DEBUG: register_cfg_def(): new config group
            has been registered: 'tcp' (num=26, size=104)</div>
          <div> 0(3066) DEBUG: <core> [timer.c:255]: init_timer():
            starting with *ticks=1210106959</div>
          <div> 0(3066) DEBUG: <core> [timer.c:297]: init_timer():
            timer_list between 0x7fe6ebf85728 and 0x7fe6ebfc9728</div>
          <div> 0(3066) INFO: <core> [tcp_main.c:4656]:
            init_tcp(): using epoll_lt as the io watch method (auto
            detected)</div>
          <div> 0(3068) DEBUG: <core> [daemonize.c:207]:
            enable_dumpable(): trying enable core dumping...</div>
          <div> 0(3068) DEBUG: <core> [daemonize.c:225]:
            enable_dumpable(): core dumping is enabled now (1)...</div>
          <div> 0(3068) DEBUG: <core> [daemonize.c:583]:
            set_core_dump(): core dump limits set to
            18446744073709551615</div>
          <div> 0(3068) DEBUG: <core> [async_task.c:88]:
            async_task_init(): start initializing asynk task framework</div>
          <div> 0(3068) DEBUG: <core> [sr_module.c:942]:
            init_mod(): db_text</div>
          <div> 0(3068) DEBUG: <core> [sr_module.c:942]:
            init_mod(): db_mysql</div>
          <div> 0(3068) DEBUG: db_mysql [km_db_mysql.c:86]:
            kam_mysql_mod_init(): MySQL client version is 5.1.73</div>
          <div> 0(3068) DEBUG: <core> [sr_module.c:942]:
            init_mod(): db_mongodb</div>
          <div> 0(3068) DEBUG: db_mongodb [db_mongodb_mod.c:98]:
            mod_init(): module initializing</div>
          <div> 0(3068) DEBUG: <core> [sr_module.c:942]:
            init_mod(): sl</div>
          <div> 0(3068) DEBUG: <core> [md5utils.c:67]:
            MD5StringArray(): MD5 calculated:
            f452807bca511b98621cbbe6e749d8ef</div>
          <div> 0(3068) DEBUG: <core> [sr_module.c:672]:
            find_mod_export_record(): find_export_record: found
            <load_tm> in module tm
            [/usr/local/lib64/kamailio/modules/tm.so]</div>
          <div> 0(3068) ERROR: tm [tm_load.c:37]: load_tm(): tm:load_tm:
            Module not initialized yet, make sure that all modules that
            need tm module are loaded after tm in the configuration file</div>
          <div> 0(3068) INFO: sl [sl.c:157]: mod_init(): could not bind
            tm module - only stateless mode available during modules
            initialization</div>
          <div> 0(3068) DEBUG: <core> [sr_module.c:942]:
            init_mod(): maxfwd</div>
          <div> 0(3068) DEBUG: <core> [cfg/cfg.c:176]:
            cfg_declare(): DEBUG: register_cfg_def(): new config group
            has been registered: 'maxfwd' (num=1, size=4)</div>
          <div> 0(3068) DEBUG: <core> [sr_module.c:942]:
            init_mod(): textops</div>
          <div> 0(3068) DEBUG: <core> [sr_module.c:942]:
            init_mod(): tm</div>
          <div> 0(3068) DEBUG: tm [tm.c:756]: mod_init(): TM - (sizeof
            cell=488, sip_msg=1768) initializing...</div>
          <div> 0(3068) DEBUG: tm [callid.c:101]: init_callid(): Call-ID
            initialization: '76bf762544f60619'</div>
          <div> 0(3068) DEBUG: tm [lock.c:74]: lock_initialize(): DEBUG:
            lock_initialize: lock initialization started</div>
          <div> 0(3068) DEBUG: tm [timer.c:199]: tm_init_timers(): tm:
            tm_init_timers: fr=480 fr_inv=1920 wait=80 delete=4 t1=500
            t2=4000 max_inv_lifetime=2880 max_noninv_lifetime=512</div>
          <div> 0(3068) DEBUG: <core> [cfg/cfg.c:176]:
            cfg_declare(): DEBUG: register_cfg_def(): new config group
            has been registered: 'tm' (num=36, size=168)</div>
          <div> 0(3068) DEBUG: <core> [md5utils.c:67]:
            MD5StringArray(): MD5 calculated:
            eabd4dc455c32eca91da2be9405373ce</div>
          <div> 0(3068) DEBUG: <core> [md5utils.c:67]:
            MD5StringArray(): MD5 calculated:
            176231eb72a239b3e7f931a1ef6c4100</div>
          <div> 0(3068) DEBUG: <core> [sr_module.c:942]:
            init_mod(): rr</div>
          <div> 0(3068) DEBUG: <core> [sr_module.c:678]:
            find_mod_export_record(): find_export_record:
            <bind_ob> not found </div>
          <div> 0(3068) INFO: rr [../outbound/api.h:54]: ob_load_api():
            Failed to import bind_ob</div>
          <div> 0(3068) INFO: rr [rr_mod.c:174]: mod_init(): outbound
            module not available</div>
          <div> 0(3068) DEBUG: <core> [sr_module.c:942]:
            init_mod(): presence</div>
          <div> 0(3068) DEBUG: presence [presence.c:274]: mod_init():
            db_url=mongodb://localhost/kamailio/28/0x7fe6fee55608</div>
          <div> 0(3068) DEBUG: <core> [sr_module.c:672]:
            find_mod_export_record(): find_export_record: found
            <bind_sl> in module sl
            [/usr/local/lib64/kamailio/modules/sl.so]</div>
          <div> 0(3068) DEBUG: <core> [sr_module.c:672]:
            find_mod_export_record(): find_export_record: found
            <load_tm> in module tm
            [/usr/local/lib64/kamailio/modules/tm.so]</div>
          <div> 0(3068) DEBUG: <core> [sr_module.c:672]:
            find_mod_export_record(): find_export_record: found
            <t_newtran> in module tm
            [/usr/local/lib64/kamailio/modules/tm.so]</div>
          <div> 0(3068) DEBUG: <core> [sr_module.c:672]:
            find_mod_export_record(): find_export_record: found
            <t_relay_to_tcp> in module tm
            [/usr/local/lib64/kamailio/modules/tm.so]</div>
          <div> 0(3068) DEBUG: <core> [sr_module.c:672]:
            find_mod_export_record(): find_export_record: found
            <t_relay_to_udp> in module tm
            [/usr/local/lib64/kamailio/modules/tm.so]</div>
          <div> 0(3068) DEBUG: <core> [sr_module.c:672]:
            find_mod_export_record(): find_export_record: found
            <t_relay> in module tm
            [/usr/local/lib64/kamailio/modules/tm.so]</div>
          <div> 0(3068) DEBUG: <core> [sr_module.c:672]:
            find_mod_export_record(): find_export_record: found
            <t_forward_nonack> in module tm
            [/usr/local/lib64/kamailio/modules/tm.so]</div>
          <div> 0(3068) DEBUG: <core> [sr_module.c:672]:
            find_mod_export_record(): find_export_record: found
            <t_release> in module tm
            [/usr/local/lib64/kamailio/modules/tm.so]</div>
          <div> 0(3068) DEBUG: <core> [sr_module.c:672]:
            find_mod_export_record(): find_export_record: found
            <db_bind_api> in module db_mongodb
            [/usr/local/lib64/kamailio/modules/db_mongodb.so]</div>
          <div> 0(3068) DEBUG: <core> [db.c:205]: db_bind_mod():
            using db bind api for db_mongodb</div>
          <div> 0(3068) DEBUG: <core> [db.c:310]: db_do_init2():
            connection 0x7fe6fee72190 not found in pool</div>
          <div> 0(3068) DEBUG: db_mongodb [mongodb_connection.c:55]:
            db_mongodb_new_connection(): connection open to:
            mongodb://localhost/kamailio</div>
          <div> 0(3068) DEBUG: db_mongodb [mongodb_dbase.c:851]:
            db_mongodb_query(): query to collection [version]</div>
          <div> 0(3068) DEBUG: db_mongodb [mongodb_dbase.c:885]:
            db_mongodb_query(): query filter: { "table_name" :
            "presentity" }</div>
          <div> 0(3068) DEBUG: db_mongodb [mongodb_dbase.c:904]:
            db_mongodb_query(): columns filter: { "table_version" : 1 }</div>
          <div> 0(3068) DEBUG: <core> [db_res.c:116]:
            db_new_result(): allocate 56 bytes for result set at
            0x7fe6fee72338</div>
          <div> 0(3068) DEBUG: db_mongodb [mongodb_dbase.c:349]:
            db_mongodb_get_columns(): 1 columns returned from the query</div>
          <div> 0(3068) DEBUG: <core> [db_res.c:154]:
            db_allocate_columns(): allocate 8 bytes for result names at
            0x7fe6fee72410</div>
          <div> 0(3068) DEBUG: <core> [db_res.c:165]:
            db_allocate_columns(): allocate 4 bytes for result types at
            0x7fe6fee72450</div>
          <div> 0(3068) DEBUG: db_mongodb [mongodb_dbase.c:377]:
            db_mongodb_get_columns(): Found a field[0] named:
            table_version</div>
          <div> 0(3068) DEBUG: db_mongodb [mongodb_dbase.c:396]:
            db_mongodb_get_columns(): allocate 16 bytes for RES_NAMES[0]
            at 0x7fe6fee72490</div>
          <div> 0(3068) DEBUG: db_mongodb [mongodb_dbase.c:416]:
            db_mongodb_get_columns(): use DB1_DOUBLE result type</div>
          <div> 0(3068) DEBUG: db_mongodb [mongodb_dbase.c:460]:
            db_mongodb_get_columns():
            RES_NAMES(0x7fe6fee72490)[0]=[table_version] (1)</div>
          <div> 0(3068) DEBUG: <core> [db_res.c:184]:
            db_allocate_rows(): allocate 16000 bytes for rows at
            0x7fe6fee724d8</div>
          <div> 0(3068) DEBUG: db_mongodb [mongodb_dbase.c:671]:
            db_mongodb_convert_result(): selected document: { "_id" : {
            "$oid" : "55d2fc84b04c015195aee4b2" }, "table_version" : 4 }</div>
          <div> 0(3068) DEBUG: <core> [db_row.c:117]:
            db_allocate_row(): allocate 32 bytes for row values at
            0x7fe6fee76390</div>
          <div> 0(3068) DEBUG: db_mongodb [mongodb_dbase.c:522]:
            db_mongodb_convert_bson(): looking for field[0] named:
            table_version</div>
          <div> 0(3068) DEBUG: db_mongodb [mongodb_dbase.c:610]:
            db_mongodb_convert_bson():
            RES_NAMES(0x7fe6fee72490)[0]=[table_version] (1)</div>
          <div> 0(3068) DEBUG: db_mongodb [mongodb_dbase.c:682]:
            db_mongodb_convert_result(): retrieved number of rows: 1</div>
          <div> 0(3068) ERROR: <core> [db.c:414]:
            db_table_version(): invalid type (2) or nul (0) version
            columns for presentity</div>
          <div> 0(3068) DEBUG: <core> [db_res.c:79]:
            db_free_columns(): freeing 1 columns</div>
          <div> 0(3068) DEBUG: <core> [db_res.c:83]:
            db_free_columns(): freeing RES_NAMES[0] at 0x7fe6fee72490</div>
          <div> 0(3068) DEBUG: <core> [db_res.c:92]:
            db_free_columns(): freeing result names at 0x7fe6fee72410</div>
          <div> 0(3068) DEBUG: <core> [db_res.c:97]:
            db_free_columns(): freeing result types at 0x7fe6fee72450</div>
          <div> 0(3068) DEBUG: <core> [db_res.c:52]:
            db_free_rows(): freeing 1 rows</div>
          <div> 0(3068) DEBUG: <core> [db_row.c:95]:
            db_free_row(): freeing row values at 0x7fe6fee76390</div>
          <div> 0(3068) DEBUG: <core> [db_res.c:60]:
            db_free_rows(): freeing rows at 0x7fe6fee724d8</div>
          <div> 0(3068) DEBUG: <core> [db_res.c:134]:
            db_free_result(): freeing result set at 0x7fe6fee72338</div>
          <div> 0(3068) ERROR: <core> [db.c:432]:
            db_check_table_version(): querying version for table
            presentity</div>
          <div><b> 0(3068) ERROR: presence [presence.c:358]: mod_init():
              error during table version check</b></div>
          <div><b> 0(3068) ERROR: <core> [sr_module.c:945]:
              init_mod(): Error while initializing module presence
              (/usr/local/lib64/kamailio/modules/presence.so)</b></div>
          <div>ERROR: error while initializing modules</div>
          <div> 0(3068) DEBUG: <core> [db_pool.c:100]:
            pool_remove(): removing connection from the pool</div>
          <div> 0(3068) DEBUG: tm [t_funcs.c:86]: tm_shutdown(): DEBUG:
            tm_shutdown : start</div>
          <div> 0(3068) DEBUG: tm [t_funcs.c:89]: tm_shutdown(): DEBUG:
            tm_shutdown : emptying hash table</div>
          <div> 0(3068) DEBUG: tm [t_funcs.c:91]: tm_shutdown(): DEBUG:
            tm_shutdown : removing semaphores</div>
          <div> 0(3068) DEBUG: tm [t_funcs.c:93]: tm_shutdown(): DEBUG:
            tm_shutdown : destroying tmcb lists</div>
          <div> 0(3068) DEBUG: tm [t_funcs.c:96]: tm_shutdown(): DEBUG:
            tm_shutdown : done</div>
          <div> 0(3068) DEBUG: db_text [dbtext.c:106]: destroy():
            destroy ...</div>
          <div> 0(3068) INFO: <core> [sctp_core.c:53]:
            sctp_core_destroy(): SCTP API not initialized</div>
          <div> 0(3068) DEBUG: <core> [mem/shm_mem.c:232]:
            shm_mem_destroy(): shm_mem_destroy</div>
          <div> 0(3068) DEBUG: <core> [mem/shm_mem.c:235]:
            shm_mem_destroy(): destroying the shared memory lock</div>
        </div>
        <div><br>
        </div>
        <div><br>
        </div>
        <div>Best regards</div>
      </div>
    </blockquote>
    <br>
    </div></div><span><pre cols="72">-- 
Daniel-Constantin Mierla
<a href="http://twitter.com/#!/miconda" target="_blank">http://twitter.com/#!/miconda</a> - <a href="http://www.linkedin.com/in/miconda" target="_blank">http://www.linkedin.com/in/miconda</a>
Book: SIP Routing With Kamailio - <a href="http://www.asipto.com" target="_blank">http://www.asipto.com</a></pre>
  </span></div>

</blockquote></div><br><br clear="all"><div><br></div></div></div><span class="HOEnZb"><font color="#888888">-- <br><div>Cumprimentos<div>José Seabra</div></div>
</font></span></div>
</blockquote></div><br><br clear="all"><div><br></div>-- <br><div class="gmail_signature">Cumprimentos<div>José Seabra</div></div>
</div>