三つの仮説のうち二つは、データで30分あれば消せた

目標

PodのPrometheusの12時間分に入っている1回の事故を、手順どおりに調査します。時刻を相対時刻で確定し、影響を数え、仮説3つと予測を先に書いたあと、2つを棄却し、残った1つを別の指標で確証し、タイムラインとポストモーテムを残し、最後にもっと早く捉える検知器を書いて、同じデータで検証します。

なぜ重要なのか

障害調査に時間がかかる理由は、たいていデータがないからではなく、順序がないからです。仮説を先に語ってあとからデータを見ると、解釈が仮説に引きずられます。逆に「この仮説が真なら何が見えるはずか」を先に書いておけば、データがその形でないときに仮説を捨てられ、反証は確証よりはるかに安いのです。その前に必ず来るべきものが、時刻を確定することです。開始と終了がなければ、「事故区間のリクエスト率」のような言葉がそもそも計算できません。そして、すべての時刻は相対時刻で書きます。絶対時刻は、タイムゾーンとサマータイムとログサーバーの時計に乗って、振り返りを台無しにします。最後に残すのは原因だけではありません。棄却した仮説と棄却した根拠、そして検知が何分遅れたかが、次の四半期に何を直すかを決めます。

ステップ

検知条件を/root/obs-incident-triage/onset.promqlに書いてください。5分のウィンドウで5xxが占める割合です(しきい値との比較は、入れても抜いてもかまいません)。そのあと、直近12時間を1分間隔のレンジクエリで走査して、この比率が0.05を超えた区間を探し、/root/obs-incident-triage/01-onset.txtに4行を書いてください。start_minutes_ago=(最初に超えた時刻が今から何分前か、整数)、end_minutes_ago=(最後に超えた時刻)、duration_min=(超えた分の個数)、peak_ratio=(その区間の最大の比率、小数第4位)です。絶対時刻は書かないでください。
条件が真だった分だけを選んで、その分のincrease(...[1m])の値を足してください。/root/obs-incident-triage/02-impact.txtに3行failed_requests=(5xxの件数、整数)、total_requests=(全リクエスト数、整数)、failed_share=(2つの比、小数第4位)を書き、/root/obs-incident-triage/02-handlers.tsvに、ハンドラー4つを1行ずつ、タブで区切った3列<handler><탭><5xx 건수><탭><전체 5xx 중 비중>で書いてください(プレースホルダーは、タブ、5xxの件数、全体の5xxに占める割合です。割合は小数第4位)。ウィンドウを時刻で切って数えると、境界で件数がまるごと抜け落ちます。分を選んで足してください。
/root/obs-incident-triage/03-hypotheses.tsvに3行を書いてください。各行はタブで区切った4列<id><탭><가설><탭><예측><탭><검증에 쓸 PromQL>で(プレースホルダーは、id、タブ、仮説、予測、検証に使うPromQLです)、idはh1・h2・h3です。仮説は、h1 = 特定のハンドラーのコードの欠陥、h2 = トラフィックの急増による過負荷、h3 = 注文キューの下流依存の停滞です。予測の列には、「この仮説が真なら、データに何が見えるはずか」を25文字以上で書き、最後の列には、それを確認できるクエリを書きます。h1のクエリはhandlerで分ける必要があり、h2はhttp_requests_totalのrate、h3はqueue_depthを見る必要があります。
3つの仮説のうち、データで棄却できる2つを選んで、/root/obs-incident-triage/04-refuted.tsvに2行で書いてください。各行はタブで区切った4列<id><탭><측정값><탭><판정><탭><근거>で(プレースホルダーは、id、タブ、測定値、判定、根拠です)、判定はrefutedです。測定値はidごとに決まっています。ハンドラーの仮説はハンドラーごとの5xx率(5分ウィンドウ)の12時間の最大値どうしの、最大−最小(小数第4位)、トラフィックの仮説は事故区間の平均1秒あたりリクエスト数 ÷ 事故開始直前1時間(最後の5分は除く)の平均(小数第4位)です。根拠は25文字以上で、数字を含める必要があります。
/root/obs-incident-triage/05-confirm.txtに5行を書いてください。hypothesis=(残った仮説のid)、queue_peak=(12時間のqueue_depthの最大値、整数)、queue_baseline=(同じ12時間の中央値、整数)、overlap_min=(キューの深さが100を超えた分のうち、エラー条件も真だった分の個数、整数)、evidence=(40文字以上で、数字を含む1行)です。確証は、最初の条件式とは別の指標で行う必要があります。
/root/obs-incident-triage/06-timeline.tsvに4行を書いてください。各行はタブで区切った3列<event><탭><minutes_ago><탭><근거>で(プレースホルダーは、event、タブ、minutes_ago、根拠です)、eventはimpact_start・detect・impact_end・latency_tail_startの4種類です。detectは今使っているアラート(5分ウィンドウの5xx率が0.10を超える状態が10分継続)が鳴った時刻で、latency_tail_startはp99レイテンシが1秒を超え始めた時刻です(エラーの事故とは別の出来事です)。minutes_agoは整数で、根拠の列には、その値を出した指標やクエリの名前を10文字以上で書きます。
/root/obs-incident-triage/07-postmortem.txtに5行を書いてください。time_to_detect_min=(影響の開始からアラートまで何分か、整数)、time_to_recover_min=(影響の開始から影響の終了まで何分か、整数)、impact=(40文字以上、数字を含める)、why_late=(検知が遅れた理由、60文字以上)、next_change=(次に変えること、60文字以上)です。2つの数字は、ステップ6のタイムラインからそのまま出ます。
/root/obs-incident-triage/rules/faster.ymlに、fasterグループとFastErrorRatioアラートを書いてください。expr・for・labels.severity・annotations.runbook_urlが必要で、forは<정수>mの形式です(プレースホルダーは整数です)。このルールは、今のアラート(5分ウィンドウ・0.10・10分継続)より3分以上早く鳴る必要があり、同じ12時間の中で、事故区間の外で鳴った分が10分を超えてはなりません。そして/root/obs-incident-triage/08-gain.txtに、3行baseline_detect_min_ago=、new_detect_min_ago=、gain_min=(2つの値の差)を整数で書いてください。

参考

作業ディレクトリは/root/obs-incident-triageです。なければ先に作成してください。
クエリ1回はpromq "<PromQL>"で投げます。このラボはレンジクエリを多く使うので、curl -sG --data-urlencode "query=..." --data-urlencode "start=..." --data-urlencode "end=..." --data-urlencode "step=60" http://127.0.0.1:9090/api/v1/query_rangeの形を手に慣らしておいてください。
PodのPrometheusには12時間分があらかじめ入っていて、その中に事故が1回入っています。テールレイテンシだけが跳ねる区間がもう1つ別にありますが、それはこの事故とは別の出来事です。
絶対時刻を使わないでください。すべての時刻は「今から何分前」で書きます。採点ツールもそう見ます。
よくある間違い: 事故区間を時刻で切って数えてしまうこと。境界がずれると失敗件数がまるごと抜け落ちます。条件が真だった分を選んで足してください。
よくある間違い: 残った仮説を、最初に書いた条件式でもう一度確認してしまうこと。それは確証ではなく、同じ言葉の繰り返しです。
Postmortem Culture (SRE Book第15章)・Effective Troubleshooting (SRE Book第12章)・Managing Incidents (SRE Book第14章)・Alerting rules・Query API (range queries)

開始時刻をデータで確定する

検知条件を/root/obs-incident-triage/onset.promqlに書いてください。5分のウィンドウで5xxが占める割合です(しきい値との比較は、入れても抜いてもかまいません)。そのあと、直近12時間を1分間隔のレンジクエリで走査して、この比率が0.05を超えた区間を探し、/root/obs-incident-triage/01-onset.txtに4行を書いてください。start_minutes_ago=(最初に超えた時刻が今から何分前か、整数)、end_minutes_ago=(最後に超えた時刻)、duration_min=(超えた分の個数)、peak_ratio=(その区間の最大の比率、小数第4位)です。絶対時刻は書かないでください。

レンジクエリは、/api/v1/query_rangeにstart・end・stepを付けて投げます。step=60なら、1分に値が1つ出ます。date +%sで今を秒で得て、43200を引けば12時間前です。結果のJSONは、jq -r '.data.result[0].values[] | "\(.[0])\t\(.[1])"'で表にできます。

影響範囲を数える: 何件が失敗し、どこに集中したか

条件が真だった分だけを選んで、その分のincrease(...[1m])の値を足してください。/root/obs-incident-triage/02-impact.txtに3行failed_requests=(5xxの件数、整数)、total_requests=(全リクエスト数、整数)、failed_share=(2つの比、小数第4位)を書き、/root/obs-incident-triage/02-handlers.tsvに、ハンドラー4つを1行ずつ、タブで区切った3列<handler><탭><5xx 건수><탭><전체 5xx 중 비중>で書いてください(プレースホルダーは、タブ、5xxの件数、全体の5xxに占める割合です。割合は小数第4位)。ウィンドウを時刻で切って数えると、境界で件数がまるごと抜け落ちます。分を選んで足してください。

ステップ1で作った比率の表から、値が0.05を超えるタイムスタンプだけを抜き出しておけば、別の照会結果とそのタイムスタンプで突き合わせて足せます(awk 'NR==FNR{m[$1]=1;next} ($1 in m){s+=$2}')。ハンドラー名は、/api/orders・/api/users・/api/search・/healthzです。

仮説より先に、予測を書く

/root/obs-incident-triage/03-hypotheses.tsvに3行を書いてください。各行はタブで区切った4列<id><탭><가설><탭><예측><탭><검증에 쓸 PromQL>で(プレースホルダーは、id、タブ、仮説、予測、検証に使うPromQLです)、idはh1・h2・h3です。仮説は、h1 = 特定のハンドラーのコードの欠陥、h2 = トラフィックの急増による過負荷、h3 = 注文キューの下流依存の停滞です。予測の列には、「この仮説が真なら、データに何が見えるはずか」を25文字以上で書き、最後の列には、それを確認できるクエリを書きます。h1のクエリはhandlerで分ける必要があり、h2はhttp_requests_totalのrate、h3はqueue_depthを見る必要があります。

予測は、「何が見えたら、この仮説が間違っていると言えるか」を裏返して書くと、うまく出てきます。たとえば1つのハンドラーの欠陥なら、他のハンドラーは平常のはずで、全部がそろって跳ねているなら、その仮説は消えます。3つのクエリは、実際に結果が出る必要があります。採点ツールが直接投げてみます。

データで2つの仮説を棄却する

3つの仮説のうち、データで棄却できる2つを選んで、/root/obs-incident-triage/04-refuted.tsvに2行で書いてください。各行はタブで区切った4列<id><탭><측정값><탭><판정><탭><근거>で(プレースホルダーは、id、タブ、測定値、判定、根拠です)、判定はrefutedです。測定値はidごとに決まっています。ハンドラーの仮説はハンドラーごとの5xx率(5分ウィンドウ)の12時間の最大値どうしの、最大−最小(小数第4位)、トラフィックの仮説は事故区間の平均1秒あたりリクエスト数 ÷ 事故開始直前1時間(最後の5分は除く)の平均(小数第4位)です。根拠は25文字以上で、数字を含める必要があります。

ハンドラーが4つなら、最大値も4つです。1つのハンドラーだけが壊れていれば、この4つが大きく開き、共通の原因ならほぼ同じです。トラフィックの比は、1の近くなら「急増ではない」という意味です。2つの数字とも、12時間のレンジクエリを走査して求めればよく、事故区間は、ステップ1で選んだ分をそのまま使います。

残った仮説を別のシグナルで確証する

/root/obs-incident-triage/05-confirm.txtに5行を書いてください。hypothesis=(残った仮説のid)、queue_peak=(12時間のqueue_depthの最大値、整数)、queue_baseline=(同じ12時間の中央値、整数)、overlap_min=(キューの深さが100を超えた分のうち、エラー条件も真だった分の個数、整数)、evidence=(40文字以上で、数字を含む1行)です。確証は、最初の条件式とは別の指標で行う必要があります。

中央値は、値だけを取り出して並べ替え、真ん中を選べばよいのです。重なった分の個数は、ステップ1で選んだ分の集合と、キューが100を超えた分の集合の積集合の大きさです。2つの区間がほぼ完全に重なるなら、同じ出来事である可能性が高く、それがエラー指標と独立した2つ目の証拠になります。

機械が読める事故タイムライン

/root/obs-incident-triage/06-timeline.tsvに4行を書いてください。各行はタブで区切った3列<event><탭><minutes_ago><탭><근거>で(プレースホルダーは、event、タブ、minutes_ago、根拠です)、eventはimpact_start・detect・impact_end・latency_tail_startの4種類です。detectは今使っているアラート(5分ウィンドウの5xx率が0.10を超える状態が10分継続)が鳴った時刻で、latency_tail_startはp99レイテンシが1秒を超え始めた時刻です(エラーの事故とは別の出来事です)。minutes_agoは整数で、根拠の列には、その値を出した指標やクエリの名前を10文字以上で書きます。

継続条件(for)は、「条件が連続して真の分が、それだけ積み上がったあと」という意味です。1分間隔の表で、連続して真の個数を数えていき、11個目になる分が、アラートが鳴る時刻です。p99は、histogram_quantile(0.99, sum by (le) (rate(http_request_duration_seconds_bucket[5m])))で求めます。

ポストモーテム: 検知はなぜ遅れたか

/root/obs-incident-triage/07-postmortem.txtに5行を書いてください。time_to_detect_min=(影響の開始からアラートまで何分か、整数)、time_to_recover_min=(影響の開始から影響の終了まで何分か、整数)、impact=(40文字以上、数字を含める)、why_late=(検知が遅れた理由、60文字以上)、next_change=(次に変えること、60文字以上)です。2つの数字は、ステップ6のタイムラインからそのまま出ます。

検知遅延は、アラートのウィンドウ長と継続条件が作る値です。5分のウィンドウはそれ自体が遅延を生み、forがその分を加えます。next_change=には、次のステップで実際に作るルールの方向を書いておくと、つながります。復旧時間は、事故がどれだけ長かったかであって、人が何をしたかではありません。

もっと早く捉える検知器を書いて、同じデータで検証する

/root/obs-incident-triage/rules/faster.ymlに、fasterグループとFastErrorRatioアラートを書いてください。expr・for・labels.severity・annotations.runbook_urlが必要で、forは<정수>mの形式です(プレースホルダーは整数です)。このルールは、今のアラート(5分ウィンドウ・0.10・10分継続)より3分以上早く鳴る必要があり、同じ12時間の中で、事故区間の外で鳴った分が10分を超えてはなりません。そして/root/obs-incident-triage/08-gain.txtに、3行baseline_detect_min_ago=、new_detect_min_ago=、gain_min=(2つの値の差)を整数で書いてください。

ウィンドウを短くすれば早くなりますが、ノイズも大きくなります。そのため「空振りのページがないか」を、同じデータで一緒に確認する必要があります。平常時のエラー率がいくつかをステップ1の表で見て、それより十分に高いしきい値を選べば、短いウィンドウでも静かです。promtool check rules <파일>で、形式を先に確認してください(プレースホルダーはファイル名です)。