Just got this rather surprising result:
regression=# \timing
Timing is on.
regression=# explain analyze select * from tenk1 a join tenk1 b on a.unique1 = b.unique2;
QUERY PLAN
--------------------------------------------------------------------------------------------------------------------------Hash
Join (cost=825.00..2484.00 rows=10000 width=488) (actual time=250.510..2557.129 rows=10000 loops=1) Hash Cond:
(a.unique1= b.unique2) -> Seq Scan on tenk1 a (cost=0.00..458.00 rows=10000 width=244) (actual time=0.084..30.070
rows=10000loops=1) -> Hash (cost=458.00..458.00 rows=10000 width=244) (actual time=250.242..250.242 rows=10000
loops=1) -> Seq Scan on tenk1 b (cost=0.00..458.00 rows=10000 width=244) (actual time=0.019..23.317 rows=10000
loops=1)Totalruntime: 847.855 ms
(6 rows)
Time: 856.179 ms
regression=#
The "Total runtime" is correct AFAICT, which puts the top node's "actual
time" rather far out in left field. This is pretty repeatable on my old
slow HPPA machine. A new Xeon shows less of a discrepancy, but it's
still claiming top node actual > total, which is not right.
I realize that the sampling code can't be expected to be exactly right,
but a factor-of-three error is not acceptable. One of us broke this :-(
regards, tom lane