まとめ
| 観点 | 内容 |
|---|---|
| 課題 | 一覧APIで N+1 クエリが多発し、ページ取得ごとに大量の SELECT が発行されていた。 |
| 対応 | データアクセス層を再設計し、関連データを Preload で一括取得。複合条件の参照は IN句によるバッチ取得で最適化。 |
| 観測 | リクエスト相関IDをキーとした構造化クエリログを導入し、クエリ数・種別・レイテンシをリアルタイム可視化。 |
| 結果・成果 | クエリ数を削減し DB負荷と接続プールの占有率が安定。さらに、性能退行を常時検知できる状態を確立。 |
発生概要
社内向けチケット管理SaaSでは、案件(ticket)、担当者(user)、ステータス(status)、コメント(comment)、顧客情報(customer)など、複数テーブルを結合した一覧表示APIを提供していた。
運用チームから「一覧の表示が遅い」「APIの応答が体感的に重い」との報告があり、監視メトリクス上でもレスポンス遅延が継続的に確認された。
初期実装では、チケット本体を取得後に関連データをループで個別に読み込む構成となっていた。
var tickets []Ticket
db.Find(&tickets)
for i := range tickets {
db.First(&tickets[i].User, tickets[i].UserID)
db.First(&tickets[i].Status, tickets[i].StatusID)
db.First(&tickets[i].Customer, tickets[i].CustomerID)
}
※本コードは N+1 問題の発生パターンを簡略化して示したサンプルです。
実際の環境ではトランザクション管理を含む構成になっていましたが、問題の本質(1件ずつ関連データを取得するループ構造)を明確にするため省略しています。
この実装により、1リクエストで多数の SELECT 文が発行され、いわゆる N+1クエリ問題 が発生していた。
調査・測定フェーズ
APIレスポンスの遅延要因を特定するため、アプリケーションとデータベースの両面から観測を行った。
まず、Lambda関数の実行ログを詳細化し、各リクエストごとに処理時間・クエリ回数・SQL種別を記録するよう構成を変更。
Lambda の awsRequestID を相関IDとして全レイヤーに付与し、1リクエスト単位でログを追跡可能にした。
ORMのロガーを拡張し、SQL発行ごとにクエリ種別・実行時間・影響件数を構造化して出力。
また、リクエスト終了時には「total_sql」「total_select」「total_insert」などの集計サマリを必ず出し、どのリクエストで異常なクエリ回数が発生しているかを即座に検知できるようにした。
データベース側ではスロークエリログを有効化し、アプリケーションログの request_id を SQL コメントに付与。
これにより、アプリ層の構造化ログとDB側の実行状況を突き合わせ、一覧取得時に多数の SELECT が連鎖する N+1 パターンを明確に確認した。
実装サンプル(相関IDの伝搬、構造化ロガー、GORMロガー拡張、SQLコメント埋め込み)は 「参考」 を参照。
比較検討フェーズ
N+1解消と応答時間短縮に向け、複数案を比較し「クエリ削減/実装コスト/影響範囲/運用負荷/ロールバック容易」の観点で評価。
採用
-
Preload(Eager Loading)
ORMの関連をあらかじめまとめて取得。一覧+必要な関連を最小回数のSQLに集約。
狙い:N+1の本質的解消/変更はデータアクセス層に限定 -
バッチ取得(IN句)
一覧で集めたIDを用いて関連を一括フェッチし、メモリで合流。
狙い:Preloadで足りない複合条件を柔軟に吸収
見送り
-
短TTLキャッシュ(読み取り)
ステータス・担当者基礎情報など変動の小さいデータを短寿命でキャッシュ。
狙い:再参照の平準化/DB負荷の緩和 -
ページング & 取得列の最適化
ページサイズ・ソートキー・選択カラムを見直して転送量とデコードコストを削減。
狙い:レイテンシの安定化/過剰取得の抑制
簡易比較
| 案 | クエリ削減 | 実装コスト | 影響範囲 | 運用負荷 | ロールバック容易 |
|---|---|---|---|---|---|
| Preload | ◎ | ◎ | 小 | 小 | ◎ |
| バッチ取得(IN) | ○ | ○ | 中 | 小 | ○ |
| 短TTLキャッシュ | ○ | ○ | 小 | 中 | ○ |
| ページング/列最適化 | ○ | ◎ | 大 | 小 | ◎ |
採用理由
- 改修が データアクセス層に収まり、API仕様やフロント改修が不要。
- クエリ回数の直減が見込め、レイテンシ改善に直結。
- 設定差分が小さく 段階導入/即ロールバック が可能。
計測方針(評価軸)
- リクエスト単位の 総クエリ数/SELECT回数/レイテンシ分布。
- エラーレート/タイムアウト/スロークエリ件数の推移。
将来候補(現時点では保留)
- 手書きSQL+JOIN最適化:高い自由度だが保守負荷が大。まずはORMで到達可能。
- 事前集計・非正規化:設計インパクト・再計算コストが大。アクセス増で再評価。
注:詳細な手段(手書きSQL、非正規化)は、上記案で改善が頭打ちになった段階で再検討する。
Preload補足
ORM(GORM)における “関連テーブルをあらかじめまとめて取得する” 機能で、チケット一覧の取得時にユーザ・顧客・ステータス情報を一括で取得し、N+1構造を根本的に解消できるのが特徴。
// Before: 各チケットごとに関連を個別取得(N+1)
var tickets []Ticket
db.Find(&tickets)
for i := range tickets {
db.First(&tickets[i].User, tickets[i].UserID)
db.First(&tickets[i].Customer, tickets[i].CustomerID)
db.First(&tickets[i].Status, tickets[i].StatusID)
}
// After: Preloadで関連を一括取得(1クエリに集約)
var tickets []Ticket
db.Preload("User").Preload("Customer").Preload("Status").Find(&tickets)
バッチ取得(IN句)が有効なケース
- 親ごとに条件が違う関連を取りたい
例)「各チケットの最新コメントだけ」など、親ごとにLIMIT 1/ORDER BYが異なる。 - 複合条件やサブクエリが必要
例)「Customer が特定タグを持つ場合のみ User を付与」等、JOINや存在チェックが絡む。 - 多段(2段以上)の関連をまとめたい
例)Ticket -> Customer -> Companyの2段目以降を一括取得してメモリで合流。
移行計画
方針(外部非破壊・可逆性重視)
- API仕様は変えない:レスポンス構造は現状維持。最適化はデータアクセス層(DAO/Repository)で実施。
- 機能フラグで切替:
preload.enabledを環境変数で制御。 - 即時ロールバック可:問題発生時はフラグOFFで旧経路へ戻す
事前準備
- 計測の土台:
request_id起点の構造化ログ(総SQL数/SELECT回数/レイテンシ/スロークエリ)をダッシュボード化。 - ガードレール:SLO/アラート閾値を設定(例:総SQL増加・レイテンシ上振れ・タイムアウト率上昇)。
段階リリース
- 対象の切り方:まずは利用頻度の高い一覧APIを 対象エンドポイント単位で限定有効化。
監視・アラート
- 即時監視:総SQL数、SELECT比率、p95/タイムアウト、スロークエリ件数、DB CPU/IO。
- 異常時の自動対応:閾値超過でフラグを自動OFF
結果
定量的成果
-
総クエリ数の削減
一覧APIの1リクエストあたりのSQL発行数が大幅に減少(N+1構造を除去)。 -
レスポンス時間の安定化
遅延の主因だった多重SELECTが解消され、リクエスト間のばらつきが減少。
ピーク時でもタイムアウトが発生せず、APIの応答時間分布が安定レンジに収束。 -
スロークエリの激減
既存で頻出していた「同一クエリの連続発行」によるスロークエリログ出力がほぼ解消。
DB側CPU負荷・I/O待ち時間も安定化。 -
リソース効率の改善
クエリ数削減により接続プールの占有率が下がり、Lambda同時実行数やDBコネクション数のスパイクが減少。
結果として、インフラコスト(DB・Lambda実行時間)も抑制傾向。
定性的成果
-
開発・運用負荷の軽減
クエリ最適化がデータアクセス層に閉じたため、上位レイヤーの影響がなく改修が容易に。
コードベースも統一化され、N+1検知や性能回帰テストを定常運用に組み込みやすくなった。 -
改善の再利用性が向上
Preload/IN句バッチ構成を汎用化し、他モジュールでも同パターンで展開可能に。
データ取得ロジックが標準化され、類似問題の再発防止にも寄与。 -
プロダクト体験の向上
一覧表示の体感速度が改善し、サポート部門・営業部門の業務効率が向上。
顧客問い合わせ対応やチケット検索の待機時間が減り、日常業務のストレスが軽減した。
参考
以下は、N+1検知とログ相関の仕組みを示す抜粋です。
実コードはORM設定・PIIマスキング・エラーハンドリング等を含みますが、ここでは要点のみ掲載しています。
相関IDの伝搬(Lambdaハンドラ抜粋)
func withRequestID(ctx context.Context, req events.APIGatewayProxyRequest) context.Context {
rid := req.Headers["x-request-id"]
if rid == "" {
if awsID := ctx.Value("aws_request_id"); awsID != nil {
if s, ok := awsID.(string); ok { rid = s }
}
}
return context.WithValue(ctx, "request_id", rid)
}
構造化ログ出力(主要部)
func Log(ctx context.Context, level, msg string, f map[string]any) {
f["ts"] = time.Now().UTC().Format(time.RFC3339Nano)
if rid := ctx.Value("request_id"); rid != nil {
f["request_id"] = rid
}
b, _ := json.Marshal(f)
fmt.Println(string(b))
}
GORMロガー拡張(Trace抜粋)
func (l *GormStructuredLogger) Trace(ctx context.Context, begin time.Time, fc func() (string, int64), err error) {
sql, rows := fc()
op := detectOp(sql)
logx.Log(ctx, "debug", "sql_event", map[string]any{
"op": op, "rows": rows, "elapsed_ms": time.Since(begin).Milliseconds(),
})
}
SQLコメントへの request_id 埋め込み
func WithRequestIDTag(ctx context.Context, db *gorm.DB) *gorm.DB {
if rid, ok := ctx.Value("request_id").(string); ok {
return db.Set("gorm:query_option", fmt.Sprintf("/* request_id=%s */", rid))
}
return db
}
※ 実際の実装ではログ集約、SQLマスキング、Prometheusメトリクス送出などを併用。
| レイヤー | 主な観測ポイント | どんな情報が得られるか | 主な目的 |
|---|---|---|---|
| APIレイヤー(Lambdaハンドラ) | - request_id(相関ID)- 処理開始・終了時刻 - 総クエリ数 / 処理時間 |
- どのリクエストが遅いか - どのエンドポイントで遅延が起きているか - 「1リクエスト=何件SQL」か |
どのAPIがボトルネックか特定 |
| ORMレイヤー(GORMロガー) | - 各SQLの実行時間 (elapsed_ms)- クエリ種別 ( SELECT/INSERT/UPDATE)- 行数 ( rows) |
- どんなSQLがどのくらい走ってるか - N+1の兆候(SELECT連打) - UPDATE/INSERTの偏り |
N+1などアプリ内構造の異常検知 |
| DBレイヤー(MySQL Slow Query Log) | - 実際のSQL文 - 実行時間・ロック時間 - /* request_id=... */ コメント付き |
- どのSQLが遅いか - 実行計画・インデックスの効き具合 - 同一リクエスト内での複数クエリ発行 |
アプリ内遅延とDB負荷の突き合わせ |