Thread: [Opalvoip-devel] Bug in rtp.cxx
Brought to you by:
csoutheren,
rjongbloed
|
From: Southanon R. <sra...@la...> - 2013-02-15 19:37:01
|
There seems to be a bug in rtp.cxx that causes the jitterLevel to jump
up in some cases. The bug is seen when the difference in time goes from
large to small to large again. This seems to be present in the opal
3.10.9 release.
This is the line of the bug in rtp.cxx, function is Internal_OnReceiveData.
// As per RFC3550 Appendix 8
diff *= GetJitterTimeUnits(); // Convert to timestamp units
long variance = diff - lastTransitTime;
Both "diff" and "lastTransitTime" are unsigned. If lastTransitTime is
bigger than diff, this produces a very large unsigned number. Not the
small negative number we are expecting.
Here is sample output demonstrating what is happening:
0:11.293 RTP Jitter:0xe3494910 rtp.cxx(1346) RTP Session
1, ssrc=3735373445, jitterLevel = 21
0:11.318 RTP Jitter:0xe3494910 rtp.cxx(1305) RTP
Session 1, ssrc=3735373445, tick = 170:25:21.136, lastReceivedPacketTime
= 170:25:21.110, diff = 26
0:11.318 RTP Jitter:0xe3494910 rtp.cxx(1324) RTP
Session 1, ssrc=3735373445, diff = 208, lastTransitTime = 152, variance
= 56, variance2 = 56
0:11.318 RTP Jitter:0xe3494910 rtp.cxx(1346) RTP
Session 1, ssrc=3735373445, jitterLevel = 76
0:11.333 RTP Jitter:0xe3494910 rtp.cxx(1305) RTP
Session 1, ssrc=3735373445, tick = 170:25:21.151, lastReceivedPacketTime
= 170:25:21.136, diff = 15
0:11.333 RTP Jitter:0xe3494910 rtp.cxx(1324) RTP
Session 1, ssrc=3735373445, diff = 120, lastTransitTime = 208, variance
= 4294967208, variance2 = -88
0:11.333 RTP Jitter:0xe3494910 rtp.cxx(1346) RTP
Session 1, ssrc=3735373445, jitterLevel = 4294967279
0:11.353 RTP Jitter:0xe3494910 rtp.cxx(1305) RTP
Session 1, ssrc=3735373445, tick = 170:25:21.170, lastReceivedPacketTime
= 170:25:21.151, diff = 19
0:11.353 RTP Jitter:0xe3494910 rtp.cxx(1324) RTP
Session 1, ssrc=3735373445, diff = 152, lastTransitTime = 120, variance
= 32, variance2 = 32
Notice the jump in the variance value when diff is smaller than
lastTransitTime. variance2 is the same calculation with lastTransitTime
type casted to a long. Since this variance is part of the jitterLevel
calculation, this subsequently causes the jitterLevel to jump in value
dramatically.
Best Regards,
Southanon
|
|
From: Robert J. <ro...@vo...> - 2013-02-15 23:09:13
|
As "variance" is a signed value the "unsigned wraparound" problem should not occur. However, I can see in the log what you are saying. The only thing I can think of is you are using a 64 bit compiler and "variance" is a 64 bit signed integer. Then, if the compiler does not do the sign extension for the unsigned expression (diff - lastTransitTime) then I can see how it could occur. I have changed the code to guarantee a positive number. *Robert Jongbloed* /OPAL/OpenH323/PTLib Architect and Co-founder./ Commercial support at http://www.voxlucida.com.au On 16/02/2013 6:09 AM, Southanon Ratsamy wrote: > There seems to be a bug in rtp.cxx that causes the jitterLevel to jump > up in some cases. The bug is seen when the difference in time goes > from large to small to large again. This seems to be present in the > opal 3.10.9 release. > > This is the line of the bug in rtp.cxx, function is > Internal_OnReceiveData. > > // As per RFC3550 Appendix 8 > diff *= GetJitterTimeUnits(); // Convert to timestamp units > long variance = diff - lastTransitTime; > > Both "diff" and "lastTransitTime" are unsigned. If lastTransitTime is > bigger than diff, this produces a very large unsigned number. Not the > small negative number we are expecting. > > Here is sample output demonstrating what is happening: > > 0:11.293 RTP Jitter:0xe3494910 rtp.cxx(1346) RTP Session > 1, ssrc=3735373445, jitterLevel = 21 > 0:11.318 RTP Jitter:0xe3494910 rtp.cxx(1305) RTP > Session 1, ssrc=3735373445, tick = 170:25:21.136, > lastReceivedPacketTime = 170:25:21.110, diff = 26 > 0:11.318 RTP Jitter:0xe3494910 rtp.cxx(1324) RTP > Session 1, ssrc=3735373445, diff = 208, lastTransitTime = 152, > variance = 56, variance2 = 56 > > 0:11.318 RTP Jitter:0xe3494910 rtp.cxx(1346) RTP > Session 1, ssrc=3735373445, jitterLevel = 76 > 0:11.333 RTP Jitter:0xe3494910 rtp.cxx(1305) RTP > Session 1, ssrc=3735373445, tick = 170:25:21.151, > lastReceivedPacketTime = 170:25:21.136, diff = 15 > 0:11.333 RTP Jitter:0xe3494910 rtp.cxx(1324) RTP > Session 1, ssrc=3735373445, diff = 120, lastTransitTime = 208, > variance = 4294967208, variance2 = -88 > > 0:11.333 RTP Jitter:0xe3494910 rtp.cxx(1346) RTP > Session 1, ssrc=3735373445, jitterLevel = 4294967279 > 0:11.353 RTP Jitter:0xe3494910 rtp.cxx(1305) RTP > Session 1, ssrc=3735373445, tick = 170:25:21.170, > lastReceivedPacketTime = 170:25:21.151, diff = 19 > 0:11.353 RTP Jitter:0xe3494910 rtp.cxx(1324) RTP > Session 1, ssrc=3735373445, diff = 152, lastTransitTime = 120, > variance = 32, variance2 = 32 > > Notice the jump in the variance value when diff is smaller than > lastTransitTime. variance2 is the same calculation with > lastTransitTime type casted to a long. Since this variance is part of > the jitterLevel calculation, this subsequently causes the jitterLevel > to jump in value dramatically. > > Best Regards, > Southanon > > > ------------------------------------------------------------------------------ > The Go Parallel Website, sponsored by Intel - in partnership with Geeknet, > is your hub for all things parallel software development, from weekly thought > leadership blogs to news, videos, case studies, tutorials, tech docs, > whitepapers, evaluation guides, and opinion stories. Check out the most > recent posts - join the conversation now. http://goparallel.sourceforge.net/ > > > _______________________________________________ > Opalvoip-devel mailing list > Opa...@li... > https://lists.sourceforge.net/lists/listinfo/opalvoip-devel |
|
From: Southanon R. <sra...@la...> - 2013-02-16 05:45:47
|
Thanks Robert. You are exactly right. We are using a 64 bit compiler.
Thank you very much for the update.
I had an additional question that I could not figure out while I was in
this part of the code. Would you mind elaborating on the use of
JitterRoundingGuardBits (4) and GetJitterTimeUnits (8)? I see that you
are multiplying the difference in time by GetJitterTimeUnits. This seems
to be the only deviation from the definition per RFC3550 Appendix 8. I
did notice that you are later dividing this out when calling
GetAvgJitterTime. However, I am unclear on the use of the
JitterRoundingGuardBits. I notice you are shifting the jitterLevel in
both the Average and the Max calculations but not the Remote
calculation. Why?
DWORD GetAvgJitterTime() const { return
(jitterLevel>>JitterRoundingGuardBits)/GetJitterTimeUnits(); }
DWORD GetMaxJitterTime() const { return
(maximumJitterLevel>>JitterRoundingGuardBits)/GetJitterTimeUnits(); }
DWORD GetJitterTimeOnRemote() const { return
jitterLevelOnRemote/GetJitterTimeUnits(); }
Thank you in advance for your time.
Best Regards,
Southanon
On 2/15/13 5:08 PM, Robert Jongbloed wrote:
> As "variance" is a signed value the "unsigned wraparound" problem
> should not occur. However, I can see in the log what you are saying.
>
> The only thing I can think of is you are using a 64 bit compiler and
> "variance" is a 64 bit signed integer. Then, if the compiler does not
> do the sign extension for the unsigned expression (diff -
> lastTransitTime) then I can see how it could occur.
>
> I have changed the code to guarantee a positive number.
>
> *Robert Jongbloed*
> /OPAL/OpenH323/PTLib Architect and Co-founder./
> Commercial support at http://www.voxlucida.com.au
>
> On 16/02/2013 6:09 AM, Southanon Ratsamy wrote:
>> There seems to be a bug in rtp.cxx that causes the jitterLevel to
>> jump up in some cases. The bug is seen when the difference in time
>> goes from large to small to large again. This seems to be present in
>> the opal 3.10.9 release.
>>
>> This is the line of the bug in rtp.cxx, function is
>> Internal_OnReceiveData.
>>
>> // As per RFC3550 Appendix 8
>> diff *= GetJitterTimeUnits(); // Convert to timestamp units
>> long variance = diff - lastTransitTime;
>>
>> Both "diff" and "lastTransitTime" are unsigned. If lastTransitTime is
>> bigger than diff, this produces a very large unsigned number. Not the
>> small negative number we are expecting.
>>
>> Here is sample output demonstrating what is happening:
>>
>> 0:11.293 RTP Jitter:0xe3494910 rtp.cxx(1346) RTP
>> Session 1, ssrc=3735373445, jitterLevel = 21
>> 0:11.318 RTP Jitter:0xe3494910 rtp.cxx(1305) RTP
>> Session 1, ssrc=3735373445, tick = 170:25:21.136,
>> lastReceivedPacketTime = 170:25:21.110, diff = 26
>> 0:11.318 RTP Jitter:0xe3494910 rtp.cxx(1324) RTP
>> Session 1, ssrc=3735373445, diff = 208, lastTransitTime = 152,
>> variance = 56, variance2 = 56
>>
>> 0:11.318 RTP Jitter:0xe3494910 rtp.cxx(1346) RTP
>> Session 1, ssrc=3735373445, jitterLevel = 76
>> 0:11.333 RTP Jitter:0xe3494910 rtp.cxx(1305) RTP
>> Session 1, ssrc=3735373445, tick = 170:25:21.151,
>> lastReceivedPacketTime = 170:25:21.136, diff = 15
>> 0:11.333 RTP Jitter:0xe3494910 rtp.cxx(1324) RTP
>> Session 1, ssrc=3735373445, diff = 120, lastTransitTime = 208,
>> variance = 4294967208, variance2 = -88
>>
>> 0:11.333 RTP Jitter:0xe3494910 rtp.cxx(1346) RTP
>> Session 1, ssrc=3735373445, jitterLevel = 4294967279
>> 0:11.353 RTP Jitter:0xe3494910 rtp.cxx(1305) RTP
>> Session 1, ssrc=3735373445, tick = 170:25:21.170,
>> lastReceivedPacketTime = 170:25:21.151, diff = 19
>> 0:11.353 RTP Jitter:0xe3494910 rtp.cxx(1324) RTP
>> Session 1, ssrc=3735373445, diff = 152, lastTransitTime = 120,
>> variance = 32, variance2 = 32
>>
>> Notice the jump in the variance value when diff is smaller than
>> lastTransitTime. variance2 is the same calculation with
>> lastTransitTime type casted to a long. Since this variance is part of
>> the jitterLevel calculation, this subsequently causes the jitterLevel
>> to jump in value dramatically.
>>
>> Best Regards,
>> Southanon
>>
>>
>> ------------------------------------------------------------------------------
>> The Go Parallel Website, sponsored by Intel - in partnership with Geeknet,
>> is your hub for all things parallel software development, from weekly thought
>> leadership blogs to news, videos, case studies, tutorials, tech docs,
>> whitepapers, evaluation guides, and opinion stories. Check out the most
>> recent posts - join the conversation now.http://goparallel.sourceforge.net/
>>
>>
>> _______________________________________________
>> Opalvoip-devel mailing list
>> Opa...@li...
>> https://lists.sourceforge.net/lists/listinfo/opalvoip-devel
>
|
|
From: Robert J. <ro...@vo...> - 2013-02-16 05:03:52
|
GetJitterTimeUnits() is to convert the time measurements in milliseconds to the RTP timestamp units that are required to send over the wire. The timestamp is usually 8000Hz, it could be 16000Hz or whatever. The guard bits are to avoid rounding errors in the calculations as floating point is not used. And that bit is in fact in the RFC3550 appendix, if you look a little closer, I have just made an identifier for the value 4 they use. *Robert Jongbloed* /OPAL/OpenH323/PTLib Architect and Co-founder./ Commercial support at http://www.voxlucida.com.au On 16/02/2013 3:53 PM, Southanon Ratsamy wrote: > Thanks Robert. You are exactly right. We are using a 64 bit compiler. > Thank you very much for the update. > > I had an additional question that I could not figure out while I was > in this part of the code. Would you mind elaborating on the use of > JitterRoundingGuardBits (4) and GetJitterTimeUnits (8)? I see that you > are multiplying the difference in time by GetJitterTimeUnits. This > seems to be the only deviation from the definition per RFC3550 > Appendix 8. I did notice that you are later dividing this out when > calling GetAvgJitterTime. However, I am unclear on the use of the > JitterRoundingGuardBits. I notice you are shifting the jitterLevel in > both the Average and the Max calculations but not the Remote > calculation. Why? > > DWORD GetAvgJitterTime() const { return > (jitterLevel>>JitterRoundingGuardBits)/GetJitterTimeUnits(); } > DWORD GetMaxJitterTime() const { return > (maximumJitterLevel>>JitterRoundingGuardBits)/GetJitterTimeUnits(); } > DWORD GetJitterTimeOnRemote() const { return > jitterLevelOnRemote/GetJitterTimeUnits(); } > > Thank you in advance for your time. > > Best Regards, > Southanon > > On 2/15/13 5:08 PM, Robert Jongbloed wrote: >> As "variance" is a signed value the "unsigned wraparound" problem >> should not occur. However, I can see in the log what you are saying. >> >> The only thing I can think of is you are using a 64 bit compiler and >> "variance" is a 64 bit signed integer. Then, if the compiler does not >> do the sign extension for the unsigned expression (diff - >> lastTransitTime) then I can see how it could occur. >> >> I have changed the code to guarantee a positive number. >> >> *Robert Jongbloed* >> /OPAL/OpenH323/PTLib Architect and Co-founder./ >> Commercial support at http://www.voxlucida.com.au >> >> On 16/02/2013 6:09 AM, Southanon Ratsamy wrote: >>> There seems to be a bug in rtp.cxx that causes the jitterLevel to >>> jump up in some cases. The bug is seen when the difference in time >>> goes from large to small to large again. This seems to be present in >>> the opal 3.10.9 release. >>> >>> This is the line of the bug in rtp.cxx, function is >>> Internal_OnReceiveData. >>> >>> // As per RFC3550 Appendix 8 >>> diff *= GetJitterTimeUnits(); // Convert to timestamp units >>> long variance = diff - lastTransitTime; >>> >>> Both "diff" and "lastTransitTime" are unsigned. If lastTransitTime >>> is bigger than diff, this produces a very large unsigned number. Not >>> the small negative number we are expecting. >>> >>> Here is sample output demonstrating what is happening: >>> >>> 0:11.293 RTP Jitter:0xe3494910 rtp.cxx(1346) RTP >>> Session 1, ssrc=3735373445, jitterLevel = 21 >>> 0:11.318 RTP Jitter:0xe3494910 rtp.cxx(1305) RTP >>> Session 1, ssrc=3735373445, tick = 170:25:21.136, >>> lastReceivedPacketTime = 170:25:21.110, diff = 26 >>> 0:11.318 RTP Jitter:0xe3494910 rtp.cxx(1324) RTP >>> Session 1, ssrc=3735373445, diff = 208, lastTransitTime = 152, >>> variance = 56, variance2 = 56 >>> >>> 0:11.318 RTP Jitter:0xe3494910 rtp.cxx(1346) RTP >>> Session 1, ssrc=3735373445, jitterLevel = 76 >>> 0:11.333 RTP Jitter:0xe3494910 rtp.cxx(1305) RTP >>> Session 1, ssrc=3735373445, tick = 170:25:21.151, >>> lastReceivedPacketTime = 170:25:21.136, diff = 15 >>> 0:11.333 RTP Jitter:0xe3494910 rtp.cxx(1324) RTP >>> Session 1, ssrc=3735373445, diff = 120, lastTransitTime = 208, >>> variance = 4294967208, variance2 = -88 >>> >>> 0:11.333 RTP Jitter:0xe3494910 rtp.cxx(1346) RTP >>> Session 1, ssrc=3735373445, jitterLevel = 4294967279 >>> 0:11.353 RTP Jitter:0xe3494910 rtp.cxx(1305) RTP >>> Session 1, ssrc=3735373445, tick = 170:25:21.170, >>> lastReceivedPacketTime = 170:25:21.151, diff = 19 >>> 0:11.353 RTP Jitter:0xe3494910 rtp.cxx(1324) RTP >>> Session 1, ssrc=3735373445, diff = 152, lastTransitTime = 120, >>> variance = 32, variance2 = 32 >>> >>> Notice the jump in the variance value when diff is smaller than >>> lastTransitTime. variance2 is the same calculation with >>> lastTransitTime type casted to a long. Since this variance is part >>> of the jitterLevel calculation, this subsequently causes the >>> jitterLevel to jump in value dramatically. >>> >>> Best Regards, >>> Southanon >>> >>> >>> ------------------------------------------------------------------------------ >>> The Go Parallel Website, sponsored by Intel - in partnership with Geeknet, >>> is your hub for all things parallel software development, from weekly thought >>> leadership blogs to news, videos, case studies, tutorials, tech docs, >>> whitepapers, evaluation guides, and opinion stories. Check out the most >>> recent posts - join the conversation now.http://goparallel.sourceforge.net/ >>> >>> >>> _______________________________________________ >>> Opalvoip-devel mailing list >>> Opa...@li... >>> https://lists.sourceforge.net/lists/listinfo/opalvoip-devel >> > |