Python logging模組用法快速攻略

無論使用哪種程式語言，最常用的偵錯程式碼的方式是：使用輸出語句（比如 C 語言中使用 printf，Python 中使用 print() 函數）輸出程式執行過程中一些關鍵的變數的值，檢視它們的值是否正確，從而找到出錯的地方。這種偵錯方法最大的缺點是，當找到問題所在之後，需要再將用於偵錯的輸出語句刪掉。

在 Python 中，有一種比頻繁使用 print() 偵錯程式更簡便的方法，就是使用 logging 模組，該模組可以很容易地建立自定義的訊息記錄，這些紀錄檔訊息將描述程式執行何時到達紀錄檔函數呼叫，並列出指定的任何變數當時的值。

啟用 logging 模組很簡單，直接將下面的程式碼複製到程式開頭：

import logging
logging.basicConfig(level=logging.DEBUG, format=' %(asctime)s - %(levelname)s - %(message)s')

讀者不需要關心這兩行程式碼的具體工作原理，但基本上，當 Python 記錄一個事件的紀錄檔時，它會建立一個 LogRecord 物件，儲存關於該事件的資訊。

假如我們編寫了如下一個函數，其設計的初衷是用來計算一個數的階乘，但該函數有些問題，需要偵錯：

import logging
logging.basicConfig(level=logging.DEBUG, format=' %(asctime)s - %(levelname)s - %(message)s')
logging.debug('Start of program')
def factorial(n):
    logging.debug('Start of factorial(%s%%)' % (n))
    total = 1
    for i in range(n + 1):
        total *= i
        logging.debug('i is ' + str(i) + ', total is ' + str(total))
    logging.debug('End of factorial(%s%%)' % (n))
    return total
print(factorial(5))
logging.debug('End of program')

執行結果為：

2019-09-11 14:14:56,928 - DEBUG - Start of program
2019-09-11 14:14:56,945 - DEBUG - Start of factorial(5%)
2019-09-11 14:14:56,959 - DEBUG - i is 0, total is 0
2019-09-11 14:14:56,967 - DEBUG - i is 1, total is 0
2019-09-11 14:14:56,979 - DEBUG - i is 2, total is 0
2019-09-11 14:14:56,991 - DEBUG - i is 3, total is 0
2019-09-11 14:14:57,000 - DEBUG - i is 4, total is 0
2019-09-11 14:14:57,013 - DEBUG - i is 5, total is 0
2019-09-11 14:14:57,024 - DEBUG - End of factorial(5%)
0
2019-09-11 14:14:57,042 - DEBUG - End of program

可以看到，通過 logging.debug() 函數可以列印紀錄檔資訊，這個 debug() 函數將呼叫 basicConfig() 列印一行資訊，這行資訊的格式是在 basicConfig() 函數中指定的，並且包括傳遞給 debug() 的訊息。

分析程式的執行結果，factorial(5) 返回 0 作為 5 的階乘的結果，這顯然是不對的。for 迴圈應該用從 1 到 5 的數，乘以 total 的值，但 logging.debug() 顯示的紀錄檔資訊表明，i 變數從 0 開始，而不是 1。因為 0 乘任何數都是 0，所以接下來的疊代中，total 的值都是錯的。紀錄檔訊息提供了可以追蹤的痕跡，幫助我們弄清楚程式執行過程哪裡不對。

將程式碼行 for i in range（n + 1）：改為 for i in range（1，n + 1）：，再次執行程式，輸出結果為：

2019-09-11 14:21:18,047 - DEBUG - Start of program
2019-09-11 14:21:18,067 - DEBUG - Start of factorial(5%)
2019-09-11 14:21:18,072 - DEBUG - i is 1, total is 1
2019-09-11 14:21:18,082 - DEBUG - i is 2, total is 2
2019-09-11 14:21:18,087 - DEBUG - i is 3, total is 6
2019-09-11 14:21:18,093 - DEBUG - i is 4, total is 24
2019-09-11 14:21:18,101 - DEBUG - i is 5, total is 120
2019-09-11 14:21:18,106 - DEBUG - End of factorial(5%)
120
2019-09-11 14:21:18,123 - DEBUG - End of program

Python logging紀錄檔級別

“紀錄檔級別”提供了一種方式，按重要性對紀錄檔訊息進行分類。5 個紀錄檔級別如表 1 所示，從最不重要到最重要。利用不同的紀錄檔函數，訊息可以按某個級別記入紀錄檔。

表 1 Python logging紀錄檔級別

級別	對應的函數	描述
DEBUG	logging.debug()	最低階別，用於小細節，通常只有在診斷問題時，才會關心這些訊息。
INFO	logging.info()	用於記錄程式中一般事件的資訊，或確認一切工作正常。
WARNING	logging.warning()	用於表示可能的問題，它不會阻止程式的工作，但將來可能會。
ERROR	logging.error()	用於記錄錯誤，它導致程式做某事失敗。
CRITICAL	logging.critical()	最高階別，用於表示致命的錯誤，它導致或將要導致程式完全停止工作。

紀錄檔訊息將會作為一個字串，傳遞給這些函數。另外，紀錄檔級別只是一種建議，歸根到底還是由程式設計師自己來決定紀錄檔訊息屬於哪一種型別。

舉個例子：

>>>import logging
>>> logging.basicConfig(level=logging.DEBUG, format=' %(asctime)s - %(levelname)s - %(message)s')
>>> logging.debug('Some debugging details.')
2019-09-11 14:32:34,249 - DEBUG - Some debugging details.
>>> logging.info('The logging module is working.')
2019-09-11 14:32:47,456 - INFO - The logging module is working.
>>> logging.warning('An error message is about to be logged.')
2019-09-11 14:33:02,391 - WARNING - An error message is about to be logged.
>>> logging.error('An error has occurred.')
2019-09-11 14:33:14,413 - ERROR - An error has occurred.
>>> logging.critical('The program is unable to recover!')
2019-09-11 14:33:24,071 - CRITICAL - The program is unable to recover!

紀錄檔級別的好處在於，我們可以改變想看到的紀錄檔訊息的優先順序。比如說，向 basicConfig() 函數傳入 logging.DEBUG 作為 level 關鍵字引數，這將顯示所有級別為 DEBUG 的紀錄檔訊息。當開發了更多的程式後，我們可能只對錯誤感興趣，在這種情況下，可以將 basicConfig() 的 level 引數設定為 logging.ERROR，這將只顯示 ERROR 和 CRITICAL 訊息，跳過 DEBUG、INFO 和 WARNING 訊息。

Python logging禁用紀錄檔

在偵錯完程式後，可能並不希望所有這些紀錄檔訊息出現在螢幕上，這時就可以使用 logging.disable() 函數禁用這些紀錄檔訊息，從而不必進入到程式中，手工刪除所有的紀錄檔呼叫。

logging.disable() 函數的用法是，向其傳入一個紀錄檔級別，它會禁止該級別以及更低階別的所有紀錄檔訊息。因此，如果想要禁用所有紀錄檔，只要在程式中新增 logging.disable(logging.CRITICAL) 即可，例如：

>>> import logging
>>> logging.basicConfig(level=logging.INFO, format=' %(asctime)s - %(levelname)s - %(message)s')
>>> logging.critical('Critical error! Critical error!')
2019-09-11 14:42:14,833 - CRITICAL - Critical error! Critical error!
>>> logging.disable(logging.CRITICAL)
>>> logging.critical('Critical error! Critical error!')
>>> logging.error('Error! Error!')

因為 logging.disable() 將禁用它之後的所有訊息，所以可以將其新增到程式中更接近 import logging 的位置，這樣更容易找到它，方便根據需要注釋掉它，或取消註釋，從而啟用或禁用紀錄檔訊息。

將紀錄檔訊息輸出到檔案中

雖然紀錄檔訊息很有用，但它們可能塞滿螢幕，讓你很難讀到程式的輸出。考慮到這種情況，可以將紀錄檔資訊寫入到檔案，既能使螢幕保持乾淨，又能儲存資訊，一舉兩得。

將紀錄檔訊息輸出到檔案中的實現方法很簡單，只需要設定 logging.basicConfig() 函數中的 filename 關鍵字引數即可，例如：

>>> import logging
>>> logging.basicConfig(filename='demo.txt', level=logging.DEBUG, format='%(asctime)s - %(levelname)s - %(message)s')

此程式中，將紀錄檔訊息儲存到了 demo.txt 檔案中，該檔案就位於執行的程式檔案所在的目錄。