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

[Daniel-Constantin Mierla]

Hello,


On 08.11.17 07:23, David Escartín wrote:
> Hello Daniel
>
> sorry about that.
no worries, it was more for the future to keep a conversation in a
single place, if it is not some generic announcement or similar ...
>
> 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

Do you know if all these dialogs were active at the last restart? Or new
dialogs after restart expose the same issue?

Cheers,
Daniel

>
> 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
>

-- 
Daniel-Constantin Mierla
www.twitter.com/miconda -- www.linkedin.com/in/miconda
Kamailio Advanced Training, Nov 13-15, 2017, in Berlin - www.asipto.com
Kamailio World Conference - www.kamailioworld.com