Flashback and Forth

A reader of my previous post about Oracle’s Flashback Database posted a comment noting that the Oracle documentation doesn’t make any reference to the ability of the FLASHBACK DATABASE command to roll the database forward, which I had affirmed to be possible. Even in an example in the Database B&R User’s Guide, the FLASHBACK DATABASE command is used to rewind the database while the RECOVER DATABASE is used to roll it forward.

I knew from experience that the database can be rolled back and forth using the FLASHBACK DATABASE command and decided to have a closer look.

Flashback Restore and Flashback Recovery

When executing a flashback of the database to a target SCN, Oracle executes two distinct operations in the background:

1. The first operation is called Flashback Restore. In this phase, Oracle restores all the blocks that were modified after the target SCN to a state prior to that point, using the data stored in the flashback logs. This operation undoes all the changes made after the target SCN but still leaves the database in an inconsistent state.
2. The database then performs a Flashback Media Recovery, which rolls the database forward up to the target SCN, using the information in the archived redo logs. At this point, the FLASHBACK DATABASE command is completed, and the database is left in a mounted and inconsistent state.

After the FLASHBACK DATABASE operation, the database can be opened. This action will rollback the transactions that were still uncommitted at target SCN, leaving persisted only the data committed up to that point.

I couldn’t find much detailed information about the two phases of the FLASHBACK DATABASE command. The “Flashback Media Recovery” operation seems to be/do the same as the traditional Media Recovery, even though it’s logged explicitly as a “Flashback Media Recovery” in the alert.log. Conceptually, it’s just rolling forward an inconsistent database, which is exactly what Oracle’s traditional Media Recovery is for.

The Flashback Restore, though, is a new operation introduced with the Flashback Database feature. It requires the information in the flashback logs, which are only generated when Flashback Database is enabled for the database (either explicitly through the ALTER DATABASE FLASHBACK ON command, or implicitly by creating a guaranteed restore point). I tried to find more information in the public domain and in MOS about it, but couldn’t find much. What I describe in this post are just conclusions from my own observations so far. All my tests were performed on Oracle 11.2.0.3.3.

“Flash-forward”

The description of the two phases of the FLASHBACK DATABASE command given above explains how this command rolls the database back to a point in time in the past.

Let’s imagine that the FLASHBACK command completed and that the database is at target SCN. Now, we want to roll the database forward to a more recent point in time. Can we FLASHBACK DATABASE again or should we use RECOVER DATABASE? The answer is: Both commands can be used, but they work differently.

The way the RECOVER DATABASE command works in this case is straight forward and well-known. It’ll read changes from the archived logs and apply them to the database, advancing the database SCN up to the new target specified or to a point where the database is in a consistent state (in the case of a complete recovery).

The FLASHBACK DATABASE command will still execute its two phases, even though the target is now in the future. First, the Flashback Restore will rollback the database to a point in time further in the past. The Flashback Media Recovery will then start from that point and perform media recovery up to the new target SCN.

Judging from my observations so far, the RECOVER DATABASE command seems to be, performance-wise, the best option here since it avoids executing the unnecessary Flashback Restore, which rolls the database backwards just to roll it forwards again. FLASHBACK DATABASE, though, works just fine, but incurs that overhead. The nice thing about the latter command is that its syntax doesn’t change regardless of whether or not we want to roll the database backwards or forwards. It’s more consistent, making it easier to use.

I performed quite a few tests to try verifying the exact behavior of the FLASHBACK DATABASE command. However, my tests haven’t covered every possible scenario like, for example, flashback scenarios with large flashback windows and/or volume of data changes. It might be that the FLASHBACK DATABASE commands implements some optimizations that I haven’t noticed or been able to verify. If that’s not the case, Oracle should at least run a straight RECOVER DATABASE in case a FLASHBACK DATABASE is executed to a point in time in the future.

How far back does the Flashback Restore go?

One of the things that is still unclear to me is how far back the Flashback Restore goes before the Flashback Media Recovery starts. I’m still investigating/testing that. In my early tests, with relatively small flashback windows, *every* FLASHBACK DATABASE operation seems to cause the database to roll back to the first SCN of the earliest flashback log (or very close to that). This means that if you’re trying to flashback the database to only 1 minute ago and have a flashback retention window of 1 hour, the database will be first rolled back to the state of 1 hour ago and then rolled forward through Media Recovery to the point in time of 1 minute ago. If your flashback retention window is large, this operation can take very long, even for “small flashbacks”.

I’m still doing a few more tests to see what more I can find about this. I’d love to hear from other people who may have looked into this before and may have other information. I’ll blog about whatever I can find on this subject.

Example

To finish this post, this is a quick example to show that the FLASHBACK DATABASE can be used to roll a database forward. I created restore points for ease of use but I could have use SCN references instead.

First, I created a sample table and inserted some data, creating restore points along the way and switching logs so that we can see some media recovery activity in the logs later on.

SQL> create table mytest (name varchar2(30));
Table created.
SQL> create restore point FIRST;
Restore point created.
SQL> insert into mytest values ('John');
1 row created.
SQL> alter system switch logfile;
System altered.
SQL> create restore point SECOND;
Restore point created.
SQL> insert into mytest values ('Ringo');
1 row created.
SQL> create restore point THIRD;
Restore point created.
SQL> alter system switch logfile;
System altered.
SQL> insert into mytest values ('Paul');
1 row created.
SQL> create restore point FOURTH;
Restore point created.
SQL> alter system switch logfile;
System altered.
SQL> insert into mytest values ('George');
1 row created.
SQL> alter system switch logfile;
System altered.
SQL> create restore point FIFTH;
Restore point created.

I then shut the database down, mounted it, and performed a flashback to the first restore point.

SQL> shutdown immediate
Database closed.
Database dismounted.
ORACLE instance shut down.
SQL> startup mount
ORACLE instance started.
Total System Global Area  521936896 bytes
Fixed Size		    2229944 bytes
Variable Size		  499124552 bytes
Database Buffers	   16777216 bytes
Redo Buffers		    3805184 bytes
Database mounted.
SQL> flashback database to restore point FIRST;
Flashback complete.

The first thing we can see in the alert.log is the Flashback Restore phase:

Mon Aug 27 10:23:02 2012
flashback database to restore point FIRST
Flashback Restore Start
Mon Aug 27 10:24:14 2012
Flashback Restore Complete

And the the Flashback Media Recovery:

Flashback Media Recovery Start
Serial Media Recovery started
Flashback mount Marker scn during SCN 2261672
Marker checkpoint scn during mount SCN 2261190
Marker fgda seq 7 bno 6215
Flashback mount unfinished crash recovery 1
Flashback unfinished crash recovery is set during start of  media recovery
Flashback Media Recovery Log /u02/oradata/flash_recovery_area/ORCL/archivelog/2012_08_27/o1_mf_1_728_83pgh7y1_.arc
Flashback Media Recovery Log /u02/oradata/flash_recovery_area/ORCL/archivelog/2012_08_27/o1_mf_1_729_83pgh88q_.arc
Flashback Media Recovery Log /u02/oradata/flash_recovery_area/ORCL/archivelog/2012_08_27/o1_mf_1_730_83pghlws_.arc
Flashback Media Recovery Log /u02/oradata/flash_recovery_area/ORCL/archivelog/2012_08_27/o1_mf_1_731_83pgj516_.arc
Flashback Media Recovery Log /u02/oradata/flash_recovery_area/ORCL/archivelog/2012_08_27/o1_mf_1_732_83pgjc72_.arc
Flashback Media Recovery Log /u02/oradata/flash_recovery_area/ORCL/archivelog/2012_08_27/o1_mf_1_733_83q0gn8l_.arc
Incomplete Recovery applied until change 2261558 time 08/27/2012 10:18:22
Flashback Media Recovery Complete
Completed: flashback database to restore point FIRST

Note that all the archived logs above were generated before the sample table was created, which indicates that the Flashback Restore phase rolled the database back to a point in time well before the FIRST restore point. From my tests, this point in time coincides with the beginning of the flashback retention window.

I then performed a RECOVER DATABASE to the THIRD restore point:

RMAN> recover database to restore point THIRD;
Starting recover at 27-AUG-12
using target database control file instead of recovery catalog
allocated channel: ORA_DISK_1
channel ORA_DISK_1: SID=20 device type=DISK
starting media recovery
archived log for thread 1 with sequence 733 is already on disk as file /u02/oradata/flash_recovery_area/ORCL/archivelog/2012_08_27/o1_mf_1_733_83q0gn8l_.arc
archived log for thread 1 with sequence 734 is already on disk as file /u02/oradata/flash_recovery_area/ORCL/archivelog/2012_08_27/o1_mf_1_734_83q0hyox_.arc
archived log file name=/u02/oradata/flash_recovery_area/ORCL/archivelog/2012_08_27/o1_mf_1_733_83q0gn8l_.arc thread=1 sequence=733
archived log file name=/u02/oradata/flash_recovery_area/ORCL/archivelog/2012_08_27/o1_mf_1_734_83q0hyox_.arc thread=1 sequence=734
media recovery complete, elapsed time: 00:00:00
Finished recover at 27-AUG-12

The result is a simple and straight-forward media recovery, reading from log sequences 733 and 734. We can see more details in the alert.log:

Mon Aug 27 10:25:25 2012
alter database recover datafile list clear
Completed: alter database recover datafile list clear
alter database recover datafile list
 1 , 2 , 3 , 4 , 5 , 6
Completed: alter database recover datafile list
 1 , 2 , 3 , 4 , 5 , 6
alter database recover if needed
 start until change 2261599
Media Recovery Start
Serial Media Recovery started
Flashback mount Marker scn during SCN 2261672
Marker checkpoint scn during mount SCN 2261190
Marker fgda seq 7 bno 6215
Flashback mount unfinished crash recovery 1
Flashback unfinished crash recovery is set during start of  media recovery
ORA-279 signalled during: alter database recover if needed
 start until change 2261599
...
alter database recover logfile '/u02/oradata/flash_recovery_area/ORCL/archivelog/2012_08_27/o1_mf_1_733_83q0gn8l_.arc'
Media Recovery Log /u02/oradata/flash_recovery_area/ORCL/archivelog/2012_08_27/o1_mf_1_733_83q0gn8l_.arc
ORA-279 signalled during: alter database recover logfile '/u02/oradata/flash_recovery_area/ORCL/archivelog/2012_08_27/o1_mf_1_733_83q0gn8l_.arc'...
alter database recover logfile '/u02/oradata/flash_recovery_area/ORCL/archivelog/2012_08_27/o1_mf_1_734_83q0hyox_.arc'
Media Recovery Log /u02/oradata/flash_recovery_area/ORCL/archivelog/2012_08_27/o1_mf_1_734_83q0hyox_.arc
Incomplete Recovery applied until change 2261599 time 08/27/2012 10:19:33
Media Recovery Complete (orcl)
Completed: alter database recover logfile '/u02/oradata/flash_recovery_area/ORCL/archivelog/2012_08_27/o1_mf_1_734_83q0hyox_.arc'

Lastly, I rolled the database forward again using the FLASHBACK DATABASE command to restore point FIFTH:

RMAN> flashback database to restore point FIFTH;
Starting flashback at 27-AUG-12
using channel ORA_DISK_1
starting media recovery
archived log for thread 1 with sequence 728 is already on disk as file /u02/oradata/flash_recovery_area/ORCL/archivelog/2012_08_27/o1_mf_1_728_83pgh7y1_.arc
archived log for thread 1 with sequence 729 is already on disk as file /u02/oradata/flash_recovery_area/ORCL/archivelog/2012_08_27/o1_mf_1_729_83pgh88q_.arc
archived log for thread 1 with sequence 730 is already on disk as file /u02/oradata/flash_recovery_area/ORCL/archivelog/2012_08_27/o1_mf_1_730_83pghlws_.arc
archived log for thread 1 with sequence 731 is already on disk as file /u02/oradata/flash_recovery_area/ORCL/archivelog/2012_08_27/o1_mf_1_731_83pgj516_.arc
archived log for thread 1 with sequence 732 is already on disk as file /u02/oradata/flash_recovery_area/ORCL/archivelog/2012_08_27/o1_mf_1_732_83pgjc72_.arc
archived log for thread 1 with sequence 733 is already on disk as file /u02/oradata/flash_recovery_area/ORCL/archivelog/2012_08_27/o1_mf_1_733_83q0gn8l_.arc
archived log for thread 1 with sequence 734 is already on disk as file /u02/oradata/flash_recovery_area/ORCL/archivelog/2012_08_27/o1_mf_1_734_83q0hyox_.arc
archived log for thread 1 with sequence 735 is already on disk as file /u02/oradata/flash_recovery_area/ORCL/archivelog/2012_08_27/o1_mf_1_735_83q0k1xx_.arc
archived log for thread 1 with sequence 736 is already on disk as file /u02/oradata/flash_recovery_area/ORCL/archivelog/2012_08_27/o1_mf_1_736_83q0m5k8_.arc
archived log for thread 1 with sequence 737 is already on disk as file /u02/oradata/ORCL/orcl/redo02.log
media recovery complete, elapsed time: 00:00:15
Finished flashback at 27-AUG-12

Notice the amount of extra work performed above when compared with that of the RECOVER DATABASE command! The Flashback Restore took the database back to the same point it did in the first flashback command and the Flashback Media Recovery started applying changes from log sequence 728 again. It applied all the logs and, finally, the changes in the current online redo log file (redo02.log). The alert.log shows the following information:

Mon Aug 27 10:25:48 2012
alter database recover datafile list clear
Completed: alter database recover datafile list clear
RMAN flashback database to before scn 2261666 in incarnation 1
Flashback Restore Start
Mon Aug 27 10:26:15 2012
Flashback Restore Complete
Flashback Media Recovery Start
Serial Media Recovery started
Flashback mount Marker scn during SCN 2261672
Marker checkpoint scn during mount SCN 2261190
Marker fgda seq 7 bno 6215
Flashback mount unfinished crash recovery 1
Flashback unfinished crash recovery is set during start of  media recovery
Flashback Media Recovery Log /u02/oradata/flash_recovery_area/ORCL/archivelog/2012_08_27/o1_mf_1_728_83pgh7y1_.arc
Mon Aug 27 10:26:25 2012
Flashback Media Recovery Log /u02/oradata/flash_recovery_area/ORCL/archivelog/2012_08_27/o1_mf_1_729_83pgh88q_.arc
Flashback Media Recovery Log /u02/oradata/flash_recovery_area/ORCL/archivelog/2012_08_27/o1_mf_1_730_83pghlws_.arc
Flashback Media Recovery Log /u02/oradata/flash_recovery_area/ORCL/archivelog/2012_08_27/o1_mf_1_731_83pgj516_.arc
Mon Aug 27 10:26:36 2012
Flashback Media Recovery Log /u02/oradata/flash_recovery_area/ORCL/archivelog/2012_08_27/o1_mf_1_732_83pgjc72_.arc
Flashback Media Recovery Log /u02/oradata/flash_recovery_area/ORCL/archivelog/2012_08_27/o1_mf_1_733_83q0gn8l_.arc
Flashback Media Recovery Log /u02/oradata/flash_recovery_area/ORCL/archivelog/2012_08_27/o1_mf_1_734_83q0hyox_.arc
Recovery of Online Redo Log: Thread 1 Group 3 Seq 735 Reading mem 0
  Mem# 0: /u02/oradata/ORCL/orcl/redo03.log
Recovery of Online Redo Log: Thread 1 Group 1 Seq 736 Reading mem 0
  Mem# 0: /u02/oradata/ORCL/orcl/redo01.log
Recovery of Online Redo Log: Thread 1 Group 2 Seq 737 Reading mem 0
  Mem# 0: /u02/oradata/ORCL/orcl/redo02.log
Incomplete Recovery applied until change 2261666 time 08/27/2012 10:21:37
Flashback Media Recovery Complete
Completed: RMAN flashback database to before scn 2261666 in incarnation 1