1752518 - Intermittent Assertion failure: false (Please ensure to IPC_FAIL only when in an unrecoverable, unexpected state.), at /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:68

Status: RESOLVED FIXED

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

Description

[Treeherder Bug Filer]

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

---

[task 2022-01-28T10:31:04.620Z] 10:31:04     INFO - TEST-OK | devtools/client/webconsole/test/browser/browser_console_window_object_inheritance.js | took 11122ms
[task 2022-01-28T10:31:04.659Z] 10:31:04     INFO - GECKO(4746) | [Child 5241: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 7f61b9a62c00 == 1 [pid = 5241] [id = 3]
[task 2022-01-28T10:31:04.660Z] 10:31:04     INFO - GECKO(4746) | [Child 5241: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 1 (7f61b9a29740) [pid = 5241] [serial = 10] [outer = 0]
[task 2022-01-28T10:31:04.661Z] 10:31:04     INFO - GECKO(4746) | [Child 5241: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 2 (7f61b9a63000) [pid = 5241] [serial = 11] [outer = 7f61b9a29740]
[task 2022-01-28T10:31:04.689Z] 10:31:04     INFO - GECKO(4746) | [Parent 4746, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, false) failed with result 0x804B0050 (NS_ERROR_INSUFFICIENT_DOMAIN_LEVELS): file /builds/worker/checkouts/gecko/toolkit/components/antitracking/URLQueryStringStripper.cpp:129
[task 2022-01-28T10:31:04.694Z] 10:31:04     INFO - GECKO(4746) | [Child 5241, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, false) failed with result 0x804B0050 (NS_ERROR_INSUFFICIENT_DOMAIN_LEVELS): file /builds/worker/checkouts/gecko/toolkit/components/antitracking/URLQueryStringStripper.cpp:129
[task 2022-01-28T10:31:04.738Z] 10:31:04     INFO - GECKO(4746) | [Child 5241, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, false) failed with result 0x804B0050 (NS_ERROR_INSUFFICIENT_DOMAIN_LEVELS): file /builds/worker/checkouts/gecko/toolkit/components/antitracking/URLQueryStringStripper.cpp:129
[task 2022-01-28T10:31:04.847Z] 10:31:04     INFO - checking window state
[task 2022-01-28T10:31:05.035Z] 10:31:05     INFO - GECKO(4746) | [Parent 4746: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 25 (7f3e507f4000) [pid = 4746] [serial = 117] [outer = 7f3e6cd37040]
[task 2022-01-28T10:31:05.123Z] 10:31:05     INFO - GECKO(4746) | [Parent 4746, Main Thread] WARNING: NS_ENSURE_TRUE(presShell) failed: file /builds/worker/checkouts/gecko/dom/base/nsGlobalWindowOuter.cpp:4233
[task 2022-01-28T10:31:05.160Z] 10:31:05     INFO - GECKO(4746) | [Parent 4746: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 26 (7f3e507e6c00) [pid = 4746] [serial = 118] [outer = 7f3e6cd37040]
[task 2022-01-28T10:31:05.261Z] 10:31:05     INFO - GECKO(4746) | JavaScript error: , line 0: NotFoundError: No such JSWindowActor 'DevToolsFrame'
[task 2022-01-28T10:31:05.281Z] 10:31:05     INFO - GECKO(4746) | [Child 4903: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 7fc03a960000 == 1 [pid = 4903] [id = 19] [url = about:blank]
[task 2022-01-28T10:31:05.301Z] 10:31:05     INFO - Console message: [JavaScript Error: "NotFoundError: No such JSWindowActor 'DevToolsFrame'"]
[task 2022-01-28T10:31:05.485Z] 10:31:05     INFO - GECKO(4746) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmpz3wb3zq5.mozrunner/runtests_leaks_tab_pid5430.log
[task 2022-01-28T10:31:05.487Z] 10:31:05     INFO - GECKO(4746) | [5430, Main Thread] WARNING: XPCOM_MEM_BLOAT_LOG is set, disabling native allocations.: file /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp:254
[task 2022-01-28T10:31:05.632Z] 10:31:05     INFO - GECKO(4746) | [Child 5430, Main Thread] WARNING: could not set real-time limit in CubebUtils::InitLibrary: file /builds/worker/checkouts/gecko/dom/media/CubebUtils.cpp:693
[task 2022-01-28T10:31:13.072Z] 10:31:13     INFO - GECKO(4746) | [Child 4821: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 7fe6f4721000 == 0 [pid = 4821] [id = 21] [url = about:blank]
[task 2022-01-28T10:31:13.682Z] 10:31:13     INFO - GECKO(4746) | [Child 4841: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 10 (7f686d6a7400) [pid = 4841] [serial = 30] [outer = 0] [url = moz-extension://2cc470a9-e21d-4097-afdb-05f7c77d6cd2/_generated_background_page.html]
[task 2022-01-28T10:31:13.693Z] 10:31:13     INFO - GECKO(4746) | [Child 4868: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 7feace0cdc00 == 0 [pid = 4868] [id = 0] [url = about:newtab]
[task 2022-01-28T10:31:13.701Z] 10:31:13     INFO - GECKO(4746) | [Child 4868, Main Thread] WARNING: NS_ENSURE_TRUE(!mHasOrHasHadOwnerWindow || mOwnerWindow) failed: file /builds/worker/checkouts/gecko/dom/events/DOMEventTargetHelper.cpp:307
[task 2022-01-28T10:31:15.084Z] 10:31:15     INFO - GECKO(4746) | [Child 4903: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 7fc03a964c00 == 0 [pid = 4903] [id = 20] [url = about:blank]
[task 2022-01-28T10:31:16.311Z] 10:31:16     INFO - GECKO(4746) | [Child 4821: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 1 (7fe6f4721400) [pid = 4821] [serial = 54] [outer = 0] [url = about:blank]
[task 2022-01-28T10:31:16.314Z] 10:31:16     INFO - GECKO(4746) | [Child 4821: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 0 (7fe6f59c5040) [pid = 4821] [serial = 53] [outer = 0] [url = about:blank]
[task 2022-01-28T10:31:17.649Z] 10:31:17     INFO - GECKO(4746) | [Child 4903: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 4 (7fc03a961c00) [pid = 4903] [serial = 47] [outer = 0] [url = about:blank]
[task 2022-01-28T10:31:17.650Z] 10:31:17     INFO - GECKO(4746) | [Child 4903: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 3 (7fc03a965000) [pid = 4903] [serial = 49] [outer = 0] [url = about:blank]
[task 2022-01-28T10:31:17.651Z] 10:31:17     INFO - GECKO(4746) | [Child 4903: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 2 (7fc055a7d740) [pid = 4903] [serial = 46] [outer = 0] [url = about:blank]
[task 2022-01-28T10:31:17.652Z] 10:31:17     INFO - GECKO(4746) | [Child 4903: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 1 (7fc055a7d900) [pid = 4903] [serial = 48] [outer = 0] [url = about:blank]
[task 2022-01-28T10:31:17.653Z] 10:31:17     INFO - GECKO(4746) | [Child 4903: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 0 (7fc03a966400) [pid = 4903] [serial = 50] [outer = 0] [url = about:blank]
[task 2022-01-28T10:31:19.856Z] 10:31:19     INFO - GECKO(4746) | [Parent 4746: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 7f3e58f8d000 == 6 [pid = 4746] [id = 53] [url = about:blank]
[task 2022-01-28T10:31:19.857Z] 10:31:19     INFO - GECKO(4746) | [Parent 4746: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 7f3e528cd800 == 5 [pid = 4746] [id = 52] [url = chrome://devtools/content/webconsole/index.html]
[task 2022-01-28T10:31:20.523Z] 10:31:20     INFO - GECKO(4746) | [Child 4868: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 1 (7feae8a7d740) [pid = 4868] [serial = 1] [outer = 0] [url = about:newtab]
[task 2022-01-28T10:31:23.121Z] 10:31:23     INFO - GECKO(4746) | Assertion failure: false (Please ensure to IPC_FAIL only when in an unrecoverable, unexpected state.), at /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:68
[task 2022-01-28T10:31:23.138Z] 10:31:23     INFO -  Initializing stack-fixing for the first stack frame, this may take a while...
[task 2022-01-28T10:31:30.149Z] 10:31:30     INFO - GECKO(4746) | #01: mozilla::ipc::IPCResult::Fail(mozilla::NotNull<mozilla::ipc::IProtocol*>, char const*, char const*) [ipc/glue/ProtocolUtils.cpp:66]
[task 2022-01-28T10:31:30.150Z] 10:31:30     INFO - GECKO(4746) | #02: mozilla::ipc::PBackgroundParent::OnMessageReceived(IPC::Message const&) [s3:gecko-generated-sources:b08aa34787ec758599ed2e4f02a3f1d3ca0a5ef76a807da8c233e475390b0e4b13ce8abd3ce7b7fc829b0627c92dbd3d02428e443d302c0180d02c0bc83c0bfa/ipc/ipdl/PBackgroundParent.cpp::6379]
[task 2022-01-28T10:31:30.151Z] 10:31:30     INFO - GECKO(4746) | #03: mozilla::ipc::MessageChannel::DispatchAsyncMessage(mozilla::ipc::ActorLifecycleProxy*, IPC::Message const&) [ipc/glue/MessageChannel.cpp:1658]
[task 2022-01-28T10:31:30.152Z] 10:31:30     INFO - GECKO(4746) | #04: mozilla::ipc::MessageChannel::DispatchMessage(IPC::Message&&) [ipc/glue/MessageChannel.cpp:1586]
[task 2022-01-28T10:31:30.152Z] 10:31:30     INFO - GECKO(4746) | #05: mozilla::ipc::MessageChannel::RunMessage(mozilla::ipc::MessageChannel::MessageTask&) [ipc/glue/MessageChannel.cpp:1452]
[task 2022-01-28T10:31:30.153Z] 10:31:30     INFO - GECKO(4746) | #06: mozilla::ipc::MessageChannel::MessageTask::Run() [ipc/glue/MessageChannel.cpp:1482]
[task 2022-01-28T10:31:30.154Z] 10:31:30     INFO - GECKO(4746) | #07: nsThread::ProcessNextEvent(bool, bool*) [xpcom/threads/nsThread.cpp:1190]
[task 2022-01-28T10:31:30.155Z] 10:31:30     INFO - GECKO(4746) | #08: NS_ProcessNextEvent(nsIThread*, bool) [xpcom/threads/nsThreadUtils.cpp:467]
[task 2022-01-28T10:31:30.155Z] 10:31:30     INFO - GECKO(4746) | #09: mozilla::ipc::MessagePumpForNonMainThreads::Run(base::MessagePump::Delegate*) [ipc/glue/MessagePump.cpp:301]
[task 2022-01-28T10:31:30.156Z] 10:31:30     INFO - GECKO(4746) | #10: MessageLoop::RunInternal() [ipc/chromium/src/base/message_loop.cc:331]
[task 2022-01-28T10:31:30.157Z] 10:31:30     INFO - GECKO(4746) | #11: MessageLoop::Run() [ipc/chromium/src/base/message_loop.cc:307]
[task 2022-01-28T10:31:30.158Z] 10:31:30     INFO - GECKO(4746) | #12: nsThread::ThreadFunc(void*) [xpcom/threads/nsThread.cpp:393]
[task 2022-01-28T10:31:30.165Z] 10:31:30     INFO - GECKO(4746) | #13: _pt_root [nsprpub/pr/src/pthreads/ptthread.c:204]
[task 2022-01-28T10:31:30.166Z] 10:31:30     INFO - GECKO(4746) | #14: ??? [/lib/x86_64-linux-gnu/libpthread.so.0 + 0x76db]
[task 2022-01-28T10:31:30.173Z] 10:31:30     INFO - GECKO(4746) | #15: clone [/lib/x86_64-linux-gnu/libc.so.6 + 0x121a3f]
[task 2022-01-28T10:31:30.174Z] 10:31:30     INFO - GECKO(4746) | #16: ??? (???:???)
[task 2022-01-28T10:31:30.174Z] 10:31:30     INFO - GECKO(4746) | ###!!! [Parent][PCompositorManagerParent] Error: RunMessage(msgname=PCompositorBridge::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
[task 2022-01-28T10:31:30.175Z] 10:31:30     INFO - GECKO(4746) | ###!!! [Parent][PImageBridgeParent] Error: RunMessage(msgname=PImageBridge::Msg_WillClose) Channel closing: too late to send/recv, messages will be lost
[task 2022-01-28T10:31:30.176Z] 10:31:30     INFO - GECKO(4746) | [Child 5430, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_StartedGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:499
[task 2022-01-28T10:31:30.176Z] 10:31:30     INFO - GECKO(4746) | [Child 5430, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_DoneGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:499
[task 2022-01-28T10:31:30.177Z] 10:31:30     INFO - GECKO(4746) | ExceptionHandler::GenerateDump cloned child 5452
[task 2022-01-28T10:31:30.177Z] 10:31:30     INFO - GECKO(4746) | ExceptionHandler::SendContinueSignalToChild sent continue signal to child
[task 2022-01-28T10:31:30.178Z] 10:31:30     INFO - GECKO(4746) | [Child 5430, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_StartedGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:499
[task 2022-01-28T10:31:30.179Z] 10:31:30     INFO - GECKO(4746) | ExceptionHandler::WaitForContinueSignal waiting for continue signal...
[task 2022-01-28T10:31:30.179Z] 10:31:30     INFO - GECKO(4746) | [Child 5430, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_DoneGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:499
[task 2022-01-28T10:31:30.181Z] 10:31:30     INFO - GECKO(4746) | [Child 5430, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/checkouts/gecko/xpcom/base/nsCycleCollector.cpp:3351
[task 2022-01-28T10:31:30.181Z] 10:31:30     INFO - GECKO(4746) | [Child 5430, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_StartedGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:499
[task 2022-01-28T10:31:30.182Z] 10:31:30     INFO - GECKO(4746) | [Child 5430, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_DoneGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:499
[task 2022-01-28T10:31:30.183Z] 10:31:30     INFO - GECKO(4746) | [Child 5430, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_StartedGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:499
[task 2022-01-28T10:31:30.183Z] 10:31:30     INFO - GECKO(4746) | [Child 5430, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_DoneGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:499
[task 2022-01-28T10:31:30.184Z] 10:31:30     INFO - GECKO(4746) | [Child 5430, Main Thread] WARNING: NS_ENSURE_TRUE(Preferences::InitStaticMembers()) failed: file /builds/worker/checkouts/gecko/modules/libpref/Preferences.cpp:4448
[task 2022-01-28T10:31:30.185Z] 10:31:30     INFO - GECKO(4746) | [2022-01-28T10:31:23Z WARN  webrender::device::gl] Missing optimized shader source for gpu_cache_update
[task 2022-01-28T10:31:30.185Z] 10:31:30     INFO - GECKO(4746) | [Child 4868, IPC I/O Child] WARNING: [2D25ACBA90B6BDF6.4385032C6EB6DBD5]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:349
[task 2022-01-28T10:31:30.186Z] 10:31:30     INFO - GECKO(4746) | [Child 4868, IPC I/O Child] WARNING: [2D25ACBA90B6BDF6.4385032C6EB6DBD5]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:349
[task 2022-01-28T10:31:30.186Z] 10:31:30     INFO - GECKO(4746) | [Child 4868, IPC I/O Child] WARNING: [2D25ACBA90B6BDF6.4385032C6EB6DBD5]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:349
[task 2022-01-28T10:31:30.187Z] 10:31:30     INFO - GECKO(4746) | [Child 5241, IPC I/O Child] WARNING: [248B0DD365E312BC.39181261E8840620]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:349
[task 2022-01-28T10:31:30.187Z] 10:31:30     INFO - GECKO(4746) | [Child 4868, IPC I/O Child] WARNING: [2D25ACBA90B6BDF6.4385032C6EB6DBD5]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:349
[task 2022-01-28T10:31:30.187Z] 10:31:30     INFO - GECKO(4746) | [Child 5241, IPC I/O Child] WARNING: [248B0DD365E312BC.39181261E8840620]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:349
[task 2022-01-28T10:31:30.188Z] 10:31:30     INFO - GECKO(4746) | [Child 5241, IPC I/O Child] WARNING: [248B0DD365E312BC.39181261E8840620]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:349
[task 2022-01-28T10:31:30.188Z] 10:31:30     INFO - GECKO(4746) | [Child 4868, IPC I/O Child] WARNING: [2D25ACBA90B6BDF6.4385032C6EB6DBD5]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:349
[task 2022-01-28T10:31:30.188Z] 10:31:30     INFO - GECKO(4746) | [Child 5241, IPC I/O Child] WARNING: [248B0DD365E312BC.39181261E8840620]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:349
[task 2022-01-28T10:31:30.189Z] 10:31:30     INFO - GECKO(4746) | [Child 4868, IPC I/O Child] WARNING: [2D25ACBA90B6BDF6.4385032C6EB6DBD5]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:349
[task 2022-01-28T10:31:30.189Z] 10:31:30     INFO - GECKO(4746) | [Child 5241, IPC I/O Child] WARNING: [248B0DD365E312BC.39181261E8840620]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:349
[task 2022-01-28T10:31:30.189Z] 10:31:30     INFO - GECKO(4746) | [Child 4868, IPC I/O Child] WARNING: [2D25ACBA90B6BDF6.4385032C6EB6DBD5]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:349
[task 2022-01-28T10:31:30.190Z] 10:31:30     INFO - GECKO(4746) | Exiting due to channel error.
[task 2022-01-28T10:31:30.190Z] 10:31:30     INFO - GECKO(4746) | [Child 5241, IPC I/O Child] WARNING: [248B0DD365E312BC.39181261E8840620]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:349
[task 2022-01-28T10:31:30.190Z] 10:31:30     INFO - GECKO(4746) | [Child 5241, IPC I/O Child] WARNING: [248B0DD365E312BC.39181261E8840620]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:349
[task 2022-01-28T10:31:30.191Z] 10:31:30     INFO - GECKO(4746) | Exiting due to channel error.
[task 2022-01-28T10:31:30.191Z] 10:31:30     INFO - GECKO(4746) | [Child 4903, IPC I/O Child] WARNING: [1FD2868D3D94ACE6.3CF982BE6FC66740]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:349
[task 2022-01-28T10:31:30.191Z] 10:31:30     INFO - GECKO(4746) | [Child 4903, IPC I/O Child] WARNING: [1FD2868D3D94ACE6.3CF982BE6FC66740]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:349
[task 2022-01-28T10:31:30.194Z] 10:31:30     INFO - GECKO(4746) | [Child 4903, IPC I/O Child] WARNING: [1FD2868D3D94ACE6.3CF982BE6FC66740]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:349
[task 2022-01-28T10:31:30.194Z] 10:31:30     INFO - GECKO(4746) | [Child 4903, IPC I/O Child] WARNING: [1FD2868D3D94ACE6.3CF982BE6FC66740]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:349
[task 2022-01-28T10:31:30.195Z] 10:31:30     INFO - GECKO(4746) | [Child 4903, IPC I/O Child] WARNING: [1FD2868D3D94ACE6.3CF982BE6FC66740]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:349
[task 2022-01-28T10:31:30.195Z] 10:31:30     INFO - GECKO(4746) | Exiting due to channel error.
[task 2022-01-28T10:31:30.195Z] 10:31:30     INFO - GECKO(4746) | [Child 4841, IPC I/O Child] WARNING: [E38CA8D8BE367C90.E7AB5A7D1018173E]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:349
[task 2022-01-28T10:31:30.195Z] 10:31:30     INFO - GECKO(4746) | [Child 4841, IPC I/O Child] WARNING: [E38CA8D8BE367C90.E7AB5A7D1018173E]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:349
[task 2022-01-28T10:31:30.200Z] 10:31:30     INFO - GECKO(4746) | [Child 4841, IPC I/O Child] WARNING: [E38CA8D8BE367C90.E7AB5A7D1018173E]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:349
[task 2022-01-28T10:31:30.201Z] 10:31:30     INFO - GECKO(4746) | [Child 4841, IPC I/O Child] WARNING: [E38CA8D8BE367C90.E7AB5A7D1018173E]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:349
[task 2022-01-28T10:31:30.201Z] 10:31:30     INFO - GECKO(4746) | [Child 4841, IPC I/O Child] WARNING: [E38CA8D8BE367C90.E7AB5A7D1018173E]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:349
[task 2022-01-28T10:31:30.202Z] 10:31:30     INFO - GECKO(4746) | [Child 4841, IPC I/O Child] WARNING: [E38CA8D8BE367C90.E7AB5A7D1018173E]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:349
[task 2022-01-28T10:31:30.202Z] 10:31:30     INFO - GECKO(4746) | [Child 4841, IPC I/O Child] WARNING: [E38CA8D8BE367C90.E7AB5A7D1018173E]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:349
[task 2022-01-28T10:31:30.203Z] 10:31:30     INFO - GECKO(4746) | [Child 4841, IPC I/O Child] WARNING: [E38CA8D8BE367C90.E7AB5A7D1018173E]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:349
[task 2022-01-28T10:31:30.203Z] 10:31:30     INFO - GECKO(4746) | [Child 4841, IPC I/O Child] WARNING: [E38CA8D8BE367C90.E7AB5A7D1018173E]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:349
[task 2022-01-28T10:31:30.204Z] 10:31:30     INFO - GECKO(4746) | Exiting due to channel error.
[task 2022-01-28T10:31:30.204Z] 10:31:30     INFO - GECKO(4746) | [Child 4821, IPC I/O Child] WARNING: [2135F9EFDB25A61D.95C464599F9DA928]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:349
[task 2022-01-28T10:31:30.204Z] 10:31:30     INFO - GECKO(4746) | [Child 4821, IPC I/O Child] WARNING: [2135F9EFDB25A61D.95C464599F9DA928]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:349
[task 2022-01-28T10:31:30.205Z] 10:31:30     INFO - GECKO(4746) | [Child 4821, IPC I/O Child] WARNING: [2135F9EFDB25A61D.95C464599F9DA928]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:349
[task 2022-01-28T10:31:30.205Z] 10:31:30     INFO - GECKO(4746) | [Child 4821, IPC I/O Child] WARNING: [2135F9EFDB25A61D.95C464599F9DA928]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:349
[task 2022-01-28T10:31:30.206Z] 10:31:30     INFO - GECKO(4746) | [Child 4821, IPC I/O Child] WARNING: [2135F9EFDB25A61D.95C464599F9DA928]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:349
[task 2022-01-28T10:31:30.206Z] 10:31:30     INFO - GECKO(4746) | [Child 4821, IPC I/O Child] WARNING: [2135F9EFDB25A61D.95C464599F9DA928]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:349
[task 2022-01-28T10:31:30.207Z] 10:31:30     INFO - GECKO(4746) | [Child 4821, IPC I/O Child] WARNING: [2135F9EFDB25A61D.95C464599F9DA928]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:349
[task 2022-01-28T10:31:30.207Z] 10:31:30     INFO - GECKO(4746) | [Child 4821, IPC I/O Child] WARNING: [2135F9EFDB25A61D.95C464599F9DA928]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:349
[task 2022-01-28T10:31:30.208Z] 10:31:30     INFO - GECKO(4746) | [Child 4821, IPC I/O Child] WARNING: [2135F9EFDB25A61D.95C464599F9DA928]: Ignoring message 'EVENT_MESSAGE' to peer 1.1 due to a missing broker: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:349
[task 2022-01-28T10:31:30.209Z] 10:31:30     INFO - GECKO(4746) | Exiting due to channel error.
[task 2022-01-28T10:31:30.209Z] 10:31:30     INFO - TEST-INFO | Main app process: exit 11
[task 2022-01-28T10:31:30.210Z] 10:31:30    ERROR - TEST-UNEXPECTED-FAIL | ShutdownLeaks | process() called before end of test suite
[task 2022-01-28T10:31:30.211Z] 10:31:30     INFO - TEST-INFO | Confirming we saw 121 DOCSHELL created and 110 destroyed log strings.

Comment 1

[Jed Davis [:jld] ⟨⏰|UTC-7⟩ ⟦he/him⟧]

(In reply to Treeherder Bug Filer from comment #0)

#01: mozilla::ipc::IPCResult::Fail(mozilla::NotNull<mozilla::ipc::IProtocol*>, char const*, char const*) [ipc/glue/ProtocolUtils.cpp:66]
#02: mozilla::ipc::PBackgroundParent::OnMessageReceived(IPC::Message const&) [s3:gecko-generated-sources:…/ipc/ipdl/PBackgroundParent.cpp::6379]

That's less than entirely helpful because of inlining, but like 6379 of that generated file is currently this:

if ((!((this)->RecvPRemoteLazyInputStreamConstructor(actor, std::move(aID), std::move(aSize))))) {

Which brings us to this IPC_FAIL, and this method that it's calling. Sending this over to DOM:File because that seems to be where things start going wrong.

Comment 2

[Intermittent Failures Robot]

6 failures in 3445 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 1
• autoland: 5

Platform and build breakdown:

• linux1804-64-qr: 4
  • debug: 4
• windows10-64-2004-qr: 1
  • debug: 1
• macosx1015-64-qr: 1
  • debug: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1752518&startday=2022-01-24&endday=2022-01-30&tree=all

Comment 3

[Intermittent Failures Robot]

14 failures in 3165 pushes (0.004 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 9
• mozilla-central: 4
• try: 1

Platform and build breakdown:

• linux1804-64-qr: 10
  • debug: 10
• macosx1015-64-qr: 2
  • debug: 2
• windows10-64-2004-qr: 1
  • debug: 1
• linux1804-64-domstreams-qr: 1
  • debug: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1752518&startday=2022-01-31&endday=2022-02-06&tree=all

Comment 4

[Intermittent Failures Robot]

6 failures in 3711 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 6

Platform and build breakdown:

• windows10-64-2004-qr: 1
  • debug: 1
• linux1804-64-qr: 3
  • debug: 3
• linux1804-64-asan-qr: 1
  • opt: 1
• macosx1015-64-qr: 1
  • debug: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1752518&startday=2022-02-07&endday=2022-02-13&tree=all

Comment 5

[Jens Stutte [:jstutte]]

(In reply to Jed Davis [:jld] ⟨⏰|UTC-7⟩ ⟦he/him⟧ from comment #1)

Which brings us to this IPC_FAIL, and this method that it's calling. Sending this over to DOM:File because that seems to be where things start going wrong.

Thanks for the pointers! That brings us to the RemoteLazyInputStreamStorage singleton which is removed on "xpcom-shutdown".

Being shutdown an expected state, we should probably not IPC_FAIL if RemoteLazyInputStreamStorage::Get() returned a nullptr. The question would be: Should the caller be informed that something went wrong here?

In any case this feeds into bug 1755245 and should be treated there.

Comment 6

[Jens Stutte [:jstutte]]

Actually we are in ipc/glue land here, so I'll put a patch here.

Comment 7

[Jens Stutte [:jstutte]]

Attachment: Bug 1752518: No need to ever IPC_FAIL on RemoteLazyInputStream creation. r?#dom-storage-reviewers

Comment 8

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/ce6ff2779892
No need to ever IPC_FAIL on RemoteLazyInputStream creation. r=dom-storage-reviewers,necko-reviewers,kershaw,janv

Comment 9

[Iulian Moraru]

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

Comment 10

[Sandor Molnar[:smolnar]]

This is still happening
Failure log

Comment 11

[Jens Stutte [:jstutte]]

This is probably just a different case, but let's keep them all on this intermittent.

Comment 12

[Intermittent Failures Robot]

6 failures in 3281 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 2
• autoland: 4

Platform and build breakdown:

• linux1804-64-qr: 3
  • debug: 3
• macosx1015-64-qr: 3
  • debug: 3

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1752518&startday=2022-02-14&endday=2022-02-20&tree=all

Comment 13

[Intermittent Failures Robot]

7 failures in 2992 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 1
• autoland: 6

Platform and build breakdown:

• linux1804-64-qr: 2
  • debug: 2
• macosx1015-64-qr: 3
  • debug: 3
• linux1804-64-domstreams-qr: 1
  • debug: 1
• windows10-64-2004-qr: 1
  • debug: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1752518&startday=2022-02-21&endday=2022-02-27&tree=all

Comment 14

[Jens Stutte [:jstutte]]

(In reply to Sandor Molnar from comment #10)

This is still happening
Failure log

(In reply to Jens Stutte [:jstutte] from comment #11)

This is probably just a different case, but let's keep them all on this intermittent.

Unfortunately it is not clear where the SendMessagePortForceClose came from. But IIUC the MessagePortService singleton can go away any time such that we should never rely on it to exist (which is not the case in that concrete log as I see the The service must exist if we want to close an existing MessagePort. message in the log). But even if it would exist, a ForceClose on an unexisting message port is just a no-op we can probably silently ignore?

Comment 16

[Jens Stutte [:jstutte]]

(In reply to Jens Stutte [:jstutte] from comment #14)

But even if it would exist, a ForceClose on an unexisting message port is just a no-op we can probably silently ignore?

FWIW, https://treeherder.mozilla.org/logviewer?job_id=366515781&repo=mozilla-central&lineNumber=5290 seems to be a case where the singleton existed.

Comment 17

[Nika Layzell [:nika] (ni? for response)]

(In reply to Jens Stutte [:jstutte] from comment #14)

Unfortunately it is not clear where the SendMessagePortForceClose came from. But IIUC the MessagePortService singleton can go away any time such that we should never rely on it to exist (which is not the case in that concrete log as I see the The service must exist if we want to close an existing MessagePort. message in the log). But even if it would exist, a ForceClose on an unexisting message port is just a no-op we can probably silently ignore?

I'm unfortunately not super familiar with the implementation of MessagePort in gecko, so I don't think I'm the right person to ask this question to. :asuth would probably know more about it. In general if it's still possible to receive messages after the service has been shutdown, you probably ought to handle it smoothly.

(In reply to Jens Stutte [:jstutte] from comment #16)

FWIW, https://treeherder.mozilla.org/logviewer?job_id=366515781&repo=mozilla-central&lineNumber=5290 seems to be a case where the singleton existed.

I think the singleton didn't exist there. That was an android test, so log messages like warnings only appear in the logcat log file, which you need to download seperately. Looking at the logcat output, it appears that a warning about the service not existing was emitted:

02-02 22:39:41.160 14760 14783 I Gecko   : [Parent 14760, Unnamed thread 776ff5f20bd0] WARNING: The service must exist if we want to close an existing MessagePort.: file /builds/worker/checkouts/gecko/dom/messagechannel/MessagePortParent.cpp:170
02-02 22:39:41.160 14760 14783 F MOZ_Assert: Assertion failure: false (Please ensure to IPC_FAIL only when in an unrecoverable, unexpected state.), at /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:68

Comment 18

[Jens Stutte [:jstutte]]

Thanks for trying to help, and sorry I got misled to IPC by the source folder.

Comment 19

[Jens Stutte [:jstutte]]

Attachment: Bug 1752518: Ignore missing MessagePortService inside MessagePortParent::ForceClose. r?#dom-worker-reviewers

Comment 20

[Jens Stutte [:jstutte]]

Let's move the discussion to the proposed patch, Nika's answer kind of strengthened my opinion we should just ignore this.

Comment 21

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/063b8fdaf41a
Ignore missing MessagePortService inside MessagePortParent::ForceClose. r=asuth

Comment 22

[Noemi Erli[:noemi_erli]]

https://hg.mozilla.org/mozilla-central/rev/063b8fdaf41a

Comment 23

[Intermittent Failures Robot]

1 failures in 3063 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• macosx1015-64-qr: 1
  • debug: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1752518&startday=2022-02-28&endday=2022-03-06&tree=all