2052043 - xpcshell timeout profiles can be truncated or lost when the scheduled dump is killed mid-write

Status: RESOLVED FIXED

(Core :: Gecko Profiler, defect, P3)

Description

[Florian Quèze [:florian]]

With the Gecko profiler running by default, an xpcshell test that times out (typically a shutdown hang) should leave a complete, parseable profile so the hang is diagnosable. The scheduled off-main-thread timeout dump added in bug 2050049 (profiler_schedule_dump_to_file / nsIProfiler.scheduleDumpToFile) is written by the profiler's sampler thread, and two things can prevent a complete profile from reaching the artifacts:

1. The xpcshell harness (runxpcshelltests.py) can force-kill the process while the sampler thread is still writing, uploading truncated (unparseable) JSON.
2. Fatal-abort paths -- AsyncShutdown's gDebug.abort and the nsTerminator watchdog -- can crash the process mid-write.

The profile file also stays flat at ~350 KB during the slow in-memory "threads" build (everything is spliced into the output only at the end), so its size is not a usable progress signal for deciding whether to keep waiting.

Planned work:

• Dump at the full test timeout and move the harness safety-net kill to 150% of the timeout, widening the window the dump has to complete.
• Have the sampler thread exit the process as soon as the scheduled dump is fully written (aExitAfterDump), so a timed out test ends promptly instead of sitting idle until the 150% safety-net kill.
• Let fatal-abort paths wait for an in-progress scheduled dump (profiler_wait_for_scheduled_dump / nsIProfiler.waitForScheduledDump) instead of crashing over a half-written profile.
• Report the dump's 0..1 streaming progress via a <profile>.progress sidecar file (fed by the profiler's ProgressLogger / SharedProgress) so the harness defers its kill while progress advances and only kills on a genuine stall.

Comment 1

[Florian Quèze [:florian]]

Attachment: Bug 2052043 - Dump the xpcshell timeout profile at the full timeout and move the harness safety-net kill to 150%, r=ahal.

Comment 2

[Florian Quèze [:florian]]

Attachment: Bug 2052043 - Exit the process after writing a scheduled timeout profile so xpcshell timeout profiles aren't truncated, r=#profiler-reviewers,ahal.

Comment 3

[Florian Quèze [:florian]]

Attachment: Bug 2052043 - Let fatal-abort paths wait for an in-progress scheduled profiler dump instead of crashing mid-write, r=#profiler-reviewers.

Comment 4

[Florian Quèze [:florian]]

Attachment: Bug 2052043 - Report scheduled-dump streaming progress via a sidecar file so the xpcshell harness defers its kill while the dump is still progressing, r=#profiler-reviewers,ahal.

Comment 5

[Florian Quèze [:florian]]

Try push with the patches on a set of tests and a configuration (profiler sampling all threads) where the profiles were consistently truncated without the patches: https://treeherder.mozilla.org/jobs?repo=try&revision=83362d90e731660503e6dccc3ee69714638907c2
All profiles now seem valid.

A larger try push of all xpcshell tests: https://treeherder.mozilla.org/jobs?repo=try&revision=888868794818eda0042819aa8afbe08aba64c452

Comment 6

[Markus Stange [:mstange]]

I haven't looked at the patches yet, but my inclination is to avoid the file and reduce complexity. What we're doing here is:

1. Trigger a profile dump at 100% of the timeout
2. Definitely kill the browser at 150% of timeout + 5 minutes
3. Don't wait the entire max time if profile dumping completes earlier
4. Don't wait the entire max time if profile dumping is hanging (makes no progress)

1 and 2 sound good. We could do 3 by killing the browser from within Firefox once we're done with dumping the profile. And maybe 4 isn't that important? If we can discard 4 then we don't need the file.

I'll look at the patches now to see how much complexity this would actually avoid.

Comment 7

[Pulsebot]

Pushed by [e-mail]:
https://github.com/mozilla-firefox/firefox/commit/fea2cb9c3377
https://hg.mozilla.org/integration/autoland/rev/80558d586e12
Dump the xpcshell timeout profile at the full timeout and move the harness safety-net kill to 150%, r=ahal.
https://github.com/mozilla-firefox/firefox/commit/fae05b0ab162
https://hg.mozilla.org/integration/autoland/rev/18a7895dd488
Exit the process after writing a scheduled timeout profile so xpcshell timeout profiles aren't truncated, r=ahal,profiler-reviewers,mstange.
https://github.com/mozilla-firefox/firefox/commit/cd4a4a3e5aad
https://hg.mozilla.org/integration/autoland/rev/48184b06a4ea
Let fatal-abort paths wait for an in-progress scheduled profiler dump instead of crashing mid-write, r=profiler-reviewers,mstange.
https://github.com/mozilla-firefox/firefox/commit/3ecee2222643
https://hg.mozilla.org/integration/autoland/rev/f2259ca5ffac
Report scheduled-dump streaming progress via a sidecar file so the xpcshell harness defers its kill while the dump is still progressing, r=profiler-reviewers,mstange.

Comment 8

[Pulsebot]

Pushed by [e-mail]:
https://github.com/mozilla-firefox/firefox/commit/e2fcff109358
https://hg.mozilla.org/integration/autoland/rev/b5d85ec10416
Dump the xpcshell timeout profile at the full timeout and move the harness safety-net kill to 150%, r=ahal.
https://github.com/mozilla-firefox/firefox/commit/eca48a2100c6
https://hg.mozilla.org/integration/autoland/rev/ac4407ac1dcf
Exit the process after writing a scheduled timeout profile so xpcshell timeout profiles aren't truncated, r=ahal,profiler-reviewers,mstange.
https://github.com/mozilla-firefox/firefox/commit/bac159981d4b
https://hg.mozilla.org/integration/autoland/rev/d336ab1b50d3
Let fatal-abort paths wait for an in-progress scheduled profiler dump instead of crashing mid-write, r=profiler-reviewers,mstange.
https://github.com/mozilla-firefox/firefox/commit/464a326d88ea
https://hg.mozilla.org/integration/autoland/rev/b5a72f733905
Report scheduled-dump streaming progress via a sidecar file so the xpcshell harness defers its kill while the dump is still progressing, r=profiler-reviewers,mstange.

Comment 9

[pstanciu]

https://hg.mozilla.org/mozilla-central/rev/80558d586e12
https://hg.mozilla.org/mozilla-central/rev/18a7895dd488
https://hg.mozilla.org/mozilla-central/rev/48184b06a4ea
https://hg.mozilla.org/mozilla-central/rev/f2259ca5ffac
https://hg.mozilla.org/mozilla-central/rev/b5d85ec10416
https://hg.mozilla.org/mozilla-central/rev/ac4407ac1dcf
https://hg.mozilla.org/mozilla-central/rev/d336ab1b50d3
https://hg.mozilla.org/mozilla-central/rev/b5a72f733905