Python | テスト・設計・品質:ロギング設計

Python Python
スポンサーリンク

ロギング設計って何?一言でいうと「あとから原因を追えるように“足跡”を設計すること」

ロギング設計は、
「エラーが起きたとき・おかしな動きをしたときに、あとから原因を追えるように、どこで何を記録しておくかを考えること」です。

単に print を散らばせるのではなく、

どのレベルでログを出すか(INFO / WARNING / ERROR など)
どんな情報を必ず残すか(ユーザーID、リクエストIDなど)
どこでログを出して、どこでは出さないか
どこに書き出すか(コンソール、ファイル、外部サービスなど)

を「設計」として決めていくイメージです。

Python には標準で logging モジュールがあるので、これを前提に話を進めます。


まずは「printデバッグ」と「logging」の違いを押さえる

print だけで頑張ると何がつらくなるか

初心者のうちは、よくこうします。

def process_order(order_id: int) -> None:
    print("start process_order", order_id)
    ...
    print("end process_order", order_id)
Python

小さいスクリプトならこれでも十分です。
でも、規模が少し大きくなると、次のような問題が出てきます。

どのメッセージが重要で、どれがただのデバッグ用なのか分からない
本番環境で print が混ざると、標準出力がぐちゃぐちゃになる
ファイルに残したいとき、自分で全部制御しないといけない

そこで登場するのが logging です。

logging の基本:レベルとロガー

最小限の例から見てみます。

import logging

logging.basicConfig(level=logging.INFO)

def process_order(order_id: int) -> None:
    logging.info("start process_order order_id=%s", order_id)
    ...
    logging.info("end process_order order_id=%s", order_id)
Python

ここで大事なのは、

logging.info のように「レベル」を付けてログを出す
basicConfig で「どのレベル以上を出すか」を切り替えられる

という点です。

例えば、開発中は DEBUG まで全部出す、本番では INFO 以上だけ出す、という切り替えが簡単にできます。


ロギング設計の軸その1:ログレベルを「意味」で使い分ける

代表的なログレベルと使い分けのイメージ

Python の logging には、主に次のレベルがあります。

DEBUG
開発者向けの細かい情報(処理の途中経過など)

INFO
通常の動作の記録(開始・終了・重要なイベント)

WARNING
想定内だが注意すべき状況(リトライした、デフォルト値を使ったなど)

ERROR
処理が失敗した(例外が発生したなど)

CRITICAL
システム全体に影響する重大な問題

ロギング設計では、「どの状況でどのレベルを使うか」を決めておくことが重要です。

具体例:注文処理のログレベル設計

注文処理の関数を例にしてみます。

import logging

logger = logging.getLogger(__name__)

def process_order(order_id: int) -> None:
    logger.info("start process_order order_id=%s", order_id)

    try:
        order = load_order(order_id)
    except OrderNotFound:
        logger.warning("order not found order_id=%s", order_id)
        return

    logger.debug("loaded order order_id=%s status=%s", order_id, order.status)

    try:
        charge(order)
    except PaymentError as e:
        logger.error("payment failed order_id=%s error=%s", order_id, e)
        raise

    logger.info("completed process_order order_id=%s", order_id)
Python

ここでは、

処理の開始・終了は INFO
想定内の「見つからない」は WARNING
開発者向けの詳細情報は DEBUG
本当に失敗したときは ERROR

というルールで使い分けています。

この「レベルの意味」をチームや自分の中で揃えておくと、ログが一気に読みやすくなります。


ロギング設計の軸その2:「何を必ず残すか」を決める

コンテキスト情報を必ず入れる

ログは「メッセージだけ」だと、あとから追うのが大変です。

例えば、

logger.error("payment failed")
Python

だけだと、「どの注文で?」が分かりません。

最低限、次のような情報を一緒に残すように設計すると、トレースしやすくなります。

ユーザーID
注文ID
リクエストID(Webなら)

さっきの例では、order_id を必ず入れるようにしています。

logger.error("payment failed order_id=%s error=%s", order_id, e)
Python

この「必ず付ける情報」を決めておくのが、ロギング設計の重要ポイントです。

フォーマットを統一する

basicConfig でフォーマットを指定すると、ログの見た目を揃えられます。

import logging

logging.basicConfig(
    level=logging.INFO,
    format="%(asctime)s [%(levelname)s] %(name)s %(message)s",
)
Python

これで、ログは例えばこう出ます。

2026-04-02 20:30:00,123 [INFO] app.order start process_order order_id=123
2026-04-02 20:30:01,456 [ERROR] app.order payment failed order_id=123 error=Timeout

時刻、レベル、ロガー名、メッセージが揃っていると、
あとから見返したときに「いつ・どこで・何が起きたか」がすぐ分かります。


ロギング設計の軸その3:どこでログを出すか/出さないか

なんでもかんでもログにしない

ロギング設計でやりがちなのが、「とりあえず全部ログに出す」です。

例えば、ループの中で毎回 DEBUG を出したり、
大量のデータをそのままログに書いたり。

これは、ログがノイズだらけになり、本当に必要な情報が埋もれてしまいます。

意識したいのは、「イベント」をログにすることです。

処理の開始・終了
外部サービスとのやりとり(リクエスト・レスポンスの概要)
重要な分岐(リトライした、スキップしたなど)
エラー・例外

逆に、「毎回の細かいループの中身」などは、
本当に必要なときだけ DEBUG で一時的に出す、くらいに留めるのが現実的です。

ドメイン層では「意味のあるログ」を出す

ドメインロジックの中でログを出すときは、
「ビジネス的に意味のあるイベント」を記録するのが良いです。

例えば、注文ドメインなら、

注文が作成された
支払いが成功した
支払いが失敗した
注文がキャンセルされた

などです。

class OrderService:
    def __init__(self, logger: logging.Logger) -> None:
        self._logger = logger

    def cancel(self, order_id: int) -> None:
        ...
        self._logger.info("order canceled order_id=%s", order_id)
Python

こうしておくと、「ビジネスイベントのタイムライン」としてログを追えるようになります。


ロギング設計とテスト・品質の関係

ログは「本番での唯一の手がかり」になる

テスト環境では再現しないバグが、本番でだけ起きることがあります。
そのとき、頼りになるのはログです。

どのリクエストで
どのユーザーで
どの処理の途中で
どんなエラーが起きたか

これを追えるかどうかは、ロギング設計にかかっています。

「とりあえず print」ではなく、
「どのイベントを、どのレベルで、どんな情報と一緒に残すか」を考えておくことは、
品質の最後の砦に近いです。

ログを前提にしたテストも書ける

場合によっては、「この処理をしたら、このログが出るべき」というテストを書くこともあります。

例えば、「支払い失敗時には ERROR ログが出るべき」というテスト。

import logging

class ListHandler(logging.Handler):
    def __init__(self) -> None:
        super().__init__()
        self.records: list[logging.LogRecord] = []

    def emit(self, record: logging.LogRecord) -> None:
        self.records.append(record)

def test_payment_error_logs_error():
    logger = logging.getLogger("app.order")
    handler = ListHandler()
    logger.addHandler(handler)
    logger.setLevel(logging.DEBUG)

    # ここで、わざと支払いエラーを起こすような処理を呼ぶ
    try:
        process_order(order_id=999)  # 例えば存在しないID
    except PaymentError:
        pass

    assert any(r.levelno == logging.ERROR for r in handler.records)
Python

ここまでやるかどうかはケース次第ですが、
「ログも仕様の一部」として扱うことがある、というのは知っておくと良いです。


初心者がロギング設計でまず意識するといいこと

まずは「モジュールごとにロガーを持つ」習慣をつける

logging.getLogger(__name__) を各モジュールで呼んでおくのは、定番パターンです。

# app/order.py
import logging

logger = logging.getLogger(__name__)

def process_order(order_id: int) -> None:
    logger.info("start process_order order_id=%s", order_id)
Python

こうしておくと、
「どのモジュールからのログか」が %(name)s で分かるようになります。

「何が起きたか」を一文で説明できるログを書く

ログメッセージを書くときは、

「この行だけ読んで、何が起きたか分かるか?」

を意識してください。

悪い例:

logger.error("failed")
Python

良い例:

logger.error("payment failed order_id=%s error=%s", order_id, e)
Python

未来の自分が、ログだけを見て状況を再現できるかどうか。
その視点でメッセージを書くと、ロギング設計の質が一気に上がります。


まとめ(ロギング設計は「未来の自分のために足跡をデザインすること」)

初心者目線で整理すると、ロギング設計はこういうものです。

logging を使って、ログレベル(DEBUG / INFO / WARNING / ERROR)を意味で使い分け、処理の開始・終了・重要なイベント・エラーを一貫したルールで記録する。
注文IDやユーザーIDなどのコンテキスト情報を必ず含め、フォーマットを揃えることで、「いつ・どこで・何が起きたか」をあとから追いやすくする。
なんでもかんでもログにするのではなく、「ビジネス的に意味のあるイベント」を中心にログを設計すると、本番でのトラブルシュートや品質維持の強力な武器になる。

タイトルとURLをコピーしました