[Home]

Summary:ASTERISK-02338: IAXY generates incorrect timestamps in IAX2 stream
Reporter:Steve Davies . (stevedavies)Labels:
Date Opened:2004-09-04 06:19:27Date Closed:2008-01-15 15:06:55.000-0600
Priority:MinorRegression?No
Status:Closed/CompleteComponents:Channels/chan_iax2
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) iaxytimestamps.log.gz
Description:The IAXY box (up to and including version 18) frequently skips timestamps in its generated voice frames.

I'm NOT saying that the IAXY sends frames late or loses some.  It does generate a steady stream, but every few seconds the timestamps jump ahead.

For example:

 at time:      IAXY sends:
   20              20
   40              40
   60              176
   80              180

The nett jump ahead often seems to be 100msec (5 frames).  Other jumps are seen, but they are always an exact multiple of 20msec.

Remember - I'm not talking about lost frames.  Its an issue with the IAXY losing count of the frames or bytes its sent, or something like that.

I will attach a log file showing what I mean.

These messed up timestamps cause the jitter buffer code major problems.  It is indistinguishable from real network jitter, so the code corrects it - but in doing so introduces corruption as really the frames are right on time (on my lan, anyway), but it's the timestamps that are messed up.

Perhaps some may say just turn the jitter buffer off.  However if an IAXY users' all is forwarded on from the local machine using IAX again, then the timestamp problem will be forwarded on - perhaps to a 3rd party system that does have jitter buffer enabled.

Comments:By: Mark Spencer (markster) 2004-09-04 10:51:07

Certainly needs to be fixed, but I don't believe it merits status as a "MAJOR" bug since clearly there is a work around.
By: Mark Spencer (markster) 2004-09-04 12:21:08

I have a test image prepared to fix the problem, can you find me on IRC so I can get it to you?
By: Steve Davies . (stevedavies) 2004-09-04 14:00:51

Hi Mark,

Thanks for the quick response.  However, the test image doesn't make any difference.  (I did make sure that it really downloaded to my IAXY, and it is saying version 19).

Anyway, here is another log extract in detail.

Here I've added extra logging in ast_channel_bridge, so you can see exactly when the frames are processed in local machine timestamps.  There is nearly exactly 20 msec between each IAXY frame - INCLUDING 20 msec between the frame stamped 10040 and the following one stamped 10180.

Note that all the "delivered immediatelys" are because the jitter buffer is disabled.  This also means you can be sure that frames get to ast_channel_bridge immediately when they arrive.

This call was bridged between the IAX2 channel to the IAXY, and a local TDM400 Zap interface.

Regards,
Steve




Sep  4 20:51:19 DEBUG[131080]: Jitter: call=3 ts=10000 VOICE: min=-179 max=0 jb=40 +0; lateness=-174; jitter=179 historic=179
Sep  4 20:51:19 DEBUG[131080]: schedule_delivery: Delivering immediately (Calculated ms is 0)
Sep  4 20:51:19 DEBUG[262159]: ast_channel_bridge: At 1094323879.378565 reading from IAX2/iaxy1@iaxy1/3
Sep  4 20:51:19 DEBUG[262159]: ast_channel_bridge: At 1094323879.390295 reading from Zap/2-1
Sep  4 20:51:19 DEBUG[262159]: Sending 9851 on 3/8278 to 195.217.255.35:4569
Sep  4 20:51:19 DEBUG[131080]: Jitter: call=3 ts=10020 VOICE: min=-179 max=0 jb=40 +0; lateness=-174; jitter=179 historic=178
Sep  4 20:51:19 DEBUG[131080]: schedule_delivery: Delivering immediately (Calculated ms is 0)
Sep  4 20:51:19 DEBUG[262159]: ast_channel_bridge: At 1094323879.398552 reading from IAX2/iaxy1@iaxy1/3
Sep  4 20:51:19 DEBUG[262159]: ast_channel_bridge: At 1094323879.410294 reading from Zap/2-1
Sep  4 20:51:19 DEBUG[262159]: Sending 9871 on 3/8278 to 195.217.255.35:4569
Sep  4 20:51:19 DEBUG[131080]: Jitter: call=3 ts=10040 VOICE: min=-179 max=0 jb=40 +0; lateness=-174; jitter=179 historic=179
Sep  4 20:51:19 DEBUG[131080]: schedule_delivery: Delivering immediately (Calculated ms is 0)
Sep  4 20:51:19 DEBUG[262159]: ast_channel_bridge: At 1094323879.418555 reading from IAX2/iaxy1@iaxy1/3
Sep  4 20:51:19 DEBUG[262159]: ast_channel_bridge: At 1094323879.430291 reading from Zap/2-1
Sep  4 20:51:19 DEBUG[262159]: Sending 9891 on 3/8278 to 195.217.255.35:4569
Sep  4 20:51:19 DEBUG[131080]: Jitter: call=3 ts=10180 VOICE: min=-294 max=0 jb=40 +0; lateness=-294; jitter=294 historic=294
Sep  4 20:51:19 DEBUG[131080]: schedule_delivery: Delivering immediately (Calculated ms is 0)
Sep  4 20:51:19 DEBUG[262159]: ast_channel_bridge: At 1094323879.438562 reading from IAX2/iaxy1@iaxy1/3
Sep  4 20:51:19 DEBUG[262159]: ast_channel_bridge: At 1094323879.450327 reading from Zap/2-1
Sep  4 20:51:19 DEBUG[262159]: Sending 9911 on 3/8278 to 195.217.255.35:4569
Sep  4 20:51:19 DEBUG[131080]: Jitter: call=3 ts=10200 VOICE: min=-294 max=0 jb=40 +0; lateness=-294; jitter=294 historic=293
Sep  4 20:51:19 DEBUG[131080]: schedule_delivery: Delivering immediately (Calculated ms is 0)
Sep  4 20:51:19 DEBUG[262159]: ast_channel_bridge: At 1094323879.458474 reading from IAX2/iaxy1@iaxy1/3
Sep  4 20:51:19 DEBUG[262159]: ast_channel_bridge: At 1094323879.470322 reading from Zap/2-1
Sep  4 20:51:19 DEBUG[262159]: Sending 9931 on 3/8278 to 195.217.255.35:4569
By: Mark Spencer (markster) 2004-09-04 23:27:21

How about the second image i gave you?
By: Steve Davies . (stevedavies) 2004-09-06 02:07:41

Hi,

Mark sent me a second test image that is MUCH MUCH better than v18 at timekeeping.  He has now sent me a third that I will test as soon as I get home.

Thanks for the great support, Mark!

Steve
By: Mark Spencer (markster) 2004-09-06 22:06:36

Fixed in CVS
By: Digium Subversion (svnbot) 2008-01-15 15:06:55.000-0600

Repository: asterisk
Revision: 3737

U   trunk/contrib/firmware/iax/iaxy.bin

------------------------------------------------------------------------
r3737 | markster | 2008-01-15 15:06:54 -0600 (Tue, 15 Jan 2008) | 2 lines

Upgrade firmware to version 19 (improved timestamps from bug ASTERISK-2338), extra protetions for buck boost Q7.

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

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