[Home]

Summary:ASTERISK-25563: Channel Hangup after DTMF during Playback
Reporter:Martin Vogt (martinvogt.xcom)Labels:
Date Opened:2015-11-16 07:17:32.000-0600Date Closed:2015-11-19 09:05:42.000-0600
Priority:MajorRegression?
Status:Closed/CompleteComponents:Applications/app_playback Resources/res_agi
Versions:13.4.0 13.6.0 Frequency of
Occurrence		Constant
Related
Issues:
Environment:CentOS 7 in KVM Virtual MachineAttachments:( 0) debug9_25563.txt
Description:We have an Adhearsion based AGI application.
In Adheasion we use the function menu that starts the playback function in asterisk.
If we send a dtmf to the channel during the playback, the normal behavior should be that asterisk stops the playback an continues the agi application. but we get a hangup on the channel.

extensions.conf:
{noformat}
[from_sip]
exten => 777,1,NoOp(Extension: ${EXTEN})
exten => 777,2,Set(AGI_HOST=127.0.0.1)
exten => 777,3,Goto(menu_test,${EXTEN},1)

[menu_test]
exten => _777,1,AGI(agi:async)  
{noformat}

adhearsion dialplan:
{noformat}
class TestController < Adhearsion::CallController

 def run

   answer

   # menu %w(file://vm-press file://vm-first file://vm-for file://vm-password), :limit => 1, :timeout => 5.seconds do
   menu %w(file://vm-press file://vm-first file://vm-for file://vm-password), :terminator => '#' do
     match [1, 2, 3] do |dial|
       logger.info "Caller pressed #{dial}"
     end
   end

   play 'file://vm-pls-try-again'

   #####################################
   # this menu is never audible
   #####################################
   menu %w(file://vm-press file://vm-first file://vm-for file://vm-password), :limit => 1 do
     match [1, 2, 3] do |dial|
       logger.info "Caller pressed #{dial}"
     end
   end

   hangup

 end
end
{noformat}

{noformat}
SIP/111 dials 777 ---> 777@from_sip ---> 777@menu_test ---> AGI ---> menu (adhearsion) ---> Playback(asterisk) ---> dtmf to channel ---> hangup
{noformat}

We did a tcpdump and found out that adhearsion is not sending the hangup request to asterisk. So we think asterisk clears the call on its own.

We have already opened an issue on the adhearsion bug tracker: https://github.com/adhearsion/adhearsion-asr/issues/29
The Adhearsion developement team also thinks that asterisk clears the call by itself.

debug logs follow...
Comments:By: Asterisk Team (asteriskteam) 2015-11-16 07:17:33.587-0600

Thanks for creating a report! The issue has entered the triage process. That means the issue will wait in this status until a Bug Marshal has an opportunity to review the issue. Once the issue has been reviewed you will receive comments regarding the next steps towards resolution.

A good first step is for you to review the [Asterisk Issue Guidelines|https://wiki.asterisk.org/wiki/display/AST/Asterisk+Issue+Guidelines] if you haven't already. The guidelines detail what is expected from an Asterisk issue report.

Then, if you are submitting a patch, please review the [Patch Contribution Process|https://wiki.asterisk.org/wiki/display/AST/Patch+Contribution+Process].
By: Martin Vogt (martinvogt.xcom) 2015-11-16 07:21:38.384-0600

DEBUG9 log from the testcall
By: Rusty Newton (rnewton) 2015-11-18 18:41:13.020-0600

What dialplan is at asterisk-redirect,1,1 ?
By: Matt Jordan (mjordan) 2015-11-18 19:21:24.073-0600

I'm not sure I see a bug here.

First, the DTMF doesn't trigger a hangup. In fact, Adhearsion appears to be issuing an AMI Redirect - which is perfectly fine, and is probably triggered by the DTMF it sees.

We can see that the redirect appears to occur, as the channel is dropped into a new extension - {{adhearion-redirect,1,1}}.

{code}
[Nov 16 14:06:58] DEBUG[1699] manager.c: Running action 'Redirect'
[Nov 16 14:06:58] DEBUG[1699] channel.c: Soft-Hanging (0x02) up channel 'SIP/111-0000001f'


[Nov 16 14:07:00] DEBUG[1699] manager.c: Examining AMI event:
Event: AsyncAGIExec
Privilege: agi,all
SequenceNumber: 2119
File: manager.c
Line: 1693
Func: manager_default_msg_cb
Channel: SIP/111-0000001f
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 111
CallerIDName: biw CC 111
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
Language: de
AccountCode:
Context: adhearsion-redirect
Exten: 1
Priority: 1
Uniqueid: 1447679214.312
Linkedid: 1447679214.312
Result: 200%20result%3D0%0A
CommandId: 3373c2bb-8788-482a-81e5-a8859c5cccae
{code}

Not long after that, the SNOM phone sends Asterisk a BYE request.

{code}
<--- SIP read from UDP:10.47.22.251:5060 --->
BYE sip:777@10.47.20.42:5060 SIP/2.0
Via: SIP/2.0/UDP 10.47.22.251:5060;branch=z9hG4bK-70t9x71qq02s;rport
From: "biw CC 111" <sip:111@10.47.20.42>;tag=18zyekwi52
To: <sip:777@10.47.20.42>;tag=as0d7f289b
Call-ID: 3c9d0f30e227-pcr6c46zzn6u
CSeq: 3 BYE
Max-Forwards: 70
Contact: <sip:111@10.47.22.251:5060;line=r0tupat7>;reg-id=1
User-Agent: snom320/7.3.30
RTP-RxStat: Total_Rx_Pkts=239,Rx_Pkts=239,Rx_Pkts_Lost=0,Remote_Rx_Pkts_Lost=0
RTP-TxStat: Total_Tx_Pkts=423,Tx_Pkts=423,Remote_Tx_Pkts=239
Content-Length: 0

<------------->

[Nov 16 14:07:03] DEBUG[1224][C-00000034] chan_sip.c: Received bye, issuing owner hangup
[Nov 16 14:07:03] VERBOSE[1224][C-00000034] chan_sip.c:
<--- Transmitting (no NAT) to 10.47.22.251:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.47.22.251:5060;branch=z9hG4bK-70t9x71qq02s;received=10.47.22.251;rport=5060
From: "biw CC 111" <sip:111@10.47.20.42>;tag=18zyekwi52
To: <sip:777@10.47.20.42>;tag=as0d7f289b
Call-ID: 3c9d0f30e227-pcr6c46zzn6u
CSeq: 3 BYE
Server: Asterisk PBX 13.6.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Content-Length: 0


<------------>
{code}

Note that this is what hangs up your SIP channel - not Asterisk. Asterisk merely does what the phone tell is to do:

{code}

[Nov 16 14:07:03] DEBUG[1699] manager.c: Examining AMI event:
Event: HangupRequest
Privilege: call,all
SequenceNumber: 2125
File: manager_channels.c
Line: 732
Func: channel_hangup_request_cb
Channel: SIP/111-0000001f
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 111
CallerIDName: biw CC 111
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
Language: de
AccountCode:
Context: adhearsion-redirect
Exten: 1
Priority: 1
Uniqueid: 1447679214.312
Linkedid: 1447679214.312


[Nov 16 14:07:03] DEBUG[13834][C-00000034] res_agi.c: No frame read on channel SIP/111-0000001f, going out ...
[Nov 16 14:07:03] DEBUG[13834][C-00000034] pbx.c: Spawn extension (adhearsion-redirect,1,1) exited non-zero on 'SIP/111-0000001f'
[Nov 16 14:07:03] DEBUG[13834][C-00000034] channel.c: Soft-Hanging (0x10) up channel 'SIP/111-0000001f'
[Nov 16 14:07:03] DEBUG[13834][C-00000034] channel.c: Hanging up channel 'SIP/111-0000001f'
[Nov 16 14:07:03] DEBUG[13834][C-00000034] chan_sip.c: Hangup call SIP/111-0000001f, SIP callid 3c9d0f30e227-pcr6c46zzn6u
{code}

So: Adhearsion issues a valid Redirect, Asterisk moves the channel, and then - for some reason - the SNOM sends us a BYE request. I'm not sure why the SNOM sent us a BYE request - if you didn't hang up the phone, then it could be for a variety of reasons. Either way, nothing here looks to be an Asterisk bug.