看到row lock waits发生在一个索引上。
3 那么，究竟是什么操作导致了这个enq: TX – row lock contention等待事件呢？ 查看系统中，当前有哪些会话产生了enq: TX – row lock contention等待事件？
SQL> select event,sid,p1,p2,p3 from v$session_wait where event='enq: TX - row lock contention';
EVENT SID P1 P2 P3
---------------------------------------------------------------- ---------- ---------- ---------- ----------
enq: TX - row lock contention 224 1415053316 1441815 144197
enq: TX - row lock contention 238 1415053316 1441815 144197
enq: TX - row lock contention 247 1415053316 1441815 144197
enq: TX - row lock contention 248 1415053316 1441815 144197
enq: TX - row lock contention 253 1415053316 1441815 144197
SQL>
看到SID为224,238,247,248,253的会话产生enq: TX – row lock contention等待事件。
4 查看系统中的当前会话，是在哪个对象上产生了产生了enq: TX – row lock contention等待事件？
SQL> select ROW_WAIT_OBJ#,ROW_WAIT_FILE#,ROW_WAIT_BLOCK#,ROW_WAIT_ROW# from v$session where event='enq: TX - row lock contention';
ROW_WAIT_OBJ# ROW_WAIT_FILE# ROW_WAIT_BLOCK# ROW_WAIT_ROW#
------------- -------------- --------------- -------------
369195 0 0 0
369195 0 0 0
369195 0 0 0
369195 0 0 0
369195 0 0 0
369195 0 0 0
6 rows selected
SQL>
5 那么这个数据库对象为369195的对象究竟是什么呢？
SQL> select object_name,object_id from dba_objects where object_id=369195;
OBJECT_NAME OBJECT_ID
----------------------------------- ----------
BIND_PROCESS_LOG_REFNO 369195
SQL> select OWNER,OBJECT_NAME,OBJECT_ID,DATA_OBJECT_ID, OBJECT_TYPE from dba_objects where object_name='BIND_PROCESS_LOG_REFNO';
OWNER OBJECT_NAME OBJECT_ID DATA_OBJECT_ID OBJECT_TYPE
------------------------------ ----------------------------- ---------- -------------- -------------------
SUNISCO BIND_PROCESS_LOG_REFNO 369195 369195 INDEX
SQL>
可以看到，定位到的结果同上述AWR报告中段统计信息吻合，是SUNISCO这个用户下的一个索引。
6 接下来，继续看看SID为224,238,247,248,253的会话到底在执行哪些操作导致enq: TX – row lock contention等待事件？
SQL> select sid,sql_text from v$session a,v$sql b where sid in(224,238,247,248,253) and (b.sql_id=a.sql_id or b.sql_id=a.prev_sql_id);
SID SQL_TEXT
---------- --------------------------------------------------------------------------------
224 select count(1) from EDI_MESSAGE_PROCESS_LOG where (LOG_ID = :P_0_0 )
224 INSERT INTO EDI_MESSAGE_PROCESS_LOG(LOG_ID, SERVICE_TYPE, SERVICE_STATUS, INFO_C
238 select count(1) from EDI_MESSAGE_PROCESS_LOG where (LOG_ID = :P_0_0 )
238 INSERT INTO EDI_MESSAGE_PROCESS_LOG(LOG_ID, SERVICE_TYPE, SERVICE_STATUS, INFO_C
247 INSERT INTO EDI_MESSAGE_PROCESS_LOG(LOG_ID, SERVICE_TYPE, SERVICE_STATUS, REFNO,
247 INSERT INTO EDI_MESSAGE_PROCESS_LOG(LOG_ID, SERVICE_TYPE, SERVICE_STATUS, REFNO,
248 INSERT INTO EDI_MESSAGE_PROCESS_LOG (LOG_ID, SERVICE_TYPE, SERVICE_STATUS, REFNO
248 INSERT INTO EDI_MESSAGE_PROCESS_LOG (LOG_ID, SERVICE_TYPE, SERVICE_STATUS, REFNO
248 SELECT SEQ_NEWID.NEXTVAL FROM DUAL
253 SELECT SEQ_NEWID.NEXTVAL FROM DUAL
253 INSERT INTO EDI_MESSAGE_PROCESS_LOG (LOG_ID, SERVICE_TYPE, SERVICE_STATUS, REFNO
11 rows selected
SQL>
看到有SQL_ID不同的SQL在同时向EDI_MESSAGE_PROCESS_LOG这张表执行INSERT操作。
7 接下去看看EDI_MESSAGE_PROCESS_LOG这张表和索引BIND_PROCESS_LOG_REFNO之间有没有什么关系？
SQL> select index_name,table_name,index_type from user_indexes where table_name='EDI_MESSAGE_PROCESS_LOG';
INDEX_NAME TABLE_NAME INDEX_TYPE
------------------------------ ------------------------------ ----------
PK_EDI_MESSAGE_PROCESS_LOG EDI_MESSAGE_PROCESS_LOG NORMAL
ID_EDI_LOG_INPUT_DATE EDI_MESSAGE_PROCESS_LOG NORMAL
BIND_PROCESS_LOG_REFNO EDI_MESSAGE_PROCESS_LOG BITMAP
SQL> select index_name,table_name,column_name from user_ind_columns where table_name='EDI_MESSAGE_PROCESS_LOG';
INDEX_NAME TABLE_NAME COLUMN_NAM
------------------------------ ------------------------------ ----------
PK_EDI_MESSAGE_PROCESS_LOG EDI_MESSAGE_PROCESS_LOG LOG_ID
ID_EDI_LOG_INPUT_DATE EDI_MESSAGE_PROCESS_LOG INPUT_DATE
BIND_PROCESS_LOG_REFNO EDI_MESSAGE_PROCESS_LOG REFNO
SQL> select object_name,object_id,object_type,created from user_objects where object_name='BIND_PROCESS_LOG_REFNO';
OBJECT_NAME OBJECT_ID OBJECT_TYPE CREATED
------------------------------ ---------- --------------- -------------------
BIND_PROCESS_LOG_REFNO 369195 INDEX 2012/11/05 10:18:28
SQL> select index_name,index_type from user_indexes where index_name='BIND_PROCESS_LOG_REFNO';
INDEX_NAME INDEX_TYPE
------------------------------- -----------
BIND_PROCESS_LOG_REFNO BITMAP
SQL>
发现，这个索引BIND_PROCESS_LOG_REFNO是位于EDI_MESSAGE_PROCESS_LOG这张表的REFNO字段上的一个位图索引，而且是2012/11/05 10:18:28创建的，也就是说是近期才创建的1个位图索引。
问题定位到这一步基本比较清晰了，产生enq: TX – row lock contention事件的原因就是上述的第2个可能原因：位图索引同时被更新或同时并发的向位图索引字段上插入相同字段值。
8 那么，解决的办法也比较简单了，就是干掉这个位图索引，因为这个位图索引在这种应用场景下确实不太适合。事后，经过同客户方沟通确认，该索引是他们的一个DBA当初看到系统比较慢，而加上去的一个位图索引。
9 补充，从当时的ADDM报告中，也可以看到数据库给我们的建议：
FINDING 4: 20% impact (6013 seconds)
------------------------------------
发现 SQL 语句正处于行锁定等待。
RECOMMENDATION 1: Application Analysis, 17% benefit (5131 seconds)
ACTION: 在 INDEX "SUNISCO.BIND_PROCESS_LOG_REFNO" (对象 ID 为 369195)
中检测到了严重的行争用。使用指定的阻塞 SQL 语句在应用程序逻辑中跟踪行争
用的起因。
RELEVANT OBJECT: database object with id 369195
RATIONALE: SQL_ID 为 "dr4uxu769tmmb" 的 SQL 语句在行锁上被阻塞。
RELEVANT OBJECT: SQL statement with SQL_ID dr4uxu769tmmb
INSERT INTO EDI_MESSAGE_PROCESS_LOG(LOG_ID, SERVICE_TYPE,
SERVICE_STATUS, LOG_DATETIME, REFNO, REF_TYPE, MSG_ID, BL_NO, BL_ID,
VOYAGE_ID, VESSEL_NAME, IMO_NO, VOYAGE_NO, FUNCTION_TYPE, INPUT_DATE,
IN_STATUS, SYSTEM_TYPE, ERROR_LOG, FILE_NAME) VALUES ( :B1 , :B2 ,
:B3 , :B4 , :B5 , :B6 , :B7 , :B8 , :B9 , :B10 , :B11 , :B12 , :B13 ,
:B14 , :B15 , :B16 , :B17 , :B18 , :B19 )
RATIONALE: SQL_ID 为 "dxsbgubsb6r4n" 的 SQL 语句在行锁上被阻塞。
RELEVANT OBJECT: SQL statement with SQL_ID dxsbgubsb6r4n
INSERT INTO EDI_MESSAGE_PROCESS_LOG(LOG_ID, SERVICE_TYPE,
SERVICE_STATUS, INFO_CODE, INFORMATION, INFO_LEVEL, LOG_DATETIME,
REFNO, REF_TYPE, MSG_ID, BL_NO, VOYAGE_ID, VESSEL_NAME, IMO_NO,
VOYAGE_NO, FUNCTION_TYPE, INPUT_DATE, IN_STATUS, SYSTEM_TYPE,
ERROR_LOG, FILE_NAME) VALUES ( :B1 , :B2 , :B3 , :B4 , :B5 , :B6 ,
:B7 , :B8 , :B9 , :B10 , :B11 , :B12 , :B13 , :B14 , :B15 , :B16 ,
:B17 , :B18 , :B19 , :B20 , :B21 )
RATIONALE: SQL_ID 为 "b38qhyzvn5bdd" 的 SQL 语句在行锁上被阻塞。
RELEVANT OBJECT: SQL statement with SQL_ID b38qhyzvn5bdd
INSERT INTO EDI_MESSAGE_PROCESS_LOG(LOG_ID, SERVICE_TYPE,
SERVICE_STATUS, LOG_DATETIME, REFNO, REF_TYPE, MSG_ID, BL_NO,
VOYAGE_ID, VESSEL_NAME, IMO_NO, VOYAGE_NO, FUNCTION_TYPE, INPUT_DATE,
IN_STATUS, SYSTEM_TYPE, ERROR_LOG, FILE_NAME) VALUES ( :B1 , :B2 ,
:B3 , :B4 , :B5 , :B6 , :B7 , :B8 , :B9 , :B10 , :B11 , :B12 , :B13 ,
:B14 , :B15 , :B16 , :B17 , :B18 )
RATIONALE: SQL_ID 为 "36k2xpx3c6wr5" 的 SQL 语句在行锁上被阻塞。
RELEVANT OBJECT: SQL statement with SQL_ID 36k2xpx3c6wr5
INSERT INTO EDI_MESSAGE_PROCESS_LOG(LOG_ID, SERVICE_TYPE,
SERVICE_STATUS, REFNO, REF_TYPE, MSG_ID, BL_NO, VOYAGE_ID,
VESSEL_NAME, IMO_NO, VOYAGE_NO, FUNCTION_TYPE, INPUT_DATE, IN_STATUS,
SYSTEM_TYPE, ERROR_LOG, FILE_NAME) VALUES ( :B1 , :B2 , :B3 , :B4 ,
:B5 , :B6 , :B7 , :B8 , :B9 , :B10 , :B11 , :B12 , :B13 , :B14 , :B15
, :B16 , :B17 )
RATIONALE: 具有 ID "268", 用户 ID "31", 程序 "FC.EdiService.Import.exe" 和
模块
"FC.EdiService.Import.exe" 的会话是构成此建议案中的优化建议的 51% 的阻
塞会话。
RATIONALE: 具有 ID "307", 用户 ID "31", 程序 "FC.EdiService.Import.exe" 和
模块
"FC.EdiService.Import.exe" 的会话是构成此建议案中的优化建议的 11% 的阻
塞会话。
RATIONALE: 具有 ID "227", 用户 ID "31", 程序 "FC.EdiService.Import.exe" 和
模块
"FC.EdiService.Import.exe" 的会话是构成此建议案中的优化建议的 11% 的阻
塞会话。
RATIONALE: 具有 ID "273", 用户 ID "31", 程序 "FC.EdiService.Import.exe" 和
模块
"FC.EdiService.Import.exe" 的会话是构成此建议案中的优化建议的 9% 的阻塞
会话。
10 最后，从本案例中，可以看到在日常的数据库维护中，添加或修改一些对象信息时，务必要经过严格的测试，尤其是在生产系统上做调整更应如此。同样，可以看出，数据库的一些理论基础知识对于DBA还是蛮重要的。
