Re: [SR-Users] Dialog - timeout for dlg with CallID

Hello, OK, so I've added it as a first function in the request_route. I will keep you updated. Thanks On Wed, 12 Aug 2020 at 11:20, Daniel-Constantin Mierla &lt;miconda(a)gmail.com&gt; wrote: > Hello, > > try with dlg_manage() before any of the dialog functions/vars -- I > noticed a condition for skipping double processing, which could be a result > of such case (I haven't dug further in the code yet). > > Cheers, > Daniel > On 12.08.20 12:06, Ilie Soltanici wrote: > > Hello, > > Yes, ACK have the To-tag: > > *To: <sip:+1234567890@192.168.89.110 > &lt;sip%3A%2B1234567890(a)192.168.89.110&gt;&gt;;tag=05e27170-ffe5-4e90-b785-9a2fffa0194d* > > Yes, I'm using dlg_va() function before calling dlg_manage() function. > Could that be the reason? What is strange is that this is happening > randomly (20-30 calls per day) with some of the calls only, and cannot be > replicated. > Thanks > > On Wed, 12 Aug 2020 at 10:54, Daniel-Constantin Mierla &lt;miconda(a)gmail.com&gt; > wrote: > >> Do you have the pcap with the traffic of this call? Does the ACK has the >> To-tag? Do you access dialog in any other way before calling dlg_manage() >> (e.g., by $dlg_var() or other function from dialog module)? >> >> Cheers, >> Daniel >> On 12.08.20 11:48, Ilie Soltanici wrote: >> >> Unfortunately that's everything I can see for this call, maybe the >> systemd daemon didn't log all the messages. It's strange as I have all >> ratelimit's disabled. >> I will try get another call log, hope that I would be able to get more >> information there. >> >> Thanks >> >> On Wed, 12 Aug 2020 at 10:24, Daniel-Constantin Mierla < >> miconda(a)gmail.com&gt; wrote: >> >>> Hello, >>> >>> are these all debug messages printed for ACK processing? >>> >>> There should be a log message like: >>> >>> ... changed from state X to state Y ... >>> >>> Cheers, >>> Daniel >>> On 12.08.20 10:56, Ilie Soltanici wrote: >>> >>> Hello, >>> >>> After a couple of days trying to run kamailio in debug mode 3 finally I >>> was able to catch one call with this issue. Please see below the Debug Log >>> for the ACK: >>> >>> Aug 12 08:37:38 kamailio.localhost kamailio[28296]: DEBUG: {INVITE (2) >>> | Seq=103 | Source IP=192.168.89.110 (udp) | Call ID= >>> 5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060} <core> >>> [db_query.c:72]: db_do_submit_query(): submitted query: insert into >>> `dialog_vars` (`hash_entry`,`hash_id`,`dialog_key`,`dialog_value` ) values >>> (273,1534,'start_time','1597217857.509'), result 0 >>> Aug 12 08:37:38 kamailio.localhost kamailio[28296]: DEBUG: {INVITE (2) >>> | Seq=103 | Source IP=192.168.89.110 (udp) | Call ID= >>> 5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060} dialog >>> [dlg_db_handler.c:834]: update_dialog_dbinfo_unsafe(): updated 13 vars for >>> dlg [273:1534] >>> Aug 12 08:37:38 kamailio.localhost kamailio[28296]: DEBUG: {INVITE (2) >>> | Seq=103 | Source IP=192.168.89.110 (udp) | Call ID= >>> 5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060} db_cluster >>> [dbcl_api.c:483]: db_cluster_use_table(): use table (dialog) - cluster >>> [kamailio] >>> Aug 12 08:37:38 kamailio.localhost kamailio[28296]: DEBUG: {INVITE (2) >>> | Seq=103 | Source IP=192.168.89.110 (udp) | Call ID= >>> 5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060} <core> >>> [db_query.c:72]: db_do_submit_query(): submitted query: insert into >>> `dialog` >>> (`hash_entry`,`hash_id`,`callid`,`from_uri`,`from_tag`,`to_uri`,`to_tag`,`caller_sock`,`callee_sock`,`start_time`,`state`,`timeout`,`caller_cseq`,`callee_cseq`,`caller_contact`,`callee_contact`,`caller_route_set`,`callee_route_set`,`sflags`,`toroute_name`,`req_uri`,`xdata`,`iflags` >>> ) values (273,1534,' >>> 5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060',' >>> sip:+987654321@192.168.50.139','as5a6d564e',' >>> sip:+1234567890@192.168.89.110 >>> ','05e27170-ffe5-4e90-b785-9a2fffa0194d','udp:192.168.50.12:5060','udp: >>> 192.168.180.16:5060',1597217858,3,1538026468,'103','0',' >>> sip:+987654321@192.168.50.139:5060','sip:192.168.82.230:5060',NULL,' >>> <sip:192.168.82.250:5060;lr>',0,NULL,'sip:+1234567890@192.168.89.110',NULL,0), >>> result 0 >>> Aug 12 08:37:38 kamailio.localhost kamailio[28296]: DEBUG: {INVITE (2) >>> | Seq=103 | Source IP=192.168.89.110 (udp) | Call ID= >>> 5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060} dialog >>> [dlg_timer.c:110]: insert_dialog_timer_unsafe(): inserting 0x7f769a594418 >>> for 59202190 >>> Aug 12 08:37:38 kamailio.localhost kamailio[28296]: DEBUG: {INVITE (2) >>> | Seq=103 | Source IP=192.168.89.110 (udp) | Call ID= >>> 5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060} dialog >>> [dlg_hash.c:1045]: dlg_ref_helper(): ref op on 0x7f769a5943b8 with 1 from >>> dlg_handlers.c:557 >>> Aug 12 08:37:38 kamailio.localhost kamailio[28296]: DEBUG: {INVITE (2) >>> | Seq=103 | Source IP=192.168.89.110 (udp) | Call ID= >>> 5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060} dialog >>> [dlg_hash.c:1049]: dlg_ref_helper(): ref dlg 0x7f769a5943b8 with 1 -> 3 >>> Aug 12 08:37:38 kamailio.localhost kamailio[28296]: DEBUG: {INVITE (2) >>> | Seq=103 | Source IP=192.168.89.110 (udp) | Call ID= >>> 5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060} dialog >>> [dlg_hash.c:1065]: dlg_unref_helper(): unref op on 0x7f769a5943b8 with 1 >>> from dlg_hash.c:1083 >>> Aug 12 08:37:38 kamailio.localhost kamailio[28296]: DEBUG: {INVITE (2) >>> | Seq=103 | Source IP=192.168.89.110 (udp) | Call ID= >>> 5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060} <core> >>> [core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <103> <INVITE> >>> Aug 12 08:37:38 kamailio.localhost kamailio[28307]: DEBUG: {ACK (1) | >>> Seq=103 | Source IP=192.168.50.139 (udp) | Call ID= >>> 5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060} sl >>> [sl_funcs.c:421]: sl_filter_ACK(): too late to be a local ACK! >>> Aug 12 08:37:38 kamailio.localhost kamailio[28307]: DEBUG: {ACK (1) | >>> Seq=103 | Source IP=192.168.50.139 (udp) | Call ID= >>> 5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060} dialog >>> [dlg_var.c:276]: print_lists(): ua=AGENT (flags 1) >>> Aug 12 08:37:38 kamailio.localhost kamailio[28307]: DEBUG: {ACK (1) | >>> Seq=103 | Source IP=192.168.50.139 (udp) | Call ID= >>> 5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060} dialog >>> [dlg_var.c:276]: print_lists(): ua=AGENT (flags 1) >>> Aug 12 08:37:38 kamailio.localhost kamailio[28307]: DEBUG: {ACK (1) | >>> Seq=103 | Source IP=192.168.50.139 (udp) | Call ID= >>> 5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060} dialog >>> [dlg_var.c:276]: print_lists(): dest_ip=192.168.89.110 (flags 1) >>> Aug 12 08:37:38 kamailio.localhost kamailio[28307]: DEBUG: {ACK (1) | >>> Seq=103 | Source IP=192.168.50.139 (udp) | Call ID= >>> 5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060} dialog >>> [dlg_var.c:276]: print_lists(): dest_ip=192.168.89.110 (flags 1) >>> Aug 12 08:37:38 kamailio.localhost kamailio[28307]: DEBUG: {ACK (1) | >>> Seq=103 | Source IP=192.168.50.139 (udp) | Call ID= >>> 5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060} rr [loose.c:90]: >>> is_preloaded(): is_preloaded: No >>> Aug 12 08:37:38 kamailio.localhost kamailio[28307]: DEBUG: {ACK (1) | >>> Seq=103 | Source IP=192.168.50.139 (udp) | Call ID= >>> 5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060} dialog >>> [dlg_hash.c:1065]: dlg_unref_helper(): unref op on 0x7f769a5c8b48 with 1 >>> from dlg_hash.c:1083 >>> Aug 12 08:37:38 kamailio.localhost kamailio[28307]: DEBUG: {ACK (1) | >>> Seq=103 | Source IP=192.168.50.139 (udp) | Call ID= >>> 5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060} dialog >>> [dlg_var.c:276]: print_lists(): log=1 (flags 3) >>> Aug 12 08:37:38 kamailio.localhost kamailio[28307]: DEBUG: {ACK (1) | >>> Seq=103 | Source IP=192.168.50.139 (udp) | Call ID= >>> 5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060} dialog >>> [dlg_var.c:276]: print_lists(): called_number=0123456789 (flags 1) >>> Aug 12 08:37:38 kamailio.localhost kamailio[28307]: DEBUG: {ACK (1) | >>> Seq=103 | Source IP=192.168.50.139 (udp) | Call ID= >>> 5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060} tm >>> [t_lookup.c:1330]: t_newtran(): msg (0x7f76bf204b68) id=5441/28307 global >>> id=5440/28307 T start=(nil) >>> Aug 12 08:37:38 kamailio.localhost kamailio[28307]: DEBUG: {ACK (1) | >>> Seq=103 | Source IP=192.168.50.139 (udp) | Call ID= >>> 5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060} <core> >>> [db_query.c:72]: db_do_submit_query(): submitted query: insert into `acc` >>> (`method`,`from_tag`,`to_tag`,`callid`,`sip_code`,`sip_reason`,`time`,`time_attr`,`time_exten`,`src_user`,`src_domain`,`src_ip`,`dst_ouser`,`dst_user`,`dst_domain`,`cseq` >>> ) values ('ACK','as5a6d564e','05e27170-ffe5-4e90-b785-9a2fffa0194d',' >>> 5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060','200','OK','2020-08-12 >>> 08:37:38',1597217858,642167,'+987654321','192.168.50.139','192.168.50.139','+0123456789','','192.168.82.230','103'), >>> result 0 >>> Aug 12 08:37:38 kamailio.localhost kamailio[28307]: DEBUG: {ACK (1) | >>> Seq=103 | Source IP=192.168.50.139 (udp) | Call ID= >>> 5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060} acc >>> [acc_extra.h:64]: free_strar_mem(): Freeing memory, type is 2, >>> message_index 9, index i 0 >>> Aug 12 08:37:38 kamailio.localhost kamailio[28307]: DEBUG: {ACK (1) | >>> Seq=103 | Source IP=192.168.50.139 (udp) | Call ID= >>> 5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060} acc >>> [acc_extra.h:64]: free_strar_mem(): Freeing memory, type is 2, >>> message_index 9, index i 1 >>> Aug 12 08:37:38 kamailio.localhost kamailio[28307]: DEBUG: {ACK (1) | >>> Seq=103 | Source IP=192.168.50.139 (udp) | Call ID= >>> 5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060} acc >>> [acc_extra.h:64]: free_strar_mem(): Freeing memory, type is 2, >>> message_index 9, index i 2 >>> Aug 12 08:37:38 kamailio.localhost kamailio[28307]: DEBUG: {ACK (1) | >>> Seq=103 | Source IP=192.168.50.139 (udp) | Call ID= >>> 5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060} <core> >>> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: >>> tag=05e27170-ffe5-4e90-b785-9a2fffa0194d >>> Aug 12 08:37:42 kamailio.localhost kamailio[28324]: DEBUG: dialog >>> [dlg_hash.c:361]: destroy_dlg(): removed timer for dlg 0x7f769a5c8b48 >>> [273:1533] with clid ' >>> 5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060' and tags >>> 'as5a6d564e' '' >>> Aug 12 08:37:42 kamailio.localhost kamailio[28324]: DEBUG: dialog >>> [dlg_db_handler.c:710]: remove_dialog_from_db(): trying to remove dialog [ >>> 5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060], update_flag is >>> 640 >>> Aug 12 08:37:42 kamailio.localhost kamailio[28324]: DEBUG: dialog >>> [dlg_db_handler.c:736]: remove_dialog_from_db(): callid was >>> 5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060 >>> Aug 12 08:40:08 kamailio.localhost kamailio[28323]: WARNING: dialog >>> [dlg_handlers.c:1652]: dlg_ontimeout(): dlg timeout - callid: ' >>> 5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060' tags: >>> 'as5a6d564e' '05e27170-ffe5-4e90-b785-9a2fffa0194d' ostate: 3 >>> Aug 12 08:40:08 kamailio.localhost kamailio[28323]: DEBUG: <core> >>> [db_query.c:72]: db_do_submit_query(): submitted query: insert into >>> `acc_cdrs` >>> (`start_time`,`end_time`,`duration`,`account_id`,`aleg_uuid`,`bleg_uuid`,`caller_number`,`called_number`,`sip_code`,`sip_reason`,`sip_user_agent`,`kamailio_server`,`billsec`,`src_ip`,`dest_ip`,`direction` >>> ) values ('2020-08-12 08:37:37','2020-08-12 08:37:37',0.000000 ,'101',' >>> 5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060',' >>> 29176259973485-74271626511770@192.168.1.228','987654321','0123456789',NULL,NULL,'AGENT','SRV',NULL,'192.168.50.139','192.168.89.110','OUTBOUND'), >>> result 0 >>> Aug 12 08:40:08 kamailio.localhost kamailio[28323]: DEBUG: dialog >>> [dlg_hash.c:361]: destroy_dlg(): removed timer for dlg 0x7f769a5943b8 >>> [273:1534] with clid ' >>> 5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060' and tags >>> 'as5a6d564e' '05e27170-ffe5-4e90-b785-9a2fffa0194d' >>> Aug 12 08:40:08 kamailio.localhost kamailio[28323]: DEBUG: dialog >>> [dlg_db_handler.c:710]: remove_dialog_from_db(): trying to remove dialog [ >>> 5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060], update_flag is >>> 1542 >>> Aug 12 08:40:08 kamailio.localhost kamailio[28323]: DEBUG: dialog >>> [dlg_db_handler.c:736]: remove_dialog_from_db(): callid was >>> 5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060 >>> >>> >>> What I noticed strange here, is that SL module reporting: >>> >>> * sl_filter_ACK(): too late to be a local ACK! * >>> >>> I'm not sure that this is the core of the problem, but maybe you can >>> spot something here. >>> >>> This is sl_module configuration, in case if you'll need it: >>> # ---- sl params ---- >>> modparam("sl", "default_code", 505) >>> modparam("sl", "default_reason", "Server Error") >>> >>> Thanks. >>> >>> On Thu, 30 Jul 2020 at 07:22, Daniel-Constantin Mierla < >>> miconda(a)gmail.com&gt; wrote: >>> >>>> Hello, >>>> >>>> run with debug=3 in kamailio.cfg and send here all the log messages >>>> printed by kamailio when processing the ACK. >>>> >>>> Cheers, >>>> Daniel >>>> On 29.07.20 18:48, Ilie Soltanici wrote: >>>> >>>> Hello, >>>> >>>> I changed the configuration file to call dlg_manage() for all methods: >>>> >>>> if (loose_route()) { >>>> dlg_manage(); >>>> >>>> if (is_method("BYE")) { >>>> setflag(FLAG_ACC); >>>> setflag(FLAG_ACCMISSED); >>>> $dlg_var(billsec) = $DLG_lifetime; >>>> } >>>> >>>> route(RELAY); >>>> exit; >>>> }; >>>> >>>> but, unfortunately this is not helping either. I'm not sure that there >>>> is a buggy UA messing RR because this is happening with 4 Providers >>>> randomly. >>>> What else I noticed is that this is happening mostly with ISP's using >>>> authorization, with other ISPs using IP as whitelisted source I didn't >>>> notice anything like that. >>>> Could this be related somehow? >>>> Thanks. >>>> >>>> >>>> On Wed, 29 Jul 2020 at 17:19, Sergiu Pojoga &lt;pojogas(a)gmail.com&gt; wrote: >>>> >>>>> Correct me if I'm wrong, but not all within-dialogs are 'calls', for >>>>> e.g. NOTIFY with a preset Route after SUBSCRIBE, wondering how dlg_manage() >>>>> would treat those, would it count them as 'calls'? >>>>> >>>>> Not to mention that docs mention "dlg_manage() - this makes sense >>>>> only for initial requests) >>>>> >>>>> On Wed, Jul 29, 2020 at 10:55 AM M S &lt;shaheryarkh(a)gmail.com&gt; wrote: >>>>> >>>>>> Please put dlg_manage immediately after loose_route condition, e.g. >>>>>> >>>>>> if (loose_route) { >>>>>> dlg_manage(); >>>>>> ... >>>>>> } >>>>>> >>>>>> There is no harm in calling it for every SIP method (not just BYE or >>>>>> ACK) within dialog. It will help for re-invites (call hold / unhold events) >>>>>> etc. from same buggy UAs as well. >>>>>> >>>>>> Thank you. >>>>>> >>>>>> >>>>>> On Wed, Jul 29, 2020 at 3:21 PM Ilie Soltanici &lt;iliusha.md(a)gmail.com&gt; >>>>>> wrote: >>>>>> >>>>>>> Hello, >>>>>>> >>>>>>> I've tried what you recommended, but without success so far. >>>>>>> >>>>>>> This is the configuration block: >>>>>>> >>>>>>> if (!has_totag()) return; >>>>>>> >>>>>>> if (is_method("ACK")) { >>>>>>> dlg_manage(); >>>>>>> } >>>>>>> >>>>>>> if (loose_route()) { >>>>>>> if (is_method("BYE")) { >>>>>>> dlg_manage(); >>>>>>> setflag(FLAG_ACC); >>>>>>> setflag(FLAG_ACCMISSED); >>>>>>> $dlg_var(billsec) = $DLG_lifetime; >>>>>>> } >>>>>>> route(RELAY); >>>>>>> exit; >>>>>>> }; >>>>>>> >>>>>>> if (is_method("ACK") ) { >>>>>>> if ( t_check_trans() ) { >>>>>>> route(RELAY); >>>>>>> exit; >>>>>>> } else { >>>>>>> sl_send_reply("606", "Not Acceptable"); >>>>>>> exit; >>>>>>> } >>>>>>> } >>>>>>> >>>>>>> Here is the sip trace: >>>>>>> https://pastebin.com/Aen2GCjm >>>>>>> >>>>>>> And that's the error I'm getting in the Kamailio log file: >>>>>>> >>>>>>> WARNING: dialog [dlg_handlers.c:1652]: dlg_ontimeout(): dlg timeout >>>>>>> - callid: ' 0555141d7d3hsag78sgce830391f9348@10.1.50.240:5060' >>>>>>> tags: 'as52c10007' 'Uv7HS0jX65ctF' ostate: 3 >>>>>>> >>>>>>> Any other ideas? >>>>>>> >>>>>>> On Tue, 28 Jul 2020 at 15:44, Daniel-Constantin Mierla < >>>>>>> miconda(a)gmail.com&gt; wrote: >>>>>>> >>>>>>>> Hello, >>>>>>>> >>>>>>>> I see the in-dialog ACK in the trace, try with dlg_manage() >>>>>>>> explicitly used for it. >>>>>>>> >>>>>>>> The warning messages are not when processing the ack, but on >>>>>>>> dialog timeout, if you do not get some other errors like 90-120 seconds >>>>>>>> before, when the ack was routed, then it was no processing error for it. >>>>>>>> >>>>>>>> Cheers, >>>>>>>> Daniel >>>>>>>> On 28.07.20 12:31, Ilie Soltanici wrote: >>>>>>>> >>>>>>>> Hello, >>>>>>>> >>>>>>>> In the Kamailio logs I can see only those errors: >>>>>>>> >>>>>>>> WARNING: dialog [dlg_handlers.c:1652]: dlg_ontimeout(): dlg >>>>>>>> timeout - callid: '45b0130e14a692b95134696d2fc5f2a9' tags: 'as31fb1118' >>>>>>>> '12UDcK9S8630r' ostate: 3 >>>>>>>> WARNING: acc [acc_cdr.c:230]: db_write_cdr(): fallback to dlg_only >>>>>>>> search because of message doesn't exist >>>>>>>> >>>>>>>> Here you can see the full sip trace: >>>>>>>> https://pastebin.com/Q4eqcGJj >>>>>>>> >>>>>>>> The First Invite it's from the Asterisk server (192.168.0.140), >>>>>>>> and the second one - it's from Kamailio (192.168.1.16), >>>>>>>> 192.168.2.0/24 - it's an ISP. What 's strange for me here is that >>>>>>>> Kamailio it's still adding rr_param to the RR Header even if it's disabled >>>>>>>> in the module configuration, why would that be? >>>>>>>> >>>>>>>> This is the module configuration: >>>>>>>> modparam("dialog", "enable_stats", 1) >>>>>>>> modparam("dialog", "rr_param", "did") >>>>>>>> modparam("dialog", "dlg_match_mode", 2) >>>>>>>> modparam("dialog", "default_timeout", 10800) >>>>>>>> modparam("dialog", "early_timeout", 180) >>>>>>>> modparam("dialog", "noack_timeout", 90) >>>>>>>> modparam("dialog", "track_cseq_updates", 1) >>>>>>>> modparam("dialog", "dlg_extra_hdrs", "Hint: Inactivity Timeout\r\n >>>>>>>> ") >>>>>>>> modparam("dialog", "detect_spirals", 1) >>>>>>>> modparam("dialog", "db_mode", 1) >>>>>>>> >>>>>>>> I will try to run dlg_manage for ACK within the dialog and see if >>>>>>>> it works. >>>>>>>> Thank you. >>>>>>>> >>>>>>>> >>>>>>>> On Tue, 28 Jul 2020 at 09:26, Daniel-Constantin Mierla < >>>>>>>> miconda(a)gmail.com&gt; wrote: >>>>>>>> >>>>>>>>> Hello, >>>>>>>>> >>>>>>>>> that confirms my guessing -- the ack was not handled in the >>>>>>>>> dialog context, the state 3 is defined inside dlg_hash.h by: >>>>>>>>> >>>>>>>>> #define DLG_STATE_CONFIRMED_NA 3 /*!< confirmed dialog without a >>>>>>>>> ACK yet */ >>>>>>>>> >>>>>>>>> Do you see any error messages in the logs when handling the ACK >>>>>>>>> in the config? Did you grab the pcap with sip traffic for such a call? >>>>>>>>> >>>>>>>>> Try also to explicitly execute dlg_manage() for ACK within dialog. >>>>>>>>> >>>>>>>>> Cheers, >>>>>>>>> Daniel >>>>>>>>> On 28.07.20 10:05, Ilie Soltanici wrote: >>>>>>>>> >>>>>>>>> Hello, >>>>>>>>> >>>>>>>>> I re-compiled Kamailio from the Master branch and I'm getting the >>>>>>>>> old state: 3 >>>>>>>>> >>>>>>>>> *dlg_ontimeout(): dlg timeout - callid: >>>>>>>>> '225ce4fc79d78c0f5477d02d02f3feea' tags: 'as3f0a58cf' >>>>>>>>> 'a9eb002d-c544-47f7-84ec-1c4e690cd0b4' ostate: 3* >>>>>>>>> >>>>>>>>> [ilie.soltanici@dev ~]$ /usr/local/sbin/kamailio -V >>>>>>>>> version: kamailio 5.3.5 (x86_64/linux) ff2f8c >>>>>>>>> >>>>>>>>> Thanks >>>>>>>>> >>>>>>>>> On Mon, 27 Jul 2020 at 08:56, Daniel-Constantin Mierla < >>>>>>>>> miconda(a)gmail.com&gt; wrote: >>>>>>>>> >>>>>>>>>> Hello, >>>>>>>>>> >>>>>>>>>> this sounds like the ACK is not matched for dialog processing >>>>>>>>>> and the early_timeout is firing. I just pushed a commit to dialog module to >>>>>>>>>> print the old state when the timeout callback function is executed, maybe >>>>>>>>>> you can test with it -- it is in branch 5.3: >>>>>>>>>> >>>>>>>>>> - >>>>>>>>>> https://github.com/kamailio/kamailio/commit/ff2f8c4e63b4fefa7dc5b10835505c3… >>>>>>>>>> >>>>>>>>>> Otherwise, maybe call dlg_manage() for ACK, although the >>>>>>>>>> loose_route() callback should be executed and ACK handled for dialog >>>>>>>>>> processing. >>>>>>>>>> >>>>>>>>>> Cheers, >>>>>>>>>> Daniel >>>>>>>>>> On 24.07.20 12:46, Ilie Soltanici wrote: >>>>>>>>>> >>>>>>>>>> Hello, >>>>>>>>>> >>>>>>>>>> I'm trying to get CDR working in Kamailio by using the acc and >>>>>>>>>> dialog modules. Everything seemed to be working fine - until i noticed that >>>>>>>>>> for some of the calls the call duration is 0, even if that call has been >>>>>>>>>> successfully established and duration was for about a few minutes. In the >>>>>>>>>> Kamailio logs I'm getting such errors: >>>>>>>>>> >>>>>>>>>> WARNING: dialog [dlg_handlers.c:1649]: dlg_ontimeout(): timeout >>>>>>>>>> for dlg with CallID '304bad142b50bb3a7a117816439ea3d5' and tags >>>>>>>>>> 'as3adde5c7' '7d28152f-e0e3-4bcf-9d5c-21c3723b95c5' >>>>>>>>>> WARNING: acc [acc_cdr.c:230]: db_write_cdr(): fallback to >>>>>>>>>> dlg_only search because of message doesn't exist. >>>>>>>>>> >>>>>>>>>> This error I'm getting at about 2 min after the ACK message for >>>>>>>>>> 200 OK. I'm not sure that this is related to the dialog timeout, but below >>>>>>>>>> you can see the related configuration for the dialog module: >>>>>>>>>> >>>>>>>>>> modparam("dialog", "default_timeout", 10800) # 3 hours >>>>>>>>>> modparam("dialog", "early_timeout", 180) >>>>>>>>>> modparam("dialog", "noack_timeout", 90) >>>>>>>>>> >>>>>>>>>> Unfortunately, I'm not able to reproduce this issue, as that's >>>>>>>>>> happening randomly and just a few times per day. On the SIP Level i didn't >>>>>>>>>> notice any strange issues. >>>>>>>>>> >>>>>>>>>> Any ideas why is that happening? >>>>>>>>>> Thank you. >>>>>>>>>> >>>>>>>>>> _______________________________________________ >>>>>>>>>> Kamailio (SER) - Users Mailing Listsr-users@lists.kamailio.orghttps://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users >>>>>>>>>> >>>>>>>>>> -- >>>>>>>>>> Daniel-Constantin Mierla -- www.asipto.comwww.twitter.com/miconda -- www.linkedin.com/in/miconda >>>>>>>>>> Funding: https://www.paypal.me/dcmierla >>>>>>>>>> >>>>>>>>>> -- >>>>>>>>> Daniel-Constantin Mierla -- www.asipto.comwww.twitter.com/miconda -- www.linkedin.com/in/miconda >>>>>>>>> Funding: https://www.paypal.me/dcmierla >>>>>>>>> >>>>>>>>> -- >>>>>>>> Daniel-Constantin Mierla -- www.asipto.comwww.twitter.com/miconda -- www.linkedin.com/in/miconda >>>>>>>> Funding: https://www.paypal.me/dcmierla >>>>>>>> >>>>>>>> _______________________________________________ >>>>>>> Kamailio (SER) - Users Mailing List >>>>>>> sr-users(a)lists.kamailio.org >>>>>>> https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users >>>>>>> >>>>>> _______________________________________________ >>>>>> Kamailio (SER) - Users Mailing List >>>>>> sr-users(a)lists.kamailio.org >>>>>> https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users >>>>>> >>>>> _______________________________________________ >>>>> Kamailio (SER) - Users Mailing List >>>>> sr-users(a)lists.kamailio.org >>>>> https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users >>>>> >>>> >>>> _______________________________________________ >>>> Kamailio (SER) - Users Mailing Listsr-users@lists.kamailio.orghttps://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users >>>> >>>> -- >>>> Daniel-Constantin Mierla -- www.asipto.comwww.twitter.com/miconda -- www.linkedin.com/in/miconda >>>> Funding: https://www.paypal.me/dcmierla >>>> >>>> -- >>> Daniel-Constantin Mierla -- www.asipto.comwww.twitter.com/miconda -- www.linkedin.com/in/miconda >>> Funding: https://www.paypal.me/dcmierla >>> >>> -- >> Daniel-Constantin Mierla -- www.asipto.comwww.twitter.com/miconda -- www.linkedin.com/in/miconda >> Funding: https://www.paypal.me/dcmierla >> >> -- > Daniel-Constantin Mierla -- www.asipto.comwww.twitter.com/miconda -- www.linkedin.com/in/miconda > Funding: https://www.paypal.me/dcmierla > >