リアル事例から読み解く Webパフォーマンスチューニングの勘所 2023.12.14 Offers @fujiwara 藤原俊一郎

@fujiwara (X(Twitter), GitHub, Bluesky) 面白法人カヤック SREチーム ISUCON 優勝 4回 ISUCON 運営(出題) 4回 Amazon ECSデプロイツール github.com/kayac/ecspresso

リアル事例 = 障害が発生してしまった事例 このプロジェクトでは、新機能リリース前に負荷試験をしていた 負荷試験の想定rps(requests per ssconds) 2500rps (途中いろいろあったが)とりあえずこの想定rpsはクリア しかし、本番では障害が発生してしまった

負荷試験時点での最終的なボトルネックのクエリ SELECT ... l.is_xxx AND h.id IS NOT NULL AS isXXX, ... FROM l LEFT JOIN (SELECT ... FROM h) INNER JOIN u ON l.uid=u.uid INNER JOIN ... ORDER BY isXXX DESC, ... LIMIT 100 ORDER BY している isXXX はJOIN後の演算結果によって決まるbool値 false のものを下に落としたかったためらしい… INDEXは使えないため l テーブルをフルスキャンする実行計画に 100行しか必要ないのに2000行程度をスキャンしていた

できればリリース前に直したかったが… スケジュール的な都合 この程度なら致命的ではない見込み(サーバーリソース的に) を勘案して、このまま行くことに

本番リリース後 負荷試験の想定rpsよりもかなり少ないリクエスト数で推移 (見積もりで相当余裕を見ていたため) 「これなら問題ないでしょう……」 → 障害発生

起きたこと 1. 問題のクエリを発行しているAPIのレイテンシが徐々に増加 (2〜3秒→10秒) 2. (スマホアプリ)クライアントが10秒でタイムアウトしてリトライ 3. リトライにより更にサーバーの負荷が増加 4. リトライを諦めたクライアントが全台ログイン処理(重い)からやり直し →

なぜ致命的ではない(はずだった)クエリが致命傷になったのか SELECT ... l.is_xxx AND h.id IS NOT NULL AS isXXX, ... FROM l LEFT JOIN (SELECT ... FROM h) INNER JOIN u ON l.uid=u.uid INNER JOIN ... ORDER BY isXXX DESC, ... LIMIT 100 負荷試験では、 l テーブル(約2,000行)のフルスキャンになっていた 本番では u テーブル (8万行以上)のフルスキャン になっていた！

なぜ実行計画が変わってしまったのか INDEXはどちらにちゃんとある 行数もほぼ同様 オプティマイザの気まぐれ…? ではない INNER JOIN u ON l.uid=u.uid -- <- 犯人 この uid カラムは VARCHAR(255) 負荷試験環境では問題なくINDEXで結合できていた 本番環境ではINDEXが使えずにフルスキャンになっていた ヒント 本番環境のDBはMySQL 5.7からアップグレードしていた 負荷試験環境のDBは最初からMySQL 8.0だった

MySQL 5.7→8.0 でデフォルトのCOLLATION(照合順序)が変わっている utf8mb4_geneal_ci → utf8mb4_0900_ai_ci MySQL 5.7時代からあったテーブルと、MySQL 8.0にアップグレード後に 作ったテーブルではCOLLATIONが異なる状態になっていた COLLATIONが違うカラムはINDEXを使って結合できない

パフォーマンス障害の原因は単純ではない そもそものアップグレード時のミス なぜか文字列型のカラムでJOINしていた BIGINTのprimary keyがあるのに、別のuniqueな文字列keyで… 負荷試験を問題なくクリアしたので様子をちゃんと見ていなかった 「rpsのわりにちょっとDB負荷が高いような…?」とは思っていた クライアントのタイムアウト(10秒)、リトライの挙動を サーバーエンジニアが意識していなかった 即時リトライして負荷を上げてしまうクライアントの作りもよくなかった

これを踏まえて「勘所」の話

どうやって原因究明したか

どうやって原因究明したか 当日自分はオンコールを受けなかった 担当者が調査したがすぐには判明せず、アクセスが減って自然回復したので翌日に持ち 越し 翌日調査の結果 RDS Performance Insightsで、問題のクエリが大きな負荷になっている rows が当初の想定よりもかなり多い(10万行レベル) 問題のクエリが発行されているAPIのレスポンスタイムが2秒程度から徐々に10秒ま で遅くなっている アクセスログから、10秒付近が上限になっているリクエストが多い(クライアントタ イムアウト) 問題のクエリを発行しているAPIへのリクエストが増加→DBのCPU負荷が限界に→クラ イアントがタイムアウトからのリトライ、と断定

問題のクエリでindexが使えていないことを発見するまでの足取り

問題のクエリでindexが使えていないことを発見するまでの足取り 本番環境でexplainすると、確かにindexが使えていない possible_keysにはindexが出てくるが、実際にはフルスキャン 負荷試験環境では使えている indexがあるけどJOINに使えないパターンを思い出す indexのあるカラムで演算した結果を使っている? 8.0からは関数インデックスがあるけど 型が違う? よくあるのはINTとBIGINTでJOINしたり 演算もしていないし型も同じ、ただし今回JOINに使っているのは文字列型カラム JOINするために文字列の一致を見る=> COLLATIONの影響を受けるのでは!? COLLATIONが違うカラムの結合にはindexが使えない(正解)

モニタリングが足りなかった問題

モニタリングが足りなかった問題 普段はMackerelでモニタリングすることが多い この案件ではMackerelを入れられなかった。CloudWatchとRDS Performance Insights のみ 自分が MySQL(RDS, Aurora) で見るメトリクス筆頭 > InnoDB rows read InnoDBから何行を読み取っているか 単位時間あたりに読み込む行数がほぼCPU負荷に直結(比例することが多い) 発行しているクエリ数と比較して、読み込む行数が多い = indexが使えていない or 使え ていても非効率なクエリが多いのがすぐ分かる ISUCON本にも3章でMySQLの負荷を見るところで最初に書いた話 しかし、CloudWatchには実はこのメトリクスはない

ISUCONでこのネタはありか

ISUCONでこのネタはありか ちょうど今年の作問期間だったのでネタとして提案しようかちょっと迷った でも流石に罠過ぎるなと思ったので入れなかった 自分でも1時間分からなかったし 関わったメンバーが選手として参加しているので公正性に問題あり