Getting Realtime Output Using Subprocess

Getting realtime output using subprocess

I tried this, and for some reason while the code

for line in p.stdout:
  ...

buffers aggressively, the variant

while True:
  line = p.stdout.readline()
  if not line: break
  ...

does not. Apparently this is a known bug: http://bugs.python.org/issue3907 (The issue is now "Closed" as of Aug 29, 2018)

How to get realtime Python subprocess output?

This is one way to do it and it worked for me in a Linux shell. It uses an unbuffered IO object and prints out one character at a time. I'm quite sure there are better ways since I'm not an expert on either subprocess or event handling. You may also want to look into asyncio.

with subprocess.Popen(cmd, stdout=subprocess.PIPE, bufsize=0) as p:
    char = p.stdout.read(1)
    while char != b'':
        print(char.decode('UTF-8'), end='', flush=True)
        char = p.stdout.read(1)

Getting realtime and full output using subprocess

Why don't you collect the complete/full output along the way?

backup = subprocess.Popen("rsync ....", shell=True, stdout=subprocess.PIPE, stderr=subprocess.STDOUT)
full = []
for line in iter(backup.stdout.readline, b''):
   line = line.rstrip().decode('utf8')
   print(">>>", line)
   full.append(line)

output = '\n'.join(full)
print("full output:", output)

Realtime output from subprocess in Python

Getting (or rather, not getting) real time output is a perennial annoyance when calling subprocesses in Python. See this question for an in-depth discussion, but the short version is that adding the keyword arg bufsize=1 to the Popen call may be the secret sauce you need.

Also, why do you have time.sleep(10)? You do realize that means that you'll have to wait 10 seconds in between each line getting logged, right? Try restructuring the calls you're making to read the output. Assuming you're using Python 3, try this:

from subprocess import PIPE, Popen

with Popen(command, shell=True, stdout=PIPE, bufsize=1) as sp:
    for line in sp.stdout:
        logging.critical(line)

I just tested the above code and can confirm it works. Try it out yourself here. The linked test version prints a timestamp before each line of the log.

If that's still not working

There's nothing you can do in the Python script if the subprocess you're calling doesn't flush it's output on a regular basis. You mentioned Django, right? Is the output you're trying to log being produced via standard Python print() calls? If so, you can modify them to flush more aggressively:

print(s, flush=True)

Every other language I've worked with also has an equivalent flush command, so (assuming you have access to/can modify the source of the subprocess) you should be able to make this work.

---

Related Topics