<div dir="ltr"><div>Hello,</div><div><br></div><div>Yes, ACK have the To-tag:</div><div><b><br></b></div><div><b>To: <<a href="mailto:sip%3A%2B1234567890@192.168.89.110">sip:+1234567890@192.168.89.110</a>>;tag=05e27170-ffe5-4e90-b785-9a2fffa0194d</b></div><div><b><br></b></div><div>Yes, I'm using
dlg_va() function before calling dlg_manage() function. <br></div><div>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.</div><div>Thanks<br>
</div><div><b></b></div></div><br><div class="gmail_quote"><div dir="ltr" class="gmail_attr">On Wed, 12 Aug 2020 at 10:54, 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>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)?</p>
<p>Cheers,<br>
Daniel<br>
</p>
<div>On 12.08.20 11:48, Ilie Soltanici
wrote:<br>
</div>
<blockquote type="cite">
<div dir="ltr">
<div>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.</div>
<div>I will try get another call log, hope that I would be able
to get more information there.</div>
<div><br>
</div>
<div>Thanks<br>
</div>
</div>
<br>
<div class="gmail_quote">
<div dir="ltr" class="gmail_attr">On Wed, 12 Aug 2020 at 10:24,
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>are these all debug messages printed for ACK processing?</p>
<p>There should be a log message like:</p>
<p>... changed from state X to state Y ...</p>
<p>Cheers,<br>
Daniel<br>
</p>
<div>On 12.08.20 10:56, Ilie Soltanici wrote:<br>
</div>
<blockquote type="cite">
<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" target="_blank">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" target="_blank">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" target="_blank">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" target="_blank">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" target="_blank">5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060</a>','<a href="mailto:sip%3A%2B987654321@192.168.50.139" target="_blank">sip:+987654321@192.168.50.139</a>','as5a6d564e','<a href="mailto:sip%3A%2B1234567890@192.168.89.110" target="_blank">sip:+1234567890@192.168.89.110</a>','05e27170-ffe5-4e90-b785-9a2fffa0194d','udp:<a href="http://192.168.50.12:5060" target="_blank">192.168.50.12:5060</a>','udp:<a href="http://192.168.180.16:5060" target="_blank">192.168.180.16:5060</a>',1597217858,3,1538026468,'103','0','<a href="http://sip:+987654321@192.168.50.139:5060" target="_blank">sip:+987654321@192.168.50.139:5060</a>','sip:<a href="http://192.168.82.230:5060" target="_blank">192.168.82.230:5060</a>',NULL,'<a><sip:192.168.82.250:5060;lr></a>',0,NULL,'<a href="mailto:sip%3A%2B1234567890@192.168.89.110" target="_blank">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" target="_blank">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" target="_blank">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" target="_blank">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" target="_blank">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" target="_blank">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" target="_blank">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" target="_blank">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" target="_blank">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" target="_blank">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" target="_blank">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" target="_blank">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" target="_blank">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" target="_blank">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" target="_blank">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" target="_blank">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" target="_blank">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" target="_blank">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" target="_blank">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" target="_blank">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" target="_blank">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" target="_blank">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" target="_blank">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" target="_blank">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" target="_blank">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" target="_blank">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" target="_blank">5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060</a>','<a href="mailto:29176259973485-74271626511770@192.168.1.228" target="_blank">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" target="_blank">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" target="_blank">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" target="_blank">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-wrap"><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>
<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" 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>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>
</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>