探讨python logging多线程和多进程的安全问题

2019-11-14 21:40 编程相关 python

前言

我们讨论日志的安全问题，主要是讨论将日志写入到同一个文件的安全问题，即使用FileHandler及其子类的安全问题。首先需要明确一点的是，logging模块是多线程安全的，但并非多进程安全。

为什么logging是线程安全的

在单个进程使用多线程将日志输出到同一个文件，是没有问题的。原因也很好理解，是因为在官方实现里就已经加入了线程锁，所以不存在多个线程在同一时刻都在写入文件的问题。

以下为官方实现的一个代码片段：


x
def handle(self, record):
    rv = self.filter(record)
    if rv:
        self.acquire()
        try:
            self.emit(record)
        finally:
            self.release()
    return rv

需要了解的一点是，此段代码是放在顶级父类--Handler类中的，所以不管日志以何种形式输出，都是thread-safe的。

使用多进程会带来哪些问题

为了最大限度利用机器CPU资源，采用多进程部署Python代码，已经是非常普遍的一种做法。为了查看日志方便，将日志输出同一个文件里，也是非常普遍的做法。但这种做法如果不加改造，是有问题的，虽然在实际使用中，大部分时候看起来是正常的，这也导致我们常常会忽视它，但它是客观存在的，是有概率出现的。

我们说日志不安全，具体表现为以下两个方面：

日志紊乱：比如两个进程分别输出xxxx和yyyy两条日志，在文件中会得到类似xxyxyxyy的结果。
日志丢失：丢失某些日志行，或者整个文件内容丢失。

为什么多进程输出日志是不安全的

这个话题是其实可以引出另一个话题的，那就是多进程如何安全地写入文件，在此就不详细讨论此话题了，只要知道如果是以O_APPEND模式打开的文件，那读写文件是原子性的，不存在安全性问题。从python源码我们也可以得知，logging模块读写日志就是采用的O_APPEND模式，那我们就奇怪了，既然O_APPEND能保证写文件的原子性，为何还有多进程安全问题呢？

答案就在文件缓冲区buffer上面，写入日志首先是将日志内容保存在一个buffer上面，当buffer满了或者主动调用了flush，才将buffer的内容写入到磁盘。问题的关键是读写buffer不是多进程安全的。

另一个多进程输出日志不安全的场景和原因

在使用RotatingFileHandler或者TimerRotatingFileHandler对日志切割时候，如果是多进程环境，就会出现日志不能正常输出，以及历史日志丢失的情况出现。究其原因，是不同进程之间拿到的文件句柄不一致导致的。举个简单的例子，进程A对日志分割之后，进程B并不知道日志已经分隔，进程B手里拿到的还是旧的句柄，当进程B再去对日志文件操作时，就会出现问题。

如何解决多进程安全问题

解决多进程输出日志到一个文件问题，解决方法很多，Python的官网也介绍了一些，比如使用SocketHandler或者QueueHandler。另一种可行的是通过加文件锁的方式，保证不同进程不会同时操作同一个文件，第三方包 concurrent-log-handler，采用的就是这种方式，下面是使用concurrent-log-handler的一个例子：


x
from logging import getLogger, INFO
from concurrent_log_handler import ConcurrentRotatingFileHandler
import os
log = getLogger()
logfile = os.path.abspath("mylogfile.log")
rotateHandler = ConcurrentRotatingFileHandler(logfile, "a", 512*1024, 5)
log.addHandler(rotateHandler)

参考