在Python中记录特定线程和共享日志文件

我想使用Python的logging模块在多线程Python应用程序中实现每个线程的日志记录。我在主模块(创建线程)的记录器名称中添加了一个唯一的ID:

mylogger = logging.getLogger(str(someInt) + __name__)

此模块使用多个同样支持日志记录的模块，但其日志记录器初始化如下:

mylogger = logging.getLogger(__name__)

由于被调用者类看不到调用者的日志，调用者的日志是特定于线程的，但被调用者的日志根据其路径保存在一个全局文件中。

我们能做些什么来避免改变传递str(someInt)到每个其他模块，并使用它们不变，但仍然记录到线程特定的文件?

可以通过logging.Filter实现，这里有一个例子:

import threading
import logging
import logging.config

class ThreadLogFilter(logging.Filter):
    """
    This filter only show log entries for specified thread name
    """
    def __init__(self, thread_name, *args, **kwargs):
        logging.Filter.__init__(self, *args, **kwargs)
        self.thread_name = thread_name
    def filter(self, record):
        return record.threadName == self.thread_name

def start_thread_logging():
    """
    Add a log handler to separate file for current thread
    """
    thread_name = threading.Thread.getName(threading.current_thread())
    log_file = '/tmp/perThreadLogging-{}.log'.format(thread_name)
    log_handler = logging.FileHandler(log_file)
    log_handler.setLevel(logging.DEBUG)
    formatter = logging.Formatter(
        "%(asctime)-15s"
        "| %(threadName)-11s"
        "| %(levelname)-5s"
        "| %(message)s")
    log_handler.setFormatter(formatter)
    log_filter = ThreadLogFilter(thread_name)
    log_handler.addFilter(log_filter)
    logger = logging.getLogger()
    logger.addHandler(log_handler)
    return log_handler

def stop_thread_logging(log_handler):
    # Remove thread log handler from root logger
    logging.getLogger().removeHandler(log_handler)
    # Close the thread log handler so that the lock on log file can be released
    log_handler.close()

def worker():
    thread_log_handler = start_thread_logging()
    logging.info('Info log entry in sub thread.')
    logging.debug('Debug log entry in sub thread.')
    stop_thread_logging(thread_log_handler)

def config_root_logger():
    log_file = '/tmp/perThreadLogging.log'
    formatter = "%(asctime)-15s" 
                "| %(threadName)-11s" 
                "| %(levelname)-5s" 
                "| %(message)s"
    logging.config.dictConfig({
        'version': 1,
        'formatters': {
            'root_formatter': {
                'format': formatter
            }
        },
        'handlers': {
            'console': {
                'level': 'INFO',
                'class': 'logging.StreamHandler',
                'formatter': 'root_formatter'
            },
            'log_file': {
                'class': 'logging.FileHandler',
                'level': 'DEBUG',
                'filename': log_file,
                'formatter': 'root_formatter',
            }
        },
        'loggers': {
            '': {
                'handlers': [
                    'console',
                    'log_file',
                ],
                'level': 'DEBUG',
                'propagate': True
            }
        }
    })

if __name__ == '__main__':
    config_root_logger()
    logging.info('Info log entry in main thread.')
    logging.debug('Debug log entry in main thread.')
    for i in xrange(3):
        t = threading.Thread(target=worker,
                             name='Thread-{}'.format(i),
                             args=[])
        t.start()

控制台输出

$ python perThreadLoggingSample.py
2019-03-07 10:29:34,318| MainThread | INFO | Info log entry in main thread.
2019-03-07 10:29:34,320| Thread-0   | INFO | Info log entry in sub thread.
2019-03-07 10:29:34,320| Thread-1   | INFO | Info log entry in sub thread.
2019-03-07 10:29:34,320| Thread-2   | INFO | Info log entry in sub thread.
$

检查日志文件:

$ cat /tmp/perThreadLogging.log
2019-03-07 10:29:34,318| MainThread | INFO | Info log entry in main thread.
2019-03-07 10:29:34,319| MainThread | DEBUG| Debug log entry in main thread.
2019-03-07 10:29:34,320| Thread-0   | INFO | Info log entry in sub thread.
2019-03-07 10:29:34,320| Thread-1   | INFO | Info log entry in sub thread.
2019-03-07 10:29:34,321| Thread-0   | DEBUG| Debug log entry in sub thread.
2019-03-07 10:29:34,320| Thread-2   | INFO | Info log entry in sub thread.
2019-03-07 10:29:34,321| Thread-1   | DEBUG| Debug log entry in sub thread.
2019-03-07 10:29:34,321| Thread-2   | DEBUG| Debug log entry in sub thread.
$
$ cat /tmp/perThreadLogging-Thread-0.log
2019-03-07 10:29:34,320| Thread-0   | INFO | Info log entry in sub thread.
2019-03-07 10:29:34,321| Thread-0   | DEBUG| Debug log entry in sub thread.
$
$ cat /tmp/perThreadLogging-Thread-1.log
2019-03-07 10:29:34,320| Thread-1   | INFO | Info log entry in sub thread.
2019-03-07 10:29:34,321| Thread-1   | DEBUG| Debug log entry in sub thread.
$
$ cat /tmp/perThreadLogging-Thread-2.log
2019-03-07 10:29:34,320| Thread-2   | INFO | Info log entry in sub thread.
2019-03-07 10:29:34,321| Thread-2   | DEBUG| Debug log entry in sub thread.
$

虽然我对我所建议的内容没有真正的经验，但我会尝试使用线程本地存储。

线程局部存储

表示线程本地数据的类。线程本地数据是数据其值是线程特定的。要管理线程本地数据，只需创建一个本地实例(或子类)并在其上存储属性它。对于不同的线程，实例的值是不同的。

你可以用下面的方式保存和访问这些变量:

import threading
mydata = threading.local()
mydata.x = 1

我建议在创建特定于线程的日志记录器时将其保存到线程本地变量中，然后在必要时通过线程本地存储再次访问该日志记录器。

看一下，它帮助我理解了thread-local:

Python中的线程本地存储

我不建议为单独的线程提供单独的文件的解决方案:如果您将thread/threadName添加到格式字符串中，您总是可以从公共日志文件中分离出信息。你可以做你所要求的，使用Filter子类，在这篇文章中描述了一个类似的(但不相同的)用例。

一个可能的解决方案是替换getLogger:

import logging
old_getlogger= logging.getLogger
def my_getlogger(name):
    return old_getlogger( (str(someInt) if name==__name__ else "") + name)
logging.getLogger= my_getlogger

您需要确保someInt具有正确的值，但这可能很难，这取决于您的代码结构。@Marek的建议使用线程本地存储可能是有用的。

据我所知，这实际上是python日志系统中一个棘手的问题。如果您可以访问创建新线程的每个位置，并且可以通过日志处理程序和过滤器更改日志控制，则可以破解解决方案。但是一旦你的代码在某个地方调用了一些想要自己执行线程的lib/代码，这种解决方案就失败了，至少就lib的线程将记录消息的位置而言。

我在

问了一个更详细的相关问题

如何在python中从不同的线程记录不同的文件?

我也在上面提到的@Vinay Sajip的博客上发表了一篇评论，揭露了这个问题。也就是说，据我所知(我可能是错的)，他的解决方案并没有解决这里的潜在问题。没有什么能真正做到这一点，除非做一些高级的魔法，包括调用堆栈跟踪或诸如此类的事情来消除线程+日志中的这个基本缺点。多处理包也不能解决这个问题。每个进程仍然绑定到相同的根记录器(顺便说一句，在我天真的情况下，这似乎有点奇怪/令人担忧)

如果一个线程可以查询它的父线程，但是它不能。

相关内容

最新更新

热门标签：