Henrik Skupin [:whimboo][⌚️UTC+1] Reporter
	Description • 6 years ago

Bug 1407383 fixed a hang in wdspec jobs for an issue in mozlog. Here we seem to hang when starting the runner:

https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1407383&startday=2018-03-07&endday=2018-03-11&tree=all

[task 2018-03-09T22:02:26.685Z] 22:02:26     INFO - PID 2998 | Headers { Connection: close
[task 2018-03-09T22:02:26.687Z] 22:02:26     INFO - PID 2998 | , Content-Type: application/json; charset=utf-8
[task 2018-03-09T22:02:26.687Z] 22:02:26     INFO - PID 2998 | , Cache-Control: no-cache
[task 2018-03-09T22:02:26.688Z] 22:02:26     INFO - PID 2998 | , Content-Length: 13
[task 2018-03-09T22:02:26.688Z] 22:02:26     INFO - PID 2998 | , Date: Fri, 09 Mar 2018 22:02:16 GMT
[task 2018-03-09T22:02:26.688Z] 22:02:26     INFO - PID 2998 | , }]
[task 2018-03-09T22:02:26.689Z] 22:02:26     INFO - PID 2998 | 1520632936362	hyper::server::response	DEBUG	write 13 bytes
[task 2018-03-09T22:02:26.689Z] 22:02:26     INFO - PID 2998 | 1520632936362	hyper::server::response	TRACE	ending
[task 2018-03-09T22:02:26.691Z] 22:02:26     INFO - Starting runner
[task 2018-03-09T22:19:36.599Z] 22:19:36     INFO - Automation Error: mozprocess timed out after 1000 seconds running ['/builds/worker/workspace/build/venv/bin

Interestingly this is visible since we see the excessive logging of hyper which I filed as bug 1444431. Maybe that is related.

	Henrik Skupin [:whimboo][⌚️UTC+1] Reporter
	Comment 1 • 6 years ago

The actual failure count is low yet, so moving to P5.

	Henrik Skupin [:whimboo][⌚️UTC+1] Reporter
	Comment 4 • 6 years ago

The patch on bug 1444431 fixed it in central, but it was missed to also uplift to beta. I requested it, and we should see a drop of the failure soon.

	Henrik Skupin [:whimboo][⌚️UTC+1] Reporter
	Comment 5 • 6 years ago

(In reply to OrangeFactor Robot from comment #3)
> * mozilla-release: 1

This is actually a hang which was fixed by bug 1407383 but which didn't make it to release.

	Henrik Skupin [:whimboo][⌚️UTC+1] Reporter
	Comment 6 • 6 years ago

I wonder if too much log output actually causes this hang. It reminds me to a warning as put into the Python subprocess `Popen.wait()` documentation:

> This will deadlock when using stdout=PIPE and/or stderr=PIPE and the child process generates enough output to a pipe such that it blocks waiting for the OS pipe buffer to accept more data. Use communicate() to avoid that. 

James and Andreas, how do we communicate with the subprocesses?

	Andreas Tolfsen ❲:ato❳ Assignee
	Comment 7 • 6 years ago

For the WebDriver servers, wptrunner uses mozprocess.ProcessHandler’s
processOutputLine:

    https://searchfox.org/mozilla-central/rev/028cd8342899357d80fafba2d528a0fd5819e316/testing/web-platform/tests/tools/wptrunner/wptrunner/webdriver_server.py#55-61

It does look like mozprocesses uses subprocess.PIPE internally.

	Henrik Skupin [:whimboo][⌚️UTC+1] Reporter
	Comment 9 • 6 years ago

Since bug 1444431 has been uplifted to mozilla-beta those hangs are gone.