Why postgres query is taking so long-CodePudding

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 plan from New Relic...though couldnt understand much of it

[{"Node Type":"Sort","Parallel Aware":"?","Parent Relationship":"Outer","Plan Rows":1,"Plan Width":118,"Plans":[{"Alias":"esnpartvie0_","Node Type":"Subquery Scan","Parallel Aware":"?","Parent Relationship":"Outer","Plan Rows":1,"Plan Width":118,"Plans":[{"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"],"Node Type":"Aggregate","Parallel Aware":"?","Parent Relationship":"Subquery","Partial Mode":"?","Plan Rows":1,"Plan Width":2537,"Plans":[{"Node Type":"WindowAgg","Parallel Aware":"?","Parent Relationship":"InitPlan","Plan Rows":211872,"Plan Width":119,"Plans":[{"Node Type":"Sort","Parallel Aware":"?","Parent Relationship":"Outer","Plan Rows":211872,"Plan Width":111,"Plans":[{"Alias":"part_comment","Node Type":"Seq Scan","Parallel Aware":"?","Parent Relationship":"Outer","Plan Rows":211872,"Plan Width":111,"Relation Name":"part_comment","Startup Cost":0,"Total Cost":10359.72}],"Sort Key":["part_comment.part_id","part_comment.created_at DESC"],"Startup Cost":41415.8,"Total Cost":41945.48}],"Startup Cost":41415.8,"Subplan Name":"?","Total Cost":45653.24},{"Node Type":"Sort","Parallel Aware":"?","Parent Relationship":"Outer","Plan Rows":1,"Plan Width":1238,"Plans":[{"Inner Unique":"?","Join Type":"Inner","Node Type":"Nested Loop","Parallel Aware":"?","Parent Relationship":"Outer","Plan Rows":1,"Plan Width":1238,"Plans":[{"Inner Unique":"?","Join Filter":"?","Join Type":"Left","Node Type":"Nested Loop","Parallel Aware":"?","Parent Relationship":"Outer","Plan Rows":1,"Plan Width":1218,"Plans":[{"Inner Unique":"?","Join Type":"Left","Node Type":"Nested Loop","Parallel Aware":"?","Parent Relationship":"Outer","Plan Rows":1,"Plan Width":702,"Plans":[{"Inner Unique":"?","Join Type":"Left","Node Type":"Nested Loop","Parallel Aware":"?","Parent Relationship":"Outer","Plan Rows":1,"Plan Width":678,"Plans":[{"Inner Unique":"?","Join Type":"Left","Node Type":"Nested Loop","Parallel Aware":"?","Parent Relationship":"Outer","Plan Rows":1,"Plan Width":614,"Plans":[{"Inner Unique":"?","Join Type":"Left","Node Type":"Nested Loop","Parallel Aware":"?","Parent Relationship":"Outer","Plan Rows":1,"Plan Width":550,"Plans":[{"Inner Unique":"?","Join Type":"Left","Node Type":"Nested Loop","Parallel Aware":"?","Parent Relationship":"Outer","Plan Rows":1,"Plan Width":516,"Plans":[{"Inner Unique":"?","Join Type":"Left","Node Type":"Nested Loop","Parallel Aware":"?","Parent Relationship":"Outer","Plan Rows":1,"Plan Width":452,"Plans":[{"Inner Unique":"?","Join Type":"Left","Node Type":"Nested Loop","Parallel Aware":"?","Parent Relationship":"Outer","Plan Rows":1,"Plan Width":278,"Plans":[{"Inner Unique":"?","Join Filter":"?","Join Type":"Left","Node Type":"Nested Loop","Parallel Aware":"?","Parent Relationship":"Outer","Plan Rows":1,"Plan Width":214,"Plans":[{"Inner Unique":"?","Join Type":"Inner","Node Type":"Nested Loop","Parallel Aware":"?","Parent Relationship":"Outer","Plan Rows":1,"Plan Width":173,"Plans":[{"Inner Unique":"?","Join Type":"Inner","Node Type":"Nested Loop","Parallel Aware":"?","Parent Relationship":"Outer","Plan Rows":1,"Plan Width":166,"Plans":[{"Inner Unique":"?","Join Type":"Inner","Node Type":"Nested Loop","Parallel Aware":"?","Parent Relationship":"Outer","Plan Rows":1,"Plan Width":108,"Plans":[{"Inner Unique":"?","Join Type":"Inner","Node Type":"Nested Loop","Parallel Aware":"?","Parent Relationship":"Outer","Plan Rows":1,"Plan Width":46,"Plans":[{"Hash Cond":"?","Inner Unique":"?","Join Type":"Inner","Node Type":"Hash Join","Parallel Aware":"?","Parent Relationship":"Outer","Plan Rows":1,"Plan Width":41,"Plans":[{"Alias":"m","Node Type":"Seq Scan","Parallel Aware":"?","Parent Relationship":"Outer","Plan Rows":113,"Plan Width":17,"Relation Name":"model","Startup Cost":0,"Total Cost":3.13},{"Node Type":"Hash","Parallel Aware":"?","Parent Relationship":"Inner","Plan Rows":1,"Plan Width":28,"Plans":[{"Alias":"e","Filter":"?","Index Cond":"?","Index Name":"esn_pkey","Node Type":"Index Scan","Parallel Aware":"?","Parent Relationship":"Outer","Plan Rows":1,"Plan Width":28,"Relation Name":"esn","Scan Direction":"Forward","Startup Cost":0.29,"Total Cost":8.3}],"Startup Cost":8.3,"Total Cost":8.3}],"Startup Cost":8.31,"Total Cost":11.75},{"Alias":"w","Index Cond":"?","Index Name":"work_order_pkey","Node Type":"Index Scan","Parallel Aware":"?","Parent Relationship":"Inner","Plan Rows":1,"Plan Width":13,"Relation Name":"work_order","Scan Direction":"Forward","Startup Cost":0.29,"Total Cost":8.3}],"Startup Cost":8.6,"Total Cost":20.06},{"Alias":"ef","Filter":"?","Index Cond":"?","Index Name":"engine_family_pkey","Node Type":"Index Scan","Parallel Aware":"?","Parent Relationship":"Inner","Plan Rows":1,"Plan Width":66,"Relation Name":"engine_family","Scan Direction":"Forward","Startup Cost":0.14,"Total Cost":0.26}],"Startup Cost":8.73,"Total Cost":20.44},{"Alias":"s","Filter":"?","Node Type":"Seq Scan","Parallel Aware":"?","Parent Relationship":"Inner","Plan Rows":1,"Plan Width":62,"Relation Name":"site","Startup Cost":0,"Total Cost":1.11}],"Startup Cost":8.73,"Total Cost":21.57},{"Alias":"c","Index Cond":"?","Index Name":"customer_pkey","Node Type":"Index Scan","Parallel Aware":"?","Parent Relationship":"Inner","Plan Rows":1,"Plan Width":11,"Relation Name":"customer","Scan Direction":"Forward","Startup Cost":0.27,"Total Cost":8.29}],"Startup Cost":9.01,"Total Cost":29.89},{"Node Type":"Gather","Parallel Aware":"?","Parent Relationship":"Inner","Plan Rows":29,"Plan Width":41,"Plans":[{"Alias":"p","Filter":"?","Node Type":"Seq Scan","Parallel Aware":"?","Parent Relationship":"Outer","Plan Rows":12,"Plan Width":41,"Relation Name":"part","Startup Cost":0,"Total Cost":18577.22}],"Single Copy":"?","Startup Cost":1000,"Total Cost":19580.12,"Workers Planned":"?"}],"Startup Cost":1009.01,"Total Cost":19610.38},{"Alias":"ws","Index Cond":"?","Index Name":"work_scope_pkey","Node Type":"Index Scan","Parallel Aware":"?","Parent Relationship":"Inner","Plan Rows":1,"Plan Width":72,"Relation Name":"work_scope","Scan Direction":"Forward","Startup Cost":0.15,"Total Cost":8.17}],"Startup Cost":1009.16,"Total Cost":19618.58},{"Alias":"so","Index Cond":"?","Index Name":"source_pkey","Node Type":"Index Scan","Parallel Aware":"?","Parent Relationship":"Inner","Plan Rows":1,"Plan Width":182,"Relation Name":"source","Scan Direction":"Forward","Startup Cost":0.14,"Total Cost":0.57}],"Startup Cost":1009.29,"Total Cost":19619.19},{"Alias":"st","Index Cond":"?","Index Name":"status_pkey","Node Type":"Index Scan","Parallel Aware":"?","Parent Relationship":"Inner","Plan Rows":1,"Plan Width":72,"Relation Name":"status","Scan Direction":"Forward","Startup Cost":0.13,"Total Cost":0.56}],"Startup Cost":1009.43,"Total Cost":19619.9},{"Alias":"mat","Index Cond":"?","Index Name":"material_stream_pkey","Node Type":"Index Scan","Parallel Aware":"?","Parent Relationship":"Inner","Plan Rows":1,"Plan Width":42,"Relation Name":"material_stream","Scan Direction":"Forward","Startup Cost":0.13,"Total Cost":0.56}],"Startup Cost":1009.56,"Total Cost":19620.68},{"Alias":"dr","Index Cond":"?","Index Name":"dr_status_pkey","Node Type":"Index Scan","Parallel Aware":"?","Parent Relationship":"Inner","Plan Rows":1,"Plan Width":72,"Relation Name":"dr_status","Scan Direction":"Forward","Startup Cost":0.13,"Total Cost":0.56}],"Startup Cost":1009.68,"Total Cost":19621.52},{"Alias":"hpc","Index Cond":"?","Index Name":"hpc_status_pkey","Node Type":"Index Scan","Parallel Aware":"?","Parent Relationship":"Inner","Plan Rows":1,"Plan Width":72,"Relation Name":"hpc_status","Scan Direction":"Forward","Startup Cost":0.13,"Total Cost":0.56}],"Startup Cost":1009.82,"Total Cost":19622.23},{"Alias":"module","Index Cond":"?","Index Name":"module_pkey","Node Type":"Index Scan","Parallel Aware":"?","Parent Relationship":"Inner","Plan Rows":1,"Plan Width":32,"Relation Name":"module","Scan Direction":"Forward","Startup Cost":0.14,"Total Cost":0.57}],"Startup Cost":1009.95,"Total Cost":19622.83},{"Alias":"ic","CTE Name":"?","Filter":"?","Node Type":"CTE Scan","Parallel Aware":"?","Parent Relationship":"Inner","Plan Rows":1059,"Plan Width":520,"Startup Cost":0,"Total Cost":4767.12}],"Startup Cost":1009.95,"Total Cost":24403.19},{"Alias":"ed","Filter":"?","Index Cond":"?","Index Name":"esn_dates_esn_id_key","Node Type":"Index Scan","Parallel Aware":"?","Parent Relationship":"Inner","Plan Rows":1,"Plan Width":20,"Relation Name":"esn_dates","Scan Direction":"Forward","Startup Cost":0.29,"Total Cost":8.32}],"Startup Cost":1010.24,"Total Cost":24411.51}],"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","ws.name","ic.comment"],"Startup Cost":24411.52,"Total Cost":24411.53}],"Startup Cost":70064.76,"Strategy":"Sorted","Total Cost":70064.85}],"Startup Cost":70064.76,"Total Cost":70064.86}],"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"],"Startup Cost":70064.87,"Total Cost":70064.87}]

CodePudding user response：

It looks so this query returns 200K of rows. Some clients are very slow when they have to read lot of rows from server. Some times can be slow network communication.

CodePudding user response：

If I run the query from postgres client it takes 300ms

So your query is not slow, your client (application code) is.

Few things to consider here:

does the client actually need thousands of rows at once? if this is for example user-facing UI, you probably want some pages, and you can limit what you get from DB to one page at the time
does client "buffer" the results (storing them in some kind of list/dictionary), or does your code do any processing in streaming manner (as it gets rows from DB reader). Time to transfer results to client counts into "total query time", and if your client is slow to accept rows from reader, that is your reason.