Python script printouts just appearing at the end of execution when calling it externally and logging stdout/stderr into file

Question

I'm calling a script from another one by using:

command = 'python foo.py'
with open('./logs.txt', 'w') as file:
    p = Popen(command, shell=True, stderr=file, stdout=file)
    p.wait()

Where foo.py does several call for another script bar.py.

By doing this, unfortunately I get a behavior that I didn't want when it's writing to the text file. The printouts are getting messed up and, for some reason, bar.py printouts appears before foo.py, which gets messy as the code follows a linear execution and the printouts I wanted to see were executed before calling bar.py.

When I use sys.stdout and sys.stderr and Popen's stdout and stderr, respectively, I don't see this behavior happening.

Any clue why this happens?

Just to illustrate the situation, a crafted printout, when writing to external file (I will use a third script call for better exemplification):

[bar.py] This is print 1
[xyz.py] This is print 1
[foo.py] This is print 1
[foo.py] This is print 2
[foo.py] This is print 3

What I actually would like to see/it's happening when using sys' stdout/stderr:

[foo.py] This is print 1
[bar.py] This is print 1
[foo.py] This is print 2
[xyz.py] This is print 1
[foo.py] This is print 3

For the foo.py printouts I'm just using Python's print() method. Don't know about the external ones because it wasn't written by me.

Strangely this behavior happens on docker logs too, i.e. when I execute this chain on a container and want to see the printouts . So, I think it can be related in some way.

How can I solve this?

Answer 1

I expect this is due to output buffering.

This answer on stack exchange suggests:

... When process STDOUT is redirected to something other than a terminal, then the output is buffered into some OS-specific-sized buffer (perhaps 4k or 8k in many cases). Conversely, when outputting to a terminal, STDOUT will be line-buffered or not buffered at all, so you'll see output after each \n or for each character

This answer may be helpful, it describes how to disable output buffering.

The easy thing to try would be to tell Python to run unbuffered with the -u flag:

command = 'python -u foo.py'