查询估计与 postgres 中的实际时间存在巨大差异答案

【问题标题】：Huge divergence in query estimate vs actual time in postgres查询估计与 postgres 中的实际时间存在巨大差异
【发布时间】：2022-01-06 02:22:48
【问题描述】：

在具有相同数据库的两个不同环境（本地计算机和 heroku 上的生产环境）之间，我们发现相同但相当简单的查询的执行时间存在很大差异。

查询是：

SELECT "property_tax_bills".* FROM "property_tax_bills" INNER JOIN "property_tax_bill_parsed_addresses" ON "property_tax_bills"."id" = "property_tax_bill_parsed_addresses"."property_tax_bill_id" WHERE "property_tax_bill_parsed_addresses"."parsed_address_id" = 2 AND "property_tax_bills"."statement_date" = '2021-11-20';

property_tax_bills 是一个很大的表（4400 万条记录），连接表 property_tax_bill_parsed_addresses 也同样大。

通过 psql 在本地运行的 EXPLAIN ANALYZE 命令返回以下内容：

 Gather  (cost=1105.30..64845.64 rows=219 width=147) (actual time=15.054..18.941 rows=101 loops=1)
   Output: property_tax_bills.id, property_tax_bills.owner_name, property_tax_bills.property_address, property_tax_bills.mailing_address, property_tax_bills.statement_date, property_tax_bills.pluto_record_id, property_tax_bills.created_at, property_tax_bills.updated_at, property_tax_bills.bbl
   Workers Planned: 2
   Workers Launched: 2
   Buffers: shared hit=25539
   ->  Nested Loop  (cost=105.30..63823.74 rows=91 width=147) (actual time=12.147..12.291 rows=34 loops=3)
         Output: property_tax_bills.id, property_tax_bills.owner_name, property_tax_bills.property_address, property_tax_bills.mailing_address, property_tax_bills.statement_date, property_tax_bills.pluto_record_id, property_tax_bills.created_at, property_tax_bills.updated_at, property_tax_bills.bbl
         Inner Unique: true
         Buffers: shared hit=25539
         Worker 0:  actual time=10.752..10.898 rows=36 loops=1
           Buffers: shared hit=7647
         Worker 1:  actual time=11.014..11.162 rows=28 loops=1
           Buffers: shared hit=6483
         ->  Parallel Bitmap Heap Scan on public.property_tax_bill_parsed_addresses  (cost=104.73..32879.67 rows=3672 width=8) (actual time=0.634..3.758 rows=1442 loops=3)
               Output: property_tax_bill_parsed_addresses.id, property_tax_bill_parsed_addresses.property_tax_bill_id, property_tax_bill_parsed_addresses.parsed_address_id, property_tax_bill_parsed_addresses.raw_address, property_tax_bill_parsed_addresses.processed_address, property_tax_bill_parsed_addresses.created_at, property_tax_bill_parsed_addresses.updated_at, property_tax_bill_parsed_addresses.is_verified, property_tax_bill_parsed_addresses.error_message
               Recheck Cond: (property_tax_bill_parsed_addresses.parsed_address_id = 2)
               Heap Blocks: exact=1745
               Buffers: shared hit=3912
               Worker 0:  actual time=0.041..2.924 rows=1295 loops=1
                 Buffers: shared hit=1171
               Worker 1:  actual time=0.045..3.356 rows=1099 loops=1
                 Buffers: shared hit=987
               ->  Bitmap Index Scan on part_i_ptbpa_o_p_a_id_where_not_null  (cost=0.00..102.53 rows=8812 width=0) (actual time=1.049..1.049 rows=4325 loops=1)
                     Index Cond: (property_tax_bill_parsed_addresses.parsed_address_id = 2)
                     Buffers: shared hit=9
         ->  Index Scan using property_tax_bills_pkey on public.property_tax_bills  (cost=0.56..8.43 rows=1 width=147) (actual time=0.006..0.006 rows=0 loops=4325)
               Output: property_tax_bills.id, property_tax_bills.owner_name, property_tax_bills.property_address, property_tax_bills.mailing_address, property_tax_bills.statement_date, property_tax_bills.pluto_record_id, property_tax_bills.created_at, property_tax_bills.updated_at, property_tax_bills.bbl
               Index Cond: (property_tax_bills.id = property_tax_bill_parsed_addresses.property_tax_bill_id)
               Filter: (property_tax_bills.statement_date = '2021-11-20'::date)
               Rows Removed by Filter: 1
               Buffers: shared hit=21627
               Worker 0:  actual time=0.006..0.006 rows=0 loops=1295
                 Buffers: shared hit=6476
               Worker 1:  actual time=0.007..0.007 rows=0 loops=1099
                 Buffers: shared hit=5496
 Planning:
   Buffers: shared hit=498
 Planning Time: 1.750 ms
 Execution Time: 19.000 ms

在生产环境中，通过 heroku pg:psql 运行的相同命令会返回：

 Nested Loop  (cost=0.20..7.50 rows=1 width=147) (actual time=15.895..2152.165 rows=101 loops=1)
   Output: property_tax_bills.id, property_tax_bills.owner_name, property_tax_bills.property_address, property_tax_bills.mailing_address, property_tax_bills.statement_date, property_tax_bills.pluto_record_id, property_tax_bills.created_at, property_tax_bills.updated_at, property_tax_bills.bbl
   Inner Unique: true
   Buffers: shared hit=5581088
   ->  Index Scan using index_property_tax_bills_on_statement_date on public.property_tax_bills  (cost=0.09..3.38 rows=1 width=147) (actual time=0.034..208.051 rows=1110860 loops=1)
         Output: property_tax_bills.id, property_tax_bills.owner_name, property_tax_bills.property_address, property_tax_bills.mailing_address, property_tax_bills.statement_date, property_tax_bills.pluto_record_id, property_tax_bills.created_at, property_tax_bills.updated_at, property_tax_bills.bbl
         Index Cond: (property_tax_bills.statement_date = '2021-11-20'::date)
         Buffers: shared hit=26788
   ->  Index Scan using i_pr_tax_bill_p_a_o_p_r_b_id on public.property_tax_bill_parsed_addresses  (cost=0.11..4.12 rows=1 width=8) (actual time=0.002..0.002 rows=0 loops=1110860)
         Output: property_tax_bill_parsed_addresses.id, property_tax_bill_parsed_addresses.property_tax_bill_id, property_tax_bill_parsed_addresses.parsed_address_id, property_tax_bill_parsed_addresses.raw_address, property_tax_bill_parsed_addresses.processed_address, property_tax_bill_parsed_addresses.created_at, property_tax_bill_parsed_addresses.updated_at, property_tax_bill_parsed_addresses.is_verified, property_tax_bill_parsed_addresses.error_message
         Index Cond: (property_tax_bill_parsed_addresses.property_tax_bill_id = property_tax_bills.id)
         Filter: (property_tax_bill_parsed_addresses.parsed_address_id = 2)
         Rows Removed by Filter: 1
         Buffers: shared hit=5554300
 Planning Time: 0.225 ms
 Execution Time: 2152.224 ms

如您所见，本地查询计划要复杂得多，估计要长得多。然而在 prod 上，查询计划简单直观，估计很快，但实际上执行速度比本地慢 2 个数量级。该应用正在实时运行，但流量很少（4-5 个用户，最多 15 个请求/分钟）。

关于每台机器规格的一些附加信息：

Local 在 NVME 上运行 64GB 的 RAM 和 12 个内核，读/写速度大致为 5 GB/s - Postgres 版本 13.4

Production 是 Heroku 上的标准 9 764GB RAM postgres 实例。 - Postgres 客户端版本 13.4

【问题讨论】：

postgres 版本是否相同？
都是 13.4 - 更新了帖子
可能与 statement_date = '2021-11-20' 的行数中的百万倍错误估计有关。对您的表格进行分析。
ANALYZE 没有实质性地改变估计或执行时间

标签： sql ruby-on-rails postgresql heroku heroku-postgres

【解决方案1】：

这是你的问题：

使用 i_pr_tax_bill_p_a_o_p_r_b_id 进行索引扫描 public.property_tax_bill_parsed_addresses（成本=0.11..4.12 行=1 宽度=8) (实际时间=0.002..0.002 行=0 循环=1110860) ... 指数条件：（property_tax_bill_parsed_addresses.property_tax_bill_id = property_tax_bills.id) 过滤器：(property_tax_bill_parsed_addresses.parsed_address_id = 2)

过滤器删除的行数：1

它正在执行 1110860 次索引扫描，并在成功找到数据后删除大部分数据。

将 parsed_address_id 添加到该索引中，以避免之后的过滤。

CREATE INDEX idx_name_of_your_index ON property_tax_bill_parsed_addresses (property_tax_bill_id,parsed_address_id);

当你有这个索引时，查询计划会改变吗？

【讨论】：

原来我们已经有了那个索引，它只是被跳过，取而代之的是 JUST property_tax_bill_id 上的索引
@AdamMay：也许扩展统计可以解决这个问题，为规划者提供有关数据收集的更好信息。检查postgresql.org/docs/13/sql-createstatistics.html

【解决方案2】：

感谢Frank Heikens，我们发现没有使用更有效的索引。我们在 property_tax_bill_id 和 (property_tax_bill_id, parsed_address_id) 上都有一个唯一索引。

通过删除 property_tax_bill_id 上的冗余唯一索引，然后重新添加它，它促使查询计划器使用更快的计划 - 这是新的结果计划：

 Nested Loop  (cost=0.20..652.83 rows=3 width=147) (actual time=26.039..26.505 rows=101 loops=1)
   Output: property_tax_bills.id, property_tax_bills.owner_name, property_tax_bills.property_address, property_tax_bills.mailing_address, property_tax_bills.statement_date, property_tax_bills.pluto_record_id, property_tax_bills.created_at, property_tax_bills.updated_at, property_tax_bills.bbl
   Inner Unique: true
   Buffers: shared hit=25524
   ->  Index Scan using part_i_ptbpa_o_p_a_id_where_not_null on public.property_tax_bill_parsed_addresses  (cost=0.09..208.09 rows=108 width=8) (actual time=0.026..4.929 rows=4325 loops=1)
         Output: property_tax_bill_parsed_addresses.id, property_tax_bill_parsed_addresses.property_tax_bill_id, property_tax_bill_parsed_addresses.parsed_address_id, property_tax_bill_parsed_addresses.raw_address, property_tax_bill_parsed_addresses.processed_address, property_tax_bill_parsed_addresses.created_at, property_tax_bill_parsed_addresses.updated_at, property_tax_bill_parsed_addresses.is_verified, property_tax_bill_parsed_addresses.error_message
         Index Cond: (property_tax_bill_parsed_addresses.parsed_address_id = 2)
         Buffers: shared hit=3899
   ->  Index Scan using property_tax_bills_pkey on public.property_tax_bills  (cost=0.11..4.12 rows=1 width=147) (actual time=0.005..0.005 rows=0 loops=4325)
         Output: property_tax_bills.id, property_tax_bills.owner_name, property_tax_bills.property_address, property_tax_bills.mailing_address, property_tax_bills.statement_date, property_tax_bills.pluto_record_id, property_tax_bills.created_at, property_tax_bills.updated_at, property_tax_bills.bbl
         Index Cond: (property_tax_bills.id = property_tax_bill_parsed_addresses.property_tax_bill_id)
         Filter: (property_tax_bills.statement_date = '2021-11-20'::date)
         Rows Removed by Filter: 1
         Buffers: shared hit=21625
 Planning:
   Buffers: shared hit=20
 Planning Time: 0.593 ms
 Execution Time: 26.554 ms

它现在正在使用其他部分索引，这似乎可以加快速度。虽然仍然没有使用最快的索引（跨 parsed_address_id 和 property_tax_bill_id 的多列），但性能提升足以满足我们的需求。

这仍然是一个谜，因为我不确定删除和重新添加如何如此彻底地改变了查询计划，但我不想在嘴里看到一匹礼物马。

【讨论】：