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这种导致数据库性能下降的问题，并建立应急处理机制。

ITPub博客

ORACLE RAC集群大范围delete大表与insert&update同时执行导致活动会话数飙升

最新文章