ISUCON3予選で何も出来なかった話 #isucon

YAPCYAPC::Asia 2013 で「社内ISUCONのつくりかた」を発表しました - 酒日記 はてな支店に刺激されたので ISUCON に会社の後輩と参加しました。
もともと3名で登録してたけど、インフラ方面の頼みの綱がこれなくなっててんやわんやした結果、ほとんど何も出来ずに終わってしまった。もともとアプリ寄りなのでインフラとか全然わからなかった。

やったこと

作業ログは残してあるけど時間軸が記憶頼みなので適当に記載。

事前準備

1時間前に会社について方針を練る。とりあえず、序盤は top で概要把握して、おそらく DB が序盤のボトルネックになるだろうからスロークエリの出し方とか予習してた。
あとは前回・前々回の参加者ブログ*1を読み返してた。

序盤

AWS はちょくちょく使ってたので大丈夫だと思っていたけど、Quick Launch Wizard から Key Pair 変更できなかったりなんなりで20分ほど出遅れる。
SSH で接続できるようになったらとりあえず README 読んでアプリを nodejs に切り替えてから最初のベンチを取った*2。ちなみに、lingr 見て supervisord についてググってってしてたらこの時点で11時近くになってた気がする。初期スコアは確か1000ちょいだったかな。
とりあえず、ベンチ取りながら top 見てると案の定 MySQL に負荷がかかってるみたいなので、自分はそっちの調査とチューニングをして後輩にはアプリのコードで怪しそうな処理がないか見てもらうことに。バージョン管理とかどうしようか考えたけど、とりあえず webapp 以下を git init しておいた。
そういえば、後輩にはアプリのコードとは別にベンチマークツールの挙動を解析してもらおうと思ったけどバイナリだったので諦めた*3。そりゃそうか。
mysql 入って show variables でスロークエリが OFF なのを確認。isucon ユーザでは設定書き換えれなかったので my.cnf を探す。 my.cnf が /usr/my.cnf しかみつからなかったので、無視して sudo vi /etc/my.cnf にスロークエリの設定だけ書く。

[mysqld]
slow_query_log = ON
long_query_time = 0.01

ベンチ回して mysqldumpslow で確認したので片っ端からインデックスはった。created_at は不要かもしれないとは思ったけど、既存データがちゃんと id 順で入ってるのか確認するのが面倒だったので後回し*4

ALTER TABLE memos ADD INDEX is_private(is_private);
ALTER TABLE memos ADD INDEX list(is_private,created_at,id);
ALTER TABLE memos ADD INDEX user(user,created_at);

インデックスはった後、公式のベンチ実行時に DB リセットされるのに気付き、lingr を見つつ init 用のファイルを作成。インフラ力*5が無くて exit 0 とファイルの実行権限ではまったけど、ここまででスコアは 2000 前後。
途中後輩が毎回 username を users テーブルから取ってきてるのを見つけたので、username を memos に持つように指示。/memo で older と newer の計算も重そうだと言ってたで、SQL 1本に出来そうだと思ったけど早くなるか微妙だと判断したため後回しに。ちなみに、この判断は間違ってたっぽい。
初期化スクリプトで既存データにも username 持たせないといけないのでそれに着手しようとしたところで 12 時過ぎていたのでお昼に。

中盤

昼ごはんを食べながらせめてスコア 5000 位はいかないとなーとか話してた。

後輩が username 周りの実装が終わったので、初期化スクリプトで以下の SQL を読みこませるようにした。

    /** ADD COLUMN **/
    ALTER TABLE memos ADD `username` varchar(255) NOT NULL AFTER user;

    /** UPDATE username in memos table **/
    UPDATE memos, users
       SET memos.username = users.username
     WHERE memos.id = users.id;

    /** ADD INDEX **/
    ALTER TABLE memos ADD INDEX is_private(is_private);
    ALTER TABLE memos ADD INDEX user(user,created_at);
    ALTER TABLE memos ADD INDEX list(is_private,created_at,id);

これでスコアは 2400 くらい出た。
後は、node のログを見てると /js, /css, /img とかの静的ファイルを返していたので、静的ファイルは Apache で返そうと試みる。みんな簡単に「静的ファイルをApacheで返すようにした」とか言ってるので簡単そうに思ってたけどここで大ハマリした。テンパってたのと Apache 力の低さと、途中で Varnish か memcached で返そうとか思ってグチャグチャしてるうちにベンチ通らなくなって詰んだ。基本から勉強しよう。
後輩には、ログをざっと見た感じ /recent とかが重そうって言ってあって、それを考慮しつつアプリ側の細かい修正をしてたようだけど、ここらへんから情報共有してる余裕がなくて余り把握していない。

終盤

結局ベンチ通らないまま原因がわからなかったので、残り1時間くらいでインスタンスを新しく立ち上げてそちらにこれまでの作業を移行することに。移行自体は10分程度で終了し*6、公式ベンチをまわしてみるとスコアが 2000 に下がってた。なぜ?
最後のあがきで ApacheMySQL のパラメータ・チューニングを試みるも大きな効果はなし。
後輩が /memo の older と newer の件を思い出したけど時既に遅く、両方見つけたらループから抜けるという適当な処理を入れて最後のベンチを取ろうとしたらタイムアップ。最終的にスコア 2600 台が出たけど送信できず。

反省点

  • 会社にドンピシャな書籍がいくつかあったのに Web の情報ばかりに頼ってしまった。本を読もう。
  • まずアプリの内容を把握しておくべきだった。Markdown 変換の処理に終了後まで気づかず*7。アプリちゃんとみてればもう少しやれることがあったな。
  • 後回しにしたタスクの棚卸し大事。
  • --workload の意味に気づかず。ただ負荷が上がるだけのストイックモードなのかと思った。負荷が上がるということは捌ける数も下がってスコア下がるんだろうなという安直な発想してしまった。んなオプションあるわけない。
  • インフラ力がたりない。もう少し色々弄らないとな、nginx 触ってみよう。

まとめ

基本的なことすら出来ず残念*8でした。ただ、普段やらないインフラ周りの設定とか勉強できたのでかなり学びが有ったし楽しかった。@fujiwara さん @acidlemon さん始め、運営のみなさんありがとうございました!

Java 実装あったら嬉しかったかも。

*1:特にチームfujiwara組を中心に

*2:LL系で二人ともわかるのがJavaScriptだった

*3:リバースエンジニアリングまでは流石にやらない

*4:すっかり忘れてたのでその後着手せず……

*5:常識

*6:ここまで大した作業をしていないということ

*7:画面見た時点で気づけ

*8:実質インデックスはったのみ