Masayan tech blog.

  1. ブログ記事一覧>
  2. Pythonのロギング実践ガイド

Pythonのロギング実践ガイド

公開日

目次

この記事を読むことで得られるメリット

  • Pythonのロギングシステムの基本から応用までを体系的に学べる
  • 共通の落とし穴を避け、ベストプラクティスに従ったコードが書けるようになる
  • プロジェクトで再利用可能なロギング設定の方法を習得できる
  • デバッグ効率が向上し、問題発見・解決が容易になる
  • 本番環境でのログ管理が適切に行えるようになる

この記事を読むのにかかる時間

約15分

Pythonロギングの基本概念

Pythonのロギングシステムは階層構造を持っており、大きく分けて「ルートロガー」と「名前付きロガー」の2種類がある。

ロギングシステムの階層構造は、Pythonのパッケージ・モジュール構造を反映しており、最も上位に位置するのがルートロガーだ。この階層構造を理解することで、効果的なロギング設計が可能になる。

# ロギングの基本的な階層構造
root (ルートロガー)
├── app
│   ├── app.models
│   └── app.views
└── lib
    └── lib.utils

ロガーオブジェクトの正しい使い方

loggingを直接importして使用しない

ロギングを実装する際の最も重要なポイントは、ルートロガーを直接変更しないことだ。

NG例：

import logging
logging.debug('this is bad logging')  # ルートロガーを直接使用している

この方法ではルートロガーを直接変更することになり、グローバル変数を直接書き換えるのと同様の問題が発生する。例えば、ログレベルを変更すると、他のモジュールのロギング動作にも影響を与えてしまう。

OK例：

from logging import getLogger
logger = getLogger(__name__)  # 現在のモジュール名でロガーを取得
logger.debug('this is good logging')

この方法では、現在のモジュール専用のロガーを取得するため、他のモジュールに影響を与えず、階層構造も適切に維持できる。

現在のモジュール名を使用してロガーオブジェクトを取得する

__name__を使用することで、ログメッセージにどのモジュールから生成されたかを明示できる。これにより問題発生時の原因特定が容易になる。

ログレベルの理解と活用

Pythonのロギングシステムには5つの標準ログレベルがある：

  1. DEBUG - 詳細なデバッグ情報
  2. INFO - 一般的な情報メッセージ
  3. WARNING - 警告（潜在的な問題）
  4. ERROR - エラー（機能が動作しない）
  5. CRITICAL - 重大なエラー（プログラムが動作しない可能性）

ログレベルを適切に設定することで、出力されるログの量と種類を制御できる：

from logging import getLogger, INFO

logger = getLogger(__name__)
logger.setLevel(INFO)  # INFO以上のログレベルのみ出力

logger.debug('debug')  # 表示されない
logger.info('info')    # 表示される
logger.warning('warning')  # 表示される
logger.error('error')  # 表示される
logger.critical('critical')  # 表示される

各ログレベルの詳細な使用シーンについては、Python公式ドキュメントを参照するとよい。

ハンドラーの設定と活用法

ログを実際に出力するためには、ハンドラーの設定が必要だ。主に使用される2種類のハンドラーについて説明する：

  1. StreamHandler - コンソールにログを出力
  2. FileHandler - ファイルにログを出力
from logging import getLogger, StreamHandler, FileHandler, Formatter, INFO, ERROR

logger = getLogger(__name__)
logger.setLevel(INFO)

# StreamHandlerの設定
ch = StreamHandler()
ch.setLevel(INFO)
ch_formatter = Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
ch.setFormatter(ch_formatter)
logger.addHandler(ch)

# FileHandlerの設定
fh = FileHandler('log/test.log')
fh.setLevel(ERROR)  # ERRORとCRITICALのみファイルに記録
fh_formatter = Formatter('%(asctime)s - %(levelname)s - %(filename)s - %(name)s - %(funcName)s - %(message)s')
fh.setFormatter(fh_formatter)
logger.addHandler(fh)

ロガーとハンドラーのログレベル関係

ロガーとハンドラーのログレベルは独立しており、それぞれが独自のフィルタリングを行う。ただし、重要なポイントとして：

  • ロガーは設定されたレベル未満のメッセージをフィルタリングするため、ロガーのレベルがハンドラーのレベルより高い場合、ハンドラーに低レベルのメッセージは届かない
  • 各ハンドラーは独自のログレベルとフォーマットを持つことができる

フォーマッターによるログの整形

フォーマッターを使用すると、ログメッセージに時刻、モジュール名、ログレベルなどの情報を追加できる：

from logging import getLogger, StreamHandler, Formatter

logger = getLogger(__name__)
handler = StreamHandler()
format = Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
handler.setFormatter(format)
logger.addHandler(handler)

logger.info('this is formatted log')

一般的なフォーマット指定子には以下のものがある：

  • %(asctime)s - 日時
  • %(name)s - ロガー名
  • %(levelname)s - ログレベル名
  • %(message)s - ログメッセージ
  • %(filename)s - ファイル名
  • %(funcName)s - 関数名
  • %(lineno)d - 行番号

設定ファイルを使ったロギング設定

大規模なアプリケーションでは、設定ファイルを使用してロギングの設定を管理すると便利だ。Pythonでは、主に以下の方法がある：

  1. fileConfig - INIファイルから設定を読み込む
  2. dictConfig - 辞書から設定を読み込む

fileConfig（INIファイル）

from logging import getLogger
import logging.config

logging.config.fileConfig('logging_settings.ini')
logger = getLogger('root')

logger.info('this is fileConfig from logging_settings.ini')

logging_settings.iniの内容：

[loggers]
keys=root

[handlers]
keys=newStreamhandler

[formatters]
keys=newFormatter

[logger_root]
level=INFO
handlers=newStreamhandler

[handler_newStreamhandler]
class=StreamHandler
level=DEBUG
formatter=newFormatter
args=(sys.stderr,)

[formatter_newFormatter]
format=%(asctime)s - %(name)s - %(levelname)s - %(message)s

dictConfig（辞書）

from logging import getLogger, DEBUG, INFO
import logging.config

dict_logging_settings = {
    'version': 1,
    'handlers': {
        'newStreamHandler': {
            'class': 'logging.StreamHandler',
            'formatter': 'newFormatter',
            'level': DEBUG
        }
    },
    'formatters': {
        'newFormatter': {
            'format': '%(asctime)s - %(name)s - %(levelname)s - %(message)s'
        },
    },
    'root': {
        'handlers': ['newStreamHandler'],
        'level': INFO
    },
    'loggers': {}
}

logging.config.dictConfig(dict_logging_settings)
logger = getLogger('root')

logger.info('this is dictConfig from dict_logging_settings')

Python公式ドキュメントではJSON/YAMLを使用した設定が推奨されている。INIファイルは読み書きが複雑になる傾向があるためだ。JSONはPython標準ライブラリで読み込めるが、YAMLは外部ライブラリが必要となる。

注意点として、設定ファイルのパラメータであるdisable_existing_loggersの取り扱いに注意が必要だ。

print文ではなくloggerを使うべき理由

1. 情報量が多い

printはシンプルでデバッグ時に便利だが、本番環境のコードではloggingモジュールを使用すべきだ。ロギングでは各メッセージに時刻やログレベルなど多くのメタデータを含められる。

2. ログレベルを指定できる

ロギングでは、メッセージの重要度に応じたログレベルを明示的に指定できる。これにより、どのようなメッセージなのかがすぐに判断できるのだ。

3. 出力先の指定が豊富

printはコンソールにしか出力できないが、ロギングはファイル、コンソール、メールなど様々な出力先に対応している。

4. トレースバックを簡単に含められる

例外発生時にトレースバックを記録する場合：

try:
    open('/path/to/does/not/exist', 'rb')
except (SystemExit, KeyboardInterrupt):
    raise
except Exception:
    logger.error('Failed to open file', exc_info=True)  # トレースバック情報が自動的に含まれる

実践的なロギングパターン

大規模なアプリケーションでは、以下のようなベストプラクティスを考慮すべきだ：

  1. アプリケーション起動時にロギング設定を行う
  2. 異なる環境（開発、テスト、本番）で異なるロギング設定を使用する
  3. 重要な操作やエラーは適切なログレベルで記録する
  4. ログローテーションを設定して、ログファイルのサイズ管理を行う