Infrastructure at your Service

Oracle Team

An example of ORA-01152: file … was not restored from a sufficiently old backup

By April 30, 2021 Oracle One Comment

By Franck Pachot

.


Oracle Error: 
ORA-01547: warning: RECOVER succeeded but OPEN RESETLOGS would get error below 
ORA-01152: file ... was not restored from a sufficiently old backup 
ORA-01110: data file ...

This error is one of the most misunderstood recovery error. It can happen in different case but I have here a simple example to reproduce it, with some comments and queries to see the state. I run an example to avoid long theory but let’s put the main media recovery concepts in a few words. [Note that even if my idea was to put only a few words… it is longer than expected, so skip to the example if that’s what you were expecting]

Except when you are doing direct-path insert, the database files (datafiles) are written from the buffer cache, by the database writer, asynchronously, without caring about transactions. At any point in time, in a database that is opened, you may have commited changes for which the changed block is not yet written to the datafiles. You may also have changes written to the datafiles which are not commited yet or will be rolled back later. You may also have some part only of an atomic changes. There are points (checkpoint) where the database ensures that what has been changed in memory is written back to the datafiles. Those points are important as they mark the start of the redo log stream that is required to ensure that the changes done in memory can be applied (recovered) to the datafiles in case of database crash. The controlfile keeps track of this but the checkpoint information (time, SCN, redo threads,…) is also written to the datafile headers so that recovery is possible even of the current controlfile is lost, or restored from a backup.

This is for instance failure. But the stream of redo may be used also in case of media recovery where you had to restore a datafile from a previous backup, in order to bring the datafile to the current state. Then the datafile header shows a checkpoint from a previous point in time (before the last checkpoint of the current state) and recovery can be possible because the redo from before the last checkpoint has also been backed up as archived logs. And finally, there’s also the possibility that all datafiles are from past checkpoints, because you want to do Point-In-Time Recovery (PITR) either by restoring all datafiles from a previous backup, and recover up to this PIT only. Or you used flashback database to bring them back, which recovers to this PIT as well. In those cases, you will open to a new incarnation of the database, like a branch in the timeline, and OPEN RESETLOGS to explicitly tell Oracle that you know that your datafile state is different than the current state, as known in the controlfile and the online redo logs (which will then be discarded).

However, even if you have this possibility, with a datafile PIT state that does not match the controlfile one, there are some conditions that must be met in order to open the database without inconsistencies. Basically, they must be consistent among themselves. Because table data are in some datafiles, indexes may be in others, metadata in another one, undo vertors elswhere, and the same for foreign key parent table… So even if all recovery is correct (no changes lost thanks to redo log recovery) the database may refuse an OPEN RESETLOGS. And that’s basically what ORA-01152 tells you: your recovery is ok for each file, but the point you recovered to is not globally the same consistent state.

So, there are two major pieces of information that are checked by Oracle when opening the database. One is about the consistency of each datafiles and the other is about the consistency of the database. When the database is opened, there may be some changes that are from after the checkpoint recorded in the datafile header, because dbwriter continuously does its job. This is known as the datafile being “fuzzy”. Only when the database is closed, the fuzzy bit is cleared to say that all blocks of the datafiles are consistent with the checkpoint time. That’s for each datafile consistency. And in order to leave a clean state, closing the database also does a last checkpoint so that all datafiles are consistent. This can be opened without the need to apply some redo log, given that you want to get the database at the same point in time than it was closed. But once closed, you can do things that Oracle doesn’t know. Like restoring the files from a previous backup, even from a hot backup where the files were fuzzy. So, in any case, when Oracle opens the database it checks the datafile headers, as if it were not cleanly closed.


SQL> host mkdir -p /u90/{close,open}/{before,after}

I create directories to put a backup of a datafile. I’ll backup the datafile in the open or mount state (to have fuzzy and non fuzzy backups). And from two points in time (‘before’ and ‘after’ the state I want to open resetlogs)


SQL> select open_mode,current_scn,checkpoint_change#,archive_change#,controlfile_change# from v$database;

    OPEN_MODE    CURRENT_SCN    CHECKPOINT_CHANGE#    ARCHIVE_CHANGE#    CONTROLFILE_CHANGE#
_____________ ______________ _____________________ __________________ ______________________
READ WRITE           1692588               1692038            1691878                1692586

SQL> select * from (select file#,name,substr(status,1,3) sta,error err,recover rec,fuzzy fuz,checkpoint_time checkpoint from v$datafile_header)
     natural join (select hxfil file#, fhsta, fhscn, fhrba_seq, fhafs from x$kcvfhall);

   FILE#                                             NAME    STA    ERR    REC    FUZ              CHECKPOINT    FHSTA      FHSCN    FHRBA_SEQ    FHAFS
________ ________________________________________________ ______ ______ ______ ______ _______________________ ________ __________ ____________ ________
       1 /u02/oradata/CDB19/system01CDB19.dbf             ONL           NO     YES    30-apr-2021 10:38:02        8196 1692038             183 0
       2 /u02/oradata/CDB19/pdbseed/system01CDB19.dbf     ONL                  NO     05-aug-2019 17:03:21        8192 1276435              17 0
       3 /u02/oradata/CDB19/sysaux01CDB19.dbf             ONL           NO     YES    30-apr-2021 10:38:02           4 1692038             183 0
       4 /u02/oradata/CDB19/pdbseed/sysaux01CDB19.dbf     ONL                  NO     05-aug-2019 17:03:21           0 1276435              17 0
       5 /u02/oradata/CDB19/undotbs01CDB19.dbf            ONL           NO     YES    30-apr-2021 10:38:02           4 1692038             183 0
       6 /u02/oradata/CDB19/pdbseed/undotbs01CDB19.dbf    ONL                  NO     05-aug-2019 17:03:21           0 1276435              17 0
       7 /u02/oradata/CDB19/users01CDB19.dbf              ONL           NO     YES    30-apr-2021 10:38:02           4 1692038             183 0
       8 /u02/oradata/CDB19/PDB/system01CDB19.dbf         ONL           NO     YES    30-apr-2021 10:38:02        8196 1692038             183 0
       9 /u02/oradata/CDB19/PDB/sysaux01CDB19.dbf         ONL           NO     YES    30-apr-2021 10:38:02           4 1692038             183 0
      10 /u02/oradata/CDB19/PDB/undotbs01CDB19.dbf        ONL           NO     YES    30-apr-2021 10:38:02           4 1692038             183 0
      11 /u02/oradata/CDB19/PDB/users01.dbf               ONL           NO     YES    30-apr-2021 10:38:02           4 1692038             183 0

11 rows selected.

I’ll run those queries each time. They show the checkpoint SCN of my database, from the controlfile, and from my datafile headers. The FUZZY=YES column tells me that the database is opened, which means that there are changes in the datafiles that were written after the checkpoint. This is also visible by the flag 4 in FHSTA (or 8196 because 8192 is another flag for the SYSTEM datafiles). There are files that are not fuzzy even if the database is opened, because the tablespaces are in read-only, PDB$SEED in this example. You can see that their checkpoint time is from a long time ago because they havent been opened read-write since them. As they are not fuzzy, and checkpointed at the same SCN, they are consistent. And as they are read-only since then Oracle knows that they don’t need any recovery. I think we have a clue about this with the RECOVER column being null.


SQL> alter database begin backup;

Database altered.

SQL> host cp /u02/oradata/CDB19/users01CDB19.dbf /u90/open/before

SQL> alter database end backup;

Database altered.

I’ve taken a hot backup of this datafile. The backup mode ensures that recovery will be possible, but the file is still online, and fuzzy, with db writer writing to it. So the header stilll shows it fuzzy and with the last checkpoint SCN.


SQL> shutdown immediate;
Database closed.
Database dismounted.
ORACLE instance shut down.

SQL> startup mount
ORACLE instance started.

Total System Global Area   2147482744 bytes
Fixed Size                    9137272 bytes
Variable Size               520093696 bytes
Database Buffers           1610612736 bytes
Redo Buffers                  7639040 bytes
Database mounted.

I’ve closed my database cleanly and started it in mount, which means not opened.


SQL> select open_mode,current_scn,checkpoint_change#,archive_change#,controlfile_change# from v$database;

   OPEN_MODE    CURRENT_SCN    CHECKPOINT_CHANGE#    ARCHIVE_CHANGE#    CONTROLFILE_CHANGE#
____________ ______________ _____________________ __________________ ______________________
MOUNTED                   0               1692886            1692000                1692860

SQL> select * from (select file#,name,substr(status,1,3) sta,error err,recover rec,fuzzy fuz,checkpoint_time checkpoint from v$datafile_header)
          natural join (select hxfil file#, fhsta, fhscn, fhrba_seq, fhafs from x$kcvfhall);

   FILE#                                             NAME    STA    ERR    REC    FUZ             CHECKPOINT    FHSTA      FHSCN    FHRBA_SEQ    FHAFS
________ ________________________________________________ ______ ______ ______ ______ ______________________ ________ __________ ____________ ________
       1 /u02/oradata/CDB19/system01CDB19.dbf             ONL           NO     NO     2021-04-30 10:56:41        8192 1692886             183 0
       2 /u02/oradata/CDB19/pdbseed/system01CDB19.dbf     ONL                  NO     2019-08-05 17:03:21        8192 1276435              17 0
       3 /u02/oradata/CDB19/sysaux01CDB19.dbf             ONL           NO     NO     2021-04-30 10:56:41           0 1692886             183 0
       4 /u02/oradata/CDB19/pdbseed/sysaux01CDB19.dbf     ONL                  NO     2019-08-05 17:03:21           0 1276435              17 0
       5 /u02/oradata/CDB19/undotbs01CDB19.dbf            ONL           NO     NO     2021-04-30 10:56:41           0 1692886             183 0
       6 /u02/oradata/CDB19/pdbseed/undotbs01CDB19.dbf    ONL                  NO     2019-08-05 17:03:21           0 1276435              17 0
       7 /u02/oradata/CDB19/users01CDB19.dbf              ONL           NO     NO     2021-04-30 10:56:41           0 1692886             183 0
       8 /u02/oradata/CDB19/PDB/system01CDB19.dbf         ONL                  NO     2021-04-30 10:56:39        8192 1692776             183 0
       9 /u02/oradata/CDB19/PDB/sysaux01CDB19.dbf         ONL                  NO     2021-04-30 10:56:39           0 1692776             183 0
      10 /u02/oradata/CDB19/PDB/undotbs01CDB19.dbf        ONL                  NO     2021-04-30 10:56:39           0 1692776             183 0
      11 /u02/oradata/CDB19/PDB/users01.dbf               ONL                  NO     2021-04-30 10:56:39           0 1692776             183 0

11 rows selected.

After a clean shutdown, no files are fuzzy and all files where checkpointed at the same time: SCN 1692886 that we see in v$datafile and v$datafile_header. All consistent. You can see that the PDB datafiles have a SCN a little bit earlier but this is because the PDB are closed before the database is. Exactly the same as the read-only PDB$SEED. Then checkpoint is consistent for the container but earlier than the database and the RECOVER column is null.


SQL> host cp /u02/oradata/CDB19/users01CDB19.dbf /u90/close/before

I’ve taken another backup of my datafile here, now in a non fuzzy state (like a cold backup)


SQL> create restore point now guarantee flashback database;
Restore point NOW created.

I’m taking a snapshot of my database here as I’ll come back to this point. This PIT that I call ‘now’ is the where I’ll try to restore the datafile from backups from before (what i just did) or from after (what i’m going to do before reverting back to this snapshot)


SQL> alter database open;
Database altered.

SQL> select open_mode,current_scn,checkpoint_change#,archive_change#,controlfile_change# from v$database;

    OPEN_MODE    CURRENT_SCN    CHECKPOINT_CHANGE#    ARCHIVE_CHANGE#    CONTROLFILE_CHANGE#
_____________ ______________ _____________________ __________________ ______________________
READ WRITE           1693832               1692889            1692000                1692999

SQL> select * from (select file#,name,substr(status,1,3) sta,error err,recover rec,fuzzy fuz,checkpoint_time checkpoint from v$datafile_header)
               natural join (select hxfil file#, fhsta, fhscn, fhrba_seq, fhafs from x$kcvfhall);

   FILE#                                             NAME    STA    ERR    REC    FUZ             CHECKPOINT    FHSTA      FHSCN    FHRBA_SEQ    FHAFS
________ ________________________________________________ ______ ______ ______ ______ ______________________ ________ __________ ____________ ________
       1 /u02/oradata/CDB19/system01CDB19.dbf             ONL           NO     YES    2021-04-30 11:03:00        8196 1692889             183 0
       2 /u02/oradata/CDB19/pdbseed/system01CDB19.dbf     ONL                  NO     2019-08-05 17:03:21        8192 1276435              17 0
       3 /u02/oradata/CDB19/sysaux01CDB19.dbf             ONL           NO     YES    2021-04-30 11:03:00           4 1692889             183 0
       4 /u02/oradata/CDB19/pdbseed/sysaux01CDB19.dbf     ONL                  NO     2019-08-05 17:03:21           0 1276435              17 0
       5 /u02/oradata/CDB19/undotbs01CDB19.dbf            ONL           NO     YES    2021-04-30 11:03:00           4 1692889             183 0
       6 /u02/oradata/CDB19/pdbseed/undotbs01CDB19.dbf    ONL                  NO     2019-08-05 17:03:21           0 1276435              17 0
       7 /u02/oradata/CDB19/users01CDB19.dbf              ONL           NO     YES    2021-04-30 11:03:00           4 1692889             183 0
       8 /u02/oradata/CDB19/PDB/system01CDB19.dbf         ONL                  NO     2021-04-30 10:56:39        8192 1692776             183 0
       9 /u02/oradata/CDB19/PDB/sysaux01CDB19.dbf         ONL                  NO     2021-04-30 10:56:39           0 1692776             183 0
      10 /u02/oradata/CDB19/PDB/undotbs01CDB19.dbf        ONL                  NO     2021-04-30 10:56:39           0 1692776             183 0
      11 /u02/oradata/CDB19/PDB/users01.dbf               ONL                  NO     2021-04-30 10:56:39           0 1692776             183 0

11 rows selected.

SQL> alter system checkpoint;

System CHECKPOINT altered.

SQL> alter database begin backup;

Database altered.

SQL> host cp /u02/oradata/CDB19/users01CDB19.dbf /u90/open/after

SQL> alter database end backup;

Same as I did before, a hot backup of my datafile, but from a later point in time.


Database altered.

SQL> shutdown immediate;
Database closed.
Database dismounted.
ORACLE instance shut down.

SQL> startup mount
ORACLE instance started.

Total System Global Area   2147482744 bytes
Fixed Size                    9137272 bytes
Variable Size               520093696 bytes
Database Buffers           1610612736 bytes
Redo Buffers                  7639040 bytes
Database mounted.

SQL> select open_mode,current_scn,checkpoint_change#,archive_change#,controlfile_change# from v$database;

   OPEN_MODE    CURRENT_SCN    CHECKPOINT_CHANGE#    ARCHIVE_CHANGE#    CONTROLFILE_CHANGE#
____________ ______________ _____________________ __________________ ______________________
MOUNTED                   0               1694252            1692000                1693891


SQL> select * from (select file#,name,substr(status,1,3) sta,error err,recover rec,fuzzy fuz,checkpoint_time checkpoint from v$datafile_header)
     natural join (select hxfil file#, fhsta, fhscn, fhrba_seq, fhafs from x$kcvfhall);

   FILE#                                             NAME    STA    ERR    REC    FUZ             CHECKPOINT    FHSTA      FHSCN    FHRBA_SEQ    FHAFS
________ ________________________________________________ ______ ______ ______ ______ ______________________ ________ __________ ____________ ________
       1 /u02/oradata/CDB19/system01CDB19.dbf             ONL           NO     NO     2021-04-30 11:05:43        8192 1694252             183 0
       2 /u02/oradata/CDB19/pdbseed/system01CDB19.dbf     ONL                  NO     2019-08-05 17:03:21        8192 1276435              17 0
       3 /u02/oradata/CDB19/sysaux01CDB19.dbf             ONL           NO     NO     2021-04-30 11:05:43           0 1694252             183 0
       4 /u02/oradata/CDB19/pdbseed/sysaux01CDB19.dbf     ONL                  NO     2019-08-05 17:03:21           0 1276435              17 0
       5 /u02/oradata/CDB19/undotbs01CDB19.dbf            ONL           NO     NO     2021-04-30 11:05:43           0 1694252             183 0
       6 /u02/oradata/CDB19/pdbseed/undotbs01CDB19.dbf    ONL                  NO     2019-08-05 17:03:21           0 1276435              17 0
       7 /u02/oradata/CDB19/users01CDB19.dbf              ONL           NO     NO     2021-04-30 11:05:43           0 1694252             183 0
       8 /u02/oradata/CDB19/PDB/system01CDB19.dbf         ONL                  NO     2021-04-30 10:56:39        8192 1692776             183 0
       9 /u02/oradata/CDB19/PDB/sysaux01CDB19.dbf         ONL                  NO     2021-04-30 10:56:39           0 1692776             183 0
      10 /u02/oradata/CDB19/PDB/undotbs01CDB19.dbf        ONL                  NO     2021-04-30 10:56:39           0 1692776             183 0
      11 /u02/oradata/CDB19/PDB/users01.dbf               ONL                  NO     2021-04-30 10:56:39           0 1692776             183 0

SQL> host cp /u02/oradata/CDB19/users01CDB19.dbf /u90/close/after

And finally a cold backup from a later point in time.


SQL> host ls -l /u90/{close,open}/{before,after}
/u90/close/after:
total 5140
-rw-r-----. 1 oracle oinstall 5251072 Apr 30 11:07 users01CDB19.dbf

/u90/close/before:
total 5140
-rw-r-----. 1 oracle oinstall 5251072 Apr 30 11:00 users01CDB19.dbf

/u90/open/after:
total 5140
-rw-r-----. 1 oracle oinstall 5251072 Apr 30 11:05 users01CDB19.dbf

/u90/open/before:
total 5140
-rw-r-----. 1 oracle oinstall 5251072 Apr 30 10:55 users01CDB19.dbf

I have 4 backups, from before and after, and in a clean or fuzzy state.


SQL> flashback database to restore point now;

Flashback succeeded.

Now back to my snapshot so that my current state is after the ‘before’ backup and before the ‘after’ backup. Sorry for this bad description of it, time travel is never easy to explain.


SQL> select open_mode,current_scn,checkpoint_change#,archive_change#,controlfile_change# from v$database;

   OPEN_MODE    CURRENT_SCN    CHECKPOINT_CHANGE#    ARCHIVE_CHANGE#    CONTROLFILE_CHANGE#
____________ ______________ _____________________ __________________ ______________________
MOUNTED                   0               1694252            1692000                1692886


SQL> select * from (select file#,name,substr(status,1,3) sta,error err,recover rec,fuzzy fuz,checkpoint_time checkpoint from v$datafile_header)
     natural join (select hxfil file#, fhsta, fhscn, fhrba_seq, fhafs from x$kcvfhall);

   FILE#                                             NAME    STA    ERR    REC    FUZ             CHECKPOINT    FHSTA      FHSCN    FHRBA_SEQ    FHAFS
________ ________________________________________________ ______ ______ ______ ______ ______________________ ________ __________ ____________ ________
       1 /u02/oradata/CDB19/system01CDB19.dbf             ONL                  NO     2021-04-30 10:56:41        8192 1692886             183 0
       2 /u02/oradata/CDB19/pdbseed/system01CDB19.dbf     ONL                  NO     2019-08-05 17:03:21        8192 1276435              17 0
       3 /u02/oradata/CDB19/sysaux01CDB19.dbf             ONL                  NO     2021-04-30 10:56:41           0 1692886             183 0
       4 /u02/oradata/CDB19/pdbseed/sysaux01CDB19.dbf     ONL                  NO     2019-08-05 17:03:21           0 1276435              17 0
       5 /u02/oradata/CDB19/undotbs01CDB19.dbf            ONL                  NO     2021-04-30 10:56:41           0 1692886             183 0
       6 /u02/oradata/CDB19/pdbseed/undotbs01CDB19.dbf    ONL                  NO     2019-08-05 17:03:21           0 1276435              17 0
       7 /u02/oradata/CDB19/users01CDB19.dbf              ONL                  NO     2021-04-30 10:56:41           0 1692886             183 0
       8 /u02/oradata/CDB19/PDB/system01CDB19.dbf         ONL                  NO     2021-04-30 10:56:39        8192 1692776             183 0
       9 /u02/oradata/CDB19/PDB/sysaux01CDB19.dbf         ONL                  NO     2021-04-30 10:56:39           0 1692776             183 0
      10 /u02/oradata/CDB19/PDB/undotbs01CDB19.dbf        ONL                  NO     2021-04-30 10:56:39           0 1692776             183 0
      11 /u02/oradata/CDB19/PDB/users01.dbf               ONL                  NO     2021-04-30 10:56:39           0 1692776             183 0
11 rows selected.

So, here we are. In closed (mount) state. No files are opened, No files are fuzzy. The checkpoint time is consistent – we will check only the CDB$ROOT now as we know the other containers where checkpointed earlier when closed. So CDB$ROOT checkpoint is at 10:56:41, SCN 1692886, which matches the controlfile SCN. I can OPEN RESETLOGS this database without any recovery but that’s not what I want to show.


SQL> host cp /u90/open/before/users01CDB19.dbf /u02/oradata/CDB19/users01CDB19.dbf

I restored the datafile from the previous hot backup (older than my current state, and fuzzy)


SQL> select * from (select file#,name,substr(status,1,3) sta,error err,recover rec,fuzzy fuz,checkpoint_time checkpoint from v$datafile_header)
  2* natural join (select hxfil file#, fhsta, fhscn, fhrba_seq, fhafs from x$kcvfhall);

   FILE#                                             NAME    STA    ERR    REC    FUZ             CHECKPOINT    FHSTA      FHSCN    FHRBA_SEQ    FHAFS
________ ________________________________________________ ______ ______ ______ ______ ______________________ ________ __________ ____________ ________
       1 /u02/oradata/CDB19/system01CDB19.dbf             ONL                  NO     2021-04-30 10:56:41        8192 1692886             183 0
       2 /u02/oradata/CDB19/pdbseed/system01CDB19.dbf     ONL                  NO     2019-08-05 17:03:21        8192 1276435              17 0
       3 /u02/oradata/CDB19/sysaux01CDB19.dbf             ONL                  NO     2021-04-30 10:56:41           0 1692886             183 0
       4 /u02/oradata/CDB19/pdbseed/sysaux01CDB19.dbf     ONL                  NO     2019-08-05 17:03:21           0 1276435              17 0
       5 /u02/oradata/CDB19/undotbs01CDB19.dbf            ONL                  NO     2021-04-30 10:56:41           0 1692886             183 0
       6 /u02/oradata/CDB19/pdbseed/undotbs01CDB19.dbf    ONL                  NO     2019-08-05 17:03:21           0 1276435              17 0
       7 /u02/oradata/CDB19/users01CDB19.dbf              ONL                  YES    2021-04-30 10:53:23           1 1692602             183 0
       8 /u02/oradata/CDB19/PDB/system01CDB19.dbf         ONL                  NO     2021-04-30 11:11:00        8192 1692776               1 0
       9 /u02/oradata/CDB19/PDB/sysaux01CDB19.dbf         ONL                  NO     2021-04-30 11:11:00           0 1692776               1 0
      10 /u02/oradata/CDB19/PDB/undotbs01CDB19.dbf        ONL                  NO     2021-04-30 11:11:00           0 1692776               1 0
      11 /u02/oradata/CDB19/PDB/users01.dbf               ONL                  NO     2021-04-30 11:11:00           0 1692776               1 0

11 rows selected.

The file header shows the fuzzy state (FUZZY=Y) and this means that Oracle needs to apply some redo log, starting from the checkpoint SCN 1692602 and until it brings it to a consistent state, at least after the END BACKUP, to the end of fuzziness.


SQL> alter database open resetlogs;

Error starting at line : 1 in command -
alter database open resetlogs
Error report -
ORA-01195: online backup of file 7 needs more recovery to be consistent
ORA-01110: data file 7: '/u02/oradata/CDB19/users01CDB19.dbf'
01195. 00000 -  "online backup of file %s needs more recovery to be consistent"
*Cause:    An incomplete recovery session was started, but an insufficient
           number of logs were applied to make the file consistent. The
           reported file is an online backup which must be recovered to the
           time the backup ended.
*Action:   Either apply more logs until the file is consistent or
           restore the database files from an older backup and repeat recovery.
SQL>

I’ll not do this recovery. I’m just showing the error message. This is ORA-01195 that tells you you need more recovery to clear the fuzziness.


SQL> host cp /u90/close/before/users01CDB19.dbf /u02/oradata/CDB19/users01CDB19.dbf

I’ve restored from the cold backup here. So no fuzzy flag in the header.


SQL> alter database open resetlogs;

Database altered.

SQL> select * from (select file#,name,substr(status,1,3) sta,error err,recover rec,fuzzy fuz,checkpoint_time checkpoint from v$datafile_header)
  2* natural join (select hxfil file#, fhsta, fhscn, fhrba_seq, fhafs from x$kcvfhall);

   FILE#                                             NAME    STA    ERR    REC    FUZ             CHECKPOINT    FHSTA      FHSCN    FHRBA_SEQ    FHAFS
________ ________________________________________________ ______ ______ ______ ______ ______________________ ________ __________ ____________ ________
       1 /u02/oradata/CDB19/system01CDB19.dbf             ONL           NO     YES    2021-04-30 11:48:42        8196 1692890               1 0
       2 /u02/oradata/CDB19/pdbseed/system01CDB19.dbf     ONL                  NO     2019-08-05 17:03:21        8192 1276435              17 0
       3 /u02/oradata/CDB19/sysaux01CDB19.dbf             ONL           NO     YES    2021-04-30 11:48:42           4 1692890               1 0
       4 /u02/oradata/CDB19/pdbseed/sysaux01CDB19.dbf     ONL                  NO     2019-08-05 17:03:21           0 1276435              17 0
       5 /u02/oradata/CDB19/undotbs01CDB19.dbf            ONL           NO     YES    2021-04-30 11:48:42           4 1692890               1 0
       6 /u02/oradata/CDB19/pdbseed/undotbs01CDB19.dbf    ONL                  NO     2019-08-05 17:03:21           0 1276435              17 0
       7 /u02/oradata/CDB19/users01CDB19.dbf              ONL           NO     YES    2021-04-30 11:48:42           4 1692890               1 0
       8 /u02/oradata/CDB19/PDB/system01CDB19.dbf         ONL                  NO     2021-04-30 11:48:45        8192 1693089               1 0
       9 /u02/oradata/CDB19/PDB/sysaux01CDB19.dbf         ONL                  NO     2021-04-30 11:48:45           0 1693089               1 0
      10 /u02/oradata/CDB19/PDB/undotbs01CDB19.dbf        ONL                  NO     2021-04-30 11:48:45           0 1693089               1 0
      11 /u02/oradata/CDB19/PDB/users01.dbf               ONL                  NO     2021-04-30 11:48:45           0 1693089               1 0

11 rows selected.

SQL> select open_mode,current_scn,checkpoint_change#,archive_change#,controlfile_change# from v$database;

    OPEN_MODE    CURRENT_SCN    CHECKPOINT_CHANGE#    ARCHIVE_CHANGE#    CONTROLFILE_CHANGE#
_____________ ______________ _____________________ __________________ ______________________
READ WRITE           1694039               1692890                  0                1693104

From this cold backup, I was able to OPEN RESETLOGS. Because this cold backup was taken when the database was closed, so all are consistent.

This was to show the ORA-01195 meaning: a datafile needs to be recovered to be consistent by itself.

Now we will see the consistency with the other datafiles by restoring a backup from the future.


SQL> shutdown immediate;
Database closed.
Database dismounted.
ORACLE instance shut down.
SQL> startup mount
ORACLE instance started.

Total System Global Area   2147482744 bytes
Fixed Size                    9137272 bytes
Variable Size               520093696 bytes
Database Buffers           1610612736 bytes
Redo Buffers                  7639040 bytes
Database mounted.
SQL> flashback database to restore point now;

Flashback succeeded.

SQL> select open_mode,current_scn,checkpoint_change#,archive_change#,controlfile_change# from v$database;

   OPEN_MODE    CURRENT_SCN    CHECKPOINT_CHANGE#    ARCHIVE_CHANGE#    CONTROLFILE_CHANGE#
____________ ______________ _____________________ __________________ ______________________
MOUNTED                   0               1694381                  0                1692886

SQL> select * from (select file#,name,substr(status,1,3) sta,error err,recover rec,fuzzy fuz,checkpoint_time checkpoint from v$datafile_header)
     natural join (select hxfil file#, fhsta, fhscn, fhrba_seq, fhafs from x$kcvfhall);

   FILE#                                             NAME    STA    ERR    REC    FUZ             CHECKPOINT    FHSTA      FHSCN    FHRBA_SEQ    FHAFS
________ ________________________________________________ ______ ______ ______ ______ ______________________ ________ __________ ____________ ________
       1 /u02/oradata/CDB19/system01CDB19.dbf             ONL                  NO     2021-04-30 10:56:41        8192 1692886             183 0
       2 /u02/oradata/CDB19/pdbseed/system01CDB19.dbf     ONL                  NO     2019-08-05 17:03:21        8192 1276435              17 0
       3 /u02/oradata/CDB19/sysaux01CDB19.dbf             ONL                  NO     2021-04-30 10:56:41           0 1692886             183 0
       4 /u02/oradata/CDB19/pdbseed/sysaux01CDB19.dbf     ONL                  NO     2019-08-05 17:03:21           0 1276435              17 0
       5 /u02/oradata/CDB19/undotbs01CDB19.dbf            ONL                  NO     2021-04-30 10:56:41           0 1692886             183 0
       6 /u02/oradata/CDB19/pdbseed/undotbs01CDB19.dbf    ONL                  NO     2019-08-05 17:03:21           0 1276435              17 0
       7 /u02/oradata/CDB19/users01CDB19.dbf              ONL                  NO     2021-04-30 10:56:41           0 1692886             183 0
       8 /u02/oradata/CDB19/PDB/system01CDB19.dbf         ONL                  NO     2021-04-30 11:48:35        8192 1692776               1 0
       9 /u02/oradata/CDB19/PDB/sysaux01CDB19.dbf         ONL                  NO     2021-04-30 11:48:35           0 1692776               1 0
      10 /u02/oradata/CDB19/PDB/undotbs01CDB19.dbf        ONL                  NO     2021-04-30 11:48:35           0 1692776               1 0
      11 /u02/oradata/CDB19/PDB/users01.dbf               ONL                  NO     2021-04-30 11:48:35           0 1692776               1 0

11 rows selected.

as my OPEN RESETLOGS was sucessfull, I flashback database again to go to the same point in time for my experiment.


SQL> host cp /u90/close/after/users01CDB19.dbf /u02/oradata/CDB19/users01CDB19.dbf

I’ve restored the cold backup (not fuzzy) but from a checkpoint that happened after my current state.


SQL> select * from (select file#,name,substr(status,1,3) sta,error err,recover rec,fuzzy fuz,checkpoint_time checkpoint from v$datafile_header)
     natural join (select hxfil file#, fhsta, fhscn, fhrba_seq, fhafs from x$kcvfhall);

   FILE#                                             NAME    STA    ERR    REC    FUZ             CHECKPOINT    FHSTA      FHSCN    FHRBA_SEQ    FHAFS
________ ________________________________________________ ______ ______ ______ ______ ______________________ ________ __________ ____________ ________
       1 /u02/oradata/CDB19/system01CDB19.dbf             ONL                  NO     2021-04-30 10:56:41        8192 1692886             183 0
       2 /u02/oradata/CDB19/pdbseed/system01CDB19.dbf     ONL                  NO     2019-08-05 17:03:21        8192 1276435              17 0
       3 /u02/oradata/CDB19/sysaux01CDB19.dbf             ONL                  NO     2021-04-30 10:56:41           0 1692886             183 0
       4 /u02/oradata/CDB19/pdbseed/sysaux01CDB19.dbf     ONL                  NO     2019-08-05 17:03:21           0 1276435              17 0
       5 /u02/oradata/CDB19/undotbs01CDB19.dbf            ONL                  NO     2021-04-30 10:56:41           0 1692886             183 0
       6 /u02/oradata/CDB19/pdbseed/undotbs01CDB19.dbf    ONL                  NO     2019-08-05 17:03:21           0 1276435              17 0
       7 /u02/oradata/CDB19/users01CDB19.dbf              ONL                  NO     2021-04-30 11:05:43           0 1694252             183 0
       8 /u02/oradata/CDB19/PDB/system01CDB19.dbf         ONL                  NO     2021-04-30 11:48:35        8192 1692776               1 0
       9 /u02/oradata/CDB19/PDB/sysaux01CDB19.dbf         ONL                  NO     2021-04-30 11:48:35           0 1692776               1 0
      10 /u02/oradata/CDB19/PDB/undotbs01CDB19.dbf        ONL                  NO     2021-04-30 11:48:35           0 1692776               1 0
      11 /u02/oradata/CDB19/PDB/users01.dbf               ONL                  NO     2021-04-30 11:48:35           0 1692776               1 0

11 rows selected.

SQL> select open_mode,current_scn,checkpoint_change#,archive_change#,controlfile_change# from v$database;

   OPEN_MODE    CURRENT_SCN    CHECKPOINT_CHANGE#    ARCHIVE_CHANGE#    CONTROLFILE_CHANGE#
____________ ______________ _____________________ __________________ ______________________
MOUNTED                   0               1694381                  0                1692886

You can see the datafile is not fuzzy but with a checkpoint at 11:05:43, SCN 1694252, where all other datafiles, for this container, and the controlfile, are at 10:56:41, SCN 1692886. My file is from a state in the future of the other ones.


SQL> alter database open resetlogs;

Error starting at line : 1 in command -
alter database open resetlogs
Error report -
ORA-01152: file 7 was not restored from a sufficiently old backup
ORA-01110: data file 7: '/u02/oradata/CDB19/users01CDB19.dbf'
01152. 00000 -  "file %s was not restored from a sufficiently old backup "
*Cause:    An incomplete recovery session was started, but an insufficient
           number of logs were applied to make the database consistent. This
           file is still in the future of the last log applied. The most
           likely cause of this error is forgetting to restore the file
           from a backup before doing incomplete recovery.
*Action:   Either apply more logs until the database is consistent or
           restore the database file from an older backup and repeat recovery.

Here is ORA-01152 and the message may be misleading because there can be several reasons. Maybe the problem is the file mentioned, because you restored it from a backup that is too recent when compared to the others and to the point in time you want to open resetlogs. Or maybe it was not restored at all and it is the current datafile that remains there because you forgot to restore one file. Or maybe you want to go to a further point in time by recovering the other datafile up to the same PIT as this one.

I’ll not go further here, this blog post is already too long. Of course, I’ll get the same error if I restore the fuzzy backup from the future. When you encounter this error you may think about the Point In Time you want to recover to. Either you have the right PIT and then you need to restore a backup of this datafile from before this point in time. Or maybe you want to recover to a further point in time to reach the state of this datafile. The error message supposes you have recovered to the right point in time but didn’t restore the right file.

I tried to summarize this situation in a tweet:


One Comment

  • Grzegorz Gorysz says:

    Thank You for the blog post, I think I had similar error on standby after restoring corrupted datafile with rman from service but standby ‘fixed’ by itself.
    Regards
    Greg

Leave a Reply

This site uses Akismet to reduce spam. Learn how your comment data is processed.

Oracle Team
Oracle Team