Closed Bug 1593874 Opened 6 years ago Closed 6 years ago

Intermittent TEST-UNEXPECTED-TIMEOUT | /service-workers/service-worker/claim-not-using-registration.https.html | Test claim client which is not using registration - Test timed out

Categories

(Core :: DOM: Service Workers, defect, P5)

Product:
Core
Component:
DOM: Service Workers
Type:
defect

Tracking

()

Status:
RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: intermittent-failure)

Filed by: rmaries [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=274486368&repo=mozilla-central
Full log: https://queue.taskcluster.net/v1/task/Mot_jV6TTSGqUSF3YOumPA/runs/0/artifacts/public/logs/live_backing.log

[task 2019-11-04T23:24:48.615Z] 23:24:48 INFO - TEST-START | /service-workers/service-worker/claim-not-using-registration.https.html
[task 2019-11-04T23:25:03.371Z] 23:25:03 INFO - PID 18291 | --DOMWINDOW == 3 (0x7f8ac523c800) [pid = 18729] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2019-11-04T23:25:03.371Z] 23:25:03 INFO - PID 18291 | --DOMWINDOW == 2 (0x7f8ac4e46400) [pid = 18729] [serial = 3] [outer = (nil)] [url = about:blank]
[task 2019-11-04T23:25:19.602Z] 23:25:19 INFO -
[task 2019-11-04T23:25:19.602Z] 23:25:19 INFO - TEST-UNEXPECTED-TIMEOUT | /service-workers/service-worker/claim-not-using-registration.https.html | Test claim client which is not using registration - Test timed out
[task 2019-11-04T23:25:19.602Z] 23:25:19 INFO -
[task 2019-11-04T23:25:19.602Z] 23:25:19 INFO - TEST-UNEXPECTED-NOTRUN | /service-workers/service-worker/claim-not-using-registration.https.html | Test claim client when there's a longer-matched registration not already used by the page - expected PASS
[task 2019-11-04T23:25:19.603Z] 23:25:19 INFO - TEST-UNEXPECTED-TIMEOUT | /service-workers/service-worker/claim-not-using-registration.https.html | expected OK
[task 2019-11-04T23:25:19.603Z] 23:25:19 INFO - TEST-INFO took 30986ms
[task 2019-11-04T23:25:19.631Z] 23:25:19 INFO - PID 18291 | 1572909919629 Marionette INFO Stopped listening on port 33574
[task 2019-11-04T23:25:19.721Z] 23:25:19 INFO - PID 18291 | --DOCSHELL 0x7f22db81f000 == 2 [pid = 18354] [id = {2dfa797b-52fd-4771-82f6-773f87c92a7f}] [url = moz-extension://39d3b617-3459-404e-9988-b0b68ca34164/_generated_background_page.html]
[task 2019-11-04T23:25:19.721Z] 23:25:19 INFO - PID 18291 | --DOCSHELL 0x7f22f4e84800 == 1 [pid = 18354] [id = {a08a2a82-0a25-4d27-b26e-cfb73a1466e7}] [url = moz-extension://e915d520-d341-4dd9-9cdd-1fbfdc846523/_generated_background_page.html]
[task 2019-11-04T23:25:19.919Z] 23:25:19 INFO - PID 18291 | --DOCSHELL 0x7f22dafc1000 == 0 [pid = 18354] [id = {b67436a1-caf2-4506-8567-4b5bd0dd6c00}] [url = moz-extension://fbcdd4b4-61b4-4b90-a9af-e329d458bdd9/_generated_background_page.html]
[task 2019-11-04T23:25:20.016Z] 23:25:20 INFO - PID 18291 | --DOCSHELL 0x7f8ac52b7800 == 0 [pid = 18729] [id = {457bb79b-4038-4148-a6bd-21a13ae74376}] [url = https://web-platform.test:8443/service-workers/service-worker/claim-not-using-registration.https.html]
[task 2019-11-04T23:25:20.037Z] 23:25:20 INFO - PID 18291 | [2019-11-04T23:25:20Z WARN xulstore::persist] tried to remove key that isn't in the store
[task 2019-11-04T23:25:20.039Z] 23:25:20 INFO - PID 18291 | [2019-11-04T23:25:20Z WARN xulstore::persist] tried to remove key that isn't in the store
[task 2019-11-04T23:25:20.055Z] 23:25:20 INFO - PID 18291 | --DOMWINDOW == 1 (0x7f8ac5243000) [pid = 18729] [serial = 4] [outer = (nil)] [url = https://web-platform.test:8443/service-workers/service-worker/claim-not-using-registration.https.html]
[task 2019-11-04T23:25:20.055Z] 23:25:20 INFO - PID 18291 | --DOMWINDOW == 0 (0x7f8ac5102f20) [pid = 18729] [serial = 1] [outer = (nil)] [url = https://web-platform.test:8443/service-workers/service-worker/claim-not-using-registration.https.html]
[task 2019-11-04T23:25:20.071Z] 23:25:20 INFO - PID 18291 | --DOMWINDOW == 5 (0x7f22dc2e13e0) [pid = 18354] [serial = 5] [outer = (nil)] [url = moz-extension://e915d520-d341-4dd9-9cdd-1fbfdc846523/_generated_background_page.html]
[task 2019-11-04T23:25:20.072Z] 23:25:20 INFO - PID 18291 | --DOMWINDOW == 4 (0x7f22dc2e26a0) [pid = 18354] [serial = 3] [outer = (nil)] [url = moz-extension://39d3b617-3459-404e-9988-b0b68ca34164/_generated_background_page.html]
[task 2019-11-04T23:25:20.074Z] 23:25:20 INFO - PID 18291 | --DOMWINDOW == 3 (0x7f22dc2e24c0) [pid = 18354] [serial = 1] [outer = (nil)] [url = moz-extension://fbcdd4b4-61b4-4b90-a9af-e329d458bdd9/_generated_background_page.html]
[task 2019-11-04T23:25:20.075Z] 23:25:20 INFO - PID 18291 | --DOMWINDOW == 2 (0x7f22dc3d9000) [pid = 18354] [serial = 10] [outer = (nil)] [url = moz-extension://39d3b617-3459-404e-9988-b0b68ca34164/_generated_background_page.html]
[task 2019-11-04T23:25:20.075Z] 23:25:20 INFO - PID 18291 | --DOMWINDOW == 1 (0x7f22db8a0400) [pid = 18354] [serial = 11] [outer = (nil)] [url = moz-extension://e915d520-d341-4dd9-9cdd-1fbfdc846523/_generated_background_page.html]
[task 2019-11-04T23:25:20.076Z] 23:25:20 INFO - PID 18291 | --DOMWINDOW == 0 (0x7f22dc37c400) [pid = 18354] [serial = 9] [outer = (nil)] [url = moz-extension://fbcdd4b4-61b4-4b90-a9af-e329d458bdd9/_generated_background_page.html]
[task 2019-11-04T23:25:20.092Z] 23:25:20 INFO - PID 18291 | nsStringStats
[task 2019-11-04T23:25:20.092Z] 23:25:20 INFO - PID 18291 | => mAllocCount: 8923
[task 2019-11-04T23:25:20.093Z] 23:25:20 INFO - PID 18291 | => mReallocCount: 0
[task 2019-11-04T23:25:20.093Z] 23:25:20 INFO - PID 18291 | => mFreeCount: 8923
[task 2019-11-04T23:25:20.094Z] 23:25:20 INFO - PID 18291 | => mShareCount: 8074
[task 2019-11-04T23:25:20.094Z] 23:25:20 INFO - PID 18291 | => mAdoptCount: 524
[task 2019-11-04T23:25:20.095Z] 23:25:20 INFO - PID 18291 | => mAdoptFreeCount: 528
[task 2019-11-04T23:25:20.095Z] 23:25:20 INFO - PID 18291 | => Process ID: 18729, Thread ID: 140234448172864
[task 2019-11-04T23:25:20.103Z] 23:25:20 INFO - PID 18291 | nsStringStats
[task 2019-11-04T23:25:20.105Z] 23:25:20 INFO - PID 18291 | => mAllocCount: 14619
[task 2019-11-04T23:25:20.105Z] 23:25:20 INFO - PID 18291 | => mReallocCount: 0
[task 2019-11-04T23:25:20.105Z] 23:25:20 INFO - PID 18291 | => mFreeCount: 14619
[task 2019-11-04T23:25:20.106Z] 23:25:20 INFO - PID 18291 | => mShareCount: 8260
[task 2019-11-04T23:25:20.106Z] 23:25:20 INFO - PID 18291 | => mAdoptCount: 388
[task 2019-11-04T23:25:20.106Z] 23:25:20 INFO - PID 18291 | => mAdoptFreeCount: 412
[task 2019-11-04T23:25:20.106Z] 23:25:20 INFO - PID 18291 | => Process ID: 18354, Thread ID: 139788137305920
[task 2019-11-04T23:25:27.964Z] 23:25:27 INFO - PID 18291 | --DOCSHELL 0x7f6badcba800 == 1 [pid = 18377] [id = {97fcbd86-4882-47ff-bcab-ec1410df10ea}] [url = https://web-platform.test:8443/testharness_runner.html]
[task 2019-11-04T23:25:28.065Z] 23:25:28 INFO - PID 18291 | --DOMWINDOW == 4 (0x7f6baefe82e0) [pid = 18377] [serial = 5] [outer = (nil)] [url = about:newtab]
[task 2019-11-04T23:25:28.065Z] 23:25:28 INFO - PID 18291 | --DOMWINDOW == 3 (0x7f6baefe7f20) [pid = 18377] [serial = 1] [outer = (nil)] [url = https://web-platform.test:8443/testharness_runner.html]
[task 2019-11-04T23:25:28.066Z] 23:25:28 INFO - PID 18291 | --DOCSHELL 0x7f6badc79000 == 0 [pid = 18377] [id = {83bfc9bd-987c-4c38-9218-1b68a8be7cf8}] [url = about:newtab]
[task 2019-11-04T23:25:29.983Z] 23:25:29 INFO - PID 18291 | WARNING: At least one completion condition is taking too long to complete. Conditions: [{"name":"ServiceWorkerShutdownBlocker: shutting down Service Workers","state":{"pendingPromises":1,"acceptingPromises":false},"filename":"/builds/worker/workspace/build/src/dom/serviceworkers/ServiceWorkerShutdownBlocker.cpp","lineNumber":82,"stack":"Service Workers shutdown"}] Barrier: profile-change-teardown
[task 2019-11-04T23:25:32.065Z] 23:25:32 INFO - PID 18291 | --DOMWINDOW == 2 (0x7f6baf0ed400) [pid = 18377] [serial = 8] [outer = (nil)] [url = http://web-platform.test:8000/testharness_runner.html]
[task 2019-11-04T23:25:32.065Z] 23:25:32 INFO - PID 18291 | --DOMWINDOW == 1 (0x7f6baa64f400) [pid = 18377] [serial = 9] [outer = (nil)] [url = https://web-platform.test:8443/testharness_runner.html]
[task 2019-11-04T23:25:32.065Z] 23:25:32 INFO - PID 18291 | --DOMWINDOW == 0 (0x7f6badc9bc00) [pid = 18377] [serial = 7] [outer = (nil)] [url = about:newtab]
[task 2019-11-04T23:25:34.880Z] 23:25:34 INFO - PID 18291 | console.error: (new Error("SessionFile is closed", "resource:///modules/sessionstore/SessionFile.jsm", 433))
[task 2019-11-04T23:26:20.989Z] 23:26:20 INFO - PID 18291 | FATAL ERROR: AsyncShutdown timeout in profile-change-teardown Conditions: [{"name":"ServiceWorkerShutdownBlocker: shutting down Service Workers","state":{"pendingPromises":1,"acceptingPromises":false},"filename":"/builds/worker/workspace/build/src/dom/serviceworkers/ServiceWorkerShutdownBlocker.cpp","lineNumber":82,"stack":"Service Workers shutdown"}] 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 2019-11-04T23:26:20.989Z] 23:26:20 INFO - PID 18291 | [Parent 18291, Main Thread] ###!!! ABORT: file /builds/worker/workspace/build/src/dom/serviceworkers/ServiceWorkerShutdownBlocker.cpp, line 82
[task 2019-11-04T23:26:46.598Z] 23:26:46 INFO - PID 18291 | #01: NS_InvokeByIndex
[task 2019-11-04T23:26:46.598Z] 23:26:46 INFO -
[task 2019-11-04T23:26:46.598Z] 23:26:46 INFO - PID 18291 | #02: CallMethodHelper::Call() [js/xpconnect/src/XPCWrappedNative.cpp:1183]
[task 2019-11-04T23:26:46.599Z] 23:26:46 INFO -
[task 2019-11-04T23:26:46.599Z] 23:26:46 INFO - PID 18291 | #03: XPCWrappedNative::CallMethod(XPCCallContext&, XPCWrappedNative::CallMode) [js/xpconnect/src/XPCWrappedNative.cpp:1149]
[task 2019-11-04T23:26:46.600Z] 23:26:46 INFO -
[task 2019-11-04T23:26:46.600Z] 23:26:46 INFO - PID 18291 | #04: XPC_WN_CallMethod(JSContext*, unsigned int, JS::Value*) [js/xpconnect/src/XPCWrappedNativeJSOps.cpp:946]
[task 2019-11-04T23:26:46.601Z] 23:26:46 INFO -
[task 2019-11-04T23:26:46.601Z] 23:26:46 INFO - PID 18291 | #05: CallJSNative(JSContext*, bool ()(JSContext, unsigned int, JS::Value*), js::CallReason, JS::CallArgs const&) [js/src/vm/Interpreter.cpp:456]
[task 2019-11-04T23:26:46.602Z] 23:26:46 INFO -
[task 2019-11-04T23:26:46.602Z] 23:26:46 INFO - PID 18291 | #06: js::InternalCallOrConstruct(JSContext*, JS::CallArgs const&, js::MaybeConstruct, js::CallReason) [js/src/vm/Interpreter.cpp:548]
[task 2019-11-04T23:26:46.602Z] 23:26:46 INFO -
[task 2019-11-04T23:26:46.606Z] 23:26:46 INFO - PID 18291 | #07: Interpret(JSContext*, js::RunState&) [js/src/vm/Interpreter.cpp:0]
[task 2019-11-04T23:26:46.606Z] 23:26:46 INFO -
[task 2019-11-04T23:26:46.607Z] 23:26:46 INFO - PID 18291 | #08: js::RunScript(JSContext*, js::RunState&) [js/src/vm/Interpreter.cpp:423]
[task 2019-11-04T23:26:46.607Z] 23:26:46 INFO -
[task 2019-11-04T23:26:46.607Z] 23:26:46 INFO - PID 18291 | #09: js::InternalCallOrConstruct(JSContext*, JS::CallArgs const&, js::MaybeConstruct, js::CallReason) [js/src/vm/Interpreter.cpp:589]
[task 2019-11-04T23:26:46.607Z] 23:26:46 INFO -
[task 2019-11-04T23:26:46.607Z] 23:26:46 INFO - PID 18291 | #10: <name omitted> [js/src/vm/Interpreter.cpp:634]
[task 2019-11-04T23:26:46.607Z] 23:26:46 INFO -
[task 2019-11-04T23:26:46.608Z] 23:26:46 INFO - PID 18291 | #11: js::Call(JSContext*, JS::Handle<JS::Value>, JS::Handle<JS::Value>, JS::Handle<JS::Value>, JS::MutableHandle<JS::Value>) [js/src/vm/Interpreter.h:104]
[task 2019-11-04T23:26:46.608Z] 23:26:46 INFO -
[task 2019-11-04T23:26:46.608Z] 23:26:46 INFO - PID 18291 | #12: PromiseReactionJob(JSContext*, unsigned int, JS::Value*) [js/src/builtin/Promise.cpp:1698]
[task 2019-11-04T23:26:46.608Z] 23:26:46 INFO -
[task 2019-11-04T23:26:46.608Z] 23:26:46 INFO - PID 18291 | #13: CallJSNative(JSContext*, bool ()(JSContext, unsigned int, JS::Value*), js::CallReason, JS::CallArgs const&) [js/src/vm/Interpreter.cpp:456]
[task 2019-11-04T23:26:46.608Z] 23:26:46 INFO -
[task 2019-11-04T23:26:46.608Z] 23:26:46 INFO - PID 18291 | #14: js::InternalCallOrConstruct(JSContext*, JS::CallArgs const&, js::MaybeConstruct, js::CallReason) [js/src/vm/Interpreter.cpp:548]
[task 2019-11-04T23:26:46.609Z] 23:26:46 INFO -
[task 2019-11-04T23:26:46.609Z] 23:26:46 INFO - PID 18291 | #15: <name omitted> [js/src/vm/Interpreter.cpp:634]
[task 2019-11-04T23:26:46.609Z] 23:26:46 INFO -
[task 2019-11-04T23:26:46.609Z] 23:26:46 INFO - PID 18291 | #16: JS::Call(JSContext*, JS::Handle<JS::Value>, JS::Handle<JS::Value>, JS::HandleValueArray const&, JS::MutableHandle<JS::Value>) [js/src/jsapi.cpp:2718]
[task 2019-11-04T23:26:46.609Z] 23:26:46 INFO -
[task 2019-11-04T23:26:46.609Z] 23:26:46 INFO - PID 18291 | #17: mozilla::dom::PromiseJobCallback::Call(JSContext*, JS::Handle<JS::Value>, mozilla::ErrorResult&) [s3:gecko-generated-sources:459bd68f053d4775f5b0b7c60fdedb096097672d24585038b4bb3482166c8e296d4679eb046b8f15653c228c4c1978ecacfffce20fced70b78964dafea2eee2d/dom/bindings/PromiseBinding.cpp::26]
[task 2019-11-04T23:26:46.609Z] 23:26:46 INFO -
[task 2019-11-04T23:26:46.610Z] 23:26:46 INFO - PID 18291 | #18: mozilla::dom::PromiseJobCallback::Call(mozilla::ErrorResult&, char const*, mozilla::dom::CallbackObject::ExceptionHandling, JS::Realm*) [s3:gecko-generated-sources:8ff597fee16137a41c5c768d4731e63150ba2f32aaccb2a1985be307f0fad868e61bb63f08de085a377133bcfcb41787e072b5d1f0cda75a29d00492f676fce1/dist/include/mozilla/dom/PromiseBinding.h::91]
[task 2019-11-04T23:26:46.610Z] 23:26:46 INFO -
[task 2019-11-04T23:26:46.610Z] 23:26:46 INFO - PID 18291 | #19: mozilla::PromiseJobRunnable::Run(mozilla::AutoSlowOperation&) [xpcom/base/CycleCollectedJSContext.cpp:209]
[task 2019-11-04T23:26:46.610Z] 23:26:46 INFO -
[task 2019-11-04T23:26:46.610Z] 23:26:46 INFO - PID 18291 | #20: mozilla::CycleCollectedJSContext::PerformMicroTaskCheckPoint(bool) [xpcom/base/CycleCollectedJSContext.cpp:630]
[task 2019-11-04T23:26:46.610Z] 23:26:46 INFO -
[task 2019-11-04T23:26:46.610Z] 23:26:46 INFO - PID 18291 | #21: mozilla::CycleCollectedJSContext::AfterProcessTask(unsigned int) [xpcom/base/CycleCollectedJSContext.cpp:462]
[task 2019-11-04T23:26:46.610Z] 23:26:46 INFO -
[task 2019-11-04T23:26:46.611Z] 23:26:46 INFO - PID 18291 | #22: XPCJSContext::AfterProcessTask(unsigned int) [js/xpconnect/src/XPCJSContext.cpp:1323]
[task 2019-11-04T23:26:46.611Z] 23:26:46 INFO -
[task 2019-11-04T23:26:46.611Z] 23:26:46 INFO - PID 18291 | #23: nsThread::ProcessNextEvent(bool, bool*) [xpcom/threads/nsThread.cpp:0]
[task 2019-11-04T23:26:46.611Z] 23:26:46 INFO -
[task 2019-11-04T23:26:46.611Z] 23:26:46 INFO - PID 18291 | #24: NS_InvokeByIndex
[task 2019-11-04T23:26:46.611Z] 23:26:46 INFO -
[task 2019-11-04T23:26:46.612Z] 23:26:46 INFO - PID 18291 | #25: CallMethodHelper::Call() [js/xpconnect/src/XPCWrappedNative.cpp:1183]
[task 2019-11-04T23:26:46.613Z] 23:26:46 INFO -
[task 2019-11-04T23:26:46.613Z] 23:26:46 INFO - PID 18291 | #26: XPCWrappedNative::CallMethod(XPCCallContext&, XPCWrappedNative::CallMode) [js/xpconnect/src/XPCWrappedNative.cpp:1149]
[task 2019-11-04T23:26:46.613Z] 23:26:46 INFO -
[task 2019-11-04T23:26:46.614Z] 23:26:46 INFO - PID 18291 | #27: XPC_WN_CallMethod(JSContext*, unsigned int, JS::Value*) [js/xpconnect/src/XPCWrappedNativeJSOps.cpp:946]
[task 2019-11-04T23:26:46.614Z] 23:26:46 INFO -
[task 2019-11-04T23:26:46.614Z] 23:26:46 INFO - PID 18291 | #28: ??? (???:???)
[task 2019-11-04T23:26:46.615Z] 23:26:46 INFO - PID 18291 | [Parent 18291, Main Thread] ###!!! ABORT: file /builds/worker/workspace/build/src/dom/serviceworkers/ServiceWorkerShutdownBlocker.cpp, line 82
[task 2019-11-04T23:26:46.615Z] 23:26:46 INFO - PID 18291 | Hit MOZ_CRASH() at /builds/worker/workspace/build/src/memory/mozalloc/mozalloc_abort.cpp:33
[task 2019-11-04T23:26:46.616Z] 23:26:46 INFO - PID 18291 | ExceptionHandler::GenerateDump cloned child 18805ExceptionHandler::WaitForContinueSignal waiting for continue signal...
[task 2019-11-04T23:26:46.617Z] 23:26:46 INFO - PID 18291 | ExceptionHandler::SendContinueSignalToChild sent continue signal to child
[task 2019-11-04T23:26:46.617Z] 23:26:46 INFO - PID 18291 | Exiting due to channel error.
[task 2019-11-04T23:26:46.617Z] 23:26:46 INFO - PID 18291 | Exiting due to channel error.
[task 2019-11-04T23:26:46.653Z] 23:26:46 INFO - Browser exited with return code 11

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.