low cache rba恢复到on disk rba
SQL> shutdown abort;
ORACLE instance shut down.
SQL> startup nomount;
ORACLE instance started.
Total System Global Area 764121088 bytes
Fixed Size 2257152 bytes
Variable Size 499126016 bytes
Database Buffers 255852544 bytes
Redo Buffers 6885376 bytes
SQL> oradebug setmypid;
Statement processed.
SQL> alter database mount;
Database altered.
SQL> alter session set events 'immediate trace name controlf level 12';
Session altered.
SQL> oradebug tracename_file;
ORA-00070: command tracename_file is not valid
SQL> oradebug tracefile_name;
/opt/11g/oracle/diag/rdbms/orcldbtest/orcldbtest/trace/orcldbtest_ora_10829.trc
SQL> alter session set events 'immediate trace name controlf off';
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)
06/24/2020 14:38:23
DB Name "ORCLDBTE"
Database flags = 0x00404000 0x00001000
Controlfile Creation Timestamp 06/24/2020 14:38:23
Incmplt recovery scn: 0x0000.00000000
Resetlogs scn: 0x0000.0010f384 Resetlogs Timestamp 06/24/2020 14:49:16
Prior resetlogs scn: 0x0000.000e2006 Prior resetlogs Timestamp 04/24/2019 14:57:50
Redo Version: compatible=0xb200400
#Data files = 5, #Online files = 5
Database checkpoint: Thread=1 scn: 0x0000.0012787a -----10进制 1210490
CHECKPOINT PROGRESS RECORDS
***************************************************************************
(size = 8180, compat size = 8180, section max = 11, section in-use = 0,
last-recid= 0, old-recno = 0, last-recno = 0)
(extent = 1, blkno = 2, numrecs = 11)
THREAD #1 - status:0x2 flags:0x0 dirty:15
low cache rba:(0x4.168b.0) on disk rba:(0x4.1715.0)
on disk scn: 0x0000.00127ca2 07/04/2020 23:41:21
resetlogs scn: 0x0000.0010f384 06/24/2020 14:49:16
heartbeat: 1044917597 mount id: 3131257367
控制文件DATABASE ENTRY记录的检查点是12787a 10进制 1210490， CHECKPOINT PROGRESS RECORDS中记录的low cache rba 0x4.168b，log seqenuce 是4，block number 168b 10进制 5771，on disk scn: 0x0000.00127ca2 10进制 1211554
跟踪open过程
SQL> alter session set events '10046 trace name context forever,level 12';
Session altered.
SQL> alter database open;
Database altered.
SQL> alter session set events '10046 trace name context off';
Session altered.
查看跟踪文件
*** 2020-07-05 00:05:30.839
WAIT #140413278455400: nam='SQL*Net message from client' ela= 19379251 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1593878730839504
CLOSE #140413278455400:c=6,e=7,dep=0,type=1,tim=1593878730839670
XCTEND rlbk=0, rd_only=1, tim=1593878730840005
=====================
PARSING IN CURSOR #140413278450048 len=19 dep=0 uid=0 oct=35 lid=0 tim=1593878730840359 hv=1907384048 ad='8d590a70' sqlid='a01hp0psv0rrh'
alter database open
END OF STMT
PARSE #140413278450048:c=650,e=650,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=0,tim=1593878730840358
WAIT #140413278450048: nam='control file sequential read' ela= 20 file#=0 block#=1 blocks=1 obj#=-1 tim=1593878730840964
WAIT #140413278450048: nam='control file sequential read' ela= 7 file#=1 block#=1 blocks=1 obj#=-1 tim=1593878730841008
WAIT #140413278450048: nam='control file sequential read' ela= 6 file#=0 block#=16 blocks=1 obj#=-1 tim=1593878730841027
WAIT #140413278450048: nam='control file sequential read' ela= 5 file#=0 block#=18 blocks=1 obj#=-1 tim=1593878730841043
WAIT #140413278450048: nam='rdbms ipc reply' ela= 192 from_process=12 timeout=2147483647 p3=0 obj#=-1 tim=1593878730841336
WAIT #140413278450048: nam='rdbms ipc reply' ela= 146 from_process=12 timeout=2147483647 p3=0 obj#=-1 tim=1593878730841539
WAIT #140413278450048: nam='control file sequential read' ela= 7 file#=0 block#=1 blocks=1 obj#=-1 tim=1593878730841590
WAIT #140413278450048: nam='control file sequential read' ela= 3 file#=0 block#=16 blocks=1 obj#=-1 tim=1593878730841603
WAIT #140413278450048: nam='control file sequential read' ela= 3 file#=0 block#=18 blocks=1 obj#=-1 tim=1593878730841612
WAIT #140413278450048: nam='rdbms ipc reply' ela= 2022 from_process=10 timeout=910 p3=0 obj#=-1 tim=1593878730843664
WAIT #140413278450048: nam='control file sequential read' ela= 7 file#=0 block#=1 blocks=1 obj#=-1 tim=1593878730843748
WAIT #140413278450048: nam='control file sequential read' ela= 3 file#=0 block#=16 blocks=1 obj#=-1 tim=1593878730843761
WAIT #140413278450048: nam='control file sequential read' ela= 3 file#=0 block#=18 blocks=1 obj#=-1 tim=1593878730843770
WAIT #140413278450048: nam='control file sequential read' ela= 3 file#=0 block#=302 blocks=1 obj#=-1 tim=1593878730843779
WAIT #140413278450048: nam='control file sequential read' ela= 2 file#=0 block#=1 blocks=1 obj#=-1 tim=1593878730843811
WAIT #140413278450048: nam='control file sequential read' ela= 4 file#=1 block#=1 blocks=1 obj#=-1 tim=1593878730843824
WAIT #140413278450048: nam='control file sequential read' ela= 3 file#=0 block#=16 blocks=1 obj#=-1 tim=1593878730843832
WAIT #140413278450048: nam='control file sequential read' ela= 2 file#=0 block#=18 blocks=1 obj#=-1 tim=1593878730843839
WAIT #140413278450048: nam='control file sequential read' ela= 7 file#=0 block#=302 blocks=1 obj#=-1 tim=1593878730843927
WAIT #140413278450048: nam='Disk file operations I/O' ela= 28 FileOperation=2 fileno=1 filetype=2 obj#=-1 tim=1593878730844097
WAIT #140413278450048: nam='Disk file operations I/O' ela= 13 FileOperation=2 fileno=2 filetype=2 obj#=-1 tim=1593878730844136
WAIT #140413278450048: nam='Disk file operations I/O' ela= 10 FileOperation=2 fileno=3 filetype=2 obj#=-1 tim=1593878730844161
WAIT #140413278450048: nam='Disk file operations I/O' ela= 5 FileOperation=2 fileno=4 filetype=2 obj#=-1 tim=1593878730844172
WAIT #140413278450048: nam='Disk file operations I/O' ela= 5 FileOperation=2 fileno=5 filetype=2 obj#=-1 tim=1593878730844184
WAIT #140413278450048: nam='Disk file operations I/O' ela= 6 FileOperation=2 fileno=201 filetype=2 obj#=-1 tim=1593878730844200
WAIT #140413278450048: nam='control file sequential read' ela= 6 file#=0 block#=24 blocks=1 obj#=-1 tim=1593878730844216
WAIT #140413278450048: nam='db file sequential read' ela= 14 file#=1 block#=1 blocks=1 obj#=-1 tim=1593878730844247
WAIT #140413278450048: nam='db file single write' ela= 534 file#=1 block#=1 blocks=1 obj#=-1 tim=1593878730844813
WAIT #140413278450048: nam='db file sequential read' ela= 77 file#=2 block#=1 blocks=1 obj#=-1 tim=1593878730844988
WAIT #140413278450048: nam='db file single write' ela= 429 file#=2 block#=1 blocks=1 obj#=-1 tim=1593878730845460
WAIT #140413278450048: nam='db file sequential read' ela= 7 file#=3 block#=1 blocks=1 obj#=-1 tim=1593878730845518
WAIT #140413278450048: nam='db file single write' ela= 302 file#=3 block#=1 blocks=1 obj#=-1 tim=1593878730845841
WAIT #140413278450048: nam='db file sequential read' ela= 5 file#=4 block#=1 blocks=1 obj#=-1 tim=1593878730845890
WAIT #140413278450048: nam='db file single write' ela= 393 file#=4 block#=1 blocks=1 obj#=-1 tim=1593878730846304
WAIT #140413278450048: nam='db file sequential read' ela= 4 file#=5 block#=1 blocks=1 obj#=-1 tim=1593878730846332
WAIT #140413278450048: nam='db file single write' ela= 363 file#=5 block#=1 blocks=1 obj#=-1 tim=1593878730846712
WAIT #140413278450048: nam='control file parallel write' ela= 587 files=2 block#=23 requests=2 obj#=-1 tim=1593878730847323
WAIT #140413278450048: nam='control file parallel write' ela= 487 files=2 block#=17 requests=2 obj#=-1 tim=1593878730847849
WAIT #140413278450048: nam='control file parallel write' ela= 622 files=2 block#=15 requests=2 obj#=-1 tim=1593878730848499
WAIT #140413278450048: nam='control file parallel write' ela= 633 files=2 block#=1 requests=2 obj#=-1 tim=1593878730849199
WAIT #140413278450048: nam='os thread startup' ela= 12391 p1=0 p2=0 p3=0 obj#=-1 tim=1593878730862038
WAIT #140413278450048: nam='os thread startup' ela= 11530 p1=0 p2=0 p3=0 obj#=-1 tim=1593878730873717
WAIT #140413278450048: nam='PX Deq: Join ACK' ela= 1278 sleeptime/senderid=268500992 passes=1 p3=2371597480 obj#=-1 tim=1593878730875274
WAIT #140413278450048: nam='PX Deq: Join ACK' ela= 548 sleeptime/senderid=268500993 passes=1 p3=2371596792 obj#=-1 tim=1593878730875867
Successfully allocated 2 recovery slaves
Using 67 overflow buffers per recovery slave
WAIT #140413278450048: nam='parallel recovery coord wait for reply' ela= 2195 p1=268500992 p2=1 p3=2371597480 obj#=-1 tim=1593878730880281
WAIT #140413278450048: nam='parallel recovery coord wait for reply' ela= 355 p1=268500993 p2=1 p3=2371596792 obj#=-1 tim=1593878730880687
WAIT #140413278450048: nam='rdbms ipc reply' ela= 151 from_process=10 timeout=2147483647 p3=0 obj#=-1 tim=1593878730880875
WAIT #140413278450048: nam='control file sequential read' ela= 3 file#=0 block#=1 blocks=1 obj#=-1 tim=1593878730880902
WAIT #140413278450048: nam='control file sequential read' ela= 2 file#=1 block#=1 blocks=1 obj#=-1 tim=1593878730880911
WAIT #140413278450048: nam='control file sequential read' ela= 2 file#=0 block#=15 blocks=1 obj#=-1 tim=1593878730880918
WAIT #140413278450048: nam='control file sequential read' ela= 2 file#=0 block#=17 blocks=1 obj#=-1 tim=1593878730880924
WAIT #140413278450048: nam='control file sequential read' ela= 3 file#=0 block#=302 blocks=1 obj#=-1 tim=1593878730880936
WAIT #140413278450048: nam='control file sequential read' ela= 3 file#=0 block#=19 blocks=1 obj#=-1 tim=1593878730880951
WAIT #140413278450048: nam='control file sequential read' ela= 3 file#=0 block#=22 blocks=1 obj#=-1 tim=1593878730880958
Thread 1 checkpoint: logseq 4, block 5285, scn 1210490
WAIT #140413278450048: nam='control file sequential read' ela= 11 file#=0 block#=3 blocks=1 obj#=-1 tim=1593878730881093
cache-low rba: logseq 4, block 5771
on-disk rba: logseq 4, block 5909, scn 1211554
start recovery at logseq 4, block 5771, scn 0
-- Redo read_disk statistics --
Read rate (ASYNC): 69Kb in 0.25s => 0.27 Mb/sec
Longest record: 0Kb, moves: 0/413 (0%)
Change moves: 5/42 (11%), moved: 0Mb
Longest LWN: 18Kb, moves: 0/34 (0%), moved: 0Mb
Last redo scn: 0x0000.00127ca0 (1211552)
----------------------------------------------
日志
Sun Jul 05 00:05:30 2020
alter database open
Beginning crash recovery of 1 threads
parallel recovery started with 2 processes
Started redo scan
Completed redo scan
read 69 KB redo, 15 data blocks need recovery
Thread 1: logseq 4, block 5771
Recovery of Online Redo Log: Thread 1 Group 1 Seq 4 Reading mem 0
Mem# 0: /oradata/ORCLDBTEST/onlinelog/o1_mf_1_gd027gd1_.log
Completed redo application of 0.01MB
Completed crash recovery at
Thread 1: logseq 4, block 5909, scn 1231554
15 data blocks read, 15 data blocks written, 69 redo k-bytes read
SQL> select * from v$log;
GROUP# THREAD# SEQUENCE# BYTES BLOCKSIZE MEMBERS ARC STATUS FIRST_CHANGE# FIRST_TIM NEXT_CHANGE# NEXT_TIME
---------- ---------- ---------- ---------- ---------- ---------- --- ---------------- ------------- --------- ------------ ---------
1 1 4 52428800 512 1 NO INACTIVE 1208286 04-JUL-20 1231556 05-JUL-20
2 1 5 52428800 512 1 NO CURRENT 1231556 05-JUL-20 2.8147E+14
3 1 3 52428800 512 1 NO INACTIVE 1166863 04-JUL-20 1208286 04-JUL-20
可以看到open过程中的起点scn 1210490， on-disk rba: logseq 4, block 5909, scn 1211554 16进制 127CA2，与控制文件中的是一致。从告警日志与v$log视图中也可以看到相关信息。
