LoginSignup
25
13

More than 1 year has passed since last update.

@shinsa82(Shin Saito)

【Python】logging はとりあえず basicConfig() 呼ぶところから初めて、次は YAML で書いて dictConfig() で設定しろ

Last updated at Posted at 2020-12-06

Status

  • lastResort ハンドラの説明に誤りがあります。直します。 → 直した。

概要

詳しくは、後述の対応するセクションを読んでほしい。

  • (A) まず、何も設定しなくても ログレベル WARNING 以上のログが標準エラーに出力される。
  • (B) レベルやフォーマットだけ設定したいなら、トップレベルのスクリプトで logging.basicConfig() を呼び、ルートロガーとハンドラを設定する。
    • ファイルにも出力できる。
    • ログメッセージ全体のフォーマット、そのうち日時のフォーマット、をそれぞれ設定できる。
  • (C) もっと詳しく設定したいなら、設定ファイルに書いてプログラム内で読み込ませる。
    • INI 形式で書いたら fileConfig() でファイルを指定して読み込み & 設定させる。
    • YAML や JSON なら他のモジュールで辞書形式で読み込んだあとに dictConfig() で設定する。
    • プログラムでも設定できるけどおすすめしない。
    • なお、Java みたいに、デフォルトの名前の設定ファイルを自動的に読み込む、ような機能は存在しない。

長くなったので、アーキテクチャについては別の記事で解説する。

環境

  • macOS Big Sur (ver. 11.2.1)
  • Python 3.9.2 (anyenv-pyenv でインストール)

参考文献

サンプルプログラム

サンプルプログラムは以下。このプログラムはモジュールレベルのロギングメソッド logging.info() などを呼んでいる。実際のプログラムを書く場合はこれらを使わず、logging.getLogger(__name__) などとして、自モジュール用のロガーを取得しそのメソッドを呼ぶほうがいい。

exp1.py
from logging import (DEBUG, INFO, basicConfig, critical, debug, error,
                     exception, info, warning)


def show_logs():
    "(possibly) show logs."
    print('-' * 10)
    debug('DEBUG level log')
    print('-' * 10)
    info('INFO level log')
    print('-' * 10)
    warning('WARNING level log')
    print('-' * 10)
    error('ERROR level log')
    print('-' * 10)
    try:
        raise Exception('foo bar.')
    except:
        exception('EXCEPTION level log')
    print('-' * 10)
    critical('CRITICAL level log')
    print('-' * 10)


if __name__ == "__main__":
    # このあと、ここでいろいろ設定を変えてみる
    show_logs()

(A) 何も設定しなくても一応ログは出る

まず、何も設定しなくても ログレベル WARNING 以上のログが標準エラーに出力される。 これで満足なら何もしなくていい。
上の exp1.py を実行するとこうなる:

$ python exp1.py 
----------
----------
----------
WARNING:root:WARNING level log
----------
ERROR:root:ERROR level log
----------
ERROR:root:EXCEPTION level log
Traceback (most recent call last):
  File "/Users/shinsa/git/python-experiments/logging-experiments/exp1.py", line 17, in show_logs
    raise Exception('foo bar.')
Exception: foo bar.
----------
CRITICAL:root:CRITICAL level log
----------

ログが標準エラーに出ていることは python exp1.py > /dev/null もしくは python exp1.py 2> /dev/nullとすればわかる。前者だとログは出るし、後者だと出ない。
なお、exception() はスタックトレースも同時に出力してくれる便利な関数で、例外ハンドラ (= except 節) の中で使うことが想定されている。

ここでは ルートロガー と、それに割り当てられた ハンドラ が出力に用いられており、今回のサンプルプログラムでは自動生成されている。この動作に興味があるなら次のセクションを見てほしい。

ルートロガーハンドラの自動生成

内部動作に興味がないならスキップしてください

logging.info() などモジュールの関数を呼ぶと、ログは ルートロガー 経由で出力される。ログに現れている root が、出力に用いられたロガーの名前である。通常、ロガーに送られたログメッセージはそれに所属する各ハンドラで処理される。

もし、ルートロガーにログが到達したときにルートロガーにハンドラが設定されていない場合には、WARNING 以上を出力する標準エラーへの StreamHandler が自動生成されて、ルートロガーに追加され、そこでログが処理される。

なおルートロガーは

  • logging.getLogger()/logging.getLogger(None) または
  • logging.getLogger('root') (Python 3.9+)

で取得できる:

>>> from logging import getLogger
>>> a = getLogger()
>>> b = getLogger(None)
>>> c = getLogger('root')
>>> a is b
True
>>> b is c
True
>>> a
<RootLogger root (WARNING)>

出力結果から、ロガーが WARNING レベル以上のログのみハンドラに渡すこと、が読み取れる。
ハンドラについても調べてみる。マニュアルには記述がないが、ロガー l のハンドラは l.handlers で取得できる。

>>> import logging
>>> root_logger = logging.getLogger('root')
>>> root_logger
<RootLogger root (WARNING)>
>>> root_logger.handlers
[]
# 続く

この段階ではルートロガーにハンドラは割り当てられていない。次の warning() で出力しようとする際に自動でハンドラが作られる。

# 続き
>>> logging.warning('warn')
WARNING:root:warn
>>> root_logger.handlers
[<StreamHandler <stderr> (NOTSET)>]

warning() によって標準エラーにログが出力された後に調べると、StreamHandler が追加設定されていることがわかる。NOTSET はレベルに関わらず、ハンドラに届いた全てのログを出力するが、ルートロガーが WARNING レベル以上のログしか通さないため、結果として実際に出力されるログはレベルが WARNING 以上のものである。

(B) ルートロガーを basicConfig() で設定する

(A) の方法による出力で満足できない人の大半はおそらく

  • ログレベルを設定したい
  • ログフォーマットを設定したい
  • ファイルに出したい

などがしたいのだと思う。

logging.basicConfig() を呼ぶと ルートロガーとそのハンドラを簡易的に作成・設定 することができる。これで満足なら他にすべきことはない。統一したログ出力を望むなら、このメソッドを呼ぶタイミングはできるだけ早く (＝ 前述のハンドラが自動生成される前)、つまり、誰かが info() などのロギングメソッドを呼ぶ前に行う必要がある。

たとえば、サンプルのトップレベル部分をこうしてみる:

if __name__ == "__main__":
    # ここでいろいろ設定を変えてみる
    basicConfig(
        level=DEBUG, format='{asctime} [{levelname:.4}] {name}: {message}', style='{')
    show_logs()

実行すると以下のように、DEBUG レベルのログが表示され、フォーマットが変化していることもわかる。

$ python exp3.py 
----------
2020-12-06 02:35:04,367 [DEBU] root: DEBUG level log
----------
2020-12-06 02:35:04,367 [INFO] root: INFO level log
----------
2020-12-06 02:35:04,367 [WARN] root: WARNING level log
----------
2020-12-06 02:35:04,367 [ERRO] root: ERROR level log
----------
2020-12-06 02:35:04,367 [ERRO] root: EXCEPTION level log
Traceback (most recent call last):
  File "/Users/shinsa/git/python-experiments/logging-experiments/exp3.py", line 17, in show_logs
    raise Exception('foo bar.')
Exception: foo bar.
----------
2020-12-06 02:35:04,368 [CRIT] root: CRITICAL level log
----------

フォーマットなどの指定

  • ログフォーマットの書式は選べる:
    • デフォルトのログフォーマットは "%(levelname)s:%(name)s:%(message)s" である。これは古い書式 (% 演算子に使用するもの) で書かれている。style='%' を指定した場合は、このフォーマットを使用する。
    • style = '{' とすると、私が書いたようにフォーマット済みリテラル形式 (str.format() 形式) で指定できる。
    • style = '$' を指定すると string.Template.substitute() で指定するものが使える。
  • なお、時刻、たとえば {asctime} がどう表示されるかは別の引数 datefmt で指定する。デフォルトは "%Y-%m-%d %H:%M:%S" で、これに ",<ミリ秒>" が追加されて表示される

ファイルに出力

ファイルに出力したい場合は basicConfig(filename=<ファイル名>, filemode=<モード>) で設定できる。お手軽！

設定の上書き (ver. 3.8+)

Python バージョン 3.8 からは、basicConfig(..., force=True) と指定することにより、ルートロガーに設定されているすべてのハンドラを削除して、この呼出で指定したハンドラが設定される。デフォルトの動作は force=False であり、これはルートロガーに対してこのメソッドによる追加のハンドラを設定する。

(参考) ロガーの取得

logging.getLogger(名前) で適切な Logger を取得し、そのメソッド info() などを呼ぶことによりログ出力を行う。

  • 名前に自モジュール名を指定することが推奨されている: logging.getLogger(__name__)
  • 前述の通り、logging.getLogger() などとすると、ルートロガーが取得できる。
  • モジュールレベル関数 logging.info() などは、ルートロガーのロギングメソッドを呼んでいる。

(C) ファイルによる設定

より細かく制御したい、たとえば、複数の先に出力したい・モジュールによってログレベルを細粒度で変えたい、などの場合には各コンポーネントについて設定する必要がある。ただしプログラム的にやるのはやめたほうがいい。ファイルで設定するのがおすすめである。

  • 設定ファイル経由で行う場合は、プログラム中でどのファイルを読み込むかを明示的に指定する必要がある。 デフォルトの設定ファイルパスとか、ファイルの場所を設定できるデフォルトの環境変数、などは存在しないというのが私の理解である。
    • 設定ファイルのデフォルトフォーマットは INI ファイル形式 (ConfigParser で読み込めるもの)。 ただし、Python の dict でも設定できるので、YAML を読み込んで dict に変換し、それを設定することができる。

INI ファイル形式 (configparser 形式) の場合: fileConfig()

たとえば、先ほどの設定と等価な、このような設定ファイルを用意:

logging.conf
[loggers]
keys = root

[handlers]
keys = consoleHandler

[formatters]
keys = myformatter

[logger_root]
level = DEBUG
handlers = consoleHandler

[handler_consoleHandler]
class = StreamHandler
formatter = myformatter
stream = sys.stderr

[formatter_myformatter]
format = {asctime} [{levelname:.4}] {name}: {message}
style = {

basicConfig() のようなショートカットした設定はできないので、少なくとも Logger、Handler、Formatter を定義する必要がある。

読み込ませるにはこんな感じ:

exp4.py
if __name__ == "__main__":
    # ここでいろいろ設定を変えてみる
    fileConfig(fname='./logging.conf')
    show_logs()

ちゃんと標準エラーに出ているようだ。

$ python exp4.py
----------
2020-12-06 17:34:11,647 [DEBU] root: DEBUG level log
----------
2020-12-06 17:34:11,647 [INFO] root: INFO level log
----------
2020-12-06 17:34:11,647 [WARN] root: WARNING level log
----------
2020-12-06 17:34:11,647 [ERRO] root: ERROR level log
----------
2020-12-06 17:34:11,647 [ERRO] root: EXCEPTION level log
Traceback (most recent call last):
  File "/Users/shinsa/git/python-experiments/logging-experiments/exp4.py", line 18, in show_logs
    raise Exception('foo bar.')
Exception: foo bar.
----------
2020-12-06 17:34:11,647 [CRIT] root: CRITICAL level log
----------

$ python exp4.py 2> /dev/null
----------
----------
----------
----------
----------
----------
----------

YAML や JSON の場合: dictConfig()

YAML の場合は、PyYAML (https://pyyaml.org/) などを使って dict 形式で読み込む。そうすると dictConfig() が使える。

logging.yaml
version: 1

root:
  level: DEBUG
  handlers: [console]

handlers:
  console:
    class: logging.StreamHandler
    stream: ext://sys.stderr
    formatter: myformatter

formatters:
  myformatter:
    format: "{asctime} [{levelname:.4}] {name}: {message}"
    style: "{"

メインプログラムの方はこう書き換えると、正しく動作する。ファイルに日本語が含まれる場合には encoding の指定が必要:

exp5.py
from yaml import safe_load

...

if __name__ == "__main__":
    # ここでいろいろ設定を変えてみる
    with open('./logging.yaml', encoding='utf-8') as f:
        config = safe_load(f)
    dictConfig(config)
    show_logs()

注意するところは、version: 1 が必要であることと、標準エラーの記述方法である。

JSON の場合はビルトインの json.load() があるのでそれを使えばいい。

なお、設定ファイルが書けるようになるためには、おそらくアーキテクチャを少し理解する必要がある。次の記事で説明する。

既存のロガー設定を残す

Thanks to @KAZAMAI_NaruTo.

fileConfig() および dictConfig() は、規定の動作は呼ばれたときに既存の (ルート以外の) ロガーを削除する。これらを残すには disable_existing_loggers=False を指定すればよい。fileConfig() では引数として指定すればよい。

fileConfig(..., disable_existing_loggers=False)

dictConfig() では引数として指定する dict のプロパティとして指定すればよい。

dictConfig({'disable_existing_loggers': False, ...})

(参考) Last-resort ハンドラによるデフォルト動作

ロガーに送られたログメッセージはそれに紐付いた各ハンドラで処理される。
我々が何もしなくてもルートロガーは存在するが、明示的に設定をしない場合ハンドラは設定されない。ただし前述のように、ルートロガーにログが到達したときにハンドラが設定されていないとデフォルトのハンドラが自動生成される。

もし、この自動生成ハンドラを削除するなどして、ルートロガーにハンドラが存在しなくなった場合、予め作られている「最終手段 (= last-resort) ハンドラ」で処理される。

このハンドラは logging.lastResort に格納されているので表示してみる:

>>> import logging
>>> logging.lastResort
<_StderrHandler <stderr> (WARNING)>

出力結果から、標準エラーに出力すること、WARNING レベル以上を出力すること、が読み取れる。

25
13
2

Register as a new user and use Qiita more conveniently

  1. You get articles that match your needs
  2. You can efficiently read back useful information
  3. You can use dark theme
What you can do with signing up
Sign upLogin
25
13