<div dir="ltr"><div>Hello,</div><div><br></div><div>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:</div><div><br></div><div>Aug 12 08:37:38 kamailio.localhost kamailio[28296]: DEBUG: {INVITE (2) | Seq=103 | Source IP=192.168.89.110 (udp) | Call ID=<a href="http://5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060">5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060</a>} <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<br>Aug 12 08:37:38 kamailio.localhost kamailio[28296]: DEBUG: {INVITE (2) | Seq=103 | Source IP=192.168.89.110 (udp) | Call ID=<a href="http://5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060">5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060</a>} dialog [dlg_db_handler.c:834]: update_dialog_dbinfo_unsafe(): updated 13 vars for dlg [273:1534]<br>Aug 12 08:37:38 kamailio.localhost kamailio[28296]: DEBUG: {INVITE (2) | Seq=103 | Source IP=192.168.89.110 (udp) | Call ID=<a href="http://5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060">5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060</a>} db_cluster [dbcl_api.c:483]: db_cluster_use_table(): use table (dialog) - cluster [kamailio]<br>Aug 12 08:37:38 kamailio.localhost kamailio[28296]: DEBUG: {INVITE (2) | Seq=103 | Source IP=192.168.89.110 (udp) | Call ID=<a href="http://5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060">5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060</a>} <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,'<a href="http://5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060">5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060</a>','<a href="mailto:sip%3A%2B987654321@192.168.50.139">sip:+987654321@192.168.50.139</a>','as5a6d564e','<a href="mailto:sip%3A%2B1234567890@192.168.89.110">sip:+1234567890@192.168.89.110</a>','05e27170-ffe5-4e90-b785-9a2fffa0194d','udp:<a href="http://192.168.50.12:5060">192.168.50.12:5060</a>','udp:<a href="http://192.168.180.16:5060">192.168.180.16:5060</a>',1597217858,3,1538026468,'103','0','<a href="http://sip:+987654321@192.168.50.139:5060">sip:+987654321@192.168.50.139:5060</a>','sip:<a href="http://192.168.82.230:5060">192.168.82.230:5060</a>',NULL,'<sip:192.168.82.250:5060;lr>',0,NULL,'<a href="mailto:sip%3A%2B1234567890@192.168.89.110">sip:+1234567890@192.168.89.110</a>',NULL,0), result 0<br>Aug 12 08:37:38 kamailio.localhost kamailio[28296]: DEBUG: {INVITE (2) | Seq=103 | Source IP=192.168.89.110 (udp) | Call ID=<a href="http://5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060">5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060</a>} dialog [dlg_timer.c:110]: insert_dialog_timer_unsafe(): inserting 0x7f769a594418 for 59202190<br>Aug 12 08:37:38 kamailio.localhost kamailio[28296]: DEBUG: {INVITE (2) | Seq=103 | Source IP=192.168.89.110 (udp) | Call ID=<a href="http://5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060">5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060</a>} dialog [dlg_hash.c:1045]: dlg_ref_helper(): ref op on 0x7f769a5943b8 with 1 from dlg_handlers.c:557<br>Aug 12 08:37:38 kamailio.localhost kamailio[28296]: DEBUG: {INVITE (2) | Seq=103 | Source IP=192.168.89.110 (udp) | Call ID=<a href="http://5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060">5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060</a>} dialog [dlg_hash.c:1049]: dlg_ref_helper(): ref dlg 0x7f769a5943b8 with 1 -> 3<br>Aug 12 08:37:38 kamailio.localhost kamailio[28296]: DEBUG: {INVITE (2) | Seq=103 | Source IP=192.168.89.110 (udp) | Call ID=<a href="http://5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060">5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060</a>} dialog [dlg_hash.c:1065]: dlg_unref_helper(): unref op on 0x7f769a5943b8 with 1 from dlg_hash.c:1083<br>Aug 12 08:37:38 kamailio.localhost kamailio[28296]: DEBUG: {INVITE (2) | Seq=103 | Source IP=192.168.89.110 (udp) | Call ID=<a href="http://5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060">5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060</a>} <core> [core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <103> <INVITE><br>Aug 12 08:37:38 kamailio.localhost kamailio[28307]: DEBUG: {ACK (1) | Seq=103 | Source IP=192.168.50.139 (udp) | Call ID=<a href="http://5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060">5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060</a>} sl [sl_funcs.c:421]: sl_filter_ACK(): too late to be a local ACK!<br>Aug 12 08:37:38 kamailio.localhost kamailio[28307]: DEBUG: {ACK (1) | Seq=103 | Source IP=192.168.50.139 (udp) | Call ID=<a href="http://5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060">5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060</a>} dialog [dlg_var.c:276]: print_lists(): ua=AGENT (flags 1)<br>Aug 12 08:37:38 kamailio.localhost kamailio[28307]: DEBUG: {ACK (1) | Seq=103 | Source IP=192.168.50.139 (udp) | Call ID=<a href="http://5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060">5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060</a>} dialog [dlg_var.c:276]: print_lists(): ua=AGENT (flags 1)<br>Aug 12 08:37:38 kamailio.localhost kamailio[28307]: DEBUG: {ACK (1) | Seq=103 | Source IP=192.168.50.139 (udp) | Call ID=<a href="http://5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060">5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060</a>} dialog [dlg_var.c:276]: print_lists(): dest_ip=192.168.89.110 (flags 1)<br>Aug 12 08:37:38 kamailio.localhost kamailio[28307]: DEBUG: {ACK (1) | Seq=103 | Source IP=192.168.50.139 (udp) | Call ID=<a href="http://5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060">5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060</a>} dialog [dlg_var.c:276]: print_lists(): dest_ip=192.168.89.110 (flags 1)<br>Aug 12 08:37:38 kamailio.localhost kamailio[28307]: DEBUG: {ACK (1) | Seq=103 | Source IP=192.168.50.139 (udp) | Call ID=<a href="http://5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060">5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060</a>} rr [loose.c:90]: is_preloaded(): is_preloaded: No<br>Aug 12 08:37:38 kamailio.localhost kamailio[28307]: DEBUG: {ACK (1) | Seq=103 | Source IP=192.168.50.139 (udp) | Call ID=<a href="http://5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060">5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060</a>} dialog [dlg_hash.c:1065]: dlg_unref_helper(): unref op on 0x7f769a5c8b48 with 1 from dlg_hash.c:1083<br>Aug 12 08:37:38 kamailio.localhost kamailio[28307]: DEBUG: {ACK (1) | Seq=103 | Source IP=192.168.50.139 (udp) | Call ID=<a href="http://5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060">5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060</a>} dialog [dlg_var.c:276]: print_lists(): log=1 (flags 3)<br>Aug 12 08:37:38 kamailio.localhost kamailio[28307]: DEBUG: {ACK (1) | Seq=103 | Source IP=192.168.50.139 (udp) | Call ID=<a href="http://5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060">5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060</a>} dialog [dlg_var.c:276]: print_lists(): called_number=0123456789 (flags 1)<br>Aug 12 08:37:38 kamailio.localhost kamailio[28307]: DEBUG: {ACK (1) | Seq=103 | Source IP=192.168.50.139 (udp) | Call ID=<a href="http://5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060">5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060</a>} tm [t_lookup.c:1330]: t_newtran(): msg (0x7f76bf204b68) id=5441/28307 global id=5440/28307 T start=(nil)<br>Aug 12 08:37:38 kamailio.localhost kamailio[28307]: DEBUG: {ACK (1) | Seq=103 | Source IP=192.168.50.139 (udp) | Call ID=<a href="http://5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060">5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060</a>} <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','<a href="http://5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060">5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060</a>','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<br>Aug 12 08:37:38 kamailio.localhost kamailio[28307]: DEBUG: {ACK (1) | Seq=103 | Source IP=192.168.50.139 (udp) | Call ID=<a href="http://5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060">5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060</a>} acc [acc_extra.h:64]: free_strar_mem(): Freeing memory, type is 2, message_index 9, index i 0<br>Aug 12 08:37:38 kamailio.localhost kamailio[28307]: DEBUG: {ACK (1) | Seq=103 | Source IP=192.168.50.139 (udp) | Call ID=<a href="http://5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060">5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060</a>} acc [acc_extra.h:64]: free_strar_mem(): Freeing memory, type is 2, message_index 9, index i 1<br>Aug 12 08:37:38 kamailio.localhost kamailio[28307]: DEBUG: {ACK (1) | Seq=103 | Source IP=192.168.50.139 (udp) | Call ID=<a href="http://5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060">5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060</a>} acc [acc_extra.h:64]: free_strar_mem(): Freeing memory, type is 2, message_index 9, index i 2<br>Aug 12 08:37:38 kamailio.localhost kamailio[28307]: DEBUG: {ACK (1) | Seq=103 | Source IP=192.168.50.139 (udp) | Call ID=<a href="http://5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060">5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060</a>} <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=05e27170-ffe5-4e90-b785-9a2fffa0194d<br>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 '<a href="http://5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060">5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060</a>' and tags 'as5a6d564e' ''<br>Aug 12 08:37:42 kamailio.localhost kamailio[28324]: DEBUG: dialog [dlg_db_handler.c:710]: remove_dialog_from_db(): trying to remove dialog [<a href="http://5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060">5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060</a>], update_flag is 640<br>Aug 12 08:37:42 kamailio.localhost kamailio[28324]: DEBUG: dialog [dlg_db_handler.c:736]: remove_dialog_from_db(): callid was <a href="http://5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060">5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060</a><br>Aug 12 08:40:08 kamailio.localhost kamailio[28323]: WARNING: dialog [dlg_handlers.c:1652]: dlg_ontimeout(): dlg timeout - callid: '<a href="http://5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060">5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060</a>' tags: 'as5a6d564e' '05e27170-ffe5-4e90-b785-9a2fffa0194d' ostate: 3<br>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','<a href="http://5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060">5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060</a>','<a href="mailto:29176259973485-74271626511770@192.168.1.228">29176259973485-74271626511770@192.168.1.228</a>','987654321','0123456789',NULL,NULL,'AGENT','SRV',NULL,'192.168.50.139','192.168.89.110','OUTBOUND'), result 0<br>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 '<a href="http://5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060">5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060</a>' and tags 'as5a6d564e' '05e27170-ffe5-4e90-b785-9a2fffa0194d'<br>Aug 12 08:40:08 kamailio.localhost kamailio[28323]: DEBUG: dialog [dlg_db_handler.c:710]: remove_dialog_from_db(): trying to remove dialog [<a href="http://5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060">5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060</a>], update_flag is 1542<br>Aug 12 08:40:08 kamailio.localhost kamailio[28323]: DEBUG: dialog [dlg_db_handler.c:736]: remove_dialog_from_db(): callid was <a href="http://5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060">5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060</a></div><div><br></div><div><br></div><div>What I noticed strange here, is that SL module reporting:</div><div><b>
sl_filter_ACK(): too late to be a local ACK! <br></b></div><div><b><br></b></div><div>I'm not sure that this is the core of the problem, but maybe you can spot something here.</div><div><br></div><div>This is sl_module configuration, in case if you'll need it:</div><div>
<div style="color:rgb(171,178,191);background-color:rgb(40,44,52);font-family:"Fira Code",Consolas,"Courier New",monospace;font-weight:normal;font-size:14px;line-height:19px;white-space:pre"><div><span style="color:rgb(92,99,112);font-style:italic"># ---- sl params ----</span></div><div><span style="color:rgb(198,120,221)">modparam</span><span style="color:rgb(171,178,191)">(</span><span style="color:rgb(152,195,121)">"sl"</span><span style="color:rgb(171,178,191)">, </span><span style="color:rgb(152,195,121)">"default_code"</span><span style="color:rgb(171,178,191)">, </span><span style="color:rgb(209,154,102)">505</span><span style="color:rgb(171,178,191)">)</span></div><div><span style="color:rgb(198,120,221)">modparam</span><span style="color:rgb(171,178,191)">(</span><span style="color:rgb(152,195,121)">"sl"</span><span style="color:rgb(171,178,191)">, </span><span style="color:rgb(152,195,121)">"default_reason"</span><span style="color:rgb(171,178,191)">, </span><span style="color:rgb(152,195,121)">"Server Error"</span><span style="color:rgb(171,178,191)">)</span></div></div>
</div><div><br></div><div>Thanks.<br></div><div><b></b></div></div><br><div class="gmail_quote"><div dir="ltr" class="gmail_attr">On Thu, 30 Jul 2020 at 07:22, Daniel-Constantin Mierla <<a href="mailto:miconda@gmail.com">miconda@gmail.com</a>> wrote:<br></div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">
<div>
<p>Hello,</p>
<p>run with debug=3 in kamailio.cfg and send here all the log
messages printed by kamailio when processing the ACK.</p>
<p>Cheers,<br>
Daniel<br>
</p>
<div>On 29.07.20 18:48, Ilie Soltanici
wrote:<br>
</div>
<blockquote type="cite">
<div dir="ltr">
<div>Hello,</div>
<div><br>
</div>
<div>I changed the configuration file to call dlg_manage() for
all methods:</div>
<div><br>
</div>
<div>if (loose_route()) {<br>
dlg_manage();<br>
<br>
if (is_method("BYE")) {<br>
setflag(FLAG_ACC);<br>
setflag(FLAG_ACCMISSED);<br>
$dlg_var(billsec) = $DLG_lifetime;<br>
}<br>
<br>
route(RELAY);<br>
exit;<br>
};</div>
<div><br>
</div>
<div>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.</div>
<div>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.</div>
<div>Could this be related somehow?</div>
<div>Thanks.<br>
</div>
<div><br>
</div>
</div>
<br>
<div class="gmail_quote">
<div dir="ltr" class="gmail_attr">On Wed, 29 Jul 2020 at 17:19,
Sergiu Pojoga <<a href="mailto:pojogas@gmail.com" target="_blank">pojogas@gmail.com</a>> wrote:<br>
</div>
<blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">
<div dir="ltr">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'?<br>
<div><br>
</div>
<div>Not to mention that docs mention "dlg_manage() - this
makes sense only for initial requests)</div>
</div>
<br>
<div class="gmail_quote">
<div dir="ltr" class="gmail_attr">On Wed, Jul 29, 2020 at
10:55 AM M S <<a href="mailto:shaheryarkh@gmail.com" target="_blank">shaheryarkh@gmail.com</a>>
wrote:<br>
</div>
<blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">
<div dir="ltr">
<div dir="ltr">Please put dlg_manage immediately after
loose_route condition, e.g.
<div><br>
</div>
<div>if (loose_route) {</div>
<div> dlg_manage();</div>
<div>...</div>
<div>}</div>
</div>
<div><br>
</div>
<div>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.</div>
<div><br>
</div>
<div>Thank you.</div>
<div><br>
</div>
<div><br>
</div>
<div class="gmail_quote">
<div dir="ltr" class="gmail_attr">On Wed, Jul 29, 2020
at 3:21 PM Ilie Soltanici <<a href="mailto:iliusha.md@gmail.com" target="_blank">iliusha.md@gmail.com</a>>
wrote:<br>
</div>
<blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">
<div dir="ltr">
<div>Hello,</div>
<div><br>
</div>
<div>I've tried what you recommended, but without
success so far.</div>
<div><br>
</div>
<div>This is the configuration block:<br>
</div>
<div><br>
</div>
<div>if (!has_totag()) return;</div>
<div><br>
</div>
<div>if (is_method("ACK")) {<br>
dlg_manage();<br>
}<br>
<br>
if (loose_route()) {<br>
if (is_method("BYE")) {<br>
dlg_manage();<br>
setflag(FLAG_ACC);<br>
setflag(FLAG_ACCMISSED);<br>
$dlg_var(billsec) = $DLG_lifetime;<br>
}<br>
route(RELAY);<br>
exit;<br>
};<br>
<br>
if (is_method("ACK") ) {<br>
if ( t_check_trans() ) {<br>
route(RELAY);<br>
exit;<br>
} else {<br>
sl_send_reply("606", "Not Acceptable");<br>
exit;<br>
}<br>
}<br>
</div>
<div><br>
</div>
<div>Here is the sip trace:</div>
<div>
<a href="https://pastebin.com/Aen2GCjm" target="_blank">https://pastebin.com/Aen2GCjm</a>
<br>
</div>
<div><br>
</div>
<div>And that's the error I'm getting in the
Kamailio log file:</div>
<div><br>
</div>
<div>WARNING: dialog [dlg_handlers.c:1652]:
dlg_ontimeout(): dlg timeout - callid: '
<a href="http://0555141d7d3hsag78sgce830391f9348@10.1.50.240:5060" target="_blank">0555141d7d3hsag78sgce830391f9348@10.1.50.240:5060</a>'
tags: 'as52c10007' 'Uv7HS0jX65ctF' ostate: 3</div>
<div><br>
</div>
<div>Any other ideas?<br>
</div>
</div>
<br>
<div class="gmail_quote">
<div dir="ltr" class="gmail_attr">On Tue, 28 Jul
2020 at 15:44, Daniel-Constantin Mierla <<a href="mailto:miconda@gmail.com" target="_blank">miconda@gmail.com</a>>
wrote:<br>
</div>
<blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">
<div>
<p>Hello,</p>
<p>I see the in-dialog ACK in the trace, try
with dlg_manage() explicitly used for it.</p>
<p>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.</p>
<p>Cheers,<br>
Daniel<br>
</p>
<div>On 28.07.20 12:31, Ilie Soltanici wrote:<br>
</div>
<blockquote type="cite">
<div dir="ltr">
<div>Hello,</div>
<div><br>
</div>
<div>In the Kamailio logs I can see only
those errors:</div>
<div><br>
</div>
<div>WARNING: dialog
[dlg_handlers.c:1652]: dlg_ontimeout():
dlg timeout - callid:
'45b0130e14a692b95134696d2fc5f2a9' tags:
'as31fb1118' '12UDcK9S8630r' ostate: 3</div>
<div>WARNING: acc [acc_cdr.c:230]:
db_write_cdr(): fallback to dlg_only
search because of message doesn't exist</div>
<div><br>
</div>
<div>Here you can see the full sip trace:</div>
<div> <a href="https://pastebin.com/Q4eqcGJj" target="_blank">https://pastebin.com/Q4eqcGJj</a></div>
<div><br>
</div>
<div>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), <a href="http://192.168.2.0/24" target="_blank">192.168.2.0/24</a>
- 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?<br>
</div>
<div><br>
</div>
<div>This is the module configuration:</div>
<div>
<div style="color:rgb(171,178,191);background-color:rgb(40,44,52);font-family:"Fira Code",Consolas,"Courier New",monospace;font-weight:normal;font-size:14px;line-height:19px;white-space:pre-wrap"><div><span style="color:rgb(198,120,221)">modparam</span><span style="color:rgb(171,178,191)">(</span><span style="color:rgb(152,195,121)">"dialog"</span><span style="color:rgb(171,178,191)">, </span><span style="color:rgb(152,195,121)">"enable_stats"</span><span style="color:rgb(171,178,191)">, </span><span style="color:rgb(209,154,102)">1</span><span style="color:rgb(171,178,191)">)</span></div><div><span style="color:rgb(198,120,221)">modparam</span><span style="color:rgb(171,178,191)">(</span><span style="color:rgb(152,195,121)">"dialog"</span><span style="color:rgb(171,178,191)">, </span><span style="color:rgb(152,195,121)">"rr_param"</span><span style="color:rgb(171,178,191)">, </span><span style="color:rgb(152,195,121)">"did"</span><span style="color:rgb(171,178,191)">)</span></div><div><span style="color:rgb(198,120,221)">modparam</span><span style="color:rgb(171,178,191)">(</span><span style="color:rgb(152,195,121)">"dialog"</span><span style="color:rgb(171,178,191)">, </span><span style="color:rgb(152,195,121)">"dlg_match_mode"</span><span style="color:rgb(171,178,191)">, </span><span style="color:rgb(209,154,102)">2</span><span style="color:rgb(171,178,191)">)</span></div><div><span style="color:rgb(198,120,221)">modparam</span><span style="color:rgb(171,178,191)">(</span><span style="color:rgb(152,195,121)">"dialog"</span><span style="color:rgb(171,178,191)">, </span><span style="color:rgb(152,195,121)">"default_timeout"</span><span style="color:rgb(171,178,191)">, </span><span style="color:rgb(209,154,102)">10800</span><span style="color:rgb(171,178,191)">)</span><span style="color:rgb(92,99,112);font-style:italic"></span></div><div><span style="color:rgb(198,120,221)">modparam</span><span style="color:rgb(171,178,191)">(</span><span style="color:rgb(152,195,121)">"dialog"</span><span style="color:rgb(171,178,191)">, </span><span style="color:rgb(152,195,121)">"early_timeout"</span><span style="color:rgb(171,178,191)">, </span><span style="color:rgb(209,154,102)">180</span><span style="color:rgb(171,178,191)">)</span></div><div><span style="color:rgb(198,120,221)">modparam</span><span style="color:rgb(171,178,191)">(</span><span style="color:rgb(152,195,121)">"dialog"</span><span style="color:rgb(171,178,191)">, </span><span style="color:rgb(152,195,121)">"noack_timeout"</span><span style="color:rgb(171,178,191)">, </span><span style="color:rgb(209,154,102)">90</span><span style="color:rgb(171,178,191)">)</span></div><div><span style="color:rgb(198,120,221)">modparam</span><span style="color:rgb(171,178,191)">(</span><span style="color:rgb(152,195,121)">"dialog"</span><span style="color:rgb(171,178,191)">, </span><span style="color:rgb(152,195,121)">"track_cseq_updates"</span><span style="color:rgb(171,178,191)">, </span><span style="color:rgb(209,154,102)">1</span><span style="color:rgb(171,178,191)">)</span></div><div><span style="color:rgb(198,120,221)">modparam</span><span style="color:rgb(171,178,191)">(</span><span style="color:rgb(152,195,121)">"dialog"</span><span style="color:rgb(171,178,191)">, </span><span style="color:rgb(152,195,121)">"dlg_extra_hdrs"</span><span style="color:rgb(171,178,191)">, </span><span style="color:rgb(152,195,121)">"Hint: Inactivity Timeout</span><span style="color:rgb(86,182,194)">\r\n</span><span style="color:rgb(152,195,121)">"</span><span style="color:rgb(171,178,191)">)</span>
</div><div><span style="color:rgb(198,120,221)">modparam</span><span style="color:rgb(171,178,191)">(</span><span style="color:rgb(152,195,121)">"dialog"</span><span style="color:rgb(171,178,191)">, </span><span style="color:rgb(152,195,121)">"detect_spirals"</span><span style="color:rgb(171,178,191)">, </span><span style="color:rgb(209,154,102)">1</span><span style="color:rgb(171,178,191)">)</span></div><div><span style="color:rgb(198,120,221)">modparam</span><span style="color:rgb(171,178,191)">(</span><span style="color:rgb(152,195,121)">"dialog"</span><span style="color:rgb(171,178,191)">, </span><span style="color:rgb(152,195,121)">"db_mode"</span><span style="color:rgb(171,178,191)">, </span><span style="color:rgb(209,154,102)">1</span><span style="color:rgb(171,178,191)">)</span></div></div>
</div>
<div><br>
</div>
<div>I will try to run dlg_manage for ACK
within the dialog and see if it works.</div>
<div>Thank you.<br>
</div>
<div><br>
</div>
</div>
<br>
<div class="gmail_quote">
<div dir="ltr" class="gmail_attr">On Tue,
28 Jul 2020 at 09:26, Daniel-Constantin
Mierla <<a href="mailto:miconda@gmail.com" target="_blank">miconda@gmail.com</a>>
wrote:<br>
</div>
<blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">
<div>
<p>Hello,</p>
<p>that confirms my guessing -- the
ack was not handled in the dialog
context, the state 3 is defined
inside dlg_hash.h by:</p>
<p>#define DLG_STATE_CONFIRMED_NA 3
/*!< confirmed dialog without a
ACK yet */<br>
</p>
<p>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?</p>
<p>Try also to explicitly execute
dlg_manage() for ACK within dialog.</p>
<p>Cheers,<br>
Daniel<br>
</p>
<div>On 28.07.20 10:05, Ilie Soltanici
wrote:<br>
</div>
<blockquote type="cite">
<div dir="ltr">
<div>Hello,</div>
<div><br>
</div>
<div>I re-compiled Kamailio from
the Master branch and I'm
getting the old state: 3</div>
<div><br>
</div>
<div><b>dlg_ontimeout(): dlg
timeout - callid:
'225ce4fc79d78c0f5477d02d02f3feea'
tags: 'as3f0a58cf'
'a9eb002d-c544-47f7-84ec-1c4e690cd0b4'
ostate: 3</b></div>
<div><br>
</div>
<div>[ilie.soltanici@dev ~]$
/usr/local/sbin/kamailio -V<br>
version: kamailio 5.3.5
(x86_64/linux) ff2f8c</div>
<div><br>
</div>
<div>Thanks<br>
</div>
</div>
<br>
<div class="gmail_quote">
<div dir="ltr" class="gmail_attr">On
Mon, 27 Jul 2020 at 08:56,
Daniel-Constantin Mierla <<a href="mailto:miconda@gmail.com" target="_blank">miconda@gmail.com</a>>
wrote:<br>
</div>
<blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">
<div>
<p>Hello,</p>
<p>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:</p>
<p> - <a href="https://github.com/kamailio/kamailio/commit/ff2f8c4e63b4fefa7dc5b10835505c3c4ae84388" target="_blank">https://github.com/kamailio/kamailio/commit/ff2f8c4e63b4fefa7dc5b10835505c3c4ae84388</a></p>
<p>Otherwise, maybe call
dlg_manage() for ACK,
although the loose_route()
callback should be executed
and ACK handled for dialog
processing.</p>
<p>Cheers,<br>
Daniel<br>
</p>
<div>On 24.07.20 12:46, Ilie
Soltanici wrote:<br>
</div>
<blockquote type="cite">
<div dir="ltr">
<div>Hello,</div>
<div><br>
</div>
<div>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:</div>
<div><br>
</div>
<div>WARNING: dialog
[dlg_handlers.c:1649]:
dlg_ontimeout(): timeout
for dlg with CallID
'304bad142b50bb3a7a117816439ea3d5'
and tags 'as3adde5c7'
'7d28152f-e0e3-4bcf-9d5c-21c3723b95c5'</div>
<div>WARNING: acc
[acc_cdr.c:230]:
db_write_cdr(): fallback
to dlg_only search
because of message
doesn't exist.</div>
<div><br>
</div>
<div>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:</div>
<div><br>
</div>
<div>
<div style="color:rgb(171,178,191);background-color:rgb(40,44,52);font-family:"Fira Code",Consolas,"Courier New",monospace;font-weight:normal;font-size:14px;line-height:19px;white-space:pre-wrap"><div><span style="color:rgb(198,120,221)">modparam</span><span style="color:rgb(171,178,191)">(</span><span style="color:rgb(152,195,121)">"dialog"</span><span style="color:rgb(171,178,191)">, </span><span style="color:rgb(152,195,121)">"default_timeout"</span><span style="color:rgb(171,178,191)">, </span><span style="color:rgb(209,154,102)">10800</span><span style="color:rgb(171,178,191)">) </span><span style="color:rgb(92,99,112);font-style:italic"># 3 hours</span></div><div><span style="color:rgb(198,120,221)">modparam</span><span style="color:rgb(171,178,191)">(</span><span style="color:rgb(152,195,121)">"dialog"</span><span style="color:rgb(171,178,191)">, </span><span style="color:rgb(152,195,121)">"early_timeout"</span><span style="color:rgb(171,178,191)">, </span><span style="color:rgb(209,154,102)">180</span><span style="color:rgb(171,178,191)">)</span></div><div><span style="color:rgb(198,120,221)">modparam</span><span style="color:rgb(171,178,191)">(</span><span style="color:rgb(152,195,121)">"dialog"</span><span style="color:rgb(171,178,191)">, </span><span style="color:rgb(152,195,121)">"noack_timeout"</span><span style="color:rgb(171,178,191)">, </span><span style="color:rgb(209,154,102)">90</span><span style="color:rgb(171,178,191)">)</span></div></div>
</div>
<div><br>
</div>
<div>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. <br>
</div>
<div><br>
</div>
<div>Any ideas why is that
happening?</div>
<div>Thank you.<br>
</div>
</div>
<br>
<fieldset></fieldset>
<pre>_______________________________________________
Kamailio (SER) - Users Mailing List
<a href="mailto:sr-users@lists.kamailio.org" target="_blank">sr-users@lists.kamailio.org</a>
<a href="https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users" target="_blank">https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users</a>
</pre>
</blockquote>
<pre cols="72">--
Daniel-Constantin Mierla -- <a href="http://www.asipto.com" target="_blank">www.asipto.com</a>
<a href="http://www.twitter.com/miconda" target="_blank">www.twitter.com/miconda</a> -- <a href="http://www.linkedin.com/in/miconda" target="_blank">www.linkedin.com/in/miconda</a>
Funding: <a href="https://www.paypal.me/dcmierla" target="_blank">https://www.paypal.me/dcmierla</a></pre>
</div>
</blockquote>
</div>
</blockquote>
<pre cols="72">--
Daniel-Constantin Mierla -- <a href="http://www.asipto.com" target="_blank">www.asipto.com</a>
<a href="http://www.twitter.com/miconda" target="_blank">www.twitter.com/miconda</a> -- <a href="http://www.linkedin.com/in/miconda" target="_blank">www.linkedin.com/in/miconda</a>
Funding: <a href="https://www.paypal.me/dcmierla" target="_blank">https://www.paypal.me/dcmierla</a></pre>
</div>
</blockquote>
</div>
</blockquote>
<pre cols="72">--
Daniel-Constantin Mierla -- <a href="http://www.asipto.com" target="_blank">www.asipto.com</a>
<a href="http://www.twitter.com/miconda" target="_blank">www.twitter.com/miconda</a> -- <a href="http://www.linkedin.com/in/miconda" target="_blank">www.linkedin.com/in/miconda</a>
Funding: <a href="https://www.paypal.me/dcmierla" target="_blank">https://www.paypal.me/dcmierla</a></pre>
</div>
</blockquote>
</div>
_______________________________________________<br>
Kamailio (SER) - Users Mailing List<br>
<a href="mailto:sr-users@lists.kamailio.org" target="_blank">sr-users@lists.kamailio.org</a><br>
<a href="https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users" rel="noreferrer" target="_blank">https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users</a><br>
</blockquote>
</div>
</div>
_______________________________________________<br>
Kamailio (SER) - Users Mailing List<br>
<a href="mailto:sr-users@lists.kamailio.org" target="_blank">sr-users@lists.kamailio.org</a><br>
<a href="https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users" rel="noreferrer" target="_blank">https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users</a><br>
</blockquote>
</div>
_______________________________________________<br>
Kamailio (SER) - Users Mailing List<br>
<a href="mailto:sr-users@lists.kamailio.org" target="_blank">sr-users@lists.kamailio.org</a><br>
<a href="https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users" rel="noreferrer" target="_blank">https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users</a><br>
</blockquote>
</div>
<br>
<fieldset></fieldset>
<pre>_______________________________________________
Kamailio (SER) - Users Mailing List
<a href="mailto:sr-users@lists.kamailio.org" target="_blank">sr-users@lists.kamailio.org</a>
<a href="https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users" target="_blank">https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users</a>
</pre>
</blockquote>
<pre cols="72">--
Daniel-Constantin Mierla -- <a href="http://www.asipto.com" target="_blank">www.asipto.com</a>
<a href="http://www.twitter.com/miconda" target="_blank">www.twitter.com/miconda</a> -- <a href="http://www.linkedin.com/in/miconda" target="_blank">www.linkedin.com/in/miconda</a>
Funding: <a href="https://www.paypal.me/dcmierla" target="_blank">https://www.paypal.me/dcmierla</a></pre>
</div>
</blockquote></div>