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(a)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(a)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(a)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(a)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 &#39;1409565771_82382809(a)195.219.240.46&#39; > <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 > &#39;1409565771_82382809(a)195.219.240.46&#39; > > 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(a)lists.kamailio.org > https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users

Hello, On 08.11.17 07:23, David Escartín wrote: 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 ... 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(a)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(a)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(a)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(a)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 >>> &#39;1409565771_82382809(a)195.219.240.46&#39; >>> <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 >>> &#39;1409565771_82382809(a)195.219.240.46&#39; >>> >>> 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(a)lists.kamailio.org >>> https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users

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(a)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(a)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(a)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(a)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 >>>>> &#39;1409565771_82382809(a)195.219.240.46&#39; >>>>> <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 >>>>> &#39;1409565771_82382809(a)195.219.240.46&#39; >>>>> >>>>> 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(a)lists.kamailio.org >>>>> https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users

Hello, On 14.11.17 08:24, David Escartín wrote: this is mainly for topos, but you can take it as well, because is safer with it over all. 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(a)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(a)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(a)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(a)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 >>>>>>> &#39;1409565771_82382809(a)195.219.240.46&#39; >>>>>>> <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 >>>>>>> &#39;1409565771_82382809(a)195.219.240.46&#39; >>>>>>> >>>>>>> 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(a)lists.kamailio.org >>>>>>> https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users