大家好，我是JiekeXu,江湖人稱“強哥”，青學會MOP技術社區主席，榮獲Oracle ACE Pro稱號，金倉社區最具價值倡導者KVA，崖山最具價值專家YVP，IvorySQL開源社區專家顧問委員會成員，KWDB社區MVP，墨天輪MVP，墨天輪年度“墨力之星”，擁有Oracle OCP/OCM認證,MySQL 5.7/8.0 OCP認證以及金倉KCA、KCP、KCM、KCSM證書，PCA、PCTA、OBCA、OGCA等眾多國產數據庫認證證書,歡迎關注我的微信公眾號“JiekeXu DBA之路”，然后點擊右上方三個點“設為星標”置頂，更多干貨文章才能第一時間推送，謝謝！
前 言
有這樣一個有趣的問題，昨天早上有一位開發同事找過來說在生產環境上通過PLSQL客戶端查詢相同的 SQL 在主庫執行較快，大約 5s 左右，在備庫執行卻需要 60s 多，此 SQL 所在的應用連接的是只讀備庫，導致接口超時，出現故障。
然后我去執行 SQL 發現確實現象一樣，主庫快備庫慢，但當我登錄到服務器去執行 SQL 時僅需要 8s 左右，相差不大也不是特別慢，在接受范圍內；于是又登陸到節點2 執行發現特別慢，需要 60s 多才查出來了三條數據。真是奇怪了，RAC 兩節點查看數據居然執行時間快慢大不一樣，這是一個有趣的事情，直接一探究竟。
問題排查
首先交代一下為何會出現這樣的問題，大概是因為上周六這套環境剛做了主備切換，原來的備庫是運行在 RHEL9.6 的 RU19.23 RAC 上，主庫是運行在 RHEL7.8 的 RU19.15 RAC 上，切換后為了還可以回退暫時沒有更新 RU23 補丁，備庫版本還是 19.15，主備庫版本不一致。
查看數據庫參數文件使用的是 spfile 存在于 ASM 上，說明參數文件僅一份，創建 pfile 查看參數文件內容，實例 2 也沒有單獨的參數設置，和實例 1 是一樣的參數設置。操作系統CPU內存資源、內核參數都是最開始配置的這塊都是一樣的，可以說資源、配置都一樣了。
然后通過 PLSQL F5 或者 set autot on 查看執行計劃，除了備庫實例 2 慢之外，執行計劃都一樣。
那么我們通過 10046 跟蹤一下備庫實例 2 會話看看有啥不一樣呢。
使用 10046 跟蹤
oradebug setmypid
oradebug unlimit;
oradebug event 10046 trace name context forever,level 12;
--執行查詢SQL
oradebug tracefile_name
--格式化輸出
tkprof JTDB1_ora_58856.trc -output = RAC1.txt
tkprof JTDB2_ora_55007.trc -output = RAC2.txt
ALTER SESSION SET EVENTS '10046 trace name context forever, level 12';
ALTER SESSION SET EVENTS '10046 trace name context off';
TKPROF（Trace Kernel Profiler）是 Oracle 自帶的命令行工具，用于將原始的 SQL 跟蹤文件（*.trc）轉換為易讀的格式化報告，解析 SQL 執行的耗時、執行計劃、等待事件等關鍵信息，是診斷慢 SQL、定位性能瓶頸的核心工具。
tkprof <原始跟蹤文件.trc> <輸出報告.txt> [可選參數] tkprof /u01/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_12345.trc \ /home/oracle/sql_report.txt \ sort=ela \ sys=NO \ explain=scott/tiger \ waits=YES
如下圖，通過查看 trace 發現執行 62.88 秒，“gc cr multi block mixed”等待事件最多，TIMES WAITED 等待總次數為 59118，Max wait 單次最大等待時長（以百分之一秒為單位）0.62，Total Waited 總耗時是 45.44 秒。
tkprof JTDB2_ora_55007.trc ins2.txt sys=no sort=prsela,exeela,fchela
格式化之后的結果，更易于閱讀，但同時也省去了一些細節信息，我是沒怎么看過，很多都不理解，不過現在 AI 盛行，也算有個小助手了，如果不格式化全部能看懂的人還是比較厲害的了。
如圖，看到“gc cr multi block mixed”等待事件最多且為一個不常見的等待事件，所以只能借助搜索引擎了，在 MOS 中搜索，AI 直接給出了一個參考答案：
本答案適用于：Oracle數據庫 - 企業版 - 版本11.2.0.4至21.9 [發行版11.2至21.0]
“gc cr multi block mixed”等待異常值的問題在文檔標題中有所描述：Bug 34482043 - 一些“gc cr multi block mixed”等待異常值導致 19c 出現性能回歸。
根據文檔，此bug僅在使用Real Application Clusters (RAC)時相關，并會導致CR多塊讀取性能下降。
34482043的修復首次包含在19.18.0.0.230117（2023年1月）DB發布更新（DB RU）中。
早期版本可能提供臨時補丁。有關此bug的問題，請咨詢Oracle支持。
查看文章 Bug 34482043, SQL 執行時的等待事件 gc cr multi block mixed，且執行時間過長，還是 RAC 架構，數據庫版本目前還是 19.15，那么剛好命中這個Bug，MOS 給出的答案是 19.9–19.18 RAC 架構下的 bug。知道問題原因了，那么就很好解決了，直接備庫補丁也升級到 19.23 就可以解決了。
This bug is only relevant when using Real Application Clusters (RAC)
CR Multi block read performance degradation.
REDISCOVERY INFORMATION:
FG traces show IPCLW discarding messages with older sequence number than the
expected.
Example:
IPCLW:[0.1]{-}[WAIT]:PROTO: [1659935330904717]ipclw_data_chunk_process:1219
Discarding msg with seq # 2030753391, expecting 2030753394
問題解決
因補丁升級需要有停機窗口，一時半會兒沒法停機，則暫時折中的辦法就是新建一個 service 優先連接節點1，到晚上后修改連接串重啟此應用為最優，后續有停機窗口，可停機打補丁。
新建 service
分別在主備庫使用 Oracle 用戶創建 service 優先連接節點1，當節點1無法連接時才會考慮連接節點2，這樣算臨時解決了此 SQL 性能查詢問題，后續尋找窗口打補丁。
srvctl add service -db jiekexudb -service r_mobile_sel -preferred "jiekexudb1" -available "jiekexudb2" -failback yes -tafpolicy basic srvctl start service -db jiekexudb -service r_mobile_sel srvctl config service -db jiekexudb -service r_mobile_sel
打補丁
差不多過了快一個月申請停機窗口打完了此備庫的補丁到 RU 19.23.240416，打補丁的過程需要停機，使用 root 自動打補丁時不能在家目錄或者根目錄執行，其他細節這里不在贅述了，然后在主庫執行了datapatch SQL腳本，主備數據正常同步后查看版本為主庫的版本。
set line 456
col ACTION_TIME for a30
col DESCRIPTION for a55
select patch_id, action,status,action_time,description from dba_registry_sqlpatch;
PATCH_ID ACTION STATUS ACTION_TIME DESCRIPTION
---------- --------------- ------------------------- ------------------------------ -------------------------------------------------------
33806152 APPLY SUCCESS 18-FEB-23 12.09.24.905617 PM Database Release Update : 19.15.0.0.220419 (33806152)
36199232 APPLY SUCCESS 29-NOV-25 04.37.51.555823 PM OJVM RELEASE UPDATE: 19.23.0.0.240416 (36199232)
36233263 APPLY SUCCESS 29-NOV-25 04.38.49.343052 PM Database Release Update : 19.23.0.0.240416 (36233263)
在打補丁的過程中嘗試通過刷緩存或者重啟節點 2 實例，都沒有解決此慢查詢問題，只有打完補丁跑完 SQL 后才恢復到和節點 1 一樣的時間。
alter system flush buffer_cache;
alter system flush shared_pool;
shu immediate
主庫執行都是 4 秒多，備庫第一次執行 35 秒多，后面幾次執行穩定在 7 秒左右。此問題算是告一段落了，具體的 SQL 暫時也就不用優化了。
| 主庫RAC1執行時間 | 主庫RAC2執行時間 |
|---|---|
| Elapsed: 00:00:04.45 | Elapsed: 00:00:04.44 |
| Elapsed: 00:00:04.38 | Elapsed: 00:00:04.29 |
| 備庫升級補丁RU19.23后的執行時間 | |
| 備庫 RAC1 執行時間 | 備庫 RAC2 執行時間 |
| Elapsed: 00:00:30.76 | Elapsed: 00:00:35.17 |
| Elapsed: 00:00:06.54 | Elapsed: 00:00:06.55 |
| Elapsed: 00:00:07.61 | Elapsed: 00:00:07.64 |
參考文章
Doc ID 34482043.8 --MOS改版前文檔 id KI35400 Bug 34482043 - Some "gc cr multi block mixed" wait outliers cause a performance regression in 19c
全文完，希望可以幫到正在閱讀的你，如果覺得有幫助，可以分享給你身邊的朋友，同事，你關心誰就分享給誰，一起學習共同進步~~~
歡迎關注我的公眾號【JiekeXu DBA之路】，一起學習新知識！
——————————————————————————
公眾號：JiekeXu DBA之路
墨天輪：http://www.sunline.cc/u/4347
CSDN ：https://blog.csdn.net/JiekeXu
ITPUB：https://blog.itpub.net/69968215
騰訊云：https://cloud.tencent.com/developer/user/5645107
——————————————————————————
