[sr-dev] [tracker] Comment added: zombie dialogs in state 5

Tue Sep 23 17:18:18 CEST 2014

THIS IS AN AUTOMATED MESSAGE, DO NOT REPLY.

The following task has a new comment added:

FS#424 - zombie dialogs in state 5
User who did this - Ovidiu Sas (osas)

----------
It is the dialog:end route, so it cannot be executed inside dlg_manage().
Here are the logs with all the functions that are called during BYE processing:
 - has_totag()
 - loose_route()
 - if (is_method("INVITE")) {
 - t_relay()

<code>
Sep 23 11:11:36 centos k[1053]: ERROR: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio//kamailio.cfg] l=151 a=26 n=xlog
Sep 23 11:11:36 centos k[1053]: INFO: <script>: [2] >>>>>>>>>>>>>>>>>>>>> calling has_totag()
Sep 23 11:11:36 centos k[1053]: ERROR: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio//kamailio.cfg] l=196 a=16 n=if
Sep 23 11:11:36 centos k[1053]: ERROR: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio//kamailio.cfg] l=152 a=24 n=has_totag
Sep 23 11:11:36 centos k[1053]: ERROR: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio//kamailio.cfg] l=159 a=26 n=xlog
Sep 23 11:11:36 centos k[1053]: INFO: <script>: [2] >>>>>>>>>>>>>>>>>>>>> calling loose_route()
Sep 23 11:11:36 centos k[1053]: ERROR: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio//kamailio.cfg] l=191 a=16 n=if
Sep 23 11:11:36 centos k[1053]: ERROR: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio//kamailio.cfg] l=160 a=24 n=loose_route
Sep 23 11:11:36 centos k[1053]: NOTICE: dialog [dlg_hash.c:680]: dlg_get_by_iuid(): MICONDA: diuid=[0x7f9d6156fc20] diuid->h_entry=[0] diuid->h_id=[0]
Sep 23 11:11:36 centos k[1053]: DEBUG: dialog [dlg_handlers.c:1168]: dlg_onroute(): route param is '0e5.d692' (len=8)
Sep 23 11:11:36 centos k[1053]: DEBUG: dialog [dlg_hash.c:654]: dlg_lookup(): ref dlg 0x7f9d68473070 with 1 -> 3
Sep 23 11:11:36 centos k[1053]: DEBUG: dialog [dlg_hash.c:656]: dlg_lookup(): dialog id=10605 found on entry 1504
Sep 23 11:11:36 centos k[1053]: DEBUG: dialog [dlg_profile.c:511]: set_current_dialog(): setting current dialog [1504:10605]
Sep 23 11:11:36 centos k[1053]: DEBUG: dialog [dlg_hash.c:1067]: next_state_dlg(): dialog 0x7f9d68473070 changed from state 4 to state 5, due event 7 (ref 3)
Sep 23 11:11:36 centos k[1053]: DEBUG: dialog [dlg_hash.c:855]: dlg_ref(): ref dlg 0x7f9d68473070 with 1 -> 4
Sep 23 11:11:36 centos k[1053]: DEBUG: dialog [dlg_handlers.c:1557]: dlg_run_event_route(): executing event_route 1 on state 5
Sep 23 11:11:36 centos k[1053]: ERROR: *** cfgtrace:local_route=[BYE] c=[/usr/local/etc/kamailio//kamailio.cfg] l=367 a=26 n=xlog
Sep 23 11:11:36 centos k[1053]: INFO: <script>: [2] entering event_route[dialog:end]
Sep 23 11:11:36 centos k[1053]: ERROR: *** cfgtrace:local_route=[BYE] c=[/usr/local/etc/kamailio//kamailio.cfg] l=369 a=25 n=usleep
Sep 23 11:11:37 centos k[1049]: ERROR: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio//kamailio.cfg] l=151 a=26 n=xlog
Sep 23 11:11:37 centos k[1049]: INFO: <script>: [3] >>>>>>>>>>>>>>>>>>>>> calling has_totag()
Sep 23 11:11:37 centos k[1049]: ERROR: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio//kamailio.cfg] l=196 a=16 n=if
Sep 23 11:11:37 centos k[1049]: ERROR: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio//kamailio.cfg] l=152 a=24 n=has_totag
Sep 23 11:11:37 centos k[1049]: ERROR: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio//kamailio.cfg] l=159 a=26 n=xlog
Sep 23 11:11:37 centos k[1049]: INFO: <script>: [3] >>>>>>>>>>>>>>>>>>>>> calling loose_route()
Sep 23 11:11:37 centos k[1049]: ERROR: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio//kamailio.cfg] l=191 a=16 n=if
Sep 23 11:11:37 centos k[1049]: ERROR: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio//kamailio.cfg] l=160 a=24 n=loose_route
Sep 23 11:11:37 centos k[1049]: NOTICE: dialog [dlg_hash.c:680]: dlg_get_by_iuid(): MICONDA: diuid=[0x7f9d6156fc20] diuid->h_entry=[0] diuid->h_id=[0]
Sep 23 11:11:37 centos k[1049]: DEBUG: dialog [dlg_handlers.c:1168]: dlg_onroute(): route param is '0e5.d692' (len=8)
Sep 23 11:11:37 centos k[1049]: DEBUG: dialog [dlg_hash.c:654]: dlg_lookup(): ref dlg 0x7f9d68473070 with 1 -> 5
Sep 23 11:11:37 centos k[1049]: DEBUG: dialog [dlg_hash.c:656]: dlg_lookup(): dialog id=10605 found on entry 1504
Sep 23 11:11:37 centos k[1049]: DEBUG: dialog [dlg_profile.c:511]: set_current_dialog(): setting current dialog [1504:10605]
Sep 23 11:11:37 centos k[1049]: DEBUG: dialog [dlg_hash.c:1067]: next_state_dlg(): dialog 0x7f9d68473070 changed from state 5 to state 5, due event 7 (ref 5)
Sep 23 11:11:37 centos k[1049]: DEBUG: dialog [dlg_hash.c:873]: dlg_unref(): unref dlg 0x7f9d68473070 with 1 -> 4
Sep 23 11:11:37 centos k[1049]: ERROR: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio//kamailio.cfg] l=161 a=26 n=xlog
Sep 23 11:11:37 centos k[1049]: INFO: <script>: [3] >>>>>>>>>>>>>>>>>>>>> calling is_method("INVITE")
Sep 23 11:11:37 centos k[1049]: ERROR: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio//kamailio.cfg] l=171 a=16 n=if
Sep 23 11:11:37 centos k[1049]: ERROR: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio//kamailio.cfg] l=162 a=25 n=is_method
Sep 23 11:11:37 centos k[1049]: ERROR: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio//kamailio.cfg] l=171 a=26 n=xlog
Sep 23 11:11:37 centos k[1049]: INFO: <script>: [3] >>>>>>>>>>>>>>>>>>>>> calling t_relay()
Sep 23 11:11:37 centos k[1049]: ERROR: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio//kamailio.cfg] l=172 a=24 n=t_relay
Sep 23 11:11:37 centos k[1049]: DEBUG: tm [t_lookup.c:1373]: t_newtran(): DEBUG: t_newtran: msg id=3 , global msg id=2 , T on entrance=0xffffffffffffffff
Sep 23 11:11:37 centos k[1049]: DEBUG: tm [t_lookup.c:527]: t_lookup_request(): t_lookup_request: start searching: hash=9393, isACK=0
Sep 23 11:11:37 centos k[1049]: DEBUG: tm [t_lookup.c:485]: matching_3261(): DEBUG: RFC3261 transaction matching failed
Sep 23 11:11:37 centos k[1049]: DEBUG: tm [t_lookup.c:709]: t_lookup_request(): DEBUG: t_lookup_request: no transaction found
Sep 23 11:11:37 centos k[1049]: DEBUG: tm [t_hooks.c:374]: run_reqin_callbacks_internal(): DBG: trans=0x7f9d68473320, callback type 1, id 0 entered
Sep 23 11:11:37 centos k[1049]: DEBUG: tm [t_hooks.c:374]: run_reqin_callbacks_internal(): DBG: trans=0x7f9d68473320, callback type 1, id 0 entered
Sep 23 11:11:37 centos k[1049]: NOTICE: dialog [dlg_handlers.c:716]: dlg_onreq(): MICONDA: method_value=[8]
Sep 23 11:11:37 centos k[1049]: NOTICE: dialog [dlg_handlers.c:720]: dlg_onreq(): MICONDA: method is METHOD_BYE
Sep 23 11:11:37 centos k[1049]: DEBUG: tm [t_funcs.c:394]: t_relay_to(): SER: new transaction fwd'ed
Sep 23 11:11:37 centos k[1049]: ERROR: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio//kamailio.cfg] l=192 a=2 n=exit
Sep 23 11:11:37 centos k[1049]: NOTICE: dialog [dlg_hash.c:680]: dlg_get_by_iuid(): MICONDA: diuid=[0x7f9d6156fc20] diuid->h_entry=[1504] diuid->h_id=[10605]
Sep 23 11:11:37 centos k[1049]: DEBUG: dialog [dlg_hash.c:654]: dlg_lookup(): ref dlg 0x7f9d68473070 with 1 -> 5
Sep 23 11:11:37 centos k[1049]: DEBUG: dialog [dlg_hash.c:656]: dlg_lookup(): dialog id=10605 found on entry 1504
Sep 23 11:11:37 centos k[1049]: NOTICE: dialog [dlg_var.c:47]: dlg_cfg_cb(): MICONDA: dlg=[0x7f9d68473070]
Sep 23 11:11:37 centos k[1049]: NOTICE: dialog [dlg_var.c:50]: dlg_cfg_cb(): MICONDA: _dlg_ctx.t=[1] dlg->state=[5] _dlg_ctx.expect_t=[0]
Sep 23 11:11:37 centos k[1049]: DEBUG: dialog [dlg_hash.c:873]: dlg_unref(): unref dlg 0x7f9d68473070 with 1 -> 4
Sep 23 11:11:37 centos k[1049]: NOTICE: dialog [dlg_hash.c:680]: dlg_get_by_iuid(): MICONDA: diuid=[0x7f9d6156fc20] diuid->h_entry=[0] diuid->h_id=[0]
Sep 23 11:11:37 centos k[1052]: DEBUG: tm [t_lookup.c:1072]: t_check_msg(): DEBUG: t_check_msg: msg id=3 global id=2 T start=(nil)
Sep 23 11:11:37 centos k[1052]: DEBUG: tm [t_lookup.c:949]: t_reply_matching(): DEBUG: t_reply_matching: hash 9393 label 0 branch 0
Sep 23 11:11:37 centos k[1052]: DEBUG: tm [t_lookup.c:1004]: t_reply_matching(): DEBUG: t_reply_matching: reply matched (T=0x7f9d68473320)!
Sep 23 11:11:37 centos k[1052]: DEBUG: tm [t_hooks.c:288]: run_trans_callbacks_internal(): DBG: trans=0x7f9d68473320, callback type 2, id 0 entered
Sep 23 11:11:37 centos k[1052]: NOTICE: dialog [dlg_hash.c:680]: dlg_get_by_iuid(): MICONDA: diuid=[0x7f9d68475d68] diuid->h_entry=[1504] diuid->h_id=[10605]
Sep 23 11:11:37 centos k[1052]: DEBUG: dialog [dlg_hash.c:654]: dlg_lookup(): ref dlg 0x7f9d68473070 with 1 -> 5
Sep 23 11:11:37 centos k[1052]: DEBUG: dialog [dlg_hash.c:656]: dlg_lookup(): dialog id=10605 found on entry 1504
Sep 23 11:11:37 centos k[1052]: DEBUG: dialog [dlg_profile.c:511]: set_current_dialog(): setting current dialog [1504:10605]
Sep 23 11:11:37 centos k[1052]: DEBUG: dialog [dlg_hash.c:873]: dlg_unref(): unref dlg 0x7f9d68473070 with 1 -> 4
Sep 23 11:11:37 centos k[1052]: DEBUG: tm [t_lookup.c:1141]: t_check_msg(): DEBUG: t_check_msg: msg id=3 global id=3 T end=0x7f9d68473320
Sep 23 11:11:37 centos k[1052]: DEBUG: tm [t_reply.c:2210]: reply_received(): DEBUG: reply_received: org. status uas=0, uac[0]=0 local=0 is_invite=0)
Sep 23 11:11:37 centos k[1052]: DEBUG: tm [t_reply.c:1304]: t_should_relay_response(): ->>>>>>>>> T_code=0, new_code=200
Sep 23 11:11:37 centos k[1052]: DEBUG: tm [t_reply.c:1822]: relay_reply(): DEBUG: relay_reply: branch=0, save=0, relay=0 icode=0
Sep 23 11:11:37 centos k[1052]: DEBUG: tm [t_reply.c:1663]: cleanup_uac_timers(): DEBUG: cleanup_uac_timers: RETR/FR timers reset
Sep 23 11:11:38 centos k[1053]: ERROR: *** cfgtrace:local_route=[BYE] c=[/usr/local/etc/kamailio//kamailio.cfg] l=370 a=26 n=xlog
Sep 23 11:11:38 centos k[1053]: INFO: <script>: [2] exiting event_route[dialog:end]
Sep 23 11:11:38 centos k[1053]: DEBUG: dialog [dlg_hash.c:873]: dlg_unref(): unref dlg 0x7f9d68473070 with 1 -> 3
Sep 23 11:11:38 centos k[1053]: DEBUG: dialog [dlg_hash.c:855]: dlg_ref(): ref dlg 0x7f9d68473070 with 1 -> 4
Sep 23 11:11:38 centos k[1053]: DEBUG: dialog [dlg_handlers.c:1290]: dlg_onroute(): BYE successfully processed
Sep 23 11:11:38 centos k[1053]: DEBUG: dialog [dlg_hash.c:873]: dlg_unref(): unref dlg 0x7f9d68473070 with 2 -> 2
Sep 23 11:11:38 centos k[1053]: DEBUG: dialog [dlg_hash.c:873]: dlg_unref(): unref dlg 0x7f9d68473070 with 1 -> 1
Sep 23 11:11:38 centos k[1053]: ERROR: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio//kamailio.cfg] l=161 a=26 n=xlog
Sep 23 11:11:38 centos k[1053]: INFO: <script>: [2] >>>>>>>>>>>>>>>>>>>>> calling is_method("INVITE")
Sep 23 11:11:38 centos k[1053]: ERROR: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio//kamailio.cfg] l=171 a=16 n=if
Sep 23 11:11:38 centos k[1053]: ERROR: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio//kamailio.cfg] l=162 a=25 n=is_method
Sep 23 11:11:38 centos k[1053]: ERROR: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio//kamailio.cfg] l=171 a=26 n=xlog
Sep 23 11:11:38 centos k[1053]: INFO: <script>: [2] >>>>>>>>>>>>>>>>>>>>> calling t_relay()
Sep 23 11:11:38 centos k[1053]: ERROR: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio//kamailio.cfg] l=172 a=24 n=t_relay
Sep 23 11:11:38 centos k[1053]: DEBUG: tm [t_lookup.c:1373]: t_newtran(): DEBUG: t_newtran: msg id=2 , global msg id=1 , T on entrance=0xffffffffffffffff
Sep 23 11:11:38 centos k[1053]: DEBUG: tm [t_lookup.c:527]: t_lookup_request(): t_lookup_request: start searching: hash=9393, isACK=0
Sep 23 11:11:38 centos k[1053]: DEBUG: tm [t_lookup.c:470]: matching_3261(): DEBUG: RFC3261 transaction matched, tid=-533d3dd6
Sep 23 11:11:38 centos k[1053]: DEBUG: tm [t_lookup.c:726]: t_lookup_request(): DEBUG: t_lookup_request: transaction found (T=0x7f9d68473320)
Sep 23 11:11:38 centos k[1053]: DEBUG: tm [t_reply.c:1623]: t_retransmit_reply(): DEBUG: reply retransmitted. buf=0x7f9d632333e0: SIP/2.0 2..., shmem=0x7f9d68476c40: SIP/2.0 2
Sep 23 11:11:38 centos k[1053]: ERROR: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/usr/local/etc/kamailio//kamailio.cfg] l=192 a=2 n=exit
Sep 23 11:11:38 centos k[1053]: NOTICE: dialog [dlg_hash.c:680]: dlg_get_by_iuid(): MICONDA: diuid=[0x7f9d6156fc20] diuid->h_entry=[0] diuid->h_id=[0]
Sep 23 11:11:38 centos k[1053]: NOTICE: dialog [dlg_var.c:47]: dlg_cfg_cb(): MICONDA: dlg=[(nil)]
Sep 23 11:11:38 centos k[1053]: NOTICE: dialog [dlg_hash.c:680]: dlg_get_by_iuid(): MICONDA: diuid=[0x7f9d6156fc20] diuid->h_entry=[0] diuid->h_id=[0]
Sep 23 11:11:42 centos k[1055]: DEBUG: dialog [dlg_handlers.c:324]: dlg_iuid_sfree(): freeing dlg iuid [1504:10605] (0x7f9d68475d68)
</code>

loose_route() is running [dialog:end] route where we have the blocking sleep.
----------

More information can be found at the following URL:
http://sip-router.org/tracker/index.php?do=details&task_id=424#comment1646

You are receiving this message because you have requested it from the Flyspray bugtracking system.  If you did not expect this message or don't want to receive mails in future, you can change your notification settings at the URL shown above.