Version 11.2.0.2.0
Hello Guys, i am having a bit of a trouble trying to interpret the trace file for a dead lock.
The environment is a two node rac environment and the job runs only in the first node, the job runs an update statement on the tables. and I suspect that this is not a row level locking since there is no information on the rows in the trace files. Also since the environment is a rac env, I am not seeing the ORA-00060 error, instead I am seeing "Global Wait-For-Graph(WFG) at ddTS[0.24aa] :"
I've read the Arup Nandas blogs which tells of some scenarios where the dead lock might occur from a DB side.
The Arup Nanda Blog: Application Design is the only Reason for Deadlocks? Think Again
Reason for Deadlock from DB side - ITL Shortage,
Absense of index on Foreign key, (ruled out, since the indexes are present on the foreign keys)
Direct loading, (ruled out, since the job is not a direct load)
Bitmap index contention, (ruled out, since none of the indexes are bitmap indexes)
primary key overlap (happens only for inserts) (ruled out, since the job is an update and not an insert)
The only reason I can think of is the ITL Shortage from the db side. I ran the following sql and got the following result.
select owner, object_name, value
from v$segment_statistics
where statistic_name = 'ITL waits'
and value > 0
***RESULT***
| PRDMMIS | AD_CLM_LN_DERIVED_ELEMENT | 103 |
| PRDMMIS | AD_CLM_HDR_DERIVED_ELEMENT | 257 |
| PRDMMIS | AD_CLM_LN_DERIVED_ELEMENT | 9 |
| PRDMMIS | AD_CLM_HDR_DERIVED_ELEMENT | 5 |
| PRDMMIS | AD_CLM_HDR_DERIVED_ELEMENT | 7 |
"AD_CLM_LN_DERIVED_ELEMENT" & "AD_CLM_HDR_DERIVED_ELEMENT" are the tables on which the UPDATE statement is being performed.
Now I want to confirm whether the deadlock is from DB issue or it is data issue. There are THREE OCCURRENCES where the dead lock occurs and the following are the excerpts from the trace files with the three scenarios. Can you please help me interpret these trace files and help me conclude what the actual problem is regarding the dead lock.
Thank You
Occurrence 1:
Wed Feb 26 02:21:10 2014
Global Enqueue Services Deadlock detected. More info in file
/clu01/oracle/diag/rdbms/chpprd/CHPPRD1/trace/CHPPRD1_lmd0_41687.trc.
*** 2014-02-26 02:21:09.139
Global blockers dump start:---------------------------------
DUMP LOCAL BLOCKER/HOLDER: block level 3 res [0xbc0005][0xc5cc3],[TX][ext 0x1,0x0]
----------resource b905f6878----------------------
resname : [0xbc0005][0xc5cc3],[TX][ext 0x1,0x0]
hash mask : x3
Local inst : 1
dir_inst : 1
master_inst : 1
hv idx : 39
hv last r.inc : 0
current inc : 4
hv status : 0
hv master : 0
open options : dd
grant_bits : KJUSERNL KJUSEREX
grant mode : KJUSERNL KJUSERCR KJUSERCW KJUSERPR KJUSERPW KJUSEREX
count : 2 0 0 0 0 1
val_state : KJUSERVS_NOVALUE
valblk : 0xffffffff7d346038000000087a9c3430 .}4`8z40
access_inst : 1
vbreq_state : 0
state : x0
resp : b905f6878
On Scan_q? : N
Total accesses: 4044
Imm. accesses: 2516
Granted_locks : 1
Cvting_locks : 2
value_block: ff ff ff ff 7d 34 60 38 00 00 00 08 7a 9c 34 30
GRANTED_Q :
lp b9db2ffc0 gl KJUSEREX rp b905f6878 [0xbc0005][0xc5cc3],[TX][ext 0x1,0x0]
master 1 gl owner b9eccc438 possible pid 58132 xid 1008-0087-00005E93 bast 0 rseq 474 mseq 0 history 0x14951495
open opt KJUSERDEADLOCK
CONVERT_Q:
lp b9da9bac0 gl KJUSERNL rl KJUSERPR rp b905f6878 [0xbc0005][0xc5cc3],[TX][ext 0x1,0x0]
master 1 gl owner b94c86588 possible pid 58106 xid 1008-0084-0000993A bast 0 rseq 474 mseq 0 history 0x49ab549a
convert opt KJUSERGETVALUE
lp b9bed32f8 gl KJUSERNL rl KJUSERPR rp b905f6878 [0xbc0005][0xc5cc3],[TX][ext 0x1,0x0]
master 1 gl owner b9cce95a0 possible pid 58220 xid 1008-0088-00005B7E bast 0 rseq 474 mseq 0 history 0x49ab549a
convert opt KJUSERGETVALUE KJUSERNODEADLOCKWAIT
----------enqueue b9db2ffc0------------------------
lock version : 2906601
Owner inst : 1
grant_level : KJUSEREX
req_level : KJUSEREX
bast_level : KJUSERNL
notify_func : 0
resp : b905f6878
procp : b97400338
pid : 0
proc version : 1021
oprocp : 0
opid : 0
group lock owner : b9eccc438
possible pid : 58132
xid : 1008-0087-00005E93
dd_time : 0.0 secs
dd_count : 0
timeout : 0.0 secs
On_timer_q? : N
On_dd_q? : N
lock_state : GRANTED
ast_flag : 0x0
Open Options : KJUSERDEADLOCK
Convert options : KJUSERNOQUEUE KJUSERNODEADLOCKWAIT
History : 0x14951495
Msg_Seq : 0x0
res_seq : 474
valblk : 0x0000000000000004ffffffff7fffc090 .
user session for deadlock lock 0xb9db2ffc0
sid: 1564 ser: 24011 audsid: 526700481 user: 95/PRDMMIS
flags: (0x210041) USR/- flags_idl: (0x1) BSY/-/-/-/-/-
flags2: (0x40009) -/-/INC
pid: 135 O/S info: user: oracle, term: UNKNOWN, ospid: 58132
image: oracle@hcs391chprpd301 (J002)
client details:
O/S info: user: oracle, term: UNKNOWN, ospid: 58132
machine: hcs391chprpd301 program: oracle@hcs391chprpd301 (J002)
application name: RAInbound Count:182, hash value=2494290731
action name: Claim Count: 3, hash value=708318624
current SQL:
UPDATE AD_CLM_LN_DERIVED_ELEMENT SET CHECK_DATE = :B6 , CHECK_NMBR = :B5 , PAY_ORDER_DATE = :B4 , EFT_TRACE_NMBR = :B3 , MODIFIED_BY = :B2 , MODIFIED_DATE = SYSDATE WHERE CLAIM_LINE_SID = :B1
DUMP LOCAL BLOCKER: initiate state dump for DEADLOCK
possible owner[135.58132] on resource TX-00BC0005-000C5CC3
*** 2014-02-26 02:21:09.142
Submitting asynchronized dump request [28]. summary=[ges process stack dump (kjdglblkrdm1)].
Local hanganalyze find 1 local blockers blocking this session (pid=58132 sid=1564).
Dumping blocker#0 (pid=58209 sid=1642)
DUMP LOCAL BLOCKER: initiate state dump for DEADLOCK
possible owner[137.58209] on resource TX-00BC0005-000C5CC3
*** 2014-02-26 02:21:09.142
Submitting asynchronized dump request [28]. summary=[ges process stack dump (kjdglblkrdm1)].
DUMP LOCAL BLOCKER/HOLDER: block level 3 res [0x69001a][0x27108d],[TX][ext 0x1,0x0]
----------resource b9b93df28----------------------
resname : [0x69001a][0x27108d],[TX][ext 0x1,0x0]
hash mask : x3
Local inst : 1
dir_inst : 1
master_inst : 1
hv idx : 6
hv last r.inc : 4
current inc : 4
hv status : 0
hv master : 1
open options : dd
grant_bits : KJUSERNL KJUSEREX
grant mode : KJUSERNL KJUSERCR KJUSERCW KJUSERPR KJUSERPW KJUSEREX
count : 1 0 0 0 0 1
val_state : KJUSERVS_NOVALUE
valblk : 0x0101ffff7d3460380000000107f2a6c0 .}4`8
access_inst : 1
vbreq_state : 0
state : x0
resp : b9b93df28
On Scan_q? : N
Total accesses: 4351
Imm. accesses: 3192
Granted_locks : 1
Cvting_locks : 1
value_block: 01 01 ff ff 7d 34 60 38 00 00 00 01 07 f2 a6 c0
GRANTED_Q :
lp b9bed3128 gl KJUSEREX rp b9b93df28 [0x69001a][0x27108d],[TX][ext 0x1,0x0]
master 1 gl owner b94cdd100 possible pid 58209 xid 1008-0089-00003490 bast 0 rseq 517 mseq 0 history 0x49ab5495
open opt KJUSERDEADLOCK
CONVERT_Q:
lp b9fd430c8 gl KJUSERNL rl KJUSERPR rp b9b93df28 [0x69001a][0x27108d],[TX][ext 0x1,0x0]
master 1 gl owner b9eccc438 possible pid 58132 xid 1008-0087-00005E93 bast 0 rseq 517 mseq 0 history 0x49ab549a
convert opt KJUSERGETVALUE
----------enqueue b9bed3128------------------------
lock version : 1355107
Owner inst : 1
grant_level : KJUSEREX
req_level : KJUSEREX
bast_level : KJUSERNL
notify_func : 0
resp : b9b93df28
procp : b973c4d68
pid : 58220
proc version : 296
oprocp : 0
opid : 58220
group lock owner : b94cdd100
possible pid : 58209
xid : 1008-0089-00003490
dd_time : 0.0 secs
dd_count : 0
timeout : 0.0 secs
On_timer_q? : N
On_dd_q? : N
lock_state : GRANTED
ast_flag : 0x0
Open Options : KJUSERDEADLOCK
Convert options : KJUSERNOQUEUE KJUSERNODEADLOCKWAIT
History : 0x49ab5495
Msg_Seq : 0x0
res_seq : 517
valblk : 0xffffffff7fffb53100000001016172c8 .1ar
user session for deadlock lock 0xb9bed3128
sid: 1642 ser: 61257 audsid: 526700266 user: 95/PRDMMIS
flags: (0x210041) USR/- flags_idl: (0x1) BSY/-/-/-/-/-
flags2: (0x40009) -/-/INC
pid: 137 O/S info: user: oracle, term: UNKNOWN, ospid: 58209
image: oracle@hcs391chprpd301 (J004)
client details:
O/S info: user: oracle, term: UNKNOWN, ospid: 58209
machine: hcs391chprpd301 program: oracle@hcs391chprpd301 (J004)
application name: RAInbound Count:453, hash value=1224572795
action name: Claim Count: 27, hash value=3113471375
current SQL:
UPDATE AD_CLM_HDR_DERIVED_ELEMENT SET CHECK_DATE = :B7 , CHECK_NMBR = :B6 , PAY_ORDER_DATE = :B5 , PYMNT_CYCLE_DATE = NVL2 (:B4 , :B4 , PYMNT_CYCLE_DATE), EFT_TRACE_NMBR = :B3 , MODIFIED_BY = :B2 , MODIFIED_DATE = SYSDATE WHERE CLAIM_HEADER_SID = :B1
DUMP LOCAL BLOCKER: initiate state dump for DEADLOCK
possible owner[137.58209] on resource TX-0069001A-0027108D
*** 2014-02-26 02:21:09.144
Submitting asynchronized dump request [28]. summary=[ges process stack dump (kjdglblkrdm1)].
DUMP LOCAL BLOCKER/HOLDER: block level 3 res [0xb10012][0x1e32bd],[TX][ext 0x1,0x0]
----------resource b9d5b90e0----------------------
resname : [0xb10012][0x1e32bd],[TX][ext 0x1,0x0]
hash mask : x3
Local inst : 1
dir_inst : 1
master_inst : 1
hv idx : 46
hv last r.inc : 4
current inc : 4
hv status : 0
hv master : 1
open options : dd
grant_bits : KJUSERNL KJUSEREX
grant mode : KJUSERNL KJUSERCR KJUSERCW KJUSERPR KJUSERPW KJUSEREX
count : 1 0 0 0 0 1
val_state : KJUSERVS_NOVALUE
valblk : 0x0101ffff7d3460380000000107f2a6c0 .}4`8
access_inst : 1
vbreq_state : 0
state : x0
resp : b9d5b90e0
On Scan_q? : N
Total accesses: 6667
Imm. accesses: 5992
Granted_locks : 1
Cvting_locks : 1
value_block: 01 01 ff ff 7d 34 60 38 00 00 00 01 07 f2 a6 c0
GRANTED_Q :
lp b9fd42ef8 gl KJUSEREX rp b9d5b90e0 [0xb10012][0x1e32bd],[TX][ext 0x1,0x0]
master 1 gl owner b94c86588 possible pid 58106 xid 1008-0084-0000993A bast 0 rseq 393 mseq 0 history 0x14951495
open opt KJUSERDEADLOCK
CONVERT_Q:
lp b97dd6460 gl KJUSERNL rl KJUSERPR rp b9d5b90e0 [0xb10012][0x1e32bd],[TX][ext 0x1,0x0]
master 1 gl owner b94cdd100 possible pid 58209 xid 1008-0089-00003490 bast 0 rseq 393 mseq 0 history 0x49ab549a
convert opt KJUSERGETVALUE
----------enqueue b9fd42ef8------------------------
lock version : 964969
Owner inst : 1
grant_level : KJUSEREX
req_level : KJUSEREX
bast_level : KJUSERNL
notify_func : 0
resp : b9d5b90e0
procp : b9739cab8
pid : 58132
proc version : 449
oprocp : 0
opid : 58132
group lock owner : b94c86588
possible pid : 58106
xid : 1008-0084-0000993A
dd_time : 0.0 secs
dd_count : 0
timeout : 0.0 secs
On_timer_q? : N
On_dd_q? : N
lock_state : GRANTED
ast_flag : 0x0
Open Options : KJUSERDEADLOCK
Convert options : KJUSERNOQUEUE KJUSERNODEADLOCKWAIT
History : 0x14951495
Msg_Seq : 0x0
res_seq : 393
valblk : 0xffffffff7fffb53100000001016172c8 .1ar
user session for deadlock lock 0xb9fd42ef8
sid: 1445 ser: 52997 audsid: 526700379 user: 95/PRDMMIS
flags: (0x210041) USR/- flags_idl: (0x1) BSY/-/-/-/-/-
flags2: (0x40009) -/-/INC
pid: 132 O/S info: user: oracle, term: UNKNOWN, ospid: 58106
image: oracle@hcs391chprpd301 (J000)
client details:
O/S info: user: oracle, term: UNKNOWN, ospid: 58106
machine: hcs391chprpd301 program: oracle@hcs391chprpd301 (J000)
application name: RAInbound Count:454, hash value=1060838266
action name: Claim Count: 0, hash value=1122187447
current SQL:
UPDATE AD_CLM_LN_DERIVED_ELEMENT SET CHECK_DATE = :B6 , CHECK_NMBR = :B5 , PAY_ORDER_DATE = :B4 , EFT_TRACE_NMBR = :B3 , MODIFIED_BY = :B2 , MODIFIED_DATE = SYSDATE WHERE CLAIM_LINE_SID = :B1
DUMP LOCAL BLOCKER: initiate state dump for DEADLOCK
possible owner[132.58106] on resource TX-00B10012-001E32BD
*** 2014-02-26 02:21:09.146
Submitting asynchronized dump request [28]. summary=[ges process stack dump (kjdglblkrdm1)].
Global blockers dump end:-----------------------------------
Global Wait-For-Graph(WFG) at ddTS[0.24aa] :
BLOCKED 0xb9da9bac0 3 wq 2 cvtops x1 TX 0xbc0005.0xc5cc3(ext 0x1,0x0)[1008-0084-0000993A] inst 1
BLOCKER 0xb9db2ffc0 3 wq 1 cvtops x28 TX 0xbc0005.0xc5cc3(ext 0x1,0x0)[1008-0087-00005E93] inst 1
BLOCKED 0xb9fd430c8 3 wq 2 cvtops x1 TX 0x69001a.0x27108d(ext 0x1,0x0)[1008-0087-00005E93] inst 1
BLOCKER 0xb9bed3128 3 wq 1 cvtops x28 TX 0x69001a.0x27108d(ext 0x1,0x0)[1008-0089-00003490] inst 1
BLOCKED 0xb97dd6460 3 wq 2 cvtops x1 TX 0xb10012.0x1e32bd(ext 0x1,0x0)[1008-0089-00003490] inst 1
BLOCKER 0xb9fd42ef8 3 wq 1 cvtops x28 TX 0xb10012.0x1e32bd(ext 0x1,0x0)[1008-0084-0000993A] inst 1
*** 2014-02-26 02:21:10.146
* Cancel deadlock victim lockp 0xb9da9bac0