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/xavp.c:446]: xavp_destroy_list(): destroying xavp list (nil)

Jul 12 08:12:09 sip kamailio[22302]: DEBUG: <core> [core/receive.c:378]: receive_msg(): cleaning up

Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/udp_server.c:492]: udp_rcv_loop(): received on udp socket: (106/100/419) [[ACK sip:923335550609@sip.talkhomeappcall.com;transport=UDP SIP/2.0 0D 0A Via: SIP/2.0/UDP 115.186.137.147]]

Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:604]: parse_msg(): SIP Request:

Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:606]: parse_msg(): method: <ACK>

Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:608]: parse_msg(): uri: <sip:923335550609@sip.talkhomeappcall.com;transport=UDP>

Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:610]: parse_msg(): version: <SIP/2.0>

Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK-524287-1---6a391e4fb0f8a8f6>; state=16

Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5

Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:492]: parse_headers(): Via found, flags=2

Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:494]: parse_headers(): this is the first via

Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=9fe2d4c84d97a4af81aa65ca8fc51b3d-9b76

Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29

Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:171]: get_hdr_field(): <To> [100]; uri=[sip:923335550609@sip.talkhomeappcall.com;transport=UDP]

Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:172]: get_hdr_field(): to body [<sip:923335550609@sip.talkhomeappcall.com;transport=UDP>]

Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <2> <ACK>

Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/receive.c:205]: receive_msg(): --- received sip message - request - call-id: [v51-8AifZ2mXi4RFMRej9A..] - cseq: [2 ACK]

Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/receive.c:248]: receive_msg(): preparing to run routing scripts...

Jul 12 08:12:09 sip kamailio[22303]: DEBUG: sl [sl_funcs.c:387]: sl_filter_ACK(): too late to be a local ACK!

Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:183]: get_hdr_field(): content_length=0

Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): found end of header

Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=dc4e5a14

Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29

Jul 12 08:12:09 sip kamailio[22303]: DEBUG: sanity [sanity_mod.c:256]: w_sanity_check(): sanity checks result: 1

Jul 12 08:12:09 sip kamailio[22303]: DEBUG: maxfwd [mf_funcs.c:74]: is_maxfwd_present(): value = 70

Jul 12 08:12:09 sip kamailio[22303]: DEBUG: maxfwd [maxfwd.c:148]: process_maxfwd_header(): value 70 decreased to 50

Jul 12 08:12:09 sip kamailio[22303]: DEBUG: pv [pv_core.c:966]: pv_get_useragent(): no User-Agent header

Jul 12 08:12:09 sip kamailio[22303]: DEBUG: 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/xavp.c:446]: xavp_destroy_list(): destroying xavp list (nil)

Jul 12 08:12:09 sip kamailio[22303]: DEBUG: <core> [core/receive.c:378]: receive_msg(): cleaning up

Jul 12 08:12:10 sip kamailio[22302]: DEBUG: <core> [core/udp_server.c:514]: udp_rcv_loop(): probing packet received from 217.33.40.242 57067

Thanks for your time.

Best Regards,

Aqs

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

Have you looked at log messages, any errors?

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

Cheers,
Daniel

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

...

is it some configuration issue?

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

Any suggestion is much appreciated.

Best Regards,

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

On 10.07.18 22:08, Aqs Younas wrote:

Greeting list,

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

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

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

Cheers,
Daniel
2018/07/10 19:47:41.125893 172.31.21.87:5060 -> 39.38.156.111:59969

SIP/2.0 500 I'm terribly sorry, server error occurred (1/TM )

Via: SIP/2.0/UDP 39.38.156.111:59969;branch=z9hG4bK-524287-1---91c6114330fe6293;rport=59969

To: <sip:923335550609@sip.talkhomeappcall.com;transport=UDP>;tag=9fe2d4c84d97a4af81aa65ca8fc51b3d-62cb

From: <sip:923135082344@sip.talkhomeappcall.com;transport=UDP>;tag=d72eaf4c

Call-ID: VkAwxpSgkKSGn5dXaXgn5A..

CSeq: 2 INVITE

Content-Length: 0

root@sip:~# kamailio -V

version: kamailio 5.1.3 (x86_64/linux)

flags: STATS: Off, USE_TCP, USE_TLS, USE_SCTP, TLS_HOOKS, DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, SHM_MEM, SHM_MMAP, PKG_MALLOC, Q_MALLOC, F_MALLOC, TLSF_MALLOC, DBG_SR_MEMORY, USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT, USE_DNS_CACHE, USE_DNS_FAILOVER, USE_NAPTR, USE_DST_BLACKLIST, HAVE_RESOLV_RES

ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16, MAX_URI_SIZE 1024, BUF_SIZE 65535, DEFAULT PKG_SIZE 8MB

poll method support: poll, epoll_lt, epoll_et, sigio_rt, select.

id: unknown

compiled on 08:06:26 May 2 2018 with gcc 4.9.2

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

Best Regards,

Aqs Younas
_______________________________________________
Kamailio (SER) - Users Mailing List
sr-users@lists.kamailio.org
https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users
-- 
Daniel-Constantin Mierla -- www.asipto.com
www.twitter.com/miconda -- www.linkedin.com/in/miconda
Kamailio World Conference -- www.kamailioworld.com
_______________________________________________
Kamailio (SER) - Users Mailing List
sr-users@lists.kamailio.org
https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users
-- 
Daniel-Constantin Mierla -- www.asipto.com
www.twitter.com/miconda -- www.linkedin.com/in/miconda
Kamailio World Conference -- www.kamailioworld.com