首页 > 解决方案 > 为什么 postgres 查询需要这么长时间

问题描述

我对在 aws rds 生产中运行需要超过 5 分钟的视图有一个有问题的查询。查询很简单,只有85000条记录。无法理解为什么要花这么长时间。如果我从 postgres 客户端运行查询需要 300 毫秒,但从应用程序运行时相同的查询,在 New Relic 中显示 5 分钟或更长时间。查询是:

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

我也有来自 pgadmin4 的 EXPLAIN ANALYZE BUFFERS FORMAT TEXT 计划......虽然不能理解很多

"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"

上述查询选择的视图定义 (moa.esn_part_view)

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;

标签: sqldatabasepostgresqlquery-optimizationpostgresql-performance

解决方案


看起来这个查询返回了 200K 的行。一些客户端在必须从服务器读取大量行时非常慢。有时网络通信可能很慢。


推荐阅读