RAC instance Crashes with ,'CONTROL FILE SEQUENTIAL READ'<='ENQ: CF - CONTENTION'<='RECOVERY INSTANCE RECOVERY COMPLETION'
(Doc ID 3069810.1)
Last updated on FEBRUARY 01, 2025
Applies to:
Oracle Database - Enterprise Edition - Version 23.4 to 23.7 [Release 23]Information in this document applies to any platform.
Symptoms
RAC instance Crashes with ,'CONTROL FILE SEQUENTIAL READ'<='ENQ: CF - CONTENTION'<='RECOVERY INSTANCE RECOVERY COMPLETION'
Diag trace shows:
[<hostname>:na2_diag_115778.trc]
Trace file /u01/app/oracle/diag/rdbms/na/na2/trace/na2_diag_115778.trc
Oracle Database 23c Enterprise Edition Release 23.0.0.0.0 - Development
Version 23.4.0.23.00
Build label: RDBMS_MAIN_LINUX.X64_240115
*** 2024-01-15T23:22:44.900796-07:00 (CDB$ROOT(1))
===============================================================================
HANG ANALYSIS:
instances (db_name.oracle_sid): na.na2, na.na3, na.na4, na.na1
oradebug_node_dump_level: 3
analysis initiated by oradebug
os thread scheduling delay history: (sampling every 1.000000 secs)
0.000000 secs at [ 23:22:44 ]
NOTE: scheduling delay has not been sampled for 0.765820 secs
0.000000 secs from [ 23:22:40 - 23:22:45 ], 5 sec avg
0.000000 secs from [ 23:21:45 - 23:22:45 ], 1 min avg
0.000000 secs from [ 23:17:45 - 23:22:45 ], 5 min avg
vktm time drift history
===============================================================================
Chains most likely to have caused the hang:
*** 2024-01-15T23:22:44.902636-07:00 (CDB$ROOT(1))
[a] Chain 1 Signature: 'control file sequential read'<='enq: CF - contention'<='recovery instance recovery completion'
Chain 1 Signature Hash: 0x69a83570
[b] Chain 2 Signature: 'gc current request'<='enq: TX - row lock contention'
Chain 2 Signature Hash: 0x670f45d4
[c] Chain 3 Signature: 'gc current request'<='enq: TX - row lock contention'
Chain 3 Signature Hash: 0x670f45d4
===============================================================================
Non-intersecting chains:
-------------------------------------------------------------------------------
Chain 1:
-------------------------------------------------------------------------------
Oracle session identified by:
{
instance: 2 (na.na2)
os id: 116774, S (sleeping)
process id: 163, oracle@<hostname>(TNS V1-V3), fatal
session id: 9302
session serial #: 56627
module name: 1 (oraagent.bin@<hostname> (TNS V1-V3))
pdb id: 1 (CDB$ROOT)
}
is waiting for 'recovery instance recovery completion' with wait info:
{
time in wait: 19 min 59 sec
timeout after: never
wait id: 933
blocking: 0 sessions
immediate waiters: 0 sessions
immediate blockers: os id: 209396, program: oracle@<domain> (SMON)
current sql_id: 2880646557
running time(secs): 1200
current sql: ALTER DATABASE OPEN /* db agent *//* {0:0:0} */
short stack: ksedsts<-ksdxfstk<-ksdxcb<-sspuser<-__sighandler()<-semtimedop<-sskgpwwait<-skgpwwait<-ksliwat<-kslwaitctx<-kcvirv_internal<-kcfopd<-adbdrv_op
tions<-opiexe<-opiosq0<-kpooprx<-kpoal8<-opiodr<-ttcpip<-opitsk<-opiino<-opiodr<-opidrv<-sou2o<-opimai_real<-ssthrdmain<-main<-__libc_start_main<-_start
wait history:
* time between current wait and wait #1: 0.000072 sec
1. event: 'control file sequential read'
time waited: 0.000373 sec
wait id: 932 p1: 'file#'=0x0
p2: 'block#'=0x2a
p3: 'blocks'=0x1
* time between wait #1 and #2: 0.000009 sec
2. event: 'control file sequential read'
time waited: 0.003324 sec
wait id: 931 p1: 'file#'=0x0
p2: 'block#'=0x28
p3: 'blocks'=0x1
* time between wait #2 and #3: 0.000013 sec
3. event: 'control file sequential read'
time waited: 0.003295 sec
wait id: 930 p1: 'file#'=0x0
p2: 'block#'=0x1
p3: 'blocks'=0x1
}
and is blocked by
=> Oracle session identified by:
{
instance: 1 (na.na1)
os id: 209396
process id: 52, oracle@<domain>(SMON), fatal
session id: 2706
session serial #: 13848
pdb id: 1 (CDB$ROOT)
}
which is waiting for 'enq: CF - contention' with wait info:
{
p1: 'name|mode'=0x43460004
p2: '0'=0x0
p3: 'operation'=0x0
time in wait: 2 min 59 sec
timeout after: 12 min 0 sec
wait id: 1061332
blocking: 712 sessions
immediate waiters: 617 sessions
immediate blockers: os id: 209286, program: oracle@<domain> (LGWR)
current sql_id: 0 (0000000000000)
current sql: <none>
short stack: ksedsts<-ksdxfstk<-ksdxcb<-sspuser<-__sighandler()<-semtimedop<-sskgpwwait<-skgpwwait<-ksliwat<-kslwaitctx<-kjusuc<-ksipgetctxia<-ksqcmi<-ksqg
tlctx<-ksqgelctx<-kcc_get_enqueue<-kccocx<-kcc_begin_txn_internal<-kcrfro<-kcratr_scan<-kcratr<-kctrec<-kcvirv_internal<-kcvirv<-ktmmon<-ktmSmonMain<-ksbrdp_int<-ksbdis
patch<-opirip<-opidrv<-sou2o<-opimai_real<-ssthrdmain<-main<-__libc_start_main<-_start
wait history:
* time between current wait and wait #1: 0.000052 sec
1. event: 'Disk file operations I/O'
time waited: 0.000032 sec (last interval)
time waited: 0.058648 sec (total)
wait id: 1061327 p1: 'FileOperation'=0x5
p2: 'fileno'=0x0
p3: 'filetype'=0x3
* time between wait #1 and #2: 0.000000 sec
2. event: 'ASM file metadata operation'
time waited: 0.000004 sec (last interval)
time waited: 0.058509 sec (total)
wait id: 1061328 p1: 'msgop'=0x12
p2: 'locn'=0x0
* time between wait #2 and #3: 0.000000 sec
3. event: 'KSV master wait'
time waited: 0.034843 sec
wait id: 1061331 p1: 'indicator'=0x9
}
and is blocked by
=> Oracle session identified by:
{
instance: 1 (na.na1)
os id: 209286
process id: 51, oracle@.us.oracle.com (LGWR), fatal
session id: 8621
session serial #: 44604
module name: 1 (sys$abs_timeout)
action name: 1 (Redo writer log switch operations)
pdb id: 1 (CDB$ROOT)
}
which is waiting for 'control file sequential read' with wait info:
{
p1: 'file#'=0x0
p2: 'block#'=0x1
p3: 'blocks'=0x1
px1: 'disk number'=0x22
px2: 'au'=0x21
px3: 'offset'=0x4000
time in wait: 0.000000 sec
timeout after: never
wait id: 26638336
blocking: 715 sessions
immediate waiters: 5 sessions
current sql_id: 0 (0000000000000)
current sql: <none>
short stack: ksedsts<-ksdxfstk<-ksdxcb<-sspuser<-__sighandler()<-semtimedop<-sskgpwwait<-skgpwwait<-ksliwat<-kslwaitctx<-kjusuc<-ksipgetctxia<-ksqcmi<-ksqg
tlctx<-ksqgelctx<-kcc_get_enqueue<-kccocx<-kcc_begin_txn_internal<-kcrfwl<-ksb_act_run_int<-ksb_act_run<-ksbabs<-ksbrdp_int<-ksbdispatch<-opirip<-opidrv<-sou2o<-opimai_
real<-ssthrdmain<-main<-__libc_start_main<-_start
wait history:
* time between current wait and wait #1: 0.000016 sec
1. event: 'enq: CF - contention'
time waited: 0.007416 sec
wait id: 26638335 p1: 'name|mode'=0x43460005
p2: '0'=0x0
p3: 'operation'=0x0
* time between wait #1 and #2: 0.000060 sec
2. event: 'LGWR all worker groups'
time waited: 0.000054 sec
wait id: 26638334
* time between wait #2 and #3: 0.000154 sec
3. event: 'control file parallel write'
time waited: 0.000336 sec
wait id: 26638333 p1: 'files'=0x1
p2: 'block#'=0x1
p3: 'requests'=0x1
}
Cause
To view full details, sign in with your My Oracle Support account. |
|
Don't have a My Oracle Support account? Click to get started! |
In this Document
Symptoms |
Cause |
Solution |
References |