结论
1,oracle应用死锁会产生trace file，并且会在告警日志记录相关文件的目录
2,trace file大体包括几部分内容
3,第一部分内容为：表明死锁是什么类型的死锁
信息如下：
DEADLOCK DETECTED ( ORA-00060 )
[Transaction Deadlock]
The following deadlock is not an ORACLE error. It is a --标明死锁是由应用本面设计不合理或者SQL原因引发，而本ORACLE本身的原因导致
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:
4，第二部分内容为：死锁的阻塞者及等待者详细信息
Deadlock graph:
竞争的资源 ----可见分为阻塞者 以及等待者
---------Blocker(s)-------- ---------Waiter(s)---------
Resource Name process session holds waits process session holds waits
TX-000f001f-000004e5 56 90 X 72 2 X
TX-0007001b-0001efe3 72 2 X 56 90 X
4.1,关于上述4的竞争资源含义：竞争的资源第2部分表明xidusn,xidslot,xidsqn,对应于v$transaction，具体分析见下测试细节
4.2,关于阻塞者及等待者的含义：见文识义，不再复述
5，第三部分内容为：与死锁相关的表记录信息
Rows waited on:
Session 241: obj - rowid = 000125EF - AAASXvAAEAAAYJPAAA --相关的死锁会话，表记录对应的ROWID
(dictionary objn - 75247, file - 4, block - 98895, slot - 0) --死锁的对象，所属文件及块号，以及槽编号
Session 261: obj - rowid = 000125EF - AAASXvAAEAAAYJPAAB
(dictionary objn - 75247, file - 4, block - 98895, slot - 1)
6，死锁所属进程的信息
包括了进程信息，所属会话的信息，会话运行SQL以及等待事件和历史等待事件列表相关信息
Information for THIS session:
----- Current SQL Statement for this session (sql_id=b3tmrc0st5pyb) -----
update t_lock set a=11 where a=1
===================================================
PROCESS STATE
-------------
Process global information:
process: 0xdd6589c0, call: 0xd27aead8, xact: 0xd9898658, curses: 0xdc90b030, usrses: 0xdc90b030
----------------------------------------
SO: 0xdd6589c0, type: 2, owner: (nil), flag: INIT/-/-/0x00 if: 0x3 c: 0x3
proc=0xdd6589c0, name=process, file=ksu.h LINE:11459, pg=0
(process) Oracle pid:184, ser:2, calls cur/top: 0xd27aead8/0xd27aead8
flags : (0x0) -
flags2: (0x0), flags3: (0x0)
intr error: 0, call error: 0, sess error: 0, txn error 0
intr queue: empty
ksudlp FALSE at location: 0
(post info) last post received: 0 0 252
具体信息请参见如下测试细节
测试
---oracle version
SQL> select * from v$version where rownum=1;
BANNER
--------------------------------------------------------------------------------
Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - 64bit Production
---session 241
SQL> select sid from v$mystat where rownum=1;
SID
----------
241
SQL> select pid,spid,addr from v$process where addr=(select paddr from v$session where sid=(select sid from v$mystat where rownum=1));
PID SPID ADDR
---------- ------------------------------------------------ ----------------
184 15936 00000000DD6589C0
SQL> create table t_lock(a int,b int);
Table created.
SQL> insert into t_lock select level,level from dual connect by level<=2;
2 rows created.
SQL> commit;
Commit complete.
SQL> select * from t_lock;
A B
---------- ----------
1 1
2 2
SQL> update t_lock set a=22 where a=2;
1 row updated.
----session 261
SQL> select sid from v$mystat where rownum=1;
SID
----------
261
SQL> update t_lock set a=11 where a=1;
1 row updated.
SQL> select pid,spid,addr from v$process where addr=(select paddr from v$session where sid=(select sid from v$mystat where rownum=1));
PID SPID ADDR
---------- ------------------------------------------------ ----------------
185 15937 00000000DD659A00
---session 241及261分别执行如下
SQL> update t_lock set a=11 where a=1;
update t_lock set a=11 where a=1
*
ERROR at line 1:
ORA-00060: deadlock detected while waiting for resource
---session 261
SQL> update t_lock set a=22 where a=2;
查看告警日志，可见出现死锁会记录在告警日志
[root@seconary ~]# su - oracle
[oracle@seconary ~]$ cd /oracle/diag/rdbms/guowang/guowang/trace/
[oracle@seconary trace]$ tail -f alert_guowang.log
Sun Nov 08 19:06:04 2015
ORA-00060: Deadlock detected. More info in file /oracle/diag/rdbms/guowang/guowang/trace/guowang_ora_15936.trc.
我们分析下死锁的TRACE FILE,获取有价值的内容，直接在源文件直行分析，便于交插参考
*** 2015-11-08 19:06:01.260
DEADLOCK DETECTED ( ORA-00060 )
[Transaction Deadlock]
The following deadlock is not an ORACLE error. It is a --标明死锁是由应用本面设计不合理或者SQL原因引发，而本ORACLE本身的原因导致
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-00b40017-00002e45 184 241 X 185 261 X
TX-00c2001d-00002c68 185 261 X 184 241 X
由上可见，有2条记录，第一条记录表明261会话请求排它X锁，却发现当被241会话以X排它模式持有，所以只能等待
第二条记录同理，但刚好相反
小结下：
上述包括：
竞争的资源 ：它有3部分构成，第一部分很简单，表明锁的类型，第2和第3部分，请继续看我下面的分析
阻塞者信息：进程，会话，持锁模式，等待模式
等待者信息：进程，会话，持锁模式，等待模式
先看下上述竞争的资源构成
SQL> select type,name,id1_tag,id2_tag,is_user,description from v$lock_type where lower(type) like '%tx%';
TYPE NAME ID1_TAG ID2_TAG IS_USER DESCRIPTION
--------------- ------------------------- -------------------- -------------------- ---------- --------------------------------------------------
TX Transaction usn<<16 | slot sequence YES Lock held by a transaction to allow other transact
ions to wait for it
SQL> select saddr,sid from v$session where sid in (241,261);
SADDR SID
---------------- ----------
00000000DC90B030 241
00000000DC8D0F70 261
SQL> select xidusn,xidslot,xidsqn,ubafil,ubablk,ubasqn,ubarec from v$transaction where ses_addr in ('00000000DC90B030','00000000DC8D0F70');
XIDUSN XIDSLOT XIDSQN UBAFIL UBABLK UBASQN UBAREC
---------- ---------- ---------- ---------- ---------- ---------- ----------
194 29 11368 7 755 2670 23
180 23 11845 7 531 2810 37
SQL> select to_char(194,'xxxxxxx') xidusn,to_char(29,'xxxxxxx') xidslot,to_char(11368,'xxxxxxx') xidsqn from dual;
XIDUSN XIDSLOT XIDSQN
---------------- ---------------- ----------------
c2 1d 2c68
可见竞争的资源第2部分表明xidusn,xidslot,xidsqn,对应于v$transaction
再看下did,参考前文：http://blog.itpub.net/9240380/viewspace-1819341/
session 241: DID 0001-00B8-00000003 session 261: DID 0001-00B9-00000001
session 261: DID 0001-00B9-00000001 session 241: DID 0001-00B8-00000003
可见死锁DID在2个会话就是交插的，很易理解，因为是死锁吗
继续看，会显示与死锁相关的表记录信息
Rows waited on:
Session 241: obj - rowid = 000125EF - AAASXvAAEAAAYJPAAA --相关的死锁会话，表记录对应的ROWID
(dictionary objn - 75247, file - 4, block - 98895, slot - 0) --死锁的对象，所属文件及块号，以及槽编号
Session 261: obj - rowid = 000125EF - AAASXvAAEAAAYJPAAB
(dictionary objn - 75247, file - 4, block - 98895, slot - 1)
SQL> select object_id,object_name from dba_objects where object_id=75247;
OBJECT_ID OBJECT_NAME
---------- ------------------------------
75247 T_LOCK
SQL> select a,b,rowid from scott.t_lock;
A B ROWID
---------- ---------- ------------------
1 1 AAASXvAAEAAAYJPAAA
2 2 AAASXvAAEAAAYJPAAB
--通过死锁记录的ROWID可以定位到表对应的记录
SQL> select a,b,rowid from scott.t_lock where rowid in ('AAASXvAAEAAAYJPAAA','AAASXvAAEAAAYJPAAB');
A B ROWID
---------- ---------- ------------------
1 1 AAASXvAAEAAAYJPAAA
2 2 AAASXvAAEAAAYJPAAB
再看看上述的slot含义是什么呢？
SQL> select DBMS_ROWID.ROWID_RELATIVE_FNO(ROWID) file_no,DBMS_ROWID.ROWID_BLOCK_NUMBER(ROWID) block_no,dbms_rowid.rowid_row_number(rowid) record_no from scott.t_lock;
FILE_NO BLOCK_NO RECORD_NO
---------- ---------- ----------
4 98895 0
4 98895 1
结合BLOCK DUMP可知上述的slot代表record_no记录的标号
Block header dump: 0x0101824f
Object id on Block? Y
seg/obj: 0x125ef csc: 0x00.4b9039a itc: 2 flg: E typ: 1 - DATA
brn: 0 bdba: 0x1018248 ver: 0x01 opc: 0
inc: 0 exflg: 0
Itl Xid Uba Flag Lck Scn/Fsc
0x01 0x00b4.017.00002e45 0x01c00213.0afa.25 ---- 1 fsc 0x0000.00000000
0x02 0x00c2.01d.00002c68 0x01c002f3.0a6e.17 ---- 1 fsc 0x0000.00000000
下面信息会显示导致死锁会话正在执行的SQL
----- Information for the OTHER waiting sessions -----
Session 261:
sid: 261 ser: 9 audsid: 31722060 user: 84/SCOTT flags: 0x45
pid: 185 O/S info: user: oracle, term: UNKNOWN, ospid: 15937
image: oracle@seconary (TNS V1-V3)
client details:
O/S info: user: oracle, term: pts/4, ospid: 15933
machine: seconary program: sqlplus@seconary (TNS V1-V3)
application name: SQL*Plus, hash value=3669949024
current SQL:
update t_lock set a=22 where a=2 --正在运行的SQL
----- End of information for the OTHER waiting sessions -----
死锁所属进程的信息
包括了进程信息，所属会话的信息，会话运行SQL以及等待事件和历史等待事件列表相关信息
Information for THIS session:
----- Current SQL Statement for this session (sql_id=b3tmrc0st5pyb) -----
update t_lock set a=11 where a=1
===================================================
PROCESS STATE
-------------
Process global information:
process: 0xdd6589c0, call: 0xd27aead8, xact: 0xd9898658, curses: 0xdc90b030, usrses: 0xdc90b030
----------------------------------------
SO: 0xdd6589c0, type: 2, owner: (nil), flag: INIT/-/-/0x00 if: 0x3 c: 0x3
proc=0xdd6589c0, name=process, file=ksu.h LINE:11459, pg=0
(process) Oracle pid:184, ser:2, calls cur/top: 0xd27aead8/0xd27aead8
flags : (0x0) -
flags2: (0x0), flags3: (0x0)
intr error: 0, call error: 0, sess error: 0, txn error 0
intr queue: empty
ksudlp FALSE at location: 0
(post info) last post received: 0 0 252
last post received-location: kgsk2.h LINE:638 ID:kgskrunnextint: posting new vt to run
last process to post me: dd5ba2c0 2 2
last post sent: 0 0 253
last post sent-location: kgsk2.h LINE:641 ID:kgskchk: posting new vt to run
last process posted by me: dd5be3c0 6 0
(latch info) wait_event=0 bits=0
Process Group: DEFAULT, pseudo proc: 0xdd9a34d0
O/S info: user: oracle, term: UNKNOWN, ospid: 15936
OSD pid info: Unix process pid: 15936, image: oracle@seconary (TNS V1-V3)
Dump of memory from 0x00000000DD536240 to 0x00000000DD536448
0DD536240 00000000 00000000 00000000 00000000 [................]
Repeat 31 times
0DD536440 00000000 00000000 [........]
(FOB) flags=2050 fib=0xd8f365d0 incno=0 pending i/o cnt=0
fname=/oracle/oradata/guowang/tbs_undo_nb.dbf
fno=7 lblksz=8192 fsiz=10656
----------------------------------------
SO: 0xdb964af8, type: 13, owner: 0xdd6589c0, flag: INIT/-/-/0x00 if: 0x1 c: 0x1
proc=0xdd6589c0, name=channel handle, file=ksr2.h LINE:347, pg=0
(broadcast handle) 0xdb964af8 flag: (1) PUBLISHER,
owner: 0xdd6589c0 - ospid: 15936
event: 2, last message event: 0,
last message waited event: 0,
next message: (nil)(0), messages published: 1
channel: (0xdb9b20b0) RBR channel [name: 29]
scope: 7, event: 186, last mesage event: 186,
publishers/subscribers: 2/1,
messages published: 177
heuristic msg queue length: 0
----------------------------------------
SO: 0xdb964958, type: 13, owner: 0xdd6589c0, flag: INIT/-/-/0x00 if: 0x1 c: 0x1
proc=0xdd6589c0, name=channel handle, file=ksr2.h LINE:347, pg=0
(broadcast handle) 0xdb964958 flag: (1) PUBLISHER,
owner: 0xdd6589c0 - ospid: 15936
event: 2, last message event: 0,
last message waited event: 0,
next message: (nil)(0), messages published: 1
channel: (0xdb9b2208) obj broadcast channel [name: 30]
scope: 7, event: 121, last mesage event: 121,
publishers/subscribers: 1/1,
messages published: 118
heuristic msg queue length: 0
(FOB) flags=2050 fib=0xd8f353a0 incno=0 pending i/o cnt=0
fname=/oracle/oradata/guowang/users01.dbf
fno=4 lblksz=8192 fsiz=108800
(FOB) flags=2050 fib=0xd8f377e8 incno=0 pending i/o cnt=0
fname=/oracle/oradata/guowang/temp02.dbf
fno=202 lblksz=8192 fsiz=131072
(FOB) flags=2050 fib=0xd8f371e8 incno=0 pending i/o cnt=0
fname=/oracle/oradata/guowang/temp01.dbf
fno=201 lblksz=8192 fsiz=2560
(FOB) flags=2050 fib=0xd8f34788 incno=0 pending i/o cnt=0
fname=/oracle/oradata/guowang/sysaux01.dbf
fno=2 lblksz=8192 fsiz=198400
(FOB) flags=2050 fib=0xd8f34188 incno=0 pending i/o cnt=0
fname=/oracle/oradata/guowang/system01.dbf
fno=1 lblksz=8192 fsiz=145920
----------------------------------------
SO: 0xdc90b030, type: 4, owner: 0xdd6589c0, flag: INIT/-/-/0x00 if: 0x3 c: 0x3
proc=0xdd6589c0, name=session, file=ksu.h LINE:11467, pg=0
(session) sid: 241 ser: 10 trans: 0xd9898658, creator: 0xdd6589c0
flags: (0x45) USR/- flags_idl: (0x1) BSY/-/-/-/-/-
flags2: (0x40008) -/-
DID: , short-term DID:
txn branch: (nil)
oct: 6, prv: 0, sql: 0xce920f68, psql: 0xcedb6180, user: 84/SCOTT
ksuxds FALSE at location: 0
service name: SYS$USERS
client details:
O/S info: user: oracle, term: pts/5, ospid: 15935
machine: seconary program: sqlplus@seconary (TNS V1-V3)
application name: SQL*Plus, hash value=3669949024
Current Wait Stack:
0: waiting for 'enq: TX - row lock contention'
name|mode=0x54580006, usn<<16 | slot=0xc2001d, sequence=0x2c68
wait_id=257 seq_num=258 snap_id=1
wait times: snap=19.179006 sec, exc=19.179006 sec, total=19.179006 sec
wait times: max=infinite, heur=19.179006 sec
wait counts: calls=6 os=6
in_wait=1 iflags=0x15a0
There are 1 sessions blocked by this session.
Dumping one waiter:
inst: 1, sid: 11, ser: 1
wait event: 'latch: enqueue hash chains'
p1: 'address'=0xdb69fea0
p2: 'number'=0x1c
p3: 'tries'=0x0
row_wait_obj#: 4294967295, block#: 0, row#: 0, file# 0
min_blocked_time: 0 secs, waiter_cache_ver: 1014
2626
被折叠的 条评论
为什么被折叠?
到【灌水乐园】发言
