Review of: pg_stat_statements with query tree normalization

From: Daniel Farina <daniel(at)heroku(dot)com>
To: pgsql-hackers <pgsql-hackers(at)postgresql(dot)org>, Peter Geoghegan <peter(at)2ndquadrant(dot)com>
Subject: Review of: pg_stat_statements with query tree normalization
Date: 2012-01-15 11:41:55
Message-ID: CAAZKuFYKRku9SHaarCrVxm-AN0=rBD3yD8_+REia4mFzG5gcyA@mail.gmail.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-hackers

I've *finally* gotten around to reviewing this patch.

My first step was to de-bitrot it very slightly. More on that in a moment.

After that, I tried using it. Installation worked nicely -- I did
CREATE EXTENSION and then tried reading from pg_stat_statements. I
was then given an error message to add pg_stat_statements into
shared_preload_libraries, and so I did. Given its use of shared
memory, there is not much other choice, but it's neat that I got it
running in just a few minutes without reading any documentation. I
ran a non-trivial but not-enormous application against the
pg_stat_statements-enabled database, and the results were immediate
and helpful, being correctly normalized and statistics apparently
accrued.

'make check' also worked fine. I ran with assertions and debugging enabled.

This query I suspect will quickly become a new crowd-pleaser:

SELECT * FROM pg_stat_statements ORDER BY total_time DESC LIMIT 20;

The output looks like this (fixed width looks best):

userid | 16385
dbid | 16386
query | SELECT * FROM lock_head($1, $2);
calls | 12843
total_time | 19.795586
rows | 8825
shared_blks_hit | 194583
shared_blks_read | 19
shared_blks_written | 0
local_blks_hit | 0
local_blks_read | 0
local_blks_written | 0
temp_blks_read | 0
temp_blks_written | 0

A couple of nit-picks: a query execution is probably not often
referred to as a "call", and total_time doesn't signify its units in
the name, but I eyeballed it to be seconds.

I cannot see superuser query text when I'm in a non-superuser role,
however, I can see the execution statistics:

userid | 10
dbid | 16386
query | <insufficient privilege>
calls | 1448
total_time | 0.696188
rows | 205616
shared_blks_hit | 13018
shared_blks_read | 14
shared_blks_written | 0
local_blks_hit | 0
local_blks_read | 0
local_blks_written | 0
temp_blks_read | 0
temp_blks_written | 0

Prepared statements are less informative, unless one knows their
naming convention:

query | execute foo;

I don't know what JDBC users or ActiveRecord 3 users are going to
think about that. However, just about everyone else will be happy.

The patch very nicely handles its intended task: folding together
queries with the same literal. This is the key feature that makes the
output really useful, and is quite unique: the next best thing I know
of is pgfouine, which uses some heuristics and needs to be run over
specially formatted logs, usually offline. This is much better, much
faster, more interactive, and much more sound when it comes to
normalizing queries.

Onto the mechanism: the patch is both a contrib and changes to
Postgres. The changes to postgres are mechanical in nature, but
voluminous. The key change is to not only remember the position of
Const nodes in the query tree, but also their length, and this change
is really extensive although repetitive. It was this swathe of change
that bitrotted the source, when new references to some flex constructs
were added. Every such reference has needs to explicitly refer to
'.begins', which is the beginning position of the const -- this used
to be the only information tracked. Because .length was never
required by postgres in the past, it fastidiously bookkeeps that
information without ever referring to it internally: only
pg_stat_statements does.

There is a performance test program (written in Python) conveniently
included in the contrib to allay fears that such const-length
bookkeeping may be too expensive. I have not run it yet myself.

There is also a regression test -- also a python program -- presumably
because it would be more difficult to test this the "normal" way via
pg_regress, at least to get a full integration test.

I'm a little surprised that pg_stat_statements.c uses direct recursion
instead of the mutually recursive walker interface, which makes it
quite a bit different than most passes in the optimizer I've seen.

I'm still looking at the mechanism in more detail, but I am having a
fairly easy time following it -- there's just a lot of it to cover the
litany of Nodes. I'll submit my editorializations of whitespace and
anti-bitrot to Peter Geoghegan via git (actually, that information is
below, for any curious onlookers). If anyone wants to play with the
this anti-bitrotted copy against a very recent master, please see:

$ git fetch https://github.com/fdr/postgres.git
pg_stat_statements_norm:pg_stat_statements_norm
$ git checkout pg_stat_statements_norm

All in all, it looks and works well, inside and out.

--
fdr

Responses

Browse pgsql-hackers by date

  From Date Subject
Next Message Peter Geoghegan 2012-01-15 12:51:39 Re: Review of: pg_stat_statements with query tree normalization
Previous Message Greg Smith 2012-01-15 09:35:18 Re: pgstat documentation tables