Making sense of jitter related PJMEDIA debug messages

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



A little bit addition, actually pjsua should produce the same log messages,
it's just that they are suppressed by log level is 4. Whether they're
harmful or not depends on whether the audio quality is good (or not). If
audio is good, then they're not harmful, and if audio is bad, then those are
stuff that you or I need to look into. :)

Cheers
 Benny


On Mon, Sep 8, 2008 at 3:57 PM, Klaus Darilion <klaus.mailinglists at pernau.at
> wrote:

> Hi Ruud!
>
> I have tons of such warnings when testing with clients running in
> VMwares. The time in my VMware is not accurate thus the clients have
> different timing and it happens that the jitter buffer gets filled up or
> gets empty. Then pjsip dynamically increases/decreases playback speed to
> compensate the different timing (actually the pitch stays constant -
> thus streaming a music file sounds very funy).
>
> Maybe your problem is similar.
>
> regards
> klaus
>
> Ruud Klaver schrieb:
> > Hi,
> >
> > I'm using PJMEDIA from my own application, and I've noticed that it
> > outputs a lot of debug statements related to the audio stream. I do
> > not see these messages when I use the pjsua binary.
> >
> > I want to make sure I am handling streams correctly and do not have
> > any jitter issues caused e.g. by threading. Could someone help me by
> > explaining exactly what these messages mean and if they are harmful in
> > any way?
> >
> > This is an excerpt from my log:
> >
> > 2008-09-08 14:00:38.617000 (4)   Master/sound: Underflow, buf_cnt=0,
> > will generate 1 frame
> > 2008-09-08 14:00:38.618000 (5)   strm0x95d9a8: Jitter buffer empty
> > (prefetch=1)
> > 2008-09-08 14:00:38.620000 (5)   strm0x95d9a8: Start talksprut..
> > 2008-09-08 14:00:38.642000 (5)   strm0x95d9a8: RTP status: badpt=0,
> > badssrc=0, dup=0, outorder=0, probation=-1, restart=0
> > 2008-09-08 14:00:38.675000 (5)   strm0x95d9a8: jb updated(2),
> > prefetch=2, size=2
> > 2008-09-08 14:00:39.244000 (4)   strm0x95d9a8: VAD re-enabled
> > 2008-09-08 14:00:39.244000 (5)   strm0x95d9a8: Starting silence
> > 2008-09-08 14:00:39.821000 (5)   strm0x95d9a8: jb updated(2),
> > prefetch=4, size=4
> > 2008-09-08 14:00:41.522000 (5)   strm0x95d9a8: Start talksprut..
> > 2008-09-08 14:00:41.538000 (5)   strm0x95d9a8: Starting silence
> > 2008-09-08 14:00:41.853000 (5)   strm0x95d9a8: jb updated(1),
> > prefetch=3, size=2
> > 2008-09-08 14:00:43.604000 (5)   strm0x95d9a8: Internal RTCP NTP clock
> > skew detected: lsr=0x9266d31b, now=0x926a9aca, dlsr=0x4c624 (4:773ms),
> > diff=65141
> > 2008-09-08 14:00:43.870000 (5)   strm0x95d9a8: jb updated(1),
> > prefetch=2, size=2
> > 2008-09-08 14:00:46.051000 (5)   strm0x95d9a8: Start talksprut..
> > 2008-09-08 14:00:46.936000 (5)   strm0x95d9a8: Starting silence
> > 2008-09-08 14:00:47.052000 (5)   strm0x95d9a8: Start talksprut..
> > 2008-09-08 14:00:47.310000 (5)   strm0x95d9a8: Jitter buffer empty
> > (prefetch=2)
> > 2008-09-08 14:00:47.339000 (5)   strm0x95d9a8: jb updated(2),
> > prefetch=4, size=4
> > 2008-09-08 14:00:48.039000 (5)   strm0x95d9a8: Starting silence
> > 2008-09-08 14:00:48.562000 (5)   strm0x95d9a8: Start talksprut..
> > 2008-09-08 14:00:48.606000 (5)   strm0x95d9a8: Internal RTCP NTP clock
> > skew detected: lsr=0x926bb2fd, now=0x926f9b31, dlsr=0x4e5e3 (4:897ms),
> > diff=64943
> > 2008-09-08 14:00:49.356000 (5)   strm0x95d9a8: jb updated(1),
> > prefetch=3, size=4
> > 2008-09-08 14:00:50.724000 (5)   strm0x95d9a8: Starting silence
> > 2008-09-08 14:00:51.145000 (5)   strm0x95d9a8: Start talksprut..
> > 2008-09-08 14:00:51.373000 (5)   strm0x95d9a8: jb updated(1),
> > prefetch=2, size=4
> > 2008-09-08 14:00:51.374000 (5)   strm0x95d9a8: JB shrinking 1
> > frame(s), size=3
> > 2008-09-08 14:00:51.943000 (5)   strm0x95d9a8: Starting silence
> > 2008-09-08 14:00:51.958000 (5)   strm0x95d9a8: Start talksprut..
> > 2008-09-08 14:00:53.602000 (5)   strm0x95d9a8: Internal RTCP NTP clock
> > skew detected: lsr=0x9270c79f, now=0x92749a20, dlsr=0x4d0e5 (4:815ms),
> > diff=65124
> > 2008-09-08 14:00:54.261000 (5)   strm0x95d9a8: jb updated(2),
> > prefetch=4, size=5
> > 2008-09-08 14:00:57.033000 (5)   strm0x95d9a8: jb updated(1),
> > prefetch=3, size=3
> > 2008-09-08 14:00:58.605000 (5)   strm0x95d9a8: Internal RTCP NTP clock
> > skew detected: lsr=0x9275dbed, now=0x92799b07, dlsr=0x4bd2f (4:738ms),
> > diff=65045
> > 2008-09-08 14:00:59.051000 (5)   strm0x95d9a8: jb updated(1),
> > prefetch=2, size=3
> > 2008-09-08 14:01:03.603000 (5)   strm0x95d9a8: Internal RTCP NTP clock
> > skew detected: lsr=0x927af044, now=0x927e9a6b, dlsr=0x4a872 (4:657ms),
> > diff=65099
> > 2008-09-08 14:01:08.542000 (5)   strm0x95d9a8: jb updated(2),
> > prefetch=4, size=5
> > 2008-09-08 14:01:12.318000 (5)   strm0x95d9a8: Starting silence
> > 2008-09-08 14:01:12.373000 (5)   strm0x95d9a8: jb updated(1),
> > prefetch=3, size=3
> > 2008-09-08 14:01:12.754000 (5)   strm0x95d9a8: Start talksprut..
> > 2008-09-08 14:01:14.391000 (5)   strm0x95d9a8: jb updated(1),
> > prefetch=2, size=3
> > 2008-09-08 14:01:14.713000 (5)   strm0x95d9a8: Starting silence
> > 2008-09-08 14:01:14.800000 (5)   strm0x95d9a8: Start talksprut..
> > 2008-09-08 14:01:23.882000 (5)   strm0x95d9a8: jb updated(2),
> > prefetch=4, size=5
> > 2008-09-08 14:01:25.322000 (5)   strm0x95d9a8: Starting silence
> > 2008-09-08 14:01:26.032000 (5)   strm0x95d9a8: Start talksprut..
> > 2008-09-08 14:01:27.249000 (5)   strm0x95d9a8: Jitter buffer empty
> > (prefetch=4)
> > 2008-09-08 14:01:29.295000 (5)   strm0x95d9a8: jb updated(1),
> > prefetch=3, size=4
> > 2008-09-08 14:01:31.312000 (5)   strm0x95d9a8: jb updated(1),
> > prefetch=2, size=4
> > 2008-09-08 14:01:31.312000 (5)   strm0x95d9a8: JB shrinking 1
> > frame(s), size=3
> > 2008-09-08 14:01:33.797000 (5)   strm0x95d9a8: Starting silence
> > 2008-09-08 14:01:33.971000 (5)   strm0x95d9a8: Start talksprut..
> > 2008-09-08 14:01:38.162000 (5)   strm0x95d9a8: jb updated(2),
> > prefetch=4, size=5
> > 2008-09-08 14:01:42.269000 (5)   strm0x95d9a8: Jitter buffer empty
> > (prefetch=4)
> > 2008-09-08 14:01:44.316000 (5)   strm0x95d9a8: jb updated(1),
> > prefetch=3, size=4
> > 2008-09-08 14:01:46.333000 (5)   strm0x95d9a8: jb updated(1),
> > prefetch=2, size=4
> > 2008-09-08 14:01:46.333000 (5)   strm0x95d9a8: JB shrinking 1
> > frame(s), size=3
> > 2008-09-08 14:01:48.603000 (5)   strm0x95d9a8: Internal RTCP NTP clock
> > skew detected: lsr=0x92a8a74d, now=0x92ab9a86, dlsr=0x3f1a9 (3:943ms),
> > diff=65136
> > 2008-09-08 14:01:53.342000 (5)   strm0x95d9a8: jb updated(2),
> > prefetch=4, size=5
> > 2008-09-08 14:01:53.602000 (5)   strm0x95d9a8: Internal RTCP NTP clock
> > skew detected: lsr=0x92adbb9d, now=0x92b09a33, dlsr=0x3dced (3:862ms),
> > diff=65111
> >
> > Thanks in advance.
> >
> > Ruud Klaver
> > AG Projects
> >
> > _______________________________________________
> > Visit our blog: http://blog.pjsip.org
> >
> > pjsip mailing list
> > pjsip at lists.pjsip.org
> > http://lists.pjsip.org/mailman/listinfo/pjsip_lists.pjsip.org
>
> _______________________________________________
> Visit our blog: http://blog.pjsip.org
>
> pjsip mailing list
> pjsip at lists.pjsip.org
> http://lists.pjsip.org/mailman/listinfo/pjsip_lists.pjsip.org
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.pjsip.org/pipermail/pjsip_lists.pjsip.org/attachments/20080908/a4486e68/attachment-0001.html 


[Index of Archives]     [Asterisk Users]     [Asterisk App Development]     [Linux ARM Kernel]     [Linux ARM]     [Linux Omap]     [Fedora ARM]     [IETF Annouce]     [Security]     [Bugtraq]     [Linux]     [Linux OMAP]     [Linux MIPS]     [Linux API]
  Powered by Linux