2018年6月7日 21：30左右，客戶一oracle rac 11.2.0.3叢集資料庫活動會話數短時間內飆升，經過分析發現，客戶應用21:26:00
首先發起對一張12G，6700萬條資料的大表進行大範圍刪除，同時叢集2個節點還同時對delete的表進行insert——很奇葩的是，有一
個匿名儲存過程塊除了有對delete表的insert，還包含對另一張表的update，由於delete執行慢，insert和儲存過程被堵塞，還形成了
死鎖，最終導致叢集資料庫活動會話數急速飆升。下面提供詳細的分析過程，僅此用來說明客戶這一應用設計不合理，也說明oracle
叢集執行交叉業務可能導致嚴重的效能問題。
環境資訊：
作業系統：HPUNIX
資料庫：oracle 11.2.0.3 rac
1、oracle OEM監控到的活動會話數飆升圖

2、根據oracle OEM監控顯示，叢集活動會話數飆升的時間段是2018-06-07 21:20~21:50，據此做2叢集2個節點的21:00~22:00
的AWR，叢集節點1、2資料庫例項1、2資料庫負載DB Time分別為21861、23614，說明問題時段例項1、2負載很高，資料庫活動會話數從21 :00的
200左右曾至少達到多1745，符合OEM監控顯示的問題現象。

3、檢視2個節點的TOP頂級等待事件，發現等待事件enq: TX - row lock contention平均等待時間異常為221600多ms。

4、審查2個節點的AWR發現節點1 TOP SQL order by CPU Time發現有一條SQL語句9mf3mj1kz45fg，其執行時間911.80秒，消耗
CPU時間佔總DBTIME的20.22%。

5、透過dba_hist_active_session_hitory檢視檢視sql語句9mf3mj1kz45fg的執行時間為21:26~21:36

6、進一步檢視dba_hist_sess_history等待事件enq: TX - row lock contention的出現時間是2018-6-7 21 :26 :02與delete(9mf3mj1kz45fg
開始執行時間21 :26 :00)語句執行開始時間吻合。

7、查詢問題時段資料庫delete：9mf3mj1kz45fg、insert：3qz3ks1zr2w8y、儲存過程：gczwn5gn7tbgc執行語句，發現有delete、insert、
匿名儲存過程塊操作同一張表，後續觀察中類似3qz3ks1zr2w8y、0y7a6hjak1x2b的sql語句還有很多。

SQL_ID	SQL語句	操作的表	開始執行時間	例項名
9mf3mj1kz45fg	delete from symmetricKeyDBJnl where operTime < '20180531'	SYMMETRICKEYDBJNL	21 :26 :00	inst1
3qz3ks1zr2w8y	INSERT INTO SYMMETRICKEYDBJNL(OPERTIME, KEYNAME, OPERATION, LMKPROTECTMODE, KEYVALUE, CHECKVALUE, OLDKEYVALUE, OLDCHECKVALUE, OPERATORTYPE, OPERATOR)VALUES('20180607212833', 'ATM.N0920035.zpk', 2, '01', '7D1E274A87DF908DD47AFB6A8C72D720', 'F0F98D2456744F1A', '847CB110CF7E11504F1E14061470C745', 'C92C2E2C100E0223', 1, 'QD:QD')	SYMMETRICKEYDBJNL	21:26:05	inst2
gczwn5gn7tbgc	INSERT INTO SYMMETRICKEYDBJNL(OPERTIME, KEYNAME, OPERATION, LMKPROTECTMODE, KEYVALUE, CHECKVALUE, OLDKEYVALUE, OLDCHECKVALUE, OPERATORTYPE, OPERATOR)VALUES('20180607213642', 'ATM.A3460030.zpk', 2, '01', '9C833BD378776530B0E0E9FB5095D3F8', 'E8956965AEE05BFA', '24D249F0E8D3F7D7957943E4640AD84B', '9E7D88AD2EA772A4', 1, 'QD:QD')	SYMMETRICKEYDBJNL	21:26:27	inst1
daf2q0md8k7c0	INSERT INTO SYMMETRICKEYDBJNL(OPERTIME, KEYNAME, OPERATION, LMKPROTECTMODE, KEYVALUE, CHECKVALUE, OLDKEYVALUE, OLDCHECKVALUE, OPERATORTYPE, OPERATOR)VALUES('20180607212634', 'ATM.N0910079.zak', 2, '01', '14FCF75C06DAF3041071BCA14004DF3D', '5331D74CB999FF01', '34441AADB40E43F057FE91E88A35E698', 'EB143CED99E5524B', 1, 'QD:QD')	SYMMETRICKEYDBJNL	21 :26 :33	inst2
0y7a6hjak1x2b	beginupdate symmetricKeyValueset lmkProtectMode = '01', keyValue = 'E62C2E34E4703AFCEED83781345340CE', oldKeyValue = 'DD78ACEA61CA1847635481BF090616DD' where keyName = 'ATM.D0330048.zpk';update symmetricKeyDB set algorithmID = 0, checkValue = '603B31F427AFC157', oldCheckValue = '2AD39EA361A0A758', keyUpdateTime='20180607212942' where keyName = 'ATM.D0330048.zpk';insert into symmetricKeyDBJnl(operTime, keyName, operation, lmkProtectMode, keyValue, checkValue, oldKeyValue, oldCheckValue, operatorType, operator)values('20180607212942', 'ATM.D0330048.zpk', 2, '01', 'E62C2E34E4703AFCEED83781345340CE', '603B31F427AFC157', 'DD78ACEA61CA1847635481BF090616DD', '2AD39EA361A0A758', 1, 'QD:QD'); end;	symmetricKeyValuesymmetricKeyDBJnl		inst1 inst2

8、檢視delete語句的執行計劃，發現表SYMMETRICKEYDBJNL是全表掃描，並且執行時間比較長，消耗CPU資源比較嚴重。

9、繼續調查表SYMMETRICKEYDBJNL發現該表有12G之大，資料量有6700萬之多，並且沒有索引。

10、到此可知，叢集在2018-06-07 21 :26 ~2018-06-07 21 :36 出現活動會話連線數激增的原因是節點1的delete大表阻塞了節
點1、節點2後續發起的操作同張表的insert和巢狀有insert儲存過程事務，並且影響到儲存過程中對其他表的update操作事務，
最終導致叢集資料庫連線會話數的飆升。
11、給客戶的問題處理建議

a.對大表delete刪除操作，分批次執行，例如一次刪除一週的資料，並且執行大範圍刪除操作的同時儘可能避免同時執行insert
或巢狀有操作相同表的DML語句，否則容易引起死鎖。

b.對大表刪除建議先備份，先對需要的資料放入臨時表，然後對大表進行truncate，儘可能縮短資料清理操作執行時間。

c.加強監控力度，及時發現delete這種導致資料庫效能下降的問題，並建立應急處理機制。

ORACLE RAC叢集大範圍delete大表與insert&update同時執行導致活動會話數飆升

相關文章