ITPub博客

首页 > 数据库 > Oracle > flashback log的写入机制研究

flashback log的写入机制研究

原创 Oracle 作者:oliseh 时间:2015-04-25 22:06:46 0 删除 编辑
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         <----c2=15代表update执行的次数


--执行后观察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                               <---c2=0
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         <----c2=15代表update执行的次数


--执行后观察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        <-----定位到具体哪个block
      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   <---属于system表空间
file#: 2   <---属于sysaux表空间
file#: 3   <---属于undo表空间
file#: 9   <---数据我们测试表t0425_1所在的表空间


---很明显,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




来自 “ ITPUB博客 ” ,链接:http://blog.itpub.net/53956/viewspace-1602019/,如需转载,请注明出处,否则将追究法律责任。

请登录后发表评论 登录
全部评论
不仅仅专注Oracle database技术, member of SHOUG

注册时间:2014-04-06

  • 博文量
    128
  • 访问量
    1617085