logminer定位事务没有结束的dml操作

2021-12-24 00:00:00 查询 执行 事务 会话 结束


近经常遇到用户TX行锁等待, 发现行锁等待的根源的会话,但是这个SQL执行结束了,后续会话同时执行了查询等其他操作,无法从会话层面获得这个事务的
SQL。下面我们通过测试,使用logminer获得事务未结束的SQL。
环境介绍:
285 397会话都执行update语句,280会话执行delete语句,280随后执行查询操作,我们看阻塞关系
285会话:update CRE_TRUNC_EXP_MAIN set object_name='test' where data_object_id=2020;
397会话:update CRE_TRUNC_EXP_MAIN set object_name='test' where data_object_id=2020;
280会话:delete from CRE_TRUNC_EXP_MAIN where data_object_id=2020;
通过查询发现285,397号会话都在等待TX锁,状态为WAITING,阻塞会话是280
SQL>select sid,serial#,sql_id,event,blocking_session,SECONDS_IN_WAIT,state,WAIT_CLASS from v$session where blocking_session is not null

SID SERIAL# SQL_ID EVENT BLOCKING_SESSION SECONDS_IN_WAIT STATE WAIT_CLASS
---------- ---------- -------------------------- ----------------------------- ---------------- --------------- ---------- --------------------
285 26732 3trzkf8gs9j8m enq: TX - row lock contention 280 790 WAITING Application
397 55592 3trzkf8gs9j8m enq: TX - row lock contention 280 579 WAITING Application

下面查询280号会话的等待情况
SQL> select sid,serial#,sql_id,prev_sql_id,event,blocking_session,SECONDS_IN_WAIT,state,WAIT_CLASS from v$session where sid=280
SID SERIAL# SQL_ID PREV_SQL_ID EVENT   BLOCKING_SESSION SECONDS_IN_WAIT STATE WAIT_CLASS
---------- ---------- ---------- -------------------------- ----------------------------- ---------------- --------------- ---------- ------------------- ---------------
280 61179 24wr724at7zdf SQL*Net message from client     350 WAITING      Idl
继续查询280会话的Idle等待,以及之前执行的SQL,显然这个语句不会阻塞update操作。
PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
SQL_ID 24wr724at7zdf, child number 0
-------------------------------------
select * from cre_trunc_exp_main where data_object_id=2060

Plan hash value: 4190393095

-----------------------------------------------------------------------------------------
| Id | Operation | Name | E-Rows |E-Bytes| Cost (%CPU)| E-Time |
-----------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | | | 299 (100)| |
| 1 | TABLE ACCESS FULL| CRE_TRUNC_EXP_MAIN | 1 | 137 | 299 (1)| 00:00:01 |
-----------------------------------------------------------------------------------------

显然目前280会话还有其他事务,其实整个事务就是在诸多查询之前的delete操作
SQL> delete from cre_trunc_exp_main where data_object_id=2020;

1 row deleted.

如何查询会话280未结束事务的SQL呢?我们知道Redo记录用户的操作行为DDL DML,即使事务没有结束依然会被记录到redo只是标记为事务没有结束,
下面我们从会话280是阻塞会话开始一步步通过logminer捕获这条事务没有结束的SQL。
显然280号会话又未结束的事务

SQL> select xid,XIDUSN,XIDSLOT,XIDSQN,start_scn,a.status,a.start_time from v$transaction a , v$session b where b.saddr=a.ses_addr and b.sid=280;

XID XIDUSN XIDSLOT XIDSQN START_SCN STATUS START_TIME
---------------- ---------- ---------- ---------- ---------- -------------------------------- ----------------------------------------
09001F00C4020000 9 31 708 4122655 ACTIVE 12/24/21 11:05:43

说明280号会话依然有事务XID=09001F00C4020000,但是没有结束,起始SCN=4122655。 因为当前事务SQL操作会保存在当前日志,我们切换下日志,然后从归档日志
挖掘。
SQL> alter system switch logfile;

System altered.

通过SCN=4122655作为过滤条件来定位需要挖掘的归档日志。
SQL> select sequence#,name from v$archived_log where 4122655 between first_change# and next_change#;

SEQUENCE# NAME
---------- ----------------------------------------------------------------------
23 +ARCH/PROD/ARCHIVELOG/2021_12_24/thread_1_seq_23.266.1092139991

开启logminer

SQL> execute DBMS_LOGMNR.ADD_LOGFILE (LOGFILENAME =>'+ARCH/PROD/ARCHIVELOG/2021_12_24/thread_1_seq_23.266.1092139991',OPTIONS => DBMS_LOGMNR.NEW);

PL/SQL procedure successfully completed.

SQL> EXECUTE DBMS_LOGMNR.START_LOGMNR(OPTIONS => DBMS_LOGMNR.DICT_FROM_ONLINE_CATALOG);

PL/SQL procedure successfully completed.

查找事务的SQL,通过条件xidusn=9 and xidslt=31 and xidsqn=708来过滤未结束事务的执行的SQL。


SQL> select sql_redo from v$logmnr_contents where xidusn=9 and xidslt=31 and xidsqn=708;

SQL_REDO
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
set transaction read write;
delete from "LIN"."CRE_TRUNC_EXP_MAIN" where "OWNER" = 'PUBLIC' and "OBJECT_NAME" = 'V$SYSTEM_PARAMETER2' and "SUBOBJECT_NAME" IS NULL and "OBJECT_ID" = '2020' and "DATA_OBJECT_ID" = '2020' and "OBJEC
T_TYPE" = 'SYNONYM' and "CREATED" = TO_DATE('2019-04-17 00:59:27', 'yyyy-mm-dd hh24:mi:ss') and "LAST_DDL_TIME" = TO_DATE('2019-04-17 00:59:27', 'yyyy-mm-dd hh24:mi:ss') and "TIMESTAMP" = '2019-04-17:
00:59:27' and "STATUS" = 'VALID' and "TEMPORARY" = 'N' and "GENERATED" = 'N' and "SECONDARY" = 'N' and "NAMESPACE" = '1' and "EDITION_NAME" IS NULL and "SHARING" = 'METADATA LINK' and "EDITIONABLE" =
'N' and "ORACLE_MAINTAINED" = 'Y' and "APPLICATION" = 'N' and "DEFAULT_COLLATION" IS NULL and "DUPLICATED" = 'N' and "SHARDED" = 'N' and "CREATED_APPID" IS NULL and "CREATED_VSNID" IS NULL and "MODIFI
ED_APPID" IS NULL and "MODIFIED_VSNID" IS NULL and ROWID = 'AAAR1eAABAAAIRzAAh';


更详细查询
SQL> select timestamp, scn, xidusn||'.'||xidslt||'.'||xidsqn "XID", operation,commit_timestamp, cscn, username, thread#, seg_owner||'.'||seg_name "SEG_OWNER.SEG_NAME",substr(rollback,1,2) rollback, operation_code, sql_redo
2 from v$logmnr_contents where xidusn=9 and xidslt=31 and xidsqn=708;


相关文章