こんにちは、オプティムのプロダクト開発部でOptimal Bizのサーバーサイドを担当している伊藤です。
2019年9月7日10:00〜18:00に開催されたISUCON2019の予選に参加しました！
投稿が遅くなってしまいましたが、とても楽しかったのでレポートを上げたいと思います。
ISUCONとは
「Iikanjini Speed Up Contest」の略だそうです。 Webアプリケーションのパフォーマンス改善コンテストであり、お題となる少しパフォーマンスの悪いWebアプリを制限時間内にどこまでいい感じにスピードアップできるかを競います。
公式サイトはこちら
参加メンバー
社内で参加メンバーを2名募り、3人で出場しました。 チーム名はひねりもなく「biz」にしました。
結果
スコアが記録された431チーム中、99位でした。ギリギリ2桁。
今回の課題
アプリケーション
ISUCARIという架空の「椅子を専門に扱うフリマアプリ」でした。
シナリオ
「割引キャンペーン的なのを実施したらパンクするから18時までになんとかしろ」 ということらしいです。
アプリ構成
サーバーはアリババクラウドのインスタンスが3つ提供されます。使い方は自由でした。
- CPU2
- Memory4G
- HDD
フロントはReact、DBはMySQL、リバースプロキシにnginx、
バックエンド(APIサーバー)は以下の言語から選べます。今回はRubyを選んで参加しました。
- Go
- Ruby
- Python
- PHP
- Node
- Perl
ソースコードはGitHubに公開されてます。 https://github.com/isucon/isucon9-qualify
採点
用意されたベンチマークを実行します。 ベンチマークの採点は「どれだけ椅子の売買がされて売上をあげられたか」でした。
「いい感じにする」というのがスピードアップするだけが答えじゃない感じがします。
参加中のできごと
09:30集合
弊社のリフレッシュルームに集合してセットアップ。
10:00競技開始
いきなりISUCONのサーバーが500を返してきて問題が見えない状態でスタートしました。
有名な人が「俺達がベンチマーカーだ」とか言ってるのを眺めていました。
問題公開後はとりあえずマニュアルを読み、インスタンスを立て、初期段階のベンチを回したりしました。
11:00
ソースをscpで持ってきてプライベートのgitリポジトリに投げ込みます。
すでにアプリを開いたりソースを開いたりする前から盛り上がって色んな案がでました。
- アプリがリソースを返しているのでnginxにやってもらう
- mysqldumpのサイズ見て載せられそうならメモリに載せる
- 画像多いからhttp2にしたら早くなるかも
- プロセス増加
- スロークエリログ出力
- アクセスログからどのリクエストに時間かかってるかを計測する
12:00
この時点で主要なassetsがアプリから帰ってたのをnginxに仕事をさせるようにしたりました。
Kataribeでアクセスログを解析して、アクセスポイントごとの処理内容を出力しました。
Top 20 Sort By Count Count Total Mean Stddev Min Request 107 312.690 2.9223 1.7760 0.057 GET /users/transactions.json HTTP/1.1 61 18.203 0.2984 0.2158 0.066 POST /login HTTP/1.1 56 2.256 0.0403 0.0897 0.002 POST /sell HTTP/1.1 55 51.589 0.9380 0.8092 0.001 POST /buy HTTP/1.1 54 4.455 0.0825 0.1487 0.002 GET /settings HTTP/1.1 42 20.516 0.4885 0.3903 0.001 POST /ship_done HTTP/1.1 ・ ・ ・
ボトルネックになっていそうなリクエストからソースコードを読み解いていきます。
わかったのは概ね以下の内容です。
transactions.jsonというエンドポイントがとにかく時間がかかる- N+1のクエリが大量
- N+1で外部アプリへのAPIがリクエストされている
loginも結構時間がかかる- 原因はこの時点ではすぐにわかりませんでした
13:00~15:00くらい
各々が思いついた改善をえいやこらと進めていました。
transactions.jsonのAPIリクエストをなんとかする- 「椅子の配送完了」ステータスは「配送終わったら変化しないだろう」と考え完了ステータスの場合はリクエストしない
transactions.jsonで利用されている椅子のカテゴリなどの固定値をキャッシュするloginを解析してパスワードの暗号化がCPUを食っていることを割り出す
15:00〜17:30くらい
引き続き思いついたことを直していきます。
Top 20 Sort By Total
Count Total Mean Stddev Min Request
113 340.646 3.0146 1.9723 0.059 GET /users/transactions.json
61 59.324 0.9725 0.8032 0.001 POST /buy
46 24.353 0.5294 0.3876 0.001 POST /ship_done
44 22.460 0.5105 0.3984 0.001 POST /ship
25 18.064 0.7226 0.2597 0.014 POST /complete
62 17.148 0.2766 0.1828 0.065 POST /login
2 10.500 5.2500 0.5460 4.704 GET /users/transactions.json?created_at=xxxx&item_id=xx
2 9.975 4.9875 0.0425 4.945 GET /users/transactions.json?created_at=xxxxx&item_id=xx
2 9.877 4.9385 0.0335 4.905 GET /users/transactions.json?created_at=xxxx&item_id=xx
・
・
・
この時点で初期スコアとはあまり変化がなく、難しさを実感してました。
transactions.jsonのN+1の数を減らすtransactions.jsonのAPI実行を並列化する- MySQLを2つ目のインスタンスに移す
17:30〜18:00
怒涛のベンチマークラッシュ
MySQLを外に出したらスコアがぐっと伸びました。
さらにISUCONのマニュアルに最初から記載されていた「ベンチマークのキャンペーンの還元率」という設定値を増やしたらユーザー数が増えるらしく、スコアが倍以上になりました。
MySQLのチューニングやpumaのプロセス数の調整などを駆け込みで行い更に伸びました。
感想
とにかく楽しかったです。
あーでもない、こーでもないと言いながら必死になって改善していました。
後から調べたらエンジニアの研修として取り入れている会社もあるようでした。とても効果がありそうに思います。
実際にありそうなパフォーマンス改善を実感し、しかも先輩エンジニアがどう直すのか見ながら体験できます。
他のチームでは500を返すと減点になるから、エラーが起きたら「売り切れ」を表示してスコアを伸ばした人もいました。
確かに実際のユーザーも500を返したらブラウザバックしますが、売り切れなら他の椅子を探すかもしれないと思いました。
おわりに
OPTiMではWebアプリケーションの開発・改善の技術に興味のあるエンジニアを募集しています。
ご興味いただけたらぜひこちらもご覧ください！
