ISUCON研修おかわり会 講義スライド

2025/6/26に開催したCTO協会新卒合同研修非公式アフターイベントの講義資料です

Transcript

1. ISUCON 研修おかわり会 パフォーマンスチューニングを始めよう [paki & yata] 1
2. 本日の流れ（アジェンダ） 1. (5 分) オープニング 2. (15 分) Part 0: ISUCON の基本 3. (20 分) Part 1: 改善 ① データベース (インデックス) 4. (15 分) Part 2: 改善 ② Web サーバー (静的ファイル) 5. (25 分) Part 3: 改善 ③ アプリケーション (N+1 問題) 6. (10 分) まとめと Q&A 2
3. オープニング 自己紹介、概要 (5 分) 3
4. 自己紹介 kazu-gor(@kazu-gor2) 株式会社 エブリー SWE AI 研究 → コンテンツ Mgr→ デー タエンジニア → PO→ BE（今） ISUCON は最下位でした コーヒーが好きです 4
5. 自己紹介 yata(@0e2b3c) 株式会社 LayerX バクラク勤怠 SWE フロントエンドずっとやってま した ISUCON 研修は一応１位でした スマブラとヨルシカが好きです 5
6. 本日のゴール MUST ISUCON の基本的な流れ 計測 → 特定 → 改善 のサイクルを理解する private-isu を題材に、自力で 1 つ以上 の改善を体験する BETTER ログを読み解き、適切な改善アクションを 自分で考えて実行できる ための基 礎を築く 6
7. 進め方 ① ISUCON 研修と同じ private-isu というアプリケーションを使います コースごとの進め方 初級：講義 → ハンズオン → グループワーク 中級：無限にグループワーク コード 初級：スタートの状態(ログの設定やライブラリのダウンロードはすでにされ ている) 中級：ある程度チューニングされた状態(インデックス、N+1,静的ファイルの 返却、Prepared Statement の抑制、memcache の活用、connection の設定、 外部ライブラリの削除) 7
8. 進め方 ② 各パートのコマンドやコードは全て /lecture にあるので参考にしてください 講義内で紹介するコマンドは Makefile で定義されているので実際のコマンドを見 たい場合はそちらを参照してください 8
9. 注意点 今日話す二人とも ISUCON のプロではありません 今回のために頑張って準備しましたが不足があったらごめんなさい LayerX のスライドテンプレート使ってるけど全く会社を代表していません ISUCON 研修の時とは環境が違うのでスコアが全然違います 圧倒的に今回の方がスコアが出やすい 2 万点くらいまでは差がないがそれ以降は全然違う 前回の 5 万点が今回の 25 万点くらいのイメージです python だとそもそもそんなに点数が出ない 9
10. 環境構築について 事前にアナウンスしていた通り、AWS の環境を使用します。 CloudFormation というサービスを使うことで全員が同じ構成のサーバーを簡単に 作成できます。 まだ環境構築できていない人 は、後ほど一緒にやりましょう！ 10
11. Part 0: ISUCON の基本 ISUCON の基本的な流れ、計測、特定、改善を理解しよう (15 分) 11
12. ISUCON とは？ Iikanjini Speed Up CONtest お題となる Web サービスを限界まで高速化を図るチューニングバトル DB やアプリケーション、OS などをガチャガチャする 仕様さえ守っていれば何でもあり！とにかく速く！ バックエンド、インフラの知識を総動員して立ち向かう競技 ベンチマーカーが負荷試験を行って、捌けたアクセス数に応じてスコアが上がっ ていく 12
13. 推測するな、計測せよ (Don't guess, measure.) パフォーマンスチューニングの鉄則です。 なぜ？ 勘や思い込みでの修正は、的外れだったり、時には悪化させることさえあ る。 どうするか 今一番ボトルネックになっている場所を見つけて、そこに適切なアプローチ を取る 計測 → 特定 → 改善のサイクルを一つずつ積み上げていく 13
14. 基本的な２つのボトルネック データベース データの取得、挿入がボトルネックになりがち 一つ一つは軽くても蓄積するとかなりのボトルネックに 0.1 秒で処理できるクエリも 10000 回叩かれたら 10 秒かかる アプリケーション データを無駄に取得していたり、何回も取得しているとレスポンスが遅くな る 実際は、実質データベースのボトルネックだったりもする 14
15. じゃあどっちが問題かってどうすれば分かる？ まずは CPU の使用量を見よう CPU の使用量が多い方に問題がありそう！と見当を付けられる CPU がどちらかに偏っている = もう片方の性能を引き出しきれていない 15
16. 実際に見てみよう 16
17. [ハンズオン] 計測の準備 まず、初期状態の性能を測ってみましょう。 1. makefile の準備 便利コマンド集を使えるようになります 2. ログファイルをリセット 過去のログを消して、ベンチマーク実行中のログだけを記録できるようにし ます。 make prepare 17
18. [ハンズオン] ベンチマーカーを実行して CPU の使用量を見る ベンチマーカーの実行 ターミナルで make benchmark を実行 top コマンドで CPU 使用量を見る 現在の CPU の使用量をモニタリングできるコマンド ベンチマーカーの実行中に別ターミナルで top コマンドを叩いてみましょう CPU%みたいなところを見る 何が 上位に来ていましたか？(誰かに聞いてみる) 18
19. じゃあどっちが問題かってどうすれば分かる？(再掲) まずは CPU の使用量を見よう CPU の使用量が多い方に問題がありそう！と見当を付けられる CPU がどちらかに偏っている = もう片方の性能を引き出しきれていない MySQL のせいでアプリケーションが暇している状態 アプリ < もっと返せるのに DB に足引っ張られてるよ〜 19
20. ベンチマーカーの実行が終わったら初期スコアを確認 おそらく 4,000 点前後のスコアが出るはずです。この数値を覚えておきましょ う。 20
21. 分かったらどうすんの？ もちろんどちらが原因なのかが分かっただけでは足りない じゃあどうする？↓ もっと詳しく分析する！ 21
22. 詳細な分析用の計測ツール２選 本日は代表的な 2 つのツールを使います。(make コマンドで隠蔽されているけど) 1. アクセスログ解析: alp どのエンドポイント（URL）が 遅いか / たくさん呼ばれているか を教えてく れる。 アプリケーションのパフォーマンスを測定するときに使う 2. スロークエリログ解析: pt-query-digest どの SQL クエリが 遅い(スロー)か を教えてくれる。 DB のパフォーマンスを測定するときに使う 22
23. [ハンズオン] アクセスログ解析 with alp どの Web リクエスト がボトルネックか見てみましょう。 # どのエンドポイントにどれくらいアクセスがあるかを分析する # 中身はalpのコマンド make analyze-access-log 23
24. 出力例 +-------+-----+-----+-----+-----+-----+-------+--------+------------------+ | COUNT | 1% | 50% | 99% | AVG | MAX | SUM | METHOD | URI | +-------+-----+-----+-----+-----+-----+-------+--------+------------------+ | 1800 | ... | ... | ... | 0.82| 1.51| 1476.0| GET | / | | 1200 | ... | ... | ... | 0.55| 1.10| 660.0| GET | /posts?offset=10 | | 600 | ... | ... | ... | 0.30| 0.80| 180.0| POST | /login | | ... | ... | ... | ... | ... | ... | ... | ... | ... | +-------+-----+-----+-----+-----+-----+-------+--------+------------------+ SUM (合計時間) や AVG (平均時間) が大きいところが怪しい！ 24
25. [ハンズオン] スロークエリログ解析 with pt-query-digest どの SQL クエリ がボトルネックか見てみる。 # どのクエリがどれくらい叩かれているかを分析する # 中身はpt-query-digestのコマンド make analyze-slowquery-log 25
26. 出力例 (一部抜粋): # Query 1: 0.01 QPS, 0.01x concurrency, ID 0x... # This item is included in the report because its total time is ... # Scores: V/M = 0.01 # Time range: ... to ... # Attribute pct total min max avg ... # ============ === ======= ======= ======= ======= ======= # Count 50 1800 # **Exec time** 63 5225s 2s 4s 3s ... # ... SELECT `posts`.* FROM `posts` ORDER BY `created_at` DESC LIMIT 10 OFFSET 10; # Query 2: ... SELECT `comments`.* FROM `comments` WHERE `post_id` = ? ORDER BY `created_at` DESC; Exec time (合計実行時間) が大きいクエリが怪しい！ 26
27. [グループ] 自己紹介タイム (2 分) 名前（ハンドルネーム） ISUCON の参加経験 or 前回の ISUCON 研修がどんな感じだったか 今日学びたいこと 27
28. [グループ] ボトルネックはどこだ？ (5 分) alp の結果と pt-query-digest の結果を見て、今一番解決するべきものはどれでしょう か？ グループで議論して、仮説を立ててみてください。 議論のヒント: まずそもそももっと修正すべきなのは DB?アプリ？ DB だとしたらどのクエリが一番重そう？ アプリケーションだとしたらどのエンドポイントが一番重そう？ 28
29. どこかのグループに聞いてみようのコーナー 29
30. 想定解 DB の SELECT * FROM comments WHERE post_id = 〇〇 を改善するの が一番効果が高そう！ CPU の使用量は DB が圧倒的に多い → こっちが問題そう その DB の中で最も実行時間が大きいものが comments を取得するクエリ 30
31. Part 1: データベースのチューニング インデックスを使ってクエリを高速化しよう (20 分) 31
32. インデックス (Index) とは？ データベースの検索を高速にするための 「索引」 です。 例：分厚い ISUCON の技術書 インデックスなし: "N+1 問題" のページを探すのに、全ページをめくる必要が ある ( = フルスキャン ) インデックスあり: 索引(あいうえお順)で "N+1 問題" を引くだけで見つけられ る ( = インデックススキャン ) データベース君が見る行数が減るから速くなる！ WHERE 句や ORDER BY 句で頻繁に使われるカラムにインデックスを貼ると効果的！ 32
33. EXPLAIN で実行計画を見る EXPLAIN SELECT * FROM comments WHERE post_id = 12345; 注目ポイント type: ALL: ヤバい！ フルテーブルスキャン。インデックスが効いていない。 ref, range, index: インデックスが使われている。良い。 rows: スキャンすると予測される行数。この数が少ないほど良い。 33
34. [ハンズオン] インデックスを追加しよう MySQL にログイン mysql -u isuconp -p isuconp # パスワードもisuconp インデックスを追加する SQL を実行 alter table comments add index post_id_idx(post_id); さっきの EXPLAIN をもう一度実行して結果が変わっているか確認！ ついでにベンチマーカーももう一度実行してスコアが変わっているか確認しましょ う！ 34
35. 少しだけ発展 ① インデックスの中身 ② BTree というものが使われている 大体３〜４回で目的のデータに辿り着けるようになっているので速い 35
36. 少しだけ発展 オプティマイザ DB にはどうやってデータにアクセスするかの計画を立てるオプティマイザが いる(EXPLAIN で見れる) カーナビのような役割 ユーザーが意識しなくてもいい感じに速いルートを選定してくれる(ただし完 璧ではない) 36
37. スコア上がった？ 37
38. 今日のMUSTゴールクリア！ めでたい 🎉 38
39. [グループ]改善できそうな場所を探してみよう(8 分) make analayze-query を使って、更にインデックスを用いて改善できる場所がないか 探してみよう 可能だったら実際にインデックスを貼ってスコアが変わったかどうかを試してみてく ださい！ 39
40. Part 2: Web サーバー nginx から静的ファイルを返して高速化しよう (15 分) 40
41. 静的ファイル vs 動的ファイル 静的ファイル (Static Files) 誰がいつアクセスしても 内容が変わらない ファイル。 例: CSS, JavaScript, 画像ファイル (JPG, PNG) 動的ファイル (Dynamic Content) アクセスごとにプログラムが実行され、内容が変わる ファイル。 例: ユーザーの投稿一覧、ログイン後のマイページ 41
42. 現状のprivate-isu 全てのアクセスを一度 アプリケーションが受け取ってから処理している。 静的ファイルまでアプリケーションが処理するのは 非効率！ 内容が同じなんだったらアプリケーション挟まなくても同じものを返し続け ればいい アプリケーションを介さず返せば高速になるし CPU の負荷も減って嬉しい リバースプロキシを使えばできる！ 42
43. リバースプロキシとは？ サーバーの受付係みたいなもの 役割: クライアントとサーバーの間に位置し、通信の中継や制御を行う クライアントからのリクエストを受け取り、適切なバックエンドサーバーに 転送 主な機能: キャッシュ機能: 頻繁にアクセスされるコンテンツや静的ファイルをキャッシ ュ 負荷分散: 複数のバックエンドサーバーへリクエストを振り分け セキュリティ: バックエンドサーバーを直接公開せず保護 43
44. Nginx による静的ファイル配信 Web サーバー (Nginx) が静的ファイルへのリクエストを直接処理し、アプリケーション に渡さないようにする。 メリット アプリケーションの負荷が減り、動的コンテンツの処理に専念できる。 Web サーバーはファイル配信が得意なので、高速に応答できる。 44
45. [ハンズオン]ログを集計してみよう 再度ログを集計してみましょう。 その前に古いアクセスログを移動しておきます。 # 今までのアクセスログを移動 make rotate-access-log 45
46. [ハンズオン]アプリケーションのログを集計してみる ベンチマーカーを実行して、アクセスログを集計します。 # ベンチマーカーを走らせるための、スコア計測用コマンド make benchmark # 集計用のコマンド make analyze-access-log ここからなにがわかるでしょうか？ 46
47. [グループ] どれが静的ファイル？ (3 分) アクセスされているエンドポイントの中には、アプリケーションの計算なしに返 却できる静的ファイルがいくつかあります。 それはどれでしょうか？ 47
48. [ハンズオン] アプリケーションのパフォーマンス改善 設定ファイルを開き、isucon.conf の設定ファイルを参考にして、 静的ファイルの配信を設定してみましょう。 # 設定ファイルを開く sudo vi /etc/nginx/sites-available/isucon.conf # /lecture/part3/static_file.confを参考にファイルを書き換え # 設定ファイルの文法チェック sudo nginx -t # nginxのreload make reload-nginx ベンチーマーカーを実行してスコアやエンドポイントのレスポンスがどうなってるか確 認！ 48
49. リバースプロキシのキャッシュ機能 Nginx をリバースプロキシとして使う場合、キャッシュ機能が大きなメリットになりま す。 なぜキャッシュが効果的？ 頻繁にアクセスされるコンテンツを Nginx が保持 バックエンドのアプリケーションサーバーまで行かずに、Nginx から直接レスポン スを返せる 結果: レスポンス時間の短縮とサーバー負荷の軽減 49
50. [ハンズオン] 画像をキャッシュする 設定ファイルを開き、isucon.conf の設定ファイルを参考にして、 静的ファイルの配信を設定してみましょう。 # 設定ファイルを開く sudo vi /etc/nginx/sites-available/isucon.conf # /lecture/part3/static_file.confを参考にファイルを書き換え # 設定ファイルの文法チェック sudo nginx -t # nginxのreload make reload-nginx 50
51. 確認 今まで通りログを移動した後にベンチマーカーを走らせて、スコアが変わったか 確認！ make analyze-access-log で静的ファイルの返却が速くなっているも確認！ 51
52. Part 3: アプリケーション N+1 問題を解決してアプリケーションを高速化しよう (25 分) 52
53. N+1 問題ってなに？ 「1 つのデータを取るために、1 回＋ N 回もデータベースに問い合わせちゃう問題」 ファミレスで例えると... あなたはファミレスの店員です。5 人のお客さんが来店しました。 N+1 問題が起きている状態： i. 「1 人目は何を注文した？」→ 厨房に伝えに行く（1 回目） ii. 「2 人目は何を注文した？」→ 厨房に伝えに行く（2 回目） iii. 「3 人目は.. 合計 5 回も厨房を往復！疲れる！時間がかかる！非効率！ 53
54. じゃあどうする？ 解決した状態： 1. 「全員分の注文を承ります！」→ 厨房に 1 回行くだけ 54
55. コードで見る N+1 問題 // N+1問題が発生するコード // 1回目のクエリ posts, _ := db.Query("SELECT * FROM posts") for posts.Next() { var post Post posts.Scan(&post.ID, &post.Title) // ループの中でクエリが発生！（N回） comments, _ := db.Query("SELECT * FROM comments WHERE post_id = ?", post.ID) count := 0 for comments.Next() { count++ } fmt.Printf("%s has %d comments\n", post.Title, count) } // → 投稿が100件あったら、101回もデータベースと通信！ for 文の中で何度も DB に問い合わせをしている。 55
56. N+1 問題はわかったけどなにがいけないの？ ループ処理をするたびに DB に問い合わせする → 10 件ぐらいなら毎回探索してもそこまで負荷にはならなさそう → 100,000 件あったら何回も 100,000 件に対して欲しいデータを探しにいく？ 想像できる通り、DB のパフォーマンスが悪化して以下のような事態に。 ユーザ： 「なんかこのサイト重くない？」 開発者： 「なんか DB のリソースめっちゃ使ってない？」 これは ISUCON に限った話ではありません。 実際の開発でも気を抜くと起こり得ます。 56
57. では N+1 問題をどうやってみつけるか 「理解したよ、SQL が for 文の中で大量に呼ばれている場所を探すんだよね？」 57
58. 違います、計測してください。 58
59. N+1 問題の発見方法 ログで発見する(pt-query-digest) # 中身はpt-query-digest make analyze-access-log こんな症状が見つかったら要注意！ 同じようなクエリが大量に発行されている SELECT * FROM comments WHERE post_id = ? が 1000 回とか... 合計実行時間（Exec time）がやたら長い 59
60. [グループ] private-isu の N+1 を探せ！ (5 分) alp の結果で遅かった / (トップページ) の処理を見てみましょう。 ソースコードは /home/isucon/private_isu/webapp/golang/app.go or python/app.py にあります。 // /home/isucon/private_isu/webapp/golang/app.go // トップページのハンドラー func getIndex(w http.ResponseWriter, r *http.Request) { // 投稿を取得 results := []Post{} err := db.Select(&results, "SELECT * FROM `posts` ORDER BY `created_at` DESC LIMIT ?", postsPerPage) for i := 0; i < len(results); i++ { // この中で何をしている？ err := db.Get(&results[i].User, "SELECT * FROM `users` WHERE `id` = ?", results[i].UserID) // コメント数を取得 var count int db.Get(&count, "SELECT COUNT(*) FROM `comments` WHERE `post_id` = ?", results[i].ID) results[i].CommentCount = count // コメントを取得 comments := []Comment{} db.Select(&comments, "SELECT * FROM `comments` WHERE `post_id` = ? ORDER BY `created_at` DESC LIMIT 3", results[i].ID) for j := 0; j < len(comments); j++ { db.Get(&comments[j].User, "SELECT * FROM `users` WHERE `id` = ?", comments[j].UserID) } results[i].Comments = comments 60
61. [ハンズオン] N+1 問題を修正しよう トップページの処理を改善します。 コメントやユーザー情報をまとめて取得し、ループ内での SQL 発行をなくしましょ う。 修正方針: 1. 取得した posts の id と user_id を集める。 2. IN 句を使って、comments と users を一括で取得する。 3. Map を使って、Post に Comment や User を効率的に紐付ける。 // 例: IN句を使った一括取得 postIDs := []int{1, 2, 3, 4, 5} query := "SELECT * FROM comments WHERE post_id IN (?, ?, ?, ?, ?)" db.Select(&comments, query, postIDs...) // MapでO(1)アクセスを実現 61
62. [ハンズオン] デプロイと再計測 アプリケーションを再起動 # app.goを開く vim -n /private_isu/webapp/golang/app.go # Go アプリケーションを再起動 make build-app ベンチマークを再実行 ブラウザでベンチマークを実行し、スコアの変化を確認します。 ログを再度 alp や pt-query-digest で見てみましょう。 SELECT * FROM comments WHERE post_id = ? のようなクエリが減っているはずです。 スコアは上がりましたか？ 62
63. まとめと Q&A (10 分) 63
64. スコアの Before / After 改善内容 スコア（目安） 備考 初期状態 ~ 3,000 インデックス追加後 ~ 25,000 DB のボトルネックも解消 静的ファイル配信後 ~ 80,000 アプリの負荷を下げて安定化 N+1 問題修正後 ~ 180,000+ アプリケーションの改善が大きく効く！ ※ スコアは環境やタイミングで変動します。 重要なのは、計測 → 特定 → 改善のサイクルを回すことです！ 64
65. 本日の振り返り 計測 alp でアクセスログを見て、遅いエンドポイントを特定した。 pt-query-digest でスロークエリログを見て、遅い SQL を特定した。 特定と改善 インデックス: EXPLAIN で実行計画を確認し、 CREATE INDEX で改善した。 静的ファイル: Nginx から直接配信するように設定し、アプリの負荷を軽減し た。 N+1 問題: ループ内の SQL 発行をやめ、Eager Loading で改善した。 このサイクルを、素早く正確に回すことが ISUCON 攻略の鍵です！ 65
66. ネクストステップ 他の改善手法を試してみる アプリケーションのプロファイリング DB のコネクション数調整 Nginx, MySQL のパラメータチューニング 複数台構成 (DB サーバーを分けるなど) ISUCON の過去問に挑戦する isucon.net に過去のすべての問題と解説ブログへのリンクがあります。 コミュニティに参加する 勉強会や Discord などで情報交換するのもおすすめです。 66
67. ご清聴ありがとうございました！ インスタンス落とすの忘れないでね ♡ お金たくさん取られるよ ♡ Q&A 67