Closed Bug 1782635 Opened 3 years ago Closed 3 years ago

Intermittent TEST-UNEXPECTED-TIMEOUT | /fetch/metadata/trailing-dot.https.sub.any.serviceworker.html | expected OK

Categories

(Core :: DOM: Networking, defect, P5)

Product:
Core
Component:
DOM: Networking
Type:
defect

Tracking

()

Status:
RESOLVED DUPLICATE of bug 1785684

People

(Reporter: intermittent-bug-filer, Unassigned)

References

Details

(Keywords: intermittent-failure)

Filed by: apavel [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=386058340&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/OkhymhQMQFCNcR5ybnZxNA/runs/0/artifacts/public/logs/live_backing.log

task 2022-08-01T22:58:40.984Z] 22:58:40     INFO - TEST-START | /fetch/metadata/trailing-dot.https.sub.any.serviceworker.html
[task 2022-08-01T22:58:40.989Z] 22:58:40     INFO - Closing window eff88720-ca5f-4641-8cb6-f0eb97350946
[task 2022-08-01T22:59:01.369Z] 22:59:01     INFO - TEST-UNEXPECTED-TIMEOUT | /fetch/metadata/trailing-dot.https.sub.any.serviceworker.html | expected OK
[task 2022-08-01T22:59:01.370Z] 22:59:01     INFO - TEST-INFO took 20387ms
[task 2022-08-01T22:59:01.372Z] 22:59:01     INFO - PID 7369 | 1659394741371	Marionette	INFO	Stopped listening on port 41377
[task 2022-08-01T22:59:09.435Z] 22:59:09     INFO - PID 7369 | [Parent 7369, Main Thread] WARNING: ContentParent: id=7f930a667f00 - BlockShutdown: CanSend.: file /builds/worker/checkouts/gecko/dom/ipc/ContentParent.cpp:3595
[task 2022-08-01T22:59:09.436Z] 22:59:09     INFO - PID 7369 | [Parent 7369, Main Thread] WARNING: ContentParent: id=7f930a667f00 - ShutDownProcess: Sent shutdown message.: file /builds/worker/checkouts/gecko/dom/ipc/ContentParent.cpp:1799
[task 2022-08-01T22:59:09.438Z] 22:59:09     INFO - PID 7369 | [Parent 7369, Main Thread] WARNING: ContentParent: id=7f930ed20500 - BlockShutdown: CanSend.: file /builds/worker/checkouts/gecko/dom/ipc/ContentParent.cpp:3595
[task 2022-08-01T22:59:09.440Z] 22:59:09     INFO - PID 7369 | [Parent 7369, Main Thread] WARNING: ContentParent: id=7f930ed20500 - ShutDownProcess: Sent shutdown message.: file /builds/worker/checkouts/gecko/dom/ipc/ContentParent.cpp:1799
[task 2022-08-01T22:59:09.440Z] 22:59:09     INFO - PID 7369 | [Parent 7369, Main Thread] WARNING: ContentParent: id=7f92f4af1600 - BlockShutdown: CanSend.: file /builds/worker/checkouts/gecko/dom/ipc/ContentParent.cpp:3595
[task 2022-08-01T22:59:09.440Z] 22:59:09     INFO - PID 7369 | [Parent 7369, Main Thread] WARNING: ContentParent: id=7f92f4af1600 - ShutDownProcess: Sent shutdown message.: file /builds/worker/checkouts/gecko/dom/ipc/ContentParent.cpp:1799
[task 2022-08-01T22:59:09.440Z] 22:59:09     INFO - PID 7369 | [Parent 7369, Main Thread] WARNING: ContentParent: id=7f92f3741600 - BlockShutdown: CanSend.: file /builds/worker/checkouts/gecko/dom/ipc/ContentParent.cpp:3595
[task 2022-08-01T22:59:09.441Z] 22:59:09     INFO - PID 7369 | [Parent 7369, Main Thread] WARNING: ContentParent: id=7f92f3741600 - ShutDownProcess: Sent shutdown message.: file /builds/worker/checkouts/gecko/dom/ipc/ContentParent.cpp:1799
[task 2022-08-01T22:59:11.632Z] 22:59:11     INFO - PID 7369 | WARNING: At least one completion condition is taking too long to complete. Conditions: [{"name":"MediaShutdownManager: shutdown","state":{"decoderInfo":"video/mp4, video/mp4, video/mp4, video/mp4, ","sInitPhase":3},"filename":"/builds/worker/checkouts/gecko/dom/media/MediaShutdownManager.cpp","lineNumber":71,"stack":"MediaShutdownManager shutdown"}] Barrier: xpcom-will-shutdown
[task 2022-08-01T22:59:16.591Z] 22:59:16     INFO - PID 7369 | console.error: (new Error("SessionFile is closed", "resource:///modules/sessionstore/SessionFile.jsm", 380))
[task 2022-08-01T22:59:19.438Z] 22:59:19     INFO - PID 7369 | WARNING: At least one completion condition is taking too long to complete. Conditions: [{"name":"ContentParent: id=7f930a667f00","state":{"remoteTypePrefix":"webServiceWorker"},"filename":"/builds/worker/checkouts/gecko/dom/ipc/ContentParent.cpp","lineNumber":3688,"stack":["resource://gre/modules/nsAsyncShutdown.jsm:addBlocker:164"]},{"name":"ContentParent: id=7f930ed20500","state":{"remoteTypePrefix":"prealloc"},"filename":"/builds/worker/checkouts/gecko/dom/ipc/ContentParent.cpp","lineNumber":3688,"stack":["resource://gre/modules/nsAsyncShutdown.jsm:addBlocker:164"]},{"name":"ContentParent: id=7f92f4af1600","state":{"remoteTypePrefix":"prealloc"},"filename":"/builds/worker/checkouts/gecko/dom/ipc/ContentParent.cpp","lineNumber":3688,"stack":["resource://gre/modules/nsAsyncShutdown.jsm:addBlocker:164"]},{"name":"ContentParent: id=7f92f3741600","state":{"remoteTypePrefix":"prealloc"},"filename":"/builds/worker/checkouts/gecko/dom/ipc/ContentParent.cpp","lineNumber":3688,"stack":["resource://gre/modules/nsAsyncShutdown.jsm:addBlocker:164"]}] Barrier: profile-before-change
[task 2022-08-01T23:00:02.633Z] 23:00:02     INFO - PID 7369 | FATAL ERROR: AsyncShutdown timeout in xpcom-will-shutdown Conditions: [{"name":"MediaShutdownManager: shutdown","state":{"decoderInfo":"video/mp4, video/mp4, video/mp4, video/mp4, ","sInitPhase":3},"filename":"/builds/worker/checkouts/gecko/dom/media/MediaShutdownManager.cpp","lineNumber":71,"stack":"MediaShutdownManager 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 2022-08-01T23:00:02.634Z] 23:00:02     INFO - PID 7369 | [Child 7612, Main Thread] ###!!! ABORT: file /builds/worker/checkouts/gecko/dom/media/MediaShutdownManager.cpp:71
[task 2022-08-01T23:00:10.438Z] 23:00:10     INFO - PID 7369 | FATAL ERROR: AsyncShutdown timeout in profile-before-change Conditions: [{"name":"ContentParent: id=7f930a667f00","state":{"remoteTypePrefix":"webServiceWorker"},"filename":"/builds/worker/checkouts/gecko/dom/ipc/ContentParent.cpp","lineNumber":3688,"stack":["resource://gre/modules/nsAsyncShutdown.jsm:addBlocker:164"]},{"name":"ContentParent: id=7f930ed20500","state":{"remoteTypePrefix":"prealloc"},"filename":"/builds/worker/checkouts/gecko/dom/ipc/ContentParent.cpp","lineNumber":3688,"stack":["resource://gre/modules/nsAsyncShutdown.jsm:addBlocker:164"]},{"name":"ContentParent: id=7f92f4af1600","state":{"remoteTypePrefix":"prealloc"},"filename":"/builds/worker/checkouts/gecko/dom/ipc/ContentParent.cpp","lineNumber":3688,"stack":["resource://gre/modules/nsAsyncShutdown.jsm:addBlocker:164"]},{"name":"ContentParent: id=7f92f3741600","state":{"remoteTypePrefix":"prealloc"},"filename":"/builds/worker/checkouts/gecko/dom/ipc/ContentParent.cpp","lineNumber":3688,"stack":["resource://gre/modules/nsAsyncShutdown.jsm:addBlocker:164"]}] 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 2022-08-01T23:00:10.439Z] 23:00:10     INFO - PID 7369 | [Parent 7369, Main Thread] ###!!! ABORT: file /builds/worker/checkouts/gecko/dom/ipc/ContentParent.cpp:3688
[task 2022-08-01T23:00:10.443Z] 23:00:10     INFO - PID 7369 | ExceptionHandler::GenerateDump cloned child 8583
[task 2022-08-01T23:00:10.444Z] 23:00:10     INFO - PID 7369 | ExceptionHandler::SendContinueSignalToChild sent continue signal to child
[task 2022-08-01T23:00:10.444Z] 23:00:10     INFO - PID 7369 | ExceptionHandler::WaitForContinueSignal waiting for continue signal...
[task 2022-08-01T23:00:12.418Z] 23:00:12     INFO - Browser exited with return code 11
[task 2022-08-01T23:00:12.422Z] 23:00:12     INFO - Closing logging queue
[task 2022-08-01T23:00:12.422Z] 23:00:12     INFO - queue closed
[task 2022-08-01T23:00:12.436Z] 23:00:12     INFO - Application command: /builds/worker/workspace/build/application/firefox/firefox --marionette about:blank -profile /tmp/tmp2p8b00nb
[task 2022-08-01T23:00:12.444Z] 23:00:12     INFO - PID 8103 | [CodeCoverage] Setting handlers for process 8103.
[task 2022-08-01T23:00:12.446Z] 23:00:12     INFO - PID 8103 | 1659394664401	Marionette	INFO	Marionette enabled
[task 2022-08-01T23:00:12.447Z] 23:00:12     INFO - PID 8103 | 1659394664407	Marionette	INFO	Listening on port 33243
[task 2022-08-01T23:00:12.447Z] 23:00:12     INFO - PID 8103 | [CodeCoverage] Setting handlers for process 8218.
[task 2022-08-01T23:00:12.448Z] 23:00:12     INFO - PID 8103 | [CodeCoverage] Setting handlers for process 8222.
[task 2022-08-01T23:00:12.449Z] 23:00:12     INFO - PID 8103 | console.warn: SearchSettings: "get: No settings file exists, new profile?" (new NotFoundError("Could not open the file at /tmp/tmpf1hyicpc/search.json.mozlz4", (void 0)))
[task 2022-08-01T23:00:12.449Z] 23:00:12     INFO - Starting runner
[task 2022-08-01T23:02:32.463Z] 23:02:32     INFO - Browser exited with return code -15
[task 2022-08-01T23:02:32.566Z] 23:02:32 CRITICAL - Loading initial page http://web-platform.test:8000/testharness_runner.html failed. Ensure that the there are no other programs bound to this port and that your firewall rules or network setup does not prevent access.
[task 2022-08-01T23:02:32.567Z] 23:02:32 CRITICAL - Traceback (most recent call last):
[task 2022-08-01T23:02:32.567Z] 23:02:32 CRITICAL -   File "/builds/worker/workspace/build/tests/web-platform/tests/tools/wptrunner/wptrunner/executors/executormarionette.py", line 166, in load_runner
[task 2022-08-01T23:02:32.567Z] 23:02:32 CRITICAL -     self.dismiss_alert(lambda: self.marionette.navigate(url))
[task 2022-08-01T23:02:32.567Z] 23:02:32 CRITICAL -   File "/builds/worker/workspace/build/tests/web-platform/tests/tools/wptrunner/wptrunner/executors/executormarionette.py", line 214, in dismiss_alert
[task 2022-08-01T23:02:32.567Z] 23:02:32 CRITICAL -     f()
[task 2022-08-01T23:02:32.567Z] 23:02:32 CRITICAL -   File "/builds/worker/workspace/build/tests/web-platform/tests/tools/wptrunner/wptrunner/executors/executormarionette.py", line 166, in <lambda>
[task 2022-08-01T23:02:32.567Z] 23:02:32 CRITICAL -     self.dismiss_alert(lambda: self.marionette.navigate(url))
[task 2022-08-01T23:02:32.567Z] 23:02:32 CRITICAL -   File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_driver/marionette.py", line 1572, in navigate
[task 2022-08-01T23:02:32.567Z] 23:02:32 CRITICAL -     self._send_message("WebDriver:Navigate", {"url": url})
[task 2022-08-01T23:02:32.567Z] 23:02:32 CRITICAL -   File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_driver/decorators.py", line 37, in _
[task 2022-08-01T23:02:32.567Z] 23:02:32 CRITICAL -     m._handle_socket_failure()
[task 2022-08-01T23:02:32.567Z] 23:02:32 CRITICAL -   File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_driver/marionette.py", line 710, in _handle_socket_failure
[task 2022-08-01T23:02:32.567Z] 23:02:32 CRITICAL -     reraise(exc_cls, exc, tb)
[task 2022-08-01T23:02:32.567Z] 23:02:32 CRITICAL -   File "/builds/worker/workspace/build/tests/web-platform/tests/tools/third_party/six/six.py", line 703, in reraise
[task 2022-08-01T23:02:32.567Z] 23:02:32 CRITICAL -     raise value
[task 2022-08-01T23:02:32.567Z] 23:02:32 CRITICAL -   File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_driver/decorators.py", line 27, in _
[task 2022-08-01T23:02:32.567Z] 23:02:32 CRITICAL -     return func(*args, **kwargs)
[task 2022-08-01T23:02:32.567Z] 23:02:32 CRITICAL -   File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_driver/marionette.py", line 659, in _send_message
[task 2022-08-01T23:02:32.567Z] 23:02:32 CRITICAL -     msg = self.client.request(name, params)
[task 2022-08-01T23:02:32.567Z] 23:02:32 CRITICAL -   File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_driver/transport.py", line 383, in request
[task 2022-08-01T23:02:32.567Z] 23:02:32 CRITICAL -     return self.receive()
[task 2022-08-01T23:02:32.567Z] 23:02:32 CRITICAL -   File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_driver/transport.py", line 230, in receive
[task 2022-08-01T23:02:32.567Z] 23:02:32 CRITICAL -     raise socket.error("No data received over socket")
[task 2022-08-01T23:02:32.567Z] 23:02:32 CRITICAL - OSError: No data received over socket
[task 2022-08-01T23:02:32.567Z] 23:02:32 CRITICAL - 
[task 2022-08-01T23:02:32.567Z] 23:02:32  WARNING - Command left in command_queue during cleanup: 'init_failed', ()
[task 2022-08-01T23:02:32.568Z] 23:02:32     INFO - Closing logging queue
[task 2022-08-01T23:02:32.568Z] 23:02:32     INFO - queue closed
[task 2022-08-01T23:02:32.584Z] 23:02:32     INFO - Application command: /builds/worker/workspace/build/application/firefox/firefox --marionette about:blank -profile /tmp/tmppp8clzxh
[task 2022-08-01T23:02:32.609Z] 23:02:32     INFO - PID 8588 | [CodeCoverage] Setting handlers for process 8588.
[task 2022-08-01T23:02:32.609Z] 23:02:32     INFO - PID 8588 | 1659394813380	Marionette	INFO	Marionette enabled
[task 2022-08-01T23:02:32.609Z] 23:02:32     INFO - PID 8588 | 1659394813384	Marionette	INFO	Listening on port 40530
[task 2022-08-01T23:02:32.609Z] 23:02:32     INFO - PID 8588 | console.warn: SearchSettings: "get: No settings file exists, new profile?" (new NotFoundError("Could not open the file at /tmp/tmp2p8b00nb/search.json.mozlz4", (void 0)))
[task 2022-08-01T23:02:32.609Z] 23:02:32     INFO - Starting runner
[task 2022-08-01T23:02:33.769Z] 23:02:33     INFO - PID 8588 | [CodeCoverage] Setting handlers for process 8690.
[task 2022-08-01T23:02:33.806Z] 23:02:33     INFO - PID 8588 | [CodeCoverage] Setting handlers for process 8695.
[task 2022-08-01T23:02:35.092Z] 23:02:35     INFO - PID 8588 | [CodeCoverage] Setting handlers for process 8845.
Status: NEW → RESOLVED
Closed: 3 years ago
Resolution: --- → DUPLICATE
You need to log in before you can comment on or make changes to this bug.