pythonのloggingについてのメモ

loggingについて

python標準のlog書き出しライブラリであるloggingパッケージの使い方メモです

loggingの公式ドキュメント
https://docs.python.org/ja/3/library/logging.html#handler-objects

参考にしたページ

ログ出力のための print と import logging はやめてほしい
https://qiita.com/amedama/items/b856b2f30c2f38665701

python logging best practice
https://pieces.openpolitics.com/2012/04/python-logging-best-practices/

pythonのlog出力
https://qiita.com/yopya/items/63155923602bf97dec53

使い方

Loggerにレベルとフォーマットの管理をしてもらい、Handlerに書き出し先を管理してもらいます。

Logger

logging.getLogger()によりloggerインスタンスを作ることができます。引数としてlogger名を与えてフォーマットに含めるとここで指定したlogger名をlogに書き出すことができます

from logging import getLogger
logger = getLogger('hoge')

レベル

書き出しレベルを設定しておいて、閾値以下のlogは書き出さないようにすることが出来ます。細々とした情報はDEBUGのときにしか必要ないので、実運用時にはWARNING以上のlogしか書き出さない、というような事が出来るわけです。

これを上記で作ったloggerに追加することでレベルの閾値を指定できます。

from logging import DEBUG
logger.setLevel(DEBUG)

Handler

logging.StreamHandler()によりstdoutに、logging.handlers.RotatingFileHandler()によりテキストファイルにlogを書き出せます。

stdout

from logging import StreamHandler
handler = StreamHandler()

file出力

from logging import handlers
handler = handlers.RotatingFileHandler(filename='./hoge.log')

フォーマット

logのフォーマットも自由に指定することが出来ます

from logging import Formatter
formatter = Formatter("[%(asctime)s] [%(process)d] [%(name)s] [%(levelname)s] %(message)s")
handler.setFormatter(formatter)

書き出し

以下のようにレベルを指定して書き出します

logger.debug('debugレベルで書き出します')
logger.info('infoレベルで書き出します')
logger.warning('warnレベルで書き出します')
logger.error('errorレベルで書き出します')
logger.critical('criticalレベルで書き出します')

実際の使い方

こちらのページのやり方が分かりやすかったのでお借りしました。
https://qiita.com/yopya/items/63155923602bf97dec53

上記のあれこれをClassにしておいて一括で使おうというやり方ですね。

logger.py

from logging import Formatter, handlers, StreamHandler, getLogger, DEBUG


class Logger:
    def __init__(self, name=__name__, filename='./fuga.log', level=DEBUG):
        assert isinstance(filename, str), 'filename must be string: {}'.format(filename)

        self.logger = getLogger(name)
        self.logger.setLevel(level)
        formatter = Formatter("[%(asctime)s] [%(process)d] [%(name)s] [%(levelname)s] %(message)s")

        # stdout
        handler = StreamHandler()
        handler.setLevel(level)
        handler.setFormatter(formatter)
        self.logger.addHandler(handler)

        # file
        handler = handlers.RotatingFileHandler(filename=filename,
                                               maxBytes=1048576,
                                               backupCount=3)
        handler.setLevel(level)
        handler.setFormatter(formatter)
        self.logger.addHandler(handler)

    def debug(self, msg):
        self.logger.debug(msg)

    def info(self, msg):
        self.logger.info(msg)

    def warn(self, msg):
        self.logger.warning(msg)

    def error(self, msg):
        self.logger.error(msg)

    def critical(self, msg):
        self.logger.critical(msg)

上記をimportして使ってみます

main.py

import logger


def main():
    log = logger.Logger('hoge')
    log.debug('test debug')
    log.info('test info')
    log.warn('test warn')
    log.error('test error')
    log.critical('test critical')


if __name__ == '__main__':
    main()

hogeと書かれているのはloggerを作成したときに指定したlogger名なので、モジュールごとにこれを変えておけばどのモジュールが書いたログなのかも分かるようになります。

fuga.log

[2020-11-26 18:10:53,002] [5760] [hoge] [DEBUG] test debug
[2020-11-26 18:10:53,002] [5760] [hoge] [INFO] test info
[2020-11-26 18:10:53,003] [5760] [hoge] [WARNING] test warn
[2020-11-26 18:10:53,003] [5760] [hoge] [ERROR] test error
[2020-11-26 18:10:53,003] [5760] [hoge] [CRITICAL] test critical

また、levelをDEBUGではなくWARNに変更すると以下のように出力が制限されます。

fuga.log

[2020-11-26 18:10:53,003] [5760] [hoge] [WARNING] test warn
[2020-11-26 18:10:53,003] [5760] [hoge] [ERROR] test error
[2020-11-26 18:10:53,003] [5760] [hoge] [CRITICAL] test critical

まとめ

とりあえず使うだけならとても簡単だけど、込み入ったモジュールでバグを素早く見つけられるようにするには結構ノウハウが必要になりそうなので、スマートな使い方を模索していきたい所存でござる