[SR-Users] strange --dialog in delete state is too old-- log line managing dialog hashes

[David Escartín]

Hello Daniel

sorry about that.

yes, if we make a restart, after a while (not fixed time some times 
minutes, some times 2 hours),  we start to see those types of messages

i attach you the sip messages of the call of the logs in the first mail
the INVITE receiver is the Kamailio instance.

thanks a lot and sorry again about the 2 email accounts
david


El 07/11/17 a las 18:40, Daniel-Constantin Mierla escribió:
> Hello,
>
> first: no need to post on both sr-users and sr-dev, it makes it hard to
> follow up if people answer on different lists.
>
> If it is about a stable release, you can use the sr-users, if it is
> about devel version, you can use sr-dev. Of course, if it is a bug, you
> can open an issue on:
>
>    - https://github.com/kamailio/kamailio/issues
>
> Now, back to the message itself -- have you done a recent restart before
> this situation is exposed? Do you capture the traffic in your network?
> If yes, can you extract the sip packets for one of these calls and send
> them over to me?
>
> Cheers,
> Daniel
>
>
> On 07.11.17 16:30, David Escartín wrote:
>> hello all
>>
>> recently we are seeing some weird messages handling with dialogs in
>> Kamailio version 5.0
>> we sometimes are seeing messages like
>> /usr/local/kamailio/sbin/kamailio[15372]: NOTICE: dialog
>> [dlg_hash.c:249]: dlg_clean_run(): dialog in delete state is too old
>> (0x7fa65445c850 ref 3)
>> /usr/local/kamailio/sbin/kamailio[15372]: NOTICE: dialog
>> [dlg_hash.c:235]: dlg_clean_run(): dialog in early state is too old
>> (0x7fa652d57110 ref 1)
>>
>> we increased the debug description adding some lines to the dialog
>> module code so we could track the calls of the calls that these
>> messages belong to, and we could see that those messages appeared in
>> calls just released at that moment, for example:
>>
>> <134>Nov  4 11:21:38 localhost
>> /usr/local/kamailio/sbin/kamailio[4108]: INFO: mad-localhost-1 Call
>> 97980 / Call-ID 1409565771_82382809 at 195.219.240.46: Creating dialog
>> [8043:21772] with hash id 21772 and hash entry 8043
>> <134>Nov  4 11:21:38 localhost
>> /usr/local/kamailio/sbin/kamailio[4106]: INFO: mad-localhost-1 Call
>> 97980 / Call-ID 1409565771_82382809 at 195.219.240.46: Status 100, 6610
>> <134>Nov  4 11:21:39 localhost
>> /usr/local/kamailio/sbin/kamailio[4111]: INFO: mad-localhost-1 Call
>> 97980 / Call-ID 1409565771_82382809 at 195.219.240.46: CANCEL received in
>> A-Leg, relaying downstream
>> <134>Nov  4 11:21:39 localhost
>> /usr/local/kamailio/sbin/kamailio[4112]: INFO: mad-localhost-1 Call
>> 97980 / Call-ID 1409565771_82382809 at 195.219.240.46: Status 487, 6610
>> <133>Nov  4 11:21:39 localhost
>> /usr/local/kamailio/sbin/kamailio[4139]: NOTICE: dialog
>> [dlg_hash.c:251]: dlg_clean_run(): dialog in delete state is too old
>> (0x7fa0c02a6870 ref 3) with callid '1409565771_82382809 at 195.219.240.46'
>> <129>Nov  4 11:21:39 mad-proxy-inout-1
>> /usr/local/kamailio/sbin/kamailio[4112]: ALERT: dialog
>> [dlg_handlers.c:1715]: dlg_run_event_route(): after event route -
>> dialog not found [8043:21772] (1/5) (0x7fa0c02a6870) with callid
>> '1409565771_82382809 at 195.219.240.46'
>>
>> we printed the dialog id and entry hash values and we can see there
>> are no other calls creating same values in the previous hours, or
>> using same memory allocation, or same callid, so it seems like there
>> was some kind of strange issue with the dialog timers....¿?
>> By the way, this is happening only few times (80-100 times) a day
>> having many thousands of calls, so it's quite difficult for us to
>> duplicate, we couldn't do it until now.
>> We also tried to use the timer_procs 0 or 1 to use a different proc
>> timer but seems the issue happens in both scenarios.
>>
>> The configuration change we made and seems it was done when these
>> messages started to appear is to use dialog event_route when ended and
>> failed to do some stuff there managing some dialog variables.
>> Does ti make any sense that attempting to use those variables could
>> cause these behaviour?
>> Do you have any idea about it could be or how we can check it deeper?
>>
>> thanks a lot and regards
>> david escartin
>>
>> _______________________________________________
>> Kamailio (SER) - Users Mailing List
>> sr-users at lists.kamailio.org
>> https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users

-------------- next part --------------
A non-text attachment was scrubbed...
Name: HOMER_CID_1409565771_82382809 at 195.219.240.46.pcap
Type: application/vnd.tcpdump.pcap
Size: 3276 bytes
Desc: not available
URL: <http://lists.kamailio.org/pipermail/sr-users/attachments/20171108/09bca18a/attachment.pcap>