Closed Bug 1715642 Opened 3 years ago Closed 3 years ago

reftest-snapshot | Jobs are sensitive to going blue / retries / rarely finishing after switching to QR

Tracking

()

Status:

RESOLVED DUPLICATE of bug 1710321

People

(Reporter: aosmond, Unassigned)

References

(Blocks 1 open bug)

Details

Attachments

(1 file)

Rs1 log which went blue.zip 3 years ago Andrew Osmond [:aosmond] (he/him) (deleted), application/zip		Details

Andrew Osmond [:aosmond] (he/him)

Reporter

Description

•

3 years ago

Typically reftest-snapshot Rs1 will hit the need to retry after bug 1696093 landed:

https://treeherder.mozilla.org/jobs?repo=try&revision=d95c0dc6f4199f538c0270753864d6da221117d8

Skipping the tests does not appear to help:

https://treeherder.mozilla.org/jobs?repo=try&revision=0c232439be792f8b29aab5d6365da6e475d01ac3

This was demonstrated by bisecting and pushing to try. It was always green before the patch landed, and almost always blue after (and would show intermittents otherwise not seen before it the rare cases the test finished).

Andrew Osmond [:aosmond] (he/him)

Reporter

Comment 1

•

3 years ago

This turns out not to be AVIFs fault. It added new reftests which changed the batching order.

No longer regressed by: 1696093

Summary: reftest-snapshot | AVIF transform reftests cause qr Rs1 job to require retries / go blue in CI → reftest-snapshot | Jobs are sensitive to going blue / retries / rarely finishing

Andrew Osmond [:aosmond] (he/him)

Reporter

Comment 2

•

3 years ago

Attached file Rs1 log which went blue.zip (deleted) — Details

I was not getting logs most of the time, but I managed to grab this one mid test and collect it. This shows a test just looping forever until the job gives up, specifically layout/reftests/transform/partial-prerender-expansion-with-resolution-1.html:

[task 2021-06-09T22:58:31.398Z] 22:58:31     INFO - REFTEST TEST-START | layout/reftests/transform/partial-prerender-expansion-with-resolution-1.html == layout/reftests/transform/partial-prerender-expansion-with-resolution-ref.html
[task 2021-06-09T22:58:31.405Z] 22:58:31     INFO - [Child 2177, Main Thread] WARNING: Shouldn't call SchedulePaint in a detached pres context: file /builds/worker/checkouts/gecko/layout/generic/nsIFrame.cpp:7168
[task 2021-06-09T22:58:31.410Z] 22:58:31     INFO - [Child 2177, Main Thread] WARNING: Shouldn't call SchedulePaint in a detached pres context: file /builds/worker/checkouts/gecko/layout/generic/nsIFrame.cpp:7168
[task 2021-06-09T22:58:31.410Z] 22:58:31     INFO - [Child 2177, Main Thread] WARNING: Shouldn't call SchedulePaint in a detached pres context: file /builds/worker/checkouts/gecko/layout/generic/nsIFrame.cpp:7168
[task 2021-06-09T22:58:31.416Z] 22:58:31     INFO - [Child 2177, Main Thread] WARNING: Shouldn't call SchedulePaint in a detached pres context: file /builds/worker/checkouts/gecko/layout/generic/nsIFrame.cpp:7168
[task 2021-06-09T22:58:31.417Z] 22:58:31     INFO - [Child 2177, Main Thread] WARNING: Shouldn't call SchedulePaint in a detached pres context: file /builds/worker/checkouts/gecko/layout/generic/nsIFrame.cpp:7168
[task 2021-06-09T22:58:31.418Z] 22:58:31     INFO - [Child 2177, Main Thread] WARNING: Shouldn't call SchedulePaint in a detached pres context: file /builds/worker/checkouts/gecko/layout/generic/nsIFrame.cpp:7168
[task 2021-06-09T22:58:31.418Z] 22:58:31     INFO - REFTEST INFO | SET PREFERENCE pref(dom.meta-viewport.enabled,true)
[task 2021-06-09T22:58:31.419Z] 22:58:31     INFO - REFTEST TEST-LOAD | file:///builds/worker/workspace/build/tests/reftest/tests/layout/reftests/transform/partial-prerender-expansion-with-resolution-1.html | 134 / 139 (96%)
[task 2021-06-09T22:58:31.432Z] 22:58:31     INFO - [Child 2177, Main Thread] WARNING: early callback, or time went backwards: '!aAllowIdleDispatch', file /builds/worker/checkouts/gecko/xpcom/threads/IdleTaskRunner.cpp:179
[task 2021-06-09T22:58:31.525Z] 22:58:31     INFO - [Child 2177, Main Thread] WARNING: early callback, or time went backwards: '!aAllowIdleDispatch', file /builds/worker/checkouts/gecko/xpcom/threads/IdleTaskRunner.cpp:179
[task 2021-06-09T22:58:31.542Z] 22:58:31     INFO - [Child 2177, Main Thread] WARNING: early callback, or time went backwards: '!aAllowIdleDispatch', file /builds/worker/checkouts/gecko/xpcom/threads/IdleTaskRunner.cpp:179
[task 2021-06-09T23:01:25.688Z] 23:01:25     INFO - REFTEST INFO | RESTORE PREFERENCE pref(dom.meta-viewport.enabled,false)
[task 2021-06-09T23:01:29.736Z] 23:01:29     INFO - REFTEST INFO | SET PREFERENCE pref(dom.meta-viewport.enabled,true)
[task 2021-06-09T23:01:30.873Z] 23:01:30     INFO - REFTEST TEST-LOAD | file:///builds/worker/workspace/build/tests/reftest/tests/layout/reftests/transform/partial-prerender-expansion-with-resolution-ref.html | 134 / 139 (96%)
[task 2021-06-09T23:01:37.047Z] 23:01:36     INFO - [Child 2177, Main Thread] WARNING: Shouldn't call SchedulePaint in a detached pres context: file /builds/worker/checkouts/gecko/layout/generic/nsIFrame.cpp:7168
[task 2021-06-09T23:01:38.197Z] 23:01:37     INFO - [Child 2177, Main Thread] WARNING: Shouldn't call SchedulePaint in a detached pres context: file /builds/worker/checkouts/gecko/layout/generic/nsIFrame.cpp:7168
[task 2021-06-09T23:01:40.094Z] 23:01:39     INFO - [Child 2177, Main Thread] WARNING: Shouldn't call SchedulePaint in a detached pres context: file /builds/worker/checkouts/gecko/layout/generic/nsIFrame.cpp:7168
[task 2021-06-09T23:01:43.609Z] 23:01:43     INFO - [Child 2177, Main Thread] WARNING: Shouldn't call SchedulePaint in a detached pres context: file /builds/worker/checkouts/gecko/layout/generic/nsIFrame.cpp:7168
[task 2021-06-09T23:02:07.036Z] 23:02:06     INFO - [Child 2177, Main Thread] WARNING: Shouldn't call SchedulePaint in a detached pres context: file /builds/worker/checkouts/gecko/layout/generic/nsIFrame.cpp:7168
[task 2021-06-09T23:02:08.481Z] 23:02:08     INFO - [Child 2177, Main Thread] WARNING: Shouldn't call SchedulePaint in a detached pres context: file /builds/worker/checkouts/gecko/layout/generic/nsIFrame.cpp:7168
[task 2021-06-09T23:02:09.333Z] 23:02:09     INFO - [Child 2177, Main Thread] WARNING: Shouldn't call SchedulePaint in a detached pres context: file /builds/worker/checkouts/gecko/layout/generic/nsIFrame.cpp:7168
[task 2021-06-09T23:06:40.152Z] 23:06:39     INFO - console.error: (new Error("Transaction timeout, most likely caused by unresolved pending work.", "resource://gre/modules/Sqlite.jsm", 966))
[task 2021-06-09T23:06:45.412Z] 23:06:45     INFO - console.error: "Unexpected transaction in progress when trying to start a new one."
[task 2021-06-09T23:07:53.451Z] 23:07:53     INFO - REFTEST TEST-UNEXPECTED-FAIL | layout/reftests/transform/partial-prerender-expansion-with-resolution-1.html == layout/reftests/transform/partial-prerender-expansion-with-resolution-ref.html | load failed: timed out waiting for test to complete (waiting for onload scripts to complete)
[task 2021-06-09T23:07:53.884Z] 23:07:53     INFO - REFTEST INFO | Saved log: START file:///builds/worker/workspace/build/tests/reftest/tests/layout/reftests/transform/partial-prerender-expansion-with-resolution-1.html
[task 2021-06-09T23:07:54.155Z] 23:07:54     INFO - REFTEST INFO | Saved log: [CONTENT] Setting resolution to 0.5
[task 2021-06-09T23:07:54.543Z] 23:07:54     INFO - REFTEST INFO | Saved log: [CONTENT] OnDocumentLoad triggering WaitForTestEnd
[task 2021-06-09T23:07:54.581Z] 23:07:54     INFO - REFTEST INFO | Saved log: [CONTENT] WaitForTestEnd: Adding listeners
[task 2021-06-09T23:07:55.107Z] 23:07:54     INFO - REFTEST INFO | Saved log: Initializing canvas snapshot
[task 2021-06-09T23:07:55.501Z] 23:07:55     INFO - REFTEST INFO | Saved log: [CONTENT] MakeProgress
[task 2021-06-09T23:07:55.549Z] 23:07:55     INFO - REFTEST INFO | Saved log: [CONTENT] AfterPaintListener in file:///builds/worker/workspace/build/tests/reftest/tests/layout/reftests/transform/partial-prerender-expansion-with-resolution-1.html
[task 2021-06-09T23:07:55.549Z] 23:07:55     INFO - REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_TO_FIRE_INVALIDATE_EVENT
[task 2021-06-09T23:07:55.549Z] 23:07:55     INFO - REFTEST INFO | Saved log: [CONTENT] MakeProgress: waiting for updateCanvasPending
[task 2021-06-09T23:07:56.329Z] 23:07:56     INFO - REFTEST INFO | Saved log: [CONTENT] HandlePendingTasksAfterMakeProgress updating canvas
[task 2021-06-09T23:07:56.636Z] 23:07:56     INFO - REFTEST INFO | Saved log: [CONTENT] Webrender enabled, sending update whole canvas for invalidation
[task 2021-06-09T23:07:56.963Z] 23:07:56     INFO - REFTEST INFO | Saved log: [CONTENT] Test file chose to skip SynchronizeForSnapshot
[task 2021-06-09T23:07:57.066Z] 23:07:57     INFO - REFTEST INFO | Saved log: Updating entire canvas for invalidation
[task 2021-06-09T23:07:57.066Z] 23:07:57     INFO - REFTEST INFO | Saved log: [CONTENT] MakeProgress
[task 2021-06-09T23:07:57.066Z] 23:07:57     INFO - REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_TO_FIRE_INVALIDATE_EVENT
[task 2021-06-09T23:07:57.067Z] 23:07:57     INFO - REFTEST INFO | Saved log: [CONTENT] MakeProgress: dispatching MozReftestInvalidate
[task 2021-06-09T23:07:57.067Z] 23:07:57     INFO - REFTEST INFO | Saved log: [CONTENT] MakeProgress
[task 2021-06-09T23:07:57.078Z] 23:07:57     INFO - REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_FOR_REFTEST_WAIT_REMOVAL
[task 2021-06-09T23:07:57.078Z] 23:07:57     INFO - REFTEST INFO | Saved log: [CONTENT] MakeProgress: waiting for reftest-wait to be removed
[task 2021-06-09T23:07:57.078Z] 23:07:57     INFO - REFTEST INFO | Saved log: [CONTENT] AfterPaintListener in file:///builds/worker/workspace/build/tests/reftest/tests/layout/reftests/transform/partial-prerender-expansion-with-resolution-1.html
[task 2021-06-09T23:07:57.078Z] 23:07:57     INFO - REFTEST INFO | Saved log: [CONTENT] HandlePendingTasksAfterMakeProgress updating canvas
[task 2021-06-09T23:07:57.079Z] 23:07:57     INFO - REFTEST INFO | Saved log: [CONTENT] Webrender enabled, sending update whole canvas for invalidation
[task 2021-06-09T23:07:57.079Z] 23:07:57     INFO - REFTEST INFO | Saved log: [CONTENT] Test file chose to skip SynchronizeForSnapshot
[task 2021-06-09T23:07:57.080Z] 23:07:57     INFO - REFTEST INFO | Saved log: Updating entire canvas for invalidation
[task 2021-06-09T23:07:57.080Z] 23:07:57     INFO - REFTEST INFO | Saved log: [CONTENT] MakeProgress
[task 2021-06-09T23:07:57.080Z] 23:07:57     INFO - REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_FOR_REFTEST_WAIT_REMOVAL
[task 2021-06-09T23:07:57.080Z] 23:07:57     INFO - REFTEST INFO | Saved log: [CONTENT] MakeProgress: waiting for reftest-wait to be removed
[task 2021-06-09T23:07:57.080Z] 23:07:57     INFO - REFTEST INFO | Saved log: [CONTENT] AttrModifiedListener fired
[task 2021-06-09T23:07:57.080Z] 23:07:57     INFO - REFTEST INFO | Saved log: [CONTENT] MakeProgress
[task 2021-06-09T23:07:57.080Z] 23:07:57     INFO - REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_FOR_REFTEST_WAIT_REMOVAL
[task 2021-06-09T23:07:57.080Z] 23:07:57     INFO - REFTEST INFO | Saved log: [CONTENT] MakeProgress
[task 2021-06-09T23:07:57.080Z] 23:07:57     INFO - REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_FOR_SPELL_CHECKS
[task 2021-06-09T23:07:57.081Z] 23:07:57     INFO - REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_FOR_APZ_FLUSH
[task 2021-06-09T23:07:57.081Z] 23:07:57     INFO - REFTEST INFO | Saved log: [CONTENT] MakeProgress: APZ flush not required

[task 2021-06-09T23:07:59.786Z] 23:07:59     INFO - REFTEST INFO | Saved log: [CONTENT] AfterPaintListener in file:///builds/worker/workspace/build/tests/reftest/tests/layout/reftests/transform/partial-prerender-expansion-with-resolution-1.html
[task 2021-06-09T23:07:59.786Z] 23:07:59     INFO - REFTEST INFO | Saved log: [CONTENT] HandlePendingTasksAfterMakeProgress updating canvas
[task 2021-06-09T23:07:59.787Z] 23:07:59     INFO - REFTEST INFO | Saved log: [CONTENT] Webrender enabled, sending update whole canvas for invalidation
[task 2021-06-09T23:07:59.787Z] 23:07:59     INFO - REFTEST INFO | Saved log: [CONTENT] Test file chose to skip SynchronizeForSnapshot
[task 2021-06-09T23:07:59.787Z] 23:07:59     INFO - REFTEST INFO | Saved log: Updating entire canvas for invalidation
[task 2021-06-09T23:07:59.787Z] 23:07:59     INFO - REFTEST INFO | Saved log: [CONTENT] MakeProgress
[task 2021-06-09T23:07:59.788Z] 23:07:59     INFO - REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_TO_FINISH
[task 2021-06-09T23:07:59.788Z] 23:07:59     INFO - REFTEST INFO | Saved log: [CONTENT] MakeProgress: waiting for MozAfterPaint
[task 2021-06-09T23:07:59.788Z] 23:07:59     INFO - REFTEST INFO | Saved log: [CONTENT] HandlePendingTasksAfterMakeProgress waiting for a MozAfterPaint
[task 2021-06-09T23:07:59.789Z] 23:07:59     INFO - REFTEST INFO | Saved log: [CONTENT] AfterPaintListener in file:///builds/worker/workspace/build/tests/reftest/tests/layout/reftests/transform/partial-prerender-expansion-with-resolution-1.html
[task 2021-06-09T23:07:59.789Z] 23:07:59     INFO - REFTEST INFO | Saved log: [CONTENT] HandlePendingTasksAfterMakeProgress updating canvas
[task 2021-06-09T23:07:59.790Z] 23:07:59     INFO - REFTEST INFO | Saved log: [CONTENT] Webrender enabled, sending update whole canvas for invalidation
[task 2021-06-09T23:07:59.800Z] 23:07:59     INFO - REFTEST INFO | Saved log: [CONTENT] Test file chose to skip SynchronizeForSnapshot
[task 2021-06-09T23:07:59.800Z] 23:07:59     INFO - REFTEST INFO | Saved log: Updating entire canvas for invalidation
[task 2021-06-09T23:07:59.801Z] 23:07:59     INFO - REFTEST INFO | Saved log: [CONTENT] MakeProgress
[task 2021-06-09T23:07:59.801Z] 23:07:59     INFO - REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_TO_FINISH
[task 2021-06-09T23:07:59.801Z] 23:07:59     INFO - REFTEST INFO | Saved log: [CONTENT] MakeProgress: waiting for MozAfterPaint
[task 2021-06-09T23:07:59.801Z] 23:07:59     INFO - REFTEST INFO | Saved log: [CONTENT] HandlePendingTasksAfterMakeProgress waiting for a MozAfterPaint

Andrew Osmond [:aosmond] (he/him)

Reporter

Comment 3

•

3 years ago

Any thoughts Matt?

Flags: needinfo?(matt.woodrow)

Andrew Osmond [:aosmond] (he/him)

Reporter

Updated

•

3 years ago

Summary: reftest-snapshot | Jobs are sensitive to going blue / retries / rarely finishing → reftest-snapshot | Jobs are sensitive to going blue / retries / rarely finishing after switching to QR

Andrew Osmond [:aosmond] (he/him)

Reporter

Updated

•

3 years ago

Blocks: 1715335

Matt Woodrow (:mattwoodrow)

Comment 4

•

3 years ago

Sounds like might be similar to this issue (which is why this test is disable for WR on Android) - https://bugzilla.mozilla.org/show_bug.cgi?id=1710321#c2

Flags: needinfo?(matt.woodrow)

Andrew Osmond [:aosmond] (he/him)

Reporter

Updated

•

3 years ago

Status: NEW → RESOLVED

Closed: 3 years ago

Resolution: --- → DUPLICATE

You need to log in before you can comment on or make changes to this bug.

Bugzilla

reftest-snapshot | Jobs are sensitive to going blue / retries / rarely finishing after switching to QR

Categories

(Core :: Graphics: WebRender, defect, P3)

Tracking

()

People

(Reporter: aosmond, Unassigned)

References

(Blocks 1 open bug)

Details

Crash Data

Security

(public)

User Story

Attachments

(1 file)

Description

Comment 1

Comment 2

Comment 3

Updated

Updated

Comment 4

Updated

Attachment

General

Description

File Name

Content Type