一次rhel5.8的文件系統只讀造成的ORA-00354: corrupt redo log block header
Wed Jun 03 03:31:24 CST 2015 Thread 1 advanced to log sequence 396 (LGWR switch) Current log# 3 seq# 396 mem# 0: /u01/app/oracle/oradata/orcl/redo03.log Wed Jun 03 19:05:48 CST 2015 Thread 1 advanced to log sequence 397 (LGWR switch) ----------------->從這個地方可以看出來:sequence 397為current redo log Current log# 1 seq# 397 mem# 0: /u01/app/oracle/oradata/orcl/redo01.log Wed Jun 03 20:44:19 CST 2015 Errors in file /u01/app/oracle/admin/orcl/bdump/orcl_j000_30071.trc: ORA-07445: exception encountered: core dump [kglats()+106] [SIGSEGV] [Address not mapped to object] [0x000000000] [] [] ORA-01403: no data found Wed Jun 03 22:00:26 CST 2015 Errors in file /u01/app/oracle/admin/orcl/bdump/orcl_j001_30285.trc: ORA-07445: exception encountered: core dump [kglhdiv_callback()+79] [SIGSEGV] [Address not mapped to object] [0x0000000D4] [] [] Thu Jun 04 20:28:17 CST 2015 Starting ORACLE instance (normal)
後來數據庫實例重啟(人為重啟):
Completed: ALTER DATABASE MOUNT Thu Jun 04 20:28:24 CST 2015 ALTER DATABASE OPEN Thu Jun 04 20:28:24 CST 2015 Beginning crash recovery of 1 threads parallel recovery started with 3 processes Thu Jun 04 20:28:24 CST 2015 Started redo scan Thu Jun 04 20:28:24 CST 2015 Completed redo scan 1210 redo blocks read, 287 data blocks need recovery Thu Jun 04 20:28:25 CST 2015 Started redo application at Thread 1: logseq 397, block 660827 Thu Jun 04 20:28:25 CST 2015 Recovery of Online Redo Log: Thread 1 Group 1 Seq 397 Reading mem 0 Mem# 0: /u01/app/oracle/oradata/orcl/redo01.log Thu Jun 04 20:28:25 CST 2015 Completed redo application Thu Jun 04 20:28:29 CST 2015 Completed crash recovery at Thread 1: logseq 397, block 662037, scn 1359645 287 data blocks read, 287 data blocks written, 1210 redo blocks read Thu Jun 04 20:28:30 CST 2015 LGWR: STARTING ARCH PROCESSES ARC0 started with pid=19, OS id=3609 Thu Jun 04 20:28:30 CST 2015 ARC0: Archival started ARC1: Archival started LGWR: STARTING ARCH PROCESSES COMPLETE ARC1 started with pid=20, OS id=3611 Thu Jun 04 20:28:30 CST 2015 Thread 1 advanced to log sequence 398 (thread open) --->已經使用sequence 398,此時,sequence 398為current redo log Thread 1 opened at log sequence 398 Current log# 2 seq# 398 mem# 0: /u01/app/oracle/oradata/orcl/redo02.log Successful open of redo thread 1 Thu Jun 04 20:28:30 CST 2015 MTTR advisory is disabled because FAST_START_MTTR_TARGET is not set Thu Jun 04 20:28:30 CST 2015 ARC0: Becoming the 'no FAL' ARCH ARC0: Becoming the 'no SRL' ARCH Thu Jun 04 20:28:30 CST 2015 SMON: enabling cache recovery Thu Jun 04 20:28:30 CST 2015 ARC1: Becoming the heartbeat ARCH Thu Jun 04 20:28:35 CST 2015 ARC0: Log corruption near block 385521 change 1314765 time ? --->發現redo log 有損壞 Thu Jun 04 20:28:35 CST 2015 Errors in file /u01/app/oracle/admin/orcl/bdump/orcl_arc0_3609.trc: ORA-00354: corrupt redo log block header --->發現redo log header有損壞 ORA-00353: log corruption near block 385521 change 1314765 time 06/03/2015 19:05:47 ORA-00312: online log 1 thread 1: '/u01/app/oracle/oradata/orcl/redo01.log' ARC0: All Archive destinations made inactive due to error 354 Thu Jun 04 20:28:35 CST 2015 ARC0: Closing local archive destination LOG_ARCHIVE_DEST_1: '/home/oracle/1_397_880950378.dbf' (error 354) (orcl) Committing creation of archivelog '/home/oracle/1_397_880950378.dbf' (error 354) Thu Jun 04 20:28:43 CST 2015 Successfully onlined Undo Tablespace 1. Thu Jun 04 20:28:43 CST 2015 SMON: enabling tx recovery Thu Jun 04 20:28:45 CST 2015 ARCH: Archival stopped, error occurred. Will continue retrying Thu Jun 04 20:28:45 CST 2015 ORACLE Instance orcl - Archival Error Thu Jun 04 20:28:45 CST 2015 Database Characterset is ZHS16GBK Thu Jun 04 20:28:45 CST 2015 ORA-16038: log 1 sequence# 397 cannot be archived ORA-00354: corrupt redo log block header ORA-00312: online log 1 thread 1: '/u01/app/oracle/oradata/orcl/redo01.log' Thu Jun 04 20:28:45 CST 2015 Errors in file /u01/app/oracle/admin/orcl/bdump/orcl_arc0_3609.trc: ORA-16038: log 1 sequence# 397 cannot be archived ORA-00354: corrupt redo log block header ORA-00312: online log 1 thread 1: '/u01/app/oracle/oradata/orcl/redo01.log' Opening with internal Resource Manager plan replication_dependency_tracking turned off (no async multimaster replication found) Starting background process QMNC QMNC started with pid=21, OS id=3637 Thu Jun 04 20:28:49 CST 2015 Completed: ALTER DATABASE OPEN ------->db open了。open歸open,無法歸檔的話,業務早晚會hang。 --->此時/u01/app/oracle/oradata/orcl/redo02.log,是sequence 398,是current redo log。
Thread 1 advanced to log sequence 399 (LGWR switch) Current log# 3 seq# 399 mem# 0: /u01/app/oracle/oradata/orcl/redo03.log --->此時/u01/app/oracle/oradata/orcl/redo03.log,是sequence 399,是current redo log。
--->然後,sqlplus中發出了日志切換的語句:alter system switch logfile; Thread 1 cannot allocate new log, sequence 400---->已經不能進行日志切換,因為sequence 397未被歸檔,不允許被覆蓋,此時db hang住。 All online logs needed archiving Current log# 3 seq# 399 mem# 0: /u01/app/oracle/oradata/orcl/redo03.log Thu Jun 04 21:28:31 CST 2015 ARC0: Log corruption near block 385521 change 1314765 time ? Thu Jun 04 21:28:31 CST 2015 Errors in file /u01/app/oracle/admin/orcl/bdump/orcl_arc0_3609.trc: ORA-00354: corrupt redo log block header ORA-00353: log corruption near block 385521 change 1314765 time 06/03/2015 19:05:47 ORA-00312: online log 1 thread 1: '/u01/app/oracle/oradata/orcl/redo01.log' ARC0: All Archive destinations made inactive due to error 354 Thu Jun 04 21:28:31 CST 2015 ARC0: Closing local archive destination LOG_ARCHIVE_DEST_1: '/home/oracle/1_397_880950378.dbf' (error 354) (orcl) ARCH: Archival stopped, error occurred. Will continue retrying Thu Jun 04 21:28:34 CST 2015 ORACLE Instance orcl - Archival Error Thu Jun 04 21:28:34 CST 2015 ORA-16038: log 1 sequence# 397 cannot be archived ORA-00354: corrupt redo log block header ORA-00312: online log 1 thread 1: '/u01/app/oracle/oradata/orcl/redo01.log' Thu Jun 04 21:28:34 CST 2015 Errors in file /u01/app/oracle/admin/orcl/bdump/orcl_arc0_3609.trc: ORA-16038: log 1 sequence# 397 cannot be archived ORA-00354: corrupt redo log block header ORA-00312: online log 1 thread 1: '/u01/app/oracle/oradata/orcl/redo01.log' ARCH: Archival stopped, error occurred. Will continue retrying Thu Jun 04 21:28:34 CST 2015 ORACLE Instance orcl - Archival Error Thu Jun 04 21:28:34 CST 2015 ORA-16014: log 1 sequence# 397 not archived, no available destinations ORA-00312: online log 1 thread 1: '/u01/app/oracle/oradata/orcl/redo01.log' Thu Jun 04 21:28:34 CST 2015 Errors in file /u01/app/oracle/admin/orcl/bdump/orcl_arc0_3609.trc: ORA-16014: log 1 sequence# 397 not archived, no available destinations ORA-00312: online log 1 thread 1: '/u01/app/oracle/oradata/orcl/redo01.log'
啟動db到mount狀態,進行處理
[oracle@lei1 ~]$ sqlplus / as sysdba SQL*Plus: Release 10.2.0.5.0 - Production on Fri Jun 12 23:14:24 2015 Copyright (c) 1982, 2010, Oracle. All Rights Reserved. Connected to an idle instance. SQL> startup mount; ORACLE instance started. Total System Global Area 2147483648 bytes Fixed Size 2097696 bytes Variable Size 536874464 bytes Database Buffers 1593835520 bytes Redo Buffers 14675968 bytes Database mounted. SQL> set line 200 SQL> select * from v$log; GROUP# THREAD# SEQUENCE# BYTES MEMBERS ARC STATUS FIRST_CHANGE# FIRST_TIM ---------- ---------- ---------- ---------- ---------- --- ---------------- ------------- --------- 1 1 397 536870912 1 NO INACTIVE 1294462 03-JUN-15 3 1 399 536870912 1 NO CURRENT 1361682 04-JUN-15 2 1 398 536870912 1 YES INACTIVE 1359647 04-JUN-15 SQL> alter database clear logfile group 1; alter database clear logfile group 1 * ERROR at line 1: ORA-00350: log 1 of instance orcl (thread 1) needs to be archived ORA-00312: online log 1 thread 1: '/u01/app/oracle/oradata/orcl/redo01.log' SQL> alter database clear unarchived logfile group 1; Database altered. SQL> select * from v$log; GROUP# THREAD# SEQUENCE# BYTES MEMBERS ARC STATUS FIRST_CHANGE# FIRST_TIM ---------- ---------- ---------- ---------- ---------- --- ---------------- ------------- --------- 1 1 0 536870912 1 YES UNUSED 1294462 03-JUN-15 3 1 399 536870912 1 NO CURRENT 1361682 04-JUN-15 2 1 398 536870912 1 YES INACTIVE 1359647 04-JUN-15 SQL> archive log list; Database log mode Archive Mode Automatic archival Enabled Archive destination /home/oracle Oldest online log sequence 0 Next log sequence to archive 399 Current log sequence 399 SQL>
此時alert日志的輸出如下:
Fri Jun 12 23:20:27 CST 2015 alter database clear logfile group 1 Fri Jun 12 23:20:27 CST 2015 ORA-350 signalled during: alter database clear logfile group 1... Fri Jun 12 23:22:30 CST 2015 alter database clear unarchived logfile group 1 Fri Jun 12 23:22:31 CST 2015 WARNING! CLEARING REDO LOG WHICH HAS NOT BEEN ARCHIVED. BACKUPS TAKEN BEFORE 06/04/2015 20:28:30 (CHANGE 1359647) CANNOT BE USED FOR RECOVERY. Clearing online log 1 of thread 1 sequence number 397 Fri Jun 12 23:22:43 CST 2015 Completed: alter database clear unarchived logfile group 1