index only scan taking longer to run

Started by Ayub Malmost 5 years ago3 messagesgeneral
Jump to latest
#1Ayub M
hiayub@gmail.com

In the below execution plan, the index scan on five_lima (table has 900m
records) is where it's spending most of its time. I want to bring down the
runtime to a few seconds, how do I optimize it? Tried forcing seq scan and
ran vacuum/analyze but it is not helping.

As per explain analysis from depesz, the index scan on five_lima is
spending 86% of time.

five_lima 2 43,600.875 ms 86.6 % Index Only Scan Backward 1 21,936.780 ms
50.3 % Index Scan 1 21,664.095 ms 49.7 %

https://explain.depesz.com/s/7lXg

GroupAggregate (cost=5236122.79..5238409.75 rows=19058 width=392)
(actual time=50337.968..50338.284 rows=76 loops=1)
Group Key: ((((((three.papa)::text || 'sierra_tango'::text) ||
(quebec_three.mike_india)::text) ||
bravo_five((quebec_three.sierra_uniform)::text, 3,
'november_golf'::text)) || 'lima_charlie'::text)),
quebec_three.mike_india, quebec_three.sierra_uniform
-> Sort (cost=5236122.79..5236170.44 rows=19058 width=120) (actual
time=50337.880..50337.903 rows=773 loops=1)
Sort Key: ((((((three.papa)::text || 'sierra_tango'::text)
|| (quebec_three.mike_india)::text) ||
bravo_five((quebec_three.sierra_uniform)::text, 3,
'november_golf'::text)) || 'lima_charlie'::text)),
quebec_three.mike_india, quebec_three.sierra_uniform
Sort Method: quicksort Memory: 142kB
-> Hash Left Join (cost=5221327.29..5234767.95 rows=19058
width=120) (actual time=49423.721..50337.319 rows=773 loops=1)
Hash Cond: (((quebec_three.mike_india)::bpchar =
three.mike_india) AND (quebec_three.sierra_uniform =
three.sierra_uniform))
-> GroupAggregate (cost=5221204.51..5233639.85
rows=19058 width=292) (actual time=49422.982..50336.121 rows=773
loops=1)
Group Key: quebec_three.mike_india,
quebec_three.sierra_uniform, quebec_three.whiskey, quebec_three.tango,
quebec_three.juliet_charlie, quebec_three.victor_papa,
quebec_three.yankee, quebec_three.india_papa,
quebec_three.victor_charlie, quebec_three.november_hotel,
quebec_three.hotel_november
-> Sort (cost=5221204.51..5221680.96 rows=190580
width=228) (actual time=49408.728..49416.532 rows=250551 loops=1)
Sort Key: quebec_three.mike_india,
quebec_three.sierra_uniform, quebec_three.whiskey, quebec_three.tango,
quebec_three.juliet_charlie, quebec_three.victor_papa,
quebec_three.yankee, quebec_three.india_papa,
quebec_three.victor_charlie, quebec_three.november_hotel,
quebec_three.hotel_november
Sort Method: quicksort Memory: 27472kB
-> Subquery Scan on quebec_three
(cost=5191626.46..5204490.61 rows=190580 width=228) (actual
time=49045.224..49167.610 rows=250551 loops=1)
-> Unique
(cost=5191626.46..5198773.21 rows=190580 width=286) (actual
time=49045.204..49136.969 rows=250551 loops=1)
-> Sort
(cost=5191626.46..5192102.91 rows=190580 width=286) (actual
time=49045.190..49071.536 rows=252496 loops=1)
Sort Key:
mike_november1.sierra_uniform, mike_november1.charlie_six,
mike_november1.foxtrot_india, (xray(mike_november1.delta_xray,
'zulu'::text)), mike_november1.whiskey, quebec_sierra.tango,
quebec_sierra.juliet_charlie, golf.oscar_lima, (CASE WHEN
((("six_four"((five_hotel.tango)::text, 2))::integer = 5) AND
(five_hotel.juliet_charlie <> november_november
('charlie_tango'::bpchar[]))) THEN 'oscar_romeo'::text ELSE NULL::text
END), (CASE WHEN ((("six_four"((five_hotel.tango)::text, 2))::integer
= 5) AND (five_hotel.juliet_charlie = ANY
('charlie_tango'::bpchar[]))) THEN 'romeo'::text ELSE NULL::text END),
(CASE WHEN ((("six_four"((five_hotel.tango)::text, 2))::integer = 6)
AND (five_hotel.juliet_charlie <> november_november
('charlie_tango'::bpchar[]))) THEN 'oscar_romeo'::text ELSE NULL::text
END), (CASE WHEN ((("six_four"((five_hotel.tango)::text, 2))::integer
= 6) AND (five_hotel.juliet_charlie = ANY
('charlie_tango'::bpchar[]))) THEN 'romeo'::text ELSE NULL::text END),
(CASE WHEN (golf.oscar_lima five_romeo NOT NULL) THEN
'delta_foxtrot'::text ELSE 'oscar_romeo'::text END), (CASE WHEN
(("six_four"((five_hotel.tango)::text, 2))::integer = 15) THEN
'oscar_romeo'::text ELSE NULL::text END)
Sort Method: quicksort
Memory: 41652kB
-> Nested Loop Left Join
(cost=661986.99..5174912.56 rows=190580 width=286) (actual
time=1737.304..47625.922 rows=252496 loops=1)
-> Gather
(cost=661986.29..3041816.11 rows=190580 width=79) (actual
time=1733.755..1827.448 rows=252383 loops=1)
Workers Planned: 2
Workers Launched: 2
-> Parallel
Hash Left Join (cost=660986.29..3021758.11 rows=79408 width=79)
(actual time=1723.881..8094.375 rows=84128 loops=3)
Hash
Cond: (((mike_november1.mike_india)::text =
(seven_quebec.mike_india)::text) AND
((mike_november1.foxtrot_india)::text =
(seven_quebec.foxtrot_india)::text) AND (mike_november1.sierra_uniform
= seven_quebec.sierra_uniform))
->
Nested Loop Left Join (cost=420698.30..2780844.78 rows=79408
width=74) (actual time=1263.213..7579.180 rows=84128 loops=3)
->
Nested Loop Left Join (cost=420697.72..2359299.65 rows=79408
width=69) (actual time=1262.995..6114.930 rows=84128 loops=3)

-> Nested Loop Left Join (cost=420697.15..1943062.02 rows=79408
width=53) (actual time=1262.617..4846.387 rows=83834 loops=3)

-> Parallel Hash Left Join (cost=420691.40..1289489.61
rows=79408 width=53) (actual time=1262.432..3244.712 rows=83191
loops=3)

Hash Cond: (((mike_november1.mike_india)::text =
(five_hotel.mike_india)::text) AND
((mike_november1.foxtrot_india)::text =
(five_hotel.foxtrot_india)::text) AND (mike_november1.sierra_uniform =
five_hotel.sierra_uniform))

-> Parallel Index Scan using lima_papa on six_echo
juliet_xray_xray (cost=0.57..867904.42 rows=79408 width=45) (actual
time=1.304..1922.996 rows=83190 loops=3)

Index Cond: ((delta_xray >=
'four_kilo'::timestamp without time zone) AND (delta_xray <=
'uniform'::timestamp without time zone) AND ((mike_india)::text =
'five_papa'::text))

Filter: (oscar_quebec = 'quebec_golf'::numeric)

Rows Removed by Filter: 115955

-> Parallel Hash (cost=404875.54..404875.54
rows=421741 width=32) (actual time=1259.567..1259.567 rows=93164
loops=3)

Buckets: 1048576 Batches: 1 Memory Usage:
27936kB

-> Parallel Bitmap Heap Scan on delta_echo
five_hotel (cost=87668.95..404875.54 rows=421741 width=32) (actual
time=947.771..1217.127 rows=93164 loops=3)

Recheck Cond: ((mike_india)::text =
'five_papa'::text)

Heap Blocks: exact=24664

-> Bitmap Index Scan on india_three
(cost=0.00..87415.90 rows=1012179 width=0) (actual
time=935.805..935.805 rows=466562 loops=1)

Index Cond: ((mike_india)::text =
'five_papa'::text)

-> Bitmap Heap Scan on two_bravo juliet_xray_delta
(cost=5.76..8.20 rows=1 width=32) (actual time=0.018..0.018 rows=1
loops=249572)

Recheck Cond: (((charlie_six)::text =
(mike_november1.charlie_six)::text) AND ((foxtrot_india)::text =
(mike_november1.foxtrot_india)::text))

Filter: (((mike_india)::text = 'five_papa'::text) AND
((mike_india)::text = (mike_november1.mike_india)::text) AND
(sierra_uniform = mike_november1.sierra_uniform))

Heap Blocks: exact=16

-> BitmapAnd (cost=5.76..5.76 rows=1 width=0) (actual
time=0.016..0.016 rows=0 loops=249572)

-> Bitmap Index Scan on victor_three
(cost=0.00..2.74 rows=5 width=0) (actual time=0.010..0.010 rows=1
loops=249572)

Index Cond: ((charlie_six)::text =
(mike_november1.charlie_six)::text)

-> Bitmap Index Scan on two_delta
(cost=0.00..2.77 rows=16 width=0) (actual time=0.010..0.010 rows=1
loops=128367)

Index Cond: ((foxtrot_india)::text =
(mike_november1.foxtrot_india)::text)

-> Index Scan using hotel_oscar on charlie_yankee golf
(cost=0.57..5.21 rows=1 width=40) (actual time=0.015..0.015 rows=1
loops=251501)

Index Cond: ((foxtrot_india)::text =
(mike_november1.foxtrot_india)::text)

Filter: (((mike_india)::text = 'five_papa'::text) AND
((mike_india)::text = (mike_november1.mike_india)::text) AND
(sierra_uniform = mike_november1.sierra_uniform))

Rows Removed by Filter: 0
->
Index Scan using seven_victor on five_charlie bravo_oscar
(cost=0.57..5.28 rows=1 width=23) (actual time=0.017..0.017 rows=1
loops=252383)

Index Cond: ((charlie_six)::text =
(mike_november1.charlie_six)::text)

Filter: (((mike_india)::text = 'five_papa'::text) AND
((mike_india)::text = (mike_november1.mike_india)::text) AND
(sierra_uniform = mike_november1.sierra_uniform))

Rows Removed by Filter: 0
->
Parallel Hash (cost=232855.56..232855.56 rows=198198 width=29)
(actual time=459.697..459.697 rows=66317 loops=3)

Buckets: 524288 Batches: 1 Memory Usage: 16608kB
->
Parallel Bitmap Heap Scan on victor_four seven_quebec
(cost=20722.12..232855.56 rows=198198 width=29) (actual
time=111.386..434.496 rows=66317 loops=3)

Recheck Cond: ((mike_india)::text = 'five_papa'::text)

Heap Blocks: exact=27484

-> Bitmap Index Scan on four_charlie (cost=0.00..20603.20
rows=475676 width=0) (actual time=107.013..107.013 rows=227154
loops=1)

Index Cond: ((mike_india)::text = 'five_papa'::text)
-> Index Scan using
hotel_whiskey on five_lima quebec_sierra (cost=0.70..11.08 rows=1
width=33) (actual time=0.179..0.180 rows=1 loops=252383)
Index Cond:
(((foxtrot_india)::text = (mike_november1.foxtrot_india)::text) AND
((mike_india)::text = (mike_november1.mike_india)::text) AND
((mike_india)::text = 'five_papa'::text) AND (sierra_uniform =
mike_november1.sierra_uniform))
Filter:
(bravo_lima = (delta_four 2))
Rows Removed
by Filter: 6
SubPlan
-> Result
(cost=5.55..5.58 rows=1 width=8) (actual time=0.013..0.013 rows=1
loops=1828065)
InitPlan
->
Limit (cost=0.70..5.55 rows=1 width=8) (actual time=0.012..0.012
rows=1 loops=1828065)

-> Index Only Scan Backward using hotel_whiskey on five_lima
foxtrot_four (cost=0.70..5.55 rows=1 width=8) (actual
time=0.012..0.012 rows=1 loops=1828065)

Index Cond: ((foxtrot_india =
(quebec_sierra.foxtrot_india)::text) AND (mike_india =
(quebec_sierra.mike_india)::text) AND (sierra_uniform =
quebec_sierra.sierra_uniform) AND (oscar_quebec =
quebec_sierra.oscar_quebec) AND (bravo_lima five_romeo NOT NULL))

Heap Fetches: 18062
-> Hash (cost=70.67..70.67 rows=1489 width=20) (actual
time=0.644..0.644 rows=1489 loops=1)
Buckets: 2048 Batches: 1 Memory Usage: 95kB
-> Seq Scan on bravo_zulu three
(cost=0.00..70.67 rows=1489 width=20) (actual time=0.048..0.416
rows=1489 loops=1)
Planning time: 24.541 ms
Execution time: 50356.651 ms

Here is the query -

explain analyze select
quebec_three.mike_india,quebec_three.sierra_uniform,papa
||'('||quebec_three.mike_india||bravo_five(quebec_three.sierra_uniform::text,3,'0')||')'
as papa,sum( dms_appl_pending + dms_appl_done + no_of_fee_pending +
veri_appl_pending
)no_of_appl_done,sum(veri_appl_done)veri_appl_done,sum(veri_appl_rejected)veri_appl_rejected,sum(veri_appl_pending)veri_appl_pending,sum(app_appl_done)appr_appl_done,sum(app_appl_rejected)appr_appl_rejected,sum(app_appl_pending)appr_appl_pending
,sum(no_of_fee_pending)no_of_fee_pending,sum(no_of_fee_done)no_of_fee_done
,sum(dms_appl_pending)dms_appl_pending,sum(dms_appl_done)dms_appl_donefrom(select
quebec_three.mike_india,quebec_three.sierra_uniform,case when
right(quebec_three.tango::text,2)::int=05 and
quebec_three.juliet_charlie ='C' then count(distinct
quebec_three.foxtrot_india) else 0 end veri_appl_done,case when
(victor_papa='R' ) then count(quebec_three.foxtrot_india) else 0 end
as veri_appl_rejected,case when (yankee='P' ) then count(distinct
quebec_three.foxtrot_india) else 0 end as veri_appl_pending,case when
whiskey='A' and (right(quebec_three.tango::text,2)::int=06 and
quebec_three.juliet_charlie ='C') then count(distinct
quebec_three.foxtrot_india) else 0 end app_appl_done,case when
(india_papa='R') then count(distinct quebec_three.foxtrot_india) else
0 end as app_appl_rejected,case when (victor_charlie='P') then
count(distinct quebec_three.foxtrot_india) else 0 end as
app_appl_pending,case when november_hotel='P' then count(distinct
quebec_three.foxtrot_india) else 0 end as no_of_fee_pending,case when
november_hotel='A' then count(distinct quebec_three.foxtrot_india)
else 0 end as no_of_fee_done,case when (hotel_november='P' ) then
count(distinct quebec_three.foxtrot_india) else 0 end as
dms_appl_pending,case when right(quebec_three.tango::text,2)::int=15
and quebec_three.juliet_charlie ='C' then count(distinct
quebec_three.foxtrot_india) else 0 end dms_appl_donefrom(select
distinct quebec_three.mike_india,quebec_three.sierra_uniform
,quebec_three.charlie_six,quebec_three.foxtrot_india,xray(quebec_three.delta_xray,'dd-Mon-yyyy')delta_xray,quebec_three.whiskey,quebec_sierra.tango,quebec_sierra.juliet_charlie,golf.oscar_lima,case
when right(five_hotel.tango::text,2)::int=05 and
five_hotel.juliet_charlie not in ('M','I') then oscar_romeo else null
end yankee,case when right(five_hotel.tango::text,2)::int=05 and
five_hotel.juliet_charlie in ('M','I') then romeo else null end
victor_papa,case when right(five_hotel.tango::text,2)::int=06 and
five_hotel.juliet_charlie not in ('M','I') then oscar_romeo else null
end victor_charlie,case when right(five_hotel.tango::text,2)::int=06
and five_hotel.juliet_charlie in ('M','I') then romeo else null end
india_papa,case when golf.oscar_lima is not null then delta_foxtrot
else oscar_romeo end november_hotel,case when
right(five_hotel.tango::text,2)::int=15 then oscar_romeo else null
end hotel_novemberfrom six_echo quebec_threeleft join delta_echo
five_hotel on five_hotel.foxtrot_india=quebec_three.foxtrot_india and
five_hotel.mike_india=quebec_three.mike_india and
five_hotel.sierra_uniform=quebec_three.sierra_uniformleft join
five_lima quebec_sierra on
quebec_sierra.foxtrot_india=quebec_three.foxtrot_india and
quebec_sierra.mike_india=quebec_three.mike_india and
quebec_sierra.sierra_uniform=quebec_three.sierra_uniform and
quebec_sierra.bravo_lima =(select max(bravo_lima) from five_lima
foxtrot_four where
foxtrot_four.foxtrot_india=quebec_sierra.foxtrot_india and
foxtrot_four.mike_india=quebec_sierra.mike_india and
foxtrot_four.sierra_uniform=quebec_sierra.sierra_uniform and
foxtrot_four.oscar_quebec=quebec_sierra.oscar_quebec)left join
hsrp.vt_hsrp h on h.foxtrot_india=quebec_three.foxtrot_india and
h.charlie_six=quebec_three.charlie_six and
h.mike_india=quebec_three.mike_india and
h.sierra_uniform=quebec_three.sierra_uniformleft join two_bravo
juliet_xray_delta on
juliet_xray_delta.foxtrot_india=quebec_three.foxtrot_india and
juliet_xray_delta.charlie_six=quebec_three.charlie_six and
juliet_xray_delta.mike_india=quebec_three.mike_india and
juliet_xray_delta.sierra_uniform=quebec_three.sierra_uniformleft join
charlie_yankee golf on golf.foxtrot_india=quebec_three.foxtrot_india
and golf.mike_india=quebec_three.mike_india and
golf.sierra_uniform=quebec_three.sierra_uniformleft join five_charlie
bravo_oscar on bravo_oscar.charlie_six=quebec_three.charlie_six and
bravo_oscar.mike_india=quebec_three.mike_india and
bravo_oscar.sierra_uniform=quebec_three.sierra_uniform left join
victor_four seven_quebec on
seven_quebec.foxtrot_india=quebec_three.foxtrot_india and
seven_quebec.mike_india=quebec_three.mike_india and
seven_quebec.sierra_uniform=quebec_three.sierra_uniform left join
vm_vh_class vh on
vh.vh_class=COALESCE(bravo_oscar.vh_class,seven_quebec.vh_class)where
quebec_three.mike_india='UP' and case when 0=0 then true else
quebec_three.sierra_uniform=0 end and quebec_three.delta_xray
between '2021-03-01 00:00:00.000000 +05:30' and ('2021-04-02
23:59:59.999000 +05:30'::date + interval '1 day' - interval '1
sec')and quebec_three.oscar_quebec in (123)
)quebec_threegroup by
1,2,whiskey,quebec_three.tango,quebec_three.juliet_charlie,victor_papa,yankee,india_papa,victor_charlie,november_hotel,hotel_november
)quebec_three left join bravo_zulu three on
three.mike_india=quebec_three.mike_india and
three.sierra_uniform=quebec_three.sierra_uniformgroup by 1,2,3 order
by 3;

Adding orignal partial query/indexes/plan -

Partial query:
.....
vow4(# left join vha_status c on c.appl_no=a.appl_no and
c.state_cd=a.state_cd and c.off_cd=a.off_cd
vow4(# and c.moved_on =(select max(moved_on) from vha_status c1 where
c1.appl_no=c.appl_no
vow4(# and c1.state_cd=c.state_cd and c1.off_cd=c.off_cd and c1.pur_cd=c.pur_cd)
.....
vow4(# where a.state_cd='UP' and case when 0=0 then true else
a.off_cd=0 end and a.appl_dt between '2021-03-01 00:00:00.000000
+05:30' and ('2021-04-02 23:59:59.999000 +05:30'::date + interval '1
day' - interval '1 sec')
vow4(# and a.pur_cd in (123)

Indexes:
"vha_status_pkey" PRIMARY KEY, btree (appl_no, pur_cd, file_movement_slno)
"idx_state_cd_vha_status" btree (state_cd)
"va_status_moved_on_indx" btree (moved_on)
"vha_status_appl_no_state_cd_off_cd_pur_cd_moved_on_idx" btree
(appl_no, state_cd, off_cd, pur_cd, moved_on)
"vha_status_movedon_state_cd_off_cd_idx" btree (moved_on, state_cd, off_cd)

Partial Plan:-> Index Scan using
vha_status_appl_no_state_cd_off_cd_pur_cd_moved_on_idx on vha_status c
(cost=0.70..11.08 rows=1 width=33) (actual time=0.179..0.180 rows=1
loops=252383)
Index Cond:
(((appl_no)::text = (a_1.appl_no)::text) AND ((state_cd)::text =
(a_1.state_cd)::text) AND ((state_cd)::text = 'UP'::text) AND (off_cd
= a_1.off_cd))
Filter:
(moved_on = (SubPlan 2))
Rows Removed
by Filter: 6
SubPlan 2
-> Result
(cost=5.55..5.58 rows=1 width=8) (actual time=0.013..0.013 rows=1
loops=1828065)

InitPlan 1 (returns $4)
->
Limit (cost=0.70..5.55 rows=1 width=8) (actual time=0.012..0.012
rows=1 loops=1828065)

-> Index Only Scan Backward using
vha_status_appl_no_state_cd_off_cd_pur_cd_moved_on_idx on vha_status
c1 (cost=0.70..5.55 rows=1 width=8) (actual time=0.012..0.012 rows=1
loops=1828065)

Index Cond: ((appl_no = (c.appl_no)::text) AND (state_cd =
(c.state_cd)::text) AND (off_cd = c.off_cd) AND (pur_cd = c.pur_cd)
AND (moved_on IS NOT NULL))

Heap Fetches: 18062

#2Michael Lewis
mlewis@entrata.com
In reply to: Ayub M (#1)
Re: index only scan taking longer to run

Without knowledge of the structure of your data, or even real table/field
names to be able to read the query with some sense of what the tables might
be like, offering advice is rather difficult. I didn't notice any nodes
with huge estimation problems at least.

I will suggest that DISTINCT is often a bad code smell for me with
expecting the system to sort data and remove duplicates, when I should have
controlled my set through proper joins.

Also, when I see a join condition on the result of a subquery, I question
the data structure. re:
bravo_lima = ( SELECT max(bravo_lima) FROM five_lima foxtrot_four ...)

#3David Rowley
dgrowleyml@gmail.com
In reply to: Ayub M (#1)
Re: index only scan taking longer to run

On Thu, 29 Apr 2021 at 21:02, Ayub M <hiayub@gmail.com> wrote:

In the below execution plan, the index scan on five_lima (table has 900m records) is where it's spending most of its time. I want to bring down the runtime to a few seconds, how do I optimize it? Tried forcing seq scan and ran vacuum/analyze but it is not helping.

You might want to look into the track_io_timing GUC and EXPLAIN
(ANALYZE, BUFFERS) to get an idea of if the additional time is spent
doing I/O or not.

As per explain analysis from depesz, the index scan on five_lima is spending 86% of time.

If you don't think the Nested Loop join to five_lima is the best plan,
then you could check if effective_cache_size is set correctly. Too
high a value there could cause more parameterized nested loop joins
than you might like. random_page_cost is also important here. If
that's set too low then the planner might tend prefer nested loops
with index scans more than hash and merge joins.

Check the documents for more details on those settings.

David