[asterisk-bugs] [Asterisk 0018105]: Playback of audio file (gsm, ulaw) audio and dialplan stops when caller is inbound over iax2

Asterisk Bug Tracker noreply at bugs.digium.com
Wed Oct 27 13:10:24 CDT 2010


A NOTE has been added to this issue. 
====================================================================== 
https://issues.asterisk.org/view.php?id=18105 
====================================================================== 
Reported By:                n5yzv
Assigned To:                
====================================================================== 
Project:                    Asterisk
Issue ID:                   18105
Category:                   Channels/chan_iax2
Reproducibility:            always
Severity:                   major
Priority:                   normal
Status:                     acknowledged
Asterisk Version:           1.6.2.13 
JIRA:                       SWP-2349 
Regression:                 No 
Reviewboard Link:            
SVN Branch (only for SVN checkouts, not tarball releases): N/A 
SVN Revision (number only!):  
Request Review:              
====================================================================== 
Date Submitted:             2010-10-07 11:34 CDT
Last Modified:              2010-10-27 13:10 CDT
====================================================================== 
Summary:                    Playback of audio file (gsm,ulaw) audio and dialplan
stops when caller is inbound over iax2
Description: 
Inbound call that arrives from IAX2 channel, when call is answered by a sip
phone (tested with polycom only) works fine.  No issues.  However if call
is not answered, call is dumped to voicemail, about 1 - 3 seconds of the
the greeting (The person at extension...) is played such as "The pers....".
 This is also true for instead of sending call directly so a simple
extension such as:
exten => 888,1,Playback(en/vm-theperson)
The same thing happens.  However, if a local sip phone calls the same
extension or voicemail, everything works as expected.  I have been trying
numerous 1.6.2.x versions and have had to downgrade every time to 1.6.1.12
in order to have a functional box.
======================================================================
Relationships       ID      Summary
----------------------------------------------------------------------
related to          0018110 Playback stalls when playing demo-congr...
====================================================================== 

---------------------------------------------------------------------- 
 (0128424) mdeneen (reporter) - 2010-10-27 13:10
 https://issues.asterisk.org/view.php?id=18105#c128424 
---------------------------------------------------------------------- 
I have noticed this as well with 1.6.2.13.  In my situation, it happens
during a Background() call with a WaitExten() at the end of the audio. 
Even though the audio stops (and waits seemingly forever) I can press a
button to send DTMF, and WaitExten() accepts the DTMF as if nothing unusual
had happened.

I've experienced this both inside and outside of a VM.  I have an asterisk
playground where I can monkey around as much as I want, so please let me
know if there is anything I can do to debug this.

Here is my iax2 debug output:


    -- Accepting AUTHENTICATED call from 10.33.0.1:
       > requested format = g729,
       > requested prefs = (g729),
       > actual format = g729,
       > host prefs = (g729),
       > priority = mine
    -- Executing [2100 at from-trusted-remote:1]
Goto("IAX2/pbx-asterisk-dev-1089", "bus-intro,s,1") in new stack
    -- Goto (bus-intro,s,1)
    -- Executing [s at bus-intro:1] Answer("IAX2/pbx-asterisk-dev-1089", "")
in new stack
Tx-Frame Retry[000] -- OSeqno: 001 ISeqno: 002 Type: IAX     Subclass:
ACCEPT 
   Timestamp: 00013ms  SCall: 01089  DCall: 17363 [10.33.0.1:4569]
   FORMAT          : 256

Tx-Frame Retry[000] -- OSeqno: 002 ISeqno: 002 Type: CONTROL Subclass:
ANSWER 
   Timestamp: 00016ms  SCall: 01089  DCall: 17363 [10.33.0.1:4569]
Tx-Frame Retry[000] -- OSeqno: 003 ISeqno: 002 Type: CONTROL Subclass:
(255?)
   Timestamp: 00019ms  SCall: 01089  DCall: 17363 [10.33.0.1:4569]
Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 002 Type: IAX     Subclass: ACK
   
   Timestamp: 00013ms  SCall: 17363  DCall: 01089 [10.33.0.1:4569]
Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 003 Type: IAX     Subclass: ACK
   
   Timestamp: 00016ms  SCall: 17363  DCall: 01089 [10.33.0.1:4569]
Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 004 Type: IAX     Subclass: ACK
   
   Timestamp: 00019ms  SCall: 17363  DCall: 01089 [10.33.0.1:4569]
Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 004 Type: CONTROL Subclass:
SRCUPDT
   Timestamp: 00024ms  SCall: 17363  DCall: 01089 [10.33.0.1:4569]
Tx-Frame Retry[-01] -- OSeqno: 004 ISeqno: 003 Type: IAX     Subclass: ACK
   
   Timestamp: 00024ms  SCall: 01089  DCall: 17363 [10.33.0.1:4569]
Rx-Frame Retry[ No] -- OSeqno: 003 ISeqno: 004 Type: CONTROL Subclass:
SRCUPDT
   Timestamp: 00027ms  SCall: 17363  DCall: 01089 [10.33.0.1:4569]
Tx-Frame Retry[-01] -- OSeqno: 004 ISeqno: 004 Type: IAX     Subclass: ACK
   
   Timestamp: 00027ms  SCall: 01089  DCall: 17363 [10.33.0.1:4569]
Rx-Frame Retry[ No] -- OSeqno: 004 ISeqno: 004 Type: CONTROL Subclass:
SRCUPDT
   Timestamp: 00030ms  SCall: 17363  DCall: 01089 [10.33.0.1:4569]
Tx-Frame Retry[-01] -- OSeqno: 004 ISeqno: 005 Type: IAX     Subclass: ACK
   
   Timestamp: 00030ms  SCall: 01089  DCall: 17363 [10.33.0.1:4569]
Rx-Frame Retry[ No] -- OSeqno: 005 ISeqno: 004 Type: CONTROL Subclass:
SRCUPDT
   Timestamp: 00033ms  SCall: 17363  DCall: 01089 [10.33.0.1:4569]
Tx-Frame Retry[-01] -- OSeqno: 004 ISeqno: 006 Type: IAX     Subclass: ACK
   
   Timestamp: 00033ms  SCall: 01089  DCall: 17363 [10.33.0.1:4569]
Rx-Frame Retry[ No] -- OSeqno: 006 ISeqno: 004 Type: CONTROL Subclass:
SRCUPDT
   Timestamp: 00036ms  SCall: 17363  DCall: 01089 [10.33.0.1:4569]
Tx-Frame Retry[-01] -- OSeqno: 004 ISeqno: 007 Type: IAX     Subclass: ACK
   
   Timestamp: 00036ms  SCall: 01089  DCall: 17363 [10.33.0.1:4569]
Rx-Frame Retry[ No] -- OSeqno: 007 ISeqno: 004 Type: CONTROL Subclass:
SRCUPDT
   Timestamp: 00039ms  SCall: 17363  DCall: 01089 [10.33.0.1:4569]
Tx-Frame Retry[-01] -- OSeqno: 004 ISeqno: 008 Type: IAX     Subclass: ACK
   
   Timestamp: 00039ms  SCall: 01089  DCall: 17363 [10.33.0.1:4569]
Rx-Frame Retry[ No] -- OSeqno: 008 ISeqno: 004 Type: CONTROL Subclass:
SRCUPDT
   Timestamp: 00042ms  SCall: 17363  DCall: 01089 [10.33.0.1:4569]
Tx-Frame Retry[-01] -- OSeqno: 004 ISeqno: 009 Type: IAX     Subclass: ACK
   
   Timestamp: 00042ms  SCall: 01089  DCall: 17363 [10.33.0.1:4569]
Rx-Frame Retry[ No] -- OSeqno: 009 ISeqno: 004 Type: VOICE   Subclass:
136
   Timestamp: 00140ms  SCall: 17363  DCall: 01089 [10.33.0.1:4569]
Tx-Frame Retry[-01] -- OSeqno: 004 ISeqno: 010 Type: IAX     Subclass: ACK
   
   Timestamp: 00140ms  SCall: 01089  DCall: 17363 [10.33.0.1:4569]
    -- Executing [s at bus-intro:2] AGI("IAX2/pbx-asterisk-dev-1089",
"log_call_start.agi") in new stack
    -- Launched AGI Script /var/lib/asterisk/agi-bin/log_call_start.agi
    -- <IAX2/pbx-asterisk-dev-1089>AGI Script log_call_start.agi
completed, returning 0
    -- Executing [s at bus-intro:3] Wait("IAX2/pbx-asterisk-dev-1089", "1")
in new stack
    -- Executing [s at bus-intro:4] Set("IAX2/pbx-asterisk-dev-1089",
"TIMEOUT(digit)=2") in new stack
    -- Digit timeout set to 2.000
    -- Executing [s at bus-intro:5] NoOp("IAX2/pbx-asterisk-dev-1089", "") in
new stack
    -- Executing [s at bus-intro:6] Set("IAX2/pbx-asterisk-dev-1089",
"invalidCt=0") in new stack
    -- Executing [s at bus-intro:7] AGI("IAX2/pbx-asterisk-dev-1089",
"log_call_node_access.agi,"Intro"") in new stack
    -- Launched AGI Script
/var/lib/asterisk/agi-bin/log_call_node_access.agi
    -- <IAX2/pbx-asterisk-dev-1089>AGI Script log_call_node_access.agi
completed, returning 0
    -- Executing [s at bus-intro:8] NoOp("IAX2/pbx-asterisk-dev-1089", "") in
new stack
    -- Executing [s at bus-intro:9] BackGround("IAX2/pbx-asterisk-dev-1089",
"sounds/Intro") in new stack
    -- <IAX2/pbx-asterisk-dev-1089> Playing 'sounds/Intro.g729' (language
'en')
Tx-Frame Retry[000] -- OSeqno: 004 ISeqno: 010 Type: VOICE   Subclass:
136
   Timestamp: 01280ms  SCall: 01089  DCall: 17363 [10.33.0.1:4569]
Rx-Frame Retry[ No] -- OSeqno: 010 ISeqno: 005 Type: IAX     Subclass: ACK
   
   Timestamp: 01280ms  SCall: 17363  DCall: 01089 [10.33.0.1:4569]
Rx-Frame Retry[ No] -- OSeqno: 010 ISeqno: 005 Type: IAX     Subclass:
LAGRQ  
   Timestamp: 10023ms  SCall: 17363  DCall: 01089 [10.33.0.1:4569]
Tx-Frame Retry[000] -- OSeqno: 005 ISeqno: 011 Type: IAX     Subclass:
LAGRP  
   Timestamp: 10023ms  SCall: 01089  DCall: 17363 [10.33.0.1:4569]
Rx-Frame Retry[ No] -- OSeqno: 011 ISeqno: 006 Type: IAX     Subclass: ACK
   
   Timestamp: 10023ms  SCall: 17363  DCall: 01089 [10.33.0.1:4569]
Tx-Frame Retry[000] -- OSeqno: 006 ISeqno: 011 Type: IAX     Subclass:
LAGRQ  
   Timestamp: 10019ms  SCall: 01089  DCall: 17363 [10.33.0.1:4569]
Rx-Frame Retry[ No] -- OSeqno: 011 ISeqno: 007 Type: IAX     Subclass:
LAGRP  
   Timestamp: 10019ms  SCall: 17363  DCall: 01089 [10.33.0.1:4569]
Tx-Frame Retry[-01] -- OSeqno: 007 ISeqno: 012 Type: IAX     Subclass: ACK
   
   Timestamp: 10019ms  SCall: 01089  DCall: 17363 [10.33.0.1:4569]
Rx-Frame Retry[ No] -- OSeqno: 012 ISeqno: 007 Type: IAX     Subclass:
LAGRQ  
   Timestamp: 20015ms  SCall: 17363  DCall: 01089 [10.33.0.1:4569]
Tx-Frame Retry[000] -- OSeqno: 007 ISeqno: 013 Type: IAX     Subclass:
LAGRP  
   Timestamp: 20015ms  SCall: 01089  DCall: 17363 [10.33.0.1:4569]
Rx-Frame Retry[ No] -- OSeqno: 013 ISeqno: 008 Type: IAX     Subclass: ACK
   
   Timestamp: 20015ms  SCall: 17363  DCall: 01089 [10.33.0.1:4569]
Tx-Frame Retry[000] -- OSeqno: 008 ISeqno: 013 Type: IAX     Subclass:
LAGRQ  
   Timestamp: 20018ms  SCall: 01089  DCall: 17363 [10.33.0.1:4569]
Rx-Frame Retry[ No] -- OSeqno: 013 ISeqno: 009 Type: IAX     Subclass:
LAGRP  
   Timestamp: 20018ms  SCall: 17363  DCall: 01089 [10.33.0.1:4569]
Tx-Frame Retry[-01] -- OSeqno: 009 ISeqno: 014 Type: IAX     Subclass: ACK
   
   Timestamp: 20018ms  SCall: 01089  DCall: 17363 [10.33.0.1:4569]
Rx-Frame Retry[ No] -- OSeqno: 014 ISeqno: 009 Type: IAX     Subclass:
PING   
   Timestamp: 21014ms  SCall: 17363  DCall: 01089 [10.33.0.1:4569]
Tx-Frame Retry[000] -- OSeqno: 009 ISeqno: 015 Type: IAX     Subclass:
PONG   
   Timestamp: 21014ms  SCall: 01089  DCall: 17363 [10.33.0.1:4569]
   RR_JITTER       : 0
   RR_LOSS         : 0
   RR_PKTS         : 1
   RR_DELAY        : 40
   RR_DROPPED      : 0
   RR_OUTOFORDER   : 0

Rx-Frame Retry[ No] -- OSeqno: 015 ISeqno: 010 Type: IAX     Subclass: ACK
   
   Timestamp: 21014ms  SCall: 17363  DCall: 01089 [10.33.0.1:4569]
Tx-Frame Retry[000] -- OSeqno: 010 ISeqno: 015 Type: IAX     Subclass:
PING   
   Timestamp: 21018ms  SCall: 01089  DCall: 17363 [10.33.0.1:4569]
Rx-Frame Retry[ No] -- OSeqno: 015 ISeqno: 011 Type: IAX     Subclass:
PONG   
   Timestamp: 21018ms  SCall: 17363  DCall: 01089 [10.33.0.1:4569]
   RR_JITTER       : 0
   RR_LOSS         : 0
   RR_PKTS         : 1
   RR_DELAY        : 40
   RR_DROPPED      : 0
   RR_OUTOFORDER   : 0

Tx-Frame Retry[-01] -- OSeqno: 011 ISeqno: 016 Type: IAX     Subclass: ACK
   
   Timestamp: 21018ms  SCall: 01089  DCall: 17363 [10.33.0.1:4569]
Rx-Frame Retry[ No] -- OSeqno: 016 ISeqno: 011 Type: IAX     Subclass:
LAGRQ  
   Timestamp: 30015ms  SCall: 17363  DCall: 01089 [10.33.0.1:4569]
Tx-Frame Retry[000] -- OSeqno: 011 ISeqno: 017 Type: IAX     Subclass:
LAGRP  
   Timestamp: 30015ms  SCall: 01089  DCall: 17363 [10.33.0.1:4569]
Rx-Frame Retry[ No] -- OSeqno: 017 ISeqno: 012 Type: IAX     Subclass: ACK
   
   Timestamp: 30015ms  SCall: 17363  DCall: 01089 [10.33.0.1:4569]
Tx-Frame Retry[000] -- OSeqno: 012 ISeqno: 017 Type: IAX     Subclass:
LAGRQ  
   Timestamp: 30018ms  SCall: 01089  DCall: 17363 [10.33.0.1:4569]
Rx-Frame Retry[ No] -- OSeqno: 017 ISeqno: 013 Type: IAX     Subclass:
LAGRP  
   Timestamp: 30018ms  SCall: 17363  DCall: 01089 [10.33.0.1:4569]
Tx-Frame Retry[-01] -- OSeqno: 013 ISeqno: 018 Type: IAX     Subclass: ACK
   
   Timestamp: 30018ms  SCall: 01089  DCall: 17363 [10.33.0.1:4569]
Rx-Frame Retry[ No] -- OSeqno: 018 ISeqno: 013 Type: CONTROL Subclass:
SRCUPDT
   Timestamp: 32863ms  SCall: 17363  DCall: 01089 [10.33.0.1:4569]
Tx-Frame Retry[-01] -- OSeqno: 013 ISeqno: 019 Type: IAX     Subclass: ACK
   
   Timestamp: 32863ms  SCall: 01089  DCall: 17363 [10.33.0.1:4569]
Rx-Frame Retry[ No] -- OSeqno: 019 ISeqno: 013 Type: IAX     Subclass:
HANGUP 
   Timestamp: 32978ms  SCall: 17363  DCall: 01089 [10.33.0.1:4569]
   CAUSE CODE      : 16 

Issue History 
Date Modified    Username       Field                    Change               
====================================================================== 
2010-10-27 13:10 mdeneen        Note Added: 0128424                          
======================================================================




More information about the asterisk-bugs mailing list