Closed Bug 1609042 Opened 6 years ago Closed 6 years ago

Intermittent TEST-UNEXPECTED-TIMEOUT | /css/css-grid/grid-layout-properties.html | Executor hit external timeout (this may indicate a hang)

Categories

(Core :: Layout: Grid, defect, P5)

Product:
Core
Component:
Layout: Grid
Type:
defect

Tracking

()

Status:
RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

References

(Regression)

Details

(Keywords: intermittent-failure, regression)

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

[task 2020-01-14T05:52:22.157Z] 05:52:22 INFO - TEST-START | /css/css-grid/grid-layout-properties.html
[task 2020-01-14T05:52:22.175Z] 05:52:22 INFO - Setting pref dom.animations-api.compositing.enabled (true)
[task 2020-01-14T05:52:22.205Z] 05:52:22 INFO - PID 6212 | [CodeCoverage] Requested flush for 8548.
[task 2020-01-14T05:52:23.531Z] 05:52:23 INFO - PID 6212 | [CodeCoverage] flush completed.
[task 2020-01-14T05:52:23.760Z] 05:52:23 INFO - PID 6212 | [CodeCoverage] JS flush completed.
[task 2020-01-14T05:52:23.760Z] 05:52:23 INFO - PID 6212 | [CodeCoverage] Requested flush for 5032.
[task 2020-01-14T05:52:23.760Z] 05:52:23 INFO - PID 6212 | [CodeCoverage] Requested flush for 10244.
[task 2020-01-14T05:52:23.760Z] 05:52:23 INFO - PID 6212 | [CodeCoverage] Requested flush for 6216.
[task 2020-01-14T05:52:27.442Z] 05:52:27 INFO - PID 6212 | [CodeCoverage] flush completed.
[task 2020-01-14T05:52:27.463Z] 05:52:27 INFO - PID 6212 | [CodeCoverage] JS flush completed.
[task 2020-01-14T05:52:31.184Z] 05:52:31 INFO - PID 6212 | [CodeCoverage] flush completed.
[task 2020-01-14T05:52:31.203Z] 05:52:31 INFO - PID 6212 | [CodeCoverage] JS flush completed.
[task 2020-01-14T05:52:35.017Z] 05:52:35 INFO - PID 6212 | [CodeCoverage] flush completed.
[task 2020-01-14T05:52:35.059Z] 05:52:35 INFO - PID 6212 | [CodeCoverage] JS flush completed.
[task 2020-01-14T05:52:36.213Z] 05:52:36 INFO - PID 6212 | [CodeCoverage] Requested flush for 8548.
[task 2020-01-14T05:52:37.527Z] 05:52:37 INFO - PID 6212 | [CodeCoverage] flush completed.
[task 2020-01-14T05:52:37.738Z] 05:52:37 INFO - PID 6212 | [CodeCoverage] JS flush completed.
[task 2020-01-14T05:52:37.738Z] 05:52:37 INFO - PID 6212 | [CodeCoverage] Requested flush for 10244.
[task 2020-01-14T05:52:37.738Z] 05:52:37 INFO - PID 6212 | [CodeCoverage] Requested flush for 5032.
[task 2020-01-14T05:52:37.738Z] 05:52:37 INFO - PID 6212 | [CodeCoverage] Requested flush for 6216.
[task 2020-01-14T05:52:37.738Z] 05:52:37 INFO - PID 6212 | [CodeCoverage] Requested flush for 9564.
[task 2020-01-14T05:52:41.466Z] 05:52:41 INFO - PID 6212 | [CodeCoverage] flush completed.
[task 2020-01-14T05:52:41.497Z] 05:52:41 INFO - PID 6212 | [CodeCoverage] JS flush completed.
[task 2020-01-14T05:52:42.203Z] 05:52:42 INFO - TEST-UNEXPECTED-TIMEOUT | /css/css-grid/grid-layout-properties.html | Executor hit external timeout (this may indicate a hang)
[task 2020-01-14T05:52:42.203Z] 05:52:42 INFO - File "c:\mozilla-build\python\Lib\threading.py", line 774, in __bootstrap
[task 2020-01-14T05:52:42.203Z] 05:52:42 INFO - self.__bootstrap_inner()
[task 2020-01-14T05:52:42.203Z] 05:52:42 INFO - File "c:\mozilla-build\python\Lib\threading.py", line 801, in __bootstrap_inner
[task 2020-01-14T05:52:42.203Z] 05:52:42 INFO - self.run()
[task 2020-01-14T05:52:42.203Z] 05:52:42 INFO - File "c:\mozilla-build\python\Lib\threading.py", line 754, in run
[task 2020-01-14T05:52:42.203Z] 05:52:42 INFO - self.__target(*self.__args, **self.__kwargs)
[task 2020-01-14T05:52:42.203Z] 05:52:42 INFO - File "Z:\task_1578979384\build\tests\web-platform\tests\tools\wptrunner\wptrunner\executors\executormarionette.py", line 642, in run_func
[task 2020-01-14T05:52:42.203Z] 05:52:42 INFO - self.result = True, self.func(self.protocol, self.url, self.timeout)
[task 2020-01-14T05:52:42.203Z] 05:52:42 INFO - File "Z:\task_1578979384\build\tests\web-platform\tests\tools\wptrunner\wptrunner\executors\executormarionette.py", line 762, in do_testharness
[task 2020-01-14T05:52:42.203Z] 05:52:42 INFO - self.protocol.coverage.dump()
[task 2020-01-14T05:52:42.203Z] 05:52:42 INFO - File "Z:\task_1578979384\build\tests\web-platform\tests\tools\wptrunner\wptrunner\executors\executormarionette.py", line 484, in dump
[task 2020-01-14T05:52:42.204Z] 05:52:42 INFO - error = self.marionette.execute_async_script(script)
[task 2020-01-14T05:52:42.204Z] 05:52:42 INFO - File "Z:\task_1578979384\build\venv\lib\site-packages\marionette_driver\marionette.py", line 1656, in execute_async_script
[task 2020-01-14T05:52:42.204Z] 05:52:42 INFO - rv = self._send_message("WebDriver:ExecuteAsyncScript", body, key="value")
[task 2020-01-14T05:52:42.204Z] 05:52:42 INFO - File "Z:\task_1578979384\build\venv\lib\site-packages\marionette_driver\decorators.py", line 26, in _
[task 2020-01-14T05:52:42.204Z] 05:52:42 INFO - return func(*args, **kwargs)
[task 2020-01-14T05:52:42.204Z] 05:52:42 INFO - File "Z:\task_1578979384\build\venv\lib\site-packages\marionette_driver\marionette.py", line 590, in _send_message
[task 2020-01-14T05:52:42.204Z] 05:52:42 INFO - msg = self.client.request(name, params)
[task 2020-01-14T05:52:42.204Z] 05:52:42 INFO - File "Z:\task_1578979384\build\venv\lib\site-packages\marionette_driver\transport.py", line 273, in request
[task 2020-01-14T05:52:42.204Z] 05:52:42 INFO - return self.receive()
[task 2020-01-14T05:52:42.204Z] 05:52:42 INFO - File "Z:\task_1578979384\build\venv\lib\site-packages\marionette_driver\transport.py", line 153, in receive
[task 2020-01-14T05:52:42.204Z] 05:52:42 INFO - chunk = self._sock.recv(bytes_to_recv)
[task 2020-01-14T05:52:42.204Z] 05:52:42 INFO - TEST-INFO took 20048ms
[task 2020-01-14T05:52:42.204Z] 05:52:42 INFO - No more tests
[task 2020-01-14T05:52:45.103Z] 05:52:45 INFO - PID 6212 | [CodeCoverage] flush completed.
[task 2020-01-14T05:52:45.122Z] 05:52:45 INFO - PID 6212 | [CodeCoverage] JS flush completed.
[task 2020-01-14T05:52:48.766Z] 05:52:48 INFO - PID 6212 | [CodeCoverage] flush completed.
[task 2020-01-14T05:52:48.804Z] 05:52:48 INFO - PID 6212 | [CodeCoverage] JS flush completed.
[task 2020-01-14T05:52:52.453Z] 05:52:52 INFO - PID 6212 | [CodeCoverage] flush completed.
[task 2020-01-14T05:52:52.462Z] 05:52:52 INFO - PID 6212 | [CodeCoverage] JS flush completed.
[task 2020-01-14T05:53:53.273Z] 05:53:53 INFO - Browser exited with return code 572
[task 2020-01-14T05:53:53.273Z] 05:53:53 INFO - PROCESS LEAKS None
[task 2020-01-14T05:53:53.274Z] 05:53:53 INFO - PROCESS LEAKS None
[task 2020-01-14T05:53:53.275Z] 05:53:53 INFO - Closing logging queue
[task 2020-01-14T05:53:53.275Z] 05:53:53 WARNING - Traceback (most recent call last):
[task 2020-01-14T05:53:53.275Z] 05:53:53 WARNING - File "Z:\task_1578979384\build\tests\web-platform\tests\tools\wptrunner\wptrunner\executors\executormarionette.py", line 642, in run_func
[task 2020-01-14T05:53:53.275Z] 05:53:53 WARNING - self.result = True, self.func(self.protocol, self.url, self.timeout)
[task 2020-01-14T05:53:53.275Z] 05:53:53 WARNING - File "Z:\task_1578979384\build\tests\web-platform\tests\tools\wptrunner\wptrunner\executors\executormarionette.py", line 762, in do_testharness
[task 2020-01-14T05:53:53.275Z] 05:53:53 WARNING - self.protocol.coverage.dump()
[task 2020-01-14T05:53:53.275Z] 05:53:53 WARNING - File "Z:\task_1578979384\build\tests\web-platform\tests\tools\wptrunner\wptrunner\executors\executormarionette.py", line 489, in dump
[task 2020-01-14T05:53:53.275Z] 05:53:53 WARNING - pass
[task 2020-01-14T05:53:53.276Z] 05:53:53 WARNING - File "c:\mozilla-build\python\Lib\contextlib.py", line 35, in exit
[task 2020-01-14T05:53:53.276Z] 05:53:53 WARNING - self.gen.throw(type, value, traceback)
[task 2020-01-14T05:53:53.276Z] 05:53:53 WARNING - File "Z:\task_1578979384\build\venv\lib\site-packages\marionette_driver\marionette.py", line 1332, in using_context
[task 2020-01-14T05:53:53.276Z] 05:53:53 WARNING - self.set_context(scope)
[task 2020-01-14T05:53:53.276Z] 05:53:53 WARNING - File "Z:\task_1578979384\build\venv\lib\site-packages\marionette_driver\marionette.py", line 1309, in set_context
[task 2020-01-14T05:53:53.276Z] 05:53:53 WARNING - {"value": context})
[task 2020-01-14T05:53:53.276Z] 05:53:53 WARNING - File "Z:\task_1578979384\build\venv\lib\site-packages\marionette_driver\decorators.py", line 26, in _
[task 2020-01-14T05:53:53.276Z] 05:53:53 WARNING - return func(*args, **kwargs)
[task 2020-01-14T05:53:53.276Z] 05:53:53 WARNING - File "Z:\task_1578979384\build\venv\lib\site-packages\marionette_driver\marionette.py", line 590, in _send_message
[task 2020-01-14T05:53:53.276Z] 05:53:53 WARNING - msg = self.client.request(name, params)
[task 2020-01-14T05:53:53.276Z] 05:53:53 WARNING - File "Z:\task_1578979384\build\venv\lib\site-packages\marionette_driver\transport.py", line 273, in request
[task 2020-01-14T05:53:53.276Z] 05:53:53 WARNING - return self.receive()
[task 2020-01-14T05:53:53.276Z] 05:53:53 WARNING - File "Z:\task_1578979384\build\venv\lib\site-packages\marionette_driver\transport.py", line 166, in receive
[task 2020-01-14T05:53:53.276Z] 05:53:53 WARNING - if len(remaining) == int(length):
[task 2020-01-14T05:53:53.276Z] 05:53:53 WARNING - ValueError: invalid literal for int() with base 10: 'script timeout","message"'
[task 2020-01-14T05:53:53.276Z] 05:53:53 WARNING -
[task 2020-01-14T05:53:53.276Z] 05:53:53 INFO - queue closed
[task 2020-01-14T05:53:53.277Z] 05:53:53 INFO - PROCESS LEAKS None
[task 2020-01-14T05:53:53.277Z] 05:53:53 INFO - Got 1 unexpected results
[task 2020-01-14T05:53:53.277Z] 05:53:53 INFO - SUITE-END | took 98s
[task 2020-01-14T05:53:53.307Z] 05:53:53 INFO - Removed font: Ahem.ttf
[task 2020-01-14T05:53:53.326Z] 05:53:53 INFO - Closing logging queue
[task 2020-01-14T05:53:53.326Z] 05:53:53 INFO - queue closed
[task 2020-01-14T05:53:53.530Z] 05:53:53 ERROR - Return code: 1
[task 2020-01-14T05:53:53.548Z] Error: No objdir path for moz-extension://9876bf42-db9a-49f8-8904-3ccea77f01c3/build/buildSettings.js.
[task 2020-01-14T05:53:53.548Z] Couldn't find source info for moz-extension://9876bf42-db9a-49f8-8904-3ccea77f01c3/build/buildSettings.js, removing record
[task 2020-01-14T05:53:53.548Z] Error: No objdir path for moz-extension://9876bf42-db9a-49f8-8904-3ccea77f01c3/background/startBackground.js.
[task 2020-01-14T05:53:53.548Z] Couldn't find source info for moz-extension://9876bf42-db9a-49f8-8904-3ccea77f01c3/background/startBackground.js, removing record
[task 2020-01-14T05:53:53.548Z] Error: No objdir path for Z:\task_1578979384\build\tests\web-platform\tests\tools\wptrunner\wptrunner\executors\executormarionette.py.
[task 2020-01-14T05:53:53.548Z] Couldn't find source info for Z:\task_1578979384\build\tests\web-platform\tests\tools\wptrunner\wptrunner\executors\executormarionette.py, removing record
[task 2020-01-14T05:53:53.549Z] Error: No objdir path for self-hosted.
[task 2020-01-14T05:53:53.549Z] Couldn't find source info for self-hosted, removing record
[task 2020-01-14T05:53:53.617Z] Error: No objdir path for resource://webcompat/aboutPageProcessScript.js.
[task 2020-01-14T05:53:53.617Z] Couldn't find source info for resource://webcompat/aboutPageProcessScript.js, removing record
[task 2020-01-14T05:53:53.617Z] Error: No objdir path for resource://formautofill/FormAutofill.jsm.

Flags: needinfo?(emilio)
Regressed by: 1599206
Has Regression Range: --- → yes
Keywords: regression

This is on ccov only which is tier2 right? Chances are that ccov is just too slow for some of these tests.

Flags: needinfo?(emilio)

Yes, so far only on ccov and one time occurrence

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.