Hi All,
I missed some details in my last email, so please ignore that one and
read this one instead. Thank You.
I've written an AMI interface and it's been working for the last few
years. I am currently working on a new feature and came across an issue
where Asterisk stops processing AGI requests (issued via AMI), making it
impossible to then even physically hang up a channel (until the next
call comes in on that channel)!
The problem is that if I try to redirect a ChanSpy SpyerChannel to an
extension priority that should put the channel into AGI(agi:async) mode,
the redirect action never occurs. While I get the response that the
redirect is successful, the actual AGI(agi:async) event never
occurs/never shows up on either the CLI or within the AMI responses
(from Asterisk). The CLI shows the SpyerChannel to be stuck in ChanSpy
mode.
Note/In Addition: Although not in the output I'm currently providing,
after the redirect attempt (to redirect the SpyerChannel channel out of
ChanSpy mode) I've even tried issuing (via AMI): Command: EXEC
SoftHangup and Command: EXEC Hangup and when I do I just get a response
that the AGI command is queue'd and nothing further from the channel.
After a few issued Redirect commands (again after the attempt to
redirect the SpyerChannel channel out of ChanSpy mode), I've even gotten
some "Error" responses with "Message: Redirect failed, channel not up".
If I try physically hanging up the DAHDI trunk, after issuing the first
redirect request, that still doesn't hang up and/or cause the commands
to execute (per the CLI). However, if I physically hang up the
SpyerChannel DAHDI trunk without issuing any Redirect commands to it
then the ChanSpyEnd AMI command does come in and the channel does indeed
hangup. Also: If I put both channels into a MeetMe conference then the
ChanSpyEnd AMI command also comes in..but it would be rediculous to do
that just to the ends up then hanging up the SpyerChannel! That being
said: If I'm missing something then I'm open to suggestions.
Here are the relevant extensions you'll need to know what the priorities
I am redirecting to should do:
exten => testbox,6(abort_voice),Verbose(1,Abort Complete: ${CHANNEL})
exten => testbox,7,AGI(agi:async)
exten => testbox,77(one_way_conn),AGI(agi:async)
Here are the AMI commands I issued around the issue, with timestamps and
some inline comments:
2016-07-06 13:41:55.248900 ><<<<<<< Action: Redirect
2016-07-06 13:41:55.257217 ><<<<<<< Channel: DAHDI/i1/5144213700-105
2016-07-06 13:41:55.257217 ><<<<<<< Exten: testbox
2016-07-06 13:41:55.257217 ><<<<<<< Priority: one_way_conn
2016-07-06 13:41:55.257217 ><<<<<<< Context: phones-context
2016-07-06 13:41:55.257217 ><<<<<<< ActionID: 1811486554
2016-07-06 13:41:55.257217 ><<<<<<<
2016-07-06 13:41:55.257217 ><<<<<<< Action: AGI
2016-07-06 13:41:55.258040 ><<<<<<< Channel: DAHDI/i1/5144213700-105
2016-07-06 13:41:55.258040 ><<<<<<< Command: EXEC ChanSpy DAHDI/25-1,Bwq
2016-07-06 13:41:55.258040 ><<<<<<< Exten: testbox
2016-07-06 13:41:55.258040 ><<<<<<< Priority: 7
2016-07-06 13:41:55.258040 ><<<<<<< Context: phones-context
2016-07-06 13:41:55.258040 ><<<<<<< ActionID: 1811486555
2016-07-06 13:41:55.258040 ><<<<<<<
2016-07-06 13:41:55.258040 <>>>>>>> Response: Success
2016-07-06 13:41:55.258374 <>>>>>>> ActionID: 1811486554
2016-07-06 13:41:55.258374 <>>>>>>> Message: Redirect successful
2016-07-06 13:41:55.258374 <>>>>>>>
2016-07-06 13:41:55.258374 <>>>>>>> Event: AsyncAGI
2016-07-06 13:41:55.258374 <>>>>>>> Privilege: agi,all
2016-07-06 13:41:55.258374 <>>>>>>> SubEvent: Exec
2016-07-06 13:41:55.258374 <>>>>>>> Channel: DAHDI/i1/5144213700-105
2016-07-06 13:41:55.258374 <>>>>>>> Result: 200%20result%3D-1%0A
2016-07-06 13:41:55.258374 <>>>>>>>
2016-07-06 13:41:55.258374 <>>>>>>> Event: AsyncAGI
2016-07-06 13:41:55.258374 <>>>>>>> Privilege: agi,all
2016-07-06 13:41:55.258374 <>>>>>>> SubEvent: End
2016-07-06 13:41:55.258374 <>>>>>>> Channel: DAHDI/i1/5144213700-105
2016-07-06 13:41:55.258374 <>>>>>>>
2016-07-06 13:41:55.258374 <>>>>>>> Event: VarSet
2016-07-06 13:41:55.258374 <>>>>>>> Privilege: dialplan,all
2016-07-06 13:41:55.258374 <>>>>>>> Channel: DAHDI/i1/5144213700-105
2016-07-06 13:41:55.258374 <>>>>>>> Variable: AGISTATUS
2016-07-06 13:41:55.258374 <>>>>>>> Value: HANGUP
2016-07-06 13:41:55.258374 <>>>>>>> Uniqueid: 1467826896.691
2016-07-06 13:41:55.258374 <>>>>>>>
2016-07-06 13:41:55.258374 <>>>>>>> Event: Newexten
2016-07-06 13:41:55.258374 <>>>>>>> Privilege: dialplan,all
2016-07-06 13:41:55.258374 <>>>>>>> Channel: DAHDI/i1/5144213700-105
2016-07-06 13:41:55.258374 <>>>>>>> Context: phones-context
2016-07-06 13:41:55.258374 <>>>>>>> Extension: testbox
2016-07-06 13:41:55.258374 <>>>>>>> Priority: 77
2016-07-06 13:41:55.258374 <>>>>>>> Application: AGI
2016-07-06 13:41:55.258374 <>>>>>>> AppData: agi:async
2016-07-06 13:41:55.258374 <>>>>>>> Uniqueid: 1467826896.691
2016-07-06 13:41:55.258374 <>>>>>>>
2016-07-06 13:41:55.258374 <>>>>>>> Event: AsyncAGI
2016-07-06 13:41:55.258374 <>>>>>>> Privilege: agi,all
2016-07-06 13:41:55.258374 <>>>>>>> SubEvent: Start
2016-07-06 13:41:55.258374 <>>>>>>> Channel: DAHDI/i1/5144213700-105
2016-07-06 13:41:55.258374 <>>>>>>> Env:
agi_request%3A%20async%0Aagi_channel%3A%20DAHDI%2Fi1%2F5144213700-105%0Aagi_language%3A%20en%0Aagi_type%3A%20DAHDI%0Aagi_uniqueid%3A%201467826896.691%0Aagi_version%3A%2011.2.1%0Aagi_callerid%3A%205144213700%0Aagi_calleridname%3A%20unknown%0Aagi_callingpres%3A%200%0Aagi_callingani2%3A%200%0Aagi_callington%3A%201%0Aagi_callingtns%3A%200%0Aagi_dnid%3A%207770002%0Aagi_rdnis%3A%20unknown%0Aagi_context%3A%20phones-context%0Aagi_extension%3A%20testbox%0Aagi_priority%3A%2077%0Aagi_enhanced%3A%200.0%0Aagi_accountcode%3A%20%0Aagi_threadid%3A%20139683789784832%0A%0A
2016-07-06 13:41:55.258374 <>>>>>>>
2016-07-06 13:41:55.258374 <>>>>>>> Response: Success
2016-07-06 13:41:55.258374 <>>>>>>> ActionID: 1811486555
2016-07-06 13:41:55.258374 <>>>>>>> Message: Added AGI command to queue
2016-07-06 13:41:55.258374 <>>>>>>>
2016-07-06 13:41:55.258374 <>>>>>>> Event: AGIExec
2016-07-06 13:41:55.268871 <>>>>>>> Privilege: agi,all
2016-07-06 13:41:55.268871 <>>>>>>> SubEvent: Start
2016-07-06 13:41:55.268871 <>>>>>>> Channel: DAHDI/i1/5144213700-105
2016-07-06 13:41:55.268871 <>>>>>>> CommandId: 474622134
2016-07-06 13:41:55.268871 <>>>>>>> Command: EXEC ChanSpy DAHDI/25-1,Bwq
2016-07-06 13:41:55.268871 <>>>>>>>
2016-07-06 13:41:55.268871 <>>>>>>> Event: ChanSpyStart
2016-07-06 13:41:55.369354 <>>>>>>> Privilege: call,all
2016-07-06 13:41:55.369354 <>>>>>>> SpyerChannel: DAHDI/i1/5144213700-105
2016-07-06 13:41:55.369354 <>>>>>>> SpyeeChannel: DAHDI/25-1
2016-07-06 13:41:55.369354 <>>>>>>>
2016-07-06 13:41:55.369354 ><<<<<<< Action: Redirect
2016-07-06 13:42:13.513395 ><<<<<<< Channel: DAHDI/25-1
2016-07-06 13:42:13.513395 ><<<<<<< Exten: operator
2016-07-06 13:42:13.513395 ><<<<<<< Priority: one_way_conn
2016-07-06 13:42:13.513395 ><<<<<<< Context: phones-context
2016-07-06 13:42:13.513395 ><<<<<<< ActionID: 1811486556
2016-07-06 13:42:13.513395 ><<<<<<<
Here's where I try to redirect SpyerChannel to AGI(agi:async), in order
to get it out of/end ChanSpy
(Note: I'm even redirecting the SpyeeChannel, as above, to no avail):
2016-07-06 13:42:13.513395 ><<<<<<< Action: Redirect
2016-07-06 13:42:13.514265 ><<<<<<< Channel: DAHDI/i1/5144213700-105
2016-07-06 13:42:13.514265 ><<<<<<< Exten: testbox
2016-07-06 13:42:13.514265 ><<<<<<< Priority: one_way_conn
2016-07-06 13:42:13.514265 ><<<<<<< Context: phones-context
2016-07-06 13:42:13.514265 ><<<<<<< ActionID: 1811486557
2016-07-06 13:42:13.514265 ><<<<<<<
2016-07-06 13:42:13.514265 <>>>>>>> Response: Success
2016-07-06 13:42:13.514384 <>>>>>>> ActionID: 1811486556
2016-07-06 13:42:13.514384 <>>>>>>> Message: Redirect successful
2016-07-06 13:42:13.514384 <>>>>>>>
2016-07-06 13:42:13.514384 <>>>>>>> Event: AsyncAGI
2016-07-06 13:42:13.514384 <>>>>>>> Privilege: agi,all
2016-07-06 13:42:13.514384 <>>>>>>> SubEvent: End
2016-07-06 13:42:13.514384 <>>>>>>> Channel: DAHDI/25-1
2016-07-06 13:42:13.514384 <>>>>>>>
2016-07-06 13:42:13.514384 <>>>>>>> Event: VarSet
2016-07-06 13:42:13.514384 <>>>>>>> Privilege: dialplan,all
2016-07-06 13:42:13.514384 <>>>>>>> Channel: DAHDI/25-1
2016-07-06 13:42:13.514384 <>>>>>>> Variable: AGISTATUS
2016-07-06 13:42:13.514384 <>>>>>>> Value: HANGUP
2016-07-06 13:42:13.514384 <>>>>>>> Uniqueid: 1467826872.690
2016-07-06 13:42:13.514384 <>>>>>>>
2016-07-06 13:42:13.514384 <>>>>>>> Event: Newexten
2016-07-06 13:42:13.514384 <>>>>>>> Privilege: dialplan,all
2016-07-06 13:42:13.514384 <>>>>>>> Channel: DAHDI/25-1
2016-07-06 13:42:13.514384 <>>>>>>> Context: phones-context
2016-07-06 13:42:13.514384 <>>>>>>> Extension: operator
2016-07-06 13:42:13.514384 <>>>>>>> Priority: 77
2016-07-06 13:42:13.514384 <>>>>>>> Application: AGI
2016-07-06 13:42:13.514384 <>>>>>>> AppData: agi:async
2016-07-06 13:42:13.514384 <>>>>>>> Uniqueid: 1467826872.690
2016-07-06 13:42:13.514384 <>>>>>>>
2016-07-06 13:42:13.514384 <>>>>>>> Event: AsyncAGI
2016-07-06 13:42:13.514384 <>>>>>>> Privilege: agi,all
2016-07-06 13:42:13.514384 <>>>>>>> SubEvent: Start
2016-07-06 13:42:13.514384 <>>>>>>> Channel: DAHDI/25-1
2016-07-06 13:42:13.514384 <>>>>>>> Env:
agi_request%3A%20async%0Aagi_channel%3A%20DAHDI%2F25-1%0Aagi_language%3A%20en%0Aagi_type%3A%20DAHDI%0Aagi_uniqueid%3A%201467826872.690%0Aagi_version%3A%2011.2.1%0Aagi_callerid%3A%205144213737%0Aagi_calleridname%3A%20Inbound%20Analog%20Channels%0Aagi_callingpres%3A%200%0Aagi_callingani2%3A%200%0Aagi_callington%3A%200%0Aagi_callingtns%3A%200%0Aagi_dnid%3A%20unknown%0Aagi_rdnis%3A%20unknown%0Aagi_context%3A%20phones-context%0Aagi_extension%3A%20operator%0Aagi_priority%3A%2077%0Aagi_enhanced%3A%200.0%0Aagi_accountcode%3A%20%0Aagi_threadid%3A%20139683790292736%0A%0A
2016-07-06 13:42:13.514384 <>>>>>>>
2016-07-06 13:42:13.514384 ><<<<<<< Action: Redirect
2016-07-06 13:42:13.520744 ><<<<<<< Channel: DAHDI/25-1
2016-07-06 13:42:13.520744 ><<<<<<< Exten: operator
2016-07-06 13:42:13.520744 ><<<<<<< Priority: abort_voice
2016-07-06 13:42:13.520744 ><<<<<<< Context: phones-context
2016-07-06 13:42:13.520744 ><<<<<<< ActionID: 1811486558
2016-07-06 13:42:13.520744 ><<<<<<<
2016-07-06 13:42:13.520744 <>>>>>>> Response: Success
2016-07-06 13:42:13.520852 <>>>>>>> ActionID: 1811486557
2016-07-06 13:42:13.520852 <>>>>>>> Message: Redirect successful
2016-07-06 13:42:13.520852 <>>>>>>>
2016-07-06 13:42:13.520852 <>>>>>>> Response: Success
2016-07-06 13:42:13.520852 <>>>>>>> ActionID: 1811486558
2016-07-06 13:42:13.520852 <>>>>>>> Message: Redirect successful
2016-07-06 13:42:13.521943 <>>>>>>>
2016-07-06 13:42:13.521943 <>>>>>>> Event: AsyncAGI
2016-07-06 13:42:13.521943 <>>>>>>> Privilege: agi,all
2016-07-06 13:42:13.521943 <>>>>>>> SubEvent: End
2016-07-06 13:42:13.521943 <>>>>>>> Channel: DAHDI/25-1
2016-07-06 13:42:13.521943 <>>>>>>>
2016-07-06 13:42:13.521943 <>>>>>>> Event: VarSet
2016-07-06 13:42:13.521943 <>>>>>>> Privilege: dialplan,all
2016-07-06 13:42:13.521943 <>>>>>>> Channel: DAHDI/25-1
2016-07-06 13:42:13.521943 <>>>>>>> Variable: AGISTATUS
2016-07-06 13:42:13.521943 <>>>>>>> Value: HANGUP
2016-07-06 13:42:13.521943 <>>>>>>> Uniqueid: 1467826872.690
2016-07-06 13:42:13.521943 <>>>>>>>
2016-07-06 13:42:13.521943 <>>>>>>> Event: Newexten
2016-07-06 13:42:13.521943 <>>>>>>> Privilege: dialplan,all
2016-07-06 13:42:13.521943 <>>>>>>> Channel: DAHDI/25-1
2016-07-06 13:42:13.521943 <>>>>>>> Context: phones-context
2016-07-06 13:42:13.521943 <>>>>>>> Extension: operator
2016-07-06 13:42:13.521943 <>>>>>>> Priority: 6
2016-07-06 13:42:13.521943 <>>>>>>> Application: Verbose
2016-07-06 13:42:13.521943 <>>>>>>> AppData: 1,Abort Complete: DAHDI/25-1
2016-07-06 13:42:13.521943 <>>>>>>> Uniqueid: 1467826872.690
2016-07-06 13:42:13.521943 <>>>>>>>
2016-07-06 13:42:13.521943 <>>>>>>> Event: Newexten
2016-07-06 13:42:13.521943 <>>>>>>> Privilege: dialplan,all
2016-07-06 13:42:13.521943 <>>>>>>> Channel: DAHDI/25-1
2016-07-06 13:42:13.521943 <>>>>>>> Context: phones-context
2016-07-06 13:42:13.521943 <>>>>>>> Extension: operator
2016-07-06 13:42:13.521943 <>>>>>>> Priority: 7
2016-07-06 13:42:13.521943 <>>>>>>> Application: AGI
2016-07-06 13:42:13.521943 <>>>>>>> AppData: agi:async
2016-07-06 13:42:13.521943 <>>>>>>> Uniqueid: 1467826872.690
2016-07-06 13:42:13.521943 <>>>>>>>
2016-07-06 13:42:13.521943 <>>>>>>> Event: AsyncAGI
2016-07-06 13:42:13.521943 <>>>>>>> Privilege: agi,all
2016-07-06 13:42:13.521943 <>>>>>>> SubEvent: Start
2016-07-06 13:42:13.521943 <>>>>>>> Channel: DAHDI/25-1
2016-07-06 13:42:13.521943 <>>>>>>> Env:
agi_request%3A%20async%0Aagi_channel%3A%20DAHDI%2F25-1%0Aagi_language%3A%20en%0Aagi_type%3A%20DAHDI%0Aagi_uniqueid%3A%201467826872.690%0Aagi_version%3A%2011.2.1%0Aagi_callerid%3A%205144213737%0Aagi_calleridname%3A%20Inbound%20Analog%20Channels%0Aagi_callingpres%3A%200%0Aagi_callingani2%3A%200%0Aagi_callington%3A%200%0Aagi_callingtns%3A%200%0Aagi_dnid%3A%20unknown%0Aagi_rdnis%3A%20unknown%0Aagi_context%3A%20phones-context%0Aagi_extension%3A%20operator%0Aagi_priority%3A%207%0Aagi_enhanced%3A%200.0%0Aagi_accountcode%3A%20%0Aagi_threadid%3A%20139683790292736%0A%0A
==> At this point it doesn't matter if I hang up the phone headset or
not, I get nothing further from Asterisk on the AMI connection.
Here is the output from the CLI, to go along with the above AMI logs:
-- Executing [testbox@phones-context:77]
AGI("DAHDI/i1/5144213700-105", "agi:async") in new stack
-- AGI Script Executing Application: (ChanSpy) Options:
(DAHDI/25-1,Bwq)
== Spying on channel DAHDI/25-1
[Jul 6 13:41:55] NOTICE[22720][C-0000020d]: app_chanspy.c:487
start_spying: Attaching DAHDI/i1/5144213700-105 to DAHDI/25-1
[Jul 6 13:41:55] NOTICE[22720][C-0000020d]: app_chanspy.c:487
start_spying: Attaching DAHDI/i1/5144213700-105 to DAHDI/25-1
== Spawn extension (phones-context, operator, 77) exited non-zero on
'DAHDI/25-1'
-- Executing [operator@phones-context:77] AGI("DAHDI/25-1",
"agi:async") in new stack
== Spawn extension (phones-context, operator, 6) exited non-zero on
'DAHDI/25-1'
-- Executing [operator@phones-context:6] Verbose("DAHDI/25-1",
"1,Abort Complete: DAHDI/25-1") in new stack
Abort Complete: DAHDI/25-1
-- Executing [operator@phones-context:7] AGI("DAHDI/25-1",
"agi:async") in new stack
-- Span 1: Channel 0/1 got hangup request, cause 16
-- Span 1: Channel 0/1 got hangup, cause 16
==> Notice how the "agi:async" (from the redirect) on "DAHDI/25-1"
SpyeeChannel occurs, but it never occurs on the DAHDI/i1/5144213700-105
channel (the SpyerChannel) despite having been issued back-to-back. Also
notice that the hangup CLI output occurred AFTER I physically hung up
the headset, yet nothing showed up in the AMI communication and the
SpyerChannel still shows up in the CLI output (see below) after this occurs!
Here's the "core show channels" command I then issued, so you can see
that BOTH Spyee and Spyer channels are still active and the Spyer
channel (DAHDI/i1/5144213700-105) is still listed as being in ChanSpy
and listening to the SpyeeChannel (DAHDI/25-1) :
daniel*CLI> core show channels
Channel Location State Application(Data)
DAHDI/i1/5144213700- testbox@phones-context Up ChanSpy(DAHDI/25-1,Bwq)
DAHDI/25-1 operator@phones-context Rsrvd AGI(agi:async)
2 active channels
Note: If you believe I should issue a bug report for this then please
let me know and I will put all this info into it. I just figured it
would be better to address this to this list first.
Thank You for all your help in advance,
Daniel
--
Daniel McFarlane
Szeto Technologies Inc.
885 Ellingham Ave
Pointe Claire, Québec
Canada, H9R 5E8
tel: (514) 630-7878
fax: (514) 630-6394
http://www.szeto.ca
--
_____________________________________________________________________
-- Bandwidth and Colocation Provided by http://www.api-digital.com --
asterisk-dev mailing list
To UNSUBSCRIBE or update options visit:
http://lists.digium.com/mailman/listinfo/asterisk-dev
