Need a better way to execute console commands from python and log the results

Question

I have a python script which needs to execute several command line utilities. The stdout output is sometimes used for further processing. In all cases, I want to log the results and raise an exception if an error is detected. I use the following function to achieve this:

def execute(cmd, logsink):
    logsink.log("executing: %s\n" % cmd)
    popen_obj = subprocess.Popen(\
          cmd, shell=True, stdout=subprocess.PIPE, stderr=subprocess.PIPE)
    (stdout, stderr) = popen_obj.communicate()
    returncode = popen_obj.returncode
    if (returncode <> 0):
       logsink.log("   RETURN CODE: %s\n" % str(returncode))
    if (len(stdout.strip()) > 0):
       logsink.log("   STDOUT:\n%s\n" % stdout)
    if (len(stderr.strip()) > 0):
       logsink.log("   STDERR:\n%s\n" % stderr)
    if (returncode <> 0):
       raise Exception, "execute failed with error output:\n%s" % stderr
    return stdout

"logsink" can be any python object with a log method. I typically use this to forward the logging data to a specific file, or echo it to the console, or both, or something else...

This works pretty good, except for three problems where I need more fine-grained control than the communicate() method provides:

1. stdout and stderr output can be interleaved on the console, but the above function logs them separately. This can complicate the interpretation of the log. How do I log stdout and stderr lines interleaved, in the same order as they were output?
2. The above function will only log the command output once the command has completed. This complicates diagnosis of issues when commands get stuck in an infinite loop or take a very long time for some other reason. How do I get the log in real-time, while the command is still executing?
3. If the logs are large, it can get hard to interpret which command generated which output. Is there a way to prefix each line with something (e.g. the first word of the cmd string followed by :).

Answer 1

You can redirect to a file if you just want the output in a file for later evaluation.

Your already defining the stdout/stderr of the processes your executuing by the stdout=/stderr= methods.

In your example code your just redirecting to the scripts current out/err assigments.

subprocess.Popen(cmd, shell=True, stdout=subprocess.PIPE, stderr=subprocess.PIPE)

sys.stdout and sys.stderr are just file-like objects. As the documentation documentation on sys.stdout mentions, "Any object is acceptable as long as it has a write() method that takes a string argument."

f = open('cmd_fileoutput.txt', 'w')
subprocess.Popen(cmd, shell=True, stdout=f, stderr=f)

So you only need to given it a class with a write method in order to re-direct output.

If you want both console output and file output may be making a class to manage the output.

General redirection:

# Redirecting stdout and stderr to a file
f = open('log.txt', 'w')
sys.stdout = f
sys.stderr = f

Making a redirection class:

# redirecting to both
class OutputManager:
    def __init__(self, filename, console):
        self.f = open(filename, 'w')
        self.con = console

    def write(self, data):
        self.con.write(data)
        self.f.write(data)

new_stdout = OutputManager("log.txt", sys.stdout)

Interleaving is dependant on buffering, so you may or may not get the output you expect. (You can probably turn off or reduce the buffering used, but I don't remember how at the moment)

Answer 2

You can look into pexpect (http://www.noah.org/wiki/Pexpect)

It solves 1) and 2) out of the box, prefixing the output might be a little trickier.

Answer 3

One other option:

def run_test(test_cmd):
    with tempfile.TemporaryFile() as cmd_out:
        proc = subprocess.Popen(test_cmd, stdout=cmd_out, stderr=cmd_out)
        proc.wait()
        cmd_out.seek(0)
        output = "".join(cmd_out.readlines())
    return (proc.returncode, output)

This will interleave stdout and stderr as desired, in a real file that is conveniently open for you.

Answer 4

This is by no means a complete or exhaustive answer, but perhaps you should look into the Fabric module.

http://docs.fabfile.org/0.9.1/

Makes parallel execution of shell commands and error handling rather easy.