I could not find anything related to error. Below are the full detailed logs. Again thanks for you help.  

Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/udp_server.c:492]: udp_rcv_loop(): received on udp socket: (106/100/963) [[INVITE sip:923335550609@sip.talkhomeappcall.com;transport=UDP SIP/2.0 0D  0A Via: SIP/2.0/UDP 115.186.137.]]
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:604]: parse_msg(): SIP Request:
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:606]: parse_msg():  method:  <INVITE>
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:608]: parse_msg():  uri:     <sip:923335550609@sip.talkhomeappcall.com;transport=UDP>
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:610]: parse_msg():  version: <SIP/2.0>
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK-524287-1---5e6fadd00170a89c>; state=16
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:492]: parse_headers(): Via found, flags=2
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:494]: parse_headers(): this is the first via
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=10
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:171]: get_hdr_field(): <To> [58]; uri=[sip:923335550609@sip.talkhomeappcall.com;transport=UDP]
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:172]: get_hdr_field(): to body [<sip:923335550609@sip.talkhomeappcall.com;transport=UDP>#015#012]
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <1> <INVITE>
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/receive.c:205]: receive_msg(): --- received sip message - request - call-id: [v51-8AifZ2mXi4RFMRej9A..] - cseq: [1 INVITE]
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/receive.c:248]: receive_msg(): preparing to run routing scripts...
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:183]: get_hdr_field(): content_length=245
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): found end of header
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=dc4e5a14
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: sanity [sanity_mod.c:256]: w_sanity_check(): sanity checks result: 1
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: maxfwd [mf_funcs.c:74]: is_maxfwd_present(): value = 70
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: maxfwd [maxfwd.c:148]: process_maxfwd_header(): value 70 decreased to 50
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: siputils [sipops.c:159]: is_first_hop(): no 2nd via found - first hop
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: textops [textops.c:3083]: has_body_helper(): content type is 196611
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/parser/sdp/sdp_helpr_funcs.c:504]: extract_mediaip(): located IP address [115.186.137.147] in `o=' field
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/parser/sdp/sdp_helpr_funcs.c:504]: extract_mediaip(): located IP address [115.186.137.147] in `c=' field
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: rtpengine [rtpengine_funcs.c:140]: check_content_type(): type <application/sdp> found valid
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: rtpengine [rtpengine.c:2704]: select_rtpp_node_old(): rtpengine hash table lookup failed to find node for calllen=24 callid=v51-8AifZ2mXi4RFMRej9A.. viabranch=
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: rtpengine [rtpengine.c:2251]: rtpp_function_call(): proxy reply: d3:sdp321:v=0#015#012o=Z 0 0 IN IP4 18.130.57.226#015#012s=Z#015#012c=IN IP4 18.130.57.226#015#012t=0 0#015#012m=audio 20324 RTP/AVP 3 110 8 0 97 101#015#012a=rtpmap:3 GSM/8000#015#012a=rtpmap:110 speex/8000#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:0 PCMU/8000#015#012a=rtpmap:97 iLBC/8000#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:97 mode=30#015#012a=fmtp:101 0-16#015#012a=sendrecv#015#012a=rtcp:20325#015#0126:result2:oke
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: rtpengine [rtpengine.c:2320]: rtpp_function_call(): rtpengine hash table insert node=udp:127.0.0.1:2223 for calllen=24 callid=v51-8AifZ2mXi4RFMRej9A.. viabranch=
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: siputils [checks.c:120]: has_totag(): no totag
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: rr [loose.c:1209]: is_direction(): param ftag not found
Jul 12 08:12:00 sip kamailio[22303]: INFO: <script>: v51-8AifZ2mXi4RFMRej9A..|log|originated from User-Agent: Z 3.7.30891 r30851
Jul 12 08:12:00 sip kamailio[22303]: INFO: <script>: [R-ATTEMPT-AUTHORIZATION:v51-8AifZ2mXi4RFMRej9A..] -> In authentication for INVITE against 923135082344@sip.talkhomeappcall.com
Jul 12 08:12:00 sip kamailio[22303]: INFO: <script>: [R-ATTEMPT-AUTHORIZATION:v51-8AifZ2mXi4RFMRej9A..] -> got password: e5ef068edf311111111000002124bf90 from cache against 923135082344@sip.talkhomeappcall.com
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: auth [auth_mod.c:847]: w_pv_auth_check(): realm [sip.talkhomeappcall.com] flags [1] checks [1]
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: auth [api.c:78]: pre_auth(): Credentials with realm 'sip.talkhomeappcall.com' not found
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: auth [auth_mod.c:508]: pv_authenticate(): no credentials
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: auth [challenge.c:165]: get_challenge_hf(): realm='sip.talkhomeappcall.com'
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: auth [challenge.c:275]: get_challenge_hf(): auth: 'Proxy-Authenticate: Digest realm="sip.talkhomeappcall.com", nonce="W0cOfFtHDVBWPzjaU1WezcAAr+iIrJXl"#015#012'
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: sl [sl.c:282]: send_reply(): reply in stateless mode (sl)
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/msg_translator.c:159]: check_via_address(): (115.186.137.147, 115.186.137.147, 0)
Jul 12 08:12:00 sip kamailio[22303]: WARNING: <script>: [R-CHECK-AUTHORIZATION:v51-8AifZ2mXi4RFMRej9A..] -> issued auth challenge to failed INVITE attempt for 923135082344@sip.talkhomeappcall.com from IP 115.186.137.147:61717
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/receive.c:289]: receive_msg(): request-route executed in: 3405 usec
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/xavp.c:446]: xavp_destroy_list(): destroying xavp list (nil)
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/receive.c:378]: receive_msg(): cleaning up
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/parser/sdp/sdp.c:794]: free_sdp(): _sdp = 0x7f3ac975eb18
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/parser/sdp/sdp.c:796]: free_sdp(): sdp = 0x7f3ac975feb8
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/parser/sdp/sdp.c:798]: free_sdp(): session = 0x7f3ac9729ce0
Jul 12 08:12:00 sip kamailio[22302]: DEBUG: <core> [core/udp_server.c:492]: udp_rcv_loop(): received on udp socket: (106/100/419) [[ACK sip:923335550609@sip.talkhomeappcall.com;transport=UDP SIP/2.0 0D  0A Via: SIP/2.0/UDP 115.186.137.147]]
Jul 12 08:12:00 sip kamailio[22302]: DEBUG: <core> [core/parser/msg_parser.c:604]: parse_msg(): SIP Request:
Jul 12 08:12:00 sip kamailio[22302]: DEBUG: <core> [core/parser/msg_parser.c:606]: parse_msg():  method:  <ACK>
Jul 12 08:12:00 sip kamailio[22302]: DEBUG: <core> [core/parser/msg_parser.c:608]: parse_msg():  uri:     <sip:923335550609@sip.talkhomeappcall.com;transport=UDP>
Jul 12 08:12:00 sip kamailio[22302]: DEBUG: <core> [core/parser/msg_parser.c:610]: parse_msg():  version: <SIP/2.0>
Jul 12 08:12:00 sip kamailio[22302]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK-524287-1---5e6fadd00170a89c>; state=16
Jul 12 08:12:00 sip kamailio[22302]: DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5
Jul 12 08:12:00 sip kamailio[22302]: DEBUG: <core> [core/parser/msg_parser.c:492]: parse_headers(): Via found, flags=2
Jul 12 08:12:00 sip kamailio[22302]: DEBUG: <core> [core/parser/msg_parser.c:494]: parse_headers(): this is the first via
Jul 12 08:12:00 sip kamailio[22302]: DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=24981d2e17dbb5775661067d94809cd2.e7c9
Jul 12 08:12:00 sip kamailio[22302]: DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29
Jul 12 08:12:00 sip kamailio[22302]: DEBUG: <core> [core/parser/msg_parser.c:171]: get_hdr_field(): <To> [100]; uri=[sip:923335550609@sip.talkhomeappcall.com;transport=UDP]
Jul 12 08:12:00 sip kamailio[22302]: DEBUG: <core> [core/parser/msg_parser.c:172]: get_hdr_field(): to body [<sip:923335550609@sip.talkhomeappcall.com;transport=UDP>]
Jul 12 08:12:00 sip kamailio[22302]: DEBUG: <core> [core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <1> <ACK>
Jul 12 08:12:00 sip kamailio[22302]: DEBUG: <core> [core/receive.c:205]: receive_msg(): --- received sip message - request - call-id: [v51-8AifZ2mXi4RFMRej9A..] - cseq: [1 ACK]
Jul 12 08:12:00 sip kamailio[22302]: DEBUG: <core> [core/receive.c:248]: receive_msg(): preparing to run routing scripts...
Jul 12 08:12:00 sip kamailio[22302]: DEBUG: sl [sl_funcs.c:406]: sl_filter_ACK(): SL local ACK found -> dropping it!
Jul 12 08:12:00 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:00 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:00 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:00 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:00 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:00 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:00 sip kamailio[22302]: DEBUG: <core> [core/xavp.c:446]: xavp_destroy_list(): destroying xavp list (nil)
Jul 12 08:12:00 sip kamailio[22302]: DEBUG: <core> [core/receive.c:378]: receive_msg(): cleaning up
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/udp_server.c:492]: udp_rcv_loop(): received on udp socket: (106/100/1208) [[INVITE sip:923335550609@sip.talkhomeappcall.com;transport=UDP SIP/2.0 0D  0A Via: SIP/2.0/UDP 115.186.137.]]
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:604]: parse_msg(): SIP Request:
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:606]: parse_msg():  method:  <INVITE>
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:608]: parse_msg():  uri:     <sip:923335550609@sip.talkhomeappcall.com;transport=UDP>
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:610]: parse_msg():  version: <SIP/2.0>
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK-524287-1---6a391e4fb0f8a8f6>; state=16
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:492]: parse_headers(): Via found, flags=2
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:494]: parse_headers(): this is the first via
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=10
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:171]: get_hdr_field(): <To> [58]; uri=[sip:923335550609@sip.talkhomeappcall.com;transport=UDP]
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:172]: get_hdr_field(): to body [<sip:923335550609@sip.talkhomeappcall.com;transport=UDP>#015#012]
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <2> <INVITE>
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/receive.c:205]: receive_msg(): --- received sip message - request - call-id: [v51-8AifZ2mXi4RFMRej9A..] - cseq: [2 INVITE]
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/receive.c:248]: receive_msg(): preparing to run routing scripts...
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:183]: get_hdr_field(): content_length=245
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): found end of header
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=dc4e5a14
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: sanity [sanity_mod.c:256]: w_sanity_check(): sanity checks result: 1
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: maxfwd [mf_funcs.c:74]: is_maxfwd_present(): value = 70
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: maxfwd [maxfwd.c:148]: process_maxfwd_header(): value 70 decreased to 50
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: siputils [sipops.c:159]: is_first_hop(): no 2nd via found - first hop
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: textops [textops.c:3083]: has_body_helper(): content type is 196611
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/parser/sdp/sdp_helpr_funcs.c:504]: extract_mediaip(): located IP address [115.186.137.147] in `o=' field
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/parser/sdp/sdp_helpr_funcs.c:504]: extract_mediaip(): located IP address [115.186.137.147] in `c=' field
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: rtpengine [rtpengine_funcs.c:140]: check_content_type(): type <application/sdp> found valid
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: rtpengine [rtpengine.c:2708]: select_rtpp_node_old(): rtpengine hash table lookup find node=udp:127.0.0.1:2223 for calllen=24 callid=v51-8AifZ2mXi4RFMRej9A.. viabranch=
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: rtpengine [rtpengine.c:2251]: rtpp_function_call(): proxy reply: d3:sdp321:v=0#015#012o=Z 0 0 IN IP4 18.130.57.226#015#012s=Z#015#012c=IN IP4 18.130.57.226#015#012t=0 0#015#012m=audio 20324 RTP/AVP 3 110 8 0 97 101#015#012a=rtpmap:3 GSM/8000#015#012a=rtpmap:110 speex/8000#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:0 PCMU/8000#015#012a=rtpmap:97 iLBC/8000#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:97 mode=30#015#012a=fmtp:101 0-16#015#012a=sendrecv#015#012a=rtcp:20325#015#0126:result2:oke
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: siputils [checks.c:120]: has_totag(): no totag
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: rr [loose.c:1209]: is_direction(): param ftag not found
Jul 12 08:12:00 sip kamailio[22303]: INFO: <script>: v51-8AifZ2mXi4RFMRej9A..|log|originated from User-Agent: Z 3.7.30891 r30851
Jul 12 08:12:00 sip kamailio[22303]: INFO: <script>: [R-ATTEMPT-AUTHORIZATION:v51-8AifZ2mXi4RFMRej9A..] -> In authentication for INVITE against 923135082344@sip.talkhomeappcall.com
Jul 12 08:12:00 sip kamailio[22303]: INFO: <script>: [R-ATTEMPT-AUTHORIZATION:v51-8AifZ2mXi4RFMRej9A..] -> got password: e5ef068edf311111111000002124bf90 from cache against 923135082344@sip.talkhomeappcall.com
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: auth [auth_mod.c:847]: w_pv_auth_check(): realm [sip.talkhomeappcall.com] flags [1] checks [1]
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: auth [api.c:88]: pre_auth(): digest-algo: MD5 parsed value: 1
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: auth [api.c:292]: auth_check_response(): Our result = 'bae0c3bad25ef6951fcc9142dbf6e29c'
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: auth [api.c:299]: auth_check_response(): Authorization is OK
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: sl [sl.c:282]: send_reply(): reply in stateless mode (sl)
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/msg_translator.c:159]: check_via_address(): (115.186.137.147, 115.186.137.147, 0)
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: registrar [lookup.c:256]: lookup_helper(): contact for [923335550609] found by address
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: tm [t_lookup.c:1320]: t_newtran(): msg id=1105 , global msg id=1103 , T on entrance=(nil)
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: tm [t_lookup.c:477]: t_lookup_request(): start searching: hash=47588, isACK=0
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: tm [t_lookup.c:435]: matching_3261(): RFC3261 transaction matching failed
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: tm [t_lookup.c:659]: t_lookup_request(): no transaction found
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/md5utils.c:67]: MD5StringArray(): MD5 calculated: c598ebabb2493d5c9aebf673208c6bea
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: tsilo [ts_store.c:80]: ts_store(): storing transaction 47588:281286645 for r-uri: 923335550609
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: tsilo [ts_hash.c:263]: insert_ts_urecord(): urecord entry 0x7f3ac4daaad8
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: tsilo [ts_handlers.c:56]: ts_set_tm_callbacks(): registered TMCB for transaction 47588:281286645
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: tsilo [ts_store.c:103]: ts_store(): transaction 47588:281286645 (ruri: 923335550609) inserted
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: htable [ht_var.c:90]: pv_set_ht_cell(): set value for $sht(vtp=>stored::923335550609)
Jul 12 08:12:00 sip kamailio[22303]: INFO: <script>: [USER-LOOKUP:v51-8AifZ2mXi4RFMRej9A..] -> stored transaction [47588:281286645] 923135082344=> 923335550609
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: tm [t_lookup.c:1320]: t_newtran(): msg id=1105 , global msg id=1105 , T on entrance=0x7f3ac5004448
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: tm [t_lookup.c:1324]: t_newtran(): transaction already in process 0x7f3ac5004448
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/msg_translator.c:424]: clen_builder(): content-length: 321 (321)
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/msg_translator.c:159]: check_via_address(): (115.186.137.147, 115.186.137.147, 0)
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: tm [t_funcs.c:372]: t_relay_to(): new transaction forwarded
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: http_async_client [async_http.c:731]: header_list_add(): stored new http header: [User-Agent: testheader]
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: http_async_client [async_http.c:731]: header_list_add(): stored new http header: [Host: app.com]
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: http_async_client [async_http.c:731]: header_list_add(): stored new http header: [Authorization: Basic NDQ3N00000000000011111TQ=]
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: http_async_client [async_http.c:731]: header_list_add(): stored new http header: [Content-Type: application/json]
Jul 12 08:12:00 sip kamailio[22303]: INFO: <script>: To User: 923335550609 From User: 923135082344
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: http_async_client [async_http.c:472]: async_send_query(): transaction suspended [47588:281286645]
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client [async_http.c:388]: notification_socket_cb(): query received: [http://app.com/push/notification/923335550609] (0x7f3ac5048008)
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: http_async_client [async_http.c:625]: async_push_query(): query sent [http://app.com/push/notification/923335550609] (0x7f3ac5048008) to worker 4
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:423]: new_request(): received query http://app.com/push/notification/923335550609 with timeout 5000, tls_verify_peer 1, tls_verify_host 1 (param=0x7f3ac5048008)
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/receive.c:289]: receive_msg(): request-route executed in: 5910 usec
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x28b12f0 (8)-> 0x28b12f0 (9)
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x28b12f0 is 867
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client [hm_hash.c:119]: build_http_m_cell(): hash id for 0x28b12f0 is 867
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client [hm_hash.c:130]: link_http_m_cell(): linking new cell 0x7f3ac4ff5778 to table 0x7f3ac4fc5418 [867]
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:530]: new_request(): Adding easy 0x28b12f0 to multi 0x289a570 (http://app.com/push/notification/923335550609)
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:53]: multi_timer_cb(): multi_timer_cb: Setting timeout to 1 ms
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/xavp.c:446]: xavp_destroy_list(): destroying xavp list (nil)
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/receive.c:378]: receive_msg(): cleaning up
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/parser/sdp/sdp.c:794]: free_sdp(): _sdp = 0x7f3ac975eb18
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/parser/sdp/sdp.c:796]: free_sdp(): sdp = 0x7f3ac972e418
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/parser/sdp/sdp.c:798]: free_sdp(): session = 0x7f3ac9729ce0
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:67]: timer_cb(): timeout on socket -1
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:53]: multi_timer_cb(): multi_timer_cb: Setting timeout to 1 ms
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:561]: check_multi_info(): REMAINING: 1
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:67]: timer_cb(): timeout on socket -1
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:53]: multi_timer_cb(): multi_timer_cb: Setting timeout to 1 ms
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:561]: check_multi_info(): REMAINING: 1
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:67]: timer_cb(): timeout on socket -1
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:53]: multi_timer_cb(): multi_timer_cb: Setting timeout to 1 ms
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:561]: check_multi_info(): REMAINING: 1
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:67]: timer_cb(): timeout on socket -1
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:53]: multi_timer_cb(): multi_timer_cb: Setting timeout to 3 ms
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:561]: check_multi_info(): REMAINING: 1
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:67]: timer_cb(): timeout on socket -1
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:53]: multi_timer_cb(): multi_timer_cb: Setting timeout to 1 ms
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:561]: check_multi_info(): REMAINING: 1
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:67]: timer_cb(): timeout on socket -1
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:161]: sock_cb(): socket callback: s=11 e=0x28b12f0 what=OUT
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:179]: sock_cb(): Adding data: OUT
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x28b12f0 (8)-> 0x28b12f0 (9)
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x28b12f0 is 867
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x28b12f0 found on table entry 867
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:615]: setsock(): added event 0x28ba160 to socket 11
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:53]: multi_timer_cb(): multi_timer_cb: Setting timeout to 199 ms
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:561]: check_multi_info(): REMAINING: 1
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x28b12f0 (8)-> 0x28b12f0 (9)
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x28b12f0 is 867
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x28b12f0 found on table entry 867
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:96]: event_cb(): activity 4 on socket 11: action 2
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:129]: event_cb(): performing action 2 on socket 11
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:161]: sock_cb(): socket callback: s=11 e=0x28b12f0 what=IN
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:184]: sock_cb(): Changing action from OUT to IN
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:615]: setsock(): added event 0x28ba160 to socket 11
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:131]: event_cb(): action 2 on socket 11 performed
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:561]: check_multi_info(): REMAINING: 1
Jul 12 08:12:01 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:67]: timer_cb(): timeout on socket -1
Jul 12 08:12:01 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:561]: check_multi_info(): REMAINING: 1
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core> [core/udp_server.c:492]: udp_rcv_loop(): received on udp socket: (118/100/635) [[SIP/2.0 180 Ringing 0D  0A CSeq: 2 INVITE 0D  0A Call-ID: v51-8AifZ2mXi4RFMRej9A.. 0D  0A From: <sip:923135082344@sip.]]
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core> [core/parser/msg_parser.c:614]: parse_msg(): SIP Reply  (status):
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core> [core/parser/msg_parser.c:616]: parse_msg():  version: <SIP/2.0>
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core> [core/parser/msg_parser.c:618]: parse_msg():  status:  <180>
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core> [core/parser/msg_parser.c:620]: parse_msg():  reason:  <Ringing>
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core> [core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <2> <INVITE>
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=26d24c34
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core> [core/parser/msg_parser.c:171]: get_hdr_field(): <To> [71]; uri=[sip:923335550609@sip.talkhomeappcall.com;transport=UDP]
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core> [core/parser/msg_parser.c:172]: get_hdr_field(): to body [<sip:923335550609@sip.talkhomeappcall.com;transport=UDP>]
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK4e9b.c598ebabb2493d5c9aebf673208c6bea.0>; state=9
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core> [core/parser/parse_via.c:2681]: parse_via(): parsing via: next via
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 235, <rport> = <61717>; state=6
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK-524287-1---6a391e4fb0f8a8f6>; state=16
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core> [core/parser/msg_parser.c:492]: parse_headers(): Via found, flags=2
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core> [core/parser/msg_parser.c:494]: parse_headers(): this is the first via
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core> [core/receive.c:205]: receive_msg(): --- received sip message - reply - call-id: [v51-8AifZ2mXi4RFMRej9A..] - cseq: [2 INVITE]
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: tm [t_lookup.c:1019]: t_check_msg(): msg (0x7f3ac975e930) id=1137 global id=1135 T start=(nil)
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: tm [t_lookup.c:897]: t_reply_matching(): t_reply_matching: hash 47588 label 0 branch 0
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: tm [t_lookup.c:951]: t_reply_matching(): reply (0x7f3ac975e930) matched an active transaction (T=0x7f3ac5004448)!
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: tm [t_lookup.c:1088]: t_check_msg(): msg (0x7f3ac975e930) id=1137 global id=1137 T end=0x7f3ac5004448
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: tm [t_reply.c:2207]: reply_received(): org. status uas=0, uac[0]=0 local=0 is_invite=1)
Jul 12 08:12:01 sip kamailio[22302]: INFO: <script>: [R-EXTERNAL_REPLY:v51-8AifZ2mXi4RFMRej9A..] -> saw reply to METHOD:INVITE RESPONSE:'180 Ringing' from 115.186.137.147:5060
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: tm [t_lookup.c:1019]: t_check_msg(): msg (0x7f3ac975e930) id=1137 global id=1137 T start=0x7f3ac5004448
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: tm [t_lookup.c:1091]: t_check_msg(): T (0x7f3ac5004448) already found for msg (0x7f3ac975e930)!
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core> [core/parser/msg_parser.c:183]: get_hdr_field(): content_length=0
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): found end of header
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core> [core/socket_info.c:564]: grep_sock_info(): checking if host==us: 13==12 && [18.130.57.226] == [172.31.21.87]
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core> [core/socket_info.c:583]: grep_sock_info(): checking advertise if host==us: 13==13 && [18.130.57.226] == [18.130.57.226]
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: textops [textops.c:3063]: has_body_helper(): content length is zero
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: tm [t_reply.c:1263]: t_should_relay_response(): ->>>>>>>>> T_code=0, new_code=180
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: tm [t_reply.c:1786]: relay_reply(): branch=0, save=0, relay=0 icode=0
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core> [core/msg_translator.c:2265]: generate_res_buf_from_sip_res(): old size: 635, new size: 552
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core> [core/msg_translator.c:2283]: generate_res_buf_from_sip_res(): copied size: orig:573, new: 490, rest: 62 msg=#012SIP/2.0 180 Ringing#015#012CSeq: 2 INVITE#015#012Call-ID: v51-8AifZ2mXi4RFMRej9A..#015#012From: <sip:923135082344@sip.talkhomeappcall.com;transport=UDP>;tag=dc4e5a14#015#012To: <sip:923335550609@sip.talkhomeappcall.com;transport=UDP>;tag=26d24c34#015#012Via: SIP/2.0/UDP 115.186.137.147:61717;rport=61717;branch=z9hG4bK-524287-1---6a391e4fb0f8a8f6#015#012Record-Route: <sip:18.130.57.226;lr=on;ftag=dc4e5a14>#015#012Contact: "923335550609" <sip:923335550609@115.186.137.147:5060;transport=udp;registering_acc=sip_talkhomeappcall_com>#015#012User-Agent: Jitsi2.10.5550Windows 10#015#012Content-Length: 0
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core> [core/receive.c:362]: receive_msg(): reply-route executed in: 2261 usec
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core> [core/xavp.c:446]: xavp_destroy_list(): destroying xavp list (nil)
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core> [core/receive.c:378]: receive_msg(): cleaning up
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core> [core/udp_server.c:492]: udp_rcv_loop(): received on udp socket: (118/100/635) [[SIP/2.0 180 Ringing 0D  0A CSeq: 2 INVITE 0D  0A Call-ID: v51-8AifZ2mXi4RFMRej9A.. 0D  0A From: <sip:923135082344@sip.]]
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:614]: parse_msg(): SIP Reply  (status):
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:616]: parse_msg():  version: <SIP/2.0>
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:618]: parse_msg():  status:  <180>
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:620]: parse_msg():  reason:  <Ringing>
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <2> <INVITE>
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=26d24c34
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:171]: get_hdr_field(): <To> [71]; uri=[sip:923335550609@sip.talkhomeappcall.com;transport=UDP]
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:172]: get_hdr_field(): to body [<sip:923335550609@sip.talkhomeappcall.com;transport=UDP>]
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK4e9b.c598ebabb2493d5c9aebf673208c6bea.0>; state=9
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core> [core/parser/parse_via.c:2681]: parse_via(): parsing via: next via
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 235, <rport> = <61717>; state=6
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK-524287-1---6a391e4fb0f8a8f6>; state=16
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:492]: parse_headers(): Via found, flags=2
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:494]: parse_headers(): this is the first via
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core> [core/receive.c:205]: receive_msg(): --- received sip message - reply - call-id: [v51-8AifZ2mXi4RFMRej9A..] - cseq: [2 INVITE]
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: tm [t_lookup.c:1019]: t_check_msg(): msg (0x7f3ac975e930) id=1106 global id=1105 T start=0xffffffffffffffff
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: tm [t_lookup.c:897]: t_reply_matching(): t_reply_matching: hash 47588 label 0 branch 0
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: tm [t_lookup.c:951]: t_reply_matching(): reply (0x7f3ac975e930) matched an active transaction (T=0x7f3ac5004448)!
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: tm [t_lookup.c:1088]: t_check_msg(): msg (0x7f3ac975e930) id=1106 global id=1106 T end=0x7f3ac5004448
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: tm [t_reply.c:2207]: reply_received(): org. status uas=180, uac[0]=180 local=0 is_invite=1)
Jul 12 08:12:01 sip kamailio[22303]: INFO: <script>: [R-EXTERNAL_REPLY:v51-8AifZ2mXi4RFMRej9A..] -> saw reply to METHOD:INVITE RESPONSE:'180 Ringing' from 115.186.137.147:5060
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: tm [t_lookup.c:1019]: t_check_msg(): msg (0x7f3ac975e930) id=1106 global id=1106 T start=0x7f3ac5004448
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: tm [t_lookup.c:1091]: t_check_msg(): T (0x7f3ac5004448) already found for msg (0x7f3ac975e930)!
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:183]: get_hdr_field(): content_length=0
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): found end of header
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core> [core/socket_info.c:564]: grep_sock_info(): checking if host==us: 13==12 && [18.130.57.226] == [172.31.21.87]
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core> [core/socket_info.c:583]: grep_sock_info(): checking advertise if host==us: 13==13 && [18.130.57.226] == [18.130.57.226]
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: textops [textops.c:3063]: has_body_helper(): content length is zero
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: tm [t_reply.c:1263]: t_should_relay_response(): ->>>>>>>>> T_code=180, new_code=180
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: tm [t_reply.c:1786]: relay_reply(): branch=0, save=0, relay=0 icode=0
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core> [core/msg_translator.c:2265]: generate_res_buf_from_sip_res(): old size: 635, new size: 552
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core> [core/msg_translator.c:2283]: generate_res_buf_from_sip_res(): copied size: orig:573, new: 490, rest: 62 msg=#012SIP/2.0 180 Ringing#015#012CSeq: 2 INVITE#015#012Call-ID: v51-8AifZ2mXi4RFMRej9A..#015#012From: <sip:923135082344@sip.talkhomeappcall.com;transport=UDP>;tag=dc4e5a14#015#012To: <sip:923335550609@sip.talkhomeappcall.com;transport=UDP>;tag=26d24c34#015#012Via: SIP/2.0/UDP 115.186.137.147:61717;rport=61717;branch=z9hG4bK-524287-1---6a391e4fb0f8a8f6#015#012Record-Route: <sip:18.130.57.226;lr=on;ftag=dc4e5a14>#015#012Contact: "923335550609" <sip:923335550609@115.186.137.147:5060;transport=udp;registering_acc=sip_talkhomeappcall_com>#015#012User-Agent: Jitsi2.10.5550Windows 10#015#012Content-Length: 0
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core> [core/receive.c:362]: receive_msg(): reply-route executed in: 2206 usec
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core> [core/xavp.c:446]: xavp_destroy_list(): destroying xavp list (nil)
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core> [core/receive.c:378]: receive_msg(): cleaning up
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x28b12f0 (8)-> 0x28b12f0 (9)
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x28b12f0 is 867
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x28b12f0 found on table entry 867
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:96]: event_cb(): activity 2 on socket 11: action 1
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:129]: event_cb(): performing action 1 on socket 11
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:249]: write_cb(): data received: HTTP/1.1 200 OK#015#012 [17]
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x28b12f0 (8)-> 0x28b12f0 (9)
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x28b12f0 is 867
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x28b12f0 found on table entry 867
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:289]: write_cb(): getting easy handler info (0x28b12f0)
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:249]: write_cb(): data received: Content-Length: 40#015#012 [20]
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x28b12f0 (8)-> 0x28b12f0 (9)
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x28b12f0 is 867
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x28b12f0 found on table entry 867
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:289]: write_cb(): getting easy handler info (0x28b12f0)
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:249]: write_cb(): data received: Content-Type: application/json; charset=utf-8#015#012 [47]
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x28b12f0 (8)-> 0x28b12f0 (9)
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x28b12f0 is 867
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x28b12f0 found on table entry 867
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:289]: write_cb(): getting easy handler info (0x28b12f0)
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:249]: write_cb(): data received: Server: Microsoft-HTTPAPI/2.0#015#012 [31]
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x28b12f0 (8)-> 0x28b12f0 (9)
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x28b12f0 is 867
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x28b12f0 found on table entry 867
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:289]: write_cb(): getting easy handler info (0x28b12f0)
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:249]: write_cb(): data received: Date: Thu, 12 Jul 2018 08:12:51 GMT#015#012 [37]
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x28b12f0 (8)-> 0x28b12f0 (9)
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x28b12f0 is 867
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x28b12f0 found on table entry 867
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:289]: write_cb(): getting easy handler info (0x28b12f0)
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:249]: write_cb(): data received: #015#012 [2]
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x28b12f0 (8)-> 0x28b12f0 (9)
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x28b12f0 is 867
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x28b12f0 found on table entry 867
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:289]: write_cb(): getting easy handler info (0x28b12f0)
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:249]: write_cb(): data received: {"message":"Message","status":"Success"} [40]
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x28b12f0 (8)-> 0x28b12f0 (9)
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x28b12f0 is 867
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x28b12f0 found on table entry 867
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:289]: write_cb(): getting easy handler info (0x28b12f0)
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:161]: sock_cb(): socket callback: s=11 e=0x28b12f0 what=REMOVE
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:166]: sock_cb(): freeing event 0x28ba160
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:131]: event_cb(): action 1 on socket 11 performed
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:561]: check_multi_info(): REMAINING: 0
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:568]: check_multi_info(): DONE: http://app.com/push/notification/923335550609 => (0)
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x28b12f0 (8)-> 0x28b12f0 (9)
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client [hm_hash.c:93]: build_hash_key(): hash for 0x28b12f0 is 867
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client [hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x28b12f0 found on table entry 867
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client [async_http.c:162]: async_http_cb(): query result = HTTP/1.1 200 OK#015#012Content-Length: 40#015#012Content-Type: application/json; charset=utf-8#015#012Server: Microsoft-HTTPAPI/2.0#015#012Date: Thu, 12 Jul 2018 08:12:51 GMT#015#012#015#012{"message":"Message","status":"Success"} [194]
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: <core> [core/parser/msg_parser.c:614]: parse_msg(): SIP Reply  (status):
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: <core> [core/parser/msg_parser.c:616]: parse_msg():  version: <HTTP/1.1>
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: <core> [core/parser/msg_parser.c:618]: parse_msg():  status:  <200>
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: <core> [core/parser/msg_parser.c:620]: parse_msg():  reason:  <OK>
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: <core> [core/parser/msg_parser.c:183]: get_hdr_field(): content_length=40
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): found end of header
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client [async_http.c:209]: async_http_cb(): successfully parsed http reply 0x7f3ac975e930
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: tm [t_lookup.c:1585]: t_lookup_ident(): transaction found
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client [async_http.c:241]: async_http_cb(): resuming transaction (47588:281286645)
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: tm [t_lookup.c:1585]: t_lookup_ident(): transaction found
Jul 12 08:12:02 sip kamailio[22321]: INFO: <script>: [PUSH-HTTP-REPLY:v51-8AifZ2mXi4RFMRej9A..] -> status 200
Jul 12 08:12:02 sip kamailio[22321]: INFO: <script>: [PUSH-HTTP-REPLY:v51-8AifZ2mXi4RFMRej9A..] -> body   {"message":"Message","status":"Success"}
Jul 12 08:12:02 sip kamailio[22321]: INFO: <script>: [PUSH-HTTP-REPLY:v51-8AifZ2mXi4RFMRej9A..] -> v51-8AifZ2mXi4RFMRej9A..|end|issued has successfully send push notification
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client [async_http.h:135]: free_async_query(): freeing query 0x7f3ac5048008
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:579]: check_multi_info(): reply: [200] HTTP/1.1 200 OK#015#012Content-Length: 40#015#012Content-Type: application/json; charset=utf-8#015#012Server: Microsoft-HTTPAPI/2.0#015#012Date: Thu, 12 Jul 2018 08:12:51 GMT#015#012#015#012{"message":"Message","status":"Success"} [194]
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:584]: check_multi_info(): cleaning up cell 0x7f3ac4ff5778
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:589]: check_multi_info(): Removing handle 0x28b12f0
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client [http_multi.c:147]: event_cb(): last transfer done, kill timeout
Jul 12 08:12:02 sip kamailio[22336]: DEBUG: <core> [core/io_wait.h:602]: io_watch_del(): DBG: io_watch_del (0xa53880, 107, -1, 0x0) fd_no=45 called
Jul 12 08:12:02 sip kamailio[22336]: DEBUG: <core> [core/tcp_main.c:4196]: handle_tcpconn_ev(): sending to child, events 1
Jul 12 08:12:02 sip kamailio[22336]: DEBUG: <core> [core/tcp_main.c:3878]: send2child(): selected tcp worker 4 31(22332) for activity on [tls:172.31.21.87:5061], 0x7f3ac504ba10
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core> [core/tcp_read.c:1740]: handle_io(): received n=8 con=0x7f3ac504ba10, fd=12
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core> [core/tcp_read.c:1540]: tcp_read_req(): content-length=287
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core> [core/parser/msg_parser.c:604]: parse_msg(): SIP Request:
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core> [core/parser/msg_parser.c:606]: parse_msg():  method:  <PUBLISH>
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core> [core/parser/msg_parser.c:608]: parse_msg():  uri:     <sip:447825152591@sip.talkhomeappcall.com;transport=TLS>
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core> [core/parser/msg_parser.c:610]: parse_msg():  version: <SIP/2.0>
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK-524287-1---97bfb6537506e53b>; state=16
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core> [core/parser/msg_parser.c:492]: parse_headers(): Via found, flags=2
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core> [core/parser/msg_parser.c:494]: parse_headers(): this is the first via
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=10
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core> [core/parser/msg_parser.c:171]: get_hdr_field(): <To> [58]; uri=[sip:447825152591@sip.talkhomeappcall.com;transport=TLS]
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core> [core/parser/msg_parser.c:172]: get_hdr_field(): to body [<sip:447825152591@sip.talkhomeappcall.com;transport=TLS>#015#012]
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core> [core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <1> <PUBLISH>
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core> [core/receive.c:205]: receive_msg(): --- received sip message - request - call-id: [9k-onV_CLivT1AJd9PfB1A..] - cseq: [1 PUBLISH]
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core> [core/receive.c:248]: receive_msg(): preparing to run routing scripts...
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core> [core/parser/msg_parser.c:183]: get_hdr_field(): content_length=287
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): found end of header
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=eb6f1d48
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: sanity [sanity_mod.c:256]: w_sanity_check(): sanity checks result: 1
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: maxfwd [mf_funcs.c:74]: is_maxfwd_present(): value = 70
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: maxfwd [maxfwd.c:148]: process_maxfwd_header(): value 70 decreased to 50
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: siputils [sipops.c:159]: is_first_hop(): no 2nd via found - first hop
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: textops [textops.c:3083]: has_body_helper(): content type is 196613
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: siputils [checks.c:120]: has_totag(): no totag
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core> [core/msg_translator.c:159]: check_via_address(): (115.186.137.147, 192.168.0.104, 0)
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core> [core/tcp_main.c:2226]: tcpconn_send_put(): send from reader (22332 (31)), reusing fd
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core> [core/tcp_main.c:2460]: tcpconn_do_send(): sending...
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core> [core/tcp_main.c:2494]: tcpconn_do_send(): after real write: c= 0x7f3ac504ba10 n=421 fd=12
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core> [core/tcp_main.c:2495]: tcpconn_do_send(): buf=#012#027#003#001#001�#026-�Jz�8(+è#015��C��G#036�=�#012\{��#033[!��#031[#0015#036��$�#027#020#016<�!S�v-��J�f�#021�*��P(��nE�#017#001��EY#031띪+�n�����<%#023a�R�Cs#030�HR�k ��ɠ���G�M��:#012\b>�u�%����������?��#003e�a�Dv&%��-��X�y^ў#002cs#020l��2#033#025#037��U#001�`#027����#002q#016ޑH��/M7�!#014b�Y��#014;�[�$��Ω#012keRN�#013Y#030a#017��#031���#030�#032(�6\#013ԭ�#001�#020�x#003#016[��gd6#035�t�XH#026���#032�+��i� �<�?�_�#033�WCa���?�B��|`'|��
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core> [core/receive.c:289]: receive_msg(): request-route executed in: 1841 usec
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core> [core/xavp.c:446]: xavp_destroy_list(): destroying xavp list (nil)
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core> [core/receive.c:378]: receive_msg(): cleaning up
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG: io_watch_add(0xa9cf40, 12, 2, 0x7f3ac504ba10), fd_no=1
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core> [core/udp_server.c:492]: udp_rcv_loop(): received on udp socket: (118/100/635) [[SIP/2.0 180 Ringing 0D  0A CSeq: 2 INVITE 0D  0A Call-ID: v51-8AifZ2mXi4RFMRej9A.. 0D  0A From: <sip:923135082344@sip.]]
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core> [core/parser/msg_parser.c:614]: parse_msg(): SIP Reply  (status):
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core> [core/parser/msg_parser.c:616]: parse_msg():  version: <SIP/2.0>
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core> [core/parser/msg_parser.c:618]: parse_msg():  status:  <180>
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core> [core/parser/msg_parser.c:620]: parse_msg():  reason:  <Ringing>
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core> [core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <2> <INVITE>
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=26d24c34
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core> [core/parser/msg_parser.c:171]: get_hdr_field(): <To> [71]; uri=[sip:923335550609@sip.talkhomeappcall.com;transport=UDP]
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core> [core/parser/msg_parser.c:172]: get_hdr_field(): to body [<sip:923335550609@sip.talkhomeappcall.com;transport=UDP>]
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK4e9b.c598ebabb2493d5c9aebf673208c6bea.0>; state=9
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core> [core/parser/parse_via.c:2681]: parse_via(): parsing via: next via
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 235, <rport> = <61717>; state=6
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK-524287-1---6a391e4fb0f8a8f6>; state=16
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core> [core/parser/msg_parser.c:492]: parse_headers(): Via found, flags=2
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core> [core/parser/msg_parser.c:494]: parse_headers(): this is the first via
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core> [core/receive.c:205]: receive_msg(): --- received sip message - reply - call-id: [v51-8AifZ2mXi4RFMRej9A..] - cseq: [2 INVITE]
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: tm [t_lookup.c:1019]: t_check_msg(): msg (0x7f3ac975e930) id=1138 global id=1137 T start=0xffffffffffffffff
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: tm [t_lookup.c:897]: t_reply_matching(): t_reply_matching: hash 47588 label 0 branch 0
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: tm [t_lookup.c:951]: t_reply_matching(): reply (0x7f3ac975e930) matched an active transaction (T=0x7f3ac5004448)!
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: tm [t_lookup.c:1088]: t_check_msg(): msg (0x7f3ac975e930) id=1138 global id=1138 T end=0x7f3ac5004448
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: tm [t_reply.c:2207]: reply_received(): org. status uas=180, uac[0]=180 local=0 is_invite=1)
Jul 12 08:12:02 sip kamailio[22302]: INFO: <script>: [R-EXTERNAL_REPLY:v51-8AifZ2mXi4RFMRej9A..] -> saw reply to METHOD:INVITE RESPONSE:'180 Ringing' from 115.186.137.147:5060
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: tm [t_lookup.c:1019]: t_check_msg(): msg (0x7f3ac975e930) id=1138 global id=1138 T start=0x7f3ac5004448
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: tm [t_lookup.c:1091]: t_check_msg(): T (0x7f3ac5004448) already found for msg (0x7f3ac975e930)!
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core> [core/parser/msg_parser.c:183]: get_hdr_field(): content_length=0
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): found end of header
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core> [core/socket_info.c:564]: grep_sock_info(): checking if host==us: 13==12 && [18.130.57.226] == [172.31.21.87]
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core> [core/socket_info.c:583]: grep_sock_info(): checking advertise if host==us: 13==13 && [18.130.57.226] == [18.130.57.226]
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: textops [textops.c:3063]: has_body_helper(): content length is zero
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: tm [t_reply.c:1263]: t_should_relay_response(): ->>>>>>>>> T_code=180, new_code=180
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: tm [t_reply.c:1786]: relay_reply(): branch=0, save=0, relay=0 icode=0
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core> [core/msg_translator.c:2265]: generate_res_buf_from_sip_res(): old size: 635, new size: 552
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core> [core/msg_translator.c:2283]: generate_res_buf_from_sip_res(): copied size: orig:573, new: 490, rest: 62 msg=#012SIP/2.0 180 Ringing#015#012CSeq: 2 INVITE#015#012Call-ID: v51-8AifZ2mXi4RFMRej9A..#015#012From: <sip:923135082344@sip.talkhomeappcall.com;transport=UDP>;tag=dc4e5a14#015#012To: <sip:923335550609@sip.talkhomeappcall.com;transport=UDP>;tag=26d24c34#015#012Via: SIP/2.0/UDP 115.186.137.147:61717;rport=61717;branch=z9hG4bK-524287-1---6a391e4fb0f8a8f6#015#012Record-Route: <sip:18.130.57.226;lr=on;ftag=dc4e5a14>#015#012Contact: "923335550609" <sip:923335550609@115.186.137.147:5060;transport=udp;registering_acc=sip_talkhomeappcall_com>#015#012User-Agent: Jitsi2.10.5550Windows 10#015#012Content-Length: 0
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core> [core/receive.c:362]: receive_msg(): reply-route executed in: 2109 usec
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core> [core/xavp.c:446]: xavp_destroy_list(): destroying xavp list (nil)
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core> [core/receive.c:378]: receive_msg(): cleaning up
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core> [core/udp_server.c:492]: udp_rcv_loop(): received on udp socket: (118/100/635) [[SIP/2.0 180 Ringing 0D  0A CSeq: 2 INVITE 0D  0A Call-ID: v51-8AifZ2mXi4RFMRej9A.. 0D  0A From: <sip:923135082344@sip.]]
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:614]: parse_msg(): SIP Reply  (status):
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:616]: parse_msg():  version: <SIP/2.0>
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:618]: parse_msg():  status:  <180>
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:620]: parse_msg():  reason:  <Ringing>
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <2> <INVITE>
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=26d24c34
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:171]: get_hdr_field(): <To> [71]; uri=[sip:923335550609@sip.talkhomeappcall.com;transport=UDP]
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:172]: get_hdr_field(): to body [<sip:923335550609@sip.talkhomeappcall.com;transport=UDP>]
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK4e9b.c598ebabb2493d5c9aebf673208c6bea.0>; state=9
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core> [core/parser/parse_via.c:2681]: parse_via(): parsing via: next via
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 235, <rport> = <61717>; state=6
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK-524287-1---6a391e4fb0f8a8f6>; state=16
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:492]: parse_headers(): Via found, flags=2
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:494]: parse_headers(): this is the first via
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core> [core/receive.c:205]: receive_msg(): --- received sip message - reply - call-id: [v51-8AifZ2mXi4RFMRej9A..] - cseq: [2 INVITE]
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: tm [t_lookup.c:1019]: t_check_msg(): msg (0x7f3ac975e930) id=1107 global id=1106 T start=0xffffffffffffffff
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: tm [t_lookup.c:897]: t_reply_matching(): t_reply_matching: hash 47588 label 0 branch 0
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: tm [t_lookup.c:951]: t_reply_matching(): reply (0x7f3ac975e930) matched an active transaction (T=0x7f3ac5004448)!
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: tm [t_lookup.c:1088]: t_check_msg(): msg (0x7f3ac975e930) id=1107 global id=1107 T end=0x7f3ac5004448
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: tm [t_reply.c:2207]: reply_received(): org. status uas=180, uac[0]=180 local=0 is_invite=1)
Jul 12 08:12:04 sip kamailio[22303]: INFO: <script>: [R-EXTERNAL_REPLY:v51-8AifZ2mXi4RFMRej9A..] -> saw reply to METHOD:INVITE RESPONSE:'180 Ringing' from 115.186.137.147:5060
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: tm [t_lookup.c:1019]: t_check_msg(): msg (0x7f3ac975e930) id=1107 global id=1107 T start=0x7f3ac5004448
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: tm [t_lookup.c:1091]: t_check_msg(): T (0x7f3ac5004448) already found for msg (0x7f3ac975e930)!
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:183]: get_hdr_field(): content_length=0
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): found end of header
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core> [core/socket_info.c:564]: grep_sock_info(): checking if host==us: 13==12 && [18.130.57.226] == [172.31.21.87]
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core> [core/socket_info.c:583]: grep_sock_info(): checking advertise if host==us: 13==13 && [18.130.57.226] == [18.130.57.226]
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: textops [textops.c:3063]: has_body_helper(): content length is zero
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: tm [t_reply.c:1263]: t_should_relay_response(): ->>>>>>>>> T_code=180, new_code=180
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: tm [t_reply.c:1786]: relay_reply(): branch=0, save=0, relay=0 icode=0
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core> [core/msg_translator.c:2265]: generate_res_buf_from_sip_res(): old size: 635, new size: 552
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core> [core/msg_translator.c:2283]: generate_res_buf_from_sip_res(): copied size: orig:573, new: 490, rest: 62 msg=#012SIP/2.0 180 Ringing#015#012CSeq: 2 INVITE#015#012Call-ID: v51-8AifZ2mXi4RFMRej9A..#015#012From: <sip:923135082344@sip.talkhomeappcall.com;transport=UDP>;tag=dc4e5a14#015#012To: <sip:923335550609@sip.talkhomeappcall.com;transport=UDP>;tag=26d24c34#015#012Via: SIP/2.0/UDP 115.186.137.147:61717;rport=61717;branch=z9hG4bK-524287-1---6a391e4fb0f8a8f6#015#012Record-Route: <sip:18.130.57.226;lr=on;ftag=dc4e5a14>#015#012Contact: "923335550609" <sip:923335550609@115.186.137.147:5060;transport=udp;registering_acc=sip_talkhomeappcall_com>#015#012User-Agent: Jitsi2.10.5550Windows 10#015#012Content-Length: 0
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core> [core/receive.c:362]: receive_msg(): reply-route executed in: 1784 usec
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core> [core/xavp.c:446]: xavp_destroy_list(): destroying xavp list (nil)
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core> [core/receive.c:378]: receive_msg(): cleaning up
Jul 12 08:12:08 sip kamailio[22332]: DEBUG: <core> [core/io_wait.h:602]: io_watch_del(): DBG: io_watch_del (0xa9cf40, 12, -1, 0x10) fd_no=2 called
Jul 12 08:12:08 sip kamailio[22332]: DEBUG: <core> [core/tcp_read.c:1664]: release_tcpconn(): releasing con 0x7f3ac504ba10, state 1, fd=12, id=6 ([115.186.137.147]:54391 -> [115.186.137.147]:5061)
Jul 12 08:12:08 sip kamailio[22332]: DEBUG: <core> [core/tcp_read.c:1665]: release_tcpconn(): extra_data 0x7f3ac5048f40
Jul 12 08:12:08 sip kamailio[22336]: DEBUG: <core> [core/tcp_main.c:3308]: handle_tcp_child(): reader response= 7f3ac504ba10, 1 from 4
Jul 12 08:12:08 sip kamailio[22336]: DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG: io_watch_add(0xa53880, 107, 2, 0x7f3ac504ba10), fd_no=44
Jul 12 08:12:08 sip kamailio[22336]: DEBUG: <core> [core/tcp_main.c:3435]: handle_tcp_child(): CONN_RELEASE  0x7f3ac504ba10 refcnt= 1
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/udp_server.c:492]: udp_rcv_loop(): received on udp socket: (106/100/660) [[CANCEL sip:923335550609@sip.talkhomeappcall.com;transport=UDP SIP/2.0 0D  0A Via: SIP/2.0/UDP 115.186.137.]]
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/parser/msg_parser.c:604]: parse_msg(): SIP Request:
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/parser/msg_parser.c:606]: parse_msg():  method:  <CANCEL>
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/parser/msg_parser.c:608]: parse_msg():  uri:     <sip:923335550609@sip.talkhomeappcall.com;transport=UDP>
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/parser/msg_parser.c:610]: parse_msg():  version: <SIP/2.0>
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK-524287-1---6a391e4fb0f8a8f6>; state=16
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/parser/msg_parser.c:492]: parse_headers(): Via found, flags=2
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/parser/msg_parser.c:494]: parse_headers(): this is the first via
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=10
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/parser/msg_parser.c:171]: get_hdr_field(): <To> [58]; uri=[sip:923335550609@sip.talkhomeappcall.com;transport=UDP]
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/parser/msg_parser.c:172]: get_hdr_field(): to body [<sip:923335550609@sip.talkhomeappcall.com;transport=UDP>#015#012]
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <2> <CANCEL>
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/receive.c:205]: receive_msg(): --- received sip message - request - call-id: [v51-8AifZ2mXi4RFMRej9A..] - cseq: [2 CANCEL]
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/receive.c:248]: receive_msg(): preparing to run routing scripts...
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/parser/msg_parser.c:183]: get_hdr_field(): content_length=0
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): found end of header
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=dc4e5a14
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: sanity [sanity_mod.c:256]: w_sanity_check(): sanity checks result: 1
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: maxfwd [mf_funcs.c:74]: is_maxfwd_present(): value = 70
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: maxfwd [maxfwd.c:148]: process_maxfwd_header(): value 70 decreased to 50
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: siputils [sipops.c:159]: is_first_hop(): no 2nd via found - first hop
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: textops [textops.c:3063]: has_body_helper(): content length is zero
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: siputils [checks.c:120]: has_totag(): no totag
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_lookup.c:711]: t_lookupOriginalT(): searching on hash entry 47588
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_lookup.c:420]: matching_3261(): RFC3261 transaction matched, tid=-524287-1---6a391e4fb0f8a8f6
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_lookup.c:807]: t_lookupOriginalT(): canceled transaction found (0x7f3ac5004448)!
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_lookup.c:810]: t_lookupOriginalT(): found - lookup completed
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [tm.c:1091]: ki_t_lookup_cancel_flags(): lookup_original: t_lookupOriginalT returned: 0x7f3ac5004448
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_lookup.c:1320]: t_newtran(): msg id=1139 , global msg id=1138 , T on entrance=0xffffffffffffffff
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_lookup.c:477]: t_lookup_request(): start searching: hash=47588, isACK=0
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_lookup.c:435]: matching_3261(): RFC3261 transaction matching failed
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_lookup.c:659]: t_lookup_request(): no transaction found
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/md5utils.c:67]: MD5StringArray(): MD5 calculated: c598ebabb2493d5c9aebf673208c6bea
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_lookup.c:711]: t_lookupOriginalT(): searching on hash entry 47588
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_lookup.c:420]: matching_3261(): RFC3261 transaction matched, tid=-524287-1---6a391e4fb0f8a8f6
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_lookup.c:807]: t_lookupOriginalT(): canceled transaction found (0x7f3ac5004448)!
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_lookup.c:810]: t_lookupOriginalT(): found - lookup completed
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_cancel.c:335]: cancel_branch(): sending cancel...
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_fwd.c:1426]: e2e_cancel(): e2e cancel proceeding
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/msg_translator.c:159]: check_via_address(): (115.186.137.147, 115.186.137.147, 0)
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_reply.c:1629]: cleanup_uac_timers(): RETR/FR timers reset
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_reply.c:596]: _reply_light(): reply sent out. buf=0x7f3ac9760ba8: SIP/2.0 200 cancelin..., shmem=0x7f3ac4ff5778: SIP/2.0 200 cancelin
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_reply.c:606]: _reply_light(): finished
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_funcs.c:372]: t_relay_to(): new transaction forwarded
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/receive.c:289]: receive_msg(): request-route executed in: 3428 usec
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/xavp.c:446]: xavp_destroy_list(): destroying xavp list (nil)
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/receive.c:378]: receive_msg(): cleaning up
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/udp_server.c:492]: udp_rcv_loop(): received on udp socket: (118/100/486) [[SIP/2.0 200 OK 0D  0A CSeq: 2 CANCEL 0D  0A Call-ID: v51-8AifZ2mXi4RFMRej9A.. 0D  0A From: <sip:923135082344@sip.talkh]]
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:614]: parse_msg(): SIP Reply  (status):
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:616]: parse_msg():  version: <SIP/2.0>
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:618]: parse_msg():  status:  <200>
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:620]: parse_msg():  reason:  <OK>
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <2> <CANCEL>
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=26d24c34
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:171]: get_hdr_field(): <To> [71]; uri=[sip:923335550609@sip.talkhomeappcall.com;transport=UDP]
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:172]: get_hdr_field(): to body [<sip:923335550609@sip.talkhomeappcall.com;transport=UDP>]
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK4e9b.c598ebabb2493d5c9aebf673208c6bea.0>; state=16
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:492]: parse_headers(): Via found, flags=2
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:494]: parse_headers(): this is the first via
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/receive.c:205]: receive_msg(): --- received sip message - reply - call-id: [v51-8AifZ2mXi4RFMRej9A..] - cseq: [2 CANCEL]
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: tm [t_lookup.c:1019]: t_check_msg(): msg (0x7f3ac975e930) id=1108 global id=1107 T start=0xffffffffffffffff
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: tm [t_lookup.c:897]: t_reply_matching(): t_reply_matching: hash 47588 label 0 branch 0
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: tm [t_lookup.c:951]: t_reply_matching(): reply (0x7f3ac975e930) matched an active transaction (T=0x7f3ac5004448)!
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: tm [t_lookup.c:1088]: t_check_msg(): msg (0x7f3ac975e930) id=1108 global id=1108 T end=0x7f3ac5004448
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: tm [t_reply.c:2207]: reply_received(): org. status uas=180, uac[0]=180 local=0 is_invite=1)
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: tm [t_reply.c:2220]: reply_received(): reply to local CANCEL processed
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/receive.c:362]: receive_msg(): reply-route executed in: 752 usec
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/xavp.c:446]: xavp_destroy_list(): destroying xavp list (nil)
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/receive.c:378]: receive_msg(): cleaning up
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/udp_server.c:492]: udp_rcv_loop(): received on udp socket: (118/100/591) [[SIP/2.0 487 Request Terminated 0D  0A CSeq: 2 INVITE 0D  0A Call-ID: v51-8AifZ2mXi4RFMRej9A.. 0D  0A From: <sip:923135]]
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/parser/msg_parser.c:614]: parse_msg(): SIP Reply  (status):
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/parser/msg_parser.c:616]: parse_msg():  version: <SIP/2.0>
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/parser/msg_parser.c:618]: parse_msg():  status:  <487>
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/parser/msg_parser.c:620]: parse_msg():  reason:  <Request Terminated>
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <2> <INVITE>
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=26d24c34
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/parser/msg_parser.c:171]: get_hdr_field(): <To> [71]; uri=[sip:923335550609@sip.talkhomeappcall.com;transport=UDP]
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/parser/msg_parser.c:172]: get_hdr_field(): to body [<sip:923335550609@sip.talkhomeappcall.com;transport=UDP>]
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK4e9b.c598ebabb2493d5c9aebf673208c6bea.0>; state=9
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/parser/parse_via.c:2681]: parse_via(): parsing via: next via
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 235, <rport> = <61717>; state=6
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK-524287-1---6a391e4fb0f8a8f6>; state=16
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/parser/msg_parser.c:492]: parse_headers(): Via found, flags=2
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/parser/msg_parser.c:494]: parse_headers(): this is the first via
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/receive.c:205]: receive_msg(): --- received sip message - reply - call-id: [v51-8AifZ2mXi4RFMRej9A..] - cseq: [2 INVITE]
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_lookup.c:1019]: t_check_msg(): msg (0x7f3ac975e930) id=1140 global id=1139 T start=0xffffffffffffffff
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_lookup.c:897]: t_reply_matching(): t_reply_matching: hash 47588 label 0 branch 0
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_lookup.c:951]: t_reply_matching(): reply (0x7f3ac975e930) matched an active transaction (T=0x7f3ac5004448)!
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_lookup.c:1088]: t_check_msg(): msg (0x7f3ac975e930) id=1140 global id=1140 T end=0x7f3ac5004448
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_reply.c:2207]: reply_received(): org. status uas=180, uac[0]=180 local=0 is_invite=1)
Jul 12 08:12:09 sip kamailio[22302]: INFO: <script>: [R-EXTERNAL_REPLY:v51-8AifZ2mXi4RFMRej9A..] -> saw reply to METHOD:INVITE RESPONSE:'487 Request Terminated' from 115.186.137.147:5060
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_lookup.c:1019]: t_check_msg(): msg (0x7f3ac975e930) id=1140 global id=1140 T start=0x7f3ac5004448
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_lookup.c:1091]: t_check_msg(): T (0x7f3ac5004448) already found for msg (0x7f3ac975e930)!
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/parser/msg_parser.c:183]: get_hdr_field(): content_length=0
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): found end of header
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: siputils [sipops.c:171]: is_first_hop(): no record-route header - first hop
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: textops [textops.c:3063]: has_body_helper(): content length is zero
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_reply.c:1263]: t_should_relay_response(): ->>>>>>>>> T_code=180, new_code=487
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_lookup.c:1019]: t_check_msg(): msg (0x7f3ac50441b0) id=1104 global id=1104 T start=0x7f3ac5004448
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_lookup.c:1091]: t_check_msg(): T (0x7f3ac5004448) already found for msg (0x7f3ac50441b0)!
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tmx [t_var.c:534]: pv_get_tm_reply_code(): reply code is <487>
Jul 12 08:12:09 sip kamailio[22302]: INFO: <script>: v51-8AifZ2mXi4RFMRej9A..|start|external failure route, 487 generated for method INVITE after progress
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/msg_translator.c:159]: check_via_address(): (115.186.137.147, 115.186.137.147, 0)
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_reply.c:1629]: cleanup_uac_timers(): RETR/FR timers reset
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_reply.c:596]: _reply_light(): reply sent out. buf=0x7f3ac9760da0: SIP/2.0 500 I'm terr..., shmem=0x7f3ac5025330: SIP/2.0 500 I'm terr
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_reply.c:606]: _reply_light(): finished
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_reply.c:1786]: relay_reply(): branch=0, save=0, relay=-1 icode=0
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_reply.c:1629]: cleanup_uac_timers(): RETR/FR timers reset
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/receive.c:362]: receive_msg(): reply-route executed in: 2909 usec
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/xavp.c:446]: xavp_destroy_list(): destroying xavp list (nil)
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/receive.c:378]: receive_msg(): cleaning up
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/udp_server.c:492]: udp_rcv_loop(): received on udp socket: (106/100/419) [[ACK sip:923335550609@sip.talkhomeappcall.com;transport=UDP SIP/2.0 0D  0A Via: SIP/2.0/UDP 115.186.137.147]]
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:604]: parse_msg(): SIP Request:
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:606]: parse_msg():  method:  <ACK>
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:608]: parse_msg():  uri:     <sip:923335550609@sip.talkhomeappcall.com;transport=UDP>
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:610]: parse_msg():  version: <SIP/2.0>
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK-524287-1---6a391e4fb0f8a8f6>; state=16
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:492]: parse_headers(): Via found, flags=2
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:494]: parse_headers(): this is the first via
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=9fe2d4c84d97a4af81aa65ca8fc51b3d-9b76
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:171]: get_hdr_field(): <To> [100]; uri=[sip:923335550609@sip.talkhomeappcall.com;transport=UDP]
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:172]: get_hdr_field(): to body [<sip:923335550609@sip.talkhomeappcall.com;transport=UDP>]
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <2> <ACK>
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/receive.c:205]: receive_msg(): --- received sip message - request - call-id: [v51-8AifZ2mXi4RFMRej9A..] - cseq: [2 ACK]
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/receive.c:248]: receive_msg(): preparing to run routing scripts...
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: sl [sl_funcs.c:387]: sl_filter_ACK(): too late to be a local ACK!
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:183]: get_hdr_field(): content_length=0
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): found end of header
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=dc4e5a14
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: sanity [sanity_mod.c:256]: w_sanity_check(): sanity checks result: 1
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: maxfwd [mf_funcs.c:74]: is_maxfwd_present(): value = 70
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: maxfwd [maxfwd.c:148]: process_maxfwd_header(): value 70 decreased to 50
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: pv [pv_core.c:966]: pv_get_useragent(): no User-Agent header
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: pv [pv_core.c:966]: pv_get_useragent(): no User-Agent header
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: pv [pv_core.c:966]: pv_get_useragent(): no User-Agent header
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: siputils [sipops.c:159]: is_first_hop(): no 2nd via found - first hop
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: textops [textops.c:3063]: has_body_helper(): content length is zero
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: siputils [checks.c:123]: has_totag(): totag found
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: rr [loose.c:112]: find_first_route(): No Route headers found
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: rr [loose.c:944]: loose_route(): There is no Route HF
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: tm [t_lookup.c:1019]: t_check_msg(): msg (0x7f3ac975e930) id=1109 global id=1108 T start=0xffffffffffffffff
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: tm [t_lookup.c:477]: t_lookup_request(): start searching: hash=47588, isACK=1
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: tm [t_lookup.c:420]: matching_3261(): RFC3261 transaction matched, tid=-524287-1---6a391e4fb0f8a8f6
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: tm [t_lookup.c:676]: t_lookup_request(): transaction found (T=0x7f3ac5004448)
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: tm [t_lookup.c:1088]: t_check_msg(): msg (0x7f3ac975e930) id=1109 global id=1109 T end=0x7f3ac5004448
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: tm [t_reply.c:1629]: cleanup_uac_timers(): RETR/FR timers reset
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/timer.c:575]: timer_add_safe(): timer_add called on an active timer 0x7f3ac50044c8 (0x7f3ac44f3ce0, 0x7f3ac44f3ce0), flags 201
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: tm [t_funcs.c:147]: put_on_wait(): transaction 0x7f3ac5004448 already on wait
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/receive.c:289]: receive_msg(): request-route executed in: 2922 usec
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/xavp.c:446]: xavp_destroy_list(): destroying xavp list (nil)
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/receive.c:378]: receive_msg(): cleaning up
Jul 12 08:12:10 sip kamailio[22302]: DEBUG: <core> [core/udp_server.c:514]: udp_rcv_loop(): probing packet received from 217.33.40.242 57067


Thanks for your time. 

Best Regards, 
Aqs

On Thu, 12 Jul 2018 at 12:56, Daniel-Constantin Mierla <miconda@gmail.com> wrote:

Have you looked at log messages, any errors?

If not, then run with debug=3 in kamailio config and send full log messages for such call.

Cheers,
Daniel


On 11.07.18 19:15, Aqs Younas wrote:
Sorry, if i could not explain it well before.  I hope below picture will make it clear. 

...

is it some configuration issue? 

BTW what is the best way to call multiple async functions in kamailio. 

Any suggestion is much appreciated. 

Best Regards, 

Aqs Younas

On Wed, 11 Jul 2018 at 12:39, Daniel-Constantin Mierla <miconda@gmail.com> wrote:

Hello,


On 10.07.18 22:08, Aqs Younas wrote:
Greeting list, 

I am using two async functions(http_async_query) in configuration one for authentication and other one for push notifications. I am also using tsilio module to suspend the transaction and resumed it.  

I am resetting this flag 'T_ASYNC_SUSPENDED' before suspending the transaction. Everything is working fine except. When caller send CANCEL on the call, kamailio successfully completes sip flow at callee(B party) side but send back below packet towards caller.

what the above statement means? Kamailio forwarded the invite to callee, got 200ok, but sends back the 200 response?

Cheers,
Daniel

 
2018/07/10 19:47:41.125893 172.31.21.87:5060 -> 39.38.156.111:59969
SIP/2.0 500 I'm terribly sorry, server error occurred (1/TM )
Via: SIP/2.0/UDP 39.38.156.111:59969;branch=z9hG4bK-524287-1---91c6114330fe6293;rport=59969
To: <sip:923335550609@sip.talkhomeappcall.com;transport=UDP>;tag=9fe2d4c84d97a4af81aa65ca8fc51b3d-62cb
From: <sip:923135082344@sip.talkhomeappcall.com;transport=UDP>;tag=d72eaf4c
Call-ID: VkAwxpSgkKSGn5dXaXgn5A..
CSeq: 2 INVITE
Content-Length: 0


root@sip:~# kamailio -V
version: kamailio 5.1.3 (x86_64/linux)
flags: STATS: Off, USE_TCP, USE_TLS, USE_SCTP, TLS_HOOKS, DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, SHM_MEM, SHM_MMAP, PKG_MALLOC, Q_MALLOC, F_MALLOC, TLSF_MALLOC, DBG_SR_MEMORY, USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT, USE_DNS_CACHE, USE_DNS_FAILOVER, USE_NAPTR, USE_DST_BLACKLIST, HAVE_RESOLV_RES
ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16, MAX_URI_SIZE 1024, BUF_SIZE 65535, DEFAULT PKG_SIZE 8MB
poll method support: poll, epoll_lt, epoll_et, sigio_rt, select.
id: unknown
compiled on 08:06:26 May  2 2018 with gcc 4.9.2


Could someone please help me out how to fix this. Cancels are handles automatically so, i cannot hardcore anything to resolve it. 

Best Regards, 

Aqs Younas



_______________________________________________
Kamailio (SER) - Users Mailing List
sr-users@lists.kamailio.org
https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users


-- 
Daniel-Constantin Mierla -- www.asipto.com
www.twitter.com/miconda -- www.linkedin.com/in/miconda
Kamailio World Conference -- www.kamailioworld.com


_______________________________________________
Kamailio (SER) - Users Mailing List
sr-users@lists.kamailio.org
https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users


-- 
Daniel-Constantin Mierla -- www.asipto.com
www.twitter.com/miconda -- www.linkedin.com/in/miconda
Kamailio World Conference -- www.kamailioworld.com