Flashback log裡存放的是data block修改前的image，當我們修改一個data block時，data block before image會首先從buffer cache被複制到flashback generation buffer，然後再由RVWR(Recovery writer)程式將before image從flashback generation buffer讀取出來寫入到flashback log。Flashback database時會使用flashback log裡的data block before image覆蓋對應資料檔案中的data block，這個過程稱為Flashback restore。

三種情況下會生成Flashback log：
1、開啟資料庫級的flashback功能：
alter database flashback on;
select flashback_on from v$database;
FLASHBACK_ON
------------------
YES

2、資料庫級的flashback功能處於關閉狀態，但建立了guaranteed restore point：
alter database flashback off;
create restore point grp1 guarantee flashback database;

select flashback_on from v$database;

FLASHBACK_ON
------------------
RESTORE POINT ONLY

3、資料庫級的flashback功能處於開啟狀態，且又建立了guaranteed restore point
alter database flashback on;
create restore point grp1 guarantee flashback database;

select flashback_on from v$database;

FLASHBACK_ON
------------------
YES

第1種情況：資料庫級別開啟flashback功能，但沒有建立guaranteed restore point，flashback database能夠回溯到的時間點取決於db_flashback_retention_target，但這並不是一個硬性指標，當遇到Fast Recovery Area用滿的時候較早生成的Flashback log會被清理掉以留出足夠的空間給新生成的flashback log，所以無法保證一定能將資料庫flashback到db_flashback_retention_target指定的時間點。data block被修改之前其before image被寫入flashback log，對於活躍度較高的data block並不是每次更改都會觸發before image寫入flashback log，這樣做的目的是有效降低Flashback log write對資料庫IO效能的影響

第2種情況：建立了guaranteed restore point，但沒有在資料庫級別開啟flashback功能，也稱為Guaranteed restore point without flashback logging，這種情況確保資料庫一定能flashback到guaranteed restore point建立時的狀態，如果出現Fast Recovery Area用滿且又沒有obsolete file可以刪除的時候甚至會引起資料庫Hang。guaranteed restore point的功能有點類似儲存上的snapshot概念，提供了完整保留某一個時間點資料的功能，建立了guaranteed restore point之後，某個data block被更改，且一定是首次更改的時候，data block before image才會被寫入Flashback log，即Copy-on-first-write，即使該data block之後再次被修改，其before image也不會再次被寫入flashback log，對同一個data block來說其before-image永遠只會寫入一次flashback log

第3種情況，也稱為Guaranteed restore point with flashback logging，集1、2之大成，確保資料庫能flashback到從guaranteed restore point時間點開始的任何時間點

因為第3種情況包含了第1種，我們僅針對上面的第2、3種情況研究一下flashback log的生成機制。
先引入一個隱含引數_flashback_barrier_interval，我們前面提到過在資料庫級別的flashback功能開啟時，同一個block被更改多次的情況下，不會每次都將before image寫入flashback log，data block被更改的時候需要計算距離上一次更改的時間，當這個時間間隔大於等於_flashback_barrier_interval時才會將before image寫入flashback log，_flashback_barrier_interval的預設值是1800秒，為了方便測試我們調整為60秒，修改此引數需要重啟例項

alter system set "_flashback_barrier_interval"=60 scope=spfile;

startup force

show parameter _flashback_barrier_interval

NAME TYPE VALUE
------------------------------------ ----------- ------------------------------
_flashback_barrier_interval integer 60

================Part 1. Guaranteed restore point without flashback logging================
--清理掉所有存在的配置
&& connect SYS
alter database flashback off;
drop restore point grp0425_1;

--建立測試表
&& connect scott
drop table t0425_1;
create table t0425_1 (c1 varchar2(10),c2 number) tablespace ts0422_1;
insert into t0425_1 values('AAAAA',0);
commit;

select * from t0425_1;

C1 C2
---------- ----------
AAAAA 0

--記錄資料塊的地址
select dbms_rowid.rowid_block_number(rowid),dbms_rowid.rowid_relative_fno(rowid) from t0425_1;
DBMS_ROWID.ROWID_BLOCK_NUMBER(ROWID) DBMS_ROWID.ROWID_RELATIVE_FNO(ROWID)
------------------------------------ ------------------------------------
45459 9

--建立guarantee restore point並開啟database flashback
&& connect sys
create restore point grp0425_1 guarantee flashback database;

select flashback_on from v$database;

FLASHBACK_ON
------------------
RESTORE POINT ONLY

--執行前觀察flashback log的生成量
col restore_point_time format a5
col time format a50
col name format a30
set numwidth 16
set linesize 180
select * from v$flashback_database_stat;
BEGIN_TIME END_TIME FLASHBACK_DATA DB_DATA REDO_DATA ESTIMATED_FLASHBACK_SIZE
----------------- ----------------- ---------------- ---------------- ---------------- ------------------------
20150425 21:00:08 20150425 21:00:22 425984 32768 46080 0

--執行前觀察flashback log write的生成量
col name format a50
set linesize 150
select n.name,s.value from v$sysstat s,v$statname n where n.statistic#=s.statistic# and n.name=s.name and n.name like 'flashback log write%';
NAME VALUE
-------------------------------------------------- ----------------
flashback log writes 212
flashback log write bytes 14737408

--下列的過程持續執行300秒，update語句執行15次，每次執行距離上一次間隔20秒
declare
v_cnt number:=1;
begin
while ( v_cnt < 16 ) loop
update t0425_1 set c2=v_cnt;
commit;
dbms_lock.sleep(20);
v_cnt:=v_cnt+1;
end loop;
end;
/

SCOTT@tstdb1-SQL> select * from t0425_1;

C1 C2
---------- ----------
AAAAA 15

--執行後觀察flashback log的生成量
col restore_point_time format a5
col time format a50
col name format a30
set numwidth 16
set linesize 180
select * from v$flashback_database_stat;
BEGIN_TIME END_TIME FLASHBACK_DATA DB_DATA REDO_DATA ESTIMATED_FLASHBACK_SIZE
----------------- ----------------- ---------------- ---------------- ---------------- ------------------------
20150425 21:07:03 20150425 21:07:17 8192 0 7168 0
20150425 21:03:39 20150425 21:07:03 155648 1564672 146432 0
20150425 21:00:08 20150425 21:03:39 0 0 0 0

--執行後觀察flashback log write的生成量
col name format a50
set linesize 150
select n.name,s.value from v$sysstat s,v$statname n where n.statistic#=s.statistic# and n.name=s.name and n.name like 'flashback log write%';
NAME VALUE
------------------------------ ----------------
flashback log writes 225
flashback log write bytes 16171008

--獲取flashback log的最大和最小序號
select min(log#),max(log#) from v$flashback_database_logfile;
MIN(LOG#) MAX(LOG#)
---------- ----------
1 2

--從所有的flashback log裡dump出記錄block 9/40587的內容
select * from v$diag_info; --tstdb1_ora_37159746.trc

alter system dump flashback logfile 1 dba 9 45459;
alter system dump flashback logfile 2 dba 9 45459;

--將9/40587轉換成rdba，到.trc檔案中搜尋
select to_char(dbms_utility.make_data_block_address(9,45459),'xxxxxxxx') from dual;
TO_CHAR(D
---------
240b193

--rdba: 0x0240b193只儲存了一個版本
cat tstdb1_ora_37159746.trc |grep "file#: 9 rdba: 0x0240b193"
file#: 9 rdba: 0x0240b193

--從flashback log裡dump出block 9/45459，以驗證是否為原始值
alter system dump flashback logfile 1 dba 9 45459;

--dump內容如下
Block header dump: 0x0240b193
Object id on Block? Y
seg/obj: 0x8ce8 csc: 0xb92.63701f44 itc: 2 flg: E typ: 1 - DATA
brn: 0 bdba: 0x240b190 ver: 0x01 opc: 0
inc: 0 exflg: 0

Itl Xid Uba Flag Lck Scn/Fsc
0x01 0x000a.00d.0000f0fa 0x00c2bc9c.28a4.1f --U- 1 fsc 0x0000.63701f45
0x02 0x0000.000.00000000 0x00000000.0000.00 ---- 0 fsc 0x0000.00000000
bdba: 0x0240b193
data_block_dump,data header at 0x112ec0a64
===============
tsiz: 0x1f98
hsiz: 0x14
pbl: 0x112ec0a64
76543210
flag=--------
ntab=1
nrow=1
frre=-1
fsbo=0x14
fseo=0x1f8d
avsp=0x1f79
tosp=0x1f79
0xe:pti[0] nrow=1 offs=0
0x12:pri[0] offs=0x1f8d
block_row_dump:
tab 0, row 0, @0x1f8d
tl: 11 fb: --H-FL-- lb: 0x1 cc: 2
col 0: [ 5] 41 41 41 41 41
col 1: [ 1] 80
end_of_block_dump
End-Of-Thread reached
---------- Flashback Read Statistics ----------
Total Elapsed time 0.94s
Number of sequential reads: 131 => 1020Kb per read
Sequential read speed: 133744Kb in 0.94s => 138.15 Mb/sec
Total waited on sequential reads to complete 0.92s
No random reads.
Number of async reads: 1

--儲存的是t0425_1的初始值c1='AAAAA',c2=0
select utl_raw.cast_to_number(80) from dual;
UTL_RAW.CAST_TO_NUMBER('80')
----------------------------
0

select utl_raw.cast_to_varchar2(replace('41 41 41 41 41',' ')) from dual;
UTL_RAW.CAST_TO_VARCHAR2(REPLACE('4141414141',''))
----------------------------------------------------------------------------------------------------
AAAAA

Guaranteed restore point without flashback logging的情況下，可以看出被修改的data block before image僅在block被首次修改時才會寫入flashback log，後續的修改不會再寫入，期間的flashback log生成量為1433600 bytes,flashback log writes為13次

====================Part 2. Guaranteed restore point with flashback logging==================
--清理掉所有存在的配置
&& connect SYS
alter database flashback off;
drop restore point grp0425_1;

--建立測試表
&& connect scott
drop table t0425_1;
create table t0425_1 (c1 varchar2(10),c2 number) tablespace ts0422_1;
insert into t0425_1 values('AAAAA',0);
commit;

select * from t0425_1;

C1 C2
---------- ----------
AAAAA 0

--記錄資料塊的地址
select dbms_rowid.rowid_block_number(rowid),dbms_rowid.rowid_relative_fno(rowid) from t0425_1;
DBMS_ROWID.ROWID_BLOCK_NUMBER(ROWID) DBMS_ROWID.ROWID_RELATIVE_FNO(ROWID)
------------------------------------ ------------------------------------
40587 9

--建立guarantee restore point並開啟database flashback
&& connect sys
create restore point grp0425_1 guarantee flashback database;
alter database flashback on;

select flashback_on from v$database;

FLASHBACK_ON
------------------
YES

--執行前觀察flashback log的生成量
col restore_point_time format a5
col time format a50
col name format a30
set numwidth 16
set linesize 180
select * from v$flashback_database_stat;
BEGIN_TIME END_TIME FLASHBACK_DATA DB_DATA REDO_DATA ESTIMATED_FLASHBACK_SIZE
----------------- ----------------- ---------------- ---------------- ---------------- ------------------------
20150425 17:30:27 20150425 17:30:41 147456 0 9216 0

--執行前觀察flashback log write的生成量
col name format a50
set linesize 150
select n.name,s.value from v$sysstat s,v$statname n where n.statistic#=s.statistic# and n.name=s.name and n.name like 'flashback log write%';
NAME VALUE
-------------------------------------------------- ----------------
flashback log writes 5
flashback log write bytes 245760

--下列的過程持續執行300秒，update語句執行15次，每次執行距離上一次間隔20秒
declare
v_cnt number:=1;
begin
while ( v_cnt < 16 ) loop
update t0425_1 set c2=v_cnt;
commit;
dbms_lock.sleep(20);
v_cnt:=v_cnt+1;
end loop;
end;
/

SCOTT@tstdb1-SQL> select * from t0425_1;

C1 C2
---------- ----------
AAAAA 15

--執行後觀察flashback log的生成量
col restore_point_time format a5
col time format a50
col name format a30
set numwidth 16
set linesize 180
select * from v$flashback_database_stat;
BEGIN_TIME END_TIME FLASHBACK_DATA DB_DATA REDO_DATA ESTIMATED_FLASHBACK_SIZE
----------------- ----------------- ---------------- ---------------- ---------------- ------------------------
20150425 17:39:47 20150425 17:40:34 139264 32768 14336 0
20150425 17:37:44 20150425 17:39:47 442368 819200 37888 0
20150425 17:34:43 20150425 17:37:44 720896 188416 80384 0
20150425 17:32:40 20150425 17:34:43 1097728 942080 174592 0
20150425 17:30:27 20150425 17:32:40 614400 0 44032 0

--執行後觀察flashback log write的生成量
col name format a50
set linesize 150
select n.name,s.value from v$sysstat s,v$statname n where n.statistic#=s.statistic# and n.name=s.name and n.name like 'flashback log write%';
NAME VALUE
-------------------------------------------------- ----------------
flashback log writes 57
flashback log write bytes 3031040

--獲取flashback log的編號範圍
select min(log#),max(log#) from v$flashback_database_logfile;
MIN(LOG#) MAX(LOG#)
---------- ----------
1 2

--從所有的flashback log裡dump出記錄block 9/40587的內容
select * from v$diag_info; --tstdb1_ora_40371176.trc

alter system dump flashback logfile 1 dba 9 40587;
alter system dump flashback logfile 2 dba 9 40587;

--將9/40587轉換成rdba，到.trc檔案中搜尋
select to_char(dbms_utility.make_data_block_address(9,40587),'xxxxxxxx') from dual;
TO_CHAR(D
---------
2409e8b

--0x02409e8b一共存在6個版本
cat tstdb1_ora_40371176.trc |grep "file#: 9 rdba: 0x02409e8b"
file#: 9 rdba: 0x02409e8b
file#: 9 rdba: 0x02409e8b
file#: 9 rdba: 0x02409e8b
file#: 9 rdba: 0x02409e8b
file#: 9 rdba: 0x02409e8b
file#: 9 rdba: 0x02409e8b

cat tstdb1_ora_40371176.trc |grep "file#: 9 rdba: 0x02409e8b" | wc -l
6

以上結果可以看出300秒的時間內block 9/40587雖然被update了15次(每次update距離上一次的時間間隔是20秒)，但只有6次被記錄到了flashback log，因為_flashback_barrier_interval=60，所以基本是每三次update裡有一次會寫入flashback。300秒的時間內生成的flashback log約為2867200 bytes，產生的flashback log writes為52次，比Guaranteed restore point without flashback logging的情況都要大得多。當我們將_flashback_barrier_interval設定為100秒(過程略)時，300秒內觀察到4次寫入flashback的操作，期間生成的flashback log約為3710976 bytes，flashback log writes為50次。
_flashback_barrier_interval設定為60秒時flashback log寫入次數是6次，產生的flashback log為2867200 bytes
_flashback_barrier_interval設定為100秒時flashback log寫入次數下降為3次，產生的flashback log為3710976 bytes，為何次數下降了一半，但flashback log的生產量卻和原來差不多？
因為大部分的flashback log都是由undo block產生的，我們對錶t0425_1所進行了15次update，每次update都會涉及到對undo block的修改，每次使用的undo block都有可能不相同，undo block的before image也要寫入flashback log，undo表空間是資料庫裡最活躍的表空間之一，前臺應用及其所觸發的recursive操作都有可能修改undo block，background process自身會發起對系統表的更改操作，也牽涉到undo，所以在flashback log裡所儲存的大部分before image都來自undo block，
使用下面的命令可以知道序號為1的flashback log裡儲存了哪些data block以及這些block所對應的file#，例如alter system dump logfile 1 logical能夠輸出以下內容：
**** Record at fba: (lno 2 thr 1 seq 2 bno 16384 bof 1464) ****
RECORD HEADER:
Type: 1 (Block Image) Size: 28
RECORD DATA (Block Image):
file#: 3 rdba: 0x00c3be36
Next scn: 0x0000.00000000 [0.0]
Flag: 0x0
Block Size: 8192
**** Record at fba: (lno 2 thr 1 seq 2 bno 16383 bof 1412) ****
RECORD HEADER:
Type: 1 (Block Image) Size: 28
RECORD DATA (Block Image):
file#: 3 rdba: 0x00c3be35
Next scn: 0x0000.00000000 [0.0]
Flag: 0x0
Block Size: 8192
**** Record at fba: (lno 2 thr 1 seq 2 bno 16382 bof 1360) ****
RECORD HEADER:
Type: 1 (Block Image) Size: 28
RECORD DATA (Block Image):
file#: 3 rdba: 0x00c3be34
Next scn: 0x0000.00000000 [0.0]
Flag: 0x0
Block Size: 8192

在我的測試資料庫裡，將log#=1、2的兩個flashback log匯出到.trc檔案
alter system dump logfile 1 logical;
alter system dump logfile 2 logical;

透過以下shell命令，過濾出部分有用的資訊：
---flashback log包含了來自哪些datafile的block
cat tstdb1_ora_39977214.trc | grep file# | awk '{print $1 " "$2}' |sort -u
file#: 1
file#: 2
file#: 3
file#: 9

---很明顯，flashback log裡記錄的大部分都是system、sysaux、undo裡的data block，真正使用者表空間只佔了4個block

cat tstdb1_ora_39977214.trc | grep "file#: 1" | awk '{print $1 " "$2}' | wc -l
129
cat tstdb1_ora_39977214.trc | grep "file#: 2" | awk '{print $1 " "$2}' | wc -l
414
cat tstdb1_ora_39977214.trc | grep "file#: 3" | awk '{print $1 " "$2}' | wc -l
267
cat tstdb1_ora_39977214.trc | grep "file#: 9" | awk '{print $1 " "$2}' | wc -l
4

flashback log的寫入機制研究

相關文章