Does EXPLAIN ANALYZE show a wrong plan for MIN/MAX?
Hi,
I've noticed that sometimes EXPLAIN ANALYZE is much slower than the
plain query. After investigating I found that it happens when using MIN
or MAX aggregates.
It seems that the plan outputted is not the optimized one (available
since 8.1) that is really used when running the plain query.
I.e. this is about 14 times slower:
db=> SELECT min(t_stamp) FROM stats;
min
------------------------
2005-01-14 17:43:59+01
(1 row)
Time: 2206.841 ms
========
db=> EXPLAIN ANALYZE SELECT min(t_stamp) FROM stats;
QUERY PLAN
-----------------------------------------------------------------------------------------------------------------------------------------
Aggregate (cost=65461.73..65461.74 rows=1 width=8) (actual
time=30692.485..30692.488 rows=1 loops=1)
-> Append (cost=0.00..59648.38 rows=2325338 width=8) (actual
time=0.043..22841.814 rows=2325018 loops=1)
-> Seq Scan on stats (cost=0.00..13.20 rows=320 width=8)
(actual time=0.004..0.004 rows=0 loops=1)
-> Seq Scan on stats_200501 stats (cost=0.00..1.30 rows=30
width=8) (actual time=0.030..0.132 rows=30 loops=1)
-> Seq Scan on stats_200502 stats (cost=0.00..117.81
rows=4581 width=8) (actual time=0.055..16.635 rows=4581 loops=1)
-> Seq Scan on stats_200503 stats (cost=0.00..333.05
rows=12905 width=8) (actual time=0.108..46.866 rows=12905 loops=1)
-> Seq Scan on stats_200504 stats (cost=0.00..805.40
rows=31140 width=8) (actual time=0.212..113.868 rows=31140 loops=1)
-> Seq Scan on stats_200505 stats (cost=0.00..5432.80
rows=211580 width=8) (actual time=1.394..767.939 rows=211580 loops=1)
-> Seq Scan on stats_200506 stats (cost=0.00..9533.68
rows=371768 width=8) (actual time=2.870..1352.216 rows=371768 loops=1)
-> Seq Scan on stats_200507 stats (cost=0.00..9467.76
rows=369176 width=8) (actual time=2.761..1348.064 rows=369176 loops=1)
-> Seq Scan on stats_200508 stats (cost=0.00..6023.04
rows=234804 width=8) (actual time=1.537..853.712 rows=234804 loops=1)
-> Seq Scan on stats_200509 stats (cost=0.00..11600.68
rows=452568 width=8) (actual time=3.608..1644.433 rows=452568 loops=1)
-> Seq Scan on stats_200510 stats (cost=0.00..16318.62
rows=636462 width=8) (actual time=5.367..2329.015 rows=636462 loops=1)
-> Seq Scan on stats_200511 stats (cost=0.00..1.04 rows=4
width=8) (actual time=0.028..0.041 rows=4 loops=1)
Total runtime: 30692.627 ms
(15 rows)
Time: 30694.357 ms
=========
Best regards
--
Matteo Beccati
http://phpadsnew.com
http://phppgads.com
Hi all, I just installed PostgreSQL 8.1 win32 and didn't find option to
install contrib/xml2, is it available on win32? Shall I build it on my own?
Thanks in advance
Paolo
On Fri, Nov 11, 2005 at 11:05:45AM +0100, Matteo Beccati wrote:
Hi,
I've noticed that sometimes EXPLAIN ANALYZE is much slower than the
plain query. After investigating I found that it happens when using MIN
or MAX aggregates.It seems that the plan outputted is not the optimized one (available
since 8.1) that is really used when running the plain query.
It may also be that the overhead of calling gettimeofday() several
times per tuple is blowing the time out. What platform is this?
Hope this helps,
--
Martijn van Oosterhout <kleptog@svana.org> http://svana.org/kleptog/
Show quoted text
Patent. n. Genius is 5% inspiration and 95% perspiration. A patent is a
tool for doing 5% of the work and then sitting around waiting for someone
else to do the other 95% so you can sue them.
Martijn van Oosterhout wrote:
I've noticed that sometimes EXPLAIN ANALYZE is much slower than the
plain query. After investigating I found that it happens when using MIN
or MAX aggregates.It seems that the plan outputted is not the optimized one (available
since 8.1) that is really used when running the plain query.It may also be that the overhead of calling gettimeofday() several
times per tuple is blowing the time out. What platform is this?
FreeBSD 5.4-RELEASE on an HP DL380 G4.
I've also tried to do the same on another machine which has 8.0.3 and
FreeBSD 4.9-RELEASE-p3: times for the same query are 15s vs 63s with
EXPLAIN ANALYZE. Of course I know 8.0 doesn't optimize min/max the same
way 8.1 does.
Hope this helps.
Best regards
--
Matteo Beccati
http://phpadsnew.com
http://phppgads.com
Martijn van Oosterhout <kleptog@svana.org> writes:
On Fri, Nov 11, 2005 at 11:05:45AM +0100, Matteo Beccati wrote:
It seems that the plan outputted is not the optimized one (available
since 8.1) that is really used when running the plain query.
It may also be that the overhead of calling gettimeofday() several
times per tuple is blowing the time out. What platform is this?
Martijn's explanation is by far the more probable. The high overhead
of EXPLAIN ANALYZE has been documented before.
regards, tom lane
Tom Lane wrote:
Martijn van Oosterhout <kleptog@svana.org> writes:
On Fri, Nov 11, 2005 at 11:05:45AM +0100, Matteo Beccati wrote:
It seems that the plan outputted is not the optimized one (available
since 8.1) that is really used when running the plain query.It may also be that the overhead of calling gettimeofday() several
times per tuple is blowing the time out. What platform is this?Martijn's explanation is by far the more probable. The high overhead
of EXPLAIN ANALYZE has been documented before.
OK, I've had the same explaination on IRC by dennisb, but I thought it
was strange to have a 15x slowdown.
So, does benchmarking queries using explain analyze lead to unreliable
results? Shouldn't a min/max query use a index scan when possible?
Best regards
--
Matteo Beccati
http://phpadsnew.com
http://phppgads.com