This discussion is archived
1 2 Previous Next 17 Replies Latest reply: Oct 11, 2012 1:16 PM by Osama_Mustafa RSS

Strange deadlock issue (no unindexed foreign key)

orausern Explorer
Currently Being Moderated
Hi,
We are on 11.2.0.2 on Linux. There is a deadlock in our db (I first checked that no foreign key is unindexed). This deadlock has this type of data in alert file (after trimming it a lot). Can someone suggest on what could be the root cause?
--FROM Alert log: "Global Enqueue Services Deadlock detected. More info in file....trc"
--below from trace file:
Oracle Database 11g Enterprise Edition Release 11.2.0.2.0 - 64bit Production
With the Partitioning, Real Application Clusters, OLAP, Data Mining
and Real Application Testing options
ORACLE_HOME = /oracle/product/database/1120/db1
System name:     Linux
Node name:     NODE1
Release:     2.6.32.59-0.3-default
Version:     #1 SMP 2012-04-27 11:14:44 +0200
Machine:     x86_64
Instance name: db02
Redo thread mounted by this instance: 0 <none>
Oracle process number: 12
Unix process pid: 17454, image: oracle@db01 (LMD0)


*** 2012-09-16 00:54:00.094
*** SESSION ID:(181.1) 2012-09-16 00:54:00.094
*** CLIENT ID:() 2012-09-16 00:54:00.094
*** SERVICE NAME:() 2012-09-16 00:54:00.094
*** MODULE NAME:() 2012-09-16 00:54:00.094
*** ACTION NAME:() 2012-09-16 00:54:00.094
 
* Load Monitor used for high load check 
* Old Low - High Load Threshold Range = [0 - 0] 
* hlcpu 5 (kjihpc 5), slpct 90, llpct 75 
* New Low - High Load Threshold Range = [30720 - 40960] 

*** 2012-09-16 00:54:02.690
KSXPCINI: kjxgnpub KSXP 2.2.0GESR000 13, 0

*** 2012-09-16 00:54:11.168
ftd (4) received from node 1 (84 5.0/0.0) 
all ftds received 
* kjxhvmaph: domain 0 valid = 1 according to instance 1 
ftd (6) received from node 1 (84 7.0/0.0) 

all ftds received 
ftd (19) received from node 1 (84 20.0/0.0) 
all ftds received 
* Initialize deadlock detection * 
ftd (21) received from node 1 (84 22.0/0.0) 
all ftds received 
ftd (23) received from node 1 (84 22.0/0.0) 
all ftds received 

*** 2012-09-16 00:54:11.460
* kjxpnpgoh: PnP Go Ahead received from 1 (pnp inc 84) 

*** 2012-09-16 00:54:31.988
Begin DRM(399) (swin 1) - AFFINITY transfer pkey 4.1 to 2 oscan 1.1
kjiobjscn 1 
ftd (30) received from node 1 (84 0.31/0.0) 
all ftds received 
ftd (33) received from node 1 (84 0.34/5.0) 
all ftds received 
ftd (35) received from node 1 (84 0.36/6.0) 
all ftds received 
ftd (37) received from node 1 (84 0.38/7.0) 
all ftds received 
2012-09-16 00:54:32.061349 : 

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

*** 2012-09-16 00:55:02.914
2012-09-16 00:55:02.914301 : Setting 3-way CR grants to 1 global-lru off? 0
2012-09-16 03:00:44.727542 : Setting 3-way CR grants to 1 global-lru off? 0

*** 2012-09-16 03:04:25.696
Begin DRM(400) (swin 0) - AFFINITY transfer pkey 74335.0 to 2 oscan 0.0
kjiobjscn 1 
ftd (30) received from node 1 (84 0.30/0.0) 
all ftds received 



* kjxftdn: break from kjxftdn, post lmon later 
ftd (37) received from node 1 (84 0.38/0.0) 
all ftds received 
ftd (30) received from node 1 (84 0.31/0.0) 
all ftds received 
ftd (33) received from node 1 (84 0.34/0.0) 
all ftds received 
ftd (35) received from node 1 (84 0.35/0.0) 
all ftds received 


* kjxftdn: break from kjxftdn, post lmon later 
ftd (37) received from node 1 (84 0.38/0.0) 
all ftds received 
ftd (30) received from node 1 (84 0.30/0.0) 
all ftds received 

(repeated such entry removed)
* End DRM for pkey remastering request(s) (locally requested)

*** 2012-09-17 07:20:51.111
Begin DRM(401) (swin 0) - AFFINITY transfer pkey 88491.0 to 2 oscan 0.0
kjiobjscn 1 
ftd (30) received from node 1 (84 0.31/0.0) 
all ftds received 
ftd (30) received from node 1 (84 0.30/0.0) 
all ftds received 


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

* kjxftdn: break from kjxftdn, post lmon later 
2012-09-17 07:20:51.407739 : 

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

*** 2012-09-17 22:04:10.873
Begin DRM(402) (swin 0) - AFFINITY transfer pkey 74331.0 to 2 oscan 0.0
kjiobjscn 1 

*** 2012-09-17 22:04:11.001
ftd (30) received from node 1 (84 0.31/0.0) 
all ftds received 
ftd (33) received from node 1 (84 0.34/0.0) 
ftd (30) received from node 1 (84 0.30/0.0) 
all ftds received 


* kjxftdn: break from kjxftdn, post lmon later 
ftd (35) received from node 1 (84 0.36/0.0) 
all ftds received 
ftd (33) received from node 1 (84 0.33/0.0) 
all ftds received 

* kjxftdn: break from kjxftdn, post lmon later 

*** 2012-09-18 11:07:30.967
ftd (35) received from node 1 (84 0.36/0.0) 
all ftds received 
ftd (37) received from node 1 (84 0.38/0.0) 
all ftds received 
2012-09-18 11:07:30.973676 : 
End DRM(405) for pkey transfer request(s) from 1
ENQUEUE DUMP REQUEST: from 1 spnum 12 on [0xf0008][0x24a0],[TX][ext 0x4,0x0] for reason 3 mtype 0

*** 2012-09-18 17:14:20.114
DUMP LOCAL BLOCKER/HOLDER: block level 3 res [0xf0008][0x24a0],[TX][ext 0x4,0x0]
----------resource 0xc2bc3f50----------------------
resname       : [0xf0008][0x24a0],[TX][ext 0x4,0x0]
hash mask     : x3
Local inst    : 2
dir_inst      : 2
master_inst   : 2
hv idx        : 124
hv last r.inc : 84
current inc   : 84
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   : 2
vbreq_state   : 0
state         : x0
resp          : 0xc2bc3f50
On Scan_q?    : N
Total accesses: 2652
Imm.  accesses: 2516
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 0xd0f7e510 gl KJUSEREX rp 0xc2bc3f50 [0xf0008][0x24a0],[TX][ext 0x4,0x0]
  master 2 gl owner 0xd5df5688 possible pid 19261 xid 53000-0002-00000286 bast 0 rseq 125 mseq 0 history 0x4977d495
  open opt KJUSERDEADLOCK  
CONVERT_Q: 
lp 0xd0f7e6e0 gl KJUSERNL rl KJUSERPR rp 0xc2bc3f50 [0xf0008][0x24a0],[TX][ext 0x4,0x0]
  master 2 owner 1  bast 1 rseq 207 mseq 0x1 history 0x77d497ad
  convert opt KJUSERGETVALUE  
----------enqueue 0xd0f7e510------------------------
lock version     : 89
Owner inst       : 2
grant_level      : KJUSEREX
req_level        : KJUSEREX
bast_level       : KJUSERNL
notify_func      : (nil)
resp             : 0xc2bc3f50
procp            : 0xdb10cc20
pid              : 17454
proc version     : 0
oprocp           : (nil)
opid             : 17454
group lock owner : 0xd5df5688
possible pid     : 19261
xid              : 53000-0002-00000286
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          : 0x4977d495
Msg_Seq          : 0x0
res_seq          : 125
valblk           : 0x00000000000000000000000000000000 .
user session for deadlock lock 0xd0f7e510
  sid: 290 ser: 713 audsid: 82787243 user: 64/SCOTT    flags: (0x41) USR/- flags_idl: (0x1) BSY/-/-/-/-/-
    flags2: (0x40009) -/-/INC
  pid: 83 O/S info: user: grid, term: UNKNOWN, ospid: 19261
    image: oracle@db1
  client details:
    O/S info: user: wasadmin, term: unknown, ospid: 1234
    machine: cdldvjassvap291 program: JDBC Thin Client
    application name: JDBC Thin Client, hash value=2546894660
  current SQL:
  INSERT INTO tab1 SELECT x from tab2;

DUMP LOCAL BLOCKER: initiate state dump for DEADLOCK
  possible owner[83.19261] on resource TX-000F0008-000024A0

*** 2012-09-18 17:14:20.115
Submitting asynchronized dump request [28]. summary=[ges process stack dump (kjdglblkrdm1)].
Global blockers dump start:---------------------------------
DUMP LOCAL BLOCKER/HOLDER: block level 3 res [0x150019][0x12b0a],[TX][ext 0x2,0x0]
----------resource 0xdcf6de80----------------------
resname       : [0x150019][0x12b0a],[TX][ext 0x2,0x0]
hash mask     : x3
Local inst    : 2
dir_inst      : 1
master_inst   : 1
hv idx        : 119
hv last r.inc : 82
current inc   : 84
hv status     : 0
hv master     : 0
open options  : dd 
Held mode     : KJUSERNL
Cvt mode      : KJUSERPR
Next Cvt mode : KJUSERNL
msg_seq       : 0x1
res_seq       : 32
grant_bits    : KJUSERNL 
grant mode    : KJUSERNL  KJUSERCR  KJUSERCW  KJUSERPR  KJUSERPW  KJUSEREX
count         : 1         0         0         0         0         0
val_state     : KJUSERVS_NOVALUE
valblk        : 0xd0f5415aff7f00000000000000000000 .AZ
access_inst   : 1
vbreq_state   : 0
state         : x8
resp          : 0xdcf6de80
On Scan_q?    : N
Total accesses: 3472
Imm.  accesses: 1369
Granted_locks : 0 
Cvting_locks  : 1 
value_block:  d0 f5 41 5a ff 7f 00 00 00 00 00 00 00 00 00 00
GRANTED_Q :
CONVERT_Q: 
lp 0xdb976808 gl KJUSERNL rl KJUSERPR rp 0xdcf6de80 [0x150019][0x12b0a],[TX][ext 0x2,0x0]
  master 1 gl owner 0xdc688bc0 possible pid 19261 xid 53000-0002-00000286 bast 0 rseq 32 mseq 0 history 0x495149da
  convert opt KJUSERGETVALUE  
DUMP LOCAL BLOCKER/HOLDER: block level 3 res [0xf0008][0x24a0],[TX][ext 0x4,0x0]
----------resource 0xc2bc3f50----------------------
resname       : [0xf0008][0x24a0],[TX][ext 0x4,0x0]
hash mask     : x3
Local inst    : 2
dir_inst      : 2
master_inst   : 2
hv idx        : 124
hv last r.inc : 84
current inc   : 84
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        : 0xd0f5415aff7f00000000000000000000 .AZ
access_inst   : 2
vbreq_state   : 0
state         : x0
resp          : 0xc2bc3f50
On Scan_q?    : N
Total accesses: 2654
Imm.  accesses: 2517
Granted_locks : 1 
Cvting_locks  : 1 
value_block:  d0 f5 41 5a ff 7f 00 00 00 00 00 00 00 00 00 00
GRANTED_Q :
lp 0xd0f7e510 gl KJUSEREX rp 0xc2bc3f50 [0xf0008][0x24a0],[TX][ext 0x4,0x0]
  master 2 gl owner 0xd5df5688 possible pid 19261 xid 53000-0002-00000286 bast 0 rseq 125 mseq 0 history 0x4977d495
  open opt KJUSERDEADLOCK  
CONVERT_Q: 
lp 0xd0f7e6e0 gl KJUSERNL rl KJUSERPR rp 0xc2bc3f50 [0xf0008][0x24a0],[TX][ext 0x4,0x0]
  master 2 owner 1  bast 1 rseq 207 mseq 0x1 history 0x77d497ad
  convert opt KJUSERGETVALUE  
----------enqueue 0xd0f7e510------------------------
lock version     : 89
Owner inst       : 2
grant_level      : KJUSEREX
req_level        : KJUSEREX
bast_level       : KJUSERNL
notify_func      : (nil)
resp             : 0xc2bc3f50
procp            : 0xdb10cc20
pid              : 17454
proc version     : 0
oprocp           : (nil)
opid             : 17454
group lock owner : 0xd5df5688
possible pid     : 19261
xid              : 53000-0002-00000286
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          : 0x4977d495
Msg_Seq          : 0x0
res_seq          : 125
valblk           : 0x00000000000000003100050200000000 .1
user session for deadlock lock 0xd0f7e510
  sid: 290 ser: 713 audsid: 82787243 user: 64/SCOTT
    flags: (0x41) USR/- flags_idl: (0x1) BSY/-/-/-/-/-
    flags2: (0x40009) -/-/INC
  pid: 83 O/S info: user: grid, term: UNKNOWN, ospid: 19261
    image: oracle@db1
  client details:
    O/S info: user: wasadmin, term: unknown, ospid: 1234
    machine: cdldvjassvap291 program: JDBC Thin Client
    application name: JDBC Thin Client, hash value=2546894660
  current SQL:
  INSERT INTO tab1 SELECT x from tab2; (made up )
DUMP LOCAL BLOCKER: initiate state dump for DEADLOCK
  possible owner[83.19261] on resource TX-000F0008-000024A0

*** 2012-09-18 17:14:20.116
Submitting asynchronized dump request [28]. summary=[ges process stack dump (kjdglblkrdm1)].
Global blockers dump end:-----------------------------------
Global Wait-For-Graph(WFG) at ddTS[0.1] :
BLOCKED 0xdb976808 3 wq 2 cvtops x1 TX 0x150019.0x12b0a(ext 0x2,0x0)[53000-0002-00000286] inst 2 
BLOCKER 0xcc55d558 3 wq 1 cvtops x28 TX 0x150019.0x12b0a(ext 0x2,0x0)[4C000-0001-0000014C] inst 1 
BLOCKED 0xdb7dcfc8 3 wq 2 cvtops x1 TX 0xf0008.0x24a0(ext 0x4,0x0)[4C000-0001-0000014C] inst 1 
BLOCKER 0xd0f7e510 3 wq 1 cvtops x28 TX 0xf0008.0x24a0(ext 0x4,0x0)[53000-0002-00000286] inst 2 

*** 2012-09-18 17:14:20.687
* Cancel deadlock victim lockp 0xdb976808 

*** 2012-09-18 17:14:25.028
ENQUEUE DUMP REQUEST: from 1 spnum 12 on [0x1a0006][0x2b6e],[TX][ext 0x4,0x0] for reason 3 mtype 0
DUMP LOCAL BLOCKER/HOLDER: block level 3 res [0x1a0006][0x2b6e],[TX][ext 0x4,0x0]
----------resource 0xde49c768----------------------
resname       : [0x1a0006][0x2b6e],[TX][ext 0x4,0x0]
hash mask     : x3
Local inst    : 2
dir_inst      : 2
master_inst   : 2
hv idx        : 72
hv last r.inc : 84
current inc   : 84
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   : 2
vbreq_state   : 0
state         : x0
resp          : 0xde49c768
On Scan_q?    : N
Total accesses: 1823
Imm.  accesses: 1789
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 0xdb40f4a0 gl KJUSEREX rp 0xde49c768 [0x1a0006][0x2b6e],[TX][ext 0x4,0x0]
  master 2 gl owner 0xd7f08fa8 possible pid 19228 xid 46000-0002-000004A4 bast 0 rseq 32 mseq 0 history 0x4977d495
  open opt KJUSERDEADLOCK  
CONVERT_Q: 
lp 0xdb414320 gl KJUSERNL rl KJUSERPR rp 0xde49c768 [0x1a0006][0x2b6e],[TX][ext 0x4,0x0]
  master 2 owner 1  bast 1 rseq 190 mseq 0x1 history 0x77d497ad
  convert opt KJUSERGETVALUE  
----------enqueue 0xdb40f4a0------------------------
lock version     : 129
Owner inst       : 2
grant_level      : KJUSEREX
req_level        : KJUSEREX
bast_level       : KJUSERNL
notify_func      : (nil)
resp             : 0xde49c768
procp            : 0xdb10cc20
pid              : 17454
proc version     : 0
oprocp           : (nil)
opid             : 17454
group lock owner : 0xd7f08fa8
possible pid     : 19228
xid              : 46000-0002-000004A4
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          : 0x4977d495
Msg_Seq          : 0x0
res_seq          : 32
valblk           : 0x00000000000000000000000000000000 .
user session for deadlock lock 0xdb40f4a0
  sid: 94 ser: 2065 audsid: 82787238 user: 64/SCOTT    flags: (0x41) USR/- flags_idl: (0x1) BSY/-/-/-/-/-
    flags2: (0x40009) -/-/INC
  pid: 70 O/S info: user: grid, term: UNKNOWN, ospid: 19228
    image: oracle@db1
  client details:
    O/S info: user: wasadmin, term: unknown, ospid: 1234
    machine: cdldvjassvap291 program: JDBC Thin Client
    application name: JDBC Thin Client, hash value=2546894660
  current SQL:
  INSERT INTO tab1 SELECT x from tab2; (made up)
DUMP LOCAL BLOCKER: initiate state dump for DEADLOCK
  possible owner[70.19228] on resource TX-001A0006-00002B6E

*** 2012-09-18 17:14:25.029
Submitting asynchronized dump request [28]. summary=[ges process stack dump (kjdglblkrdm1)].
Global blockers dump start:---------------------------------
DUMP LOCAL BLOCKER/HOLDER: block level 3 res [0x160016][0x9249],[TX][ext 0x2,0x0]
----------resource 0xdb2d6758----------------------
resname       : [0x160016][0x9249],[TX][ext 0x2,0x0]
hash mask     : x3
Local inst    : 2
dir_inst      : 1
master_inst   : 1
hv idx        : 51
hv last r.inc : 82
current inc   : 84
hv status     : 0
hv master     : 0
open options  : dd 
Held mode     : KJUSERNL
Cvt mode      : KJUSERPR
Next Cvt mode : KJUSERNL
msg_seq       : 0x1
res_seq       : 49
grant_bits    : KJUSERNL 
grant mode    : KJUSERNL  KJUSERCR  KJUSERCW  KJUSERPR  KJUSERPW  KJUSEREX
count         : 1         0         0         0         0         0
val_state     : KJUSERVS_NOVALUE
valblk        : 0xd0f5415aff7f00000000000000000000 .AZ
access_inst   : 1
vbreq_state   : 0
state         : x8
resp          : 0xdb2d6758
On Scan_q?    : N
Total accesses: 1620
Imm.  accesses: 1442
Granted_locks : 0 
Cvting_locks  : 1 
value_block:  d0 f5 41 5a ff 7f 00 00 00 00 00 00 00 00 00 00
GRANTED_Q :
CONVERT_Q: 
lp 0xdb682d78 gl KJUSERNL rl KJUSERPR rp 0xdb2d6758 [0x160016][0x9249],[TX][ext 0x2,0x0]
  master 1 gl owner 0xdc568020 possible pid 19228 xid 46000-0002-000004A4 bast 0 rseq 49 mseq 0 history 0x495149da
  convert opt KJUSERGETVALUE  
DUMP LOCAL BLOCKER/HOLDER: block level 3 res [0x1a0006][0x2b6e],[TX][ext 0x4,0x0]
----------resource 0xde49c768----------------------
resname       : [0x1a0006][0x2b6e],[TX][ext 0x4,0x0]
hash mask     : x3
Local inst    : 2
dir_inst      : 2
master_inst   : 2
hv idx        : 72
hv last r.inc : 84
current inc   : 84
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        : 0xd0f5415aff7f00000000000000000000 .AZ
access_inst   : 2
vbreq_state   : 0
state         : x0
resp          : 0xde49c768
On Scan_q?    : N
Total accesses: 1825
Imm.  accesses: 1790
Granted_locks : 1 
Cvting_locks  : 1 
value_block:  d0 f5 41 5a ff 7f 00 00 00 00 00 00 00 00 00 00
GRANTED_Q :
lp 0xdb40f4a0 gl KJUSEREX rp 0xde49c768 [0x1a0006][0x2b6e],[TX][ext 0x4,0x0]
  master 2 gl owner 0xd7f08fa8 possible pid 19228 xid 46000-0002-000004A4 bast 0 rseq 32 mseq 0 history 0x4977d495
  open opt KJUSERDEADLOCK  
CONVERT_Q: 
lp 0xdb414320 gl KJUSERNL rl KJUSERPR rp 0xde49c768 [0x1a0006][0x2b6e],[TX][ext 0x4,0x0]
  master 2 owner 1  bast 1 rseq 190 mseq 0x1 history 0x77d497ad
  convert opt KJUSERGETVALUE  
----------enqueue 0xdb40f4a0------------------------
lock version     : 129
Owner inst       : 2
grant_level      : KJUSEREX
req_level        : KJUSEREX
bast_level       : KJUSERNL
notify_func      : (nil)
resp             : 0xde49c768
procp            : 0xdb10cc20
pid              : 17454
proc version     : 0
oprocp           : (nil)
opid             : 17454
group lock owner : 0xd7f08fa8
possible pid     : 19228
xid              : 46000-0002-000004A4
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          : 0x4977d495
Msg_Seq          : 0x0
res_seq          : 32
valblk           : 0x00000000000000003100050200000000 .1
user session for deadlock lock 0xdb40f4a0
  sid: 94 ser: 2065 audsid: 82787238 user: 64/SCOTT    flags: (0x41) USR/- flags_idl: (0x1) BSY/-/-/-/-/-
    flags2: (0x40009) -/-/INC
  pid: 70 O/S info: user: grid, term: UNKNOWN, ospid: 19228
    image: oracle@db1
  client details:
    O/S info: user: wasadmin, term: unknown, ospid: 1234
    machine: cdldvjassvap291 program: JDBC Thin Client
    application name: JDBC Thin Client, hash value=2546894660
  current SQL:
  INSERT INTO tab1 SELECT x from tab2;(made up)
DUMP LOCAL BLOCKER: initiate state dump for DEADLOCK
  possible owner[70.19228] on resource TX-001A0006-00002B6E

*** 2012-09-18 17:14:25.030
Submitting asynchronized dump request [28]. summary=[ges process stack dump (kjdglblkrdm1)].
Global blockers dump end:-----------------------------------
Global Wait-For-Graph(WFG) at ddTS[0.2] :
BLOCKED 0xdb682d78 3 wq 2 cvtops x1 TX 0x160016.0x9249(ext 0x2,0x0)[46000-0002-000004A4] inst 2 
BLOCKER 0xcefeaf70 3 wq 1 cvtops x28 TX 0x160016.0x9249(ext 0x2,0x0)[54000-0001-000000A9] inst 1 
BLOCKED 0xdb9b6380 3 wq 2 cvtops x1 TX 0x1a0006.0x2b6e(ext 0x4,0x0)[54000-0001-000000A9] inst 1 
BLOCKER 0xdb40f4a0 3 wq 1 cvtops x28 TX 0x1a0006.0x2b6e(ext 0x4,0x0)[46000-0002-000004A4] inst 2 

*** 2012-09-18 17:14:25.667
* Cancel deadlock victim lockp 0xdb682d78 

*** 2012-09-18 18:09:23.508
Begin DRM(406) (swin 0) - AFFINITY transfer pkey 88431.0 to 2 oscan 0.0
kjiobjscn 1 
ftd (30) received from node 1 (84 0.30/0.0) 
all ftds received 

* kjxftdn: break from kjxftdn, post lmon later 
ftd (33) received from node 1 (84 0.34/0.0) 
all ftds received 
ftd (35) received from node 1 (84 0.36/0.0) 
all ftds received 
ftd (37) received from node 1 (84 0.38/0.0) 
all ftds received 
ftd (30) received from node 1 (84 0.31/0.0) 
all ftds received 
ftd (33) received from node 1 (84 0.34/0.0) 
all ftds received 
ftd (35) received from node 1 (84 0.36/0.0) 
all ftds received 
ftd (37) received from node 1 (84 0.38/0.0) 
all ftds received 
ftd (30) received from node 1 (84 0.30/0.0) 
all ftds received 
Edited by: orausern on Oct 10, 2012 5:57 AM

Edited by: orausern on Oct 10, 2012 5:58 AM
  • 1. Re: Strange deadlock issue (no unindexed foreign key)
    Marco V. Expert
    Currently Being Moderated
    Could you post these tables structures:
    INSERT INTO tab1 SELECT x from tab2
  • 2. Re: Strange deadlock issue (no unindexed foreign key)
    orausern Explorer
    Currently Being Moderated
    Both tables have columns like:
    QL> desc TAB1
     Name                                      Null?    Type
     ----------------------------------------- -------- --------------------------
     CID                                NOT NULL VARCHAR2(16)
     GID                                 NOT NULL NUMBER(12)
     INCL                                  NOT NULL NUMBER(1)
     Is_ADDED                           NOT NULL NUMBER(1)
     CREATED                                           DATE
     CREATED_BY                                     VARCHAR2(80)
     TRAN_ID                                           VARCHAR2(250)
    
    
    primary key on (cid, gid)
    
    tab2 is same as tab1
    
    
    also there is one more statement inthe actual trace file:
    
    delete from tab3  where cid = :1 
    L> desc TAB3
     Name                                      Null?    Type
    ----------------------------------------- -------- --------------------------
    CID                                NOT NULL VARCHAR2(16)
    UID             NOT NULL VARCHAR2(16)
    FNAME                   VARCHAR2(64)
    LNAME                   VARCHAR2(64)
    
    Primary key on (cid, uid) 
  • 3. Re: Strange deadlock issue (no unindexed foreign key)
    Osama_Mustafa Oracle ACE
    Currently Being Moderated
    Start with MOS :

    *Troubleshooting "Global Enqueue Services Deadlock detected" [ID 1443482.1]*
    *Global Enqueue Services Deadlock detected - Single resource deadlock: blocking enqueue which blocks itself, f 1 [ID 973178.1]*

    Seems its Bug , Check from your Database Version and see the above document .
  • 4. Re: Strange deadlock issue (no unindexed foreign key)
    orausern Explorer
    Currently Being Moderated
    I actually went through that note but none of it seems applicable. If you see the kind of message in my trace file they are quite different. "Single resource deadlock: blocking enqueue which blocks itself, f 1 [ID " such message is not there and instead I have tons of lines like "ftd (13) received from node 2 (92 14.0/0.0)
    all ftds received
    ftd (15) received from node 2 (92 16.0/0.0)
    all ftds received "

    Not finding anywhere any clue on what that means.

    Thanks,
    Orausern

    Edited by: orausern on Oct 10, 2012 9:05 AM                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                       
  • 5. Re: Strange deadlock issue (no unindexed foreign key)
    sb92075 Guru
    Currently Being Moderated
    submit Service Request to Oracle Support
  • 6. Re: Strange deadlock issue (no unindexed foreign key)
    Osama_Mustafa Oracle ACE
    Currently Being Moderated
    But what your alert log indicate also . Open SR or go throw Notes if you are not see them applicable your SR is the best Solution
  • 7. Re: Strange deadlock issue (no unindexed foreign key)
    orausern Explorer
    Currently Being Moderated
    Thanks Experts. I will open the SR. I was thinking may be there was something other than that which is going to fix this (like that unindexed foreign key thing). But yes I see now that SR is what is to be done.

    Thanks,
  • 8. Re: Strange deadlock issue (no unindexed foreign key)
    Mark Malakanov (user11181920) Expert
    Currently Being Moderated
    Deadlocks are usually caused by (incorrect) applications workflows.

    could you please describe what different sessions simultaneously do with Tab1, Tab2 and Tab3?
  • 9. Re: Strange deadlock issue (no unindexed foreign key)
    jgarry Guru
    Currently Being Moderated
    Looks like you are running into this thing: http://orainternals.wordpress.com/2010/03/25/rac-object-remastering-dynamic-remastering/
  • 10. Re: Strange deadlock issue (no unindexed foreign key)
    orausern Explorer
    Currently Being Moderated
    Hi jgarry,

    its too techy for me, what does it mean and how we have to address it?

    Thanks,
  • 11. Re: Strange deadlock issue (no unindexed foreign key)
    orausern Explorer
    Currently Being Moderated
    About the point:
    >
    Deadlocks are usually caused by (incorrect) applications workflows.
    Could you please describe what different sessions simultaneously do with Tab1, Tab2 and Tab3?
    They (dev) said that this is caused by a single session and not multiple sessions. how can I verify about it?

    Thanks
  • 12. Re: Strange deadlock issue (no unindexed foreign key)
    sb92075 Guru
    Currently Being Moderated
    orausern wrote:
    About the point:
    >
    Deadlocks are usually caused by (incorrect) applications workflows.
    Could you please describe what different sessions simultaneously do with Tab1, Tab2 and Tab3?
    They (dev) said that this is caused by a single session and not multiple sessions. how can I verify about it?

    Thanks
    ask Dev to show you same code module that issue all 3 SQL involved in the deadlock.
    Theoretically it is possible that a single session has issued all conflicting DML; but usual case is that different sessions issue conflicting DML
  • 13. Re: Strange deadlock issue (no unindexed foreign key)
    jgarry Guru
    Currently Being Moderated
    It means you are using RAC and are running into an issue with affinity - that means blocks belong to the node that needs them. Perhaps there is a bug when you delete. Open the SR.
  • 14. Re: Strange deadlock issue (no unindexed foreign key)
    Mark Malakanov (user11181920) Expert
    Currently Being Moderated
    They (dev) said that this is caused by a single session and not multiple sessions. how can I verify about it?
    I am not sure, but for both deadlock from your log I see common opid 17454 that deadlocked with pids 19261 and 19228.

    >
    opid : 17454
    possible pid : 19261
    user session for deadlock lock 0xd0f7e510
    sid: 290 ser: 713 audsid: 82787243 user: 64/SCOTT
    DUMP LOCAL BLOCKER: initiate state dump for DEADLOCK
    possible owner[83.19261] on resource TX-000F0008-000024A0
    >


    >
    pid : 17454
    possible pid : 19228
    user session for deadlock lock 0xdb40f4a0
    sid: 94 ser: 2065 audsid: 82787238 user: 64/SCOTT flags: (0x41) DUMP LOCAL BLOCKER: initiate state dump for DEADLOCK
    possible owner[70.19228] on resource TX-001A0006-00002B6E
    >

    May be one Dev was running one session (17454), another Dev was running 19228 ? Or 17454 was a job?

    Do you use RAC?
    How many developers work on same tables?
    What SQL code they issue?
1 2 Previous Next

Legend

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