この記事は Let’s talk about logging の翻訳です。
Nate Finch による Go Forum への投稿で始まったスレッド を見てこの記事を書くことにしました。
この記事は Go を対象にしていますが、あなたのいままでのやり方を振り返ってみたら、同じ考え方がより広く適用できると思います。
なんでこんなに足りないの？
訳注: "Why no Love?" を、「（愛されてないから）機能が足りない」というニュアンスで解釈しましたが、自信が無いです。
Go の log パッケージ はレベル付きのロギングを提供していません。なので手動で debug, info, warn, error のようなプレフィックスを書く必要があります。
また、 Go はパッケージごとにログの出力レベルを制御する方法も提供していません。
比較対象としてサードパーティーのロギングライブラリを見てみましょう。
Google の glog は次のレベルをサポートしています:
- Info
- Warning
- Error
- Fatal (プログラムを終了する)
Juju で開発されている loggo は次のレベルを提供しています:
- Trace
- Debug
- Info
- Warning
- Error
- Critical
Loggo はログの verbosity をパッケージごとに調整する機能を持っています。
この2つのライブラリは、明らかに他の言語のロギングライブラリの影響を受けています。
これらの流れをたどると、 syslog(3) や、たぶんさらに過去にまで遡れると思います。
そして私は、このやり方は間違っていると考えます。
私は、 全ての ロギングライブラリは、 多すぎる 機能を提供しているという点で間違っています。プログラマーが本当に考えなければならないといけないことは、ログを読む人とのコミュニケーションです。目が回るような大量のオプションは、その一番大切な事からプログラマーの目をそらせてしまいます。
良いロギングパッケージは、もっと少ない機能、もっと少ないレベルだけを持つべきだと考えます。
warning について
まずは一番簡単なレベルからはじめましょう。誰も warning レベルを必要としていません。
だれも warning を読みません。なぜなら、その意味合い上、何も問題が起こってないのですから。
もしかすると、将来なにか問題が起こるかもしれません。でもそれはだれか他人の問題です。
あなたがレベル付きロギングパッケージを使っているとしたら、ログレベルを warning に設定する理由はありますか？
たぶん info か error レベルを使うはずです。
ログレベルを warning に設定しているとしたら、きっとエラーを warning レベルで出力してしまっているのでしょう。
warning レベルを除去しましょう。それはただの情報表示のためのメッセージか、エラーです。
fatal について
fatal レベルは、ログメッセージを書いて、 os.Exit(1) を呼びます。これは次のようなことを意味します:
- 他の goroutine の defer 文は実行されません
- バッファの内容はフラッシュされません
- テンポラリファイルやディレクトリは削除されません
基本的には、 log.Fatal は panic と同じ意味合いの、より情報が少ないバージョンです。
ライブラリが panic を使うべきではない1というのは一般的に受け入れられていますが、
log.Fatal2を呼び出すのも同じ効果を持つので、同じく行儀が悪いです。
このクリーンアップ問題について、シャットダウンハンドラを使って解決する提案は、ログシステムを
クリーンアップ操作を行うすべての場所に密結合させてしまうので、関心事の分離に違反します。
fatal レベルのログを出力しないでください。代わりに error を呼び出し元に返してください。
error が main.main まで戻ったら、そこが全ての終了前のクリーンアップ処理を制御する正しい場所です。
error について
エラーハンドリングとロギングは密接に関係しています。
そのため、error レベルでログに書くというエラー処理が簡単に正当化されがちですが、私は反対します。
Go では、関数やメソッドが error を返した場合、現実的な選択肢は次の2つです:
- エラーに対処する
- さらに呼び出し元にエラーを返す。エラーを返す前に他のエラー値でラップするかもしれないけれど、ここでの議論には関係しない。
エラーをログに書くことでエラーに対処した場合、それはもうエラーではありません -- もう処理済みなのですから。
エラーをログに書くことがエラー処理なら、それをエラーとしてログに書くことはもう適切ではありません。
納得してもらうために、次のコード例を見てください:
err := somethingHard()
if err != nil {
log.Error("oops, something was too hard", err)
return err // what is this, Java ?
}
エラーは処理するか呼び出し元に返すかしているはずなので、 error レベルでログを書くべきではないです。
私は、何かの条件が発生したことをログに書くべきではないと言っている訳ではありません。 log.Error の目的が log.Info と同じになっていると言いたいのです。
if err := planA(); err != nil {
log.Infof("could't open the foo file, continuing with plan b: %v", err)
planB()
}
私は、 エラーをログに書くな とは言っていません。今問題にしているのは、ミニマルなロギングAPIは何かということです。
そして error レベルで書かれているログの圧倒的大多数が、単にエラーに関係しているという理由だけで error レベルを利用していると考えます。
そういったログは実際には情報提供のためのものなので、ロギングAPIから error レベルを削除することができます。
他に何が？
warning を無視し、 error レベルは必要ではないことを議論し、 log.Fatal() の動作はアプリケーションのトップレベルで行うべきだということを示しました。
後何が有るでしょう？
私は、ログするべき情報は次の2つだけだと考えます:
- 開発者がソフトウェアを開発中、デバッグ中に利用する情報
- ユーザーがソフトウェアを利用するときに利用する情報
明らかに、これらは debug と info レベルが意味するものです。
log.Info は単に出力にメッセージを書くべきです。そのメッセージはユーザーにとって有益なはずなので、その出力を止めるオプションを提供するべきではありません。
対処できないエラーが発生した場合、それはプログラムを終了する main.main にまで返されるべきです。
最後のログメッセージに FATAL というプレフィックスをつけたり、 os.Stderr に直接 fmt.Fprintf を使って出力する必要があるという不便さは、ロギングパッケージに log.Fatal メソッドを追加する十分な理由ではありません。
log.Debug は完全に別の問題です。これは開発者やサポートエンジニアのためのものです。
開発中には、デバッグ用の文は、 trace や debug2 レベルに頼ることなく書けるべきです。
ログパッケージは debug 出力の有効／無効を、パッケージ単位やより小さい単位で制御できるようにするべきです。
おわりに
これが twitter poll なら、あなたに次の問題を出しました。
- ロギングは重要だ
- ロギングは難しい
実際には、ロギングは両方です。
解決策は、分解し、気を散らせる不要な要素を情け容赦なく削ることです。
あなたはどう思いますか？ Is this just crazy enough to work, or just plain crazy ?
訳注: 最後の文の解釈に自信が持てない＆良い訳も思いつかないので訳しませんでした。誰か良い訳があれば教えて下さい。