神器 Logging，你真的了解嗎？
本文轉(zhuǎn)載自微信公眾號「Python技術(shù)」，作者派森醬。轉(zhuǎn)載本文請聯(lián)系Python技術(shù)公眾號。
logging 是 python 標準模塊，用于記錄和處理程序中的日志。
功能很強大，官方文檔很詳細，網(wǎng)上也有大量的說明和教程，但是對很多初次接觸的同學來說，存在一些障礙。
一是因為標準庫文檔太過繁瑣，需要較高的理論基礎(chǔ)，著急用時，常常被文檔搞暈。
二是大部分說明材料要么是官方文檔的羅列，要么是簡單的應用，對實際應用幫助不大。
今天，我們從應用上的一些問題開始，探討一下日志神器 logging 極其背后的原理，讓它能真正的幫助到我們。
該用 logging.debug 還是 logger.debug ?
debug 是日志模塊中的一個日志等級為 DEBUG 的日志生成方法，還有 info、warning、error、critial，這里用 debug 做為代表進行說明。
我們常會看到，一會兒用 logging.debug 記錄日志，一會兒又用 logger.debug 記錄日志，到底該用什么?
先看代碼:
- import logging
- logging.debug('調(diào)試信息')
- logger = logging.getLogger()
- logger.debug('調(diào)試信息')
首先 logging 是作為一個模塊被引入的。logging.debug 用的是 logging 模塊的模塊方法。
logger 是用 logging.getLogger() 生成的，是一個 日志對象，logger.debug 調(diào)用的是 logger 這個日志對象的方法。
上面的代碼中 logging.debug 和 logger.debug 的效果完全是一樣的。
這是因為，為了讓開發(fā)者方便使用，logging 模塊提供了一些列模塊方法，如 debug，在引入模塊后，就可以直接使用。這樣開發(fā)者就不必關(guān)心日志模塊的細節(jié)，像用 print 一樣輸出日志。
如果需要對日志輸出進行定制化，比如將日志輸出到文件中，過濾某些級別的日志，就需要創(chuàng)建或者得到一個實際的日志對象來處理，如上面代碼中通過 getLogger 方法得到的日志對象。
我們知道，程序設(shè)計里要避免重復的設(shè)計，如果模塊方法采用一套機制，日志對象上的方法采用另一套機制，就會出現(xiàn)重復造輪子的問題。
所以在使用模塊方法，logging 其實創(chuàng)建了一個日志對象 —— root logger。
也就是 logging.debug 這個調(diào)用，實質(zhì)上是調(diào)用 root logger 的日志方法。
相當于默認情況下 root logger 會作為日志處理對象。
如何獲得 root logger 對象呢?
通過不帶參數(shù)的 logging.getLogger() 方法獲得。
那么 logging.debug 和 rootLogger.debug 是一會事，可以理解(但不嚴謹)為 logging.debug 是 rootlogger.debug 的快捷方式。
日志樹
稍加留意就會觀察到，程序是有層次結(jié)構(gòu)的，通過相互引用，調(diào)用形成一個樹狀結(jié)構(gòu)。
程序加載的地方是樹根，比如 python 中要運行的代碼文件，我們稱之為 main。從樹根開始長出其他枝葉。對于一個模塊來說，又會形成一個自己的樹。
如何用日志清楚地記錄層次結(jié)構(gòu)呢?
雖然直接打印出調(diào)用堆棧也可以看到調(diào)用結(jié)構(gòu)，不過不太直觀，缺乏業(yè)務邏輯描述。
而用 print 來打印出層次結(jié)構(gòu)，需要編寫大量的代碼才能反射出(通過運行狀態(tài)獲取代碼狀態(tài)的一種方式)調(diào)用環(huán)境。
logging 提供了完畢的解決方案。
前面提到的 root logger 就是整個日志樹的根，其他所有的 logger 都是從 root logger 伸展出來的枝葉。只要通過 getLogger(loggername) 方法獲得的 logger 對象，都是伸展自 root logger 的。
如何向下伸展呢?
很簡單，就像引用模塊的層次關(guān)系一樣，用 . 分隔層次就好了，例如：
- logger = logging.getLogger('mod1.mod2.mod3')
- logger.debug("調(diào)試信息")
語句 logging.getLogger('mod1.mod2.mod3') 實際上創(chuàng)建了三個 logger，名稱分別是 mod1、mod1.mod2 和 mod1.mod2.mod3
mod1 為根，mod1.mod2 為子，mod1.mod2.mod3 為孫。
如果在 mod1 上設(shè)置了日志處理器(handler)，那么其他兩個的日志對象都會用到這個處理器。
這樣不但記錄的日志更清晰而且，可以為同一個根的日志對象設(shè)置可以共享的日志處理方式。
這樣感覺也不方便，需要些那么多層次，如何才能更方便呢?在下面的 實踐參考 里會有說明。
logging.basicConfig 的功與過
說完了日志模塊的樹狀結(jié)構(gòu)，來看看一個很常用的設(shè)置方法 basicConfig。
它可以方便的設(shè)置日志處理和記錄方式，如沒必要，不用為每個日志對象單獨設(shè)置。
根據(jù)第一節(jié)的分析，我們知道，直接使用模塊方法，用的其實是 root logger，那么就能明白 basicConfig 設(shè)置了 root logger 的日志處理方式。
這就意味著:
一旦設(shè)置了通過 logging.basicConfig 設(shè)置了日志處理方式，其他所有日志都很受到影響。
另外 basicConfig 是個一次性方法，即:
只有第一次設(shè)置有效，其后設(shè)置無效
本來是個一勞永逸的方法。
但用錯了地方，就會很麻煩。
看下例子：
- __all__ = ['Connection', 'ConnectionPool', 'logger']
- warnings.filterwarnings('error', category=pymysql.err.Warning)
- # use logging module for easy debug
- logging.basicConfig(format='%(asctime)s %(levelname)8s: %(message)s', datefmt='%m-%d %H:%M:%S')
- logger = logging.getLogger(__name__)
- logger.setLevel('WARNING')
這段代碼中，用 logging.basicConfig 對日志做了設(shè)置，意思是后面的日志都按照這樣的方式輸出。
但它是一個底層模塊 —— pymysqlpool[1]。
pymysqlpool 封裝了 pymysql[2] 模塊，提供了鏈接池特性，在多線程處理數(shù)據(jù)庫場景下很有用。
也就是說，pymysqlpool 只會被引用加載，不會作為 main 被加載，這就比較尷尬了，因為 main 中對日志的設(shè)置就沒有效果。
作為一個服務類模塊(相對于業(yè)務的底層模塊)，不要通過 basicConfig 來設(shè)置日志模式，要么通過自己專屬的日志對象來設(shè)置，要么不去設(shè)置，統(tǒng)一交給 main 去設(shè)置，例如：
- logger = logging.getLogger(__name__)
- fmt = logging.Formatter("%(asctime)s %(levelname)8s: %(message)s", datefmt='%m-%d %H:%M:%S')
- hdl = logging.StreamHandler()
- hdl.setFormatter(fmt)
- logger.addHandler(hdl)
- logger.setLevel('WARNING')
如果為了測試，可以在測試的初始化方法中，使用 basicConfig 來設(shè)置，因為測試時，模塊往往是被作為程序入庫加載的。
實踐參考
了解了日志模塊的一下特性，和其中的原理之后，這里有幾條實踐參考。
- 不要再子模塊中使用 logging.basicConfig 設(shè)置日志模式
- 強烈建議在任何模塊中通過 logger = logging.getLogger(__name__) 來創(chuàng)建日志對象 因為 __name__ 代表的就是模板被加載的引用名稱。
例如 from a.b.c import b 模塊 c 中的 __name__ 值就為 a.b.c。
- 而且這個引用名稱剛好符合 logger 定義的層次結(jié)構(gòu)。
通過命令行參數(shù)設(shè)置不同類型的日志，見代碼：
- import logging
- import argparse
- logger = logging.getLogger(__name__)
- def create_args_parse():
- parser = argparse.ArgumentParser(description="參數(shù)列表")
- parser.add_argument('-d', '--debug', action='store_true', help='調(diào)試模式')
- # 加入其他命令行參數(shù)
- return parser
- def set_logger(debug):
- formatter = logging.Formatter('%(asctime)s - %(levelname)8s - %(name)s - %(filename)s:%(lineno)d - %(thread)d- %(funcName)s:\t%(message)s')
- if debug:
- hd = logging.StreamHandler()
- logger.setLevel(logging.DEBUG)
- hd.setFormatter(formatter)
- else:
- hd = logging.FileHandler(f'{__name__}.log', 'a', encoding='utf-8')
- logger.setLevel(logging.INFO)
- hd.setFormatter(formatter)
- logger.addHandler(hd)
- if __name__ == '__main__':
- parser = create_args_parse()
- args = parser.parse_args()
- debug = args.debug
- set_logger(debug)
- ...
代碼有點長，但不難懂。
- create_args_parse 方法用于解析命令行參數(shù)，其中定義了一個 debug 參數(shù)，表示開啟調(diào)試模式
- set_logger 方法接收一個是否為調(diào)試模式的參數(shù)，根據(jù)是否為調(diào)試模式，設(shè)置不同的日志模式
- main 中，首先調(diào)用 create_args_parse 獲得命令行參數(shù)對象，然后從中解析出參數(shù)，提取 debug 模式，傳送給 set_logger 方法，設(shè)置日志模式
- 這樣只需要在運行程序時，加上參數(shù) -d 就可以讓日志打印到終端上，不加，日志就會自動去 __main__.log 日志文件中去了。
總結(jié)
python 為我們提供了很多便利的功能，有些需要真的用到才能有所體會，所以在遇到問題時，需要多研究一下，找到其中的特點和內(nèi)在的原理或機制，這樣就能更好的應用了。
在我理解了 logging 的原理之后，已經(jīng)在我的很多項目中發(fā)揮了巨大作用，而且再也不必糾結(jié)于怎么用，如何更合理等這些問題了。
期望這篇文章也能對你有所幫助，比心。
參考資料
[1]pymysqlpool: https://pypi.org/project/pymysql-pool/
[2]pymysql: https://pypi.org/project/PyMySQL/
