[taskcluster 2025-01-10 21:26:57.118Z] Task ID: bwOBCiDpRfa1hLHzMUrmag
[taskcluster 2025-01-10 21:26:57.118Z] Worker ID: 3392017151734591612
[taskcluster 2025-01-10 21:26:57.118Z] Worker Group: us-west1-a
[taskcluster 2025-01-10 21:26:57.118Z] Worker Node Type: projects/474530013412/machineTypes/c2-standard-4
[taskcluster 2025-01-10 21:26:57.118Z] Worker Type: t-linux-large-noscratch-gcp
[taskcluster 2025-01-10 21:26:57.118Z] Public IP: 35.230.11.155
[taskcluster 2025-01-10 21:26:57.118Z] Hostname: gecko-t-t-linux-large-noscratch-gcp-eozzlirwq1cx84aw7qxbxw
[taskcluster 2025-01-10 21:26:57.118Z] using cache "ci-level-1-checkouts-hg58-v3-51c21ecd6de64212b936" -> /builds/worker/checkouts
[taskcluster 2025-01-10 21:26:57.118Z] using cache "ci-level-1-tooltool-cache-v3-51c21ecd6de64212b936" -> /builds/worker/tooltool-cache

[taskcluster 2025-01-10 21:26:58.105Z] Image 'public/image.tar.zst' from task 'RSV3FRr9SaSCVjsZt1klJA' loaded.  Using image ID sha256:3d8e26c0e4876a61c08e88451bc57d93cca9293a01ac793a915af37d2799fd46.
[taskcluster 2025-01-10 21:26:58.117Z] === Task Starting ===
 * Starting system message bus dbus        
[ OK ]
[setup 2025-01-10T21:26:58.606Z] run-task started in /builds/worker
[cache 2025-01-10T21:26:58.608Z] cache /builds/worker/checkouts exists; requirements: gid=1000 uid=1000 version=1
[cache 2025-01-10T21:26:58.608Z] cache /builds/worker/tooltool-cache exists; requirements: gid=1000 uid=1000 version=1
[volume 2025-01-10T21:26:58.608Z] changing ownership of volume /builds/worker/.cache to 1000:1000
[volume 2025-01-10T21:26:58.608Z] volume /builds/worker/checkouts is a cache
[volume 2025-01-10T21:26:58.608Z] volume /builds/worker/tooltool-cache is a cache
[volume 2025-01-10T21:26:58.608Z] changing ownership of volume /builds/worker/workspace to 1000:1000

...(3376 lines hidden)...

[task 2025-01-10T21:29:48.419Z] 21:29:48     INFO - GECKO(2023) | MEMORY STAT | vsize 10856MB | residentFast 189MB | heapAllocated 17MB
[task 2025-01-10T21:29:48.494Z] 21:29:48     INFO - TEST-OK | widget/tests/test_clipboard.html | took 350ms
[task 2025-01-10T21:29:48.580Z] 21:29:48     INFO - TEST-START | widget/tests/test_clipboard_asyncSetData.html
[task 2025-01-10T21:29:48.940Z] 21:29:48     INFO - GECKO(2023) | MEMORY STAT | vsize 10856MB | residentFast 191MB | heapAllocated 18MB
[task 2025-01-10T21:29:49.050Z] 21:29:49     INFO - TEST-OK | widget/tests/test_clipboard_asyncSetData.html | took 464ms
[task 2025-01-10T21:29:49.159Z] 21:29:49     INFO - TEST-START | widget/tests/test_clipboard_getDataSnapshot.html
[task 2025-01-10T21:29:49.411Z] 21:29:49     INFO - GECKO(2023) | [Parent 2023, Main Thread] WARNING: IPC message 'PClipboardReadRequest::Reply_GetData' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:557
[task 2025-01-10T21:29:49.461Z] 21:29:49     INFO - GECKO(2023) | [Parent 2023, Main Thread] WARNING: IPC message 'PClipboardReadRequest::Reply_GetData' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:557
[task 2025-01-10T21:29:49.553Z] 21:29:49     INFO - GECKO(2023) | [Parent 2023, Main Thread] WARNING: IPC message 'PClipboardReadRequest::Reply_GetData' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:557
[task 2025-01-10T21:29:49.602Z] 21:29:49     INFO - GECKO(2023) | [Parent 2023, Main Thread] WARNING: IPC message 'PClipboardReadRequest::Reply_GetData' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:557
[task 2025-01-10T21:29:49.645Z] 21:29:49     INFO - GECKO(2023) | MEMORY STAT | vsize 10856MB | residentFast 192MB | heapAllocated 18MB
[task 2025-01-10T21:29:49.708Z] 21:29:49     INFO - TEST-OK | widget/tests/test_clipboard_getDataSnapshot.html | took 550ms
[task 2025-01-10T21:29:49.818Z] 21:29:49     INFO - TEST-START | widget/tests/test_clipboard_getDataSnapshotSync.html
[task 2025-01-10T21:29:50.084Z] 21:29:50     INFO - GECKO(2023) | [Parent 2023, Main Thread] WARNING: IPC message 'PClipboardReadRequest::Reply_GetData' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:557
[task 2025-01-10T21:29:50.129Z] 21:29:50     INFO - GECKO(2023) | [Parent 2023, Main Thread] WARNING: IPC message 'PClipboardReadRequest::Reply_GetData' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:557
[task 2025-01-10T21:29:50.209Z] 21:29:50     INFO - GECKO(2023) | [Parent 2023, Main Thread] WARNING: IPC message 'PClipboardReadRequest::Reply_GetData' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:557
[task 2025-01-10T21:29:50.250Z] 21:29:50     INFO - GECKO(2023) | [Parent 2023, Main Thread] WARNING: IPC message 'PClipboardReadRequest::Reply_GetData' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:557
[task 2025-01-10T21:29:50.289Z] 21:29:50     INFO - GECKO(2023) | MEMORY STAT | vsize 10856MB | residentFast 191MB | heapAllocated 18MB
[task 2025-01-10T21:29:50.352Z] 21:29:50     INFO - TEST-OK | widget/tests/test_clipboard_getDataSnapshotSync.html | took 535ms
[task 2025-01-10T21:29:50.471Z] 21:29:50     INFO - TEST-START | widget/tests/test_contextmenu_by_mouse_on_unix.html
[task 2025-01-10T21:29:50.802Z] 21:29:50     INFO - GECKO(2023) | MEMORY STAT | vsize 2664MB | residentFast 192MB | heapAllocated 18MB
[task 2025-01-10T21:29:50.892Z] 21:29:50     INFO - TEST-OK | widget/tests/test_contextmenu_by_mouse_on_unix.html | took 417ms
[task 2025-01-10T21:29:51.006Z] 21:29:51     INFO - TEST-START | widget/tests/test_textScaleFactor_system_font.html
[task 2025-01-10T21:29:51.778Z] 21:29:51     INFO - GECKO(2023) | MEMORY STAT | vsize 2664MB | residentFast 191MB | heapAllocated 18MB
[task 2025-01-10T21:29:52.249Z] 21:29:52     INFO - TEST-OK | widget/tests/test_textScaleFactor_system_font.html | took 1241ms
[task 2025-01-10T21:29:52.360Z] 21:29:52     INFO - TEST-START | Shutdown
[task 2025-01-10T21:29:52.360Z] 21:29:52     INFO - Passed:  2789
[task 2025-01-10T21:29:52.361Z] 21:29:52     INFO - Failed:  0
[task 2025-01-10T21:29:52.361Z] 21:29:52     INFO - Todo:    68
[task 2025-01-10T21:29:52.362Z] 21:29:52     INFO - Mode:    e10s
[task 2025-01-10T21:29:52.364Z] 21:29:52     INFO - Slowest: 5572ms - /tests/widget/tests/test_assign_event_data.html
[task 2025-01-10T21:29:52.365Z] 21:29:52     INFO - SimpleTest FINISHED
[task 2025-01-10T21:29:52.366Z] 21:29:52     INFO - TEST-INFO | Ran 1 Loops
[task 2025-01-10T21:29:52.366Z] 21:29:52     INFO - SimpleTest FINISHED
[task 2025-01-10T21:29:52.874Z] 21:29:52     INFO - GECKO(2023) | JavaScript error: resource://gre/modules/AsyncShutdown.sys.mjs, line 569: NotFoundError: No such JSWindowActor 'SpecialPowers'
[task 2025-01-10T21:29:52.881Z] 21:29:52     INFO - GECKO(2023) | JavaScript error: resource://gre/modules/AsyncShutdown.sys.mjs, line 569: NotFoundError: No such JSWindowActor 'AppTestDelegate'
[task 2025-01-10T21:29:52.882Z] 21:29:52     INFO - GECKO(2023) | JavaScript error: resource://gre/modules/AsyncShutdown.sys.mjs, line 569: NotFoundError: No such JSWindowActor 'AppTestDelegate'
[task 2025-01-10T21:29:52.962Z] 21:29:52     INFO - GECKO(2023) | 1736544592961	Marionette	TRACE	Received observer notification quit-application
[task 2025-01-10T21:29:52.964Z] 21:29:52     INFO - GECKO(2023) | 1736544592962	Marionette	INFO	Stopped listening on port 2828
[task 2025-01-10T21:29:52.970Z] 21:29:52     INFO - GECKO(2023) | 1736544592970	Marionette	DEBUG	Marionette stopped listening
[task 2025-01-10T21:29:53.047Z] 21:29:53     INFO - GECKO(2023) | [Child 2224, Main Thread] WARNING: IPC message 'PContent::Msg_StoreUserInteractionAsPermission' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:557
[task 2025-01-10T21:29:53.047Z] 21:29:53     INFO - GECKO(2023) | [Child 2224, Main Thread] WARNING: NS_ENSURE_TRUE(aWindowContext) failed: file /builds/worker/checkouts/gecko/toolkit/components/antitracking/bouncetrackingprotection/BounceTrackingProtection.cpp:437
[task 2025-01-10T21:29:53.049Z] 21:29:53     INFO - GECKO(2023) | [Child 2224, Main Thread] WARNING: IPC message 'PContent::Msg_StoreUserInteractionAsPermission' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:557
[task 2025-01-10T21:29:53.050Z] 21:29:53     INFO - GECKO(2023) | [Child 2224, Main Thread] WARNING: NS_ENSURE_TRUE(aWindowContext) failed: file /builds/worker/checkouts/gecko/toolkit/components/antitracking/bouncetrackingprotection/BounceTrackingProtection.cpp:437
[task 2025-01-10T21:29:53.064Z] 21:29:53     INFO - GECKO(2023) | [Parent 2023, Socket Thread] WARNING: cannot post event if not initialized: file /builds/worker/checkouts/gecko/netwerk/protocol/http/nsHttpConnectionMgr.cpp:235
[task 2025-01-10T21:29:53.065Z] 21:29:53     INFO - GECKO(2023) | [Parent 2023, Socket Thread] WARNING: cannot post event if not initialized: file /builds/worker/checkouts/gecko/netwerk/protocol/http/nsHttpConnectionMgr.cpp:235
[task 2025-01-10T21:29:53.585Z] 21:29:53     INFO - GECKO(2023) | [Parent 2023, Main Thread] WARNING: BlockShutdown: Init failed: 'NS_FAILED(rv)', file /builds/worker/checkouts/gecko/toolkit/components/antitracking/bouncetrackingprotection/BounceTrackingProtectionStorage.cpp:378
[task 2025-01-10T21:29:53.734Z] 21:29:53     INFO - GECKO(2023) | [Parent 2023, IPDL Background] WARNING: quota manager shutdown step: '0.000000s: startCrashBrowserTimer', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2316
[task 2025-01-10T21:29:53.736Z] 21:29:53     INFO - GECKO(2023) | [Parent 2023, IPDL Background] WARNING: quota manager shutdown step: '0.000000s: initiateShutdownWorkThreads', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2316
[task 2025-01-10T21:29:53.736Z] 21:29:53     INFO - GECKO(2023) | [Parent 2023, IPDL Background] WARNING: idb: '0.000000s: starting', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2316
[task 2025-01-10T21:29:53.737Z] 21:29:53     INFO - GECKO(2023) | [Parent 2023, IPDL Background] WARNING: cache: '0.000000s: starting', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2316
[task 2025-01-10T21:29:53.737Z] 21:29:53     INFO - GECKO(2023) | [Parent 2023, IPDL Background] WARNING: sdb: '0.000000s: starting', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2316
[task 2025-01-10T21:29:53.737Z] 21:29:53     INFO - GECKO(2023) | [Parent 2023, IPDL Background] WARNING: fs: '0.000000s: starting', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2316
[task 2025-01-10T21:29:53.737Z] 21:29:53     INFO - GECKO(2023) | [Parent 2023, IPDL Background] WARNING: ls: '0.000000s: starting', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2316
[task 2025-01-10T21:29:53.738Z] 21:29:53     INFO - GECKO(2023) | [Parent 2023, IPDL Background] WARNING: quota manager shutdown step: '0.000000s: startKillActorsTimer', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2316
[task 2025-01-10T21:29:53.738Z] 21:29:53     INFO - GECKO(2023) | [Parent 2023, IPDL Background] WARNING: idb: '0.000000s: Live database entry removed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2316
[task 2025-01-10T21:29:53.738Z] 21:29:53     INFO - GECKO(2023) | [Parent 2023, IPDL Background] WARNING: idb: '0.000000s: gLiveDatabaseHashtable entry removed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2316
[task 2025-01-10T21:29:53.742Z] 21:29:53     INFO - GECKO(2023) | [Parent 2023, IPDL Background] WARNING: idb: '0.004000s: Live database entry removed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2316
[task 2025-01-10T21:29:53.742Z] 21:29:53     INFO - GECKO(2023) | [Parent 2023, IPDL Background] WARNING: idb: '0.004000s: Live database entry removed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2316
[task 2025-01-10T21:29:53.743Z] 21:29:53     INFO - GECKO(2023) | [Parent 2023, IPDL Background] WARNING: idb: '0.004000s: gLiveDatabaseHashtable entry removed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2316
[task 2025-01-10T21:29:53.743Z] 21:29:53     INFO - GECKO(2023) | [Parent 2023, QuotaManager IO] WARNING: quota manager shutdown step: '0.004000s: ShutdownStorageOp::DoDirectoryWork -> ShutdownStorageInternal.', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2316
[task 2025-01-10T21:29:53.756Z] 21:29:53     INFO - GECKO(2023) | [Parent 2023, IPDL Background] WARNING: quota manager shutdown step: '0.020000s: stopKillActorsTimer', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2316
[task 2025-01-10T21:29:53.757Z] 21:29:53     INFO - GECKO(2023) | [Parent 2023, IPDL Background] WARNING: quota manager shutdown step: '0.020000s: shutdownAndJoinWorkThreads', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2316
[task 2025-01-10T21:29:53.760Z] 21:29:53     INFO - GECKO(2023) | [Parent 2023, IPDL Background] WARNING: idb: '0.020000s: completed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2316
[task 2025-01-10T21:29:53.760Z] 21:29:53     INFO - GECKO(2023) | [Parent 2023, IPDL Background] WARNING: cache: '0.020000s: completed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2316
[task 2025-01-10T21:29:53.760Z] 21:29:53     INFO - GECKO(2023) | [Parent 2023, IPDL Background] WARNING: sdb: '0.020000s: completed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2316
[task 2025-01-10T21:29:53.760Z] 21:29:53     INFO - GECKO(2023) | [Parent 2023, IPDL Background] WARNING: fs: '0.020000s: completed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2316
[task 2025-01-10T21:29:53.760Z] 21:29:53     INFO - GECKO(2023) | [Parent 2023, IPDL Background] WARNING: ls: '0.020000s: completed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2316
[task 2025-01-10T21:29:53.760Z] 21:29:53     INFO - GECKO(2023) | [Parent 2023, IPDL Background] WARNING: quota manager shutdown step: '0.020000s: shutdownAndJoinIOThread', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2316
[task 2025-01-10T21:29:53.760Z] 21:29:53     INFO - GECKO(2023) | [Parent 2023, IPDL Background] WARNING: quota manager shutdown step: '0.020000s: invalidatePendingDirectoryLocks', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2316
[task 2025-01-10T21:29:53.760Z] 21:29:53     INFO - GECKO(2023) | [Parent 2023, IPDL Background] WARNING: quota manager shutdown step: '0.020000s: stopCrashBrowserTimer', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2316
[task 2025-01-10T21:29:53.886Z] 21:29:53     INFO - GECKO(2023) | [Parent 2023, Main Thread] WARNING: NS_ENSURE_TRUE(aWindowContext) failed: file /builds/worker/checkouts/gecko/toolkit/components/antitracking/bouncetrackingprotection/BounceTrackingProtection.cpp:437
[task 2025-01-10T21:29:53.891Z] 21:29:53     INFO - GECKO(2023) | [Utility 2216, Main Thread] WARNING: IPC message 'PUtilityProcess::Msg_FOGData' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:557
[task 2025-01-10T21:29:53.913Z] 21:29:53     INFO - GECKO(2023) | [RDD 2122, Main Thread] WARNING: IPC message 'PRDD::Msg_FOGData' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:557
[task 2025-01-10T21:29:53.929Z] 21:29:53     INFO - GECKO(2023) | Destroying context 7f882de29c80 surface 0 on display 7f882de2f100
[task 2025-01-10T21:29:54.682Z] 21:29:54     INFO - GECKO(2023) | [Parent 2023, Main Thread] WARNING: NS_ENSURE_SUCCESS_VOID(rv) failed with result 0x8000FFFF (NS_ERROR_UNEXPECTED): file /builds/worker/checkouts/gecko/dom/file/uri/BlobURLProtocolHandler.cpp:406
[task 2025-01-10T21:29:54.683Z] 21:29:54     INFO - GECKO(2023) | [Parent 2023, Main Thread] WARNING: NS_ENSURE_TRUE(!!svc) failed: file /builds/worker/checkouts/gecko/dom/file/uri/BlobURLProtocolHandler.cpp:506
[task 2025-01-10T21:29:54.684Z] 21:29:54     INFO - GECKO(2023) | [Parent 2023, Main Thread] WARNING: NS_ENSURE_SUCCESS_VOID(rv) failed with result 0x8000FFFF (NS_ERROR_UNEXPECTED): file /builds/worker/checkouts/gecko/dom/file/uri/BlobURLProtocolHandler.cpp:406
[task 2025-01-10T21:29:54.685Z] 21:29:54     INFO - GECKO(2023) | [Parent 2023, Main Thread] WARNING: NS_ENSURE_TRUE(!!svc) failed: file /builds/worker/checkouts/gecko/dom/file/uri/BlobURLProtocolHandler.cpp:506
[task 2025-01-10T21:29:54.685Z] 21:29:54     INFO - GECKO(2023) | [Parent 2023, Main Thread] WARNING: NS_ENSURE_SUCCESS_VOID(rv) failed with result 0x8000FFFF (NS_ERROR_UNEXPECTED): file /builds/worker/checkouts/gecko/dom/file/uri/BlobURLProtocolHandler.cpp:406
[task 2025-01-10T21:29:54.686Z] 21:29:54     INFO - GECKO(2023) | [Parent 2023, Main Thread] WARNING: NS_ENSURE_TRUE(!!svc) failed: file /builds/worker/checkouts/gecko/dom/file/uri/BlobURLProtocolHandler.cpp:506
[task 2025-01-10T21:29:54.686Z] 21:29:54     INFO - GECKO(2023) | [Parent 2023, Main Thread] WARNING: NS_ENSURE_SUCCESS_VOID(rv) failed with result 0x8000FFFF (NS_ERROR_UNEXPECTED): file /builds/worker/checkouts/gecko/dom/file/uri/BlobURLProtocolHandler.cpp:406
[task 2025-01-10T21:29:54.687Z] 21:29:54     INFO - GECKO(2023) | [Parent 2023, Main Thread] WARNING: NS_ENSURE_TRUE(!!svc) failed: file /builds/worker/checkouts/gecko/dom/file/uri/BlobURLProtocolHandler.cpp:506
[task 2025-01-10T21:29:54.687Z] 21:29:54     INFO - GECKO(2023) | [Parent 2023, Main Thread] WARNING: NS_ENSURE_SUCCESS_VOID(rv) failed with result 0x8000FFFF (NS_ERROR_UNEXPECTED): file /builds/worker/checkouts/gecko/dom/file/uri/BlobURLProtocolHandler.cpp:406
[task 2025-01-10T21:29:54.688Z] 21:29:54     INFO - GECKO(2023) | [Parent 2023, Main Thread] WARNING: NS_ENSURE_TRUE(!!svc) failed: file /builds/worker/checkouts/gecko/dom/file/uri/BlobURLProtocolHandler.cpp:506
[task 2025-01-10T21:29:54.688Z] 21:29:54     INFO - GECKO(2023) | [Parent 2023, Main Thread] WARNING: NS_ENSURE_SUCCESS_VOID(rv) failed with result 0x8000FFFF (NS_ERROR_UNEXPECTED): file /builds/worker/checkouts/gecko/dom/file/uri/BlobURLProtocolHandler.cpp:406
[task 2025-01-10T21:29:54.689Z] 21:29:54     INFO - GECKO(2023) | [Parent 2023, Main Thread] WARNING: NS_ENSURE_TRUE(!!svc) failed: file /builds/worker/checkouts/gecko/dom/file/uri/BlobURLProtocolHandler.cpp:506
[task 2025-01-10T21:29:54.734Z] 21:29:54     INFO - GECKO(2023) | [Parent 2023, IPC I/O Parent] WARNING: process 2216 is a zombie: file /builds/worker/checkouts/gecko/ipc/chromium/src/base/process_util_posix.cc:245
[task 2025-01-10T21:29:54.735Z] 21:29:54     INFO - GECKO(2023) | [Parent 2023, IPC I/O Parent] WARNING: process 2122 is a zombie: file /builds/worker/checkouts/gecko/ipc/chromium/src/base/process_util_posix.cc:245
[task 2025-01-10T21:29:54.751Z] 21:29:54     INFO - TEST-INFO | Main app process: exit 0
[task 2025-01-10T21:29:54.751Z] 21:29:54     INFO - runtests.py | Application ran for: 0:00:23.351105
[task 2025-01-10T21:29:54.752Z] 21:29:54     INFO - zombiecheck | Reading PID log: /tmp/tmpg9fs12tlpidlog
[task 2025-01-10T21:29:54.752Z] 21:29:54     INFO - ==> process 2023 launched child process 2097
[task 2025-01-10T21:29:54.752Z] 21:29:54     INFO - zombiecheck | Checking for orphan process with PID: 2097
[task 2025-01-10T21:29:54.753Z] 21:29:54     INFO - Stopping web server
[task 2025-01-10T21:29:54.755Z] 21:29:54     INFO - Server shut down.
[task 2025-01-10T21:29:54.757Z] 21:29:54     INFO - Web server killed.
[task 2025-01-10T21:29:54.757Z] 21:29:54     INFO - Stopping web socket server
[task 2025-01-10T21:29:54.757Z] 21:29:54     INFO - Stopping ssltunnel
[task 2025-01-10T21:29:54.757Z] 21:29:54     INFO - Stopping gst for v4l2loopback
[task 2025-01-10T21:29:54.757Z] 21:29:54     INFO - leakcheck | Processing log file /tmp/tmp0cxher1t.mozrunner/runtests_leaks.log for scope widget/tests/mochitest.toml
[task 2025-01-10T21:29:54.760Z] 21:29:54     INFO - TEST-INFO | leakcheck | default process: leak threshold set at 0 bytes
[task 2025-01-10T21:29:54.760Z] 21:29:54     INFO - TEST-INFO | leakcheck | tab process: leak threshold set at 0 bytes
[task 2025-01-10T21:29:54.760Z] 21:29:54     INFO - TEST-INFO | leakcheck | gmplugin process: leak threshold set at 20000 bytes
[task 2025-01-10T21:29:54.760Z] 21:29:54     INFO - TEST-INFO | leakcheck | gpu process: leak threshold set at 0 bytes
[task 2025-01-10T21:29:54.760Z] 21:29:54     INFO - TEST-INFO | leakcheck | vr process: leak threshold set at 0 bytes
[task 2025-01-10T21:29:54.760Z] 21:29:54     INFO - TEST-INFO | leakcheck | rdd process: leak threshold set at 0 bytes
[task 2025-01-10T21:29:54.760Z] 21:29:54     INFO - TEST-INFO | leakcheck | socket process: leak threshold set at 0 bytes
[task 2025-01-10T21:29:54.760Z] 21:29:54     INFO - TEST-INFO | leakcheck | forkserver process: leak threshold set at 0 bytes
[task 2025-01-10T21:29:54.761Z] 21:29:54     INFO - TEST-INFO | leakcheck | utility process: leak threshold set at 0 bytes
[task 2025-01-10T21:29:54.761Z] 21:29:54     INFO - leakcheck | Processing leak log file /tmp/tmp0cxher1t.mozrunner/runtests_leaks_rdd_pid2122.log
[task 2025-01-10T21:29:54.761Z] 21:29:54     INFO - TEST-PASS | leakcheck | rdd no leaks detected!
[task 2025-01-10T21:29:54.761Z] 21:29:54     INFO - leakcheck | Processing leak log file /tmp/tmp0cxher1t.mozrunner/runtests_leaks_tab_pid2287.log
[task 2025-01-10T21:29:54.761Z] 21:29:54     INFO - TEST-PASS | leakcheck | tab no leaks detected!
[task 2025-01-10T21:29:54.762Z] 21:29:54     INFO - leakcheck | Processing leak log file /tmp/tmp0cxher1t.mozrunner/runtests_leaks_tab_pid2224.log
[task 2025-01-10T21:29:54.764Z] 21:29:54     INFO - TEST-PASS | leakcheck | tab no leaks detected!
[task 2025-01-10T21:29:54.764Z] 21:29:54     INFO - leakcheck | Processing leak log file /tmp/tmp0cxher1t.mozrunner/runtests_leaks_tab_pid2227.log
[task 2025-01-10T21:29:54.765Z] 21:29:54     INFO - TEST-PASS | leakcheck | tab no leaks detected!
[task 2025-01-10T21:29:54.766Z] 21:29:54     INFO - leakcheck | Processing leak log file /tmp/tmp0cxher1t.mozrunner/runtests_leaks_tab_pid2112.log
[task 2025-01-10T21:29:54.767Z] 21:29:54     INFO - TEST-PASS | leakcheck | tab no leaks detected!
[task 2025-01-10T21:29:54.767Z] 21:29:54     INFO - leakcheck | Processing leak log file /tmp/tmp0cxher1t.mozrunner/runtests_leaks_forkserver_pid2097.log
[task 2025-01-10T21:29:54.768Z] 21:29:54     INFO - TEST-PASS | leakcheck | forkserver no leaks detected!
[task 2025-01-10T21:29:54.768Z] 21:29:54     INFO - leakcheck | Processing leak log file /tmp/tmp0cxher1t.mozrunner/runtests_leaks_tab_pid2340.log
[task 2025-01-10T21:29:54.768Z] 21:29:54     INFO - TEST-PASS | leakcheck | tab no leaks detected!
[task 2025-01-10T21:29:54.769Z] 21:29:54     INFO - leakcheck | Processing leak log file /tmp/tmp0cxher1t.mozrunner/runtests_leaks_tab_pid2248.log
[task 2025-01-10T21:29:54.769Z] 21:29:54     INFO - TEST-PASS | leakcheck | tab no leaks detected!
[task 2025-01-10T21:29:54.770Z] 21:29:54     INFO - leakcheck | Processing leak log file /tmp/tmp0cxher1t.mozrunner/runtests_leaks.log
[task 2025-01-10T21:29:54.774Z] 21:29:54     INFO - TEST-PASS | leakcheck | default no leaks detected!
[task 2025-01-10T21:29:54.774Z] 21:29:54     INFO - leakcheck | Processing leak log file /tmp/tmp0cxher1t.mozrunner/runtests_leaks_utility_pid2216.log
[task 2025-01-10T21:29:54.774Z] 21:29:54     INFO - TEST-PASS | leakcheck | utility no leaks detected!
[task 2025-01-10T21:29:54.775Z] 21:29:54     INFO - leakcheck | Processing leak log file /tmp/tmp0cxher1t.mozrunner/runtests_leaks_tab_pid2152.log
[task 2025-01-10T21:29:54.776Z] 21:29:54     INFO - TEST-PASS | leakcheck | tab no leaks detected!
[task 2025-01-10T21:29:54.776Z] 21:29:54     INFO - runtests.py | Running tests: end.
[task 2025-01-10T21:29:54.826Z] 21:29:54     INFO - Buffered messages finished
[task 2025-01-10T21:29:54.827Z] 21:29:54     INFO -  0 INFO TEST-START | Shutdown
[task 2025-01-10T21:29:54.827Z] 21:29:54     INFO -  1 INFO Passed:  29082
[task 2025-01-10T21:29:54.827Z] 21:29:54     INFO -  2 INFO Failed:  0
[task 2025-01-10T21:29:54.827Z] 21:29:54     INFO -  3 INFO Todo:    98
[task 2025-01-10T21:29:54.827Z] 21:29:54     INFO -  4 INFO Mode:    e10s
[task 2025-01-10T21:29:54.827Z] 21:29:54     INFO -  5 INFO SimpleTest FINISHED
[task 2025-01-10T21:29:54.827Z] 21:29:54     INFO - Buffered messages finished
[task 2025-01-10T21:29:54.828Z] 21:29:54     INFO - SUITE-END | took 80s
[task 2025-01-10T21:29:54.859Z] 21:29:54     INFO - Return code: 0
[task 2025-01-10T21:29:54.860Z] 21:29:54     INFO - TinderboxPrint: mochitest-mochitest-plain<br/>80/0/0
[task 2025-01-10T21:29:54.860Z] 21:29:54     INFO - The mochitest suite: mochitest-plain ran with return status: SUCCESS
[task 2025-01-10T21:29:54.860Z] 21:29:54     INFO - Running post-action listener: _package_coverage_data
[task 2025-01-10T21:29:54.860Z] 21:29:54     INFO - Running post-action listener: _resource_record_post_action
[task 2025-01-10T21:29:54.860Z] 21:29:54     INFO - Running post-action listener: process_java_coverage_data
[task 2025-01-10T21:29:54.860Z] 21:29:54     INFO - [mozharness: 2025-01-10 21:29:54.860711Z] Finished run-tests step (success)
[task 2025-01-10T21:29:54.860Z] 21:29:54     INFO - [mozharness: 2025-01-10 21:29:54.860777Z] Running uninstall step.
[task 2025-01-10T21:29:54.860Z] 21:29:54     INFO - Running pre-action listener: _resource_record_pre_action
[task 2025-01-10T21:29:54.860Z] 21:29:54     INFO - Running main action method: uninstall
[task 2025-01-10T21:29:54.860Z] 21:29:54     INFO - Skipping uninstall for non-MSIX test
[task 2025-01-10T21:29:54.860Z] 21:29:54     INFO - Running post-action listener: _resource_record_post_action
[task 2025-01-10T21:29:54.861Z] 21:29:54     INFO - [mozharness: 2025-01-10 21:29:54.860997Z] Finished uninstall step (success)
[task 2025-01-10T21:29:54.861Z] 21:29:54     INFO - Running post-run listener: _resource_record_post_run
[task 2025-01-10T21:29:54.931Z] 21:29:54     INFO - Validating Perfherder data against /builds/worker/workspace/mozharness/external_tools/performance-artifact-schema.json
[task 2025-01-10T21:29:54.933Z] 21:29:54     INFO - PERFHERDER_DATA: {"framework": {"name": "job_resource_usage"}, "suites": [{"name": "mochitest.mochitest-plain.overall", "extraOptions": ["e10s", "taskcluster-projects/474530013412/machineTypes/c2-standard-4"], "subtests": [{"name": "cpu_percent", "value": 49.019983089064276}, {"name": "io_write_bytes", "value": 564903936}, {"name": "io.read_bytes", "value": 0}, {"name": "io_write_time", "value": 446000}, {"name": "io_read_time", "value": 0}]}, {"name": "mochitest.mochitest-plain.start-pulseaudio", "subtests": [{"name": "time", "value": 0.01596777099996416}, {"name": "cpu_percent", "value": 0}]}, {"name": "mochitest.mochitest-plain.install", "subtests": [{"name": "time", "value": 7.049401963999912}, {"name": "cpu_percent", "value": 25.05289855072464}]}, {"name": "mochitest.mochitest-plain.stage-files", "subtests": [{"name": "time", "value": 0.00023433599994859833}, {"name": "cpu_percent", "value": 0}]}, {"name": "mochitest.mochitest-plain.run-tests", "subtests": [{"name": "time", "value": 81.68120632699993}, {"name": "cpu_percent", "value": 51.093780637254916}]}, {"name": "mochitest.mochitest-plain.uninstall", "subtests": [{"name": "time", "value": 0.00012355299998034752}, {"name": "cpu_percent", "value": 0}]}]}
[task 2025-01-10T21:29:54.933Z] 21:29:54     INFO - Total resource usage - Wall time: 89s; CPU: Can't collect data; Read bytes: 0; Write bytes: 564903936; Read time: 0; Write time: 446000
[task 2025-01-10T21:29:54.933Z] 21:29:54     INFO - TinderboxPrint: I/O read bytes / time<br/>0 / 0
[task 2025-01-10T21:29:54.934Z] 21:29:54     INFO - TinderboxPrint: I/O write bytes / time<br/>564,903,936 / 446,000
[task 2025-01-10T21:29:54.934Z] 21:29:54     INFO - TinderboxPrint: CPU idle<br/>169.6 (48.1%)
[task 2025-01-10T21:29:54.934Z] 21:29:54     INFO - TinderboxPrint: CPU iowait<br/>9.8 (2.8%)
[task 2025-01-10T21:29:54.934Z] 21:29:54     INFO - TinderboxPrint: CPU system<br/>15.0 (4.3%)
[task 2025-01-10T21:29:54.934Z] 21:29:54     INFO - TinderboxPrint: CPU user<br/>157.7 (44.8%)
[task 2025-01-10T21:29:54.934Z] 21:29:54     INFO - TinderboxPrint: Swap in / out<br/>0 / 0
[task 2025-01-10T21:29:54.934Z] 21:29:54     INFO - start-pulseaudio - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2025-01-10T21:29:54.935Z] 21:29:54     INFO - install - Wall time: 7s; CPU: 25%; Read bytes: 0; Write bytes: 598016; Read time: 0; Write time: 288
[task 2025-01-10T21:29:54.935Z] 21:29:54     INFO - stage-files - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2025-01-10T21:29:54.940Z] 21:29:54     INFO - run-tests - Wall time: 82s; CPU: 51%; Read bytes: 0; Write bytes: 564305920; Read time: 0; Write time: 445712
[task 2025-01-10T21:29:54.940Z] 21:29:54     INFO - uninstall - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2025-01-10T21:29:55.130Z] 
[task 2025-01-10T21:29:55.130Z] # Run a custom mach command (this is typically used by action tasks to run
[task 2025-01-10T21:29:55.130Z] # harnesses in a particular way)
[task 2025-01-10T21:29:55.130Z] if [ "$CUSTOM_MACH_COMMAND" ]; then
[task 2025-01-10T21:29:55.130Z]     eval "'$WORKSPACE/build/venv/bin/python' '$WORKSPACE/build/tests/mach' ${CUSTOM_MACH_COMMAND} ${@}"
[task 2025-01-10T21:29:55.130Z]     exit $?
[task 2025-01-10T21:29:55.130Z] fi
[task 2025-01-10T21:29:55.130Z] + '[' '' ']'
[task 2025-01-10T21:29:55.130Z] cleanup
[task 2025-01-10T21:29:55.130Z] + cleanup
[task 2025-01-10T21:29:55.130Z] + local rv=0
[task 2025-01-10T21:29:55.130Z] + [[ -s /builds/worker/.xsession-errors ]]
[task 2025-01-10T21:29:55.130Z] + cp /builds/worker/.xsession-errors /builds/worker/artifacts/public/xsession-errors.log
[task 2025-01-10T21:29:55.131Z] + false
[task 2025-01-10T21:29:55.131Z] + '[' ']'
[task 2025-01-10T21:29:55.131Z] + true
[task 2025-01-10T21:29:55.131Z] + cleanup_xvfb
[task 2025-01-10T21:29:55.132Z] ++ pidof Xvfb
[task 2025-01-10T21:29:55.135Z] + local xvfb_pid=49
[task 2025-01-10T21:29:55.135Z] + local vnc=false
[task 2025-01-10T21:29:55.135Z] + local interactive=false
[task 2025-01-10T21:29:55.135Z] + '[' -n 49 ']'
[task 2025-01-10T21:29:55.135Z] + [[ false == false ]]
[task 2025-01-10T21:29:55.135Z] + [[ false == false ]]
[task 2025-01-10T21:29:55.135Z] + kill 49
[task 2025-01-10T21:29:55.135Z] + exit 0
[taskcluster 2025-01-10 21:29:55.537Z] === Task Finished ===
[taskcluster 2025-01-10 21:29:56.845Z] Successful task run with exit code: 0 completed in 179.728 seconds