Search code examples
pythonstdoutstderrchild-process

Redirecting stdout/stderr of a child process to a file


I have a Python script (popen.py) which runs another Python script (counter.py) as a child process with the output redirected to /tmp/counter.log. The code I am using is:

/tmp/counter.py

#!/usr/bin/env python2
import time

i = 0
while True:
    print i
    i +=1
    time.sleep(1)

/tmp/popen.py

#!/usr/bin/env python2
import subprocess

f = open("/tmp/counter.log", "a+")
p = subprocess.Popen("/tmp/counter.py", stdout=f, stderr=f, bufsize=1)

However when I run popen.py the child process is created and stays running, however nothing get written to /tmp/counter.log until the output reaches 4096 bytes, then it appears to be flushed to the file.

Is there any way I can get my child process to write to the logfile line-by-line without modifying the counter.py script itself?

The reason I don't want to modify counter.py is that the child process may not always be running a Python script. I've tried the same thing running a small executable (written in C) and the same problem occurs.

I have tried writing a self-flushing wrapper for the file and using that for stdout as described here but that doesn't work either.

I've done some debugging with lsof and strace and this is what I've managed to find out:

lsof (file descriptors)

Running /tmp/counter.py manually

COMMAND PID   USER   FD   TYPE DEVICE SIZE/OFF   NODE NAME
python2 629 daniel    0u   CHR  136,0      0t0      3 /dev/pts/0
python2 629 daniel    1u   CHR  136,0      0t0      3 /dev/pts/0
python2 629 daniel    2u   CHR  136,0      0t0      3 /dev/pts/0

Running /tmp/counter.py via /tmp/popen.py

COMMAND PID   USER   FD   TYPE DEVICE SIZE/OFF   NODE NAME
python2 638 daniel    0u   CHR  136,0      0t0      3 /dev/pts/0
python2 638 daniel    1u   REG  202,0        0    768 /tmp/counter.log
python2 638 daniel    2u   REG  202,0        0    768 /tmp/counter.log

strace (system calls during the while loop)

Running /tmp/counter.py manually

select(0, NULL, NULL, NULL, {1, 0})     = 0 (Timeout)
write(1, "11\n", 3)                     = 3
select(0, NULL, NULL, NULL, {1, 0})     = 0 (Timeout)
write(1, "12\n", 3)                     = 3
select(0, NULL, NULL, NULL, {1, 0})     = 0 (Timeout)
write(1, "13\n", 3)                     = 3
select(0, NULL, NULL, NULL, {1, 0})     = 0 (Timeout)
write(1, "14\n", 3)                     = 3
select(0, NULL, NULL, NULL, {1, 0})     = 0 (Timeout)
write(1, "15\n", 3)                     = 3

Running /tmp/counter.py via /tmp/popen.py

select(0, NULL, NULL, NULL, {1, 0})     = 0 (Timeout)
select(0, NULL, NULL, NULL, {1, 0})     = 0 (Timeout)
select(0, NULL, NULL, NULL, {1, 0})     = 0 (Timeout)
select(0, NULL, NULL, NULL, {1, 0})     = 0 (Timeout)
select(0, NULL, NULL, NULL, {1, 0})     = 0 (Timeout)
...
write(1, "11\n12\n13\n14\n15\n16\n17\n18\n"..., 4096) = 4096

Solution

  • The solution I ended up using, which does not fully solve the problem, but is the most acceptable compromise at this point, is to set the PYTHONUNBUFFERED environment variable while spawning a child process:

    #!/usr/bin/env python2
    import subprocess
    
    f = open("/tmp/counter.log", "a+")
    p = subprocess.Popen("/tmp/counter.py", stdout=f, stderr=f, env={
        "PYTHONUNBUFFERED": "Yes please"
    })
    

    This has the lowest overhead in terms of extra code and additional processes, but only works if the child process is a Python script.