1481000 - Intermittent toolkit/components/extensions/test/xpcshell/test_ext_storage_managed.js | test_manifest_not_found - [test_manifest_not_found : 257] A promise chain failed to handle a rejection

Status: RESOLVED DUPLICATE of bug 1480948

(WebExtensions :: General, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: nerli [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=192065366&repo=autoland

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

[task 2018-08-04T14:40:41.234Z] 14:40:41     INFO -  TEST-START | xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_ext_api_permissions.js
[task 2018-08-04T14:40:41.939Z] 14:40:41     INFO -  TEST-PASS | xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_ext_api_permissions.js | took 703ms
[task 2018-08-04T14:40:41.954Z] 14:40:41     INFO -  TEST-START | xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_ext_storage_managed.js
[task 2018-08-04T14:40:42.742Z] 14:40:42  WARNING -  TEST-UNEXPECTED-FAIL | xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_ext_storage_managed.js | xpcshell return code: 0
[task 2018-08-04T14:40:42.744Z] 14:40:42     INFO -  TEST-INFO took 784ms
[task 2018-08-04T14:40:42.745Z] 14:40:42     INFO -  >>>>>>>
[task 2018-08-04T14:40:42.747Z] 14:40:42     INFO -  (xpcshell/head.js) | test MAIN run_test pending (1)
[task 2018-08-04T14:40:42.749Z] 14:40:42     INFO -  (xpcshell/head.js) | test run_next_test 0 pending (2)
[task 2018-08-04T14:40:42.751Z] 14:40:42     INFO -  (xpcshell/head.js) | test MAIN run_test finished (2)
[task 2018-08-04T14:40:42.752Z] 14:40:42     INFO -  running event loop
[task 2018-08-04T14:40:42.754Z] 14:40:42     INFO -  xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_ext_storage_managed.js | Starting check_remote
[task 2018-08-04T14:40:42.756Z] 14:40:42     INFO -  (xpcshell/head.js) | test check_remote pending (2)
[task 2018-08-04T14:40:42.758Z] 14:40:42     INFO -  TEST-PASS | xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_ext_storage_managed.js | check_remote - [check_remote : 1441] useRemoteWebExtensions matches - false == false
[task 2018-08-04T14:40:42.758Z] 14:40:42     INFO -  TEST-PASS | xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_ext_storage_managed.js | check_remote - [check_remote : 1441] testing from extension process - true == true
[task 2018-08-04T14:40:42.758Z] 14:40:42     INFO -  (xpcshell/head.js) | test run_next_test 0 finished (2)
[task 2018-08-04T14:40:42.759Z] 14:40:42     INFO -  (xpcshell/head.js) | test run_next_test 1 pending (2)
[task 2018-08-04T14:40:42.759Z] 14:40:42     INFO -  (xpcshell/head.js) | test check_remote finished (2)
[task 2018-08-04T14:40:42.759Z] 14:40:42     INFO -  xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_ext_storage_managed.js | Starting setup
[task 2018-08-04T14:40:42.759Z] 14:40:42     INFO -  (xpcshell/head.js) | test setup pending (2)
[task 2018-08-04T14:40:42.759Z] 14:40:42     INFO -  PID 22702 | 1533393642109	addons.xpi	WARN	List of valid built-in add-ons could not be parsed.: [Exception... "Component returned failure code: 0xc1f30001 (NS_ERROR_NOT_INITIALIZED) [nsIXPCComponents_Utils.readUTF8URI]"  nsresult: "0xc1f30001 (NS_ERROR_NOT_INITIALIZED)"  location: "JS frame :: resource://gre/modules/addons/XPIProvider.jsm :: startup :: line 2093"  data: no] Stack trace: startup()@resource://gre/modules/addons/XPIProvider.jsm:2093
[task 2018-08-04T14:40:42.759Z] 14:40:42     INFO -  PID 22702 | callProvider()@resource://gre/modules/AddonManager.jsm:206
[task 2018-08-04T14:40:42.759Z] 14:40:42     INFO -  PID 22702 | _startProvider()@resource://gre/modules/AddonManager.jsm:654
[task 2018-08-04T14:40:42.759Z] 14:40:42     INFO -  PID 22702 | startup()@resource://gre/modules/AddonManager.jsm:813
[task 2018-08-04T14:40:42.759Z] 14:40:42     INFO -  PID 22702 | startup()@resource://gre/modules/AddonManager.jsm:2808
[task 2018-08-04T14:40:42.759Z] 14:40:42     INFO -  PID 22702 | observe()@jar:file:///builds/worker/workspace/build/application/firefox/omni.ja!/components/addonManager.js:66
[task 2018-08-04T14:40:42.759Z] 14:40:42     INFO -  PID 22702 | startAddonManager()@resource://testing-common/ExtensionXPCShellUtils.jsm:733
[task 2018-08-04T14:40:42.759Z] 14:40:42     INFO -  PID 22702 | setup()@/builds/worker/workspace/build/tests/xpcshell/tests/toolkit/components/extensions/test/xpcshell/test_ext_storage_managed.js:23
[task 2018-08-04T14:40:42.759Z] 14:40:42     INFO -  PID 22702 | JavaScript strict warning: resource://gre/modules/LightweightThemeManager.jsm, line 772: ReferenceError: reference to undefined property "version"
[task 2018-08-04T14:40:42.759Z] 14:40:42     INFO -  (xpcshell/head.js) | test run_next_test 1 finished (2)
[task 2018-08-04T14:40:42.759Z] 14:40:42     INFO -  "CONSOLE_MESSAGE: (info) 1533393642109	addons.xpi	WARN	List of valid built-in add-ons could not be parsed.: [Exception... "Component returned failure code: 0xc1f30001 (NS_ERROR_NOT_INITIALIZED) [nsIXPCComponents_Utils.readUTF8URI]"  nsresult: "0xc1f30001 (NS_ERROR_NOT_INITIALIZED)"  location: "JS frame :: resource://gre/modules/addons/XPIProvider.jsm :: startup :: line 2093"  data: no] Stack trace: startup()@resource://gre/modules/addons/XPIProvider.jsm:2093
[task 2018-08-04T14:40:42.759Z] 14:40:42     INFO -  callProvider()@resource://gre/modules/AddonManager.jsm:206
[task 2018-08-04T14:40:42.759Z] 14:40:42     INFO -  _startProvider()@resource://gre/modules/AddonManager.jsm:654
[task 2018-08-04T14:40:42.759Z] 14:40:42     INFO -  startup()@resource://gre/modules/AddonManager.jsm:813
[task 2018-08-04T14:40:42.759Z] 14:40:42     INFO -  startup()@resource://gre/modules/AddonManager.jsm:2808
[task 2018-08-04T14:40:42.759Z] 14:40:42     INFO -  observe()@jar:file:///builds/worker/workspace/build/application/firefox/omni.ja!/components/addonManager.js:66
[task 2018-08-04T14:40:42.760Z] 14:40:42     INFO -  startAddonManager()@resource://testing-common/ExtensionXPCShellUtils.jsm:733
[task 2018-08-04T14:40:42.760Z] 14:40:42     INFO -  setup()@/builds/worker/workspace/build/tests/xpcshell/tests/toolkit/components/extensions/test/xpcshell/test_ext_storage_managed.js:23"
[task 2018-08-04T14:40:42.760Z] 14:40:42     INFO -  "CONSOLE_MESSAGE: (warn) [JavaScript Warning: "ReferenceError: reference to undefined property "version"" {file: "resource://gre/modules/LightweightThemeManager.jsm" line: 772}]"
[task 2018-08-04T14:40:42.760Z] 14:40:42     INFO -  (xpcshell/head.js) | test run_next_test 2 pending (2)
[task 2018-08-04T14:40:42.760Z] 14:40:42     INFO -  (xpcshell/head.js) | test setup finished (2)
[task 2018-08-04T14:40:42.760Z] 14:40:42     INFO -  xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_ext_storage_managed.js | Starting test_storage_managed
[task 2018-08-04T14:40:42.760Z] 14:40:42     INFO -  (xpcshell/head.js) | test test_storage_managed pending (2)
[task 2018-08-04T14:40:42.760Z] 14:40:42     INFO -  "Extension attached"
[task 2018-08-04T14:40:42.760Z] 14:40:42     INFO -  (xpcshell/head.js) | test run_next_test 2 finished (2)
[task 2018-08-04T14:40:42.760Z] 14:40:42     INFO -  TEST-PASS | xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_ext_storage_managed.js | test_storage_managed - [test_storage_managed : 299] Promise rejected, expecting rejection to match /storage.managed is read-only/, got "storage.managed is read-only": browser.storage.managed.set() rejects because it's read only - true == true
[task 2018-08-04T14:40:42.760Z] 14:40:42     INFO -  TEST-PASS | xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_ext_storage_managed.js | test_storage_managed - [test_storage_managed : 299] Promise rejected, expecting rejection to match /storage.managed is read-only/, got "storage.managed is read-only": browser.storage.managed.remove() rejects because it's read only - true == true
[task 2018-08-04T14:40:42.760Z] 14:40:42     INFO -  TEST-PASS | xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_ext_storage_managed.js | test_storage_managed - [test_storage_managed : 299] Promise rejected, expecting rejection to match /storage.managed is read-only/, got "storage.managed is read-only": browser.storage.managed.clear() rejects because it's read only - true == true
[task 2018-08-04T14:40:42.760Z] 14:40:42     INFO -  TEST-PASS | xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_ext_storage_managed.js | test_storage_managed - [test_storage_managed : 93] [{"null":null,"str":"hello","obj":{"a":[2,3],"b":true}},{"str":"hello"},{"null":null,"obj":{"a":[2,3],"b":true}},{"str":"hello","num":2}] deepEqual [{"null":null,"str":"hello","obj":{"a":[2,3],"b":true}},{"str":"hello"},{"null":null,"obj":{"a":[2,3],"b":true}},{"str":"hello","num":2}]
[task 2018-08-04T14:40:42.760Z] 14:40:42     INFO -  (xpcshell/head.js) | test run_next_test 3 pending (2)
[task 2018-08-04T14:40:42.760Z] 14:40:42     INFO -  (xpcshell/head.js) | test test_storage_managed finished (2)
[task 2018-08-04T14:40:42.760Z] 14:40:42     INFO -  xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_ext_storage_managed.js | Starting test_manifest_not_found
[task 2018-08-04T14:40:42.760Z] 14:40:42     INFO -  (xpcshell/head.js) | test test_manifest_not_found pending (2)
[task 2018-08-04T14:40:42.760Z] 14:40:42     INFO -  "Extension attached"
[task 2018-08-04T14:40:42.765Z] 14:40:42     INFO -  (xpcshell/head.js) | test run_next_test 3 finished (2)
[task 2018-08-04T14:40:42.767Z] 14:40:42     INFO -  TEST-PASS | xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_ext_storage_managed.js | test_manifest_not_found - [test_manifest_not_found : 299] Promise rejected, expecting rejection to match /Managed storage manifest not found/, got "Managed storage manifest not found": browser.storage.managed.get() rejects when without manifest - true == true
[task 2018-08-04T14:40:42.768Z] 14:40:42     INFO -  TEST-PASS | xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_ext_storage_managed.js | test_manifest_not_found - [test_manifest_not_found : 303] nulltrue == true
[task 2018-08-04T14:40:42.770Z] 14:40:42     INFO -  (xpcshell/head.js) | test run_next_test 4 pending (2)
[task 2018-08-04T14:40:42.772Z] 14:40:42     INFO -  (xpcshell/head.js) | test test_manifest_not_found finished (2)
[task 2018-08-04T14:40:42.774Z] 14:40:42     INFO -  (xpcshell/head.js) | test run_next_test 4 finished (1)
[task 2018-08-04T14:40:42.775Z] 14:40:42     INFO -  exiting test
[task 2018-08-04T14:40:42.777Z] 14:40:42     INFO -  "CONSOLE_MESSAGE: (error) [JavaScript Error: "IndexedDB UnknownErr: ActorsParent.cpp:13939"]"
[task 2018-08-04T14:40:42.778Z] 14:40:42     INFO -  PID 22702 | 1533393642624	addons.webextension.{4a7cb8d5-c041-4ed7-a9ed-6b2ef29b5674}	WARN	Loading extension '{4a7cb8d5-c041-4ed7-a9ed-6b2ef29b5674}': storage.local data migration cancelled, unable to open IDB connection: A request was aborted, for example through a call to IDBTransaction.abort.::
[task 2018-08-04T14:40:42.781Z] 14:40:42     INFO -  PID 22702 | 1533393642625	addons.webextension.{4a7cb8d5-c041-4ed7-a9ed-6b2ef29b5674}	WARN	Loading extension '{4a7cb8d5-c041-4ed7-a9ed-6b2ef29b5674}': JSONFile backend is being kept enabled by an unexpected IDBBackend failure: A request was aborted, for example through a call to IDBTransaction.abort.::
[task 2018-08-04T14:40:42.786Z] 14:40:42     INFO -  "CONSOLE_MESSAGE: (info) 1533393642624	addons.webextension.{4a7cb8d5-c041-4ed7-a9ed-6b2ef29b5674}	WARN	Loading extension '{4a7cb8d5-c041-4ed7-a9ed-6b2ef29b5674}': storage.local data migration cancelled, unable to open IDB connection: A request was aborted, for example through a call to IDBTransaction.abort.::"
[task 2018-08-04T14:40:42.789Z] 14:40:42     INFO -  "CONSOLE_MESSAGE: (info) 1533393642625	addons.webextension.{4a7cb8d5-c041-4ed7-a9ed-6b2ef29b5674}	WARN	Loading extension '{4a7cb8d5-c041-4ed7-a9ed-6b2ef29b5674}': JSONFile backend is being kept enabled by an unexpected IDBBackend failure: A request was aborted, for example through a call to IDBTransaction.abort.::"
[task 2018-08-04T14:40:42.794Z] 14:40:42  WARNING -  TEST-UNEXPECTED-FAIL | xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_ext_storage_managed.js | test_manifest_not_found - [test_manifest_not_found : 257] A promise chain failed to handle a rejection: A request was aborted, for example through a call to IDBTransaction.abort. - stack: Transaction/this._completionPromise</transaction.onerror@resource://gre/modules/IndexedDB.jsm:237:9
[task 2018-08-04T14:40:42.796Z] 14:40:42     INFO -  _execute_test@/builds/worker/workspace/build/tests/xpcshell/head.js:618:5
[task 2018-08-04T14:40:42.798Z] 14:40:42     INFO -  @-e:1:1
[task 2018-08-04T14:40:42.803Z] 14:40:42     INFO -  Rejection date: Sat Aug 04 2018 14:40:42 GMT+0000 (UTC) - false == true
[task 2018-08-04T14:40:42.805Z] 14:40:42     INFO -  resource://testing-common/PromiseTestUtils.jsm:assertNoUncaughtRejections:257
[task 2018-08-04T14:40:42.807Z] 14:40:42     INFO -  /builds/worker/workspace/build/tests/xpcshell/head.js:_execute_test:625
[task 2018-08-04T14:40:42.808Z] 14:40:42     INFO -  -e:null:1
[task 2018-08-04T14:40:42.810Z] 14:40:42     INFO -  exiting test
[task 2018-08-04T14:40:42.812Z] 14:40:42     INFO -  PID 22702 | JavaScript error: /builds/worker/workspace/build/tests/xpcshell/head.js, line 746: NS_ERROR_ABORT:
[task 2018-08-04T14:40:42.814Z] 14:40:42     INFO -  <<<<<<<
[task 2018-08-04T14:40:42.815Z] 14:40:42     INFO -  INFO | Result summary:
[task 2018-08-04T14:40:42.817Z] 14:40:42     INFO -  INFO | Passed: 396
[task 2018-08-04T14:40:42.819Z] 14:40:42  WARNING -  INFO | Failed: 1
[task 2018-08-04T14:40:42.820Z] 14:40:42  WARNING -  One or more unittests failed.
[task 2018-08-04T14:40:42.821Z] 14:40:42     INFO -  INFO | Todo: 4
[task 2018-08-04T14:40:42.822Z] 14:40:42     INFO -  INFO | Retried: 2
[task 2018-08-04T14:40:42.822Z] 14:40:42     INFO -  SUITE-END | took 345s
[task 2018-08-04T14:40:42.822Z] 14:40:42     INFO -  Node moz-http2 server shutting down ...
[task 2018-08-04T14:40:42.870Z] 14:40:42    ERROR - Return code: 1

Comment 1

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

This failure is also related to the same underlying reason of Bug 1480948, the test extensions from test_ext_storage_managed.js (as described in Bug 1480948 comment 3 for test_ext_schema.js) have the "storage" permission but they do not await on a promise returned by a storage.local API call, and so the extension may be shutting down while the data migration is ongoing (in this particular case the extension seems to be shutting down while the data migration is opening the IndexedDB connection).   

https://searchfox.org/mozilla-central/rev/e9d2dce0820fa2616174396459498bcb96ecf812/toolkit/components/extensions/test/xpcshell/test_ext_storage_managed.js#105,110,114

Comment 2

[Intermittent Failures Robot]

2 failures in 2561 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-inbound: 1
* mozilla-central: 1

Platform breakdown:
* linux32: 1
* linux64-qr: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1481000&startday=2018-08-05&endday=2018-08-11&tree=all

Comment 3

[Intermittent Failures Robot]

2 failures in 2579 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-central: 1
* mozilla-inbound: 1

Platform breakdown:
* linux64-qr: 1
* linux32: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1481000&startday=2018-08-06&endday=2018-08-12&tree=all

Comment 4

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

As mentioned in Comment 1, this was related to the same underlying issue fixed in Bug 1480948.