3

I am running a Django webserver, and am trying to print the output of a subprocess in real-time to the log. If I commend out the readline line and uncomment the yowzer line, I get the desired stream of logged output, but as soon as I try to run this as-is I get no output. What am I doing wrong? All the results I can find seem to suggest that this would work as-is.

sp = subprocess.Popen(command, shell=True, stdout=subprocess.PIPE)

while sp.poll() is None:
    logging.critical(sp.stdout.readline())
    #logging.critical('yowzer')
    time.sleep(10)

Thank you!

[edit April 3] It turns out the issue wasn't that the command was long-running, but rather that I was using a semicolon to concat a 'su user' command with the main command. Removing the su solved the issue.

2 Answers2

4

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.

tel
  • 13,005
  • 2
  • 44
  • 62
  • Thanks tel! I've tried adding bufsize=1 and it still doesn't seem to work. I've noticed that if I have both yowzer and the readline logging going, the yowzer line doesn't get logged either. – katrinaathedvig Mar 28 '18 at 22:35
  • Thanks tel! I tried running your example script with 'dd if=/dev/zero of=/dev/stdout' (my command is a long-running process) and it still seems to hang. Is there no way to get output before the command is done running? – katrinaathedvig Mar 28 '18 at 23:21
  • @katrinaathedvig the thing about the `dd if=/dev/zero of=/dev/stdout` command is that, even if you just run it in a terminal, it won't produce any output whatsoever until it either dies or receives a signal (ie `TERM`). So of course a Python script won't be able to log the output in real time, since the output doesn't exist until the command is finished. If that's the kind of problem you're running into, see the section under "If that's still not working" in my answer above – tel Mar 29 '18 at 00:10
  • Ah, I tested it out with count=500 before running it without, and somehow didn't notice the difference in output. The main command I'm running does generate output before it finishes though. – katrinaathedvig Mar 29 '18 at 00:54
  • 1
    If your command is a python script (`command = ['python','myscript.py']`), and you can't / don't want to provide the keyword argument `flush=True` to all print statements, you can try using the unbuffered command line option for python `command = ['python','-u','myscript.py']` – mario Apr 15 '20 at 13:19
0

This is an old post, but in Python 3 -- tested in Python 3.11 -- the following code worked for me, to stream live or "real time" output using the subprocess module:

import sys
from os import fdopen
from subprocess import Popen, PIPE, STDOUT


with Popen(command,
           shell=True,
           stdout=PIPE,
           stderr=STDOUT) as sp:

    with fdopen(sys.stdout.fileno(), 'wb', closefd=False) as stdout:

        for line in sp.stdout:
            stdout.write(line)
            stdout.flush()

Convenience Function

As it's idiomatic, I usually create a convenience function run to chain a list of commands in the terminal and stream the output in real time.

Note that I use && as the separator here, but you could easily use another one, such as ; if you don't want to fail early on error, or even & instead.

import sys
from os import fdopen
from subprocess import Popen, PIPE, STDOUT

def run(cmds, join='&&'):
    with Popen(join.join(cmds),
               shell=True,
               stdout=PIPE,
               stderr=STDOUT) as sp:
        with fdopen(sys.stdout.fileno(), 'wb', closefd=False) as stdout:
            for line in sp.stdout:
                stdout.write(line)
                stdout.flush()

Usage is like so:

commands = [
    'echo hello',
    'sleep 3',
    'echo world',
    'sleep 2',
    'echo !',
]
run(commands)
rv.kvetch
  • 9,940
  • 3
  • 24
  • 53