現在、Kaggleにガチ挑戦中のツクダンです。
いろいろな書籍・動画を参考にして学習を進めていますが、以下のYouTube動画での「ログをとる(コード実行中におこるイベントを追跡・記録)」という操作が有益で驚きました。
ただそこで出てくる「loggingモジュール」の使い方がわかりにくかったので、頭の整理ついでに記事にまとめることにしました。
loggingを初めて使う人にも分かりやすくまとめてあるので、興味のある人は参考にしてみてください。
loggingを使うときにやること4つ
まずはloggingモジュールを使って、Loggerオブジェクトを作成していきます。
ざっくりまとめると、やることは以下の四つ。
- loggingモジュールから必要なものをインポート
- getLogger()でloggerの作成
- Formatterで出力形式を設定
- ハンドラの設定を行いloggerに追加する
それぞれのステップの詳細は後述するとして、まずは全体のコードを載せます。
<strong>#1
from logging import getLogger, Formatter, StreamHandler, FileHandler, DEBUG, INFO
#2
logger = getLogger(__name__)
logger.setLevel(DEBUG)
#3
log_fmt = Formatter("%(asctime)s %(name)s %(lineno)d [%(levelname)s][%(funcName)s] %(message)s")
#4-1
stream_handler = StreamHandler()
stream_handler.setLevel(INFO)
stream_handler.setFormatter(log_fmt)
logger.addHandler(stream_handler)
#4-2
file_handler = FileHandler("../train.py.log" , "a")
file_handler.setLevel(DEBUG)
file_handler.setFormatter(log_fmt)
logger.addHandler(file_handler)
</strong>
Step1. loggingモジュールから必要なものをインポート
<strong>from logging import getLogger, Formatter, StreamHandler, FileHandler, DEBUG, INFO</strong>
まずはloggingモジュールから、logger作成に必要なものをインポートします。
- loggerオブジェクトを作成するgetLogger関数
- フォーマッタオブジェクトを作成するFormatter(クラス)
- 使用したいハンドラ(Handler)
今回はハンドラの中でも使用頻度の高い、StreamHandlerとFileHandlerの二種類をインポートしています。※ハンドラの詳細は、記事の後半で説明します。
Step2. logger作成と設定
<strong>logger = getLogger(__name__)
logger.setLevel(DEBUG)</strong>
次にgetLogger関数を用いてインスタンスを生成し、loggerオブジェクトを作成します。
かっこ()の中はloggerの名前。なんでもOKです。
続いてsetLevelメソッドを使って、「ロギングレベル」を設定します。
loggerオブジェクトは、「そこでログをとるのがどれくらい重要か?」という重要性レベルのようなもと設定可能で、重要性の低いものからDEBUG、INFO、WARNING、ERROR、CRITICALの5段階に分けられます。
そして「ロギングレベル」の設定は、「どのレベル設定以上のログをとるか」を決めること。
例えば一番下のDEBUGレベルに設定すれば、全レベルのloggerが働き、ログをとります。
※文章で読むとややこしいですが、実際にコードを動かせば単純です
もっと詳しく知りたい人は基本 logging チュートリアルが参考になります。
Step3. ログの出力フォーマットを設定
<strong>log_fmt = Formatter("%(asctime)s %(name)s %(lineno)d [%(levelname)s][%(funcName)s] %(message)s")</strong>
次にFormatterオブジェクトをつかって、ログの出力形式を設定します。
詳しくは公式ドキュメントをご覧ください。
設定自体は好みですのでご自由に。
上の設定だと出力は:
(日時)(logger名)(何行目のloggerか)(重要性レベル)(メッセージ)
となり、実際の出力は以下のようになります。
2022-05-26 03:24:05,161 main 33 [INFO][] start
2022-05-26 03:24:09,006 main 43 [INFO][] data preparation end (595212, 58)
2022-05-26 03:24:31,209 main 76 [INFO][] train end
2022-05-26 03:24:34,087 main 83 [INFO][] test data load end (892816, 58)
2022-05-26 03:24:34,330 main 87 [INFO][] submit sanple data load end (892816, 2)
2022-05-26 03:24:35,867 main 91 [INFO][] end
ソースコードは僕のGithubに挙げているので参考にしてみてください。
https://github.com/tsukudan/kaggle_code/blob/main/protos/cross-val.py
Step4. ハンドラの設定とloggerへの追加
<strong>#4-1
stream_handler = StreamHandler()
stream_handler.setLevel(INFO)
stream_handler.setFormatter(log_fmt)
logger.addHandler(stream_handler)
#4-2
file_handler = FileHandler("../train.py.log" , "a")
file_handler.setLevel(DEBUG)
file_handler.setFormatter(log_fmt)
logger.addHandler(file_handler)</strong>
最後に好みの機能を搭載しているハンドラオブジェクト作成していきます。
といってもやることは単純。
まずimportしたハンドラクラスそ変数に代入し、インスタンスを作成します。※StreamHandlerとFileHandlerの細かい設定は後述
続いてsetLevelメソッドとsetFormatterメソッドを使って、「ハンドラの機能を作動させるログレベル」と「出力の形式」を設定します。
ここまででloggerの設定は終わり。
ここから先は「ハンドラってなんなの?」という疑問が残って眠れないひとに向けた内容です。
ハンドラとは?
ハンドラは、loggerがとったログをメッセージとして外部に出力する役割を担っています。
実はloggerによって取られたログは、loggerの中に記録されているだけ。
ハンドラがいて初めて、僕たちの目に見えるようになるのです。
詳しく公式ドキュメントのLogging Flowを参照。
よく使うハンドラ:StreamHandlerとFileHandler
ハンドラの中でもStreamHandlerとFileHandlerは特に使用頻度が高いです。(というかこれ以外の需要があるのか?)
StreamHandlerはログをコンソールに出力します。
FileHandlerは指定したファイルの中にログを出力し、ログを別ファイルの中に記録することが可能です。
最後にそれぞれのハンドラの今回のコード詳細を解説。
StreamHandler
stream_handler = StreamHandler()
stream_handler.setLevel(INFO)
stream_handler.setFormatter(log_fmt)
logger.addHandler(stream_handler)
今回のStreamHandlerはINFOレベルに設定されていることから、コンソールにはDEBUGレベルのログは出力されません。
またフォーマットはloggerの設定と全く同じものが使われています。
もちろん変えることも可能です。
FileHandler
file_handler = FileHandler("../train.py.log" , "a")
file_handler.setLevel(DEBUG)
file_handler.setFormatter(log_fmt)
logger.addHandler(file_handler)
FileHandlerのインスタンス生成時に渡す引数は:
(”ログ出力を保存するファイルのパス”, mode = “a” )の形式。
modeは保存形式を指定するもので、デフォルト値がmode = “a”。他にもmode = “w”などもあります。
二つの違いは、同じコードを何度も実行した場合を考えるとわかりやすい。
mode = “a”の場合は、保存先のファイルの中に追記されていきます。つまりコードを実行する回数が多いほどファイル内のログの記録も増えていきます。
一方でmode = “w”の場合、コードを実行するたびに新しいファイルが作られます。つまりログの記録は常に一回分しか残りません。
>> pythonのloggingモジュールでlogファイルを毎回新調したい
またレベルがDEBUGに設定されているので、ログファイルにはすべてのレベルのログが記録されます。
Python loggingの使い方まとめ
今回はコード実行中のイベントごとの実行時間を記録できるloggerの使い方を分かりやすく解説しました。
loggerをうまく使えば、実行時間の記録だけでなく、バグの発見、Kaggleコンペ中の試行錯誤の記録を残したりなど活用法は様々です。
ぜひとも、使えるようにしておきましょう。