更新：向下滚动到编辑部分 (4) 以获得几乎完全可用的版本。还删除了 EDIT SECTION (1)，因为否则这篇文章太长了，这可能是最没有帮助的部分。最初在 EDIT SECTION (1) 中的链接如下。
如何将 sys.stdout 复制到 python 中的日志文件？
在这里搜索了很长时间，但第一次提出问题。
解释：
我需要将打印重定向到日志，因为我通过使用打印语句记录消息的系统调用来合并 C 代码。还有大量由我的同事编写的旧 Python 代码被调用，它们也使用 print 语句进行调试。
最终，我希望它能够为我更新的代码处理 logging.info('message')，但也能够通过内置的日志记录模块重定向打印语句，以获得我无法更改或根本没有的代码'还没来得及更新。
下面是我想出的一些示例代码，以简明扼要地展示我的问题。
问题：
- 我将以下设置用于我的日志，但每次打印时，我的日志中都会出现重复条目（和一个空白行）。谁能解释为什么会这样？
- 最好为日志找出更好的设置，以便当我通过日志重定向打印命令时，格式语句包含正确的模块名称。
- 我对这个 Tee(object) 类的使用似乎偶尔会破坏一些东西。请参阅下面的支持信息部分。
我的代码：
编辑：最初是 setuplog.Tee。初始化包含if os.path.exists(LOGNAME): os.remove(LOGNAME). 这已被删除并放入 base.py。
设置日志.py：
#!/usr/bin/python
import sys
import os
import logging
import logging.config
LOGNAME = 'log.txt'
CONFIG = {
'version': 1,
'disable_existing_loggers': True,
'formatters': {
'simple': {
'format': '%(module)s:%(thread)d: %(message)s'
},
},
'handlers': {
'console': {
'level': 'NOTSET',
'class': 'logging.StreamHandler',
'formatter': 'simple'
},
'file': {
'level': 'NOTSET',
'class': 'logging.FileHandler',
'formatter': 'simple',
'filename': LOGNAME
},
},
'root': {
'level': 'NOTSET',
'handlers': ['console', 'file']
},
}
class Tee(object):
def __init__(self):
logging.config.dictConfig(CONFIG)
self.logger = logging.getLogger(__name__)
self.stdout = sys.stdout
sys.stdout = self
def __del__(self):
sys.stdout = self.stdout
def write(self, data):
self.logger.info(data)
基础.py：
#!/usr/bin/python
import sys
import os
import logging
# My modules.
import setuplog
#import aux2
LOGNAME = 'log.txt'
if os.path.exists(LOGNAME):
os.remove(LOGNAME)
not_sure_what_to_call_this = setuplog.Tee()
print '1 base'
logging.info('2 base')
print '3 base'
os.system('./aux1.py')
logging.info('4 base')
#aux2.aux2Function()
#logging.info('5 base')
辅助1.py：
#!/usr/bin/python
import sys
import os
import logging
import setuplog
not_sure_what_to_call_this = setuplog.Tee()
def main():
print '1 aux1'
logging.info('2 aux1')
print '3 aux1'
logging.info('4 aux1')
if __name__ == '__main__':
main()
辅助2.py：
#!/usr/bin/python
import sys
import os
import logging
import setuplog
not_sure_what_to_call_this = setuplog.Tee()
def aux2Function():
print '1 aux2'
logging.info('2 aux2')
print '3 aux2'
然后我从 shell "./base.py" 运行并产生以下输出（在控制台和 log.txt 中）：
setuplog:139833296844608: 1 aux1
setuplog:139833296844608:
aux1:139833296844608: 2 aux1
setuplog:139833296844608: 3 aux1
setuplog:139833296844608:
aux1:139833296844608: 4 aux1
如您所见，使用 print 生成的条目是重复的（问题 1）。另外，我需要想出一个更好的约定来显示模块名称（问题 2）。
问题 3 的支持信息：
从 base.py 中，如果我取消注释“import aux2”、“aux2.aux2Function()”和“logging.info('5 base')”，这是新的输出（直接来自我的控制台，因为这是唯一的地方Python错误转到）：
base:140425995155264: 2 base
setuplog:140360687101760: 1 aux1
setuplog:140360687101760:
aux1:140360687101760: 2 aux1
setuplog:140360687101760: 3 aux1
setuplog:140360687101760:
aux1:140360687101760: 4 aux1
base:140425995155264: 4 base
aux2:140425995155264: 2 aux2
base:140425995155264: 5 base
Exception AttributeError: "'NoneType' object has no attribute 'stdout'" in <bound method Tee.__del__ of <setuplog.Tee object at 0x7fb772f58f10>> ignored
编辑部分（2）：
我一直在玩，这种作品。这里（再次）是示例代码的更新版本。
它“有点”起作用的原因是：
- 我认为应该不惜一切代价避免异常，这利用了一个。
- 日志输出现在有点手动。让我解释。%(name)s 按预期出现，但我必须手动设置。相反，我更喜欢某种能够自动选择文件名的描述符，或者类似的东西（选择函数作为奖励？）。%(module)s 总是为打印语句显示“setuplog”（正确），即使我希望报告的模块是打印语句的来源，而不是我的类将打印语句引导到日志记录模块的模块。
设置日志.py：
#!/usr/bin/python
import sys
import os
import logging
import logging.config
def startLog(name):
logname = 'log.txt'
config = {
'version': 1,
'disable_existing_loggers': True,
'formatters': {
'simple': {
'format': '%(name)s:%(module)s:%(thread)s: %(message)s'
},
},
'handlers': {
'console': {
'level': 'NOTSET',
'class': 'logging.StreamHandler',
'formatter': 'simple'
},
'file': {
'level': 'NOTSET',
'class': 'logging.FileHandler',
'formatter': 'simple',
'filename': logname
},
},
'root': {
'level': 'NOTSET',
'handlers': ['console', 'file'],
},
}
logging.config.dictConfig(config)
return logging.getLogger(name)
class Tee():
def __init__(self, logger):
self.stdout = sys.stdout
self.data = ''
self.logger = logger
sys.stdout = self
def __del__(self):
try:
sys.stdout = self.stdout
except AttributeError:
pass
def write(self, data):
self.data += data
self.data = str(self.data)
if '\x0a' in self.data or '\x0d' in self.data:
self.data = self.data.rstrip('\x0a\x0d')
self.logger.info(self.data)
self.data = ''
基础.py：
#!/usr/bin/python
import sys
import os
import logging
# My modules.
import setuplog
import aux2
LOGNAME = 'log.txt'
if os.path.exists(LOGNAME):
os.remove(LOGNAME)
logger = setuplog.startLog('base')
setuplog.Tee(logger)
print '1 base'
logger.info('2 base')
print '3 base'
os.system('./aux1.py')
logger.info('4 base')
aux2.aux2Function()
logger.info('5 base')
辅助1.py：
#!/usr/bin/python
import sys
import os
import logging
import setuplog
def main():
logger = setuplog.startLog('aux1')
setuplog.Tee(logger)
print '1 aux1'
logger.info('2 aux1')
print '3 aux1'
logger.info('4 aux1')
if __name__ == '__main__':
main()
辅助2.py：
#!/usr/bin/python
import sys
import os
import logging
import setuplog
def aux2Function():
logger = setuplog.startLog('aux2')
setuplog.Tee(logger)
print '1 aux2'
logger.info('2 aux2')
print '3 aux2'
和输出：
base:setuplog:139712687740736: 1 base
base:base:139712687740736: 2 base
base:setuplog:139712687740736: 3 base
aux1:setuplog:140408798721856: 1 aux1
aux1:aux1:140408798721856: 2 aux1
aux1:setuplog:140408798721856: 3 aux1
aux1:aux1:140408798721856: 4 aux1
base:base:139712687740736: 4 base
aux2:setuplog:139712687740736: 1 aux2
aux2:aux2:139712687740736: 2 aux2
aux2:setuplog:139712687740736: 3 aux2
编辑部分（3）：
感谢 reddit 上的精彩回复（http://www.reddit.com/r/learnpython/comments/1kaduo/python_logging_module_for_print_statements/cbn2lef），我能够为 AttributeError 开发一个解决方法。我没有使用异常，而是将类转换为单例。
这是更新的 Tee 类的代码：
class Tee(object):
_instance = None
def __init__(self, logger):
self.stdout = sys.stdout
self.data = ''
self.logger = logger
sys.stdout = self
def __new__(cls, *args, **kwargs):
if not cls._instance:
cls._instance = super(Tee, cls).__new__(cls, *args, **kwargs)
return cls._instance
def __del__(self):
sys.stdout = self.stdout
def write(self, data):
self.data += data
self.data = str(self.data)
if '\x0a' in self.data or '\x0d' in self.data:
self.data = self.data.rstrip('\x0a\x0d')
self.logger.info(self.data)
self.data = ''
编辑部分（4）：
这几乎完全有效！它对我来说足够好来实现它。现在唯一的问题是让输出的格式更有帮助。例如，对于所有重新路由的打印语句，%(filename)s 是 setuplog.py。如果 %(filename)s 是 print 语句的来源文件，那将更加有益。有任何想法吗？
另外，我不得不放弃字典方法。我可以完成所有工作的唯一方法是通过 Python 代码设置记录器。
最后一点，查看 aux3.py。如果使用 os.system 而不是子进程，则日志记录的顺序会混乱。有谁知道仍然使用 os.system 并获得正确顺序的解决方法（所以我不必将每个最后一个 os.system 更改为 subprocess.Popen）？
setuplog.py （您可以忽略函数 startDictLog 和 startFileLog 因为它们不起作用。但是，startCodeLog 可以！）：
#!/usr/bin/python
import sys
import os
import logging
import logging.config
def startLog(name, propagate):
'''The only point of this function was to enable me to quickly
and easily switch how I wanted to configure the logging. So far,
I have only been able to get the last way working
(startCodeLog).'''
#return startDictLog(name)
#return startFileLog(name)
return startCodeLog(name, propagate)
def startDictLog(name):
'''Configure logging usinga dictionary.'''
LOGNAME = 'loop.log'
DEBUGNAME = 'debug.log'
config = {
'version': 1,
'disable_existing_loggers': True,
'formatters': {
'bare': {
# Added the BARE to distinguish between normal prints
# and those that get rerouted. In use, I would format it
# such that only the message is printed.
'format': 'BARE: %(message)s'
},
'simple': {
'format': '%(module)s-%(name)s: %(message)s'
},
'time': {
'format': '%(asctime)s-%(filename)s-%(module)s-%(name)s: %(message)s',
'datefmt': '%H:%M:%S'
},
},
'handlers': {
'console': {
'level': 'NOTSET',
'class': 'logging.StreamHandler',
'formatter': 'bare'
},
'normal': {
'level': 'INFO',
'class': 'logging.FileHandler',
'formatter': 'simple',
'filename': LOGNAME
},
'debug': {
'level': 'NOTSET',
'class': 'logging.FileHandler',
'formatter': 'time',
'filename': DEBUGNAME
},
},
'root': {
'level': 'NOTSET',
'handlers': ['console', 'normal', 'debug'],
},
}
logging.config.dictConfig(config)
return logging.getLogger(name)
def startFileLog(name):
'''Configure logging using a configuration file.'''
CONFIGFILE = 'logging.conf'
logging.config.fileConfig(CONFIGFILE)
return logging.getLogger(name)
def startCodeLog(name, propagate):
'''Configure logging using this code.'''
LOGFILE = 'loop.log'
DEBUGFILE = 'debug.log'
_logger = logging.getLogger(name)
_logger.setLevel(logging.NOTSET)
if propagate in [False, 'n', 'no', 0]:
_logger.propagate = False
_console = logging.StreamHandler()
_normal = logging.FileHandler(LOGFILE)
_debug = logging.FileHandler(DEBUGFILE)
_bare = logging.Formatter('BARE: %(message)s')
_simple = logging.Formatter('%(module)s-%(name)s: %(message)s')
_time = logging.Formatter('%(asctime)s-%(module)s-%(name)s: %(message)s',
datefmt = '%H:%M:%S')
# I added _complex only here, to the working way of setting up the configuration,
# in hopes that this data may help someone figure out how to get the printout
# to be more useful. For example, it's not helpful that the filename is
# setuplog.py for every print statement. It would be more beneficial to somehow
# get the filename of where the print statement originated.
_complex = logging.Formatter('%(filename)s-%(funcName)s-%(name)s: %(message)s')
# Normally this is set to _bare to imitate the output of the old version of the
# scripts I am updating, but for our purposes, _complex is more convenient.
_console.setLevel(logging.NOTSET)
_console.setFormatter(_complex)
# This imitates the format of the logs from versions before I applied this update.
_normal.setLevel(logging.INFO)
_normal.setFormatter(_bare)
# This is a new log file I created to help me debug other aspects of the scipts
# I am updating.
_debug.setLevel(logging.DEBUG)
_debug.setFormatter(_time)
_logger.addHandler(_console)
_logger.addHandler(_normal)
_logger.addHandler(_debug)
return _logger
class Tee(object):
'''Creates a singleton class that tees print statements to the
handlers above.'''
_instance = None
def __init__(self, logger):
self.stdout = sys.stdout
self.logger = logger
sys.stdout = self
self._buf = ''
# Part of old method in the write function.
#self.data = ''
def __new__(cls, *args, **kwargs):
'''This is the singleton implementation. This avoids errors with
multiple instances trying to access the same standard output.'''
if not cls._instance:
cls._instance = super(Tee, cls).__new__(cls, *args, **kwargs)
return cls._instance
def write(self, data):
# This method doesn't work with how I had to implement subprocess.
#self.data = data.rstrip('\r\n')
#if self.data:
# self.logger.info(self.data)
# Also doesn't seem to work with my subprocess implementation.
#self.data += data
#self.data = str(self.data)
#if '\x0a' in self.data or '\x0d' in self.data:
# self.data = self.data.rstrip('\x0a\x0d')
# self.logger.info(self.data)
# self.data = ''
# Only way I could get it working with my subprocess implementation.
self._buf = ''.join([self._buf, data])
while '\n' in self._buf:
line, _, tail = self._buf.partition('\n')
if line.strip():
self.logger.info(line)
self._buf = tail
基础.py：
#!/usr/bin/python
import sys
import os
import logging
import subprocess
# My modules below.
import setuplog
import aux2
# It is assumed that this script will be executed via the command line,
# and each time we run it, we want new log files.
LOGNAME = 'loop.log'
DEBUGNAME ='debug.log'
if os.path.exists(LOGNAME):
os.remove(LOGNAME)
if os.path.exists(DEBUGNAME):
os.remove(DEBUGNAME)
# It seems more convenient to store the logging configuration elsewhere,
# hence my module setuplog.
logger = setuplog.startLog('', True)
logger = setuplog.startLog('base', False)
# This initializes sys.stdout being redirected through logging. Can anyone
# explain how calling this class achieves this? I am a bit fuzzy on my
# understanding here.
setuplog.Tee(logger)
# Test to see how it works in this module.
print '1 base'
logger.info('2 base')
print '3 base'
# Below shows how to get logging to work with scripts that can
# not be modified. In my case, I have C code that I don't want to modify,
# but I still need to log it's output.
# I will have to go through the old code and change all os.system calls
# to instead utilize subprocess. Too bad because this will take some time
# and be "busy work", but at least it works. What can ya do, os.system is
# depreciated anyway. The positive side is that only the root application
# needs to change its system calls to use subprocess. The scipts that it
# calls upon can remain untouched.
aux1_py_path = '"%s"' % os.path.join(os.path.dirname(__file__), 'aux1.py')
#os.system(aux1_py_path) # Example to show how os.system doesn't work.
print 'aux1_py_path:', aux1_py_path
sys_call = subprocess.Popen(aux1_py_path, shell=True, stdout=subprocess.PIPE,
stderr=subprocess.PIPE)
sys_stdout, sys_stderr = sys_call.communicate()
print sys_stdout
print sys_stderr
# This is to ensure that the order of the logging events is correct. With an
# old method I used (not with logging, simply redirecting stdout into an
# opened file), the order would often get messed up.
logger.info('4 base')
# This example is to show how to get logging to work with Python scripts I am
# willing to modify, at least partially. See aux2.py. It is simply a print
# statement, followed by a logging statement, followed by another print
# statement. They all output properly with this method.
aux2.aux2Function()
# Again to ensure the order of events is correct.
logger.info('5 base')
辅助1.py：
#!/usr/bin/python
import logging
import subprocess
import os
def main():
'''We expect the print statements to go through, as they are
being sent to logging. However, these logging statements
do nothing as no logger has been instantiated. This is the
behavior we should expect, as this script mimics a script
that we would not modify, so it would not have logging calls
anyway.'''
print '1 aux1'
logging.info('2 aux1')
print '3 aux1'
logging.info('4 aux1')
# Here, neither option works unless the root of all these calls
# was made with subprocess and in the script that called the
# tee class. If both conditions are met, subprocess works as it
# should. However, os.system returns the print out from the call
# out of order.
aux3_py_path = '"%s"' % os.path.join(os.path.dirname(__file__), 'aux3.py')
#os.system(aux3_py_path)
sys_call = subprocess.Popen(aux3_py_path, shell=True,
stdout=subprocess.PIPE,
stderr=subprocess.PIPE)
sys_stdout, sys_stderr = sys_call.communicate()
print sys_stdout
print sys_stderr
if __name__ == '__main__':
main()
辅助2.py：
#!/usr/bin/python
import sys
import os
import logging
import setuplog
def aux2Function():
# The following two lines are not necessary for most functionality.
# However, if the following two lines are uncommented, then %(name)s
# in the format descriptor of logging will correctly be 'aux2' rather
# than base. Both lines are required for this to work.
logger = setuplog.startLog('aux2', False)
setuplog.Tee(logger)
print '1 aux2'
logging.info('2 aux2')
print '3 aux2'
辅助3.py：
#!/usr/bin/python
import logging
def main():
'''See __doc__ for aux1.py. Again, we don't expect the logging.info
to work, but that's okay because theoretically, this is some script
we can't modify that simply generates output with print or print
like functions.'''
print '1 aux3'
logging.info('2 aux3')
print '3 aux3'
if __name__ == '__main__':
main()
logging.conf（不起作用）：
[loggers]
keys=root
[handlers]
keys=console,normal,debug
[formatters]
keys=bare,simple,time
[logger_root]
level=NOTSET
handlers=console,normal,debug
[handler_console]
level=NOTSET
class=StreamHandler
formatter=bare
args=(sys.stdout,)
[handler_normal]
level=INFO
class=FileHandler
formatter=simple
args=('loop.log',)
[handler_debug]
level=DEBUG
class=FileHandler
formatter=time
args=('debug.log',)
[formatter_bare]
format=%(message)s
[formatter_simple]
format=%(module)s-%(name)s: %(message)s
[formatter_time]
format=%(asctime)s-%(filename)s-%(module)s-%(name)s: %(message)s
datefmt=%H:%M:%S