January 5th, 2010 by depesz | Tags: , , , , | 1 comment »
Did it help? If yes - maybe you can help me?

Today small, but (at least for me) really useful patch. Committed on 15th of December by Robert Haas, and written by Itagaki Takahiro, this patch does:

Log Message:
-----------
Add an EXPLAIN (BUFFERS) option to show buffer-usage statistics.
 
This patch also removes buffer-usage statistics from the track_counts
output, since this (or the global server statistics) is deemed to be a better
interface to this information.
 
Itagaki Takahiro, reviewed by Euler Taveira de Oliveira.

What exactly it is? Let's see:

# explain ( analyze on, buffers on ) select count(*) from pg_attribute ;
QUERY PLAN
-------------------------------------------------------------------------------------------------------------------
Aggregate (cost=64.70..64.71 rows=1 width=0) (actual time=0.466..0.466 rows=1 loops=1)
Buffers: shared hit=18 read=21
-> Seq Scan on pg_attribute (cost=0.00..59.56 rows=2056 width=0) (actual time=0.002..0.301 rows=2002 loops=1)
Buffers: shared hit=18 read=21
Total runtime: 0.492 ms
(5 rows)

As we can see, PostgreSQL had to read 39 pages from disk, 18 of which had been already in shared buffers.

Usually, when running such query for 2nd time, we should see it be a bit faster, because pages are cached. Let's see:

# explain ( analyze on, buffers on ) select count(*) from pg_attribute ;
QUERY PLAN
-------------------------------------------------------------------------------------------------------------------
Aggregate (cost=64.70..64.71 rows=1 width=0) (actual time=0.325..0.325 rows=1 loops=1)
Buffers: shared hit=39
-> Seq Scan on pg_attribute (cost=0.00..59.56 rows=2056 width=0) (actual time=0.004..0.171 rows=2002 loops=1)
Buffers: shared hit=39
Total runtime: 0.353 ms
(5 rows)

Nice. Now we see that all pages have been read from cache.

Of course using it for such simple queries doesn't make much sense, but it's just to show expected output.

When adding this capability, it was also propagated to auto explain contrib module – you can now set auto_explain.log_buffers GUC to enable it, but since it requires also ANALYZE – use with caution.

  1. One comment

  2. # comboy
    Nov 10, 2010

    I just wanted to say: Your blog is way too freaking awesome. I love every single post. I’m too lazy to write it under every one of them, but keep in mind you’re doing great work.

    And if by any chance I happen to meet you on some conference in Poland I definitely owe you some beers for time saved.

Leave a comment