Closed Bug 1469609 Opened 7 years ago Closed 7 years ago

Intermittent svg/smil/pause/init-pause-1.svg | application timed out after 370 seconds with no output

Categories

(Core :: SVG, defect, P5)

Product:
Core
Component:
SVG
Type:
defect

Tracking

()

Status:
RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: intermittent-failure)

Filed by: btara [at] mozilla.com https://treeherder.mozilla.org/logviewer.html#?job_id=183804029&repo=autoland https://queue.taskcluster.net/v1/task/Zy9m_FBhQZSMD5niEVqpLA/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/Zy9m_FBhQZSMD5niEVqpLA/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1 [task 2018-06-19T14:40:48.341Z] 14:40:48 INFO - REFTEST TEST-START | file:///builds/worker/workspace/build/tests/reftest/tests/layout/reftests/svg/smil/pause/init-pause-1.svg == file:///builds/worker/workspace/build/tests/reftest/tests/layout/reftests/svg/smil/pause/init-pause-1-ref.svg [task 2018-06-19T14:40:48.345Z] 14:40:48 INFO - REFTEST TEST-LOAD | file:///builds/worker/workspace/build/tests/reftest/tests/layout/reftests/svg/smil/pause/init-pause-1.svg | 0 / 1 (0%) [task 2018-06-19T14:40:48.645Z] 14:40:48 INFO - REFTEST INFO | drawWindow flags = DRAWWINDOW_DRAW_CARET | DRAWWINDOW_DRAW_VIEW | DRAWWINDOW_USE_WIDGET_LAYERS; window size = 800,1000; test browser size = 800,1000 [task 2018-06-19T14:40:48.890Z] 14:40:48 INFO - REFTEST TEST-LOAD | file:///builds/worker/workspace/build/tests/reftest/tests/layout/reftests/svg/smil/pause/init-pause-1-ref.svg | 0 / 1 (0%) [task 2018-06-19T14:40:49.084Z] 14:40:49 INFO - REFTEST TEST-PASS | file:///builds/worker/workspace/build/tests/reftest/tests/layout/reftests/svg/smil/pause/init-pause-1.svg == file:///builds/worker/workspace/build/tests/reftest/tests/layout/reftests/svg/smil/pause/init-pause-1-ref.svg | image comparison, max difference: 0, number of differing pixels: 0 [task 2018-06-19T14:40:49.084Z] 14:40:49 INFO - REFTEST TEST-END | file:///builds/worker/workspace/build/tests/reftest/tests/layout/reftests/svg/smil/pause/init-pause-1.svg == file:///builds/worker/workspace/build/tests/reftest/tests/layout/reftests/svg/smil/pause/init-pause-1-ref.svg [task 2018-06-19T14:40:49.191Z] 14:40:49 INFO - REFTEST INFO | Slowest test took 512ms (file:///builds/worker/workspace/build/tests/reftest/tests/layout/reftests/svg/smil/pause/init-pause-1.svg) [task 2018-06-19T14:40:49.192Z] 14:40:49 INFO - REFTEST INFO | Total canvas count = 2 [task 2018-06-19T14:40:49.596Z] 14:40:49 INFO - JavaScript error: chrome://reftest/content/reftest.jsm, line 1546: NS_ERROR_NOT_AVAILABLE: Component returned failure code: 0x80040111 (NS_ERROR_NOT_AVAILABLE) [nsIPropertyBag2.getPropertyAsAString] [task 2018-06-19T14:40:49.701Z] 14:40:49 INFO - JavaScript error: chrome://reftest/content/reftest.jsm, line 1546: NS_ERROR_NOT_AVAILABLE: Component returned failure code: 0x80040111 (NS_ERROR_NOT_AVAILABLE) [nsIPropertyBag2.getPropertyAsAString] [task 2018-06-19T14:40:49.730Z] 14:40:49 INFO - ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost [task 2018-06-19T14:40:50.198Z] 14:40:50 INFO - 1529419250196 Marionette DEBUG Received observer notification xpcom-will-shutdown [task 2018-06-19T14:40:50.200Z] 14:40:50 INFO - 1529419250197 Marionette INFO Stopped listening on port 2828 [task 2018-06-19T14:40:50.201Z] 14:40:50 INFO - 1529419250197 Marionette DEBUG Remote service is inactive [task 2018-06-19T14:40:51.143Z] 14:40:51 INFO - REFTEST INFO | Process mode: e10s [task 2018-06-19T14:40:51.144Z] 14:40:51 WARNING - leakcheck | refcount logging is off, so leaks can't be detected! [task 2018-06-19T14:40:51.145Z] 14:40:51 INFO - REFTEST INFO | Running tests in file:///builds/worker/workspace/build/tests/reftest/tests/layout/reftests/position-dynamic-changes/relative/reftest.list [task 2018-06-19T14:40:51.161Z] 14:40:51 INFO - REFTEST INFO | INFO | runtests.py | ASan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer [task 2018-06-19T14:40:51.170Z] 14:40:51 INFO - REFTEST INFO | INFO | runtests.py | ASan running in default memory configuration [task 2018-06-19T14:40:51.171Z] 14:40:51 INFO - REFTEST INFO | Running with e10s: True [task 2018-06-19T14:40:51.171Z] 14:40:51 INFO - REFTEST INFO | Application command: /builds/worker/workspace/build/application/firefox/firefox -marionette -profile /tmp/tmpt6BScm.mozrunner [task 2018-06-19T14:40:53.077Z] 14:40:53 INFO - 1529419253068 Marionette DEBUG Received observer notification profile-after-change [task 2018-06-19T14:40:53.179Z] 14:40:53 INFO - ATTENTION: default value of option force_s3tc_enable overridden by environment. [task 2018-06-19T14:40:53.256Z] 14:40:53 INFO - 1529419253245 Marionette DEBUG Received observer notification command-line-startup [task 2018-06-19T14:40:53.256Z] 14:40:53 INFO - 1529419253246 Marionette DEBUG Received observer notification nsPref:changed [task 2018-06-19T14:40:53.259Z] 14:40:53 INFO - 1529419253246 Marionette DEBUG Init aborted (running=false, enabled=true, finalUIStartup=false) [task 2018-06-19T14:40:57.162Z] 14:40:57 INFO - 1529419257158 Marionette DEBUG Received observer notification sessionstore-windows-restored [task 2018-06-19T14:40:57.165Z] 14:40:57 INFO - 1529419257159 Marionette DEBUG Waiting for delayed startup... [task 2018-06-19T14:40:59.029Z] 14:40:59 INFO - 1529419259017 Marionette DEBUG Waiting for startup tests... [task 2018-06-19T14:40:59.313Z] 14:40:59 INFO - 1529419259307 Marionette INFO Listening on port 2828 [task 2018-06-19T14:40:59.314Z] 14:40:59 INFO - 1529419259309 Marionette DEBUG Remote service is active [task 2018-06-19T14:40:59.373Z] 14:40:59 INFO - 1529419259368 Marionette DEBUG Accepted connection 0 from 127.0.0.1:60946 [task 2018-06-19T14:40:59.394Z] 14:40:59 INFO - 1529419259384 Marionette DEBUG Closed connection 0 [task 2018-06-19T14:40:59.395Z] 14:40:59 INFO - 1529419259391 Marionette DEBUG Accepted connection 1 from 127.0.0.1:60948 [task 2018-06-19T14:40:59.404Z] 14:40:59 INFO - 1529419259399 Marionette TRACE 1 -> [0,1,"WebDriver:NewSession",{}] [task 2018-06-19T14:40:59.946Z] 14:40:59 INFO - 1529419259937 Marionette DEBUG [2147483649] Frame script loaded [task 2018-06-19T14:40:59.970Z] 14:40:59 INFO - 1529419259964 Marionette DEBUG [2147483649] Frame script registered [task 2018-06-19T14:41:00.007Z] 14:41:00 INFO - 1529419260002 Marionette TRACE 1 <- [1,1,null,{"sessionId":"ec700c30-73f5-45e0-9195-c40748706df3","capabilities":{"browserName":"firefox","browserVersion":"62.0a ... ssID":3911,"moz:profile":"/tmp/tmpt6BScm.mozrunner","moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true}}] [task 2018-06-19T14:41:00.028Z] 14:41:00 INFO - 1529419260023 Marionette TRACE 1 -> [0,2,"Addon:Install",{"path":"/builds/worker/workspace/build/tests/reftest/reftest","temporary":true}] [task 2018-06-19T14:41:00.125Z] 14:41:00 INFO - 1529419260118 Marionette TRACE 1 <- [1,2,null,{"value":"reftest@mozilla.org"}] [task 2018-06-19T14:41:00.999Z] 14:41:00 INFO - 1529419260993 Marionette TRACE 1 -> [0,3,"WebDriver:DeleteSession",{}] [task 2018-06-19T14:41:01.007Z] 14:41:01 INFO - 1529419261001 Marionette TRACE 1 <- [1,3,null,{"value":null}] [task 2018-06-19T14:41:01.044Z] 14:41:01 INFO - 1529419261031 Marionette DEBUG Closed connection 1 [task 2018-06-19T14:41:03.044Z] 14:41:03 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00FA,name=PContent::Msg_AccumulateChildKeyedHistograms) Channel closing: too late to send/recv, messages will be lost [task 2018-06-19T14:41:03.046Z] 14:41:03 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00FE,name=PContent::Msg_RecordDiscardedData) Channel closing: too late to send/recv, messages will be lost [task 2018-06-19T14:41:06.482Z] 14:41:06 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00F9,name=PContent::Msg_AccumulateChildHistograms) Channel closing: too late to send/recv, messages will be lost [task 2018-06-19T14:41:06.483Z] 14:41:06 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00FE,name=PContent::Msg_RecordDiscardedData) Channel closing: too late to send/recv, messages will be lost [task 2018-06-19T14:41:10.822Z] 14:41:10 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00F9,name=PContent::Msg_AccumulateChildHistograms) Channel closing: too late to send/recv, messages will be lost [task 2018-06-19T14:41:10.824Z] 14:41:10 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00FE,name=PContent::Msg_RecordDiscardedData) Channel closing: too late to send/recv, messages will be lost [task 2018-06-19T14:41:12.826Z] 14:41:12 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00F9,name=PContent::Msg_AccumulateChildHistograms) Channel closing: too late to send/recv, messages will be lost [task 2018-06-19T14:41:12.827Z] 14:41:12 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00FA,name=PContent::Msg_AccumulateChildKeyedHistograms) Channel closing: too late to send/recv, messages will be lost [task 2018-06-19T14:41:12.828Z] 14:41:12 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00FE,name=PContent::Msg_RecordDiscardedData) Channel closing: too late to send/recv, messages will be lost [task 2018-06-19T14:41:16.276Z] 14:41:16 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x550027,name=PNecko::Msg_RemoveRequestContext) Channel closing: too late to send/recv, messages will be lost [task 2018-06-19T14:41:17.141Z] 14:41:17 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00F9,name=PContent::Msg_AccumulateChildHistograms) Channel closing: too late to send/recv, messages will be lost [task 2018-06-19T14:41:17.142Z] 14:41:17 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00FE,name=PContent::Msg_RecordDiscardedData) Channel closing: too late to send/recv, messages will be lost [task 2018-06-19T14:41:19.145Z] 14:41:19 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00F9,name=PContent::Msg_AccumulateChildHistograms) Channel closing: too late to send/recv, messages will be lost [task 2018-06-19T14:41:19.147Z] 14:41:19 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00FA,name=PContent::Msg_AccumulateChildKeyedHistograms) Channel closing: too late to send/recv, messages will be lost [task 2018-06-19T14:41:19.148Z] 14:41:19 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00FE,name=PContent::Msg_RecordDiscardedData) Channel closing: too late to send/recv, messages will be lost [task 2018-06-19T14:41:42.445Z] 14:41:42 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00FB,name=PContent::Msg_UpdateChildScalars) Channel closing: too late to send/recv, messages will be lost [task 2018-06-19T14:41:42.447Z] 14:41:42 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00FE,name=PContent::Msg_RecordDiscardedData) Channel closing: too late to send/recv, messages will be lost [task 2018-06-19T14:41:57.428Z] 14:41:57 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00F9,name=PContent::Msg_AccumulateChildHistograms) Channel closing: too late to send/recv, messages will be lost [task 2018-06-19T14:41:57.434Z] 14:41:57 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x2D00FE,name=PContent::Msg_RecordDiscardedData) Channel closing: too late to send/recv, messages will be lost [task 2018-06-19T14:48:07.446Z] 14:48:07 ERROR - REFTEST ERROR | file:///builds/worker/workspace/build/tests/reftest/tests/layout/reftests/svg/smil/pause/init-pause-1.svg | application timed out after 370 seconds with no output [task 2018-06-19T14:48:07.449Z] 14:48:07 ERROR - REFTEST ERROR | Force-terminating active process(es). [task 2018-06-19T14:48:07.451Z] 14:48:07 INFO - REFTEST TEST-INFO | started process screentopng [task 2018-06-19T14:48:08.119Z] 14:48:08 INFO - REFTEST TEST-INFO | screentopng: exit 0 [task 2018-06-19T14:48:08.119Z] 14:48:08 INFO - REFTEST INFO | Can't trigger Breakpad, just killing process [task 2018-06-19T14:48:08.218Z] 14:48:08 ERROR - TEST-UNEXPECTED-FAIL | file:///builds/worker/workspace/build/tests/reftest/tests/layout/reftests/svg/smil/pause/init-pause-1.svg | application terminated with exit code -15 [task 2018-06-19T14:48:08.226Z] 14:48:08 INFO - REFTEST INFO | Process mode: e10s [task 2018-06-19T14:48:08.228Z] 14:48:08 WARNING - leakcheck | refcount logging is off, so leaks can't be detected! [task 2018-06-19T14:48:08.228Z] 14:48:08 INFO - REFTEST INFO | Running tests in file:///builds/worker/workspace/build/tests/reftest/tests/layout/reftests/bidi/reftest.list [task 2018-06-19T14:48:08.256Z] 14:48:08 INFO - REFTEST INFO | INFO | runtests.py | ASan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer [task 2018-06-19T14:48:08.264Z] 14:48:08 INFO - REFTEST INFO | INFO | runtests.py | ASan running in default memory configuration
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
Status: NEW → RESOLVED
Closed: 7 years ago
Resolution: --- → INCOMPLETE
The new instance (comment 3) is on "Linux x64 asan", so it's likely an instance of bug 1477115.
Actually I guess bug 1477115 is about a different message (that one is "Connection timed out after 360s", whereas this is "application timed out after 370s")
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
Status: REOPENED → RESOLVED
Closed: 7 years ago → 7 years ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.