HOWTO/Graph HTTP Requests in Real Time

A couple of years back, I was faced with the need to create a real-time graph of HTTP transactions: Successful transactions (code 200), redirects (300), errors (400) and internal errors (500), plus a transferred byte count.

Since I use RRDTool to graph just about anything, the main challenge was the "real-time" bit. Well, it turned out that 300 second intervals (5 minutes' worth) were more than enough, since graphs of HTTP transactions with shorter sampling rates are meaningless to most people.

The main problem was reading the Apache log file on the fly and maintaining a running tally of events per interval. Well, it so happens that Apache supports multiple simultaneous log destinations, and you can just as easily log to another program with the CustomLog directive:

LogFormat "%h %l %u %t \"%r\" %>s %b \"%{Referer}i\" \"%{User-Agent}i\" \
           \"%{HTTP_X_FORWARDED_FOR}e\" \"%{HTTP_CLIENT_IP}e\"" combined
CustomLog "|/opt/scripts/updatehttp.pl" combined

(The LogFormat directive above defines a quite complete custom log format that includes HTTP proxy information besides the usual "common" log format)

/opt/scripts/updatehttp.pl is a simple Perl script that begins by checking whether the RRD archive for the data exists. A few notes on that, then:

The RRD File

Using an RRD COUNTER would not work properly, since the accumulated count would just keep on increasing, and I wanted to store actual events per interval. So I created the RRD file with GAUGEs instead, storing one DS per each HTTP error code type and another for bytes transferred:

DS:R200:GAUGE:300:0:U
DS:R300:GAUGE:300:0:U
DS:R400:GAUGE:300:0:U
DS:R500:GAUGE:300:0:U
DS:BYTES:GAUGE:300:0:U

These were stored in a fairly large archive (a year's worth of 5-minute samples, roughly 4MB of hard disk space):

RRA:MAX:0.5:1:105120

The script could have been made a bit more Perlish (by using the RRDTool Perl bindings), but I wanted to keep it fairly portable (to other languages, even), so I stuck to using system() to invoke RRDTool.

The script begins by checking for the RRD file (creating it if it doesn't exist), and then enters an infinite loop with an alarm (set at 300 seconds).

Between alarms, it parses STDIN for fields 8 (the HTTP result code of the current log line) and 9 (the amount of bytes transferred), and adds them up.

When the alarm is invoked, the script breaks from the eval construct and updates the RRD, looping again to begin the next 5 minutes of log parsing:

#!/usr/bin/perl
$rrdtool = "/usr/bin/rrdtool";
$rrd = "/var/log/httpd/http.rrd";
if( !-e $rrd ) {
  system( "$rrdtool create $rrd DS:R200:GAUGE:300:0:U \
           DS:R300:GAUGE:300:0:U DS:R400:GAUGE:300:0:U \
           DS:R500:GAUGE:300:0:U DS:BYTES:GAUGE:300:0:U \
           RRA:MAX:0.5:1:105120" );
}
while(1) {
    eval{
      local $SIG{ALRM} = sub { die "alarm\n" };
      @counters = split( /:/, "0:0:0:0:0:0" );
      $bytes=0;
      alarm 300;
      while( <> ) {
        @fields = split /\s+/;
        $code = $fields[8];
        $bytes += $fields[9];
        $category = int($code/100.0);
        $counters[$category]++;
      };
      alarm 0;
    };
  if( $@ ) {
    die unless $@ eq "alarm\n";
    $time=time();
    system( "$rrdtool update $rrd $time:$counters[2]:$counters[3]:" . \
            "$counters[4]:$counters[5]:$bytes\n" );
  }
}

The above script can be easily modified to graph the results (in a lazy fashion, only generating the GIF file if the data requires it) by adding another call to RRDTool after the update, but some people might prefer to generate the image on demand:

Here's the syntax to graph the bytes DS alone (check the manual to learn how to stack multiple data sources):

system( "$rrdtool graph /var/www/html/base.gif -z -s -3900 -e -300 " . \
        "-w 196 -h 120 DEF:bytes=$rrd:BYTES:MAX AREA:bytes#333333:Bytes" );

Note that with -e -300 we skip the last sample - which may not yet have been stored - and that starting with -s -3900 will therefore plot the data for the last hour.

And remember: The raw bytes data represents the total sum of bytes transferred during a 5-minute period, which can be quite high - so don't be alarmed if you see 1MB-high bars on your graph; that's just you looking at your site over the LAN. :)