一个enq: TX - row lock contention的案例
文章分类:数据库
RAC重新搭建延后了,就是这个case
系统环境:
RHEL 4.4
oracle 10.2.0.3
用户反映每天业务繁忙时间段(大约21:30)程式“卡死”
是第三天早上反映给我,简单跑了一下ASH
看到
系统环境:
RHEL 4.4
oracle 10.2.0.3
用户反映每天业务繁忙时间段(大约21:30)程式“卡死”
是第三天早上反映给我,简单跑了一下ASH
看到
- Event Event Class % Activity Avg Active Sessions
- enq: TX - row lock contention Application 41.37 0.40
- CPU + Wait for CPU CPU 12.28 0.12
- gc buffer busy Cluster 8.30 0.08
- db file scattered read User I/O 5.49 0.05
- gc cr block busy Cluster 4.17 0.04
Event Event Class % Activity Avg Active Sessions
enq: TX - row lock contention Application 41.37 0.40
CPU + Wait for CPU CPU 12.28 0.12
gc buffer busy Cluster 8.30 0.08
db file scattered read User I/O 5.49 0.05
gc cr block busy Cluster 4.17 0.04
其中enq: TX - row lock contention占用user event高达40+%
再查查是哪些语句导致争用
基本都是对于相同的表的insert操作
第三日晚上我在现场处理,看到有大量的insert操作被block了
因为经验不足,没有多看引起block的session和sql语句就直接kill session
询问过程序员后知道,每次程序进行作业前都尝试对一个临时表插入若干条记录,以表示当前作业已经占用资源,其他作业不能进行操作
通常这个动作都是很快完成,完成后会马上把相关的记录从该表中删除
但是很可能因为当时因为某些原因,insert或者后来的delete操作没有commit
所以导致TX row lock争用
在alert log中可以看到
- Mon Jan 18 21:26:06 2010
- GES: Potential blocker (pid=29649) on resource TX-00020003-0009D959;
- enqueue info in file /oracle/admin/phaws/bdump/phaws1_lmd0_13687.trc and DIAG trace file
- Mon Jan 18 21:27:23 2010
- Thread 1 advanced to log sequence 83802
- Current log# 2 seq# 83802 mem# 0: /PHAWS_D00/redo/redo1_02a.log
- Current log# 2 seq# 83802 mem# 1: /PHAWS_D01/redo/redo1_02b.log
- Mon Jan 18 21:34:35 2010
- GES: Potential blocker (pid=30496) on resource TX-000A0000-0075A034;
- enqueue info in file /oracle/admin/phaws/udump/phaws1_ora_7697.trc and DIAG trace file
- Mon Jan 18 21:45:04 2010
- GES: Potential blocker (pid=29513) on resource TX-00080016-000A7D28;
- enqueue info in file /oracle/admin/phaws/udump/phaws1_ora_22590.trc and DIAG trace file
Mon Jan 18 21:26:06 2010
GES: Potential blocker (pid=29649) on resource TX-00020003-0009D959;
enqueue info in file /oracle/admin/phaws/bdump/phaws1_lmd0_13687.trc and DIAG trace file
Mon Jan 18 21:27:23 2010
Thread 1 advanced to log sequence 83802
Current log# 2 seq# 83802 mem# 0: /PHAWS_D00/redo/redo1_02a.log
Current log# 2 seq# 83802 mem# 1: /PHAWS_D01/redo/redo1_02b.log
Mon Jan 18 21:34:35 2010
GES: Potential blocker (pid=30496) on resource TX-000A0000-0075A034;
enqueue info in file /oracle/admin/phaws/udump/phaws1_ora_7697.trc and DIAG trace file
Mon Jan 18 21:45:04 2010
GES: Potential blocker (pid=29513) on resource TX-00080016-000A7D28;
enqueue info in file /oracle/admin/phaws/udump/phaws1_ora_22590.trc and DIAG trace file
再查看相关的DIAG文件,发现以下信息
- O/S info: user: lile1028, term: NHTSOA23, ospid: 6308:3944, machine: NBWDE/NHTSOA23
- program: WMSSG.exe
- application name: WMSSG.exe, hash value=0
O/S info: user: lile1028, term: NHTSOA23, ospid: 6308:3944, machine: NBWDE/NHTSOA23
program: WMSSG.exe
application name: WMSSG.exe, hash value=0
而再留意,DIAG中都是NHTSOA23这台Terminal server发起的block
无独有偶,今天检查该server发现有掉包的情况,究竟是不是因为掉包而导致commit失败呢?
from:http://guoyanxi.javaeye.com/blog/575692