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