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

SQL> shutdown immediate;Database closed.Database dismounted.ORACLE instance shut down.SQL> startup mount;ORACLE instance started.Total System Global Area 6680915968 bytesFixed Size                  2213936 bytesVariable Size            3758098384 bytesDatabase Buffers         2885681152 bytesRedo Buffers               34922496 bytesDatabase 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 orclCheckpointed 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.dbfcreation 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 bytesFixed Size                  2213936 bytesVariable Size            3758098384 bytesDatabase Buffers         2885681152 bytesRedo Buffers               34922496 bytesDatabase mounted.SQL> alter session set events'immediate trace name controlf level 12';SQL> @?/gettrcnameTRACE_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 orclCheckpointed 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.dbfcreation 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 processesStarted redo scanCompleted redo scan read 31 KB redo, 26 data blocks need recoveryStarted redo application at Thread 1: logseq 141, block 4690Recovery of Online Redo Log: Thread 1 Group 3 Seq 141 Reading mem 0  Mem# 0: /DBBK/oracle/oradata/orcl/redo03.logRecovery of Online Redo Log: Thread 1 Group 1 Seq 142 Reading mem 0  Mem# 0: /DBBK/oracle/oradata/orcl/redo01.logCompleted redo application of 0.01MBCompleted 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 2015LGWR: STARTING ARCH PROCESSESMon Jan 12 17:53:18 2015ARC0 started with pid=27, OS id=32295 ARC0: Archival startedLGWR: STARTING ARCH PROCESSES COMPLETEARC0: STARTING ARCH PROCESSESThread 1 advanced to log sequence 143 (thread open)Mon Jan 12 17:53:19 2015ARC1 started with pid=28, OS id=32297 Mon Jan 12 17:53:19 2015ARC2 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.logSuccessful open of redo thread 1ARC1: Archival startedMon Jan 12 17:53:19 2015ARC3 started with pid=30, OS id=32301 ARC2: Archival startedARC2: Becoming the 'no FAL' ARCHARC2: Becoming the 'no SRL' ARCHARC1: Becoming the heartbeat ARCHMon Jan 12 17:53:19 2015SMON: enabling cache recoveryArchived 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 recoveryDatabase Characterset is WE8MSWIN1252No Resource Manager plan activereplication_dependency_tracking turned off (no async multimaster replication found)Starting background process QMNCMon Jan 12 17:53:20 2015QMNC started with pid=31, OS id=32305 Completed: alter database openARC3: Archival startedARC0: STARTING ARCH PROCESSES COMPLETEMon Jan 12 17:53:22 2015Starting background process CJQ0Mon Jan 12 17:53:22 2015CJQ0 started with pid=32, OS id=32322Mon Jan 12 18:03:20 2015Starting background process SMCOMon Jan 12 18:03:20 2015SMCO started with pid=19, OS id=852 Mon Jan 12 22:00:00 2015Setting Resource Manager plan SCHEDULER[0x3003]:DEFAULT_MAINTENANCE_PLAN via scheduler windowSetting Resource Manager plan DEFAULT_MAINTENANCE_PLAN via parameterMon Jan 12 22:00:00 2015Starting background process VKRMMon Jan 12 22:00:00 2015VKRM started with pid=24, OS id=21736 Mon Jan 12 22:00:02 2015Begin 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