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

Huge divergence in query estimate vs actual time in postgres

在具有相同数据库的两个不同环境(本地计算机和 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 是一个很大的 table(4400 万条记录),连接 table property_tax_bill_parsed_addresses 同样大。

EXPLAIN ANALYZE 命令运行 通过本地 psql returns 以下内容:

 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 returns this:

 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

如您所见,本地的查询计划要复杂得多,估计要长得多。然而在产品上,查询计划简单直观,估计速度很快,但实际上执行速度比本地慢 2 个数量级。该应用程序 运行 正在上线,但流量很少(4-5 位用户,最多 15 位 requests/minute)。

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

本地有 64GB RAM 和 12 个内核 运行在 NVME 上大约能够 read/write 的 5 GB/s - Postgres 版本 13.4

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

这是你的问题:

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) ... 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

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

将 parsed_address_id 添加到此索引,以避免之后的过滤。

CREATE INDEX idx_name_of_your_index ON property_tax_bill_parsed_addresses (property_tax_bill_id,parsed_address_id);

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

感谢 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 的多列),但性能提升足以满足我们的需求。

这仍然有点神秘,因为我不确定删除和重新添加是如何彻底改变查询计划的,但我不想在嘴里看礼物马。