最近我得到了ORA-00060死锁错误。
我读了这篇文章，这篇文章和这篇文章，但我不确定问题是什么:未索引的FK导致这个或其他问题。
我的问题是如何理解这个跟踪文件以及如何解决它?
下面是跟踪文件:
*** 2015-06-02 14:53:45.513
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
TM-00014d94-00000000 497 556 S 332 1414 SX
TM-00014d94-00000000 332 1414 SX 416 1038 S
TX-0011000f-000000ab 416 1038 X 302 457 S
TM-00014d94-00000000 302 457 SX 497 556 S
session 556: DID 0001-01F1-0000000D session 1414: DID 0001-014C-00000022
session 1414: DID 0001-014C-00000022 session 1038: DID 0001-01A0-0000000C
session 1038: DID 0001-01A0-0000000C session 457: DID 0001-012E-00000028
session 457: DID 0001-012E-00000028 session 556: DID 0001-01F1-0000000D
Rows waited on:
Session 556: obj - rowid = 00014D94 - AAAAAAAAAAAAAAAAAA
(dictionary objn - 85396, file - 0, block - 0, slot - 0)
Session 1414: obj - rowid = 00014D94 - AAAAAAAAAAAAAAAAAA
(dictionary objn - 85396, file - 0, block - 0, slot - 0)
Session 1038: obj - rowid = 00014D94 - AAAAAAAAAAAAAAAAAA
(dictionary objn - 85396, file - 0, block - 0, slot - 0)
Session 457: obj - rowid = 00014FA0 - AAAU+gAAEAAAft+AAA
(dictionary objn - 85920, file - 4, block - 129918, slot - 0)
----- Information for the OTHER waiting sessions -----
Session 1414:
sid: 1414 ser: 1424 audsid: 100128 user: 91/SW flags: 0x45
pid: 332 O/S info: user: oracle, term: UNKNOWN, ospid: 10179
image: oracle@jwdb
client details:
O/S info: user: root, term: unknown, ospid: 1234
machine: localhost.localdomain program: JDBC Thin Client
application name: JDBC Thin Client, hash value=2546894660
current SQL:
insert into t_course_takes (created_at, updated_at, attend, course_id, course_take_type_id, election_mode_id, lesson_id, limit_group_id, paid, remark, semester_id, state, std_id, turn, virtual_cost, id) values (:1 , :2 , :3 , :4 , :5 , :6 , :7 , :8 , :9 , :10 , :11 , :12 , :13 , :14 , :15 , :16 )
Session 1038:
sid: 1038 ser: 951 audsid: 100212 user: 91/SW flags: 0x45
pid: 416 O/S info: user: oracle, term: UNKNOWN, ospid: 10343
image: oracle@jwdb
client details:
O/S info: user: root, term: unknown, ospid: 1234
machine: localhost.localdomain program: JDBC Thin Client
application name: JDBC Thin Client, hash value=2546894660
current SQL:
delete from t_course_takes where id=:1
Session 457:
sid: 457 ser: 2983 audsid: 100099 user: 91/SW flags: 0x45
pid: 302 O/S info: user: oracle, term: UNKNOWN, ospid: 10111
image: oracle@jwdb
client details:
O/S info: user: root, term: unknown, ospid: 1234
machine: jdbcclient program: JDBC Thin Client
application name: JDBC Thin Client, hash value=2546894660
current SQL:
insert into t_elect_loggers (created_at, updated_at, course_code, course_name, course_take_type_id, course_type, credits, election_mode_id, ip_address, lesson_no, operator_code, operator_name, project_id, remark, screening, semester_id, std_code, std_name, turn, type, virtual_orig, virtual_rest, id) values (:1 , :2 , :3 , :4 , :5 , :6 , :7 , :8 , :9 , :10 , :11 , :12 , :13 , :14 , :15 , :16 , :17 , :18 , :19 , :20 , :21 , :22 , :23 )
----- End of information for the OTHER waiting sessions -----
Information for THIS session:
----- Current SQL Statement for this session (sql_id=ca9jc1g44ap41) -----
delete from t_course_takes where id=:1
===================================================
PROCESS STATE
-------------
Process global information:
process: 0x9d0fd98c8, call: 0x95429a500, xact: 0x922b10710, curses: 0x94110e198, usrses: 0x94110e198
----------------------------------------
SO: 0x9d0fd98c8, type: 2, owner: (nil), flag: INIT/-/-/0x00 if: 0x3 c: 0x3
proc=0x9d0fd98c8, name=process, file=ksu.h LINE:11459, pg=0
(process) Oracle pid:497, ser:7, calls cur/top: 0x95429a500/0x95429a500
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 9
last post received-location: ksq.h LINE:1877 ID:ksqrcl
last process to post me: 900fd0348 12 0
last post sent: 0 0 9
last post sent-location: ksq.h LINE:1877 ID:ksqrcl
last process posted by me: 900fce2c8 17 0
(latch info) wait_event=0 bits=0
Process Group: DEFAULT, pseudo proc: 0x90102ea98
O/S info: user: oracle, term: UNKNOWN, ospid: 10507
OSD pid info: Unix process pid: 10507, image: oracle@jwdb
Dump of memory from 0x0000000921009C90 to 0x0000000921009E98
921009C90 00000000 00000000 00000000 00000000 [................]
Repeat 31 times
921009E90 00000000 00000000 [........]
(FOB) flags=2050 fib=0x902c3c2b8 incno=0 pending i/o cnt=0
fname=/home/jwdb/oracle/oradata/orcl/undotbs01.dbf
fno=3 lblksz=8192 fsiz=238080
(FOB) flags=2050 fib=0x902c3c8b8 incno=0 pending i/o cnt=0
fname=/home/jwdb/oracle/oradata/orcl/users01.dbf
fno=4 lblksz=8192 fsiz=603680
(FOB) flags=2050 fib=0x902c3b6a0 incno=0 pending i/o cnt=0
fname=/home/jwdb/oracle/oradata/orcl/system01.dbf
fno=1 lblksz=8192 fsiz=92160
----------------------------------------
SO: 0x94110e198, type: 4, owner: 0x9d0fd98c8, flag: INIT/-/-/0x00 if: 0x3 c: 0x3
proc=0x9d0fd98c8, name=session, file=ksu.h LINE:11467, pg=0
(session) sid: 556 ser: 3224 trans: 0x922b10710, creator: 0x9d0fd98c8
flags: (0x45) USR/- flags_idl: (0x1) BSY/-/-/-/-/-
flags2: (0x40008) -/-
DID: , short-term DID:
txn branch: (nil)
oct: 7, prv: 0, sql: 0x9cfed0be0, psql: 0x9afeb20c8, user: 91/SW
ksuxds FALSE at location: 0
service name: SYS$USERS
client details:
O/S info: user: root, term: unknown, ospid: 1234
machine: localhost.localdomain program: JDBC Thin Client
application name: JDBC Thin Client, hash value=2546894660
Current Wait Stack:
0: waiting for 'enq: TM - contention'
name|mode=0x544d0004, object #=0x14d94, table/partition=0x0
wait_id=787 seq_num=896 snap_id=53
wait times: snap=0.023828 sec, exc=4 min 18 sec, total=4 min 18 sec
wait times: max=infinite, heur=4 min 18 sec
wait counts: calls=87 os=87
in_wait=1 iflags=0x15a0
There is at least one session blocking this session.
Dumping first 3 direct blockers:
inst: 1, sid: 457, ser: 2983
inst: 1, sid: 1353, ser: 5618
inst: 1, sid: 907, ser: 5215
Dumping final blocker:
inst: 1, sid: 1168, ser: 1194
There are 1 sessions blocked by this session.
Dumping one waiter:
inst: 1, sid: 1136, ser: 2212
wait event: 'enq: TM - contention'
p1: 'name|mode'=0x544d0004
p2: 'object #'=0x14d94
p3: 'table/partition'=0x0
row_wait_obj#: 85396, block#: 0, row#: 0, file# 0
min_blocked_time: 12 secs, waiter_cache_ver: 32536
Wait State:
fixed_waits=0 flags=0x23 boundary=(nil)/-1
Session Wait History:
elapsed time of 0.000000 sec since current wait
0: waited for 'latch: enqueue hash chains'
address=0x9313226a0, number=0x1c, tries=0x0
wait_id=839 seq_num=895 snap_id=1
wait times: snap=0.226082 sec, exc=0.226082 sec, total=0.226082 sec
wait times: max=infinite
wait counts: calls=0 os=0
occurred after 0.000000 sec of elapsed time
1: waited for 'enq: TM - contention'
name|mode=0x544d0004, object #=0x14d94, table/partition=0x0
wait_id=787 seq_num=894 snap_id=52
wait times: snap=3.000901 sec, exc=4 min 18 sec, total=4 min 18 sec
wait times: max=infinite
wait counts: calls=87 os=87
occurred after 0.000000 sec of elapsed time
2: waited for 'latch: enqueue hash chains'
address=0x6000cf38, number=0x1c, tries=0x0
wait_id=838 seq_num=893 snap_id=1
wait times: snap=0.000142 sec, exc=0.000142 sec, total=0.000142 sec
wait times: max=infinite
wait counts: calls=0 os=0
occurred after 0.000000 sec of elapsed time
3: waited for 'enq: TM - contention'
name|mode=0x544d0004, object #=0x14d94, table/partition=0x0
wait_id=787 seq_num=892 snap_id=51
wait times: snap=12.003822 sec, exc=4 min 15 sec, total=4 min 15 sec
wait times: max=infinite
wait counts: calls=86 os=86
occurred after 0.000000 sec of elapsed time
4: waited for 'latch: enqueue hash chains'
address=0x6000cf38, number=0x1c, tries=0x0
wait_id=837 seq_num=891 snap_id=1
wait times: snap=0.000170 sec, exc=0.000170 sec, total=0.000170 sec
wait times: max=infinite
wait counts: calls=0 os=0
occurred after 0.000000 sec of elapsed time
5: waited for 'enq: TM - contention'
name|mode=0x544d0004, object #=0x14d94, table/partition=0x0
wait_id=787 seq_num=890 snap_id=50
wait times: snap=6.001627 sec, exc=4 min 3 sec, total=4 min 3 sec
wait times: max=infinite
wait counts: calls=82 os=82
occurred after 0.000000 sec of elapsed time
6: waited for 'latch: enqueue hash chains'
address=0x6000cf38, number=0x1c, tries=0x0
wait_id=836 seq_num=889 snap_id=1
wait times: snap=0.000378 sec, exc=0.000378 sec, total=0.000378 sec
wait times: max=infinite
wait counts: calls=0 os=0
occurred after 0.000000 sec of elapsed time
7: waited for 'enq: TM - contention'
name|mode=0x544d0004, object #=0x14d94, table/partition=0x0
wait_id=787 seq_num=888 snap_id=49
wait times: snap=3.000543 sec, exc=3 min 57 sec, total=3 min 57 sec
wait times: max=infinite
wait counts: calls=80 os=80
occurred after 0.000000 sec of elapsed time
8: waited for 'latch: enqueue hash chains'
address=0x6000cf38, number=0x1c, tries=0x0
wait_id=835 seq_num=887 snap_id=1
wait times: snap=0.000350 sec, exc=0.000350 sec, total=0.000350 sec
wait times: max=infinite
wait counts: calls=0 os=0
occurred after 0.000000 sec of elapsed time
9: waited for 'enq: TM - contention'
name|mode=0x544d0004, object #=0x14d94, table/partition=0x0
wait_id=787 seq_num=886 snap_id=48
wait times: snap=3.000880 sec, exc=3 min 54 sec, total=3 min 54 sec
wait times: max=infinite
wait counts: calls=79 os=79
occurred after 0.000000 sec of elapsed time
更新于6/5/2015
整个跟踪文件在这里
这台ORA-00060也给我的团队带来了问题。跟踪文件显示两个会话彼此阻塞为TX—X --------S。在我们的示例中，我们确保多线程环境分布在unique_number列上，这样两个线程就不会更新同一条记录。再往下看，跟踪文件显示"enq: TX - allocate ITL entry"。当处理运行时，我检查了等待类型:
select blocking_session, sid, serial#, wait_class, seconds_in_wait
from
v$session
where
blocking_session is not NULL
order by
blocking_session;
显示等待类是"Configure"因此，我增加了处理使用的表的initran。然后还减少了批大小，以便提交发生得更频繁而不是更早。之后问题就解决了。