ISUCON入門 その3

その1: https://speakerdeck.com/teppgg/isuconru-men
その2: https://speakerdeck.com/teppgg/isuconru-men-sono2

Transcript

1. ISUCON入門 その3
2. はじめに このスライドは下記の続きです • ISUCON入門 - Speaker Deck • ISUCON入門 その2 - Speaker Deck
3. 目次 1. 初期状態（約650点） 2. commentテーブルにインデックスを追加する（約 7000点） 3. unicorn workerプロセスを4にする（約15,000点） 4. 静的ファイルをnginxで配信する（約17,000点） 5. アップロード画像を静的ファイル化する（約 22,000点） 6. GET / を解析する 7. postとuserをJOINして必要な行数だけ取得する（約 90,000点） 8. ベンチマーカーが使用するファイルディスクリプタ上限を増加させる 9. プリペアドステートメントを改善する（約 110,000点） 10. commentテーブルにインデックスを追加する（約 115,000点） 11. postからのN+1クエリ結果をキャッシュする（約 180,000点） 12. 適切なインデックスが使えないクエリを解決する（約 200,000点） 13. 外部コマンドの呼び出しをやめる（約 240,000点） 14. MySQLの設定を調整する（約 255,000点） 15. memcachedへのN+1を解消する（約300,000点） 16. RubyのYJITを有効にする（約 320,000点）
4. 9. プリペアドステートメントを改善する • access.logを解析する ➢ SELECT postsが下位に移動している（以前のボトルネックが解消された） ➢ ADMIN PREPAREが最上位に来た（次のボトルネックをみつけた） # Rank Query ID Response time Calls R/Call V/M Item # ==== ============================ ============= ====== ====== ===== ==== # 1 0xDA556F9115773A1A99AA016... 19.0724 21.9% 246791 0.0001 0.00 ADMIN PREPARE # 2 0xCDEB1AFF2AE2BE51B2ED5CF... 15.2428 17.5% 292 0.0522 0.00 SELECT comments # 3 0x624863D30DAC59FA1684928... 12.9436 14.9% 72495 0.0002 0.00 SELECT comments # 4 0x396201721CD58410E070DA9... 10.8505 12.5% 92163 0.0001 0.00 SELECT users # 5 0xC4EBFD8718C1E68CCD1E021... 10.5816 12.1% 292 0.0362 0.00 SELECT posts users
5. 9. プリペアドステートメントを改善する • ADMIN PREPAREとは ➢ DBのプリペアドステートメントという機能 ➢ 変数を埋め込み可能な SQL文テンプレを用意してくれる メリット ◦ 同じようなSQL文を何回も実行するならテンプレ使えて早い ◦ SQL文と変数を分離するため SQLインジェクション対策になる デメリット ◦ 沢山の種類のSQL文を実行する場合、テンプレ用意に時間がかかって遅い
6. 9. プリペアドステートメントを改善する • 元コード（app.rb）の該当箇所を修正 # プリペアドステートメント有効 comment_count = db.prepare( 'SELECT COUNT(*) AS count FROM `comments` WHERE `user_id` = ?' ).execute( user[:id] ).first[:count] 　　　　↓↓↓ # プリペアドステートメント無効 comment_count = db.xquery( 'SELECT COUNT(*) AS count FROM `comments` WHERE `user_id` = ?', user[:id] ).first[:count]
7. 9. プリペアドステートメントを改善する • ベンチマークの結果 ➢ スコア：87123点→91115,点 isucon@bench:~$ /home/isucon/private_isu.git/benchmarker/bin/benchmarker -u /home/isucon/private_isu.git/benchmarker/userdata -t http://35.77.103.107/ { "pass":true, "score":91115, "success":88104, "fail":0, "messages":[] } isucon@bench:~$
8. 9. プリペアドステートメントを改善する • 改めて、access.logを解析する ➢ ADMIN PREPAREが消えた（ボトルネックが解消した） # Rank Query ID Response time Calls R/Call V/M Item # ==== ============================ ============= ====== ====== ===== ==== # 1 0x624863D30DAC59FA1684928... 19.9920 21.8% 81275 0.0002 0.00 SELECT comments # 2 0x396201721CD58410E070DA9... 17.7549 19.3% 101405 0.0002 0.00 SELECT users # 3 0x422390B42D4DD86C7539A5F... 16.6451 18.1% 83157 0.0002 0.00 SELECT comments # 4 0xCDEB1AFF2AE2BE51B2ED5CF... 16.4284 17.9% 317 0.0518 0.00 SELECT comments # 5 0xC4EBFD8718C1E68CCD1E021... 12.1914 13.3% 317 0.0385 0.00 SELECT posts users # 6 0xC9383ACA6FF14C29E819735... 1.9124 2.1% 317 0.0060 0.00 SELECT posts
9. 目次 1. 初期状態（約650点） 2. commentテーブルにインデックスを追加する（約 7000点） 3. unicorn workerプロセスを4にする（約15,000点） 4. 静的ファイルをnginxで配信する（約17,000点） 5. アップロード画像を静的ファイル化する（約 22,000点） 6. GET / を解析する 7. postとuserをJOINして必要な行数だけ取得する（約 90,000点） 8. ベンチマーカーが使用するファイルディスクリプタ上限を増加させる 9. プリペアドステートメントを改善する（約 110,000点） 10. commentテーブルにインデックスを追加する（約 115,000点） 11. postからのN+1クエリ結果をキャッシュする（約 180,000点） 12. 適切なインデックスが使えないクエリを解決する（約 200,000点） 13. 外部コマンドの呼び出しをやめる（約 240,000点） 14. MySQLの設定を調整する（約 255,000点） 15. memcachedへのN+1を解消する（約300,000点） 16. RubyのYJITを有効にする（約 320,000点）
10. 10. commentテーブルにインデックスを追加する • access.logを解析する ➢ 上位3つは、1回1回は早いけど発行回数が大量 → 発行元（Rubyコード）直さないといけないから大変そう ➢ 第4位は、発行回数は少ないけど 1回1回が重い → MySQLのクエリ直したら改善出来そう # Rank Query ID Response time Calls R/Call V/M Item # ==== ============================ ============= ====== ====== ===== ==== # 1 0x624863D30DAC59FA1684928... 19.9920 21.8% 81275 0.0002 0.00 SELECT comments # 2 0x396201721CD58410E070DA9... 17.7549 19.3% 101405 0.0002 0.00 SELECT users # 3 0x422390B42D4DD86C7539A5F... 16.6451 18.1% 83157 0.0002 0.00 SELECT comments # 4 0xCDEB1AFF2AE2BE51B2ED5CF... 16.4284 17.9% 317 0.0518 0.00 SELECT comments # 5 0xC4EBFD8718C1E68CCD1E021... 12.1914 13.3% 317 0.0385 0.00 SELECT posts users # 6 0xC9383ACA6FF14C29E819735... 1.9124 2.1% 317 0.0060 0.00 SELECT posts
11. 10. commentテーブルにインデックスを追加する • 第4位のクエリの実行計画を見てみる ➢ keyはNULLでrowsが大量 → インデックスを貼ったら直せるパターン mysql> explain SELECT COUNT(*) AS count FROM `comments` WHERE `user_id` = '197'\G *************************** 1. row *************************** id: 1 select_type: SIMPLE table: comments partitions: NULL type: ALL possible_keys: NULL key: NULL key_len: NULL ref: NULL rows: 99666 filtered: 10.00 Extra: Using where 1 row in set, 1 warning (0.00 sec)
12. 10. commentテーブルにインデックスを追加する • 前にやった感じでのDBのチューニングをする ▪user_idのインデックスを追加 mysql> alter table comments add index idx_user_id (user_id); ▪commentsテーブルにインデックスが追加されてることを確認 mysql> show create table comments\G *************************** 1. row *************************** PRIMARY KEY (`id`), KEY `index_post_id` (`post_id`), //第1章で追加したやつ KEY `idx_user_id` (`user_id`) //今回追加したやつ ▪実行計画にkeyが入って、rowsが小さくなったことを確認 mysql> explain SELECT COUNT(*) AS count FROM `comments` WHERE `user_id` = '197'\G *************************** 1. row *************************** key: idx_user_id rows: 100
13. 10. commentテーブルにインデックスを追加する • ベンチマークの結果 ➢ スコア：91115点→92771点 ➢ あまりスコア伸びてない isucon@bench:~$ /home/isucon/private_isu.git/benchmarker/bin/benchmarker -u /home/isucon/private_isu.git/benchmarker/userdata -t http://43.206.154.191/ { "pass":true, "score":95984, "success":92771, "fail":0,"messages":[] } isucon@bench:~$
14. 10. commentテーブルにインデックスを追加する • 改めて、access.logを解析する ➢ 第4位のSELECT commentsが消えた（改善した） ➢ 新たな第4位のSELECT post usersもMySQLのチューニングで改善できそうだが、 下位を改善してもあまりスコア伸びないと分かったので、先に上位 3つを改善することにする # Rank Query ID Response time Calls R/Call V/M Item # ==== ============================ ============= ====== ====== ===== ==== # 1 0x624863D30DAC59FA1684928... 20.1565 25.4% 85216 0.0002 0.00 SELECT comments # 2 0x396201721CD58410E070DA9... 18.0951 22.8% 108345 0.0002 0.00 SELECT users # 3 0x422390B42D4DD86C7539A5F... 16.4828 20.8% 87391 0.0002 0.00 SELECT comments # 4 0xC4EBFD8718C1E68CCD1E021... 14.3948 18.1% 374 0.0385 0.00 SELECT posts users # 5 0xC9383ACA6FF14C29E819735... 2.3046 2.9% 374 0.0062 0.00 SELECT posts # 6 0x9F2038550F51B0A3AB05CA5... 1.2499 1.6% 194 0.0064 0.00 INSERT comments
15. 目次 1. 初期状態（約650点） 2. commentテーブルにインデックスを追加する（約 7000点） 3. unicorn workerプロセスを4にする（約15,000点） 4. 静的ファイルをnginxで配信する（約17,000点） 5. アップロード画像を静的ファイル化する（約 22,000点） 6. GET / を解析する 7. postとuserをJOINして必要な行数だけ取得する（約 90,000点） 8. ベンチマーカーが使用するファイルディスクリプタ上限を増加させる 9. プリペアドステートメントを改善する（約 110,000点） 10. commentテーブルにインデックスを追加する（約 115,000点） 11. postからの N+1クエリ結果をキャッシュする（約 180,000点） 12. 適切なインデックスが使えないクエリを解決する（約 200,000点） 13. 外部コマンドの呼び出しをやめる（約 240,000点） 14. MySQLの設定を調整する（約 255,000点） 15. memcachedへのN+1を解消する（約300,000点） 16. RubyのYJITを有効にする（約 320,000点）
16. 11. postからのN+1クエリ結果をキャッシュする • access.log上位3つを改善する ➢ 1回1回は早いけど、発行数は多いパターン → MySQLではなく、発行元（Rubyコード）を直す # Rank Query ID Response time Calls R/Call V/M Item # ==== ============================ ============= ====== ====== ===== ==== # 1 0x624863D30DAC59FA1684928... 20.1565 25.4% 85216 0.0002 0.00 SELECT comments # 2 0x396201721CD58410E070DA9... 18.0951 22.8% 108345 0.0002 0.00 SELECT users # 3 0x422390B42D4DD86C7539A5F... 16.4828 20.8% 87391 0.0002 0.00 SELECT comments # 4 0xC4EBFD8718C1E68CCD1E021... 14.3948 18.1% 374 0.0385 0.00 SELECT posts users # 5 0xC9383ACA6FF14C29E819735... 2.3046 2.9% 374 0.0062 0.00 SELECT posts # 6 0x9F2038550F51B0A3AB05CA5... 1.2499 1.6% 194 0.0064 0.00 INSERT comments
17. 11. postからのN+1クエリ結果をキャッシュする • 上位3つのクエリを見る • クエリが元コード（app.rb）のどこで使われてるか見る ➢ 表示する投稿を準備する関数（ make_posts()）で使われてる SELECT * FROM `comments` WHERE `post_id` = '12601' ORDER BY `created_at` DESC LIMIT 3\G SELECT * FROM `users` WHERE `id` = '533'\G SELECT COUNT(*) AS `count` FROM `comments` WHERE `post_id` = '9995'\G def make_posts(results) results.to_a.each do |post| post[:comment_count] = db.xquery('SELECT COUNT(*) FROM comments WHERE post_id = ?') comments = db.xquery('SELECT * FROM `comments` WHERE `post_id` = ? )
18. 11. postからのN+1クエリ結果をキャッシュする • make_posts関数の動きを見る # GET / にアクセスが来た時の処理 get '/' do # postテーブルの中身を resultsに格納 results = db.query("SELECT * FROM posts") # make_posts関数に投げる posts = make_posts(results) # make_posts関数の定義 def make_posts(results) # resultsをの中身をループで見る（ for文） results.to_a.each do |post| # ある投稿 (post_id=?)のコメント数を取得 post[:comment_count] = db.xquery('SELECT COUNT(*) FROM comments WHERE post_id = ?') # ある投稿 (post_id=?)のコメントを取得 comments = db.xquery('SELECT * FROM `comments` WHERE `post_id` = ? ) # postに返す posts.push(post)
19. 11. postからのN+1クエリ結果をキャッシュする 問題点 • make_posts関数内でループするたびに2重クエリしてる（=N+1問題） ➢ postsを全行クエリ→該当postからcommentへクエリ 改善案1 • postテーブルにcommentsテーブルをJOINして、1回のクエリで両方取る ❌1個のpostに対して何個commentがあるか不明のため、LIMIT句が使えない 改善案2 • キャッシュを利用してMySQLへのクエリを減らす ✅キャッシュがあれば使う、無いなら MySQLにクエリする
20. 11. postからのN+1クエリ結果をキャッシュする • MySQLより先にmemcachedを見るようにmake_posts関数を修正 def make_posts(results) results.to_a.each do |post| # 投稿のコメント数をmemcachedからGET cached_comments_count = memcached.get("comments.#{post[:id]}.count") if cached_comments_count # キャッシュがあるならそれを使う post[:comment_count] = cached_comments_count.to_i else # キャッシュがないならMySQLにクエリする post[:comment_count] = db.xquery('SELECT COUNT(*) FROM comments WHERE post_id = ?') # 次からキャッシュで使えるようにmemcachedに保存 memcached.set("comments.#{post[:id]}.count", post[:comment_count], 10) end # 投稿のコメントをmemcachedからGET # コメント数のGETと同じかんじに修正 # postに返す posts.push(post)
21. 11. postからのN+1クエリ結果をキャッシュする • ベンチマークの結果 ➢ スコア：92771点→152168点 → 上位のスロークエリを改善するとスコアの伸びが良い isucon@bench:~$ /home/isucon/private_isu.git/benchmarker/bin/benchmarker -u /home/isucon/private_isu.git/benchmarker/userdata -t http://35.78.88.43/ { "pass":true, "score":152168, "success":147141, "fail":0, "messages":[] } isucon@bench:~$
22. 11. postからのN+1クエリ結果をキャッシュする • access.logを解析する ➢ ボトルネックになっていた 上位3つは20msec→2msec以下になった ➢ 1位に上がってきたクエリ が全体時間の50%を占めている（新たなボトルネック） # Profile # Rank Query ID Response time Calls R/Call V/M Ite # ==== ============================== ============= ===== ====== ===== === # 1 0xC4EBFD8718C1E68CCD1E02198... 22.1365 50.7% 559 0.0396 0.00 SELECT posts users # 2 0xC9383ACA6FF14C29E819735F0... 3.8091 8.7% 559 0.0068 0.00 SELECT posts # 3 0x112E2062ED5F42DC18C1C3895... 2.8430 6.5% 6858 0.0004 0.00 SELECT comments users # 4 0x4CF87FFC4EEAB96CC9465208F... 2.1865 5.0% 4445 0.0005 0.00 SELECT posts users # 5 0x422390B42D4DD86C7539A5F45... 1.8839 4.3% 6817 0.0003 0.00 SELECT comments
23. 目次 1. 初期状態（約650点） 2. commentテーブルにインデックスを追加する（約 7000点） 3. unicorn workerプロセスを4にする（約15,000点） 4. 静的ファイルをnginxで配信する（約17,000点） 5. アップロード画像を静的ファイル化する（約 22,000点） 6. GET / を解析する 7. postとuserをJOINして必要な行数だけ取得する（約 90,000点） 8. ベンチマーカーが使用するファイルディスクリプタ上限を増加させる 9. プリペアドステートメントを改善する（約 110,000点） 10. commentテーブルにインデックスを追加する（約 115,000点） 11. postからのN+1クエリ結果をキャッシュする（約 180,000点） 12. 適切なインデックスが使えないクエリを解決する（約 200,000点） 13. 外部コマンドの呼び出しをやめる（約 240,000点） 14. MySQLの設定を調整する（約 255,000点） 15. memcachedへのN+1を解消する（約300,000点） 16. RubyのYJITを有効にする（約 320,000点）
24. 12. 適切なインデックスが使えないクエリを解決する • 新たに1位に上がってきたクエリを見る ➢ 条件一致のレコードを 20件探してる → 条件一致が20件以下の場合は全行探してしまう SELECT p.id, p.user_id, p.body, p.created_at, p.mime, u.account_name FROM `posts` AS p JOIN `users` AS u ON (p.user_id=u.id) WHERE `user_id` = '66' AND u.del_flg=0 ORDER BY p.created_at DESC LIMIT 20\G
25. 12. 適切なインデックスが使えないクエリを解決する • 試しにuser_id=66でクエリしてみる ➢ 結果が6件出た → 20件以下なので全行精査している mysql> SELECT p.id, p.user_id, p.body, p.created_at, p.mime, u.account_name -> FROM `posts` AS p JOIN `users` AS u ON (p.user_id=u.id) -> WHERE `user_id` = '66' AND u.del_flg=0 -> ORDER BY p.created_at DESC -> LIMIT 20\G *************************** 1. row *************************** id: 5077 user_id: 66 body: Bye ((ヾ( ^-^)ゞ Byeー♪ created_at: 2016-01-02 10:24:37 mime: image/jpeg account_name: janice ～中略～～ 6 rows in set (0.06 sec)
26. 12. 適切なインデックスが使えないクエリを解決する • 複合インデックスを追加 ➢ user_idで絞り込んでからcreated_atでソートする mysql> ALTER TABLE posts ADD INDEX posts_user_index (user_id, created_at DESC); Query OK, 0 rows affected (0.11 sec) Records: 0 Duplicates: 0 Warnings: 0
27. 12. 適切なインデックスが使えないクエリを解決する 参照keyがposts_user_indexになった mysql> explain -> SELECT p.id, p.user_id, p.body, p.created_at, p.mime, u.account_name FROM `posts` AS p JOIN `users` AS u ON (p.user_id=u.id) WHERE `user_id` = '66' AND u.del_flg=0 ORDER BY p.created_at DESC LIMIT 20\G *************************** 1. row *************************** ～中略～ *************************** 2. row *************************** id: 1 select_type: SIMPLE table: p partitions: NULL type: index possible_keys: NULL key: posts_order_idx key_len: 4 ref: NULL rows: 20 filtered: 1.00 Extra: Using where 2 rows in set, 1 warning (0.00 sec) mysql> explain SELECT p.id, p.user_id, p.body, p.created_at, p.mime, u.account_name FROM `posts` AS p JOIN `users` AS u ON (p.user_id=u.id) WHERE `user_id` = '66' AND u.del_flg=0 ORDER BY p.created_at DESC LIMIT 20\G *************************** 1. row *************************** ～中略～ *************************** 2. row *************************** id: 1 select_type: SIMPLE table: p partitions: NULL type: ref possible_keys: posts_user_index key: posts_user_index key_len: 4 ref: const rows: 6 filtered: 100.00 Extra: Using index condition 2 rows in set, 1 warning (0.00 sec) →
28. 12. 適切なインデックスが使えないクエリを解決する • ベンチマークの結果 ➢ スコア：152168点→34389点 → スコア下がった isucon@bench:~$ /home/isucon/private_isu.git/benchmarker/bin/benchmarker -u /home/isucon/private_isu.git/benchmarker/userdata -t http://43.207.54.152 { "pass":true, "score":34389, "success":33204, "fail":0, "messages":[] } isucon@bench:~$
29. 12. 適切なインデックスが使えないクエリを解決する • topコマンドで解析する ➢ mysqlのCPU使用率が153%になっている isucon@main $ top PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ 963 mysql 20 0 1823000 454380 37376 S 153.7 11.6 2:02.37 2057 isucon 20 0 585008 48048 9856 R 6.0 1.2 0:04.49 2068 isucon 20 0 582804 46400 9856 S 6.0 1.2 0:04.52 2045 isucon 20 0 582124 45712 9856 S 5.7 1.2 0:04.56 2049 isucon 20 0 582468 45796 9728 S 5.7 1.2 0:04.44 719 www-data 20 0 13440 5960 4096 R 3.0 0.2 0:02.00 553 memcache 20 0 427544 20992 3712 S 2.7 0.5 0:02.13 718 www-data 20 0 13472 6068 4224 S 2.0 0.2 0:01.97 16 root 20 0 0 0 0 I 0.3 0.0 0:00.19 83 root 20 0 0 0 0 S 0.3 0.0 0:00.10 185 root rt 0 288948 27136 8704 S 0.3 0.7 0:00
30. 12. 適切なインデックスが使えないクエリを解決する • FORCE INDEX追加 ➢ app.rb内のクエリを下記に置き換え SELECT p.id, p.user_id, p.body, p.created_at, p.mime, u.account_name FROM `posts` AS p FORCE INDEX (posts_user_index) JOIN `users` AS u ON (p.user_id=u.id) WHERE `user_id` = '66' AND u.del_flg=0 ORDER BY p.created_at DESC LIMIT 20\G
31. 12. 適切なインデックスが使えないクエリを解決する • 再度topコマンドを解析 ➢ mysqlのCPU使用率が改善された isucon@main $ top PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ 18353 isucon 20 0 584592 47756 9856 R 24.7 1.2 0:01.54 18359 isucon 20 0 581684 44876 9728 S 24.7 1.1 0:01.56 18350 isucon 20 0 582068 45580 9856 S 24.0 1.2 0:01.58 18356 isucon 20 0 585796 49076 9856 R 24.0 1.3 0:01.52 963 mysql 20 0 1824032 463980 37376 S 19.0 11.9 4:47.48 718 www-data 20 0 13472 6068 4224 R 10.3 0.2 0:05.00 553 memcache 20 0 428572 22016 3712 S 9.7 0.6 0:05.66 719 www-data 20 0 13440 6088 4096 R 9.3 0.2 0:05.30 15 root 20 0 0 0 0 S 0.3 0.0 0:00.10 16 root 20 0 0 0 0 I 0.3 0.0 0:00.39
32. 12. 適切なインデックスが使えないクエリを解決する • accessログを解析する ➢ レスポンスタイムが突出したクエリが無くなった → DBのチューニングはこれで十分そう # Profile # Rank Query ID Response time Calls R/Call V/M Ite # ==== ============================== ============= ===== ====== ===== === # 1 0x112E2062ED5F42DC18C1C3895... 3.4657 15.7% 7697 0.0005 0.00 SELECT comments users # 2 0xBE0EEB30D0DA45B7410710982... 2.6552 12.0% 4464 0.0006 0.00 SELECT posts # 3 0x422390B42D4DD86C7539A5F45... 2.3309 10.6% 7652 0.0003 0.00 SELECT comments # 4 0x6BABCF7018EBE3C3E2A7F30AE... 2.1030 9.5% 3567 0.0006 0.00 SELECT comments users # 5 0x9F2038550F51B0A3AB05CA526... 1.9227 8.7% 323 0.0060 0.00 INSERT comments # 6 0x26489ECBE26887E480CA8067F... 1.8249 8.3% 330 0.0055 0.00 INSERT users # 7 0xBEFBE0AB18C503DA1D3F314DB... 1.3808 6.3% 1790 0.0008 0.00 SELECT posts # 8 0xECBECF7B69BE18F9FC9366A09... 1.3549 6.1% 3746 0.0004 0.00 SELECT posts # 9 0x009A61E5EFBD5A5E4097914B4... 1.2948 5.9% 231 0.0056 0.00 INSERT posts
33. 12. 適切なインデックスが使えないクエリを解決する • ベンチマークの結果 ➢ スコア：152168点→147662点 → スコア変わってない... isucon@bench:~$ /home/isucon/private_isu.git/benchmarker/bin/benchmarker -u /home/isucon/private_isu.git/benchmarker/userdata -t http://13.114.20.202 { "pass":true, "score":147662, "success":142863, "fail":0, "messages":[] }
34. 目次 1. 初期状態（約650点） 2. commentテーブルにインデックスを追加する（約 7000点） 3. unicorn workerプロセスを4にする（約15,000点） 4. 静的ファイルをnginxで配信する（約17,000点） 5. アップロード画像を静的ファイル化する（約 22,000点） 6. GET / を解析する 7. postとuserをJOINして必要な行数だけ取得する（約 90,000点） 8. ベンチマーカーが使用するファイルディスクリプタ上限を増加させる 9. プリペアドステートメントを改善する（約 110,000点） 10. commentテーブルにインデックスを追加する（約 115,000点） 11. postからのN+1クエリ結果をキャッシュする（約 180,000点） 12. 適切なインデックスが使えないクエリを解決する（約 200,000点） 13. 外部コマンドの呼び出しをやめる（約 240,000点） 14. MySQLの設定を調整する（約 255,000点） 15. memcachedへのN+1を解消する（約300,000点） 16. RubyのYJITを有効にする（約 320,000点）
35. 13. 外部コマンドの呼び出しをやめる • alpでアクセスを解析する ➢ loginとregister（ログイン処理）に時間がかかっている isucon@main:~/private_isu$ alp json --sort avg -r -m "/posts/[0-9]+,/@\w+,/im age/\d+" -o count,method,uri,min,avg,max,sum < /var/log/nginx/access.log +--------+--------+--------------------+-------+-------+-------+---------+ | COUNT | METHOD | URI | MIN | AVG | MAX | SUM | +--------+--------+--------------------+-------+-------+-------+---------+ | 635 | GET | /@\w+ | 0.009 | 0.051 | 0.095 | 32.573 | | 322 | POST | /register | 0.013 | 0.048 | 0.075 | 15.572 | | 1 | GET | /initialize 　 | 0.047 | 0.047 | 0.047 | 0.047 | | 2323 | POST | /login | 0.001 | 0.040 | 0.090 | 92.066 | | 1760 | GET | /posts | 0.012 | 0.039 | 0.117 | 68.827 | ～以下略～
36. 13. 外部コマンドの呼び出しをやめる • app.rbのログイン処理の部分を修正する ▪修正前：外部コマンドのopensslを呼び出してハッシュ値を計算 def digest(src) # opensslのバージョンによっては (stdin)= というのがつくので取る `printf "%s" #{Shellwords.shellescape(src)} | openssl dgst -sha512 | sed 's/^.*= //'`.strip end ↓ ▪修正前：ライブラリからopensslを呼び出してハッシュ値を計算 require 'openssl' ~略~ def digest(src) # ログイン時のハッシュ値の計算 return OpenSSL::Digest::SHA512.hexdigest(src) end
37. 13. 外部コマンドの呼び出しをやめる • 改めて、alpでアクセスを解析する ➢ loginとregister（ログイン処理）の平均処理時間が上位から消えた（ボトルネックの解消） isucon@main:~$ alp json --sort avg -r -m "/posts/[0-9]+,/@\w+,/image/\d+" -o count,method,uri,min,avg,max,sum < /var/log/nginx/access.log +--------+--------+--------------------+-------+-------+-------+---------+ | COUNT | METHOD | URI | MIN | AVG | MAX | SUM | +--------+--------+--------------------+-------+-------+-------+---------+ | 1 | GET | /initialize | 0.078 | 0.078 | 0.078 | 0.078 | | 1107 | GET | /@\w+ | 0.007 | 0.035 | 0.172 | 38.258 | | 2230 | GET | /posts | 0.004 | 0.024 | 0.078 | 54.435 | | 7274 | GET | / | 0.003 | 0.020 | 0.150 | 143.447 | | 918 | POST | / | 0.002 | 0.017 | 0.065 | 15.999 | | 628 | POST | /comment | 0.004 | 0.015 | 0.050 | 9.703 |
38. 13. 外部コマンドの呼び出しをやめる • ベンチマークの結果 ➢ スコア：147662点→193529点 isucon@bench:~$ /home/isucon/private_isu.git/benchmarker/bin/benchmarker -u /home/isucon/private_isu.git/benchmarker/userdata -t http://13.114.20.202 { "pass":true, "score":193529, "success":185614, "fail":0, "messages":[] } isucon@bench:~$
39. 目次 1. 初期状態（約650点） 2. commentテーブルにインデックスを追加する（約 7000点） 3. unicorn workerプロセスを4にする（約15,000点） 4. 静的ファイルをnginxで配信する（約17,000点） 5. アップロード画像を静的ファイル化する（約 22,000点） 6. GET / を解析する 7. postとuserをJOINして必要な行数だけ取得する（約 90,000点） 8. ベンチマーカーが使用するファイルディスクリプタ上限を増加させる 9. プリペアドステートメントを改善する（約 110,000点） 10. commentテーブルにインデックスを追加する（約 115,000点） 11. postからのN+1クエリ結果をキャッシュする（約 180,000点） 12. 適切なインデックスが使えないクエリを解決する（約 200,000点） 13. 外部コマンドの呼び出しをやめる（約 240,000点） 14. MySQLの設定を調整する（約 255,000点） 15. memcachedへのN+1を解消する（約300,000点） 16. RubyのYJITを有効にする（約 320,000点）
40. 14. MySQLの設定を調整する • accessログを解析する ➢ INSERT（更新クエリ）が目立っている # Profile # Rank Query ID Response time Calls R/Call V/M Item # ==== ============================= ============= ===== ====== ===== ==== # 1 0x112E2062ED5F42DC18C1C389... 4.7709 14.9% 11606 0.0004 0.00 SELECT comments users # 2 0x26489ECBE26887E480CA8067... 4.4635 13.9% 753 0.0059 0.00 INSERT users # 3 0x9F2038550F51B0A3AB05CA52... 3.8675 12.1% 643 0.0060 0.00 INSERT comments # 4 0xBE0EEB30D0DA45B741071098... 3.2618 10.2% 7454 0.0004 0.00 SELECT posts # 5 0x422390B42D4DD86C7539A5F4... 3.0876 9.6% 11600 0.0003 0.00 SELECT comments # 6 0x009A61E5EFBD5A5E4097914B... 2.7647 8.6% 470 0.0059 0.00 INSERT posts # 7 0x6BABCF7018EBE3C3E2A7F30A... 2.3682 7.4% 5506 0.0004 0.00 SELECT comments users # 8 0x396201721CD58410E070DA94... 1.6819 5.2% 7964 0.0002 0.00 SELECT users # 9 0xECBECF7B69BE18F9FC9366A0... 1.4037 4.4% 6162 0.0002 0.00 SELECT posts # 10 0xBEFBE0AB18C503DA1D3F314D... 1.3012 4.1% 2290 0.0006 0.00 SELECT posts # 11 0xA047A0D0BA167343E5B36786... 0.9659 3.0% 4685 0.0002 0.00 SELECT users # 12 0xC37F2207FE2E699A3A976F5E... 0.6034 1.9% 1135 0.0005 0.00 SELECT comments
41. 14. MySQLの設定を調整する • INSERTの原因（fsync）を無効化する ※fsync：MySQLのバックアップ機能。ディスクキャッシュのデータをストレージと同期する。 ▪場所： /etc/mysql/mysql.conf.d/mysqld.cnf # コミットごとに更新データをログに置き、 1秒ごとにログをフラッシュする innodb_flush_log_at_trx_commit = 2 # バイナリログを無効化 disable-log-bin = 1
42. 14. MySQLの設定を調整する • 改めて、accessログを解析する ➢ INSERTが下位に移動（ボトルネックが解消した） # Profile # Rank Query ID Response time Calls R/Call V/M Item # ==== ============================= ============= ===== ====== ===== ==== # 1 0x112E2062ED5F42DC18C1C389... 4.5158 20.5% 12077 0.0004 0.00 SELECT comments users # 2 0xBE0EEB30D0DA45B741071098... 3.3324 15.1% 7602 0.0004 0.00 SELECT posts # 3 0x422390B42D4DD86C7539A5F4... 3.2087 14.5% 12061 0.0003 0.00 SELECT comments # 4 0x6BABCF7018EBE3C3E2A7F30A... 2.4715 11.2% 5742 0.0004 0.00 SELECT comments users # 5 0x396201721CD58410E070DA94... 1.8512 8.4% 8271 0.0002 0.00 SELECT users # 6 0xECBECF7B69BE18F9FC9366A0... 1.4553 6.6% 6301 0.0002 0.00 SELECT posts # 7 0xBEFBE0AB18C503DA1D3F314D... 1.2782 5.8% 2310 0.0006 0.00 SELECT posts # 8 0xA047A0D0BA167343E5B36786... 0.9464 4.3% 4771 0.0002 0.00 SELECT users # 9 0xC37F2207FE2E699A3A976F5E... 0.6284 2.8% 1180 0.0005 0.00 SELECT comments # 10 0x5F65502E75502F86855ED95D... 0.4703 2.1% 1180 0.0004 0.00 SELECT posts users # 11 0x9F2038550F51B0A3AB05CA52... 0.3721 1.7% 675 0.0006 0.00 INSERT comments # 12 0x26489ECBE26887E480CA8067... 0.3425 1.6% 789 0.0004 0.00 INSERT users # 13 0xCDEB1AFF2AE2BE51B2ED5CF0... 0.3120 1.4% 1180 0.0003 0.00 SELECT comments
43. 14. MySQLの設定を調整する • INSERTの原因（fsync）を無効化する ※fsync：MySQLのバックアップ機能。ディスクキャッシュのデータをストレージと同期する。 ▪場所： /etc/mysql/mysql.conf.d/mysqld.cnf # コミットごとに更新データをログに置き、 1秒ごとにログをフラッシュする innodb_flush_log_at_trx_commit = 2 # バイナリログを無効化 disable-log-bin = 1
44. 14. MySQLの設定を調整する • ベンチマークの結果 ➢ スコア：193529点→222192点 isucon@bench:~$ /home/isucon/private_isu.git/benchmarker/bin/benchmarker -u /home/isucon/private_isu.git/benchmarker/userdata -t http://13.112.126.211 { "pass":true, "score":222192, "success":212077, "fail":0, "messages":[] } isucon@bench:~$
45. 14. MySQLの設定を調整する • 解析用に全出力していたスロークエリを無効にする # slow_query_log = 1 slow_query_log = 0
46. 14. MySQLの設定を調整する • ベンチマークの結果 ➢ スコア：215087点→225272点 isucon@bench:~$ /home/isucon/private_isu.git/benchmarker/bin/benchmarker -u /home/isucon/private_isu.git/benchmarker/userdata -t http://13.112.126.211 { "pass":true, "score":225272, "success":215087, "fail":0," messages":[] } isucon@bench:~$
47. 目次 1. 初期状態（約650点） 2. commentテーブルにインデックスを追加する（約 7000点） 3. unicorn workerプロセスを4にする（約15,000点） 4. 静的ファイルをnginxで配信する（約17,000点） 5. アップロード画像を静的ファイル化する（約 22,000点） 6. GET / を解析する 7. postとuserをJOINして必要な行数だけ取得する（約 90,000点） 8. ベンチマーカーが使用するファイルディスクリプタ上限を増加させる 9. プリペアドステートメントを改善する（約 110,000点） 10. commentテーブルにインデックスを追加する（約 115,000点） 11. postからのN+1クエリ結果をキャッシュする（約 180,000点） 12. 適切なインデックスが使えないクエリを解決する（約 200,000点） 13. 外部コマンドの呼び出しをやめる（約 240,000点） 14. MySQLの設定を調整する（約 255,000点） 15. memcachedへのN+1を解消する（約 300,000点） 16. RubyのYJITを有効にする（約 320,000点）
48. 15. memcachedへのN+1を解消する • アプリサーバ壊れて復旧不可になった isucon@bench:~$ /home/isucon/private_isu.git/benchmarker/bin/benchmarker -u /home/isucon/private_isu.git/benchmarker/userdata -t http://13.112.126.211 {"pass":false,"score":0,"success":20,"fail":50,"messages":["response code should be 200, got 500 (GET /@terri)"," ステータスコードが正しくありません : expected 200, got 500 (POST /)","静的ファイルが正しくありません (GET /css/style.css)","静的ファイルが正しくありません (GET /favicon.ico)","静的ファイルが正しくありません (GET /image/10000.png)","静的ファイルが正しくありません (GET /image/17582.jpg)","静的ファイルが正しくありません (GET /image/9980.jpg)","静的フ ァイルが正しくありません (GET /image/9981.jpg)","静的ファイルが正しくありません (GET /image/9982.jpg)","静的ファイルが正しくありません (GET /image/9983.jpg)","静的ファイルが正しくありません (GET /image/9985.jpg)","静的ファイルが正 しくありません (GET /image/9986.jpg)","静的ファイルが正しくありません (GET /image/9987.jpg)","静的ファイルが正しくありません (GET /image/9988.jpg)","静的 ファイルが正しくありません (GET /image/9989.jpg)","静的ファイルが正しくありません (GET /image/9990.jpg)","静的ファイルが正しくありません (GET /image/9991.jpg)","静的ファイルが正しくありません (GET /image/9993.jpg)","静的ファイルが 正しくありません (GET /image/9994.jpg)","静的ファイルが正しくありません (GET /image/9995.jpg)","静的ファイルが正しくありません (GET /image/9996.jpg)","静 的ファイルが正しくありません (GET /image/9997.jpg)","静的ファイルが正しくありません (GET /image/9998.jpg)","静的ファイルが正しくありません (GET /image/9999.jpg)","静的ファイルが正しくありません (GET /js/main.js)","静的ファイルが正 しくありません (GET /js/timeago.min.js)"]} isucon@bench:~$