January 13th, 2009 by depesz | Tags: , , , , , | 13 comments »
Did it help? If yes - maybe you can help me? Donate BTC to 19zPa5diT2LZqGtTi8f8bfApLn8rw9zBHx

On 4th of January, Tom Lane committed patch by Takahiro Itagaki, which adds new contrib module – pg_stat_statements:

Log Message:
-----------
Add contrib/pg_stat_statements for server-wide tracking of statement execution
statistics.
 
Takahiro Itagaki

What is it for? Well, actually, it takes some work away from projects like pgFouine or my own analyze.pgsql.logs.pl.

To this day, when you want/need to see some query statistics you have to log all queries, and then run some software that will parse it, normalize queries, and run some kind of statistics on it.

Now, the log-parse part is no longer neccessary.

This is how it works.

First, you have to modify your postgresql.conf. Open it, and find line with shared_preload_libraries parameter. Add there pg_stat_statements, like this:

shared_preload_libraries = 'pg_stat_statements' # (change requires restart)

As you can see in the comment, change here requires server restart. Before we will do it, let's add some more options to .conf file:

pg_stat_statements.max = 100
pg_stat_statements.track = top
pg_stat_statements.save = off

To make it work, we will also need to add “pg_stat_statements" to “custom_variable_classes" option, which is usually empty, but if you have one already defined, just add new one like this:

custom_variable_classes = 'depesz,pg_stat_statements' # list of custom variable class names

Afterwards, we can restart PostgreSQL.

Now, tracking is enabled, but to view stats, we have to create appropriate functions and view, by loading pg_stat_statements.sql to any database:

# \i work/share/postgresql/contrib/pg_stat_statements.sql
SET
CREATE FUNCTION
CREATE FUNCTION
CREATE VIEW
GRANT
REVOKE

( of course your path might be different ).

So, let's see how it works. First, let's check if (just after connection) the stats are empty:

# select * from pg_stat_statements;
userid | dbid | query | calls | total_time | rows
--------+------+-------+-------+------------+------
(0 rows)

So, now let's repeat last query:

# select * from pg_stat_statements;
userid | dbid | query | calls | total_time | rows
--------+-------+-----------------------------------+-------+------------+------
10 | 16389 | select * from pg_stat_statements; | 1 | 0.000131 | 0
(1 row)

Wow! It works.

Now, let's reset stats (select pg_stat_statements_reset();) and do some more tests:

(pgdba@[local]:5840) 15:42:41 [pgdba]
# select 1 + 2;
?column?
----------
3
(1 row)
 
(depesz@[local]:5840) 15:40:39 [depesz]
# select 2 + 3;
?column?
----------
5
(1 row)
 
(depesz@[local]:5840) 15:43:13 [depesz]
# select count(*) from pg_class where relkind = 'r';
count
-------
50
(1 row)

And, how do stats look like now?

# select * from pg_stat_statements;
userid | dbid | query | calls | total_time | rows
--------+-------+----------------------------------------------------+-------+------------+------
16384 | 16388 | select count(*) from pg_class where relkind = 'r'; | 1 | 0.000271 | 1
10 | 16389 | select 1 + 2; | 1 | 1.9e-05 | 1
16384 | 16388 | select 2 + 3; | 1 | 2.2e-05 | 1
10 | 16389 | select pg_stat_statements_reset(); | 1 | 3.3e-05 | 1
(4 rows)

Nice. And how does it work with prepared statements?

# select pg_stat_statements_reset();
pg_stat_statements_reset
--------------------------
 
(1 row)
 
# prepare x(int4, int4) as select $1 + $2;
PREPARE
# execute x(1,2);
?column?
----------
3
(1 row)
 
# execute x(2,3);
?column?
----------
5
(1 row)
 
(pgdba@[local]:5840) 15:45:54 [pgdba]
# prepare y(int4, int4) as select $1 + $2;
PREPARE
(pgdba@[local]:5840) 15:46:00 [pgdba]
# execute y(3,4);
?column?
----------
7
(1 row)
 
(pgdba@[local]:5840) 15:46:05 [pgdba]
# select * from pg_stat_statements;
userid | dbid | query | calls | total_time | rows
--------+-------+------------------------------------------+-------+------------+------
10 | 16389 | prepare y(int4, int4) as select $1 + $2; | 1 | 1.7e-05 | 1
10 | 16389 | select pg_stat_statements_reset(); | 1 | 3.4e-05 | 1
10 | 16389 | prepare x(int4, int4) as select $1 + $2; | 2 | 3.3e-05 | 2
(3 rows)

Interesting. It looks like “prepare" is shown to be called as many times, as it was executed. Besides this little point – it looks great.

Now. I configured pg_stat_statements to keep tabs on 100 different queries. What will happen after 100th query? Which one will be removed?

This simple one-liner will add 100 different queries:

( echo "SELECT pg_stat_statements_reset();"; for a in $( seq 1 99 ); do echo "select $a;"; done ) | psql

# select count(*) from pg_stat_statements;
count
-------
100
(1 row)

BUT the query: “select count(*) from pg_stat_statements" was also added. So some query had to be removed from pg_stat_statements. Or perhaps count(*) was not added to stats? Let's find out:

# select * from pg_stat_statements order by query;
...

Apparently, pg_stat_statements will remove random record, with lowest number of calls. I.e. if there are 100 records, each with calls = 1 – you can't find out which row will be removed from stats when new query will arrive. But, generally it's not a big issue.

To sum it up. I think that functionality of the module would be greatly enhanced if it would store queries without parameters (instead of “select 2 + 3″ -> “select $1 + $2″, or something like this) – otherwise, with real-world databases, the buffer for queries will fill up too soon, and it will not “catch" the fact that “select * from table where id = 3″ and “select * from table where id = 23″ is practically the same.

But, since there are already tools for doing this kind of analysis, this new addition (pg_stat_statements) is welcome, as it can be used with smaller systems.

  1. 13 comments

  2. # vcardenas
    Jan 13, 2009

    Thanks for explaining this, is very helpful… any hints about the impact in performance?

  3. Jan 14, 2009

    @vcardenas:
    Well, I tested it for only couple of runs of pgbench, but it looks like there is practically none overhead. I.e. technically there has to be one, but the difference of speed of pgbench was bigger because of random fluctuations of load on the machine (my laptop) than from turning on pg_stat_statements.

  4. # Thomas
    Jan 14, 2009

    Hi,

    I really love your site, but the black backround is extremely hard to read.
    Why don’t you use a white background and black font as everybody else does?

    I’m glad I can turn off CSS using Firefox so I can at least read the full article without getting a headache

  5. Jan 14, 2009

    @Thomas:
    hi,
    well, the most important reason is that I personally *hate* white backgrounds.

    Also – did you notice theme switcher in sidebar?

  6. Jan 15, 2009

    depesz,
    theme switcher switches the theme but takes you back to the main page.
    and when you click article title, it takes you to the article but switches the theme back to the default.
    (debian/firefox3)

  7. # Ptomaine
    Jan 16, 2009

    I think you should add an extra timestamp column to your stats table so that you can remove the oldest records first instead of random ones. Moreover, this column could be very useful for stats info (e.g. how much time did elapse between the first and last statement of a block of statements?).

  8. Jan 16, 2009

    @Ptomaine:
    sorry, but what “my” stats table?

    if you mean pg_stat_statements – it’s not mine – it’s postgresql, and the suggestion might be sensible to send to pg-general, or even pg-bugs mailing list.

  9. Mar 15, 2009

    Hello, Hubert. Seems like there’s a misunderstanding. It will “catch” the fact that “select * from table where id = 3″ and “select * from table where id = 23″ is practically the same. Look at the end of the document
    http://developer.postgresql.org/pgdocs/postgres/pgstatstatements.html

  10. Mar 15, 2009

    @Sergey Konoplev:
    Unfortunately it’s not the case. Please check this:

    create table x (i int4);

    insert into x (i) select generate_series(1,10);

    select * from x where i = 1;

    select * from x where i = 2;

    # select * from pg_stat_statements;
    userid | dbid | query | calls | total_time | rows
    --------+-------+-------------------------------------------------+-------+------------+------
    16384 | 16390 | select * from x where i = 1; | 1 | 5.6e-05 | 1
    16384 | 16390 | insert into x (i) select generate_series(1,10); | 1 | 0.000294 | 10
    16384 | 16390 | select * from x where i = 2; | 1 | 4.4e-05 | 1
    (3 rows)

    it works in this was with prepared statements, but not with typed-in queries.

  11. # zhle521
    Oct 10, 2011

    well, i want use this interesting stat tool in 8.3.7, but only support on 8.4. How i can do this?

  12. Oct 10, 2011

    @zhle521:
    upgrade postgresql to newer version.

    or extract the patch from git repository, and try to modify it so it will be possible to apply on 8.3 source tree.

  13. # zhle521
    Oct 11, 2011

    thks, i try, but too many dependencies on new version source,. So, i gave it up and found another solution to the problem.

  14. # Andrew Hammond
    Jan 4, 2012

    If you’re using a newer version of PostgreSQL, rather than the old-fashioned way of loading this extension:

    \i work/share/postgresql/contrib/pg_stat_statements.sql
    

    Use instead the new CREATE EXTENSION feature.

    CREATE EXTENSION pg_stat_statements
    

    This has tab-completion support and is a quick way to see what extensions are included in your build / package.

Leave a comment