RAC环境报错ORA-00239: timeout waiting for control file enqueue排查

最近，有一个用户RAC环境反映业务缓慢；调查数据库日志发现错误ORA-00239: timeout waiting for control file enqueue: held by 'inst 2, osid 7591' for more than 900 seconds；当时系统负载很低，通过检查alert日志报错的过程(这是日志报错的过程)inst 2, osid 7591)发现持有control file enqueue的为LGWR过程；进一步调查LGWR进程TRACE日志，有很多IO缓慢的提示。

在此前提下，调查OS日志，还有一些磁盘错误信息；通过更换主机，进一步调查和确认硬件维护人员HBA然后系统恢复正常。

有关日志如下：

1.ALERT日志中的ORA-00239: timeout waiting for control file enqueue信息 Sat Feb 19 21:47:36 2022 Errors in file /u01/app/oracle/diag/rdbms/orcl/orcl1/trace/orcl1_arc0_8317.trc  (incident=1154998): ORA-00239: timeout waiting for control file enqueue: held by 'inst 2, osid 7591' for more than 900 seconds Incident details in: /u01/app/oracle/diag/rdbms/orcl/orcl1/incident/incdir_1154998/orcl1_arc0_8317_i1154998.trc opidrv aborting process ARC0 ospid (8317) as a result of ORA-603 Sat Feb 19 21:47:37 2022 Sweep [inc][1154998]: completed Sweep [inc2][1154998]: completed Sat Feb 19 21:52:52 2022 Suspending MMON slave action ketbgact_ for 82800 seconds Sat Feb 19 21:53:55 2022 Suspending MMON action 'undo usage' for 82800 seconds  2.检查数据库中持有锁的过程信息  [oracle@CRXJ-DB-2 ~]$ cd /u01/app/oracle/diag/rdbms/orcl/orcl2/trace [oracle@CRXJ-DB-2 trace]$ ls *7591* orcl2_lgwr_7591.trc  orcl2_lgwr_7591.trm [oracle@CRXJ-DB-2 trace]$ ls -al orcl2_lgwr_7591.trc -rw-r----- 1 oracle asmadmin 748774 Feb 19 20:00 orcl2_lgwr_7591.trc 3.查看LGWR进程TRACE信息 [oracle@CRXJ-DB-2 trace]$ tail -n 50 orcl2_lgwr_7591.trc …………  *** 2022-02-19 17:02:47.221 Warning: log write elapsed time 837ms, size 1KB  (set event 10468 level 4 to disable this warning)  *** 2022-02-19 19:10:58.951 Warning: log write elapsed time 516ms, size 1058KB  (set event 10468 level 4 to disable this warning)  *** 2022-02-19 19:22:50.852 Warning: log write elapsed time 534ms, size 0KB  (set event 10468 level 4 to disable this warning)  *** 2022-02-19 20:00:55.692 Warning: log write broadcast wait time 3354ms  (set event 10468 level 8 to disable this warning)        4.查看操作系统日志：  Feb 20 13:00:48 crxj-db-2 kernel: 6>sd 3:0:0:16: [sdq] Sense Key : Illegal Request [current]  Feb 20 13:00:48 crxj-db-2 kernel: sd 3:0:0:16: [sdq]  Feb 20 13:00:48 crxj-db-2 kernel: sd 3:0:0:10: [sdk] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE Feb 20 13:00:48 crxj-db-2 kernel: sd 3:0:0:10: [sdk] Sense Key : Illegal Request [current]  Feb 20 13:00:48 crxj-db-2 kernel: sd 3:0:0:10: [sdk] <> ASC=0x94 ASCQ=0x1<> ASC=0x94 ASCQ=0x1ASC=0x94 ASCQ=0x1 Feb 20 13:00:48 crxj-db-2 kernel: sd 3:0:0:16: [sdq] CDB: Read(10): 28 00 00 00 00 00 00 00 08 00 Feb 20 13:00:48 crxj-db-2 kernel: end_request: I/O error, dev sdq, sector 0 Feb 20 13:00:48 crxj-db-2 kernel: ASC=0x94 ASCQ=0x1 Feb 20 13:00:48 crxj-db-2 kernel: sd 3:0:0:10: [sdk] CDB: Read(10): 28 00 00 00 00 00 00 00 08 00 Feb 20 13:00:48 crxj-db-2 kernel: end_request: I/O error, dev sdk, sector 0 ………… Feb 20 13:00:48 crxj-db-2 kernel: sd 3:0:0:18: [sds] Sense Key : Illegal Request [current]  Feb 20 13:00:48 crxj-db-2 kernel: sd 3:0:0:18: [sds] <> ASC=0x94 ASCQ=0x1ASC=0x94 ASCQ=0x1 Feb 20 13:00:48 crxj-db-2 kernel: sd 3:0:0:18: [sds] CDB: Read(10): 28 00 00 00 00 00 00 00 08 00 Feb 20 13:00:48 crxj-db-2 kernel: end_request: I/O error, dev sds, sector 0 Feb 20 13:00:48 crxj-db-2 kernel: [current]  Feb 20 13:00:48 crxj-db-2 kernel: sd 3:0:0:2: [sdc] <> ASC=0x94 ASCQ=0x1ASC=0x94 ASCQ=0x1 Feb 20 13:00:48 crxj-db-2 kernel: sd 3:0:0:2: [sdc] CDB: Read(10): 28 00 00 00 00 00 00 00 08 00