天天看點

一次Oracle bug的故障排查過程思考

版權聲明:本文為部落客原創文章,遵循 CC 4.0 BY-SA 版權協定,轉載請附上原文出處連結和本聲明。

本文連結:https://blog.csdn.net/bisal/article/details/101729688

問題現象:

一套十幾個TPS的系統被執行2分鐘(00:30-00:32)的夜維(删除曆史過期的資料)搞挂了。

初步分析:

通過應用日志,定位到應用處理都卡在了一條SQL語句上,這個SQL要更新一個包含4個CLOB列的表,有的update操作執行時間超過了10秒,形如,

update A set a=:1, b=:2, c=:3 ... where id=:10 and update_time=:11;           

複制

通過夜維日志,定位到在應用出現卡頓的時間内,夜維正在執行删除這張A表的操作,SQL中會接受删除日期和一次删除的條數作為參數,分别是90和10000,表示一次删除10000條90天以前的曆史資料(一天大約20萬),日志記錄了一次删除10000條的用時,都在6-10秒内,和前幾日的執行時間相比,基本一緻,并未出現異常,

delete from A where update_time <= trunc(sysdate) - :1 and rownum <= :2           

複制

通過作業系統oswtop監控的資訊,發現故障期間,資料庫伺服器的CPU idle曾降低到0%,正常時間段内,CPU idle通常是80%-90%,是以故障期間,應該是什麼操作,極度消耗CPU。

通過資料庫AWR,看到resmgr:cpu quantum排在榜首,

一次Oracle bug的故障排查過程思考

在故障時間段内,看到業務的update和夜維的delete操作等待事件的資訊,尤其update操作,等待的就是resmgr:cpu quantum,

一次Oracle bug的故障排查過程思考

這個等待事件,參考了eygle的文章(https://www.eygle.com/archives/2011/07/events_resmgr_cpu_quantum.html),提示這個問題是和資源管理相關的,如果啟用資源管理計劃,就可能遇到這個問題。如果确認性能受到了資源管理期的影響,正常的解決方案是禁用資源管理,禁用預設的維護計劃(DEFAULT_MAINTENANCE_PLAN Metalink:786346.1)。

經過确認,每天00:00-02:00,啟動了預設的維護視窗,為了保障一些背景任務的執行,update等待resmgr:cpu quantum很可能是因為更新操作消耗了太多的CPU,觸發了Oracle對update操作的資源限制,是以應該是正常現象,是以,找到update消耗更多CPU才是問題的關鍵。

通過SQL AWR,确認update語句的執行計劃隻有一個,而且用的INDEX UNIQUE SCAN,相對來說是很高效的,

一次Oracle bug的故障排查過程思考

通過計算,發現故障期間,一條update操作消耗的邏輯讀高達20多萬,而正常時間段,一條update操作僅消耗20多。

基于以上資訊,初步得到問題的主線,夜維執行期間,正常業務的update操作邏輯讀超高(20多萬),消耗CPU異常,導緻Oracle啟動了資源限制,限制了更新操作CPU的使用,等待事件是resmgr:cpu quantum,update操作變慢了,前面的請求未處理完成,後面的請求就進入了等待隊列,發生了雪崩效應,進而搞挂了應用。

現在的問題是,為什麼故障期間,一條update操作消耗的邏輯讀如此之多?

應用邏輯:

梳理下應用邏輯,出現問題的功能,是記錄流水資訊,大緻的操作步驟,

1. insert一條記錄,其中包括插入第一個CLOB列。

2. update這條記錄的第二個CLOB列。

3. update這條記錄的第三個CLOB列。

4. update這條記錄的第四個CLOB列。

其中CLOB是個大封包,從容量看,這張表是100G,其中一個CLOB是300G,另外三個CLOB将近100G。

深入分析:

資料庫是11.2.0.4,根據故障的現象,一條update操作在delete删除的同時,邏輯讀超高。MOS上有這個bug描述,Bug 19791273 - Poor UPDATE SQL performance due to space search cache for updates on ASSM segment (Doc ID 19791273.8)

This bug is only relevant when using ASSM Space Management (Bitmap Managed Segments)

This problem can occur if the fix for bug 13641076 is present. That fix enables the use of space search cache in updates as well as inserts but this can degrade the performance of the UPDATE SQL operations.

This fix disables the space search cache for UPDATE operations to avoid the performance overhead.

Workaround

指出當使用ASSM位圖管理段的時候,可能因為對update開啟了space search cache的功能而導緻update性能降低。

出現這個問題,另外有個前提,就是已經修複了13641076這個bug(換句話說,很可能是因為修複了13641076這個bug,而引出了19791273這個bug,資料庫是11.2.0.4,包含了13641076的patch),這個bug。13641076這個bug,是讓update和insert操作一樣能使用space search cache功能,盡管這會降低update的一些性能。

19791273這個bug的fix,會對update操作禁用space search cache,避免性能過載。作為這個fix的替代方案,就是設定10019事件。

space search cache是什麼?那再看下13641076這個bug,Bug 13641076 - High buffer gets for insert statement - rejection list does not fire - superseded (Doc ID 13641076.8),

This bug is only relevant when using ASSM Space Management (Bitmap Managed Segments)

這個bug同樣和ASSM空間管理相關,指出當存在一個并發未送出的大資料量delete操作時,insert操作會消耗大量buffer gets。在這種情況下,insert首次嘗試尋找段空閑空間的時候,需要通路很多的塊資料,但是下次執行時,就會通路一個“黑名單”清單(即space search cache),其中标記了哪些塊不可用,是以利用這個“黑名單”就可做到避免讀取那些不可用的塊。但是這個“黑名單”是基于遊标的,如果DML遊标關閉,下次打開新遊标,“黑名單”就需要重建。是以這個fix所要做的就是讓“黑名單”改為基于會話,而不是遊标。換句話說,推測這個cache會存儲在PGA中,基于會話存儲。

是以,當存在一個并發未送出的大資料量delete操作,而insert操作消耗了超高的buffer gets,同一個會話下次通路相同對象的時候,利用這個fix,就能從這個“黑名單”緩存中得到性能的提升。

有些蒙圈了,我們重新梳理這兩個bug,首先,第二個bug(13641076),是說當存在一個并發未送出的大資料量delete操作時,insert操作會消耗大量邏輯讀,原因就是在ASSM下尋找段空閑空間時需要通路的space search cache是基于遊标的,下次使用新遊标,會導緻space search cache重建,是以這個bug對應的fix,會讓這個“黑名單”改為基于會話,而不是遊标。13641076這個bug,是讓update和insert操作一樣能使用space search cache功能,盡管這會降低update的一些性能。但是因為這個bug,引入了另一個bug(19791273),他會讓更新update操作在使用space search cache的時候出現性能問題,對應這個fix,會讓update禁用space search cache,以緩解性能問題,他的替代方案,就是設定10019事件。

初步定位到這個bug,那就順着看,能不能通過patch解決,19791273的patch在11.2.0.4.17和19中都有,唯獨沒18的,但我們的資料庫,恰巧就是18,而且嘗試使用這兩個patch,都出現了和目前PSU沖突的提示,

一次Oracle bug的故障排查過程思考

從這張圖上,可以看出讓Oracle給個18的patch,更困難些。。。

一次Oracle bug的故障排查過程思考

是以,在資料庫層面,通過patch解決問題就比較難了,根據MOS,另一種方案,就是設定10019事件,關閉space search cache。

第一次測試:

在DG備庫,開啟snapshot閃回,在一個PLSQL Developer中手工執行delete批量删除的操作,模拟夜維,在另一個PLSQL Developer中利用從資料庫提取的業務資料拼接出的update語句,執行更新操作,模拟業務。

update操作在更新CLOB列的時候,需要向空值處填充一個很大的值,可能出現目前塊無法容納所要更新的内容,需要找到新的塊空間操作,是以可能進入到上面bug描述的場景中。

發現确實出現了update邏輯讀高的現象,大約2萬多。設定10019事件,再次執行上述的操作,邏輯讀降到200多,

alter system set events '10019 trace name context forever, level 1';           

複制

但是當進行第二次測試的時候,注意此處使用的資料,無論是delete還是update都和首次相同,即使未設定10019事件,并未出現邏輯讀高的現象。

對他的猜測,很可能是首次delete和update,update已經找到了新的塊空間,再次做相同資料的測試,雖然從資料層面來看,是從0變成了大值(CLOB),但是從塊空間看,是可以重用的,無需申請新的塊空間,是以未出現邏輯讀高的現象。

第二次測試:

在生産環境中,設定了10019事件,執行夜維程式,發現日志記錄删除到第10次10000的時候,資料庫的CPU idle開始下降,業務服務的響應時間開始飙升,此時為了避免出現問題,及時kill了程式。難道是10019未生效?還是未啟作用?bug的定位有問題?

推測是這樣,雖然設定了10019事件,關閉space search cache,但上面說了,這個cache是基于會話級别的,是以隻有重新建立會話(PGA),所做操作,才能生效,應用使用的是連接配接池,是以要麼重新開機連接配接池,或者重新開機資料庫節點,否則目前會話,還是會使用sapce search cache。

DG備庫測試的時候,無論是重新開機資料庫節點,還是重新打開PLSQL Developer,每次都相當于一個新連接配接,和這個測試不同。

在這次測試中,發現了另外一個問題,雖然夜維程式每次日志記錄了删除10000條記錄,但實際上他是執行了所有delete表資料的操作,才做了commit,并未真正實作批量送出,是以和上面bug提到“a concurrent uncommitted large DELETE”更加吻合。

解決方案:

1.資料庫層面,設定10019事件,應用重新開機連接配接池(相比重新開機資料庫節點成本要低),或許即使不改夜維的批量送出,這個問題也能得到解決。

2.應用層面,夜維程式增加真正的批量送出,降低一次delete操作涉及的資料塊個數,減少space search cache的重建,避免出現“a concurrent uncommitted large DELETE”的場景,即使沒打patch,應該能減小影響。

3.應用層面,考慮使用分區表,drop partition的方式,将資料删除時間降到最低。但是,如果原表改為分區表,會導緻全局索引重建。可以換另外的一種思路,修改業務邏輯,将這幾個CLOB單獨建立成一張interval的間隔分區子表,按天做分區,業務操作的時候,關聯主子表,夜維操作的時候,drop partition直接删除分區,讓CLOB的删除操作幾乎瞬時完成,将update受到delete影響的可能性,将到最低。

其實,從應用設計角度來看,無論patch、10019事件是否有作用,夜維程式做到批量送出,還是需要的,畢竟即使不會觸發邏輯讀高的問題,這種未送出的大事務,還是會對UNDO等資源有沖擊,而且若從業務邏輯上看,更是沒這必要,不用關心資料是不是一次能全部删除,即使中間異常了,隻是删除了部分的資料,再執行就可以了,資料之間,不存在任何關聯。是以,這個問題雖然根源是資料庫的一個bug,但實際上也考察了開發人員對delete删除的原理、UNDO的原理、批量送出的原理的了解,以及應用的設計。