ISUCON4 オンライン予選 一日目の結果発表 : ISUCON公式Blog
ISUCON4 予選に参加して私のチームの『チームフリー素材』が土曜日で暫定二位でした
チームメンバーは会社の先輩になる @walf443 さんと @edvakf さんの計 3 人で出場しました
私以外の 2 人は去年の本戦にも出場していますが,そのチームに一人欠員が出たため未経験の私が入った感じです
それでチーム名は色々混乱を産んだようで申し訳ありません…
チーム名の由来としては
@catatsuy さんはうちのチームのフリー素材部分をたんとうしています。
— サービス提供レベルのみかん (@walf443) 2014, 9月 27
とのことです
というわけでとりあえずやったことをまとめておきます
やりながら定まっていった全体的な方針としては
『アプリケーションではなくベンチマークツールに CPU を避けるようにする』
という方針で最適化を行いました
ISUCON4 本選出場の一部基準変更についての詳細 : ISUCON公式Blog
上の記事のように土曜日は --workload
にバグがあり高いスコアを取りやすい状態でしたが,私のチームはこれがバグという認識はなく調整すべきパラメータの一つだと思いどこまで上げられるかの検証にも時間を割きました
バグといっても --workload
を上げれば並列数は上がるのでアプリケーションへの負荷が高くなりますし,ベンチマークを取るのにも時間がかかるようになるのでただ上げれば勝てるという感じでもなかったと思います
また後日に benchmarker-v2 でスコアを測ったところ workload 16 で 44194 でした
benchmarker-v2 で調整していたわけではないですがこの数字なのでまあそこそこかなと思います
開発準備
私のチームは事前に何回か一緒に練習をしながら作戦を決めていたので最初にやることはある程度決まっていました 当日もこの連携がうまく行っていたので焦ること無く
今回は Go を使ってやることを事前に決めていたので Go を選択しました
そして当日はプライベートリポジトリで GitHub 上にリポジトリを置いて開発を始めました
その後に @walf443 さんが Mac 上で開発環境を整えることができるのかを検証して開発環境を整え方を全員に伝えました
これも事前に決めていたもので Go はミドルウェアが Mac 上で動けば Mac でも問題なく開発できることが過去の ISUCON の課題から分かっていたのでまず Mac での開発環境構築ができるか検証することになっていました
またこの間に /home/isucon の権限の問題で isucon ユーザーに ssh 出来なくなっていたのでその辺を修正を @edvakf さんがやっていました
その間に私は事前に決めてあった方法で Nginx のアクセスログからどのルーティングに時間を使っているのか調査をするために Nginx の設定変更と計測結果を Slack に貼りました
Ruby - ltsv access log summary tool - Qiita
これを使ってアクセスが多いルーティングと時間がかかっているルーティングを調べます
ここから遅いと分かったルーティングの処理を潰していきます
その間に @edvakf さんがベンチマークを回してその出力を Slack に投稿するシェルスクリプトを作ってくれていたので以後はこのシェルスクリプトを使ってスコアを計測していました
その後に Nginx と Go を UNIX ドメインソケット経由で通信できるようにソースコードを変更して Nginx の設定も変更しました
その際に flag を使ってポート番号を指定した場合は tcp で起動するようにして手元での開発に問題が出ないようにしました
martini での書き換えはやったことがなかったのですが,意外とすんなりいけました
その頃には手元での開発に成功していたので私の手元でも開発できるようにしました
事前の調査で Go のプロファイリングツールでは MySQL などの接続待ちなどがうまく出てきてくれないことが分かっていたので walf443/stopwatch を仕込んで時間のかかるクエリなどを調査できるようにしました
ここまでの流れは事前に決めてあった流れをやっていた感じです
ここまでを 11 時までに終わらせました
開発とチューニング
そこからは遅いと分かったルーティングにある遅い SQL を何とかするために pt-query-digest
を使ってスロークエリを調べました
そして INDEX を貼り,my.cnf に innodb_flush_log_at_trx_commit
を 0 にしたり innodb_buffer_pool_size
を 1g にしたりしました
しかしこの辺りで静的ファイル配信時に cannot assign requested のようなエラーが benchmarker で出るようになりました
Nginx のエラーではないことを確認してからローカルポートの枯渇ということに気付いて sysctl.conf
をいじって今後必要そうな設定をしていきました
net.core.somaxconn = 1024 net.core.rmem_max = 8388608 net.core.wmem_max = 6553600 net.ipv4.tcp_rmem = 4096 87380 8388608 net.ipv4.tcp_wmem = 4096 65536 6553600 net.ipv4.tcp_fin_timeout = 5 net.ipv4.ip_local_port_range = 1024 65535
今回の benchmarker では 127.0.0.1/8 のネットワークから様々な IP アドレスを用意して接続してくるために並列数を上げるとすぐにローカルポートが枯渇してしまいます
この辺で 13 時が過ぎていましたが --workload
が 2 でスコアが 21102 というところでした
これでエラーも出なくなったので --workload
をどこまで増やせるのかというのを試していきました
それで 16 で 34474 までコードの変更なく伸びることを確認したので後半にこの値をいじることを決めました
またアプリケーションも変更して IP の Failure Count など SQL を引いている処理を goCache で持って SQL を実行しないようにしました
この辺の変更で当初は CPU をかなり使っていた MySQL の CPU の使用率を減らすことに成功していました
そして Nginx のログから TOP ページがアクセス数が多いということが分かっていたので Go 側でテンプレートエンジンを通さずに文字列として返すようにしました
この変更が 13:49 に行ったベンチマークで --workload
16 でスコアが 38780 になっていました
その後にも User の Locked を goCache を使って高速にする戦略や初期化時に goCache でキャッシュを持つ戦略で --workload
16 でスコアが 39999 になりました
その後に MySQL の接続を UNIX ドメインソケットでやるのを忘れていたので行ったところまた静的ファイル配信時に cannot assign requested というエラーがまた出るようになりました
そこでまた sysctl.conf
をいじってローカルポートを再利用するようにしました
net.ipv4.tcp_tw_reuse = 1 net.ipv4.tcp_tw_recycle = 1
この設定に気付くのに 50 分くらい費やしてしまいましたが,なんとか 16 時に --workload
32 で 42346 のスコアを出しました
ここらへんで --workload
がどこまで上げられるか試すことになり試したところ --workload
128 で 45287 になりました
そこで --workload
を 256 にしたところスコアは跳ね上がり 70662 になりましたが fail が出てきていたのでこのままではスコアを伸ばせないということが分かりました
そこでエラーがファイルディスクリプタの枯渇だろうということで limits.conf で isucon ユーザーのファイルディスクリプタを増やしました
そうするとエラーが出なくなったので安心しました
この時点で 16:45 になっています
今回の ISUCON は benchmarker に CPU を割いたもの勝ちであることに早い段階から気付いていたので benchmarker 以外に CPU を喰っているものをここから潰していきました
意外だったのは supervisord でこれはアプリケーションのログをファイルに書き込むので CPU を使っていました
martini は MARTINI_ENV=production
という環境変数を渡すとログを吐かなくなるらしいですが,そんなことは知らなかったので martini 自体のソースコードを変更してログを吐かないようにした上で go install し直しました
これは本当は Fork して直したかったのですが GitHub の仕様では public なプロジェクトを private なリポジトリに Fork することはできないらしく,この時チームは暫定一位だったのでそのメンバーである私が martini を Fork していじり始めたらレギュレーション的にかなりまずいと思ったので直接いじるという選択をしました
正直 ISUCON のアプリはそんなに大きくないので Go に慣れているなら真っ先に Martini を除くことに時間を使った方がいいかもしれません
これで supervisord の CPU 使用率をほぼ無くすことに成功してさらに負荷をかけられるようになっていきます
そして top を見ていると 4 worker にした Nginx が実質 3 コアしか使っていないことが分かったので 2 worker に変更してコンテキストスイッチを減らしました
そして一度再起動試験をしようということで 17 時過ぎに一度再起動して問題ないかどうか確認しました
特にファイルディスクリプタ周りなどの設定は再起動後にも有効になるのかどうかかなり不安でしたが,特に問題なくベンチマークが通ったのでホッとしました
その後どこまで --workload
を上げることができるのか検証していました
私のやった感じでは 300 までなら耐えられそうでしたが,17 時時点で暫定一位だったのでここで無理をして失格になるのも嫌だったので少し --workload
を落として 280 で提出しました
今回の ISUCON のルールではある程度 fail していても通ってしまうので fail を気にせず --workload
を高くして高いスコアを出すという戦略もありだったような気もしますが,個人的に fail が起こるのは非常に嫌だったので fail が 0 で終了する値に調整して提出しました
最終スコアは 82386 で暫定二位で終了しました
まとめ
なんか --workload
のバグを突いたみたいに言われることが多いのですが,バグを突いたつもりはなく高負荷に耐えられるようにチューニングしたつもりです
チームとしては事前に何回か練習をして作戦を決めていたので最初に戸惑うこと無く作業が行えたので非常に良かったです
ただ私はまだ Go 力が低い状態なので本戦に進めるなら Go の勉強と ISUCON 本戦の作戦と対策を立てていきたいと思います
それと 17 時過ぎた辺りから極度の緊張?で胃が痛くてお腹痛いって言いながらずっと作業していました
お腹痛い
— 隠居 (@catatsuy) 2014, 9月 27
めっちゃお腹痛い
— 隠居 (@catatsuy) 2014, 9月 27
本当にお腹痛い
— 隠居 (@catatsuy) 2014, 9月 27
暫定一位は逃したっぽい
— 隠居 (@catatsuy) 2014, 9月 27
そんなことよりお腹痛い
— 隠居 (@catatsuy) 2014, 9月 27
こういうこともあるので体調を万全にして今度の ISUCON は臨みたいと思います