Re: [PERFORM] Very slow inner join query Unacceptable latency.

From: <fburgess(at)radiantblue(dot)com>
To: "Scott Marlowe" <scott(dot)marlowe(at)gmail(dot)com>
Cc: "Jaime Casanova" <jaime(at)2ndquadrant(dot)com>, "psql performance list" <pgsql-performance(at)postgresql(dot)org>, "Postgres General" <pgsql-general(at)postgresql(dot)org>
Subject: Re: [PERFORM] Very slow inner join query Unacceptable latency.
Date: 2013-05-24 21:44:28
Message-ID: 20130524144428.5a830134ae84016b0174832fdc1a3173.adf4cb1e7c.wbe@email11.secureserver.net
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-general pgsql-performance

<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(dot)marlowe(at)gmail(dot)com">scott(dot)marlowe(at)gmail(dot)com</a>&gt;<br>
Date: Thu, May 23, 2013 11:16 pm<br>
To: <a href="mailto:fburgess(at)radiantblue(dot)com">fburgess(at)radiantblue(dot)com</a><br>
Cc: Jaime Casanova &lt;<a href="mailto:jaime(at)2ndquadrant(dot)com">jaime(at)2ndquadrant(dot)com</a>&gt;, psql performance list<br>
&lt;<a href="mailto:pgsql-performance(at)postgresql(dot)org">pgsql-performance(at)postgresql(dot)org</a>&gt;, Postgres General<br>
&lt;<a href="mailto:pgsql-general(at)postgresql(dot)org">pgsql-general(at)postgresql(dot)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>

Attachment Content-Type Size
unknown_filename text/html 7.0 KB

Responses

Browse pgsql-general by date

  From Date Subject
Next Message Scott Marlowe 2013-05-24 22:03:39 Re: [PERFORM] Very slow inner join query Unacceptable latency.
Previous Message PG User 2013-05-24 20:16:53 Re: data file corruption

Browse pgsql-performance by date

  From Date Subject
Next Message Scott Marlowe 2013-05-24 22:03:39 Re: [PERFORM] Very slow inner join query Unacceptable latency.
Previous Message sachin kotwal 2013-05-24 13:22:22 Re: pgbench: spike in pgbench results(graphs) while testing pg_hint_plan performance