はじめに
ログは「必要な情報が載っていれば問題ない」と思われがちですが、
実務で運用しているアプリでは ログの書き方ひとつで無駄な処理コストが発生します。
特にKotlinでは、一見きれいに見える書き方が
実はLoggerの最適化を殺してしまうケースがあります。
今回は、
「ログは出ていないのに処理が走っている」
という状況をきっかけに、Logger の正しい使い方を調べた話をまとめます。
コード(例)
logger.info("version: ${Util.getVersion}")
Kotlin的には自然で、実際にログも問題なく出力されます。
何が問題なのか?
ポイントは「ログレベルが無効な場合」
多くのLoggerは、ログレベル(DEBUGやINFOなどによる表示フィルタ)がOFFの場合、ログ出力処理自体をスキップします。
しかし、Kotlinの文字列補間は Loggerに渡す前に評価されます。
つまりこのコードでは:
logger.info("version: ${Util.getVersion}")
が必ず実行される&文字列の生成処理も必ず行われる
推奨の書き方
logger.info("value: {}", value)
このときLoggerは:
- INFOが有効か確認
- 無効なら引数を触らずにreturn(引数内の値がない場合はログが流れない)
- 文字列結合もしない