価値を提供し続けるために

価値を提供し続けると言うことはどう言うことであろうか？僕たちはIT屋さんなので、もしITIL的な解釈をするのであれば、デリバーしたシステムが継続して稼働することである。PMBOKでもプロジェクト開始前にベネフィットマネジメント（つまりプロジェクト完了後にいつになったら利益が生み出せるのか？）の計画が求められ、デリバー後に想定外のダウンタイムが発生することなどもってのほかである。
ここでは、価値を提供し続けるためにはいかに想定外のダウンタイムを発生させないか、ダウンはせずとも性能劣化をさせないために何を準備しておけばいいかロギング戦略を中心にシステムやサービスのオブザーバビリティ（可観測性）について話をする。
※タイトル画像の絵は2023/1/3現在未発売であり、この本のレビューやこの本の内容を元にした考察ではありません。

オブザーバビリティエンジニアリングのためのログ

オブザーバビリティエンジニアリングは文字通りエンジニアリングである。エンジニアリングの役は下記の通り。

可観測性を設計するため科学的な知識を当てはめる行動だ。今一度その目的を言うと、システムやサービスの価値を提供し続けること、そのためにはサービスの停止やスローダウンにつながる兆候をログとして出力し、それを対応する適切な部署や人に連絡する必要がある。出力する内容は今何が起きているかと言うことやプログラムのスタックトレースを出力するだけではすぐにネクストアクションが取れる訳ではないので、正常な状態に戻すためのネクストアクションが即座に取れる情報も合わせて出力しなければいけない。ここでは次の3つの観点で議論をする。

1. 警告・異常系ログ

2. 正常系ログ

3. デバッグログ

すべきもの

警告・異常系ログの出力

異常系のログは必ず出さなければいけない。しかし出力すればなんでもいいと言う訳ではない。出力する目的はあくまでも価値を提供し続けること＝サービスが稼働し続けることであり、もしシステム障害や障害につながる状況が発生するのであれば、即座にネクストアクションにつながる情報も合わせて出力しなければならない。
いくつか例を出してその良し悪しを説明する。
例1. ログを出力しない。

try:
    con.connect('user:password@xxxx')
    con.execute('select * from test')
except Exception as e:
    raise e

正直こんなコードを各人はいないかと思われるが、実際いる。特にJavaのように文法的に何かしらの例外をキャッチするようにクラスメソッドが実装されており、それを利用したいがために仕方なく例外をキャッチするよう記述はするが、その後は何もしない。これの何が悪いかと言うと、障害を復旧させるためのネクストアクションを取るための情報がないのである。上記のコードは極端な例ではあるが、そもそもデータベースへの認証エラーなのか？それとも接続障害なのか？はたまたSQL文の実行時のエラーなのか色々な選択肢が考えられ、障害を特定するために検証することがたくさん出てくることになる。

正常系ログの出力

正常系のログも必ず出さなければいけない。ただし、目的が警告・異常系のログとは根本的に異なる。
正常系のログを出す目的は主に二つ。次の2つを実現するためのメトリクスの収集のためだ。

1. 監査

2. 統計

監査は主に認証などの処理で出力する。たとえIDとパスワードが合っていたとしても、それが異常な時間帯（＝通常の運用時間外）のログインや、異常な回数（認証のセッションタイムアウトが30分にもかかわらず、1分間に複数回の認証成功）などが合った場合は、何かよくないことが発生していると判断せざるを得ない。しかしこう言った状況を判断する要望・要件が最初からプロジェクトオーナーやプロダクトオーナーから提示されることはないため、機能化されることもない。そのため、ログを出力しておき、後ほどそれが適正かどうか監査に役立てる必要がある。
一方統計は、システムのパフォーマンスや利用頻度を調査するために出力する。特定の機能のスプリットタイムや、利用頻度を記録しておき、統計情報をまとめて把握しておくことで、今後どのような対策を取らないといけないのかの目安ができ、次の計画のインプットとなる。また性能試験をするときは、これらの統計情報を元にして性能試験のシナリオやテストデータを作成することになる。闇雲に負荷をかけてもそれが妥当かどうかは誰も判断できないが、こうした統計情報を元に性能試験をイテレートすることでシステムの可用性の向上＝価値を提供し続けることにつながるのである。
なお、スプリットタイムは以前であればデバッグログやトレースログとして出力していたかもしれない。これは単体試験レベルの話をしているのであれば正しい。しかし僕が今議論している価値を提供し続けることを目的とした場合、INFOレベルで出力するのが適切である。

してはいけないもの

デバッグログの出力

デバッグログは残してはいけない。トレースログも然りである。本来はこれらはデバッガーを用いて確認される内容であり、ログで確認するものではない。
無用なログが多くなると言うことは、ログの中から必要な情報を検索する上でノイズとなる。ノイズがあると、ネクストアクションを取るのに必要な情報を探す時に認知負荷を上げることになり、初動の遅延につながるからである。
また、デバッグログやトレースログはコードの可読性を悪くする。プログラマーは本来必要最低限のビジネスロジックを記述することに注力すべきであり、それはそのまま保守性へとつながるからである。ビジネスとジック以外が記載されたコードは可読性が悪く、それを保守するものの認知負荷をあげる。もし根本的にコードを修正しないといけないバグが検出された場合、またそのコードを変更要望に合わせて修正する時にロジックをコードを追って理解することを阻害するものは排除しなければならない。

ログレベルに関する誤解

昔はログをローカルシステムのディスクに書き出していた。つまりログを出力すれば出力するほどDisk I/Oを増やし、システムパフォーマンス低下の原因に繋がった。そのためログレベルを設定し開発環境やステージング環境ではINFOレベルやDEBUGレベルまで、商用環境ではWARNレベルやCRITICALレベルにしか設定しない設計・設定も見受けられた。
システムの多重化やマイクロサービス化が進んだ現代はどうであろうか？ログはFluentdやAWS Cloud Watchを利用して1箇所に集約される。これはローカルのシステムにログを書き出すと、多重化されたシステムのどこに必要なログがあるのか探すのが現実的ではなく、またDockerのような環境を使用しているとコンテナがダウンするとログそのものが消失してしまう恐れがあるためだ。
Network I/Oのパフォーマンス >>>>>>>>>>>>>>> Disk I/Oのパフォーマンスであることを踏まえると、必要であるならばログの出力をログレベルで絞ると言ったことはすべきではない。ただし、これはログレベルを考える必要がないと言っている訳ではなく、Next Actionを取りやすくするためには、やはりログレベルはきちんと整理・設計されて然るべきである。

まとめ

ログは目的もなく漫然と出力しても、有効に活用できないどころか可観測性の観点からノイズとなる。さらに言うとコードの可読性の低下にも繋がりいいことがない。
ログは必要最低限、目的を果たすために必要な情報を出力すること。そしてログの内容を設計する場合、常にネクストアクションを想定して、ログのメッセージを決めなければいけない。また正常系のログであってもそれをどのように集計し、活用するかを設計することで可観測性を考慮した設計といえ、またそれによってサービスを稼働し続ける＝価値を提供し続けることが可能となるのである。

One More Plus

正常系のログを出力するだけでは、正直片手落ちになる恐れもある。これを防ぐためには事前に性能試験をしておく必要があり、ここではそもそもの性能要件を満たすかどうかといった試験だけではなく、どこまで負荷をあげたら正常に動作しなくなるか、瞬間的にはどの程度負荷をかけても耐えることができるかと言ったこともメトリクスとして測っておく必要がある。