pythonのprint()をlogger.infoに変える黒魔術(loggedpy)

loggedpy python logging

github.com

pythonのprint()をlogger.infoに変える黒魔術(loggedpy)を実装してみた（土日）。

発端はこのtweet。

意外とやってみると辛かったり奥深さを感じたりした（中のコードを覗くと辛さがわかるかもしれない。暇だったらどこかで発表したい。かも）。

loggedpy

使いかたはpythonのかわりにloggedpyコマンドを使うだけ(日常的に使うと言うよりはデバッグのときに使う感じかもしれない)。するとprint()を使った部分があたかもログ出力のように扱われる。

$ loggedpy hello.py
INFO  2018-09-24 01:06:56,698 hello hello
INFO  2018-09-24 01:06:56,698 bye

# 元々の出力
$ python hello.py
hello hello
bye

現状は logging.BASIC_FORMATにasctimeを追加しただけの状態だけれど。良いデフォルト値を募集中。

ちなみに上の出力結果を返すコードは以下のようなもの

def main():
    print("hello hello")
    print("bye")


if __name__ == "__main__":
    main()

対応しているもの

以下3つ全てにおおよそ対応

  • python <filename>.py での実行
  • setup.pyなどでインストールされるコマンドの実行
  • python -m <module> での実行

詳しくはreadme参照

--flavor

出力結果を変えたくなった場合には--flavorオプションで実装を差し替えられる。例えばもうちょっと出力を豪華にするには以下の様なコードを書く

customized.py

import logging
import loggedpy


class Flavor(loggedpy.Flavor):
    format = "%(levelname)s\t%(asctime)s\t%(name)s\tin\t%(filename)s:%(lineno)s\t%(funcName)s\t%(message)s"
    level = logging.DEBUG

今度は以下の様な出力になる（funcNameやlinenoが追加されてちょっと豪華）

$ loggedpy --flavor=./customized.py:Flavor hello.py
INFO    2018-09-26 22:23:38,377 __main__    in  hello.py:2  main    hello hello
INFO    2018-09-26 22:23:38,377 __main__    in  hello.py:3  main    bye

使える変数はloggingのLogRecord属性にあるもの。

JSON出力

昔作ったmonokakiと組み合わせると手軽にJSON出力にできる。

$ loggedpy --flavor=./customized.py:Flavor ../hello.py
{
  "logger": "__main__",
  "levelname": "INFO",
  "asctime": "2018-09-26 22:27:07,258",
  "name": "__main__",
  "filename": "hello.py",
  "lineno": 2,
  "funcName": "main",
  "message": "hello hello"
}
{
  "logger": "__main__",
  "levelname": "INFO",
  "asctime": "2018-09-26 22:27:07,258",
  "name": "__main__",
  "filename": "hello.py",
  "lineno": 3,
  "funcName": "main",
  "message": "bye"
}

詳しくはexamplesを参照

追記

以下ができたらpypiにあげる（たぶん）

  • djangoなどでの動作確認
  • デフォルトの出力を良い感じにする(まだ決めあぐねている）