匪夷所思:罕見的 Oracle 全域性事務鎖等待事件分析
資料技術嘉年華等你來
活動預告:11.16-17日,北京市東三環中路61號富力萬麗酒店,相聚資料技術嘉年華,(99元票務)免費購票倒計時,點選檢視大會詳情。
楊長老帶來主題“深入核心-Oracle雙活架構和踩坑案例實戰”,敬請期待~
點選“閱讀原文”或者掃描下圖二維碼註冊購票,即將售罄,趕快參與鴨!
楊廷琨,雲和恩墨CTO,Oracle ACED,ITPUB Oracle 資料庫管理版版主 ,人稱"楊長老”,十數年如一日堅持進行Oracle技術研究與寫作,號稱"Oracle的百科全書”,迄今已經在自己的部落格上發表了超過3000篇技術文章。與 Eygle 共同主編出版了多本《Oracle DBA手記》系列圖書。
此次大會楊長老分享的主題是“深入核心-Oracle雙活架構和踩坑案例實戰”,來聽楊老師分享架構,看他如何巧妙地處理雷區。
這是在某客戶現場的一次即時分析,這個問題困擾了使用者一段時間,資料庫體現為嚴重的效能問題,導致應用出現大範圍超時以及會話激增等問題,多次嘗試 kill session 都無法徹底解決問題,重啟後系統恢復正常。
拿到故障時刻的 AWR 報告,可以發現問題時刻,資料庫的主要等待為:
Global transaction acquire instance locks 和 enq: TX - row lock contention。
Event | Waits | Time(s) | Avg wait (ms) | % DB time | Wait Class |
Global transaction acquire instance locks | 5,342 | 5,343 | 1000 | 74.09 | Configuration |
enq: TX - row lock contention | 5 | 1,437 | 287308 | 19.92 | Application |
DB CPU | 331 | 4.59 | |||
direct path read | 37,708 | 72 | 2 | 0.99 | User I/O |
log file sync | 7,817 | 12 | 2 | 0.16 | Commit |
其中 TX – row lock contention 等待十分常見,這個等待事件造成應用的阻塞也很容易理解,但是Global transaction acquire instance locks並不是常見等待,從字面上理解,是全域性事務在嘗試獲取例項鎖。這個等待在等待時間佔比上,消耗了將近75%的DB TIME。
當然資料庫中TOP 5中最嚴重的等待不一定是問題的根源,分析問題時刻的 ASH 資訊,在問題時刻,最先出現的是全域性事務獲取鎖的等待,隨後開始出現行鎖等待:
SQL> select to_char(sample_time, 'hh24miss'), session_id, event, blocking_session
2 from dba_hist_active_sess_history
3 where sample_time >= to_date('201810180652', 'yyyymmddhh24mi')
4 and sample_time <= to_date('201810180700', 'yyyymmddhh24mi')
5 and instance_number = 1
6 order by 1, 2;
首先出現問題的是會話 763,其處於Global transaction acquire instance locks等待中,該會話並未顯示被其他會話阻塞。之後開始出現了行鎖等待,這些等待enq: TX - row lock contention的會話,其阻塞物件都是會話763。
顯然在本次故障中,雖然最終導致大範圍業務掛起的是enq: TX - row lock contention等待,但是最終問題的根源是Global transaction acquire instance locks等待。
幾乎與此同時,後臺告警日誌出現大量的報錯:
Thu Oct 18 06:53:33 2018
opiodr aborting process unknown ospid (26428) as a result of ORA-24756
Thu Oct 18 06:53:36 2018
Errors in file /trace/orcl1_pmon_30688.trc:
ORA-24756: transaction does not exist
Errors in file /trace/orcl1_pmon_30688.trc:
ORA-24756: transaction does not exist
Errors in file /trace/orcl1_pmon_30688.trc:
ORA-24756: transaction does not exist
Errors in file /trace/orcl1_pmon_30688.trc:
ORA-24756: transaction does not exist
資料庫中出現該等待的時間點 06:52,再考慮到等待在報錯前會經歷一個超時,因此資料庫中的等待與告警日誌中的 ORA-24756 錯誤有密切的關係。
以 ORA-24756 作為關鍵字查詢 MOS,可以找到與當前現象非常接近的文章:
PMON cleanup fails with ORA-24756: transaction does not exist (文件 ID 2299927.1)。
文件中描述的報錯現象與當前問題一致,且資料庫版本也很接近。Oracle認為這個錯誤是由於PMON程序在清理不存在的事務時出現了卡住的現象。
Oracle給出了幾個比較類似的bug,但是這些bug的狀態不是不可重現就是已中止,因此類似的問題並沒有明確的結論:
Bug 20676168 - PMON GOT CONTINUOUS ORA-24756 DURING SHUTDOWN <<<<<<<<<< Closed, Could Not Reproduce
Bug 16317766 - EXADATA : ORA-24756: TRANSACTION DOES NOT EXIST <<<<<<<<<<<< Suspended, Req'd Info not Avail
Bug 9757979 - PMON CLEANUP FAILS WITH ORA-24756: TRANSACTION DOES NOT EXIST <<<<<<<<<<< Closed, Could Not Reproduce
無論是Global transaction acquire instance locks等待還是後臺alert日誌中不斷出現的ORA-24756錯誤,問題都指向Oracle的鎖和全域性事務處理。
而從11g以後,RAC的全域性事務的處理由後臺程序GTXn來自動維護。該程序是否啟動受初始化引數 global_txn_processes 的控制,該引數預設值為1,也就是在資料庫啟動的時候會預設啟動GTXn程序。
詢問客戶近期是否進行過應用和資料庫的調整,可以確認的是客戶的應用程式並未發生任何變化,在之前也未出現過類似的問題,不過在出現問題之前,資料庫做過主庫和Data Guard備庫之間的切換演練,而切換演練完成後,恢復正常業務時,就出現了這次故障。顯然這次切換演練的操作是被懷疑的重點。
在詳細檢查了alert告警日誌後發現,在DATA GUARD演練後切換回主庫時,GTXn程序未啟動:
Thu Oct 18 02:36:18 2018
alter database commit to switchover to physical standby with session shutdown
ALTER DATABASE COMMIT TO SWITCHOVER TO PHYSICAL STANDBY [Process Id: 4366] (orcl1)
.
Switchover: Primary controlfile converted to standby controlfile succesfully.
Switchover: Complete - Database shutdown required
Completed: alter database commit to switchover to physical standby with session shutdown
Thu Oct 18 02:45:27 2018
.
RFS[8]: Assigned to RFS process 3216
RFS[8]: Identified database type as 'physical standby': Client is ARCH pid 11990
Thu Oct 18 03:11:13 2018
alter database open
AUDIT_TRAIL initialization parameter is changed to OS, as DB is NOT compatible for database opened with read-only access
This instance was first to open
Beginning standby crash recovery.
Serial Media Recovery started
.
Thu Oct 18 03:11:13 2018
SMON: enabling cache recovery
Dictionary check beginning
Dictionary check complete
Database Characterset is ZHS16GBK
No Resource Manager plan active
Starting background process GTX0
Thu Oct 18 03:11:14 2018
GTX0 started with pid=51, OS id=5041
replication_dependency_tracking turned off (no async multimaster replication found)
Physical standby database opened for read only access.
Completed: alter database open
.
Thu Oct 18 04:57:19 2018
alter database commit to switchover to primary with session shutdown
ALTER DATABASE SWITCHOVER TO PRIMARY (orcl1)
Maximum wait for role transition is 15 minutes.
Switchover: Media recovery is still active
Role Change: Canceling MRP - no more redo to apply
.
Switchover: Complete - Database mounted as primary
Completed: alter database commit to switchover to primary with session shutdown
Thu Oct 18 04:57:39 2018
alter database open
This instance was first to open
Picked broadcast on commit scheme to generate SCNs
.
Thu Oct 18 04:57:44 2018
QMNC started with pid=41, OS id=22585
LOGSTDBY: Validating controlfile with logical metadata
LOGSTDBY: Validation complete
Completed: alter database open
.
Thu Oct 18 06:53:33 2018
opiodr aborting process unknown ospid (26428) as a result of ORA-24756
Thu Oct 18 06:53:36 2018
Errors in file /trace/orcl1_pmon_30688.trc:
ORA-24756: transaction does not exist
Errors in file /trace/orcl1_pmon_30688.trc:
.
Starting background process GTX0
Thu Oct 18 09:51:20 2018
GTX0 started with pid=36, OS id=32470
Starting background process RCBG
Thu Oct 18 09:51:20 2018
從上面節選的部分alert日誌可以看到,在2點36分,主庫執行了SWITCHOVER操作,開始切換演練。
在3點11分,資料庫開啟,alert中提示,當前資料庫為物理備庫,為只讀開啟模式,在隨後的日誌中標紅的部分,顯示此時後臺程序GTX0程序啟動。
在4點57分,資料庫再次執行SWITCHOVER切換,此時資料庫並未完全SHUTDOWN,而是直接轉換為MOUNT模式,並於4點57分44秒完成了資料庫的OPEN過程。但是這個時間段的alert中並未發現GXTn程序的啟動。
而在alert中發現GTX0程序再次出現,是故障之後例項1重啟時刻的9點51分。
顯然,問題已經非常明確,在資料庫由物理備庫切換為主庫的過程中,GTXn程序沒有啟動,這導致了Oracle無法處理分散式事務的鎖問題,因此前臺會話出現Global transaction acquire instance locks等待,而後臺PMON也無法正常的清理會話和事務。
由於例項2在SWITCHOVER切換過程中是被SHUTDOWN後重新啟動的,因此例項2上的GTXn程序是正常啟動的,這也是應用切換到例項2上不在出現故障的原因。
如果要避免類似的問題產生,一方面在進行DATA GUARD的切換演練後,在主庫切換到PRIMARY模式後,再執行一次資料庫重啟的操作,確保所有必要的程序都會啟動。另一方面,對於應用程式,如果確實需要修改其他資料庫中的表,應該通過建立其他資料庫連線的方式來實現,避免在資料庫中通過資料庫鏈的方式直接更新遠端表。
這個案例給我們的警示是:
資料庫的工作非常緊密,不同版本的變化也不斷向前,瞭解資料庫不同版本的新特性,在進行變更時進行詳細的檢查確認,才能確保資料庫安全穩定執行,少出問題。
資料技術嘉年華大禮包
在本屆資料技術嘉年華大會上,您不僅可以獲得行業技術大禮包,我們在現場為技術愛好者們準備了抽獎環節,主辦方以及各大讚助夥伴為大家準備了多份精美大禮包,每個禮包中包含...
青雲——精美限量紀念T恤
雲和恩墨——限量紀念電腦內膽包
PingCAP——健身斜跨帆布包
至頂網——精美玩偶
戴爾——馬拉松紀念款摺疊雙肩
創業邦——2018年會價值588門票1張
容聯——2018商務電腦手提包
易捷行雲——運動款紀念雙肩包
華章——2018珍藏版技術圖書
等等
支付寶“錦鯉”活動僅僅出現了一個“信小呆”,本屆資料技術嘉年華現場將出現多個“信小呆”,以上只是禮包中部分獎品,小編已經迫不及待想要更多的人知道這個福利了,動動手指,轉發出去,攜身邊技術愛好者一起來享用這場技術盛宴,最後“滿載而歸” 吧,[壞笑][壞笑]。
社團粉絲福利:本文下方評論點贊滿10個的讀者可以得到價值99元優惠券,小編會留言回覆您優惠碼,一分錢即可參會。
集贊截止時間:2018年11月15日。
點選“原文連結”註冊購票哦,購票過程中有任何問題,可加小助手微信:Enmoedu05。
資料技術嘉年華等你來!
近期文章