loggingの有効/無効を真面目に書くのがめんどくさくなったのでDEBUG=1を見て勝手に有効にすることにした
loggingの有効/無効を真面目に書くのがめんどくさくなったのでDEBUG=1を見て勝手に有効にすることにしました。めんどくさかったので。
バージョン2.5.0の話です
$ pip install handofcats $ pip freeze | grep handofcats handofcats==2.5.0
普通に使う
例えば以下の様なコードがあるとします。
hello.py
from handofcats import as_command import logging logger = logging.getLogger(__name__) @as_command def hello(*, name: str = "world") -> None: logger.debug("DEBUG") logger.info(f"hello {name}") logger.warning("WARN")
引数なし
普通に使う場合にはloggingは有効になりません。ただしpythonのデフォルトの動作としてWARNING以降のログレベルのものは表示されます。
$ python hello.py WARN
loggingを追加
-h
でヘルプを見ると --logging
オプションが追加されています。
$ python hello.py -h usage: hello.py [-h] [--expose] [--inplace] [--typed] [--name NAME] [--logging {CRITICAL,FATAL,ERROR,WARN,WARNING,INFO,DEBUG,NOTSET}] optional arguments: -h, --help show this help message and exit --expose --inplace --typed --name NAME (default: 'world') --logging {CRITICAL,FATAL,ERROR,WARN,WARNING,INFO,DEBUG,NOTSET}
なにか困ったときに見たいのは、INFOないしはDEBUGのログです。
そんなわけで --logging=INFO
をつけて実行してみます。INFO以降も出てきました。
$ python hello.py --logging=INFO level:INFO name:__main__ where:hello.py:10 relative:36.0102653503418 message:hello world level:WARNING name:__main__ where:hello.py:11 relative:36.16213798522949 message:WARN
なんとなくLTSVで表示しています。
ここの表示内容は変えるかもしれません。あるいは何かいい感じのpresetを指定するような形にしてdefaultはいじらないようにするかもしれません。ただあんまり頑張りたくはない気持ちもあったりします。
個人的には、スタートしてからどれくらいの時間が経ったのかという relativeCreatedAt や ファイル名と行数が見たかったりします。
messageの部分が後ろになってしまうという問題はあったりしますが、まぁそこはデバッグのときには、出力できそうな情報を全部の情報出力して、あとでgrepしたりエディタで開いたりという形が多そうな気がするので良いということにしてしまっています。
DEBUG=1
コマンドラインオプションなんてめんどくさいということがあったりすると思います。例えばMakefile越しに実行されているときなどは、環境変数を経由して渡せます。
どうせDEBUGのときにはすべての情報が見たいということだろうと思うので、DEBUG=1
で有効になります。
$ DEBUG=1 python hello.py ** handofcats.injectlogging: DEBUG=1, activate logging ** level:DEBUG name:__main__ where:hello.py:9 relative:38.42568397521973 message:DEBUG level:INFO name:__main__ where:hello.py:10 relative:38.67387771606445 message:hello world level:WARNING name:__main__ where:hello.py:11 relative:38.74564170837402 message:WARN
ちなみに --logging=INFO
などloggingオプションが渡されていた場合にはそちらが優先されます。
もう少し真面目に環境変数を扱う
もう少し真面目に環境変数を扱ってみます。例えばJSON形式で無理やり出力したいということはできなくはないです。
- LOGGING_FORMAT
- LOGGING_STREAM
- LOGGING_LEVEL
が使えます。ただ真面目に使おうとする機会がそんなにくるとは思っていないです。せいぜいstderrではなくstdoutに出力したいくらいの要望なような気がしています。あとはフォーマットが気に入らない場合など。
$ LOGGIG_FORMAT=stdout $ LOGGING_FORMAT='{"level": "%(levelname)s", "funcname": "%(funcName)s", "message": "%(message)r"}' $ LOGGING_LEVEL=DEBUG $ python hello.py {"level": "DEBUG", "funcname": "hello", "message": "'DEBUG'"} {"level": "INFO", "funcname": "hello", "message": "'hello world'"} {"level": "WARNING", "funcname": "hello", "message": "'WARN'"}
例えば以下の様なMakefile越しに使う感じにすればまだましになるかもしれません (あるいはexportしてあげると毎回定義する必要はなくなります)。
04: LEVEL ?= DEBUG 04: FORMAT ?= {"level": "%(levelname)s", "funcname": "%(funcName)s", "message": "%(message)r"} 04: STREAM ?= stdout 04: LOGGIG_FORMAT=${STREAM} LOGGING_FORMAT='${FORMAT}' LOGGING_LEVEL=${LEVEL} python hello.py
もちろんas_commandデコレータを付けていないコードにも
もちろんas_commandを付けていない関数にもhandofcats越しに実行してあげれば大丈夫です。
$ DEBUG=1 python -m handofcats ./messages.py:debug ** handofcats.injectlogging: DEBUG=1, activate logging ** level:DEBUG name:messages where:messages.py:7 relative:38.02919387817383 message:DEBUG
このときのコードは以下の様な感じです。
messages.py
import logging logger = logging.getLogger(__name__) def debug(): logger.debug("DEBUG") def info(): logger.info("INFO") def warning(): logger.warning("WARNING")
詳細
テキトーに logging.basicConfig()
を実行しているだけです。
まとめ
めんどくさいときには DEBUG=1
で実行。loggingが有効になる。
gist