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:-
- 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.
- We were upgrading from 12.4 version to (13.4 and later)
- vCPU: 2 , RAM: 8 GB
- Attached Stats for all tables in this schema for your reference.
- Attached is metadata for one of the table person for your reference.
We have performed many such below steps, but it did not help:-
- We have performed Vacuum/Analyze/Reindex post Upgrade.
- 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
- Disabled Seqcan/ nestedloop
- Tweaked random_page_cost/seq_page_cost
- Set default_statistics_target=1000 and then run vacuum(analyze,verbose) on selected tables.
- 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,
Technical Specialist,
Data Platform Support & Delivery
-----Original Message-----
From: Tom Lane <tgl@xxxxxxxxxxxxx>
Sent: Monday, March 21, 2022 7:29 PM
To: Prajna Shetty <Prajna.Shetty@xxxxxxxxxxxx>
Cc: pgsql-bugs@xxxxxxxxxxxxxxxxxxxx; Beenu Sharma <Beenu.Sharma@xxxxxxxxxxxx>
Subject: Re: Performance issue post upgrade on Version 13 - Incorrect Estimation Cost choosing Hash Aggregate-Nested Left Loop Join
From: Tom Lane <tgl@xxxxxxxxxxxxx>
Sent: Monday, March 21, 2022 7:29 PM
To: Prajna Shetty <Prajna.Shetty@xxxxxxxxxxxx>
Cc: pgsql-bugs@xxxxxxxxxxxxxxxxxxxx; Beenu Sharma <Beenu.Sharma@xxxxxxxxxxxx>
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.Shetty@xxxxxxxxxxxx> 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
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
________________________________
Attachment:
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"Attachment:
pg_class_202203221142.csv
Description: pg_class_202203221142.csv
Attachment:
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"
