diary.sorah.jp

ISUCON7 予選突破した (白金動物園) #isucon

techtext

7 回目の ISUCON、なんとか 2 日通しの枠で予選通過できて本当に良かった。 今回も @mirakui, @rosylilly と一緒に白金動物園として参加しています。

今回はギリギリの集合ながら予定より開始が遅れたので、アニメを 2 本見ました。結城友奈は勇者である -鷲尾須美の章- #2 はチームビルディングの話で景気が良かった [独自研究] し、その後も something 景気が良い物ということで Fate/Apocrypha #16 も見たけどこれも景気が良かったです。アストルフォ私服。

というわけで、白金動物園の手の内を公開します。ベストスコアは 34 万ほどで対したことないけど…。上位陣のスコアびびる。

実装

https://github.com/shirokanezoo/isucon7q

Ruby + Go… にする目論見が最終的に Ruby のみです。ベスト 346,917 点 で最後のサブミットが 31 万ちょい。

最後に発覚したバグ取り間に合わなかったし、コードレビューと動作検証が雑すぎた。

やった事

おおよそ時系列。 (今回は時系列ログがあんまりなくて…。)

割当てられた 3 台のサーバをそれぞれ isu1,isu2,isu3 と以下呼称します。また、ベンチ対象サーバは front, アプリプロセスを動かしていたのは app と呼称します。MySQL/Redis は基本 isu3 に置いて(置きっぱ)でした。

mysqld.conf 書き換え

いつものに置き換えた。毎回 my.cnf の場所が分からなくてしばらく探すのそろそろやめたい。

nginx.conf 書き換え

c08e58d9dc 712a31ec0e

とりあえずいつも使っている nginx.conf に入れ替えた。client_max_body_size などは元々の設定でおおきめにとられていたのでそれは輸入した。 isu1 を一旦 front として、isu2 で Ruby 実装を動かしてそこにプロキシするようにしていた。

実装言語決め

とりあえず Ruby、なんか困ったら Go とした。最初から Go でも良かったかもしれない。

そうすると決めた時点でとりあえず git clone --depth=1 https://github.com/ruby/ruby して trunk をビルド & インストールした。どこまで効果があったのかは知らない。

MySQL index とか

rosylilly に SELECT クエリざっと出してもらって明らかに足りてなさそうなのを貼った。

alter table message add index chidid (`channel_id`,`id`);
alter table image add index idxname (name);

あと下記。なぜか text だったので…

alter table user modify avatar_icon varchar(100);
alter table user modify display_name varchar(512);

front-app 間の Keep-Alive 等

front から app にリバースプロキシするのを front から直接 app プロセスの bind しているポートに飛ばすのではなく、app 上の nginx を Keep-Alive 用に噛ますように変更。

Cache-Control

8a4b3de2a5

add_header Cache-Control "public, max-age=86400";

を fonts, js, css, icons に設定した。ただ現状だとスコアが fonts/js/css も設定すると落ちてしまう状況だったので icons のみに一旦絞った (加点が 304 Not Mofidied だと 100 回につき 1 度になる)。

スコア 17,133。

/icons はキャッシュが効くまでグローバル側iface (100M) を使い切るくらい帯域を食うけれど、304 が回ってくるとすぐに落ち着く。ただ、後述するような /icons を MySQL から剥がすのをやってからじゃないとそこまで到達するのはできない。

Expires が雑で怖いから使わないのは当然として Cache-Control 、別に public だったら public, そうじゃなかったら private 明記しない? みんな max-age とかだけ書いてハマってたっぽいのかーと思いました。

とはいえ、現代 CDN でも public なくてもキャッシュしてくれるし、正直厳しい仕様といえば完全にそう。 Conditional GET 界は未だ混沌としているので、下手に出題で触れると大火傷という印象が (4 の出題をやったときの感想として) あります。 「CDN 前提なんか察せるわけないだろ」は 4 の本選で経験したでしょみんな。将来の出題者のみなさんは覚えといてほしい…。 (流れ弾つらい、あのときはすいませんでした。)

/icons の画像を MySQL から普通のファイルに引っ張りだす

25bc4cf4e2 c62f60a60a 5bfb06bd64 760975c5ab 9fb0adf0d5 1eac77e5f6 327105a2d3 0981893648

rosylilly が実装。 /profile でファイルに保存するようにして MySQL に入れるのをやめた。 isu1 が front だったので、isu1 に画像を置くことにして、 /profile, /icons は isu1 の app プロセスで捌くことに。

後述するように 1 台に置いておくだけで問題ないと判断したので特に分散はしてないです。ただ POST /profile のボトルネックにはなっちゃってた気がするけど、他にやることありそうだったので無視していた。

MySQL から最初 600Mbps くらい出ててゲラゲラ笑いながら初回ベンチみてた。

最後の方に別で rosylilly が SHA1 計算を先頭ちょっとだけしか読ませないような実装にチャレンジしてたけど fujiwara組 と同じでよくわからない理由でベンチの検証フェーズでコケるようになってやめた。ユーザーID とかにするアイデアは最初から無かった (images テーブルを見たらめちゃくちゃ重複している事が判明していたので)。

static_gzip

228175a745

効果確認してないけど一応 gzip -k を JS/CSS にかけた。Webfont って掛ける価値あるんだっけ?

puma の設定をする

595175cc83 fd1b61a20e d6f81d2463 1fc7b5d83c

mirakui に puma 分からんから適当に書いてとオーダーして puma.conf.rb を書いてもらった。この時点で :5000 に加え UNIX ドメインソケットも listen。

最終的に workers 2, threads 32,32 で運用していた。この頃になってやっとメモリやコア数を確認するという日和った行為をしていた。

MySQL コネクションを使い回す

07c18e275a fa8c84ce4f 159219416f fae2d21328

Ruby 実装ではリクエスト毎に MySQL クライアントを生成していたので、これをスレッドローカルにストアするようにした。

… が、参考実装に prepared statement を close (statement.close) してない箇所がいくつかあって command out of order の Mysql2::Error をたくさん出すなどして大変だった。まず close 漏れまでの特定がしんどくて、次に直していくのも大変だった。ステートメントクローズカルタと呼んでた。mysql2-cs-bind 、何故つかわれていないのか…

あと、client not connected も出たので init_command, reconnect を適当に使った (mirakui が)。

GET /message の N+1 を潰す

0765cf6037

rosylilly がなんかやってた。後で気付いたけどこれ普通に JOIN でいいじゃんね。ね?

このあたりでスコアは score は 55,548。

haveread と未読カウントの Redis 化

2030f9a0f5 bf0e166073 6891329f42 7b4f5cf6d8 c41bad5b1f e60f83e78a a07b6f10b4 c1e0134de0 47cf95e444

全チャンネルの合計メッセージを Redis 上に hash で持って (HINCRBY で差分更新)、既読の記録が残ってたら (これはユーザーごとに 1 hash) SQL で計算する、という感じにした。

/fetch の HTTP long polling 化

(↑で同時にマージされている)

Redis 化にあわせて各種メッセージ更新で pubsub 使って /fetch を HTTP long polling にした。後述する別の施策の布石でもあった。タイムアウトは 5 秒。 ただ正直そんな効果あったか分からない。 Ruby で /fetch にたくさんクライアントぶらさげておいてもそんな効果なかったかも (/message にすぐ行ければスコア周り良くなるかなとか思ってた)。

この時点でスコアは 91,449。

isu2 の front 化

2f230c2a9b 2fe16404f3

そろそろfront 増やしてもいいかもねという事で isu2 をベンチ対象へ。

画像は isu1 にしかないので、画像は isu1 にリバースプロキシするようにしていた。内側の帯域は 1Gbps くらいあるはずだし、キャッシュ回れば帯域もグッと減るし問題ないだろと思ってやったけど事実問題なかった。

fetch だけ isu3 にもやらせる

318eba6f9f

/fetch が long polling になったので isu3 もサービスインして fetch だけやらせたりしていた。

nginx の client_body_buffer_size を調整

dcfd356998

/profile だけ client_body_buffer_size 5000k; にした。

チャンネルリスト・description 取得を調整

ad839acd55

SELECT * FROM channel を id,name に絞って description は引き直すようにした。

static asset も Cache-Control

46d11bfc4f

そろそろしてもスコアでるのではと思って icons 以外も Cache-Control 入れたら上昇効果。

/fetch の手前に雑 long polling proxy を置く

e2d5352794 f9d2652e12 618d971cde 682e4dbba9 48bb065263

Puma で long polling しても threads に限界あるしと思って、Go で rosylilly に Redis pubsub のメッセージがくるまでリクエストをせき止めするプロキシを書いてもらった。

ただコードレビューが雑すぎてバグに気付いておらずサービスアウト。直す方法はおもいついて指示したけど実装間に合わず (もっとはやく気付いてれば…。) この時意図せず "0 秒 sleep" と言うような状態になってたけど実は問題がなかった…?

0 秒 sleep な状態でも 292,819 を出していた。こ、これに気付いてれば…。

ERB テンプレートから空白削除

3db65770d7

なんかめちゃくちゃこれでスコア上がったのすごい「えっ」感あるんだけど、ベンチマーカ帯域問題ですかね…。

この時点で(帯域ガチャがあったものの) 346,917 (ベストスコア)。

/message オンメモリキャッシュ化 (失敗)

2ac14b8f0b 332a3c1db6 77f6212218 a32d5c5afe 4c9f4be7cf cebf615bc4

Redis じゃなくて Ruby のプロセスにするのをわたしが書いてた。全 message を Redis pubsub に流してオンメモリで最新 100 件持つみたいな実装…。「メッセージの順序が違う」とか、メッセージが増殖するとかいろんなバグを取りきれず没。Puma で multi thread やめて worker 増やしまくる戦略にきりかえても良かったのでは…?

あとまあ publish してから receive してメモリに積まれるまで結構レイテンシがあって即座に /message を GET されても返せないとか。ここ完成させたいなぁ。

再起動試験

問題なく再起動できて良かったですね。

puma が上がってくるの遅すぎて Before=nginx.service 入れたけど started には一瞬でなっちゃうから意味なくて、再起動後1 分ほど Bad Gateway を出しつづける状態だった。

  • sorah: 再起動試験で起動時間は見ますか?
  • うんえい: 具体的な制限時間はないけど再起動後現実的な時間で動作確認できなかったら失格にするヨ
  • sorah: なるほど! 現実的な時間ですね。

のような会話をして :thinking_face: みたいな気持ちになりながら「まぁ1分くらいだし」と放置した。みんな :thinking_face: reaction つけてきてちょっと面白かった。

真面目にやろうとすると Type=notifyとか Type=forking にするしかないけどリスク高いのでやめた。

反省

  • レギュレーション読み合わせはしよう
  • レスポンスの傾向にも注目しよう (リクエストヘッダしか見てなかった!!!)
  • わたしがアプリコードに手を入れはじめたのが 16〜17時くらいで遅すぎたね。
  • レスポンス傾向やリクエスト傾向やレギュレーションをひたすら読む係を置くといいのかなあ。mirakui にアクセスログ分析はやってもらってたし適当に中身見るのもお願いするかなー。

その他

  • キャッシュはとりあえず全然してなかったり非常に保守的。もうちょっとアグレッシブでも良かったかも
  • あらゆる変更は全部 isu1 〜 3 に投入していた。 (DB やストレージ部分を除く) 柔軟に app の割当てや front の調整をできるようにしておいて、front の nginx でいい感じに調整するようにした。
    • アプリコードの変更や頻繁に変更する設定は git に入れることにして、サーバ上で deploy.sh を叩く事で git pull, cp, systemctl restart 等々が走るようにしておいた。
  • fail2ban 入ってるんだ…しかも何度か実際に攻撃 ban しとるし、という感想。ハマるの嫌だったので真っ先に iptables -I INPUT 0 -s ${オフィスで利用してるISPのprefix}/16 -j ACCEPT とかで予防しておいた。丁寧に /29 や /32 並べてもよかったけどそんな余裕はない。
    • あとはまあ 3306 とかそのへんは -i eth0 -j DROP で。
  • mysql の max_connections を引き上げると EMFILE になるので LimitNOFILE をドロップインで引き上げた。
  • モニタを置いてたけど結構便利だった。本選ではなんかモニタ代わりのマシン持っていくかなぁ。
  • 今回もチームメンバーが何やってるか特にみんな互いに把握してないと思う。
  • コミットログ見るとサーバーのセットアップ含めてほとんどわたしが手を動かしてて笑った。でもまー、他チームとその後に話したけど、実装馬力はチーム内で 1〜1.5 で十分なんだよな。あとは分析や作戦練りしてもらってた方がいい。チームの分析力は向上させたい。
  • ピリピリしてるので「は?」とか言いがちだけど、なんとかなるうちのチームにはいつも助けられています。
  • なんかわたしがファシリテート(?)しがちだったのか、3つくらい同時に問題を投げられて考えるシーンがおおかった気がする。気のせいかわたしが立ち回りアホなだけかどっちかですね。ちゃんと EAGAIN を返せる成長。
  • 途中、弊社関係者 (ex- 含む) で 1〜3位埋まっておおおっとなった。というか今回うちから特に「みんな出ようね〜」とか encourage してないのにすごい人数出てた気がする。会議室休日なのに埋まり具合がすごかったし。
  • ISUCON の翌日に国際線に乗るのは非常にオススメできない事が分かった。荷物の準備 30 分とかでやってタクシーに飛び乗るはめになったので忘れ物が不安。 (本稿は飛行機から書いたり git push なりをしました)

まとめ

予選にしてはかなり濃い問題でめちゃくちゃ楽しかった。正直 Ruby でここまでいけるとは思ってなかったので嬉しいなー。ミライナタワーのぼれて本当によかった。

下記は時系列タイムライン。

タイムライン

  • 13:03: ssh_config コミット ~sorah
  • 13:08: hosts ファイルコミット ~mirakui
  • 13:10: ~/isubata のコミット ~sorah
  • 13:24: mysqld,nginx,redis,unicorn のいつもの奴を用意 ~sorah 781f7f69f9
  • 13:34: env.sh のコミット ~sorah 13e3a12bbb
  • 13:51: /icons static file 化の支度 ~rosylilly 25bc4cf4e2 c62f60a60a
  • 13:56: nginx.conf がりがり書いた ~sorah c08e58d9dc 712a31ec0e
  • 14:26: Cache-Control の導入 ~sorah 8a4b3de2a5
  • 14:34: static asset の CC は一旦送出停止 ~sorah 4a13460fef
  • 14:35: nginxからプロキシ先の Keep-Alive 設定 ~sorah 4864e074a5 d6e87ff237
  • 14:38: icon をファイル保存できるようにする奴ができた ~rosylilly s/5bfb06bd643b21587e1c10e20ea4f8d6b38bfcd5
  • 14:40: static_gzip のための *.gz ファイルをコミット ~sorah 228175a745
  • 14:40: ディレクトリを調整しながら /icons を static file 化 ~sorah ~rosylilly 760975c5ab 9fb0adf0d5 1eac77e5f6 0981893648 327105a2d3
  • 14:48: deploy.sh の準備 ~sorah 392bb01e19 7ecb09dbef 4fc7c86e98 16be3e61f1
  • 15:02: Redis の準備をはじめる。とりあえず bind address の変更から ~sorah 5510daced3
  • 15:11: Puma の設定ファイルが置かれる ~mirakui 595175cc83
  • 15:05: Mysql2 インスタンスをスレッドローカルに ~sorah 07c18e275a
  • 15:12: Redis クライアントまわりのヘルパを実装 ~sorah 2030f9a0f5
  • 15:16: Puma の設定ファイルを適当に調整。RuntimeDirectory をなんとなく使う。 d6f81d2463
  • 15:16: ↑でいじった service unit の ExecStart が適当すぎたので調整 3f798222c8 1fc7b5d83c 8373c7b165
  • 15:17: user の N+1 を解消 ~rosylilly 0765cf6037 7dd2912b68
  • 16:01: rack-ltsv_logger を試す ~mirakui b383d519b6
  • 16:06: SQL 文の地道な改善 (UPDATEまとめたり) ~rosylilly 2a88932190 6dcb723e74
  • 16:21: Mysql2::Error に悩みだす。一旦 db をリクエスト毎へ戻す 9dcfd8ae9a
  • 16:35: reconnect と init_command で解決を試みる ~mirakui fa8c84ce4f
  • 16:43: なんとなく preload_app をやめる 7b17137751
  • 16:52: statement.close カルタ開始 ~sorah 159219416f
  • 16:57: haveread の Redis 化, /fetch の long polling 化が完成 ~sorah 6891329f42
  • 17:01: バリデーションが通らなくなったりしたので試行錯誤 ~sorah 7b4f5cf6d8 c41bad5b1f e60f83e78a a07b6f10b4 c1e0134de0
  • 17:09: long polling の timeout を 5 秒に ~sorah 47cf95e444
  • 17:11: statement.close カルタ ~sorah fae2d21328
  • 17:15: icons 見当たらなかったら isu1 に reverse proxy するようにして、isu2 の front サービスインに備える。 ~sorah 2f230c2a9b
  • 17:16: isu2 を入れるのに合わせて、isu1,2 それぞれローカルの app を使うようにする。~sorah 2fe16404f3
  • 17:22: threads 数の調整 ~sorah 511b415645
  • 17:24: max_connections 引き上げ ~sorah 099affc27f
  • 17:32: Hash iteration 中に modify できない罠を修正 ~sorah 2bbf40c85f
  • 17:16: 性能落ちたのでスレッド数を戻す ~sorah 49f6092cd9
  • 17:38: isu3 を /fetch のみのサーバとして入れる。スレッド数多め ~sorah 318eba6f9f
  • 17:43: isubata の LimitNOFILE を引き上げ ~sorah bf3eef7268
  • 17:47: /profile の client_body_buffer_size を引き上げ ~sorah dcfd356998
  • 17:53: app の backlog を引き上げ ~sorah cfb329fb32
  • 17:53: /fetch を isu3 一本化 ~sorah 3ea0ba4775
  • 17:58: stackprof を試す ~sorah 6a6a0b9b31
  • 18:02: rack-ltsv_logger が重そうなので外す ~sorah 89bf01f9d1
  • 18:15: キャッシュに備える…が使ってない。 ~sorah ba8c5c6404
  • 18:15: チャンネルリスト生成や description の取得部分を改善。 ~sorah ad839acd55
  • 18:33: stackprof 無効化 ~sorah 2681545b25
  • 18:34: rosylilly の /fetch long polling proxy がマージされる ~rosylilly e2d5352794
  • 18:35: static asset の Cache-Control を戻す ~sorah 46d11bfc4f
  • 18:40: long polling proxy をサービスイン ~sorah f9d2652e12
  • 18:43: isu2 も long polling proxy 入りで /fetch に戻す ~sorah 5556dde25d
  • 18:43: nginx のログが vhost 間で重複しちゃってたので front の :80 で listen してる server でだけ出すように ~sorah 92880478d6
  • 18:46: long polling proxy を入れたのはいいけど、Ruby 側で long polling 待ちを止めてなかったのでリクエストヘッダを見て即座に返すようにしたりできるように。proxy からはそのヘッダ付きでリクエストをよこすように修正 ~sorah ~rosylilly 618d971cde 682e4dbba9 48bb065263
  • 19:00: avatar_icon のファイル名生成規則を変更する ~rosylilly b29bc70d6a a1ab6c5539 704dbd591d
  • 19:36: ERBテンプレートから空白が消える ~rosylilly 3db65770d7
  • 19:50: /message オンメモリ化がなんとなく動きはじめたので master に入れる ~sorah 2ac14b8f0b 332a3c1db6 593e85784d 77f6212218 a32d5c5afe
  • 20:12: バグ取り…。 4c9f4be7cf cebf615bc4
  • 20:17: long polling proxy がバグっている事に今更気付く。修正方法は sorah が伝えたけど、没に。 ~sorah ~rosylilly d8572203b0 4597584dde 9bb0a993e4
  • 20:29: スコア 346,917 までリバート。いくつか cherry-pick 2467580106 585110b4ee e34193a33a c4f414f7c3
  • 20:38: /fetch 担当サーバーの再調整 ~sorah 27df7c6305
  • 20:43: Before=nginx.service ~sorah 67634a834d

Published at