ORACLE死锁(ORA-00060)故障排查的一般性手法
【背景】
今晨巡检发现SAP PRD产生一个死锁:
Sun Jun 29 10:30:36 2014ORA-00060: Deadlock detected. More info in file /oracle/PRD/saptrace/diag/rdbms/prd/PRD/trace/PRD_ora_2065024.trc.
网上找到一个不错的troubleshooting的blog,虽然不是SAP系统产生的,但也有很不错的参考价值,转于此并进行一定的完善和处理,如下:
【故障现象】:
两个Java写的后台批处理同时执行时,发生了死锁现象。(我的情况是SAP PRD环境,但底层数据库一样是Oracle。)
【排查手法】:
通过查询视图,找到被锁住的对象v$locked_object,根据其locked_mode,判断其锁类型
查询SQL语句:
SET PAGESIZE 2000 LINESIZE 1000;
col XIDUSN format 99;
col OBJECT_ID format 99999999;
col OWNER format a8;
col OBJECT_NAME format a25;
col SESSION_ID format 99999;
col ORACLE_USERNAME format a8;
col OS_USER_NAME format a8;
col PROCESS formaT 999999;
COL LOCKE format a4;
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的安装路径,可以借助于文件检索功能。
【相关Log】:
Alert: /oracle/PRD/saptrace/diag/rdbms/prd/PRD/trace/alert_PRD.logTrace:/oracle/PRD/saptrace/diag/rdbms/prd/PRD/trace/PRD_ora_2065024.trc