enq: TM - contention

最新推荐文章于 2024-02-04 16:38:35 发布

cuiwangxie1183

最新推荐文章于 2024-02-04 16:38:35 发布

阅读量273

点赞数

文章标签：数据库

20150812，00点到2点，平台数据库发生了以下等待事件告警

enq: TM - contention enq: TX - index contention

（1）查看等待事件为 enq: TM - contention 的sql_id，以及blocking session

select event, blocking_session, blocking_session_serial#，sql_id, count(*)
   from dba_hist_active_sess_history ash
where sample_time >=
           to_timestamp('2015-08-12 00:00:00', 'yyyy-mm-dd hh24:mi:ss')
   and sample_time <=
           to_timestamp('2015-08-12 08:00:00', 'yyyy-mm-dd hh24:mi:ss')
   and event = 'enq: TM - contention'
group by event, blocking_session，blocking_session_serial#, sql_id;

	EVENT	BLOCKING_SESSION	BLOCKING_SESSION_SERIAL#	SQL_ID	COUNT(*)
1	enq: TM - contention			8108u8ww0kph0	424
2	enq: TM - contention			dsvxzg8x39fj9	20
3	enq: TM - contention			0aa9zws1p566t	2
4	enq: TM - contention	383	32323	0aa9zws1p566t	1669
5	enq: TM - contention	383	32323	8108u8ww0kph0	207619
6	enq: TM - contention	383	32323	dsvxzg8x39fj9	10806

t_scs_order 这张表的dml操作。它们都被383会话所阻，有关这条语句的sql_text 如下：

点击(此处)折叠或打开

dsvxzg8x39fj9：
update t_scs_order o set o.stat = :1 where o.order_id = :2
8108u8ww0kph0：
INSERT INTO T_SCS_ORDER
(ORDER_ID,
ORDER_CODE,
CUST_ID,
ORDER_TYPE,
AREA_CODE,
TERM_ID,
ACCT_DATE,
BEGIN_DATE,
END_DATE,
EFF_DATE,
LOGIN_TYPE,
STAT,
PAY_STAT,
ACT_STAT,
MEMO,
TERM_SEQ,
OPER_ORIG)
VALUES
(:ORDER_ID,
:ORDER_CODE,
:CUST_ID,
:ORDER_TYPE,
:AREA_CODE,
:TERM_ID,
sysdate,
TO_DATE(:BEGIN_DATE, 'YYYYMMDDHH24MISS'),
TO_DATE(:END_DATE, 'YYYYMMDDHH24MISS'),
TO_DATE(:EFF_DATE, 'YYYYMMDDHH24MISS'),
:LOGIN_TYPE,
:STAT,
:PAY_STAT,
:ACT_STAT,
:MEMO,
:TERM_SEQ,
:OPER_ORIG)
0aa9zws1p566t：
Update T_SCS_ORDER set STAT = STAT where ORDER_ID='150812091208436'

（2）查看会话383所执行的sql，以及它的等待事件。

select event,blocking_session,blocking_session_serial#,sql_id,count(*)

from dba_hist_active_sess_history ash

where sample_time>=to_timestamp('2015-08-12 00:00:00','yyyy-mm-dd hh24:mi:ss')

and sample_time<=to_timestamp('2015-08-12 08:00:00','yyyy-mm-dd hh24:mi:ss')

and session_id = 383 and session_serial# = 32323

group by event,blocking_session,blocking_session_serial#，sql_id;

	EVENT	BLOCKING_SESSION	BLOCKING_SESSION_SERIAL#	SQL_ID	COUNT(*)
1	library cache lock	3339	6013	bmp7ygwb9x3hq	153
2				0ukzw7tygh0vx	1
3	db file sequential read			avpgp9xrrz2k0	1
4	library cache lock	1146	3917	6rsnmw8m285rd	344
5				avpgp9xrrz2k0	2
6				du7sx8d1f3a5w	2

383所执行的sql为

点击(此处)折叠或打开

bmp7ygwb9x3hq：
alter table T_SCS_ORDER enable row movement
6rsnmw8m285rd ：
alter table T_SCS_ORDER disable row movement

查看383会话执行语句，是来自于存储过程里面，这点查询DBA_SOURCEK这个视图可以看到。
下面为查询方法：

SELECT * FROM DBA_SOURCE WHERE UPPER(TEXT) LIKE '%ALTER TABLE T_SCS_ORDER ENABLE ROW MOVEMENT%' -- 注意要都转换成大写

OWNER NAME TYPE LINE TEXT

1 MEPF_DEV P_SCS_UPDATESTAT PROCEDURE 178 "execute immediate 'alter table T_SCS_ORDER enable row movement';

发现，383会话的等待事件为 library cache lock，并且被3339，1146所阻塞。

（3）查看3339，1146会话状态。

3339：

select event,blocking_session,sql_id,count(*)

from dba_hist_active_sess_history ash

where sample_time>=to_timestamp('2015-08-12 00:00:00','yyyy-mm-dd hh24:mi:ss')

and sample_time<=to_timestamp('2015-08-12 08:00:00','yyyy-mm-dd hh24:mi:ss')

and session_id = 3339 and ash.session_serial# = 6013.

group by event,blocking_session,sql_id;

	EVENT	BLOCKING_SESSION	SQL_ID	COUNT(*)
1			gtdp3m0ga7cd7	217
2			gtdp3m0ga7cd7	93

其中gtdp3m0ga7cd7，这个sql的文本大小为3MB,格式如下：

该sql很长，解析会耗很多时间。涉及到t_scs_order这张表，再解析期间，会持有 t_scs_order相关的锁。

1146：

select event,blocking_session,sql_id,count(*)

from dba_hist_active_sess_history ash

where sample_time>=to_timestamp('2015-08-12 00:00:00','yyyy-mm-dd hh24:mi:ss')

and sample_time<=to_timestamp('2015-08-12 08:00:00','yyyy-mm-dd hh24:mi:ss')

and session_id = 1146 and ash.session_serial# = 3917

group by event,blocking_session,sql_id

	EVENT	BLOCKING_SESSION	SQL_ID	COUNT(*)
1			gtdp3m0ga7cd7	346
2	library cache lock	3339	gtdp3m0ga7cd7	217
3	SQL*Net break/reset to client		gtdp3m0ga7cd7	92

发现 1146 在某个时间段也被3339阻塞。

3339 的sql是从 12-8月 -15 12.00.00.705 上午开始执行

1146 是从12-8月 -15 12.00.00.705 上午开始执行

（4）分析总结

3339 先进行解析，获得相关锁，导致338，1146一直等待， 12-8月 -15 12.36.17.479 上午，释放资源后，383（alter table T_SCS_ORDER enable row movement），先获得锁，执行成功后，1146获得相关锁。

1146 在12-8月 -15 12.36.17.479 上午获得相关锁，然后一直持有到 12-8月 -15 01.38.10.284 上午释放锁。此间，383又执行了一条语句（alter table T_SCS_ORDER disable row movement），然后一直被1146所阻塞，直到 01.38.10.284获得锁。

在此阶段，对这张表的dml的语句，都会被381阻塞。

此时，有很多insert的语句

2015/8/12 1:38

客户端等待事件监控告警(20150812 013807)：等待事件：enq: TX - index contention，类型：Concurrency，SQL_ID:8108u8ww0kph0，数量：28，恐影响生产业务，请尽快处理！(研发中心数据组监控)

enq: TX - index contention

WAIT_EVENT

8108u8ww0kph0

大量并发的insert语句，会造成 enq: TX - index contention，和split 索引块有关，增加索引叶子，枝节点。

5）以下是相关session的相互争用的表

session1(3339)	session2（1146）	session3（383）	other session	time	explanation
gtdp3m0ga7cd7 (参考文本)	gtdp3m0ga7cd7 library cache lock			12-8月 -15 12.00.00.705 上午	3339获得了相关的锁，1146处于library cache lock等待状态
同上	同上	bmp7ygwb9x3hq library cache lock		12-8月 -15 12.10.45.062 上午	此时383的存储过程跑到了bmp7ygwb9x3hq这句话，383和1146都在等待t_scs_order相关的锁。被3339阻塞
同上	同上	同上	等待事件监控告警(20150812 001233)：等待事件：enq: TM - contention，类型：Application，SQL_ID:8108u8ww0kph0，数量：43，	2015/8/12 0:12	其它session的对t_scs_order这张表的dml操作，都被383所阻塞，此时383还没有获得相关的锁，但是383申请的是表锁，require等级高，所以，dml操作都被require的阻塞
同上	同上	同上	等待事件监控告警(20150812 001733)：等待事件：enq: TM - contention，类型：Application，SQL_ID:8108u8ww0kph0，数量：197	2015/8/12 0:17	原因同上，dml操作阻塞数量越来越多
同上	同上	同上	等待事件监控告警(20150812 002233)：等待事件：enq: TM - contention，类型：Application，SQL_ID:8108u8ww0kph0，数量：342	2015/8/12 0:22	原因同上，dml操作阻塞数量越来越多
同上	同上	同上	等待事件监控告警(20150812 002733)：等待事件：enq: TM - contention，类型：Application，SQL_ID:8108u8ww0kph0，数量：459	2015/8/12 0:27	原因同上，dml操作阻塞数量越来越多
gtdp3m0ga7cd7 SQL*Net break/reset to client	gtdp3m0ga7cd7	du7sx8d1f3a5w		12-8月 -15 12.36.27.549 上午	3339释放了锁，同时也出现了SQL*Net break/reset to client等待事件，1146和383都获得了锁， 383的alter table语句执行成功，紧接着执行了du7sx8d1f3a5w这条语句
同上	同上	6rsnmw8m285rd library cache lock		12-8月 -15 12.36.47.709 上午	此时383alter语句被1146所阻塞
同上	同上	同上	等待事件监控告警(20150812 004233)：等待事件：enq: TM - contention，类型：Application，SQL_ID:8108u8ww0kph0，数量：104	2015/8/12 0:42	此时锁的数量少了，因为在12.36.27.549这个点，释放了一部分
	同上	同上		12-8月 -15 12.51.54.244 上午	此时3339会话结束， 383的alter语句还是被1146阻塞
	同上	同上	等待事件监控告警(20150812 005234)：等待事件：enq: TM - contention，类型：Application，SQL_ID:8108u8ww0kph0，数量：251	2015/8/12 0:52	锁再次挤压，并且数量继续增多
	gtdp3m0ga7cd7 SQL*Net break/reset to client		enq: TX - index contention，类型：Concurrency，SQL_ID:8108u8ww0kph0，数量：28	12-8月 -15 01.38.10.284	此时1146释放锁，同时出现了该等待事件SQL*Net break/reset to client，并且此时383的alter语句获得了锁资源，执行成功，然后，关于这张表的insert语句也依次获得了锁，产生了enq: TX - index contention