[SR-Users] SIP/2.0 500 I'm terribly sorry, server error occurred (1/TM)

Thu Jul 12 10:37:17 CEST 2018

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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at sip.talkhomeappcall.com;transport=UDP>;tag=dc4e5a14#015#012To:
<sip:923335550609 at 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 at 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 at 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 at 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 at 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 at sip.talkhomeappcall.com;transport=UDP>;tag=dc4e5a14#015#012To:
<sip:923335550609 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at sip.talkhomeappcall.com;transport=UDP>;tag=dc4e5a14#015#012To:
<sip:923335550609 at 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 at 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 at 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 at 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 at 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 at sip.talkhomeappcall.com;transport=UDP>;tag=dc4e5a14#015#012To:
<sip:923335550609 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at sip.talkhomeappcall.com
<sip%3A923335550609 at 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 at sip.talkhomeappcall.com
<sip%3A923335550609 at 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 at sip.talkhomeappcall.com
<sip%3A923335550609 at 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 at sip.talkhomeappcall.com
<sip%3A923335550609 at 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 at 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 at 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 at sip.talkhomeappcall.com
>> ;transport=UDP>;tag=9fe2d4c84d97a4af81aa65ca8fc51b3d-62cb
>> From: <sip:923135082344 at sip.talkhomeappcall.com
>> ;transport=UDP>;tag=d72eaf4c
>> Call-ID: VkAwxpSgkKSGn5dXaXgn5A..
>> CSeq: 2 INVITE
>> Content-Length: 0
>>
>>
>> root at 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 Listsr-users at lists.kamailio.orghttps://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users
>>
>>
>> --
>> Daniel-Constantin Mierla -- www.asipto.comwww.twitter.com/miconda -- www.linkedin.com/in/miconda
>> Kamailio World Conference -- www.kamailioworld.com
>>
>>
>
> _______________________________________________
> Kamailio (SER) - Users Mailing Listsr-users at lists.kamailio.orghttps://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users
>
>
> --
> Daniel-Constantin Mierla -- www.asipto.comwww.twitter.com/miconda -- www.linkedin.com/in/miconda
> Kamailio World Conference -- www.kamailioworld.com
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.kamailio.org/pipermail/sr-users/attachments/20180712/ff81cea1/attachment.html>