暂无图片
暂无图片
7
暂无图片
暂无图片
暂无图片

oracle bct触发ORA-600 [krccfl_chunk] 导致数据库宕无法启动

故障概述

收到ORACLE数据库告警,检查数据库宕,尝试启库失败,mount到open阶段ORA-03113: end-of-file on communication channel,分析日志,找到关键报错ORA-00600 [krccfl_chunk] [0x7FFFF1638760], [236160],通过mos搜索及call stack判断与BCT相关,通过关闭BCT数据库启动成功,故障恢复。

故障分析

故障环境为一套2节点的ORACLE RAC数据库

故障事件梳理分析如下

1、故障前一晚维护人员表空间添加数据文件时ASM磁盘组没带“+”号导致数据文件加到本地,这是一个ORACLE维护人员常犯的错误,事发后RAC其它节点读写该文件报错,意识到该问题后自行处理,把数据文件移动到ASM DATADG中,恢复正常。

12c后可以通过move datafile online快束解决该问题

ALTER DATABASE MOVE DATAFILE ( 'filename' | 'ASM_filename' | file_number )
[ TO ( 'filename' | 'ASM_filename' ) ]
[ REUSE ] [ KEEP  

2、第二天上班后,数据库宕,起库失败

SQL> startup
ORACLE instance started.

Total System Global Area 3.2212E+11 bytes
Fixed Size                 30154992 bytes
Variable Size            6.8719E+10 bytes
Database Buffers         2.5287E+11 bytes
Redo Buffers              506712064 bytes
Database mounted.
ORA-03113: end-of-file on communication channel
Process ID: 37145
Session ID: 26742 Serial number: 52501

3、节点2 CTWR 报错ORA-00600 [krccfl_chunk],终止数据库实例。

CTWR为Block Change Tracking后台进程

alert 日志

2025-02-25T08:39:18.568741+08:00
Errors in file /oracle/app/oracle/diag/rdbms/prod/prod2/trace/prod2_ctwr_18172.trc  (incident=1528836):
ORA-00600: internal error code, arguments: [krccfl_chunk], [0x7FFFF2998760], [236160], [], [], [], [], [], [], [], [], []
Incident details in: /oracle/app/oracle/diag/rdbms/prod/prod2/incident/incdir_1528836/prod2_ctwr_18172_i1528836.trc
2025-02-25T08:39:20.430291+08:00
Use ADRCI or Support Workbench to package the incident.
See Note 411.1 at My Oracle Support for error and packaging details.
2025-02-25T08:39:20.430465+08:00
Block change tracking service error 600. <<<<块跟踪进程CTWR ORA-600,终止实例
2025-02-25T08:39:20.560265+08:00
Dumping diagnostic data in directory=[cdmp_20250225083920], requested by (instance=2, osid=18172 (CTWR)), summary=[incident=1528836].
2025-02-25T08:40:21.569711+08:00
Errors in file /oracle/app/oracle/diag/rdbms/prod/prod2/trace/prod2_ctwr_18172.trc:
ORA-00600: internal error code, arguments: [krccfl_chunk], [0x7FFFF2998760], [236160], [], [], [], [], [], [], [], [], []
Errors in file /oracle/app/oracle/diag/rdbms/prod/prod2/trace/prod2_ctwr_18172.trc  (incident=1528837):
ORA-487 [] [] [] [] [] [] [] [] [] [] [] []
Incident details in: /oracle/app/oracle/diag/rdbms/prod/prod2/incident/incdir_1528837/prod2_ctwr_18172_i1528837.trc
2025-02-25T08:40:23.665753+08:00
USER (ospid: 18172): terminating the instance due to ORA error 487 <<<
2025-02-25T08:40:23.682724+08:00
opiodr aborting process unknown ospid (2942) as a result of ORA-1092

4、由于节点2宕,节点1需要进行instance recover,在instance recover过程中smon同样报错ORA-00600 [krccfl_chunk]导致示例终止

2025-02-25T08:40:50.309528+08:00
Increasing priority of 12 RS
Reconfiguration started (old inc 12, new inc 14)
List of instances (total 1) :
 1
Dead instances (total 1) :
 2
My inst 1   
publish big name space -  dead or down/up instance detected, invalidate domain 0 
 Global Resource Directory frozen
* dead instance detected - domain 0 invalid = TRUE 
 Communication channels reestablished
 Master broadcasted resource hash value bitmaps
 Non-local Process blocks cleaned out
2025-02-25T08:40:50.788742+08:00
 LMS 7: 51 GCS shadows cancelled, 5 closed, 0 Xw survived, skipped 0
2025-02-25T08:40:50.788775+08:00
 LMS 9: 57 GCS shadows cancelled, 6 closed, 0 Xw survived, skipped 0
2025-02-25T08:40:50.788807+08:00
 LMS 5: 69 GCS shadows cancelled, 9 closed, 0 Xw survived, skipped 0
2025-02-25T08:40:50.788851+08:00
 LMS 2: 72 GCS shadows cancelled, 5 closed, 0 Xw survived, skipped 0
2025-02-25T08:40:50.788879+08:00
 LMS 6: 68 GCS shadows cancelled, 5 closed, 0 Xw survived, skipped 0
2025-02-25T08:40:50.788886+08:00
 LMS 3: 86 GCS shadows cancelled, 7 closed, 0 Xw survived, skipped 0
2025-02-25T08:40:50.788964+08:00
 LMS 4: 61 GCS shadows cancelled, 5 closed, 0 Xw survived, skipped 0
2025-02-25T08:40:50.789078+08:00
 LMS 11: 62 GCS shadows cancelled, 6 closed, 0 Xw survived, skipped 0
2025-02-25T08:40:50.789098+08:00
 LMS 10: 130 GCS shadows cancelled, 6 closed, 0 Xw survived, skipped 0
2025-02-25T08:40:50.789101+08:00
 LMS 0: 92 GCS shadows cancelled, 8 closed, 0 Xw survived, skipped 0
2025-02-25T08:40:50.813525+08:00
 LMS 8: 77 GCS shadows cancelled, 6 closed, 0 Xw survived, skipped 0
2025-02-25T08:40:50.813605+08:00
 LMS 1: 74 GCS shadows cancelled, 4 closed, 0 Xw survived, skipped 0
2025-02-25T08:40:52.748033+08:00
 Set master node info 
 Dwn-cvts replayed, VALBLKs dubious
 All grantable enqueues granted
 Post SMON to start 1st pass IR
2025-02-25T08:40:56.916934+08:00
Reconfiguration complete (total time 6.6 secs)  <<<<
Decreasing priority of 12 RS
Decreasing number of high priority LMS from 12 to 0
2025-02-25T08:40:57.036319+08:00
Instance recovery: looking for dead threads <<<
2025-02-25T08:40:57.039627+08:00
Beginning instance recovery of 1 threads  <<<<实例2宕,开始实例RECOVER
 parallel recovery started with 8 processes
 Thread 2: Recovery starting at checkpoint rba (logseq 146431 block 3761033), scn 0
2025-02-25T08:40:57.230672+08:00
Instance Recovery "using" the Recovery Set constructed by RMS0 after pruning per Buddy Instance feature.
2025-02-25T08:40:57.230761+08:00
Started redo scan from RMS0's current RBA
2025-02-25T08:40:57.666441+08:00
Completed redo scan (from RMS0's current RBA to end of thread)
 read 324362 KB redo, 89992 data blocks need recovery
2025-02-25T08:40:58.186865+08:00
validate pdb 0, flags x10, valid 0, pdb flags x8a4 
* validated domain 0, flags = 0x8a0
2025-02-25T08:40:58.307194+08:00
Started redo application at
 Thread 2: logseq 146431, block 3761033, offset 0
2025-02-25T08:40:58.338240+08:00
Recovery of Online Redo Log: Thread 2 Group 7 Seq 146431 Reading mem 
  Mem# 0: +DATADG/prod/ONLINELOG/group_7.467.1075917623
2025-02-25T08:40:59.244175+08:00
ALTER SYSTEM SET remote_listener=' prod-scan:1521' SCOPE=MEMORY SID='prod1';
2025-02-25T08:40:59.250464+08:00
ALTER SYSTEM SET listener_networks='' SCOPE=MEMORY SID='prod1';
2025-02-25T08:41:02.289862+08:00
Errors in file /oracle/app/oracle/diag/rdbms/prod/prod1/trace/prod1_smon_88757.trc  (incident=4657517):
ORA-00600: internal error code, arguments: [krccfl_chunk], [0x7FFFF26E7760], [236160], [], [], [], [], [], [], [], [], [] <<< instance recover过程中smon 600 ,实例终止
Incident details in: /oracle/app/oracle/diag/rdbms/prod/prod1/incident/incdir_4657517/prod1_smon_88757_i4657517.trc
2025-02-25T08:41:03.714153+08:00
Use ADRCI or Support Workbench to package the incident.
See Note 411.1 at My Oracle Support for error and packaging details.
2025-02-25T08:41:03.714520+08:00
Errors in file /oracle/app/oracle/diag/rdbms/prod/prod1/trace/prod1_smon_88757.trc:
ORA-00600: internal error code, arguments: [krccfl_chunk], [0x7FFFF26E7760], [236160], [], [], [], [], [], [], [], [], []
2025-02-25T08:41:03.732519+08:00
System state dump requested by (instance=1, osid=88757 (SMON)), summary=[abnormal instance termination]. error - 'Instance is terminating.
'
SMON (ospid: 88757): terminating the instance due to ORA error 600 <<<<

5、数据库启动过程中 crash recovery 时报错ORA-00600 [krccfl_chunk],导致启动失败

Beginning crash recovery of 2 threads
 parallel recovery started with 8 processes
 Thread 2: Recovery starting at checkpoint rba (logseq 146431 block 3761033), scn 0
 Thread 1: Recovery starting at checkpoint rba (logseq 102613 block 6905023), scn 0
2025-02-25T08:46:42.150418+08:00
Started redo scan
2025-02-25T08:46:43.431398+08:00
Completed redo scan
 read 734834 KB redo, 95016 data blocks need recovery
2025-02-25T08:46:45.657386+08:00
Started redo application at
 Thread 1: logseq 102613, block 6905023, offset 0
 Thread 2: logseq 146431, block 3761033, offset 0
2025-02-25T08:46:45.665961+08:00
Recovery of Online Redo Log: Thread 1 Group 1 Seq 102613 Reading mem 0
  Mem# 0: +DATADG/prod/ONLINELOG/group_1.869.1075916753
2025-02-25T08:46:45.673326+08:00
Recovery of Online Redo Log: Thread 2 Group 7 Seq 146431 Reading mem 0
  Mem# 0: +DATADG/prod/ONLINELOG/group_7.467.1075917623
2025-02-25T08:46:50.330991+08:00
Errors in file /oracle/app/oracle/diag/rdbms/prod/prod1/trace/prod1_ora_4531.trc  (incident=5138012):
ORA-00600: internal error code, arguments: [krccfl_chunk], [0x7FFFF1638760], [236160], [], [], [], [], [], [], [], [], []
Incident details in: /oracle/app/oracle/diag/rdbms/prod/prod1/incident/incdir_5138012/prod1_ora_4531_i5138012.trc
2025-02-25T08:46:51.705226+08:00
Use ADRCI or Support Workbench to package the incident.
See Note 411.1 at My Oracle Support for error and packaging details.
2025-02-25T08:46:51.712862+08:00
Dumping diagnostic data in directory=[cdmp_20250225084651], requested by (instance=1, osid=4531), summary=[incident=5138012].
2025-02-25T08:46:51.733372+08:00
Slave encountered ORA-10388 exception during crash recovery
2025-02-25T08:46:51.733384+08:00
Slave encountered ORA-10388 exception during crash recovery
2025-02-25T08:46:51.733420+08:00
Slave encountered ORA-10388 exception during crash recovery
2025-02-25T08:46:51.733559+08:00
Recovery slave process is holding some recovery locks. Killing the instance now due to error ORA-10388. kcl_have_lock 0, kcrpxrso 0xa8da26148, rdq 1, rcq 0
Recovery slave process is holding some recovery locks. Killing the instance now due to error ORA-10388. kcl_have_lock 0, kcrpxrso 0xa8da25f68, rdq 1, rcq 0
2025-02-25T08:46:51.733613+08:00
Recovery slave process is holding some recovery locks. Killing the instance now due to error ORA-10388. kcl_have_lock 0, kcrpxrso 0xa8da259c8, rdq 1, rcq 0
2025-02-25T08:46:51.733820+08:00
Errors in file /oracle/app/oracle/diag/rdbms/prod/prod1/trace/prod1_p004_53393.trc:
ORA-10388: parallel query server interrupt (failure)
2025-02-25T08:46:51.733855+08:00
Errors in file /oracle/app/oracle/diag/rdbms/prod/prod1/trace/prod1_p003_53331.trc:
ORA-10388: parallel query server interrupt (failure)
2025-02-25T08:46:51.733924+08:00
Errors in file /oracle/app/oracle/diag/rdbms/prod/prod1/trace/prod1_p000_53213.trc:
ORA-10388: parallel query server interrupt (failure)
2025-02-25T08:46:51.733933+08:00
Slave encountered ORA-10388 exception during crash recovery
2025-02-25T08:46:51.734029+08:00
Slave encountered ORA-10388 exception during crash recovery
2025-02-25T08:46:51.734043+08:00
Slave encountered ORA-10388 exception during crash recovery
2025-02-25T08:46:51.734113+08:00
Slave encountered ORA-10388 exception during crash recovery
2025-02-25T08:46:51.734164+08:00
Recovery slave process is holding some recovery locks. Killing the instance now due to error ORA-10388. kcl_have_lock 0, kcrpxrso 0xa8da26328, rdq 1, rcq 0
2025-02-25T08:46:51.734247+08:00
Recovery slave process is holding some recovery locks. Killing the instance now due to error ORA-10388. kcl_have_lock 0, kcrpxrso 0xa8da25ba8, rdq 1, rcq 0
2025-02-25T08:46:51.734287+08:00
Recovery slave process is holding some recovery locks. Killing the instance now due to error ORA-10388. kcl_have_lock 0, kcrpxrso 0xa8da266e8, rdq 1, rcq 0
2025-02-25T08:46:51.734333+08:00
Recovery slave process is holding some recovery locks. Killing the instance now due to error ORA-10388. kcl_have_lock 0, kcrpxrso 0xa8da26508, rdq 1, rcq 0
2025-02-25T08:46:51.734396+08:00
Slave encountered ORA-10388 exception during crash recovery
2025-02-25T08:46:51.734403+08:00
Errors in file /oracle/app/oracle/diag/rdbms/prod/prod1/trace/prod1_p005_53431.trc:
ORA-10388: parallel query server interrupt (failure)
2025-02-25T08:46:51.734447+08:00
Errors in file /oracle/app/oracle/diag/rdbms/prod/prod1/trace/prod1_p001_53254.trc:
ORA-10388: parallel query server interrupt (failure)
2025-02-25T08:46:51.734515+08:00
Errors in file /oracle/app/oracle/diag/rdbms/prod/prod1/trace/prod1_p007_53544.trc:
ORA-10388: parallel query server interrupt (failure)
2025-02-25T08:46:51.734581+08:00
Recovery slave process is holding some recovery locks. Killing the instance now due to error ORA-10388. kcl_have_lock 0, kcrpxrso 0xa8da25d88, rdq 1, rcq 0
2025-02-25T08:46:51.734614+08:00
Errors in file /oracle/app/oracle/diag/rdbms/prod/prod1/trace/prod1_p006_53488.trc:
ORA-10388: parallel query server interrupt (failure)
2025-02-25T08:46:51.734783+08:00
Errors in file /oracle/app/oracle/diag/rdbms/prod/prod1/trace/prod1_p002_53296.trc:
ORA-10388: parallel query server interrupt (failure)
USER (ospid: 53393): terminating the instance due to ORA error 10388
2025-02-25T08:46:51.775775+08:00
opiodr aborting process unknown ospid (99505) as a result of ORA-1092
2025-02-25T08:46:51.777912+08:00
ORA-1092 : opitsk aborting process
2025-02-25T08:46:52.134762+08:00
System state dump requested by (instance=1, osid=53393 (P004)), summary=[abnormal instance termination].
System State dumped to trace file /oracle/app/oracle/diag/rdbms/prod/prod1/trace/prod1_diag_128944.trc
2025-02-25T08:46:52.294727+08:00
ORA-1092 : opitsk aborting process
2025-02-25T08:46:52.346837+08:00
License high water mark = 61
2025-02-25T08:46:57.796389+08:00
Instance terminated by USER, pid = 53393
2025-02-25T08:46:58.165393+08:00
Warning: 2 processes are still attacheded to shmid 983054:
 (size: 57344 bytes, creator pid: 111222, last attach/detach pid: 129368)
2025-02-25T08:46:58.348141+08:00
USER(prelim) (ospid: 102381): terminating the instance
2025-02-25T08:46:58.352611+08:00
Instance terminated by USER(prelim), pid = 102381

6、ORA-600 [krccfl_chunk]分析

krcc krcc函数为block change tracking功能函数

krccacp <=> kernel recovery block change tracking advance the checkpoint
krccckp <=>  kernel recovery block change tracking checkpoint

通过mos搜索ORA-600 [krccfl_chunk]可以找到多篇相关文章,其中2篇关键文章如下

Database doesn’t open after crash ORA-00600 [krccfl_chunk] (Doc ID 2967548.1)
Ora-600 Krccfl_chunk When Block Change Tracking enabled (Doc ID 2046745.1

总结如下

1、ORA-600 [krccfl_chunk]为BCT触发,禁用BCT启库成功。

2、RAC数据库,数据文件加到本地,同时开启BCT时,可引发该问题,通过禁用BCT,把数据文件MOVE到ASM共享存储中解决。

3、问题解决后,可以再次启用BCT后,需要重新进行0、1级备份。

4、这可能是一个未公开的BUG。

故障解决

SQL> startup mount
ORACLE instance started.

Total System Global Area 3.2212E+11 bytes
Fixed Size                 30154992 bytes
Variable Size            6.8719E+10 bytes
Database Buffers         2.5287E+11 bytes
Redo Buffers              506712064 bytes
Database mounted.
SQL> 
SQL> alter database disable block change tracking;

Database altered.

SQL> alter database open;

Database altered.

参考文档

Database doesn’t open after crash ORA-00600 [krccfl_chunk] (Doc ID 2967548.1)
Ora-600 Krccfl_chunk When Block Change Tracking enabled (Doc ID 2046745.1

「喜欢这篇文章,您的关注和赞赏是给作者最好的鼓励」
关注作者
【版权声明】本文为墨天轮用户原创内容,转载时必须标注文章的来源(墨天轮),文章链接,文章作者等基本信息,否则作者和墨天轮有权追究责任。如果您发现墨天轮中有涉嫌抄袭或者侵权的内容,欢迎发送邮件至:contact@modb.pro进行举报,并提供相关证据,一经查实,墨天轮将立刻删除相关内容。

评论