Summary:ASTERISK-15108: [regression] Early audio message doesn't play over SIP
Reporter:miki (miki)Labels:
Date Opened:2009-11-10 01:02:07.000-0600Date Closed:2010-01-05 12:07:35.000-0600
Versions:Frequency of
Environment:Attachments:( 0) 200287_Playback_no_answer_OK.txt
( 1) 226683_Playback_with_answer_OK.txt
( 2) 226683_Playback_with_no_answer_-__no_183.txt
( 3) 226683_Playback_with_noanswer_-_WARNING_message.txt
Description:We use early audio messages to notify caller about reason why callee isn't reachable. It has stopped working over SIP in the SVN trunk sometime between rev 200287 and 226683. 183 Session Progress message isn't send back to caller and audio channel isn't open when Playback function with noanswer parameter is called.
Message is played without any problem even in rev 226683 if call is answered. Warning message "file.c:746 ast_readaudio_callback: Failed to write frame" does appear sometimes (not always).


I attached some traces
1) shows correct behavior in 200287
2) shows correct behavior in 226683 if call is answered (Playback is called without parameter noanswer)
3) shows incorrect behavior in 226683 if call isn't answered early audio should be opened
4) shows warning message in 226683

************************* 200287 Playback no answer - OK *************************
(see file '200287 Playback no answer OK.txt')

************************* 226683 Playback with answer - OK *************************
(see file '226686 Playback with answer OK.txt')

************************* 226683 Playback with noanswer - no 183 Session Progres message *************************
(see file '226683 Playback with no answer - no 183.txt')

************************* 226683 Playback with noanswer - WARNING message does appear sometimes *************************
(see file '226683 Playback with noanswer - WARNING message.txt')
Comments:By: Leif Madsen (lmadsen) 2009-11-10 08:26:31.000-0600

Note that in order to keep the notes in the top of this issue, I've cleaned it up by putting the debugging information into separate txt files which you can access. I've updated the notes above in order to reference the file where the data used to exist. Thanks!

By: David Vossel (dvossel) 2009-11-24 17:41:43.000-0600

I believe this may be related to r216438 in trunk

By: Alec Davis (alecdavis) 2009-11-24 21:24:41.000-0600

We had similar, no audio, but from the ISDN. No SIP involved.

Taking advice regarding progress from r216438 fixed it.
But see later commit note r220289 or bug ASTERISK-14705

By: David Vossel (dvossel) 2009-11-25 09:54:54.000-0600

use Progress() in the dialplan before calling PlayBack() with noanswer and everything should work fine.

By: miki (miki) 2009-12-01 17:34:51.000-0600

Thank you for explanation. It's clear it is caused by changed behavior of chan_sip and default option NO to prematuremedia for 1.6.2 since r216438.

Notes in SVN are fine but since it is changed behavior in comparison to default implicit sending of Progress message until this release I think it should be noticed in CHANGES and UPGRADE files as well. I think some clear Warning message from certain debug level in case media frames are sent to SIP channel and prematuremedia option is disabled will be welcome and helpful to many people troubleshooting what's happened after upgrade to 1.6.2 if they haven't read release notes carefully.

By: Digium Subversion (svnbot) 2009-12-02 17:35:22.000-0600

Repository: asterisk
Revision: 232657

U   trunk/CHANGES
U   trunk/UPGRADE.txt

r232657 | dvossel | 2009-12-02 17:35:22 -0600 (Wed, 02 Dec 2009) | 6 lines

update CHANGES and UPGRADE.txt for early media behavior change between 1.6.1 and 1.6.2

(closes issue ASTERISK-15108)
Reported by: miki



By: Digium Subversion (svnbot) 2009-12-02 17:36:25.000-0600

Repository: asterisk
Revision: 232658

_U  branches/1.6.2/
U   branches/1.6.2/CHANGES
U   branches/1.6.2/UPGRADE.txt

r232658 | dvossel | 2009-12-02 17:36:25 -0600 (Wed, 02 Dec 2009) | 12 lines

Merged revisions 232657 via svnmerge from

 r232657 | dvossel | 2009-12-02 17:27:45 -0600 (Wed, 02 Dec 2009) | 6 lines
 update CHANGES and UPGRADE.txt for early media behavior change between 1.6.1 and 1.6.2
 (closes issue ASTERISK-15108)
 Reported by: miki



By: Digium Subversion (svnbot) 2009-12-02 17:37:14.000-0600

Repository: asterisk
Revision: 232659

_U  branches/1.6.1/

r232659 | dvossel | 2009-12-02 17:37:14 -0600 (Wed, 02 Dec 2009) | 11 lines

Blocked revisions 232657 via svnmerge

 r232657 | dvossel | 2009-12-02 17:27:45 -0600 (Wed, 02 Dec 2009) | 6 lines
 update CHANGES and UPGRADE.txt for early media behavior change between 1.6.1 and 1.6.2
 (closes issue ASTERISK-15108)
 Reported by: miki



By: Tilghman Lesher (tilghman) 2009-12-22 20:39:53.000-0600

Actually, it was not a change, but merely a correction to a BUG that was in 1.6.1 for only a very short amount of time (2 weeks).  The Playback app should NEVER have implicitly sent Progress.

By: Tilghman Lesher (tilghman) 2009-12-22 20:47:42.000-0600

Additionally, this commit should probably go into 1.4 and 1.6.0, as well, and the version numbers changed for 1.6.1 and 1.6.2, since, as I noted, this change affected all current releases and was not a change between 1.6.1 and 1.6.2.

By: miki (miki) 2010-01-05 11:54:21.000-0600

Tilghman - no one has said Playback implicitly sent or should have sent Progress.

Issue results from introduction of premature media option in chan_sip and that the premature media filter is disabled in older versions by default for compatibility but is enabled by default in 1.6.2. Hence 1.6.2 behaves differently because of the change. Explicit Progress must be added or prematuremedia option value must be changed in order to script start working properly again after upgrade.
Note: premature media filter was enabled by default in 1.6.0 and 1.6.1 too just for about 1-1,5 hour ;-) It was disabled in 1.4 all time.

By: David Vossel (dvossel) 2010-01-05 12:07:34.000-0600

1.6.1 and 1.6.2 behave differently.  The prematuremedia option is already documented.  My change just documents this behavior change in 1.6.2.