1918387 - Intermittent leakcheck | default 24 bytes leaked (StringBuffer)

Status: RESOLVED DUPLICATE of bug 1906222

(Core :: DOM: UI Events & Focus Handling, defect, P5)

Description

[Treeherder Bug Filer]

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

---

[task 2024-09-12T12:49:44.972Z] 12:49:44     INFO - TEST-OK | widget/tests/test_wheeltransaction.xhtml | took 15952ms
[task 2024-09-12T12:49:45.082Z] 12:49:45     INFO - TEST-START | Shutdown
[task 2024-09-12T12:49:45.083Z] 12:49:45     INFO - Passed:  10535
[task 2024-09-12T12:49:45.083Z] 12:49:45     INFO - Failed:  0
[task 2024-09-12T12:49:45.084Z] 12:49:45     INFO - Todo:    23
[task 2024-09-12T12:49:45.084Z] 12:49:45     INFO - Mode:    non-e10s
[task 2024-09-12T12:49:45.085Z] 12:49:45     INFO - Slowest: 37096ms - chrome://mochitests/content/chrome/widget/tests/test_ime_state_on_focus_move_in_parent.html
[task 2024-09-12T12:49:45.086Z] 12:49:45     INFO - SimpleTest FINISHED
[task 2024-09-12T12:49:45.086Z] 12:49:45     INFO - TEST-INFO | Ran 1 Loops
[task 2024-09-12T12:49:45.086Z] 12:49:45     INFO - SimpleTest FINISHED
[task 2024-09-12T12:49:45.191Z] 12:49:45     INFO - GECKO(1054) | [WARN  webrender::device::gl] Cropping texture upload Box2D((0, 0), (0, 1)) to None
[task 2024-09-12T12:49:45.191Z] 12:49:45     INFO - GECKO(1054) | [WARN  webrender::device::gl] Cropping texture upload Box2D((0, 0), (0, 1)) to None
[task 2024-09-12T12:49:45.192Z] 12:49:45     INFO - GECKO(1054) | [WARN  webrender::device::gl] Cropping texture upload Box2D((0, 0), (0, 1)) to None
[task 2024-09-12T12:49:45.194Z] 12:49:45     INFO - GECKO(1054) | JavaScript error: resource://gre/modules/AsyncShutdown.sys.mjs, line 569: NotFoundError: No such JSWindowActor 'SpecialPowers'
[task 2024-09-12T12:49:45.196Z] 12:49:45     INFO - GECKO(1054) | [Parent 1054, Main Thread] WARNING: kInitialModuleCount too low, consider increasing its value: file /builds/worker/checkouts/gecko/xpcom/base/Logging.cpp:567
[task 2024-09-12T12:49:45.587Z] 12:49:45     INFO - GECKO(1054) | 1726145385586	Marionette	TRACE	Received observer notification quit-application
[task 2024-09-12T12:49:45.587Z] 12:49:45     INFO - GECKO(1054) | 1726145385586	Marionette	INFO	Stopped listening on port 2828
[task 2024-09-12T12:49:45.591Z] 12:49:45     INFO - GECKO(1054) | 1726145385590	Marionette	DEBUG	Marionette stopped listening
[task 2024-09-12T12:49:45.611Z] 12:49:45     INFO - GECKO(1054) | console.error: (new TypeError("can't access property \"apply\", p[aMethod] is null", "chrome://browser/content/tabbrowser/tabbrowser.js", 1055))
[task 2024-09-12T12:49:45.692Z] 12:49:45     INFO - GECKO(1054) | [Parent 1054, Socket Thread] WARNING: cannot post event if not initialized: file /builds/worker/checkouts/gecko/netwerk/protocol/http/nsHttpConnectionMgr.cpp:240
[task 2024-09-12T12:49:45.694Z] 12:49:45     INFO - GECKO(1054) | [Parent 1054, Socket Thread] WARNING: cannot post event if not initialized: file /builds/worker/checkouts/gecko/netwerk/protocol/http/nsHttpConnectionMgr.cpp:240
[task 2024-09-12T12:49:45.694Z] 12:49:45     INFO - GECKO(1054) | [Parent 1054, Socket Thread] WARNING: cannot post event if not initialized: file /builds/worker/checkouts/gecko/netwerk/protocol/http/nsHttpConnectionMgr.cpp:240
[task 2024-09-12T12:49:46.061Z] 12:49:46     INFO - GECKO(1054) | [Parent 1054, Main Thread] WARNING: BlockShutdown: Init failed: 'NS_FAILED(rv)', file /builds/worker/checkouts/gecko/toolkit/components/antitracking/bouncetrackingprotection/BounceTrackingProtectionStorage.cpp:345
[task 2024-09-12T12:49:46.197Z] 12:49:46     INFO - GECKO(1054) | [Parent 1054, Main Thread] WARNING: kInitialModuleCount too low, consider increasing its value: file /builds/worker/checkouts/gecko/xpcom/base/Logging.cpp:567
[task 2024-09-12T12:49:46.198Z] 12:49:46     INFO - GECKO(1054) | [Parent 1054, IPDL Background] WARNING: quota manager shutdown step: '0.000000s: startCrashBrowserTimer', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2220
[task 2024-09-12T12:49:46.198Z] 12:49:46     INFO - GECKO(1054) | [Parent 1054, IPDL Background] WARNING: quota manager shutdown step: '0.000000s: initiateShutdownWorkThreads', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2220
[task 2024-09-12T12:49:46.199Z] 12:49:46     INFO - GECKO(1054) | [Parent 1054, IPDL Background] WARNING: idb: '0.000000s: starting', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2220
[task 2024-09-12T12:49:46.199Z] 12:49:46     INFO - GECKO(1054) | [Parent 1054, IPDL Background] WARNING: cache: '0.000000s: starting', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2220
[task 2024-09-12T12:49:46.200Z] 12:49:46     INFO - GECKO(1054) | [Parent 1054, IPDL Background] WARNING: sdb: '0.000000s: starting', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2220
[task 2024-09-12T12:49:46.200Z] 12:49:46     INFO - GECKO(1054) | [Parent 1054, IPDL Background] WARNING: fs: '0.000000s: starting', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2220
[task 2024-09-12T12:49:46.200Z] 12:49:46     INFO - GECKO(1054) | [Parent 1054, IPDL Background] WARNING: ls: '0.000000s: starting', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2220
[task 2024-09-12T12:49:46.201Z] 12:49:46     INFO - GECKO(1054) | [Parent 1054, IPDL Background] WARNING: quota manager shutdown step: '0.000000s: startKillActorsTimer', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2220
[task 2024-09-12T12:49:46.201Z] 12:49:46     INFO - GECKO(1054) | [Parent 1054, IPDL Background] WARNING: idb: '0.000000s: Live database entry removed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2220
[task 2024-09-12T12:49:46.201Z] 12:49:46     INFO - GECKO(1054) | [Parent 1054, IPDL Background] WARNING: idb: '0.000000s: gLiveDatabaseHashtable entry removed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2220
[task 2024-09-12T12:49:46.204Z] 12:49:46     INFO - GECKO(1054) | [Parent 1054, IPDL Background] WARNING: idb: '0.008000s: Live database entry removed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2220
[task 2024-09-12T12:49:46.204Z] 12:49:46     INFO - GECKO(1054) | [Parent 1054, IPDL Background] WARNING: idb: '0.008000s: Live database entry removed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2220
[task 2024-09-12T12:49:46.208Z] 12:49:46     INFO - GECKO(1054) | [Parent 1054, IPDL Background] WARNING: idb: '0.008000s: gLiveDatabaseHashtable entry removed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2220
[task 2024-09-12T12:49:46.208Z] 12:49:46     INFO - GECKO(1054) | [Parent 1054, QuotaManager IO] WARNING: quota manager shutdown step: '0.008000s: ShutdownStorageOp::DoDirectoryWork -> ShutdownStorageInternal.', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2220
[task 2024-09-12T12:49:46.208Z] 12:49:46     INFO - GECKO(1054) | [Parent 1054, IPDL Background] WARNING: quota manager shutdown step: '0.008000s: stopKillActorsTimer', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2220
[task 2024-09-12T12:49:46.208Z] 12:49:46     INFO - GECKO(1054) | [Parent 1054, IPDL Background] WARNING: quota manager shutdown step: '0.008000s: shutdownAndJoinWorkThreads', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2220
[task 2024-09-12T12:49:46.208Z] 12:49:46     INFO - GECKO(1054) | [Parent 1054, IPDL Background] WARNING: idb: '0.008000s: completed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2220
[task 2024-09-12T12:49:46.208Z] 12:49:46     INFO - GECKO(1054) | [Parent 1054, IPDL Background] WARNING: cache: '0.008000s: completed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2220
[task 2024-09-12T12:49:46.209Z] 12:49:46     INFO - GECKO(1054) | [Parent 1054, IPDL Background] WARNING: sdb: '0.008000s: completed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2220
[task 2024-09-12T12:49:46.209Z] 12:49:46     INFO - GECKO(1054) | [Parent 1054, IPDL Background] WARNING: fs: '0.008000s: completed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2220
[task 2024-09-12T12:49:46.209Z] 12:49:46     INFO - GECKO(1054) | [Parent 1054, IPDL Background] WARNING: ls: '0.008000s: completed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2220
[task 2024-09-12T12:49:46.209Z] 12:49:46     INFO - GECKO(1054) | [Parent 1054, IPDL Background] WARNING: quota manager shutdown step: '0.008000s: shutdownAndJoinIOThread', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2220
[task 2024-09-12T12:49:46.209Z] 12:49:46     INFO - GECKO(1054) | [Parent 1054, IPDL Background] WARNING: quota manager shutdown step: '0.008000s: invalidatePendingDirectoryLocks', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2220
[task 2024-09-12T12:49:46.209Z] 12:49:46     INFO - GECKO(1054) | [Parent 1054, IPDL Background] WARNING: quota manager shutdown step: '0.008000s: stopCrashBrowserTimer', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2220
[task 2024-09-12T12:49:46.349Z] 12:49:46     INFO - GECKO(1054) | [Parent 1054, Main Thread] WARNING: NS_ENSURE_TRUE(aWindowContext) failed: file /builds/worker/checkouts/gecko/toolkit/components/antitracking/bouncetrackingprotection/BounceTrackingProtection.cpp:452
[task 2024-09-12T12:49:46.349Z] 12:49:46     INFO - GECKO(1054) | [Parent 1054, Main Thread] WARNING: NS_ENSURE_TRUE(aWindowContext) failed: file /builds/worker/checkouts/gecko/toolkit/components/antitracking/bouncetrackingprotection/BounceTrackingProtection.cpp:452
[task 2024-09-12T12:49:46.350Z] 12:49:46     INFO - GECKO(1054) | [Parent 1054, Main Thread] WARNING: NS_ENSURE_TRUE(aWindowContext) failed: file /builds/worker/checkouts/gecko/toolkit/components/antitracking/bouncetrackingprotection/BounceTrackingProtection.cpp:452
[task 2024-09-12T12:49:46.355Z] 12:49:46     INFO - GECKO(1054) | [Utility 1193, Main Thread] WARNING: IPC message 'PUtilityProcess::Msg_FOGData' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:557
[task 2024-09-12T12:49:46.357Z] 12:49:46     INFO - GECKO(1054) | [Parent 1054, IPC I/O Parent] WARNING: kInitialModuleCount too low, consider increasing its value: file /builds/worker/checkouts/gecko/xpcom/base/Logging.cpp:567
[task 2024-09-12T12:49:46.435Z] 12:49:46     INFO - GECKO(1054) | Destroying context 7f4c77321e40 surface 0 on display 7f4c773c5100
[task 2024-09-12T12:49:46.440Z] 12:49:46     INFO - GECKO(1054) | [Parent 1054, Main Thread] WARNING: kInitialModuleCount too low, consider increasing its value: file /builds/worker/checkouts/gecko/xpcom/base/Logging.cpp:567
[task 2024-09-12T12:49:47.679Z] 12:49:47     INFO - GECKO(1054) | [Parent 1054, 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 2024-09-12T12:49:47.680Z] 12:49:47     INFO - GECKO(1054) | [Parent 1054, Main Thread] WARNING: NS_ENSURE_TRUE(!!svc) failed: file /builds/worker/checkouts/gecko/dom/file/uri/BlobURLProtocolHandler.cpp:506
[task 2024-09-12T12:49:47.743Z] 12:49:47     INFO - GECKO(1054) | [Parent 1054, Main Thread] WARNING: kInitialModuleCount too low, consider increasing its value: file /builds/worker/checkouts/gecko/xpcom/base/Logging.cpp:567
[task 2024-09-12T12:49:47.763Z] 12:49:47     INFO - TEST-INFO | Main app process: exit 0
[task 2024-09-12T12:49:47.763Z] 12:49:47     INFO - runtests.py | Application ran for: 0:01:46.298426
[task 2024-09-12T12:49:47.763Z] 12:49:47     INFO - zombiecheck | Reading PID log: /tmp/tmpnzjyxcyepidlog
[task 2024-09-12T12:49:47.764Z] 12:49:47     INFO - ==> process 1054 launched child process 1193
[task 2024-09-12T12:49:47.764Z] 12:49:47     INFO - zombiecheck | Checking for orphan process with PID: 1193
[task 2024-09-12T12:49:47.764Z] 12:49:47     INFO - Stopping web server
[task 2024-09-12T12:49:47.772Z] 12:49:47     INFO - Server shut down.
[task 2024-09-12T12:49:47.773Z] 12:49:47     INFO - Web server killed.
[task 2024-09-12T12:49:47.773Z] 12:49:47     INFO - Stopping web socket server
[task 2024-09-12T12:49:47.773Z] 12:49:47     INFO - Stopping ssltunnel
[task 2024-09-12T12:49:47.774Z] 12:49:47     INFO - Stopping gst for v4l2loopback
[task 2024-09-12T12:49:47.774Z] 12:49:47     INFO - leakcheck | Processing log file /tmp/tmpz2qq7r5y.mozrunner/runtests_leaks.log for scope widget/tests/chrome.toml
[task 2024-09-12T12:49:47.775Z] 12:49:47     INFO - TEST-INFO | leakcheck | default process: leak threshold set at 0 bytes
[task 2024-09-12T12:49:47.775Z] 12:49:47     INFO - TEST-INFO | leakcheck | tab process: leak threshold set at 0 bytes
[task 2024-09-12T12:49:47.775Z] 12:49:47     INFO - TEST-INFO | leakcheck | gmplugin process: leak threshold set at 20000 bytes
[task 2024-09-12T12:49:47.776Z] 12:49:47     INFO - TEST-INFO | leakcheck | gpu process: leak threshold set at 0 bytes
[task 2024-09-12T12:49:47.776Z] 12:49:47     INFO - TEST-INFO | leakcheck | vr process: leak threshold set at 0 bytes
[task 2024-09-12T12:49:47.778Z] 12:49:47     INFO - TEST-INFO | leakcheck | rdd process: leak threshold set at 0 bytes
[task 2024-09-12T12:49:47.778Z] 12:49:47     INFO - TEST-INFO | leakcheck | socket process: leak threshold set at 0 bytes
[task 2024-09-12T12:49:47.778Z] 12:49:47     INFO - TEST-INFO | leakcheck | sandboxbroker process: leak threshold set at 0 bytes
[task 2024-09-12T12:49:47.778Z] 12:49:47     INFO - TEST-INFO | leakcheck | forkserver process: leak threshold set at 0 bytes
[task 2024-09-12T12:49:47.778Z] 12:49:47     INFO - TEST-INFO | leakcheck | utility process: leak threshold set at 0 bytes
[task 2024-09-12T12:49:47.778Z] 12:49:47     INFO - leakcheck | Processing leak log file /tmp/tmpz2qq7r5y.mozrunner/runtests_leaks_utility_pid1193.log
[task 2024-09-12T12:49:47.778Z] 12:49:47     INFO - TEST-PASS | leakcheck | utility no leaks detected!
[task 2024-09-12T12:49:47.778Z] 12:49:47     INFO - leakcheck | Processing leak log file /tmp/tmpz2qq7r5y.mozrunner/runtests_leaks.log
[task 2024-09-12T12:49:47.778Z] 12:49:47     INFO - 
[task 2024-09-12T12:49:47.778Z] 12:49:47     INFO - == BloatView: ALL (cumulative) LEAK AND BLOAT STATISTICS, default process 1054
[task 2024-09-12T12:49:47.778Z] 12:49:47     INFO - 
[task 2024-09-12T12:49:47.778Z] 12:49:47     INFO -      |<----------------Class--------------->|<-----Bytes------>|<----Objects---->|
[task 2024-09-12T12:49:47.778Z] 12:49:47     INFO -      |                                      | Per-Inst   Leaked|   Total      Rem|
[task 2024-09-12T12:49:47.778Z] 12:49:47     INFO -    0 |TOTAL                                 |       24       24|67244809        3|
[task 2024-09-12T12:49:47.779Z] 12:49:47     INFO - 1160 |StringBuffer                          |        8       24| 1485053        3|
[task 2024-09-12T12:49:47.781Z] 12:49:47     INFO - 
[task 2024-09-12T12:49:47.781Z] 12:49:47     INFO - nsTraceRefcnt::DumpStatistics: 2100 entries
[task 2024-09-12T12:49:47.782Z] 12:49:47     INFO - TEST-INFO | leakcheck | default leaked 3 StringBuffer
[task 2024-09-12T12:49:47.782Z] 12:49:47     INFO - TEST-UNEXPECTED-FAIL | leakcheck | default 24 bytes leaked (StringBuffer)
[task 2024-09-12T12:49:47.782Z] 12:49:47     INFO - 
[task 2024-09-12T12:49:47.782Z] 12:49:47     INFO - runtests.py | Running tests: end.
[task 2024-09-12T12:49:47.848Z] 12:49:47     INFO - Buffered messages finished
[task 2024-09-12T12:49:47.849Z] 12:49:47     INFO -  0 INFO TEST-START | Shutdown
[task 2024-09-12T12:49:47.849Z] 12:49:47     INFO -  1 INFO Passed:  10535
[task 2024-09-12T12:49:47.849Z] 12:49:47     INFO -  2 INFO Failed:  0
[task 2024-09-12T12:49:47.850Z] 12:49:47     INFO -  3 INFO Todo:    23
[task 2024-09-12T12:49:47.850Z] 12:49:47     INFO -  4 INFO Mode:    non-e10s
[task 2024-09-12T12:49:47.850Z] 12:49:47     INFO -  5 INFO SimpleTest FINISHED
[task 2024-09-12T12:49:47.850Z] 12:49:47     INFO - Buffered messages finished
[task 2024-09-12T12:49:47.850Z] 12:49:47     INFO - SUITE-END | took 107s
[task 2024-09-12T12:49:47.878Z] 12:49:47     INFO - Return code: 0
[task 2024-09-12T12:49:47.879Z] 12:49:47  WARNING - Got 1 unexpected statuses
[task 2024-09-12T12:49:47.879Z] 12:49:47     INFO - TinderboxPrint: mochitest-mochitest-chrome<br/>82/<em class="testfail">1</em>/0
[task 2024-09-12T12:49:47.879Z] 12:49:47  WARNING - setting return code to 1
[task 2024-09-12T12:49:47.879Z] 12:49:47     INFO - The mochitest suite: mochitest-chrome ran with return status: WARNING
[task 2024-09-12T12:49:47.879Z] 12:49:47     INFO - Running post-action listener: _package_coverage_data
[task 2024-09-12T12:49:47.879Z] 12:49:47     INFO - Running post-action listener: _resource_record_post_action
[task 2024-09-12T12:49:47.879Z] 12:49:47     INFO - Running post-action listener: process_java_coverage_data
[task 2024-09-12T12:49:47.880Z] 12:49:47     INFO - [mozharness: 2024-09-12 12:49:47.879880Z] Finished run-tests step (success)
[task 2024-09-12T12:49:47.880Z] 12:49:47     INFO - [mozharness: 2024-09-12 12:49:47.879933Z] Running uninstall step.
[task 2024-09-12T12:49:47.880Z] 12:49:47     INFO - Running pre-action listener: _resource_record_pre_action
[task 2024-09-12T12:49:47.880Z] 12:49:47     INFO - Running main action method: uninstall
[task 2024-09-12T12:49:47.880Z] 12:49:47     INFO - Skipping uninstall for non-MSIX test
[task 2024-09-12T12:49:47.880Z] 12:49:47     INFO - Running post-action listener: _resource_record_post_action
[task 2024-09-12T12:49:47.880Z] 12:49:47     INFO - [mozharness: 2024-09-12 12:49:47.880155Z] Finished uninstall step (success)
[task 2024-09-12T12:49:47.880Z] 12:49:47     INFO - Running post-run listener: _resource_record_post_run
[task 2024-09-12T12:49:47.954Z] 12:49:47     INFO - Validating Perfherder data against /builds/worker/workspace/mozharness/external_tools/performance-artifact-schema.json
[task 2024-09-12T12:49:47.956Z] 12:49:47     INFO - PERFHERDER_DATA: {"framework": {"name": "job_resource_usage"}, "suites": [{"name": "mochitest.mochitest-chrome.3.overall", "extraOptions": ["taskcluster-projects/887720501152/machineTypes/c2-standard-4"], "subtests": [{"name": "cpu_percent", "value": 44.25819570602803}, {"name": "io_write_bytes", "value": 470519808}, {"name": "io.read_bytes", "value": 8192}, {"name": "io_write_time", "value": 351044}, {"name": "io_read_time", "value": 316}]}, {"name": "mochitest.mochitest-chrome.3.start-pulseaudio", "subtests": [{"name": "time", "value": 0.016643516999920394}, {"name": "cpu_percent", "value": 0}]}, {"name": "mochitest.mochitest-chrome.3.install", "subtests": [{"name": "time", "value": 13.566936052000074}, {"name": "cpu_percent", "value": 25.075000000000003}]}, {"name": "mochitest.mochitest-chrome.3.stage-files", "subtests": [{"name": "time", "value": 0.00033097100003942614}, {"name": "cpu_percent", "value": 0}]}, {"name": "mochitest.mochitest-chrome.3.run-tests", "subtests": [{"name": "time", "value": 107.49399073199993}, {"name": "cpu_percent", "value": 46.69075884543757}]}, {"name": "mochitest.mochitest-chrome.3.uninstall", "subtests": [{"name": "time", "value": 0.00014247199987948989}, {"name": "cpu_percent", "value": 0}]}]}
[task 2024-09-12T12:49:47.956Z] 12:49:47     INFO - Total resource usage - Wall time: 121s; CPU: Can't collect data; Read bytes: 8192; Write bytes: 470519808; Read time: 316; Write time: 351044
[task 2024-09-12T12:49:47.956Z] 12:49:47     INFO - TinderboxPrint: I/O read bytes / time<br/>8,192 / 316
[task 2024-09-12T12:49:47.956Z] 12:49:47     INFO - TinderboxPrint: I/O write bytes / time<br/>470,519,808 / 351,044
[task 2024-09-12T12:49:47.956Z] 12:49:47     INFO - TinderboxPrint: CPU idle<br/>264.8 (55.1%)
[task 2024-09-12T12:49:47.956Z] 12:49:47     INFO - TinderboxPrint: CPU system<br/>12.5 (2.6%)
[task 2024-09-12T12:49:47.956Z] 12:49:47     INFO - TinderboxPrint: CPU user<br/>200.0 (41.6%)
[task 2024-09-12T12:49:47.956Z] 12:49:47     INFO - TinderboxPrint: Swap in / out<br/>0 / 0
[task 2024-09-12T12:49:47.956Z] 12:49:47     INFO - start-pulseaudio - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2024-09-12T12:49:47.958Z] 12:49:47     INFO - install - Wall time: 14s; CPU: 25%; Read bytes: 0; Write bytes: 3440640; Read time: 0; Write time: 832
[task 2024-09-12T12:49:47.958Z] 12:49:47     INFO - stage-files - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2024-09-12T12:49:47.964Z] 12:49:47     INFO - run-tests - Wall time: 107s; CPU: 47%; Read bytes: 8192; Write bytes: 466939904; Read time: 316; Write time: 350184
[task 2024-09-12T12:49:47.965Z] 12:49:47     INFO - uninstall - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2024-09-12T12:49:48.171Z] 12:49:48  WARNING - returning nonzero exit status 1
[task 2024-09-12T12:49:48.202Z] cleanup