APIサーバーでApacheベンチを使用して非常に簡単なベンチマークを実行しようとしています.Webサーバーの負荷テストには理想的なツールではないことはわかっていますが、それは重要ではありません.
いくつかのサーバーといくつかの VM (これらのサーバーでホストされています) があります。それらはすべて、nginx、uwsgi、cherrypy webapp の同じスタックを実行しています。新しいサーバー (VM なし) で apachebench を実行すると、結果は次のようになります。
Server Software: CherryPy/3.2.2
Server Hostname: 10.0.2.4
Server Port: 5000
Document Path: /api/v4/ping
Document Length: 245 bytes
Concurrency Level: 1
Time taken for tests: 10.100 seconds
Complete requests: 1000
Failed requests: 0
Write errors: 0
Total transferred: 397000 bytes
HTML transferred: 245000 bytes
Requests per second: 99.01 [#/sec] (mean)
Time per request: 10.100 [ms] (mean)
Time per request: 10.100 [ms] (mean, across all concurrent requests)
Transfer rate: 38.38 [Kbytes/sec] received
Connection Times (ms)
min mean[+/-sd] median max
Connect: 1 4 54.7 1 1002
Processing: 3 6 2.0 6 34
Waiting: 3 6 2.0 6 34
Total: 4 10 54.8 7 1008
Percentage of the requests served within a certain time (ms)
50% 7
66% 8
75% 8
80% 8
90% 9
95% 9
98% 11
99% 12
100% 1008 (longest request)
ここで奇妙なのは、ご覧のとおり、ほとんどのリクエストが 12 ミリ秒以内に処理されることです。しかし、一部のリクエストには 10 倍以上の時間がかかっています。どうやら、問題は「接続」フェーズにあるようです。
他のサーバーまたは VM にクエリを実行する任意のサーバーまたは VM から、この効果を確実に再現できます。ただし、localhost に対するクエリは常に高速です。
また、スロー リクエストは均一に分散されているように見えます。ab (同時実行設定 1) で 50 リクエストしか実行していない場合でも、スロー リクエストがいくつか発生します (ただし、数回の試行が必要な場合もあります)。
問題をさらに特定するために、まったく同じ動作を示すnginxのhello worldページに対するベンチマークだけを知っています(したがって、これは私たちのアプリではありません)。
この問題に最初に気付いたとき、膨大な数の 'TIME_WAIT' 接続にも気付きました。いくつかの sysctl フラグを微調整してみました。TIME_WAIT はかなり少なくなりましたが、問題は解決しません。
あらゆる種類のsysctl設定を試しましたが、役に立ちませんでした。
すべてのサーバーは、Intel プロセッサを搭載した適度に新しいマシンであり、すべて Ubuntu サーバーを実行しますが、バージョンが異なります: 10.10、12.10、および 13.04。
完全を期すために、2 つの Google Compute Engine VM で nginx のフロントページに対して同じベンチマークを実行しようとしましたが、同じ動作は表示されません。
情報が不足している場合は、喜んで投稿を修正します:)。
編集:
クロックを ntpdate と同期した後、ホスト 3 からホスト 4 へのソケットを開き、再び閉じる Python スクリプトを実行しました。プロセスに 0.5 秒以上かかった場合は、正確な時間枠が記録されます。両方のサーバーで tcpdump を実行しているときにこれを実行しました。これは出力の一部です。ある時点で、いくつかのパケットを転送するのに約 1 秒かかることに注意してください。問題は、これらの結果をどのように解釈すればよいか、私にはよくわからないということです。
ホスト 3:
13:24:59.591046 IP (tos 0x0, ttl 64, id 17736, offset 0, flags [DF], proto TCP (6), length 60)
sm-host-3.45573 > sm-host-4.5000: Flags [S], cksum 0x3b59 (incorrect -> 0x69fa), seq 2690430222, win 14480, options [mss 1460,sackOK,TS val 406581318 ecr 90980708,nop,wscale 7], length 0
13:24:59.591110 IP (tos 0x0, ttl 60, id 2866, offset 0, flags [DF], proto TCP (6), length 52)
sm-host-4.5000 > sm-host-3.45572: Flags [F.], cksum 0x4d59 (correct), seq 1, ack 2, win 114, options [nop,nop,TS val 90980709 ecr 406581318], length 0
13:24:59.591127 IP (tos 0x0, ttl 64, id 30162, offset 0, flags [DF], proto TCP (6), length 52)
sm-host-3.45572 > sm-host-4.5000: Flags [.], cksum 0x3b51 (incorrect -> 0x4d59), seq 2, ack 2, win 114, options [nop,nop,TS val 406581318 ecr 90980709], length 0
13:25:00.588453 IP (tos 0x0, ttl 64, id 17737, offset 0, flags [DF], proto TCP (6), length 60)
sm-host-3.45573 > sm-host-4.5000: Flags [S], cksum 0x3b59 (incorrect -> 0x6900), seq 2690430222, win 14480, options [mss 1460,sackOK,TS val 406581568 ecr 90980708,nop,wscale 7], length 0
13:25:00.588766 IP (tos 0x0, ttl 60, id 0, offset 0, flags [DF], proto TCP (6), length 60)
sm-host-4.5000 > sm-host-3.45573: Flags [S.], cksum 0x4168 (correct), seq 2011803549, ack 2690430223, win 14480, options [mss 1460,sackOK,TS val 90980958 ecr 406581318,nop,wscale 7], length 0
13:25:00.588814 IP (tos 0x0, ttl 64, id 17738, offset 0, flags [DF], proto TCP (6), length 52)
sm-host-3.45573 > sm-host-4.5000: Flags [.], cksum 0x3b51 (incorrect -> 0xa758), seq 1, ack 1, win 114, options [nop,nop,TS val 406581568 ecr 90980958], length 0
13:25:00.588821 IP (tos 0x0, ttl 60, id 0, offset 0, flags [DF], proto TCP (6), length 60)
sm-host-4.5000 > sm-host-3.45573: Flags [S.], cksum 0x4168 (correct), seq 2011803549, ack 2690430223, win 14480, options [mss 1460,sackOK,TS val 90980958 ecr 406581318,nop,wscale 7], length 0
Host-4 (ほぼ同じ時間枠):
13:24:59.587624 IP (tos 0x0, ttl 60, id 11, offset 0, flags [DF], proto TCP (6), length 52)
sm-host-3.45569 > sm-host-4.5000: Flags [.], cksum 0x54c4 (correct), seq 2, ack 2, win 114, options [nop,nop,TS val 406581318 ecr 90980708], length 0
13:24:59.587630 IP (tos 0x0, ttl 60, id 30162, offset 0, flags [DF], proto TCP (6), length 52)
sm-host-3.45572 > sm-host-4.5000: Flags [.], cksum 0x4d59 (correct), seq 2, ack 2, win 114, options [nop,nop,TS val 406581318 ecr 90980709], length 0
13:25:00.585005 IP (tos 0x0, ttl 60, id 17736, offset 0, flags [DF], proto TCP (6), length 60)
sm-host-3.45573 > sm-host-4.5000: Flags [S], cksum 0x69fa (correct), seq 2690430222, win 14480, options [mss 1460,sackOK,TS val 406581318 ecr 90980708,nop,wscale 7], length 0
13:25:00.585026 IP (tos 0x0, ttl 64, id 0, offset 0, flags [DF], proto TCP (6), length 60)
sm-host-4.5000 > sm-host-3.45573: Flags [S.], cksum 0x4168 (correct), seq 2011803549, ack 2690430223, win 14480, options [mss 1460,sackOK,TS val 90980958 ecr 406581318,nop,wscale 7], length 0
13:25:00.585032 IP (tos 0x0, ttl 60, id 17737, offset 0, flags [DF], proto TCP (6), length 60)
sm-host-3.45573 > sm-host-4.5000: Flags [S], cksum 0x6900 (correct), seq 2690430222, win 14480, options [mss 1460,sackOK,TS val 406581568 ecr 90980708,nop,wscale 7], length 0
13:25:00.585039 IP (tos 0x0, ttl 64, id 0, offset 0, flags [DF], proto TCP (6), length 60)
sm-host-4.5000 > sm-host-3.45573: Flags [S.], cksum 0x4168 (correct), seq 2011803549, ack 2690430223, win 14480, options [mss 1460,sackOK,TS val 90980958 ecr 406581318,nop,wscale 7], length 0
13:25:00.585331 IP (tos 0x0, ttl 60, id 17738, offset 0, flags [DF], proto TCP (6), length 52)
sm-host-3.45573 > sm-host-4.5000: Flags [.], cksum 0xa758 (correct), seq 1, ack 1, win 114, options [nop,nop,TS val 406581568 ecr 90980958], length 0