【Python】loggingを使ってログ出力する方法

ログ出力をしようと思った経緯

Pythonの開発にVisual Studio Codeを使っていますが、複数の環境設定を作ってデバッグをしようと思ってもブレイクポイントを付けると処理が止まってしまいデバッグが出来なくなることがありました。（ブレイクポイントで黄色くなり止まっているわけでもなく。。。）
MacではVisual Studio Codeを再インストールして色々やっているとうまくデバッグ出来たのですが、Windowsでは再インストールしてもダメでした。
なのでVisual Studio Codeはエディターとして割り切っていくことにしました。ブレイクポイントを設置しなければデバッグ実行もできるので。

しかし、変数の値など確認したいことはあります。
print()でターミナルに出力してもいいのですが、ログ出力となるともう少し良い方法がないかと調べていました。
するとloggingというログ出力するモジュールが標準で用意されていたので使い方を残しておきます。

設定ファイルを使ったログ出力

ログ出力する為にコードに設定内容を書くのは見難くなるので、設定内容などはクラス化したり別ファイルに記述しようかと思っていたら、これまた標準で解決するよい方法が用意されていました。logging.configモジュールを使うことでログの設定をファイルで管理することができます。

ここから実際に、設定ファイル(logging.conf)とサンプルコード(smple.py)を使って説明します。
まだ、部分的にしか理解できていないので間違っていたらご指摘ください。

設定ファイル(logging.conf)、実行ファイル(sample.py)を作成し実行

 
[loggers]                   # ロガー名を設定
keys = root                 # rootは必須

[handlers]                  # ハンドラー名を設定
keys = file, console

[formatters]                # フォーマット名を設定
keys = myFormat

[logger_root]               # ロガーの設定 -- logger_[ロガー名]
level = DEBUG               # ログレベルを指定
handlers = file, console    # ハンドラーを指定

[handler_file]              # ハンドラーの設定 -- handler_[ハンドラー名]
class = handlers.TimedRotatingFileHandler # ハンドラのクラスを指定(ファイル出力)
formatter = myFormat        # ログのフォーマットを指定
args = ('log/root.log','D') # 引数指定(ファイル名, 日単位で上書き）

[handler_console]           # ハンドラーの設定
class = StreamHandler       # ハンドラーのクラスを指定(標準出力)
formatter = myFormat        # ログのフォーマットを指定
args = (sys.stdout,)        # 引数指定

[formatter_myFormat]        # フォーマットの設定 -- formatter_[フォーマット名]
format = [%(asctime)s][%(levelname)s](%(filename)s:%(lineno)s) %(message)s
datefmt = %Y/%m/%d %H:%M:%S # 日付の書式を指定

import logging.config

# 設定ファイル(logging.conf)の読込
logging.config.fileConfig("logging.conf")
LOG = logging.getLogger()

# 各レベルでのログ出力
LOG.info("info level log")
LOG.debug("info debug log")

実行結果、ターミナルとファイル(root.log)に以下のログが出力されます。

[2018/11/07 14:29:43][INFO](sample.py:8) info log
[2018/11/07 14:29:43][DEBUG](sample.py:9) debug log

まずは設定ファイル（logging.conf）から説明します。

設定ファイルには以下の項目を必ず記述する必要があります。

[loggers]
keys = root [,任意のlogger名]
[handlers]
keys = [任意のhandler名]
[formatters]
keys = [任意のformat名前]

各keysに複数設定する場合は","カンマで区切ります。

ロガーの設定

先頭に[logger_root]など、設定するロガーを定義します。ここではrootの設定を行っています。
記述方法はlogger_[keysで設定したロガー名]です。

今回の設定では、levelはログレベルはDEBUGを指定しています。
handlersではハンドラーの名前を設定します。[handler_handler名]での設定が適応されます。

[logger_root]               # ロガーの設定 -- logger_[ロガー名]
level = DEBUG               # ログレベルを指定
handlers = file, console    # ハンドラーを指定

ログレベルは他にも色々あります。

NOTSET   設定値などの記録（全ての記録）
DEBUG　  動作確認などデバッグの記録
INFO     正常動作の記録
WARNING  ログの定義名
ERROR    エラーなど重大な問題
CRITICAL 停止など致命的な問題

ハンドラーの設定

先頭に[handler_file]や[handler_console]など、設定するハンドラーを定義します。ここではfileとconsoleの設定を行っています。
記述方法はhandler_[keysで設定したハンドラー名]です。

handler_file はログをlogフォルダ内のroot.logファイルに出力します。
フォルダは自動で作成されないので事前に作成しておく必要があります。
formatterで出力するログのフォーマットを指定しています。

handler_console は通常のログ出力です。Macだとターミナル上に出力されます。
argsにはsys.stdout, sys.stderrなどを設定するようです（いまいちここの違いが理解できていません）

[handler_file]              # ハンドラーの設定 -- handler_[ハンドラー名]
class = handlers.TimedRotatingFileHandler # ハンドラのクラスを指定(ファイル出力)
formatter = myFormat        # ログのフォーマットを指定
args = ('log/root.log','D') # 引数指定(ファイル名, 日単位で上書き）

[handler_console]           # ハンドラーの設定
class = StreamHandler       # ハンドラーのクラスを指定(標準出力)
formatter = myFormat        # ログのフォーマットを指定
args = (sys.stdout,)        # 引数指定

フォーマットの設定

先頭に[handler_file]など、設定するフォーマットを定義します。ここではmyFormatの設定を行っています。
記述方法はhandler_[keysで設定したフォーマット名]です。

format はログの出力形式を指定します。
datefrt はログに日付を出力する時の日付書式を指定します。

[formatter_myFormat]        # フォーマットの設定 -- formatter_[フォーマット名]
format = [%(asctime)s][%(levelname)s](%(filename)s:%(lineno)s) %(message)s
datefmt = %Y/%m/%d %H:%M:%S # 日付の書式を指定

formatの形式です。これらを好きなように組み合わせて出力する事が出来ます。

%(asctime)s   実行時刻
%(filename)s  ファイル名
%(funcName)s  行番号
%(levelname)s ログの定義
%(lineno)d    ログレベル名
%(message)s   ログメッセージ
%(module)s    モジュール名
%(name)s      関数名
%(process)d   プロセスID
%(thread)d    スレッドID