4

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
Kir Chou
  • 2,980
  • 1
  • 36
  • 48
  • 1
    If you don't mind creating a "wrapper" running your original program piped to `tee logfile` , see here https://en.wikipedia.org/wiki/Tee_(command) – VPfB Jan 05 '19 at 12:55

2 Answers2

2

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)
UtahJarhead
  • 2,091
  • 1
  • 14
  • 21
  • 1
    Thanks UtahJarhead, I tried to run your code but getting so much error. e.g. `formatter = log.Formatter('%(message)s') AttributeError: 'RootLogger' object has no attribute 'Formatter'` Previous code provided by @Kir Chou almost perfect, but there is some unwanted character in the output such as `b'\r\n`. –  Jan 06 '19 at 03:03
  • This doesn't handle the case of `os.system` which simply uses the stdout and stderr file descriptors directly. But there is no good reason to use `os.system` anyway; this is one of many, many reasons to always prefer `subprocess.run`. – tripleee Jan 06 '19 at 10:27
  • @Sabrina, valid point. I had a typo. Instead of `log.Formatter()` it needed to be `logging.formatter()`. My bad. – UtahJarhead Jan 07 '19 at 16:56
  • @tripleee, Agreed, but I preferr `subprocess.Popen()` or `subprocess.check_output()` – UtahJarhead Jan 07 '19 at 16:56
  • Thanks @UtahJarhead ... I changed the code but still getting an error `formatter = logging.formatter('%(message)s') AttributeError: module 'logging' has no attribute 'formatter'` –  Jan 07 '19 at 17:57
  • 1
    As per the Python documentation, you should generally avoid `Popen` if one of the higher-level wrapper functions does what you need. `subprocess.run` is more versatile than the legacy `check_*` functions though I suppose they still have their place. – tripleee Jan 07 '19 at 18:50
  • @Sabrina, capitalize Formatter. Sorry 'bout that. Was typing it off the cuff. – UtahJarhead Jan 07 '19 at 20:10
1

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.*
Kir Chou
  • 2,980
  • 1
  • 36
  • 48
  • With regard to decoding program output, unfortunately with the Windows command line, programs may output text as the console input or output codepage (defaults to system locale OEM), the system locale OEM or ANSI codepage, the user locale OEM or ANSI codepage, the user's preferred UI language, UTF-8, or even UTF-16. You have to know what the program does on a case by case basic. It's complete chaos. We're in luck if all text happens to be (7-bit) ASCII. – Eryk Sun Jan 05 '19 at 18:30
  • Thats not windows specific. On Linux it is the LC_* madness. Try displaying a Linux ext4 filename correctly... – schlenk Jan 06 '19 at 01:35
  • Thanks @Kir Chou, your code is working, but there is some unwanted char such as `b'\r\nMicrosoft Windows [Version 10]\r\n'` ... would it be possible to remove `b'\r\n`? –  Jan 06 '19 at 03:05
  • 1
    @Sabrina The reason why it returned with `\r\n` was because the stdout got the raw output without any decoding. In your case, you can post process the data by `stdout.decode().replace('\r\n', '')`. This should work if the returned stdout can be decoded in utf8. Knowing that dealing str and bytes is another big topic in Python, i’m not going to explain deeply here. – Kir Chou Jan 06 '19 at 05:59
  • You really want to avoid raw `Popen` for all scenarios which the much simpler and more robust hich-level wrapper `subprocess.run` can handle. – tripleee Jan 06 '19 at 10:29