[Home]

Summary:ASTERISK-13167: RTP playout does not match ptime
Reporter:Kevin Stewart (skavin)Labels:
Date Opened:2008-12-04 16:02:07.000-0600Date Closed:2011-07-26 14:44:42
Priority:MajorRegression?No
Status:Closed/CompleteComponents:Core/RTP
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:
Description:when a sip client invites with a alaw and ptime of 30. Asterisk sends RTP at intervals of 20 and 40 ms as captured by tcpdump on the asterisk server.
this is causing 20ms jitter on these connections.


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

sip debug from a call to *666 and play tt-weasels
below that is a tcpdump of our outbound traffic just to show the asterisk rtp timings


<--- SIP read from 192.168.2.239:5061 --->
INVITE sip:*666@192.168.2.238 SIP/2.0
Via: SIP/2.0/UDP 192.168.2.239:5061;branch=z9hG4bK-95c97f06
From: 6499744000 <sip:6499744000@192.168.2.238>;tag=cbecad7c9557b996o1
To: <sip:*666@192.168.2.238>
Remote-Party-ID: 6499744000 <sip:6499744000@192.168.2.238>;screen=yes;party=calling
Call-ID: 88beaff4-be4cd97e@192.168.2.239
CSeq: 101 INVITE
Max-Forwards: 70
Contact: 6499744000 <sip:6499744000@192.168.2.239:5061>
Expires: 240
User-Agent: Linksys/SPA2102-3.3.6
Content-Length: 255
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER
Supported: x-sipura
Content-Type: application/sdp

v=0
o=- 112227 112227 IN IP4 192.168.2.239
s=-
c=IN IP4 192.168.2.239
t=0 0
m=audio 16472 RTP/AVP 8 100 101
a=rtpmap:8 PCMA/8000
a=rtpmap:100 NSE/8000
a=fmtp:100 192-193
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:30
a=sendrecv

<------------->
--- (15 headers 13 lines) ---
Sending to 192.168.2.239 : 5061 (NAT)
Using INVITE request as basis request - 88beaff4-be4cd97e@192.168.2.239
Found user '6499744000'
Found RTP audio format 8
Found RTP audio format 100
Found RTP audio format 101
Peer audio RTP is at port 192.168.2.239:16472
Found audio description format PCMA for ID 8
Found unknown media description format NSE for ID 100
Found audio description format telephone-event for ID 101
Capabilities: us - 0xc (ulaw|alaw), peer - audio=0x8 (alaw)/video=0x0 (nothing), combined - 0x8 (alaw)
Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event)
Peer audio RTP is at port 192.168.2.239:16472
Looking for *666 in default (domain 192.168.2.238)
list_route: hop: <sip:6499744000@192.168.2.239:5061>
llusrv2*CLI>
<--- Transmitting (NAT) to 192.168.2.239:5061 --->
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.2.239:5061;branch=z9hG4bK-95c97f06;received=192.168.2.239
From: 6499744000 <sip:6499744000@192.168.2.238>;tag=cbecad7c9557b996o1
To: <sip:*666@192.168.2.238>
Call-ID: 88beaff4-be4cd97e@192.168.2.239
CSeq: 101 INVITE
User-Agent: italk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Contact: <sip:*666@192.168.2.238>
Content-Length: 0


<------------>
   -- Executing [*666@default:1] NoCDR("SIP/6499744000-008e23c0", "") in new stack
   -- Executing [*666@default:2] Playback("SIP/6499744000-008e23c0", "tt-weasels") in new stack
Audio is at 192.168.2.238 port 39854
Adding codec 0x8 (alaw) to SDP
Adding non-codec 0x1 (telephone-event) to SDP
llusrv2*CLI>
<--- Reliably Transmitting (NAT) to 192.168.2.239:5061 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.2.239:5061;branch=z9hG4bK-95c97f06;received=192.168.2.239
From: 6499744000 <sip:6499744000@192.168.2.238>;tag=cbecad7c9557b996o1
To: <sip:*666@192.168.2.238>;tag=as11cf6dd3
Call-ID: 88beaff4-be4cd97e@192.168.2.239
CSeq: 101 INVITE
User-Agent: italk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Contact: <sip:*666@192.168.2.238>
Content-Type: application/sdp
Content-Length: 215

v=0
o=root 18036 18036 IN IP4 192.168.2.238
s=session
c=IN IP4 192.168.2.238
t=0 0
m=audio 39854 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:30
a=sendrecv

<------------>
   -- <SIP/6499744000-008e23c0> Playing 'tt-weasels' (language 'SS')
llusrv2*CLI>
<--- SIP read from 192.168.2.239:5061 --->
ACK sip:*666@192.168.2.238 SIP/2.0
Via: SIP/2.0/UDP 192.168.2.239:5061;branch=z9hG4bK-6b90595
From: 6499744000 <sip:6499744000@192.168.2.238>;tag=cbecad7c9557b996o1
To: <sip:*666@192.168.2.238>;tag=as11cf6dd3
Call-ID: 88beaff4-be4cd97e@192.168.2.239
CSeq: 101 ACK
Max-Forwards: 70
Contact: 6499744000 <sip:6499744000@192.168.2.239:5061>
User-Agent: Linksys/SPA2102-3.3.6
Content-Length: 0


<------------->
--- (10 headers 0 lines) ---
   -- Executing [*666@default:3] Playback("SIP/6499744000-008e23c0", "vm-sorry") in new stack
   -- <SIP/6499744000-008e23c0> Playing 'vm-sorry' (language 'SS')
llusrv2*CLI>
<--- SIP read from 192.168.2.239:5061 --->
BYE sip:*666@192.168.2.238 SIP/2.0
Via: SIP/2.0/UDP 192.168.2.239:5061;branch=z9hG4bK-90f919b4
From: 6499744000 <sip:6499744000@192.168.2.238>;tag=cbecad7c9557b996o1
To: <sip:*666@192.168.2.238>;tag=as11cf6dd3
Call-ID: 88beaff4-be4cd97e@192.168.2.239
CSeq: 102 BYE
Max-Forwards: 70
User-Agent: Linksys/SPA2102-3.3.6
Content-Length: 0


<------------->
--- (9 headers 0 lines) ---
Sending to 192.168.2.239 : 5061 (NAT)
llusrv2*CLI>
<--- Transmitting (NAT) to 192.168.2.239:5061 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.2.239:5061;branch=z9hG4bK-90f919b4;received=192.168.2.239
From: 6499744000 <sip:6499744000@192.168.2.238>;tag=cbecad7c9557b996o1
To: <sip:*666@192.168.2.238>;tag=as11cf6dd3
Call-ID: 88beaff4-be4cd97e@192.168.2.239
CSeq: 102 BYE
User-Agent: italk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Contact: <sip:*666@192.168.2.238>
Content-Length: 0


<------------>
 == Spawn extension (default, *666, 3) exited non-zero on 'SIP/6499744000-008e23c0'
   -- Executing [h@default:1] MYSQL("SIP/6499744000-008e23c0", "Connect connid 202.180.64.81 italk l1f3t1m3 cdr") in new stack
   -- Executing [h@default:2] MYSQL("SIP/6499744000-008e23c0", "Query resultid 1 UPDATE `cdrdisa` SET `hangup`='1' WHERE `uniqueid`='202.180.125.193-1228427947.9'") in new stack
   -- Executing [h@default:3] MYSQL("SIP/6499744000-008e23c0", "Disconnect 1") in new stack
Really destroying SIP dialog '88beaff4-be4cd97e@192.168.2.239' Method: BYE


***************************

10:59:07.275497 IP 192.168.2.238.sip > 192.168.2.239.sip-tls: SIP, length: 434
10:59:07.275987 IP 192.168.2.238.sip > 192.168.2.239.sip-tls: SIP, length: 693
10:59:07.295750 IP 192.168.2.238.39854 > 192.168.2.239.16472: UDP, length 252
10:59:07.315744 IP 192.168.2.238.39854 > 192.168.2.239.16472: UDP, length 252
10:59:07.355748 IP 192.168.2.238.39854 > 192.168.2.239.16472: UDP, length 252
10:59:07.375750 IP 192.168.2.238.39854 > 192.168.2.239.16472: UDP, length 252
10:59:07.415750 IP 192.168.2.238.39854 > 192.168.2.239.16472: UDP, length 252
10:59:07.435749 IP 192.168.2.238.39854 > 192.168.2.239.16472: UDP, length 252
10:59:07.475748 IP 192.168.2.238.39854 > 192.168.2.239.16472: UDP, length 252
10:59:07.495753 IP 192.168.2.238.39854 > 192.168.2.239.16472: UDP, length 252

Comments:By: Terry Wilson (twilson) 2008-12-04 18:39:12.000-0600

Do you have allow=alaw:30 in your sip.conf?  See doc/rtp-packetization.txt  Also, I forgot to mention autoframing=yes in sip.conf.


By: Kevin Stewart (skavin) 2008-12-04 19:02:45.000-0600

I have tried with  allow=alaw,allow=alaw:20 and allow=alaw:30
it does not seem to make a difference
I am Skavin on #asterisk-bugs if you would like to chat
By: Mark Michelson (mmichelson) 2008-12-04 19:12:25.000-0600

Looking at the code, it appears that one thing that may affect the ability for this to work properly would be the "autoframing" option in sip.conf. You can set this either in the general section or per-peer. The default for this setting is for it to be off. If this is not already turned on, please set "autoframing=yes" either for this SIP peer or in the general section and see if this corrects the problem.

I'll look for other potential problem areas in case this is not enough to fix the issue.

Edit: And it appears that otherwiseguy already suggested this. Oops.


By: Kevin Stewart (skavin) 2008-12-04 19:34:52.000-0600

autoframing is yes in my  general section
my users are realtime and I dont know if I can set autoframing per peer

here is the relevant peer info for that peer

 Codecs       : 0xc (ulaw|alaw)
 Codec Order  : (alaw:30,ulaw:30)
 Auto-Framing:  Yes
By: dea (dea) 2008-12-05 15:36:12.000-0600

The issue is not unique to SIP.  Somewhere along the line the
ast_smoother infrastructure was busted.

I have not figured out exactly how just yet.  Either we are not
allocating the smoother when needed, or not reading/writing from
it when we should.

The channels are negotiating the appropriate framing/packetization,
and the core appears to be trying to honor it (rtp debug will show
the correct size packets, but the timestamps may be off).

I noticed the behaviour for SIP/OOH323 channels joined to a meetme.
By: Kevin Stewart (skavin) 2008-12-05 17:32:48.000-0600

I am also seeing it sip to sip with one leg ptime 30 and the other 20


A party  ---  ptime 30 --->  Asterisk --- ptime 20 --> bparty

A tx -> 30 30 30 30          ast tx ->  0 30 0 30 30 0 30 30 0
        0 20 40 20 40 20 40  <- ast tx  20 20 20 20 20 20       <- B tx

The deltas look like asterisk is sending packets when it gets a packet in.

Could asterisk not be only sending packets when it receives packets and not be internally triggering?

looking at the atx leg
it receives 30 ms so sends 20 and buffers 10
waits 30 gets 30 and send 40 ms in 2 sequential packets

when ever asterisk sends data from a bridged call there has always been a packet come in within 0.0001 of a second before it does not seem to send without that incoming packet.
ie delaying a packet 10 ms to play at 30ms multiples when sending from 20ms to 30ms or delaying 20ms when passing data from a 30 to 20 ms call

just trying to rationalize what I am seeing my be totally off on this.

my servers are using ztdummy if that helps as they are only sip to sip.
By: dea (dea) 2008-12-05 18:08:20.000-0600

I should have also said that I am also using ztdummy and have this in
asterisk.conf:
[options]
internal_timing = yes
By: dea (dea) 2008-12-07 01:31:44.000-0600

I think I figured out what is happening and can offer up a few suggestions
to fix it.  It will be mid-week before I can work on a patch, so I am hoping
a core developer can validate my ideas.

Scenario-
   Client A uses 20ms packetization/framing
   Client B uses 30ms packetization/framing
   Clock/RTP starts at zero to simplify the explination

TS = 0   Client A sends a 20ms packet to Asterisk
        Client B's write callback is triggered, and the smoother
        attepts to build a packet, but the smoother does not
        contain enough audio, so it returns a null
TS = 20  Client A sends anouther 20ms packet
        Client B's write callback is triggered and finds 40ms of
        audio in the smoother and sends a properly framed 30ms packet
TS = 40  Client A sends anouther 20ms packet
        Client B's write callback is triggered and finds 30ms of
        audio in the smoother, 10ms left over from the 2nd packet
        from client A's send packet and 20ms from the 3rd packet
        and sends a properly framed 30ms packet.  The smoother is now
        empty and the process starts over

Why it happens-
        The internal_timing and packetization features were developed
        at roughly the same time, and there were some interdepenencies.
        One change that appears to have been lost was setting the
        timeout for the channels Zap/Dahdi timer to the packetization
        interval.

Possible solutions-
        1.  Just change the call timing/generator timer to 80 samples
            or 10ms.  The timer will fire twice as often, but will
            allow for accurate RTP timing.
            Pros-
                 1 or 2 lines of code
            Cons-
                 Increased system load for the extra timer activity
                 May not work well with 33ms iLBC

         2.  Pass appropriate information to the generator setup
             function to set the timer to fire at the packetization
             interval.
             Pros-
                 Lower system load
                 Should work with any packetization
             Cons-
                 More code, more complex

One other issue that concerns me is smoother sizing.  I need to
re-read the code a few more times to be sure of this, but I suspect
that we may not be setting a large enough buffer.  Imagine the crazy
situation where one client has a 20ms packetization requirement and
is bridged to a client using 240ms.  While 240ms packetizaion is
likely insane, it is legal for some codecs.  The channel servicing
the 20ms client would need a buffer 13~15 times larger than it's
packetization interval to hold the audio and to have a chance to buffer
the second packet.  When coding the smoother, should we focus on the
realistic, or the legal possible requirements?

I suspect this issue is related to a number of recent bug reports that
involve meetme and playback, where the client devices are not using
20ms of audio.  The issue also effects 1.4 and 1.6

putnopvut, I hope this helps explain the issue.  I maybe able to put
some time towards this on Tuesday or Wednesday, but I'd like some
guidence about which solution option would be prefered.

frame, and nothing happens
By: Kevin Stewart (skavin) 2008-12-07 02:01:05.000-0600

I have also had voice mail issues on our linksys spa2102s changing them from 30 (the linksys default) to 20ms fixed the voice mail issues we had been seeing.
We where getting corruption of the audio like packet loss bit in a regular pattern when listening to voice mails even when connected across a LAN.

It was also tracked to the 40 20 40 stepping of the RTP play out.
I don't think the linksys adaptive jitter buffer likes this sort of jitter.
By: Kevin P. Fleming (kpfleming) 2009-02-26 11:48:58.000-0600

Josh just brought this issue to my attention, as this is an area that I've been working in the last few days.

DEA's analysis is mostly correct, at least as far as why the outgoing packet stream looks the way that it does. However, his conclusion that this is related the timingfd on the channel is unfortunately not valid; when two channels are bridged, there is no timingfd involved, nor is 'internal_timing' involved. In a channel bridge, outgoing packet timing is based entirely on incoming packet timing.

This is certainly something that should and will be addressed, but it's not a trivial change. It will require that *all* outbound RTP streams use a timing source for generation of packets, because we cannot rely on the inbound packet stream to provide timing (or even consistently sized input packets). This is also necessary to do proper jitter buffering, since the jitter buffer may have stored up frames to be delivered at a later time, and there needs to be some trigger for when that time has arrived.

I'll give this some more thought and post some notes here, but it is unlikely that this will be addressed in Asterisk 1.4 at all, as the invasiveness of the changes would be likely to destabilize things too much.

(I do find it unfortunate that jitter buffers in these products can't handle 20ms of jitter; it makes those jitter buffers nearly useless)
By: Kevin Stewart (skavin) 2009-02-26 13:57:56.000-0600

Thank you for looking at this I am sure other people are getting this and don't know it.
I think the linksys jitter buffer is buffering for an average of the jitter not max.
In this case any adaptive algorithm that does not use max will fail most of the time.
By: dea (dea) 2009-02-26 14:37:47.000-0600

I saw the post on the -dev list about the multiframe queuing and wondered if
it would alter the situation.

I understand the two bridged channel scenario, but would this also explain
the same behaviour when a channel is 'bridged' to an app, such as meetme?

I have continued to think about the options, and I suspect the the RTP
session would need a dedicated write thread, but only if the channels
differ in their framing/packetization/timing requirements.

If such a thread was used, then ast_write could continue to feed frames
into the smoother and the thread would 'consume' the frames based on the
required timing.  Where I get lost is how we would schedule the thread,
usleep is to ugly to consider (yes?), and a callback implimentation is
beyond my skills.
By: Kevin Stewart (skavin) 2009-02-26 19:08:13.000-0600

I think it would affect bridged apps
The First time I ever saw this issue was with a linksys on 30ms listening to voicemail. It had regular clipping. Since then all our managed devices have been hard set to 20ms and they then play happily with asterisk.
By: jahrome (jahrome) 2009-05-11 08:03:27

Hello,

I can confirm I have this kind of problem too. In addition, I have seen other people reporting this problem on French Forums as French VoIP providers impose ptime of 30ms which envolves compatibility issues with non ptime configurable clients.
A patch would be welcome :)

Thank you.

Cheers,


By: pasandev (pasandev) 2009-11-06 03:53:14.000-0600

I tested autoframing with asterisk 1.4.21.2

and works for me with some sip phone. netcomm v90.

When the phone specify the rtp packetization in SDP asterisk negotiate to that frame size

Below is the SIP Packets I observed during my test.




<--- SIP read from 192.168.101.118:5060 --->
INVITE sip:2025@192.168.101.182:5060;transport=udp SIP/2.0
Via: SIP/2.0/UDP 192.168.101.118:5060;rport;branch=z9hG4bK1794878507
From: "2026" <sip:2026@192.168.101.182;user=phone>;tag=5581114
To: <sip:2025@192.168.101.182>
Call-ID: 675324517@192.168.101.118:5060
CSeq: 4 INVITE
Contact: <sip:2026@192.168.101.118:5060>
Max-Forwards: 30
User-Agent: NETCOMM
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, NOTIFY, REFER, REGISTER, MESSAGE
Content-Type: application/sdp
Content-Length:   223

v=0
o=NETCOMM 1257480847 1257480847 IN IP4 192.168.101.118
s=NETCOMM
c=IN IP4 192.168.101.118
t=0 0
m=audio 10000 RTP/AVP 18 101
a=rtpmap:18 G729/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:100


===========================================================================================================
Response From asterisk
===========================================================================================================


<--- Reliably Transmitting (no NAT) to 192.168.101.118:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.101.118:5060;branch=z9hG4bK1653030959;received=192.168.101.118;rport=5060
From: "2026" <sip:2026@192.168.101.182;user=phone>;tag=5581114
To: <sip:2025@192.168.101.182>;tag=as27cf1d2d
Call-ID: 675324517@192.168.101.118:5060
CSeq: 5 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Contact: <sip:2025@192.168.101.182>
Content-Type: application/sdp
Content-Length: 268

v=0
o=root 2849 2849 IN IP4 192.168.101.182
s=session
c=IN IP4 192.168.101.182
t=0 0
m=audio 18180 RTP/AVP 18 101
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:100
a=sendrecv


This means autoframing works if client specify the ptime in itz SDP


I try this test with a Mitel 5224 But Didn't work, coz Mitel doesn't change the ptime in SDP when it configured with different RTP frame sizes
By: Luke H (luckman212) 2011-04-23 14:03:13

Is this still an issue with Asterisk 1.8.3.3 ?  I think I may be having this issue with a Linksys/Sipura SPA2102 that has a 30ms jitterbuffer which apparently CANNOT be disabled, so ptime=20 (0.020) doesn't really make sense for that device.  I have left it at the default 30ms but I get "matrix-style" audio from time to time especially in the beginning of a bridged call between ATA<->PBX (both devices on the same 1Gbit LAN segment).  

Haven't done extensive RTP debugging but it would seem this might be related.  I'm on Asterisk 1.8.3.3.
By: Russell Bryant (russell) 2011-07-26 14:44:37.504-0500

Per the Asterisk maintenance timeline page at http://www.asterisk.org/asterisk-versions maintenance (bug) support for the 1.4 and 1.6.x branches has ended. For continued maintenance support please move to the 1.8 branch which is a long term support (LTS) branch. For more information about branch support, please see https://wiki.asterisk.org/wiki/display/AST/Asterisk+Versions

If this is still an issue, please open a new issue so it can be re-triaged appropriately. Thanks!
By: not here (looserouting) 2012-12-19 10:28:02.961-0600

I dont know if it is related.

my Asterisk 10 svn recievs an INVITE from A with ptime:20 and invites B also with ptime:20.
now B sends an OK with ptime:30. The OK from Asterisk to A contains ptime:20.

But now the RTP stream from asterisk to A is the same as from B to asterisk. That means asterisk doesn't change the stream and is transmitting with a ptime of 30ms.

regarding the RFC this shouldn't be an issiue since the ptime may change during the session.

but this can lead to strange behaviour of A like synchronisations problems.