Closed Bug 1629490 Opened 5 years ago Closed 5 years ago

Intermittent layout/reftests/image/img-invalidation-local-transform-1.html == layout/reftests/image/img-invalidation-local-transform-1-ref.html | load failed: timed out after 13 ms waiting for 'load' event for undefined

Categories

(Core :: Layout: Images, Video, and HTML Frames, defect, P5)

Product:
Core
Component:
Layout: Images, Video, and HTML Frames
Type:
defect

Tracking

()

Status:
RESOLVED FIXED
Milestone:
mozilla77
Tracking Flags:
Tracking Status
firefox77 --- fixed

People

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

Details

(Keywords: intermittent-failure)

Attachments

(3 files)

Bug 1629490. The composited frame is now invalid for animated images that have finished. r=aosmond
47 bytes, text/x-phabricator-request
Details | Review
Bug 1629490. In RasterImage invalidate if we get a non-empty dirty rect, don't ignore it if mFrameAdvanced is false. r=aosmond
47 bytes, text/x-phabricator-request
Details | Review
Bug 1629490. Add a crashtest and a mochitest. r=aosmond
47 bytes, text/x-phabricator-request
Details | Review

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

[task 2020-04-13T05:58:34.844Z] 05:58:34 INFO - REFTEST TEST-START | layout/reftests/image/img-invalidation-local-transform-1.html == layout/reftests/image/img-invalidation-local-transform-1-ref.html
[task 2020-04-13T05:58:34.844Z] 05:58:34 INFO - REFTEST TEST-LOAD | file:///Z:/task_1586757060/build/tests/reftest/tests/layout/reftests/image/img-invalidation-local-transform-1.html | 0 / 1 (0%)
[task 2020-04-13T06:01:28.900Z] 06:01:28 INFO - [Parent 11232, Main Thread] WARNING: Suboptimal indexes for the SQL statement 0x26da9bdb5e0 (http://mzl.la/1FuID0j).: file /builds/worker/checkouts/gecko/storage/mozStoragePrivateHelpers.cpp, line 106
[task 2020-04-13T06:03:34.862Z] 06:03:34 INFO - REFTEST TEST-UNEXPECTED-FAIL | layout/reftests/image/img-invalidation-local-transform-1.html == layout/reftests/image/img-invalidation-local-transform-1-ref.html | load failed: timed out after 13 ms waiting for 'load' event for undefined
[task 2020-04-13T06:03:34.862Z] 06:03:34 INFO - REFTEST INFO | Saved log: START file:///Z:/task_1586757060/build/tests/reftest/tests/layout/reftests/image/img-invalidation-local-transform-1.html
[task 2020-04-13T06:03:34.862Z] 06:03:34 INFO - REFTEST INFO | Saved log: [CONTENT] OnDocumentLoad triggering WaitForTestEnd
[task 2020-04-13T06:03:34.862Z] 06:03:34 INFO - REFTEST INFO | Saved log: [CONTENT] WaitForTestEnd: Adding listeners
[task 2020-04-13T06:03:34.864Z] 06:03:34 INFO - REFTEST INFO | Saved log: [CONTENT] AfterPaintListener in file:///Z:/task_1586757060/build/tests/reftest/tests/layout/reftests/image/img-invalidation-local-transform-1.html
[task 2020-04-13T06:03:34.865Z] 06:03:34 INFO - REFTEST INFO | Saved log: [CONTENT] AfterPaintListener in file:///Z:/task_1586757060/build/tests/reftest/tests/layout/reftests/image/img-invalidation-local-transform-1.html
[task 2020-04-13T06:03:34.865Z] 06:03:34 INFO - REFTEST INFO | Saved log: Initializing canvas snapshot
[task 2020-04-13T06:03:34.867Z] 06:03:34 INFO - REFTEST INFO | Saved log: DoDrawWindow 0,0,800,1000
[task 2020-04-13T06:03:34.867Z] 06:03:34 INFO - REFTEST INFO | Saved log: [CONTENT] MakeProgress
[task 2020-04-13T06:03:34.869Z] 06:03:34 INFO - REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_TO_FIRE_INVALIDATE_EVENT
[task 2020-04-13T06:03:34.870Z] 06:03:34 INFO - REFTEST INFO | Saved log: [CONTENT] MakeProgress: waiting for updateCanvasPending
[task 2020-04-13T06:03:34.872Z] 06:03:34 INFO - REFTEST INFO | Saved log: [CONTENT] HandlePendingTasksAfterMakeProgress updating canvas
[task 2020-04-13T06:03:34.873Z] 06:03:34 INFO - REFTEST INFO | Saved log: [CONTENT] SendUpdateCanvasForEvent with 1 rects
[task 2020-04-13T06:03:34.874Z] 06:03:34 INFO - REFTEST INFO | Saved log: [CONTENT] Rect: 0 0 800 1000
[task 2020-04-13T06:03:34.874Z] 06:03:34 INFO - REFTEST INFO | Saved log: Updating canvas for invalidation
[task 2020-04-13T06:03:34.875Z] 06:03:34 INFO - REFTEST INFO | Saved log: DoDrawWindow 0,0,800,1000
[task 2020-04-13T06:03:34.876Z] 06:03:34 INFO - REFTEST INFO | Saved log: [CONTENT] MakeProgress
[task 2020-04-13T06:03:34.877Z] 06:03:34 INFO - REFTEST INFO | Saved log: [CONTENT] AfterPaintListener in file:///Z:/task_1586757060/build/tests/reftest/tests/layout/reftests/image/img-invalidation-local-transform-1.html
[task 2020-04-13T06:03:34.877Z] 06:03:34 INFO - REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_TO_FIRE_INVALIDATE_EVENT
[task 2020-04-13T06:03:34.877Z] 06:03:34 INFO - REFTEST INFO | Saved log: [CONTENT] MakeProgress: waiting for updateCanvasPending
[task 2020-04-13T06:03:34.877Z] 06:03:34 INFO - REFTEST INFO | Saved log: [CONTENT] HandlePendingTasksAfterMakeProgress updating canvas
[task 2020-04-13T06:03:34.878Z] 06:03:34 INFO - REFTEST INFO | Saved log: [CONTENT] SendUpdateCanvasForEvent with 1 rects
[task 2020-04-13T06:03:34.878Z] 06:03:34 INFO - REFTEST INFO | Saved log: [CONTENT] Rect: 8 8 458 290
[task 2020-04-13T06:03:34.878Z] 06:03:34 INFO - REFTEST INFO | Saved log: Updating canvas for invalidation
[task 2020-04-13T06:03:34.878Z] 06:03:34 INFO - REFTEST INFO | Saved log: DoDrawWindow 8,8,450,282
[task 2020-04-13T06:03:34.879Z] 06:03:34 INFO - REFTEST INFO | Saved log: [CONTENT] MakeProgress
[task 2020-04-13T06:03:34.879Z] 06:03:34 INFO - REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_TO_FIRE_INVALIDATE_EVENT
[task 2020-04-13T06:03:34.879Z] 06:03:34 INFO - REFTEST INFO | Saved log: [CONTENT] MakeProgress: dispatching MozReftestInvalidate
[task 2020-04-13T06:03:34.880Z] 06:03:34 INFO - REFTEST INFO | Saved log: [CONTENT] MakeProgress
[task 2020-04-13T06:03:34.880Z] 06:03:34 INFO - REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_FOR_REFTEST_WAIT_REMOVAL
[task 2020-04-13T06:03:34.880Z] 06:03:34 INFO - REFTEST INFO | Saved log: [CONTENT] MakeProgress: waiting for reftest-wait to be removed
[task 2020-04-13T06:03:34.880Z] 06:03:34 INFO - REFTEST TEST-END | layout/reftests/image/img-invalidation-local-transform-1.html == layout/reftests/image/img-invalidation-local-transform-1-ref.html

This happened during a test-verify run because this is a newly added test. Looks like the img.decode() promise never fulfilled. Not sure why that would happen. I would be interested to know. We'll see if we get intermittents in this test.

This is actually a one line change. The rest is just removing unneeded parameters.

The composited frame used to be valid for animations that had finished because we saved a separate composited frame, and since the animation had finished it was the final frame, so it had to be valid to display.

Now we don't have a separate composited frame so we only have a valid frame to display if we've decoded up to the current frame. For non-finished animations RequestRefresh will clear mCompositedFrameInvalid, but for finished animations we have to clear it, the easiest place is when we know we are fully decoded.

This problem caused img.decode to never fulfill or reject because we never sent out any frame update notifications because mCompositedFrameInvalid was always false because mAnimationFinished was always true. So we didn't get the invalidation that flipping mCompositedFrameInvalid to false when a full decode finished would cause.

Assignee: nobody → tnikkel
Status: NEW → ASSIGNED
Attachment #9140392 - Attachment description: Bug 1629490. The composited frame is now invalid for animated images that have finished. r?aosmond → Bug 1629490. The composited frame is now invalid for animated images that have finished. r=aosmond

We invalidate for more things than just frames advancing (if we are redecoding and still showing the same frame as before discarding for example). So there is no reason that the dirty rect and a frame being advanced should be linked.

Depends on D70838

The mochitest caught the issue of the second patch here so there is value in both it seems.

Depends on D71483

Attachment #9141571 - Attachment description: Bug 1629490. In RasterImage invalidate if we get a non-empty dirty rect, don't ignore it if mFrameAdvanced is false. r?aosmond → Bug 1629490. In RasterImage invalidate if we get a non-empty dirty rect, don't ignore it if mFrameAdvanced is false. r=aosmond
Attachment #9141572 - Attachment description: Bug 1629490. Add a crashtest and a mochitest. r?aosmond → Bug 1629490. Add a crashtest and a mochitest. r=aosmond
Pushed by tnikkel@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/ba69034f5207 The composited frame is now invalid for animated images that have finished. r=aosmond https://hg.mozilla.org/integration/autoland/rev/f997fe14a6a5 In RasterImage invalidate if we get a non-empty dirty rect, don't ignore it if mFrameAdvanced is false. r=aosmond https://hg.mozilla.org/integration/autoland/rev/de2ced51599d Add a crashtest and a mochitest. r=aosmond

Backed out 3 changesets (Bug 1629490) fo causing reftest failures at layout/reftests/image/img-invalidation-local-transform-1.html

Push with failure: https://treeherder.mozilla.org/#/jobs?repo=autoland&selectedJob=298324710&resultStatus=testfailed%2Cbusted%2Cexception&classifiedState=unclassified&revision=de2ced51599d93dd91870579e2c78a14b77b4f7d

Failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=298324964&repo=autoland&lineNumber=31198

Backout link: https://treeherder.mozilla.org/#/jobs?repo=autoland&resultStatus=testfailed%2Cbusted%2Cexception&classifiedState=unclassified&revision=c51636a76ead5b77d75d51d661c8c86b056bc46b

[task 2020-04-20T02:56:45.849Z] 02:56:45     INFO - REFTEST TEST-START | layout/reftests/image/img-invalidation-local-transform-1.html == layout/reftests/image/img-invalidation-local-transform-1-ref.html
[task 2020-04-20T02:56:45.850Z] 02:56:45     INFO - REFTEST TEST-LOAD | file:///Users/cltbld/tasks/task_1587342389/build/tests/reftest/tests/layout/reftests/image/img-invalidation-local-transform-1.html | 54 / 55 (98%)
[task 2020-04-20T02:56:45.891Z] 02:56:45     INFO - JavaScript error: , line 0: EncodingError: Invalid encoded image data.
[task 2020-04-20T02:56:53.024Z] 02:56:53     INFO - 2020-04-20 02:56:52.982 firefox[3563:49630] Persistent UI failed to open file file:///Users/cltbld/Library/Saved%20Application%20State/org.mozilla.nightlydebug.savedState/window_1.data: No such file or directory (2)
[task 2020-04-20T02:59:26.541Z] 02:59:26     INFO - console.log: *** PurgeTrackerService:: "Purging trackers enabled, beginning batch."
[task 2020-04-20T02:59:26.561Z] 02:59:26     INFO - console.log: *** PurgeTrackerService:: "All cookie purging finished, resetting list until tomorrow."
[task 2020-04-20T02:59:26.653Z] 02:59:26     INFO - [Parent 3563, Main Thread] WARNING: Suboptimal indexes for the SQL statement 0x130b5f7b0 (http://mzl.la/1FuID0j).: file /builds/worker/checkouts/gecko/storage/mozStoragePrivateHelpers.cpp, line 106
[task 2020-04-20T03:01:46.015Z] 03:01:46     INFO - REFTEST TEST-UNEXPECTED-FAIL | layout/reftests/image/img-invalidation-local-transform-1.html == layout/reftests/image/img-invalidation-local-transform-1-ref.html | load failed: timed out waiting for reftest-wait to be removed
[task 2020-04-20T03:01:46.015Z] 03:01:46     INFO - REFTEST INFO | Saved log: START file:///Users/cltbld/tasks/task_1587342389/build/tests/reftest/tests/layout/reftests/image/img-invalidation-local-transform-1.html
[task 2020-04-20T03:01:46.015Z] 03:01:46     INFO - REFTEST INFO | Saved log: [CONTENT] OnDocumentLoad triggering WaitForTestEnd
[task 2020-04-20T03:01:46.016Z] 03:01:46     INFO - REFTEST INFO | Saved log: [CONTENT] WaitForTestEnd: Adding listeners
[task 2020-04-20T03:01:46.016Z] 03:01:46     INFO - REFTEST INFO | Saved log: Initializing canvas snapshot
[task 2020-04-20T03:01:46.016Z] 03:01:46     INFO - REFTEST INFO | Saved log: DoDrawWindow 0,0,800,1000
[task 2020-04-20T03:01:46.016Z] 03:01:46     INFO - REFTEST INFO | Saved log: [CONTENT] MakeProgress
[task 2020-04-20T03:01:46.016Z] 03:01:46     INFO - REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_TO_FIRE_INVALIDATE_EVENT
[task 2020-04-20T03:01:46.023Z] 03:01:46     INFO - REFTEST INFO | Saved log: [CONTENT] MakeProgress: waiting for MozAfterPaint
[task 2020-04-20T03:01:46.023Z] 03:01:46     INFO - REFTEST INFO | Saved log: [CONTENT] HandlePendingTasksAfterMakeProgress waiting for a MozAfterPaint
[task 2020-04-20T03:01:46.023Z] 03:01:46     INFO - REFTEST INFO | Saved log: [CONTENT] AfterPaintListener in file:///Users/cltbld/tasks/task_1587342389/build/tests/reftest/tests/layout/reftests/image/img-invalidation-local-transform-1.html
[task 2020-04-20T03:01:46.023Z] 03:01:46     INFO - REFTEST INFO | Saved log: [CONTENT] HandlePendingTasksAfterMakeProgress updating canvas
[task 2020-04-20T03:01:46.023Z] 03:01:46     INFO - REFTEST INFO | Saved log: [CONTENT] SendUpdateCanvasForEvent with 1 rects
[task 2020-04-20T03:01:46.023Z] 03:01:46     INFO - REFTEST INFO | Saved log: [CONTENT] Rect: 0 0 800 1000
[task 2020-04-20T03:01:46.023Z] 03:01:46     INFO - REFTEST INFO | Saved log: Updating canvas for invalidation
[task 2020-04-20T03:01:46.024Z] 03:01:46     INFO - REFTEST INFO | Saved log: DoDrawWindow 0,0,800,1000
[task 2020-04-20T03:01:46.024Z] 03:01:46     INFO - REFTEST INFO | Saved log: [CONTENT] MakeProgress
[task 2020-04-20T03:01:46.024Z] 03:01:46     INFO - REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_TO_FIRE_INVALIDATE_EVENT
[task 2020-04-20T03:01:46.024Z] 03:01:46     INFO - REFTEST INFO | Saved log: [CONTENT] MakeProgress: dispatching MozReftestInvalidate
[task 2020-04-20T03:01:46.024Z] 03:01:46     INFO - REFTEST INFO | Saved log: [CONTENT] MakeProgress
[task 2020-04-20T03:01:46.024Z] 03:01:46     INFO - REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_FOR_REFTEST_WAIT_REMOVAL
[task 2020-04-20T03:01:46.024Z] 03:01:46     INFO - REFTEST INFO | Saved log: [CONTENT] MakeProgress: waiting for reftest-wait to be removed
Flags: needinfo?(tnikkel)

phab or something after my tree but before landing on autoland messed up my changeset.

hg export of the changeset in my tree:

diff --git a/layout/reftests/image/img-invalidation-local-transform-1.png b/image/test/crashtests/finite-apng.png
copy from layout/reftests/image/img-invalidation-local-transform-1.png
copy to image/test/crashtests/finite-apng.png
diff --git a/layout/reftests/image/img-invalidation-local-transform-1.png b/image/test/mochitest/finite-apng.png
copy from layout/reftests/image/img-invalidation-local-transform-1.png
copy to image/test/mochitest/finite-apng.png

So it makes two new copies of layout/reftests/image/img-invalidation-local-transform-1.png elsewhere in the tree.

From https://hg.mozilla.org/integration/autoland/rev/de2ced51599d:

rename from layout/reftests/image/img-invalidation-local-transform-1.png
rename to image/test/crashtests/finite-apng.png

copy from layout/reftests/image/img-invalidation-local-transform-1.png
copy to image/test/mochitest/finite-apng.png

Which deletes the original. :( I'll change my changeset locally to avoid this bug and reland and file a phab (?) bug.

Flags: needinfo?(tnikkel)

Filed a phab bug -> bug 1631315.

Pushed by tnikkel@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/280cbd358ca2 The composited frame is now invalid for animated images that have finished. r=aosmond https://hg.mozilla.org/integration/autoland/rev/619ab802a11e In RasterImage invalidate if we get a non-empty dirty rect, don't ignore it if mFrameAdvanced is false. r=aosmond https://hg.mozilla.org/integration/autoland/rev/086730671504 Add a crashtest and a mochitest. r=aosmond

https://hg.mozilla.org/mozilla-central/rev/280cbd358ca2
https://hg.mozilla.org/mozilla-central/rev/619ab802a11e
https://hg.mozilla.org/mozilla-central/rev/086730671504

Status: ASSIGNED → RESOLVED
Closed: 5 years ago
status-firefox77: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → mozilla77
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: