首先来看一下数据库正常关闭的情况:

SQL> shutdown immediate;
Database closed.
Database dismounted.
ORACLE instance shut down.
SQL> startup mount;
ORACLE instance started.
Total System Global Area 6680915968 bytes
Fixed Size                  2213936 bytes
Variable Size            3758098384 bytes
Database Buffers         2885681152 bytes
Redo Buffers               34922496 bytes
Database mounted.
SQL> alter session set events 'immediate trace name controlf level 12';
Session altered.
***************************************************************************
DATABASE ENTRY
***************************************************************************
 (size = 316, compat size = 316, section max = 1, section in-use = 1,
  last-recid= 0, old-recno = 0, last-recno = 0)
 (extent = 1, blkno = 1, numrecs = 1)
 12/16/2014 13:08:14
 DB Name "ORCL"
 Database flags = 0x00404001 0x00001200
 Controlfile Creation Timestamp  12/16/2014 13:08:14
 Incmplt recovery scn: 0x0000.00000000
 Resetlogs scn: 0x0000.000e6c20 Resetlogs Timestamp  12/16/2014 13:08:16
 Prior resetlogs scn: 0x0000.00000001 Prior resetlogs Timestamp  08/15/2009
 00:16:43
 Redo Version: compatible=0xb200000
 #Data files = 5, #Online files = 5
 Database checkpoint: Thread=1 scn: 0x0000.0027157c
 Threads: #Enabled=1, #Open=0, Head=0, Tail=0

 数据库条目中Database checkpoint:Thread=1 scn:0x0000.0027157c 表示数据库的结束检查点。

***************************************************************************
REDO THREAD RECORDS
***************************************************************************
 (size = 256, compat size = 256, section max = 8, section in-use = 1,
  last-recid= 0, old-recno = 0, last-recno = 0)
 (extent = 1, blkno = 9, numrecs = 8)
THREAD #1 - status:0xe thread links forward:0 back:0
 #logs:3 first:1 last:3 current:3 last used seq#:0x8d
 enabled at scn: 0x0000.000e6c20 12/16/2014 13:08:16
 disabled at scn: 0x0000.00000000 01/01/1988 00:00:00
 opened at 12/31/2014 18:02:29 by instance orcl
Checkpointed at scn:  0x0000.0027157c 01/12/2015 17:00:59
 thread:1 rba:(0x8d.f96.10)

查看Redo Thread Records中检查点 Checkpointed at scn:  0x0000.0027157c 01/12/2015 17:00:59

***************************************************************************
DATA FILE RECORDS
***************************************************************************
 (size = 520, compat size = 520, section max = 100, section in-use = 5,
  last-recid= 37, old-recno = 0, last-recno = 0)
 (extent = 1, blkno = 11, numrecs = 100)
DATA FILE #1: 
  name #7: /DBBK/oracle/oradata/orcl/system01.dbf
creation size=0 block size=8192 status=0xe head=7 tail=7 dup=1
 tablespace 0, index=1 krfil=1 prev_file=0
 unrecoverable scn: 0x0000.00000000 01/01/1988 00:00:00
 Checkpoint cnt:242 scn: 0x0000.0027157c 01/12/2015 17:00:59
 Stop scn: 0x0000.0027157c 01/12/2015 17:00:59
 Creation Checkpointed at scn:  0x0000.00000007 08/15/2009 00:16:48
 thread:0 rba:(0x0.0.0)

 

查看Data File Records 中Checkpoint和Stop记录

Checkpoint cnt:242 scn: 0x0000.0027157c 01/12/2015 17:00:59
Stop scn: 0x0000.0027157c

这段表名在数据库正常shutdown的时候,实际发生了CKPT,所以Checkpoint scn与Stop scn一致。

因为正常关闭,数据库后续的启动将正常进行。

 

数据库异常关闭的情况

SQL> ALTER SYSTEM SWITCH LOGFILE;
System altered.
SQL> shutdown abort;
ORACLE instance shut down.
SQL> startup mount;
ORACLE instance started.
Total System Global Area 6680915968 bytes
Fixed Size                  2213936 bytes
Variable Size            3758098384 bytes
Database Buffers         2885681152 bytes
Redo Buffers               34922496 bytes
Database mounted.
SQL> alter session set events'immediate trace name controlf level 12';
SQL> @?/gettrcname
TRACE_FILE
--------------------------------------------------------------------------------
/DBBK/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_31004.trc

查看跟踪日志

***************************************************************************
DATABASE ENTRY
***************************************************************************
 (size = 316, compat size = 316, section max = 1, section in-use = 1,
  last-recid= 0, old-recno = 0, last-recno = 0)
 (extent = 1, blkno = 1, numrecs = 1)
 12/16/2014 13:08:14
 DB Name "ORCL"
 Database flags = 0x00404001 0x00001200
 Controlfile Creation Timestamp  12/16/2014 13:08:14
 Incmplt recovery scn: 0x0000.00000000
 Resetlogs scn: 0x0000.000e6c20 Resetlogs Timestamp  12/16/2014 13:08:16
 Prior resetlogs scn: 0x0000.00000001 Prior resetlogs Timestamp  08/15/2009
 00:16:43
 Redo Version: compatible=0xb200000
 #Data files = 5, #Online files = 5
 Database checkpoint: Thread=1 scn: 0x0000.0027157f
 Threads: #Enabled=1, #Open=1, Head=1, Tail=1

再来看数据库的检查点信息:Database checkpoint: Thread=1 scn: 0x0000.0027157f

***************************************************************************
REDO THREAD RECORDS
***************************************************************************
 (size = 256, compat size = 256, section max = 8, section in-use = 1,
  last-recid= 0, old-recno = 0, last-recno = 0)
 (extent = 1, blkno = 9, numrecs = 8)
THREAD #1 - status:0xf thread links forward:0 back:0
 #logs:3 first:1 last:3 current:1 last used seq#:0x8e
 enabled at scn: 0x0000.000e6c20 12/16/2014 13:08:16
 disabled at scn: 0x0000.00000000 01/01/1988 00:00:00
 opened at 01/12/2015 17:27:19 by instance orcl
Checkpointed at scn:  0x0000.0027157f 01/12/2015 17:27:19
 thread:1 rba:(0x8d.f96.10)

查看Redo:Checkpointed at scn:  0x0000.0027157f 01/12/2015 17:27:19 这里说明在Redo记录中已经完成了检查点检查。

***************************************************************************

DATA FILE RECORDS

***************************************************************************

 (size = 520, compat size = 520, section max = 100, section in-use = 5,

  last-recid= 37, old-recno = 0, last-recno = 0)

 (extent = 1, blkno = 11, numrecs = 100)

DATA FILE #1: 

  name #7: /DBBK/oracle/oradata/orcl/system01.dbf

creation size=0 block size=8192 status=0xe head=7 tail=7 dup=1

 tablespace 0, index=1 krfil=1 prev_file=0

 unrecoverable scn: 0x0000.00000000 01/01/1988 00:00:00

 Checkpoint cnt:243 scn: 0x0000.0027157f 01/12/2015 17:27:19

 Stop scn: 0xffff.ffffffff 01/12/2015 17:00:59

 Creation Checkpointed at scn:  0x0000.00000007 08/15/2009 00:16:48

 thread:0 rba:(0x0.0.0)

 

检查Data File Records的时候发现Checkpoint scn与Stop scn存在不一致的情况: 

Checkpoint cnt:243 scn: 0x0000.0027157f 01/12/2015 17:27:19

Stop scn: 0xffff.ffffffff 01/12/2015 17:00:59
此处说明我通过abort关闭数据库以后,因为没有进行关闭后的CKPT,导致buffer中的脏数据并没有写到数据文件中,因此数据文件的Stop scn用最大值ffff.ffffffff表示。

 

启动Oracle到Open状态,观察告警日志,数据库如果能在Redo日志中读取到未写入数据文件的记录,则Oracle自动执行实例恢复(Instance Recovery)

实例恢复包括两个步骤 Cache Recovery和Transaction Recovery

Beginning crash recovery of 1 threads
 parallel recovery started with 7 processes
Started redo scan
Completed redo scan
 read 31 KB redo, 26 data blocks need recovery
Started redo application at
 Thread 1: logseq 141, block 4690
Recovery of Online Redo Log: Thread 1 Group 3 Seq 141 Reading mem 0
  Mem# 0: /DBBK/oracle/oradata/orcl/redo03.log
Recovery of Online Redo Log: Thread 1 Group 1 Seq 142 Reading mem 0
  Mem# 0: /DBBK/oracle/oradata/orcl/redo01.log
Completed redo application of 0.01MB
Completed crash recovery at
 Thread 1: logseq 142, block 2, scn 2582016
 26 data blocks read, 26 data blocks written, 31 redo k-bytes read
-- 此处结束Cache Recovery 从Redo日志中扫描到缺失的数据块进行恢复

Mon Jan 12 17:53:18 2015
LGWR: STARTING ARCH PROCESSES
Mon Jan 12 17:53:18 2015
ARC0 started with pid=27, OS id=32295 
ARC0: Archival started
LGWR: STARTING ARCH PROCESSES COMPLETE
ARC0: STARTING ARCH PROCESSES
Thread 1 advanced to log sequence 143 (thread open)
Mon Jan 12 17:53:19 2015
ARC1 started with pid=28, OS id=32297 
Mon Jan 12 17:53:19 2015
ARC2 started with pid=29, OS id=32299 
Thread 1 opened at log sequence 143
  Current log# 2 seq# 143 mem# 0: /DBBK/oracle/oradata/orcl/redo02.log
Successful open of redo thread 1
ARC1: Archival started
Mon Jan 12 17:53:19 2015
ARC3 started with pid=30, OS id=32301 
ARC2: Archival started
ARC2: Becoming the 'no FAL' ARCH
ARC2: Becoming the 'no SRL' ARCH
ARC1: Becoming the heartbeat ARCH
Mon Jan 12 17:53:19 2015
SMON: enabling cache recovery
Archived Log entry 85 added for thread 1 sequence 142 ID 0x531a7e3e dest 1:
Successfully onlined Undo Tablespace 2.
Verifying file header compatibility for 11g tablespace encryption..
Verifying 11g file header compatibility for tablespace encryption completed
-- 此处提示开始Transaction Recovery 数据库回滚未提交的事务。
SMON: enabling tx recovery
Database Characterset is WE8MSWIN1252
No Resource Manager plan active
replication_dependency_tracking turned off (no async multimaster replication found)
Starting background process QMNC
Mon Jan 12 17:53:20 2015
QMNC started with pid=31, OS id=32305 
Completed: alter database open
ARC3: Archival started
ARC0: STARTING ARCH PROCESSES COMPLETE
Mon Jan 12 17:53:22 2015
Starting background process CJQ0
Mon Jan 12 17:53:22 2015
CJQ0 started with pid=32, OS id=32322
Mon Jan 12 18:03:20 2015
Starting background process SMCO
Mon Jan 12 18:03:20 2015
SMCO started with pid=19, OS id=852 
Mon Jan 12 22:00:00 2015
Setting Resource Manager plan SCHEDULER[0x3003]:DEFAULT_MAINTENANCE_PLAN via scheduler window
Setting Resource Manager plan DEFAULT_MAINTENANCE_PLAN via parameter
Mon Jan 12 22:00:00 2015
Starting background process VKRM
Mon Jan 12 22:00:00 2015
VKRM started with pid=24, OS id=21736 
Mon Jan 12 22:00:02 2015
Begin automatic SQL Tuning Advisor run for special tuning task  "SYS_AUTO_SQL_TUNING_TASK"
End automatic SQL Tuning Advisor run for special tuning task  "SYS_AUTO_SQL_TUNING_TASK"

 在这个恢复过程中,Oracle用两个特性来增加恢复的效率。Fast-Start On-Demand Rollback和Fast-Start Parallel Rollback。

Fast-Start On-Demand Rollback的特点,允许数据库打开后使用新的事务,这通常只需要很短的Cache Recovery时间。如果一个用户视图访问被中止进程锁定的记录,则Oracle回滚那些请求新事务的记录。在 Fast-Start On-Demand Rollback中,后台进程SMON充当调度员的角色,启用多个进程并行回滚事务集。

Fast-Start Parallel Rollback 主要对长时间运行未提交的事务有效。尤其是对并行INSERT,DELETE,UPDATE有效。SMON自动决定何时回滚未提交的事务,并在多进程上分散工作。

 

Fast-Start Parallel Rollback的一个特殊形式是 内部事务恢复(Intra-Transcation Recovery)在内部事务恢复中,一个大的事务可以被拆分,分配给多个服务进程进行并行回滚。

可以通过fast_start_parallel_rollback参数控制并行回滚,该参数有三个值。

FALSE  禁止使用fast_start_parallel_rollback

LOW 限制恢复进程不能超过cpu_count*2

HIGH 限制恢复进程不能超过cpu_count*4