1255371 - Invalid RTCP SR sent by Firefox when h264 is used

Status: RESOLVED FIXED

(Core :: WebRTC: Networking, defect, P1)

Description

[andysem]

Attachment: rtcp.log

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

Steps to reproduce:

We're developing MCU software that supports WebRTC clients, and we found a problem with Firefox 44.0.2 and 45 (at least), when h264 codec is used for video. The problem is that the periodic RTCP sender reports (RTCP SR) sent by the browser contain inconsistent NTP/RTP timestamps, which makes audio/video synchronization impossible.

I've attached an example of logs corresponding to a single call. the rtcp.log file contains decrypted RTCP SR packets received from the browser and the warnings that indicate the problem. Each warning indicates a discrepancy between the last two RTCP SRs in terms of time passed according to NTP timeline and RTP timeline.

For example, the line at 13:59:08.877037 says that the last two RTCP SRs differ by 10 ms according to NTP timestamps and 73 ms according to RTP timestamps. You can verify that from the respective RTCP SR dumps in lines 13:59:08.866781 and 13:59:08.877033:

The first RTCP SR:
NTP1: da 8b d1 fc dd dd a0 5a = 15747911406015324250
RTP1: aa f4 ed d5 = 2868178389

The second RTCP SR:
NTP2: da 8b d1 fc e0 7e f1 78 = 15747911406059450744
RTP2: aa f5 07 d9 = 2868185049

The difference between them:
NTP difference: (NTP2 - NTP1) / 4294967296 * 1000 ms = 10.2740000002086162567138671875 ms
RTP difference: (RTP2 - RTP1) / 90000 * 1000 ms = 74 ms

The decoding is done according to https://tools.ietf.org/html/rfc3550#section-6.4.1. The 90000 is the clock rate of the RTP video stream.

These two differences are expected to be roughly equal as both clocks are supposed to be monotonic, yet as you can see from the log they differ by 2 or more times. This makes it impossible to use RTCP SRs to synchronize video and audio streams (which is basically done by mapping RTP timestamps of both streams to the common NTP timeline).

I'll note that the actual RTP timestamps of the RTP video packets seem to be increased at the expected rate. These timestamps also seem to have a different base value than the RTP timestamps in the RTCP SRs, which leads me to suspect that the timestamps in RTCP SRs are calculated by a different source (yet SSRC in the SRs is equal to the one that sends RTP video packets).

I'll add that this problem does not appear if VP8 is used to send video.

For convenience I've also attached the following files:
rtcp_sr.log - just the RTCP SR dumps
sdp_client.txt - the SDP offer was generated by Firefox and set as the local description
sdp_server.txt - the SDP answer that was generated by our software and set as the remote description

I'm using Firefox on Kubuntu 15.10 x86_64.



Actual results:

The timestamp differences between RTCP SRs are inconsistent between NTP and RTP timestamps.


Expected results:

The timestamp differences should be roughly equal.

Comment 1

[andysem]

Attachment: Just the RTCP SR dumps

Comment 2

[andysem]

Attachment: sdp_client.txt

Comment 3

[andysem]

Attachment: sdp_server.txt

Comment 4

[Maire Reavy [:mreavy]]

Bumping the priority to get this resolved before the end of our work week.

Comment 5

[Dan Minor [:dminor]]

I'll see if I can get anywhere with this one.

Comment 6

[Martin Storsjö]

FWIW, if I remember correctly from when I bumped into this, the issue was that the RTP times sent in the RTCP SR packets had no correspondence at all to the RTP timestamps in the actual media packets, like they were using different offsets.

Comment 7

[Dan Minor [:dminor]]

Attachment: Bug 1255371 - Invalid RTCP SR sent by Firefox when h264 is used;

Setting the capture_time_ms to -1 causes RTCPSender::SetLastRtpTime to ignore
it and use the current clock time. The default value of 0 will be used in the
the calculation in RTCPSender::BuildSR and cause mismatched timestamps.

Review commit: https://reviewboard.mozilla.org/r/74140/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/74140/

Comment 8

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

Comment on attachment 8784828 [details]
Bug 1255371 - Invalid RTCP SR sent by Firefox when h264 is used;

https://reviewboard.mozilla.org/r/74140/#review72018

I presume this causes the problem to go away in testing.  Thanks!

Comment 9

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

Comment on attachment 8784828 [details]
Bug 1255371 - Invalid RTCP SR sent by Firefox when h264 is used;

https://reviewboard.mozilla.org/r/74140/#review72020

Comment 10

[Dan Minor [:dminor]]

Comment on attachment 8784828 [details]
Bug 1255371 - Invalid RTCP SR sent by Firefox when h264 is used;

https://reviewboard.mozilla.org/r/74140/#review72018

I tested this manually by logging the difference between the RTCP timestamp and the previous RTP timestamp. With this in place, the differences are more or less of the same magnitude regardless of whether VP8 or H.264 are used. Without the patch applied, the differences when using H.264 were very large. I'm not sure if this is a good candidate for an automated test.

Comment 11

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/d87a34ed4be4
Invalid RTCP SR sent by Firefox when h264 is used; r=jesup

Comment 12

[Wes Kocher (:KWierso) (Not reading bugmail; email directly if needed)]

https://hg.mozilla.org/mozilla-central/rev/d87a34ed4be4