如何分析CPU被打爆——实战篇

1前言

在上一篇 《如何分析CPU 100%的情况》文章里面，我介绍了数据库中常见的 CPU 被打爆的情形以及对应的排查手段，这一篇会以一个实战案例来模拟分析一下 CPU 被打爆的罪魁祸首，闲话少叙，进入正题。

2分区子表过多

我第一个能想到的便是分区表，因为分区表用得多用得广，案例也十分典型，尤其是当某个表含有大量子表的时候，性能问题便尤为突出。此处为了演示的效果，以 10 版本为例

In PostgreSQL 11 this elimination of unneeded partitions (aka partition pruning) is no longer an exhaustive linear search. A binary search quickly identifies matching LIST and RANGE partitions. A hashing function finds the matching partitions for HASH partitioned tables, which are new in PG11.

This also makes improvements so that it’s able to prune partitions in a few more cases than was previously possible.

在 PostgreSQL 11 中，消除不需要的分区（分区裁剪）不再是穷举线性搜索。二进制搜索可以快速识别匹配的 LIST 和 RANGE 分区。一个散列函数为HASH分区表找到匹配的分区，这是11中的新功能。

这也进行了改进，因此它能够在比以前更多的情况下裁剪分区。

可以看到，在 11 以前的版本，分区裁剪使用的线性扫描，通过"constraint_exclusion"机制进行，这是一种线性算法，需要逐个查看每个分区的元数据，以检查分区是否匹配，也就意味着子表越多，进行裁剪消耗的时间也就越多，在 11 以后使用了类似二分查找的方式，加速裁剪的速度。

此处使用 SQL 拼接和 gexec 的方式构造分区表（gexec 可以将查询缓冲区发送到服务端，然后将查询输出的每一行作为要执行的 SQL 语句进行处理）。

postgres=# create table native_partition (like test_partition including all) partition by list(id);
CREATE TABLE
postgres=# SELECT 'CREATE TABLE native_partition_list_' || p_id || ' PARTITION of native_partition FOR VALUES in (' || p_id || ');' FROM generate_series(1,10000) as p_id ;  ---创建一万个子表
                                          ?column?                                           
---------------------------------------------------------------------------------------------
 CREATE TABLE native_partition_list_1 PARTITION of native_partition FOR VALUES in (1);
 CREATE TABLE native_partition_list_2 PARTITION of native_partition FOR VALUES in (2);
 CREATE TABLE native_partition_list_3 PARTITION of native_partition FOR VALUES in (3);
 CREATE TABLE native_partition_list_4 PARTITION of native_partition FOR VALUES in (4);
 ...
postgres=# \gexec
...
postgres=# \d native_partition
              Partitioned table "public.native_partition"
 Column |            Type             | Collation | Nullable | Default 
--------+-----------------------------+-----------+----------+---------
 id     | integer                     |           |          | 
 info   | text                        |           |          | 
 t_time | timestamp without time zone |           | not null | 
Partition key: LIST (id)
Number of partitions: 10000 (Use \d+ to list them.)
postgres=# insert into native_partition select id,md5(random()::text),clock_timestamp() from generate_series(1,10000) as id;
INSERT 0 10000

现在 native_partition 分区表共有一万个子表，此时的查询光是生成执行计划都会耗时许久

postgres=# explain analyze select id from native_partition where id = '99';
                                                       QUERY PLAN                                                        
-------------------------------------------------------------------------------------------------------------------------
 Append  (cost=0.00..24.12 rows=6 width=4) (actual time=0.770..0.772 rows=1 loops=1)
   ->  Seq Scan on native_partition_list_99  (cost=0.00..24.12 rows=6 width=4) (actual time=0.769..0.770 rows=1 loops=1)
         Filter: (id = 99)
 Planning time: 922.075 ms
 Execution time: 0.972 ms
(5 rows)

可以看到计划时间就高达接近 1 秒，实际执行 0.1 秒。现在让我们用 pgbench 压测一下（就只做简单的裁剪查询），同时配合 perf 捕捉 CPU 高消耗的部分

[postgres@xiongcc ~]$ cat bench.sh 
\set aid random(1,10000)
SELECT info FROM native_partition WHERE id = :aid;

perf 加上 -g 可以查看调用链，通过上下键选择某个函数，按回车就可以展开：perf top -u postgres -g

如我在《PostgreSQL优化器解析》篇章里面所说过，一条SQL来了之后，会经过Parser → Analyzer → Rewriter → Planner → Executor这一系列步骤。若是DDL语句，无需进行优化，到utility模块处理，对于DML则需要按照完整的流程。

exec_simple_query 则作为查询的入口，然后会调用一系列函数去执行对应的动作

1. pg_parse_query 生成语法解析树（上图的 Parser 阶段）
2. parse_analyze 返回查询树（上图的 Analyzer 阶段）
3. pg_rewrite_query 生成重写后的语法树（上图的 Rewriter 阶段）

pg_plan_queries 则作为查询优化的入口（上图的 Planner 阶段）

清除了调用链之后再来看 perf 生成的结果就清晰多了。可以看到 CPU 耗时基本都耗费在了执行计划生成的阶段中。

另外除了 perf top，我一般还喜欢用 perf record 进行采样，perf record -F 99 -a -g -- sleep 60，采集 60 秒以后会保存在文件 perf.data 中（采样时间为 60 秒，每秒采样 99 个事件），然后使用 perf report 工具进行分析，perf report --stdio

这里也可以看到一些关键的地方

• subquery_planner：做一些预处理，如我在优化器解析篇章里所说，比如函数内联、子链提升、表达式预处理等等
• relation_excluded_by_constraints/get_relation_constraints：如前面所说，裁剪使用的 constraint_exclusion 线性算法
• expand_inherited_tables/find_all_inheritors，这个函数就是识别分区表并找到所有的分区子表的入口

既然提到了 perf，那就不得不提组合拳火焰图了，火焰图因其形似火焰而得名，前面的命令缺乏一个全局的视野，我们无法看出全局的调用栈，也弄不清楚这些函数之间的关系。火焰图则不然。开源代码地址：https://github.com/brendangregg/FlameGraph，使用方式也很简单：

1. 用perf script工具对perf.data（第二步使用perf record采集到的数据）进行解析：perf script -i perf.data &> perf.unfold
2. 将perf.unfold中的符号进行折叠：./stackcollapse-perf.pl perf.unfold &> perf.folded
3. 最后生成svg图：./flamegraph.pl perf.folded > perf.svg

然后随便用个看图工具打开 perf.svg

• 由底部到顶部可以追溯一个唯一的调用链，下面的方块是上面方块的父调用。
• 同一父调用的方块从左到右以字母序排列。
• 方块上的字符表示一个调用名称，括号内是火焰图指向的调用在火焰图中出现的次数和这个方块占最底层方块的宽度百分比。
• 方块的颜色没有实际意义，相邻方块的颜色差只为了便于查看。
• x轴表示采样次数或者频率，如果一个函数在 x 轴占据的宽度越宽，就表示它被抽到的次数多，即执行的时间长。注意，x 轴不代表时间，而是所有的调用栈合并后，按字母顺序排列的。
• y 轴表示调用栈，每一层都是一个函数。调用栈越深，火焰就越高，顶部就是正在执行的函数，下方都是它的父函数。

我们需要关注的是火焰图顶部的一些 “平顶山”（plateaus），顶部说明它没有子调用，方块宽说明它耗时长，长时间夯住，或者被非常频率地调用，这种方块指向的调用才是性能问题的罪魁祸首。这个图也很清晰，relation_excluded_by_constraints占据了很大宽度，整个图大部分都耗在了生成执行计划的过程中。

3小结

至此，我们通过 perf 分析出了 CPU 冲高的大致方向（expand_inherited_tables/find_all_inheritors涉及到分区子表，relation_excluded_by_constraints约束排除，线性扫描）。下一篇我们再模拟一下 CPU 冲高的其他案例，拭目以待。