#!/usr/bin/perl
#
#    analyze_postgresql analyzes statement run times from the PostgreSQL 8.3/8.4/9.0
#    server log, when statement and duration logging is enabled.
#    Copyright (C) 2011  Erik G. Burrows
#
#    This program is free software; you can redistribute it and/or modify
#    it under the terms of the GNU General Public License as published by
#    the Free Software Foundation; either version 2 of the License, or
#    (at your option) any later version.
#
#    This program is distributed in the hope that it will be useful,
#    but WITHOUT ANY WARRANTY; without even the implied warranty of
#    MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
#    GNU General Public License for more details.
#
#    You should have received a copy of the GNU General Public License
#    along with this program; if not, write to the Free Software
#    Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA  02111-1307  USA
#

#
# To use:
#    1. In your postgresql.conf file, set log_min_duration_statement > 0.
#    2. Run analyze script as ./analyze_postgresql.pl < logfile
#
# The most time consuming statements will be displayed, sorted by "cost" descending.
# Statement "cost" is computed by multiplying the average statement run time by the
# number of times it was executed.
#
# For purposes of accounting, when parsing statements, all numbers are converted to
# 1234, and all quoted strings are converted to 'foo'. This allows statements
# varying only with specified data to be counted together.

%statements = ();
$limit_display = 30;

$cur_sql = "";
$cur_time = 0;

while(<STDIN>) {
    if (/^\d\d\d\d-\d\d-\d\d \d\d\:\d\d\:\d\d [A-Z,0-9,\-]{3}/) {

	if ($cur_sql) {
	    add_statement($cur_sql, $cur_time);
	    $cur_sql = "";
	}

	if (/^\d\d\d\d-\d\d-\d\d \d\d\:\d\d\:\d\d [A-Z,0-9,\-]{3} LOG\:\s+ duration\: ([0-9,\.]+) ms\s+ statement\:\s*(.*)$/) {

	    $cur_sql = $2;
	    $cur_time = $1;
	
	}

    } else {
	$cur_sql .= $_;
    }
}

foreach $sql (keys(%statements)) {
    $total = 0;

    foreach (@{$statements{$sql}->{"times"}}) {
	$total += $_;
    }

    $statements{$sql}->{"average"} = $total / $statements{$sql}->{"count"};
}

$i = 0;
foreach $sql (sort({$statements{$b}->{"count"} * $statements{$b}->{"average"} <=> $statements{$a}->{"count"} * $statements{$a}->{"average"} } keys(%statements))) {
    ++$i;

    if ($i > $limit_display) {
	last;
    }

    print $statements{$sql}->{"count"} . " x " . (int($statements{$sql}->{"average"}) / 1000) . " (" . (int($statements{$sql}->{"count"} * $statements{$sql}->{"average"}) / 1000) . ") $sql\n";
}

sub scrub {
    ($_) = @_;

    s/\'\'//g;
    s/\'.*?\'/\'foo\'/g;
    s/\d+/1234/g;

    return $_;
}

sub add_statement {
    my($sql, $time) = @_;

    $sql = scrub($sql);

    if (! defined $statements{$sql}) {

	$statements{$sql} = {
			     sql => $sql,
			     times => [],
			     count => 0
			     };
    }

    ++$statements{$sql}->{"count"};
	    
    push(@{$statements{$sql}->{"times"}}, $time);
}