logging — print の代わりに記録する

loggingはアプリの動きを段階的に記録するための標準モジュールです。printでデバッグ出力を書くと、本番では消したいのに消し忘れる、重要度の区別が付かない、ファイルにも出したくなるけど書き換えが大変といった問題が出ます。loggingを使うと、重要度（DEBUG / INFO / WARNING / ERROR / CRITICAL）で出力を絞れて、Formatterで書式を統一でき、Handlerで出力先（標準出力 / ファイル / リモート）を切り替えられます。

ログレベル — 5 段階の重要度

logging は5 段階のレベルを持ち、Logger に設定したレベル以上のメッセージだけが出力されます。開発中はDEBUG、本番はINFOやWARNINGに設定する運用が一般的で、コード側を変えずに設定 1 箇所で出力量を切り替えられるのがprintとの最大の違いです。

まず basicConfig で書式とレベルを整え、INFO のログを 1 件出します。

① logging を読み込み、basicConfigをlevel=logging.INFO、format="[%(levelname)s] %(message)s"、force=Trueで設定してください

② logger = logging.getLogger("app")でロガーを取得してください

③ logger.info("アプリ起動")で 1 件出力してください

（正しく実行できれば解説が表示されます）

WARNING / ERROR / DEBUG のレベル使い分け

ロガーが設定済みの状態で、INFO 以外のレベルを呼び分けて出力を観察します。設定レベルが INFO なので、DEBUG は何も出力されないことも合わせて確認します。これが logging の「設定 1 箇所で出力量を切り替えられる」仕組みの基礎です。

実践 1 のロガー設定をそのまま使い、3 種類のレベルで出力します。INFO 設定なので DEBUG は表示されないことに注意。

① logger.warning("設定ファイルが古い")で WARNING を出力してください

② logger.error("DB 接続失敗")で ERROR を出力してください

③ logger.debug("詳細トレース")を呼んでください — INFO レベル設定下では何も表示されないはずです

ファイルへログを出力する

実プロジェクトでは、ログを画面に出すだけでなくファイルに残しておきたい場面が大半です。後からgrepで原因調査をしたり、運用監視ツールに取り込んだりするためです。basicConfigにfilename="app.log"を渡せば、ルートロガーの出力先がファイルに切り替わります — printで同じことをするにはすべてのprintを書き換える必要があるのに対し、loggingなら設定 1 箇所で出力先を変えられます。

filemodeは"a"(既定、追記)か"w"(上書き)を指定します。本番運用では追記にして履歴を残しますが、開発中は上書きで毎回まっさらから始めるほうが調査しやすいことが多いです。画面とファイルの両方に出したい場合は、basicConfigではなく後述のStreamHandler + FileHandlerを併用する形になります。

import logging
import os

# 親フォルダを先に作っておく (FileHandler は自動で作らない)
os.makedirs("logs", exist_ok=True)

# basicConfig に filename を渡すと、出力先がファイルに切り替わる
logging.basicConfig(
    level=logging.INFO,
    format="[%(levelname)s] %(message)s",
    filename="logs/app.log",   # ファイル出力
    filemode="w",               # "a" (追記) or "w" (上書き)
    force=True,
)
logger = logging.getLogger("app")

logger.info("起動しました")
logger.warning("設定が古い")
logger.error("DB 接続失敗")

# ファイルから読み出して内容を確認
with open("logs/app.log") as f:
    print(f.read(), end="")

basicConfigにfilenameを渡してログをファイル出力に切り替え、書き出した内容をファイルから読み返します。

① os.makedirs("logs", exist_ok=True)で親フォルダを先に作ってください (FileHandlerは親フォルダを自動で作らないため)

② logging を読み込み、basicConfigを以下の設定で呼んでください — level=logging.INFO、format="[%(levelname)s] %(message)s"、filename="logs/app.log"、filemode="w"、force=True

③ logger = logging.getLogger("app")でロガーを取得してください

④ INFO / WARNING / ERROR で 3 件のログを出してください — 順に"起動しました"、"設定が古い"、"DB 接続失敗"

⑤ open("logs/app.log")でファイルを読み、--- logs/app.log の中身 ---という見出しの後に内容を末尾改行を付けずに表示してください (print(content, end=""))

ハンドラを別ファイルで定義する

アプリが大きくなると、ロガーの設定（書式、レベル、出力先）を専用のモジュールに切り出して、各モジュールからimportして使う構成にします。ロガー設定の重複を避け、書式や出力先を 1 箇所で変更できるようになります。StreamHandlerを直接組み立て、Formatterを割り当てて、logger.addHandler(...)で登録する手動構成のパターンを別ファイルに置く形です。

# log_setup.py — ロガー設定を切り出した専用モジュール
import logging

def setup_logger(name):
    logger = logging.getLogger(name)
    logger.setLevel(logging.INFO)

    if not logger.handlers:                       # 重複登録を防ぐ
        handler = logging.StreamHandler()
        handler.setFormatter(
            logging.Formatter("[%(name)s] [%(levelname)s] %(message)s")
        )
        logger.addHandler(handler)
        logger.propagate = False                  # ルートに伝播させない
    return logger

# main.py — log_setup を import して使う側
from log_setup import setup_logger

logger = setup_logger("orders")
logger.info("注文を受け付けました")

事前にlog_setup.pyが用意してあります(コンソール左の📂ファイルから中身を確認できます)。main.py側でsetup_loggerを import して、ロガー名"orders"で 3 件のログを出します。

① from log_setup import setup_loggerで関数を読み込んでください

② logger = setup_logger("orders")でロガーを取得してください

③ INFO / WARNING / ERROR で 3 件のログを出してください — 順に"注文を受け付けました"、"在庫が残り少ない"、"決済 API がエラーを返した"

より詳細な書式 — 時刻・モジュール名・行番号

Formatterの書式文字列には%(...)s形式の置換コードを並べることで、運用に必要な情報を 1 行に集約できます。よく使う 6 つの置換コードと出力例を表にまとめます。ロガー名はparent.child.grandchildのようなドット区切りで階層化でき、getLogger(__name__)を各モジュールで呼ぶだけで「どのモジュールから出たログか」が自動で記録されます。

import logging

# 本番運用向けの詳細書式
logging.basicConfig(
    level=logging.INFO,
    format="%(asctime)s [%(name)s] [%(levelname)s] %(funcName)s:%(lineno)d - %(message)s",
    datefmt="%Y-%m-%d %H:%M:%S",
    force=True,
)

logger = logging.getLogger("app.orders")

def process_order(order_id):
    logger.info(f"注文 {order_id} を処理")

process_order(1234)
# 出力例:
# 2024-12-01 10:30:45 [app.orders] [INFO] process_order:13 - 注文 1234 を処理

app / app.orders / app.orders.paymentの 3 段階の階層ロガー名で出力し、%(name)sでどのモジュールから出たかを表示します。本番では%(asctime)sを加えて時刻も入れますが、ここでは出力が変わらないよう階層名のみで動作を観察します。

① logging を読み込み、basicConfigをlevel=logging.INFO、format="[%(name)s] [%(levelname)s] %(message)s"、force=Trueで設定してください

② 3 つのロガーを取得してください — logging.getLogger("app")、logging.getLogger("app.orders")、logging.getLogger("app.orders.payment")

③ それぞれで 1 件ずつ出力してください — appでinfo("アプリ起動")、app.ordersでinfo("注文を受け付け")、app.orders.paymentでerror("決済 API がエラー")

yaml で設定を切り出す

ロガー設定が複雑になってくると、Python コードの中に書式・ハンドラ・レベルをハードコードする代わりにyamlの設定ファイルに切り出す形にします。logging.config.dictConfig(...)はdict形式の設定を受け取るので、yaml をパースして渡すだけでロガー全体を構成できます。コードを変えずに本番・ステージング・開発で別の設定ファイルを読み込ませる、といった運用が一気にしやすくなります。

# logging.yml — ロガー設定の単一ソース
version: 1
disable_existing_loggers: false
formatters:
  default:
    format: "[%(name)s] [%(levelname)s] %(message)s"
handlers:
  console:
    class: logging.StreamHandler
    formatter: default
    level: INFO
loggers:
  app:
    level: INFO
    handlers: [console]
    propagate: false

事前にlogging.ymlが用意してあります (コンソール左の📂ファイルから中身を確認できます)。yaml.safe_loadで dict に変換し、logging.config.dictConfigに渡してロガーを構成します。

① logging、logging.config、yamlを読み込んでください

② with open("logging.yml") as f:で開き、yaml.safe_load(f)で dict に変換してください

③ その dict をlogging.config.dictConfig(...)に渡して設定を適用してください

④ logger = logging.getLogger("app")でロガーを取得し、INFO と WARNING で 1 件ずつ出力してください — 順に"yaml 設定で起動"と"yaml 経由の WARNING"

ログのローテーション

ログを書き続けるとファイルが無限に肥大化するため、本番運用では古いファイルを別名にして削除する ローテーションが必須です。logging.handlersにはサイズベースと時刻ベースの 2 種類があり、用途に応じて使い分けます。

RotatingFileHandler — サイズベース

RotatingFileHandler(filename, maxBytes, backupCount)はmaxBytesを超えそうになると新しいファイルに切り替える Handler です。古いファイルはapp.log.1 / app.log.2の連番でリネームされ、backupCountを超えると最古から削除されます。maxBytes=10_000_000(10 MB) + backupCount=5なら最大 60 MB を上限にログが回り続けます。

import logging
from logging.handlers import RotatingFileHandler

# サイズベース: maxBytes 超過でローテーション
size_handler = RotatingFileHandler(
    "app.log",
    maxBytes=10_000_000,   # 10 MB を超えそうになると切り替え
    backupCount=5,         # app.log.1 〜 app.log.5 を保持 (合計最大 60MB)
)
size_handler.setFormatter(logging.Formatter("[%(levelname)s] %(message)s"))

事前にrotate_logging.ymlが用意してあります (コンソール左の📂ファイルから中身を確認できます)。maxBytes=60 / backupCount=2のRotatingFileHandler設定をyaml 側で書いておき、コードでは yaml を読み込んで使うだけにします。

① os / shutilを読み込み、rotate/フォルダを削除して作り直してください。あわせて、ロガーrotate_demoの既存ハンドラを close + removeHandlerで全消去してください (再実行時の干渉を防ぎます)

② with open("rotate_logging.yml")で yaml を開き、yaml.safe_load(f)で dict に変換、logging.config.dictConfig(...)に渡してハンドラを構成してください

③ logger = logging.getLogger("rotate_demo")でロガーを取得し、for i in range(15):のループでlogger.info(f"event {i:02d}")を 15 回出してください

④ os.listdir("rotate")からapp.logで始まるファイルだけを取り出してソートし、ローテーション後のファイル数: ◯の見出しの後にファイル名を- ファイル名の形で 1 行ずつ表示してください

TimedRotatingFileHandler — 時刻ベース

TimedRotatingFileHandler(filename, when, interval, backupCount)はwhenで指定した時刻の節目でローテーションする Handler です。when="midnight"(毎日 0 時)、"H"(時)、"M"(分)、"S"(秒)、"D"(日) など。バックアップはapp.log.2024-12-01_00-00-00のようにタイムスタンプ付きで、ファイル名から「いつのログか」が直接読み取れます。

import logging
from logging.handlers import TimedRotatingFileHandler

# 時刻ベース: 毎日 0 時にローテーション
day_handler = TimedRotatingFileHandler(
    "app.log",
    when="midnight",   # "S" 秒 / "M" 分 / "H" 時 / "D" 日 / "midnight" など
    interval=1,         # 何単位ごとか (when="H", interval=6 なら 6 時間ごと)
    backupCount=30,     # 過去 30 日分を保持
)
day_handler.setFormatter(
    logging.Formatter("%(asctime)s [%(levelname)s] %(message)s")
)

事前にtime_logging.ymlが用意してあります。when: S(秒単位)/ interval: 1 / backupCount: 3のTimedRotatingFileHandler設定を yaml 側で書いておき、Python コードではtime.sleepで時間の流れをシミュレートしてローテーションを発火させます。

① logging / os / shutil / timeを読み込み、ロガーtrotate_demoの既存ハンドラを close + removeHandlerで全消去してからtrotate/フォルダを削除して作り直してください

② with open("time_logging.yml")で yaml を開き、yaml.safe_load(f)で dict に変換、logging.config.dictConfig(...)に渡してハンドラを構成してください

③ ロガーを取得し、logger.info(...) → time.sleep(1.2) → logger.info(...) → time.sleep(1.2) → logger.info(...)の順で 3 件のログを出して2 回のローテーションを発生させてください

④ os.listdir("trotate")の中身からapp.log(現在のログ)とそれ以外(タイムスタンプ付きバックアップ)を分け、現在のログあり: True/Falseとバックアップ数: ◯を表示してください