You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@httpd.apache.org by Yakov Shapiro <ys...@gmail.com> on 2012/03/05 00:19:12 UTC

[users@httpd] Apache 2.2 on Windows refuses to process more than 5 requests from one client concurrently

Hello,

I have been trying to configure Apache 2.2 running on Windows to
simultaneously handle a large number - say, a hundred - of incoming
web requests from a single UNIX machine. I have already raised
ThreadsPerChild on the Apache server to 128. To isolate the problem, I
also wrote a short Perl script for Windows, goodnight.pl. It sleeps
for 3 seconds, prints a message and exits. I wrote a second scrpit,
testharness.pl, to run on UNIX. It forks off 20 processes that each
send a single web request to goodnight.pl using Curl.

Since my ThreadsPerChild is well above 20, and nobody else is using my
Apache server, I expect it to handle all 20 requests to goodnight.pl
at once. So testharness.pl should complete in 3 seconds (give or take
a little time to establish the connection). If I modify testharness.pl
to fork off only one process and send one web request, then it does
exit in 3 seconds. However, with 20 simultaneous requests, the test
harness takes 12 seconds to finish. The Apache access log (see end of
this message) shows that all 20 requests arrive at the same second,
but the first five take 3 seconds to process, the next five, 6
seconds, the next five, 9 seconds and the last five, 12 seconds. As
far as I can tell, this slowness is not caused by goodnight.pl (which
does nothing except sleep, print and exit). If I add benchmarking to
goodnight.pl to log the script start time, then the logs show the last
five instances of the script are started 9 seconds after the request
is received by Apache.

I have also ran tcpdump on UNIX to see if this slowness is caused by
network issues. It does not appear to be: Apache instantly confirms
that it has received the request, but then takes longer than expected
(12 seconds instead of 3) to send back a response. I have also checked
the load on the Windows machine, using Task Manager. The memory and
CPU usage stay well below 75% through my test.

Is there anything I can do (or check) to change that behavior, and
make all 20 requests process at once? My access log and error log are
below. My httpd.conf is attached to this e-mail. My Windows OS is
Windows Server Standard, Service Pack 2. It is running Apache HTTP
Server 2.2 and ActivePerl version 5.8.8, build 817.

I would greatly appreciate any help with this issue.

Yakov Shapiro

P.S. Below is my Apache error log. To my eye it looks normal:

[Sun Mar 04 17:36:06 2012] [notice] Apache/2.2.15 (Win32)
mod_perl/2.0.4-dev Perl/v5.10.1 configured -- resuming normal
operations
[Sun Mar 04 17:36:06 2012] [notice] Server built: Mar  4 2010 11:27:46
[Sun Mar 04 17:36:06 2012] [notice] Parent: Created child process 2684
[Sun Mar 04 17:36:06 2012] [debug] mpm_winnt.c(487): Parent: Sent the
scoreboard to the child
[Sun Mar 04 17:36:06 2012] [info] Parent: Duplicating socket 228 and
sending it to child process 2684
[Sun Mar 04 17:36:06 2012] [debug] mpm_winnt.c(605): Parent: Sent 1
listeners to child 2684
[Sun Mar 04 17:36:06 2012] [notice] Child 2684: Child process is running
[Sun Mar 04 17:36:06 2012] [debug] mpm_winnt.c(408): Child 2684:
Retrieved our scoreboard from the parent.
[Sun Mar 04 17:36:06 2012] [debug] mpm_winnt.c(564): Child 2684:
retrieved 1 listeners from parent
[Sun Mar 04 17:36:06 2012] [notice] Child 2684: Acquired the start mutex.
[Sun Mar 04 17:36:06 2012] [notice] Child 2684: Starting 128 worker threads.
[Sun Mar 04 17:36:06 2012] [notice] Child 2684: Starting thread to
listen on port 80.

Here is my Apache access log. It shows the problem: the requests to
the same script are taking progressively longer to process (the first
few are done in 3 seconds, the last few take 12 seconds).

172.25.122.29 - - [04/Mar/2012:17:39:04 -0500] "GET
/perl/goodnight.pl?requestnumber=2 HTTP/1.1" 200 26 3 3000000
172.25.122.29 - - [04/Mar/2012:17:39:04 -0500] "GET
/perl/goodnight.pl?requestnumber=1 HTTP/1.1" 200 26 3 3000000
172.25.122.29 - - [04/Mar/2012:17:39:04 -0500] "GET
/perl/goodnight.pl?requestnumber=12 HTTP/1.1" 200 26 3 3000000
172.25.122.29 - - [04/Mar/2012:17:39:04 -0500] "GET
/perl/goodnight.pl?requestnumber=10 HTTP/1.1" 200 26 3 3015625
172.25.122.29 - - [04/Mar/2012:17:39:04 -0500] "GET
/perl/goodnight.pl?requestnumber=3 HTTP/1.1" 200 26 3 3031250
172.25.122.29 - - [04/Mar/2012:17:39:04 -0500] "GET
/perl/goodnight.pl?requestnumber=4 HTTP/1.1" 200 26 5 5984375
172.25.122.29 - - [04/Mar/2012:17:39:04 -0500] "GET
/perl/goodnight.pl?requestnumber=6 HTTP/1.1" 200 26 6 6000000
172.25.122.29 - - [04/Mar/2012:17:39:04 -0500] "GET
/perl/goodnight.pl?requestnumber=5 HTTP/1.1" 200 26 6 6000000
172.25.122.29 - - [04/Mar/2012:17:39:04 -0500] "GET
/perl/goodnight.pl?requestnumber=16 HTTP/1.1" 200 26 6 6015625
172.25.122.29 - - [04/Mar/2012:17:39:04 -0500] "GET
/perl/goodnight.pl?requestnumber=13 HTTP/1.1" 200 26 6 6031250
172.25.122.29 - - [04/Mar/2012:17:39:04 -0500] "GET
/perl/goodnight.pl?requestnumber=8 HTTP/1.1" 200 26 8 8984375
172.25.122.29 - - [04/Mar/2012:17:39:04 -0500] "GET
/perl/goodnight.pl?requestnumber=7 HTTP/1.1" 200 26 9 9000000
172.25.122.29 - - [04/Mar/2012:17:39:04 -0500] "GET
/perl/goodnight.pl?requestnumber=11 HTTP/1.1" 200 26 9 9000000
172.25.122.29 - - [04/Mar/2012:17:39:04 -0500] "GET
/perl/goodnight.pl?requestnumber=14 HTTP/1.1" 200 26 9 9015625
172.25.122.29 - - [04/Mar/2012:17:39:04 -0500] "GET
/perl/goodnight.pl?requestnumber=9 HTTP/1.1" 200 26 9 9031250
172.25.122.29 - - [04/Mar/2012:17:39:04 -0500] "GET
/perl/goodnight.pl?requestnumber=18 HTTP/1.1" 200 26 11 11984375
172.25.122.29 - - [04/Mar/2012:17:39:04 -0500] "GET
/perl/goodnight.pl?requestnumber=20 HTTP/1.1" 200 26 12 12000000
172.25.122.29 - - [04/Mar/2012:17:39:04 -0500] "GET
/perl/goodnight.pl?requestnumber=15 HTTP/1.1" 200 26 12 12000000
172.25.122.29 - - [04/Mar/2012:17:39:04 -0500] "GET
/perl/goodnight.pl?requestnumber=17 HTTP/1.1" 200 26 12 12015625
172.25.122.29 - - [04/Mar/2012:17:39:04 -0500] "GET
/perl/goodnight.pl?requestnumber=19 HTTP/1.1" 200 26 12 12031250

[users@httpd] Re: Apache 2.2 on Windows refuses to process more than 5 requests from one client concurrently

Posted by Yakov Shapiro <ys...@gmail.com>.
Hello there,

A coworker of mine was able to find the solution on Google. if you add

PerlInterpMax 20

to the httpd.conf, then all 20 concurrent requests will get processed
simultaneously. The default value for PerlInterpMax is 5, which means
that Apache will not run more than 5 Perl interpreters at the same
time.

I hope this answer helps someone who runs into the same problem later.

Yakov Shapiro

On Sun, Mar 4, 2012 at 6:19 PM, Yakov Shapiro <ys...@gmail.com> wrote:
> Hello,
>
> I have been trying to configure Apache 2.2 running on Windows to
> simultaneously handle a large number - say, a hundred - of incoming
> web requests from a single UNIX machine. I have already raised
> ThreadsPerChild on the Apache server to 128. To isolate the problem, I
> also wrote a short Perl script for Windows, goodnight.pl. It sleeps
> for 3 seconds, prints a message and exits. I wrote a second scrpit,
> testharness.pl, to run on UNIX. It forks off 20 processes that each
> send a single web request to goodnight.pl using Curl.
>
> Since my ThreadsPerChild is well above 20, and nobody else is using my
> Apache server, I expect it to handle all 20 requests to goodnight.pl
> at once. So testharness.pl should complete in 3 seconds (give or take
> a little time to establish the connection). If I modify testharness.pl
> to fork off only one process and send one web request, then it does
> exit in 3 seconds. However, with 20 simultaneous requests, the test
> harness takes 12 seconds to finish. The Apache access log (see end of
> this message) shows that all 20 requests arrive at the same second,
> but the first five take 3 seconds to process, the next five, 6
> seconds, the next five, 9 seconds and the last five, 12 seconds. As
> far as I can tell, this slowness is not caused by goodnight.pl (which
> does nothing except sleep, print and exit). If I add benchmarking to
> goodnight.pl to log the script start time, then the logs show the last
> five instances of the script are started 9 seconds after the request
> is received by Apache.
>
> I have also ran tcpdump on UNIX to see if this slowness is caused by
> network issues. It does not appear to be: Apache instantly confirms
> that it has received the request, but then takes longer than expected
> (12 seconds instead of 3) to send back a response. I have also checked
> the load on the Windows machine, using Task Manager. The memory and
> CPU usage stay well below 75% through my test.
>
> Is there anything I can do (or check) to change that behavior, and
> make all 20 requests process at once? My access log and error log are
> below. My httpd.conf is attached to this e-mail. My Windows OS is
> Windows Server Standard, Service Pack 2. It is running Apache HTTP
> Server 2.2 and ActivePerl version 5.8.8, build 817.
>
> I would greatly appreciate any help with this issue.
>
> Yakov Shapiro
>
> P.S. Below is my Apache error log. To my eye it looks normal:
>
> [Sun Mar 04 17:36:06 2012] [notice] Apache/2.2.15 (Win32)
> mod_perl/2.0.4-dev Perl/v5.10.1 configured -- resuming normal
> operations
> [Sun Mar 04 17:36:06 2012] [notice] Server built: Mar  4 2010 11:27:46
> [Sun Mar 04 17:36:06 2012] [notice] Parent: Created child process 2684
> [Sun Mar 04 17:36:06 2012] [debug] mpm_winnt.c(487): Parent: Sent the
> scoreboard to the child
> [Sun Mar 04 17:36:06 2012] [info] Parent: Duplicating socket 228 and
> sending it to child process 2684
> [Sun Mar 04 17:36:06 2012] [debug] mpm_winnt.c(605): Parent: Sent 1
> listeners to child 2684
> [Sun Mar 04 17:36:06 2012] [notice] Child 2684: Child process is running
> [Sun Mar 04 17:36:06 2012] [debug] mpm_winnt.c(408): Child 2684:
> Retrieved our scoreboard from the parent.
> [Sun Mar 04 17:36:06 2012] [debug] mpm_winnt.c(564): Child 2684:
> retrieved 1 listeners from parent
> [Sun Mar 04 17:36:06 2012] [notice] Child 2684: Acquired the start mutex.
> [Sun Mar 04 17:36:06 2012] [notice] Child 2684: Starting 128 worker threads.
> [Sun Mar 04 17:36:06 2012] [notice] Child 2684: Starting thread to
> listen on port 80.
>
> Here is my Apache access log. It shows the problem: the requests to
> the same script are taking progressively longer to process (the first
> few are done in 3 seconds, the last few take 12 seconds).
>
> 172.25.122.29 - - [04/Mar/2012:17:39:04 -0500] "GET
> /perl/goodnight.pl?requestnumber=2 HTTP/1.1" 200 26 3 3000000
> 172.25.122.29 - - [04/Mar/2012:17:39:04 -0500] "GET
> /perl/goodnight.pl?requestnumber=1 HTTP/1.1" 200 26 3 3000000
> 172.25.122.29 - - [04/Mar/2012:17:39:04 -0500] "GET
> /perl/goodnight.pl?requestnumber=12 HTTP/1.1" 200 26 3 3000000
> 172.25.122.29 - - [04/Mar/2012:17:39:04 -0500] "GET
> /perl/goodnight.pl?requestnumber=10 HTTP/1.1" 200 26 3 3015625
> 172.25.122.29 - - [04/Mar/2012:17:39:04 -0500] "GET
> /perl/goodnight.pl?requestnumber=3 HTTP/1.1" 200 26 3 3031250
> 172.25.122.29 - - [04/Mar/2012:17:39:04 -0500] "GET
> /perl/goodnight.pl?requestnumber=4 HTTP/1.1" 200 26 5 5984375
> 172.25.122.29 - - [04/Mar/2012:17:39:04 -0500] "GET
> /perl/goodnight.pl?requestnumber=6 HTTP/1.1" 200 26 6 6000000
> 172.25.122.29 - - [04/Mar/2012:17:39:04 -0500] "GET
> /perl/goodnight.pl?requestnumber=5 HTTP/1.1" 200 26 6 6000000
> 172.25.122.29 - - [04/Mar/2012:17:39:04 -0500] "GET
> /perl/goodnight.pl?requestnumber=16 HTTP/1.1" 200 26 6 6015625
> 172.25.122.29 - - [04/Mar/2012:17:39:04 -0500] "GET
> /perl/goodnight.pl?requestnumber=13 HTTP/1.1" 200 26 6 6031250
> 172.25.122.29 - - [04/Mar/2012:17:39:04 -0500] "GET
> /perl/goodnight.pl?requestnumber=8 HTTP/1.1" 200 26 8 8984375
> 172.25.122.29 - - [04/Mar/2012:17:39:04 -0500] "GET
> /perl/goodnight.pl?requestnumber=7 HTTP/1.1" 200 26 9 9000000
> 172.25.122.29 - - [04/Mar/2012:17:39:04 -0500] "GET
> /perl/goodnight.pl?requestnumber=11 HTTP/1.1" 200 26 9 9000000
> 172.25.122.29 - - [04/Mar/2012:17:39:04 -0500] "GET
> /perl/goodnight.pl?requestnumber=14 HTTP/1.1" 200 26 9 9015625
> 172.25.122.29 - - [04/Mar/2012:17:39:04 -0500] "GET
> /perl/goodnight.pl?requestnumber=9 HTTP/1.1" 200 26 9 9031250
> 172.25.122.29 - - [04/Mar/2012:17:39:04 -0500] "GET
> /perl/goodnight.pl?requestnumber=18 HTTP/1.1" 200 26 11 11984375
> 172.25.122.29 - - [04/Mar/2012:17:39:04 -0500] "GET
> /perl/goodnight.pl?requestnumber=20 HTTP/1.1" 200 26 12 12000000
> 172.25.122.29 - - [04/Mar/2012:17:39:04 -0500] "GET
> /perl/goodnight.pl?requestnumber=15 HTTP/1.1" 200 26 12 12000000
> 172.25.122.29 - - [04/Mar/2012:17:39:04 -0500] "GET
> /perl/goodnight.pl?requestnumber=17 HTTP/1.1" 200 26 12 12015625
> 172.25.122.29 - - [04/Mar/2012:17:39:04 -0500] "GET
> /perl/goodnight.pl?requestnumber=19 HTTP/1.1" 200 26 12 12031250

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@httpd.apache.org
For additional commands, e-mail: users-help@httpd.apache.org