Closed Bug 1470787 Opened 8 years ago Closed 8 years ago

Intermittent image/test/reftest/bmp/bmp-corrupted/wrapper.html?invalid-truncated-metadata.bmp | 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: dluca [at] mozilla.com https://treeherder.mozilla.org/logviewer.html#?job_id=184617624&repo=mozilla-central https://queue.taskcluster.net/v1/task/SmXtcylbT2iQqHH_f3uw2Q/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/SmXtcylbT2iQqHH_f3uw2Q/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1 REFTEST TEST-START | file:///builds/worker/workspace/build/tests/reftest/tests/image/test/reftest/bmp/bmp-corrupted/wrapper.html?invalid-truncated-metadata.bmp == about:blank [task 2018-06-24T22:53:17.009Z] 22:53:17 INFO - REFTEST TEST-LOAD | file:///builds/worker/workspace/build/tests/reftest/tests/image/test/reftest/bmp/bmp-corrupted/wrapper.html?invalid-truncated-metadata.bmp | 7 / 8 (87%) [task 2018-06-24T22:53:17.072Z] 22:53:17 INFO - REFTEST TEST-PASS | file:///builds/worker/workspace/build/tests/reftest/tests/image/test/reftest/bmp/bmp-corrupted/wrapper.html?invalid-truncated-metadata.bmp == about:blank | image comparison, max difference: 0, number of differing pixels: 0 [task 2018-06-24T22:53:17.072Z] 22:53:17 INFO - REFTEST TEST-END | file:///builds/worker/workspace/build/tests/reftest/tests/image/test/reftest/bmp/bmp-corrupted/wrapper.html?invalid-truncated-metadata.bmp == about:blank [task 2018-06-24T22:53:17.092Z] 22:53:17 INFO - REFTEST INFO | Slowest test took 93ms (file:///builds/worker/workspace/build/tests/reftest/tests/image/test/reftest/bmp/bmp-corrupted/wrapper.html?invalid-signature.bmp) [task 2018-06-24T22:53:17.094Z] 22:53:17 INFO - REFTEST INFO | Total canvas count = 2 [task 2018-06-24T22:53:17.321Z] 22:53:17 INFO - JavaScript error: chrome://reftest/content/reftest.jsm, line 1547: NS_ERROR_NOT_AVAILABLE: Component returned failure code: 0x80040111 (NS_ERROR_NOT_AVAILABLE) [nsIPropertyBag2.getPropertyAsAString] [task 2018-06-24T22:53:17.337Z] 22:53:17 INFO - ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost [task 2018-06-24T22:53:17.738Z] 22:53:17 INFO - 1529880797733 Marionette DEBUG Received observer notification xpcom-will-shutdown [task 2018-06-24T22:53:17.738Z] 22:53:17 INFO - 1529880797733 Marionette INFO Stopped listening on port 2828 [task 2018-06-24T22:53:17.738Z] 22:53:17 INFO - 1529880797733 Marionette DEBUG Remote service is inactive [task 2018-06-24T22:53:18.546Z] 22:53:18 INFO - REFTEST INFO | Process mode: e10s [task 2018-06-24T22:53:18.547Z] 22:53:18 WARNING - leakcheck | refcount logging is off, so leaks can't be detected! [task 2018-06-24T22:53:18.548Z] 22:53:18 INFO - REFTEST INFO | Running tests in file:///builds/worker/workspace/build/tests/reftest/tests/layout/reftests/css-invalid/output/reftest.list [task 2018-06-24T22:53:18.564Z] 22:53:18 INFO - REFTEST INFO | INFO | runtests.py | ASan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer [task 2018-06-24T22:53:18.572Z] 22:53:18 INFO - REFTEST INFO | INFO | runtests.py | ASan running in default memory configuration [task 2018-06-24T22:53:18.573Z] 22:53:18 INFO - REFTEST INFO | Running with e10s: True [task 2018-06-24T22:53:18.574Z] 22:53:18 INFO - REFTEST INFO | Application command: /builds/worker/workspace/build/application/firefox/firefox -marionette -profile /tmp/tmpClVnPS.mozrunner [task 2018-06-24T22:53:20.331Z] 22:53:20 INFO - 1529880800322 Marionette DEBUG Received observer notification profile-after-change [task 2018-06-24T22:53:20.461Z] 22:53:20 INFO - 1529880800454 Marionette DEBUG Received observer notification command-line-startup [task 2018-06-24T22:53:20.462Z] 22:53:20 INFO - 1529880800454 Marionette DEBUG Received observer notification nsPref:changed [task 2018-06-24T22:53:20.463Z] 22:53:20 INFO - 1529880800455 Marionette DEBUG Init aborted (running=false, enabled=true, finalUIStartup=false) [task 2018-06-24T22:53:23.734Z] 22:53:23 INFO - 1529880803718 Marionette DEBUG Received observer notification sessionstore-windows-restored [task 2018-06-24T22:53:23.734Z] 22:53:23 INFO - 1529880803718 Marionette DEBUG Waiting for delayed startup... [task 2018-06-24T22:53:25.228Z] 22:53:25 INFO - 1529880805218 Marionette DEBUG Waiting for startup tests... [task 2018-06-24T22:53:25.507Z] 22:53:25 INFO - 1529880805500 Marionette INFO Listening on port 2828 [task 2018-06-24T22:53:25.509Z] 22:53:25 INFO - 1529880805501 Marionette DEBUG Remote service is active [task 2018-06-24T22:53:25.546Z] 22:53:25 INFO - 1529880805531 Marionette DEBUG Accepted connection 0 from 127.0.0.1:42946 [task 2018-06-24T22:53:25.548Z] 22:53:25 INFO - 1529880805542 Marionette DEBUG Accepted connection 1 from 127.0.0.1:42948 [task 2018-06-24T22:53:25.550Z] 22:53:25 INFO - 1529880805545 Marionette DEBUG Closed connection 0 [task 2018-06-24T22:53:25.567Z] 22:53:25 INFO - 1529880805557 Marionette TRACE 1 -> [0,1,"WebDriver:NewSession",{}] [task 2018-06-24T22:53:25.918Z] 22:53:25 INFO - 1529880805904 Marionette DEBUG [2147483649] Frame script loaded [task 2018-06-24T22:53:25.962Z] 22:53:25 INFO - 1529880805957 Marionette DEBUG [2147483649] Frame script registered [task 2018-06-24T22:53:25.999Z] 22:53:25 INFO - 1529880805987 Marionette TRACE 1 <- [1,1,null,{"sessionId":"4e858ad0-c054-4804-a60b-c73953fb9037","capabilities":{"browserName":"firefox","browserVersion":"62.0a ... ssID":2201,"moz:profile":"/tmp/tmpClVnPS.mozrunner","moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true}}] [task 2018-06-24T22:53:26.014Z] 22:53:26 INFO - 1529880806007 Marionette TRACE 1 -> [0,2,"Addon:Install",{"path":"/builds/worker/workspace/build/tests/reftest/reftest","temporary":true}] [task 2018-06-24T22:53:26.091Z] 22:53:26 INFO - 1529880806085 Marionette TRACE 1 <- [1,2,null,{"value":"reftest@mozilla.org"}] [task 2018-06-24T22:53:26.313Z] 22:53:26 INFO - 1529880806310 Marionette TRACE 1 -> [0,3,"WebDriver:DeleteSession",{}] [task 2018-06-24T22:53:26.317Z] 22:53:26 INFO - 1529880806315 Marionette TRACE 1 <- [1,3,null,{"value":null}] [task 2018-06-24T22:53:26.354Z] 22:53:26 INFO - 1529880806350 Marionette DEBUG Closed connection 1 [task 2018-06-24T22:53:28.345Z] 22:53:28 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00FB,name=PContent::Msg_AccumulateChildKeyedHistograms) Channel closing: too late to send/recv, messages will be lost [task 2018-06-24T22:53:28.347Z] 22:53:28 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00FF,name=PContent::Msg_RecordDiscardedData) Channel closing: too late to send/recv, messages will be lost [task 2018-06-24T22:53:33.162Z] 22:53:33 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00FA,name=PContent::Msg_AccumulateChildHistograms) Channel closing: too late to send/recv, messages will be lost [task 2018-06-24T22:53:33.162Z] 22:53:33 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00FF,name=PContent::Msg_RecordDiscardedData) Channel closing: too late to send/recv, messages will be lost [task 2018-06-24T22:53:37.495Z] 22:53:37 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00FA,name=PContent::Msg_AccumulateChildHistograms) Channel closing: too late to send/recv, messages will be lost [task 2018-06-24T22:53:37.497Z] 22:53:37 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00FF,name=PContent::Msg_RecordDiscardedData) Channel closing: too late to send/recv, messages will be lost [task 2018-06-24T22:53:39.495Z] 22:53:39 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00FA,name=PContent::Msg_AccumulateChildHistograms) Channel closing: too late to send/recv, messages will be lost [task 2018-06-24T22:53:39.498Z] 22:53:39 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00FB,name=PContent::Msg_AccumulateChildKeyedHistograms) Channel closing: too late to send/recv, messages will be lost [task 2018-06-24T22:53:39.499Z] 22:53:39 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00FF,name=PContent::Msg_RecordDiscardedData) Channel closing: too late to send/recv, messages will be lost [task 2018-06-24T22:53:42.977Z] 22:53:42 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x550027,name=PNecko::Msg_RemoveRequestContext) Channel closing: too late to send/recv, messages will be lost [task 2018-06-24T22:53:43.811Z] 22:53:43 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00FA,name=PContent::Msg_AccumulateChildHistograms) Channel closing: too late to send/recv, messages will be lost [task 2018-06-24T22:53:43.811Z] 22:53:43 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00FF,name=PContent::Msg_RecordDiscardedData) Channel closing: too late to send/recv, messages will be lost [task 2018-06-24T22:53:45.809Z] 22:53:45 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00FA,name=PContent::Msg_AccumulateChildHistograms) Channel closing: too late to send/recv, messages will be lost [task 2018-06-24T22:53:45.812Z] 22:53:45 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00FB,name=PContent::Msg_AccumulateChildKeyedHistograms) Channel closing: too late to send/recv, messages will be lost [task 2018-06-24T22:53:45.813Z] 22:53:45 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00FF,name=PContent::Msg_RecordDiscardedData) Channel closing: too late to send/recv, messages will be lost [task 2018-06-24T22:54:10.110Z] 22:54:10 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00FC,name=PContent::Msg_UpdateChildScalars) Channel closing: too late to send/recv, messages will be lost [task 2018-06-24T22:54:10.113Z] 22:54:10 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00FF,name=PContent::Msg_RecordDiscardedData) Channel closing: too late to send/recv, messages will be lost [task 2018-06-24T22:54:24.383Z] 22:54:24 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00FA,name=PContent::Msg_AccumulateChildHistograms) Channel closing: too late to send/recv, messages will be lost [task 2018-06-24T22:54:24.384Z] 22:54:24 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00FF,name=PContent::Msg_RecordDiscardedData) Channel closing: too late to send/recv, messages will be lost [task 2018-06-24T23:00:34.385Z] 23:00:34 ERROR - REFTEST ERROR | file:///builds/worker/workspace/build/tests/reftest/tests/image/test/reftest/bmp/bmp-corrupted/wrapper.html?invalid-truncated-metadata.bmp | application timed out after 370 seconds with no output [task 2018-06-24T23:00:34.389Z] 23:00:34 ERROR - REFTEST ERROR | Force-terminating active process(es). [task 2018-06-24T23:00:34.391Z] 23:00:34 INFO - REFTEST TEST-INFO | started process screentopng [task 2018-06-24T23:00:34.894Z] 23:00:34 INFO - REFTEST TEST-INFO | screentopng: exit 0 [task 2018-06-24T23:00:34.894Z] 23:00:34 INFO - REFTEST INFO | Can't trigger Breakpad, just killing process [task 2018-06-24T23:00:34.971Z] 23:00:34 ERROR - TEST-UNEXPECTED-FAIL | file:///builds/worker/workspace/build/tests/reftest/tests/image/test/reftest/bmp/bmp-corrupted/wrapper.html?invalid-truncated-metadata.bmp | application terminated with exit code -15 [task 2018-06-24T23:00:34.974Z] 23:00:34 INFO - REFTEST INFO | Process mode: e10s [task 2018-06-24T23:00:34.975Z] 23:00:34 WARNING - leakcheck | refcount logging is off, so leaks can't be detected! [task 2018-06-24T23:00:34.977Z] 23:00:34 INFO - REFTEST INFO | Running tests in file:///builds/worker/workspace/build/tests/reftest/tests/layout/reftests/font-loading-api/reftest.list [task 2018-06-24T23:00:34.995Z] 23:00:34 INFO - REFTEST INFO | INFO | runtests.py | ASan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer [task 2018-06-24T23:00:35.011Z] 23:00:35 INFO - REFTEST INFO | INFO | runtests.py | ASan running in default memory configuration [task 2018-06-24T23:00:35.013Z] 23:00:35 INFO - REFTEST INFO | Running with e10s: True [task 2018-06-24T23:00:35.014Z] 23:00:35 INFO - REFTEST INFO | Application command: /builds/worker/workspace/build/application/firefox/firefox -marionette -profile /tmp/tmp43yoeF.mozrunner [task 2018-06-24T23:00:36.799Z] 23:00:36 INFO - 1529881236794 Marionette DEBUG Received observer notification profile-after-change [task 2018-06-24T23:00:36.936Z] 23:00:36 INFO - 1529881236930 Marionette DEBUG Received observer notification command-line-startup [task 2018-06-24T23:00:36.937Z] 23:00:36 INFO - 1529881236930 Marionette DEBUG Received observer notification nsPref:changed [task 2018-06-24T23:00:36.938Z] 23:00:36 INFO - 1529881236930 Marionette DEBUG Init aborted (running=false, enabled=true, finalUIStartup=false) [task 2018-06-24T23:00:40.293Z] 23:00:40 INFO - 1529881240283 Marionette DEBUG Received observer notification sessionstore-windows-restored [task 2018-06-24T23:00:40.295Z] 23:00:40 INFO - 1529881240284 Marionette DEBUG Waiting for delayed startup... [task 2018-06-24T23:00:41.713Z] 23:00:41 INFO - 1529881241707 Marionette DEBUG Waiting for startup tests... [task 2018-06-24T23:00:42.020Z] 23:00:42 INFO - 1529881242017 Marionette INFO Listening on port 2828 [task 2018-06-24T23:00:42.021Z] 23:00:42 INFO - 1529881242019 Marionette DEBUG Remote service is active [task 2018-06-24T23:00:42.077Z] 23:00:42 INFO - 1529881242073 Marionette DEBUG Accepted connection 0 from 127.0.0.1:43284 [task 2018-06-24T23:00:42.096Z] 23:00:42 INFO - 1529881242084 Marionette DEBUG Closed connection 0 [task 2018-06-24T23:00:42.098Z] 23:00:42 INFO - 1529881242088 Marionette DEBUG Accepted connection 1 from 127.0.0.1:43286 [task 2018-06-24T23:00:42.106Z] 23:00:42 INFO - 1529881242099 Marionette TRACE 1 -> [0,1,"WebDriver:NewSession",{}] [task 2018-06-24T23:00:42.467Z] 23:00:42 INFO - 1529881242457 Marionette DEBUG [2147483649] Frame script loaded [task 2018-06-24T23:00:42.469Z] 23:00:42 INFO - 1529881242463 Marionette DEBUG [2147483649] Frame script registered [task 2018-06-24T23:00:42.505Z] 23:00:42 INFO - 1529881242499 Marionette TRACE 1 <- [1,1,null,{"sessionId":"50110efc-21d3-4e55-addc-7ad60fa26010","capabilities":{"browserName":"firefox","browserVersion":"62.0a ... ssID":2340,"moz:profile":"/tmp/tmp43yoeF.mozrunner","moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true}}] [task 2018-06-24T23:00:42.567Z] 23:00:42 INFO - 1529881242562 Marionette TRACE 1 -> [0,2,"Addon:Install",{"path":"/builds/worker/workspace/build/tests/reftest/reftest","temporary":true}] [task 2018-06-24T23:00:42.635Z] 23:00:42 INFO - 1529881242631 Marionette TRACE 1 <- [1,2,null,{"value":"reftest@mozilla.org"}] [task 2018-06-24T23:00:42.795Z] 23:00:42 INFO - 1529881242783 Marionette TRACE 1 -> [0,3,"WebDriver:DeleteSession",{}] [task 2018-06-24T23:00:42.796Z] 23:00:42 INFO - 1529881242786 Marionette TRACE 1 <- [1,3,null,{"value":null}] [task 2018-06-24T23:00:42.811Z] 23:00:42 INFO - 1529881242799 Marionette DEBUG Closed connection 1
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
Status: NEW → RESOLVED
Closed: 8 years ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.