前言天下武功，唯快不破。在偵探的世界中，破案效率永遠是衡量一名偵探能力的不二法門。作為推理界冉冉升起的新星，大偵探福爾摩斯·K憑借著冷靜的頭腦、嚴謹?shù)乃季S，為我們展現(xiàn)了一場場華麗而熱血的推理盛宴。
接下來，我們不僅僅是看客，還將追隨福爾摩斯·K的腳步，體驗一場身臨其境的冒險。一起尋訪產(chǎn)生數(shù)據(jù)庫性能問題的根源，深度探索和解析數(shù)據(jù)庫性能問題：
妙用調(diào)優(yōu)“四劍客”，輕松完成金倉數(shù)據(jù)庫KingbaseES的性能調(diào)優(yōu)！
案情接入，問題初露端倪
案發(fā)時間
2022.10.26 晴
案發(fā)地點
X客戶項目現(xiàn)場
案件描述
業(yè)務(wù)系統(tǒng)上線前出現(xiàn)性能問題，導(dǎo)致業(yè)務(wù)卡頓情況嚴重。
案情接入
由于生產(chǎn)環(huán)境不可隨意改動，在現(xiàn)場支援的華生醫(yī)生配置了與生產(chǎn)環(huán)境一致的測試環(huán)境，來進行初步的診斷。后續(xù)的性能優(yōu)化方案也會先于測試環(huán)境驗證，待性能達標(biāo)之后，方可在生產(chǎn)環(huán)境上線。
根據(jù)華生醫(yī)生跟X客戶的溝通，多個應(yīng)用場景使用連接池連接到KingbaseES服務(wù)器，300并發(fā)，其中一個業(yè)務(wù)場景慢，吞吐量上不來，平均一個業(yè)務(wù)請求超過85秒。華生醫(yī)生要在當(dāng)日內(nèi)完成對該業(yè)務(wù)場景的性能優(yōu)化，使X客戶的平均業(yè)務(wù)響應(yīng)時間進入10秒，以保證業(yè)務(wù)系統(tǒng)按時上線。但在有限的時間內(nèi)快速優(yōu)化業(yè)務(wù)場景的性能，實非華生醫(yī)生所長。于是，大偵探福爾摩斯·K便被召喚閃亮登場。
抽絲剝繭，探索服務(wù)器環(huán)境
魅影重重的故事已被華生醫(yī)生初步解開謎底，然而，如何讓“犯罪分子”——不正確的配置參數(shù)或低性能的SQL語句伏誅，依舊是一場酣暢淋漓的偵探冒險。
就這樣，福爾摩斯·K攜金倉數(shù)據(jù)庫KingbaseES性能優(yōu)化四劍客KWR、KSH、KDDM和KWR Diff踏上了性能調(diào)優(yōu)之旅。
在和現(xiàn)場的華生簡單對接后，福爾摩斯·K首先要排查一下服務(wù)器主機環(huán)境，并了解KES在該業(yè)務(wù)場景下的整體性能表現(xiàn)，確定性能優(yōu)化目標(biāo)。這通過KWR十分容易就能獲得。
Step.1 產(chǎn)生KWR報告分析主機環(huán)境
配置KWR開關(guān)并讓配置參數(shù)全局生效，迅速開啟壓測模擬約20分鐘，生成KWR快照及報告：
KES版本信息，主機CPU能力、內(nèi)存容量、OS基本信息，客戶端連接數(shù)跟華生描述的基本一致。
福爾摩斯·K通過KWR的主機統(tǒng)計報告，可排查主機環(huán)境的CPU、IO、內(nèi)存、網(wǎng)絡(luò)性能等性能指標(biāo)是否存在問題：
主機CPU報告顯示，用戶態(tài)CPU占用92.50%，空閑僅6.67%，屬于業(yè)務(wù)非常繁忙的情況。當(dāng)然，如果CPU繁忙全部由KES服務(wù)器所造成，那就沒有大的影響，并且說明X客戶之前應(yīng)該進行過一定程度的性能調(diào)優(yōu)。
這一點通過負載分析報告里面的DB Time和DB CPU值很容易來判斷：
每秒DB CPU為190.01，超過了主機的CPU核心數(shù)，對于300個并發(fā)客戶端連接的負載來說正常。也說明絕大部分CPU負載都在KES服務(wù)器上，跟主機上的其他進程無關(guān)。
繼續(xù)查看主機IO報告：
KWR報告顯示，sdb磁盤每秒有59 MB的寫操作，福爾摩斯·K熟練地在KSQL里輸入了幾條SQL查詢，確認了KES數(shù)據(jù)目錄正位于該磁盤上。再看其他磁盤均沒有明顯的IO操作。第一個線索隱隱約約出現(xiàn)了。但是這59 MB的磁盤IO到底來自哪里呢？
福爾摩斯·K暫時壓下心頭的疑云，留待后續(xù)進一步分析。
繼續(xù)查看主機內(nèi)存報告和主機網(wǎng)絡(luò)報告，報告顯示剩余內(nèi)存充足（449 GB），網(wǎng)絡(luò)也未發(fā)現(xiàn)異常指標(biāo)。
條分縷析，拆解數(shù)據(jù)庫實例
探索主機環(huán)境后，福爾摩斯·K暫時擱置了對磁盤IO問題的疑問，開始分析數(shù)據(jù)庫實例。數(shù)據(jù)庫實例重點關(guān)注負載分析報告、實例效率百分比報告、Top 10前臺等待事件報告、時間模型統(tǒng)計報告等，并需要同時關(guān)注IO方面部分指標(biāo)。
Step.2分析前臺等待事件
根據(jù)以往的經(jīng)驗，數(shù)據(jù)庫產(chǎn)生性能問題時，往往會伴隨著某幾個等待事件較高的現(xiàn)象。因此，福爾摩斯·K在分析完操作系統(tǒng)環(huán)境后，優(yōu)先查看了前臺等待事件分類報告：
前臺等待幾乎都是IO等待，占數(shù)據(jù)庫時間8.36 %，它們主要包括哪些等待事件，通過Top 10前臺等待事件報告很容易查到：
報告顯示這8.36%的IO等待事件，主要來自BufFileWrite（5.84%）和BufFileRead（2.52%），其他等待事件可以忽略。
福爾摩斯·K現(xiàn)在得到了第二條線索：2個跟IO相關(guān)的等待事件。
但是這2個等待事件的存在是否合理呢？目前還不能斷然下結(jié)論，需要繼續(xù)分析時間模型和數(shù)據(jù)庫實例IO組成。
Step.3分析KES時間模型
KES時間模型是性能分析不可或缺的關(guān)鍵指標(biāo)，通過對數(shù)據(jù)庫時間模型的拆解，能夠知道數(shù)據(jù)的時間花費到哪里去了，也容易定位像軟解析、硬解析等問題。
KES的數(shù)據(jù)庫時間模型公式：DB Time = DB CPU + Foreground Wait Time，即：
數(shù)據(jù)庫時間 = 數(shù)據(jù)庫CPU時間 + 前臺（客戶端會話）等待時間，
前臺等待時間 = 前臺IO時間 + 前臺網(wǎng)絡(luò)讀寫時間 + 鎖等待時間 + ...
時間模型統(tǒng)計報告顯示花費時間最多的是DB CPU，為91.64%，其次是前臺等待時間，為8.36 %，沒有發(fā)現(xiàn)SQL解析、執(zhí)行計劃緩存、網(wǎng)絡(luò)讀寫等問題，因此，福爾摩斯·K只能按照常規(guī)從負載報告開始分析，從數(shù)據(jù)庫實例全局了解一下可能的瓶頸點。
Step.4分析KES負載
負載分析報告里提供了大量經(jīng)過提煉的指標(biāo)，包括數(shù)據(jù)庫時間、前臺等待事件、實例IO、解析計劃執(zhí)行次數(shù)、事務(wù)、元組、死鎖、登錄登出等。其中每秒那列的統(tǒng)計值很直觀。
比如：每秒Transactions，等價于TPS，每秒Execute Calls，等價于QPS。
報告顯示，數(shù)據(jù)庫時間正常、前臺等待事件較高，每秒17.34。
WAL日志（WAL Size）讀寫很低，難道是沒有開WAL日志嗎？福爾摩斯·K和華生帶著疑惑跟客戶確認了該業(yè)務(wù)場景的數(shù)據(jù)不生產(chǎn)WAL日志。
數(shù)據(jù)頁（Block Read/Write Size）的讀寫較高，每秒讀233.24 MB，每秒寫242.90 MB，似乎存在點問題。這令福爾摩斯·K想起主機磁盤IO每秒59 MB的寫操作，兩個指標(biāo)的異常讓他漸漸摸到了問題的脈絡(luò)。接下來需要分析一下該指標(biāo)的合理性。
Step.5多維度分析數(shù)據(jù)塊讀寫的合理性
查看SQL類型統(tǒng)計報告，能夠知道SQL負載特征：SELECT語句占了100%。沒有增刪改查SQL語句。
這不合情理！雖然查詢語句也可能會讀寫磁盤，但是每秒50M+的讀和寫，引起了福爾摩斯·K深深的懷疑。報告顯示讀和寫的數(shù)量相當(dāng)，難道是數(shù)據(jù)頁緩沖區(qū)不夠？
檢查實例效率百分比報告中的Buffer Hit（緩沖命中率）為100%。說明Shared buffer設(shè)置是足夠的，幾乎全部的數(shù)據(jù)頁都能在數(shù)據(jù)緩沖區(qū)讀到。
那么另一種可能就是臨時表的讀寫了。但業(yè)務(wù)系統(tǒng)開發(fā)人員卻反饋，該業(yè)務(wù)場景里幾乎沒有使用大的臨時表。福爾摩斯·K第一次陷入了苦思：這50 MB的IO讀寫到底來自數(shù)據(jù)庫哪里呢？
華生端來了2杯濃濃的咖啡，福爾摩斯喝了一口。突然間，靈光一閃，IO分析報告還沒有看，雖然它并非一棵IO分解樹，但是它也提供了共享塊、本地塊、臨時塊的IO統(tǒng)計等信息：
找到了！數(shù)據(jù)庫中存在233.24 MB/s的讀臨時塊，242.88 MB/s的寫臨時塊。與負載分析報告里的IO讀寫一致，但是高于主機IO里的59 MB/s讀寫，這也是合理的，說明操作系統(tǒng)緩存了一部分KES發(fā)出的寫盤請求。進一步分析，臨時塊不是臨時表的讀寫，而是SQL語句在排序、Hash連接的時候使用的臨時使用的磁盤空間。
檢查快照期間參數(shù)配置報告，果然，搜索到work_mem為10240 kB，這是KES的默認配置。對于普通的查詢是足夠的，但對于存在大量復(fù)雜Hash join或者排序的SQL就會有所不足。
現(xiàn)在再回顧一下Step2里的兩個前臺等待事件：
BufFileWrite：等待3751萬次，數(shù)據(jù)庫時間占比：5.85 %。
BufFileRead：等待3534萬次，數(shù)據(jù)庫時間占比：2.52 %。
這兩個等待事件一般意味著KES的work_mem不夠，導(dǎo)致寫臨時磁盤了，并發(fā)越高性能影響越大。
內(nèi)心的疑慮終于解開了！福爾摩斯·K也得到了第三條線索：客戶端會話配置的work_mem不夠。后面需要找到跟work_mem性能問題關(guān)聯(lián)的SQL。
撥云見日，快速定位問題
在云山霧罩的迷案中抽絲剝繭，以嚴密推理拆解分析；在千絲萬縷的疑難中撥云見日，以邏輯思維快速定位問題。
Step.6定位問題SQL
福爾摩斯·K主要從TOP SQL報告中查看問題SQL，確認其中是否有Hash和排序方面的操作。TOP SQL報告由一系列按照執(zhí)行時間、IO時間、返回元組數(shù)等排序的子報告組成，能按照多個維度檢查資源消耗高的SQL語句的執(zhí)行情況。
通過TOP SQL統(tǒng)計的按數(shù)據(jù)庫時間排序的SQL語句報告，即可找出消耗數(shù)據(jù)庫時間最多的SQL：
排在前兩位的SQL分別占了76.36 %和24.64 %的數(shù)據(jù)時間，平均執(zhí)行時間63.62秒和23.44秒，等待時間占比為8.67 %和7.52 %，應(yīng)該就是BufFileRead和BufFileWrite兩個等待事件。
為了驗證這一點，福爾摩斯·K基于剛才的KWR快照生成了一份KDDM報告。不僅看到了等待事件，還看到了跟他們關(guān)聯(lián)的SQL語句，確實是那兩個執(zhí)行時間長的SQL：
經(jīng)過與X客戶的研發(fā)人員溝通，這兩條復(fù)雜SQL語句（主要是第一條SQL，第二條SQL為非關(guān)鍵SQL可以不關(guān)注）之前僅需要不到30秒左右就能執(zhí)行完成，最近感覺越來越慢，有時候執(zhí)行會超過2到3分鐘。看來它就是問題SQL了，優(yōu)化它是重中之重。
福爾摩斯·K從完整SQL列表報告里，很快找到了對應(yīng)的SQL，生成的執(zhí)行計劃十分復(fù)雜，果然發(fā)現(xiàn)了里面存在不少Hash Join以及外部排序（external merge Disk），平均使用磁盤空間在32 MB左右，遠遠大于當(dāng)前設(shè)置的10 MB。
此時，性能瓶頸已經(jīng)非常明確，即客戶端會話進程的work_mem太小，導(dǎo)致了大量的磁盤排序操作。
Step.7應(yīng)用work_mem優(yōu)化
將當(dāng)前會話進程的work_mem設(shè)置為32 MB后，再觀察問題SQL語句的執(zhí)行計劃，外部磁盤排序已經(jīng)看不到了。然而，work_mem的修改會對每一個客戶端會話進程都生效，不能設(shè)置過大，否則容易引起主機內(nèi)存不夠。這個問題卻難不倒福爾摩斯·K，他伸了一個懶腰，大腦里飛快的計算著：300個會話，每個會話32 MB，一共需要9.375 GB內(nèi)存，以極限情況1200個會話計算，最多需要37.5 GB內(nèi)存。在可以接受范圍之內(nèi)。
福爾摩斯·K將數(shù)據(jù)庫實例的work_mem參數(shù)配置成32 MB，重啟服務(wù)器，跑性能負載，創(chuàng)建KWR快照并生成報告，KES實例IO中的臨時文件讀寫降低到0.5 MB/s降低到0.02 %，DB CPU提升到 99.97%，時間模型等其他性能指標(biāo)也無明顯瓶頸。雖然沒有完全消滅磁盤排序操作，但是現(xiàn)在的影響幾乎可以不關(guān)注了。
兩個執(zhí)行時間最長的SQL語句的平均執(zhí)行時間降到43.94秒和7.71秒：
站在一旁的華生對福爾摩斯·K佩服不已，心里想：待項目結(jié)束后，一定好好請教福爾摩斯·K，學(xué)個一招半招，再把KWR工具好好實踐一下！
措置裕如，輕松調(diào)優(yōu)SQL
福爾摩斯·K通過分析問題SQL的執(zhí)行計劃時發(fā)現(xiàn)了一個連接順序的問題，還有一個優(yōu)化器估算返回行數(shù)不準的問題，通過Hint輕松搞定，畢竟SQL優(yōu)化是他最擅長的。
慢SQL的平均執(zhí)行時間進一步優(yōu)化到35.27秒。
Step.8使用索引建議
剩下的優(yōu)化空間在哪里呢？福爾摩斯·K又一次陷入了思考，剛才看KDDM報告并沒有給出其他重要的建議，甚至連索引建議也沒有，要是通過手工一個一個地分析表和索引估計一天分析不完......等等，剛才好像沒有開索引建議開關(guān)！
打開索引建議開關(guān)后，重新壓測，生成KDDM報告。果然，索引建議赫然在目：
按照KDDM的索引建議提示，和X客戶的開發(fā)人員做了一個簡單溝通，該索引原來是存在的，后來他們批量更新數(shù)據(jù)的時候，臨時把索引刪除后忘記加回來了。給目標(biāo)表創(chuàng)建索引后，性能進一步提升到7.23秒。經(jīng)過幾次驗證，客戶應(yīng)用場景平均響應(yīng)降低到8.51秒，優(yōu)化任務(wù)完成。
探本溯源，再會調(diào)優(yōu)"四劍客"
在和客戶確認系統(tǒng)性能指標(biāo)達到預(yù)期，交付任務(wù)之后，華生拿來了小本本，熱情地請教起福爾摩斯·K來：
華生：我之前也聽說過KES的KWR、KSH、KDDM和KWR Diff調(diào)優(yōu)組件，但平時用得少只會用KSH來看等待事件和它們關(guān)聯(lián)的SQL語句，沒想到KWR居然提供了那么多的性能指標(biāo)和模型，而且使用它們調(diào)優(yōu)確實和簡單和直接。尤其是KDDM，能夠直接定位問題并給出建議，太酷了！
福爾摩斯·K：是的，華生。有了高度集成化的KWR、KSH、KDDM、KWR Diff之后，在開始SQL優(yōu)化之前幾乎都可以用他們來先做數(shù)據(jù)庫實例調(diào)優(yōu)。這會節(jié)省DBA大量查詢各種統(tǒng)計表和數(shù)據(jù)庫日志的時間，你看我這次調(diào)優(yōu)，基本沒有查詢它們。
華生：是的，那這些調(diào)優(yōu)組件之間有啥區(qū)別和聯(lián)系呢？
福爾摩斯·K：我這有一個總結(jié)表，你可以參考。
這次調(diào)優(yōu)沒有使用到KSH，是因為不適合這次X客戶的這種長周期性能問題場景。還有就是KWR Diff報告也很有用，調(diào)優(yōu)前后產(chǎn)生一份KWR Diff報告，觀察前后性能指標(biāo)的差異，這對提升調(diào)優(yōu)水平有很大幫助。
華生：總結(jié)得太好了！我要向我們組的小伙伴推廣調(diào)優(yōu)“四劍客”。
