python 跨模塊實現按照文件大小，日期實現日志分割，反轉

    筆者的一個自動化測試平台項目，采用了python作為后端服務器語言。項目基於快速成型目的，寫了一個極其簡陋的日志記錄功能，支持日志記錄到文件和支持根據日志級別在終端打印不同顏色的log。但隨着測試平台上線運行，發現日志文件大小急劇膨脹，運行一段時間，往往一個log能有幾個G大小，而且也不能根據日期查看日志內容。基於根據文件大小和日志實現日志分割，在下查閱了不少前輩的資料，不斷嘗試，終於得出一個可以用的demo，在此分享也做個記錄，不足之處，還望指正。

這是本人工作前輩的初始版本：

#!/usr/bin/python
# -*- coding: utf-8 -*-

import os
import time
import logging
import platform
if platform.system() == 'Windows':
    from ctypes import windll, c_ulong

    def color_text_decorator(function):
        def real_func(self, string):
            windll.Kernel32.GetStdHandle.restype = c_ulong
            h = windll.Kernel32.GetStdHandle(c_ulong(0xfffffff5))
            if function.__name__.upper() == 'ERROR':
                windll.Kernel32.SetConsoleTextAttribute(h, 12)
            elif function.__name__.upper() == 'WARN':
                windll.Kernel32.SetConsoleTextAttribute(h, 13)
            elif function.__name__.upper() == 'INFO':
                windll.Kernel32.SetConsoleTextAttribute(h, 14)
            elif function.__name__.upper() == 'DEBUG':
                windll.Kernel32.SetConsoleTextAttribute(h, 15)
            else:
                windll.Kernel32.SetConsoleTextAttribute(h, 15)
            function(self, string)
            windll.Kernel32.SetConsoleTextAttribute(h, 15)
        return real_func
else:
    def color_text_decorator(function):
        def real_func(self, string):
            if function.__name__.upper() == 'ERROR':
                self.stream.write('\033[0;31;40m')
            elif function.__name__.upper() == 'WARN':
                self.stream.write('\033[0;35;40m')
            elif function.__name__.upper() == 'INFO':
                self.stream.write('\033[0;33;40m')
            elif function.__name__.upper() == 'DEBUG':
                self.stream.write('\033[0;37;40m')
            else:
                self.stream.write('\033[0;37;40m')
            function(self, string)
            self.stream.write('\033[0m')
        return real_func

FORMAT = '[%(asctime)s] [%(name)s] [%(levelname)s] %(message)s'


class Logger(object):
    DEBUG_MODE = True
    LOG_LEVEL = 5
    GLOBAL_FILENAME = 'static/testlog/syslog/atc.log'

    def __init__(self, name, filename=None):
        current_path = os.path.join(os.path.dirname(
            os.path.abspath(__file__)), 'static', 'testlog/syslog')
        if not os.path.exists(current_path):
            os.makedirs(current_path)

        # baseconfig
        logging.basicConfig()
        self.logger = logging.getLogger(name)
        self.logger.setLevel(logging.DEBUG)
        formatter = logging.Formatter(FORMAT)

        # output to terminal
        sh = logging.StreamHandler()
        sh.setFormatter(formatter)
        sh.setLevel(logging.DEBUG if self.DEBUG_MODE else logging.INFO)
        self.logger.addHandler(sh)
        self.stream = sh.stream

        # output to global file
        if self.GLOBAL_FILENAME:
            fh_all = logging.FileHandler(self.GLOBAL_FILENAME, 'a')
            #fh_all = logging.handlers.TimedRotatingFileHandler(self.GLOBAL_FILENAME,'M',1,0)
            #fh_all.suffix ="_%Y_%m_%d-%H_%M.log"
            fh_all.setFormatter(formatter)
            fh_all.setLevel(logging.DEBUG)
            self.logger.addHandler(fh_all)
            self.logger.propagate = 0

        # output to user define file
        if filename is not None:
            fh = logging.FileHandler(filename, 'a')
            fh.setFormatter(formatter)
            fh.setLevel(logging.DEBUG)
            self.logger.addHandler(fh)
            self.logger.propagate = 0

    @color_text_decorator
    def hint(self, string):
        # 去除多余連續空格
        strTmp = str(string)
        strTmp = ' '.join(strTmp.split())
        if self.LOG_LEVEL >= 5:
            return self.logger.debug(strTmp)
        else:
            pass

    @color_text_decorator
    def debug(self, string):
        # 去除多余連續空格
        strTmp = str(string)
        strTmp = ' '.join(strTmp.split())
        if self.LOG_LEVEL >= 4:
            return self.logger.debug(strTmp)
        else:
            pass

    @color_text_decorator
    def info(self, string):
        # 去除多余連續空格
        strTmp = str(string)
        strTmp = ' '.join(strTmp.split())
        if self.LOG_LEVEL >= 3:
            return self.logger.info(strTmp)
        else:
            pass

    @color_text_decorator
    def warn(self, string):
        # 去除多余連續空格
        strTmp = str(string)
        strTmp = ' '.join(strTmp.split())
        if self.LOG_LEVEL >= 2:
            return self.logger.warn(strTmp)
        else:
            pass

    @color_text_decorator
    def error(self, string):
        # 去除多余連續空格
        strTmp = str(string)
        strTmp = ' '.join(strTmp.split())
        if self.LOG_LEVEL >= 1:
            return self.logger.error(strTmp)
        else:
            pass


class TestLogModule(object):

    def __init__(self):
        pass

    def runtest(self):
        logger = Logger('TEST')

        iCount = 0
        while True:
            iCount = iCount + 1
            logger.error(str(iCount))
            logger.debug('1   22   333   4444     55555      666666')
            logger.info('1   22   333   4444     55555      666666')
            logger.warn('1   22   333   4444     55555      666666')
            logger.error('1   22   333   4444     55555      666666')
            time.sleep(1)
            if iCount >= 120:
                break
        # for a in xrange(10):
        #     logger.debug('1   22   333   4444     55555      666666')
        #     logger.info('1   22   333   4444     55555      666666')
        #     logger.warn('1   22   333   4444     55555      666666')
        #     logger.error('1   22   333   4444     55555      666666')
        #     time.sleep(1)


if __name__ == '__main__':
    TestLogModule().runtest()

我們的需求可以用logging.handlers實現，具體方法為logging.handlers.TimedRotatingFileHandler和logging.handlers.RotatingFileHandler。

class logging.handlers.RotatingFileHandler(filename, mode='a', maxBytes=0, backupCount=0, encoding=None, delay=0)
返回RotatingFileHandler類的實例。指明的文件被打開，並被用作日志流。如果沒有指明mode，使用'a'。如果encoding不為None，使用指定的編碼來打開文件。如果delay為真，只到第一次調用emit()的時候才打開文件。默認情況下，文件會一直增長。

可以使用maxBytes 和 backupCount 來讓文件在預定義的尺寸發生翻轉。當文件大小大概要超出時，文件被關閉，新文件被打開用來輸出。當文件大小接近於maxBytes長度時，翻轉會發生；如果maxBytes為0，翻轉永不發生。如果backupCount不為0，系統將保存老的日志文件，在文件名后加上‘.1’, ‘.2’這樣的擴展名。例如如果backupCount是5，基本的文件名是app.log，將會得到app.log, app.log.1, app.log.2到 app.log.5。總是寫到文件app.log中。當文件被填滿，文件被關閉並重命名為app.log.1，而已存的app.log.1, app.log.2等文件被重命名為app.log.2, app.log.3等。

改變於版本2.6：新增了delay。

doRollover()
如上所述做文件的翻轉。

emit(record)
輸出記錄到文件，負責文件的翻轉。

class logging.handlers.TimedRotatingFileHandler(filename, when='h', interval=1, backupCount=0, encoding=None, delay=False, utc=False)
返回TimedRotatingFileHandler類的實例。 指明的文件被打開，並用作日志流。在循環時它也會設置文件后綴。循環發生基於when 和 interval的乘積。

使用when來指明interval的類型。可能的值列在下面。注意大小寫不敏感。

Value    Type of interval
'S'    Seconds
'M'    Minutes
'H'    Hours
'D'    Days
'W0'-'W6'    Weekday (0=Monday)
'midnight'    Roll over at midnight
注意在使用基於工作日的循環時，‘W0’表示星期一，‘W1’表示星期二，依此類推，‘W6’表示星期日。這種情況下不使用interval。

系統會保存老的日志文件，在文件名后添加擴展名。擴展名基於日期和時間，根據翻轉間隔，使用strftime格式%Y-%m-%d_%H-%M-%S，或者其前面一部分。

第一次計算下一次翻轉時間的時候（創建handler時），要么使用已存文件的上一次修改時間，要么使用當前時間。

如果utc為真，使用UTC時間；否則使用本地時間。

如果backupCount不為0，最多保留backupCount個文件，如果產生更多的文件，最老的文件會被刪除。刪除邏輯使用間隔來決定刪除哪些文件，所以改變間隔可能會導致老的文件被保留。

如果delay為真，只到第一次調用emit()時文件才被打開。

改變於版本2.6：新增了delay和utc。

doRollover()
如上所述做文件的翻轉。

emit(record)
輸出記錄到文件，負責文件的翻轉。

改良第一步：將logging.handlers.TimedRotatingFileHandler和logging.handlers.RotatingFileHandler添加到初始版本中去

Logger類新增logginghandlers.TimeRotatingFileHandler和logging.handlers.RotatingFileHandler 的handler

class Logger(object):
    DEBUG_MODE = True
    LOG_LEVEL = 5
    GLOBAL_FILENAME = 'static/testlog/syslog/atc.log'

    def __init__(self, name, filename=None):
        current_path = os.path.join(os.path.dirname(
            os.path.abspath(__file__)), 'static', 'testlog/syslog')
        if not os.path.exists(current_path):
            os.makedirs(current_path)

        # baseconfig
        logging.basicConfig()
        self.logger = logging.getLogger(name)
        self.logger.setLevel(logging.DEBUG)
        formatter = logging.Formatter(FORMAT)

        # output to terminal
        sh = logging.StreamHandler()
        sh.setFormatter(formatter)
        sh.setLevel(logging.DEBUG if self.DEBUG_MODE else logging.INFO)
        self.logger.addHandler(sh)
        self.stream = sh.stream

        # output to global file
        if self.GLOBAL_FILENAME:         
            th_all = logging.handlers.TimedRotatingFileHandler(self.GLOBAL_FILENAME, when='midnight',interval=1, backupCount=7)
            th_all.setFormatter(formatter)
            th_all.setLevel(logging.DEBUG)
            self.logger.addHandler(th_all)
            # self.logger.propagate = 0

    
        rh_all = logging.handlers.RotatingFileHandler('static/testlog/syslog/rf.log', mode='a',maxBytes=2000*2000, backupCount=3)
        rh_all.setFormatter(formatter)
        rh_all.setLevel(logging.DEBUG)
        self.logger.addHandler(rh_all)
        # self.logger.propagate = 0

        # output to user define file
        if filename is not None:
            fh = logging.FileHandler(filename, 'a')
            fh.setFormatter(formatter)
            fh.setLevel(logging.DEBUG)
            self.logger.addHandler(fh)
            self.logger.propagate = 0

實際結果並不如人意，新添加的兩個handler在日志發生反轉的時候，新建立的日志文件並不能把各模塊的日志輸出記錄下來，會出現只記錄了一部分模塊日志的情況。

再次修改，這次我們為了移除模塊共寫一個文件的影響，另外新建一個mainlogger，由它記錄各模塊的日志輸出，並且在日志反轉時，新建日志文件。

#!/usr/bin/python
# -*- coding: utf-8 -*-

import os
import time
import logging
import logging.handlers
import platform

if platform.system() == 'Windows':
    from ctypes import windll, c_ulong

    def color_text_decorator(function):
        def real_func(self, string):
            windll.Kernel32.GetStdHandle.restype = c_ulong
            h = windll.Kernel32.GetStdHandle(c_ulong(0xfffffff5))
            if function.__name__.upper() == 'ERROR':
                windll.Kernel32.SetConsoleTextAttribute(h, 12)
            elif function.__name__.upper() == 'WARN':
                windll.Kernel32.SetConsoleTextAttribute(h, 13)
            elif function.__name__.upper() == 'INFO':
                windll.Kernel32.SetConsoleTextAttribute(h, 14)
            elif function.__name__.upper() == 'DEBUG':
                windll.Kernel32.SetConsoleTextAttribute(h, 15)
            else:
                windll.Kernel32.SetConsoleTextAttribute(h, 15)
            function(self, string)
            windll.Kernel32.SetConsoleTextAttribute(h, 15)
        return real_func
else:
    def color_text_decorator(function):
        def real_func(self, string):
            if function.__name__.upper() == 'ERROR':
                self.stream.write('\033[0;31;40m')
            elif function.__name__.upper() == 'WARN':
                self.stream.write('\033[0;35;40m')
            elif function.__name__.upper() == 'INFO':
                self.stream.write('\033[0;33;40m')
            elif function.__name__.upper() == 'DEBUG':
                self.stream.write('\033[0;37;40m')
            else:
                self.stream.write('\033[0;37;40m')
            function(self, string)
            self.stream.write('\033[0m')
        return real_func

FORMAT = '[%(asctime)s] [%(name)s] [%(levelname)s] %(message)s'


class MainLogger(object):
    DEBUG_MODE = True
    LOG_LEVEL = 5

    def __init__(self, name):
        current_path = os.path.join(os.path.dirname(
            os.path.abspath(__file__)), 'static', 'testlog', 'syslog')
        if not os.path.exists(current_path):
            os.makedirs(current_path)

        # baseconfig
        logging.basicConfig()
        self.logger = logging.getLogger(name)
        self.logger.setLevel(logging.DEBUG)
        formatter = logging.Formatter(FORMAT)

        th_all = logging.handlers.TimedRotatingFileHandler(
            os.path.join(current_path, 'master_main_atc.log'), when='midnight', interval=1, backupCount=7)
        th_all.setFormatter(formatter)
        th_all.setLevel(logging.DEBUG)
        self.logger.addHandler(th_all)

        rh_all = logging.handlers.RotatingFileHandler(
            os.path.join(current_path, 'master_main_logger_rf.log'), mode='a', maxBytes=2000 * 2000, backupCount=3)
        rh_all.setFormatter(formatter)
        rh_all.setLevel(logging.DEBUG)
        self.logger.addHandler(rh_all)
        # 防止在終端重復打印
        self.logger.propagate = 0

    def hint(self, string):
        # 去除多余連續空格
        strTmp = str(string)
        strTmp = ' '.join(strTmp.split())
        if self.LOG_LEVEL >= 5:
            return self.logger.debug(strTmp)
        else:
            pass

    def debug(self, string):
        # 去除多余連續空格
        strTmp = str(string)
        strTmp = ' '.join(strTmp.split())
        if self.LOG_LEVEL >= 4:
            return self.logger.debug(strTmp)
        else:
            pass

    def info(self, string):
        # 去除多余連續空格
        strTmp = str(string)
        strTmp = ' '.join(strTmp.split())
        if self.LOG_LEVEL >= 3:
            return self.logger.info(strTmp)
        else:
            pass

    def warn(self, string):
        # 去除多余連續空格
        strTmp = str(string)
        strTmp = ' '.join(strTmp.split())
        if self.LOG_LEVEL >= 2:
            return self.logger.warn(strTmp)
        else:
            pass

    def error(self, string):
        # 去除多余連續空格
        strTmp = str(string)
        strTmp = ' '.join(strTmp.split())
        if self.LOG_LEVEL >= 1:
            return self.logger.error(strTmp)
        else:
            pass

main_logger = MainLogger('MasterMainLogger')


class Logger(object):
    DEBUG_MODE = True
    LOG_LEVEL = 5

    def __init__(self, name, filename=None):

        self.name = name
        # baseconfig
        logging.basicConfig()
        self.logger = logging.getLogger(name)
        self.logger.setLevel(logging.DEBUG)
        formatter = logging.Formatter(FORMAT)

        # output to terminal
        sh = logging.StreamHandler()
        sh.setFormatter(formatter)
        sh.setLevel(logging.DEBUG if self.DEBUG_MODE else logging.INFO)
        self.logger.addHandler(sh)
        self.stream = sh.stream
      
        # output to user define file
        if filename is not None:
            fh = logging.FileHandler(filename, 'a')
            fh.setFormatter(formatter)
            fh.setLevel(logging.DEBUG)
            self.logger.addHandler(fh)
            self.logger.propagate = 0

        # 防止在終端重復打印
        self.logger.propagate = 0

    @color_text_decorator
    def hint(self, string):
        # 去除多余連續空格
        strTmp = str(string)
        strTmp = ' '.join(strTmp.split())
        main_logger.hint("[" + self.name + "] "  + strTmp)
        if self.LOG_LEVEL >= 5:
            return self.logger.debug(strTmp)
        else:
            pass

    @color_text_decorator
    def debug(self, string):
        # 去除多余連續空格
        strTmp = str(string)
        strTmp = ' '.join(strTmp.split())
        main_logger.debug("[" + self.name + "] "  + strTmp)
        if self.LOG_LEVEL >= 4:
            return self.logger.debug(strTmp)
        else:
            pass

    @color_text_decorator
    def info(self, string):
        # 去除多余連續空格
        strTmp = str(string)
        strTmp = ' '.join(strTmp.split())
        main_logger.info("[" + self.name + "] "  + strTmp)
        if self.LOG_LEVEL >= 3:
            return self.logger.info(strTmp)
        else:
            pass

    @color_text_decorator
    def warn(self, string):
        # 去除多余連續空格
        strTmp = str(string)
        strTmp = ' '.join(strTmp.split())
        main_logger.warn("[" + self.name + "] "  + strTmp)
        if self.LOG_LEVEL >= 2:
            return self.logger.warn(strTmp)
        else:
            pass

    @color_text_decorator
    def error(self, string):
        # 去除多余連續空格
        strTmp = str(string)
        strTmp = ' '.join(strTmp.split())
        main_logger.error("[" + self.name + "] "  + strTmp)
        if self.LOG_LEVEL >= 1:
            return self.logger.error(strTmp)
        else:
            pass


class TestLogModule(object):

    def __init__(self):
        pass

    def runtest(self):
        logger = Logger('TEST')

        iCount = 0
        while True:
            iCount = iCount + 1
            logger.error(str(iCount))
            logger.debug('1   22   333   4444     55555      666666')
            logger.info('1   22   333   4444     55555      666666')
            logger.warn('1   22   333   4444     55555      666666')
            logger.error('1   22   333   4444     55555      666666')
            time.sleep(1)
            if iCount >= 120:
                break
        # for a in xrange(10):
        #     logger.debug('1   22   333   4444     55555      666666')
        #     logger.info('1   22   333   4444     55555      666666')
        #     logger.warn('1   22   333   4444     55555      666666')
        #     logger.error('1   22   333   4444     55555      666666')
        #     time.sleep(1)


if __name__ == '__main__':
    TestLogModule().runtest()

 這次，終於達到筆者現階段的需求，但是又發現了新的問題，如果以上代碼運行在多進程環境中，日志反轉時，不再建立新日志文件，python的logging模塊報錯，提示文件已打開，導致日志記錄失敗。