Closed Bug 1470808 Opened 7 years ago Closed 7 years ago

Intermittent image/test/reftest/gif/truncated-framerect.html | application timed out after 370 seconds with no output

Categories

(Core :: Graphics: ImageLib, defect, P5)

Product:
Core
Component:
Graphics: ImageLib
Type:
defect

Tracking

()

Status:
RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: intermittent-failure)

Filed by: apavel [at] mozilla.com https://treeherder.mozilla.org/logviewer.html#?job_id=184599920&repo=try https://queue.taskcluster.net/v1/task/QNMf_gmERAqFlUUB6lFFbw/runs/0/artifacts/public/logs/live_backing.log https://hg.mozilla.org/mozilla-central/raw-file/tip/layout/tools/reftest/reftest-analyzer.xhtml#logurl=https://queue.taskcluster.net/v1/task/QNMf_gmERAqFlUUB6lFFbw/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1 Central as Beta simulation: [task 2018-06-24T15:49:41.915Z] 15:49:41 INFO - REFTEST TEST-START | file:///builds/worker/workspace/build/tests/reftest/tests/image/test/reftest/gif/truncated-framerect.html == file:///builds/worker/workspace/build/tests/reftest/tests/image/test/reftest/gif/truncated-framerect-ref.html [task 2018-06-24T15:49:41.915Z] 15:49:41 INFO - REFTEST TEST-LOAD | file:///builds/worker/workspace/build/tests/reftest/tests/image/test/reftest/gif/truncated-framerect.html | 10 / 11 (90%) [task 2018-06-24T15:49:42.018Z] 15:49:42 INFO - REFTEST TEST-LOAD | file:///builds/worker/workspace/build/tests/reftest/tests/image/test/reftest/gif/truncated-framerect-ref.html | 10 / 11 (90%) [task 2018-06-24T15:49:42.097Z] 15:49:42 INFO - REFTEST TEST-PASS | file:///builds/worker/workspace/build/tests/reftest/tests/image/test/reftest/gif/truncated-framerect.html == file:///builds/worker/workspace/build/tests/reftest/tests/image/test/reftest/gif/truncated-framerect-ref.html | image comparison, max difference: 0, number of differing pixels: 0 [task 2018-06-24T15:49:42.097Z] 15:49:42 INFO - REFTEST TEST-END | file:///builds/worker/workspace/build/tests/reftest/tests/image/test/reftest/gif/truncated-framerect.html == file:///builds/worker/workspace/build/tests/reftest/tests/image/test/reftest/gif/truncated-framerect-ref.html [task 2018-06-24T15:49:42.122Z] 15:49:42 INFO - REFTEST INFO | Slowest test took 654ms (file:///builds/worker/workspace/build/tests/reftest/tests/image/test/reftest/gif/delaytest.html?transparent-animation.gif) [task 2018-06-24T15:49:42.122Z] 15:49:42 INFO - REFTEST INFO | Total canvas count = 2 [task 2018-06-24T15:49:42.401Z] 15:49:42 INFO - JavaScript error: chrome://reftest/content/reftest.jsm, line 1536: NS_ERROR_NOT_AVAILABLE: Component returned failure code: 0x80040111 (NS_ERROR_NOT_AVAILABLE) [nsIPropertyBag2.getPropertyAsAString] [task 2018-06-24T15:49:42.451Z] 15:49:42 INFO - JavaScript error: chrome://reftest/content/reftest.jsm, line 1536: NS_ERROR_NOT_AVAILABLE: Component returned failure code: 0x80040111 (NS_ERROR_NOT_AVAILABLE) [nsIPropertyBag2.getPropertyAsAString] [task 2018-06-24T15:49:43.116Z] 15:49:43 INFO - 1529855383084 Marionette DEBUG Received observer notification xpcom-will-shutdown [task 2018-06-24T15:49:43.117Z] 15:49:43 INFO - 1529855383085 Marionette INFO Stopped listening on port 2828 [task 2018-06-24T15:49:43.118Z] 15:49:43 INFO - 1529855383085 Marionette DEBUG Remote service is inactive [task 2018-06-24T15:49:43.801Z] 15:49:43 INFO - REFTEST INFO | Process mode: e10s [task 2018-06-24T15:49:43.802Z] 15:49:43 WARNING - leakcheck | refcount logging is off, so leaks can't be detected! [task 2018-06-24T15:49:43.802Z] 15:49:43 INFO - REFTEST INFO | Running tests in file:///builds/worker/workspace/build/tests/reftest/tests/layout/reftests/cssom/reftest.list [task 2018-06-24T15:49:43.960Z] 15:49:43 INFO - REFTEST INFO | INFO | runtests.py | ASan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer [task 2018-06-24T15:49:43.969Z] 15:49:43 INFO - REFTEST INFO | INFO | runtests.py | ASan running in default memory configuration [task 2018-06-24T15:49:43.971Z] 15:49:43 INFO - REFTEST INFO | Running with e10s: True [task 2018-06-24T15:49:43.972Z] 15:49:43 INFO - REFTEST INFO | Application command: /builds/worker/workspace/build/application/firefox/firefox -marionette -profile /tmp/tmp__hPz1.mozrunner [task 2018-06-24T15:49:46.087Z] 15:49:46 INFO - 1529855386081 Marionette DEBUG Received observer notification profile-after-change [task 2018-06-24T15:49:46.184Z] 15:49:46 INFO - ATTENTION: default value of option force_s3tc_enable overridden by environment. [task 2018-06-24T15:49:46.253Z] 15:49:46 INFO - 1529855386248 Marionette DEBUG Received observer notification command-line-startup [task 2018-06-24T15:49:46.255Z] 15:49:46 INFO - 1529855386249 Marionette DEBUG Received observer notification nsPref:changed [task 2018-06-24T15:49:46.257Z] 15:49:46 INFO - 1529855386249 Marionette DEBUG Init aborted (running=false, enabled=true, finalUIStartup=false) [task 2018-06-24T15:49:50.133Z] 15:49:50 INFO - 1529855390127 Marionette DEBUG Received observer notification sessionstore-windows-restored [task 2018-06-24T15:49:50.135Z] 15:49:50 INFO - 1529855390128 Marionette DEBUG Waiting for delayed startup... [task 2018-06-24T15:49:51.734Z] 15:49:51 INFO - 1529855391730 Marionette INFO Listening on port 2828 [task 2018-06-24T15:49:51.736Z] 15:49:51 INFO - 1529855391732 Marionette DEBUG Remote service is active [task 2018-06-24T15:49:51.780Z] 15:49:51 INFO - 1529855391775 Marionette DEBUG Accepted connection 0 from 127.0.0.1:43746 [task 2018-06-24T15:49:51.808Z] 15:49:51 INFO - 1529855391804 Marionette DEBUG Closed connection 0 [task 2018-06-24T15:49:51.825Z] 15:49:51 INFO - 1529855391807 Marionette DEBUG Accepted connection 1 from 127.0.0.1:43748 [task 2018-06-24T15:49:51.847Z] 15:49:51 INFO - 1529855391842 Marionette TRACE 1 -> [0,1,"WebDriver:NewSession",{}] [task 2018-06-24T15:49:52.400Z] 15:49:52 INFO - 1529855392392 Marionette DEBUG [2147483649] Frame script loaded [task 2018-06-24T15:49:52.403Z] 15:49:52 INFO - 1529855392399 Marionette DEBUG [2147483649] Frame script registered [task 2018-06-24T15:49:52.432Z] 15:49:52 INFO - 1529855392427 Marionette TRACE 1 <- [1,1,null,{"sessionId":"0e86cf28-f181-4b58-bbd5-b234ac9ba7d7","capabilities":{"browserName":"firefox","browserVersion":"62.0" ... ssID":7659,"moz:profile":"/tmp/tmp__hPz1.mozrunner","moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true}}] [task 2018-06-24T15:49:52.468Z] 15:49:52 INFO - 1529855392465 Marionette TRACE 1 -> [0,2,"Addon:Install",{"path":"/builds/worker/workspace/build/tests/reftest/reftest","temporary":true}] [task 2018-06-24T15:49:52.747Z] 15:49:52 INFO - 1529855392737 Marionette TRACE 1 <- [1,2,null,{"value":"reftest@mozilla.org"}] [task 2018-06-24T15:49:53.383Z] 15:49:53 INFO - 1529855393374 Marionette TRACE 1 -> [0,3,"WebDriver:DeleteSession",{}] [task 2018-06-24T15:49:53.385Z] 15:49:53 INFO - 1529855393379 Marionette TRACE 1 <- [1,3,null,{"value":null}] [task 2018-06-24T15:49:53.407Z] 15:49:53 INFO - 1529855393404 Marionette DEBUG Closed connection 1 [task 2018-06-24T15:49:55.411Z] 15:49:55 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00FB,name=PContent::Msg_AccumulateChildKeyedHistograms) Channel closing: too late to send/recv, messages will be lost [task 2018-06-24T15:49:55.411Z] 15:49:55 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00FF,name=PContent::Msg_RecordDiscardedData) Channel closing: too late to send/recv, messages will be lost [task 2018-06-24T15:49:59.333Z] 15:49:59 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00FA,name=PContent::Msg_AccumulateChildHistograms) Channel closing: too late to send/recv, messages will be lost [task 2018-06-24T15:49:59.334Z] 15:49:59 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00FF,name=PContent::Msg_RecordDiscardedData) Channel closing: too late to send/recv, messages will be lost [task 2018-06-24T15:50:03.683Z] 15:50:03 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00FA,name=PContent::Msg_AccumulateChildHistograms) Channel closing: too late to send/recv, messages will be lost [task 2018-06-24T15:50:03.685Z] 15:50:03 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00FF,name=PContent::Msg_RecordDiscardedData) Channel closing: too late to send/recv, messages will be lost [task 2018-06-24T15:50:05.676Z] 15:50:05 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00FA,name=PContent::Msg_AccumulateChildHistograms) Channel closing: too late to send/recv, messages will be lost [task 2018-06-24T15:50:05.678Z] 15:50:05 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00FB,name=PContent::Msg_AccumulateChildKeyedHistograms) Channel closing: too late to send/recv, messages will be lost [task 2018-06-24T15:50:05.679Z] 15:50:05 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00FF,name=PContent::Msg_RecordDiscardedData) Channel closing: too late to send/recv, messages will be lost [task 2018-06-24T15:50:09.992Z] 15:50:09 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00FA,name=PContent::Msg_AccumulateChildHistograms) Channel closing: too late to send/recv, messages will be lost [task 2018-06-24T15:50:09.994Z] 15:50:09 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00FF,name=PContent::Msg_RecordDiscardedData) Channel closing: too late to send/recv, messages will be lost [task 2018-06-24T15:50:09.996Z] 15:50:09 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x550027,name=PNecko::Msg_RemoveRequestContext) Channel closing: too late to send/recv, messages will be lost [task 2018-06-24T15:50:11.997Z] 15:50:11 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00FA,name=PContent::Msg_AccumulateChildHistograms) Channel closing: too late to send/recv, messages will be lost [task 2018-06-24T15:50:11.998Z] 15:50:11 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00FF,name=PContent::Msg_RecordDiscardedData) Channel closing: too late to send/recv, messages will be lost [task 2018-06-24T15:50:36.293Z] 15:50:36 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00FC,name=PContent::Msg_UpdateChildScalars) Channel closing: too late to send/recv, messages will be lost [task 2018-06-24T15:50:36.294Z] 15:50:36 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00FF,name=PContent::Msg_RecordDiscardedData) Channel closing: too late to send/recv, messages will be lost [task 2018-06-24T15:50:50.454Z] 15:50:50 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00FA,name=PContent::Msg_AccumulateChildHistograms) Channel closing: too late to send/recv, messages will be lost [task 2018-06-24T15:50:50.457Z] 15:50:50 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00FF,name=PContent::Msg_RecordDiscardedData) Channel closing: too late to send/recv, messages will be lost [task 2018-06-24T15:51:01.756Z] 15:51:01 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D0108,name=PContent::Msg_AsyncMessage) Channel closing: too late to send/recv, messages will be lost [task 2018-06-24T15:51:01.759Z] 15:51:01 INFO - JavaScript error: resource://gre/modules/GCTelemetry.jsm, line 231: NS_ERROR_UNEXPECTED: [task 2018-06-24T15:51:01.763Z] 15:51:01 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00B1,name=PContent::Msg_ScriptError) Channel closing: too late to send/recv, messages will be lost [task 2018-06-24T15:51:03.705Z] 15:51:03 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00FA,name=PContent::Msg_AccumulateChildHistograms) Channel closing: too late to send/recv, messages will be lost [task 2018-06-24T15:51:03.707Z] 15:51:03 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00FB,name=PContent::Msg_AccumulateChildKeyedHistograms) Channel closing: too late to send/recv, messages will be lost [task 2018-06-24T15:51:03.708Z] 15:51:03 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00FF,name=PContent::Msg_RecordDiscardedData) Channel closing: too late to send/recv, messages will be lost [task 2018-06-24T15:54:54.253Z] 15:54:54 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D0108,name=PContent::Msg_AsyncMessage) Channel closing: too late to send/recv, messages will be lost [task 2018-06-24T15:54:54.254Z] 15:54:54 INFO - JavaScript error: resource://gre/modules/GCTelemetry.jsm, line 231: NS_ERROR_UNEXPECTED: [task 2018-06-24T15:54:54.254Z] 15:54:54 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00B1,name=PContent::Msg_ScriptError) Channel closing: too late to send/recv, messages will be lost [task 2018-06-24T15:54:56.148Z] 15:54:56 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00FA,name=PContent::Msg_AccumulateChildHistograms) Channel closing: too late to send/recv, messages will be lost [task 2018-06-24T15:54:56.151Z] 15:54:56 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00FB,name=PContent::Msg_AccumulateChildKeyedHistograms) Channel closing: too late to send/recv, messages will be lost [task 2018-06-24T15:54:56.152Z] 15:54:56 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00FF,name=PContent::Msg_RecordDiscardedData) Channel closing: too late to send/recv, messages will be lost [task 2018-06-24T15:55:54.291Z] 15:55:54 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D0108,name=PContent::Msg_AsyncMessage) Channel closing: too late to send/recv, messages will be lost [task 2018-06-24T15:55:54.294Z] 15:55:54 INFO - JavaScript error: resource://gre/modules/GCTelemetry.jsm, line 231: NS_ERROR_UNEXPECTED: [task 2018-06-24T15:55:54.296Z] 15:55:54 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00B1,name=PContent::Msg_ScriptError) Channel closing: too late to send/recv, messages will be lost [task 2018-06-24T15:55:56.240Z] 15:55:56 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00FA,name=PContent::Msg_AccumulateChildHistograms) Channel closing: too late to send/recv, messages will be lost [task 2018-06-24T15:55:56.241Z] 15:55:56 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00FB,name=PContent::Msg_AccumulateChildKeyedHistograms) Channel closing: too late to send/recv, messages will be lost [task 2018-06-24T15:55:56.241Z] 15:55:56 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00FF,name=PContent::Msg_RecordDiscardedData) Channel closing: too late to send/recv, messages will be lost [task 2018-06-24T16:02:06.244Z] 16:02:06 ERROR - REFTEST ERROR | file:///builds/worker/workspace/build/tests/reftest/tests/image/test/reftest/gif/truncated-framerect.html | application timed out after 370 seconds with no output [task 2018-06-24T16:02:06.246Z] 16:02:06 ERROR - REFTEST ERROR | Force-terminating active process(es). [task 2018-06-24T16:02:06.248Z] 16:02:06 INFO - REFTEST TEST-INFO | started process screentopng [task 2018-06-24T16:02:06.891Z] 16:02:06 INFO - REFTEST TEST-INFO | screentopng: exit 0 [task 2018-06-24T16:02:06.894Z] 16:02:06 INFO - REFTEST INFO | Can't trigger Breakpad, just killing process [task 2018-06-24T16:02:06.985Z] 16:02:06 ERROR - TEST-UNEXPECTED-FAIL | file:///builds/worker/workspace/build/tests/reftest/tests/image/test/reftest/gif/truncated-framerect.html | application terminated with exit code -15 [task 2018-06-24T16:02:07.002Z] 16:02:07 INFO - REFTEST INFO | Process mode: e10s [task 2018-06-24T16:02:07.002Z] 16:02:07 WARNING - leakcheck | refcount logging is off, so leaks can't be detected! [task 2018-06-24T16:02:07.002Z] 16:02:07 INFO - REFTEST INFO | Running tests in file:///builds/worker/workspace/build/tests/reftest/tests/layout/reftests/web-animations/reftest.list [task 2018-06-24T16:02:07.019Z] 16:02:07 INFO - REFTEST INFO | INFO | runtests.py | ASan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer [task 2018-06-24T16:02:07.027Z] 16:02:07 INFO - REFTEST INFO | INFO | runtests.py | ASan running in default memory configuration [task 2018-06-24T16:02:07.032Z] 16:02:07 INFO - REFTEST INFO | Running with e10s: True [task 2018-06-24T16:02:07.032Z] 16:02:07 INFO - REFTEST INFO | Application command: /builds/worker/workspace/build/application/firefox/firefox -marionette -profile /tmp/tmp7MKBRx.mozrunner [task 2018-06-24T16:02:08.777Z] 16:02:08 INFO - 1529856128771 Marionette DEBUG Received observer notification profile-after-change [task 2018-06-24T16:02:08.873Z] 16:02:08 INFO - ATTENTION: default value of option force_s3tc_enable overridden by environment. [task 2018-06-24T16:02:08.935Z] 16:02:08 INFO - 1529856128932 Marionette DEBUG Received observer notification command-line-startup [task 2018-06-24T16:02:08.939Z] 16:02:08 INFO - 1529856128933 Marionette DEBUG Received observer notification nsPref:changed [task 2018-06-24T16:02:08.941Z] 16:02:08 INFO - 1529856128933 Marionette DEBUG Init aborted (running=false, enabled=true, finalUIStartup=false) [task 2018-06-24T16:02:12.460Z] 16:02:12 INFO - 1529856132451 Marionette DEBUG Received observer notification sessionstore-windows-restored [task 2018-06-24T16:02:12.461Z] 16:02:12 INFO - 1529856132452 Marionette DEBUG Waiting for delayed startup... [task 2018-06-24T16:02:14.200Z] 16:02:14 INFO - 1529856134189 Marionette INFO Listening on port 2828 [task 2018-06-24T16:02:14.200Z] 16:02:14 INFO - 1529856134190 Marionette DEBUG Remote service is active [task 2018-06-24T16:02:14.362Z] 16:02:14 INFO - 1529856134355 Marionette DEBUG Accepted connection 0 from 127.0.0.1:44220 [task 2018-06-24T16:02:14.371Z] 16:02:14 INFO - 1529856134364 Marionette DEBUG Closed connection 0 [task 2018-06-24T16:02:14.372Z] 16:02:14 INFO - 1529856134366 Marionette DEBUG Accepted connection 1 from 127.0.0.1:44222 [task 2018-06-24T16:02:14.413Z] 16:02:14 INFO - 1529856134408 Marionette TRACE 1 -> [0,1,"WebDriver:NewSession",{}] [task 2018-06-24T16:02:14.692Z] 16:02:14 INFO - 1529856134683 Marionette DEBUG [2147483649] Frame script loaded [task 2018-06-24T16:02:14.692Z] 16:02:14 INFO - 1529856134686 Marionette DEBUG [2147483649] Frame script registered [task 2018-06-24T16:02:14.728Z] 16:02:14 INFO - 1529856134716 Marionette TRACE 1 <- [1,1,null,{"sessionId":"eb5f4881-3689-4454-838b-24ed67270c1a","capabilities":{"browserName":"firefox","browserVersion":"62.0" ... ssID":7799,"moz:profile":"/tmp/tmp7MKBRx.mozrunner","moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true}}] [task 2018-06-24T16:02:14.737Z] 16:02:14 INFO - 1529856134731 Marionette TRACE 1 -> [0,2,"Addon:Install",{"path":"/builds/worker/workspace/build/tests/reftest/reftest","temporary":true}] [task 2018-06-24T16:02:14.814Z] 16:02:14 INFO - 1529856134809 Marionette TRACE 1 <- [1,2,null,{"value":"reftest@mozilla.org"}] [task 2018-06-24T16:02:15.280Z] 16:02:15 INFO - 1529856135268 Marionette TRACE 1 -> [0,3,"WebDriver:DeleteSession",{}] [task 2018-06-24T16:02:15.280Z] 16:02:15 INFO - 1529856135272 Marionette TRACE 1 <- [1,3,null,{"value":null}] [task 2018-06-24T16:02:15.296Z] 16:02:15 INFO - 1529856135291 Marionette DEBUG Closed connection 1
Summary: Intermittent image/test/reftest/gif/truncated-framerect.html | application timed out after 370 seconds with no output when Gecko 62 merges to Beta on 18-06-2018 → Intermittent image/test/reftest/gif/truncated-framerect.html | application timed out after 370 seconds with no output
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
Status: NEW → RESOLVED
Closed: 7 years ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.