Oracle Database Discussions

Hi All,
I working on 3 node RAC on Linux boxes and we are not using ASM. I found "Global Enqueue Services Deadlock detected" in alert log of node 1 and 3 and there is common message in all 3nodes "opidcl aborting process unknown ospid (17558) as a result of ORA-3113" with different OSPID's.
Please check the below information and provide me your valuable suggestions. What is the issue happened to occur this and resolution.

below are the portion of alert log information when the issue happened from all nodes.

1st node alert log:
===========

opidcl aborting process unknown ospid (18450) as a result of ORA-3113
Tue Aug 23 13:50:48 2011
PMON deletion of process succeeded
Tue Aug 23 13:51:49 2011
Global Enqueue Services Deadlock detected. More info in file
/u01/app/ccoreqal/oracle/diag/rdbms/ccmintpte/ccmintpt1/trace/ccmintpt1_lmd0_20127.trc.
Tue Aug 23 13:51:49 2011
opidcl aborting process unknown ospid (15593) as a result of ORA-3113
Tue Aug 23 13:51:49 2011
opidcl aborting process unknown ospid (14641) as a result of ORA-3113

Tue Aug 23 13:51:49 2011
opidcl aborting process unknown ospid (16384) as a result of ORA-3113
Tue Aug 23 13:51:49 2011
opidcl aborting process unknown ospid (17708) as a result of ORA-3113
Tue Aug 23 17:26:48 2011
Thread 1 advanced to log sequence 12682 (LGWR switch)
Current log# 2 seq# 12682 mem# 0: /u04/oradata/ccoreqal/ccmintpt/ccmintpte/redo02.rdo
Tue Aug 23 18:23:29 2011
Thread 1 advanced to log sequence 12683 (LGWR switch)
Current log# 1 seq# 12683 mem# 0: /u04/oradata/ccoreqal/ccmintpt/ccmintpte/redo01.rdo
Tue Aug 23 21:57:11 2011
Thread 1 advanced to log sequence 12684 (LGWR switch)
Current log# 2 seq# 12684 mem# 0: /u04/oradata/ccoreqal/ccmintpt/ccmintpte/redo02.rdo
Tue Aug 23 22:00:00 2011
Setting Resource Manager plan DEFAULT_MAINTENANCE_PLAN via parameter
Tue Aug 23 22:00:00 2011
Starting background process VKRM
Tue Aug 23 22:00:00 2011
VKRM started with pid=129, OS id=22116
Tue Aug 23 22:43:22 2011
Thread 1 advanced to log sequence 12685 (LGWR switch)
Current log# 1 seq# 12685 mem# 0: /u04/oradata/ccoreqal/ccmintpt/ccmintpte/redo01.rdo
Tue Aug 23 23:31:45 2011


Log information from /u01/app/ccoreqal/oracle/diag/rdbms/ccmintpte/ccmintpt1/trace/ccmintpt1_lmd0_20127.trc: on 1st node
==============================================================================


----------enqueue 0x26d2ede90------------------------
lock version : 85909
Owner node : 0
grant_level : KJUSERCW
req_level : KJUSERPW
bast_level : KJUSERNL
notify_func : (nil)
resp : 0x27630f788
procp : 0x2724c5640
pid : 6837
proc version : 60
oprocp : (nil)
opid : 6837
group lock owner : 0x2703ade80
possible pid : 6837
xid : 7E000-0001-00000164
dd_time : 4.0 secs
dd_count : 0
timeout : 0.0 secs
On_timer_q? : N
On_dd_q? : Y
lock_state : CONVERTING
Open Options : KJUSERDEADLOCK
Convert options : KJUSERGETVALUE
History : 0x5a55a55a
Msg_Seq : 0x0
res_seq : 2
valblk : 0xc3b1cd4c32ab04000000000000000000 .L2
user session for deadlock lock 0x26d2ede90
sid: 3778 ser: 35653 audsid: 16307274 user: 93/CUSTOMERCENTRAL_N flags: 0x45
pid: 126 O/S info: user: oracle, term: UNKNOWN, ospid: 6837
image: oracle@qysqalccoredb01.data.ieptc.intuit.net

client details:
O/S info: user: app, term: unknown, ospid: 1234
machine: qynprfccoreap02.ieptc.intuit.net program: JDBC Thin Client
application name: JDBC Thin Client, hash value=2546894660
current SQL: <none>
DUMP LOCAL BLOCKER: initiate state dump for DEADLOCK
possible owner[126.6837] on resource TM-000126DD-00000000

*** 2011-08-23 13:47:12.109
Submitting asynchronized dump request [28]
Global blockers dump end:-----------------------------------
ENQUEUE DUMP REQUEST: from 3 spnum 12 on [0x126dd][0x0],[TM] for reason 3 mtype 0
DUMP LOCAL BLOCKER/HOLDER: block level 2 res [0x126dd][0x0],[TM]
----------resource 0x27630f788----------------------
resname : [0x126dd][0x0],[TM]
Local node : 0
dir_node : 2
master_node : 2
hv idx : 49
hv last r.inc : 2
current inc : 10
hv status : 0
hv master : 2
open options : dd cached
Held mode : KJUSERCW
Cvt mode : KJUSERPW
Next Cvt mode : KJUSERPW
msg_seq : 0x90007
res_seq : 2
grant_bits : KJUSERNL KJUSERCW
grant mode : KJUSERNL KJUSERCR KJUSERCW KJUSERPR KJUSERPW KJUSEREX
count : 106 0 1 0 0 0
val_state : KJUSERVS_NOVALUE
valblk : 0xc08923766c2b000000000000ff7f0000 .#vl+
access_node : 0
vbreq_state : 0
state : x8
resp : 0x27630f788
On Scan_q? : N
cache level : 0
Total accesses: 2895704
Imm. accesses: 2878419
Granted_locks : 0
Cvting_locks : 107
value_block: c0 89 23 76 6c 2b 00 00 00 00 00 00 ff 7f 00 00
GRANTED_Q :
CONVERT_Q:
lp 0x26d2ede90 gl KJUSERCW rl KJUSERPW rp 0x27630f788 [0x126dd][0x0],[TM]
master 2 gl owner 0x2703ade80 possible pid 6837 xid 7E000-0001-00000164 bast 0 rseq 2 mseq 0 history 0x5a55a55a
convert opt KJUSERGETVALUE
lp 0x26db0aa90 gl KJUSERNL rl KJUSERCW rp 0x27630f788 [0x126dd][0x0],[TM]





Alert log info from node2:
================
opidcl aborting process unknown ospid (20443) as a result of ORA-3113
Tue Aug 23 13:51:50 2011
opidcl aborting process unknown ospid (17434) as a result of ORA-3113
Tue Aug 23 13:51:50 2011
opidcl aborting process unknown ospid (19879) as a result of ORA-3113
Tue Aug 23 13:51:50 2011
opidcl aborting process unknown ospid (19795) as a result of ORA-3113
Tue Aug 23 13:51:50 2011
opidcl aborting process unknown ospid (17459) as a result of ORA-3113
Tue Aug 23 13:51:50 2011
opidcl aborting process unknown ospid (18907) as a result of ORA-3113
Tue Aug 23 13:51:50 2011
opidcl aborting process unknown ospid (17572) as a result of ORA-3113
Tue Aug 23 13:51:50 2011
opidcl aborting process unknown ospid (19524) as a result of ORA-3113
Tue Aug 23 13:51:51 2011
opidcl aborting process unknown ospid (19201) as a result of ORA-3113
Tue Aug 23 17:27:32 2011
Thread 2 advanced to log sequence 12134 (LGWR switch)
Current log# 4 seq# 12134 mem# 0: /u04/oradata/ccoreqal/ccmintpt/ccmintpte/redo04.rdo
Tue Aug 23 17:58:27 2011
Thread 2 advanced to log sequence 12135 (LGWR switch)
Current log# 3 seq# 12135 mem# 0: /u04/oradata/ccoreqal/ccmintpt/ccmintpte/redo03.rdo




Alert log info from 3rd node:
===================

opidcl aborting process unknown ospid (28525) as a result of ORA-3113
Tue Aug 23 13:50:23 2011
opidcl aborting process unknown ospid (1590) as a result of ORA-3113
Tue Aug 23 13:50:22 2011
opidcl aborting process unknown ospid (32287) as a result of ORA-3113
Tue Aug 23 13:50:29 2011
Global Enqueue Services Deadlock detected. More info in file
/u01/app/ccoreqal/oracle/diag/rdbms/ccmintpte/ccmintpt3/trace/ccmintpt3_lmd0_10303.trc.
Global Enqueue Services Deadlock detected. More info in file
/u01/app/ccoreqal/oracle/diag/rdbms/ccmintpte/ccmintpt3/trace/ccmintpt3_lmd0_10303.trc.
Global Enqueue Services Deadlock detected. More info in file
/u01/app/ccoreqal/oracle/diag/rdbms/ccmintpte/ccmintpt3/trace/ccmintpt3_lmd0_10303.trc.
Tue Aug 23 13:50:49 2011
Global Enqueue Services Deadlock detected. More info in file
/u01/app/ccoreqal/oracle/diag/rdbms/ccmintpte/ccmintpt3/trace/ccmintpt3_lmd0_10303.trc.
Global Enqueue Services Deadlock detected. More info in file
/u01/app/ccoreqal/oracle/diag/rdbms/ccmintpte/ccmintpt3/trace/ccmintpt3_lmd0_10303.trc.
Tue Aug 23 13:50:59 2011
Global Enqueue Services Deadlock detected. More info in file
/u01/app/ccoreqal/oracle/diag/rdbms/ccmintpte/ccmintpt3/trace/ccmintpt3_lmd0_10303.trc.




Info from /u01/app/ccoreqal/oracle/diag/rdbms/ccmintpte/ccmintpt3/trace/ccmintpt3_lmd0_10303.trc:
================================================================



lp 0x26d2ffdb0 gl KJUSERNL rl KJUSERCW rp 0x276539058 [0x126dd][0x0],[TM]
master 2 gl owner 0x2871fc430 possible pid 1764 xid 29A000-0003-00000006 bast 0 rseq 4 mseq 0 history 0x4951449a
convert opt KJUSERGETVALUE
----------enqueue 0x26f1f3050------------------------
lock version : 5291
Owner node : 2
grant_level : KJUSERCW
req_level : KJUSERPW
bast_level : KJUSERNL
notify_func : (nil)
resp : 0x276539058
procp : 0x272477050
pid : 26639
proc version : 183
oprocp : (nil)
opid : 26639
group lock owner : 0x27b223fa8
possible pid : 26639
xid : 52000-0003-00000265
dd_time : -166.0 secs
dd_count : 52
timeout : 0.0 secs
On_timer_q? : N
On_dd_q? : Y
lock_state : CONVERTING
Open Options : KJUSERDEADLOCK
Convert options : KJUSERGETVALUE
History : 0x4951495a
Msg_Seq : 0x0
res_seq : 4
valblk : 0x00000000ff7f00003100050200000000 .1
user session for deadlock lock 0x26f1f3050
sid: 1341 ser: 56948 audsid: 15763948 user: 93/CUSTOMERCENTRAL_N flags: 0x45
pid: 82 O/S info: user: oracle, term: UNKNOWN, ospid: 26639
image: oracle@qysqalccoredb03.data.ieptc.intuit.net
client details:
O/S info: user: app, term: unknown, ospid: 1234
machine: qynprfccoreap02.ieptc.intuit.net program: JDBC Thin Client
application name: JDBC Thin Client, hash value=2546894660
current SQL: <none>
DUMP LOCAL BLOCKER: initiate state dump for DEADLOCK
possible owner[82.26639] on resource TM-000126DD-00000000

*** 2011-08-23 13:49:58.068
Submitting asynchronized dump request [28]
Global blockers dump end:-----------------------------------
Global Wait-For-Graph(WFG) at ddTS[0.549b1] :
BLOCKED 0x26e258bc8 2 wq 2 cvtops x1 TM 0x126dd.0x0 [1B8000-0003-00000046] inst 3
BLOCKER 0x26f1f3050 2 wq 2 cvtops x1 TM 0x126dd.0x0 [52000-0003-00000265] inst 3
BLOCKED 0x26f1f3050 4 wq 2 cvtops x1 TM 0x126dd.0x0 [52000-0003-00000265] inst 3
BLOCKER 0x26d2ede90 4 wq 2 cvtops x1 TM 0x126dd.0x0 [7E000-0001-00000164] inst 1
BLOCKED 0x26d2ede90 4 wq 2 cvtops x1 TM 0x126dd.0x0 [7E000-0001-00000164] inst 1
BLOCKER 0x26e258bc8 4 wq 2 cvtops x1 TM 0x126dd.0x0 [1B8000-0003-00000046] inst 3