postgres 从 9.5 升级到 11 将连接更改为嵌套循环,使其非常慢

Posted

技术标签:

【中文标题】postgres 从 9.5 升级到 11 将连接更改为嵌套循环,使其非常慢【英文标题】:postgres upgrade from 9.5 to 11 changed join to Nested loop making it very slow 【发布时间】:2020-04-13 07:24:52 【问题描述】:

最近我将我的 postgresql 从 9.5 升级到 11.6,之后我注意到我的一些查询花费了 50 倍的时间,在分析查询后我注意到连接类型在版本 11 中从 哈希连接到嵌套循环连接。 虽然每件事都像数据集一样,但索引 这是查询

count(*)
FROM
devices
LEFT OUTER JOIN tests ON tests.device_id = devices.id
AND tests.deleted_at IS NULL
AND(tests.status = 0
OR tests.status = 1
OR tests.status = 2
OR tests.status = 3
OR tests.status = 8)
WHERE
devices.deleted_at IS NULL
AND(tests.id IS NULL)
AND(devices.next_test_date >= '2020-04-12 05:18:00');
AND(devices.next_test_date <= '2020-05-12 05:19:00');

这是 9.5 版中 EXPLAIN ANALYZE 的结果

  ->  Hash Right Join  (cost=57394.39..116654.22 rows=1 width=0) (actual time=450.637..457.209 rows=23900 loops=1)
        Hash Cond: (tests.device_id = devices.id)
        Filter: (tests.id IS NULL)
        Rows Removed by Filter: 3354
        ->  Bitmap Heap Scan on tests  (cost=5252.89..64186.75 rows=80198 width=16) (actual time=29.369..105.722 rows=42449 loops=1)
              Recheck Cond: ((status = 0) OR (status = 1) OR (status = 2) OR (status = 3) OR (status = 8))
              Filter: (deleted_at IS NULL)
              Rows Removed by Filter: 62336
              Heap Blocks: exact=37155
              ->  BitmapOr  (cost=5252.89..5252.89 rows=94732 width=0) (actual time=22.435..22.435 rows=0 loops=1)
                    ->  Bitmap Index Scan on index_tests_on_status  (cost=0.00..2864.08 rows=52754 width=0) (actual time=12.024..12.024 rows=57001 loops=1)
                          Index Cond: (status = 0)
                    ->  Bitmap Index Scan on index_tests_on_status  (cost=0.00..1745.55 rows=32149 width=0) (actual time=6.083..6.083 rows=32221 loops=1)
                          Index Cond: (status = 1)
                    ->  Bitmap Index Scan on index_tests_on_status  (cost=0.00..181.00 rows=3277 width=0) (actual time=0.993..0.993 rows=7065 loops=1)
                          Index Cond: (status = 2)
                    ->  Bitmap Index Scan on index_tests_on_status  (cost=0.00..181.00 rows=3277 width=0) (actual time=2.353..2.353 rows=8767 loops=1)
                          Index Cond: (status = 3)
                    ->  Bitmap Index Scan on index_tests_on_status  (cost=0.00..181.00 rows=3277 width=0) (actual time=0.975..0.975 rows=5242 loops=1)
                          Index Cond: (status = 8)
        ->  Hash  (cost=51829.28..51829.28 rows=24978 width=8) (actual time=328.692..328.692 rows=27216 loops=1)
              Buckets: 32768  Batches: 1  Memory Usage: 1320kB
              ->  Seq Scan on devices  (cost=0.00..51829.28 rows=24978 width=8) (actual time=0.041..317.112 rows=27216 loops=1)
"                    Filter: ((deleted_at IS NULL) AND (next_test_date >= '2020-04-12 05:18:00'::timestamp without time zone) AND (next_test_date <= '2020-05-12 05:19:00'::timestamp without time zone))"
                    Rows Removed by Filter: 766049
Planning time: 0.362 ms
Execution time: 462.653 ms

在 11.6 版中解释分析

Aggregate  (cost=13634.81..13634.82 rows=1 width=8) (actual time=466211.022..466211.022 rows=1 loops=1)
  ->  Nested Loop Left Join  (cost=1858.14..13634.81 rows=1 width=0) (actual time=175.748..466182.183 rows=24085 loops=1)
        Join Filter: (tests.device_id = devices.id)
        Rows Removed by Join Filter: 1139392316
        Filter: (tests.id IS NULL)
        Rows Removed by Filter: 3180
        ->  Bitmap Heap Scan on devices  (cost=102.17..11789.55 rows=20 width=8) (actual time=37.555..428.278 rows=27227 loops=1)
              Recheck Cond: (deleted_at IS NULL)
"              Filter: ((next_test_date >= '2020-04-12 05:18:00'::timestamp without time zone) AND (next_test_date <= '2020-05-12 05:19:00'::timestamp without time zone))"
              Rows Removed by Filter: 678655
              Heap Blocks: exact=39437
              ->  Bitmap Index Scan on idx_16425_index_devices_on_deleted_at  (cost=0.00..102.17 rows=3966 width=0) (actual time=31.221..31.221 rows=705882 loops=1)
                    Index Cond: (deleted_at IS NULL)
        ->  Materialize  (cost=1755.97..1839.31 rows=20 width=16) (actual time=0.003..8.151 rows=41848 loops=27227)
              ->  Bitmap Heap Scan on tests  (cost=1755.97..1839.21 rows=20 width=16) (actual time=79.346..108.975 rows=41848 loops=1)
                    Recheck Cond: ((deleted_at IS NULL) AND ((status = 0) OR (status = 1) OR (status = 2) OR (status = 3) OR (status = 8)))
                    Heap Blocks: exact=18099
                    ->  BitmapAnd  (cost=1755.97..1755.97 rows=21 width=0) (actual time=76.318..76.319 rows=0 loops=1)
                          ->  Bitmap Index Scan on idx_16490_index_tests_on_deleted_at  (cost=0.00..402.62 rows=826 width=0) (actual time=58.256..58.256 rows=978886 loops=1)
                                Index Cond: (deleted_at IS NULL)
                          ->  BitmapOr  (cost=1353.10..1353.10 rows=4131 width=0) (actual time=14.690..14.690 rows=0 loops=1)
                                ->  Bitmap Index Scan on index_tests_on_status  (cost=0.00..270.62 rows=826 width=0) (actual time=8.690..8.690 rows=67092 loops=1)
                                      Index Cond: (status = 0)
                                ->  Bitmap Index Scan on index_tests_on_status  (cost=0.00..270.62 rows=826 width=0) (actual time=3.145..3.145 rows=37208 loops=1)
                                      Index Cond: (status = 1)
                                ->  Bitmap Index Scan on index_tests_on_status  (cost=0.00..270.62 rows=826 width=0) (actual time=0.513..0.514 rows=7525 loops=1)
                                      Index Cond: (status = 2)
                                ->  Bitmap Index Scan on index_tests_on_status  (cost=0.00..270.62 rows=826 width=0) (actual time=1.639..1.639 rows=15994 loops=1)
                                      Index Cond: (status = 3)
                                ->  Bitmap Index Scan on index_tests_on_status  (cost=0.00..270.62 rows=826 width=0) (actual time=0.698..0.699 rows=9117 loops=1)
                                      Index Cond: (status = 8)
Planning Time: 0.296 ms
Execution Time: 466211.374 ms

感谢任何帮助,谢谢。

【问题讨论】:

添加最新的统计信息 ? select relname, last_analyze, last_autoanalyze from pg_stat_all_tables where relname in ('tests', 'devices');的输出是什么 升级后您是否在所有相关表上运行vacuum analyze?如果您使用pg_upgrade,它会为此创建一个批处理文件anlayze_new_cluster @pifor the result of select pg_stat_all_tables is null :\ 请在您指出问题时回复您作为答案。 尝试在两个表上至少运行analyze 【参考方案1】:

您至少需要在两个表上运行analyze

【讨论】:

以上是关于postgres 从 9.5 升级到 11 将连接更改为嵌套循环,使其非常慢的主要内容,如果未能解决你的问题,请参考以下文章

利用pg_upgrade更新数据库(从8.4升级到9.5)

升级到版本 11 后 Postgres 查询产生高磁盘 IO

Postgres Plus Advanced Server (PPAS) 9.5 是不是支持将属性更改(删除/添加)复合对象类型?

相同数据空间内的 postgres 主要升级(9.5.x 到 9.6.x)

Heroku Postgres 升级后 Flyway 无法连接到数据库

我可以从 JDBC 连接为 Postgres 设置会话变量吗