4

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?

Community
  • 1
  • 1
fabrik
  • 14,094
  • 8
  • 55
  • 71
  • Have you checked the logs of the server and the CMS? – palacsint Oct 07 '11 at 11:41
  • 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 Oct 09 '11 at 18:49
  • @palacsint Logs are fine, everything is normal. – fabrik Oct 10 '11 at 13:29
  • @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 Oct 10 '11 at 13:33

1 Answers1

4

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.

Community
  • 1
  • 1
palacsint
  • 28,416
  • 10
  • 82
  • 109
  • Tried both but unfortunately, no success. Just got fewer RPS (0.07/sec) – fabrik Oct 11 '11 at 09:07
  • Show the original request (from a browser) and the parameters of the Apache Benchmark. Maybe just a typo. And check the update please. – palacsint Oct 11 '11 at 09:38
  • original test request is `ab -t 30 -c 10 http://popnroll.hu/` ATM investigating your update. – fabrik Oct 11 '11 at 09:41
  • measuring run time in the error_log displaying exactly the same timestamp both the first and the last line. – fabrik Oct 11 '11 at 09:51
  • Try `ab -k`. I don't know why it is so faster (yet). – palacsint Oct 11 '11 at 10:12
  • My original query itself was the problem? – fabrik Oct 11 '11 at 10:15
  • Checking with HTTPerf or Chrome's devtools it says the Keep-Alive header is presented. – fabrik Oct 11 '11 at 11:09
  • I think HTTPerf send HTTP 1.1 requests, not 1.0. Check with `wget -S`. – palacsint Oct 11 '11 at 11:27
  • Sorry, i don't get it. How can i bench the site correctly under HTTP/1.0? – fabrik Oct 11 '11 at 11:50
  • Check the update. I've comleted my examples with full `ab` command lines. – palacsint Oct 11 '11 at 12:10
  • the first one has failed with `Test aborted after 10 failures` but the second one does 223 RPS'. So that's the workaround for the Apachebench? BTW there's still some bug in my code? – fabrik Oct 11 '11 at 12:14
  • Yes, the second command works for me too. Yes, there is a bug somewhere. The Apache Benchmark should work well without the `-k` and `-H` parameters. It could be PHP or Apache bug or misconfiguration too but I don't have any idea what could cause this behaviour. Is it an open-source or available to public CMS? – palacsint Oct 11 '11 at 12:38
  • It's definetly a bug in the source code of the CMS (and not a PHP or Apache bug). I've just noticed that `ab` works well with a plain php script on the same server. (I've updated the answer too.) – palacsint Oct 11 '11 at 13:27