Python 單元測試與除錯：`logging` 設定完整指南

簡介

在開發 Python 專案時，測試與除錯 是保證程式品質的關鍵步驟。即使測試覆蓋率再高，若缺乏適當的日誌（logging）資訊，仍然難以快速定位問題、追蹤執行流程，甚至在正式環境中排除故障。
logging 模組是 Python 標準庫提供的功能強大且彈性的日誌系統，從簡單的 print() 替代到支援多層級、檔案輸出、輪替與結構化日誌，它都能滿足不同階段的需求。

本篇文章將從 概念、設定、實作範例 逐步說明，讓讀者能在單元測試與除錯時，利用 logging 建立可讀、可維護、可擴充的日誌機制，並避免常見的陷阱。

核心概念

1. Logger、Handler、Formatter 的角色分離

元件	功能說明	常見類型
Logger	產生日誌訊息的入口，負責決定訊息的等級（level）與傳遞給哪個 Handler。	`logging.getLogger(name)`
Handler	決定日誌訊息寫入位置（檔案、控制台、網路、DB 等）。每個 Handler 可自行設定等級與過濾規則。	`StreamHandler`、`FileHandler`、`RotatingFileHandler`、`SMTPHandler`
Formatter	定義輸出格式（時間、等級、模組、訊息等），讓日誌易於閱讀或機器解析。	`logging.Formatter(fmt, datefmt)`

概念小結：Logger → Handler → Formatter，三層分工讓日誌設定既彈性又不會互相干擾。

2. 日誌等級（Log Levels）

等級	數值	使用情境
`CRITICAL`	50	程式無法繼續執行的致命錯誤
`ERROR`	40	需要立即處理的錯誤
`WARNING`	30	潛在問題或不建議的使用方式
`INFO`	20	常規資訊（流程、狀態）
`DEBUG`	10	開發階段的詳細除錯資訊
`NOTSET`	0	繼承父 logger 的等級

技巧：在 測試環境 建議把根 logger 等級設為 DEBUG，而在 正式環境 則調整為 INFO 或 WARNING，以減少不必要的磁碟寫入與資訊外洩。

3. 基本設定：`basicConfig`

最簡單的方式是直接呼叫 logging.basicConfig()，一次完成 Handler、Formatter 與 Level 的設定。

import logging

# 設定根 logger，輸出到 console，等級為 DEBUG，格式自訂
logging.basicConfig(
    level=logging.DEBUG,
    format='%(asctime)s [%(levelname)s] %(name)s: %(message)s',
    datefmt='%Y-%m-%d %H:%M:%S'
)

logger = logging.getLogger(__name__)

logger.debug('這是一條 DEBUG 訊息')
logger.info('程式開始執行')
logger.warning('偵測到不建議的參數')
logger.error('發生錯誤，將拋出例外')
logger.critical('系統即將關閉')

basicConfig 只會在第一次呼叫時生效，若已有 Handler 存在，後續呼叫不會重新設定。這是 常見陷阱，請在程式入口（如 if __name__ == '__main__':）一次性完成設定。

4. 多 Handler 範例：同時寫檔與輸出至 Console

在較大型的專案中，往往需要同時把日誌寫入檔案（方便事後分析）以及即時顯示在 console（開發除錯）。

import logging
import sys
from logging.handlers import RotatingFileHandler

# 建立根 logger
logger = logging.getLogger('myapp')
logger.setLevel(logging.DEBUG)   # 允許所有等級的訊息傳遞

# 1️⃣ Console Handler（顯示 INFO 以上）
console_handler = logging.StreamHandler(sys.stdout)
console_handler.setLevel(logging.INFO)
console_formatter = logging.Formatter(
    fmt='%(asctime)s [%(levelname)s] %(message)s',
    datefmt='%H:%M:%S'
)
console_handler.setFormatter(console_formatter)

# 2️⃣ Rotating File Handler（寫入 DEBUG 以上，檔案大小 5 MB 循環 3 份）
file_handler = RotatingFileHandler('logs/app.log', maxBytes=5*1024*1024, backupCount=3, encoding='utf-8')
file_handler.setLevel(logging.DEBUG)
file_formatter = logging.Formatter(
    fmt='%(asctime)s %(levelname)s %(module)s:%(lineno)d - %(message)s',
    datefmt='%Y-%m-%d %H:%M:%S'
)
file_handler.setFormatter(file_formatter)

# 把 Handler 加入 logger
logger.addHandler(console_handler)
logger.addHandler(file_handler)

# 測試訊息
logger.debug('Debug 訊息寫入檔案')
logger.info('Info 訊息同時出現在 console 與檔案')
logger.error('Error 訊息示範')

說明：

RotatingFileHandler 可自動切割檔案，避免單一日誌檔過大。

console_handler 設為 INFO，讓開發時不被過多 DEBUG 訊息淹沒。

logger.addHandler() 可以重複呼叫，讓同一 logger 同時擁有多個輸出目標。

5. 使用 `dictConfig` 進行「宣告式」設定

在較複雜的應用（如 Django、Flask）中，我們常把設定寫在 YAML / JSON 或 Python dict，透過 logging.config.dictConfig 載入。這樣的好處是 設定與程式碼分離，且易於在不同環境切換。

import logging
import logging.config

LOGGING_CONFIG = {
    'version': 1,
    'disable_existing_loggers': False,   # 保留已存在的 logger
    'formatters': {
        'standard': {
            'format': '%(asctime)s %(levelname)s %(name)s %(module)s:%(lineno)d - %(message)s',
            'datefmt': '%Y-%m-%d %H:%M:%S'
        },
    },
    'handlers': {
        'console': {
            'class': 'logging.StreamHandler',
            'level': 'INFO',
            'formatter': 'standard',
            'stream': 'ext://sys.stdout'
        },
        'file': {
            'class': 'logging.handlers.TimedRotatingFileHandler',
            'level': 'DEBUG',
            'formatter': 'standard',
            'filename': 'logs/timed_app.log',
            'when': 'midnight',
            'backupCount': 7,
            'encoding': 'utf-8',
        },
    },
    'loggers': {
        'myapp': {
            'level': 'DEBUG',
            'handlers': ['console', 'file'],
            'propagate': False
        },
    }
}

logging.config.dictConfig(LOGGING_CONFIG)
logger = logging.getLogger('myapp')

logger.debug('使用 dictConfig 設定的 Debug 訊息')
logger.info('Info 訊息會同時出現在 console 與檔案')

重點：

disable_existing_loggers=False 可避免把第三方套件的 logger 全部關閉。

TimedRotatingFileHandler 依時間切割（如每日午夜），適合長期運行的服務。

propagate=False 防止訊息向上傳遞至根 logger，避免重複輸出。

6. 捕捉例外與堆疊資訊（Exception Logging）

在單元測試失敗或程式崩潰時，完整的例外堆疊 能提供關鍵線索。logger.exception() 會自動把當前的例外資訊（traceback）寫入日誌，等同於 logger.error(..., exc_info=True)。

import logging

logging.basicConfig(level=logging.ERROR, format='%(asctime)s %(levelname)s %(message)s')
logger = logging.getLogger('exception_demo')

def divide(a, b):
    try:
        return a / b
    except ZeroDivisionError:
        logger.exception('除以零錯誤發生，參數 a=%s, b=%s', a, b)
        # 重新拋出或回傳預設值
        raise

# 呼叫測試
try:
    divide(10, 0)
except ZeroDivisionError:
    pass

執行後的日誌會包含完整的堆疊追蹤，方便在 CI/CD 或 錯誤回報 系統中直接定位問題。

常見陷阱與最佳實踐

陷阱	說明	解決方案
多次呼叫 `basicConfig`	後面的設定不會生效，導致日誌仍使用舊的 Handler。	在程式入口一次性呼叫，或改用 `dictConfig` / 手動建立 Handler。
根 logger 等級過高	例如把根 logger 設為 `WARNING`，會過濾掉 `INFO`/`DEBUG`，測試時看不到關鍵訊息。	在測試環境使用 `logging.getLogger().setLevel(logging.DEBUG)`。
忘記關閉檔案 Handler	長時間執行的程式若頻繁建立 `FileHandler`，可能導致檔案描述符耗盡。	使用上下文管理（`with`）或在程式結束時呼叫 `handler.close()`。
日誌檔案未加鎖	多執行緒/多程序寫同一檔案會產生亂碼。	使用 `ConcurrentLogHandler`（第三方）或改用 Syslog/ELK 集中式日誌。
過度使用 `DEBUG`	產生龐大檔案，且可能泄露敏感資訊。	僅在開發或臨時除錯時開啟，正式環境限制為 `INFO` 或更高。

最佳實踐摘要：

統一入口：在 main.py 或測試套件的 conftest.py 中設定日誌，避免散落在各模組。
環境變數切換：利用 LOG_LEVEL、LOG_FILE 等環境變數，在不同部署階段自動調整。
結構化日誌：若要與 ELK、Splunk 整合，可使用 json 格式的 Formatter。
測試時捕捉日誌：unittest/pytest 提供 caplog（pytest）或 self.assertLogs（unittest）驗證日誌內容。

實際應用場景

場景	為什麼需要 `logging`	建議設定
單元測試	驗證錯誤訊息、追蹤測試流程	在 `pytest` 中使用 `caplog`，把根 logger 設為 `DEBUG`，只在測試失敗時輸出檔案。
CI/CD Pipeline	當測試失敗或部署錯誤時，自動收集日誌供分析	使用 `TimedRotatingFileHandler` + `json` Formatter，將日誌上傳至 Artifacts。
Web API（Flask/Django）	服務異常、請求追蹤、使用者行為分析	為每個 request 建立 Request ID，在 `Formatter` 中加入 `%(request_id)s`，並使用 `RotatingFileHandler`。
背景工作（Celery、Airflow）	任務失敗、重試次數、執行時間	使用 `FileHandler` + `TimedRotatingFileHandler`，在每個 task 開頭記錄 `task_id`、`args`、`kwargs`。
嵌入式/IoT	設備資源有限，需限制日誌大小	使用 `MemoryHandler` 暫存，滿額時寫入磁碟或透過網路傳送。

範例：Flask 中加入 Request ID

from flask import Flask, request, g
import logging
import uuid

app = Flask(__name__)

# 設定 logger
logger = logging.getLogger('flask_app')
handler = logging.StreamHandler()
formatter = logging.Formatter(
    fmt='%(asctime)s %(levelname)s %(request_id)s %(message)s',
    datefmt='%Y-%m-%d %H:%M:%S'
)
handler.setFormatter(formatter)
logger.addHandler(handler)
logger.setLevel(logging.INFO)

@app.before_request
def assign_request_id():
    g.request_id = str(uuid.uuid4())
    # 把 request_id 加入 log record 的 extra
    request.environ['log_extra'] = {'request_id': g.request_id}

@app.after_request
def after(resp):
    logger.info('Request finished', extra=request.environ.get('log_extra', {}))
    return resp

@app.route('/hello')
def hello():
    logger.debug('進入 hello endpoint', extra={'request_id': g.request_id})
    return 'Hello World!'

if __name__ == '__main__':
    app.run()

此範例示範如何在 每一次請求 中自動產生唯一 ID，並把它帶入日誌，讓日後追蹤單一請求的全程日誌變得簡單。

總結

logging 是 Python 除錯與測試 的核心工具，透過 Logger、Handler、Formatter 的分層設計，我們可以同時滿足 即時除錯、長期紀錄 與 集中式分析 的需求。
從最簡單的 basicConfig 到彈性的 dictConfig，再到進階的 Rotating、TimedRotating、Concurrent 等 Handler，根據不同的 運行環境（開發、測試、正式）調整等級與輸出目標，是保持日誌效能與安全的關鍵。
常見的陷阱（多次呼叫 basicConfig、根 logger 等級過高、檔案未關閉等）只要遵守 一次性設定、環境變數切換、適時關閉資源 的原則，就能輕鬆避免。
在 單元測試、CI/CD、Web 服務、背景工作 等實務場景中加入結構化、可追蹤的日誌，不僅提升除錯速度，也為日後的 運維、監控與分析 打下堅實基礎。

最後提醒：在撰寫程式碼時，先思考「我需要哪種層級的資訊」以及「日誌最終要給誰看」，再選擇合適的 logging 設定。只要把日誌當作 程式的生命線，除錯與測試的痛點自然會減少，開發效率也會顯著提升。祝你在 Python 專案中玩得開心，寫出乾淨、可追蹤的程式！

Python 單元測試與除錯：logging 設定完整指南

簡介