This discussion is archived
1 2 Previous Next 19 Replies Latest reply: Nov 6, 2012 4:22 AM by orausern RSS

Cause of Deadlock

orausern Explorer
Currently Being Moderated
Hi Experts,
I am on Oracle 11.2.0.2 on Linux. In my database, there is a deadlock reported and I am not able to find out reason for it or even which two different sessions participated in it. Following is the info from the deadlock trace file. I will be thankful for any pointers on the cause of the issue.
 
*** 2012-10-25 15:38:06.189 
ENQUEUE DUMP REQUEST: from 2 spnum 12 on [0xa001f][0x33e15],[TX][ext 0x2,0x0] for reason 3 mtype 0 
DUMP LOCAL BLOCKER/HOLDER: block level 3 res [0xa001f][0x33e15],[TX][ext 0x2,0x0] 
----------resource 0xdd61cea0---------------------- 
resname       : [0xa001f][0x33e15],[TX][ext 0x2,0x0] 
hash mask     : x3 
Local inst    : 1 
dir_inst      : 1 
master_inst   : 1 
hv idx        : 8 
hv last r.inc : 8 
current inc   : 8 
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        : 0x00000000000000000000000000000000 . 
access_inst   : 1 
vbreq_state   : 0 
state         : x0 
resp          : 0xdd61cea0 
On Scan_q?    : N 
Total accesses: 6860 
Imm.  accesses: 6057 
Granted_locks : 1 
Cvting_locks  : 1 
value_block:  00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 
GRANTED_Q : 
lp 0xcb4fabd0 gl KJUSEREX rp 0xdd61cea0 [0xa001f][0x33e15],[TX][ext 0x2,0x0] 
  master 1 gl owner 0xd4c45958 possible pid 582 xid 77000-0001-00000C6F bast 0 rseq 767 mseq 0 history 0xd497d495 
  open opt KJUSERDEADLOCK   
CONVERT_Q: 
lp 0xcc5dae48 gl KJUSERNL rl KJUSERPR rp 0xdd61cea0 [0xa001f][0x33e15],[TX][ext 0x2,0x0] 
  master 1 owner 2  bast 1 rseq 264 mseq 0x1 history 0x77d497ad 
  convert opt KJUSERGETVALUE   
----------enqueue 0xcb4fabd0------------------------ 
lock version     : 535 
Owner inst       : 1 
grant_level      : KJUSEREX 
req_level        : KJUSEREX 
bast_level       : KJUSERNL 
notify_func      : (nil) 
resp             : 0xdd61cea0 
procp            : 0xdcf1f730 
pid              : 18995 
proc version     : 0 
oprocp           : (nil) 
opid             : 18995 
group lock owner : 0xd4c45958 
possible pid     : 582 
xid              : 77000-0001-00000C6F 
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          : 0xd497d495 
Msg_Seq          : 0x0 
res_seq          : 767 
valblk           : 0x00000000000000000000000000000000 . 
user session for deadlock lock 0xcb4fabd0 <----this seems to be the same session as below and I dont see info of any other session 
  sid: 349 ser: 12203 audsid: 102101678 user: 72/PORTALWFN45_ACS 
    flags: (0x41) USR/- flags_idl: (0x1) BSY/-/-/-/-/- 
    flags2: (0x40009) -/-/INC 
  pid: 119 O/S info: user: grid, term: UNKNOWN, ospid: 582 
    image: oracle@cdlt3f002db01 
  client details: 
    O/S info: user: wasadmin, term: unknown, ospid: 1234 
    machine: cdldvjassvap048.nj.adp.com program: JDBC Thin Client 
    application name: JDBC Thin Client, hash value=2546894660 
  current SQL: 
    INSERT INTO ACCESS_CLNT_GRP_XRF (CLNT_OID, GRP_ID, INCLUDED, ADDED_MANUALLY, CREATED_DATE, CREATED_BY) SELECT DISTINCT X.CLNT_OID, X.GRP_OID, :"SYS_B_0" AS INCLUDED, :"SYS_B_1" AS ADDED_MANUALLY, SYSDATE AS CREATED_DATE, :1  AS CREATED_BY  FROM ACCESS_CLNT_GRP_RULE_XRF X WHERE X.GRP_ID = :2  AND NOT EXISTS (SELECT :"SYS_B_2" FROM ACCESS_CLNT_GRP_XRF UG WHERE UG.CLNT_OID= X.CLNT_OID AND UG.GRP_ID= X.GRP_ID) 
DUMP LOCAL BLOCKER: initiate state dump for DEADLOCK 
  possible owner[119.582] on resource TX-000A001F-00033E15 

*** 2012-10-25 15:38:06.190 
Submitting asynchronized dump request [28]. summary=[ges process stack dump (kjdglblkrdm1)]. 
Global blockers dump start:--------------------------------- 
DUMP LOCAL BLOCKER/HOLDER: block level 3 res [0x170011][0x10ab5],[TX][ext 0x4,0x0] 
----------resource 0xda168d40---------------------- 
resname       : [0x170011][0x10ab5],[TX][ext 0x4,0x0] 
hash mask     : x3 
Local inst    : 1 
dir_inst      : 2 
master_inst   : 2 
hv idx        : 26 
hv last r.inc : 8 
current inc   : 8 
hv status     : 0 
hv master     : 1 
open options  : dd 
Held mode     : KJUSERNL 
Cvt mode      : KJUSERPR 
Next Cvt mode : KJUSERNL 
msg_seq       : 0x1 
res_seq       : 290 
grant_bits    : KJUSERNL 
grant mode    : KJUSERNL  KJUSERCR  KJUSERCW  KJUSERPR  KJUSERPW  KJUSEREX 
count         : 1         0         0         0         0         0 
val_state     : KJUSERVS_NOVALUE 
valblk        : 0x70529d50ff7f00000000000000000000 pRP 
access_inst   : 2 
vbreq_state   : 0 
state         : x8 
resp          : 0xda168d40 
On Scan_q?    : N 
Total accesses: 8496 
Imm.  accesses: 7633 
Granted_locks : 0 
Cvting_locks  : 1 
value_block:  70 52 9d 50 ff 7f 00 00 00 00 00 00 00 00 00 00 
GRANTED_Q : 
CONVERT_Q: 
lp 0xdb922560 gl KJUSERNL rl KJUSERPR rp 0xda168d40 [0x170011][0x10ab5],[TX][ext 0x4,0x0] 
  master 2 gl owner 0xdf73f828 possible pid 582 xid 77000-0001-00000C6F bast 0 rseq 290 mseq 0 history 0x495149da 
  convert opt KJUSERGETVALUE   
DUMP LOCAL BLOCKER/HOLDER: block level 3 res [0xa001f][0x33e15],[TX][ext 0x2,0x0] 
----------resource 0xdd61cea0---------------------- 
resname       : [0xa001f][0x33e15],[TX][ext 0x2,0x0] 
hash mask     : x3 
Local inst    : 1 
dir_inst      : 1 
master_inst   : 1 
hv idx        : 8 
hv last r.inc : 8 
current inc   : 8 
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        : 0x70529d50ff7f00000000000000000000 pRP 
access_inst   : 1 
vbreq_state   : 0 
state         : x0 
resp          : 0xdd61cea0 
On Scan_q?    : N 
Total accesses: 6862 
Imm.  accesses: 6058 
Granted_locks : 1 
Cvting_locks  : 1 
value_block:  70 52 9d 50 ff 7f 00 00 00 00 00 00 00 00 00 00 
GRANTED_Q : 
lp 0xcb4fabd0 gl KJUSEREX rp 0xdd61cea0 [0xa001f][0x33e15],[TX][ext 0x2,0x0] 
  master 1 gl owner 0xd4c45958 possible pid 582 xid 77000-0001-00000C6F bast 0 rseq 767 mseq 0 history 0xd497d495 
  open opt KJUSERDEADLOCK   
CONVERT_Q: 
lp 0xcc5dae48 gl KJUSERNL rl KJUSERPR rp 0xdd61cea0 [0xa001f][0x33e15],[TX][ext 0x2,0x0] 
  master 1 owner 2  bast 1 rseq 264 mseq 0x1 history 0x77d497ad 
  convert opt KJUSERGETVALUE   
----------enqueue 0xcb4fabd0------------------------ 
lock version     : 535 
Owner inst       : 1 
grant_level      : KJUSEREX 
req_level        : KJUSEREX 
bast_level       : KJUSERNL 
notify_func      : (nil) 
resp             : 0xdd61cea0 
procp            : 0xdcf1f730 
pid              : 18995 
proc version     : 0 
oprocp           : (nil) 
opid             : 18995 
group lock owner : 0xd4c45958 
possible pid     : 582 
xid              : 77000-0001-00000C6F 
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          : 0xd497d495 
Msg_Seq          : 0x0 
res_seq          : 767 
valblk           : 0x00000000000000003100050200000000 .1 
user session for deadlock lock 0xcb4fabd0 <----this seems to be the same session as above and I dont see info of any other session 
  sid: 349 ser: 12203 audsid: 102101678 user: 72/PORTALWFN45_ACS 

  sid: 349 ser: 12203 audsid: 102101678 user: 72/PORTALWFN45_ACS 
    flags: (0x41) USR/- flags_idl: (0x1) BSY/-/-/-/-/- 
    flags2: (0x40009) -/-/INC 
  pid: 119 O/S info: user: grid, term: UNKNOWN, ospid: 582 
    image: oracle@cdlt3f002db01 
  client details: 
    O/S info: user: wasadmin, term: unknown, ospid: 1234 
    machine: cdldvjassvap048.nj.adp.com program: JDBC Thin Client 
    application name: JDBC Thin Client, hash value=2546894660 
  current SQL: 
  INSERT INTO ACCESS_CLNT_GRP_XRF (CLNT_OID, GRP_ID, INCLUDED, ADDED_MANUALLY, CREATED_DATE, CREATED_BY) SELECT DISTINCT X.CLNT_OID, X.GRP_OID, :"SYS_B_0" AS INCLUDED, :"SYS_B_1" AS ADDED_MANUALLY, SYSDATE AS CREATED_DATE, :1  AS CREATED_BY  FROM ACCESS_CLNT_GRP_RULE_XRF X WHERE X.GRP_ID = :2  AND NOT EXISTS (SELECT :"SYS_B_2" FROM ACCESS_CLNT_GRP_XRF UG WHERE UG.CLNT_OID= X.CLNT_OID AND UG.GRP_ID= X.GRP_ID) 
DUMP LOCAL BLOCKER: initiate state dump for DEADLOCK 
  possible owner[119.582] on resource TX-000A001F-00033E15 

*** 2012-10-25 15:38:06.191 
Submitting asynchronized dump request [28]. summary=[ges process stack dump (kjdglblkrdm1)]. 
Global blockers dump end:----------------------------------- 
Global Wait-For-Graph(WFG) at ddTS[0.8a] : 
BLOCKED 0xdb922560 3 wq 2 cvtops x1 TX 0x170011.0x10ab5(ext 0x4,0x0)[77000-0001-00000C6F] inst 1 
BLOCKER 0xdb339ad0 3 wq 1 cvtops x28 TX 0x170011.0x10ab5(ext 0x4,0x0)[71000-0002-00002D5B] inst 2 
BLOCKED 0xdb7f3648 3 wq 2 cvtops x1 TX 0xa001f.0x33e15(ext 0x2,0x0)[71000-0002-00002D5B] inst 2 
BLOCKER 0xcb4fabd0 3 wq 1 cvtops x28 TX 0xa001f.0x33e15(ext 0x2,0x0)[77000-0001-00000C6F] inst 1 

*** 2012-10-25 15:38:07.113 
* Cancel deadlock victim lockp 0xdb922560 
2012-10-25 17:26:16.039638 : Setting 3-way CR grants to 0 global-lru off? 0 

*** 2012-10-25 17:27:49.961 
2012-10-25 17:27:49.961892 : Setting 3-way CR grants to 1 global-lru off? 0 
2012-10-25 17:52:42.505182 : Setting 3-way CR grants to 1 global-lru off? 0 
* received DRM start msg from 2 (cnt 1, last 1, rmno 50) 

*** 2012-10-25 19:16:31.443 
Rcvd DRM(50) AFFINITY Transfer pkey 88431.0 from 1 to 2 oscan 1.1 
ftd (30) received from node 2 (8 0.31/0.0) 
all ftds received 
ftd (33) received from node 2 (8 0.32/0.0) 
all ftds received 

* kjxftdn: break from kjxftdn, post lmon later 
ftd (35) received from node 2 (8 0.36/0.0) 
all ftds received 
ftd (37) received from node 2 (8 0.38/0.0) 
all ftds received 
ftd (30) received from node 2 (8 0.31/0.0) 
all ftds received 
ftd (33) received from node 2 (8 0.33/0.0) 
all ftds received 

* kjxftdn: break from kjxftdn, post lmon later 
ftd (35) received from node 2 (8 0.36/0.0) 
all ftds received 
ftd (37) received from node 2 (8 0.38/0.0) 
all ftds received 
ftd (30) received from node 2 (8 0.31/0.0) 
all ftds received 
ftd (33) received from node 2 (8 0.33/0.0) 
all ftds received 

* kjxftdn: break from kjxftdn, post lmon later 
ftd (35) received from node 2 (8 0.36/0.0) 
all ftds received 
ftd (37) received from node 2 (8 0.38/0.0) 
all ftds received 
ftd (30) received from node 2 (8 0.31/0.0) 
all ftds received 
ftd (33) received from node 2 (8 0.33/0.0) 
all ftds received 

* kjxftdn: break from kjxftdn, post lmon later 
ftd (35) received from node 2 (8 0.36/0.0) 
all ftds received 
ftd (37) received from node 2 (8 0.37/0.0) 
all ftds received 

* kjxftdn: break from kjxftdn, post lmon later 
ftd (30) received from node 2 (8 0.31/0.0) 
all ftds received 
ftd (33) received from node 2 (8 0.32/0.0) 
all ftds received 

* kjxftdn: break from kjxftdn, post lmon later 
ftd (35) received from node 2 (8 0.36/0.0) 
all ftds received 
ftd (37) received from node 2 (8 0.38/0.0) 
all ftds received 
ftd (30) received from node 2 (8 0.31/0.0) 
all ftds received 
ftd (33) received from node 2 (8 0.33/0.0) 
all ftds received 

* kjxftdn: break from kjxftdn, post lmon later 
ftd (35) received from node 2 (8 0.36/0.0) 
all ftds received 
ftd (37) received from node 2 (8 0.38/0.0) 
all ftds received 
ftd (30) received from node 2 (8 0.31/0.0) 
all ftds received 
ftd (33) received from node 2 (8 0.33/0.0) 
all ftds received 

* kjxftdn: break from kjxftdn, post lmon later 
ftd (35) received from node 2 (8 0.36/0.0) 
all ftds received 
ftd (37) received from node 2 (8 0.38/0.0) 
all ftds received 
ftd (30) received from node 2 (8 0.31/0.0) 
all ftds received 
ftd (33) received from node 2 (8 0.33/0.0) 
all ftds received 

* kjxftdn: break from kjxftdn, post lmon later 
ftd (35) received from node 2 (8 0.36/0.0) 
all ftds received 
ftd (37) received from node 2 (8 0.38/0.0) 
all ftds received 
2012-10-25 19:16:31.687987 : 
End DRM(50) for pkey transfer request(s) from 2 
stale cvak(res) fr 2:0xdfff5898([0x1978f378][0x8fba1c6e],[LB][ext 0x0,0x0])[h=KJUSERNL,n=KJUSEREX,b=KJUSERNL,ls=KJUSERSTAT_NOVALUE]mseq:0x10003(msg),0x0(resp)rseq:0x416(msg),0x417(resp) 

*** 2012-10-25 22:06:03.671 
----------resource 0xdfff5898---------------------- 
resname       : [0x1978f378][0x8fba1c6e],[LB][ext 0x0,0x0] 
hash mask     : x3 
Local inst    : 1 
dir_inst      : 2 
master_inst   : 2 
hv idx        : 50 
hv last r.inc : 8 
current inc   : 8 
hv status     : 0 
hv master     : 1 
open options  : dd 
Held mode     : KJUSERNL 
Cvt mode      : KJUSERPR 
Next Cvt mode : KJUSERNL 
msg_seq       : (nil) 
res_seq       : 1047 
grant_bits    : KJUSERNL 
grant mode    : KJUSERNL  KJUSERCR  KJUSERCW  KJUSERPR  KJUSERPW  KJUSEREX 
count         : 1         0         0         0         0         0 
val_state     : KJUSERVS_NOVALUE 
valblk        : 0x94160ec3eccc040094160ec3eccc0400 . 
access_inst   : 2 
vbreq_state   : 0 
state         : x4 
resp          : 0xdfff5898 
On Scan_q?    : N 
Total accesses: 13084 
Imm.  accesses: 11996 
Granted_locks : 0 
Cvting_locks  : 1 
value_block:  94 16 0e c3 ec cc 04 00 94 16 0e c3 ec cc 04 00 
GRANTED_Q : 
CONVERT_Q: 
lp 0xdb6588d0 gl KJUSERNL rl KJUSERPR rp 0xdfff5898 [0x1978f378][0x8fba1c6e],[LB][ext 0x0,0x0] 
  master 2 gl owner 0xdc5d6240 possible pid 6224 xid 4B000-0001-000012F8 bast 0 rseq 1047 mseq 0 history 0x495149da 
  convert opt   
MSG [16:KJX_CONV_AST_IND] [0x1978f378][0x8fba1c6e],[LB][ext 0x0,0x0] RMno=65706 inc=8 len=112 sender=(2,2) seq=0 
     fg=p stat=KJUSERSTAT_NOVALUE spnum=12 flg=x0 
    flow ctrl: ver=8 flag=161 len=112 tkts=0 seq=0 wrp=0 
               sndr=2 dest=1 rcvr=0 
     rseq x416 mseq x10003 copts x1 hl 5 cl 0 nl 0 
     valblk 0x01000000815f93600000000000000000 ._` 
stale cvak(res) fr 2:0xdfff5898([0x1978f378][0x8fba1c6e],[LB][ext 0x0,0x0])[h=KJUSERNL,n=KJUSEREX,b=KJUSERPR,ls=KJUSERSTAT_NOVALUE]mseq:0x10004(msg),0x0(resp)rseq:0x416(msg),0x417(resp) 
----------resource 0xdfff5898---------------------- 
resname       : [0x1978f378][0x8fba1c6e],[LB][ext 0x0,0x0] 
hash mask     : x3 
Local inst    : 1 
dir_inst      : 2 
master_inst   : 2 
hv idx        : 50 
hv last r.inc : 8 
current inc   : 8 
hv status     : 0 
hv master     : 1 
open options  : dd 
Held mode     : KJUSERNL 
Cvt mode      : KJUSERPR 
Next Cvt mode : KJUSERNL 
msg_seq       : (nil) 
res_seq       : 1047 
grant_bits    : KJUSERNL 
grant mode    : KJUSERNL  KJUSERCR  KJUSERCW  KJUSERPR  KJUSERPW  KJUSEREX 
count         : 1         0         0         0         0         0 
val_state     : KJUSERVS_NOVALUE 
valblk        : 0x24000000000000000008000000000000 $ 
access_inst   : 2 
vbreq_state   : 0 
state         : x4 
resp          : 0xdfff5898 
On Scan_q?    : N 
Total accesses: 13085 
Imm.  accesses: 11997 
Granted_locks : 0 
Cvting_locks  : 1 
value_block:  24 00 00 00 00 00 00 00 00 08 00 00 00 00 00 00 
GRANTED_Q : 
CONVERT_Q: 
lp 0xdb6588d0 gl KJUSERNL rl KJUSERPR rp 0xdfff5898 [0x1978f378][0x8fba1c6e],[LB][ext 0x0,0x0] 
  master 2 gl owner 0xdc5d6240 possible pid 6224 xid 4B000-0001-000012F8 bast 0 rseq 1047 mseq 0 history 0x495149da 
  convert opt   
MSG [16:KJX_CONV_AST_IND] [0x1978f378][0x8fba1c6e],[LB][ext 0x0,0x0] RMno=3 inc=8 len=112 sender=(2,2) seq=0 
     fg=p stat=KJUSERSTAT_NOVALUE spnum=12 flg=xc 
    flow ctrl: ver=-106 flag=161 len=112 tkts=0 seq=0 wrp=0 
               sndr=2 dest=1 rcvr=0 
     rseq x416 mseq x10004 copts x0 hl 5 cl 0 nl 3 
     valblk 0x0000000000a907006800000000000000 .h 
kjddt2vb: valblk  [0.8c] > local ts [0.8b] 

*** 2012-10-25 22:16:54.817 
Begin DRM(51) (swin 0) - AFFINITY transfer pkey 88431.0 to 1 oscan 0.1 
kjiobjscn 1 
ftd (30) received from node 2 (8 0.0/0.0) 
all ftds received 

* kjxftdn: break from kjxftdn, post lmon later 
ftd (33) received from node 2 (8 0.32/0.0) 
all ftds received 

* kjxftdn: break from kjxftdn, post lmon later 
ftd (37) received from node 2 (8 0.36/0.0) 
all ftds received 
ftd (35) received from node 2 (8 0.36/0.0) 
all ftds received 

* kjxftdn: break from kjxftdn, post lmon later 
ftd (30) received from node 2 (8 0.30/0.0) 
all ftds received 

* kjxftdn: break from kjxftdn, post lmon later 
ftd (33) received from node 2 (8 0.34/0.0) 
all ftds received 
ftd (37) received from node 2 (8 0.36/0.0) 
all ftds received 
ftd (35) received from node 2 (8 0.36/0.0) 
all ftds received 

* kjxftdn: break from kjxftdn, post lmon later 
ftd (30) received from node 2 (8 0.30/0.0) 
all ftds received 

* kjxftdn: break from kjxftdn, post lmon later 
ftd (33) received from node 2 (8 0.34/0.0) 
all ftds received 
ftd (35) received from node 2 (8 0.36/0.0) 
all ftds received 
ftd (37) received from node 2 (8 0.37/0.0) 
all ftds received 

* kjxftdn: break from kjxftdn, post lmon later 
ftd (30) received from node 2 (8 0.31/0.0) 
all ftds received 
ftd (33) received from node 2 (8 0.34/0.0) 
all ftds received 
ftd (35) received from node 2 (8 0.36/0.0) 
all ftds received 
ftd (37) received from node 2 (8 0.37/0.0) 
all ftds received 

* kjxftdn: break from kjxftdn, post lmon later 
ftd (30) received from node 2 (8 0.31/0.0) 
all ftds received 
ftd (33) received from node 2 (8 0.34/0.0) 
all ftds received 
ftd (37) received from node 2 (8 0.36/0.0) 
all ftds received 
ftd (35) received from node 2 (8 0.36/0.0) 
all ftds received 
ftd (30) received from node 2 (8 0.31/0.0) 
all ftds received 
ftd (33) received from node 2 (8 0.34/0.0) 
all ftds received 
ftd (37) received from node 2 (8 0.36/0.0) 
all ftds received 
ftd (35) received from node 2 (8 0.36/0.0) 
all ftds received 
ftd (30) received from node 2 (8 0.30/0.0) 
all ftds received 

* kjxftdn: break from kjxftdn, post lmon later 
ftd (33) received from node 2 (8 0.34/0.0) 
all ftds received 
ftd (37) received from node 2 (8 0.36/0.0) 
all ftds received 
ftd (35) received from node 2 (8 0.36/0.0) 
all ftds received 
ftd (30) received from node 2 (8 0.30/0.0) 
all ftds received 

* kjxftdn: break from kjxftdn, post lmon later 
ftd (33) received from node 2 (8 0.34/0.0) 
all ftds received 
ftd (37) received from node 2 (8 0.36/0.0) 
all ftds received 
ftd (35) received from node 2 (8 0.36/0.0) 
all ftds received 

* kjxftdn: break from kjxftdn, post lmon later 
2012-10-25 22:16:55.112752 : 

* End DRM for pkey remastering request(s) (locally requested) 

*** 2012-10-25 22:22:35.175 
2012-10-25 22:22:35.175781 : Setting 3-way CR grants to 0 global-lru off? 0 

*** 2012-10-25 22:24:09.000 
2012-10-25 22:24:09.000900 : Setting 3-way CR grants to 1 global-lru off? 0 
2012-10-25 22:29:20.348861 : Setting 3-way CR grants to 1 global-lru off? 0 
2012-10-25 23:15:02.016255 : Setting 3-way CR grants to 0 global-lru off? 0 

*** 2012-10-25 23:16:05.212 
2012-10-25 23:16:05.212156 : Setting 3-way CR grants to 1 global-lru off? 0 

*** 2012-10-25 23:16:36.041 
2012-10-25 23:16:36.041650 : Setting 3-way CR grants to 0 global-lru off? 0 

*** 2012-10-25 23:18:10.146 
2012-10-25 23:18:10.146473 : Setting 3-way CR grants to 1 global-lru off? 0 

*** 2012-10-25 23:23:24.514 
2012-10-25 23:23:24.514488 : Setting 3-way CR grants to 0 global-lru off? 0 

*** 2012-10-25 23:24:26.699 
2012-10-25 23:24:26.699355 : Setting 3-way CR grants to 1 global-lru off? 0 
2012-10-25 23:32:11.212627 : Setting 3-way CR grants to 0 global-lru off? 0 

*** 2012-10-25 23:33:13.028 
2012-10-25 23:33:13.028646 : Setting 3-way CR grants to 1 global-lru off? 0 

*** 2012-10-25 23:36:22.121 
2012-10-25 23:36:22.121783 : Setting 3-way CR grants to 0 global-lru off? 0 

*** 2012-10-25 23:36:58.785 
* received DRM start msg from 2 (cnt 1, last 1, rmno 52) 
Rcvd DRM(52) AFFINITY Transfer pkey 88431.0 from 1 to 2 oscan 1.1 

*** 2012-10-25 23:36:58.875 
ftd (30) received from node 2 (8 0.31/0.0) 
all ftds received 
ftd (33) received from node 2 (8 0.33/0.0) 
all ftds received 

* kjxftdn: break from kjxftdn, post lmon later 
ftd (35) received from node 2 (8 0.36/0.0) 
all ftds received 
ftd (37) received from node 2 (8 0.37/0.0) 
all ftds received 

* kjxftdn: break from kjxftdn, post lmon later 
ftd (30) received from node 2 (8 0.31/0.0) 
all ftds received 
ftd (33) received from node 2 (8 0.33/0.0) 
all ftds received 

* kjxftdn: break from kjxftdn, post lmon later 
ftd (35) received from node 2 (8 0.36/0.0) 
all ftds received 
ftd (37) received from node 2 (8 0.38/0.0) 
all ftds received 
ftd (30) received from node 2 (8 0.31/0.0) 
all ftds received 
ftd (33) received from node 2 (8 0.32/0.0) 
all ftds received 

* kjxftdn: break from kjxftdn, post lmon later 
ftd (35) received from node 2 (8 0.36/0.0) 
all ftds received 
ftd (37) received from node 2 (8 0.38/0.0) 
all ftds received 
ftd (30) received from node 2 (8 0.31/0.0) 
all ftds received 
ftd (33) received from node 2 (8 0.33/0.0) 
all ftds received 

* kjxftdn: break from kjxftdn, post lmon later 
ftd (35) received from node 2 (8 0.36/0.0) 
all ftds received 
ftd (37) received from node 2 (8 0.38/0.0) 
all ftds received 
ftd (30) received from node 2 (8 0.31/0.0) 
all ftds received 
ftd (33) received from node 2 (8 0.33/0.0) 
all ftds received 

* kjxftdn: break from kjxftdn, post lmon later 
ftd (35) received from node 2 (8 0.36/0.0) 
all ftds received 
ftd (37) received from node 2 (8 0.38/0.0) 
all ftds received 
ftd (30) received from node 2 (8 0.31/0.0) 
all ftds received 
ftd (33) received from node 2 (8 0.33/0.0) 
all ftds received 

* kjxftdn: break from kjxftdn, post lmon later 
ftd (35) received from node 2 (8 0.36/0.0) 
all ftds received 
ftd (37) received from node 2 (8 0.38/0.0) 
all ftds received 
ftd (30) received from node 2 (8 0.31/0.0) 
all ftds received 
ftd (33) received from node 2 (8 0.32/0.0) 
all ftds received 

* kjxftdn: break from kjxftdn, post lmon later 
ftd (35) received from node 2 (8 0.36/0.0) 
all ftds received 
ftd (37) received from node 2 (8 0.38/0.0) 
all ftds received 
ftd (30) received from node 2 (8 0.31/0.0) 
all ftds received 
ftd (33) received from node 2 (8 0.32/0.0) 
all ftds received 

* kjxftdn: break from kjxftdn, post lmon later 
ftd (35) received from node 2 (8 0.36/0.0) 
all ftds received 
ftd (37) received from node 2 (8 0.38/0.0) 
all ftds received 
2012-10-25 23:36:59.124760 : 
End DRM(52) for pkey transfer request(s) from 2 

*** 2012-10-25 23:38:26.130 
2012-10-25 23:38:26.130755 : Setting 3-way CR grants to 1 global-lru off? 0 
2012-10-25 23:58:38.071978 : Setting 3-way CR grants to 0 global-lru off? 0 

*** 2012-10-26 00:00:44.096 
2012-10-26 00:00:44.096005 : Setting 3-way CR grants to 1 global-lru off? 0 

*** 2012-10-26 00:04:22.583 
2012-10-26 00:04:22.583348 : Setting 3-way CR grants to 0 global-lru off? 0 

*** 2012-10-26 00:08:31.315 
2012-10-26 00:08:31.315412 : Setting 3-way CR grants to 1 global-lru off? 0 
2012-10-26 00:20:57.846700 : Setting 3-way CR grants to 0 global-lru off? 0 

*** 2012-10-26 00:25:05.085 
2012-10-26 00:25:05.085042 : Setting 3-way CR grants to 1 global-lru off? 0 
2012-10-26 00:44:17.764966 : Setting 3-way CR grants to 0 global-lru off? 0 

*** 2012-10-26 00:48:25.602 
2012-10-26 00:48:25.602491 : Setting 3-way CR grants to 1 global-lru off? 0 
2012-10-26 01:14:50.222098 : Setting 3-way CR grants to 0 global-lru off? 0 

*** 2012-10-26 01:19:00.590 
2012-10-26 01:19:00.590826 : Setting 3-way CR grants to 1 global-lru off? 0 
2012-10-26 02:44:09.453387 : Setting 3-way CR grants to 0 global-lru off? 0 

*** 2012-10-26 02:49:19.105 
2012-10-26 02:49:19.105284 : Setting 3-way CR grants to 1 global-lru off? 0 
2012-10-26 02:59:41.444548 : Setting 3-way CR grants to 0 global-lru off? 0 

*** 2012-10-26 03:02:47.808 
2012-10-26 03:02:47.808071 : Setting 3-way CR grants to 1 global-lru off? 0 

*** 2012-10-26 03:05:22.310 
2012-10-26 03:05:22.310631 : Setting 3-way CR grants to 0 global-lru off? 0 

*** 2012-10-26 03:07:16.408 
* received DRM start msg from 2 (cnt 2, last 1, rmno 53) 
Rcvd DRM(53) AFFINITY Transfer pkey 74335.0 from 1 to 2 oscan 1.1 
Rcvd DRM(53) AFFINITY Transfer pkey 88398.0 from 1 to 2 oscan 1.1 
ftd (30) received from node 2 (8 0.0/0.0) 
all ftds received 

* kjxftdn: break from kjxftdn, post lmon later 
ftd (33) received from node 2 (8 0.32/0.0) 
all ftds received 

* kjxftdn: break from kjxftdn, post lmon later 
ftd (35) received from node 2 (8 0.36/0.0) 
all ftds received 
ftd (37) received from node 2 (8 0.38/0.0) 
all ftds received 
ftd (30) received from node 2 (8 0.31/0.0) 
all ftds received 
ftd (33) received from node 2 (8 0.33/0.0) 
all ftds received 

* kjxftdn: break from kjxftdn, post lmon later 
ftd (35) received from node 2 (8 0.36/0.0) 
all ftds received 
ftd (37) received from node 2 (8 0.38/0.0) 
all ftds received 
ftd (30) received from node 2 (8 0.31/0.0) 
all ftds received 
ftd (33) received from node 2 (8 0.33/0.0) 
all ftds received 

* kjxftdn: break from kjxftdn, post lmon later 
ftd (35) received from node 2 (8 0.36/0.0) 
all ftds received 
ftd (37) received from node 2 (8 0.38/0.0) 
all ftds received 
ftd (30) received from node 2 (8 0.31/0.0) 
all ftds received 
ftd (33) received from node 2 (8 0.33/0.0) 
all ftds received 

* kjxftdn: break from kjxftdn, post lmon later 
ftd (35) received from node 2 (8 0.36/0.0) 
all ftds received 
ftd (37) received from node 2 (8 0.38/0.0) 
all ftds received 
ftd (30) received from node 2 (8 0.31/0.0) 
all ftds received 
ftd (33) received from node 2 (8 0.33/0.0) 
all ftds received 

* kjxftdn: break from kjxftdn, post lmon later 
ftd (35) received from node 2 (8 0.36/0.0) 
all ftds received 
ftd (37) received from node 2 (8 0.38/0.0) 
all ftds received 
ftd (30) received from node 2 (8 0.31/0.0) 
all ftds received 
ftd (33) received from node 2 (8 0.33/0.0) 
all ftds received 

* kjxftdn: break from kjxftdn, post lmon later 
ftd (35) received from node 2 (8 0.36/0.0) 
all ftds received 
ftd (37) received from node 2 (8 0.38/0.0) 
all ftds received 
ftd (30) received from node 2 (8 0.31/0.0) 
all ftds received 
ftd (33) received from node 2 (8 0.33/0.0) 
all ftds received 

* kjxftdn: break from kjxftdn, post lmon later 
ftd (35) received from node 2 (8 0.36/0.0) 
all ftds received 
ftd (37) received from node 2 (8 0.38/0.0) 
all ftds received 
ftd (30) received from node 2 (8 0.31/0.0) 
all ftds received 
ftd (33) received from node 2 (8 0.33/0.0) 
all ftds received 

* kjxftdn: break from kjxftdn, post lmon later 
ftd (35) received from node 2 (8 0.36/0.0) 
all ftds received 
ftd (37) received from node 2 (8 0.38/0.0) 
all ftds received 
2012-10-26 03:07:16.718164 : 
End DRM(53) for pkey transfer request(s) from 2 

*** 2012-10-26 03:11:35.100 
2012-10-26 03:11:35.100544 : Setting 3-way CR grants to 1 global-lru off? 0 
2012-10-26 03:44:44.666224 : Setting 3-way CR grants to 0 global-lru off? 0 
2012-10-26 04:00:49.272473 : Setting 3-way CR grants to 1 global-lru off? 0 

*** 2012-10-26 04:08:35.037 
2012-10-26 04:08:35.037716 : Setting 3-way CR grants to 0 global-lru off? 0 

*** 2012-10-26 04:11:41.226 
2012-10-26 04:11:41.226172 : Setting 3-way CR grants to 1 global-lru off? 0 
  • 1. Re: Cause of Deadlock
    Osama_Mustafa Oracle ACE
    Currently Being Moderated
    Oracle Solve Deadlock by its own self
  • 2. Re: Cause of Deadlock
    orausern Explorer
    Currently Being Moderated
    >
    Oracle Solve Deadlock by its own self
    >
    Yes! But it will also run into the same issues again and again unless the issue is identified and resolved. For that reason I want to find what could have caused the deadlock. But from the deadlock file, I am not able to make out the reason.

    Thanks,
  • 3. Re: Cause of Deadlock
    Osama_Mustafa Oracle ACE
    Currently Being Moderated
      client details: 
        O/S info: user: wasadmin, term: unknown, ospid: 1234 
        machine: cdldvjassvap048.nj.adp.com program: JDBC Thin Client 
        application name: JDBC Thin Client, hash value=2546894660 
      current SQL: 
        INSERT INTO ACCESS_CLNT_GRP_XRF (CLNT_OID, GRP_ID, INCLUDED, ADDED_MANUALLY, CREATED_DATE, CREATED_BY) SELECT DISTINCT X.CLNT_OID, X.GRP_OID, :"SYS_B_0" AS INCLUDED, :"SYS_B_1" AS ADDED_MANUALLY, SYSDATE AS CREATED_DATE, :1  AS CREATED_BY  FROM ACCESS_CLNT_GRP_RULE_XRF X WHERE X.GRP_ID = :2  AND NOT EXISTS (SELECT :"SYS_B_2" FROM ACCESS_CLNT_GRP_XRF UG WHERE UG.CLNT_OID= X.CLNT_OID AND UG.GRP_ID= X.GRP_ID) 
    DUMP LOCAL BLOCKER: initiate state dump for DEADLOCK 
      possible owner[119.582] on resource TX-000A001F-00033E15 
    Check from this user wasadmin and insert clause , your application caused this deadlock
  • 4. Re: Cause of Deadlock
    orausern Explorer
    Currently Being Moderated
    Yes true! I could make out that this one sql is involved in the deadlock. But my question and doubt here is that, just one session by itself can not cause deadlock right? For deadlock there has to be two sessions whereas here I dont' see two different sessions. So how can a single session cause deadlock?

    Thanks,
  • 5. Re: Cause of Deadlock
    Dom Brooks Guru
    Currently Being Moderated
    BLOCKED 0xdb922560 3 wq 2 cvtops x1 TX 0x170011.0x10ab5(ext 0x4,0x0)[77000-0001-00000C6F] inst 1 
    BLOCKER 0xdb339ad0 3 wq 1 cvtops x28 TX 0x170011.0x10ab5(ext 0x4,0x0)[71000-0002-00002D5B] inst 2 
    BLOCKED 0xdb7f3648 3 wq 2 cvtops x1 TX 0xa001f.0x33e15(ext 0x2,0x0)[71000-0002-00002D5B] inst 2 
    BLOCKER 0xcb4fabd0 3 wq 1 cvtops x28 TX
    Lock mode in WFG is column 3. Interpret using:
    #define KJUSERNL 0         /* no permissions */   (Null)  
    #define KJUSERCR 1         /* concurrent read */ (Row-S (SS))  
    #define KJUSERCW 2         /* concurrent write */ (Row-X (SX))  
    #define KJUSERPR 3         /* protected read */    (Share)  
    #define KJUSERPW 4         /* protected write */ (S/Row-X (SSX))  
    #define KJUSEREX 5         /* exclusive access */ (Exclusive) 
    These are mode 4 (S) TX locks which can have a few causes, including ITLs, unique indexes and bitmap indexes.
  • 6. Re: Cause of Deadlock
    Osama_Mustafa Oracle ACE
    Currently Being Moderated
    Yes , But as i told you before seems application Need to be monitor again
  • 7. Re: Cause of Deadlock
    Jonathan Lewis Oracle ACE Director
    Currently Being Moderated
    orausern wrote:
    Yes true! I could make out that this one sql is involved in the deadlock. But my question and doubt here is that, just one session by itself can not cause deadlock right? For deadlock there has to be two sessions whereas here I dont' see two different sessions. So how can a single session cause deadlock?
    You're running RAC - the other session is in the other instance, but presumably it survived the deadlock collision and the application response left you with no other information.

    The deadlock is between tx/6 and tx/4 - and since the SQL we see in this trace is for an insert, it's possible that it's a problem relating to conflict on unique (or bitmap) index entries. (Generally tx/4 is something to do with indexes, although there are a couple of exotic causes that relate to internal activity.)

    The tx/6 tx/4 show up in some of the detail in the granted_q and convert_q:
    GRANTED_Q : 
    lp 0xcb4fabd0 gl KJUSEREX rp 0xdd61cea0 [0xa001f][0x33e15],[TX][ext 0x2,0x0] 
      master 1 gl owner 0xd4c45958 possible pid 582 xid 77000-0001-00000C6F bast 0 rseq 767 mseq 0 history 0xd497d495 
      open opt KJUSERDEADLOCK   
    CONVERT_Q: 
    lp 0xcc5dae48 gl KJUSERNL rl KJUSERPR rp 0xdd61cea0 [0xa001f][0x33e15],[TX][ext 0x2,0x0] 
      master 1 owner 2  bast 1 rseq 264 mseq 0x1 history 0x77d497ad 
      convert opt KJUSERGETVALUE   
    Note the granted_q has KJUSEREX (exclusive / 6)
    and the convert_q has KJUSERPR (protected read / 4)

    Look initially for code that generates values which might allow for duplicates to appear in different instances. Bear in mind, though, that it might be something to do with anomalies in referential integrity such as child rows being inserted in one instance for parent rows that have been inserted, but not yet committed in the other instance.

    Regards
    Jonathan Lewis
  • 8. Re: Cause of Deadlock
    orausern Explorer
    Currently Being Moderated
    Thanks a lot Jonathan! I can confirm that there are no ref. key on the related tables. the strange thing is I see only one session here. I have pasted the ENTIRE relevant portion of the trace file. If there is a deadlock, will there not be TWO sessions? Here I see one only - but I have only very basic knowledge on deadlocks and none in interpreting deadlock trace files!
  • 9. Re: Cause of Deadlock
    Dom Brooks Guru
    Currently Being Moderated
    If you're licensed for Diagnostic pack, you could use Active Session History (ASH) to see if you can get some more information about the deadlock participants.

    Deadlock detection kicks in on about 3 seconds.
    The in-memory ASH buffer, exposed via (G)V$ACTIVE_SESSION_HISTORY (GV for RAC obviously), samples all sessions actively working or actively waiting every second so you might well get some valuable additional information from across the cluster.

    This ASH buffer has a limited lifespan before the active sessions from once every 10 seconds are stored down in the ASH repository - DBA_HIST_ACTIVE_SESS_HISTORY. So you have to then be a bit lucky to get anything about the deadlock situation.
  • 10. Re: Cause of Deadlock
    Mohamed Houri Pro
    Currently Being Moderated
     If there is a deadlock, will there not be TWO sessions?
    It is not necessary to have two differents sessions in order to produce a deadlock. Think about a single session using autonomous transaction. It is easy then to produce a deadlock within this single session (but two differents transactions)
    create table t1
     (col1 number primary key);
    
    create table t2
     (col1    number primary key
     ,status  varchar2(12) not null
     ,col2    number
     ,col2v   number generated always as (case when status = 'ACTIVE' then col2 end) VIRTUAL
      ,constraint t2_fk foreign key (col2v) references t1(col1)
      ,constraint t2_ck check (status in ('ACTIVE','INACTIVE') and (status = 'INACTIVE'
     or col2 is not null))
     );
     
    insert into t1
    select rownum
    from dual
    connect by level <=100;
     
    commit;
     
    insert into t2 (col1, status, col2) values (1, 'ACTIVE',50);
     
    declare
    pragma autonomous_transaction;
    begin
      delete from t1
      where col1 = 99;
      commit;
    end;
    /
     
    ORA-00060: deadlock detected while waiting for resource
    ORA-06512: at line 4
    00060. 00000 -  "deadlock detected while waiting for resource";
    *Cause:    Transactions deadlocked one another while waiting for resources.
    *Action:   Look at the trace file to see the transactions and resources
               involved. Retry if necessary.
     
    Best regards

    Mohamed Houri
    www.hourim.wordpress.com
  • 11. Re: Cause of Deadlock
    sb92075 Guru
    Currently Being Moderated
    ORA-00060 deposits many useful details in the alert_SID.log file.

    please post these details for us to review.
  • 12. Re: Cause of Deadlock
    orausern Explorer
    Currently Being Moderated
    @Mohamed:
    Thank you very much!! I wasn't aware at all of this possibility and will expore this in more detail. One thing though - the moment we remove the Ref. Constraint , the dead lock goes away - I ran your code in my 11.2.0.2 db, got deadlock, removed the Ref. Key constraint and it went fine. Now it is absolute certain that in this table where I got deadlock there is no foreign key. So may be other factors are in play here! But thanks for the insight on autonomous txn possibility. I know that our batch pl/sql programs have this autonomous txns and that may have something to do!
    @sb92075
    Yes I missed to post it! Alert log has this info:
    Global Enqueue Services Deadlock detected. More info in file /oracle/diag/rdbms/db01/db0101/trace/db01_lmd01_18994.trc
  • 13. Re: Cause of Deadlock
    sb92075 Guru
    Currently Being Moderated
    orausern wrote:
    @Mohamed:
    Thank you very much!! I wasn't aware at all of this possibility and will expore this in more detail. One thing though - the moment we remove the Ref. Constraint , the dead lock goes away - I ran your code in my 11.2.0.2 db, got deadlock, removed the Ref. Key constraint and it went fine. Now it is absolute certain that in this table where I got deadlock there is no foreign key. So may be other factors are in play here! But thanks for the insight on autonomous txn possibility. I know that our batch pl/sql programs have this autonomous txns and that may have something to do!
    @sb92075
    Yes I missed to post it! Alert log has this info:
    There are more details in alert_SID.log file itself.

    Be sure that the FK constraint has an actual INDEX on the appropriate column(s) otherwise whole table can be locked!
  • 14. Re: Cause of Deadlock
    orausern Explorer
    Currently Being Moderated
    >
    Be sure that the FK constraint has an actual INDEX on the appropriate column(s) otherwise whole table can be locked!
    >

    In my previous reply I was referring to the example that Howri gave on how a single session can cause deadlock...in the actual deadlock situatiion for which I asked the question, there is no foreign key involved. Also alert log has only this one line:
    Global Enqueue Services Deadlock detected. More info in file...
    Thanks again!!,
1 2 Previous Next

Legend

  • Correct Answers - 10 points
  • Helpful Answers - 5 points