1549116 - Intermittent toolkit/mozapps/extensions/test/xpcshell/<random test> | test_after_restart - [test_after_restart : 257] A promise chain failed to handle a rejection: getSignedStatus is not a function

Status: RESOLVED DUPLICATE of bug 1549061

(Toolkit :: Add-ons Manager, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: archaeopteryx [at] coole-files.de
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=244676200&repo=mozilla-release
Full log: https://queue.taskcluster.net/v1/task/EWHoB5n2SQuZWYuKPyKyXw/runs/0/artifacts/public/logs/live_backing.log

---

Started to show up frequently when the fix for bug 1548973 landed.

20:13:21 INFO - "CONSOLE_MESSAGE: (info) 1557000800797 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 2153" data: no] Stack trace: startup()@resource://gre/modules/addons/XPIProvider.jsm:2153
20:13:21 INFO - callProvider()@resource://gre/modules/AddonManager.jsm:203
20:13:21 INFO - _startProvider()@resource://gre/modules/AddonManager.jsm:652
20:13:21 INFO - startup()@resource://gre/modules/AddonManager.jsm:805
20:13:21 INFO - startup()@resource://gre/modules/AddonManager.jsm:2775
20:13:21 INFO - observe()@jar:file:///Users/cltbld/tasks/task_1556999561/build/application/Firefox.app/Contents/Resources/omni.ja!/components/addonManager.js:66
20:13:21 INFO - promiseStartupManager()@resource://testing-common/AddonTestUtils.jsm:796
20:13:21 INFO - promiseRestartManager()@resource://testing-common/AddonTestUtils.jsm:872
20:13:21 INFO - _do_main()@/Users/cltbld/tasks/task_1556999561/build/tests/xpcshell/head.js:224
20:13:21 INFO - _execute_test()@/Users/cltbld/tasks/task_1556999561/build/tests/xpcshell/head.js:528
20:13:21 INFO - -e:1"
20:13:21 INFO - "CONSOLE_MESSAGE: (info) 1557000800799 addons.xpi INFO SystemAddonLocation directory is missing"
20:13:21 INFO - "CONSOLE_MESSAGE: (info) 1557000800800 addons.xpi DEBUG checkForChanges"
20:13:21 INFO - "CONSOLE_MESSAGE: (info) 1557000800800 addons.xpi DEBUG Loaded add-on state: {"app-profile":{"addons":{"[e-mail]":{"dependencies":[],"enabled":true,"lastModifiedTime":1557000800000,"loader":null,"path":"[e-mail]","runInSafeMode":false,"signedState":4,"telemetryKey":"addon1%40tests.mozilla.org:1.0","version":"1.0"},"[e-mail]":{"dependencies":[],"enabled":false,"lastModifiedTime":1557000800000,"loader":null,"path":"[e-mail]","runInSafeMode":false,"signedState":4,"telemetryKey":"addon2%40tests.mozilla.org:1.0","version":"1.0"},"[e-mail]":{"dependencies":[],"enabled":true,"lastModifiedTime":1557000800000,"loader":null,"path":"[e-mail]","runInSafeMode":false,"signedState":4,"telemetryKey":"addon3%40tests.mozilla.org:1.0","version":"1.0"},"[e-mail]":{"dependencies":[],"enabled":false,"lastModifiedTime":1557000800000,"loader":null,"path":"[e-mail]","runInSafeMode":false,"signedState":4,"telemetryKey":"addon4%40tests.mozilla.org:1.0","version":"1.0"},"[e-mail]":{"dependencies":[],"enabled":false,"lastModifiedTime":1557000800000,"loader":null,"path":"[e-mail]","runInSafeMode":false,"signedState":4,"telemetryKey":"addon5%40tests.mozilla.org:1.0","version":"1.0"},"[e-mail]":{"dependencies":[],"enabled":false,"lastModifiedTime":1557000800000,"loader":null,"path":"[e-mail]","runInSafeMode":false,"signedState":4,"telemetryKey":"theme1%40tests.mozilla.org:1.0","version":"1.0","type":"theme"},"[e-mail]":{"dependencies":[],"enabled":true,"lastModifiedTime":1557000800000,"loader":null,"path":"[e-mail]","runInSafeMode":false,"signedState":4,"telemetryKey":"theme2%40tests.mozilla.org:1.0","version":"1.0","type":"theme"}},"staged":{},"path":"/var/folders/t6/5yx7r9hd1633_wp873pqd3n000000x/T/xpc-profile-Mqje3X/extensions"}}"
20:13:21 INFO - "CONSOLE_MESSAGE: (warn) [JavaScript Warning: "ReferenceError: reference to undefined property "currentModifiedTime"" {file: "resource://gre/modules/addons/XPIProvider.jsm" line: 442}]"
20:13:21 INFO - "CONSOLE_MESSAGE: (info) 1557000800802 addons.xpi DEBUG Existing add-on [e-mail] in app-profile"
20:13:21 INFO - "CONSOLE_MESSAGE: (info) 1557000800802 addons.xpi DEBUG Existing add-on [e-mail] in app-profile"
20:13:21 INFO - "CONSOLE_MESSAGE: (info) 1557000800803 addons.xpi DEBUG Existing add-on [e-mail] in app-profile"
20:13:21 INFO - "CONSOLE_MESSAGE: (info) 1557000800803 addons.xpi DEBUG Existing add-on [e-mail] in app-profile"
20:13:21 INFO - "CONSOLE_MESSAGE: (info) 1557000800803 addons.xpi DEBUG Existing add-on [e-mail] in app-profile"
20:13:21 INFO - "CONSOLE_MESSAGE: (info) 1557000800803 addons.xpi DEBUG Existing add-on [e-mail] in app-profile"
20:13:21 INFO - "CONSOLE_MESSAGE: (info) 1557000800803 addons.xpi DEBUG Existing add-on [e-mail] in app-profile"
20:13:21 INFO - "CONSOLE_MESSAGE: (info) 1557000800804 addons.xpi DEBUG scanForChanges changed: false, state: {}"
20:13:21 INFO - "CONSOLE_MESSAGE: (info) 1557000800804 addons.xpi DEBUG No changes found"
20:13:21 INFO - "CONSOLE_MESSAGE: (info) 1557000800805 addons.xpi DEBUG Loading bootstrap scope from /var/folders/t6/5yx7r9hd1633_wp873pqd3n000000x/T/xpc-profile-Mqje3X/extensions/[e-mail]"
20:13:21 INFO - "CONSOLE_MESSAGE: (info) 1557000800805 addons.xpi DEBUG Calling bootstrap method startup on [e-mail] version 1.0"
20:13:21 INFO - "CONSOLE_MESSAGE: (info) 1557000800806 addons.xpi DEBUG Loading bootstrap scope from /var/folders/t6/5yx7r9hd1633_wp873pqd3n000000x/T/xpc-profile-Mqje3X/extensions/[e-mail]"
20:13:21 INFO - "CONSOLE_MESSAGE: (info) 1557000800806 addons.xpi DEBUG Calling bootstrap method startup on [e-mail] version 1.0"
20:13:21 INFO - "CONSOLE_MESSAGE: (info) 1557000800806 addons.xpi DEBUG Loading bootstrap scope from /var/folders/t6/5yx7r9hd1633_wp873pqd3n000000x/T/xpc-profile-Mqje3X/extensions/[e-mail]"
20:13:21 INFO - "CONSOLE_MESSAGE: (info) 1557000800806 addons.xpi DEBUG Calling bootstrap method startup on [e-mail] version 1.0"
20:13:21 INFO - "CONSOLE_MESSAGE: (info) 1557000800807 addons.xpi DEBUG hotfix for addon signing cert has not been applied; applying"
20:13:21 INFO - "CONSOLE_MESSAGE: (info) 1557000800808 addons.xpi DEBUG new intermediate certificate added"
20:13:21 INFO - "CONSOLE_MESSAGE: (info) 1557000800814 addons.xpi-utils DEBUG Starting async load of XPI database /var/folders/t6/5yx7r9hd1633_wp873pqd3n000000x/T/xpc-profile-Mqje3X/extensions.json"
20:13:21 INFO - "CONSOLE_MESSAGE: (info) 1557000800815 addons.manager DEBUG Registering shutdown blocker for XPIProvider"
20:13:21 INFO - "CONSOLE_MESSAGE: (info) 1557000800815 addons.manager DEBUG Provider finished startup: XPIProvider"
20:13:21 INFO - "CONSOLE_MESSAGE: (info) 1557000800817 addons.manager DEBUG Completed startup sequence"
20:13:21 INFO - PID 7279 | 1557000800832 addons.xpi-utils DEBUG Finished async read of XPI database, parsing...
20:13:21 INFO - "CONSOLE_MESSAGE: (info) 1557000800832 addons.xpi-utils DEBUG Finished async read of XPI database, parsing..."
20:13:21 INFO - "Test add-on state after restart"
20:13:21 INFO - PID 7279 | JavaScript error: resource://gre/modules/addons/XPIInstall.jsm, line 330: TypeError: getSignedStatus is not a function
20:13:21 INFO - "CONSOLE_MESSAGE: (error) [JavaScript Error: "TypeError: getSignedStatus is not a function" {file: "resource://gre/modules/addons/XPIInstall.jsm" line: 330}]"
20:13:21 INFO - PID 7279 | 1557000800842 addons.xpi-utils DEBUG Successfully read XPI database
20:13:21 INFO - "Checking state of addon [e-mail]"
20:13:21 INFO - TEST-PASS | xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_badschema.js | test_after_restart - [test_after_restart : 203] Addon [e-mail] should exist - {} == true
20:13:21 INFO - TEST-PASS | xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_badschema.js | test_after_restart - [test_after_restart : 203] Expected value of addon.isActive - true deepEqual true
20:13:21 INFO - TEST-PASS | xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_badschema.js | test_after_restart - [test_after_restart : 203] Expected value of addon.userDisabled - false deepEqual false
20:13:21 INFO - TEST-PASS | xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_badschema.js | test_after_restart - [test_after_restart : 203] Expected value of addon.appDisabled - false deepEqual false
20:13:21 INFO - TEST-PASS | xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_badschema.js | test_after_restart - [test_after_restart : 203] Expected value of addon.pendingOperations - 0 deepEqual 0
20:13:21 INFO - "Checking state of addon [e-mail]"
20:13:21 INFO - TEST-PASS | xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_badschema.js | test_after_restart - [test_after_restart : 203] Addon [e-mail] should exist - {} == true
20:13:21 INFO - TEST-PASS | xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_badschema.js | test_after_restart - [test_after_restart : 203] Expected value of addon.isActive - false deepEqual false
20:13:21 INFO - TEST-PASS | xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_badschema.js | test_after_restart - [test_after_restart : 203] Expected value of addon.userDisabled - true deepEqual true
20:13:21 INFO - TEST-PASS | xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_badschema.js | test_after_restart - [test_after_restart : 203] Expected value of addon.appDisabled - false deepEqual false
20:13:21 INFO - TEST-PASS | xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_badschema.js | test_after_restart - [test_after_restart : 203] Expected value of addon.pendingOperations - 0 deepEqual 0
20:13:21 INFO - "Checking state of addon [e-mail]"
20:13:21 INFO - TEST-PASS | xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_badschema.js | test_after_restart - [test_after_restart : 203] Addon [e-mail] should exist - {} == true
20:13:21 INFO - TEST-PASS | xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_badschema.js | test_after_restart - [test_after_restart : 203] Expected value of addon.isActive - true deepEqual true
20:13:21 INFO - TEST-PASS | xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_badschema.js | test_after_restart - [test_after_restart : 203] Expected value of addon.userDisabled - false deepEqual false
20:13:21 INFO - TEST-PASS | xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_badschema.js | test_after_restart - [test_after_restart : 203] Expected value of addon.appDisabled - false deepEqual false
20:13:21 INFO - TEST-PASS | xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_badschema.js | test_after_restart - [test_after_restart : 203] Expected value of addon.pendingOperations - 0 deepEqual 0
20:13:21 INFO - "Checking state of addon [e-mail]"
20:13:21 INFO - TEST-PASS | xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_badschema.js | test_after_restart - [test_after_restart : 203] Addon [e-mail] should exist - {} == true
20:13:21 INFO - TEST-PASS | xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_badschema.js | test_after_restart - [test_after_restart : 203] Expected value of addon.isActive - false deepEqual false
20:13:21 INFO - TEST-PASS | xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_badschema.js | test_after_restart - [test_after_restart : 203] Expected value of addon.userDisabled - true deepEqual true
20:13:21 INFO - TEST-PASS | xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_badschema.js | test_after_restart - [test_after_restart : 203] Expected value of addon.appDisabled - false deepEqual false
20:13:21 INFO - TEST-PASS | xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_badschema.js | test_after_restart - [test_after_restart : 203] Expected value of addon.pendingOperations - 0 deepEqual 0
20:13:21 INFO - "Checking state of addon [e-mail]"
20:13:21 INFO - TEST-PASS | xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_badschema.js | test_after_restart - [test_after_restart : 203] Addon [e-mail] should exist - {} == true
20:13:21 INFO - TEST-PASS | xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_badschema.js | test_after_restart - [test_after_restart : 203] Expected value of addon.isActive - false deepEqual false
20:13:21 INFO - TEST-PASS | xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_badschema.js | test_after_restart - [test_after_restart : 203] Expected value of addon.userDisabled - false deepEqual false
20:13:21 INFO - TEST-PASS | xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_badschema.js | test_after_restart - [test_after_restart : 203] Expected value of addon.appDisabled - true deepEqual true
20:13:21 INFO - TEST-PASS | xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_badschema.js | test_after_restart - [test_after_restart : 203] Expected value of addon.pendingOperations - 0 deepEqual 0
20:13:21 INFO - "Checking state of addon [e-mail]"
20:13:21 INFO - TEST-PASS | xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_badschema.js | test_after_restart - [test_after_restart : 203] Addon [e-mail] should exist - {} == true
20:13:21 INFO - TEST-PASS | xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_badschema.js | test_after_restart - [test_after_restart : 203] Expected value of addon.isActive - false deepEqual false
20:13:21 INFO - TEST-PASS | xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_badschema.js | test_after_restart - [test_after_restart : 203] Expected value of addon.userDisabled - true deepEqual true
20:13:21 INFO - TEST-PASS | xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_badschema.js | test_after_restart - [test_after_restart : 203] Expected value of addon.appDisabled - false deepEqual false
20:13:21 INFO - TEST-PASS | xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_badschema.js | test_after_restart - [test_after_restart : 203] Expected value of addon.pendingOperations - 0 deepEqual 0
20:13:21 INFO - "Checking state of addon [e-mail]"
20:13:21 INFO - TEST-PASS | xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_badschema.js | test_after_restart - [test_after_restart : 203] Addon [e-mail] should exist - {} == true
20:13:21 INFO - TEST-PASS | xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_badschema.js | test_after_restart - [test_after_restart : 203] Expected value of addon.isActive - true deepEqual true
20:13:21 INFO - TEST-PASS | xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_badschema.js | test_after_restart - [test_after_restart : 203] Expected value of addon.userDisabled - false deepEqual false
20:13:21 INFO - TEST-PASS | xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_badschema.js | test_after_restart - [test_after_restart : 203] Expected value of addon.appDisabled - false deepEqual false
20:13:21 INFO - TEST-PASS | xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_badschema.js | test_after_restart - [test_after_restart : 203] Expected value of addon.pendingOperations - 0 deepEqual 0
20:13:21 INFO - PID 7279 | 1557000800863 addons.xpi DEBUG Calling bootstrap method shutdown on [e-mail] version 1.0
20:13:21 INFO - PID 7279 | 1557000800864 addons.xpi DEBUG Calling bootstrap method shutdown on [e-mail] version 1.0
20:13:21 INFO - PID 7279 | 1557000800865 addons.xpi DEBUG Calling bootstrap method shutdown on [e-mail] version 1.0
20:13:21 INFO - PID 7279 | 1557000800865 addons.manager DEBUG shutdown
20:13:21 INFO - PID 7279 | 1557000800867 addons.manager DEBUG Calling shutdown blocker for LightweightThemeManager
20:13:21 INFO - PID 7279 | 1557000800867 addons.manager DEBUG Calling shutdown blocker for GMPProvider
20:13:21 INFO - PID 7279 | 1557000800868 addons.manager DEBUG Calling shutdown blocker for PluginProvider
20:13:21 INFO - PID 7279 | 1557000800868 addons.manager DEBUG Calling shutdown blocker for XPIProvider
20:13:21 INFO - PID 7279 | 1557000800868 addons.xpi DEBUG shutdown
20:13:21 INFO - PID 7279 | 1557000800868 addons.xpi-utils DEBUG shutdown
20:13:21 INFO - "CONSOLE_MESSAGE: (info) 1557000800842 addons.xpi-utils DEBUG Successfully read XPI database"
20:13:21 INFO - "CONSOLE_MESSAGE: (info) 1557000800863 addons.xpi DEBUG Calling bootstrap method shutdown on [e-mail] version 1.0"
20:13:21 INFO - "CONSOLE_MESSAGE: (info) 1557000800864 addons.xpi DEBUG Calling bootstrap method shutdown on [e-mail] version 1.0"
20:13:21 INFO - "CONSOLE_MESSAGE: (info) 1557000800865 addons.xpi DEBUG Calling bootstrap method shutdown on [e-mail] version 1.0"
20:13:21 INFO - "CONSOLE_MESSAGE: (info) 1557000800865 addons.manager DEBUG shutdown"
20:13:21 INFO - "CONSOLE_MESSAGE: (info) 1557000800867 addons.manager DEBUG Calling shutdown blocker for LightweightThemeManager"
20:13:21 INFO - "CONSOLE_MESSAGE: (info) 1557000800867 addons.manager DEBUG Calling shutdown blocker for GMPProvider"
20:13:21 INFO - "CONSOLE_MESSAGE: (info) 1557000800868 addons.manager DEBUG Calling shutdown blocker for PluginProvider"
20:13:21 INFO - "CONSOLE_MESSAGE: (info) 1557000800868 addons.manager DEBUG Calling shutdown blocker for XPIProvider"
20:13:21 INFO - "CONSOLE_MESSAGE: (info) 1557000800868 addons.xpi DEBUG shutdown"
20:13:21 INFO - "CONSOLE_MESSAGE: (info) 1557000800868 addons.xpi-utils DEBUG shutdown"
20:13:21 INFO - PID 7279 | 1557000800872 addons.manager DEBUG Async provider shutdown done
20:13:21 INFO - (xpcshell/head.js) | test run_next_test 2 pending (2)
20:13:21 INFO - (xpcshell/head.js) | test test_after_restart finished (2)
20:13:21 INFO - "CONSOLE_MESSAGE: (info) 1557000800872 addons.manager DEBUG Async provider shutdown done"
20:13:21 WARNING - TEST-UNEXPECTED-FAIL | xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_badschema.js | test_after_restart - [test_after_restart : 257] A promise chain failed to handle a rejection: getSignedStatus is not a function - stack: openSignedAppFileFinished@resource://gre/modules/addons/XPIInstall.jsm:330:26
20:13:21 INFO - overrideCertDB/openSignedAppFileAsync/</<@resource://testing-common/AddonTestUtils.jsm:724:15
20:13:21 INFO - _do_main@/Users/cltbld/tasks/task_1556999561/build/tests/xpcshell/head.js:224:3
20:13:21 INFO - _execute_test@/Users/cltbld/tasks/task_1556999561/build/tests/xpcshell/head.js:528:5
20:13:21 INFO - @-e:1:1
20:13:21 INFO - Rejection date: Sat May 04 2019 20:13:20 GMT+0000 (Greenwich Mean Time) - false == true
20:13:21 INFO - resource://testing-common/PromiseTestUtils.jsm:assertNoUncaughtRejections:257
20:13:21 INFO - /Users/cltbld/tasks/task_1556999561/build/tests/xpcshell/head.js:_run_next_test:1407
20:13:21 INFO - /Users/cltbld/tasks/task_1556999561/build/tests/xpcshell/head.js:run:687
20:13:21 INFO - /Users/cltbld/tasks/task_1556999561/build/tests/xpcshell/head.js:_do_main:224
20:13:21 INFO - /Users/cltbld/tasks/task_1556999561/build/tests/xpcshell/head.js:_execute_test:528
20:13:21 INFO - -e:null:1
20:13:21 INFO - exiting test

Comment 2

[Intermittent Failures Robot]

10 failures in 4131 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-release: 10

Platform breakdown:

• linux64-qr: 2
• windows7-32: 4
• macosx64-nightly: 4

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1549116&startday=2019-04-29&endday=2019-05-05&tree=all

Comment 3

[Intermittent Failures Robot]

10 failures in 4658 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-release: 10

Platform breakdown:

• macosx64-nightly: 1
• windows7-32-nightly: 1
• windows10-64-nightly: 6
• linux64-nightly: 1
• linux32-nightly: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1549116&startday=2019-05-13&endday=2019-05-19&tree=all