1787366 - Intermittent TEST-UNEXPECTED-TIMEOUT | /webdriver/tests/bidi/log/entry_added/javascript.py | expected OK

Status: RESOLVED DUPLICATE of bug 1630162

(Remote Protocol :: Marionette, defect, P5)

Description

[Treeherder Bug Filer]

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

---

[task 2022-08-26T00:18:37.647Z] 00:18:37     INFO - PID 7056 | 1661473117644	RemoteAgent	TRACE	Received observer notification quit-application
[task 2022-08-26T00:18:37.649Z] 00:18:37     INFO - PID 7056 | 1661473117645	Marionette	DEBUG	0 <- [1,20,null,{"cause":"shutdown","forced":false}]
[task 2022-08-26T00:18:37.660Z] 00:18:37     INFO - PID 7056 | 1661473117662	RemoteAgent	TRACE	MessageHandler WINDOW_GLOBAL for session e082ec8c-e3f7-41a1-9648-a638b80a2e52 is being destroyed
[task 2022-08-26T00:18:37.664Z] 00:18:37     INFO - PID 7056 | 1661473117662	RemoteAgent	TRACE	Unregistered MessageHandler WINDOW_GLOBAL for session e082ec8c-e3f7-41a1-9648-a638b80a2e52
[task 2022-08-26T00:18:37.667Z] 00:18:37     INFO - PID 7056 | 1661473117665	RemoteAgent	DEBUG	Resetting recommended pref browser.contentblocking.features.standard
[task 2022-08-26T00:18:37.668Z] 00:18:37     INFO - PID 7056 | 1661473117666	RemoteAgent	DEBUG	Resetting recommended pref network.cookie.cookieBehavior
[task 2022-08-26T00:18:37.668Z] 00:18:37     INFO - PID 7056 | 1661473117666	webdriver::server	DEBUG	Teardown session
[task 2022-08-26T00:18:37.673Z] 00:18:37     INFO - PID 7056 | 1661473117671	Marionette	DEBUG	Closed connection 0
[task 2022-08-26T00:18:37.684Z] 00:18:37     INFO - PID 7056 | [Parent 5596, Main Thread] WARNING: ContentParent: id=1a346000 - BlockShutdown: CanSend.: file /builds/worker/checkouts/gecko/dom/ipc/ContentParent.cpp:3672
[task 2022-08-26T00:18:37.699Z] 00:18:37     INFO - PID 7056 | [Parent 5596, Main Thread] WARNING: ContentParent: id=1a346000 - ShutDownProcess: Sent shutdown message.: file /builds/worker/checkouts/gecko/dom/ipc/ContentParent.cpp:1804
[task 2022-08-26T00:18:37.700Z] 00:18:37     INFO - PID 7056 | [Parent 5596, Main Thread] WARNING: ContentParent: id=1d257700 - BlockShutdown: CanSend.: file /builds/worker/checkouts/gecko/dom/ipc/ContentParent.cpp:3672
[task 2022-08-26T00:18:37.701Z] 00:18:37     INFO - PID 7056 | [Parent 5596, Main Thread] WARNING: ContentParent: id=1d257700 - ShutDownProcess: Sent shutdown message.: file /builds/worker/checkouts/gecko/dom/ipc/ContentParent.cpp:1804
[task 2022-08-26T00:18:37.702Z] 00:18:37     INFO - PID 7056 | [Parent 5596, Main Thread] WARNING: ContentParent: id=1d259b00 - BlockShutdown: CanSend.: file /builds/worker/checkouts/gecko/dom/ipc/ContentParent.cpp:3672
[task 2022-08-26T00:18:37.702Z] 00:18:37     INFO - PID 7056 | [Parent 5596, Main Thread] WARNING: ContentParent: id=1d259b00 - ShutDownProcess: Sent shutdown message.: file /builds/worker/checkouts/gecko/dom/ipc/ContentParent.cpp:1804
[task 2022-08-26T00:18:37.703Z] 00:18:37     INFO - PID 7056 | [Parent 5596, Main Thread] WARNING: ContentParent: id=1d25aa00 - BlockShutdown: CanSend.: file /builds/worker/checkouts/gecko/dom/ipc/ContentParent.cpp:3672
[task 2022-08-26T00:18:37.704Z] 00:18:37     INFO - PID 7056 | [Parent 5596, Main Thread] WARNING: ContentParent: id=1d25aa00 - ShutDownProcess: Sent shutdown message.: file /builds/worker/checkouts/gecko/dom/ipc/ContentParent.cpp:1804
[task 2022-08-26T00:18:37.714Z] 00:18:37     INFO - PID 7056 | [Parent 5596, Main Thread] WARNING: ContentParent: id=1a346000 - ShutDownProcess: Closing channel.: file /builds/worker/checkouts/gecko/dom/ipc/ContentParent.cpp:1844
[task 2022-08-26T00:18:37.714Z] 00:18:37     INFO - PID 7056 | [Parent 5596, Main Thread] WARNING: ContentParent: id=1a346000 - RemoveShutdownBlockers: file /builds/worker/checkouts/gecko/dom/ipc/ContentParent.cpp:3787
[task 2022-08-26T00:18:37.716Z] 00:18:37     INFO - PID 7056 | [Parent 5596, Main Thread] WARNING: ContentParent: id=1d257700 - ShutDownProcess: Closing channel.: file /builds/worker/checkouts/gecko/dom/ipc/ContentParent.cpp:1844
[task 2022-08-26T00:18:37.717Z] 00:18:37     INFO - PID 7056 | [Parent 5596, Main Thread] WARNING: ContentParent: id=1d257700 - RemoveShutdownBlockers: file /builds/worker/checkouts/gecko/dom/ipc/ContentParent.cpp:3787
[task 2022-08-26T00:18:37.718Z] 00:18:37     INFO - PID 7056 | [Parent 5596, Main Thread] WARNING: ContentParent: id=1d259b00 - ShutDownProcess: Closing channel.: file /builds/worker/checkouts/gecko/dom/ipc/ContentParent.cpp:1844
[task 2022-08-26T00:18:37.719Z] 00:18:37     INFO - PID 7056 | [Parent 5596, Main Thread] WARNING: ContentParent: id=1d259b00 - RemoveShutdownBlockers: file /builds/worker/checkouts/gecko/dom/ipc/ContentParent.cpp:3787
[task 2022-08-26T00:18:37.720Z] 00:18:37     INFO - PID 7056 | [Parent 5596, Main Thread] WARNING: ContentParent: id=1d25aa00 - ShutDownProcess: Closing channel.: file /builds/worker/checkouts/gecko/dom/ipc/ContentParent.cpp:1844
[task 2022-08-26T00:18:37.720Z] 00:18:37     INFO - PID 7056 | [Parent 5596, Main Thread] WARNING: ContentParent: id=1d25aa00 - RemoveShutdownBlockers: file /builds/worker/checkouts/gecko/dom/ipc/ContentParent.cpp:3787
[task 2022-08-26T00:19:05.329Z] 00:19:05     INFO - TEST-UNEXPECTED-TIMEOUT | /webdriver/tests/bidi/log/entry_added/javascript.py | expected OK
[task 2022-08-26T00:19:05.329Z] 00:19:05     INFO - TEST-INFO took 30021ms
[task 2022-08-26T00:19:05.519Z] 00:19:05     INFO - Closing logging queue
[task 2022-08-26T00:19:05.528Z] 00:19:05     INFO - queue closed
[task 2022-08-26T00:19:06.039Z] 00:19:06     INFO - PID 8972 | 1661473145548	geckodriver	INFO	Listening on 127.0.0.1:49930
[task 2022-08-26T00:19:06.043Z] 00:19:06     INFO - Starting runner
[task 2022-08-26T00:19:06.712Z] 00:19:06     INFO - TEST-START | /webdriver/tests/bidi/log/entry_added/stacktrace.py

Comment 1

[Henrik Skupin [:whimboo][⌚️UTC+1]]

It' not clear what exactly causes this shutdown hang. As such duping to bug 1630162.

Comment 2

[BMO Automation]

Moving bug to Remote Protocol::Marionette component per bug 1815831.