Intermittent dom/ipc/tests/browser_ProcessPriorityManager.js | single tracking bug
Categories
(Core :: DOM: Content Processes, defect, P3)
Tracking
()
Tracking | Status | |
---|---|---|
firefox121 | --- | fixed |
People
(Reporter: jmaher, Unassigned)
References
Details
(Keywords: intermittent-failure, intermittent-testcase, Whiteboard: [stockwell disable-recommended])
Attachments
(1 obsolete file)
Reporter | ||
Comment 1•3 years ago
|
||
Additional information about this bug failures and frequency patterns can be found by running: ./mach test-info failure-report --bug 1775836
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Updated•3 years ago
|
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 28•2 years ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit BugBot documentation.
Comment 29•2 years ago
|
||
treeherder |
New failure instance: https://treeherder.mozilla.org/logviewer?job_id=420673669&repo=mozilla-esr102
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 34•1 years ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit BugBot documentation.
Comment 35•1 years ago
|
||
treeherder |
New failure instance: https://treeherder.mozilla.org/logviewer?job_id=426758094&repo=mozilla-esr102
Comment hidden (Intermittent Failures Robot) |
Comment 37•1 year ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit BugBot documentation.
Comment 38•1 year ago
|
||
treeherder |
New failure instance: https://treeherder.mozilla.org/logviewer?job_id=430099145&repo=autoland
Comment hidden (Intermittent Failures Robot) |
Comment 40•1 year ago
|
||
Update
There have been 34 total failures within the last 7 days:
- 18 failures on Linux 18.04 x64 WebRender opt/debug
- 15 failures on Linux 18.04 x64 WebRender Shippable opt/debug
- 1 failure on Windows 11 x86 22H2 WebRender Shippable opt
Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=430889155&repo=autoland&lineNumber=15932
[task 2023-09-30T18:23:12.946Z] 18:23:12 INFO - TEST-PASS | dom/ipc/tests/browser_ProcessPriorityManager.js | Process with child ID 2 reached expected priority: FOREGROUND - true == true -
[task 2023-09-30T18:23:12.946Z] 18:23:12 INFO - Buffered messages finished
[task 2023-09-30T18:23:12.946Z] 18:23:12 INFO - TEST-UNEXPECTED-FAIL | dom/ipc/tests/browser_ProcessPriorityManager.js | Should have seen no process priority change for child ID 14 - "FOREGROUND" == null - {"filename":"chrome://mochitests/content/browser/dom/ipc/tests/browser_ProcessPriorityManager.js","name":"ensureNoPriorityChange","sourceId":630,"lineNumber":113,"columnNumber":12,"sourceLine":"","asyncCause":null,"asyncCaller":{"filename":"chrome://mochitests/content/browser/dom/ipc/tests/browser_ProcessPriorityManager.js","name":"waitForBrowserTreePriority","sourceId":630,"lineNumber":148,"columnNumber":18,"sourceLine":"","asyncCause":null,"asyncCaller":null,"caller":{"filename":"chrome://mochitests/content/browser/dom/ipc/tests/browser_ProcessPriorityManager.js","name":"assertPriorityChangeOnBackground","sourceId":630,"lineNumber":274,"columnNumber":41,"sourceLine":"","asyncCause":null,"asyncCaller":null,"caller":{"filename":"chrome://mochitests/content/browser/dom/ipc/tests/browser_ProcessPriorityManager.js","name":"test_video_background_tab/<","sourceId":630,"lineNumber":694,"columnNumber":11,"sourceLine":"","asyncCause":null,"asyncCaller":{"filename":"resource://testing-common/BrowserTestUtils.sys.mjs","name":"withNewTab","sourceId":582,"lineNumber":146,"columnNumber":22,"sourceLine":"","asyncCause":null,"asyncCaller":{"filename":"chrome://mochitests/content/browser/dom/ipc/tests/browser_ProcessPriorityManager.js","name":"test_video_background_tab","sourceId":630,"lineNumber":655,"columnNumber":26,"sourceLine":"","asyncCause":null,"asyncCaller":null,"caller":{"filename":"chrome://mochikit/content/browser-test.js","name":"handleTask","sourceId":549,"lineNumber":1131,"columnNumber":26,"sourceLine":"","asyncCause":null,"asyncCaller":null,"caller":{"filename":"chrome://mochikit/content/browser-test.js","name":"_runTaskBasedTest","sourceId":549,"lineNumber":1203,"columnNumber":18,"sourceLine":"","asyncCause":null,"asyncCaller":{"filename":"chrome://mochikit/content/browser-test.js","name":"Tester_execTest","sourceId":549,"lineNumber":1345,"columnNumber":14,"sourceLine":"","asyncCause":null,"asyncCaller":null,"caller":{"filename":"chrome://mochikit/content/browser-test.js","name":"nextTest/<","sourceId":549,"lineNumber":1120,"columnNumber":14,"sourceLine":"","asyncCause":null,"asyncCaller":null,"caller":{"filename":"chrome://mochikit/content/tests/SimpleTest/SimpleTest.js","name":"SimpleTest.waitForFocus/<","sourceId":576,"lineNumber":1058,"columnNumber":13,"sourceLine":"","asyncCause":null,"asyncCaller":null,"caller":null,"formattedStack":"SimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1058:13\n","nativeSavedFrame":{}},"formattedStack":"nextTest/<@chrome://mochikit/content/browser-test.js:1120:14\nSimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1058:13\n","nativeSavedFrame":{}},"formattedStack":"async*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:1058:13\n","nativeSavedFrame":{}},"caller":null,"formattedStack":"_runTaskBasedTest@chrome://mochikit/content/browser-test.js:1203:18\nasync*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:1058:13\n","nativeSavedFrame":{}},"formattedStack":"handleTask@chrome://mochikit/content/browser-test.js:1131:26\n_runTaskBasedTest@chrome://mochikit/content/browser-test.js:1203:18\nasync*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:1058:13\n","nativeSavedFrame":{}},"formattedStack":"async*test_video_background_tab@chrome://mochitests/content/browser/dom/ipc/tests/browser_ProcessPriorityManager.js:655:26\nhandleTask@chrome://mochikit/content/browser-test.js:1131:26\n_runTaskBasedTest@chrome://mochikit/content/browser-test.js:1203:18\nasync*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:1058:13\n","nativeSavedFrame":{}},"caller":null,"formattedStack":"async*withNewTab@resource://testing-common/BrowserTestUtils.sys.mjs:146:22\nasync*test_video_background_tab@chrome://mochitests/content/browser/dom/ipc/tests/browser_ProcessPriorityManager.js:655:26\nhandleTask@chrome://mochikit/content/browser-test.js:1131:26\n_runTaskBasedTest@chrome://mochikit/content/browser-test.js:1203:18\nasync*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:1058:13\n","nativeSavedFrame":{}},"caller":null,"formattedStack":"test_video_background_tab/<@chrome://mochitests/content/browser/dom/ipc/tests/browser_ProcessPriorityManager.js:694:11\nasync*withNewTab@resource://testing-common/BrowserTestUtils.sys.mjs:146:22\nasync*test_video_background_tab@chrome://mochitests/content/browser/dom/ipc/tests/browser_ProcessPriorityManager.js:655:26\nhandleTask@chrome://mochikit/content/browser-test.js:1131:26\n_runTaskBasedTest@chrome://mochikit/content/browser-test.js:1203:18\nasync*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:1058:13\n","nativeSavedFrame":{}},"formattedStack":"assertPriorityChangeOnBackground@chrome://mochitests/content/browser/dom/ipc/tests/browser_ProcessPriorityManager.js:274:41\ntest_video_background_tab/<@chrome://mochitests/content/browser/dom/ipc/tests/browser_ProcessPriorityManager.js:694:11\nasync*withNewTab@resource://testing-common/BrowserTestUtils.sys.mjs:146:22\nasync*test_video_background_tab@chrome://mochitests/content/browser/dom/ipc/tests/browser_ProcessPriorityManager.js:655:26\nhandleTask@chrome://mochikit/content/browser-test.js:1131:26\n_runTaskBasedTest@chrome://mochikit/content/browser-test.js:1203:18\nasync*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:1058:13\n","nativeSavedFrame":{}},"formattedStack":"async*waitForBrowserTreePriority@chrome://mochitests/content/browser/dom/ipc/tests/browser_ProcessPriorityManager.js:148:18\nassertPriorityChangeOnBackground@chrome://mochitests/content/browser/dom/ipc/tests/browser_ProcessPriorityManager.js:274:41\ntest_video_background_tab/<@chrome://mochitests/content/browser/dom/ipc/tests/browser_ProcessPriorityManager.js:694:11\nasync*withNewTab@resource://testing-common/BrowserTestUtils.sys.mjs:146:22\nasync*test_video_background_tab@chrome://mochitests/content/browser/dom/ipc/tests/browser_ProcessPriorityManager.js:655:26\nhandleTask@chrome://mochikit/content/browser-test.js:1131:26\n_runTaskBasedTest@chrome://mochikit/content/browser-test.js:1203:18\nasync*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:1058:13\n","nativeSavedFrame":{}},"caller":null,"formattedStack":"ensureNoPriorityChange@chrome://mochitests/content/browser/dom/ipc/tests/browser_ProcessPriorityManager.js:113:12\nasync*waitForBrowserTreePriority@chrome://mochitests/content/browser/dom/ipc/tests/browser_ProcessPriorityManager.js:148:18\nassertPriorityChangeOnBackground@chrome://mochitests/content/browser/dom/ipc/tests/browser_ProcessPriorityManager.js:274:41\ntest_video_background_tab/<@chrome://mochitests/content/browser/dom/ipc/tests/browser_ProcessPriorityManager.js:694:11\nasync*withNewTab@resource://testing-common/BrowserTestUtils.sys.mjs:146:22\nasync*test_video_background_tab@chrome://mochitests/content/browser/dom/ipc/tests/browser_ProcessPriorityManager.js:655:26\nhandleTask@chrome://mochikit/content/browser-test.js:1131:26\n_runTaskBasedTest@chrome://mochikit/content/browser-test.js:1203:18\nasync*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:1058:13\n","nativeSavedFrame":{}}
[task 2023-09-30T18:23:12.946Z] 18:23:12 INFO - Stack trace:
[task 2023-09-30T18:23:12.946Z] 18:23:12 INFO - chrome://mochitests/content/browser/dom/ipc/tests/browser_ProcessPriorityManager.js:ensureNoPriorityChange:113
[task 2023-09-30T18:23:12.947Z] 18:23:12 INFO - chrome://mochitests/content/browser/dom/ipc/tests/browser_ProcessPriorityManager.js:waitForBrowserTreePriority:148
[task 2023-09-30T18:23:12.947Z] 18:23:12 INFO - chrome://mochitests/content/browser/dom/ipc/tests/browser_ProcessPriorityManager.js:assertPriorityChangeOnBackground:274
[task 2023-09-30T18:23:12.947Z] 18:23:12 INFO - chrome://mochitests/content/browser/dom/ipc/tests/browser_ProcessPriorityManager.js:test_video_background_tab/<:694
[task 2023-09-30T18:23:12.947Z] 18:23:12 INFO - resource://testing-common/BrowserTestUtils.sys.mjs:withNewTab:146
[task 2023-09-30T18:23:12.947Z] 18:23:12 INFO - chrome://mochitests/content/browser/dom/ipc/tests/browser_ProcessPriorityManager.js:test_video_background_tab:655
[task 2023-09-30T18:23:12.947Z] 18:23:12 INFO - chrome://mochikit/content/browser-test.js:handleTask:1131
[task 2023-09-30T18:23:12.947Z] 18:23:12 INFO - chrome://mochikit/content/browser-test.js:_runTaskBasedTest:1203
[task 2023-09-30T18:23:12.947Z] 18:23:12 INFO - chrome://mochikit/content/browser-test.js:Tester_execTest:1345
[task 2023-09-30T18:23:12.947Z] 18:23:12 INFO - chrome://mochikit/content/browser-test.js:nextTest/<:1120
[task 2023-09-30T18:23:12.947Z] 18:23:12 INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/<:1058
[task 2023-09-30T18:23:12.948Z] 18:23:12 INFO - TEST-PASS | dom/ipc/tests/browser_ProcessPriorityManager.js | Tabs should be running in separate processes. - 2814 != 2432 -
Kagami, can you assign this to someone?
Thank you.
Comment hidden (Intermittent Failures Robot) |
Comment 42•1 year ago
|
||
Hi Kris, it seems you are the person who touched dom/ipc/ProcessPriorityManager.cpp last time in bug 1834629, would you like to take a look here?
Comment 43•1 year ago
|
||
It looks like it started failing frequently on Friday. Maybe the first step is to do some retriggers to narrow that down a bit. There's nothing obviously related that landed, looking back from the first failure. The closest was bug 1853244 which changed the .ini files to .toml though I don't know how that could cause an issue here.
Comment 45•1 year ago
|
||
Going back about 10 pushes before the first failure (see bc4), it looks like this test was being skipped.
TEST-START | dom/ipc/tests/browser_ProcessPriorityManager.js
TEST-SKIP | dom/ipc/tests/browser_ProcessPriorityManager.js | took 0ms
I think this strengthens my theory that this is related to bug 1853244, though I'll have to investigate more to see. However, I'm not sure why it was being skipped before. That doesn't make any sense to me.
This was the .ini entry (plus some support files):
[browser_ProcessPriorityManager.js]
skip-if = (os != "win") || (os != "linux") || (os != "mac")
Comment 46•1 year ago
|
||
I did some retriggers of bc tests around the landing of bug 1853244. There are a few odd issues here.
-
Prior to the landing of that, it appears we were just never running browser_ProcessPriorityManager.js. Who knows when that happened. Looking back at the failures in this bug, the last time I see a failure besides esr102 was a failure on release in the 2022-09-04 summary. Before that, there was a failure on autoland on 2022-08-14. I assume Linux opt just has been failing for a long time and we never noticed because it never ran. In the short term, maybe the path forward here is to disable this test on Linux opt. We'll still get Linux testing in debug builds. This feature has a lot of OS-specific code paths, so we want to avoid disabling it entirely on any given OS.
-
I triggered bc1 through bc7 on a bunch of pushes a bug 1853244 landed (for linux 64 opt bc spi-nw), as you can see here. On the pushes for bug 1853244, bug 1854456, and bug 1854551, browser_ProcessPriorityManager.js (and maybe the entire dom/ipc directory?) is never run. Then on the first push for bug 1171441, suddenly it is being run. Very bizarre. Joel, is it expected that your .toml change would cause this directory to just not get run like that? The bc test runs there are mostly (but not entirely)
Reporter | ||
Comment 47•1 year ago
|
||
previously this was in the browser.ini as:
[browser_ProcessPriorityManager.js]
skip-if = (os != "win") || (os != "linux") || (os != "mac")
now it is:
["browser_ProcessPriorityManager.js"]
skip-if = ["os == 'android'"]
prior to this we skipped this test on linux:
https://treeherder.mozilla.org/logviewer?job_id=430081428&repo=autoland
so the test was never ran, but the directory was scheduled.
I have seen this behavior before (earlier this year, before any .toml stuff) and have been puzzled by it. I see in the batch6 landing that only .ini manifests were scheduled. Our first 2 rounds we did verify logs of tests (on central) that things were running properly. Possibly there is a quirk with test identification/selection on autoland.
As for the topic of this bug, is it possible that this was not run anywhere before? The logic was sort of a mess.
Comment hidden (Intermittent Failures Robot) |
Comment 49•1 year ago
|
||
Sheriffs: if the failure rate here is too high, I think it would make sense to disable it on Linux opt.
Comment 50•1 year ago
|
||
There have been around 38 failures within the last 7 days, and 79 failures within the last 30 days.
It has not yet reached our disable-recommended queue, but if it does, we will go on with disabling it on Linux opt.
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 55•1 year ago
|
||
Update:
There have been 51 total failures in the last 7 days.
There are:
- 1 failure on linux1804-64-asan-qr opt
- 28 failures on linux1804-64-qr opt and debug
- 20 failures on linux1804-64-shippable-qr opt
- 1 failure on windows11-32-2009-qr opt
- 1 failure on windows11-64-2009-asan-qr opt
Recent failure log.
Comment hidden (Intermittent Failures Robot) |
Comment 57•1 year ago
|
||
Bug was closed by mistake. Reopening.
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 60•1 year ago
|
||
Updated•1 year ago
|
Comment 61•1 year ago
|
||
This has reached the "disable-recommended" state. Made a patch to disable this test on Linux opt due to frequent failures and as per comment 49. Please remember to re-enable the test when making a fix for the failures.
Hi Andrew! Can you please take another look at this?
Thank you!
Updated•1 year ago
|
Comment hidden (Intermittent Failures Robot) |
Updated•1 year ago
|
Comment 63•1 year ago
|
||
It looks like the failure is happening in test_video_background_tab() at the assertPriorityChangeOnBackground with the comment "The tab with the unmuted video should stay at PROCESS_PRIORITY_FOREGROUND when backgrounded.". I looked at 15 logs, and they all had the exact same line numbers for all frames in the assertion stack.
The actual assertion is in ensureNoPriorityChange(), and it is complaining that the video tab is in noChangeChildIDs with priority FOREGROUND. This is interesting because (as the comment above suggests) the initial priority is also FOREGROUND. So, I think for some reason the priority is changing to something else, then changing back to FOREGROUND. It would be kind of cool to record a log of the priorities we saw and then give a better error message. I filed bug 1864446 for that.
I'm not familiar with the mechanism we use for ensuring prioritization of video playing audio. I'm guessing this is the mHoldsPlayingAudioWakeLock stuff. So I'll have to read some code.
Comment 64•1 year ago
|
||
I implemented the logging I suggested in bug 1864446. The priority history is BACKGROUND_PERCEIVABLE then FOREGROUND.
It looks like the problem is that when we unmute the video element in the content process, it sends an async message to the parent. If the priority manager gets that message after BrowserPriorityChanged
gets called from the tab switch then that means the process priority temporarily gets set to BACKGROUND_PERCEIVABLE. I can reproduce the issue sometimes and with logging I think I confirmed that is what is actually happening.
The fix is to wait after the unmute for the parent process to get the wakelock message from the unmute before doing the tab switch.
Updated•1 year ago
|
Updated•1 year ago
|
Comment 65•1 year ago
|
||
Comment on attachment 9363137 [details]
Bug 1775836 - disable browser_ProcessPriorityManager.js on Linux opt for frequent failures. r=#intermittent-reviewers,mccr8,janv
My test fix is queued up for landing.
Comment hidden (Intermittent Failures Robot) |
Comment 67•1 year ago
|
||
It looks like the failures are fixed. I do see a verify failure that is a timeout. I'm not sure if that is related to my changes or not. I guess we can keep an eye on that.
Comment hidden (Intermittent Failures Robot) |
Updated•1 year ago
|
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Description
•