Posted at

テストで実際に見たウェブサーバの「遅い」状態とは

More than 1 year has passed since last update.

さくらインターネットのアドベントカレンダー25日目が空いてしまったので、ウェブサーバのチューンナップについて書くことにしました。

私は今日からお休みですが、さくらインターネットは年末年始も休まずに働いていますので、ご安心ください。

年末年始のシフトに入ってくれた社員の皆さんに感謝です。

ということで、責任を持って空いたカレンダーの埋め合わせをさせて頂きますw


サーバのレスポンスが遅いとは?

なんだかサーバのレスポンスが悪いなぁってことは皆さんも体験されたことあると思います。

原因としては大きく分けて2種類あり、ひとつはApacheやnginxなどのウェブサーバソフトウェアの設定において同時に処理できる上限に達しているケースと、サーバ自体の負荷が高まっているケースです。

前者はApacheでいうとMaxClientsを調整することで対応できますが、そもそもサーバの性能以上にMaxClientsを設定してしまうと、逆にレスポンスが悪くなります。

後者はまさしくそういう状態であり、CPUやディスクI/O、メモリなどのリソースが不足することにより、レスポンスが悪くなります。


Apacheに負荷をかけてみる

今回は、さくらのクラウドで1GBのメモリーを搭載したインスタンスを立ち上げてテストしてみます。

テストに際しては、CentOS 7.4にApacheをインストールして行います。

今回のテストでは、200MBのメモリーを消費するプログラムを用意して、これを複数同時に呼び出すことでメモリー不足の状態を作ります。

これにより、メモリー不足でスワップアウトする状態となり、I/O負荷が高まる状態をテストすることが出来ます。

# yum install httpd -y

# systemctl enable httpd.service
# systemctl start httpd.service

このあと、ウェブサーバに負荷をかけるためのプログラムをダウンロードします。

# git clone git@github.com:kunihirotanaka/loadcgi.git

# cd loadcgi
# make
# cp loadcgi /var/www/cgi-bin/
# curl http://localhost/cgi-bin/loadcgi
OK

OKと出れば成功です。このプログラムはメモリを200MB確保して終了するという動作をします。

CGIとして呼び出すことにより、1リクエストあたり最大200MBのメモリ空間が消費されます。


dstatを使ったモニタリング

それでは、大量のアクセスをウェブサーバに送信してみますが、その前に負荷テスト中のサーバ負荷をモニタリングするために、dstatを実行します。

dstatは、vmstatで出てくるCPUやI/Oの情報だけでなく、ロードアベレージやネットワーク帯域などをまとめて見られるコマンドであり、インストールされていない場合にはvmstatを使ってもかまいません。

dstatのインストールは、CentOSならyumで、Ubuntuの場合はapt-getで行えます。


CentOSの場合

# yum install dstat -y



Ubuntuの場合

$ sudo apt-get install dstat


それでは実行します。

なおコマンドラインオプションは以下のとおりです。

オプション
オプションの意味

-c
CPUを表示

-m
メモリを表示

-s
スワップの状態を表示

-d
ディスクを表示

-l
ロードアベレージを表示

-n
ネットワーク状態を表示

-r
I/O状態を表示

実行すると、vmstatと同じように状態を表示し続けます。


dstat

# dstat -cmsdlnr

----total-cpu-usage---- ------memory-usage----- ----swap--- -dsk/total- ---load-avg--- -net/total- --io/total-
usr sys idl wai hiq siq| used buff cach free| used free| read writ| 1m 5m 15m | recv send| read writ
0 0 100 0 0 0| 196M 34.8M 479M 282M| 0 4096M|8746B 8920B| 0 0.01 0.05| 0 0 |0.32 0.25
0 0 100 0 0 0| 196M 34.8M 479M 282M| 0 4096M| 0 0 | 0 0.01 0.05| 154B 150B| 0 0

このサーバの場合には、メモリーのうち196MBが使用中、34.8MBがバッファキャッシュ、478MBがページキャッシュ、284MBが空きということが分かります。

スワップは全く使われておらず、4GBまるまる空いています。


リクエストを行う

それでは、すべての準備が整いましたので、abコマンドを使ってウェブサーバにリクエストを送出してみましょう。

先ほど実行したdstatは、そのまま実行し続けてください。

abコマンドに -n 1000 というオプションをつけて、1000リクエストを送出してみます。

# ab -n 1000 http://localhost/cgi-bin/loadcgi

~略~
Concurrency Level: 1
Time taken for tests: 87.709 seconds
Complete requests: 1000
Failed requests: 0
Write errors: 0
Total transferred: 150121 bytes
HTML transferred: 3000 bytes
Requests per second: 11.40 [#/sec] (mean)
Time per request: 87.709 [ms] (mean)
Time per request: 87.709 [ms] (mean, across all concurrent requests)
Transfer rate: 1.67 [Kbytes/sec] received

Connection Times (ms)
min mean[+/-sd] median max
Connect: 0 0 0.0 0 0
Processing: 73 88 5.8 87 123
Waiting: 70 82 5.7 81 121
Total: 73 88 5.8 87 123

1000リクエストの処理完了まで87.7秒かかりました。

秒間11.4回のリクエストに答えることができ、応答時間の中央値は87ミリ秒だったことが分かります。

このときのdstatの状況はどうでしょうか。

# dstat -cmsdlnr

----total-cpu-usage---- ------memory-usage----- ----swap--- -dsk/total- ---load-avg--- -net/total- --io/total-
usr sys idl wai hiq siq| used buff cach free| used free| read writ| 1m 5m 15m | recv send| read writ
0 0 100 0 0 0| 196M 34.9M 479M 282M| 0 4096M|8712B 8887B| 0 0.01 0.05| 0 0 |0.32 0.24
0 0 100 0 0 0| 196M 34.9M 479M 282M| 0 4096M| 0 0 | 0 0.01 0.05| 334B 150B| 0 0
0 0 100 0 0 0| 196M 34.9M 479M 282M| 0 4096M| 0 0 | 0 0.01 0.05| 480B 1238B| 0 0
0 1 99 0 0 0| 196M 34.9M 479M 282M| 0 4096M| 0 0 | 0 0.01 0.05| 756B 1272B| 0 0
20 50 29 0 0 1| 307M 34.9M 479M 171M| 0 4096M| 212k 0 | 0 0.01 0.05| 484B 750B|2.00 0
27 73 0 0 0 0| 199M 34.9M 479M 279M| 0 4096M| 0 0 | 0 0.01 0.05| 240B 374B| 0 0
29 71 0 0 0 0| 346M 34.9M 479M 132M| 0 4096M| 0 0 | 0 0.01 0.05| 334B 534B| 0 0
29 71 0 0 0 0| 329M 34.9M 479M 150M| 0 4096M| 0 0 | 0 0.01 0.05| 796B 1240B| 0 0
30 70 0 0 0 0| 227M 34.9M 479M 251M| 0 4096M| 0 0 | 0 0.01 0.05| 420B 102B| 0 0
31 69 0 0 0 0| 373M 34.9M 479M 105M| 0 4096M| 0 16k|0.08 0.03 0.05| 334B 518B| 0 2.00
~略~
34 66 0 0 0 0| 289M 35.0M 480M 189M| 0 4096M| 0 0 |1.29 0.39 0.17| 154B 534B| 0 0
20 33 46 0 0 0| 201M 35.0M 480M 277M| 0 4096M| 0 0 |1.29 0.39 0.17|2222B 5342B| 0 0
3 1 96 0 0 0| 201M 35.0M 480M 277M| 0 4096M| 0 0 |1.29 0.39 0.17| 664B 652B| 0 0
0 0 100 0 0 0| 202M 35.0M 480M 276M| 0 4096M| 0 0 |1.18 0.38 0.17|8854B 584B| 0 0

だいたい、4行目くらいからリクエストが開始され、usrとsysで示されるCPU負荷が高まり、CPU使用率が100%になっていることが分かります。

またusedで示されるメモリの使用量は、200MB弱と300MB代後半を行ったり来たりしており、200MB占有するCGIが呼び出されていることが示唆されます。

とはいえ、実メモリ内で収まっているため、swapについては変動がなく、ディスクI/Oについても特に負荷が高まっている様子はありません。


並列してリクエストを行う

次に、並列して複数のリクエストを送出してみます。

このテストサーバは1GBのメモリを搭載しており、buff/cach/freeを足して800MB弱しかありませんので、200MB占有するCGIを4~5個実行するだけで、メモリがあふれるはずです。

ということで、その倍にあたる10並列でリクエストを送るとどうなるかをテストしてみましょう。

先ほどと同じように1000個のリクエストを送出しますが、-c 10 で10並列にしてみます。

# ab -n 1000 -c 10 http://localhost/cgi-bin/loadcgi

~略~
Concurrency Level: 10
Time taken for tests: 671.529 seconds
Complete requests: 1000
Failed requests: 0
Write errors: 0
Total transferred: 165093 bytes
HTML transferred: 3000 bytes
Requests per second: 1.49 [#/sec] (mean)
Time per request: 6715.294 [ms] (mean)
Time per request: 671.529 [ms] (mean, across all concurrent requests)
Transfer rate: 0.24 [Kbytes/sec] received

Connection Times (ms)
min mean[+/-sd] median max
Connect: 0 1 4.0 0 45
Processing: 87 6710 782.5 6714 10654
Waiting: 78 6691 802.8 6708 10565
Total: 87 6711 782.6 6721 10654

1000リクエストの処理完了まで671.5秒かかりました。

さっきが87.7秒だったので、7~8倍近くの時間がかかっています。

応答時間の中央値は、先ほどが87ミリ秒だったのに対して6721ミリ秒となり、応答時間は80倍ちかくかかる結果となりました。

dstatの結果を見ても顕著です。

# dstat -cmsdlnr

----total-cpu-usage---- ------memory-usage----- ----swap--- -dsk/total- ---load-avg--- -net/total- --io/total-
usr sys idl wai hiq siq| used buff cach free| used free| read writ| 1m 5m 15m | recv send| read writ
0 0 100 0 0 0| 199M 35.1M 480M 279M| 0 4096M|8534B 8727B| 0 0.02 0.06| 0 0 |0.31 0.24
0 0 100 0 0 0| 199M 35.1M 480M 279M| 0 4096M| 0 0 | 0 0.02 0.06| 394B 150B| 0 0
5 11 83 0 0 1| 350M 35.1M 480M 127M| 0 4096M| 0 0 | 0 0.02 0.06| 570B 1906B| 0 0
5 59 0 36 0 0| 916M 420k 28.6M 47.7M| 69M 4027M| 616k 65M| 0 0.02 0.06| 334B 374B|13.0 727
1 25 0 74 0 0| 932M 80.0k 10.8M 49.4M| 282M 3814M|2576k 252M| 0 0.02 0.06| 574B 518B|65.0 806
1 26 0 73 0 0| 927M 80.0k 12.6M 52.7M| 436M 3660M| 668k 103M| 0 0.02 0.06| 454B 550B|32.0 496
3 31 0 66 0 0| 931M 80.0k 13.2M 47.8M| 534M 3562M|1544k 112M| 0 0.02 0.06| 334B 550B|51.0 573
1 31 0 68 0 0| 926M 216k 13.9M 51.9M| 720M 3376M|2604k 174M|1.04 0.23 0.13| 360B 550B| 118 863
9 53 0 37 0 1| 728M 224k 14.0M 251M| 77M 4019M|6920k 50M|1.04 0.23 0.13| 420B 550B| 235 282
4 42 0 54 0 0| 933M 228k 11.7M 47.8M| 318M 3778M|1044k 200M|1.04 0.23 0.13| 848B 550B|44.0 878
3 35 0 62 0 0| 933M 216k 11.6M 47.7M| 470M 3626M| 180k 170M|1.04 0.23 0.13| 522B 1304B|7.00 601
2 27 0 71 0 0| 933M 216k 11.6M 47.8M| 541M 3555M| 264k 92M|1.04 0.23 0.13| 394B 102B|13.0 434
5 45 0 50 0 0| 931M 200k 11.4M 49.8M| 433M 3663M|2764k 118M|1.92 0.43 0.20| 394B 550B|89.0 651
13 79 0 8 0 0| 936M 112k 8740k 47.7M| 220M 3876M|5324k 222M|1.92 0.43 0.20| 300B 550B| 233 778
1 27 0 72 0 0| 936M 112k 8900k 47.7M| 286M 3810M| 684k 59M|1.92 0.43 0.20| 154B 550B|21.0 323
1 30 0 68 0 1| 936M 112k 8864k 47.7M| 453M 3643M| 284k 181M|1.92 0.43 0.20| 334B 550B|16.0 706
2 38 0 59 0 1| 935M 532k 9036k 47.7M| 651M 3445M|1072k 196M|1.92 0.43 0.20| 334B 550B| 155 841
2 35 0 63 0 0| 935M 672k 9344k 47.7M| 662M 3434M| 648k 120M|2.65 0.60 0.25| 274B 550B|20.0 706
6 60 0 34 0 0| 342M 632k 8792k 641M| 99M 3997M|2960k 74M|2.65 0.60 0.25| 180B 550B| 153 272
8 58 0 33 0 0| 932M 632k 8780k 50.9M| 320M 3776M| 996k 250M|2.65 0.60 0.25| 488B 550B|81.0 845
1 25 0 74 0 0| 933M 632k 8792k 49.8M| 363M 3733M| 124k 3904k|2.65 0.60 0.25| 0 550B|4.00 16.0
1 28 0 71 0 0| 936M 632k 8752k 47.7M| 600M 3496M| 432k 239M|2.65 0.60 0.25| 574B 550B|15.0 846
2 28 0 70 0 0| 936M 632k 8780k 47.6M| 662M 3434M| 448k 154M|3.48 0.81 0.32| 274B 534B|21.0 470
2 38 0 60 0 0| 936M 592k 8204k 47.6M| 566M 3530M|1384k 118M|3.48 0.81 0.32| 120B 550B|61.0 477
6 48 0 46 0 1| 357M 176k 8232k 627M| 106M 3990M|6276k 70M|3.48 0.81 0.32| 60B 550B| 339 259
3 33 0 64 0 0| 298M 112k 8088k 686M| 178M 3918M| 12M 825M|4.32 1.03 0.40|2210B 1158B| 653 3424 missed 4 ticks
~略~
0 25 0 75 0 0| 933M 80.0k 11.5M 47.8M| 630M 3466M| 320k 118M|16.0 13.9 7.84| 706B 832B|30.0 529
1 29 0 70 0 0| 933M 80.0k 11.6M 47.7M| 738M 3358M| 208k 107M|16.0 13.9 7.84| 454B 66B|13.0 457
5 39 0 56 0 0| 934M 88.0k 10.7M 47.8M| 694M 3402M|1440k 90M|16.0 13.9 7.84| 120B 550B|81.0 438
14 66 0 20 0 0| 925M 220k 16.8M 50.8M| 107M 3989M| 24M 942M|15.9 13.9 7.92|2869B 1669B|1622 4003
3 35 0 62 0 0|96.9M 368k 12.9M 882M| 106M 3990M|5444k 0 |15.9 13.9 7.92| 0 54B| 116 0 missed 6 ticks
13 28 44 16 0 0| 102M 696k 27.6M 862M| 103M 3993M| 22M 0 |15.9 13.9 7.92| 634B 2852B| 845 0

4行目くらいからリクエストが開始されていますが、usedが跳ね上がり、buffやcachで示されるキャッシュもほとんど開放されてしまいました。

そして、ディスクI/Oが大幅に上昇し、スワップの使用量がどんどん増えていることがわかります。

途中でdstatコマンドがmissed 4 ticksと出力しており、モニタリングすらままならない高負荷状態になっています。

なお、気をつけなければならないのは、idlが0になってCPU使用率が100%のように見えますが、実際にはusrとsysを足した数がCPU使用率であり、だいたい30%~60%程度しか使われていないことです。

このdstatの結果は、明らかにメモリー不足を示していますが、ロードアベレージ16近くまで上がっているということだけでCPUふやさなきゃという判断にならないように注意しましょう。

このあたりは、「I/O負荷の正確な状況はiowaitでは分かりません - さくらインターネット Advent Calendar 2017 9日目」にて、私が書いた記事でも解説しています。


同時受付可能な値を少なくする

さて、今回はApacheの設定がデフォルトなので、MaxClientsが大きな値になっており、10並列くらいであればすべて受け付けてしまいます。

その結果、サーバのメモリー搭載量を超えて受け付けてしまい、結果としてスワップアウトを引き起こしてしまったため、レスポンスが大幅に悪化しました。

ウェブサーバソフトウェアによって設定方法は異なりますが、Apacheの場合であればMaxClientsで変更が出来ます。

CentOS 7.Xの場合には/etc/httpd/conf.d/mpm.confというファイルを作成し、そこにMaxClientsを記述して再起動すれば変更完了です。


/etc/httpd/conf.d/mpm.conf

MaxClients 4


今回のサーバでは、200MB使用するCGIが4個までであれば実メモリに載りますので、4という数値を設定しました。

変更後、CentOS 7.Xの場合には、systemctlコマンドで設定ファイルが再読み込みされます。

# systemctl restart httpd.service

# ps aux | grep httpd
root 1241 0.0 0.4 226240 4692 ? Ss 12月28 0:03 /usr/sbin/httpd -DFOREGROUND
apache 19068 0.0 0.2 226240 2764 ? S 10:08 0:00 /usr/sbin/httpd -DFOREGROUND
apache 19069 0.0 0.2 226240 2764 ? S 10:08 0:00 /usr/sbin/httpd -DFOREGROUND
apache 19070 0.0 0.2 226240 2768 ? S 10:08 0:00 /usr/sbin/httpd -DFOREGROUND
apache 19071 0.0 0.2 226240 2768 ? S 10:08 0:00 /usr/sbin/httpd -DFOREGROUND

再読み込み後に、apache権限のプロセスが4個起動していれば再読み込みが完了です。


テスト前にスワップをリセットする

それではテストを、といいたいところなのですが、先ほどサーバに大きな負荷をかけたことで、いまだにスワップアウトしたままのプロセスがいます。

これだとレスポンスが悪化するので、スワップをoff/onしてリセットします。

# swapoff -a && swapon -a

ちなみに、dstatを眺めていると、リセットされる様子が分かります。

# dstat -cmsdlnr

----total-cpu-usage---- ------memory-usage----- ----swap--- -dsk/total- ---load-avg--- -net/total- --io/total-
usr sys idl wai hiq siq| used buff cach free| used free| read writ| 1m 5m 15m | recv send| read writ
0 0 100 0 0 0| 104M 4664k 48.0M 836M| 90M 4006M| 0 0 | 0 0.03 1.05| 574B 150B| 0 0
0 3 62 35 0 0| 105M 4664k 51.3M 832M| 86M 4010M|3848k 0 | 0 0.03 1.05| 934B 1826B| 962 0
1 11 0 88 0 0| 114M 4664k 51.9M 822M| 74M 4022M| 10M 0 |0.08 0.04 1.05| 180B 150B|2624 0
0 6 0 94 0 0| 124M 4664k 51.9M 812M| 63M 4033M| 10M 0 |0.08 0.04 1.05| 574B 534B|2568 0
0 11 0 89 0 0| 133M 4664k 51.9M 803M| 52M 4044M|9016k 0 |0.08 0.04 1.05| 334B 534B|2254 0
0 10 0 90 0 0| 143M 4664k 51.9M 793M| 36M 4060M| 10M 0 |0.08 0.04 1.05| 300B 534B|2624 0
0 10 0 90 0 0| 152M 4664k 53.2M 782M| 23M 4073M| 10M 0 |0.08 0.04 1.05| 488B 534B|2637 0
1 4 55 39 0 1| 139M 5868k 54.1M 794M| 0 4096M|6404k 0 |0.08 0.04 1.04| 420B 1068B|1130 0
0 0 100 0 0 0| 139M 5868k 54.1M 794M| 0 4096M| 0 0 |0.08 0.04 1.04| 240B 198B| 0 0

swapoffすることで、dskのreadが跳ね上がるとともに、swapのusedが減って行っています。

なお、buffとcachで示されるキャッシュについても、このテストを行う前に比べると大きく減っていますが、ファイルアクセスを頻繁にするプログラムではないので、今回は置いておきましょう。

余談ですが、MySQLなどファイルにランダムアクセスするアプリケーションの場合、データベースファイルのいろんな場所を読み込むたびにいろんな場所がキャッシュされますが、最初にファイル全体をcatもしくはddして読み込んでおけば全体がキャッシュされるので、起動直後や高負荷後のパフォーマンスの悪さを解消できるという裏技もあります。

このあたりは、「いまさら聞けないLinuxとメモリの基礎&vmstatの詳しい使い方 - さくらインターネット Advent Calendar 2016 25日目」にて、私が書いた記事でも解説しています。


MaxClientsを少なくした状態で並列してリクエストを行う

ではサーバ能力を勘案してApacheを調整しましたので、先ほどと同じく10並列でリクエストを送出してみます。

# ab -n 1000 -c 10 http://localhost/cgi-bin/loadcgi

~略~
Concurrency Level: 10
Time taken for tests: 91.399 seconds
Complete requests: 1000
Failed requests: 0
Write errors: 0
Total transferred: 150007 bytes
HTML transferred: 3000 bytes
Requests per second: 10.94 [#/sec] (mean)
Time per request: 913.990 [ms] (mean)
Time per request: 91.399 [ms] (mean, across all concurrent requests)
Transfer rate: 1.60 [Kbytes/sec] received

Connection Times (ms)
min mean[+/-sd] median max
Connect: 0 0 0.0 0 0
Processing: 98 909 87.6 900 1171
Waiting: 89 903 87.3 893 1161
Total: 98 909 87.6 900 1171

どうでしょうか。

並列ではない最初のテストよりはレスポンスが悪いものの、MaxClientsを減らす前の並列したリクエストを送った際よりも、明らかにスループットが改善しています。

dstatの結果を見ても、swapが上昇している様子は見受けられません。

# dstat -cmsdlnr

----total-cpu-usage---- ------memory-usage----- ----swap--- -dsk/total- ---load-avg--- -net/total- --io/total-
usr sys idl wai hiq siq| used buff cach free| used free| read writ| 1m 5m 15m | recv send| read writ
0 1 98 1 0 0| 138M 5956k 54.2M 794M| 0 4096M| 44k 1865k| 0 0.01 0.38| 0 0 |2.52 8.00
0 0 100 0 0 0| 138M 5956k 54.2M 794M| 0 4096M| 0 0 | 0 0.01 0.38| 514B 150B| 0 0
0 0 100 0 0 0| 138M 5956k 54.2M 794M| 0 4096M| 0 0 | 0 0.01 0.38| 514B 1254B| 0 0
15 74 11 0 0 0| 142M 5960k 54.2M 791M| 0 4096M|4096B 0 | 0 0.01 0.38| 510B 1186B|1.00 0
17 83 0 0 0 0| 608M 3940k 32.1M 349M| 0 4096M| 336k 4096B| 0 0.01 0.38| 394B 374B|3.00 1.00
18 82 0 0 0 0| 317M 3940k 32.2M 639M| 0 4096M| 0 0 | 0 0.01 0.38| 412B 534B| 0 0
19 81 0 0 0 0| 572M 3940k 33.1M 384M| 0 4096M| 996k 0 |0.40 0.10 0.40| 330B 1052B|22.0 0
17 83 0 0 0 0| 501M 3940k 33.1M 454M| 0 4096M|4096B 0 |0.40 0.10 0.40| 454B 684B|1.00 0
16 84 0 0 0 0| 518M 3948k 33.1M 438M| 0 4096M| 0 12k|0.40 0.10 0.40| 574B 854B| 0 2.00
18 82 0 0 0 0| 498M 3948k 33.1M 457M| 0 4096M| 0 0 |0.40 0.10 0.40| 300B 534B| 0 0
17 83 0 0 0 0| 541M 3948k 33.1M 415M| 0 4096M| 0 0 |0.40 0.10 0.40| 308B 534B| 0 0
16 84 0 0 0 0| 443M 3948k 33.1M 513M| 0 4096M| 0 0 |0.69 0.16 0.42| 180B 518B| 0 0


アプリケーション側で同時アクセスを抑制する

ここまでは、MaxClientsを調整して同時に受け付けられる数を抑制しました。

しかしながら、これでは負荷のあまり高くない静的リクエストまで抑制されてしまいます。

今回のloadcgiでは、同時アクセスを抑制する機能を搭載しており、これにより200MBのメモリを確保するプロセスをひとつに限定することが出来ます。

具体的には、loadcgi内でメモリ確保する前にflockすることにより、同時にメモリを確保しないようにしています。

loadcgiのあとにlockとパスを付加すると、PATH_INFOを読み出してロックします。

ApacheのMaxClientsを256に戻してabを実行してみましょう。


/etc/httpd/conf.d/mpm.conf

MaxClients 256


# systemctl restart httpd.service

# ab -n 1000 -c 10 http://localhost/cgi-bin/loadcgi/lock
Concurrency Level: 10
Time taken for tests: 90.698 seconds
Complete requests: 1000
Failed requests: 0
Write errors: 0
Total transferred: 155083 bytes
HTML transferred: 8000 bytes
Requests per second: 11.03 [#/sec] (mean)
Time per request: 906.976 [ms] (mean)
Time per request: 90.698 [ms] (mean, across all concurrent requests)
Transfer rate: 1.67 [Kbytes/sec] received

Connection Times (ms)
min mean[+/-sd] median max
Connect: 0 0 0.0 0 1
Processing: 109 902 62.0 902 1024
Waiting: 97 886 62.0 886 1006
Total: 109 902 62.0 902 1024

結果、MaxClientsを低く抑えたときと同じように、レスポンスは若干悪いものの、スループットはほとんど悪化していません。

実行されているCGIを見れば、一つのプロセスを除いてS状態でメモリを確保せずに待っていることが分かりますが、同時にメモリを確保しないために、CGIが並列して負荷に直結していないことが分かります。

apache   28271  3.0  8.3 208968 85328 ?        R    12:10   0:00 /var/www/cgi-bin/loadcgi

apache 28272 0.0 0.0 4164 344 ? S 12:10 0:00 /var/www/cgi-bin/loadcgi
apache 28273 0.0 0.0 4164 344 ? S 12:10 0:00 /var/www/cgi-bin/loadcgi
apache 28274 0.0 0.0 4164 344 ? S 12:10 0:00 /var/www/cgi-bin/loadcgi
apache 28275 0.0 0.0 4164 348 ? S 12:10 0:00 /var/www/cgi-bin/loadcgi
apache 28276 0.0 0.0 4164 348 ? S 12:10 0:00 /var/www/cgi-bin/loadcgi
apache 28277 0.0 0.0 4164 344 ? S 12:10 0:00 /var/www/cgi-bin/loadcgi
apache 28278 0.0 0.0 4164 344 ? S 12:10 0:00 /var/www/cgi-bin/loadcgi
apache 28279 0.0 0.0 4164 344 ? S 12:10 0:00 /var/www/cgi-bin/loadcgi
apache 28280 0.0 0.0 4164 348 ? S 12:10 0:00 /var/www/cgi-bin/loadcgi

dstatを見ても、CPUこそ使い切っていますが、swapは特に使っていません。

# dstat -cmsdlnr

----total-cpu-usage---- ------memory-usage----- ----swap--- -dsk/total- ---load-avg--- -net/total- --io/total-
usr sys idl wai hiq siq| used buff cach free| used free| read writ| 1m 5m 15m | recv send| read writ
0 1 97 1 0 0| 113M 2844k 66.4M 810M| 0 4096M| 42k 1694k|0.21 0.53 0.50| 0 0 |2.37 7.29
0 0 100 0 0 0| 113M 2844k 66.4M 810M| 0 4096M| 0 0 |0.19 0.52 0.50| 274B 150B| 0 0
9 31 60 0 0 0| 300M 2844k 66.4M 623M| 0 4096M| 0 0 |0.19 0.52 0.50| 424B 1922B| 0 0
21 79 0 0 0 0| 255M 2844k 66.4M 668M| 0 4096M| 0 0 |0.19 0.52 0.50| 306B 892B| 0 0
21 79 0 0 0 0| 172M 2844k 66.4M 751M| 0 4096M| 0 0 |0.19 0.52 0.50| 454B 94B| 0 0
20 80 0 0 0 0| 249M 2844k 66.4M 674M| 0 4096M| 0 0 |0.19 0.52 0.50| 394B 518B| 0 0
22 78 0 0 0 0| 229M 2844k 66.4M 694M| 0 4096M| 0 0 |0.33 0.54 0.51| 394B 518B| 0 0


さいごに

それでは、今回のテストの結果を比較してみましょう。

並列度
1
10
(MaxClients変更前)
10
(MaxClients=4)
10
lockあり

time
87.7秒
671.5秒
91.4秒
90.7秒

r/s
11.40回
1.49回
10.94回
11.03回

min
73ms
87ms
98ms
109ms

mean
88ms
6711ms
909ms
902ms

median
87ms
6721ms
900ms
902ms

max
123ms
10654ms
1171ms
1024ms

timeで示した1000回のリクエストが完了するまでにかかる時間で言うと、MaxClientsを大きく設定しすぎた状態において圧倒的にレスポンスが悪化しています。

つまり、MaxClientsさえ適切に設定し、サーバに載せたメモリーよりもアプリケーションがメモリーを消費しないようにすれば、秒間のリクエスト数は稼げるということを示しています。

もしくは、MaxClientsが大きかったとしても、アプリケーション側で同時実行をある程度抑制することでも効果は大きいといえます。

今回は実験しませんでしたが、データベースなどバックエンドにボトルネックがある場合にも、それが顕在化しない範囲でMaxClientsを設定したり、バックエンドへの接続数をアプリケーション側で抑制する必要があるでしょう。

つぎに、meanやmedianで示されるレスポンスにかかる平均値・中央値ですが、MaxClientsが大きすぎる場合にレスポンスが悪化するのは当然としても、MaxClientsが小さすぎる場合にも悪化していることが分かります。

そのため、スワップアウトしたり、バックエンドに負荷をかけすぎないように、サーバの能力よりも低くMaxClientsを設定したり、アプリケーション側でウエイトすることは重要ですが、それを超える同時リクエストが恒常的に発生する場合には、サーバのスペックアップやバックエンドの並列化などを行わなければなりません。

なお、最も難しいのがCPUやメモリへの負荷が低い静的コンテンツ(HTMLや画像など)と、CPUやメモリへの負荷が高いアプリケーションが同居しているときです。

MaxClientsが小さすぎると静的コンテンツのレスポンスが悪くなるし、大きすぎるとアプリケーションがたくさん動いた際にスループットが悪くなります。

先ほどのようにアプリケーション側で同時実行を抑制する方法もありますが、なかなかそうも行かないケースも多いと思います。

アプリケーションで対応しきれない場合には、サーバ側の設計やサイト構成で対応する方法もあり、静的コンテンツと動的コンテンツを置くサーバを分離したり、「ウェブアクセラレータ by さくらインターネット -手軽に使える高コストパフォーマンスCDNサービス-」(宣伝!)などのCDNを使ったり、フロント側にnginxなどのリバースプロキシーを置いてフロントは同じように見えつつもバックを分離するなどの方法があります。

トリッキーですが、同じサーバでもポートを分けてApacheを起動し、静的コンテンツはMaxClientsを128とかにして、動的コンテンツはMaxClientsを4とかにして、ローカルでプロキシーするなどの方法もあります。

サーバー屋としてはたくさんサーバを使ってほしいわけですが、個人的にはサーバーの無駄づかいは良くないと思いますし、しかしながらサーバが遅い状況が続くのはビジネスチャンスを逃すことになるので、さまざまなコマンドで状況を適切に把握し、適切なサーバ設定とスケーリングをされることをおすすめします。