Closed Bug 1749068 Opened 3 years ago Closed 2 years ago

Intermittent leakcheck | tab 1240 bytes leaked (CondVar, Mutex, PRemoteWorkerChild, RemoteWorkerChild, ShutdownOnWorker, ...)

Categories

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

defect

Tracking

()

RESOLVED WORKSFORME

People

(Reporter: intermittent-bug-filer, Assigned: asuth)

References

Details

(Keywords: intermittent-failure, Whiteboard: [stockwell disabled][stockwell needswork:owner])

Attachments

(2 files)

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


[task 2022-01-07T20:26:03.102Z] 20:26:03     INFO - TEST-START | dom/serviceworkers/test/test_hsts_upgrade_intercept.html
[task 2022-01-07T20:26:04.277Z] 20:26:04     INFO - GECKO(10652) | [Parent 10652, Main Thread] WARNING: WebProgress Ignored: no longer current window global: file /builds/worker/checkouts/gecko/dom/ipc/BrowserParent.cpp:2985
[task 2022-01-07T20:26:04.997Z] 20:26:04     INFO - GECKO(10652) | [Parent 10652, Main Thread] WARNING: WebProgress Ignored: no longer current window global: file /builds/worker/checkouts/gecko/dom/ipc/BrowserParent.cpp:2985
[task 2022-01-07T20:26:05.278Z] 20:26:05     INFO - GECKO(10652) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmp89xuz2c7.mozrunner/runtests_leaks_tab_pid10922.log
[task 2022-01-07T20:26:05.280Z] 20:26:05     INFO - GECKO(10652) | [10922, Main Thread] WARNING: XPCOM_MEM_BLOAT_LOG is set, disabling native allocations.: file /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp:253
[task 2022-01-07T20:26:05.317Z] 20:26:05     INFO - GECKO(10652) | [Child 10922, 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-07T20:26:05.400Z] 20:26:05     INFO - GECKO(10652) | Couldn't convert chrome URL: chrome://branding/locale/brand.properties
[task 2022-01-07T20:26:05.401Z] 20:26:05     INFO - GECKO(10652) | [Child 10922, Main Thread] WARNING: Could not get the program name for a cubeb stream.: 'NS_SUCCEEDED(rv)', file /builds/worker/checkouts/gecko/dom/media/CubebUtils.cpp:413
[task 2022-01-07T20:26:05.516Z] 20:26:05     INFO - GECKO(10652) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmp89xuz2c7.mozrunner/runtests_leaks_tab_pid10934.log
[task 2022-01-07T20:26:05.520Z] 20:26:05     INFO - GECKO(10652) | [10934, Main Thread] WARNING: XPCOM_MEM_BLOAT_LOG is set, disabling native allocations.: file /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp:253
[task 2022-01-07T20:26:05.548Z] 20:26:05     INFO - GECKO(10652) | [Child 10934, 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-07T20:26:05.613Z] 20:26:05     INFO - GECKO(10652) | Couldn't convert chrome URL: chrome://branding/locale/brand.properties
[task 2022-01-07T20:26:05.617Z] 20:26:05     INFO - GECKO(10652) | [Child 10934, Main Thread] WARNING: Could not get the program name for a cubeb stream.: 'NS_SUCCEEDED(rv)', file /builds/worker/checkouts/gecko/dom/media/CubebUtils.cpp:413
[task 2022-01-07T20:26:06.842Z] 20:26:06     INFO - GECKO(10652) | MEMORY STAT vsizeMaxContiguous not supported in this build configuration.
[task 2022-01-07T20:26:06.845Z] 20:26:06     INFO - GECKO(10652) | MEMORY STAT | vsize 2524MB | residentFast 132MB | heapAllocated 9MB
[task 2022-01-07T20:26:06.890Z] 20:26:06     INFO - TEST-OK | dom/serviceworkers/test/test_hsts_upgrade_intercept.html | took 3787ms
[task 2022-01-07T20:26:06.917Z] 20:26:06     INFO - TEST-START | Shutdown
[task 2022-01-07T20:26:06.918Z] 20:26:06     INFO - Passed:  6
[task 2022-01-07T20:26:06.919Z] 20:26:06     INFO - Failed:  0
[task 2022-01-07T20:26:06.920Z] 20:26:06     INFO - Todo:    0
[task 2022-01-07T20:26:06.921Z] 20:26:06     INFO - Mode:    e10s
[task 2022-01-07T20:26:06.922Z] 20:26:06     INFO - Slowest: 3787ms - https://example.org:443/tests/dom/serviceworkers/test/test_hsts_upgrade_intercept.html
[task 2022-01-07T20:26:06.922Z] 20:26:06     INFO - SimpleTest FINISHED
[task 2022-01-07T20:26:06.923Z] 20:26:06     INFO - TEST-INFO | Ran 1 Loops
[task 2022-01-07T20:26:06.924Z] 20:26:06     INFO - SimpleTest FINISHED
[task 2022-01-07T20:26:07.046Z] 20:26:07     INFO - GECKO(10652) | [Child 10814, Main Thread] WARNING: '!CanSend() || !mManager || !mManager->CanSend()', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:44
[task 2022-01-07T20:26:07.050Z] 20:26:07     INFO - GECKO(10652) | [Child 10814, Main Thread] WARNING: '!CanSend() || !mManager || !mManager->CanSend()', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:44
[task 2022-01-07T20:26:07.079Z] 20:26:07     INFO - GECKO(10652) | [Child 10814, Main Thread] WARNING: '!CanSend() || !mManager || !mManager->CanSend()', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:44
[task 2022-01-07T20:26:07.097Z] 20:26:07     INFO - GECKO(10652) | [Child 10814, Main Thread] WARNING: '!CanSend() || !mManager || !mManager->CanSend()', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:44
[task 2022-01-07T20:26:07.129Z] 20:26:07     INFO - GECKO(10652) | [Child 10814, Main Thread] WARNING: '!CanSend() || !mManager || !mManager->CanSend()', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:44
[task 2022-01-07T20:26:07.132Z] 20:26:07     INFO - GECKO(10652) | [Child 10814, Main Thread] WARNING: '!CanSend() || !mManager || !mManager->CanSend()', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:44
[task 2022-01-07T20:26:07.190Z] 20:26:07     INFO - GECKO(10652) | [Child 10814, Main Thread] WARNING: '!CanSend() || !mManager || !mManager->CanSend()', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:44
[task 2022-01-07T20:26:07.296Z] 20:26:07     INFO - GECKO(10652) | JavaScript error: resource://gre/modules/AsyncShutdown.jsm, line 575: NotFoundError: No such JSWindowActor 'SpecialPowers'
[task 2022-01-07T20:26:07.417Z] 20:26:07     INFO - GECKO(10652) | 1641587167416	Marionette	TRACE	Received observer notification quit-application
[task 2022-01-07T20:26:07.423Z] 20:26:07     INFO - GECKO(10652) | 1641587167416	Marionette	INFO	Stopped listening on port 2828
[task 2022-01-07T20:26:07.427Z] 20:26:07     INFO - GECKO(10652) | 1641587167417	Marionette	DEBUG	Marionette stopped listening
[task 2022-01-07T20:26:07.520Z] 20:26:07     INFO - GECKO(10652) | [Parent 10652, Compositor] WARNING: Possibly dropping task posted to updater thread: file /builds/worker/checkouts/gecko/gfx/layers/apz/src/APZUpdater.cpp:362
[task 2022-01-07T20:26:07.528Z] 20:26:07     INFO - GECKO(10652) | JavaScript error: resource://gre/modules/URLQueryStrippingListService.jsm, line 90: TypeError: can't access property "removeEventListener", Services.cpmm.sharedData is null
[task 2022-01-07T20:26:07.529Z] 20:26:07     INFO - GECKO(10652) | ###!!! [Parent][PBackgroundParent] Error: RunMessage(msgname=PRemoteWorkerService::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
[task 2022-01-07T20:26:07.537Z] 20:26:07     INFO - GECKO(10652) | [Child 10814, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_StartedGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:523
[task 2022-01-07T20:26:07.566Z] 20:26:07     INFO - GECKO(10652) | ###!!! [Parent][PImageBridgeParent] Error: RunMessage(msgname=PImageBridge::Msg_WillClose) Channel closing: too late to send/recv, messages will be lost
[task 2022-01-07T20:26:07.573Z] 20:26:07     INFO - GECKO(10652) | [Child 10757, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_StartedGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:523
[task 2022-01-07T20:26:07.583Z] 20:26:07     INFO - GECKO(10652) | [Parent 10652, Main Thread] WARNING: Not resolving response 'PContent::Reply_DiscardBrowsingContext': actor is dead: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:898
[task 2022-01-07T20:26:07.594Z] 20:26:07     INFO - GECKO(10652) | [Parent 10652, Main Thread] WARNING: 'mProgress != Progress::ShutdownCompleted', file /builds/worker/checkouts/gecko/dom/serviceworkers/ServiceWorkerShutdownState.cpp:57
[task 2022-01-07T20:26:07.597Z] 20:26:07     INFO - GECKO(10652) | [Child 10753, Main Thread] WARNING: NS_ENSURE_TRUE(!mHasOrHasHadOwnerWindow || mOwnerWindow) failed: file /builds/worker/checkouts/gecko/dom/events/DOMEventTargetHelper.cpp:307
[task 2022-01-07T20:26:07.597Z] 20:26:07     INFO - GECKO(10652) | [Child 10753, Main Thread] WARNING: NS_ENSURE_TRUE(!mHasOrHasHadOwnerWindow || mOwnerWindow) failed: file /builds/worker/checkouts/gecko/dom/events/DOMEventTargetHelper.cpp:307
[task 2022-01-07T20:26:07.601Z] 20:26:07     INFO - GECKO(10652) | [Parent 10652, IPDL Background] WARNING: 'aResult.IsReject()', file /builds/worker/checkouts/gecko/dom/workers/remoteworkers/RemoteWorkerController.cpp:476
[task 2022-01-07T20:26:07.601Z] 20:26:07     INFO - GECKO(10652) | [Parent 10652, IPDL Background] WARNING: 'aResult.IsReject()', file /builds/worker/checkouts/gecko/dom/workers/remoteworkers/RemoteWorkerControllerParent.cpp:125
[task 2022-01-07T20:26:07.610Z] 20:26:07     INFO - GECKO(10652) | ###!!! [Parent][PImageBridgeParent] Error: RunMessage(msgname=PImageBridge::Msg_WillClose) Channel closing: too late to send/recv, messages will be lost
[task 2022-01-07T20:26:07.616Z] 20:26:07     INFO - GECKO(10652) | [Child 10753, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_StartedGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:523
[task 2022-01-07T20:26:07.629Z] 20:26:07     INFO - GECKO(10652) | [Child 10851, Main Thread] WARNING: A runnable was posted to a worker that is already shutting down!: file /builds/worker/checkouts/gecko/dom/workers/WorkerPrivate.cpp:1492
[task 2022-01-07T20:26:07.630Z] 20:26:07     INFO - GECKO(10652) | [Child 10851, Main Thread] WARNING: Failed to dispatch offline status change event!: file /builds/worker/checkouts/gecko/dom/workers/WorkerPrivate.cpp:1969
[task 2022-01-07T20:26:07.633Z] 20:26:07     INFO - GECKO(10652) | ###!!! [Parent][PCompositorManagerParent] Error: RunMessage(msgname=PCompositorBridge::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
[task 2022-01-07T20:26:07.633Z] 20:26:07     INFO - GECKO(10652) | ###!!! [Parent][PImageBridgeParent] Error: RunMessage(msgname=PImageBridge::Msg_WillClose) Channel closing: too late to send/recv, messages will be lost
[task 2022-01-07T20:26:07.648Z] 20:26:07     INFO - GECKO(10652) | [Child 10851, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_StartedGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:523
[task 2022-01-07T20:26:07.655Z] 20:26:07     INFO - GECKO(10652) | [Parent 10652, Socket Thread] WARNING: cannot post event if not initialized: file /builds/worker/checkouts/gecko/netwerk/protocol/http/nsHttpConnectionMgr.cpp:197
[task 2022-01-07T20:26:07.655Z] 20:26:07     INFO - GECKO(10652) | [Parent 10652, Socket Thread] WARNING: cannot post event if not initialized: file /builds/worker/checkouts/gecko/netwerk/protocol/http/nsHttpConnectionMgr.cpp:197
[task 2022-01-07T20:26:07.655Z] 20:26:07     INFO - GECKO(10652) | [Parent 10652, Socket Thread] WARNING: cannot post event if not initialized: file /builds/worker/checkouts/gecko/netwerk/protocol/http/nsHttpConnectionMgr.cpp:197
[task 2022-01-07T20:26:07.655Z] 20:26:07     INFO - GECKO(10652) | [Parent 10652, Socket Thread] WARNING: cannot post event if not initialized: file /builds/worker/checkouts/gecko/netwerk/protocol/http/nsHttpConnectionMgr.cpp:197
[task 2022-01-07T20:26:07.667Z] 20:26:07     INFO - GECKO(10652) | [Child 10851, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_DoneGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:523
[task 2022-01-07T20:26:07.667Z] 20:26:07     INFO - GECKO(10652) | [2022-01-07T20:26:07Z WARN  xulstore::persist] tried to remove key that isn't in the store
[task 2022-01-07T20:26:07.667Z] 20:26:07     INFO - GECKO(10652) | [2022-01-07T20:26:07Z WARN  xulstore::persist] tried to remove key that isn't in the store
[task 2022-01-07T20:26:07.670Z] 20:26:07     INFO - GECKO(10652) | [Child 10851, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_StartedGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:523
[task 2022-01-07T20:26:07.674Z] 20:26:07     INFO - GECKO(10652) | [Child 10757, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_DoneGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:523
[task 2022-01-07T20:26:07.680Z] 20:26:07     INFO - GECKO(10652) | [Child 10851, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_DoneGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:523
[task 2022-01-07T20:26:07.688Z] 20:26:07     INFO - GECKO(10652) | [Child 10851, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/checkouts/gecko/xpcom/base/nsCycleCollector.cpp:3351
[task 2022-01-07T20:26:07.688Z] 20:26:07     INFO - GECKO(10652) | [Child 10851, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_StartedGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:523
[task 2022-01-07T20:26:07.691Z] 20:26:07     INFO - GECKO(10652) | [Child 10814, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_DoneGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:523
[task 2022-01-07T20:26:07.692Z] 20:26:07     INFO - GECKO(10652) | [Child 10814, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_StartedGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:523
[task 2022-01-07T20:26:07.704Z] 20:26:07     INFO - GECKO(10652) | [Child 10851, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_DoneGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:523
[task 2022-01-07T20:26:07.704Z] 20:26:07     INFO - GECKO(10652) | [Child 10851, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_StartedGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:523
[task 2022-01-07T20:26:07.705Z] 20:26:07     INFO - GECKO(10652) | [Child 10851, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_DoneGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:523
[task 2022-01-07T20:26:07.709Z] 20:26:07     INFO - GECKO(10652) | [Child 10851, Main Thread] WARNING: NS_ENSURE_TRUE(Preferences::InitStaticMembers()) failed: file /builds/worker/checkouts/gecko/modules/libpref/Preferences.cpp:4438
[task 2022-01-07T20:26:07.771Z] 20:26:07     INFO - GECKO(10652) | [Child 10814, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_DoneGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:523
[task 2022-01-07T20:26:07.799Z] 20:26:07     INFO - GECKO(10652) | [Child 10757, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_StartedGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:523
[task 2022-01-07T20:26:07.818Z] 20:26:07     INFO - GECKO(10652) | [Child 10757, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_DoneGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:523
[task 2022-01-07T20:26:07.827Z] 20:26:07     INFO - GECKO(10652) | [Child 10753, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_DoneGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:523
[task 2022-01-07T20:26:07.828Z] 20:26:07     INFO - GECKO(10652) | [Child 10753, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_StartedGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:523
[task 2022-01-07T20:26:07.831Z] 20:26:07     INFO - GECKO(10652) | [Child 10757, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/checkouts/gecko/xpcom/base/nsCycleCollector.cpp:3351
[task 2022-01-07T20:26:07.837Z] 20:26:07     INFO - GECKO(10652) | [Child 10757, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_StartedGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:523
[task 2022-01-07T20:26:07.847Z] 20:26:07     INFO - GECKO(10652) | [Child 10757, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_DoneGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:523
[task 2022-01-07T20:26:07.848Z] 20:26:07     INFO - GECKO(10652) | [Child 10757, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_StartedGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:523
[task 2022-01-07T20:26:07.851Z] 20:26:07     INFO - GECKO(10652) | [Child 10757, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_DoneGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:523
[task 2022-01-07T20:26:07.857Z] 20:26:07     INFO - GECKO(10652) | [Child 10757, Main Thread] WARNING: NS_ENSURE_TRUE(Preferences::InitStaticMembers()) failed: file /builds/worker/checkouts/gecko/modules/libpref/Preferences.cpp:4438
[task 2022-01-07T20:26:07.948Z] 20:26:07     INFO - GECKO(10652) | [Child 10753, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_DoneGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:523
[task 2022-01-07T20:26:07.949Z] 20:26:07     INFO - GECKO(10652) | [Child 10814, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_StartedGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:523
[task 2022-01-07T20:26:07.976Z] 20:26:07     INFO - GECKO(10652) | [Child 10814, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_DoneGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:523
[task 2022-01-07T20:26:07.983Z] 20:26:07     INFO - GECKO(10652) | [Child 10814, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/checkouts/gecko/xpcom/base/nsCycleCollector.cpp:3351
[task 2022-01-07T20:26:07.996Z] 20:26:07     INFO - GECKO(10652) | [Child 10814, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_StartedGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:523
[task 2022-01-07T20:26:08.005Z] 20:26:08     INFO - GECKO(10652) | [Child 10814, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_DoneGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:523
[task 2022-01-07T20:26:08.006Z] 20:26:08     INFO - GECKO(10652) | [Child 10814, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_StartedGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:523
[task 2022-01-07T20:26:08.012Z] 20:26:08     INFO - GECKO(10652) | [Child 10814, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_DoneGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:523
[task 2022-01-07T20:26:08.017Z] 20:26:08     INFO - GECKO(10652) | [Child 10814, Main Thread] WARNING: NS_ENSURE_TRUE(Preferences::InitStaticMembers()) failed: file /builds/worker/checkouts/gecko/modules/libpref/Preferences.cpp:4438
[task 2022-01-07T20:26:08.084Z] 20:26:08     INFO - GECKO(10652) | [Child 10753, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_StartedGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:523
[task 2022-01-07T20:26:08.098Z] 20:26:08     INFO - GECKO(10652) | [Child 10753, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_DoneGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:523
[task 2022-01-07T20:26:08.105Z] 20:26:08     INFO - GECKO(10652) | [Child 10753, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/checkouts/gecko/xpcom/base/nsCycleCollector.cpp:3351
[task 2022-01-07T20:26:08.109Z] 20:26:08     INFO - GECKO(10652) | [Child 10753, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_StartedGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:523
[task 2022-01-07T20:26:08.120Z] 20:26:08     INFO - GECKO(10652) | [Child 10753, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_DoneGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue

....
[task 2022-01-07T20:26:10.550Z] 20:26:10     INFO - TEST-PASS | leakcheck | tab no leaks detected!
[task 2022-01-07T20:26:10.551Z] 20:26:10     INFO - leakcheck | Processing leak log file /tmp/tmp89xuz2c7.mozrunner/runtests_leaks_tab_pid6558.log
[task 2022-01-07T20:26:10.552Z] 20:26:10     INFO - 
[task 2022-01-07T20:26:10.552Z] 20:26:10     INFO - == BloatView: ALL (cumulative) LEAK AND BLOAT STATISTICS, tab process 6558
[task 2022-01-07T20:26:10.553Z] 20:26:10     INFO - 
[task 2022-01-07T20:26:10.553Z] 20:26:10     INFO -      |<----------------Class--------------->|<-----Bytes------>|<----Objects---->|
[task 2022-01-07T20:26:10.553Z] 20:26:10     INFO -      |                                      | Per-Inst   Leaked|   Total      Rem|
[task 2022-01-07T20:26:10.554Z] 20:26:10     INFO -    0 |TOTAL                                 |       53     1240|   12611       13|
[task 2022-01-07T20:26:10.554Z] 20:26:10     INFO -   39 |CondVar                               |       80       80|      47        1|
[task 2022-01-07T20:26:10.555Z] 20:26:10     INFO -  133 |Mutex                                 |       72      216|     372        3|
[task 2022-01-07T20:26:10.555Z] 20:26:10     INFO -  206 |PRemoteWorkerChild                    |       64       64|       1        1|
[task 2022-01-07T20:26:10.556Z] 20:26:10     INFO -  246 |RemoteWorkerChild                     |      224      224|       1        1|
[task 2022-01-07T20:26:10.562Z] 20:26:10     INFO -  281 |ShutdownOnWorker                      |       40       40|       1        1|
[task 2022-01-07T20:26:10.563Z] 20:26:10     INFO -  301 |ThreadEventTarget                     |       64       64|      14        1|
[task 2022-01-07T20:26:10.563Z] 20:26:10     INFO -  303 |ThreadSafeWeakReference<RemoteWorkerCh|       24       24|       1        1|
[task 2022-01-07T20:26:10.564Z] 20:26:10     INFO -  304 |ThreadTargetSink                      |       16       16|      14        1|
[task 2022-01-07T20:26:10.564Z] 20:26:10     INFO -  482 |nsStringBuffer                        |        8        8|    6922        1|
[task 2022-01-07T20:26:10.565Z] 20:26:10     INFO -  489 |nsThread                              |      464      464|      16        1|
[task 2022-01-07T20:26:10.566Z] 20:26:10     INFO -  514 |operator()                            |       40       40|       4        1|
[task 2022-01-07T20:26:10.566Z] 20:26:10     INFO - 
[task 2022-01-07T20:26:10.567Z] 20:26:10     INFO - nsTraceRefcnt::DumpStatistics: 516 entries
[task 2022-01-07T20:26:10.568Z] 20:26:10     INFO - TEST-INFO | leakcheck | tab leaked 1 CondVar
[task 2022-01-07T20:26:10.568Z] 20:26:10     INFO - TEST-INFO | leakcheck | tab leaked 3 Mutex
[task 2022-01-07T20:26:10.569Z] 20:26:10     INFO - TEST-INFO | leakcheck | tab leaked 1 PRemoteWorkerChild
[task 2022-01-07T20:26:10.569Z] 20:26:10     INFO - TEST-INFO | leakcheck | tab leaked 1 RemoteWorkerChild
[task 2022-01-07T20:26:10.570Z] 20:26:10     INFO - TEST-INFO | leakcheck | tab leaked 1 ShutdownOnWorker
[task 2022-01-07T20:26:10.571Z] 20:26:10     INFO - TEST-INFO | leakcheck | tab leaked 1 ThreadEventTarget
[task 2022-01-07T20:26:10.571Z] 20:26:10     INFO - TEST-INFO | leakcheck | tab leaked 1 ThreadSafeWeakReference<RemoteWorkerCh
[task 2022-01-07T20:26:10.572Z] 20:26:10     INFO - TEST-INFO | leakcheck | tab leaked 1 ThreadTargetSink
[task 2022-01-07T20:26:10.573Z] 20:26:10     INFO - TEST-INFO | leakcheck | tab leaked 1 nsStringBuffer
[task 2022-01-07T20:26:10.573Z] 20:26:10     INFO - TEST-INFO | leakcheck | tab leaked 1 nsThread
[task 2022-01-07T20:26:10.574Z] 20:26:10     INFO - TEST-INFO | leakcheck | tab leaked 1 operator()
[task 2022-01-07T20:26:10.575Z] 20:26:10     INFO - TEST-UNEXPECTED-FAIL | leakcheck | tab 1240 bytes leaked (CondVar, Mutex, PRemoteWorkerChild, RemoteWorkerChild, ShutdownOnWorker, ...)
[task 2022-01-07T20:26:10.575Z] 20:26:10     INFO - 
[task 2022-01-07T20:26:10.576Z] 20:26:10     INFO - leakcheck | Processing leak log file /tmp/tmp89xuz2c7.mozrunner/runtests_leaks_tab_pid8568.log
[task 2022-01-07T20:26:10.577Z] 20:26:10     INFO - 
[task 2022-01-07T20:26:10.577Z] 20:26:10     INFO - == BloatView: ALL (cumulative) LEAK AND BLOAT STATISTICS, tab process 8568
[task 2022-01-07T20:26:10.578Z] 20:26:10     INFO - 
[task 2022-01-07T20:26:10.578Z] 20:26:10     INFO -      |<----------------Class--------------->|<-----Bytes------>|<----Objects---->|
[task 2022-01-07T20:26:10.579Z] 20:26:10     INFO -      |                                      | Per-Inst   Leaked|   Total      Rem|
[task 2022-01-07T20:26:10.579Z] 20:26:10     INFO -    0 |TOTAL                                 |       55        0|   13435        0|
[task 2022-01-07T20:26:10.580Z] 20:26:10     INFO - 
[task 2022-01-07T20:26:10.581Z] 20:26:10     INFO - nsTraceRefcnt::DumpStatistics: 528 entries
[task 2022-01-07T20:26:10.581Z] 20:26:10     INFO - TEST-PASS | leakcheck | tab no leaks detected!

There are 30 total failures in the last 7 days on linux1804-64-qr debug
Recent failure: https://treeherder.mozilla.org/logviewer?job_id=364408876&repo=mozilla-central&lineNumber=11502

[task 2022-01-17T22:36:59.485Z] 22:36:59     INFO -   fission.autostart=true
[task 2022-01-17T22:36:59.503Z] 22:36:59     INFO - TEST-START | dom/serviceworkers/test/test_hsts_upgrade_intercept.html
[task 2022-01-17T22:37:01.791Z] 22:37:01     INFO - GECKO(7953) | MEMORY STAT vsizeMaxContiguous not supported in this build configuration.
[task 2022-01-17T22:37:01.793Z] 22:37:01     INFO - GECKO(7953) | MEMORY STAT | vsize 2526MB | residentFast 134MB | heapAllocated 10MB
[task 2022-01-17T22:37:01.846Z] 22:37:01     INFO - TEST-OK | dom/serviceworkers/test/test_hsts_upgrade_intercept.html | took 2343ms
[task 2022-01-17T22:37:01.870Z] 22:37:01     INFO - TEST-START | Shutdown
[task 2022-01-17T22:37:01.872Z] 22:37:01     INFO - Passed:  6
[task 2022-01-17T22:37:01.873Z] 22:37:01     INFO - Failed:  0
[task 2022-01-17T22:37:01.873Z] 22:37:01     INFO - Todo:    0
[task 2022-01-17T22:37:01.874Z] 22:37:01     INFO - Mode:    e10s
[task 2022-01-17T22:37:01.875Z] 22:37:01     INFO - Slowest: 2343ms - /tests/dom/serviceworkers/test/test_hsts_upgrade_intercept.html
[task 2022-01-17T22:37:01.876Z] 22:37:01     INFO - SimpleTest FINISHED
[task 2022-01-17T22:37:01.882Z] 22:37:01     INFO - TEST-INFO | Ran 1 Loops
[task 2022-01-17T22:37:01.882Z] 22:37:01     INFO - SimpleTest FINISHED

task 2022-01-17T22:37:04.848Z] 22:37:04     INFO - TEST-PASS | leakcheck | tab no leaks detected!
[task 2022-01-17T22:37:04.848Z] 22:37:04     INFO - leakcheck | Processing leak log file /tmp/tmpb6ctgnt6.mozrunner/runtests_leaks_tab_pid5111.log
[task 2022-01-17T22:37:04.849Z] 22:37:04     INFO - 
[task 2022-01-17T22:37:04.849Z] 22:37:04     INFO - == BloatView: ALL (cumulative) LEAK AND BLOAT STATISTICS, tab process 5111
[task 2022-01-17T22:37:04.850Z] 22:37:04     INFO - 
[task 2022-01-17T22:37:04.850Z] 22:37:04     INFO -      |<----------------Class--------------->|<-----Bytes------>|<----Objects---->|
[task 2022-01-17T22:37:04.851Z] 22:37:04     INFO -      |                                      | Per-Inst   Leaked|   Total      Rem|
[task 2022-01-17T22:37:04.851Z] 22:37:04     INFO -    0 |TOTAL                                 |       53     1240|   12705       13|
[task 2022-01-17T22:37:04.852Z] 22:37:04     INFO -   39 |CondVar                               |       80       80|      49        1|
[task 2022-01-17T22:37:04.852Z] 22:37:04     INFO -  133 |Mutex                                 |       72      216|     377        3|
[task 2022-01-17T22:37:04.853Z] 22:37:04     INFO -  210 |PRemoteWorkerChild                    |       64       64|       1        1|
[task 2022-01-17T22:37:04.853Z] 22:37:04     INFO -  250 |RemoteWorkerChild                     |      224      224|       1        1|
[task 2022-01-17T22:37:04.854Z] 22:37:04     INFO -  284 |ShutdownOnWorker                      |       40       40|       1        1|
[task 2022-01-17T22:37:04.854Z] 22:37:04     INFO -  310 |ThreadEventTarget                     |       64       64|      14        1|
[task 2022-01-17T22:37:04.855Z] 22:37:04     INFO -  312 |ThreadSafeWeakReference<RemoteWorkerCh|       24       24|       1        1|
[task 2022-01-17T22:37:04.855Z] 22:37:04     INFO -  313 |ThreadTargetSink                      |       16       16|      14        1|
[task 2022-01-17T22:37:04.856Z] 22:37:04     INFO -  491 |nsStringBuffer                        |        8        8|    6932        1|
[task 2022-01-17T22:37:04.856Z] 22:37:04     INFO -  498 |nsThread                              |      464      464|      16        1|
[task 2022-01-17T22:37:04.857Z] 22:37:04     INFO -  523 |operator()                            |       40       40|       4        1|
[task 2022-01-17T22:37:04.857Z] 22:37:04     INFO - 
[task 2022-01-17T22:37:04.858Z] 22:37:04     INFO - nsTraceRefcnt::DumpStatistics: 525 entries
[task 2022-01-17T22:37:04.858Z] 22:37:04     INFO - TEST-INFO | leakcheck | tab leaked 1 CondVar
[task 2022-01-17T22:37:04.859Z] 22:37:04     INFO - TEST-INFO | leakcheck | tab leaked 3 Mutex
[task 2022-01-17T22:37:04.859Z] 22:37:04     INFO - TEST-INFO | leakcheck | tab leaked 1 PRemoteWorkerChild
[task 2022-01-17T22:37:04.860Z] 22:37:04     INFO - TEST-INFO | leakcheck | tab leaked 1 RemoteWorkerChild
[task 2022-01-17T22:37:04.860Z] 22:37:04     INFO - TEST-INFO | leakcheck | tab leaked 1 ShutdownOnWorker
[task 2022-01-17T22:37:04.861Z] 22:37:04     INFO - TEST-INFO | leakcheck | tab leaked 1 ThreadEventTarget
[task 2022-01-17T22:37:04.861Z] 22:37:04     INFO - TEST-INFO | leakcheck | tab leaked 1 ThreadSafeWeakReference<RemoteWorkerCh
[task 2022-01-17T22:37:04.862Z] 22:37:04     INFO - TEST-INFO | leakcheck | tab leaked 1 ThreadTargetSink
[task 2022-01-17T22:37:04.862Z] 22:37:04     INFO - TEST-INFO | leakcheck | tab leaked 1 nsStringBuffer
[task 2022-01-17T22:37:04.863Z] 22:37:04     INFO - TEST-INFO | leakcheck | tab leaked 1 nsThread
[task 2022-01-17T22:37:04.863Z] 22:37:04     INFO - TEST-INFO | leakcheck | tab leaked 1 operator()
[task 2022-01-17T22:37:04.864Z] 22:37:04     INFO - TEST-UNEXPECTED-FAIL | leakcheck | tab 1240 bytes leaked (CondVar, Mutex, PRemoteWorkerChild, RemoteWorkerChild, ShutdownOnWorker, ...)
[task 2022-01-17T22:37:04.864Z] 22:37:04     INFO - 
[task 2022-01-17T22:37:04.864Z] 22:37:04     INFO - leakcheck | Processing leak log file /tmp/tmpb6ctgnt6.mozrunner/runtests_leaks_tab_pid6360.log
[task 2022-01-17T22:37:04.865Z] 22:37:04     INFO - 
[task 2022-01-17T22:37:04.865Z] 22:37:04     INFO - == BloatView: ALL (cumulative) LEAK AND BLOAT STATISTICS, tab process 6360
[task 2022-01-17T22:37:04.866Z] 22:37:04     INFO - 
[task 2022-01-17T22:37:04.866Z] 22:37:04     INFO -      |<----------------Class--------------->|<-----Bytes------>|<----Objects---->|
[task 2022-01-17T22:37:04.867Z] 22:37:04     INFO -      |                                      | Per-Inst   Leaked|   Total      Rem|
[task 2022-01-17T22:37:04.868Z] 22:37:04     INFO -    0 |TOTAL                                 |       56        0|   18605        0|
[task 2022-01-17T22:37:04.868Z] 22:37:04     INFO - 
[task 2022-01-17T22:37:04.868Z] 22:37:04     INFO - nsTraceRefcnt::DumpStatistics: 736 entries
[task 2022-01-17T22:37:04.869Z] 22:37:04     INFO - TEST-PASS | leakcheck | tab no leaks detected!

Jens, can you, please, take a look?
Thank you.

Flags: needinfo?(jstutte)
Whiteboard: [stockwell needswork:owner]

Weird. It went down completely for a week after a short, huge peak, but now we see it again at lower level.

Flags: needinfo?(jstutte)

Update:
There have been 40 failures within the last 7 days:
• 7 failures on linux1804-64-domstreams-qr debug
• 33 failures on Linux 18.04 x64 WebRender debug
Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=366823976&repo=autoland&lineNumber=12141

[task 2022-02-05T09:58:45.141Z] 09:58:45     INFO - TEST-START | dom/serviceworkers/test/test_hsts_upgrade_intercept.html
<...>
[task 2022-02-05T09:58:50.251Z] 09:58:50     INFO - TEST-PASS | leakcheck | tab no leaks detected!
[task 2022-02-05T09:58:50.252Z] 09:58:50     INFO - leakcheck | Processing leak log file /tmp/tmpfb8lgx66.mozrunner/runtests_leaks_tab_pid5701.log
[task 2022-02-05T09:58:50.252Z] 09:58:50     INFO - 
[task 2022-02-05T09:58:50.253Z] 09:58:50     INFO - == BloatView: ALL (cumulative) LEAK AND BLOAT STATISTICS, tab process 5701
[task 2022-02-05T09:58:50.254Z] 09:58:50     INFO - 
[task 2022-02-05T09:58:50.255Z] 09:58:50     INFO -      |<----------------Class--------------->|<-----Bytes------>|<----Objects---->|
[task 2022-02-05T09:58:50.256Z] 09:58:50     INFO -      |                                      | Per-Inst   Leaked|   Total      Rem|
[task 2022-02-05T09:58:50.257Z] 09:58:50     INFO -    0 |TOTAL                                 |       52     1240|   12763       13|
[task 2022-02-05T09:58:50.258Z] 09:58:50     INFO -   40 |CondVar                               |       80       80|      49        1|
[task 2022-02-05T09:58:50.258Z] 09:58:50     INFO -  134 |Mutex                                 |       72      216|     369        3|
[task 2022-02-05T09:58:50.259Z] 09:58:50     INFO -  212 |PRemoteWorkerChild                    |       64       64|       1        1|
[task 2022-02-05T09:58:50.260Z] 09:58:50     INFO -  253 |RemoteWorkerChild                     |      224      224|       1        1|
[task 2022-02-05T09:58:50.261Z] 09:58:50     INFO -  288 |ShutdownOnWorker                      |       40       40|       1        1|
[task 2022-02-05T09:58:50.262Z] 09:58:50     INFO -  312 |ThreadEventTarget                     |       64       64|      15        1|
[task 2022-02-05T09:58:50.263Z] 09:58:50     INFO -  314 |ThreadSafeWeakReference<RemoteWorkerCh|       24       24|       1        1|
[task 2022-02-05T09:58:50.264Z] 09:58:50     INFO -  315 |ThreadTargetSink                      |       16       16|      15        1|
[task 2022-02-05T09:58:50.265Z] 09:58:50     INFO -  494 |nsStringBuffer                        |        8        8|    6931        1|
[task 2022-02-05T09:58:50.266Z] 09:58:50     INFO -  501 |nsThread                              |      464      464|      17        1|
[task 2022-02-05T09:58:50.267Z] 09:58:50     INFO -  526 |operator()                            |       40       40|       4        1|
[task 2022-02-05T09:58:50.267Z] 09:58:50     INFO - 
[task 2022-02-05T09:58:50.268Z] 09:58:50     INFO - nsTraceRefcnt::DumpStatistics: 528 entries
[task 2022-02-05T09:58:50.269Z] 09:58:50     INFO - TEST-INFO | leakcheck | tab leaked 1 CondVar
[task 2022-02-05T09:58:50.270Z] 09:58:50     INFO - TEST-INFO | leakcheck | tab leaked 3 Mutex
[task 2022-02-05T09:58:50.270Z] 09:58:50     INFO - TEST-INFO | leakcheck | tab leaked 1 PRemoteWorkerChild
[task 2022-02-05T09:58:50.271Z] 09:58:50     INFO - TEST-INFO | leakcheck | tab leaked 1 RemoteWorkerChild
[task 2022-02-05T09:58:50.272Z] 09:58:50     INFO - TEST-INFO | leakcheck | tab leaked 1 ShutdownOnWorker
[task 2022-02-05T09:58:50.273Z] 09:58:50     INFO - TEST-INFO | leakcheck | tab leaked 1 ThreadEventTarget
[task 2022-02-05T09:58:50.273Z] 09:58:50     INFO - TEST-INFO | leakcheck | tab leaked 1 ThreadSafeWeakReference<RemoteWorkerCh
[task 2022-02-05T09:58:50.274Z] 09:58:50     INFO - TEST-INFO | leakcheck | tab leaked 1 ThreadTargetSink
[task 2022-02-05T09:58:50.275Z] 09:58:50     INFO - TEST-INFO | leakcheck | tab leaked 1 nsStringBuffer
[task 2022-02-05T09:58:50.276Z] 09:58:50     INFO - TEST-INFO | leakcheck | tab leaked 1 nsThread
[task 2022-02-05T09:58:50.276Z] 09:58:50     INFO - TEST-INFO | leakcheck | tab leaked 1 operator()
[task 2022-02-05T09:58:50.277Z] 09:58:50     INFO - TEST-UNEXPECTED-FAIL | leakcheck | tab 1240 bytes leaked (CondVar, Mutex, PRemoteWorkerChild, RemoteWorkerChild, ShutdownOnWorker, ...)
[task 2022-02-05T09:58:50.278Z] 09:58:50     INFO - 
[task 2022-02-05T09:58:50.279Z] 09:58:50     INFO - leakcheck | Processing leak log file /tmp/tmpfb8lgx66.mozrunner/runtests_leaks_tab_pid7743.log
[task 2022-02-05T09:58:50.280Z] 09:58:50     INFO - 
[task 2022-02-05T09:58:50.281Z] 09:58:50     INFO - == BloatView: ALL (cumulative) LEAK AND BLOAT STATISTICS, tab process 7743
[task 2022-02-05T09:58:50.281Z] 09:58:50     INFO - 
[task 2022-02-05T09:58:50.282Z] 09:58:50     INFO -      |<----------------Class--------------->|<-----Bytes------>|<----Objects---->|
[task 2022-02-05T09:58:50.283Z] 09:58:50     INFO -      |                                      | Per-Inst   Leaked|   Total      Rem|
[task 2022-02-05T09:58:50.284Z] 09:58:50     INFO -    0 |TOTAL                                 |       56        0|   18180        0|
[task 2022-02-05T09:58:50.284Z] 09:58:50     INFO - 
[task 2022-02-05T09:58:50.285Z] 09:58:50     INFO - nsTraceRefcnt::DumpStatistics: 755 entries
[task 2022-02-05T09:58:50.286Z] 09:58:50     INFO - TEST-PASS | leakcheck | tab no leaks detected!
Whiteboard: [stockwell unknown] → [stockwell needswork:owner]

Hi Jens! It seems that the failure rate has increased again.

Flags: needinfo?(jstutte)

I checked the last ~20 failure logs and some leaks occur after test_hsts_upgrade_intercept.html and others after test_cache_worker_gc.html.

Assignee: nobody → apavel
Status: NEW → ASSIGNED
Assignee: apavel → nobody
Status: ASSIGNED → NEW
Keywords: leave-open
Whiteboard: [stockwell needswork:owner] → [stockwell needswork:owner][stockwell disabled]
Pushed by apavel@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/979c9105b1fd disable test_hsts_upgrade_intercept.html and test_cache_worker_gc.html to reduce failure rate r=intermittent-reviewers,MasterWayZ DONTBUILD

Update:
There have been 32 failures within the last 7 days:
• 6 failures on linux1804-64-domstreams-qr debug
• 25 failures on Linux 18.04 x64 WebRender debug
• 1 failures on Windows 7 WebRender opt
Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=369384608&repo=autoland&lineNumber=16078

[task 2022-02-27T21:55:11.780Z] 21:55:11     INFO - TEST-START | dom/serviceworkers/test/test_xslt.html
[task 2022-02-27T21:55:11.794Z] 21:55:11     INFO - GECKO(6277) | [Child 10626, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_DoneGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:498
[task 2022-02-27T21:55:11.800Z] 21:55:11     INFO - GECKO(6277) | [Child 10626, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/checkouts/gecko/xpcom/base/nsCycleCollector.cpp:3359
[task 2022-02-27T21:55:11.816Z] 21:55:11     INFO - GECKO(6277) | [Child 10626, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_StartedGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:498
[task 2022-02-27T21:55:11.828Z] 21:55:11     INFO - GECKO(6277) | [Child 10626, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_DoneGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:498
[task 2022-02-27T21:55:11.831Z] 21:55:11     INFO - GECKO(6277) | [Child 10626, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_StartedGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:498
[task 2022-02-27T21:55:11.854Z] 21:55:11     INFO - GECKO(6277) | [Child 10626, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_DoneGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:498
[task 2022-02-27T21:55:11.876Z] 21:55:11     INFO - GECKO(6277) | [Child 10626, Main Thread] WARNING: NS_ENSURE_TRUE(Preferences::InitStaticMembers()) failed: file /builds/worker/checkouts/gecko/modules/libpref/Preferences.cpp:4470
[task 2022-02-27T21:55:11.899Z] 21:55:11     INFO - GECKO(6277) | [Child 10623, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_StartedGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:498
[task 2022-02-27T21:55:11.944Z] 21:55:11     INFO - GECKO(6277) | [Child 10623, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_DoneGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:498
[task 2022-02-27T21:55:11.960Z] 21:55:11     INFO - GECKO(6277) | [Child 10623, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/checkouts/gecko/xpcom/base/nsCycleCollector.cpp:3359
[task 2022-02-27T21:55:11.970Z] 21:55:11     INFO - GECKO(6277) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmpawbgwbrj.mozrunner/runtests_leaks_tab_pid10711.log
[task 2022-02-27T21:55:11.971Z] 21:55:11     INFO - GECKO(6277) | [10711, Main Thread] WARNING: XPCOM_MEM_BLOAT_LOG is set, disabling native allocations.: file /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp:281
[task 2022-02-27T21:55:11.972Z] 21:55:11     INFO - GECKO(6277) | [Child 10623, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_StartedGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:498
[task 2022-02-27T21:55:11.985Z] 21:55:11     INFO - GECKO(6277) | [Child 10623, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_DoneGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:498
[task 2022-02-27T21:55:11.986Z] 21:55:11     INFO - GECKO(6277) | [Child 10623, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_StartedGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:498
[task 2022-02-27T21:55:12.005Z] 21:55:12     INFO - GECKO(6277) | [Child 10623, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_DoneGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:498
[task 2022-02-27T21:55:12.017Z] 21:55:12     INFO - GECKO(6277) | [Child 10623, Main Thread] WARNING: NS_ENSURE_TRUE(Preferences::InitStaticMembers()) failed: file /builds/worker/checkouts/gecko/modules/libpref/Preferences.cpp:4470
[task 2022-02-27T21:55:12.055Z] 21:55:12     INFO - GECKO(6277) | [Child 10711, Main Thread] WARNING: could not set real-time limit in CubebUtils::InitLibrary: file /builds/worker/checkouts/gecko/dom/media/CubebUtils.cpp:693
[task 2022-02-27T21:55:12.165Z] 21:55:12     INFO - GECKO(6277) | [Parent 6277, Main Thread] WARNING: WebProgress Ignored: no longer current window global: file /builds/worker/checkouts/gecko/dom/ipc/BrowserParent.cpp:2988
[task 2022-02-27T21:55:12.323Z] 21:55:12     INFO - GECKO(6277) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmpawbgwbrj.mozrunner/runtests_leaks_tab_pid10726.log
[task 2022-02-27T21:55:12.325Z] 21:55:12     INFO - GECKO(6277) | [10726, Main Thread] WARNING: XPCOM_MEM_BLOAT_LOG is set, disabling native allocations.: file /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp:281
[task 2022-02-27T21:55:12.353Z] 21:55:12     INFO - GECKO(6277) | [Child 10726, Main Thread] WARNING: could not set real-time limit in CubebUtils::InitLibrary: file /builds/worker/checkouts/gecko/dom/media/CubebUtils.cpp:693
[task 2022-02-27T21:55:12.946Z] 21:55:12     INFO - GECKO(6277) | Set request mode
[task 2022-02-27T21:55:13.282Z] 21:55:13     INFO - GECKO(6277) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmpawbgwbrj.mozrunner/runtests_leaks_tab_pid10757.log
[task 2022-02-27T21:55:13.283Z] 21:55:13     INFO - GECKO(6277) | [10757, Main Thread] WARNING: XPCOM_MEM_BLOAT_LOG is set, disabling native allocations.: file /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp:281
[task 2022-02-27T21:55:13.351Z] 21:55:13     INFO - GECKO(6277) | [Child 10757, Main Thread] WARNING: could not set real-time limit in CubebUtils::InitLibrary: file /builds/worker/checkouts/gecko/dom/media/CubebUtils.cpp:693
[task 2022-02-27T21:55:13.409Z] 21:55:13     INFO - GECKO(6277) | [Child 10680, Worker Launcher] WARNING: 'aResult.IsReject()', file /builds/worker/checkouts/gecko/dom/serviceworkers/FetchEventOpProxyChild.cpp:127
[task 2022-02-27T21:55:13.410Z] 21:55:13     INFO - GECKO(6277) | JavaScript error: , line 0: NetworkError: AutoCancel
[task 2022-02-27T21:55:13.444Z] 21:55:13     INFO - GECKO(6277) | [Child 10660, Main Thread] WARNING: '!wgc', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorProtocol.cpp:189
<...>
[task 2022-02-27T21:55:18.606Z] 21:55:18     INFO - leakcheck | Processing leak log file /tmp/tmpawbgwbrj.mozrunner/runtests_leaks_tab_pid6589.log
[task 2022-02-27T21:55:18.607Z] 21:55:18     INFO - 
[task 2022-02-27T21:55:18.607Z] 21:55:18     INFO - == BloatView: ALL (cumulative) LEAK AND BLOAT STATISTICS, tab process 6589
[task 2022-02-27T21:55:18.608Z] 21:55:18     INFO - 
[task 2022-02-27T21:55:18.609Z] 21:55:18     INFO -      |<----------------Class--------------->|<-----Bytes------>|<----Objects---->|
[task 2022-02-27T21:55:18.609Z] 21:55:18     INFO -      |                                      | Per-Inst   Leaked|   Total      Rem|
[task 2022-02-27T21:55:18.610Z] 21:55:18     INFO -    0 |TOTAL                                 |       62     1240|   13510       13|
[task 2022-02-27T21:55:18.611Z] 21:55:18     INFO -   37 |CondVar                               |       80       80|      57        1|
[task 2022-02-27T21:55:18.611Z] 21:55:18     INFO -  125 |Mutex                                 |       72      216|     408        3|
[task 2022-02-27T21:55:18.612Z] 21:55:18     INFO -  197 |PRemoteWorkerChild                    |       64       64|       2        1|
[task 2022-02-27T21:55:18.613Z] 21:55:18     INFO -  239 |RemoteWorkerChild                     |      224      224|       2        1|
[task 2022-02-27T21:55:18.613Z] 21:55:18     INFO -  275 |ShutdownOnWorker                      |       40       40|       2        1|
[task 2022-02-27T21:55:18.614Z] 21:55:18     INFO -  299 |ThreadEventTarget                     |       64       64|      17        1|
[task 2022-02-27T21:55:18.615Z] 21:55:18     INFO -  301 |ThreadSafeWeakReference<RemoteWorkerCh|       24       24|       2        1|
[task 2022-02-27T21:55:18.615Z] 21:55:18     INFO -  302 |ThreadTargetSink                      |       16       16|      17        1|
[task 2022-02-27T21:55:18.616Z] 21:55:18     INFO -  479 |nsStringBuffer                        |        8        8|    7197        1|
[task 2022-02-27T21:55:18.617Z] 21:55:18     INFO -  486 |nsThread                              |      464      464|      18        1|
[task 2022-02-27T21:55:18.617Z] 21:55:18     INFO -  512 |operator()                            |       40       40|      12        1|
[task 2022-02-27T21:55:18.618Z] 21:55:18     INFO - 
[task 2022-02-27T21:55:18.619Z] 21:55:18     INFO - nsTraceRefcnt::DumpStatistics: 514 entries
[task 2022-02-27T21:55:18.619Z] 21:55:18     INFO - TEST-INFO | leakcheck | tab leaked 1 CondVar
[task 2022-02-27T21:55:18.620Z] 21:55:18     INFO - TEST-INFO | leakcheck | tab leaked 3 Mutex
[task 2022-02-27T21:55:18.621Z] 21:55:18     INFO - TEST-INFO | leakcheck | tab leaked 1 PRemoteWorkerChild
[task 2022-02-27T21:55:18.621Z] 21:55:18     INFO - TEST-INFO | leakcheck | tab leaked 1 RemoteWorkerChild
[task 2022-02-27T21:55:18.622Z] 21:55:18     INFO - TEST-INFO | leakcheck | tab leaked 1 ShutdownOnWorker
[task 2022-02-27T21:55:18.622Z] 21:55:18     INFO - TEST-INFO | leakcheck | tab leaked 1 ThreadEventTarget
[task 2022-02-27T21:55:18.623Z] 21:55:18     INFO - TEST-INFO | leakcheck | tab leaked 1 ThreadSafeWeakReference<RemoteWorkerCh
[task 2022-02-27T21:55:18.624Z] 21:55:18     INFO - TEST-INFO | leakcheck | tab leaked 1 ThreadTargetSink
[task 2022-02-27T21:55:18.624Z] 21:55:18     INFO - TEST-INFO | leakcheck | tab leaked 1 nsStringBuffer
[task 2022-02-27T21:55:18.625Z] 21:55:18     INFO - TEST-INFO | leakcheck | tab leaked 1 nsThread
[task 2022-02-27T21:55:18.626Z] 21:55:18     INFO - TEST-INFO | leakcheck | tab leaked 1 operator()
[task 2022-02-27T21:55:18.626Z] 21:55:18     INFO - TEST-UNEXPECTED-FAIL | leakcheck | tab 1240 bytes leaked (CondVar, Mutex, PRemoteWorkerChild, RemoteWorkerChild, ShutdownOnWorker, ...)
[task 2022-02-27T21:55:18.627Z] 21:55:18     INFO - 
Flags: needinfo?(jstutte)

Hi Jen! Can you please take another look at this? Even with the disables made the failure rate it's quite high.
Thank you!

Flags: needinfo?(jstutte)

I'm guessing that bug 1717657 is the LeakSanitizer manifestation of the same issue.

My guess would be that a worker is trying to dispatch something to the main thread too late in shutdown, so it fails and we leak the runnable.

See Also: → 1717657

(In reply to Andrew McCreight [:mccr8] from comment #21)

I'm guessing that bug 1717657 is the LeakSanitizer manifestation of the same issue.

That sounds very plausible.

My guess would be that a worker is trying to dispatch something to the main thread too late in shutdown, so it fails and we leak the runnable.
The dispatch in question is happening here in the callback of the RemoteWorkerChild's WeakWorkerRef.

IIUC the magic of RemoteWorkerChild::InitializeOnWorker() we are on the worker thread and

What is not evident (to me) is:

  • who actually is the mOwningEventTarget (if it is the main thread as suspected by :mccr8 shouldn't it live longer than the worker?) and which Dispatch function actually applies ?
  • what makes the dispatch apparently fail ?
Flags: needinfo?(jstutte) → needinfo?(bugmail)

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

  • who actually is the mOwningEventTarget (if it is the main thread as suspected by :mccr8 shouldn't it live longer than the worker?) and which Dispatch function actually applies ?

The RemoteWorkerChild is created on the "Worker Launcher" which it then saves into mOwningEventTarget.

This thread gets shutdown starting at "xpcom-shutdown" which involves a thread bounce. A runnable first runs ShutdownOnTargetThread on the Worker Launcher thread, which should cause ActorDestroy to be called on all the RemoteWorkerChild instances as a result.

  • what makes the dispatch apparently fail ?

Presumably there is a race at shutdown where the content process is able to get to xpcom-shutdown before ServiceWorkerManager's attempted teardown of all the ServiceWorkers actually completes.

The general options to improve this would potentially be:

  • Have the per-ServiceWorker shutdown promises tracking be more diligent about individual ServiceWorker shutdown.
  • Have the ServiceWorkerManager shutdown blocker be more diligent in making sure that the RemoteWorkerManager (in the parent) and all of its per-process RemoteWorkerService instances have fully shutdown (in debug builds and any other builds where we actually will perform full XPCOM shutdown in the content processes, which is not release builds AIUI).
    • This would likely involve a new capability for RemoteWorkerManager/RemoteWorkerService. The argument for this is that we don't need to worry about the per-SW shutdown nuances as much and then the RemoteWorkerService can potentially help provide a semantic barrier here which ensures that when shutdown is reported no new workers can be started. This may also be overkill.
  • Have the (per-process) RemoteWorkerService shutdown use an async shutdown blocker that waits to make sure all of the RemoteWorkerChild instances have fully completed their async teardown process rather than assuming that the Send__delete__ was sufficient.
Flags: needinfo?(bugmail)

If we need to disable more tests, I checked the latest 15 files:

  • 11 of them had the leak in dom/serviceworkers/test/test_xslt.html
  • 4 of them had the leak in dom/cache/test/mochitest/test_cache_orphaned_body.html

I think those are just the last tests in the directories. Disabling them will likely not make the leaks go away.

Severity: S4 → S3
Priority: -- → P2

(In reply to Andrew McCreight [:mccr8] from comment #25)

I think those are just the last tests in the directories. Disabling them will likely not make the leaks go away.

Yes, we have definitely many random instances of this leak, disabling tests would just reduce our test-coverage to no avail. I'd propose to concentrate work on this bug here.

Eden, can you start to look into this (starting from comment 23)?

Flags: needinfo?(echuang)
See Also: → 1743092

There have been 37 failures in the last 7 days: https://treeherder.mozilla.org/intermittent-failures/bugdetails?startday=2022-03-17&endday=2022-03-24&tree=trunk&bug=1749068

Happens on: linux1804-64-qr debug.

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=372116933&repo=mozilla-central&lineNumber=12319

Eden, did you had a chance to look into this?

Flags: needinfo?(echuang)
Flags: needinfo?(echuang)

There have been 33 total failures in the last 7 days, recent failure log.
Affected platforms are:

  • linux1804-64-qr

There have been 36 total failures in the last 7 days, recent failure log.
Affected platforms are:

  • linux1804-64-qr

Hi Eden, are there any updates here?

Flags: needinfo?(echuang)
Flags: needinfo?(echuang)

There have been 33 total failures in the last 7 days, recent failure log.
Affected platforms are:

  • linux1804-64-qr
Flags: needinfo?(echuang)

There have been 53 failures in the last 7 days.

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=378433384&repo=autoland&lineNumber=3672

Eden, could you look into this?

Flags: needinfo?(echuang)

There have been 62 total failures in the last 7 days, recent failure log.
Affected platforms are:

  • linux1804-64-qr

Jens, could you please redirect this to someone as it is again on the list of disable-recommended bugs with 202 total failures in last 30 days. Thank you.

Flags: needinfo?(jstutte)
Whiteboard: [stockwell disabled][stockwell disable-recommended] → [stockwell disabled][stockwell needswork:owner]

Andrew, could you please take a look if there is any low hanging fruit out of the options from comment 23 here? Thanks

Flags: needinfo?(jstutte)
Flags: needinfo?(echuang)
Flags: needinfo?(bugmail)

There have been 65 total failures in the last 7 days, recent failure log.
Affected platforms are:

  • linux1804-64-qr

There have been 83 total failures in the last 7 days, recent failure log.
Affected platforms are:

  • linux1804-64-qr

There have been 65 total failures in the last 7 days, recent failure log.
Affected platforms are:

  • linux1804-64-qr
Flags: needinfo?(bugmail)
Flags: needinfo?(bugmail)

There have been 40 total failures in the last 7 days, recent failure log.
Affected platforms are:

  • linux1804-64-qr

There have been 41 total failures in the last 7 days, recent failure log.
Affected platforms are:

  • linux1804-64-qr
Pushed by apavel@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/b4bde08b5b5f disable tests on linux64 debug to reduce leaks r=intermittent-reviewers,jmaher DONTBUILD

There are 40 total failures in the last 7 days on linux1804-64-qr debug
Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=390704379&repo=mozilla-central&lineNumber=3308

[task 2022-09-17T10:01:07.035Z] 10:01:07     INFO - == BloatView: ALL (cumulative) LEAK AND BLOAT STATISTICS, tab process 2249
[task 2022-09-17T10:01:07.035Z] 10:01:07     INFO - 
[task 2022-09-17T10:01:07.036Z] 10:01:07     INFO -      |<----------------Class--------------->|<-----Bytes------>|<----Objects---->|
[task 2022-09-17T10:01:07.037Z] 10:01:07     INFO -      |                                      | Per-Inst   Leaked|   Total      Rem|
[task 2022-09-17T10:01:07.037Z] 10:01:07     INFO -    0 |TOTAL                                 |       55     1216|   17018       13|
[task 2022-09-17T10:01:07.038Z] 10:01:07     INFO -   55 |CondVar                               |       80       80|      51        1|
[task 2022-09-17T10:01:07.038Z] 10:01:07     INFO -  172 |Mutex                                 |       72      216|     420        3|
[task 2022-09-17T10:01:07.041Z] 10:01:07     INFO -  263 |PRemoteWorkerChild                    |       64       64|       1        1|
[task 2022-09-17T10:01:07.042Z] 10:01:07     INFO -  307 |RemoteWorkerChild                     |      224      224|       1        1|
[task 2022-09-17T10:01:07.042Z] 10:01:07     INFO -  348 |ShutdownOnWorker                      |       40       40|       1        1|
[task 2022-09-17T10:01:07.043Z] 10:01:07     INFO -  371 |ThreadEventTarget                     |       48       48|      15        1|
[task 2022-09-17T10:01:07.043Z] 10:01:07     INFO -  373 |ThreadSafeWeakReference               |       24       24|       3        1|
[task 2022-09-17T10:01:07.044Z] 10:01:07     INFO -  375 |ThreadTargetSink                      |       16       16|      15        1|
[task 2022-09-17T10:01:07.045Z] 10:01:07     INFO -  572 |nsStringBuffer                        |        8        8|    8826        1|
[task 2022-09-17T10:01:07.045Z] 10:01:07     INFO -  579 |nsThread                              |      456      456|      16        1|
[task 2022-09-17T10:01:07.046Z] 10:01:07     INFO -  608 |operator()                            |       40       40|      12        1|
[task 2022-09-17T10:01:07.046Z] 10:01:07     INFO - 
[task 2022-09-17T10:01:07.047Z] 10:01:07     INFO - nsTraceRefcnt::DumpStatistics: 611 entries
[task 2022-09-17T10:01:07.049Z] 10:01:07     INFO - TEST-INFO | leakcheck | tab leaked 1 CondVar
[task 2022-09-17T10:01:07.049Z] 10:01:07     INFO - TEST-INFO | leakcheck | tab leaked 3 Mutex
[task 2022-09-17T10:01:07.050Z] 10:01:07     INFO - TEST-INFO | leakcheck | tab leaked 1 PRemoteWorkerChild
[task 2022-09-17T10:01:07.050Z] 10:01:07     INFO - TEST-INFO | leakcheck | tab leaked 1 RemoteWorkerChild
[task 2022-09-17T10:01:07.050Z] 10:01:07     INFO - TEST-INFO | leakcheck | tab leaked 1 ShutdownOnWorker
[task 2022-09-17T10:01:07.051Z] 10:01:07     INFO - TEST-INFO | leakcheck | tab leaked 1 ThreadEventTarget
[task 2022-09-17T10:01:07.051Z] 10:01:07     INFO - TEST-INFO | leakcheck | tab leaked 1 ThreadSafeWeakReference
[task 2022-09-17T10:01:07.052Z] 10:01:07     INFO - TEST-INFO | leakcheck | tab leaked 1 ThreadTargetSink
[task 2022-09-17T10:01:07.052Z] 10:01:07     INFO - TEST-INFO | leakcheck | tab leaked 1 nsStringBuffer
[task 2022-09-17T10:01:07.052Z] 10:01:07     INFO - TEST-INFO | leakcheck | tab leaked 1 nsThread
[task 2022-09-17T10:01:07.053Z] 10:01:07     INFO - TEST-INFO | leakcheck | tab leaked 1 operator()
[task 2022-09-17T10:01:07.054Z] 10:01:07     INFO - TEST-UNEXPECTED-FAIL | leakcheck | tab 1216 bytes leaked (CondVar, Mutex, PRemoteWorkerChild, RemoteWorkerChild, ShutdownOnWorker, ...)
[task 2022-09-17T10:01:07.054Z] 10:01:07     INFO - 
[task 2022-09-17T10:01:07.054Z] 10:01:07     INFO - leakcheck | Processing leak log file /tmp/tmp3hb7dlob.mozrunner/runtests_leaks_tab_pid2011.log
[task 2022-09-17T10:01:07.055Z] 10:01:07     INFO - TEST-PASS | leakcheck | tab no leaks detected!
[task 2022-09-17T10:01:07.056Z] 10:01:07     INFO - leakcheck | Processing leak log file /tmp/tmp3hb7dlob.mozrunner/runtests_leaks_tab_pid1922.log
[task 2022-09-17T10:01:07.057Z] 10:01:07     INFO - TEST-PASS | leakcheck | tab no leaks detected!
[task 2022-09-17T10:01:07.057Z] 10:01:07     INFO - leakcheck | Processing leak log file /tmp/tmp3hb7dlob.mozrunner/runtests_leaks_tab_pid1788.log
[task 2022-09-17T10:01:07.057Z] 10:01:07     INFO - TEST-PASS | leakcheck | tab no leaks detected!
[task 2022-09-17T10:01:07.058Z] 10:01:07     INFO - leakcheck | Processing leak log file /tmp/tmp3hb7dlob.mozrunner/runtests_leaks_tab_pid1873.log
[task 2022-09-17T10:01:07.062Z] 10:01:07     INFO - TEST-PASS | leakcheck | tab no leaks detected!
[task 2022-09-17T10:01:07.063Z] 10:01:07     INFO - leakcheck | Processing leak log file /tmp/tmp3hb7dlob.mozrunner/runtests_leaks_tab_pid1739.log
[task 2022-09-17T10:01:07.063Z] 10:01:07     INFO - TEST-PASS | leakcheck | tab no leaks detected!
[task 2022-09-17T10:01:07.064Z] 10:01:07     INFO - leakcheck | Processing leak log file /tmp/tmp3hb7dlob.mozrunner/runtests_leaks_tab_pid1869.log
[task 2022-09-17T10:01:07.064Z] 10:01:07     INFO - TEST-PASS | leakcheck | tab no leaks detected!
[task 2022-09-17T10:01:07.065Z] 10:01:07     INFO - leakcheck | Processing leak log file /tmp/tmp3hb7dlob.mozrunner/runtests_leaks.log
[task 2022-09-17T10:01:07.070Z] 10:01:07     INFO - TEST-PASS | leakcheck | default no leaks detected!
[task 2022-09-17T10:01:07.070Z] 10:01:07     INFO - leakcheck | Processing leak log file /tmp/tmp3hb7dlob.mozrunner/runtests_leaks_tab_pid2095.log
[task 2022-09-17T10:01:07.072Z] 10:01:07     INFO - TEST-PASS | leakcheck | tab no leaks detected!
[task 2022-09-17T10:01:07.073Z] 10:01:07     INFO - leakcheck | Processing leak log file /tmp/tmp3hb7dlob.mozrunner/runtests_leaks_tab_pid2224.log
[task 2022-09-17T10:01:07.074Z] 10:01:07     INFO - TEST-PASS | leakcheck | tab no leaks detected!
[task 2022-09-17T10:01:07.075Z] 10:01:07     INFO - leakcheck | Processing leak log file /tmp/tmp3hb7dlob.mozrunner/runtests_leaks_tab_pid2341.log
[task 2022-09-17T10:01:07.076Z] 10:01:07     INFO - TEST-PASS | leakcheck | tab no leaks detected!
[task 2022-09-17T10:01:07.077Z] 10:01:07     INFO - leakcheck | Processing leak log file /tmp/tmp3hb7dlob.mozrunner/runtests_leaks_tab_pid2129.log
[task 2022-09-17T10:01:07.079Z] 10:01:07     INFO - TEST-PASS | leakcheck | tab no leaks detected!
[task 2022-09-17T10:01:07.079Z] 10:01:07     INFO - leakcheck | Processing leak log file /tmp/tmp3hb7dlob.mozrunner/runtests_leaks_tab_pid1979.log
[task 2022-09-17T10:01:07.081Z] 10:01:07     INFO - TEST-PASS | leakcheck | tab no leaks detected!
[task 2022-09-17T10:01:07.081Z] 10:01:07     INFO - runtests.py | Running tests: end.

Andrew are there any updates here?

Flags: needinfo?(bugmail)
Flags: needinfo?(bugmail)

There have been 43 total failures in the last 7 days, recent failure log.
Affected platforms are:

  • linux1804-64-qr

There have been 38 total failures in the last 7 days, recent failure log.
Affected platforms are:

  • linux1804-64-qr

There have been 35 total failures in the last 7 days, recent failure log.
Affected platforms are:

  • linux1804-64-qr

There have been 38 total failures in the last 7 days, recent failure log.
Affected platforms are:

  • linux1804-64-qr

I think my upcoming fix for bug 1775784 will fix this.

Assignee: nobody → bugmail
Status: NEW → ASSIGNED
Depends on: 1775784
Flags: needinfo?(bugmail)
Duplicate of this bug: 1796609

There have been 67 total failures in the last 7 days, recent failure log.
Affected platforms are:

  • linux1804-64-qr
[task 2022-11-20T09:51:03.729Z] 09:51:03     INFO - TEST-PASS | leakcheck | tab no leaks detected!
[task 2022-11-20T09:51:03.731Z] 09:51:03     INFO - leakcheck | Processing leak log file /tmp/tmplwx1g6tx.mozrunner/runtests_leaks_tab_pid7332.log
[task 2022-11-20T09:51:03.732Z] 09:51:03     INFO - 
[task 2022-11-20T09:51:03.733Z] 09:51:03     INFO - == BloatView: ALL (cumulative) LEAK AND BLOAT STATISTICS, tab process 7332
[task 2022-11-20T09:51:03.735Z] 09:51:03     INFO - 
[task 2022-11-20T09:51:03.736Z] 09:51:03     INFO -      |<----------------Class--------------->|<-----Bytes------>|<----Objects---->|
[task 2022-11-20T09:51:03.737Z] 09:51:03     INFO -      |                                      | Per-Inst   Leaked|   Total      Rem|
[task 2022-11-20T09:51:03.739Z] 09:51:03     INFO -    0 |TOTAL                                 |       51     1216|   14541       13|
[task 2022-11-20T09:51:03.740Z] 09:51:03     INFO -   48 |CondVar                               |       80       80|      46        1|
[task 2022-11-20T09:51:03.741Z] 09:51:03     INFO -  151 |Mutex                                 |       72      216|     380        3|
[task 2022-11-20T09:51:03.743Z] 09:51:03     INFO -  226 |PRemoteWorkerChild                    |       64       64|       1        1|
[task 2022-11-20T09:51:03.744Z] 09:51:03     INFO -  266 |RemoteWorkerChild                     |      224      224|       1        1|
[task 2022-11-20T09:51:03.746Z] 09:51:03     INFO -  305 |ShutdownOnWorker                      |       40       40|       1        1|
[task 2022-11-20T09:51:03.747Z] 09:51:03     INFO -  328 |ThreadEventTarget                     |       48       48|      13        1|
[task 2022-11-20T09:51:03.753Z] 09:51:03     INFO -  331 |ThreadSafeWeakReference               |       24       24|       3        1|
[task 2022-11-20T09:51:03.755Z] 09:51:03     INFO -  333 |ThreadTargetSink                      |       16       16|      13        1|
[task 2022-11-20T09:51:03.756Z] 09:51:03     INFO -  514 |nsStringBuffer                        |        8        8|    8378        1|
[task 2022-11-20T09:51:03.757Z] 09:51:03     INFO -  521 |nsThread                              |      456      456|      15        1|
[task 2022-11-20T09:51:03.759Z] 09:51:03     INFO -  549 |operator()                            |       40       40|      14        1|
[task 2022-11-20T09:51:03.760Z] 09:51:03     INFO - 
[task 2022-11-20T09:51:03.761Z] 09:51:03     INFO - nsTraceRefcnt::DumpStatistics: 552 entries
[task 2022-11-20T09:51:03.763Z] 09:51:03     INFO - TEST-INFO | leakcheck | tab leaked 1 CondVar
[task 2022-11-20T09:51:03.764Z] 09:51:03     INFO - TEST-INFO | leakcheck | tab leaked 3 Mutex
[task 2022-11-20T09:51:03.766Z] 09:51:03     INFO - TEST-INFO | leakcheck | tab leaked 1 PRemoteWorkerChild
[task 2022-11-20T09:51:03.767Z] 09:51:03     INFO - TEST-INFO | leakcheck | tab leaked 1 RemoteWorkerChild
[task 2022-11-20T09:51:03.768Z] 09:51:03     INFO - TEST-INFO | leakcheck | tab leaked 1 ShutdownOnWorker
[task 2022-11-20T09:51:03.770Z] 09:51:03     INFO - TEST-INFO | leakcheck | tab leaked 1 ThreadEventTarget
[task 2022-11-20T09:51:03.771Z] 09:51:03     INFO - TEST-INFO | leakcheck | tab leaked 1 ThreadSafeWeakReference
[task 2022-11-20T09:51:03.772Z] 09:51:03     INFO - TEST-INFO | leakcheck | tab leaked 1 ThreadTargetSink
[task 2022-11-20T09:51:03.774Z] 09:51:03     INFO - TEST-INFO | leakcheck | tab leaked 1 nsStringBuffer
[task 2022-11-20T09:51:03.775Z] 09:51:03     INFO - TEST-INFO | leakcheck | tab leaked 1 nsThread
[task 2022-11-20T09:51:03.776Z] 09:51:03     INFO - TEST-INFO | leakcheck | tab leaked 1 operator()
[task 2022-11-20T09:51:03.778Z] 09:51:03     INFO - TEST-UNEXPECTED-FAIL | leakcheck | tab 1216 bytes leaked (CondVar, Mutex, PRemoteWorkerChild, RemoteWorkerChild, ShutdownOnWorker, ...)
[task 2022-11-20T09:51:03.779Z] 09:51:03     INFO - 
[task 2022-11-20T09:51:03.780Z] 09:51:03     INFO - leakcheck | Processing leak log file /tmp/tmplwx1g6tx.mozrunner/runtests_leaks_tab_pid7052.log
[task 2022-11-20T09:51:03.781Z] 09:51:03     INFO - TEST-PASS | leakcheck | tab no leaks detected!
Flags: needinfo?(bugmail)

There have been 81 total failures in the last 7 days, recent failure log.
Affected platforms are:

  • linux1804-64-qr

There have been 85 total failures in the last 7 days, recent failure log.
Affected platforms are:

  • linux1804-64-qr

There have been 79 total failures in the last 7 days, recent failure log.
Affected platforms are:

  • linux1804-64-qr

There have been 52 total failures in the last 7 days, recent failure log.
Affected platforms are:

  • linux1804-64-qr

There have been 50 total failures in the last 7 days, recent failure log.
Affected platforms are:

  • linux1804-64-qr

Update:

There have been 79 failures within the last 7 days, all of them on Linux 18.04 x64 WebRender debug.

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=402337579&repo=autoland&lineNumber=3144

Andrew, do you have time to look at this?

Flags: needinfo?(bugmail)
Flags: needinfo?(bugmail)

There have been 86 total failures in the last 7 days, recent failure log.
Affected platforms are:

  • linux1804-64-qr

There have been 103 total failures in the last 7 days, recent failure log.
Affected platforms are:

  • linux1804-64-qr

There have been 110 total failures in the last 7 days, recent failure log.

All failures are on linux1804-64-qr.

There have been 110 total failures in the last 7 days.
All failures are on Linux 18.04 x64 WebRender debug.

Recent failure log.

[task 2023-02-14T05:27:29.088Z] 05:27:29     INFO - TEST-PASS | leakcheck | tab no leaks detected!
[task 2023-02-14T05:27:29.089Z] 05:27:29     INFO - leakcheck | Processing leak log file /tmp/tmptx_kfzan.mozrunner/runtests_leaks_tab_pid2475.log
[task 2023-02-14T05:27:29.090Z] 05:27:29     INFO - 
[task 2023-02-14T05:27:29.091Z] 05:27:29     INFO - == BloatView: ALL (cumulative) LEAK AND BLOAT STATISTICS, tab process 2475
[task 2023-02-14T05:27:29.092Z] 05:27:29     INFO - 
[task 2023-02-14T05:27:29.093Z] 05:27:29     INFO -      |<----------------Class--------------->|<-----Bytes------>|<----Objects---->|
[task 2023-02-14T05:27:29.094Z] 05:27:29     INFO -      |                                      | Per-Inst   Leaked|   Total      Rem|
[task 2023-02-14T05:27:29.095Z] 05:27:29     INFO -    0 |TOTAL                                 |       52     1208|   14337       13|
[task 2023-02-14T05:27:29.095Z] 05:27:29     INFO -   45 |CondVar                               |       80       80|      47        1|
[task 2023-02-14T05:27:29.096Z] 05:27:29     INFO -  141 |Mutex                                 |       72      216|     399        3|
[task 2023-02-14T05:27:29.097Z] 05:27:29     INFO -  211 |PRemoteWorkerChild                    |       64       64|       1        1|
[task 2023-02-14T05:27:29.098Z] 05:27:29     INFO -  251 |RemoteWorkerChild                     |      224      224|       1        1|
[task 2023-02-14T05:27:29.099Z] 05:27:29     INFO -  289 |ShutdownOnWorker                      |       40       40|       1        1|
[task 2023-02-14T05:27:29.100Z] 05:27:29     INFO -  312 |ThreadEventTarget                     |       48       48|      14        1|
[task 2023-02-14T05:27:29.101Z] 05:27:29     INFO -  315 |ThreadSafeWeakReference               |       24       24|       3        1|
[task 2023-02-14T05:27:29.102Z] 05:27:29     INFO -  317 |ThreadTargetSink                      |       16       16|      14        1|
[task 2023-02-14T05:27:29.103Z] 05:27:29     INFO -  499 |nsStringBuffer                        |        8        8|    8421        1|
[task 2023-02-14T05:27:29.104Z] 05:27:29     INFO -  506 |nsThread                              |      448      448|      16        1|
[task 2023-02-14T05:27:29.105Z] 05:27:29     INFO -  533 |operator()                            |       40       40|      10        1|
[task 2023-02-14T05:27:29.106Z] 05:27:29     INFO - 
[task 2023-02-14T05:27:29.107Z] 05:27:29     INFO - nsTraceRefcnt::DumpStatistics: 535 entries
[task 2023-02-14T05:27:29.108Z] 05:27:29     INFO - TEST-INFO | leakcheck | tab leaked 1 CondVar
[task 2023-02-14T05:27:29.109Z] 05:27:29     INFO - TEST-INFO | leakcheck | tab leaked 3 Mutex
[task 2023-02-14T05:27:29.110Z] 05:27:29     INFO - TEST-INFO | leakcheck | tab leaked 1 PRemoteWorkerChild
[task 2023-02-14T05:27:29.110Z] 05:27:29     INFO - TEST-INFO | leakcheck | tab leaked 1 RemoteWorkerChild
[task 2023-02-14T05:27:29.111Z] 05:27:29     INFO - TEST-INFO | leakcheck | tab leaked 1 ShutdownOnWorker
[task 2023-02-14T05:27:29.112Z] 05:27:29     INFO - TEST-INFO | leakcheck | tab leaked 1 ThreadEventTarget
[task 2023-02-14T05:27:29.113Z] 05:27:29     INFO - TEST-INFO | leakcheck | tab leaked 1 ThreadSafeWeakReference
[task 2023-02-14T05:27:29.114Z] 05:27:29     INFO - TEST-INFO | leakcheck | tab leaked 1 ThreadTargetSink
[task 2023-02-14T05:27:29.115Z] 05:27:29     INFO - TEST-INFO | leakcheck | tab leaked 1 nsStringBuffer
[task 2023-02-14T05:27:29.116Z] 05:27:29     INFO - TEST-INFO | leakcheck | tab leaked 1 nsThread
[task 2023-02-14T05:27:29.116Z] 05:27:29     INFO - TEST-INFO | leakcheck | tab leaked 1 operator()
[task 2023-02-14T05:27:29.118Z] 05:27:29     INFO - TEST-UNEXPECTED-FAIL | leakcheck | tab 1208 bytes leaked (CondVar, Mutex, PRemoteWorkerChild, RemoteWorkerChild, ShutdownOnWorker, ...)
[task 2023-02-14T05:27:29.118Z] 05:27:29     INFO - 
[task 2023-02-14T05:27:29.119Z] 05:27:29     INFO - leakcheck | Processing leak log file /tmp/tmptx_kfzan.mozrunner/runtests_leaks_tab_pid2885.log
[task 2023-02-14T05:27:29.120Z] 05:27:29     INFO - TEST-PASS | leakcheck | tab no leaks detected!

There has been a total of 137 total failures within the last 7 days, all of them on Linux 18.04 x64 WebRender debug.

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=406927958&repo=autoland&lineNumber=19108

[task 2023-02-25T13:19:15.046Z] 13:19:15     INFO - TEST-PASS | leakcheck | tab no leaks detected!
[task 2023-02-25T13:19:15.047Z] 13:19:15     INFO - leakcheck | Processing leak log file /tmp/tmprzosa49x.mozrunner/runtests_leaks_tab_pid12508.log
[task 2023-02-25T13:19:15.047Z] 13:19:15     INFO - 
[task 2023-02-25T13:19:15.048Z] 13:19:15     INFO - == BloatView: ALL (cumulative) LEAK AND BLOAT STATISTICS, tab process 12508
[task 2023-02-25T13:19:15.049Z] 13:19:15     INFO - 
[task 2023-02-25T13:19:15.050Z] 13:19:15     INFO -      |<----------------Class--------------->|<-----Bytes------>|<----Objects---->|
[task 2023-02-25T13:19:15.051Z] 13:19:15     INFO -      |                                      | Per-Inst   Leaked|   Total      Rem|
[task 2023-02-25T13:19:15.051Z] 13:19:15     INFO -    0 |TOTAL                                 |       52     1208|   14177       13|
[task 2023-02-25T13:19:15.052Z] 13:19:15     INFO -   45 |CondVar                               |       80       80|      47        1|
[task 2023-02-25T13:19:15.053Z] 13:19:15     INFO -  143 |Mutex                                 |       72      216|     395        3|
[task 2023-02-25T13:19:15.054Z] 13:19:15     INFO -  214 |PRemoteWorkerChild                    |       64       64|       1        1|
[task 2023-02-25T13:19:15.054Z] 13:19:15     INFO -  253 |RemoteWorkerChild                     |      224      224|       1        1|
[task 2023-02-25T13:19:15.055Z] 13:19:15     INFO -  291 |ShutdownOnWorker                      |       40       40|       1        1|
[task 2023-02-25T13:19:15.056Z] 13:19:15     INFO -  314 |ThreadEventTarget                     |       48       48|      14        1|
[task 2023-02-25T13:19:15.057Z] 13:19:15     INFO -  317 |ThreadSafeWeakReference               |       24       24|       3        1|
[task 2023-02-25T13:19:15.058Z] 13:19:15     INFO -  319 |ThreadTargetSink                      |       16       16|      14        1|
[task 2023-02-25T13:19:15.058Z] 13:19:15     INFO -  499 |nsStringBuffer                        |        8        8|    8395        1|
[task 2023-02-25T13:19:15.059Z] 13:19:15     INFO -  506 |nsThread                              |      448      448|      16        1|
[task 2023-02-25T13:19:15.060Z] 13:19:15     INFO -  532 |operator()                            |       40       40|      10        1|
[task 2023-02-25T13:19:15.060Z] 13:19:15     INFO - 
[task 2023-02-25T13:19:15.061Z] 13:19:15     INFO - nsTraceRefcnt::DumpStatistics: 534 entries
[task 2023-02-25T13:19:15.062Z] 13:19:15     INFO - TEST-INFO | leakcheck | tab leaked 1 CondVar
[task 2023-02-25T13:19:15.063Z] 13:19:15     INFO - TEST-INFO | leakcheck | tab leaked 3 Mutex
[task 2023-02-25T13:19:15.063Z] 13:19:15     INFO - TEST-INFO | leakcheck | tab leaked 1 PRemoteWorkerChild
[task 2023-02-25T13:19:15.064Z] 13:19:15     INFO - TEST-INFO | leakcheck | tab leaked 1 RemoteWorkerChild
[task 2023-02-25T13:19:15.065Z] 13:19:15     INFO - TEST-INFO | leakcheck | tab leaked 1 ShutdownOnWorker
[task 2023-02-25T13:19:15.065Z] 13:19:15     INFO - TEST-INFO | leakcheck | tab leaked 1 ThreadEventTarget
[task 2023-02-25T13:19:15.066Z] 13:19:15     INFO - TEST-INFO | leakcheck | tab leaked 1 ThreadSafeWeakReference
[task 2023-02-25T13:19:15.067Z] 13:19:15     INFO - TEST-INFO | leakcheck | tab leaked 1 ThreadTargetSink
[task 2023-02-25T13:19:15.067Z] 13:19:15     INFO - TEST-INFO | leakcheck | tab leaked 1 nsStringBuffer
[task 2023-02-25T13:19:15.068Z] 13:19:15     INFO - TEST-INFO | leakcheck | tab leaked 1 nsThread
[task 2023-02-25T13:19:15.069Z] 13:19:15     INFO - TEST-INFO | leakcheck | tab leaked 1 operator()
[task 2023-02-25T13:19:15.070Z] 13:19:15     INFO - TEST-UNEXPECTED-FAIL | leakcheck | tab 1208 bytes leaked (CondVar, Mutex, PRemoteWorkerChild, RemoteWorkerChild, ShutdownOnWorker, ...)

Jari, can you help us assign this to someone?
Thank you!

Flags: needinfo?(jjalkanen)

This will be fixed by the landing of bug 1775784 which is currently undergoing extensive review.

Flags: needinfo?(jjalkanen)
Flags: needinfo?(bugmail)

(In reply to Andrew Sutherland [:asuth] (he/him) from comment #160)

This will be fixed by the landing of bug 1775784 which is currently undergoing extensive review.

Fix seems to be confirmed by the data.

Status: ASSIGNED → RESOLVED
Closed: 2 years ago
Resolution: --- → WORKSFORME
See Also: → 1824506
See Also: 1824506
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: