Re: [SR-Users] ACK not forwarding to Asterisk

​​Hi Yasin Thanks for your reply! That means my setup does not work if Kamailio and Asterisk are sitting on the same IP. Or is there something I can do? Do you have a proposal what I could change? Regards Mathias Config snippet of WITHINDLG: ... # Handle requests within SIP dialogs route[WITHINDLG] { xlog("XXXXXXXXXXXXXXXXXXXXXXX\nWITHINDLG\n"); if (!has_totag()) return; # sequential request withing a dialog should # take the path determined by record-routing if (loose_route()) { xlog("XXXXXXXXXXXXXXXXXXXXXXX\nLoose route\n"); if (is_method("BYE")) { setflag(FLT_ACC); # do accounting ... setflag(FLT_ACCFAILED); # ... even if the transaction fails } else if ( is_method("NOTIFY") ) { # Add Record-Route for in-dialog NOTIFY as per RFC 6665. record_route(); } route(RELAY); exit; } if (is_method("SUBSCRIBE") && uri == myself) { # in-dialog subscribe requests route(PRESENCE); exit; } xlog("XXXXXXXXXXXXXXXXXXXXXXX\nWITHINDLG\n"); if ( is_method("ACK") ) { xlog("XXXXXXXXXXXXXXXXXXXXXXX\nACK\n"); if ( t_check_trans() ) { xlog("XXXXXXXXXXXXXXXXXXXXXXX\nt_check_trans\n"); # no loose-route, but stateful ACK; # must be an ACK after a 487 # or e.g. 404 from upstream server route(RELAY); exit; } else { xlog("XXXXXXXXXXXXXXXXXXXXXXX\nignore\n"); # ACK without matching transaction ... ignore and discard exit; } } sl_send_reply("404","Not here"); exit; } ​ ... Following the log output of the relevant OK and ACK: Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: <core> [core/udp_server.c:492]: udp_rcv_loop(): received on udp socket: (106/100/1091) [[SIP/2.0 200 OK 0D 0A Via: SIP/2.0/UDP 10.40.8.104:5070;branch=z9hG4bK4825.fc814778ec04597ae4759a9771bfef0]] Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: <core> [core/parser/msg_parser.c:620]: parse_msg(): SIP Reply (status): Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: <core> [core/parser/msg_parser.c:622]: parse_msg(): version: <SIP/2.0> Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: <core> [core/parser/msg_parser.c:624]: parse_msg(): status: <200> Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: <core> [core/parser/msg_parser.c:626]: parse_msg(): reason: <OK> Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK4825.fc814778ec04597ae4759a9771bfef09.0>; state=6 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 234, <received> = <10.40.8.104>; state=16 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: <core> [core/parser/msg_parser.c:498]: parse_headers(): Via found, flags=2 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: <core> [core/parser/msg_parser.c:500]: parse_headers(): this is the first via Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 234, <received> = <10.40.6.188>; state=6 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 235, <rport> = <60223>; state=6 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bKPjBBr32NDnGLx0KwymDtyAXs.rIuFIwAdi>; state=16 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: <core> [core/parser/msg_parser.c:498]: parse_headers(): Via found, flags=78 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: <core> [core/parser/msg_parser.c:511]: parse_headers(): this is the second via Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=as21517b15 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: <core> [core/parser/msg_parser.c:171]: get_hdr_field(): <To> [44]; uri=[sip:004112345@10.40.8.104] Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: <core> [core/parser/msg_parser.c:174]: get_hdr_field(): to body [<sip:004112345@10.40.8.104>], to tag [as21517b15] Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: <core> [core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <27457> <INVITE> Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: <core> [core/receive.c:245]: receive_msg(): --- received sip message - reply - call-id: [otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy] - cseq: [27457 INVITE] Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: <core> [core/parser/msg_parser.c:185]: get_hdr_field(): content_length=271 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): found end of header Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: {2 27457 INVITE otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} tm [t_lookup.c:1043]: t_check_msg(): msg (0xb72fb410) id=26/18447 global id=25/18447 T start=0xffffffff Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: {2 27457 INVITE otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} tm [t_lookup.c:920]: t_reply_matching(): t_reply_matching: hash 21124 label 0 branch 0 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: {2 27457 INVITE otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} tm [t_lookup.c:974]: t_reply_matching(): reply (0xb72fb410) matched an active transaction (T=0xb4931af4)! Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: {2 27457 INVITE otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} tm [t_hooks.c:258]: run_trans_callbacks_internal(): DBG: trans=0xb4931af4, callback type 2, id 0 entered Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: {2 27457 INVITE otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} acc [acc_logic.c:682]: tmcb_func(): acc callback called for t(0xb4931af4) event type 2, reply code 200 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: {2 27457 INVITE otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} acc [acc_logic.c:414]: should_acc_reply(): probing acc state - code: 200 flags: 0x2 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: {2 27457 INVITE otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} acc [acc_logic.c:446]: should_acc_reply(): acc is on Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: {2 27457 INVITE otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} tm [t_hooks.c:258]: run_trans_callbacks_internal(): DBG: trans=0xb4931af4, callback type 2, id 0 entered Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: {2 27457 INVITE otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:712]: dlg_lookup(): ref dlg 0xb4934aec with 1 -> 3 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: {2 27457 INVITE otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:714]: dlg_lookup(): dialog id=8415 found on entry 3438 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: {2 27457 INVITE otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_profile.c:536]: set_current_dialog(): setting current dialog [3438:8415] Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: {2 27457 INVITE otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:957]: dlg_unref_helper(): unref op on 0xb4934aec with 1 from dlg_hash.c:975 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: {2 27457 INVITE otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:961]: dlg_unref_helper(): unref dlg 0xb4934aec with 1 -> 2 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: {2 27457 INVITE otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} tm [t_lookup.c:1113]: t_check_msg(): msg (0xb72fb410) id=26/18447 global id=26/18447 T end=0xb4931af4 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: {2 27457 INVITE otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} tm [t_reply.c:2243]: reply_received(): transaction found - T:0xb4931af4 branch:0 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: {2 27457 INVITE otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} tm [t_reply.c:2258]: reply_received(): org. status uas=200, uac[0]=200 local=0 is_invite=1) Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: {2 27457 INVITE otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <script>: incoming reply Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: {2 27457 INVITE otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} tm [t_reply.c:1266]: t_should_relay_response(): ->>>>>>>>> T_code=200, new_code=200 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: {2 27457 INVITE otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} tm [t_reply.c:1271]: t_should_relay_response(): 200 INV after final sent Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: {2 27457 INVITE otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} tm [t_reply.c:1824]: relay_reply(): reply status=1 branch=0, save=0, relay=0 icode=0 msg status=200 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: {2 27457 INVITE otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} tm [t_hooks.c:258]: run_trans_callbacks_internal(): DBG: trans=0xb4931af4, callback type 32, id 0 entered Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: {2 27457 INVITE otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:712]: dlg_lookup(): ref dlg 0xb4934aec with 1 -> 3 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: {2 27457 INVITE otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:714]: dlg_lookup(): dialog id=8415 found on entry 3438 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: {2 27457 INVITE otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:957]: dlg_unref_helper(): unref op on 0xb4934aec with 1 from dlg_hash.c:975 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: {2 27457 INVITE otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:961]: dlg_unref_helper(): unref dlg 0xb4934aec with 1 -> 2 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: {2 27457 INVITE otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/msg_translator.c:2288]: generate_res_buf_from_sip_res(): old size: 1091, new size: 981 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: {2 27457 INVITE otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/msg_translator.c:2306]: generate_res_buf_from_sip_res(): copied size: orig:126, new: 16, rest: 965 msg= SIP/2.0 200 OK^M Via: SIP/2.0/UDP 10.40.6.188:60223;received=10.40.6.188;rport=60223;branch=z9hG4bKPjBBr32NDnGLx0KwymDtyAXs.rIuFIwAdi^M Record-Route: <sip:10.40.8.104:5070;lr;ftag=1DoN4DknAgMG5nSNVGynmZgOtY9Ap6nP;did=e6d.fd02>^M From: <sip:proxydevice@10.40.8.104>;tag=1DoN4DknAgMG5nSNVGynmZgOtY9Ap6nP^M To: <sip:004112345@10.40.8.104>;tag=as21517b15^M Call-ID: otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy^M CSeq: 27457 INVITE^M Server: Asterisk PBX 12.3.2^M Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE^M Supported: replaces, timer^M Session-Expires: 1800;refresher=uas^M Contact: <sip:004112345@10.40.8.104:5060>^M Content-Type: application/sdp^M Require: timer^M Content-Length: 271^M ^M v=0^M o=root 623479861 623479861 IN IP4 10.40.8.104^M s=Asterisk PBX 12.3.2^M Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: {2 27457 INVITE otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} tm [t_reply.c:305]: update_totag_set(): to-tag retransmission Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: {2 27457 INVITE otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} tm [t_reply.c:2016]: relay_reply(): reply buffer sent out Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: {2 27457 INVITE otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/receive.c:441]: receive_msg(): reply-route executed in: 490 usec Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: {2 27457 INVITE otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_var.c:97]: cb_dlg_locals_reset(): resetting the local dialog shortcuts on script callback: 2147483652 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: {2 27457 INVITE otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil) Mar 12 09:21:43 oAN last message repeated 5 times Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: {2 27457 INVITE otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/xavp.c:495]: xavp_destroy_list(): destroying xavp list (nil) Mar 12 09:21:43 oAN /usr/sbin/kamailio[18447]: DEBUG: {2 27457 INVITE otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/receive.c:457]: receive_msg(): cleaning up Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: <core> [core/udp_server.c:492]: udp_rcv_loop(): received on udp socket: (106/100/442) [[ACK sip:004112345@10.40.8.104:5060 SIP/2.0 0D 0A Via: SIP/2.0/UDP 10.40.6.188:60223;rport;branch=z9hG4bKP]] Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: <core> [core/parser/msg_parser.c:610]: parse_msg(): SIP Request: Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: <core> [core/parser/msg_parser.c:612]: parse_msg(): method: <ACK> Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: <core> [core/parser/msg_parser.c:614]: parse_msg(): uri: <sip:004112345@10.40.8.104:5060> Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: <core> [core/parser/msg_parser.c:616]: parse_msg(): version: <SIP/2.0> Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 235, <rport> = <n/a>; state=6 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bKPjvd1MSxMjv6dfOGdbAVxKz.iPtydNiEtQ>; state=16 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: <core> [core/parser/msg_parser.c:498]: parse_headers(): Via found, flags=2 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: <core> [core/parser/msg_parser.c:500]: parse_headers(): this is the first via Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=as21517b15 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: <core> [core/parser/msg_parser.c:171]: get_hdr_field(): <To> [44]; uri=[sip:004112345@10.40.8.104] Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: <core> [core/parser/msg_parser.c:174]: get_hdr_field(): to body [<sip:004112345@10.40.8.104>], to tag [as21517b15] Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: <core> [core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <27457> <ACK> Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: <core> [core/receive.c:245]: receive_msg(): --- received sip message - request - call-id: [otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy] - cseq: [27457 ACK] Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: <core> [core/parser/msg_parser.c:185]: get_hdr_field(): content_length=0 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): found end of header Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/receive.c:295]: receive_msg(): preparing to run routing scripts... Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sl [sl_funcs.c:397]: sl_filter_ACK(): too late to be a local ACK! Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=1DoN4DknAgMG5nSNVGynmZgOtY9Ap6nP Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:769]: internal_get_dlg(): ref dlg 0xb4934aec with 1 -> 3 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:772]: internal_get_dlg(): dialog callid='otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy' found on entry 3438, dir=1 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_profile.c:536]: set_current_dialog(): setting current dialog [3438:8415] Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:1158]: next_state_dlg(): dialog 0xb4934aec changed from state 3 to state 4, due event 6 (ref 3) Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_timer.c:110]: insert_dialog_timer_unsafe(): inserting 0xb4934b30 for 12143697 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_handlers.c:1475]: dlg_onroute(): confirming ACK successfully processed Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:957]: dlg_unref_helper(): unref op on 0xb4934aec with 1 from dlg_hash.c:975 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:961]: dlg_unref_helper(): unref dlg 0xb4934aec with 1 -> 2 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} pv [pv_core.c:1031]: pv_get_useragent(): no User-Agent header Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} maxfwd [mf_funcs.c:74]: is_maxfwd_present(): value = 70 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:247]: check_ruri_sip_version(): check_ruri_sip_version entered Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:270]: check_ruri_sip_version(): check_ruri_sip_version passed Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:277]: check_ruri_scheme(): check_ruri_scheme entered Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:297]: check_ruri_scheme(): check_ruri_scheme passed Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:305]: check_required_headers(): check_required_headers entered Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:313]: check_required_headers(): check_required_headers passed Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:479]: check_cseq_method(): check_cseq_method entered Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:512]: check_cseq_method(): check_cseq_method passed Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:521]: check_cseq_value(): check_cseq_value entered Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:549]: check_cseq_value(): check_cseq_value passed Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:558]: check_cl(): check_cl entered Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:583]: check_cl(): check_cl passed Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:595]: check_expires_value(): check_expires_value entered Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:632]: check_expires_value(): no expires header found Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:728]: check_parse_uris(): check_parse_uris entered Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:732]: check_parse_uris(): parsing ruri Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:746]: check_parse_uris(): looking up From header Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:786]: check_parse_uris(): parsing From URI Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:804]: check_parse_uris(): looking up To header Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:826]: check_parse_uris(): check_parse_uris(): parsing To URI Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:871]: check_parse_uris(): check_parse_uris passed Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity_mod.c:254]: w_sanity_check(): sanity checks result: 1 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: ERROR: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <script>: XXXXXXXXXXXXXXXXXXXXXXX WITHINDLG Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} siputils [checks.c:123]: has_totag(): totag found Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} rr [loose.c:91]: is_preloaded(): is_preloaded: No Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/socket_info.c:564]: grep_sock_info(): checking if host==us: 11==11 && [10.40.8.104] == [10.40.8.104] Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/socket_info.c:567]: grep_sock_info(): checking if port 5070 (advertise 5070) matches port 5060 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} rr [loose.c:677]: after_strict(): Next hop: 'sip:10.40.8.104:5070;lr;ftag=1DoN4DknAgMG5nSNVGynmZgOtY9Ap6nP;did=e6d.fd02' is loose router Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} rr [loose.c:727]: after_strict(): The last route URI: 'sip:10.40.8.104:5070;lr;ftag=1DoN4DknAgMG5nSNVGynmZgOtY9Ap6nP;did=e6d.fd02' Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: ERROR: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <script>: XXXXXXXXXXXXXXXXXXXXXXX Loose route Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} tm [t_lookup.c:1346]: t_newtran(): msg (0xb72fb410) id=25/18442 global id=24/18442 T start=0xffffffff Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} tm [t_lookup.c:500]: t_lookup_request(): start searching: hash=21124, isACK=1 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} tm [t_lookup.c:458]: matching_3261(): RFC3261 transaction matching failed - via branch [z9hG4bKPjvd1MSxMjv6dfOGdbAVxKz.iPtydNiEtQ] Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} tm [t_lookup.c:682]: t_lookup_request(): no transaction found Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} tm [t_funcs.c:287]: t_relay_to(): forwarding ACK statelessly Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/dns_cache.c:3193]: dns_srv_sip_resolve(): (10.40.8.104, 0, 0), ip, ret=0 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/md5utils.c:67]: MD5StringArray(): MD5 calculated: 29cbe80853cc3d43347f3c0b4b643e4c Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/forward.c:557]: forward_request(): Sending: ACK sip:10.40.8.104:5070;lr;ftag=1DoN4DknAgMG5nSNVGynmZgOtY9Ap6nP;did=e6d.fd02 SIP/2.0^M Via: SIP/2.0/UDP 10.40.8.104:5070;branch=z9hG4bK4825.29cbe80853cc3d43347f3c0b4b643e4c.0^M Via: SIP/2.0/UDP 10.40.6.188:60223;received=10.40.6.188;rport=60223;branch=z9hG4bKPjvd1MSxMjv6dfOGdbAVxKz.iPtydNiEtQ^M Max-Forwards: 69^M From: <sip:proxydevice@10.40.8.104>;tag=1DoN4DknAgMG5nSNVGynmZgOtY9Ap6nP^M To: <sip:004112345@10.40.8.104>;tag=as21517b15^M Call-ID: otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy^M CSeq: 27457 ACK^M Content-Length: 0^M ^M . Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/forward.c:559]: forward_request(): orig. len=442, new_len=517, proto=1 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/receive.c:353]: receive_msg(): request-route executed in: 936 usec Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:712]: dlg_lookup(): ref dlg 0xb4934aec with 1 -> 3 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: <core> [core/udp_server.c:492]: udp_rcv_loop(): received on udp socket: (106/100/517) [[ACK sip:10.40.8.104:5070;lr;ftag=1DoN4DknAgMG5nSNVGynmZgOtY9Ap6nP;did=e6d.fd02 SIP/2.0 0D 0A Via: SIP/2.0]] Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:714]: dlg_lookup(): dialog id=8415 found on entry 3438 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:957]: dlg_unref_helper(): unref op on 0xb4934aec with 1 from dlg_hash.c:975 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: <core> [core/parser/msg_parser.c:610]: parse_msg(): SIP Request: Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:961]: dlg_unref_helper(): unref dlg 0xb4934aec with 1 -> 2 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil) Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: <core> [core/parser/msg_parser.c:612]: parse_msg(): method: <ACK> Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil) Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: <core> [core/parser/msg_parser.c:614]: parse_msg(): uri: <sip:10.40.8.104:5070;lr;ftag=1DoN4DknAgMG5nSNVGynmZgOtY9Ap6nP;did=e6d.fd02> Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil) Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil) Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: <core> [core/parser/msg_parser.c:616]: parse_msg(): version: <SIP/2.0> Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil) Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil) Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK4825.29cbe80853cc3d43347f3c0b4b643e4c.0>; state=16 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/xavp.c:495]: xavp_destroy_list(): destroying xavp list (nil) Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18442]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/receive.c:457]: receive_msg(): cleaning up Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: <core> [core/parser/msg_parser.c:498]: parse_headers(): Via found, flags=2 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: <core> [core/parser/msg_parser.c:500]: parse_headers(): this is the first via Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 234, <received> = <10.40.6.188>; state=6 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 235, <rport> = <60223>; state=6 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bKPjvd1MSxMjv6dfOGdbAVxKz.iPtydNiEtQ>; state=16 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: <core> [core/parser/msg_parser.c:498]: parse_headers(): Via found, flags=78 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: <core> [core/parser/msg_parser.c:511]: parse_headers(): this is the second via Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=as21517b15 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: <core> [core/parser/msg_parser.c:171]: get_hdr_field(): <To> [44]; uri=[sip:004112345@10.40.8.104] Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: <core> [core/parser/msg_parser.c:174]: get_hdr_field(): to body [<sip:004112345@10.40.8.104>], to tag [as21517b15] Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: <core> [core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <27457> <ACK> Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: <core> [core/receive.c:245]: receive_msg(): --- received sip message - request - call-id: [otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy] - cseq: [27457 ACK] Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: <core> [core/parser/msg_parser.c:185]: get_hdr_field(): content_length=0 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): found end of header Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/receive.c:295]: receive_msg(): preparing to run routing scripts... Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sl [sl_funcs.c:397]: sl_filter_ACK(): too late to be a local ACK! Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=1DoN4DknAgMG5nSNVGynmZgOtY9Ap6nP Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:769]: internal_get_dlg(): ref dlg 0xb4934aec with 1 -> 3 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:772]: internal_get_dlg(): dialog callid='otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy' found on entry 3438, dir=1 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_profile.c:536]: set_current_dialog(): setting current dialog [3438:8415] Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:1158]: next_state_dlg(): dialog 0xb4934aec changed from state 4 to state 4, due event 6 (ref 3) Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_timer.c:110]: insert_dialog_timer_unsafe(): inserting 0xb4934b30 for 12143697 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_handlers.c:1480]: dlg_onroute(): sequential request successfully processed Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} rr [record.c:925]: add_rr_param(): rr_param_buf=<;did=e6d.fd02> Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:957]: dlg_unref_helper(): unref op on 0xb4934aec with 1 from dlg_hash.c:975 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:961]: dlg_unref_helper(): unref dlg 0xb4934aec with 1 -> 2 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} pv [pv_core.c:1031]: pv_get_useragent(): no User-Agent header Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} maxfwd [mf_funcs.c:74]: is_maxfwd_present(): value = 69 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:247]: check_ruri_sip_version(): check_ruri_sip_version entered Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:270]: check_ruri_sip_version(): check_ruri_sip_version passed Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:277]: check_ruri_scheme(): check_ruri_scheme entered Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:297]: check_ruri_scheme(): check_ruri_scheme passed Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:305]: check_required_headers(): check_required_headers entered Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:313]: check_required_headers(): check_required_headers passed Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:479]: check_cseq_method(): check_cseq_method entered Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:512]: check_cseq_method(): check_cseq_method passed Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:521]: check_cseq_value(): check_cseq_value entered Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:549]: check_cseq_value(): check_cseq_value passed Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:558]: check_cl(): check_cl entered Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:583]: check_cl(): check_cl passed Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:595]: check_expires_value(): check_expires_value entered Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:632]: check_expires_value(): no expires header found Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:728]: check_parse_uris(): check_parse_uris entered Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:732]: check_parse_uris(): parsing ruri Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:746]: check_parse_uris(): looking up From header Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:786]: check_parse_uris(): parsing From URI Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:804]: check_parse_uris(): looking up To header Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:826]: check_parse_uris(): check_parse_uris(): parsing To URI Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:871]: check_parse_uris(): check_parse_uris passed Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity_mod.c:254]: w_sanity_check(): sanity checks result: 1 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: ERROR: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <script>: XXXXXXXXXXXXXXXXXXXXXXX WITHINDLG Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} siputils [checks.c:123]: has_totag(): totag found Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} rr [loose.c:114]: find_first_route(): No Route headers found Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} rr [loose.c:961]: loose_route(): There is no Route HF Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: ERROR: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <script>: XXXXXXXXXXXXXXXXXXXXXXX WITHINDLG Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: ERROR: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <script>: XXXXXXXXXXXXXXXXXXXXXXX ACK Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} tm [t_lookup.c:1043]: t_check_msg(): msg (0xb72fb410) id=26/18443 global id=25/18443 T start=0xffffffff Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} tm [t_lookup.c:500]: t_lookup_request(): start searching: hash=21124, isACK=1 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} tm [t_lookup.c:458]: matching_3261(): RFC3261 transaction matching failed - via branch [z9hG4bK4825.29cbe80853cc3d43347f3c0b4b643e4c.0] Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} tm [t_lookup.c:682]: t_lookup_request(): no transaction found Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} tm [t_lookup.c:1113]: t_check_msg(): msg (0xb72fb410) id=26/18443 global id=26/18443 T end=(nil) Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: ERROR: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <script>: XXXXXXXXXXXXXXXXXXXXXXX ignore Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/receive.c:353]: receive_msg(): request-route executed in: 737 usec Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:712]: dlg_lookup(): ref dlg 0xb4934aec with 1 -> 3 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:714]: dlg_lookup(): dialog id=8415 found on entry 3438 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:957]: dlg_unref_helper(): unref op on 0xb4934aec with 1 from dlg_hash.c:975 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:961]: dlg_unref_helper(): unref dlg 0xb4934aec with 1 -> 2 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil) Mar 12 09:21:43 oAN last message repeated 5 times Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/xavp.c:495]: xavp_destroy_list(): destroying xavp list (nil) Mar 12 09:21:43 oAN /usr/sbin/kamailio[18443]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/receive.c:457]: receive_msg(): cleaning up Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: <core> [core/udp_server.c:492]: udp_rcv_loop(): received on udp socket: (106/100/442) [[ACK sip:004112345@10.40.8.104:5060 SIP/2.0 0D 0A Via: SIP/2.0/UDP 10.40.6.188:60223;rport;branch=z9hG4bKP]] Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: <core> [core/parser/msg_parser.c:610]: parse_msg(): SIP Request: Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: <core> [core/parser/msg_parser.c:612]: parse_msg(): method: <ACK> Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: <core> [core/parser/msg_parser.c:614]: parse_msg(): uri: <sip:004112345@10.40.8.104:5060> Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: <core> [core/parser/msg_parser.c:616]: parse_msg(): version: <SIP/2.0> Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 235, <rport> = <n/a>; state=6 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bKPjvd1MSxMjv6dfOGdbAVxKz.iPtydNiEtQ>; state=16 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: <core> [core/parser/msg_parser.c:498]: parse_headers(): Via found, flags=2 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: <core> [core/parser/msg_parser.c:500]: parse_headers(): this is the first via Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=as21517b15 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: <core> [core/parser/msg_parser.c:171]: get_hdr_field(): <To> [44]; uri=[sip:004112345@10.40.8.104] Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: <core> [core/parser/msg_parser.c:174]: get_hdr_field(): to body [<sip:004112345@10.40.8.104>], to tag [as21517b15] Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: <core> [core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <27457> <ACK> Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: <core> [core/receive.c:245]: receive_msg(): --- received sip message - request - call-id: [otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy] - cseq: [27457 ACK] Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: <core> [core/parser/msg_parser.c:185]: get_hdr_field(): content_length=0 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): found end of header Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/receive.c:295]: receive_msg(): preparing to run routing scripts... Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sl [sl_funcs.c:397]: sl_filter_ACK(): too late to be a local ACK! Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: <core> [core/udp_server.c:492]: udp_rcv_loop(): received on udp socket: (106/100/442) [[ACK sip:004112345@10.40.8.104:5060 SIP/2.0 0D 0A Via: SIP/2.0/UDP 10.40.6.188:60223;rport;branch=z9hG4bKP]] Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=1DoN4DknAgMG5nSNVGynmZgOtY9Ap6nP Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: <core> [core/parser/msg_parser.c:610]: parse_msg(): SIP Request: Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: <core> [core/parser/msg_parser.c:612]: parse_msg(): method: <ACK> Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:769]: internal_get_dlg(): ref dlg 0xb4934aec with 1 -> 3 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: <core> [core/parser/msg_parser.c:614]: parse_msg(): uri: <sip:004112345@10.40.8.104:5060> Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: <core> [core/parser/msg_parser.c:616]: parse_msg(): version: <SIP/2.0> Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 235, <rport> = <n/a>; state=6 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:772]: internal_get_dlg(): dialog callid='otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy' found on entry 3438, dir=1 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bKPjvd1MSxMjv6dfOGdbAVxKz.iPtydNiEtQ>; state=16 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_profile.c:536]: set_current_dialog(): setting current dialog [3438:8415] Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:1158]: next_state_dlg(): dialog 0xb4934aec changed from state 4 to state 4, due event 6 (ref 3) Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: <core> [core/parser/msg_parser.c:498]: parse_headers(): Via found, flags=2 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: <core> [core/parser/msg_parser.c:500]: parse_headers(): this is the first via Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=as21517b15 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_timer.c:110]: insert_dialog_timer_unsafe(): inserting 0xb4934b30 for 12143697 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_handlers.c:1480]: dlg_onroute(): sequential request successfully processed Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: <core> [core/parser/msg_parser.c:171]: get_hdr_field(): <To> [44]; uri=[sip:004112345@10.40.8.104] Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} rr [record.c:925]: add_rr_param(): rr_param_buf=<;did=e6d.fd02> Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:957]: dlg_unref_helper(): unref op on 0xb4934aec with 1 from dlg_hash.c:975 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: <core> [core/parser/msg_parser.c:174]: get_hdr_field(): to body [<sip:004112345@10.40.8.104>], to tag [as21517b15] Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: <core> [core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <27457> <ACK> Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:961]: dlg_unref_helper(): unref dlg 0xb4934aec with 1 -> 2 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: <core> [core/receive.c:245]: receive_msg(): --- received sip message - request - call-id: [otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy] - cseq: [27457 ACK] Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: <core> [core/parser/msg_parser.c:185]: get_hdr_field(): content_length=0 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} pv [pv_core.c:1031]: pv_get_useragent(): no User-Agent header Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): found end of header Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/receive.c:295]: receive_msg(): preparing to run routing scripts... Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} maxfwd [mf_funcs.c:74]: is_maxfwd_present(): value = 70 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sl [sl_funcs.c:397]: sl_filter_ACK(): too late to be a local ACK! Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:247]: check_ruri_sip_version(): check_ruri_sip_version entered Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:270]: check_ruri_sip_version(): check_ruri_sip_version passed Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=1DoN4DknAgMG5nSNVGynmZgOtY9Ap6nP Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:277]: check_ruri_scheme(): check_ruri_scheme entered Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:769]: internal_get_dlg(): ref dlg 0xb4934aec with 1 -> 3 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:772]: internal_get_dlg(): dialog callid='otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy' found on entry 3438, dir=1 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:297]: check_ruri_scheme(): check_ruri_scheme passed Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_profile.c:536]: set_current_dialog(): setting current dialog [3438:8415] Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:1158]: next_state_dlg(): dialog 0xb4934aec changed from state 4 to state 4, due event 6 (ref 3) Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:305]: check_required_headers(): check_required_headers entered Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:313]: check_required_headers(): check_required_headers passed Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_timer.c:110]: insert_dialog_timer_unsafe(): inserting 0xb4934b30 for 12143697 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_handlers.c:1480]: dlg_onroute(): sequential request successfully processed Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:479]: check_cseq_method(): check_cseq_method entered Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} rr [record.c:925]: add_rr_param(): rr_param_buf=<;did=e6d.fd02> Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:957]: dlg_unref_helper(): unref op on 0xb4934aec with 1 from dlg_hash.c:975 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:512]: check_cseq_method(): check_cseq_method passed Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:961]: dlg_unref_helper(): unref dlg 0xb4934aec with 1 -> 2 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} pv [pv_core.c:1031]: pv_get_useragent(): no User-Agent header Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} maxfwd [mf_funcs.c:74]: is_maxfwd_present(): value = 70 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:521]: check_cseq_value(): check_cseq_value entered Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:247]: check_ruri_sip_version(): check_ruri_sip_version entered Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:549]: check_cseq_value(): check_cseq_value passed Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:270]: check_ruri_sip_version(): check_ruri_sip_version passed Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:558]: check_cl(): check_cl entered Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:277]: check_ruri_scheme(): check_ruri_scheme entered Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:297]: check_ruri_scheme(): check_ruri_scheme passed Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:583]: check_cl(): check_cl passed Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:305]: check_required_headers(): check_required_headers entered Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:595]: check_expires_value(): check_expires_value entered Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:313]: check_required_headers(): check_required_headers passed Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:632]: check_expires_value(): no expires header found Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:479]: check_cseq_method(): check_cseq_method entered Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:728]: check_parse_uris(): check_parse_uris entered Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:512]: check_cseq_method(): check_cseq_method passed Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:732]: check_parse_uris(): parsing ruri Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:521]: check_cseq_value(): check_cseq_value entered Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:746]: check_parse_uris(): looking up From header Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:549]: check_cseq_value(): check_cseq_value passed Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:786]: check_parse_uris(): parsing From URI Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:558]: check_cl(): check_cl entered Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:804]: check_parse_uris(): looking up To header Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:583]: check_cl(): check_cl passed Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:826]: check_parse_uris(): check_parse_uris(): parsing To URI Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:595]: check_expires_value(): check_expires_value entered Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:871]: check_parse_uris(): check_parse_uris passed Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:632]: check_expires_value(): no expires header found Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity_mod.c:254]: w_sanity_check(): sanity checks result: 1 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:728]: check_parse_uris(): check_parse_uris entered Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: ERROR: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <script>: XXXXXXXXXXXXXXXXXXXXXXX WITHINDLG Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:732]: check_parse_uris(): parsing ruri Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} siputils [checks.c:123]: has_totag(): totag found Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:746]: check_parse_uris(): looking up From header Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} rr [loose.c:91]: is_preloaded(): is_preloaded: No Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:786]: check_parse_uris(): parsing From URI Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:804]: check_parse_uris(): looking up To header Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/socket_info.c:564]: grep_sock_info(): checking if host==us: 11==11 && [10.40.8.104] == [10.40.8.104] Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:826]: check_parse_uris(): check_parse_uris(): parsing To URI Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:871]: check_parse_uris(): check_parse_uris passed Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/socket_info.c:567]: grep_sock_info(): checking if port 5070 (advertise 5070) matches port 5060 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} rr [loose.c:677]: after_strict(): Next hop: 'sip:10.40.8.104:5070;lr;ftag=1DoN4DknAgMG5nSNVGynmZgOtY9Ap6nP;did=e6d.fd02' is loose router Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity_mod.c:254]: w_sanity_check(): sanity checks result: 1 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: ERROR: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <script>: XXXXXXXXXXXXXXXXXXXXXXX WITHINDLG Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} rr [loose.c:727]: after_strict(): The last route URI: 'sip:10.40.8.104:5070;lr;ftag=1DoN4DknAgMG5nSNVGynmZgOtY9Ap6nP;did=e6d.fd02' Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} siputils [checks.c:123]: has_totag(): totag found Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: ERROR: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <script>: XXXXXXXXXXXXXXXXXXXXXXX Loose route Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} rr [loose.c:91]: is_preloaded(): is_preloaded: No Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/socket_info.c:564]: grep_sock_info(): checking if host==us: 11==11 && [10.40.8.104] == [10.40.8.104] Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} tm [t_lookup.c:1346]: t_newtran(): msg (0xb72fb410) id=27/18445 global id=26/18445 T start=0xffffffff Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/socket_info.c:567]: grep_sock_info(): checking if port 5070 (advertise 5070) matches port 5060 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} tm [t_lookup.c:500]: t_lookup_request(): start searching: hash=21124, isACK=1 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} rr [loose.c:677]: after_strict(): Next hop: 'sip:10.40.8.104:5070;lr;ftag=1DoN4DknAgMG5nSNVGynmZgOtY9Ap6nP;did=e6d.fd02' is loose router Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} rr [loose.c:727]: after_strict(): The last route URI: 'sip:10.40.8.104:5070;lr;ftag=1DoN4DknAgMG5nSNVGynmZgOtY9Ap6nP;did=e6d.fd02' Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} tm [t_lookup.c:458]: matching_3261(): RFC3261 transaction matching failed - via branch [z9hG4bKPjvd1MSxMjv6dfOGdbAVxKz.iPtydNiEtQ] Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: ERROR: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <script>: XXXXXXXXXXXXXXXXXXXXXXX Loose route Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} tm [t_lookup.c:682]: t_lookup_request(): no transaction found Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} tm [t_lookup.c:1346]: t_newtran(): msg (0xb72fb410) id=25/18444 global id=24/18444 T start=0xffffffff Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} tm [t_funcs.c:287]: t_relay_to(): forwarding ACK statelessly Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} tm [t_lookup.c:500]: t_lookup_request(): start searching: hash=21124, isACK=1 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} tm [t_lookup.c:458]: matching_3261(): RFC3261 transaction matching failed - via branch [z9hG4bKPjvd1MSxMjv6dfOGdbAVxKz.iPtydNiEtQ] Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/dns_cache.c:3193]: dns_srv_sip_resolve(): (10.40.8.104, 0, 0), ip, ret=0 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/md5utils.c:67]: MD5StringArray(): MD5 calculated: 29cbe80853cc3d43347f3c0b4b643e4c Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/forward.c:557]: forward_request(): Sending: ACK sip:10.40.8.104:5070;lr;ftag=1DoN4DknAgMG5nSNVGynmZgOtY9Ap6nP;did=e6d.fd02 SIP/2.0^M Via: SIP/2.0/UDP 10.40.8.104:5070;branch=z9hG4bK4825.29cbe80853cc3d43347f3c0b4b643e4c.0^M Via: SIP/2.0/UDP 10.40.6.188:60223;received=10.40.6.188;rport=60223;branch=z9hG4bKPjvd1MSxMjv6dfOGdbAVxKz.iPtydNiEtQ^M Max-Forwards: 69^M From: <sip:proxydevice@10.40.8.104>;tag=1DoN4DknAgMG5nSNVGynmZgOtY9Ap6nP^M To: <sip:004112345@10.40.8.104>;tag=as21517b15^M Call-ID: otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy^M CSeq: 27457 ACK^M Content-Length: 0^M ^M . Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} tm [t_lookup.c:682]: t_lookup_request(): no transaction found Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/forward.c:559]: forward_request(): orig. len=442, new_len=517, proto=1 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} tm [t_funcs.c:287]: t_relay_to(): forwarding ACK statelessly Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/dns_cache.c:3193]: dns_srv_sip_resolve(): (10.40.8.104, 0, 0), ip, ret=0 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/md5utils.c:67]: MD5StringArray(): MD5 calculated: 29cbe80853cc3d43347f3c0b4b643e4c Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: <core> [core/udp_server.c:492]: udp_rcv_loop(): received on udp socket: (106/100/517) [[ACK sip:10.40.8.104:5070;lr;ftag=1DoN4DknAgMG5nSNVGynmZgOtY9Ap6nP;did=e6d.fd02 SIP/2.0 0D 0A Via: SIP/2.0]] Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/receive.c:353]: receive_msg(): request-route executed in: 2883 usec Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/forward.c:557]: forward_request(): Sending: ACK sip:10.40.8.104:5070;lr;ftag=1DoN4DknAgMG5nSNVGynmZgOtY9Ap6nP;did=e6d.fd02 SIP/2.0^M Via: SIP/2.0/UDP 10.40.8.104:5070;branch=z9hG4bK4825.29cbe80853cc3d43347f3c0b4b643e4c.0^M Via: SIP/2.0/UDP 10.40.6.188:60223;received=10.40.6.188;rport=60223;branch=z9hG4bKPjvd1MSxMjv6dfOGdbAVxKz.iPtydNiEtQ^M Max-Forwards: 69^M From: <sip:proxydevice@10.40.8.104>;tag=1DoN4DknAgMG5nSNVGynmZgOtY9Ap6nP^M To: <sip:004112345@10.40.8.104>;tag=as21517b15^M Call-ID: otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy^M CSeq: 27457 ACK^M Content-Length: 0^M ^M . Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: <core> [core/parser/msg_parser.c:610]: parse_msg(): SIP Request: Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:712]: dlg_lookup(): ref dlg 0xb4934aec with 1 -> 3 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:714]: dlg_lookup(): dialog id=8415 found on entry 3438 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: <core> [core/parser/msg_parser.c:612]: parse_msg(): method: <ACK> Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: <core> [core/parser/msg_parser.c:614]: parse_msg(): uri: <sip:10.40.8.104:5070;lr;ftag=1DoN4DknAgMG5nSNVGynmZgOtY9Ap6nP;did=e6d.fd02> Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:957]: dlg_unref_helper(): unref op on 0xb4934aec with 1 from dlg_hash.c:975 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:961]: dlg_unref_helper(): unref dlg 0xb4934aec with 1 -> 2 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: <core> [core/parser/msg_parser.c:616]: parse_msg(): version: <SIP/2.0> Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/forward.c:559]: forward_request(): orig. len=442, new_len=517, proto=1 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil) Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK4825.29cbe80853cc3d43347f3c0b4b643e4c.0>; state=16 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil) Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/receive.c:353]: receive_msg(): request-route executed in: 2527 usec Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:712]: dlg_lookup(): ref dlg 0xb4934aec with 1 -> 3 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: <core> [core/udp_server.c:492]: udp_rcv_loop(): received on udp socket: (106/100/517) [[ACK sip:10.40.8.104:5070;lr;ftag=1DoN4DknAgMG5nSNVGynmZgOtY9Ap6nP;did=e6d.fd02 SIP/2.0 0D 0A Via: SIP/2.0]] Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: <core> [core/parser/msg_parser.c:610]: parse_msg(): SIP Request: Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil) Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:714]: dlg_lookup(): dialog id=8415 found on entry 3438 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:957]: dlg_unref_helper(): unref op on 0xb4934aec with 1 from dlg_hash.c:975 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: <core> [core/parser/msg_parser.c:612]: parse_msg(): method: <ACK> Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil) Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: <core> [core/parser/msg_parser.c:498]: parse_headers(): Via found, flags=2 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:961]: dlg_unref_helper(): unref dlg 0xb4934aec with 1 -> 2 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil) Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil) Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: <core> [core/parser/msg_parser.c:500]: parse_headers(): this is the first via Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: <core> [core/parser/msg_parser.c:614]: parse_msg(): uri: <sip:10.40.8.104:5070;lr;ftag=1DoN4DknAgMG5nSNVGynmZgOtY9Ap6nP;did=e6d.fd02> Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil) Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil) Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 234, <received> = <10.40.6.188>; state=6 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 235, <rport> = <60223>; state=6 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bKPjvd1MSxMjv6dfOGdbAVxKz.iPtydNiEtQ>; state=16 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/xavp.c:495]: xavp_destroy_list(): destroying xavp list (nil) Mar 12 09:21:43 oAN /usr/sbin/kamailio[18445]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/receive.c:457]: receive_msg(): cleaning up Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil) Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: <core> [core/parser/msg_parser.c:616]: parse_msg(): version: <SIP/2.0> Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil) Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: <core> [core/parser/msg_parser.c:498]: parse_headers(): Via found, flags=78 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK4825.29cbe80853cc3d43347f3c0b4b643e4c.0>; state=16 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil) Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: <core> [core/parser/msg_parser.c:511]: parse_headers(): this is the second via Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil) Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=as21517b15 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/xavp.c:495]: xavp_destroy_list(): destroying xavp list (nil) Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: <core> [core/parser/msg_parser.c:498]: parse_headers(): Via found, flags=2 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18444]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/receive.c:457]: receive_msg(): cleaning up Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: <core> [core/parser/msg_parser.c:500]: parse_headers(): this is the first via Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: <core> [core/parser/msg_parser.c:171]: get_hdr_field(): <To> [44]; uri=[sip:004112345@10.40.8.104] Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 234, <received> = <10.40.6.188>; state=6 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 235, <rport> = <60223>; state=6 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: <core> [core/parser/msg_parser.c:174]: get_hdr_field(): to body [<sip:004112345@10.40.8.104>], to tag [as21517b15] Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: <core> [core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <27457> <ACK> Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bKPjvd1MSxMjv6dfOGdbAVxKz.iPtydNiEtQ>; state=16 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: <core> [core/receive.c:245]: receive_msg(): --- received sip message - request - call-id: [otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy] - cseq: [27457 ACK] Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: <core> [core/parser/msg_parser.c:185]: get_hdr_field(): content_length=0 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: <core> [core/parser/msg_parser.c:498]: parse_headers(): Via found, flags=78 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): found end of header Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: <core> [core/parser/msg_parser.c:511]: parse_headers(): this is the second via Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/receive.c:295]: receive_msg(): preparing to run routing scripts... Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=as21517b15 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sl [sl_funcs.c:397]: sl_filter_ACK(): too late to be a local ACK! Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: <core> [core/parser/msg_parser.c:171]: get_hdr_field(): <To> [44]; uri=[sip:004112345@10.40.8.104] Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=1DoN4DknAgMG5nSNVGynmZgOtY9Ap6nP Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: <core> [core/parser/msg_parser.c:174]: get_hdr_field(): to body [<sip:004112345@10.40.8.104>], to tag [as21517b15] Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: <core> [core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <27457> <ACK> Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: <core> [core/receive.c:245]: receive_msg(): --- received sip message - request - call-id: [otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy] - cseq: [27457 ACK] Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: <core> [core/parser/msg_parser.c:185]: get_hdr_field(): content_length=0 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:769]: internal_get_dlg(): ref dlg 0xb4934aec with 1 -> 3 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): found end of header Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/receive.c:295]: receive_msg(): preparing to run routing scripts... Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:772]: internal_get_dlg(): dialog callid='otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy' found on entry 3438, dir=1 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sl [sl_funcs.c:397]: sl_filter_ACK(): too late to be a local ACK! Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_profile.c:536]: set_current_dialog(): setting current dialog [3438:8415] Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:1158]: next_state_dlg(): dialog 0xb4934aec changed from state 4 to state 4, due event 6 (ref 3) Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=1DoN4DknAgMG5nSNVGynmZgOtY9Ap6nP Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_timer.c:110]: insert_dialog_timer_unsafe(): inserting 0xb4934b30 for 12143697 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_handlers.c:1480]: dlg_onroute(): sequential request successfully processed Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:769]: internal_get_dlg(): ref dlg 0xb4934aec with 1 -> 4 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:772]: internal_get_dlg(): dialog callid='otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy' found on entry 3438, dir=1 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} rr [record.c:925]: add_rr_param(): rr_param_buf=<;did=e6d.fd02> Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:957]: dlg_unref_helper(): unref op on 0xb4934aec with 1 from dlg_hash.c:975 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:961]: dlg_unref_helper(): unref dlg 0xb4934aec with 1 -> 3 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_profile.c:536]: set_current_dialog(): setting current dialog [3438:8415] Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} pv [pv_core.c:1031]: pv_get_useragent(): no User-Agent header Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} maxfwd [mf_funcs.c:74]: is_maxfwd_present(): value = 69 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:1158]: next_state_dlg(): dialog 0xb4934aec changed from state 4 to state 4, due event 6 (ref 3) Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:247]: check_ruri_sip_version(): check_ruri_sip_version entered Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_timer.c:110]: insert_dialog_timer_unsafe(): inserting 0xb4934b30 for 12143697 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:270]: check_ruri_sip_version(): check_ruri_sip_version passed Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_handlers.c:1480]: dlg_onroute(): sequential request successfully processed Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} rr [record.c:925]: add_rr_param(): rr_param_buf=<;did=e6d.fd02> Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:277]: check_ruri_scheme(): check_ruri_scheme entered Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:957]: dlg_unref_helper(): unref op on 0xb4934aec with 1 from dlg_hash.c:975 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:297]: check_ruri_scheme(): check_ruri_scheme passed Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:961]: dlg_unref_helper(): unref dlg 0xb4934aec with 1 -> 2 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:305]: check_required_headers(): check_required_headers entered Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:313]: check_required_headers(): check_required_headers passed Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} pv [pv_core.c:1031]: pv_get_useragent(): no User-Agent header Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:479]: check_cseq_method(): check_cseq_method entered Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:512]: check_cseq_method(): check_cseq_method passed Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} maxfwd [mf_funcs.c:74]: is_maxfwd_present(): value = 69 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:521]: check_cseq_value(): check_cseq_value entered Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:549]: check_cseq_value(): check_cseq_value passed Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:247]: check_ruri_sip_version(): check_ruri_sip_version entered Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:558]: check_cl(): check_cl entered Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:583]: check_cl(): check_cl passed Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:270]: check_ruri_sip_version(): check_ruri_sip_version passed Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:595]: check_expires_value(): check_expires_value entered Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:277]: check_ruri_scheme(): check_ruri_scheme entered Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:632]: check_expires_value(): no expires header found Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:297]: check_ruri_scheme(): check_ruri_scheme passed Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:305]: check_required_headers(): check_required_headers entered Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:728]: check_parse_uris(): check_parse_uris entered Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:732]: check_parse_uris(): parsing ruri Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:313]: check_required_headers(): check_required_headers passed Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:479]: check_cseq_method(): check_cseq_method entered Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:746]: check_parse_uris(): looking up From header Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:786]: check_parse_uris(): parsing From URI Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:512]: check_cseq_method(): check_cseq_method passed Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:521]: check_cseq_value(): check_cseq_value entered Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:804]: check_parse_uris(): looking up To header Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:826]: check_parse_uris(): check_parse_uris(): parsing To URI Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:549]: check_cseq_value(): check_cseq_value passed Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:558]: check_cl(): check_cl entered Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:871]: check_parse_uris(): check_parse_uris passed Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:583]: check_cl(): check_cl passed Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:595]: check_expires_value(): check_expires_value entered Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity_mod.c:254]: w_sanity_check(): sanity checks result: 1 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:632]: check_expires_value(): no expires header found Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: ERROR: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <script>: XXXXXXXXXXXXXXXXXXXXXXX WITHINDLG Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:728]: check_parse_uris(): check_parse_uris entered Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} siputils [checks.c:123]: has_totag(): totag found Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} rr [loose.c:114]: find_first_route(): No Route headers found Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} rr [loose.c:961]: loose_route(): There is no Route HF Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:732]: check_parse_uris(): parsing ruri Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:746]: check_parse_uris(): looking up From header Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: ERROR: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <script>: XXXXXXXXXXXXXXXXXXXXXXX WITHINDLG Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: ERROR: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <script>: XXXXXXXXXXXXXXXXXXXXXXX ACK Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} tm [t_lookup.c:1043]: t_check_msg(): msg (0xb72fb410) id=24/18448 global id=23/18448 T start=0xffffffff Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} tm [t_lookup.c:500]: t_lookup_request(): start searching: hash=21124, isACK=1 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:786]: check_parse_uris(): parsing From URI Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} tm [t_lookup.c:458]: matching_3261(): RFC3261 transaction matching failed - via branch [z9hG4bK4825.29cbe80853cc3d43347f3c0b4b643e4c.0] Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:804]: check_parse_uris(): looking up To header Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:826]: check_parse_uris(): check_parse_uris(): parsing To URI Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} tm [t_lookup.c:682]: t_lookup_request(): no transaction found Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} tm [t_lookup.c:1113]: t_check_msg(): msg (0xb72fb410) id=24/18448 global id=24/18448 T end=(nil) Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: ERROR: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <script>: XXXXXXXXXXXXXXXXXXXXXXX ignore Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/receive.c:353]: receive_msg(): request-route executed in: 1941 usec Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity.c:871]: check_parse_uris(): check_parse_uris passed Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:712]: dlg_lookup(): ref dlg 0xb4934aec with 1 -> 3 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} sanity [sanity_mod.c:254]: w_sanity_check(): sanity checks result: 1 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:714]: dlg_lookup(): dialog id=8415 found on entry 3438 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: ERROR: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <script>: XXXXXXXXXXXXXXXXXXXXXXX WITHINDLG Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} siputils [checks.c:123]: has_totag(): totag found Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} rr [loose.c:114]: find_first_route(): No Route headers found Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} rr [loose.c:961]: loose_route(): There is no Route HF Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:957]: dlg_unref_helper(): unref op on 0xb4934aec with 1 from dlg_hash.c:975 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:961]: dlg_unref_helper(): unref dlg 0xb4934aec with 1 -> 2 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: ERROR: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <script>: XXXXXXXXXXXXXXXXXXXXXXX WITHINDLG Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: ERROR: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <script>: XXXXXXXXXXXXXXXXXXXXXXX ACK Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} tm [t_lookup.c:1043]: t_check_msg(): msg (0xb72fb410) id=27/18446 global id=26/18446 T start=0xffffffff Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} tm [t_lookup.c:500]: t_lookup_request(): start searching: hash=21124, isACK=1 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil) Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil) Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} tm [t_lookup.c:458]: matching_3261(): RFC3261 transaction matching failed - via branch [z9hG4bK4825.29cbe80853cc3d43347f3c0b4b643e4c.0] Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} tm [t_lookup.c:682]: t_lookup_request(): no transaction found Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil) Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil) Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} tm [t_lookup.c:1113]: t_check_msg(): msg (0xb72fb410) id=27/18446 global id=27/18446 T end=(nil) Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: ERROR: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <script>: XXXXXXXXXXXXXXXXXXXXXXX ignore Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/receive.c:353]: receive_msg(): request-route executed in: 2123 usec Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil) Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:712]: dlg_lookup(): ref dlg 0xb4934aec with 1 -> 3 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil) Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/xavp.c:495]: xavp_destroy_list(): destroying xavp list (nil) Mar 12 09:21:43 oAN /usr/sbin/kamailio[18448]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/receive.c:457]: receive_msg(): cleaning up Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:714]: dlg_lookup(): dialog id=8415 found on entry 3438 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:957]: dlg_unref_helper(): unref op on 0xb4934aec with 1 from dlg_hash.c:975 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} dialog [dlg_hash.c:961]: dlg_unref_helper(): unref dlg 0xb4934aec with 1 -> 2 Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil) Mar 12 09:21:43 oAN last message repeated 5 times Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/xavp.c:495]: xavp_destroy_list(): destroying xavp list (nil) Mar 12 09:21:43 oAN /usr/sbin/kamailio[18446]: DEBUG: {1 27457 ACK otoEsJ246gIFd.4F3Z6nE7PwA9XsgKCy} <core> [core/receive.c:457]: receive_msg(): cleaning up Mar 12 09:21:43 oAN /usr/sbin/kamailio[18449]: DEBUG: <core> [core/udp_server.c:492]: udp_rcv_loop(): received on udp socket: (106/100/1091) [[SIP/2.0 200 OK 0D 0A Via: SIP/2.0/UDP 10.40.8.104:5070;branch=z9hG4bK4825.fc814778ec04597ae4759a9771bfef0]]