Python 程序員必須要學會的「日誌」記錄

知識 12-09

寫在之前

在我們的現實生活中，「日誌記錄」其實是一件非常重要的事情，比如銀行的轉賬記錄，汽車的行車記錄儀記錄行駛過程中的一切，如果出現了什麼問題，我們可以通過「日誌記錄」來搞清楚到底發生了什麼事情。

除了在生活中，在日常的系統開發以及調試等過程中，記錄日誌同樣是一件很重要的事情。很多編程初學者並沒有「記錄日誌」的習慣，認為記錄日誌是一件可有可無的事情，出現問題的時候只要使用 print 函數列印一下程序的中間結果即可，真是 too young too naive。只是 print 的話對於簡單的腳本程序來說或許可行，可是到了碰到複雜的系統，你如果還是只用 print 這種方式的話，你會看到大量的消息，看到吐也不一定能找到其中有用的消息。

「日誌」是一個系統的重要組成部分，用來記錄用戶操作、系統運行狀態和錯誤信息，它的好壞直接影響到系統出現問題時定位的速度，有日誌記錄，我們可以在服務崩潰的時候很快的通過查看日誌來發現問題出現的地方，同樣也可以通過對日誌的觀察和分析，提前發現系統可能存在的風險。

Python 的標準日誌模塊

上面我們說了「日誌」是如此的重要，作為無所不能的 Python 當然也有日誌相關的功能，Python 標準庫中提供了 logging 模塊供我們使用。在最簡單的使用中，默認情況下 logging 將日誌列印到屏幕終端，我們可以直接導入 logging 模塊，然後調用 debug，info，warn，error 和 critical 等函數來記錄日誌，默認日誌的級別為 warning，級別比 warning 高的日誌才會被顯示（critical > error > warning > info > debug），「級別」是一個邏輯上的概念，用來區分日誌的重要程度。

import logging

logging.debug("debug message")

logging.info("info message")

logging.warn("warn message")

logging.error("error message")

logging.critical("critical message")

上述代碼的執行結果如下所示：

WARNING:root:warn message

ERROR:root:error message

CRITICAL:root:critical message

我在上面說過，用 print 的話會產生大量的信息，從而很難從中找到真正有用的信息。而 logging 中將日誌分成不同的級別以後，我們在大多數時間只保存級別比較高的日誌信息，從而提高了日誌的性能和分析速度，這樣我們就可以很快速的從一個很大的日誌文件里找到錯誤的信息。

配置日誌格式

我們在用 logging 來記錄日誌之前，先來進行一些簡單的配置：

import logging

logging.basicConfig(filename= "test.log", level= logging.INFO)

logging.debug("debug message")

logging.info("info message")

logging.warn("warn message")

logging.error("error message")

logging.critical("critical message")

運行上面的代碼以後，會在當前的目錄下新建一個 test.log 的文件，這個文件中存儲 info 以及 info 以上級別的日誌記錄。運行一次的結果如下所示：

INFO:root:info message

WARNING:root:warn message

ERROR:root:error message

CRITICAL:root:critical message

上面的例子中，我是用 basicConfig 對日誌進行了簡單的配置，其實我們還可以進行更為複雜些的配置，在此之前，我們先來了解一下 logging 中的幾個概念：

Logger：日誌記錄器，是應用程序中可以直接使用的介面。

Handler：日誌處理器，用以表明將日誌保存到什麼地方以及保存多久。

Formatter：格式化，用以配置日誌的輸出格式。

上述三者的關係是：一個 Logger 使用一個 Handler，一個 Handler 使用一個 Formatter。那麼概念我們知道了，該如何去使用它們呢？我們的 logging 中有很多種方式來配置文件，簡單的就用上面所說的 basicConfig，對於比較複雜的我們可以將日誌的配置保存在一個配置文件中，然後在主程序中使用 fileConfig 讀取配置文件。

基本的知識我們知道了，下面我們來做一個小的題目：日誌文件保存所有 debug 及其以上級別的日誌，每條日誌中要有列印日誌的時間，日誌的級別和日誌的內容。請先自己嘗試著思考一下，如果你已經思考完畢請繼續向下看：

import logging

logging.basicConfig(

level= logging.DEBUG,

format = "%(asctime)s : %(levelname)s : %(message)s",

filename= "test.log"

)

logging.debug("debug message")

logging.info("info message")

logging.warn("warn message")

logging.error("error message")

logging.critical("critical message")

上述代碼的一次運行結果如下：

2018-10-19 22:50:35,225 : DEBUG : debug message

2018-10-19 22:50:35,225 : INFO : info message

2018-10-19 22:50:35,225 : WARNING : warn message

2018-10-19 22:50:35,225 : ERROR : error message

2018-10-19 22:50:35,225 : CRITICAL : critical message

我剛剛在上面說過，對於比較複雜的我們可以將日誌的配置保存在一個配置文件中，然後在主程序中使用 fileConfig 讀取配置文件。下面我們就來看一個典型的日誌配置文件（配置文件名為 logging.conf）：

[loggers]

keys = root

[handlers]

keys = logfile

[formatters]

keys = generic

[logger_root]

handlers = logfile

[handler_logfile]

class = handlers.TimedRotatingFileHandler

args = ("test.log", "midnight", 1, 10)

level = DEBUG

formatter = generic

[formatter_generic]

format = %(asctime)s %(levelname)-5.5s [%(name)s:%(lineno)s] %(message)s

在上述的日誌配置文件中，首先我們在 [loggers] 中聲明了一個叫做 root 的日誌記錄器（logger），在 [handlers] 中聲明了一個叫 logfile 的日誌處理器（handler），在 [formatters] 中聲明了一個名為 generic 的格式化（formatter）。之後在 [logger_root] 中定義 root 這個日誌處理器（logger）所使用的日誌處理器（handler）是哪個，在 [handler_logfile] 中定義了日誌處理器（handler）輸出日誌的方式、日誌文件的切換時間等。最後在 [formatter_generic] 中定義了日誌的格式，包括日誌的產生時間，級別、文件名以及行號等信息。

有了上述的配置文件以後，我們就可以在主代碼中使用 logging.conf 模塊的 fileConfig 函數載入日誌配置：

import logging

import logging.config

logging.config.fileConfig("logging.conf")

logging.debug("debug message")

logging.info("info message")

logging.warn("warn message")

logging.error("error message")

logging.critical("critical message")

上述代碼的運行一次的結果如下所示：

2018-10-19 23:00:02,809 WARNI [root:8] warn message

2018-10-19 23:00:02,809 ERROR [root:9] error message