1654248 - The WEBRTC_CALL_DURATION histogram is not recorded after having a call on jitsi, google meet, or hangouts

Status: VERIFIED FIXED

(Core :: WebRTC, defect, P2)

Description

[Ciprian Muresan [:cmuresan], Formerly of Ecosystem QA - please needinfo @mcoman for things regarding the team]

Attachment: Screen Recording 2020-07-21 at 15.06.34.mov

[Affected versions]:

• Firefox Nightly 80.0a1, Build ID 20200720094507
• Firefox Beta 79.0, Build ID 20200720193547

[Affected Platforms]:

• Windows 10 x64
• macOS 10.15.4
• Ubuntu 16.04 x64

[Prerequisites:]

• Have the following prefs set:
  • privacy.webrtc.allowSilencingNotifications to true
  • privacy.webrtc.legacyGlobalIndicator to false

[Steps to reproduce]:

1. Open the browser with the profile from prerequisites and navigate to the meet.google.com, hangouts.google.com,or meet.jit.si page.
2. Host a call and have someone join from another device.
3. End the call and navigate to the about:telemetry page.
4. Search for the WEBRTC_CALL_DURATION histogram and observe the behavior.

[Expected result]:

• The histogram is displayed.

[Actual result]:

• The histogram is not recorded.

[Notes]:

• The issue is also reproducible on join.me on Windows and macOS.
• The issue is not reproducible with Zoom, Facebook, Whereby, Talky, webroom.net, jumpchat, and linkello.
• Attached a screen recording with the issue.

Comment 1

[Mike Conley (:mconley) (:⚙️) (PTO June 8 - 12)]

The WEBRTC_CALL_DURATION measurement is done deep in the WebRTC stack, outside of the control of the front-end from what I can tell. Any idea what's happening here, jib?

Comment 2

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

WEBRTC_CALL_DURATION was unfortunately defined with 1000 buckets—most histograms cap out at 100—which I believe is why it doesn't render as a histogram in the measurement dashboard, even though it is still recorded, as you can tell from the 426.26k Ping Count.

We know the data is there, even in release, as we've done sql queries on it like this one (a graph that for full disclosure is incorrect since it discounts non-webrtc users, but is still pretty and shows an uptick in usage during COVID-19 among active WebRTC users).

I hadn't tried it in the about:telemetry dashboard before, but perhaps it suffers from the same problem? Would love to see this fixed.

Tossing over to Telemetry folks, as I suspect this is a data display problem.

Comment 3

[Jan-Erik Rediger [:janerik]]

The measurement dashboard does show data, it's all crammed to the left, but even the higher buckets still have a few samples (and are thus not eliminated from the view).

Not sure about about:telemetry, so far I haven't been able to make it record and without data I can't check if it's a data display problem.

Comment 4

[Jan-Erik Rediger [:janerik]]

Tried a call on https://talky.io/ and indeed it's recorded.
about:telemetry displays that just fine.

That puts it back into Core::WebRTC as it seems to be a recording issue.

Comment 5

[Romain Testard [:RT]]

Can you please confirm if this is indeed an issue with the probe for certain domains? We were planning on shipping an experiment next monday that uses the value from this probe to measure experiment success - it would be good to get a confirmation of the issue so we can plan the experiment accordingly.

Comment 6

[Alex Chronopoulos [:achronop]]

Redirect to jib

Comment 7

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

[Tracking Requested - why for this release]: WEBRTC_CALL_DURATION telemetry recording has been broken since 71.

WEBRTC_CALL_DURATION recording is effectively non-functional for any real site, except the most trivial demo that doesn't do any renegotiation.

I've reproduced this with mozregression using the following steps:

STRs:

1. Start a fresh instance of Firefox.
2. Open https://jsfiddle.net/jib1/3x9andz7/ and share cam+mic
3. Open a second tab
4. Close the first tab
5. Open about:telemetry#search=WEBRTC_CALL_DURATION

Expected result: A histogram for WEBRTC_CALL_DURATION is shown
Actual result: No histogram for WEBRTC_CALL_DURATION is shown

Regression range:

• mozregression gave in at 2019-10-01-2019-10-02, which points squarely to bug 1571015.

In short, the regressing bug added a ref-counting mechanism delaying reporting of WEBRTC_CALL_DURATION until the number of active peer connections per URI drops to zero.

The bug is startCallTelem (which increments) is called in every pc.setRemoteDescription call, whereas RecordEndOfCallTelemetry is called just once on pc.close (the STR fiddle re-negotiates once to repro).

Comment 8

[Dan Minor [:dminor]]

You've already identified the problem and the found the regressing bug, so I'm not sure what additional information is needed here.

I don't know if we can salvage the approach from Bug 1571015 or if we should just revert those changes. If we revert it, we'll be back to measuring PeerConnection duration rather than call duration, but maybe that is ok. Since I made a mess of things the first time around, I think we'd be better off if someone with greater knowledge of PeerConnection had a look at this.

Comment 9

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

I'll take a stab at it.

Comment 10

[Dan Minor [:dminor]]

Thank you!

Comment 11

[Julien Cristau [:jcristau]]

Not sure we need to track since it's been broken for a while.

Comment 12

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

Attachment: Bug 1654248 - Fix missing telemetry reporting of WEBRTC_CALL_DURATION, and stop counting renegotiations in WEBRTC_CALL_COUNT_2.

Comment 13

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

Attachment: request.md

Comment 14

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

Attachment: request.md

Comment 15

[Tim Smith (inactive) 👨‍🔬 [:tdsmith]]

Comment on attachment 9166920 [details]
request.md

Thanks!

1) Is there or will there be **documentation** that describes the schema for the ultimate data set in a public, complete, and accurate way? Click the documentation link provided in Q6 and ensure it is publicly accessible and does or will contain documentation for the data collection. (see [here](https://github.com/mozilla/activity-stream/blob/master/docs/v2-system-addon/data_dictionary.md), [here](https://github.com/mozilla-mobile/focus/wiki/Install-and-event-tracking-with-the-Adjust-SDK), and [here](https://firefox-source-docs.mozilla.org/toolkit/components/telemetry/telemetry/index.html) for examples).  Refer to the appendix for "documentation" if more detail about documentation standards is needed.

Yes, in Histograms.json and the probe dictionary.

2) Is there a control mechanism that allows the user to turn the data collection on and off? (Note, for data collection not needed for security purposes, Mozilla provides such a control mechanism) Provide details as to the control mechanism available.

Yes, the Firefox telemetry opt-out.

3) If the request is for permanent data collection, is there someone who will monitor the data over time?

Yes, Jan-Ivar Bruaroey will monitor the collection.

4) Using the **[category system of data types](https://wiki.mozilla.org/Firefox/Data_Collection)** on the Mozilla wiki, what collection type of data do the requested measurements fall under?

Category 1, technical data.

5) Is the data collection request for default-on or default-off?

Default-on.

6) Does the instrumentation include the addition of **any *new* identifiers** (whether anonymous or otherwise; e.g., username, random IDs, etc.  See the appendix for more details)?

No.

7) Is the data collection covered by the existing Firefox privacy notice?

Yes.

8) Does there need to be a check-in in the future to determine whether to renew the data? 

No, permanent collection.

9) Does the data collection use a third-party collection tool?

No.

Comment 16

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/e51e334b08cd
Fix missing telemetry reporting of WEBRTC_CALL_DURATION, and stop counting renegotiations in WEBRTC_CALL_COUNT_2. r=bwc

Comment 17

[Andreea Pavel [:apavel]]

Backed out for failing PeerConnectionImpl.cpp

Push with failures: https://treeherder.mozilla.org/#/jobs?repo=autoland&group_state=expanded&selectedTaskRun=ZCd5nWH2RLOLmxCtq_1JwQ.0&resultStatus=testfailed%2Cbusted%2Cexception&revision=e51e334b08cdaa97bf65cce34aefa5176d62ff8e

Failure log:

• Assertion: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=311702931&repo=autoland&lineNumber=8301
• Crash: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=311704200&repo=autoland&lineNumber=1870

Backout: https://hg.mozilla.org/integration/autoland/rev/c7d03304f6f8b71f5012bc1587a9f37c8ee672d6

Comment 18

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/c71f8ebaf601
Fix missing telemetry reporting of WEBRTC_CALL_DURATION, and stop counting renegotiations in WEBRTC_CALL_COUNT_2. r=bwc

Comment 19

[Natalia Csoregi [:nataliaCs]]

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

Comment 20

[Ciprian Muresan [:cmuresan], Formerly of Ecosystem QA - please needinfo @mcoman for things regarding the team]

I have verified that the issue is no longer reproducible on the latest Nightly 81.0a1 (Build ID 20200810213634) using Windows 10 x64, macOS 10.15, and Ubuntu 20.04. The WEBRTC_CALL_DURATION histogram is collected when having a call on meet.google.com, hangouts.google.com, and meet.jit.si.

Comment 21

[Ryan VanderMeulen [:RyanVM]]

Too late for Fx80, but I'd consider taking this on ESR78 still if we think it's important enough to do so.

Comment 22

[Romain Testard [:RT]]

(In reply to Ryan VanderMeulen [:RyanVM] from comment #21)

Too late for Fx80, but I'd consider taking this on ESR78 still if we think it's important enough to do so.

I don't think this is needed on ESR where telemetry is heavily biased by opt-out - I cannot think of any useful output from this change on ESR at the moment.