Posted inPython

Pythonのloggingモジュール完全ガイド：デバッグを速く、運用を楽に

Python tutorial - IT technology blog
Python tutorial - IT technology blog

ロギングがないときの問題

自分が作ったautomationプロジェクトは最初200行程度で、すべてうまく動いていた。print()でデバッグするだけで十分だった。それがやがて2000行になり、VPS上で24時間365日稼働するサービスになった。そのとき初めて気づいた——深夜3時にエラーが発生しても、振り返れるものが何もない。あるのは…真っ黒な画面だけ。

print()はファイルに保存されない。タイムスタンプもない。どのモジュールでエラーが起きたかもわからない。そして何より重要なのは——本番環境がクラッシュしたとき、必要なのはクラッシュ直前に「何が起きていたか」であり、最後のエラーメッセージだけでは不十分だということだ。

Pythonの標準ライブラリに含まれるloggingモジュールは、まさにその問題を解決するために生まれた。一度学べば、ずっと使える。

押さえておくべき核心概念

ログレベルとは？

Pythonのloggingには5段階のレベルがある（低い順に）：

  • DEBUG (10) — 技術的な詳細情報。開発中に使用
  • INFO (20) — 正常な動作状況の情報
  • WARNING (30) — 警告。エラーではないが注意が必要
  • ERROR (40) — エラーが発生したが、プログラムは継続可能
  • CRITICAL (50) — 重大なエラー。プログラムが停止する可能性がある

ロガーは、設定したレベル以上のメッセージのみを記録する。WARNINGに設定するとDEBUGとINFOは完全に無視される——本番環境でノイズを減らすのに便利だ。

理解すべき3つの構成要素

この3つが連携して機能する。どれか一つ欠けると、ログが出なかったり、意図しない場所に出力されたりする：

  • Logger — log.info()やlog.error()などを呼び出す場所。各ロガーには固有の名前があり、通常はモジュール名を使う。
  • Handler — ログの出力先を決定する：コンソール、ファイル、メール、HTTPエンドポイントなど。
  • Formatter — ログの表示形式を決定する：タイムスタンプの有無、モジュール名の有無、フォーマットなど。

実践：ステップバイステップ

ステップ1：5行で基本セットアップ

import logging

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

logging.info("スクリプトを開始します")
logging.warning("警告: 設定ファイルが見つかりません。デフォルト値を使用します")
logging.error("データベース接続エラー")

出力：

2026-03-25 10:15:32,104 - INFO - スクリプトを開始します
2026-03-25 10:15:32,105 - WARNING - 警告: 設定ファイルが見つかりません。デフォルト値を使用します
2026-03-25 10:15:32,106 - ERROR - データベース接続エラー

すぐに動かせるが、ログはコンソールにしか表示されない。ターミナルを閉じると全部消えてしまう。

ステップ2：ログをファイルに書き出す

import logging

logging.basicConfig(
    level=logging.INFO,
    format="%(asctime)s - %(name)s - %(levelname)s - %(message)s",
    handlers=[
        logging.FileHandler("app.log", encoding="utf-8"),
        logging.StreamHandler()  # コンソールにも表示する
    ]
)

log = logging.getLogger(__name__)
log.info("データベース接続に成功しました")

__name__でロガーに名前をつけるのが標準的なやり方だ——プロジェクトに数十のモジュールがあっても、ログを見ればどのファイルからのメッセージかすぐにわかる。推測する必要がない。

ステップ3：ログローテーション——ファイルの肥大化を防ぐ

ローテーションなしで数ヶ月24時間365日稼働させると、ログファイルが数GBになることがある。20GBのVPSではそれが現実の問題になる。RotatingFileHandlerがこれをすっきり解決してくれる：

import logging
from logging.handlers import RotatingFileHandler

log = logging.getLogger("myapp")
log.setLevel(logging.DEBUG)

# ファイルごとに最大5MB、バックアップを3つ保持
handler = RotatingFileHandler(
    "app.log",
    maxBytes=5 * 1024 * 1024,  # 5MB
    backupCount=3,
    encoding="utf-8"
)
formatter = logging.Formatter(
    "%(asctime)s - %(name)s - %(levelname)s - %(message)s"
)
handler.setFormatter(formatter)
log.addHandler(handler)

log.info("ロガーの準備ができました")

結果：app.log、app.log.1、app.log.2、app.log.3——合計最大約20MBで、満杯になると自動的にローテーションされる。

ステップ4：モジュールごとにロギングを整理する

プロジェクトが大きくなると、各モジュールに独自のロガーが必要になる。セットアップコードをあちこちにコピーペーストするのではなく、一箇所に集約したセットアップ関数を作り、どこからでも呼び出せるようにしよう。たとえば外部APIを呼び出すモジュールでも、同じセットアップ関数を2行で使い回せる：

# logger.py
import logging
from logging.handlers import RotatingFileHandler

def setup_logger(name: str, log_file: str = "app.log", level=logging.INFO):
    logger = logging.getLogger(name)
    if logger.handlers:  # ハンドラーの重複追加を防ぐ
        return logger

    logger.setLevel(level)
    fmt = logging.Formatter(
        "%(asctime)s [%(name)s] %(levelname)s: %(message)s",
        datefmt="%Y-%m-%d %H:%M:%S"
    )

    fh = RotatingFileHandler(log_file, maxBytes=5_000_000, backupCount=3)
    fh.setFormatter(fmt)

    ch = logging.StreamHandler()
    ch.setFormatter(fmt)

    logger.addHandler(fh)
    logger.addHandler(ch)
    return logger

各モジュールで必要なのはたった2行：

# database.py
from logger import setup_logger

log = setup_logger(__name__)

def connect(url):
    log.info(f"{url} に接続します")
    # ...
    log.debug("Connection pool initialized")

ステップ5：例外を正しくログに記録する

よくある間違い：例外をログに記録するのにトレースバックを忘れて、エラーがどの行で発生したかわからなくなること。

# 悪い例 — メッセージだけでトレースバックが失われる
try:
    result = 10 / 0
except ZeroDivisionError as e:
    log.error(f"エラー: {e}")

# 良い例 — 完全なトレースバックを保持する
try:
    result = 10 / 0
except ZeroDivisionError:
    log.exception("計算に失敗しました")  # スタックトレースを自動的に付加する

# 別の方法（同等）
try:
    result = 10 / 0
except ZeroDivisionError:
    log.error("計算に失敗しました", exc_info=True)

log.exception()はexceptブロック内でのみ使用できる。スタックトレース付きのlog.error()と同等だ——深夜2時に本番の問題をデバッグするとき、完全なトレースバックこそが最も必要なものだ。

ステップ6：ログにコンテキストを追加する——並列タスクのトレース

10個のタスクを同時に処理するサービスで、すべてのログが同じファイルに出力される——見ると混沌としている。LoggerAdapterを使えば、あるスコープのすべてのログ行にコンテキスト（例：タスクID）を付与できる：

import logging

# コンテキストを表示するためにフォーマッターに %(task_id)s が必要
fmt = logging.Formatter("%(asctime)s [%(task_id)s] %(levelname)s: %(message)s")
handler = logging.StreamHandler()
handler.setFormatter(fmt)

base_log = logging.getLogger("worker")
base_log.addHandler(handler)
base_log.setLevel(logging.DEBUG)

def process_task(task_id: str, data: dict):
    log = logging.LoggerAdapter(base_log, {"task_id": task_id})
    log.info("処理を開始します")
    log.info(f"{len(data)} 件のアイテムを処理します")
    # 出力:
    # 2026-03-25 10:00:01 [abc-123] INFO: 処理を開始します
    # 2026-03-25 10:00:01 [abc-123] INFO: 42 件のアイテムを処理します

process_task("abc-123", {})
process_task("xyz-456", {})

2つのタスクのログが入り混じっていても、確認したいタスクだけを絞り込める——grep abc-123 app.logだけでいい。

まとめ

自分のautomationプロジェクトを振り返ると——200行のprint()から、完全なロギングシステムを備えた2000行へ——最も大きな違いが現れるのはコーディング中ではなく、問題が発生したときだ。5MB×3バックアップのログローテーションにより、1週間分の動作記録を遡って確認できる。log.exception()により、トレースバックが失われることは二度とない。

覚えておくべき重要なポイント：

  • 最初からprint()の代わりにlogging.getLogger(__name__)を使う——コストは低く、メリットは大きい
  • ログが無限に膨らまないようRotatingFileHandlerを設定する
  • exceptブロックでは必ずlog.exception()を使う——トレースバックを失わないために
  • ロガーのセットアップ関数を専用モジュールに切り出し、コピーペーストを避ける
  • 本番環境はINFO、開発環境はDEBUG——DEBUGを本番に出してはいけない

次のプロジェクトでは、仮想環境のセットアップと同じくビジネスロジックを書く前にロギングをセットアップしよう。後で問題が発生したとき——必ず発生する——そのときの自分に感謝することになる。

Share:
Tags: