故障现象:
两个Java写的后台批处理同时执行时,发生了死锁现象。
排查手法:
通过查询视图,找到被锁住的对象v$locked_object,根据其locked_mode,判断其锁类型
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,0);">'NULL',0);">2,0);">(SS)3,0);">(SX)4,0);">(S)5,0);">(SSX)6,0);">(X)???') locked_mode
from v$locked_object l,dba_objects o
where l.object_id = o.object_id
判断查询结果,发现两个Session对同一个表的数据行进行了排他。
用以下的语句对视图v$sqltext进行查询,可以得到当前正在执行的sql语句,以及执行sql语句的session
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-00000002session 102: DID 0001-0040-00000002
session 102: DID 0001-0040-00000002session 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,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:@L_404_5@
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:
UPDATEXXXX SETXXXX这里是导致死锁的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) -----
UPDATEXXXX SET XXXX这里是导致死锁的sql语句2
===================================================