Terrible Apache Bench results on Custom CMS

4
votes

Please note: This is not a complain about a shoddy CMS.

Just toying with Apache Bench and got terrible results with our custom CMS, more exactly i got:

Requests per second:    0.37 [#/sec] (mean)

When i run another test with a plain php file i got:

Requests per second:    4786.07 [#/sec] (mean)

Another test with a previous version of the CMS:

Requests per second:    6068.66 [#/sec] (mean)

The website(s) are working fine, no problems detected, Google's Webmaster Tools reports our sites as faster than 80% of the pages which is fine, i think.

The test was:

ab -t 30 -c 10 http://example.com/

Maybe some kind of Apache problem? Bad .htaccess config, or similar?

Update:

Just ran a simple test with sockets and the results are similar. Page loads very, very slowly. If i ran my script with another website everything is fine.

Also, there's a small hint about a chunk length problem. (Bad Apache Headers, or line endings?)

The site is gzipped, and when verbose logging turned on, i see these lines in the response:

LOG: Response code = 200
LOG: header received:
HTTP/1.1 200 OK
Date: Tue, 04 Oct 2011 13:10:49 GMT
Server: Apache
Set-Cookie: PHPSESSID=ibnfoqir9fee2koirfl5mhm633; path=/
Expires: Sat, 26 Jul 1997 05:00:00 GMT
Cache-Control: no-store, no-cache, must-revalidate
Pragma: no-cache
Cache-Control: post-check=0, pre-check=0
Vary: Accept-Encoding
Transfer-Encoding: chunked
Content-Type: text/html; charset=UTF-8

2ef6

Always at the same place, in the middle of the HTML-source, then <!DOCTYPE HTML> again.

Please, help.

Update #2:

Just checked my HTTP headers with Rex Swain's HTTP Viewer and got these results:

HTTP/1.1·200·OK(CR)(LF)
Date:·Wed,·05·Oct·2011·08:33:51·GMT(CR)(LF)
Server:·Apache(CR)(LF)
Set-Cookie:·PHPSESSID=n88g3qcvv9p6irm1fo0qfse8m2;·path=/(CR)(LF)
Expires:·Sat,·26·Jul·1997·05:00:00·GMT(CR)(LF)
Cache-Control:·no-store,·no-cache,·must-revalidate(CR)(LF)
Pragma:·no-cache(CR)(LF)
Cache-Control:·post-check=0,·pre-check=0(CR)(LF)
Vary:·Accept-Encoding(CR)(LF)
Connection:·close(CR)(LF)
Transfer-Encoding:·chunked(CR)(LF)
Content-Type:·text/html;·charset=UTF-8(CR)(LF)
(CR)(LF)

Do you notice anything unusual?

1
apachebenchmarkingchunked-encodingapachebenchhttp-chunked
Have you checked the logs of the server and the CMS? - palacsint
You might 1st check whether the issue is coming from the client or server side. Then isolate the problem(s) by a dichotomial approach to isolate the main issue. - hornetbzz
@palacsint Logs are fine, everything is normal. - fabrik
@hornetbzz When i'm opening the site in a browser, everything is normal (no signs of this weak performance). Running apachebench (the same server or an other one, no diff) or getting it via a simple socket test the results are terrible. - fabrik

1 Answers

4
votes

If it works well with ordinary web browsers (as you mentioned in the comments) the CMS handle the requests from Apache Benchmark differently.

A quick checklist:

  • AFAIK Apache Benchmark just send simple requests without any cookie handling, so try to set -C with a valid cookie (copy the values from a web browser).
  • Try to send exactly the same headers to the CMS as the web browser sends. Save a dump of a valid request with netcat, HttpFox or a packet sniffer and set the missing headers with -H.
  • Profile the CMS on the server while you're sending to it a request with Apache Benchmark. Maybe you found the bottleneck. Two poor man's error_log calls with a timestamp in the first and the last line of the index.php (or the tested script's entry point) could show how fast is the PHP script and help to calculate the overhead of the Apache HTTP Server and network.
  • If you run socket tests and browser tests from different machines it's could be a DNS issue (turn off HostnameLookups in Apache). Try to run them from the same machine.
  • Try ab -k ... or ab -H "Connection: close" ....

I guess the CMS does some costly initialization when it initializes the session and it's happens when it processes the first request. Since Apache Benchmark does not send the cookies back the CMS it creates a new session for every request and it's the cause of the slow answers.

A second guess is that the CMS handle the incoming http headers differently and the headers which was sent (or the lack of them) by Apache Benchmark trigger some costly/slow processing. It looks more appropriate since the report of the Google's Webmaster Tools.

Apache Benchmark sends HTTP 1.0 request, for example:

GET / HTTP/1.0
Host: localhost:9100
User-Agent: ApacheBench/2.3
Accept: */*

It looks to me that your server does not send any http header about Keep-Alive settings but it assumes that the client uses keep-alive when the client uses HTTP 1.0. It's not an RFC compliant behaviour:

From RFC 2616, 19.6.2 Compatibility with HTTP/1.0 Persistent Connections:

Some clients and servers might wish to be compatible with some
previous implementations of persistent connections in HTTP/1.0
clients and servers. Persistent connections in HTTP/1.0 are
explicitly negotiated as they are not the default behavior.

By default Apache Benchmark doesn't use keep-alive so it waits when the response arrives for the closing of the socket. The server closes it after 15 seconds idle. Downloading the main page with wget also takes 15 seconds. Wget also uses HTTP 1.0 in the request.

I think it's a bug in the PHP code of the CMS since ab works well on the same server with a plain php file. Anyway, you can workaround it with using keep-alive connections (-k):

ab -k -t 30 -c 10 http://example.com/

or with explicitly disabling persistent connections:

ab -H "Connection: close" -t 30 -c 10 http://example.com/

but it's still a server side issue and your original ab commands is right.

Please note that this bug probably affects only HTTP 1.0 clients (like Apache Benchmark, wget) and clients with regular browsers will not notice it.