[Home]

Summary:ASTERISK-24747: Call is not terminated in time due to lack of RTP nor it is shutdown if peer sends BYE
Reporter:Fabian Borot (fborot)Labels:
Date Opened:2015-02-02 10:27:05.000-0600Date Closed:2015-04-07 15:03:07
Priority:MajorRegression?
Status:Closed/CompleteComponents:
Versions:11.2.1 Frequency of
Occurrence
Related
Issues:
is related toASTERISK-24831 Upon receiving BYE a dialog is scheduled for destruction in 32000 ms and gets stuck, causing long calls
Environment:Linux 2.6.18-274.7.1.el5 #1 SMP Thu Oct 20 16:21:01 EDT 2011 x86_64 x86_64 x86_64 GNU/Linux CentOS release 5.7 (Final) Attachments:( 0) asterisk_log.txt
Description:We use RTP time out as a protection to shutdown the calls when there is lack of RTP for 30 secs. We have been noticing lately this behavior, either the calling or called peer terminates the call and asterisk takes a long time, (variable, around 30-40 secs later) to forward the BYE to the other leg.
At the same time, asterisk shows in the logs for those calls that the call will be terminated due to Lack of RTP activity in 30 secs, we see the message "Rescheduling destruction for 10000 ms" for the channel, several times, not even spaced out every 10000 ms but 40 secs, 50 secs etc until eventually (sometimes after 4 mins) the call is terminated, causing to log the duration of the call with wrong values. Our customer are complaining  about it. We restarted the asterisk and so far it hasn't happened again but it looks like this behavior lasted several weeks and we don't know yet the repercussion of this issue because it may take a couple of billing cycles for the customers to create the disputes.

The weird thing is that the BYE sent by the peers is acknowledged with the 200 OK but the calls are not terminated, they are terminated after several cycles of that "Rescheduling destruction" msgs.
Looks like while the asterisk is in the process of terminating the call due t lack of rtp that the BYE msg is not taking into account to terminate the call. Is this possible ?
thank you
Any ideas?
Has anybody experienced an issue like this before?
Comments:By: Matt Jordan (mjordan) 2015-02-02 10:40:46.605-0600

# Since you have no logs and no configuration information attached to the issue, all we could offer is speculation. Please read the [Asterisk Issue Guidelines|https://wiki.asterisk.org/wiki/display/AST/Asterisk+Issue+Guidelines] for what information you need to provide.
# The issue tracker is not a good forum for discussion. Your questions would be better served on the [asterisk-users|http://lists.digium.com/mailman/listinfo/asterisk-users] mailing list.

If you can provide logs, configuration information, and steps to reproduce the problem, please attach them to the issue and comment here. If not, a bug marshal will close this issue out.

Thanks!
By: Fabian Borot (fborot) 2015-02-02 16:25:03.918-0600

Hi, Please see attached log
By: Rusty Newton (rnewton) 2015-02-02 17:29:23.471-0600

So it looks like there is an issue there, however you haven't provides steps to reproduce the issue.

Even with a deeper log (you didn't provide a log showing the *debug* log messages). It is unlikely we can solve the issue from the log alone.

Can you provide steps and configuration to allow us to reproduce the issue?
By: Fabian Borot (fborot) 2015-02-03 08:13:00.258-0600

that is the problem, the replication. We can not replicate it at least so far but we were hoping to get some insight as to what to look for in order to alleviate the effect if this happens again. We have these ideas in mind:
1- reduce the rtptimeout to 3 seconds instead of 30 seconds
2- find in the code the part that re-schedule it to 10000 ms, and reduce that time to 2000 ms maybe
3- as you can see even though it said rescheduling the autodestruction in 10000 ms it was not happening every 10000 ms either, check that logic.
4- I see in the code that an AMI EVENT gets fired in the function  "static int check_rtp_timeout" :

                               ast_log(LOG_NOTICE, "Disconnecting call '%s' for lack of RTP activity in %ld seconds\n",
                                       ast_channel_name(dialog->owner), (long) (t - dialog->lastrtprx));
                               manager_event(EVENT_FLAG_CALL, "SessionTimeout", "Source: RTPTimeout\r\n"
                                               "Channel: %s\r\nUniqueid: %s\r\n", ast_channel_name(dialog->owner), ast_channel_uniqueid(dialog->owner));

If that is the case we could maybe disconnect the channel upon receiving the AMI event, we hope that that hangup will happen if commanded from AMI,

Let me know what you think pls
By: Fabian Borot (fborot) 2015-02-18 11:09:56.247-0600

ok, we were able to enable the debug level logs, we can not reproduce the issue because it is random , but we hope that with the sip debug on and the debug level enabled we can provide you with the information that you need. please reply if somebody is still watching this issue, thank you
By: Rusty Newton (rnewton) 2015-03-06 15:47:56.028-0600

{quote}
but we hope that with the sip debug on and the debug level enabled we can provide you with the information that you need.
{quote}

Did you attach the new log with 'DEBUG' type log messages (please also, level 5 or above)? I don't see it.

I don't have a specific opinion on your options for a work-around. Whichever works for you is fine for a work-around. If you can get the new log up I'll take a look at that and get a developer to review it if it has anything useful.
By: Rusty Newton (rnewton) 2015-03-06 15:48:17.614-0600

Remember to press Send Back or Enter Feedback when replying so that we will see the issue sooner.
By: Rusty Newton (rnewton) 2015-04-07 15:03:07.402-0500

Since we can't reproduce the issue and don't have the additional logs required I'm going to go ahead and close this out.

If you are able to get additional data on how to reproduce the issue, or the logs required then please contact a bug marshal in #asterisk-bugs or #asterisk-dev on irc.freenode.net.

Thanks,