[Home]

Summary:ASTERISK-01226: Passing original timestamps requires validation of ALL sources
Reporter:Paul Cadach (pcadach)Labels:
Date Opened:2004-03-17 00:33:52.000-0600Date Closed:2004-09-25 02:53:49
Priority:MajorRegression?No
Status:Closed/CompleteComponents:Core/General
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:
Description:Usually command frames (not voice/video) are generated "on the fly" like:
void xxx()
{
 ast_frame f;
 f.class = ...
 ...
 send_frame_function(..., &f, ...);
}

Procedures like pointed above needs to be checked to zeroing newly added timestamp field "delivery".

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

Timestamp bug found and acknoweleged at IAX2 channel's function send_command(). Possible solution are:
--- channels/chan_iax2.c~       Wed Mar 17 09:19:25 2004
+++ channels/chan_iax2.c        Wed Mar 17 11:10:09 2004
@@ -3092,6 +3092,7 @@
       f.offset = 0;
       f.src = __FUNCTION__;
       f.data = data;
+       memset(&f.delivery, 0, sizeof(f.delivery));
       return iax2_send(i, &f, ts, seqno, now, transfer, final);
}

Comments:By: Paul Cadach (pcadach) 2004-03-17 00:49:15.000-0600

Other possible solution is to assign empty structure to local variable by construction like:
ast_frame f = {};
By: Brian West (bkw918) 2004-03-17 14:54:50.000-0600

does this fixed the MAJOR fucked issues with IAX2 to SIP with the recent changes to rtp.c, frame.c and frame.h?
By: zoa (zoa) 2004-03-17 14:55:42.000-0600

no bkw, but the latest bug i changed to "resolved" does
By: Paul Cadach (pcadach) 2004-03-17 15:25:35.000-0600

There are many places to validate for correct handling of "transparent" timestamping. One place is IAX2, other place resolved by zoa at RTP, etc... But RTP's patch doesn't resolve weirdness for H.323 calls:
DEBUG[35857]: rtp.c:1004 ast_rtp_raw_write: Difference is 792479792, ms is 1511552782

So, detailed revising and validating of sources are required to make this pretty "transparency" working nice everywhere.
By: zoa (zoa) 2004-03-18 03:11:36.000-0600

Any ideas if this might cause problems in communications between two different boxes  ?
(one running a pre-timestamp-fix cvs version and one a post-timestampfix version ?).
By: Paul Cadach (pcadach) 2004-03-18 14:52:03.000-0600

Oops... calc_txstamp() at rtp.c requires to store last delivery argument value to distinguish between "bridged" and "non-bridged" (self-generated) frames and calculate timestamps appropriately.

Also, codec translation doesn't handles timestamps.
By: Paul Cadach (pcadach) 2004-03-18 15:21:05.000-0600

And, IAX2 "transparent timestamp" calculations still broken a little - timestamps "floats" +/- 1 ms when RTP's stream passes frames granularly (at 160 RTP's ticks for me, i.e. 20 ms exactly), codec translation isn't used jet (both sides, RTP and IAX2, uses the same codec).
By: Paul Cadach (pcadach) 2004-03-18 16:13:33.000-0600

2zoa: possible solution to make interwoking between old (non-timestamp-passing) ans new versions is to provide option to "trust" or "not trust" for timestamps, at least for IAX channel driver which generates timestamps based on real packet delivery time, not planned/proposed time. In opposition to IAX2, *'s RTP stack uses predicted timestamps so they are more granulated (i.e. steps by real playout time of frame to send) than generated by IAX.

"Hard" solution (tested at my boxes) is to comment out fr->af.delivery manipulations at schedule_delivery() in iax2.c, something like this (line numbers can differs from your):
--- chan_iax2.c~        Fri Mar 19 02:56:11 2004
+++ chan_iax2.c Fri Mar 19 02:56:11 2004
@@ -1595,16 +1595,18 @@
               ms += 65536;
               fr->ts -= 65536;
       }

+#if 0
       fr->af.delivery.tv_sec = iaxs[fr->callno]->rxcore.tv_sec;
       fr->af.delivery.tv_usec = iaxs[fr->callno]->rxcore.tv_usec;
       fr->af.delivery.tv_sec += fr->ts / 1000;
       fr->af.delivery.tv_usec += (fr->ts % 1000) * 1000;
       if (fr->af.delivery.tv_usec >= 1000000) {
               fr->af.delivery.tv_usec -= 1000000;
               fr->af.delivery.tv_sec += 1;
       }
+#endif


       /* Rotate our history queue of "lateness".  Don't worry about those initial
          zeros because the first entry will always be zero */
By: Mark Spencer (markster) 2004-03-19 03:18:11.000-0600

I believe i have a much simpler and more elegant fix.  please confirm it works for you.  Thanks!
By: Paul Cadach (pcadach) 2004-03-19 08:49:05.000-0600

Yep, looks like fix proposed by me. But what about "floating" of timestamps pointed before in this track? An example connection scheme is Skinny (RTP) <-> * -> IAX2 <-> * (echo application), and timestamps provided by both ends of first Asterisk is next:
16904368 (RTP) -> 3641 (IAX2)
16904528 (RTP) -> 3662 (IAX2)
As you can see, RTP's delta is 160 tick, i.e. 20 ms exactly, but IAX2's delta is 21 ms. When IAX2 packets comes back to RTP it makes inconsistence of RTP's timestamps.

Also, IAX2 always drops first "long" voice frame... Could it be fixed?
By: Mark Spencer (markster) 2004-03-19 10:46:57.000-0600

Find me on irc and i'll login and look.
By: Paul Cadach (pcadach) 2004-03-19 15:06:17.000-0600

Forget about dropping first full voice frame... My mistake...
By: Mark Spencer (markster) 2004-03-20 00:25:54.000-0600

I've modified both iax and sip to round their timestamps to nearest 20ms.  That should fix it, can you confirm?
By: rburkholder (rburkholder) 2004-03-20 17:09:23.000-0600

There must be some differences in 'gettimeofday'.  As when the 20ms thing was implemented, it broke on two different boxes for me.  An Ethereal dump shows what is happening:

361   4.106471    10.1.1.12 -> 10.1.6.2     RTP Payload type=ITU-T G.711 PCMU, SSRC=276914230, Seq=19241, Time=3718062136
362   4.125856     10.1.6.2 -> 10.1.1.12    RTP Payload type=ITU-T G.711 PCMU, SSRC=521637715, Seq=52738, Time=29615344
363   4.126468    10.1.1.12 -> 10.1.6.2     RTP Payload type=ITU-T G.711 PCMU, SSRC=276914230, Seq=19242, Time=3718062136
364   4.145901     10.1.6.2 -> 10.1.1.12    RTP Payload type=ITU-T G.711 PCMU, SSRC=521637715, Seq=52739, Time=29615504

10.1.1.12 is *, 10.1.6.2 is a Cisco phone.  You can see the Time stamps for the phone increase by 160, but the timestamps from * do not.  When I put the code back to the way it was, things worked better.  

I also note that the sequences on the cisco phone are EXACT multiples of 160.  The * sequences vary.  You would think that the sum of the differences of the differences between sequences should equal 0, but they do not.  

Perhaps the time stamp should be a multiple of the sequence number instead so that exact timestamps may be computed, such like Cisco phones do.

The milliwatt app helped me to aurally test 'goodness' of the timestamping.
By: Mark Spencer (markster) 2004-03-20 18:35:44.000-0600

I cannot duplicate this problem with echo.  I've updated app_milliwatt to be aware of delivery times and also made sure that playtones knows about it.  Hopefully there won't be any more surprises along the way.
By: Paul Cadach (pcadach) 2004-03-21 01:43:35.000-0600

2Mark: zeroing delivery time at indications.c isn't required because frame structure is filled by zeroes before generation of wave's data. The same for res/res_musiconhold.c (frame is zeroed out immediately before filling with real values).
By: Mark Spencer (markster) 2004-03-21 02:39:53.000-0600

Okay I took out the unnecessary ones, i'll go ahead and close this one out.