Issues on 9.5 to 9.6 Upgrade.
<html><body><span style="font-family:Verdana; color:#000000; font-size:10pt;"><div>Servers: Redhack 6.9 64 bit.</div><div>Postgres OLD Server version 9.5.6</div><div>Postgres New Server 9.6.6</div><div><br></div><div>Issues BIG difference in speed on the following SQL statement from 9.5 to 9.6 ...<br></div><div><br></div><div>EXPLAIN ANALYZE<br>select de_caseid, de_seqno, de_document_num, doc_link.dm_id as dm_id,<br> doc_link.dm_seq as dm_seq, doc_link.dm_dls_id as dm_dls_id,<br> doc_link.dm_restrict_view as dm_restrict_view, document_v.dm_type as dm_type,<br> document_v.dm_id as accessable<br>from dktentry left outer join doc_link on de_doc_id = doc_link.dm_id<br> left outer join document_v on doc_link.dm_id = document_v.dm_id</div><div> and doc_link.dm_seq = document_v.dm_seq where de_caseid in (800)<br>;<br></div><div><br></div><div>Number of rows in table dktentry:</div><div>psql -x -c "select count(*) from dktentry;"<br>-[ RECORD 1 ]-<br>count | 376555</div><div>Number of Rows in table document_v:</div><div> psql -x -c "select count(*) from document_v;"<br>-[ RECORD 1 ]-<br>count | 931306</div><div>Number of rows in table doc_link:</div><div> psql -x -c "select count(*) from doc_link;"<br>-[ RECORD 1 ]--<br>count | 1329305<br><br></div><div><br></div><div>We are migrating our current 9.5 batch of Postgres servers to a new batch of Postgres 9.6 servers.</div><div>We have tried using both pd_dump and pg dumpall to move the files across.</div><div><br></div><div>However , when executing the above statement on the 9.5 version, we get the following:</div><div>************* 9.5 Postgres<br></div><div>[postgres@sudb114 admintools]$ psql -x -f docittest.sql<br>-[ RECORD 1 ]----------------------------------------------------------------------------------------------------------- ----------------------------------<br>QUERY PLAN | Nested Loop Left Join (cost=1.28..355.98 rows=104 width=32) (actual time=4.017..4.684 rows=6 loops=1)<br>-[ RECORD 2 ]----------------------------------------------------------------------------------------------------------- ----------------------------------<br>QUERY PLAN | -> Nested Loop Left Join (cost=0.85..310.53 rows=39 width=26) (actual time=0.134..0.283 rows=6 loops=1)<br>-[ RECORD 3 ]----------------------------------------------------------------------------------------------------------- ----------------------------------<br>QUERY PLAN | -> Index Scan using u_dktentry_pkey on u_dktentry x0 (cost=0.42..60.94 rows=20 width=16) (actual time=0.093..0.131 rows=5 loops=1)<br>-[ RECORD 4 ]----------------------------------------------------------------------------------------------------------- ----------------------------------<br>QUERY PLAN | Index Cond: (de_caseid = 800)<br>-[ RECORD 5 ]----------------------------------------------------------------------------------------------------------- ----------------------------------<br>QUERY PLAN | Filter: ((de_restrict_view = 0) OR (may_access_docket((de_restrict_view)::integer, de_caseid, de_seqno, 0, 0) <> 0))<br>-[ RECORD 6 ]----------------------------------------------------------------------------------------------------------- ----------------------------------<br>QUERY PLAN | -> Index Scan using u_document_pkey on u_document x0_1 (cost=0.43..12.46 rows=2 width=14) (actual time=0.028..0.029 rows=1 loops=5)<br>-[ RECORD 7 ]----------------------------------------------------------------------------------------------------------- ----------------------------------<br>QUERY PLAN | Index Cond: (x0.de_doc_id = dm_id)<br>-[ RECORD 8 ]----------------------------------------------------------------------------------------------------------- ----------------------------------<br>QUERY PLAN | -> Index Scan using u_document_pkey on u_document x0_2 (cost=0.43..1.16 rows=1 width=10) (actual time=0 .732..0.732 rows=0 loops=6)<br>-[ RECORD 9 ]----------------------------------------------------------------------------------------------------------- ----------------------------------<br>QUERY PLAN | Index Cond: ((x0_1.dm_id = dm_id) AND (x0_1.dm_seq = dm_seq))<br>-[ RECORD 10 ]---------------------------------------------------------------------------------------------------------- ----------------------------------<br>QUERY PLAN | Filter: ((dm_restrict_view = 0) OR (may_access_doc((dm_restrict_view)::integer, dm_id, dm_seq, dm_t ype) <> 0))<br>-[ RECORD 11 ]---------------------------------------------------------------------------------------------------------- ----------------------------------<br>QUERY PLAN | Rows Removed by Filter: 1<br>-[ RECORD 12 ]---------------------------------------------------------------------------------------------------------- ----------------------------------<br>QUERY PLAN | Planning time: 1.579 ms<br>-[ RECORD 13 ]---------------------------------------------------------------------------------------------------------- ----------------------------------<br>QUERY PLAN | Execution time: 4.797 ms<br><br></div><div>Which is pretty quick on the 9.5</div><div><br></div><div>******************* 9.6 Version</div><div><br></div><div>On the 9.6 servers we get the following:</div><div><br></div><div>-[ RECORD 1 ]----------------------------------------------------------------------------------------------------------------------------------------------------------<br>QUERY PLAN | Merge Left Join (cost=878831.70..8759238.40 rows=473192005 width=38) (actual time=15035.085..16338.751 rows=6 loops=1)<br>-[ RECORD 2 ]----------------------------------------------------------------------------------------------------------------------------------------------------------<br>QUERY PLAN | Merge Cond: (x0.de_doc_id = x0_1.dm_id)<br>-[ RECORD 3 ]----------------------------------------------------------------------------------------------------------------------------------------------------------<br>QUERY PLAN | -> Sort (cost=4770.34..4775.72 rows=2153 width=16) (actual time=0.157..0.159 rows=5 loops=1)<br>-[ RECORD 4 ]----------------------------------------------------------------------------------------------------------------------------------------------------------<br>QUERY PLAN | Sort Key: x0.de_doc_id<br>-[ RECORD 5 ]----------------------------------------------------------------------------------------------------------------------------------------------------------<br>QUERY PLAN | Sort Method: quicksort Memory: 25kB<br>-[ RECORD 6 ]----------------------------------------------------------------------------------------------------------------------------------------------------------<br>QUERY PLAN | -> Bitmap Heap Scan on u_dktentry x0 (cost=41.19..4651.15 rows=2153 width=16) (actual time=0.075..0.130 rows=5 loops=1)<br>-[ RECORD 7 ]----------------------------------------------------------------------------------------------------------------------------------------------------------<br>QUERY PLAN | Recheck Cond: (de_caseid = 800)<br>-[ RECORD 8 ]----------------------------------------------------------------------------------------------------------------------------------------------------------<br>QUERY PLAN | Filter: ((de_restrict_view = 0) OR (may_access_docket((de_restrict_view)::integer, de_caseid, de_seqno, 0, 0) <> 0))<br>-[ RECORD 9 ]----------------------------------------------------------------------------------------------------------------------------------------------------------<br>QUERY PLAN | Heap Blocks: exact=4<br>-[ RECORD 10 ]---------------------------------------------------------------------------------------------------------------------------------------------------------<br>QUERY PLAN | -> Bitmap Index Scan on u_dktentry_pkey (cost=0.00..40.65 rows=2164 width=0) (actual time=0.052..0.052 rows=5 loops=1)<br>-[ RECORD 11 ]---------------------------------------------------------------------------------------------------------------------------------------------------------<br>QUERY PLAN | Index Cond: (de_caseid = 800)<br>-[ RECORD 12 ]---------------------------------------------------------------------------------------------------------------------------------------------------------<br>QUERY PLAN | -> Materialize (cost=874061.36..1766468.42 rows=43956527 width=26) (actual time=15024.172..16223.201 rows=1182655 loops=1)<br> RECORD 13 ]---------------------------------------------------------------------------------------------------------------------------------------------------------<br>QUERY PLAN | -> Merge Left Join (cost=874061.36..1656577.10 rows=43956527 width=26) (actual time=15024.165..15990.605 rows=1182655 loops=1)<br>-[ RECORD 14 ]---------------------------------------------------------------------------------------------------------------------------------------------------------<br>QUERY PLAN | Merge Cond: ((x0_1.dm_id = x0_2.dm_id) AND (x0_1.dm_seq = x0_2.dm_seq))<br>-[ RECORD 15 ]---------------------------------------------------------------------------------------------------------------------------------------------------------<br>QUERY PLAN | -> Sort (cost=266298.76..269622.02 rows=1329305 width=14) (actual time=1119.467..1344.975 rows=1182655 loops=1)<br>-[ RECORD 16 ]---------------------------------------------------------------------------------------------------------------------------------------------------------<br>QUERY PLAN | Sort Key: x0_1.dm_id, x0_1.dm_seq<br>-[ RECORD 17 ]---------------------------------------------------------------------------------------------------------------------------------------------------------<br>QUERY PLAN | Sort Method: external merge Disk: 31168kB<br>-[ RECORD 18 ]---------------------------------------------------------------------------------------------------------------------------------------------------------<br>QUERY PLAN | -> Seq Scan on u_document x0_1 (cost=0.00..108375.05 rows=1329305 width=14) (actual time=0.015..550.634 rows=1329305 loops=1)<br>-[ RECORD 19 ]---------------------------------------------------------------------------------------------------------------------------------------------------------<br>QUERY PLAN | -> Materialize (cost=607762.60..614376.06 rows=1322692 width=16) (actual time=13904.690..14203.239 rows=833199 loops=1)<br>-[ RECORD 20 ]---------------------------------------------------------------------------------------------------------------------------------------------------------<br>QUERY PLAN | -> Sort (cost=607762.60..611069.33 rows=1322692 width=16) (actual time=13904.688..14097.990 rows=833199 loops=1)<br>-[ RECORD 21 ]---------------------------------------------------------------------------------------------------------------------------------------------------------<br>QUERY PLAN | Sort Key: x0_2.dm_id, x0_2.dm_seq<br>-[ RECORD 22 ]---------------------------------------------------------------------------------------------------------------------------------------------------------<br>QUERY PLAN | Sort Method: external merge Disk: 19168kB<br>-[ RECORD 23 ]---------------------------------------------------------------------------------------------------------------------------------------------------------<br>QUERY PLAN | -> Seq Scan on u_document x0_2 (cost=0.00..450671.09 rows=1322692 width=16) (actual time=3.134..13444.415 rows=931306 loops=1)</div><div>-[ RECORD 24 ]---------------------------------------------------------------------------------------------------------------------------------------------------------<br>QUERY PLAN | Filter: ((dm_restrict_view = 0) OR (may_access_doc((dm_restrict_view)::integer, dm_id, dm_seq, dm_type) <> 0))<br>-[ RECORD 25 ]---------------------------------------------------------------------------------------------------------------------------------------------------------<br>QUERY PLAN | Rows Removed by Filter: 397999<br>-[ RECORD 26 ]---------------------------------------------------------------------------------------------------------------------------------------------------------<br>QUERY PLAN | Planning time: 1.567 ms<br>-[ RECORD 27 ]---------------------------------------------------------------------------------------------------------------------------------------------------------<br>QUERY PLAN | Execution time: 16347.890 ms<br><br></div><div><br></div><div>Can anyoen explain WHY there is such a big difference? Is it the SQL statement or a bug in the pgdump ?<br></div><div><br></div><div><br></div><div><br></div><div><span style="font-size: 8pt;" mce_style="font-size: 8pt;"></span><span style="font-size: 8pt;" mce_style="font-size: 8pt;">Ben Duncan - Business Network Solutions, Inc. 336 Elton Road Jackson MS, 39212<br>"Never attribute to malice, that which can be adequately explained by stupidity"<br>- Hanlon's Razor<br></span></div></span></body></html>
On Wed, Jun 13, 2018 at 11:16 AM, <bend@linux4ms.net> wrote:
Can anyoen explain WHY there is such a big difference? Is it the SQL
statement or a bug in the pgdump ?
Did you analyze the database after upgrading? Or at least the tables in
question? Those are very different plans.
--
Don Seiler
www.seiler.us
<html><body><span style="font-family:Verdana; color:#000000; font-size:10pt;"><div>Analyze the DB exactly how?</div><div><br></div><div>I did run a reindexdb after migration to no affect.</div><div><br></div><div>Yeah the PLANS are a big difference ....<br></div><div><br></div><div><span style="font-size: 8pt;"></span><span style="font-size: 8pt;">Ben Duncan - Business Network Solutions, Inc. 336 Elton Road Jackson MS, 39212<br>"Never attribute to malice, that which can be adequately explained by stupidity"<br>- Hanlon's Razor<br></span></div><div><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: Issues on 9.5 to 9.6 Upgrade.<br>
From: Don Seiler <<a href="mailto:don@seiler.us">don@seiler.us</a>><br>
Date: Wed, June 13, 2018 11:24 am<br>
To: <a href="mailto:bend@linux4ms.net">bend@linux4ms.net</a><br>
Cc: Postgres General <<a href="mailto:pgsql-general@postgresql.org">pgsql-general@postgresql.org</a>><br>
<br>
<div dir="ltr"><div class="gmail_extra"><div class="gmail_quote">On Wed, Jun 13, 2018 at 11:16 AM, <span dir="ltr"><<a href="mailto:bend@linux4ms.net" target="_blank">bend@linux4ms.net</a>></span> wrote:<blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"><div><span style="font-family:Verdana;color:#000000;font-size:10pt"><div><br></div><div>Can anyoen explain WHY there is such a big difference? Is it the SQL statement or a bug in the pgdump ?<br></div><div><br></div></span></div> </blockquote></div><br>Did you analyze the database after upgrading? Or at least the tables in question? Those are very different plans.<br clear="all"><div><br></div>-- <br><div class="gmail_signature" data-smartmail="gmail_signature"><div dir="ltr"><div>Don Seiler<br><a href="http://www.seiler.us" target="_blank">www.seiler.us</a></div></div></div> </div></div>
</div>
</blockquote></span></body></html>
Import Notes
Resolved by subject fallback
On 06/13/2018 09:44 AM, bend@linux4ms.net wrote:
Analyze the DB exactly how?
https://www.postgresql.org/docs/10/static/sql-analyze.html
I did run a reindexdb after migration to no affect.
Yeah the PLANS are a big difference ....
Ben Duncan - Business Network Solutions, Inc. 336 Elton Road Jackson MS,
39212
"Never attribute to malice, that which can be adequately explained by
stupidity"
- Hanlon's Razor-------- Original Message --------
Subject: Re: Issues on 9.5 to 9.6 Upgrade.
From: Don Seiler <don@seiler.us <mailto:don@seiler.us>>
Date: Wed, June 13, 2018 11:24 am
To: bend@linux4ms.net <mailto:bend@linux4ms.net>
Cc: Postgres General <pgsql-general@postgresql.org
<mailto:pgsql-general@postgresql.org>>On Wed, Jun 13, 2018 at 11:16 AM, <bend@linux4ms.net
<mailto:bend@linux4ms.net>> wrote:Can anyoen explain WHY there is such a big difference? Is it the
SQL statement or a bug in the pgdump ?Did you analyze the database after upgrading? Or at least the tables
in question? Those are very different plans.--
Don Seiler
www.seiler.us <http://www.seiler.us>
--
Adrian Klaver
adrian.klaver@aklaver.com
<html><body><span style="font-family:Verdana; color:#000000; font-size:10pt;"><div>Ok, this seemed to solve it:</div><div><br></div><div>> vacuumdb -zv ; reindexdb -v<br></div><div><br></div><div>And we are back to full speed ....</div><div><br></div><div>Thanks for pointing out the ANALYZE ...</div><div><br></div><div><span style="font-size: 8pt;"></span><span style="font-size: 8pt;">Ben Duncan - Business Network Solutions, Inc. 336 Elton Road Jackson MS, 39212<br>"Never attribute to malice, that which can be adequately explained by stupidity"<br>- Hanlon's Razor<br></span></div><div><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: Issues on 9.5 to 9.6 Upgrade.<br>
From: Adrian Klaver <<a href="mailto:adrian.klaver@aklaver.com">adrian.klaver@aklaver.com</a>><br>
Date: Wed, June 13, 2018 11:45 am<br>
To: <a href="mailto:bend@linux4ms.net">bend@linux4ms.net</a>, Postgres General <<a href="mailto:pgsql-general@postgresql.org">pgsql-general@postgresql.org</a>><br>
<br>
On 06/13/2018 09:44 AM, <a href="mailto:bend@linux4ms.net">bend@linux4ms.net</a> wrote:<br>
> Analyze the DB exactly how?<br>
<br>
<a href="https://www.postgresql.org/docs/10/static/sql-analyze.html">https://www.postgresql.org/docs/10/static/sql-analyze.html</a><br>
<br>
> <br>
> I did run a reindexdb after migration to no affect.<br>
> <br>
> Yeah the PLANS are a big difference ....<br>
> <br>
> Ben Duncan - Business Network Solutions, Inc. 336 Elton Road Jackson MS, <br>
> 39212<br>
> "Never attribute to malice, that which can be adequately explained by <br>
> stupidity"<br>
> - Hanlon's Razor<br>
> <br>
> <br>
> -------- Original Message --------<br>
> Subject: Re: Issues on 9.5 to 9.6 Upgrade.<br>
> From: Don Seiler <<a href="mailto:don@seiler.us">don@seiler.us</a> ><<a href="mailto:don@seiler.us">mailto:don@seiler.us</a>>><br>
> Date: Wed, June 13, 2018 11:24 am<br>
> To: <a href="mailto:bend@linux4ms.net">bend@linux4ms.net</a> <<a href="mailto:bend@linux4ms.net">mailto:bend@linux4ms.net</a>><br>
> Cc: Postgres General <<a href="mailto:pgsql-general@postgresql.org">pgsql-general@postgresql.org</a><br>
> <<a href="mailto:pgsql-general@postgresql.org">mailto:pgsql-general@postgresql.org</a>>><br>
> <br>
> On Wed, Jun 13, 2018 at 11:16 AM, <<a href="mailto:bend@linux4ms.net">bend@linux4ms.net</a><br>
> <<a href="mailto:bend@linux4ms.net">mailto:bend@linux4ms.net</a>>> wrote:<br>
> <br>
> <br>
> Can anyoen explain WHY there is such a big difference? Is it the<br>
> SQL statement or a bug in the pgdump ?<br>
> <br>
> <br>
> Did you analyze the database after upgrading? Or at least the tables<br>
> in question? Those are very different plans.<br>
> <br>
> -- <br>
> Don Seiler<br>
> <a href="http://www.seiler.us">www.seiler.us</a> <http://<a href="http://www.seiler.us">www.seiler.us</a>&gt;<br>
> <br>
<br>
<br>
-- <br>
Adrian Klaver<br>
<a href="mailto:adrian.klaver@aklaver.com">adrian.klaver@aklaver.com</a><br>
<br>
</div>
</blockquote></span></body></html>
Import Notes
Resolved by subject fallback