Here's another occurence of the issue. It looks like all the messages were captured this time. It appears that the callback is not being called after the second 200 OK.
``` 7(14177) DEBUG: tm [uac.c:249]: t_uac_prepare(): DEBUG:tm:t_uac: next_hop=sip:callcentric.com 7(14177) DEBUG: <core> [dns_cache.c:537]: _dns_hash_find(): (_sip._udp.callcentric.com(25), 33), h=428 7(14177) DEBUG: <core> [dns_cache.c:537]: _dns_hash_find(): (alpha13.callcentric.com(23), 1), h=8 7(14177) DEBUG: <core> [forward.c:174]: get_out_socket(): socket determined: 0x771578e4 7(14177) DEBUG: tm [uac.c:150]: dlg2hash(): DEBUG: dlg2hash: 23186 2(14172) DEBUG: <core> [parser/msg_parser.c:616]: parse_msg(): SIP Reply (status): 2(14172) DEBUG: <core> [parser/msg_parser.c:618]: parse_msg(): version: <SIP/2.0> 2(14172) DEBUG: <core> [parser/msg_parser.c:620]: parse_msg(): status: <407> 2(14172) DEBUG: <core> [parser/msg_parser.c:622]: parse_msg(): reason: <Proxy Authentication Required> 2(14172) DEBUG: <core> [parser/parse_via.c:1254]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK29a5.d1684c32000000000000000000000000.0>; state=16 2(14172) DEBUG: <core> [parser/parse_via.c:2642]: parse_via(): end of header reached, state=5 2(14172) DEBUG: <core> [parser/msg_parser.c:496]: parse_headers(): parse_headers: Via found, flags=2 2(14172) DEBUG: <core> [parser/msg_parser.c:498]: parse_headers(): parse_headers: this is the first via 2(14172) DEBUG: <core> [receive.c:134]: receive_msg(): After parse_msg... 2(14172) DEBUG: tm [t_lookup.c:1011]: t_check_msg(): DEBUG: t_check_msg: msg id=3497 global id=3496 T start=0xffffffff 2(14172) DEBUG: <core> [parser/parse_addr_spec.c:894]: parse_addr_spec(): end of header reached, state=10 2(14172) DEBUG: <core> [parser/msg_parser.c:173]: get_hdr_field(): DEBUG: get_hdr_field: <t> [35]; uri=[sip:removedXXXX@callcentric.com] 2(14172) DEBUG: <core> [parser/msg_parser.c:175]: get_hdr_field(): DEBUG: to body [sip:removedXXXX@callcentric.com ] 2(14172) DEBUG: <core> [parser/msg_parser.c:153]: get_hdr_field(): get_hdr_field: cseq <CSeq>: <10> <REGISTER> 2(14172) DEBUG: <core> [parser/msg_parser.c:187]: get_hdr_field(): DEBUG: get_hdr_body : content_length=0 2(14172) DEBUG: <core> [parser/msg_parser.c:89]: get_hdr_field(): found end of header 2(14172) DEBUG: tm [t_lookup.c:888]: t_reply_matching(): DEBUG: t_reply_matching: hash 23186 label 0 branch 0 2(14172) DEBUG: tm [t_lookup.c:943]: t_reply_matching(): DEBUG: t_reply_matching: reply matched (T=0x766f92f0)! 2(14172) DEBUG: tm [t_lookup.c:1080]: t_check_msg(): DEBUG: t_check_msg: msg id=3497 global id=3497 T end=0x766f92f0 2(14172) DEBUG: tm [t_reply.c:2136]: reply_received(): DEBUG: reply_received: org. status uas=0, uac[0]=0 local=2 is_invite=0) 2(14172) DEBUG: tm [t_reply.c:1230]: t_should_relay_response(): ->>>>>>>>> T_code=0, new_code=407 2(14172) DEBUG: tm [t_reply.c:2016]: local_reply(): DEBUG: local_reply: branch=0, save=0, winner=0 2(14172) DEBUG: tm [t_reply.c:2053]: local_reply(): DEBUG: local transaction completed 2(14172) DEBUG: tm [t_hooks.c:266]: run_trans_callbacks_internal(): DBG: trans=0x766f92f0, callback type 1024, id 0 entered 2(14172) DEBUG: uac [uac_reg.c:723]: uac_reg_tm_callback(): completed with status 407 [uuid: removedXXXX+uac] 2(14172) DEBUG: uac [auth.c:218]: get_autenticate_hdr(): looking for header "Proxy-Authenticate" 2(14172) DEBUG: uac [uac_reg.c:806]: uac_reg_tm_callback(): auth header body [Digest realm="callcentric.com", domain="sip:callcentric.com", nonce="5e6f1a6152212007fcd6fbbd6616612c", opaque="", stale=TRUE, algorithm=MD5] 2(14172) DEBUG: uac [auth_hdr.c:203]: parse_authenticate_body(): <realm>="callcentric.com" state=2 2(14172) DEBUG: uac [auth_hdr.c:203]: parse_authenticate_body(): <domain>="sip:callcentric.com" state=0 2(14172) DEBUG: uac [auth_hdr.c:203]: parse_authenticate_body(): <nonce>="5e6f1a6152212007fcd6fbbd6616612c" state=3 2(14172) DEBUG: uac [auth_hdr.c:203]: parse_authenticate_body(): <opaque>="" state=6 2(14172) DEBUG: uac [auth_hdr.c:203]: parse_authenticate_body(): <stale>="TRUE" state=4 2(14172) DEBUG: uac [auth_hdr.c:203]: parse_authenticate_body(): <algorithm>="MD5" state=7 2(14172) DEBUG: uac [auth_hdr.c:402]: build_authorization_hdr(): hdr is <Proxy-Authorization: Digest username="removedXXXX", realm="callcentric.com", nonce="5e6f1a6152212007fcd6fbbd6616612c", uri="sip:callcentric.com", response="cd8a7b2cb2b24a12034a7ad70f8e8150", algorithm=MD5
2(14172) DEBUG: <core> [parser/parse_addr_spec.c:172]: parse_to_param(): DEBUG: add_param: tag=2afe4db221460197112d59bc9a08ee82-778a 2(14172) DEBUG: <core> [parser/parse_addr_spec.c:894]: parse_addr_spec(): end of header reached, state=29 2(14172) DEBUG: tm [uac.c:249]: t_uac_prepare(): DEBUG:tm:t_uac: next_hop=sip:callcentric.com 2(14172) DEBUG: <core> [dns_cache.c:537]: _dns_hash_find(): (_sip._udp.callcentric.com(25), 33), h=428 2(14172) DEBUG: <core> [dns_cache.c:537]: _dns_hash_find(): (alpha13.callcentric.com(23), 1), h=8 2(14172) DEBUG: <core> [forward.c:174]: get_out_socket(): socket determined: 0x771578e4 2(14172) DEBUG: tm [uac.c:150]: dlg2hash(): DEBUG: dlg2hash: 23187 2(14172) DEBUG: tm [t_reply.c:1589]: cleanup_uac_timers(): DEBUG: cleanup_uac_timers: RETR/FR timers reset 2(14172) DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil) 2(14172) DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil) 2(14172) DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil) 2(14172) DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil) 2(14172) DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil) 2(14172) DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil) 2(14172) DEBUG: <core> [xavp.c:446]: xavp_destroy_list(): destroying xavp list (nil) 2(14172) DEBUG: <core> [receive.c:278]: receive_msg(): cleaning up 2(14172) DEBUG: <core> [parser/msg_parser.c:616]: parse_msg(): SIP Reply (status): 2(14172) DEBUG: <core> [parser/msg_parser.c:618]: parse_msg(): version: <SIP/2.0> 2(14172) DEBUG: <core> [parser/msg_parser.c:620]: parse_msg(): status: <200> 2(14172) DEBUG: <core> [parser/msg_parser.c:622]: parse_msg(): reason: <Ok> 2(14172) DEBUG: <core> [parser/parse_via.c:1254]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK39a5.32682cb2000000000000000000000000.0>; state=16 2(14172) DEBUG: <core> [parser/parse_via.c:2642]: parse_via(): end of header reached, state=5 2(14172) DEBUG: <core> [parser/msg_parser.c:496]: parse_headers(): parse_headers: Via found, flags=2 2(14172) DEBUG: <core> [parser/msg_parser.c:498]: parse_headers(): parse_headers: this is the first via 2(14172) DEBUG: <core> [receive.c:134]: receive_msg(): After parse_msg... 2(14172) DEBUG: tm [t_lookup.c:1011]: t_check_msg(): DEBUG: t_check_msg: msg id=3498 global id=3497 T start=0xffffffff 2(14172) DEBUG: <core> [parser/parse_addr_spec.c:894]: parse_addr_spec(): end of header reached, state=10 2(14172) DEBUG: <core> [parser/msg_parser.c:173]: get_hdr_field(): DEBUG: get_hdr_field: <t> [35]; uri=[sip:removedXXXX@callcentric.com] 2(14172) DEBUG: <core> [parser/msg_parser.c:175]: get_hdr_field(): DEBUG: to body [sip:removedXXXX@callcentric.com ] 2(14172) DEBUG: <core> [parser/msg_parser.c:153]: get_hdr_field(): get_hdr_field: cseq <CSeq>: <11> <REGISTER> 2(14172) DEBUG: tm [t_lookup.c:888]: t_reply_matching(): DEBUG: t_reply_matching: hash 23187 label 0 branch 0 2(14172) DEBUG: tm [t_lookup.c:943]: t_reply_matching(): DEBUG: t_reply_matching: reply matched (T=0x766facc4)! 2(14172) DEBUG: tm [t_lookup.c:1080]: t_check_msg(): DEBUG: t_check_msg: msg id=3498 global id=3498 T end=0x766facc4 2(14172) DEBUG: tm [t_reply.c:2136]: reply_received(): DEBUG: reply_received: org. status uas=0, uac[0]=0 local=2 is_invite=0) 2(14172) DEBUG: tm [t_reply.c:1230]: t_should_relay_response(): ->>>>>>>>> T_code=0, new_code=200 2(14172) DEBUG: tm [t_reply.c:2016]: local_reply(): DEBUG: local_reply: branch=0, save=0, winner=0 2(14172) DEBUG: tm [t_reply.c:2053]: local_reply(): DEBUG: local transaction completed 2(14172) DEBUG: tm [t_reply.c:1589]: cleanup_uac_timers(): DEBUG: cleanup_uac_timers: RETR/FR timers reset 2(14172) DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil) 2(14172) DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil) 2(14172) DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil) 2(14172) DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil) 2(14172) DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil) 2(14172) DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil) 2(14172) DEBUG: <core> [xavp.c:446]: xavp_destroy_list(): destroying xavp list (nil) 2(14172) DEBUG: <core> [receive.c:278]: receive_msg(): cleaning up ```
--- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/255#issuecomment-125188355