4 月 24 日，早上七點，老 K 為迎接某國有大型銀行批次投產(chǎn)后開門營業(yè)作現(xiàn)場支持該行運維團隊的工作；根據(jù)以往的經(jīng)驗，該行每次批次投產(chǎn)會有數(shù)十套系統(tǒng)的軟件 / 環(huán)境版本變化、系統(tǒng)遷移等操作，在投產(chǎn)后的第一個工作日開門營業(yè)后，多少會有一些問題；而 ORACLE 數(shù)據(jù)庫作為各業(yè)務(wù)系統(tǒng)中的重要一環(huán)，往往是領(lǐng)導們關(guān)注的重點。

在定南等地區(qū)，都構(gòu)建了全面的區(qū)域性戰(zhàn)略布局，加強發(fā)展的系統(tǒng)性、市場前瞻性、產(chǎn)品創(chuàng)新能力，以專注、極致的服務(wù)理念，為客戶提供成都網(wǎng)站制作、網(wǎng)站設(shè)計 網(wǎng)站設(shè)計制作按需網(wǎng)站設(shè)計,公司網(wǎng)站建設(shè),企業(yè)網(wǎng)站建設(shè),品牌網(wǎng)站制作,營銷型網(wǎng)站建設(shè),成都外貿(mào)網(wǎng)站建設(shè),定南網(wǎng)站建設(shè)費用合理。

時間大約在 8 點左右，應(yīng)用維護團隊報出問題來：某套系統(tǒng)的某關(guān)鍵業(yè)務(wù)在開門前，需要先上送報表到某國家監(jiān)管機構(gòu)，報表主要就是通過在數(shù)據(jù)庫中執(zhí)行 SQL 語句生成的；以往這個報表的生成時間只需要 2 分鐘，而今跑了二十分鐘也沒有動靜，重提了好幾次也沒有效果，而前端柜臺業(yè)務(wù)開門時間是在 8 點半，必須要馬上解決，避免影響到業(yè)務(wù)開門時間；

通過現(xiàn)場快速查看，系統(tǒng)整體無異常，只是業(yè)務(wù)報表的 SQL 執(zhí)行時間偏長，主要運行在 CPU 上，看起來可能是邏輯讀過大了，在分析間，老 K 也了解到該系統(tǒng)在這次批次投產(chǎn)過程中的變化；

雖然這個報表 SQL 以前也運行過，奈何這是新的環(huán)境，原環(huán)境也已經(jīng)不在，沒法對比，看起來需要從頭開始分析了；

老 K 首先通過 dbms_workload_repository.create_snapshot 做了一個 snapshot ，然后抓一下 awrsqrpt 對語句進行分析；

語句邏輯讀確實非常大：

可以看到：

語句執(zhí)行了將近 1300 秒，仍未執(zhí)行完成；

邏輯讀達到 4.5 億；

通常來說，對于 SQL 性能問題，只需要理解 SQL 業(yè)務(wù)邏輯，分析一下 SQL 執(zhí)行計劃，然后充分了解相關(guān)各表的數(shù)據(jù)分布，就可以給出相應(yīng)的解決方案；只不過，這一次留給老 K 時間似乎有些短，壓力山大。

不過沒有關(guān)系，按套路來，先看看語句內(nèi)容和執(zhí)行計劃，然而，事情是這個樣子的：

這樣，老 K 就有幾分方了，光是執(zhí)行計劃就達到了 568 行；再去看 SQL 語句內(nèi)容，語句密密麻麻，操作終端上的 SQL 工具根本無法格式化 SQL 內(nèi)容，基本也不具備可讀性；簡單看一眼執(zhí)行計劃，稍微能總結(jié)一些執(zhí)行計劃的特點：

如果是你，你將如何進一步分析呢？

說話間，從開始查問題，到與應(yīng)用溝通，大致看語句，了解執(zhí)行計劃，十分鐘已經(jīng)過去了，時間已經(jīng)來到了 8 點 10 分，留給老 K 的時間已經(jīng)不多了；除了執(zhí)行計劃，其他思考結(jié)果如下：

那么，這里，看起來我們目前能做的應(yīng)該就是統(tǒng)計信息了，在短時間內(nèi)沒有辦法分析 SQL 和 SQL 執(zhí)行計劃的情況下，收集統(tǒng)計信息應(yīng)該是值得一試的方案；但是新問題來了，涉及上百張表，大的有幾十個 G ，如果逐個收集統(tǒng)計信息，再先后重提應(yīng)用報表 SQL ，估計又得損失幾百萬了 ~~ 所以， 到這里，我們需要做的事情是，找到那個最有可能有問題的表，收集統(tǒng)計信息，然后試著再重提批量，這里，時間緊迫，要求必須一擊即中。 老 K 需要閉上眼睛靜靜的思考一分鐘，確實，在一分鐘以后，老 K 想到了一個可以一試的思路，并且取得很好的效果！

OK ，思考歸來，老 K 的思路是，語句的邏輯讀非常大，而以前執(zhí)行較快，正常來說邏輯讀不會太大，如果這里真的是某個表的統(tǒng)計信息不準的話， 應(yīng)該該表或者與該表關(guān)聯(lián)的表的邏輯讀會比較大 （這一句很重要），而該段時間內(nèi)主要就是這條 SQL 在執(zhí)行，那么我們?yōu)槭裁床豢纯催@段時間的 AWR 報告，看看是哪個表或者哪些表的邏輯讀比較大呢？

可以看到， XXDEALS 表占比整庫邏輯讀的 92.35% ；

XXDEALS_IDX7 的邏輯讀也達到了 1600 萬；

所屬用戶也正是運行報表 SQL 的用戶；

進一步檢查可以知道，執(zhí)行計劃中的該表是存在的， 查看表的信息，大小大約 700M 左右，不算大，而且表的上次統(tǒng)計信息收集時間已經(jīng)是 4 月 7 日，看上去距離當前時間也較久了 ；說干就干，開 8 個并行收集該表的統(tǒng)計信息；一分鐘時間就收集完成，再重提批量任務(wù)，執(zhí)行計劃已經(jīng)發(fā)生變化，執(zhí)行完整個批量需要的時間大約就在 5 分鐘左右 ;

最終，報表順利上報，業(yè)務(wù)也基本準時開門，皆大歡喜。

我們看到，在這里的問題處理過程中，老 K 取巧了一下，在 SQL 語句和執(zhí)行計劃都非常長，無法在短時間內(nèi)直接定位執(zhí)行計劃中所存在的問題的情況下，基于 SQL 執(zhí)行時邏輯讀非常高的特點，借助 AWR 報告中邏輯讀 top 分布的情況，大致定位到可能存在導致執(zhí)行計劃不正確的表，并收集統(tǒng)計信息，最終解決了問題； ORACLE 提供了很多工具和方法來定位不同的問題，關(guān)鍵看我們能不能利用這些已有信息，發(fā)現(xiàn)信息中的特征來找到解決方法；

問題是解決了，但是因為差點影響到業(yè)務(wù)開門，上面的領(lǐng)導還是比較關(guān)切，需要一個解釋，或者說需要一個團隊來承擔這個責任，這中間幾個關(guān)鍵點：

然而時間已經(jīng)過了 8 點半，業(yè)務(wù)也均已開門，各新投系統(tǒng)和升級的系統(tǒng)也陸陸續(xù)續(xù)出現(xiàn)了一些小問題，需要在數(shù)據(jù)庫方面進行排查；要給出這個解釋暫時只能是口頭上的，也許沒有足夠的時間進行驗證。

通常來說，通過統(tǒng)計信息收集解決的問題，那無非就是統(tǒng)計信息過舊導致的；

但是這里有一個問題無法用統(tǒng)計信息過舊來解釋：為什么以往一直沒有問題，這次遷移到新的環(huán)境了，上來就有問題？是不是導入過程中有什么不該做的操作呢？

這里就需要仔細看看表的統(tǒng)計信息的收集時間了 :

可以看到，除最新收集的統(tǒng)計信息外， XXDEALS 表曾經(jīng)收集過兩次，一次收集時間是 4 月 7 日，一次收集時間是 4 月 22 日（也就是數(shù)據(jù)導入當天），然而在我們最近一次收集之前表的最新統(tǒng)計信息收集時間是 4 月 7 日，那么意味著表的統(tǒng)計信息分析時間軸是這樣的：

  4 月 22 日   ---->  4 月 7 日   ----->  4 月 24 日

是不是很奇怪，老 K 頓感疑惑，不過通過數(shù)據(jù)導入日志確認了 4 月 22 日 18:04 這個時間點其實正是在 dump 的導入過程中之后，老 K 的疑惑也就解開了。

在確認完這個統(tǒng)計信息分析的時間軸后，老 K 就有理由做出下述完美的猜想了：

我們通過腳本查看 SQL 涉及的表的統(tǒng)計信息的最新時間，發(fā)現(xiàn)確實有部分表的統(tǒng)計信息分析時間是在導入完成之后，部分表的分析時間是在導入完成之前；這樣看來，上述假設(shè)是極有可能的，基于上述可能，我們再次重申了我們對 ORACLE 數(shù)據(jù)庫數(shù)據(jù)導入后對應(yīng)用維護團隊的操作要求也是我們的結(jié)論：

在導入完成后，需要重新收集表的統(tǒng)計信息（可以按表或者按用戶收集），其中， method_opt 參數(shù)建議指定為 repeat ；

在與領(lǐng)導匯報完后，這口老鍋算是甩的非常完美了 ^_^ ，老 K 繼續(xù)匆匆投入到其他問題的處理當中，驗證的事情可能需要留待后續(xù)來實現(xiàn)了。

到目前為止，我們分析到的問題可以捋一下：

時間空下來，想到如此完美的猜想，老 K 立即開始驗證起來；現(xiàn)在，我們有了針對 SQL 前后的兩個執(zhí)行計劃，可以通過對比結(jié)果來分析原因了；語句依然還是太長，基本沒法直接讀，但是確認了一點， 語句確實是由 unionall 組合了大量的較簡單的多表連接來完成的 。

我們收集了表 XXDEALS 的統(tǒng)計信息，那么我們主要關(guān)注執(zhí)行計劃中 XXDEALS 相關(guān)的部分的變化即可，然而， 568 行的執(zhí)行計劃，與 XXDEALS 相關(guān)的部分也有幾十處，我們又如何能快速定位出導致邏輯讀劇增的那部分呢？

較差執(zhí)行計劃:

較好的執(zhí)行計劃：

從執(zhí)行計劃分析，符合我們上述的小技巧，如果使用 hash join ，原則上兩表只需要執(zhí)行一次掃描，而如果是 NL ，則可能會因為驅(qū)動表估算的行數(shù)不準而導致被驅(qū)動表的邏輯讀大增；

從變態(tài)的 SQL 語句中搜索出對應(yīng)這段執(zhí)行計劃的 SQL 大致如下：

并通過使用加 hint 的方式執(zhí)行該語句讓其跑出兩個執(zhí)行計劃對比起邏輯讀和執(zhí)行計劃，可以驗證這段 SQL 確實是導致整個 SQL 執(zhí)行效率大大下降的原因； 就這樣，我們通過執(zhí)行計劃的分析，將紛繁的 SQL 分析化解為簡短的兩表關(guān)聯(lián)的分析；

根據(jù)上述分析，這里我們又可以進一步簡化；兩個執(zhí)行計劃中，驅(qū)動表的位置和評估行數(shù)都沒有變化，那么我們唯一需要關(guān)注的是在較差的執(zhí)行計劃中，為什么會使用 NL 呢？

即，我們需要關(guān)注的就只剩下表 XXDEALS 在相關(guān) maturitydate 條件和 flagofdeal 條件下，為什么一個會走索引，而另一個卻沒有走索引，與統(tǒng)計信息的關(guān)系又如何?

要精確定位問題，在這里可能需要重現(xiàn)問題。這里其實要重現(xiàn)問題比較簡單，老 K 通過 dbms_stats.restore_table_stats 恢復表的統(tǒng)計信息，并將新舊表的定義（包含了統(tǒng)計信息又不用導數(shù)據(jù)）各導出一份，導入到 11.2.0.4 的測試環(huán)境中去，分別命名為 DEALS_0407 和 DEALS_0424 ，兩表分別使用的是 4 月 7 日的統(tǒng)計信息和 4 月 24 日的統(tǒng)計信息，也可以基本反映兩個日期中表的數(shù)據(jù)分布情況。

通過簡單測試，我們又把 maturitydate 字段的影響給排除掉了，現(xiàn)在唯一的區(qū)別就在與使用 flagofdeal=‘O’ 時，兩表評估的行數(shù)不一致；

那么這里 317 和 455K 都是怎么算出來的呢？我們試著看看 10053 能不能給我們一些幫助 ;

DEALS_0407 的 10053 關(guān)鍵評估信息：

DEALS_0424 的 10053 關(guān)鍵評估信息：

我們可以看到，兩表總行數(shù)上（ Original ）的區(qū)別不大， flagofdeal 列的密度（ Density ）有一些區(qū)別，最主要的是區(qū)別是兩表 flagofdeal 列 Frequency 直方圖的桶數(shù)量（ Bkts ）居然不同， DEALS_0407 只有 5 個桶，而 DEALS_0424 卻有 6 個桶；

老 K 簡單一算，對于 DEALS_0407 最終估算的 317 不正是等于 1017318 （ Original ） *0.000311 （ Newdensity ）嗎？這樣看來，顯然 ’O’ 值并不在直方圖的 popular value 中了；

而 DEALS_0424 中，最終估算的 455K 條記錄則像是其 popular value 中估算出來的了；如果真的是這樣的話，那么基本是可以確認是因為數(shù)據(jù)變化，即 DEALS_0407 表中沒有 ’O’ 值記錄，而在 DEALS_0424 中則大量插入 / 修改了 ’O’ 值記錄了。

然而，這一次，有了充分的時間，老 K 就不再輕易下結(jié)論了！

首先，我們來驗證 DEALS_0424 的估算值是否準確：

其中 get_external_value 數(shù)據(jù)來為自定義的轉(zhuǎn)換 endpoint_value 為實際字符串的函數(shù)，已經(jīng)發(fā)布在 “ 中亦安圖”公眾賬號中，有需要的朋友可以關(guān)注中亦安圖公眾號，回復 “ 直方圖函數(shù) ” 獲?。?/p>

我們看到， ‘O’ 值的 endpoint_number 為 14164 ；

那么其評估值即為： 1021005 （ Original ） * （（ 14164-7839 ） /14177 ） =455K

與 10053 trace 和執(zhí)行計劃中的都一致；

另一方面， DEALS_0407 直方圖桶的個數(shù)是 5 個，那么它又是些什么值呢，我們不妨也簡單看一下，確認一下是否確實是缺少了 ‘O’ 值：

然而，結(jié)果似乎不如我們所愿， DEALS_0407 雖然確實是 5 個桶，但是卻是包含了 ‘O’ 值的；使用同樣方法去估算 ’O’ 值的記錄數(shù)應(yīng)該差不多是 465K ：

看起來，確實在遷移升級期間沒有那么大的數(shù)據(jù)的變化；

那到這里，問題又是什么呢？

考慮到在之前環(huán)境中，原 SQL 的執(zhí)行是沒有問題的，那么是不是說在原環(huán)境中對 flagofdeal=‘O’ 的記錄數(shù)評估應(yīng)該是準確的呢？不如我們再來驗證一下：

沒錯，我們看到，如果我們再 SQL 中增加 OPTIMIZER_FEATURES_ENABLE('10.2.0.5') 的 hint 讓數(shù)據(jù)庫使用 10.2.0.5 的優(yōu)化器的話，是能正確的評估出該 ’O’ 值記錄的行數(shù)；

同樣，即使是 11.2.0.3 的優(yōu)化器，也同樣能正確的評估出 ’O’ 值記錄的行數(shù)：

如此，老 K 更是迷惘了，難道單單 11.2.0.4 有問題，那是為什么呢？

我們還是要回到評估行數(shù)的問題上來，為什么明明我們看到的直方圖的記錄中有 ‘O’ 值， 11.2.0.4 的優(yōu)化器卻認為直方圖信息中沒有 ‘O’ 值呢？難道是老 K 給出的 get_external_value 函數(shù)存在問題？這時，老 K 想起了在處理字符串的問題是經(jīng)常會給我們帶來視覺錯誤的一個問題，那就是空格，于是，我再次查詢直方圖信息：

沒錯，就是空格，其實在轉(zhuǎn)化成字符串后，發(fā)現(xiàn)，兩者還是有區(qū)別的，我們再仔細對比的話，其實兩表直方圖的 endpoint_value 確實是不一樣的；我們又通過對比同表的其他字段直方圖信息確認了，一般如果實際值一樣，在信息里的 endpoint_value 應(yīng)該是一樣的：

最后，通過多次確認測試，最終定位到只要列的類型為 char 類型，而且字段長度低于 8 ，那么會出現(xiàn)在 11.2.0.3 （及更低版本）與 11.2.0.4 的直方圖信息 endpoint_value 不一致；測試過程此處不表；

基本上能確認是 oracle 的一個變化，至少是 11.2.0.3 到 11.2.0.4 之間的一個變化；接下來的任務(wù)就是找到 ORACLE 官方的說明來，之前老 K 也查了幾次 MOS ，也許是因為定位的還不夠精準，導致在 MOS 查找的關(guān)鍵字不夠 “ 關(guān)鍵 ” ，每次都是搜出一大堆結(jié)果卻無法逐一細細閱讀而毫無收獲，這次老 K 上 MOS 使用關(guān)鍵詞 “char endpoint_value different” 進行搜索，很快就找到了文章 “ Bug 18550628 : AFTER UPGRADE TO 11.2.0.4QUERIES USING CHAR FIELDS CAN PERFORM POORLY ” ，看起來與我們發(fā)現(xiàn)的情況非常符合，然而打開文章卻并沒有什么實際內(nèi)容，看起來像是因為開 SR 而形成的 bug 文章；然而，仔細看該文章，可以注意到它實際指向了另一篇文章：

查找 18255105 ，找到的文章是“ Patch for upgrade scripts to identify histograms affected by fix ofbug 15898932 ” ;

描述如下：

各位觀眾，讀完獲得了什么呢？反正，老K是獲得了許多，累了就不多說了。

本文轉(zhuǎn)載于中亦安圖