11 Jul
2018
11 Jul
'18
1:08 a.m.
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.
2018/07/10 19:47:41.125893 172.31.21.87:5060 -> 39.38.156.111:59969
SIP/2.0 500 I'm terribly sorry, server error occurred (1/TM )
Via: SIP/2.0/UDP 39.38.156.111:59969
;branch=z9hG4bK-524287-1---91c6114330fe6293;rport=59969
To: <sip:923335550609@sip.talkhomeappcall.com
;transport=UDP>;tag=9fe2d4c84d97a4af81aa65ca8fc51b3d-62cb
From: <sip:923135082344@sip.talkhomeappcall.com;transport=UDP>;tag=d72eaf4c
Call-ID: VkAwxpSgkKSGn5dXaXgn5A..
CSeq: 2 INVITE
Content-Length: 0
root@sip:~# kamailio -V
version: kamailio 5.1.3 (x86_64/linux)
flags: STATS: Off, USE_TCP, USE_TLS, USE_SCTP, TLS_HOOKS, DISABLE_NAGLE,
USE_MCAST, DNS_IP_HACK, SHM_MEM, SHM_MMAP, PKG_MALLOC, Q_MALLOC, F_MALLOC,
TLSF_MALLOC, DBG_SR_MEMORY, USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT,
USE_DNS_CACHE, USE_DNS_FAILOVER, USE_NAPTR, USE_DST_BLACKLIST,
HAVE_RESOLV_RES
ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16,
MAX_URI_SIZE 1024, BUF_SIZE 65535, DEFAULT PKG_SIZE 8MB
poll method support: poll, epoll_lt, epoll_et, sigio_rt, select.
id: unknown
compiled on 08:06:26 May 2 2018 with gcc 4.9.2
Could someone please help me out how to fix this. Cancels are handles
automatically so, i cannot hardcore anything to resolve it.
Best Regards,
Aqs Younas
11 Jul
11 Jul
12:38 p.m.
New subject: SIP/2.0 500 I'm terribly sorry, server error occurred (1/TM)
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
<http://172.31.21.87:5060> -> 39.38.156.111:59969
<http://39.38.156.111:59969>
SIP/2.0 500 I'm terribly sorry, server error occurred (1/TM )
Via: SIP/2.0/UDP
39.38.156.111:59969;branch=z9hG4bK-524287-1---91c6114330fe6293;rport=59969
To: <sip:923335550609@sip.talkhomeappcall.com
<mailto:sip%3A923335550609@sip.talkhomeappcall.com>;transport=UDP>;tag=9fe2d4c84d97a4af81aa65ca8fc51b3d-62cb
From: <sip:923135082344@sip.talkhomeappcall.com
<mailto:sip%3A923135082344@sip.talkhomeappcall.com>;transport=UDP>;tag=d72eaf4c
Call-ID: VkAwxpSgkKSGn5dXaXgn5A..
CSeq: 2 INVITE
Content-Length: 0
root@sip:~# kamailio -V
version: kamailio 5.1.3 (x86_64/linux)
flags: STATS: Off, USE_TCP, USE_TLS, USE_SCTP, TLS_HOOKS,
DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, SHM_MEM, SHM_MMAP, PKG_MALLOC,
Q_MALLOC, F_MALLOC, TLSF_MALLOC, DBG_SR_MEMORY, USE_FUTEX,
FAST_LOCK-ADAPTIVE_WAIT, USE_DNS_CACHE, USE_DNS_FAILOVER, USE_NAPTR,
USE_DST_BLACKLIST, HAVE_RESOLV_RES
ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16,
MAX_URI_SIZE 1024, BUF_SIZE 65535, DEFAULT PKG_SIZE 8MB
poll method support: poll, epoll_lt, epoll_et, sigio_rt, select.
id: unknown
compiled on 08:06:26 May 2 2018 with gcc 4.9.2
Could someone please help me out how to fix this. Cancels are handles
automatically so, i cannot hardcore anything to resolve it.
Best Regards,
Aqs Younas
_______________________________________________
Kamailio (SER) - Users Mailing List
sr-users(a)lists.kamailio.org
https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users
--
Daniel-Constantin Mierla -- www.asipto.com
www.twitter.com/miconda -- www.linkedin.com/in/miconda
Kamailio World Conference -- www.kamailioworld.com
10:15 p.m.
Sorry, if i could not explain it well before. I hope below picture will
make it clear.
[image: image.png]
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(a)gmail.com>
wrote:
Hello,
On 10.07.18 22:08, Aqs Younas wrote:
Greeting list,
I am using two async functions(http_async_query) in configuration one for
authentication and other one for push notifications. I am also using tsilio
module to suspend the transaction and resumed it.
I am resetting this flag 'T_ASYNC_SUSPENDED' before suspending the
transaction. Everything is working fine except. When caller send CANCEL on
the call, kamailio successfully completes sip flow at callee(B party) side
but send back below packet towards caller.
what the above statement means? Kamailio forwarded the invite to callee,
got 200ok, but sends back the 200 response?
Cheers,
Daniel
2018/07/10 19:47:41.125893 172.31.21.87:5060 -> 39.38.156.111:59969
SIP/2.0 500 I'm terribly sorry, server error occurred (1/TM )
Via: SIP/2.0/UDP 39.38.156.111:59969
;branch=z9hG4bK-524287-1---91c6114330fe6293;rport=59969
To: <sip:923335550609@sip.talkhomeappcall.com
;transport=UDP>;tag=9fe2d4c84d97a4af81aa65ca8fc51b3d-62cb
From: <sip:923135082344@sip.talkhomeappcall.com
;transport=UDP>;tag=d72eaf4c
Call-ID: VkAwxpSgkKSGn5dXaXgn5A..
CSeq: 2 INVITE
Content-Length: 0
root@sip:~# kamailio -V
version: kamailio 5.1.3 (x86_64/linux)
flags: STATS: Off, USE_TCP, USE_TLS, USE_SCTP, TLS_HOOKS, DISABLE_NAGLE,
USE_MCAST, DNS_IP_HACK, SHM_MEM, SHM_MMAP, PKG_MALLOC, Q_MALLOC, F_MALLOC,
TLSF_MALLOC, DBG_SR_MEMORY, USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT,
USE_DNS_CACHE, USE_DNS_FAILOVER, USE_NAPTR, USE_DST_BLACKLIST,
HAVE_RESOLV_RES
ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16,
MAX_URI_SIZE 1024, BUF_SIZE 65535, DEFAULT PKG_SIZE 8MB
poll method support: poll, epoll_lt, epoll_et, sigio_rt, select.
id: unknown
compiled on 08:06:26 May 2 2018 with gcc 4.9.2
Could someone please help me out how to fix this. Cancels are handles
automatically so, i cannot hardcore anything to resolve it.
Best Regards,
Aqs Younas
_______________________________________________
Kamailio (SER) - Users Mailing
Listsr-users@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
12 Jul
12 Jul
12:56 p.m.
New subject: SIP/2.0 500 I'm terribly sorry, server error occurred (1/TM)
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(a)gmail.com <mailto:miconda@gmail.com>> wrote:
Hello,
On 10.07.18 22:08, Aqs Younas wrote:
--
Daniel-Constantin Mierla -- www.asipto.com
www.twitter.com/miconda -- www.linkedin.com/in/miconda
Kamailio World Conference -- www.kamailioworld.com
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
<http://172.31.21.87:5060> -> 39.38.156.111:59969
<http://39.38.156.111:59969>
SIP/2.0 500 I'm terribly sorry, server error occurred (1/TM )
Via: SIP/2.0/UDP
39.38.156.111:59969;branch=z9hG4bK-524287-1---91c6114330fe6293;rport=59969
To: <sip:923335550609@sip.talkhomeappcall.com
<mailto:sip%3A923335550609@sip.talkhomeappcall.com>;transport=UDP>;tag=9fe2d4c84d97a4af81aa65ca8fc51b3d-62cb
From: <sip:923135082344@sip.talkhomeappcall.com
<mailto:sip%3A923135082344@sip.talkhomeappcall.com>;transport=UDP>;tag=d72eaf4c
Call-ID: VkAwxpSgkKSGn5dXaXgn5A..
CSeq: 2 INVITE
Content-Length: 0
root@sip:~# kamailio -V
version: kamailio 5.1.3 (x86_64/linux)
flags: STATS: Off, USE_TCP, USE_TLS, USE_SCTP, TLS_HOOKS,
DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, SHM_MEM, SHM_MMAP,
PKG_MALLOC, Q_MALLOC, F_MALLOC, TLSF_MALLOC, DBG_SR_MEMORY,
USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT, USE_DNS_CACHE,
USE_DNS_FAILOVER, USE_NAPTR, USE_DST_BLACKLIST, HAVE_RESOLV_RES
ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN
16, MAX_URI_SIZE 1024, BUF_SIZE 65535, DEFAULT PKG_SIZE 8MB
poll method support: poll, epoll_lt, epoll_et, sigio_rt, select.
id: unknown
compiled on 08:06:26 May 2 2018 with gcc 4.9.2
Could someone please help me out how to fix this. Cancels are
handles automatically so, i cannot hardcore anything to resolve it.
Best Regards,
Aqs Younas
_______________________________________________
Kamailio (SER) - Users Mailing List
sr-users(a)lists.kamailio.org <mailto:sr-users@lists.kamailio.org>
https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users
--
Daniel-Constantin Mierla -- www.asipto.com <http://www.asipto.com>
www.twitter.com/miconda <http://www.twitter.com/miconda> --
www.linkedin.com/in/miconda <http://www.linkedin.com/in/miconda>
Kamailio World Conference -- www.kamailioworld.com
<http://www.kamailioworld.com>
_______________________________________________
Kamailio (SER) - Users Mailing List
sr-users(a)lists.kamailio.org
https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users
1:37 p.m.
I could not find anything related to error. Below are the full detailed
logs. Again thanks for you help.
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/udp_server.c:492]:
udp_rcv_loop(): received on udp socket: (106/100/963) [[INVITE
sip:923335550609@sip.talkhomeappcall.com;transport=UDP SIP/2.0 0D 0A Via:
SIP/2.0/UDP 115.186.137.]]
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:604]: parse_msg(): SIP Request:
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:606]: parse_msg(): method: <INVITE>
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:608]: parse_msg(): uri: <
sip:923335550609@sip.talkhomeappcall.com;transport=UDP>
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:610]: parse_msg(): version: <SIP/2.0>
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core>
[core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232,
<branch> = <z9hG4bK-524287-1---5e6fadd00170a89c>; state=16
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core>
[core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:492]: parse_headers(): Via found, flags=2
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:494]: parse_headers(): this is the first via
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core>
[core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header
reached, state=10
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:171]: get_hdr_field(): <To> [58]; uri=[
sip:923335550609@sip.talkhomeappcall.com;transport=UDP]
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:172]: get_hdr_field(): to body [<
sip:923335550609@sip.talkhomeappcall.com;transport=UDP>#015#012]
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <1>
<INVITE>
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/receive.c:205]:
receive_msg(): --- received sip message - request - call-id:
[v51-8AifZ2mXi4RFMRej9A..] - cseq: [1 INVITE]
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/receive.c:248]:
receive_msg(): preparing to run routing scripts...
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:183]: get_hdr_field(): content_length=245
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:89]: get_hdr_field(): found end of header
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core>
[core/parser/parse_addr_spec.c:185]: parse_to_param(): add param:
tag=dc4e5a14
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core>
[core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header
reached, state=29
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: sanity [sanity_mod.c:256]:
w_sanity_check(): sanity checks result: 1
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: maxfwd [mf_funcs.c:74]:
is_maxfwd_present(): value = 70
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: maxfwd [maxfwd.c:148]:
process_maxfwd_header(): value 70 decreased to 50
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: siputils [sipops.c:159]:
is_first_hop(): no 2nd via found - first hop
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: textops [textops.c:3083]:
has_body_helper(): content type is 196611
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core>
[core/parser/sdp/sdp_helpr_funcs.c:504]: extract_mediaip(): located IP
address [115.186.137.147] in `o=' field
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core>
[core/parser/sdp/sdp_helpr_funcs.c:504]: extract_mediaip(): located IP
address [115.186.137.147] in `c=' field
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: rtpengine
[rtpengine_funcs.c:140]: check_content_type(): type <application/sdp> found
valid
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: rtpengine [rtpengine.c:2704]:
select_rtpp_node_old(): rtpengine hash table lookup failed to find node for
calllen=24 callid=v51-8AifZ2mXi4RFMRej9A.. viabranch=
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: rtpengine [rtpengine.c:2251]:
rtpp_function_call(): proxy reply: d3:sdp321:v=0#015#012o=Z 0 0 IN IP4
18.130.57.226#015#012s=Z#015#012c=IN IP4 18.130.57.226#015#012t=0
0#015#012m=audio 20324 RTP/AVP 3 110 8 0 97 101#015#012a=rtpmap:3
GSM/8000#015#012a=rtpmap:110 speex/8000#015#012a=rtpmap:8
PCMA/8000#015#012a=rtpmap:0 PCMU/8000#015#012a=rtpmap:97
iLBC/8000#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:97
mode=30#015#012a=fmtp:101
0-16#015#012a=sendrecv#015#012a=rtcp:20325#015#0126:result2:oke
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: rtpengine [rtpengine.c:2320]:
rtpp_function_call(): rtpengine hash table insert node=udp:127.0.0.1:2223
for calllen=24 callid=v51-8AifZ2mXi4RFMRej9A.. viabranch=
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: siputils [checks.c:120]:
has_totag(): no totag
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: rr [loose.c:1209]:
is_direction(): param ftag not found
Jul 12 08:12:00 sip kamailio[22303]: INFO: <script>:
v51-8AifZ2mXi4RFMRej9A..|log|originated from User-Agent: Z 3.7.30891 r30851
Jul 12 08:12:00 sip kamailio[22303]: INFO: <script>:
[R-ATTEMPT-AUTHORIZATION:v51-8AifZ2mXi4RFMRej9A..] -> In authentication for
INVITE against 923135082344(a)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(a)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(a)sip.talkhomeappcall.com from IP
115.186.137.147:61717
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/receive.c:289]:
receive_msg(): request-route executed in: 3405 usec
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/xavp.c:446]:
xavp_destroy_list(): destroying xavp list (nil)
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/receive.c:378]:
receive_msg(): cleaning up
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core>
[core/parser/sdp/sdp.c:794]: free_sdp(): _sdp = 0x7f3ac975eb18
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core>
[core/parser/sdp/sdp.c:796]: free_sdp(): sdp = 0x7f3ac975feb8
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core>
[core/parser/sdp/sdp.c:798]: free_sdp(): session = 0x7f3ac9729ce0
Jul 12 08:12:00 sip kamailio[22302]: DEBUG: <core> [core/udp_server.c:492]:
udp_rcv_loop(): received on udp socket: (106/100/419) [[ACK
sip:923335550609@sip.talkhomeappcall.com;transport=UDP SIP/2.0 0D 0A Via:
SIP/2.0/UDP 115.186.137.147]]
Jul 12 08:12:00 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:604]: parse_msg(): SIP Request:
Jul 12 08:12:00 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:606]: parse_msg(): method: <ACK>
Jul 12 08:12:00 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:608]: parse_msg(): uri: <
sip:923335550609@sip.talkhomeappcall.com;transport=UDP>
Jul 12 08:12:00 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:610]: parse_msg(): version: <SIP/2.0>
Jul 12 08:12:00 sip kamailio[22302]: DEBUG: <core>
[core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232,
<branch> = <z9hG4bK-524287-1---5e6fadd00170a89c>; state=16
Jul 12 08:12:00 sip kamailio[22302]: DEBUG: <core>
[core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5
Jul 12 08:12:00 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:492]: parse_headers(): Via found, flags=2
Jul 12 08:12:00 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:494]: parse_headers(): this is the first via
Jul 12 08:12:00 sip kamailio[22302]: DEBUG: <core>
[core/parser/parse_addr_spec.c:185]: parse_to_param(): add param:
tag=24981d2e17dbb5775661067d94809cd2.e7c9
Jul 12 08:12:00 sip kamailio[22302]: DEBUG: <core>
[core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header
reached, state=29
Jul 12 08:12:00 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:171]: get_hdr_field(): <To> [100]; uri=[
sip:923335550609@sip.talkhomeappcall.com;transport=UDP]
Jul 12 08:12:00 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:172]: get_hdr_field(): to body [<
sip:923335550609@sip.talkhomeappcall.com;transport=UDP>]
Jul 12 08:12:00 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <1> <ACK>
Jul 12 08:12:00 sip kamailio[22302]: DEBUG: <core> [core/receive.c:205]:
receive_msg(): --- received sip message - request - call-id:
[v51-8AifZ2mXi4RFMRej9A..] - cseq: [1 ACK]
Jul 12 08:12:00 sip kamailio[22302]: DEBUG: <core> [core/receive.c:248]:
receive_msg(): preparing to run routing scripts...
Jul 12 08:12:00 sip kamailio[22302]: DEBUG: sl [sl_funcs.c:406]:
sl_filter_ACK(): SL local ACK found -> dropping it!
Jul 12 08:12:00 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:00 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:00 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:00 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:00 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:00 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:00 sip kamailio[22302]: DEBUG: <core> [core/xavp.c:446]:
xavp_destroy_list(): destroying xavp list (nil)
Jul 12 08:12:00 sip kamailio[22302]: DEBUG: <core> [core/receive.c:378]:
receive_msg(): cleaning up
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/udp_server.c:492]:
udp_rcv_loop(): received on udp socket: (106/100/1208) [[INVITE
sip:923335550609@sip.talkhomeappcall.com;transport=UDP SIP/2.0 0D 0A Via:
SIP/2.0/UDP 115.186.137.]]
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:604]: parse_msg(): SIP Request:
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:606]: parse_msg(): method: <INVITE>
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:608]: parse_msg(): uri: <
sip:923335550609@sip.talkhomeappcall.com;transport=UDP>
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:610]: parse_msg(): version: <SIP/2.0>
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core>
[core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232,
<branch> = <z9hG4bK-524287-1---6a391e4fb0f8a8f6>; state=16
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core>
[core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:492]: parse_headers(): Via found, flags=2
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:494]: parse_headers(): this is the first via
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core>
[core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header
reached, state=10
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:171]: get_hdr_field(): <To> [58]; uri=[
sip:923335550609@sip.talkhomeappcall.com;transport=UDP]
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:172]: get_hdr_field(): to body [<
sip:923335550609@sip.talkhomeappcall.com;transport=UDP>#015#012]
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <2>
<INVITE>
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/receive.c:205]:
receive_msg(): --- received sip message - request - call-id:
[v51-8AifZ2mXi4RFMRej9A..] - cseq: [2 INVITE]
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/receive.c:248]:
receive_msg(): preparing to run routing scripts...
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:183]: get_hdr_field(): content_length=245
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:89]: get_hdr_field(): found end of header
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core>
[core/parser/parse_addr_spec.c:185]: parse_to_param(): add param:
tag=dc4e5a14
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core>
[core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header
reached, state=29
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: sanity [sanity_mod.c:256]:
w_sanity_check(): sanity checks result: 1
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: maxfwd [mf_funcs.c:74]:
is_maxfwd_present(): value = 70
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: maxfwd [maxfwd.c:148]:
process_maxfwd_header(): value 70 decreased to 50
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: siputils [sipops.c:159]:
is_first_hop(): no 2nd via found - first hop
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: textops [textops.c:3083]:
has_body_helper(): content type is 196611
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core>
[core/parser/sdp/sdp_helpr_funcs.c:504]: extract_mediaip(): located IP
address [115.186.137.147] in `o=' field
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core>
[core/parser/sdp/sdp_helpr_funcs.c:504]: extract_mediaip(): located IP
address [115.186.137.147] in `c=' field
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: rtpengine
[rtpengine_funcs.c:140]: check_content_type(): type <application/sdp> found
valid
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: rtpengine [rtpengine.c:2708]:
select_rtpp_node_old(): rtpengine hash table lookup find node=udp:
127.0.0.1:2223 for calllen=24 callid=v51-8AifZ2mXi4RFMRej9A.. viabranch=
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: rtpengine [rtpengine.c:2251]:
rtpp_function_call(): proxy reply: d3:sdp321:v=0#015#012o=Z 0 0 IN IP4
18.130.57.226#015#012s=Z#015#012c=IN IP4 18.130.57.226#015#012t=0
0#015#012m=audio 20324 RTP/AVP 3 110 8 0 97 101#015#012a=rtpmap:3
GSM/8000#015#012a=rtpmap:110 speex/8000#015#012a=rtpmap:8
PCMA/8000#015#012a=rtpmap:0 PCMU/8000#015#012a=rtpmap:97
iLBC/8000#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:97
mode=30#015#012a=fmtp:101
0-16#015#012a=sendrecv#015#012a=rtcp:20325#015#0126:result2:oke
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: siputils [checks.c:120]:
has_totag(): no totag
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: rr [loose.c:1209]:
is_direction(): param ftag not found
Jul 12 08:12:00 sip kamailio[22303]: INFO: <script>:
v51-8AifZ2mXi4RFMRej9A..|log|originated from User-Agent: Z 3.7.30891 r30851
Jul 12 08:12:00 sip kamailio[22303]: INFO: <script>:
[R-ATTEMPT-AUTHORIZATION:v51-8AifZ2mXi4RFMRej9A..] -> In authentication for
INVITE against 923135082344(a)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(a)sip.talkhomeappcall.com
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: auth [auth_mod.c:847]:
w_pv_auth_check(): realm [sip.talkhomeappcall.com] flags [1] checks [1]
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: auth [api.c:88]: pre_auth():
digest-algo: MD5 parsed value: 1
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: auth [api.c:292]:
auth_check_response(): Our result = 'bae0c3bad25ef6951fcc9142dbf6e29c'
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: auth [api.c:299]:
auth_check_response(): Authorization is OK
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: sl [sl.c:282]: send_reply():
reply in stateless mode (sl)
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core>
[core/msg_translator.c:159]: check_via_address(): (115.186.137.147,
115.186.137.147, 0)
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: registrar [lookup.c:256]:
lookup_helper(): contact for [923335550609] found by address
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: tm [t_lookup.c:1320]:
t_newtran(): msg id=1105 , global msg id=1103 , T on entrance=(nil)
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: tm [t_lookup.c:477]:
t_lookup_request(): start searching: hash=47588, isACK=0
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: tm [t_lookup.c:435]:
matching_3261(): RFC3261 transaction matching failed
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: tm [t_lookup.c:659]:
t_lookup_request(): no transaction found
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/md5utils.c:67]:
MD5StringArray(): MD5 calculated: c598ebabb2493d5c9aebf673208c6bea
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: tsilo [ts_store.c:80]:
ts_store(): storing transaction 47588:281286645 for r-uri: 923335550609
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: tsilo [ts_hash.c:263]:
insert_ts_urecord(): urecord entry 0x7f3ac4daaad8
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: tsilo [ts_handlers.c:56]:
ts_set_tm_callbacks(): registered TMCB for transaction 47588:281286645
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: tsilo [ts_store.c:103]:
ts_store(): transaction 47588:281286645 (ruri: 923335550609) inserted
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: htable [ht_var.c:90]:
pv_set_ht_cell(): set value for $sht(vtp=>stored::923335550609)
Jul 12 08:12:00 sip kamailio[22303]: INFO: <script>:
[USER-LOOKUP:v51-8AifZ2mXi4RFMRej9A..] -> stored transaction
[47588:281286645] 923135082344=> 923335550609
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: tm [t_lookup.c:1320]:
t_newtran(): msg id=1105 , global msg id=1105 , T on entrance=0x7f3ac5004448
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: tm [t_lookup.c:1324]:
t_newtran(): transaction already in process 0x7f3ac5004448
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core>
[core/msg_translator.c:424]: clen_builder(): content-length: 321 (321)
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core>
[core/msg_translator.c:159]: check_via_address(): (115.186.137.147,
115.186.137.147, 0)
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: tm [t_funcs.c:372]:
t_relay_to(): new transaction forwarded
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: http_async_client
[async_http.c:731]: header_list_add(): stored new http header: [User-Agent:
testheader]
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: http_async_client
[async_http.c:731]: header_list_add(): stored new http header: [Host:
app.com]
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: http_async_client
[async_http.c:731]: header_list_add(): stored new http header:
[Authorization: Basic NDQ3N00000000000011111TQ=]
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: http_async_client
[async_http.c:731]: header_list_add(): stored new http header:
[Content-Type: application/json]
Jul 12 08:12:00 sip kamailio[22303]: INFO: <script>: To User: 923335550609
From User: 923135082344
Jul 12 08:12:00 sip
kamailio[22303]: DEBUG: http_async_client
[async_http.c:472]: async_send_query(): transaction suspended
[47588:281286645]
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client
[async_http.c:388]: notification_socket_cb(): query received: [
http://app.com/push/notification/923335550609] (0x7f3ac5048008)
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: http_async_client
[async_http.c:625]: async_push_query(): query sent [
http://app.com/push/notification/923335550609] (0x7f3ac5048008) to worker 4
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:423]: new_request(): received query
http://app.com/push/notification/923335550609 with timeout 5000,
tls_verify_peer 1, tls_verify_host 1 (param=0x7f3ac5048008)
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/receive.c:289]:
receive_msg(): request-route executed in: 5910 usec
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client
[hm_hash.c:80]: build_hash_key(): received id 0x28b12f0 (8)-> 0x28b12f0 (9)
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client
[hm_hash.c:93]: build_hash_key(): hash for 0x28b12f0 is 867
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client
[hm_hash.c:119]: build_http_m_cell(): hash id for 0x28b12f0 is 867
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client
[hm_hash.c:130]: link_http_m_cell(): linking new cell 0x7f3ac4ff5778 to
table 0x7f3ac4fc5418 [867]
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:530]: new_request(): Adding easy 0x28b12f0 to multi 0x289a570
(http://app.com/push/notification/923335550609)
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:53]: multi_timer_cb(): multi_timer_cb: Setting timeout to 1 ms
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/xavp.c:446]:
xavp_destroy_list(): destroying xavp list (nil)
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core> [core/receive.c:378]:
receive_msg(): cleaning up
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core>
[core/parser/sdp/sdp.c:794]: free_sdp(): _sdp = 0x7f3ac975eb18
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core>
[core/parser/sdp/sdp.c:796]: free_sdp(): sdp = 0x7f3ac972e418
Jul 12 08:12:00 sip kamailio[22303]: DEBUG: <core>
[core/parser/sdp/sdp.c:798]: free_sdp(): session = 0x7f3ac9729ce0
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:67]: timer_cb(): timeout on socket -1
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:53]: multi_timer_cb(): multi_timer_cb: Setting timeout to 1 ms
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:561]: check_multi_info(): REMAINING: 1
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:67]: timer_cb(): timeout on socket -1
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:53]: multi_timer_cb(): multi_timer_cb: Setting timeout to 1 ms
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:561]: check_multi_info(): REMAINING: 1
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:67]: timer_cb(): timeout on socket -1
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:53]: multi_timer_cb(): multi_timer_cb: Setting timeout to 1 ms
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:561]: check_multi_info(): REMAINING: 1
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:67]: timer_cb(): timeout on socket -1
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:53]: multi_timer_cb(): multi_timer_cb: Setting timeout to 3 ms
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:561]: check_multi_info(): REMAINING: 1
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:67]: timer_cb(): timeout on socket -1
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:53]: multi_timer_cb(): multi_timer_cb: Setting timeout to 1 ms
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:561]: check_multi_info(): REMAINING: 1
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:67]: timer_cb(): timeout on socket -1
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:161]: sock_cb(): socket callback: s=11 e=0x28b12f0 what=OUT
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:179]: sock_cb(): Adding data: OUT
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client
[hm_hash.c:80]: build_hash_key(): received id 0x28b12f0 (8)-> 0x28b12f0 (9)
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client
[hm_hash.c:93]: build_hash_key(): hash for 0x28b12f0 is 867
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client
[hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x28b12f0
found on table entry 867
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:615]: setsock(): added event 0x28ba160 to socket 11
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:53]: multi_timer_cb(): multi_timer_cb: Setting timeout to 199
ms
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:561]: check_multi_info(): REMAINING: 1
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client
[hm_hash.c:80]: build_hash_key(): received id 0x28b12f0 (8)-> 0x28b12f0 (9)
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client
[hm_hash.c:93]: build_hash_key(): hash for 0x28b12f0 is 867
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client
[hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x28b12f0
found on table entry 867
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:96]: event_cb(): activity 4 on socket 11: action 2
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:129]: event_cb(): performing action 2 on socket 11
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:161]: sock_cb(): socket callback: s=11 e=0x28b12f0 what=IN
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:184]: sock_cb(): Changing action from OUT to IN
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:615]: setsock(): added event 0x28ba160 to socket 11
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:131]: event_cb(): action 2 on socket 11 performed
Jul 12 08:12:00 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:561]: check_multi_info(): REMAINING: 1
Jul 12 08:12:01 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:67]: timer_cb(): timeout on socket -1
Jul 12 08:12:01 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:561]: check_multi_info(): REMAINING: 1
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core> [core/udp_server.c:492]:
udp_rcv_loop(): received on udp socket: (118/100/635) [[SIP/2.0 180 Ringing
0D 0A CSeq: 2 INVITE 0D 0A Call-ID: v51-8AifZ2mXi4RFMRej9A.. 0D 0A From:
<sip:923135082344@sip.]]
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:614]: parse_msg(): SIP Reply (status):
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:616]: parse_msg(): version: <SIP/2.0>
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:618]: parse_msg(): status: <180>
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:620]: parse_msg(): reason: <Ringing>
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <2>
<INVITE>
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core>
[core/parser/parse_addr_spec.c:185]: parse_to_param(): add param:
tag=26d24c34
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core>
[core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header
reached, state=29
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:171]: get_hdr_field(): <To> [71]; uri=[
sip:923335550609@sip.talkhomeappcall.com;transport=UDP]
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:172]: get_hdr_field(): to body [<
sip:923335550609@sip.talkhomeappcall.com;transport=UDP>]
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core>
[core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232,
<branch> = <z9hG4bK4e9b.c598ebabb2493d5c9aebf673208c6bea.0>; state=9
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core>
[core/parser/parse_via.c:2681]: parse_via(): parsing via: next via
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core>
[core/parser/parse_via.c:1303]: parse_via_param(): Found param type 235,
<rport> = <61717>; state=6
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core>
[core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232,
<branch> = <z9hG4bK-524287-1---6a391e4fb0f8a8f6>; state=16
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core>
[core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:492]: parse_headers(): Via found, flags=2
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:494]: parse_headers(): this is the first via
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core> [core/receive.c:205]:
receive_msg(): --- received sip message - reply - call-id:
[v51-8AifZ2mXi4RFMRej9A..] - cseq: [2 INVITE]
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: tm [t_lookup.c:1019]:
t_check_msg(): msg (0x7f3ac975e930) id=1137 global id=1135 T start=(nil)
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: tm [t_lookup.c:897]:
t_reply_matching(): t_reply_matching: hash 47588 label 0 branch 0
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: tm [t_lookup.c:951]:
t_reply_matching(): reply (0x7f3ac975e930) matched an active transaction
(T=0x7f3ac5004448)!
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: tm [t_lookup.c:1088]:
t_check_msg(): msg (0x7f3ac975e930) id=1137 global id=1137 T
end=0x7f3ac5004448
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: tm [t_reply.c:2207]:
reply_received(): org. status uas=0, uac[0]=0 local=0 is_invite=1)
Jul 12 08:12:01 sip kamailio[22302]: INFO: <script>:
[R-EXTERNAL_REPLY:v51-8AifZ2mXi4RFMRej9A..] -> saw reply to METHOD:INVITE
RESPONSE:'180 Ringing' from 115.186.137.147:5060
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: tm [t_lookup.c:1019]:
t_check_msg(): msg (0x7f3ac975e930) id=1137 global id=1137 T
start=0x7f3ac5004448
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: tm [t_lookup.c:1091]:
t_check_msg(): T (0x7f3ac5004448) already found for msg (0x7f3ac975e930)!
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:183]: get_hdr_field(): content_length=0
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:89]: get_hdr_field(): found end of header
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core>
[core/socket_info.c:564]: grep_sock_info(): checking if host==us: 13==12 &&
[18.130.57.226] == [172.31.21.87]
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core>
[core/socket_info.c:583]: grep_sock_info(): checking advertise if host==us:
13==13 && [18.130.57.226] == [18.130.57.226]
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: textops [textops.c:3063]:
has_body_helper(): content length is zero
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: tm [t_reply.c:1263]:
t_should_relay_response(): ->>>>>>>>> T_code=0, new_code=180
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: tm [t_reply.c:1786]:
relay_reply(): branch=0, save=0, relay=0 icode=0
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core>
[core/msg_translator.c:2265]: generate_res_buf_from_sip_res(): old size:
635, new size: 552
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core>
[core/msg_translator.c:2283]: generate_res_buf_from_sip_res(): copied size:
orig:573, new: 490, rest: 62 msg=#012SIP/2.0 180 Ringing#015#012CSeq: 2
INVITE#015#012Call-ID: v51-8AifZ2mXi4RFMRej9A..#015#012From: <
sip:923135082344@sip.talkhomeappcall.com;transport=UDP>;tag=dc4e5a14#015#012To:
<sip:923335550609@sip.talkhomeappcall.com;transport=UDP>;tag=26d24c34#015#012Via:
SIP/2.0/UDP
115.186.137.147:61717;rport=61717;branch=z9hG4bK-524287-1---6a391e4fb0f8a8f6#015#012Record-Route:
<sip:18.130.57.226;lr=on;ftag=dc4e5a14>#015#012Contact: "923335550609"
<sip:923335550609@115.186.137.147:5060;transport=udp;registering_acc=sip_talkhomeappcall_com>#015#012User-Agent:
Jitsi2.10.5550Windows 10#015#012Content-Length: 0
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core> [core/receive.c:362]:
receive_msg(): reply-route executed in: 2261 usec
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core> [core/xavp.c:446]:
xavp_destroy_list(): destroying xavp list (nil)
Jul 12 08:12:01 sip kamailio[22302]: DEBUG: <core> [core/receive.c:378]:
receive_msg(): cleaning up
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core> [core/udp_server.c:492]:
udp_rcv_loop(): received on udp socket: (118/100/635) [[SIP/2.0 180 Ringing
0D 0A CSeq: 2 INVITE 0D 0A Call-ID: v51-8AifZ2mXi4RFMRej9A.. 0D 0A From:
<sip:923135082344@sip.]]
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:614]: parse_msg(): SIP Reply (status):
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:616]: parse_msg(): version: <SIP/2.0>
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:618]: parse_msg(): status: <180>
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:620]: parse_msg(): reason: <Ringing>
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <2>
<INVITE>
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core>
[core/parser/parse_addr_spec.c:185]: parse_to_param(): add param:
tag=26d24c34
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core>
[core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header
reached, state=29
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:171]: get_hdr_field(): <To> [71]; uri=[
sip:923335550609@sip.talkhomeappcall.com;transport=UDP]
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:172]: get_hdr_field(): to body [<
sip:923335550609@sip.talkhomeappcall.com;transport=UDP>]
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core>
[core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232,
<branch> = <z9hG4bK4e9b.c598ebabb2493d5c9aebf673208c6bea.0>; state=9
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core>
[core/parser/parse_via.c:2681]: parse_via(): parsing via: next via
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core>
[core/parser/parse_via.c:1303]: parse_via_param(): Found param type 235,
<rport> = <61717>; state=6
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core>
[core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232,
<branch> = <z9hG4bK-524287-1---6a391e4fb0f8a8f6>; state=16
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core>
[core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:492]: parse_headers(): Via found, flags=2
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:494]: parse_headers(): this is the first via
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core> [core/receive.c:205]:
receive_msg(): --- received sip message - reply - call-id:
[v51-8AifZ2mXi4RFMRej9A..] - cseq: [2 INVITE]
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: tm [t_lookup.c:1019]:
t_check_msg(): msg (0x7f3ac975e930) id=1106 global id=1105 T
start=0xffffffffffffffff
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: tm [t_lookup.c:897]:
t_reply_matching(): t_reply_matching: hash 47588 label 0 branch 0
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: tm [t_lookup.c:951]:
t_reply_matching(): reply (0x7f3ac975e930) matched an active transaction
(T=0x7f3ac5004448)!
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: tm [t_lookup.c:1088]:
t_check_msg(): msg (0x7f3ac975e930) id=1106 global id=1106 T
end=0x7f3ac5004448
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: tm [t_reply.c:2207]:
reply_received(): org. status uas=180, uac[0]=180 local=0 is_invite=1)
Jul 12 08:12:01 sip kamailio[22303]: INFO: <script>:
[R-EXTERNAL_REPLY:v51-8AifZ2mXi4RFMRej9A..] -> saw reply to METHOD:INVITE
RESPONSE:'180 Ringing' from 115.186.137.147:5060
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: tm [t_lookup.c:1019]:
t_check_msg(): msg (0x7f3ac975e930) id=1106 global id=1106 T
start=0x7f3ac5004448
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: tm [t_lookup.c:1091]:
t_check_msg(): T (0x7f3ac5004448) already found for msg (0x7f3ac975e930)!
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:183]: get_hdr_field(): content_length=0
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:89]: get_hdr_field(): found end of header
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core>
[core/socket_info.c:564]: grep_sock_info(): checking if host==us: 13==12 &&
[18.130.57.226] == [172.31.21.87]
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core>
[core/socket_info.c:583]: grep_sock_info(): checking advertise if host==us:
13==13 && [18.130.57.226] == [18.130.57.226]
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: textops [textops.c:3063]:
has_body_helper(): content length is zero
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: tm [t_reply.c:1263]:
t_should_relay_response(): ->>>>>>>>> T_code=180, new_code=180
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: tm [t_reply.c:1786]:
relay_reply(): branch=0, save=0, relay=0 icode=0
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core>
[core/msg_translator.c:2265]: generate_res_buf_from_sip_res(): old size:
635, new size: 552
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core>
[core/msg_translator.c:2283]: generate_res_buf_from_sip_res(): copied size:
orig:573, new: 490, rest: 62 msg=#012SIP/2.0 180 Ringing#015#012CSeq: 2
INVITE#015#012Call-ID: v51-8AifZ2mXi4RFMRej9A..#015#012From: <
sip:923135082344@sip.talkhomeappcall.com;transport=UDP>;tag=dc4e5a14#015#012To:
<sip:923335550609@sip.talkhomeappcall.com;transport=UDP>;tag=26d24c34#015#012Via:
SIP/2.0/UDP
115.186.137.147:61717;rport=61717;branch=z9hG4bK-524287-1---6a391e4fb0f8a8f6#015#012Record-Route:
<sip:18.130.57.226;lr=on;ftag=dc4e5a14>#015#012Contact: "923335550609"
<sip:923335550609@115.186.137.147:5060;transport=udp;registering_acc=sip_talkhomeappcall_com>#015#012User-Agent:
Jitsi2.10.5550Windows 10#015#012Content-Length: 0
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core> [core/receive.c:362]:
receive_msg(): reply-route executed in: 2206 usec
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core> [core/xavp.c:446]:
xavp_destroy_list(): destroying xavp list (nil)
Jul 12 08:12:01 sip kamailio[22303]: DEBUG: <core> [core/receive.c:378]:
receive_msg(): cleaning up
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client
[hm_hash.c:80]: build_hash_key(): received id 0x28b12f0 (8)-> 0x28b12f0 (9)
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client
[hm_hash.c:93]: build_hash_key(): hash for 0x28b12f0 is 867
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client
[hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x28b12f0
found on table entry 867
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:96]: event_cb(): activity 2 on socket 11: action 1
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:129]: event_cb(): performing action 1 on socket 11
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:249]: write_cb(): data received: HTTP/1.1 200 OK#015#012 [17]
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client
[hm_hash.c:80]: build_hash_key(): received id 0x28b12f0 (8)-> 0x28b12f0 (9)
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client
[hm_hash.c:93]: build_hash_key(): hash for 0x28b12f0 is 867
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client
[hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x28b12f0
found on table entry 867
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:289]: write_cb(): getting easy handler info (0x28b12f0)
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:249]: write_cb(): data received: Content-Length: 40#015#012
[20]
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client
[hm_hash.c:80]: build_hash_key(): received id 0x28b12f0 (8)-> 0x28b12f0 (9)
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client
[hm_hash.c:93]: build_hash_key(): hash for 0x28b12f0 is 867
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client
[hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x28b12f0
found on table entry 867
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:289]: write_cb(): getting easy handler info (0x28b12f0)
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:249]: write_cb(): data received: Content-Type:
application/json; charset=utf-8#015#012 [47]
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client
[hm_hash.c:80]: build_hash_key(): received id 0x28b12f0 (8)-> 0x28b12f0 (9)
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client
[hm_hash.c:93]: build_hash_key(): hash for 0x28b12f0 is 867
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client
[hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x28b12f0
found on table entry 867
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:289]: write_cb(): getting easy handler info (0x28b12f0)
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:249]: write_cb(): data received: Server:
Microsoft-HTTPAPI/2.0#015#012 [31]
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client
[hm_hash.c:80]: build_hash_key(): received id 0x28b12f0 (8)-> 0x28b12f0 (9)
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client
[hm_hash.c:93]: build_hash_key(): hash for 0x28b12f0 is 867
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client
[hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x28b12f0
found on table entry 867
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:289]: write_cb(): getting easy handler info (0x28b12f0)
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:249]: write_cb(): data received: Date: Thu, 12 Jul 2018
08:12:51 GMT#015#012 [37]
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client
[hm_hash.c:80]: build_hash_key(): received id 0x28b12f0 (8)-> 0x28b12f0 (9)
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client
[hm_hash.c:93]: build_hash_key(): hash for 0x28b12f0 is 867
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client
[hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x28b12f0
found on table entry 867
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:289]: write_cb(): getting easy handler info (0x28b12f0)
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:249]: write_cb(): data received: #015#012 [2]
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client
[hm_hash.c:80]: build_hash_key(): received id 0x28b12f0 (8)-> 0x28b12f0 (9)
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client
[hm_hash.c:93]: build_hash_key(): hash for 0x28b12f0 is 867
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client
[hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x28b12f0
found on table entry 867
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:289]: write_cb(): getting easy handler info (0x28b12f0)
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:249]: write_cb(): data received:
{"message":"Message","status":"Success"} [40]
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client
[hm_hash.c:80]: build_hash_key(): received id 0x28b12f0 (8)-> 0x28b12f0 (9)
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client
[hm_hash.c:93]: build_hash_key(): hash for 0x28b12f0 is 867
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client
[hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x28b12f0
found on table entry 867
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:289]: write_cb(): getting easy handler info (0x28b12f0)
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:161]: sock_cb(): socket callback: s=11 e=0x28b12f0 what=REMOVE
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:166]: sock_cb(): freeing event 0x28ba160
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:131]: event_cb(): action 1 on socket 11 performed
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:561]: check_multi_info(): REMAINING: 0
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:568]: check_multi_info(): DONE:
http://app.com/push/notification/923335550609 => (0)
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client
[hm_hash.c:80]: build_hash_key(): received id 0x28b12f0 (8)-> 0x28b12f0 (9)
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client
[hm_hash.c:93]: build_hash_key(): hash for 0x28b12f0 is 867
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client
[hm_hash.c:157]: http_m_cell_lookup(): http_m_cell with easy=0x28b12f0
found on table entry 867
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client
[async_http.c:162]: async_http_cb(): query result = HTTP/1.1 200
OK#015#012Content-Length: 40#015#012Content-Type: application/json;
charset=utf-8#015#012Server: Microsoft-HTTPAPI/2.0#015#012Date: Thu, 12 Jul
2018 08:12:51
GMT#015#012#015#012{"message":"Message","status":"Success"}
[194]
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: <core>
[core/parser/msg_parser.c:614]: parse_msg(): SIP Reply (status):
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: <core>
[core/parser/msg_parser.c:616]: parse_msg(): version: <HTTP/1.1>
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: <core>
[core/parser/msg_parser.c:618]: parse_msg(): status: <200>
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: <core>
[core/parser/msg_parser.c:620]: parse_msg(): reason: <OK>
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: <core>
[core/parser/msg_parser.c:183]: get_hdr_field(): content_length=40
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: <core>
[core/parser/msg_parser.c:89]: get_hdr_field(): found end of header
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client
[async_http.c:209]: async_http_cb(): successfully parsed http reply
0x7f3ac975e930
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: tm [t_lookup.c:1585]:
t_lookup_ident(): transaction found
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client
[async_http.c:241]: async_http_cb(): resuming transaction (47588:281286645)
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: tm [t_lookup.c:1585]:
t_lookup_ident(): transaction found
Jul 12 08:12:02 sip kamailio[22321]: INFO: <script>:
[PUSH-HTTP-REPLY:v51-8AifZ2mXi4RFMRej9A..] -> status 200
Jul 12 08:12:02 sip kamailio[22321]: INFO: <script>:
[PUSH-HTTP-REPLY:v51-8AifZ2mXi4RFMRej9A..] -> body
{"message":"Message","status":"Success"}
Jul 12 08:12:02 sip kamailio[22321]: INFO: <script>:
[PUSH-HTTP-REPLY:v51-8AifZ2mXi4RFMRej9A..] ->
v51-8AifZ2mXi4RFMRej9A..|end|issued has successfully send push notification
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client
[async_http.h:135]: free_async_query(): freeing query 0x7f3ac5048008
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:579]: check_multi_info(): reply: [200] HTTP/1.1 200
OK#015#012Content-Length: 40#015#012Content-Type: application/json;
charset=utf-8#015#012Server: Microsoft-HTTPAPI/2.0#015#012Date: Thu, 12 Jul
2018 08:12:51
GMT#015#012#015#012{"message":"Message","status":"Success"}
[194]
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:584]: check_multi_info(): cleaning up cell 0x7f3ac4ff5778
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:589]: check_multi_info(): Removing handle 0x28b12f0
Jul 12 08:12:02 sip kamailio[22321]: DEBUG: http_async_client
[http_multi.c:147]: event_cb(): last transfer done, kill timeout
Jul 12 08:12:02 sip kamailio[22336]: DEBUG: <core> [core/io_wait.h:602]:
io_watch_del(): DBG: io_watch_del (0xa53880, 107, -1, 0x0) fd_no=45 called
Jul 12 08:12:02 sip kamailio[22336]: DEBUG: <core> [core/tcp_main.c:4196]:
handle_tcpconn_ev(): sending to child, events 1
Jul 12 08:12:02 sip kamailio[22336]: DEBUG: <core> [core/tcp_main.c:3878]:
send2child(): selected tcp worker 4 31(22332) for activity on [tls:
172.31.21.87:5061], 0x7f3ac504ba10
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core> [core/tcp_read.c:1740]:
handle_io(): received n=8 con=0x7f3ac504ba10, fd=12
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core> [core/tcp_read.c:1540]:
tcp_read_req(): content-length=287
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core>
[core/parser/msg_parser.c:604]: parse_msg(): SIP Request:
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core>
[core/parser/msg_parser.c:606]: parse_msg(): method: <PUBLISH>
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core>
[core/parser/msg_parser.c:608]: parse_msg(): uri: <
sip:447825152591@sip.talkhomeappcall.com;transport=TLS>
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core>
[core/parser/msg_parser.c:610]: parse_msg(): version: <SIP/2.0>
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core>
[core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232,
<branch> = <z9hG4bK-524287-1---97bfb6537506e53b>; state=16
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core>
[core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core>
[core/parser/msg_parser.c:492]: parse_headers(): Via found, flags=2
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core>
[core/parser/msg_parser.c:494]: parse_headers(): this is the first via
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core>
[core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header
reached, state=10
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core>
[core/parser/msg_parser.c:171]: get_hdr_field(): <To> [58]; uri=[
sip:447825152591@sip.talkhomeappcall.com;transport=TLS]
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core>
[core/parser/msg_parser.c:172]: get_hdr_field(): to body [<
sip:447825152591@sip.talkhomeappcall.com;transport=TLS>#015#012]
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core>
[core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <1>
<PUBLISH>
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core> [core/receive.c:205]:
receive_msg(): --- received sip message - request - call-id:
[9k-onV_CLivT1AJd9PfB1A..] - cseq: [1 PUBLISH]
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core> [core/receive.c:248]:
receive_msg(): preparing to run routing scripts...
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core>
[core/parser/msg_parser.c:183]: get_hdr_field(): content_length=287
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core>
[core/parser/msg_parser.c:89]: get_hdr_field(): found end of header
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core>
[core/parser/parse_addr_spec.c:185]: parse_to_param(): add param:
tag=eb6f1d48
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core>
[core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header
reached, state=29
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: sanity [sanity_mod.c:256]:
w_sanity_check(): sanity checks result: 1
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: maxfwd [mf_funcs.c:74]:
is_maxfwd_present(): value = 70
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: maxfwd [maxfwd.c:148]:
process_maxfwd_header(): value 70 decreased to 50
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: siputils [sipops.c:159]:
is_first_hop(): no 2nd via found - first hop
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: textops [textops.c:3083]:
has_body_helper(): content type is 196613
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: siputils [checks.c:120]:
has_totag(): no totag
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core>
[core/msg_translator.c:159]: check_via_address(): (115.186.137.147,
192.168.0.104, 0)
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core> [core/tcp_main.c:2226]:
tcpconn_send_put(): send from reader (22332 (31)), reusing fd
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core> [core/tcp_main.c:2460]:
tcpconn_do_send(): sending...
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core> [core/tcp_main.c:2494]:
tcpconn_do_send(): after real write: c= 0x7f3ac504ba10 n=421 fd=12
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core> [core/tcp_main.c:2495]:
tcpconn_do_send():
buf=#012#027#003#001#001�#026-�Jz�8(+è#015��C��G#036�=�#012\{��#033[!��#031[#0015#036��$�#027#020#016<�!S�v-��J�f�#021�*��P(��nE�#017#001��EY#031띪+�n�����<%#023a�R�Cs#030�HR�k
��ɠ���G�M��:#012\b>�u�%����������?��#003e�a�Dv&%��-��X�y^ў#002cs#020l��2#033#025#037��U#001�`#027����#002q#016ޑH��/M7�!#014b�Y��#014;�[�$��Ω#012keRN�#013Y#030a#017��#031���#030�#032(�6\#013ԭ�#001�#020�x#003#016[��gd6#035�t�XH#026���#032�+��i�
�<�?�_�#033�WCa���?�B��|`'|��
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core> [core/receive.c:289]:
receive_msg(): request-route executed in: 1841 usec
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core> [core/xavp.c:446]:
xavp_destroy_list(): destroying xavp list (nil)
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core> [core/receive.c:378]:
receive_msg(): cleaning up
Jul 12 08:12:02 sip kamailio[22332]: DEBUG: <core> [core/io_wait.h:380]:
io_watch_add(): DBG: io_watch_add(0xa9cf40, 12, 2, 0x7f3ac504ba10), fd_no=1
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core> [core/udp_server.c:492]:
udp_rcv_loop(): received on udp socket: (118/100/635) [[SIP/2.0 180 Ringing
0D 0A CSeq: 2 INVITE 0D 0A Call-ID: v51-8AifZ2mXi4RFMRej9A.. 0D 0A From:
<sip:923135082344@sip.]]
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:614]: parse_msg(): SIP Reply (status):
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:616]: parse_msg(): version: <SIP/2.0>
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:618]: parse_msg(): status: <180>
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:620]: parse_msg(): reason: <Ringing>
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <2>
<INVITE>
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core>
[core/parser/parse_addr_spec.c:185]: parse_to_param(): add param:
tag=26d24c34
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core>
[core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header
reached, state=29
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:171]: get_hdr_field(): <To> [71]; uri=[
sip:923335550609@sip.talkhomeappcall.com;transport=UDP]
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:172]: get_hdr_field(): to body [<
sip:923335550609@sip.talkhomeappcall.com;transport=UDP>]
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core>
[core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232,
<branch> = <z9hG4bK4e9b.c598ebabb2493d5c9aebf673208c6bea.0>; state=9
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core>
[core/parser/parse_via.c:2681]: parse_via(): parsing via: next via
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core>
[core/parser/parse_via.c:1303]: parse_via_param(): Found param type 235,
<rport> = <61717>; state=6
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core>
[core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232,
<branch> = <z9hG4bK-524287-1---6a391e4fb0f8a8f6>; state=16
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core>
[core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:492]: parse_headers(): Via found, flags=2
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:494]: parse_headers(): this is the first via
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core> [core/receive.c:205]:
receive_msg(): --- received sip message - reply - call-id:
[v51-8AifZ2mXi4RFMRej9A..] - cseq: [2 INVITE]
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: tm [t_lookup.c:1019]:
t_check_msg(): msg (0x7f3ac975e930) id=1138 global id=1137 T
start=0xffffffffffffffff
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: tm [t_lookup.c:897]:
t_reply_matching(): t_reply_matching: hash 47588 label 0 branch 0
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: tm [t_lookup.c:951]:
t_reply_matching(): reply (0x7f3ac975e930) matched an active transaction
(T=0x7f3ac5004448)!
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: tm [t_lookup.c:1088]:
t_check_msg(): msg (0x7f3ac975e930) id=1138 global id=1138 T
end=0x7f3ac5004448
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: tm [t_reply.c:2207]:
reply_received(): org. status uas=180, uac[0]=180 local=0 is_invite=1)
Jul 12 08:12:02 sip kamailio[22302]: INFO: <script>:
[R-EXTERNAL_REPLY:v51-8AifZ2mXi4RFMRej9A..] -> saw reply to METHOD:INVITE
RESPONSE:'180 Ringing' from 115.186.137.147:5060
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: tm [t_lookup.c:1019]:
t_check_msg(): msg (0x7f3ac975e930) id=1138 global id=1138 T
start=0x7f3ac5004448
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: tm [t_lookup.c:1091]:
t_check_msg(): T (0x7f3ac5004448) already found for msg (0x7f3ac975e930)!
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:183]: get_hdr_field(): content_length=0
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:89]: get_hdr_field(): found end of header
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core>
[core/socket_info.c:564]: grep_sock_info(): checking if host==us: 13==12 &&
[18.130.57.226] == [172.31.21.87]
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core>
[core/socket_info.c:583]: grep_sock_info(): checking advertise if host==us:
13==13 && [18.130.57.226] == [18.130.57.226]
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: textops [textops.c:3063]:
has_body_helper(): content length is zero
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: tm [t_reply.c:1263]:
t_should_relay_response(): ->>>>>>>>> T_code=180, new_code=180
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: tm [t_reply.c:1786]:
relay_reply(): branch=0, save=0, relay=0 icode=0
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core>
[core/msg_translator.c:2265]: generate_res_buf_from_sip_res(): old size:
635, new size: 552
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core>
[core/msg_translator.c:2283]: generate_res_buf_from_sip_res(): copied size:
orig:573, new: 490, rest: 62 msg=#012SIP/2.0 180 Ringing#015#012CSeq: 2
INVITE#015#012Call-ID: v51-8AifZ2mXi4RFMRej9A..#015#012From: <
sip:923135082344@sip.talkhomeappcall.com;transport=UDP>;tag=dc4e5a14#015#012To:
<sip:923335550609@sip.talkhomeappcall.com;transport=UDP>;tag=26d24c34#015#012Via:
SIP/2.0/UDP
115.186.137.147:61717;rport=61717;branch=z9hG4bK-524287-1---6a391e4fb0f8a8f6#015#012Record-Route:
<sip:18.130.57.226;lr=on;ftag=dc4e5a14>#015#012Contact: "923335550609"
<sip:923335550609@115.186.137.147:5060;transport=udp;registering_acc=sip_talkhomeappcall_com>#015#012User-Agent:
Jitsi2.10.5550Windows 10#015#012Content-Length: 0
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core> [core/receive.c:362]:
receive_msg(): reply-route executed in: 2109 usec
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core> [core/xavp.c:446]:
xavp_destroy_list(): destroying xavp list (nil)
Jul 12 08:12:02 sip kamailio[22302]: DEBUG: <core> [core/receive.c:378]:
receive_msg(): cleaning up
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core> [core/udp_server.c:492]:
udp_rcv_loop(): received on udp socket: (118/100/635) [[SIP/2.0 180 Ringing
0D 0A CSeq: 2 INVITE 0D 0A Call-ID: v51-8AifZ2mXi4RFMRej9A.. 0D 0A From:
<sip:923135082344@sip.]]
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:614]: parse_msg(): SIP Reply (status):
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:616]: parse_msg(): version: <SIP/2.0>
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:618]: parse_msg(): status: <180>
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:620]: parse_msg(): reason: <Ringing>
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <2>
<INVITE>
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core>
[core/parser/parse_addr_spec.c:185]: parse_to_param(): add param:
tag=26d24c34
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core>
[core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header
reached, state=29
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:171]: get_hdr_field(): <To> [71]; uri=[
sip:923335550609@sip.talkhomeappcall.com;transport=UDP]
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:172]: get_hdr_field(): to body [<
sip:923335550609@sip.talkhomeappcall.com;transport=UDP>]
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core>
[core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232,
<branch> = <z9hG4bK4e9b.c598ebabb2493d5c9aebf673208c6bea.0>; state=9
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core>
[core/parser/parse_via.c:2681]: parse_via(): parsing via: next via
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core>
[core/parser/parse_via.c:1303]: parse_via_param(): Found param type 235,
<rport> = <61717>; state=6
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core>
[core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232,
<branch> = <z9hG4bK-524287-1---6a391e4fb0f8a8f6>; state=16
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core>
[core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:492]: parse_headers(): Via found, flags=2
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:494]: parse_headers(): this is the first via
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core> [core/receive.c:205]:
receive_msg(): --- received sip message - reply - call-id:
[v51-8AifZ2mXi4RFMRej9A..] - cseq: [2 INVITE]
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: tm [t_lookup.c:1019]:
t_check_msg(): msg (0x7f3ac975e930) id=1107 global id=1106 T
start=0xffffffffffffffff
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: tm [t_lookup.c:897]:
t_reply_matching(): t_reply_matching: hash 47588 label 0 branch 0
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: tm [t_lookup.c:951]:
t_reply_matching(): reply (0x7f3ac975e930) matched an active transaction
(T=0x7f3ac5004448)!
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: tm [t_lookup.c:1088]:
t_check_msg(): msg (0x7f3ac975e930) id=1107 global id=1107 T
end=0x7f3ac5004448
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: tm [t_reply.c:2207]:
reply_received(): org. status uas=180, uac[0]=180 local=0 is_invite=1)
Jul 12 08:12:04 sip kamailio[22303]: INFO: <script>:
[R-EXTERNAL_REPLY:v51-8AifZ2mXi4RFMRej9A..] -> saw reply to METHOD:INVITE
RESPONSE:'180 Ringing' from 115.186.137.147:5060
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: tm [t_lookup.c:1019]:
t_check_msg(): msg (0x7f3ac975e930) id=1107 global id=1107 T
start=0x7f3ac5004448
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: tm [t_lookup.c:1091]:
t_check_msg(): T (0x7f3ac5004448) already found for msg (0x7f3ac975e930)!
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:183]: get_hdr_field(): content_length=0
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:89]: get_hdr_field(): found end of header
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core>
[core/socket_info.c:564]: grep_sock_info(): checking if host==us: 13==12 &&
[18.130.57.226] == [172.31.21.87]
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core>
[core/socket_info.c:583]: grep_sock_info(): checking advertise if host==us:
13==13 && [18.130.57.226] == [18.130.57.226]
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: textops [textops.c:3063]:
has_body_helper(): content length is zero
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: tm [t_reply.c:1263]:
t_should_relay_response(): ->>>>>>>>> T_code=180, new_code=180
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: tm [t_reply.c:1786]:
relay_reply(): branch=0, save=0, relay=0 icode=0
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core>
[core/msg_translator.c:2265]: generate_res_buf_from_sip_res(): old size:
635, new size: 552
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core>
[core/msg_translator.c:2283]: generate_res_buf_from_sip_res(): copied size:
orig:573, new: 490, rest: 62 msg=#012SIP/2.0 180 Ringing#015#012CSeq: 2
INVITE#015#012Call-ID: v51-8AifZ2mXi4RFMRej9A..#015#012From: <
sip:923135082344@sip.talkhomeappcall.com;transport=UDP>;tag=dc4e5a14#015#012To:
<sip:923335550609@sip.talkhomeappcall.com;transport=UDP>;tag=26d24c34#015#012Via:
SIP/2.0/UDP
115.186.137.147:61717;rport=61717;branch=z9hG4bK-524287-1---6a391e4fb0f8a8f6#015#012Record-Route:
<sip:18.130.57.226;lr=on;ftag=dc4e5a14>#015#012Contact: "923335550609"
<sip:923335550609@115.186.137.147:5060;transport=udp;registering_acc=sip_talkhomeappcall_com>#015#012User-Agent:
Jitsi2.10.5550Windows 10#015#012Content-Length: 0
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core> [core/receive.c:362]:
receive_msg(): reply-route executed in: 1784 usec
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core> [core/xavp.c:446]:
xavp_destroy_list(): destroying xavp list (nil)
Jul 12 08:12:04 sip kamailio[22303]: DEBUG: <core> [core/receive.c:378]:
receive_msg(): cleaning up
Jul 12 08:12:08 sip kamailio[22332]: DEBUG: <core> [core/io_wait.h:602]:
io_watch_del(): DBG: io_watch_del (0xa9cf40, 12, -1, 0x10) fd_no=2 called
Jul 12 08:12:08 sip kamailio[22332]: DEBUG: <core> [core/tcp_read.c:1664]:
release_tcpconn(): releasing con 0x7f3ac504ba10, state 1, fd=12, id=6
([115.186.137.147]:54391 -> [115.186.137.147]:5061)
Jul 12 08:12:08 sip kamailio[22332]: DEBUG: <core> [core/tcp_read.c:1665]:
release_tcpconn(): extra_data 0x7f3ac5048f40
Jul 12 08:12:08 sip kamailio[22336]: DEBUG: <core> [core/tcp_main.c:3308]:
handle_tcp_child(): reader response= 7f3ac504ba10, 1 from 4
Jul 12 08:12:08 sip kamailio[22336]: DEBUG: <core> [core/io_wait.h:380]:
io_watch_add(): DBG: io_watch_add(0xa53880, 107, 2, 0x7f3ac504ba10),
fd_no=44
Jul 12 08:12:08 sip kamailio[22336]: DEBUG: <core> [core/tcp_main.c:3435]:
handle_tcp_child(): CONN_RELEASE 0x7f3ac504ba10 refcnt= 1
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/udp_server.c:492]:
udp_rcv_loop(): received on udp socket: (106/100/660) [[CANCEL
sip:923335550609@sip.talkhomeappcall.com;transport=UDP SIP/2.0 0D 0A Via:
SIP/2.0/UDP 115.186.137.]]
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:604]: parse_msg(): SIP Request:
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:606]: parse_msg(): method: <CANCEL>
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:608]: parse_msg(): uri: <
sip:923335550609@sip.talkhomeappcall.com;transport=UDP>
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:610]: parse_msg(): version: <SIP/2.0>
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232,
<branch> = <z9hG4bK-524287-1---6a391e4fb0f8a8f6>; state=16
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:492]: parse_headers(): Via found, flags=2
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:494]: parse_headers(): this is the first via
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header
reached, state=10
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:171]: get_hdr_field(): <To> [58]; uri=[
sip:923335550609@sip.talkhomeappcall.com;transport=UDP]
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:172]: get_hdr_field(): to body [<
sip:923335550609@sip.talkhomeappcall.com;transport=UDP>#015#012]
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <2>
<CANCEL>
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/receive.c:205]:
receive_msg(): --- received sip message - request - call-id:
[v51-8AifZ2mXi4RFMRej9A..] - cseq: [2 CANCEL]
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/receive.c:248]:
receive_msg(): preparing to run routing scripts...
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:183]: get_hdr_field(): content_length=0
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:89]: get_hdr_field(): found end of header
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/parse_addr_spec.c:185]: parse_to_param(): add param:
tag=dc4e5a14
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header
reached, state=29
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: sanity [sanity_mod.c:256]:
w_sanity_check(): sanity checks result: 1
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: maxfwd [mf_funcs.c:74]:
is_maxfwd_present(): value = 70
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: maxfwd [maxfwd.c:148]:
process_maxfwd_header(): value 70 decreased to 50
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: siputils [sipops.c:159]:
is_first_hop(): no 2nd via found - first hop
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: textops [textops.c:3063]:
has_body_helper(): content length is zero
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: siputils [checks.c:120]:
has_totag(): no totag
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_lookup.c:711]:
t_lookupOriginalT(): searching on hash entry 47588
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_lookup.c:420]:
matching_3261(): RFC3261 transaction matched,
tid=-524287-1---6a391e4fb0f8a8f6
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_lookup.c:807]:
t_lookupOriginalT(): canceled transaction found (0x7f3ac5004448)!
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_lookup.c:810]:
t_lookupOriginalT(): found - lookup completed
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [tm.c:1091]:
ki_t_lookup_cancel_flags(): lookup_original: t_lookupOriginalT returned:
0x7f3ac5004448
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_lookup.c:1320]:
t_newtran(): msg id=1139 , global msg id=1138 , T on
entrance=0xffffffffffffffff
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_lookup.c:477]:
t_lookup_request(): start searching: hash=47588, isACK=0
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_lookup.c:435]:
matching_3261(): RFC3261 transaction matching failed
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_lookup.c:659]:
t_lookup_request(): no transaction found
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/md5utils.c:67]:
MD5StringArray(): MD5 calculated: c598ebabb2493d5c9aebf673208c6bea
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_lookup.c:711]:
t_lookupOriginalT(): searching on hash entry 47588
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_lookup.c:420]:
matching_3261(): RFC3261 transaction matched,
tid=-524287-1---6a391e4fb0f8a8f6
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_lookup.c:807]:
t_lookupOriginalT(): canceled transaction found (0x7f3ac5004448)!
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_lookup.c:810]:
t_lookupOriginalT(): found - lookup completed
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_cancel.c:335]:
cancel_branch(): sending cancel...
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_fwd.c:1426]:
e2e_cancel(): e2e cancel proceeding
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/msg_translator.c:159]: check_via_address(): (115.186.137.147,
115.186.137.147, 0)
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_reply.c:1629]:
cleanup_uac_timers(): RETR/FR timers reset
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_reply.c:596]:
_reply_light(): reply sent out. buf=0x7f3ac9760ba8: SIP/2.0 200
cancelin..., shmem=0x7f3ac4ff5778: SIP/2.0 200 cancelin
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_reply.c:606]:
_reply_light(): finished
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_funcs.c:372]:
t_relay_to(): new transaction forwarded
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/receive.c:289]:
receive_msg(): request-route executed in: 3428 usec
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/xavp.c:446]:
xavp_destroy_list(): destroying xavp list (nil)
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/receive.c:378]:
receive_msg(): cleaning up
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/udp_server.c:492]:
udp_rcv_loop(): received on udp socket: (118/100/486) [[SIP/2.0 200 OK 0D
0A CSeq: 2 CANCEL 0D 0A Call-ID: v51-8AifZ2mXi4RFMRej9A.. 0D 0A From:
<sip:923135082344@sip.talkh]]
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:614]: parse_msg(): SIP Reply (status):
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:616]: parse_msg(): version: <SIP/2.0>
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:618]: parse_msg(): status: <200>
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:620]: parse_msg(): reason: <OK>
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <2>
<CANCEL>
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/parse_addr_spec.c:185]: parse_to_param(): add param:
tag=26d24c34
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header
reached, state=29
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:171]: get_hdr_field(): <To> [71]; uri=[
sip:923335550609@sip.talkhomeappcall.com;transport=UDP]
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:172]: get_hdr_field(): to body [<
sip:923335550609@sip.talkhomeappcall.com;transport=UDP>]
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232,
<branch> = <z9hG4bK4e9b.c598ebabb2493d5c9aebf673208c6bea.0>; state=16
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:492]: parse_headers(): Via found, flags=2
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:494]: parse_headers(): this is the first via
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/receive.c:205]:
receive_msg(): --- received sip message - reply - call-id:
[v51-8AifZ2mXi4RFMRej9A..] - cseq: [2 CANCEL]
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: tm [t_lookup.c:1019]:
t_check_msg(): msg (0x7f3ac975e930) id=1108 global id=1107 T
start=0xffffffffffffffff
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: tm [t_lookup.c:897]:
t_reply_matching(): t_reply_matching: hash 47588 label 0 branch 0
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: tm [t_lookup.c:951]:
t_reply_matching(): reply (0x7f3ac975e930) matched an active transaction
(T=0x7f3ac5004448)!
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: tm [t_lookup.c:1088]:
t_check_msg(): msg (0x7f3ac975e930) id=1108 global id=1108 T
end=0x7f3ac5004448
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: tm [t_reply.c:2207]:
reply_received(): org. status uas=180, uac[0]=180 local=0 is_invite=1)
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: tm [t_reply.c:2220]:
reply_received(): reply to local CANCEL processed
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/receive.c:362]:
receive_msg(): reply-route executed in: 752 usec
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/xavp.c:446]:
xavp_destroy_list(): destroying xavp list (nil)
Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/receive.c:378]:
receive_msg(): cleaning up
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/udp_server.c:492]:
udp_rcv_loop(): received on udp socket: (118/100/591) [[SIP/2.0 487 Request
Terminated 0D 0A CSeq: 2 INVITE 0D 0A Call-ID: v51-8AifZ2mXi4RFMRej9A..
0D 0A From: <sip:923135]]
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:614]: parse_msg(): SIP Reply (status):
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:616]: parse_msg(): version: <SIP/2.0>
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:618]: parse_msg(): status: <487>
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:620]: parse_msg(): reason: <Request Terminated>
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <2>
<INVITE>
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/parse_addr_spec.c:185]: parse_to_param(): add param:
tag=26d24c34
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header
reached, state=29
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:171]: get_hdr_field(): <To> [71]; uri=[
sip:923335550609@sip.talkhomeappcall.com;transport=UDP]
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:172]: get_hdr_field(): to body [<
sip:923335550609@sip.talkhomeappcall.com;transport=UDP>]
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232,
<branch> = <z9hG4bK4e9b.c598ebabb2493d5c9aebf673208c6bea.0>; state=9
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/parse_via.c:2681]: parse_via(): parsing via: next via
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/parse_via.c:1303]: parse_via_param(): Found param type 235,
<rport> = <61717>; state=6
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232,
<branch> = <z9hG4bK-524287-1---6a391e4fb0f8a8f6>; state=16
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:492]: parse_headers(): Via found, flags=2
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:494]: parse_headers(): this is the first via
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/receive.c:205]:
receive_msg(): --- received sip message - reply - call-id:
[v51-8AifZ2mXi4RFMRej9A..] - cseq: [2 INVITE]
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_lookup.c:1019]:
t_check_msg(): msg (0x7f3ac975e930) id=1140 global id=1139 T
start=0xffffffffffffffff
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_lookup.c:897]:
t_reply_matching(): t_reply_matching: hash 47588 label 0 branch 0
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_lookup.c:951]:
t_reply_matching(): reply (0x7f3ac975e930) matched an active transaction
(T=0x7f3ac5004448)!
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_lookup.c:1088]:
t_check_msg(): msg (0x7f3ac975e930) id=1140 global id=1140 T
end=0x7f3ac5004448
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_reply.c:2207]:
reply_received(): org. status uas=180, uac[0]=180 local=0 is_invite=1)
Jul 12 08:12:09 sip kamailio[22302]: INFO: <script>:
[R-EXTERNAL_REPLY:v51-8AifZ2mXi4RFMRej9A..] -> saw reply to METHOD:INVITE
RESPONSE:'487 Request Terminated' from 115.186.137.147:5060
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_lookup.c:1019]:
t_check_msg(): msg (0x7f3ac975e930) id=1140 global id=1140 T
start=0x7f3ac5004448
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_lookup.c:1091]:
t_check_msg(): T (0x7f3ac5004448) already found for msg (0x7f3ac975e930)!
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:183]: get_hdr_field(): content_length=0
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:89]: get_hdr_field(): found end of header
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: siputils [sipops.c:171]:
is_first_hop(): no record-route header - first hop
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: textops [textops.c:3063]:
has_body_helper(): content length is zero
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_reply.c:1263]:
t_should_relay_response(): ->>>>>>>>> T_code=180, new_code=487
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_lookup.c:1019]:
t_check_msg(): msg (0x7f3ac50441b0) id=1104 global id=1104 T
start=0x7f3ac5004448
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_lookup.c:1091]:
t_check_msg(): T (0x7f3ac5004448) already found for msg (0x7f3ac50441b0)!
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tmx [t_var.c:534]:
pv_get_tm_reply_code(): reply code is <487>
Jul 12 08:12:09 sip kamailio[22302]: INFO: <script>:
v51-8AifZ2mXi4RFMRej9A..|start|external failure route, 487 generated for
method INVITE after progress
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/msg_translator.c:159]: check_via_address(): (115.186.137.147,
115.186.137.147, 0)
*Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_reply.c:1629]:
cleanup_uac_timers(): RETR/FR timers reset*
*Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_reply.c:596]:
_reply_light(): reply sent out. buf=0x7f3ac9760da0: SIP/2.0 500 I'm
terr..., shmem=0x7f3ac5025330: SIP/2.0 500 I'm terr*
*Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_reply.c:606]:
_reply_light(): finished*
*Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_reply.c:1786]:
relay_reply(): branch=0, save=0, relay=-1 icode=0*
*Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_reply.c:1629]:
cleanup_uac_timers(): RETR/FR timers reset*
*Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/receive.c:362]:
receive_msg(): reply-route executed in: 2909 usec*
*Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)*
*Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)*
*Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)*
*Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)*
*Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)*
*Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)*
*Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/xavp.c:446]:
xavp_destroy_list(): destroying xavp list (nil)*
*Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/receive.c:378]:
receive_msg(): cleaning up*
*Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/udp_server.c:492]: udp_rcv_loop(): received on udp socket:
(106/100/419) [[ACK sip:923335550609@sip.talkhomeappcall.com
<sip%3A923335550609(a)sip.talkhomeappcall.com>;transport=UDP SIP/2.0 0D 0A
Via: SIP/2.0/UDP 115.186.137.147]]*
*Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:604]: parse_msg(): SIP Request:*
*Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:606]: parse_msg(): method: <ACK>*
*Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:608]: parse_msg(): uri:
<sip:923335550609@sip.talkhomeappcall.com
<sip%3A923335550609(a)sip.talkhomeappcall.com>;transport=UDP>*
*Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:610]: parse_msg(): version: <SIP/2.0>*
*Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232,
<branch> = <z9hG4bK-524287-1---6a391e4fb0f8a8f6>; state=16*
*Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5*
*Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:492]: parse_headers(): Via found, flags=2*
*Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:494]: parse_headers(): this is the first via*
*Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/parse_addr_spec.c:185]: parse_to_param(): add param:
tag=9fe2d4c84d97a4af81aa65ca8fc51b3d-9b76*
*Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header
reached, state=29*
*Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:171]: get_hdr_field(): <To> [100];
uri=[sip:923335550609@sip.talkhomeappcall.com
<sip%3A923335550609(a)sip.talkhomeappcall.com>;transport=UDP]*
*Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:172]: get_hdr_field(): to body
[<sip:923335550609@sip.talkhomeappcall.com
<sip%3A923335550609(a)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(a)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(a)gmail.com>
wrote:
Hello,
On 10.07.18 22:08, Aqs Younas wrote:
Greeting list,
I am using two async functions(http_async_query) in configuration one for
authentication and other one for push notifications. I am also using tsilio
module to suspend the transaction and resumed it.
I am resetting this flag 'T_ASYNC_SUSPENDED' before suspending the
transaction. Everything is working fine except. When caller send CANCEL on
the call, kamailio successfully completes sip flow at callee(B party) side
but send back below packet towards caller.
what the above statement means? Kamailio forwarded the invite to callee,
got 200ok, but sends back the 200 response?
Cheers,
Daniel
2018/07/10 19:47:41.125893 172.31.21.87:5060 -> 39.38.156.111:59969
SIP/2.0 500 I'm terribly sorry, server error occurred (1/TM )
Via: SIP/2.0/UDP 39.38.156.111:59969
;branch=z9hG4bK-524287-1---91c6114330fe6293;rport=59969
To: <sip:923335550609@sip.talkhomeappcall.com
;transport=UDP>;tag=9fe2d4c84d97a4af81aa65ca8fc51b3d-62cb
From: <sip:923135082344@sip.talkhomeappcall.com
;transport=UDP>;tag=d72eaf4c
Call-ID: VkAwxpSgkKSGn5dXaXgn5A..
CSeq: 2 INVITE
Content-Length: 0
root@sip:~# kamailio -V
version: kamailio 5.1.3 (x86_64/linux)
flags: STATS: Off, USE_TCP, USE_TLS, USE_SCTP, TLS_HOOKS, DISABLE_NAGLE,
USE_MCAST, DNS_IP_HACK, SHM_MEM, SHM_MMAP, PKG_MALLOC, Q_MALLOC, F_MALLOC,
TLSF_MALLOC, DBG_SR_MEMORY, USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT,
USE_DNS_CACHE, USE_DNS_FAILOVER, USE_NAPTR, USE_DST_BLACKLIST,
HAVE_RESOLV_RES
ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16,
MAX_URI_SIZE 1024, BUF_SIZE 65535, DEFAULT PKG_SIZE 8MB
poll method support: poll, epoll_lt, epoll_et, sigio_rt, select.
id: unknown
compiled on 08:06:26 May 2 2018 with gcc 4.9.2
Could someone please help me out how to fix this. Cancels are handles
automatically so, i cannot hardcore anything to resolve it.
Best Regards,
Aqs Younas
_______________________________________________
Kamailio (SER) - Users Mailing
Listsr-users@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@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
13 Jul
13 Jul
1 p.m.
New subject: SIP/2.0 500 I'm terribly sorry, server error occurred (1/TM)
Hello,
can you give here the INVITE that is sent out by Kamailio? In the
screenshot that you gave in a previous email it was the incoming INVITE.
From the logs, the 487 is matching the first branch,
but that should be
the one that was suspended, not the outgoing one.
Reading back this email thread, you said:
"I am resetting this flag 'T_ASYNC_SUSPENDED' before suspending the
transaction."
How do you do that? Can you list the order of operations that happen,
like next?
- INVITE received
- http async for auth
- reset the T_ASYNC_SUSPENDED flag ?!?
- http async for push
Cheers,
Daniel
On 12.07.18 10:37, Aqs Younas wrote:
I could not find anything related to error. Below are
the full
detailed logs. Again thanks for you help.
[...]
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/udp_server.c:492]: udp_rcv_loop(): received on udp socket:
(118/100/591) [[SIP/2.0 487 Request Terminated 0D 0A CSeq: 2 INVITE
0D 0A Call-ID: v51-8AifZ2mXi4RFMRej9A.. 0D 0A From: <sip:923135]]
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:614]: parse_msg(): SIP Reply (status):
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:616]: parse_msg(): version: <SIP/2.0>
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:618]: parse_msg(): status: <487>
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:620]: parse_msg(): reason: <Request
Terminated>
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <2>
<INVITE>
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/parse_addr_spec.c:185]: parse_to_param(): add param:
tag=26d24c34
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header
reached, state=29
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:171]: get_hdr_field(): <To> [71];
uri=[sip:923335550609@sip.talkhomeappcall.com
<mailto:sip%3A923335550609@sip.talkhomeappcall.com>;transport=UDP]
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:172]: get_hdr_field(): to body
[<sip:923335550609@sip.talkhomeappcall.com
<mailto:sip%3A923335550609@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 <http://115.186.137.147:5060>
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_lookup.c:1019]:
t_check_msg(): msg (0x7f3ac975e930) id=1140 global id=1140 T
start=0x7f3ac5004448
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_lookup.c:1091]:
t_check_msg(): T (0x7f3ac5004448) already found for msg (0x7f3ac975e930)!
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:183]: get_hdr_field(): content_length=0
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:89]: get_hdr_field(): found end of header
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: siputils [sipops.c:171]:
is_first_hop(): no record-route header - first hop
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: textops [textops.c:3063]:
has_body_helper(): content length is zero
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_reply.c:1263]:
t_should_relay_response(): ->>>>>>>>> T_code=180,
new_code=487
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_lookup.c:1019]:
t_check_msg(): msg (0x7f3ac50441b0) id=1104 global id=1104 T
start=0x7f3ac5004448
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_lookup.c:1091]:
t_check_msg(): T (0x7f3ac5004448) already found for msg (0x7f3ac50441b0)!
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tmx [t_var.c:534]:
pv_get_tm_reply_code(): reply code is <487>
Jul 12 08:12:09 sip kamailio[22302]: INFO: <script>:
v51-8AifZ2mXi4RFMRej9A..|start|external failure route, 487 generated
for method INVITE after progress
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/msg_translator.c:159]: check_via_address(): (115.186.137.147,
115.186.137.147, 0)
*Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_reply.c:1629]:
cleanup_uac_timers(): RETR/FR timers reset*
*Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_reply.c:596]:
_reply_light(): reply sent out. buf=0x7f3ac9760da0: SIP/2.0 500 I'm
terr..., shmem=0x7f3ac5025330: SIP/2.0 500 I'm terr*
*Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_reply.c:606]:
_reply_light(): finished*
*Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_reply.c:1786]:
relay_reply(): branch=0, save=0, relay=-1 icode=0*
*Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_reply.c:1629]:
cleanup_uac_timers(): RETR/FR timers reset*
*Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/receive.c:362]: receive_msg(): reply-route executed in: 2909 usec*
*Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)*
*Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)*
*Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)*
*Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)*
*Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)*
*Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)*
*Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/xavp.c:446]:
xavp_destroy_list(): destroying xavp list (nil)*
*Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/receive.c:378]: receive_msg(): cleaning up*
*Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/udp_server.c:492]: udp_rcv_loop(): received on udp socket:
(106/100/419) [[ACK sip:923335550609@sip.talkhomeappcall.com
<mailto:sip%3A923335550609@sip.talkhomeappcall.com>;transport=UDP
SIP/2.0 0D 0A Via: SIP/2.0/UDP 115.186.137.147]]*
*Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:604]: parse_msg(): SIP Request:*
*Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:606]: parse_msg(): method: <ACK>*
*Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:608]: parse_msg(): uri:
<sip:923335550609@sip.talkhomeappcall.com
<mailto:sip%3A923335550609@sip.talkhomeappcall.com>;transport=UDP>*
*Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:610]: parse_msg(): version: <SIP/2.0>*
*Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/parse_via.c:1303]: parse_via_param(): Found param type
232, <branch> = <z9hG4bK-524287-1---6a391e4fb0f8a8f6>; state=16*
*Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/parse_via.c:2639]: parse_via(): end of header reached,
state=5*
*Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:492]: parse_headers(): Via found, flags=2*
*Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:494]: parse_headers(): this is the first via*
*Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/parse_addr_spec.c:185]: parse_to_param(): add param:
tag=9fe2d4c84d97a4af81aa65ca8fc51b3d-9b76*
*Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header
reached, state=29*
*Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:171]: get_hdr_field(): <To> [100];
uri=[sip:923335550609@sip.talkhomeappcall.com
<mailto:sip%3A923335550609@sip.talkhomeappcall.com>;transport=UDP]*
*Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:172]: get_hdr_field(): to body
[<sip:923335550609@sip.talkhomeappcall.com
<mailto:sip%3A923335550609@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(a)gmail.com <mailto:miconda@gmail.com>> wrote:
Have you looked at log messages, any errors?
If not, then run with debug=3 in kamailio config and send full log
messages for such call.
Cheers,
Daniel
On 11.07.18 19:15, Aqs Younas wrote:
--
Daniel-Constantin Mierla -- www.asipto.com
www.twitter.com/miconda -- www.linkedin.com/in/miconda
Kamailio World Conference -- www.kamailioworld.com
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(a)gmail.com <mailto:miconda@gmail.com>> wrote:
Hello,
On 10.07.18 22:08, Aqs Younas wrote:
--
Daniel-Constantin Mierla -- www.asipto.com <http://www.asipto.com>
www.twitter.com/miconda <http://www.twitter.com/miconda> --
www.linkedin.com/in/miconda <http://www.linkedin.com/in/miconda>
Kamailio World Conference -- www.kamailioworld.com
<http://www.kamailioworld.com>
_______________________________________________
Kamailio (SER) - Users Mailing List
sr-users(a)lists.kamailio.org
https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users 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
<http://172.31.21.87:5060> -> 39.38.156.111:59969
<http://39.38.156.111:59969>
SIP/2.0 500 I'm terribly sorry, server error occurred (1/TM )
Via: SIP/2.0/UDP
39.38.156.111:59969;branch=z9hG4bK-524287-1---91c6114330fe6293;rport=59969
To: <sip:923335550609@sip.talkhomeappcall.com
<mailto:sip%3A923335550609@sip.talkhomeappcall.com>;transport=UDP>;tag=9fe2d4c84d97a4af81aa65ca8fc51b3d-62cb
From: <sip:923135082344@sip.talkhomeappcall.com
<mailto:sip%3A923135082344@sip.talkhomeappcall.com>;transport=UDP>;tag=d72eaf4c
Call-ID: VkAwxpSgkKSGn5dXaXgn5A..
CSeq: 2 INVITE
Content-Length: 0
root@sip:~# kamailio -V
version: kamailio 5.1.3 (x86_64/linux)
flags: STATS: Off, USE_TCP, USE_TLS, USE_SCTP, TLS_HOOKS,
DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, SHM_MEM, SHM_MMAP,
PKG_MALLOC, Q_MALLOC, F_MALLOC, TLSF_MALLOC, DBG_SR_MEMORY,
USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT, USE_DNS_CACHE,
USE_DNS_FAILOVER, USE_NAPTR, USE_DST_BLACKLIST, HAVE_RESOLV_RES
ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144,
MAX_LISTEN 16, MAX_URI_SIZE 1024, BUF_SIZE 65535, DEFAULT
PKG_SIZE 8MB
poll method support: poll, epoll_lt, epoll_et, sigio_rt, select.
id: unknown
compiled on 08:06:26 May 2 2018 with gcc 4.9.2
Could someone please help me out how to fix this. Cancels
are handles automatically so, i cannot hardcore anything to
resolve it.
Best Regards,
Aqs Younas
_______________________________________________
Kamailio (SER) - Users Mailing List
sr-users(a)lists.kamailio.org <mailto:sr-users@lists.kamailio.org>
https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users
--
Daniel-Constantin Mierla -- www.asipto.com <http://www.asipto.com>
www.twitter.com/miconda <http://www.twitter.com/miconda> --
www.linkedin.com/in/miconda <http://www.linkedin.com/in/miconda>
Kamailio World Conference -- www.kamailioworld.com
<http://www.kamailioworld.com>
_______________________________________________
Kamailio (SER) - Users Mailing List
sr-users(a)lists.kamailio.org <mailto:sr-users@lists.kamailio.org>
https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users
3:32 p.m.
Thanks for replying. Here are the requested details.
N*OTE: Since, Party B is already registered. So, this transaction is not
suspended by using t_suspend(). *
INVITE sent out by the kamailio.
2018/07/13 10:03:39.529954 172.31.21.87:5060 -> 115.186.137.147:5060
INVITE
sip:923335550609@192.168.0.102:5060;transport=udp;registering_acc=sip_talkhomeappcall_com
SIP/2.0
Record-Route: <sip:18.130.57.226;lr=on;ftag=ca4e124a>
Via: SIP/2.0/UDP 18.130.57.226:5060
;branch=z9hG4bKb073.59d340ab13783ca3e986b077d8c3cc09.1
Via: SIP/2.0/UDP 192.168.0.102:34264
;rport=34264;received=115.186.137.147;branch=z9hG4bK-524287-1---d3a65fa7d1d9b7b4
Max-Forwards: 50
Contact: <sip:923135082344@115.186.137.147:34264;transport=UDP>
To: <sip:923335550609@sip.talkhomeappcall.com;transport=UDP>
From: <sip:923135082344@sip.talkhomeappcall.com;transport=UDP>;tag=ca4e124a
Call-ID: rygunB2mU7m1w3mE46c1Ww..
CSeq: 2 INVITE
Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO,
SUBSCRIBE
Content-Type: application/sdp
Supported: replaces, norefersub, extended-refer, timer, outbound, path,
X-cisco-serviceuri
User-Agent: Z 3.7.30891 r30851
Allow-Events: presence, kpml
Content-Length: 321
v=0
o=Z 0 0 IN IP4 18.130.57.226
s=Z
c=IN IP4 18.130.57.226
t=0 0
m=audio 39698 RTP/AVP 3 110 8 0 97 101
a=rtpmap:3 GSM/8000
a=rtpmap:110 speex/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:97 iLBC/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:97 mode=30
a=fmtp:101 0-16
a=sendrecv
a=rtcp:39699
I have defined the flag ' T_ASYNC_SUSPENDED'.
*#!define T_ASYNC_SUSPENDED 5*
Order of call it like below.
1. Call comes
2. Send a http async for authentication.
3. On 200 OK from http I perform user lookup
4. If B party is registered call is send towards it.
i) Push notification is sent for further registration against device B.
route[USER_LOOKUP]
{
send_reply("100", "Trying");
if (is_method("INVITE")) {
if (!lookup("location"))
{
route(SEND_PUSH);
}else{
ts_store();
$sht(vtp=>stored::$rU) = 1;
xlog("L_INFO","[USER-LOOKUP:$ci] -> stored transaction
[$T(id_index):$T(id_label)] $fU=> $rU\n");
t_on_reply("EXTERNAL_REPLY");
t_on_failure("EXTERNAL_FAULT");
t_relay();
route(SEND_PUSH);
}
}
}
5. If B party is not registered PUSH notification is send
i) On 200 OK from push notification transaction is suspending like this
after setting the flag ' T_ASYNC_SUSPENDED'
# suspend the transaction
route[SUSPEND] {
* resetflag(T_ASYNC_SUSPENDED);*
if(!t_suspend())
{
xlog("L_ERR","[R-SUSPEND:$ci] -> failed suspending
trasaction [$T(id_index): $T(id_label)]\n");
send_reply("501", "Unknown destination");
exit;
}
xlog("L_INFO","[R-SUSPEND:$ci] -> suspended transaction
[$T(id_index):$T(id_label)] $fU => $rU\n");
$sht(vtp=>join::$rU) = "" + $T(id_index) + ":"
+$T(id_label);
xlog("L_INFO","[R-SUSPEND:$ci] -> htable key value
[$sht(vtp=>join::$rU)]\n");
}
Thanks for your time. Please let me know if any further information is
required.
Best Regards,
Aqs.
On Fri, 13 Jul 2018 at 13:00, Daniel-Constantin Mierla <miconda(a)gmail.com>
wrote:
Hello,
can you give here the INVITE that is sent out by Kamailio? In the
screenshot that you gave in a previous email it was the incoming INVITE.
From the logs, the 487 is matching the first branch, but that should be
the one that was suspended, not the outgoing one.
Reading back this email thread, you said:
"I am resetting this flag 'T_ASYNC_SUSPENDED' before suspending the
transaction."
How do you do that? Can you list the order of operations that happen, like
next?
- INVITE received
- http async for auth
- reset the T_ASYNC_SUSPENDED flag ?!?
- http async for push
Cheers,
Daniel
On 12.07.18 10:37, Aqs Younas wrote:
I could not find anything related to error. Below are the full detailed
logs. Again thanks for you help.
[...]
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/udp_server.c:492]: udp_rcv_loop(): received on udp socket:
(118/100/591) [[SIP/2.0 487 Request Terminated 0D 0A CSeq: 2 INVITE 0D 0A
Call-ID: v51-8AifZ2mXi4RFMRej9A.. 0D 0A From: <sip:923135]]
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:614]: parse_msg(): SIP Reply (status):
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:616]: parse_msg(): version: <SIP/2.0>
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:618]: parse_msg(): status: <487>
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:620]: parse_msg(): reason: <Request Terminated>
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <2>
<INVITE>
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/parse_addr_spec.c:185]: parse_to_param(): add param:
tag=26d24c34
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header
reached, state=29
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:171]: get_hdr_field(): <To> [71]; uri=[
sip:923335550609@sip.talkhomeappcall.com;transport=UDP]
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:172]: get_hdr_field(): to body [<
sip:923335550609@sip.talkhomeappcall.com;transport=UDP>]
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232,
<branch> = <z9hG4bK4e9b.c598ebabb2493d5c9aebf673208c6bea.0>; state=9
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/parse_via.c:2681]: parse_via(): parsing via: next via
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/parse_via.c:1303]: parse_via_param(): Found param type 235,
<rport> = <61717>; state=6
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232,
<branch> = <z9hG4bK-524287-1---6a391e4fb0f8a8f6>; state=16
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:492]: parse_headers(): Via found, flags=2
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:494]: parse_headers(): this is the first via
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/receive.c:205]:
receive_msg(): --- received sip message - reply - call-id:
[v51-8AifZ2mXi4RFMRej9A..] - cseq: [2 INVITE]
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_lookup.c:1019]:
t_check_msg(): msg (0x7f3ac975e930) id=1140 global id=1139 T
start=0xffffffffffffffff
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_lookup.c:897]:
t_reply_matching(): t_reply_matching: hash 47588 label 0 branch 0
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_lookup.c:951]:
t_reply_matching(): reply (0x7f3ac975e930) matched an active transaction
(T=0x7f3ac5004448)!
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_lookup.c:1088]:
t_check_msg(): msg (0x7f3ac975e930) id=1140 global id=1140 T
end=0x7f3ac5004448
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_reply.c:2207]:
reply_received(): org. status uas=180, uac[0]=180 local=0 is_invite=1)
Jul 12 08:12:09 sip kamailio[22302]: INFO: <script>:
[R-EXTERNAL_REPLY:v51-8AifZ2mXi4RFMRej9A..] -> saw reply to METHOD:INVITE
RESPONSE:'487 Request Terminated' from 115.186.137.147:5060
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_lookup.c:1019]:
t_check_msg(): msg (0x7f3ac975e930) id=1140 global id=1140 T
start=0x7f3ac5004448
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_lookup.c:1091]:
t_check_msg(): T (0x7f3ac5004448) already found for msg (0x7f3ac975e930)!
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:183]: get_hdr_field(): content_length=0
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:89]: get_hdr_field(): found end of header
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: siputils [sipops.c:171]:
is_first_hop(): no record-route header - first hop
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: textops [textops.c:3063]:
has_body_helper(): content length is zero
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_reply.c:1263]:
t_should_relay_response(): ->>>>>>>>> T_code=180,
new_code=487
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_lookup.c:1019]:
t_check_msg(): msg (0x7f3ac50441b0) id=1104 global id=1104 T
start=0x7f3ac5004448
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_lookup.c:1091]:
t_check_msg(): T (0x7f3ac5004448) already found for msg (0x7f3ac50441b0)!
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tmx [t_var.c:534]:
pv_get_tm_reply_code(): reply code is <487>
Jul 12 08:12:09 sip kamailio[22302]: INFO: <script>:
v51-8AifZ2mXi4RFMRej9A..|start|external failure route, 487 generated for
method INVITE after progress
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/msg_translator.c:159]: check_via_address(): (115.186.137.147,
115.186.137.147, 0)
*Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_reply.c:1629]:
cleanup_uac_timers(): RETR/FR timers reset*
*Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_reply.c:596]:
_reply_light(): reply sent out. buf=0x7f3ac9760da0: SIP/2.0 500 I'm
terr..., shmem=0x7f3ac5025330: SIP/2.0 500 I'm terr*
*Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_reply.c:606]:
_reply_light(): finished*
*Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_reply.c:1786]:
relay_reply(): branch=0, save=0, relay=-1 icode=0*
*Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_reply.c:1629]:
cleanup_uac_timers(): RETR/FR timers reset*
*Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/receive.c:362]:
receive_msg(): reply-route executed in: 2909 usec*
*Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)*
*Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)*
*Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)*
*Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)*
*Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)*
*Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/usr_avp.c:636]:
destroy_avp_list(): destroying list (nil)*
*Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/xavp.c:446]:
xavp_destroy_list(): destroying xavp list (nil)*
*Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/receive.c:378]:
receive_msg(): cleaning up*
*Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/udp_server.c:492]: udp_rcv_loop(): received on udp socket:
(106/100/419) [[ACK sip:923335550609@sip.talkhomeappcall.com
<sip%3A923335550609(a)sip.talkhomeappcall.com>;transport=UDP SIP/2.0 0D 0A
Via: SIP/2.0/UDP 115.186.137.147]]*
*Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:604]: parse_msg(): SIP Request:*
*Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:606]: parse_msg(): method: <ACK>*
*Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:608]: parse_msg(): uri:
<sip:923335550609@sip.talkhomeappcall.com
<sip%3A923335550609(a)sip.talkhomeappcall.com>;transport=UDP>*
*Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:610]: parse_msg(): version: <SIP/2.0>*
*Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232,
<branch> = <z9hG4bK-524287-1---6a391e4fb0f8a8f6>; state=16*
*Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5*
*Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:492]: parse_headers(): Via found, flags=2*
*Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:494]: parse_headers(): this is the first via*
*Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/parse_addr_spec.c:185]: parse_to_param(): add param:
tag=9fe2d4c84d97a4af81aa65ca8fc51b3d-9b76*
*Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header
reached, state=29*
*Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:171]: get_hdr_field(): <To> [100];
uri=[sip:923335550609@sip.talkhomeappcall.com
<sip%3A923335550609(a)sip.talkhomeappcall.com>;transport=UDP]*
*Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:172]: get_hdr_field(): to body
[<sip:923335550609@sip.talkhomeappcall.com
<sip%3A923335550609(a)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(a)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(a)gmail.com>
wrote:
_______________________________________________
Kamailio (SER) - Users Mailing
Listsr-users@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
Hello,
On 10.07.18 22:08, Aqs Younas wrote:
Greeting list,
I am using two async functions(http_async_query) in configuration one
for authentication and other one for push notifications. I am also using
tsilio module to suspend the transaction and resumed it.
I am resetting this flag 'T_ASYNC_SUSPENDED' before suspending the
transaction. Everything is working fine except. When caller send CANCEL on
the call, kamailio successfully completes sip flow at callee(B party) side
but send back below packet towards caller.
what the above statement means? Kamailio forwarded the invite to callee,
got 200ok, but sends back the 200 response?
Cheers,
Daniel
2018/07/10 19:47:41.125893 172.31.21.87:5060 -> 39.38.156.111:59969
SIP/2.0 500 I'm terribly sorry, server error occurred (1/TM )
Via: SIP/2.0/UDP 39.38.156.111:59969
;branch=z9hG4bK-524287-1---91c6114330fe6293;rport=59969
To: <sip:923335550609@sip.talkhomeappcall.com
;transport=UDP>;tag=9fe2d4c84d97a4af81aa65ca8fc51b3d-62cb
From: <sip:923135082344@sip.talkhomeappcall.com
;transport=UDP>;tag=d72eaf4c
Call-ID: VkAwxpSgkKSGn5dXaXgn5A..
CSeq: 2 INVITE
Content-Length: 0
root@sip:~# kamailio -V
version: kamailio 5.1.3 (x86_64/linux)
flags: STATS: Off, USE_TCP, USE_TLS, USE_SCTP, TLS_HOOKS, DISABLE_NAGLE,
USE_MCAST, DNS_IP_HACK, SHM_MEM, SHM_MMAP, PKG_MALLOC, Q_MALLOC, F_MALLOC,
TLSF_MALLOC, DBG_SR_MEMORY, USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT,
USE_DNS_CACHE, USE_DNS_FAILOVER, USE_NAPTR, USE_DST_BLACKLIST,
HAVE_RESOLV_RES
ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16,
MAX_URI_SIZE 1024, BUF_SIZE 65535, DEFAULT PKG_SIZE 8MB
poll method support: poll, epoll_lt, epoll_et, sigio_rt, select.
id: unknown
compiled on 08:06:26 May 2 2018 with gcc 4.9.2
Could someone please help me out how to fix this. Cancels are handles
automatically so, i cannot hardcore anything to resolve it.
Best Regards,
Aqs Younas
_______________________________________________
Kamailio (SER) - Users Mailing
Listsr-users@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@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
4:05 p.m.
New subject: SIP/2.0 500 I'm terribly sorry, server error occurred (1/TM)
But this is different scenario than the logs you sent, so I can't relate
them anymore.
Maybe it is better to send both the pcap with all sip messages of the
call and the logs taken for that call. First add in your config:
log_prefix="{$mt $hdr(CSeq) $ci} "
To be easier to correlate the logs with the sip messages as well as look
at messages with wireshark of other tool.
Cheers,
Daniel
On 13.07.18 12:32, Aqs Younas wrote:
Thanks for replying. Here are the requested details.
N*OTE: Since, Party B is already registered. So, this transaction is
not suspended by using t_suspend(). *
INVITE sent out by the kamailio.
2018/07/13 10:03:39.529954 172.31.21.87:5060
<http://172.31.21.87:5060> -> 115.186.137.147:5060
<http://115.186.137.147:5060>
INVITE
sip:923335550609@192.168.0.102:5060;transport=udp;registering_acc=sip_talkhomeappcall_com
SIP/2.0
Record-Route: <sip:18.130.57.226;lr=on;ftag=ca4e124a>
Via: SIP/2.0/UDP
18.130.57.226:5060;branch=z9hG4bKb073.59d340ab13783ca3e986b077d8c3cc09.1
Via: SIP/2.0/UDP
192.168.0.102:34264;rport=34264;received=115.186.137.147;branch=z9hG4bK-524287-1---d3a65fa7d1d9b7b4
Max-Forwards: 50
Contact: <sip:923135082344@115.186.137.147:34264;transport=UDP>
To: <sip:923335550609@sip.talkhomeappcall.com
<mailto:sip%3A923335550609@sip.talkhomeappcall.com>;transport=UDP>
From: <sip:923135082344@sip.talkhomeappcall.com
<mailto:sip%3A923135082344@sip.talkhomeappcall.com>;transport=UDP>;tag=ca4e124a
Call-ID: rygunB2mU7m1w3mE46c1Ww..
CSeq: 2 INVITE
Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS,
INFO, SUBSCRIBE
Content-Type: application/sdp
Supported: replaces, norefersub, extended-refer, timer, outbound,
path, X-cisco-serviceuri
User-Agent: Z 3.7.30891 r30851
Allow-Events: presence, kpml
Content-Length: 321
v=0
o=Z 0 0 IN IP4 18.130.57.226
s=Z
c=IN IP4 18.130.57.226
t=0 0
m=audio 39698 RTP/AVP 3 110 8 0 97 101
a=rtpmap:3 GSM/8000
a=rtpmap:110 speex/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:97 iLBC/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:97 mode=30
a=fmtp:101 0-16
a=sendrecv
a=rtcp:39699
I have defined the flag ' T_ASYNC_SUSPENDED'.
*#!define T_ASYNC_SUSPENDED 5*
Order of call it like below.
1. Call comes
2. Send a http async for authentication.
3. On 200 OK from http I perform user lookup
4. If B party is registered call is send towards it.
i) Push notification is sent for further registration against
device B.
route[USER_LOOKUP]
{
send_reply("100", "Trying");
if (is_method("INVITE")) {
if (!lookup("location"))
{
route(SEND_PUSH);
}else{
ts_store();
$sht(vtp=>stored::$rU) = 1;
xlog("L_INFO","[USER-LOOKUP:$ci] -> stored transaction
[$T(id_index):$T(id_label)] $fU=> $rU\n");
t_on_reply("EXTERNAL_REPLY");
t_on_failure("EXTERNAL_FAULT");
t_relay();
route(SEND_PUSH);
}
}
}
5. If B party is not registered PUSH notification is send
i) On 200 OK from push notification transaction is suspending like
this after setting the flag ' T_ASYNC_SUSPENDED'
# suspend the transaction
route[SUSPEND] {
* resetflag(T_ASYNC_SUSPENDED);*
if(!t_suspend())
{
xlog("L_ERR","[R-SUSPEND:$ci] -> failed suspending
trasaction [$T(id_index): $T(id_label)]\n");
send_reply("501", "Unknown destination");
exit;
}
xlog("L_INFO","[R-SUSPEND:$ci] -> suspended transaction
[$T(id_index):$T(id_label)] $fU => $rU\n");
$sht(vtp=>join::$rU) = "" + $T(id_index) + ":"
+$T(id_label);
xlog("L_INFO","[R-SUSPEND:$ci] -> htable key value
[$sht(vtp=>join::$rU)]\n");
}
Thanks for your time. Please let me know if any further information is
required.
Best Regards,
Aqs.
On Fri, 13 Jul 2018 at 13:00, Daniel-Constantin Mierla
<miconda(a)gmail.com <mailto:miconda@gmail.com>> wrote:
Hello,
can you give here the INVITE that is sent out by Kamailio? In the
screenshot that you gave in a previous email it was the incoming
INVITE.
From the logs, the 487 is matching the first branch, but that
should be the one that was suspended, not the outgoing one.
Reading back this email thread, you said:
"I am resetting this flag 'T_ASYNC_SUSPENDED' before suspending
the transaction."
How do you do that? Can you list the order of operations that
happen, like next?
- INVITE received
- http async for auth
- reset the T_ASYNC_SUSPENDED flag ?!?
- http async for push
Cheers,
Daniel
On 12.07.18 10:37, Aqs Younas wrote:
--
Daniel-Constantin Mierla -- www.asipto.com
www.twitter.com/miconda -- www.linkedin.com/in/miconda
Kamailio World Conference -- www.kamailioworld.com
I could not find anything related to error.
Below are the full
detailed logs. Again thanks for you help.
[...]
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/udp_server.c:492]: udp_rcv_loop(): received on udp socket:
(118/100/591) [[SIP/2.0 487 Request Terminated 0D 0A CSeq: 2
INVITE 0D 0A Call-ID: v51-8AifZ2mXi4RFMRej9A.. 0D 0A From:
<sip:923135]]
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:614]: parse_msg(): SIP Reply (status):
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:616]: parse_msg(): version: <SIP/2.0>
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:618]: parse_msg(): status: <487>
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:620]: parse_msg(): reason: <Request
Terminated>
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <2>
<INVITE>
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/parse_addr_spec.c:185]: parse_to_param(): add param:
tag=26d24c34
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of
header reached, state=29
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:171]: get_hdr_field(): <To> [71];
uri=[sip:923335550609@sip.talkhomeappcall.com
<mailto:sip%3A923335550609@sip.talkhomeappcall.com>;transport=UDP]
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:172]: get_hdr_field(): to body
[<sip:923335550609@sip.talkhomeappcall.com
<mailto:sip%3A923335550609@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 <http://115.186.137.147:5060>
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_lookup.c:1019]:
t_check_msg(): msg (0x7f3ac975e930) id=1140 global id=1140 T
start=0x7f3ac5004448
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_lookup.c:1091]:
t_check_msg(): T (0x7f3ac5004448) already found for msg
(0x7f3ac975e930)!
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:183]: get_hdr_field(): content_length=0
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/parser/msg_parser.c:89]: get_hdr_field(): found end of header
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: siputils
[sipops.c:171]: is_first_hop(): no record-route header - first hop
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: textops
[textops.c:3063]: has_body_helper(): content length is zero
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_reply.c:1263]:
t_should_relay_response(): ->>>>>>>>> T_code=180,
new_code=487
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_lookup.c:1019]:
t_check_msg(): msg (0x7f3ac50441b0) id=1104 global id=1104 T
start=0x7f3ac5004448
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_lookup.c:1091]:
t_check_msg(): T (0x7f3ac5004448) already found for msg
(0x7f3ac50441b0)!
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tmx [t_var.c:534]:
pv_get_tm_reply_code(): reply code is <487>
Jul 12 08:12:09 sip kamailio[22302]: INFO: <script>:
v51-8AifZ2mXi4RFMRej9A..|start|external failure route, 487
generated for method INVITE after progress
Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/msg_translator.c:159]: check_via_address():
(115.186.137.147, 115.186.137.147, 0)
*Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_reply.c:1629]:
cleanup_uac_timers(): RETR/FR timers reset*
*Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_reply.c:596]:
_reply_light(): reply sent out. buf=0x7f3ac9760da0: SIP/2.0 500
I'm terr..., shmem=0x7f3ac5025330: SIP/2.0 500 I'm terr*
*Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_reply.c:606]:
_reply_light(): finished*
*Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_reply.c:1786]:
relay_reply(): branch=0, save=0, relay=-1 icode=0*
*Jul 12 08:12:09 sip kamailio[22302]: DEBUG: tm [t_reply.c:1629]:
cleanup_uac_timers(): RETR/FR timers reset*
*Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/receive.c:362]: receive_msg(): reply-route executed in:
2909 usec*
*Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)*
*Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)*
*Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)*
*Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)*
*Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)*
*Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)*
*Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/xavp.c:446]: xavp_destroy_list(): destroying xavp list (nil)*
*Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core>
[core/receive.c:378]: receive_msg(): cleaning up*
*Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/udp_server.c:492]: udp_rcv_loop(): received on udp socket:
(106/100/419) [[ACK sip:923335550609@sip.talkhomeappcall.com
<mailto:sip%3A923335550609@sip.talkhomeappcall.com>;transport=UDP
SIP/2.0 0D 0A Via: SIP/2.0/UDP 115.186.137.147]]*
*Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:604]: parse_msg(): SIP Request:*
*Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:606]: parse_msg(): method: <ACK>*
*Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:608]: parse_msg(): uri:
<sip:923335550609@sip.talkhomeappcall.com
<mailto:sip%3A923335550609@sip.talkhomeappcall.com>;transport=UDP>*
*Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:610]: parse_msg(): version: <SIP/2.0>*
*Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/parse_via.c:1303]: parse_via_param(): Found param
type 232, <branch> = <z9hG4bK-524287-1---6a391e4fb0f8a8f6>; state=16*
*Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/parse_via.c:2639]: parse_via(): end of header
reached, state=5*
*Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:492]: parse_headers(): Via found, flags=2*
*Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:494]: parse_headers(): this is the
first via*
*Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/parse_addr_spec.c:185]: parse_to_param(): add param:
tag=9fe2d4c84d97a4af81aa65ca8fc51b3d-9b76*
*Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of
header reached, state=29*
*Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:171]: get_hdr_field(): <To> [100];
uri=[sip:923335550609@sip.talkhomeappcall.com
<mailto:sip%3A923335550609@sip.talkhomeappcall.com>;transport=UDP]*
*Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core>
[core/parser/msg_parser.c:172]: get_hdr_field(): to body
[<sip:923335550609@sip.talkhomeappcall.com
<mailto:sip%3A923335550609@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(a)gmail.com <mailto:miconda@gmail.com>> wrote:
Have you looked at log messages, any errors?
If not, then run with debug=3 in kamailio config and send
full log messages for such call.
Cheers,
Daniel
On 11.07.18 19:15, Aqs Younas wrote:
--
Daniel-Constantin Mierla -- www.asipto.com <http://www.asipto.com>
www.twitter.com/miconda <http://www.twitter.com/miconda> --
www.linkedin.com/in/miconda <http://www.linkedin.com/in/miconda>
Kamailio World Conference -- www.kamailioworld.com
<http://www.kamailioworld.com>
_______________________________________________
Kamailio (SER) - Users Mailing List
sr-users(a)lists.kamailio.org
https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users 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(a)gmail.com <mailto:miconda@gmail.com>> wrote:
Hello,
On 10.07.18 22:08, Aqs Younas wrote:
--
Daniel-Constantin Mierla -- www.asipto.com <http://www.asipto.com>
www.twitter.com/miconda <http://www.twitter.com/miconda> --
www.linkedin.com/in/miconda <http://www.linkedin.com/in/miconda>
Kamailio World Conference -- www.kamailioworld.com
<http://www.kamailioworld.com>
_______________________________________________
Kamailio (SER) - Users Mailing List
sr-users(a)lists.kamailio.org <mailto:sr-users@lists.kamailio.org>
https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users 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
<http://172.31.21.87:5060> -> 39.38.156.111:59969
<http://39.38.156.111:59969>
SIP/2.0 500 I'm terribly sorry, server error occurred
(1/TM )
Via: SIP/2.0/UDP
39.38.156.111:59969;branch=z9hG4bK-524287-1---91c6114330fe6293;rport=59969
To: <sip:923335550609@sip.talkhomeappcall.com
<mailto:sip%3A923335550609@sip.talkhomeappcall.com>;transport=UDP>;tag=9fe2d4c84d97a4af81aa65ca8fc51b3d-62cb
From: <sip:923135082344@sip.talkhomeappcall.com
<mailto:sip%3A923135082344@sip.talkhomeappcall.com>;transport=UDP>;tag=d72eaf4c
Call-ID: VkAwxpSgkKSGn5dXaXgn5A..
CSeq: 2 INVITE
Content-Length: 0
root@sip:~# kamailio -V
version: kamailio 5.1.3 (x86_64/linux)
flags: STATS: Off, USE_TCP, USE_TLS, USE_SCTP,
TLS_HOOKS, DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK,
SHM_MEM, SHM_MMAP, PKG_MALLOC, Q_MALLOC, F_MALLOC,
TLSF_MALLOC, DBG_SR_MEMORY, USE_FUTEX,
FAST_LOCK-ADAPTIVE_WAIT, USE_DNS_CACHE,
USE_DNS_FAILOVER, USE_NAPTR, USE_DST_BLACKLIST,
HAVE_RESOLV_RES
ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144,
MAX_LISTEN 16, MAX_URI_SIZE 1024, BUF_SIZE 65535,
DEFAULT PKG_SIZE 8MB
poll method support: poll, epoll_lt, epoll_et,
sigio_rt, select.
id: unknown
compiled on 08:06:26 May 2 2018 with gcc 4.9.2
Could someone please help me out how to fix this.
Cancels are handles automatically so, i cannot hardcore
anything to resolve it.
Best Regards,
Aqs Younas
_______________________________________________
Kamailio (SER) - Users Mailing List
sr-users(a)lists.kamailio.org
<mailto:sr-users@lists.kamailio.org>
https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users
--
Daniel-Constantin Mierla -- www.asipto.com <http://www.asipto.com>
www.twitter.com/miconda <http://www.twitter.com/miconda> --
www.linkedin.com/in/miconda
<http://www.linkedin.com/in/miconda>
Kamailio World Conference -- www.kamailioworld.com
<http://www.kamailioworld.com>
_______________________________________________
Kamailio (SER) - Users Mailing List
sr-users(a)lists.kamailio.org <mailto:sr-users@lists.kamailio.org>
https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users 
12 Jul
12 Jul
8:17 p.m.
Very unlikely, but may be try playing with the TM's params, like for e.g.
https://kamailio.org/docs/modules/5.1.x/modules/tm.html#remap_503_500
On Thu, Jul 12, 2018 at 2:56 AM Aqs Younas <aqsyounas(a)gmail.com> wrote:
Sorry, if i could not explain it well before. I hope
below picture will
make it clear.
[image: image.png]
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(a)gmail.com>
wrote:
Hello,
On 10.07.18 22:08, Aqs Younas wrote:
Greeting list,
I am using two async functions(http_async_query) in configuration one for
authentication and other one for push notifications. I am also using tsilio
module to suspend the transaction and resumed it.
I am resetting this flag 'T_ASYNC_SUSPENDED' before suspending the
transaction. Everything is working fine except. When caller send CANCEL on
the call, kamailio successfully completes sip flow at callee(B party) side
but send back below packet towards caller.
what the above statement means? Kamailio forwarded the invite to callee,
got 200ok, but sends back the 200 response?
Cheers,
Daniel
2018/07/10 19:47:41.125893 172.31.21.87:5060 -> 39.38.156.111:59969
SIP/2.0 500 I'm terribly sorry, server error occurred (1/TM )
Via: SIP/2.0/UDP 39.38.156.111:59969
;branch=z9hG4bK-524287-1---91c6114330fe6293;rport=59969
To: <sip:923335550609@sip.talkhomeappcall.com
;transport=UDP>;tag=9fe2d4c84d97a4af81aa65ca8fc51b3d-62cb
From: <sip:923135082344@sip.talkhomeappcall.com
;transport=UDP>;tag=d72eaf4c
Call-ID: VkAwxpSgkKSGn5dXaXgn5A..
CSeq: 2 INVITE
Content-Length: 0
root@sip:~# kamailio -V
version: kamailio 5.1.3 (x86_64/linux)
flags: STATS: Off, USE_TCP, USE_TLS, USE_SCTP, TLS_HOOKS, DISABLE_NAGLE,
USE_MCAST, DNS_IP_HACK, SHM_MEM, SHM_MMAP, PKG_MALLOC, Q_MALLOC, F_MALLOC,
TLSF_MALLOC, DBG_SR_MEMORY, USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT,
USE_DNS_CACHE, USE_DNS_FAILOVER, USE_NAPTR, USE_DST_BLACKLIST,
HAVE_RESOLV_RES
ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16,
MAX_URI_SIZE 1024, BUF_SIZE 65535, DEFAULT PKG_SIZE 8MB
poll method support: poll, epoll_lt, epoll_et, sigio_rt, select.
id: unknown
compiled on 08:06:26 May 2 2018 with gcc 4.9.2
Could someone please help me out how to fix this. Cancels are handles
automatically so, i cannot hardcore anything to resolve it.
Best Regards,
Aqs Younas
_______________________________________________
Kamailio (SER) - Users Mailing
Listsr-users@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
List
sr-users(a)lists.kamailio.org
https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users
2124
days inactive
2127
days old
8 comments
3 participants
participants (3)
-
Aqs Younas -
Daniel-Constantin Mierla -
Sergiu Pojoga