ISUCON10本選に出場し17:00時点ではベストスコア1位だったもののfailフィニッシュになりました
TL;DR
ISUCON10本選に出場し、17:00時点でベストスコア1位につけるも最終的にはfailフィニッシュとなった（と思われる）matsuuです、こんにちは。
体制（予選から再掲）
チーム名 ウー馬場ーイーツ
| あいこん | なまえ | やくわり |
|---|---|---|
 |
matsuu | バリバリ実装する前衛 |
 |
netmarkjp | 司令塔 |
 |
ishikawa84g | |
本選も同じくそれぞれの場所からリモート体制です。
方針
基本的に予選を踏襲してsshrc+tmux+vim(or nvim)です。
gitについてはファイルシステムのルートで git init を実行し、.gitignoreで /home と /etc を記録するようにしました。このあたりはまだ改善余地があったので来年に向けて改善を続けます。
解析ツール
予選と同じのため省略
最終構成
最終構成は以下の通りです。
| サーバ | スペック | 構成要素 | 備考 |
|---|---|---|---|
| isu1 | 1コア1GB | envoy+varnish | varnishを追加インストール |
| isu2 | 2コア2GB | mysql | バージョン変更なし |
| isu3 | 4コア1GB | xsuportal/benchmark_server | golang |
当初は1台目のみを使い、ある程度負荷傾向が定まってきてから最適なスペックに配分していきました。
ベンチマーク結果
初動
開始後、自分はkataribeやpt-query-digestなどを設定できるよう調整。言語もrubyからgolangに変更しています。
envoyを自分で触るのはほぼ初めてだったものの、envoyの公式ドキュメントを確認したところデフォルトのログ形式でも %DURATION% として応答時間が記録されることを確認。そのままkataribeに食わせることに。kataribeの設定はこんな感じ。
# kataribe.toml scale = -3 effective_digit = 3 log_format = '^\[([^\]]+)\] "((?:\\"|[^"])*)" (\d+) (\d+|-) (\d+) (\d+) (\d+) (\d+) .*$' request_index = 2 status_index = 3 bytes_index = 6 duration_index = 7
今回MySQLのバージョンが最初から8.0.21だったので、予選から本選の間に調べたREDOログの無効化を速攻で実施してます。
ALTER INSTANCE DISABLE INNODB REDO_LOG;
本番環境で実行しちゃダメだぞ！
マニュアルを読む
私が初動のenvoy調整をしている間に @netmarkjp と @ishikawa84g でマニュアルを通読してもらいました。 気になるところは @ishikawa84g がスライドにまとめ上げていて後で参照しやすくとても助かりました。わいわい。
初回ベンチ実行
初回ベンチ実行でダッシュボード表示(/api/audience/dashboard)が遅いことを確認してます。 kataribe実行結果より
Top 50 Sort By Total Count Total Mean Stddev Min P99.9 Max 2xx 3xx 4xx 5xx TotalBytes MinBytes MeanBytes MaxBytes Request 11606 1821.391 0.1569 0.1799 0.002 1.560 1.990 11606 0 0 0 249308292 2 21480 25122 GET /api/audience/dashboard HTTP/2 1596 581.121 0.3641 0.1905 0.001 0.665 0.666 1596 0 0 0 34450 5 21 80 POST /xsuportal.proto.services.bench.BenchmarkQueue/ReceiveBenchmarkJob HTTP/2 2978 572.663 0.1923 0.2492 0.001 1.941 2.525 2978 0 0 0 34173 0 11 73 get /api/contestant/notifications?.*
アプリ実装とSQLを確認したもののすぐの改修が難しく、いくつかインデックスの追加しても速度改善が見込めない状況でした。
キャッシュ戦略
ただ、マニュアルをしっかり読んでいたため1秒間はキャッシュできることを確認したのでenvoyとxsuportalの間にVarnishを挟んでキャッシュする戦略としました。
初期化対策のため /initialize にアクセスがあった場合はキャッシュを削除するよう設定しています。
# /etc/varnish/default.vcl
vcl 4.0;
backend default {
.host = "127.0.0.1";
.port = "9292";
}
sub vcl_recv {
if (req.url ~ "^/initialize") {
ban("obj.http.url ~ ^/api/audience/dashboard");
}
}
sub vcl_backend_response {
if (beresp.http.content-type ~ "text") {
set beresp.do_gzip = true;
}
if (beresp.http.content-type ~ "javascript") {
set beresp.do_gzip = true;
}
if (bereq.url ~ "^/packs/") {
set beresp.ttl = 60s;
set beresp.http.cache-control = "public, max-age=60";
}
if (bereq.url ~ "^/api/audience/dashboard") {
set beresp.ttl = 1s;
set beresp.http.cache-control = "public, max-age=1";
}
}
この１秒キャッシュはその後負荷が増えると応答遅延などの影響でエラーとなる場合あり、キャッシュ時間は 1s → 0.8s → 0.7s と徐々に短くしてます。
上記の結果もありkataribeの結果はダッシュボード表示が2番に下がったことを確認してます。
Top 50 Sort By Total Count Total Mean Stddev Min P99.9 Max 2xx 3xx 4xx 5xx TotalBytes MinBytes MeanBytes MaxBytes Request 1822 510.656 0.2803 0.2199 0.007 0.637 0.671 1822 0 0 0 70231 5 38 80 POST /xsuportal.proto.services.bench.BenchmarkQueue/ReceiveBenchmarkJob HTTP/2 21365 205.622 0.0096 0.0265 0.000 0.382 0.416 21354 0 0 11 790986026 2 37022 55120 GET /api/audience/dashboard HTTP/2 4392 129.572 0.0295 0.0282 0.002 0.332 0.400 4392 0 0 0 77408 0 17 74 get /api/contestant/notifications?.*
ReceiveBenchmarkJob対策
次に多い ReceiveBenchmarkJobのソースコードを見て「ウッ、gRPCなんも分からん」となったものの、SELECT FOR UPDATEからUPDATEを実行している実装があって一応「あっこれ予選で見たやつだ」となって念の為修正しています。
負荷が増えないところからTeamCapacityの気づき
CPUやメモリに負荷がなくボトルネックになっている様子がないことから何らかのリミットを考えてトラフィック量を削減するためにVarnishでgzip応答を返してみるものの改善せず、何だろうなとマニュアルとソースとにらめっこしていたところ、アプリ側でTeamCapacityで上限が制約されていることを確認。これだーと気づいてTeamCapacityを増やしていきました。 10→20→60→120→180→60。このあたりの調整に時間をかけていたのですが、最終的には120でフィニッシュしています。
open files limit対策
TeamCapacityを増やしていくとenvoyやアプリでopen files limitに引っかかったようなメッセージが表示されることを確認したのでインフラにめっぽう強い我々は速攻で対処しています。
# systemctl edit envoy.service [Service] LimitNOFILE=524288
13:07、スコアは25455です。
メモリ対策
MySQLとVarnishのメモリ消費が問題となったので、以下のように対策を実施しました。
- MySQLはメモリ量の多いisu2サーバに移設
- Varnishはメモリ設定を変更しても削減されず
- xsuportal宛の通信をすべてVarnishに通していたが、キャッシュ対象のみ通すように変更
Varnishのメモリ消費原因の特定がなかなかできなかったのですが、大量の接続とgzip処理による負荷ではないかと思っています。これで一旦メモリ消費は解消しています。
Varnishではforkが問題になったのでこちらも併せて引き上げています。
# systemctl edit varnish.service [Service] TasksMax=4096
CPU負荷対策
このあたりでアプリ(xsuportal)のCPU負荷がネックとなっていたのでCPUコアの数が多いisu3へアプリを移設しました。
この時点で14:49、スコアは30244でした。
通知機能対策
この頃になると通知機能がボトルネックになっていました。
Top 50 Sort By Total Count Total Mean Stddev Min P99.9 Max 2xx 3xx 4xx 5xx TotalBytes MinBytes MeanBytes MaxBytes Request 19604 2624.748 0.1339 0.1460 0.001 1.325 1.943 19604 0 0 0 196884 0 10 118 get /api/contestant/notifications?.* 2100 2031.179 0.9672 1.1011 0.002 8.695 9.750 2100 0 0 0 77559 5 36 80 POST /xsuportal.proto.services.bench.BenchmarkQueue/ReceiveBenchmarkJob HTTP/2 1123 1038.024 0.9243 1.0063 0.001 5.062 5.306 1121 0 2 0 5275953 0 4698 9800 GET /api/contestant/clarifications HTTP/2
そこでアプリケーションマニュアルで手厚く説明されているWeb Push serviceの実装に踏み切ります。 慣れないWebPush実装は少し手こずったものの、なんとかベンチマークが実行できるところまで実装することができました。
Top 50 Sort By Total Count Total Mean Stddev Min P99.9 Max 2xx 3xx 4xx 5xx TotalBytes MinBytes MeanBytes MaxBytes Request 2146 1892.735 0.8820 1.1223 0.003 9.864 10.454 2146 0 0 0 85671 5 39 80 POST /xsuportal.proto.services.bench.BenchmarkQueue/ReceiveBenchmarkJob HTTP/2 22411 1785.695 0.0797 0.1195 0.000 1.240 1.843 22411 0 0 0 0 0 0 0 get /api/contestant/notifications?.* 1321 963.386 0.7293 0.9943 0.002 4.938 4.980 1319 0 2 0 5946332 0 4501 8850 GET /api/contestant/clarifications HTTP/2
この時点で16:29、スコアは32173でした。
TeamCapacity調整
ここからはTeamCapacityを60から120に引き上げることでベストスコア44269を記録するもののfailとなる割合が多く、3回に1回ぐらいの頻度でしか成功しない状況が続きます。 が、ここで当日マニュアルの「競技時間終了後に運営によって行う作業手順」を 3回のうち1回でも負荷テストに通ればok、それでダメでもその次の再チェックで通ればok と勘違いをしてしまいこのままフィニッシュとしてしまいました。 ここで日和って120から60などに下げておけばおそらくfailにならずに完走できたのではないかと悔やんでおります。うーむ、悔しい。
わいわい
そんなわけでウー馬場ーイーツはほぼインフラエンジニア力で大半のスコアを稼ぎ、おまけで通知機能のプログラミングを少し頑張った実装になりました。まだまだ改善の余地はあるので引き続き感想戦に邁進し、来年こそは優勝をもぎ取ろうと思います。来年の活躍にどうぞご期待ください。
