RAC环境redo在各节点本地导致数据库故障恢复

Posted on 2025 年 08 月 09 日 by 惜分飞

最近一个运行在win平台的rac,由于断电之后,集群两个节点均无法正常启动,客户进行了一系列尝试,结果到了ora-600 kclchkblk_4错误无法继续.
通过对数据库日志分析,回溯了故障大概的原因,启动的时候报错为:
节点1启动报错

Sun Aug 03 15:21:22 2025
alter database open
This instance was first to open
Beginning crash recovery of 2 threads
 parallel recovery started with 32 processes
Started redo scan
Errors in file D:\APP\ADMINISTRATOR\diag\rdbms\orcl\orcl1\trace\orcl1_ora_7108.trc:
ORA-00314: 日志 11 (用于线程 2) 要求的 sequence# 147717 与 147541 不匹配
ORA-00312: 联机日志 11 线程 2: 'D:\REDOLOG\REDO011.LOG'
Abort recovery for domain 0
Aborting crash recovery due to error 314
Errors in file D:\APP\ADMINISTRATOR\diag\rdbms\orcl\orcl1\trace\orcl1_ora_7108.trc:
ORA-00314: 日志 11 (用于线程 2) 要求的 sequence# 147717 与 147541 不匹配
ORA-00312: 联机日志 11 线程 2: 'D:\REDOLOG\REDO011.LOG'
Abort recovery for domain 0
Errors in file D:\APP\ADMINISTRATOR\diag\rdbms\orcl\orcl1\trace\orcl1_ora_7108.trc:
ORA-00314: 日志 11 (用于线程 2) 要求的 sequence# 147717 与 147541 不匹配
ORA-00312: 联机日志 11 线程 2: 'D:\REDOLOG\REDO011.LOG'
ORA-314 signalled during: alter database open...

节点2启动报错

Sat Aug 02 15:45:43 2025
Successful mount of redo thread 2, with mount id 1735887907
Database mounted in Shared Mode (CLUSTER_DATABASE=TRUE)
Lost write protection disabled
Completed: ALTER DATABASE MOUNT /* db agent *//* {1:47460:124} */
ALTER DATABASE OPEN /* db agent *//* {1:47460:124} */
This instance was first to open
Beginning crash recovery of 2 threads
Sat Aug 02 15:45:49 2025
 parallel recovery started with 32 processes
Started redo scan
Errors in file D:\APP\ADMINISTRATOR\diag\rdbms\orcl\orcl2\trace\orcl2_ora_3444.trc:
ORA-00314: ?? 1 (???? 1) ??? sequence# 67782 ? 60818 ???
ORA-00312: ???? 1 ?? 1: 'D:\REDOLOG\REDO01.LOG'
Abort recovery for domain 0
Aborting crash recovery due to error 314
Errors in file D:\APP\ADMINISTRATOR\diag\rdbms\orcl\orcl2\trace\orcl2_ora_3444.trc:
ORA-00314: ?? 1 (???? 1) ??? sequence# 67782 ? 60818 ???
ORA-00312: ???? 1 ?? 1: 'D:\REDOLOG\REDO01.LOG'
Abort recovery for domain 0
Errors in file D:\APP\ADMINISTRATOR\diag\rdbms\orcl\orcl2\trace\orcl2_ora_3444.trc:
ORA-00314: ?? 1 (???? 1) ??? sequence# 67782 ? 60818 ???
ORA-00312: ???? 1 ?? 1: 'D:\REDOLOG\REDO01.LOG'
ORA-314 signalled during: ALTER DATABASE OPEN /* db agent *//* {1:47460:124} */...

看到这两个报错信息得出两个结论：
1）比较明显节点1需要thead 2的 group 11 sequence为147717,但是实际group 11文件的sequence为147541；而节点2启动需要thread 1的group 1 sequence为67782，但是实际中group 1文件的sequnece为60818,这两个都相差比较多,属于非正常的情况,很可能是文件本身有问题
2）这是一套win的rac架构,理论上redo应该在共享文件系统（一般是asm中)，而这个第一感觉很可能是本地文件系统中
客户当时恢复之时查询信息截图

查看了两个节点的最后redo切换信息

--节点1
Sat Aug 02 10:49:31 2025
Thread 1 advanced to log sequence 67782 (LGWR switch)
  Current log# 1 seq# 67782 mem# 0: D:\REDOLOG\REDO01.LOG

--节点2（redo每组2G,节点2长时间没跑业务,之时做数据库导出操作,所以切换时间比较久远）
Sat Jul 26 16:56:42 2025
Thread 2 advanced to log sequence 147717 (LGWR switch)
  Current log# 11 seq# 147717 mem# 0: D:\REDOLOG\REDO011.LOG

并查看两个机器d:/redolog信息(客户自行resetlogs之后的,非第一现场,但是可以确认两个节点各自有一份redo文件

本来这个是一个比较小的故障,只要把节点2的thread 1的redo拷贝到到节点1或者节点1的thread 2的redo拷贝到节点2,然后正常open库即可,现场恢复对rac不太熟悉,直接按照互联网上检索的处理方法,加上_allow_resetlogs_corruption然后强制拉库,结果不太幸运,拉库失败报ORA-600 kclchkblk_4错误

Sun Aug 03 18:59:24 2025
alter database open resetlogs
RESETLOGS is being done without consistancy checks. This may result
in a corrupted database. The database should be recreated.
RESETLOGS after incomplete recovery UNTIL CHANGE 21497084214
Resetting resetlogs activation ID 1543012633 (0x5bf88119)
Sun Aug 03 18:59:46 2025
Setting recovery target incarnation to 3
Sun Aug 03 18:59:46 2025
This instance was first to open
Picked broadcast on commit scheme to generate SCNs
Sun Aug 03 18:59:48 2025
Assigning activation ID 1735960667 (0x6778a85b)
Thread 1 opened at log sequence 1
  Current log# 1 seq# 1 mem# 0: D:\REDOLOG\REDO01.LOG
Successful open of redo thread 1
MTTR advisory is disabled because FAST_START_MTTR_TARGET is not set
Sun Aug 03 18:59:49 2025
SMON: enabling cache recovery
Instance recovery: looking for dead threads
Instance recovery: lock domain invalid but no dead threads
Errors in file D:\APP\ADMINISTRATOR\diag\rdbms\orcl\orcl1\trace\orcl1_ora_8508.trc  (incident=728324):
ORA-00600: 内部错误代码, 参数: [kclchkblk_4], [5], [200595988], [5], [22247740], [], [], [], [], [], [], []
Incident details in: D:\APP\ADMINISTRATOR\diag\rdbms\orcl\orcl1\incident\incdir_728324\orcl1_ora_8508_i728324.trc
Use ADRCI or Support Workbench to package the incident.
See Note 411.1 at My Oracle Support for error and packaging details.
Sun Aug 03 18:59:53 2025
Errors in file D:\APP\ADMINISTRATOR\diag\rdbms\orcl\orcl1\trace\orcl1_ora_8508.trc:
ORA-00704: 引导程序进程失败
ORA-00704: 引导程序进程失败
ORA-00600: 内部错误代码, 参数: [kclchkblk_4], [5], [200595988], [5], [22247740], [], [], [], [], [], [], []
Errors in file D:\APP\ADMINISTRATOR\diag\rdbms\orcl\orcl1\trace\orcl1_ora_8508.trc:
ORA-00704: 引导程序进程失败
ORA-00704: 引导程序进程失败
ORA-00600: 内部错误代码, 参数: [kclchkblk_4], [5], [200595988], [5], [22247740], [], [], [], [], [], [], []
Error 704 happened during db open, shutting down database
USER (ospid: 8508): terminating the instance due to error 704
Sun Aug 03 18:59:54 2025
opiodr aborting process unknown ospid (9480) as a result of ORA-1092
Sun Aug 03 19:00:09 2025
Instance terminated by USER, pid = 8508
ORA-1092 signalled during: alter database open resetlogs...
opiodr aborting process unknown ospid (8508) as a result of ORA-1092

这个故障之后,客户那边无法自行恢复,让我这边介入处理,对于这个错误以前处理比较多,一般就是scn问题,通过Patch SCN小工具快速解决

数据库open成功之后主要报一些ORA-600 4137,ORA-600 6006等错误

Database Characterset is ZHS16GBK
Errors in file D:\APP\ADMINISTRATOR\diag\rdbms\orcl\orcl1\trace\orcl1_smon_8300.trc  (incident=1176205):
ORA-00600: 内部错误代码, 参数: [4137], [1.14.2713957], [0], [0], [], [], [], [], [], [], [], []
Incident details in: D:\APP\ADMINISTRATOR\diag\rdbms\orcl\orcl1\incident\incdir_1176205\orcl1_smon_8300_i1176205.trc
Use ADRCI or Support Workbench to package the incident.
See Note 411.1 at My Oracle Support for error and packaging details.
Fri Aug 08 19:03:14 2025
ORACLE Instance orcl1 (pid = 25) - Error 600 encountered while recovering transaction (1, 14).
Errors in file D:\APP\ADMINISTRATOR\diag\rdbms\orcl\orcl1\trace\orcl1_smon_8300.trc:
ORA-00600: 内部错误代码, 参数: [4137], [1.14.2713957], [0], [0], [], [], [], [], [], [], [], []
Fri Aug 08 19:03:15 2025
ORACLE Instance orcl1 (pid = 25) - Error 600 encountered while recovering transaction (5, 19).
Errors in file D:\APP\ADMINISTRATOR\diag\rdbms\orcl\orcl1\trace\orcl1_smon_8300.trc:
ORA-00600: 内部错误代码, 参数: [4137], [5.19.2318502], [0], [0], [], [], [], [], [], [], [], []
Starting background process MMON
Fri Aug 08 19:03:18 2025
MMON started with pid=29, OS id=4624
Fri Aug 08 19:03:19 2025
Errors in file D:\APP\ADMINISTRATOR\diag\rdbms\orcl\orcl1\trace\orcl1_smon_8300.trc  (incident=1176207):
ORA-00600: 内部错误代码, 参数: [6006], [1], [], [], [], [], [], [], [], [], [], []
Incident details in: D:\APP\ADMINISTRATOR\diag\rdbms\orcl\orcl1\incident\incdir_1176207\orcl1_smon_8300_i1176207.trc
Starting background process MMNL
Fri Aug 08 19:03:19 2025
MMNL started with pid=30, OS id=8344
Use ADRCI or Support Workbench to package the incident.
See Note 411.1 at My Oracle Support for error and packaging details.
ORACLE Instance orcl1 (pid = 25) - Error 600 encountered while recovering transaction (46, 28) on object 197344.
Errors in file D:\APP\ADMINISTRATOR\diag\rdbms\orcl\orcl1\trace\orcl1_smon_8300.trc:
ORA-00600: 内部错误代码, 参数: [6006], [1], [], [], [], [], [], [], [], [], [], []

通过重建undo解决该错误,数据库稳定运行,没有再crash和报明显错误,导出核心数据,完成本次恢复任务.

Oracle 21c 202507补丁-21.19

Posted on 2025 年 08 月 09 日 by 惜分飞

联系：手机/微信(+86 17813235971) QQ(107644445)

标题：Oracle 21c 202507补丁-21.19

Description	Database Update	GI Update	Windows Bundle Patch
JUL2025 (21.19.0.0.0)	38068980	38068887	37962964
APR2025 (21.18.0.0.0)	37655430	37642955	37532378
JAN2025 (21.17.0.0.0)	37350281	37349593	37500148
OCT2024 (21.16.0.0.0)	36991631	36990664	36878842
JUL2024 (21.15.0.0.0)	36696242	36696109	36521898
APR2024 (21.14.0.0.0)	36352352	36352207	36219877
JAN2024 (21.13.0.0.0)	36041222	36031790	35962857
OCT2023 (21.12.0.0.0)	35740258	35738010	35681617
JUL2023 (21.11.0.0.0)	35428978	35427907	35347974
APR2023 (21.10.0.0.0)	35134934	35132566	35046488
JAN2023 (21.9.0.0.0)	34839741	34838415	34750812
Oct2022 (21.8.0.0.0)	34527084	34526142	34468137
JUL2022 (21.7.0.0.0)	34160444	34155589	34110698
APR2022 (21.6.0.0.0)	33843745	33859395	33829143
JAN2022 (21.5.0.0.0)	33516412	33531909	33589769
OCT2021 (21.4.0.0.0)	33239276	33250101	NA

参考:Assistant: Download Reference for Oracle Database/GI Update, Revision, PSU, SPU(CPU), Bundle Patches, Patchsets and Base Releases (Doc ID 2118136.2)

ORA-600 kcratr_nab_less_than_odr和ORA-600 4194故障处理

Posted on 2025 年 08 月 08 日 by 惜分飞

联系：手机/微信(+86 17813235971) QQ(107644445)

标题：ORA-600 kcratr_nab_less_than_odr和ORA-600 4194故障处理

客户一个11.2.0.1的库由于断电导致启动的时候报ORA-600 kcratr_nab_less_than_odr错误

Wed Aug 06 15:55:07 2025
ALTER DATABASE OPEN
Beginning crash recovery of 1 threads
 parallel recovery started with 27 processes
Started redo scan
Completed redo scan
 read 11787 KB redo, 4129 data blocks need recovery
Errors in file d:\app\xff\diag\rdbms\primary\orcl\trace\orcl_ora_3520.trc  (incident=2624321):
ORA-00600: 内部错误代码, 参数: [kcratr_nab_less_than_odr], [1], [111988], [42537], [43285], [], [], [], [], [], [], []
Incident details in: d:\app\xff\diag\rdbms\primary\orcl\incident\incdir_2624321\orcl_ora_3520_i2624321.trc
Aborting crash recovery due to error 600
Errors in file d:\app\xff\diag\rdbms\primary\orcl\trace\orcl_ora_3520.trc:
ORA-00600: 内部错误代码, 参数: [kcratr_nab_less_than_odr], [1], [111988], [42537], [43285], [], [], [], [], [], [], []
Errors in file d:\app\xff\diag\rdbms\primary\orcl\trace\orcl_ora_3520.trc:
ORA-00600: 内部错误代码, 参数: [kcratr_nab_less_than_odr], [1], [111988], [42537], [43285], [], [], [], [], [], [], []
ORA-600 signalled during: ALTER DATABASE OPEN...

类似的ORA-600 kcratr_nab_less_than_odr故障处理不少,但是应用redo完成之后,再open报错的不多:
12c启动报kcratr_nab_less_than_odr
又一例ORA-600 kcratr_nab_less_than_odr
ORA-600 kcratr_nab_less_than_odr故障解决
 差点被误操作的ORA-600 kcratr_nab_less_than_odr故障
 11.2.0.4库中遇到ORA-600 kcratr_nab_less_than_odr报错
但是这个客户比较不幸,经过一系列尝试打开数据库,但是报ORA-600 4194错误

Wed Aug 06 17:09:33 2025
ALTER DATABASE RECOVER  database until cancel using backup controlfile  
Media Recovery Start
 started logmerger process
Parallel Media Recovery started with 28 slaves
ORA-279 signalled during: ALTER DATABASE RECOVER  database until cancel using backup controlfile  ...
Wed Aug 06 17:10:17 2025
ALTER DATABASE RECOVER    LOGFILE 'D:\app\xff\oradata\orcl\REDO05.LOG'  
Media Recovery Log D:\app\xff\oradata\orcl\REDO05.LOG
Wed Aug 06 17:10:17 2025
Incomplete recovery applied all redo ever generated.
Recovery completed through change 2118813100 time 08/06/2025 15:02:15
Completed: ALTER DATABASE RECOVER    LOGFILE 'D:\app\xff\oradata\orcl\REDO05.LOG'  
Wed Aug 06 17:14:05 2025
alter database open resetlogs
Archived Log entry 188143 added for thread 1 sequence 111985 ID 0x634438e6 dest 1:
Archived Log entry 188144 added for thread 1 sequence 111986 ID 0x634438e6 dest 1:
Archived Log entry 188145 added for thread 1 sequence 111987 ID 0x634438e6 dest 1:
Archived Log entry 188146 added for thread 1 sequence 111984 ID 0x634438e6 dest 1:
Archived Log entry 188147 added for thread 1 sequence 111988 ID 0x634438e6 dest 1:
RESETLOGS after complete recovery through change 2118813100
Resetting resetlogs activation ID 1665415398 (0x634438e6)
Wed Aug 06 17:15:03 2025
Archived Log entry 188148 added for thread 1 sequence 1 ID 0x677cfac1 dest 1:
Successfully onlined Undo Tablespace 2.
Dictionary check beginning
Dictionary check complete
Verifying file header compatibility for 11g tablespace encryption..
Verifying 11g file header compatibility for tablespace encryption completed
SMON: enabling tx recovery
Database Characterset is ZHS16GBK
No Resource Manager plan active
Errors in file d:\app\xff\diag\rdbms\primary\orcl\trace\orcl_smon_2428.trc  (incident=3264274):
ORA-00600: internal error code, arguments: [4194], [], [], [], [], [], [], [], [], [], [], []
Incident details in: d:\app\xff\diag\rdbms\primary\orcl\incident\incdir_3264274\orcl_smon_2428_i3264274.trc
replication_dependency_tracking turned off (no async multimaster replication found)
Starting background process QMNC
Wed Aug 06 17:15:06 2025
QMNC started with pid=34, OS id=3052 
LOGSTDBY: Validating controlfile with logical metadata
LOGSTDBY: Validation complete
Completed: alter database open resetlogs

后续由于该undo异常报ORA-01595和ORA-600 4194等错误导致数据库crash

Wed Aug 06 17:15:49 2025
Doing block recovery for file 3 block 888
Resuming block recovery (PMON) for file 3 block 888
Block recovery from logseq 2, block 316 to scn 2118813732
Recovery of Online Redo Log: Thread 1 Group 2 Seq 2 Reading mem 0
  Mem# 0: D:\APP\xff\ORADATA\ORCL\REDO02.LOG
Block recovery stopped at EOT rba 2.447.16
Block recovery completed at rba 2.447.16, scn 0.2118813732
Doing block recovery for file 3 block 1960
Resuming block recovery (PMON) for file 3 block 1960
Block recovery from logseq 2, block 316 to scn 2118813622
Recovery of Online Redo Log: Thread 1 Group 2 Seq 2 Reading mem 0
  Mem# 0: D:\APP\xff\ORADATA\ORCL\REDO02.LOG
Block recovery completed at rba 2.317.16, scn 0.2118813626
Errors in file d:\app\xff\diag\rdbms\primary\orcl\trace\orcl_smon_2428.trc:
ORA-01595: error freeing extent (2) of rollback segment (27))
ORA-00600: internal error code, arguments: [4194], [], [], [], [], [], [], [], [], [], [], []

接手这个库之后,处理工作相对比较简单,直接对异常undo进行重建即可

Thu Aug 07 09:35:08 2025
create undo tablespace undotbs2 datafile 'D:\APP\xff\ORADATA\ORCL\undotbs02.dbf' size 128M autoextend on
Completed: create undo tablespace undotbs2 datafile 'D:\APP\xff\ORADATA\ORCL\undotbs02.dbf' size 128M autoextend on
Thu Aug 07 09:37:53 2025
drop tablespace UNDOTBS1 including contents and datafiles
Deleted file D:\APP\xff\ORADATA\ORCL\UNDOTBS01.DBF
Completed: drop tablespace UNDOTBS1 including contents and datafiles

然后数据库报大量的ORA-600 kdsgrp1错误

Thu Aug 07 10:03:53 2025
Errors in file d:\app\xff\diag\rdbms\primary\orcl\trace\orcl_ora_6156.trc  (incident=5121829):
ORA-00600: 内部错误代码, 参数: [kdsgrp1], [], [], [], [], [], [], [], [], [], [], []
Thu Aug 07 10:04:00 2025
Errors in file d:\app\xff\diag\rdbms\primary\orcl\trace\orcl_ora_4564.trc  (incident=5121501):
ORA-00600: 内部错误代码, 参数: [kdsgrp1], [], [], [], [], [], [], [], [], [], [], []
Thu Aug 07 10:04:06 2025
Errors in file d:\app\xff\diag\rdbms\primary\orcl\trace\orcl_ora_9160.trc  (incident=5121837):
ORA-00600: 内部错误代码, 参数: [kdsgrp1], [], [], [], [], [], [], [], [], [], [], []
Thu Aug 07 10:04:16 2025
Errors in file d:\app\xff\diag\rdbms\primary\orcl\trace\orcl_ora_5868.trc  (incident=5121821):
ORA-00600: 内部错误代码, 参数: [kdsgrp1], [], [], [], [], [], [], [], [], [], [], []
Thu Aug 07 10:04:28 2025
Errors in file d:\app\xff\diag\rdbms\primary\orcl\trace\orcl_ora_4448.trc  (incident=5122077):
ORA-00600: 内部错误代码, 参数: [kdsgrp1], [], [], [], [], [], [], [], [], [], [], []

* kdsgrp1-1: *************************************************
            row 0x013a9ae9.0 continuation at
            0x013a9ae9.0 file# 4 block# 3840745 slot 0 not found
KDSTABN_GET: 0 ..... ntab: 1
curSlot: 0 ..... nrows: 2
kdsgrp - dump CR block dba=0x013a9ae9
Block header dump:  0x013a9ae9
 Object id on Block? Y
 seg/obj: 0x31dd9  csc: 0x00.7dc0f246  itc: 2  flg: E  typ: 1 - DATA
     brn: 0  bdba: 0x13a9082 ver: 0x01 opc: 0
     inc: 2  exflg: 0
 
 Itl           Xid                  Uba         Flag  Lck        Scn/Fsc
0x01   0x0000.000.00000000  0x00000000.0000.00  ----    0  fsc 0x0000.00000000
0x02   0x0000.000.00000000  0x00000000.0000.00  ----    0  fsc 0x0000.00000000

通过分析是由于index和表记录不匹配导致,对index进行重新rebuild完成本次修复任务.

pg_wal中文件的名称中的logseq和实际文件中的logseq不匹配

Posted on 2025 年 08 月 06 日 by 惜分飞

联系：手机/微信(+86 17813235971) QQ(107644445)

标题：pg_wal中文件的名称中的logseq和实际文件中的logseq不匹配

一个朋友由于某种原因给我发了一个pg_wal里面的wal文件,让我帮忙分析下故障原因,我打开文件之后发现文件编号小的修改时间比编号大的文件修改时间要新

wal日志文件命名规则：
我们看到的wal日志是这样的：0000000100004D6E000000CF
其中前8位:00000001表示timeline
中间8位：00004D6E表示logid
最后8位：000000CF表示logseg
在上述截图中,可以看到logseq为CF的文件比D0的要新很多,这个初步给人感觉不太正常.使用pg_waldump分别对其进行dump操作

[postgres@xifenfei bin]$ pg_waldump /data/wal/0000000100004D6E000000D0|head -10
pg_waldump: fatal: could not find a valid record after 4D6E/D0000000

这样可以看出来CF的wal文件可以正常dump出来,但是D0的文件dump报pg_waldump: fatal: could not find a valid record after类似异常.通过od命令分别对两个文件进行分析

[postgres@xifenfei bin]$ od -x /data/wal/0000000100004D6E000000CF|head -1
0000000 d101 0006 0001 0000 0000 cf00 4d6e 0000
[postgres@xifenfei bin]$ od -x /data/wal/0000000100004D6E000000D0|head -1
0000000 d101 0007 0001 0000 0000 9400 4d6e 0000

从第8个字节到第12个字节结束为logseq的值,这里明显可以看出来D0文件的logseq值和实际文件中的不一致.尝试把D0修改为94之后即可正常的pg_waldump进行分析