データベースの接続数上限で、お客様のMacを危うく再起動しかけた話

当社はお客様向けに、小規模なMac miniのフリートを運用しています。ハブ上のデーモンが各マシンをSSHでポーリングし、テレメトリをコントロールプレーンに送ります。マシンの応答がなくなると、段階的に対応します。まず待ちます。次にスマートプラグでマシンの電源を再投入します。それでもだめなら人を呼びます。

先週、コントロールプレーンが500エラーを返し始めました。13分後、デーモンは4台のMacすべてが死んでいると判断し、それぞれの電源再投入を記録しました。2台は有料のお客様のものでした。3台目はその朝に売れたばかりでした。

実際に壊れていたもの

データベースのコネクションプールです。コントロールプレーンはサーバーレス関数で動いていて、Postgresのプーラーにつないでいます。プーラーには、プロジェクト全体で接続15本という上限があります。ウォーム状態の関数がいくつかで接続を使い切り、データベースを使うAPIルートがすべて失敗し始めました。詳細は別の記事に書きました。

Macは正常でした。SSHも動いていました。GUIのセッションもすべて起動していました。そのうち1台でビルドしていたお客様は、何も気づきませんでした。壊れていたのは、Macが壊れているかどうかを知るためのシステムだけでした。

正常なフリートが死んでいるように見えた経緯

デーモンは、マシンごとにタイムスタンプを1つだけ持っていました。最後にポーリングが成功した時刻です。エスカレーションの処理は、それを現在時刻と比べていました。ポーリングはまずコントロールプレーンからマシン一覧を取得し、取得に失敗したらそこで終わります。それ自体はもっともな作りでした。

そのため、障害中はポーリングが一度も実行されず、タイムスタンプも進まず、すべての経過時間が一斉に伸びました。エスカレーションの処理は、デーモンが一度も試していないことを知りませんでした。4台のマシンから13分間の沈黙を見て、作られたとおりの動作をしたのです。

ladder: Unit 02 unreachable 12m51s → power cycle
ladder: Unit 03 unreachable 12m51s → power cycle
ladder: Unit 04 unreachable 12m51s → power cycle
ladder: Unit 05 unreachable 12m43s → power cycle

どれも再起動しなかった理由

スマートプラグが設定されていなかったからです。電源再投入の段階でプラグを探し、見つからないので次へ進みました。後で確かめると、4台の稼働時間は6日、6日、1日、約1時間でした。何も触れられていませんでした。

これは設計ではなく、運です。スマートプラグは、次に導入するマシンの計画に入っています。もし取り付けてあったら、データベースの接続の問題で、お客様のMac 3台の電源が落ちていました。うち1台はビルドの最中だったかもしれません。どのマシンも何も悪いことはしていませんでした。

修正

デーモンは現在、マシン一覧の取得に成功して実際に各マシンへ接続を試みた最後の時刻を記録しています。それが最近でなければ、エスカレーションの処理は動作を拒否し、理由をログに残します。原因はマシンではなく、コントロールプレーンだと。

ladder: skipped, no successful unit poll in 14m02s (control plane, not the units)

この行は、何を拒否しているのか、その理由は何かを正確に伝えています。古い仕組みも、最初からこう言うべきでした。

根底にあるルールは単純です。復旧処理は、確認が実際に実行された証拠を必要とすべきです。「接続を試みて失敗した」は証拠です。「連絡がない」は証拠ではありません。監視する側が止まったときも、まったく同じに見えるからです。

ご自身の自動化でテストすべきこと

当社は、Macが死んだときに何が起きるかはテストしていました。Macを監視する仕組みが死んだときに何が起きるかは、一度もテストしていませんでした。この2つは別のテストです。そして電源スイッチに手を伸ばすのは、2つめのほうです。