How is the response time in the apache logs measured and at what point does it start and stop?

Solution 1:

I assume you mean the response-time as delivered by %D in the log-line (i.e. time in microseconds to serve the request). The time stated there is the duration from the successful reading of the URI (for instance GET / HTTP/1.1) but before the rest of the headers to the logging of said request, which happens once it has been served completely (in source-code terms this would be from httpd://apache.wirebrain.de/lxr/source/server/protocol.c#617?v=2.2.14 to apache.wirebrain.de/lxr/source/modules/loggers/mod_log_config.c#623?v=2.2.14). So yes, once Apache actually gets to read said request, it only takes 30ms.

Whether the added latency is due to the load of the machine depends on where that load is generated, and how your Apache httpd is configured. One explanation would be that all your httpd workers are busy and the request gets stuck in the accept-queue (see www.cs.rice.edu/CS/Systems/Web-measurement/paper/node3.html for a bit more technical background of what that is; short version is that httpd does not immediately have to accept a connection if there are no available workers).

To get an indication of whether this is happening would be to look at httpd's status-page (localhost/server-status, you will want to have mod_status (httpd.apache.org/docs/2.2/mod/mod_status.html) configured for that) and look at whether you have any idle workers left (and whether they are "enough"). If not, try increasing the number of workers httpd spawns (the exact configuration of which depends on which MPM-module you use; for mpm_worker (httpd.apache.org/docs/2.2/mod/worker.html), you would increase MaxClients, ThreadsPerChild, ServerLimit, etc. as appropriate. Take care not to exceed your machine's available memory or maximum of open files though (remember that each connection is at minimum one filehandle).

Depending on /why/ all the apache workers are tied up, this may help you. If they are all tied up in long-running dynamic page generation (i.e. mod_php or the like), all this is gonna do is increase the load on your system. If the load on your system is from a sub-par storage subsystem and all the Apache processes are tied up in large file transfers and waiting on the I/O subsystem, you'll just get more load. There are workarounds for both; if it's dynamic content, you will want to limit concurrent access to long-running scripts (for instance by getting PHP out of the worker process and into, say, a FastCGI or even CGI process and limiting the amount of those to somewhere below the MaxClients setting so that non-dynamic objects can be served simultaneously without incurring an accept-backlog on them.

Sorry for the missing http-links, apparently my reputation on this site is not enough to actually post links.