python多进程解决日志错乱问题

       由于python多线程机制的原因，导致python的多线程每次只能使用一个cpu内核。在这种情况下，python的多线程也只有在高io的程序中。在高计算的程序中启动多线程，再加上线程切换的开销，多线程反倒会拖累系统运行的速度。所以在python的web开发中，一般我们会使用gunicorn之类的容器来强行启动多个进程来发挥多核处理器的性能。但是由于是多进程，会导致仅仅是线程安全的logger日志模块儿会发生错误。尤其是在进行了时间分割前提下，出错的概率更高。

       python的logger日志是仿照Java开发的。全都是仅仅保证线程安全，这样在进程安全下就会出现问题。

       如果我们设定每个小时生成一个logger文件，设定写入的logger文件为info.log。这样他们的执行流程为：生成info.log。写入日志，当过去一个小时以后。判定info.log-2018-11-30-1文件是否存在。如果存在删除info.log-2018-11-30-1，重命名info.log为info.log-2018-11-30-1。重新生成info.log并将logger写入指针指向新的info.log文件。

       这个流程在多线程安全下是没问题的。但是再多进程下，由于创建日志的先后顺序（只有有日志继续写入的情况下才会进行生成新的日志文件的操作），1号进程先判定info.log-2018-11-30-1文件不存在，然后重命名info.log为info.log-2018-11-30-1。但是此时可能2号进程还在向info.log文件进行写入，由于写入流已经打开，所以他会继续向info.log-2018-11-30-1中写入。等到2号进程开始重命名操作，此时info.log-2018-11-30-1已经存在，然后他会进行删除操作，这样就会导致日志丢失。而2号进程此时将info.log重命名为info.log-2018-11-30-1，也会导致1号进行继续向info.log-2018-11-30-1写入，这样就导致了日志错乱。

      所以解决思路就很简单，重写FileHandler模块，将执行流程更改为：直接判定info.log-2018-11-30-1是否存在，如果存在就继续追加写入，如果不存在生成info.log-2018-11-30-1并写入。这样就避免了由于重命名删除引起的错误

      这是源代码：

class SafeFileHandler(FileHandler):
    def __init__(self, filename, mode="a", encoding=None, delay=0, suffix="%Y-%m-%d_%H"):
        if codecs is None:
            encoding = None
        current_time = time.strftime(suffix, time.localtime())
        FileHandler.__init__(self, filename + "." + current_time, mode, encoding, delay)

        self.filename = os.fspath(filename)

        self.mode = mode
        self.encoding = encoding
        self.suffix = suffix
        self.suffix_time = current_time

    def emit(self, record):
        try:
            if self.check_base_filename():
                self.build_base_filename()
            FileHandler.emit(self, record)
        except(KeyboardInterrupt, SystemExit):
            raise
        except:
            self.handleError(record)

    def check_base_filename(self):
        time_tuple = time.localtime()

        if self.suffix_time != time.strftime(self.suffix, time_tuple) or not os.path.exists(
                os.path.abspath(self.filename) + '.' + self.suffix_time):
            return 1
        else:
            return 0

    def build_base_filename(self):
        if self.stream:
            self.stream.close()
            self.stream = None

        # if self.suffix_time != "":
        #     index = self.baseFilename.find("." + self.suffix_time)
        #     if index == -1:
        #         index = self.baseFilename.rfind(".")
        #     self.baseFilename = self.baseFilename[:index]

        current_time_tuple = time.localtime()
        self.suffix_time = time.strftime(self.suffix, current_time_tuple)
        self.baseFilename = os.path.abspath(self.filename) + "." + self.suffix_time

        if not self.delay:
            self.stream = open(self.baseFilename, self.mode, encoding=self.encoding)

以下为封装的调用logger模块代码：

import logging
import time
import configparser


from SafeFileHandler import SafeFileHandler

config = configparser.RawConfigParser()
config.read('conf/log4j.ini')

formate = config.get('default', 'format')
filepath = config.get('default', 'filepath')
level = config.get('default', 'level').lower()
suffix = config.get('default', 'suffix')
encoding = config.get('default', 'encoding')


def getLogger(className):
    formatter = logging.Formatter(formate)
    tfrHandler = SafeFileHandler(filepath + '/' + className + ".log", encoding=encoding, suffix=suffix)
    tfrHandler.setFormatter(formatter)

    logging.basicConfig()
    logger = logging.getLogger(className)
    logger.addHandler(tfrHandler)

    if level == 'info':
        logger.setLevel(logging.INFO)
    elif level == 'error':
        logger.setLevel(logging.ERROR)
    return logger


if __name__ == '__main__':
    logger = getLogger('myLog')
    for i in range(0, 100):
        logger.debug('I\'m debug')
        logger.warning('I\'m warning')
        logger.info('I\'m info')
        logger.error('I\'m error')
        time.sleep(1)

log4j配置文件为：

[default]
format = %(asctime)s File "%(filename)s",line %(lineno)s %(levelname)s: %(message)s
filepath = logs
level = INFO
suffix = %Y-%m-%d_%H
when = H
interval = 1
backupCount = 0
encoding = UTF-8