1886772 - Intermittent [tier 2] /css/css-layout-api/constraints/fixed-block-size-fixed.https.html | single tracking bug

Status: RESOLVED INCOMPLETE

(Core :: Layout, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: imoraru [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=451665470&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/ZZD16AJeR5elDPRW3nqbhQ/runs/0/artifacts/public/logs/live_backing.log
Reftest URL: https://hg.mozilla.org/mozilla-central/raw-file/tip/layout/tools/reftest/reftest-analyzer.xhtml#logurl=https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/ZZD16AJeR5elDPRW3nqbhQ/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1

---

[task 2024-03-21T14:02:57.350Z] 14:02:57     INFO - TEST-START | /css/css-layout-api/constraints/fixed-block-size-fixed.https.html
[task 2024-03-21T14:02:57.351Z] 14:02:57     INFO - PID 5844 | 1711029777350	Marionette	INFO	Testing https://web-platform.test:8443/css/css-layout-api/constraints/fixed-block-size-fixed.https.html == http://web-platform.test:8000/css/css-layout-api/green-square-ref.html
[task 2024-03-21T14:02:59.883Z] 14:02:59     INFO - TEST-UNEXPECTED-TIMEOUT | /css/css-layout-api/constraints/fixed-block-size-fixed.https.html | expected FAIL
[task 2024-03-21T14:02:59.883Z] 14:02:59     INFO - TEST-INFO expected FAIL | took 2534ms
[task 2024-03-21T14:02:59.893Z] 14:02:59     INFO - PID 5844 | 1711029779892	Marionette	INFO	Stopped listening on port 53471
[task 2024-03-21T14:03:13.483Z] 14:03:13     INFO - Browser exited with return code 0
[task 2024-03-21T14:03:13.484Z] 14:03:13     INFO - Closing logging queue
[task 2024-03-21T14:03:13.484Z] 14:03:13     INFO - queue closed
[task 2024-03-21T14:03:13.533Z] 14:03:13     INFO - Application command: Z:\task_171102798689494\build\application\firefox\firefox.exe -marionette about:blank --wait-for-browser -profile C:\Users\task_171102798689494\AppData\Local\Temp\tmp97i_sffw
[task 2024-03-21T14:03:13.540Z] 14:03:13     INFO - PID 3864 | 1711029772581	Marionette	INFO	Marionette enabled
[task 2024-03-21T14:03:13.541Z] 14:03:13     INFO - PID 3864 | 1711029772663	Marionette	INFO	Listening on port 53563
[task 2024-03-21T14:03:13.541Z] 14:03:13     INFO - Starting runner
[task 2024-03-21T14:03:14.572Z] 14:03:14     INFO - TEST-START | /css/css-layout-api/constraints/fixed-block-size-flex-basis-vrl.https.html

Comment 1

[Daniel Holbert [:dholbert]]

If I'm reading the log right, this test was judged as a TIMEOUT after only 2.5 seconds (took 2534ms)... that seems suspiciously low for a "test timed out" judgement. I thought 10s was our default/lowest timeout threshold for WPTs?

jgraham or jmaher, do you know what might be going on here? Do we actually have a ~2.5 second timeout threshold for these tests? (If so, we should probably increase that; some of the nearby tests are taking e.g. 1732ms, 1976ms, 2229ms, if I scroll around a bit in the log -- super close to whatever threshold this test happened to trip over.)

Comment 2

[Intermittent Failures Robot]

1 failures in 3791 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 1

Platform and build breakdown:

• windows11-64-2009-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1886772&startday=2024-03-18&endday=2024-03-24&tree=all

Comment 3

[James Graham [:jgraham]]

The problem is that this is put in a backlog job, where the timeout is overridden in mozharness: https://searchfox.org/mozilla-central/source/testing/mozharness/scripts/web_platform_tests.py#443 The tests are never validated with such a short timeout, and I agree that it seems problematic.

Comment 4

[Daniel Holbert [:dholbert]]

Thanks, that makes some sense. Adding some additional detail:

(In reply to James Graham [:jgraham] from comment #3)

The problem is that this is put in a backlog job

That happens via the implementation-status: backlog annotation here, from bug 1572820.

It seems we do this for about 100 directories of tests, based on a searchfox search. I would bet that many/most of those tests are simply "expected: FAIL" (due to us not implementing some feature), and the 0.25x timeout multiplier puts them at risk of triggering intermittent failures and resulting confusion & bug-spam like this bug here. (For tests that are simply expected-failure, the reduced timeout multiplier (bug 1643177) turns every test into a potential infrequent intermittent-timeout, given that (per comment 1) many of the tests are extremely close to tripping over the reduced 2.5s timeout threshold. I'd bet we've already proceeded to annotate some such tests as expected-timeout, not due to a "real" timeout but only because they overshoot this reduced 2.5s threshold occasionally.)

Two ideas for ways forward here:
(1) If possible, it seems like we should only apply bug 1643177's timeout multiplier for tests that are explicitly annotated as expected timeout (which seems to be what bug 1643177 comment 0 was assuming about all of the backlog tests -- "Since the tests in the backlog side of things are expected to time out by default,[...]").

(2) One less-elegant solution would be to simply treat every test in the backlog task as having TIMEOUT included in its list of acceptable results, whether due to an actual timeout in the test or due to our reduced time threshold. That would feel pretty clumsy, though, and could give us reduced test-coverage for real regressions where we inadvertently introduce a perma-hang that one of the backlog tests happens to trigger.

jmaher, does proposal (1) make sense to you / do you have other ideas about what we could do here?

Comment 5

[Joel Maher ( :jmaher ) (UTC -8)]

I like #1. I am unsure of how to proceed here. Possibly we pass in a backlog parameter to the harness and before the test if the possible expectations include TIMEOUT, then we set the multiplier. I am hunting around and will for a bit more.

Comment 6

[Joel Maher ( :jmaher ) (UTC -8)]

I assume the code around https://searchfox.org/mozilla-central/source/testing/web-platform/tests/tools/wptrunner/wptrunner/testrunner.py#655 would need to be modified. I am not sure if we have access to the expected test results here.

Comment 7

[Joel Maher ( :jmaher ) (UTC -8)]

we should be able to use self.state.test.expected() to get what is expected, maybe need a call for self.state.test.known_intermittent. Of course a backlog variable needs to be plumbed down there

Comment 8

[Joel Maher ( :jmaher ) (UTC -8)]

Attachment: Bug 1886772 - only use backlog timeout multiplier if expecting a timeout. r=jgraham

Comment 9

[BugBot [:suhaib / :marco/ :calixte]]

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