1322484 - Invalid RTP Timestamp in first RTCP SR when sent before first media packet is sent

Status: RESOLVED DUPLICATE of bug 1341285

(Core :: WebRTC: Audio/Video, defect)

Description

[Eric Bunyan]

User Agent: Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:50.0) Gecko/20100101 Firefox/50.0
Build ID: 20161114145022

Steps to reproduce:

On one of our testers machines we made a call from Firefox which reliably results in Firefox producing for the video stream, an RTCP receiver report, then an RTCP sender report, then sending RTP packets.

I could not reproduce the problem on my machine. The tester reproduced it reliably on 51 beta and 52 dev. His machine spec was:
--> CPU : Intel core i3-4160 CPU@3.60GHz
--> RAM : 8GB
--> OS : Windows 7
--> Timezone : IST(UTC +5:30)
--> Camera : external Camera Logitech HD720p (they have tried with other camera too with the same result)


Actual results:

The RTP timestamp in the RTCP SR had no relation to the RTP timestamp in first RTP packet (89ms later in one capture I looked at). This causes lipsync issues on the remote device.

This seems to only happen when the SR is sent before any RTP packets for the stream. For some reason an RTCP BYE is sent at the start of the stream which is the RR, then the SR appears correctly saying 0 packets have been sent. It looks like it might be a little similar to 1225729, due to this happening only when an SR is sent before RTP. It does not appear to happen on 50 or earlier.

I've attached a pcap with the decrypted stream Firefox sends for video.


Expected results:

The RTP timestamp in the SR should have been close to that in the first RTP packet.

Comment 1

[Alex Chronopoulos [:achronop]]

Did you forget to attach the pcap file?

Comment 2

[Eric Bunyan]

Attachment: Decrypted video stream from firefox

For some reason the attachment didn't warn me it couldn't attach due to size when I created the bug. I've cut it down to the first 5 seconds as I don't think anything later will be relevant.

Comment 3

[Randell Jesup [:jesup] (needinfo me)]

I see no timestamp jumps in that trace.

You can compress the data with bzip2, gzip, or zip, or put it somewhere I can download it (dropbox/etc).
Timestamps went from 3443315364 to 3443762304 over ~ 5 seconds, which at 90000/s = 4.966 seconds, and there were no in-stream jumps

Comment 4

[Eric Bunyan]

It is only in the RTCP where the timestamps jump. The first sender report (packet 2) has an RTP timestamp of 787834794, the second sender report (packet 20, ~900ms later) then jumps to 3443407794.

Comment 5

[Alex Chronopoulos [:achronop]]

Any update on this?

Comment 6

[Byron Campen [:bwc]]

This is likely the result of the following computation using 0 as |last_rtp_timestamp_| when no RTP has been sent yet:

https://searchfox.org/mozilla-central/rev/2a355e56c490768be676689de18629485c9d699b/media/webrtc/trunk/webrtc/modules/rtp_rtcp/source/rtcp_sender.cc#480-482

However, it seems that there's a deeper flaw here. |last_rtp_timestamp_| is updated when an RTP packet is sent. But RFC 3550 says the following:

"Note that
in most cases this timestamp will not be equal to the RTP
timestamp in any adjacent data packet. Rather, it MUST be
calculated from the corresponding NTP timestamp using the
relationship between the RTP timestamp counter and real time as
maintained by periodically checking the wallclock time at a
sampling instant.
"

So, it sounds like the number we should put here is the RTP timestamp we would get right now if we sent an RTP packet right now, not the RTP timestamp of the most recently sent RTP packet.

Nico, Dan, does this sound accurate to you?

Comment 7

[Byron Campen [:bwc]]

Ok, I see that we're adding some extra to that timestamp based on current time vs when we last encoded, so maybe it works. Still, we shouldn't be using 0 as an input.

Comment 8

[Nico Grunbaum [:ng, @chew:mozilla.org]]

Byron, that seems right to me. I checked the upstream repo and this appears to be there as well.

"Ok, I see that we're adding some extra to that timestamp based on current time vs when we last encoded, so maybe it works. Still, we shouldn't be using 0 as an input."

By my reading of https://tools.ietf.org/html/rfc3550#section-5.1 RTP timestamps SHOULD start at a random value (which doesn't preclude zero). We should probably record whether or not the initial timestamp has been recorded, or stick it in an Optional type, or etc.

Whatever we do, it should be up streamed.

Comment 9

[Dan Minor [:dminor]]

That is my understanding as well, that times should be estimated based on what the timestamp would be if an RTP packet were sent at the current time. The rtp sender code does create a random offset, I can't remember offhand where, but I have hardcoded it to be zero before to make debugging easier. I'll take this bug but I'm not sure I'll be able to start on it right away. Feel free to steal it if you are interested :)

Comment 10

[Dan Minor [:dminor]]

At the time this bug was reported, December 2016, we were running branch 49. The branch 57 update, which landed June 2017, added this assertion [1] and this check [2] to prevent sending SRs before media has been sent. A quick browse of the branch 49 code [3] shows nothing similar, so I believe this bug was fixed by Bug 1341285.

[1] https://searchfox.org/mozilla-central/rev/2a10f4812f3f7c7645d253a4fe52f26bf58e20e8/media/webrtc/trunk/webrtc/modules/rtp_rtcp/source/rtcp_sender.cc#473
[2] https://searchfox.org/mozilla-central/rev/2a10f4812f3f7c7645d253a4fe52f26bf58e20e8/media/webrtc/trunk/webrtc/modules/rtp_rtcp/source/rtcp_sender.cc#748
[3] https://searchfox.org/mozilla-central/rev/794e00db15cf64b69f3807fd69eb8daa8c927d99/media/webrtc/trunk/webrtc/modules/rtp_rtcp/source/rtcp_sender.cc#863