1448513 - Intermittent gfx/layers/apz/test/mochitest/test_group_touchevents.html | helper_basic_pan.html | check that the window scrolled - got 49, expected 50

Status: RESOLVED FIXED

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

Description

[Treeherder Bug Filer]

Filed by: rgurzau [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=169995324&repo=mozilla-central

https://queue.taskcluster.net/v1/task/DksFK17_RiiyRvME922WDg/runs/0/artifacts/public/logs/live_backing.log

23:32:11     INFO -  1582 INFO None1583 INFO TEST-START | gfx/layers/apz/test/mochitest/test_group_touchevents.html
23:32:11     INFO -  GECKO(1172) | ++DOMWINDOW == 26 (000001C505C3E800) [pid = 2868] [serial = 76] [outer = 000001C50372F400]
23:32:11     INFO -  GECKO(1172) | --DOCSHELL 000001C50536A800 == 4 [pid = 2868] [id = {f9001329-489f-40b1-915b-eaf1c47ccb0a}]
23:32:11     INFO -  GECKO(1172) | ++DOCSHELL 000001C5044B1800 == 5 [pid = 2868] [id = {a8d77b26-a693-4570-8c4e-7359c6bb5188}]
23:32:11     INFO -  GECKO(1172) | ++DOMWINDOW == 27 (000001C505C44C00) [pid = 2868] [serial = 77] [outer = 0000000000000000]
23:32:11     INFO -  GECKO(1172) | ++DOMWINDOW == 28 (000001C505C46400) [pid = 2868] [serial = 78] [outer = 000001C505C44C00]
23:32:11     INFO -  GECKO(1172) | ++DOMWINDOW == 29 (000001C505C45000) [pid = 2868] [serial = 79] [outer = 000001C505C44C00]
23:32:11     INFO -  GECKO(1172) | Parent process: flushed APZ repaints, waiting for callback...
23:32:11     INFO -  GECKO(1172) | [Child 2868, Main Thread] WARNING: Unable to find interface object on global: file z:/build/build/src/dom/base/nsGlobalWindowInner.cpp, line 2975
23:32:11     INFO -  GECKO(1172) | [Child 2868, Main Thread] WARNING: Unable to find interface object on global: file z:/build/build/src/dom/base/nsGlobalWindowInner.cpp, line 2975
23:32:12     INFO -  GECKO(1172) | Flushed APZ repaints, waiting for callback...
23:32:12     INFO -  GECKO(1172) | Finished native drag, waiting for transform-end observer...
23:32:12     INFO -  GECKO(1172) | Transform complete; flushing repaints...
23:32:12     INFO -  GECKO(1172) | Flushed APZ repaints, waiting for callback...
23:32:12     INFO -  TEST-INFO | started process screenshot
23:32:12     INFO -  TEST-INFO | screenshot: exit 0
23:32:12     INFO -  Buffered messages logged at 23:32:11
23:32:12     INFO -  1584 INFO TEST-PASS | gfx/layers/apz/test/mochitest/test_group_touchevents.html | Check if TouchEvent is supported (it should be, the test harness forces it on everywhere)
23:32:12     INFO -  1585 INFO must wait for load
23:32:12     INFO -  Buffered messages finished
23:32:12    ERROR -  1586 INFO TEST-UNEXPECTED-FAIL | gfx/layers/apz/test/mochitest/test_group_touchevents.html | helper_basic_pan.html | check that the window scrolled - got 49, expected 50
23:32:12     INFO -      SimpleTest.is@SimpleTest/SimpleTest.js:312:5
23:32:12     INFO -      spawnTest/w.is@gfx/layers/apz/test/mochitest/apz_test_utils.js:243:45
23:32:12     INFO -      checkScroll@gfx/layers/apz/test/mochitest/helper_basic_pan.html:25:3
23:32:12     INFO -      promise callback*flushApzRepaints@gfx/layers/apz/test/mochitest/apz_test_utils.js:138:3
23:32:12     INFO -      transformEnd@gfx/layers/apz/test/mochitest/helper_basic_pan.html:16:5

Comment 1

[Intermittent Failures Robot]

6 failures in 822 pushes (0.007 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* mozilla-central: 4
* mozilla-inbound: 1
* autoland: 1

Platform breakdown:
* windows10-64: 5
* windows10-64-ccov: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1448513&startday=2018-03-20&endday=2018-03-26&tree=trunk

Comment 2

[Intermittent Failures Robot]

2 failures in 718 pushes (0.003 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* mozilla-inbound: 1
* autoland: 1

Platform breakdown:
* windows10-64: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1448513&startday=2018-03-26&endday=2018-04-01&tree=trunk

Comment 3

[Intermittent Failures Robot]

2 failures in 782 pushes (0.003 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* try: 1
* mozilla-inbound: 1

Platform breakdown:
* windows10-64-ccov: 1
* windows10-64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1448513&startday=2018-04-16&endday=2018-04-22&tree=trunk

Comment 4

[Intermittent Failures Robot]

3 failures in 780 pushes (0.004 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* autoland: 2
* mozilla-central: 1

Platform breakdown:
* windows10-64: 2
* windows10-64-ccov: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1448513&startday=2018-04-23&endday=2018-04-29&tree=trunk

Comment 5

[Intermittent Failures Robot]

3 failures in 551 pushes (0.005 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* mozilla-esr60: 1
* mozilla-central: 1
* autoland: 1

Platform breakdown:
* windows10-64: 2
* windows10-64-ccov: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1448513&startday=2018-04-30&endday=2018-05-06&tree=trunk

Comment 6

[Intermittent Failures Robot]

7 failures in 660 pushes (0.011 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* try: 3
* mozilla-central: 2
* mozilla-inbound: 1
* autoland: 1

Platform breakdown:
* windows10-64: 3
* windows10-64-devedition: 2
* windows10-64-ccov: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1448513&startday=2018-05-07&endday=2018-05-13&tree=trunk

Comment 7

[Intermittent Failures Robot]

11 failures in 639 pushes (0.017 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* try: 4
* mozilla-central: 3
* mozilla-inbound: 2
* mozilla-beta: 1
* autoland: 1

Platform breakdown:
* windows10-64: 8
* windows10-64-ccov: 3

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1448513&startday=2018-05-14&endday=2018-05-20&tree=trunk

Comment 8

[Intermittent Failures Robot]

2 failures in 632 pushes (0.003 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* mozilla-esr60: 1
* mozilla-central: 1

Platform breakdown:
* windows10-64-ccov: 1
* windows10-64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1448513&startday=2018-05-21&endday=2018-05-27&tree=trunk

Comment 9

[Intermittent Failures Robot]

3 failures in 655 pushes (0.005 failures/push) were associated with this bug in the last 7 days.    

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

Platform breakdown:
* windows10-64: 2
* windows10-64-ccov: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1448513&startday=2018-05-28&endday=2018-06-03&tree=trunk

Comment 10

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

This seems to hit frequently with the test re-enabled on windows10-64-qr. I'll take a quick look.

Comment 11

[Intermittent Failures Robot]

14 failures in 669 pushes (0.021 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* mozilla-inbound: 6
* try: 3
* mozilla-central: 2
* autoland: 2
* mozilla-esr60: 1

Platform breakdown:
* windows10-64: 11
* windows10-64-qr: 2
* windows10-64-ccov: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1448513&startday=2018-06-04&endday=2018-06-10&tree=trunk

Comment 12

[Intermittent Failures Robot]

21 failures in 408 pushes (0.051 failures/push) were associated with this bug in the last 7 days. 

This is the #31 most frequent failure this week.   

Repository breakdown:
* mozilla-inbound: 9
* try: 4
* autoland: 4
* mozilla-central: 3
* mozilla-beta: 1

Platform breakdown:
* windows10-64-qr: 19
* windows10-64-nightly: 1
* windows10-64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1448513&startday=2018-06-11&endday=2018-06-17&tree=trunk

Comment 13

[Natalia Csoregi [:nataliaCs]]

There were 33 failures in the last 7 days, on Windows 10x64 asan (4 failures) and Windows 10x64 QR (29 failures).

Example failure log: https://treeherder.mozilla.org/logviewer.html#?job_id=184084858&repo=mozilla-central&lineNumber=6478

02:56:19     INFO -  1144 INFO TEST-PASS | gfx/layers/apz/test/mochitest/test_group_touchevents.html | Check if TouchEvent is supported (it should be, the test harness forces it on everywhere)
02:56:19     INFO -  1145 INFO must wait for load
02:56:19     INFO -  Buffered messages finished
02:56:19    ERROR -  1146 INFO TEST-UNEXPECTED-FAIL | gfx/layers/apz/test/mochitest/test_group_touchevents.html | helper_basic_pan.html | check that the window scrolled - got 49, expected 50
02:56:19     INFO -      SimpleTest.is@SimpleTest/SimpleTest.js:312:5
02:56:19     INFO -      spawnTest/w.is@gfx/layers/apz/test/mochitest/apz_test_utils.js:254:45
02:56:19     INFO -      checkScroll@gfx/layers/apz/test/mochitest/helper_basic_pan.html:25:3
02:56:19     INFO -      setTimeout handler*repaintDone@gfx/layers/apz/test/mochitest/apz_test_utils.js:122:7
02:56:21     INFO -  GECKO(3604) | Parent process: flushed APZ repaints, waiting for callback...
02:56:21     INFO -  GECKO(3604) | Flushed APZ repaints, waiting for callback...
02:56:21     INFO -  GECKO(3604) | Finished native drag, waiting for transform-end observer...
02:56:21     INFO -  GECKO(3604) | Transform complete; flushing repaints...
02:56:21     INFO -  GECKO(3604) | Flushed APZ repaints, waiting for callback...
02:56:21     INFO -  1147 INFO TEST-PASS | gfx/layers/apz/test/mochitest/test_group_touchevents.html | helper_div_pan.html | check that the div scrolled

Comment 14

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

The problem here appears to be that the first touchmove is always consumed to overcome the touch start tolerance amount, regardless of how many pixels were in that touchmove. So if we get a sequence of touchevents like so:

touchstart (18, 108)
touchmove  (18, 105) <-- this is passed to [1]
touchmove  (18, 104) <-- this scrolls by 1 pixel
...
touchmove  (18, 57)  <-- this puts the scroll position at y=48

This is what is happening; we send touch events for 51 pixels (which is the desired 50, plus 1 to overcome the threshold). But the first few get squashed together and so in the end we scroll a few less pixels.

[1] https://searchfox.org/mozilla-central/rev/93d2b9860b3d341258c7c5dcd4e278dea544432b/gfx/layers/apz/src/AsyncPanZoomController.cpp#1305

Comment 15

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

Attachment: Bug 1448513 - Only do the panThreshold check if the threshold is > 0.

This optimization also sneakily avoids the call to UpdateWithTouchAtDevicePoint
which is what updates the Axis::mPos variable to the new touch point. Without
that update, mPos remains at the touchstart point, which ensures that the full
pixel delta from all the touchmove events gets turned into scrolling. Without
this, the first touchmove event always gets consumed in the process of overcoming
the pan threshold, which lead to flaky test behaviour.

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

Comment 16

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

Presumably this was only happening on windows because that's the only platform on which the touch events were getting squashed together. We do try to send the touch events into the OS so that it's more representative of actual user behaviour, and it could be that windows is more aggressive with the coalescing of events than other platforms.

Anyway, try push with my patch: https://treeherder.mozilla.org/#/jobs?repo=try&revision=288ead78f3fbc2df1ea1f28d8537855231b5fec8

Comment 17

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

Comment on attachment 8987182 [details]
Bug 1448513 - Only do the panThreshold check if the threshold is > 0.

https://reviewboard.mozilla.org/r/252428/#review258918

::: gfx/layers/apz/test/mochitest/apz_test_native_event_utils.js:286
(Diff revision 1)
>  }
>  
> -// A handy constant when synthesizing native touch drag events with the pref
> -// "apz.touch_start_tolerance" set to 0. In this case, the first touchmove with
> -// a nonzero pixel movement is consumed by the APZ to transition from the
> -// "touching" state to the "panning" state, so calls to synthesizeNativeTouchDrag
> +// Note that when calling this function you'll want to make sure that the pref
> +// "apz.touch_start_tolerance" is set to 0, or some of the touchmove will get
> +// consumed to overcome the panning threshold.
> +function synthesizeNativeTouchDrag(aElement, aX, aY, aDeltaX, aDeltaY, aSlop, aObserver = null, aTouchId = 0) {

Whoops, this patch includes an aSlop argument which shouldn't be there... new patch coming in a sec.

Comment 18

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

Attachment: Bug 1448513 - Only do the panThreshold check if the threshold is > 0.

This optimization also sneakily avoids the call to UpdateWithTouchAtDevicePoint
which is what updates the Axis::mPos variable to the new touch point. Without
that update, mPos remains at the touchstart point, which ensures that the full
pixel delta from all the touchmove events gets turned into scrolling. Without
this, the first touchmove event always gets consumed in the process of overcoming
the pan threshold, which lead to flaky test behaviour.

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

Comment 19

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

https://treeherder.mozilla.org/#/jobs?repo=try&revision=8252714140f387ed57fb2a4336ccb3205113d688 is the new try push

Comment 20

[Botond Ballo [:botond]]

Comment on attachment 8987189 [details]
Bug 1448513 - Only do the panThreshold check if the threshold is > 0.

https://reviewboard.mozilla.org/r/252430/#review258954

Nice cleanup :)

Comment 21

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/580bc3d27e23
Only do the panThreshold check if the threshold is > 0. r=botond

Comment 22

[Intermittent Failures Robot]

20 failures in 84 pushes (0.238 failures/push) were associated with this bug yesterday.    

Repository breakdown:
* autoland: 10
* mozilla-inbound: 4
* mozilla-central: 4
* try: 1
* mozilla-beta: 1

Platform breakdown:
* windows10-64: 14
* windows10-64-qr: 6

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1448513&startday=2018-06-22&endday=2018-06-22&tree=trunk

Comment 23

[Cristian Brindusan [:cbrindusan]]

https://hg.mozilla.org/mozilla-central/rev/580bc3d27e23

Comment 25

[Intermittent Failures Robot]

57 failures in 521 pushes (0.109 failures/push) were associated with this bug in the last 7 days. 

This is the #7 most frequent failure this week.  

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **  

Repository breakdown:
* autoland: 25
* mozilla-inbound: 13
* mozilla-central: 11
* try: 7
* mozilla-beta: 1

Platform breakdown:
* windows10-64-qr: 32
* windows10-64: 25

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1448513&startday=2018-06-18&endday=2018-06-24&tree=trunk

Comment 26

[Intermittent Failures Robot]

1 failures in 718 pushes (0.001 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* mozilla-release: 1

Platform breakdown:
* windows10-64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1448513&startday=2018-06-25&endday=2018-07-01&tree=trunk