初めてのKubernetes本番運用でハマった話 ── 503をログから追いかけて
はじめに ── リリース初期に、オブザーバビリティは「まだ早い」のか
SRE のプラクティスを、いつから始めるべきか。これは専任の SRE がいない組織ほど悩ましい問いだと思います。
「まずはリリースする」「ユーザーが増えてから監視を整える」「SLO はプロダクトが安定してから」。私たちもそう考えていました。そして実際、監視基盤がほぼゼロの状態で本番運用を始めました。
結果として、リリース初期の本番環境で 503 が止まらなくなり、初歩的な落とし穴のすべてにハマりました。そして原因を追いかける中で、順序が逆だったことに気づきます。オブザーバビリティは「システムが育ってから整えるもの」ではなく、システムを育てるために必要なものでした。
ログだけを頼りに 503 の原因を追いかけた調査の流れと、そこから得た学びをお伝えすることで、これから Kubernetes を使い始める方に「しくじり先生」としてオブザーバビリティの大切さが伝われば嬉しいです。
自己紹介
Ryunosuke(@Kobujee_53)と申します。自社システムを、アプリからインフラまで横断で開発・運用しています。
昨年から 1 年半ほど、社内のさまざまなシステムを Kubernetes で運用してきました。SRE チームも昨年立ち上がり、現在は 3 人のチームになっています。
ただし、今回お話しする障害と向き合っていた当時は、その 1 年半のいちばん最初です。私がインフラの構築・運用担当で、Kubernetes はほとんど未経験。専任の SRE もいませんでした。この記事は、そこからの振り返りになります。
前提と構成
対象は、人材紹介事業の顧客管理システム(CRM)と、業務委託向けの稼働・契約管理システムです。ユーザーは社内の営業担当で 100 数名程度。ユーザーさんも含めると数千アカウント規模になります。開発チーム + 兼任 SRE 1 名(私)という体制でした。
構成は以下の通りです。
ユーザー → Cloud LB → GKE Gateway / NEG → crm-api Pod 群 → AlloyDB
- バックエンド: NestJS の API
- フロントエンド: Next.js
- 基盤: GKE Autopilot + Gateway + NEG
- HPA でオートスケール
GKE Autopilot を初めて導入したプロダクトの、リリース初期という時期でした。
ある日、特定の API が 503 を返しているという報告
ある日、不具合の報告を受けました。調べてみると、たしかに特定の API が 503 を返しています。
PUT /talent/{talentId}/call-in/judge/approve → 503 (failed_to_connect_to_backend)
エラーの詳細は failed_to_connect_to_backend。ロードバランサからバックエンドの Pod へ接続できなかった、という状態です。
業務影響としては逆引きで発覚しました。承認処理が実行されない → DB にレコードが作られない → Slack 通知も飛ばない。業務側からは「承認ボタンを押したのに通知が来ない」という形で見えていたわけです。
ログのタイムラインを見ると、こうなっていました。
| 時刻 | 事象 |
|---|---|
| 12:12:09 | 1回目 再起動開始 |
| 12:12:13 | 起動完了 |
| 12:14:16 | 503発生 ← 起動2分後に再クラッシュ |
| 12:15:04 | 2回目 再起動開始 |
| 12:15:06 | 起動完了 |
Pod が起動した 2 分後くらいに再びクラッシュして、再起動を繰り返している。この「起動してはすぐ死ぬ」パターンが、まず最初の手がかりでした。
そして調べていくうちに、報告があった API 以外も実は失敗していたことが分かってきます。結果的に、この 503 の原因は複数の要因が重なっていて、いくつものパターンから発生していました。それをひとつずつ紐解いていくことになります。
監視基盤ゼロ、ログだけで全体像を組み立てる
調査が大変だった一番の理由は、当時この基盤に監視の仕組みがほとんど無かったことです。
ダッシュボードも、Prometheus のようなメトリクス基盤も、アラートも整っていない。頼れるのはログだけでした。
そこで全体像を把握するために、次の 2 つを頼りに調査を行いました。
- Cloud Logging: 外から見た失敗(LB の 503)を時系列で抽出・集計
- KHI(Kubernetes History Inspector): クラスタ内部の状態遷移をタイムラインで可視化
ポイントは、これらのツールを使ってGKEやLBなど複数サービス間のログを同じ時間軸に重ねることです。
| ログ | 見えるもの | キー |
|---|---|---|
http_load_balancer |
外から見た失敗 | 503 / serverIp |
k8s_container |
中で起きた再起動 | Starting / started |
外から見た失敗と、中で起きた再起動を同一時間軸に並べる。これによって、点だった事象が線でつながっていきました。以降で紹介する 5 つの落とし穴は、すべてこの「型」で見つけたものです。
ハマり① startupProbe 不在 → Liveness Kill ループ
ひとつ目の落とし穴です。
症状: Pod が起動しては数十秒で殺され、再起動を繰り返す。
Kubernetes には probe(ヘルスチェック)の仕組みが 3 種類ありますが、私たちはこのうち startupProbe を置いていませんでした。
原因は次の通りです。
- 初期化が間に合わないのに startupProbe が無かった
- 旧 liveness の設定:
initialDelay 30s + period 10s × threshold 3≒ 起動後約 60 秒で強制 Kill - liveness も readiness も同じ
/を見ていて、役割が分かれていなかった
起動が遅いのに、liveness が約 60 秒で「死んでいる」と判断して Kill する。また起動して、また Kill ── という無限ループに陥っていました。
対策は、本当にドキュメント通りです。startupProbe で起動を待たせ、liveness と readiness を「DB に依存しない / 依存する」で役割分担させました。
| Probe | 役割 | endpoint |
|---|---|---|
| startupProbe | 起動の猶予(最大 60s 待つ) | /readyz |
| livenessProbe | プロセス生存(DB 非依存) | /livez |
| readinessProbe | 受入可否(DB 依存) | /readyz |
念のため整理しておくと、livenessProbe はプロセスが生きているかの確認で、失敗すると強制的に再起動します。readinessProbe はトラフィックを受けられるかの確認。そして startupProbe は、Pod 内のプロセス起動が終わるまで待ってくれる猶予用です。
ハマり② NEG / EndpointSlice の readiness 非同期レース
①だけでは解決しませんでした。ふたつ目です。
症状: スケールアウトで増えた Pod が、Ready になる前に LB からトラフィックを受けて 503。
KHI と監査ログで EndpointSlice の遷移を追跡したところ、こういう流れでした。
- HPA が replicas を 2 → 3 に増やす(自動スケール)
- 新 Pod が
ready:falseのまま EndpointSlice に登録される - その隙に LB がルーティング → 503
- 数分後、アプリの起動が完了して
ready:trueになり解消
つまり「Pod が Ready」と「LB が送り始める」は別タイミングであり、NEG 構成ではこの伝播が勝手には同期しない。これを知らなかったために起きた事象でした。
ハマり③ LB ヘルスチェックの検知ラグ(in-place restart)
さて、まだ治りません。3つ目です。
症状: Pod は生きているのに中のコンテナだけが in-place restart している間、LB が気づかず約 30 秒間死んだコンテナに送り続けて 503 がバーストする。
発見できた決め手は、503 ログの serverIp を集計したことでした。同じ Pod の IP に約 29 秒間で 69 件が集中しており、SIGTERM → Created container → started という時間窓と一致したのです。
対策として、LB のヘルスチェック設定を次のように変更しました。
| 設定 | 変更内容 |
|---|---|
checkIntervalSec |
15 → 5(検知ラグ 約 30s → 約 10s) |
timeoutSec |
default 15 → 3 を明示 |
requestPath |
/readyz → /(shallow) |
ここで重要なのが、チェック先を /readyz から浅い / へ変更したことです。理由は、DB 接続まで確認する深いチェックを LB に使うと、DB が一瞬詰まっただけで全 Pod が一斉に Unhealthy になり、連鎖障害(カスケード障害)を招くからです。
役割分担としては、LB HC = shallow(/)/ kubelet readiness = deep(/readyz) に整理しました。
「Pod は生きているがコンテナが死ぬ」というレイヤを意識することと、ヘルスチェックは “深さ” で役割を分けるということが大きな学びでした。
ハマり④ keepAliveTimeout × LB の Keep-Alive 不整合
さらに4つ目です。
症状: 再起動とは無関係に、1 分あたり 1〜2 件の散発的な 503(backend_connection_closed_before_data_sent_to_client)が常時発生。
原因は、Node.js と GCP LB の Keep-Alive タイムアウトの不整合でした。
- Node.js の
keepAliveTimeoutはデフォルト 5 秒のまま - 一方、GCP LB の backend keepalive は 600 秒固定
- アプリ側が先に接続を閉じる瞬間に来たリクエストが 503 になる
対策は、アプリ側のタイムアウトを必ず LB より長くすることです。
await app.listen(port);
const httpServer = app.getHttpServer();
httpServer.keepAliveTimeout = 620_000; // LB(600s)より長く
httpServer.headersTimeout = 625_000; // keepAliveより大きく
学び: アプリと LB の “接続を閉じる順序” を合わせる。クラウド LB の keepalive は固定値なので、アプリ側を必ず上回らせる。
ハマり⑤ GKE Autopilot のノード自動削除 × PDB 未設定
そして最後の5つ目です。
ここまで話してきたことを対策していっても、503 は続いていました。しかもその原因は、先ほどまで話してきたオートスケールではありませんでした。
最初は HPA(水平スケール)が細かく Pod 数を上下させるフラッピングを疑いました。しかし、トラフィックが安定している夜間でも症状が続くのです。
そこで 14 時間分を実測し、分析を進めました。
| 観測項目 | 結果 |
|---|---|
| crm-api Pod の Killing | 25 件 |
| クラスタ全体の Node 削除 | 255 件(≈18/h) |
| Kill ↔ 同ホスト Node 削除 の相関 | 24/25(96%) |
| Kill → Node 削除 の時間差 | +6 分 |
| HPA 起因の kill | 8 件のみ |
Pod の Kill のうち 96% が、同じホストのノード削除と一致していました。Kill の前後 6 分でノードが消えていたのです。
真因はこうでした。
- Autopilot が bin-packing 最適化で node を高頻度に削除(1 時間あたり約 18 台)しており、crm-api Pod も巻き添えで evict されていた
- PDB(PodDisruptionBudget)が未設定のため、「いつ evict してもよい」と扱われていた。
minReplicas: 2は voluntary disruption を保護しない - available が瞬間的に 1.5〜1.8 にディップ = 一瞬 1 Pod 体制になり、503 バーストの条件が揃う
HPA 側の設定である minReplicas を設定していたので守られているつもりでいたのですが、この自発的な追い出しは防げないということを理解しておらず、観測もできていませんでした。
対策として、PDB に minAvailable: 2 を全環境へ追加し、「新 Pod が ready になってから旧 Pod を evict する」ことを強制しました。
まとめ ── 初めての K8s 本番運用で踏んだ 5 つの落とし穴
- startupProbe 不在 → Liveness Kill ループ
- NEG / EndpointSlice の readiness 非同期レース
- LB ヘルスチェックの検知ラグ(in-place restart)
- Node.js
keepAliveTimeout× LB の Keep-Alive 不整合 - GKE Autopilot のノード自動削除 × PDB 未設定(夜間の巻き添え evict)
5 つもありますが、共通する学びは 「Pod が生きている」ことと「リクエストを正しく返せる」ことは別物、ということです。信頼性を「Pod が動いていること」で測っていた限り、私たちのシステムは「正常」でした。ユーザーから見た失敗は、まったく別のレイヤに存在していたわけです。
そしてもうひとつ。本当に当たり前のことですが、モニタリング環境が整っていれば、ここまでログで順番に相関関係を仮説立てて調べていたようなことも、一目で分かる状態に持っていけるはずなんですよね。
SRE を支えるオブザーバビリティは、障害検知だけでなく、打った手の答え合わせにも使える。そしてリリース初期だろうが関係なく必要だということを学びました。
実際、ハマり①〜④の対策を打ったあとも 503 は続いていました。もし「対策したから直ったはず」で終わっていたら、真因であるハマり⑤には辿り着けなかったと思います。打った手が効いたかどうかを確かめる手段があったからこそ、次の仮説に進めたわけです。これは障害対応というより、改善サイクルを回すための土台そのものだと思います。
監視は異常時のためだと思っていたけれど、本当は「自分が今、何をしているのかを理解するため」のものでした。これが一番の学びです。
本当のゴールは「起きる前に光らせる / 起きた瞬間に気づく」
ここからは、それからどのように体制を改善しているかについても書いておきます。
5 つの落とし穴は、どれも事前アラートが無かったものばかりでした。最速の検知器が「人間の通報」だった状態です。
「追えた」というのは、オブザーバビリティの最低ラインでしかありません。
現状 業務通報 → ログ手集計(人間が起点)
↓
あるべき アラート自動(向こうから気づく)
MTTR(復旧時間)を縮める前に、まず MTTD(検知時間)を人間の通報より速くする。ここまでやり切るのが本当のゴールだと思っています。
今どこにいて、次どこへ
チームでは、オブザーバビリティの成熟度を 5 段階で捉えて改善を進めています。
| レベル | 状態 | 現在地 |
|---|---|---|
| L0 | 受動(業務通報で知る) | スタート地点 |
| L1 | 可視(ダッシュボードで後追い) | |
| L2 | 通知(向こうから知らせる) | 現在 |
| L3 | 予測(バジェット枯渇前に動く) | |
| L4 | 自動(検知 → 緩和が自動) |
L0 は受動、業務通報で知る段階。L1 は可視、ダッシュボードで後追いできる段階です。そして現在取り組んでいるのが L2 の通知、システムの方から知らせてくれる段階。アラートの拡充・運用を進めており、形骸化しないように、平常時の計測結果を元にアラートのしきい値を詰めているところです。その先に L3 の予測、L4 の自動化があると考えています。
3 本柱の現状ギャップはこう捉えています。
- ◎ メトリクス
- ◎ ログ
- △ トレース ── OpenTelemetry + Sentry はあるが、障害調査で常用されていない。開発チームも含めた運用化が課題
計測基盤はどんどん整備していますが、運用に乗っていないものがあることが課題です。「入れたかどうか」ではなく「障害調査で実際に使われているかどうか」でしか、オブザーバビリティの成熟度は測れないと感じています。
おわりに ── 「まだ早い」は、たぶん逆だった
初めての Kubernetes 本番運用で、5 つの落とし穴すべてにハマった話でした。どれも「知識としては知っていた」はずのことでしたが、自分たちのログで観測して初めて本当に理解できたと思っています。
あれから 1 年半、社内のさまざまなシステムを Kubernetes で運用してきて、いま振り返って強く思うのは、冒頭に書いた順序の話です。
私たちは「オブザーバビリティはシステムが育ってから」と考えていました。でも実際に起きたのは、観測できないから原因が分からず、原因が分からないから対策の効果も分からず、システムを育てられないという状態でした。5 つの落とし穴のうち 4 つまで潰しても 503 が止まらなかったあの期間は、まさにそれです。
SRE は信頼性をエンジニアリングする営みですが、その前提には「いま自分たちのシステムがどうなっているかを知っている」ことがあります。SLO を決めるにも、エラーバジェットを使うにも、まず測れなければ始まりません。そう考えると、オブザーバビリティに「まだ早い」という段階は、たぶん存在しないのだと思います。専任の SRE がいない時期こそ、人間の勘と手集計に頼らずに済む仕組みが要る、とも言えます。
いま私たちは L2(システムの方から知らせてくれる)を運用に乗せている途中です。まだ道半ばですが、同じように専任の SRE がいない状態で Kubernetes に向き合っている方にとって、この記事が「最初にどこへ投資すべきか」を考えるきっかけになれば幸いです。