1477115 - Intermittent timeout: Connection timed out after 360s linux asan

Reporter

Description

•

6 years ago

treeherder

Filed by: ccoroiu [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=189018201&repo=mozilla-inbound

https://queue.taskcluster.net/v1/task/VvhEejS5Sz-AZdGbEcCSGg/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/VvhEejS5Sz-AZdGbEcCSGg/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1

[task 2018-07-19T20:34:42.496Z] 20:34:42     INFO - TEST-START | /css/css-shapes/shape-outside/shape-image/shape-image-000.html
[task 2018-07-19T20:40:42.504Z] 20:40:42 CRITICAL - Traceback (most recent call last):
[task 2018-07-19T20:40:42.505Z] 20:40:42 CRITICAL -   File "/builds/worker/workspace/build/tests/web-platform/tests/tools/wptrunner/wptrunner/testrunner.py", line 134, in start_runner
[task 2018-07-19T20:40:42.505Z] 20:40:42 CRITICAL -     runner.run()
[task 2018-07-19T20:40:42.506Z] 20:40:42 CRITICAL -   File "/builds/worker/workspace/build/tests/web-platform/tests/tools/wptrunner/wptrunner/testrunner.py", line 83, in run
[task 2018-07-19T20:40:42.506Z] 20:40:42 CRITICAL -     self.setup()
[task 2018-07-19T20:40:42.507Z] 20:40:42 CRITICAL -   File "/builds/worker/workspace/build/tests/web-platform/tests/tools/wptrunner/wptrunner/testrunner.py", line 70, in setup
[task 2018-07-19T20:40:42.507Z] 20:40:42 CRITICAL -     self.executor.setup(self)
[task 2018-07-19T20:40:42.508Z] 20:40:42 CRITICAL -   File "/builds/worker/workspace/build/tests/web-platform/tests/tools/wptrunner/wptrunner/executors/executormarionette.py", line 717, in setup
[task 2018-07-19T20:40:42.508Z] 20:40:42 CRITICAL -     self.implementation.setup(**self.implementation_kwargs)
[task 2018-07-19T20:40:42.509Z] 20:40:42 CRITICAL -   File "/builds/worker/workspace/build/tests/web-platform/tests/tools/wptrunner/wptrunner/executors/executormarionette.py", line 808, in setup
[task 2018-07-19T20:40:42.510Z] 20:40:42 CRITICAL -     self.executor.protocol.marionette._send_message("reftest:setup", data)
[task 2018-07-19T20:40:42.511Z] 20:40:42 CRITICAL -   File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/decorators.py", line 31, in _
[task 2018-07-19T20:40:42.512Z] 20:40:42 CRITICAL -     m._handle_socket_failure()
[task 2018-07-19T20:40:42.514Z] 20:40:42 CRITICAL -   File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/marionette.py", line 813, in _handle_socket_failure
[task 2018-07-19T20:40:42.515Z] 20:40:42 CRITICAL -     reraise(exc, val, tb)
[task 2018-07-19T20:40:42.515Z] 20:40:42 CRITICAL -   File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/decorators.py", line 26, in _
[task 2018-07-19T20:40:42.516Z] 20:40:42 CRITICAL -     return func(*args, **kwargs)
[task 2018-07-19T20:40:42.517Z] 20:40:42 CRITICAL -   File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/marionette.py", line 753, in _send_message
[task 2018-07-19T20:40:42.517Z] 20:40:42 CRITICAL -     msg = self.client.request(name, params)
[task 2018-07-19T20:40:42.518Z] 20:40:42 CRITICAL -   File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/transport.py", line 273, in request
[task 2018-07-19T20:40:42.519Z] 20:40:42 CRITICAL -     return self.receive()
[task 2018-07-19T20:40:42.520Z] 20:40:42 CRITICAL -   File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/transport.py", line 183, in receive
[task 2018-07-19T20:40:42.520Z] 20:40:42 CRITICAL -     raise socket.timeout("Connection timed out after {}s".format(self.socket_timeout))
[task 2018-07-19T20:40:42.521Z] 20:40:42 CRITICAL - timeout: Connection timed out after 360s
[task 2018-07-19T20:40:42.521Z] 20:40:42 CRITICAL - 
[task 2018-07-19T20:40:42.570Z] 20:40:42     INFO - Browser exited with return code -15
[task 2018-07-19T20:40:42.571Z] 20:40:42  WARNING - Traceback (most recent call last):
[task 2018-07-19T20:40:42.571Z] 20:40:42  WARNING -   File "/builds/worker/workspace/build/tests/web-platform/tests/tools/wptrunner/wptrunner/executors/executormarionette.py", line 827, in teardown
[task 2018-07-19T20:40:42.572Z] 20:40:42  WARNING -     self.executor.protocol.marionette._send_message("reftest:teardown", {})
[task 2018-07-19T20:40:42.572Z] 20:40:42  WARNING -   File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/decorators.py", line 26, in _
[task 2018-07-19T20:40:42.572Z] 20:40:42  WARNING -     return func(*args, **kwargs)
[task 2018-07-19T20:40:42.573Z] 20:40:42  WARNING -   File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/marionette.py", line 750, in _send_message
[task 2018-07-19T20:40:42.573Z] 20:40:42  WARNING -     raise errors.MarionetteException("Please start a session")
[task 2018-07-19T20:40:42.573Z] 20:40:42  WARNING - MarionetteException: Please start a session

Cristina Coroiu [:ccoroiu]

Updated

•

6 years ago

Depends on: 1354232

Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)

Comment 1

•

6 years ago

James, can you take a look at this, please?

Component: CSS Parsing and Computation → web-platform-tests

Product: Core → Testing

Andreea Pavel [:apavel]

Comment 2

•

6 years ago

This seems to have started on the push where the bug was filed, Bug 1354232.

Comment hidden (Intermittent Failures Robot)

14 failures in 653 pushes (0.021 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* mozilla-inbound: 7
* autoland: 4
* mozilla-central: 3

Platform breakdown:
* linux64: 13
* linux64-qr: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1477115&startday=2018-07-16&endday=2018-07-22&tree=trunk

Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)

Comment 5

•

6 years ago

James, can you take a look at this, please?

Flags: needinfo?(james)

James Graham [:jgraham]

Comment 6

•

6 years ago

If we're not seeing this on other builds, it's possible that the ASAN build is just taking >360s to start up. But that seems very long indeed…

James Graham [:jgraham]

Comment 7

•

6 years ago

Only happening with reftests seems pretty suspicious though; maybe something in the marionette reftest implementation has a race condition or so…

Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)

Updated

•

6 years ago

Comment 9

•

6 years ago

There have been 46 failures since the bug was filed, on linux64 asan.

Recent failure log:
https://treeherder.mozilla.org/logviewer.html#?job_id=189785176&repo=autoland&lineNumber=13469

[task 2018-07-24T13:40:58.988Z] 13:40:58     INFO - TEST-START | /css/css-scoping/css-scoping-shadow-assigned-node-with-before-after.html
[task 2018-07-24T13:46:59.133Z] 13:46:59 CRITICAL - Traceback (most recent call last):
[task 2018-07-24T13:46:59.133Z] 13:46:59 CRITICAL -   File "/builds/worker/workspace/build/tests/web-platform/tests/tools/wptrunner/wptrunner/testrunner.py", line 134, in start_runner
[task 2018-07-24T13:46:59.133Z] 13:46:59 CRITICAL -     runner.run()
[task 2018-07-24T13:46:59.133Z] 13:46:59 CRITICAL -   File "/builds/worker/workspace/build/tests/web-platform/tests/tools/wptrunner/wptrunner/testrunner.py", line 83, in run
[task 2018-07-24T13:46:59.133Z] 13:46:59 CRITICAL -     self.setup()
[task 2018-07-24T13:46:59.133Z] 13:46:59 CRITICAL -   File "/builds/worker/workspace/build/tests/web-platform/tests/tools/wptrunner/wptrunner/testrunner.py", line 70, in setup
[task 2018-07-24T13:46:59.133Z] 13:46:59 CRITICAL -     self.executor.setup(self)
[task 2018-07-24T13:46:59.133Z] 13:46:59 CRITICAL -   File "/builds/worker/workspace/build/tests/web-platform/tests/tools/wptrunner/wptrunner/executors/executormarionette.py", line 724, in setup
[task 2018-07-24T13:46:59.133Z] 13:46:59 CRITICAL -     self.implementation.setup(**self.implementation_kwargs)
[task 2018-07-24T13:46:59.133Z] 13:46:59 CRITICAL -   File "/builds/worker/workspace/build/tests/web-platform/tests/tools/wptrunner/wptrunner/executors/executormarionette.py", line 815, in setup
[task 2018-07-24T13:46:59.134Z] 13:46:59 CRITICAL -     self.executor.protocol.marionette._send_message("reftest:setup", data)
[task 2018-07-24T13:46:59.135Z] 13:46:59 CRITICAL -   File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/decorators.py", line 31, in _
[task 2018-07-24T13:46:59.136Z] 13:46:59 CRITICAL -     m._handle_socket_failure()
[task 2018-07-24T13:46:59.136Z] 13:46:59 CRITICAL -   File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/marionette.py", line 813, in _handle_socket_failure
[task 2018-07-24T13:46:59.137Z] 13:46:59 CRITICAL -     reraise(exc, val, tb)
[task 2018-07-24T13:46:59.138Z] 13:46:59 CRITICAL -   File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/decorators.py", line 26, in _
[task 2018-07-24T13:46:59.138Z] 13:46:59 CRITICAL -     return func(*args, **kwargs)
[task 2018-07-24T13:46:59.139Z] 13:46:59 CRITICAL -   File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/marionette.py", line 753, in _send_message
[task 2018-07-24T13:46:59.140Z] 13:46:59 CRITICAL -     msg = self.client.request(name, params)
[task 2018-07-24T13:46:59.141Z] 13:46:59 CRITICAL -   File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/transport.py", line 273, in request
[task 2018-07-24T13:46:59.142Z] 13:46:59 CRITICAL -     return self.receive()
[task 2018-07-24T13:46:59.144Z] 13:46:59 CRITICAL -   File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/transport.py", line 183, in receive
[task 2018-07-24T13:46:59.145Z] 13:46:59 CRITICAL -     raise socket.timeout("Connection timed out after {}s".format(self.socket_timeout))
[task 2018-07-24T13:46:59.146Z] 13:46:59 CRITICAL - timeout: Connection timed out after 360s
[task 2018-07-24T13:46:59.147Z] 13:46:59 CRITICAL - 
[task 2018-07-24T13:46:59.205Z] 13:46:59     INFO - Browser exited with return code -15

Whiteboard: [stockwell needswork]

Comment hidden (Intermittent Failures Robot)

21 failures in 138 pushes (0.152 failures/push) were associated with this bug yesterday.    

Repository breakdown:
* autoland: 10
* mozilla-inbound: 7
* mozilla-central: 4

Platform breakdown:
* linux64: 21

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1477115&startday=2018-07-25&endday=2018-07-25&tree=trunk

Comment hidden (Intermittent Failures Robot)

18 failures in 142 pushes (0.127 failures/push) were associated with this bug yesterday.    

Repository breakdown:
* autoland: 11
* mozilla-inbound: 5
* mozilla-central: 2

Platform breakdown:
* linux64: 18

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1477115&startday=2018-07-26&endday=2018-07-26&tree=trunk

Comment hidden (Intermittent Failures Robot)

17 failures in 134 pushes (0.127 failures/push) were associated with this bug yesterday.    

Repository breakdown:
* mozilla-inbound: 8
* autoland: 8
* mozilla-central: 1

Platform breakdown:
* linux64: 17

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1477115&startday=2018-07-27&endday=2018-07-27&tree=trunk

Comment hidden (Intermittent Failures Robot)

99 failures in 760 pushes (0.13 failures/push) were associated with this bug in the last 7 days. 

This is the #15 most frequent failure this week. 

** This failure happened more than 75 times this week! Resolving this bug is a very high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 1 week, the affected test(s) may be disabled. **   

Repository breakdown:
* autoland: 49
* mozilla-inbound: 37
* mozilla-central: 13

Platform breakdown:
* linux64: 99

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1477115&startday=2018-07-23&endday=2018-07-29&tree=trunk

Comment hidden (Intermittent Failures Robot)

15 failures in 114 pushes (0.132 failures/push) were associated with this bug yesterday.    

Repository breakdown:
* mozilla-inbound: 8
* autoland: 6
* try: 1

Platform breakdown:
* linux64: 15

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1477115&startday=2018-07-30&endday=2018-07-30&tree=trunk

Comment hidden (Intermittent Failures Robot)

20 failures in 546 pushes (0.037 failures/push) were associated with this bug yesterday.

** This test has failed more than 150 times in the last 21 days. It should be disabled until it can be fixed. ** 

Repository breakdown:
* mozilla-inbound: 14
* autoland: 6

Platform breakdown:
* linux64: 20

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1477115&startday=2018-08-02&endday=2018-08-02&tree=all

James Graham [:jgraham]

Comment 17

•

6 years ago

This seems to have stopped occuring on August 4th. I'm not sure what happened then though.

Flags: needinfo?(james)

Firefox Bug Husbandry Bot

Comment 18

•

6 years ago

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup

Status: NEW → RESOLVED

Closed: 6 years ago

Resolution: --- → INCOMPLETE

Eliza Balazs [:ebalazs_]

Comment 19

•

6 years ago

Recent failure log: https://treeherder.mozilla.org/logviewer.html#?job_id=200406919&repo=autoland&lineNumber=2820

Status: RESOLVED → REOPENED

Resolution: INCOMPLETE → ---

Comment hidden (Intermittent Failures Robot)

5 failures in 2902 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:
* autoland: 2
* mozilla-inbound: 2
* mozilla-central: 1

Platform breakdown:
* linux64: 5

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1477115&startday=2018-09-17&endday=2018-09-23&tree=all

Comment hidden (Intermittent Failures Robot)

6 failures in 2773 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:
* autoland: 4
* try: 1
* mozilla-central: 1

Platform breakdown:
* linux64: 6

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1477115&startday=2018-09-24&endday=2018-09-30&tree=all

Comment hidden (Intermittent Failures Robot)

2 failures in 2708 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:
* autoland: 1
* try: 1

Platform breakdown:
* linux64: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1477115&startday=2018-10-01&endday=2018-10-07&tree=all

Comment hidden (Intermittent Failures Robot)

1 failures in 2740 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:
* autoland: 1

Platform breakdown:
* linux64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1477115&startday=2018-10-08&endday=2018-10-14&tree=all

Comment hidden (Intermittent Failures Robot)

1 failures in 2759 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-central: 1

Platform breakdown:
* linux64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1477115&startday=2018-10-15&endday=2018-10-21&tree=all

Firefox Bug Husbandry Bot

Comment 25

•

6 years ago

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup

Status: REOPENED → RESOLVED

Closed: 6 years ago → 6 years ago

Resolution: --- → INCOMPLETE

Firefox Bug Husbandry Bot

Comment 26

•

6 years ago

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup