1798096 - Perma android shippable /css/css-contain/container-queries/multicol-inside-container.html | single tracking bug

Status: RESOLVED FIXED

(Core :: Layout, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: smolnar [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=394774609&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/WQP-x-hkT4Kfzxgaq90vnA/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/WQP-x-hkT4Kfzxgaq90vnA/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1

---

INFO - TEST-START | /css/css-contain/container-queries/multicol-inside-container.html
[task 2022-10-29T00:04:29.621Z] 00:04:29     INFO - TEST-UNEXPECTED-TIMEOUT | /css/css-contain/container-queries/multicol-inside-container.html | expected PASS
[task 2022-10-29T00:04:29.621Z] 00:04:29     INFO - TEST-INFO took 20160ms
[task 2022-10-29T00:04:30.043Z] 00:04:30     INFO - STDOUT: cleanup aborted: Unable to remount device
[task 2022-10-29T00:04:30.138Z] 00:04:30     INFO - STDOUT: cleanup aborted: Unable to remount device
[task 2022-10-29T00:04:30.139Z] 00:04:30     INFO - Closing logging queue
[task 2022-10-29T00:04:30.139Z] 00:04:30     INFO - queue closed
[task 2022-10-29T00:04:30.153Z] 00:04:30     INFO - Setting android reftest preferences
[task 2022-10-29T00:04:30.154Z] 00:04:30     INFO - Setting up ssl
[task 2022-10-29T00:04:30.172Z] 00:04:30     INFO - certutil | b''
[task 2022-10-29T00:04:30.190Z] 00:04:30     INFO - certutil | b''
[task 2022-10-29T00:04:30.201Z] 00:04:30     INFO - certutil | b'\nCertificate Nickname                                         Trust Attributes\n                                                             SSL,S/MIME,JAR/XPI\n\nweb-platform-tests                                           CT,, \n'
[task 2022-10-29T00:04:30.805Z] 00:04:30     INFO - adb Granting important runtime permissions to org.mozilla.geckoview.test_runner
[task 2022-10-29T00:04:32.060Z] 00:04:32     INFO - adb launch_application: am start -W -n org.mozilla.geckoview.test_runner/org.mozilla.geckoview.test_runner.TestRunnerActivity -a android.intent.action.MAIN --es env0 MOZ_CRASHREPORTER=1 --es env1 MOZ_CRASHREPORTER_NO_REPORT=1 --es env2 MOZ_CRASHREPORTER_SHUTDOWN=1 --es env3 MOZ_HIDE_RESULTS_TABLE=1 --es env4 MOZ_IN_AUTOMATION=1 --es env5 MOZ_LOG=signaling:3,mtransport:4,DataChannel:4,jsep:4 --es env6 R_LOG_LEVEL=6 --es env7 R_LOG_DESTINATION=stderr --es env8 R_LOG_VERBOSE=1 --es env9 MOZ_PROCESS_LOG=/tmp/tmp9sqarx9_pidlog --es env10 MOZ_DISABLE_NONLOCAL_CONNECTIONS=1 --es env11 STYLO_THREADS=1 --es arg0 -no-remote --es arg1 -profile --es arg2 /data/local/tmp/test_root/profile --es arg3 --marionette --es arg4 about:blank --ez use_multiprocess True
[task 2022-10-29T00:04:33.449Z] 00:04:33     INFO - Starting runner
[task 2022-10-29T00:04:34.614Z] 00:04:34     INFO - TEST-START | /css/css-contain/container-queries/pseudo-elements-002.html

Comment 1

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

Set release status flags based on info from the regressing bug 1797763

:emilio, since you are the author of the regressor, bug 1797763, could you take a look?

For more information, please visit auto_nag documentation.

Comment 2

[Intermittent Failures Robot]

22 failures in 3743 pushes (0.006 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 18
• try: 4

Platform and build breakdown:

• android-em-7-0-x86_64-shippable-lite-qr: 10
  • opt: 10
• android-em-7-0-x86_64-shippable-qr: 12
  • opt: 12

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1798096&startday=2022-10-24&endday=2022-10-30&tree=all

Comment 3

[Emilio Cobos Álvarez (:emilio)]

James, do you happen to know how to best investigate this? I don't see any stack trace of the timeout or so (which IIRC is visible when a non-wpt reftest or such times out), and I can't repro this locally at all...

Comment 4

[James Graham [:jgraham]]

Hmm, so I'm quite surprisesd that any of these tests are timing out :/

I did notice that for the timeout logs I looked at, it seems like we're always also seeing a timeout in /css/css-contain/container-queries/inner-first-line-non-matching.html which is marked as intermittent timeout on android, but could be a perma. Maybe try running both tests together? However, neither of those look like they should be able to time out unless there's a bug (in the harness, or in the APIs it's using) or we're failing to reach a stable layout state.

In terms of debugging, the first port of call would be running with remote.log.level=Trace set, which should give enough output to figure out where we're hanging.

The top-level timeout here is just using Promise.race: https://searchfox.org/mozilla-central/source/remote/marionette/reftest.sys.mjs#327 idk how easy it is to log current stack of the promise that lost the race?

Anyway, the most likely place we're waiting is somewhere in https://searchfox.org/mozilla-central/source/remote/marionette/actors/MarionetteReftestChild.sys.mjs#81 which handles both waiting for a reftest-wait class to be removed (not relevant in this case), and also for us to reach a stable layout for a screenshot.

Comment 5

[Emilio Cobos Álvarez (:emilio)]

There are some container-query tests that are expected to time-out (e.g., this, maybe the harness is attributing the timeout to the wrong test?

Comment 6

[Intermittent Failures Robot]

65 failures in 3626 pushes (0.018 failures/push) were associated with this bug in the last 7 days.

This is the #24 most frequent failure this week.

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **

Repository breakdown:

• mozilla-central: 46
• try: 19

Platform and build breakdown:

• android-em-7-0-x86_64-shippable-lite-qr: 33
  • opt: 33
• android-em-7-0-x86_64-shippable-qr: 32
  • opt: 32

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1798096&startday=2022-10-31&endday=2022-11-06&tree=all

Comment 7

[Daniel Holbert [:dholbert]]

It looks like the test is legitimately timing out; at least, the timestamps in the log do indeed show that 20 seconds are ellapsing between TEST-START and TEST-UNEXPECTED-TIMEOUT for this test. E.g. in this recent run, we have:

[task 2022-11-06T23:44:10.494Z] 23:44:10     INFO - TEST-START | /css/css-contain/container-queries/multicol-inside-container.html
[task 2022-11-06T23:44:30.641Z] 23:44:30     INFO - TEST-UNEXPECTED-TIMEOUT | /css/css-contain/container-queries/multicol-inside-container.html | expected PASS
[task 2022-11-06T23:44:30.642Z] 23:44:30     INFO - TEST-INFO took 20147ms

The test starts at 23:44:10, and gets judged to have timed out 20 seconds later at 23:44:30. (And 20 seconds seems to be the timeout threshold on this platform, based on the nearby log lines for other nearby tests that have expected-timeouts.)

So: probably we should just annotate this as expected-timeout-on-Android for the time being, to reflect reality...

Comment 8

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

Bug 1797424 kicked this down to resize-while-content-visibility-hidden.html: bug 1799569.

Comment 9

[Intermittent Failures Robot]

8 failures in 3445 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 4
• try: 4

Platform and build breakdown:

• android-em-7-0-x86_64-shippable-qr: 3
  • opt: 3
• android-em-7-0-x86_64-shippable-lite-qr: 3
  • opt: 3
• android-em-7-0-x86_64-qr: 1
  • opt: 1
• android-em-7-0-x86_64-lite-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1798096&startday=2022-11-07&endday=2022-11-13&tree=all

Comment 10

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

Set release status flags based on info from the regressing bug 1797763

Comment 11

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

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

Comment 12

[Treeherder Bug Filer]

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

Comment 13

[Daniel Holbert [:dholbert]]

(In reply to Treeherder Bug Filer from comment #12)

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

This one was actually TEST-UNEXPECTED-PASS... (The test expects to match the WPT standard "green square" reference case, and in this case it did.)

The test is annotated with an expectation of if (os == "android") and not debug: TIMEOUT:
https://searchfox.org/mozilla-central/rev/664e09d9df713177b233f21a3af177e85796c2f0/testing/web-platform/meta/css/css-contain/container-queries/multicol-inside-container.html.ini

It seems we need to update that expectation to include PASS as one possible outcome.

Comment 14

[Daniel Holbert [:dholbert]]

Attachment: Bug 1798096: Update expectation for WPT multicol-inside-container.html, to note that it sometimes passes (instead of timing out) on Android opt builds. r?#layout-reviewers

Comment 15

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/81f62de2d85e
Update expectation for WPT multicol-inside-container.html, to note that it sometimes passes (instead of timing out) on Android opt builds. r=layout-reviewers,tnikkel

Comment 16

[Atila Butkovits]

https://hg.mozilla.org/mozilla-central/rev/81f62de2d85e

Comment 17

[Intermittent Failures Robot]

15 failures in 1328 pushes (0.011 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 9
• try: 6

Platform and build breakdown:

• android-em-7-0-x86_64-shippable-qr: 9
  • opt: 9
• android-em-7-0-x86_64-shippable-lite-qr: 6
  • opt: 6

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1798096&startday=2022-12-26&endday=2023-01-01&tree=all