启动数据库查看数据库日志: 

Wed Dec 17 17:40:32 2014
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.
Wed Dec 17 17:40:34 2014
Starting background process CJQ0
Wed Dec 17 17:40:34 2014
CJQ0 started with pid=21, OS id=5863

Oracle Open阶段通过controlfile加载数据文件,加载过程中会进行数据文件的检查,并比对数据的一致性。存在不一致需要恢复。

该阶段进行如下两项内容的检查:

1、检查数据文件中的CheckPoint cnt(检查点计数)是否与控制文件中的CheckPoint cnt一致,此步骤的目的是确认数据文件中是原数据还是来自于备份。

SQL> alter session set events'immediate trace name controlf level 12';
Session altered.
***************************************************************************
DATA FILE RECORDS
***************************************************************************
 (size = 520, compat size = 520, section max = 100, section in-use = 5,
  last-recid= 34, 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:182 scn: 0x0000.001d621a 01/04/2015 08:05:09
 Stop scn: 0xffff.ffffffff 12/31/2014 18:00:30
 Creation Checkpointed at scn:  0x0000.00000007 08/15/2009 00:16:48
 thread:0 rba:(0x0.0.0)
 ......
 Offline scn: 0x0000.000e6c1f prev_range: 0
 Online Checkpointed at scn:  0x0000.000e6c20 12/16/2014 13:08:16
 thread:1 rba:(0x1.2.0)
 ......
 Hot Backup end marker scn: 0x0000.00000000
 aux_file is NOT DEFINED 
 Plugged readony: NO
 Plugin scnscn: 0x0000.00000000
 Plugin resetlogs scn/timescn: 0x0000.00000000 01/01/1988 00:00:00
 Foreign creation scn/timescn: 0x0000.00000000 01/01/1988 00:00:00
 Foreign checkpoint scn/timescn: 0x0000.00000000 01/01/1988 00:00:00
 Online move state: 0

从上面可以看到,我从controlfile文件中dump的信息包括数据文件记录,记录的信息包含数据文件号,Checkpoint cnt号,scn号等。

SQL> alter tablespace system begin backup;
Tablespace altered.
SQL> alter session set events'immediate trace name controlf level 12';
Session altered.
***************************************************************************
DATA FILE RECORDS
***************************************************************************
 (size = 520, compat size = 520, section max = 100, section in-use = 5,
  last-recid= 34, 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:183 scn: 0x0000.001d6f61 01/04/2015 09:14:06
 Stop scn: 0xffff.ffffffff 12/31/2014 18:00:30
 Creation Checkpointed at scn:  0x0000.00000007 08/15/2009 00:16:48
 thread:0 rba:(0x0.0.0)
......
 Offline scn: 0x0000.000e6c1f prev_range: 0
 Online Checkpointed at scn:  0x0000.000e6c20 12/16/2014 13:08:16
 thread:1 rba:(0x1.2.0)
......
 Hot Backup end marker scn: 0x0000.00000000
 aux_file is NOT DEFINED 
 Plugged readony: NO
 Plugin scnscn: 0x0000.00000000
 Plugin resetlogs scn/timescn: 0x0000.00000000 01/01/1988 00:00:00
 Foreign creation scn/timescn: 0x0000.00000000 01/01/1988 00:00:00
 Foreign checkpoint scn/timescn: 0x0000.00000000 01/01/1988 00:00:00
 Online move state: 0
DATA FILE #2: 
  name #6: /DBBK/oracle/oradata/orcl/sysaux01.dbf
creation size=0 block size=8192 status=0xe head=6 tail=6 dup=1
 tablespace 1, index=2 krfil=2 prev_file=0
 unrecoverable scn: 0x0000.00000000 01/01/1988 00:00:00
 Checkpoint cnt:182 scn: 0x0000.001d621a 01/04/2015 08:05:09

可以看到这数据文件间的差异显示Checkpoint cnt号以及scn的改变

<  Checkpoint cnt:183 scn: 0x0000.001d6f61 01/04/2015 09:14:06
---
>  Checkpoint cnt:182 scn: 0x0000.001d621a 01/04/2015 08:05:09

手动触发检查点检查,再次查看控制文件的dump文件

SQL> alter system checkpoint;
System altered.
SQL> alter session set events'immediate trace name controlf level 12';
Session altered.

发现由于将system数据文件(即DATA FILE #1)修改为在线备份状态,其Checkpoint cnt发生改变,但scn未改变,而其他数据文件的scn和Checkpoint发生改变。

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:184 scn: 0x0000.001d6f61 01/04/2015 09:14:06
 Stop scn: 0xffff.ffffffff 12/31/2014 18:00:30
 Creation Checkpointed at scn:  0x0000.00000007 08/15/2009 00:16:48
 thread:0 rba:(0x0.0.0)
......
 Offline scn: 0x0000.000e6c1f prev_range: 0
 Online Checkpointed at scn:  0x0000.000e6c20 12/16/2014 13:08:16
 thread:1 rba:(0x1.2.0)
......
 Hot Backup end marker scn: 0x0000.00000000
 aux_file is NOT DEFINED 
 Plugged readony: NO
 Plugin scnscn: 0x0000.00000000
 Plugin resetlogs scn/timescn: 0x0000.00000000 01/01/1988 00:00:00
 Foreign creation scn/timescn: 0x0000.00000000 01/01/1988 00:00:00
 Foreign checkpoint scn/timescn: 0x0000.00000000 01/01/1988 00:00:00
 Online move state: 0
DATA FILE #2: 
  name #6: /DBBK/oracle/oradata/orcl/sysaux01.dbf
creation size=0 block size=8192 status=0xe head=6 tail=6 dup=1
 tablespace 1, index=2 krfil=2 prev_file=0
 unrecoverable scn: 0x0000.00000000 01/01/1988 00:00:00
 Checkpoint cnt:183 scn: 0x0000.001d7114 01/04/2015 09:25:07
 Stop scn: 0xffff.ffffffff 12/31/2014 18:00:30
 Creation Checkpointed at scn:  0x0000.0000085c 08/15/2009 00:17:00
 thread:0 rba:(0x0.0.0)
......
 Offline scn: 0x0000.000e6c1f prev_range: 0
 Online Checkpointed at scn:  0x0000.000e6c20 12/16/2014 13:08:16
 thread:1 rba:(0x1.2.0)
......
 Hot Backup end marker scn: 0x0000.00000000
 aux_file is NOT DEFINED 
 Plugged readony: NO
 Plugin scnscn: 0x0000.00000000
 Plugin resetlogs scn/timescn: 0x0000.00000000 01/01/1988 00:00:00
 Foreign creation scn/timescn: 0x0000.00000000 01/01/1988 00:00:00
 Foreign checkpoint scn/timescn: 0x0000.00000000 01/01/1988 00:00:00
 Online move state: 0

关闭system表空间的在线备份状态:

SQL> alter tablespace system end backup;
Tablespace altered.
 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:185 scn: 0x0000.001d7114 01/04/2015 09:25:07
 Stop scn: 0xffff.ffffffff 12/31/2014 18:00:30
 Creation Checkpointed at scn:  0x0000.00000007 08/15/2009 00:16:48
 thread:0 rba:(0x0.0.0)
.......
 Offline scn: 0x0000.000e6c1f prev_range: 0
 Online Checkpointed at scn:  0x0000.000e6c20 12/16/2014 13:08:16
 thread:1 rba:(0x1.2.0)
......
 Hot Backup end marker scn: 0x0000.00000000
 aux_file is NOT DEFINED 
 Plugged readony: NO
 Plugin scnscn: 0x0000.00000000
 Plugin resetlogs scn/timescn: 0x0000.00000000 01/01/1988 00:00:00
 Foreign creation scn/timescn: 0x0000.00000000 01/01/1988 00:00:00
 Foreign checkpoint scn/timescn: 0x0000.00000000 01/01/1988 00:00:00
 Online move state: 0

可以看到DATA FILE #1的Checkpoint cnt和scn均发生改变

 

2、当检查点计数器检查通过后,检查数据文件头开始的scn号是否与控制文件中记录的该数据文件的结束scn是否一致,如一致则无需恢复。

SQL> select file#,name,checkpoint_change# from v$datafile_header where file#=1;
     FILE# NAME                                     CHECKPOINT_CHANGE#
---------- ---------------------------------------- ------------------
         1 /DBBK/oracle/oradata/orcl/system01.dbf              1934813
SQL> select to_number('1d7114','XXXXXX') from dual;
TO_NUMBER('1D7114','XXXXXX')
----------------------------
                     1929492

 

可以看到我通过不同时间点的controlf dump发现9:25分的时候controlfile记录的DATA FILE #1的SCN结束号为1929492,而当我10:35分查看数据文件头的scn为1934813,如果存在这种控制文件中记录的数据文件scn不等于数据文件头的SCN的情况,就可能涉及到数据恢复的情况。当我10:35 重新dump controlfile的时候,确认这两块的scn是一致的

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:186 scn: 0x0000.001d85dd 01/04/2015 10:05:27
 Stop scn: 0xffff.ffffffff 12/31/2014 18:00:30
 Creation Checkpointed at scn:  0x0000.00000007 08/15/2009 00:16:48
 thread:0 rba:(0x0.0.0)
 
SQL> select to_number('1d85dd','XXXXXX') from dual;
TO_NUMBER('1D85DD','XXXXXX')
----------------------------
                     1934813

 

关于SCN的解释:

SCN(System Change Number)被作为数据库某一时刻版本的标识,同时在事务提交时,它也被赋予唯一的SCN号,SCN被Oracle数据库用作内部的时钟机制,可以被看成逻辑上的时钟。每个数据库都有一个全局的SCN生成器。

作为Oracle数据库的逻辑时钟,数据库的事务依SCN进行排序,同时数据库依据SCN实现一致读(Read Consistency)的功能。

SCN 存在于数据库的控制文件、数据文件头、日志文件、数据块头、事务表中。冠以不同的名称如:Checkpoint、Resetlogs等

 

获取SCN的方法:

SQL> select dbms_flashback.get_system_change_number from dual;
GET_SYSTEM_CHANGE_NUMBER
------------------------
                 2027427

通过系统底层表

SQL> select max(ktuxescnw*power(2,32)+ktuxescnb) as current_scn from x$ktuxe;
CURRENT_SCN
-----------
    2027381

 

系统的SCN通常在事务提交和回滚时改变 ,对于日志文件头则包含Low SCN和Next SCN记录,重做信息则介于Low SCN和Next SCN间,而对于状态为CURRENT的日志文件,则日志的Next SCN被置为无穷大,

RECID #1 Recno 1 Record timestamp  12/16/14 13:08:40 Thread=1 Seq#=1 Link-Recid=0 kccic-Recid=2
Low scn: 0x0000.000e6c20 12/16/14 13:08:16 Next scn: 0x0000.000ee43b
SQL> select status,first_change#,next_change# from v$log;
STATUS         FIRST_CHANGE# NEXT_CHANGE#
-------------- ------------- ------------
INACTIVE       2003999       2017783
CURRENT        2017783       2.8147E+14
INACTIVE       1991500       2003999

尝试切换日志

SQL> alter system switch logfile;
System altered.
    GROUP# STATUS     FIRST_CHANGE# NEXT_CHANGE#
---------- ---------- ------------- ------------
         1 INACTIVE         2003999      2017783
         2 INACTIVE         2017783      2028494
         3 CURRENT          2028494   2.8147E+14
SQL> select dbms_flashback.get_system_change_number from dual;
GET_SYSTEM_CHANGE_NUMBER
------------------------
                 2028498
LOG FILE #2: 
  name #2: /DBBK/oracle/oradata/orcl/redo02.log
 Thread 1 redo log links: forward: 3 backward: 1
 siz: 0x19000 seq: 0x0000005c hws: 0x2 bsz: 512 nab: 0x5962 flg: 0x1 dup: 1
 Archive links: fwrd: 0 back: 0 Prev scn: 0x0000.001e941f
 Low scn: 0x0000.001ec9f7 01/05/2015 12:54:06
 Next scn: 0x0000.001ef3ce 01/05/2015 16:44:22

可以看到日志切换后,LOG FILE #2的Next SCN 发生改变,其范围从20177832028494
,通过dump控制文件信息发现文件中也记录了日志文件SCN的这一变化。另外,系统之前SCN:2027427,说明当时的重做信息被记录到了LOG FILE #2中了。当对Oracle进行恢复时,读取归档日志时就要根据这个范围值确定记录所在的日志文件。

 

书中也提到通过DUMP日志文件的方式来获取日志文件中的记录信息:

SQL> select group#,type,is_recovery_dest_file,member from v$logfile;
    GROUP# TYPE   IS_RECOVE MEMBER
---------- ------ --------- -----------------------------------------
         3 ONLINE NO        /DBBK/oracle/oradata/orcl/redo03.log
         2 ONLINE NO        /DBBK/oracle/oradata/orcl/redo02.log
         1 ONLINE NO        /DBBK/oracle/oradata/orcl/redo01.log
*** 2015-01-05 17:40:15.184
 
DUMP OF REDO FROM FILE '/DBBK/oracle/oradata/orcl/redo02.log'
 Opcodes *.*
 RBAs: 0x000000.00000000.0000 thru 0xffffffff.ffffffff.ffff
 SCNs: scn: 0x0000.00000000 thru scn: 0xffff.ffffffff
 Times: creation thru eternity
 FILE HEADER:
        Compatibility Vsn = 186646528=0xb200000
        Db ID=1394247230=0x531a863e, Db Name='ORCL'
        Activation ID=1394245182=0x531a7e3e
        Control Seq=8108=0x1fac, File size=102400=0x19000
        File Number=2, Blksiz=512, File Type=2 LOG
 descrip:"Thread 0001, Seq# 0000000092, SCN 0x0000001ec9f7-0x0000001ef3ce"
 thread: 1 nab: 0x5962 seq: 0x0000005c hws: 0x2 eot: 0 dis: 0
 resetlogs count: 0x33a53ac0 scn: 0x0000.000e6c20 (945184)
 prev resetlogs count: 0x296b946b scn: 0x0000.00000001 (1)
 Low  scn: 0x0000.001ec9f7 (2017783) 01/05/2015 12:54:06
 Next scn: 0x0000.001ef3ce (2028494) 01/05/2015 16:44:22
 Enabled scn: 0x0000.000e6c20 (945184) 12/16/2014 13:08:16
 Thread closed scn: 0x0000.001ec9f7 (2017783) 01/05/2015 12:54:06

关于Checkpoint:

     Checkpoint的意义在于减少数据库崩溃恢复的时间。

     当修改数据的时候,数据先被读取到内存当中,被修改的记录会被记录到Redo中用于恢复,因为有了Redo,修改数据在提交后不会被立即写回到磁盘中。

     常见的情况是当主机断电导致数据库Crash,在内存中修改,且尚未写入磁盘的数据将丢失,那么在下一次数据库启动时,数据库会通过Redo日志进行事务重演,进行前推操作将数据库恢复到崩溃前的状态,之后再对未提交的事务进行回滚。

    通过检查点就可以减少崩溃恢复的时间,而检查点的发生频度则影响到崩溃恢复的时间长度。与部分参数有关

SQL> select file#,creation_change#,creation_time,checkpoint_change#,checkpoint_time from v$datafile;
     FILE# CREATION_CHANGE# CREATION_TIME       CHECKPOINT_CHANGE# CHECKPOINT_TIME
---------- ---------------- ------------------- ------------------ -------------------
         1                7 2009-08-15 00:16:48            2078903 2015-01-06 08:06:35
         2             2140 2009-08-15 00:17:00            2078903 2015-01-06 08:06:35
         3           942603 2009-08-15 00:52:15            2078903 2015-01-06 08:06:35
         4            17993 2009-08-15 00:17:30            2078903 2015-01-06 08:06:35
         5           974159 2014-12-16 13:08:33            2078903 2015-01-06 08:06:35
SQL> select dbid,checkpoint_change# from v$database;
      DBID CHECKPOINT_CHANGE#
---------- ------------------
1394247230            2078903

通过获取系统当前的SCN号,可以看到目前的数据文件的检查时间发生在08:06:35秒,而当生产的SCN的系统时间如下:
 

SQL> select dbms_flashback.get_system_change_number from dual;
GET_SYSTEM_CHANGE_NUMBER
------------------------
                 2085591
SQL> select scn_to_timestamp(2085591) from dual;
SCN_TO_TIMESTAMP(2085591)
-----------------------------------------
06-JAN-15 10.35.52.000000000 AM

可以看系统检查时间发生时间与当前系统时间相差还是比较大的,这主要是因为测试库,没有触发频繁的Checkpoint。

总的来说,为了减少数据库崩溃恢复的时间,在数据库性能允许的情况下,使Checkpoint的SCN尽量接近Redo的最新变更。加快规则恢复的速度。