如何定位TX锁阻塞会话执行的SQL

2020-08-27 00:00:00 执行 操作 事务 会话 阻塞

发生TX - row lock contention等待,我们往往找到blocking_session 然后kill掉会话,但是有时候客户需要知道阻塞会话当时正在执行什么操作,需要确定SQL语句,今天我们测试这个过程,但是由于共享池中SQL的游标可能被LRU算法清除,事务内部DML的数量,所以不保证生产系统一定会捕获阻塞会话在执行的准确的SQL,甚至无法捕获。下面是定位TX锁阻塞会话执行的SQL测试

会话22;

SYS@orcl1>  delete from scott.emp1 where empno=7788;

1 row deleted.

会话1912:

SCOTT@orcl1> update emp1 set ename='' where empno=7788; <<<<此时卡主

查询阻塞信息:

SYS@orcl1>select a.sid,a.blocking_session,a.last_call_et,a.event, object_name,dbms_rowid.rowid_create(1,data_object_id,rfile#,ROW_WAIT_BLOCK#,ROW_WAIT_ROW#) "rowid" ,  c.sql_text from v$session a,v$sqlarea c ,dba_objects,v$datafile where a.blocking_session is not null and a.sql_hash_value = c.hash_value and ROW_WAIT_OBJ#=object_id and file#=ROW_WAIT_FILE#

       SID BLOCKING_SESSION LAST_CALL_ET EVENT                          OBJECT_NAME          rowid              SQL_TEXT

---------- ---------------- ------------ ------------------------------ -------------------- ------------------ --------------------------------------------------

      1912               22          729 enq: TX - row lock contention  EMP1                 AAAD3vAAFAAAADDAAH  update emp1 set ename='' where empno=7788

说明:1912号会话被22号会话阻塞,1912号会话申请行级排他锁TX锁,1912号会话正在执行SQL:update emp1 set ename='' where empno=7788,此时要修改的rowID为: AAAD3vAAFAAAADDAAH

涉及的表对象为emp1;

下面继续查询22号会话的事务信息:

SYS@orcl1>  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=22;

       SID STATUS   PROGRAM                        SQL_TEXT                                           START_TIME            USED_UBLK

---------- -------- ------------------------------ -------------------------------------------------- -------------------- ----------

        22 INACTIVE sqlplus@rac1 (TNS V1-V3)                                                          08/27/20 22:59:47             1

Elapsed: 00:00:00.08

说明: 22号会话目前处于INACTIVE也就是没有SQL语句正在执行,事务起始时间为08/27/20 22:59:47,使用了一个undo block;

下面我们继续查询22号会话,这个没有结束的事务正在执行的SQL。

SYS@orcl1>select s.sid,s.program,s.event,TO_CHAR(S.LOGON_TIME,'YYYY-MM-DD HH24:MI:SS') as sess_LOGON_TIME,TO_CHAR(T.START_DATE,'YYYY-MM-DD HH24:MI:SS') as trans_start_date,s.blocking_session,s.status,(select q.sql_text from v$sql q where q.last_active_time=t.start_date and rownum<=1) as sql_text from v$session s,v$transaction t where s.saddr=t.ses_addr

       SID PROGRAM                        EVENT                          SESS_LOGON_TIME     TRANS_START_DATE    BLOCKING_SESSION STATUS   SQL_TEXT

---------- ------------------------------ ------------------------------ ------------------- ------------------- ---------------- -------- --------------------------------------------------

        22 sqlplus@rac1 (TNS V1-V3)       SQL*Net message from client    2020-08-27 22:59:43 2020-08-27 22:59:47                  INACTIVE delete from scott.emp1 where empno=7788

Elapsed: 00:00:00.00

此时,我们知道阻塞会话正在执行delete操作,这个操作阻塞了1912会话的update操作,而阻塞会话持有的TX锁不释放,造成后续相同row的DML操作全部排队。

注意:如果共享池的特点以及事务自身DML数量,阻塞会话也就是22号会话的未结束事务的SQL很可能无法准确抓到,测试环境相对单一,而在生成环境很可能无法捕获这个SQL。

关于行锁等待,大家可以进一步参考MOS文档  :Waits for 'Enq: TX - ...' Type Events - Transaction (TX) Lock Example Scenarios (Doc ID 62354.1)

或者使用hanganalze,systemdump等进一步确认阻塞关系和每一个进程的状态信息。


相关文章