ヘッドレスCMSをメジャーアップデートしたら502エラーが発生しまくった件
CMS のメジャーアップデート後に API が不定期に 502 を返し始めた原因を、CloudWatch での切り分けと SQL 実行計画の見直しで解消した記録です。
TL;DR
- CMS のメジャーアップデート直後、API が断続的に 502 を返し始めた。
- CloudWatch で DatabaseConnections の揺れ・selectAttempt の急増・CPUUtilization の高止まりを確認し、DB 側の怪しさに着目。
- スキーマがより正規化されテーブル数と JOIN が激増、
EXPLAINするとフルテーブルスキャンだらけ。 - インデックスの貼り直し、JOIN 条件と取得カラムの絞り込み、不要 JOIN の削減でチューニング。
- 502 は解消し、CPU 使用率も低下。ケースによってはアップデート前より高速化。
システム構成（ざっくり）
- ヘッドレスCMS（スキーマをソースコードで管理・自動生成）
- MySQL（RDS）
- アプリケーションは API 経由で CMS を利用
- 監視は CloudWatch
いわゆる「よくある構成」です。
何をしたか
ヘッドレスCMSの メジャーアップデート を行いました。
大きな破壊的変更は事前に把握していたものの、スキーマ定義自体はアップデート後も問題なく生成され、マイグレーションも正常終了。
この時点では「多少レスポンスは落ちるかもな」くらいの認識でした。
起きたこと
デプロイ後しばらくしてから、以下の症状が発生。
- APIが断続的に 502エラー
- レスポンスが極端に遅くなるリクエストがある
- 再現条件が分かりづらい
CloudWatch を確認すると、怪しい兆候がいくつも見えてきました。
CloudWatchで見えた異変
コネクション数が安定しない
これまではほぼ固定だった DatabaseConnections が、アップデート後はリクエストに応じて可変するように。加えて、
- selectAttempt（SELECT系の実行回数）が倍近くに増加
- 明らかにDBへの負荷が増えている
「コネクションプールの挙動、変わってないか？」という疑念が浮上。
CPU使用率が張り付く
CPUUtilization が常時70%前後 に。スパイクではなく、「なだらかに高止まりしている」状態だったため、
- 単発の重い処理ではない
- 何かが常にDBを忙しくしている
という印象。
原因のあたりをつける
メジャーアップデートの変更点を改めて確認すると、ひとつ気になる点がありました。
正規化がさらに進んでいた
アップデートにより、
- テーブル数が 倍以上
- 中間テーブルが大量に追加
結果として、
- データ取得時に JOIN が激増
- 1リクエストあたりのSQLがかなり複雑に
「これはSQL怪しいな…」となり、アプリケーションから発行されるSQLを直接確認することに。
実行計画を見て絶望する
問題のSQLを EXPLAIN してみたところ、見事にフルテーブルスキャン。
- インデックスが使われていない
- JOIN対象テーブルも多い
- 行数もそこそこある
CPUが溶ける理由が、ようやく腑に落ちました。
やったこと
ここからは地道な改善作業。
- インデックスを貼り直す
- JOIN順・条件を見直す
- 取得カラムを必要最小限にする
- 不要なJOINを減らす
SQLを書き直しながら EXPLAIN → 修正 → 再確認 を繰り返しました。
結果
- 502エラーは解消
- CPU使用率は大幅に低下
- レスポンスは アップデート前より速くなった ケースも
正直かなり大変でしたが、「ちゃんと向き合えばちゃんと速くなる」という当たり前の事実を再確認しました。
学び
今回の件で特に痛感したことは2つ。
実行計画は必ず見る
- ORMやCMSを使っていても、SQLは裏で必ず流れている
- 「動いているからOK」は危険
- フルスキャンはだいたい悪
CloudWatchは最高の切り分けツール
- CPU
- Connections
- クエリ実行回数
これらを見るだけで「アプリなのか」「DBなのか」「設計なのか」かなり早い段階で当たりを付けられる。
おわりに
メジャーアップデートは便利になる反面、内部構造が大きく変わる ことも多いです。
特に、
- 正規化の進行
- JOIN増加
- コネクション管理の変更
このあたりは、アップデート後に必ず疑うポイントだと感じました。
しんどい事件ではありましたが、実行計画の読み方と CloudWatch のありがたみを身をもって学べたという意味では、良い経験だったのかもしれません。
同じような沼にハマった人の参考になれば幸いです。