[Home]

Summary:ASTERISK-16126: [patch] [regression] Progress in band error (don't send RTP packets)
Reporter:Tech Admin (tech_admin)Labels:
Date Opened:2010-05-21 09:31:13Date Closed:2010-07-12 12:26:13
Priority:MajorRegression?Yes
Status:Closed/CompleteComponents:Channels/chan_sip/General
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) asterisk-1.6.2.8-inband-indications.patch
( 1) bug17372.patch
( 2) issue-17185-rtp-debug.zip
( 3) issue-17372.pcap
Description:Dear all,

on a updated redhat rhel5 (kernel: 2.6.18-194.3.1.el5xen), I installed the last asterisk release (1.6.2.7) from the source code.

The problem is: SIP caller doesn't hear ringing tone.
We use progressinband=yes with ch (Switzerland) tones and voice is G729 encoded using TC400B Digium card.
After answer, all is ok: both side RTP packets go trough asterisk without translation.
The Digium card work fine with others service like IVR, Queues, Voicemail ... all using G729.



****** ADDITIONAL INFORMATION ******

A network capture show that asterisk doesn't send RTP packets after sending "183 Session Progress" packet. The session is correctly established but RTP packet are only in 1 way (caller -> asterisk). SDP seems correct with sendrecv attribute and correct IP/Port.

RTP debug only show incoming packets but nothing about outgoing.

With exactly the same configuration, I reinstalled previous version (1.6.2.6) from source code. All work fine.
Comments:By: Paul Belanger (pabelanger) 2010-05-24 14:52:25

We need a debug log (see below).
--
We require a complete debug log to help triage the issue.

This document will provide instructions on how to collect debugging logs from an Asterisk machine for the purpose of helping bug marshals troubleshoot an issue:

http://svn.digium.com/svn/asterisk/trunk/doc/HOWTO_collect_debug_information.txt
By: Elazar Broad (ebroad) 2010-05-24 15:30:09

I noticed this recently as well with SVN trunk, I have to explicitly Answer() the channel before passing the call on to internal extensions in order for ringing to work.

elazar

edit: scratch that, enabling prematuremedia resolved it.


By: Tech Admin (tech_admin) 2010-05-24 16:20:50

Unfortunately, I cannot do it now because we had to revert to a previous version, and I do not have an other server equipped with the codecs card. Are there any additional info can provide you without having to recompile?

edit: I tried to comment (default value is yes) prematuremedia parameters. Didn't work


By: Paul Belanger (pabelanger) 2010-05-24 16:32:13

Have you tried Progress() in your dialplan?
By: Tech Admin (tech_admin) 2010-05-24 16:54:09

No we have never used the "Progress" command but instead; we used AGI scripts that call the "Dial" command and it always worked for us.
By: Paul Belanger (pabelanger) 2010-05-25 08:22:56

We need a debug log (as described in the first post)

http://svn.digium.com/svn/asterisk/trunk/doc/HOWTO_collect_debug_information.txt
By: Leif Madsen (lmadsen) 2010-05-25 13:17:08

Setting to feedback while we wait for information from the reporter. Only leaving this open because it seems to be a possible regression from 1.6.2.6 -> 1.6.2.7.
By: Sam Deller (samdell3) 2010-05-25 21:01:28

IDENTICAL problem with latest version 1.4.31 also FYI.
By: Sam Deller (samdell3) 2010-05-25 21:53:05

Should have mentioned that 1.4.30 works just swell.
progressinband=yes is only broken in 1.4.31 and 1.6.7

Sorry no debugs as yet. If we can I will acquire one asap. Rather easy to replicate though...
By: Sam Deller (samdell3) 2010-05-25 21:53:43

progressinband=yes is only broken in 1.4.31 and --> 1.6.2.7 <-- (typo)
By: Jonathan Thurman (jthurman) 2010-05-26 15:00:22

This is also an issue with 1.6.1.20. Explicitly calling Answer() before Dial() creates the ringback. Yes, I know no more bug fixes for 1.6.1 but note it here for others who may have the issue.
By: Paul Belanger (pabelanger) 2010-05-26 15:32:56

As said before, we need to see a debug log to actually see what is going on.  Depending if you are doing early media, you now need to use Progress().

Otherwise, upload a debug log and we can see what is going on.
By: Paul Belanger (pabelanger) 2010-05-26 15:36:16

Here was an example posted on the mailing list, however I am not sure it is related to this issue.  Still investigating.
--
[test]
exten => 6111,1,Progress()
exten => 6111,n,Wait(1)
exten => 6111,n,Proceeding()
exten => 6111,n,Wait(1)
exten => 6111,n,Ringing()
exten => 6111,n,Wait(60)
exten => 6111,n,Hangup()
By: Dennis DeDonatis (dennisd) 2010-06-01 21:22:01

I just tested with 1.6.2.9-rc1.

I used the above example, except I used extension 520 instead of 6111.

I've attached issue-17372-no_ringing_debug.log that was when progressinband=yes was set in sip.conf and issue-17372-with_ringing_debug.log after I commented it out and did a sip reload.

I've also attached issue-17372.pcap showing the RTP packets are there, but I couldn't hear anything.

Oddly, when I tested with a Future-Nine DID, Asterisk did NOT send out any RTP packets to Future-Nine (I tested with Progress() then Dial(SIP/xxxx,30)), BUT when I tested with a voip.ms DID, I heard the early media.

Let me know what else you want and I'll attach it as soon as I can get back to this.
By: Dennis DeDonatis (dennisd) 2010-06-01 21:24:56

The rtp debug files were too big to attach, so they are both attached in issue-17185-rtp-debug.zip
By: jma_informatique (jma_informatique) 2010-06-03 03:11:11

Same problem for me when upgrading 1.4.26.2 to 1.4.31 version: no ring tone
Downgrade to 1.4.30 -> ok but.... 99.9 % cpu sometimes.

I try this morning 1.4.32

Thanks
By: Leif Madsen (lmadsen) 2010-06-03 11:27:53

Can you please try testing with Progress() in the dialplan and see if that changes anything?
By: Dennis DeDonatis (dennisd) 2010-06-03 12:37:45

All of my attached debugs/captures were run with:

exten => 520,1,NoOp()
exten => 520,n,Progress()
exten => 520,n,Wait(1)
exten => 520,n,Proceeding()
exten => 520,n,Wait(1)
exten => 520,n,Ringing()
exten => 520,n,Wait(60)
exten => 520,n,Hangup()


When testing with Future-Nine and voip.ms, the first statement was Progress() in the dialplan.
By: Federico Santulli (fsantulli) 2010-06-06 03:02:51

The problem is due to ast_prod in "ast_activate_generator" routine contained in "channel.c", moved at the end of routine since 1.6.2.7 which pushes generator to stop.

Here you got a sample:

[Jun  6 10:02:38] DEBUG[11056]: channel.c:3737 set_format: Set channel SIP/201-40377db0 to write format slin
[Jun  6 10:02:38] DEBUG[11056]: channel.c:2434 ast_settimeout: Scheduling timer at (50 requested / 50 actual) timer ticks per second
[Jun  6 10:02:38] DEBUG[11056]: channel.c:3400 ast_prod: Prodding channel 'SIP/201-40377db0'
[Jun  6 10:02:38] DEBUG[11056]: channel.c:3737 set_format: Set channel SIP/201-40377db0 to write format alaw
[Jun  6 10:02:38] DEBUG[11056]: channel.c:2434 ast_settimeout: Scheduling timer at (0 requested / 0 actual) timer ticks per second

Patch attached.


By: Leif Madsen (lmadsen) 2010-06-08 10:16:04

Awesome, thanks for the feedback and work on this guys! I'm updating the status to Ready for Testing.
By: Leif Madsen (lmadsen) 2010-06-14 13:11:19

This should get some attention in the next sprint.
By: Joel Vandal (jvandal) 2010-06-15 06:49:25

I have apply the patch "asterisk-1.6.2.8-inband-indications.patch" to Asterisk 1.4.32 and this immediately fix all "ringing" problems we experienced.

Please commit this patch also on 1.4 branches.
By: Marek Cervenka (cervajs) 2010-06-25 02:47:32

patch works for me on 1.6.2.9

this is imho major issue
By: Martin Vit (festr) 2010-06-25 02:49:04

The question is, why that function ast_prod was moved down?
By: alexr1 (alexr1) 2010-06-26 08:39:05

I've applied the patch to 1.4.33.1 and it fixed the problem for me!
By: Jonathan Thurman (jthurman) 2010-06-28 15:41:28

The patch resolves the issue for me on 1.6.2.8.
By: David Brillert (aragon) 2010-06-28 15:46:08

I also use jvandal's backport of this patch for 1.4.32 and it solves the problem for me too.
By: Jeff Peeler (jpeeler) 2010-07-06 12:41:59

The call to ast_prod can not be moved back as it was intentionally moved to prevent a deadlock scenario. Please test the latest patch as I believe it solves the issue.
By: Dennis DeDonatis (dennisd) 2010-07-06 13:01:45

I tested with 1.6.2.10-rc1.  I reverted the original patch and applied the new one.  With the new patch applied, I hear ringing with progressinband=yes and with it commented out in sip.conf.  Although, oddly, the ringing is louder with progressinband=yes.  So, it seems to be working for me.
By: Digium Subversion (svnbot) 2010-07-12 11:58:38

Repository: asterisk
Revision: 275665

U   branches/1.4/main/channel.c

------------------------------------------------------------------------
r275665 | jpeeler | 2010-07-12 11:58:38 -0500 (Mon, 12 Jul 2010) | 11 lines

Change ast_write to not stop generator when called from ast_prod.

For SIP channels configured with the progressinband option on, the ringback was
being immediately stopped. This problem was due to ast_prod being moved for a
deadlock fix in 259858. Prodding the channel after setting up the generator
triggered the check in ast_write to stop the generator. The fix here should
write the frame the same as was done before the call to ast_prod was moved.

(closes issue ASTERISK-16126)
Reported by: tech_admin

------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=275665
By: Digium Subversion (svnbot) 2010-07-12 12:21:00

Repository: asterisk
Revision: 275682

_U  trunk/
U   trunk/main/channel.c

------------------------------------------------------------------------
r275682 | jpeeler | 2010-07-12 12:21:00 -0500 (Mon, 12 Jul 2010) | 18 lines

Merged revisions 275665 via svnmerge from
https://origsvn.digium.com/svn/asterisk/branches/1.4

........
 r275665 | jpeeler | 2010-07-12 11:58:39 -0500 (Mon, 12 Jul 2010) | 11 lines
 
 Change ast_write to not stop generator when called from ast_prod.
 
 For SIP channels configured with the progressinband option on, the ringback was
 being immediately stopped. This problem was due to ast_prod being moved for a
 deadlock fix in 259858. Prodding the channel after setting up the generator
 triggered the check in ast_write to stop the generator. The fix here should
 write the frame the same as was done before the call to ast_prod was moved.
 
 (closes issue ASTERISK-16126)
 Reported by: tech_admin
........

------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=275682
By: Digium Subversion (svnbot) 2010-07-12 12:26:09

Repository: asterisk
Revision: 275706

_U  branches/1.6.2/
U   branches/1.6.2/main/channel.c

------------------------------------------------------------------------
r275706 | jpeeler | 2010-07-12 12:26:09 -0500 (Mon, 12 Jul 2010) | 25 lines

Merged revisions 275682 via svnmerge from
https://origsvn.digium.com/svn/asterisk/trunk

................
 r275682 | jpeeler | 2010-07-12 12:21:01 -0500 (Mon, 12 Jul 2010) | 18 lines
 
 Merged revisions 275665 via svnmerge from
 https://origsvn.digium.com/svn/asterisk/branches/1.4
 
 ........
   r275665 | jpeeler | 2010-07-12 11:58:39 -0500 (Mon, 12 Jul 2010) | 11 lines
   
   Change ast_write to not stop generator when called from ast_prod.
   
   For SIP channels configured with the progressinband option on, the ringback was
   being immediately stopped. This problem was due to ast_prod being moved for a
   deadlock fix in 259858. Prodding the channel after setting up the generator
   triggered the check in ast_write to stop the generator. The fix here should
   write the frame the same as was done before the call to ast_prod was moved.
   
   (closes issue ASTERISK-16126)
   Reported by: tech_admin
 ........
................

------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=275706