HAProxy log analyzer to show response latency distribution from the console

analyze_haproxy_performance.pl

#!/usr/bin/perl
# HAProxy Performance Statistics
# by Steve Kamerman
#
# To use, pipe your HAProxy log with timing information (like "0/0/1/1/3 200") to 
# this script.  It will output min, max, med, avg and a latency distribution graph.
#
# Info on timing logging in HAProxy: http://code.google.com/p/haproxy-docs/wiki/TimingEvents
#

my @timings;
@dist_breakpoints = (5,10,20,30,40,50,60,70,80,90,100,110,120,130,140,150,160,170,180,190,200);
my %dist;

foreach (@dist_breakpoints) {
	$dist{$_} = 0;
}
$dist{'Over'} = 0;

while (<>) {
	if (m#\d+/\d+/\d+/(\d+)/\d+ (\d+)#){
		next if ($2 >= 300);
		push(@timings, $1);
		$dist{get_breakpoint($1)}++;
	}
}

sort(@timings);
$total = scalar(@timings);
$med = $timings[int($total/2)];
$sum = 0;
$min = 1000;
$max = 0;
foreach (@timings) {
	$sum += $_;
	if ($_ < $min) {$min=$_;}
	if ($_ > $max) {$max=$_;}
}
$avg = int($sum / $total);

$max_count = 0;
foreach (@dist_breakpoints) {
	if ($dist{$_} > $max_count) {$max_count=$dist{$_};}
}
if ($dist{'Over'} > $max_count) {$max_count=$dist{'Over'};}

print "Total Requests: $total\n";
print "Min: $min ms\n";
print "Max: $max ms\n";
print "Med: $med ms\n";
print "Avg: $avg ms\n";
print "+----------------------\n";
print "| Latency Distribution \n";
print "+----------------------\n";

foreach (@dist_breakpoints) {
	printf("%5s: %s\n", $_, dist_line($dist{$_}, $total, $max_count));
}
printf("%5s: %s\n", 'Over', dist_line($dist{'Over'}, $total, $max_count));

sub dist_line {
	($count, $total, $max_count) = @_;
	$max_char = 100;
	$pct = ($count/$total)*100;
	$chars = ($count/$max_count)*$max_char;
	$line = '';
	foreach (0..$chars) {$line .= '#';}
	$line .= sprintf(" (%.2f%%, %s)", $pct, $count);
	return $line;
}

sub get_breakpoint {
	$val = shift;
	foreach (@dist_breakpoints) {
		if ($val < $_) {return $_;}
	}
	return 'Over';
}

sample_output.txt

# cat haproxy.log.1 | ./analyze_haproxy_performance.pl
Total Requests: 502199
Min: 0 ms
Max: 2563 ms
Med: 5 ms
Avg: 14 ms
+----------------------
| Latency Distribution
+----------------------
    5: ##################################################################################### (33.33%, 167369)
   10: ##################################################################################################### (39.40%, 197883)
   20: ##### (1.77%, 8887)
   30: ###### (1.98%, 9937)
   40: #################### (7.59%, 38097)
   50: ################################### (13.71%, 68852)
   60: ##### (1.71%, 8605)
   70: # (0.35%, 1733)
   80: # (0.08%, 406)
   90: # (0.02%, 124)
  100: # (0.02%, 104)
  110: # (0.01%, 73)
  120: # (0.01%, 36)
  130: # (0.01%, 38)
  140: # (0.00%, 12)
  150: # (0.00%, 3)
  160: # (0.00%, 4)
  170: # (0.00%, 7)
  180: # (0.00%, 0)
  190: # (0.00%, 1)
  200: # (0.00%, 2)
 Over: # (0.01%, 26)

Awesome tool, thanks a lot. It was very useful to debug some issues.