875508 - [mozprocess] Consider buffering output from mozprocess processes

Status: RESOLVED DUPLICATE of bug 794984

(Testing :: Mozbase, defect)

Description

[Gregory Szorc [:gps]]

Currently, mozprocess's processOutputLine handlers run on the main Python thread and appear to slow down the child processes's execution if the processOutputLine handlers are slow (at least on some platforms).

For example, on OS X I launched |make| for part of the Firefox build that should consume a lot of CPU while sending some output to stdout. Not a lot of output - just a single line per file being processed. If my processOutputLine handler is simple and just re-writes the line to the terminal's stdout, things are fine. I get 100% CPU saturation (as expected). But, if I perform a time.sleep(0.25) in the processOutputLine handler, I notice that CPU usage of make drops drastically. And, it drops suddenly.

I suspect that make's write(stdout) is blocking waiting on mozprocess to finish the read(stdout) and it is blocking because the pipe is unbuffered.

Anyway, the problem here is that if processOutputLine does "blocks," this could substantially slow down the executed process and prevent it from finishing sooner.

It would be rad if mozprocess had a "buffered output" option where processOutputLine() could be called on a separate thread from process output reading. That way, if processOutputLine() were slow, it wouldn't affect the underlying process - at least until a buffer became saturated. You *might* be able to do this by using a buffered pipe for stdout. But, I'm not sure if Python gives you that control. It might be easier to just spin up a new Python thread to handle calling out to processOutputLine().

Comment 1

[Andrew Halberstadt [:ahal]]

The output processing does happen in a thread: https://github.com/mozilla/mozbase/blob/master/mozprocess/mozprocess/processhandler.py#L71

Is this happening because of the GIL?

Comment 2

[Andrew Halberstadt [:ahal]]

Oops, cut a number off that link:
https://github.com/mozilla/mozbase/blob/master/mozprocess/mozprocess/processhandler.py#L713

Comment 3

[(not currently active) Ted Mielczarek]

I don't think this is the GIL, I think the existing mozprocess thread just isn't doing quite what gps envisions here. The I/O thread is reading from the process' stdout and passing each line to the handler. If the handler is slow, reading from stdout will be equally slow and could block execution of the process. What we'd ideally want here is a thread that reads stdout from the process as quickly as possible into a buffer, and then a separate thread that feeds that to the handler as fast as it will take it.

Comment 4

[Andrew Halberstadt [:ahal]]

I believe this is going to get fixed as a side effect from the patch in bug 794984. Once that lands there will be three threads:

* One reading stdout and storing lines into a Queue as fast as possible
* A second reading stderr and storing lines into the same Queue
* A third popping lines off the Queue and executing callbacks

Comment 5

[Andrew Halberstadt [:ahal]]

This should be fixed as a side-effect of the patch in bug 794984. If you disagree please feel free to re-open.