Closed Bug 1121767 Opened 10 years ago Closed 9 years ago

[e10s] TelemetryStopwatch: key "FX_PAGE_LOAD_MS" was already initialized

Categories

(Firefox :: General, defect)

Product:
Firefox
Component:
General
Platform:
x86
macOS
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

()

Status:
RESOLVED WORKSFORME
Tracking Flags:
Tracking Status
e10s + ---
firefox47 --- verified

People

(Reporter: cpeterson, Unassigned)

References

(
URL
)

Details

I see this error in the browser console when logging into the Yammer using Okta SSO, but only when e10s is enabled: https://www.yammer.com/mozilla.com TelemetryStopwatch: key "FX_PAGE_LOAD_MS" was already initialized
I see the following similar error in Fennec: E GeckoConsole(28429) [JavaScript Error: "TelemetryStopwatch: key "READER_MODE_SERIALIZE_DOM_MS" was already initialized" {file: "resource://gre/modules/TelemetryStopwatch.jsm" line: 52}]
This is not an e10s bug, I see it in single-process desktop Developer Edition 41: "TelemetryStopwatch: key "FX_PAGE_LOAD_MS" was already initialized" Nick: I think you're seeing a different error. This isn't a bug in TelemetryStopwatch, it's a bug in the code that uses it. TelemetryStopwatch just calls Cu.reportError when it notices it's being used incorrectly. Tim: How can TelemetryStopwatch.start("FX_PAGE_LOAD_MS", ...) get called twice before TelemetryStopwatch.finish("FX_PAGE_LOAD_MS", ..) ever gets called? Two tabs being loaded simultaneously?
Flags: needinfo?(ttaubert)
Loading https://www.yammer.com/mozilla.com in a tab I indeed see: start, start, stop, stop If I assume that the first "stop" belongs to the first "start" then that would also mess with the measurements if we'd always cancel() before start(). And those are supposed to be top-level loads, hm.
Flags: needinfo?(ttaubert)
The first page loaded looks like this: <html> <head> <title>Submit Form</title> </head> <body onload="javascript:document.forms[0].submit()"> <form method="post" action="https://mozilla.okta.com/app/yammer/k102e4iirRLLYWTGTOPP/sso/saml"> <input type="hidden" name="SAMLRequest" value="..."/> <input type="hidden" name="RelayState" value="..."/> </form> </body> </html> So shortly after that has loaded a new POST request is sent, which probably is the second "start". Not sure what to do about that... Should the key passed to start(), finish(), and cancel() maybe be something like: key = {browser: aBrowser, uri: aRequest.URI.spec} ? There might be edge cases, maybe not.
Yeah a more unique key passed to TelemetryStopwatch would help
Note that the key is not compared for deep equality. It's only checked as a reference to the same object. Maybe changing the key from aBrowser to aRequest would work, if the aRequest received on finish is the same obj as the one received on start (I imagine it is)
WFM in Nightly 47.
Status: NEW → RESOLVED
Closed: 9 years ago
status-firefox47: --- → verified
Resolution: --- → WORKSFORME
You need to log in before you can comment on or make changes to this bug.