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

[task 2022-07-11T04:38:31.128Z] 04:38:31     INFO - TEST-PASS | toolkit/components/processtools/tests/browser/browser_test_procinfo.js | Got some cpu time in the threads - 835 > 0 - 
[task 2022-07-11T04:38:31.129Z] 04:38:31     INFO - TEST-PASS | toolkit/components/processtools/tests/browser/browser_test_procinfo.js | The total CPU time of the process should be at least the sum of the CPU time spent by the still alive threads - 842 >= 835 - 
[task 2022-07-11T04:38:31.129Z] 04:38:31     INFO - TEST-PASS | toolkit/components/processtools/tests/browser/browser_test_procinfo.js | Child proc type should not be browser - "socket" != "browser" - 
[task 2022-07-11T04:38:31.130Z] 04:38:31     INFO - TEST-PASS | toolkit/components/processtools/tests/browser/browser_test_procinfo.js | Child proc type should be known - "socket" != "unknown" - 
[task 2022-07-11T04:38:31.130Z] 04:38:31     INFO - TEST-PASS | toolkit/components/processtools/tests/browser/browser_test_procinfo.js | Got some cpu time - 140826154 > 0 - 
[task 2022-07-11T04:38:31.130Z] 04:38:31     INFO - TEST-PASS | toolkit/components/processtools/tests/browser/browser_test_procinfo.js | Got some cpu time in the threads - 137 > 0 - 
[task 2022-07-11T04:38:31.131Z] 04:38:31     INFO - TEST-PASS | toolkit/components/processtools/tests/browser/browser_test_procinfo.js | The total CPU time of the process should be at least the sum of the CPU time spent by the still alive threads - 141 >= 137 - 
[task 2022-07-11T04:38:31.131Z] 04:38:31     INFO - TEST-PASS | toolkit/components/processtools/tests/browser/browser_test_procinfo.js | Child proc type should not be browser - "preallocated" != "browser" - 
[task 2022-07-11T04:38:31.132Z] 04:38:31     INFO - TEST-PASS | toolkit/components/processtools/tests/browser/browser_test_procinfo.js | Child proc type should be known - "preallocated" != "unknown" - 
[task 2022-07-11T04:38:31.132Z] 04:38:31     INFO - TEST-PASS | toolkit/components/processtools/tests/browser/browser_test_procinfo.js | Got some cpu time - 260588316 > 0 - 
[task 2022-07-11T04:38:31.132Z] 04:38:31     INFO - TEST-PASS | toolkit/components/processtools/tests/browser/browser_test_procinfo.js | Got some cpu time in the threads - 262 > 0 - 
[task 2022-07-11T04:38:31.133Z] 04:38:31     INFO - Buffered messages finished
[task 2022-07-11T04:38:31.134Z] 04:38:31     INFO - TEST-UNEXPECTED-FAIL | toolkit/components/processtools/tests/browser/browser_test_procinfo.js | The total CPU time of the process should be at least the sum of the CPU time spent by the still alive threads - 261 >= 262 - JS frame :: chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js :: checkProcessCpuTime :: line 40
[task 2022-07-11T04:38:31.134Z] 04:38:31     INFO - Stack trace:
[task 2022-07-11T04:38:31.134Z] 04:38:31     INFO - chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js:checkProcessCpuTime:40
[task 2022-07-11T04:38:31.134Z] 04:38:31     INFO - chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js:test_proc_info/<:118
[task 2022-07-11T04:38:31.134Z] 04:38:31     INFO - TEST-PASS | toolkit/components/processtools/tests/browser/browser_test_procinfo.js | Child proc type should not be browser - "webIsolated" != "browser" - 
[task 2022-07-11T04:38:31.135Z] 04:38:31     INFO - TEST-PASS | toolkit/components/processtools/tests/browser/browser_test_procinfo.js | Child proc should have been set - 6 != 0 - 
[task 2022-07-11T04:38:31.135Z] 04:38:31     INFO - TEST-PASS | toolkit/components/processtools/tests/browser/browser_test_procinfo.js | Child proc type should be known - "webIsolated" != "unknown" - 
[task 2022-07-11T04:38:31.135Z] 04:38:31     INFO - TEST-PASS | toolkit/components/processtools/tests/browser/browser_test_procinfo.js | Child process should have an origin - "http://example.com" != "" - 
[task 2022-07-11T04:38:31.136Z] 04:38:31     INFO - TEST-PASS | toolkit/components/processtools/tests/browser/browser_test_procinfo.js | Got some cpu time - 800980221 > 0 - 
[task 2022-07-11T04:38:31.136Z] 04:38:31     INFO - TEST-PASS | toolkit/components/processtools/tests/browser/browser_test_procinfo.js | Got some cpu time in the threads - 795 > 0 - 
[task 2022-07-11T04:38:31.137Z] 04:38:31     INFO - TEST-PASS | toolkit/components/processtools/tests/browser/browser_test_procinfo.js | The total CPU time of the process should be at least the sum of the CPU time spent by the still alive threads - 801 >= 795 - 
[task 2022-07-11T04:38:31.137Z] 04:38:31     INFO - TEST-PASS | toolkit/components/processtools/tests/browser/browser_test_procinfo.js | Child proc type should not be browser - "web" != "browser" - 
[task 2022-07-11T04:38:31.138Z] 04:38:31     INFO - TEST-PASS | toolkit/components/processtools/tests/browser/browser_test_procinfo.js | Child proc should have been set - 2 != 0 - 
[task 2022-07-11T04:38:31.138Z] 04:38:31     INFO - TEST-PASS | toolkit/components/processtools/tests/browser/browser_test_procinfo.js | Child proc type should be known - "web" != "unknown" - 
[task 2022-07-11T04:38:31.138Z] 04:38:31     INFO - TEST-PASS | toolkit/components/processtools/tests/browser/browser_test_procinfo.js | Got some cpu time - 789826103 > 0 - 
[task 2022-07-11T04:38:31.139Z] 04:38:31     INFO - TEST-PASS | toolkit/components/processtools/tests/browser/browser_test_procinfo.js | Got some cpu time in the threads - 784 > 0 - 
[task 2022-07-11T04:38:31.139Z] 04:38:31     INFO - TEST-PASS | toolkit/components/processtools/tests/browser/browser_test_procinfo.js | The total CPU time of the process should be at least the sum of the CPU time spent by the still alive threads - 790 >= 784 - 
[task 2022-07-11T04:38:31.140Z] 04:38:31     INFO - TEST-PASS | toolkit/components/processtools/tests/browser/browser_test_procinfo.js | Child proc type should not be browser - "privilegedabout" != "browser" - 

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

New failure instance: https://treeherder.mozilla.org/logviewer?job_id=388797170&repo=mozilla-esr91

There have been 30 total failures in the last 7 days.
There are:

• 16 failures on Windows 11 x64 22H2 WebRender opt
• 13 failures on Windows 11 x64 22H2 WebRender Shippable opt
• 1 failure on Windows 7 WebRender Shippable opt

Recent failure log.

[task 2023-03-16T10:15:28.783Z] 10:15:28     INFO - TEST-PASS | toolkit/components/processtools/tests/browser/browser_test_procinfo.js | Child proc type should be known - "utility" != "unknown" - 
[task 2023-03-16T10:15:28.783Z] 10:15:28     INFO - Buffered messages finished
[task 2023-03-16T10:15:28.786Z] 10:15:28     INFO - TEST-UNEXPECTED-FAIL | toolkit/components/processtools/tests/browser/browser_test_procinfo.js | Got some cpu time - 0 > 0 - {"filename":"chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js","name":"checkProcessCpuTime","sourceId":582,"lineNumber":20,"columnNumber":10,"sourceLine":"","asyncCause":null,"asyncCaller":null,"caller":{"filename":"chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js","name":"test_proc_info/<","sourceId":582,"lineNumber":115,"columnNumber":30,"sourceLine":"","asyncCause":null,"asyncCaller":null,"caller":null,"formattedStack":"test_proc_info/<@chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js:115:30\n","nativeSavedFrame":{}},"formattedStack":"checkProcessCpuTime@chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js:20:10\ntest_proc_info/<@chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js:115:30\n","nativeSavedFrame":{}}
[task 2023-03-16T10:15:28.786Z] 10:15:28     INFO - Stack trace:
[task 2023-03-16T10:15:28.786Z] 10:15:28     INFO - chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js:checkProcessCpuTime:20
[task 2023-03-16T10:15:28.786Z] 10:15:28     INFO - chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js:test_proc_info/<:115
[task 2023-03-16T10:15:28.787Z] 10:15:28     INFO - Not taking screenshot here: see the one that was previously logged
[task 2023-03-16T10:15:28.790Z] 10:15:28     INFO - TEST-UNEXPECTED-FAIL | toolkit/components/processtools/tests/browser/browser_test_procinfo.js | Got some cpu time in the threads - 0 > 0 - {"filename":"chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js","name":"checkProcessCpuTime","sourceId":582,"lineNumber":26,"columnNumber":10,"sourceLine":"","asyncCause":null,"asyncCaller":null,"caller":{"filename":"chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js","name":"test_proc_info/<","sourceId":582,"lineNumber":115,"columnNumber":30,"sourceLine":"","asyncCause":null,"asyncCaller":null,"caller":null,"formattedStack":"test_proc_info/<@chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js:115:30\n","nativeSavedFrame":{}},"formattedStack":"checkProcessCpuTime@chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js:26:10\ntest_proc_info/<@chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js:115:30\n","nativeSavedFrame":{}}
[task 2023-03-16T10:15:28.790Z] 10:15:28     INFO - Stack trace:
[task 2023-03-16T10:15:28.790Z] 10:15:28     INFO - chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js:checkProcessCpuTime:26
[task 2023-03-16T10:15:28.790Z] 10:15:28     INFO - chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js:test_proc_info/<:115
[task 2023-03-16T10:15:28.791Z] 10:15:28     INFO - TEST-PASS | toolkit/components/processtools/tests/browser/browser_test_procinfo.js | The total CPU time of the process should be at least the sum of the CPU time spent by the still alive threads - 0 >= 0 - 

Hello Jens! Any chance you could help us assign this to someone?

Thank you!

I assume that we just see some dying process. IIUC we bail out from retrieving procinfo at severel places, for example here and that in such a case we may find cpuTime to be just zero.

The question would be, if the test is meant to create a stable enough environment where it is not supposed to happen that a child process goes away while looking at all of them. Maybe procInfo should have a presumablyDead flag to keep track of such bail outs such that we can ignore them ?

florian would be a better person to say anything about the test.

@florian, did you get a chance to look into this?
Thank you

It seems there are at least 2 failure modes.

• One that is low frequency, affects preallocated content processes, and has happened on Windows 7, 10 and 11, for several months.
• One that is high frequency, Windows 11 only, and affects utility processes. This one has started recently (maybe started when we started running tests on Win11 in CI).

I haven't been able to reproduce either of these. Bug 1767149 seems related, and using --verify I could make it fail locally, but I'm not sure the failures I was seeing locally have anything to do with the failures we have in CI.

Alex, Yannis, any idea about what would be specific to Windows 11 or the utility process here?

(In reply to Florian Quèze [:florian] from comment #39)

It seems there are at least 2 failure modes.

• One that is low frequency, affects preallocated content processes, and has happened on Windows 7, 10 and 11, for several months.

My try run where I attempted to reproduce gave me a profile of this failure case: https://share.firefox.dev/3Zw51lK I haven't found anything particularly useful in it (yet?).

As we discussed with Florian, it might be helpful to augment the test case and make sure we get a view of the Utility actors [https://searchfox.org/mozilla-central/rev/9e3413f54ed6c9165b5659558091d766d34a731f/toolkit/components/aboutprocesses/content/aboutProcesses.js#269] on the process reporting 0 time. This way we might be able to know if it's a in-birth or death process or what.

Update

There have been 32 failures within the last 7 days:

• 1 failure on Linux 18.04 x64 WebRender debug
• 1 failure on Windows 11 x86 22H2 WebRender debug
• 12 failures on Windows 11 x64 22H2 WebRender opt
• 17 failures on Windows 11 x64 22H2 WebRender Shippable opt
• 1 failure on Windows 7 WebRender Shippable opt

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

[task 2023-04-15T23:25:24.282Z] 23:25:24     INFO - TEST-PASS | toolkit/components/processtools/tests/browser/browser_test_procinfo.js | Child proc type should be known - "utility" != "unknown" - 
[task 2023-04-15T23:25:24.283Z] 23:25:24     INFO - Buffered messages finished
[task 2023-04-15T23:25:24.292Z] 23:25:24     INFO - TEST-UNEXPECTED-FAIL | toolkit/components/processtools/tests/browser/browser_test_procinfo.js | Got some cpu time - 0 > 0 - {"filename":"chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js","name":"checkProcessCpuTime","sourceId":586,"lineNumber":20,"columnNumber":10,"sourceLine":"","asyncCause":null,"asyncCaller":null,"caller":{"filename":"chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js","name":"test_proc_info/<","sourceId":586,"lineNumber":115,"columnNumber":30,"sourceLine":"","asyncCause":null,"asyncCaller":{"filename":"resource://testing-common/BrowserTestUtils.sys.mjs","name":"withNewTab","sourceId":569,"lineNumber":154,"columnNumber":22,"sourceLine":"","asyncCause":null,"asyncCaller":{"filename":"chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js","name":"test_proc_info","sourceId":586,"lineNumber":55,"columnNumber":26,"sourceLine":"","asyncCause":null,"asyncCaller":{"filename":"chrome://mochikit/content/browser-test.js","name":"handleTask","sourceId":534,"lineNumber":1043,"columnNumber":26,"sourceLine":"","asyncCause":null,"asyncCaller":null,"caller":{"filename":"chrome://mochikit/content/browser-test.js","name":"_runTaskBasedTest","sourceId":534,"lineNumber":1115,"columnNumber":18,"sourceLine":"","asyncCause":null,"asyncCaller":null,"caller":{"filename":"chrome://mochikit/content/browser-test.js","name":"Tester_execTest","sourceId":534,"lineNumber":1257,"columnNumber":14,"sourceLine":"","asyncCause":null,"asyncCaller":null,"caller":{"filename":"chrome://mochikit/content/browser-test.js","name":"nextTest/<","sourceId":534,"lineNumber":1032,"columnNumber":14,"sourceLine":"","asyncCause":null,"asyncCaller":null,"caller":{"filename":"chrome://mochikit/content/tests/SimpleTest/SimpleTest.js","name":"SimpleTest.waitForFocus/<","sourceId":563,"lineNumber":1056,"columnNumber":13,"sourceLine":"","asyncCause":null,"asyncCaller":null,"caller":null,"formattedStack":"SimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1056:13\n","nativeSavedFrame":{}},"formattedStack":"nextTest/<@chrome://mochikit/content/browser-test.js:1032:14\nSimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1056:13\n","nativeSavedFrame":{}},"formattedStack":"Tester_execTest@chrome://mochikit/content/browser-test.js:1257:14\nnextTest/<@chrome://mochikit/content/browser-test.js:1032:14\nSimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1056:13\n","nativeSavedFrame":{}},"formattedStack":"_runTaskBasedTest@chrome://mochikit/content/browser-test.js:1115:18\nTester_execTest@chrome://mochikit/content/browser-test.js:1257:14\nnextTest/<@chrome://mochikit/content/browser-test.js:1032:14\nSimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1056:13\n","nativeSavedFrame":{}},"formattedStack":"async*handleTask@chrome://mochikit/content/browser-test.js:1043:26\n_runTaskBasedTest@chrome://mochikit/content/browser-test.js:1115:18\nTester_execTest@chrome://mochikit/content/browser-test.js:1257:14\nnextTest/<@chrome://mochikit/content/browser-test.js:1032:14\nSimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1056:13\n","nativeSavedFrame":{}},"caller":null,"formattedStack":"async*test_proc_info@chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js:55:26\nasync*handleTask@chrome://mochikit/content/browser-test.js:1043:26\n_runTaskBasedTest@chrome://mochikit/content/browser-test.js:1115:18\nTester_execTest@chrome://mochikit/content/browser-test.js:1257:14\nnextTest/<@chrome://mochikit/content/browser-test.js:1032:14\nSimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1056:13\n","nativeSavedFrame":{}},"caller":null,"formattedStack":"async*withNewTab@resource://testing-common/BrowserTestUtils.sys.mjs:154:22\nasync*test_proc_info@chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js:55:26\nasync*handleTask@chrome://mochikit/content/browser-test.js:1043:26\n_runTaskBasedTest@chrome://mochikit/content/browser-test.js:1115:18\nTester_execTest@chrome://mochikit/content/browser-test.js:1257:14\nnextTest/<@chrome://mochikit/content/browser-test.js:1032:14\nSimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1056:13\n","nativeSavedFrame":{}},"caller":null,"formattedStack":"test_proc_info/<@chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js:115:30\nasync*withNewTab@resource://testing-common/BrowserTestUtils.sys.mjs:154:22\nasync*test_proc_info@chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js:55:26\nasync*handleTask@chrome://mochikit/content/browser-test.js:1043:26\n_runTaskBasedTest@chrome://mochikit/content/browser-test.js:1115:18\nTester_execTest@chrome://mochikit/content/browser-test.js:1257:14\nnextTest/<@chrome://mochikit/content/browser-test.js:1032:14\nSimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1056:13\n","nativeSavedFrame":{}},"formattedStack":"checkProcessCpuTime@chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js:20:10\ntest_proc_info/<@chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js:115:30\nasync*withNewTab@resource://testing-common/BrowserTestUtils.sys.mjs:154:22\nasync*test_proc_info@chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js:55:26\nasync*handleTask@chrome://mochikit/content/browser-test.js:1043:26\n_runTaskBasedTest@chrome://mochikit/content/browser-test.js:1115:18\nTester_execTest@chrome://mochikit/content/browser-test.js:1257:14\nnextTest/<@chrome://mochikit/content/browser-test.js:1032:14\nSimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1056:13\n","nativeSavedFrame":{}}
[task 2023-04-15T23:25:24.292Z] 23:25:24     INFO - Stack trace:
[task 2023-04-15T23:25:24.292Z] 23:25:24     INFO - chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js:checkProcessCpuTime:20
[task 2023-04-15T23:25:24.292Z] 23:25:24     INFO - chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js:test_proc_info/<:115
[task 2023-04-15T23:25:24.293Z] 23:25:24     INFO - resource://testing-common/BrowserTestUtils.sys.mjs:withNewTab:154
[task 2023-04-15T23:25:24.293Z] 23:25:24     INFO - chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js:test_proc_info:55
[task 2023-04-15T23:25:24.293Z] 23:25:24     INFO - chrome://mochikit/content/browser-test.js:handleTask:1043
[task 2023-04-15T23:25:24.293Z] 23:25:24     INFO - chrome://mochikit/content/browser-test.js:_runTaskBasedTest:1115
[task 2023-04-15T23:25:24.293Z] 23:25:24     INFO - chrome://mochikit/content/browser-test.js:Tester_execTest:1257
[task 2023-04-15T23:25:24.293Z] 23:25:24     INFO - chrome://mochikit/content/browser-test.js:nextTest/<:1032
[task 2023-04-15T23:25:24.293Z] 23:25:24     INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/<:1056
[task 2023-04-15T23:25:24.294Z] 23:25:24     INFO - Not taking screenshot here: see the one that was previously logged
[task 2023-04-15T23:25:24.303Z] 23:25:24     INFO - TEST-UNEXPECTED-FAIL | toolkit/components/processtools/tests/browser/browser_test_procinfo.js | Got some cpu time in the threads - 0 > 0 - {"filename":"chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js","name":"checkProcessCpuTime","sourceId":586,"lineNumber":26,"columnNumber":10,"sourceLine":"","asyncCause":null,"asyncCaller":null,"caller":{"filename":"chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js","name":"test_proc_info/<","sourceId":586,"lineNumber":115,"columnNumber":30,"sourceLine":"","asyncCause":null,"asyncCaller":{"filename":"resource://testing-common/BrowserTestUtils.sys.mjs","name":"withNewTab","sourceId":569,"lineNumber":154,"columnNumber":22,"sourceLine":"","asyncCause":null,"asyncCaller":{"filename":"chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js","name":"test_proc_info","sourceId":586,"lineNumber":55,"columnNumber":26,"sourceLine":"","asyncCause":null,"asyncCaller":{"filename":"chrome://mochikit/content/browser-test.js","name":"handleTask","sourceId":534,"lineNumber":1043,"columnNumber":26,"sourceLine":"","asyncCause":null,"asyncCaller":null,"caller":{"filename":"chrome://mochikit/content/browser-test.js","name":"_runTaskBasedTest","sourceId":534,"lineNumber":1115,"columnNumber":18,"sourceLine":"","asyncCause":null,"asyncCaller":null,"caller":{"filename":"chrome://mochikit/content/browser-test.js","name":"Tester_execTest","sourceId":534,"lineNumber":1257,"columnNumber":14,"sourceLine":"","asyncCause":null,"asyncCaller":null,"caller":{"filename":"chrome://mochikit/content/browser-test.js","name":"nextTest/<","sourceId":534,"lineNumber":1032,"columnNumber":14,"sourceLine":"","asyncCause":null,"asyncCaller":null,"caller":{"filename":"chrome://mochikit/content/tests/SimpleTest/SimpleTest.js","name":"SimpleTest.waitForFocus/<","sourceId":563,"lineNumber":1056,"columnNumber":13,"sourceLine":"","asyncCause":null,"asyncCaller":null,"caller":null,"formattedStack":"SimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1056:13\n","nativeSavedFrame":{}},"formattedStack":"nextTest/<@chrome://mochikit/content/browser-test.js:1032:14\nSimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1056:13\n","nativeSavedFrame":{}},"formattedStack":"Tester_execTest@chrome://mochikit/content/browser-test.js:1257:14\nnextTest/<@chrome://mochikit/content/browser-test.js:1032:14\nSimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1056:13\n","nativeSavedFrame":{}},"formattedStack":"_runTaskBasedTest@chrome://mochikit/content/browser-test.js:1115:18\nTester_execTest@chrome://mochikit/content/browser-test.js:1257:14\nnextTest/<@chrome://mochikit/content/browser-test.js:1032:14\nSimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1056:13\n","nativeSavedFrame":{}},"formattedStack":"async*handleTask@chrome://mochikit/content/browser-test.js:1043:26\n_runTaskBasedTest@chrome://mochikit/content/browser-test.js:1115:18\nTester_execTest@chrome://mochikit/content/browser-test.js:1257:14\nnextTest/<@chrome://mochikit/content/browser-test.js:1032:14\nSimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1056:13\n","nativeSavedFrame":{}},"caller":null,"formattedStack":"async*test_proc_info@chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js:55:26\nasync*handleTask@chrome://mochikit/content/browser-test.js:1043:26\n_runTaskBasedTest@chrome://mochikit/content/browser-test.js:1115:18\nTester_execTest@chrome://mochikit/content/browser-test.js:1257:14\nnextTest/<@chrome://mochikit/content/browser-test.js:1032:14\nSimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1056:13\n","nativeSavedFrame":{}},"caller":null,"formattedStack":"async*withNewTab@resource://testing-common/BrowserTestUtils.sys.mjs:154:22\nasync*test_proc_info@chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js:55:26\nasync*handleTask@chrome://mochikit/content/browser-test.js:1043:26\n_runTaskBasedTest@chrome://mochikit/content/browser-test.js:1115:18\nTester_execTest@chrome://mochikit/content/browser-test.js:1257:14\nnextTest/<@chrome://mochikit/content/browser-test.js:1032:14\nSimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1056:13\n","nativeSavedFrame":{}},"caller":null,"formattedStack":"test_proc_info/<@chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js:115:30\nasync*withNewTab@resource://testing-common/BrowserTestUtils.sys.mjs:154:22\nasync*test_proc_info@chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js:55:26\nasync*handleTask@chrome://mochikit/content/browser-test.js:1043:26\n_runTaskBasedTest@chrome://mochikit/content/browser-test.js:1115:18\nTester_execTest@chrome://mochikit/content/browser-test.js:1257:14\nnextTest/<@chrome://mochikit/content/browser-test.js:1032:14\nSimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1056:13\n","nativeSavedFrame":{}},"formattedStack":"checkProcessCpuTime@chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js:26:10\ntest_proc_info/<@chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js:115:30\nasync*withNewTab@resource://testing-common/BrowserTestUtils.sys.mjs:154:22\nasync*test_proc_info@chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js:55:26\nasync*handleTask@chrome://mochikit/content/browser-test.js:1043:26\n_runTaskBasedTest@chrome://mochikit/content/browser-test.js:1115:18\nTester_execTest@chrome://mochikit/content/browser-test.js:1257:14\nnextTest/<@chrome://mochikit/content/browser-test.js:1032:14\nSimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1056:13\n","nativeSavedFrame":{}}
[task 2023-04-15T23:25:24.303Z] 23:25:24     INFO - Stack trace:
[task 2023-04-15T23:25:24.303Z] 23:25:24     INFO - chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js:checkProcessCpuTime:26
[task 2023-04-15T23:25:24.303Z] 23:25:24     INFO - chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js:test_proc_info/<:115
[task 2023-04-15T23:25:24.303Z] 23:25:24     INFO - resource://testing-common/BrowserTestUtils.sys.mjs:withNewTab:154
[task 2023-04-15T23:25:24.303Z] 23:25:24     INFO - chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js:test_proc_info:55
[task 2023-04-15T23:25:24.305Z] 23:25:24     INFO - chrome://mochikit/content/browser-test.js:handleTask:1043
[task 2023-04-15T23:25:24.305Z] 23:25:24     INFO - chrome://mochikit/content/browser-test.js:_runTaskBasedTest:1115
[task 2023-04-15T23:25:24.305Z] 23:25:24     INFO - chrome://mochikit/content/browser-test.js:Tester_execTest:1257
[task 2023-04-15T23:25:24.305Z] 23:25:24     INFO - chrome://mochikit/content/browser-test.js:nextTest/<:1032
[task 2023-04-15T23:25:24.305Z] 23:25:24     INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/<:1056
[task 2023-04-15T23:25:24.305Z] 23:25:24     INFO - TEST-PASS | toolkit/components/processtools/tests/browser/browser_test_procinfo.js | The total CPU time of the process should be at least the sum of the CPU time spent by the still alive threads - 0 >= 0 - 

There have been 31 total failures in the last 7 days.
There are:

• 1 failure on linux1804-64-qr debug
• 18 failures on windows11-64-2009-qr opt
• 10 failures on windows11-64-2009-shippable-qr opt
• 1 failure on windows7-32-qr opt
• 1 failure on windows7-32-shippable-qr opt

Recent failure log.

Joshua, as the owner of this component, can you help us assign the bug to someone? Thank you.

There have been 41 total failures in the last 7 days.
There are:

• 22 failures on Windows 11 x64 22H2 WebRender Shippable opt
• 17 failures on Windows 11 x64 22H2 WebRender opt
• 1 failure on Windows 11 x64 22H2 CCov WebRender opt
• 1 failure on Linux 18.04 x64 WebRender debug

Recent failure log.

[task 2023-06-13T20:07:26.197Z] 20:07:26     INFO - TEST-PASS | toolkit/components/processtools/tests/browser/browser_test_procinfo.js | Child proc type should be known - "utility" != "unknown" - 
[task 2023-06-13T20:07:26.197Z] 20:07:26     INFO - Buffered messages finished
[task 2023-06-13T20:07:26.205Z] 20:07:26     INFO - TEST-UNEXPECTED-FAIL | toolkit/components/processtools/tests/browser/browser_test_procinfo.js | Got some cpu time - 0 > 0 - {"filename":"chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js","name":"checkProcessCpuTime","sourceId":586,"lineNumber":20,"columnNumber":10,"sourceLine":"","asyncCause":null,"asyncCaller":null,"caller":{"filename":"chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js","name":"test_proc_info/<","sourceId":586,"lineNumber":115,"columnNumber":30,"sourceLine":"","asyncCause":null,"asyncCaller":{"filename":"resource://testing-common/BrowserTestUtils.sys.mjs","name":"withNewTab","sourceId":570,"lineNumber":149,"columnNumber":22,"sourceLine":"","asyncCause":null,"asyncCaller":{"filename":"chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js","name":"test_proc_info","sourceId":586,"lineNumber":55,"columnNumber":26,"sourceLine":"","asyncCause":null,"asyncCaller":{"filename":"chrome://mochikit/content/browser-test.js","name":"handleTask","sourceId":540,"lineNumber":1131,"columnNumber":26,"sourceLine":"","asyncCause":null,"asyncCaller":null,"caller":{"filename":"chrome://mochikit/content/browser-test.js","name":"_runTaskBasedTest","sourceId":540,"lineNumber":1203,"columnNumber":18,"sourceLine":"","asyncCause":null,"asyncCaller":null,"caller":{"filename":"chrome://mochikit/content/browser-test.js","name":"Tester_execTest","sourceId":540,"lineNumber":1345,"columnNumber":14,"sourceLine":"","asyncCause":null,"asyncCaller":null,"caller":{"filename":"chrome://mochikit/content/browser-test.js","name":"nextTest/<","sourceId":540,"lineNumber":1120,"columnNumber":14,"sourceLine":"","asyncCause":null,"asyncCaller":null,"caller":{"filename":"chrome://mochikit/content/tests/SimpleTest/SimpleTest.js","name":"SimpleTest.waitForFocus/<","sourceId":564,"lineNumber":1056,"columnNumber":13,"sourceLine":"","asyncCause":null,"asyncCaller":null,"caller":null,"formattedStack":"SimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1056:13\n","nativeSavedFrame":{}},"formattedStack":"nextTest/<@chrome://mochikit/content/browser-test.js:1120:14\nSimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1056:13\n","nativeSavedFrame":{}},"formattedStack":"Tester_execTest@chrome://mochikit/content/browser-test.js:1345:14\nnextTest/<@chrome://mochikit/content/browser-test.js:1120:14\nSimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1056:13\n","nativeSavedFrame":{}},"formattedStack":"_runTaskBasedTest@chrome://mochikit/content/browser-test.js:1203:18\nTester_execTest@chrome://mochikit/content/browser-test.js:1345:14\nnextTest/<@chrome://mochikit/content/browser-test.js:1120:14\nSimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1056:13\n","nativeSavedFrame":{}},"formattedStack":"async*handleTask@chrome://mochikit/content/browser-test.js:1131:26\n_runTaskBasedTest@chrome://mochikit/content/browser-test.js:1203:18\nTester_execTest@chrome://mochikit/content/browser-test.js:1345:14\nnextTest/<@chrome://mochikit/content/browser-test.js:1120:14\nSimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1056:13\n","nativeSavedFrame":{}},"caller":null,"formattedStack":"async*test_proc_info@chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js:55:26\nasync*handleTask@chrome://mochikit/content/browser-test.js:1131:26\n_runTaskBasedTest@chrome://mochikit/content/browser-test.js:1203:18\nTester_execTest@chrome://mochikit/content/browser-test.js:1345:14\nnextTest/<@chrome://mochikit/content/browser-test.js:1120:14\nSimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1056:13\n","nativeSavedFrame":{}},"caller":null,"formattedStack":"async*withNewTab@resource://testing-common/BrowserTestUtils.sys.mjs:149:22\nasync*test_proc_info@chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js:55:26\nasync*handleTask@chrome://mochikit/content/browser-test.js:1131:26\n_runTaskBasedTest@chrome://mochikit/content/browser-test.js:1203:18\nTester_execTest@chrome://mochikit/content/browser-test.js:1345:14\nnextTest/<@chrome://mochikit/content/browser-test.js:1120:14\nSimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1056:13\n","nativeSavedFrame":{}},"caller":null,"formattedStack":"test_proc_info/<@chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js:115:30\nasync*withNewTab@resource://testing-common/BrowserTestUtils.sys.mjs:149:22\nasync*test_proc_info@chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js:55:26\nasync*handleTask@chrome://mochikit/content/browser-test.js:1131:26\n_runTaskBasedTest@chrome://mochikit/content/browser-test.js:1203:18\nTester_execTest@chrome://mochikit/content/browser-test.js:1345:14\nnextTest/<@chrome://mochikit/content/browser-test.js:1120:14\nSimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1056:13\n","nativeSavedFrame":{}},"formattedStack":"checkProcessCpuTime@chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js:20:10\ntest_proc_info/<@chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js:115:30\nasync*withNewTab@resource://testing-common/BrowserTestUtils.sys.mjs:149:22\nasync*test_proc_info@chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js:55:26\nasync*handleTask@chrome://mochikit/content/browser-test.js:1131:26\n_runTaskBasedTest@chrome://mochikit/content/browser-test.js:1203:18\nTester_execTest@chrome://mochikit/content/browser-test.js:1345:14\nnextTest/<@chrome://mochikit/content/browser-test.js:1120:14\nSimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1056:13\n","nativeSavedFrame":{}}
[task 2023-06-13T20:07:26.205Z] 20:07:26     INFO - Stack trace:
[task 2023-06-13T20:07:26.205Z] 20:07:26     INFO - chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js:checkProcessCpuTime:20
[task 2023-06-13T20:07:26.205Z] 20:07:26     INFO - chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js:test_proc_info/<:115
[task 2023-06-13T20:07:26.205Z] 20:07:26     INFO - resource://testing-common/BrowserTestUtils.sys.mjs:withNewTab:149
[task 2023-06-13T20:07:26.205Z] 20:07:26     INFO - chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js:test_proc_info:55
[task 2023-06-13T20:07:26.205Z] 20:07:26     INFO - chrome://mochikit/content/browser-test.js:handleTask:1131
[task 2023-06-13T20:07:26.205Z] 20:07:26     INFO - chrome://mochikit/content/browser-test.js:_runTaskBasedTest:1203
[task 2023-06-13T20:07:26.206Z] 20:07:26     INFO - chrome://mochikit/content/browser-test.js:Tester_execTest:1345
[task 2023-06-13T20:07:26.206Z] 20:07:26     INFO - chrome://mochikit/content/browser-test.js:nextTest/<:1120
[task 2023-06-13T20:07:26.206Z] 20:07:26     INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/<:1056
[task 2023-06-13T20:07:26.206Z] 20:07:26     INFO - Not taking screenshot here: see the one that was previously logged
[task 2023-06-13T20:07:26.214Z] 20:07:26     INFO - TEST-UNEXPECTED-FAIL | toolkit/components/processtools/tests/browser/browser_test_procinfo.js | Got some cpu time in the threads - 0 > 0 - {"filename":"chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js","name":"checkProcessCpuTime","sourceId":586,"lineNumber":26,"columnNumber":10,"sourceLine":"","asyncCause":null,"asyncCaller":null,"caller":{"filename":"chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js","name":"test_proc_info/<","sourceId":586,"lineNumber":115,"columnNumber":30,"sourceLine":"","asyncCause":null,"asyncCaller":{"filename":"resource://testing-common/BrowserTestUtils.sys.mjs","name":"withNewTab","sourceId":570,"lineNumber":149,"columnNumber":22,"sourceLine":"","asyncCause":null,"asyncCaller":{"filename":"chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js","name":"test_proc_info","sourceId":586,"lineNumber":55,"columnNumber":26,"sourceLine":"","asyncCause":null,"asyncCaller":{"filename":"chrome://mochikit/content/browser-test.js","name":"handleTask","sourceId":540,"lineNumber":1131,"columnNumber":26,"sourceLine":"","asyncCause":null,"asyncCaller":null,"caller":{"filename":"chrome://mochikit/content/browser-test.js","name":"_runTaskBasedTest","sourceId":540,"lineNumber":1203,"columnNumber":18,"sourceLine":"","asyncCause":null,"asyncCaller":null,"caller":{"filename":"chrome://mochikit/content/browser-test.js","name":"Tester_execTest","sourceId":540,"lineNumber":1345,"columnNumber":14,"sourceLine":"","asyncCause":null,"asyncCaller":null,"caller":{"filename":"chrome://mochikit/content/browser-test.js","name":"nextTest/<","sourceId":540,"lineNumber":1120,"columnNumber":14,"sourceLine":"","asyncCause":null,"asyncCaller":null,"caller":{"filename":"chrome://mochikit/content/tests/SimpleTest/SimpleTest.js","name":"SimpleTest.waitForFocus/<","sourceId":564,"lineNumber":1056,"columnNumber":13,"sourceLine":"","asyncCause":null,"asyncCaller":null,"caller":null,"formattedStack":"SimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1056:13\n","nativeSavedFrame":{}},"formattedStack":"nextTest/<@chrome://mochikit/content/browser-test.js:1120:14\nSimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1056:13\n","nativeSavedFrame":{}},"formattedStack":"Tester_execTest@chrome://mochikit/content/browser-test.js:1345:14\nnextTest/<@chrome://mochikit/content/browser-test.js:1120:14\nSimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1056:13\n","nativeSavedFrame":{}},"formattedStack":"_runTaskBasedTest@chrome://mochikit/content/browser-test.js:1203:18\nTester_execTest@chrome://mochikit/content/browser-test.js:1345:14\nnextTest/<@chrome://mochikit/content/browser-test.js:1120:14\nSimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1056:13\n","nativeSavedFrame":{}},"formattedStack":"async*handleTask@chrome://mochikit/content/browser-test.js:1131:26\n_runTaskBasedTest@chrome://mochikit/content/browser-test.js:1203:18\nTester_execTest@chrome://mochikit/content/browser-test.js:1345:14\nnextTest/<@chrome://mochikit/content/browser-test.js:1120:14\nSimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1056:13\n","nativeSavedFrame":{}},"caller":null,"formattedStack":"async*test_proc_info@chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js:55:26\nasync*handleTask@chrome://mochikit/content/browser-test.js:1131:26\n_runTaskBasedTest@chrome://mochikit/content/browser-test.js:1203:18\nTester_execTest@chrome://mochikit/content/browser-test.js:1345:14\nnextTest/<@chrome://mochikit/content/browser-test.js:1120:14\nSimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1056:13\n","nativeSavedFrame":{}},"caller":null,"formattedStack":"async*withNewTab@resource://testing-common/BrowserTestUtils.sys.mjs:149:22\nasync*test_proc_info@chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js:55:26\nasync*handleTask@chrome://mochikit/content/browser-test.js:1131:26\n_runTaskBasedTest@chrome://mochikit/content/browser-test.js:1203:18\nTester_execTest@chrome://mochikit/content/browser-test.js:1345:14\nnextTest/<@chrome://mochikit/content/browser-test.js:1120:14\nSimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1056:13\n","nativeSavedFrame":{}},"caller":null,"formattedStack":"test_proc_info/<@chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js:115:30\nasync*withNewTab@resource://testing-common/BrowserTestUtils.sys.mjs:149:22\nasync*test_proc_info@chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js:55:26\nasync*handleTask@chrome://mochikit/content/browser-test.js:1131:26\n_runTaskBasedTest@chrome://mochikit/content/browser-test.js:1203:18\nTester_execTest@chrome://mochikit/content/browser-test.js:1345:14\nnextTest/<@chrome://mochikit/content/browser-test.js:1120:14\nSimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1056:13\n","nativeSavedFrame":{}},"formattedStack":"checkProcessCpuTime@chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js:26:10\ntest_proc_info/<@chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js:115:30\nasync*withNewTab@resource://testing-common/BrowserTestUtils.sys.mjs:149:22\nasync*test_proc_info@chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js:55:26\nasync*handleTask@chrome://mochikit/content/browser-test.js:1131:26\n_runTaskBasedTest@chrome://mochikit/content/browser-test.js:1203:18\nTester_execTest@chrome://mochikit/content/browser-test.js:1345:14\nnextTest/<@chrome://mochikit/content/browser-test.js:1120:14\nSimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1056:13\n","nativeSavedFrame":{}}
[task 2023-06-13T20:07:26.214Z] 20:07:26     INFO - Stack trace:
[task 2023-06-13T20:07:26.214Z] 20:07:26     INFO - chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js:checkProcessCpuTime:26
[task 2023-06-13T20:07:26.214Z] 20:07:26     INFO - chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js:test_proc_info/<:115
[task 2023-06-13T20:07:26.214Z] 20:07:26     INFO - resource://testing-common/BrowserTestUtils.sys.mjs:withNewTab:149
[task 2023-06-13T20:07:26.214Z] 20:07:26     INFO - chrome://mochitests/content/browser/toolkit/components/processtools/tests/browser/browser_test_procinfo.js:test_proc_info:55
[task 2023-06-13T20:07:26.214Z] 20:07:26     INFO - chrome://mochikit/content/browser-test.js:handleTask:1131
[task 2023-06-13T20:07:26.214Z] 20:07:26     INFO - chrome://mochikit/content/browser-test.js:_runTaskBasedTest:1203
[task 2023-06-13T20:07:26.214Z] 20:07:26     INFO - chrome://mochikit/content/browser-test.js:Tester_execTest:1345
[task 2023-06-13T20:07:26.214Z] 20:07:26     INFO - chrome://mochikit/content/browser-test.js:nextTest/<:1120
[task 2023-06-13T20:07:26.214Z] 20:07:26     INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/<:1056
[task 2023-06-13T20:07:26.215Z] 20:07:26     INFO - TEST-PASS | toolkit/components/processtools/tests/browser/browser_test_procinfo.js | The total CPU time of the process should be at least the sum of the CPU time spent by the still alive threads - 0 >= 0 - 

Hello Andrew! Any chance you could help us assign this to someone?

Thank you!

According to the moz.build files' component mapping as exposed by searchfox at https://searchfox.org/mozilla-central/source/toolkit/components/processtools/tests/browser/browser_test_procinfo.js this test is owned by "Toolkit :: Performance Monitoring". Moving to that component and clearing priority and severity so it can be considered for triage.

(In reply to Alexandre LISSY :gerard-majax from comment #41)

As we discussed with Florian, it might be helpful to augment the test case and make sure we get a view of the Utility actors [https://searchfox.org/mozilla-central/rev/9e3413f54ed6c9165b5659558091d766d34a731f/toolkit/components/aboutprocesses/content/aboutProcesses.js#269] on the process reporting 0 time. This way we might be able to know if it's a in-birth or death process or what.

Before disabling the test, can someone explore this?

Latest failures I can see are preallocated, not utility:

• https://treeherder.mozilla.org/logviewer?job_id=420334676&repo=autoland&lineNumber=3830-3831

woo, tons of failure on my w11 debug build ...

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

The root cause here and in bug 1819845 is the same: on virtual machines, we can't reliably get CPU use data at a resolution better than 1/64Hz (ie. in 15.625ms increments). See the code at https://searchfox.org/mozilla-central/rev/d31e56f7b3c2c18b8071a7b2a2fb6b4e01e3d3e8/toolkit/components/processtools/ProcInfo_win.cpp#36-39

My guess is that the Windows 11 VMs we use are faster than our Windows 10 VMs, and it became more common for a preallocated, utility or socket process to use less than 15.6ms of CPU time to start.

In terms of what to do to fix the bug, I tried forcing the use of the high precision method even on VM is xpc::IsInAutomation() https://hg.mozilla.org/try/rev/ab1efbf18d2d65f6b4081a29ca2f7c2f3ec2466e. That fixed browser_test_procinfo.js, but made browser_test_powerMetrics.js (ie bug 1819845) perma fail. It looks like xpc::IsInAutomation() always returns false in child processes, causing my patch to produce inconsistent CPU time values between the parent and child processes.

Indeed, it is being set via:

• https://searchfox.org/mozilla-central/rev/3b707c8fd7e978eebf24279ee51ccf07895cfbcb/js/xpconnect/src/nsXPConnect.cpp#1156
• https://searchfox.org/mozilla-central/rev/3b707c8fd7e978eebf24279ee51ccf07895cfbcb/js/xpconnect/src/nsXPConnect.cpp#155
• https://searchfox.org/mozilla-central/rev/3b707c8fd7e978eebf24279ee51ccf07895cfbcb/js/xpconnect/src/XPCModule.cpp#11
• https://searchfox.org/mozilla-central/rev/3b707c8fd7e978eebf24279ee51ccf07895cfbcb/layout/build/nsLayoutModule.cpp#100
• https://searchfox.org/mozilla-central/rev/3b707c8fd7e978eebf24279ee51ccf07895cfbcb/xpcom/components/nsComponentManager.cpp#371

This last call depends on ... The process type: https://searchfox.org/mozilla-central/rev/3b707c8fd7e978eebf24279ee51ccf07895cfbcb/xpcom/components/nsComponentManager.cpp#349-366

And as of now, there is no specific reason we would need to allow this on Utility process. Probably checking being on automation should be changed?