1 引言
最近在開發一個應用軟件，為方便調試和后期維護，在代碼中添加了日志，用的是Python內置的logging模塊，看了許多博主的博文，頗有所得。不得不說，有許多博主大牛總結得確實很好。似乎我再寫關於logging的博文有些多余，但不寫總結又總覺得沒掌握。那就寫寫吧，也方便日后回顧。
開始總結之前，先感謝幾位博主，他們的博客寫得很是詳盡：
說說為什么需要添加日志？
就像上面說的，為了調試和后期維護方便。也許在開發中沒有太大體會，但是如果將軟件部署到了生產環境中，一旦出現bug，沒有日志，就很難對當時的情況進行追蹤，有了日志，就可以根據日志盡可能的對當時的數據環境進行還原，方便debug。甚至，只要日志設計得足夠合理，還可以用於后續業務數據分析等。
2 日志等級
為什么需要對日志進行划分等級呢？
當我們出於開發時debug的目的使用日志時，我們自然是想盡可能詳盡得記錄日志，但是如果部署到生產環境中，這樣做就可能因為大量的IO占用服務器資源，所以在生產環境中就只需要記錄異常信息、錯誤情況等就好了。
所以，給日志設置等級，可以方便得、因地制宜控制日志輸出。
這里只介紹Python的logging模塊的日志等級（當然，其他日志系統的日志等級划分事實上也基本相同）。logging的日志等級包括5個：
日志等級從上到下依次提高，當在程序中設定某個日志等級之后，比設定的日志等級低的日志記錄將會被忽略，即logging就只會輸出大於和等於設定的等級的日志。我們將在下文中通過代碼示例證明這一點。
3 記錄日志
logging模塊提供兩種方法記錄日志：
（1）通過logging模塊提供的模塊級函數記錄日志；
（2）通過logging模塊提供的4大組件記錄日志。
3.1 記錄日志之logging模塊級函數
在logging模塊中，分別給出一個模塊級別函數與上面說到的日志級別相對應，用於輸出對應級別日志記錄：
也有一個函數匯總了上面5個函數的功能：
現在可以來嘗試使用一下上面的函數了：
import logging logging.debug('debug') logging.info('info') logging.warn('warn') logging.error('error') logging.critical('critical') logging.warn('Today is %s',datetime.date.today())
運行結果如下：
WARNING:root:warn
ERROR:root:error
CRITICAL:root:critical
WARNING:root:Today is 2019-03-28
上面的函數都有
*args, **kwargs這兩個參數，所以這些函數可以接受任意位置參數和關鍵字參數，這些參數填充到第一個參數msg，最后一條日志輸出中添加了當前日期就是利用了這個功能。
那為什么會只輸出后面3條日志記錄呢？上面說到過，logging就只會輸出大於和等於設定的等級的日志記錄，而logging的默認日志等級是WARNING，所以日志等級為DEBUG和INFO的兩條記錄都沒有被輸出。
如果想要輸入日志等級為DEBUG和INFO的日志記錄，就要對logging進行配置。logging也提供了一個模塊級別的專用於配置logging的函數：
嘗試使用一下這個配置函數：
import logging logging.basicConfig(level=logging.DEBUG) # 設置日志等級 logging.debug('debug') logging.info('info') logging.warn('warn') logging.error('error') logging.critical('critical')
運行結果如下：
DEBUG:root:debug
INFO:root:info
WARNING:root:warn
ERROR:root:error
CRITICAL:root:critical
看，日志等級為DEBUG和INFO的兩條記錄也都得到了輸出。
上面表格對
logging.basicConfig函數的說明中指出，logging.basicConfig函數時一次性配置，什么意思呢？意思就是說，logging.basicConfig函數只在第一次運行（第一次對logging進行配置）時起作用，后面在此設置其他參數是不會生效的。通過代碼證明一下：
import logging logging.basicConfig(level=logging.DEBUG) # 設置日志等級 logging.basicConfig(level=logging.INFO) # 重新設置日志等級 logging.debug('debug') logging.info('info') logging.warn('warn') logging.error('error') logging.critical('critical')
運行結果：
DEBUG:root:debug
INFO:root:info
WARNING:root:warn
ERROR:root:error
CRITICAL:root:critical
看到沒，DEBUG級別日志記錄還是輸出了，證明重新運行
logging.basicConfig函數設置日志級別沒有生效。
另外需要注意的是，
一定要在使用logging記錄日志之前使用logging.basicConfig進行配置，否則，不會有任何輸出。
我們再觀察一下上面的程序輸出，可以發現，每一條輸出的結果里，不僅僅只有我們輸出的字符串參數，還有其它的一些信息，例如日志等級，日志器名稱（默認是root），分隔符（這里是冒號）等，這些都是logging默認給我配置好的，當然，我們也可以通過
logging.basicConfig函數的各參數自定義logging的輸出。
上表中的參數format可以通過logging模塊中定義好模式來設定值：
所以，結合上表中的內容，我們可以實現讓每一條日志記錄輸出事件發生時間、事件發生位置、日志級別、事件內容等信息。
現在，我們來給剛才的日志添加一些輸出，例如每條日志輸出日志時間、日志級別、所在模塊名、函數名、行號等信息，並指定時間輸出格式，最后把日志輸出到當前目錄下的.log文件中。代碼如下：
import logging fmt = '%(asctime)s , %(levelname)s , %(filename)s %(funcName)s line %(lineno)s , %(message)s' datefmt = '%Y-%m-%d %H:%M:%S %a' logging.basicConfig(level=logging.DEBUG, format=fmt, datefmt=datefmt, filename=".log") logging.debug('debug') logging.info('info') logging.warn('warn') logging.error('error') logging.critical('critical')
運行上述代碼后，控制台不會再有輸出了，但當前目錄下的.log文件會寫入一下內容：
2019-03-28 16:34:08 Thu , DEBUG , log_test.py <module> line 8 , debug
2019-03-28 16:34:08 Thu , INFO , log_test.py <module> line 9 , info
2019-03-28 16:34:08 Thu , WARNING , log_test.py <module> line 10 , warn
2019-03-28 16:34:08 Thu , ERROR , log_test.py <module> line 11 , error
2019-03-28 16:34:08 Thu , CRITICAL , log_test.py <module> line 12 , critical
3.2 記錄日志之logging四大組件
logging四大組件是logging日志記錄的高級用法。四大組件包括Logger、Handelr、Filter、Formater，且都是以類的形式來使用。logging四大組件協同工作流如下如所示：
各組件功能如下：
（1）日志器：Logger
日志器Logger以工廠化的形式返回一個Logger類實例。一般而言，大多使用下面的方法獲得Logger類實例：
logging.getLogger(name)
屬性name是為Logger實例指定的名稱，如果使用同一個名稱進行實例化，則實際上只是將后面實例對象名指向前面的同名Logger實例。在使用logging模塊時，系統會自動實例化一個名為root的日志器（根日志器），當未指定name屬性時，事實上就是將變量名指向跟日志器
另外，
Logger實例具有層級繼承的特點，層級之間已“.”連接，例如：“a.b”，“a.b.c”，a是父日志器，b是子日志器，在未對子日志器進行配置情況下，子日志器默認繼承父日志器的配置，對子日志器重新配置不會影響父日志器。這一點很重要，在多模塊中記錄日子是可以使用這一特性，我們在下文代碼中實踐這一特性。根日志器是所有日志器的默認父日志器。
Logger類還有以下的常用方法：
- logger.setLevel() :設置日志器處理日志信息的最低級別
- logger.addHandler()：為該logger對象添加一個handler對象
- logger.removeHandler()：為該logger對象添加移除一個handler對象
- logger.addFilter()：為該logger對象添加一個filter對象
- logger.removeFilter()：為該logger對象移除一個filter對象
- logger.debug(),logger.info(),logger.warning(),logger.error(),logger.critical()：創建一個對應等級的日志記錄
（2）處理器：Handler
Handler實例用於將日志記錄發送到指定的位置進行輸出。一個logger對象可以添加多個handler（例如既要在控制台輸出日志，又要將日志寫入到文件A，還要講日志寫入文件B，這就可以配置3個handler），每個handler又可以定義不同日志級別，以實現日志分級過濾顯示。常用的方法包括：
- handler.setLevel()：設置handler處理的日志信息最低級別
- handler.setFormatter()：為handler設置一個格式器對象
- handler.addFilter()：為handler添加一個過濾器對象
- handler.removeFilter()：為handler刪除一個過濾器對象
要注意的是，在實際開發中，最好不要直接使用Handler類，應根據實際的功能需要，實例化Handler類的子類。Handler類的之類包括：
通過代碼來演示一下，功能如下:在控制台輸出日志(日志級別為debug），同時將日志寫入到文件a.log文件（日志級別為debug），還要講日志寫入文件b.log文件（日志級別為warn）：
import logging logger = logging.getLogger() logger.setLevel(logging.DEBUG) # 控制台輸出 con_handler = logging.StreamHandler() con_handler.setLevel(logging.INFO) logger.addHandler(con_handler) # 輸出到文件a.log file_a_handler = logging.FileHandler('./a.log', encoding='UTF-8') file_a_handler.setLevel(logging.DEBUG) logger.addHandler(file_a_handler) # 輸出到文件b.log file_b_handler = logging.FileHandler('./b.log', encoding='UTF-8') file_b_handler.setLevel(logging.WARNING) logger.addHandler(file_b_handler) if __name__=='__main__': logger.debug('debug msg') logger.info('info msg') logger.warning('warn msg')
運行上面代碼后，控制台輸出如下：
info msg
warn msg
文件a.log會寫入一下內容：
debug msg
info msg
warn msg
文件b.log會寫入以下內容：
warn msg
注意：在一個日志器中添加多個handler時要注意，最好通過logger.setLevel(logging.DEBUG)先設置一下logger本身的日志級別，如果某個handler的級別比logger的日志級別低，那么該handler的日志級別無效，handler會以logger的級別來處理。
（3）格式器：Formatter
Formatter類實例用於配置日志記錄的內容、結構等信息。可以通過以下三個參數進行配置：
- fmt：指定消息格式化字符串，如果不指定該參數則默認使用message的原始值
- datefmt：指定日期格式字符串，如果不指定該參數則默認使用"%Y-%m-%d %H:%M:%S"
- style：指定格式化占位符，可取值為 '%', '{'和 '$'，如果不指定該參數則默認使用'%'
fmt的使用方法可以參照上文中介紹過的
logging.basicConfig函數format參數的配制方法。
例：每條日志輸出日志時間、日制定及、所在模塊名、函數名、行號等信息，並指定時間輸出格式，最后把日志輸出到控制台。代碼如下：
import logging logger = logging.getLogger(__name__) handler = logging.StreamHandler() logger.setLevel(logging.DEBUG) # 定義格式器,添加到處理器中 fmt = '%(asctime)s , %(levelname)s , %(filename)s %(funcName)s line %(lineno)s , %(message)s' datefmt = '%Y-%m-%d %H:%M:%S %a' log_fmt = logging.Formatter(fmt=fmt, datefmt=datefmt) handler.setFormatter(log_fmt) logger.addHandler(handler) logger.debug('debug msg') logger.info('info msg')
控制台輸出如下：
2019-03-29 19:36:03 Fri , DEBUG , log_test2.py <module> line 14 , debug msg
2019-03-29 19:36:03 Fri , INFO , log_test2.py <module> line 15 , info msg
（4）過濾器：Filter
在我們已經知道的logging使用方法中，都是通過日志級別來控制日志是否輸出，Filter能夠實現更加強大的過濾功能，控制日志輸出。自定義的過濾器中必須覆寫filter方法，當filter的返回值判斷為True則允許輸出，反之不允許輸出。例如過濾包含敏感信息的日志，過濾器定義如下：
import logging class CountryFilter(logging.Filter): def filter(self,record): return "America" not in record.getMessage() logger = logging.getLogger() handler = logging.StreamHandler() logger.addHandler(handler) logger.setLevel(logging.DEBUG) logger.addFilter(CountryFilter()) logger.critical('I love America') logger.debug('I love China')
輸出結果：
I love China
可以看到，雖然第一條日志記錄的日志等級更高，但是因為包含了過濾器中包含的敏感信息，所以不被允許輸出。
4 logging奇淫巧技
4.1 記錄異常信息：捕獲traceback
如果在日志中，只是記錄發生了異常，那其實作用不大，如果traceback也記錄到日志中，那就完美了。強大的logging確實也提供了這一功能，而且使用也很簡單：
import logging logger = logging.getLogger(__name__) handler = logging.FileHandler('./.log',encoding='utf-8') logger.setLevel(logging.DEBUG) # 定義格式器,添加到處理器中 fmt = '%(asctime)s , %(levelname)s , %(filename)s %(funcName)s line %(lineno)s , %(message)s' datefmt = '%Y-%m-%d %H:%M:%S %a' log_fmt = logging.Formatter(fmt=fmt, datefmt=datefmt) handler.setFormatter(log_fmt) logger.addHandler(handler) try: logger.info('Running …') 1/0 except Exception as e: logger.error('Exception occurs!',exc_info = True) # logger.exception(e) # 與上面這行效果一樣
運行后，文件.log會被寫入以下內容：
2019-03-29 19:53:14 Fri , INFO , log_test2.py <module> line 15 , Running …
2019-03-29 19:53:14 Fri , ERROR , log_test2.py <module> line 18 , Exception occurs!
Traceback (most recent call last):
File "E:/myCode/test1/log_test2.py", line 16, in <module>
1/0
ZeroDivisionError: division by zero
4.2 多模塊共享日志
在開發過程中，經常出現多個模塊都需要記錄日志的情況，也許你想到的做法是在一個模塊中配置好一個logger並實例化，在需要用到的模塊中進行導入，但如果不同模塊的日志器配置有區別時，這種方法就不適用了，若是為每個模塊都定義一個logger，所有配置都需要重新寫入，有些繁瑣。還記得上文中提到logging的日志器可以通過name屬性進行分層嗎？子日志器可以繼承父日志器的配置，也可以重新配置，這就是logging給我們提供的多模塊共享日志的解決方案。看代碼：
模塊main.py中的代碼：
import logging import log_child logger = logging.getLogger('main') logger.setLevel(logging.DEBUG) fmt = '%(name)s , %(asctime)s , %(levelname)s , %(filename)s %(funcName)s line %(lineno)s , %(message)s' datefmt = '%Y-%m-%d %H:%M:%S %a' log_fmt = logging.Formatter(fmt=fmt, datefmt=datefmt) handler = logging.FileHandler('./.log',encoding='utf-8') handler.setFormatter(log_fmt) logger.addHandler(handler) if __name__=='__main__': logger.debug('Running …') log_child.fun_child()
模塊child_log.py中的代碼：
import logging logger = logging.getLogger('main.child') logger.setLevel(logging.DEBUG) def fun_child(): try: logger.info('Running …') 1 / 0 except Exception as e: logger.exception(e)
運行main.py后，.log文件會被寫入一下內容：
main , 2019-03-29 20:23:32 Fri , DEBUG , main.py <module> line 16 , Running …
main.child , 2019-03-29 20:23:32 Fri , INFO , log_child.py fun_child line 7 , Running …
main.child , 2019-03-29 20:23:32 Fri , ERROR , log_child.py fun_child line 10 , division by zero
Traceback (most recent call last):
File "E:\myCode\test1\log_child.py", line 8, in fun_child
1 / 0
ZeroDivisionError: division by zero
4.3 使用配置文件配置logger
我們之前的程序中都是將對logger的配置一並寫在程序中，但事實上，采用配置化編程的方式，將對logger的配置寫在專門的配置文件中，例如寫入json文件、conf文件、yaml文件等文件中，當需要實例化logger時，讀取即可。下面以conf文件為例，通過代碼注釋的方式，介紹logging配置文件的書寫方式。配置文件log.conf如下：
[loggers] #固定寫法,定義logger的模塊 keys=root,log_1,log_2 #創建三個logger,root是父類，必需存在的，其他兩個logger的name分別為 [logger_root] # 定制上面的logger，嚴格要求格式為"logger_loggername"，必須通過loggername與上面的logger一一對應 level=DEBUG # 設置日志級別 qualname=root # 對於root，其實這里可以不填,默認就是root handlers=debugs #設置指定處理器,如果有多個處理器，中間以逗號分隔,這個名字待會兒 我們會以固定格式"handler_(value)"創建 [logger_log_1] level=INFO qualname=log_1 #除了root以外，必須要設置這個屬性，用於定義打印輸出時候的logger名 handlers=infos propagate=0 # 是否將消息想父日志傳遞，0表示不傳遞，1表示傳遞。如果向上傳遞，父日志器接收到消息后會以父日志器的配置再次處理該消息，所以可能所有多次輸出 [logger_log_2] level=WARNING qualname=log_2 handlers=warns [handlers] #固定格式， 開始定義處理器 keys=debugs,infos,warns#定義過濾器名稱，與上面出現的handlers的值一一對應，下面定義以handler_handlername格式定義 [handler_debugs] class=StreamHandler # 指定處理器的類名 level=DEBUG # 設置級別 formatter=form01 #定義格式器,名稱為form01,下面會創建formatters，格式也是嚴格要求為formatter_formattername args=(sys.stdout,) # 控制台輸出 [handler_infos] class=FileHandler level=INFO formatter=form02 args=('b.log','a') [handler_warns] class=FileHandler level=WARNING formatter=form02 args=('a.log','a')# 寫入到文件，寫入方式 [formatters] #固定格式 keys=form01,form02 #定義名稱，下面會引用格式，與上面出現的formatter的值對應 [formatter_form01] format=%(asctime)s %(message)s # 定義消息輸出格式，內容 datefmt=%Y-%m-%d %H:%M:%S #日期輸出格式 [formatter_form02] format=%(asctime)s %(filename)s %(levelname)s %(message)s datefmt=%Y-%m-%d %H:%M:%S
實例化logger：
# _*_coding:utf-8_*_ import logging from logging.config import fileConfig fileConfig('log.conf') root= logging.getLogger(name="root") log_1= logging.getLogger(name="log_1") log_2= logging.getLogger(name="log_2") root.debug('root_debug') root.info('root_info') root.warning('root_warning') log_1.debug('log_1_debug') log_1.info('log_1_info') log_1.warning('log_1_warning') log_2.debug('log_2_debug') log_2.info('log_2_info') log_2.warning('log_2_warning')
程序運行后，控制台輸出如下：
2019-03-29 21:43:24 root_debug
2019-03-29 21:43:24 root_info
2019-03-29 21:43:24 root_warning
a.log文件將被寫入以下內容：
2019-03-29 21:43:24 main.py INFO log_1_info
2019-03-29 21:43:24 main.py WARNING log_1_warning
b.log文件將被寫入以下內容：
2019-03-29 21:43:24 main.py WARNING log_2_warning
4.3 日志回滾
什么是日志回滾呢？咋一聽，好像不知道是什么東西。日志回滾就是按照日期或者時間（有時候甚至是日志和時間綜合作用），對日志進行分割或者刪除。實際開發中經常需要用到，因為隨着應用的持續運行，日志文件會越來越龐大，對系統的性能產生影響，所以有必要刪除早起的日志。
logging中提供了兩個處理器用於日志回滾，一個是RotatingFileHandler，它主要是根據日志文件的大小進行滾動，另一個是TimeRotatingFileHandler，它主要是根據時間進行滾動。
（1）根據文件大小進行回滾
按文件大小回滾的類是RotatingFileHandler：
# -*- coding:utf-8 -*- import logging from logging.handlers import RotatingFileHandler logger = logging.getLogger('main') logger.setLevel(level = logging.INFO) # 定義一個RotatingFileHandler，最多備份三個日志文件, 每個日志文件最大1k file_handler = RotatingFileHandler(".log",maxBytes = 1*1024,backupCount = 3) file_handler.setLevel(logging.INFO) formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s') file_handler.setFormatter(formatter) cons_handler = logging.StreamHandler() cons_handler.setLevel(logging.DEBUG) cons_handler.setFormatter(formatter) logger.addHandler(file_handler) logger.addHandler(cons_handler) if __name__=='__main__': while True: logger.debug("debug") logger.info("info") logger.warning("warning") logger.critical("critical")
上述程序執行后，將持續在控制台輸出所有的日志記錄，日志記錄文件有三個，循環向日志文件中寫入日志，當文件大小達到1kb時，開始在另一個文件刪除日志記錄，並寫入新的日志記錄。
（2）根據時間進行回滾。
按文件時間回滾的類時TimeRotatingFileHandler，這一個類包含以下參數：
filename ：輸出日志文件名的前綴，比如main.log
when 是一個字符串的定義如下：
“S”: Seconds
“M”: Minutes
“H”: Hours
“D”: Days
“W”: Week day (0=Monday)
“midnight”: Roll over at midnight
interval 是指等待多少個單位when的時間后
import time import logging import logging.handlers # logging初始化工作 logging.basicConfig() # logger的初始化工作 logger = logging.getLogger('main') logger.setLevel(logging.INFO) # 添加TimedRotatingFileHandler # 定義一個1秒換一次log文件的handler # 保留3個舊log文件 timefilehandler = logging.handlers.TimedRotatingFileHandler(".log", when='S', interval=1, backupCount=3) # 設置后綴名稱，跟strftime的格式一樣 timefilehandler.suffix = "%Y-%m-%d_%H-%M-%S.log" formatter = logging.Formatter('%(asctime)s|%(name)-12s: %(levelname)-8s %(message)s') timefilehandler.setFormatter(formatter) logger.addHandler(timefilehandler) while True: time.sleep(0.1) logger.debug("debug") logger.info("info") logger.warning("warning") logger.critical("critical")
5 總結
本篇系統得總結了Python內容的日志記錄模塊logging的用法，囊括了logging的大部分內容。掌握本篇內容，感覺在開發中基本沒有問題。
參考：