Closed Bug 1456194 Opened 2 years ago Closed 2 years ago

Investigate 60s+ DEVTOOLS_*_TOOLBOX_OPEN_DELAY_MS for broken measurement

Categories

(DevTools :: General, enhancement)

57 Branch
enhancement
Not set

Tracking

(firefox61 fixed)

RESOLVED FIXED
Firefox 61
Tracking Status
firefox61 --- fixed

People

(Reporter: Harald, Assigned: ochameau)

References

Details

Attachments

(1 file)

Console, Debugger, Settings and all core panels both have a 95th percentile of 60s+

Console: https://mzl.la/2HL84CO
Debugger: https://mzl.la/2qSF95X

We need to investigate if the probe might measure some edge cases incorrectly.
Alex for
Depends on: 1405584
Flags: needinfo?(poirot.alex)
Assignee: nobody → poirot.alex
Flags: needinfo?(poirot.alex)
These probes always looked like that, I assumed it was due to a long tail of slow load.
If you look at the distribution:
  https://mzl.la/2vIXHdN
You can see that there is one.
But looking at it more closely, it would have meant that there is a long tail approximatively over 500seconds for the console which sounds unlikely.

So I looked into the code and yes, I've been tricked by performance.now behavior and by the time origin, specific for each window:
https://developer.mozilla.org/en-US/docs/Web/API/DOMHighResTimeStamp#The_time_origin
The big spike over 60s is related to users opening more than one top level window, the toolbox not opened in the first window were having wrong measurements.
Comment on attachment 8970838 [details]
Bug 1456194 - Fix toolbox startup telemetry measurement when using more than one top level window.

https://reviewboard.mozilla.org/r/239624/#review245460

Yikes, good catch!  This seems like a good incremental improvement.

Would it be better to use something like `TelemetryStopwatch`[1] instead that is designed for this purpose?  From that module, it appears there is a `Cu.now()` API[2], which might be a simpler approach if we still want to track the time ourselves while avoiding time origin issues.

[1]: https://searchfox.org/mozilla-central/source/toolkit/components/telemetry/TelemetryStopwatch.jsm
[2]: https://searchfox.org/mozilla-central/rev/36dec78aecc40539ecc8d78e91612e38810f963c/js/xpconnect/idl/xpccomponents.idl#668
Attachment #8970838 - Flags: review?(jryans) → review+
(In reply to J. Ryan Stinnett [:jryans] (use ni?) (on PTO Apr 30 - May 1) from comment #4)
> Would it be better to use something like `TelemetryStopwatch`[1] instead
> that is designed for this purpose?

I looked into TelemetryStopwatch but it requires knowing the telemetry key and toolId on start,
which isn't the case here.

>  From that module, it appears there is a `Cu.now()` API[2], which might be a simpler approach
> if we still want to track the time ourselves while avoiding time origin issues.

I switched to Cu.now everywhere. May be the telemetry RFC is going to help refactor this code to the new devtools telemetry api...
Comment on attachment 8970838 [details]
Bug 1456194 - Fix toolbox startup telemetry measurement when using more than one top level window.

Could you take a look at the new patch?
Attachment #8970838 - Flags: review+ → review?(jryans)
Comment on attachment 8970838 [details]
Bug 1456194 - Fix toolbox startup telemetry measurement when using more than one top level window.

https://reviewboard.mozilla.org/r/239624/#review247056

This really makes me wish for some kind of types or tagging in the time, so we could have some way to verify that the same time base was used, rather than just hoping...

Anyway, looks good! :)
Attachment #8970838 - Flags: review?(jryans) → review+
hg error in cmd: hg push -r tip ssh://hg.mozilla.org/integration/autoland: pushing to ssh://hg.mozilla.org/integration/autoland
remote: *** failed to import extension vcsreplicator from /var/hg/version-control-tools/pylib/vcsreplicator/vcsreplicator/hgext.py: [Errno 2] No such file or directory: '/var/hg/version-control-tools/pylib/vcsreplicator/vcsreplicator/../bootstrap.py'
searching for changes
remote: adding changesets
remote: adding manifests
remote: adding file changes
remote: added 1 changesets with 6 changes to 6 files
remote: transaction abort!
remote: rollback completed
remote: pretxnchangegroup.d_webidl hook is invalid: import of "mozhghooks.prevent_webidl_changes" failed
remote: (run with --traceback for stack trace)
abort: push failed on remote
Pushed by apoirot@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/a46dfe2330ff
Fix toolbox startup telemetry measurement when using more than one top level window. r=jryans
https://hg.mozilla.org/mozilla-central/rev/a46dfe2330ff
Status: NEW → RESOLVED
Closed: 2 years ago
Resolution: --- → FIXED
Target Milestone: --- → Firefox 61
Product: Firefox → DevTools
You need to log in before you can comment on or make changes to this bug.