#isucon2 で優勝してきました - 酒日記はてな支店

なんでもありのいい感じにスピードアップコンテスト ISUCON が 2 になって帰ってきたので、参加して優勝を勝ち取ってきました。

チームメンバーのblogも併せてご覧ください。

今回は前回の ISUCON 優勝メンバーのひとり @sugyan が転職して出題側に回ってしまったので、@typester を招聘してチーム編成。@songmu と共に3人でチーム「fujiwara組」として再参戦です。

以下、作業用IRCのログからふりかえりますと……

11:39:29 <typester> とりあえずrecent_soldはキャッシュってのはまずやることかなーと
11:39:33 <typester> おもいますが
11:39:36 <typester> たぶん松木さんがそういうのはやるとおもうので
11:39:57 <typester> 僕はRedisブランチをたちあげますのでよろしくおねがいいたす
11:40:01 <typester> fujiwara: Songmu ^
11:40:05 <Songmu> え
11:40:22 <Songmu> 了解です。
11:40:27 <typester> チケット販売とか、だいぶredisつよいとおもうってのと
11:40:32 <typester> 自分がそのベンチに興味がある
11:40:43 <Songmu> ｗｗｗ

開始30分で redis を利用するアプリケーションを実装することを typester が宣言。それの実装を待つ間に、デフォルトのアプリケーションのボトルネックを調査。

12:25:05 <fujiwara> 静的ファイルはapacheに変更
12:36:33 <fujiwara> create index stock_order_id on stock(order_id);
12:36:35 <fujiwara> indexはった
12:36:43 <Songmu> はい

初期状態では MySQL の行読み込みが非常に多くて CPU を使っていたので、slow query を眺めつつ explain して index を追加したり。

GET が来る URL は大きく分けて

/ (topページ)
/artist/*
/ticket/*

だったので、それぞれ個別に http_load でベンチを掛けてどこが重いのか計測。

この間、rev, app, db のそれぞれで dstat を実行しつつ、どこに負荷が掛かるのかを眺めていました。

12:54:52 <fujiwara> http://127.0.0.1/ => 492.856 fetches/sec
12:56:11 <fujiwara> http://127.0.0.1/artist/1 => 126.98
12:56:26 <fujiwara> artistはmysqlの負荷が高い
12:58:10 <fujiwara> http://127.0.0.1/ticket/1 => 49.698
12:58:18 <fujiwara> mysqlの負荷はartistほどではない

さらに MySQL 側を地味に改善しつつ…

13:17:03 <fujiwara> create index variation_order on stock (variation_id, order_id);
13:17:05 <fujiwara> たした
13:18:32 <fujiwara> artist 374.4 まであがった
13:35:59 <typester> redisブランチプッシュした

ここで購入処理 (重い) を Redis を利用するアプリケーションの実装が初期バージョン投入。

この時点では MySQL 利用バージョンで ticket 1000 ぐらいのスコアだったのですが、今回のアプリケーションでは非常に並列度が高い (合計200並列) ため、ある程度 Apache の子プロセス数を絞る (MaxClients 32とか) ほうが性能が安定し、1400程度になりました。

MySQLの処理が Redis の効率的なデータ型での処理(set、listなど) を利用したものに置き換えられたため、DB側の負荷は全く問題なくなりました。

しかし。その割にはスコア (ticket) は伸びず…

昨年同様、このあたりからIRCでのやりとりが少なく、口頭ベースになって記録が途絶えがちなのですが、

この時点ではボトルネックは app の CPU 負荷で、そのうちどこが重いのかを個別 URL の http_load 自前ベンチで /ticket だと特定
Devel::KYTProf で Text::Xslate->render も計測するように設定し参考、テンプレートのレンダリングで 50〜100ms 程度掛かることを特定

レギュレーション的に「データ更新から1秒以内に反映されている」ことが求められるのですが、データの更新が行われる /buy には秒間数十リクエストが押し寄せるため、POST /buy のタイミングで cache 生成 + 破棄を繰り返してもほぼ使い道がいないのです。

ということで、重いレンダリングを worker に独立させて1秒以内に cache 生成し続ける + Webアプリケーションはその cache を参照するのみにする、という方針で実装を進めました。

worker を一から作成するのは面倒なので、Webアプリケーションの /ticket/update_table_cache という URL に POST してキャッシュ生成を行うように実装＋毎秒 HTTP request を送り続けるプロセスを supervisord から起動、という実装にします。

今回のアプリケーションでは、このキャッシュ生成は1秒以内に5ページ分行う必要があるのですが、なにしろレンダリングが重いので、1リクエストで5ページ分を一気に生成すると高負荷時に2秒以上掛かることが時々発生。この遅延をベンチマークツールに検出されてしまうと fail で失格です。

Devel::KYTProf でリクエストを送り続けるプロセスからレスポンスタイムを監視した結果、