python loggingメモ

以下の例は公式ドキュメントのHow to loggingを参考にしています。

---

loggingの設定方法は、以下の2種類があります。

1. コード内で設定

2. 外部ファイルで設定する方法

コード内で設定する

コンソール(Stream)だけに出力

import logging
logger = logging.getLogger('__name__')
logger.setLevel(logging.DEBUG)
ch = logging.StreamHandler()
ch.setLevel(logging.DEBUG)
formatter = logging.Formatter('%(asctime)s, %(name)s, %(levelname)s, %(message)s')
ch.setFormatter(formatter)
logger.addHandler(ch)
# test
logger.info('test')

コンソールとファイルに出力

import logging
logger = logging.getLogger('__name__')
logger.setLevel(logging.DEBUG)
# create file handle 
fh = logging.FileHandler('spam.log')
fh.setLevel(logging.DEBUG)
# create console handle 
ch = logging.StreamHandler()
ch.setLevel(logging.ERROR)
# create formatter and add it to the handlers
formatter = logging.Formatter('%(asctime)s , %(name)s, %(levelname)s, %(message)s')
ch.setFormatter(formatter)
fh.setFormatter(formatter)
# add the handlers to logger
logger.addHandler(ch)
logger.addHandler(fh)
# レベルを変えてテスト
logger.debug('debug message')
logger.info('info message')
logger.warning('warning message')
logger.error('error message')
logger.critical('critical message')

※setlevelがfhとchで変えてあるので注意。

spam.logというファイルが作成されてlogが書き込まれていきます。

logが出ているコードの行数を出力するには、formatterの部分に　%(lineno)s 　を入れます。例えばこうします。

formatter = logging.Formatter('%(asctime)s , %(lineno)s,%(name)s, %(levelname)s, %(message)s')

ログファイルをサイズで区切ってローテーションする

ログを書き込むファイルのサイズで区切るには、RotatingFileHandlerを使います。設定は

fh =logging.handlers.RotatingFileHandler(
                                        './log.log',
                                        mode='a',
                                        maxBytes=1000000,
                                        backupCount=100
                                        )

パラメータ:
maxBytes=1000000: 約1MBで区切ります。
backupCount=100: 100ファイル残します。無制限にはできません。0だと動作しません。

1日ごとに新しいログファイルを作るには、TimedRotatingFileHandlerを使います。whenで区切り単位、intervalで数を決めます。

同じログファイルへはmode='a'(追記)が標準です。置き換えはmode='w'を追加します。

fh = logging.handlers.TimedRotatingFileHandler(
　　　　　　　　　'./log.log',
                                    when="D",
                                    interval=1,
                                    )

ログが多重になる失敗 --> clear()すると解決

1つのlogger.errorに対して2つログが入っている

上記のログ設定をコンソール上で複数回呼び出すと、logger.handlersにStreamハンドラが複数入ることになり、上の画像のようにログに同じものが何行も出たりします。Jupyterだとよくやってしまう失敗です。

解決方法は

logger.handlers = []

または

logger.handlers.clear()

でハンドラの中身をリセットすればOK。

root側にも設定が残ってしまったら

logger.root.handlers.clear()

とするとリセットできます。

残っていたら消してから再設定するようにするには、、こんな感じで。でもあまり使っていません。

import logging
try:
    if len(logger.handlers):
        logger.handlers.clear()
        logger.root.handlers.clear()
except NameError:
    pass
logger = logging.getLogger('__name__')
logger.setLevel(logging.DEBUG)# root

logファイル名を変更するとき

Jupyterでloggingをしているとき、スクリプトを一度止めて、logファイルを少しいじって保存すると再度宣言してもそのファイル名は認識されません。

ファイル名を変えても同じものとして認識されますファイル名を変えたいいときは、ログファイルを造り直さないとできませんでした。

AttributeError: module 'logging' has no attribute 'handlers'

というエラー。

loggingモジュールをインポートしてもlogging.handlersは同時にはロードされないことがあるようです。JupyterならOKでもそのまま.pyで使ったらロードされない・・・というケースもありました。

import logging
import logging.handlers

としておけば解決しました。
https://stackoverflow.com/questions/3781522/why-do-python-modules-sometimes-not-import-their-sub-modules

loggingをdesableにしたりdisableを取り消したりする

Jupyterでimport logging

logging.disable(logging.DEBUG)

とするとDEBUGは表示されなくなります。これを取り消すにはdisableをNOTSETにします。

logging.disable(logging.NOTSET)

.pyファイルのときはhandlersもインポートする

from logging import handlers # for .py

自分の環境で、jupyterではいらないですが、pythonファイルをターミナルから動かすときは、handlersモジュールをインポートしないと動きません。AttributeError: module 'logging' has no attribute 'handlers'というエラーが出ます。

logging.confファイルを作って読み込む

別ファイルに設定を書いておいて読み込む方法です。上で出てきた、コンソールにもファイルにもログ出力する方法です。

logging.conf

[loggers]
keys=root
[handlers]
keys=fileHandler,stderrHandler
[formatters]
keys=simpleFormatter
[logger_root]
level=DEBUG
handlers=fileHandler,stderrHandler
[handler_fileHandler]
level=INFO
class=FileHandler
formatter=simpleFormatter
args=('root.log','a')
[handler_stderrHandler]
level=DEBUG
class=StreamHandler
formatter=simpleFormatter
args=(sys.stderr,)
[formatter_simpleFormatter]
format=%(asctime)s - %(name)s - %(levelname)s - %(message)s

読み込むときは、下記のようにlogging.config.fileConfig("logging.conf")とします。

logging_sample.py

#! /usr/bin/python
import logging.config
logging.config.fileConfig("logging.conf")
logger = logging.getLogger()
logger.info("info level log")
logger.debug("debug level log")

$ python logging_sample.py

とやるとファイルとコンソールにサンプルの結果が出ます。

参考:

https://python-guideja.readthedocs.io/ja/latest/writing/logging.html

よく使うのはこういう感じ

ファイルへの書き込みのみ。
ログの容量を節約するためタイムスタンプは秒まで。関数名を削除
log/ というディレクトリにある「ログのファイル名.log」を出力。(※log/ディレクトリは先に作らないとエラー)

ログのファイル名には.pyファイルの__file__を使っているのでjupyterだとエラーが出ます。変数を設定する。

import logging

logger = logging.getLogger()
logger.setLevel(logging.DEBUG)
fh = logging.FileHandler("log/" + __file__ + ".log")
fh.setLevel(logging.DEBUG)
formatter = logging.Formatter(
    "%(asctime)s, %(levelname)s, %(message)s", "%Y-%m-%d %H:%M:%S"
)
fh.setFormatter(formatter)
logger.addHandler(fh)

例えばこのように出力されます。

2021-07-03 08:49:37, INFO, test

よく使うその2。

同じですが、loggerをdefで関数内で作成して、グローバルのところで呼び出しています。

def create_logger():
    import logging

    logger = logging.getLogger()
    logger.setLevel(logging.DEBUG)
    fh = logging.FileHandler("log/" + __file__ + ".log")
    fh.setLevel(logging.DEBUG)
    formatter = logging.Formatter(
        "%(asctime)s, %(levelname)s, %(message)s", "%Y-%m-%d %H:%M:%S"
    )
    fh.setFormatter(formatter)
    logger.addHandler(fh)
    return logger


def main():

    logger.debug("debug level log")


if __name__ == "__main__":
    logger = create_logger()
    try:
        main()
    except:
        logger.exception("-" * 10)

shimo lab2

2018年4月3日火曜日