Weird waste time when UNION ALL to an empty result set
Based on this article ( http://thenoyes.com/littlenoise/?p=167 ) I was
trying to make the same in Pg to
see the effects (pg 9.1.1).
I found this:
postgres=# explain(buffers true, costs true, analyze true ) select i
from random_values;
QUERY PLAN
--------------------------------------------------------------------------------------------------------------------------
Seq Scan on random_values (cost=0.00..16897.00 rows=1000000 width=4)
(actual time=0.362..2804.651 rows=1000000 loops=1)
Buffers: shared hit=576 read=6321
Total runtime: 5340.656 ms
(3 rows)
Time: 5342.060 ms
postgres=# explain (buffers true, costs true, analyze true ) (select i
from random_values) UNION ALL (SELECT NULL LIMIT 0);
QUERY PLAN
--------------------------------------------------------------------------------------------------------------------------------------
Result (cost=0.00..16897.02 rows=1000001 width=4) (actual
time=0.203..13160.797 rows=1000000 loops=1)
Buffers: shared hit=608 read=6289
-> Append (cost=0.00..16897.02 rows=1000001 width=4) (actual
time=0.196..7925.918 rows=1000000 loops=1)
Buffers: shared hit=608 read=6289
-> Seq Scan on random_values (cost=0.00..16897.00
rows=1000000 width=4) (actual time=0.190..2852.144 rows=1000000
loops=1)
Buffers: shared hit=608 read=6289
-> Limit (cost=0.00..0.01 rows=1 width=0) (actual
time=0.007..0.007 rows=0 loops=1)
-> Result (cost=0.00..0.01 rows=1 width=0) (never executed)
Total runtime: 15680.066 ms
(9 rows)
Time: 15681.999 ms
10 seconds to UNION *nothing*? Is an expected behavior?
--
--
Emanuel Calvo
Helpame.com
Emanuel Calvo <postgres.arg@gmail.com> writes:
postgres=# explain (buffers true, costs true, analyze true ) (select i
from random_values) UNION ALL (SELECT NULL LIMIT 0);
QUERY PLAN
--------------------------------------------------------------------------------------------------------------------------------------
Result (cost=0.00..16897.02 rows=1000001 width=4) (actual
time=0.203..13160.797 rows=1000000 loops=1)
Buffers: shared hit=608 read=6289
-> Append (cost=0.00..16897.02 rows=1000001 width=4) (actual
time=0.196..7925.918 rows=1000000 loops=1)
Buffers: shared hit=608 read=6289
-> Seq Scan on random_values (cost=0.00..16897.00
rows=1000000 width=4) (actual time=0.190..2852.144 rows=1000000
loops=1)
Buffers: shared hit=608 read=6289
-> Limit (cost=0.00..0.01 rows=1 width=0) (actual
time=0.007..0.007 rows=0 loops=1)
-> Result (cost=0.00..0.01 rows=1 width=0) (never executed)
Total runtime: 15680.066 ms
(9 rows)
10 seconds to UNION *nothing*? Is an expected behavior?
I'm inclined to read this result as showing that EXPLAIN ANALYZE has
very high per-node overhead on your machine. That is not too uncommon
on machines that don't have any way to read the clock without a kernel
call. You might try comparing straight execution times (without
using EXPLAIN) to get a clearer idea of how much it costs to pass data
through Append/Result. (It's not free, no.)
regards, tom lane
2011/11/10 Tom Lane <tgl@sss.pgh.pa.us>:
Emanuel Calvo <postgres.arg@gmail.com> writes:
postgres=# explain (buffers true, costs true, analyze true ) (select i
from random_values) UNION ALL (SELECT NULL LIMIT 0);
QUERY PLAN
--------------------------------------------------------------------------------------------------------------------------------------
Result (cost=0.00..16897.02 rows=1000001 width=4) (actual
time=0.203..13160.797 rows=1000000 loops=1)
Buffers: shared hit=608 read=6289
-> Append (cost=0.00..16897.02 rows=1000001 width=4) (actual
time=0.196..7925.918 rows=1000000 loops=1)
Buffers: shared hit=608 read=6289
-> Seq Scan on random_values (cost=0.00..16897.00
rows=1000000 width=4) (actual time=0.190..2852.144 rows=1000000
loops=1)
Buffers: shared hit=608 read=6289
-> Limit (cost=0.00..0.01 rows=1 width=0) (actual
time=0.007..0.007 rows=0 loops=1)
-> Result (cost=0.00..0.01 rows=1 width=0) (never executed)
Total runtime: 15680.066 ms
(9 rows)10 seconds to UNION *nothing*? Is an expected behavior?
I'm inclined to read this result as showing that EXPLAIN ANALYZE has
very high per-node overhead on your machine. That is not too uncommon
on machines that don't have any way to read the clock without a kernel
call. You might try comparing straight execution times (without
using EXPLAIN) to get a clearer idea of how much it costs to pass data
through Append/Result. (It's not free, no.)
Well, you are right. I'd executed without explain and the timing is
not highly different.
Thanks for the "EXPLAIN" !
--
--
Emanuel Calvo
Helpame.com