AsyncShutdown timeout in asyncEmitManifestEntry("chrome_settings_overrides")

RESOLVED FIXED in Firefox 67

Status

defect
P1
normal
RESOLVED FIXED
4 months ago
a month ago

People

(Reporter: philipp, Assigned: robwu)

Tracking

(Blocks 1 bug, {crash, regression})

63 Branch
mozilla67
Dependency tree / graph
Bug Flags:
qe-verify -

Firefox Tracking Flags

(firefox-esr60 unaffected, firefox65 wontfix, firefox66 wontfix, firefox67 fixed)

Details

(crash signature)

Attachments

(2 attachments)

Reporter

Description

4 months ago

+++ This bug was initially created as a clone of Bug #1493770 +++

This bug is for crash report bp-732d9200-05ae-4068-a66f-91cf50190206.

AsyncShutdownTimeout:

{

    "phase":"profile-change-teardown",
    "conditions":[
        {
            "name":"Extension shutdown: _j5Members_@ext.ask.com",
            "state":{
                "state":"Startup: Run manifest: asyncEmitManifestEntry("chrome_settings_overrides")"
            },
            "filename":"resource://gre/modules/addons/XPIProvider.jsm",
            "lineNumber":2236,
            "stack":[
                "resource://gre/modules/addons/XPIProvider.jsm:startup/<:2236",
                "resource://gre/modules/AsyncShutdown.jsm:observe:541",
                "jar:file:///C:/Program%20Files/Mozilla%20Firefox/omni.ja!/components/marionette.js:observe/<:384"
            ]
        }
    ]

}

these particular async shutdown timeout crashes started showing up since firefox 63 with webextensions adding a custom search provider.

bug 1493770 already took a stab at fixing those crashes, but that didn't make the crash volume noticeably decline in firefox 65, so i'm filing this as a followup.

this crash-stats query should catch the remaining issues:
https://crash-stats.mozilla.com/search/?async_shutdown_timeout=~chrome_settings_overrides&build_id=%3E%3D20190124174741&date=%3E%3D2019-01-01&_facets=signature&_facets=version&_facets=platform_pretty_version&_facets=useragent_locale#facet-signature

Priority: -- → P1
Assignee

Comment 1

3 months ago

TL;DR The crash is caused by await searchInitialized; at https://searchfox.org/mozilla-central/rev/cb7faaf6b4ad2528390186f1ce64618dea71031e/browser/components/extensions/parent/ext-chrome-settings-overrides.js#193

The onManifestEntry handler of ext-chrome-settings-overrides.js has several await calls, each of which could be responsible for this crash. I'm only looking at await because these block the promise. I'm not considering synchronous API calls because it's unlikely for those to block the promise for a minute.

I fetched all add-ons that were reported in the 1630 crash reports from this year until yesterday, and checked the content of the extensions' chrome_settings_override.

There are some crashes where the responsible add-on does not have chrome_settings_override.search_provider.is_default. This allows us to eliminate the majority of await uses, leaving only three potential causes of the hang:

From the reports, 2 of the add-ons involved in a crash have only set a homepage_url. This rules out the first option (because then we should have seen significantly more crashes from add-ons that had only set chrome_settings_override.homepage, and we should also also have seen a similar volume of crashes for addons that use chrome_url_overrides, because it also uses similar code).

addSearchEngine currently has many awaits, but most of these were recently added. The crashes already happened before that, so that leaves the only cause in addSearchEngine to be await ExtensionSettingsStore.addSetting (https://searchfox.org/mozilla-central/rev/10ed8acc81f55dd9a7b0a2330447592a3e5c5027/browser/components/extensions/parent/ext-chrome-settings-overrides.js#286).

ExtensionSettingsStore.addSetting is also used by ext-url-overrides.js, for we have only 23 crash reports in the same time frame as the this bug (87 crash reports in the past six months) (reports with asyncEmitManifestEntry(\"chrome_url_overrides\")).
If ExtensionSettingsStore.addSetting were to be the cause of this bug, then the crash rates for chrome_url_overrides should also have been higher.

This leaves us with one possible cause for this crash, await searchInitialized;, which is defined at https://searchfox.org/mozilla-central/rev/01b4b3830ea3cae2e9e431019afa6391b471c6da/browser/components/extensions/parent/ext-browser.js#249-254

The searchInitialized promise is only fulfilled when the "browser-search-service" notification has been triggered. Coincidentally, the defaultSearchEngine / defaultSearchEngineData fields in the telemetry environment are only set up once the notification has been triggered.
These fields are missing from the telemetry environment in the crash reports of this bug, which offers conclusive evidence that this crash is caused by the await searchInitialized;.

Reporter

Updated

3 months ago
Blocks: 1352598
Assignee

Updated

3 months ago
Assignee: nobody → rob
Status: NEW → ASSIGNED
Attachment #9043708 - Attachment description: Bug 1525729 - Reject searchInitialized promise on shutdown → Bug 1525729 - Ignore searchInitialized promise on shutdown

Comment 3

3 months ago
Pushed by rob@robwu.nl:
https://hg.mozilla.org/integration/autoland/rev/52747743fe65
Ignore searchInitialized promise on shutdown r=aswan
Attachment #9043708 - Attachment description: Bug 1525729 - Ignore searchInitialized promise on shutdown → Bug 1525729 - Stop blocking extension startup on searchInitialized
Assignee

Updated

3 months ago
Flags: needinfo?(rob)
Assignee

Updated

2 months ago
Depends on: 1534969
Assignee

Comment 5

2 months ago

When I added AddonTestUtils.initMochiTest to an existing test at
browser/components/preferences/in-content/tests/browser_extension_controlled.js
, the test started to fail often on debug builds, with errors like
"leaked 2 window(s) until shutdown".
Fix this by clearing the global that was saved by initMochiTest.

Assignee

Comment 6

2 months ago

I'm landing the patch from comment 5 first, because the other patch is part of a patch stack that has to land after comment 5's patch to avoid test failures.

Keywords: leave-open

Comment 7

2 months ago
Pushed by rob@robwu.nl:
https://hg.mozilla.org/integration/autoland/rev/e9f1a449031d
Avoid memory leak via AddonTestUtils.initMochiTest r=aswan
Assignee

Comment 9

2 months ago

Now going to land the other stack.
Green try: https://treeherder.mozilla.org/#/jobs?repo=try&revision=a5719215b8b9e36dcac09b69dd1218a136713b00
The commits of the patch stack aren't visible in the try push because they were part of a preview push (whose failures have been addressed in the above try push):
https://treeherder.mozilla.org/#/jobs?repo=try&revision=0db411f072f79dbf7dc9c399cd3b2a044947f249

Keywords: leave-open

Comment 10

2 months ago
Pushed by rob@robwu.nl:
https://hg.mozilla.org/integration/autoland/rev/f28acbccbc62
Stop blocking extension startup on searchInitialized r=aswan

Comment 11

2 months ago
bugherder
Status: ASSIGNED → RESOLVED
Last Resolved: 2 months ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla67

Comment 12

2 months ago

Can you please provide us an extension that we can use to test this manually (and some steps to reproduce the crash would be much apreciated)?

Flags: needinfo?(rob)
You need to log in before you can comment on or make changes to this bug.