Pythonで簡単にロギングを行うには

提供: tknotebook
2018年3月12日 (月) 03:42時点におけるNakamuri (トーク | 投稿記録)による版

移動: 案内検索

メインページ>コンピュータの部屋#Python>Python Tips

Python は最近山ほど書籍が出ていますが、プログラミングでは必須な ロギング に関する情報がなさすぎなので 簡単にまとめてみました。

最も簡単なやり方

とりあえず

  1. 出力先はコンソールだけ
  2. 適宜出力形式とレベルを変更できるだけでよい

の2条件を満たすだけなら恐ろしく簡単です。

まずメインモジュールの冒頭に以下の import 文を加えます。 

import logging

そしてメインモジュールのモジュールレベルの先頭に

logging.basicConfig(
    level=logging.DEBUG,
    format='%(asctime)s %(levelname)-8s %(module)-18s %(funcName)-10s %(lineno)4s: %(message)s'
)

を置きます。これでお膳立てはおしまいです。

ログを出力するところには以下のように書きます。

 logging.debug("デバッグ")
 logging.info("情報")


出力はコンソールに

2018-01-01 18:09:39,992 DEBUG    main_module        <module>     10: デバッグ
2018-01-01 18:09:39,992 INFO     main_module        <module>     11: 情報

と出力されます。

ログの第一コラムは日付、第2コラムは時刻、第3コラムはログレベル、第4コラムはモジュール名です。

第5コラムは関数名かメソッド名が表示されますが、モジュールレベルでログ出力を呼んだ場合 <module> と出力されます。 第6コラムはモジュール内の行番号、最後がログメッセージです。

メインモジュール以外でロギングを使うときは、先頭に import logging を書き、logging.debug 等でログ出力を書けばOKです。

これだけです。簡単ですよね。

より複雑なロギングを構成する

通常のアプリケーションでは、ロギングにもう少し凝る必要があります。とりあえずこんな要件を考えてみましょう。

  1. ログはコンソールとファイルに出力される。
  2. コンソールには全てのログを出力したい。
  3. ファイルには INFO(情報)以上のレベルのログだけを出力したい。
  4. ログファイルはサイズを 1MB までとし、バックアップファイル3個(つまり合計4個)でローテーションしたい。

これを実現するには3種類のやり方がありますが、その前に、python のロギングの仕組みを簡単に紹介しておきましょう。

Pythonのロギングの仕組み

Pythonのロギングの仕組みは log4net や log4j とあまり変わりません。

ロガー

Pythonのロギング では 「ロガー」 と呼ばれるオブジェクトの debug とか info 関数を呼ぶことでロギングを行います。 ロガーはそれに割りつけられた「ハンドラ」を使ってファイルやコンソールにログを送ります。ハンドラは log4j のappender ですね。

ルートロガー

ロガーの中には 「ルートロガー」 と呼ばれるロガーがあり、ログ出力を行おうとするときに無いと自動的に作られます。 但し、自動的に作られる「ルートロガー」は、ハンドラがコンソールに出力するハンドラのみ、 ログレベルがWARNING(警告) 以上のログしか出力せず、書式もとてつもなく貧弱なので使いずらいです。

最初に紹介した

logging.basicConfig(
    level=logging.DEBUG,
    format='%(asctime)s %(levelname)-8s %(module)-18s %(funcName)-10s %(lineno)4s: %(message)s'
)

強制的にルートロガーを作り、指定したログレベルで指定した書式で、コンソールへログを送るルートロガーを作ります。

この関数だけでもより複雑なロガ一の構成は可能ですが、それならば後述するもっと素直なやり方の方が良いでしょう

因に、logging.info や logging.debug はルートロガーへログを送ります。

ルートロガー以外のロガーの作り方

logger = logging.getLogger(<<ロガーの名前>>)

は新しい名前の付いたロガーを作ります。

 logger.debug("デバッグ")

というようにロガーのメソッドを呼べばこのロガーにログを送れます。

既に存在するロガーと同名の名前で getLogger を呼ぶと、既に存在するロガーの参照が返るので、同じ名前のロガーは1個しか作れません。

多くの場合、ロガーの名前はログを出力するモジュール名にすることが多いようです。

logging.getLogger で作られたロガーは、ハンドラーを持たず、何も出力できませんが、既定でログをルートロガーに転送します。

Python ロギングの仕組み.png

ここで以後説明するロガーの構成では、このロガーが既定で ログをルートロガーに転送する機能を利用します。 つまり、ハンドラやフォーマッタは全てルートロガーに設定し、 名前付きロガーから転送されてくるログ情報をルートロガーでコンソールやファイルへ出力する方式とします。

ロガーを構成する3つの方法

ロガーを構成するには3つの方法があります。

  1. pythonのコードで直接ロガーを生成編集する
  2. logging.config.dictConfig で 辞書(ハッシュ)型のデータを読み、ロガーを構成する。
  3. logging.config.fileConfig で iniファイル形式の構成ファイルを読み込んでロガーを構成する。

実は、やってみるとわかりますが、どの方法でやってもあまり変わりません。1. のやり方が最も簡潔です。

pythonはソースコードをコンパイルなしに変更して即座に実行できるので ロガーを構成する pythonコードの入ったファイルをそのまま構成ファイルとすることができます。Java の log4j の構成ファイル log4j.xml のように、 わざわざロガー専用の構成ファイルを作る必要性は薄いです。強いて言えば、2, 3 のやり方は pythonを知らない人でも変更がある程度可能なことが利点と言えるでしょう。

pythonのコードで直接ロガーを生成編集する

名前は何でもよいのですが、ロガー構成用のファイルは別モジュールとして分離したほうが良いので、それを logging_config.py としましょう。 中身はこんな感じになります。

import sys
import logging
import logging.handlers
import logging.config

#ルートロガーの作成。ログレベル=デバッグ
_root_logger = logging.getLogger('')
_root_logger.setLevel(logging.DEBUG)

#フォーマッターの作成(時刻、ログレベル、モジュール名、関数名、行番号: メッセージ を出力)
_simpleFormatter = logging.Formatter(
    fmt='%(asctime)s %(levelname)-8s %(module)-18s %(funcName)-10s %(lineno)4s: %(message)s'
)

#コンソール用ハンドラの作成。標準出力へ出力。ログレベル=デバッグ。書式は上記フォーマッター
_consoleHandler = logging.StreamHandler(sys.stdout)
_consoleHandler.setLevel(logging.DEBUG)
_consoleHandler.setFormatter(_simpleFormatter)

#コンソール用ハンドラをルートロガーに追加
_root_logger.addHandler(_consoleHandler)

#ファイル用ハンドラの作成。ファイル名は logging.log, ログレベル=INFO, ファイルサイズ 1MB, バックアップファイル3個まで、エンコーディングは utf-8
_fileHandler = logging.handlers.RotatingFileHandler(
    filename='logging.log', maxBytes=1000000, backupCount=3, encoding='utf-8'
)
_fileHandler.setLevel(logging.INFO)
_fileHandler.setFormatter(_simpleFormatter)

#ファイル用ハンドラをルートロガーに追加
_root_logger.addHandler(_fileHandler)

処理内容はコメントに書いた通りです。詳細を知りたい方は後述する参考文献を見てください。

使い方は簡単です。

メインモジュールでは

冒頭に

import logging_config
import logging

#モジュール名でロガーを生成する(メインモジュールは 名前が '__main__' になる)
log = logging.getLogger(__name__)

を置き、ログを出力したいとろこで

log.debug('デバッグ')

log.info('情報')

などと書きます。

メインモジュール以外では

import logging
log = logging.getLogger(__name__)

を頭に置き、ログを出力したいとろこで

log.debug('デバッグ')

log.info('情報')

などと書きます。

ログ出力は、 logging.debug("デバッグ") というように、ルートロガーに直接ログを送ってもよいのですが、 後でより複雑なロガーを構成する場合に備えて、モジュールごとに別にロガーを作っておいたほうが無難です。

logging.config.dictConfig で 辞書(ハッシュ)型のデータを読み、ロガーを構成する

今度は logging.config.dictConfig を使ってロガーを構成します。

logging_config.py の中身はこうなります。

import logging.config

_config = {
    'version': 1,
    'disable_existing_loggers': False,
    'formatters': {
        'simpleFormatter': {
            'format': '%(asctime)s %(levelname)-8s %(module)-18s %(funcName)-10s %(lineno)4s: %(message)s'
        }
    },
    'handlers': {
        'consoleHandler': {
            'level': 'DEBUG',
            'formatter': 'simpleFormatter',
            'class': 'logging.StreamHandler',
        },
        'fileHandler': {
            'level': 'INFO',
            'formatter': 'simpleFormatter',
            'class': 'logging.handlers.RotatingFileHandler',
            'filename': 'logging.log',
            'maxBytes': 1000000,
            'backupCount': 3,
            'encoding': 'utf-8',
        }
    },
    'loggers': {
        '': {
            'handlers': ['consoleHandler', 'fileHandler'],
            'level': "DEBUG",
        }
    }
}

logging.config.dictConfig(_config)

このやりかたでは、辞書型のデータを作成し、logging.config.dictConfig に喰わせてロガーを設定します。

設定内容は pythonのコードで直接ロガーを生成編集する と同じなので、見ていただければ わかるでしょう。

この例では辞書型のデータは python のリテラルで記述しましたが、外部ファイルに JSON や YAML で書き、 それを読み込んで生成してかまいません。PyYAML で YAML ファイルを読むのが最も簡潔になると思います。 使い方(メインモジュールやメインモジュール以外での import, ログ出力のやり方)は pythonのコードで直接ロガーを生成編集する と同じです。

logging.config.fileConfig で iniファイル形式の構成ファイルを読み込んでロガーを構成する

最後の方法は ini ファイルから構成情報を読み取り、ロガーを構成する方法です。この場合、iniファイル形式の構成ファイルを別途用意して使います。

iniファイル形式の構成ファイル logger.config はこうなります。

[loggers]
keys=root

[handlers]
keys=consoleHandler,fileHandler

[formatters]
keys=simpleFormatter

[logger_root]
level=DEBUG
handlers=consoleHandler,fileHandler

[handler_consoleHandler]
class=StreamHandler
level=DEBUG
formatter=simpleFormatter
args=(sys.stdout,)

[handler_fileHandler]
class=logging.handlers.RotatingFileHandler
level=INFO
formatter=simpleFormatter
args=("logging.log", "a", 1000000, 3, "utf-8")


[formatter_simpleFormatter]
format=%(asctime)s %(levelname)-8s %(module)-18s %(funcName)-10s %(lineno)4s: %(message)s


構成情報を別ファイルにしたので logging_config.py は小さくなって こうなります。

import logging.config

logging.config.fileConfig(fname="logging.config")


設定内容は pythonのコードで直接ロガーを生成編集する と同じ、メインモジュールやメイン以外のモジュールの書き方も 他のやり方と同じです。

注意点が一つ。iniファイル形式では、ハンドラを生成するために ハンドラのコンストラクタに渡すパラメータを args に書きますが tuple 形式で書くため、キーワード指定のパラメータが書けません。位置指定でパラメータを順番に並べて渡す必要があります。ダサいです。

最後に

以上、とても簡単ではありますが、pythonの口ギングの使い方を説明しました。

取りあえず紹介した3つの方法のどれかを丸写しすれば動くので ご活用下さい。

参考文献

Logging HOWTO
ロギングの基本的なチュートリアルです。
Logging クックブック
より高度なロギングの構成方法です。
16.7. logging.config — ロギングの環境設定
logging.config.fileConfig, logging.config.dictConfig の使い方が載っています。 環境設定辞書スキーマ(辞書型のロガー構成情報)や環境設定ファイルの書式(iniファイル形式のロガー構成情報)が載っているのもここです。
16.6. logging — Python 用ロギング機能
loggingモジュールの使い方です。