2014年3月27日木曜日

event MPM: listenerスレッドのリクエスト受付時の処理のメモ

前の投稿に書いたように、接続済みのソケットにKeep-Aliveでリクエストが届くと、そのときに空きworkerスレッドが獲得できなければ、ソケットはクローズされていた。
この辺、投稿としてまとめておく。
内容がダブってしまうが、事前に考えていないということだな。

(1) KeepAlive接続の場合


接続済みのソケットにKeep-Aliveでリクエストが届くと、そのときに空きworkerスレッドが獲得できなければ、ソケットはクローズされる

(httpd-2.4.7/server/mpm/event/event.c)

   1368 static void * APR_THREAD_FUNC listener_thread(apr_thread_t * thd, void *dummy)
   1369 {
    :

   1414     for (;;) {
    :

   1495         while (num) {
   1496             pt = (listener_poll_type *) out_pfd->client_data;
   1497             if (pt->type == PT_CSD) {
   1498                 /* one of the sockets is readable */
    :

   1502                 switch (cs->pub.state) {
   1503                 case CONN_STATE_CHECK_REQUEST_LINE_READABLE:
   1504                     cs->pub.state = CONN_STATE_READ_REQUEST_LINE;
   1505                     remove_from_q = &keepalive_q;
   1506                     /* don't wait for a worker for a keepalive request */
   1507                     blocking = 0;
   1508                     /* FALL THROUGH */
   1509                 case CONN_STATE_WRITE_COMPLETION:
   1510                     get_worker(&have_idle_worker, blocking,
   1511                                &workers_were_busy);
    :

   1532                     /* If we didn't get a worker immediately for a keep-alive
   1533                      * request, we close the connection, so that the client can
   1534                      * re-connect to a different process.
   1535                      */
   1536                     if (!have_idle_worker) {
   1537                         start_lingering_close_nonblocking(cs);
   1538                         break;
   1539                     }
    :


1510行目のget_worker()で利用可能なworkerスレッドが得られない場合(have_idle_workerが0)に、
1537行目でソケットを閉じている。
1532行目のコメントにもあるように、keep-aliveなリクエストに対してworkerスレッドが確保できなければ、直ちに接続を切り、クライアント側が再接続するのを待つという仕様になっている。


(2) 新規接続の場合


この場合、accept可能になった時点で、空きworkerスレッドが確保できなければ、accept自体を行わない。

(httpd-2.4.7/server/mpm/event/event.c)

   1615                     get_worker(&have_idle_worker, 1, &workers_were_busy);
   1616                     rc = lr->accept_func(&csd, lr, ptrans);


1615行目で、get_worker()は空きworkerスレッドが獲得できるまでブロックする。
そして、獲得後に、1616行目の関数からaccept()が実行される。

もし、別の子プロセスがいて、空きworkerスレッドがいたなら、そちらが先にaccept することになる。
この場合、空きworkerスレッドを待っていた子プロセスで、空きworkerスレッドが確保できて、1615行目から抜けたときの処理は、event MPMではソケットが非ブロックになっているので、1616行目の関数から呼び出されるaccept()処理が失敗する。
その後、確保したプールを解放するなどの処理を行ってから、何事もなく listenerスレッドとして監視処理を継続することになる。


2014年3月25日火曜日

abの出力の確認 : Failed requests

前回の計測で、Failed requestsの発生した計測結果(Keep-Aliveを有効にしたevent MPM)を確認する。

abの出力を確認する。

Document Length:        31 bytes

これは、最初に読み込んだコンテンツサイズを保持している。

Complete requests:      1000000
Failed requests:        172849
   (Connect: 0, Receive: 0, Length: 172849, Exceptions: 0)

Failed requestsはComplete requestの内数(Complete requestsに含まれる)。
Lengthエラーは、読み込んだ(ボディ)サイズが、Document Lengthと一致しない場合だ。

print文を入れて見てみると、読み込んだサイズは0。
コネクションが終了しているらしい。これがLengthエラーとしてカウントされている。
サーバで接続を切っているということになるだろう。

 $ ab -c 10 -n 100 -k http://centps5:8080/hello.html


で試すと、サーバのアクセスログの出力件数は、
Complete requests - Failed Requests
になっている。

サーバは、リクエストを受け取らないで接続を切っているのかもしれない。

ソースを確認した。

(httpd-2.4.7/server/mpm/event/event.c)

   1368 static void * APR_THREAD_FUNC listener_thread(apr_thread_t * thd, void *dummy)
   1369 {
    :

   1414     for (;;) {
    :

   1495         while (num) {
   1496             pt = (listener_poll_type *) out_pfd->client_data;
   1497             if (pt->type == PT_CSD) {
   1498                 /* one of the sockets is readable */
    :

   1502                 switch (cs->pub.state) {
   1503                 case CONN_STATE_CHECK_REQUEST_LINE_READABLE:
   1504                     cs->pub.state = CONN_STATE_READ_REQUEST_LINE;
   1505                     remove_from_q = &keepalive_q;
   1506                     /* don't wait for a worker for a keepalive request */
   1507                     blocking = 0;
   1508                     /* FALL THROUGH */
   1509                 case CONN_STATE_WRITE_COMPLETION:
   1510                     get_worker(&have_idle_worker, blocking,
   1511                                &workers_were_busy);
    :

   1532                     /* If we didn't get a worker immediately for a keep-alive
   1533                      * request, we close the connection, so that the client can
   1534                      * re-connect to a different process.
   1535                      */
   1536                     if (!have_idle_worker) {
   1537                         start_lingering_close_nonblocking(cs);
   1538                         break;
   1539                     }
    :


1510行目のget_worker()で利用可能なworkerスレッドが得られない場合(have_idle_workerが0)に、
1537行目でソケットを閉じている。
1532行目のコメントにもあるように、keep-aliveなリクエストに対してworkerスレッドが確保できなければ、直ちに接続を切り、クライアント側が再接続するのを待つという仕様になっている。

高負荷では、空きworkerスレッドが得られないことがあるため、abでの負荷検証では、接続が切られるケースが出てくることになったと考えられる。

abが、このエラーの分を余分にリクエスト投げるようになっていれば、他のFailed requestsの発生していない計測と同等の条件になるということか。どうだろう。


メモ


前回と同様な負荷をかけた場合には、サーバのアクセスログに記録されるリクエスト件数は
Complete requests - Failed Requests にはならず、少し多い。
event MPMでKeep-Aliveを有効にした場合、検証ではネットワークも限界に近くなっているので、そちらが原因ということも考えられるが、確認できていない。



2014年3月24日月曜日

worker MPMとevent MPMの比較

マシン性能で絶対値的なものは変わってくるが、同じマシン上で並べて比べていれば、いくらか傾向が窺えるのではないかと思う。
CentOS 5.10上で比較した。


(1) Keep-Alive 無効の場合

コマンド

$ ab -c 1000 -n 1000000 http://centos5:8080/hello.html

(1.1) event MPM


Server Software:        Apache/2.4.7
Server Hostname:        centos5
Server Port:            8080

Document Path:          /hello.html
Document Length:        31 bytes

Concurrency Level:      1000
Time taken for tests:   58.275 seconds
Complete requests:      1000000
Failed requests:        0
Write errors:           0
Total transferred:      274001096 bytes
HTML transferred:       31000124 bytes
Requests per second:    17160.13 [#/sec] (mean)
Time per request:       58.275 [ms] (mean)
Time per request:       0.058 [ms] (mean, across all concurrent requests)
Transfer rate:          4591.69 [Kbytes/sec] received

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0   29 114.8     16    3021
Processing:     9   29  61.2     19    4600
Waiting:        8   27  60.7     18    4595
Total:         26   58 130.1     35    4612

Percentage of the requests served within a certain time (ms)
  50%     35
  66%     38
  75%     40
  80%     43
  90%     49
  95%     57
  98%    256
  99%   1032
 100%   4612 (longest request)

(1.2) worker MPM


Server Software:        Apache/2.4.7
Server Hostname:        centos5
Server Port:            8080

Document Path:          /hello.html
Document Length:        31 bytes

Concurrency Level:      1000
Time taken for tests:   90.378 seconds
Complete requests:      1000000
Failed requests:        0
Write errors:           0
Total transferred:      274000000 bytes
HTML transferred:       31000000 bytes
Requests per second:    11064.69 [#/sec] (mean)
Time per request:       90.378 [ms] (mean)
Time per request:       0.090 [ms] (mean, across all concurrent requests)
Transfer rate:          2960.67 [Kbytes/sec] received

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    0   0.4      0      17
Processing:     8   90   2.1     90     100
Waiting:        8   90   2.1     90     100
Total:         26   90   1.9     90     105

Percentage of the requests served within a certain time (ms)
  50%     90
  66%     90
  75%     91
  80%     91
  90%     92
  95%     93
  98%     96
  99%     97
 100%    105 (longest request)


(2) Keep-Alive 有効の場合


コマンド
$ ab -c 1000 -n 1000000 -k http://centos5:8080/hello.html

(2.1) event MPM


Server Software:        Apache/2.4.7
Server Hostname:        centos5
Server Port:            8080

Document Path:          /hello.html
Document Length:        31 bytes

Concurrency Level:      1000
Time taken for tests:   34.224 seconds
Complete requests:      1000000
Failed requests:        172849
   (Connect: 0, Receive: 0, Length: 172849, Exceptions: 0)
Write errors:           0
Keep-Alive requests:    827151
Total transferred:      256590607 bytes
HTML transferred:       25641774 bytes
Requests per second:    29219.55 [#/sec] (mean)
Time per request:       34.224 [ms] (mean)
Time per request:       0.034 [ms] (mean, across all concurrent requests)
Transfer rate:          7321.74 [Kbytes/sec] received

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    0   0.6      0      17
Processing:     0   34  71.7      2     261
Waiting:        0   34  71.8      2     261
Total:          0   34  72.0      2     261

Percentage of the requests served within a certain time (ms)
  50%      2
  66%      2
  75%      2
  80%      3
  90%    189
  95%    203
  98%    215
  99%    222
 100%    261 (longest request)

(2.2) worker MPM


Server Software:        Apache/2.4.7
Server Hostname:        centos5
Server Port:            8080

Document Path:          /hello.html
Document Length:        31 bytes

Concurrency Level:      1000
Time taken for tests:   85.213 seconds
Complete requests:      1000000
Failed requests:        0
Write errors:           0
Keep-Alive requests:    990101
Total transferred:      309564449 bytes
HTML transferred:       31000000 bytes
Requests per second:    11735.33 [#/sec] (mean)
Time per request:       85.213 [ms] (mean)
Time per request:       0.085 [ms] (mean, across all concurrent requests)
Transfer rate:          3547.70 [Kbytes/sec] received

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    0   0.4      0      18
Processing:     0   81 818.1      1    8588
Waiting:        0   81 818.1      0    8588
Total:          0   81 818.2      1    8588

Percentage of the requests served within a certain time (ms)
  50%      1
  66%      1
  75%      1
  80%      1
  90%      1
  95%      1
  98%      1
  99%      3
 100%   8588 (longest request)



とりあえず、切り貼りだけ。
サーバ側のプロセス・スレッドまわりの設定はAsyncRequestWorkerFactor以外は両者同じにした。

(httpd.conf)

StartServers              2
MaxRequestWorkers         6
MinSpareThreads           6
MaxSpareThreads           6
ThreadsPerChild           3
AsyncRequestWorkerFactor 50
MaxConnectionsPerChild    0



event MPMの場合、abでエラーが発生している。

2014年3月18日火曜日

httpd-2.4.9 Release

httpd-2.4.9がリリースされた。

http://ミラーサーバ/pub/network/apache/httpd/
http://ミラーサーバ/pub/network/apache/httpd/CHANGES_2.4.9

CHANGESを見ると脆弱性が2件修正されている。

CVE-2014-0098

cookieをログ出力する処理にあった冗長な文字列解析を整理した。
値を有するcookieのみをログ出力するようにした。これにより、これにより切り詰められたcookieをログ出力するときに、segfaultするのを防いだ


CVE-2013-6438

mod_dav: 先行するスペースを削除するような場合にも、cdataの長さを正しく維持するようにした。
特別に細工したDAV WRITEリクエストを使って、DoS状態にすることかできる可能性があった。

いずれも、コードとしては、2.2.26にもあるようだ。
...2.2.27のCHANGESにも書かれていた。


2014年3月10日月曜日

event MPMのプロセス構成

各MPMに固有な処理はソースコード上 server/mpmディレクトリに下に、mpmごとのディレクトリが切られて、その下に保存されている。event MPMの場合は、 server/mpm/event だ。
そこに、event.cファイルがある。
このファイルには、MPMの主処理(mpmフック関数)である event_run()関数とそこから起動される子プロセスのコードが定義されている。
どういった処理構成なのか、図を描くと分かりやすいと思ったので、描いてみた。


親プロセスで event_run()関数が実行され、子プロセスを生成する。

通常は、StartServersディレクティブで指定された数の子プロセスが生成される。

各子プロセスの主処理は child_main()関数である。
このchild_main()関数の処理スレッドをメインスレッドと書いた。メインスレッドは各スレッドを生成するためのstartスレッドを開始し、その後、親プロセスからの終了コマンドを受け付けるためにpipeを監視している。

startスレッドは、設定のThreadsPerChildで定められた数のworkerスレッドを生成し、1つのlistenerスレッドを生成すると終了する。workerスレッドの生成は、graceful再起動の場合など時間がかかるケースがあるが、startスレッドの寿命は大体短い。
ThreadPerChild個のworkerスレッドは、StartServers個のプロセス全部で用意されるので、最初のworkerスレッド数はその掛け算 ( ThreadPerChild × StartServers )個になる。

listenerスレッドは、設定ファイルのListenディレクティブで指定されたサーバ用のソケットの監視が当初の役目だ。
ソケットが接続を受け付けると、通信用のソケットが払い出され、これをworkerスレッドに引渡す。

workerスレッドはリクエスト処理のためのスレッドだ。
通信中のソケットを受け取り、HTTPリクエストを処理する。

なお、Listenソケットは、親プロセスで生成される。
実際に接続を受け付けるaccept()の処理を行うのは子プロセスのlistenerスレッドだが、親プロセスで用意されたソケットリソースが全ての子プロセスで共有される構成になっている。

さて、event MPMの場合、workerスレッドが処理したリクエストに対してレスポンスを返した後、そのソケットがHTTPのKeep-Aliveが有効な通信の場合、次のリクエスト待ちとして、そのソケットをlistenerスレッドの監視対象に加える。それを図では接続済みソケット、と書いた。
そして、処理を終えたworkerスレッドはアイドル状態のworkerスレッドとなって、次のリクエストの到着を待つ。

ちなみに、worker MPMの場合は、Keep-Aliveな通信でworkerスレッドがレスポンスを返した後、引き続き、そのソケットに次のリクエストが到着するのをそのまま待つようになっている。
待ってる間はworkerスレッドは何も処理をしない。もし、listenerスレッドが他に新しいリクエストを受け取っても、そのworkerスレッドでは処理できない。
この次のリクエストの待ち時間が無駄だと考えられたようだ。


2014年3月3日月曜日

eventMPM: AsyncRequestWorkerFactor

次にevent MPM固有の設定を見る。
リンクはここ。
http://httpd.apache.org/docs/2.4/en/mod/event.html


AsyncRequestWorkerFactor


このディレクティブは2.4系で追加になっている。

ドキュメントをなんとなく訳してみる

event MPMは接続を非同期に処理する。
ここで、リクエスト処理スレッド(ワーカスレッド)は短期間の間、必要に応じて割り当てられ、
そして、一つのリクエスト処理スレッドと一緒の別の接続がコネクション毎に確保される。
※後半は意味不明だが、昔のドキュメントには接続に対して「(多くはSSL)」と注釈されているので、接続がリクエスト処理スレッドを占有するworker MPMと同じタイプのものを指しているようだ。つまり、2種類のタイプがあるってことだろう。

この結果、次のような状況になる。
全てのワーカが拘束され、確立した非同期接続のための新しい処理を行う処理スレッドがない。

この問題を緩和するために、event MPMは2つのことをする

1つめ。
プロセスごとに受け付ける接続数をアイドル状態のワーカスレッド数に応じて制限する

2つめ。
全てのワーカスレッドがビジー状態の場合、Keep-Alive状態の接続をクローズする。
これは、Kee-Aliveタイムアウトに至る前の接続であっても、クローズする。
これにより、それぞれのクライアントは別の、ワーカスレッドが利用できるプロセスに再接続することができる。

このディレクティブがプロセス毎の接続数の制限を細かく調整するために使用される。
プロセスが現在の接続数(クローズ中のものを除く)が下記の値より小さい場合にのみ新しい接続を受け付ける。
ThreadsPerChild + (AsyncRequestWorkerFactor * number-of-idle-workers)

これは、同時接続数の最大値が以下の値となることを意味している
(AsyncRequestWorkerFactor + 1 )*MaxRequestWorkers

AsyncRequestWorkerFactorは非整数値を取れる(例: 1.5)


以上が訳文。
次に、休み休み考えてみる。
接続には以下があるだろう。

 [A] 実際にワーカスレッドで処理中の接続
    (1)非同期処理中
    (2)同期処理中(2.4.7より前の場合は、SSL接続が該当したようだ)
 [B] Kee-Alive中などworker処理のない接続
    (1)非同期処理待ち(リクエスト受信待ち、write許可待ち)
    (2)クローズ中

[A]の数は処理中のワーカスレッド数に他ならないから、
[A]<=ThreadPerChild となる。

もし [A]+[B}<=ThreadPerChildとするのであれば、[B]接続に対応するワーカスレッドがアイドル状態でなくてはならない。
しかし、それはKeep-Alive中の接続のためにワーカスレッドを使わず、予約しているわけで、eventMPMの意味がない。
当然のこととして、空いているワーカスレッドがあるなら、接続を受け入れるべきだと考えるだろう。

そう考えても、がんがん受け入れると、どんどん[B]の数が増えていく。
そこで、

[A]+[B(1)] < ThreadsPerChild + ( AsyncRequestWorkerFactor * idle_workers(アイドルワーカ数) )

という制限を設けた。
※ちなみに、B(2)の接続は最終的なクローズ処理をlistener_threadで行っているので、アイドルワーカを必要としない。

つまり、どの程度余分に接続を受け入れるのかを調整する設定値ということになるだろう。
値が大きいほど余分に接続を受け付けることができる。

ただし、受付接続数が増えるのはアイドル状態のワーカスレッドがいる場合だ。
アイドルワーカがいない場合、当然、すべてのワーカスレッドは処理中なので、かりに接続数がThreadsPerChild(個)であっても([B]の接続がない状態)、これ以上の新規接続は受け付けない(接続数は増えない)。

接続からリクエストを受け取り、即座にレスポンスが返され、そのままKeep-Aliveになる場合、瞬間瞬間にはアイドルワーカが発生するので、新規接続を受け付けることが可能になる。
多くのリクエストを処理していれば、瞬間瞬間のアイドルワーカも減少してくる。
あるいは、リクエストの処理に要する時間が長くなると、やはり、時々刻々のワイドルワーカ数が平均的には減少する。
その場合、受け入れられる接続数の合計は抑制的になるだろう。

そして、Keep-Alive接続上に次のリクエストが到着したとき、もしアイドルワーカがいなければ、event MPMは接続を切ってしまう。
多過ぎる数の接続を受け付けている場合には、こういった事態も起こりやすいだろう。
AsyncRequestWorkerFactor を程よく設定するのは、ちょっと考える必要がありそうだ。

ところで実装を見ると、
 [A]+{B(1)] > ThreadsPerChild + ( AsyncRequestWorkerFactor * idle_workers(アイドルワーカ数) )
の場合には、新たな接続を受けつけないようになっているので、
 [A]+{B(1)] <= ThreadsPerChild + ( AsyncRequestWorkerFactor * idle_workers(アイドルワーカ数) )
という関係になるはずだ。


(httpd-2.4.7/server/mpm/event/event.c)
   1571         else if (  (int)apr_atomic_read32(&connection_count)
   1572                - (int)apr_atomic_read32(&lingering_count)
   1573              > threads_per_child
   1574                + ap_queue_info_get_idlers(worker_queue_info) *
   1575                  worker_factor / WORKER_FACTOR_SCALE)
   1576         {
   1577           if (!listeners_disabled)
   1578               disable_listensocks(process_slot);
   1579           ap_log_error(APLOG_MARK, APLOG_DEBUG, 0, ap_server_conf,
   1580                        "Too many open connections (%u), "
   1581                        "not accepting new conns in this process",
   1582                        apr_atomic_read32(&connection_count));
   1583           ap_log_error(APLOG_MARK, APLOG_TRACE1, 0, ap_server_conf,
   1584                        "Idle workers: %u",
   1585                        ap_queue_info_get_idlers(worker_queue_info));
   1586           listeners_disabled = 1;
   1587         }



  • connection_countは接続数。
  • lingering_countはクローズ中の接続数(connection_countに含まれる)。
  • apr_atomic_read32()は引数のアドレスに格納されている値をアトミックに取得する関数。
  • threads_per_childはThreadsPerChildの設定値。
  • ap_queue_info_get_idlers(worker_queue_info)はアイドルワーカ数が取得する関数。
  • worker_factorはAsyncRequestWorkerFactorの設定値のWORKER_FACTOR_SCALE倍の値を非負整数で保持している。
  • WORKER_FACTOR_SCALEは定数16。
  • ( worker_factor / WORKER_FACTOR_SCALE )が元のAsyncRequestWorkerFactorの設定値。ただし、AsyncRequestWorkerFactorは分母が16の分数の精度で保持されている。

このelse if 条件を満たすと、新たな接続を受け付けなくなる。
なぜdoubleとかで元の設定値を保持しないのか、意味があるのだろうが、分かっていない。