一、概述
好的程序開發,往往會兼顧到日志輸出的需求,以便給用戶提供必要的日志信息便於確認程序運行狀態、排錯等等。這些日志一般包括程序的正常運行日志、訪問日志、錯誤日志、數據保存日志等類型。在python中logging模塊提供了標准的日志接口,可以滿足我們對日志輸出的各種需求,下面一一詳述。
二、logging模塊入門
2.1 日志級別
業內常用的日志有五個級別,分別是:debug,info,warning,error和critical,其中debug級別最低,critical級別最高,級別越低,打印的日志等級越多。各個級別的定義如下:
默認的級別是warning,只有在warning級別和以上級別的日志才會輸出,這樣可以避免日志過多的問題。當然這個默認的級別是可以自定義修改的,下文詳述。
2.2 標准日志輸出
最簡單的日志輸出做輸出到stdout,看代碼:
1 import logging 2 3 logging.debug('[debug]') 4 logging.info('[info]') 5 logging.warning('[warning]') 6 logging.error('[error]') 7 logging.critical('[critical]') 8 9 輸出: 10 WARNING:root:[warning] 11 ERROR:root:[error] 12 CRITICAL:root:[critical] 13 14 #默認的日志級別是warning,該級別以下的日志沒有輸出
2.3 日志輸出到文件
日志輸出到文件具有持久化保存的功能,便於隨時回溯查看。通過basicConfig可以定義日志輸出的參數。關鍵參數如下:
當然了,這個日志級別是可以靈活自定義的。
1 import logging 2 3 logging.basicConfig(filename='running.log', level=logging.INFO) 4 logging.debug('[debug]') 5 logging.info('[info]') 6 logging.warning('[warning]') 7 logging.error('[error]') 8 logging.critical('[critical]')
日志文件輸出結果:
2.4 format格式化輸出日志
前面的示例中,日志的輸出沒有什么可讀性而言,這里可以通過format來增加時間等字段,提高可讀性。常用的format相關的參數如下:
示例程序:
1 import logging 2 3 logging.basicConfig(filename='running.log', level=logging.INFO, format='%(asctime)s [%(levelname)s] %(module)s %(message)s') 4 logging.debug('[debug]') 5 logging.info('service started') 6 logging.warning('memory leak') 7 logging.error('can not started') 8 logging.critical('fatal error') 9 10 程序輸出: 11 2018-02-21 07:30:22,970 [INFO] log service started 12 2018-02-21 07:30:22,971 [WARNING] log memory leak 13 2018-02-21 07:30:22,971 [ERROR] log can not started 14 2018-02-21 07:30:22,971 [CRITICAL] log fatal error
因為示例程序的文件名為log.py,所以這里日志輸出的模塊名顯示為log。還可以通datefmt參數自定義日期時間輸出格式:
1 import logging 2 3 logging.basicConfig(filename='running.log', level=logging.INFO, format='%(asctime)s [%(levelname)s] %(module)s %(message)s',datefmt='%m/%d/%Y %H:%M:%S') 4 logging.debug('[debug]') 5 logging.info('service started') 6 logging.warning('memory leak') 7 logging.error('can not started') 8 logging.critical('fatal error') 9 10 輸出: 11 02/21/2018 07:41:02 [INFO] log service started 12 02/21/2018 07:41:02 [WARNING] log memory leak 13 02/21/2018 07:41:02 [ERROR] log can not started 14 02/21/2018 07:41:02 [CRITICAL] log fatal error
三、logging模塊進階
前文講述了日志輸出的一些基本用法,復雜的用法還需要進階學習:
3.1 logging模塊的主要類概述
python使用logging模塊記錄日志涉及四個主要類:
①logger:記錄器,提供了應用程序可以直接使用的接口。
②handler:處理器,將(logger創建的)日志記錄發送到合適的目的輸出。必須有handler才能捕獲輸出的日志。
③filter:過濾器,對日志進行過濾來決定輸出哪條日志記錄。
④formatter:格式化器,決定日志記錄的最終輸出格式。
3.2 logger詳解
Logger是一個樹形層級結構,在使用接口debug,info,warn,error,critical之前必須創建Logger實例,即創建一個記錄器,如果沒有顯式的進行創建,則默認創建一個root logger,並應用默認的日志級別(WARN),處理器Handler(StreamHandler,即將日志信息打印輸出在標准輸出上),和格式化器Formatter(默認的格式即為第一個簡單使用程序中輸出的格式)。
創建方法:
logger = logging.getLogger(logger_name)
創建Logger實例后,可以使用以下方法進行相關設置:
- logger.setLevel(logging.ERROR) # 設置日志級別為ERROR,即只有日志級別大於等於ERROR的日志才會輸出
- logger.addHandler(handler_name) # 為Logger實例增加一個處理器
- logger.removeHandler(handler_name) # 為Logger實例刪除一個處理器
- logger.addFilter(filt) #為logger實例增加過濾器
- logger.removeFilter(filt) #為logger實例刪除過濾器
- logger.debug()、logger.info()、logger.warning()、logger.error()、logger.critical() #設定指定級別的日志輸出
- len(logger.handlers) #獲取handler的個數
3.3 handler詳解
handler對象負責發送相關的信息到指定目的地。Python的日志系統有多種Handler可以使用。有些Handler可以把信息輸出到控制台,有些Logger可以把信息輸出到文件,還有些 Handler可以把信息發送到網絡上。如果覺得不夠用,還可以編寫自己的Handler。可以通過addHandler()方法添加多個多handler 。
Handler處理器類型有很多種,比較常用的有三個,StreamHandler,FileHandler,NullHandler,詳情可以訪問Python logging.handlers
創建StreamHandler之后,可以通過使用以下方法設置日志級別,設置格式化器Formatter,增加或刪除過濾器Filter。
- ch.setLevel(logging.WARN) # 指定日志級別,低於WARN級別的日志將被忽略
- ch.setFormatter(formatter_name) # 設置一個格式化器formatter
- ch.addFilter(filter_name) # 增加一個過濾器,可以增加多個
- ch.removeFilter(filter_name) # 刪除一個過濾器
StreamHandler
創建方法:
sh = logging.StreamHandler(stream=None)
FileHandler
創建方法:
fh = logging.FileHandler(filename, mode='a', encoding=None, delay=False)
NullHandler
NullHandler類位於核心logging包,不做任何的格式化或者輸出。
本質上它是個“什么都不做”的handler,由庫開發者使用。
下面講解handler的重要知識點:
- logging.StreamHandler
說明:創建一個handler對象,使用這個Handler可以向類似與sys.stdout或者sys.stderr的任何文件對象(file object)輸出信息,也就是屏幕輸出。
它的構造函數是:StreamHandler([strm]),其中strm參數是一個文件對象,默認是sys.stderr。
1 import logging 2 3 logger = logging.getLogger('testlog') #創建一個logger對象 4 logger.setLevel(logging.DEBUG) #設定logger的日志級別 5 6 stdout = logging.StreamHandler() #創建一個handler對象,日志輸出到stdout 7 stdout.setLevel(logging.INFO) #設定handler的日志級別 8 9 logger.addHandler(stdout)#為logger增加指定的handler 10 logger.debug('debug log') #輸出日志 11 logger.info('info log') #輸出日志 12 13 輸出: 14 info log
上述示例程序中,由於handler中設置的日志級別是info,比logger中的debug還要高,因此結果輸出中僅僅輸出了info級別的日志。
- logging.FileHandler
說明:和StreamHandler類似,用於向一個文件輸出日志信息,不過FileHandler會幫你打開這個文件。
它的構造函數是:FileHandler(filename[,mode])。filename是文件名,必須指定一個文件名。mode是文件的打開方式。參見Python內置函數open()的用法。默認是’a',即添加到文件末尾。
1 import logging 2 3 logger = logging.getLogger('testlog') 4 logger.setLevel(logging.DEBUG) 5 6 fh = logging.FileHandler('test.log') #創建一個fileHandler對象,默認追加寫 7 fh.setLevel(logging.INFO) #設置handler的日志級別 8 9 formatter = logging.Formatter('%(asctime)s [%(levelname)s] %(message)s --%(module)s') 10 fh.setFormatter(formatter) #為handler設定格式化器 11 12 logger.addHandler(fh) 13 logger.debug('debug log') 14 logger.info('info log') 15 logger.error('error log') 16 17 輸出: 18 2018-02-21 10:55:37,804 [INFO] info log --log 19 2018-02-21 10:55:37,804 [ERROR] error log --log
- logging.handlers.RotatingFileHandler
說明:這個Handler類似於上面的FileHandler,但是它可以管理文件大小。當文件達到一定大小(字節數)之后,它會自動進行日志文件滾動切割:將當前日志文件改名,然后創建 一個新的同名日志文件繼續輸出。比如日志文件是chat.log。當chat.log達到指定的大小之后,RotatingFileHandler自動把 文件改名為chat.log.1。不過,如果chat.log.1已經存在,會先把chat.log.1重命名為chat.log.2。。。最后重新創建 chat.log,繼續輸出日志信息。
它的構造函數是:RotatingFileHandler( filename, mode, maxBytes, backupCount),其中filename和mode兩個參數和FileHandler一樣。
maxBytes用於指定日志文件的最大文件大小。如果maxBytes為0,意味着日志文件可以無限大,這時上面描述的重命名過程就不會發生。
backupCount用於指定保留的備份文件的個數。比如,如果指定為2,當上面描述的重命名過程發生時,原有的chat.log.2並不會被更名,而是被刪除。
1 import logging 2 from logging import handlers 3 4 logger = logging.getLogger(__name__) 5 logger.setLevel(logging.DEBUG) 6 7 #單個日志文件最大50字節,最多保留3個文件 8 fh = logging.handlers.RotatingFileHandler(filename='time.log', maxBytes=50, backupCount=3) 9 fh.setLevel(logging.INFO) 10 11 #設定formatter 12 formatter = logging.Formatter('%(asctime)s [%(levelname)s] %(message)s --%(module)s') 13 fh.setFormatter(formatter) 14 15 logger.addHandler(fh) 16 logger.debug('debug log') 17 logger.info('info log') 18 logger.error('error log') 19 20 輸出: 21 time.log.1 文件 2018-02-21 11:08:26,253 [INFO] info log --log 22 time.log 文件 2018-02-21 11:08:26,254 [ERROR] error log --log
上述示例程序中由於一行日志的輸出剛好達到50字節的日志文件切割臨界值,所以兩行log輸出到了兩個日志文件中,且越早輸出的日志會寫到了后綴越大的日志文件中(最新的日志文件,可認為后綴為0)
最新補充:
自己在寫一次作業時發現,.RotatingFileHandler存在一下問題:
(1) 默認寫日志的編碼不是utf-8,直接通過參數encoding='utf-8'解決
- logging.handlers.TimedRotatingFileHandler
說明:這個Handler和RotatingFileHandler類似,不過,它沒有通過判斷文件大小來決定何時重新創建日志文件,而是間隔一定時間就自動創建新的日志文件。重命名的過程與RotatingFileHandler類似,不過新的文件不是附加數字,而是當前時間。
它的構造函數是:TimedRotatingFileHandler( filename,when,interval,backupCount),其中filename參數和backupCount參數和RotatingFileHandler具有相同的意義。
interval是時間間隔。
when參數是一個字符串。表示時間間隔的單位,不區分大小寫。它有以下取值:①S:秒②M:分③H:小時④D:天⑤W :每星期(interval==0時代表星期一)⑥midnight:每天凌晨
1 import logging 2 from logging import handlers 3 import time 4 5 logger = logging.getLogger(__name__) 6 logger.setLevel(logging.DEBUG) 7 8 #每隔5秒切割一次日志文件,最多保留3份 9 fh = logging.handlers.TimedRotatingFileHandler(filename='time.log', when='S', interval=3, backupCount=3) 10 fh.setLevel(logging.INFO) 11 12 formatter = logging.Formatter('%(asctime)s [%(levelname)s] %(message)s --%(module)s') 13 fh.setFormatter(formatter) 14 15 logger.addHandler(fh) 16 logger.debug('debug log') 17 time.sleep(3) 18 logger.info('info log') 19 time.sleep(3) 20 logger.error('error log') 21 22 輸出: 23 time.log 2018-02-21 11:18:05,867 [ERROR] error log --log 24 time.log.2018-02-21_11-18-02 2018-02-21 11:18:02,842 [INFO] info log --log 25 time.log.2018-02-21_11-17-59 文件為空,但因為有sleep導致達到日志滾動的時間閾值,所以滾動生成了一個空日志文件
3.4 Formatter 格式化器
使用Formatter對象設置日志信息最后的規則、結構和內容,默認的時間格式為%Y-%m-%d %H:%M:%S。
創建方法:
formatter = logging.Formatter(fmt=None, datefmt=None)
其中,fmt是消息的格式化字符串,datefmt是日期字符串。如果不指明fmt,將使用'%(message)s'。如果不指明datefmt,將使用ISO8601日期格式。
3.5 filter 過濾器
Handlers和Loggers可以使用Filters來完成比級別更復雜的過濾。Filter基類只允許特定Logger層次以下的事件。例如用‘A.B’初始化的Filter允許Logger ‘A.B’, ‘A.B.C’, ‘A.B.C.D’, ‘A.B.D’等記錄的事件,logger‘A.BB’, ‘B.A.B’ 等就不行。 如果用空字符串來初始化,所有的事件都接受。
創建方法:
filter = logging.Filter(name='')
filter的示例程序待后續補充更新。
四、綜合運用--把日志同時輸出到標准輸出和日志文件
思路比較簡單了,先后創建StreamHandler和FileHandler,定義各自的level、formatter,最后add到logger即可。
1 import logging 2 3 logger = logging.getLogger(__name__) 4 logger.setLevel(logging.INFO) 5 6 formater = logging.Formatter('%(asctime)s [%(levelname)s] %(name)s %(message)s ---%(module)s') 7 8 sh = logging.StreamHandler() 9 sh.setLevel(logging.WARN) 10 sh.setFormatter(formater) 11 12 fh = logging.FileHandler('test.log') 13 fh.setLevel(logging.WARN) 14 fh.setFormatter(formater) 15 16 logger.addHandler(sh) 17 logger.addHandler(fh) 18 19 logger.debug('debug log') 20 logger.info('info log') 21 logger.error('error log') 22 23 輸出: 24 2018-02-21 11:39:38,398 [ERROR] __main__ error log ---log 25
五、概念總結
以下是相關概念總結:
熟悉了這些概念之后,有另外一個比較重要的事情必須清楚,即Logger是一個樹形層級結構;
Logger可以包含一個或多個Handler和Filter,即Logger與Handler或Fitler是一對多的關系;
一個Logger實例可以新增多個Handler,一個Handler可以新增多個格式化器或多個過濾器,而且日志級別將會繼承,但Handler中的日志級別會覆蓋Logger中的日志級別設置
六.最新實踐踩坑記錄--調用handler導致日志重復打印問題
常言實踐出真理,今天在一次作業小項目中實際用到了logging模塊來記錄交易日志,結果只要不是第一次記錄日志,日志都要被妥妥滴重復記錄,而且重復的次數很有規律,第二次調用就打印兩行重復的日志,第3次調用就是3行重復的,我能想象得到第n次調用就會重復n次了。剛開始以為是自己定義的日志記錄函數有問題,后面反復調試確認沒有邏輯問題,隨后在網上一搜,遇到這個問題的還不少,呵呵噠。下面記錄一個給出最簡單且容易理解的解釋和解決方案(除此之外我看到的大部分都是修改源碼,my god,暫時還不是我的菜,而且牽一發而動全身,能避免就避免把)。
以下論述引用自https://www.cnblogs.com/xqtesting/p/8734001.html
問題原因:
當第二次調用log的時候,根據getLogger(__name__)里的name獲取同一個logger,而這個logger里已經有了第一次你添加的handler,第二次調用又添加了一個handler,也就是說這個logger里有了兩個同樣的handler,所以就會出現調用幾次就會有幾個handler
解決方案:
明確了問題原因,搞定他當然就水到渠成了:
1. 添加handler時不盲目添加,先判斷一下,如果已經有了就直接寫日志
if not logger.handlers: logger.addHandler(fh)
2. 每次寫完日志就把handler remove掉
logger.removeHandler(streamhandler)
哈哈,算是知道了removeHandler大法的一大實際應用場景了。
還是總結一下吧,經過這次踩坑經歷,發現還是要多實踐綜合性強的實際項目,demo程序一般不超過25行代碼,即使有坑也不一定能踩到,而且都是些相對比較片面局限,僅僅針對某個或某幾個知識點而來,一個綜合性強的項目要勝過n打demo程序了!
還是多實踐多啃骨頭多開腦洞把,少年!