2017年什么準(zhǔn)備開發(fā)D-SMART這個產(chǎn)品的時候，是受到“知識自動化”這個理念的啟發(fā)，想通過運維知識圖譜積累運維經(jīng)驗，再輔助以深度學(xué)習(xí)、人工智能的算法，實現(xiàn)復(fù)雜的數(shù)據(jù)庫運維問題的自動化。一晃這件事也做了四年了，雖然說摸到了一些門道，不過前面依然是漫漫長路，和剛上路不同的是，現(xiàn)在天已經(jīng)蒙蒙亮了，不像我們剛剛出發(fā)的時候，只能看到前面黑沉沉的長路。這條路已經(jīng)被證明是能走得通的，剩下來的是通過漫長的積累，逐步完善知識庫。

我們的知識庫是在不斷的實踐過程中慢慢的積累，隨著從案例中提取的知識的積累不斷地彌補整個知識網(wǎng)絡(luò)中的缺陷，讓知識更豐富，能發(fā)揮更大的作用。因此每個案例對我們來實都是十分珍貴的，必須從中挖掘出最大的價值才行。

可能有朋友要說了，這有什么難的，把以往的案例抽象出來，形成知識，下次再遇到類似的問題就可以處理了，框架已經(jīng)打好了，剩下的只要積累不就行了。這實際上也是我最初的想法，不過做到今天，隨著我們不斷的拿到客戶現(xiàn)場的實際案例，我們發(fā)現(xiàn)實際上故障自動化分析并不是那么簡單的事情。

昨天有個客戶說他們的系統(tǒng)中有個業(yè)務(wù)比較慢，通過TOP EVENT發(fā)現(xiàn)存在大量的latch: row cache objects等待，有個業(yè)務(wù)相關(guān)的SQL執(zhí)行的十分緩慢，要數(shù)秒鐘才能完成?？蛻裟沁吿幹眠@些問題的經(jīng)驗也十分豐富，很快就找到了等待這些閂鎖的語句都是一條類似的語句，因為這條語句并沒有試用綁定變量，所以每次都是硬解析。這個問題大概率是和解析有關(guān)。從D-SMART的問題分析報告中也能夠找到出問題的這條SQL的情況。

在這個分析里，我們的工具做的還不夠細(xì)致，只是列出了問題，并沒有做進(jìn)一步的根因分析，這個案例也讓我們發(fā)現(xiàn)了工具的不足。不過從這些列出的情況也可以看出解析一定是出了什么問題。因為當(dāng)時這個問題已經(jīng)影響了一些交易，因此需要馬上先解決問題。客戶那邊分析后立即采取了一個措施，將cursor_sharing設(shè)置為similar，修改參數(shù)后，問題立即消失了，系統(tǒng)也恢復(fù)了正常。

事后我讓客戶把問題分析報告和當(dāng)時的AWR報告發(fā)給了我，上班后，我們也會把這個案例的監(jiān)控數(shù)據(jù)帶回來仔細(xì)分析分析。這種特殊的案例對于完善知識圖譜是十分關(guān)鍵的。這些年我們已經(jīng)很少發(fā)現(xiàn)因為硬解析而引發(fā)的性能問題了。一般來說，以目前的PC服務(wù)器的硬件來說，因為CPU的核數(shù)較多，硬解析帶來的問題已經(jīng)越來越少了，因為一次解析的時間也就是幾個毫秒到幾十毫秒，強(qiáng)大的硬件資源足以支撐十分高并發(fā)的解析。不過問題并不是那么簡單的，昨天的這個案例就是一個十分珍貴的特例的案例，具有十分高的價值。

從load profile上看，系統(tǒng)負(fù)載還不算高，每秒600多的事務(wù)，12871的執(zhí)行，數(shù)量只能算是中等。不過每秒6211次的解析說明無解析執(zhí)行的比例很低，硬解析691，占11%多一點，解析數(shù)量很高，但是應(yīng)該還不至于出現(xiàn)如此大的問題的。

命中率指標(biāo)有個十分大的疑點，那就是非解析CPU比例僅為17.2%，反過來看，就是解析占用的CPU資源高達(dá)83%左右，這是在以往的系統(tǒng)中很少會看到的現(xiàn)象。這是一臺4路14核28線程的服務(wù)器，整個服務(wù)器有56個核，112線程，從D-SMART的報告中可以看出，CPU的使用率大概是在30%左右。

從操作系統(tǒng)層面上看，各種資源還是比較充足的，CPU的R隊列最大值也沒有超過CPU的線程數(shù)。按理說當(dāng)前的硬件資源是足以支撐當(dāng)時的并發(fā)解析的量的。實際上當(dāng)時客戶電話里和我溝通這個問題的時候，我也猜測了latch:row cache objects等待比較嚴(yán)重可能存在的幾種問題，系統(tǒng)有HANG住的現(xiàn)象，SGA RESIZE，存在DDL操作，SGA設(shè)置太小等等。不過這些問題當(dāng)時都查看過，而且也被一一排除了。

去年12月1日的歷史數(shù)據(jù)

我們實驗室正好有這套系統(tǒng)去年的歷史數(shù)據(jù)，從歷史數(shù)據(jù)上看，硬解析數(shù)量一直很高，甚至有時候高達(dá)12000+/秒，不過用戶那邊以前并沒有發(fā)現(xiàn)其中存在什么問題。

從TOP EVENT上看，latch:row cache objects的平均等待時間為36毫秒。似乎這個等待時間也不高，不過如果算上一個事務(wù)平均要等待10多次這個等待事件，對系統(tǒng)的影響就很大了。

平時這個等待時間的延時為0.13毫秒，偶爾會出現(xiàn)15多毫秒的點，不過一小時平均值36毫秒的情況還沒有出現(xiàn)過。一下子暴增200多倍，導(dǎo)致系統(tǒng)異常也就很正常了。不過latch:row cache objects的延時為什么會達(dá)到這么高?執(zhí)行數(shù)量過大，解析數(shù)量過大，硬解析過大嗎?

執(zhí)行數(shù)量上看，這個系統(tǒng)每秒的執(zhí)行數(shù)量平均值在3000-4000之間，出問題時段一小時平均值為1.2萬多，是平時的3倍左右。不過平時的高峰期經(jīng)常會有超過2.5萬/秒的執(zhí)行高峰，只是沒有持續(xù)很長時間而已。

硬解析也是如此，平時的平均值大約略低于300，高峰期也會出現(xiàn)高達(dá)1.2萬+的高值，也低于出問題時段的一小時平均值690+。

從這個案例最終通過修改cursor_sharing參數(shù)就解決了問題的現(xiàn)象上看，確實是這條沒有試用綁定變量的SQL導(dǎo)致了問題，不過這個問題為什么會發(fā)生，其原因是十分復(fù)雜的。上面我們分析的持續(xù)的高峰是導(dǎo)致問題的一個十分重要的原因之一，不過這還不是所有的原因。

仔細(xì)分析和CURSOR解析相關(guān)的指標(biāo)，我們發(fā)現(xiàn)每秒的session cache命中數(shù)量只有1700左右，和6000多的解析相比，命中率也很低，換算下來大概只有28%左右。而除了這條出問題的SQL以外的其他解析較高的SQL語句的解析數(shù)量占比大約是33%，根據(jù)這個情況我們檢查了一下session_cached_cursors參數(shù)，發(fā)現(xiàn)這個參數(shù)使用了缺省的50。不過在這個案例里，加大這個參數(shù)能夠發(fā)揮的作用可能還是有限的，不過在某些其他的案例里，類似情況可能會因為這個參數(shù)的設(shè)置不合理而加重SQL 解析的負(fù)擔(dān)。

實際上這個看似并不復(fù)雜的案例里包含了很多復(fù)雜的內(nèi)容，只有十分深入的去分析它，才能發(fā)現(xiàn)更深層次的問題。雖然說當(dāng)時現(xiàn)場很快通過cursor_sharing解決了這個問題，但是如果沒有把其中的問題分析清楚，今后遇到類似的問題，我們就無法提前預(yù)警，此類問題稍微發(fā)生一些變化，我們就無法正確的去處置。因為此類問題的表象上十分類似，而實際上深層次的內(nèi)容上存在極大的不同。

這也是故障自動化分析比較難做的主要原因，同樣是硬解析，為什么有的系統(tǒng)每秒數(shù)千次都不會出問題，而這個系統(tǒng)才700就出問題了呢?這和這臺服務(wù)器的配置、CPU使用率、SQL涉及的表的數(shù)量，是不是存在分區(qū)數(shù)量極多的分區(qū)表等等，以及和昨天這個案例類似的是否存在持續(xù)時間很長的，針對同一張表的高并發(fā)解析，這些因素都有關(guān)系。如果在分析的時候要考慮到這些因素，那么我們需要更為準(zhǔn)確的采集到相關(guān)的數(shù)據(jù)，并進(jìn)行指標(biāo)化處理，并通過指標(biāo)來反映出這些問題的因素，在分析算法中也需要覆蓋這些指標(biāo)。

這種自動化分析能力只能在一次次的不盡如人意的分析中不斷地迭代優(yōu)化，才能獲得更為準(zhǔn)確的自動化分析工具。就像今天我們討論的這個案例，雖然說好像現(xiàn)在看，問題已經(jīng)分析的差不多了，而且當(dāng)時發(fā)現(xiàn)問題和解決問題也很及時。不過我感覺我們還是沒有抓住問題的最根本的那個點，因此我們還需要通過在用戶現(xiàn)場更廣泛的采集數(shù)據(jù)，從而找到更深層次的問題原因。只有不斷地從這樣的案例中去不斷地挖掘知識，我們的知識圖譜才能變得更有價值。

本文轉(zhuǎn)載自微信公眾號「白鱔的洞穴」，可以通過以下二維碼關(guān)注。轉(zhuǎn)載本文請聯(lián)系白鱔的洞穴公眾號。