python多进程记日志

缘起

工作中因为需要用到多进程并记录日志，但是遇到一系列问题导致解决了很长时间

遇到的问题

当我初次遇到这个问题时，网上搜索后说是序列化的问题，然后采用了一个第三方包pathos，ok成功解决了这个问题，但是带来了新的问题（进程进入挂起状态并一直挂着…程序不会终止），于是我开始尝试解决进程挂起的问题，但这也将我带入了死路…

ConcurrentRotatingFileHandler

在网上搜索多进程记录日志采用这个handler,并且windows包名为concurrent_log_handler，linux包名为cloghandler
这两个包的分别引入方式

from concurrent_log_handler import ConcurrentRotatingFileHandler
from cloghandler import ConcurrentRotatingFileHandler

下面是仿照真实代码的简化版

import time
import logging, logging.config
from concurrent_log_handler import ConcurrentRotatingFileHandler
from multiprocessing import Process, Pool
from pathos.multiprocessing import ProcessingPool, cpu_count

class A:
    def __init__(self, id):
        self.name = "zhang"
        self.id = id
        self.error_logger = initialize_logger(str(id), logger_name="error", setLevel=logging.DEBUG, formatter='%(asctime)s - %(filename)s[line:%(lineno)d] - %(levelname)s: %(message)s')


def initialize_logger(filename, setLevel=logging.INFO, formatter='%(asctime)s : %(levelname)s : %(message)s', logger_name="logger1"):
    log_path = filename + ".log"
    # _code_log_handler = ConcurrentRotatingFileHandler(log_path, "a", 1024 * 1024, 500)
    _code_log_handler = logging.FileHandler(log_path, encoding='utf-8')
    formatter = logging.Formatter(formatter)
    _code_log_handler.setFormatter(formatter)
    logger = logging.getLogger(logger_name)
    logger.setLevel(setLevel)
    logger.addHandler(_code_log_handler)
    return logger

def main(fa):
    for i in range(50):
        fa.error_logger.info(f'process: [], print: [{i}]')


if __name__ == '__main__':
    lst = []
    for i in range(1000000000000000,1000000000000005):
        lst.append(A(i))
    time1 = time.time()
    ProcessingPool(cpu_count()).map(main, (*lst,))
    print(time.time()-time1)

运行结果
程序假死，但日志文件是生成了的，但文件内并未记录任何东西。
晕死，然后开始解决程序假死问题，起初网上搜说是得用ConcurrentRotatingFileHandler包，结果还是卡死，我又怀疑是pathos和ConcurrentRotatingFileHandler不兼容的问题，结果完全错误。整整一天无果之后我开始转变思路，尝试别的方式解决。

跑通的代码

import time
import logging, logging.config
from concurrent_log_handler import ConcurrentRotatingFileHandler
from multiprocessing import Process, Pool
from pathos.multiprocessing import ProcessingPool, cpu_count

class A:
    def __init__(self, id):
        self.name = "zhang"
        self.id = id


def initialize_logger(filename, setLevel=logging.INFO, formatter='%(asctime)s : %(levelname)s : %(message)s', logger_name="logger1"):
    log_path = filename + ".log"
    _code_log_handler = ConcurrentRotatingFileHandler(log_path, "a", 1024 * 1024, 500)
    # _code_log_handler = logging.FileHandler(log_path, encoding='utf-8')
    formatter = logging.Formatter(formatter)
    _code_log_handler.setFormatter(formatter)
    logger = logging.getLogger(logger_name)
    logger.setLevel(setLevel)
    logger.addHandler(_code_log_handler)
    return logger

def main(fa):
	#  只是简单的把创建日志对象放到了这里，发现跑通了。
    fa.error_logger = initialize_logger(str(fa.id), logger_name="error", setLevel=logging.DEBUG,
                                          formatter='%(asctime)s - %(filename)s[line:%(lineno)d] - %(levelname)s: %(message)s')
    for i in range(50):
        fa.error_logger.info(f'process: [], print: [{i}]')


if __name__ == '__main__':
    lst = []
    for i in range(1000000000000000,1000000000000005):
        lst.append(A(i))
    time1 = time.time()
    ProcessingPool(cpu_count()).map(main, (*lst,))
    print(time.time()-time1)

生成结果

文件中内容

反推理原因

我怀疑是如果logger对象在多进程外创建可能进程无法自由调度。
其实如果最开始我顺着报错的地方自己推理一下可能问题一下就解决了。

从报错的地方可以看到，多进程内部其实会调用dump方法，可能对象内的logger对象由于某种原因无法被dump。

反思

遇到问题应该先从问题本身下手，而不是只知道百度。。。

对于最开始多进程是否要用concurrent_log_handler 包和pathos包的验证。

import time
import logging, logging.config
from concurrent_log_handler import ConcurrentRotatingFileHandler
from multiprocessing import Process, Pool
# from pathos.multiprocessing import ProcessingPool, cpu_count  已经注释

class A:
    def __init__(self, id):
        self.name = "zhang"
        self.id = id


def initialize_logger(filename, setLevel=logging.INFO, formatter='%(asctime)s : %(levelname)s : %(message)s', logger_name="logger1"):
    log_path = filename + ".log"
    # _code_log_handler = ConcurrentRotatingFileHandler(log_path, "a", 1024 * 1024, 500) 不用这个包
    _code_log_handler = logging.FileHandler(log_path, encoding='utf-8')  # 采用python自带的handler
    formatter = logging.Formatter(formatter)
    _code_log_handler.setFormatter(formatter)
    logger = logging.getLogger(logger_name)
    logger.setLevel(setLevel)
    logger.addHandler(_code_log_handler)
    return logger

def main(fa):
    fa.error_logger = initialize_logger(str(fa.id), logger_name="error", setLevel=logging.DEBUG,
                                          formatter='%(asctime)s - %(filename)s[line:%(lineno)d] - %(levelname)s: %(message)s')
    for i in range(50):
        fa.error_logger.info(f'process: [], print: [{i}]')


if __name__ == '__main__':
    lst = []
    for i in range(1000000000000000,1000000000000005):
        lst.append(A(i))
    time1 = time.time()
    Pool(16).map(main, (*lst,))
    print(time.time()-time1)

结果：
完全没问题，根本和concurrent_log_handler和pathos没有半毛钱关系。
去concurrent_log_handler官网看解释说：
这个包为 Python 的标准日志
包 (PEP 282)提供了一个额外的日志处理程序。此处理程序会将日志事件写入日志文件，
当日志文件达到特定大小时，该文件会轮换。多个进程可以安全地同时写入同一个日志文件。
如果启用，旋转日志可以被 gzip 压缩。支持 Windows 和 POSIX 系统。提供了一个可选的线程队列日志处理程序来在后台执行日志记录。

concurrent_log_handler包描述
pathos包描述