[Home]

Summary:ASTERISK-17952: RTP Timestamp jump on marker packet
Reporter:Iman Haryadi (iman)Labels:
Date Opened:2011-06-01 20:30:15Date Closed:2011-12-14 09:13:55.000-0600
Priority:MajorRegression?No
Status:Closed/CompleteComponents:Core/RTP
Versions:1.8.4 Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) full.gz
( 1) my.cap.gz
( 2) ts.JPG
( 3) Untitled.png
( 4) Untitled2.png
Description:I have been trying to track down some choppiness that I experience when my server is connected to a SIP Trunk.  I set up a inbound call and directed that to MilliWatt app to get continious tone.  When I call in, I hear the tone with drop out every few seconds.  

I dig deeper and capture packet right in the server where the asterisk is ran.  Please note that the packets captured do not leave physical network.

In that capture,  I found that on every RTP marker packet, the timestamp jump more than I expected.  My understanding is that on every RTP packet for G711u contain 20ms worth of audio.  The packet time stamp should increase by rate of 160.  Please see the attached untitled.png.  You can see that on that marker packet the timestamp jump. I use wireshark to open the captured packet files (my.cap.gz).

I also use wireshark to analyze the packet.  See untitled2.png.  Note that the decoded RTP packet has gap in it.  Note that in the Stream Analysis screen that the skew value is very huge and the rate is 9201 HZ. ( I thought that it should be like 8000HZ).  If you play the audio,  the sound of the tone is close to what you hear by calling in to the sip trunk.

I have setup 2 DID SIP Trunk from two different company.  I can not make that number public since it is a paid per minuite plan.  However,  I can share that number with the developer working on this issue.  You can hear that the tone drop out is similiar from the one that wireshark play out.

I also am attaching the asterisk log file during the call.  

Thanks
Iman


****** STEPS TO REPRODUCE ******

1. Connect to a SIP trunk.  ( Vitelity or Flowroute)
2. Start a tcpdump or wireshark.  capture all packet or packet from the SIP Trunk provider
3. Create incomming dial plan and answer that with MillWatt app
4. Make a call from land line or come other line.  
5. Observe that the tone will play with drops every few second or so

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

OS: Cenntos 5.6
Kernel: 2.6.18-164.15.1.el5xen #1 SMP Wed Mar 17 12:53:17 EDT 2010 i686 i686 i386 GNU/Linux
Asterisk Version 1.8.4.1
Dahdi Version: 2.4.1.2
Codec used in this test G711u
Comments:By: Iman Haryadi (iman) 2011-06-02 10:16:13

I just want to add some informations.

1. The server is running as DOMU in xen shipped with centos 5.6.  The xen version is 3.0.3-105.el5_5.5

2. The dump of the packet and log file is generated as I was calling in with Flowroute as provider.
By: David Woolley (davidw) 2011-06-02 10:36:03

One of the main reasons for the marker to be present is so that the recipient can expect a timestamp jump.  Each source has its own notion of time, and any change of source will set the marker.  The only problem arises when there is a jump but the marker is not set.

Basically, not a bug.


By: Iman Haryadi (iman) 2011-06-02 12:07:28

I just would like to point out that the source does not change based on the packet captured.  It is not like the call is transfered or in some conference.  It is just a plain simple call.

I am not in anyway an expert in RTP.  I believe that the mark in this case used as indication as talkspurt.  It is shown also in the capture the next few packets comes in really fast (small delay).  On each talkspurt in relation to the the last, would a time stamp really still relevant?

I tested this from 2 different SIP trunk provider (flowroute and vitelity).  I am in no way be able to test all sip trunk provider out there.  Using wireshark,  I can playback the sound that I capture.  That tone and the drops sound really close.

I can share my DID to small number of tester.  They are paid by minuites plan.  I can not publish it here for random people to test.  If you are interested,  you can download the packet capture file and play it under wireshark.  Then send me an information where I can PM you the DID.  You can verify that the tone drop out is really close.


By: Matt Jordan (mjordan) 2011-12-14 09:13:49.469-0600

As David pointed out, we don't feel that this is a bug.  Asterisk is not dropping the RTP packets, and if the packets are skewed greater then the tolerance allowed, the marker bit is set so that the recipient knows that there is a jump in time.  That is expected behavior.  Asterisk itself is not dropping the packets or introducing the time jump - so the presence of the marker bit is merely indicating that something has dropped or skewed the delivery of the RTP packets.
By: Jeppe Oland (uxorious) 2011-12-14 09:45:03.546-0600

I am also seeing audio dropouts on SIP connections.
(Running Asterisk 1.8.4.4~dfsg-2ubuntu1 on Ubuntu 11.10 with a Sangoma card).

So far it looks like it is related to RTP packets with the Mark bit set - but I have not had time to investigate much yet - when I do I will add more comments.

One thing that *does* look like a bug:
   sip show channelstats
   Peer             Call ID      Duration Recv: Pack  Lost       (     %) Jitter Send: Pack  Lost       (     %) Jitter
   x.x.x.x          xxxxxxxxxxx  00:03:24 0000009906  0000022726 (69.64%) 0.0000 0000009929  0000000001 ( 0.01%) 0.0037
   1 active SIP channel

As you can see, it claims a pretty insane lost packet count ... I believe this stems from the sequence number changing completely in the package with the Mark bit.
By: Andrew Pogrebennyk (apogrebennyk) 2011-12-29 03:36:04.683-0600

We are having a similar issue with asterisk 1.4.42
Normally the RTP timestamps increase by the time "covered" by a
packet. For example, for audio packets containing 20 ms of audio
sampled at 8,000 Hz, the timestamp for each block of audio increases
by 160. But from this particular asterisk, we see packet #71 with
timestamp=4336 and a few msec later packet #72 with timestamp=51575200.
Both packets have RTP marker bit set. The huge difference in timestamps is
causing the originating party to hang up the call. What other information
do you need or what would you suggest trying?
By: Andrew Pogrebennyk (apogrebennyk) 2011-12-29 03:36:33.894-0600

attached is the wireshark stream analysis
By: Kenneth Furge (kfurge) 2012-02-08 09:00:22.129-0600

We are experiencing the exact same issue with our SIP trunking provider (Nextiva).  Internal SIP phones do not have a problem, only SIP/RTP connections to our provider.  Most, but not all, audio interruptions are accompanied by this message in the log:

[Feb  7 21:57:52] DEBUG[3060] res_rtp_asterisk.c: Difference is 664, ms is 103
[Feb  7 21:58:06] DEBUG[3060] res_rtp_asterisk.c: Difference is 816, ms is 122
[Feb  7 21:58:10] DEBUG[3060] res_rtp_asterisk.c: Difference is 752, ms is 114
[Feb  7 22:00:10] DEBUG[3211] res_rtp_asterisk.c: Difference is 640, ms is 100
[Feb  7 22:00:25] DEBUG[3211] res_rtp_asterisk.c: Difference is 688, ms is 106
[Feb  7 22:00:26] DEBUG[3211] res_rtp_asterisk.c: Difference is 968, ms is 141
[Feb  7 22:00:27] DEBUG[3211] res_rtp_asterisk.c: Difference is 848, ms is 126
[Feb  7 22:00:31] DEBUG[3211] res_rtp_asterisk.c: Difference is 784, ms is 118
[Feb  7 22:00:44] DEBUG[3211] res_rtp_asterisk.c: Difference is 672, ms is 104
[Feb  7 22:00:47] DEBUG[3211] res_rtp_asterisk.c: Difference is 752, ms is 114

The audio interruption noted above is actually in the RTP stream sourced to the trunking provider by Asterisk.  We experience the problem with all sources tested so far (SIP phone, MOH, and milliwatt).  

I'm in the process of understanding the rtp module code to further debug this issue.  If any of the thread participants have resolved the problem, please post it here.  

Any help or guidance where the calculated numbers are derived would also be appreciated to accelerate my learning and debugging efforts.

My system is currently running Asterisk version 1.8.7.1 from the "optware" repository with the following Linux kernel:  Linux NASCB51C6 2.6.33.2 #1 SMP Sat Nov 26 00:13:38 CST 2011 i686 GNU/Linux