[asterisk-bugs] [JIRA] (ASTERISK-20486) MeetMe Unable to write frame to channel after SIP channel hangs up.
Michael Cargile (JIRA)
noreply at issues.asterisk.org
Wed Nov 7 11:35:21 CST 2012
[ https://issues.asterisk.org/jira/browse/ASTERISK-20486?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=199342#comment-199342 ]
Michael Cargile commented on ASTERISK-20486:
--------------------------------------------
Still getting the WARNING occasionally.
I noticed something though. When I first tested just now, I unapplied the meetme patch and applied the timer patch. I ran like that for about five minutes. I would occasionally get a single instance of that WARNING, then every so often the screen would flood with the same WARNING. I then reapplied the meetme patch, and I cannot get the flood to come back, but I am still getting the occasional instance of that warning. This makes me think that there are two different scenarios generating this.
> MeetMe Unable to write frame to channel after SIP channel hangs up.
> -------------------------------------------------------------------
>
> Key: ASTERISK-20486
> URL: https://issues.asterisk.org/jira/browse/ASTERISK-20486
> Project: Asterisk
> Issue Type: Bug
> Security Level: None
> Components: Applications/app_meetme, Channels/chan_sip/General
> Affects Versions: 1.8.16.0
> Environment: I have two asterisk boxes. One is running asterisk 1.4.43. It is acting like a test carrier. The other box is running 1.8.16.0 and is placing calls to the test carrier and routing them to MeetMe conferences.
> Reporter: Michael Cargile
> Attachments: asterisk-20486-ref-leak.diff, meetme_hangup_patch_ASTERISK-20486.diff, refs.gz, refs-with-patch, refs-with-patch.gz, timer_patch_ASTERISK-20486.diff
>
>
> Basically it looks like in some instances MeetMe is still trying to pass frames to a channel that should have hung up. If you look the caller id name which we use as a Unique ID matches the caller id name in the BYE event before this error. It looks like it is generating about 50 errors per second for one of these calls. I am not sure if this is a SIP issue, or a MeetMe issue. I think this might be related to this issue:
> ASTERISK-19594
> but that one has already been closed.
> Output from AGI script called before getting into the MeetMe conference to show the channel as well as the calleridname (which we use to keep track of the call):
> {noformat}
> 2012-09-28 15:14:33|agi-VDAD_ALL_outbound.agi|AGI Environment Dump:
> 2012-09-28 15:14:33|agi-VDAD_ALL_outbound.agi| -- accountcode =
> 2012-09-28 15:14:33|agi-VDAD_ALL_outbound.agi| -- arg_1 = NORMAL-----LB
> 2012-09-28 15:14:33|agi-VDAD_ALL_outbound.agi| -- callerid = 8633939330
> 2012-09-28 15:14:33|agi-VDAD_ALL_outbound.agi| -- calleridname = V9281514180000238212
> 2012-09-28 15:14:33|agi-VDAD_ALL_outbound.agi| -- callingani2 = 0
> 2012-09-28 15:14:33|agi-VDAD_ALL_outbound.agi| -- callingpres = 0
> 2012-09-28 15:14:33|agi-VDAD_ALL_outbound.agi| -- callingtns = 0
> 2012-09-28 15:14:33|agi-VDAD_ALL_outbound.agi| -- callington = 0
> 2012-09-28 15:14:33|agi-VDAD_ALL_outbound.agi| -- channel = SIP/testcarrier-00017f4b
> 2012-09-28 15:14:33|agi-VDAD_ALL_outbound.agi| -- context = default
> 2012-09-28 15:14:33|agi-VDAD_ALL_outbound.agi| -- dnid = unknown
> 2012-09-28 15:14:33|agi-VDAD_ALL_outbound.agi| -- enhanced = 0.0
> 2012-09-28 15:14:33|agi-VDAD_ALL_outbound.agi| -- extension = 8368
> 2012-09-28 15:14:33|agi-VDAD_ALL_outbound.agi| -- language = en
> 2012-09-28 15:14:33|agi-VDAD_ALL_outbound.agi| -- priority = 3
> 2012-09-28 15:14:33|agi-VDAD_ALL_outbound.agi| -- rdnis = unknown
> 2012-09-28 15:14:33|agi-VDAD_ALL_outbound.agi| -- request = agi-VDAD_ALL_outbound.agi
> 2012-09-28 15:14:33|agi-VDAD_ALL_outbound.agi| -- threadid = -1268466832
> 2012-09-28 15:14:33|agi-VDAD_ALL_outbound.agi| -- type = SIP
> 2012-09-28 15:14:33|agi-VDAD_ALL_outbound.agi| -- uniqueid = 1348859661.314636
> 2012-09-28 15:14:33|agi-VDAD_ALL_outbound.agi| -- version = 1.8.16.0
> {noformat}
> Asterisk CLI output with SIP debugging enabled:
> {noformat}
> [Sep 28 15:14:35] -- Executing [8600058 at default:1] MeetMe("SIP/testcarrier-00017f4b", "8600058,F") in new stack
> [Sep 28 15:14:35] == Parsing '/etc/asterisk/meetme.conf': [Sep 28 15:14:35] == Found
> [Sep 28 15:14:35] == Parsing '/etc/asterisk/meetme-vicidial.conf': [Sep 28 15:14:35] == Found
> [Sep 28 15:14:35] -- Created MeetMe conference 1022 for conference '8600058'
> [Sep 28 15:14:35] -- <SIP/testcarrier-00017f4b> Playing 'conf-onlyperson.gsm' (language 'en')
> ...
> [Sep 28 15:14:38]
> <--- Transmitting (NAT) to 192.168.198.14:5060 --->
> SIP/2.0 200 OK
> Via: SIP/2.0/UDP 192.168.198.14:5060;branch=z9hG4bK099f4e9c;received=192.168.198.14;rport=5060
> From: <sip:9999024387 at 192.168.198.14>;tag=as657a2bf3
> To: "V9281514180000238212" <sip:8633939330 at 192.168.198.15>;tag=as4bc64123
> Call-ID: 05a3c6f264fb72905243ca216bb0eba2 at 192.168.198.15:5060
> CSeq: 102 BYE
> Server: Asterisk PBX 1.8.16.0
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
> Supported: replaces, timer
> Content-Length: 0
> ...
> [Sep 28 15:14:39] WARNING[3688]: app_meetme.c:3678 conf_run: Unable to write frame to channel SIP/testcarrier-00017f4b
> [Sep 28 15:14:39] WARNING[3688]: app_meetme.c:3678 conf_run: Unable to write frame to channel SIP/testcarrier-00017f4b
> [Sep 28 15:14:39] WARNING[3688]: app_meetme.c:3678 conf_run: Unable to write frame to channel SIP/testcarrier-00017f4b
> [Sep 28 15:14:39] WARNING[3688]: app_meetme.c:3678 conf_run: Unable to write frame to channel SIP/testcarrier-00017f4b
> [Sep 28 15:14:39] WARNING[3688]: app_meetme.c:3678 conf_run: Unable to write frame to channel SIP/testcarrier-00017f4b
> [Sep 28 15:14:39] WARNING[3688]: app_meetme.c:3678 conf_run: Unable to write frame to channel SIP/testcarrier-00017f4b
> [Sep 28 15:14:39] WARNING[3688]: app_meetme.c:3678 conf_run: Unable to write frame to channel SIP/testcarrier-00017f4b
> [Sep 28 15:14:39] WARNING[3688]: app_meetme.c:3678 conf_run: Unable to write frame to channel SIP/testcarrier-00017f4b
> [Sep 28 15:14:39] WARNING[3688]: app_meetme.c:3678 conf_run: Unable to write frame to channel SIP/testcarrier-00017f4b
> [Sep 28 15:14:39] WARNING[3688]: app_meetme.c:3678 conf_run: Unable to write frame to channel SIP/testcarrier-00017f4b
> ...
> [Sep 28 15:14:45] WARNING[3688]: app_meetme.c:3678 conf_run: Unable to write frame to channel SIP/testcarrier-00017f4b
> [Sep 28 15:14:45] WARNING[8004]: chan_sip.c:3918 __sip_autodestruct: Autodestruct on dialog '05a3c6f264fb72905243ca216bb0eba2 at 192.168.198.15:5060' with owner in place (Method: BYE). Rescheduling destruc
> tion for 10000 ms
> [Sep 28 15:14:45] -- Hungup 'DAHDI/pseudo-753634465'
> [Sep 28 15:14:45] == Spawn extension (default, 8600058, 1) exited non-zero on 'SIP/testcarrier-00017f4b'
> [Sep 28 15:14:45] -- Executing [h at default:1] AGI("SIP/testcarrier-00017f4b", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----111---------------") in new stack
> {noformat}
> 1.8 extension.conf
> {noformat}
> ; global varibale for carrier
> TESTSIPTRUNK = SIP/testcarrier
> ; Outbound dial to test carrier
> exten => _91999NXXXXXX,1,AGI(agi://127.0.0.1:4577/call_log)
> exten => _91999NXXXXXX,2,Dial(${TESTSIPTRUNK}/${EXTEN:2},,To)
> exten => _91999NXXXXXX,3,Hangup
> ; agent connection
> exten => _999999999999,1,AGI(agi://127.0.0.1:4577/call_log)
> exten => _999999999999,2,Dial(${TESTSIPTRUNK}/${EXTEN},,To)
> exten => _999999999999,3,Hangup
> ; routing extension
> exten => 8368,1,Playback(sip-silence)
> exten => 8368,n,AGI(agi://127.0.0.1:4577/call_log)
> exten => 8368,n,AGI(agi-VDAD_ALL_outbound.agi,NORMAL-----LB)
> exten => 8368,n,AGI(agi-VDAD_ALL_outbound.agi,NORMAL-----LB)
> exten => 8368,n,Hangup()
> ; meetme conference extensions
> exten => _86000[5-9]X,1,Meetme(${EXTEN},F)
> exten => _86000[5-9]X,n,Hangup()
> exten => _8600[1-2]XX,1,Meetme(${EXTEN},F)
> exten => _8600[1-2]XX,n,Hangup()
> {noformat}
> 1.4 extension.conf
> {noformat}
> ; PERFORMANCE TESTING
> exten => _999XXXXXX1,1,Answer
> exten => _999XXXXXX1,2,Wait(2)
> exten => _999XXXXXX1,3,Playback(vicidial-welcome)
> exten => _999XXXXXX1,4,Hangup
> exten => _999XX11112,1,Wait(2)
> exten => _999XX11112,2,Answer
> exten => _999XX11112,3,Playback(ss-noservice)
> exten => _999XX11112,4,Playback(vm-goodbye)
> exten => _999XX11112,5,Hangup
> exten => _999XX18112,1,Wait(2)
> exten => _999XX18112,2,Answer
> exten => _999XX18112,3,Playback(vtiger-fax)
> exten => _999XX18112,4,Playback(vtiger-fax)
> exten => _999XX18112,5,Hangup
> exten => _999XX19112,1,Wait(2)
> exten => _999XX19112,2,Answer
> exten => _999XX19112,3,Playback(vtiger-email)
> exten => _999XX19112,4,Playback(vtiger-email)
> exten => _999XX19112,5,Hangup
> exten => _999XXXX112,1,Wait(5)
> exten => _999XXXX112,2,Answer
> exten => _999XXXX112,3,Playback(demo-instruct)
> exten => _999XXXX112,4,Playback(demo-instruct)
> exten => _999XXXX112,5,Hangup
> exten => _999XXXXXX2,1,Wait(8)
> exten => _999XXXXXX2,2,Answer
> exten => _999XXXXXX2,3,Playback(demo-instruct)
> exten => _999XXXXXX2,4,Hangup
> exten => _999XXXXXX3,1,Set(PRI_CAUSE=1)
> exten => _999XXXXXX3,2,Hangup
> exten => _999XXXXXX4,1,Set(PRI_CAUSE=27)
> exten => _999XXXXXX4,2,Hangup
> exten => _999XXXXXX5,1,Wait(60)
> exten => _999XXXXXX5,2,Hangup
> exten => _999XXXXXX6,1,Wait(10)
> exten => _999XXXXXX6,2,Answer
> exten => _999XXXXXX6,3,Playback(demo-instruct)
> exten => _999XXXXXX6,4,Hangup
> exten => _999XXXXXX7,1,Wait(12)
> exten => _999XXXXXX7,2,Answer
> exten => _999XXXXXX7,3,Playback(demo-enterkeywords)
> exten => _999XXXXXX7,4,Hangup
> exten => _999XXXXXX8,1,Set(PRI_CAUSE=17)
> exten => _999XXXXXX8,2,Hangup
> exten => _999XXXXXX9,1,Wait(6)
> exten => _999XXXXXX9,2,Answer
> exten => _999XXXXXX9,3,Playback(demo-abouttotry)
> exten => _999XXXXXX9,4,Hangup
> exten => _999XXXXXX0,1,Wait(5)
> exten => _999XXXXXX0,2,Answer
> exten => _999XXXXXX0,3,Playback(vm-goodbye)
> exten => _999XXXXXX0,4,Hangup
> ; agent playback
> exten => 99999999999,1,Answer
> exten => 99999999999,2,Playback(conf)
> exten => 99999999999,3,Playback(conf)
> exten => 99999999999,4,Playback(conf)
> exten => 99999999999,5,Playback(conf)
> exten => 99999999999,6,Playback(conf)
> exten => 99999999999,7,Playback(conf)
> exten => 99999999999,8,Playback(conf)
> exten => 99999999999,9,Playback(conf)
> exten => 99999999999,10,Playback(conf)
> exten => 99999999999,11,Playback(conf)
> exten => 99999999999,12,Playback(conf)
> exten => 99999999999,13,Playback(conf)
> exten => 99999999999,14,Hangup
> {noformat}
> 1.8 sip.conf
> {noformat}
> [testcarrier]
> type=peer
> context=trunkinbound
> usecallerid=yes
> trustrpid=yes
> sendrpid=yes
> host=192.168.198.14
> qualify=yes
> insecure=port,invite
> disallow=all
> allow=ulaw
> dtmfmode=RFC2833
> {noformat}
> 1.4 sip.conf
> {noformat}
> [testcarrier]
> type=peer
> context=trunkinbound
> usecallerid=yes
> trustrpid=yes
> sendrpid=yes
> host=192.168.198.15
> qualify=yes
> insecure=port,invite
> disallow=all
> allow=ulaw
> dtmfmode=RFC2833
> {noformat}
> System in question is being used to port the Vicidial Call Center Suite over to Asterisk 1.8. It is currently operating in test mode.
> In test mode agents are simulated by originating a call with a Local channel. The local channel is pointed at the 999999999999 extension which routes through to the 1.4 test carrier. On the test carrier the call ends up in an extension that plays classical music for 12 hours. The extension for the originated call is one of the meetme conferences. This calls stays there throughout the test.
> Outbound calls are originated as a Local channel as well. The Local channel is pointed at the 91999NXXXXXX extension depending on the "phone number" being dialed. This routed through to the 1.4 test carrier where depending on what "phone number" was dialed different things happen. The extension for the originated call is the 8368. This extension first plays sip-silence which is a 40ms sound file of nothing. This gives the Local channel a chance to optimize out as this is only done during processing of audio frames and Vicidial was written at a time when Asterisk had issues routing Local channels so refuses to do so. Next the call is logged in Vicidial with the call_log AGI and then goes into the outbound routing AGI. There it finds an agent that is available to take the call and then transfers the call to the MeetMe conference that is associated with that agent.
> As stated this error pops up occasionally. With five 'agents' logged in and about 15 'calls' being attempted at any given time it tends to take about 15 to 30 minutes before this pops up. If I up the number of 'agent' and 'calls' it can take as little as five minutes.
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
More information about the asterisk-bugs
mailing list