ISUCON7 予選1日目1位通過しました

ISUCON7予選一日目 一位通過しました

ISUCON7

ISUCONとは

お題となるWebサービスを決められたレギュレーションの中で限界まで高速化を図るチューニングバトル、それがISUCONです。過去の実績も所属している会社も全く関係ない、結果が全てのガチンコバトルです。

運営の方々のご尽力もあり、今年のISUCON7も無事開催されました。
ISUCON7 開催&日程決定 本当にありがとうございます。
1日目、2日目共に開始時刻が遅延することにはなりましたが、競技中は問題はなく、快適に開発をすることができました。

遅延している間、チームでは、「今どんな発言も運営の人にとってはノイズみたいなものだから、黙って待って、開催出来たら感謝、振替で参加できなかったとしても、ここまで頑張ってくれたことに感謝しよう。」という話をしていました。
無事開催され、本当に運営の方々には感謝しています。

チーム「MSA」

私はチーム「MSA」として予選一日目に参加させていただきました。
社内でプログラミング経験者を募集して、まずsuzukiさんが一緒に出てくれることになり、応募締め切りの一週間ほど前にken39argさんが一日目であれば参加可能ということで、チーム結成となりました。
チーム名はそれぞれの苗字の頭文字からとっています。

チームでの役割としては、私はアプリを担当し、suzukiさんはインフラ、ken39argさんにはアプリを実装してもらいつつインフラもみてもらいました。
私も社会人3年目でweb開発はまだ2年も関わっていないぐらい、suzukiさんも新卒でしたので、ken39argさんに引っ張ってもらう感じでした。

事前準備

とりあえず、一緒にランチに行き、「こんな準備がいるかなー」とか「こんな問題がでるかなー」とか話していました。
これが予選の10日ほど前だったと思いますが、githubリポジトリを作成して、issueに当日の流れを書くぐらいで、チームで集まって過去問を解くなどはしていなかったので、正直色々もたつくだろうと思っていました。(実際ちょっともたついてしまいました。)

予選当日

先にISUCON7予選の問題について触れておくと、 isubata というアプリでした。
チャットアプリケーションである idobata が元ネタだと思います。
チームの作業の流れとしては下記のような流れでした。

  1. スローガンを決める
  2. レギュレーションと当日マニュアルをみんなで読む
  3. とりあえず初期状態でベンチマーク実行
  4. 構成確認
  5. gitにコードを含めて、変更後デプロイをコマンド実行でできるようにする
  6. nginxとmysqlのログを吐くようにする + mysqlのインデックス張る
  7. ユーザーのアイコン画像の情報がDBに入っていたので引き剥がす
  8. 既読管理によるDBへの集計クエリループ削除
  9. nginxでCache-Control設定
  10. メッセージ作成のループクエリ削除
  11. 画像のproxy方法の変更
  12. 終了2時間前にスコアが急激に下がって焦る
  13. 終了30分前からは反省を始める

(残念なことにISUCONについてはほぼほぼ初心者の集まりだったためスコアを記録するなどしていないので、どういうスコア推移になったのかはわかりません。)

スローガンを決める

開始が延期したこともあって、チームでの作戦を午前中に立てていました。
そこで決めたスローガンは「落ち着く」「いつも通りのことをする」「終了1時間前になったら変更をやめる」の3つでした。
特にISUCON用に準備していたわけでもないので、いつもやっていること以外はやっても不安定になるだけだろうということで、チャレンジはしないことにしました。

レギュレーションと当日マニュアルをみんなで読む

どこまで変えていいのか、最後の測定は再起動などどうなるのか、知っておかないとスコア残らないなんてことにもなるので、じっくり読みました。

とりあえず初期状態でベンチマーク実行

初期でちゃんとアプリケーションが動くかどうか確認するため、golangに切り替えてベンチマークを実行しました。

構成確認

最初の構成を確認して、appが2台とdbが1台であることを確認しました。
1台だけcpu、メモリなどが違うなどの偏りはありませんでした。

gitにコードを含めて、変更後デプロイをコマンド実行でできるようにする (@suzuki)

gitにコードをpushし、makeコマンドのみで変更の反映ができるようにしました。

nginxとmysqlのログを吐くようにする (@ken39arg)

alpとpt-query-digestで解析できるように、nginxのアクセスログmysqlのslowlogを書き出す用に設定しました。
結果から言うと、準備不足で最後までpt-query-digestの実行はできず、コードを見つつ、slowlogを目でざっと追ってindex張るなどしました。

ユーザーのアイコン画像の情報がDBに入っていたので引き剥がす (アプリ: @mizkei、インフラ: @suzuki)

ユーザのアイコン画像がDBにBLOBで入っていたため、それを引き剥がしました。
アプリとしては特に難しいこともないので、 POST /profilemysqlにデータを入れていた箇所をファイルに書き出すようにして、 /initialize でデフォルトユーザのアイコンをDBから引き出して、ファイルに保存しました。

インフラとしては、初期の状態ではDBサーバのリソースがだいぶ余っていたのでappもおいてしまい、DB+appのサーバーに POST /profile をproxyして、静的ファイルは全てそこにおいておき、 /icons へのリクエストをそちらに流すようにしました。

既読管理によるDBへの集計クエリループ削除 (@ken39arg)

isubataではチャンネルのメッセージに対して、個々のユーザがどこまで読んでいるかを記録し、チャンネルの一覧部分で、未読件数をバッジで表示していました。
この未読件数はチャンネルのループに対して、メッセージの集計クエリがループするというだいぶ重いものになっていました。
isubataではメッセージの削除機能は存在していなかったため、メッセージの総数などはテーブルのカラムに追加して、ループクエリは削除しました。
これも /initialize でデフォルトのメッセージをカウントしてテーブルの更新をしていました。

nginxでCache-Control設定 (@suzuki)

イコン画像などは変更がなければ返す必要すらないので、304 not modifiedになるようにnginxで設定を行いました。

メッセージ作成のループクエリ削除 (@mizkei)

メッセージ作成用の関数に jsonifyMessage という、いかにもjson用の構造体など作っていますよ、みたいな名前のやつがいましたが、こいつは中でクエリを実行していて、ループクエリしていました。
そこでぱぱっとクエリのループを消して、よしベンチ、と思ったらfail。
メッセージに紐づくユーザを引いてくるという処理なのですが、元のクエリではuserのidは引いていなかったので、紐付けるidがないという状況でした。

私のくだらないミスで、10分で終わる修正が50分になり、 ken39argさんにも何がおかしいか見てもらうなど時間を使ってしまいました。

画像のproxy方法の変更 (@suzuki + @ken39arg)

ここでボトルネックがDB+appサーバーのリソースに移っていたので、appを消し去り、DBのみとして、他2台でappの処理をすべて行うようにしました。
イコン画像の処理はメモリを使うこともあって、1台で POST /profile を受けることはせず、それぞれ保存して、nginxからtry_fileで存在しなかったら、もう片方にproxyするようにしました。 ここでスコアは46万点を超えました。

終了2時間前にスコアが急激に下がって焦る

残念なことにここで私達の修正は終わりました。19:30を過ぎた頃だったと思います。(一応1日目の終了時刻は21:15ぐらい)
再起動試験をしつつ、DBのチューニングにようやく取り掛かろうというところで、急にスコアが30万まで下がりました。
原因がわからず、もう一度回すと20万、10万と下がっていきました。
なんだ?と思っていたら、appサーバー2台がswapし始めていました。
今まで変更のたびに再起動していましたが、DBのみの修正でapp再起動しななかったのですが、連続でベンチを実行することでメモリが太っていくことがわかったのです。

これは推測でしかありませんが、アイコン画像のアップロードについて、ioutil.ReadAllしている箇所があり、これが良くなかったのかなと思っています。
普段はReadAllなんてほぼほぼしないですが、ボトルネックにもなっていなかったし、画像データのsha1からファイル名を作っていたりと、修正が若干面倒だったので、放置していたのがよくなかった。

(fujiwara組の記事にありますが、GOGCの設定でも充分に防げていたようです。)

終了40分前からは反省を始める

原因はわかったので、修正どうするという話になりました。
とりあえず、数回のベンチマークであれば30万点程度までの落ち込みで済んでいたので、アプリの再起動だけして、放置しました。
不安ではありましたが、無茶な変更してfailするよりはこのままにしようという決断をしました。
nginxやmysqlのログも切らずにそのままにして放置。

その間「これがよくなかったか。」「気づけたよなー」という話をずっとして過ごしていました。
私もken39argさんも「落ち着く」ができておらず、アプリの修正でくだらないミスをしていたりして、時間の浪費があったので、これはなくしたかったという反省をしていました。

まとめ

結果として私達のチームは一日目予選一位で通過しました。
ISUCON7 本戦出場者決定のお知らせ
ただ、全体としては5位であり、まだまだ改善できるポイントはチームの役割も含めてたくさんありました。
決勝で勝つために予選での反省点を活かしていきます。

最高に楽しいイベントを開催して頂いている運営の方々に感謝です。
決勝もよろしくお願いいたします。