Summary:ASTERISK-01087: SIP/IAX2 show channels: delay and jitter wrong output
Reporter:zoa (zoa)Labels:
Date Opened:2004-02-24 08:02:24.000-0600Date Closed:2004-09-25 02:48:27
Versions:Frequency of
Description:iax2 show channels & sip show channels both seem to give incorrect output.
(0ms or a value that is way too big).


on one server:

Peer             Username    ID (Lo/Rem)  Seq (Tx/Rx)  Lag      Jitter  Format
x.x.x.x      xxx    16385/16384  00007/00012  00000ms  1454659ms  ILBC
x.x.x.x      xxx    16387/16387  00003/00005  00000ms  0005ms  ILBC
x.x.x.x      xxx    16393/16393  00008/00015  00000ms  0013ms  ILBC
x.x.x.x      xxx    16394/16394  00004/00006  00000ms  0014ms  ILBC

on the other server:

cleopatra*CLI> iax2 show channels
Peer             Username    ID (Lo/Rem)  Seq (Tx/Rx)  Lag      Jitter  Format
z.z.z.z  kreative    16386/00003  00008/00005  00120ms  0016ms  ILBC
y.y.y.y  yyy    16388/16386  00008/00004  00000ms  0003ms  ILBC
y.y.y.y  yyy    16389/16389  00031/00019  00000ms  0006ms  ILBC
y.y.y.y  yyy    16392/16388  00007/00004  00000ms  0007ms  ILBC

Server Y is calling to server X, the actual delay between the 2 hosts is 80ms

Sometimes both ends have some channels with 2343452345234ms delay and 213412341234ms jitter
(although calls sound normal and the other server reports a normal delay and jitter).

For some reason i have 0ms delay now, didnt see that before. it normally is 80ms or 45324523453245ms.

This might be not a very big bug... but then again, it might have a big influence on the jitter buffer.

SIP show channels always shows 0ms delay and 0ms jitter.
(confirmed by people in #asterisk)

Comments:By: zoa (zoa) 2004-02-24 08:42:42.000-0600

A Message from the future... (iax2 show channels)

16390/16390  00025/00018  00023ms  0005ms  ILBC
16393/16394  00021/00018  -49976ms  0004ms  ILBC
16394/16395  00012/00007  00000ms  0004ms  ILBC
16397/16399  00012/00007  00000ms  0012ms  ILBC

By: Olle Johansson (oej) 2004-02-24 09:33:19.000-0600

There's no jitter or delay handling in the SIP channel at all. The 0 is hard coded. I've added an explanation of this in chan_sip2, to avoid this confusion. There's another bug# about jitter in the SIP channel.

By: zoa (zoa) 2004-02-25 04:54:56.000-0600

today i have normal jitter and normal delay values on both servers.
(one of the servers had a reboot and a new TE410p). (+ i disabled hyperthreading).

By: clive18 (clive18) 2004-03-11 10:09:13.000-0600

I have a bad incomming connection with 550ms latency +- 50 ms jitter. My IAX2 jitter settings dont work, and basically its a shocking voice quality call.

A Jitter buffer fix, even a fixed delay, would be great.

By: zoa (zoa) 2004-03-14 20:24:39.000-0600

the patch that is in HEAD cvs for http://bugs.digium.com/bug_view_page.php?bug_id=0001195 might fix this. (or at least the delay part of it)

Update of /usr/cvsroot/asterisk/channels
In directory mongoose.digium.com:/tmp/cvs-serv8071/channels

Modified Files:
Log Message:
Preserve IAX timestamps

Index: chan_iax2.c
RCS file: /usr/cvsroot/asterisk/channels/chan_iax2.c,v
retrieving revision 1.104
retrieving revision 1.105
diff -u -d -r1.104 -r1.105
--- chan_iax2.c 7 Mar 2004 22:57:00 -0000       1.104
+++ chan_iax2.c 14 Mar 2004 23:01:12 -0000      1.105
@@ -507,7 +507,7 @@
static int send_command_final(struct chan_iax2_pvt *, char, int, unsigned int, char *, int, int);
static int send_command_transfer(struct chan_iax2_pvt *, char, int, unsigned int, char *, int);

-static unsigned int calc_timestamp(struct chan_iax2_pvt *p, unsigned int ts);
+static unsigned int calc_timestamp(struct chan_iax2_pvt *p, unsigned int ts, struct timeval *tv);

static int send_ping(void *data)
@@ -1101,7 +1101,7 @@
                               iax2_send(iaxs[fr->callno], &fr->af, fr->ts, -1, 0, 0, 0);
                       } else if (fr->af.subclass == IAX_COMMAND_LAGRP) {
                               /* This is a reply we've been given, actually measure the difference */
-                               ts = calc_timestamp(iaxs[fr->callno], 0);
+                               ts = calc_timestamp(iaxs[fr->callno], 0, NULL);
                               iaxs[fr->callno]->lag = ts - fr->ts;
               } else {
@@ -1581,6 +1581,15 @@
          IAX thread, with iaxsl lock held. */
       ms = calc_rxstamp(iaxs[fr->callno]) - fr->ts;

+       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;
+       if (fr->af.delivery.tv_usec >= 1000000) {
+               fr->af.delivery.tv_usec -= 1000000;
+               fr->af.delivery.tv_sec += 1;
+       }
       if (ms > 32767) {
               /* What likely happened here is that our counter has circled but we haven't
                  gotten the update from the main packet.  We'll just pretend that we did, and
@@ -2558,7 +2567,7 @@
       return ms + ts;

-static unsigned int calc_timestamp(struct chan_iax2_pvt *p, unsigned int ts)
+static unsigned int calc_timestamp(struct chan_iax2_pvt *p, unsigned int ts, struct timeval *delivery)
       struct timeval tv;
       unsigned int ms;
@@ -2567,8 +2576,12 @@
       /* If the timestamp is specified, just send it as is */
       if (ts)
               return ts;
-       gettimeofday(&tv, NULL);
-       ms = (tv.tv_sec - p->offset.tv_sec) * 1000 + (tv.tv_usec - p->offset.tv_usec) / 1000;
+       if (delivery && (delivery->tv_sec || delivery->tv_usec)) {
+               ms = (delivery->tv_sec - p->offset.tv_sec) * 1000 + (delivery->tv_usec - p->offset.tv_usec) / 1000;
+       } else {
+               gettimeofday(&tv, NULL);
+               ms = (tv.tv_sec - p->offset.tv_sec) * 1000 + (tv.tv_usec - p->offset.tv_usec) / 1000;
+       }
       /* We never send the same timestamp twice, so fudge a little if we must */
       if (ms <= p->lastsent)
               ms = p->lastsent + 1;
@@ -2643,7 +2656,7 @@
       lastsent = pvt->lastsent;

       /* Calculate actual timestamp */
-       fts = calc_timestamp(pvt, ts);
+       fts = calc_timestamp(pvt, ts, &f->delivery);

       if ((pvt->trunk || ((fts & 0xFFFF0000L) == (lastsent & 0xFFFF0000L)))
               /* High two bits are the same on timestamp, or sending on a trunk */ &&
@@ -4968,11 +4981,11 @@
                                       forward_command(iaxs[fr.callno], AST_FRAME_IAX, IAX_COMMAND_PONG, fr.ts, NULL, 0, -1);
                               } else {
                                       /* Calculate ping time */
-                                       iaxs[fr.callno]->pingtime =  calc_timestamp(iaxs[fr.callno], 0) - fr.ts;
+                                       iaxs[fr.callno]->pingtime =  calc_timestamp(iaxs[fr.callno], 0, NULL) - fr.ts;
                               /* Calculate ping time */
-                               iaxs[fr.callno]->pingtime =  calc_timestamp(iaxs[fr.callno], 0) - fr.ts;
+                               iaxs[fr.callno]->pingtime =  calc_timestamp(iaxs[fr.callno], 0, NULL) - fr.ts;
                               if (iaxs[fr.callno]->peerpoke) {
                                       peer = iaxs[fr.callno]->peerpoke;

By: zoa (zoa) 2004-03-19 11:47:10.000-0600

Peer             Username    ID (Lo/Rem)  Seq (Tx/Rx)  Lag      Jitter  Format
x    x    16385/16385  00007/00005  00000ms  0008ms  GSM
x    x    16391/16391  00011/00011  00000ms  777620ms  GSM
x    x    16394/16394  00007/00005  00000ms  0009ms  GSM

After the latest timestamp updates (latest cvs, stable branch), there are still timestamp problems.
(IAX2 between two latest stable branch cvs running servers)

By: Brian West (bkw918) 2004-04-10 07:05:49

turn jitter buffer off totally.  See what that does.

By: zoa (zoa) 2004-04-13 11:10:39

tried it without jitter buffer, its just not possible to run without on some days.

(For example today i suddenly experienced a burst jitter of 400ms for 30 minutes, then it all went back to a normal jitter of 10ms).

Asterisk was great in increasing and decreasing the jitter buffer, and at the beginning the output of iax2 show channels was looking fine, but now all of a sudden this is the output i'm getting:

x.x.x.x    iax-test    16384/16428  00005/00003  00000ms  0011ms  GSM
x.x.x.x    iax-test    16387/16389  00005/00003  00000ms  0011ms  GSM
x.x.x.x    iax-test    16390/16396  00011/00011  00000ms  0012ms  GSM
x.x.x.x    iax-test    16392/16415  00015/00017  00000ms  0012ms  GSM
x.x.x.x    iax-test    16398/16404  00005/00003  00000ms  0012ms  GSM
x.x.x.x    iax-test    16404/16402  00005/00003  00000ms  4351379ms  GSM  
x.x.x.x    iax-test    16405/16412  00006/00005  00000ms  0012ms  GSM
x.x.x.x    iax-test    16408/16400  00006/00005  00000ms  4351379ms  GSM  
x.x.x.x    iax-test    16415/16411  00005/00003  00000ms  4351370ms  GSM  
x.x.x.x    iax-test    16419/16432  00009/00009  00000ms  4351362ms  GSM  
x.x.x.x    iax-test    16420/16416  00005/00003  00000ms  4351370ms  GSM  
x.x.x.x    iax-test    16425/16406  00018/00021  00000ms  0011ms  GSM
x.x.x.x    iax-test    16429/16418  00026/00033  00000ms  0012ms  GSM
x.x.x.x    iax-test    16430/16425  00010/00009  00000ms  0012ms  GSM
x.x.x.x    iax-test    16436/16422  00004/00003  00000ms  4351368ms  GSM  
x.x.x.x    iax-test    16437/16440  00034/00045  00000ms  0012ms  GSM
x.x.x.x    iax-test    16439/16444  00009/00009  00000ms  4351375ms  GSM  
x.x.x.x    iax-test    16441/16442  00007/00005  00000ms  0012ms  GSM
x.x.x.x    iax-test    16445/16446  00006/00005  00000ms  0012ms  GSM
x.x.x.x    iax-test    16447/16447  00007/00005  00000ms  0011ms  GSM
x.x.x.x    iax-test    16449/16449  00007/00005  00000ms  4351365ms  GSM  
x.x.x.x    iax-test    16450/16450  00005/00003  00000ms  0012ms  GSM

I'm not running latest cvs-head, but

Asterisk CVS-04/07/04-20:53:33 built by root@imroVOIP1 on a i686 running Linux

(stable branch)

By: zoa (zoa) 2004-04-13 11:19:09

Most of the time, my fiber has a good connection, but even 30 minutes a day x 300 people is euhm quite a lot of money :)

I can live with a total delay of 400ms for a little while, its a lot better than not being able to call at all.


By: Mark Spencer (markster) 2004-04-26 00:30:20

Are you still seeing this problem?

By: zoa (zoa) 2004-04-26 04:24:08

I got an update on this one,

CVS -head does not have this origal issue, the jitter buffer works sweet for SIP -> IAX2 connections, i can recommend all people on jittery lines to use the current -head version. DO NOT USE a jitter buffer with the stable version !!!!

I however found another problem with IAXclient -> *(A) -> *(B) links, with and without native bridging where all delays and jitters on the streams from IAXclient to *(A)are reported as 0 ms by *(A).

I think asterisk really needs to have a jitter buffer on a per peer basis, as now when i set a jitter buffer (e.g. 200ms) on asterisk A and asterisk B to have a jitter buffer in both directions, i will have an extra one way jitter buffer between asterisk A and the IAXclient i don't need since IAXclient is on the same lan as asterisk A.
Would a per peer jitter buffer be a big thing to implement.

While i'm busy, could someone tell me if an IAX2 native bridge will also use the jitter buffer or the jitter buffer has no affect on these kinds of connections.?

By: twisted (twisted) 2004-05-02 00:08:06

If you're asking about a new feature, you need to open a new feature request... If you enter a native iax bridge, according to markster, the jitterbuffer is no longer in play.   I'm going to close this since the origional issue has been resolved in -head.