【實錄】首次利用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中文社區網站。

---