結局昨日のロガーの話はパッケージにした

python logging structlog monokaki

github.com

結局昨日のロガーの話はパッケージにした。100行以下で大変短く良いコード。 ただ、stdoutやstderrに出力するだけで構造化ログを実装したと言ってはだめで、何らかのdata sourceに溜め込んでそれを何らかのビューから覗くぐらいは試した方が良いのだけれど。そこまで真面目に試すやる気は出ない。

使い方

使い方はかんたんで pip install monokaki をしてから。ほぼ通常のloggingモジュールを使う感じにするだけ。

from monokaki import get_logger, basic_config, INFO as INFO_LEVEL
logger = get_logger(__name__)


def hello(log):
    log.bind(age=20).info("hello")
    log.info("bye", age=20)


def main():
    hello(logger.bind(name="foo"))


if __name__ == "__main__":
    basic_config(level=INFO_LEVEL)
    main()

出力結果

{"age": 20, "level": "INFO", "logger": "__main__", "msg": "hello", "name": "foo", "time": "2017-05-21 21:00:45,524"}
{"age": 20, "level": "INFO", "logger": "__main__", "msg": "bye", "name": "foo", "time": "2017-05-21 21:00:45,526"}

かんたんですね。いつも通りの感じ。

出力の形式を変えたい場合

出力形式を変えたい場合にはrenderer関数を作ってあげれば良い。renderer関数は辞書とlogging.LogRecordとlogging.Formatterを受け取るcallable object。関数で良い。例えばltsvで出力したい場合は以下の様な感じになる。順番なども気にしたい場合にはOrderedDictを使う。

from collections import OrderedDict


def ltsv_renderer(d, record, formatter):
    c = OrderedDict()
    c["time"] = formatter.formatTime(record)
    c["level"] = record.levelname
    c["msg"] = record.msg
    c["where"] = "{}:{}({})".format(record.filename, record.lineno, record.funcName)
    c.update(sorted(record.kwargs.items()))
    return "\t".join("{}:{}".format(k, v) for k, v in c.items())

LogRecordの扱いだけは見慣れない人もいると思うけれど。基本的にはドキュメントに書いてあるものが使えるだけ。あとは、bindなどで渡された引数はrecord.kwargsに格納されている。

これを使った結果

from monokaki import get_logger, basic_config, INFO as INFO_LEVEL
from collections import OrderedDict
logger = get_logger(__name__)


def hello(log):
    log.bind(age=20).info("hello")
    log.info("bye", age=20)

def main():
    hello(logger.bind(name="foo"))


if __name__ == "__main__":
    basic_config(level=INFO_LEVEL, renderer=ltsv_renderer)  # ここで新しく定義したltsv_rendererを使っている
    main()

こういう感じに出力は変えられる。

time:2017-05-21 21:08:18,661 level:INFO  msg:hello   where:main.py:17(hello) age:20  name:foo
time:2017-05-21 21:08:18,661    level:INFO  msg:bye where:main.py:18(hello) age:20  name:foo

もちろんexc_infoなどに対応することもできて、こう書いてあげると。exc_infoがまともに動く。

def ltsv_renderer(d, record, formatter):
    c = OrderedDict()
    c["time"] = formatter.formatTime(record)
    c["level"] = record.levelname
    c["msg"] = record.msg
    c["where"] = "{}:{}({})".format(record.filename, record.lineno, record.funcName)
    c.update(sorted(record.kwargs.items()))
    if "stack" in d:
        c["stack"] = d["stack"].replace("\n", "\\n")
    return "\t".join("{}:{}".format(k, v) for k, v in c.items())

こういう感じ。

def hello(log):
    log.bind(age=20).info("hello")
    log.info("bye", age=20)
    try:
        1 / 0
    except:
        logger.info("1/0", exc_info=True)

stackが追加されている。

time:2017-05-21 21:12:59,552 level:INFO  msg:hello   where:main.py:19(hello) age:20  name:foo
time:2017-05-21 21:12:59,552    level:INFO  msg:bye where:main.py:20(hello) age:20  name:foo
time:2017-05-21 21:12:59,553    level:INFO  msg:1/0 where:main.py:24(hello) stack:Traceback (most recent call last):\n  File "main.py", line 22, in hello\n    1 / 0\nZeroDivisionError: division by zero

Formatterを作っているだけなので

logging.Formatterを作っているだけなので。その他のloggingの設定とかちあうこともない。

import logging
from monokaki import StructuralFormatter
from monokaki import get_logger
import sys

logger = get_logger("my log")
handler = logging.StreamHandler(sys.stdout)
handler.setFormatter(StructuralFormatter())

# loggerAdapterなので内部のloggerを取り出すにはlogger.logger
logger.logger.addHandler(handler)
logger.setLevel(logging.INFO)

logger.info("hai", name="foo", age=20)
logger.logger.info("hai name=%s, age=%d", "foo", 20)

かちあうこともない。

{"age": 20, "level": "INFO", "logger": "my log", "msg": "hai", "name": "foo", "time": "2017-05-21 21:20:37,497"}
INFO:my log:hai name=foo, age=20