アプリケーションエンジニアがISUCON7の予選を解いてみた その2
前回のポストは以下をご参照下さい。
前回画像のバイナリーをMySQLに突っ込んでいる箇所がヤバそうということが分かったため、今回はそこの改善からやっていきます。
画像をDBアクセスせずに返す
以下の記事を参考にしながらISUCON7の予選突破チームがどういう戦略を取ったのか確認しました。
ざっと見た感じだとfujiwara組さんの webサーバーに画像ファイルを保存して画像がなければDBにアクセスする という戦略が一番コストが少なく実装できそうなのでその戦法を採用。
ちなみに現在の環境だとホストの/iconsをサーバーがマウントしているため、1つのサーバーでiconsをアップロードすると自動的にすべてのサーバーで同じ画像を参照できるようになるはずです。
そうすると必ずローカルファイルがヒットするため、余計なパフォーマンスゲインがあるはず。ただ今回は学習が主目的なのため、その辺りは見なかったことにしておきます。
DBから画像を抜き出す
以下の変更で起動時にMySQLから画像を抜き出し、icons配下へ保存する変更を加えます。
getIconでローカルの画像ファイルを返す
アプリケーションのコードを変更して，はじめにローカルで画像を検索するように変更します。
この辺は以下のコードほぼそのまま。
postProfileでローカルに画像ファイルを保存する
postProfileでアップロードした画像をローカルへ保存するように変更します。
この辺も以下のコードほぼそのまま。
ここまででスコアは 52828 まで上昇しました。
現状のボトルネックをもう一度把握し直す
vmstat
app01 (webサーバー)
isucon@78041320129c:~/isubata$ vmstat 1 procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu----- r b swpd free buff cache si so bi bo in cs us sy id wa st 24 4 103056 522844 46264 243300 2 34 792 633 1817 5224 7 9 83 1 0 13 0 103056 515344 46708 243388 0 0 52 2416 21887 52629 35 66 0 0 0 30 0 103056 512984 47108 244908 0 0 44 2892 20290 58955 38 62 0 0 0 42 0 103056 511828 47380 244936 0 0 0 1444 15136 67755 57 44 0 0 0 46 0 103056 512360 47712 244640 0 0 0 1724 17967 61763 39 62 0 0 0 27 1 103056 508080 48056 245948 0 0 4 2344 20889 63859 48 52 0 0 0 42 5 103056 506900 48364 245316 0 0 12 1504 20968 62356 39 62 0 0 0 39 0 103056 502560 48688 246260 0 0 260 1452 21662 62227 42 59 0 0 0 44 0 103056 501072 48992 246584 0 0 0 1492 17674 68371 53 47 0 0 0 39 0 103056 495348 49312 246536 0 0 8 1312 20131 61326 44 57 0 0 0 32 0 103056 489940 49620 246988 0 0 0 1248 19318 56272 49 51 1 0 0 44 2 103056 485044 49900 246768 0 0 0 1068 19536 55937 41 59 0 0 0 36 0 103056 481352 50228 247532 0 0 4 1436 19397 58469 48 52 0 0 0 39 0 103052 479432 50500 247636 0 0 0 1112 18378 63232 46 54 0 0 0 45 0 103052 472420 50812 247488 0 0 0 1060 18072 53886 35 65 0 0 0 29 1 103052 469852 51124 247856 0 0 0 1240 18979 56133 40 60 0 0 0 43 1 103052 469072 51432 247544 0 0 4 1424 18615 66641 45 55 0 0 0 35 0 103052 469168 51720 248268 0 0 0 1100 19934 62102 41 59 1 0 0 45 0 103052 468000 52056 248368 0 0 0 1308 21721 70621 37 64 0 0 0 35 0 103052 467772 52380 248664 0 0 4 1232 18308 63425 46 55 0 0 0 38 0 103052 467248 52708 248848 0 0 0 1212 20266 64809 41 59 0 0 0
app03 (dbサーバー)
isucon@ad3bfb718b03:~/isubata$ vmstat 1 procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu----- r b swpd free buff cache si so bi bo in cs us sy id wa st 40 1 103076 726992 26404 216824 2 36 843 630 1514 4259 6 7 86 1 0 48 0 103076 720664 26764 217648 0 0 8 2644 21197 67151 42 58 0 0 0 45 1 103076 717708 27128 219444 0 0 4 2100 18611 65462 52 48 0 0 0 35 0 103076 712372 27476 220976 0 0 16 2496 22080 63306 42 59 0 0 0 33 1 103076 705160 27964 221184 0 0 112 2284 24161 56237 30 67 2 1 0 41 0 103076 700180 28292 221188 0 0 70 1172 21565 65008 42 59 0 0 0 41 0 103076 694624 28656 221208 0 0 4 1192 21318 63835 44 56 0 0 0 43 0 103076 689028 29044 222596 0 0 4 4032 18573 71293 52 49 0 0 0 39 1 103076 682212 29412 222556 0 0 16 3040 23174 67367 36 64 0 0 0 31 0 103076 673816 29728 223524 0 0 12 3348 23139 64012 43 57 0 0 0 41 0 103076 668700 30032 224448 0 0 8 2992 19105 66637 46 55 0 0 0 40 1 103076 662992 30348 225036 0 0 4 2788 19637 69112 43 57 0 0 0 44 0 103076 661076 30636 224876 0 0 0 872 20857 55790 40 60 1 0 0 32 1 103076 659488 30984 225540 0 0 20 1036 23152 65758 39 61 0 0 0 33 0 103076 657004 31296 225744 0 0 0 976 21149 63253 42 58 0 0 0 40 0 103076 655972 31616 225904 0 0 12 1040 19495 69417 47 54 0 0 0 33 0 103076 646500 31928 226716 0 0 12 1544 20629 57917 44 55 1 0 0 34 1 103076 645540 32256 226756 0 0 8 1048 21868 66012 39 61 0 0 0 34 0 103076 644352 32568 227280 0 0 0 964 22850 72506 44 56 0 0 0
myprofiler
## 2019-02-10 05:32:19.35 +0000 488 SELECT COUNT(*) as cnt FROM message WHERE channel_id = ? 378 SELECT * FROM haveread WHERE user_id = ? AND channel_id = ? 276 SELECT name, display_name, avatar_icon FROM user WHERE id = ? 76 INSERT INTO message (channel_id, user_id, content, created_at) VALUES (?, ?, ?, NOW()) 32 SELECT * FROM message WHERE id > ? AND channel_id = ? ORDER BY id DESC LIMIT N 29 SELECT * FROM user WHERE id = ? 14 INSERT INTO haveread (user_id, channel_id, message_id, updated_at, created_at) VALUES (?, ?, ?, NOW(), NOW()) ON DUPLICATE KEY UPDATE message_id = ?, updated_at = NOW() 3 SELECT COUNT(*) as cnt FROM message WHERE channel_id = ? AND ? < id 1 SELECT * FROM message WHERE channel_id = ? ORDER BY id DESC LIMIT ? OFFSET ? 1 SELECT id FROM channel
pprof
getIcon メソッドのチューニングで気持ち良いまでに SELECT name, data FROM image WHERE name = ? がボトルネックではなくなったことが分かる。
一方で以前としてDBの負荷は高いため引き続きDB周りのチューニングが必要そう。
pprofを見ると fetchUnread メソッドの負荷が高く、myprofilerを見ると SELECT COUNT(*) as cnt FROM message WHERE channel_id = ? と SELECT * FROM haveread WHERE user_id = ? AND channel_id = ? という2つのクエリのサンプル数が多い。
fetchUnread メソッドを確認するとたしかにこの2つのクエリが呼ばれていることが確認できます。次はfetchUnread メソッドをチューニングしていきたいと思います。
追記
実際にはechoのプロセスの再起動がうまくいっていませんでした... ↑の値は恐らく本当の値とは異なります...
fetchUnread のN+1を解消する
fetchUnread はユーザーの未読メッセージ数チャネルごとに集計して返すメソッド。チャネルIDごとにループをかけて以下の作業を行っているため、N+1が発生している。
- havreadテーブルからユーザーがそのチャネルでを開いた際の最新メッセージのIDを取得する
- messageテーブルからユーザーが最後に読んだメッセージ以降のIDのメッセージを取得する
パット見、messageテーブルからhavereadの差集合をとってchannel_idでgroup_byすればいいのではと思えてしまいますが、havereadテーブルはユーザーがそのチャネルを開いた際の最新メッセージのIDが入っているだけ（読んだすべてのメッセージが入っているわけではない）なのでその戦略は取れない。
ここは様々な選択肢がありますが、なるべくシンプルに以下の方法を採用します。
- channelテーブルに総メッセージ数を表すmessage_countカラムを追加する
- ユーザー * チャネルの既読メッセージ数を保持するread_countテーブルを作成する
- 未読数は message_count - read_count で取得する
この辺はスギャブロエックスさんの戦略を参考にしました。
message_countカラムの追加
alter table channel add message_count bigint unsigned default 0 not null; を実行してmessage_countカラムを追加する。
起動時にmessage_countをセットする変更
サーバー起動時にmessage_countを集計してセットするため、initMessageCount メソッドを追加します。
一点、私の環境では make start/app/go を実行しても上記のChannelInfo構造体の変更がうまく反映されませんでした。
echoのプロセスをきちんと殺してから出ないとうまく反映されないようなので、app01とapp02のプロセスを必ず殺してからmake start/app/go を実行するようにしたほうが良さそうです。
message投稿時にmessage_countを更新する変更
上の変更に合わせて今度はメッセージ投稿時にmessage_countカラムを更新する変更を加えます。
unreadをmessage_countとread_countの差分から取得するよう変更
create table read_count(channel_id bigint not null, user_id bigint not null, count bigint default 0 not null, primary_key(channel_id, user_id)); を実行してread_countテーブルを追加します。
また、下記の変更でunreadの値を message_count - read_count で取得できるように変更します。
ここまででスコアは 29537. echoのプロセスの再起動に失敗していた前回よりも下がってしまった...
ボトルネックの確認
vmstat
app01 (webサーバー)
isucon@78041320129c:~/isubata$ vmstat 1 procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu----- r b swpd free buff cache si so bi bo in cs us sy id wa st 41 2 211060 113192 68244 589800 0 1 25 26 129 52 0 1 99 0 0 44 2 211060 107412 68688 590348 0 0 164 1832 9276 21543 22 78 0 0 0 22 2 211060 104332 68980 591288 0 0 12 1244 8980 23578 27 73 1 0 0 51 0 211060 99060 69240 592212 0 0 12 1356 10100 24555 18 82 0 0 0 35 1 211060 97884 69592 590504 0 0 40 2256 11248 27079 27 73 0 0 0 35 1 211060 95060 69888 591760 0 0 24 1188 10560 24428 26 73 1 0 0 37 1 211060 92900 70128 591508 0 0 0 1036 10952 27629 25 75 0 0 0 23 3 211060 89236 70344 591220 0 0 16 860 10163 26372 22 78 0 0 0 46 0 211060 83464 70708 591068 0 0 28 1936 10844 29331 25 74 1 1 0 28 1 211060 81460 70924 590736 0 0 16 928 9565 25634 24 75 2 0 0 23 1 211060 77088 71240 590388 0 0 44 1424 9865 24277 25 74 1 0 0 43 1 211060 68280 71560 590576 0 0 24 1712 7960 19626 24 74 1 2 0 43 1 211564 70276 70368 584732 0 504 136 2976 10624 25587 26 73 1 0 0
app03 (dbサーバー)
isucon@ad3bfb718b03:~/isubata$ vmstat 1 procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu----- r b swpd free buff cache si so bi bo in cs us sy id wa st 26 0 246720 70460 12292 277964 0 2 27 27 133 63 0 1 98 0 0 35 0 246708 67508 12592 279092 8 0 12 2836 11041 26477 25 72 2 1 0 34 1 246852 77388 12328 269712 8 152 260 3816 10359 25888 25 75 0 0 0 31 0 246848 76024 12592 270912 0 0 144 3028 10650 25552 30 67 3 1 0 39 0 246848 72980 12876 271512 0 0 536 2832 9669 25179 29 71 1 0 0 25 2 247972 90360 12052 254780 4 1128 36 3996 8338 20401 23 74 2 1 0 38 1 247972 90492 12396 254768 0 0 24 3740 10414 24218 25 74 1 1 0 40 1 247972 84800 12752 257264 0 0 36 3652 10597 23771 31 68 0 1 0 42 1 247972 81048 13116 259752 0 0 12 2952 11236 30319 30 69 1 0 0 41 0 247972 73808 13392 261816 4 0 116 3000 10608 24685 22 78 0 0 0 25 1 247972 70020 13740 262728 0 0 4 2584 10891 27299 34 66 0 0 0 48 1 247968 67796 14004 262452 4 0 4 976 9167 25268 29 71 1 0 0 37 1 248136 73760 13608 253980 8 176 16 1360 8364 23565 24 76 0 0 0 40 2 248136 69236 13992 254152 0 0 0 1268 8915 25059 22 78 0 0 0 46 1 248136 66532 14232 254784 0 0 184 900 9999 24032 31 68 0 1 0 40 0 248664 86572 13440 233640 0 528 4 1572 9601 23854 19 80 1 0 0 34 2 248664 81040 13812 234672 0 0 124 1076 9558 23042 29 71 0 1 0 30 1 248664 71728 14060 237064 0 0 4 972 9178 23529 21 77 1 0 0 41 3 248660 68808 14400 238792 4 0 16 1944 8613 24236 31 69 0 0 0 42 1 249072 87220 13700 219072 0 412 12 1720 9105 23071 33 66 0 1 0 38 1 249072 75220 14080 223628 0 0 12 2564 9466 23631 32 68 0 0 0 35 1 249072 74384 14356 224320 0 0 712 2576 9613 23116 27 73 0 0 0 41 0 249072 70108 14720 227956 0 0 128 3044 10245 26519 23 77 1 0 0 41 1 249072 70044 15096 227036 0 0 48 1804 10282 27513 26 74 0 0 0 41 0 249072 66196 15328 230052 12 0 872 1108 9906 24017 29 67 2 2 0
Frame Graphe
fetchUnread の負荷がガクッと下がって、getMessage の負荷が相対的に目立ってきました。そこで次は getMessage をチューニングしたいと思います。
長くなったので、今回はここまで。
アプリケーションエンジニアがISUCON7の予選を解いてみた その1
私は普段アプリケーションエンジニアとして働いていますが、ISUCONいつも楽しそうだなーと思って見ています。今年こそは参加したいと思い､まずは過去問 としてISUCON7の予選を解いてみようと思い立ちました。
はじめに
このポストはその際の作業ログ的な立ち位置です。私のようにアプリケーションエンジニアだけどISUCON参加してみたいという方の参考になるよう、問題を解くにあたって参考にした情報などなるべく残すようにしてみました。
またはじめにきちんと開示しておくと、ISUCON7 の予選問題を解くにあたってすでに様々な方のブログポストを読んでいます。そのため、ある程度この問題のどこにボトルネックがあるのか事前に把握しています。
ただ、なるべく "ボトルネックがどこにあるか知らなかったとしてもどうやってそこにたどり着けるのか" を意識して作業したつもりです。どなたかの参考になれば幸いです。
基本的には以下2つのブログポストを参考にしつつ、必要に応じて他のブログポストの内容も参照しながら作業を進めていきたいと思います。
環境構築
インスタンス立てるのも面倒臭いので,今回はこちらを使ってローカルでISUCONの環境を構築したいと思います。
一点注意として、私の環境では make up するとMySQLの起動に失敗しました。いろいろ調べていくと, 以下のコメントで解決しました。
make attach/app03 でMySQLのコンテナにログインし、sudo find /var/lib/mysql -type f -exec touch {} \; を実行後に make mysql/start で正常にMySQLが起動するようになりました。
マニュアル/レギュレーションの確認
当日のマニュアル/レギュレーションを確認しておきます。
構成
webサーバーが2台 (app01, app02)、dbサーバー1台 (app03) の3台構成。
マシンの調査
スペックの確認
3台とも同じ。2コアでメモリが2GB、スワップが1GB。
isucon@ad67fcd65989:~/isubata$ grep processor /proc/cpuinfo
processor : 0
processor : 1
isucon@ad67fcd65989:~/isubata$ free -m
total used free shared buff/cache available
Mem: 1999 715 324 0 959 1110
Swap: 1023 23 1000
プロセスの確認
各マシンで ps aux を実行して不要なプロセスが動いていないか確認します。見たところ特に殺せそうなプロセスはなかったためOK。
アプリを触ってみる
実際にアプリの挙動を確認してみます。http://0.0.0.0:8081/ もしくは http://0.0.0.0:8082/にアクセス。ユーザー登録からチャンネルの作成/確認など、一通り動かしてみると2ちゃんねるっぽい掲示板アプリであることが分かります。
ベンチを回してみる
make bench/start でベンチを走らせ、make bench/score で初期スコアを確認します。4707 でした。
vmstat
ベンチを回すついでにvmstatコマンドでざっくりと各サーバーの状況を取ってみます。
app01 (webサーバー)
isucon@78041320129c:~/isubata$ vmstat 5 procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu----- r b swpd free buff cache si so bi bo in cs us sy id wa st 6 0 746468 83016 6888 455884 0 5 22 30 73 191 1 1 99 0 0 28 4 753980 78304 7520 423048 217 1670 3874 4363 12624 32418 33 65 1 0 0 41 1 774708 69488 8612 443472 26 4162 20737 6709 9269 29567 35 65 0 0 0 40 0 790140 74176 8316 453092 90 3165 10917 6556 9467 30596 34 65 1 0 0 41 0 792632 70016 8248 459064 279 750 2129 3202 8016 28947 33 67 0 0 0 26 0 803932 72508 6776 439508 110 2345 2260 4744 8687 30186 35 65 0 0 0 24 0 818808 82116 6172 427648 199 3134 3327 5361 9365 31439 33 67 1 0 0 19 0 823032 83068 6224 432720 54 900 1801 4326 9230 30503 32 67 1 0 0 26 0 829024 75868 6056 435336 274 1438 4261 6826 9711 31012 30 69 1 0 0 22 1 845860 63760 4608 383932 76 3418 2433 6184 8591 26687 34 65 1 0 0 29 2 865696 66548 3336 372760 45 4011 13733 7366 9566 28477 33 66 1 0 0
app02 (webサーバー)
isucon@04d632d063c5:~/isubata$ vmstat 5 procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu----- r b swpd free buff cache si so bi bo in cs us sy id wa st 3 0 891776 66100 6580 415436 0 6 26 33 77 202 1 1 99 0 0 42 0 897920 75572 6752 359200 212 1390 5560 3638 11912 31203 32 66 2 1 0 38 2 911552 66636 6528 382508 134 2843 20476 6693 9116 31291 35 65 0 0 0 43 1 932452 65204 5568 404648 977 4989 31758 7045 9005 29463 34 66 0 0 0 35 0 944052 67480 3860 401556 1368 3538 10998 4876 8665 29767 37 62 1 0 0 21 1 957188 71604 2844 394952 2434 5192 13190 8425 8484 25573 35 64 1 0 0 16 0 967508 63432 2464 373784 2913 5055 16518 8254 9877 28847 38 61 1 0 0 38 3 992032 75700 3208 384320 2010 6612 17517 12240 9687 28078 34 65 1 0 0 18 0 1016568 73004 2944 373776 1539 6094 12325 9526 10215 30227 33 66 1 0 0 37 1 1046720 74952 2964 372864 1672 7278 17936 10458 9980 27964 32 67 1 0 0 41 4 1048212 69116 3504 376356 2367 2147 15011 6727 9275 26972 33 65 1 0 0 3 1 1012940 160008 2900 341724 3034 2638 30088 8505 8272 23301 28 69 2 1 0
app03 (dbサーバー)
isucon@ad3bfb718b03:~/isubata$ vmstat 5 procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu----- r b swpd free buff cache si so bi bo in cs us sy id wa st 4 0 1021260 73564 4584 378820 1 8 33 36 80 211 1 1 99 0 0 39 3 1020040 69852 4920 355000 874 376 1777 4165 9004 19957 17 41 41 1 0 31 1 1030796 79224 6240 308792 1262 3113 22822 8787 9829 27506 36 63 0 0 0 27 4 1048276 66428 4848 336116 610 3962 39084 9162 10046 30640 36 63 0 0 0 36 0 1048528 69956 2412 305464 1106 862 43573 3910 9008 26961 34 66 1 0 0 19 2 1048360 69048 1496 300276 1983 1434 61963 5530 9703 26530 32 67 1 0 0 44 4 1047928 68984 1112 297296 2714 2070 71141 7183 9019 23058 33 65 1 0 0
webサーバー, dbサーバーともにCPU使用率に苦しんでいるようです (特にsystem)。vmstatの各指標の解釈に関しては以下のポストを参照しました。
また、各指標のもう少し細かい解釈などは少し古い本ですが、サーバー/インフラを支える技術の4章 性能効能、チューニングの章も手元に置きながら確認しました。
dbサーバーのボトルネックを特定する
まずはdbサーバーのボトルネックをもう少し詳しく見るため、一旦myprofiler を使って重いクエリを特定します。
myprofilerのインストール
dbサーバに入って以下を実行する。
wget https://github.com/KLab/myprofiler/releases/download/0.2/myprofiler.linux_amd64.tar.gz tar xf myprofiler.linux_amd64.tar.gz sudo mv myprofiler /usr/local/bin/ rm myprofiler.linux_amd64.tar.gz
myprofilerの実行
myprofiler -user=isucon -password=isucon でprofilerを実行した状態でベンチを走らせる。
1539 SELECT name, data FROM image WHERE name = ? 135 SELECT COUNT(*) as cnt FROM message WHERE channel_id = ? 26 SELECT * FROM haveread WHERE user_id = ? AND channel_id = ? 12 SELECT * FROM message WHERE id > ? AND channel_id = ? ORDER BY id DESC LIMIT N 10 SELECT name, display_name, avatar_icon FROM user WHERE id = ? 9 SELECT * FROM user WHERE id = ? 8 INSERT INTO image (name, data) VALUES (?, ?) 4 INSERT INTO message (channel_id, user_id, content, created_at) VALUES (?, ?, ?, NOW()) 4 SELECT * FROM user WHERE name = ? 3 UPDATE user SET avatar_icon = ? WHERE id = ?
SELECT name, data FROM image WHERE name = ? がダントツでヤバそう。imageテーブルの data カラムを見ると画像のバイナリーを直接ぶち込んでいるのも分かる。バイナリーはサイズが大きく、書き込み/読み込みの際にボトルネックになりやすい。ここはサクッと解決できないので今は一旦パス。
また上位2つのクエリに対してそれぞれindexが効いているか確認する。
mysql> show create table image; +-------+--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+ | Table | Create Table | +-------+--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+ | image | CREATE TABLE `image` ( `id` bigint(20) unsigned NOT NULL AUTO_INCREMENT, `name` varchar(191) DEFAULT NULL, `data` longblob, PRIMARY KEY (`id`) ) ENGINE=InnoDB AUTO_INCREMENT=1199 DEFAULT CHARSET=utf8mb4 | +-------+--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+ 1 row in set (0.00 sec) mysql> show create table message; +---------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+ | Table | Create Table | +---------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+ | message | CREATE TABLE `message` ( `id` bigint(20) NOT NULL AUTO_INCREMENT, `channel_id` bigint(20) DEFAULT NULL, `user_id` bigint(20) DEFAULT NULL, `content` text, `created_at` datetime NOT NULL, PRIMARY KEY (`id`) ) ENGINE=InnoDB AUTO_INCREMENT=12386 DEFAULT CHARSET=utf8mb4 | +---------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+ 1 row in set (0.00 sec)
imageテーブルのnameとmessageテーブルのchannel_idは共にindexがはられていないようなのでここで対応しておきます。
mysql> ALTER TABLE image ADD INDEX index_image_on_name(name); Query OK, 0 rows affected (0.05 sec) Records: 0 Duplicates: 0 Warnings: 0 mysql> show create table image; +-------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+ | Table | Create Table | +-------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+ | image | CREATE TABLE `image` ( `id` bigint(20) unsigned NOT NULL AUTO_INCREMENT, `name` varchar(191) DEFAULT NULL, `data` longblob, PRIMARY KEY (`id`), KEY `index_image_on_name` (`name`) ) ENGINE=InnoDB AUTO_INCREMENT=1199 DEFAULT CHARSET=utf8mb4 | +-------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+ 1 row in set (0.00 sec) mysql> ALTER TABLE message ADD INDEX index_message_on_channel_id(channel_id); Query OK, 0 rows affected (0.03 sec) Records: 0 Duplicates: 0 Warnings: 0 mysql> show create table message; +---------+--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+ | Table | Create Table | +---------+--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+ | message | CREATE TABLE `message` ( `id` bigint(20) NOT NULL AUTO_INCREMENT, `channel_id` bigint(20) DEFAULT NULL, `user_id` bigint(20) DEFAULT NULL, `content` text, `created_at` datetime NOT NULL, PRIMARY KEY (`id`), KEY `index_message_on_channel_id` (`channel_id`) ) ENGINE=InnoDB AUTO_INCREMENT=12386 DEFAULT CHARSET=utf8mb4 | +---------+--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+ 1 row in set (0.00 sec)
ここまででbenchを回すとscoreは 16331 でした。
webサーバーのボトルネックを特定する
webサーバーも同様にどこがボトルネックになっているのかもう少し詳しく見ておきます。こちらはnet/http/pprofを利用します。
net/http/pprofの準備
こちらを参考にwebサーバーにpprofを仕込みます。
Install pprof. · ryotarai/isucon7q@76ec7ec · GitHub
終わったら, make app/start/go アプリの再ビルドと再起動を忘れずに。
net/http/pprofの実行
今回は以下の方法でpprofの結果をWeb UIで確認したいと思います。このあたりに関しては以下の記事を参考にしました。
http://blog.livedoor.jp/sonots/archives/18193659.html christina04.hatenablog.com
手順は以下の通りです。
1 ベンチを実行する
2 各webサーバーにログインしてpprofを実行する。ホスト側のisucon7-qualify-docker/ がマウントされているので, 各プロファイル結果はホスト側でも確認できるはず。
# @app01 curl -s http://localhost:6060/debug/pprof/profile > web1_cpu.pprof # @app02 curl -s http://localhost:6060/debug/pprof/profile > web2_cpu.pprof
3 手元(ホストのマシン)でプロファイル結果をWEB UIで表示する
# 以下はすべてホストのマシン go get -u github.com/google/pprof pprof -http=localhost:8080 web1_cpu.pprof # or web2_cpu.pprof
以下のような画面が立ち上がるはず
このままだとちょっと直感的に分かりづらいので view > Flame GraphからFlame Graphを表示します。Flame Graphの読み方に関しては以下のポストを参照しました。
Flame Graphはこんな感じになるはず。
負荷の大きい順に
main.getIcon (23.56%, 1.88s)main.fetchUnread (10.53%, 0.84s)main.getMessage (7.52%, 0.60s)main.getHistory (6.89%, 0.55s)
getIcon は err := db.QueryRow("SELECT name, data FROM image WHERE name = ?", c.Param("file_name")).Scan(&name, &data) を実行している。
先程のimageテーブルにアクセスしているので、バイナリーを直接ぶち込んでいるのがパフォーマンスネックになっていそう。ここはやはり次の改善ポイントとして取り組んで間違いなさそう。
fetchUnread はざっと見た感じ for _, chID := range channels でチャネルごとにループを回してqueryを発行しているように見えるので恐らくN+1が発生していそう。
あとの2つに関しては上の2つが解消してからもう少し詳しく見てみる。
一旦長くなったのでその1はここまで。その2ではimageテーブルのバイナリーぶち込み問題を解決したいと思います。
