ISUCON 2017 の予選を突破したので、その記録

  • 7
    Like
  • 2
    Comment

ISUCON 2017 の予選を突破しました。

スコア 214,613 で突破ラインと4千ほどしか差がなく、ぎりぎりでした。

当日は風邪を引いてしまい、パフォーマンスも完全ではなかったし、指示がバタついてメンバーには迷惑かけました。なんとか突破できて感謝しています。本戦もよろしくお願いします。

さて、以下やったことと、おおむねの時系列です。
(自分 @najeira 以外の作業は細かいところは把握していないので概要書きですが、いろいろやってくれてます)

Qiitaに書くの、技術的な話題を含むからいいよね……?

時系列

1時間目

@soundTricker
- メンバーの公開鍵を各サーバの SSH に登録
- SSH Config 配布、Fabric で作業できるよう準備
- お題アプリを GitHub のリポジトリにプッシュ

@taxpon, @najeira
- アプリのコード読み

一段落したところで、3人で一緒のモニターを見ながらコード読み。いくつかコメントを入れながら、直したいところをメモる。あまり大規模な構造変更(リライトレベルの)はなさそうだと話した。

2時間目

@najeira
- データベースに必要なインデックスを追加
- ベンチマークしつつ dstat で確認。ボトルネックがネットワーク帯域にあることが分かった
- nginx に worker_rlimit_nofile や worker_connections などを設定
- sysctl で TCP まわりの設定を変更

@soundTricker
- alp を準備して、集計し /icons/ が遅いことが分かった

@taxpon
- 画像をファイルとして各サーバに配置

nginxで Cache-Contro: public, max-age=60 で /icons/ をキャッシュするようにして 35,634 点。ベンチをまたぐ必要はないので、この時点では短めにしておいた。

各サーバにファイルとして画像を置けばいいよね、ということで @taxpon さんにやってもらったが、結局 nginx のキャッシュもファイルなので大差ないということで無駄にしてしまった。ごめん。

3,4時間目

@najeira
- nginx の設定を少しづつ変えながら計測
- nginx - Go 間の keep-alive、css/js/font/svg の gzip 設定
- Go で interpolateParam=true

@soundTricker
- /fetch のクエリ数削減 for の外に出して1クエリで処理

@taxpon
- /message の for 内のクエリ数削減(キャッシュ化など)

このあたりで 53,833 点。

キャッシュしているはずだが、まだ /icons/ が重いな……と思ってた記憶がある。まだまだネットワークが詰まっていたはず。

アプリ側の改善でスコアが伸びたのでひと安心。この時点での上位10位以内に入っていた。

5,6時間目

@najeira
- nginx, isubata, mysql の ulimit 設定
- image の SELECT で LIMIT 1
- my.cnf 修正

@soundTricker
- my.cnf 修正
- /icons/ のレスポンスに Last-Modified 追加

@taxpon
- 画像の投稿時にキャッシュを先回り作成

相変わらずネットワーク帯域がボトルネックでスコアが伸びないので、ulimit を設定したり試行錯誤。でもスコアは伸びず。

Last-Modified で大きく伸びて 106,562 点を記録。alp でみると /icons/ が大量のリクエストを処理できており、ベンチマークの負荷の上昇によって /message や他のパスもリクエスト数が増えた。

Last-Modified や ETag をつけると、キャッシュ変更がないか確認にリクエストが来てしまう。通常は、それら無しで Cache-Control: public, max-age=xxx で時間内の強制キャッシュにしているほうが、その時間はアクセスが発生せず、より軽い。なので、自分は無しにしていたのだが、@soundTricker さんが試しに Last-Modified を付けたところ、スコアが伸びた。

リクエストが来ないよりは、来てから304で返したほうが、処理数になってスコアが伸びるのかなと思い、そのままにした。

実際にはベンチマーカーのバグ?か、max-ageは無視されてリクエストが来る(つまりキャッシュは効いていなかった)ので、Last-Modifiedがよく効いた

@soundTricker「Last-Modifiedつけます」
@najeira「変更日付とか適当でいいから、昨日とか今日の朝の時刻でいいよ」

c.Response().Header().Set("Last-Modified", "sun, 22 Oct 2017 12:00:00 GMT")

後からみたら、日本時間だと21時、まさかの未来! でも時刻が変わらないことが重要だったのだ……。

@taxopon さんによるPOST画像ファイル保存と nginx try files で、何度かやったところ、213,806 を記録
(このあたりの時間帯は他メンバーの作業内容をあまり把握していない)。なお、これは後でメモリ消費が大きくなったので削除。なんども無駄にしてしまい、ごめん……。

時系列的には Last-Modified が激しく効いたように見えるが、先にアプリ側の改善が出来ていたので、ボトルネックが開放されたことで、一気に伸びたのだと思う。

ここでようやくネットワーク帯域に余裕がでてきたが、しかし、ベンチマークのスコアが安定しなくなる。

7,8時間目

ちょっとした変更でスコアが激減したりして、リバートしたりしていた。ところが、変更していない状態でベンチマークを繰り返すだけでもスコアが乱高下。メモリ消費は大きかったので、nginx, isubata を再起動しつつ計測しても安定しない。

通過圏内(ダッシュボードを見た感じで10位内の)スコアが出ていたので、再起動試験をしようと、Webの1台を再起動。ところがスコアが3万点ほどまでに激減してしまった。再起動しなかった Web 1台と DB 1台で計測したほうがスコアが良いくらい。

スクリーンショット 2017-10-22 20.35.00.png

いろいろ設定ファイルを再確認したり、再デプロイしながら試すも、なかなかスコアがあがらず。再起動でキャッシュが暖まるまでの低迷であれば、徐々にあがるはずだが、そういう挙動でもない。このあたりは @soundTricker さんに調べてもらっていた。

/icons/ がボトルネックでなくなったことで、アプリ側の負荷が高まり、また MySQL も CPU を 70% くらい使うようになってきたので、ベンチマークの対象から外した(それまではデータベースのサーバーでもアプリを動かしてリクエストを受けていた)。また、アプリを動かさないことにしたので、あまったメモリをMySQLにまわした。

そんなこんなしつつ、近い場所にいる誰かが激重のなにかをやってるんじゃないの、とか言いながらベンチを繰り返して、3万から20万をうろついていたところ、ベストの 214,613 を記録した。いまだに謎。

@soundTrikcer さんはまだ修正を入れたがっていたけど、通過の可能性がそこそこあったのと、ベンチマークのスコアが安定していないのが不安要素だったので、もうスコア計測しない! と決めてFIXとした。

最後はのんびり21時をまって終了。

スクリーンショット 2017-10-22 20.35.20.png

スクリーンショット 2017-10-22 20.43.00.png

まとめ

  • nginxで画像をキャッシュした
  • /fetch と /message のループ内クエリをなんとかした
  • COUNT(*)など他のクエリは全てそのまま、画像の保存もデータベースのまま

という感じで、 /icons/, /fetch, /message の3箇所をピンポイントで改善できたのがよかった。

他のチーム(突破したところも、していないところも)のブログ記事をみたら、うちのチームよりはるかにいろいろやっていて、本当ぎりぎりだったなという感想です。うちは計測したボトルネックに絞って注力できたのがよかったかなと思っています。効きそうだなと思ったところは他にもいろいろあったんですが、時間が足りなかった……。


いろいろ反省点があったので、本戦には修正して、優勝を目指したいですね。

運営、参加者のみなさん、お疲れ様でした。