Python日志模块在多进程环境中的混乱行为

Question

我正在尝试在一个多进程的环境中使用 logging。假设我想让每个进程写自己的日志文件。以下是我的设置：

# worker.py
import logging
import os

def worker( x ) :
    """
    Write the value of x in the log file
    """
    logger = logging.getLogger( __name__ )
    pid = os.getpid() # get the process id
    handler = logging.FileHandler( str(pid) + ".log" )  
    logger.addHandler( handler )
    logger.info( "pid={pid}, x={x}".format( **locals() ) )

这是我的 main：

import logging
import multiprocessing as mp
import worker

# logger
logger = logging.getLogger()
logger.setLevel( logging.INFO )

# handler
handler = logging.FileHandler( 'main.log' )
logger.addHandler( handler )

#
if __name__ == '__main__' :
    pool = mp.Pool( processes=2 )
    pool.map( worker.worker, range(5) )
    pool.close()
    pool.join()

现在来看输出的日志文件。这是 main.log：

pid=1985, x=0
pid=1985, x=2
pid=1986, x=1
pid=1985, x=3
pid=1986, x=4

我觉得这个输出是正常的：两个子进程把事件传递给了根父进程。所以这并不符合 多个进程写入同一个文件 的情况（对吗？）。不过这是第一个子进程的日志文件：

pid=1985, x=0
pid=1985, x=2
pid=1985, x=2
pid=1985, x=3
pid=1985, x=3
pid=1985, x=3

这是第二个子进程的日志文件：

pid=1986, x=1
pid=1986, x=4
pid=1986, x=4

看起来每个子进程对第一个输入写了一次日志，对第二个输入写了两次，对第三个输入写了三次，等等。这是怎么回事呢？

Answer 1

这个问题发生的原因是，每次你调用 worker 时，实际上都是在获取同一个 logger 对象的引用，然后又给它添加了一个新的 FileHandler。所以如果 worker 被调用了三次，它的 logger 就会有三个 FileHandlers，而这三个都在往同一个文件里写东西。你应该使用 initializer 这个关键字参数，在每个 Pool 进程启动时只设置一次 logger：

def init( ) :
    logger = logging.getLogger( __name__ )
    pid = os.getpid() # get the process id
    handler = logging.FileHandler( str(pid) + ".log" )  
    logger.addHandler( handler )

然后像这样启动池

 p = multiprocessing.Pool(processes=2, initializer=init)

这样一来，worker 就可以直接使用 logger 对象，而不需要再给它添加 FileHandler 了。