旧gaaamiiのブログ

間違ったことを書いている時があります。コメントやTwitter、ブコメなどでご指摘ください

ISUCON9(予選)の振り返り

今年も、 id:karur4n と二人で、くもキャストチームとしてISUCON9に参戦しました。楽しかったですが、今年も予選突破できず悔しい。

スコアの発表を見ると、

2,600  くもキャスト

でした。

isucon.net

例年、我々のような弱小チームに語れることなどない...という気持ちであまり真面目に振り返っていなかったのですが、我々のような弱小でも弱小なりに楽しめるんだぞというのが(まだ出たことない人などに)伝わればいいかなと思い、振り返りを書いてみました。

※ISUCONってなに?という方はこちらをご覧ください。

qiita.com

お題

毎年楽しみなお題ですが、今年はIsucariでした。椅子を販売できるサイトらしい。

f:id:shgam:20190908003340p:plain

開始時間の変更

ポータルサイトに不具合があったようで、10::00 -> 10:10に変更されました。我々は、Discordで通話してたんですがマイクの入力がイヤホンからになっていたのでMacの内蔵マイクにしたりとかそういうことをしていました。

Alibaba Cloudコンソールでイメージ展開

迅速に問題は解消されて、予告通り10:10に開始しました。

今回は、予選マニュアルの通りにAlibaba Cloudのコンソールでサーバーにイメージを展開するところからのスタートでした。前回までのISUCONは特にサーバーのセットアップが必要なく、ポータルサイトに入るとチームに与えられたサーバーのIPが表示されているので、そこにsshで入って作業を開始するという流れでした。

設定・起動を終え、サーバー名とGlobal IPとPrivate IPをポータルサイトに登録、Alibaba Cloudのコンソール画面でログインのために作成/設定しておいた鍵を共有、ローカルの/etc/hostsを編集して起動したIsucariの画面を確認するなどしました(10:30)。

f:id:shgam:20190908002040p:plain

ソースコードをプライベートリポジトリへ

id:karur4n に、Githubにプライベートリポジトリを作成、ソースコードを置いて、Contributorに追加してもらいました(10:48)。

使う参考実装はNode(TS)とSinatra(Ruby)どっちがいいかね〜みたいな感じだったので、その判断するために実装読んでもらっていたりもしました。TSでいきましょうとなって、TSでいくことに。

最初のボトルネック探し

また、alpを使ってボトルネックを探すのも、 id:karur4n がやってくれていました(11:18)。

f:id:shgam:20190907222211p:plain

2台構成にする

マニュアルを読むと、3台まで使って良いことがわかったので、ウェブ用とDB用に分けようということで、同じ手順でもう1台サーバーをたてました。この新しいサーバーのプライベートIPを環境変数MYSQL_HOSTにすればええやろと思ったのですが、ベンチを走らせたところ、どうも接続できていない(11:23)。

セキュリティグループを疑って、3306ポートを開放するルールを追加(11:41)。

しかしうまくいかない...。ここでVPCの仕組み自体の理解が浅いために、あれ、プライベートIPの指定じゃだめ?なんか追加で設定必要?などなどの寄り道をします。寄り道をしたあげく、ping叩いてプライベートIPでちゃんと通信できとるやんというのに気付き、疑念が晴れる(12:01)。

通信はできるけどmysqlクライアントからの接続だけできんぞという問題の切り分けがようやくできたので、mysqlの設定を疑い、無事、MySQLbind-address オプションが127.0.0.1になっていたのを外すことができました(12:55)。

N+1潰し

僕が2台構成の設定をしている間に、id:karur4n/users/transactions.json のN+1潰しにあたりました。

ベンチ実行 -> failed.

2台構成、N+1潰しが入ったところでベンチを実行。failしました(12:57)。修正に時間かかりそうだったので、一旦ふたりとも昼飯を食うべく休憩に入ります。1時間くらい昼休憩にしてカレーを食べました(14:00)。

ISUCONサーバー環境git設定

そこまでソースの変更をscpでアップロードしてしていたのを、サーバー環境で git pull できるようにするべく、設定をしました。サーバー環境で ssh-keygenしたやつをGithubの設定画面で設定(14:06)。

git clone したけど、publicディレクトリがちゃんとコピーできてなかったりなんやかんやで時間がたっていたが、そんなこんなの間にfailedの修正もid:karur4n が終わらせてくれていました(14:50)。

ベンチ実行 -> 1210

ベンチがパスして、スコア5000だ!!!!やった!!!と喜んでいたら、見ていたのはJob idの方で、実際は1210イスコインでした(14:55ごろ)。

1台構成にしてベンチ実行 -> 900くらい

2台構成にした意味あるんか?という疑問があったので、環境変数変えてlocalhostMySQLにつなぐように戻して再度ベンチ実行。900くらいになったので、よしじゃあ2台にしとこうというやりとりをしました(14:55ごろ)。

ts-node -> nodeへの変更

ExecStart = /home/isucon/local/node/bin/node /home/isucon/isucari/webapp/nodejs/node_modules/.bin/ts-node index.ts になっていたのを、ExecStart = /home/isucon/local/node/bin/node /home/isucon/isucari/webapp/nodejs/node_modules/.bin/ts-node index.js ビルドしたやつを実行するように変更(14:58ごろ)。TypeScriptだとビルドあるからということでそうなったんですが、よく考えるとts-nodeも結局ビルドしてからプロセス立ち上げるのでこれはやらなくてもよかった...?

campaign値の変更

今回のお題はIsucariという架空の椅子専門フリマサイトであり、以下のような仕様になっていました。

POST /initialize のレスポンスにて、イスコイン還元キャンペーンの「還元率の設定」を返すことができます。この還元率によりユーザが増減します。 有効な値は 0 以上 4 以下の整数で 0 の場合はキャンペーン機能が無効になります。

ここまで(スコアだと1210)ではこれをずっと0にしたままだったので、値を変えてベンチを走らせた結果、以下のようになりました(15:16)。

f:id:shgam:20190907233535p:plain

外部サービスのURL取得にDBから引っ張るのやめようとする

アプリケーションから外部APIを叩いている箇所があり、そのAPIのURLがDBに入っていて、それを毎回SQLで取得していました。テーブルには外部APIのURLがこのように保存されていました。

mysql> select * from configs \G;
*************************** 1. row ***************************
name: payment_service_url
 val: https://payment26.isucon9q.catatsuy.org
*************************** 2. row ***************************
name: shipment_service_url
 val: https://shipment26.isucon9q.catatsuy.org
2 rows in set (0.01 sec)

じゃあこれを文字列としてソースコードに書いちゃっていいんじゃないか、と思ってそうしたものの、ベンチがfailするようになってしまいました(15:26)。

GET /users/transactions.json: got response status code 500; expected 200,
POST /buy: got response status code 500; expected 400 (item_id: 50002),
POST /buy: got response status code 500; expected 200 (item_id: 50001)

よくマニュアルを読むベンチマーク走行時にこの値は書き換わる とのこと。残念でした。

外部サービスのURLをキャッシュしようとする

せめてこの値をキャッシュしようとしました。lru-cache というパッケージを追加し、取得の関数でキャッシュを作り、以降はそれを見るように変更しました(16:30)。しかしスコアに改善は見られず...。

getItem

/itesm/:id.json に対応するgetItemという関数がだいぶクエリを発行していたので、これもJOINすればN+1潰せる系かと思い、手を出しました(16:53)。

が、結局悩んでいる間にその修正は間に合わなそうになります(17:21)。

API リクエストが直列になってるの並列にしようとする

id:karu4n の方では、/buy で行われているAPI リクエストを並列にしようとしていました(16:55)。こちらはコミットして変更を反映するものの、スコアに影響は出ませんでした(17:14)。

なぜかfailする

時間も時間なので、そろそろ大きい改善を諦めて調整に入ろうとします。が、ベンチを走らせるとfailedになっていまいました(17:24)。しかしfailedにならず普通にpassするときもあり、よくわからんなとなります。外部サービスのURLをキャッシュするやつがなにかよくない...?と推測してその変更を外して走らせたりしたところ、安定してpassするようになったので外して提出しようと思いますが、最後の方でキャッシュをsetする位置を変えた(/initializeが叩かれたときにキャッシュするようにした)やつで試したところ、passするようだったのでその変更入れました。

ウェブサーバーのmysqlを停止

なんかもう大きなことできないなと思ってつつtopを眺めていると、ときどきmysqldが上に上がってくることがあって、DBサーバーでもないのにこいついらんやろと思ったので、おもむろにウェブサーバーの方で sudo /etc/init.d/mysql stopしときました(18:00ごろ)。

nginxいじる

最後の最後でもう時間もないですが、ぺろっと設定入れて改善するものがあれば入れたいという感じで、 id:karur4n がNginxからgzip圧縮して返すような設定を入れてくれていました。スコアが伸びなかったのでもとに戻してフィニッシュ(18:10)。

感想など

以上は、当日終わったあとにやったことを振り返ってまとめただけのものなので、僕らの勘違いが含まれている可能性もあります。後日講評と解説が公開されたら、それを読みながら再度振り返りをしたいと思います。

こうやってやっていたことを振り返ると、1つ1つ検証せず複数修正を入れて一気にベンチ走らせてスコア伸びたり落ちたりして一喜一憂という場面もあったので、相変わらず雑だったなという反省もあります。

また個人的には、ソースコードを開けば明らかに無駄に発生してそうなDBへの問い合わせは見つかるんですが、それをスピーディに直してベンチ走らせてスコア伸ばすということができておらず、すごい純粋に力不足だったな〜と感じました。そこらへん毎年 id:karur4n のほうができているので、足を引っ張ってしまって申し訳ない。

一方で、一昨年、昨年も出てるので慣れてきたのもあり、やろうとしていたことはそんなに悪くなかったような気がします。マニュアル読んでまずサーバー環境を2台に増やすとか、修正をちゃんとgitで管理/反映するとか、alpでやばそうなところを見つけてそこを直すとか、failしたらログを見て原因を見つける、というようなことはできていたので、そこらへんは例年に比べてバタバタ感が減っていて良かったと思いました。

なにより楽しかったので、また来年も参加してみようと思います。一緒に出てくれた id:karur4n と運営の方々に感謝です。 お疲れさまでした 🍣