ORA-00600 [4194], [21], [25] 数据库恢复案例

Liu Maclean(刘相兵

如果自己搞不定可以找诗檀软件专业ORACLE数据库修复团队成员帮您恢复!诗檀软件专业数据库修复团队服务热线 ： 13764045638   QQ号:47079569    邮箱：service@parnassusdata.com

某军工动力技术公司Oracle数据库出现启动故障，诗檀软件工程师 王工在分析后在2个小时内完成了数据库恢复：

1 环境
数据库版本：10.2.0.1
操作系统：windows2003 64位
数据库实例名：ORCL

1.2 技术分析


数据库于2017年某星期一，发生断电，导致数据库启动时报错ORA-00600: internal error code, arguments: [4194], [21], [25], [], [], [], [], []。 详情如下：

Thu XXXX 14:25:58 2017
ORACLE V10.2.0.1.0 - Production vsnsta=0
vsnsql=14 vsnxtr=3
Windows NT Version V5.2 Service Pack 2
CPU                 : 4 - type 586, 1 Physical Cores
Process Affinity    : 0x00000000
Memory (Avail/Total): Ph:3475M/4095M, Ph+PgF:5490M/5977M, VA:1927M/2047M
Thu XXXX 14:25:58 2017
Starting ORACLE instance (normal)
LICENSE_MAX_SESSION = 0
LICENSE_SESSIONS_WARNING = 0
Picked latch-free SCN scheme 2
Using LOG_ARCHIVE_DEST_10 parameter default value as USE_DB_RECOVERY_FILE_DEST
Autotune of undo retention is turned on.
IMODE=BR
ILAT =18
LICENSE_MAX_USERS = 0
SYS auditing is disabled
ksdpec: called for event 13740 prior to event group initialization
Starting up ORACLE RDBMS Version: 10.2.0.1.0.
System parameters with non-default values:
  processes                = 150
  event                    = 10231 trace name context forever,level 10
  __shared_pool_size       = 96468992
  __large_pool_size        = 4194304
  __java_pool_size         = 4194304
  __streams_pool_size      = 0
  spfile                   = E:\ORACLE\PRODUCT\10.2.0\DB_1\DATABASE\SPFILEORCL.ORA
  sga_target               = 612368384
  control_files            = E:\ORACLE\PRODUCT\10.2.0\ORADATA\ORCL\CONTROL01.CTL, E:\ORACLE\PRODUCT\10.2.0\ORADATA\ORCL\CONTROL02.CTL, E:\ORACLE\PRODUCT\10.2.0\ORADATA\ORCL\CONTROL03.CTL
  db_block_size            = 8192
  __db_cache_size          = 499122176
  compatible               = 10.2.0.1.0
  db_file_multiblock_read_count= 16
  db_recovery_file_dest    = E:\oracle\product\10.2.0/flash_recovery_area
  db_recovery_file_dest_size= 2147483648
  undo_management          = AUTO
  undo_tablespace          = UNDOTBS1
  remote_login_passwordfile= EXCLUSIVE
  db_domain                =
  dispatchers              = (PROTOCOL=TCP) (SERVICE=orclXDB)
  job_queue_processes      = 10
  audit_file_dest          = E:\ORACLE\PRODUCT\10.2.0\ADMIN\ORCL\ADUMP
  background_dump_dest     = E:\ORACLE\PRODUCT\10.2.0\ADMIN\ORCL\BDUMP
  user_dump_dest           = E:\ORACLE\PRODUCT\10.2.0\ADMIN\ORCL\UDUMP
  core_dump_dest           = E:\ORACLE\PRODUCT\10.2.0\ADMIN\ORCL\CDUMP
  db_name                  = orcl
  open_cursors             = 300
  pga_aggregate_target     = 203423744
MMAN started with pid=4, OS id=2692
PMON started with pid=2, OS id=2684
PSP0 started with pid=3, OS id=2688
DBW0 started with pid=5, OS id=2696
LGWR started with pid=6, OS id=2700
CKPT started with pid=7, OS id=2704
SMON started with pid=8, OS id=2708
RECO started with pid=9, OS id=2712
CJQ0 started with pid=10, OS id=2716
MMON started with pid=11, OS id=2720
Thu XXXX 14:26:03 2017
starting up 1 dispatcher(s) for network address '(ADDRESS=(PARTIAL=YES)(PROTOCOL=TCP))'...
MMNL started with pid=12, OS id=2724
Thu XXXX 14:26:03 2017
starting up 1 shared server(s) ...
Thu XXXX 14:26:04 2017
alter database mount exclusive
Thu XXXX 14:26:09 2017
Setting recovery target incarnation to 3
Thu XXXX 14:26:09 2017
Successful mount of redo thread 1, with mount id 1464551420
Thu XXXX 14:26:09 2017
Database mounted in Exclusive Mode
Completed: alter database mount exclusive
Thu XXXX 14:26:09 2017
alter database open
Thu XXXX 14:26:09 2017
Beginning crash recovery of 1 threads
parallel recovery started with 3 processes
Thu XXXX 14:26:10 2017
Started redo scan
Thu XXXX 14:26:10 2017
Completed redo scan
1008 redo blocks read, 103 data blocks need recovery
Thu XXXX 14:26:10 2017
Started redo application at
Thread 1: logseq 17, block 76
Thu XXXX 14:26:10 2017
Recovery of Online Redo Log: Thread 1 Group 2 Seq 17 Reading mem 0
  Mem# 0 errs 0: E:\ORACLE\PRODUCT\10.2.0\ORADATA\ORCL\REDO02.LOG
Thu XXXX 14:26:10 2017
Completed redo application
Thu XXXX 14:26:10 2017
Completed crash recovery at
Thread 1: logseq 17, block 1084, scn 305721697
103 data blocks read, 103 data blocks written, 1008 redo blocks read
Thu XXXX 14:26:11 2017
Thread 1 advanced to log sequence 18
Thread 1 opened at log sequence 18
  Current log# 3 seq# 18 mem# 0: E:\ORACLE\PRODUCT\10.2.0\ORADATA\ORCL\REDO03.LOG
Successful open of redo thread 1
Thu XXXX 14:26:11 2017
MTTR advisory is disabled because FAST_START_MTTR_TARGET is not set
Thu XXXX 14:26:11 2017
SMON: enabling cache recovery
Thu XXXX 14:26:15 2017
Successfully onlined Undo Tablespace 1.
Thu XXXX 14:26:15 2017
SMON: enabling tx recovery
Thu XXXX 14:26:15 2017
Database Characterset is ZHS16GBK
replication_dependency_tracking turned off (no async multimaster replication found)
Starting background process QMNC
QMNC started with pid=19, OS id=2860
Thu XXXX 14:26:25 2017
Errors in file e:\oracle\product\10.2.0\admin\orcl\udump\orcl_ora_2744.trc:
ORA-00600: 内部错误代码, 参数: [4194], [21], [25], [], [], [], [], []

Thu XXXX 14:26:27 2017
db_recovery_file_dest_size of 2048 MB is 0.66% used. This is a
user-specified limit on the amount of space that will be used by this
database for recovery-related files, and does not reflect the amount of
space available in the underlying filesystem or ASM diskgroup.
Thu XXXX 14:26:29 2017
ORA-607 signalled during: alter database open...
Doing block recovery for file 2 block 483
Block recovery from logseq 18, block 75 to scn 305721829
Thu XXXX 14:26:29 2017
Errors in file e:\oracle\product\10.2.0\admin\orcl\bdump\orcl_smon_2708.trc:
ORA-00600: internal error code, arguments: [4194], [33], [40], [], [], [], [], []

Thu XXXX 14:26:29 2017
Recovery of Online Redo Log: Thread 1 Group 3 Seq 18 Reading mem 0
  Mem# 0 errs 0: E:\ORACLE\PRODUCT\10.2.0\ORADATA\ORCL\REDO03.LOG
Block recovery stopped at EOT rba 18.78.16
Block recovery completed at rba 18.78.16, scn 0.305721829
Doing block recovery for file 2 block 25
Block recovery from logseq 18, block 75 to scn 305721825
Thu XXXX 14:26:29 2017
Recovery of Online Redo Log: Thread 1 Group 3 Seq 18 Reading mem 0
  Mem# 0 errs 0: E:\ORACLE\PRODUCT\10.2.0\ORADATA\ORCL\REDO03.LOG
Block recovery completed at rba 18.76.16, scn 0.305721828
Thu XXXX 14:26:30 2017
Doing block recovery for file 2 block 12
Block recovery from logseq 18, block 76 to scn 305721831
Thu XXXX 14:26:30 2017
Recovery of Online Redo Log: Thread 1 Group 3 Seq 18 Reading mem 0
  Mem# 0 errs 0: E:\ORACLE\PRODUCT\10.2.0\ORADATA\ORCL\REDO03.LOG
Block recovery stopped at EOT rba 18.78.16
Block recovery completed at rba 18.78.16, scn 0.305721829
Doing block recovery for file 2 block 9
Block recovery from logseq 18, block 76 to scn 305721828
Thu XXXX 14:26:30 2017
Recovery of Online Redo Log: Thread 1 Group 3 Seq 18 Reading mem 0
  Mem# 0 errs 0: E:\ORACLE\PRODUCT\10.2.0\ORADATA\ORCL\REDO03.LOG
Block recovery completed at rba 18.78.16, scn 0.305721829
Thu XXXX 14:26:31 2017
Errors in file e:\oracle\product\10.2.0\admin\orcl\bdump\orcl_smon_2708.trc:
ORA-01595: error freeing extent (2) of rollback segment (1))
ORA-00607: Internal error occurred while making a change to a data block
ORA-00600: internal error code, arguments: [4194], [33], [40], [], [], [], [], []

Thu XXXX 14:31:33 2017
Errors in file e:\oracle\product\10.2.0\admin\orcl\bdump\orcl_smon_2708.trc:
ORA-00600: internal error code, arguments: [4194], [34], [27], [], [], [], [], []

Thu XXXX 14:31:33 2017
Doing block recovery for file 2 block 2130
Block recovery from logseq 18, block 280 to scn 305721962
Thu XXXX 14:31:33 2017
Recovery of Online Redo Log: Thread 1 Group 3 Seq 18 Reading mem 0
  Mem# 0 errs 0: E:\ORACLE\PRODUCT\10.2.0\ORADATA\ORCL\REDO03.LOG
Block recovery stopped at EOT rba 18.285.16
Block recovery completed at rba 18.285.16, scn 0.305721962
Doing block recovery for file 2 block 73
Block recovery from logseq 18, block 280 to scn 305721960
Thu XXXX 14:31:34 2017
Recovery of Online Redo Log: Thread 1 Group 3 Seq 18 Reading mem 0
  Mem# 0 errs 0: E:\ORACLE\PRODUCT\10.2.0\ORADATA\ORCL\REDO03.LOG
Block recovery completed at rba 18.284.16, scn 0.305721961
Thu XXXX 14:31:34 2017
Errors in file e:\oracle\product\10.2.0\admin\orcl\bdump\orcl_smon_2708.trc:
ORA-00604: error occurred at recursive SQL level 1
ORA-00607: Internal error occurred while making a change to a data block
ORA-00600: internal error code, arguments: [4194], [34], [27], [], [], [], [], []

Thu XXXX 14:33:20 2017
Errors in file e:\oracle\product\10.2.0\admin\orcl\bdump\orcl_mmon_2720.trc:
ORA-00600: internal error code, arguments: [4194], [21], [25], [], [], [], [], []

Thu XXXX 14:33:21 2017
Flush retried for xcb 0x3338fd24, pmd 0x32844c24
Doing block recovery for file 2 block 483
No block recovery was needed
Thu XXXX 14:33:21 2017
Errors in file e:\oracle\product\10.2.0\admin\orcl\bdump\orcl_mmon_2720.trc:
ORA-00600: internal error code, arguments: [4194], [21], [25], [], [], [], [], []
ORA-00600: internal error code, arguments: [4194], [21], [25], [], [], [], [], []

Thu XXXX 14:34:24 2017
Flush retried for xcb 0x3338fd24, pmd 0x32844c24
Doing block recovery for file 2 block 483
No block recovery was needed
Thu XXXX 14:34:25 2017
Errors in file e:\oracle\product\10.2.0\admin\orcl\bdump\orcl_pmon_2684.trc:
ORA-00600: internal error code, arguments: [4194], [21], [25], [], [], [], [], []

Thu XXXX 14:34:25 2017
Errors in file e:\oracle\product\10.2.0\admin\orcl\bdump\orcl_pmon_2684.trc:
ORA-00600: internal error code, arguments: [4194], [21], [25], [], [], [], [], []

PMON: terminating instance due to error 472
Thu XXXX 14:34:25 2017
Errors in file e:\oracle\product\10.2.0\admin\orcl\bdump\orcl_q001_3268.trc:
ORA-00472: PMON  process terminated with error

Thu XXXX 14:34:26 2017
Errors in file e:\oracle\product\10.2.0\admin\orcl\bdump\orcl_reco_2712.trc:
ORA-00472: PMON  process terminated with error

Thu XXXX 14:34:26 2017
Errors in file e:\oracle\product\10.2.0\admin\orcl\bdump\orcl_smon_2708.trc:
ORA-00472: PMON  process terminated with error

Thu XXXX 14:34:26 2017
Errors in file e:\oracle\product\10.2.0\admin\orcl\bdump\orcl_ckpt_2704.trc:
ORA-00472: PMON  process terminated with error

Thu XXXX 14:34:26 2017
Errors in file e:\oracle\product\10.2.0\admin\orcl\bdump\orcl_lgwr_2700.trc:
ORA-00472: PMON  process terminated with error

Thu XXXX 14:34:26 2017
Errors in file e:\oracle\product\10.2.0\admin\orcl\bdump\orcl_dbw0_2696.trc:
ORA-00472: PMON  process terminated with error

Thu XXXX 14:34:27 2017
Errors in file e:\oracle\product\10.2.0\admin\orcl\bdump\orcl_mman_2692.trc:
ORA-00472: PMON  process terminated with error

Thu XXXX 14:34:27 2017
Errors in file e:\oracle\product\10.2.0\admin\orcl\bdump\orcl_psp0_2688.trc:
ORA-00472: PMON  process terminated with error

Instance terminated by PMON, pid = 2684

错误分析：
ORA-00600[4194]错误的根本原因是 redo记录与回滚段(rollback/undo)记录之间的不一致。当ORACLE在验证undo记录时相对应的变化需要应用到undo数据块的最大undo记录上，此时若检验出错则会报ORA-00600[4194]