[SR-Users] Dialog - timeout for dlg with CallID
Daniel-Constantin Mierla
miconda at gmail.com
Wed Aug 12 12:20:13 CEST 2020
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 at 192.168.89.110
> <mailto:sip%3A%2B1234567890 at 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 at gmail.com <mailto:miconda at 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 at gmail.com <mailto:miconda at 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 at 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 at 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 at 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 at 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 at 192.168.50.139:5060
>>> <http://5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060>','sip:+987654321 at 192.168.50.139
>>> <mailto:sip%3A%2B987654321 at 192.168.50.139>','as5a6d564e','sip:+1234567890 at 192.168.89.110
>>> <mailto:sip%3A%2B1234567890 at 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 at 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 at 192.168.89.110
>>> <mailto:sip%3A%2B1234567890 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 192.168.50.139:5060
>>> <http://5d905a9857b4136c42fc52242077ef58@192.168.50.139:5060>','29176259973485-74271626511770 at 192.168.1.228
>>> <mailto:29176259973485-74271626511770 at 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 at 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 at 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 at 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 at gmail.com <mailto:miconda at 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 at gmail.com <mailto:pojogas at 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 at gmail.com
>>>> <mailto:shaheryarkh at 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 at gmail.com
>>>> <mailto:iliusha.md at 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
>>>>
>>>> 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 at 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 at gmail.com
>>>> <mailto:miconda at 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
>>>>>
>>>>> 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 at gmail.com
>>>>> <mailto:miconda at 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 at 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 at gmail.com
>>>>>> <mailto:miconda at 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/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 at lists.kamailio.org <mailto:sr-users at lists.kamailio.org>
>>>>>>> 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
>>>>>>
>>>>> --
>>>>> 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
>>>>>
>>>> --
>>>> 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
>>>>
>>>> _______________________________________________
>>>> Kamailio (SER) - Users Mailing List
>>>> sr-users at lists.kamailio.org
>>>> <mailto:sr-users at lists.kamailio.org>
>>>> https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users
>>>>
>>>> _______________________________________________
>>>> Kamailio (SER) - Users Mailing List
>>>> sr-users at lists.kamailio.org
>>>> <mailto:sr-users at lists.kamailio.org>
>>>> https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users
>>>>
>>>> _______________________________________________
>>>> Kamailio (SER) - Users Mailing List
>>>> sr-users at lists.kamailio.org
>>>> <mailto:sr-users at lists.kamailio.org>
>>>> https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users
>>>>
>>>>
>>>> _______________________________________________
>>>> Kamailio (SER) - Users Mailing List
>>>> sr-users at lists.kamailio.org <mailto:sr-users at lists.kamailio.org>
>>>> 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
>>>
>> --
>> 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
>>
> --
> 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
>
--
Daniel-Constantin Mierla -- www.asipto.com
www.twitter.com/miconda -- www.linkedin.com/in/miconda
Funding: https://www.paypal.me/dcmierla
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.kamailio.org/pipermail/sr-users/attachments/20200812/0cb9e3db/attachment.htm>
More information about the sr-users
mailing list