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

Thu Dec 21 15:33:04 CET 2017

hello Daniel


sorry about the delay

i applied these 2 patches and the logs disappeared


thanks a lot


best regards


El 14/11/17 a las 08:38, Daniel-Constantin Mierla escribió:
> Hello,
>
>
> On 14.11.17 08:24, David Escartín wrote:
>> hello DAniel
>>
>> are these the patches you refer to?
>>
>>
>> a3d3ea837b0f4011a3ca0e51ad4a1516bb211299
>> [5.0_produccion e577807] dialog: parse all headers before getting the
>> message attributes for dialog
> this is mainly for topos, but you can take it as well, because is safer
> with it over all.
>> 0725f750e1981be8e2058ce1a48e90eb7862e8bd
>> [5.0_produccion 4ff26d1] dialog: set the end time stamp immediately
>> after going into deleted state
> this is the relevant one. There was another one to use a variable for
> setting the timeout interval, but more for flexibility than fixing the
> issue itself.
>
> Cheers,
> Daniel
>
>> best regards
>> david
>>
>>
>>
>> El 13/11/17 a las 09:42, Daniel-Constantin Mierla escribió:
>>> Hello,
>>>
>>> I pushed two patches to dialog module few days ago, can you try with
>>> that version (or with those patches backported to your version)?
>>>
>>> Cheers,
>>> Daniel
>>>
>>> On 09.11.17 18:50, David Escartín wrote:
>>>> hello Daniel
>>>>
>>>> I might think they were not, at least i cannot see dialogs being
>>>> created with the same id and entry hash values in the previous hours
>>>> to the kamailio reset, but i'm not sure. I dont know if maybe they
>>>> could be some "lost" dialogs with more than 2 hours lifetime for some
>>>> strange reason, but i could not check the dailog profile list live
>>>> because i got a "reply too big" output using the kamcmd rpc command.
>>>> I guess i should increase  binrpc_max_body_size ?
>>>>
>>>> I can try to remove traffic from the server and see if after 2 hours i
>>>> have any remaining dialog. I don't think there would be any because i
>>>> checked generally other times that the number of dialogs go to 0 after
>>>> a while (2 hours or so) when i remove traffic from a kamailio
>>>> instance. But i can check it anyway.
>>>>
>>>> i will let you know
>>>>
>>>> best regards
>>>> david
>>>>
>>>>
>>>>
>>>> El 08/11/17 a las 08:40, Daniel-Constantin Mierla escribió:
>>>>> 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