Pythonでログを出力するコード例【logging】

Pythonでログをファイルに出力する簡単な方法です。

Python標準の loggingロギング モジュールを使用して、『動作ログ』や『エラーログ』をファイルに記録します。

ログには、『時刻情報』や『実行中の関数名』も付けられます。

たくさんのXBRLを読み込んでいると、やはり、いろいろなエラーに遭遇します。XBRLのzipが破損していたり、タグ名に誤りがあったり、自身のプログラムにまずいところがあったり。

そういった例外やエラーは、とりあえずログファイルに記録しておいて、あとからひとつずつ対処していくことになると思います。

そのためのパイソンコード例を紹介します。

ロガーでの書き込みには、logging モジュールを使うのが一般的です。

スポンサーリンク

logging モジュールを使う

Python 標準のモジュールに、ログ記録用の logging モジュールがあります。これを使います。ここでは、ログの「画面表示」と「ファイル出力」をしてくれる、簡単なロガーを作って使ってみます。

決算分析システムで使っているロガーも、このような簡単なロガーがほとんどです。

公式マニュアルのページです。

logging – Python 用ロギング機能
https://docs.python.jp/3/library/logging.html

print()に相当するのが、ストリームハンドラだけのロガーです。

open()でテキスト出力に相当するのが、ファイルハンドラーだけのロガーです。

ストリームハンドラとファイルハンドラを追加すると、画面に出力しながらファイルに出力するロガーになります。

簡単なロガーだけで十分

ロガーは、簡単なもので十分でした。

ロガーの作り方は、お決まりのパターンでした。

あとは、print()の代わりに、lg.debug()などを使います。

さて、ロガーなんて使わず、自前でファイルを開いてログを記録するのでも、もちろんOKです。ログ出力の手作りです。

しかしながら、画面にも出力したいとなると、やはり print() も一緒に書くことになります。

そして、それらを関数にまとめて、便利にしようと作っていたら、結局、ロガーモジュールを作るのと同じになりました。

なので、最初からloggingモジュールの簡単なところだけ使うのがおすすめです。

実際のところ、ロギングレベルも DEBUG ひとつで十分でした。

必要に応じて、徐々に作り込んでいけば良いと思います。

Pythonでログ出力するコード例

ファイル名を指定して、ファイルにログを出力するサンプルです。

Pythonの実行ログをとるのに使います。

ロガー作成 ⇒ ログ記録 ⇒ ロガー終了の例

ロガーを作って、記録して、最後にロガーを終了(ロガーを削除)するコード例です。

ロガーの作成ですが、画面出力のための『ストリームハンドラ』と、ファイル出力のための『ファイルハンドラ』を追加します。

ファイルハンドラには、ファイルパス・書き込みモード・エンコーディングなどを指定します。ログ出力先を指定します。

ところで、ロガーの終了処理 に関しては、特に必要ないようでした。

Python 3.8 のマニュアルから、logging.shutdown() の必要性について『通常は手動で実行する必要は無い』という旨の説明が追加されていました。

When the logging module is imported, it registers this function as an exit handler (see atexit), so normally there’s no need to do that manually.

https://docs.python.org/ja/3/library/logging.html#logging.shutdown

要約すると、『import logging をしたときに、終了ハンドラとして logging.shutdown() が登録されるから、通常は手動で実行する必要はないです。』ということのようです。

以下のコード例では、ハンドラを外して閉じたり、シャットダウンを呼んだりしていますが、無くても大丈夫でした。特に問題は起こっていないです。

import os
import logging

def main():
    """ロガーテスト"""
    print('start')

    # ログフォルダ・ログファイル設定
    log_dir = r'D:\project\data_log'
    log_txt = os.path.join(log_dir, 'log.txt')


    # ロガー作成
    logger_name = __name__
    print('logger_name: "%s"' % logger_name)

    logger = logging.getLogger(logger_name)
    logger.setLevel(logging.DEBUG)


    # ストリームハンドラ作成
    stream_handler = logging.StreamHandler()
    stream_handler.setLevel(logging.DEBUG)
    stream_handler.setFormatter(logging.Formatter('%(message)s'))

    # ロガーに追加
    logger.addHandler(stream_handler)


    # ファイルハンドラ作成 (追記モード & utf-8 で記録)
    file_handler = logging.FileHandler(log_txt, mode='a', encoding='utf-8')
    file_handler.setLevel(logging.DEBUG)
    file_handler.setFormatter(logging.Formatter('%(message)s'))

    # ロガーに追加
    logger.addHandler(file_handler)


    # 記録
    logger.debug('ロギング 開始')

    try:
        raise ValueError('テスト バリューエラー')
    except:
        logger.exception('例外を記録 ここから↓')
        logger.debug('ここまで↑')

    logger.debug('ロギング 終わり')


    # ロガーに追加したハンドラを閉じてリムーブ。# しなくていい
    # [::-1]で逆順にして、リストの後ろからリムーブしていく。
    for handle in logger.handlers[::-1]:
        handle.close()
        logger.removeHandler(handle)

        # (参考) リムーブしたハンドラを表示
        if type(handle) == logging.FileHandler:
            print('Removed %s %s' % (
                str(type(handle)),
                os.path.basename(handle.baseFilename),
                ))
        else:
            print('Removed %s' % str(type(handle)))


    # ロガーをシャットダウンする
    logging.shutdown() # 書かなくていい

    print('end')
    return


if __name__ == '__main__':
    main()

実行結果です。まずは「画面出力」です。

start
logger_name: "__main__"
ロギング 開始
例外を記録 ここから↓
Traceback (most recent call last):
  File "D:\project\data_log\use_logger.py", line 43, in main
    raise ValueError('テスト バリューエラー')
ValueError: テスト バリューエラー
ここまで↑
ロギング 終わり
Removed <class 'logging.FileHandler'> log.txt
Removed <class 'logging.StreamHandler'>
end

そして「ログファイル」です。logger.debug() と logger.exception() の文字列が記録されています。logger.exception() ですが、渡した文字列に続けてスタックトレースを出力してくれます。

ロギング 開始
例外を記録 ここから↓
Traceback (most recent call last):
  File "D:\project\data_log\use_logger_0.py", line 43, in main
    raise ValueError('テスト バリューエラー')
ValueError: テスト バリューエラー
ここまで↑
ロギング 終わり

こういった例外発生時の情報は、traceback.format_exc() で取得して、logger.debug()に渡すことでも記録できます。単に記録するだけなら logger.exception() が簡潔で便利でした。

ロガーの作成を関数化して簡単に使う

Pythonのloggerでファイル出力するコードです。

ロギングモジュールから作るロガーですが、欲しい機能って、だいたい同じだったりするんですね、どのプログラムでも。

なので、上記のようなお決まりのロガーは、関数化して使っています。

以下は、ロガーの作成部分を関数化したコード例です。

"""MyLogger.py"""
import os
import logging


def main():
    """ロガーテスト"""
    print('start')

    # ログフォルダ・ログファイル設定
    log_dir = r'D:\project\data_log'
    log_txt = os.path.join(log_dir, 'log.txt')

    # ロガー作成
    lg = get_logger(__name__, log_txt)


    # 記録
    lg.debug('ロギング 開始')

    try:
        raise ValueError('テスト バリューエラー')
    except:
        lg.exception('例外を記録 ここから↓')
        lg.debug('ここまで↑')

    lg.debug('ロギング 終わり')

    print('end')
    return


def get_logger(
    logger_name, log_file,
    s_fmt='%(message)s', f_fmt='%(message)s'):
    """ロガーを取得"""
    # ロガー作成
    logger = logging.getLogger(logger_name)
    logger.setLevel(logging.DEBUG)


    # ストリームハンドラ作成
    stream_handler = logging.StreamHandler()
    stream_handler.setLevel(logging.DEBUG)
    stream_handler.setFormatter(logging.Formatter(s_fmt))

    # ロガーに追加
    logger.addHandler(stream_handler)


    # ファイルハンドラ作成
    file_handler = logging.FileHandler(log_file, mode='a', encoding='utf-8')
    file_handler.setLevel(logging.DEBUG)
    file_handler.setFormatter(logging.Formatter(f_fmt))

    # ロガーに追加
    logger.addHandler(file_handler)

    return logger

if __name__ == '__main__':
    main()

画面表示だけのロガーの作り方

ロガーにストリームハンドラ logging.StreamHandler() だけを追加すると、画面表示だけを行うロガーができます。

ログの保存先などの指定も不要です。

この場合は、プリント関数 print() とほぼ同じ機能になりますが、表示が速いというメリットがありました。

print()よりもストリームハンドラだけの .debug() で画面表示したほうが、目に見えて高速でした。文字がサラサラと流れていきます。

理由は分かりませんでしたが、print() は、ストリームハンドラだけの .debug() よりも遅いようです。

なので自分は、プロンプト画面にたくさん情報表示するようなPythonプログラムでは、高速化のために、ストリームハンドラーだけを追加したロガーを使ったりしています。

ファイル記録だけのロガーの作り方

ロガーにファイルハンドラ logging.FileHandler(log_file, mode='a', encoding='utf-8') だけを追加すると、ファイル記録だけを行うロガーができます。

プロンプト画面には何も表示されません。ファイルにだけログが出力されます。

時刻情報や実行中の関数名を出力するロガーの作り方

Pythonのロガーのフォーマットは、ロギングフォーマッター logging.Formatter() を使って設定します。

定番は『時刻情報』と『関数名』の自動付加ですね。

以下のPython公式マニュアルから、使いたいフォーマットを調べて設定します。

LogRecord 属性(ログレコード属性)
https://docs.python.jp/3/library/logging.html#logrecord-attributes

ログに時刻情報を出力 '%(asctime)s'

ログに『時刻情報』を出力するには、'%(asctime)s' を使います。

'%(message)s' のほかに '%(asctime)s' を指定すると、ログを記録した時の時刻が自動で追加されます。

具体的には、セットフォーマッター .setFormatter() の引数に以下を渡します。

logging.Formatter('%(asctime)s %(message)s')

ログに関数名を出力 '%(funcName)s'

ログに『実行中の関数名』を出力するには、'%(funcName)s' を使います。

'%(message)s' のほかに '%(funcName)s' を指定すると、ログを記録したところの関数名が自動で追加されます。

具体的には、セットフォーマッター .setFormatter() の引数に以下を渡します。

logging.Formatter('%(funcName)s %(message)s')

時刻情報と関数名を出力

ログに『時刻情報』と『実行中の関数名』を同時に追加することもできます。

セットフォーマッター .setFormatter() の引数に以下を渡します。

logging.Formatter('%(asctime)s %(funcName)s %(message)s')

他にも情報を追加したいときは、Pythonマニュアルの『LogRecord 属性』から使いたいフォーマットを選べばOKです。

Pythonのログをローテーションして記録する方法

ログのファイルサイズを指定して、分割しながら記録していく方法です。

ログファイルが巨大化すると開けなくなりますので、指定したサイズになったら新しいファイルに書き込む必要があります。

ログを自動で分割記録するには、ローテーティングファイルハンドラ RotatingFileHandler を使います。

Pythonの公式マニュアルがわかりやすかったです。

logging.handlers — ロギングハンドラ RotatingFileHandler
class logging.handlers.RotatingFileHandler(filename, mode='a', maxBytes=0, backupCount=0, encoding=None, delay=False)

Logging クックブック
ファイルをローテートする

maxBytes に、ファイルの最大サイズを渡して使います。

backupCount には普通、1以上を設定します。backupCountの数だけ、古いログファイルに連番が付いて残ります。

ログファイルがmaxBytesを超えそうになったら、自動的にファイルを閉じて、新しいログファイルに記録してくれます。

ログファイルのローテーション処理を手作りしなくていいのは嬉しいです。

タイトルとURLをコピーしました