comment on

This is a PostgreSQL query performance analyzer. I have used this for several years (so it's older and there are a couple things I would do differently) to find index and query parse problems. Since it just runs off the Postgres logfile (normally just sent to the bit bucket) you can use real life data, without much of a application performance loss (It shouldn't effect query time).

You should just have to reroute the log file from the /dev/null to a real file. The default logfile options should work.

The Output:

Total: gives you the total time of execution of a particular sql statement over the entire logfile, this gives a rough estimation of what you should be looking at.
Cost: comes from PostgreSQL query optimizer as the cost (based on time) to run the query. This is the Max cost of the query.
Avg: is the average cost (only really useful after changes)
IDX: IDX means an index was used for the main loop, SEQ the main loop was a Sequential scan of rows
Query: The actual query

#!/usr/bin/perl
use strict;
use warnings;
use Getopt::Long;

my $sort_fld = 'tot';
my $show = 25;
GetOptions ("show=i" => \$show, "sort=s" => \$sort_fld) || usage('Inva
+lid Option');
my $fn = $ARGV[0] || usage('Please specify a logfile');
usage("$fn does not exist") if (! -e $fn);
usage("$fn is not readable. Check permissions") if (! -r $fn);
usage("$fn is 0 size") if (-z $fn);
usage("$fn is not a regular file") if (! -f $fn);
usage('Invalid sort option') if (! ($sort_fld eq 'tot' or $sort_fld eq
+ 'avg' or $sort_fld eq 'cost'));

my ($lines ) = `wc -l $fn`;
$lines =~ s/\D+//g;
my %q;
my $get_q = 0;
my $query = '';
my $buffer = '';
open(FH,'<',$fn) or die "Could not open $fn: $!";
print "Reading file...\n";
my $cnt = 0;
while (my $line = <FH>) {
    if ($line =~/^DEBUG:  query:/){
        $get_q++;
    } elsif ($get_q and $line =~ /^DEBUG: /) {
        $query = $buffer;
        $buffer = '';
        $get_q = 0;
    }
    if ($get_q) {
        $buffer .= $line;
        $buffer =~ s/^DEBUG:  query://g;
        $buffer =~ s/\s+/ /g;
    }
    if (!$get_q and $line =~ /^\s+:total_cost\s+(\S+)/) {
        my $cost = $1;
        no warnings;
        $cost =~ s/([\d.]+)/$1/g;
        $q{$_}{cost} = 0 if ($q{$_}{cost} =~ /[^\d.]/);
        $q{$query}{cost} = $cost > $q{query}{cost} ? $cost : $q{$query
+}{cost};
        $q{$query}{tot} += $cost;
        push(@{$q{$query}{costs}},$cost);
        $q{$query}{cnt}++;
        use warnings;
    }
    $q{$query}{scan} = 'SEQ' if (!$get_q and $line =~ /^\s+{\s+SEQSCAN
+/);
    $q{$query}{scan} = 'IDX' if (!$get_q and $line =~ /^\s+{\s+INDEXSC
+AN/);

    $cnt++;
    print "Reading line: $cnt of $lines\r" if (!($cnt % 1000));
}
print "\n Cleaning...";
foreach ( keys %q ) {
    if (/pg_/){ delete $q{$_}; next } #skip internal tables
    my $tot;
    foreach my $cost (@{$q{$_}{costs}}) {
        $tot += $cost;
    }

    $q{$_}{cost} = 0 if (!$q{$_}{cost} or $q{$_}{cost} =~ /[^\d.]/);
    $tot ||= 0;
    $q{$_}{cnt} ||= 0;
    if ($q{$_}{cnt}) {
        $q{$_}{avg} = $tot / $q{$_}{cnt};
    }
    $q{$_}{avg} ||= 0;
    $q{$_}{tot} ||= 0;
}

print "\n DONE\n Sorting... ";

my @srt_keys =  sort { $q{$a}{$sort_fld} <=> $q{$b}{$sort_fld} } keys 
+%q;
@srt_keys = @srt_keys[$#srt_keys-($show-1)..$#srt_keys];

print "\n";
print " Total     Cost      Avg    IDX  Query\n";
print "-------- -------- --------  ---  ------->\n";
foreach (@srt_keys) {
    printf("%8s ",sprintf("%.3f",$q{$_}{tot}));
    printf("%8s ",sprintf("%.3f",$q{$_}{cost}));
    printf("%8s ",sprintf("%.3f",$q{$_}{avg}));
    print " $q{$_}{scan} $_\n";
}


sub usage {
    print "@_\n" if (@_);
    print "plog [--sort=tot|cost|avg] [--show=1000] /path/to/logfile\n
+";
    print "\t--sort : sort results by tot(Total Time) cost(Max Cost) o
+r avg(Average Cost)\n";
    print "\t--show : show number of lines (default: 25)\n";

    exit();
}
[download]

Some Sample Output:

 
 Total     Cost      Avg    IDX  Query
-------- -------- --------  ---  ------->
 138.780    5.140    5.140  IDX  select description from products wher
+e sku = '142-1007'
 138.780    5.140    5.140  IDX  select sale_price from products where
+ sku = '142-1007'
 143.920    5.140    5.140  IDX  select sale_price from products where
+ sku = '140-1028'
 143.920    5.140    5.140  IDX  select thumb from products where sku 
+= '00024'
 143.920    5.140    5.140  IDX  select sku from products where sku = 
+'142-1009'
 143.920    5.140    5.140  IDX  select option_type from products wher
+e sku = '140-1028'
 149.060    5.140    5.140  IDX  select gift_cert from products where 
+sku = '140-1028'
 154.700    5.950    5.950  IDX  select * from options where code = '1
+42-1007'
 154.700    5.950    5.950  IDX  select * from options where code = '1
+12-9083'
 154.700    5.950    5.950  IDX  select * from options where code = '1
+40-1028'
 164.480    5.140    5.140  IDX  select description from products wher
+e sku = '140-1028'
 185.040    5.140    5.140  IDX  select sku from products where sku = 
+'142-1011'
 231.300    5.140    5.140  IDX  select sku from products where sku = 
+'142-1035'
 233.100    3.150    3.150  IDX  SELECT o_group,price FROM options whe
+re sku = '142-1035' and price != ''
 233.100    3.150    3.150  IDX  SELECT o_group,price FROM options whe
+re sku = '142-1030' and price != ''
 246.720    5.140    5.140  IDX  select sku from products where sku = 
+'gift-cert'
 267.280    5.140    5.140  IDX  select thumb from products where sku 
+= '112-9083'
 267.280    5.140    5.140  IDX  select thumb from products where sku 
+= '140-1028'
 267.280    5.140    5.140  IDX  select thumb from products where sku 
+= '142-1007'
 287.840    5.140    5.140  IDX  select sku from products where sku = 
+'00024'
 292.830   97.610   97.610  SEQ  select * from products
[download]

grep

XP matters not. Look at me. Judge me by my XP, do you?

In reply to PostgreSQL Query Performance Analysis by grep

Posts are HTML formatted. Put <p> </p> tags around your paragraphs. Put <code> </code> tags around your code and data!

Titles consisting of a single word are discouraged, and in most cases are disallowed outright.

Read Where should I post X? if you're not absolutely sure you're posting in the right place.

Please read these before you post! —

Posts may use any of the Perl Monks Approved HTML tags:

a, abbr, b, big, blockquote, br, caption, center, col, colgroup, dd, del, details, div, dl, dt, em, font, h1, h2, h3, h4, h5, h6, hr, i, ins, li, ol, p, pre, readmore, small, span, spoiler, strike, strong, sub, summary, sup, table, tbody, td, tfoot, th, thead, tr, tt, u, ul, wbr

You may need to use entities for some characters, as follows. (Exception: Within code tags, you can put the characters literally.)

	For:		Use:
	&		`&`
	<		`<`
	>		`>`
	[		`[`
	]		`]`

Link using PerlMonks shortcuts! What shortcuts can I use for linking?

See Writeup Formatting Tips and other pages linked from there for more info.