Skip site navigation (1) Skip section navigation (2)

BUG #6513: explain (analyze, buffers) and toasted fields

From: maxim(dot)boguk(at)gmail(dot)com
To: pgsql-bugs(at)postgresql(dot)org
Subject: BUG #6513: explain (analyze, buffers) and toasted fields
Date: 2012-03-05 04:22:54
Message-ID: E1S4PRm-0005pG-H0@wrigleys.postgresql.org (view raw or flat)
Thread:
Lists: pgsql-bugs
The following bug has been logged on the website:

Bug reference:      6513
Logged by:          Maxim Boguk
Email address:      maxim(dot)boguk(at)gmail(dot)com
PostgreSQL version: 9.0.7
Operating system:   Linux
Description:        

I got hit by that bug when explored reasons of one very slow production
query again. 
And I lost a lot time trying reproduce the problem query on production
server with explain analyze.
Finally I found I need some workaround to get explain perform actual work
with toasted data.

So there is going the bug report:
EXPLAIN do not take into account that some result fields will require
detoasting and produce wrong buffers result.

Test case:

pgsql=# drop table if exists test;
DROP TABLE
Time: 277.926 ms
pgsql=# CREATE TABLE test (id integer primary key, value text);
NOTICE:  CREATE TABLE / PRIMARY KEY will create implicit index "test_pkey"
for table "test"
CREATE TABLE
Time: 3.812 ms
--populate table with large toasted field
pgsql=# INSERT INTO test select i,(select array_agg(random()) from
generate_series (1,1000))::text from generate_series (1,1000) as g(i);
INSERT 0 1000
Time: 3176.286 ms

--wrong explain value at least for the buffers value... and whats even worse
wrong (100x less that would be actual) runtime
--(Buffers: shared hit=7) - wrong value
pgsql=# EXPLAIN (analyze, costs, buffers) select * from test;
                                              QUERY PLAN
------------------------------------------------------------------------------------------------------
 Seq Scan on test  (cost=0.00..10.70 rows=1000 width=36) (actual
time=0.020..1.656 rows=1000 loops=1)
   Buffers: shared hit=7
 Total runtime: 3.252 ms
(3 rows)
Time: 3.704 ms

--again wrong
pgsql=# EXPLAIN (analyze, costs, buffers) select value from test;
                                              QUERY PLAN
------------------------------------------------------------------------------------------------------
 Seq Scan on test  (cost=0.00..10.70 rows=1000 width=32) (actual
time=0.013..1.625 rows=1000 loops=1)
   Buffers: shared hit=7
 Total runtime: 3.141 ms
(3 rows)
Time: 3.428 ms

--force take detoasting into account via || with toasted field
--result close to reality (Buffers: shared hit=4700 - real value)
pgsql=# EXPLAIN (analyze, costs, buffers) select value||'a' from test;
                                               QUERY PLAN
--------------------------------------------------------------------------------------------------------
 Seq Scan on test  (cost=0.00..13.20 rows=1000 width=32) (actual
time=0.264..187.855 rows=1000 loops=1)
   Buffers: shared hit=4700
 Total runtime: 189.696 ms
(3 rows)
Time: 190.001 ms

--actual timings of the both queries the same.
pgsql=# \o /dev/null
pgsql=# select * from test;
Time: 219.845 ms
pgsql=# \o /dev/null
pgsql=# select value||'a' from test;
Time: 221.599 ms

Having correct buffer hit/read values could be critical when toasted fields
are likely to be read from the HDD.




Responses

pgsql-bugs by date

Next:From: sanker.ksDate: 2012-03-05 05:41:15
Subject: BUG #6514: mount data folder in remote location
Previous:From: Magnus HaganderDate: 2012-03-04 13:13:38
Subject: Re: BUG #6502: Missing Link at Version Tracker

Privacy Policy | About PostgreSQL
Copyright © 1996-2014 The PostgreSQL Global Development Group