The following bug has been logged on the website:
Bug reference: 6513
Logged by: Maxim Boguk
Email address: maxim.boguk@gmail.com
PostgreSQL version: 9.0.7
Operating system: Linux
Description:=20=20=20=20=20=20=20=20
I got hit by that bug when explored reasons of one very slow production
query again.=20
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=3D# drop table if exists test;
DROP TABLE
Time: 277.926 ms
pgsql=3D# 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=3D# 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=3D7) - wrong value
pgsql=3D# EXPLAIN (analyze, costs, buffers) select * from test;
QUERY PLAN
---------------------------------------------------------------------------=
---------------------------
Seq Scan on test (cost=3D0.00..10.70 rows=3D1000 width=3D36) (actual
time=3D0.020..1.656 rows=3D1000 loops=3D1)
Buffers: shared hit=3D7
Total runtime: 3.252 ms
(3 rows)
Time: 3.704 ms
--again wrong
pgsql=3D# EXPLAIN (analyze, costs, buffers) select value from test;
QUERY PLAN
---------------------------------------------------------------------------=
---------------------------
Seq Scan on test (cost=3D0.00..10.70 rows=3D1000 width=3D32) (actual
time=3D0.013..1.625 rows=3D1000 loops=3D1)
Buffers: shared hit=3D7
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=3D4700 - real value)
pgsql=3D# EXPLAIN (analyze, costs, buffers) select value||'a' from test;
QUERY PLAN
---------------------------------------------------------------------------=
-----------------------------
Seq Scan on test (cost=3D0.00..13.20 rows=3D1000 width=3D32) (actual
time=3D0.264..187.855 rows=3D1000 loops=3D1)
Buffers: shared hit=3D4700
Total runtime: 189.696 ms
(3 rows)
Time: 190.001 ms
--actual timings of the both queries the same.
pgsql=3D# \o /dev/null
pgsql=3D# select * from test;
Time: 219.845 ms
pgsql=3D# \o /dev/null
pgsql=3D# 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.