MOZ_ASSERT(aGuid == mPendingTouchPreventedGuid) at gfx/layers/apz/util/APZEventState.cpp:298

RESOLVED FIXED in Firefox 44

Status

()

defect
RESOLVED FIXED
4 years ago
4 years ago

People

(Reporter: gwagner, Assigned: kats)

Tracking

unspecified
mozilla44
Points:
---
Dependency tree / graph

Firefox Tracking Flags

(firefox44 fixed)

Details

Attachments

(8 attachments)

Seen on aries with debug gecko and current trunk.

STR: Go to Setting app, Browsing privacy:

Keep tapping on the 2 toggles.
Blocks: 1134917
Posted file gdb bt
Assignee: nobody → bugmail.mozilla
I tried reproducing with the STR in comment 0 but wasn't able to. I'll upload a logging patch, if you have some time please repro with it applied and attach the log. Thanks!
Posted file logcat
Posted file one more instance
The second log you attached doesn't seem to have the problem (I don't see any lines containing the incoming guid). The first log shows the problem, but seems to indicate that the child process is getting touch-start events that are not attached to any input block and that don't line up with the events seen in the parent process.

The relevant hunk of the compositor thread log is this:

10-27 11:48:00.958  1658  1709 I Gecko   : INPQ: started new touch block 0xa5c52440 for target 0xa6253800
10-27 11:48:00.958  1658  1709 I Gecko   : INPQ: not waiting for content response on block 0xa5c52440
10-27 11:48:00.978  1658  1709 I Gecko   : INPQ: received new event in block 0xa5c52440
10-27 11:48:00.988  1658  1709 I Gecko   : INPQ: received new event in block 0xa5c52440
10-27 11:48:01.008  1658  1709 I Gecko   : INPQ: received new event in block 0xa5c52440
10-27 11:48:01.028  1658  1709 I Gecko   : INPQ: received new event in block 0xa5c52440
10-27 11:48:01.048  1658  1709 I Gecko   : INPQ: received new event in block 0xa5c52440
10-27 11:48:01.048  1658  1709 I Gecko   : INPQ: received new event in block 0xa5c52440
10-27 11:48:01.098  1658  1709 I Gecko   : INPQ: got a target apzc; block=645 guid={ l=1, p=1, v=4 }
10-27 11:48:01.098  1658  1709 I Gecko   : INPQ: got a content response; block=645
10-27 11:48:01.158  1658  1709 I Gecko   : INPQ: got a main thread timeout; block=649
10-27 11:48:01.158  1658  1709 I Gecko   : INPQ: processing input block 0xa5c52280; preventDefault 0 target 0xabbf5200
10-27 11:48:01.158  1658  1709 I Gecko   : INPQ: discarding processed touch block 0xa5c52280
10-27 11:48:01.158  1658  1709 I Gecko   : INPQ: processing input block 0xa5c52440; preventDefault 0 target 0xa6253800
10-27 11:48:01.168  1658  1709 I Gecko   : INPQ: discarding depleted touch block 0xa5c52440
10-27 11:48:01.168  1658  1709 I Gecko   : INPQ: started new touch block 0xa5c52280 for target 0xa6253800

It shows 8 input events arriving. The first is a touch-start and causes the creation of a new touch block (which has id 650). This input block gets inserted in the queue behind block 649 which has not yet been processed. The next 6 input events get added to the block. We then see the timeout occur for block 649, and it gets processed (elsewhere in the log you can see that block gets sent to the parent process). Following block 649, block 650 is processed fully. The final input event is another touch-start that causes block 650 to be discarded and creates a new block 651.

Meanwhile in the child process 2824 we see this:

10-27 11:48:01.328  2824  2824 I Gecko   : APZES: Handling event type 187
10-27 11:48:01.328  2824  2824 I Gecko   : APZES: Event not prevented; pending response for 650 { l=7, p=1, v=5 }
10-27 11:48:01.328  2824  2824 I Gecko   : APZES: Handling event type 188
10-27 11:48:01.328  2824  2824 I Gecko   : APZES: Incoming guid { l=7, p=1, v=5 }; pending guid { l=7, p=1, v=5 }
10-27 11:48:01.328  2824  2824 I Gecko   : APZES: Sending response 0 for pending guid: { l=7, p=1, v=5 }
10-27 11:48:01.328  2824  2824 I Gecko   : APZES: Handling event type 188

10-27 11:48:01.338  2824  2824 I Gecko   : APZES: Handling event type 187
10-27 11:48:01.338  2824  2824 I Gecko   : APZES: Event not prevented; pending response for 0 { l=7, p=0, v=0 }

10-27 11:48:01.348  2824  2824 I Gecko   : APZES: Handling event type 187
10-27 11:48:01.348  2824  2824 I Gecko   : APZES: Event not prevented; pending response for 0 { l=7, p=0, v=0 }

10-27 11:48:01.348  2824  2824 I Gecko   : APZES: Handling event type 188
10-27 11:48:01.348  2824  2824 I Gecko   : APZES: Incoming guid { l=7, p=1, v=5 }; pending guid { l=7, p=0, v=0 }

Here we see the touchstart (event type 187) from block 650 arrive. It's not preventDefault'ed, so it becomes the pending-response block. We see a couple of touchmove events (event type 188) come in following that. And then we see another touchstart, with block id 0 and presshellid/viewid also 0. Block 650 on the parent side had 7 events, and here we see only three arrive to the child before a new block shows up. And the block is busted or corrupted somehow. This happens a second time, and then we see a touchmove come in which causes the assertion failure.

What I suspect is going on here is that the two touchstart events showing up here are injected by the gaia system process using the injectTouchEvent API right into the middle of block 650. However, the injection must be happening outside of a touch event handler scope (i.e. inside a setTimeout or similar) so the block id doesn't get picked up. These injected touchstart events screw up the state in APZEventState.cpp and cause the assertion to trigger.
Bug 1217818 - Ignore injected touchstart events for the purposes of prevent-default notifications back to APZ. r=
Attachment #8679504 - Flags: review?(botond)
Comment on attachment 8679501 [details]
MozReview Request: Bug 1217818 - Minor refactoring to reuse a function. r=

https://reviewboard.mozilla.org/r/23443/#review21047
Attachment #8679501 - Flags: review?(botond) → review+
Attachment #8679502 - Flags: review?(botond) → review+
Comment on attachment 8679502 [details]
MozReview Request: Bug 1217818 - Add some more logging to more easily diagnose issues. r=

https://reviewboard.mozilla.org/r/23445/#review21049
Attachment #8679503 - Flags: review?(botond) → review+
Comment on attachment 8679503 [details]
MozReview Request: Bug 1217818 - Add support for the mHandledByAPZ flag on touch events as well. r=

https://reviewboard.mozilla.org/r/23447/#review21053
Attachment #8679504 - Flags: review?(botond) → review+
Comment on attachment 8679504 [details]
MozReview Request: Bug 1217818 - Ignore injected touchstart events for the purposes of prevent-default notifications back to APZ. r=

https://reviewboard.mozilla.org/r/23449/#review21051

::: gfx/layers/apz/src/APZCTreeManager.cpp:691
(Diff revision 1)
> +      touchInput.mHandledByAPZ = true;

I would have put this in the previous patch.
I moved the line to part 3. I was debating where to put it and put it in part 4 so it would be harder to miss but it makes just as much sense in part 3 :)
You need to log in before you can comment on or make changes to this bug.