フレクトのクラウドblog re:newal

http://blog.flect.co.jp/cloud/からさらに引っ越しています

トップ > 多量のリクエストを送信するには

多量のリクエストを送信するには

エンジニアの佐藤です。こんにちは。今回は、とある技術検証を通じて筆者が経験したドタバタについて書かせていただきたいと思います。

きっかけ

先月だったか、「毎秒X万のHTTPSリクエストを遅延なく処理するための実装要件を教えてほしい。」という要望が筆者に寄せられました。世間のメジャーエンドポイントがどのくらいのアクセスを想定しているのかわかりませんが、X万というのは筆者には未経験のゾーンで、試してみるしかないと思いました。

ちなみにその時点で筆者が過去に経験していた、最も多数のリクエストを処理するエンドポイントは、Heroku(https://www.heroku.com/)で実装しました。難しいことはしていません。Dynoをぐぐぐと増やしていけば、あっさり目標要件を満たしました。今回もHerokuでやったらどうかと答えたのですが、AWS指定とのこと。筆者はロードバランサとECSで検証サイトを作成しました。これを外から多量のリクエストを発信して検証すればいいと思いました。

心配事

とは言え、そんなに素直に行かないだろうなとも思っていました。心配したのは以下の2点です。

  1. そもそも、狙ったリクエスト数を発信できるか。
  2. エンドツーエンドで計測できるか。

一般的にサーバーサイドは、どんな実装であれ、可能な限り高い効率でリクエストを処理することに最適化されています。効率の悪いサーバーなど、誰も欲しがらないからです。しかしクライアント側もそうとは限りません。ブラウザであれアプリであれ、1箇所から多量にリクエストが発信される実用上のシナリオというのは存在しません。(もしそうなら、設計がまちがっているのです。)需要が無いということは、いざやろうとすると、仕様だけ見ていてはわからない落とし穴がある可能性があるということです。

もう一つの「計測できるか」ですが、単純にサーバーサイドでカウントして「毎秒X万回達成！」とやったとしても、それだけでは期待したユーザー体験を検証したことにはなりません。ひょっとしたらその瞬間、個々のリクエストはあり得ないぐらい待たされているかもしれないからです。となるとクライアント側にもそれなりの計測機能を実装して数字を収集しなければなりません。すぐにビッグデータ的スケールになってしまいます。

備え

多数のリクエストを送信するクライアント群をどうやって構成するか、また、個々のリクエストが要求を満たすことをどうやって計測するか。筆者のアイディアは以下のようなものでした。

  1. 非同期的にリクエストする。
  2. 時間的に分散させる。
  3. 計測結果を一定時間メモリにプールし、まとめてレポートする。

1. 非同期的にリクエストする

今回はHTTPSリクエストでしたので、リクエストを送信し、レスポンスを検証して完了です。つまり受信待機があるわけです。受信待機があるということは、直列的にリクエスト処理をつなげては目標を達成することが難しいということでしょう。仮にレスポンス検証まで0.01秒だったら、毎秒100回で頭打ちです。「スレッド処理」というささやきが聞こえてきますが、やたらに多数のスレッドを上げるわけにも行きません。スレッド切り替えの負荷が相対的に高まり、これまた頭打ちになるからです。なのでプログラム処理上は、レスポンスを待機することなくリクエストを投げられる仕様にしなければなりません。

筆者が今回使ったのは、Apache HTTP ComponentsのHttpAsyncClient(https://hc.apache.org/httpcomponents-asyncclient-4.1.x/index.html)でした。このライブラリではIOリアクターと呼ばれるスレッドプールでリクエストを処理します。ここへ、処理負荷とネットワーク遅延を勘案し、今回は論理コアの10倍のスレッドを設定します。また、タイムアウトも忘れずに設定します。(拙稿「アウトバウンドリクエストはAWS NAT Gatewayに握りつぶされていた」http://cloud.flect.co.jp/entry/2018/08/24/130542 参照)

IOReactorConfig ioReactorConfig = IOReactorConfig.custom()
    .setIoThreadCount(Runtime.getRuntime().availableProcessors() * 10)
    .setConnectTimeout(5 * 1000)
    .setSoTimeout(5 * 1000)
    .build();
PoolingNHttpClientConnectionManager connManager =
    new PoolingNHttpClientConnectionManager(ioReactor, ...
CloseableHttpAsyncClient httpClient = HttpAsyncClients.custom()
            .setConnectionManager(connManager)
            .build();

// 上記の初期化が終わったhttpClientに対し、以下繰り返す。
HttpGet hg = new HttpGet(url);
// サーバーの負荷試験なので、キャッシュは無効に
hg.setHeader("Cache-Control", "no-cache");
httpClient.execute(hg, new FutureCallback<HttpResponse>(){
    public void completed(HttpResponse hRes) {
        try {
            // ここへ完了処理を書く
        }
        catch (Exception ex) {...}
    } // end of completed

これでレスポンスを待たずに、設定個数のリクエストを連続的に送信できる仕掛けができました。

2. 時間的に分散させる

非同期化によっていくらでも詰め込めるからといって、一気に多数のリクエストを送信するのは良くないと思います。現実世界ではX万台のクライアントをエミュレートしているのですから、揃うわけがないのです。今回は0.1秒ごとに、全体の1/10のリクエストを送信し、さらにこのインスタンスを複数個起動することにしました。

3. 計測結果を一定時間メモリにプールし、まとめてレポートする

次に計測ですが、基本的な数値として、何回リクエストして、いくつレスポンスを受け取ったのか、また、遅延時間(注：ここでの「遅延時間」は、いわゆるレスポンスタイムではなく、レスポンスボディに含まれる時刻とレスポンス時点のクライアント時刻の差分。込み入った話になりますので、詳細は割愛します。)の平均はどれだけだったのかを、5秒に1回計測します。また、別途全てのリクエストの遅延時間を記録し、これも5秒ごとにgzip圧縮してGoogle Cloud Storageに保存しました。

いざテストしてみると。。。

一通りプログラムが動作したところで、いよいよお待ちかねのパフォーマンステストです。起動パラメターを変化させて毎秒あたりのリクエストを増やしていきました。ところが、リクエスト回数が毎秒20回を超えたあたりで予想外の事象が発生しました。

リクエスト送信個数は増えるのに、レスポンス受信個数は増えなくなったのです。

何かのボトルネックにあたったようでした。他のメトリクスも確認したところ、「CPU利用率は低いまま」「メモリ使用量がわずかずつ増えている」の2点が確認されました。サーバー側はどうかというと、依然として涼しい顔。つまり受け取ったリクエストは楽勝で返していました。これらを総合すると、 クライアント側で、何らかの理由で送信リクエストが実際にネットワークデータ送信されることなく積み上がっている、と考えられます。 いったいなぜこういうことになってしまったのでしょうか。

方々、疑う

筆者が最初に考えたのは、「インスタンスあたりの時間あたりの送信パケット上限に到達したのでは？」ということでした。冒頭に書いた通り、一つのインスタンスから一つのエンドポイントへ毎秒20回HTTPリクエストが送信されるなど、普通は無いわけです。強いて言うなら、DOSアタックなどの悪事ということになります。何らかの予防線があってもおかしくありません。また、過去にはホスティング業者も認識していなかった制約を踏んだ記憶もあります。(拙稿「AWS EC2 "悪い" EIPにご用心」http://blog.flect.co.jp/cloud/2015/11/aws-ec2-eip-c3c5.html)こういう暗黙の制約があってもおかしくありません。

それならばと、インスタンス数を50まで増やしてみました。すると合計リクエスト回数は1,000まで上昇したものの、やはりそこで頭打ちとなりました。予防線の存在を確信した筆者でしたが、目標リクエスト数X万のためにはいったいどれだけのインスタンスが要ることかと、半分諦めの心境でした。

GCPでも同じ上限に

しかし、、、いくらググっても、アウトバウンドリクエストのインスタンスあたりの上限というマニュアルも、ブログも、出てきません。さらに、筆者がかつてUDPプロトコルで似たような実験をした時の記憶から考えると、低すぎるリミットに思えました。

筆者は思い切って、クライアントの実装環境をGCPへと変えてみました。(GCPを選んだ理由は特になく、使い慣れていただけです。)すると、、、やはりインスタンスあたり毎秒20リクエストで頭打ちでした。いくら何でも、2つの環境でぴったり同じというのはおかしいような気がします。

原因はライブラリのリミット

次に筆者が疑ったのは、使用したライブラリに設定された制限です。冒頭に書いた通り、サーバー側であればパフォーマンスは高度に最適化されている一方、クライアントから大量リクエストするシナリオは世間的には稀。何らかの足枷があるのではないかと思ったのです。結果として、これが原因でした。

たどり着いた以下のAapache HTTP Componentsオフィシャルページには、次のように書かれていました。 https://hc.apache.org/httpcomponents-client-ga/tutorial/html/connmgmt.html#d5e393

Per default this implementation will create no more than 2 concurrent connections per given route and no more 20 connections in total.

それならばと以下のように設定すると、リクエスト数が頭打ちになる現象は解消されました。

PoolingNHttpClientConnectionManager connManager =
    new PoolingNHttpClientConnectionManager(ioReactor, ...
connManager.setMaxTotal(Integer.MAX_VALUE);
connManager.setDefaultMaxPerRoute(Integer.MAX_VALUE);

これにて無事、目標とする毎秒X万件のHTTPSリクエストが実行でき、必要となるサーバー要件が確認されました。

本当に正しく多数のリクエストを送信していたのか

前述の通り、今回の検証では全てのリクエストについて遅延時間を計測しています。毎秒X万リクエストの全てですから、検証時間中のリクエストの合計数はかなりの数です。それらの遅延時間の分布はどうなっているのでしょうか。Google Cloud Storageに保存されている記録をBigQueryにインポートして調べてみましょう。詳細は割愛しますが、前述の通りここでいう遅延時間とは、レスポンス直後のシステム時刻とレスポンスボディに書かれた時刻の差分のことで、もしクライアントサイドからのリクエスト時刻の分布が時間的に偏りなく一様ならば、遅延時間も0秒から3秒まで均一な分布になると予想されていました。

予備調査によると遅延時間の最小値は50ミリ秒、最大値は3650ミリ秒でした。そこで遅延時間を0 ~ 100, 100 ~ 200, ..., 3600 ~ 3700のスロットで分け、それぞれについてスロット内での平均と標準偏差を計算してみました。

結果は下記のグラフの通り、両エッジのわずかなサンプルを除くと分布には何の偏りも見られませんでした。スロットの大きさを10ミリ秒にもしてみましたが、傾向は同じでした。

f:id:masashi-sato-flect:20190430123935p:plain
遅延時間の分布

検証用のクライアントプログラムは、目論見通り、時間的に一様に、かつ緻密に、リクエストを発信してくれたようです。

最後までお読みくださり、ありがとうございました。