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-0600	Date Closed:	2010-01-05 12:07:35.000-0600
Priority:	Major	Regression?	Yes
Status:	Closed/Complete	Components:	Channels/chan_sip/General
Versions:		Frequency of Occurrence
Related Issues:
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). ****** ADDITIONAL INFORMATION ****** 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 ------------------------------------------------------------------------ http://svn.digium.com/view/asterisk?view=rev&revision=232657 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 https://origsvn.digium.com/svn/asterisk/trunk ........  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 ........ ------------------------------------------------------------------------ http://svn.digium.com/view/asterisk?view=rev&revision=232658 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 ........ ------------------------------------------------------------------------ http://svn.digium.com/view/asterisk?view=rev&revision=232659 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.