Frequent win browser/components/preferences/tests/browser_privacy_dnsoverhttps.js - This test exceeded the timeout threshold. It should be rewritten or split up. If that's not possible, use requestLongerTimeout(N), but only as a last resort
Categories
(Firefox :: Settings UI, defect, P5)
Tracking
()
| Tracking | Status | |
|---|---|---|
| firefox-esr115 | --- | unaffected |
| firefox-esr140 | --- | unaffected |
| firefox147 | --- | unaffected |
| firefox148 | --- | disabled |
| firefox149 | --- | affected |
People
(Reporter: intermittent-bug-filer, Unassigned)
References
(Regression)
Details
(4 keywords, Whiteboard: [collect_confirm_failure][stockwell disabled])
Attachments
(1 file, 1 obsolete file)
Filed by: csabou [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=542678143&repo=autoland&task=JPvt2gmwSFmpBi8h9_5dwA.0
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/JPvt2gmwSFmpBi8h9_5dwA/runs/0/artifacts/public/logs/live_backing.log
[task 2026-01-08T07:33:02.933+00:00] 07:33:02 INFO - TEST-PASS | browser/components/preferences/tests/browser_privacy_dnsoverhttps.js | testEnterprisePolicy - Expected custom resolver
[task 2026-01-08T07:33:02.934+00:00] 07:33:02 INFO - Buffered messages logged at 07:33:00
[task 2026-01-08T07:33:02.934+00:00] 07:33:02 INFO - TEST-PASS | browser/components/preferences/tests/browser_privacy_dnsoverhttps.js | testEnterprisePolicy - Sanity check the temporary file doesn't exist. - true == true
[task 2026-01-08T07:33:02.935+00:00] 07:33:02 INFO - Leaving test testEnterprisePolicy
[task 2026-01-08T07:33:02.935+00:00] 07:33:02 INFO - Buffered messages finished
[task 2026-01-08T07:33:02.936+00:00] 07:33:02 INFO - TEST-UNEXPECTED-FAIL | browser/components/preferences/tests/browser_privacy_dnsoverhttps.js - This test exceeded the timeout threshold. It should be rewritten or split up. If that's not possible, use requestLongerTimeout(N), but only as a last resort.
[task 2026-01-08T07:33:02.936+00:00] 07:33:02 INFO - GECKO(3212) | MEMORY STAT | vsize 2118206MB | vsizeMaxContiguous 64967945MB | residentFast 5626MB | heapAllocated 3325MB
[task 2026-01-08T07:33:02.937+00:00] 07:33:02 INFO - checking for open sidebars
[task 2026-01-08T07:33:02.937+00:00] 07:33:02 INFO - checking window state
[task 2026-01-08T07:33:02.938+00:00] 07:33:02 INFO - TEST-OK | browser/components/preferences/tests/browser_privacy_dnsoverhttps.js | took 396946ms
[task 2026-01-08T07:33:02.938+00:00] 07:33:02 INFO - GECKO(3212) | [Child 5508: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 268d5861400 == 1 [pid = 5508] [id = 200]
[task 2026-01-08T07:33:02.939+00:00] 07:33:02 INFO - GECKO(3212) | [Child 5508: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 2 (268d5e3bd00) [pid = 5508] [serial = 406] [outer = 0]
[task 2026-01-08T07:33:02.939+00:00] 07:33:02 INFO - GECKO(3212) | [Child 5508: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 3 (268d5869800) [pid = 5508] [serial = 407] [outer = 268d5e3bd00]
[task 2026-01-08T07:33:03.068+00:00] 07:33:03 INFO - TEST-START | browser/components/preferences/tests/browser_privacy_gpc.js
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
backfills point to bug 1978102
Comment 5•6 months ago
|
||
Set release status flags based on info from the regressing bug 1978102
:sfoster, since you are the author of the regressor, bug 1978102, could you take a look?
For more information, please visit BugBot documentation.
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
Comment 9•6 months ago
|
||
Updated•6 months ago
|
Comment 10•6 months ago
|
||
See also bug 1731059 and various other bugs like it. That bug is closed because we stopped running on win32, but it's clear we're hitting unmanageable memory use growth here as well - the limit is just higher on 64-bit builds. Doesn't stop us though!
This is the resource profile for a failing test run: https://profiler.firefox.com/from-url/https%3A%2F%2Ffirefox-ci-tc.services.mozilla.com%2Fapi%2Fqueue%2Fv1%2Ftask%2FJPvt2gmwSFmpBi8h9_5dwA%2Fruns%2F0%2Fartifacts%2Fpublic%2Ftest_info%2Fprofile_resource-usage.json/marker-chart/?globalTrackOrder=0&profileName=test-windows11-64-24h2%2Fdebug-mochitest-browser-chrome-msix-1%20%28JPvt2gmwSFmpBi8h9_5dwA.0%29&range=18781m3999969&thread=0&timelineType=category&v=12 .
Note in particular that the machine's memory usage went from about 2.5GiB to a whopping 14+ GiB over the course of running the tests in this directory.
This particular test is quite bad in that it opens lots of settings tabs with various configurations, and closes them again (one at a time, to be clear). This leads to noticeable GC/CC jank when run locally (as in, after the test finishes its actual work completely, it takes about 90 seconds to clean up on my fast-ish threadripper, on a debug build).
So I think what is happening here is that the test is just slow to reach a conclusion, and then spends a long time not outputting anything, and that makes it sad.
(In reply to amarc from comment #4)
backfills point to bug 1978102
I think this is questionable? The last push in that backfill set, further down than the window you linked, has 4 out of 10 backfill jobs failing with this test, this one has 6 out of 10, the alleged culprit here has 2 out of 5, with 2 other GC errors being listed.
If it is related, it's probably just that it introduced an additional cleanup function that somehow gives the test "room to breathe" in some way, and that is tripping the timeout detection (which has special cases for timeouts that happen before/after a lack of logging, i.e. an indication the test is still "doing something").
So I'm not really sure how to proceed here. The discussion in bug 1731059 suggests that "just run more GC/CC" is not a good solution. We can split up the test and that will help a little bit, but not with the overall trend in this directory. We could split up the directory, which will help but still doesn't actually really address the underlying problem.
I don't like the idea of disabling the test on Windows because it's effectively "unlucky" in terms of being slow because it's doing something repetitively that other tests are also doing. Looking at a profile of the test, it's difficult to point to anything specific - there's a lot of lit activity from opening the settings, and a lot of GC/CC activity - but not much in the way of actual test-specific profile activity. It's also surprising this is so Windows-specific.
The timing information suggests the test is significantly slower on Windows, but again, unclear why that would be unless it's just that the machines are slower.
It smells to me like we're leaking something when opening/closing settings, perhaps moreso on Windows than other OSes, but I don't know how to dig into that suspicion. There are no shutdown leaks reported (unless running with the profiler, which is bug 1699681).
:mccr8, any chance you can suggest how we might get to the bottom of this?
:amarc, any chance we can establish more conclusively when this stopped/started (or am I missing something) ?
:florian, anything else I should try to get to the bottom of this intermittent failure that I haven't tried yet? 😅
Comment 11•6 months ago
|
||
(In reply to :Gijs (he/him) from comment #10)
(In reply to amarc from comment #4)
backfills point to bug 1978102
I think this is questionable? The last push in that backfill set, further down than the window you linked, has 4 out of 10 backfill jobs failing with this test, this one has 6 out of 10, the alleged culprit here has 2 out of 5, with 2 other GC errors being listed.
Also, beta is marked as affected but that fix only changed behaviour-under-test on nightly, so that wouldn't make a lot of sense.
Updated•6 months ago
|
Comment 12•6 months ago
|
||
Still freq failing here. Needs more investigation.
| Comment hidden (Intermittent Failures Robot) |
Comment 14•6 months ago
|
||
That does look like a steadily growing leak. For browser-chrome tests, we do check that windows and docshells that are created during a test are also destroyed during that test, so I think we can't be leaking windows. It must be something else.
I haven't looked at test memory usage in a long time so I'm not sure if this steady growth is par for the course or not. It might be good to look at another bc test directory to see if it is that bad. Honestly, looking at the profile, it seems not great for a single test directory to take more than an hour to run. So it might just be that we always slowly leak and this builds up. If that's not the case, then you could try looking at the head.js file to see if there's anything this directory in particular is doing that is a problem.
I'll try to think of more to look at here.
Comment 15•6 months ago
|
||
Getting a memory report while it is farther along in the test directory might be useful, though I'm not sure how to do that automatically. It might be possible to use the "leave browser open" option and then manually save a memory report once it is done.
| Comment hidden (Intermittent Failures Robot) |
Updated•6 months ago
|
| Comment hidden (Intermittent Failures Robot) |
Comment 18•6 months ago
|
||
fired more backfills, that did not lead to anything unfortunately
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
Comment 21•6 months ago
|
||
(In reply to :Gijs (he/him) from comment #10)
:florian, anything else I should try to get to the bottom of this intermittent failure that I haven't tried yet? 😅
There are multiple tests in this folder that fail with shutdown leaks when running them standalone: https://treeherder.mozilla.org/jobs?repo=try&resultStatus=pending%2Crunning%2Csuccess%2Ctestfailed%2Cbusted%2Cexception%2Csuperseded%2Cretry%2Cusercancel%2Crunnable&tier=1%2C2%2C3&revision=6161f4139e5b6e7522f0775419c9ab84fd22f4e6&test_paths=browser%2Fcomponents%2Fpreferences%2Ftests&searchStr=debug
Maybe that contributes to the growing memory use over time?
| 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) |
Updated•5 months ago
|
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
Comment 34•5 months ago
|
||
| Comment hidden (Intermittent Failures Robot) |
Comment 36•5 months ago
|
||
| bugherder | ||
Updated•5 months ago
|
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
Comment 39•5 months ago
|
||
The test opens about:preferences ~40 times, with each open taking several seconds in
debug builds.
Split the monolithic test into thematic files:
- browser_privacy_dnsoverhttps.js: parental controls, defaults, enterprise policy
- browser_privacy_dnsoverhttps_modes.js: TRR mode mapping (11 variations)
- browser_privacy_dnsoverhttps_mode_switching.js: mode transitions (8 variations)
- browser_privacy_dnsoverhttps_heuristics.js: rollout heuristics (5 variations)
- browser_privacy_dnsoverhttps_other.js: UI radio toggles (3 variations)
- browser_privacy_dnsoverhttps_providers.js: NextDNS selection + remote settings (8 tests)
- browser_privacy_dnsoverhttps_custom_uri.js: custom URI management (5 variations)
Comment 40•5 months ago
|
||
(In reply to Jens Stutte [:jstutte] from comment #39)
Created attachment 9547975 [details]
WIP: Bug 2009120 - Split browser_privacy_dnsoverhttps.js into 7 files to fix frequent timeouts on Windows debug CI. r?mconley
Doesn't this just move the timeouts? See also comment 10 and the profile there. The tests early in that run take only ~2s to open and close prefs (e.g. browser_bug1184989_prevent_scrolling_when_preferences_flipped.js) and then towards the end, browser_sync_disabled.js takes 5s.
It just shouldn't be the case that this is quite this slow and that the memory use is so bad. What does it take to find out why we're slowing down this much / keeping so much memory around? Can we try the suggestions from mccr8 in comment 14, or Florian's in comment #21 ?
Updated•5 months ago
|
Updated•5 months ago
|
Comment 41•5 months ago
|
||
(In reply to :Gijs (away/busy until Mar 10) from comment #40)
Doesn't this just move the timeouts? See also comment 10 and the profile there. The tests early in that run take only ~2s to open and close prefs (e.g.
browser_bug1184989_prevent_scrolling_when_preferences_flipped.js) and then towards the end,browser_sync_disabled.jstakes 5s.It just shouldn't be the case that this is quite this slow and that the memory use is so bad. What does it take to find out why we're slowing down this much / keeping so much memory around? Can we try the suggestions from mccr8 in comment 14, or Florian's in comment #21 ?
I ran into this when trying to land (unrelated) bug 2016728. But one should also read the entire bug here before proposing a paper-over fix. I'll take a closer look.
| Comment hidden (Intermittent Failures Robot) |
Updated•5 months ago
|
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
Comment 46•4 months ago
|
||
Down from 38 to 4 per weeks feels pretty good. Florian, were there more outstanding leaks for prefs? I have a recollection of seeing another bug fly by but can't find it in the blocking/connected bugs here. It would be good to re-enable this on windows debug but not sure if that is feasible right now.
Comment 47•4 months ago
|
||
(In reply to :Gijs (he/him) from comment #46)
Down from 38 to 4 per weeks feels pretty good.
The remaining failures seem to be mostly on Windows ccov, which might be super slow for other reasons.
Florian, were there more outstanding leaks for prefs?
There's one leak of about:preferences still on my radar but reported in the browser/components/migration/tests/browser/ folder on Windows msix runs, I'm not sure it would help for this bug.
It would be good to re-enable this on windows debug but not sure if that is feasible right now.
Try and see what happens? :-)
I would also like to breakdown the test manifest into smaller manifests so we have more reasonable chunk run times on eg tsan. That might help too (or hide more failures, depending on how you look at this).
If we want to try harder to find leaks in the preference window, we could push to try something opening a new window for every test, that might catch more things.
| 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) |
Description
•