社内ISUCONが楽しかった話

8/17に社内の催し物としてISUCONをやりました。
楽しかったのでやったことを書き起こしてみます。

なお、問題は以下のY!SUCONから出題でした。 github.com

自分のスキルセット

  • フロントエンドエンジニア
  • ここ1年半ぐらいスクラムマスターやってた
  • 最近はScalaで集計周りのコードを書いたりインフラ周り(主にAnsibleやCFnなど)をほんのちょびっと

ISUCONで動けるタイプの人間じゃない・・・

事前準備

チームのメンバーが、主にアプリケーションエンジニアだけど上から下まで一通り触る競プロマンと機械学習系が強いマン。
相談した結果、競プロマン氏がインフラやらミドルウェア周りを中心、自分と機械学習マンでひとまずアプリ周りという方向になりました。

アプリはいったん自分が得意としてるJavaScript実装でスタートすることに。

リポジトリの用意・最低限の環境構築・ブラウザで業務用に開いてるタブを閉じるあたり。

本番

競技時間はおおよそ10:00開始で17:00にベンチ用のインスタンスのシャットダウン
開始時間がおおよそなのは朝は集まりが悪いので時間が確定しにくい問題があったりなかったり

10:00 ~ 10:30

  • とりあえず落ち着いて開発できる席を探して着席したら.ssh/config作ってインスタンスへログインできるように確認
  • ひとまずベンチ回す
  • アプリコードをリポジトリにいれてpushしたりデプロイスクリプトの作成に入ったり
  • アプリコード読んだり

こんな感じでエンドポイント列挙したりした f:id:sisisin444:20180817235351j:plain

10:30 ~ 12:00ぐらい

(若干時系列バラバラ

  • alpやらnginxのアクセスログやらを見れる環境を用意
  • アプリをローカルで動かすのがんばったり
  • アプリ側のパラメータ弄るだけで良さそうなところをひとまずなおした(mysqlのconnection limit1 -> 10)
  • 計測してなかったんで重いエンドポイントわからんかったけど /searchが怪しそうとアタリを付ける
  • マイクロサービスになってたアプリの統合をした方が良さそうだったので、ひとまずDBが分かれてたのを統合した

    • アプリ側はまだ普通にマイクロサービスへリクエスト投げまくってる
  • 11:30ぐらいに計測結果が出て、 //searchがクソ重いことがわかる

    • ここで / を何とかしようという方向に

11:30 ~ 13:30ぐらい

  • 競プロマンがとりあえずとってきたtweetsテーブルの結果だけuserテーブルをクエリしていたのでJOIN
    • ここでベンチが全然数字変わらずハマる。
    • デプロイスクリプトがバグっていたのが原因っぽい
    • ・・・と思いきやちゃんとデプロイしても数字伸びない
  • その間自分はマイクロサービスをモノリシックにする修正を入れたり
    • 何故かBadGatewayが出てハマる
    • ローカルでは動くし原因がわからない・・・
    • 1時間ほど慌てた結果、全部モノリシックにするのは諦めて、GET /:meだけを統合(POST,DELETEで使ってるエンドポイントの follow, unfollowはそんなに重くなかったので)したら通った
  • モノリシック化をいれてベンチするけどあんまり変わらず(たしか1000ぐらい)。もっと重い部分が別にあったのでこれは予想通り
  • friendsテーブルの正規化をやるかどうかを悩んででかい実装になるので今からこれやりきる自信がないと判断してやめ。

(ここまでスコアは全く伸びてないので地味に焦り始めてました

13:30 ~ 14:30ぐらい

  • 他の人は重いクエリを調べたり考えたりしていたっぽい(自分はあんまり把握してない)
  • 自分はJOINで絶対数字上がるはずだと思って、競プロマンの書いたJOINをさらに修正
    • WHEREにnameの検索を追加
    • LIMITを追加

ここでベンチして7000点を記録する。
他のチームが2000~3000ぐらいをうろついてたので頭一つ飛び出たのでヨッシャになった。
が、エラーが出ていたので全員で何とかしようという話に(今回のレギュレーションではエラーが出てると0点扱い)

14:30 ~ 15:00ぐらい

  • どこがエラーなのかさっぱりわからん状況が続く
  • 競プロマンがnginxのログを見て500返したり返してなかったりを発見
    • nginxのconfをここで初めてまともに見る
  • worker_processesが1になってていかにも怪しいのでとりあえずautoにした
    • ベンチが9000点になってエラーなしを記録してガッツポーズ
  • ↑の修正は / に閉じていたので、 /searchにも適用した
    • 検索条件はいったんLIKEで
    • 15000点ぐらいになった
    • が、またエラーが出る

15:00 ~ 16:45ぐらい

この時間はずっとエラーが出ていた奴と戦っていた。

またアプリじゃなくてミドルウェアが怪しいだろうという事でミドルウェア周りを手分けしてチューニングする方向で調査

innodb_buffer_pool_size = 1G
innodb_flush_log_at_trx_commit = 0
innodb_flush_method=O_DIRECT
  • 静的ファイルをnginxで返すようにしたり
  • 本当にアプリのエラーじゃないことを確かめるためにアプリにloggerを仕込んだり(ここを自前で実装せざるを得なかったのが自分のサーバサイドnode経験のなさの表れだったなあという気持ち)

他チームの追い上げもあったのでなんとしても通したいという気持ちだった中、とあるチームが突然45000点を出してきて無事死亡の気持ちを得る。

16:45 ~ 17:00

  • ミドルウェア周りのエラーだろうと思ってアプリのパフォーマンスをわざと落とす実装を入れてベンチ回したりする悪あがきしてた
    • 結局何度か回してエラー出たのでやめた
  • nginxで弄れるところないかを一生探し続けていたけどだめだった
  • 45000点のチームが何度かベンチして点数をどんどん下げてきていたので何らかの事情でrevertしてるんだろうという感じで、ワンチャンまだある!!!って感じだった

が、結局15000点のベンチを通せずじまい。
最終的に、15:00頃に通った9000点前後のスコアとなった。

結果発表

16:30頃に45000点ぐらいを出したチームが17000点程度まで落としたものの、優勝となった。
うちは9000ぐらい。

お気持ち↓

お開きになった後に反省会で話したこと

  • nginxのアクセスログじゃなくてエラーログ見たら?と指摘されて、見てみたら「Too many open files」が出ていたのを発見 以下の記事を参考に worker_rlimit_nofile をいじったら22000点でた

nginx で Too many open files エラーに対処する - Shin x blog

ぐぬぬぬぬぬぬぬぬ・・・・

  • アプリのloggerは真っ先に入れとくべきだった
  • 完全モノリシック化を諦めたのはナイス判断だった
  • ミドルウェア周りの知見なさすぎて辛かった
  • 想定回答とか見ても全然ベンチの伸び方がかみ合わないんだけど~ってなってた
    • 他のチームもJOINしたりインデックス張ったりしてもベンチ伸びないって言ってた
    • 結局どこがボトルネックなのかよーわからんかった。
  • 足回り整理マンほんと助かる・・・
  • 自分が割と取りこぼしありつつもゴリっとやるタイプで、チームメイトが問題発見とかが得意なタイプだったので自分の弱点を補ってもらえたなぁという気持ちがあった
  • めっちゃたのしかった!

感想

フロントマンが活躍するシーンあるんかいなって感じだったけど、アプリの改善ポイント多めに用意されてた感じがしたので、わりかしやれた感を得られて楽しかった。
そもそも自分はハッカソンやらみたいな限られた時間で精一杯やるってのが好きなので、全力で走った後の心地よい疲れがたまらんですね。
珍しくブログ書くぐらいには楽しかった。