全くの素人がISUCON5本戦に参加しました

2015-11-08 ISUCON, event

はじめに

ISUCON5の本戦に @methane さん、@koki_cheese さん、私(@gam0022)の3人で、チーム名 lily white として参加しました。結果は fail (サーバの再起動のテストで失格しため、スコア無し)でした。

ISUCONとは、お題となるWebサービスを限界まで高速化を図るチューニングバトルです。私は今回のISUCONに参加するまで、インフラもパフォーマンス・チューニングも経験のない全くの素人でした。自分の実力では本戦出場は絶対に不可能でしたので、本戦まで連れていってくださったチームのみなさんには本当に感謝しています。

ISUCONの攻略に関する有益な情報は、既に他のブログに多くのエントリーがあると思いますので、本記事では全くの素人がどんなふうにISUCONに参加したのかを振り返っていこうかと思います。予選+本戦を振り返るため、長文になります。すみません。チーム全体での参加の様子は、@methane さんのブログで紹介されています。

参加のきっかけは、会社の先輩でスーパーエンジニアの @methane さんがISUCONに興味のある新人を募集していたことでした。インフラやパフォーマンス・チューニングを学習する良い機会になりそうだと考えて、参加を決意しました。また、大学生の @koki_cheese さんが ISUCON メンバーを募集していたので、 @methane さんが自チームに引き入れ、チーム lily white が結成されました。

予選

まずは予選に関して、練習でやったこと、当日やったこと、後日やったことを振り返ります。

予選にむけての準備

リーダの @methane さんにアドバイスをいただきながら、私と @koki_cheese さんは練習と対策を行っていきました。

事前に、GCP(Google Cloud Platform)上で予選が実施されるというアナウンスがあったため、練習にはGCP環境を使用しました。ちなみに、ISUCON 参加チームには1年間有効な100ドル分のGCPクーポンが配布されます。

また、去年開催された ISUCON4 の予選はAWS上で実施されましたが、 ISUCON運営チームが ISUCON5 の練習用に ISUCON4 の予選のGCPのイメージを配布してくださいました。まずは、このイメージを使って ISUCON の雰囲気をつかんでいきました。

ISUCON4の予選はのお題は「いすこん銀行」というログイン機能だけの非常にシンプルなWebアプリでした。 @methane さんにプロファイリングの方法などを教わりながら、次のようなことをしました。

GCP自体の使い方の練習
以下のコマンドやツールを使った、プロファイリングの練習
- @methane さん作の myprofiler という MySQL のプロファイラ
- @methane さん作の Nginxのアクセスログを集計して、ページごとのレスポンスや通信量を調べるスクリプト
- dstat という色々なリソース状況を見るためのコマンド
- top というプロセスごとの CPUやメモリの状況を調べるコマンド
Go言語のアプリとMySQLをTCPではなく、UNIXドメインソケットで繋ぐ練習
Nginxで静的ファイルを返す設定をする練習
DBのオンメモリ作戦にチャレンジ（自分の実装力とアプリの挙動の把握力が低すぎてハマったので、当日はオンメモリは止めることにしました）

また、チームとしてGoを選択することは決まっていたのに、私はGoが全くの未経験だったので、 A Tour of Goを一通り目を通してGoに慣れておきました。

strace/pprof についても教えてもらっていましたが、これらの練習は手を付けられませんでした。

予選の当日

ISUCON5の予選のお題は「ISUXI」という某SNS風のアプリでした。また、SQLのチューニングだけでもギリギリ予選突破できるような問題となっていました。

基本的にISUCONはチーム戦ですが、私たちのチームでは個人でそれぞれチューニングを行ない、最高スコアのインスタンスを提出する作戦でいきました。

私のベストスコアは2000程度で、予選通過ボーダーラインの13898を大きく下回る結果となってしまいました。チームとしては、@methane さん1人の力で予選を突破する結果となりました。

ボトルネックの調査

まず、myprofiler でクエリをプロファイリングしたところ、relationsというテーブルが何度も参照されていることが分かりました。

また、entriesとcommentsというテーブルでは、body というカラムの1行目がタイトルとなっていて、アプリ側で1行目を取り出して、2行目以降は捨てるような処理となっており、かなり無駄な FETCH が発生していることが分かりました。

そして、いくつかのテンプレートで、usersテーブルをSELECTしていて、いわゆる「N+1」問題になっているというところまでは分かりました。

対策

まず最初に、Go言語のアプリとMySQLをTCPではなく、UNIXドメインソケットで繋ぐところをやりました。

body カラムの問題については、対応が大変そうだったので、後回しにしました。

予選マニュアルをよく読むと、「ユーザはすべてメールアドレスとパスワードでログインしますが、データベースにデフォルトで登録されているユーザは全て、パスワードはアカウント名と同じです。」とあり、追加分のユーザのデータについてもこのルールを満たしていることが分かったので、初期実装のハッシュ値の計算などを消して、メールアドレスのアカウント名だけを切り出して、パスワードとの単純な文字列の一致で行うようにしました。

この変更を加えた後もベンチマークは正常にパスしましたが、結果的にはこの変更は悪手でした。ログインの処理はベンチマーク中で数回しか行われおらず、スコア的には誤差くらいの意味しか無かったので、他のことに時間を使ったほうが有意義でした。

この後は、ずっとSQLチューニングをしていました。 INDEXを貼ったり消してEXPLAIN結果の変化を見たり、地道に「N+1」になっている箇所を潰したりしました。

ralationsというテーブルがuser同士の友達関係を保持しており、 isFriend()という関数でユーザ同士の友達関係のチェックをするために、次のSQLのクエリを使っていました。

SELECT COUNT(1) AS cnt FROM relations WHERE (one = ? AND another = ?) OR (one = ? AND another = ?)

このアプリでは友達関係は両方向で、初期データセット全てのrelationsのレコードについて、 one と another を入れ替えた対応するレコードが存在していそうなことを確認して、次のように書き換えました。

SELECT COUNT(1) AS cnt FROM relations WHERE (one = ? AND another = ?)

元のクエリでもそこまで処理が重いわけではありません。しかし、理由は後から分かりましたが、isFriend()関数はトップページを1回表示するごとに2000回以上呼ばれていたので、それなりに効果がありました。

友達の人数を取得するために友達のuesrsを全件FETCHしてGo側で配列の要素数を数えているのを、SQLのCOUNTで置き換えるなどしました。

ここまですると、友だちの最新の日記エントリ10件を返す部分がボトルネックになってきました。最初の実装だと、最新のエントリ1000件を全件取得して、上のisFriend()関数を呼んで友達のエントリーだけをフィルターしていました。そのため、isFriend()関数が大量に呼ばれていたわけです。ここが最大のボトルネックなのは察したので、残りの全ての時間をかけてここを潰す作戦にしました。

このようなケースだったら、IN句を使うことで友達のuser_idでフィルターできるという知識くらいはかろうじてありました。単純にIN句の中にサブクエリを書くように書き換えたところ、スコアが大きく下がりました。適当に書いたサブクエリがうまく最適化されていないのが原因でした。

サブクエリの中身を別の独立したSQLして分離するか、EXISTSやINNER JOINで置き換えれば良かったのですが、予選時にはそれらの知識が無かったので、間違った方向に試行錯誤して、時間切れになりました。

そして、2000程度の予選通過ボーダーラインを大きく下回るしょぼいスコアでフィニッシュしました。

予選のリベンジ

とても予選が悔しかったので、MySQLのクエリチューニングとインフラの設定だけで予選ボーダーを超える練習をしました。本当に基本的なSQLチューニングしかできませんでしたが、最終的には17000くらいスコアが出て、なんとか予選のボーダーは超えました。

クエリチューニング

例の友だちの日記エントリについては、 SQLを速くするぞやなぜMySQLのサブクエリは遅いのか。という記事を参考にして、 IN句ではなく、EXIST句に置き換えたところ、サブクエリが最適化されるようになりました。さらに INNER JOIN に置き換えてみましたが、これはあまり効果がありませんでした。

全く同じような方法で、最新の友達のコメント10件もEXISTSに置き換えると、10000点は超えるようになりました。

予選当日に潰しそこねた「N+1」を全て殲滅すると、isFriend()関数の呼び出しは1箇所だけになりました。

あまりネタバレを見ないでリベンジしていたのですが、足あとに関しては自分では良い対策が考えつかず、公式の解説の鮮やかなREPLACEとテーブルの置き換えをそのまま行いました。

クライアントでこのようなクエリを投げて、 body カラムの問題については、entries.body の1行目を entries.title に入れるスキーマの変更をしました。あとはクエリを適正に書き換えることで、body の無駄な FETCH が減らすことができます。

ALTER TABLE entries ADD COLUMN ( title VARCHAR(80) );
UPDATE entries SET title = SUBSTRING_INDEX(body,"\n",1);

圧縮テーブル

今回はDBのサイズが巨大でメモリに載りきらないので、圧縮テーブルを試しました。まずは、my.cnf でファイルフォーマットを Barracuda にして、

[mysqld]
innodb_file_format = Barracuda

クラアントでこうすると、既存テーブルも圧縮テーブルにできます。意外と簡単です。

ALTER TABLE entries row_format = compressed;

ウォームアップ

正しいウォームアップ方法は今も分かっていませんが、 innodb_buffer_pool_dump を有効にするだけでも、再起動直後のスコアはかなり効果がありました。

[mysqld]
innodb_buffer_pool_dump_at_shutdown = 1
innodb_buffer_pool_load_at_startup = 1

本戦

本戦の練習やっこと、当日やったことを振り返ります。

本戦にむけての準備

本戦の役割分担としては、環境設定などの下回り的な部分、オペレーション、MySQLのクエリチューニング、
リグレッションテストをすることになったので、これらを中心に練習しました。

クエリチューニング

上で紹介した予選のリベンジを通して、基本的なクエリチューニングを学んでおきました。また、MySQLのプロファイリングについては、プロファイリングで快適MySQLチューニング生活や MySQLのEXPLAINを徹底解説!!、 MySQL初心者に贈るインデックスチューニングのポイントまとめ2014 などの記事を読みながら練習しました。

その他にも、my.cnfの読みこまれる順序や、設定ファイルの基本的なパラメータの勉強、スキーマの変更のためのALTER系のクエリの使い方などを一通り予習しておきました。

Nginx

予選リベンジでやった以上のことは実践できませんでしたが、マスタリングNginxという本を読んでおきました。

オペレーション

sshの環境設定、DBや設定のバックアップ、プロファイリング用のログを取るなどの最低限の練習はしました。

気休め程度に、当日の環境構築のチートシートは用意しておきました。

あとは、Nginxの再起動無しにログファイルを別のファイルに退避するコマンドなどを用意して、プロファイリング用のコマンドを当日コピーすればすぐ使えるように、ビルド済のバイナルファイルをまとめておきました。

リグレッションテスト

予選ではベンチマークのキューの待ち時間が長いため、気軽にテストをできる状況では無かったです。そのため、簡易的なリグレッションテストをしようということになりました。

gorというツールを使うと、ヘッダーなどを含めてHTTPのリクエストをキャプチャできるので、この結果を見ながら簡易的なリグレッションテストを行うRubyのスクリプトを書く練習などをしました。

本戦の当日

本戦のテーマはマイクロサービスとなっていて、外部APIにリクエストを送り、その結果をまとめてユーザに返す「AirISU」というサービスでした。

スコアを上げるためには、APIへのリクエストを並列化したり、適切にレスポンスをキャッシュしたりする必要がありました。このあたりのチームの攻略方法については、@methane さんの記事に詳細があります。

本戦で私がやったことを振り返ります。

まずは事前の打ち合わせ通り、sshの環境設定を行いました。本戦ではマシンが3台構成で、初期状態ではパスワード認証だけができる状態でした。全員分の公開鍵も用意してあり、準備万端かと思いきや、ローカルから各マシンにはsshができるのに、マシン同士のsshができずに時間を無駄にしてしまいました。

@koki_cheese さんが /etc/hosts.denyが原因であることを付け止めてくださり、 /etc/hosts.allowをsshd: ALLに書き変えて対処しました。基本的な設定だったことに加え、適切に調べればすぐに分かるような問題だっただけに情けなかったです。事前の作戦では、プロファイリングやGoへのアプリの実装の切り替え・初回ベンチ・プロファイリング用のログの取得は自分の役割だったのですが、上記のsshの設定で手間取っている間に、2人に代わりにやっていただきました。

その後は、設定ファイルをバージョン管理したり、ログインシェルが sh だったので、bash に切り替えたり、事前に用意したコマンドをサーバに配置してパスを通したり、リーダの指示に従って、Nginx 周りの設定を行なっていました。

Nginxでの静的ファイルの配信は予選でもやっていたので問題無かったのですが、 gzip_static の設定は gzip コマンドの -k オプションを知らずに時間を無駄にしてしまいました。

他にも、include mime.types;を追加したところ、Nginx が再起動しなくなってしまい、 service コマンド経由で再起動するとエラーメッセージが標準出力されずに、fail としか出力されず、時間を無駄にしました。冷静に考えると、Nginxのエラーログを先に見れば、すぐに解決する問題でした。

このような初歩的な知識が無く、エラーログを読むなどの基本的なトラブルシューティングができずに、チームには迷惑をかけてしまいました。

MySQL のクエリチューニングの練習を一番練習していたのですが、本戦は MySQL ではなく postgress でした。しかも、クエリは非常に単純で、データ量も少ないのでボトルネックでは無さそうでした。 2人がDBのオンメモリ化を進めていたので、結局DBのチューニングはスルーしました。一応、pg_dump で初期データとスキーマのバックアップはとっておきましたが、最後まで使いませんでした。後から考えると、もう少しスキーマをじっくりと眺めて、インデックスだけでも適切に貼っていたりすれば、初動のスコアなら少しは貢献できたかもしれなかったです。

リグレッションテストについても、一部のレスポンスが外部APIに依存していてベンチマーク毎に結果が変わってしまうこと、予選よりもキューに空きがあってベンチマークを投げやすかったことなどがあって、リグレッションテスト自体の必要性が薄れてしまったので、作りかけで破棄しました。

後日やったこと

/etc/hosts.allowをsshd: ALLに書き変えた結果、本戦後3日くらいまでは自宅からも本戦のマシンにアクセスできる状態になっていたので、 API を叩いたり、当日は把握できなかったアプリの挙動を確認たりしていました。

公式の GCP のイメージが公開されたら、きちんと復習したいと思っています。

まとめ

ISUCON5 にチーム lily white のメンバーとして参加し、初参加ながら本戦出場を始めとして多くの貴重な機会を得ることができました。私個人としては、予選・本戦ともに、初歩的な知識や事前練習が不足していたこと、エラーログを読むなどの基本的なトラブルシューティングができなかったことで、チームのメンバーには迷惑をかけてしまいました。

結果的には、不完全燃焼でしたが、インフラやパフォーマンス・チューニングを勉強する良いきっかけになったと思います。また、社内のすごい先輩に直々に指導してもらい、意欲的な学生に出会えて、良い刺激を受けました。

来年もISUCONが開催されるのであれば、またリベンジするつもりです。それまでに、自分の力で予選突破できる程度には、頑張って実力をつけたいです。

最後に、ISUCONの運営チームの方々に深く感謝します。問題の作成やインフラの提供に加えて、GCPの無料クーポンの配布や過去の問題のイメージの準備など、練習の環境までサポートしていただきました。楽しいコンテストを、どうもありがとうございました。