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

Tue Sep 16 21:13:51 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)

----------
No luck :(
I think a fix should be implemented at tm level, so all modules using tm callbacks could benefit from it.

Here are the logs:
Sep 16 15:08:00 centos k[28276]: INFO: <script>: [2] BYE sip:4165552222 at 192.168.2.97:5064 From:sip:1234 at 192.168.2.62,tag=as0435f26e To:sip:4165552222 at 192.168.2.62,tag=f738712194561120o4 Call-ID:41a0ddf5-fb426a5c at 192.168.2.97 Contact:<null> <192.168.2.2:5060->udp:192.168.2.62:5060>
Sep 16 15:08:00 centos k[28276]: DEBUG: dialog [dlg_handlers.c:1163]: dlg_onroute(): route param is 'c46.6f21' (len=8)
Sep 16 15:08:00 centos k[28276]: DEBUG: dialog [dlg_hash.c:654]: dlg_lookup(): ref dlg 0x7f11da013070 with 1 -> 3
Sep 16 15:08:00 centos k[28276]: DEBUG: dialog [dlg_hash.c:656]: dlg_lookup(): dialog id=4854 found on entry 1612
Sep 16 15:08:00 centos k[28276]: DEBUG: dialog [dlg_profile.c:511]: set_current_dialog(): setting current dialog [1612:4854]
Sep 16 15:08:00 centos k[28276]: DEBUG: dialog [dlg_hash.c:1066]: next_state_dlg(): dialog 0x7f11da013070 changed from state 4 to state 5, due event 7 (ref 3)
Sep 16 15:08:00 centos k[28276]: DEBUG: dialog [dlg_hash.c:854]: dlg_ref(): ref dlg 0x7f11da013070 with 1 -> 4
Sep 16 15:08:00 centos k[28276]: DEBUG: dialog [dlg_handlers.c:1552]: dlg_run_event_route(): executing event_route 1 on state 5
Sep 16 15:08:00 centos k[28276]: INFO: <script>: [2] entering event_route[dialog:end]
Sep 16 15:08:00 centos k[28272]: INFO: <script>: [3] BYE sip:4165552222 at 192.168.2.97:5064 From:sip:1234 at 192.168.2.62,tag=as0435f26e To:sip:4165552222 at 192.168.2.62,tag=f738712194561120o4 Call-ID:41a0ddf5-fb426a5c at 192.168.2.97 Contact:<null> <192.168.2.2:5060->udp:192.168.2.62:5060>
Sep 16 15:08:00 centos k[28272]: DEBUG: dialog [dlg_handlers.c:1163]: dlg_onroute(): route param is 'c46.6f21' (len=8)
Sep 16 15:08:00 centos k[28272]: DEBUG: dialog [dlg_hash.c:654]: dlg_lookup(): ref dlg 0x7f11da013070 with 1 -> 5
Sep 16 15:08:00 centos k[28272]: DEBUG: dialog [dlg_hash.c:656]: dlg_lookup(): dialog id=4854 found on entry 1612
Sep 16 15:08:00 centos k[28272]: DEBUG: dialog [dlg_profile.c:511]: set_current_dialog(): setting current dialog [1612:4854]
Sep 16 15:08:00 centos k[28272]: DEBUG: dialog [dlg_hash.c:1066]: next_state_dlg(): dialog 0x7f11da013070 changed from state 5 to state 5, due event 7 (ref 5)
Sep 16 15:08:00 centos k[28272]: DEBUG: dialog [dlg_hash.c:872]: dlg_unref(): unref dlg 0x7f11da013070 with 1 -> 4
Sep 16 15:08:00 centos k[28272]: DEBUG: tm [t_lookup.c:1373]: t_newtran(): DEBUG: t_newtran: msg id=3 , global msg id=2 , T on entrance=0xffffffffffffffff
Sep 16 15:08:00 centos k[28272]: DEBUG: tm [t_lookup.c:527]: t_lookup_request(): t_lookup_request: start searching: hash=25884, isACK=0
Sep 16 15:08:00 centos k[28272]: DEBUG: tm [t_lookup.c:485]: matching_3261(): DEBUG: RFC3261 transaction matching failed
Sep 16 15:08:00 centos k[28272]: DEBUG: tm [t_lookup.c:709]: t_lookup_request(): DEBUG: t_lookup_request: no transaction found
Sep 16 15:08:00 centos k[28272]: DEBUG: tm [t_hooks.c:374]: run_reqin_callbacks_internal(): DBG: trans=0x7f11da013320, callback type 1, id 0 entered
Sep 16 15:08:00 centos k[28272]: DEBUG: tm [t_hooks.c:374]: run_reqin_callbacks_internal(): DBG: trans=0x7f11da013320, callback type 1, id 0 entered
Sep 16 15:08:00 centos k[28272]: DEBUG: tm [t_funcs.c:394]: t_relay_to(): SER: new transaction fwd'ed
Sep 16 15:08:00 centos k[28272]: DEBUG: dialog [dlg_hash.c:654]: dlg_lookup(): ref dlg 0x7f11da013070 with 1 -> 5
Sep 16 15:08:00 centos k[28272]: DEBUG: dialog [dlg_hash.c:656]: dlg_lookup(): dialog id=4854 found on entry 1612
Sep 16 15:08:00 centos k[28272]: DEBUG: dialog [dlg_hash.c:872]: dlg_unref(): unref dlg 0x7f11da013070 with 1 -> 4
Sep 16 15:08:00 centos k[28275]: DEBUG: tm [t_lookup.c:1072]: t_check_msg(): DEBUG: t_check_msg: msg id=3 global id=2 T start=(nil)
Sep 16 15:08:00 centos k[28275]: DEBUG: tm [t_lookup.c:949]: t_reply_matching(): DEBUG: t_reply_matching: hash 25884 label 0 branch 0
Sep 16 15:08:00 centos k[28275]: DEBUG: tm [t_lookup.c:1004]: t_reply_matching(): DEBUG: t_reply_matching: reply matched (T=0x7f11da013320)!
Sep 16 15:08:00 centos k[28275]: DEBUG: tm [t_hooks.c:288]: run_trans_callbacks_internal(): DBG: trans=0x7f11da013320, callback type 2, id 0 entered
Sep 16 15:08:00 centos k[28275]: DEBUG: dialog [dlg_hash.c:654]: dlg_lookup(): ref dlg 0x7f11da013070 with 1 -> 5
Sep 16 15:08:00 centos k[28275]: DEBUG: dialog [dlg_hash.c:656]: dlg_lookup(): dialog id=4854 found on entry 1612
Sep 16 15:08:00 centos k[28275]: DEBUG: dialog [dlg_profile.c:511]: set_current_dialog(): setting current dialog [1612:4854]
Sep 16 15:08:00 centos k[28275]: DEBUG: dialog [dlg_hash.c:872]: dlg_unref(): unref dlg 0x7f11da013070 with 1 -> 4
Sep 16 15:08:00 centos k[28275]: DEBUG: tm [t_lookup.c:1141]: t_check_msg(): DEBUG: t_check_msg: msg id=3 global id=3 T end=0x7f11da013320
Sep 16 15:08:00 centos k[28275]: DEBUG: tm [t_reply.c:2210]: reply_received(): DEBUG: reply_received: org. status uas=0, uac[0]=0 local=0 is_invite=0)
Sep 16 15:08:00 centos k[28275]: INFO: <script>: [3] entering onreply_route[BYE] for 200 OK Call-ID:41a0ddf5-fb426a5c at 192.168.2.97 Cseq:102
Sep 16 15:08:00 centos k[28275]: DEBUG: tm [t_reply.c:1304]: t_should_relay_response(): ->>>>>>>>> T_code=0, new_code=200
Sep 16 15:08:00 centos k[28275]: DEBUG: tm [t_reply.c:1822]: relay_reply(): DEBUG: relay_reply: branch=0, save=0, relay=0 icode=0
Sep 16 15:08:00 centos k[28275]: DEBUG: tm [t_reply.c:1663]: cleanup_uac_timers(): DEBUG: cleanup_uac_timers: RETR/FR timers reset

Sep 16 15:08:01 centos k[28276]: INFO: <script>: [2] exiting event_route[dialog:end]
Sep 16 15:08:01 centos k[28276]: DEBUG: dialog [dlg_hash.c:872]: dlg_unref(): unref dlg 0x7f11da013070 with 1 -> 3
Sep 16 15:08:01 centos k[28276]: DEBUG: dialog [dlg_hash.c:854]: dlg_ref(): ref dlg 0x7f11da013070 with 1 -> 4
Sep 16 15:08:01 centos k[28276]: DEBUG: dialog [dlg_handlers.c:1285]: dlg_onroute(): BYE successfully processed
Sep 16 15:08:01 centos k[28276]: DEBUG: dialog [dlg_hash.c:872]: dlg_unref(): unref dlg 0x7f11da013070 with 2 -> 2
Sep 16 15:08:01 centos k[28276]: DEBUG: dialog [dlg_hash.c:872]: dlg_unref(): unref dlg 0x7f11da013070 with 1 -> 1
Sep 16 15:08:01 centos k[28276]: DEBUG: tm [t_lookup.c:1373]: t_newtran(): DEBUG: t_newtran: msg id=2 , global msg id=1 , T on entrance=0xffffffffffffffff
Sep 16 15:08:01 centos k[28276]: DEBUG: tm [t_lookup.c:527]: t_lookup_request(): t_lookup_request: start searching: hash=25884, isACK=0
Sep 16 15:08:01 centos k[28276]: DEBUG: tm [t_lookup.c:470]: matching_3261(): DEBUG: RFC3261 transaction matched, tid=55953831
Sep 16 15:08:01 centos k[28276]: DEBUG: tm [t_lookup.c:726]: t_lookup_request(): DEBUG: t_lookup_request: transaction found (T=0x7f11da013320)
Sep 16 15:08:01 centos k[28276]: DEBUG: tm [t_reply.c:1623]: t_retransmit_reply(): DEBUG: reply retransmitted. buf=0x7f11d4dd37a0: SIP/2.0 2..., shmem=0x7f11da016a68: SIP/2.0 2

Sep 16 15:08:05 centos k[28278]: DEBUG: dialog [dlg_handlers.c:324]: dlg_iuid_sfree(): freeing dlg iuid [1612:4854] (0x7f11da015d68)
----------

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

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.