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:
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?
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?
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 :).
