Python 中的 Log 利器：使用 logging 模組來整理 print 訊息

前言

在 Python 中一個簡單 debug 的方式就是使用 print 函式，但當 print 散佈四處時就容易使得 Log 越發雜亂，藏木於林，很快就會迷失在 Log 叢裡。大部分人只是把 Python 內建的 logging 模組當成 print 的一個別名，然而若能聰明的利用它，除了能夠有效解決前述問題之外，你會發現 Log 不能再更清晰。

Logger & Handler

在開始使用 logging 之前，需要先了解三點重要但很少人全部提的概念。

logging 模組裡的2個主要角色：

  1. Logger：Log 生產者，預設綁定 stdout 且 Level 為 WARNING。
  2. Handler：Log 接收方。

Log 有分輕重緩急

logging模組內建5個 Level 級別（Level 數值）：

  1. CRITICAL（50）
  2. ERROR（40）
  3. WARNING（30）
  4. INFO（20）
  5. DEBUG（10）
  6. NOTSET（0），不同 Logger 對於此 Level 的意義不同，見下一段說明

Logger 可以分別呼叫 critical、 error、 warning、 info、 debug 方法來達到 Log 分流的應用，只有比設定級別（包含）還嚴重的 Log 會被輸出。例如設定 Level 為 ERROR 就只會輸出 ERROR 及 CRITICAL 訊息。

Handler 也可以設定 Level 級別，同理只接收比設定級別嚴重的 Log 訊息。

最重要的一點，Logger 是有分階層的

所以吐出的 Log 除了送往所有綁定的 Handler 之外還會往上傳遞形成一條「Log 流」直到最上層，也就是 logging 內建的 root Logger。因此如果新建的 Logger 不額外設定，所有 Log 都會匯流到該 root Logger。

編按：此處所指的最上層是河流下游的感覺，本篇將一律使用上下來表示根 Logger（Log 流下游）和子 Logger（Log 流上游）。

因此，在佈置 Logger 及 Handler 時有幾點注意事項：

  1. Logger 可以呼叫 addHandler 方法來綁定 Handler
  2. Logger 藉由綁定多個 Handler 來實現同步輸出（例如同時存 Log 檔、及輸出 GUI）
  3. 由於 Log 傳遞的特性，Handler 通常只需要（且應該只）被綁定在一個 Logger 之上
  4. NOTSET 用於 root Logger 表示不設級別（所有 Log 都印），用於其他 Logger 表示繼承使用上層 Level

讓我們來看點例子。

Root Logger

logging 最簡單的應用：

import logging

logging.basicConfig(level=logging.INFO)
logging.info('Hi!')
# in stdout: 'INFO:root:Hi'

logging 直接用就是使用了 root Logger，為了輸出 INFO 級別的 Log 先行呼叫了 basicConfig 來改變 root Logger 的 Level。上面的程式碼和以下等價。

import logging

root_logger = logging.getLogger()
root_logger.setLevel(logging.INFO)
root_logger.info('Hi!')
# int stdout: 'INFO:root:Hi'

你會發現下面的程式碼顯得很冗長，所以想偷懶就用上面的版本吧～需要了解的是 logging 本身並不是一個 Logger，只是提供了一個方便使用 root Logger 的介面。

Create A Logger

所有新建的 Logger 都是 root Logger 的下層，而 Logger 層級是用 Logger 名稱中的 . 來區分。例如：

# create a logger by passing the name to getLogger
main_logger = logging.getLogger('main')

# create a children logger to the main_logger
sub_logger = logging.getLogger('main.sub')
# or
sub_logger = main_logger.getChild('sub')

# set propagate to False if you don't want log message propagate
# sub_logger.propagate = False

在這樣的配置中，sub_logger 所吐出來的 Log 也會流至 main_logger、以及 root Logger，如果不希望 sub_logger 的東西往回流的話可以設置 propagate 屬性為 False。

這些 Logger 一樣可以使用各種級別的方法：

main_logger.warning('main warning!')
# in stdout: 'WARNING:main:main warning!'
sub_logger.debug('sub debug')
# in stdout: 'DEBUG:main.sub:sub debug'
如果沒看到 Log，請留意目前的 Level 級別，Logger 可以呼叫 getEffectiveLevel 方法查看目前套用到的級別。
如果在煩惱logger要取什麼名字，一個常見的慣例就是直接使用__name__變數。

體會一下 Log 流

用眼睛閱讀一下程式碼，試問哪些 Log 會被輸出？

import logging

logging.basicConfig(level=logging.INFO)

main_logger = logging.getLogger('main')
main_logger.setLevel(logging.WARNING)

sub_logger = logging.getLogger('main.sub')

logging.debug('root debug')
main_logger.info('main info')
sub_logger.debug('sub debug')
sub_logger.info('sub info')
sub_logger.warning('sub warning')

答對了嗎？5 個 Log 級別及 Logger 的觀念十分重要，希望大家在加入 Handler 之前都能先掌握 Logger 的用法。

Create A Handler

logging 提供了許多的 Handler，以下用 FileHandler 實作一個簡單的 Log 檔案 Handler。

# create a log file handler
file_handler = logging.FileHandler('log.txt')

# bind to a logger
logger.addHandler(file_handler)

不能再更簡單。綁定 Logger 之後，只要 Logger 有輸出（包含子 Logger 傳上來的 Log），該 log.txt 檔案就會持續寫入。

上面的程式碼也可以用 StreamHandler 等價實作：

# create a log file handler
file_handler = logging.StreamHandler(open('log.txt', 'a'))
注意：StreamHandler 不帶參數的預設值是 stderr。

此外也不限於 open，只要一個物件有實作 write 和 flush 方法，就可以帶入作為 StreamHander 的創建參數。另外如果希望限制 Log 檔案的大小上限可以改用 RotatingFileHandler，以設定其中的 maxBytes、backupCount 參數。

除了以上介紹的 Handler 之外，建議可以翻閲 logging 提供的 Handler 列表以尋找有無符合自己需求的 Handler。

Log Format

覺得預設的 Log Output 不好看可以藉由設定 format 參數來改變輸出格式，例如：

logging.basicConfig(
    format="[%(asctime)s][%(name)-5s][%(levelname)-5s] %(message)s (%(filename)s:%(lineno)d)",
    datefmt="%Y-%m-%d %H:%M:%S",
)
# output like: '[2021-10-22 13:02:26][root ][INFO ] hello world! (example.py:87)'

basicConfig 更改的是 stdout 輸出格式，format 字串中的變數名稱請參考 LogRecord attributes。

如果只想改變某個 Handler 的輸出格式需要使用 Formatter：

formatter = logging.Formatter(
    "[%(asctime)s][%(name)-5s][%(levelname)-5s] %(message)s (%(filename)s:%(lineno)d)",
    datefmt="%Y-%m-%d %H:%M:%S",
)
handler.setFormatter(formatter)
# output like: '[2021-10-22 13:02:26][root ][INFO ] hello world! (example.py:87)'

Log Traceback

當程式發生不預期的狀況時 Traceback 就很有幫助，除了自己呼叫 traceback.format_exc 之外，其實 logging 就可以幫你做到：

try:
    1/0  # make a ZeroDivisionError exception
except:
    logger.error("Error", exc_info=True)
    ## alternatively 
    # logger.info("Error", exc_info=True) 
    # logger.warning("Error", exc_info=True) 
    # logger.exception("Error")

 

本篇僅介紹 logging 模組的大概念，因此其他進階的功能例如彩色 Output（用 StreamHandler 實作）、設定 Filter 過濾訊息等等，就留待大家自行研究研究啦~

 

References

  1. logging — Logging facility for Python

 

Post Views: 8,683