やったこと
ApacheのチューニングとしてHTTP Keep-Aliveの設定をよく見かけます。
このKeep-Alive、仕組みをわかってるつもりではいるんですが、挙動をじっくり見たことがありませんでした。
そこで今回は、Keep-Aliveの有無によって
- パケットキャプチャ
- アクセスログ
がどう変わるのかを観察してみます。
環境
# cat /etc/centos-release
CentOS Linux release 7.1.1503 (Core)
# httpd -v
Server version: Apache/2.4.6 (CentOS)
Server built: Apr 2 2020 13:13:23
事前準備
今回はスレッドの動きも見たいので、ApacheをMPM workerで動かします。
設定は以下のファイルで実施します。
LoadModule mpm_worker_module modules/mod_mpm_worker.so
アクセスログでプロセスID（PID）、スレッドID（TID）とリクエストを対応付けたいので、下記の通りログ設定を編集します。
\"%{pid}P\" \"%{tid}P\"の記載が当該箇所です。
LogFormat "%h %l %u %t \"%r\" %>s %b \"%{Referer}i\" \"%{pid}P\" \"%{tid}P\" " combined
通信は、下記のtcpdumpコマンドでキャプチャします。pcapファイルに出力して、あとでWiresharkで確認します。
# tcpdump port 80 -i enp0s8 -w /home/vagrant/$(date "+%Y%m%d%H%M%S").pcap
Keep-Alive offの通信を観察する
Keep-Aliveをオフにします。
下記の下記の通り設定します。
KeepAlive Off
後でアクセスログを見てPIDとリクエストを対応付けたいので、ApacheのPIDを確認します。ユーザーがapacheと記載されているのがサーバープロセスです。一つのコントローラープロセス、4つのサーバープロセスが生成されていることがわかります。
Apacheのコントローラープロセス、サーバープロセス、スレッドの関係については以下の記事をご覧ください。
Apache2.4のMPM prefork/worker/eventの違いを理解する
# ps aux | grep httpd
root 4257 0.0 0.4 211268 4964 ? Ss 23:00 0:00 /usr/sbin/httpd -DFOREGROUND
apache 4258 0.0 0.2 211016 2828 ? S 23:00 0:00 /usr/sbin/httpd -DFOREGROUND
apache 4259 0.0 0.5 500232 5400 ? Sl 23:00 0:00 /usr/sbin/httpd -DFOREGROUND
apache 4260 0.0 0.5 500232 5400 ? Sl 23:00 0:00 /usr/sbin/httpd -DFOREGROUND
apache 4261 0.0 0.5 500232 5404 ? Sl 23:00 0:00 /usr/sbin/httpd -DFOREGROUND
リソースにアクセスしてみます。今回は1ページにつき3枚の画像を含むページを/var/www/html/index.htmlに配置し、ブラウザからアクセスしてみました。
この時、先ほどのtcpdumpコマンドで通信をキャプチャします。
アクセスログを確認してみます。
右から2列目の4桁がPID、右端の列がTIDです。4リクエストの全てが異なるスレッドによって処理されたことがわかります。
# less /var/log/httpd/access_log
192.168.33.1 - - [12/May/2020:23:02:11 +0900] "GET /index.html HTTP/1.1" 200 356 "-" "4259" "140456360896256"
192.168.33.1 - - [12/May/2020:23:02:12 +0900] "GET /20200422_142825101_iOS.jpg HTTP/1.1" 200 128575 "http://192.168.33.10/index.html" "4260" "140456268576512"
192.168.33.1 - - [12/May/2020:23:02:12 +0900] "GET /20200422_144339615_iOS.jpg HTTP/1.1" 200 69018 "http://192.168.33.10/index.html" "4259" "140456344110848"
192.168.33.1 - - [12/May/2020:23:02:12 +0900] "GET /20200422_143625154_iOS.jpg HTTP/1.1" 200 180936 "http://192.168.33.10/index.html" "4261" "140456529565440"
tcpdumpコマンドでキャプチャしたpcapをwiresharkで確認します。
下の図は、index.htmlへのGETリクエストを選択して、当該リクエストが含まれるTCPセッションを表示したところです。
一つのTCPセッションにHTTPリクエスト・レスポンスが一往復のみしか含まれていませんね。
Keep-Alive onの通信を観察する
Keep-Alive onを有効にします。
下記の通り設定します。タイムアウト値は今回Apacheデフォルトの5秒にしています。
KeepAlive On
KeepAliveTimeout 5
PID、TIDを確認します。
# ps aux | grep httpd
root 4053 0.0 0.4 211268 4964 ? Ss 21:47 0:00 /usr/sbin/httpd -DFOREGROUND
apache 4054 0.0 0.2 211016 2828 ? S 21:47 0:00 /usr/sbin/httpd -DFOREGROUND
apache 4055 0.0 0.5 631304 5936 ? Sl 21:47 0:00 /usr/sbin/httpd -DFOREGROUND
apache 4056 0.0 0.5 631304 5940 ? Sl 21:47 0:00 /usr/sbin/httpd -DFOREGROUND
apache 4057 0.0 0.5 631304 5944 ? Sl 21:47 0:00 /usr/sbin/httpd -DFOREGROUND
apache 4142 0.0 0.5 500232 5408 ? Sl 21:49 0:00 /usr/sbin/httpd -DFOREGROUND
先ほどと同じようにtcpdumpコマンドを流しつつリソースにブラウザアクセスしてから、アクセスログを確認します。
KeepAliveがoffのときは各リクエストが異なるプロセス、スレッドで処理されていましたが、今回は4リクエスト中3リクエストが同一プロセス、同一スレッドで処理されたことがわかります。
なんか1リクエストPIDは異なるのにTIDは同じやつがいますがこれはよくわかりません。
192.168.33.1 - - [12/May/2020:21:56:03 +0900] "GET /index.html HTTP/1.1" 200 356 "-" "4055" "139884928952064"
192.168.33.1 - - [12/May/2020:21:56:03 +0900] "GET /20200422_142825101_iOS.jpg HTTP/1.1" 200 128575 "http://192.168.33.10/index.html" "4055" "139884928952064"
192.168.33.1 - - [12/May/2020:21:56:03 +0900] "GET /20200422_143625154_iOS.jpg HTTP/1.1" 200 180936 "http://192.168.33.10/index.html" "4055" "139884928952064"
192.168.33.1 - - [12/May/2020:21:56:03 +0900] "GET /20200422_144339615_iOS.jpg HTTP/1.1" 200 69018 "http://192.168.33.10/index.html" "4056" "139884928952064"
ネットワークキャプチャも確認します。
先ほどと同じく、/index.htmlへのGETリクエストを選択して、当該リクエストが含まれるTCPセッションを表示します。
今回は一つのTCPセッションにHTTPリクエスト・レスポンスが三往復含まれています。
なるほど有益な設定だった
Keep-Aliveを有効にすることで、一つのTCPセッション、スレッドで複数のHTTP通信をさばく様子を目で見て確認できて満足です。
リクエストがたくさん来た時でも、Keep-Aliveが有効ならApacheがスレッド数を使い切ってしまうのを防ぐことができそうです。
ただし、Keep-Aliveを設定した場合、Keep-Aliveタイムアウト（一つのTCPセッションが次のHTTP通信を待つ時間の上限）がくるまでスレッドが占有されることになります。
Keep-Aliveを設定したうえで性能が頭打ちを迎えてしまったら、Keep-Aliveタイムアウト値やスレッド数などを見直す必要があるかもしれません。