1480948 - Intermittent toolkit/components/extensions/test/xpcshell/test_ext_schema.js | application crashed [@ libxul.so + 0x158c91d]

Status: RESOLVED FIXED

(WebExtensions :: General, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: dluca [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=191977202&repo=mozilla-inbound

https://queue.taskcluster.net/v1/task/XEDsTRXVRGeM5zTaq5C7yQ/runs/0/artifacts/public/logs/live_backing.log

NFO -  exiting test
[task 2018-08-03T23:32:37.711Z] 23:32:37     INFO -  xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_ext_schema.js | 1533339155425	addons.webextension.{a6c9c50f-5124-40bf-9090-43137d9039df}	WARN	Loading extension '{a6c9c50f-5124-40bf-9090-43137d9039df}': Unable to access extension storage.local data file: OS.File has been shut down. Rejecting post to exists::post@resource://gre/modules/osfile/osfile_async_front.jsm:407:29
[task 2018-08-03T23:32:37.711Z] 23:32:37     INFO -  xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_ext_schema.js | exists@resource://gre/modules/osfile/osfile_async_front.jsm:1117:10
[task 2018-08-03T23:32:37.711Z] 23:32:37     INFO -  xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_ext_schema.js | migrateJSONFileData@resource://gre/modules/ExtensionStorageIDB.jsm:408:30
[task 2018-08-03T23:32:37.712Z] 23:32:37     INFO -  xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_ext_schema.js | Segmentation fault
[task 2018-08-03T23:32:37.712Z] 23:32:37     INFO -  <<<<<<<
[task 2018-08-03T23:32:38.109Z] 23:32:38     INFO -  mozcrash Downloading symbols from: https://queue.taskcluster.net/v1/task/dNXwUPkAQSK9e44wp8Isvw/artifacts/public/build/target.crashreporter-symbols.zip
[task 2018-08-03T23:32:43.192Z] 23:32:43     INFO -  mozcrash Copy/paste: /usr/local/bin/linux64-minidump_stackwalk /tmp/tmp880Cto/1402d712-2894-c04e-9485-e81cb4708427.dmp /tmp/tmpegEtfx
[task 2018-08-03T23:32:43.818Z] 23:32:43     INFO -  mozcrash Saved minidump as /builds/worker/workspace/build/blobber_upload_dir/1402d712-2894-c04e-9485-e81cb4708427.dmp
[task 2018-08-03T23:32:43.818Z] 23:32:43     INFO -  mozcrash Saved app info as /builds/worker/workspace/build/blobber_upload_dir/1402d712-2894-c04e-9485-e81cb4708427.extra
[task 2018-08-03T23:32:43.819Z] 23:32:43  WARNING -  PROCESS-CRASH | xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_ext_schema.js | application crashed [@ libxul.so + 0x158c91d]
[task 2018-08-03T23:32:43.822Z] 23:32:43     INFO -  Crash dump filename: /tmp/tmp880Cto/1402d712-2894-c04e-9485-e81cb4708427.dmp
[task 2018-08-03T23:32:43.822Z] 23:32:43     INFO -  Operating system: Android
[task 2018-08-03T23:32:43.822Z] 23:32:43     INFO -                    0.0.0 Linux 2.6.29 #1 PREEMPT Thu Nov 7 22:27:50 UTC 2013 i686
[task 2018-08-03T23:32:43.822Z] 23:32:43     INFO -  CPU: x86
[task 2018-08-03T23:32:43.822Z] 23:32:43     INFO -       GenuineIntel family 6 model 3 stepping 3
[task 2018-08-03T23:32:43.822Z] 23:32:43     INFO -       1 CPU
[task 2018-08-03T23:32:43.822Z] 23:32:43     INFO -  GPU: UNKNOWN
[task 2018-08-03T23:32:43.822Z] 23:32:43     INFO -  Crash reason:  SIGSEGV
[task 2018-08-03T23:32:43.822Z] 23:32:43     INFO -  Crash address: 0xe5e5e5f5
[task 2018-08-03T23:32:43.822Z] 23:32:43     INFO -  Process uptime: not available
[task 2018-08-03T23:32:43.823Z] 23:32:43     INFO -  Thread 0 (crashed)

Comment 1

[Luca Greco [:rpl] [:luca] [:lgreco]]

Attachment: Bug 1480948 - Defer or await storage.local data migration on extension shutdown.

Review commit: https://reviewboard.mozilla.org/r/261352/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/261352/

Comment 2

[Luca Greco [:rpl] [:luca] [:lgreco]]

Attachment: Bug 1480948 - Add AsyncShutdown blocker for the storage.local data migration promise.

Review commit: https://reviewboard.mozilla.org/r/261354/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/261354/

Comment 3

[Luca Greco [:rpl] [:luca] [:lgreco]]

This failure is definitely related to Bug 1474562, one of the test extension used in test_ext_schema has the "storage" permission, and so there will be a data migration executed on idle, but this test doesn't call the storage.local API and so it may be shutting down before the data migration is ever started:

- https://searchfox.org/mozilla-central/rev/e9d2dce0820fa2616174396459498bcb96ecf812/toolkit/components/extensions/test/xpcshell/test_ext_schema.js#7-10,16

This is not something that should be fixed in the test, but we should take it into account that the extension may be shutting down before or after we schedule the storage.local data migration.

The first of the attached patches:
- do not run the data migration if the extension has been already unloaded
- awaits on the promise returned by "ExtensionStorageIDB.selectBackend" (if it has been called) before proceeding with shutting down the extension

The second one:
- adds an AsyncShutdown blocker for the "data migration" promise

Comment 4

[Luca Greco [:rpl] [:luca] [:lgreco]]

Comment on attachment 8997666 [details]
Bug 1480948 - Defer or await storage.local data migration on extension shutdown.

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/261352/diff/1-2/

Comment 5

[Luca Greco [:rpl] [:luca] [:lgreco]]

Comment on attachment 8997667 [details]
Bug 1480948 - Add AsyncShutdown blocker for the storage.local data migration promise.

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/261354/diff/1-2/

Comment 6

[Andrew Swan [:aswan]]

Comment on attachment 8997666 [details]
Bug 1480948 - Defer or await storage.local data migration on extension shutdown.

https://reviewboard.mozilla.org/r/261352/#review268564

::: toolkit/components/extensions/Extension.jsm:1854
(Diff revision 2)
>        return;
>      }
>  
> +    if (this.hasPermission("storage") && ExtensionStorageIDB.selectedBackendPromises.has(this)) {
> +      // Wait the data migration to complete.
> +      await ExtensionStorageIDB.selectedBackendPromises.get(this).catch(err => {

nit: just put this inside a try/catch

Comment 7

[Luca Greco [:rpl] [:luca] [:lgreco]]

Comment on attachment 8997666 [details]
Bug 1480948 - Defer or await storage.local data migration on extension shutdown.

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/261352/diff/2-3/

Comment 8

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/51c01db0c02f
Defer or await storage.local data migration on extension shutdown. r=aswan

Comment 9

[Arthur Iakab [arthur_iakab]]

https://hg.mozilla.org/mozilla-central/rev/51c01db0c02f

Comment 10

[Luca Greco [:rpl] [:luca] [:lgreco]]

Marking as qe-verify-, because the issue is not that easy to trigger manually, nevertheless looking at Threeherder graph (https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?startday=2018-08-07&endday=2018-08-17&tree=trunk&bug=1480948) for this issue the crash doesn't seem to have been happened again on any "try run" after we landed the fix, as a confirmation that the patch fixed the issue described in comment 3.