[sr-dev] [kamailio] UAC module - registration stuck in ONGOING state (does not retry) (#255)

AndyJRobinson notifications at github.com
Mon Jul 27 14:29:08 CEST 2015


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 at callcentric.com] 
 2(14172) DEBUG: <core> [parser/msg_parser.c:175]: get_hdr_field(): DEBUG: to body [<sip:removedXXXX at 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 at callcentric.com] 
 2(14172) DEBUG: <core> [parser/msg_parser.c:175]: get_hdr_field(): DEBUG: to body [<sip:removedXXXX at 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
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.sip-router.org/pipermail/sr-dev/attachments/20150727/d03da9ce/attachment.html>


More information about the sr-dev mailing list