Closed Bug 1263458 Opened 8 years ago Closed 8 years ago

Intermittent disable-apz-for-sle-pages.html | image comparison (==), max difference: 181, number of differing pixels: 1458

Categories

(Core :: Panning and Zooming, defect, P2)

48 Branch
Unspecified
Windows
defect

Tracking

()

RESOLVED FIXED
mozilla51
Tracking Status
firefox47 --- unaffected
firefox48 --- wontfix
firefox49 --- wontfix
firefox50 --- fixed
firefox51 --- fixed

People

(Reporter: RyanVM, Assigned: kats)

References

Details

(Keywords: intermittent-failure, Whiteboard: [gfx-noted])

Attachments

(3 files, 1 obsolete file)

Attached image test screenshot
Different scrollbar position from the looks of it.

https://treeherder.mozilla.org/logviewer.html#?job_id=163276&repo=ash

REFTEST TEST-START | file:///C:/slave/test/build/tests/reftest/tests/layout/reftests/async-scrolling/disable-apz-for-sle-pages.html
REFTEST INFO | SET PREFERENCE pref(apz.disable_for_scroll_linked_effects,true)
REFTEST TEST-LOAD | file:///C:/slave/test/build/tests/reftest/tests/layout/reftests/async-scrolling/disable-apz-for-sle-pages.html | 1869 / 13494 (13%)
REFTEST INFO | RESTORE PREFERENCE pref(apz.disable_for_scroll_linked_effects,false)
REFTEST INFO | SET PREFERENCE pref(apz.disable_for_scroll_linked_effects,true)
REFTEST TEST-LOAD | file:///C:/slave/test/build/tests/reftest/tests/layout/reftests/async-scrolling/disable-apz-for-sle-pages-ref.html | 1869 / 13494 (13%)
REFTEST TEST-UNEXPECTED-FAIL | file:///C:/slave/test/build/tests/reftest/tests/layout/reftests/async-scrolling/disable-apz-for-sle-pages.html | image comparison (==), max difference: 181, number of differing pixels: 1458
REFTEST   IMAGE 1 (TEST):
REFTEST   IMAGE 2 (REFERENCE):
REFTEST TEST-END | file:///C:/slave/test/build/tests/reftest/tests/layout/reftests/async-scrolling/disable-apz-for-sle-pages.html
REFTEST INFO | Saved log: START file:///C:/slave/test/build/tests/reftest/tests/layout/reftests/async-scrolling/disable-apz-for-sle-pages.html
REFTEST INFO | Saved log: [CONTENT] OnDocumentLoad triggering WaitForTestEnd
REFTEST INFO | Saved log: [CONTENT] WaitForTestEnd: Adding listeners
REFTEST INFO | Saved log: Initializing canvas snapshot
REFTEST INFO | Saved log: DoDrawWindow 0,0,800,1000
REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_TO_FIRE_INVALIDATE_EVENT
REFTEST INFO | Saved log: [CONTENT] MakeProgress: waiting for MozAfterPaint
REFTEST INFO | Saved log: [CONTENT] AttrModifiedListener fired
REFTEST INFO | Saved log: [CONTENT] AfterPaintListener in file:///C:/slave/test/build/tests/reftest/tests/layout/reftests/async-scrolling/disable-apz-for-sle-pages.html
REFTEST INFO | Saved log: [CONTENT] SendUpdateCanvasForEvent with 1 rects
REFTEST INFO | Saved log: [CONTENT] Rect: 0 0 800 1000
REFTEST INFO | Saved log: Updating canvas for invalidation
REFTEST INFO | Saved log: DoDrawWindow 0,0,800,1000
REFTEST INFO | Saved log: [CONTENT] AttrModifiedListener fired
REFTEST INFO | Saved log: [CONTENT] AfterPaintListener in file:///C:/slave/test/build/tests/reftest/tests/layout/reftests/async-scrolling/disable-apz-for-sle-pages.html
REFTEST INFO | Saved log: [CONTENT] SendUpdateCanvasForEvent with 1 rects
REFTEST INFO | Saved log: [CONTENT] Rect: 0 -100 783 4916
REFTEST INFO | Saved log: Updating canvas for invalidation
REFTEST INFO | Saved log: DoDrawWindow 0,0,783,1000
REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_TO_FIRE_INVALIDATE_EVENT
REFTEST INFO | Saved log: [CONTENT] MakeProgress: dispatching MozReftestInvalidate
REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_FOR_REFTEST_WAIT_REMOVAL
REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_FOR_SPELL_CHECKS
REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_FOR_APZ_FLUSH
REFTEST INFO | Saved log: [CONTENT] MakeProgress: done requesting APZ flush
REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_FOR_APZ_FLUSH
REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_FOR_APZ_FLUSH
REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_FOR_APZ_FLUSH
REFTEST INFO | Saved log: [CONTENT] MakeProgress: apz-repaints-flushed fired
REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_TO_FINISH
REFTEST INFO | Saved log: [CONTENT] MakeProgress: waiting for MozAfterPaint
REFTEST INFO | Saved log: [CONTENT] AfterPaintListener in file:///C:/slave/test/build/tests/reftest/tests/layout/reftests/async-scrolling/disable-apz-for-sle-pages.html
REFTEST INFO | Saved log: [CONTENT] SendUpdateCanvasForEvent with 0 rects
REFTEST INFO | Saved log: Updating canvas for invalidation
REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_TO_FINISH
REFTEST INFO | Saved log: [CONTENT] MakeProgress: waiting for MozAfterPaint
REFTEST INFO | Saved log: [CONTENT] AfterPaintListener in file:///C:/slave/test/build/tests/reftest/tests/layout/reftests/async-scrolling/disable-apz-for-sle-pages.html
REFTEST INFO | Saved log: [CONTENT] SendUpdateCanvasForEvent with 0 rects
REFTEST INFO | Saved log: Updating canvas for invalidation
REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_TO_FINISH
REFTEST INFO | Saved log: [CONTENT] MakeProgress: Completed
REFTEST INFO | Saved log: [CONTENT] RecordResult fired
REFTEST INFO | Saved log: RecordResult fired
REFTEST INFO | Saved log: START file:///C:/slave/test/build/tests/reftest/tests/layout/reftests/async-scrolling/disable-apz-for-sle-pages-ref.html
REFTEST INFO | Saved log: [CONTENT] OnDocumentLoad triggering WaitForTestEnd
REFTEST INFO | Saved log: [CONTENT] WaitForTestEnd: Adding listeners
REFTEST INFO | Saved log: Initializing canvas snapshot
REFTEST INFO | Saved log: DoDrawWindow 0,0,800,1000
REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_TO_FIRE_INVALIDATE_EVENT
REFTEST INFO | Saved log: [CONTENT] MakeProgress: dispatching MozReftestInvalidate
REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_FOR_REFTEST_WAIT_REMOVAL
REFTEST INFO | Saved log: [CONTENT] MakeProgress: waiting for reftest-wait to be removed
REFTEST INFO | Saved log: [CONTENT] AttrModifiedListener fired
REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_FOR_REFTEST_WAIT_REMOVAL
REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_FOR_SPELL_CHECKS
REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_FOR_APZ_FLUSH
REFTEST INFO | Saved log: [CONTENT] MakeProgress: done requesting APZ flush
REFTEST INFO | Saved log: [CONTENT] MakeProgress: apz-repaints-flushed fired
REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_TO_FINISH
REFTEST INFO | Saved log: [CONTENT] MakeProgress: waiting for MozAfterPaint
REFTEST INFO | Saved log: [CONTENT] AfterPaintListener in file:///C:/slave/test/build/tests/reftest/tests/layout/reftests/async-scrolling/disable-apz-for-sle-pages-ref.html
REFTEST INFO | Saved log: [CONTENT] SendUpdateCanvasForEvent with 0 rects
REFTEST INFO | Saved log: Updating canvas for invalidation
REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_TO_FINISH
REFTEST INFO | Saved log: [CONTENT] MakeProgress: Completed
REFTEST INFO | Saved log: [CONTENT] RecordResult fired
REFTEST INFO | Saved log: RecordResult fired
Attached image reference screenshot
"Regression" from bug 1246290 which added the test.
Assignee: nobody → bugmail.mozilla
Blocks: 1246290
Whiteboard: [gfx-noted]
Version: Trunk → 48 Branch
Assignee: bugmail.mozilla → nobody
Priority: -- → P5
This is currently the highest volume APZ intermittent-failure, I'll investigate.
Assignee: nobody → bugmail
Priority: P3 → P2
I did a try run with layers dumping enabled and from the layers dump everything looks normal. That is, the scrollbar is at y=60 while the content has the async transform applied and then in the last two layer dumps the scrollbar is at y=20 and the content has no async transform. The reftest analyzer snapshot though shows the scrollbar at y=60 still, so for some reason the snapshot taken didn't include the updated scrollbar position. I also see this in the log:

12:58:55     INFO - REFTEST INFO | Saved log: [CONTENT] SendUpdateCanvasForEvent with 1 rects
12:58:55     INFO - REFTEST INFO | Saved log: [CONTENT] Rect: 0 -100 787 1052
12:58:55     INFO - REFTEST INFO | Saved log: Updating canvas for invalidation
12:58:55     INFO - REFTEST INFO | Saved log: DoDrawWindow 0,0,787,1000

which indicates that the scrollbar area is not in the invalidation rect (w=787 instead of w=800). So I guess we're not invalidating the right area.
Adding a reftest-snapshot-all to the <html>'s class attribute should fix it by forcing a full-page snapshot. I can't repro the failure locally so here's a try push to verify:

https://treeherder.mozilla.org/#/jobs?repo=try&revision=013461c410a1
Comment on attachment 8788945 [details]
Bug 1263458 - Force a full-page snapshot to make sure the scrollbars get included as well.

https://reviewboard.mozilla.org/r/77258/#review75506

Should we investigate the reason we're not invalidating the right area, in case it's a bug?
Attachment #8788945 - Flags: review?(botond) → review+
(In reply to Botond Ballo [:botond] from comment #18)
> Should we investigate the reason we're not invalidating the right area, in
> case it's a bug?

Sorry, my comment was misleading. I think our invalidation code is fine, in that we are invalidating the right area in production. Also in production we would just composite everything but the way the reftest harness works it takes a partial snapshot of the screen to the canvas, which is what causes the issue. So the intermittent failure is an artifact of how the reftest harness works. By forcing it to snapshot everything we get it to behave more in line with what the user would see.
Pushed by kgupta@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/e103c4926305
Force a full-page snapshot to make sure the scrollbars get included as well. r=botond
Thanks, I'll take a look.
Flags: needinfo?(bugmail)
I don't really understand the failure. I can't repro it locally, and the logging I pushed to try seems to indicate that the flushApzRepaints call that runs as part of the reftest harness is going down the codepath at [1], marking the prescontext as having a pending paint. That pending paint flag never gets cleared, so the harness just keeps updating its snapshot forever until it times out.

[1] http://searchfox.org/mozilla-central/rev/950e13cca1fda6507dc53c243295044e8eda4493/layout/base/nsPresContext.cpp#163
Actually upon closer inspection it looks like the flushApzRepaints call does trigger a paint and it clears the pending paint flag, but then it gets set again somehow that's not clear to me. Also interesting is that adding reftest-no-flush to the documentElement.classList seems to fix the problem [1], although I don't really know why.

[1] https://treeherder.mozilla.org/#/jobs?repo=try&revision=ed8d625796ac
After staring at the logs some more and comparing failing runs to non-failing runs it looks like there's just a pending paint that gets stuck. It gets stuck because before it can happen, the reftest harness is stuck in an infinite loop grabbing snapshots. Each snapshot it grabs does a paint (but doesn't clear the pending paint flag, because it's a snapshot) and fires a MozAfterPaint. The MozAfterPaint is picked up by the harness and since there's still a pending paint, it goes and does another snapshot. This goes on until the test times out.

In the non-failing runs we do get a paint before this loop starts, and so the loop terminates in the first iteration because the pending paint flag is cleared. Whether or not we get a paint is random, and forcing the paint seems to fix the randomness and make the test pass consistently: https://treeherder.mozilla.org/#/jobs?repo=try&revision=858123700359

I'll do another try push with reftests on all platforms to make sure I didn't break anything else and then put the patches up for review.
Looks like dbaron is away until the 25th. Timothy, mind reviewing this?
Attachment #8790732 - Flags: review?(tnikkel)
Comment on attachment 8790732 [details] [diff] [review]
Part 2 - Force main-thread repaint after flushing APZ repaint requests

Hmm, this is a little confusing because getBoundingClientRect doesn't force a paint, it only forces layout to happen.

(In reply to Kartikaya Gupta (email:kats@mozilla.com) from comment #29)
> After staring at the logs some more and comparing failing runs to
> non-failing runs it looks like there's just a pending paint that gets stuck.
> It gets stuck because before it can happen, the reftest harness is stuck in
> an infinite loop grabbing snapshots. Each snapshot it grabs does a paint
> (but doesn't clear the pending paint flag, because it's a snapshot) and
> fires a MozAfterPaint. The MozAfterPaint is picked up by the harness and
> since there's still a pending paint, it goes and does another snapshot. This
> goes on until the test times out.

What prevents us from hitting this infinite loop in any other reftest-wait reftest? Seems like it would be a huge problem, but we aren't seeing that?
Yeah I admit I don't have answers to your questions. My understanding of all this isn't that great.

Maybe for now it's better if I just put reftest-no-flush on the test, since that seems to bypass this problem as well.
Comment on attachment 8790732 [details] [diff] [review]
Part 2 - Force main-thread repaint after flushing APZ repaint requests

Dropping this patch since as tnikkel said it's not clear why it works. If I'm going to hack things it's better to put in a test-local hack rather than hack the entire reftest harness.
Attachment #8790732 - Attachment is obsolete: true
Attachment #8790732 - Flags: review?(tnikkel)
Pushed by kgupta@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/7aa3d6539d77
Force a full-page snapshot to make sure the scrollbars get included as well. r=botond
https://hg.mozilla.org/mozilla-central/rev/7aa3d6539d77
Status: NEW → RESOLVED
Closed: 8 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla51
No longer blocks: 1286778
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: