Python Log 從小白到入門

我們有時會有要在程式執行時輸出一些後台訊息的需求，用於顯示程式當下的行為，這樣的訊息我們稱為 log。

在開發階段我們會用 log 來協助除錯，而在正式環境也會留下一些必要的 log 以便日後追蹤，例如記下用戶登入的時間／地點／裝置等資訊，讓我們可以利用這些 log 來檢測出不尋常的登入行為。

與 print() 大法不同的是，log 除了把訊息顯示在螢幕外，還有有更豐富的設定選項，例如輸出到檔案，以及設定檔案的保留週期等等，這些都是 print() 大法難以實現的特性，因此對於記錄程式行為的需求，建議還是老老實實地用專門的 log 套件來實現。

在 Python 的世界，標準函式庫就有內建 log 模組 logging。

Python 的 logging

因為是內建在標準函式庫內，所以可以直接引入：

import logging

logging.debug('debug message')
logging.info('info message')
logging.warning('warning message')
logging.error('error message')
logging.critical('critical message')

上面的範例是最簡單的用法，引入 logging 後可以直接調用，直接調用會把訊息顯示在螢幕上，上面我們調用了五個函式，他們代表的是訊息的重大程度，在 Python 文件內的定義如下：

上面的範例執行後輸出如下：

WARNING:root:warning message
ERROR:root:error message
CRITICAL:root:critical message

注意到 debug 和 info 訊息不見了！

因為 logging 預設只輸出 warning 及比 warning 更嚴重（即級別 ≥ 30）的訊息，這樣的預設配置較符合正式環境的需求，避免過多無謂的 info、debug 訊息輸出的 IO 作業把效能拖垮，或把空間灌爆。

在開發階段一般我們會把所有的訊息級別都打開方便我們除錯，因此我們把上面的範例修改一下：

import logging

dev_logger: logging.Logger = logging.getLogger(name='dev')
dev_logger.setLevel(logging.DEBUG)

handler: logging.StreamHandler = logging.StreamHandler()
dev_logger.addHandler(handler)

dev_logger.debug('debug message')
dev_logger.info('info message')
dev_logger.warning('warning message')
dev_logger.error('error message')
dev_logger.critical('critical message')

這個範例引入了 logging 的其它概念，下面一一說明。

Logger

在第一個範例未做任何設定的 logging 我們操作的是一個稱為 root 的 logger，而現在這個範例我們用 getLogger() 函式建立了另一個 dev_logger，後面的設定也都是基於這個新的 dev_logger，我們可以利用 logger 的機制建立無數個 logger，每個 logger 都可以有自己的組態，例如儲存到不同的檔案，或者不同的輸出的格式等等，雖然 root logger 也是可以被做設定的，但個人建議另外建立自己的 logger 再把它變成自己喜歡的形狀，而不要去更動 root logger 的行為，避免無意中改掉專案內依賴套件的 logger 行為。

而那句 setLevel(logging.DEBUG) 自然就是設定 logger 輸出級別的函式，裡面的 logging.DEBUG 也很單純，就是整數 10，意即輸出 debug 及比 debug 更嚴重（即級別 ≥ 10）的的訊息。

Handler

在 logging 模組的 handler 負責處理 log 訊息的輸出工作，例如輸出到螢幕上或者某個檔案內，而我們這邊使用了 logging.StreamHandler() 這個 logging 模組內預帶的 handler。StreamHandler() 在不加任何參數的情況下，會把訊息輸出到 stderr，在作業系統未做額外的配置下，stderr 可以簡單的理解為顯示到螢幕上。

而 addHandler() 就望文生義了。

值得一提的是，一個 logger 可以加上數個 handler，意即 dev_logger 除了加入一個 StreamHandler 外，還可以再定義其他的 handler，例如一個 FileHandler，如此一則 log 訊息就會被顯示在螢幕上以及被存到某個 log 檔內。

把上面的範例程式跑出來會輸出這些訊息：

debug message
info message
warning message
error message
critical message

回頭和第一個範例的結果比較一下，會發現訊息的格式不太一樣，因為我們並未對 dev_logger 設定它的訊息格式，而原始的 root logger 是有預設它的訊息格式的。

Formatter

在此我們再引入另一個 logging 設定 log 訊息格式的特性 formatter。

再把範例加工一下：

import logging

dev_logger: logging.Logger = logging.getLogger(name='dev')
dev_logger.setLevel(logging.DEBUG)

handler: logging.StreamHandler = logging.StreamHandler()
formatter: logging.Formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
handler.setFormatter(formatter)
dev_logger.addHandler(handler)

dev_logger.debug('debug message')
dev_logger.info('info message')
dev_logger.warning('warning message')
dev_logger.error('error message')
dev_logger.critical('critical message')

先看輸出結果：

2005-03-19 15:10:26,618 - dev - DEBUG - debug message
2005-03-19 15:10:26,620 - dev - INFO - info message
2005-03-19 15:10:26,695 - dev - WARNING - warn message
2005-03-19 15:10:26,697 - dev - ERROR - error message
2005-03-19 15:10:26,773 - dev - CRITICAL - critical message

這裡的格式是由程式內的 formatter 定義的，它是一個 logging.Formatter 物件，在實例化時餵入的字串定義了這個 formatter 的格式。除了範例內的代號，完整的格式代號如下：

格式代號這麼多，而在設定 log 格式時也並沒有所謂的最佳實踐格式，該怎麼設可以參考下面的原則：

• 足夠的資訊量，但不要一股腦的全塞進去，追求的是穠纖合度的平衡，爆量的 log 只會把機台的 IO 和空間塞爆。
• 人機皆可讀，log 除了給人看之外，也可以餵給外部的 log 分析服務，做到提醒或警報的功能。
• 不易混淆的分隔符號，讓不論是人讀或機讀都可以快速的解析出訊息的區段，而不會在茫茫 log 海中迷失。
• 適度的分類與分級，利用前面提到的 logger 與級別的機制，對 log 做分類與分級，debug 用的訊息不要流到別的層級；critical 的訊息不要放到 warning 而被忽略。

綜合以上，範例內的 '%(asctime)s - %(name)s - %(levelname)s - %(message)s' 就是個頗不錯的格式。

專案內的 Log 模組

上一個部份談的是 logging 本身的用法，若要在專案內導入 log 機制，還需要考慮這幾點：

1. 專案內的其它套件是否也有定義自己的 log？
2. 要如何讓自己的 log 與其他套件的 log 和平共存而不互相干擾？
3. 或者是如何依自己的需求魔改其他套件的 log 行為？

以 uvicorn 這個 ASGI server 來說，它就有自己的 log 機制，每當它跑起來就會開始吐訊息：

INFO:     Started server process [20870]
INFO:     Waiting for application startup.
INFO:     Application startup complete.
INFO:     Uvicorn running on http://127.0.0.1:8000 (Press CTRL+C to quit)

不只 uvicorn，大多數的 HTTP server 也都會吐出類似的 log，內容有啟動資訊以及訪客的請求資訊等等。

如果你不想和它的 log 互相干擾，那比較好的方式是建立自己的 logger，並設定自己的 handler 和 formatter，就如同前一部分的範例那樣。

另外由於你的 logger 有可能會在多個其他的 Python 模組內被引入，建議也把 logger 寫成獨立的模組便於使用。

如果你想魔改其它套件的 log 納為己用，那我在此為您加油！祝您好運！

結語

這篇介紹了 logging 模組的基礎用法，有些特性是本文並未涉及的，特別是組態檔的部份，logging 可以從外部的組態檔讀入配置，這樣的特性讓我們可以更好的把專案內的 log 設定與程式邏輯分離，並把所有的 logger 組織在一份獨立的檔案內，也更符合關注點分離的原則，或許未來可以再寫一篇來騙稿費。:p

Share