公開直後にクラッシュするアプリを検出する
9月25日、3件の公開が、アプリのAPIが起動のたびに数秒でクラッシュしているにもかかわらず、成功と判定されました。公開は「成功」したため、ロールバックは実行されませんでした。その数分後、バックグラウンドのチェックが公開を失敗扱いにし、サイト全体が404を返すようになりました。ヘルスチェックは、ホスティング基盤のイベントリストでクラッシュの数を数えていました。そのリストが保持するのは、マシンごとに直近の5件のイベントだけです。そのためクラッシュの連続が続くと、リストは常に埋まったままになり、数が増えなくなっていました。現在は、代わりに最新のクラッシュの時刻を比較します。クラッシュを繰り返す公開は失敗し、以前のバージョンが復元されます。
公開が待つもの
Mythexでバックエンドを持つアプリを公開すると、新しいバージョンがホスティング基盤のマシンに展開され、ヘルスチェックが公開の成否を判定します。失敗した場合は、ロールバックが以前のバージョンを戻します。
難しいのは、「起動した」と「応答している」が同じではないことです。基盤は、マシンが立ち上がるとすぐに起動済みと報告します。起動から1秒でクラッシュするアプリは直ちに再起動され、少し後にはまた起動済みと読み取られます。そのため、ヘルスチェックは長い時間をかけて、いくつかの層を重ねてきました。
- 2回確認する。 マシンが起動済みと読み取られた後、少し待ってから再び確認します。起動時のクラッシュは、2回目の確認で失敗することが多いためです。
- クラッシュの連続を監視する。 基盤がマシンのクラッシュが続いており、再起動を諦めたと報告した場合は、失敗とします。
- 公開の開始以降のクラッシュを数える。 2回の「起動済み」の確認は、再起動をまたぐことがあります。そのため、公開の開始以降に1件でもクラッシュがあれば、3回目の確認を行います。3回目の確認で前回より多くクラッシュが記録されていれば、そのアプリは安定して動いていないと判断します。
ここで失敗したのは、3番目のチェックでした。
数が増えなかった理由
クラッシュの情報は、各マシンのイベントリストから得ています。イベントには、起動、終了、再起動などがあります。基盤が保持するのは、マシンごとに直近5件のイベントだけです。
たとえば、起動から2.5秒でクラッシュし続けるアプリを考えてみてください。この中の1つは、まさにそのように動いていました。起動するたびに、クラッシュと起動のイベントが1組ずつ追加されます。数回繰り返すと、リストは埋まります。その後は、新しいイベントが追加されるたびに、古いイベントが押し出されます。リストは前に進みますが、常にほぼ同じ内訳を保ちます。つまり、クラッシュが2件、起動が2件、という内容です。
そのため、「公開の開始以降にいくつクラッシュしたか」は、確認するたびに同じ数字を返していました。2回目の確認では、たとえばクラッシュが2件と見えます。3回目の確認でも、異なるクラッシュではあるものの、件数は同じく2件でした。チェックは、クラッシュが止まったと判断し、公開を通してしまったのです。
これは9月25日に、2つのアプリで3回起きました。そのたびに、次のことが起きていました。
- 公開は稼働中とマークされました。
- 失敗が検出されなかったため、ロールバックは実行されませんでした。
- 事後にデプロイを確認するバックグラウンドの処理(照合ジョブ)が、数分後にそのデプロイを失敗扱いにしました。
- サイト全体が404を返すようになりました。
正しく時間内に失敗した公開は、ロールバックで以前のバージョンに戻せます。一方、成功と宣言された後で数分遅れて失敗した公開は、すでにロールバックをスキップしてしまっています。
原因の再現
ローカルで再現しました。動作している API を用意し、スリープさせてから、起動時にクラッシュする変更を加えて再公開しました。ヘルスチェックは、それを稼働中とマークしました。
これは本番環境の結果とも一致しました。3件の公開のどれでも、アプリは起動するたびに数秒で停止していましたが、チェックが比較するクラッシュ数は、確認の間に一度も増えていませんでした。
修正:件数ではなく、最新のクラッシュを比較する
チェックは、クラッシュを数えるのをやめ、公開の開始以降の最新のクラッシュの時刻を見るようになりました。
2回目の確認で、公開の開始以降のクラッシュが1件でも見つかった場合は、待ってから3回目の確認を行います。3回目の確認での最新のクラッシュが、2回目の確認での最新のクラッシュより後であれば、その間にマシンがまたクラッシュしたことになります。つまり安定していないため、公開は「公開後に何度もクラッシュし、まだ再起動を繰り返している」というメッセージとともに失敗します。
この方法は、イベントリストがどれだけ短くても機能します。直近5件に限られたスライディングウィンドウでは、クラッシュの総数は分からなくなりますが、新しいクラッシュが起きたことは隠せません。最新のイベントは、必ず残るからです。
この変更後、ローカルでの再現では正しく動作するようになりました。公開は失敗し、以前のイメージが復元されます。さらに、基盤の動作を模したテストも追加しました。確認のたびにクラッシュと起動が1組ずつ追加され、リストは5件に切り詰められます。そして、その判定が成功ではなく失敗になることを確認しています。
得られた教訓
- 数えるデータの形を知っておきましょう。 上限のあるリストでの件数は、リストが埋まった後には意味を持ちません。その上限は隠されていたわけではなく、チェックを上限を前提に設計していなかっただけです。
- 「いくつ起きたか」より「新しいことが起きたか」を確認しましょう。 最新のタイムスタンプは切り詰めの後も残りますが、合計は残りません。
- 遅れた失敗は、早い失敗より悪いものです。 同じ壊れたビルドでも、公開が失敗してロールバックされるなら無害です。しかし、先に成功と宣言されると、サイトが停止します。
- 実際の条件で再現しましょう。 このバグを再現するには、イベントリストを埋めるほどクラッシュしたマシンが必要でした。テストで1回だけ素早くクラッシュさせるだけでは、この問題は現れなかったでしょう。
この修正は、同じ日に行ったもう1つの修正と組み合わせて理解してください。それは、ロールバックが古いバージョンを削除するのではなく、確実に復元するようにしたものです。詳しくは、失敗した再公開が、動いているバックエンドを消すことはないをご覧ください。もし起動時にクラッシュするためにアプリの公開が失敗する場合は、公開のトラブルシューティングのドキュメントと、AIで作ったアプリのデバッグ方法のガイドが参考になります。