障害報告(対応済み)
10月13日(火)、同期が2時間止まりました
データベースの変更でテーブルがロックされ、再起動の繰り返しで解けず、同期が2時間止まりました。メモは無事です。
- 同期が2時間止まりました。メモは無事です。
- 再起動の繰り返しで、ロックが続きました。
- 起動時のマイグレーションを廃止。未対応は2件です。
何が、いつ、誰に影響したのか
修正済み、再発防止策は残り2件- 14:05デプロイで、メモのテーブルの変更が始まりました。
- 14:10同期が応答しなくなりました。
- 15:20チームが原因を突き止めました。
- 16:10同期が正常に戻りました。
つまり:同期は2時間止まりましたが、メモは失われず、修正も反映済みです。
- 何が起きて、誰に影響したのか書き込みは止まらず、端末間のコピーが止まりました。
- 2時間はどこにかかったのか気づくまで15分、原因の特定に55分、修正に50分。
- なぜ1つの変更が2時間の停止になったのか5つの段階の連鎖と、問題を長引かせた1つ。
- 何が直り、何が残っているのか再発防止策は5件。完了3件、作業中1件、判断待ち1件。
- どうすれば再発しないのか再発防止策は、それぞれ別の弱点をふさぎます。
第1章 / 全5章、約1分
何が起きて、誰に影響したのか
おさらい:同期は14:10から16:10まで止まりましたが、メモは失われていません。
ノートアプリは、接続がなくても動きます。読み書きは止まっていません。止まったのは、端末間で変更をコピーする部分です。
- 「同期待ち」というバナーが出ました。
- メモの閲覧と編集はできました。
- 変更は、各端末で送信待ちになりました。
- 別の端末には、古いメモが表示されました。
- 待っていた変更がすべて届きました。
- 消えたメモは0件です。
- 重複したメモは0件です。
- バナーは自動で消えました。
つまり:影響は2時間の遅れで、いちばん困ったのは端末を2台使う人でした。
上の数字の内訳を見る
- 14:10の時点で、190人がアプリを開いていました。
- そのうち74人が、停止中にメモを1件以上書きました。
- 送信待ちの変更は412件で、16:40までに412件すべてが届きました。
- アプリを週に使う人は約3,400人で、今回はその約6%に当たります。
この章のポイント:書き込みは止まらなかったため、起きたのはメモの損失ではなく、2時間の遅れでした。
第2章 / 全5章、約1分
2時間はどこにかかったのか
おさらい:アプリは動き続けたため、影響は2時間の遅れでした。
2時間は3つに分かれます。アラートがチームに届いたのは、同期が止まって15分後です。原因の特定に55分、修正のリリースに50分かかりました。
つまり:時間の半分近くは原因探しでした。アラートを分かりやすくすれば、いちばん時間を減らせます。
原因は見つけにくいものでした。ログに出ていたのはタイムアウトで、ロックではありません。しかも再起動のたびに、データベースにあった唯一の手がかりが消えました。
午後の動きを分刻みで見る
14:05 デプロイ開始。起動スクリプトがインデックスの構築を始める。
14:10 同期が応答しなくなる。ヘルスチェックがサーバーを再起動する。
14:22 2回目の再起動。構築が最初からやり直しになり、以後12分ごとに繰り返す。
14:25 同期のアラートがチームに届く。
15:20 原因を特定。起動のたびに、未完了の構築をやり直していた。
15:25 起動時にマイグレーションを実行しないデプロイを開始。
15:50 デプロイが終わり、サーバーが正常に起動する。
16:00 保存が再び通る。再試行の滞留が解消していく。
16:10 同期が正常に戻る。
16:40 最後の変更が届く。
この章のポイント: 120分のうち55分は原因探しだったので、アラートを分かりやすくするのがいちばん効果的です。
第3章 / 全5章、約1分
なぜ1つの変更が2時間の停止になったのか
おさらい:時間の半分近くは、ログに出ない原因を探すことに使われました。
1つの変更が4つの出来事を引き起こし、最後の1つが全体を長引かせました。連鎖を順にたどってください。赤い段階が、数分で済む話を数時間に変えました。
- マイグレーション
- データベースの構造を、コードで変更することです。
- インデックス
- 検索を速くするための索引です。大きなテーブルで構築すると、その間は保存が止まります。
- ロック
- 変更の実行中、ほかの処理を待たせる仕組みです。
- インデックス追加共有機能のために、デプロイで本番のメモのテーブルに追加しました。
- テーブルがロック構築中の約9分間、すべての保存が止まります。
- スマホが再試行30秒でタイムアウトし、190人分のアプリが一斉に再試行します。
- サーバーが再起動ヘルスチェックが応答なしと判断し、再起動します。
- 構築がやり直し起動のたびに未完了の変更を再実行するので、ロックが解けません。
つまり:構築だけなら9分で終わるはずでした。再起動の繰り返しが、それを2時間に延ばしました。
連鎖の数字の内訳を見る
- 検証用コピーのメモは2,000件で、構築は約1秒で終わりました。
- 本番のテーブルのメモは410,000件で、構築には中断なしで約9分かかります。
- サーバーは12分ごとに再起動したので、構築は最後まで終わりませんでした。
- サーバーが受け付けられる接続は50本です。再試行する190人分のアプリが、それを使い切りました。
この章のポイント: 9分のロックを2時間に延ばしたのは、インデックスではなく再起動の繰り返しでした。
第4章 / 全5章、約1分
何が直り、何が残っているのか
おさらい:再起動の繰り返しが、9分のロックを2時間に延ばしました。
振り返りで、再発防止策が5件出ました。障害を解消した対応は、すでに完了しています。
- 起動時のマイグレーションをやめる10月14日(水)に完了しました。今後は、人が手動でマイグレーションを1回だけ実行します。
- 本番サイズのコピーで事前検証完了。検証用コピーに400,000件のメモを入れたので、遅い変更はリリース前に見つかります。
- 3分でアラート完了。以前は、失敗が10分続くまで同期アラートが鳴りませんでした。
- インデックスをバックグラウンドで構築作業中。テッドさんが、保存が止まらない作り方に変更しています。期限は10月23日(金)です。
- デプロイを控える時間帯マーラさんの判断が必要です。平日の13:00〜17:00は、デプロイしないことにしますか?
つまり:今回と同じ形の障害は、もう起きません。残る2件で、別の障害が起きても影響を小さくできます。
起動スクリプトの変更点を見る
- run-migrations && start-server
+ start-server
# マイグレーションは今後、手動でのみ実行する: npm run migrate
この章のポイント: 3件が完了、1件が作業中、1件はマーラさんの判断待ちです。
第5章 / 全5章、約1分
どうすれば再発しないのか
おさらい:再発防止策は3件が完了し、2件が残っています。
再発防止策は、それぞれ別の弱点をふさぎます。遅い変更は今後も起こりえますが、同期を2時間も止めることはなくなります。
- 検証用コピーのメモは2,000件でした。
- 起動スクリプトがマイグレーションを実行していました。
- アラートは、失敗が10分続くまで鳴りませんでした。
- インデックスの構築で、すべての保存が止まりました。
- 検証用コピーのメモは400,000件です。
- マイグレーションは、人が手動で1回だけ実行します。
- アラートは3分で鳴ります。
- インデックスの構築は、バックグラウンドで実行する予定です(期限は10月23日)。
つまり:火曜日以降に4つが変わり、5つ目のデプロイを控える時間帯は判断待ちです。
この章のポイント:再発防止策はそれぞれ別の弱点をふさぐので、1つ失敗しても同期が2時間止まることはもうありません。
まとめ
- 書き込みは止まらなかったため、起きたのはメモの損失ではなく、2時間の遅れでした。
- 120分のうち55分は原因探しだったので、アラートを分かりやすくするのがいちばん効果的です。
- 9分のロックを2時間に延ばしたのは、インデックスではなく再起動の繰り返しでした。
- 3件が完了、1件が作業中、1件はマーラさんの判断待ちです。
- 再発防止策はそれぞれ別の弱点をふさぐので、1つ失敗しても同期が2時間止まることはもうありません。