とてもとても悲しいので、とりあえずやったことと言い訳を書いて気を紛らわせることにする。 敗北した身でグダグダ言うのが格好悪いことは百も承知だが、人間には魂の救済が必要であることをご理解いただきたい。
序盤〜方針決定
最初パスワードのコピペミス等でサーバーからガンガンBANされて、そもそもログインできなくなる。これで10分から20分ぐらい無駄にした気がする。 テザリングにIPを切り替えたり、他のノードから入ったりして、何とか公開鍵でログインできる環境を整える。
適当にベンチ流してスコアを取る前に、nginxのログ設定や構成を確認しalpを使って集計できる準備を整えた。デフォルト実装とRuby実装でベンチを流す。その裏で実装を一通り読む。
ざっくり図を書いて、相談。とにかく/iconsを何とかしないと話が進まないので、静的ファイルとして書き出してCache-Controlだよね、までは即決。
モリスさんの発案により全てのノードにPOSTが来た時点でPUTリクエストを転送し、WebDAVで全てのノードにファイルを書き出して、後はnginxでサーブすればいいという方針で行こうということになる。この決定は後になって思うと危険な判断ではあった。
そこに多少の準備がかかるので、その間にSQLやアプリケーションの実装周りで明らかに非効率な所を潰すことにした。俺はRubyコードの全般を直し、やんちゃさんにDB周りのインデックスやSQLを見てもらった。
中盤
/iconsの静的ファイル化が完了し、nginxにより直接サーブが可能になる。この時点でスコアが3万前後。画像ファイルのキャッシュとかは一切してないので、周りのスコアとかを見ても、まあこんなもんだろうと思う。
ここで一つ目の壁にぶち当たる。nginxにexpiresを追加してCache-Controlが動作する様にしたのだが、スコアが伸びない。この時点でベンチマーカーが一体何であるのかを考えることになる。
ここで我々のチームは、ベンチマーカーがCDNかキャッシュプロキシの様なものからのリクエストである、ということをすぐに想定できなかった。少なくとも自分はブラウザかAPIのクライアントの様なものしかすぐに想定できなかった。
ただ、ネットワークがサチっていることはメトリックから明らかであり、周りのチームとのスコア差を考えると、304かCache-Controlによるキャッシュしか方法が無いだろうというのは分かっていた。
その間に裏でワーカーの数やらキャッシュを調整し、スコアを45000ぐらいまで伸ばす。やったのは大体以下の様な感じ。
- チャンネルは作ったら変更されないので、起動時に全部Redisのハッシュにストア
- チャンネルが保持しているメッセージ数もRedisにハッシュでストアしメッセージが入ったらhincrbyする
- db.prepareを全てmysql2-cs-bindのxqueryに置き換える
- RedisとMySQLのコネクションをコネクションプール化し起動時に接続済みにしておく
- nginxとpumaのプロセス数を2にして、スレッド数やwocker_connection数を調整
- カーネルのsomaxconnが128で少なかったので数を増やす
- SQLのクエリワークロードに合わせてインデックスを張る (そんなにやることはなかった)
- N+1をJOINに変えて潰す
ちなみに、pubsubとか使えそうかなとは考えたが、3台でそれやってもなあというのと、短時間で実装するのが無理っぽかったので止めた。
しばらく悩んだ後にモリスさんが気付いてCache-Controlにpublicを突っ込んだらスコアが倍ぐらいになり、どうもCDNっぽいという話が出てきた。
終盤
Cache-Controlがある程度効いているのだが、やっぱりネットワークがサチってスコアが10万辺りで止まる。304を返して何とかする方法があるはずだ、と思ってパケットキャプチャをしてクライアントの動きを見たのだが、どうもIf-Modified-SinceやらIf-None-Matchが見当たらなかった。(本当は少数ログに残ってた可能性はあるが気付かなかった)
で、どうやって304で返すかで色々と迷走することになる。この時にベンチマークの仕様について確信が持てなかったため、肝心なことに気付けなかった。EtagやLast-Modifiedが入ってて、何故ネットワークが先にサチるのかが分からなかった。
その間も裏でアプリケーションのキャッシュ可能な場所を探したり、nginxのopen_file_cacheやらTCP周りのカーネルチューニングをやって11万ぐらいは安定して出る様になっていた。
しかし、最終的に最後まで304でレスポンスを返すことができず、アプリケーションやDBにかかっている負荷は5割に満たないまま時間切れとなった。
アプリケーションサーバー側に来ていたトラフィックは遅くても100msec、POSTでも200msecぐらいで、半数以上は数十msecで返せていたのでウェブアプリケーションとしては充分な水準だったとは思う。
最終的な敗因
終わった後の情報からの推測によると、一番致命的だったのは静的なファイルを返す様にした際に各ノードに初期画像を撒いたのだが、その時にファイルの更新時間を揃えるのを忘れたという点だと思われる。
ブラウザだったら、Cache-Controlで一旦ローカルにキャッシュされてしまえば、If-Modified-Sinceが多少異なっていても、そもそもサーバーにアクセスしないので、何も問題は無い。
しかし、後から推測するにベンチマーカーはCDNからのリクエストを想定しているものだと思われる。なのでレスポンスヘッダの状態をちゃんとチェックしてキャッシュの削除をしていたんじゃないだろうか。
もし、ファイルの更新時間が異なる同一ファイルが各ノードにあった場合、あるノードから戻ってきたLast-Modifiedが自分がリクエストしているIf-Modified-Sinceより前になる場合、というのが発生する。ここの値が一致しないとnginxはデフォルトでは普通にコンテンツを返すはず。
ここで、一つ気付いていながら確信が持てず試さなかったのが、nginxのif_modified_since beforeである。もしサーバーが持っているファイルの更新時間より未来のIf-Modified-Sinceが送られてきても、nginxは304を返すことができる設定がある。恐らくうちの場合はこれでほとんどのコンテンツに対して304を返すことができた可能性がある。
一方でEtagもレスポンスヘッダに含まれており、ファイルの更新時刻が異なる場合それも異なってしまうので、最終的にはnginxの実装に依る様な気もする。どっちにしても駄目だったかもしれないが、そこまでの知識はない。
何にせよ、上記の問題によって、初期画像に対するリクエストのほとんどが304を返すことができなかった。
そのためネットワークがサチって負荷が上がりきらずスコアが伸びなかった。3台分の帯域をフルに使ってWeb,DB共にリソースの半分以上の余力を残して11万点だったので、304がまともに返せていれば、20万後半から30万ぐらいは行けたんじゃないかとは思うのだが、完全に別の世界線の話になってしまったので、我々には本当のところは分からない……。
ちなみに、WebDAVでファイルを複製して各ノードに配置したことが危険だったのは、ファイルを書き込んだタイミングが1秒以上ズレると上記と同じ問題が発生するところだった。
そもそもファイルの更新時間という点に気付いていなかったので、ここも致命的だったのかどうかは定かではない。ローカルネットワークは帯域もレイテンシも全然余裕であり、書き込みが終わるまでに全体で0.1秒以下ぐらいしかかかってないので、よっぽど運が悪くない限りはそうそうズレることは無いと思っていたのだが、ぶっちゃけ各ノードの時計が秒単位で一致してたかというと、はなはだ怪しい。恐らくこれも影響があったのではないだろうか。
言い訳
実際、適当にいくつかの画像にアクセスした限りでは複数のノードでもEtagもLast-Modifiedも一致していたのも気付けなかった点の一つではある。
しかし、今回私にとってとてもハードルが高かったのは恐らくCDNというものを想定したベンチマーカーだったこと、そしてその挙動特性を知る経験が無かったことだ。
一応、数年Webに関する仕事をしてきて、今CTOなんぞをやっている訳だが、CDNが必要になったことなど今迄一度も無かった。ずっとB2Bで仕事をしていたのでPOSTの数が多いとかやたら複雑だとか一回のGETでめちゃめちゃ複雑な計算結果を返さなきゃいけないことは一杯あるのだが、GETはそんなに世界のあちこちから来ないし、1分に数件とか処理できれば余裕な仕事がほとんどだった。
というわけで、CDN等は遥か遠い世界の話だった。一応メルカリの事件とかは知ってて、ああやべえなCache-Control周り、とかは思ってはいたのだが、所詮対岸の火事であるという認識で、必要になった時に調べられる様に覚えておこう、ぐらいのものだった。
この辺りのハイトラフィックWebに対する地力の無さが敗因だったと言える。
一方で、運が悪かったというか問題の特性によって敗北した点もあると思っている。いくらいきなり無茶なパフォーマンス改善が降ってきたとして、そのサービスがCDNを使っているかどうかと、どういうCDNを使っているかの情報すら無いままサーバーサイドの改善にかかることはまずあり得ないだろうと思う。(まあ、この業界は想像の斜め下とか余裕で越えてくるので分からんけど)
またCDNの導入がされててS3やGCSに類するオブジェクトストレージが使えないというのも、イマイチ考えにくい。今回、ローカルのファイルシステムから画像をサーブした結果ファイルの更新時刻の罠にハマってしまったが、仕事で関わったサービスで画像をサーブするのにローカルのファイルシステムを使ったことは多分一度もなかったと思う。CDNを使うぐらいまで成長したサービスが、そういう環境が無いってのはそんなに多くはないだろう。(オンプレで開発してきて場当たり的な改善とCDNでギリギリ何とかしながら成長してしまったサービスとかならあり得ないとも言えない気はする)
というわけで、今回の問題は本当に世界レベルからのアクセスがあるB2CのハイトラフィックWebと向き合ってきた人間がやはり有利だったと思う。まあ、それがWebサービスの現実であり地力の違いである、と言われればグウの音も出ないのだが……。あー辛い……。
今回の我々のチームは全員がB2B業であり、ミドルウェアやら集計SQLやら分散処理システムやらワークフローを見るのがメインみたいな人間ばかりで、これは完全に最近のWebの現実というものに立ち向かえていなかったと言える。CDN使っててS3の無い世界なんて知らねえよww
まあ、私の様な人間はクラウドのぬるま湯に漬かって生きているのだなあ、ということを実感した1日ではあった。
今回得た教訓は、CDNの仕様は厳密に確認しなければならないということと、ローカルファイルシステムからコンテンツをサーブする時はファイルの更新時間を揃えなければいけない、ということだ。まあ後者の知見はよっぽどでないと使う機会は無さそうだが。(未来のISUCONとかぐらいっぽい)
いやー、S3って本当便利ですよね。
