ISUCON7の本選に「座るだけのコンテストってな〜んだ？」チームで参加して13位でした。学生だと5位くらい？
他のチームメンバーの記事
@brook_bach さん
@mayoko_ さん
予選の記事
問題概要
クッキークリッカーを模した，椅子を構築するオンラインゲーム Chair Constructor Online (CCO) を高速化するという課題でした。
イスを作るゲームを高速化していました #ISUCON pic.twitter.com/YaB1v4cuLl
— しょラー (@shora_kujira16) 2017年11月25日
仕様としては，イスの追加 (add_item) とアイテムの購入 (buy_item) による状態変化がクライアントにWebSocketでブロードキャストされるようになっていました。またクライアント間で状態の反映がなるべく同時に行われるように，全ての行動は未来の時刻のタイムスタンプ付きで管理されるようになっているため，複雑な処理になっています。
左下に「5000兆脚欲しい！」というロゴが見えたり（押すと実際に5000兆脚増えます），アイテム購入欄の表記が指数になっていることからも分かるように，CCOでの椅子の数は非常に大きくなります。普通はfloatを使うところですが，CCOでは椅子の数を律儀に多倍長整数を使って扱っています。自動的に多倍長整数が使われるPythonやRubyでは簡単に扱えるのに対し，演算子のオーバーロードが使えないGoでは記述が大変だったそうです。
サーバーは2コアのCPUと2GBのメモリを積んだものが4台という構成でした。
やったこと
kataribeでプロファイリングした
「WebSocketが使われているからあんまり意味ないかもな〜」とは思いつつもNginxのログから重い部分を探しました。ISUCONでよく使われているログプロファイラには matsuu/kataribe と tkuchiki/alp がありますが，私たちのチームではkataribeを使っています。理由は設定ファイル (kataribe.toml) をリポジトリに追加して共有できるからです。
↓ こんな感じで集約の設定を書きました。
[[bundle]] regexp = '^GET /room/' name = "GET /room/*" [[bundle]] regexp = '^GET /images/' name = "GET /images/*" [[bundle]] regexp = '^GET /ws/' name = "GET /ws/*"
https://github.com/arosh/isucon7-final/commit/955fc1c9902c91ac8bf5e71d8223934e93d6fc20
アプリケーションに手を加えていない状態でのプロファイリング結果を以下に示します。WebSocketではクライアントと繋ぎっぱなしのため，/ws/* 以下のレスポンス時間が長くなっていることがわかりますが，WebSocketに関してはそれ以上の情報は得られませんでした。初期設定での nginx.conf に静的ファイルを配信する設定も書いてあったため，Nginxの設定にこれ以上の時間をかけても得られるものは無さそうです。とにかくWebSocketでの処理を高速化することが重要ということがわかります。
Top 20 Sort By Total
Count Total Mean Min Max 2xx 3xx 4xx 5xx Request
104 1450.324 13.945423 0.030 57.525 0 0 0 0 GET /ws/*
72 0.214 0.002972 0.000 0.155 72 0 0 0 GET /images/*
2 0.102 0.051000 0.001 0.101 2 0 0 0 GET /phina.js HTTP/1.1
1 0.038 0.038000 0.038 0.038 1 0 0 0 GET /initialize HTTP/1.1
11 0.036 0.003273 0.001 0.009 11 0 0 0 GET /room/*
2 0.009 0.004500 0.002 0.007 2 0 0 0 GET / HTTP/1.1
2 0.000 0.000000 0.000 0.000 2 0 0 0 GET /gui.js HTTP/1.1
2 0.000 0.000000 0.000 0.000 2 0 0 0 GET /game.js HTTP/1.1
2 0.000 0.000000 0.000 0.000 2 0 0 0 GET /favicon.ico HTTP/1.1
PythonのcProfileでプロファイリングした
WebSocketでの処理は /ws というパスにまとめられていたので，もっと詳細にプロファイリングする必要が出てきました。
私たちのチームにはWebプログラミングを本業にしている人がいないので，全員が触れる言語としてPythonを採用しています。これまでに練習してきた過去問ではフレームワークとしてFlaskかBottleが使われていたので，プロファイラの使い方などを事前にまとめておいたドキュメントもWSGI用のものしか用意していませんでした。
しかしながら，今回の問題はWebSocketを使用しており，1接続が1スレッドを専有するのを避けるために aiohttp という非同期処理に対応したライブラリが使われていました。WSGIには対応していないのでプロファイラを探すところから始めなければいけませんでした。
ググってみると aio-libs/aiohttp-debugtoolbar などのライブラリも見つかったのですが，私たちが必要としているものとは違っていました。最終的には werkzeug.contrib.profiler を参考にして，同期的に行われる処理の前後でプロファイラを手動で呼び出すことにしました。このためのソースコードの変更を以下に示します。
https://github.com/arosh/isucon7-final/compare/d118466...9498eb3
（↑UNIX時間の秒が同じ場合にプロファイリング結果が上書きされてしまうというバグがあります）
プロファイラの出力は gprof2dot を使って可視化しました。使い方は以下の記事が参考になります。
複数のCPUコアを使えるように設定した
デフォルトではアプリケーションが1プロセスしか起動しないようになっており，2コアあるCPUを使い切れていなかったので設定することにしました。このあたりは @brook_bach さんがよろしくやってくれました。
Comparing 955fc1c...d118466 · arosh/isucon7-final · GitHub
Gunicornを経由してaiohttpを使うことに関しては，ドキュメントに "running aiohttp application under gunicorn is slightly slower." と書いてあるのですが，systemdを使って複数のプロセスを起動する方法が分からなかったので仕方がないです。
Server Deployment — aiohttp 2.3.5- documentation
calc_statusの高速化
競技開始からアプリのコードを読んでもらっていた @mayoko_ さん（自称「本当に座っているだけで何もやることがない」）が，プロファイリングを取る前から「calc_statusが非効率的すぎるでしょ」といって効率化してくれていました。
私には何をやっているのか全く分からないのですが，二分探索などを使って高速化してくれたっぽいです。
calc_status の高速化 by mayoko · Pull Request #2 · arosh/isucon7-final · GitHub
get_status のロックを専有ロックから共有ロックに変更した（←間違い）
データベースのロックのことを全く理解していなかったので「読み込み中に読み込みするのは許していいでしょｗ」と思ってget_statusでroom_timeに設定される専有ロックを共有ロックに変更しました。これはデッドロックするので本当はダメだと競技終了後に気づきました。サーバーの台数を増やすとスコアが下がるのはこれが原因だったのかもしれません…
共有ロックの利用？ · arosh/isucon7-final@c82e3ae · GitHub
アイテム情報を最初に読み込んでオンメモリ化した
アイテムの情報は変更されないので最初にグローバルに確保しました。
複数台構成のためのチューニングをした
何に手を付ければいいか分からなくなってきたので，とりあえず複数台構成でどこまでスコアが伸びるか試してみることにしました。理由がまだはっきりと分かっていないのですが，4台全てを使うとスコアが大きく下がってしまい，MySQLを動かしているサーバー1台と，それ以外のサーバー1台の合計2台で動かしたときが最もスコアが高くなりました。
ちなみに私たちのチームでは，複数台のサーバーに対する操作にはtmuxのsynchronize panesを使って，4台のサーバーに対して同時に git pull と sudo ./restart.sh を呼び出す方法を使っています。
calc_statusの計算を部分的にキャッシュする
@brook_bach さんと @mayoko_ さんがペアプロして頑張ってくれたのですが，試験走行を突破することができませんでした。
Comparing f22ee46...cbcf9c4 · arosh/isucon7-final · GitHub
int2expが遅いことに気づいた
気づいただけで，競技時間中には改善できませんでした。
反省
後から気づいたことや，他のチームに教えてもらったことを書きます。ベンチマークが公開されたら，本当に改善するかどうか調べたいです。
room毎に水平分割する
このアプリケーションの処理はroom毎に完全に独立なので，水平分割することができます。しかしながら，競技時間中に @mayoko_ さんに「データベースを分散できないんですか？」と提案をされたときには，MySQLを載せているサーバーのCPU負荷があまり高くないからという理由で却下してしまいました。よく考えると，データベースの負荷が高くないのにアプリのサーバーを増やすとスコアが下がる理由が謎ですね。
他のチームのブログを見ていると「部屋ごとの負荷が均等でないから分割してもCPUを使い切れなかった」という報告もあるので，あとで検証したいです。
int2exp 関数の改善
以下のような関数が全体の30%ほどを占めていました。
# JSON中で利用する10進指数表記 # [x, y] = x * 10^y def int2exp(x: int) -> (int, int): s = str(x) if not s: return (0, 0) if len(s) <= 15: return (x, 0) return (int(s[:15]), len(s)-15)
xはintなのですが，Python の int は自動的に多倍長整数になります。「椅子信託」というアイテムが買えるようになる頃には10*15000くらいになることもあります。この処理は str(x) のメモリ確保の部分がかなり重いのですが，以下のように変えると爆速になるようです。
>>> import math >>> num = 10**100000 >>> %timeit len(str(num)) 181 ms ± 2.67 ms per loop (mean ± std. dev. of 7 runs, 10 loops each) >>> %timeit int(math.log10(num)) + 1 786 ns ± 37.8 ns per loop (mean ± std. dev. of 7 runs, 1000000 loops each) >>> %timeit str(num)[:15] 185 ms ± 4.76 ms per loop (mean ± std. dev. of 7 runs, 10 loops each) >> %timeit num // (10 ** (100000 + 1 - 15)) 114 µs ± 4.43 µs per loop (mean ± std. dev. of 7 runs, 10000 loops each)
asyncioまわりの改善
Pythonのasyncioで使われているイベントループのライブラリを MagicStack/uvloop に変更すると手軽に高速化できるという報告もあるので，検証してみたいです。
あと，MySQLのクライアントとして PyMySQL/mysqlclient-python が使われていたのですが，これを aio-libs/aiomysql に変えるとどうなるのか試してみたいです（こっちはあまり効果無さそう）。
最後に
ISUCONは今年で学生部門引退なので，現在非学生 or 来年から非学生の方々にはぜひチームにお誘いいただきたく！
