ログとメトリクスでインシデントを診断する

はじめに

有効な注文が失敗する一方で、在庫のリクエストは成功しています。このラボでは、アプリケーションのメトリクスを比較し、失敗したリクエストをログで追跡します。小さな設定の不具合を修復し、失敗の履歴を消さずに回復を確認します。

最初に CloudWatch Logs で失敗したリクエストを見つける と CloudWatch メトリクスでアプリケーションの健全性を測定する を完了してください。このラボには、独自のアプリケーションとインシデントが用意されています。

認定試験との関連

実験の概要

インシデントを再現し、対照と比較する

このステップでは、有効な注文リクエストが予期せず失敗する状況を再現します。独立して準備されたサービスには、通常の設定の不具合があります。ログとメトリクスは空の状態から始まるため、自分のリクエストから観察結果を得ます。

cd /home/labex/project

curl -i -H 'Content-Type: application/json' -H 'X-Request-ID: o05-failure-1' -d '{"sku":"apple","quantity":1}' http://127.0.0.1:5050/orders

curl -i -H 'Content-Type: application/json' -H 'X-Request-ID: o05-failure-2' -d '{"sku":"apple","quantity":1}' http://127.0.0.1:5050/orders

curl -i -H 'Content-Type: application/json' -H 'X-Request-ID: o05-control' -d '{"sku":"apple","quantity":1}' http://127.0.0.1:5050/inventory

同じ有効な架空の apple リクエストに対して、orders では HTTP 503、stock_unavailable が 2 回返り、inventory では HTTP 200、accepted が返るはずです。この対照は、orders に固有の問題を示唆します。システム全体の健全性を証明するものではありません。

最近の UTC の時間窓と、正確な Application ディメンションを使い、サーバーエラー数を比較します。メトリクスは頻度を集計し、個別のログは特定のレスポンスを説明できます。

START=$(date -u -d '15 minutes ago' +%Y-%m-%dT%H:%M:%SZ)
echo "$START"

クエリ時間範囲の終了時刻を UTC で保存します：

END=$(date -u -d '1 minute' +%Y-%m-%dT%H:%M:%SZ)
echo "$END"

aws cloudwatch get-metric-statistics \
  --namespace LabEx/O05 \
  --metric-name Errors \
  --dimensions Name=Application,Value=orders \
  --start-time "$START" \
  --end-time "$END" \
  --period 60 \
  --statistics Sum

aws cloudwatch get-metric-statistics \
  --namespace LabEx/O05 \
  --metric-name Errors \
  --dimensions Name=Application,Value=inventory \
  --start-time "$START" \
  --end-time "$END" \
  --period 60 \
  --statistics Sum

返された集計区間全体で、orders の Sum は 2、inventory の Sum は 0 になるはずです。/labex/o05-reference は変更せずに保持してください。

エラー数をリクエストログに結び付ける

このステップでは、集計された症状を、具体的な失敗リクエストに結び付けます。まず ERROR をクエリし、その後、正確なリクエスト ID をクエリします。引用符付きの語句は request_id トークン全体に一致するため、似た名前のリクエストが混ざることを防げます。

aws logs filter-log-events \
  --log-group-name /labex/o05-application \
  --filter-pattern ERROR \
  --query 'events[].{Time:timestamp,Message:message}'

aws logs filter-log-events \
  --log-group-name /labex/o05-application \
  --filter-pattern '"request_id=o05-failure-1"' \
  --query 'events[].message'

両方の失敗に application=orders、status 503、reason stock_unavailable が記録されています。メトリクスとログは、最近の時間窓内の同じリクエストを対象にしています。アプリケーションの設定を調べ、有効な apple リクエストとの不一致を見つけます。

cat app.json

orders の accepted_sku は pear になっています。Inventory は、独立して期待どおりの apple 設定を使っています。これは小さな設定の不具合です。サービスを置き換えたり観測を無効にしたりすると、症状を隠すだけで、修復にはなりません。

失敗したリクエストは apple を指定しましたが、orders の設定は pear を受け入れます。この不一致は stock_unavailable の検証可能な説明であり、正常な inventory リクエストは問題の範囲を絞る手掛かりになります。次のステップでは orders の設定を変更し、有効なリクエストを再送してこの説明を検証します。復旧の証拠には、設定変更だけでなく、成功した応答とそれに対応する新しいログが必要です。

設定を修復し、回復を確認する

このステップでは、受け付ける SKU を変更し、測定データの出力を有効に保ちながら業務の応答が回復することを確かめます。通常の設定を、修正した設定に置き換えます。

cat > app.json <<'JSON'
{"logging": {"enabled": true, "group": "/labex/o05-application", "stream": "requests"}, "metrics": {"enabled": true, "namespace": "LabEx/O05"}, "accepted_sku": "apple"}
JSON

curl -i -H 'Content-Type: application/json' -H 'X-Request-ID: o05-recovered' -d '{"sku":"apple","quantity":1}' http://127.0.0.1:5050/orders

aws logs filter-log-events \
  --log-group-name /labex/o05-application \
  --filter-pattern '"request_id=o05-recovered"' \
  --query 'events[].message'

HTTP 200、accepted と、同じ回復後のリクエスト ID を持つ INFO ログが返るはずです。過去の失敗は時間窓内に残ります。正常なリクエストは Errors=0 を公開するため、エラーの累積 Sum は 2 のままで、Requests は 3 に増えます。

START=$(date -u -d '15 minutes ago' +%Y-%m-%dT%H:%M:%SZ)
echo "$START"

クエリ時間範囲の終了時刻を UTC で保存します：

END=$(date -u -d '1 minute' +%Y-%m-%dT%H:%M:%SZ)
echo "$END"

aws cloudwatch get-metric-statistics \
  --namespace LabEx/O05 \
  --metric-name Errors \
  --dimensions Name=Application,Value=orders \
  --start-time "$START" \
  --end-time "$END" \
  --period 60 \
  --statistics Sum

aws cloudwatch get-metric-statistics \
  --namespace LabEx/O05 \
  --metric-name Requests \
  --dimensions Name=Application,Value=orders \
  --start-time "$START" \
  --end-time "$END" \
  --period 60 \
  --statistics Sum

AWS View には、実際のアプリケーション系列とリクエストログが表示されます。回復後のリクエスト ID を使い、新しい成功レスポンスと、保持された失敗の履歴を区別してください。

測定データの出力を止め、所有するロググループを削除する

このステップでは、計測を止め、インシデントのロググループだけを削除します。既存のメトリクスは保持期間に従って残ります。個別のメトリクスを削除する API はありません。

cat > app.json <<'JSON'
{"logging": {"enabled": false, "group": "/labex/o05-application", "stream": "requests"}, "metrics": {"enabled": false, "namespace": "LabEx/O05"}, "accepted_sku": "apple"}
JSON

aws logs delete-log-group --log-group-name /labex/o05-application

aws logs describe-log-groups --query 'logGroups[].logGroupName'

aws logs get-log-events \
  --log-group-name /labex/o05-reference \
  --log-stream-name platform \
  --query 'events[].message'

/labex/o05-reference だけが残り、元の INFO platform reference keep unchanged メッセージが返るはずです。正常に取得した一覧で、対象を限定した削除を確認できます。失敗したクエリでは、削除の完了を証明できません。

まとめ

対照を使ってインシデントを再現し、メトリクスの件数をリクエストログに結び付けました。アプリケーションの設定を修復し、新しい成功レスポンスを確認しました。対象を限定した削除を行うまで、過去の証拠を保持しました。

詳しくは、AWS 公式ドキュメントを参照してください：メトリクスの識別、ディメンション、統計; 用語と完全一致フレーズによるログイベントのフィルタリング。