python3のloggerでミリ秒を使う、他
ブログスモールスタート第2段。
最近pythonの勉強を始めて、
ロギングには標準モジュールのlogging.loggerを使え!ってのはわかったのだけど色々苦労したのでその辺をメモ。
へなちょこエンジニア(コピペプログラマー)レベルなので、Python初学者で詰まってる人には参考になるかもしれない。
loggerとは
基礎的なところは公式ドキュメントを参照>Logging HOWTO — Python 3.6.5 ドキュメント
まあ一応ざっっっくり説明しておくと、
- logging.loggerをセット(ログの取得元を設定)
- handlerをセット(出力先を設定)
- loggerにhandlerをセット(紐づけ)
- print('debug: hogehoge')していたところを、logger.debug('hogehoge')に変える
- logger.error('hogehoge!!')みたいに重要度でレベル分けできる
といった感じで使える。
loggerに対してhandlerを複数セットしたりできるので、標準出力とファイル出力同時にするのも簡単。
フォーマッタでミリ秒/ナノ秒を使いたい
handlerに対しては、formatterを設定できる。
デフォルトだと(asctimeに対して)%Y-%m-%d %H:%M:%S
形式がセットされているので、
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
だと
2005-03-19 15:10:26,618 - simple_example - DEBUG - debug message
みたいに返ってくる(公式ドキュメントから引用)。
この日付形式に不満がなければそのままでもいいのだけれど、1984/01/24 17:00:56.999
形式にしたい。
最初にドキュメントとかを見てdatefmtにstrftimeの形で指定してあげればいいっぽいので次のコードにしたがエラー。
logging.Formatter('%(asctime)s [%(levelname)][%(name)s] %(message)s',datefmt='%Y/%m/%d %H:%M:%S.%f')
%fがだめらしい。 ※今ドキュメントよく見たらpython3.6のstrftimeに%fない?…2.xの方の情報見てたかな
解決法:次のコードを使う
logging.Formatter('%(asctime)s.%(msecs)-3d [%(levelname)-7s][%(name)s] %(message)s',datefmt='%Y/%m/%d %H:%M:%S')
datefmtでは秒まで。(msecs)でナノ秒が取れるので、それを左揃え3桁パディングしてあげればミリ秒が取れる。
独自のLogRecord属性
ログに関数IDや処理中ファイルみたいなのを出したい場合、
これをいちいちlogger.info('[XX-YY-Z001] hogehoge with [sample.csv]')
とか
functionId = 'XX-YY-Z001' filePath = 'sample.csv' …(略)… msg = '[{0}] hogehoge with [{1}]'.format(functionId,filepath) logger.info(msg)
としてもいいけど、書式がズレないように気を使うのがめんどくさいし、
途中で書式変えたくなった時死ぬほどめんどくさい。絶対ヤダ。
というわけで色々調べると、extraオプションで独自設定ができるらしい。
logging.Formatter('%(asctime)s.%(msecs)-3d [%(levelname)-7s] [%(functionId)s] %(message)s with [%(file)s]',datefmt='%Y/%m/%d %H:%M:%S')
みたいに、LogRecord属性にない(functionId),(file)をフォーマッタ時点で入れておく。
logger呼出時に、logger.info('hogehoge',extra={'functionId':'XX-YY-Z001','file':'sample.csv'})
とか
functionId = 'XX-YY-Z001' filepath = 'sample.csv' ex = {'functionId':functionId,'file':filepath} …(略)… logger.info('hogehoge',extra=ex)
してあげれば(extra引数に辞書形式で渡してあげれば)OK。
ただしこのやり方だと、logger呼出時に(functionId)や(file)がないとか、extraオプション自体がないとエラーになってしまうのでそれはそれでめんどくさい。
LogAdapterとやらをなんとかすれば解決できそうな気がするけど、とりあえず現状はここまで。
実際に書いたコード的なもの
適当に改変してるけど大体上記のことを反映したlogger生成関数。
def set_logger(): from logging import (getLogger,StreamHandler,FileHandler,Formatter, DEBUG,INFO,WARNING,ERROR) from datetime import datetime as dt import os # const的ななにか LOGLEVEL = 'DEBUG' BASEPATH = os.path.dirname(os.path.abspath(__file__)) # パス、ファイル名設定 LOGPATH = BASEPATH + '/log/system_' + dt.now().strftime('%Y%m%d') + '.log' # logger設定 logger = getLogger(__name__) logger.setLevel(LOGLEVEL) # handler設定 # フォーマット設定 handler_format = Formatter('%(asctime)s.%(msecs)-3d' + ' [%(levelname)-7s] [%(functionId)s]' + ' %(message)s with [%(file)s]', datefmt='%Y/%m/%d %H:%M:%S') # 標準出力 stream_handler = StreamHandler() stream_handler.setLevel(LOGLEVEL) stream_handler.setFormatter(handler_format) # ファイル出力 file_handler = FileHandler(LOGPATH,'a',encoding='utf-8') file_handler.setLevel(LOGLEVEL) file_handler.setFormatter(handler_format) # loggerにhandlerセット logger.addHandler(stream_handler) logger.addHandler(file_handler) return logger # 呼出時 functionId = 'XX-YY-Z001' filepath = 'sample.csv' ex = {'functionId':functionId,'file':filepath} logger.info('hogehoge',extra=ex)