[Oracle維護工程師手記]一次升級後運行變慢的分析

客戶報告，
當他從 Oracle 11.1.0.7 ，遷移到雲環境，而且升級到12.1.0.2。
運行客戶的應用程序測試，發現比之前更慢了。

從AWR report 的"Top 10 Foreground Events by Total Wait Time"和"Wait Classes by Total Wait Time"等信息，
能夠看到 CPU 值升高了。

初步思考，懷疑因爲環境的不一樣，致使性能不一樣。可是客戶說，這兩個環境的CPU數目/內存大小等各方面狀況都徹底同樣。
那麼就的考慮其餘的緣由了。

遷移前的環境和遷移後的環境對比，從AWR report 中，能夠看到，遷移後的 "Hard parse"  的比例明顯偏高。

***遷移前
Load Profile
Per Second Per Transaction Per Exec Per Call
DB Time(s): 1.1 0.0 0.00 0.00
DB CPU(s): 0.3 0.0 0.00 0.00
Parses: 158.3 4.8
Hard parses: 8.8 0.3 <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
Executes: 620.2 18.2

***遷移後
Load Profile
Per Second Per Transaction Per Exec Per Call
DB Time(s): 0.8 0.0 0.00 0.00
DB CPU(s): 0.6 0.0 0.00 0.00
Parses (SQL): 375.8 14.7
Hard parses (SQL): 75.2 3.0 <<<<<<<<<<<<<<<<<<<<<<<<< hard parse 大幅度增長
Executes (SQL): 702.7 28.3

客戶報告，在新環境裏，設置了 對 應用中的全部的 SQL文 都追加了 相似於
"SELECT /*+ OPTIMIZER_FEATURES_ENABLE('11.1.0.7') ORDERED INDEX(T0001 T0001_001) NO_USE_HASH(FBM10) */" 的hint以後，
發現性能基本回到了遷移前的水平。

從這一點來考慮，OPTIMIZER_FEATURES_ENABLE，多是影響到了 optimizer_adaptive_features 功能。這一功能會在SQL文執行
的時候，動態地判斷有沒有更好的執行計劃。而極可能對客戶程序的一部分SQL文，反而動態調整執行計劃產生了大量的Hard Parse，
總體上拖延了執行時間。

客戶也懷疑 是 文檔 2312911.1 所提到的 12.1 的 optimizer_adaptive_features 功能不夠完善致使出現問題。文檔 2312911.1
說起，12.1 的 optimizer_adaptive_features 功能不夠完善，能夠特殊處理，以達到12.2的效果(12.2中, optimizer_adaptive_
features 有所改善，被拆分紅爲了兩個參數)。

那麼，究竟是不是這樣呢，客戶但願進一步進行分析調查。

從拿到了遷移先後的AWR來對比，發現了有趣的情況：實際上從Top N SQL來看，遷移前的SQL文，遷移後執行時間其實都大幅度縮短了。

    ***遷移前環境
    ========================
    SQL ordered by Elapsed Time
       Resources reported for PL/SQL code includes the resources used by all SQL statements called by the code.
       % Total DB Time is the Elapsed Time of the SQL statement divided into the Total Database Time multiplied by 100
       Total DB Time (s): 2,597  
       Captured SQL account for 58.8% of Total  <<<<<<<<<<<<Top 10 的SQL文，佔據了總體執行時間的 59%(1532秒)
       Total DB Time (s): 2,597
       Captured PL/SQL account for 0.3% of Total
    ========================

    ***遷移後(未追加 OPTIMIZER_FEATURES_ENABLE hint 的時候)
    ========================
    SQL ordered by Elapsed Time  ★
       Resources reported for PL/SQL code includes the resources used by all SQL statements called by the code.
       % Total DB Time is the Elapsed Time of the SQL statement divided into the Total Database Time multiplied by 100
       %Total - Elapsed Time as a percentage of Total DB time
       %CPU - CPU Time as a percentage of Elapsed Time
       %IO - User I/O Time as a percentage of Elapsed Time
       Captured SQL account for 27.9% of Total DB Time (s): 1,771  <<<<<<<<<<<<Top 10 的SQL文，佔據了總體執行時間的 28%(500秒)
       Captured PL/SQL account for 1.3% of Total DB Time (s): 1,771
    ========================

從具體的top 10 SQL文執行時間上，也能夠看出來：

    ++++++++++++++++++++++++++++++++++++++++++++++
    2ac8g6tagg67x  遷移後>>17,122 回執行  CPU Time 13.27s、Elapsed Time 139.03s  
                           遷移前>>21,018 回執行  CPU Time 16s、Elapsed Time 839s

    5mt3dyz3r6af8  遷移後>>425 回執行  CPU Time 25.28s、Elapsed Time 33.10s
                          遷移前>>509回執行  CPU Time 44s、Elapsed Time 105s

    7tjhsnk6ruw6m  遷移後>>165 回執行  CPU Time 16.67s、Elapsed Time 21.69s
                           遷移前>>165 回執行  CPU Time 25s、Elapsed Time 50s

    ......

    baq2zs9gns3co  遷移後>>51,730 回執行  CPU Time 9.92s、Elapsed Time 16.57s
                           遷移前>>67,66 4回執行  CPU Time 10s、Elapsed Time 26s
    ++++++++++++++++++++++++++++++++++++++++++++++

那麼，問題到底處在哪裏呢？ 個人猜想是： 雖然TopN 那些SQL文的執行時間減少了。可是還有不少執行很短暫的SQL文，因爲動態執行
計劃調整，致使事件增長了。

這也很容易理解：

若是一條SQL語句的執行時間本來是200ms，若是動態執行計劃調整花5ms，使得因執行更好的執行計劃而較少了執行時間20ms,整體上來講
就是賺到了。

但是若是你一條小SQL執行語句，原本執行時間才20ms,若是動態執行計劃調整花5ms，使得因執行更好的執行計劃而較少了執行時間2ms,
反而執行時間增長了。

若是這條小SQL執行語句，反覆屢次執行呢？那問題就惡化了。

就比如：雖然說磨刀不誤砍柴功，可是若是每砍一個小樹杈，都要磨一次刀，那是否是有點浪費時間啊。

對於這個推測，客戶仍然想要了解更詳細的細節，那麼好吧，咱們來看看ASH的狀況：

遷移前

"In Hard Parse" ==> 15 行     "In Hard Parse" 的比例：37.5%
2018/03/12 15:26:36 --->  2018/03/12 15:37:25.693000000
SQL_ID: 30 個

遷移後

"In Hard Parse" ==> 252 行     "In Hard Parse" 的比例：76.6%
2018/03/20 11:33:50 --->  2018/03/20 12:25:58.591000000
SQL_ID: 292 個


遷移後的整體時間不但大幅度延長了，並且ASH中統計出來的sql_id 明顯增多。因此能夠推測不少本來執行時間很短的sql語句，由於執行計劃
調整的緣由，話費時間進行了 Hard Parse，因此當ASH採樣的時候，由於沒有執行完畢，更多的出如今ASH履歷中。

那麼，做爲結論， 12c的執行計劃調整並非適合全部sql文的，對效果不佳的語句，不妨添加 OPTIMIZER_FEATURES_ENABLE 進行微調。