private-isu で50万点を超えるまで with isutools

ISUCON の練習問題 private-isu を1日かけてチューニングし、Go 実装のスコアを 0 → 541,650（fail は常に 0） まで改善しました。すべての改善は自作の計測ツール isutools の数値を根拠に行っています。この記事では「どの計測が、どの修正を導き、スコアがどう動いたか」を時系列でまとめます。

private-isu チューニングのスコア推移(0から541,650まで)

改善ステップとスコアの対応は次の通りです。

環境#

• WSL2 + Docker Compose（private-isu 標準構成: nginx / Go app / MySQL / memcached）
• 競技エミュレーションとして app と MySQL は各 1 CPU に制限（compose の cpus: "1"）
• ベンチマーカーは同一ホストの Docker で実行

計測基盤: isutools#

チューニングを始める前に、計測を1箇所に集める Go モジュール isutools を作成しました（導入手順と全機能は紹介記事にまとめています）。アプリへの組み込みは実質1行です。

db, _ = sqlx.Open(isutools.SQLDriverName("mysql"), dsn)

これで localhost:19191 に管理サーバが立ち、POST /reset → ベンチ実行 → POST /save?score=N を繰り返すだけで、ベンチマークのたびに以下のデータがダッシュボードへ残ります。

• SQL（正規化クエリ別 total / count / p95）・HTTP（パス別）・nginx アクセスログ（alp 相当）
• プロセス別 CPU と マシン全体の CPU 使用率（busy / idle 内訳）
• DB スキーマ（ベンチ開始時点のインデックス一覧） と、未設定の定石を検出する advisor
• ベンチごとのスナップショット履歴と、実行間の diff ビュー
• CPU プロファイル（pprof）の自動採取・セッション単位の User Flow（ページ遷移）

ホーム画面は実行履歴の一覧になっており、各実行が git リビジョン・スコア付きで並びます。行をクリックすると当時の全計測データを閲覧できます。

isutools ダッシュボードの実行履歴一覧。各ベンチのスコアとgitリビジョンが時系列で並ぶ

時系列の改善ログ#

初期状態: score 0 (fail 55)#

初期の Go 実装はタイムアウトが多発して score 0 でした。SQL セクションの1位は SELECT * FROM comments WHERE post_id = ? ORDER BY created_at DESC LIMIT 3 で、合計 450 秒 / 1,118 回 を占めていました。DB スキーマ欄を確認すると comments テーブルにインデックスがなく、プロセス欄では mysqld が CPU 57% を使っていました。

① インデックス + N+1 一括化 → 19,290#

comments(post_id, created_at) と posts(created_at) を追加しました。さらに makePosts 内の3重 N+1（COUNT・最新3コメント・ユーザー取得）を GROUP BY・ウィンドウ関数・IN 句の3クエリに一括化し、タイムライン取得を JOIN + LIMIT 20 に変更しました。これによりタイムアウトが解消され、初めて正のスコアが出ました。

② 画像の静的配信 → 34,224#

HTTP 欄の帯域・累計時間の上位が /image/*（合計約 180 秒）でした。DB に入っている画像を一括でファイルに書き出し、nginx の try_files + expires 1d で直接配信するように変更しました。新規投稿された画像については、アプリ側でファイルへも書き出す write-through を入れています。

③ sha512 内製化ほか → 45,812#

HTTP 欄で POST /login が 63 秒を使っていました。コードを確認すると、パスワードハッシュ計算が リクエストごとに外部の openssl コマンドを exec していました。標準ライブラリの crypto/sha512 によるプロセス内計算に置き換え、あわせて /posts/:id のクエリから不要な imgdata カラムを除外しました。

④ write-through の配置バグ修正 → 111,756 (2.4倍)#

「画像を静的化したのにアプリ経由の画像配信が減っていない」ことが isutools の HTTP 欄から判明しました。調べると、②で入れた os.WriteFile が 配信成功ブランチの return の後ろ に置かれており、一度も実行されていませんでした。成功パス内に移動しただけでスコアが 2.4 倍に伸びました。

⑤ 接続チューニング → 299,668#

マシン全体の CPU 使用率を見ると busy 11.6% / idle 88.2% で、CPU にはまだ余裕がありました。そこで db.SetMaxOpenConns と GOMAXPROCS=2 を設定するとスループットが急増した一方、nginx → app 間の接続枯渇による HTTP 502 が発生して score 0 になりました。nginx 側に upstream keepalive と worker_connections 4096 を設定して解消したところ、一気に約 30 万点まで伸びました。

⑥ advisor の指摘を適用 → 348,416#

isutools に「ISUCON の定石で未設定の項目」を検出する advisor を実装したところ、初回実行で以下の3件が検出されました。

• MySQL DSN に interpolateParams=true が未設定（プリペアドステートメントの2往復が発生）
• nginx の gzip が無効
• innodb_buffer_pool_size が 128MB（データ＋索引 1,189MB の約9分の1）

この3件を適用してスコアが +16% 伸びました。

isutools の Advisor セクション。MySQL・nginx・OS・Go の未設定の定石を自動検出して表示

⑦ ユーザーキャッシュ + MySQL 書き込み設定 → 363,733#

sync.Map によるユーザーキャッシュ（/initialize と ban 時にクリア）を導入しました。isutools.Count で計測したところ ヒット率 99.85%（hit 710,745 / miss 1,064）でした。あわせて MySQL の innodb_flush_log_at_trx_commit=2 と binlog 無効化を設定しています。

⑧ コメントキャッシュ → 412,057#

post_id → 全コメント（新しい順） のキャッシュを導入し、コメント件数を len()、最新3件をスライス先頭3件から取得するようにしました。これにより makePosts の SQL 2本（ベンチあたり合計 94 秒）が削減され、ヒット率は 97.9% でした。

⑨ インデックス追加によるオプティマイザ退行の診断 → 140,914#

ユーザーページ用に posts(user_id, created_at) インデックスを追加した直後、スコアが約3分の1に急落しました。isutools の diff ビューと SQL 欄を確認すると、タイムラインの JOIN クエリが 2ms → 519ms（260倍） に悪化していました。新しいインデックスに MySQL オプティマイザが誘導され、実行計画が変わってしまったことが原因でした。

修正後の diff ビューでは、JOIN クエリの -352秒 が緑（改善）で表示され、代わりの NOT IN クエリが数秒で完了していることが確認できます。

isutools の diff ビュー。2つのベンチ実行間でクエリ毎の合計時間の増減を緑(改善)と赤(悪化)で表示

ステージ別のスコアの伸び幅

⑩ HTML フラグメントの事前バイト列化 + 退行修正 → 541,650#

仕上げとして以下の3点を実装しました。

• 論理削除ユーザー ID をメモリに保持し、タイムライン取得を JOIN から user_id NOT IN (...) + idx_created_at に変更（⑨の実行計画退行の解消）
• タイムライン1ページ目の行キャッシュ（新規投稿 / ban / /initialize で無効化）
• 投稿 HTML フラグメントの事前バイト列化: post.html 相当を事前にレンダリングし、CSRF トークン位置で3分割してキャッシュ（リクエスト時はバイト列の結合のみ）

事前レンダリングでは、投入前に標準の html/template 出力とバイト単位で一致することをテストで検証しました（html/template が + を + にエスケープする仕様への対応など）。

まとめ#

1. 推測より計測を優先する: 10回のスコア更新のうち、write-through の配置バグや GOMAXPROCS、オプティマイザの実行計画退行など、事前の推測とは異なる箇所がボトルネックになっているケースが多くありました。
2. 1箇所を速くすると次のボトルネックが露出する: ⑤でアプリ側の処理速度を上げた直後に nginx → app 間の接続枯渇（502）が発生したように、段階ごとにボトルネックが移動します。
3. インデックス追加後も必ず実行計画とベンチ結果を確認する: インデックスの追加で既存クエリの実行計画が260倍悪化するケースを diff ビューで即座に特定できました。
4. 計測オーバーヘッドを最小限に抑える: isutools を有効にした状態での ABBA 計測（off → on → on → off）では差が -0.58%（誤差範囲内）であることを確認しています。

リンク#

• 計測ツール（OSS / MIT）: github.com/ekusiadadus/isutools
• チューニング対象リポジトリ: github.com/ekusiadadus/private-isu
• 機能紹介記事: isutools — 1行で組み込めるISUCON用オールインワンプロファイラ
• 参考書籍・記事: 達人が教えるWebパフォーマンスチューニング、Giarrium さんの private-isu 連載