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

On Thu, Jun 08, 2006 at 04:58:07PM -0400, Tom Lane wrote:
> Simon Riggs <simon@2ndquadrant.com> writes:
> > So the timing is clearly responsible for the additional time I'm
> > personally experiencing and very likely to be that for others also.
> 
> Well, that's certainly unsurprising, but the question is why it's such
> a large overhead for you when it's not on other apparently-similar kit.
> 
> If anyone else is still following this discussion, could you try the
> test case Simon gave a bit earlier (select count(*) from 100000-row
> table, check \timing with and without explain analyze)?  If we could get
> a clearer picture of which platforms show the problem and which don't,
> maybe we could make some progress.
> 
> (BTW, I just tried it on my Apple Powerbook G4, and got results in line
> with what I get elsewhere.  So I've now tried it on three very different
> CPU types and OSes, and not duplicated Simon's problem on any of them.)

CPU: AMD Athlon(tm) 64 Processor 3500+ (2210.20-MHz K8-class CPU)
8.1.3 on amd64-portbld-freebsd6.0   25ms    353ms

CPU: AMD Opteron(tm) Processor 244 (1792.50-MHz K8-class CPU) (dual CPU)
8.1.4 on amd64-portbld-freebsd6.0   31ms    295ms

Powerbook G4 1.33GHz
8.1.4 on powerpc-apple-darwin8.6.0  5.1s    5.8s*

The powerbook tests were not very repeatable at 100,000 rows, so I
bumped up to 1M. The results still aren't very repeatable...
decibel=# select count(*) from i; count  
---------1000000
(1 row)

Time: 4914.604 ms
decibel=# select count(*) from i; count  
---------1000000
(1 row)

Time: 5186.516 ms
decibel=# select count(*) from i; count  
---------1000000
(1 row)

Time: 5174.418 ms
decibel=# explain analyze select count(*) from i;                                                   QUERY PLAN
                                          
 

-------------------------------------------------------------------------------------------------------------------Aggregate
(cost=16905.05..16905.06 rows=1 width=0) (actual time=5729.623..5729.624 rows=1 loops=1)  ->  Seq Scan on i
(cost=0.00..14405.24rows=999924 width=0) (actual time=0.155..4039.317 rows=1000000 loops=1)Total runtime: 5729.907 ms
 
(3 rows)

Time: 5732.076 ms
decibel=# explain analyze select count(*) from i;                                                   QUERY PLAN
                                          
 

-------------------------------------------------------------------------------------------------------------------Aggregate
(cost=16905.05..16905.06 rows=1 width=0) (actual time=5916.025..5916.026 rows=1 loops=1)  ->  Seq Scan on i
(cost=0.00..14405.24rows=999924 width=0) (actual time=0.157..4246.123 rows=1000000 loops=1)Total runtime: 5916.261 ms
 
(3 rows)

Time: 5922.542 ms
decibel=# explain analyze select count(*) from i;                                                   QUERY PLAN
                                          
 

-------------------------------------------------------------------------------------------------------------------Aggregate
(cost=16905.05..16905.06 rows=1 width=0) (actual time=5800.788..5800.789 rows=1 loops=1)  ->  Seq Scan on i
(cost=0.00..14405.24rows=999924 width=0) (actual time=0.152..4126.781 rows=1000000 loops=1)Total runtime: 5801.026 ms
 
(3 rows)

Time: 5803.070 ms
decibel=# explain analyze select count(*) from i;                                                   QUERY PLAN
                                          
 

-------------------------------------------------------------------------------------------------------------------Aggregate
(cost=16905.05..16905.06 rows=1 width=0) (actual time=5994.285..5994.286 rows=1 loops=1)  ->  Seq Scan on i
(cost=0.00..14405.24rows=999924 width=0) (actual time=0.156..4341.463 rows=1000000 loops=1)Total runtime: 5994.520 ms
 
(3 rows)

Time: 5996.577 ms
-- 
Jim C. Nasby, Sr. Engineering Consultant      jnasby@pervasive.com
Pervasive Software      http://pervasive.com    work: 512-231-6117
vcard: http://jim.nasby.net/pervasive.vcf       cell: 512-569-9461