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

Status: RESOLVED FIXED

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

Description

[Ryan VanderMeulen [:RyanVM]]

Attachment: 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

Comment 1

[Ryan VanderMeulen [:RyanVM]]

Attachment: reference screenshot

Comment 2

[Kartikaya Gupta (email:[e-mail])]

"Regression" from bug 1246290 which added the test.

Comment 3

[Intermittent Failures Robot]

15 automation job failures were associated with this bug yesterday.

Repository breakdown:
* autoland: 9
* mozilla-inbound: 5
* mozilla-aurora: 1

Platform breakdown:
* linux64: 14
* windows8-64: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1263458&startday=2016-08-19&endday=2016-08-19&tree=all

Comment 4

[Intermittent Failures Robot]

31 automation job failures were associated with this bug in the last 7 days.

Repository breakdown:
* autoland: 23
* mozilla-inbound: 5
* mozilla-aurora: 2
* mozilla-central: 1

Platform breakdown:
* linux64: 29
* windows8-64: 2

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1263458&startday=2016-08-15&endday=2016-08-21&tree=all

Comment 5

[Intermittent Failures Robot]

19 automation job failures were associated with this bug yesterday.

Repository breakdown:
* autoland: 10
* mozilla-inbound: 7
* mozilla-central: 1
* mozilla-aurora: 1

Platform breakdown:
* linux64: 18
* windows8-64: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1263458&startday=2016-08-25&endday=2016-08-25&tree=all

Comment 6

[Intermittent Failures Robot]

16 automation job failures were associated with this bug yesterday.

Repository breakdown:
* mozilla-inbound: 7
* autoland: 7
* try: 1
* fx-team: 1

Platform breakdown:
* linux64: 16

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1263458&startday=2016-08-26&endday=2016-08-26&tree=all

Comment 7

[Intermittent Failures Robot]

72 automation job failures were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-inbound: 30
* autoland: 29
* fx-team: 7
* mozilla-central: 4
* try: 1
* mozilla-aurora: 1

Platform breakdown:
* linux64: 71
* windows8-64: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1263458&startday=2016-08-22&endday=2016-08-28&tree=all

Comment 8

[Intermittent Failures Robot]

20 automation job failures were associated with this bug yesterday.

Repository breakdown:
* autoland: 12
* mozilla-inbound: 7
* mozilla-central: 1

Platform breakdown:
* linux64: 20

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1263458&startday=2016-08-30&endday=2016-08-30&tree=all

Comment 9

[Intermittent Failures Robot]

25 automation job failures were associated with this bug yesterday.

Repository breakdown:
* mozilla-inbound: 16
* autoland: 4
* mozilla-central: 3
* fx-team: 2

Platform breakdown:
* linux64: 25

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1263458&startday=2016-08-31&endday=2016-08-31&tree=all

Comment 10

[Intermittent Failures Robot]

26 automation job failures were associated with this bug yesterday.

Repository breakdown:
* mozilla-inbound: 15
* autoland: 7
* fx-team: 2
* oak: 1
* mozilla-central: 1

Platform breakdown:
* linux64: 26

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1263458&startday=2016-09-01&endday=2016-09-01&tree=all

Comment 11

[Intermittent Failures Robot]

16 automation job failures were associated with this bug yesterday.

Repository breakdown:
* mozilla-inbound: 8
* autoland: 4
* fx-team: 3
* try: 1

Platform breakdown:
* linux64: 16

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1263458&startday=2016-09-02&endday=2016-09-02&tree=all

Comment 12

[Intermittent Failures Robot]

122 automation job failures were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-inbound: 59
* autoland: 43
* mozilla-central: 9
* fx-team: 8
* try: 2
* oak: 1

Platform breakdown:
* linux64: 122

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1263458&startday=2016-08-29&endday=2016-09-04&tree=all

Comment 13

[Kartikaya Gupta (email:[e-mail])]

This is currently the highest volume APZ intermittent-failure, I'll investigate.

Comment 14

[Intermittent Failures Robot]

26 automation job failures were associated with this bug yesterday.

Repository breakdown:
* mozilla-inbound: 13
* autoland: 8
* fx-team: 3
* try: 1
* mozilla-central: 1

Platform breakdown:
* linux64: 26

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1263458&startday=2016-09-06&endday=2016-09-06&tree=all

Comment 15

[Kartikaya Gupta (email:[e-mail])]

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.

Comment 16

[Kartikaya Gupta (email:[e-mail])]

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 17

[Kartikaya Gupta (email:[e-mail])]

Attachment: Bug 1263458 - Force a full-page snapshot to make sure the scrollbars get included as well.

Review commit: https://reviewboard.mozilla.org/r/77258/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/77258/

Comment 18

[Botond Ballo [:botond]]

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?

Comment 19

[Kartikaya Gupta (email:[e-mail])]

(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.

Comment 20

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/e103c4926305
Force a full-page snapshot to make sure the scrollbars get included as well. r=botond

Comment 21

[Wes Kocher (:KWierso) (Not reading bugmail; email directly if needed)]

I had to back this out for test failures like https://treeherder.mozilla.org/logviewer.html#?job_id=3219588&repo=autoland

https://hg.mozilla.org/integration/autoland/rev/03a4262f0c40

Comment 22

[Intermittent Failures Robot]

28 automation job failures were associated with this bug yesterday.

Repository breakdown:
* mozilla-inbound: 16
* fx-team: 5
* autoland: 4
* mozilla-central: 2
* ash: 1

Platform breakdown:
* linux64: 28

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1263458&startday=2016-09-07&endday=2016-09-07&tree=all

Comment 23

[Kartikaya Gupta (email:[e-mail])]

Thanks, I'll take a look.

Comment 24

[Intermittent Failures Robot]

16 automation job failures were associated with this bug yesterday.

Repository breakdown:
* autoland: 9
* fx-team: 4
* mozilla-inbound: 2
* ash: 1

Platform breakdown:
* linux64: 16

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1263458&startday=2016-09-08&endday=2016-09-08&tree=all

Comment 25

[Kartikaya Gupta (email:[e-mail])]

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

Comment 26

[Kartikaya Gupta (email:[e-mail])]

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

Comment 27

[Intermittent Failures Robot]

16 automation job failures were associated with this bug yesterday.

Repository breakdown:
* mozilla-inbound: 7
* autoland: 6
* fx-team: 3

Platform breakdown:
* linux64: 16

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1263458&startday=2016-09-09&endday=2016-09-09&tree=all

Comment 28

[Intermittent Failures Robot]

112 automation job failures were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-inbound: 48
* autoland: 34
* fx-team: 20
* mozilla-central: 6
* ash: 3
* try: 1

Platform breakdown:
* linux64: 112

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1263458&startday=2016-09-05&endday=2016-09-11&tree=all

Comment 29

[Kartikaya Gupta (email:[e-mail])]

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.

Comment 30

[Kartikaya Gupta (email:[e-mail])]

That seemed to work: https://treeherder.mozilla.org/#/jobs?repo=try&revision=7fa25e59341e&group_state=expanded

Patch coming up.

Comment 31

[Kartikaya Gupta (email:[e-mail])]

Attachment: Part 2 - Force main-thread repaint after flushing APZ repaint requests

Looks like dbaron is away until the 25th. Timothy, mind reviewing this?

Comment 32

[Intermittent Failures Robot]

15 automation job failures were associated with this bug yesterday.

Repository breakdown:
* mozilla-inbound: 10
* fx-team: 2
* autoland: 2
* try: 1

Platform breakdown:
* linux64: 15

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1263458&startday=2016-09-13&endday=2016-09-13&tree=all

Comment 33

[Timothy Nikkel (: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:[e-mail]) 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?

Comment 34

[Kartikaya Gupta (email:[e-mail])]

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 35

[Kartikaya Gupta (email:[e-mail])]

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.

Comment 36

[Pulsebot]

Pushed by [e-mail]:
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

Comment 37

[Intermittent Failures Robot]

25 automation job failures were associated with this bug yesterday.

Repository breakdown:
* autoland: 12
* mozilla-inbound: 7
* fx-team: 6

Platform breakdown:
* linux64: 25

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1263458&startday=2016-09-14&endday=2016-09-14&tree=all

Comment 38

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/mozilla-central/rev/7aa3d6539d77

Comment 40

[Kartikaya Gupta (email:[e-mail])]

http://hg.mozilla.org/releases/mozilla-aurora/rev/22d3ca9e190a

Comment 41

[Intermittent Failures Robot]

52 automation job failures were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-inbound: 23
* autoland: 18
* fx-team: 9
* try: 1
* mozilla-central: 1

Platform breakdown:
* linux64: 52

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1263458&startday=2016-09-12&endday=2016-09-18&tree=all