1694876 - Perma Fission cross-origin TEST-UNEXPECTED-TIMEOUT | http://mochi.test:8888/tests/image/test/mochitest/test_discardFinishedAnimatedImage.html | application timed out after 370 seconds with no output

Status: RESOLVED WORKSFORME

(Core :: Graphics: ImageLib, defect)

Description

[Treeherder Bug Filer]

Filed by: cbrindusan [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=331141375&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/fAap0ZL8QsiqlbCW6CnYeA/runs/0/artifacts/public/logs/live_backing.log

---

[task 2021-02-25T05:00:37.099Z] 05:00:37     INFO - TEST-START | http://mochi.test:8888/tests/image/test/mochitest/test_discardFinishedAnimatedImage.html
[task 2021-02-25T05:00:37.179Z] 05:00:37     INFO - GECKO(9218) | [Child 10444, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/checkouts/gecko/xpcom/base/nsCycleCollector.cpp:3365
[task 2021-02-25T05:00:37.200Z] 05:00:37     INFO - GECKO(9218) | [Child 10444, Main Thread] WARNING: NS_ENSURE_TRUE(Preferences::InitStaticMembers()) failed: file /builds/worker/checkouts/gecko/modules/libpref/Preferences.cpp:4380
[task 2021-02-25T05:00:37.361Z] 05:00:37     INFO - GECKO(9218) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmpORBVN1.mozrunner/runtests_leaks_tab_pid10557.log
[task 2021-02-25T05:00:37.361Z] 05:00:37     INFO - GECKO(9218) | [10557, Main Thread] WARNING: XPCOM_MEM_BLOAT_LOG is set, disabling native allocations.: file /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp:251
[task 2021-02-25T05:00:37.502Z] 05:00:37     INFO - GECKO(9218) | [Child 10557, Main Thread] WARNING: could not set real-time limit in CubebUtils::InitLibrary: file /builds/worker/checkouts/gecko/dom/media/CubebUtils.cpp:619
[task 2021-02-25T05:05:05.178Z] 05:05:05     INFO - GECKO(9218) | 1614229505166	addons.xpi	ERROR	System addon update list error Error: got node name: html, expected: updates
[task 2021-02-25T05:05:43.021Z] 05:05:43     INFO - GECKO(9218) | JavaScript error: http://mochi.xorigin-test:8888/tests/SimpleTest/TestRunner.js, line 167: SecurityError: Permission denied to access property "wrappedJSObject" on cross-origin object
[task 2021-02-25T05:11:53.032Z] 05:11:53     INFO - Buffered messages finished
[task 2021-02-25T05:11:53.033Z] 05:11:53    ERROR - TEST-UNEXPECTED-TIMEOUT | http://mochi.test:8888/tests/image/test/mochitest/test_discardFinishedAnimatedImage.html | application timed out after 370 seconds with no output```

Comment 1

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 3

Platform and build breakdown:

• linux1804-64: 3
  • debug: 3

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1694876&startday=2021-02-22&endday=2021-02-28&tree=all

Comment 2

[Intermittent Failures Robot]

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

Repository breakdown:

• try: 2
• mozilla-central: 6

Platform and build breakdown:

• linux1804-64: 8
  • debug: 8

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1694876&startday=2021-03-01&endday=2021-03-07&tree=all

Comment 3

[Intermittent Failures Robot]

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

Repository breakdown:

• try: 7
• mozilla-central: 14

Platform and build breakdown:

• linux1804-64: 21
  • opt: 2
  • debug: 19

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1694876&startday=2021-03-08&endday=2021-03-14&tree=all

Comment 4

[Intermittent Failures Robot]

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

This is the #39 most frequent failure this week.

Repository breakdown:

• try: 9
• mozilla-central: 20

Platform and build breakdown:

• linux1804-64: 29
  • debug: 29

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1694876&startday=2021-03-15&endday=2021-03-21&tree=all

Comment 5

[Intermittent Failures Robot]

24 failures in 3967 pushes (0.006 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 20
• try: 4

Platform and build breakdown:

• linux1804-64: 24
  • debug: 24

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1694876&startday=2021-03-22&endday=2021-03-28&tree=all

Comment 6

[Chris Peterson [:cpeterson]]

Andrew, this test seems to be timing out a lot during mochitest-plain-fis-xorig-e10s tests, so this is either a Fission or xorigin issue. kmag says this test is waiting for a mozAfterPaint event that never arrives.

(kmag says the SecurityError: Permission denied to access property "wrappedJSObject" on cross-origin object error in the log is not related to this test failing and timing out. He will fix that SecurityError in bug 1701777.)

Do you think fixing this test needs to block expanding our Fission Beta experiment?

Comment 7

[Timothy Nikkel (:tnikkel)]

I've seen that SecurityError while writing apz tests in the x-origin tests, so that suggests that it is a general xorigin issue so I suspect that issue should be solved before we spend time looking at this from an imagelib perspective, or is there reason to believe otherwise?

Comment 8

[Intermittent Failures Robot]

19 failures in 3125 pushes (0.006 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• try: 2
• mozilla-central: 17

Platform and build breakdown:

• linux1804-64: 19
  • debug: 19

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1694876&startday=2021-03-29&endday=2021-04-04&tree=all

Comment 9

[Chris Peterson [:cpeterson]]

(In reply to Timothy Nikkel (:tnikkel) from comment #7)

I've seen that SecurityError while writing apz tests in the x-origin tests, so that suggests that it is a general xorigin issue so I suspect that issue should be solved before we spend time looking at this from an imagelib perspective, or is there reason to believe otherwise?

kmag says that SecurityError is unrelated to this test failing or timing out, since the test failure happens before the SecurityError. He will fix that SecurityError in bug 1701777.

Tentatively tracking for our current Fission Beta milestone, M7a. We need to determine whether this is a leak or not.

Comment 10

[Neha Kochar [:neha]]

aosmond said tnikkel would be a better match to look into this possible leak.

Comment 11

[Timothy Nikkel (:tnikkel)]

This is caused by https://hg.mozilla.org/integration/autoland/rev/d5b874ccd877

The test uses drawWindow, which can't use the retained display list, it destroys the retained display list, so the nsImageFrame for the image has mDisplayItems being empty (we only put items in mDisplayItems if we are retaining here https://searchfox.org/mozilla-central/rev/ee9dab6aa95f167a34cb178960f7375210a0bba4/layout/painting/nsDisplayList.h#2383 ). So then in nsIFrame::InvalidateFrameWithRect hasDisplayItem is false when we get the notification from the image that the next frame is ready to draw and invalidate. And so InvalidateFrameInternal does not schedule a paint, which means we never ask the image for the frame of the animation, imagelib assumes the image is not visible so it doesn't advance any further and the image stays red and doesn't advance, and the test times out.

Comment 12

[Miko Mynttinen]

(In reply to Timothy Nikkel (:tnikkel) from comment #11)

This is caused by https://hg.mozilla.org/integration/autoland/rev/d5b874ccd877

The test uses drawWindow, which can't use the retained display list, it destroys the retained display list, so the nsImageFrame for the image has mDisplayItems being empty (we only put items in mDisplayItems if we are retaining here https://searchfox.org/mozilla-central/rev/ee9dab6aa95f167a34cb178960f7375210a0bba4/layout/painting/nsDisplayList.h#2383 ). So then in nsIFrame::InvalidateFrameWithRect hasDisplayItem is false when we get the notification from the image that the next frame is ready to draw and invalidate. And so InvalidateFrameInternal does not schedule a paint, which means we never ask the image for the frame of the animation, imagelib assumes the image is not visible so it doesn't advance any further and the image stays red and doesn't advance, and the test times out.

Thank you, I can reproduce the issue, and indeed this seems to be the cause.

Comment 13

[Miko Mynttinen]

Attachment: Bug 1694876 - Always invalidate the frame and schedule a paint when nsImageFrame is invalidated r=tnikkel

Comment 14

[Miko Mynttinen]

This should get fixed when the backout of part 4 lands mozilla central.
https://hg.mozilla.org/integration/autoland/rev/2ed2319aa1d7eddd4448d88dc2bea5f3f013b2bc

Comment 15

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 16
• try: 4

Platform and build breakdown:

• linux1804-64: 20
  • debug: 20

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1694876&startday=2021-04-05&endday=2021-04-11&tree=all

Comment 16

[Miko Mynttinen]

Fixed by partial backout of bug 1526970.

Comment 17

[Intermittent Failures Robot]

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

Repository breakdown:

• try: 1

Platform and build breakdown:

• linux1804-64: 1
  • debug: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1694876&startday=2021-04-19&endday=2021-04-25&tree=all