Closed Bug 1309678 Opened 8 years ago Closed 4 years ago

Intermittent test_group_pointerevents.html | helper_bug1285070.html | Event pointerup should be generated once - got +0, expected 1

Categories

(Core :: DOM: Events, defect, P5)

Product:
Core
Component:
DOM: Events
Platform:
All
Android
Type:
defect

Tracking

()

Status:
RESOLVED FIXED

People

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

References

Details

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

Attachments

(1 file)

Logging touch and mouse events in helper_bug1285070.html for easier debugging
2.86 KB, patch
kats
: review+
Details | Diff | Splinter Review
OS: Unspecified → Android
Priority: -- → P5
Hardware: Unspecified → All
Whiteboard: [gfx-noted]
Version: unspecified → Trunk
Summary: Intermittent gfx/layers/apz/test/mochitest/test_group_pointerevents.html | helper_bug1285070.html | Event pointerup should be generated once - got +0, expected 1 → Intermittent test_group_pointerevents.html | helper_bug1285070.html | Event pointerup should be generated once - got +0, expected 1
as a note, this is a regular failure, although not enough to ask for resolution.  This seems to be android debug failures only and follow a similar pattern ( https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-inbound&job_id=102656818&lineNumber=1894 ):
[task 2017-05-28T11:08:17.031831Z] 11:08:17     INFO -  149 INFO TEST-START | gfx/layers/apz/test/mochitest/test_group_pointerevents.html
[task 2017-05-28T11:08:27.474702Z] 11:08:27     INFO -  Buffered messages logged at 11:08:21
[task 2017-05-28T11:08:27.475385Z] 11:08:27     INFO -  150 INFO must wait for load
[task 2017-05-28T11:08:27.475542Z] 11:08:27     INFO -  Buffered messages logged at 11:08:25
[task 2017-05-28T11:08:27.476950Z] 11:08:27     INFO -  151 INFO TEST-PASS | gfx/layers/apz/test/mochitest/test_group_pointerevents.html | helper_bug1285070.html | Clicked on div (at 108,109)
[task 2017-05-28T11:08:27.477051Z] 11:08:27     INFO -  152 INFO TEST-PASS | gfx/layers/apz/test/mochitest/test_group_pointerevents.html | helper_bug1285070.html | Event pointerover should be generated once
[task 2017-05-28T11:08:27.477137Z] 11:08:27     INFO -  153 INFO TEST-PASS | gfx/layers/apz/test/mochitest/test_group_pointerevents.html | helper_bug1285070.html | Event pointerenter should be generated once
[task 2017-05-28T11:08:27.477221Z] 11:08:27     INFO -  154 INFO TEST-PASS | gfx/layers/apz/test/mochitest/test_group_pointerevents.html | helper_bug1285070.html | Event pointerdown should be generated once
[task 2017-05-28T11:08:27.477313Z] 11:08:27     INFO -  Buffered messages finished
[task 2017-05-28T11:08:27.477406Z] 11:08:27     INFO -  155 INFO TEST-UNEXPECTED-FAIL | gfx/layers/apz/test/mochitest/test_group_pointerevents.html | helper_bug1285070.html | Event pointerup should be generated once - got +0, expected 1
[task 2017-05-28T11:08:27.479135Z] 11:08:27     INFO -      SimpleTest.is@SimpleTest/SimpleTest.js:312:5
[task 2017-05-28T11:08:27.479183Z] 11:08:27     INFO -      spawnTest/w.is@gfx/layers/apz/test/mochitest/apz_test_utils.js:230:45
[task 2017-05-28T11:08:27.479226Z] 11:08:27     INFO -      test/<@gfx/layers/apz/test/mochitest/helper_bug1285070.html:27:11
[task 2017-05-28T11:08:27.479290Z] 11:08:27     INFO -  156 INFO TEST-UNEXPECTED-FAIL | gfx/layers/apz/test/mochitest/test_group_pointerevents.html | helper_bug1285070.html | Event pointerleave should be generated once - got +0, expected 1
[task 2017-05-28T11:08:27.479318Z] 11:08:27     INFO -      SimpleTest.is@SimpleTest/SimpleTest.js:312:5
[task 2017-05-28T11:08:27.479347Z] 11:08:27     INFO -      spawnTest/w.is@gfx/layers/apz/test/mochitest/apz_test_utils.js:230:45
[task 2017-05-28T11:08:27.479374Z] 11:08:27     INFO -      test/<@gfx/layers/apz/test/mochitest/helper_bug1285070.html:27:11
[task 2017-05-28T11:08:27.479422Z] 11:08:27     INFO -  157 INFO TEST-UNEXPECTED-FAIL | gfx/layers/apz/test/mochitest/test_group_pointerevents.html | helper_bug1285070.html | Event pointerout should be generated once - got +0, expected 1
[task 2017-05-28T11:08:27.479448Z] 11:08:27     INFO -      SimpleTest.is@SimpleTest/SimpleTest.js:312:5
[task 2017-05-28T11:08:27.479476Z] 11:08:27     INFO -      spawnTest/w.is@gfx/layers/apz/test/mochitest/apz_test_utils.js:230:45
[task 2017-05-28T11:08:27.479504Z] 11:08:27     INFO -      test/<@gfx/layers/apz/test/mochitest/helper_bug1285070.html:27:11
[task 2017-05-28T11:08:38.035192Z] 11:08:38     INFO -  158 INFO must wait for load
[task 2017-05-28T11:08:48.584544Z] 11:08:48     INFO -  159 INFO TEST-PASS | gfx/layers/apz/test/mochitest/test_group_pointerevents.html | helper_bug1299195.html | Double tap with touch should fire 2 mousedown events
[task 2017-05-28T11:08:48.584653Z] 11:08:48     INFO -  160 INFO TEST-PASS | gfx/layers/apz/test/mochitest/test_group_pointerevents.html | helper_bug1299195.html | Double tap with touch should fire 2 mouseup events
[task 2017-05-28T11:08:48.584732Z] 11:08:48     INFO -  161 INFO TEST-PASS | gfx/layers/apz/test/mochitest/test_group_pointerevents.html | helper_bug1299195.html | Double tap with touch should fire 2 pointerdown events
[task 2017-05-28T11:08:48.584807Z] 11:08:48     INFO -  162 INFO TEST-PASS | gfx/layers/apz/test/mochitest/test_group_pointerevents.html | helper_bug1299195.html | Double tap with touch should fire 2 pointerup events
[task 2017-05-28T11:08:48.585286Z] 11:08:48     INFO -  163 INFO TEST-OK | gfx/layers/apz/test/mochitest/test_group_pointerevents.html | took 32279ms
Whiteboard: [gfx-noted] → [gfx-noted][stockwell unknown]
this has increased in frequency (40 failures in the last 7 days), still on android debug.

here is a recent log:
https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-central&job_id=109543400

and related text:
[task 2017-06-23T12:55:44.950060Z] 12:55:44     INFO -  139 INFO TEST-START | gfx/layers/apz/test/mochitest/test_group_pointerevents.html
[task 2017-06-23T12:56:06.010872Z] 12:56:06     INFO -  Buffered messages logged at 12:55:49
[task 2017-06-23T12:56:06.010941Z] 12:56:06     INFO -  140 INFO must wait for load
[task 2017-06-23T12:56:06.010979Z] 12:56:06     INFO -  Buffered messages logged at 12:55:58
[task 2017-06-23T12:56:06.011035Z] 12:56:06     INFO -  141 INFO TEST-PASS | gfx/layers/apz/test/mochitest/test_group_pointerevents.html | helper_bug1285070.html | Clicked on div (at 108,109)
[task 2017-06-23T12:56:06.011087Z] 12:56:06     INFO -  142 INFO TEST-PASS | gfx/layers/apz/test/mochitest/test_group_pointerevents.html | helper_bug1285070.html | Event pointerover should be generated once
[task 2017-06-23T12:56:06.012591Z] 12:56:06     INFO -  143 INFO TEST-PASS | gfx/layers/apz/test/mochitest/test_group_pointerevents.html | helper_bug1285070.html | Event pointerenter should be generated once
[task 2017-06-23T12:56:06.013108Z] 12:56:06     INFO -  144 INFO TEST-PASS | gfx/layers/apz/test/mochitest/test_group_pointerevents.html | helper_bug1285070.html | Event pointerdown should be generated once
[task 2017-06-23T12:56:06.017643Z] 12:56:06     INFO -  Buffered messages finished
[task 2017-06-23T12:56:06.017761Z] 12:56:06     INFO -  145 INFO TEST-UNEXPECTED-FAIL | gfx/layers/apz/test/mochitest/test_group_pointerevents.html | helper_bug1285070.html | Event pointerup should be generated once - got +0, expected 1
[task 2017-06-23T12:56:06.017826Z] 12:56:06     INFO -      SimpleTest.is@SimpleTest/SimpleTest.js:312:5
[task 2017-06-23T12:56:06.017893Z] 12:56:06     INFO -      spawnTest/w.is@gfx/layers/apz/test/mochitest/apz_test_utils.js:230:45
[task 2017-06-23T12:56:06.017955Z] 12:56:06     INFO -      test/<@gfx/layers/apz/test/mochitest/helper_bug1285070.html:27:11
[task 2017-06-23T12:56:06.018054Z] 12:56:06     INFO -  146 INFO TEST-UNEXPECTED-FAIL | gfx/layers/apz/test/mochitest/test_group_pointerevents.html | helper_bug1285070.html | Event pointerleave should be generated once - got +0, expected 1
[task 2017-06-23T12:56:06.018116Z] 12:56:06     INFO -      SimpleTest.is@SimpleTest/SimpleTest.js:312:5
[task 2017-06-23T12:56:06.018183Z] 12:56:06     INFO -      spawnTest/w.is@gfx/layers/apz/test/mochitest/apz_test_utils.js:230:45
[task 2017-06-23T12:56:06.018250Z] 12:56:06     INFO -      test/<@gfx/layers/apz/test/mochitest/helper_bug1285070.html:27:11
[task 2017-06-23T12:56:06.018361Z] 12:56:06     INFO -  147 INFO TEST-UNEXPECTED-FAIL | gfx/layers/apz/test/mochitest/test_group_pointerevents.html | helper_bug1285070.html | Event pointerout should be generated once - got +0, expected 1
[task 2017-06-23T12:56:06.018421Z] 12:56:06     INFO -      SimpleTest.is@SimpleTest/SimpleTest.js:312:5
[task 2017-06-23T12:56:06.018487Z] 12:56:06     INFO -      spawnTest/w.is@gfx/layers/apz/test/mochitest/apz_test_utils.js:230:45
[task 2017-06-23T12:56:06.018547Z] 12:56:06     INFO -      test/<@gfx/layers/apz/test/mochitest/helper_bug1285070.html:27:11
[task 2017-06-23T12:56:16.503707Z] 12:56:16     INFO -  148 INFO must wait for load
[task 2017-06-23T12:56:16.505951Z] 12:56:16     INFO -  149 INFO TEST-PASS | gfx/layers/apz/test/mochitest/test_group_pointerevents.html | helper_bug1299195.html | Double tap with touch should fire 2 mousedown events
[task 2017-06-23T12:56:16.506387Z] 12:56:16     INFO -  150 INFO TEST-PASS | gfx/layers/apz/test/mochitest/test_group_pointerevents.html | helper_bug1299195.html | Double tap with touch should fire 2 mouseup events
[task 2017-06-23T12:56:16.506812Z] 12:56:16     INFO -  151 INFO TEST-UNEXPECTED-FAIL | gfx/layers/apz/test/mochitest/test_group_pointerevents.html | helper_bug1299195.html | Double tap with touch should fire 2 pointerdown events - got 1, expected 2
[task 2017-06-23T12:56:16.507080Z] 12:56:16     INFO -      SimpleTest.is@SimpleTest/SimpleTest.js:312:5
[task 2017-06-23T12:56:16.507432Z] 12:56:16     INFO -      spawnTest/w.is@gfx/layers/apz/test/mochitest/apz_test_utils.js:230:45
[task 2017-06-23T12:56:16.507825Z] 12:56:16     INFO -      runTests/<@gfx/layers/apz/test/mochitest/helper_bug1299195.html:24:11
[task 2017-06-23T12:56:16.508236Z] 12:56:16     INFO -  152 INFO TEST-UNEXPECTED-FAIL | gfx/layers/apz/test/mochitest/test_group_pointerevents.html | helper_bug1299195.html | Double tap with touch should fire 2 pointerup events - got 1, expected 2
[task 2017-06-23T12:56:16.508468Z] 12:56:16     INFO -      SimpleTest.is@SimpleTest/SimpleTest.js:312:5
[task 2017-06-23T12:56:16.508867Z] 12:56:16     INFO -      spawnTest/w.is@gfx/layers/apz/test/mochitest/apz_test_utils.js:230:45
[task 2017-06-23T12:56:16.509215Z] 12:56:16     INFO -      runTests/<@gfx/layers/apz/test/mochitest/helper_bug1299195.html:25:11
[task 2017-06-23T12:56:16.509742Z] 12:56:16     INFO -  153 INFO TEST-OK | gfx/layers/apz/test/mochitest/test_group_pointerevents.html | took 31274ms


as a note bug 1367380 is similar yet it doesn't have an increase in failures in the last week like this bug.

:milan as triage owner for the graphics:layers components can you get this on the radar for someone on the team to take a look at sometime in the next 2 weeks?
Flags: needinfo?(milan)
Whiteboard: [gfx-noted][stockwell unknown] → [gfx-noted][stockwell needswork]
Two weeks deadline is difficult with the work week coming up and some PTOs - can we have July 14th for this?
Assignee: nobody → jnicol
Flags: needinfo?(milan) → needinfo?(jnicol)
yeah, this is a hard one with distractions- assuming this remains <75 failure/week, I am fine waiting a few extra weeks
I've tried to reproduce this with APZ logging enabled to understand what's going on, but haven't been successful in reproducing it. Kats, do you have any idea what could be going on here, or what a good approach to debugging it would be?
Flags: needinfo?(jnicol) → needinfo?(bugmail)
It looks like a DOM:Events bug, because at the point that the click event listener is triggered, only the pointerover, pointerenter and pointerdown events have been received, and the pointerup, pointerleave, pointerout have not been received. Stone, do you know why this might be happening? The test itself doesn't have much in the way of async behaviour so it seems like this is a bug in the actual event dispatching. Are the pointer events dispatched asynchronously from the touch events?
Component: Graphics: Layers → DOM: Events
Flags: needinfo?(bugmail) → needinfo?(sshih)
Whiteboard: [gfx-noted][stockwell needswork] → [gfx-noted][stockwell unknown]
(In reply to Kartikaya Gupta (email:kats@mozilla.com) from comment #25)
> It looks like a DOM:Events bug, because at the point that the click event
> listener is triggered, only the pointerover, pointerenter and pointerdown
> events have been received, and the pointerup, pointerleave, pointerout have
> not been received. Stone, do you know why this might be happening? The test
> itself doesn't have much in the way of async behaviour so it seems like this
> is a bug in the actual event dispatching. Are the pointer events dispatched
> asynchronously from the touch events?
When we got touch events in the content process, we fire the corresponding pointer events synchronously. I'm wondering is it possible that the click event is fired before the other pointer events.

According to the associated failures, this problem only happened on Android. I'm trying to understand how the API synthesizeNativeTap works on Android. I guess we don't have APZ on Android, right?
(In reply to Ming-Chou Shih [:stone] from comment #27)
> When we got touch events in the content process, we fire the corresponding
> pointer events synchronously. I'm wondering is it possible that the click
> event is fired before the other pointer events.

Hm, I guess that might be possible. I thought we had a test for that but I can't find it now.

> According to the associated failures, this problem only happened on Android.
> I'm trying to understand how the API synthesizeNativeTap works on Android. I
> guess we don't have APZ on Android, right?

We do have APZ on Android. synthesizeNativeTap on Android ends up calling the code at [1] in Java, which injects touch events into the widget code the same way "real" touch events would appear. These then go through the APZ gesture detection code as normal and should end up at [2]. That code specifically delays the click event (see [3]) so that it gets dispatched after the touch-up. It's possible that something changed somewhere and this is no longer the case. It might be worth modifying the test to log touch events in addition to pointer events, that way we will know if the touch events are also out of order, or if it's just the pointer events.

[1] http://searchfox.org/mozilla-central/rev/01d27fdd3946f7210da91b18fcccca01d7324fe2/mobile/android/geckoview/src/main/java/org/mozilla/gecko/gfx/GeckoLayerClient.java#318
[2] http://searchfox.org/mozilla-central/rev/01d27fdd3946f7210da91b18fcccca01d7324fe2/gfx/layers/apz/src/AsyncPanZoomController.cpp#2250
[3] http://searchfox.org/mozilla-central/rev/01d27fdd3946f7210da91b18fcccca01d7324fe2/gfx/layers/apz/src/AsyncPanZoomController.cpp#2270
Attachment #8887369 - Flags: review?(bugmail)
Attachment #8887369 - Flags: review?(bugmail) → review+
Pushed by sshih@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/95c747518779
Logging touch and mouse events in helper_bug1285070.html for easier debugging. r=kats.
Flags: needinfo?(sshih)
Keywords: leave-open

This seems to have stopped happening, no point keeping this bug open.

Assignee: jnicol → stone123456
Status: NEW → RESOLVED
Closed: 4 years ago
Keywords: leave-open
Resolution: --- → FIXED
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: