Take the 2-minute tour ×
Server Fault is a question and answer site for professional system and network administrators. It's 100% free, no registration required.

I run a PHP web application on an Apache 2.2 server (Ubuntu Server 10.04, 8x2GHz, 12Gb RAM) using prefork. Each day Apache gets about 100k-200k requests, of these about 100-200 hits the timeout limit (so about one in every thousand), pretty much all other requests are served well below the timeout.

What can I do to find out why this happens? Or is it normal to have some small parts of all requests timing out?

This is what I've done so far:

Requests response time

As can be seen there's very few requests that's between the timeout limit and more reasonable request. Currently the timeout limit is set to 50 seconds, previously it was set to 300 and it was still the same situation with some timeouts and then a huge gap down to the other requests.

All requests that times out are AJAX requests, but then the vast majority of them are, so perhaps that's more of a coincidence. The Apache return code is 200, but the timeout limit is clearly reached. They are from a wide range of different IPs.

I've looked at the requests that times out and there's nothing special about them, if I do the same requests they go through in far less than a second.

I've tried to look at the different resources to see if I can find the cause but no luck. There is always plenty of free memory (minimum is about 3GB free), load sometimes goes as high as 1.4 and CPU utilization to 40%, but many of the timeouts happen when the load and CPU utilization is low. Disk write/read are pretty much constant during the day. There's no entries in the MySQL slow query log (set to log anything above 1 second), an no request uses that many database writes/reads.

Request response time with system load/cpu

Blue is CPU utilization, which peaks at 40%, maroon is load with peak at 1.4. So we can see we get timeouts even with low CPU utilization/load (the ten second spikes correspond well to the CPU utilization, but that is another issue, I have higher hopes of finding out what might be causing those).

There's no errors in the Apache error log and I haven't seen it reach more than 200 active Apache processes.

Server Settings:

Timeout 50 
KeepAlive On
MaxKeepAliveRequests 100
KeepAliveTimeout 2

<IfModule mpm_prefork_module>
    ServerLimit     350
    StartServers        20
    MinSpareServers     75
    MaxSpareServers     150
    MaxClients          320
    MaxRequestsPerChild 5000
</IfModule>

Update:

I updated to Ubuntu 12.04.1, just in case, no change. I added mod_reqtimeout with settings:

RequestReadTimeout header=20-40,minrate=500
RequestReadTimeout body=10,minrate=500

Now almost all timeouts happens at 10 seconds, one or two at 20 seconds. I take that to mean that most of the time it's getting the request body that's problematic to receive? The request body should never be larger than a few hundred bytes. I've monitored the network traffic on a per 1 second basis and it never gets higher than 1Mbit/s and I don't see any rxerrs or rxdorps, considering that the server is on a 1Gbit/s line it doesn't sound like the HopelessN00b posted about. Could it be just a case of some bad user connections?

For the spikes every hour (they seem to drift around a bit, in the graphs above they're on 33 minutes past the hour, now they're on 12 minutes past), I've tried to see if there's anything periodically running (crons etc) but found nothing. PHP garbage collection runs twice every hour, but not at the time of the spikes, still I've tried with disabling it but it makes no difference.

I've used dstat with --top-cpu and top to look at the processes at the time of the spikes and all that shows up is apache working hard for a few seconds but no other process is using significant cpu.

I've made a zoomed in graph of the spikes: Zoomed request response time

To me it looks like apache halts for some few seconds and then works hard to process the requests that came in during the halt. What might cause such a halt, or am I misinterpreting it?

share|improve this question
    
I wanted to post with some graphs over the requests, but my rep is too low. –  Leon Sep 28 '12 at 12:46
    
Thanks for cleaning up the post :) –  Leon Oct 4 '12 at 13:35
add comment

2 Answers

up vote 2 down vote accepted

The first thing I note, looking at your first graph, there seems to be an hourly slowdown (occurring around 40 minutes past the hour) which may be contributing to the problem. You should have a look at the task schedulers on the OS / database.

Based on the data you've supplied, my next step woud be to look at the frequency of response times (number of responses on Y axis vs duration on X) but only including URLs which exhibit the timeout (or preferably one URL at a time). On a typical system this should follow a normal or poisson distribution - the requests which are timing out may simply be part of the tail - in which case you need to focus your efforts on general tuning. OTOH if the distribution is bi-modal then you need to look for contention somewhere in your code.

share|improve this answer
    
Thanks for your response. I'm looking into what might be causing the hourly slowdowns. In the mean time I made a frequency plot of the data I already have. This is just one of the URLs that has a timeout problem (but the others looks very similar): leela.kikora.no/apache_hist_show.png The amount of timeouts are very small compared to those that takes less than 10 seconds, but it looks like it might not be part of the tail. But on the other hand it could be just that since they represent anything that would have taken 50+ seconds, it's supposed to look like this. –  Leon Sep 28 '12 at 15:47
add comment

I have another thought on this, based on the fact that you get a large number of requests per day, and seem to have timeouts only during peak hours (from the pictures you posted).

There's a post on the Server Fault blog, Per Second Measurements Don't Cut It... is it possible some of these requests are running into the same problem the ServerFault team ran into?

We discovered that we were discarding packets pretty frequently on 1 Gbit/s interfaces at rates of only 10-30 MBit/s which hurts our performance. This is because that 10-30 MBit/s rate is really the number of bits transfered per 5 minutes converted to a one second rate. When we dug in closer with Wireshark and used one millisecond IO graphing, we saw we would frequently burst the 1 Mbit per millisecond rate of the so called 1 Gbit/s interfaces.

share|improve this answer
    
Interesting, I'll take a look at it. I've enable mod_reqtimeout and set it to RequestReadTimeout header=20-40,minrate=500 and RequestReadTimeout body=10,minrate=500 and almost all timeouts happen at 10 seconds now. I take that to mean that the request body takes too long (the body should never be more than a few hundred bytes at most) so either some of my users have bad connections or as you say there's some congestion on my server's side. –  Leon Oct 4 '12 at 13:44
add comment

Your Answer

 
discard

By posting your answer, you agree to the privacy policy and terms of service.

Not the answer you're looking for? Browse other questions tagged or ask your own question.