【巡检问题分析与最佳实践】RDS PostgreSQL 慢SQL问题

2021-11-20 03:50:55

往期分享

RDS MySQL 小版本升级最佳实践

概述

慢SQL会消耗较多的数据库资源，很容易造成数据库的负载增加，慢SQL的问题直接影响着数据库的性能，排查慢SQL问题，首先要找到RDS PG中的慢SQL，在学习EXPLAIN的语法，学会阅读执行计划，并对SQL进行优化。

找到慢SQL

控制慢日志时长的参数为log_min_duration_statement，单位为ms，默认值为超过1秒的SQL会收集在慢SQL日志中进行展示。

【巡检问题分析与最佳实践】RDS PostgreSQL 慢SQL问题

慢SQL日志查看

【巡检问题分析与最佳实践】RDS PostgreSQL 慢SQL问题

通过开启auto_explain.log_analyze、auto_explain.log_buffers、auto_explain.log_min_duration，可以在慢日志中打印慢SQL的执行计划。

【巡检问题分析与最佳实践】RDS PostgreSQL 慢SQL问题

EXPLAIN语法

EXPLAIN [ ( option [, ...] ) ] statement
EXPLAIN [ ANALYZE ] [ VERBOSE ] statement

这里 option可以是：

    ANALYZE [ boolean ]
    VERBOSE [ boolean ]
    COSTS [ boolean ]
    BUFFERS [ boolean ]
    TIMING [ boolean ]
    SUMMARY [ boolean ]
    FORMAT { TEXT | XML | JSON | YAML }

这个命令显示PostgreSQL计划器为提供的语句所生成的执行计划。该执行计划会显示将怎样扫描语句中引用的表 — 普通的顺序扫描、索引扫描等等 — 以及在引用多个表时使用何种连接算法来把来自每个输入表的行连接在一起。

postgres=# explain select * from test;
                     QUERY PLAN
----------------------------------------------------
 Seq Scan on test  (cost=0.00..1.01 rows=1 width=4)
(1 row)

显示中最重要的部分是估计出的语句执行代价，它是计划器对于该语句要运行多久的猜测（以任意的代价单位度量，但是习惯上表示取磁盘页面的次数）。事实上会显示两个数字：在第一行能被返回前的启动代价，以及返回所有行的总代价。对于大部分查询来说总代价是最重要的，但是在一些情景中（如EXISTS中的子查询），计划器将选择更小的启动代价来代替最小的总代价（因为执行器将在得到一行后停止）。此外，如果你用一个LIMIT子句限制返回行的数量，计划器会在终端代价之间做出适当的插值来估计到底哪个计划是真正代价最低的。

EXPLAIN ANALYZE SELECT * FROM tenk1 t1, tenk2 t2 WHERE t1.unique1 < 100 AND t1.unique2 = t2.unique2 ORDER BY t1.fivethous; 
QUERY PLAN 
------------------------------------------------------------------------------------------------------------------------------------
Sort (cost=717.34..717.59 rows=101 width=488) (actual time=7.761..7.774 rows=100 loops=1) 
  Sort Key: t1.fivethous 
  Sort Method: quicksort Memory: 77kB 
  -> Hash Join (cost=230.47..713.98 rows=101 width=488) (actual time=0.711..7.427 rows=100 loops=1) 
       Hash Cond: (t2.unique2 = t1.unique2) 
       -> Seq Scan on tenk2 t2 (cost=0.00..445.00 rows=10000 width=244) (actual time=0.007..2.583 rows=10000 loops=1) 
       -> Hash (cost=229.20..229.20 rows=101 width=244) (actual time=0.659..0.659 rows=100 loops=1) 
            Buckets: 1024 Batches: 1 Memory Usage: 28kB 
            -> Bitmap Heap Scan on tenk1 t1 (cost=5.07..229.20 rows=101 width=244) (actual time=0.080..0.526 rows=100 loops=1) 
                 Recheck Cond: (unique1 < 100) 
                 -> Bitmap Index Scan on tenk1_unique1 (cost=0.00..5.04 rows=101 width=0) (actual time=0.049..0.049 rows=100 loops=1) 
                      Index Cond: (unique1 < 100) 
Planning time: 0.194 ms 
Execution time: 8.008 ms

analyze:执行命令并且显示实际的运行时间和其他统计信息。参数默认值为FALSE
verbose:显示关于计划的额外信息。特别是：计划树中每个结点的输出列列表、模式限定的表和函数名、总是把表达式中的变量标上它们的范围表别名，以及总是打印统计信息被显示的每个触发器的名称。这个参数默认被设置为FALSE。
costs:包括每一个计划结点的估计启动和总代价，以及估计的行数和每行的宽度。这个参数默认被设置为TRUE。
buffers:包括缓冲区使用的信息。特别是：共享块命中、读取、标记为脏和写入的次数、本地块命中、读取、标记为脏和写入的次数、以及临时块读取和写入的次数。一次命中表示避免了一次读取，因为需要的块已经在缓存中找到了。共享块包含着来自于常规表和索引的数据，本地块包含着来自于临时表和索引的数据，而临时块包含着在排序、哈希、物化计划结点和类似情况中使用的短期工作数据。脏块的数量表示被这个查询改变的之前未被修改块的数量，而写入块的数量表示这个后台在查询处理期间从缓存中替换出去的脏块的数量。为一个较高层结点显示的块数包括它的所有子结点所用到的块数。在文本格式中，只会打印非零值。只有当ANALYZE也被启用时，这个参数才能使用。它的默认被设置为FALSE。
timing:在输出中包括实际启动时间以及在每个结点中花掉的时间。反复读取系统时钟的负荷在某些系统上会显著地拖慢查询，因此在只需要实际的行计数而不是实际时间时，把这个参数设置为FALSE可能会有用。即便用这个选项关闭结点层的计时，整个语句的运行时间也总是会被度量。只有当ANALYZE也被启用时，这个参数才能使用。它的默认被设置为TRUE。
summary:在查询计划之后包含摘要信息（例如，总计的时间信息）。当使用ANALYZE 时默认包含摘要信息，但默认情况下不包含摘要信息，但可以使用此选项启用摘要信息。使用EXPLAIN EXECUTE中的计划时间包括从缓存中获取计划所需的时间以及重新计划所需的时间（如有必要）。
format:指定输出格式，可以是 TEXT、XML、JSON 或者 YAML。非文本输出包含和文本输出格式相同的信息，但是更容易被程序解析。这个参数默认被设置为TEXT。

如何阅读执行计划

从上面的例子来看，EXPLAIN 命令的输出可以看做是一个树形结构，我们称之为查询计划树，树的每个节点包括对应的节点类型，作用对象以及其他属性例如cost、rows、width 等。如果只显示节点类型，上面的例子可以简化为如下结构：

Sort 
└── Hash Join 
          ├── Seq Scan
          └── Hash
                     └── Bitmap Heap Scan
                                └── Bitmap Index Scan

阅读执行计划是查询计划从下往上阅读，每个节点执行返回的结果会传递给父节点，比如这个例子，首先是进行Bitma Index Scan，然后将结果传递给Bitmap Heap Scan，然后传递给Hash节点。Seq Scan是与Hash平级的节点，Hash和Seq Scan两个节点将结果传递给Hash Join。Hash Join将结果传递给Sort。

在EXPLAIN 命令的输出结果中可能包含多种类型的执行节点，可以大体分为几大类：

1. 控制节点（Control Node)
2. 扫描节点（ScanNode)
3. 物化节点（Materialization Node)
4. 连接节点（Join Node)

下面详细介绍一下扫描节点，扫描节点狭义的讲指的是扫描表中的数据，实际也包含扫描函数结果集、子查询结果等。目前支持的扫描节点如下:

- Seq Scan，顺序扫描
- Index Scan，基于索引扫描，但不只是返回索引列的值
- IndexOnly Scan，基于索引扫描，并且只返回索引列的值，简称为覆盖索引
- BitmapIndex Scan，利用Bitmap 结构扫描
- BitmapHeap Scan，把BitmapIndex Scan 返回的Bitmap 结构转换为元组结构
- Tid Scan，用于扫描一个元组TID 数组
- Subquery Scan，扫描一个子查询
- Function Scan，处理含有函数的扫描
- TableFunc Scan，处理tablefunc 相关的扫描
- Values Scan，用于扫描Values 链表的扫描
- Cte Scan，用于扫描WITH 字句的结果集
- NamedTuplestore Scan，用于某些命名的结果集的扫描
- WorkTable Scan，用于扫描Recursive Union 的中间数据
- Foreign Scan，用于外键扫描
- Custom Scan，用于用户自定义的扫描

下面重点介绍常用的几个：Seq Scan、Index Scan、IndexOnly Scan、BitmapIndex Scan、BitmapHeap Scan

Seq Scan 是全表顺序扫描，一般查询没有索引的表需要全表顺序扫描，例如下面的EXPLAIN 输出：

postgres=> explain(ANALYZE,VERBOSE,BUFFERS) select * from class where st_no=2; 
QUERY PLAN 
--------------------------------------------------------------------------------------------------
Seq Scan on public.class (cost=0.00..26.00 rows=1 width=35) (actual time=0.136..0.141 rows=1 loops=1) 
    Output: st_no, name 
    Filter: (class.st_no = 2) 
    Rows Removed by Filter: 1199 
    Buffers: shared hit=11 

Planning time: 0.066 ms 
Execution time: 0.160 ms

Seq Scan on public.class 表明了这个节点的类型和作用对象，即在class 表上进行了全表扫描。
(cost=0.00..26.00 rows=1 width=35) 表明了这个节点的代价估计，0.00是节点启动成本，26.00为该节点的代价，rows是该节点输出行的估计值，width是该节点输出行的平均宽度。
(actual time=0.136..0.141 rows=1 loops=1) 表明了这个节点的真实执行信息，0.136表示该节点启动时间单位是ms。0.141表示该节点耗时单位是ms。rows代表实际输出行。loops代表节点循环次数。
Output: st_no, name 表明了SQL 的输出结果集的各个列，当EXPLAIN 命令中的选项VERBOSE 为on时才会显示。
Filter: (class.st_no = 2) 表明了Seq Scan 节点之上的Filter 操作，即全表扫描时对每行记录进行过滤操作，过滤条件为class.st_no = 2
Rows Removed by Filter: 1199 表明了过滤操作过滤了多少行记录，属于Seq Scan 节点的VERBOSE 信息，只有EXPLAIN 命令中的VERBOSE 选项为on 时才会显示
Buffers: shared hit=11 表明了从共享缓存中命中了11 个BLOCK，属于Seq Scan 节点的BUFFERS 信息，只有EXPLAIN 命令中的BUFFERS 选项为on 时才会显示
Planning time: 0.066 ms 表明了生成查询计划的时间
Execution time: 0.160 ms 表明了实际的SQL 执行时间，其中不包括查询计划的生成时间

Index Scan 是索引扫描，主要用来在WHERE 条件中存在索引列时的扫描，如上面Seq Scan 中的查询如果在st_no 上创建索引，则EXPLAIN 输出如下：

QUERY PLAN 
--------------------------------------------------------------------------------------------------
Index Scan using no_index on public.class (cost=0.28..8.29 rows=1 width=35) (actual time=0.022..0.023 rows=1 loops=1) 
     Output: st_no, name 
     Index Cond: (class.st_no = 2) 
     Buffers: shared hit=3 
Planning time: 0.119 ms 
Execution time: 0.060 ms 
(6 rows)

Index Scan using no_index on public.class 表明是使用的public.class 表的no_index 索引对表进行索引扫描的

Index Cond: (class.st_no = 2) 表明索引扫描的条件是class.st_no = 2

可以看出，使用了索引之后，对相同表的相同条件的扫描速度变快了。这是因为从全表扫描变为索引扫描，通过Buffers: shared hit=3 可以看出，需要扫描的BLOCK（或者说元组）少了，所以需要的代价也就小了，速度也就快了。

IndexOnly Scan 是覆盖索引扫描，所需的返回结果能被所扫描的索引全部覆盖，如上面Index Scan中的SQL 把“select * ” 修改为“select st_no” ，其EXPLAIN 结果输出如下：

postgres=> explain(ANALYZE,VERBOSE,BUFFERS) select st_no from class where st_no=2; 
QUERY PLAN 
--------------------------------------------------------------------------------------------------
Index Only Scan using no_index on public.class (cost=0.28..4.29 rows=1 width=4) (actual time=0.015..0.016 rows=1 loops=1) 
    Output: st_no Index Cond: (class.st_no = 2) 
    Heap Fetches: 0 
    Buffers: shared hit=3 
Planning time: 0.058 ms 
Execution time: 0.036 ms 
(7 rows)

Index Only Scan using no_index on public.class 表明使用public.class 表的no_index 索引对表进行覆盖索引扫描。Heap Fetches 表明需要扫描数据块的个数。虽然Index Only Scan 可以从索引直接输出结果。但是因为PostgreSQL MVCC 机制的实现，需要对扫描的元组进行可见性判断，即检查visibility MAP 文件。当新建表之后，如果没有进行过vacuum和autovacuum操作，这时还没有VM文件，而索引并没有保存记录的版本信息，索引Index Only Scan 还是需要扫描数据块（Heap Fetches 代表需要扫描的数据块个数）来获取版本信息，这个时候可能会比Index Scan 慢。

Bitmap Index Scan 与Index Scan 很相似，都是基于索引的扫描，但BitmapIndex Scan 节点每次执行返回的是一个位图而不是一个元组，位图中每位代表了一个扫描到的数据块。而BitmapHeap Scan一般会作为BitmapIndex Scan 的父节点，将BitmapIndex Scan 返回的位图转换为对应的元组。这样做最大的好处就是把Index Scan 的随机读转换成了按照数据块的物理顺序读取，在数据量比较大的时候，这会大大提升扫描的性能。EXPLAIN结果输出如下：

postgres=> explain(ANALYZE,VERBOSE,BUFFERS) select * from class where st_no=2; 
QUERY PLAN 
--------------------------------------------------------------------------------------------------
Bitmap Heap Scan on public.class (cost=4.29..8.30 rows=1 width=35) (actual time=0.025..0.025 rows=1 loops=1) Output: st_no, name 
Recheck Cond: (class.st_no = 2) 
Heap Blocks: exact=1 
Buffers: shared hit=3 
-> Bitmap Index Scan on no_index (cost=0.00..4.29 rows=1 width=0) (actual time=0.019..0.019 rows=1 loops=1) Index Cond: (class.st_no = 2) 
Buffers: shared hit=2 
Planning time: 0.088 ms 
Execution time: 0.063 ms 
(10 rows)

Bitmap Index Scan on no_index 表明使用no_index 索引进行位图索引扫描
Index Cond: (class.st_no = 2) 表明位图索引的条件为class.st_no = 2
Bitmap Heap Scan on public.class 表明对public.class 表进行Bitmap Heap 扫描
Recheck Cond: (class.st_no = 2) 表明Bitmap Heap Scan 的Recheck操作的条件是class.st_no = 2，这是因为Bitmap Index Scan 节点返回的是位图，位图中每位代表了一个扫描到的数据块，通过位图可以定位到一些符合条件的数据块（这里是3，Buffers: shared hit=3），而Bitmap Heap Scan 则需要对每个数据块的元组进行Recheck
Heap Blocks: exact=1 表明准确扫描到数据块的个数是1
一般来说：
大多数情况下，Index Scan 要比 Seq Scan 快。但是如果获取的结果集占所有数据的比重很大时，这时Index Scan 因为要先扫描索引再读表数据反而不如直接全表扫描来的快。
如果获取的结果集的占比比较小，但是元组数很多时，可能Bitmap Index Scan 的性能要比Index Scan 好。
如果获取的结果集能够被索引覆盖，则Index Only Scan 因为不用去读数据，只扫描索引，性能一般最好。但是如果VM 文件未生成，可能性能就会比Index Scan 要差。

SQL优化示例

无索引

canno=> explain analyze select * from t1 where id =1;
                                                    QUERY PLAN
-------------------------------------------------------------------------------------------------------------------
 Gather  (cost=1000.00..97331.31 rows=1 width=4) (actual time=0.217..302.316 rows=1 loops=1)
   Workers Planned: 2
   Workers Launched: 2
   ->  Parallel Seq Scan on t1  (cost=0.00..96331.21 rows=1 width=4) (actual time=191.208..289.240 rows=0 loops=3)
         Filter: (id = 1)
         Rows Removed by Filter: 3333333
 Planning Time: 0.030 ms
 Execution Time: 302.381 ms
(8 rows)

通过计划可以看出是全表扫描的t1表，过滤条件是id=1；
针对t1(id)创建索引
create index on t1(id)

canno=> explain analyze select * from t1 where id =1;
                                                    QUERY PLAN
-------------------------------------------------------------------------------------------------------------------
 Index Only Scan using t1_id_idx on t1  (cost=0.43..2.45 rows=1 width=4) (actual time=0.035..0.036 rows=1 loops=1)
   Index Cond: (id = 1)
   Heap Fetches: 1
 Planning Time: 0.134 ms
 Execution Time: 0.052 ms
(5 rows)

查看新的执行计划，时间缩短至0.052ms。

不是最优索引

create table t2(id int,name int);
insert into t2 select random()*(id/100),random()*(id/100) from generate_series(1,1000000) t(id);

create index on t2(id)

canno=> explain analyze select * from t2 where id=10 and name=13;
                                                   QUERY PLAN
----------------------------------------------------------------------------------------------------------------
 Index Scan using t2_id_idx on t2  (cost=0.42..12.12 rows=1 width=8) (actual time=0.098..2.631 rows=88 loops=1)
   Index Cond: (id = 10)
   Filter: (name = 13)
   Rows Removed by Filter: 4461
 Planning Time: 0.081 ms
 Execution Time: 2.655 ms
(6 rows)

查看计划发现已经做了索引扫描，但是还是存在name字段的条件过滤。可以增加一个id+name的索引。
create index on t2(id,name);

canno=> explain analyze select * from t2 where id=10 and name=13;
                                                        QUERY PLAN
---------------------------------------------------------------------------------------------------------------------------
 Index Only Scan using t2_id_name_idx on t2  (cost=0.42..15.48 rows=18 width=8) (actual time=0.028..0.134 rows=88 loops=1)
   Index Cond: ((id = 10) AND (name = 13))
   Heap Fetches: 88
 Planning Time: 0.198 ms
 Execution Time: 0.157 ms
(5 rows)

可以看出时间从2.6ms降低至0.157ms

码农公寓

往期分享

概述

找到慢SQL

EXPLAIN语法

如何阅读执行计划

SQL优化示例

无索引

不是最优索引

相关文章