Closed Bug 1786088 Opened 2 years ago Closed 2 years ago

Intermittent TV dom/html/test/test_bug1785739.html | undefined assertion name - got 1, expected 115

Categories

(Core :: DOM: Core & HTML, defect, P5)

Product:
Core
Component:
DOM: Core & HTML
Type:
defect

Tracking

()

Status:
RESOLVED FIXED
Milestone:
105 Branch
Tracking Flags:
Tracking Status
firefox-esr91 --- unaffected
firefox-esr102 --- unaffected
firefox104 --- unaffected
firefox105 --- fixed

People

(Reporter: intermittent-bug-filer, Assigned: dholbert)

References

(Regression)

Details

(Keywords: intermittent-failure, regression)

Attachments

(1 file)

Bug 1786088: Run the font-loader task eagerly for dom/html mochitests. r?jfkthame
48 bytes, text/x-phabricator-request
Details | Review

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

[task 2022-08-19T19:15:41.558Z] 19:15:41     INFO - TEST-START | dom/html/test/test_bug1785739.html
[task 2022-08-19T19:15:43.936Z] 19:15:43     INFO - TEST-INFO | started process screencapture
[task 2022-08-19T19:15:44.064Z] 19:15:44     INFO - TEST-INFO | screencapture: exit 0
[task 2022-08-19T19:15:44.064Z] 19:15:44     INFO - Buffered messages logged at 19:15:43
[task 2022-08-19T19:15:44.065Z] 19:15:44     INFO - TEST-PASS | dom/html/test/test_bug1785739.html | undefined assertion name 
[task 2022-08-19T19:15:44.065Z] 19:15:44     INFO - TEST-PASS | dom/html/test/test_bug1785739.html | undefined assertion name 
[task 2022-08-19T19:15:44.066Z] 19:15:44     INFO - TEST-PASS | dom/html/test/test_bug1785739.html | undefined assertion name 
[task 2022-08-19T19:15:44.066Z] 19:15:44     INFO - TEST-PASS | dom/html/test/test_bug1785739.html | undefined assertion name 
[task 2022-08-19T19:15:44.067Z] 19:15:44     INFO - TEST-PASS | dom/html/test/test_bug1785739.html | undefined assertion name 
[task 2022-08-19T19:15:44.067Z] 19:15:44     INFO - TEST-PASS | dom/html/test/test_bug1785739.html | undefined assertion name 
[task 2022-08-19T19:15:44.067Z] 19:15:44     INFO - Buffered messages finished
[task 2022-08-19T19:15:44.068Z] 19:15:44     INFO - TEST-UNEXPECTED-FAIL | dom/html/test/test_bug1785739.html | undefined assertion name - got 1, expected 115
[task 2022-08-19T19:15:44.068Z] 19:15:44     INFO -     SimpleTest.is@SimpleTest/SimpleTest.js:497:14
[task 2022-08-19T19:15:44.068Z] 19:15:44     INFO -     runTests@dom/html/test/test_bug1785739.html:42:9
[task 2022-08-19T19:15:44.069Z] 19:15:44     INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-08-19T19:15:44.069Z] 19:15:44     INFO - TEST-UNEXPECTED-FAIL | dom/html/test/test_bug1785739.html | undefined assertion name - got 20, expected 134
[task 2022-08-19T19:15:44.069Z] 19:15:44     INFO -     SimpleTest.is@SimpleTest/SimpleTest.js:497:14
[task 2022-08-19T19:15:44.069Z] 19:15:44     INFO -     runTests@dom/html/test/test_bug1785739.html:42:9
[task 2022-08-19T19:15:44.070Z] 19:15:44     INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-08-19T19:15:44.070Z] 19:15:44     INFO - TEST-UNEXPECTED-FAIL | dom/html/test/test_bug1785739.html | undefined assertion name - got 39, expected 153
[task 2022-08-19T19:15:44.070Z] 19:15:44     INFO -     SimpleTest.is@SimpleTest/SimpleTest.js:497:14
[task 2022-08-19T19:15:44.070Z] 19:15:44     INFO -     runTests@dom/html/test/test_bug1785739.html:42:9
[task 2022-08-19T19:15:44.071Z] 19:15:44     INFO - GECKO(1861) | MEMORY STAT vsizeMaxContiguous not supported in this build configuration.
[task 2022-08-19T19:15:44.071Z] 19:15:44     INFO - GECKO(1861) | MEMORY STAT | vsize 6562MB | residentFast 63MB | heapAllocated 7MB
[task 2022-08-19T19:15:44.072Z] 19:15:44     INFO - TEST-OK | dom/html/test/test_bug1785739.html | took 2505ms
[task 2022-08-19T19:15:44.072Z] 19:15:44     INFO - TEST-START | Shutdown
[task 2022-08-19T19:15:44.073Z] 19:15:44     INFO - Passed:  6
[task 2022-08-19T19:15:44.073Z] 19:15:44     INFO - Failed:  3
[task 2022-08-19T19:15:44.073Z] 19:15:44     INFO - Todo:    0
[task 2022-08-19T19:15:44.074Z] 19:15:44     INFO - Mode:    e10s
[task 2022-08-19T19:15:44.074Z] 19:15:44     INFO - Slowest: 2505ms - /tests/dom/html/test/test_bug1785739.html
[task 2022-08-19T19:15:44.074Z] 19:15:44     INFO - SimpleTest FINISHED
[task 2022-08-19T19:15:44.075Z] 19:15:44     INFO - TEST-INFO | Ran 1 Loops
[task 2022-08-19T19:15:44.075Z] 19:15:44     INFO - SimpleTest FINISHED
[task 2022-08-19T19:15:44.087Z] 19:15:44     INFO - GECKO(1861) | Exiting due to channel error.
[task 2022-08-19T19:15:44.088Z] 19:15:44     INFO - GECKO(1861) | Exiting due to channel error.
[task 2022-08-19T19:15:44.088Z] 19:15:44     INFO - GECKO(1861) | Exiting due to channel error.
[task 2022-08-19T19:15:44.089Z] 19:15:44     INFO - GECKO(1861) | Exiting due to channel error.
[task 2022-08-19T19:15:44.089Z] 19:15:44     INFO - GECKO(1861) | Exiting due to channel error.
[task 2022-08-19T19:15:44.090Z] 19:15:44     INFO - GECKO(1861) | Exiting due to channel error.
[task 2022-08-19T19:15:44.090Z] 19:15:44     INFO - GECKO(1861) | Exiting due to channel error.
[task 2022-08-19T19:15:44.186Z] 19:15:44     INFO - TEST-INFO | Main app process: exit 0

:saschanaz, since you are the author of the regressor, bug 1785739, could you take a look?
For more information, please visit auto_nag documentation.

Flags: needinfo?(krosylight)

Weird, let's see this happens again...

Flags: needinfo?(krosylight)

(In reply to Kagami :saschanaz from comment #2)

Weird, let's see this happens again...

Note that the failure here was in a TV (test-verify) task, which only gets triggered when a test is added/changed. And it seems the failure happened during the chaos-mode part of the run.

So: depending on how chaotic/unlikely the chaos-mode-imposed conditions were here, it's entirely possible that this issue will only ever happen in Test-Verify mode (i.e. only when the test is updated).

So: if this doesn't seem to happen again, that may be simply because it's only likely to repro during this one particular test-verify task. (And we may hit this failure again when someone makes a trivial edit to the test in the future which kicks off another round of TV tasks.)

FWIW: out of curiosity, I queued up a bunch of retriggers of the TV runs on the treeherder push in question, and the failure did indeed persist, though not every time. Seems to happen in about 15-25% of TV runs of the time on macOS right now, and I could get it to fail at all on any other platforms.

Link: https://treeherder.mozilla.org/jobs?repo=autoland&selectedTaskRun=ZMHxqG_FR72-lj_NFHyxeg.0&revision=9f31ced1b433480f1a561e08c3651a025bce2ca1&searchStr=test-verify

Currently:
OS X 10.15 WebRender opt: 7 of 37 TV tasks are orange with this issue
OS X 10.15 WebRender debug: 8 of 30 TV tasks are orange with this issue

Hmm. I guess it's probably just an existing thing though.

Depends on: 1786170

(In reply to Kagami :saschanaz from comment #5)

Hmm. I guess it's probably just an existing thing though.

Agreed, probably not a test bug or a bug in your fix; just a bug that your test is unlucky enough to be tripping over.

I morphed the test into one that quite-reliably reproduces the issue (I think it's the same issue), over in bug 1786170. Hopefully, fixing that bug will address this as well.

Assignee: nobody → dholbert
Status: NEW → ASSIGNED

This helps avoid intermittent test failures that otherwise might happen if a
"font-info-updated" notification arrives partway through a test and causes an
unexpected restyle & reframe.

(In reply to Daniel Holbert [:dholbert] from comment #6)

I morphed the test into one that quite-reliably reproduces the issue (I think it's the same issue), over in bug 1786170. Hopefully, fixing that bug will address this as well.

(I had spun that off with the intent that my morphed test would want to land as well, to exercise/test this issue in a more-targeted/reliable way, but given the diagnosis/discussion in bug 1786170 comment 5 - 11, I don't think that's worth doing after all.)

Pushed by dholbert@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/3cf88b8fe920
Run the font-loader task eagerly for dom/html mochitests. r=jfkthame

https://hg.mozilla.org/mozilla-central/rev/3cf88b8fe920

Status: ASSIGNED → RESOLVED
Closed: 2 years ago
status-firefox105: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → 105 Branch

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

status-firefox104: --- → unaffected
status-firefox-esr102: --- → unaffected
status-firefox-esr91: --- → unaffected
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: