1559108 - Perma security/manager/ssl/tests/unit/test_blocklist_onecrl.js | xpcshell return code: 1 when Gecko 69 merges to Beta on 19-07-01

Reporter

Description

•

6 years ago

[Tracking Requested - why for this release]:

Central-as-beta simulation: https://treeherder.mozilla.org/#/jobs?repo=try&resultStatus=testfailed%2Cbusted%2Cexception%2Cretry%2Cusercancel%2Crunnable&revision=6328411593db4f6b02950206fe5bcc655cc6a2f3&selectedJob=251400217

Failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=251400217&repo=try&lineNumber=5338

14:28:18 INFO - TEST-START | security/manager/ssl/tests/unit/test_blocklist_onecrl.js
14:28:19 WARNING - TEST-UNEXPECTED-FAIL | security/manager/ssl/tests/unit/test_blocklist_onecrl.js | xpcshell return code: 1
14:28:19 INFO - TEST-INFO took 756ms
14:28:19 INFO - >>>>>>>
14:28:19 INFO - PID 13656 | [13656, Main Thread] WARNING: Failed to get directory to cache.: file z:/build/build/src/security/sandbox/win/src/sandboxbroker/sandboxBroker.cpp, line 82
14:28:19 INFO - PID 13656 | [13656, Main Thread] WARNING: Failed to get directory to cache.: file z:/build/build/src/security/sandbox/win/src/sandboxbroker/sandboxBroker.cpp, line 82
14:28:19 INFO - PID 13656 | [13656, Main Thread] WARNING: Failed to get directory to cache.: file z:/build/build/src/security/sandbox/win/src/sandboxbroker/sandboxBroker.cpp, line 82
14:28:19 INFO - PID 13656 | [13656, Main Thread] WARNING: Failed to get directory to cache.: file z:/build/build/src/security/sandbox/win/src/sandboxbroker/sandboxBroker.cpp, line 82
14:28:19 INFO - PID 13656 | [13656, Main Thread] WARNING: Failed to get directory to cache.: file z:/build/build/src/security/sandbox/win/src/sandboxbroker/sandboxBroker.cpp, line 82
14:28:19 INFO - PID 13656 | [13656, Main Thread] WARNING: Couldn't get the user appdata directory. Crash events may not be produced.: file z:/build/build/src/toolkit/crashreporter/nsExceptionHandler.cpp, line 2514
14:28:19 INFO - (xpcshell/head.js) | test MAIN run_test pending (1)
14:28:19 INFO - PID 13656 | [13656, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, kKnownEsrVersion) failed with result 0x80004002: file z:/build/build/src/toolkit/components/resistfingerprinting/nsRFPService.cpp, line 662
14:28:19 INFO - PID 13656 | [13656, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80520012: file z:/build/build/src/extensions/permissions/nsPermissionManager.cpp, line 2903
14:28:19 INFO - PID 13656 | 1560349698604 addons.manager DEBUG Application has been upgraded
14:28:19 INFO - PID 13656 | 1560349698605 addons.manager DEBUG Loaded provider scope for resource://gre/modules/addons/XPIProvider.jsm: ["XPIProvider", "XPIInternal"]
14:28:19 INFO - PID 13656 | 1560349698614 addons.manager DEBUG Loaded provider scope for resource://gre/modules/addons/GMPProvider.jsm
14:28:19 INFO - PID 13656 | 1560349698619 addons.manager DEBUG Loaded provider scope for resource://gre/modules/addons/PluginProvider.jsm
14:28:19 INFO - PID 13656 | 1560349698619 addons.manager DEBUG Starting provider: XPIProvider
14:28:19 INFO - PID 13656 | 1560349698620 addons.xpi DEBUG startup
14:28:19 INFO - PID 13656 | 1560349698621 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 2243" data: no] Stack trace: startup()@resource://gre/modules/addons/XPIProvider.jsm:2243
14:28:19 INFO - PID 13656 | callProvider()@resource://gre/modules/AddonManager.jsm:193
14:28:19 INFO - PID 13656 | _startProvider()@resource://gre/modules/AddonManager.jsm:569
14:28:19 INFO - PID 13656 | startup()@resource://gre/modules/AddonManager.jsm:725
14:28:19 INFO - PID 13656 | startup()@resource://gre/modules/AddonManager.jsm:2797
14:28:19 INFO - PID 13656 | observe()@resource://gre/modules/addonManager.js:71
14:28:19 INFO - PID 13656 | promiseStartupManager()@resource://testing-common/AddonTestUtils.jsm:822
14:28:19 INFO - PID 13656 | run_test()@Z:/task_1560346424/build/tests/xpcshell/tests/security/manager/ssl/tests/unit/test_blocklist_onecrl.js:15
14:28:19 INFO - PID 13656 | _execute_test()@Z:\task_1560346424\build\tests\xpcshell\head.js:523
14:28:19 INFO - PID 13656 | -e:1
14:28:19 INFO - PID 13656 | 1560349698626 addons.xpi INFO SystemAddonLocation directory is missing
14:28:19 INFO - PID 13656 | 1560349698647 addons.xpi INFO Removing all system add-on upgrades.
14:28:19 INFO - PID 13656 | 1560349698649 addons.xpi DEBUG checkForChanges
14:28:19 INFO - PID 13656 | 1560349698650 addons.xpi DEBUG Loaded add-on state: ${}
14:28:19 INFO - PID 13656 | 1560349698651 addons.xpi DEBUG scanForChanges changed: false, state: {}
14:28:19 INFO - PID 13656 | 1560349698652 addons.xpi DEBUG Empty XPI database, setting schema version preference to 31
14:28:19 INFO - PID 13656 | 1560349698653 addons.xpi DEBUG No changes found
14:28:19 INFO - PID 13656 | 1560349698674 addons.xpi-utils DEBUG Error: Synchronously loading the add-ons database(resource://gre/modules/addons/XPIDatabase.jsm:1360:15) JS Stack trace: syncLoadDB@XPIDatabase.jsm:1360:15
14:28:19 INFO - PID 13656 | startup@XPIProvider.jsm:2289:23
14:28:19 INFO - PID 13656 | callProvider@AddonManager.jsm:193:31
14:28:19 INFO - PID 13656 | _startProvider@AddonManager.jsm:569:5
14:28:19 INFO - PID 13656 | startup@AddonManager.jsm:725:14
14:28:19 INFO - PID 13656 | startup@AddonManager.jsm:2797:26
14:28:19 INFO - PID 13656 | observe@addonManager.js:71:29
14:28:19 INFO - PID 13656 | promiseStartupManager@AddonTestUtils.jsm:822:34
14:28:19 INFO - PID 13656 | run_test@test_blocklist_onecrl.js:15:18
14:28:19 INFO - PID 13656 | _execute_test@Z:\task_1560346424\build\tests\xpcshell\head.js:523:7
14:28:19 INFO - PID 13656 | @-e:1:1
14:28:19 INFO - PID 13656 | 1560349698675 addons.xpi-utils DEBUG Starting async load of XPI database c:\users\task_1560346424\appdata\local\temp\xpc-profile-v96mg2\extensions.json
14:28:19 INFO - "CONSOLE_MESSAGE: (info) 1560349698604 addons.manager DEBUG Application has been upgraded"
14:28:19 INFO - "CONSOLE_MESSAGE: (info) 1560349698605 addons.manager DEBUG Loaded provider scope for resource://gre/modules/addons/XPIProvider.jsm: ["XPIProvider", "XPIInternal"]"
14:28:19 INFO - "CONSOLE_MESSAGE: (info) 1560349698614 addons.manager DEBUG Loaded provider scope for resource://gre/modules/addons/GMPProvider.jsm"
14:28:19 INFO - "CONSOLE_MESSAGE: (info) 1560349698619 addons.manager DEBUG Loaded provider scope for resource://gre/modules/addons/PluginProvider.jsm"
14:28:19 INFO - "CONSOLE_MESSAGE: (info) 1560349698619 addons.manager DEBUG Starting provider: XPIProvider"
14:28:19 INFO - "CONSOLE_MESSAGE: (info) 1560349698620 addons.xpi DEBUG startup"
14:28:19 INFO - "CONSOLE_MESSAGE: (info) 1560349698621 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 2243" data: no] Stack trace: startup()@resource://gre/modules/addons/XPIProvider.jsm:2243
14:28:19 INFO - callProvider()@resource://gre/modules/AddonManager.jsm:193
14:28:19 INFO - _startProvider()@resource://gre/modules/AddonManager.jsm:569
14:28:19 INFO - startup()@resource://gre/modules/AddonManager.jsm:725
14:28:19 INFO - startup()@resource://gre/modules/AddonManager.jsm:2797
14:28:19 INFO - observe()@resource://gre/modules/addonManager.js:71
14:28:19 INFO - promiseStartupManager()@resource://testing-common/AddonTestUtils.jsm:822
14:28:19 INFO - run_test()@Z:/task_1560346424/build/tests/xpcshell/tests/security/manager/ssl/tests/unit/test_blocklist_onecrl.js:15
14:28:19 INFO - _execute_test()@Z:\task_1560346424\build\tests\xpcshell\head.js:523
14:28:19 INFO - -e:1"
14:28:19 INFO - "CONSOLE_MESSAGE: (info) 1560349698626 addons.xpi INFO SystemAddonLocation directory is missing"
14:28:19 INFO - "CONSOLE_MESSAGE: (info) 1560349698647 addons.xpi INFO Removing all system add-on upgrades."
14:28:19 INFO - "CONSOLE_MESSAGE: (info) 1560349698649 addons.xpi DEBUG checkForChanges"
14:28:19 INFO - "CONSOLE_MESSAGE: (info) 1560349698650 addons.xpi DEBUG Loaded add-on state: ${}"
14:28:19 INFO - "CONSOLE_MESSAGE: (info) 1560349698651 addons.xpi DEBUG scanForChanges changed: false, state: {}"
14:28:19 INFO - "CONSOLE_MESSAGE: (info) 1560349698652 addons.xpi DEBUG Empty XPI database, setting schema version preference to 31"
14:28:19 INFO - "CONSOLE_MESSAGE: (info) 1560349698653 addons.xpi DEBUG No changes found"
14:28:19 INFO - "CONSOLE_MESSAGE: (info) 1560349698674 addons.xpi-utils DEBUG Error: Synchronously loading the add-ons database(resource://gre/modules/addons/XPIDatabase.jsm:1360:15) JS Stack trace: syncLoadDB@XPIDatabase.jsm:1360:15
14:28:19 INFO - startup@XPIProvider.jsm:2289:23
14:28:19 INFO - callProvider@AddonManager.jsm:193:31
14:28:19 INFO - _startProvider@AddonManager.jsm:569:5
14:28:19 INFO - startup@AddonManager.jsm:725:14
14:28:19 INFO - startup@AddonManager.jsm:2797:26
14:28:19 INFO - observe@addonManager.js:71:29
14:28:19 INFO - promiseStartupManager@AddonTestUtils.jsm:822:34
14:28:19 INFO - run_test@test_blocklist_onecrl.js:15:18
14:28:19 INFO - _execute_test@Z:\task_1560346424\build\tests\xpcshell\head.js:523:7
14:28:19 INFO - @-e:1:1"
14:28:19 INFO - "CONSOLE_MESSAGE: (info) 1560349698675 addons.xpi-utils DEBUG Starting async load of XPI database c:\users\task_1560346424\appdata\local\temp\xpc-profile-v96mg2\extensions.json"
14:28:19 INFO - PID 13656 | 1560349698746 addons.xpi-utils DEBUG Rebuilding XPI database with no extensions
14:28:19 INFO - PID 13656 | 1560349698751 addons.manager DEBUG Registering shutdown blocker for XPIProvider
14:28:19 INFO - PID 13656 | 1560349698751 addons.manager DEBUG Provider finished startup: XPIProvider
14:28:19 INFO - PID 13656 | 1560349698751 addons.manager DEBUG Starting provider: GMPProvider
14:28:19 INFO - PID 13656 | [13656, GMPThread] WARNING: Failed to delete GMP storage directory: file z:/build/build/src/dom/media/gmp/GMPServiceParent.cpp, line 1571
14:28:19 INFO - PID 13656 | 1560349698756 addons.manager DEBUG Registering shutdown blocker for GMPProvider
14:28:19 INFO - PID 13656 | 1560349698756 addons.manager DEBUG Provider finished startup: GMPProvider
14:28:19 INFO - PID 13656 | 1560349698756 addons.manager DEBUG Starting provider: PluginProvider
14:28:19 INFO - PID 13656 | 1560349698757 addons.manager DEBUG Registering shutdown blocker for PluginProvider
14:28:19 INFO - PID 13656 | 1560349698757 addons.manager DEBUG Provider finished startup: PluginProvider
14:28:19 INFO - PID 13656 | 1560349698763 addons.manager DEBUG Completed startup sequence
14:28:19 INFO - (xpcshell/head.js) | test MAIN run_test finished (1)
14:28:19 INFO - exiting test
14:28:19 INFO - "CONSOLE_MESSAGE: (info) 1560349698746 addons.xpi-utils DEBUG Rebuilding XPI database with no extensions"
14:28:19 INFO - PID 13656 | 1560349698777 addons.manager DEBUG before shutdown
14:28:19 INFO - PID 13656 | 1560349698778 addons.manager DEBUG shutdown
14:28:19 INFO - PID 13656 | 1560349698779 addons.manager DEBUG Calling shutdown blocker for XPIProvider
14:28:19 INFO - PID 13656 | 1560349698779 addons.xpi DEBUG shutdown
14:28:19 INFO - PID 13656 | 1560349698779 addons.xpi-utils DEBUG shutdown
14:28:19 INFO - PID 13656 | 1560349698779 addons.manager DEBUG Calling shutdown blocker for GMPProvider
14:28:19 INFO - PID 13656 | 1560349698780 addons.manager DEBUG Calling shutdown blocker for PluginProvider
14:28:19 INFO - "CONSOLE_MESSAGE: (info) 1560349698751 addons.manager DEBUG Registering shutdown blocker for XPIProvider"
14:28:19 INFO - "CONSOLE_MESSAGE: (info) 1560349698751 addons.manager DEBUG Provider finished startup: XPIProvider"
14:28:19 INFO - "CONSOLE_MESSAGE: (info) 1560349698751 addons.manager DEBUG Starting provider: GMPProvider"
14:28:19 INFO - "CONSOLE_MESSAGE: (info) 1560349698756 addons.manager DEBUG Registering shutdown blocker for GMPProvider"
14:28:19 INFO - "CONSOLE_MESSAGE: (info) 1560349698756 addons.manager DEBUG Provider finished startup: GMPProvider"
14:28:19 INFO - "CONSOLE_MESSAGE: (info) 1560349698756 addons.manager DEBUG Starting provider: PluginProvider"
14:28:19 INFO - "CONSOLE_MESSAGE: (info) 1560349698757 addons.manager DEBUG Registering shutdown blocker for PluginProvider"
14:28:19 INFO - "CONSOLE_MESSAGE: (info) 1560349698757 addons.manager DEBUG Provider finished startup: PluginProvider"
14:28:19 INFO - "CONSOLE_MESSAGE: (info) 1560349698763 addons.manager DEBUG Completed startup sequence"
14:28:19 INFO - "CONSOLE_MESSAGE: (info) 1560349698777 addons.manager DEBUG before shutdown"
14:28:19 INFO - "CONSOLE_MESSAGE: (info) 1560349698778 addons.manager DEBUG shutdown"
14:28:19 INFO - (xpcshell/head.js) | test run_next_test 0 pending (1)
14:28:19 INFO - "CONSOLE_MESSAGE: (info) 1560349698779 addons.manager DEBUG Calling shutdown blocker for XPIProvider"
14:28:19 INFO - "CONSOLE_MESSAGE: (info) 1560349698779 addons.xpi DEBUG shutdown"
14:28:19 INFO - "CONSOLE_MESSAGE: (info) 1560349698779 addons.xpi-utils DEBUG shutdown"
14:28:19 INFO - "CONSOLE_MESSAGE: (info) 1560349698779 addons.manager DEBUG Calling shutdown blocker for GMPProvider"
14:28:19 INFO - "CONSOLE_MESSAGE: (info) 1560349698780 addons.manager DEBUG Calling shutdown blocker for PluginProvider"
14:28:19 INFO - security/manager/ssl/tests/unit/test_blocklist_onecrl.js | Starting test_uses_a_custom_signer
14:28:19 INFO - (xpcshell/head.js) | test test_uses_a_custom_signer pending (2)
14:28:19 INFO - TEST-PASS | security/manager/ssl/tests/unit/test_blocklist_onecrl.js | test_uses_a_custom_signer - [test_uses_a_custom_signer : 19] "onecrl.content-signature.mozilla.org" != "remote-settings.content-signature.mozilla.org"
14:28:19 INFO - (xpcshell/head.js) | test run_next_test 0 finished (2)
14:28:19 INFO - (xpcshell/head.js) | test run_next_test 1 pending (2)
14:28:19 INFO - (xpcshell/head.js) | test test_uses_a_custom_signer finished (2)
14:28:19 INFO - PID 13656 | 1560349698798 addons.manager DEBUG Async provider shutdown done
14:28:19 INFO - security/manager/ssl/tests/unit/test_blocklist_onecrl.js | Starting test_has_initial_dump
14:28:19 INFO - (xpcshell/head.js) | test test_has_initial_dump pending (2)
14:28:19 INFO - (xpcshell/head.js) | test run_next_test 1 finished (2)
14:28:19 INFO - "CONSOLE_MESSAGE: (info) 1560349698798 addons.manager DEBUG Async provider shutdown done"
14:28:19 INFO - TEST-PASS | security/manager/ssl/tests/unit/test_blocklist_onecrl.js | test_has_initial_dump - [test_has_initial_dump : 23] true == true
14:28:19 INFO - (xpcshell/head.js) | test run_next_test 2 pending (2)
14:28:19 INFO - (xpcshell/head.js) | test test_has_initial_dump finished (2)
14:28:19 INFO - security/manager/ssl/tests/unit/test_blocklist_onecrl.js | Starting test_default_jexl_filter_is_used
14:28:19 INFO - (xpcshell/head.js) | test test_default_jexl_filter_is_used pending (2)
14:28:19 INFO - TEST-PASS | security/manager/ssl/tests/unit/test_blocklist_onecrl.js | test_default_jexl_filter_is_used - [test_default_jexl_filter_is_used : 27] "async function jexlFilterFunc(entry, environment) {\n const { filter_expression } = entry;\n if (!filter_expression) {\n return entry;\n }\n let result;\n try {\n const context = {\n env: environment,\n };\n result = await FilterExpressions.eval(filter_expression, context);\n } catch (e) {\n Cu.reportError(e);\n }\n return result ? entry : null;\n}" deepEqual "async function jexlFilterFunc(entry, environment) {\n const { filter_expression } = entry;\n if (!filter_expression) {\n return entry;\n }\n let result;\n try {\n const context = {\n env: environment,\n };\n result = await FilterExpressions.eval(filter_expression, context);\n } catch (e) {\n Cu.reportError(e);\n }\n return result ? entry : null;\n}"
14:28:19 INFO - (xpcshell/head.js) | test run_next_test 2 finished (2)
14:28:19 INFO - (xpcshell/head.js) | test run_next_test 3 pending (2)
14:28:19 INFO - (xpcshell/head.js) | test test_default_jexl_filter_is_used finished (2)
14:28:19 INFO - security/manager/ssl/tests/unit/test_blocklist_onecrl.js | Starting test_revocations_are_updated_on_sync_with_cert_storage
14:28:19 INFO - (xpcshell/head.js) | test test_revocations_are_updated_on_sync_with_cert_storage pending (2)
14:28:19 INFO - TEST-SKIP | security/manager/ssl/tests/unit/test_blocklist_onecrl.js | test_revocations_are_updated_on_sync_with_cert_storage - test_revocations_are_updated_on_sync_with_cert_storage skipped because the following conditions were met: (!AppConstants.MOZ_NEW_CERT_STORAGE)
14:28:19 INFO - (xpcshell/head.js) | test run_next_test pending (3)
14:28:19 INFO - (xpcshell/head.js) | test run_next_test 3 finished (3)
14:28:19 INFO - (xpcshell/head.js) | test run_next_test 4 pending (3)
14:28:19 INFO - (xpcshell/head.js) | test test_revocations_are_updated_on_sync_with_cert_storage finished (3)
14:28:19 INFO - (xpcshell/head.js) | test run_next_test finished (2)
14:28:19 INFO - security/manager/ssl/tests/unit/test_blocklist_onecrl.js | Starting test_revocations_are_updated_on_sync
14:28:19 INFO - (xpcshell/head.js) | test test_revocations_are_updated_on_sync pending (2)
14:28:19 INFO - PID 13656 | Attempt to add a bool pref cache for preference 'browser.cache.disk.enable' at address '00007FFFDD251C8C'was made. However, a pref was already cached at this address.
14:28:19 INFO - PID 13656 | Assertion failure: false (Should not have an existing pref cache for this address), at z:/build/build/src/modules/libpref/Preferences.cpp:3165
14:28:36 INFO - PID 13656 | #01: mozilla::net::CacheObserver::AttachToPreferences() [netwerk/cache2/CacheObserver.cpp:151]
14:28:36 INFO - PID 13656 | #02: mozilla::net::CacheObserver::Observe(nsISupports *,char const *,char16_t const *) [netwerk/cache2/CacheObserver.cpp:489]
14:28:36 INFO - PID 13656 | #03: nsObserverList::NotifyObservers(nsISupports *,char const *,char16_t const *) [xpcom/ds/nsObserverList.cpp:65]
14:28:36 INFO - PID 13656 | #04: nsObserverService::NotifyObservers(nsISupports *,char const *,char16_t const *) [xpcom/ds/nsObserverService.cpp:294]
14:28:36 INFO - PID 13656 | #05: XPTC__InvokebyIndex
14:28:36 INFO - PID 13656 | #06: CallMethodHelper::Call() [js/xpconnect/src/XPCWrappedNative.cpp:1191]
14:28:36 INFO - PID 13656 | #07: XPCWrappedNative::CallMethod(XPCCallContext &,XPCWrappedNative::CallMode) [js/xpconnect/src/XPCWrappedNative.cpp:1157]
14:28:36 INFO - PID 13656 | #08: XPC_WN_CallMethod(JSContext *,unsigned int,JS::Value *) [js/xpconnect/src/XPCWrappedNativeJSOps.cpp:943]
14:28:36 INFO - PID 13656 | #09: CallJSNative(JSContext ,bool ()(JSContext *,unsigned int,JS::Value *),JS::CallArgs const &) [js/src/vm/Interpreter.cpp:448]
14:28:36 INFO - PID 13656 | #10: js::InternalCallOrConstruct(JSContext *,JS::CallArgs const &,js::MaybeConstruct) [js/src/vm/Interpreter.cpp:540]
14:28:36 INFO - PID 13656 | #11: static bool InternalCall(struct JSContext *, const class js::AnyInvokeArgs & const) [js/src/vm/Interpreter.cpp:595]
14:28:36 INFO - PID 13656 | #12: static bool Interpret(struct JSContext *, class js::RunState & const) [js/src/vm/Interpreter.cpp:3087]
14:28:36 INFO - PID 13656 | #13: js::RunScript(JSContext *,js::RunState &) [js/src/vm/Interpreter.cpp:425]
14:28:36 INFO - PID 13656 | #14: js::InternalCallOrConstruct(JSContext *,JS::CallArgs const &,js::MaybeConstruct) [js/src/vm/Interpreter.cpp:568]
14:28:36 INFO - PID 13656 | #15: static bool InternalCall(struct JSContext *, const class js::AnyInvokeArgs & const) [js/src/vm/Interpreter.cpp:595]
14:28:36 INFO - PID 13656 | #16: js::Call(JSContext *,JS::Handle<JS::Value>,JS::Handle<JS::Value>,js::AnyInvokeArgs const &,JS::MutableHandle<JS::Value>) [js/src/vm/Interpreter.cpp:611]
14:28:36 INFO - PID 13656 | #17: JS_CallFunctionValue(JSContext *,JS::Handle<JSObject *>,JS::Handle<JS::Value>,JS::HandleValueArray const &,JS::MutableHandle<JS::Value>) [js/src/jsapi.cpp:2604]
14:28:36 INFO - PID 13656 | #18: nsXPCWrappedJS::CallMethod(unsigned short,nsXPTMethodInfo const *,nsXPTCMiniVariant *) [js/xpconnect/src/XPCWrappedJSClass.cpp:979]
14:28:36 INFO - PID 13656 | #19: PrepareAndDispatch [xpcom/reflect/xptcall/md/win32/xptcstubs_x86_64.cpp:181]
14:28:36 INFO - PID 13656 | #20: SharedStub
14:28:36 INFO - PID 13656 | #21: nsThread::ProcessNextEvent(bool,bool *) [xpcom/threads/nsThread.cpp:1204]
14:28:36 INFO - PID 13656 | #22: nsThreadManager::SpinEventLoopUntilInternal(nsINestedEventLoopCondition *,bool) [xpcom/threads/nsThreadManager.cpp:488]
14:28:36 INFO - PID 13656 | #23: XPTC__InvokebyIndex
14:28:36 INFO - PID 13656 | #24: CallMethodHelper::Call() [js/xpconnect/src/XPCWrappedNative.cpp:1191]
14:28:36 INFO - PID 13656 | #25: XPCWrappedNative::CallMethod(XPCCallContext &,XPCWrappedNative::CallMode) [js/xpconnect/src/XPCWrappedNative.cpp:1157]
14:28:36 INFO - PID 13656 | #26: XPC_WN_CallMethod(JSContext *,unsigned int,JS::Value *) [js/xpconnect/src/XPCWrappedNativeJSOps.cpp:943]
14:28:36 INFO - PID 13656 | #27: CallJSNative(JSContext ,bool ()(JSContext *,unsigned int,JS::Value *),JS::CallArgs const &) [js/src/vm/Interpreter.cpp:448]
14:28:36 INFO - PID 13656 | #28: js::InternalCallOrConstruct(JSContext *,JS::CallArgs const &,js::MaybeConstruct) [js/src/vm/Interpreter.cpp:540]
14:28:36 INFO - PID 13656 | #29: static bool InternalCall(struct JSContext *, const class js::AnyInvokeArgs & const) [js/src/vm/Interpreter.cpp:595]
14:28:36 INFO - PID 13656 | #30: static bool Interpret(struct JSContext *, class js::RunState & const) [js/src/vm/Interpreter.cpp:3087]
14:28:36 INFO - PID 13656 | #31: js::RunScript(JSContext *,js::RunState &) [js/src/vm/Interpreter.cpp:425]
14:28:36 INFO - PID 13656 | #32: js::InternalCallOrConstruct(JSContext *,JS::CallArgs const &,js::MaybeConstruct) [js/src/vm/Interpreter.cpp:568]
14:28:36 INFO - PID 13656 | #33: static bool InternalCall(struct JSContext *, const class js::AnyInvokeArgs & const) [js/src/vm/Interpreter.cpp:595]
14:28:36 INFO - PID 13656 | #34: js::Call(JSContext *,JS::Handle<JS::Value>,JS::Handle<JS::Value>,js::AnyInvokeArgs const &,JS::MutableHandle<JS::Value>) [js/src/vm/Interpreter.cpp:611]
14:28:36 INFO - PID 13656 | #35: js::ForwardingProxyHandler::call(JSContext *,JS::Handle<JSObject *>,JS::CallArgs const &) [js/src/proxy/Wrapper.cpp:162]
14:28:36 INFO - PID 13656 | #36: js::CrossCompartmentWrapper::call(JSContext *,JS::Handle<JSObject *>,JS::CallArgs const &) [js/src/proxy/CrossCompartmentWrapper.cpp:237]
14:28:36 INFO - PID 13656 | #37: js::Proxy::call(JSContext *,JS::Handle<JSObject *>,JS::CallArgs const &) [js/src/proxy/Proxy.cpp:504]
14:28:36 INFO - PID 13656 | #38: js::InternalCallOrConstruct(JSContext *,JS::CallArgs const &,js::MaybeConstruct) [js/src/vm/Interpreter.cpp:514]
14:28:36 INFO - PID 13656 | #39: static bool InternalCall(struct JSContext *, const class js::AnyInvokeArgs & const) [js/src/vm/Interpreter.cpp:595]
14:28:36 INFO - PID 13656 | #40: js::jit::DoCallFallback(JSContext *,js::jit::BaselineFrame *,js::jit::ICCall_Fallback *,unsigned int,JS::Value *,JS::MutableHandle<JS::Value>) [js/src/jit/BaselineIC.cpp:0]
14:28:36 INFO - PID 13656 | #41: ??? (???:???)
14:28:36 INFO - <<<<<<<
14:28:36 INFO - mozcrash Copy/paste: Z:\task_1560346424\build\win32-minidump_stackwalk.exe c:\users\task_1560346424\appdata\local\temp\xpc-other-jm9sv4\f8040f28-7ca9-4b74-baea-568f718e24a2.dmp Z:\task_1560346424\build\symbols
14:28:45 INFO - mozcrash Saved minidump as Z:\task_1560346424\build\blobber_upload_dir\f8040f28-7ca9-4b74-baea-568f718e24a2.dmp
14:28:45 INFO - mozcrash Saved app info as Z:\task_1560346424\build\blobber_upload_dir\f8040f28-7ca9-4b74-baea-568f718e24a2.extra
14:28:45 WARNING - PROCESS-CRASH | security/manager/ssl/tests/unit/test_blocklist_onecrl.js | application crashed [@ static void mozilla::AssertNotAlreadyCached(const char *, const class nsTSubstring<char> & const, void *)]
14:28:45 INFO - Crash dump filename: c:\users\task_1560346424\appdata\local\temp\xpc-other-jm9sv4\f8040f28-7ca9-4b74-baea-568f718e24a2.dmp
14:28:45 INFO - Operating system: Windows NT
14:28:45 INFO - 10.0.17134
14:28:45 INFO - CPU: amd64
14:28:45 INFO - family 6 model 85 stepping 3
14:28:45 INFO - 8 CPUs
14:28:45 INFO - GPU: UNKNOWN
14:28:45 INFO - Crash reason: EXCEPTION_BREAKPOINT
14:28:45 INFO - Crash address: 0x7fffd46fc530
14:28:45 INFO - Process uptime: 0 seconds
14:28:45 INFO - Thread 0 (crashed)
14:28:45 INFO - 0 xul.dll!static void mozilla::AssertNotAlreadyCached(const char *, const class nsTSubstring<char> & const, void *) [Preferences.cpp:6328411593db4f6b02950206fe5bcc655cc6a2f3 : 3173 + 0x91]
14:28:45 INFO - rax = 0x00007fffdbc72bc5 rdx = 0x00007ff80ee7a640
14:28:45 INFO - rcx = 0x00007ff80b740788 rbx = 0x00007fffdbd5b450
14:28:45 INFO - rsi = 0x00000202e6681170 rdi = 0x00007fffdd251c8c
14:28:45 INFO - rbp = 0x0000000000000000 rsp = 0x000000d9cdbfba70
14:28:45 INFO - r8 = 0x000000d9cdbf5bc8 r9 = 0x000000d9cdbf71b3
14:28:45 INFO - r10 = 0x0000000000000000 r11 = 0x000000d9cdbf70f0
14:28:45 INFO - r12 = 0x00007fffdd2a6e08 r13 = 0x00000202e6676920
14:28:45 INFO - r14 = 0x00007fffdbbb4ae0 r15 = 0x000000d9cdbfbc68
14:28:45 INFO - rip = 0x00007fffd46fc530
14:28:45 INFO - Found by: given as instruction pointer in context
14:28:45 INFO - 1 xul.dll!mozilla::Preferences::AddBoolVarCache(bool *,nsTSubstring<char> const &,bool,bool) [Preferences.cpp:6328411593db4f6b02950206fe5bcc655cc6a2f3 : 5236 + 0xf]
14:28:45 INFO - rbx = 0x00007fffdbd5b450 rbp = 0x0000000000000000
14:28:45 INFO - rsp = 0x000000d9cdbfbae0 r12 = 0x00007fffdd2a6e08
14:28:45 INFO - r13 = 0x00000202e6676920 r14 = 0x00007fffdbbb4ae0
14:28:45 INFO - r15 = 0x000000d9cdbfbc68 rip = 0x00007fffd46fc3d3
14:28:45 INFO - Found by: call frame info

BugBot [:suhaib / :marco/ :calixte]

Updated

•

6 years ago

Keywords: regression

Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)

Updated

•

6 years ago

status-firefox69: ? → affected

tracking-firefox69: --- → ?

Flags: needinfo?(mathieu)

Mathieu Leplatre [:leplatrem]

Comment 1

•

6 years ago

I don't see why we'd have this error on this unrelated pref :(

14:28:19     INFO -  security/manager/ssl/tests/unit/test_blocklist_onecrl.js | Starting test_revocations_are_updated_on_sync
14:28:19     INFO -  (xpcshell/head.js) | test test_revocations_are_updated_on_sync pending (2)
14:28:19     INFO -  PID 13656 | Attempt to add a bool pref cache for preference 'browser.cache.disk.enable' at address '00007FFFDD251C8C'was made. However, a pref was already cached at this address.
14:28:19     INFO -  PID 13656 | Assertion failure: false (Should not have an existing pref cache for this address), at z:/build/build/src/modules/libpref/Preferences.cpp:3165
14:28:36     INFO -  PID 13656 | #01: mozilla::net::CacheObserver::AttachToPreferences() [netwerk/cache2/CacheObserver.cpp:151]
14:28:36     INFO -  PID 13656 | #02: mozilla::net::CacheObserver::Observe(nsISupports *,char const *,char16_t const *) [netwerk/cache2/CacheObserver.cpp:489]
14:28:36     INFO -  PID 13656 | #03: nsObserverList::NotifyObservers(nsISupports *,char const *,char16_t const *) [xpcom/ds/nsObserverList.cpp:65]
14:28:36     INFO -  PID 13656 | #04: nsObserverService::NotifyObservers(nsISupports *,char const *,char16_t const *) [xpcom/ds/nsObserverService.cpp:294]

Can we find someone more familiar with libpref component? Gijs, you were involved in Bug 1029509, maybe you have an idea? Thanks!

Flags: needinfo?(mathieu) → needinfo?(gijskruitbosch+bugs)

:Gijs (he/him)

Comment 2

•

6 years ago

I don't really get this.

The pref thing indicates someone tried to add a pref observer pointing to the same variable. Basically, calling Add<Type>VarCache more than once with an identical first parameter.

This should never happen.

From code inspection, it doesn't look like there's more than 1 caller, only AttachPreferences called from the observe() method when it gets profile-do-change - but that should only happen once.

I also don't see why it takes a beta simulation here, ie if it's broken why isn't it broken now?

To fix this, someone probably has to get m-c updated to include whatever sheriffs use for beta simulation, get a debugger out and print the first and second both C++ and JS stacks for how AttachPreferences is called here.

Flags: needinfo?(gijskruitbosch+bugs)

Ryan VanderMeulen [:RyanVM]

Updated

•

6 years ago

status-firefox-esr60: --- → unaffected

tracking-firefox69: ? → +

Comment hidden (Intermittent Failures Robot)

Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)

Comment 4

•

6 years ago

Nicholas, can you sched some light on comment 2? This will permafail on beta with the merge from central on Monday, but only on Windows 10 x64 debug. Thank you.

Flags: needinfo?(n.nethercote)

Nicholas Nethercote [inactive]

Comment 5

•

6 years ago

Gijs's analysis is correct. This code is unusual... Add<Type>VarCache calls are usually paired with a static bool that is used to ensure that it only gets called once. Here is an example: https://searchfox.org/mozilla-central/rev/f91bd38732d4a330eba4e780812274b98eb81274/accessible/aom/AccessibleNode.cpp#22-28. The calls also usually occur very early, during some kind of initialization phase.

This code doesn't have any such static variable. So if the profile-do-change notification occurs more than once, this assertion will fire. I agree that it's strange that it only occurs on beta on Windows 10.

One option is to switch over to static prefs, as per bug 1448219. It's something that is desirable anyway, and it would fix this. It's Friday evening here; I could make that change on Monday, but it sounds like that won't be soon enough for the merge.

Flags: needinfo?(n.nethercote)

BugBot [:suhaib / :marco/ :calixte]

Comment 6

•

6 years ago

The priority flag is not set for this bug.
:keeler, could you have a look please?

For more information, please visit auto_nag documentation.

Flags: needinfo?(dkeeler)

Dana Keeler (she/her) (use needinfo) [:keeler]

Assignee

Comment 7

•

6 years ago

It looks like removing some unnecessary leftover code from the test fixes the issue: https://treeherder.mozilla.org/#/jobs?repo=try&revision=81314cf13435b69e69893762632d3b57ccf02107 (my guess is somehow that test causes the notification to fire twice). I have a patch that fixes the test, but it would still be good to fix CacheObserver either by adding a bool or as part of bug 1448219, so I filed bug 1562305.

Component: Security: PSM → Networking: Cache

Flags: needinfo?(dkeeler)

Dana Keeler (she/her) (use needinfo) [:keeler]

Assignee

Comment 8

•

6 years ago

D'oh - didn't mean to change the component.

Assignee: nobody → dkeeler

Component: Networking: Cache → Security: PSM

Priority: -- → P1

Whiteboard: [psm-assigned]

Dana Keeler (she/her) (use needinfo) [:keeler]

Assignee

Comment 9

•

6 years ago

Attached file bug 1559108 - remove unnecessary code in test_blocklist_onecrl.js that was causing unrelated failures r?KevinJacobs — Details

Previously, OneCRL was part of the add-on blocklist system. Now that we use
kinto/remote settings, using AddonTestUtils in test_blocklist_onecrl.js is
unnecessary (and it was exposing a preexisting issue with how CacheObserver uses
prefs).

Pulsebot

Comment 10

•

6 years ago

Pushed by dkeeler@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/d71b83bd4ca0 remove unnecessary code in test_blocklist_onecrl.js that was causing unrelated failures r=KevinJacobs

Natalia Csoregi [:nataliaCs]

Comment 11

•

6 years ago

bugherder

https://hg.mozilla.org/mozilla-central/rev/d71b83bd4ca0

Status: NEW → RESOLVED

Closed: 6 years ago

status-firefox69: affected → fixed

Resolution: --- → FIXED

Target Milestone: --- → mozilla69

Cosmin Sabou [:CosminS]

Comment 12

•

6 years ago

Verified in today's beta sim: https://treeherder.mozilla.org/#/jobs?repo=try&group_state=expanded&resultStatus=success%2Cpending%2Crunning%2Ctestfailed%2Cbusted%2Cexception&classifiedState=unclassified&revision=24f4ab13539d9b779350817522c079779de84633&searchStr=windows%2C10%2Cx64%2Cdebug%2Cxpcshell%2Ctests%2Ctest-windows10-64%2Fdebug-xpcshell-e10s-2%2Cx%28x2%29&selectedJob=254146655

Status: RESOLVED → VERIFIED

BugBot [:suhaib / :marco/ :calixte]

Updated

•

3 years ago

Has Regression Range: --- → yes

Bugzilla

Perma security/manager/ssl/tests/unit/test_blocklist_onecrl.js | xpcshell return code: 1 when Gecko 69 merges to Beta on 19-07-01

Categories

(Core :: Security: PSM, defect, P1)

Tracking

()

People

(Reporter: noemi_erli, Assigned: keeler)

References

(Regression)

Details

(Keywords: regression, Whiteboard: [psm-assigned])

Crash Data

Security

(public)

User Story

Attachments

(1 file)

Description

Updated

Updated

Comment 1

Comment 2

Updated

Comment 3

Comment 4

Comment 5

Comment 6

Comment 7

Comment 8

Comment 9

Comment 10

Comment 11

Comment 12

Updated

Attachment

General

Description

File Name

Content Type