++ pgsql-performa...@postgresql.org<https://www.postgresql.org/list/pgsql-performance/>
Hello Team,
There is change in query plan in 12.4 version and Version 13 resulting in
performance slowness post upgrade.
* In 12.4 version, Sort Operation Group Aggregate is selected which
results to Merge Join. Query takes ~5 seconds.
* In 13.5 version, optimizer wrongly estimates and due to new Disk Based
Hash Aggregate feature, it prefers Hash Aggregate instead of Sort Operation
which finally blocks merge-join and chooses Nested Loop Left Join. Query takes
~5 minutes.
NOTE: Disabling Hash Aggregate on instance level forces optimizer to
choose merge operation but such instance level modification is not possible in
terms of Application Functionality.
This performance issue is on all over most of queries. Attached one of the
query and its plan in both version for reference in case that helps for
recreating the issue.
Version 13 query plan has lower estimated cost than that of 12.4 which implies
13.5 planner thought it found a better plan, but it is running slower and
actual cost show more.
12.4 Version:
"Merge Right Join (cost=202198.78..295729.10 rows=1 width=8) (actual
time=1399.727..5224.574 rows=296 loops=1)"
13.5 version:-
"Nested Loop Left Join (cost=196360.90..287890.45 rows=1 width=8) (actual
time=3209.577..371300.693 rows=296 loops=1)"
Details:-
1. It is AWS Aurora-Postgresql RDS instance. We have raised case with AWS
and since this issue is a regression coming from the community PostgreSQL code,
we would like to raise bug here.
2. We were upgrading from 12.4 version to (13.4 and later)
3. vCPU: 2 , RAM: 8 GB
4. Attached Stats for all tables in this schema for your reference.
5. Attached is metadata for one of the table person for your reference.
We have performed many such below steps, but it did not help:-
1. We have performed Vacuum/Analyze/Reindex post Upgrade.
2. Tweaked work_mem so it does not spill to Disk. We can Disk Usage But it
is still using Hash Aggregate and came down from 5 minutes to 20 seconds.
(Expected ~5 seconds). Attached plan after modifying work_mem
3. Disabled Seqcan/ nestedloop
4. Tweaked random_page_cost/seq_page_cost
5. Set default_statistics_target=1000 and then run vacuum(analyze,verbose)
on selected tables.
6. We have also tested performance by increasing resources up to 4 vCPU
and 32 GB RAM.
Could you please check and confirm if this incorrect Cost Estimation is known
concern in Version 13 where in some cases optimizer calculates and prefers Hash
Aggregate==>Nested Left Loop Join instead of Merge Join?
Thanks & Regards,
Prajna Shetty
Technical Specialist,
Data Platform Support & Delivery
-----Original Message-----
From: Tom Lane <t...@sss.pgh.pa.us>
Sent: Monday, March 21, 2022 7:29 PM
To: Prajna Shetty <prajna.she...@mindtree.com>
Cc: pgsql-b...@lists.postgresql.org; Beenu Sharma <beenu.sha...@mindtree.com>
Subject: Re: Performance issue post upgrade on Version 13 - Incorrect
Estimation Cost choosing Hash Aggregate-Nested Left Loop Join
* This e-mail originated outside of Mindtree. Exercise caution before clicking
links or opening attachments *
Prajna Shetty <prajna.she...@mindtree.com<mailto:prajna.she...@mindtree.com>>
writes:
> There is change in query plan in 12.4 version and Version 13 resulting in
> performance slowness post upgrade.
Standard upgrade methods don't transfer statistics from the old version, so the
first question to ask is have you ANALYZE'd the relevant tables since upgrading?
If you have, then to offer useful help with this we'll need to see all the
details described in
https://apc01.safelinks.protection.outlook.com/?url=https%3A%2F%2Fwiki.postgresql.org%2Fwiki%2FSlow_Query_Questions&data=04%7C01%7CPrajna.Shetty%40mindtree.com%7C5ca04f6fdd7b452f51f508da0b42fc8e%7C85c997b9f49446b3a11d772983cf6f11%7C0%7C0%7C637834679772208865%7CUnknown%7CTWFpbGZsb3d8eyJWIjoiMC4wLjAwMDAiLCJQIjoiV2luMzIiLCJBTiI6Ik1haWwiLCJXVCI6Mn0%3D%7C2000&sdata=sx8OsD%2FpfdcSHV%2FUsm4Vtm7tadbZIugLFZaXfD7X%2BZc%3D&reserved=0
In any case, this is unlikely to be a bug. The pgsql-performance list would be
a more suitable place to discuss it.
regards, tom lane
________________________________
http://www.mindtree.com/email/disclaimer.html
srs.sql
Description: srs.sql
"Nested Loop Left Join (cost=196360.90..287890.45 rows=1 width=8) (actual
time=3209.577..371300.693 rows=296 loops=1)"
" Join Filter: (s.aamc_id = ssd.aamc_id)"
" Rows Removed by Join Filter: 60348903"
" -> Nested Loop (cost=15232.70..101055.49 rows=1 width=12) (actual
time=470.584..2428.982 rows=294 loops=1)"
" -> Nested Loop (cost=15232.56..101055.33 rows=1 width=17) (actual
time=470.552..2424.584 rows=294 loops=1)"
" -> Nested Loop (cost=15232.43..101055.17 rows=1 width=19)
(actual time=470.532..2420.321 rows=294 loops=1)"
" -> Gather Merge (cost=15232.29..101055.01 rows=1
width=20) (actual time=470.485..2411.475 rows=300 loops=1)"
" Workers Planned: 2"
" Workers Launched: 2"
" -> Nested Loop (cost=14232.26..100054.87 rows=1
width=20) (actual time=433.720..3722.428 rows=100 loops=3)"
" Join Filter:
(((max(student_status_detail.status_effective_dt)) = s.status_effective_dt) AND
((max(student_status_detail.last_updated_ts)) = s.last_updated_ts))"
" Rows Removed by Join Filter: 75"
" -> Merge Join (cost=14231.84..99998.30
rows=1 width=32) (actual time=433.629..3680.031 rows=100 loops=3)"
" Merge Cond: (p.aamc_id =
student_class_detail.aamc_id)"
" -> Sort (cost=14231.41..14231.79
rows=153 width=28) (actual time=188.132..188.268 rows=103 loops=3)"
" Sort Key: p.aamc_id"
" Sort Method: quicksort Memory:
38kB"
" Worker 0: Sort Method: quicksort
Memory: 27kB"
" Worker 1: Sort Method: quicksort
Memory: 33kB"
" -> Nested Loop
(cost=1192.00..14225.86 rows=153 width=28) (actual time=12.764..187.994
rows=103 loops=3)"
" Join Filter:
(student_status_detail.aamc_id = p.aamc_id)"
" -> Hash Join
(cost=1191.58..14146.71 rows=149 width=22) (actual time=12.691..186.193
rows=103 loops=3)"
" Hash Cond:
(sdp.aamc_id = student_status_detail.aamc_id)"
" -> Parallel Seq Scan
on student_degree_program sdp (cost=0.00..12561.02 rows=150139 width=6)
(actual time=0.028..151.578 rows=120438 loops=3)"
" Filter:
((degree_program_type_cd)::text = '2'::text)"
" Rows Removed by
Filter: 240907"
" -> Hash
(cost=1186.98..1186.98 rows=368 width=16) (actual time=2.054..2.056 rows=309
loops=3)"
" Buckets: 1024
Batches: 1 Memory Usage: 23kB"
" ->
HashAggregate (cost=1179.62..1183.30 rows=368 width=16) (actual
time=1.860..1.935 rows=309 loops=3)"
" Group Key:
student_status_detail.aamc_id"
" Batches: 1
Memory Usage: 61kB"
" Worker 0:
Batches: 1 Memory Usage: 61kB"
" Worker 1:
Batches: 1 Memory Usage: 61kB"
" -> Bitmap
Heap Scan on student_status_detail (cost=12.20..1176.86 rows=368 width=16)
(actual time=0.197..1.683 rows=317 loops=3)"
"
Recheck Cond: ((institution_id = 159) AND ((academic_year)::text =
'2001'::text))"
" Heap
Blocks: exact=304"
" ->
Bitmap Index Scan on
uk_student_status_detail_institutionid_academicyear_aamcid_enro
(cost=0.00..12.11 rows=368 width=0) (actual time=0.122..0.123 rows=317 loops=3)"
"
Index Cond: ((institution_id = 159) AND ((academic_year)::text =
'2001'::text))"
" -> Index Scan using
pk_person on person p (cost=0.42..0.52 rows=1 width=6) (actual
time=0.013..0.013 rows=1 loops=309)"
" Index Cond: (aamc_id =
sdp.aamc_id)"
" Filter:
((record_deleted_ind)::text = 'N'::text)"
" -> GroupAggregate (cost=0.43..85743.24
rows=1830 width=72) (actual time=1.621..3452.034 rows=282179 loops=3)"
" Group Key:
student_class_detail.aamc_id"
" Filter:
(max((student_class_detail.class_level_cd)::text) = '4'::text)"
" Rows Removed by Filter: 76060"
" -> Index Scan using
uk_student_class_detail_aamcid_classlevelcd on student_class_detail
(cost=0.43..74747.61 rows=1284079 width=6) (actual time=1.570..2723.014
rows=1272390 loops=3)"
" Filter:
(class_level_start_dt IS NOT NULL)"
" Rows Removed by Filter:
160402"
" -> Index Scan using
uk_student_status_detail_institutionid_academicyear_aamcid_enro on
student_status_detail s (cost=0.42..56.55 rows=1 width=28) (actual
time=0.055..0.412 rows=2 loops=300)"
" Index Cond: ((institution_id = 159) AND
(aamc_id = p.aamc_id))"
" -> Index Scan using pk_ref_enrollment_status on
ref_enrollment_status res (cost=0.14..0.16 rows=1 width=5) (actual
time=0.017..0.017 rows=1 loops=300)"
" Index Cond: ((enrollment_status_cd)::text =
(s.enrollment_status_cd)::text)"
" Filter: ((active_ind)::text = ANY ('{Y,N}'::text[]))"
" Rows Removed by Filter: 0"
" -> Index Only Scan using pk_ref_medical_program_type on
ref_medical_program_type rmpt (cost=0.14..0.15 rows=1 width=2) (actual
time=0.006..0.006 rows=1 loops=294)"
" Index Cond: (medical_program_type_cd =
(sdp.medical_program_type_cd)::text)"
" Heap Fetches: 294"
" -> Index Only Scan using pk_ref_academic_year on ref_academic_year a
(cost=0.14..0.16 rows=1 width=5) (actual time=0.006..0.006 rows=1 loops=294)"
" Index Cond: (academic_year = (s.academic_year)::text)"
" Heap Fetches: 294"
" -> HashAggregate (cost=181128.20..183649.79 rows=141563 width=6) (actual
time=1131.677..1235.378 rows=205269 loops=294)"
" Group Key: ssd.aamc_id, rsr.is_allowed_ind"
" Planned Partitions: 4 Batches: 1177 Memory Usage: 4145kB Disk
Usage: 7280kB"
" -> Hash Join (cost=79884.26..173165.28 rows=141563 width=6) (actual
time=339.481..1021.444 rows=274965 loops=294)"
" Hash Cond: (((ssd.enrollment_status_cd)::text =
(rsr.enrollment_status_cd)::text) AND (((lag(ssd.enrollment_status_cd, 1) OVER
(?)))::text = (rsr.next_status_cd)::text))"
" -> WindowAgg (cost=79817.04..91864.96 rows=602396 width=43)
(actual time=339.465..889.700 rows=602396 loops=294)"
" -> Sort (cost=79817.04..81323.03 rows=602396 width=11)
(actual time=339.449..466.022 rows=602396 loops=294)"
" Sort Key: ssd.aamc_id, ssd.status_effective_dt DESC"
" Sort Method: external merge Disk: 12416kB"
" -> Seq Scan on student_status_detail ssd
(cost=0.00..11688.96 rows=602396 width=11) (actual time=0.017..114.151
rows=602396 loops=294)"
" -> Hash (cost=34.09..34.09 rows=2209 width=8) (actual
time=1.058..1.059 rows=2209 loops=1)"
" Buckets: 4096 Batches: 1 Memory Usage: 119kB"
" -> Seq Scan on ref_status_rule rsr (cost=0.00..34.09
rows=2209 width=8) (actual time=0.011..0.434 rows=2209 loops=1)"
"Planning Time: 10.794 ms"
"Execution Time: 371307.301 ms""Merge Right Join (cost=202198.78..295729.10 rows=1 width=8) (actual
time=1399.727..5224.574 rows=296 loops=1)"
" Merge Cond: (ssd.aamc_id = s.aamc_id)"
" Buffers: shared hit=628970, temp read=2092 written=2106"
" -> Unique (cost=187052.73..188113.52 rows=141439 width=6) (actual
time=1005.122..1206.142 rows=206307 loops=1)"
" Buffers: shared hit=5687, temp read=2092 written=2106"
" -> Sort (cost=187052.73..187406.32 rows=141439 width=6) (actual
time=1005.121..1073.008 rows=276329 loops=1)"
" Sort Key: ssd.aamc_id, rsr.is_allowed_ind"
" Sort Method: external merge Disk: 4336kB"
" Buffers: shared hit=5687, temp read=2092 written=2106"
" -> Hash Join (cost=79817.99..173017.25 rows=141439 width=6)
(actual time=384.889..931.901 rows=276332 loops=1)"
" Hash Cond: (((ssd.enrollment_status_cd)::text =
(rsr.enrollment_status_cd)::text) AND (((lag(ssd.enrollment_status_cd, 1) OVER
(?)))::text = (rsr.next_status_cd)::text))"
" Buffers: shared hit=5684, temp read=1550 written=1560"
" -> WindowAgg (cost=79750.76..91788.12 rows=601868
width=43) (actual time=383.781..812.028 rows=601725 loops=1)"
" Buffers: shared hit=5672, temp read=1550
written=1560"
" -> Sort (cost=79750.76..81255.43 rows=601868
width=11) (actual time=383.764..492.718 rows=601725 loops=1)"
" Sort Key: ssd.aamc_id, ssd.status_effective_dt
DESC"
" Sort Method: external merge Disk: 12400kB"
" Buffers: shared hit=5672, temp read=1550
written=1560"
" -> Seq Scan on student_status_detail ssd
(cost=0.00..11687.68 rows=601868 width=11) (actual time=0.021..145.945
rows=601725 loops=1)"
" Buffers: shared hit=5669"
" -> Hash (cost=34.09..34.09 rows=2209 width=8) (actual
time=1.074..1.075 rows=2209 loops=1)"
" Buckets: 4096 Batches: 1 Memory Usage: 119kB"
" Buffers: shared hit=12"
" -> Seq Scan on ref_status_rule rsr
(cost=0.00..34.09 rows=2209 width=8) (actual time=0.027..0.683 rows=2209
loops=1)"
" Buffers: shared hit=12"
" -> Materialize (cost=15146.05..105847.58 rows=1 width=12) (actual
time=392.551..3994.498 rows=296 loops=1)"
" Buffers: shared hit=623283"
" -> Nested Loop (cost=15146.05..105847.57 rows=1 width=12) (actual
time=392.546..3993.909 rows=294 loops=1)"
" Buffers: shared hit=623283"
" -> Nested Loop (cost=15145.91..105847.41 rows=1 width=17)
(actual time=392.507..3991.089 rows=294 loops=1)"
" Buffers: shared hit=622695"
" -> Nested Loop (cost=15145.76..105847.24 rows=1
width=19) (actual time=392.458..3988.371 rows=294 loops=1)"
" Buffers: shared hit=622107"
" -> Gather Merge (cost=15145.62..105847.08 rows=1
width=20) (actual time=392.414..3974.635 rows=300 loops=1)"
" Workers Planned: 2"
" Workers Launched: 2"
" Buffers: shared hit=621507"
" -> Nested Loop (cost=14145.60..104846.94
rows=1 width=20) (actual time=346.402..3741.265 rows=100 loops=3)"
" Join Filter:
(((max(student_status_detail.status_effective_dt)) = s.status_effective_dt) AND
((max(student_status_detail.last_updated_ts)) = s.last_updated_ts))"
" Rows Removed by Join Filter: 75"
" Buffers: shared hit=621507"
" -> Merge Join
(cost=14145.17..104789.57 rows=1 width=32) (actual time=346.302..3674.516
rows=100 loops=3)"
" Merge Cond: (p.aamc_id =
student_class_detail.aamc_id)"
" Buffers: shared hit=608091"
" -> Sort (cost=14144.74..14145.12
rows=150 width=28) (actual time=207.944..208.045 rows=103 loops=3)"
" Sort Key: p.aamc_id"
" Sort Method: quicksort
Memory: 39kB"
" Worker 0: Sort Method:
quicksort Memory: 31kB"
" Worker 1: Sort Method:
quicksort Memory: 27kB"
" Buffers: shared hit=9062"
" -> Nested Loop
(cost=1182.45..14139.32 rows=150 width=28) (actual time=7.876..207.827 rows=103
loops=3)"
" Join Filter:
(student_status_detail.aamc_id = p.aamc_id)"
" Buffers: shared
hit=9054"
" -> Hash Join
(cost=1182.03..14057.72 rows=151 width=22) (actual time=7.799..205.854 rows=103
loops=3)"
" Hash Cond:
(sdp.aamc_id = student_status_detail.aamc_id)"
" Buffers: shared
hit=7816"
" -> Parallel Seq
Scan on student_degree_program sdp (cost=0.00..12485.39 rows=148688 width=6)
(actual time=0.037..172.403 rows=119754 loops=3)"
" Filter:
((degree_program_type_cd)::text = '2'::text)"
" Rows
Removed by Filter: 239438"
" Buffers:
shared hit=6872"
" -> Hash
(cost=1177.50..1177.50 rows=362 width=16) (actual time=3.757..3.760 rows=309
loops=3)"
" Buckets:
1024 Batches: 1 Memory Usage: 23kB"
" Buffers:
shared hit=944"
" ->
HashAggregate (cost=1170.26..1173.88 rows=362 width=16) (actual
time=3.601..3.676 rows=309 loops=3)"
"
Group Key: student_status_detail.aamc_id"
"
Buffers: shared hit=944"
" ->
Bitmap Heap Scan on student_status_detail (cost=20.14..1167.55 rows=362
width=16) (actual time=0.217..3.436 rows=317 loops=3)"
"
Recheck Cond: ((institution_id = 159) AND ((academic_year)::text =
'2001'::text))"
"
Heap Blocks: exact=308"
"
Buffers: shared hit=944"
"
-> Bitmap Index Scan on
uk_student_status_detail_institutionid_academicyear_aamcid_enro
(cost=0.00..20.05 rows=362 width=0) (actual time=0.146..0.146 rows=317 loops=3)"
"
Index Cond: ((institution_id = 159) AND ((academic_year)::text =
'2001'::text))"
"
Buffers: shared hit=20"
" -> Index Scan using
pk_person on person p (cost=0.42..0.53 rows=1 width=6) (actual
time=0.017..0.017 rows=1 loops=309)"
" Index Cond:
(aamc_id = sdp.aamc_id)"
" Filter:
((record_deleted_ind)::text = 'N'::text)"
" Buffers: shared
hit=1238"
" -> GroupAggregate
(cost=0.43..90621.27 rows=1824 width=72) (actual time=0.103..3412.067
rows=285793 loops=3)"
" Group Key:
student_class_detail.aamc_id"
" Filter:
(max((student_class_detail.class_level_cd)::text) = '4'::text)"
" Rows Removed by Filter:
72736"
" Buffers: shared hit=599029"
" -> Index Scan using
uk_student_class_detail_aamcid_classlevelcd on student_class_detail
(cost=0.43..79612.10 rows=1289905 width=6) (actual time=0.076..2586.756
rows=1281478 loops=3)"
" Filter:
(class_level_start_dt IS NOT NULL)"
" Rows Removed by
Filter: 152040"
" Buffers: shared
hit=599029"
" -> Index Scan using
uk_student_status_detail_institutionid_academicyear_aamcid_enro on
student_status_detail s (cost=0.42..57.35 rows=1 width=28) (actual
time=0.109..0.659 rows=2 loops=300)"
" Index Cond: ((institution_id =
159) AND (aamc_id = p.aamc_id))"
" Buffers: shared hit=13416"
" -> Index Scan using pk_ref_enrollment_status on
ref_enrollment_status res (cost=0.14..0.16 rows=1 width=5) (actual
time=0.006..0.006 rows=1 loops=300)"
" Index Cond: ((enrollment_status_cd)::text =
(s.enrollment_status_cd)::text)"
" Filter: ((active_ind)::text = ANY
('{Y,N}'::text[]))"
" Rows Removed by Filter: 0"
" Buffers: shared hit=600"
" -> Index Only Scan using pk_ref_medical_program_type on
ref_medical_program_type rmpt (cost=0.14..0.16 rows=1 width=78) (actual
time=0.005..0.005 rows=1 loops=294)"
" Index Cond: (medical_program_type_cd =
(sdp.medical_program_type_cd)::text)"
" Heap Fetches: 294"
" Buffers: shared hit=588"
" -> Index Only Scan using pk_ref_academic_year on
ref_academic_year a (cost=0.14..0.17 rows=1 width=78) (actual
time=0.005..0.005 rows=1 loops=294)"
" Index Cond: (academic_year = (s.academic_year)::text)"
" Heap Fetches: 294"
" Buffers: shared hit=588"
"Planning Time: 10.344 ms"
"Execution Time: 5228.314 ms"
pg_class_202203221142.csv
Description: pg_class_202203221142.csv
pg_stat_user_tables_202203221139.csv
Description: pg_stat_user_tables_202203221139.csv
"Nested Loop Left Join (cost=178818.14..281451.37 rows=1 width=116) (actual
time=2956.605..23710.391 rows=296 loops=1)"
" Join Filter: (s.aamc_id = ssd.aamc_id)"
" Rows Removed by Join Filter: 60343611"
" -> Nested Loop (cost=15253.88..113286.64 rows=1 width=114) (actual
time=455.051..2166.571 rows=294 loops=1)"
" -> Nested Loop (cost=15253.75..113286.48 rows=1 width=114) (actual
time=455.022..2162.649 rows=294 loops=1)"
" -> Nested Loop (cost=15253.61..113286.32 rows=1 width=100)
(actual time=454.923..2158.974 rows=294 loops=1)"
" -> Gather Merge (cost=15253.47..113286.16 rows=1
width=70) (actual time=454.902..2149.649 rows=300 loops=1)"
" Workers Planned: 2"
" Workers Launched: 2"
" -> Nested Loop (cost=14253.45..112286.02 rows=1
width=70) (actual time=305.956..3499.198 rows=100 loops=3)"
" Join Filter:
(((max(student_status_detail.status_effective_dt)) = s.status_effective_dt) AND
((max(student_status_detail.last_updated_ts)) = s.last_updated_ts))"
" Rows Removed by Join Filter: 75"
" -> Merge Join (cost=14253.02..112226.44
rows=1 width=74) (actual time=305.846..3450.131 rows=100 loops=3)"
" Merge Cond: (p.aamc_id =
student_class_detail.aamc_id)"
" -> Sort (cost=14252.59..14252.98
rows=155 width=34) (actual time=190.244..190.358 rows=103 loops=3)"
" Sort Key: p.aamc_id"
" Sort Method: quicksort Memory:
34kB"
" Worker 0: Sort Method: quicksort
Memory: 37kB"
" Worker 1: Sort Method: quicksort
Memory: 27kB"
" -> Nested Loop
(cost=1216.58..14246.96 rows=155 width=34) (actual time=6.285..190.076 rows=103
loops=3)"
" Join Filter:
(student_status_detail.aamc_id = p.aamc_id)"
" -> Hash Join
(cost=1216.15..14166.55 rows=150 width=22) (actual time=6.219..186.965 rows=103
loops=3)"
" Hash Cond:
(sdp.aamc_id = student_status_detail.aamc_id)"
" -> Parallel Seq Scan
on student_degree_program sdp (cost=0.00..12559.74 rows=148822 width=6)
(actual time=0.025..156.520 rows=120430 loops=3)"
" Filter:
((degree_program_type_cd)::text = '2'::text)"
" Rows Removed by
Filter: 240897"
" -> Hash
(cost=1211.45..1211.45 rows=376 width=16) (actual time=1.203..1.206 rows=309
loops=3)"
" Buckets: 1024
Batches: 1 Memory Usage: 23kB"
" ->
HashAggregate (cost=1203.93..1207.69 rows=376 width=16) (actual
time=1.053..1.123 rows=309 loops=3)"
" Group Key:
student_status_detail.aamc_id"
" Batches: 1
Memory Usage: 61kB"
" Worker 0:
Batches: 1 Memory Usage: 61kB"
" Worker 1:
Batches: 1 Memory Usage: 61kB"
" -> Bitmap
Heap Scan on student_status_detail (cost=16.28..1201.11 rows=376 width=16)
(actual time=0.157..0.857 rows=317 loops=3)"
"
Recheck Cond: ((institution_id = 159) AND ((academic_year)::text =
'2001'::text))"
" Heap
Blocks: exact=303"
" ->
Bitmap Index Scan on
uk_student_status_detail_institutionid_academicyear_aamcid_enro
(cost=0.00..16.19 rows=376 width=0) (actual time=0.103..0.104 rows=317 loops=3)"
"
Index Cond: ((institution_id = 159) AND ((academic_year)::text =
'2001'::text))"
" -> Index Scan using
pk_person on person p (cost=0.42..0.52 rows=1 width=12) (actual
time=0.025..0.025 rows=1 loops=309)"
" Index Cond: (aamc_id =
sdp.aamc_id)"
" Filter:
((record_deleted_ind)::text = 'N'::text)"
" -> GroupAggregate (cost=0.43..97949.47
rows=1887 width=72) (actual time=0.181..3222.790 rows=282171 loops=3)"
" Group Key:
student_class_detail.aamc_id"
" Filter:
(max((student_class_detail.class_level_cd)::text) = '4'::text)"
" Rows Removed by Filter: 76043"
" -> Index Scan using
uk_student_class_detail_aamcid_classlevelcd on student_class_detail
(cost=0.43..80412.09 rows=1281972 width=14) (actual time=0.134..2394.544
rows=1272349 loops=3)"
" Filter:
(class_level_start_dt IS NOT NULL)"
" Rows Removed by Filter:
160402"
" -> Index Scan using
uk_student_status_detail_institutionid_academicyear_aamcid_enro on
student_status_detail s (cost=0.42..59.57 rows=1 width=32) (actual
time=0.074..0.480 rows=2 loops=300)"
" Index Cond: ((institution_id = 159) AND
(aamc_id = p.aamc_id))"
" -> Index Scan using pk_ref_enrollment_status on
ref_enrollment_status res (cost=0.14..0.16 rows=1 width=33) (actual
time=0.017..0.017 rows=1 loops=300)"
" Index Cond: ((enrollment_status_cd)::text =
(s.enrollment_status_cd)::text)"
" Filter: ((active_ind)::text = ANY ('{Y,N}'::text[]))"
" Rows Removed by Filter: 0"
" -> Index Scan using pk_ref_medical_program_type on
ref_medical_program_type rmpt (cost=0.14..0.15 rows=1 width=18) (actual
time=0.004..0.004 rows=1 loops=294)"
" Index Cond: ((medical_program_type_cd)::text =
(sdp.medical_program_type_cd)::text)"
" -> Index Only Scan using pk_ref_academic_year on ref_academic_year a
(cost=0.14..0.16 rows=1 width=5) (actual time=0.005..0.005 rows=1 loops=294)"
" Index Cond: (academic_year = (s.academic_year)::text)"
" Heap Fetches: 294"
" -> HashAggregate (cost=163564.26..164979.79 rows=141553 width=6) (actual
time=8.403..60.930 rows=205251 loops=294)"
" Group Key: ssd.aamc_id, rsr.is_allowed_ind"
" Batches: 1 Memory Usage: 22545kB"
" -> Hash Join (cost=69582.28..162856.49 rows=141553 width=6) (actual
time=656.446..2221.194 rows=274942 loops=1)"
" Hash Cond: (((ssd.enrollment_status_cd)::text =
(rsr.enrollment_status_cd)::text) AND (((lag(ssd.enrollment_status_cd, 1) OVER
(?)))::text = (rsr.next_status_cd)::text))"
" -> WindowAgg (cost=69515.06..81562.10 rows=602352 width=43)
(actual time=655.232..1896.467 rows=602352 loops=1)"
" -> Sort (cost=69515.06..71020.94 rows=602352 width=11)
(actual time=655.213..867.424 rows=602352 loops=1)"
" Sort Key: ssd.aamc_id, ssd.status_effective_dt DESC"
" Sort Method: external merge Disk: 12384kB"
" -> Seq Scan on student_status_detail ssd
(cost=0.00..11688.52 rows=602352 width=11) (actual time=0.010..203.799
rows=602352 loops=1)"
" -> Hash (cost=34.09..34.09 rows=2209 width=8) (actual
time=1.166..1.167 rows=2209 loops=1)"
" Buckets: 4096 Batches: 1 Memory Usage: 119kB"
" -> Seq Scan on ref_status_rule rsr (cost=0.00..34.09
rows=2209 width=8) (actual time=0.014..0.399 rows=2209 loops=1)"
"Planning Time: 7.912 ms"
"Execution Time: 23718.218 ms"
