That EXPLAIN ANALYZE patch still needs work - Mailing list pgsql-hackers

From Tom Lane
Subject That EXPLAIN ANALYZE patch still needs work
Date
Msg-id 9727.1149562953@sss.pgh.pa.us
Whole thread Raw
Responses Re: That EXPLAIN ANALYZE patch still needs work  (Martijn van Oosterhout <kleptog@svana.org>)
List pgsql-hackers
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


pgsql-hackers by date:

Previous
From: ITAGAKI Takahiro
Date:
Subject: fillfactor using WITH syntax
Next
From: Tom Lane
Date:
Subject: Re: fillfactor using WITH syntax