Closed
Bug 1301289
Opened 8 years ago
Closed 8 years ago
Sync pings submitted too late in shutdown process
Categories
(Firefox :: Sync, defect, P1)
Firefox
Sync
Tracking
()
RESOLVED
FIXED
Firefox 51
People
(Reporter: markh, Assigned: markh)
References
Details
Attachments
(2 files)
58 bytes,
text/x-review-board-request
|
tcsc
:
review+
ritu
:
approval-mozilla-beta+
|
Details |
3.43 KB,
patch
|
markh
:
review+
|
Details | Diff | Splinter Review |
I noticed on shutdown an error in the console:
> 1473309697806 Sync.Telemetry TRACE observed xpcom-shutdown null
> JavaScript error: resource://gre/modules/AsyncShutdown.jsm, line 693: Error: Phase "TelemetryController: Waiting for pending ping activity" is finished, it is too late to register completion condition "Waiting for ping task"
The problem is that we are attempting to submit a ping on the xpcom-shutdown observer - but by this point the process has torn down so far that the ping can't be archived. about:telemetry thus never shows these pings. "quit-application" seems like a better time (that's the earliest observer when we know for sure the process is tearing down.
I also noticed that we always attempt to submit a ping, even when we didn't see any Syncs - this *should* be unlikely (given our module is only initialized as Sync itself does) but it seems worthwhile checking this.
Comment hidden (mozreview-request) |
Assignee | ||
Comment 2•8 years ago
|
||
mozreview-review |
Comment on attachment 8789210 [details]
Bug 1301289 - send accumulated sync pings earlier in the shutdown process.
https://reviewboard.mozilla.org/r/77504/#review75760
::: services/sync/modules/telemetry.js:341
(Diff revision 1)
> }
>
> finish(reason) {
> // Note that we might be in the middle of a sync right now, and so we don't
> // want to touch this.current.
> + if (this.payloads.length) {
oops - submit() checks this, so this additional block isn't needed.
Comment hidden (mozreview-request) |
Assignee | ||
Updated•8 years ago
|
Assignee: nobody → markh
Priority: -- → P1
Summary: Sync pings submitted to late in shutdown process, and possibly with an empty payload. → Sync pings submitted too late in shutdown process
Comment 4•8 years ago
|
||
(In reply to Mark Hammond [:markh] from comment #0)
> I noticed on shutdown an error in the console:
>
> > 1473309697806 Sync.Telemetry TRACE observed xpcom-shutdown null
> > JavaScript error: resource://gre/modules/AsyncShutdown.jsm, line 693: Error: Phase "TelemetryController: Waiting for pending ping activity" is finished, it is too late to register completion condition "Waiting for ping task"
We should catch this bug with a clearer error message, i will file a bug on this.
> The problem is that we are attempting to submit a ping on the xpcom-shutdown
> observer - but by this point the process has torn down so far that the ping
> can't be archived. about:telemetry thus never shows these pings.
> "quit-application" seems like a better time (that's the earliest observer
> when we know for sure the process is tearing down.
"profile-before-change" is also safe. If you are using AsyncShutdown, the `sendTelemetry` phase works too:
http://gecko.readthedocs.io/en/latest/toolkit/modules/toolkit_modules/AsyncShutdown.html#list-of-phases
Assignee | ||
Comment 5•8 years ago
|
||
(In reply to Georg Fritzsche [:gfritzsche] from comment #4)
> "profile-before-change" is also safe.
Thanks - I'll upload a new patch that uses that - the later we do it, the less chance we have of recording an aborted sync due to shutdown.
> If you are using AsyncShutdown
We aren't :(
Comment hidden (mozreview-request) |
Comment 7•8 years ago
|
||
mozreview-review |
Comment on attachment 8789210 [details]
Bug 1301289 - send accumulated sync pings earlier in the shutdown process.
https://reviewboard.mozilla.org/r/77504/#review75888
Ack! I should have checked this more thoroughly when working on the batching patch. Anyway, this looks fine modulo the typo.
::: services/sync/modules/telemetry.js:364
(Diff revision 3)
>
> submit(record) {
> // We still call submit() with possibly illegal payloads so that tests can
> // know that the ping was built. We don't end up submitting them, however.
> if (record.syncs.length) {
> + log.trace(`submitting ${record.syncs.length} sync record(s) to telemtry`);
nit: telemtry should be telemetry
Attachment #8789210 -
Flags: review?(tchiovoloni) → review+
Comment hidden (mozreview-request) |
Pushed by mhammond@skippinet.com.au:
https://hg.mozilla.org/integration/autoland/rev/09e3f293166a
send accumulated sync pings earlier in the shutdown process. r=tcsc
I had to back this out for xpcshell failures like https://treeherder.mozilla.org/logviewer.html#?job_id=3290596&repo=autoland
https://hg.mozilla.org/integration/autoland/rev/0ded9e464840
Flags: needinfo?(markh)
Comment hidden (mozreview-request) |
Assignee | ||
Comment 12•8 years ago
|
||
Thanks - error was introduced in the final version of the patch and I didn't re-run the tests. Usual story :( Pushed with a test fix.
Flags: needinfo?(markh)
Comment 13•8 years ago
|
||
Pushed by mhammond@skippinet.com.au:
https://hg.mozilla.org/integration/autoland/rev/1a47959fb817
send accumulated sync pings earlier in the shutdown process. r=tcsc
Comment 14•8 years ago
|
||
bugherder |
Status: NEW → RESOLVED
Closed: 8 years ago
status-firefox51:
--- → fixed
Resolution: --- → FIXED
Target Milestone: --- → Firefox 51
Assignee | ||
Comment 15•8 years ago
|
||
Comment on attachment 8789210 [details]
Bug 1301289 - send accumulated sync pings earlier in the shutdown process.
Approval Request Comment
[Feature/regressing bug #]: bug 1295058
[User impact if declined]: Sync pings not sent at shutdown.
[Describe test coverage new/current, TreeHerder]: Tests pass, been on 51 for some time.
[Risks and why]: Fairly low risk - limited to sync
[String/UUID change made/needed]: None
Note bug 1295058 will need to be applied before this.
Attachment #8789210 -
Flags: approval-mozilla-beta?
Waiting for a reply on this one https://bugzilla.mozilla.org/show_bug.cgi?id=1295058#c35 before deciding whether to uplift both these fixes.
status-firefox50:
--- → affected
Comment on attachment 8789210 [details]
Bug 1301289 - send accumulated sync pings earlier in the shutdown process.
Telemetry team has verified that this fix reduced the load on the server in Nightly51, Beta50+
Attachment #8789210 -
Flags: approval-mozilla-beta? → approval-mozilla-beta+
Assignee | ||
Comment 19•8 years ago
|
||
Here's a version rebased against beta.
Flags: needinfo?(markh)
Attachment #8794023 -
Flags: review+
Comment 20•8 years ago
|
||
bugherder uplift |
Flags: in-testsuite+
You need to log in
before you can comment on or make changes to this bug.
Description
•