I have a problematic query on a view which is taking more than 5 mins to run in aws rds production. The query is simple and there are only 85000 records. Not able to understand why it is taking so long. If I run the query from postgres client it takes 300ms, but the same query when its running from application, in New Relic it shows 5 mins or more. The query is :
select
esnpartvie0_.esn_id as col_0_0_,
esnpartvie0_.esn as col_1_0_,
esnpartvie0_.quarter_point as col_2_0_,
esnpartvie0_.work_order_number as col_3_0_,
esnpartvie0_.site as col_4_0_,
sum(esnpartvie0_.critical) as col_5_0_,
sum(esnpartvie0_.numshort) as col_6_0_,
sum(esnpartvie0_.wa) as col_7_0_,
esnpartvie0_.customer as col_8_0_,
esnpartvie0_.adj_accum_date as col_9_0_,
esnpartvie0_.g2_otr as col_10_0_,
esnpartvie0_.induct_date as col_11_0_,
min(esnpartvie0_.delta) as col_12_0_,
esnpartvie0_.fiscal_week_bucket_date as col_13_0_
from
moa.esn_part_view esnpartvie0_
where
esnpartvie0_.site_id =8
and esnpartvie0_.esn_id =1234
group by
esnpartvie0_.esn_id ,
esnpartvie0_.esn ,
esnpartvie0_.quarter_point ,
esnpartvie0_.work_order_number ,
esnpartvie0_.site ,
esnpartvie0_.customer ,
esnpartvie0_.adj_accum_date ,
esnpartvie0_.g2_otr ,
esnpartvie0_.induct_date ,
esnpartvie0_.fiscal_week_bucket_date
I also have the EXPLAIN ANALYZE BUFFERS FORMAT TEXT plan from pgadmin4 ...though couldnt understand much of it
"GroupAggregate (cost=68482.59..68482.64 rows=1 width=82) (actual time=663.095..663.171 rows=1 loops=1)"
" Group Key: esnpartvie0_.esn_id, esnpartvie0_.esn, esnpartvie0_.quarter_point, esnpartvie0_.work_order_number, esnpartvie0_.site, esnpartvie0_.customer, esnpartvie0_.adj_accum_date, esnpartvie0_.g2_otr, esnpartvie0_.induct_date, esnpartvie0_.fiscal_week_bucket_date"
" Buffers: shared hit=19908, temp read=27667 written=6782"
" -> Sort (cost=68482.59..68482.60 rows=1 width=70) (actual time=663.087..663.163 rows=8 loops=1)"
" Sort Key: esnpartvie0_.esn, esnpartvie0_.quarter_point, esnpartvie0_.work_order_number, esnpartvie0_.site, esnpartvie0_.customer, esnpartvie0_.adj_accum_date, esnpartvie0_.g2_otr, esnpartvie0_.induct_date, esnpartvie0_.fiscal_week_bucket_date"
" Sort Method: quicksort Memory: 26kB"
" Buffers: shared hit=19908, temp read=27667 written=6782"
" -> Subquery Scan on esnpartvie0_ (cost=68482.49..68482.58 rows=1 width=70) (actual time=663.024..663.110 rows=8 loops=1)"
" Buffers: shared hit=19897, temp read=27667 written=6782"
" -> GroupAggregate (cost=68482.49..68482.57 rows=1 width=2016) (actual time=663.023..663.107 rows=8 loops=1)"
" Group Key: e.esn_id, w.number, ed.adj_accum_date, (COALESCE(ed.gate_2_otr, 0)), ed.gate_0_start, ed.gate_1_stop, p.part_id, st.name, mat.name, so.name, dr.name, hpc.hpc_status_name, module.module_name, c.customer_id, m.model_id, ef.engine_family_id, s.site_id, ws.name, ic.comment"
" Buffers: shared hit=19897, temp read=27667 written=6782"
" CTE indexed_comments"
" -> WindowAgg (cost=39839.28..44263.80 rows=221226 width=118) (actual time=165.462..272.574 rows=215274 loops=1)"
" Buffers: shared hit=5135, temp read=3293 written=3301"
" -> Sort (cost=39839.28..40392.34 rows=221226 width=110) (actual time=165.454..197.793 rows=215274 loops=1)"
" Sort Key: part_comment.part_id, part_comment.created_at DESC"
" Sort Method: external merge Disk: 26344kB"
" Buffers: shared hit=5135, temp read=3293 written=3301"
" -> Seq Scan on part_comment (cost=0.00..7344.26 rows=221226 width=110) (actual time=0.019..35.400 rows=215274 loops=1)"
" Buffers: shared hit=5132"
" -> Sort (cost=24218.69..24218.70 rows=1 width=717) (actual time=663.017..663.090 rows=8 loops=1)"
" Sort Key: w.number, ed.adj_accum_date, (COALESCE(ed.gate_2_otr, 0)), ed.gate_0_start, ed.gate_1_stop, p.part_id, st.name, mat.name, so.name, dr.name, hpc.hpc_status_name, module.module_name, c.customer_id, m.model_id, ef.engine_family_id, s.site_id, ws.name, ic.comment"
" Sort Method: quicksort Memory: 27kB"
" Buffers: shared hit=19897, temp read=27667 written=6782"
" -> Nested Loop (cost=1010.23..24218.68 rows=1 width=717) (actual time=412.426..663.017 rows=8 loops=1)"
" Buffers: shared hit=19894, temp read=27667 written=6782"
" -> Nested Loop Left Join (cost=1009.94..24210.36 rows=1 width=697) (actual time=412.389..662.811 rows=8 loops=1)"
" Join Filter: (ic.part_id = p.part_id)"
" Rows Removed by Join Filter: 467615"
" Buffers: shared hit=19870, temp read=27667 written=6782"
" -> Nested Loop Left Join (cost=1009.94..19218.95 rows=1 width=181) (actual time=56.592..57.839 rows=8 loops=1)"
" Buffers: shared hit=14735"
" -> Nested Loop Left Join (cost=1009.81..19218.35 rows=1 width=183) (actual time=56.583..57.812 rows=8 loops=1)"
" Buffers: shared hit=14735"
" -> Nested Loop Left Join (cost=1009.67..19217.66 rows=1 width=181) (actual time=56.576..57.790 rows=8 loops=1)"
" Buffers: shared hit=14735"
" -> Nested Loop Left Join (cost=1009.55..19216.82 rows=1 width=179) (actual time=56.567..57.759 rows=8 loops=1)"
" Buffers: shared hit=14735"
" -> Nested Loop Left Join (cost=1009.42..19216.04 rows=1 width=178) (actual time=56.552..57.699 rows=8 loops=1)"
" Buffers: shared hit=14719"
" -> Nested Loop Left Join (cost=1009.28..19215.37 rows=1 width=175) (actual time=56.536..57.638 rows=8 loops=1)"
" Buffers: shared hit=14703"
" -> Nested Loop Left Join (cost=1009.14..19214.77 rows=1 width=170) (actual time=56.514..57.556 rows=8 loops=1)"
" Join Filter: (e.work_scope_id = ws.work_scope_id)"
" Buffers: shared hit=14687"
" -> Nested Loop Left Join (cost=1009.14..19213.54 rows=1 width=166) (actual time=56.487..57.481 rows=8 loops=1)"
" Join Filter: (e.esn_id = p.esn_id)"
" Buffers: shared hit=14679"
" -> Nested Loop (cost=9.14..31.40 rows=1 width=125) (actual time=0.084..0.134 rows=1 loops=1)"
" Buffers: shared hit=15"
" -> Nested Loop (cost=8.87..23.08 rows=1 width=118) (actual time=0.072..0.122 rows=1 loops=1)"
" Buffers: shared hit=12"
" -> Nested Loop (cost=8.73..21.86 rows=1 width=108) (actual time=0.063..0.111 rows=1 loops=1)"
" Buffers: shared hit=10"
" -> Nested Loop (cost=8.60..21.65 rows=1 width=46) (actual time=0.052..0.100 rows=1 loops=1)"
" Buffers: shared hit=8"
" -> Hash Join (cost=8.31..13.34 rows=1 width=41) (actual time=0.043..0.089 rows=1 loops=1)"
" Hash Cond: (m.model_id = e.model_id)"
" Buffers: shared hit=5"
" -> Seq Scan on model m (cost=0.00..4.39 rows=239 width=17) (actual time=0.011..0.039 rows=240 loops=1)"
" Buffers: shared hit=2"
" -> Hash (cost=8.30..8.30 rows=1 width=28) (actual time=0.011..0.012 rows=1 loops=1)"
" Buckets: 1024 Batches: 1 Memory Usage: 9kB"
" Buffers: shared hit=3"
" -> Index Scan using esn_pkey on esn e (cost=0.29..8.30 rows=1 width=28) (actual time=0.008..0.008 rows=1 loops=1)"
" Index Cond: (esn_id = 140339)"
" Filter: active"
" Buffers: shared hit=3"
" -> Index Scan using work_order_pkey on work_order w (cost=0.29..8.30 rows=1 width=13) (actual time=0.009..0.009 rows=1 loops=1)"
" Index Cond: (work_order_id = e.work_order_id)"
" Buffers: shared hit=3"
" -> Index Scan using engine_family_pkey on engine_family ef (cost=0.14..0.20 rows=1 width=66) (actual time=0.010..0.010 rows=1 loops=1)"
" Index Cond: (engine_family_id = m.engine_family_id)"
" Buffers: shared hit=2"
" -> Index Scan using site_pkey on site s (cost=0.14..1.15 rows=1 width=14) (actual time=0.009..0.009 rows=1 loops=1)"
" Index Cond: (site_id = ef.site_id)"
" Buffers: shared hit=2"
" -> Index Scan using customer_pkey on customer c (cost=0.27..8.29 rows=1 width=11) (actual time=0.011..0.011 rows=1 loops=1)"
" Index Cond: (customer_id = e.customer_id)"
" Buffers: shared hit=3"
" -> Gather (cost=1000.00..19181.78 rows=29 width=41) (actual time=56.400..57.333 rows=8 loops=1)"
" Workers Planned: 2"
" Workers Launched: 2"
" Buffers: shared hit=14664"
" -> Parallel Seq Scan on part p (cost=0.00..18178.88 rows=12 width=41) (actual time=51.721..52.608 rows=3 loops=3)"
" Filter: (active AND (esn_id = 140339))"
" Rows Removed by Filter: 224748"
" Buffers: shared hit=14664"
" -> Seq Scan on work_scope ws (cost=0.00..1.10 rows=10 width=12) (actual time=0.006..0.006 rows=1 loops=8)"
" Buffers: shared hit=8"
" -> Index Scan using source_pkey on source so (cost=0.14..0.57 rows=1 width=13) (actual time=0.006..0.006 rows=1 loops=8)"
" Index Cond: (p.source_id = source_id)"
" Buffers: shared hit=16"
" -> Index Scan using status_pkey on status st (cost=0.13..0.56 rows=1 width=11) (actual time=0.004..0.004 rows=1 loops=8)"
" Index Cond: (p.status_id = status_id)"
" Buffers: shared hit=16"
" -> Index Scan using material_stream_pkey on material_stream mat (cost=0.13..0.56 rows=1 width=9) (actual time=0.004..0.004 rows=1 loops=8)"
" Index Cond: (p.material_stream_id = material_stream_id)"
" Buffers: shared hit=16"
" -> Index Scan using dr_status_pkey on dr_status dr (cost=0.13..0.56 rows=1 width=10) (actual time=0.001..0.001 rows=0 loops=8)"
" Index Cond: (p.dr_status_id = dr_status_id)"
" -> Index Scan using hpc_status_pkey on hpc_status hpc (cost=0.13..0.56 rows=1 width=10) (actual time=0.001..0.001 rows=0 loops=8)"
" Index Cond: (p.hpc_status_id = hpc_status_id)"
" -> Index Scan using module_pkey on module (cost=0.14..0.57 rows=1 width=6) (actual time=0.001..0.001 rows=0 loops=8)"
" Index Cond: (p.module_id = module_id)"
" -> CTE Scan on indexed_comments ic (cost=0.00..4977.59 rows=1106 width=520) (actual time=20.687..71.973 rows=58452 loops=8)"
" Filter: (comment_index = 1)"
" Rows Removed by Filter: 156822"
" Buffers: shared hit=5135, temp read=27667 written=6782"
" -> Index Scan using esn_dates_esn_id_key on esn_dates ed (cost=0.29..8.32 rows=1 width=20) (actual time=0.020..0.021 rows=1 loops=8)"
" Index Cond: (esn_id = 140339)"
" Filter: ((gate_3_stop_actual AND (gate_3_stop >= now())) OR (gate_3_stop IS NULL) OR ((NOT gate_3_stop_actual) AND (gate_3_stop IS NOT NULL) AND (gate_3_stop >= (now() - '730 days'::interval))))"
" Buffers: shared hit=24"
"Planning time: 6.580 ms"
"Execution time: 673.922 ms"
The view definition (moa.esn_part_view) on which the above query is selecting
with indexed_comments as (
select
part_comment.part_id,
part_comment.comment,
row_number() over (partition by part_comment.part_id
order by
part_comment.created_at desc) as comment_index
from
moa.part_comment
)
select
e.esn_id,
e.name as esn,
e.is_qp_engine as quarter_point,
w.number as work_order_number,
case
when (p.part_id is null) then 0
else p.part_id
end as part_id,
p.part_number,
p.part_description,
p.quantity,
st.name as status,
p.status_id,
mat.name as material_stream,
p.material_stream_id,
so.name as source,
p.source_id,
p.oem,
p.po_number,
p.manual_cso_commit,
p.auto_cso_commit,
coalesce(p.manual_cso_commit, p.auto_cso_commit) as calculated_cso_commit,
(coalesce(ed.adj_accum_date, (ed.gate_1_stop + coalesce(ed.gate_2_otr, 0)), ed.gate_0_start) + p.accum_offset) as adjusted_accum,
dr.name as dr_status,
p.dr_status_id,
p.airway_bill,
p.core_material,
hpc.hpc_status_name as hpc_status,
p.hpc_status_id,
module.module_name,
p.module_id,
c.name as customer,
c.customer_id,
m.name as model,
m.model_id,
ef.name as engine_family,
ef.engine_family_id,
s.label as site,
s.site_id,
case
when (coalesce(p.manual_cso_commit, p.auto_cso_commit) > coalesce(ed.adj_accum_date, (ed.gate_1_stop + coalesce(ed.gate_2_otr, 0)), ed.gate_0_start)) then 1
else 0
end as critical,
case
when (coalesce(p.manual_cso_commit, p.auto_cso_commit) <= coalesce(ed.adj_accum_date, (ed.gate_1_stop + coalesce(ed.gate_2_otr, 0)), ed.gate_0_start)) then 1
else 0
end as numshort,
case
when ((p.esn_id is not null)
and (coalesce(p.manual_cso_commit, p.auto_cso_commit) is null)) then 1
else 0
end as wa,
ed.adj_accum_date,
(ed.gate_1_stop + coalesce(ed.gate_2_otr, 0)) as g2_otr,
ed.gate_0_start as induct_date,
coalesce((coalesce(ed.adj_accum_date, (ed.gate_1_stop + coalesce(ed.gate_2_otr, 0))) - max(coalesce(p.manual_cso_commit, p.auto_cso_commit))), 0) as delta,
coalesce(ed.adj_accum_date, (ed.gate_1_stop + coalesce(ed.gate_2_otr, 0)), ed.gate_0_start) as fiscal_week_bucket_date,
p.po_line_num,
p.ship_out,
p.receipt,
p.crit_ship,
e.work_scope_id,
ws.name as work_scope,
p.late_call,
p.ex_esn,
p.accum_offset,
ic.comment as latest_comment
from
(((((((((((((((moa.esn e
join moa.work_order w
using (work_order_id))
join moa.model m
using (model_id))
join moa.engine_family ef on
((m.engine_family_id = ef.engine_family_id)))
join moa.site s on
((ef.site_id = s.site_id)))
join moa.customer c
using (customer_id))
left join moa.part p on
(((e.esn_id = p.esn_id)
and (p.active <> false))))
left join moa.work_scope ws on
((e.work_scope_id = ws.work_scope_id)))
left join moa.source so on
((p.source_id = so.source_id)))
left join moa.status st on
((p.status_id = st.status_id)))
left join moa.material_stream mat
using (material_stream_id))
left join moa.dr_status dr
using (dr_status_id))
left join moa.hpc_status hpc
using (hpc_status_id))
left join moa.module module
using (module_id))
left join indexed_comments ic on
(((ic.part_id = p.part_id)
and (ic.comment_index = 1))))
join moa.esn_dates ed on
((e.esn_id = ed.esn_id)))
where
((e.active = true)
and (((ed.gate_3_stop_actual = true)
and (ed.gate_3_stop >= now()))
or (ed.gate_3_stop is null)
or ((ed.gate_3_stop_actual = false)
and (ed.gate_3_stop is not null)
and (ed.gate_3_stop >= (now() - '730 days'::interval)))))
group by
e.esn_id,
w.number,
s.label,
c.name,
p.active,
ed.adj_accum_date,
coalesce(ed.gate_2_otr, 0),
ed.gate_0_start,
ed.gate_1_stop,
p.part_id,
st.name,
mat.name,
so.name,
dr.name,
hpc.hpc_status_name,
module.module_name,
c.customer_id,
m.name,
m.model_id,
ef.name,
ef.engine_family_id,
s.site_id,
ws.name,
ic.comment;
[postgresql-performance]questions here: stackoverflow.com/tags/postgresql-performance/info, and edit accordingly.explain (analyze, buffers, format text)and then add that to your question.