三つの信号は代替品ではなく調査の順序だ
一言でいうと
トレースは「どこ」、メトリクスは「いつ、どれだけ」、ログは「なぜ」に答えます。そのため調査の順序は固定です。メトリクス → トレース → ログの順に見ます。
なぜ必要なのか
障害が起きると、たいていの人はまずログを開きます。そして30分たってもまだログを読んでいます。ログは最も詳しい反面、最もコストが高く、何を探すべきかわからないまま開くと、ただのテキストの海です。
メトリクスが先になる理由は3つあります。値が安く、常に有効で、カーディナリティが低いことです。この3つを同時に満たすので、メトリクスはアラートの根拠にできる唯一のシグナルです。トレースはサンプリングされるため「今この瞬間に悪化している」ことを保証できず、ログは量が多すぎてリアルタイムの集計コストに耐えられません。
3つのシグナルは互いを置き換えません。あるのは、互いをつなぐ3本の橋だけです。メトリクスからトレースへはexemplarで渡り、トレースからログへはtrace_idフィールドで、ログからメトリクスへはeventフィールドで戻ってきます。この橋がなければ、3つのツールをそろえても、調査は相変わらず人の勘に頼ることになります。
どう動くのか
メトリクスで本当に重要な決定は、タイプの選択です。タイプの選択は好みの問題ではありません。間違えると、あとからやりたい計算が原理的に不可能になります。
- Counter: 単調に増加し、再起動すると0になります。値そのものには意味がなく、rateで見て初めて意味が生まれます。
- Gauge: 上下します。現在の状態を表します。
- Histogram: バケットカウンターの集合です。分位数を知りたい値に使います。
- Summary: インスタンス内ですでにパーセンタイルを計算して出力します。そのため複数のインスタンスを合算する方法がありません。サービスレベル指標には使えません。
レイテンシにゲージを使えない理由は、算数で確認できます。スクレイプ間隔が15秒で、1秒あたり500件のリクエストがあるなら、ゲージに保存されるのは7,500件のうち1件の値だけです。残りは最初から存在しなかったことになります。この時系列ではp99を求められず、あとで再処理しても復元できません。
現場での姿
デプロイの直後になるたびに、リクエスト率が急上昇したり急落したりするダッシュボードによく出会います。原因はほとんど毎回同じで、rateをsumの外側にかけていることです。rateは、値が直前のサンプルより小さくなったすべての瞬間をカウンターのリセットとみなし、減る直前の値を増加分に加算します。ところが先に合計を取ると、この補正がPodごとのカウンターではなく合計にかかります。Podが1つ再起動して合計が減ると、合計全体がリセットされたものとして処理されて偽の急上昇が生まれます。ほかのPodの増加に隠れて合計が減らなければ、リセットを見逃し、再起動したPodの累積値の分だけ低く出ます。正しい形はsum(rate(x[5m])) by (route)で、rate(sum(x)[5m:])は誤りです。
もう1つは、静かな誤答です。histogram_quantileからby (le)を抜くと、エラーなしに間違った数字を返します。誰も例外を目にしないので、そのパネルは何か月もダッシュボードに残ります。
カーディナリティがバジェットを決める
メトリクス設計で最も取り返しがつきにくい失敗は、ラベルに値が無限に多いものを入れることです。時系列の数は、ラベル値の組み合わせの積で増えます。ラベルが3つで、それぞれの値が10・5・4通りなら時系列は200本ですが、そこにユーザーIDをもう1つ付けた途端、ユーザー数の分だけ掛け算されます。ユーザーが10万人なら2,000万本です。
特に危険なラベルは決まっています。ユーザーID、リクエストID、セッションID、メールアドレス、IPアドレス、そしてパスを加工せずそのまま入れたものです。/orders/8213のように識別子が埋め込まれたパスをラベルにすると、注文1件ごとに時系列が1本ずつ増えます。正しい形は/orders/:idのようにルートパターンへ正規化することで、この正規化はフレームワークがルーティングするときにすでに知っている値なので、たいていはただで手に入ります。
こうして削った情報は捨てるのではなく、別のシグナルへ移します。それが3つのシグナルを分けておく理由です。
| 知りたいこと | 置く場所 | 理由 |
|---|---|---|
| このルートがどれだけ遅いか | メトリクス | 値の種類が少なく、常に有効である必要があります |
| この遅いリクエスト1件がどこで時間を使ったか | トレース | リクエスト単位の識別子が自然に付きます |
| そのリクエストを出したユーザーは誰か | ログ | 件数に上限がなく、検索で探します |
ヒストグラムには特に注意が必要です。バケット1つが時系列1本なので、バケット20個のヒストグラムにラベルの組み合わせが200通り付くと、その指標1つで4,000本を超える時系列ができます。そのためヒストグラムは、本当に分位数が必要な指標にだけ使い、バケット境界はサービスレベル目標の近くを細かく、それ以外は粗く取ります。目標が300msなのにバケットが100msの次にいきなり1秒へ飛ぶと、p99が300msを超えたかどうかを、そのヒストグラムでは判定できません。
症状はたいていダッシュボードではなく、ストレージ側に先に現れます。Prometheusのメモリが増え続け、スクレイプが時間内に終わらなくなり、クエリが遅くなります。そのときはtopk(10, count by (__name__)({__name__=~".+"}))で時系列の多い指標から数えてみると、犯人はほとんどの場合1つか2つです。
次のラボですること
ラボ環境には、本物のPrometheusサーバーが12時間分のデータを持った状態で起動しています。エラーが急増する区間が2回、レイテンシの裾だけが跳ねる区間が1回、そして着実に減り続けるディスクが入っています。
クエリをファイルに書くだけではなく、promqで実際に投げて、返ってきた数字を読みます。あなたが書いたクエリがその3つの事象を見つけ出せるかどうかが、正解かどうかを教えてくれます。PromQLが難しい理由は文法ではなく、間違ったクエリでもエラーなしにそれらしい数字を返してくるからです。