[Asterisk-Dev] IAX2 timestamping issues identified from trace analysis

[steve at daviesfam.org]

Hi all,

I've been looking at the behaviour of the jitter buffer in IAX2.

This has uncovered some issues with timestamp generation in IAX2.  Mark - 
I sent you some traces a couple of days ago, this is a summary of the 
issues that I have found, with my proposed fixes.

I'm sorry this is long - but there is a weekend's investigation and work 
here, so I think its worth reading.

If the proposed fix approaches are OK then I'll put the issues on bugs and
start sending patches.

stevenkstevenk opened a bug with some more "knobs" for the jitter buffer - 
those should be fine along with these fixes.  But I can't really comment 
on increasing the JITTERWINDOW etc - I think we should fix the bugs 
identified here before fiddling too much with the existing jitterbuffer 
algorithm.  I did add my comments to his bug on the bugtracker.

So before making changes to the basic workings of the jitter buffer on the
receiving side, I'd like to make the generated timestamps on the sending
side as correct as possible!

Here are the issues identified:


Issue 1: crazy nonsense timestamps when chan_capi-sourced frames are 
sent over IAX2.

This is an issue that chan_capi 0.3.1 did not initialise the delivery 
field in the frame.  This was added in 0.3.2.

I do see that apparently other channels don't initialise it either - 
chan_modem_i4l for example.

Proposed fix:
  1) I and others who want to use the jitter bufer should upgrade to 
     latest chan_capi (0.3.4 at the time of writing)
  2) also think that calc_timestamp should do a sanity check of the values 
     in "delivery" before just using them!


Issue 2: apparent incoming jitter glitches every 10 seconds.

This is actually a problem with timestamp generation on the sending side.  
Control frames generated on the sending side have out of sequence 
timestamps - they get send with clock-based stamps rather than 
nextpred-derived.

This is despite the code in calc_timestamp for using lastsent+3 
timestamps.  These control frame are "genuine" (see the code)
consequently the stamp will only be adjusted if it is less than lastsent - 
and that is very unlikely because lastsent/nextpred will tend to lag 
behind the clock.

There's also a second issue in that amongst the frames exchanged every 10 
seconds, some are replies to frames that we sent (our LAGRQ gets a LAGRP 
in reply; our PING gets a PONG).  These reply frames carry _our_ 
timestamps.  Our's and their's are not synced.  And besides, this is our 
timestamp that has been to the other end and back - so has seen extra 
delay relative to the others.

Proposed fix:
  1) in calc_timestamp, either or both of:
	a) Eliminate the "genuine" distinction (what's it for, anyway?)
	   so that we'll use the +3 logic for control frames even if clock/lastsent skew
	   is up to 640msec, or whatever we make that in adjusting for 
	   issue 1.
	b) when we don't use +3, perhaps nextpred should be adjusted, so 
	   that at least we get things back into step all in one go.
  2) schedule_delivery should ignore non-voice frames when tracking jitter
  3) schedule_delivery should especially not use LAGRP/PONG/ACK frames
     to track jitter!


Issue 3: glitches every 65.536 seconds

The is the same issue as the 2nd part of issue 2 - ACKs to our VOICE 
frames are being measured by the jitter buffer

Proposed fix:
  As point 2/3 of issue 2


Issue 4: saw a case where jitter buffer saw huge jump backwards in 
timestamps

[Can't find this logfile now?  and certainly can't duplicate this problem 
on my CVS-HEAD systems]

What happened was that the VOICE full-frames weren't received.  
schedule_delivery has some logic that added 65536 to the timestamp - that 
worked for the first wrap, but failed to work again when the second VOICE 
full-frame also didn't turn up.

So things went:
  Received		Interpreted as
  0-65535		0-65535				OK!
  0-65535		65536-131071			OK!
  0-65535		65536-131071			NOT OK!

Is the sending of full voice-frames something that was added along the 
way?  In which case, our peer obviously had an old version.

This issue would explain the 65536 jitters that people report seeing in 
iax2 show channels.

Proposed fix:
  1) peer should upgrade?  or was something else wrong?
  2) schedule_delivery should be changed to handle each wrap
     by adding "n*65536" to the received miniframe timestamp.


Please send your comments and questions!

Regards,
Steve