Closed Bug 1256128 Opened 8 years ago Closed 8 years ago

Intermittent e10s test_layerization.html | inner3 becomes unlayerized after expiry | outer3 is no longer layerized after inner3 triggered expiry

Categories

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

Product:
Core
Component:
Panning and Zooming
Version:
48 Branch
Platform:
Unspecified
Linux
Type:
defect

Tracking

()

Status:
RESOLVED FIXED
Milestone:
mozilla52
Tracking Flags:
Tracking Status
e10s - ---
firefox48 --- wontfix
firefox49 --- wontfix
firefox50 --- fixed
firefox51 --- fixed
firefox52 --- fixed

People

(Reporter: aryx, Assigned: kats)

References

Details

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

Attachments

(1 file)

Bug 1256128 - Update test to handle a tricky race condition where the input event processing is delayed a little.
58 bytes, text/x-review-board-request
botond
: review+
Details 
https://treeherder.mozilla.org/logviewer.html#?job_id=23642299&repo=mozilla-inbound

21:58:48     INFO -  121 INFO TEST-PASS | gfx/layers/apz/test/mochitest/test_layerization.html | outer2 got de-layerized with inner2
21:58:48     INFO -  122 INFO TEST-FAIL | gfx/layers/apz/test/mochitest/test_layerization.html | The author of the test has indicated that flaky timeouts are expected.  Reason: we are testing code that measures an actual timeout
21:58:48     INFO -  123 INFO TEST-PASS | gfx/layers/apz/test/mochitest/test_layerization.html | expected at least one paint
21:58:48     INFO -  124 INFO TEST-UNEXPECTED-FAIL | gfx/layers/apz/test/mochitest/test_layerization.html | inner3 becomes unlayerized after expiry
21:58:48     INFO -      runTest@gfx/layers/apz/test/mochitest/test_layerization.html:195:3
21:58:48     INFO -      driveTest@gfx/layers/apz/test/mochitest/test_layerization.html:217:13
21:58:48     INFO -      setTimeout handler*SimpleTest_setTimeoutShim@SimpleTest/SimpleTest.js:621:12
21:58:48     INFO -      callDriveTestAsync@gfx/layers/apz/test/mochitest/test_layerization.html:105:3
21:58:48     INFO -      waitForPaints@SimpleTest/paint_listener.js:73:5
21:58:48     INFO -      window.waitForAllPaints@SimpleTest/paint_listener.js:81:5
21:58:48     INFO -      runTest@gfx/layers/apz/test/mochitest/test_layerization.html:194:9
21:58:48     INFO -      driveTest@gfx/layers/apz/test/mochitest/test_layerization.html:217:13
21:58:48     INFO -      setTimeout handler*SimpleTest_setTimeoutShim@SimpleTest/SimpleTest.js:621:12
21:58:48     INFO -      runTest@gfx/layers/apz/test/mochitest/test_layerization.html:193:9
21:58:48     INFO -      driveTest@gfx/layers/apz/test/mochitest/test_layerization.html:217:13
21:58:48     INFO -      setTimeout handler*SimpleTest_setTimeoutShim@SimpleTest/SimpleTest.js:621:12
21:58:48     INFO -      flushApzRepaints/repaintDone@gfx/layers/apz/test/mochitest/apz_test_utils.js:90:5
21:58:48     INFO -  125 INFO TEST-FAIL | gfx/layers/apz/test/mochitest/test_layerization.html | The author of the test has indicated that flaky timeouts are expected.  Reason: we are testing code that measures an actual timeout
21:58:48     INFO -  126 INFO TEST-PASS | gfx/layers/apz/test/mochitest/test_layerization.html | expected at least one paint
21:58:48     INFO -  Not taking screenshot here: see the one that was previously logged
21:58:48     INFO -  127 INFO TEST-UNEXPECTED-FAIL | gfx/layers/apz/test/mochitest/test_layerization.html | outer3 is no longer layerized after inner3 triggered expiry
21:58:48     INFO -      runTest@gfx/layers/apz/test/mochitest/test_layerization.html:198:3
21:58:48     INFO -      driveTest@gfx/layers/apz/test/mochitest/test_layerization.html:217:13
21:58:48     INFO -      setTimeout handler*SimpleTest_setTimeoutShim@SimpleTest/SimpleTest.js:621:12
21:58:48     INFO -      callDriveTestAsync@gfx/layers/apz/test/mochitest/test_layerization.html:105:3
21:58:48     INFO -      waitForPaints@SimpleTest/paint_listener.js:73:5
21:58:48     INFO -      window.waitForAllPaints@SimpleTest/paint_listener.js:81:5
21:58:48     INFO -      runTest@gfx/layers/apz/test/mochitest/test_layerization.html:197:9
21:58:48     INFO -      driveTest@gfx/layers/apz/test/mochitest/test_layerization.html:217:13
21:58:48     INFO -      setTimeout handler*SimpleTest_setTimeoutShim@SimpleTest/SimpleTest.js:621:12
21:58:48     INFO -      runTest@gfx/layers/apz/test/mochitest/test_layerization.html:196:9
21:58:48     INFO -      driveTest@gfx/layers/apz/test/mochitest/test_layerization.html:217:13
21:58:48     INFO -      setTimeout handler*SimpleTest_setTimeoutShim@SimpleTest/SimpleTest.js:621:12
21:58:48     INFO -      callDriveTestAsync@gfx/layers/apz/test/mochitest/test_layerization.html:105:3
21:58:48     INFO -      waitForPaints@SimpleTest/paint_listener.js:73:5
21:58:48     INFO -      window.waitForAllPaints@SimpleTest/paint_listener.js:81:5
21:58:48     INFO -      runTest@gfx/layers/apz/test/mochitest/test_layerization.html:194:9
21:58:48     INFO -      driveTest@gfx/layers/apz/test/mochitest/test_layerization.html:217:13
21:58:48     INFO -      setTimeout handler*SimpleTest_setTimeoutShim@SimpleTest/SimpleTest.js:621:12
21:58:48     INFO -      runTest@gfx/layers/apz/test/mochitest/test_layerization.html:193:9
21:58:48     INFO -      driveTest@gfx/layers/apz/test/mochitest/test_layerization.html:217:13
21:58:48     INFO -      setTimeout handler*SimpleTest_setTimeoutShim@SimpleTest/SimpleTest.js:621:12
21:58:48     INFO -      flushApzRepaints/repaintDone@gfx/layers/apz/test/mochitest/apz_test_utils.js:90:5
21:58:48     INFO -  Flushed APZ repaints, waiting for callback...
Whiteboard: gfx-noted
Component: Graphics: Layers → Panning and Zooming
Version: Trunk → 48 Branch
Only one of these so far, on Linux debug. If it turns up more we can use rr chaos mode to try to repro.
OS: Unspecified → Linux
This appears to still be happening but at a very low volume (~twice a month?)
status-firefox49: --- → affected
I got an rr recording of this while trying to catch bug 1278009. I did a quick investigation - what's happening is that inner3 is getting unlayerized as expected, but then the child process gets another repaint request from the APZ (which must have been inflight during the expiry period), and re-layerizes inner3. The re-layerization happens while the test is in the setTimeout, so then when the test checks to see if inner3/outer3 are unlayerized, those checks fail.
This has spiked up significantly since the landing of bug 1289650.
Blocks: 1289650
status-firefox48: fix-optional → wontfix
status-firefox49: fix-optional → wontfix
status-firefox50: affected → fix-optional
status-firefox51: --- → affected
Priority: -- → P3
Summary: Intermittent test_layerization.html | inner3 becomes unlayerized after expiry | outer3 is no longer layerized after inner3 triggered expiry → Intermittent e10s test_layerization.html | inner3 becomes unlayerized after expiry | outer3 is no longer layerized after inner3 triggered expiry
Remove infra and things that are actually already fixed-or-disabled, and this is the 5th most frequent failure, and the 2nd most frequent that's just one test, so next time I feel the need to disable things for the benefit of the numb fingers on my right hand, this'll be among them.
This is next on my list of intermittents to fix now that I have the fix for bug 1263458 landed, since that one was more frequent than this one. But still, feel free to disable if your fingers need un-numbing before I figure out what's going on here.
Assignee: nobody → bugmail
tracking-e10s: --- → -
I investigated this a bit more. What's happening is that at [1] the flushApzRepaints call is supposed to delay the test code until after the scroll wheel above is fully processed, but that doesn't work. The flushApzRepaints call does follow the layer tree update that tells the compositor inner3 is layerized, but it sneaks in before the SetConfirmedTargetAPZC call which has to thread-shift in the compositor at [2].

So then the test continues into the setTimeout while the compositor is now processing the scroll wheel input after having gotten the confirmed target. The scroll results in a content repaint which then delays the displayport expiry until after the setTimeout expires, causing the test to fail.

[1] http://searchfox.org/mozilla-central/rev/f6c298b36db67a7109079c0dd7755f329c1d58e2/gfx/layers/apz/test/mochitest/test_layerization.html#155
[2] http://searchfox.org/mozilla-central/rev/f6c298b36db67a7109079c0dd7755f329c1d58e2/gfx/layers/ipc/CompositorBridgeParent.cpp#1704
Ironically this is a regression from bug 1246480, because before that landed we would wait for the scroll event and thus ensure that the input event was fully processed.
Blocks: 1246480
No longer blocks: 1289650
Comment on attachment 8792874 [details]
Bug 1256128 - Update test to handle a tricky race condition where the input event processing is delayed a little.

https://reviewboard.mozilla.org/r/79762/#review78806
Attachment #8792874 - Flags: review?(botond) → review+
Pushed by kgupta@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/26e0cc5ad055
Update test to handle a tricky race condition where the input event processing is delayed a little. r=botond
https://hg.mozilla.org/mozilla-central/rev/26e0cc5ad055
Status: NEW → RESOLVED
Closed: 8 years ago
status-firefox52: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → mozilla52
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: