Pythonのロギングについてお勉強したメモ

2014年9月1日 Log Python

今までロギングをほとんど使ったことがなかったので、勉強を兼ねてまとめておきます。

基本的な使い方

>>> import logging
>>> logging.log(100, 'test')
Level 100:root:test
 
# [ばっど] 書式文字列はその場で組み立てずに
>>> logging.warn('test %s,%s' % (1, 2))
WARNING:root:test 1,2
 
# [ぐっど] 引数として渡す
>>> logging.warn('test %s,%s', 1, 2)
WARNING:root:test 1,2
 
# 文字列以外が渡されると文字列に変換される
>>> logging.warn({'a': 1})
WARNING:root:{'a': 1}

書式文字列をその場で組み立てないほうがよい理由は、後述するハンドラやフィルタによってそれぞれの引数を参照することができるからです。
また、出力関数は引数に文字列以外が渡されると文字列に変換されて出力されるようですが、辞書やリストがJSON出力されるという期待はしないほうがよいでしょう(引用符がシングルクォートだったりするので)。

ロガー

おそらくあまり正確ではありませんがロガーはログの出力名を管理します。ツリー構造をもつことができ、出力時には「親.子.孫」のように”.”区切りで表現されます。ツリーの頂点は「root」と表現されます。

>>> import logging
 
# ロガーを取得する
>>> logger = logging.getLogger('aaa')
 
# ロガーでの出力
>>> logger.warn('test')
WARNING:aaa:test
 
# loggerの継承(子ロガーを作る)
>>> logger2 = logger.getChild('bbb')
>>> logger2.warn('test')
WARNING:aaa.bbb:test2
 
# ロガー名が同じだとオブジェクトも同じ
>>> logger3 = logging.getLogger('aaa.bbb')
>>> logger3 is logger2
True
 
# 親ロガーを参照
>>> logger2.parent is logger
True
 
# ロガー名を指定しないとルートロガー
>>> logger0 = logging.getLogger('')
>>> logger0
<logging.RootLogger at 0x7f0fbdea5210>
 
# 頂点はルートロガー 
>>> logger.parent is logger0
True
 
# 「root」という名前で作成したロガーはルートロガーとは別物
>>> logger4 = logging.getLogger('root')
>>> logger4 is logger0
False
 
# 名前は同じだけど
>>> logger4.name == logger0.name
True
 
# 継承すると別物だとわかる
>>> logger42 = logger4.getChild('inherit')
>>> logger02 = logger0.getChild('inherit')
>>> logger42.name, logger02.name
('root.inherit', 'inherit')
 
# 文字の種類と継承の深さに制限はなさそう
>>> logger_special = logging.getLogger('.'.join('!"#$%&\'()-=^~|\\@`[{;+:*]},<.>/?_'))
>>> logger_special.warn('test')
WARNING:!.".#.$.%.&.'.(.).-.=.^.~.|.\.@.`.[.{.;.+.:.*.].}.,.<...>./.?._:test

ログレベル

ログレベルは主に出力の足切りに使われます。レベルがしきい値(数値)未満のログは出力されません。また以下のログレベルにはエイリアスが与えられています。

ログレベル	エイリアス	用途
0	NOTSET	すべての記録
10	DEBUG	デバッグ用の記録
20	INFO	正常動作の記録
30	WARNING, WARN	不正動作の記録
40	ERROR	エラーの記録
50	CRITICAL, FATAL	緊急的なやばいやつ

>>> import logging
>>> logger = logging.getLogger('aaa')
 
# しきい値未満のログは出力されない
>>> logger.setLevel(logging.INFO)
>>> logger.debug('test')
>>> logger.info('test')
INFO:leveltest:test
 
# ログレベルは数値でも指定できる。
>>> logger.log(21, 'test')
Level 21:leveltest:test
 
# 数値と同じエイリアスが存在する場合は、エイリアスが出力される
>>> logger.log(20, 'test')
INFO:leveltest:test

ハンドラ

ハンドラによって発生したログの出力先を操作することができます。

>>> import logging
>>> logger = logging.getLogger('handletest')
 
# 最初は何も設定されていない
>>> logger.handlers
[]
 
# test.logというファイルにログを出力するためのハンドラを追加する
>>> fh = logging.FileHandler('test.log', 'a+')
>>> logger.addHandler(fh)
>>> logger.handlers
[<logging.FileHandler at 0x7fdc2a2ad450>]
>>> logger.warn('test')
WARNING:handlertest:test
>>> logger.error('test2')
ERROR:handlertest:test2
# test.logにも出力される
>>> open('test.log').read()
'test\ntest2\n'
# ハンドラを削除する
>>> logger.handlers.removeHandler(fh)
>>> logger.critical('test3')
CRITICAL:handlertest:test3
>>> open('test.log').read()
'test\ntest2\n'

コンソールに出力するためのStreamHandlerというハンドラもあります。上記の例のようにハンドラを指定しなくてもコンソールへの出力がされたので指定するのは無駄かと思っていましたが、どうやら違うみたいです。ハンドラを指定しなくてもコンソールへの出力が行われるのはインタラクティブモード時のみのようで、モジュールとして実行すると「No handlers could be found for logger handlertest”」と言われます。(この辺り挙動がおかしかったので自信ない)

モジュールからコンソールに出力したい場合は以下のようにStreamHandlerを追加します。

#!/usr/bin/env python
import logging
 
logger = logging.getLogger('handlertest')
logger.setLevel(10)
 
sh = logging.StreamHandler()
logger.addHandler(sh)
logger.debug('test')

他にもSMTPやSyslogへの出力ハンドラなどが標準で用意されています。詳しくはこちらを参照してください。

フォーマッタ

デフォルトのままではメッセージしか出力されません。でも場合によってはロガー名や出力時間も表示したいことがあります。そんなときはフォーマッタを指定することで解決できます。

>>> import logging
>>> formatter = logging.Formatter('[%(name)s] %(message)s')
>>> sh = logging.StreamHandler()
# フォーマッタはハンドラに設定する
>>> sh.setFormatter(formatter)
>>> logger = logging.getLogger('formattest')
>>> logger.addHandler(sh)
>>> logger.setLevel(10)
>>> logger.debug('test')
[formattest] test

フォーマッタで使える属性はこちらを参照してください。

フィルタ

通常ログ出力の可否はログレベルによって決められますが、それ以外の条件によって判断したい場合もあります。フィルタを使うとログレコード等をもとに出力可否を判断することができます。

>>> import logging
>>> class SumFilter(logging.Filter):
...     def filter(self, record):
...         """書式文字列の引数の合計が10以上なら出力するという謎のフィルタ
...         """
...         # recordの属性に追加すると後から参照できる
...         record.sum = sum(record.args)
...         # True判定が返れば出力される
...         return record.sum >= 10
 
>>> # formatterからsum属性を参照
>>> formatter = logging.Formatter('%(message)s = %(sum)s')      
>>> sf = SumFilter()
>>> sh = logging.StreamHandler()
>>> sh.setFormatter(formatter)
 
>>> logger = logging.getLogger('filtertest')
>>> logger.setLevel(10)
>>> logger.addFilter(sf)
>>> logger.addHandler(sh)
 
# 2 + 3 + 4 = 9 (10未満のため出力されない)
>>> logger.debug('%s + %s + %s', 2, 3, 4)
 
>>> logger.debug('%s + %s + %s', 3, 4, 5)
3 + 4 + 5 = 12

« 次の記事 HOME 前の記事 »