Stalled out download of trainhop XPI can still cause shutdown hangs / crashes
Categories
(Firefox :: New Tab Page, defect)
Tracking
()
| Tracking | Status | |
|---|---|---|
| firefox-esr140 | --- | unaffected |
| firefox-esr153 | --- | wontfix |
| firefox155 | --- | wontfix |
| firefox156 | --- | fixed |
| firefox157 | --- | fixed |
People
(Reporter: mconley, Assigned: mconley)
References
(Blocks 2 open bugs)
Details
(Keywords: crash, topcrash)
Crash Data
Attachments
(3 files)
|
5.60 KB,
patch
|
Details | Diff | Splinter Review | |
|
48 bytes,
text/x-phabricator-request
|
Details | Review | |
|
48 bytes,
text/x-phabricator-request
|
phab-bot
:
approval-mozilla-beta+
|
Details | Review |
Bug 1991490 addressed a shutdown hang that could occur if a download of the train-hop XPI was occurring but not yet complete at the time of shutdown. From looking at the crash stat graphs over the last few months since that patch landed, and since we've done several more train-hops, it seems that there are still occurances of shutdown hangs occurring:
This bug is for investigating what's going on.
| Assignee | ||
Updated•7 months ago
|
Updated•7 months ago
|
Comment 2•7 months ago
|
||
This bug has the keyword crash, so its type should be defect.
Comment 3•7 months ago
|
||
The severity field is not set for this bug.
:thecount, could you have a look please?
For more information, please visit BugBot documentation.
| Assignee | ||
Comment 4•7 months ago
|
||
One of the things we can perhaps do here is add the fetchState option, to try to give our crash reports a better sense of what state the task is in when it times out.
Before we do that though, I want to back up and consider what happens if we remove the AsyncShutdown blocker altogether. rpl, are we certain that we actually need to finalize an attempt to download / install the train-hop? What is the worst-case scenario for interrupting that process without waiting for it to finish?
Comment 5•7 months ago
|
||
One of the things we can perhaps do here is add the fetchState option, to try to give our crash reports a better sense of what state the task is in when it times out.
That feels valuable, I should have thought about doing that when we were looking into the previous shutdown hang.
Before we do that though, I want to back up and consider what happens if we remove the AsyncShutdown blocker altogether. rpl, are we certain that we actually need to finalize an attempt to download / install the train-hop? What is the worst-case scenario for interrupting that process without waiting for it to finish?
Looking to the logic related to what we are doing inside method that handles the train hop I'd assume nothing too bad should be happening in the most common scenario, I feel that the firstStartup scenario would concern me a bit more because in that case we would be willing to move forward with the staged installation.
To be honest the fact that we do have a deferred task that we are re-arming makes me kind of prefer if we could be sure to finalize it, mainly because it feels odd to leave it without an explicit finalization (but I couldn't think of a particular thing that would make that really bad in practice).
The other thing that was bothering me was not having a more clear idea of what may be going on when the issue is hit and so I took a more close look to the code paths and I tried to force a few more edge cases that I could think of, in particular one where the xpi installation has not been technically started yet by the time we are starting to be shutting down the application, the logic that handles the train hopping has more than a few await for things that are technically async and so it felt like not that unlikely that the shutdown may be initiate in between those async calls being awaited on.
As an example, I managed to hit a shutdown hang consistently by calling Services.startup.quit(Ci.nsIAppStartup.eAttemptQuit) right before the await this._installTrainhopAddon(...) call near the end of the updateTrainhopAddonState here or between that and the install.install() call that gets the installation started.
In that case as you also mentioned briefly in comment 0, the change we have applied as part of Bug 1991490 isn't really helping, with that change we only cancel the installation did actually start to receive some data, but if that wasn't yet the case there wouldn't be any observer in the DownloadAddonInstall instance that would be getting notified about the quit-application-granted topic and so the download would not be cancelled.
The xpcshell test that I'm attaching tries to demonstrate the role that the appShutdownConfirmed shutdown blocker is having in preventing the shutdown to proceed further, and also demonstrates that using profileChangeTeardown doesn't hit that same kind of hang (because that shutdown phase is coming right after the "profile-change-net-teardown" phase where the network teardown does actually make all DownloadAddonInstall to fail due to the onStopRequest http activity triggering the pending download to fail right away (unfortunately I couldn't find a way to test it out as realistically as in the attached patch without calling Services.startup.quit in the test itself, and so I don't consider that test as is something we could land, but I decided to attach it because it demonstrate the same behavior that I was hitting in a Firefox build by forcing an app shutdown purposely at the right time).
Similarly, by applying a change like that in the AboutNewTabResourceMapping.sys.mjs module (as in the diff that follows) I wasn't able to trigger the shutdown hang in the same way as before applying it.
:mconley wdyt? does the following seem worth a try?
(as a side note, the following patch also apply another small tweak to be sure we would not be completed the postponed installation if we got past the download but we are also shutting down).
diff --git a/browser/components/newtab/AboutNewTabResourceMapping.sys.mjs b/browser/components/newtab/AboutNewTabResourceMapping.sys.mjs
index 92f9893f7e15..e66243fe75cd 100644
--- a/browser/components/newtab/AboutNewTabResourceMapping.sys.mjs
+++ b/browser/components/newtab/AboutNewTabResourceMapping.sys.mjs
@@ -399,7 +399,14 @@ export var AboutNewTabResourceMapping = {
delayMs,
idleTimeoutMs
);
- lazy.AsyncShutdown.appShutdownConfirmed.addBlocker(
+ // Trainhop Updates finalization added as a blocker of AppShutdownTeardown,
+ // which happens right after AppShutdownNetTeardown (which is expected to
+ // stop any DownloadAddonInstall still in progress) and reduce the time needed
+ // by this AsyncShutdown blocker to become fully finalized.
+ //
+ // See https://searchfox.org/firefox-main/rev/ad106dcbb4/ipc/docs/proc_shutdown.md#25-27
+ // for more details about the shutdown sequence.
+ lazy.AsyncShutdown.profileChangeTeardown.addBlocker(
`${TRAINHOP_NIMBUS_FEATURE_ID} scheduleUpdateTrainhopAddonState shutting down`,
() => this._updateAddonStateDeferredTask.finalize()
);
@@ -643,14 +650,20 @@ export var AboutNewTabResourceMapping = {
},
onInstallPostponed: () => {
this.logger.debug("Train-hop install postponed, as expected");
- if (forceRestartlessInstall && !this.initialized) {
+ if (
+ forceRestartlessInstall &&
+ !this.initialized &&
+ !Services.startup.attemptingQuit
+ ) {
this.logger.debug("Forcing restartless install of train-hop");
newInstall.continuePostponedInstall();
} else {
this.logger.debug("Not forcing restartless install");
if (forceRestartlessInstall) {
this.logger.debug(
- "We must have initialized before the XPI finished downloading."
+ Services.startup.attemptingQuit
+ ? "Application Shutdown already initiated"
+ : "We must have initialized before the XPI finished downloading."
);
}
deferred.resolve();
Comment 6•7 months ago
|
||
I'm removing the assignee implicitly set by bugzilla when I have attached the xpcshell test to demonstrate the role that appShutdownConfirmed blocker seems to have in triggering a shutdown hang, but as mentioned in comment 5 that patch is not meant to be landed (the test resorts to call Services.startup.quit to recreate the scenario).
Let's determine first if we feel that the rationale sounds reasonable and if the tweak described at the end of comment 5 feels like worth pursuing.
Comment 7•7 months ago
•
|
||
I've been thinking about this some more today and another middle ground approach may be to:
-
to not use an AsyncShutdown blocker anymore on the AboutNewTabResourceMapping side (as mentioned in comment 4), but to also add logic to bail out instead of calling newInstall.continuePostponedInstall by checking explicitly if Services.startup.attemptingQuit is true in the onInstallPostponed (similar to the diff at the end of comment 5)
-
and to leave to the AsyncShutdown blockers on the XPIProvider side the responsability to deal with the XPIProvider's operations that may still be in progress while we are about to shutdown.
Comment 8•5 months ago
|
||
Looks like we're still seeing this spike every time a new trainhop addon ships. Anything we can do to get it moving forward again?
| Assignee | ||
Comment 9•1 month ago
|
||
Looking again...
| Assignee | ||
Comment 10•1 month ago
|
||
Hey rpl, I think your middle ground in comment 7 sounds very reasonable to me. Do you have time to review a patch if I take a crack at it?
Comment 11•1 month ago
|
||
(In reply to Mike Conley (:mconley) (:⚙️) from comment #10)
Hey rpl, I think your middle ground in comment 7 sounds very reasonable to me. Do you have time to review a patch if I take a crack at it?
Hey Mike, sorry for not getting back to you sooner. Yes I'll be more than happy to give a review pass of the patch applying those changes, feel free to add me as the reviewer on the patch once you are putting it up on phabricator.
Comment 13•1 month ago
|
||
According to crash ping data, this is currently the #2 highest main process crasher in release (and it could potentially be #1, since the #1 crasher is a mistaken signature that hides more AsyncShutdownTimeout signatures). This should be a high priority to fix, as it is linked with elevated crash rates on Linux and Windows over the past few months.
Comment 14•1 month ago
|
||
scheduleUpdateTrainhopAddonState registered an AsyncShutdown.appShutdownConfirmed
blocker that awaited _updateAddonStateDeferredTask.finalize(). That tied application
shutdown to the completion of a train-hop XPI download/install, producing the
AsyncShutdownTimeout | quit-application | newtabTrainhopAddon scheduleUpdateTrainhopAddonState shutting down top crash.
Bug 1991490 relied on DownloadAddonInstall's quit-application-granted observer to
cancel an in-flight download, but that notification is one-shot and is fired before
AppShutdownConfirmed. If the deferred task is anywhere in its await chain
(NimbusFeatures.ready(), AddonManager.getAddonByID, getAllInstalls,
getInstallForURL, ...) when it fires, the install started afterwards registers its
observer too late, is never cancelled, and the blocker hangs until the AsyncShutdown
timeout kills the process. There is also no shutdown handling at all during the
post-download staging window (onStopRequest removes both observers before staging).
Rather than papering over that race, take the middle-ground approach agreed in comment 7:
- Drop the AsyncShutdown blocker entirely. Interrupting the update is safe: an already
staged install is applied on the next startup, and everything else is recomputed from
the Nimbus enrollments next session. Finalizing XPIProvider operations that are still
in progress is left to the XPIProvider's own AsyncShutdown blockers. - Add an
_isAppShuttingDown()helper based onnsIAppStartup.attemptingQuit(the
earliest signal, set beforequit-application-grantedis notified) plus the existing
isInOrBeyondShutdownPhase(APPSHUTDOWNCONFIRMED)check, for shutdowns that don't go
throughnsIAppStartup.quit. - Use it to bail out of the deferred task, to avoid starting a download that could never
be cancelled, and to avoid callingcontinuePostponedInstall()on the FirstStartup
restartless path once shutdown has begun.
Adds test_nimbus_newtabTrainhopAddon_shutdown.js, which reproduces the hang: with a
stalled _installTrainhopAddon, triggering the appShutdownConfirmed barrier used to
block until the harness force-killed the process; it now returns immediately. It also
covers not starting a download and not forcing a restartless install during shutdown.
test_nimbus_newtabTrainhopAddon_onBrowserReady.js finalizes the deferred task directly
now that no blocker does it.
Updated•1 month ago
|
Updated•1 month ago
|
Comment 15•1 month ago
|
||
Is it possible that this same bug is causing the AsyncShutdownTimeout | profile-before-change | AddonManager: shutting down. crash signature?
Comment 16•1 month ago
|
||
Comment 17•1 month ago
|
||
| bugherder | ||
Updated•1 month ago
|
Comment 18•1 month ago
|
||
The patch landed in nightly and beta is affected.
:mconley, is this bug important enough to require an uplift?
- If yes, please nominate the patch for beta approval.
- See https://wiki.mozilla.org/Release_Management/Requesting_an_Uplift for documentation on how to request an uplift.
- If no, please set
status-firefox156towontfix.
For more information, please visit BugBot documentation.
| Assignee | ||
Comment 19•1 month ago
|
||
scheduleUpdateTrainhopAddonState registered an AsyncShutdown.appShutdownConfirmed
blocker that awaited _updateAddonStateDeferredTask.finalize(). That tied application
shutdown to the completion of a train-hop XPI download/install, producing the
AsyncShutdownTimeout | quit-application | newtabTrainhopAddon scheduleUpdateTrainhopAddonState shutting down top crash.
To fix this, we now:
- Drop the AsyncShutdown blocker entirely. Interrupting the update is safe: an already
staged install is applied on the next startup, and everything else is recomputed from
the Nimbus enrollments next session. Finalizing XPIProvider operations that are still
in progress is left to the XPIProvider's own AsyncShutdown blockers. - Add an
_isAppShuttingDown()helper based onnsIAppStartup.attemptingQuit(the
earliest signal, set beforequit-application-grantedis notified) plus the existing
isInOrBeyondShutdownPhase(APPSHUTDOWNCONFIRMED)check, for shutdowns that don't go
throughnsIAppStartup.quit. - Use it to bail out of the deferred task, to avoid starting a download that could never
be cancelled, and to avoid callingcontinuePostponedInstall()on the FirstStartup
restartless path once shutdown has begun.
Original Revision: https://phabricator.services.mozilla.com/D320515
Updated•1 month ago
|
Comment 20•1 month ago
|
||
firefox-beta Uplift Approval Request
- User impact if declined/Reason for urgency: We believe this will address a top shutdown crash that occurs when download of a newtab trainhop XPI is only partially completed at shutdown.
- Code covered by automated testing?: yes
- Fix verified in Nightly?: no
- Needs manual QE testing?: no
- Steps to reproduce for manual QE testing:
- Risk associated with taking this patch: low
- Explanation of risk level: This removes an AsyncShutdown blocker within the mechanism that downloads and installs the newtab trainhop XPI. The goal is to get this uplifted to Beta and do a trainhop to that channel in order to ensure that the deployment mechanism still works and that the crashes have gone.
- String changes made/needed?: None.
- Is Android affected?: no
Updated•1 month ago
|
| Assignee | ||
Updated•1 month ago
|
Updated•1 month ago
|
Comment 21•1 month ago
|
||
| uplift | ||
Updated•27 days ago
|
Description
•