Truncated Output Log Files When Logging Stdout And Stderr Separately

I have set up a subprocess command within a context manager that pipes the stdout and stderr to separate files via my own logger. This is a variation on the answer given here: http

Solution 1:

I think I've finally figured it out. The problem here is that the StreamLogger code can't explicitly check to make sure the stdout is fully written. Once the main thread running the subprocess receives a returncode, it exits the context manager, calling the __exit__() method of the StreamLogger, which is inherited from IOBase (source code here). And this calls close() which changes the self._run attribute to False. This causes the thread that is polling the pipe to stop looping, regardless of what is still coming through the pipe.

This works fine for most commands with small to moderate outputs to stdout, where there is no lag time between the returncode returning and the output being written. But in my case I'm running a program through subprocess with a substantial amount of text written to stdout. So there's a kind of race against time to try and get the pipe cleared before the main thread tells the child thread to stop polling the pipe.

The two critical variables here are the size of the buffer being read from the pipe and the frequency at which the pipe is polled. I fixed my problem by increasing the buffer size in os.read() to 4096, and also removing the time.sleep() in the while loop in the _flusher() method. This maximizes the amount of data that can be read from the pipe and in my case ensures the output is fully logged before the logging loop stops.