1343691 - RTCP stats missing in FF53 (fallout from webrtc.org 49 update)

Status: VERIFIED FIXED

(Core :: WebRTC, defect, P1)

Description

[Jan-Ivar Bruaroey [:jib] (needinfo? me)]

RTCP stats are missing for both video and audio in the following fiddle.

STRs:
 1. Open https://jsfiddle.net/jib1/eboqozdy/ and share camera.
 2. Wait ~5 seconds

Expected result:

  Sender side:

  Timestamp: 18:43:24 GMT-0500 (EST) Type: outbound-rtp
  SSRC: 783676504 Sent: 12165 packets (12.50 MB)
  Dropped frames: 124

  RTCP: Timestamp: 18:43:23 GMT-0500 (EST) Type: inbound-rtp
  SSRC: 783676504 Received: 12165 packets (12.14 MB) Lost: 0
  Discarded packets: undefined Jitter: 0.375

  Receiver side:

  Timestamp: 18:43:24 GMT-0500 (EST) Type: inbound-rtp
  SSRC: 783676504 Received: 12165 packets (12.38 MB) Lost: 0
  Discarded packets: 0 Jitter: 0.375

  RTCP: Timestamp: 18:43:23 GMT-0500 (EST) Type: outbound-rtp
  SSRC: 783676504 Sent: 12165 packets (12.14 MB)
  Dropped frames: undefined

Actual result:

  Sender side

  Timestamp: 18:43:24 GMT-0500 (EST) Type: outbound-rtp
  SSRC: 783676504 Sent: 12165 packets (12.50 MB)
  Dropped frames: 124

  Receiver side

  Timestamp: 18:43:24 GMT-0500 (EST) Type: inbound-rtp
  SSRC: 783676504 Received: 12165 packets (12.38 MB) Lost: 0
  Discarded packets: 0 Jitter: 0.375

Regression range:

15:12.90 INFO: Last good revision: 935e36fde31c6ecd8321beb29d896e42a70aecd0
15:12.90 INFO: First bad revision: 126348e718d03dec640b30b5def70fce8aa71527
15:12.90 INFO: Pushlog:
https://hg.mozilla.org/integration/mozilla-inbound/pushloghtml?fromchange=935e36fde31c6ecd8321beb29d896e42a70aecd0&tochange=126348e718d03dec640b30b5def70fce8aa71527

Comment 1

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

Attachment: Bug 1343691 - fix missing rtcp stats;

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

Comment 2

[Jan-Ivar Bruaroey [:jib] (needinfo? me)]

Comment on attachment 8845286 [details]
Bug 1343691 - fix missing rtcp stats;

https://reviewboard.mozilla.org/r/118458/#review120564

GetRTCPReceiverReport looks fine with nits, but GetRTCPSenderReport still looks a bit messed up to me.

::: media/webrtc/signaling/src/media-conduit/AudioConduit.cpp:208
(Diff revision 1)
> +  if (rttMs == 0) { // GetRemoteRTCPReceiverInfo fills RTT with 0 if unavailable
> +    *rttMs = -1;
> +  }

This should be inside if (result) to avoid potentially touching uninitialized data, depending on what kind of secondary-result convention the called function follows, if any.

I also think you meant to dereference rttMS.

I find the early-bail convention avoids these sorts of problems better. E.g.:

    bool result = ...
    if (!result) {
      return false;
    }
    *timestamp = ...
    if (*rttMs == 0) {
      *rttMs = -1;
    }
    return true;

::: media/webrtc/signaling/src/media-conduit/VideoConduit.cpp:852
(Diff revision 1)
> +    *rttMs = (rtt >= 0) ? // -1 indicates that RTT is unavailable
> +      static_cast<int32_t>(std::min<int64_t>(rtt, INT32_MAX)) : -1;

-1 should survive the cast, so no need for conditional code here I think. KISS. I'd keep the comment though.

::: media/webrtc/signaling/src/media-conduit/VideoConduit.cpp:871
(Diff revision 1)
> -
> -  const webrtc::VideoSendStream::Stats& stats = mSendStream->GetStats();
> +  const webrtc::VideoReceiveStream::Stats& stats = mRecvStream->GetStats();
> +  *packetsSent = stats.rtp_stats.transmitted.packets;
> -  *packetsSent = 0;
> -  for (auto entry: stats.substreams){
> -    *packetsSent += entry.second.rtp_stats.transmitted.packets;
> -    // NG -- per https://www.w3.org/TR/webrtc-stats/ this is only payload bytes
> +  // NG -- per https://www.w3.org/TR/webrtc-stats/ this is only payload bytes
> -    *bytesSent += entry.second.rtp_stats.MediaPayloadBytes();
> +  *bytesSent = stats.rtp_stats.MediaPayloadBytes();

This doesn't look right. rtp_stats look like data counters. Though why they would have a field called 'transmitted.packets' on am mRecvStream I don't know.

There's a sibling called rtcp_stats here, but doesn't seem to contain what we want.

Comment 3

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

Comment on attachment 8845286 [details]
Bug 1343691 - fix missing rtcp stats;

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/118458/diff/1-2/

Comment 4

[Jan-Ivar Bruaroey [:jib] (needinfo? me)]

Comment on attachment 8845286 [details]
Bug 1343691 - fix missing rtcp stats;

https://reviewboard.mozilla.org/r/118458/#review120564

> This should be inside if (result) to avoid potentially touching uninitialized data, depending on what kind of secondary-result convention the called function follows, if any.
> 
> I also think you meant to dereference rttMS.
> 
> I find the early-bail convention avoids these sorts of problems better. E.g.:
> 
>     bool result = ...
>     if (!result) {
>       return false;
>     }
>     *timestamp = ...
>     if (*rttMs == 0) {
>       *rttMs = -1;
>     }
>     return true;

This is still not fixed properly. Did you forget to address it?

Comment 5

[Jan-Ivar Bruaroey [:jib] (needinfo? me)]

Comment on attachment 8845286 [details]
Bug 1343691 - fix missing rtcp stats;

https://reviewboard.mozilla.org/r/118458/#review121076

Glad to see this fixed! r- on timestamp calculation and missing nits.

::: media/webrtc/signaling/src/media-conduit/AudioConduit.cpp:208
(Diff revision 2)
> +  if (*rttMs == 0) {
> +    // GetRemoteRTCPReceiverInfo fills RTT with 0 if it is unavailable
> +    *rttMs = MediaSessionConduit::RTT_UNAVAILABLE;
> +  }

See comment 4.

::: media/webrtc/signaling/src/media-conduit/VideoConduit.cpp:852
(Diff revision 2)
> +    *rttMs = (rtt >= 0) ?
> +      static_cast<int32_t>(std::min<int64_t>(rtt, INT32_MAX)) :
> +      MediaSessionConduit::RTT_UNAVAILABLE;

See comment 2.

::: media/webrtc/signaling/src/media-conduit/VideoConduit.cpp:875
(Diff revision 2)
> -
> -  // Note: timestamp is not correct per the spec... should be time the rtcp
> -  // was received (remote) or sent (local)
> -  *timestamp = webrtc::Clock::GetRealTimeClock()->TimeInMilliseconds();
> +  *timestamp = NTPtoDOMHighResTimeStamp(senderInfo.NTPseconds,
> +                                        senderInfo.NTPfraction);
> +  *packetsSent = senderInfo.sendPacketCount;
> +  *bytesSent = senderInfo.sendOctetCount;

The WG recently decided RTCStats.timestamp should be local time of arrival of the RTCP packet. While imperfect, the old code here is closer to being right.

What you're calculating here, the NTP timestamp, should instead go into a new `remoteTimestamp` member in the spec [1]. The PR hasn't merged yet, but it should be uncontroversial, so feel free to add as a new member!

[1] https://github.com/w3c/webrtc-stats/pull/164#issue-210206591

::: media/webrtc/trunk/webrtc/video/video_receive_stream.cc:412
(Diff revision 2)
>    return -1;
>  }
>  
> +bool
> +VideoReceiveStream::GetRemoteRTCPSenderInfo(RTCPSenderInfo* sender_info) const {
> +  return -1 != vie_channel_->GetRemoteRTCPSenderInfo(sender_info);

Nit:

    return vie_channel_->GetRemoteRTCPSenderInfo(sender_info) != -1;

::: media/webrtc/trunk/webrtc/video/vie_channel.cc:885
(Diff revision 2)
>    int64_t rtt = 0;
>    if (rtp_rtcp_modules_[0]->RTT(remote_ssrc, &rtt, &dummy, &dummy, &dummy) != 0) {
>      LOG_F(LS_ERROR) << "failed to get RTT";
>      return -1;
>    }

Lovely how the upstream video and audio side differ on handling of missing rtt! May be worth a comment somewhere.

::: media/webrtc/trunk/webrtc/video/vie_channel.cc:898
(Diff revision 2)
> -//->@@NG //     LOG_F(LS_ERROR) << "failed to read RTCP SR sender info";
> -//->@@NG //     return -1;
> -//->@@NG //   }
> -//->@@NG //
> -//->@@NG //   sender_info->NTP_timestamp_high = rtcp_sender_info.NTPseconds;
> -//->@@NG //   sender_info->NTP_timestamp_low = rtcp_sender_info.NTPfraction;
> -//->@@NG //   sender_info->RTP_timestamp = rtcp_sender_info.RTPtimeStamp;
> -//->@@NG //   sender_info->sender_packet_count = rtcp_sender_info.sendPacketCount;
> -//->@@NG //   sender_info->sender_octet_count = rtcp_sender_info.sendOctetCount;
> -//->@@NG //   return 0;
> -//->@@NG // }
> +  RTCPSenderInfo rtcp_sender_info;
> +  if (rtp_rtcp_modules_[0] &&
> +    rtp_rtcp_modules_[0]->RemoteRTCPStat(&rtcp_sender_info) != 0) {
> +    LOG_F(LS_ERROR) << "failed to read RTCP SR sender info";
> +    return -1;
> +  }
> +
> +  sender_info->NTPseconds = rtcp_sender_info.NTPseconds;
> +  sender_info->NTPfraction = rtcp_sender_info.NTPfraction;
> +  sender_info->RTPtimeStamp = rtcp_sender_info.RTPtimeStamp;
> +  sender_info->sendPacketCount = rtcp_sender_info.sendPacketCount;
> +  sender_info->sendOctetCount = rtcp_sender_info.sendOctetCount;

Why copy RTCPSenderInfo here?

Comment 6

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

Comment on attachment 8845286 [details]
Bug 1343691 - fix missing rtcp stats;

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/118458/diff/2-3/

Comment 7

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

Comment on attachment 8845286 [details]
Bug 1343691 - fix missing rtcp stats;

https://reviewboard.mozilla.org/r/118458/#review121076

> See comment 2.

It should. I am replacing it with an opaque value at the layer that should return a consistent value. See the changes to AudioConduit. I think this is easier to follow. Re-adding the comment though.

> The WG recently decided RTCStats.timestamp should be local time of arrival of the RTCP packet. While imperfect, the old code here is closer to being right.
> 
> What you're calculating here, the NTP timestamp, should instead go into a new `remoteTimestamp` member in the spec [1]. The PR hasn't merged yet, but it should be uncontroversial, so feel free to add as a new member!
> 
> [1] https://github.com/w3c/webrtc-stats/pull/164#issue-210206591

Changed. I will add it as a new member in a new bug, as this patch is time critical (**no pun intended (or avoided)**).

> Nit:
> 
>     return vie_channel_->GetRemoteRTCPSenderInfo(sender_info) != -1;

Changed. Hmm, I find it more readable where the action is all grouped together, so you don't have to scan to the end of the line. It is clear within 6 characters from the return that you are returning a boolean, and not the value vie_channel_->GetRemoteRTCPSenderInfo(sender_info).

> Lovely how the upstream video and audio side differ on handling of missing rtt! May be worth a comment somewhere.

Noted!

> Why copy RTCPSenderInfo here?

Good question!

Comment 8

[Jan-Ivar Bruaroey [:jib] (needinfo? me)]

Comment on attachment 8845286 [details]
Bug 1343691 - fix missing rtcp stats;

https://reviewboard.mozilla.org/r/118458/#review121110

::: media/webrtc/signaling/src/media-conduit/AudioConduit.cpp:201
(Diff revisions 2 - 3)
>    bool result = !mPtrRTP->GetRemoteRTCPReceiverInfo(mChannel, ntpHigh, ntpLow,
>                                                      *packetsReceived,
>                                                      *bytesReceived,
>                                                      *jitterMs,
>                                                      fractionLost,
>                                                      *cumulativeLost,
>                                                      *rttMs);
> +  if (!result) {
> +    return false;
> +  }
> +  *timestamp = NTPtoDOMHighResTimeStamp(ntpHigh, ntpLow);

Yeah I see you just moved this one, but we should perhaps change this to 

    webrtc::Clock::GetRealTimeClock()->TimeInMilliseconds()

as well for consistency. WDYT?

::: media/webrtc/signaling/src/media-conduit/VideoConduit.cpp:875
(Diff revisions 2 - 3)
>      MutexAutoLock lock(mCodecMutex);
>      if (!mRecvStream || !mRecvStream->GetRemoteRTCPSenderInfo(&senderInfo)) {
>        return false;
>      }
>    }
> -  *timestamp = NTPtoDOMHighResTimeStamp(senderInfo.NTPseconds,
> +  *timestamp = webrtc::Clock::GetRealTimeClock()->TimeInMilliseconds();

I think we lost a comment here about this not being entirely accurate, that it really should be time of receipt of rtcp packet. Can we bring it back?

Comment 9

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

Comment on attachment 8845286 [details]
Bug 1343691 - fix missing rtcp stats;

https://reviewboard.mozilla.org/r/118458/#review121110

> Yeah I see you just moved this one, but we should perhaps change this to 
> 
>     webrtc::Clock::GetRealTimeClock()->TimeInMilliseconds()
> 
> as well for consistency. WDYT?

I will change it. If this was "comment 2" or "comment 4", I was just counting differently. Comment 4 seemed to be itself ...

> I think we lost a comment here about this not being entirely accurate, that it really should be time of receipt of rtcp packet. Can we bring it back?

You are correct, thanks.

Comment 10

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

Comment on attachment 8845286 [details]
Bug 1343691 - fix missing rtcp stats;

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/118458/diff/3-4/

Comment 11

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

Comment on attachment 8845286 [details]
Bug 1343691 - fix missing rtcp stats;

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/118458/diff/4-5/

Comment 12

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

Comment on attachment 8845286 [details]
Bug 1343691 - fix missing rtcp stats;

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/118458/diff/5-6/

Comment 13

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

Comment on attachment 8845286 [details]
Bug 1343691 - fix missing rtcp stats;

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/118458/diff/6-7/

Comment 14

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

Comment on attachment 8845286 [details]
Bug 1343691 - fix missing rtcp stats;

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/118458/diff/7-8/

Comment 15

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/cbbd3f3e6246
fix missing rtcp stats;r=jib

Comment 16

[Carsten Book [:Tomcat]]

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

Comment 17

[Ryan VanderMeulen [:RyanVM]]

Please request Aurora/Beta approval on this patch when you get a chance.

Comment 18

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

Comment on attachment 8845286 [details]
Bug 1343691 - fix missing rtcp stats;

Approval Request Comment
[Feature/Bug causing the regression]: Bug 1343691 & import of WebRTC 49

[User impact if declined]: potentially decreased call WebRTC call quality, and poorer metrics for WebRTC service providers

[Is this code covered by automated tests?]: partially, the existence of the fields was hand tested the sanity of the fields has mochitest coverage

[Has the fix been verified in Nightly?]: Yes

[Needs manual test from QE? If yes, steps to reproduce]: Yes, testing using the fiddle exactly as outlined in comment #1.

[List of other uplifts needed for the feature/fix]: 1337810

[Is the change risky?]: limited risk
[Why is the change risky/not risky?]: it is a patch of small size and the intended effect of the patch is not itself risky

[String changes made/needed]: None

Comment 19

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

(In reply to Nico Grunbaum [:ng] from comment #18)
> Comment on attachment 8845286 [details]
> Bug 1343691 - fix missing rtcp stats;
> 
> Approval Request Comment
> [Feature/Bug causing the regression]: Bug 1343691 & import of WebRTC 49
The bug was introduced in bug 1250356 (WebRTC 49 update)

Comment 20

[Gerry Chang [:gchang]]

Hi Brindusa, could you help find someone to verify if this issue was fixed as expected on a latest Nightly build? Thanks!

Comment 21

[Brindusa Tot, Desktop QA]

Reproduced using Nightly 54.0a1 (Build ID: 20170210030206) on Windows 10 x64.

I can confirm this issue is fixed on the latest Nightly build 55.0a1, Build ID 20170321030211. This was verified on Windows 10 x64, on Mac 10.12 and Ubuntu 16.04.

Comment 22

[Gerry Chang [:gchang]]

Comment on attachment 8845286 [details]
Bug 1343691 - fix missing rtcp stats;

Fix a WebRTC regression issue and was verified. Aurora54+ & Beta53+.

Comment 23

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/releases/mozilla-aurora/rev/0d8334905820

Comment 24

[Carsten Book [:Tomcat]]

has problems to apply to beta: Nico could you take a look, thanks!

grafting 406474:0d8334905820 "Bug 1343691 - fix missing rtcp stats;r=jib a=gchang"
merging media/webrtc/signaling/src/media-conduit/AudioConduit.cpp
merging media/webrtc/signaling/src/media-conduit/VideoConduit.cpp
merging media/webrtc/trunk/webrtc/video/vie_channel.cc
merging media/webrtc/trunk/webrtc/video_send_stream.h
warning: conflicts while merging media/webrtc/signaling/src/media-conduit/VideoConduit.cpp! (edit, then use 'hg resolve --mark')
abort: unresolved conflicts, can't continue
(use 'hg resolve' and 'hg graft --continue'

Comment 25

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

Carsten, absolutely.

Comment 26

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

Attachment: manual resolution of beta merge conflict

This is a manual resolution of the VideoConduit.cpp merge conflict in beta. Carston, is there anything else that needs to be done on my end?

Comment 27

[Carsten Book [:Tomcat]]

no worked perfect, will uplift! thanks nico!

Comment 28

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/releases/mozilla-beta/rev/410550719c97

Comment 29

[Emil Ghitta, QA [:emilghitta]]

I have reproduced the issue mentioned in comment 0, using an affected Firefox 54.0a1 (Build Id:20170301030202) build on Windows 10 64bit.

I have verified that the issue is not reproducible using Firefox 53.0b6 (Build Id:20170323090023) and Firefox 54.0a2 (Build Id: 20170324004022) using Windows 10 64bit, Mac Os X 10.11.6 and Ubuntu 16.04 64 bit.

Comment 31

[Dan Minor [:dminor]]

We should try to upstream anything relevant here.