ANBOB™

最近遇到一客户一套Oracle 19c(19.13) RAC 所有实例在提示ORA-00600 [krccfl_chunk] crash，并且无法启动，该问题发生前提是启用了Block Change Tracking，但并不是它的问题，而是前一天做了一个增加表空间的错误操作，如果有低于19.17的RAC数据库，并且启用了BCT时，注意这个未公开的bug，如果加文件人为失误. 可能会导致您所有的业务中断，这里简单记录。

-- node2 db alert
2025-02-25T08:39:18.568741+08:00
Errors in file /oracle/app/oracle/diag/rdbms/anbob/anbob2/trace/anbob2_ctwr_18172.trc  (incident=1528836):
ORA-00600: internal error code, arguments: [krccfl_chunk], [0x7FFFF2998760], [236160], [], [], [], [], [], [], [], [], []
Incident details in: /oracle/app/oracle/diag/rdbms/anbob/anbob2/incident/incdir_1528836/anbob2_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. 
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/anbob/anbob2/trace/anbob2_ctwr_18172.trc:
ORA-00600: internal error code, arguments: [krccfl_chunk], [0x7FFFF2998760], [236160], [], [], [], [], [], [], [], [], []
Errors in file /oracle/app/oracle/diag/rdbms/anbob/anbob2/trace/anbob2_ctwr_18172.trc  (incident=1528837):
ORA-487 [] [] [] [] [] [] [] [] [] [] [] []
Incident details in: /oracle/app/oracle/diag/rdbms/anbob/anbob2/incident/incdir_1528837/anbob2_ctwr_18172_i1528837.trc
2025-02-25T08:40:23.665753+08:00
USER (ospid: 18172): terminating the instance due to ORA error 487


-- node1 db alert log
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   
 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/anbob/ONLINELOG/group_7.467.1075917623
2025-02-25T08:40:59.244175+08:00
ALTER SYSTEM SET remote_listener=' ldyya-scan:1521' SCOPE=MEMORY SID='anbob1';
2025-02-25T08:40:59.250464+08:00
ALTER SYSTEM SET listener_networks='' SCOPE=MEMORY SID='anbob1';
2025-02-25T08:41:02.289862+08:00
Errors in file /oracle/app/oracle/diag/rdbms/anbob/anbob1/trace/anbob1_smon_88757.trc  (incident=4657517):
ORA-00600: internal error code, arguments: [krccfl_chunk], [0x7FFFF26E7760], [236160], [], [], [], [], [], [], [], [], [] 
Incident details in: /oracle/app/oracle/diag/rdbms/anbob/anbob1/incident/incdir_4657517/anbob1_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/anbob/anbob1/trace/anbob1_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

尝试重启失败

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

日志anbob2_ctwr_18172.trc

2025-02-25 08:39:18.338*:KRC:krcc.c@3868:krccda(): ==================================================

*** 2025-02-25T08:39:18.340341+08:00
2025-02-25 08:39:18.339*:KRC:krcc.c@3884:krccda(): dumping all krcc state.
2025-02-25 08:39:18.339*:KRC:krcc.c@4164:krccdx(): krccx (0x7ffff7e1f8c0): flags=, csno=2, cde=[flags=, switchcnt=31754, scn=19470715324201, tim=02/25/2025 08:37:50], cdebno=19, bitsperfbb=3904, bitsperfbe=245952, filemax=2048, tid=9, rqcount=0
2025-02-25 08:39:18.339*:KRC:krcc.c@3888:krccda(): --------------------------------------------------
2025-02-25 08:39:18.339*:KRC:krcc.c@3889:krccda(): Checkpoints
2025-02-25 08:39:18.339*:KRC:krcc.c@3900:krccda(): Dirty buffer list
2025-02-25 08:39:18.339*:KRC:krcc.c@4023:krccdb(): krccb (0xe80cda028): flags=, cl=0x7ffff239b580 [983808, 1967616), cf=0x7ffff2997170 (1374), cr=(nil), bno=5327808, buf=0xe80ea3000, ref=02/25/2025 08:38:21, dirty=02/25/2025 08:38:21
2025-02-25 08:39:18.339*:KRC:krcc.c@4023:krccdb(): krccb (0xf00ed5bf0): flags=, cl=0x7ffff22a5560 [1967616, 2951424), cf=0x7ffff298ca00 (481), cr=(nil), bno=1869824, buf=0xf01027000, ref=02/25/2025 08:38:21, dirty=02/25/2025 08:38:21
2025-02-25 08:39:18.339*:KRC:krcc.c@4023:krccdb(): krccb (0xe008e1650): flags=, cl=0x7ffff270ff10 [0, 983808), cf=0x7ffff298ed70 (670), cr=(nil), bno=318784, buf=0xe00993000, ref=02/25/2025 08:38:21, dirty=02/25/2025 08:38:21
2025-02-25 08:39:18.339*:KRC:krcc.c@4023:krccdb(): krccb (0xdc0add3c8): flags=, cl=0x7ffff2712e30 [983808, 1967616), cf=0x7ffff2995520 (1223), cr=(nil), bno=4614080, buf=0xdc0b47000, ref=02/25/2025 08:38:21, dirty=02/25/2025 08:38:21
2025-02-25 08:39:18.339*:KRC:krcc.c@4023:krccdb(): krccb (0xe20ed6100): flags=, cl=0x7ffff229d770 [983808, 1967616), cf=0x7ffff298f490 (708), cr=(nil), bno=949824, buf=0xe210b7000, ref=02/25/2025 08:38:21, dirty=02/25/2025 08:38:21
2025-02-25 08:39:18.339*:KRC:krcc.c@4023:krccdb(): krccb (0xe608e1cc8): flags=, cl=0x7ffff272d0f8 [1967616, 2951424), cf=0x7ffff2992df0 (1014), cr=(nil), bno=3587968, buf=0xe60a4b000, ref=02/25/2025 08:38:21, dirty=02/25/2025 08:38:21
........
2025-02-25 08:39:18.494*:KRC:krcc.c@4130:krccdr(): krccr (0x13756c4c10): cb=0xe60add260, time=06/29/2093 17:33:13
2025-02-25 08:39:18.494*:KRC:krcc.c@4130:krccdr(): krccr (0x2354fb4e0): cb=0xe808e1188, time=06/29/2093 17:33:16
2025-02-25 08:39:18.494*:KRC:krcc.c@4130:krccdr(): krccr (0x14334795f8): cb=0xe210d1e30, time=06/29/2093 17:33:17
2025-02-25 08:39:18.494*:KRC:krcc.c@4130:krccdr(): krccr (0x13bf8dd8c0): cb=0xe20adda40, time=06/29/2093 17:33:18
2025-02-25 08:39:18.494*:KRC:krcc.c@4130:krccdr(): krccr (0x555de57f8): cb=0xe202ee0b8, time=06/29/2093 17:33:19
2025-02-25 08:39:18.494*:KRC:krcc.c@4130:krccdr(): krccr (0x37dddfca0): cb=0xf008e1968, time=06/29/2093 17:33:19
2025-02-25 08:39:18.494*:KRC:krcc.c@4130:krccdr(): krccr (0x13bf8db640): cb=0xe20ed5218, time=06/29/2093 17:33:20
2025-02-25 08:39:18.494*:KRC:krcc.c@4130:krccdr(): krccr (0x23dec38e0): cb=0xe80ed5380, time=06/29/2093 17:33:20
2025-02-25T08:39:18.569692+08:00
Incident 1528836 created, dump file: /oracle/app/oracle/diag/rdbms/anbob/anbob2/incident/incdir_1528836/anbob2_ctwr_18172_i1528836.trc
ORA-00600: internal error code, arguments: [krccfl_chunk], [0x7FFFF2998760], [236160], [], [], [], [], [], [], [], [], []

kge_experr : Found error ORA-600 not in expected list.
kge_experr: Dumping error frames [top = 1 : barrier top = 0]
kge_experr : [0] : Error = ORA-600 : Call stack =   ksedsts()+426<-kge_snap_callstack()+77<-kgeadse()+557<-kgerinv_internal()+44<-kgerinv()+40<-kgesinv()+21<-ksesin()+180<-krccfl()+1832<-krcchg()+127<-krcptmo()+1893<-ksb_act_run_int()+117<-ksb_act_run()+130<-ksbcti()+1880<-ksbabs()+2362<-krcpabs()+2468<-k
kge_experr: Dumping error frames - done
2025-02-25 08:39:20.429*:KRC:krcp.c@4860:krcpq_dump(): krcpq : ------------------------------------------
2025-02-25 08:39:20.429*:KRC:krcp.c@4865:krcpq_dump(): krcpq (0x5fff61670): begin_krcpq=0xd787fe000, end_krcpq=0xd796fe000,
2025-02-25 08:39:20.429*:KRC:krcp.c@4872:krcpq_dump(): empty_krcpq=0xd79223cd0(443358), full_krcpq=0xd791e0218(431809)
2025-02-25 08:39:20.429*:KRC:krcp.c@4877:krcpq_dump(): latch_krcpq (0x9d514edb8), pe_max_krcpq=655359, emptycnt_krcpq=163840,
2025-02-25 08:39:20.429*:KRC:krcp.c@4882:krcpq_dump(): flags_krcpq=17, high_scn_krcpq=19470718986311, high_pscn_krcpq=     0
2025-02-25 08:39:20.429*:KRC:krcp.c@4893:krcpq_dump(): krcpe (0xd787fe000): fno=    0, bno=   56607, scn=19470715216240, cnt=1
2025-02-25 08:39:20.429*:KRC:krcp.c@4893:krcpq_dump(): krcpe (0xd787fe018): fno=    0, bno= 3046896, scn=19470715216240, cnt=1
2025-02-25 08:39:20.429*:KRC:krcp.c@4893:krcpq_dump(): krcpe (0xd787fe030): fno=    0, bno=   56607, scn=19470715216240, cnt=1

Orafun

ksesin()+180 kernel service error signal an internal error (named)
krccfl()+1832 kernel redo block change tracking [partial hit for: krc ]
krcchg()+127 kernel redo block change tracking [partial hit for: krc ]
krcptmo()+1893 kernel redo block change tracking ctwr timeout action, this is the main loop
ksb_act_run_int()+117 kernel service background processes [partial hit for: ksb ]
ksb_act_run()+130 kernel service background processes [partial hit for: ksb ]
ksbcti()+1880 kernel service background processes call timeout/interrupts
ksbabs() kernel service background processes action based server

通过报错进程ctwr和函数KRCC能判断与 Block Change Tracking 块跟踪相关, 根据报错与call stack 不难匹配到 MOS Doc. 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)

解决方法
禁用BCT

SQL> alter database disable block change tracking;

SQL> alter database open;

那触发问题的原因呢？ 2046745.1 文档中有提到问题的原因

One of the datafile was added by mistake in Local filesystem in RAC.
Once it was detected, the datafile was taken offline.
Since BCT was enabled this in turn triggered the ora-00600.

从DB Alert LOG往前缕，能发现前一晚上确实有错误的增加数据文件到本地文件系统过，“alter tablespace xxx add datafile ‘DATA’ size xxG …”, ASM磁盘组前忘记带”+” 号， 并且数据库有提示ora-1157错误，随后有做datafile move 操作移动到了ASM中。 与文档描述较匹配，且版本低于19.17.

小结：
Oracle RAC数据库，当启用了BCT块跟踪后， 因为有人错误的增加表空间文件到本地文件系统，虽后来有修正移动到ASM DISKGROUP中，但是也刚好该版本中有bug，此日数据库BCT触发了ORA-600，并且无法正常启动，禁用BCT清理BCT信息后，重启实例正常。

打赏

微信扫一扫，打赏作者吧～