How to get 'print()', 'os.system()' and 'subprocess.run()' output to be displayed in both console and log file?

Viewed 1569

Initially, I've a simple program to print out the whole output to the console.

Initial Code to display output in the console only

import os, subprocess

print("1. Before")
os.system('ver')                            
subprocess.run('whoami')        
print('\n2. After')

Output in console

1. Before

Microsoft Windows [Version 10]
user01

2. After

Then, I decided to have a copy on a log file (log.txt) too while maintaining the original output to the console.

So, this is the new code.

import os, subprocess, sys

old_stdout = sys.stdout
log_file = open("log.txt","w")
sys.stdout = log_file

print("1. Before")          # This appear in message.log only, but NOT in console
os.system('ver')            # This appear in console only, but NOT in message.log
subprocess.run('whoami')    # This appear in console only, but NOT in message.log
print('\n2. After')         # This appear in message.log only, but NOT in console

sys.stdout = old_stdout
log_file.close()

Unfortunately, this didn't really work as expected. Some of the output only displayed on the console (os.system('ver') and subprocess.run('whoami')) while the print() function was only displayed on log.txt file and not in the console anymore.

Output in console

Microsoft Windows [Version 10]
user01

Output in log.txt file

1. Before

2. After

I was hoping to get similar output on both console and log.txt file. Is this possible? What's wrong with my new code? Please let me know how to fix this.

Desired Output in both console and log.txt file

1. Before

Microsoft Windows [Version 10]
user01

2. After
2 Answers

The most appropriate way to handle this is with logging. Here's an example:

This is the python 2.6+ and 3.x version of how you can do it. (Can't override print() before 2.6)

log = logging.getLogger()
log.setLevel(logging.INFO)

# How should our message appear?
formatter = logging.Formatter('%(message)s')

# This prints to screen
ch = log.StreamHandler()
ch.setLevel(logging.INFO)
ch.setFormatter(formatter)
log.addHandler(ch)

# This prints to file
fh = log.FileHandler('/path/to/output_file.txt')
fh.setLevel(logging.DEBUG)
fh.setFormatter(formatter)
log.addHandler(fh)

def print(*args, **kwargs):
    log.DEBUG(*args)

That option allows you the capability of using logging levels. For instance, you can put debug logging throughout your code for when the application starts acting funky. Swap logLevel to logging.DEBUG and suddenly, you're getting that output to screen. Notice in the above example, we have 2 different logging levels, one for screen and another for file. Yes, this will produce different output to each destination. You can remedy this by changing both to use logging.INFO (or logging.DEBUG, etc). (See full docs relating to log levels here.)

In the above example, I've overridden print(), but I'd recommend instead that you just reference your framework using log.DEBUG('Variable xyz: {}'.format(xyz)) or log.INFO('Some stuff that you want printed.)

Full logging documentation.

There's another, easier way to do it with overriding, but not quite so robust:

try:
    # Python 2
    import __builtin__
except ImportError:
    # Python 3
    import builtins as __builtin__
logfile = '/path/to/logging_file.log'

def print(*args, **kwargs):
    """Your custom print() function."""
    with open(logfile) as f_out:
        f_out.write(args[0])
        f_out.write('\n')
        # Uncomment the below line if you want to tail the log or something where you need that info written to disk ASAP.
        # f_out.flush()
    return __builtin__.print(*args, **kwargs)

There is no magic done by system, file pointer such as stdout and stderr need to be treated differently by your code. For example, stdout is one of the file pointer, you can do it in below:

log_file_pointer = open('log.txt', 'wt')
print('print_to_fp', file=log_file_pointer)
# Note: the print function will actually call log_file_pointer.write('print_to_fp')

Based on your requirement, you want to make the magic function to handle more than one file pointer in single line, you need a wrapper function in below:

def print_fps(content, files=[]):
    for fi in files:
        print(content, file=fi)
# the argument `file` of print does zero magic, it can only handle one file pointer once. 

Then, you can make the magic happen now (make the output in both screen and file.)

import sys

log_file_pointer = open('log.txt', 'wt')
print_fps('1. Before', files=[log_file_pointer, sys.stdout])
print_fps('\n2. After', files=[log_file_pointer, sys.stdout])

After finishing the print part, let's move on to system call. Running any command in the operating system, you will get the return in default system file pointers: stdout and stderr. In python3, you can get those result in bytes by subprocess.Popen. And while running below code, what you want should be the result in stdout.

import subprocess

p = subprocess.Popen("whoami", shell=True, stdout=subprocess.PIPE, stderr=subprocess.PIPE)
stdout, stderr = p.communicate()

# stdout: b'user01'
# stdout: b''

Yet again, you can call the wrapper function written in above and make output in both stdout and targeted file_pointer.

print_fps(stdout, files=[log_file_pointer, sys.stdout])

Finally, combining all the code in above. (Plus one more convenient function.)

import subprocess, sys

def print_fps(content, files=[]):
    for fi in files:
        print(content, file=fi)

def get_stdout(command):
    p = subprocess.Popen(command, shell=True, stdout=subprocess.PIPE, stderr=subprocess.PIPE)
    stdout, stderr = p.communicate()
    # Note: Original idea is to return raw stdout 
    # return stdout
    # Based on the scenario of the @Sabrina, the raw bytes of stdout needs decoding in utf-8 plus replacing newline '\r\n' to be pure
    return stdout.decode().replace('\r\n', '')

log_file_pointer = open('log.txt', 'wt')
print_fps('1. Before', files=[log_file_pointer, sys.stdout])
print_fps(get_stdout('ver'), files=[log_file_pointer, sys.stdout])
print_fps(get_stdout('whoami'), files=[log_file_pointer, sys.stdout])
print_fps('\n2. After', files=[log_file_pointer, sys.stdout])
  • Note: because the output of Popen is in bytes, you might need to do decode to remove b''. You can run stdout.decode() to decode bytes to utf-8 decoded str.*
Related