Measuring Apache request processing time

I support a fair number of Apache web server instances, and periodically need to measure the time it takes Apache (and it’s various modules) to process a request. On Solaris 10 hosts, I can use DTrace to retrieve this information on the fly. Since Solaris 9 and CentOS and Redhat Linux don’t come with DTrace, I use a different approach on these platforms.

To get the time when each request was received by Apache, I used mod_header’s “Header” directive, and “%t” option (time when a request was received, measured in milliseconds from the epoch), to add a response header with the time each request was received:

Header set X-Request-Received: %t

To get the total time Apache spent processing a request, I use mod_header’s “Header” directive, and “%D” option (milliseconds spent processing the request), to add a response header with the total time Apache spent processing each request:

Header set X-Request-Processing-Time: %D

Since I don’t always need the headers to be present, I like to be able to enable and disable them from the command line. The easiest way to do this is by enclosing the directives in a conditional block similar to the following:

<IfDefine RequestTime>
Header set X-Request-Received: %t
Header set X-Request-Processing-Time: %D

And using the httpd “-D” option to enable them:

$ httpd -k start -DRequestTime

After the headers are enabled, you will see entries similar to the following in each HTTP response:

$ curl -v

About to connect() to port 8080

< ..... >

< HTTP/1.1 200 OK
< Date: Tue, 02 Jan 2007 17:59:42TGMT:00-04:00
< Server: Apache/2.2.3 (Unix) DAV/2
< Last-Modified: Sat, 20 Nov 2004 20:16:24 GMT
< ETag: "34d37-2c-4c23b600"
< Accept-Ranges: bytes
< Content-Length: 44
< X-Request-Received: t=1167760782452525
< X-Request-Processing-Time: D=3513
< Content-Type: text/html

Similar capabilities are available for measuring request processing time on the client. Total time is helpful, but knowing how much of that time was consumed by Apache is invaluable!

This article was posted by Matty on 2007-01-02 14:27:00 -0400 -0400