Python 中 logging 日志模塊在多進程環境下的使用

因為我的個人網站 restran.net 已經啟用，博客園的內容已經不再更新。請訪問我的個人網站獲取這篇文章的最新內容，Python 中 logging 日志模塊在多進程環境下的使用

使用 Python 來寫后台任務時，時常需要使用輸出日志來記錄程序運行的狀態，並在發生錯誤時將錯誤的詳細信息保存下來，以別調試和分析。Python 的 logging 模塊就是這種情況下的好幫手。

logging 模塊可以指定日志的級別，DEBUG、INFO、WARNING、ERROR、CRITICAL，例如可以在開發和調試時，把 DEBUG 以上級別的日志都輸出，而在生產環境下，只輸出 INFO 級別。（如果不特別指定，默認級別是 warning）

logging 還可以指定輸出到命令行或者文件，還可以按時間或大小分割日志文件。

關於 logging 的詳細使用，這里就不再細說，可以參考官方文檔，或者這里的介紹。

logging 的配置

通常情況下，我們需要將日志保存到文件中，並期望能自動分割文件，避免日志文件太大。下面給出了一個 logging 的配置例子。

import logging.config

logging.config.dictConfig({
    'version': 1,
    'disable_existing_loggers': True,
    'formatters': {
        'verbose': {
            'format': "[%(asctime)s] %(levelname)s [%(name)s:%(lineno)s] %(message)s",
            'datefmt': "%Y-%m-%d %H:%M:%S"
        },
        'simple': {
            'format': '%(levelname)s %(message)s'
        },
    },
    'handlers': {
        'null': {
            'level': 'DEBUG',
            'class': 'logging.NullHandler',
        },
        'console': {
            'level': 'DEBUG',
            'class': 'logging.StreamHandler',
            'formatter': 'verbose'
        },
        'file': {
            'level': 'DEBUG',
            'class': 'logging.RotatingFileHandler',
            # 當達到10MB時分割日志
            'maxBytes': 1024 * 1024 * 10,
            # 最多保留50份文件
            'backupCount': 50,
            # If delay is true,
            # then file opening is deferred until the first call to emit().
            'delay': True,
            'filename': 'logs/mysite.log',
            'formatter': 'verbose'
        }
    },
    'loggers': {
        '': {
            'handlers': ['file'],
            'level': 'info',
        },
    }
})

我們在一個模塊內，就可以這么使用來記錄日志

import logging
logger = logging.getLogger(__name__)

if __name__ == '__main__':
    logger.info('log info')

多進程環境下的使用

按照官方文檔的介紹，logging 是線程安全的，也就是說，在一個進程內的多個線程同時往同一個文件寫日志是安全的。但是（對，這里有個但是）多個進程往同一個文件寫日志不是安全的。官方的說法是這樣的：

Because there is no standard way to serialize access to a single file across multiple processes in Python. If you need to log to a single file from multiple processes, one way of doing this is to have all the processes log to a SocketHandler, and have a separate process which implements a socket server which reads from the socket and logs to file. (If you prefer, you can dedicate one thread in one of the existing processes to perform this function.)

有的人會說，那我不用多進程不就可以了。但是 Python 有一個 GIL 的大鎖（關於 GIL 的糾葛可以看這里），使用多線程是沒法利用到多核 CPU 的，大部分情況下會改用多進程來利用多核 CPU，因此我們還是繞不開不開多進程下日志的問題。

為了解決這個問題，可以使用 ConcurrentLogHandler，ConcurrentLogHandler 可以在多進程環境下安全的將日志寫入到同一個文件，並且可以在日志文件達到特定大小時，分割日志文件。在默認的 logging 模塊中，有個 TimedRotatingFileHandler 類，可以按時間分割日志文件，可惜 ConcurrentLogHandler 不支持這種按時間分割日志文件的方式。

重新修改下 handlers 中的 class。

logging.config.dictConfig({
    ...
    'handlers': {
        'file': {
            'level': 'DEBUG',
            # 如果沒有使用並發的日志處理類，在多實例的情況下日志會出現缺失
            'class': 'cloghandler.ConcurrentRotatingFileHandler',
            # 當達到10MB時分割日志
            'maxBytes': 1024 * 1024 * 10,
            # 最多保留50份文件
            'backupCount': 50,
            # If delay is true,
            # then file opening is deferred until the first call to emit().
            'delay': True,
            'filename': 'logs/mysite.log',
            'formatter': 'verbose'
        }
    },
    ...
})

運行后可以發現，會自動創建一個.lock文件，通過鎖的方式來安全的寫日志文件。