奇怪enq: TX - row lock contention行锁等待事件模拟验证
曾经遇到一个奇怪的问题，用户反映行锁等待严重，前台系统无法使用，我定位到某个会话时，该会话一直持有锁不释放，但是开发反映用户执行的SQL会交给框架去commit数据，不会出现执行完DML操作而不释放的情况，但是事实确实如此，我们怀疑用户虽然执行了SQL，但是异常退出导致用户进程依然存在，导致后续阻塞。今天做个测试，验证这个问题，这里完全重现了生产环境的输出结果，从而验证肯定是阻塞会话没有释放锁导致
排查TX锁长时间等待问题nq: TX - row lock contention
26号会话执行update操作，持有行锁 lmode>0 event like ‘enq%’ - gv$lock
SCOTT@orcl1>select userenv('sid') from dual;
USERENV('SID')
--------------
26
Elapsed: 00:00:00.00
SCOTT@orcl1> update emp1 set ename='test' where empno=7788;
1 row updated.
Elapsed: 00:00:00.01
发生23号的阻塞后，我们在会话26执行一条select的SQL
SCOTT@orcl1>select userenv('sid') from dual;
USERENV('SID')
--------------
26
Elapsed: 00:00:00.00
23号会话Delete同一行数据 申请行锁 request>0 ,event like ‘enq%’ - gv$lock
下面我们通过脚本查询当前持有和申请TX锁的会话信息
SYS@orcl2>select
a.inst_id "INST",a.sid,a.id1,a.id2,a.type,a.request,a.ctime "SECS",
c.spid "SPID",
b.OSUSER, b.USERNAME, b.PROCESS,b.MACHINE,b.program,
case
when rawtohex(b.SQL_ADDRESS) <> '00'
then 'CURR'
else 'PREV'
end STAT,
d.sql_text "SQL"
from
gv$lock a, gv$session b, gv$process c,gv$sql d
where
(a.id1,a.id2) in
(
select ID1,ID2 from gv$lock where type = 'TX' and request>0
)
and a.inst_id = b.inst_id
and a.inst_id = c.inst_id
and a.sid = b.sid
and b.paddr = c.addr
and
case
when rawtohex(b.SQL_ADDRESS) <> '00'
then b.SQL_ADDRESS
else b.PREV_SQL_ADDR
end
= d.address
and
case
when b.SQL_HASH_VALUE > 0
then b.SQL_HASH_VALUE
else b.PREV_HASH_VALUE
end
= d.hash_value
order by a.id1,a.id2,a.request;
INST SID ID1 ID2 TY REQUEST SECS SPID
----- ------ ---------- ---------- -- -------- ---------- ------------------------
OSUSER USERNAME PROCESS MACHINE PROGRAM STAT
---------- ---------- ------------------------ -------------------- -------------------- ----
SQL
------------------------------------------------------------
1 26 131086 710 TX 0 754 5000
oracle SCOTT 4959 rac1 sqlplus@rac1 (TNS V1 CURR-V3)
select userenv('sid') from dual
2 23 131086 710 TX 6 741 4680
oracle SYS 4679 rac2 sqlplus@rac2 (TNS V1 CURR-V3)
delete from scott.emp1 where empno=7788
Elapsed: 00:00:02.15
此时有两行记录
分析：
行：26号会话持有TX锁，查询时执行的SQL为select userenv('sid') from dual
第二行：23号会话申请Tx锁，被阻塞的SQL为delete from scott.emp1 where empno=7788
如果通过gv$session查会话26的SQL_id无法获取之前的update操作的SQL，但是我们可以确认这个事务没有结束，或者用户提交了数据，但是这会话异常关闭，这条SQL依然再执行，会话没有退出。
SYS@orcl2>select status,sql_id from gv$session where sid=26;
STATUS SQL_ID
-------- -------------
INACTIVE fjp94552967gh <<<<<< 该SQL不是update语句
Elapsed: 00:00:00.02
下面我们查询会话26（阻塞者） 的事务信息
SYS@orcl2>select s.sid,s.status,program,(select substr(sql_text,1,80) from v$open_cursor where sql_id=s.sql_id and s.status='ACTIVE') sql_text,t.start_time,t.used_ublk from gv$session s,gv$transaction t where s.inst_id=t.inst_id and s.taddr=t.addr and s.sid=26;
SID STATUS PROGRAM SQL_TEXT START_TIME USED_UBLK
------ -------- ------------------------------ ------------------------------------------------------------ -------------------- ----------
26 INACTIVE sqlplus@rac1 (TNS V1-V3) 08/26/20 23:02:58 1
Elapsed: 00:00:00.03
发现26号会话的事务没有结束，而其会话状态为NACTIVE
从测试看我们阻塞者26号会话执行update操作，这个事务没有结束，因为select 不会产生事务，造成后续操作相同行记录被阻塞。
在生产库中遇到的问题很可能是当时操作的用户退出异常，用户进程没有正常退出导致。我们kill会话26就是让Oracle结束事务，从而消除阻塞。
我再通过ASH看看阻塞关系：
SYS@orcl2>select inst_id,session_id,sql_id ,event,blocking_session,count(*) from gv$active_session_history where event like 'enq%' and blocking_session>0 group by inst_id,session_id,sql_id ,event,blocking_session order by count(*) desc;
INST_ID SESSION_ID SQL_ID EVENT BLOCKING_SESSION COUNT(*)
---------- ---------- ------------- ---------------------------------------------------------------- ---------------- ----------
2 23 gy44zy8p19pfx enq: TX - row lock contention 26 3650
2 1887 enq: FU - contention 1901 5
1 16 enq: PE - contention 12 1
Elapsed: 00:00:00.05
我们看到会话26阻塞会话23已经3650秒，被阻塞的会话23正在执行SQL： gy44zy8p19pfx 下面我们查询会话26的信息，kill该会话。
select sid,serial#,status from gv$session where sid=26;
SYS@orcl2>select inst_id,sid,serial#,status from gv$session where sid=26;
INST_ID SID SERIAL# STATUS
---------- ------ ---------- --------
2 26 59 ACTIVE
1 26 13 INACTIVE
Elapsed: 00:00:00.02
开启一个新会话，生产中我们肯定不会是执行用户的会话，测试需要注意，否则不能“自杀”。
SYS@orcl1>alter system kill session '26,13';
System altered.
Elapsed: 00:00:00.01
此时行锁问题解决。
相关文章