[Oracle] ORACLE死锁故障排查的一般性手法的备忘录/分析死锁日志

两个Java写的后台批处理同时执行时，发生了死锁现象。

 

排查手法：

通过查询视图，找到被锁住的对象v$locked_object，根据其locked_mode，判断其锁类型

查询SQL语句：

select l.xidusn, l.object_id, o.owner, o.object_name, 
l.session_id, l.oracle_username, l.os_user_name, l.process, 
decode(l.locked_mode, 0, '',
        1, 'NULL',
        2, '(SS)',
        3, '(SX)',
        4, '(S)',
        5, '(SSX)',
        6, '(X)',
        '???') locked_mode
from v$locked_object l, dba_objects o
where l.object_id = o.object_id

判断查询结果，发现两个Session对同一个表的数据行进行了排他。

 

用以下的语句对视图v$sqltext进行查询，可以得到当前正在执行的SQL语句，以及执行SQL语句的session

select username, osuser, machine, terminal, program, 
    sid, serial#, status, sql_address, sql_text
from v$session ss, v$sqltext sq
where type = 'USER'
and ss.sql_address = sq.address
order by ss.sid, ss.serial#, sq.piece

可以发现对同一表中的同一数据行进行更新的两条SQL语句。

通过这两条SQL语句，可以定位Java程序中导致问题的代码。

 

问题原因分析：

对Java代码进行分析后，发现有一个按照数据行主键，逐行循环处理的操作。

不幸的是，循环前，从KeySet（）生成的主键列表没有进行排序，导致每次循环的执行顺序都是随机的。

例如，假设两个session都想要对数据行A,B,C,D进行处理，很有可能session1先处理了A,B，

而此时session2刚好处理完了C,D。这样，session1想要继续处理的C,D由于正被session2给锁住，所以无法继续执行。

session2想要处理的A,B也被session1给锁着，session2也无法继续，两个session最终都没有办法终止。

 

借助于ORACLE的TRACE文件

Oracle发现死锁后，会在alert_[SID].log文件中输出如下的警告信息：ORA-00060: Deadlock detected.

并提示去查看相应的*.trc文件。通过分析*.trc文件可以看到死锁的详细情况，

下面是一个*.trc文件的例子:

 

*** 2012-01-09 20:11:22.379
DEADLOCK DETECTED ( ORA-00060 )
 
[Transaction Deadlock]
 
The following deadlock is not an ORACLE error. It is a
deadlock due to user error in the design of an application
or from issuing incorrect ad-hoc SQL. The following
information may aid in determining the deadlock:
 
Deadlock graph:
                       ---------Blocker(s)--------  ---------Waiter(s)---------
Resource Name          process session holds waits  process session holds waits
TX-000a0006-0000f48f        65     101     X             64     102           X
TX-0007000f-0000d8a3        64     102     X             65     101           X
 
session 101: DID 0001-0041-00000002 session 102: DID 0001-0040-00000002 
session 102: DID 0001-0040-00000002 session 101: DID 0001-0041-00000002 
 这里明确指出了发生死锁的两个session的ID
Rows waited on:
  Session 101: obj - rowid = 0008915A - AACJFaAAFAAEwq1AAA
  (dictionary objn - 561498, file - 5, block - 1247925, slot - 0)
  Session 102: obj - rowid = 0008915A - AACJFaAAFAAEwq1AAI
  (dictionary objn - 561498, file - 5, block - 1247925, slot - 8)
 
----- Information for the OTHER waiting sessions -----
Session 102:
  sid: 102 ser: 2 audsid: 25260645 user: 87/USR_BAT flags: 0x41
  pid: 64 O/S info: user: ora_1, term: UNKNOWN, ospid: 5915
    image: oracle@pcXX
  client details:
    O/S info: user: root, term: unknown, ospid: 1234
    machine: pcXX program: JDBC Thin Client
    application name: JDBC Thin Client, hash value=2546894660
  current SQL:
  
UPDATE XXXX SET XXXX  这里是导致死锁的SQL语句1

----- End of information for the OTHER waiting sessions -----
 
Information for THIS session:
 

*** 2012-01-09 20:11:22.530
----- Current SQL Statement for this session (sql_id=b0qn65w78t10b) -----
UPDATE XXXX SET XXXX 这里是导致死锁的SQL语句2 

===================================================

 

※ log文件和trc文件的存放路径，取决于Oracle的安装路径，可以借助于文件检索功能。