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

sip-router bugtracker at sip-router.org
Fri Sep 19 22:35:48 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)

----------
<code>
$ kamailio -V
version: kamailio 4.2.0-pre0 (x86_64/linux) fef8a4-dirty
flags: STATS: Off, USE_TCP, USE_TLS, TLS_HOOKS, USE_RAW_SOCKS, DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, SHM_MEM, SHM_MMAP, PKG_MALLOC, F_MALLOC, DBG_F_MALLOC, 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 4MB
poll method support: poll, epoll_lt, epoll_et, sigio_rt, select.
id: fef8a4 -dirty
compiled on 16:31:51 Sep 19 2014 with gcc 4.4.7
$ git diff
diff --git a/modules/dialog/dlg_handlers.c b/modules/dialog/dlg_handlers.c
index 16c711f..11559ea 100644
--- a/modules/dialog/dlg_handlers.c
+++ b/modules/dialog/dlg_handlers.c
@@ -713,11 +713,16 @@ void dlg_onreq(struct cell* t, int type, struct tmcb_params *param)
        sip_msg_t *req = param->req;
        dlg_cell_t *dlg = NULL;

+       LM_NOTICE("MICONDA: method_value=[%d]\n", req->first_line.u.request.method_value);
+
        if(req->first_line.u.request.method_value == METHOD_BYE) {
                _dlg_ctx.t = 1;
+               LM_NOTICE("MICONDA: method is METHOD_BYE\n");
                return;
        }

+       LM_NOTICE("MICONDA: method is NOT METHOD_BYE\n");
+
        if(req->first_line.u.request.method_value != METHOD_INVITE)
                return;

</code>

Log output (only tm and dialog):
<code>
Sep 19 16:33:31 centos k[23777]: INFO: <script>: [2] BYE sip:4165552222 at 192.168.2.97:5064 From:sip:1234 at 192.168.2.62,tag=as65285b8c To:sip:4165552222 at 192.168.2.62,tag=8278024a33425aa4o4 Call-ID:ee13dfc2-9eff5b8c at 192.168.2.97 Contact:<null> <192.168.2.2:5060->udp:192.168.2.62:5060>
Sep 19 16:33:31 centos k[23777]: DEBUG: dialog [dlg_handlers.c:1168]: dlg_onroute(): route param is 'af8.d3a' (len=7)
Sep 19 16:33:31 centos k[23777]: DEBUG: dialog [dlg_hash.c:654]: dlg_lookup(): ref dlg 0x7fe04e73c070 with 1 -> 3
Sep 19 16:33:31 centos k[23777]: DEBUG: dialog [dlg_hash.c:656]: dlg_lookup(): dialog id=2621 found on entry 2298
Sep 19 16:33:31 centos k[23777]: DEBUG: dialog [dlg_profile.c:511]: set_current_dialog(): setting current dialog [2298:2621]
Sep 19 16:33:31 centos k[23777]: DEBUG: dialog [dlg_hash.c:1066]: next_state_dlg(): dialog 0x7fe04e73c070 changed from state 4 to state 5, due event 7 (ref 3)
Sep 19 16:33:31 centos k[23777]: DEBUG: dialog [dlg_hash.c:854]: dlg_ref(): ref dlg 0x7fe04e73c070 with 1 -> 4
Sep 19 16:33:31 centos k[23777]: DEBUG: dialog [dlg_handlers.c:1557]: dlg_run_event_route(): executing event_route 1 on state 5
Sep 19 16:33:31 centos k[23777]: INFO: <script>: [2] entering event_route[dialog:end]
Sep 19 16:33:32 centos k[23773]: INFO: <script>: [3] BYE sip:4165552222 at 192.168.2.97:5064 From:sip:1234 at 192.168.2.62,tag=as65285b8c To:sip:4165552222 at 192.168.2.62,tag=8278024a33425aa4o4 Call-ID:ee13dfc2-9eff5b8c at 192.168.2.97 Contact:<null> <192.168.2.2:5060->udp:192.168.2.62:5060>
Sep 19 16:33:32 centos k[23773]: DEBUG: dialog [dlg_handlers.c:1168]: dlg_onroute(): route param is 'af8.d3a' (len=7)
Sep 19 16:33:32 centos k[23773]: DEBUG: dialog [dlg_hash.c:654]: dlg_lookup(): ref dlg 0x7fe04e73c070 with 1 -> 5
Sep 19 16:33:32 centos k[23773]: DEBUG: dialog [dlg_hash.c:656]: dlg_lookup(): dialog id=2621 found on entry 2298
Sep 19 16:33:32 centos k[23773]: DEBUG: dialog [dlg_profile.c:511]: set_current_dialog(): setting current dialog [2298:2621]
Sep 19 16:33:32 centos k[23773]: DEBUG: dialog [dlg_hash.c:1066]: next_state_dlg(): dialog 0x7fe04e73c070 changed from state 5 to state 5, due event 7 (ref 5)
Sep 19 16:33:32 centos k[23773]: DEBUG: dialog [dlg_hash.c:872]: dlg_unref(): unref dlg 0x7fe04e73c070 with 1 -> 4
Sep 19 16:33:32 centos k[23773]: DEBUG: tm [t_lookup.c:1373]: t_newtran(): DEBUG: t_newtran: msg id=3 , global msg id=2 , T on entrance=0xffffffffffffffff
Sep 19 16:33:32 centos k[23773]: DEBUG: tm [t_lookup.c:527]: t_lookup_request(): t_lookup_request: start searching: hash=18378, isACK=0
Sep 19 16:33:32 centos k[23773]: DEBUG: tm [t_lookup.c:485]: matching_3261(): DEBUG: RFC3261 transaction matching failed
Sep 19 16:33:32 centos k[23773]: DEBUG: tm [t_lookup.c:709]: t_lookup_request(): DEBUG: t_lookup_request: no transaction found
Sep 19 16:33:32 centos k[23773]: DEBUG: tm [t_hooks.c:374]: run_reqin_callbacks_internal(): DBG: trans=0x7fe04e73c320, callback type 1, id 0 entered
Sep 19 16:33:32 centos k[23773]: DEBUG: tm [t_hooks.c:374]: run_reqin_callbacks_internal(): DBG: trans=0x7fe04e73c320, callback type 1, id 0 entered
Sep 19 16:33:32 centos k[23773]: NOTICE: dialog [dlg_handlers.c:716]: dlg_onreq(): MICONDA: method_value=[8]
Sep 19 16:33:32 centos k[23773]: NOTICE: dialog [dlg_handlers.c:720]: dlg_onreq(): MICONDA: method is METHOD_BYE
Sep 19 16:33:32 centos k[23773]: DEBUG: tm [t_funcs.c:394]: t_relay_to(): SER: new transaction fwd'ed
Sep 19 16:33:32 centos k[23773]: DEBUG: dialog [dlg_hash.c:654]: dlg_lookup(): ref dlg 0x7fe04e73c070 with 1 -> 5
Sep 19 16:33:32 centos k[23773]: DEBUG: dialog [dlg_hash.c:656]: dlg_lookup(): dialog id=2621 found on entry 2298
Sep 19 16:33:32 centos k[23773]: DEBUG: dialog [dlg_hash.c:872]: dlg_unref(): unref dlg 0x7fe04e73c070 with 1 -> 4
Sep 19 16:33:32 centos k[23776]: DEBUG: tm [t_lookup.c:1072]: t_check_msg(): DEBUG: t_check_msg: msg id=3 global id=2 T start=(nil)
Sep 19 16:33:32 centos k[23776]: DEBUG: tm [t_lookup.c:949]: t_reply_matching(): DEBUG: t_reply_matching: hash 18378 label 0 branch 0
Sep 19 16:33:32 centos k[23776]: DEBUG: tm [t_lookup.c:1004]: t_reply_matching(): DEBUG: t_reply_matching: reply matched (T=0x7fe04e73c320)!
Sep 19 16:33:32 centos k[23776]: DEBUG: tm [t_hooks.c:288]: run_trans_callbacks_internal(): DBG: trans=0x7fe04e73c320, callback type 2, id 0 entered
Sep 19 16:33:32 centos k[23776]: DEBUG: dialog [dlg_hash.c:654]: dlg_lookup(): ref dlg 0x7fe04e73c070 with 1 -> 5
Sep 19 16:33:32 centos k[23776]: DEBUG: dialog [dlg_hash.c:656]: dlg_lookup(): dialog id=2621 found on entry 2298
Sep 19 16:33:32 centos k[23776]: DEBUG: dialog [dlg_profile.c:511]: set_current_dialog(): setting current dialog [2298:2621]
Sep 19 16:33:32 centos k[23776]: DEBUG: dialog [dlg_hash.c:872]: dlg_unref(): unref dlg 0x7fe04e73c070 with 1 -> 4
Sep 19 16:33:32 centos k[23776]: DEBUG: tm [t_lookup.c:1141]: t_check_msg(): DEBUG: t_check_msg: msg id=3 global id=3 T end=0x7fe04e73c320
Sep 19 16:33:32 centos k[23776]: DEBUG: tm [t_reply.c:2210]: reply_received(): DEBUG: reply_received: org. status uas=0, uac[0]=0 local=0 is_invite=0)
Sep 19 16:33:32 centos k[23776]: INFO: <script>: [3] entering onreply_route[BYE] for 200 OK Call-ID:ee13dfc2-9eff5b8c at 192.168.2.97 Cseq:102
Sep 19 16:33:32 centos k[23776]: INFO: <script>: [3] exiting onreply_route[BYE] for 200 OK Call-ID:ee13dfc2-9eff5b8c at 192.168.2.97 Cseq:102
Sep 19 16:33:32 centos k[23776]: DEBUG: tm [t_reply.c:1304]: t_should_relay_response(): ->>>>>>>>> T_code=0, new_code=200
Sep 19 16:33:32 centos k[23776]: DEBUG: tm [t_reply.c:1822]: relay_reply(): DEBUG: relay_reply: branch=0, save=0, relay=0 icode=0
Sep 19 16:33:32 centos k[23776]: DEBUG: tm [t_reply.c:1663]: cleanup_uac_timers(): DEBUG: cleanup_uac_timers: RETR/FR timers reset
Sep 19 16:33:33 centos k[23777]: INFO: <script>: [2] exiting event_route[dialog:end]
Sep 19 16:33:33 centos k[23777]: DEBUG: dialog [dlg_hash.c:872]: dlg_unref(): unref dlg 0x7fe04e73c070 with 1 -> 3
Sep 19 16:33:33 centos k[23777]: DEBUG: dialog [dlg_hash.c:854]: dlg_ref(): ref dlg 0x7fe04e73c070 with 1 -> 4
Sep 19 16:33:33 centos k[23777]: DEBUG: dialog [dlg_handlers.c:1290]: dlg_onroute(): BYE successfully processed
Sep 19 16:33:33 centos k[23777]: DEBUG: dialog [dlg_hash.c:872]: dlg_unref(): unref dlg 0x7fe04e73c070 with 2 -> 2
Sep 19 16:33:33 centos k[23777]: DEBUG: dialog [dlg_hash.c:872]: dlg_unref(): unref dlg 0x7fe04e73c070 with 1 -> 1
Sep 19 16:33:33 centos k[23777]: DEBUG: tm [t_lookup.c:1373]: t_newtran(): DEBUG: t_newtran: msg id=2 , global msg id=1 , T on entrance=0xffffffffffffffff
Sep 19 16:33:33 centos k[23777]: DEBUG: tm [t_lookup.c:527]: t_lookup_request(): t_lookup_request: start searching: hash=18378, isACK=0
Sep 19 16:33:33 centos k[23777]: DEBUG: tm [t_lookup.c:470]: matching_3261(): DEBUG: RFC3261 transaction matched, tid=43a8d12b
Sep 19 16:33:33 centos k[23777]: DEBUG: tm [t_lookup.c:726]: t_lookup_request(): DEBUG: t_lookup_request: transaction found (T=0x7fe04e73c320)
Sep 19 16:33:33 centos k[23777]: DEBUG: tm [t_reply.c:1623]: t_retransmit_reply(): DEBUG: reply retransmitted. buf=0x7fe0494fc340: SIP/2.0 2..., shmem=0x7fe04e73fa68: SIP/2.0 2
Sep 19 16:33:37 centos k[23779]: DEBUG: dialog [dlg_handlers.c:324]: dlg_iuid_sfree(): freeing dlg iuid [2298:2621] (0x7fe04e73ed68)
</code>

The zombie dialog:
<code>
$ kamcmd dlg.list
{
        h_entry: 2298
        h_id: 2621
        call-id: ee13dfc2-9eff5b8c at 192.168.2.97
        from_uri: sip:4165552222 at 192.168.2.62
        to_uri: sip:1234 at 192.168.2.62
        state: 5
        start_ts: 1411158800
        init_ts: 1411158797
        timeout: 0
        lifetime: 3600
        dflags: 519
        sflags: 0
        iflags: 1
        caller: {
                tag: 8278024a33425aa4o4
                contact: sip:4165552222 at 192.168.2.97:5064
                cseq: 101
                route_set:
                socket: udp:192.168.2.62:5060
        }
        callee: {
                tag: as65285b8c
                contact: sip:240 at 192.168.2.2:5060
                cseq: 0
                route_set:
                socket: udp:192.168.2.62:5060
        }
        profiles: {
        }
        variables: {
        }
}
</code>
----------

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

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.

More information about the sr-dev mailing list