アプリケーションエンジニアが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 をチューニングしたいと思います。
長くなったので、今回はここまで。
