【实录】首次利用GPCC历史数据调优Greenplum 完结篇

本文做者Pivotal Greenplum工程技术经理王昊所在的Greenplum研发部门近期在帮助客户解决一个全局性能问题，并经过本文记录了分析过程和解决思路。咱们在【实录】首次利用GPCC历史数据调优Greenplum 第一部分中帮助你们了解了GPDB集群的总体性能特征，在【实录】首次利用GPCC历史数据调优Greenplum 第二部分中分析了查询负载总体状况。今天，将为你们带来《首次利用GPCC历史数据调优Greenplum》系列的完结篇——分析数据表行数变化趋势供你们学习讨论。

第三部分，分析数据表行数变化趋势

在第一部分的末尾，咱们怀疑的另外一个方向就是用户的数据量是否发生了显著的增长。因为数据量增长能够直接致使磁盘IO变多，侧面上也能联系到“总体性能降低”的反馈。

GPCC4.9/6.1即将提供数据表大小的监控和变化趋势历史数据的功能，但撰写本文时，该功能还在研发中，本次客户的数据固然也不包括这些全新历史数据。

可是这并不意味着咱们一筹莫展，这里咱们介绍GPCC4.8的第三个历史表：gpmetrics.gpcc_plannode_history。这个表能够记录（1）Master上生成的查询计划树（2）查询执行时每一个查询计划节点在每一个Segment进程上运行的实际结果。

执行计划节点历史（gpmetrics.gpcc_plannode_history）是GPCC 4.x的新功能，之前的GPPerfmon并无相似功能。这个表提供的信息很是丰富，所以也须要占用更多空间，为了平衡GPCC目前只对执行时间超过10秒的查询记录完整的计划节点历史。这个表的用途很是多，例如绘制图形化的执行计划树，在之前的介绍文章《新一代Greenplum监控管理平台》里有过介绍。

这里咱们借助这个表的信息推算用户数据表大小及变化趋势。咱们知道GP执行查询时经过Seq Scan节点进行表扫描；若是扫描节点的条件是空，则说明是一个全表扫描；在此基础上累加全部Segment 上同一扫描节点的输出的行数，即为该表的实际行数。

基于此下面的查询能够统计出全部的全表扫描的结果。

WITH master_nodes (tmid, ssid, ccnt, nodeid, rel_oid, relation_name) AS (
   SELECT tmid, ssid, ccnt, nodeid, max(rel_oid), max(relation_name)
   FROM gpmetrics.gpcc_plannode_history
   WHERE ctime >= '2019-09-23' AND ctime < '2019-10-17'
   AND node_type IN ('Seq Scan', 'Append-only Scan', 'Append-only Columnar Scan', 'Table Scan', 'Bitmap Heap Scan')
   AND condition = '' -- 只统计没有过滤条件的全表扫描
   AND segid = -1      -- MASTER记录的执行计划过滤出适合的query id + node id
   GROUP BY tmid, ssid, ccnt, nodeid
),
table_rows (rel_oid, relation_name, hash_name, cdate, row_cnt, scan_cnt) AS (
   SELECT rel_oid, relation_name, substring(md5(relation_name) FROM 1 FOR 12) tname
       , ctime::date ctime, round(avg(row_cnt)) AS row_cnt, count(*) AS scan_cnt
   FROM (
       SELECT n.ctime, n.tmid, n.ssid, n.ccnt, n.nodeid, m.rel_oid, m.relation_name, sum(n.tuple_count + n.ntuples) row_cnt
       FROM gpmetrics.gpcc_plannode_history n -- JOIN全部Segment的数据累加获得行数
       INNER JOIN master_nodes m
       ON n.tmid = m.tmid AND n.ssid = m.ssid AND n.ccnt = m.ccnt AND n.nodeid = m.nodeid
       GROUP BY n.ctime, n.tmid, n.ssid, n.ccnt, n.nodeid, m.rel_oid, m.relation_name
   ) dt
   GROUP BY rel_oid, relation_name, ctime::date
   HAVING avg(row_cnt) > 10000 AND count(*) > 10 -- 粗略过滤掉过小的表和不常常访问的表
)
SELECT tr.rel_oid, tr.hash_name, tr.cdate, tr.row_cnt, tr.scan_cnt
FROM table_rows tr
INNER JOIN (
   SELECT rel_oid, relation_name, sum(row_cnt), rank() OVER(ORDER BY sum(row_cnt) DESC) rn
   FROM table_rows GROUP BY rel_oid, relation_name, hash_name
) tor -- 按照表内的行数排序
ON tr.rel_oid = tor.rel_oid AND tr.relation_name = tor.relation_name
ORDER BY tor.rn, cdate
;

结果比较长，下图截取了排名靠前的行

剖析

经过对一批主要的业务表进行统计，发现从9月22日升级到10月中旬期间，没有明显的数据量变化，故推断用户业务模型不存在显著的数据量增大现象，所以致使性能退化的可能性低。

第四部分，分析具体查询的查询计划

结合第二部分和第三部分的分析结果，咱们基本排除了查询变多、数据量变大等因素，这时第一部分的现象（磁盘IO变多）仍是悬案。经过汇总报告和客户进一步沟通，咱们获得了重要的信息，性能降低的反馈主要来自于数据库用户f8da676。

在前面第二部分分析中注意到了该用户是短查询为主，并且对比GP4和GP5的数据，长查询的耗时有必定增长。客户自述该数据库用户是经过Web应用访问数据库。这种Web端的查询通常时间较短，对响应时间要求高，若是个别高频查询速度变慢确实会形成用户体验显著下降。

结合上述分析结果加上客户反馈的佐证，咱们聚焦到f8da676的查询，钻取更细节的信息。首先的调查高频度重复发生的查询。在Web应用里有大量固化在程序里的查询，例如登录、打开页面、查询这些操做。这种工做负载的一个特色就是相同的SQL语句大量查询重复发生，因此咱们优先关注这些查询，按照累计的执行时间排序。在gpcc_queries_history表里又一个字段query_hash，咱们对这个字段作group by就能够汇集重复的查询。（本案中客户不提供query_text，只能利用query_hash）

SELECT substring(query_hash FROM 1 FOR 12)
     , count(*) cnt, sum(tfinish - tsubmit)::interval(0)
     , avg(tfinish - tsubmit)
FROM gpmetrics.gpcc_queries_history
WHERE substring(md5(username) FROM 1 FOR 7) = 'f8da676'  -- 限定咱们要调查的用户
GROUP BY query_hash
HAVING count(*) > 500 -- 重复次数超过必定数量
ORDER BY sum(tfinish - tsubmit) DESC -- 按照累计执行时间排序
LIMIT 20; -- 取TOP2

  substring   |   cnt    |    sum    |       avg
--------------+----------+-----------+-----------------
 f19c3f3fa258 |    53903 | 133:55:28 | 00:00:08.944363
 a0a59ee1ae70 |   205398 | 52:49:56  | 00:00:00.925986
 3e8124b89ecc |  1166734 | 50:45:45  | 00:00:00.156629
 645323facf3d |    51237 | 39:53:02  | 00:00:02.802317
 864a2dace31e | 10591406 | 32:56:50  | 00:00:00.011199
 e15e361b69e2 |  2079284 | 29:42:11  | 00:00:00.051427
 91085d8d4f7b |    15485 | 26:40:19  | 00:00:06.20077
 e7c1dd315794 |    54448 | 20:03:46  | 00:00:01.326516
 59e587262761 |    44803 | 12:10:03  | 00:00:00.977689
 57630afb6ab7 |   225377 | 09:53:57  | 00:00:00.158123
 203de5f2a3d7 |    42702 | 09:27:24  | 00:00:00.797241
 cbb3d6598b1d |    55918 | 09:25:43  | 00:00:00.60702
 7e6d6491c0f1 |   268018 | 09:19:58  | 00:00:00.125357
 bbc6d3151ae2 |    27763 | 09:17:16  | 00:00:01.20432
 c6f57e4d2bf6 |   267741 | 08:35:38  | 00:00:00.11555
 0172117cf4e2 |   435072 | 07:58:14  | 00:00:00.065952
 5b492fd46683 |   107781 | 07:57:19  | 00:00:00.265714
 5c5ffc59b6f9 |    64307 | 07:48:24  | 00:00:00.437028
 f811d0f43ec0 |    42565 | 06:49:33  | 00:00:00.577295
 bd4c80a9d9f2 |   267741 | 06:33:46  | 00:00:00.088241

剖析

这个结果里排名第一的查询f19c3f3fa258很是抢眼，它知足三个重要的特征：

1. 重复次数足够多

* 日均2000次以上，要么是某些任务周期性调度，要么是由UI页面人工操做时触发的

* 咱们经过下面SQL了解该查询天天发生的时间

SELECT extract(hour FROM tfinish) AS hour_of_day, count(*)
FROM gpmetrics.gpcc_queries_history
WHERE substring(md5(username) FROM 1 FOR 7) = 'f8da676'
AND substring(query_hash FROM 1 FOR 12) = 'f19c3f3fa258'
GROUP BY 1
ORDER BY 1；

* 不难看出这个查询是天天白天数量多，应该是人工操做触发的

2. 累计执行时间很是长，达到133小时55分钟

* 咱们经过如下SQL得知，在f8da676用户下的所有查询累计也只有1300小时左右，单独这一个查询就占了10%的执行时间。

SELECT sum(tfinish - tsubmit)::interval(0)
FROM gpmetrics.gpcc_queries_history
WHERE substring(md5(username) FROM 1 FOR 7) = 'f8da676';

   sum
------------
 1320:34:01

3. 该查询的平均执行时间偏长，达到8秒之多。这种量级的查询若是出如今业务系统中，与那些毫秒级的短查询不一样，足以引发用户的体验下降。

综合上述三点，咱们认为f19c3f3fa258这个查询很是值得怀疑，有着很高的分析价值，应该立刻着手调查。

定位到具体查询以后，咱们经过查询计划继续了解该查询的更多细节。

第一步，经过gpcc_queries_history, 咱们找到这个执行较长的一次的query ID：

SELECT tmid, ssid, ccnt, (tfinish - tsubmit)::interval(0)
FROM gpmetrics.gpcc_queries_history
WHERE substring(md5(username) FROM 1 FOR 7) = 'f8da676'
AND substring(query_hash FROM 1 FOR 12) = 'f19c3f3fa258'
ORDER BY 4 DESC
LIMIT 3;

    tmid    |  ssid  | ccnt | interval
------------+--------+------+----------
 1569340966 |  42118 |   18 | 00:03:49
 1569340966 | 518345 |   30 | 00:03:23
 1569340966 |  46178 |   10 | 00:03:18

第二步，用query ID找到这个查询的执行计划（这里对出现的表名进行了脱敏处理）

SELECT nodeid, parent_nodeid AS pnid, node_type, rel_oid, relation_name, condition
FROM gpmetrics.gpcc_plannode_history
WHERE tmid = 1569340966 AND ssid = 42118 AND ccnt = 18
AND segid = -1 AND sliceid = 0
ORDER BY nodeid;

第三步，经过nodeid和parent_nodeid之间的父子关系，恢复这个查询的计划树

这个查询树展现的很是清晰

1. 这是一个简单的单表查询，对表t1扫描加汇集，扫描时应用了范围过滤条件 $2 <= abc < $3 和等值过滤条件 def = $1。

2. 典型的两阶段汇集，如今Segment上本地聚合一次，再Gather Motion到Master上全局聚合一次。这是GP常规的执行计划。

3. 这个查询对AO表t1的18个分区进行了扫描。

咱们不清楚t1表一共有多少分区，也不清楚分区键和分布键各自是什么。一种怀疑就是列abc就是分区键，planner优化器应该根据abc列上的范围条件进行分区裁剪，从而减小扫描的分区数。猜想某些缘由致使没能正确进行分区裁剪。

抱着这种猜想，经过进一步跟客户，咱们获得了t1表的定义DDL（已脱敏）。果真abc是分区键。该表一年一个分区，共18个分区。

CREATE TABLE t1 (
   …  -- 此处省略若干行
   abc timestamp without time zone NOT NULL,
   …  -- 此处省略若干行
)
WITH (appendonly=true, orientation=row) DISTRIBUTED BY (...) PARTITION BY RANGE(abc)
 (
 START ('2002-01-01 00:00:00'::timestamp without time zone) END ('2003-01-01 00:00:00'::timestamp without time zone) EVERY ('1 year'::interval) WITH (tablename='t1_1_prt_2', appendonly=true, orientation=row ),
 START ('2003-01-01 00:00:00'::timestamp without time zone) END ('2004-01-01 00:00:00'::timestamp without time zone) EVERY ('1 year'::interval) WITH (tablename='t1_1_prt_3', appendonly=true, orientation=row ),
… -- 此处省略若干行
 START ('2016-01-01 00:00:00'::timestamp without time zone) END ('2017-01-01 00:00:00'::timestamp without time zone) EVERY ('1 year'::interval) WITH (tablename='t1_1_prt_16', appendonly=true, orientation=row ),
 START ('2017-01-01 00:00:00'::timestamp without time zone) END ('2018-01-01 00:00:00'::timestamp without time zone) EVERY ('1 year'::interval) WITH (tablename='t1_1_prt_17', appendonly=true, orientation=row ),
 START ('2018-01-01 00:00:00'::timestamp without time zone) END ('2019-01-01 00:00:00'::timestamp without time zone) EVERY ('1 year'::interval) WITH (tablename='t1_1_prt_18', appendonly=true, orientation=row ),
 DEFAULT PARTITION others  WITH (tablename='t1_1_prt_others', appendonly=true, orientation=row )
 );

至此咱们高度怀疑这个查询没能正确利用GP的分区裁剪功能，每次查询都对十几年来的所有数据进行了扫描，形成查询时间长达8秒。并且这个缘由也能充分佐证磁盘IO增多的现象。

第五部分，缘由分析和后续处置

定位到了问题查询和现象，咱们的工程师很快发现

1. 客户提交的查询使用了JDBC

JDBC在提交查询时会时使用Prepare … Execute 方式。Prepare一个带参数的查询时GPDB会先生成一个执行计划，因为此时参数未知，GPDB可能无法应用分区裁剪或DirectDispatch这样的优化。当执行Execute时，参数才会告知GPDB，这时GPDB会判断直接使用Prepare生成的查询计划仍是从新生成一个更优的查询计划。本案例中捕捉到的慢查询都是没有从新生成执行计划，所以没能定期望应用分区裁剪。

在老版本GP4上，并无直接使用Prepare语句生成的执行计划的功能，所以全部查询计划都是在Execute时从新生成的。这原本是一个GP4的问题，在GP5获得了改进，便可以采用Prepare预生成的查询计划以加速执行，可是本案例中反而致使了Prepare出的低效查询计划被采用了。

2. 客户关闭了ORCA

在上面状况中，即使采用了没有分区裁剪的执行计划，ORCA也能克服这个问题。由于ORCA会生成动态分区扫描的计划，这种优化技术将分区裁剪的决定权下放到执行器的执行阶段，所以不会收到Prepare语句的影响。但由于客户环境下ORCA默认关闭了，才暴露出了此次的问题。

经验证，升级JDBC驱动，增长适当的调试参数后，问题基本获得解决。除了这个查询以外，咱们能够预期的是其余查询将也能够应用分区裁剪、DirectDispatch这些优化，集群的总体响应速度和磁盘负载应该一并好转。

后记

我在2018年末杭州的PG大会上作过一个报告，大胆提出了要经过查询历史数据改进数据库自动化运维的观点，原报告见《为您详细讲解Greenplum 5 智能化运维》。通过将近一年的时间，终于有机会在实际生产中运用，颇为欣慰。

这个案例中展现的不少分析手段、分析角度都是比较独特的，在之前咱们做为GP的原厂研发人员也不曾使用过。我但愿基于这样的案例拓展对用户查询负载的认识，逐步从这些分析方法中筛选出有效的套路，进而落实到智能化运维产品中。这个愿景目前看来充满机遇和挑战，一旦可以实现，相信会带来广阔的应用价值。

得到更多关于Greenpum的技术干货，请访问Greenplum中文社区网站。

---