On 20/11/2013 12:01, Daniel-Constantin Mierla wrote: Hi Daniel, local-request is triggered by a BYE I have attached sample log and trace There is some kind of dialogs mixing. Here is the 1st call dialog as reported by "kamctl mi dlg_list" _before and after_ the 2d call is answered: # kamctl mi dlg_list dialog:: hash=2790:3231 state:: 2 ref_count:: 1 timestart:: 0 timeout:: 0 callid:: GoXhk8GfkIEEqFyFNcySEjSOOpVKg4Uq from_uri:: sip:15909901@staging.voip from_tag:: swYh88AkicGbSHpK.D1z7uo3EX9Q-.AZ caller_contact:: sip:37984520-gch2kindtioq8@10.0.1.10:5060;transport=udp caller_cseq:: 24899 caller_route_set:: caller_bind_addr:: udp:10.0.1.10:5060 callee_bind_addr:: to_uri:: sip:+3360000011@staging.voip to_tag:: callee_contact:: callee_cseq:: callee_route_set:: # kamctl mi dlg_list dialog:: hash=2790:3231 state:: 3 ref_count:: 2 timestart:: 1384952191 timeout:: 20242152 callid:: GoXhk8GfkIEEqFyFNcySEjSOOpVKg4Uq from_uri:: sip:15909901@staging.voip from_tag:: swYh88AkicGbSHpK.D1z7uo3EX9Q-.AZ caller_contact:: sip:37984520-gch2kindtioq8@10.0.1.20:5060;transport=udp caller_cseq:: 24899 caller_route_set:: caller_bind_addr:: udp:10.0.1.10:5060 callee_bind_addr:: udp:10.0.1.10:5060 to_uri:: sip:+3360000011@staging.voip to_tag:: as6c8b935a callee_contact:: sip:+3360000022@10.0.1.11:5060 callee_cseq:: callee_route_set::

Hello Everyone,  Daniel,  This is directly related to the previous emails on this subject, sent by Guillaume. I am adresing here the exact same issue, we work together. The following piece of code is supposed to disconnect the previous call placed by a user: We save call-id,totag (if we have 180,183),fromtag,cseq of the INVITE of the previous dialog in memcache and we retrieve them for each call the user is placing.   if ($avp(saved_totag_of_previous_call)!=$null){                                                         # the above check should be equivalent with hastotag() on the other call .                                                         if(dlg_get("$avp(saved_previous_call_callid)", "$avp(saved_totag_of_previous_call)", "$avp(saved_fromtag_of_previous_call)"))                                                                                                          {                                                                         # sending BYEs to the previous dialog originated by this user                                                                          if (dlg_bye("all"))                                                                         {                                                                                 xlog("L_INFO","BYE sent to caller&callee");                                                                         } else {                                                                                 xlog("L_INFO","could not send locally generated BYEs\n");                                                                         }                                                                                                                                          dlg_get("$ci","$tt","$ft");                                                                                                                 # this BYE will be caught in event_route[tm:local-request] where we do some accounting                                                                                  } else {                                                         # # dialog should be in early state  - eg: 183 or 180 has been received                                                                  xlog("dlg_get() failed - because the dialog was not confirmed\n");                                                                 if (t_cancel_callid("$avp(saved_previous_call_callid)", "$avp(saved_previous_call_invite_cseq)", "22")) {                                                                           xlog("maxcall:transaction cancelled  - i am in call with call-id: $ci  \n");                                                                           # do stuff here                                                                  } else {                                                                           xlog("maxcall:cannot send forced cancel - the previous dialog had a totag - early state \n");                                                                             xlog("maxcall:i am in call with call-id: $ci \n");                                                                                                                          }                                                          # do stuff here                                                        } else {                                                                  # dialog should be in preceeding state - `100 Trying`  was received (`100 Trying` does not have a totag)                                                                  if (t_cancel_callid("$avp(saved_previous_call_callid)", "$avp(saved_previous_call_invite_cseq)", "22")) {                                                                        xlog("maxcall:transaction cancelled . i am in call with call-id: $ci \n");                                                                        # do stuff here                                                           } else {                                                                        xlog("maxcall:cannot send forced cancel - the previous dialog did not have a totag - preceeding state\n");                                                                            xlog("maxcall:I am in call with call-id: $ci \n");                                                                                          } } We see this in the logs, for two quick successive calls from the same UA (same user)  so we could reach the condition when t_cancel_callid() is called , with  $avp(saved_totag_of_previous_call) being null : So this is when the the user makes the second call:  0(21429) INFO: <script>: cancelling call 3e20b1db528ce041 (entry= 2776, id= 2165 ) 0(21429) DEBUG: tm [t_lookup.c:1742]: t_lookup_callid(): created comparable call_id header field: >Call-ID: 3e20b1db528ce0$ <  0(21429) DEBUG: tm [t_lookup.c:1746]: t_lookup_callid(): created comparable cseq header field: >CSeq: 20 INVITE<  0(21429) DEBUG: tm [t_lookup.c:1749]: t_lookup_callid(): just locked hash index 57175, looking for transactions there:  0(21429) DEBUG: tm [t_lookup.c:1762]: t_lookup_callid(): we have a match: callid=>>Call-ID: 3e20b1db528ce041 << cseq=>>CSeq: 20<<  0(21429) DEBUG: tm [t_lookup.c:1767]: t_lookup_callid(): DEBUG: t_lookup_callid: transaction found.  0(21429) DEBUG: tmx [tmx_mod.c:364]: t_cancel_callid(): Now calling cancel_uacs  0(21429) DEBUG: tm [t_cancel.c:329]: cancel_branch(): DEBUG: cancel_branch: sending cancel...  0(21429) ERROR: <script>: maxcall:transaction cancelled . i am in call with call-id: 2bf9efb7528ce04d  #  <- this is our custom logging  0(21429) ERROR: <script>: the other call (previous) had call-id:  3e20b1db528ce041  [...] then:  0(21429) DEBUG: dialog [dlg_hash.c:600]: dlg_lookup(): ref dlg 0x7f4179801d08 with 1 -> 2  0(21429) DEBUG: dialog [dlg_hash.c:602]: dlg_lookup(): dialog id=9721 found on entry 2505  0(21429) DEBUG: dialog [dlg_var.c:49]: dlg_cfg_cb(): new dialog with no trasaction after config execution  0(21429) DEBUG: dialog [dlg_hash.c:765]: dlg_unref(): unref dlg 0x7f4179801d08 with 1 -> 1  0(21429) DEBUG: dialog [dlg_hash.c:765]: dlg_unref(): unref dlg 0x7f4179801d08 with 1 -> 0  0(21429) DEBUG: dialog [dlg_hash.c:765]: dlg_unref(): ref <=0 for dialog 0x7f4179801d08  0(21429) DEBUG: dialog [dlg_hash.c:316]: destroy_dlg(): destroying dialog 0x7f4179801d08 (ref 0)  0(21429) DEBUG: dialog [dlg_hash.c:332]: destroy_dlg(): removed timer for dlg 0x7f4179801d08 [2505:9721] with clid '2bf9efb7528ce04d' and tags '76bc4edf528ce04d' '' What happens is that kamailio seems that it destroys the second dialog , instead of the first one. This leads to other inconsitency : DEBUG: dialog [dlg_hash.c:664]: internal_get_dlg(): no dialog callid='2bf9efb7528ce04d' found  # <- it cannot match the ACK for the second call. [...]  0(21429) WARNING: dialog [dlg_handlers.c:1127]: dlg_onroute(): unable to find dialog for BYE with route param '9c9.9f52' [2505:9721]   # <- it cannot match the BYE for the second call  0(21429) DEBUG: dialog [dlg_hash.c:664]: internal_get_dlg(): no dialog callid='2bf9efb7528ce04d' found  0(21429) DEBUG: dialog [dlg_hash.c:695]: get_dlg(): no dialog callid='2bf9efb7528ce04d' found  0(21429) DEBUG: dialog [dlg_handlers.c:1173]: dlg_onroute(): Callid '2bf9efb7528ce04d' not found [...]  1(21430) INFO: <script>: event_route[local-request]: call-id=3e20b1db528ce041 from=15909901 to=+33630815276 : local_route (method= BYE) :: dlg flag: 1 1(21430) DEBUG: pv [pv_trans.c:315]: tr_eval_string(): i=0 j=1  0(21429) WARNING: dialog [dlg_req_within.c:177]: bye_reply_cb(): inconsitent dlg timer data on dlg 0x7f41797e7048 [2776:2165] with clid '3e20b1db528ce041' and tags '522612bb528ce041' 'as1b2c7ace'  0(21429) DEBUG: dialog [dlg_hash.c:332]: destroy_dlg(): removed timer for dlg 0x7f41797e7048 [2776:2165] with clid '3e20b1db528ce041' and tags '522612bb528ce041' 'as1b2c7ace' It it also mixing the timeout of the first dialog with the one of the second. If we put a default timeout of 15 seconds for all calls  and we cancel the first call,kamailio will generate a BYEs in event_route[tm:local-request] after 15 seconds after the call other call was answered,  but with the call-id of the first call - it is mixing dialogs as we can see with kamctl. We suspect that t_cancel_callid() is not destroying the proper dialog at the right time.  We use dlg_manage() on every INVITE. It is the same behaviour with kamailio 4.0.2 and kamailio 4.0.3 . Any hints / ideas about this problem ? Is the problem in the dialog module, or t_cancel_callid() is doing something wrong ? Thank you. Regards, Dragos On Wednesday, November 20, 2013 10:57 PM, Daniel-Constantin Mierla &lt;miconda(a)gmail.com&gt; wrote: Hello, are you dropping replies? I don't see the 'SIP/2.0 487 Request Terminated' being sent to caller, it looks ok and has two Via headers. Cheers, Daniel On 11/20/13 4:06 PM, Guillaume Bour wrote: On 20/11/2013 12:01, Daniel-Constantin Mierla wrote: Hello, On 11/20/13 11:50 AM, Guillaume Bour wrote: Hi All We wan't to prevent our users to make more than one call at time, so we choose to disconnect the previous call. When the previous call is established, we use dlg_bye(), and its ok. But when it is in early state, we use t_cancel_callid() to cancel its INVITE transaction. We face 2 issues:     1) we use local-request event route to account calls on timeout. Sometimes this route is called for the cancelled call (after default timeout of 1 hour) what is in the local-request in this case? Is it a BYE?     2) t_cancel_callid() cancel previous call, but also make current dialog disappear: call is still ongoing and we can answer and talk to each other, but the dialog does not appear in 'kamctl stats dialog' and 'kamctl mi dlg_list' commands ? Can you send the log with debug=3 in kamailio.cfg? It will help to see what happens. Otherwise, if the call id is different for current dialog, it should not happen. The ngrep output in this situation (for both first and second invite) will help. Cheers, Daniel Hi Daniel, local-request is triggered by a BYE I have attached sample log and trace There is some kind of dialogs mixing. Here is the 1st call dialog as reported by "kamctl mi dlg_list" before and after the 2d call is answered: # kamctl mi dlg_list dialog::  hash=2790:3231         state:: 2         ref_count:: 1         timestart:: 0         timeout:: 0         callid:: GoXhk8GfkIEEqFyFNcySEjSOOpVKg4Uq         from_uri:: sip:15909901@staging.voip         from_tag:: swYh88AkicGbSHpK.D1z7uo3EX9Q-.AZ         caller_contact:: sip:37984520-gch2kindtioq8@10.0.1.10:5060;transport=udp         caller_cseq:: 24899         caller_route_set::         caller_bind_addr:: udp:10.0.1.10:5060         callee_bind_addr::         to_uri:: sip:+3360000011@staging.voip         to_tag::         callee_contact::         callee_cseq::         callee_route_set:: # kamctl mi dlg_list dialog::  hash=2790:3231         state:: 3         ref_count:: 2         timestart:: 1384952191         timeout:: 20242152         callid:: GoXhk8GfkIEEqFyFNcySEjSOOpVKg4Uq         from_uri:: sip:15909901@staging.voip         from_tag:: swYh88AkicGbSHpK.D1z7uo3EX9Q-.AZ         caller_contact:: sip:37984520-gch2kindtioq8@10.0.1.20:5060;transport=udp         caller_cseq:: 24899         caller_route_set::         caller_bind_addr:: udp:10.0.1.10:5060         callee_bind_addr:: udp:10.0.1.10:5060         to_uri:: sip:+3360000011@staging.voip         to_tag:: as6c8b935a         callee_contact:: sip:+3360000022@10.0.1.11:5060         callee_cseq::         callee_route_set:: _______________________________________________ SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list sr-users(a)lists.sip-router.org http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users -- Daniel-Constantin Mierla - http://www.asipto.com http://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda Kamailio Advanced Trainings - Berlin, Nov 25-28 - more details about Kamailio trainings at http://www.asipto.com - _______________________________________________ SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list sr-users(a)lists.sip-router.org http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users

Hello Guillaume, I pushed two commits on master branch: - http://git.sip-router.org/cgi-bin/gitweb.cgi/sip-router/?a=commit;h=777dd5e… - http://git.sip-router.org/cgi-bin/gitweb.cgi/sip-router/?a=commit;h=60372d6… The changes restore the previous values for T and T_branch, should be safer for the case when t_cancel_callid() is used in the context of another transaction. The patches are for master branch, but should apply easily to 4.0 branch. If you confirm they are working fine, then I will backport to git branch 4.0 as well. Cheers, Daniel On 11/21/13 5:19 PM, Guillaume Bour wrote: -- Daniel-Constantin Mierla - http://www.asipto.com http://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda

Hello Guillaume, thanks, I will backport. Is this solving the issue reported in this email thread, or the one related to the drop of another early dialog is still there? Cheers, Daniel On 11/25/13 4:47 PM, Guillaume Bour wrote: -- Daniel-Constantin Mierla - http://www.asipto.com http://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda

Hello Regarding the stuck dialog in state 5 , we had wait_ack = 1 ; we've put wait_ack = 0 , and the cancelled dialog does not show in the output of `kamctl mi dlg_list` anymore. Regards, Dragos On Tuesday, November 26, 2013 9:32 AM, Guillaume Bour &lt;libon.voiceteam(a)gmail.com&gt; wrote: On 25/11/2013 21:35, Daniel-Constantin Mierla wrote: Hello Guillaume, thanks, I will backport. Is this solving the issue reported in this email thread, or the one related to the drop of another early dialog is still there? Hi, Yes, the correct early dialog is cancelled, and the local-request event route is not executed anymore for this dialog. But it remains indefinitly listed in output of command "kamctl mi dlg_list", so I suppose the dialog is not really destroyed $> /opt/kamailio/sbin/kamctl mi dlg_list dialog::  hash=1149:11437         state:: 5         ref_count:: 1         timestart:: 0         timeout:: 0         callid:: q69aDDCPso8rh-0NqPxv39VCt8XPgwrN         from_uri:: sip:15909901@staging.voip         from_tag:: V7wg6INO0Sp3o0Od1AIzPyUXbUuRLOFy         caller_contact:: sip:62389754-sbcqi87bli6bc@10.0.1.106:5060;transport=udp         caller_cseq:: 16068         caller_route_set::         caller_bind_addr:: udp:10.0.1.10:5060         callee_bind_addr::         to_uri:: sip:+33600000011@staging.voip         to_tag::         callee_contact::         callee_cseq::         callee_route_set:: Regards, Guillaume On 24/11/2013 16:35, Daniel-Constantin Mierla wrote: Hello Guillaume, I pushed two commits on master branch: - http://git.sip-router.org/cgi-bin/gitweb.cgi/sip-router/?a=commit;h=777dd5e… - http://git.sip-router.org/cgi-bin/gitweb.cgi/sip-router/?a=commit;h=60372d6… The changes restore the previous values for T and T_branch, should be safer for the case when t_cancel_callid() is used in the context of another transaction. The patches are for master branch, but should apply easily to 4.0 branch. If you confirm they are working fine, then I will backport to git branch 4.0 as well. Hi Daniel, I have tested it on 4.0 branch, and its working fine Regards, Guillaume Cheers, Hi Daniel No, replies are not dropped. I looked into source code, particularly tmx_mod.c::t_cancel_callid() function. It alter the global pointer T (pointing to the transaction currently processed), but do not restore original value at the end:   - at the beginning of t_cancel_callid(), T is NULL   - then t_lookup_callid() make it point to the transaction we want to cancel   - and the pointer is not cleanup before exiting t_cancel_callid Here is a patch that fix this issue (it may not be the correct way to do it) Regards, Guillaume On 20/11/2013 22:57, Daniel-Constantin Mierla wrote: Hello, are you dropping replies? I don't see the 'SIP/2.0 487 Request Terminated' being sent to caller, it looks ok and has two Via headers. Cheers, Daniel On 11/20/13 4:06 PM, Guillaume Bour wrote: On 20/11/2013 12:01, Daniel-Constantin Mierla wrote: Hello, On 11/20/13 11:50 AM, Guillaume Bour wrote: Hi All We wan't to prevent our users to make more than one call at time, so we choose to disconnect the previous call. When the previous call is established, we use dlg_bye(), and its ok. But when it is in early state, we use t_cancel_callid() to cancel its INVITE transaction. We face 2 issues:     1) we use local-request event route to account calls on timeout. Sometimes this route is called for the cancelled call (after default timeout of 1 hour) what is in the local-request in this case? Is it a BYE?     2) t_cancel_callid() cancel previous call, but also make current dialog disappear: call is still ongoing and we can answer and talk to each other, but the dialog does not appear in 'kamctl stats dialog' and 'kamctl mi dlg_list' commands t_cancel_callid() ? Can you send the log with debug=3 in kamailio.cfg? It will help to see what happens. Otherwise, if the call id is different for current dialog, it should not happen. The ngrep output in this situation (for both first and second invite) will help. Cheers, Daniel Hi Daniel, local-request is triggered by a BYE I have attached sample log and trace There is some kind of dialogs mixing. Here is the 1st call dialog as reported by "kamctl mi dlg_list" before and after the 2d call is answered: # kamctl mi dlg_list dialog::  hash=2790:3231         state:: 2         ref_count:: 1         timestart:: 0         timeout:: 0         callid:: GoXhk8GfkIEEqFyFNcySEjSOOpVKg4Uq         from_uri:: sip:15909901@staging.voip         from_tag:: swYh88AkicGbSHpK.D1z7uo3EX9Q-.AZ         caller_contact:: sip:37984520-gch2kindtioq8@10.0.1.10:5060;transport=udp         caller_cseq:: 24899         caller_route_set::         caller_bind_addr:: udp:10.0.1.10:5060         callee_bind_addr::         to_uri:: sip:+3360000011@staging.voip         to_tag::         callee_contact::         callee_cseq::         callee_route_set:: # kamctl mi dlg_list dialog::  hash=2790:3231         state:: 3         ref_count:: 2         timestart:: 1384952191         timeout:: 20242152         callid:: GoXhk8GfkIEEqFyFNcySEjSOOpVKg4Uq         from_uri:: sip:15909901@staging.voip         from_tag:: swYh88AkicGbSHpK.D1z7uo3EX9Q-.AZ         caller_contact:: sip:37984520-gch2kindtioq8@10.0.1.20:5060;transport=udp         caller_cseq:: 24899         caller_route_set::         caller_bind_addr:: udp:10.0.1.10:5060         callee_bind_addr:: udp:10.0.1.10:5060         to_uri:: sip:+3360000011@staging.voip         to_tag:: as6c8b935a         callee_contact:: sip:+3360000022@10.0.1.11:5060         callee_cseq::         callee_route_set:: _______________________________________________ SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list sr-users(a)lists.sip-router.org http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users -- Daniel-Constantin Mierla - http://www.asipto.com http://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda Kamailio Advanced Trainings - Berlin, Nov 25-28 - more details about Kamailio trainings at http://www.asipto.com - _______________________________________________ SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list sr-users(a)lists.sip-router.org http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users _______________________________________________ SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list sr-users(a)lists.sip-router.org http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users -- Daniel-Constantin Mierla - http://www.asipto.com http://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda _______________________________________________ SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list sr-users(a)lists.sip-router.org http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users _______________________________________________ SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list sr-users(a)lists.sip-router.org http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users -- Daniel-Constantin Mierla - http://www.asipto.com http://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda _______________________________________________ SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list sr-users(a)lists.sip-router.org http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users _______________________________________________ SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list sr-users(a)lists.sip-router.org http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users