Open Bug 1354561 Opened 3 years ago Updated 2 months ago

Intermittent test_animSVGImage2.html | timing out after 120000ms. Animated image still doesn't look correct, after call #1 to myOnFrameUpdate

Categories

(Core :: ImageLib, defect)

defect
Not set

Tracking

()

REOPENED

People

(Reporter: intermittent-bug-filer, Unassigned)

References

(Blocks 1 open bug)

Details

(Keywords: intermittent-failure, leave-open, Whiteboard: [stockwell disabled])

Attachments

(2 files)

Duplicate of this bug: 1354760
Summary: Intermittent image/test/mochitest/test_animSVGImage2.html | timing out after 120000ms. Animated image still doesn't look correct, after call #1 to myOnFrameUpdate → Intermittent test_animSVGImage2.html | timing out after 120000ms. Animated image still doesn't look correct, after call #1 to myOnFrameUpdate
https://wiki.mozilla.org/Bugmasters#Intermittent_Test_Failure_Cleanup
Status: NEW → RESOLVED
Closed: 2 years ago
Resolution: --- → INCOMPLETE
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
Status: REOPENED → RESOLVED
Closed: 2 years ago2 years ago
Resolution: --- → INCOMPLETE
Recent failure log: https://treeherder.mozilla.org/logviewer.html#?job_id=169019795&repo=autoland&lineNumber=6924

20:43:43     INFO -  1175 INFO TEST-START | image/test/mochitest/test_ImageContentLoaded.html
20:43:44     INFO -  GECKO(3056) | MEMORY STAT | vsize 457MB | vsizeMaxContiguous 779MB | residentFast 67MB | heapAllocated 15MB
20:43:44     INFO -  1176 INFO TEST-OK | image/test/mochitest/test_ImageContentLoaded.html | took 1130ms
20:43:44     INFO -  1177 INFO TEST-START | image/test/mochitest/test_animSVGImage2.html
20:45:44     INFO -  TEST-INFO | started process screenshot
20:45:44     INFO -  TEST-INFO | screenshot: exit 0
20:45:44     INFO -  Buffered messages logged at 20:43:44
20:45:44     INFO -  1178 INFO TEST-PASS | image/test/mochitest/test_animSVGImage2.html | A valid string reason is expected
20:45:44     INFO -  1179 INFO TEST-PASS | image/test/mochitest/test_animSVGImage2.html | Reason cannot be empty
20:45:44     INFO -  1180 INFO TEST-PASS | image/test/mochitest/test_animSVGImage2.html | reference snapshot shouldn't match blank page snapshot
20:45:44     INFO -  1181 INFO TEST-PASS | image/test/mochitest/test_animSVGImage2.html | reference div should disappear when it becomes display:none
20:45:44     INFO -  1182 INFO TEST-FAIL | image/test/mochitest/test_animSVGImage2.html | The author of the test has indicated that flaky timeouts are expected.  Reason: Early failure timeout
20:45:44     INFO -  1183 INFO TEST-PASS | image/test/mochitest/test_animSVGImage2.html | myOnFrameUpdate called
20:45:44     INFO -  Buffered messages finished
20:45:44    ERROR -  1184 INFO TEST-UNEXPECTED-FAIL | image/test/mochitest/test_animSVGImage2.html | timing out after 120000ms.  Animated image still doesn't look correct, after call #1 to myOnFrameUpdate
20:45:44     INFO -      failTest@image/test/mochitest/test_animSVGImage2.html:77:3
20:45:44     INFO -      setTimeout handler*SimpleTest_setTimeoutShim@SimpleTest/SimpleTest.js:676:12
20:45:44     INFO -      main@image/test/mochitest/test_animSVGImage2.html:116:3
20:45:44     INFO -      EventHandlerNonNull*@image/test/mochitest/test_animSVGImage2.html:119:1
20:45:44     INFO -  GECKO(3056) | MEMORY STAT | vsize 462MB | vsizeMaxContiguous 771MB | residentFast 70MB | heapAllocated 11MB
20:45:44     INFO -  1185 INFO TEST-OK | image/test/mochitest/test_animSVGImage2.html | took 120072ms
20:45:44     INFO -  1186 INFO TEST-START | image/test/mochitest/test_animation.html
20:45:44     INFO -  GECKO(3056) | MEMORY STAT | vsize 467MB | vsizeMaxContiguous 767MB | residentFast 76MB | heapAllocated 16MB
20:45:44     INFO -  1187 INFO TEST-OK | image/test/mochitest/test_animation.html | took 262ms
20:45:44     INFO -  1188 INFO TEST-START | image/test/mochitest/test_animation2.html
20:45:44     INFO -  GECKO(3056) | MEMORY STAT | vsize 474MB | vsizeMaxContiguous 760MB | residentFast 81MB | heapAllocated 20MB
20:45:44     INFO -  1189 INFO TEST-OK | image/test/mochitest/test_animation2.html | took 124ms
20:45:44     INFO -  1190 INFO TEST-START | image/test/mochitest/test_animation_operators.html
20:45:44     INFO -  GECKO(3056) | JavaScript error: , line 0: TypeError: can't access dead object
20:45:45     INFO -  GECKO(3056) | JavaScript error: , line 0: TypeError: can't access dead object
20:45:45     INFO -  GECKO(3056) | JavaScript error: , line 0: TypeError: can't access dead object
20:45:45     INFO -  GECKO(3056) | JavaScript error: , line 0: TypeError: can't access dead object
20:45:45     INFO -  GECKO(3056) | JavaScript error: , line 0: TypeError: can't access dead object
20:45:45     INFO -  GECKO(3056) | JavaScript error: , line 0: TypeError: can't access dead object
20:45:45     INFO -  GECKO(3056) | JavaScript error: , line 0: TypeError: can't access dead object
20:45:45     INFO -  GECKO(3056) | JavaScript error: , line 0: TypeError: can't access dead object
20:45:45     INFO -  GECKO(3056) | JavaScript error: , line 0: TypeError: can't access dead object
20:45:45     INFO -  GECKO(3056) | JavaScript error: , line 0: TypeError: can't access dead object
20:45:45     INFO -  GECKO(3056) | JavaScript error: , line 0: TypeError: can't access dead object
20:45:45     INFO -  GECKO(3056) | JavaScript error: , line 0: TypeError: can't access dead object
20:45:45     INFO -  GECKO(3056) | JavaScript error: , line 0: TypeError: can't access dead object
20:45:45     INFO -  GECKO(3056) | JavaScript error: , line 0: TypeError: can't access dead object
20:45:45     INFO -  GECKO(3056) | JavaScript error: , line 0: TypeError: can't access dead object
20:45:45     INFO -  GECKO(3056) | JavaScript error: , line 0: TypeError: can't access dead object
20:45:45     INFO -  GECKO(3056) | JavaScript error: , line 0: TypeError: can't access dead object
20:45:45     INFO -  GECKO(3056) | JavaScript error: , line 0: TypeError: can't access dead object
20:45:45     INFO -  GECKO(3056) | JavaScript error: , line 0: TypeError: can't access dead object
20:45:45     INFO -  GECKO(3056) | JavaScript error: , line 0: TypeError: can't access dead object
20:45:45     INFO -  GECKO(3056) | MEMORY STAT | vsize 478MB | vsizeMaxContiguous 760MB | residentFast 92MB | heapAllocated 28MB
20:45:45     INFO -  1191 INFO TEST-OK | image/test/mochitest/test_animation_operators.html | took 504ms
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
Status: REOPENED → RESOLVED
Closed: 2 years ago2 years ago
Resolution: --- → INCOMPLETE
Recent failure log: https://treeherder.mozilla.org/logviewer.html#?job_id=179842554&repo=try&lineNumber=6804

[task 2018-05-23T16:19:14.330Z] 16:19:14     INFO - TEST-START | gfx/layers/apz/test/mochitest/test_bug1277814.html
[task 2018-05-23T16:19:14.440Z] 16:19:14     INFO - GECKO(5781) | Parent process: flushed APZ repaints, waiting for callback...
[task 2018-05-23T16:19:14.557Z] 16:19:14     INFO - GECKO(5781) | Flushed APZ repaints, waiting for callback...
[task 2018-05-23T16:19:16.008Z] 16:19:16     INFO - GECKO(5781) | Flushed APZ repaints, waiting for callback...
[task 2018-05-23T16:24:41.647Z] 16:24:41     INFO - TEST-INFO | started process screentopng
[task 2018-05-23T16:24:41.933Z] 16:24:41     INFO - TEST-INFO | screentopng: exit 0
[task 2018-05-23T16:24:41.935Z] 16:24:41     INFO - TEST-UNEXPECTED-FAIL | gfx/layers/apz/test/mochitest/test_bug1277814.html | Test timed out. 
[task 2018-05-23T16:24:41.936Z] 16:24:41     INFO -     reportError@SimpleTest/TestRunner.js:121:7
[task 2018-05-23T16:24:41.936Z] 16:24:41     INFO -     TestRunner._checkForHangs@SimpleTest/TestRunner.js:142:7
[task 2018-05-23T16:24:42.644Z] 16:24:42     INFO - GECKO(5781) | MEMORY STAT | vsize 1574MB | residentFast 117MB | heapAllocated 21MB
[task 2018-05-23T16:24:42.656Z] 16:24:42     INFO - TEST-OK | gfx/layers/apz/test/mochitest/test_bug1277814.html | took 328323ms
[task 2018-05-23T16:24:42.700Z] 16:24:42     INFO - TEST-START | gfx/layers/apz/test/mochitest/test_bug1304689-2.html
[task 2018-05-23T16:24:42.881Z] 16:24:42     INFO - GECKO(5781) | Parent process: flushed APZ repaints, waiting for callback...
[task 2018-05-23T16:24:43.901Z] 16:24:43     INFO - GECKO(5781) | Flushed APZ repaints, waiting for callback...
[task 2018-05-23T16:24:44.305Z] 16:24:44     INFO - GECKO(5781) | Flushed APZ repaints, waiting for callback...
[task 2018-05-23T16:24:45.049Z] 16:24:45     INFO - GECKO(5781) | Flushed APZ repaints, waiting for callback...
[task 2018-05-23T16:24:45.050Z] 16:24:45     INFO - GECKO(5781) | MEMORY STAT | vsize 1574MB | residentFast 118MB | heapAllocated 21MB
[task 2018-05-23T16:24:45.052Z] 16:24:45     INFO - TEST-OK | gfx/layers/apz/test/mochitest/test_bug1304689-2.html | took 2357ms
[task 2018-05-23T16:24:45.073Z] 16:24:45     INFO - TEST-START | gfx/layers/apz/test/mochitest/test_bug1304689.html
[task 2018-05-23T16:24:45.198Z] 16:24:45     INFO - GECKO(5781) | Parent process: flushed APZ repaints, waiting for callback...
[task 2018-05-23T16:24:45.307Z] 16:24:45     INFO - GECKO(5781) | Flushed APZ repaints, waiting for callback...
[task 2018-05-23T16:24:45.404Z] 16:24:45     INFO - GECKO(5781) | Flushed APZ repaints, waiting for callback...
[task 2018-05-23T16:24:46.173Z] 16:24:46     INFO - GECKO(5781) | Flushed APZ repaints, waiting for callback...
[task 2018-05-23T16:24:46.181Z] 16:24:46     INFO - GECKO(5781) | MEMORY STAT | vsize 1574MB | residentFast 118MB | heapAllocated 21MB
[task 2018-05-23T16:24:46.199Z] 16:24:46     INFO - TEST-OK | gfx/layers/apz/test/mochitest/test_bug1304689.html | took 1118ms
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
In the last 7 days, there are 30 failures on this bug.
They occur on windows10-64-qr (opt).
Recent failure log: https://treeherder.mozilla.org/logviewer.html#?job_id=182874492&repo=mozilla-central&lineNumber=7093
23:42:30     INFO -  1187 INFO TEST-START | image/test/mochitest/test_animSVGImage2.html
23:42:30     INFO -  GECKO(3628) | WARN: rx::HLSLCompiler::compileToBinary(228):
23:42:30     INFO -  GECKO(3628) | C:\fakepath(649,20-34): warning X3556: integer modulus may be much slower, try using uints if possible.
23:42:30     INFO -  GECKO(3628) | C:\fakepath(649,39-53): warning X3556: integer divides may be much slower, try using uints if possible.
23:44:30     INFO -  TEST-INFO | started process screenshot
23:44:30     INFO -  TEST-INFO | screenshot: exit 0
23:44:30     INFO -  Buffered messages logged at 23:42:30
23:44:30     INFO -  1188 INFO TEST-PASS | image/test/mochitest/test_animSVGImage2.html | A valid string reason is expected
23:44:30     INFO -  1189 INFO TEST-PASS | image/test/mochitest/test_animSVGImage2.html | Reason cannot be empty
23:44:30     INFO -  1190 INFO TEST-PASS | image/test/mochitest/test_animSVGImage2.html | reference snapshot shouldn't match blank page snapshot
23:44:30     INFO -  1191 INFO TEST-PASS | image/test/mochitest/test_animSVGImage2.html | reference div should disappear when it becomes display:none
23:44:30     INFO -  1192 INFO TEST-FAIL | image/test/mochitest/test_animSVGImage2.html | The author of the test has indicated that flaky timeouts are expected.  Reason: Early failure timeout
23:44:30     INFO -  1193 INFO TEST-PASS | image/test/mochitest/test_animSVGImage2.html | myOnFrameUpdate called
23:44:30     INFO -  Buffered messages finished
23:44:30    ERROR -  1194 INFO TEST-UNEXPECTED-FAIL | image/test/mochitest/test_animSVGImage2.html | timing out after 120000ms.  Animated image still doesn't look correct, after call #1 to myOnFrameUpdate
23:44:30     INFO -      failTest@image/test/mochitest/test_animSVGImage2.html:77:3
23:44:30     INFO -      setTimeout handler*SimpleTest_setTimeoutShim@SimpleTest/SimpleTest.js:676:12
23:44:30     INFO -      main@image/test/mochitest/test_animSVGImage2.html:116:3
23:44:30     INFO -      EventHandlerNonNull*@image/test/mochitest/test_animSVGImage2.html:119:1
23:44:30     INFO -  GECKO(3628) | MEMORY STAT | vsize 2098640MB | vsizeMaxContiguous 129654780MB | residentFast 82MB | heapAllocated 10MB
23:44:30     INFO -  1195 INFO TEST-OK | image/test/mochitest/test_animSVGImage2.html | took 120155ms
:aosmond, can you have a look at this?
Flags: needinfo?(aosmond)
Update: there were 30 failures in the last 7 days: 29 failures on Windows 10x64 QR and 1 on Linux 32.
This bug failed 33 times in the last 7 days. Failures happen only on windows10-64-qr on opt build types.

Log:
https://treeherder.mozilla.org/logviewer.html#?job_id=190473493&repo=mozilla-inbound&lineNumber=7334

1215 INFO TEST-PASS | image/test/mochitest/test_animSVGImage2.html | myOnFrameUpdate called
10:09:10     INFO -  Buffered messages finished
10:09:10    ERROR -  1216 INFO TEST-UNEXPECTED-FAIL | image/test/mochitest/test_animSVGImage2.html | timing out after 120000ms.  Animated image still doesn't look correct, after call #1 to myOnFrameUpdate
10:09:10     INFO -      failTest@image/test/mochitest/test_animSVGImage2.html:77:3
10:09:10     INFO -      setTimeout handler*SimpleTest_setTimeoutShim@SimpleTest/SimpleTest.js:676:12
10:09:10     INFO -      main@image/test/mochitest/test_animSVGImage2.html:116:3
10:09:10     INFO -      EventHandlerNonNull*@image/test/mochitest/test_animSVGImage2.html:119:1
10:09:10     INFO -  GECKO(8792) | MEMORY STAT | vsize 1482MB | vsizeMaxContiguous 131115135MB | residentFast 76MB | heapAllocated 12MB
10:09:10     INFO -  1217 INFO TEST-OK | image/test/mochitest/test_animSVGImage2.html | took 120197ms

:aosmond:

Can you please take a look at this?
Whiteboard: [stockwell unknown] → [stockwell needswork]
In the past 7 days we had 61 failures, all on windows10-64-qr opt build type.

:aosmond Can you please take a look at this issue?
aosmond:

Hi,

Have you had a chance to take a look at this bug yet?
Please take a look over this. Thanks.
Attachment #9000157 - Flags: review?(jmaher)
Comment on attachment 9000157 [details] [diff] [review]
Disable on windows webrender

Review of attachment 9000157 [details] [diff] [review]:
-----------------------------------------------------------------

looks good
Attachment #9000157 - Flags: review?(jmaher) → review+
Whiteboard: [stockwell disable-recommended] → [stockwell disabled]
Pushed by cbrindusan@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/2852ef022080
Disable test_animSVGImage2.html on windows webrender for frequent failures. r=jmaher
Keywords: checkin-needed
I wonder if the problem is that FRAME_UPDATE doesn't guarantee it was repainted yet and we don't do anything when we take the screenshot to ensure it has happened.

In the last 7 days there have been 50 occurrences all on Linux64 QR build type Opt.

Whiteboard: [stockwell disabled] → [stockwell disabled][stockwell needswork]
Whiteboard: [stockwell disabled][stockwell needswork] → [stockwell needswork]

Created a patch in case we decide to disable this test. There are 99 failures in the last 21 days, on linux64-qr.

Attachment #9036860 - Flags: review?(jmaher)
Comment on attachment 9036860 [details] [diff] [review]
Skipped test on linux qr

Review of attachment 9036860 [details] [diff] [review]:
-----------------------------------------------------------------

70 failures on linux-qr in the last week == ready to disable.
Attachment #9036860 - Flags: review?(jmaher) → review+
Keywords: checkin-needed
Whiteboard: [stockwell needswork:owner] → [stockwell disabled]

Pushed by rmaries@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/ed01030dd8ad
Disable test_animSVGImage2.html on linux qr for frequent failures. r=jmaher

Keywords: checkin-needed
Flags: needinfo?(aosmond)
You need to log in before you can comment on or make changes to this bug.