1 說明
某天值班,收到應用反饋說有個測試庫最近每天都出現接口超時情況,請求排查。

雖說這個庫是一個測試庫,但承載著核心系統訂單模塊的回歸測試、新功能驗證等核心測試場景,最近系統很卡:

接口超時導致第三方無法完成每日既定的測試用例,可能影響后續版本的上線計劃,用戶體驗極差,抱怨頻繁。
2 處理措施1
2.1 檢查進程數
根據該 11g RAC 集群的歷史維護記錄,此前曾因最大進程數設置過低(原設 2000)導致進程數滿,進而引發接口超時,后來將節點 1 的processes調整為 5000。
查看參數設置情況:

節點2的最大進程數只有1000,當時基于ASH判斷節點 2 業務量低(峰值小于 1000),便未同步調整,保持 1000 不變。
查看近期節點1歷史進程數:


可以看到,節點 1 每天中午 12 點左右,當前進程數會都會超過 4000 左右,距離 5000 的上限僅差 幾百,接近滿負荷;而9月3日這天,當前進程數的峰值更是達到4985,這時候新進程完全是連不上節點1了,導致接口連接超時。
再查看節點2進程數:

而節點 2 的進程數在相同時間峰值最高僅 760,遠低于 1000 的上限,兩個節點的負載差異懸殊,大量應用連接集中在節點 1,導致節點 1 進程數頻繁接近閾值。
2.2 調整參數
既然節點 2 存在資源冗余,且節點 1 負載過高,決定將節點 2 的最大進程數同步調整為 5000,然后將節點1部分的業務連接分流到節點2,以提升整體資源承載能力。
修改參數:
# 關閉實例2
srvctl stop instance -d xxx -i xxx -o immediate
# 啟動實例2到nomount狀態
srvctl start instance -d xxx -i xxx2 -o nomount
# 修改參數
alter system set processes=5000 scope=both sid='xxx2';
# 關閉實例2
srvctl stop instance -d xxx -i xxx -o immediate
# 啟動實例2
srvctl start instance -d xxx -i xxx2
由于processes是靜態參數,需重啟實例才能生效。
2.3 服務調整
調整參數后,如何快速把一部分應用連接分到節點2?
肯定不能讓應用去改代碼,最快的辦法就是調整服務,修改主節點。用以下腳本可以直觀看出各個服務的負載占比情況:

可以看到,節點 1 上有兩個核心服務的DBTIME占比分別為 55.69% 和 44.29%,合計達 99.98%,幾乎所有應用連接都集中在這兩個服務上。
為分攤負載,決定將其中一個服務的主節點從節點 1 切換為節點 2,操作如下:
# 將服務改為主2備1
srvctl modify service -d xxx -s xxx -modifyconfig -preferred xxx2 -acailable xxx1
# 把服務從xxx1節點切換到xxx2
srvctl relocate service -d xxx -s xxx -i xxx1 -t xxx2
操作完成后,讓應用重啟相關服務關聯的應用進程,因應用端會復用舊連接,僅調整服務配置無法讓現有連接切換,重啟后新連接才會優先分配至節點 2。
3 處理措施2
然鵝,第二天相同的時間,應用側還是反饋有超時情況,看來調整最大進程數和服務配置沒有效果。
3.1 表收集統計信息
并且有一個很奇怪的現象,應用反饋說一些表不帶任何條件查詢就很慢,而表也是小表,只有1條數那種。
據開發反饋,收集相關表的統計信息后,系統短暫恢復正常,但僅過 2 小時,超時問題再次出現,這說明故障根源并非單純的統計信息過期,需要展開更深入的排查。

這種不帶條件查詢很慢,第一反應就是高水位,但是去庫里查看發現高水位并沒有很嚴重,表的統計信息也未過期。難道是抽樣比例太小了,統計信息不準?
重新收集了一次統計信息后,再次執行查詢發現還是很慢,什么條件都不帶竟然1分鐘出不了結果,太奇怪了。
根據上述情況,感覺這個庫已經完全用不了了。。。
3.2 異常等待事件
既然過往處理辦法無法解決問題,那只能回歸常規的問題解決思路了,查看awr、等待事件、TOPSQL等。
看ash高峰期時的等待事件如下:


絕大部分是latch free等待事件,占總等待次數的 91% 以上。形成原因是共享池或Buffer Cache競爭,****常見于高并發 OLTP。
3.2.1 檢查內存使用情況
既然是latch free等待事件,則檢查一下shared pool和buffer cache的使用情況。
awr查看負載情況:

整個庫一點也不忙。
查看共享池:

總體上,Buffer Cache 穩定,Shared Pool大小略減,內存使用率上升了一丟丟,執行次數大于1次的sql數量減少了30%左右。
根據上面的信息可以推斷硬解析有可能增多?
查看硬解析:

硬解析很少,不到2%,正常。
3.2.2 分析 Latch 競爭的根源
內存資源無異常,說明latch free等待并非由內存不足引發,需進一步分析 Latch 的具體類型。
確定該 Latch 對應的名稱和類型。看ash中的P2,找出latch id:

99% 以上的latch free等待對應的latch_id=414,查看latch name,根據hash值查看高峰期latch情況:

從結果看,query server process 相關閂鎖存在嚴重爭用,閂鎖被頻繁訪問,總等待時間很長,大量會話在競爭該 Latch,導致 SQL 一直在等待。
在awr中得到驗證,匹配這兩個latch:

可以看到,`query server process相關閂鎖等待時間達到了了75944秒,失敗率有4.88%。
3.3 并行問題
上面已經查到latch free等待都是由于`query server process 相關latch引起的,而這個latch又是和并行相關的。
根據 Oracle 官方文檔(Note 651060):

意思是:如果在并行進程執行期間有新的子進程產生,則query server process`閂鎖會被保留。
回頭看top 10 events:

存在并行等待事件PX Deq: Slave Session Stats,等待次數很高,有26萬次。
該等待事件在并行執行場景下常見,是并行子進程間的通信等待,該等待事件進入Top 5 等待事件,說明 數據庫中存在大量不必要的并行執行。
查看latch free事件等待次數top sql:

查看top1 sql的執行計劃:

這個sql僅僅是select *,沒有任何where條件,但執行計劃卻啟用了并行執行:心中已有了答案:表開了并行。
查看開了并行的表:

結果一共536張表開了并行,而生產庫所有表都是不開的,而且這些表都是核心表,高頻使用,并行不高才有鬼。。。
3.4 關閉表并行
讓應用自行把這些表并行調整為1:

9月4日關閉并行后,往后2天觀察到等待事件正常,latch free等待事件幾乎沒有了:

進程數維持穩定狀態,節點1峰值小于2200:

問題解決。
4 總結
本次故障的核心根源是測試庫中 五百多張表被錯誤開了表并行,在并行執行創建大量子進程,引發query server process Latch 激烈競爭,最終導致latch free等待事件爆發,導致接口超時與查詢緩慢。




