Closed
Bug 1817260
Opened 3 years ago
Closed 3 years ago
Intermittent FATAL ERROR: AsyncShutdown timeout in profile-change-teardown Conditions: [{"name":"Extension shutdown: webcompat@mozilla.org ","state":{"state":"Startup: Run manifest, asyncEmitManifestEntry(\"background\")"},"filename":"resource://gre/module
Categories
(Testing :: web-platform-tests, defect, P5)
Testing
web-platform-tests
Tracking
(Not tracked)
RESOLVED
DUPLICATE
of bug 1740162
People
(Reporter: intermittent-bug-filer, Unassigned)
Details
(Keywords: intermittent-failure)
Filed by: nbeleuzu [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=405860468&repo=try
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/abfmnkIwQ8aphFEu60UVFw/runs/0/artifacts/public/logs/live_backing.log
[task 2023-02-16T13:04:36.333Z] 13:04:36 INFO - Browser exited with return code 0
[task 2023-02-16T13:04:36.336Z] 13:04:36 INFO - Closing logging queue
[task 2023-02-16T13:04:36.336Z] 13:04:36 INFO - queue closed
[task 2023-02-16T13:04:36.371Z] 13:04:36 INFO - INFO | runtests.py | ASan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer
[task 2023-02-16T13:04:36.380Z] 13:04:36 INFO - LSan enabled.
[task 2023-02-16T13:04:36.380Z] 13:04:36 INFO - INFO | runtests.py | ASan running in default memory configuration
[task 2023-02-16T13:04:36.381Z] 13:04:36 INFO - UBSan enabled.
[task 2023-02-16T13:04:36.382Z] 13:04:36 INFO - Application command: /builds/worker/workspace/build/application/firefox/firefox --marionette about:blank -profile /tmp/tmptww3h3em
[task 2023-02-16T13:04:36.398Z] 13:04:36 INFO - PID 24457 | 1676552208195 Marionette INFO Marionette enabled
[task 2023-02-16T13:04:36.401Z] 13:04:36 INFO - PID 24457 | 1676552208214 Marionette FATAL Marionette server failed to start: Error: Could not bind to port 33054 (NS_ERROR_SOCKET_ADDRESS_IN_USE)(chrome://remote/content/marionette/server.sys.mjs:77:17) JS Stack trace: set acceptConnections@sys.mjs:77:17
[task 2023-02-16T13:04:36.402Z] 13:04:36 INFO - PID 24457 | start@sys.mjs:107:5
[task 2023-02-16T13:04:36.403Z] 13:04:36 INFO - PID 24457 | init@sys.mjs:226:19
[task 2023-02-16T13:04:36.404Z] 13:04:36 INFO - PID 24457 | observe@sys.mjs:178:20
[task 2023-02-16T13:04:36.408Z] 13:04:36 INFO - PID 24457 | WARNING: At least one completion condition is taking too long to complete. Conditions: [{"name":"Extension shutdown: webcompat@mozilla.org","state":{"state":"Startup: Run manifest, asyncEmitManifestEntry(\"background\")"},"filename":"resource://gre/modules/addons/XPIProvider.jsm","lineNumber":2630,"stack":["resource://gre/modules/addons/XPIProvider.jsm:startup/<:2630","resource://gre/modules/AsyncShutdown.sys.mjs:observe:576","chrome://remote/content/components/Marionette.sys.mjs:init:230"]},{"name":"Extension shutdown: webcompat-reporter@mozilla.org","state":{"state":"Startup: Run manifest, asyncEmitManifestEntry(\"background\")"},"filename":"resource://gre/modules/addons/XPIProvider.jsm","lineNumber":2630,"stack":["resource://gre/modules/addons/XPIProvider.jsm:startup/<:2630","resource://gre/modules/AsyncShutdown.sys.mjs:observe:576","chrome://remote/content/components/Marionette.sys.mjs:init:230"]},{"name":"Extension shutdown: screenshots@mozilla.org","state":{"state":"Startup: Run manifest, asyncEmitManifestEntry(\"background\")"},"filename":"resource://gre/modules/addons/XPIProvider.jsm","lineNumber":2630,"stack":["resource://gre/modules/addons/XPIProvider.jsm:startup/<:2630","resource://gre/modules/AsyncShutdown.sys.mjs:observe:576","chrome://remote/content/components/Marionette.sys.mjs:init:230"]},{"name":"Extension shutdown: pictureinpicture@mozilla.org","state":{"state":"Startup: Run manifest, asyncEmitManifestEntry(\"background\")"},"filename":"resource://gre/modules/addons/XPIProvider.jsm","lineNumber":2630,"stack":["resource://gre/modules/addons/XPIProvider.jsm:startup/<:2630","resource://gre/modules/AsyncShutdown.sys.mjs:observe:576","chrome://remote/content/components/Marionette.sys.mjs:init:230"]},{"name":"Extension shutdown: formautofill@mozilla.org","state":{"state":"Startup: Run manifest, asyncEmitManifestEntry(\"background\")"},"filename":"resource://gre/modules/addons/XPIProvider.jsm","lineNumber":2630,"stack":["resource://gre/modules/addons/XPIProvider.jsm:startup/<:2630","resource://gre/modules/AsyncShutdown.sys.mjs:observe:576","chrome://remote/content/components/Marionette.sys.mjs:init:230"]}] Barrier: profile-change-teardown
[task 2023-02-16T13:04:36.409Z] 13:04:36 INFO - PID 24457 | FATAL ERROR: AsyncShutdown timeout in profile-change-teardown Conditions: [{"name":"Extension shutdown: webcompat@mozilla.org","state":{"state":"Startup: Run manifest, asyncEmitManifestEntry(\"background\")"},"filename":"resource://gre/modules/addons/XPIProvider.jsm","lineNumber":2630,"stack":["resource://gre/modules/addons/XPIProvider.jsm:startup/<:2630","resource://gre/modules/AsyncShutdown.sys.mjs:observe:576","chrome://remote/content/components/Marionette.sys.mjs:init:230"]},{"name":"Extension shutdown: webcompat-reporter@mozilla.org","state":{"state":"Startup: Run manifest, asyncEmitManifestEntry(\"background\")"},"filename":"resource://gre/modules/addons/XPIProvider.jsm","lineNumber":2630,"stack":["resource://gre/modules/addons/XPIProvider.jsm:startup/<:2630","resource://gre/modules/AsyncShutdown.sys.mjs:observe:576","chrome://remote/content/components/Marionette.sys.mjs:init:230"]},{"name":"Extension shutdown: screenshots@mozilla.org","state":{"state":"Startup: Run manifest, asyncEmitManifestEntry(\"background\")"},"filename":"resource://gre/modules/addons/XPIProvider.jsm","lineNumber":2630,"stack":["resource://gre/modules/addons/XPIProvider.jsm:startup/<:2630","resource://gre/modules/AsyncShutdown.sys.mjs:observe:576","chrome://remote/content/components/Marionette.sys.mjs:init:230"]},{"name":"Extension shutdown: pictureinpicture@mozilla.org","state":{"state":"Startup: Run manifest, asyncEmitManifestEntry(\"background\")"},"filename":"resource://gre/modules/addons/XPIProvider.jsm","lineNumber":2630,"stack":["resource://gre/modules/addons/XPIProvider.jsm:startup/<:2630","resource://gre/modules/AsyncShutdown.sys.mjs:observe:576","chrome://remote/content/components/Marionette.sys.mjs:init:230"]},{"name":"Extension shutdown: formautofill@mozilla.org","state":{"state":"Startup: Run manifest, asyncEmitManifestEntry(\"background\")"},"filename":"resource://gre/modules/addons/XPIProvider.jsm","lineNumber":2630,"stack":["resource://gre/modules/addons/XPIProvider.jsm:startup/<:2630","resource://gre/modules/AsyncShutdown.sys.mjs:observe:576","chrome://remote/content/components/Marionette.sys.mjs:init:230"]}] At least one completion condition failed to complete within a reasonable amount of time. Causing a crash to ensure that we do not leave the user with an unresponsive process draining resources.
[task 2023-02-16T13:04:36.410Z] 13:04:36 INFO - PID 24457 | WARNING: No crash reporter available
[task 2023-02-16T13:04:36.410Z] 13:04:36 INFO - PID 24457 | [Parent 24457, Main Thread] ###!!! ABORT: file resource://gre/modules/addons/XPIProvider.jsm:2630
[task 2023-02-16T13:04:36.411Z] 13:04:36 INFO - PID 24457 | AddressSanitizer:DEADLYSIGNAL
[task 2023-02-16T13:04:36.412Z] 13:04:36 INFO - PID 24457 | =================================================================
[task 2023-02-16T13:04:36.412Z] 13:04:36 ERROR - PID 24457 | ==24457==ERROR: AddressSanitizer: SEGV on unknown address 0x000000000001 (pc 0x7fb5d04cde6e bp 0x7ffc03d919d0 sp 0x7ffc03d90fc0 T0)
[task 2023-02-16T13:04:36.413Z] 13:04:36 INFO - PID 24457 | ==24457==The signal is caused by a WRITE memory access.
[task 2023-02-16T13:04:36.414Z] 13:04:36 INFO - PID 24457 | ==24457==Hint: address points to the zero page.
| Comment hidden (Intermittent Failures Robot) |
|
||
Comment 2•3 years ago
|
||
The actual failure is: AddressSanitizer: SEGV /builds/worker/checkouts/gecko/xpcom/base/nsDebugImpl.cpp in NS_DebugBreak
[task 2023-02-16T13:04:36.411Z] 13:04:36 INFO - PID 24457 | AddressSanitizer:DEADLYSIGNAL
[task 2023-02-16T13:04:36.412Z] 13:04:36 INFO - PID 24457 | =================================================================
[task 2023-02-16T13:04:36.412Z] 13:04:36 ERROR - PID 24457 | ==24457==ERROR: AddressSanitizer: SEGV on unknown address 0x000000000001 (pc 0x7fb5d04cde6e bp 0x7ffc03d919d0 sp 0x7ffc03d90fc0 T0)
[task 2023-02-16T13:04:36.413Z] 13:04:36 INFO - PID 24457 | ==24457==The signal is caused by a WRITE memory access.
[task 2023-02-16T13:04:36.414Z] 13:04:36 INFO - PID 24457 | ==24457==Hint: address points to the zero page.
[task 2023-02-16T13:04:36.414Z] 13:04:36 INFO - PID 24457 | #0 0x7fb5d04cde6e in NS_DebugBreak /builds/worker/checkouts/gecko/xpcom/base/nsDebugImpl.cpp
[task 2023-02-16T13:04:36.415Z] 13:04:36 INFO - PID 24457 | #1 0x7fb5d04ce557 in nsDebugImpl::Abort(char const*, int) /builds/worker/checkouts/gecko/xpcom/base/nsDebugImpl.cpp:129:3
[task 2023-02-16T13:04:36.416Z] 13:04:36 INFO - PID 24457 | #2 0x7fb5d0765545 in NS_InvokeByIndex /builds/worker/checkouts/gecko/xpcom/reflect/xptcall/md/unix/xptcinvoke_asm_x86_64_unix.S:101
[task 2023-02-16T13:04:36.417Z] 13:04:36 INFO - PID 24457 | #3 0x7fb5d2094a7a in Invoke /builds/worker/checkouts/gecko/js/xpconnect/src/XPCWrappedNative.cpp:1626:10
[task 2023-02-16T13:04:36.417Z] 13:04:36 INFO - PID 24457 | #4 0x7fb5d2094a7a in Call /builds/worker/checkouts/gecko/js/xpconnect/src/XPCWrappedNative.cpp:1179:19
[task 2023-02-16T13:04:36.418Z] 13:04:36 INFO - PID 24457 | #5 0x7fb5d2094a7a in XPCWrappedNative::CallMethod(XPCCallContext&, XPCWrappedNative::CallMode) /builds/worker/checkouts/gecko/js/xpconnect/src/XPCWrappedNative.cpp:1125:23
[task 2023-02-16T13:04:36.419Z] 13:04:36 INFO - PID 24457 | #6 0x7fb5d209935d in XPC_WN_CallMethod(JSContext*, unsigned int, JS::Value*) /builds/worker/checkouts/gecko/js/xpconnect/src/XPCWrappedNativeJSOps.cpp:965:10
[task 2023-02-16T13:04:36.420Z] 13:04:36 INFO - PID 24457 | #7 0x7fb5dd3d666e in CallJSNative /builds/worker/checkouts/gecko/js/src/vm/Interpreter.cpp:459:13
[task 2023-02-16T13:04:36.421Z] 13:04:36 INFO - PID 24457 | #8 0x7fb5dd3d666e in js::InternalCallOrConstruct(JSContext*, JS::CallArgs const&, js::MaybeConstruct, js::CallReason) /builds/worker/checkouts/gecko/js/src/vm/Interpreter.cpp:547:12
[task 2023-02-16T13:04:36.421Z] 13:04:36 INFO - PID 24457 | #9 0x7fb5dd3c57ca in InternalCall /builds/worker/checkouts/gecko/js/src/vm/Interpreter.cpp:614:10
[task 2023-02-16T13:04:36.422Z] 13:04:36 INFO - PID 24457 | #10 0x7fb5dd3c57ca in CallFromStack /builds/worker/checkouts/gecko/js/src/vm/Interpreter.cpp:619:10
[task 2023-02-16T13:04:36.423Z] 13:04:36 INFO - PID 24457 | #11 0x7fb5dd3c57ca in Interpret(JSContext*, js::RunState&) /builds/worker/checkouts/gecko/js/src/vm/Interpreter.cpp:3362:16
[task 2023-02-16T13:04:36.423Z] 13:04:36 INFO - PID 24457 | #12 0x7fb5dd3a984c in js::RunScript(JSContext*, js::RunState&) /builds/worker/checkouts/gecko/js/src/vm/Interpreter.cpp:431:13
[task 2023-02-16T13:04:36.424Z] 13:04:36 INFO - PID 24457 | #13 0x7fb5dd3d6759 in js::InternalCallOrConstruct(JSContext*, JS::CallArgs const&, js::MaybeConstruct, js::CallReason) /builds/worker/checkouts/gecko/js/src/vm/Interpreter.cpp:579:13
[task 2023-02-16T13:04:36.425Z] 13:04:36 INFO - PID 24457 | #14 0x7fb5dd3d837f in InternalCall /builds/worker/checkouts/gecko/js/src/vm/Interpreter.cpp:614:10
[task 2023-02-16T13:04:36.425Z] 13:04:36 INFO - PID 24457 | #15 0x7fb5dd3d837f in js::Call(JSContext*, JS::Handle<JS::Value>, JS::Handle<JS::Value>, js::AnyInvokeArgs const&, JS::MutableHandle<JS::Value>, js::CallReason) /builds/worker/checkouts/gecko/js/src/vm/Interpreter.cpp:646:8
[task 2023-02-16T13:04:36.426Z] 13:04:36 INFO - PID 24457 | #16 0x7fb5dd75c552 in Call /builds/worker/checkouts/gecko/js/src/vm/Interpreter.h:116:10
[task 2023-02-16T13:04:36.427Z] 13:04:36 INFO - PID 24457 | #17 0x7fb5dd75c552 in PromiseReactionJob(JSContext*, unsigned int, JS::Value*) /builds/worker/checkouts/gecko/js/src/builtin/Promise.cpp:2240:10
[task 2023-02-16T13:04:36.428Z] 13:04:36 INFO - PID 24457 | #18 0x7fb5dd3d666e in CallJSNative /builds/worker/checkouts/gecko/js/src/vm/Interpreter.cpp:459:13
[task 2023-02-16T13:04:36.428Z] 13:04:36 INFO - PID 24457 | #19 0x7fb5dd3d666e in js::InternalCallOrConstruct(JSContext*, JS::CallArgs const&, js::MaybeConstruct, js::CallReason) /builds/worker/checkouts/gecko/js/src/vm/Interpreter.cpp:547:12
[task 2023-02-16T13:04:36.429Z] 13:04:36 INFO - PID 24457 | #20 0x7fb5dd3d837f in InternalCall /builds/worker/checkouts/gecko/js/src/vm/Interpreter.cpp:614:10
[task 2023-02-16T13:04:36.430Z] 13:04:36 INFO - PID 24457 | #21 0x7fb5dd3d837f in js::Call(JSContext*, JS::Handle<JS::Value>, JS::Handle<JS::Value>, js::AnyInvokeArgs const&, JS::MutableHandle<JS::Value>, js::CallReason) /builds/worker/checkouts/gecko/js/src/vm/Interpreter.cpp:646:8
[task 2023-02-16T13:04:36.431Z] 13:04:36 INFO - PID 24457 | #22 0x7fb5dd4df02e in JS::Call(JSContext*, JS::Handle<JS::Value>, JS::Handle<JS::Value>, JS::HandleValueArray const&, JS::MutableHandle<JS::Value>) /builds/worker/checkouts/gecko/js/src/vm/CallAndConstruct.cpp:117:10
[task 2023-02-16T13:04:36.431Z] 13:04:36 INFO - PID 24457 | #23 0x7fb5d423048c in mozilla::dom::PromiseJobCallback::Call(mozilla::dom::BindingCallContext&, JS::Handle<JS::Value>, mozilla::ErrorResult&) /builds/worker/workspace/obj-build/dom/bindings/PromiseBinding.cpp:83:8
[task 2023-02-16T13:04:36.432Z] 13:04:36 INFO - PID 24457 | #24 0x7fb5d051a8fa in Call /builds/worker/workspace/obj-build/dist/include/mozilla/dom/PromiseBinding.h:198:12
[task 2023-02-16T13:04:36.433Z] 13:04:36 INFO - PID 24457 | #25 0x7fb5d051a8fa in Call /builds/worker/workspace/obj-build/dist/include/mozilla/dom/PromiseBinding.h:211:12
[task 2023-02-16T13:04:36.434Z] 13:04:36 INFO - PID 24457 | #26 0x7fb5d051a8fa in mozilla::PromiseJobRunnable::Run(mozilla::AutoSlowOperation&) /builds/worker/checkouts/gecko/xpcom/base/CycleCollectedJSContext.cpp:213:18
[task 2023-02-16T13:04:36.434Z] 13:04:36 INFO - PID 24457 | #27 0x7fb5d04fc27c in mozilla::CycleCollectedJSContext::PerformMicroTaskCheckPoint(bool) /builds/worker/checkouts/gecko/xpcom/base/CycleCollectedJSContext.cpp:676:17
[task 2023-02-16T13:04:36.435Z] 13:04:36 INFO - PID 24457 | #28 0x7fb5d04fd05f in mozilla::CycleCollectedJSContext::AfterProcessTask(unsigned int) /builds/worker/checkouts/gecko/xpcom/base/CycleCollectedJSContext.cpp:463:3
[task 2023-02-16T13:04:36.436Z] 13:04:36 INFO - PID 24457 | #29 0x7fb5d2017f24 in XPCJSContext::AfterProcessTask(unsigned int) /builds/worker/checkouts/gecko/js/xpconnect/src/XPCJSContext.cpp:1480:28
[task 2023-02-16T13:04:36.437Z] 13:04:36 INFO - PID 24457 | #30 0x7fb5d071caa7 in nsThread::ProcessNextEvent(bool, bool*) /builds/worker/checkouts/gecko/xpcom/threads/nsThread.cpp:1262:24
[task 2023-02-16T13:04:36.437Z] 13:04:36 INFO - PID 24457 | #31 0x7fb5d0765545 in NS_InvokeByIndex /builds/worker/checkouts/gecko/xpcom/reflect/xptcall/md/unix/xptcinvoke_asm_x86_64_unix.S:101
[task 2023-02-16T13:04:36.438Z] 13:04:36 INFO - PID 24457 | #32 0x7fb5d2094a7a in Invoke /builds/worker/checkouts/gecko/js/xpconnect/src/XPCWrappedNative.cpp:1626:10
[task 2023-02-16T13:04:36.439Z] 13:04:36 INFO - PID 24457 | #33 0x7fb5d2094a7a in Call /builds/worker/checkouts/gecko/js/xpconnect/src/XPCWrappedNative.cpp:1179:19
[task 2023-02-16T13:04:36.440Z] 13:04:36 INFO - PID 24457 | #34 0x7fb5d2094a7a in XPCWrappedNative::CallMethod(XPCCallContext&, XPCWrappedNative::CallMode) /builds/worker/checkouts/gecko/js/xpconnect/src/XPCWrappedNative.cpp:1125:23
[task 2023-02-16T13:04:36.441Z] 13:04:36 INFO - PID 24457 | #35 0x7fb5d209935d in XPC_WN_CallMethod(JSContext*, unsigned int, JS::Value*) /builds/worker/checkouts/gecko/js/xpconnect/src/XPCWrappedNativeJSOps.cpp:965:10
[task 2023-02-16T13:04:36.441Z] 13:04:36 INFO - PID 24457 | #36 0x7fb53d251871 (<unknown module>)
[task 2023-02-16T13:04:36.442Z] 13:04:36 INFO - PID 24457 | AddressSanitizer can not provide additional info.
[task 2023-02-16T13:04:36.443Z] 13:04:36 INFO - PID 24457 | SUMMARY: AddressSanitizer: SEGV /builds/worker/checkouts/gecko/xpcom/base/nsDebugImpl.cpp in NS_DebugBreak
[task 2023-02-16T13:04:36.444Z] 13:04:36 INFO - PID 24457 | ==24457==ABORTING
You need to log in
before you can comment on or make changes to this bug.
Description
•