It seems an issue of data distribution. More likely when traversing without orderby [default ascending order] matching rows were found quickly. You can validate the same by using order by 14 asc, 2 asc limit 10.
You can try creating an index on auditlogid desc, auditedtime desc. OR any other combination with auditedtime which here higher chances of finding matching rows quickly.
On Tue, Feb 8, 2022 at 11:25 AM Valli Annamalai <aishwaryaanns@xxxxxxxxx> wrote:
Postgres version: 11.4
Problem:
Query choosing Bad Index Path (ASC/DESC ordering). Details are provided below
Table:
\d public.distdbentityauditlog1_46625_temp_mahi3;
Table "public.distdbentityauditlog1_46625_temp_mahi3"
Column | Type | Collation | Nullable | Default
------------------+-----------------------------+-----------+----------+---------
zgid | bigint | | not null |
auditlogid | bigint | | not null |
recordid | bigint | | |
recordname | text | | |
module | character varying(50) | | not null |
actioninfo | character varying(255) | | not null |
relatedid | bigint | | |
relatedname | character varying(255) | | |
relatedmodule | character varying(50) | | |
accountid | bigint | | |
accountname | character varying(255) | | |
doneby | character varying(255) | | not null |
userid | bigint | | |
auditedtime | timestamp without time zone | | not null |
fieldhistoryinfo | text | | |
isauditlogdata | boolean | | not null |
otherdetails | text | | |
audittype | integer | | not null |
requesteruserid | bigint | | |
actiontype | integer | | not null |
source | integer | | not null |
module_lower | character varying(50) | | not null |
Indexes:
"distdbentityauditlog1_46625_temp_mahi3_pkey" PRIMARY KEY, btree (zgid, auditedtime, auditlogid)
"distdbentityauditlog1_idx1_46625_temp_mahi3" btree (recordid)
"distdbentityauditlog1_idx2_46625_temp_mahi3" btree (auditlogid)
"distdbentityauditlog1_idx3_46625_temp_mahi3" btree (relatedid)
"distdbentityauditlog1_idx4_46625_temp_mahi3" gist (actioninfo gist_trgm_ops)
"distdbentityauditlog1_idx5_46625_temp_mahi3" btree (actioninfo)
"distdbentityauditlog1_idx6_46625_temp_mahi3" btree (auditedtime DESC, module)
explain (analyse, buffers, verbose) SELECT zgid, auditlogid, recordid, recordname, module, actioninfo, relatedid, relatedname, relatedmodule, accountid, accountname, doneby, userid, auditedtime, fieldhistoryinfo, isauditlogdata, otherdetails, audittype, requesteruserid, actiontype, source FROM public.distdbentityauditlog1_46625_temp_mahi3 distdbentityauditlog1 WHERE ((actiontype = ANY ('{2,9,14,55,56,67}'::integer[])) AND ((recordid = '15842006928391817'::bigint) OR ((module)::text = 'Contacts'::text)) AND ((recordid = '15842006928391817'::bigint) OR (relatedid = '15842006928391817'::bigint)) AND (audittype <> ALL ('{2,4,5,6}'::integer[])) AND (auditedtime >= '2021-03-27 09:43:17'::timestamp without time zone) AND (zgid = 100)) ORDER BY 14 DESC, 2 DESC LIMIT '10'::bigint;
Limit (cost=0.43..415.30 rows=10 width=400) (actual time=7582.965..7583.477 rows=10 loops=1)
Output: zgid, auditlogid, recordid, recordname, module, actioninfo, relatedid, relatedname, relatedmodule, accountid, accountname, doneby, userid, auditedtime, fieldhistoryinfo, isauditlogdata, otherdetails, audittype, requesteruserid, actiontype, source
Buffers: shared hit=552685 read=1464159
-> Index Scan Backward using distdbentityauditlog1_46625_temp_mahi3_pkey on public.distdbentityauditlog1_46625_temp_mahi3 distdbentityauditlog1 (cost=0.43..436281.55 rows=10516 width=400) (actual time=7582.962..7583.470 rows=10
loops=1)
Output: zgid, auditlogid, recordid, recordname, module, actioninfo, relatedid, relatedname, relatedmodule, accountid, accountname, doneby, userid, auditedtime, fieldhistoryinfo, isauditlogdata, otherdetails, audittype, requesteruserid, actiontype, source
Index Cond: ((distdbentityauditlog1.zgid = 100) AND (distdbentityauditlog1.auditedtime >= '2021-03-27 09:43:17'::timestamp without time zone))
Filter: (((distdbentityauditlog1.recordid = '15842006928391817'::bigint) OR ((distdbentityauditlog1.module)::text = 'Contacts'::text)) AND ((distdbentityauditlog1.recordid = '15842006928391817'::bigint) OR (distdbentityauditlog1.relatedid = '15842006928391817'::bigint)) AND (distdbentityauditlog1.audittype <> ALL ('{2,4,5,6}'::integer[])) AND (distdbentityauditlog1.actiontype = ANY ('{2,9,14,55,56,67}'::integer[])))
Rows Removed by Filter: 2943989
Buffers: shared hit=552685 read=1464159
Planning Time: 0.567 ms
Execution Time: 7583.558 ms
(11 rows)
Doubt:
In Index Scan Backward using distdbentityauditlog1_46625_temp_mahi3_pkey, the startup time was more. So thinking about whether backward scanning takes more time, created a new index and tested with the same query as follows.
create index distdbentityauditlog1_idx7_46625_temp_mahi3 on distdbentityauditlog1_46625_temp_mahi3(zgid, auditedtime desc, module desc);
analyse public.distdbentityauditlog1_46625_temp_mahi3;
explain (analyse, buffers, verbose) SELECT zgid, auditlogid, recordid, recordname, module, actioninfo, relatedid, relatedname, relatedmodule, accountid, accountname, doneby, userid, auditedtime, fieldhistoryinfo, isauditlogdata, otherdetails, audittype, requesteruserid, actiontype, source FROM public.distdbentityauditlog1_46625_temp_mahi3 distdbentityauditlog1 WHERE ((actiontype = ANY ('{2,9,14,55,56,67}'::integer[])) AND ((recordid = '15842006928391817'::bigint) OR ((module)::text = 'Contacts'::text)) AND ((recordid = '15842006928391817'::bigint) OR (relatedid = '15842006928391817'::bigint)) AND (audittype <> ALL ('{2,4,5,6}'::integer[])) AND (auditedtime >= '2021-03-27 09:43:17'::timestamp without time zone) AND (zgid = 100)) ORDER BY 14 DESC, 2 DESC LIMIT '10'::bigint;
Limit (cost=0.43..393.34 rows=10 width=399) (actual time=8115.775..8116.441 rows=10 loops=1)
Output: zgid, auditlogid, recordid, recordname, module, actioninfo, relatedid, relatedname, relatedmodule, accountid, accountname, doneby, userid, auditedtime, fieldhistoryinfo, isauditlogdata, otherdetails, audittype, requesteruserid, actiontype, source
Buffers: shared hit=519970 read=1496874 written=44
-> Index Scan Backward using distdbentityauditlog1_46625_temp_mahi3_pkey on public.distdbentityauditlog1_46625_temp_mahi3 distdbentityauditlog1 (cost=0.43..436209.86 rows=11102 width=399) (actual time=8115.772..8116.435 rows=10
loops=1)
Output: zgid, auditlogid, recordid, recordname, module, actioninfo, relatedid, relatedname, relatedmodule, accountid, accountname, doneby, userid, auditedtime, fieldhistoryinfo, isauditlogdata, otherdetails, audittype, requesteruserid, actiontype, source
Index Cond: ((distdbentityauditlog1.zgid = 100) AND (distdbentityauditlog1.auditedtime >= '2021-03-27 09:43:17'::timestamp without time zone))
Filter: (((distdbentityauditlog1.recordid = '15842006928391817'::bigint) OR ((distdbentityauditlog1.module)::text = 'Contacts'::text)) AND ((distdbentityauditlog1.recordid = '15842006928391817'::bigint) OR (distdbentityauditlog1.relatedid = '15842006928391817'::bigint)) AND (distdbentityauditlog1.audittype <> ALL ('{2,4,5,6}'::integer[])) AND (distdbentityauditlog1.actiontype = ANY ('{2,9,14,55,56,67}'::integer[])))
Rows Removed by Filter: 2943989
Buffers: shared hit=519970 read=1496874 written=44
Planning Time: 1.152 ms
Execution Time: 8116.518 ms
Still no improvement in performance.
If DESC has been removed from ORDER BY clause in query, then the performance is good as follows
explain (analyse, buffers, verbose) SELECT zgid, auditlogid, recordid, recordname, module, actioninfo, relatedid, relatedname, relatedmodule, accountid, accountname, doneby, userid, auditedtime, fieldhistoryinfo, isauditlogdata, otherdetails, audittype, requesteruserid, actiontype, source FROM public.distdbentityauditlog1_46625_temp_mahi3 distdbentityauditlog1 WHERE ((actiontype = ANY ('{2,9,14,55,56,67}'::integer[])) AND ((recordid = '15842006928391817'::bigint) OR ((module)::text = 'Contacts'::text)) AND ((recordid = '15842006928391817'::bigint) OR (relatedid = '15842006928391817'::bigint)) AND (audittype <> ALL ('{2,4,5,6}'::integer[])) AND (auditedtime >= '2021-03-27 09:43:17'::timestamp without time zone) AND (zgid = 100)) ORDER BY 14, 2 LIMIT '10'::bigint;
Limit (cost=0.43..393.34 rows=10 width=399) (actual time=0.471..0.865 rows=10 loops=1)
Output: zgid, auditlogid, recordid, recordname, module, actioninfo, relatedid, relatedname, relatedmodule, accountid, accountname, doneby, userid, auditedtime, fieldhistoryinfo, isauditlogdata, otherdetails, audittype, requesteruserid, actiontype, source
Buffers: shared hit=24 read=111
-> Index Scan using distdbentityauditlog1_46625_temp_mahi3_pkey on public.distdbentityauditlog1_46625_temp_mahi3 distdbentityauditlog1 (cost=0.43..436209.86 rows=11102 width=399) (actual time=0.468..0.860 rows=10 loops=1)
Output: zgid, auditlogid, recordid, recordname, module, actioninfo, relatedid, relatedname, relatedmodule, accountid, accountname, doneby, userid, auditedtime, fieldhistoryinfo, isauditlogdata, otherdetails, audittype, requesteruserid, actiontype, source
Index Cond: ((distdbentityauditlog1.zgid = 100) AND (distdbentityauditlog1.auditedtime >= '2021-03-27 09:43:17'::timestamp without time zone))
Filter: (((distdbentityauditlog1.recordid = '15842006928391817'::bigint) OR ((distdbentityauditlog1.module)::text = 'Contacts'::text)) AND ((distdbentityauditlog1.recordid = '15842006928391817'::bigint) OR (distdbentityauditlog1.relatedid = '15842006928391817'::bigint)) AND (distdbentityauditlog1.audittype <> ALL ('{2,4,5,6}'::integer[])) AND (distdbentityauditlog1.actiontype = ANY ('{2,9,14,55,56,67}'::integer[])))
Rows Removed by Filter: 174
Buffers: shared hit=24 read=111
Planning Time: 0.442 ms
Execution Time: 0.923 ms
Thus how to improve performance for DESC operation here?
Monika Yadav
Phone: 9971515242