天天看點

ORACLE執行個體恢複過程詳細分析--使用dump、BBED等多種工具結合分析

---友情提示,内容較多,可以從博文左上的+目錄選擇小節友善閱讀。

 實驗思路:  --實驗相關TRACE檔案:http://download.csdn.net/detail/q947817003/6646723

1.資料庫OPEN,,做DML操作不送出,檢視檢查點。

2.SHUTDOWN ABORT并重新開機到MOUNT并查詢檢查點

3.DUMP控制檔案檢視CHECKPOINT_CHANGE#/RBA

4.DUMP資料檔案檢視CHECKPOINT_CHANGE#/RBA,與DUMP控制檔案對比

5.DUMP REDO日志檔案,檢視、對比CHECKPOINT_CHANGE#/RBA

6.使用BBED檢視資料檔案頭中的CHECKPOINT_CHANGE#/RBA

7.執行EVENT事件的語句,OPEN資料庫,再DUMP控制檔案

8.分析OPEN時,通過ALERT日志檢視的恢複過程--前滾

9.分析OPEN時,EVENT事件生成的TRACE中檢視恢複過程--前滾

10.OPEN資料庫時,通過ALERT日志及EVENT事件生成的TRACE中資訊解析執行個體恢複的復原

11.分析OPEN後的控制檔案資訊

參考資料及感謝:

guoyJoe   http://blog.csdn.net/guoyJoe/article/details/9034425

dbsnake   http://www.dbsnake.com/oracle-instance-recovery-end-point.html

實驗結論有: 

1.控制檔案提供恢複所需目前REDO日志的RBA資訊,目前REDO日志提供具體的用于恢複的日志内容,最終是将日志内容應用于資料檔案。--執行個體恢複三者不能缺。

2.資料庫OPEN時開始執行個體恢複,先應用日志内容,應用完後從alert日志中來看是已經可以連接配接至資料庫,此時如果UNDO未完成,就有使用者發出操作,資料庫程序會将復原後的資料發送至使用者- -可能會有等待。

3.重要的一點,資料檔案、目前REDO日志檔案、控制檔案正常時執行個體恢複無需DBA幹預,自動完成哈哈。

4.如果目前REDO日志丢了,隻能做不完全恢複了。

關于執行個體恢複起止點:--來自dbsnake

可能會出現On Disk RBA比Low Cache RBA小的情況,如果Oracle發現存在這種情況,則會強制寫redo。

On Disk RBA隻是表示Instance Recovery的時候至少要恢複到On Disk RBA,它隻是真正的current redo log file的最尾端一個前鏡像。

執行個體恢複的起點是:Low Cache RBA和Thread Checkpoint RBA中的較大值; 執行個體恢複的終點就是current redo log file的最尾端。 On-Disk RBA是要最低恢複到的位置--事實上是隻要On-Disk RBA後還有日志塊就要恢複完的。

Oracle在做執行個體恢複的時候是受隐含參數_two_pass的控制,其預設為true,這表示要Oracle做執行個體恢複的時候是采用Two Pass Recovery,即要掃描current redo log file兩次。

Two Pass Recovery的核心是在做執行個體恢複時要去掉那些已經被寫入資料檔案的資料塊所對應的redo record,Oracle稱這些redo record為Block Written Record (BWR)。

###################################################################

1.資料庫正常運作,多種途徑檢視資料庫中檢查點

在普通使用者下執行DML操作不送出

[email protected] bys3>set time on

13:18:17 [email protected] bys3>select * from a;   --此表在USER表空間。

B

----------

55

8

3

13:18:21 [email protected] bys3>delete a;

4 rows deleted.

13:18:36 [email protected] bys3>select * from a;

no rows selected

再打開一個會話(同一會話切換使用者會送出操作),多種途徑檢視資料庫中檢查點:詳見:http://blog.csdn.net/q947817003/article/details/11590735

[email protected] bys3>set time on

13:18:44 [email protected] bys3>col name for a35

13:18:52 [email protected] bys3>select dbid,name,checkpoint_change# from v$database;

      DBID NAME                                CHECKPOINT_CHANGE#

---------- ----------------------------------- ------------------

3358363031 BYS3                                           1991217

13:18:59 [email protected] bys3>select file#,name,checkpoint_change#,to_char(checkpoint_time,'yyyy-mm-dd hh24:mi:ss') cptime from v$datafile;

     FILE# NAME                                CHECKPOINT_CHANGE# CPTIME

---------- ----------------------------------- ------------------ -------------------

         1 /u01/oradata/bys3/system01.dbf                 1991217 2013-12-02 13:17:26

         2 /u01/oradata/bys3/sysaux01.dbf                 1991217 2013-12-02 13:17:26

         3 /u01/oradata/bys3/undotbs01.dbf                1991217 2013-12-02 13:17:26

         4 /u01/oradata/bys3/user01.dbf                   1991217 2013-12-02 13:17:26

13:19:25 [email protected] bys3>select name,checkpoint_change# from v$datafile_header;

NAME                                CHECKPOINT_CHANGE#

----------------------------------- ------------------

/u01/oradata/bys3/system01.dbf                 1991217

/u01/oradata/bys3/sysaux01.dbf                 1991217

/u01/oradata/bys3/undotbs01.dbf                1991217

/u01/oradata/bys3/user01.dbf                   1991217

目前目前REDO日志使用情況:

13:19:57 [email protected] bys3>col member for a30

13:20:01 [email protected] bys3>select a.member,a.type,b.thread#,b.sequence#,b.bytes/1024/1024 MB,b.status,b.archived from v$logfile a,v$log b where a.group#=b.group#;

MEMBER                         TYPE       THREAD#  SEQUENCE#         MB STATUS           ARC

------------------------------ ------- ---------- ---------- ---------- ---------------- ---

/u01/oradata/bys3/redo01.log   ONLINE           1        106         50 INACTIVE         YES

/u01/oradata/bys3/redo02.log   ONLINE           1        107         50 CURRENT          NO

/u01/oradata/bys3/redo03.log   ONLINE           1        105         50 INACTIVE         YES

###################################################################

2.模拟斷電--shutdown abort,并重新開機到MOUNT 查詢檢查點

13:20:02 [email protected] bys3>shutdown abort;    ----13:22:11執行完此指令

ORACLE instance shut down.

13:22:11 [email protected] bys3>

alert日志:  --推薦個小方法:把alert日志做一個軟連結到ORACLE使用者家目錄,檢視友善。

[[email protected] ~]$ cat alert_bys3.log

Mon Dec 02 13:22:09 2013

Shutting down instance (abort)

License high water mark = 4

USER (ospid: 846): terminating the instance

Instance terminated by USER, pid = 846

Mon Dec 02 13:22:11 2013

Instance shutdown complete

######################################

重新開機資料庫到MOUNT,從資料庫中檢視資料庫中檢查點、控制檔案及資料檔案頭檢查點,一緻則無需媒體恢複

資料庫MOUNT狀态下直接在資料庫中使用SQL語句查詢: 

[email protected] bys3>select status from v$instance;

STATUS

------------

MOUNTED

[email protected] bys3>select dbid,name,checkpoint_change# from v$database;    --資料庫全局-檢查點 SCN,在控制檔案中

      DBID NAME      CHECKPOINT_CHANGE#

---------- --------- ------------------

3358363031 BYS3                 1991217

[email protected] bys3>select file#,name,checkpoint_change#,to_char(checkpoint_time,'yyyy-mm-dd hh24:mi:ss') cptime from v$datafile;    --checkpoint scn,表示該資料檔案最近一次執行檢查點操作時的SCN,在控制檔案中。

     FILE# NAME                                CHECKPOINT_CHANGE# CPTIME

---------- ----------------------------------- ------------------ -------------------

         1 /u01/oradata/bys3/system01.dbf                 1991217 2013-12-02 13:17:26

         2 /u01/oradata/bys3/sysaux01.dbf                 1991217 2013-12-02 13:17:26

         3 /u01/oradata/bys3/undotbs01.dbf                1991217 2013-12-02 13:17:26

         4 /u01/oradata/bys3/user01.dbf                   1991217 2013-12-02 13:17:26

[email protected] bys3>select name,checkpoint_change# from v$datafile_header;   --CHECKPOINT_CHANGE#表示該資料檔案最近一次執行檢查點操作時的SCN,在資料檔案頭

NAME                                CHECKPOINT_CHANGE#

----------------------------------- ------------------

/u01/oradata/bys3/system01.dbf                 1991217

/u01/oradata/bys3/sysaux01.dbf                 1991217

/u01/oradata/bys3/undotbs01.dbf                1991217

/u01/oradata/bys3/user01.dbf                   1991217

###################################################################

3.DUMP控制檔案檢視CHECKPOINT_CHANGE#/RBA

更詳細DUMP控制檔案方式見:http://blog.csdn.net/q947817003/article/details/16370273

[email protected] bys3>alter session set events 'immediate trace name controlf level 12';

Session altered.

[email protected] bys3>select value from v$diag_info where name like 'Default%';

VALUE

------------------------------------------------------------------------------

/u01/diag/rdbms/bys3/bys3/trace/bys3_ora_980.trc

檢視TRACE檔案:   --截取部分内容

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

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)

 11/14/2013 14:23:19

 DB Name "BYS3"

 Database flags = 0x00404001 0x00001200

 Controlfile Creation Timestamp  11/14/2013 14:23:21

 Incmplt recovery scn: 0x0000.00000000

 Resetlogs scn: 0x0000.00000001 Resetlogs Timestamp  11/14/2013 14:23:19

 Prior resetlogs scn: 0x0000.00000000 Prior resetlogs Timestamp  01/01/1988 00:00:00

 Redo Version: compatible=0xb200000

 #Data files = 4, #Online files = 4

 Database checkpoint: Thread=1 scn: 0x0000.001e6231

Threads: #Enabled=1, #Open=1, Head=1, Tail=1

 enabled  threads:  01000000 00000000 00000000 00000000 00000000 00000000

 Max log members = 5, Max data members = 1

 Arch list: Head=2, Tail=2, Force scn: 0x0000.001b6c94scn: 0x0000.00000000

 Activation ID: 3358374039

 SCN compatibility 1

 Auto-rollover enabled

 Controlfile Checkpointed at scn:  0x0000.001e6286 12/02/2013 13:17:28   ---這是增量檢查點的位置SCN -1991302

 thread:0 rba:(0x0.0.0)

 ###############

可以看到檢查點的資訊:Database checkpoint: Thread=1 scn: 0x0000.001e6231

換算為十進制的SCN為:   ---與上一步查詢對應

[email protected] bys3>select to_number('1e6231','xxxxxxxxx') from dual;

TO_NUMBER('1C8E12','XXXXXXXXX')

-------------------------------

                           1991217

###############

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

CHECKPOINT PROGRESS RECORDS

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

 (size = 8180, compat size = 8180, section max = 4, section in-use = 0,

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

 (extent = 1, blkno = 2, numrecs = 4)

THREAD #1 - status:0x2 flags:0x0 dirty:104   ---髒塊數量104

low cache rba:(0x6b.3.0) on disk rba:(0x6b.197.0)   ---資料檔案檢查點 Scn以及stop scn值據說來自于目前REDO日志

on disk scn: 0x0000.001e638d 12/02/2013 13:21:37   --ON DISK SCN

resetlogs scn: 0x0000.00000001 11/14/2013 14:23:19

heartbeat: 833133356 mount id: 3360007946

################

在檢查點程序記錄部分,記錄了Dirty Buffer的數量是104.

包含Low Cache RBA和On Disk RBA的資訊,

low cache rba:(0x6b.3.0) on disk rba:(0x6b.197.0)

 -- low cache rba:(0x6b.3.0):   執行個體恢複的起點:107号日志,第3個塊,第0個位元組

 --on disk rba:(0x6b.197.0):  執行個體恢複的終點:107号日志,第407個塊,第0個位元組   --最前面結論是執行個體恢複終點實際為current redo log file的最尾端,但是在控制檔案、日志中記錄的是這個 on disk rba

on disk scn: 0x0000.001e638d 12/02/2013 13:21:37

資料庫恢複的檢查點終點是SCN--0x0000.001e638d,十進制是:1991565。   

On-Disk RBA的SCN是1991565,這是執行個體恢複的終點。

資料庫的恢複SCN範圍也就由此确定,即SCN範圍:增量檢查點:1991302--On-Disk RBA,用SCN表示即:1991302 ===>>>1991565

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

DATA FILE RECORDS

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

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

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

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

DATA FILE #1: DATA FILE #2: DATA FILE #3: 和DATA FILE #3差不多,并且在本實驗中不涉及,精簡篇幅就省略了。

DATA FILE #4:

  name #8: /u01/oradata/bys3/user01.dbf

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

 tablespace 4, index=5 krfil=4 prev_file=0

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

Checkpoint cnt:167 scn: 0x0000.001e6231 12/02/2013 13:17:26      ---cnt:167是檢查點計數,來自資料檔案。--與下一步DUMP資料檔案中SYSTEM表空間資料檔案的CTL CNT對應。一緻說明來自同一版本,而不是備份。

 Stop scn: 0xffff.ffffffff 12/02/2013 13:16:13                                              --STOP SCN是FFFF,資料檔案的STOP SCP不等于Checkpoint SCN。意味着資料庫上一次關閉未執行完全檢查點,是異常關閉。故需要執行個體恢複。

 Creation Checkpointed at scn:  0x0000.000034f9 11/14/2013 14:26:26

 thread:1 rba:(0x1.ce8a.10)

 enabled  threads:  01000000 00000000 00000000 00000000 00000000 00000000

 Offline scn: 0x0000.00000000 prev_range: 0

 Online Checkpointed at scn:  0x0000.00000000

 thread:0 rba:(0x0.0.0)

 enabled  threads:  00000000 00000000 00000000 00000000 00000000 00000000

 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

########################

這裡在第1步做DML操作時,所在的是USER表空間。

DATA FILE #4: 中的檢查點資訊如下:

Checkpoint cnt:167 scn: 0x0000.001e6231 12/02/2013 13:17:26

--控制檔案中儲存的資料檔案檢查點SCN=1e6231 轉成10進制為1991217,與前文吻合

Stop scn: 0xffff.ffffffff 12/11/2012 22:53:05

--結束的SCN填無窮大,說明是異常關機的,重新開機資料庫必須做執行個體恢複

###################################################################

4.DUMP資料檔案檢視CHECKPOINT_CHANGE#/RBA,與DUMP控制檔案對比

更詳細DUMP資料檔案方式見:http://blog.csdn.net/q947817003/article/details/16369041

[email protected] bys3>alter system set events 'immediate trace name file_hdrs level 3';    --最好和上一步DUMP控制檔案在不同的會話

System altered.

[email protected] bys3>select value from v$diag_info where name like 'Default%';

VALUE

----------------------------------------------------------------------

/u01/diag/rdbms/bys3/bys3/trace/bys3_ora_1010.trc

檢視TRACE檔案:   --截取部分内容--

DATA FILE #1:

  name #4: /u01/oradata/bys3/system01.dbf

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

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

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

 Checkpoint cnt:167 scn: 0x0000.001e6231 12/02/2013 13:17:26      -----------CKPT CNT 167與上一步DUMP控制檔案中對應

 Stop scn: 0xffff.ffffffff 12/02/2013 13:16:13                   ------- --STOP SCN是FFFF,資料檔案的STOP SCP不等于Checkpoint SCN。意味着資料庫上一次關閉未執行完全檢查點,是異常關閉。故需要執行個體恢複。

 Creation Checkpointed at scn:  0x0000.00000015 11/14/2013 14:24:22

 thread:1 rba:(0x1.3.10)

 enabled  threads:  01000000 00000000 00000000 00000000 00000000 00000000

 Offline scn: 0x0000.00000000 prev_range: 0

 Online Checkpointed at scn:  0x0000.00000000

 thread:0 rba:(0x0.0.0)

 enabled  threads:  00000000 00000000 00000000 00000000 00000000 00000000

000000 00000000

  00000000 00000000 00000000 00000000 00000000 00000000

 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

 V10 STYLE FILE HEADER:

    Compatibility Vsn = 186646528=0xb200000

    Db ID=3358363031=0xc82c8d97, Db Name='BYS3'

    Activation ID=0=0x0

    Control Seq=8489=0x2129, File size=64000=0xfa00

    File Number=1, Blksiz=8192, File Type=3 DATA

Tablespace #0 - SYSTEM  rel_fn:1

Creation   at   scn: 0x0000.00000015 11/14/2013 14:24:22

Backup taken at scn: 0x0000.00000000 01/01/1988 00:00:00 thread:0

 reset logs count:0x318f5cd7 scn: 0x0000.00000001

 prev reset logs count:0x0 scn: 0x0000.00000000

 recovered at 12/02/2013 13:17:26

 status:0x2004 root dba:0x00400208 chkpt cnt: 167 ctl cnt:166  -----------CKPT CNT 167, CTL CNT 166與上一步DUMP控制檔案中對應

###################################################

Tablespace #4 - USERS  rel_fn:4

Creation   at   scn: 0x0000.000034f9 11/14/2013 14:26:26

Backup taken at scn: 0x0000.00000000 01/01/1988 00:00:00 thread:0

 reset logs count:0x318f5cd7 scn: 0x0000.00000001

 prev reset logs count:0x0 scn: 0x0000.00000000

 recovered at 12/02/2013 13:17:26

 status:0x4 root dba:0x00000000 chkpt cnt: 168 ctl cnt:167         

begin-hot-backup file size: 0

Checkpointed at scn:  0x0000.001e6231 12/02/2013 13:17:26     -------檢查點 scn:  0x0000.001e6231與前文吻合

 thread:1 rba:(0x6b.2.10)                                                                        --------REDO日志的位址0x6b.2.10---> 107号日志,第2号塊,第16個位元組

 enabled  threads:  01000000 00000000 00000000 00000000 00000000 00000000

Backup Checkpointed at scn:  0x0000.00000000

 thread:0 rba:(0x0.0.0)

 enabled  threads:  00000000 00000000 00000000 00000000 00000000 00000000

External cache id: 0x0 0x0 0x0 0x0

Absolute fuzzy scn: 0x0000.00000000

Recovery fuzzy scn: 0x0000.00000000 01/01/1988 00:00:00

Terminal Recovery Stamp  01/01/1988 00:00:00

Platform Information:     Creation Platform ID: 10

Current Platform ID: 10    Last Platform ID: 10

DUMP OF TEMP FILES: 1 files in database

第3步中:《《注意:

從控制檔案中得到重做日志恢複起始位址如下:

low cache rba:(0x6b.3.0) on disk rba:(0x6b.197.0)

 -- low cache rba:(0x6b.3.0):

 執行個體恢複的起點:107号日志,第3個塊,第0個位元組

 --on disk rba:(0x6b.197.0):

 執行個體恢複的終點:107号日志,第407個塊,第0個位元組   --具體是不是終點,最後讨論

on disk scn: 0x0000.001e638d 12/02/2013 13:21:37

資料庫恢複的檢查點終點是SCN--0x0000.001e638d,十進制是:1991565。   

On-Disk RBA的SCN是1991565,這是執行個體恢複的終點。

資料庫的恢複SCN範圍也就由此确定,即SCN範圍:最後檢查點:1991217--On-Disk RBA,用SCN表示即:1991217 ===>>>1991565》》

--說明:

執行個體恢複的起點是Low Cache RBA和Thread Checkpoint RBA中的最大值, 執行個體恢複的終點就是current redo log file的最尾端而不是On-Disk RBA。 On-Disk RBA是要最低恢複到的位置。

這樣,本實驗中執行個體恢複的起始的重做日志是以控制檔案中的low cache rba:(0x6b.3.0)開始恢複,而不是從檔案頭的thread:1 rba:(0x6b.2.10)

########################################################################

5.DUMP REDO日志檔案   --在第一步已經确定了目前日志是redo02.log

更詳細方法,見:http://blog.csdn.net/q947817003/article/details/16370203

[email protected] bys3>alter system dump logfile '/u01/oradata/bys3/redo02.log';

System altered.

[email protected] bys3>select value from v$diag_info where name like 'Default%';

VALUE

------------------------------------------------------------------

/u01/diag/rdbms/bys3/bys3/trace/bys3_ora_1906.trc

REDO日志DUMP最後一個REDO RECORD 的一部分CHANGE #1:  --不知道如何解讀,留白吧???

REDO RECORD - Thread:1 RBA: 0x00006b.00000194.0084 LEN: 0x0418 VLD: 0x09  ---與上一步的對應

SCN: 0x0000.001e638c SUBSCN:  1 12/02/2013 13:21:37

CHANGE #1 TYP:2 CLS:1 AFN:1 DBA:0x004007e1 OBJ:288 SCN:0x0000.001e6386 SEQ:2 OP:11.5 ENC:0 RBL:0

KTB Redo

op: 0x11  ver: 0x01  

compat bit: 4 (post-11) padding: 1

op: F  xid:  0x0009.017.00000642    uba: 0x00c00cac.00f9.28

Block cleanout record, scn:  0x0000.001e638b ver: 0x01 opt: 0x02, entries follow...

  itli: 2  flg: 2  scn: 0x0000.001e6386

KDO Op code: URP row dependencies Disabled

  xtype: XA flags: 0x00000000  bdba: 0x004007e1  hdba: 0x004007e0

itli: 1  ispac: 0  maxfr: 4863

tabn: 0 slot: 1(0x1) flag: 0x2c lock: 1 ckix: 182

ncol: 19 nnew: 6 size: -7

col  4: [ 7]  78 71 0c 02 0e 16 26

col  5: *NULL*

col  6: [ 7]  78 71 0c 02 0e 17 26

col  7: [21]

 c0 06 60 3d 13 34 56 13 34 56 13 34 56 13 34 56 13 34 56 1e 0b

col  9: [ 1]  80

col 10: [ 1]  80

 ###################################################################

6:使用BBED檢視資料檔案頭CHECKPOINT_CHANGE#及rba

[[email protected] ~]$ cat par.bbd

blocksize=8192

listfile=bbedfile.txt

mode=edit

[[email protected] ~]$ cat bbedfile.txt

1       /u01/oradata/bys3/system01.dbf  524288000

2       /u01/oradata/bys3/sysaux01.dbf  340787200

3       /u01/oradata/bys3/undotbs01.dbf 209715200

4       /u01/oradata/bys3/user01.dbf    52428800

[[email protected] ~]$ bbed parfile=par.bbd

Password:

BBED: Release 2.0.0.0.0 - Limited Production on Sun Dec 1 22:29:18 2013

Copyright (c) 1982, 2011, Oracle and/or its affiliates.  All rights reserved.

************ !!! For Oracle Internal Use only !!! ***************

BBED> set file 4 block 1

        FILE#           4

        BLOCK#          1

BBED> map /v

 File: /u01/oradata/bys3/user01.dbf (4)

 Block: 1                                     Dba:0x01000001

------------------------------------------------------------

 Data File Header

 struct kcvfh, 860 bytes                    @0       

    struct kcvfhbfh, 20 bytes               @0       

    struct kcvfhhdr, 76 bytes               @20      

    ub4 kcvfhrdb                            @96      

    struct kcvfhcrs, 8 bytes                @100     

    ub4 kcvfhcrt                            @108     

    ub4 kcvfhrlc                            @112     

    struct kcvfhrls, 8 bytes                @116     

    ub4 kcvfhbti                            @124     

    struct kcvfhbsc, 8 bytes                @128     

    ub2 kcvfhbth                            @136     

    ub2 kcvfhsta                            @138     

    struct kcvfhckp, 36 bytes               @484     

    ub4 kcvfhcpc                            @140     

    ub4 kcvfhrts                            @144     

    ub4 kcvfhccc                            @148     

    struct kcvfhbcp, 36 bytes               @152     

    ub4 kcvfhbhz                            @312     

    struct kcvfhxcd, 16 bytes               @316     

    sword kcvfhtsn                          @332     

    ub2 kcvfhtln                            @336     

    text kcvfhtnm[30]                       @338     

    ub4 kcvfhrfn                            @368     

    struct kcvfhrfs, 8 bytes                @372     

    ub4 kcvfhrft                            @380     

    struct kcvfhafs, 8 bytes                @384     

    ub4 kcvfhbbc                            @392     

    ub4 kcvfhncb                            @396     

    ub4 kcvfhmcb                            @400     

    ub4 kcvfhlcb                            @404     

    ub4 kcvfhbcs                            @408     

    ub2 kcvfhofb                            @412     

    ub2 kcvfhnfb                            @414     

    ub4 kcvfhprc                            @416     

    struct kcvfhprs, 8 bytes                @420     

    struct kcvfhprfs, 8 bytes               @428     

    ub4 kcvfhtrt                            @444     

 ub4 tailchk                                @8188    

BBED> print kcvfhckp

struct kcvfhckp, 36 bytes                   @484     

   struct kcvcpscn, 8 bytes                 @484     

      ub4 kscnbas                           @484      0x001e6231

      ub2 kscnwrp                           @488      0x0000

   ub4 kcvcptim                             @492      0x31a859e6

   ub2 kcvcpthr                             @496      0x0001

   union u, 12 bytes                        @500     

      struct kcvcprba, 12 bytes             @500     

         ub4 kcrbaseq                       @500      0x0000006b

         ub4 kcrbabno                       @504      0x00000002

         ub2 kcrbabof                       @508      0x0010

   ub1 kcvcpetb[0]                          @512      0x02

   ub1 kcvcpetb[1]                          @513      0x00

   ub1 kcvcpetb[2]                          @514      0x00

   ub1 kcvcpetb[3]                          @515      0x00

   ub1 kcvcpetb[4]                          @516      0x00

   ub1 kcvcpetb[5]                          @517      0x00

   ub1 kcvcpetb[6]                          @518      0x00

   ub1 kcvcpetb[7]                          @519      0x00

BBED> set offset 500

        OFFSET          500

BBED> dump /v   [email protected]開始,4位元組表示日志序号,4位元組表示塊号,2位元組表示日志塊中第幾個位元組,表示的是資料檔案頭的RBA資訊

從資料塊中計算出的RBA資訊與print kcvfhckp中的一緻,就不重複算了。

關于日志塊大小,詳見:http://blog.csdn.net/q947817003/article/details/11350359

 File: /u01/oradata/bys3/user01.dbf (4)

 Block: 1       Offsets:  500 to 1011  Dba:0x01000001

-------------------------------------------------------

 6b000000 02000000 10000400 02000000 l k...............

 00000000 00000000 00000000 00000000 l ................

 00000000 00000000 00000000 00000000 l ................

省略。。。。

 <16 bytes per line>

這裡CHKPOINT_SCN資訊是:

struct kcvcpscn, 8 bytes                 @484     

      ub4 kscnbas                           @484      0x001e6231

      ub2 kscnwrp                           @488      0x0000

這三行就是檢查點的SCN資訊,kscnbas--0x001c8e12,kscnwrp--0x0000ub4 --實驗有效的4個byte: 0x0000

scn計算方法:SCN=(SCN_WRP * 4294967296) + SCN_BAS   --SCN的詳細介紹及計算:http://blog.csdn.net/q947817003/article/details/11590983

是以此處的SCN就是:0x0000.001e6231;10進制SCN号為:1991217

RBA資訊是:

 struct kcvcprba, 12 bytes             @500     

         ub4 kcrbaseq                       @500      0x0000006b     --序号,

         ub4 kcrbabno                       @504      0x00000002     --塊号

         ub2 kcrbabof                       @508      0x0010         --位元組号

換算為十進制表示為:107号日志,2号塊,16位元組

與上一步DUMP資料檔案資訊得出的一緻:

thread:1 rba:(0x6b.2.10)

--重做日志的位址0x6b.2.10---> 107号日志,第2号塊,第16個位元組

###################################################################

7.執行EVENT事件的語句,OPEN資料庫後立刻DUMP控制檔案

注意事項:要把EVENT事件的語句執行上,不然實驗所需資料不連貫哈哈

關于下面用到的10013/10015事件,分别是在Startup時跟蹤事務恢複,在事務恢複後做Dump回退段頭資訊。

EVENT事件詳見http://blog.csdn.net/q947817003/article/details/16359765

說明:--在這裡用這兩個語句不知道到底能不能DUMP出詳細的REDO應用及復原資訊,從生成的TRACE檔案來看有這方面資訊,好像不太詳細。。。

[email protected] bys3>alter session set events '10013 trace name context forever,level 1';

Session altered.

[email protected] bys3>alter session set events '10015 trace name context forever,level 1';

Session altered.

[email protected] bys3>alter database open;

Database altered.

[email protected] bys3>select value from v$diag_info where name like 'Default%';

VALUE

----------------------------------------------------------------------

/u01/diag/rdbms/bys3/bys3/trace/bys3_ora_1955.trc

另開一會話在OPEN資料庫後立刻執行:

[email protected] bys3>alter session set events 'immediate trace name controlf level 12';

Session altered.

[email protected] bys3>select value from v$diag_info where name like 'Default%';

VALUE

------------------------------------------------------------------------------

/u01/diag/rdbms/bys3/bys3/trace/bys3_ora_2108.trc

在OPEN過程中,ORACLE檢查以下兩項:  詳見:http://blog.csdn.net/haibusuanyun/article/details/11271107

1.檢查資料檔案頭中檢查點計數(checkpoint CNT)是否與控制檔案中檢查點計數(checkpoint CNT)一緻。以此确定資料檔案是否來自恢複檔案。

2.如果檢查點計數檢查通過,資料庫進行第二次檢查,檢查資料檔案頭的開始SCN和控制檔案中記錄的該檔案的結束SCN是否一緻,如果控制檔案中記錄的結束SCN等于資料檔案頭的開始SCN,不需要執行個體恢複。

以上兩次檢查通過後,打開資料庫,鎖定資料檔案,并将每個資料檔案的結束SCN設定為無窮大。

##################################################################

8.分析OPEN時,通過ALERT日志檢視的恢複過程--前滾

 [[email protected] ~]$ cat alert_bys3.log

Mon Dec 02 20:35:20 2013

alter database open

Beginning crash recovery of 1 threads    --開始執行個體恢複

Started redo scan     --開始掃描REDO日志

Completed redo scan   --完成掃描REDO日志

 read 202 KB redo, 104 data blocks need recovery  --需要恢複的資料塊104塊,REDO日志202KB,按low cache rba--on disk rba來算是407-3=404個日志塊,一個日志塊大小是512位元組,正好202KB。

Started redo application at

 Thread 1: logseq 107, block 3     --這裡可以看到,是從107号日志第3塊開始應用REDO-與第3步中low cache rba:(0x6b.3.0)吻合

Recovery of Online Redo Log: Thread 1 Group 2 Seq 107 Reading mem 0

  Mem# 0: /u01/oradata/bys3/redo02.log   --所使用REDO日志檔案,與第一步查詢吻合。

Completed redo application of 0.16MB  

Completed crash recovery at

 Thread 1: logseq 107, block 407, scn 2011565  --完成執行個體恢複的位置,與第3步中on disk rba:(0x6b.197.0)吻合

 104 data blocks read, 104 data blocks written, 202 redo k-bytes read   --執行個體恢複涉及資訊統計

Mon Dec 02 20:35:20 2013

LGWR: STARTING ARCH PROCESSES    ----可以看到 執行個體恢複完成後,ARCH程序啟動

Mon Dec 02 20:35:21 2013

ARC0 started with pid=19, OS id=2112

ARC0: Archival started

LGWR: STARTING ARCH PROCESSES COMPLETE

ARC0: STARTING ARCH PROCESSES

Thread 1 advanced to log sequence 108 (thread open)

Thread 1 opened at log sequence 108

  Current log# 3 seq# 108 mem# 0: /u01/oradata/bys3/redo03.log

Successful open of redo thread 1       ----可以看到 執行個體恢複完成後,REDO日志啟動

MTTR advisory is disabled because FAST_START_MTTR_TARGET is not set

Mon Dec 02 20:35:22 2013

SMON: enabling cache recovery

Mon Dec 02 20:35:22 2013

ARC1 started with pid=20, OS id=2116

Mon Dec 02 20:35:22 2013

ARC2 started with pid=21, OS id=2122

ARC1: Archival started

ARC2: Archival started

ARC1: Becoming the 'no FAL' ARCH

ARC1: Becoming the 'no SRL' ARCH

ARC2: Becoming the heartbeat ARCH

Mon Dec 02 20:35:23 2013

ARC3 started with pid=22, OS id=2126

還有段ALERT日志涉及復原放在下一小節

 ################################################################

9.分析OPEN時,EVENT事件生成的TRACE中檢視恢複過程--前滾

TRACE檔案内容:

Thread 1 checkpoint: logseq 107, block 2, scn 1991217       

  cache-low rba: logseq 107, block 3      --這一段資訊與MOUNT時DUMP控制檔案的一樣

    on-disk rba: logseq 107, block 407, scn 1991565

  start recovery at logseq 107, block 3, scn 0   --執行個體恢複起點: MOUNT時DUMP控制檔案的low cache rba:(0x6b.3.0)

*** 2013-12-02 20:35:20.739

Started writing zeroblks thread 1 seq 107 blocks 407-414

*** 2013-12-02 20:35:20.745

Completed writing zeroblks thread 1 seq 107

==== Redo read statistics for thread 1 ====

Total physical reads (from disk and memory): 4096Kb   

-- Redo read_disk statistics             --這個應該是執行個體恢複期間REDO讀寫統計

Read rate (ASYNC): 202Kb in 0.22s => 0.90 Mb/sec   --REDO的速度-202KB與ALERT日志中對應

Longest record: 17Kb, moves: 0/287 (0%)

Longest LWN: 18Kb, moves: 0/99 (0%), moved: 0Mb

Last redo scn: 0x0000.001e638c (1991564)    --最後一個REDO的SCN:與On-Disk RBA的SCN是1991565差1

----------------------------------------------

----- Recovery Hash Table Statistics ---------

Hash table buckets = 262144

Longest hash chain = 1

Average hash chain = 104/104 = 1.0

Max compares per lookup = 1

Avg compares per lookup = 1120/1224 = 0.9

----------------------------------------------

*** 2013-12-02 20:35:20.749

KCRA: start recovery claims for 104 data blocks

*** 2013-12-02 20:35:20.781

KCRA: blocks processed = 104/104, claimed = 104, eliminated = 0

*** 2013-12-02 20:35:20.783

Recovery of Online Redo Log: Thread 1 Group 2 Seq 107 Reading mem 0

*** 2013-12-02 20:35:20.815

Completed redo application of 0.16MB    --與ALERT中對照

*** 2013-12-02 20:35:20.944

Completed recovery checkpoint   --可以看到 執行個體恢複完後做了檢查點

----- Recovery Hash Table Statistics ---------

Hash table buckets = 262144

Longest hash chain = 1

Average hash chain = 104/104 = 1.0

Max compares per lookup = 1

Avg compares per lookup = 1224/1224 = 1.0

----------------------------------------------

Recovery sets nab of thread 1 seq 107 to 407 with 8 zeroblks

##################################################################

10.OPEN資料庫時,通過ALERT日志及EVENT事件生成的TRACE中資訊解析執行個體恢複的復原

能力有限,解析不了,留着以後解決吧。

ALERT日志中復原資訊:

[1955] Successfully onlined Undo Tablespace 2.    --

Undo initialization finished serial:0 start:985058364 end:985058674 diff:310 (3 seconds)   --從這句看應該是有復原操作,能力有限,沒更好解釋。。。

Verifying file header compatibility for 11g tablespace encryption..

Verifying 11g file header compatibility for tablespace encryption completed

SMON: enabling tx recovery

Database Characterset is AL32UTF8

Archived Log entry 77 added for thread 1 sequence 107 ID 0xc82cb897 dest 1:

No Resource Manager plan active

replication_dependency_tracking turned off (no async multimaster replication found)

Starting background process QMNC

Mon Dec 02 20:35:24 2013

QMNC started with pid=23, OS id=2130

ARC3: Archival started

ARC0: STARTING ARCH PROCESSES COMPLETE

Completed: alter database open

#############################

EVENT事件生成的TRACE中資訊

*** 2013-12-02 20:35:22.989

Acq rollback segment SYSTEM

Rec rollback segment _SYSSMU1_3056155133$

Recovering transaction (1, 21)      --看這裡好像是SYSTEM復原段做的事務恢複

Marking transaction (1, 21) dead

Rec rollback segment _SYSSMU2_3692097322$

Rec rollback segment _SYSSMU3_3366438251$

Rec rollback segment _SYSSMU4_3660460897$

Rec rollback segment _SYSSMU5_1917899003$

Rec rollback segment _SYSSMU6_3107841501$

Rec rollback segment _SYSSMU7_1420906157$

Rec rollback segment _SYSSMU8_2178365988$

Rec rollback segment _SYSSMU9_1689884801$

Rec rollback segment _SYSSMU10_3239467560$

*** 2013-12-02 20:35:23.225

Recovering transaction (1, 21)    ----這個好像是復原的第一步中未送出的事務,不知道具體如何查詢驗證

Marking transaction (1, 21) dead

Acq rollback segment _SYSSMU1_3056155133$

Acq rollback segment _SYSSMU2_3692097322$

Acq rollback segment _SYSSMU3_3366438251$

Acq rollback segment _SYSSMU4_3660460897$

Acq rollback segment _SYSSMU5_1917899003$

Acq rollback segment _SYSSMU6_3107841501$

Acq rollback segment _SYSSMU7_1420906157$

Acq rollback segment _SYSSMU8_2178365988$

Acq rollback segment _SYSSMU9_1689884801$

Acq rollback segment _SYSSMU10_3239467560$

kwqmnich: current time:: 12: 35: 23: 0

kwqmnich: instance no 0 repartition flag 1

kwqmnich: initialized job cache structure

*** 2013-12-02 20:35:24.574

ktsmgtur(): TUR was not tuned for 25928 secs

ktsmg_advance_slot(): MMNL advances slot after 25928 seconds

################################################################################

11.分析OPEN後的控制檔案資訊--能力有限分析較少

TRACE檔案内容

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)

 11/14/2013 14:23:19

 DB Name "BYS3"

 Database flags = 0x00404001 0x00001200

 Controlfile Creation Timestamp  11/14/2013 14:23:21

 Incmplt recovery scn: 0x0000.00000000

 Resetlogs scn: 0x0000.00000001 Resetlogs Timestamp  11/14/2013 14:23:19

 Prior resetlogs scn: 0x0000.00000000 Prior resetlogs Timestamp  01/01/1988 00:00:00

 Redo Version: compatible=0xb200000

 #Data files = 4, #Online files = 4

 Database checkpoint: Thread=1 scn: 0x0000.001eb1b0   --檢查點已經更新

 Threads: #Enabled=1, #Open=1, Head=1, Tail=1

 enabled  threads:  01000000 00000000 00000000 00000000 00000000 00000000

 Max log members = 5, Max data members = 1

 Arch list: Head=3, Tail=3, Force scn: 0x0000.001b6c94scn: 0x0000.00000000

 Activation ID: 3358374039

 SCN compatibility 1

 Auto-rollover enabled

 Controlfile Checkpointed at scn:  0x0000.001eb212 12/02/2013 20:35:25

 thread:0 rba:(0x0.0.0)

 enabled  threads:  00000000 00000000 00000000 00000000 00000000 00000000

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

CHECKPOINT PROGRESS RECORDS

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

 (size = 8180, compat size = 8180, section max = 4, section in-use = 0,

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

 (extent = 1, blkno = 2, numrecs = 4)

THREAD #1 - status:0x2 flags:0x0 dirty:43

low cache rba:(0x6c.3.0) on disk rba:(0x6c.76.0)  --on disk rba已經遞增

on disk scn: 0x0000.001eb212 12/02/2013 20:35:24  --on disk scn已經遞增

resetlogs scn: 0x0000.00000001 11/14/2013 14:23:19

heartbeat: 833141767 mount id: 3360007946

繼續閱讀