问题现象
接到一线反馈某客户 RAC 数据库在凌晨1节点发生重启，如下是实例关闭时的 alert 日志，需要分析重启的原因。
2024-07-11T00:12:47.155358+08:00
Thread 1 advanced to log sequence 16934 (LGWR switch), current SCN: 963891258
Current log# 2 seq# 16934 mem# 0: /u04/app/oracle/redo/DGSDB/onlinelog/o1_mf_2_jf8gndxq_.log
2024-07-11T00:12:47.279896+08:00
TT03 (PID:75960): SRL selected for T-1.S-16934 for LAD:2
2024-07-11T00:14:07.760112+08:00
LGWR (ospid: 41222) waits for event 'enq: CF - contention' for 74 secs.
Errors in file /u01/app/oracle/diag/rdbms/dgsdb/dgsdb1/trace/dgsdb1_lmhb_41209.trc (incident=32002) (PDBNAME=CDB$ROOT):
ORA-29770: global enqueue process LGWR (OSID 41222) is hung for more than 70 seconds
Incident details in: /u01/app/oracle/diag/rdbms/dgsdb/dgsdb1/incident/incdir_32002/dgsdb1_lmhb_41209_i32002.trc
2024-07-11T00:14:14.291083+08:00
LOCK_DBGRP: GCR_SYSTEST debug event locked group GR+DB_DGSDB by memno 0
LMHB (ospid: 41209): terminating the instance due to ORA error 29770
Cause - 'ERROR: Some process(s) is not making progress.
LMHB (ospid: 41209) is terminating the instance.
Please check LMHB trace file for more details.
Please also check the CPU load, I/O load and other system properties for anomalous behavior
ERROR: Some process(s'
2024-07-11T00:14:15.371261+08:00
ORA-1092 : opitsk aborting process
2024-07-11T00:14:15.623922+08:00
Dumping diagnostic data in directory=[cdmp_20240711001414], requested by (instance=1, osid=41209 (LMHB)), summary=[abnormal instance termination].
2024-07-11T00:14:17.066102+08:00
Instance terminated by LMHB, pid = 41209
问题分析
（1）trace日志分析
从 alert 日志中可以很明显看出是 LGWR 进程 hang 死，LMHB 进程 kill 了实例，类似的这种 Oracle 核心进行无响应导致重启的案例非常常见，MOS上有专门一篇文档介绍此类问题：
OERR: ORA-29770 "global enqueue process %s (OSID %s) is hung for more than %s seconds" Reference Note (Doc ID 2010718.1)
首先我们根据 alert 日志中的提示查看 lmhb trace 文件。
从截图中可以看到 LGWR 进程在等待 enq: CF - contention 已74秒，blocker为 inst: 1, sid: 163, ser: 19870，且为 final blocker。
继续查看往下查看会话的采样历史，故障发生时 LGWR 进程仍在等待 enq: CF - contention (still in wait)。
查找blocker（inst: 1, sid: 163, ser: 19870）的 dump 信息，该进程为RMS0，故障时等待是事件为 Disk file operations I/O ，且该会话阻塞了11个会话，其中肯定就包含 LGWR 。
还是一样继续往下查看 RMS0 的采样历史，故障发生时在Disk file operations I/O (still in wait)，且在120s的采样时间里，等待时间最长的同样是 enq: CF - contention （44s）。
把 LGWR 和 RMS0 的等待事件和时间结合起来看，可以看出开始 LGWR 和 RMS0 开始都在等待 enq: CF - contention ，但最终故障前 LGWR 仍在等待 enq: CF - contention ，RMS0 在等待 Disk file operations I/O 。
RMS0：
00:12:13 - 00:12:34 enq: CF - contention
00:12:56 - 00:13:40 enq: CF - contention
00:13:41 - 00:14:09 Disk file operations I/O (still in wait)
LGWR：
00:12:07 - 00:12:09 enq: CF - contention
00:12:15 - 00:12:34 enq: CF - contention
00:12:53 - 00:14:07 enq: CF - contention (still in wait)
这里对 enq: CF - contention 和 Disk file operations I/O 两个等待事件做下记录：
通过 Performance Degradation as a Result of ‘enq: CF - contention’ (Doc ID 1072417.1) 里的介绍，在需要读取控制文件的任何操作期间都可以看到CF队列，CF锁用于序列化控制文件事务和读写控制文件的共享部分。通常，CF锁的分配时间很短，并在以下情况下使用:
- checkpointing
- switching logfiles
- archiving redologs
- performing crash recovery
- logfile manipulation
- begin/end hot backup
- DML access for NOLOGGING objects
通过 Tuning ‘Disk file operations I/O’ (Doc ID 2494106.1) 里的介绍，该事件用于等待磁盘文件操作(例如，打开、关闭、查找和调整大小)。它还用于各种 I/O 操作，如块 dump 和密码文件访问，属于 IO 等待。
（2）OSWatcher日志分析
从 oswps 日志中搜索 rms0 查看，可以看到在故障前其状态为D。
状态D表示：不可中断的睡眠状态。进程在等待I/O（比如磁盘或网络）的时候，不能被信号（signal）中断。
到这里其实可以猜测问题极有可能出在 IO 层面，直接查看 IO 的情况。
我们看下面的 IO wait 和进程阻塞队列两张趋势图，走势基本一致，IO wait 达到20%左右，进程阻塞队列会有明显的上升。
IO的响应时间指标也至关重要，但是趋势图被一次异常高的数据给破坏，不方便阅读。
但通过下面的磁盘平均时延数据可以看到，IO 问题非常严重。
（3）AWR分析
最后看看 AWR 中关于 IO 的指标，IO问题确实非常严重。
但从 Load Profile 里看，数据库几乎没什么业务量，每秒事务量0.3，这就更不正常了。
问题结论
IO异常导致数据库关键进程 hung 进而导致实例重启。
参考文档
OERR: ORA-29770 "global enqueue process %s (OSID %s) is hung for more than %s seconds" Reference Note (Doc ID 2010718.1)
Performance Degradation as a Result of 'enq: CF - contention' (Doc ID 1072417.1)
Tuning 'Disk file operations I/O' (Doc ID 2494106.1)
