2012/11/04

Perlの上級初心者がISUCON2に行ってきた話

あーどうもどうもこんにちは、acidlemonです。

今回はタイトルにあるとおり11/3、文化の日にあったNHN Japan主催のISUCON2(いい感じにスピードアップコンテスト2)に参加してきた話です。2〜3人で構成した25チームがスコアを競うために実サーバ60台、仮想マシン120台(1チームに仮想マシン4台)を用意して行われるWebサービスのスピードアップコンテストということでこれだけの量を用意出来る主催のNHNさんマジすげぇー。こんな大規模でスピード感あふれるイベントに参加できたことはかなり貴重な経験でした。どうもありがとうございます。

1ヶ月くらい前

うちの会社にはディフェンディングチャンピオンのfujiwara組がおり、もう1チームくらい出てみたらってことで新卒の若者チームが出るような雰囲気だったのですが結局出なかったようで、中途のおっさん2人+年齢詐称気味の新卒というチームで参加することにしました。あんまり分担とかはきっちり決まっていなかったのですが3人並べてみると…

• @kenjiskywalker (劣化型@fujiwara)
• @mackee_w (劣化型@songmu)
• @acidlemon (劣化型@typester)

とまぁこんな感じになっておりfujiwara組を劣化させるとこうなるみたいなチームになっていたことに私驚きを隠せません。まぁいいや。

なおチーム名は「チームぽわわ」となっており「またぽわわか」と思われる読者の方もおられるかもしれません。確かに私はfoo, barやhogeとかの変数名の代わりにpowawaを使いますし、チャットでとぼけるときにぽわわとかぽわぽわとか言いますし、ましてや過去にはネトゲでぽわぽわっていうギルドでオンラインイベントに挑んだこともありましたが今回は@kenjiskywalkerにエントリーを任せたらチームぽわわになってたという話です。普通にkenji組とかでよかったのに。

なお、恐ろしいことにこのチームメンバーはいずれもPerl歴が6ヶ月未満で、ぼくに至ってはWebサービス作り始めて4ヶ月、ついでにPerlもちゃんとさわりはじめて4ヶ月ということでWebサービスのキャリアだけ言えばぼくが一番低かったのではないかと... いやはや恐縮です。プログラムを書くこと自体はもう10年以上のキャリアがあるため、先日typesterには「れもんちゃんはPerlの文法理解が怪しいけどコード自体はバリバリ書けるので、上級初心者ぐらいまでは行ってるし特にこちらからはもう教えることないですね」みたいな感じの謎の突き放しを食らっております。上級初心者ってなんだよ。

前日まで

そもそも前回のISUCONがあった2011年8月の時点ではWeb業界にいなかったという私ですのでとりあえず社内IRCの#powawaにディフェンディングチャンピオンを呼び出していろいろ聞いてみたりしつつレギュレーションを読んでみると前回は3分間に回った回数をスコアとする感じだったのが今回は規定回数実行までの時間を競う形式になっていることに気付きました。

ということは、たぶんGETの負荷をガンガンかけながらPOSTを規定回実行するというWebアプリになってることは容易に想像できます。NHNのサービスを見回すとそういうサービスはなかったような気がするんですが、まぁ去年はBlogだったから今年はNAVERまとめみたいなやつかなぁ...だとするとGETの嵐に耐えながら画像をアップロードしたりするのかなぁと想像していました。

結論からいうとチケット販売システムだったので事前予想の「GETの負荷をガンガンかけながらPOSTを規定回数実行する」っていうのは合ってましたね! てかレギュレーション読めばそりゃわかるか。

とりあえず前日の夜くらいまでに社内の雑談は終わりにして前日の相談を開始...する前にライバルを蹴り出します。

19:51:24 Songmu: さらば
19:51:27 Songmu: good luck
19:51:31 Songmu has left ()
 :
 :
21:59:57 acidlemon: そろそろけりまーす
22:00:52 acidlemon has kicked fujiwara (がんばりましょう)
22:01:03 acidlemon has kicked typester (スパイよろしく)

スパイはぜんぜんよろしくしてくれませんでした。

このあとRedisはまぁ使うでしょって話と、varnish使いたいと言われたけどそもそも何それって言ってぐぐったりしているうちに夜が明けていました。なお、私は24時くらいにとっとと寝ており前日の相談をほとんど読んでおりませんでしたが...

11:00〜12:00

とりあえずざっとPerlのアプリを眺めてみると、生でSQLが書いてあるのでちょっと面食らいました。PerlでMySQL叩くのDBIC経由でしかやったことないよ! でもまぁnodeやPHPでSQLを直書き(プレースホルダはもちろん使うよ)してたことはあるので読む分にはなんとかなりました。

ざっとアプリのソースとアクセスログを見てみた感想としては

• 正規化されすぎててDBひく効率が悪そうな気がする(最近売れた10件のJOIN4つくらいあるし)
• 静的ファイルをアプリが返すようになってるのでapacheで返すべき
• ORDER BY RAND()ってことは購入する席はクライアントが指定するのではなくてサーバが割り当てるのか、つまりチェッカは購入できた席についてのチェックはできないんだなぁ
• アクセスしてくるサーバは全部で6台くらいあるので並列数は高そう
• /buyのORDER BY RAND()を外してもエラーにならないもののスコアも改善されない。購入処理はネックになってない

まぁすべて感想であって何も計測していないんですけどね。この時点ではXslateのテンプレートを読んでなかったので座席に色をつけるところで4096回のループが回っていることに気付いてませんでした。

12:30

ここらへんで方針が決まります。

会場が鯖弁当の匂いに包まれたところでチームでいろいろ話をしてみて、マスターデータがそんなにでかくない、購入データも高々40000件程度にしかならないということでRedisに全部突っ込んで問題なさそうだねという結論に。マスターデータはアプリのメモリに乗っけても問題ないサイズなのでMySQLを捨ててアプリをオーバーホールしましょうということになりました。つまり、ここまでの考え方は2位だった山形組さんによく似ています。

12:38:24 acidlemon: マスターデータを全部アプリのオンメモリに載せてマスターデータDB廃止!
12:39:44 acidlemon: 購入データもRedisに乗っけてMysqlを廃止!
12:39:54 acidlemon: 心配性おじさんになってきたよ

@mackee_wがのんびり弁当食ってるのでとりあえずぼくがアプリを書き直し始めます。

13:00〜16:00

アプリを全部書き直すことにしたので、まずはマスターデータをハッシュデータにするところから。一番細かい単位はvariationが10個ということと、URLのパスがトップページ、アーティストページ、チケットページになっていることからとりあえずartistとそのID、ticketとそのID、variationとそのIDを持たせた配列をハッシュにvariationというキーで突っ込んで、artistsキーとticketsキーに参照を入れた配列を作りました。

マスターデータができたので次は購入処理だーということで /buy を書き直しました。このアプリの処理はマスターデータを引く部分と購入してデータを格納するとこに別れているので、初期データを作るところと購入処理を書いてしまえば扱うべきデータを作る部分が全部おわるので、あとは読み出し処理で必要に応じて必要なデータを追加すればOKだなーという感じですね。

まず、シートの連番割り当てが可能なのでそのほうがやりやすいだろうということで、連番割り当てで行くことに決定。ていうかやっぱ早い者勝ちでいい席がとれたほうがいいかなーと思って最前列から埋めていったほうがいいよねと作っていたときは(ユーザ目線で)考えてました。ただ、これ運用者視点だとアクセスの殺到を減らすために席の割り当てはランダムに作った方がいいですね。懇親会の時に「CMとかで時間指定でサービス開始をアナウンスしないでくれ、殺到させてサーバに負荷がかかるだけだー」という雑談を聞いたのを思い出しました。いやでもいい席になるまでキャンセルして取り直すっていうプレイができるようになるのはよくないかな...(完全に話が脱線しています)。

データの保存はもちろんRedisです。購入データと件数と00-00から割り当てはじめて今どこまで行ったかの割り当て済カーソルデータを保存しました。売れたseatの個数はvariationごと、ticketごとにキーを作って$redis->incrしまくる感じで作り、購入データはシートごとに固有のキーを作ってそこにメンバーIDをいれる感じで作ります。本来はトランザクションの必要な処理なので、Redisをmultiしてexecするというプレイが必要だったんですが、心の余裕がなかったのでそのまま垂れ流してやっています(シングルワーカー脳)。

このRedisの使い方はベストプラクティスからほど遠い使い方で、あとでtypesterに聞いたら「全座席の番号を空いてる座席として最初にSetに突っ込んで、Setから1個要素を取り出して削除するというspopコマンドがランダムに取れてくることを利用してそれをランダムに席を割り当てるルーチンとして使う」というのがRedis的な使い方だったようですね。たしかにぼくの作り方だと在庫管理的なところが非常に脆弱に感じになっている感じがします。

さて、/buyのあとにトップページである / を書き直したところで14時半くらいになってとりあえずチェック。ちゃんと手元では動いています。続いて /artist/{artist_id} を書き直し、最後に /ticket/{ticket_id} を書き直すために ticket.tx を見てびっくり。なんと座席表をレンダリングするために4096回のループが回っているではないか...

でもまぁこの時点でこれをどうにかすることに頭を使うよりもひとまずオーバーホールを終わらせないと話にならないのでそれをなんとか16時過ぎに終わらせてサーバにデプロイしはじめました。

とりあえずデプロイしてもらっている間レンダリング問題を考えていたんですが、まぁアプリ側で出来ることはないだろう、と。MySQLなしの構成にした都合上DBネックがないのでスペックの高いDBサーバでアプリを動かせばパワープレイでレンダリングできるだろうからとりあえずそれでやるしかないねと。それでもダメならアプリに来る回数を減らす(キャッシュする)しかないねという感じでした。

ちなみに、この時間並行して@kenjiskywalkerがvarnishの導入を模索しており、「2回目以降の POST /buy が来たらアプリに渡さずにキャッシュを返す」というブラフプレイをしたところ売れたチケット数が4095でFAILするという事案が発生し、周りの動揺を誘っていたようです。

15:19:26 kenjiskywalker: http://gyazo.com/8b34ac4cfa4a6ebd3b87cfc09fce2a5b
15:19:30 kenjiskywalker: uleru
15:20:43 macopy: ukeru
15:21:02 kenjiskywalker: tagomorisさんにそれエラーでしょって突っ込まれてうける
15:23:00 acidlemon: うしろから
15:23:12 acidlemon: チームぽわわ 4000とかいってますよ、なにこれって声が聞こえた
15:23:39 acidlemon: マジフロントで購入完了画面のダミーだけ出してるだけなのにひどいブラフプレイ
15:24:53 kenjiskywalker: Main Bench:seat list is not updated correctly (still "available"), variation id:7, seat id:01-20

これはひどい。

16:00〜17:00

デプロイが終わったんですがベンチマークをスタートするとベンチがいきなり止まります。エラーを見るとadminの初期化は302200じゃないとダメみたいなコードだったんですがどうがんばって見比べてもちゃんとPOST /admin は302を返してるし、その次のGET /artist/1も200を返してるのでダメっぽいところが見当たらず。これで結構時間を食ってしまったんですが、「ワーカーの数が...」と言われて私たいへんな事実に気付きました。

よく考えたらマスターデータの初期化をPOST /adminでやってたので、ワーカーが複数いたら1ワーカーしかマスターデータが初期化されない。いやーまぁそのぐらいは別にどうにかなるんですが、いろんなものをアプリのメモリ上に持っていたのでワーカーが1じゃないと動かない設計になっていました。なんというシングルワーカー脳... @mackee_wを半分遊ばせておいて3時間ずっとコード書いてたという自分も相当シングルワーカープレイでしたが、アウトプットしたものまでシングルワーカーなのはもはや笑うしかないですね。

17:00〜18:00

とりあえずStarmanのワーカー数を1にしたら無事テストがスタートし、csv吐き出しを実装してなかったのでさすがに最後にFAILしましたが1分間の走破はしたようです。でもスコアは1分で200チケット程度しかさばけてなかったので、せっかくRedisを使ってもさすがにワーカーが1じゃどうしようもないよねということでこれを修正しにかかります。

この時点でアプリが抱えていた問題は少なくとも2個ありました。ベンチマークが始まらない理由であったマスターデータの初期化は初回アクセス時にハッシュを初期化すればいいとして、もう1個の問題は「最近売れたアイテムをアプリのオンメモリにおいていた」ことでした。マルチワーカーで動かすにはこれをRedisに退避させないといけないのでそこを直す必要がありますが、一方csv吐き出しも作らなきゃならないので... ということで大変なパニックに。

じゃあ、@mackee_wにcsv吐き出しを任せる、Redisに入れるキー名はこれにする! と決めて作業開始しましたが、Redisへの入れ方がよくなくて躓いているままタイムアップ。SetじゃなくてListに入れるべきだったのと、購入データをキーごとに分けるのは(本来)ダメでハッシュをJSON化して1キーに入れるべきだったというのは終わった後にわかったことでした。

おわりに

そんなわけで、Redis力が足りなかったのと純粋なPerlコーディング力が足りずにオーバーホールに失敗してスコア無しという最低の結果に終わりましたが、アイディアとしては特別賞チームにやり方にかなり似ていただけに非常に残念。山形組との違いとしては

• シングルプロセスマルチスレッドではなくマルチワーカープロセスを目指してた
• オールオンメモリじゃなくて永続データのストアとしてredisを使ってた
• フロントにvarnishを置こうとしてた

といったあたりでしょうか。おそらくアプリ側をちゃんと書き切れたところで4096マスのtableをレンダリングするところがやはり詰まるところは予想できるので、そこをなんとかしないことにはスコアは伸びなかったと思います。

ところでこの記事を書くためにIRCのログを読み返してたんですが、前日にこういう発言がありました。

22:01:30 acidlemon: 分担: まこぴーがアプリを見る
22:01:40 acidlemon: けんじおじさんがインフラ周りをみる
22:01:51 acidlemon: ぼくはフロントまわりとかをみる

あれ、なんでオレずっとアプリのオーバーホールやってたんだろう? 素直にアプリ書くのは@mackee_wに任せればよかったか。