[Home]

Summary:ASTERISK-19949: app_meetme unable to write frame to Local/XXX channel (stuck channel)
Reporter:Johan Wilfer (johan)Labels:
Date Opened:2012-06-04 02:17:45Date Closed:2012-11-07 11:20:47.000-0600
Priority:MajorRegression?No
Status:Closed/CompleteComponents:Applications/app_meetme Channels/chan_local
Versions:1.8.12.1 1.8.17.0 Frequency of
Occurrence		Constant
Related
Issues:
is duplicated byASTERISK-20486 MeetMe Unable to write frame to channel after SIP channel hangs up.
Environment:Debian 6.0 i386 (kernel 2.6.32-5-686-bigmem) Attachments:( 0) myDebugLog_20121009.txt
( 1) myDebugLog.gz
Description:Under some circumstances Meetme is stuck in a loop generating about 25 lines / sec "Unable to write frame to channel"
This seems to be very sensitive to exact timing, the following dialplan creates an endless loop of messages on my development server (have also seen this on our production server):

{code}
context originate_local {
 s => {
   Originate(Local/left@local_channels,exten,local_channels,right,1);
 }
}

context local_channels {
 left => {
   Answer();
   Meetme(1,dq);
 }
 
 right => {
   Answer();
   Wait(0.5);
 }
}
{code}

This produces the following output on the console:
{code}
[Oct  9 20:37:20] VERBOSE[21675] pbx.c:     -- Executing [s@originate_local:1] Originate("SIP/trunk-00000000", "Local/left@local_channels,exten,local_channels,right,1") in new stack
[Oct  9 20:37:20] VERBOSE[21677] pbx.c:     -- Executing [left@local_channels:1] Answer("Local/left@local_channels-00000000;2", "") in new stack
[Oct  9 20:37:20] VERBOSE[21678] pbx.c:     -- Executing [right@local_channels:1] Answer("Local/left@local_channels-00000000;1", "") in new stack
[Oct  9 20:37:20] VERBOSE[21678] pbx.c:     -- Executing [right@local_channels:2] Wait("Local/left@local_channels-00000000;1", "0.5") in new stack
[Oct  9 20:37:20] VERBOSE[21675] pbx.c:     -- Auto fallthrough, channel 'SIP/trunk-00000000' status is 'UNKNOWN'
[Oct  9 20:37:20] VERBOSE[21677] pbx.c:     -- Executing [left@local_channels:2] MeetMe("Local/left@local_channels-00000000;2", "1,dq") in new stack
[Oct  9 20:37:20] VERBOSE[21678] pbx.c:     -- Auto fallthrough, channel 'Local/left@local_channels-00000000;1' status is 'UNKNOWN'
[Oct  9 20:37:20] VERBOSE[21677] app_meetme.c:     -- Created MeetMe conference 1023 for conference '1'
[Oct  9 20:37:20] WARNING[21677] app_meetme.c: Unable to write frame to channel Local/left@local_channels-00000000;2
[Oct  9 20:37:20] WARNING[21677] app_meetme.c: Unable to write frame to channel Local/left@local_channels-00000000;2
[Oct  9 20:37:20] WARNING[21677] app_meetme.c: Unable to write frame to channel Local/left@local_channels-00000000;2
[Oct  9 20:37:20] WARNING[21677] app_meetme.c: Unable to write frame to channel Local/left@local_channels-00000000;2
[Oct  9 20:37:20] WARNING[21677] app_meetme.c: Unable to write frame to channel Local/left@local_channels-00000000;2
[Oct  9 20:37:20] WARNING[21677] app_meetme.c: Unable to write frame to channel Local/left@local_channels-00000000;2
[Oct  9 20:37:20] WARNING[21677] app_meetme.c: Unable to write frame to channel Local/left@local_channels-00000000;2
[Oct  9 20:37:20] WARNING[21677] app_meetme.c: Unable to write frame to channel Local/left@local_channels-00000000;2
[Oct  9 20:37:20] WARNING[21677] app_meetme.c: Unable to write frame to channel Local/left@local_channels-00000000;2
[Oct  9 20:37:20] WARNING[21677] app_meetme.c: Unable to write frame to channel Local/left@local_channels-00000000;2
[Oct  9 20:37:20] WARNING[21677] app_meetme.c: Unable to write frame to channel Local/left@local_channels-00000000;2
[Oct  9 20:37:20] WARNING[21677] app_meetme.c: Unable to write frame to channel Local/left@local_channels-00000000;2
[Oct  9 20:37:20] WARNING[21677] app_meetme.c: Unable to write frame to channel Local/left@local_channels-00000000;2
[Oct  9 20:37:20] WARNING[21677] app_meetme.c: Unable to write frame to channel Local/left@local_channels-00000000;2
[Oct  9 20:37:20] WARNING[21677] app_meetme.c: Unable to write frame to channel Local/left@local_channels-00000000;2
[Oct  9 20:37:20] WARNING[21677] app_meetme.c: Unable to write frame to channel Local/left@local_channels-00000000;2
[Oct  9 20:37:20] WARNING[21677] app_meetme.c: Unable to write frame to channel Local/left@local_channels-00000000;2
[Oct  9 20:37:20] WARNING[21677] app_meetme.c: Unable to write frame to channel Local/left@local_channels-00000000;2
[Oct  9 20:37:20] WARNING[21677] app_meetme.c: Unable to write frame to channel Local/left@local_channels-00000000;2
[Oct  9 20:37:20] WARNING[21677] app_meetme.c: Unable to write frame to channel Local/left@local_channels-00000000;2
[Oct  9 20:37:20] WARNING[21677] app_meetme.c: Unable to write frame to channel Local/left@local_channels-00000000;2
[Oct  9 20:37:20] WARNING[21677] app_meetme.c: Unable to write frame to channel Local/left@local_channels-00000000;2
[Oct  9 20:37:21] WARNING[21677] app_meetme.c: Unable to write frame to channel Local/left@local_channels-00000000;2
[Oct  9 20:37:21] WARNING[21677] app_meetme.c: Unable to write frame to channel Local/left@local_channels-00000000;2
[Oct  9 20:37:21] WARNING[21677] app_meetme.c: Unable to write frame to channel Local/left@local_channels-00000000;2

.
.
.
{code}

The patch in issue ASTERISK-19594 https://issues.asterisk.org/jira/secure/attachment/43067/meetme-hangup-trunk-360459.patch seems to work, but apparently only masks the problem.

Also there is ASTERISK-20486 that seems to be a duplicate of this bug.

I've tried different wait-intervals but only Wait(0.5) seems to trigger this problem and do so constantly.
Comments:By: Rusty Newton (rnewton) 2012-06-04 19:43:44.720-0500

We require a complete debug log to help triage the issue. This document will provide instructions on how to collect debugging logs from an Asterisk machine for the purpose of helping bug marshals troubleshoot an issue: https://wiki.asterisk.org/wiki/display/AST/Collecting+Debug+Information


Please get a full log with DEBUG and VERBOSE at least level 5 demonstrating the issue in the log. Point out where in the log the issue occurs.
By: Johan Wilfer (johan) 2012-06-05 02:08:48.635-0500

The patch meetme-hangup-trunk-360459.patch in issue ASTERISK-19594 seems to prevent this from reoccur.

The system has been running an Asterisk with this patch since Monday morning, and not it's now been 24 hours without the problem.

You want me to revert the patch to get the original behavior back with a debug log?
By: Johan Wilfer (johan) 2012-06-06 04:17:52.228-0500

Attached debuglog, around line 394930 you start to see:
[Jun  6 09:03:12] WARNING[29963] app_meetme.c: Unable to write frame to channel Local/388@conference_announce_event_connect_room-52ea;2

This is Asterisk 1.8.12.1 without the patch from ASTERISK-19594.
By: Matt Jordan (mjordan) 2012-06-14 08:55:16.019-0500

Thanks for the log - while that patch may have 'fixed' the issue, it may or may not be the correct solution to this problem.

What appears to have happened is that app_meetme still has a reference to a channel that should have been disposed of, given that the Local channel was hung up.
By: Johan Wilfer (johan) 2012-08-29 02:11:29.478-0500

Similar bug report: ASTERISK-19491, maybe this can provide some clues to what happens here?
By: Johan Wilfer (johan) 2012-09-10 02:05:04.913-0500

Can we please move this forward somehow?

Just verified the patch from ASTERISK-19594 has worked in production for three months now without any issue. This server is dedicated to doing conference calls 24/7..

By: Matt Jordan (mjordan) 2012-09-10 07:54:25.482-0500

The patch on ASTERISK-19594 is not going to be committed because it was not the correct solution to the problem on that issue.  As the comments state on ASTERISK-19594, the commit r357761 ended up resolving that particular issue.

In general, 'stuck' channels are indicative of something more fundamentally 'wrong', and the patch on ASTERISK-19594 would only mask the problem (and would only resolve it in MeetMe - if the channel happened to get 'stuck' in another application, it would not fix it there).

Other than that, this issue is in queue.  It will be worked as developer resources become available.
By: Johan Wilfer (johan) 2012-09-10 08:24:57.585-0500

Ok, thanks for the feedback!


By: Erik Wallin (erikw@pushtalk.se) 2012-09-10 11:22:43.684-0500

I'm seeing this, on 1.8.7.1. It's a production machine so, I'm not able to upgrade it at this time.

I only need one participant in the conference to trigger the problem. Usually it's easier to reproduce if it's done early in the conference call.

Could this have something to do with the announcement of the participant enter/leave? It seems that the problem is triggered if I hang up the last channel while an announcement is made.

I've not been able to reproduce this on a conference without announcements.

Kicking the user from the meetme conference works. It's not necessary to restart asterisk to stop the log messages or to get rid of the stuck channels.
By: Johan Wilfer (johan) 2012-09-10 12:43:49.912-0500

I'm getting this without any announcement. (Using flags: "dq"). But, I have a custom "announcement-channel" that I Originate and place into the conference. With this Local-channel I play some sounds and exit.

I don't how the builtin announcement works, but maybe this has to do with two channels entering/leaving the conference at the same time causing a race somehow?
By: Julian Yap (jyap) 2012-09-10 14:30:11.905-0500

I can reproduce this on: certified-asterisk-1.8.11-cert4

By: Johan Wilfer (johan) 2012-10-01 01:55:45.725-0500

Updated issue and added chan_local as a component.

This looks like a similar issue: ASTERISK-20486
Matt: Could both be a result of a ref count leak?
By: Michael L. Young (elguero) 2012-10-06 19:36:04.784-0500

Johan, the debug log looks a little bit different.  I am not sure if this is related or not.  Might be... not too sure.
By: Johan Wilfer (johan) 2012-10-09 14:16:34.322-0500

New debug log, asterisk is stopped right after the errors are starting to roll down the screen.
By: Johan Wilfer (johan) 2012-10-09 14:19:42.050-0500

Updated the issue with a summary how to recreate this scenario. For me the above dialplan creates this error every time.
By: Michael L. Young (elguero) 2012-10-09 15:28:50.061-0500

Johan, I think what you are seeing is that the local channel is being optimized out.  Try adding /n to the local channel and see if the error message goes away.

"Local/left@local_channels/n"
By: Johan Wilfer (johan) 2012-10-09 15:39:05.678-0500

Nope. Same thing...
By: Jonathan Rose (jrose) 2012-11-07 11:20:47.204-0600

Please follow this on ASTERISK-20486

If resolution of this issue doesn't resolve this issue, let me know and we'll reopen this. But I'm pretty confident that the one stone will kill all the birds.