Queries are taking way longer in 9.6 than 9.5

From: Ravi Tammineni <rtammineni(at)partner(dot)aligntech(dot)com>
To: "pgsql-admin(at)postgresql(dot)org" <pgsql-admin(at)postgresql(dot)org>, "pgsql-general(at)postgresql(dot)org" <pgsql-general(at)postgresql(dot)org>, "pgadmin-support(at)postgresql(dot)org" <pgadmin-support(at)postgresql(dot)org>
Subject: Queries are taking way longer in 9.6 than 9.5
Date: 2017-01-17 19:31:31
Message-ID: MWHPR02MB2655591A4E27B425FABD5E93807C0@MWHPR02MB2655.namprd02.prod.outlook.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgadmin-support pgsql-admin pgsql-general

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

Responses

Browse pgadmin-support by date

  From Date Subject
Next Message Melvin Davidson 2017-01-17 19:36:22 Re: [GENERAL] Queries are taking way longer in 9.6 than 9.5
Previous Message Shira Bezalel 2017-01-17 18:13:11 Function not displaying PARALLEL SAFE on SQL tab

Browse pgsql-admin by date

  From Date Subject
Next Message Melvin Davidson 2017-01-17 19:36:22 Re: [GENERAL] Queries are taking way longer in 9.6 than 9.5
Previous Message Jan Harasym 2017-01-16 08:04:14 Re: Lock Error

Browse pgsql-general by date

  From Date Subject
Next Message Melvin Davidson 2017-01-17 19:36:22 Re: [GENERAL] Queries are taking way longer in 9.6 than 9.5
Previous Message David G. Johnston 2017-01-17 18:40:10 Re: COPY to question