Run subprocess and print output to logging

Question

I am looking for the way to call shell scripts from python and write their stdout and stderr to file using logging. Here is my code:

import logging import tempfile import shlex import os def run_shell_command(command_line): command_line_args = shlex.split(command_line) logging.info('Subprocess: \"' + command_line + '\"') process_succeeded = True try: process_output_filename = tempfile.mktemp(suffix = 'subprocess_tmp_file_') process_output = open(process_output_filename, 'w') command_line_process = subprocess.Popen(command_line_args,\ stdout = process_output,\ stderr = process_output) command_line_process.wait() process_output.close() process_output = open(process_output_filename, 'r') log_subprocess_output(process_output) process_output.close() os.remove(process_output_filename) except: exception = sys.exc_info()[1] logging.info('Exception occured: ' + str(exception)) process_succeeded = False if process_succeeded: logging.info('Subprocess finished') else: logging.info('Subprocess failed') return process_succeeded

And I am sure that there is the way to do it without creating temporary file to store process output. Any ideas?

Does log_subprocess_output expect a file object or a string object? — falsetru
– falsetru, Commented Feb 22, 2014 at 11:52

jfs · Accepted Answer · 2016-11-18 13:29:05Z

86

You could try to pass the pipe directly without buffering the whole subprocess output in memory:

from subprocess import Popen, PIPE, STDOUT process = Popen(command_line_args, stdout=PIPE, stderr=STDOUT) with process.stdout: log_subprocess_output(process.stdout) exitcode = process.wait() # 0 means success

where log_subprocess_output() could look like:

def log_subprocess_output(pipe): for line in iter(pipe.readline, b''): # b'\n'-separated lines logging.info('got line from subprocess: %r', line)

edited Nov 18, 2016 at 13:29

answered Feb 24, 2014 at 4:17

jfs

417k210 gold badges1k silver badges1.7k bronze badges

Sign up to request clarification or add additional context in comments.

23 Comments

0 _ Over a year ago

if the output is expected to be large, then this can hand the subprocess: thraxil.org/users/anders/posts/2008/03/13/…

jfs Over a year ago

@IoannisFilippidis: the code in the answer works for any output no matter how large it is. The article that you've linked does not apply here.

knoight Over a year ago

@J.F.Sebastian - curious is there a need to worry about p.wait()? Docs have a warning about Popen.wait which seems to relate to the issue @IoannisFilippidis brought up.

jfs Over a year ago

@knoight: it is ok to call it after I/O is done (note: p.stdout.close()). Again, the blog post does not apply to the code in the answer (it would apply if you move (DO NOT DO IT!!!) p.wait() before log_subprocess_ouput() call in this case).

jfs Over a year ago

@mark: you are right about p name. It meant command_line_process which is too long for a small code example, I've renamed both to process¶ Your code log.info(p.stdout) does not make sense (it was not from my answer) that is why I've suggested a new question with a complete code example (there could be other errors in your code)¶ Your link accumulates the whole subprocess output in memory before logging anything. The code in my answer allows to log while the child process is still running without exhausting all available memory.

|

Bakuriu · Accepted Answer · 2015-04-02 07:39:55Z

I am sure that there is the way to do it without creating temporary file to store process output

You simply have to check for the documentation of Popen, in particular about stdout and stderr:

stdin, stdout and stderr specify the executed program’s standard input, standard output and standard error file handles, respectively. Valid values are PIPE, an existing file descriptor (a positive integer), an existing file object, and None. PIPE indicates that a new pipe to the child should be created. With the default settings of None, no redirection will occur; the child’s file handles will be inherited from the parent. Additionally, stderr can be STDOUT, which indicates that the stderr data from the child process should be captured into the same file handle as for stdout.

So you can see that you can either use a file object, or the PIPE value. This allows you to use the communicate() method to retrieve the output:

from StringIO import StringIO process = subprocess.Popen(arguments, stdout=subprocess.PIPE, stderr=subprocess.STDOUT) output, error = process.communicate() log_subprocess_output(StringIO(output))

I'd rewrite your code as:

import shlex import logging import subprocess from StringIO import StringIO def run_shell_command(command_line): command_line_args = shlex.split(command_line) logging.info('Subprocess: "' + command_line + '"') try: command_line_process = subprocess.Popen( command_line_args, stdout=subprocess.PIPE, stderr=subprocess.STDOUT, ) process_output, _ = command_line_process.communicate() # process_output is now a string, not a file, # you may want to do: # process_output = StringIO(process_output) log_subprocess_output(process_output) except (OSError, CalledProcessError) as exception: logging.info('Exception occured: ' + str(exception)) logging.info('Subprocess failed') return False else: # no exception was raised logging.info('Subprocess finished') return True

If you don't need to seek inside the file; the pipe could be used as is to log subprocess' output
What does the log_suprocess_output look like for your code sample?
That results in the entire stdout/stderr content to reside in memory as strings, which may not be ideal for processes that do a lot of writing to stdout / stderr.
Sir you are an absolute genius. Thank you so much for this lovely piece of code. I wish I could upvote twice!

leocrimson · Accepted Answer · 2020-04-09 00:14:08Z

I was trying to achieve the same on check_call and check_ouput. I found this solution to be working.

import logging import threading import os import subprocess logging.basicConfig(format='%(levelname)s:%(message)s', level=logging.INFO) class LogPipe(threading.Thread): def __init__(self, level): """Setup the object with a logger and a loglevel and start the thread """ threading.Thread.__init__(self) self.daemon = False self.level = level self.fdRead, self.fdWrite = os.pipe() self.pipeReader = os.fdopen(self.fdRead) self.start() def fileno(self): """Return the write file descriptor of the pipe""" return self.fdWrite def run(self): """Run the thread, logging everything.""" for line in iter(self.pipeReader.readline, ''): logging.log(self.level, line.strip('\n')) self.pipeReader.close() def close(self): """Close the write end of the pipe.""" os.close(self.fdWrite) def write(self): """If your code has something like sys.stdout.write""" logging.log(self.level, message) def flush(self): """If you code has something like this sys.stdout.flush""" pass

After implementing it, I performed the below steps:

try: # It works on multiple handlers as well logging.basicConfig(handlers=[logging.FileHandler(log_file), logging.StreamHandler()]) sys.stdout = LogPipe(logging.INFO) sys.stderr = LogPipe(logging.ERROR) ... subprocess.check_call(subprocess_cmd, stdout=sys.stdout, stderr=sys.stderr) export_output = subprocess.check_output(subprocess_cmd, stderr=sys.stderr) ... finally: sys.stdout.close() sys.stderr.close() # It is neccessary to close the file handlers properly. sys.stdout = sys.__stdout__ sys.stderr = sys.__stderr__ logging.shutdown() os.remove(log_file)

thanos.a · Accepted Answer · 2021-10-07 11:31:09Z

This worked for me:

from subprocess import Popen, PIPE, STDOUT command = f"shell command with arguments" process = Popen(command, shell=True, stdout=PIPE, stderr=STDOUT) with process.stdout: for line in iter(process.stdout.readline, b''): print(line.decode("utf-8").strip())

With exception handling:

from subprocess import Popen, PIPE, STDOUT, CalledProcessError command = f"shell command with arguments" process = Popen(command, shell=True, stdout=PIPE, stderr=STDOUT) with process.stdout: try: for line in iter(process.stdout.readline, b''): print(line.decode("utf-8").strip()) except CalledProcessError as e: print(f"{str(e)}")

The subprocess documentation says that using shell=True is a significant security risk as it opens you up to shell injection vulnerabilities. docs.python.org/2/library/…

ddelange · Accepted Answer · 2025-11-18 15:49:57Z

Handling the live output stream of a command can be achieved by iterating over stdout as the subprocess.Popen runs.

This implementation:

uses a with-statement such that standard file descriptors are closed, and the process is waited for
propagates keyword arguments to the subprocess constructor
defaults to text=True to automatically decode bytestrings into strings
raises a CalledProcessError upon failure if check=True like subprocess.run does
returns a CompletedProcess upon success like subprocess.run does
redirects stderr to stdout (to handle them separately see my multithreaded answer)

import logging from subprocess import PIPE, STDOUT, CalledProcessError, CompletedProcess, Popen def stream_command( args, *, stdout_handler=logging.info, # for a separate stderr_handler (using multithreading), see https://stackoverflow.com/a/76634163/5511061 check=True, text=True, **kwargs, ): """Mimic subprocess.run, while processing the command output in real time ref https://stackoverflow.com/a/76626021/5511061.""" with Popen(args, text=text, stdout=PIPE, stderr=STDOUT, **kwargs) as process: for line in process.stdout: stdout_handler(line[:-1]) retcode = process.poll() if check and retcode: raise CalledProcessError(retcode, process.args) return CompletedProcess(process.args, retcode)

Logging to a file then becomes as simple as setting up logging:

logging.basicConfig( level=logging.INFO, filename="./capture.log", filemode="w", encoding="utf-8", ) logging.info("test from python") stream_command(["echo", "test from subprocess"])

With the resulting file:

$ cat ./capture.log INFO:root:test from python INFO:root:test from subprocess

The behaviour can be tweaked to preference (print instead of logging.info, or both, etc.):

stream_command(["echo", "test"]) # INFO:root:test stream_command("cat ./nonexist", shell=True, check=False) # ERROR:root:cat: ./nonexist: No such file or directory stream_command(["echo", "test"], stdout_handler=print) # test stdout_lines = [] def handler(line): print(line) logging.info(line) stdout_lines.append(line) stream_command(["echo", "test"], stdout_handler=handler) print(stdout_lines) # test # INFO:root:test # ['test']

Collectives™ on Stack Overflow

Run subprocess and print output to logging

5 Answers 5

23 Comments

6 Comments

Comments

1 Comment

1 Comment

Linked

Hot Network Questions

Collectives™ on Stack Overflow

5 Answers 5

23 Comments

6 Comments

Comments

1 Comment

1 Comment

Linked

Related