ログとメトリクスで様子を見る

ある通販サイトで、年に一度の大きなセールがありました。

朝10時、注文が一気に増えました。10時20分、お客様から「支払いができない」という電話が入りました。

そのとき初めて、チームは決済の失敗に気づきました。20分のあいだ、誰も知らなかったのです。このレッスンでは、お客様より先に気づく方法を学びます。

アプリは、注文や失敗などの出来事をログに一行ずつ書きます。一行には、時刻、重さ、内容が並びます。

重さは、INFO (ふつう)、WARN (注意)、ERROR (失敗) などで分けます。ERROR の行を探せば、何が失敗したかが分かります。

次のブロックで、セールの日のログを調べましょう。

mkdir -p tsuhan && cd tsuhan
cat > app.log <<'END'
10:00:01 INFO  注文を受け付けました order=1201
10:00:03 INFO  注文を受け付けました order=1202
10:00:04 WARN  決済の応答が遅い 2100ms
10:00:06 ERROR 決済に失敗しました order=1203
10:00:07 INFO  注文を受け付けました order=1204
10:00:09 ERROR 決済に失敗しました order=1205
10:00:10 WARN  在庫の確認が遅い 1800ms
END

echo "全部の行:"
wc -l < app.log
echo "エラーの行:"
grep -c 'ERROR' app.log
grep 'ERROR' app.log

# ERROR を WARN に変えて、遅い処理を探してみてください。

ログは細かいですが、一行ずつ読むと時間がかかります。そこで、5分ごとの件数や割合を数えます。これがメトリクスです。

よく見るのは、エラー率と応答時間です。エラー率は、エラーの数を全部の数で割り、100を掛けて出します。

下の表で、セールの朝の変化を追いましょう。

メトリクスを人がずっと見ている必要はありません。「エラー率が5%を超えたら知らせる」と決めておきます。この5%がしきい値です。

このサイトにそのアラートがあれば、10:05 過ぎに担当者のスマホが鳴りました。お客様の電話より、15分早く動けたはずです。