[asterisk-bugs] [JIRA] Created: (ASTERISK-20548) MeetMe Unable to write frame to channel after SIP channel hangs up.
Rusty Newton (JIRA)
noreply at issues.asterisk.org
Wed Oct 10 17:33:27 CDT 2012
MeetMe Unable to write frame to channel after SIP channel hangs up.
-------------------------------------------------------------------
Key: ASTERISK-20548
URL: https://issues.asterisk.org/jira/browse/ASTERISK-20548
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
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.
For more information on JIRA, see: http://www.atlassian.com/software/jira
More information about the asterisk-bugs
mailing list