1559570 - Intermittent gfx/layers/apz/test/mochitest/test_bug1151663.html | found the RCD node

Status: REOPENED

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

Description

[Treeherder Bug Filer]

Filed by: aciure [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=252011964&repo=autoland
Full log: https://queue.taskcluster.net/v1/task/EfLF6IdGRgy_jefYKH10YQ/runs/0/artifacts/public/logs/live_backing.log

---

[task 2019-06-15T06:52:36.839Z] 06:52:36 INFO - Buffered messages finished
[task 2019-06-15T06:52:36.839Z] 06:52:36 INFO - TEST-UNEXPECTED-FAIL | gfx/layers/apz/test/mochitest/test_bug1151663.html | found the RCD node
[task 2019-06-15T06:52:36.839Z] 06:52:36 INFO - SimpleTest.ok@SimpleTest/SimpleTest.js:275:18
[task 2019-06-15T06:52:36.839Z] 06:52:36 INFO - testBug1151663@gfx/layers/apz/test/mochitest/helper_bug1151663.html:51:18
[task 2019-06-15T06:52:36.839Z] 06:52:36 INFO - setTimeout handlerrepaintDone@gfx/layers/apz/test/mochitest/apz_test_utils.js:174:7
[task 2019-06-15T06:52:36.839Z] 06:52:36 INFO - GECKO(2911) | JavaScript error: http://mochi.test:8888/tests/gfx/layers/apz/test/mochitest/helper_bug1151663.html, line 52: TypeError: rcd is null
[task 2019-06-15T06:52:36.839Z] 06:52:36 INFO - GECKO(2911) | --DOMWINDOW == 14 (0x7f842a010800) [pid = 2911] [serial = 6] [outer = (nil)] [url = about:blank]
[task 2019-06-15T06:52:37.533Z] 06:52:37 INFO - GECKO(2911) | --DOMWINDOW == 9 (0x7f7daa1b6400) [pid = 3004] [serial = 6] [outer = (nil)] [url = about:blank]
[task 2019-06-15T06:52:37.533Z] 06:52:37 INFO - GECKO(2911) | --DOMWINDOW == 8 (0x7f7daaf9ec00) [pid = 3004] [serial = 3] [outer = (nil)] [url = about:blank]
[task 2019-06-15T06:52:41.153Z] 06:52:41 INFO - GECKO(2911) | --DOMWINDOW == 13 (0x7f8426d23800) [pid = 2911] [serial = 14] [outer = (nil)] [url = about:blank]
[task 2019-06-15T06:52:41.633Z] 06:52:41 INFO - GECKO(2911) | --DOMWINDOW == 7 (0x7f7daa1b6000) [pid = 3004] [serial = 10] [outer = (nil)] [url = about:blank]
[task 2019-06-15T06:52:41.634Z] 06:52:41 INFO - GECKO(2911) | --DOMWINDOW == 6 (0x7f7daa1b4c00) [pid = 3004] [serial = 7] [outer = (nil)] [url = about:blank]
[task 2019-06-15T06:52:42.160Z] 06:52:42 INFO - GECKO(2911) | --DOMWINDOW == 2 (0x7fda63803400) [pid = 3076] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2019-06-15T06:52:42.767Z] 06:52:42 INFO - GECKO(2911) | [Parent 2911, StreamTrans #5] WARNING: 'NS_FAILED(rv)', file /builds/worker/workspace/build/src/modules/libjar/nsJARChannel.cpp, line 371
[task 2019-06-15T06:52:42.768Z] 06:52:42 INFO - GECKO(2911) | [Parent 2911, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80520012: file /builds/worker/workspace/build/src/modules/libjar/nsJARChannel.cpp, line 994
[task 2019-06-15T06:58:01.796Z] 06:58:01 INFO - Not taking screenshot here: see the one that was previously logged
[task 2019-06-15T06:58:01.798Z] 06:58:01 INFO - TEST-UNEXPECTED-FAIL | gfx/layers/apz/test/mochitest/test_bug1151663.html | Test timed out.
[task 2019-06-15T06:58:01.798Z] 06:58:01 INFO - SimpleTest.ok@SimpleTest/SimpleTest.js:275:18
[task 2019-06-15T06:58:01.798Z] 06:58:01 INFO - reportError@SimpleTest/TestRunner.js:121:22
[task 2019-06-15T06:58:01.798Z] 06:58:01 INFO - TestRunner._checkForHangs@SimpleTest/TestRunner.js:142:7
[task 2019-06-15T06:58:01.799Z] 06:58:01 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
[task 2019-06-15T06:58:01.799Z] 06:58:01 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
[task 2019-06-15T06:58:01.799Z] 06:58:01 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
[task 2019-06-15T06:58:01.799Z] 06:58:01 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
[task 2019-06-15T06:58:01.799Z] 06:58:01 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
[task 2019-06-15T06:58:01.800Z] 06:58:01 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
[task 2019-06-15T06:58:01.800Z] 06:58:01 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
[task 2019-06-15T06:58:01.800Z] 06:58:01 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
[task 2019-06-15T06:58:01.800Z] 06:58:01 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
[task 2019-06-15T06:58:01.800Z] 06:58:01 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
[task 2019-06-15T06:58:01.800Z] 06:58:01 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
[task 2019-06-15T06:58:01.801Z] 06:58:01 INFO - TestRunner.runTests/<@SimpleTest/TestRunner.js:381:20
[task 2019-06-15T06:58:01.801Z] 06:58:01 INFO - promise callbackTestRunner.runTests@SimpleTest/TestRunner.js:368:50
[task 2019-06-15T06:58:01.801Z] 06:58:01 INFO - RunSet.runtests@SimpleTest/setup.js:201:14
[task 2019-06-15T06:58:01.802Z] 06:58:01 INFO - RunSet.runall@SimpleTest/setup.js:180:12
[task 2019-06-15T06:58:01.802Z] 06:58:01 INFO - hookupTests@SimpleTest/setup.js:273:12
[task 2019-06-15T06:58:01.802Z] 06:58:01 INFO - parseTestManifest@http://mochi.test:8888/manifestLibrary.js:36:5
[task 2019-06-15T06:58:01.802Z] 06:58:01 INFO - getTestManifest/req.onload@http://mochi.test:8888/manifestLibrary.js:49:11
[task 2019-06-15T06:58:01.803Z] 06:58:01 INFO - EventHandlerNonNullgetTestManifest@http://mochi.test:8888/manifestLibrary.js:45:3

Comment 1

[Intermittent Failures Robot]

44 failures in 228 pushes (0.193 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 22
• mozilla-central: 12
• mozilla-inbound: 7
• try: 3

Platform breakdown:

• linux64-qr: 27
• linux64-shippable-qr: 17

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1559570&startday=2019-06-15&endday=2019-06-15&tree=all

Comment 2

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

https://treeherder.mozilla.org/#/jobs?repo=autoland&searchStr=linux%2Cx64%2Cquantumrender%2Cdebug%2Cmochitests%2Ctest-linux64-qr%2Fdebug-mochitest-e10s-12%2Cm%2812%29&tochange=d82fddfaec911b800f754083eaba96da06f14f62&fromchange=da58eb922ff22ba6fefbdb40fa51d3c551092191&group_state=expanded&selectedJob=252009953

I kicked off some more retriggers but it looks like maybe it was caused by bug 1558442.

Comment 3

[Emilio Cobos Álvarez (:emilio)]

Hmm, so that test doesn't seem to have any style change whatsoever, so it's unclear to me how that patch should cause it... I guess the RCD node stands for root content document?

Comment 4

[Andreea Pavel [:apavel]]

Retriggers: https://treeherder.mozilla.org/#/jobs?repo=autoland&selectedJob=252009953&searchStr=linux%2Cx64%2Cquantumrender%2Cdebug%2Cmochitests%2Ctest-linux64-qr%2Fdebug-mochitest-e10s-12%2Cm%2812%29&tochange=d82fddfaec911b800f754083eaba96da06f14f62&fromchange=da58eb922ff22ba6fefbdb40fa51d3c551092191

Hi Emilio. At this rate the test will soon reach the disable recommended queue, are you working on a fix or should I ni someone else?

Comment 5

[Emilio Cobos Álvarez (:emilio)]

I'm not working on this because I don't really know how my patch could've caused it. My patch at best makes some reflows faster, but I don't possibly know how could it affect this.

Kats, am I looking at the right thing? I don't see any dynamic style change in that subtest (nor anything non-statically positioned really, either in the test or in the window it opens).

Is it possible that waitForApzStable is not waiting for the right thing? That waits only for one window, afaict. Also, I think given we don't allow duplicate message listeners, if two different tests are waiting for APZ one of them may get the event too soon and deregister too early... Though I guess that may not happen since before doing that we're waiting for the window to get focus...

Comment 6

[Emilio Cobos Álvarez (:emilio)]

Also, Andreea, do you know if this happens only on WebRender? Or does the failure happen on other platforms?

Comment 7

[Andreea Pavel [:apavel]]

Yes, this occurs only on webrender: https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?startday=2019-06-09&endday=2019-06-16&tree=trunk&bug=1559570

Comment 8

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

Would your change have affected this: https://searchfox.org/mozilla-central/rev/e42e1a1be58abbd81efd8d78d6d0699979f43138/gfx/layers/apz/test/mochitest/apz_test_utils.js#452

Comment 9

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

I'm guessing yes, that's the problem: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=252131533&repo=try&lineNumber=390313

Is there some change we can make to that helper to force a full flush/repaint?

Comment 10

[Emilio Cobos Álvarez (:emilio)]

Yes, it is indeed... We can probably modify box-sizing or something to cause the same kind of flush that this was causing...

Do you know exactly which part of the layout flush is this code is relying on? My code should still cause a layout flush, just a smaller reflow scoped to the body rather than a full reflow. It'd be great to make it a bit less footgunny :)

Comment 11

[Emilio Cobos Álvarez (:emilio)]

Attachment: Bug 1559570 - Use a different style change to trigger AllReflowHints for now. r=kats

box-sizing changes seem a bit less likely to be optimized away in the near
future...

Comment 12

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

(In reply to Emilio Cobos Álvarez (:emilio) from comment #10)

Yes, it is indeed... We can probably modify box-sizing or something to cause the same kind of flush that this was causing...

SGTM, will r+ your patch in a sec.

Do you know exactly which part of the layout flush is this code is relying on? My code should still cause a layout flush, just a smaller reflow scoped to the body rather than a full reflow. It'd be great to make it a bit less footgunny :)

We really just need to force a repaint here, so that an updated layer tree gets sent to the compositor. I think I copy/pasted this code from elsewhere and don't have a great understanding of the layout flush mechanics involved, just that it seemed to do what we wanted.

Comment 13

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/5c58b5952441
Use a different style change to trigger AllReflowHints for now. r=kats

Comment 14

[Intermittent Failures Robot]

69 failures in 4753 pushes (0.015 failures/push) were associated with this bug in the last 7 days.

This is the #25 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: 30
• mozilla-central: 22
• mozilla-inbound: 14
• try: 3

Platform breakdown:

• linux64-qr: 40
• linux64-shippable-qr: 29

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1559570&startday=2019-06-10&endday=2019-06-16&tree=all

Comment 15

[Alexandru Michis [:malexandru]]

https://hg.mozilla.org/mozilla-central/rev/5c58b5952441

Comment 16

[Razvan Maries]

New occurrence on Beta simulation: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=252622584&repo=try&lineNumber=5739

Comment 17

[Intermittent Failures Robot]

4 failures in 2581 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-inbound: 3
• try: 1

Platform breakdown:

• linux64-qr: 1
• linux64-shippable-qr: 1
• macosx1010-64-shippable: 1
• macosx1010-64-devedition: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1559570&startday=2019-06-17&endday=2019-06-23&tree=all

Comment 18

[Andreea Pavel [:apavel]]

Emilio this is still failing https://treeherder.mozilla.org/logviewer.html#?job_id=253342373&repo=autoland

Comment 19

[Emilio Cobos Álvarez (:emilio)]

It looks like the frequency is much lower now though, right?

I don't really have better ideas to change it to be even more reliable without invalidating the world... Kats, is doing a proper repaint (i.e., changing a color property or background) something to avoid here? Or should we do that?

Comment 20

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

Doing that is fine, if it will force a proper repaint and send the full layer tree over.

Comment 21

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 1
• mozilla-central: 2
• mozilla-inbound: 1
• try: 1

Platform breakdown:

• macosx1010-64: 1
• macosx1010-64-shippable: 3
• macosx1010-64-devedition: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1559570&startday=2019-06-24&endday=2019-06-30&tree=all

Comment 22

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 2
• mozilla-central: 1

Platform breakdown:

• macosx1014-64: 1
• macosx1010-64-shippable: 1
• macosx1014-64-shippable: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1559570&startday=2019-07-01&endday=2019-07-07&tree=all

Comment 23

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 2

Platform breakdown:

• macosx1014-64: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1559570&startday=2019-07-08&endday=2019-07-14&tree=all

Comment 24

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

All the recent failures are on macOS without WebRender enabled. Not sure if it's the same problem as what Emilio's patch fixed. In theory it might be a similar thing, or it might be a different regression.

Comment 25

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 4

Platform breakdown:

• macosx1014-64: 4

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1559570&startday=2019-07-15&endday=2019-07-21&tree=all

Comment 26

[Intermittent Failures Robot]

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

Repository breakdown:

• try: 1
• autoland: 2
• mozilla-inbound: 2

Platform breakdown:

• macosx1014-64-devedition: 1
• macosx1014-64: 2
• macosx1014-64-shippable: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1559570&startday=2019-07-22&endday=2019-07-28&tree=all

Comment 27

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 1
• mozilla-inbound: 1

Platform breakdown:

• macosx1014-64: 1
• macosx1014-64-shippable: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1559570&startday=2019-07-29&endday=2019-08-04&tree=all

Comment 28

[Intermittent Failures Robot]

8 failures in 4666 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 7
• mozilla-central: 1

Platform breakdown:

• macosx1014-64: 6
• macosx1014-64-shippable: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1559570&startday=2019-08-05&endday=2019-08-11&tree=all

Comment 29

[Intermittent Failures Robot]

8 failures in 4839 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 6
• mozilla-beta: 1
• mozilla-inbound: 1

Platform breakdown:

• macosx1014-64-shippable: 3
• macosx1014-64: 5

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1559570&startday=2019-08-12&endday=2019-08-18&tree=all

Comment 30

[Botond Ballo [:botond]]

Removing "regression" keyword from APZ intermittents for reasons laid out in bug 1571054 comment 0.

Comment 31

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 4
• mozilla-inbound: 2

Platform breakdown:

• macosx1014-64: 3
• macosx1014-64-shippable: 3

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1559570&startday=2019-08-19&endday=2019-08-25&tree=all

Comment 32

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 1

Platform breakdown:

• macosx1014-64-shippable: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1559570&startday=2020-02-03&endday=2020-02-09&tree=all

Comment 33

[Intermittent Failures Robot]

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

Repository breakdown:

• try: 1

Platform breakdown:

• linux1804-64-shippable: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1559570&startday=2020-04-13&endday=2020-04-19&tree=all