Re: weird execution plan

From: "Huang, Suya" <Suya(dot)Huang(at)au(dot)experian(dot)com>
To: David G Johnston <david(dot)g(dot)johnston(at)gmail(dot)com>, "pgsql-performance(at)postgresql(dot)org" <pgsql-performance(at)postgresql(dot)org>
Subject: Re: weird execution plan
Date: 2014-09-12 03:41:08
Message-ID: D83E55F5F4D99B4A9B4C4E259E6227CD01EBF0B6@AUX1EXC02.apac.experian.local
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-performance

-----Original Message-----
From: pgsql-performance-owner(at)postgresql(dot)org [mailto:pgsql-performance-owner(at)postgresql(dot)org] On Behalf Of David G Johnston
Sent: Friday, September 12, 2014 12:45 PM
To: pgsql-performance(at)postgresql(dot)org
Subject: Re: [PERFORM] weird execution plan

Huang, Suya wrote
> Can someone figure out why the first query runs so slow comparing to
> the second one? They generate the same result...

Try: EXPLAIN (ANALYZE, BUFFERS)

I believe you are only seeing caching effects.

David J.

--
View this message in context: http://postgresql.1045698.n5.nabble.com/weird-execution-plan-tp5818730p5818733.html
Sent from the PostgreSQL - performance mailing list archive at Nabble.com.

--
Sent via pgsql-performance mailing list (pgsql-performance(at)postgresql(dot)org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-performance

=================================================================================================================
Both queries have been run several times so cache would have same effect on both of them? Below is the plan with buffer information.

dev=# explain (ANALYZE, BUFFERS) with x as (select distinct wid from terms_weekly_20140503 a join port_terms b on a.term=b.terms) select count(*) from x;
QUERY PLAN
------------------------------------------------------------------------------------------------------------------------------------------------------------------
Aggregate (cost=2226187.62..2226187.63 rows=1 width=0) (actual time=3533.998..3533.999 rows=1 loops=1)
Buffers: shared hit=86752 read=68837
CTE x
-> HashAggregate (cost=2226181.12..2226183.12 rows=200 width=516) (actual time=3383.700..3448.554 rows=212249 loops=1)
Buffers: shared hit=86752 read=68837
-> Hash Join (cost=37.67..2095240.22 rows=52376358 width=516) (actual time=0.799..3010.906 rows=1067696 loops=1)
Hash Cond: (a.term = b.terms)
Buffers: shared hit=86752 read=68837
-> Seq Scan on terms_weekly_20140503 a (cost=0.00..240738.81 rows=8516481 width=548) (actual time=0.023..1277.352 rows=8516481 loops=1)
Buffers: shared hit=86739 read=68835
-> Hash (cost=22.30..22.30 rows=1230 width=32) (actual time=0.699..0.699 rows=1000 loops=1)
Buckets: 1024 Batches: 1 Memory Usage: 51kB
Buffers: shared hit=7
-> Seq Scan on port_terms b (cost=0.00..22.30 rows=1230 width=32) (actual time=0.009..0.270 rows=1000 loops=1)
Buffers: shared hit=7
-> CTE Scan on x (cost=0.00..4.00 rows=200 width=0) (actual time=3383.707..3518.884 rows=212249 loops=1)
Buffers: shared hit=86752 read=68837
Total runtime: 3541.277 ms
(18 rows)

Time: 3552.505 ms
dev=# explain (analyze,buffers) select count(distinct w_id) from terms_weekly_20140503 a join port_terms b on a.term=b.terms;
QUERY PLAN
---------------------------------------------------------------------------------------------------------------------------------------------------------
Aggregate (cost=2226181.12..2226181.13 rows=1 width=516) (actual time=18914.881..18914.882 rows=1 loops=1)
Buffers: shared hit=155589
-> Hash Join (cost=37.67..2095240.22 rows=52376358 width=516) (actual time=0.802..2616.410 rows=1067696 loops=1)
Hash Cond: (a.term = b.terms)
Buffers: shared hit=155589
-> Seq Scan on terms_weekly_20140503 a (cost=0.00..240738.81 rows=8516481 width=548) (actual time=0.010..966.380 rows=8516481 loops=1)
Buffers: shared hit=155574
-> Hash (cost=22.30..22.30 rows=1230 width=32) (actual time=0.729..0.729 rows=1000 loops=1)
Buckets: 1024 Batches: 1 Memory Usage: 51kB
Buffers: shared hit=7
-> Seq Scan on port_terms b (cost=0.00..22.30 rows=1230 width=32) (actual time=0.009..0.300 rows=1000 loops=1)
Buffers: shared hit=7
Total runtime: 18914.933 ms
(13 rows)

Time: 18915.712 ms

In response to

Responses

Browse pgsql-performance by date

  From Date Subject
Next Message David G Johnston 2014-09-12 21:34:28 Re: weird execution plan
Previous Message Huang, Suya 2014-09-12 03:33:42 Re: how to change the provoke table in hash join