だらだらと思いついたこととか書くブログ

エンジニア的なネタとか備忘録とかを書いていく予定

isucon2019予選 1日目の参加記録

イントロダクション

9/17(土)にisuconに会社の同僚2名(以下 Aさん、Bさんで表記)と参戦してきました。 結果は、あえなく失敗でしたが、集まってわいわい言いながら問題に向かっていく、というのはとても楽しかったです。

また、問題も今までとは傾向の違うところがあったり、なるほどーと思わされるところがあったりと、とても楽しませていただきました。 運営の皆様、そして一緒に出場してくれた同僚の2名、どうもありがとうございました!

isucon9予選の問題

isucariという椅子を売りたい人と買いたい人をつなぐサービス UIや画像からマイクロサービスでのサーバーサイドのアプリケーションまで、すごくしっかり作り込まれていました。

同僚と振り返りで出た話でも、今までの問題と比べて改善ポイントが見つけづらかった、というのが出ていました

github.com

当日の記録メモ

AM10:00〜

会社の会議室に集合して準備。公式で10分ほど遅れるとのアナウンスがあり、おっとトラブルかー、という気持ちと、「10分で直すってすごいな。。大丈夫かな」とか考えていましたが、 本当に10分もかからず対応完了で10:10から競技開始。

早速マニュアルの確認から。 isucari...、あ、本当にメルカリで来たのか。 け、決済、、QR、、ここまで、対応しているのかと思いながら、マニュアルを眺めていました。

その間に、AさんがAlibabaCloudでインスタンスの作成。 自分はAWSとかもちゃんと触ったことなかったので、ふむふむと見させてもらいつつ自分一人だったら絶対ハマってたなぁと思ったりしていた。

無事にインスタンスが作成されてIPが共有されたので各自sshの設定をしてログイン。 その後、サーバのプロセスや確認してnginx,mysqlが動いていて初期実装でgoのアプリが動いていることを確認。

自分はそれと並行して、運用スクリプトをいじったりansibleの設定を直したりしていた。

Bさんはgoの設定やリポジトリへのpushをしたり、schemaSpyというツールでスキーマ構成を把握したり、アプリのコードを追いかけたりとしてもらっていた。 これのおかげでローカルでのコンパイルインスタンスへのデプロイも手軽に出来て効率的に進められたように思う。

AM11:00くらい?

ここらで、まずはベンチを動かしてみることに。 nginxのログ設定とmysqlのスロークエリログの設定をしてベンチを開始、だが、スロークエリが出ない。。 設定を確認してみたらスロークエリOFF、ロングクエリタイム=1になっていた(逆にしたつもりでいた)という感じで、初っ端からミス・・

気を取り直して、設定を修正して再度ベンチを実施。 インデックスちょっと張ってみるかーといった話が出てきたり、ログやコードからN+1クエリ直さないとね、という話をしたり、 categoriesあたりはメモリに載せちゃおうかという話をしたりしていた。

ここで分担しつつ作業を進めていくが、ローカルでアプリがうまく動かせず、それと並行しつつ対応。 とりあえずローカルでコンパイルして問題なければ、サーバにデプロイして確認するかーという感じなり、それぞれの担当作業に着手。

Bさんがものすごい勢いでN+1クエリを解消。あとでコミットログ見ると凄まじい発想力と実装力。。まじで神・・ 自分はcategoriesのキャッシュ化に着手。 Aさんはクエリのインデックス作成や問題のありそうなクエリや実装の調査を対応。

go力や把握力が低くて、まずなぜかMapでのキャッシュ化を試みて、時間をかけて対応したものの、全然使えないことに気づく。。マジで使えないやつ。。 その後に、構造体でちゃんと持てばいいじゃんと気づき、対応するものの、既存のクエリでは全件、取得のところしか切り替えられず、 他のところはフィルタリングなどがうまくいかずつまる・・

そんなこんなしているうちに、BさんがN+1を解消した実装でベンチを回すが、あれ、、あんまり負荷が上がっていかない?という話が出てきた。 Aさんがマニュアルをチェックしてくれて、ここでキャンペーンの設定があることに気づく。

ここの変更と自分の中途半端な実装を混ぜて一旦デプロイして再度、ベンチを回してみることに。 まずはレベル4で、当然のように落ちる。。

スロークエリを見てみてもあまりそれらしいものは出てこないのでDB問題ではなさそう。 nginxのログから新着一覧の取得あたりが遅そう?という話になり、とりあえずそのあたりも含めてがっつりコードを追ってみることに。 自分はAPIのコードや呼び出し部分もしかして改善必要?と思って見てみたり、/buyが怪しそうということで、処理の流れを見ていたりした。

PM0:00~2:00くらい

確かこの辺りで、カテゴリのparent_id引いているところ決めてうちで固定値で何とかなりそうでは、という話がAさんから出て対応してもらったり、改善できそうなクエリを直してもらったりした。 途中、/buyのuserのロックいらないのでは?と思い、FOR UPDATE外してみたり、不要なロックしている箇所がなさそうか見ていじってみたりしたが改善が見られず・・ 思い返してみると、この辺でnetdataやプロファイルとか入れられればよかったかも。

途中nginxが1コアしかつかっていない事に気づいて設定を修正してもみるが、改善は見られず。

PM2:00くらい

いったん昼飯を挟みつつ、goのnet/httpが同一の最大接続数のデフォルト設定が2であることを発見。 32まで増やしてみるが変わらず・・いま思えばもっと前で止まっているので当然・・

お昼食べつつ、みんなでマニュアルを見返して、あー、ちゃんと更新や登録は即座に反映しないとって明記されているね。って話をしたり、 カテゴリ新着一覧はやたら「即座に」って書いているのに、新着一覧がないのは即座に返さなくていいってこと?インデックスページなのでキャッシュ使って改善した方がいいのでは?どうしようかー という話が出て、主眼は新着一覧ページをどう改善するかに変わってきた

PM3:00くらい

ここでAさんが高い商品を買ってもらえるようにすればスコア出るのでは?クエリのORDER変えてみては?という話から、それやってみようとなり、対応してもらうものの、どうやらここはいじってていけない的なエラーが発生。 この辺り、AさんとBさんのお二人が色々トライ&エラーで対応してくれていて、自分はAPI呼び出し部分なんとか出来ないかなー、もしくはロック減らせないか、とか考えいていたが何も出てこず。。

pprofでプロファイル取ってみたのは、この辺だったはず。 やっぱり新着一覧がって話とログイン周り時間かかっているねって話になり、ログイン周り見てみるが怪しげなところが見つけられず。 プロファイルでログイン周りのロジックで負荷が高そうというのは出ていたものの、ハッシュ化のところで、ん?ってなったが、ここはいじれないかーと思い、手を出さなかったのは、後悔ポイントの一つ。せめてcostいじっておくべきだったよ・・

この辺でnetdataも入れてみる。ポートが開いておらず試行錯誤。AlibabaCloudのコンソールでポートを開けてもらいやっと見れる状態に。 この辺でハマる自分のレベルの低さを痛感。。

トライ&エラーでログをみながら、ロックってログが出てるなんだろ?/buyだね、という話になり、同僚がロックエラーが出ているIDをログに出してみようと提案。 早速、対応してもらいベンチ回してみると同じ商品に対する購入処理が集中して、落ちていることが判明。 神エンジニアが排他制御を入れてくれ、ベンチを回してみると、5,000くらい?(記憶が怪しい)がスコアが出てくれるようになり、光が見えてきた。 その後、数回、ベンチを回してみてちゃんとスコアが出るようになったことを確認しつつ、同僚二人が諸々、修正を実施してくれて5,000くらい?で一時的に30位以内(たしか、そのくらい)に入った。

PM4:00

CPUがボトルネックであることはわかっていたので、よし、これを複数台構成にすれば、もっと改善するのでは?ということで、この辺りか複数台構成への変更に着手開始。 排他制御はこのままだと複数台構成にできないということで、redisを使って排他制御をする事に。これを同僚がサクッと実装、マジで神。

redis自体は自分が用意していたansibleで入れるつもりがエラー連発。 結局、同僚が見つけてくれた対応方法を実施したり、同僚が対応入れてくれたりで解決。

ここから自分はnginxの複数台構成の設定に着手。

PM5:00

間違えてグローバルIPで接続しようとしたりするなどショボいミスをしつつもとりあえず設定完了して、ベンチ開始。 ちゃんと振り分けができていることは確認できたが、どうにもすぐ落ちる。 ここで、画像が複数台対応してないじゃん、と気づき/uploadの場合、自サーバのみを見るように変更。 しかし、それでもまだ落ちるし、IPエラーみたいなログも出るし、時間もないしで調査。 ここで、/sellも画像、関係していると気づき対応しtベンチを回す。これが確かPM6:00前くらい。

ギリギリで間に合ったかと思ったがFAILし、結局、このまま解決せずタイムアップ。

タイムアップ後

ログを確認していると、なぜかhttp301が出ている事に気づく、これに気づきnginxのlocation設定が間違っている可能性が浮上。 手元の環境で設定を直して、画面から確認してみるとエラーになるところが解消。"/sell"とすべきところを"/sell/"にしていたせいという、痛恨のミス。 これは本当に申し訳ないことをしてしまった・・ マジでちゃんとnginx勉強しとけよ自分、と切に、切に思いました。

p.s 帰宅後、同僚が入れてくれた修正などを見て、あの短時間でここまでの修正を、、これをFAILにしてしまって本当に申し訳ない気持ちでいっぱいになりました

全体振り返りなど

  • ansibleやログローテスクリプトなどを事前に用意していたが、色々ツメが甘くログローテスクリプト以外はあんまり役に立たなかった気がする
  • ansibleはubuntuでの設定ファイルの構成に合わせておくべきだった(isucon8のcentosの構成に合わせていたため勉強不足もありハマった)
  • goでのロジックがさらっと書けなかったのは、単純に力不足と練習不足だったのでここはちゃんと勉強しておく
  • newrelicなどマイクロサービスでのボトルネックなどを可視化出来るようなツールにも慣れておく
  • nginxとmysqlは基本なので定期的に勉強しておく

来年も機会があれば参加したいです。なので、それまでの今回の反省点を少しでもつぶせるようにしたい