1. 程式人生 > >python多程序解決日誌錯亂問題

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