年归档：2022

commit_wait和commit_logging设置不当导致数据库无法正常启动

发表于 2022 年 3 月 25 日由惜分飞

客户数据库设置以下参数，突然掉电之后，数据库无法正常启动

  commit_wait              = "NOWAIT"
  commit_logging           = "BATCH"

数据库open报错

alter database open
Block change tracking file is current.
Beginning crash recovery of 1 threads
 parallel recovery started with 31 processes
Started redo scan
Errors in file /media/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_28711.trc  (incident=8002955):
ORA-00353: log corruption near block 3 change 17372812227460 time 03/20/2022 00:11:51
ORA-00312: online log 12315  thread 1: '/media/oracle/redolog/redo05.log'
Aborting crash recovery due to error 399
Errors in file /media/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_28711.trc:
ORA-00399: corrupt change description in redo log
ORA-00353: log corruption near block 3 change 17372812227460 time 03/20/2022 00:11:51
ORA-00312: online log 12315 thread 1: '/media/oracle/redolog/redo05.log'
Errors in file /media/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_28711.trc:
ORA-00399: corrupt change description in redo log
ORA-00353: log corruption near block 3 change 17372812227460 time 03/20/2022 00:11:51
ORA-00312: online log 12315  thread 1: '/media/oracle/redolog/redo05.log'
ORA-399 signalled during: alter database open...

报错信息比较明显是由于redo损坏导致,尝试强制open库

Sun Mar 20 18:32:35 2022
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 17372812227456
Resetting resetlogs activation ID 1627598093 (0x61032d0d)
Sun Mar 20 18:34:08 2022
Setting recovery target incarnation to 2
Sun Mar 20 18:34:08 2022
Initializing SCN for created control file
Database SCN compatibility initialized to 3
Warning - High Database SCN: Current SCN value is 17372812227459, threshold SCN value is 0
If you have not previously reported this warning on this database, 
please notify Oracle Support so that additional diagnosis can be performed.
Sun Mar 20 18:34:08 2022
Assigning activation ID 1627615603 (0x61037173)
Thread 1 opened at log sequence 1
  Current log# 2 seq# 1 mem# 0: /media/oracle/redolog/redo02.log
Successful open of redo thread 1
MTTR advisory is disabled because FAST_START_MTTR_TARGET is not set
Sun Mar 20 18:34:08 2022
SMON: enabling cache recovery
Errors in file /media/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_14369.trc  (incident=8003142):
ORA-00600: internal error code, arguments: [2662], [4044], [3964482439], [4044], [3964488833], [12669344], 
Incident details in: /media/oracle/diag/rdbms/orcl/orcl/incident/incdir_8003142/orcl_ora_14369_i8003142.trc
Errors in file /media/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_14369.trc  (incident=8003143):
ORA-00353: log corruption near block 3 change 17372812227462 time 03/20/2022 18:34:10
ORA-00312: online log 2 thread 1: '/media/oracle/redolog/redo02.log'
ORA-00600: internal error code, arguments: [2662], [4044], [3964482439], [4044], [3964488833], [12669344], 
Incident details in: /media/oracle/diag/rdbms/orcl/orcl/incident/incdir_8003143/orcl_ora_14369_i8003143.trc
Errors in file /media/oracle/diag/rdbms/orcl/orcl/incident/incdir_8003142/orcl_ora_14369_i8003142.trc:
ORA-00399: corrupt change description in redo log
ORA-00353: log corruption near block 3 change 17372812227462 time 03/20/2022 18:34:10
ORA-00312: online log 2 thread 1: '/media/oracle/redolog/redo02.log'
ORA-00600: internal error code, arguments: [2662], [4044], [3964482439], [4044], [3964488833], [12669344], 
Errors in file /media/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_14369.trc  (incident=8003144):
ORA-00353: log corruption near block 3 change 17372812227462 time 03/20/2022 18:34:10
ORA-00334: archived log: '/media/oracle/redolog/redo02.log'
ORA-00600: internal error code, arguments: [2662], [4044], [3964482439], [4044], [3964488833], [12669344], 
Incident details in: /media/oracle/diag/rdbms/orcl/orcl/incident/incdir_8003144/orcl_ora_14369_i8003144.trc
Sun Mar 20 18:34:11 2022
ORA-00603: ORACLE server session terminated by fatal error
ORA-00600: internal error code, arguments: [2662], [4044], [3964482444], [4044], [3964488833], [12669344], 
ORA-00600: internal error code, arguments: [2662], [4044], [3964482443], [4044], [3964488833], [12669344], 
ORA-01092: ORACLE instance terminated. Disconnection forced
ORA-00600: internal error code, arguments: [2662], [4044], [3964482439], [4044], [3964488833], [12669344],

强制open数据库报ora-600 2662错误,比较常见,通过修改scn再尝试open库

Sun Mar 20 18:38:43 2022
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 17372812227460
Resetting resetlogs activation ID 1627615603 (0x61037173)
Sun Mar 20 18:40:02 2022
Setting recovery target incarnation to 2
Sun Mar 20 18:40:02 2022
Initializing SCN for created control file
Database SCN compatibility initialized to 3
Warning - High Database SCN: Current SCN value is 17372812227463, threshold SCN value is 0
If you have not previously reported this warning on this database,
please notify Oracle Support so that additional diagnosis can be performed.
Sun Mar 20 18:40:02 2022
Assigning activation ID 1627669665 (0x610444a1)
Thread 1 opened at log sequence 1
Current log# 2 seq# 1 mem# 0: /media/oracle/redolog/redo02.log
Successful open of redo thread 1
MTTR advisory is disabled because FAST_START_MTTR_TARGET is not set
Sun Mar 20 18:40:02 2022
SMON: enabling cache recovery
Undo initialization finished serial:0 start:779809538 end:779809788 diff:250 (2 seconds)
Dictionary check beginning
Tablespace 'TEMP' #3 found in data dictionary,
but not in the controlfile. Adding to controlfile.
Dictionary check complete
Verifying file header compatibility for 11g tablespace encryption..
Verifying 11g file header compatibility for tablespace encryption completed
SMON: enabling tx recovery
*********************************************************************
WARNING: The following temporary tablespaces contain no files.
This condition can occur when a backup controlfile has
been restored. It may be necessary to add files to these
tablespaces. That can be done using the SQL statement:

ALTER TABLESPACE <tablespace_name> ADD TEMPFILE

Alternatively, if these temporary tablespaces are no longer
needed, then they can be dropped.
Empty temporary tablespace: TEMP
*********************************************************************
Database Characterset is AL32UTF8
No Resource Manager plan active
**********************************************************
WARNING: Files may exists in db_recovery_file_dest
that are not known to the database. Use the RMAN command
CATALOG RECOVERY AREA to re-catalog any such files.
If files cannot be cataloged, then manually delete them
using OS command.
One of the following events caused this:
1. A backup controlfile was restored.
2. A standby controlfile was restored.
3. The controlfile was re-created.
4. db_recovery_file_dest had previously been enabled and
then disabled.
**********************************************************
replication_dependency_tracking turned off (no async multimaster replication found)
Starting background process QMNC
Sun Mar 20 18:40:04 2022
QMNC started with pid=55, OS id=16232
LOGSTDBY: Validating controlfile with logical metadata
LOGSTDBY: Validation complete
Sun Mar 20 18:40:05 2022
db_recovery_file_dest_size of 3882 MB is 0.00% 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.
Sun Mar 20 18:40:05 2022
Starting background process CJQ0
Sun Mar 20 18:40:05 2022
CJQ0 started with pid=58, OS id=16251
Completed: alter database open resetlogs

后续增加temp,导出数据到新库,恢复完成

发表在 Oracle备份恢复 | 标签为 ORA-00353 ORA-00312, ORA-600 2662 | 评论关闭

ORA-00742 ORA-00312故障恢复

发表于 2022 年 2 月 27 日由惜分飞

11.2.0.4版本数据库启动报ORA-00742 ORA-00312错误

Fri Feb 25 15:02:27 2022
ALTER DATABASE   MOUNT
Successful mount of redo thread 1, with mount id 2001521283
Database mounted in Exclusive Mode
Lost write protection disabled
Completed: ALTER DATABASE   MOUNT
Fri Feb 25 15:02:31 2022
ALTER DATABASE OPEN
Beginning crash recovery of 1 threads
 parallel recovery started with 11 processes
Started redo scan
Aborting crash recovery due to error 742
Errors in file /u01/app/oracle/diag/rdbms/xifenfei/xifenfei/trace/xifenfei_ora_98720.trc:
ORA-00742: Log read detects lost write in thread %d sequence %d block %d
ORA-00312: online log 1 thread 1: '/u01/app/oracle/oradata/xifenfei/redo01.log'
Errors in file /u01/app/oracle/diag/rdbms/xifenfei/xifenfei/trace/xifenfei_ora_98720.trc:
ORA-00742: Log read detects lost write in thread %d sequence %d block %d
ORA-00312: online log 1 thread 1: '/u01/app/oracle/oradata/xifenfei/redo01.log'
ORA-742 signalled during: ALTER DATABASE OPEN...

现场人员进行错误恢复尝试

Fri Feb 25 15:17:17 2022
ALTER DATABASE RECOVER    CANCEL  
Fri Feb 25 15:17:17 2022
Errors in file /u01/app/oracle/diag/rdbms/xifenfei/xifenfei/trace/xifenfei_pr00_130027.trc:
ORA-01547: warning: RECOVER succeeded but OPEN RESETLOGS would get error below
ORA-01194: file 1 needs more recovery to be consistent
ORA-01110: data file 1: '/u01/app/oracle/oradata/xifenfei/system01.dbf'
ORA-1547 signalled during: ALTER DATABASE RECOVER    CANCEL  ...
ALTER DATABASE RECOVER CANCEL 
ORA-1112 signalled during: ALTER DATABASE RECOVER CANCEL ...

通过一些人工修复异常redo之后,数据库顺利直接open成功

ALTER DATABASE RECOVER  database  
Media Recovery Start
 started logmerger process
Parallel Media Recovery started with 12 slaves
Sat Feb 26 09:45:07 2022
Recovery of Online Redo Log: Thread 1 Group 1 Seq 5281 Reading mem 0
  Mem# 0: /u01/app/oracle/oradata/xifenfei/redo01.log
Sat Feb 26 09:45:08 2022
Media Recovery Complete (xifenfei)
Completed: ALTER DATABASE RECOVER  database  
Sat Feb 26 09:45:25 2022
alter database open
Beginning crash recovery of 1 threads
 parallel recovery started with 11 processes
Started redo scan
Completed redo scan
 read 4861 KB redo, 0 data blocks need recovery
Started redo application at
 Thread 1: logseq 5281, block 2, scn 262332375
Recovery of Online Redo Log: Thread 1 Group 1 Seq 5281 Reading mem 0
  Mem# 0: /u01/app/oracle/oradata/xifenfei/redo01.log
Completed redo application of 0.00MB
Completed crash recovery at
 Thread 1: logseq 5281, block 9725, scn 262353916
 0 data blocks read, 0 data blocks written, 4861 redo k-bytes read
Initializing SCN for created control file
Database SCN compatibility initialized to 3
Warning - High Database SCN: Current SCN value is 262353917, threshold SCN value is 0
If you have not previously reported this warning on this database, 
please notify Oracle Support so that additional diagnosis can be performed.
Sat Feb 26 09:45:25 2022
Thread 1 advanced to log sequence 5282 (thread open)
Thread 1 opened at log sequence 5282
  Current log# 2 seq# 5282 mem# 0: /u01/app/oracle/oradata/xifenfei/redo02.log
Successful open of redo thread 1
MTTR advisory is disabled because FAST_START_MTTR_TARGET is not set
Sat Feb 26 09:45:25 2022
SMON: enabling cache recovery
[111600] Successfully onlined Undo Tablespace 2.
Undo initialization finished serial:0 start:69076924 end:69077284 diff:360 (3 seconds)
Dictionary check beginning
Tablespace 'TEMP' #3 found in data dictionary,
but not in the controlfile. Adding to controlfile.
Dictionary check complete
Verifying file header compatibility for 11g tablespace encryption..
Verifying 11g file header compatibility for tablespace encryption completed
Database Characterset is ZHS16GBK
No Resource Manager plan active
replication_dependency_tracking turned off (no async multimaster replication found)
Starting background process QMNC
Sat Feb 26 09:45:26 2022
QMNC started with pid=20, OS id=116832 
LOGSTDBY: Validating controlfile with logical metadata
LOGSTDBY: Validation complete
Completed: alter database open

数据库正常open,数据0丢失,数据库可以直接使用

发表在 Oracle备份恢复 | 标签为 ORA-00742, ORA-00742 ORA-00312 | 评论关闭

110T oracle故障恢复

发表于 2022 年 2 月 23 日由惜分飞

有客户一套110T的数据库由于存储控制器故障导致数据库无法正常启动,启动报错如下：

Wed Feb  2 23:16:13 2022
Recovery of Online Redo Log: Thread 1 Group 7 Seq 1647469 Reading mem 0
  Mem# 0: /dev/vgredo6/rredo7b
  Mem# 1: /dev/vgredo4/rredo7a
Wed Feb  2 23:16:14 2022
Errors in file /opt/oracle/admin/xifenfei/udump/xifenfei_ora_26754.trc:
ORA-07445: exception encountered: core dump [_memcpy()+7040] [SIGSEGV] [Address not mapped to object] [] [] []
Wed Feb  2 23:16:15 2022
Errors in file /opt/oracle/admin/xifenfei/udump/xifenfei_ora_26754.trc:
ORA-07445: exception encountered: core dump [kcbzdh()+560] [SIGSEGV] [Address not mapped to object] [] [] []
ORA-07445: exception encountered: core dump [_memcpy()+7040] [SIGSEGV] [Address not mapped to object] [] [] []
Wed Feb  2 23:16:16 2022
Errors in file /opt/oracle/admin/xifenfei/udump/xifenfei_ora_26754.trc:
ORA-07445: exception encountered: core dump [kcbzdh()+560] [SIGSEGV] [Address not mapped to object] [] [] []
ORA-07445: exception encountered: core dump [kcbzdh()+560] [SIGSEGV] [Address not mapped to object] [] [] []
ORA-07445: exception encountered: core dump [_memcpy()+7040] [SIGSEGV] [Address not mapped to object] [] [] []
Wed Feb  2 23:16:16 2022
Errors in file /opt/oracle/admin/xifenfei/udump/xifenfei_ora_26754.trc:
ORA-00600: internal error code, arguments: [kghstack_free2], [], [], [], [], [], [], []
ORA-00607: Internal error occurred while making a change to a data block
ORA-00602: internal programming exception
ORA-07445: exception encountered: core dump [kcbzdh()+560] [SIGSEGV] [Address not mapped to object] [] [] []
ORA-07445: exception encountered: core dump [kcbzdh()+560] [SIGSEGV] [Address not mapped to object] [] [] []
ORA-07445: exception encountered: core dump [_memcpy()+7040] [SIGSEGV] [Address not mapped to object] [] [] []
Wed Feb  2 23:16:26 2022
Errors in file /opt/oracle/admin/xifenfei/bdump/xifenfei_pmon_26722.trc:
ORA-07445: exception encountered: core dump [kcbzre1()+6593] [SIGSEGV] [Address not mapped to object] [] [] []
Wed Feb  2 23:16:27 2022
Errors in file /opt/oracle/admin/xifenfei/bdump/xifenfei_pmon_26722.trc:
ORA-07445: exception encountered: core dump [kcbs_dump_adv_state()+1200] [SIGSEGV][] []
ORA-07445: exception encountered: core dump [kcbzre1()+6593] [SIGSEGV] [Address not mapped to object] [] [] []
Wed Feb  2 23:16:27 2022
Errors in file /opt/oracle/admin/xifenfei/bdump/xifenfei_pmon_26722.trc:
ORA-00602: internal programming exception
ORA-07445: exception encountered: core dump [kcbs_dump_adv_state()+1200] [SIGSEGV][] []
ORA-07445: exception encountered: core dump [kcbzre1()+6593] [SIGSEGV] [Address not mapped to object] [] [] []
Wed Feb  2 23:17:11 2022
PSP0: terminating instance due to error 472
Instance terminated by PSP0, pid = 26724

该错误原因是由于redo信息和数据文件block信息不匹配导致无法正常应用日志,从而出现异常,在后续的recover 中还出现以下错误

Fri Feb 18 16:09:59 2022
ALTER DATABASE RECOVER  datafile 609,610,611,612,613,614,615,602,603,604,605,606,607,608  
Fri Feb 18 16:09:59 2022
Media Recovery Start
 parallel recovery started with 16 processes
Fri Feb 18 16:10:00 2022
Recovery of Online Redo Log: Thread 1 Group 7 Seq 1647469 Reading mem 0
  Mem# 0: /dev/vgredo6/rredo7b
  Mem# 1: /dev/vgredo4/rredo7a
Fri Feb 18 16:12:17 2022
Errors in file /opt/oracle/admin/xifenfei/bdump/xifenfei_p000_22509.trc:
ORA-00600: internal error code, arguments: [6101], [0], [42], [96], [], [], [], []
Fri Feb 18 16:18:51 2022
Errors in file /opt/oracle/admin/xifenfei/bdump/xifenfei_p000_22509.trc:
ORA-10562: Error occurred while applying redo to data block (file# 602, block# 1693691)
ORA-10564: tablespace DBS_DCDL_PT
ORA-01110: data file 602: '/dev/vgora12/rdbs_dcdl_pt0155'
ORA-10561: block type 'TRANSACTION MANAGED INDEX BLOCK', data object# 33682645
ORA-00600: internal error code, arguments: [6101], [0], [42], [96], [], [], [], []
Fri Feb 18 16:18:55 2022
Media Recovery failed with error 12801

Fri Feb 18 18:23:59 2022
Errors in file /opt/oracle/admin/xifenfei/bdump/xifenfei_dbw1_22483.trc:
ORA-07445: exception encountered: core dump [kcbs_dump_adv_state()+1200] [SIGSEGV][] []
ORA-07445: exception encountered: core dump [ksuitm()+2400] [SIGSEGV] [] [] [] []
ORA-00472: PMON  process terminated with error
Fri Feb 18 18:24:04 2022
DBW3: terminating instance due to error 472
Fri Feb 18 18:24:04 2022
Errors in file /opt/oracle/admin/xifenfei/bdump/xifenfei_dbw3_22487.trc:
ORA-07445: exception encountered: core dump [ksuitm()+2400] [SIGSEGV] [] [] [] []
ORA-00472: PMON  process terminated with error
Fri Feb 18 18:24:04 2022
Errors in file /opt/oracle/admin/xifenfei/bdump/xifenfei_dbw3_22487.trc:
ORA-07445: exception encountered: core dump [kcbs_dump_adv_state()+1200] [SIGSEGV] [] []
ORA-07445: exception encountered: core dump [ksuitm()+2400] [SIGSEGV] [] [] [] []
ORA-00472: PMON  process terminated with error
Fri Feb 18 18:24:09 2022
LGWR: terminating instance due to error 472
Fri Feb 18 18:24:09 2022
Errors in file /opt/oracle/admin/xifenfei/bdump/xifenfei_lgwr_22489.trc:
ORA-07445: exception encountered: core dump [ksuitm()+2400] [SIGSEGV] [] [] [] []
ORA-00472: PMON  process terminated with error

从sqlplus中看到类似一些报错

SQL>  recover datafile 601;
ORA-03113: end-of-file on communication channel

SQL> recover datafile 1066;
ORA-00283: recovery session canceled due to errors
ORA-12801: error signaled in parallel query server P015
ORA-00600: internal error code, arguments: [2037], [207064103], [207064103],
[162], [6], [1], [1833009883], [1130705717]


SQL> recover datafile 1065;
ORA-00283: recovery session canceled due to errors
ORA-12801: error signaled in parallel query server P004
ORA-00600: internal error code, arguments: [kcbzpb_1], [142189139], [3], [0],
[], [], [], []


SQL> recover datafile 2042;
ORA-00283: recovery session canceled due to errors
ORA-12801: error signaled in parallel query server P014
ORA-00600: internal error code, arguments: [3020], [627], [3234156],
[2633062764], [], [], [], []
ORA-10567: Redo is inconsistent with data block

通过屏蔽一致性,强制open库成功

Sun Feb 20 21:20:06 2022
SMON: enabling tx recovery
Sun Feb 20 21:20:06 2022
Database Characterset is ZHS16GBK
Sun Feb 20 21:20:07 2022
ORACLE Instance xifenfei (pid = 38) - Error 376 encountered while recovering transaction (74, 17) on object 34131051.
Sun Feb 20 21:20:07 2022
Errors in file /opt/oracle/admin/xifenfei/bdump/xifenfei_smon_25140.trc:
ORA-00376: file 1416 cannot be read at this time
ORA-01110: data file 1416: '/dev/vgora14/rdbs_icdl_pt116'
Sun Feb 20 21:20:08 2022
Stopping background process MMNL
Sun Feb 20 21:20:09 2022
ORACLE Instance xifenfei (pid = 38) - Error 376 encountered while recovering transaction (88, 36) on object 33514955.
Sun Feb 20 21:20:09 2022
Errors in file /opt/oracle/admin/xifenfei/bdump/xifenfei_smon_25140.trc:
ORA-00376: file 1264 cannot be read at this time
ORA-01110: data file 1264: '/dev/vgora14/rdbs_icdl_pt102'
Sun Feb 20 21:20:09 2022
Stopping background process MMON
Starting background process MMON
Starting background process MMNL
MMON started with pid=46, OS id=1482
Sun Feb 20 21:20:10 2022
Errors in file /opt/oracle/admin/xifenfei/bdump/xifenfei_smon_25140.trc:
ORA-01578: ORACLE data block corrupted (file # 652, block # 3767844)
ORA-01110: data file 652: '/dev/vgora13/rdbs_dcdl_pt0205'
Sun Feb 20 21:20:10 2022
Errors in file /opt/oracle/admin/xifenfei/bdump/xifenfei_smon_25140.trc:
ORA-01578: ORACLE data block corrupted (file # 652, block # 3767661)
ORA-01110: data file 652: '/dev/vgora13/rdbs_dcdl_pt0205'
replication_dependency_tracking turned off (no async multimaster replication found)
Sun Feb 20 21:20:11 2022
Errors in file /opt/oracle/admin/xifenfei/bdump/xifenfei_smon_25140.trc:
ORA-01578: ORACLE data block corrupted (file # 652, block # 3767661)
ORA-01110: data file 652: '/dev/vgora13/rdbs_dcdl_pt0205'
Sun Feb 20 21:20:11 2022
Errors in file /opt/oracle/admin/xifenfei/bdump/xifenfei_smon_25140.trc:
ORA-01578: ORACLE data block corrupted (file # 652, block # 3767661)
ORA-01110: data file 652: '/dev/vgora13/rdbs_dcdl_pt0205'
Sun Feb 20 21:20:11 2022
LOGSTDBY: Validating controlfile with logical metadata
Sun Feb 20 21:20:11 2022
LOGSTDBY: Validation complete
Sun Feb 20 21:20:11 2022
Errors in file /opt/oracle/admin/xifenfei/bdump/xifenfei_smon_25140.trc:
ORA-01578: ORACLE data block corrupted (file # 652, block # 3767661)
ORA-01110: data file 652: '/dev/vgora13/rdbs_dcdl_pt0205'
Completed: alter database open

对于异常undo进行处理,数据库正常open

由于客户短期无法迁移数据,先对于一些坏块进行修复，暂时运行数据库后续有时间窗口进行迁移.