ISUCON2019 予選に参加しました！

こんにちは、オプティムのプロダクト開発部で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アプリケーションの開発・改善の技術に興味のあるエンジニアを募集しています。

ご興味いただけたらぜひこちらもご覧ください！