私達がISUCON4の予選で失格した"たった１つ"の理由

ISUCON4にチームhogehogeとして予選1日目に参加してきました！

で、前置きはどうでも良いから何やったのか教えろという早漏君は、
ここまで飛んでしまえばいいさ！

失格した理由だけが知りたいというくれくれ君は、
ここまで飛んでしまえばいいさ！

さて。これ、本選の予習をする予定だった時間を使って書いてみたら、
凄い長文になってしまって、削除しようと思ったけど溢れ出す煮汁の如く
言葉が出てきたので、これは言霊に失礼だという事で削除しませんでした。
きっと読むの5分位かかりますよ。・・・きっと。

チームhogehogeは全員違う会社に所属していて、仕事の案件で知り合ったり
して参加した何ともTHE社会人みたいなチームです。
hoge1とK氏と私の3人で参加しました。

既にblogで皆さんが報告されているのを見る限り、

（´-`）.｡oO（みんなレベルたけぇ・・・）

って感じで、我々がやった事って全然先を行くかっちょえー感じでもなく、
ふーん、そうなのー的なレベルだし、それなら業務でやってるよね？的なので、
全然もう読む価値すらないかもしれませんが、
まぁ、暇だし付き合ってやってもいいよ？的な方がいらっしゃるんじゃないか！？
と、勝手に思ったので、もうそれならと読み物として充実させてやろうと、
文系エンジニアの実力をみせてやるぜ！的なノリで書きはじめていたら、
いやに長文になって、これ暇人じゃないと読めない。って感じなので、
ビスコでも食しながらレッドブル片手に現実逃避の御伴に読んでくれたらいいと思います。

で、結果は予選失格！な訳なのですが、まぁそれについても色々なドラマがあり、
ドラスティックな変化を執行していた訳ではないんですが、それはそれで
小規模な変化を色々と行った訳で、じゃー、なんなのさ。って言われると、
もう何なのかよく解らないんですが、強いて言えば、「楽しかった」って感じ。

本選に出れなかったんですが、本選の日の予定は勿論空けていたので、
「ヒカリエを見上げながら敗者の反省会という名の飲み会」
でも開いて惨めさを染み込ませて、
次回は絶対に本選に行ってやるという気持ちを高めようかと思います。
是非一緒に惨めさを染み込ませたいという方がいらっしゃれば
@taka3110_pcc までご連絡ください。

前置きはこの辺にして、
我々が選択した言語はみんな大好きPHPです。
perlかphpの2択でしたが、業務で慣れてるphpを選択しました。

で、色々チューニングした結果、
最高で38000、最終的な提出スコアは36500程度
でした。

予選1日目は、いろいろあれな事が発生したので、修正込で自己計測だと38000位でした。
惨敗かと思ってたら、意外にギリギリのスコアだったようで。まぁ、失格な訳ですが。



では、当日のドラマをどうぞ。



自社の会議室を借りれるという事で、皆さんにお越し頂きました。
会議室にhoge1、K氏と私の3人がお酒以外で初めて集まりました。

まずやった事。

・100万円の使い道を決める。
まず、これが大事。これを決めないとやる気が起きないという事で、
とりあえず、30万を分割し、残りの10万で祝勝会という王道パターンに決定。
決まった後は、やるぞやるぞコールです。

・コミュニケーションツールを決める
みんなアカウントを持っているという事でChatworkに即決定です。
といっても、今回は口頭と白板やモニタでのコミュニケーションが主だったので、
使用用途としては画像やURLのシェアと「コピペして欲しいコマンドを貼る」程度でした。

・コードやコンフィグの管理方針を決める
gitとかやるよりこの規模ならrsyncすればよくね？という発想で全員一致。
マスターのインスタンスと各人のインスタンスを作り、声を掛けながらマージしていくやり方に。

役割分担としては、
K氏      コード全般解析やチューニング
hoge1   インフラ回りのチューニング
自分     お茶くみ
という感じです。

お茶くみとして先ずやった仕事としては、
・お茶を配る
・お菓子を配る
・モニタや白板等、会議室の準備をする
って感じです。

一応、一番年上なんですけどねっ！
始まる前からもうあれです。あ、このメンツなら俺、戦力外やなと。
もう、K氏もhoge1も各社の中核を担う素晴らしいエンジニア達なんで！
とりあえず、会議室の設営やモニタの準備等をやらせて頂きました！
ひゃっふぅぅぅぅぅ！これで100万もらえるなんてすばらしいイベントやっ！
もう住宅ローンに回して家族からも「パパ素敵！」的な感じの祝福があるだろう！
って思ってて、この時までは勝つ自信がありました。

10:15くらいになったところでスタート。
ベンチを走らせたところ3位になりました。
ここからゴリゴリとK氏がコード全般の解析を始めます。

hoge1もゴリゴリとインフラを触り始めており、私は遠い目をしてました。
追い付くべくphp変更にあたってrubyのプロセスが落ちない等の紆余曲折を経て、
なんとかphpに変更完了。

と、この調子だとちょっとした小説になりそうなので、ダイジェストでどうぞ。


※赤字は目に見えて効果があったものです。

方針としては、大きな変更は1チャンスというイメージ。
CPUが全く使えていないのでCPUを効率的に使う為の設定、
並列処理を上げるチューニングへと大枠の方針決定。
また、memoryが大量に余っているので、I/Owaitを無くして
より効率よく処理させる方針に。

構成はphpの最初に入っていた構成のままです。
nginx --> php-fpm(2インスタンス) --> mysql

簡単に効果があった順に書くと
・MySQLのindex変更
・カーネルチューニング
・オンメモリ化（セッション含む）
・不要モジュールの削除
というような感じでしょうか。
MySQLのindexを変更する事によって効率よくCPUを消費出来るようになり、
phpやベンチに回せるようになって処理速度が向上。
カーネルが追いつかなくなった為にカーネルのチューニングを実施。
残っているI/Oを全てメモリに行くようにして、phpの重い処理を削除。
・・・振り返ると普段どおりの事をやった感じです。

本来はここから色々変更するという形になっていくと思うのですが、
そこまでは今回は手が回りませんでした。

という訳で、足取りを詳細に書いてみました。

---

Start～15:00

[自分がやった事]
・インフラのボトルネック調査
 dstatをインストールしてdstat / vmstat / topでボトルネックを確認しました。
 と言っても、MySQLが使うCPUが目立ちすぎていたので直ぐに解りましたが。。

・オンメモリ化（結果的に採用）
 一番最初にこれに取り組んだが殆ど変わらなかった為、一旦不採用にしました。
 ⇒最後に劇的な変化がありました。

・mysqlの設定チューニング（採用）
 mysqlの設定は各種bufferサイズを上げたのと、
 tmp/cache系の設定をmysql_tunerの情報を参考に入れました。
 あとはinnodbのコンカレンシーをセット。

・phpの再インストール（不採用）
 ちょっとスコアが上がったが、余り意味が無くバグが増えるのもあれなので見送り。
 　※configureオプションを見直してしっかりかえてれば・・・と後悔。

・index等を静的化（不採用）
 login等の処理でエラー多発。DOM構造を変えちゃうかも？という事で見送り。

・MySQLのアップデート（不採用）
 5.6に変更しましたがtimedateの問題でクエリを修正した結果、逆に遅くなりました。


[チームメンバーがやってたっぽい事]
・ソースコードから仕様の把握
 処理遷移を全員でシェア

・ボトルネックの洗い出し
 SQLがポイントという話に。indexの見直しを開始。

・MySQL index 作成（採用）
 indexを貼り換えたり適切なものにしていく事で劇的に変化。


[この時の感覚]
 15時の段階でindexの効果が目に見えて確認出来ており、
 徐々にスコアアップし、10000超え。
 しかし、周りのスコアがもの凄いアップしてました。
 一気に上がってるチームも居たので、恐らくコードとか全部変えてるんだろうと。
 （この予測はのちのブログを見る限り、合っていたようです）
 とりあえず、出来るところまでやろうと励まし合いながら進めました。

---

～17:00

[自分がやった事]
・APCuのインストール（不採用）
 ソースコンパイルでインストール。不採用理由は後述。

・nginxでcache（不採用）
 適当なキャッシュ設定だったので逆に下がった。
 ※こちらもしっかりと設定出来てれば、2000位のアップが見込めたので後悔。

・niceの調整（不採用）
 mysql、ベンチマーク、nginx、php-fpmそれぞれのパターンを試したがイマイチ。


[チームメンバーがやってたっぽい事]
・カーネルチューニング（採用）
 tcp session timeout設定、port range 拡張、ulimit -n 設定などなど、
 tcp周りとファイルディスクリプタ不足のエラー解消

・php-fpm 多重起動（採用）
 より並列処理させる為に、ポートを変更してもう１つphp-fpmを起動

・php date 変更（採用）
 phpのdateを設定

・APCの代わりに/dev/shmにファイルおいてみた（不採用）
 デフォルト状態の時間と変わらず

・APCで検索結果キャッシュ（不採用）
 SQL実行が高速化したためオーバヘッドが多く意味なし

・検索結果をRadisにキャッシュを検討（不採用）
 DBからの整合性がとれない+時間が無い為断念
 ※ここに早めに着手する決断が出来ていればと後悔。

[この時の感覚]
 この段階で既に詰めにかからなければいけなかったのですが、
 試していた事に対するバグ取りが結構時間が掛かるという事で、
 デフォルトのミドル構成で勝負する事を決定。
 カーネルチューニングで徐々にスコアは上がりますが、
 周りのチームのようにスコアがなかなか上がらず、半ばあきらめムードに。

---

～17:50

[自分がやった事]
・xdebug削除（採用）
 不要なモジュールの削除という事でxdebugを削除。

・カーネルチューニングにプラス（採用）
 net.ipv4.tcp_syncookies = 0を追加

・nginxとphp-fpmの通信をunix socketに変更（不採用）
 ファイルディスクリプタが追いつかない状態になり断念。
 ※ここをクリアしていれば結構増えたかもと少し手を付けるのが遅れたのを後悔



[チームメンバーがやってたっぽい事]
・nginx backend との keepalived 60（採用）
 nginxとphp-fpmのkeepaliveを設定して接続コストを少しでも減らそうと。

・log出力停止（採用）
 全プロセスのログ出力を停止してI/Oを極限まで削減

・セッション、MySQLデータのオンメモリ化（採用）
 /tmpに吐かれていたセッションファイルとMySQLのデータを/dev/shmに変更
 Diskへのアクセスをほぼ無くし、I/Owaitを0に。


[この時の感覚]
 残り45分くらいにしてセッションのオンメモリ化とxdebugの削除で、
 何とか37000台まで上がる事が出来て最後まで戦える状態に。
 ただ、なかなかその他の施策が上手くいかず、決め手に欠けており、
 焦りばかりが進むような状態でした。

---

～18:00

35000～38000で結構振り幅があった為、願いを込めながらベンチマーク連投。
結果的に値が下がってフィニッシュ orz


今回のチューニングを通して気付いたのが、
・チューニング仕きってから始めてI/O勝負になる。
・MySQLがCPUゴリゴリ使ってる場合は、indexの貼り方等、クエリ確認を優先
という感じでしょうか。
真っ先にI/Oとか色々弄ってたんですが、indexとかそっちをチューニングした
後じゃないと、効果が見えてきませんでした。
インフラ回りをガッツリいじる前にやる事あるんじゃないの？というのが教訓。

---

で、1日目だけにあった終了後のイベントに突入
～18:30
終わってからworkloadに盛り上がっているのに気付き、自分達も試したところ、

いやああああああああああああああっていう数字が。

workloadを600にしたところ、failも少なく234173。
9分程度っで完了しました。

この瞬間、完全に敗北を覚悟。
「もう、酒飲もう！　もうね。。飲もう！」
って事で、このまま新宿めだかに場所を移して反省会に突入。

本来であれば、workloadの恩恵を真っ先に受けるべき戦略だったのに、
このバグに気付かなかったのは我々の完全なミスでした。
1分で終わるだろうという勝手な憶測によりworkloadを10～30位で確認してました。
12が丁度良かったので、これをセットして報告をしましたが、並列処理を考えて
チューニングしたので、100とか桁を変えて確認しても良かった筈。完全な思い込みです。


負け・・・。負け・・・。圧倒的・・・負け！！！！


というカイジのナレーションが私の頭をよぎっていました。

ただ、これだといかに負荷を掛けるかという、負荷コンテストになるのでは？
「これ、ISUCONじゃなくてIFUCONやんけ。」という話が出た位のタイミングで、
チャットルームを覗いていたところ、運営様よりお知らせが。

ベンチマークソフトをアップデートしてバグを改修したうえで、
再計測をし更に3枠追加します！との事。

いやー、これ当日も良いジャッジだと思いましたが、
後日確認してみて改めて物凄いジャッジだと思いました。
順位を推測しながら皆さんのブログを確認していたら、
プラス3組ってものすごい絶妙な数字で、
workloadで勝ち上がった人達の分追加されているイメージなのかなと。
それを当日、あのタイミングでジャッジしたのは運営さん凄いなと。

題材も、これ弄るとこそんな無いのでは？という感じでしたが、
弄ってみると以外にも伸びしろがあるという面白い内容でした。
何よりphpでも結構戦えるね～というのが解って嬉しかったです。
今回は失格という残念な結果に終わりましたが、
次回必ずや本選に行けるように日々精進したいと思います！



あ！大事な事、忘れてましたね。
失格になった１つの理由ですが、恐らくお気付きの方もいらっしゃると思います。
～17:50にあったパートですね。

・セッション、MySQLデータのオンメモリ化　です。

我々はベンチマークを実施する前提でプロセスを立ち上げるのは問題無い
という確認をしていたので、ベンチマークソフトのinitに仕組みを仕込みました。

簡単に言うと、ベンチのinitでrsyncをして/dev/shmに移すという作戦でした。
再起動テストも実施して、完璧と考える状態で提出しました。

しかしながら、レギュレーションには以下が記載されていました。
"ベンチマーク実行時にアプリケーションに書き込まれたデータは、再起動後にも取得できること。"

もうお気付きですね。

これだと、実施後の再起動でデータの整合性が取れないんです。
私たちが失格した"たった１つ"の理由。それは・・・


「レギュレーションをちゃんと理解していなかったこと。」


次回は先ず読み合わせからやります！
っていうか、俺、遠い目をしながら最初にレギュレーション読んでた！
だまっててごめん！っていうか、スルーしてて、ほんとごめんなさい！！！


俺等は技術で負けたんじゃない！国語で負けたんだ！


という名言を文系エンジニアが吐いたところでドラマをクローズしようかと。


ちゃんちゃん。