1. はじめに — ロギングは「保険」ではなく「視界」

ログを軽視するエンジニアは多くありませんが、「動くまで print で書いて、動いたら忘れる」のはよく見る現実です。本番運用で問題が起きたとき、現場で頼れるのはログだけです。設計時に「現場で何が起きたか後から追える状態」を意図して作っておく必要があります。

本記事は、私が業務で 24 時間動く監視アプリを開発・運用してきた経験を、自宅環境で再現できる形に整理したものです。Python 標準の logging モジュールの全体像は 公式ドキュメント も合わせて参照してください。

2. logging モジュールの 4 大要素

  • Logger: 「どこから出されたログか」を区別する論理的な単位。階層構造（ドット区切り）
  • Handler: 「どこに出すか」を決める。ファイル / コンソール / イベントログ / リモートサーバー
  • Formatter: 「どう整形するか」を決める。日時、レベル、メッセージなど
  • Filter: 「出すか / 出さないか」のカスタム判定（オプショナル）

4 つの組み合わせを設計し直すだけで、運用の見通しは劇的に変わります。

3. 最小実装からスタート

3.1 NG 例: 何もしない / basicConfig

# NG: 設計せずに使うと、後から制御が効かない
import logging
logging.basicConfig(level=logging.INFO)
logging.info("started")

これでも動きますが、複数モジュールから同じ logging を呼ぶと制御が効かなくなり、ライブラリ側のログが混入したり、エンコーディングが OS 依存になったりします。もう 1 つ重要な仕様として、basicConfig() は root ロガーに既にハンドラがあると 2 回目以降は黙って無視されます（Python 3.8+ なら force=True で上書き可能）。「各モジュールで basicConfig を呼べばいい」という発想は、この仕様で静かに破綻します。

3.2 推奨パターン: 起動時に 1 回だけ設定する

main.py と同じ場所に app フォルダを作り、その中に log_setup.py として保存します。

# app/log_setup.py
import logging
import logging.handlers
import sys
from pathlib import Path


def setup_logging(log_dir: Path, app_name: str = "app", level: int = logging.INFO) -> None:
    log_dir.mkdir(parents=True, exist_ok=True)

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

    # 1) ファイル: 日次ローテーション、14 日分保持
    file_handler = logging.handlers.TimedRotatingFileHandler(
        filename=log_dir / f"{app_name}.log",
        when="midnight",
        backupCount=14,
        encoding="utf-8",
    )
    file_handler.setFormatter(fmt)
    file_handler.setLevel(logging.INFO)

    # 2) エラー専用ファイル: ERROR 以上のみ集める
    err_handler = logging.handlers.RotatingFileHandler(
        filename=log_dir / f"{app_name}-error.log",
        maxBytes=10 * 1024 * 1024,
        backupCount=10,
        encoding="utf-8",
    )
    err_handler.setFormatter(fmt)
    err_handler.setLevel(logging.ERROR)

    # 3) コンソール: 開発時のみ役立つ
    console_handler = logging.StreamHandler(sys.stderr)
    console_handler.setFormatter(fmt)
    console_handler.setLevel(logging.DEBUG)

    root = logging.getLogger()
    root.setLevel(level)
    root.handlers.clear()
    for h in (file_handler, err_handler, console_handler):
        root.addHandler(h)

使い方はこうです。アプリの入口（main.py）で 1 回だけ呼び、各モジュールでは getLogger(__name__) を使います。

# main.py
import logging
from pathlib import Path

from app.log_setup import setup_logging

setup_logging(Path("logs"))
logger = logging.getLogger(__name__)
logger.info("app started")

これでログのソースがモジュール単位で追えるようになります。なおこの構成では root ロガーに付けるため、うるさい外部ライブラリのログも流れ込みます。必要に応じて logging.getLogger("urllib3").setLevel(logging.WARNING) のように個別に絞ってください。また Path("logs") は相対パスなので、タスクスケジューラやサービスから起動する場合は Path(__file__).parent / "logs" のような絶対パス基準にします（作業フォルダが C:\Windows\System32 になり、ログが行方不明になる定番事故を防げます）。

4. ハンドラの選定基準

4.1 RotatingFileHandler vs TimedRotatingFileHandler

  • RotatingFileHandler: ファイルサイズで切る。1 ファイルが膨大にならないことを保証したいときに有利
  • TimedRotatingFileHandler: 時刻で切る。「毎日 0:00 で切り替え」のような時系列管理がしたいときに有利

製造現場のような「日次で集計する」運用では、TimedRotatingFileHandler の when="midnight" が最も使いやすいです。各ハンドラの詳細仕様は logging.handlers の公式ドキュメント を参照してください。

4.2 SMTPHandler / NTEventLogHandler / SysLogHandler

  • SMTPHandler: ERROR 以上をメール送信。本番現場では遅延・スパム化のリスクあり、別レイヤ（Slack 等）への通知のほうが現実的
  • NTEventLogHandler: Windows のイベントビューアに記録。サービス系のアプリで有用（pywin32 が必要で、イベントソースの登録に管理者権限が要る点に注意）
  • SysLogHandler: Linux 環境で集中ログサーバーに送る

4.3 自前 Handler の落とし穴

「Slack に通知する自前 Handler」を書く場合、ハンドラ内でブロッキング処理（HTTP リクエスト）を行うと、ログ出力が遅延し、最悪アプリ全体が詰まります。QueueHandler + 別スレッドで処理する設計にしてください（後述）。

5. ログレベルの使い分け

  • DEBUG: 開発・調査時のみ。本番では原則出さない
  • INFO: 「正常時に何が起きているか」を記録。設備接続、データ受信件数、サマリ
  • WARNING: 「異常ではないが注意が必要」。再接続、リトライ、近接しきい値
  • ERROR: 「機能の一部が失敗した」。通信エラー、書き込み失敗
  • CRITICAL: 「アプリ全体に影響する致命傷」。設定ファイル読込失敗、ライセンス切れ

本番では INFO 以上が出る設計を基本にし、トラブル調査時に環境変数や設定で DEBUG に切り替えられる作りにします。

6. ログレベルの動的切り替え

import logging
import os
from pathlib import Path

from app.log_setup import setup_logging

# .strip() が地味に重要（後述の cmd の罠対策）
LEVEL = os.environ.get("LOG_LEVEL", "INFO").strip().upper()
setup_logging(log_dir=Path("logs"), level=getattr(logging, LEVEL, logging.INFO))

これで現場 PC でも環境変数ひとつで一時的に詳細ログを取れます。トラブル調査の現場で重要な機能です。設定方法はシェルによって違います。コマンドプロンプト（cmd）の場合（2 行に分けて実行）:

set LOG_LEVEL=DEBUG
app.exe

PowerShell の場合:

$env:LOG_LEVEL = "DEBUG"
.\app.exe

どちらもそのウィンドウ限りの設定です。調査が終わったら窓を閉じれば元の INFO に戻ります（「システムのプロパティ」で恒久設定すると、調査後も DEBUG が出っぱなしになるので注意）。

cmd で set LOG_LEVEL=DEBUG && app.exe と 1 行に書きたくなりますが、&& の前のスペースが値に含まれて "DEBUG "（末尾スペース付き）になります（筆者環境で実測）。上のコードが .strip() を挟んでいるのはこのためです。なお、24 時間止められない監視アプリでレベル変更のたびに再起動できない場合は、設定ファイルを定期的に読み直して logging.getLogger().setLevel(...) を実行時に呼ぶ方式にすると、無停止で切り替えられます。

7. 例外ロギングの定石

try:
    risky_operation()
except Exception:
    logger.exception("risky_operation failed")
    # スタックトレース付きで自動的に記録される

logger.exception は ERROR レベルでスタックトレースを含めてくれます。logger.error + 文字列連結より確実に多くの情報が残ります。

8. 構造化ログ（JSON Lines）

ログを解析対象として扱うなら、人間可読形式より JSON Lines のほうが圧倒的に扱いやすくなります。

import json
import logging


class JsonFormatter(logging.Formatter):
    def format(self, record: logging.LogRecord) -> str:
        payload = {
            "ts": self.formatTime(record, "%Y-%m-%dT%H:%M:%S%z"),
            "level": record.levelname,
            "logger": record.name,
            "message": record.getMessage(),
        }
        # extra= で渡された追加フィールドを乗せる
        for key, value in record.__dict__.items():
            if key.startswith("ctx_"):
                payload[key[4:]] = value
        if record.exc_info:
            payload["exc_info"] = self.formatException(record.exc_info)
        # default=str: datetime 等の非 JSON 型が extra に来ても落ちないように
        return json.dumps(payload, ensure_ascii=False, default=str)


# 配線: 3.2 の setup_logging 内で file_handler.setFormatter(JsonFormatter()) とする
# 使用例
logger = logging.getLogger("app.boot")
logger.info(
    "machine started",
    extra={"ctx_lot": "L0001", "ctx_machine": "M-01"},
)
# => {"ts":"2026-08-03T10:00:00+0900","level":"INFO","logger":"app.boot",
#     "message":"machine started","lot":"L0001","machine":"M-01"}

JSON Lines（1 行 1 JSON の構造化ログ仕様）にしておくと、後段で jq や pandas / DuckDB で集計しやすくなります。「どの設備で何回エラーが起きたか」のような集計が、Windows 標準の PowerShell なら Get-Content app.log | ConvertFrom-Json | Where-Object level -eq "ERROR" | Group-Object machine で出ます（Linux / Git Bash 環境なら要インストールの jq で jq 'select(.level=="ERROR") | .machine' app.log | sort | uniq -c）。

9. ローテーションの落とし穴

9.1 マルチプロセスでのローテーション

用語の整理から——プロセスは「別々に起動したアプリ（app.exe を 2 個立ち上げたら 2 プロセス）」、スレッドは「1 つのアプリの中の並行処理」です。RotatingFileHandler や TimedRotatingFileHandler は複数プロセスから同じファイルに書くと壊れます（ローテーションのタイミングがプロセス間で同期されないため）。複数の Python プロセスから同じログに集約したい場合は、10.2 の QueueHandler + 親プロセス集約パターンを使います。ちなみに「毎日 0:00 に切り替え」が夜勤帯の真っ最中になる 24 時間工場では、TimedRotatingFileHandler(when="midnight", atTime=...) でローテーション時刻を生産の切れ目に合わせられます。

9.2 サービスとして動かしているとき

NSSM（Windows でアプリをサービス化する定番ツール。詳細は Windows サービス化の記事）にはログローテーション機能 AppRotateFiles がありますが、これは NSSM がリダイレクトした標準出力・標準エラーのファイルにだけ効くもので、アプリが自前で開いたログファイルには効きません。両方でローテーションを設定すると、空ファイルや書き込みエラーの原因になります。「1 つのファイルのローテーションを担当する主体は 1 つに絞る」のが鉄則です。

9.3 Windows でローテーションが失敗する（PermissionError）

単一プロセスでも Windows 特有の罠があります。ローテーションはファイルのリネームで実現されるため、その瞬間に別のプログラムがログファイルを開いていると PermissionError で失敗します。犯人の定番は、ログを開きっぱなしのエディタ・tail 系ツール（Get-Content -Wait 等）・ウイルス対策ソフトのスキャンです。深夜 0 時のローテーションだけ失敗する、という症状ならまずこれを疑ってください。

10. QueueHandler パターン

10.1 高負荷対応（同一プロセス内の非同期化）

ログ書き込みがボトルネックになるアプリでは、QueueHandler でいったんキュー（バッファ）に積み、別スレッドの書き込み係が実際のファイル出力を担う設計が有効です。これは 3.2 の setup_logging の置き換え版です（両方は呼びません）。注意: ここで使う queue.Queue は同一プロセス内のスレッド間専用です（複数プロセスの集約は次節）。

import logging
import logging.handlers
import queue
from pathlib import Path


def setup_async_logging(log_path: Path) -> logging.handlers.QueueListener:
    log_path.parent.mkdir(parents=True, exist_ok=True)
    log_queue: queue.Queue = queue.Queue(-1)

    fmt = logging.Formatter("%(asctime)s [%(levelname)s] %(message)s")
    file_handler = logging.handlers.TimedRotatingFileHandler(
        log_path, when="midnight", backupCount=14, encoding="utf-8"
    )
    file_handler.setFormatter(fmt)

    listener = logging.handlers.QueueListener(log_queue, file_handler)
    listener.start()

    queue_handler = logging.handlers.QueueHandler(log_queue)
    root = logging.getLogger()
    root.handlers.clear()
    root.addHandler(queue_handler)
    root.setLevel(logging.INFO)

    return listener  # シャットダウン時に listener.stop() を呼ぶ

業務スレッドはキューに積むだけで即時返ってくるため、ログ起因の遅延がほぼゼロになります。

10.2 マルチプロセス集約（複数プロセスから 1 つのログへ）

リード文の「複数プロセスからログを書いたら混ざった」への回答はこちらです。multiprocessing.Queue を子プロセスに渡し、子プロセスは QueueHandler で積むだけ・ファイルに書くのは親プロセスだけという構成にします（ファイルを開くプロセスが 1 つになるので、9.1 の破損問題が起きません）。

import logging
import logging.handlers
import multiprocessing as mp
from pathlib import Path


def worker(log_queue: mp.Queue) -> None:
    """子プロセス側: ハンドラは QueueHandler だけにする"""
    root = logging.getLogger()
    root.handlers.clear()
    root.addHandler(logging.handlers.QueueHandler(log_queue))
    root.setLevel(logging.INFO)

    logging.getLogger(__name__).info("worker started")
    # ... 業務処理 ...


if __name__ == "__main__":
    log_queue: mp.Queue = mp.Queue(-1)

    # ファイルに書くのは親プロセスだけ
    log_dir = Path("logs")
    log_dir.mkdir(parents=True, exist_ok=True)
    file_handler = logging.handlers.TimedRotatingFileHandler(
        log_dir / "app.log", when="midnight", backupCount=14, encoding="utf-8"
    )
    file_handler.setFormatter(logging.Formatter(
        "%(asctime)s [%(levelname)s] %(processName)s %(name)s: %(message)s"
    ))

    listener = logging.handlers.QueueListener(log_queue, file_handler)
    listener.start()

    procs = [mp.Process(target=worker, args=(log_queue,), name=f"worker-{i}")
             for i in range(3)]
    for p in procs:
        p.start()
    for p in procs:
        p.join()

    listener.stop()

フォーマットに %(processName)s を入れておくと、どのプロセスのログかが一目で分かります。この例では子プロセスだけがログを書く構成なので、親プロセス自身もログを書きたい場合は、親の root ロガーにも QueueHandler(log_queue) を付けてください。なお、プロセスが別マシンにまたがる場合や、そもそも親子関係のない別アプリ同士の場合は、SocketHandler でログ収集サーバーに送る方式が公式ドキュメントで案内されています。

11. 「いつ・何を」記録すべきか

製造業のアプリで、私が必ずログに残すよう設計している項目を挙げます。

  • 起動 / 停止: バージョン、Python のエンコーディング、UTF-8 モードフラグ、設定ファイルパス、PID
  • 外部接続: 接続先（IP / ポート）、認証方式、接続成功 / 失敗、リトライ回数
  • データ受信: 受信件数のサマリ（毎分・毎時・毎日）、欠損率、レイテンシ
  • 状態遷移: アラート発生 / 復帰、設定変更、しきい値変更
  • 例外: 全例外をスタックトレース付きで残す（無視するなら明示的に書く）
  • 外部呼び出し: API / DB / ファイル I/O のレイテンシ

12. ログの肥大化対策

「毎秒 1 行のログを延々と書く」と、1 ヶ月で数 GB に達します。対策は以下です。

  • サマリ集約: 「1 件ずつログ」ではなく、「1 分ごとに件数とエラー数のサマリ」にまとめる
  • レベル分離: DEBUG は本番では出さない
  • backupCount を厳しく: ローテーション履歴の上限を必ず設定。「14 日分」「30 日分」のような明示
  • ディスク監視: 残り容量を別系統で監視し、危険水準でアラート。閉域網の現場 PC なら、タスクスケジューラ + shutil.disk_usage() で毎時チェックして WARNING を書く数行のスクリプトで十分

13. ログを「見やすくする」工夫

  • ロガー名（%(name)s）を活用: app.modbus, app.alert, app.ui のようにモジュール単位で分け、絞り込みしやすくする
  • 絵文字や色は使わない: 製造現場の文字端末でも問題なく読める形式にする（コンソールログは別途色付けしてもよい）
  • 1 メッセージ 1 イベント: 改行を含めず、1 行 1 メッセージで完結させる。grep / jq / pandas で扱いやすくなる

14. 障害調査の流れ（チェックリスト）

本番でトラブル発生時、現場から「何かログを見てほしい」と言われたとき、私が定番でやる手順です。

  1. app-error.log（ERROR 以上集約）を時系列で確認
  2. 同時刻の app.log（全体）の前後 30 行を確認
  3. 例外スタックトレースの「自分のコード行」を特定
  4. 引数 / 設定値 / 受信値を extra= で残してあれば、その値を確認
  5. サービスログ（NSSM の stderr.log）と Windows イベントログも確認

15. おわりに

ロギングは派手な機能ではありませんが、本番運用に出した瞬間から、エンジニアの仕事を救う最も重要なインフラになります。「エラーが出たら慌ててログを書き足す」のではなく、「最初からログを書いておくと、エラーの正体が即座にわかる」状態を作っておくこと——それが 24 時間運用に耐えるアプリの土台です。

本記事のロギング設計テンプレートは、業務で長期運用してきたアプリから抽出した最小単位です。プロジェクトごとに少しずつ調整しながら使ってください。

関連記事

参考文献・一次情報