Spring Boot API で散発的に発生する 504 エラーの原因究明:ゲートウェイではなくコネクションプールの枯渇

事象の概要

先週、注文検索 API で断続的に 504 エラーが発生するという障害対応を担当した。通常時の P95 レスポンスタイムは 80ms 程度なのに、毎日夜間のピーク時にだけ数十秒間続く 504 が出現し、その後自然に収束していた。

システム構成は以下の通り:

クライアント → Nginx → Spring Boot → MySQL

Nginx のタイムアウトは 30 秒に設定されており、アプリケーション層のログには明確なエラーが記録されていなかった。当初はゲートウェイ側の設定が厳しすぎるのではないかという見方が主流だった。

タイムアウト値の引き上げは最終手段

安易に Nginx のタイムアウトを 60 秒に延長するのは、問題の本質を見逃すことになる。まず以下の 3 つのメトリクスを確認した:

  • アプリケーションのスレッドプール使用率
  • HikariCP のコネクション使用状況
  • MySQL のスロークエリ発生時刻との相関

アプリケーションログに以下の記録が散見された:

HikariPool-1 - Timeout failure stats (total=20, active=20, idle=0, waiting=34)
java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30000ms.

このログは重要な手がかりを示している。API 処理自体が遅いわけではなく、データベースコネクションが枯渇し、後続リクエストがコネクション獲得を待ち続け、結果としてゲートウェイのタイムアウトに到達している。

ボトルネックの特定

MySQL のスロークエリログを精査した結果、特定の時間帯に以下のクエリが顕著に遅延していることが判明した:

SELECT *
FROM order_item
WHERE sku_id = ?
  AND order_state IN (100, 200, 300)
ORDER BY create_time DESC
LIMIT 50;

実行時間が 8〜12 秒に達するケースがあった。テーブルは約 900 万行を保有し、既存のインデックスは以下のみ:

KEY idx_product (sku_id),
KEY idx_time (create_time)

実行計画を確認すると、MySQL は idx_product を選択し、その後でフィルタリングとソートを行っていた。特定の人気商品(sku_id)ではヒット件数が膨大になり、ソート処理のコストが急増していた。

EXPLAIN SELECT ...;

Extra カラムに以下の表示が確認された:

Using where; Using filesort

インデックスの再設計

クエリの絞り込み条件とソート条件が固定されているため、複合インデックスを新規作成した:

ALTER TABLE order_item
ADD INDEX idx_product_state_time (sku_id, order_state, create_time);

インデックス設計にあたり、以下の点を検証した:

  1. order_state のカーディナリティは低いが、絞り込み条件として機能するため sku_id の後に配置
  2. create_time はソート用途のため、複合インデックスの末尾に配置することで filesort を回避

適用後の実行計画は以下に改善:

type: range
key: idx_product_state_time
Extra: Using where; Using index condition

スロークエリは秒単位から数十ミリ秒に短縮。HikariCP の active コネクション数もピーク時に張り付くことがなくなった。

フェイルファストの導入

インデックス修正に加え、以下の防御策を実装した:

spring:
  datasource:
    hikari:
      maximum-pool-size: 20
      connection-timeout: 3000

コネクション獲得の待機時間を 30 秒から 3 秒に短縮。これによりデータベース異常時にリクエストが早期に失敗し、Tomcat のワーカースレッドが長時間占有されるのを防ぐ。

さらに、レイテンシ監視用のログ出力も追加した:

var begin = Instant.now();
try {
    return itemRepository.fetchByProduct(param);
} finally {
    var elapsed = Duration.between(begin, Instant.now()).toMillis();
    if (elapsed > 1000) {
        log.warn("遅延検出: 経過時間={}ms, 商品ID={}", elapsed, param.getProductId());
    }
}

教訓と今後の指針

今回の事象はゲートウェイの 504 という表象の裏に、スロークエリによるコネクションプール枯渇という本質があった。類似問題の調査では、以下の順序で診断を進めることを推奨する:

  1. ゲートウェイタイムアウトは結果であり、根本原因ではない
  2. コネクションプールの active / idle / waiting 数値を、インターフェースレイテンシより先に確認
  3. スロークエリの発生時刻とアラート時刻を厳密に照合し、平均値に惑わされない
  4. 特定のパラメータ値(ホットスポット)が、通常時は問題ないインデックス設計を破壊するケースに留意

Nginx のタイムアウト変更は行わず、インデックス最適化とコネクション獲得戦略の修正のみで対応。リリース後 2 日間の監視で、夜間ピーク時の 504 発生はゼロとなった。

タグ: Spring Boot hikaricp MySQL パフォーマンスチューニング インデックス最適化

9月15日 03:39 投稿