Hello,
somehow this discussion got out of my sight, good that you revive it. I wanted to explore more the conditions that lead to have the function for states update not executed ... I see you created a pull request, we can track the evolution there or better just create an issue for it not to forget again.
Cheers, Daniel
On 23.09.20 19:59, Julien Chavanton wrote:
I created a special branch in case someone wants to propose more debuggability modifications
https://github.com/kamailio/kamailio/pull/2483 https://github.com/kamailio/kamailio/pull/2483
On Wed, Sep 23, 2020 at 10:33 AM Julien Chavanton <jchavanton@gmail.com mailto:jchavanton@gmail.com> wrote:
I will start isolating to problem with this patch On Wed, Sep 23, 2020 at 9:17 AM Julien Chavanton <jchavanton@gmail.com <mailto:jchavanton@gmail.com>> wrote: Hi, I am also troubleshooting unexpected no-ack disconnection. recently I added a modification to catch them before they would take place in the logs commit 2f1338a67579c8fef58deec911d417851ff55cda (tag: v5.3.3.fr.4) Author: Julien Chavanton <jchavanton@gmail.com <mailto:jchavanton@gmail.com>> Date: Fri Jul 24 14:51:02 2020 -0700 dialog: log no-ack timer disconnection diff --git a/src/modules/dialog/dlg_hash.c b/src/modules/dialog/dlg_hash.c index 4e0e28b788..273b43b286 100644 --- a/src/modules/dialog/dlg_hash.c +++ b/src/modules/dialog/dlg_hash.c @@ -243,6 +243,10 @@ int dlg_clean_run(ticks_t ti) unlink_unsafe_dlg(&d_table->entries[i], tdlg); destroy_dlg(tdlg); } + if(tdlg->state==DLG_STATE_CONFIRMED_NA && tdlg->start_ts>0 && tdlg->start_ts<tm-60) { + LM_NOTICE("dialog disconnection no-ACK call-id[%.*s][%u]<[%u - 60]\n", + tdlg->callid.len, tdlg->callid.s, tdlg->start_ts, tm); + } if(tdlg->state==DLG_STATE_CONFIRMED_NA && tdlg->start_ts>0 && tdlg->start_ts<tm-dlg_noack_timeout) { if(update_dlg_timer(&tdlg->tl, 10)<0) { I found many and they do not seem to be missing anything, the to/from/call-id and route header are there and when I replay some they work just fine. I am now adding more debugging lines in dlg_onroute to isolate the check/condition that is not updating the dialog on reception of an ACK I am also having a look at your logs to see if this seems to be the same problem On Mon, Aug 17, 2020 at 11:43 PM Ilie Soltanici <iliusha.md@gmail.com <mailto:iliusha.md@gmail.com>> wrote: Hello, Back to this issue again, I just got another DEBUG log file which seems to have more information, could you please take a look? Thank you. On Wed, 12 Aug 2020 at 15:18, Ilie Soltanici <iliusha.md@gmail.com <mailto:iliusha.md@gmail.com>> wrote: Hello, Setting the dlg_manage() function just before any other functions/vars didn't help either. I will try to get another debug log, maybe I will be able to get more information from there. Thanks On Wed, 12 Aug 2020 at 11:26, Ilie Soltanici <iliusha.md@gmail.com <mailto:iliusha.md@gmail.com>> wrote: 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 <miconda@gmail.com <mailto:miconda@gmail.com>> 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 <mailto:sip%3A%2B1234567890@192.168.89.110>>;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 <miconda@gmail.com <mailto:miconda@gmail.com>> 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@gmail.com <mailto:miconda@gmail.com>> 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 <http://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 <http://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 <http://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 <http://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 <http://5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060>','sip:+987654321@192.168.50.139 <mailto:sip%3A%2B987654321@192.168.50.139>','as5a6d564e','sip:+1234567890@192.168.89.110 <mailto:sip%3A%2B1234567890@192.168.89.110>','05e27170-ffe5-4e90-b785-9a2fffa0194d','udp:192.168.50.12:5060 <http://192.168.50.12:5060>','udp:192.168.180.16:5060 <http://192.168.180.16:5060>',1597217858,3,1538026468,'103','0','sip:+987654321@192.168.50.139:5060 <http://sip:+987654321@192.168.50.139:5060>','sip:192.168.82.230:5060 <http://192.168.82.230:5060>',NULL,'<sip:192.168.82.250:5060;lr>',0,NULL,'sip:+1234567890@192.168.89.110 <mailto:sip%3A%2B1234567890@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 <http://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 <http://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 <http://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 <http://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 <http://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 <http://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 <http://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 <http://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 <http://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 <http://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 <http://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 <http://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 <http://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 <http://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 <http://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 <http://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 <http://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 <http://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 <http://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 <http://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 <http://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 <http://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 <http://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 <http://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 <http://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 <http://5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060>','29176259973485-74271626511770@192.168.1.228 <mailto: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 <http://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 <http://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 <http://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@gmail.com <mailto:miconda@gmail.com>> 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 <pojogas@gmail.com <mailto:pojogas@gmail.com>> 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 <shaheryarkh@gmail.com <mailto:shaheryarkh@gmail.com>> 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 <iliusha.md@gmail.com <mailto:iliusha.md@gmail.com>> 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 <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 <http://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@gmail.com <mailto:miconda@gmail.com>> 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 <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 <http://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@gmail.com <mailto:miconda@gmail.com>> 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@gmail.com > mailto:miconda@gmail.com> > 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/ff2f8c4e63b4fefa7dc5b10835505c3c... > https://github.com/kamailio/kamailio/commit/ff2f8c4e63b4fefa7dc5b10835505c3c4ae84388 > > 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 List >> sr-users@lists.kamailio.org mailto:sr-users@lists.kamailio.org >> https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users > > -- > Daniel-Constantin Mierla -- www.asipto.com http://www.asipto.com > www.twitter.com/miconda http://www.twitter.com/miconda -- www.linkedin.com/in/miconda http://www.linkedin.com/in/miconda > Funding: https://www.paypal.me/dcmierla https://www.paypal.me/dcmierla
>
Daniel-Constantin Mierla -- www.asipto.com <http://www.asipto.com> www.twitter.com/miconda <http://www.twitter.com/miconda> -- www.linkedin.com/in/miconda <http://www.linkedin.com/in/miconda> Funding: https://www.paypal.me/dcmierla <https://www.paypal.me/dcmierla>-- Daniel-Constantin Mierla -- www.asipto.com <http://www.asipto.com> www.twitter.com/miconda <http://www.twitter.com/miconda> -- www.linkedin.com/in/miconda <http://www.linkedin.com/in/miconda> Funding: https://www.paypal.me/dcmierla <https://www.paypal.me/dcmierla> _______________________________________________ Kamailio (SER) - Users Mailing List sr-users@lists.kamailio.org <mailto:sr-users@lists.kamailio.org> https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users <https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users> _______________________________________________ Kamailio (SER) - Users Mailing List sr-users@lists.kamailio.org <mailto:sr-users@lists.kamailio.org> https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users <https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users> _______________________________________________ Kamailio (SER) - Users Mailing List sr-users@lists.kamailio.org <mailto:sr-users@lists.kamailio.org> https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users <https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users> _______________________________________________ Kamailio (SER) - Users Mailing List sr-users@lists.kamailio.org <mailto:sr-users@lists.kamailio.org> https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users <https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users>-- Daniel-Constantin Mierla -- www.asipto.com <http://www.asipto.com> www.twitter.com/miconda <http://www.twitter.com/miconda> -- www.linkedin.com/in/miconda <http://www.linkedin.com/in/miconda> Funding: https://www.paypal.me/dcmierla <https://www.paypal.me/dcmierla>-- Daniel-Constantin Mierla -- www.asipto.com <http://www.asipto.com> www.twitter.com/miconda <http://www.twitter.com/miconda> -- www.linkedin.com/in/miconda <http://www.linkedin.com/in/miconda> Funding: https://www.paypal.me/dcmierla <https://www.paypal.me/dcmierla>-- Daniel-Constantin Mierla -- www.asipto.com <http://www.asipto.com> www.twitter.com/miconda <http://www.twitter.com/miconda> -- www.linkedin.com/in/miconda <http://www.linkedin.com/in/miconda> Funding: https://www.paypal.me/dcmierla <https://www.paypal.me/dcmierla>-- Daniel-Constantin Mierla -- www.asipto.com <http://www.asipto.com> www.twitter.com/miconda <http://www.twitter.com/miconda> -- www.linkedin.com/in/miconda <http://www.linkedin.com/in/miconda> Funding: https://www.paypal.me/dcmierla <https://www.paypal.me/dcmierla> _______________________________________________ Kamailio (SER) - Users Mailing List sr-users@lists.kamailio.org <mailto:sr-users@lists.kamailio.org> https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users <https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users>
Kamailio (SER) - Users Mailing List sr-users@lists.kamailio.org https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users