如何让'print()'、'os.system()'和'subprocess.run()'的输出同时显示在控制台和日志文件中？

Question

起初，我有一个简单的程序将整个输出打印到控制台。

最初的代码仅在控制台中显示输出

import os, subprocess

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

控制台输出

1. Before

Microsoft Windows [Version 10]
user01

2. After

接着，我决定在将原始输出发送到控制台的同时，在日志文件(log.txt)上也保留一份副本。

因此，这是新代码。

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()

很遗憾，这个并没有像预期的那样有效。输出的部分内容仅在控制台上显示（os.system('ver') 和 subprocess.run('whoami')），而 print() 函数则只在 log.txt 文件中显示，不再出现在控制台上。 控制台输出

Microsoft Windows [Version 10]
user01

在log.txt文件中输出结果。

1. Before

2. After

我希望在控制台和log.txt文件中获得类似的输出。这是否可能？我的新代码有什么问题？请告诉我如何修复它。

期望输出结果应该在控制台和log.txt文件中都一致。

1. Before

Microsoft Windows [Version 10]
user01

2. After

- user9013730

---

如果您不介意创建一个“包装器”，将原始程序导向到tee logfile，请参见此处https://en.wikipedia.org/wiki/Tee_(command)。 - VPfB

Answer 1

处理这个问题最合适的方法是使用日志记录。以下是一个示例：

这是Python 2.6+和3.x版本的处理方式。（在2.6之前无法覆盖print()）

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)

该选项允许您使用日志级别。例如，您可以在代码中放置调试日志以跟踪应用程序的异常行为。将"logLevel"更改为"logging.DEBUG"，突然间，您就可以在屏幕上看到输出了。请注意，在上面的例子中，我们有两个不同的日志级别，一个用于屏幕输出，另一个用于文件输出。是的，这会产生不同的输出结果，您可以通过将它们都更改为使用 "logging.INFO"（或 "logging.DEBUG"等）来解决这个问题。 （在此处查看有关日志级别的完整文档。）

在上面的例子中，我已覆盖了“print()”，但我建议您只是使用参照您的框架来编写"log.DEBUG('Variable xyz: {}'.format(xyz))" 或 "log.INFO('Some stuff that you want printed.')" 完整的"loggin"文档。 还有另一种更简单的方法进行覆盖，但并不是那么强大：

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

---

谢谢 UtahJarhead，我尝试运行你的代码但是出现了很多错误。例如： formatter = log.Formatter('%(message)s') AttributeError: 'RootLogger' object has no attribute 'Formatter'之前由 @Kir Chou 提供的代码几乎完美，但输出中有一些不需要的字符，例如 b'\r\n。 - user9013730

这并不处理os.system的情况，它只是直接使用stdout和stderr文件描述符。但是，没有什么好理由使用os.system；这是始终优先选择subprocess.run的众多原因之一。 - tripleee

谢谢@UtahJarhead...我改了代码但还是出错了formatter = logging.formatter('%(message)s') AttributeError: module 'logging' has no attribute 'formatter' - user9013730

根据Python文档，如果有更高级别的包装函数可以满足您的需求，通常应避免使用Popen。 subprocess.run比传统的check_*函数更加灵活，尽管我认为它们仍然有其用处。 - tripleee

@Sabrina，请将Formatter的首字母大写。抱歉，我随口打字了。 - UtahJarhead

Answer 2

系统没有任何魔法，文件指针（如stdout和stderr）需要由您的代码进行不同处理。例如，stdout是其中之一，您可以按照以下方式操作：

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')

根据您的要求，您希望编写一个魔法函数，以便在单行中处理多个文件指针。您需要使用以下包装器函数：

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. 

然后，现在你可以让魔法发生了（将输出同时显示在屏幕和文件中）。

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])

完成了print部分后，让我们继续进行系统调用。在操作系统中运行任何命令，您将在默认系统文件指针stdout和stderr中获得返回结果。在python3中，您可以通过subprocess.Popen以bytes的形式获取这些结果。当运行下面的代码时，您想要的应该是stdout中的结果。

import subprocess

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

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

再次强调，您可以调用上面编写的包装函数，在标准输出和目标文件指针中生成输出。

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

最后，将上面的所有代码组合起来。（再加上一个方便的函数。）

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])

• 注意: 因为Popen的输出是字节，你可能需要进行解码以去除 b''。你可以运行 stdout.decode() 将字节解码为UTF-8解码字符串。

- Kir Chou

---

关于解码程序输出，不幸的是，在Windows命令行中，程序可能会将文本输出作为控制台输入或输出代码页（默认为系统区域设置OEM），系统区域设置OEM或ANSI代码页，用户区域设置OEM或ANSI代码页，用户首选UI语言，UTF-8甚至UTF-16。你必须逐个情况地了解程序做了什么。这完全是一片混乱。如果所有文本恰好是（7位）ASCII，则我们很幸运。 - Eryk Sun

这不是特定于Windows的。在Linux上，它是LC_*疯狂。尝试正确显示Linux ext4文件名... - schlenk

谢谢 @Kir Chou，你的代码有效，但是有一些不必要的字符，比如 b'\r\nMicrosoft Windows [Version 10]\r\n' ... 是否可能去掉 b'\r\n？ - user9013730

@Sabrina，它返回\r\n的原因是stdout获得了未经任何解码的原始输出。在您的情况下，您可以通过stdout.decode().replace('\r\n', '')对数据进行后处理。如果返回的stdout可以用utf8解码，则应该可以正常工作。知道在Python中处理str和bytes是另一个大主题，我不会在这里深入解释。 - Kir Chou

你真的应该尽可能避免使用原始的 Popen，因为更简单、更可靠的高级封装器 subprocess.run 可以处理所有情况。 - tripleee