pg.ddx.io  pgsql-performance@postgresql.org mailing list archive  
help / color / mirror / Atom feed
Very slow inner join query Unacceptable latency.
13+ messages / 5 participants
[nested] [flat]

* Very slow inner join query Unacceptable latency.
@ 2013-05-21 21:53 fburgess@radiantblue.com
  2013-05-21 21:59 ` Re: Very slow inner join query Unacceptable latency. Jaime Casanova <jaime@2ndquadrant.com>
  2013-05-22 05:57 ` Re: Very slow inner join query Unacceptable latency. Amit Kapila <amit.kapila@huawei.com>
  0 siblings, 2 replies; 13+ messages in thread

From: fburgess@radiantblue.com @ 2013-05-21 21:53 UTC (permalink / raw)
  To: pgsql-performance; +Cc: pgsql-general@postgresql.org

<html><body><span style="font-family:Verdana; color:#000000; font-size:10pt;"><div>The SARS_ACTS table currently has 37,115,515 rows<br><br>we have indexed: idx_sars_acts_acts_run_id ON SARS_ACTS USING btree (sars_run_id)<br>we have pk constraint on the SARS_ACTS_RUN table; sars_acts_run_pkey PRIMARY KEY (id )<br><br>serverdb=# explain select count(*) as y0_ from SARS_ACTS this_ inner join SARS_ACTS_RUN tr1_ on this_.SARS_RUN_ID=<a href="http://tr1_.ID">tr1_.ID</a; where tr1_.ALGORITHM='SMAT';<br>&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; QUERY PLAN<br>--------------------------------------------------------------------------------------------------------------------------<br>Aggregate&nbsp; (cost=4213952.17..4213952.18 rows=1 width=0)<br>&nbsp; -&gt; Hash Join&nbsp; (cost=230573.06..4213943.93 rows=3296 width=0)<br>&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; Hash Cond:&nbsp; (this_.SARS_RUN_ID=<a href="http://tr1_.ID">tr1_.ID</a>)<br>&nbsp;&nbsp;&nbsp;&nbsp;&nbsp...; -&gt;&nbsp; Seq Scan om sars_acts this_&nbsp; (cost=0.00..3844241.84 rows=37092284 width=8)<br>&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; -&gt;&nbsp; Hash&nbsp; (cost=230565.81..230565.81 rows=580 width=8)<br>&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; -&gt; Seq Scan on sars_acts_run tr1_&nbsp; (cost=0.00..230565.81 rows=580 width=8)<br>&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; Filter:&nbsp; ((algorithm)::text = 'SMAT'::text)<br>(7 rows)<br><br>This query executes in approximately 5.3 minutes to complete, very very slow, our users are not happy.<br><br>I did add an index on SARS_ACTS_RUN.ALGORITHM column but it didn't improve the run time. <br>The planner just changed the "Filter:" to an "Index Scan:" improving the cost of the Seq Scan <br>on the sars_acts_run table, but the overall run time remained the same. It seems like the bottleneck <br>is in the Seq Scan on the sars_acts table.<br><br>&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; -&gt; Seq Scan on sars_acts_run tr1_&nbsp; (cost=0.00..230565.81 rows=580 width=8)<br>&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; Filter:&nbsp; ((algorithm)::text = 'SMAT'::text)<br><br>Does anyone have suggestions about how to speed it up?<br><a target="_blank" href="mailto:pgsql-performance@postgresql.org"></a></div></span></body></html>




^ permalink  raw  reply  [nested|flat] 13+ messages in thread

* Re: Very slow inner join query Unacceptable latency.
  2013-05-21 21:53 Very slow inner join query Unacceptable latency. fburgess@radiantblue.com
@ 2013-05-21 21:59 ` Jaime Casanova <jaime@2ndquadrant.com>
  1 sibling, 0 replies; 13+ messages in thread

From: Jaime Casanova @ 2013-05-21 21:59 UTC (permalink / raw)
  To: Freddie Burgess <fburgess@radiantblue.com>; +Cc: pgsql-performance; Postgres General <pgsql-general@postgresql.org>

On Tue, May 21, 2013 at 4:53 PM,  <fburgess@radiantblue.com> wrote:
> The SARS_ACTS table currently has 37,115,515 rows
>
> we have indexed: idx_sars_acts_acts_run_id ON SARS_ACTS USING btree
> (sars_run_id)
> we have pk constraint on the SARS_ACTS_RUN table; sars_acts_run_pkey PRIMARY
> KEY (id )
>
> serverdb=# explain select count(*) as y0_ from SARS_ACTS this_ inner join
> SARS_ACTS_RUN tr1_ on this_.SARS_RUN_ID=tr1_.ID where tr1_.ALGORITHM='SMAT';

can you please show us an EXPLAIN ANALYZE of this query (not only
EXPLAIN). please paste it in a file and attach it so it doesn't get
reformatted by the mail client.

what version of postgres is this?

--
Jaime Casanova         www.2ndQuadrant.com
Professional PostgreSQL: Soporte 24x7 y capacitación
Phone: +593 4 5107566         Cell: +593 987171157


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



^ permalink  raw  reply  [nested|flat] 13+ messages in thread

* Re: Very slow inner join query Unacceptable latency.
  2013-05-21 21:53 Very slow inner join query Unacceptable latency. fburgess@radiantblue.com
@ 2013-05-22 05:57 ` Amit Kapila <amit.kapila@huawei.com>
  1 sibling, 0 replies; 13+ messages in thread

From: Amit Kapila @ 2013-05-22 05:57 UTC (permalink / raw)
  To: fburgess@radiantblue.com; pgsql-performance; +Cc: pgsql-general@postgresql.org

On Wednesday, May 22, 2013 3:24 AM fburgess wrote:

> The SARS_ACTS table currently has 37,115,515 rows

> we have indexed: idx_sars_acts_acts_run_id ON SARS_ACTS USING btree (sars_run_id)
> we have pk constraint on the SARS_ACTS_RUN table; sars_acts_run_pkey PRIMARY KEY (id )

> serverdb=# explain select count(*) as y0_ from SARS_ACTS this_ inner join SARS_ACTS_RUN tr1_ on this_.SARS_RUN_ID=tr1_.ID where tr1_.ALGORITHM='SMAT';
>                                                    QUERY PLAN
> --------------------------------------------------------------------------------------------------------------------------
> Aggregate  (cost=4213952.17..4213952.18 rows=1 width=0)
>  -> Hash Join  (cost=230573.06..4213943.93 rows=3296 width=0)
>       Hash Cond:  (this_.SARS_RUN_ID=tr1_.ID)
>       ->  Seq Scan om sars_acts this_  (cost=0.00..3844241.84 rows=37092284 width=8)
>       ->  Hash  (cost=230565.81..230565.81 rows=580 width=8)
>              -> Seq Scan on sars_acts_run tr1_  (cost=0.00..230565.81 rows=580 width=8)
>                   Filter:  ((algorithm)::text = 'SMAT'::text)
> (7 rows)



> This query executes in approximately 5.3 minutes to complete, very very slow, our users are not happy.

> I did add an index on SARS_ACTS_RUN.ALGORITHM column but it didn't improve the run time. 
> The planner just changed the "Filter:" to an "Index Scan:" improving the cost of the Seq Scan 
> on the sars_acts_run table, but the overall run time remained the same. It seems like the bottleneck 
> is in the Seq Scan on the sars_acts table.

>              -> Seq Scan on sars_acts_run tr1_  (cost=0.00..230565.81 rows=580 width=8)
>                   Filter:  ((algorithm)::text = 'SMAT'::text)

> Does anyone have suggestions about how to speed it up?

Could you please once trying Analyzing both tables and then run the query to check which plan it uses:

Analyze SARS_ACTS;
Analyze SARS_ACTS_RUN;


With Regards,
Amit Kapila.



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



^ permalink  raw  reply  [nested|flat] 13+ messages in thread

* Re: [PERFORM] Very slow inner join query Unacceptable latency.
@ 2013-05-22 14:41 fburgess@radiantblue.com
  2013-05-23 00:17 ` Re: Very slow inner join query Unacceptable latency. Jeff Janes <jeff.janes@gmail.com>
  2013-05-24 06:16 ` Re: [PERFORM] Very slow inner join query Unacceptable latency. Scott Marlowe <scott.marlowe@gmail.com>
  0 siblings, 2 replies; 13+ messages in thread

From: fburgess@radiantblue.com @ 2013-05-22 14:41 UTC (permalink / raw)
  To: Jaime Casanova <jaime@2ndquadrant.com>; +Cc: pgsql-performance; Postgres General <pgsql-general@postgresql.org>


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

Attachments:

explainanalyzesql.txt (text/plain, 1.3K) download The SARS_ACTS table currently has 37,115,515 rows I re-added the index on algorithm: idx_sars_acts_run_algorithm ON SARS_ACTS_RUN (algorithm) serverdb=# explain analyze select count(*) as y0_ from SARS_ACTS this_ inner join SARS_ACTS_RUN tr1_ on this_.SARS_RUN_ID=tr1_.ID where tr1_.ALGORITHM='SMAT'; QUERY PLAN -------------------------------------------------------------------------------------------------------------------------- Aggregate (cost=3983424.05..3983424.06 rows=1 width=0) (actual time=1358298.003..1358298.004 rows=1 loops=1) -> Hash Join (cost=44.93..3983415.81 rows=3297 width=0) (actual time=2593.768..1358041.205 rows 1481710 loops=1) Hash Cond: (this_.SARS_RUN_ID=tr1_.ID) -> Seq Scan om sars_acts this_ (cost=0.00..3844241.84 rows=37092284 width=8) (actual time=0.026..1348954.763 rows=37461345 loops=1) -> Hash (cost=37.68..37.68 rows=580 width=8) (actual time=435.655..435.655 rows=441 loops=1) Buckets: 1024 Batches: 1 Memory Usage: 18kB -> Index Scan using idx_mars_track_run_algorithm on SARS_ACTS_RUN tr1_ (cost=0.00..37.68 rows=580 width=8) (actual time=10.580..435.273 rows 441 loops=1) Index Cond: ((algorithm)::text = 'SMAT'::text) Total runtime: 1358298.664 ms <- 22.6383 minutes (9 rows)
^ permalink raw reply [nested|flat] 13+ messages in thread

* Re: Very slow inner join query Unacceptable latency.
  2013-05-22 14:41 Re: [PERFORM] Very slow inner join query Unacceptable latency. fburgess@radiantblue.com
@ 2013-05-23 00:17 ` Jeff Janes <jeff.janes@gmail.com>
  1 sibling, 0 replies; 13+ messages in thread

From: Jeff Janes @ 2013-05-23 00:17 UTC (permalink / raw)
  To: fburgess@radiantblue.com; +Cc: Jaime Casanova <jaime@2ndquadrant.com>; pgsql-performance; Postgres General <pgsql-general@postgresql.org>

On Wed, May 22, 2013 at 7:41 AM, <fburgess@radiantblue.com> wrote:

> PostgreSQL 9.1.6 on linux
>

^ permalink  raw  reply  [nested|flat] 13+ messages in thread

* Re: [PERFORM] Very slow inner join query Unacceptable latency.
  2013-05-22 14:41 Re: [PERFORM] Very slow inner join query Unacceptable latency. fburgess@radiantblue.com
@ 2013-05-24 06:16 ` Scott Marlowe <scott.marlowe@gmail.com>
  1 sibling, 0 replies; 13+ messages in thread

From: Scott Marlowe @ 2013-05-24 06:16 UTC (permalink / raw)
  To: fburgess@radiantblue.com; +Cc: Jaime Casanova <jaime@2ndquadrant.com>; pgsql-performance; Postgres General <pgsql-general@postgresql.org>

Looking at the execution plan makes me wonder what your work_mem is
set to.  Try cranking it up to test and lowering random_page_cost:

set work_mem='500MB';
set random_page_cost=1.2;
explain analyze select ...

and see what you get.


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



^ permalink  raw  reply  [nested|flat] 13+ messages in thread

* Re: Very slow inner join query Unacceptable latency.
@ 2013-05-23 06:13 Amit Kapila <amit.kapila@huawei.com>
  0 siblings, 0 replies; 13+ messages in thread

From: Amit Kapila @ 2013-05-23 06:13 UTC (permalink / raw)
  To: fburgess@radiantblue.com; +Cc: pgsql-performance

On Wednesday, May 22, 2013 10:03 PM fburgess wrote:

> I did perform a explain analyze on the query.

Explain analyze doesn't help to collect statistics. You should use Analyze <table_name>.

Ideally optimizer should have slected the best plan, but just to check you can once try with

SET enable_hashjoin=off;

And see what is the plan it chooses and does it pick up index scan on larger table?

Could you please output of \d SARS_ACTS and \d SARS_ACTS_RUN?


With Regards,
Amit Kapila.



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



^ permalink  raw  reply  [nested|flat] 13+ messages in thread

* Re: [PERFORM] Very slow inner join query Unacceptable latency.
@ 2013-05-23 17:21 fburgess@radiantblue.com
  2013-05-23 23:34 ` Re: [PERFORM] Very slow inner join query Unacceptable latency. Jaime Casanova <jaime@2ndquadrant.com>
  2013-05-24 05:14 ` Re: [PERFORM] Very slow inner join query Unacceptable latency. Amit Kapila <amit.kapila@huawei.com>
  0 siblings, 2 replies; 13+ messages in thread

From: fburgess@radiantblue.com @ 2013-05-23 17:21 UTC (permalink / raw)
  To: Jeff Janes <jeff.janes@gmail.com>; +Cc: Jaime Casanova <jaime@2ndquadrant.com>; pgsql-performance; Postgres General <pgsql-general@postgresql.org>

<html><body><span style="font-family:Verdana; color:#000000; font-size:10pt;"><div>serverdb=# set enable_hashjoin=off;<br>SET<br>serverdb=# explain select count(*) as y0_ from SARS_ACTS this_ inner join <span style="color:rgb(0,0,0);white-space:pre-wrap">SARS_ACTS_RUN</span> tr1_ on this_.SARS_RUN_ID=<a href="http://tr1_.ID">tr1_.ID</a; where tr1.ALGORITHM='SMAT';<br><br>&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; QUERY PLAN<br>--------------------------------------------------------------------------------------------------------------------------<br>Aggregate&nbsp; (cost=7765563.69..7765563.70 rows=1 width=0) <br>&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; Nested Loop&nbsp; (cost=0.00..7765555.35 rows=3336 width=0)<br>&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; -&gt; Index Scan using idx_sars_acts_run_algorithm on sars_acts_run tr1_&nbsp; (cost=0.00..44.32 rows=650 width=8) <br>&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; Index Cond:&nbsp; ((algorithm)::text = 'SMAT'::text)<br>&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; -&gt; Index Scan using idx_sars_acts_run_id_end_time on sars_acts this_&nbsp; (cost=0.00..11891.29 rows=4452 width=8) <br>&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; Index Cond:&nbsp; (SARS_RUN_ID=<a href="http://tr1_.ID">tr1_.ID</a>)<br>(6 rows)<br><br>serverdb=# \timing<br>TIming is on.<br><br>serverdb=# select count(*) as y0_ from SARS_ACTS this_ inner join <span style="color:rgb(0,0,0);white-space:pre-wrap">SARS_ACTS_RUN</span> tr1_ on this_.SARS_RUN_ID=<a href="http://tr1_.ID">tr1_.ID</a; where tr1.ALGORITHM='SMAT';<br>&nbsp;y0_<br>------<br>1481710<br>(1 row)<br><br>Time: 85069.416 ms &lt; 1.4 minutes &lt;-- not great, but much better!<br><br>Subsequently, runs in the milliseconds once cached.</div><div><br></div><div>But what negative impact is disabling hash joins?</div><div><br></div><div>Sorry, I just executed the explain without the analyze, I'll send out the "explain analyze" next reply.</div><div><br></div><div>thanks</div><div><br></div><div>Freddie<br></div><div><br></div>
<blockquote id="replyBlockquote" webmail="1" style="border-left: 2px solid blue; margin-left: 8px; padding-left: 8px; font-size:10pt; color:black; font-family:verdana;">
<div id="wmQuoteWrapper">
-------- Original Message --------<br>
Subject: Re: [PERFORM] Very slow inner join query Unacceptable latency.<br>
From: Jeff Janes &lt;<a href="mailto:jeff.janes@gmail.com">jeff.janes@gmail.com</a>&gt;<br>
Date: Wed, May 22, 2013 5:17 pm<br>
To: <a href="mailto:fburgess@radiantblue.com">fburgess@radiantblue.com</a><br>
Cc: Jaime Casanova &lt;<a href="mailto:jaime@2ndquadrant.com">jaime@2ndquadrant.com</a>&gt;,  psql performance list<br>
&lt;<a href="mailto:pgsql-performance@postgresql.org">pgsql-performance@postgresql.org</a>&gt;,  Postgres General<br>
&lt;<a href="mailto:pgsql-general@postgresql.org">pgsql-general@postgresql.org</a>&gt;<br>
<br>
<div dir="ltr">On Wed, May 22, 2013 at 7:41 AM, <span dir="ltr">&lt;<a href="mailto:fburgess@radiantblue.com" target="_blank">fburgess@radiantblue.com</a>&gt;</span> wrote:<br><div class="gmail_extra"><div class="gmail_quote"> <blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left-width:1px;border-left-color:rgb(204,204,204);border-left-style:solid;padding-left:1ex"><div><span style="font-size:10pt;font-family:Verdana"><div> PostgreSQL 9.1.6 on linux<br></div></span></div></blockquote><div><br></div><div><br></div><div style="">From the numbers in your attached plan, it seems like it should be doing a nested loop from the 580 rows (it thinks) that match in&nbsp;<span style="color:rgb(0,0,0);white-space:pre-wrap">SARS_ACTS_RUN against the index on sars_run_id to pull out the&nbsp;</span><span style="color:rgb(0,0,0);white-space:pre-wrap">3297 rows (again, it think, though it is way of there)</span><span style="color:rgb(0,0,0);white-space:pre-wrap">. I can't see why it would not do that. There were some planner issues in the early 9.2 releases that caused very large indexes to be punished, but I don't think those were in 9.1</span></div> <div style=""><span style="color:rgb(0,0,0);white-space:pre-wrap"><br></span></div><div style=""><font color="#000000"><span style="white-space:pre-wrap">Could you "set enable_hashjoin to off" and post the "explain analyze" that that gives?</span></font><br> </div><div style=""><font color="#000000"><span style="white-space:pre-wrap"><br></span></font></div><div style=""><font color="#000000"><span style="white-space:pre-wrap"><br></span></font></div><div style=""><font color="#000000"><span style="white-space:pre-wrap">Cheers,</span></font></div> <div style=""><font color="#000000"><span style="white-space:pre-wrap"><br></span></font></div><div style=""><font color="#000000"><span style="white-space:pre-wrap">Jeff</span></font></div><div>&nbsp;</div></div></div></div> 
</div>
</blockquote></span></body></html>




^ permalink  raw  reply  [nested|flat] 13+ messages in thread

* Re: [PERFORM] Very slow inner join query Unacceptable latency.
  2013-05-23 17:21 Re: [PERFORM] Very slow inner join query Unacceptable latency. fburgess@radiantblue.com
@ 2013-05-23 23:34 ` Jaime Casanova <jaime@2ndquadrant.com>
  1 sibling, 0 replies; 13+ messages in thread

From: Jaime Casanova @ 2013-05-23 23:34 UTC (permalink / raw)
  To: Freddie Burgess <fburgess@radiantblue.com>; +Cc: Jeff Janes <jeff.janes@gmail.com>; pgsql-performance; Postgres General <pgsql-general@postgresql.org>

On Thu, May 23, 2013 at 12:21 PM,  <fburgess@radiantblue.com> wrote:
>
> But what negative impact is disabling hash joins?
>

doing it just for a single query, could be a tool for solving
particular problems.
setting it in postgresql.conf, therefore affecting all queries, is
like using a hammer to change tv channel... it will cause more
problems than the one it solves.

what you can do is:

1) execute:

SET enable_hashjoin TO OFF;
SELECT here
RESET enable_hashjoin TO ON;

2) in a function:

CREATE FUNCTION do_something() RETURNS bigint AS
$$
   SELECT here
$$ LANGUAGE sql SET enable_hashjoin TO OFF STABLE;

--
Jaime Casanova         www.2ndQuadrant.com
Professional PostgreSQL: Soporte 24x7 y capacitación
Phone: +593 4 5107566         Cell: +593 987171157


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



^ permalink  raw  reply  [nested|flat] 13+ messages in thread

* Re: [PERFORM] Very slow inner join query Unacceptable latency.
  2013-05-23 17:21 Re: [PERFORM] Very slow inner join query Unacceptable latency. fburgess@radiantblue.com
@ 2013-05-24 05:14 ` Amit Kapila <amit.kapila@huawei.com>
  1 sibling, 0 replies; 13+ messages in thread

From: Amit Kapila @ 2013-05-24 05:14 UTC (permalink / raw)
  To: fburgess@radiantblue.com; 'Jeff Janes' <jeff.janes@gmail.com>; +Cc: 'Jaime Casanova' <jaime@2ndquadrant.com>; pgsql-performance; 'Postgres General' <pgsql-general@postgresql.org>


On Thursday, May 23, 2013 10:51 PM fburgess wrote:
> serverdb=# set enable_hashjoin=off;
> SET
> serverdb=# explain select count(*) as y0_ from SARS_ACTS this_ inner join SARS_ACTS_RUN tr1_ on this_.SARS_RUN_ID=tr1_.ID where tr1.ALGORITHM='SMAT';

>                                                     QUERY PLAN
> --------------------------------------------------------------------------------------------------------------------------
> Aggregate  (cost=7765563.69..7765563.70 rows=1 width=0) 
>      Nested Loop  (cost=0.00..7765555.35 rows=3336 width=0)
>         -> Index Scan using idx_sars_acts_run_algorithm on sars_acts_run tr1_  (cost=0.00..44.32 rows=650 width=8) 
>              Index Cond:  ((algorithm)::text = 'SMAT'::text)
>         -> Index Scan using idx_sars_acts_run_id_end_time on sars_acts this_  (cost=0.00..11891.29 rows=4452 width=8) 
>              Index Cond:  (SARS_RUN_ID=tr1_.ID)
>(6 rows)

>serverdb=# \timing
>TIming is on.

>serverdb=# select count(*) as y0_ from SARS_ACTS this_ inner join SARS_ACTS_RUN tr1_ on this_.SARS_RUN_ID=tr1_.ID where tr1.ALGORITHM='SMAT';
> y0_
>------
>1481710
>(1 row)

> Time: 85069.416 ms < 1.4 minutes <-- not great, but much better!

> Subsequently, runs in the milliseconds once cached.

If I see the plan from your other mail as below where Hash join is selected, the cost of Nested Loop is much more, that is the reason why optimizer would have selected 
Hash Join. 

serverdb=# explain analyze select count(*) as y0_ from SARS_ACTS this_ inner join SARS_ACTS_RUN tr1_ on this_.SARS_RUN_ID=tr1_.ID where tr1_.ALGORITHM='SMAT';
                                                    QUERY PLAN
--------------------------------------------------------------------------------------------------------------------------
Aggregate  (cost=3983424.05..3983424.06 rows=1 width=0) (actual time=1358298.003..1358298.004 rows=1 loops=1)
  -> Hash Join  (cost=44.93..3983415.81 rows=3297 width=0) (actual time=2593.768..1358041.205 rows 1481710 loops=1)


It is quite surprising that after optimizer decided the cost of some plan (Hash Join) to be lower but actual execution cost of same is more. 
There might be some problem with cost calculation model of Hash Join for some cases.

By the way which version of PostgreSQL you are using?

> But what negative impact is disabling hash joins?

I think using it as a temporary fix might be okay, but keeping such code in your application might be risky for you, because as the data changes in your tables, it could be quite possible that
in future Hash Join might be the best and cheapest way.

Can you try reproducing it with small data or else can you attach your schema and data for the tables/indexes used in query?

With Regards,
Amit Kapila.



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



^ permalink  raw  reply  [nested|flat] 13+ messages in thread

* Re: [PERFORM] Very slow inner join query Unacceptable latency.
@ 2013-05-24 21:44 fburgess@radiantblue.com
  2013-05-24 22:03 ` Re: [PERFORM] Very slow inner join query Unacceptable latency. Scott Marlowe <scott.marlowe@gmail.com>
  0 siblings, 1 reply; 13+ messages in thread

From: fburgess@radiantblue.com @ 2013-05-24 21:44 UTC (permalink / raw)
  To: Scott Marlowe <scott.marlowe@gmail.com>; +Cc: Jaime Casanova <jaime@2ndquadrant.com>; pgsql-performance; Postgres General <pgsql-general@postgresql.org>

<html><body><span style="font-family:Verdana; color:#000000; font-size:10pt;"><div><br>1.) Server setting<br><br>memory: 32960116kB = 32GB<br><br><br>2.) Current Postgresql configuration settings of note in my environment.<br><br>enable_hashjoin=off<br>work_mem = 16MB <br>#random_page_cost-4.0 &lt;- default<br>maintenance_work_mem=256MB<br>shared_buffers = 8GB<br><br><br>serverdb=# explain analyze select count(*) as y0_ from SARS_ACTS this_ inner join SARS_ACTS_RUN tr1_ on this_.SARS_RUN_ID=<a href="http://tr1_.ID">tr1_.ID</a; where tr1.ALGORITHM='SMAT';<br><br>&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; QUERY PLAN<br>--------------------------------------------------------------------------------------------------------------------------<br>Aggregate&nbsp; (cost=5714258.72..5714258.73 rows=1 width=0) (actual time=54402.148..54402.148 rows=1 loops=1)<br>&nbsp;&nbsp;&nbsp;&nbsp; Nested Loop&nbsp; (cost=0.00..5714253.25 rows=2188 width=0) (actual time=5.920..54090.676 rows=1481710 loops=1)<br>&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; -&gt; Index Scan using idx_SARS_ACTS_run_algorithm on SARS_ACTS_run tr1_&nbsp; (cost=0.00..32.71 rows=442 width=8) (actual time=1.423..205.256 rows=441 loops=1)<br>&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; Index Cond:&nbsp; ((algorithm)::text = 'SMAT'::text)<br>&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; -&gt; Index Scan using idx_SARS_ACTS_run_id_end_time on SARS_ACTS this_&nbsp; (cost=0.00..12874.40 rows=4296 width=8) (actual time=749..121.125 rows=3360 loops=441)<br>&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; Index Cond:&nbsp; (SARS_RUN_ID=<a href="http://tr1_.ID">tr1_.ID</a>)<br>Total runtime: 54402.212 ms &lt;- 54 seconds<br><br>(7 rows)<br><br>3.) Setting the recommended parameters<br><br><br>serverdb=# set work_mem='500MB';<br>SET<br>serverdb=# set random_page_cost=1.2;<br>SET<br>serverdb=# explain analyze select count(*) as y0_ from SARS_ACTS this_ inner join SARS_ACTS_RUN tr1_ on this_.SARS_RUN_ID=<a href="http://tr1_.ID">tr1_.ID</a; where tr1.ALGORITHM='SMAT';<br><br>&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; QUERY PLAN<br>--------------------------------------------------------------------------------------------------------------------------<br>Aggregate&nbsp; (cost=1754246.85..1754246.86 rows=1 width=0) (actual time=1817.644..1817.644 rows=1 loops=1)<br>&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; Nested Loop&nbsp; (cost=0.00..1754241.38 rows=2188 width=0) (actual time=0.135..1627.954 rows=1481710 loops=1)<br>&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; -&gt; Index Scan using idx_SARS_ACTS_run_algorithm on SARS_ACTS_run tr1_&nbsp; (cost=0.00..22.40 rows=442 width=8) (actual time=0.067..0.561 rows=441 loops=1)<br>&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; Index Cond:&nbsp; ((algorithm)::text = 'SMAT'::text)<br>&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; -&gt; Index Scan using idx_SARS_ACTS_run_id_end_time on SARS_ACTS this_&nbsp; (cost=0.00..3915.12 rows=4296 width=8) (actual time=0.008..2.972 rows=3360 loops=441)<br>&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; Index Cond:&nbsp; (SARS_RUN_ID=<a href="http://tr1_.ID">tr1_.ID</a>)<br>Total runtime: 1817.695 ms&nbsp; 1.8 seconds &lt;- very good response time improvement<br><br>(7 rows)<br><br>4.) Now toggling the enable_hashjoin, I suspect the plan is cached, so these results may be suspect.<br><br><br>serverdb=# set enable_hashjoin=on;<br>SET<br>serverdb=# explain analyze select count(*) as y0_ from SARS_ACTS this_ inner join SARS_ACTS_RUN tr1_ on this_.SARS_RUN_ID=<a href="http://tr1_.ID">tr1_.ID</a; where tr1.ALGORITHM='SMAT';<br><br>&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; QUERY PLAN<br>--------------------------------------------------------------------------------------------------------------------------<br>Aggregate&nbsp; (cost=1754246.85..1754246.86 rows=1 width=0) (actual time=1606.683..1606.683 rows=1 loops=1)<br>&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; Nested Loop&nbsp; (cost=0.00..1754241.38 rows=2188 width=0) (actual time=0.136..1442.463 rows=1481710 loops=1)<br>&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; -&gt; Index Scan using idx_SARS_ACTS_run_algorithm on SARS_ACTS_run tr1_&nbsp; (cost=0.00..22.40 rows=442 width=8) (actual time=0.068..0.591 rows=441 loops=1)<br>&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; Index Cond:&nbsp; ((algorithm)::text = 'SMAT'::text)<br>&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; -&gt; Index Scan using idx_SARS_ACTS_run_id_end_time on SARS_ACTS this_&nbsp; (cost=0.00..3915.12 rows=4296 width=8) (actual time=0.007..2.659 rows=3360 loops=441)<br>&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; Index Cond:&nbsp; (SARS_RUN_ID=<a href="http://tr1_.ID">tr1_.ID</a>)<br>Total runtime: 1606.728 ms 1.6 seconds &lt;- very good response time improvement<br><br>(7 rows)<br><br>Questions:<br><br>Any concerns with setting these conf variables you recommended; work_mem, random_page_cost dbserver wide (in postgresql,conf)? <br><br>Thanks so much!!!<br><br></div>
<blockquote id="replyBlockquote" webmail="1" style="border-left: 2px solid blue; margin-left: 8px; padding-left: 8px; font-size:10pt; color:black; font-family:verdana;">
<div id="wmQuoteWrapper">
-------- Original Message --------<br>
Subject: Re: [GENERAL] [PERFORM] Very slow inner join query Unacceptable<br>
latency.<br>
From: Scott Marlowe &lt;<a href="mailto:scott.marlowe@gmail.com">scott.marlowe@gmail.com</a>&gt;<br>
Date: Thu, May 23, 2013 11:16 pm<br>
To: <a href="mailto:fburgess@radiantblue.com">fburgess@radiantblue.com</a><br>
Cc: Jaime Casanova &lt;<a href="mailto:jaime@2ndquadrant.com">jaime@2ndquadrant.com</a>&gt;,  psql performance list<br>
&lt;<a href="mailto:pgsql-performance@postgresql.org">pgsql-performance@postgresql.org</a>&gt;,  Postgres General<br>
&lt;<a href="mailto:pgsql-general@postgresql.org">pgsql-general@postgresql.org</a>&gt;<br>
<br>
Looking at the execution plan makes me wonder what your work_mem is<br>
set to.  Try cranking it up to test and lowering random_page_cost:<br>
<br>
set work_mem='500MB';<br>
set random_page_cost=1.2;<br>
explain analyze select ...<br>
<br>
and see what you get.<br>

</div>
</blockquote></span></body></html>




^ permalink  raw  reply  [nested|flat] 13+ messages in thread

* Re: [PERFORM] Very slow inner join query Unacceptable latency.
  2013-05-24 21:44 Re: [PERFORM] Very slow inner join query Unacceptable latency. fburgess@radiantblue.com
@ 2013-05-24 22:03 ` Scott Marlowe <scott.marlowe@gmail.com>
  0 siblings, 0 replies; 13+ messages in thread

From: Scott Marlowe @ 2013-05-24 22:03 UTC (permalink / raw)
  To: fburgess@radiantblue.com; +Cc: Jaime Casanova <jaime@2ndquadrant.com>; pgsql-performance; Postgres General <pgsql-general@postgresql.org>

On Fri, May 24, 2013 at 3:44 PM,  <fburgess@radiantblue.com> wrote:

> Total runtime: 1606.728 ms 1.6 seconds <- very good response time
> improvement
>
> (7 rows)
>
> Questions:
>
> Any concerns with setting these conf variables you recommended; work_mem,
> random_page_cost dbserver wide (in postgresql,conf)?
>
> Thanks so much!!!

Yes 500MB is pretty high especially if you have a lot of connections.
Try it with it back down to 16MB and see how it does.  Work mem is per
sort so a setting as high as 500MB can exhaust memory on the machine
under heavy load.

--
To understand recursion, one must first understand recursion.


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



^ permalink  raw  reply  [nested|flat] 13+ messages in thread

* Re: [PERFORM] Very slow inner join query Unacceptable latency.
@ 2013-05-29 14:44 fburgess@radiantblue.com
  0 siblings, 0 replies; 13+ messages in thread

From: fburgess@radiantblue.com @ 2013-05-29 14:44 UTC (permalink / raw)
  To: Scott Marlowe <scott.marlowe@gmail.com>; +Cc: Jaime Casanova <jaime@2ndquadrant.com>; pgsql-performance; Postgres General <pgsql-general@postgresql.org>

<html><body><span style="font-family:Verdana; color:#000000; font-size:10pt;"><div>We re-tested&nbsp;these settings a few times after our initial test and&nbsp;realized that the execution time I posted was shewed, because the execution plan was cached after the initial run. Subsequent executions ran in a little over a second.</div>
<div>There&nbsp;ended up being no significant&nbsp;saving by setting these parameters. Un-cached the query ran in about 55 seconds.&nbsp;</div>
<div>&nbsp;</div>
<BLOCKQUOTE style="BORDER-LEFT: blue 2px solid; PADDING-LEFT: 8px; FONT-FAMILY: verdana; COLOR: black; MARGIN-LEFT: 8px; FONT-SIZE: 10pt" id=replyBlockquote webmail="1">
<DIV id=wmQuoteWrapper>-------- Original Message --------<BR>Subject: Re: [GENERAL] [PERFORM] Very slow inner join query Unacceptable<BR>latency.<BR>From: Scott Marlowe &lt;<a href="mailto:scott.marlowe@gmail.com">scott.marlowe@gmail.com</a>&gt;<BR>Date: Fri, May 24, 2013 3:03 pm<BR>To: <a href="mailto:fburgess@radiantblue.com">fburgess@radiantblue.com</a><BR>Cc: Jaime Casanova &lt;<a href="mailto:jaime@2ndquadrant.com">jaime@2ndquadrant.com</a>&gt;, psql performance list<BR>&lt;<a href="mailto:pgsql-performance@postgresql.org">pgsql-performance@postgresql.org</a>&gt;, Postgres General<BR>&lt;<a href="mailto:pgsql-general@postgresql.org">pgsql-general@postgresql.org</a>&gt;<BR><BR>On Fri, May 24, 2013 at 3:44 PM, &lt;<a href="mailto:fburgess@radiantblue.com">fburgess@radiantblue.com</a>&gt; wrote:<BR><BR>&gt; Total runtime: 1606.728 ms 1.6 seconds &lt;- very good response time<BR>&gt; improvement<BR>&gt;<BR>&gt; (7 rows)<BR>&gt;<BR>&gt; Questions:<BR>&gt;<BR>&gt; Any concerns with setting these conf variables you recommended; work_mem,<BR>&gt; random_page_cost dbserver wide (in postgresql,conf)?<BR>&gt;<BR>&gt; Thanks so much!!!<BR><BR>Yes 500MB is pretty high especially if you have a lot of connections.<BR>Try it with it back down to 16MB and see how it does. Work mem is per<BR>sort so a setting as high as 500MB can exhaust memory on the machine<BR>under heavy load.<BR><BR>--<BR>To understand recursion, one must first understand recursion.<BR></DIV></BLOCKQUOTE></span></body></html>




^ permalink  raw  reply  [nested|flat] 13+ messages in thread


end of thread, other threads:[~2013-05-29 14:44 UTC | newest]

Thread overview: 13+ messages (download: mbox mbox.gz follow: Atom feed)
-- links below jump to the message on this page --
2013-05-21 21:53 Very slow inner join query Unacceptable latency. fburgess@radiantblue.com
2013-05-21 21:59 ` Jaime Casanova <jaime@2ndquadrant.com>
2013-05-22 05:57 ` Amit Kapila <amit.kapila@huawei.com>
2013-05-22 14:41 Re: [PERFORM] Very slow inner join query Unacceptable latency. fburgess@radiantblue.com
2013-05-23 00:17 ` Jeff Janes <jeff.janes@gmail.com>
2013-05-24 06:16 ` Scott Marlowe <scott.marlowe@gmail.com>
2013-05-23 06:13 Re: Very slow inner join query Unacceptable latency. Amit Kapila <amit.kapila@huawei.com>
2013-05-23 17:21 Re: [PERFORM] Very slow inner join query Unacceptable latency. fburgess@radiantblue.com
2013-05-23 23:34 ` Jaime Casanova <jaime@2ndquadrant.com>
2013-05-24 05:14 ` Amit Kapila <amit.kapila@huawei.com>
2013-05-24 21:44 Re: [PERFORM] Very slow inner join query Unacceptable latency. fburgess@radiantblue.com
2013-05-24 22:03 ` Scott Marlowe <scott.marlowe@gmail.com>
2013-05-29 14:44 Re: [PERFORM] Very slow inner join query Unacceptable latency. fburgess@radiantblue.com

This inbox is served by DDX for PostgreSQL; see mirroring instructions
for how to clone and mirror all data and code used for this inbox