Thread: [ADMIN] Queries are taking way longer in 9.6 than 9.5

[ADMIN] Queries are taking way longer in 9.6 than 9.5

From
Ravi Tammineni
Date:

Hi,

 

We have recently upgraded to 9.6 and few queries are performing very poorly. Query execution time has increased more 4 or 5 times in 9.6. Qeruy execution plan is also completely changed. I am not sure whether its because of Parallel feature or any bug in 9.6. There are few similar kind of queries and all of them are taking more time in 9.6.

 

Following query is taking 70ms in 9.5 and the same query is taking 2 minutes in 9.6. Execution plan is totally different in 9.6 and seems like there is a major flaw while generating the execution plan. Instead of filtering the low cardinality, its filtering from biggest table. Somehow nested loop joins are screwed up.

 

 

I really appreciate your help.

 

explain analyze

SELECT count(*)

FROM

    tblCnPatientOrderMap po

    JOIN tblPuOrderStatus os ON po.vip_order_id = os.vip_order_id

    JOIN tblPuOrderStatusHistory osh ON os.order_status_history_id = osh.order_status_history_id

WHERE

    exists(SELECT 1

           FROM

               tblCnDoctorPatientMap d

           WHERE d.vip_patient_id = po.vip_patient_id

                 AND exists(SELECT 1

                            FROM

                                tblCnAccounts a

                            WHERE a.master_user_id = d.master_user_id AND

                                  a.user_name = 'dddddd'))

    AND osh.vip_order_type IN (17)--assist

    --AND osh.tx_submit_date IS NOT NULL

    AND osh.cancelled_date IS NULL

    AND osh.cc_accept_date IS NOT NULL;

 

 

##########################  9.5 Execution plan

 

                                                                     QUERY PLAN

-----------------------------------------------------------------------------------------------------------------------------------------------------

Aggregate  (cost=1177.25..1177.26 rows=1 width=0)

   ->  Nested Loop  (cost=67.83..1177.25 rows=5 width=0)

         ->  Nested Loop  (cost=67.71..254.81 rows=1322 width=4)

               ->  Nested Loop  (cost=67.63..104.45 rows=1322 width=4)

                     ->  HashAggregate  (cost=67.54..68.12 rows=192 width=4)

                           Group Key: d.vip_patient_id

 

                           ->  Nested Loop  (cost=0.17..67.44 rows=192 width=4)

                                 ->  Index Scan using unq_user_name on tblcnaccounts a  (cost=0.08..4.09 rows=1 width=4)

                                       Index Cond: ((user_name)::text = 'dddddd'::text)

 

                                 ->  Index Only Scan using idx_tblcndoctorpatientmap on tblcndoctorpatientmap d  (cost=0.09..62.78 rows=192 width=8)

                                       Index Cond: (master_user_id = a.master_user_id)

                     ->  Index Scan using idx_tblcnpatientordermap on tblcnpatientordermap po  (cost=0.09..0.17 rows=7 width=8)

                           Index Cond: (vip_patient_id = d.vip_patient_id)

               ->  Index Scan using tblpuorderstatus_pkey on tblpuorderstatus os  (cost=0.09..0.11 rows=1 width=8)

                     Index Cond: (vip_order_id = po.vip_order_id)

         ->  Index Scan using tblpuorderstatushistory_pkey on tblpuorderstatushistory osh  (cost=0.11..0.69 rows=1 width=4)

               Index Cond: (order_status_history_id = os.order_status_history_id)

               Filter: ((cancelled_date IS NULL) AND (cc_accept_date IS NOT NULL) AND (vip_order_type = 17))

 

#####################################################################################################################################

 

##########################  9.6 Execution plan

                                                             QUERY PLAN

-------------------------------------------------------------------------------------------------------------------------------------

Aggregate  (cost=3185034.17..3185034.17 rows=1 width=8)

   ->  Nested Loop Semi Join  (cost=3012833.92..3185010.91 rows=46511 width=0)

 

         ->  Nested Loop  (cost=3012833.75..3137291.51 rows=46511 width=4)

 

               ->  Hash Join  (cost=3012833.67..3117860.77 rows=46511 width=4)

                     Hash Cond: (os.order_status_history_id = osh.order_status_history_id)

 

                     ->  Seq Scan on tblpuorderstatus os  (cost=0.00..96498.46 rows=11185486 width=8)

                     ->  Hash  (cost=3010979.77..3010979.77 rows=529686 width=4)

                           ->  Gather  (cost=1000.00..3010979.77 rows=529686 width=4)

                                 Workers Planned: 2

                                 ->  Parallel Seq Scan on tblpuorderstatushistory osh  (cost=0.00..2957011.17 rows=220702 width=4)

 

                                       Filter: ((cancelled_date IS NULL) AND (cc_accept_date IS NOT NULL) AND (vip_order_type = 17))

 

               ->  Index Scan using tblcnpatientordermap_pkey on tblcnpatientordermap po  (cost=0.09..0.41 rows=1 width=8)

 

                     Index Cond: (vip_order_id = os.vip_order_id)

 

         ->  Nested Loop Semi Join  (cost=0.17..1.02 rows=1 width=4)

               ->  Index Scan using tblcndoctorpatientmap_pkey on tblcndoctorpatientmap d  (cost=0.09..0.39 rows=1 width=8)

                     Index Cond: (vip_patient_id = po.vip_patient_id)

               ->  Index Scan using tblcnaccounts_pkey on tblcnaccounts a  (cost=0.08..0.36 rows=1 width=4)

                     Index Cond: (master_user_id = d.master_user_id)

                     Filter: ((user_name)::text = 'dddddd'::text)

(19 rows)

 

 

Regards,

ravi

Re: [ADMIN] [GENERAL] Queries are taking way longer in 9.6 than 9.5

From
Melvin Davidson
Date:


On Tue, Jan 17, 2017 at 2:31 PM, Ravi Tammineni <rtammineni@partner.aligntech.com> wrote:

Hi,

 

We have recently upgraded to 9.6 and few queries are performing very poorly. Query execution time has increased more 4 or 5 times in 9.6. Qeruy execution plan is also completely changed. I am not sure whether its because of Parallel feature or any bug in 9.6. There are few similar kind of queries and all of them are taking more time in 9.6.

 

Following query is taking 70ms in 9.5 and the same query is taking 2 minutes in 9.6. Execution plan is totally different in 9.6 and seems like there is a major flaw while generating the execution plan. Instead of filtering the low cardinality, its filtering from biggest table. Somehow nested loop joins are screwed up.

 

 

I really appreciate your help.

 

explain analyze

SELECT count(*)

FROM

    tblCnPatientOrderMap po

    JOIN tblPuOrderStatus os ON po.vip_order_id = os.vip_order_id

    JOIN tblPuOrderStatusHistory osh ON os.order_status_history_id = osh.order_status_history_id

WHERE

    exists(SELECT 1

           FROM

               tblCnDoctorPatientMap d

           WHERE d.vip_patient_id = po.vip_patient_id

                 AND exists(SELECT 1

                            FROM

                                tblCnAccounts a

                            WHERE a.master_user_id = d.master_user_id AND

                                  a.user_name = 'dddddd'))

    AND osh.vip_order_type IN (17)--assist

    --AND osh.tx_submit_date IS NOT NULL

    AND osh.cancelled_date IS NULL

    AND osh.cc_accept_date IS NOT NULL;

 

 

##########################  9.5 Execution plan

 

                                                                     QUERY PLAN

-----------------------------------------------------------------------------------------------------------------------------------------------------

Aggregate  (cost=1177.25..1177.26 rows=1 width=0)

   ->  Nested Loop  (cost=67.83..1177.25 rows=5 width=0)

         ->  Nested Loop  (cost=67.71..254.81 rows=1322 width=4)

               ->  Nested Loop  (cost=67.63..104.45 rows=1322 width=4)

                     ->  HashAggregate  (cost=67.54..68.12 rows=192 width=4)

                           Group Key: d.vip_patient_id

 

                           ->  Nested Loop  (cost=0.17..67.44 rows=192 width=4)

                                 ->  Index Scan using unq_user_name on tblcnaccounts a  (cost=0.08..4.09 rows=1 width=4)

                                       Index Cond: ((user_name)::text = 'dddddd'::text)

 

                                 ->  Index Only Scan using idx_tblcndoctorpatientmap on tblcndoctorpatientmap d  (cost=0.09..62.78 rows=192 width=8)

                                       Index Cond: (master_user_id = a.master_user_id)

                     ->  Index Scan using idx_tblcnpatientordermap on tblcnpatientordermap po  (cost=0.09..0.17 rows=7 width=8)

                           Index Cond: (vip_patient_id = d.vip_patient_id)

               ->  Index Scan using tblpuorderstatus_pkey on tblpuorderstatus os  (cost=0.09..0.11 rows=1 width=8)

                     Index Cond: (vip_order_id = po.vip_order_id)

         ->  Index Scan using tblpuorderstatushistory_pkey on tblpuorderstatushistory osh  (cost=0.11..0.69 rows=1 width=4)

               Index Cond: (order_status_history_id = os.order_status_history_id)

               Filter: ((cancelled_date IS NULL) AND (cc_accept_date IS NOT NULL) AND (vip_order_type = 17))

 

#####################################################################################################################################

 

##########################  9.6 Execution plan

                                                             QUERY PLAN

-------------------------------------------------------------------------------------------------------------------------------------

Aggregate  (cost=3185034.17..3185034.17 rows=1 width=8)

   ->  Nested Loop Semi Join  (cost=3012833.92..3185010.91 rows=46511 width=0)

 

         ->  Nested Loop  (cost=3012833.75..3137291.51 rows=46511 width=4)

 

               ->  Hash Join  (cost=3012833.67..3117860.77 rows=46511 width=4)

                     Hash Cond: (os.order_status_history_id = osh.order_status_history_id)

 

                     ->  Seq Scan on tblpuorderstatus os  (cost=0.00..96498.46 rows=11185486 width=8)

                     ->  Hash  (cost=3010979.77..3010979.77 rows=529686 width=4)

                           ->  Gather  (cost=1000.00..3010979.77 rows=529686 width=4)

                                 Workers Planned: 2

                                 ->  Parallel Seq Scan on tblpuorderstatushistory osh  (cost=0.00..2957011.17 rows=220702 width=4)

 

                                       Filter: ((cancelled_date IS NULL) AND (cc_accept_date IS NOT NULL) AND (vip_order_type = 17))

 

               ->  Index Scan using tblcnpatientordermap_pkey on tblcnpatientordermap po  (cost=0.09..0.41 rows=1 width=8)

 

                     Index Cond: (vip_order_id = os.vip_order_id)

 

         ->  Nested Loop Semi Join  (cost=0.17..1.02 rows=1 width=4)

               ->  Index Scan using tblcndoctorpatientmap_pkey on tblcndoctorpatientmap d  (cost=0.09..0.39 rows=1 width=8)

                     Index Cond: (vip_patient_id = po.vip_patient_id)

               ->  Index Scan using tblcnaccounts_pkey on tblcnaccounts a  (cost=0.08..0.36 rows=1 width=4)

                     Index Cond: (master_user_id = d.master_user_id)

                     Filter: ((user_name)::text = 'dddddd'::text)

(19 rows)

 

 

Regards,

ravi


1. Have you run ANALYZE on the database after upgrading?
2. Have you insured that the proper changed were done to the postgresql.conf in 9.6?


--
Melvin Davidson
I reserve the right to fantasize.  Whether or not you
wish to share my fantasy is entirely up to you.

Re: [ADMIN] [GENERAL] Queries are taking way longer in 9.6 than 9.5

From
Adrian Klaver
Date:
On 01/17/2017 11:31 AM, Ravi Tammineni wrote:
> Hi,
>
>
>
> We have recently upgraded to 9.6 and few queries are performing very
> poorly. Query execution time has increased more 4 or 5 times in 9.6.
> Qeruy execution plan is also completely changed. I am not sure whether
> its because of Parallel feature or any bug in 9.6. There are few similar
> kind of queries and all of them are taking more time in 9.6.

How did you upgrade from 9.5 --> 9.6?

Did you run ANALYZE on the tables after the upgrade?

Tend to doubt parallel query is at issue here, as it is turned off by
default:

https://www.postgresql.org/docs/9.6/static/runtime-config-resource.html#GUC-MAX-PARALLEL-WORKERS-PER-GATHER

For more info:

https://www.postgresql.org/docs/9.6/static/parallel-query.html
>
>
>
> Following query is taking 70ms in 9.5 and the same query is taking 2
> minutes in 9.6. Execution plan is totally different in 9.6 and seems
> like there is a major flaw while generating the execution plan. Instead
> of filtering the low cardinality, its filtering from biggest table.
> Somehow nested loop joins are screwed up.
>
>
>
>
>
> I really appreciate your help.
>
>
>
> explain analyze
>
> SELECT count(*)
>
> FROM
>
>     tblCnPatientOrderMap po
>
>     JOIN tblPuOrderStatus os ON po.vip_order_id = os.vip_order_id
>
>     JOIN tblPuOrderStatusHistory osh ON os.order_status_history_id =
> osh.order_status_history_id
>
> WHERE
>
>     exists(SELECT 1
>
>            FROM
>
>                tblCnDoctorPatientMap d
>
>            WHERE d.vip_patient_id = po.vip_patient_id
>
>                  AND exists(SELECT 1
>
>                             FROM
>
>                                 tblCnAccounts a
>
>                             WHERE a.master_user_id = d.master_user_id AND
>
>                                   a.user_name = 'dddddd'))
>
>     AND osh.vip_order_type IN (17)--assist
>
>     --AND osh.tx_submit_date IS NOT NULL
>
>     AND osh.cancelled_date IS NULL
>
>     AND osh.cc_accept_date IS NOT NULL;
>
>
>
>
>
> ##########################  9.5 Execution plan
>
>
>
>
> QUERY PLAN
>
>
-----------------------------------------------------------------------------------------------------------------------------------------------------
>
> Aggregate  (cost=1177.25..1177.26 rows=1 width=0)
>
>    ->  Nested Loop  (cost=67.83..1177.25 rows=5 width=0)
>
>          ->  Nested Loop  (cost=67.71..254.81 rows=1322 width=4)
>
>                ->  Nested Loop  (cost=67.63..104.45 rows=1322 width=4)
>
>                      ->  HashAggregate  (cost=67.54..68.12 rows=192 width=4)
>
>                            Group Key: d.vip_patient_id
>
>
>
>                            ->  Nested Loop  (cost=0.17..67.44 rows=192
> width=4)
>
>                                  ->  Index Scan using unq_user_name on
> tblcnaccounts a  (cost=0.08..4.09 rows=1 width=4)
>
>                                        Index Cond: ((user_name)::text =
> 'dddddd'::text)
>
>
>
>                                  ->  Index Only Scan using
> idx_tblcndoctorpatientmap on tblcndoctorpatientmap d  (cost=0.09..62.78
> rows=192 width=8)
>
>                                        Index Cond: (master_user_id =
> a.master_user_id)
>
>                      ->  Index Scan using idx_tblcnpatientordermap on
> tblcnpatientordermap po  (cost=0.09..0.17 rows=7 width=8)
>
>                            Index Cond: (vip_patient_id = d.vip_patient_id)
>
>                ->  Index Scan using tblpuorderstatus_pkey on
> tblpuorderstatus os  (cost=0.09..0.11 rows=1 width=8)
>
>                      Index Cond: (vip_order_id = po.vip_order_id)
>
>          ->  Index Scan using tblpuorderstatushistory_pkey on
> tblpuorderstatushistory osh  (cost=0.11..0.69 rows=1 width=4)
>
>                Index Cond: (order_status_history_id =
> os.order_status_history_id)
>
>                Filter: ((cancelled_date IS NULL) AND (cc_accept_date IS
> NOT NULL) AND (vip_order_type = 17))
>
>
>
>
#####################################################################################################################################
>
>
>
> ##########################  9.6 Execution plan
>
>                                                              QUERY PLAN
>
>
-------------------------------------------------------------------------------------------------------------------------------------
>
> Aggregate  (cost=3185034.17..3185034.17 rows=1 width=8)
>
>    ->  Nested Loop Semi Join  (cost=3012833.92..3185010.91 rows=46511
> width=0)
>
>
>
>          ->  Nested Loop  (cost=3012833.75..3137291.51 rows=46511 width=4)
>
>
>
>                ->  Hash Join  (cost=3012833.67..3117860.77 rows=46511
> width=4)
>
>                      Hash Cond: (os.order_status_history_id =
> osh.order_status_history_id)
>
>
>
>                      ->  Seq Scan on tblpuorderstatus os
> (cost=0.00..96498.46 rows=11185486 width=8)
>
>                      ->  Hash  (cost=3010979.77..3010979.77 rows=529686
> width=4)
>
>                            ->  Gather  (cost=1000.00..3010979.77
> rows=529686 width=4)
>
>                                  Workers Planned: 2
>
>                                  ->  Parallel Seq Scan on
> tblpuorderstatushistory osh  (cost=0.00..2957011.17 rows=220702 width=4)
>
>
>
>                                        Filter: ((cancelled_date IS NULL)
> AND (cc_accept_date IS NOT NULL) AND (vip_order_type = 17))
>
>
>
>                ->  Index Scan using tblcnpatientordermap_pkey on
> tblcnpatientordermap po  (cost=0.09..0.41 rows=1 width=8)
>
>
>
>                      Index Cond: (vip_order_id = os.vip_order_id)
>
>
>
>          ->  Nested Loop Semi Join  (cost=0.17..1.02 rows=1 width=4)
>
>                ->  Index Scan using tblcndoctorpatientmap_pkey on
> tblcndoctorpatientmap d  (cost=0.09..0.39 rows=1 width=8)
>
>                      Index Cond: (vip_patient_id = po.vip_patient_id)
>
>                ->  Index Scan using tblcnaccounts_pkey on tblcnaccounts
> a  (cost=0.08..0.36 rows=1 width=4)
>
>                      Index Cond: (master_user_id = d.master_user_id)
>
>                      Filter: ((user_name)::text = 'dddddd'::text)
>
> (19 rows)
>
>
>
>
>
> Regards,
>
> ravi
>


--
Adrian Klaver
adrian.klaver@aklaver.com


Re: [pgadmin-support] [GENERAL] Queries are taking way longer in 9.6 than 9.5

From
Ravi Tammineni
Date:

Hi Melvin,

 

We have deployed our databases in Heroku and we have followed the upgrade option that they have provided to us. Here is the command.

 

heroku pg:upgrade --app <app_name>

 

I am not sure whether they are doing the vacuum after the upgrade. I have disabled the parallel execution; still execution plan is not correct.

 

                                                          QUERY PLAN

-------------------------------------------------------------------------------------------------------------------------------

Aggregate  (cost=3391172.70..3391172.71 rows=1 width=8)

   ->  Nested Loop Semi Join  (cost=3218963.06..3391149.45 rows=46513 width=0)

         ->  Nested Loop  (cost=3218962.89..3343428.74 rows=46513 width=4)

               ->  Hash Join  (cost=3218962.80..3323993.25 rows=46513 width=4)

                     Hash Cond: (os.order_status_history_id = osh.order_status_history_id)

                     ->  Seq Scan on tblpuorderstatus os  (cost=0.00..96501.53 rows=11185842 width=8)

                     ->  Hash  (cost=3217108.89..3217108.89 rows=529689 width=4)

                           ->  Seq Scan on tblpuorderstatushistory osh  (cost=0.00..3217108.89 rows=529689 width=4)

                                 Filter: ((cancelled_date IS NULL) AND (cc_accept_date IS NOT NULL) AND (vip_order_type = 17))

               ->  Index Scan using tblcnpatientordermap_pkey on tblcnpatientordermap po  (cost=0.09..0.41 rows=1 width=8)

                     Index Cond: (vip_order_id = os.vip_order_id)

         ->  Nested Loop Semi Join  (cost=0.17..1.02 rows=1 width=4)

               ->  Index Scan using tblcndoctorpatientmap_pkey on tblcndoctorpatientmap d  (cost=0.09..0.39 rows=1 width=8)

                     Index Cond: (vip_patient_id = po.vip_patient_id)

               ->  Index Scan using tblcnaccounts_pkey on tblcnaccounts a  (cost=0.08..0.36 rows=1 width=4)

                     Index Cond: (master_user_id = d.master_user_id)

                     Filter: ((user_name)::text = 'rdoyleda'::text)

(17 rows)

 

Thanks

ravi

 

 

 

From: Melvin Davidson [mailto:melvin6925@gmail.com]
Sent: Tuesday, January 17, 2017 11:36 AM
To: Ravi Tammineni <rtammineni@partner.aligntech.com>
Cc: pgsql-admin@postgresql.org; pgsql-general@postgresql.org; pgadmin-support@postgresql.org
Subject: Re: [GENERAL] Queries are taking way longer in 9.6 than 9.5

 

 

 

On Tue, Jan 17, 2017 at 2:31 PM, Ravi Tammineni <rtammineni@partner.aligntech.com> wrote:

Hi,

 

We have recently upgraded to 9.6 and few queries are performing very poorly. Query execution time has increased more 4 or 5 times in 9.6. Qeruy execution plan is also completely changed. I am not sure whether its because of Parallel feature or any bug in 9.6. There are few similar kind of queries and all of them are taking more time in 9.6.

 

Following query is taking 70ms in 9.5 and the same query is taking 2 minutes in 9.6. Execution plan is totally different in 9.6 and seems like there is a major flaw while generating the execution plan. Instead of filtering the low cardinality, its filtering from biggest table. Somehow nested loop joins are screwed up.

 

 

I really appreciate your help.

 

explain analyze

SELECT count(*)

FROM

    tblCnPatientOrderMap po

    JOIN tblPuOrderStatus os ON po.vip_order_id = os.vip_order_id

    JOIN tblPuOrderStatusHistory osh ON os.order_status_history_id = osh.order_status_history_id

WHERE

    exists(SELECT 1

           FROM

               tblCnDoctorPatientMap d

           WHERE d.vip_patient_id = po.vip_patient_id

                 AND exists(SELECT 1

                            FROM

                                tblCnAccounts a

                            WHERE a.master_user_id = d.master_user_id AND

                                  a.user_name = 'dddddd'))

    AND osh.vip_order_type IN (17)--assist

    --AND osh.tx_submit_date IS NOT NULL

    AND osh.cancelled_date IS NULL

    AND osh.cc_accept_date IS NOT NULL;

 

 

##########################  9.5 Execution plan

 

                                                                     QUERY PLAN

-----------------------------------------------------------------------------------------------------------------------------------------------------

Aggregate  (cost=1177.25..1177.26 rows=1 width=0)

   ->  Nested Loop  (cost=67.83..1177.25 rows=5 width=0)

         ->  Nested Loop  (cost=67.71..254.81 rows=1322 width=4)

               ->  Nested Loop  (cost=67.63..104.45 rows=1322 width=4)

                     ->  HashAggregate  (cost=67.54..68.12 rows=192 width=4)

                           Group Key: d.vip_patient_id

 

                           ->  Nested Loop  (cost=0.17..67.44 rows=192 width=4)

                                 ->  Index Scan using unq_user_name on tblcnaccounts a  (cost=0.08..4.09 rows=1 width=4)

                                       Index Cond: ((user_name)::text = 'dddddd'::text)

 

                                 ->  Index Only Scan using idx_tblcndoctorpatientmap on tblcndoctorpatientmap d  (cost=0.09..62.78 rows=192 width=8)

                                       Index Cond: (master_user_id = a.master_user_id)

                     ->  Index Scan using idx_tblcnpatientordermap on tblcnpatientordermap po  (cost=0.09..0.17 rows=7 width=8)

                           Index Cond: (vip_patient_id = d.vip_patient_id)

               ->  Index Scan using tblpuorderstatus_pkey on tblpuorderstatus os  (cost=0.09..0.11 rows=1 width=8)

                     Index Cond: (vip_order_id = po.vip_order_id)

         ->  Index Scan using tblpuorderstatushistory_pkey on tblpuorderstatushistory osh  (cost=0.11..0.69 rows=1 width=4)

               Index Cond: (order_status_history_id = os.order_status_history_id)

               Filter: ((cancelled_date IS NULL) AND (cc_accept_date IS NOT NULL) AND (vip_order_type = 17))

 

#####################################################################################################################################

 

##########################  9.6 Execution plan

                                                             QUERY PLAN

-------------------------------------------------------------------------------------------------------------------------------------

Aggregate  (cost=3185034.17..3185034.17 rows=1 width=8)

   ->  Nested Loop Semi Join  (cost=3012833.92..3185010.91 rows=46511 width=0)

 

         ->  Nested Loop  (cost=3012833.75..3137291.51 rows=46511 width=4)

 

               ->  Hash Join  (cost=3012833.67..3117860.77 rows=46511 width=4)

                     Hash Cond: (os.order_status_history_id = osh.order_status_history_id)

 

                     ->  Seq Scan on tblpuorderstatus os  (cost=0.00..96498.46 rows=11185486 width=8)

                     ->  Hash  (cost=3010979.77..3010979.77 rows=529686 width=4)

                           ->  Gather  (cost=1000.00..3010979.77 rows=529686 width=4)

                                 Workers Planned: 2

                                 ->  Parallel Seq Scan on tblpuorderstatushistory osh  (cost=0.00..2957011.17 rows=220702 width=4)

 

                                       Filter: ((cancelled_date IS NULL) AND (cc_accept_date IS NOT NULL) AND (vip_order_type = 17))

 

               ->  Index Scan using tblcnpatientordermap_pkey on tblcnpatientordermap po  (cost=0.09..0.41 rows=1 width=8)

 

                     Index Cond: (vip_order_id = os.vip_order_id)

 

         ->  Nested Loop Semi Join  (cost=0.17..1.02 rows=1 width=4)

               ->  Index Scan using tblcndoctorpatientmap_pkey on tblcndoctorpatientmap d  (cost=0.09..0.39 rows=1 width=8)

                     Index Cond: (vip_patient_id = po.vip_patient_id)

               ->  Index Scan using tblcnaccounts_pkey on tblcnaccounts a  (cost=0.08..0.36 rows=1 width=4)

                     Index Cond: (master_user_id = d.master_user_id)

                     Filter: ((user_name)::text = 'dddddd'::text)

(19 rows)

 

 

Regards,

ravi


1. Have you run ANALYZE on the database after upgrading?

2. Have you insured that the proper changed were done to the postgresql.conf in 9.6?



--

Melvin Davidson
I reserve the right to fantasize.  Whether or not you
wish to share my fantasy is entirely up to you.
Image removed by sender.

Re: [ADMIN] [GENERAL] Queries are taking way longer in 9.6 than 9.5

From
Ravi Tammineni
Date:
Hi Adrain,

We have deployed our databases in Heroku and we have followed the upgrade option that they have provided to us. Here is
thecommand. 

heroku pg:upgrade --app <app_name>

I am not sure whether they are doing the vacuum after the upgrade or not. I have disabled the parallel execution; still
executionplan is not correct. 

                                                          QUERY PLAN

-------------------------------------------------------------------------------------------------------------------------------
Aggregate  (cost=3391172.70..3391172.71 rows=1 width=8)
   ->  Nested Loop Semi Join  (cost=3218963.06..3391149.45 rows=46513 width=0)
         ->  Nested Loop  (cost=3218962.89..3343428.74 rows=46513 width=4)
               ->  Hash Join  (cost=3218962.80..3323993.25 rows=46513 width=4)
                     Hash Cond: (os.order_status_history_id = osh.order_status_history_id)
                     ->  Seq Scan on tblpuorderstatus os  (cost=0.00..96501.53 rows=11185842 width=8)
                     ->  Hash  (cost=3217108.89..3217108.89 rows=529689 width=4)
                           ->  Seq Scan on tblpuorderstatushistory osh  (cost=0.00..3217108.89 rows=529689 width=4)
                                 Filter: ((cancelled_date IS NULL) AND (cc_accept_date IS NOT NULL) AND (vip_order_type
=17)) 
               ->  Index Scan using tblcnpatientordermap_pkey on tblcnpatientordermap po  (cost=0.09..0.41 rows=1
width=8)
                     Index Cond: (vip_order_id = os.vip_order_id)
         ->  Nested Loop Semi Join  (cost=0.17..1.02 rows=1 width=4)
               ->  Index Scan using tblcndoctorpatientmap_pkey on tblcndoctorpatientmap d  (cost=0.09..0.39 rows=1
width=8)
                     Index Cond: (vip_patient_id = po.vip_patient_id)
               ->  Index Scan using tblcnaccounts_pkey on tblcnaccounts a  (cost=0.08..0.36 rows=1 width=4)
                     Index Cond: (master_user_id = d.master_user_id)
                     Filter: ((user_name)::text = 'rdoyleda'::text)
(17 rows)

Thanks
ravi



-----Original Message-----
From: Adrian Klaver [mailto:adrian.klaver@aklaver.com]
Sent: Tuesday, January 17, 2017 11:42 AM
To: Ravi Tammineni <rtammineni@partner.aligntech.com>; pgsql-admin@postgresql.org; pgsql-general@postgresql.org;
pgadmin-support@postgresql.org
Subject: Re: [GENERAL] Queries are taking way longer in 9.6 than 9.5

On 01/17/2017 11:31 AM, Ravi Tammineni wrote:
> Hi,
>
>
>
> We have recently upgraded to 9.6 and few queries are performing very
> poorly. Query execution time has increased more 4 or 5 times in 9.6.
> Qeruy execution plan is also completely changed. I am not sure whether
> its because of Parallel feature or any bug in 9.6. There are few
> similar kind of queries and all of them are taking more time in 9.6.

How did you upgrade from 9.5 --> 9.6?

Did you run ANALYZE on the tables after the upgrade?

Tend to doubt parallel query is at issue here, as it is turned off by
default:

https://www.postgresql.org/docs/9.6/static/runtime-config-resource.html#GUC-MAX-PARALLEL-WORKERS-PER-GATHER

For more info:

https://www.postgresql.org/docs/9.6/static/parallel-query.html
>
>
>
> Following query is taking 70ms in 9.5 and the same query is taking 2
> minutes in 9.6. Execution plan is totally different in 9.6 and seems
> like there is a major flaw while generating the execution plan.
> Instead of filtering the low cardinality, its filtering from biggest table.
> Somehow nested loop joins are screwed up.
>
>
>
>
>
> I really appreciate your help.
>
>
>
> explain analyze
>
> SELECT count(*)
>
> FROM
>
>     tblCnPatientOrderMap po
>
>     JOIN tblPuOrderStatus os ON po.vip_order_id = os.vip_order_id
>
>     JOIN tblPuOrderStatusHistory osh ON os.order_status_history_id =
> osh.order_status_history_id
>
> WHERE
>
>     exists(SELECT 1
>
>            FROM
>
>                tblCnDoctorPatientMap d
>
>            WHERE d.vip_patient_id = po.vip_patient_id
>
>                  AND exists(SELECT 1
>
>                             FROM
>
>                                 tblCnAccounts a
>
>                             WHERE a.master_user_id = d.master_user_id
> AND
>
>                                   a.user_name = 'dddddd'))
>
>     AND osh.vip_order_type IN (17)--assist
>
>     --AND osh.tx_submit_date IS NOT NULL
>
>     AND osh.cancelled_date IS NULL
>
>     AND osh.cc_accept_date IS NOT NULL;
>
>
>
>
>
> ##########################  9.5 Execution plan
>
>
>
>
> QUERY PLAN
>
> ----------------------------------------------------------------------
> ----------------------------------------------------------------------
> ---------
>
> Aggregate  (cost=1177.25..1177.26 rows=1 width=0)
>
>    ->  Nested Loop  (cost=67.83..1177.25 rows=5 width=0)
>
>          ->  Nested Loop  (cost=67.71..254.81 rows=1322 width=4)
>
>                ->  Nested Loop  (cost=67.63..104.45 rows=1322 width=4)
>
>                      ->  HashAggregate  (cost=67.54..68.12 rows=192
> width=4)
>
>                            Group Key: d.vip_patient_id
>
>
>
>                            ->  Nested Loop  (cost=0.17..67.44 rows=192
> width=4)
>
>                                  ->  Index Scan using unq_user_name on
> tblcnaccounts a  (cost=0.08..4.09 rows=1 width=4)
>
>                                        Index Cond: ((user_name)::text
> =
> 'dddddd'::text)
>
>
>
>                                  ->  Index Only Scan using
> idx_tblcndoctorpatientmap on tblcndoctorpatientmap d
> (cost=0.09..62.78
> rows=192 width=8)
>
>                                        Index Cond: (master_user_id =
> a.master_user_id)
>
>                      ->  Index Scan using idx_tblcnpatientordermap on
> tblcnpatientordermap po  (cost=0.09..0.17 rows=7 width=8)
>
>                            Index Cond: (vip_patient_id =
> d.vip_patient_id)
>
>                ->  Index Scan using tblpuorderstatus_pkey on
> tblpuorderstatus os  (cost=0.09..0.11 rows=1 width=8)
>
>                      Index Cond: (vip_order_id = po.vip_order_id)
>
>          ->  Index Scan using tblpuorderstatushistory_pkey on
> tblpuorderstatushistory osh  (cost=0.11..0.69 rows=1 width=4)
>
>                Index Cond: (order_status_history_id =
> os.order_status_history_id)
>
>                Filter: ((cancelled_date IS NULL) AND (cc_accept_date
> IS NOT NULL) AND (vip_order_type = 17))
>
>
>
> ######################################################################
> ###############################################################
>
>
>
> ##########################  9.6 Execution plan
>
>                                                              QUERY
> PLAN
>
> ----------------------------------------------------------------------
> ---------------------------------------------------------------
>
> Aggregate  (cost=3185034.17..3185034.17 rows=1 width=8)
>
>    ->  Nested Loop Semi Join  (cost=3012833.92..3185010.91 rows=46511
> width=0)
>
>
>
>          ->  Nested Loop  (cost=3012833.75..3137291.51 rows=46511
> width=4)
>
>
>
>                ->  Hash Join  (cost=3012833.67..3117860.77 rows=46511
> width=4)
>
>                      Hash Cond: (os.order_status_history_id =
> osh.order_status_history_id)
>
>
>
>                      ->  Seq Scan on tblpuorderstatus os
> (cost=0.00..96498.46 rows=11185486 width=8)
>
>                      ->  Hash  (cost=3010979.77..3010979.77
> rows=529686
> width=4)
>
>                            ->  Gather  (cost=1000.00..3010979.77
> rows=529686 width=4)
>
>                                  Workers Planned: 2
>
>                                  ->  Parallel Seq Scan on
> tblpuorderstatushistory osh  (cost=0.00..2957011.17 rows=220702
> width=4)
>
>
>
>                                        Filter: ((cancelled_date IS
> NULL) AND (cc_accept_date IS NOT NULL) AND (vip_order_type = 17))
>
>
>
>                ->  Index Scan using tblcnpatientordermap_pkey on
> tblcnpatientordermap po  (cost=0.09..0.41 rows=1 width=8)
>
>
>
>                      Index Cond: (vip_order_id = os.vip_order_id)
>
>
>
>          ->  Nested Loop Semi Join  (cost=0.17..1.02 rows=1 width=4)
>
>                ->  Index Scan using tblcndoctorpatientmap_pkey on
> tblcndoctorpatientmap d  (cost=0.09..0.39 rows=1 width=8)
>
>                      Index Cond: (vip_patient_id = po.vip_patient_id)
>
>                ->  Index Scan using tblcnaccounts_pkey on
> tblcnaccounts a  (cost=0.08..0.36 rows=1 width=4)
>
>                      Index Cond: (master_user_id = d.master_user_id)
>
>                      Filter: ((user_name)::text = 'dddddd'::text)
>
> (19 rows)
>
>
>
>
>
> Regards,
>
> ravi
>


--
Adrian Klaver
adrian.klaver@aklaver.com


Re: [ADMIN] [GENERAL] Queries are taking way longer in 9.6 than 9.5

From
Melvin Davidson
Date:


On Tue, Jan 17, 2017 at 3:12 PM, Ravi Tammineni <rtammineni@partner.aligntech.com> wrote:
Hi Adrain,

We have deployed our databases in Heroku and we have followed the upgrade option that they have provided to us. Here is the command.

heroku pg:upgrade --app <app_name>

I am not sure whether they are doing the vacuum after the upgrade or not. I have disabled the parallel execution; still execution plan is not correct.

                                                          QUERY PLAN
-------------------------------------------------------------------------------------------------------------------------------
Aggregate  (cost=3391172.70..3391172.71 rows=1 width=8)
   ->  Nested Loop Semi Join  (cost=3218963.06..3391149.45 rows=46513 width=0)
         ->  Nested Loop  (cost=3218962.89..3343428.74 rows=46513 width=4)
               ->  Hash Join  (cost=3218962.80..3323993.25 rows=46513 width=4)
                     Hash Cond: (os.order_status_history_id = osh.order_status_history_id)
                     ->  Seq Scan on tblpuorderstatus os  (cost=0.00..96501.53 rows=11185842 width=8)
                     ->  Hash  (cost=3217108.89..3217108.89 rows=529689 width=4)
                           ->  Seq Scan on tblpuorderstatushistory osh  (cost=0.00..3217108.89 rows=529689 width=4)
                                 Filter: ((cancelled_date IS NULL) AND (cc_accept_date IS NOT NULL) AND (vip_order_type = 17))
               ->  Index Scan using tblcnpatientordermap_pkey on tblcnpatientordermap po  (cost=0.09..0.41 rows=1 width=8)
                     Index Cond: (vip_order_id = os.vip_order_id)
         ->  Nested Loop Semi Join  (cost=0.17..1.02 rows=1 width=4)
               ->  Index Scan using tblcndoctorpatientmap_pkey on tblcndoctorpatientmap d  (cost=0.09..0.39 rows=1 width=8)
                     Index Cond: (vip_patient_id = po.vip_patient_id)
               ->  Index Scan using tblcnaccounts_pkey on tblcnaccounts a  (cost=0.08..0.36 rows=1 width=4)
                     Index Cond: (master_user_id = d.master_user_id)
                     Filter: ((user_name)::text = 'rdoyleda'::text)
(17 rows)

Thanks
ravi



-----Original Message-----
From: Adrian Klaver [mailto:adrian.klaver@aklaver.com]
Sent: Tuesday, January 17, 2017 11:42 AM
To: Ravi Tammineni <rtammineni@partner.aligntech.com>; pgsql-admin@postgresql.org; pgsql-general@postgresql.org; pgadmin-support@postgresql.org
Subject: Re: [GENERAL] Queries are taking way longer in 9.6 than 9.5

On 01/17/2017 11:31 AM, Ravi Tammineni wrote:
> Hi,
>
>
>
> We have recently upgraded to 9.6 and few queries are performing very
> poorly. Query execution time has increased more 4 or 5 times in 9.6.
> Qeruy execution plan is also completely changed. I am not sure whether
> its because of Parallel feature or any bug in 9.6. There are few
> similar kind of queries and all of them are taking more time in 9.6.

How did you upgrade from 9.5 --> 9.6?

Did you run ANALYZE on the tables after the upgrade?

Tend to doubt parallel query is at issue here, as it is turned off by
default:

https://www.postgresql.org/docs/9.6/static/runtime-config-resource.html#GUC-MAX-PARALLEL-WORKERS-PER-GATHER

For more info:

https://www.postgresql.org/docs/9.6/static/parallel-query.html
>
>
>
> Following query is taking 70ms in 9.5 and the same query is taking 2
> minutes in 9.6. Execution plan is totally different in 9.6 and seems
> like there is a major flaw while generating the execution plan.
> Instead of filtering the low cardinality, its filtering from biggest table.
> Somehow nested loop joins are screwed up.
>
>
>
>
>
> I really appreciate your help.
>
>
>
> explain analyze
>
> SELECT count(*)
>
> FROM
>
>     tblCnPatientOrderMap po
>
>     JOIN tblPuOrderStatus os ON po.vip_order_id = os.vip_order_id
>
>     JOIN tblPuOrderStatusHistory osh ON os.order_status_history_id =
> osh.order_status_history_id
>
> WHERE
>
>     exists(SELECT 1
>
>            FROM
>
>                tblCnDoctorPatientMap d
>
>            WHERE d.vip_patient_id = po.vip_patient_id
>
>                  AND exists(SELECT 1
>
>                             FROM
>
>                                 tblCnAccounts a
>
>                             WHERE a.master_user_id = d.master_user_id
> AND
>
>                                   a.user_name = 'dddddd'))
>
>     AND osh.vip_order_type IN (17)--assist
>
>     --AND osh.tx_submit_date IS NOT NULL
>
>     AND osh.cancelled_date IS NULL
>
>     AND osh.cc_accept_date IS NOT NULL;
>
>
>
>
>
> ##########################  9.5 Execution plan
>
>
>
>
> QUERY PLAN
>
> ----------------------------------------------------------------------
> ----------------------------------------------------------------------
> ---------
>
> Aggregate  (cost=1177.25..1177.26 rows=1 width=0)
>
>    ->  Nested Loop  (cost=67.83..1177.25 rows=5 width=0)
>
>          ->  Nested Loop  (cost=67.71..254.81 rows=1322 width=4)
>
>                ->  Nested Loop  (cost=67.63..104.45 rows=1322 width=4)
>
>                      ->  HashAggregate  (cost=67.54..68.12 rows=192
> width=4)
>
>                            Group Key: d.vip_patient_id
>
>
>
>                            ->  Nested Loop  (cost=0.17..67.44 rows=192
> width=4)
>
>                                  ->  Index Scan using unq_user_name on
> tblcnaccounts a  (cost=0.08..4.09 rows=1 width=4)
>
>                                        Index Cond: ((user_name)::text
> =
> 'dddddd'::text)
>
>
>
>                                  ->  Index Only Scan using
> idx_tblcndoctorpatientmap on tblcndoctorpatientmap d
> (cost=0.09..62.78
> rows=192 width=8)
>
>                                        Index Cond: (master_user_id =
> a.master_user_id)
>
>                      ->  Index Scan using idx_tblcnpatientordermap on
> tblcnpatientordermap po  (cost=0.09..0.17 rows=7 width=8)
>
>                            Index Cond: (vip_patient_id =
> d.vip_patient_id)
>
>                ->  Index Scan using tblpuorderstatus_pkey on
> tblpuorderstatus os  (cost=0.09..0.11 rows=1 width=8)
>
>                      Index Cond: (vip_order_id = po.vip_order_id)
>
>          ->  Index Scan using tblpuorderstatushistory_pkey on
> tblpuorderstatushistory osh  (cost=0.11..0.69 rows=1 width=4)
>
>                Index Cond: (order_status_history_id =
> os.order_status_history_id)
>
>                Filter: ((cancelled_date IS NULL) AND (cc_accept_date
> IS NOT NULL) AND (vip_order_type = 17))
>
>
>
> ######################################################################
> ###############################################################
>
>
>
> ##########################  9.6 Execution plan
>
>                                                              QUERY
> PLAN
>
> ----------------------------------------------------------------------
> ---------------------------------------------------------------
>
> Aggregate  (cost=3185034.17..3185034.17 rows=1 width=8)
>
>    ->  Nested Loop Semi Join  (cost=3012833.92..3185010.91 rows=46511
> width=0)
>
>
>
>          ->  Nested Loop  (cost=3012833.75..3137291.51 rows=46511
> width=4)
>
>
>
>                ->  Hash Join  (cost=3012833.67..3117860.77 rows=46511
> width=4)
>
>                      Hash Cond: (os.order_status_history_id =
> osh.order_status_history_id)
>
>
>
>                      ->  Seq Scan on tblpuorderstatus os
> (cost=0.00..96498.46 rows=11185486 width=8)
>
>                      ->  Hash  (cost=3010979.77..3010979.77
> rows=529686
> width=4)
>
>                            ->  Gather  (cost=1000.00..3010979.77
> rows=529686 width=4)
>
>                                  Workers Planned: 2
>
>                                  ->  Parallel Seq Scan on
> tblpuorderstatushistory osh  (cost=0.00..2957011.17 rows=220702
> width=4)
>
>
>
>                                        Filter: ((cancelled_date IS
> NULL) AND (cc_accept_date IS NOT NULL) AND (vip_order_type = 17))
>
>
>
>                ->  Index Scan using tblcnpatientordermap_pkey on
> tblcnpatientordermap po  (cost=0.09..0.41 rows=1 width=8)
>
>
>
>                      Index Cond: (vip_order_id = os.vip_order_id)
>
>
>
>          ->  Nested Loop Semi Join  (cost=0.17..1.02 rows=1 width=4)
>
>                ->  Index Scan using tblcndoctorpatientmap_pkey on
> tblcndoctorpatientmap d  (cost=0.09..0.39 rows=1 width=8)
>
>                      Index Cond: (vip_patient_id = po.vip_patient_id)
>
>                ->  Index Scan using tblcnaccounts_pkey on
> tblcnaccounts a  (cost=0.08..0.36 rows=1 width=4)
>
>                      Index Cond: (master_user_id = d.master_user_id)
>
>                      Filter: ((user_name)::text = 'dddddd'::text)
>
> (19 rows)
>
>
>
>
>
> Regards,
>
> ravi
>


--
Adrian Klaver
adrian.klaver@aklaver.com


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

>I am not sure whether they are doing the vacuum after the upgrade or not
So just run an ANALYZE on the database!








--
Melvin Davidson
I reserve the right to fantasize.  Whether or not you
wish to share my fantasy is entirely up to you.