DEADLOCK DETECTED (ORA-00060)Trace实例分析

DEADLOCK DETECTED (ORA-00060)Trace实例分析
Oracle中引入的行级锁的概念，在大幅提高性能的同时也带来了一点麻烦。对于设计不良或者说处理不当的应用逻辑，有可能出发死锁。对于死锁的跟踪和分析，最简单直接的方法就是分析trace文件。每出现死锁，系统都会生成一个trace文件到USER_DUMP_DEST目录下。
SQL> show parameter USER_DUMP_DEST;


NAME TYPE VALUE
------------------------------------ ----------- ------------------------------
user_dump_dest string D:/ORACLE/PRODUCT/10.2.0/ADMIN/ORCL/UDUMP
正如Tom所言，Oracle认为这些应用死锁是应用自己导致的错误。而且Tom说，在大多情况下，Oracle的这种看法是正确的。不同于其他许多的RDBMS，Oracle极少出现死锁，甚至可以认为几乎不存在。通常情况下，必须认为地提供条件才会产生死锁。
在Oracle9i中，如果子表外键所在的列没有加索引，那么在父表上对主键进行更新和删除的时候要对子表加Share锁，那么，如果发现一个SID下的Object涉及到多个表，可以检察一下是否存在外键索引未加的问题。外键如果导致死锁那么他的类型通常是4 or 5 (S or SSX)。
位图（Bitmap）索引比较适合于那些取值单一的低基数列，但是对于更新比较频繁的表，会带来大量的锁阻塞的可能性，降低了系统的效率，适合于OLAP。所以使用前要考虑清楚。
那么10g以后，出现死锁，并且holds waits为X的，都是逻辑设计问题。特别严重的出现在程序循环中。
下面先举一个简单的死锁例子，看看Trace能带给我们哪些信息。
下面的例子的原理是
session A locks row X
sesssion B locks row Y
session A tries to lock row Y
session B tries to lock row X
Session A fails after roughly 3 seconds with a deadlock ORA-00060
Session A:
Connected to Oracle Database
10g Enterprise Edition Release 10.2.0.3.0
Connected as johnson_hgc


SQL>

SQL>
create
table t_deadlock_demo( id
int , tname varchar( 200));


Table created
SQL>
insert
into t_deadlock_demo values ( 1,'org_demo1' );


1
row inserted
SQL>
insert
into t_deadlock_demo values ( 2,'org_demo2' );


1
row inserted
SQL>
select * from t_deadlock_demo;


ID TNAME
--------------------------------------- ------
1 org_demo1
2 org_demo2
SQL>
update t_deadlock_demo set tname = 'session1_demo2' where
id = 2;


1
row
updated
Session B:
SQL>
update t_deadlock_demo set tname = 'session2_demo1' where
id = 1;


1
row
updated
这个时候各为其主，不会发生锁，都是行级。接下来开始上演死锁。
Session A:
SQL>
update t_deadlock_demo set tname = 'session1_demo1' where
id = 1; (Lock)
Session B:
SQL>
update t_deadlock_demo set tname = 'session2_demo2' where
id = 2;


1
row
updated
这个时候Session B的操作会导致SessionA的操作发生死锁，那么SessionA的最后一步操作会被Oracle强行中断。刚才的锁等待变成了
SQL>
update t_deadlock_demo set tname = 'session1_demo1' where
id = 1;


update t_deadlock_demo set tname = 'session1_demo1' where
id = 1


ORA-00060 : 等待资源时检测到死锁
而此时，SessionB顺利执行结束，等待提交。
我们可以发现USER_DUMP_DEST目录下已经出现了一个跟踪文件【orcl_ora_3448.trc】。
下面是其中的主要内容
Dump file d:/oracle/product/10.2.0/admin/orcl/udump/orcl_ora_3448.trc
Mon Apr 06 14:50:52 2009
ORACLE V10.2.0.3.0 - Production vsnsta=0
vsnsql=14 vsnxtr=3
Oracle Database 10g Enterprise Edition Release 10.2.0.3.0 - Production
With the Partitioning, OLAP and Data Mining options
Windows Server 2003 Version V5.2 Service Pack 2
CPU                 : 4 - type 586, 1 Physical Cores
Process Affinity    : 0x00000000
Memory (Avail/Total): Ph:1655M/4060M, Ph+PgF:3370M/5938M, VA:1254M/2047M
Instance name: orcl
Redo thread mounted by this instance: 1
Oracle process number: 20
Windows thread id: 3448, image: ORACLE.EXE (SHAD)

*** 2009-04-06 14:50:52.539
*** ACTION NAME Command Window - New) 2009-04-06 14:50:52.539
*** MODULE NAME PL/SQL Developer) 2009-04-06 14:50:52.539
*** SERVICE NAME orcl) 2009-04-06 14:50:52.539
*** SESSION ID:(149.17) 2009-04-06 14:50:52.539
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 frCAom 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-000c0029-00001c1f        20     149     X              21     152           X
TX-00080010-00003474        21     152     X              20     149           X
session 149: DID 0001-0014-00000004 session 152: DID 0001-0015-00000002
session 152: DID 0001-0015-00000002 session 149: DID 0001-0014-00000004
Rows waited on:
Session 152: obj - rowid = 00086FCA - AACG/KAAbAAAAScAAB
  (dictionary objn - 552906 , file - 27, block - 1180, slot - 1)
Session 149: obj - rowid = 00086FCA - AACG/KAAbAAAAScAAA
  (dictionary objn - 552906 , file - 27, block - 1180, slot - 0)
Information on the OTHER waiting sessions:
Session 152:
  pid=21 serial=21 audsid=1330117 user: 165/JOHNSON_HGC
  O/S info: user: johnsonjiang, term: DELAWARE, ospid: 7984:9504, machine: GEARTEKS/DELAWARE
            program: PlSqlDev.exe
  application name: PL/SQL Developer, hash value=1190136663
  action name: Command Window - New, hash value=254318129
  Current SQL Statement:
 
update t_deadlock_demo set tname = 'session2_demo2'where id = 2
End of information on OTHER waiting sessions.
Current SQL statement for this session:
update t_deadlock_demo set tname = 'session1_demo1'where id = 1
===================================================
几个重要的信息就是锁的类型是X，说明是DML语句导致的行级排他锁，涉及到两个Session：149和152。149就是报错ora-00060的Session。
下面是两个Session涉及到的对象ID，三种颜色其实代表的都是同样的意思。
0086PCA的10进制就是552906
SQL> select dbms_rowid.rowid_object( 'AACG/KAAbAAAAScAAA' ) from dual;

DBMS_ROWID.ROWID_OBJECT('AACG/
------------------------------
                        552906

SQL> select dbms_rowid.rowid_object( 'AACG/KAAbAAAAScAAB' ) from dual;

DBMS_ROWID.ROWID_OBJECT('AACG/
------------------------------
                        552906

查找对象：
SQL> SELECT t.owner, t.object_name, t.object_type FROM all_objects t WHERE t.data_object_id = 552906
OWNER OBJECT_NAME OBJECT_TYPE
------------------------------ ------------------------------ -------------------
JOHNSON_HGC T_DEADLOCK_DEMO TABLE
update t_deadlock_demo set tname = 'session2_demo2'where id = 2
End of information on OTHER waiting sessions.
Current SQL statement for this session:
update t_deadlock_demo set tname = 'session1_demo1'where id = 1
说明id=1这句死在了id=2的抢下。
===============================================================================================
下面这个例子是上面例子的延伸，上面这样的例子如果不是处理超级复杂的更新，很慢，一般来说也不回碰到这么巧合的事情。
但是如果一个程序逻辑复杂，处理流程较多，尤其是在TRIGGER中处理逻辑，甚至还用上了CURSOR来逐条处理的时候，死锁就比较容易发生了。
下面举一个简单模拟的例子。
创建两个表：
CREATE
TABLE t_deadlock1( id INTEGER);
CREATE
TABLE t_deadlock2( id INTEGER);
创建两个表的插入触发器。
create
or
replace
trigger t_deadlock1_i
after INSERT on t_deadlock1
for each row
declare
i INTEGER;
t_temp VARCHAR2( 200);
begin
update t_deadlock_demo set tname = 'session1_demo2'where id = 2;


i := 0;
WHILE i <= 9999999 LOOP
t_temp := 'aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa';
t_temp := 'aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa';
t_temp := 'aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa';
t_temp := 'aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa';
t_temp := 'aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa';
t_temp := 'aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa';
t_temp := 'aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa';
t_temp := 'aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa';


i := i + 1;
END LOOP;


update t_deadlock_demo set tname = 'session1_demo1'where id = 1;


end t_deadlock1_u;
/
create
or
replace
trigger t_deadlock2_i
after INSERT on t_deadlock2
for each row
declare
i INTEGER;
t_temp VARCHAR2( 200);
begin
update t_deadlock_demo set tname = 'session2_demo1'where id = 1;


i := 0;
WHILE i <= 9999999 LOOP
t_temp := 'aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa';
t_temp := 'aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa';
t_temp := 'aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa';
t_temp := 'aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa';
t_temp := 'aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa';
t_temp := 'aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa';
t_temp := 'aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa';
t_temp := 'aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa';


i := i + 1;
END LOOP;


update t_deadlock_demo set tname = 'session2_demo2'where id = 2;




end t_deadlock2_u;
/
分别执行两条插入语句：
Session 152：
SQL> insert into t_deadlock2 values (1);


insert into t_deadlock2 values (1)


ORA-00060: 等待资源时检测到死锁
ORA-06512: 在 "JOHNSON_HGC.T_DEADLOCK2_I", line 21
ORA-04088: 触发器 'JOHNSON_HGC.T_DEADLOCK2_I' 执行过程中出错
Session 149：
SQL> insert into t_deadlock1 values (1);


1 row inserted
Trace文件：
Dump file d:/oracle/product/10.2.0/admin/orcl/udump/orcl_ora_3164.trc
Mon Apr 06 16:32:55 2009
ORACLE V10.2.0.3.0 - Production vsnsta=0
vsnsql=14 vsnxtr=3
Oracle Database 10g Enterprise Edition Release 10.2.0.3.0 - Production
With the Partitioning, OLAP and Data Mining options
Windows Server 2003 Version V5.2 Service Pack 2
CPU                 : 4 - type 586, 1 Physical Cores
Process Affinity    : 0x00000000
Memory (Avail/Total): Ph:1642M/4060M, Ph+PgF:3360M/5938M, VA:1236M/2047M
Instance name: orcl
Redo thread mounted by this instance: 1
Oracle process number: 21
Windows thread id: 3164, image: ORACLE.EXE (SHAD)

*** 2009-04-06 16:32:55.571
*** ACTION NAME:(Command Window - New) 2009-04-06 16:32:55.571
*** MODULE NAME:(PL/SQL Developer) 2009-04-06 16:32:55.571
*** SERVICE NAME:(orcl) 2009-04-06 16:32:55.571
*** SESSION ID:(152.27) 2009-04-06 16:32:55.571
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-000b0005-00001d18        21     152     X              20     149           X
TX-00010005-00002513        20     149     X              21     152           X
session 152: DID 0001-0015-00000004 session 149: DID 0001-0014-00000006
session 149: DID 0001-0014-00000006 session 152: DID 0001-0015-00000004
Rows waited on:
Session 149: obj - rowid = 00086FCA - AACG/KAAbAAAAScAAA
  (dictionary objn - 552906 , file - 27, block - 1180, slot - 0)
Session 152: obj - rowid = 00086FCA - AACG/KAAbAAAAScAAB
  (dictionary objn - 552906 , file - 27, block - 1180, slot - 1)
Information on the OTHER waiting sessions:
Session 149:
  pid=20 serial=20 audsid=1330124 user: 165/JOHNSON_HGC
  O/S info: user: johnsonjiang, term: DELAWARE, ospid: 7984:9504, machine: GEARTEKS/DELAWARE
            program: PlSqlDev.exe
  application name: PL/SQL Developer, hash value=1190136663
  action name: Command Window - New, hash value=254318129
  Current SQL Statement:
 
insert into t_deadlock1 values (1)
End of information on OTHER waiting sessions.
Current SQL statement for this session:
UPDATE T_DEADLOCK_DEMO SET TNAME = 'session2_demo2'WHERE ID = 2
----- PL/SQL Call Stack -----
  object      line  object
  handle    number  name
57C4C314        21  JOHNSON_HGC.T_DEADLOCK2_I
===================================================
死掉的是Session152进程。这里提示的语句是Trigger中执行的子句，也是出现中断的语句。
而另一条导致死锁的语句由于成功执行，所以这里显示出来的是最外围的语句
insert into t_deadlock1 values (1)
所以大家以后查错的时候，只要注意和152进程出错对象 552906相关的149对象的程序包即可。