Understanding RESETLOGS

Whenever we do an Incomplete Recovery (recovery until CANCEL or until a specific SCN/CHANGE#, SEQUENCE# or TIME), we have to OPEN the database with a RESETLOGS.

RESETLOGS_TIME has to be indicated by Oracle if we were to query the database later. This is the time when the RESETLOGS was issued. RESETLOGS_CHANGE# is the SCN for the database at the issuance of the command. Oracle also provides information of the RESETLOGS_ID for each "incarnation". A RESETLOGS creates a new "incarnation" of the database.

Thus, my database has this information :

SQL> select sysdate from dual;

SYSDATE
---------
29-JAN-12

SQL> select resetlogs_time from v$database;

RESETLOGS
---------
01-JAN-12

SQL> select incarnation#, resetlogs_change#, resetlogs_time, resetlogs_id                            
  2  from v$database_incarnation
  3  order by 1;

INCARNATION# RESETLOGS_CHANGE# RESETLOGS RESETLOGS_ID
------------ ----------------- --------- ------------
           1                 1 13-AUG-09    694825248
           2            754488 30-OCT-09    701609923
           3           4955792 01-JAN-12    771419578
           4           4957614 01-JAN-12    771421939

SQL> 

As of today, 29-Jan, we can see that the database has undergone 4 RESETLOGS, the latest having been on 01-JAN-12 (in fact, there were two RESETLOGS that date). Why does this query report duplicate entries for the same SEQUENCE# ?

SQL> l
  1  select sequence#, trunc(first_time)
  2  from v$archived_log
  3  where first_time > to_date('31-DEC-11','DD-MON-RR')
  4* order by 1
SQL> /

 SEQUENCE# TRUNC(FIR
---------- ---------
         1 01-JAN-12
         1 01-JAN-12
         1 01-JAN-12
         1 01-JAN-12
         1 01-JAN-12
         2 01-JAN-12
         2 01-JAN-12
         2 14-JAN-12
         2 01-JAN-12
         2 01-JAN-12
         3 01-JAN-12
         3 01-JAN-12
         3 15-JAN-12
         3 01-JAN-12
         4 15-JAN-12
         5 15-JAN-12
       180 01-JAN-12
       180 01-JAN-12
       180 01-JAN-12
       181 01-JAN-12
       181 01-JAN-12
       181 01-JAN-12
       182 01-JAN-12
       182 01-JAN-12

24 rows selected.

SQL> 

It does seem very confusing to have SEQUENCE#1 to SEQUENCE#3 report 5 entries each. And why is there a gap between SEQUENCE#5 and SEQUENCE#180 ?   Can we dig deeper ?

I can collect more information thus :

SQL> select resetlogs_id, sequence#, trunc(first_time)
  2  from v$archived_log
  3  order by 1,2
  4  /

RESETLOGS_ID  SEQUENCE# TRUNC(FIR
------------ ---------- ---------
   701609923        179 26-DEC-11
   701609923        180 01-JAN-12
   701609923        180 01-JAN-12
   701609923        180 01-JAN-12
   701609923        181 01-JAN-12
   701609923        181 01-JAN-12
   701609923        181 01-JAN-12
   701609923        182 01-JAN-12
   701609923        182 01-JAN-12
   771419578          1 01-JAN-12
   771419578          1 01-JAN-12
   771419578          1 01-JAN-12
   771419578          1 01-JAN-12
   771419578          2 01-JAN-12
   771419578          2 01-JAN-12
   771419578          2 01-JAN-12
   771419578          2 01-JAN-12
   771419578          3 01-JAN-12
   771419578          3 01-JAN-12
   771419578          3 01-JAN-12
   771421939          1 01-JAN-12
   771421939          2 14-JAN-12
   771421939          3 15-JAN-12
   771421939          4 15-JAN-12
   771421939          5 15-JAN-12

25 rows selected.

SQL> 

Now, I can see that the SEQUENCE# 179 to 182 are for 26-DEC-11 to 01-JAN-12 for INCARNATION#2 which existed from 30-OCT-09 to 01-JAN-12 (this information is retrieved from V$DATABASE_INCARNATION from the earlier query). Yet, there are repeated entries from the same SEQUENCE# (180 and 181 have three entries each while 182 has two entries) !   Was each log file archived more than once ?  Similarly, in INCARNATION#3 I have three entries for each of SEQUENCE# 1 to 3.  Then, the latest INCARNATION#4  (for RESETLOGS_ID 771421939) has only 1 entry each for SEQUENCE# 1 to 5.

Were there really multiple archivelogs created from SEQUENCE# 180 to 182 and again for 1 to 3 on 01-JAN-12 ?

Here's a listing of archivelog files :

[oracle@linux64 2012_01_01]$ pwd
/home/oracle/app/oracle/flash_recovery_area/ORCL/archivelog/2012_01_01
[oracle@linux64 2012_01_01]$ ls -ltr
total 10200
-rw-rw---- 1 oracle oracle 5261824 Jan  1 10:59 o1_mf_1_179_7hzlzvcg_.arc
-rw-rw---- 1 oracle oracle   90112 Jan  1 11:00 o1_mf_1_180_7hzm1ogl_.arc
-rw-rw---- 1 oracle oracle  483840 Jan  1 11:02 o1_mf_1_181_7hzm5frg_.arc
-rw-rw---- 1 oracle oracle  377856 Jan  1 11:12 o1_mf_1_182_7hzmst65_.arc
-rw-rw---- 1 oracle oracle  483840 Jan  1 11:12 o1_mf_1_181_7hzmst4n_.arc
-rw-rw---- 1 oracle oracle   90112 Jan  1 11:12 o1_mf_1_180_7hzmst70_.arc
-rw-rw---- 1 oracle oracle 1486336 Jan  1 11:25 o1_mf_1_1_7hznjsy3_.arc
-rw-rw---- 1 oracle oracle   15872 Jan  1 11:26 o1_mf_1_2_7hznmzh7_.arc
-rw-rw---- 1 oracle oracle  590848 Jan  1 11:52 o1_mf_1_3_7hzp3my5_.arc
-rw-rw---- 1 oracle oracle   15872 Jan  1 11:52 o1_mf_1_2_7hzp3mxw_.arc
-rw-rw---- 1 oracle oracle 1486336 Jan  1 11:52 o1_mf_1_1_7hzp3mvq_.arc
[oracle@linux64 2012_01_01]$ 

That's curious ! I dont' see three archivelog files, but I do see two archivelogs for SEQUENCE# 180 and 181 and 1 and 2!!

Can anyone explain this ?
Hint : I did an OPEN RESETLOGS.

.
.
UPDATE 06-Feb :
Since there hasn't been a response ....
some more information ...

SQL> l
  1  select sequence#, resetlogs_id,
  2  to_char(first_time,'DD-MON HH24:MI:SS'), to_char(completion_time,'DD-MON HH24:MI:SS'),
  3  nvl(name,'Name is a NULL')
  4  from v$archived_log
  5  where sequence# in (1,2,3,180,181,182)
  6* order by sequence#, resetlogs_id, completion_time
SQL> /

 SEQUENCE# RESETLOGS_ID TO_CHAR(FIRST_TIME,'DD-M TO_CHAR(COMPLETION_TIME,
---------- ------------ ------------------------ ------------------------
NVL(NAME,'NAMEISANULL')
--------------------------------------------------------------------------------
         1    771419578 01-JAN 11:12:58          01-JAN 11:25:14
/home/oracle/app/oracle/flash_recovery_area/ORCL/archivelog/2012_01_01/o1_mf_1_1
_7hznjsy3_.arc

         1    771419578 01-JAN 11:12:58          01-JAN 11:48:44
Name is a NULL

         1    771419578 01-JAN 11:12:58          01-JAN 11:50:00
/home/oracle/app/oracle/oradata/orcl/redo01.log

         1    771419578 01-JAN 11:12:58          01-JAN 11:52:19
/home/oracle/app/oracle/flash_recovery_area/ORCL/archivelog/2012_01_01/o1_mf_1_1
_7hzp3mvq_.arc

         1    771421939 01-JAN 11:52:19          14-JAN 23:48:56
/home/oracle/app/oracle/flash_recovery_area/ORCL/archivelog/2012_01_14/o1_mf_1_1
_7k38z82o_.arc

         2    771419578 01-JAN 11:25:13          01-JAN 11:26:55
/home/oracle/app/oracle/flash_recovery_area/ORCL/archivelog/2012_01_01/o1_mf_1_2
_7hznmzh7_.arc

         2    771419578 01-JAN 11:25:13          01-JAN 11:48:44
Name is a NULL

         2    771419578 01-JAN 11:25:13          01-JAN 11:50:00
/home/oracle/app/oracle/oradata/orcl/redo02.log

         2    771419578 01-JAN 11:25:13          01-JAN 11:52:19
/home/oracle/app/oracle/flash_recovery_area/ORCL/archivelog/2012_01_01/o1_mf_1_2
_7hzp3mxw_.arc

         2    771421939 14-JAN 23:48:55          15-JAN 22:47:38
/home/oracle/app/oracle/flash_recovery_area/ORCL/archivelog/2012_01_15/o1_mf_1_2
_7k5srb64_.arc

         3    771419578 01-JAN 11:26:55          01-JAN 11:48:44
Name is a NULL

         3    771419578 01-JAN 11:26:55          01-JAN 11:50:00
/home/oracle/app/oracle/oradata/orcl/redo03.log

         3    771419578 01-JAN 11:26:55          01-JAN 11:52:19
/home/oracle/app/oracle/flash_recovery_area/ORCL/archivelog/2012_01_01/o1_mf_1_3
_7hzp3my5_.arc

         3    771421939 15-JAN 22:47:38          15-JAN 23:14:40
/home/oracle/app/oracle/flash_recovery_area/ORCL/archivelog/2012_01_15/o1_mf_1_3
_7k5vc0nf_.arc

       180    701609923 01-JAN 10:59:07          01-JAN 11:00:05
/home/oracle/app/oracle/flash_recovery_area/ORCL/archivelog/2012_01_01/o1_mf_1_1
80_7hzm1ogl_.arc

       180    701609923 01-JAN 10:59:07          01-JAN 11:11:00
Name is a NULL

       180    701609923 01-JAN 10:59:07          01-JAN 11:12:58
/home/oracle/app/oracle/flash_recovery_area/ORCL/archivelog/2012_01_01/o1_mf_1_1
80_7hzmst70_.arc

       181    701609923 01-JAN 11:00:05          01-JAN 11:08:38
/home/oracle/app/oracle/flash_recovery_area/ORCL/archivelog/2012_01_01/o1_mf_1_1
81_7hzm5frg_.arc

       181    701609923 01-JAN 11:00:05          01-JAN 11:11:00
Name is a NULL

       181    701609923 01-JAN 11:00:05          01-JAN 11:12:58
/home/oracle/app/oracle/flash_recovery_area/ORCL/archivelog/2012_01_01/o1_mf_1_1
81_7hzmst4n_.arc

       182    701609923 01-JAN 11:02:05          01-JAN 11:11:00
Name is a NULL

       182    701609923 01-JAN 11:02:05          01-JAN 11:12:58
/home/oracle/app/oracle/flash_recovery_area/ORCL/archivelog/2012_01_01/o1_mf_1_1
82_7hzmst65_.arc


22 rows selected.

SQL> 

Look at the number of occurrences of SEQUENCE#1. Check the COMPLETION TIME for these entries. Why is the NAME a NULL value for some occurrences ?

.....  OK .... since it is unlikely that anyone will yet reply to the latest question .....
Here's more information from the alert.log :

Sun Jan 01 11:25:13 2012
ALTER SYSTEM ARCHIVE LOG
Sun Jan 01 11:25:13 2012
Thread 1 advanced to log sequence 2 (LGWR switch)
  Current log# 2 seq# 2 mem# 0: /home/oracle/app/oracle/oradata/orcl/redo02.log
Sun Jan 01 11:25:14 2012
Archived Log entry 10 added for thread 1 sequence 1 ID 0x4d6fd925 dest 1:


Sun Jan 01 11:33:24 2012
alter database mount
Sun Jan 01 11:33:28 2012
Successful mount of redo thread 1, with mount id 1299165956
Database mounted in Exclusive Mode
Lost write protection disabled
Completed: alter database mount
Sun Jan 01 11:35:19 2012
Errors in file /home/oracle/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_m000_4414.trc:
ORA-27037: unable to obtain file status
Linux Error: 13: Permission denied
Additional information: 3
ORA-01122: database file 14 failed verification check
ORA-01110: data file 14: '/oradata/add_tbs.dbf'
ORA-01565: error in identifying file '/oradata/add_tbs.dbf'
ORA-27037: unable to obtain file status
Linux Error: 13: Permission denied
Additional information: 3
Checker run found 1 new persistent data failures
Sun Jan 01 11:36:21 2012
Errors in file /home/oracle/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_m000_4427.trc:
ORA-27037: unable to obtain file status
Linux Error: 13: Permission denied
Additional information: 3
ORA-01122: database file 14 failed verification check
ORA-01110: data file 14: '/oradata/add_tbs.dbf'
ORA-01565: error in identifying file '/oradata/add_tbs.dbf'
ORA-27037: unable to obtain file status
Linux Error: 13: Permission denied
Additional information: 3
Sun Jan 01 11:36:23 2012
Full restore complete of datafile 7 /home/oracle/app/oracle/oradata/orcl/FLOW_1146416395631714.dbf.  Elapsed time: 0:00:00
  checkpoint is 4956847
  last deallocation scn is 960623
Full restore complete of datafile 4 /home/oracle/app/oracle/oradata/orcl/users01.dbf.  Elapsed time: 0:00:08
  checkpoint is 4956847
  last deallocation scn is 4932522
Sun Jan 01 11:36:38 2012
Full restore complete of datafile 6 /home/oracle/app/oracle/oradata/orcl/FLOW_1046101119510758.dbf.  Elapsed time: 0:00:00
  checkpoint is 4956853
  last deallocation scn is 833081
Full restore complete of datafile 8 /home/oracle/app/oracle/oradata/orcl/FLOW_1170420963682633.dbf.  Elapsed time: 0:00:01
  checkpoint is 4956853
  last deallocation scn is 969921
Full restore complete of datafile 5 /home/oracle/app/oracle/oradata/orcl/example01.dbf.  Elapsed time: 0:00:03
  checkpoint is 4956853
  last deallocation scn is 985357
Full restore complete of datafile 9 /home/oracle/app/oracle/oradata/orcl/FLOW_1194425963955800.dbf.  Elapsed time: 0:00:01
  checkpoint is 4956856
  last deallocation scn is 976123
Full restore complete of datafile 10 /home/oracle/app/oracle/oradata/orcl/FLOW_1218408858999342.dbf.  Elapsed time: 0:00:01
  checkpoint is 4956856
  last deallocation scn is 981657
Full restore complete of datafile 11 /home/oracle/app/oracle/oradata/orcl/FLOW_1242310449730067.dbf.  Elapsed time: 0:00:01
  checkpoint is 4956856
  last deallocation scn is 1367698
Full restore complete of datafile 12 /home/oracle/app/oracle/oradata/orcl/FLOW_1266412439758696.dbf.  Elapsed time: 0:00:01
  checkpoint is 4956856
  last deallocation scn is 2558126
Full restore complete of datafile 13 /home/oracle/app/oracle/oradata/orcl/APEX_1295922881855015.dbf.  Elapsed time: 0:00:01
  checkpoint is 4956856
Sun Jan 01 11:37:41 2012
Signalling error 1152 for datafile 4!
Signalling error 1152 for datafile 5!
Signalling error 1152 for datafile 6!
Signalling error 1152 for datafile 7!
Signalling error 1152 for datafile 8!
Signalling error 1152 for datafile 9!
Signalling error 1152 for datafile 10!
Signalling error 1152 for datafile 11!
Signalling error 1152 for datafile 12!
Signalling error 1152 for datafile 13!
Errors in file /home/oracle/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_m000_4436.trc:
ORA-27037: unable to obtain file status
Linux Error: 13: Permission denied
Additional information: 3
ORA-01122: database file 14 failed verification check
ORA-01110: data file 14: '/oradata/add_tbs.dbf'
ORA-01565: error in identifying file '/oradata/add_tbs.dbf'
ORA-27037: unable to obtain file status
Linux Error: 13: Permission denied
Additional information: 3
Checker run found 12 new persistent data failures
Sun Jan 01 11:41:53 2012
Signalling error 1152 for datafile 4!
Signalling error 1152 for datafile 5!
Signalling error 1152 for datafile 6!
Signalling error 1152 for datafile 7!
Signalling error 1152 for datafile 8!
Signalling error 1152 for datafile 9!
Signalling error 1152 for datafile 10!
Signalling error 1152 for datafile 11!

Sun Jan 01 11:44:09 2012
Full restore complete of datafile 1 /home/oracle/app/oracle/oradata/orcl/system01.dbf.  Elapsed time: 0:01:09
  checkpoint is 4956816 
  last deallocation scn is 2681676
  Undo Optimization current scn is 4717725

Sun Jan 01 11:45:38 2012
Full restore complete of datafile 2 /home/oracle/app/oracle/oradata/orcl/sysaux01.dbf.  Elapsed time: 0:01:13
  checkpoint is 4956816
  last deallocation scn is 4862545

Sun Jan 01 11:45:57 2012
Full restore complete of datafile 3 /home/oracle/app/oracle/oradata/orcl/undotbs01.dbf.  Elapsed time: 0:00:10
  checkpoint is 4956816
  last deallocation scn is 4718440
  Undo Optimization current scn is 4717725

Sun Jan 01 11:48:02 2012
Full restore complete of datafile 14 to datafile copy /home/oracle/app/oracle/oradata/orcl/add_tbs.dbf.  Elapsed time: 0:00:00 
  checkpoint is 4956816

Switch of datafile 14 complete to datafile copy
  checkpoint is 4956816

alter database recover datafile list clear
Completed: alter database recover datafile list clear
alter database recover datafile list
 1 , 2 , 3 , 4 , 5 , 6 , 7 , 8 , 9 , 10 , 11 , 12 , 13 , 14
Completed: alter database recover datafile list
 1 , 2 , 3 , 4 , 5 , 6 , 7 , 8 , 9 , 10 , 11 , 12 , 13 , 14
alter database recover if needed
 start until cancel using backup controlfile
Media Recovery Start
 started logmerger process
Parallel Media Recovery started with 4 slaves
ORA-279 signalled during: alter database recover if needed
 start until cancel using backup controlfile
...
alter database recover logfile '/home/oracle/app/oracle/flash_recovery_area/ORCL/archivelog/2012_01_01/o1_mf_1_2_7hznmzh7_.arc'
Media Recovery Log /home/oracle/app/oracle/flash_recovery_area/ORCL/archivelog/2012_01_01/o1_mf_1_2_7hznmzh7_.arc
Sun Jan 01 11:50:01 2012
ORA-279 signalled during: alter database recover logfile '/home/oracle/app/oracle/flash_recovery_area/ORCL/archivelog/2012_01_01/o1_mf_1_2_7hznmzh7_.arc'...
alter database recover logfile '/home/oracle/app/oracle/oradata/orcl/redo03.log'
Media Recovery Log /home/oracle/app/oracle/oradata/orcl/redo03.log
Sun Jan 01 11:50:01 2012
Incomplete recovery applied all redo ever generated.
Recovery completed through change 4957613 time 01/01/2012 11:30:06
Media Recovery Complete (orcl)
Completed: alter database recover logfile '/home/oracle/app/oracle/oradata/orcl/redo03.log'
Sun Jan 01 11:52:19 2012
alter database open resetlogs
Archived Log entry 18 added for thread 1 sequence 1 ID 0x4d6fd925 dest 1:
Archived Log entry 19 added for thread 1 sequence 2 ID 0x4d6fd925 dest 1:
Archived Log entry 20 added for thread 1 sequence 3 ID 0x4d6fd925 dest 1:
RESETLOGS after complete recovery through change 4957613
Resetting resetlogs activation ID 1299175717 (0x4d6fd925)
Sun Jan 01 11:52:23 2012
Setting recovery target incarnation to 4
Sun Jan 01 11:52:23 2012
Assigning activation ID 1299165956 (0x4d6fb304)

Sun Jan 01 11:52:24 2012
ARC2 started with pid=20, OS id=4534
Thread 1 opened at log sequence 1
  Current log# 1 seq# 1 mem# 0: /home/oracle/app/oracle/oradata/orcl/redo01.log
Successful open of redo thread 1

Do you notice how SEQUENCE#1 was Archive Log Entry 10 and again entry 18 after an OPEN RESETLOGS. The actual Online Redo Log files were *still present* and yet, I did an Incomplete Recovery and OPEN RESETLOGS. The Onlne Redo Log file that was present on disk was *again* archived out by Oracle (and a new activiation ID and target incarnation assigned). Thus, this was an OPEN RESETLOGS with Online Redo Logs present. Oracle automatically detected that the files were present and archived them out ! . .

.
.
.

Oracle Wiki Relaunched

Oracle Wiki has been reluanched as wikis.oracle.com  .   It doesn't seem to be very well organized currently.  Multiple pages with the name "Home" appear at the first page and each of these are for specific product homes.  The list of "spaces" doesn't seem to include the core RDBMS product or the EBusiness Suite yet.

I'll wait a week or two before deciding if I want to contribute to Oracle Wiki (or Wikis ?)
.
.
.

Departmental Analytics -- a "pro-local" approach ?

Curt Monash has posted about Departmental Analytics - best practices.  He is of the view that "corporate standards" should NOT be an obstacle to departments running their own Analytics implementations.

.
.
.

Refreshing an MV on a Prebuilt Table

I had earlier demonstrated creating an MV on a Prebuilt Table.  A few days ago, I had a question on refreshing such an MV.
Here is a simple demonstration :

SQL> -- create the source table
SQL> create table mv_source (id number not null, item_name varchar2(30));

Table created.

SQL> insert  into mv_source select object_id, object_name from user_objects;

6 rows created.

SQL> select count(*) from mv_source;

  COUNT(*)                                                                      
----------                                                                      
         6                                                                      

SQL> alter table mv_source add constraint mv_source_pk primary key (id);

Table altered.

SQL> 
SQL> -- create an MV Log on the source table
SQL> create materialized view log on mv_source;

Materialized view log created.

SQL> 
SQL> -- create the MV as a prebuilt table
SQL> -- e.g. this could have been via export/import ?
SQL> create table my_mv as select * from mv_source;

Table created.

SQL> create materialized view my_mv on prebuilt table refresh fast as select * from mv_source;

Materialized view created.

SQL> select count(*) from my_mv;

  COUNT(*)                                                                      
----------                                                                      
         6                                                                      

SQL> 
SQL> -- setup new data
SQL> select count(*) from mlog$_mv_source;

  COUNT(*)                                                                      
----------                                                                      
         0                                                                      

SQL> insert into mv_source values (1000000, 'AN_ITEM');

1 row created.

SQL> insert into mv_source values (2000000, 'ANOTHER_ITEM');

1 row created.

SQL> insert into mv_source values (3000000, 'THIRD_ITEM');

1 row created.

SQL> commit;

Commit complete.

SQL> select count(*) from mlog$_mv_source;

  COUNT(*)                                                                      
----------                                                                      
         3                                                                      

SQL> 
SQL> -- refresh the MV
SQL> exec dbms_session.session_trace_enable();

PL/SQL procedure successfully completed.

SQL> exec dbms_mview.refresh('MY_MV','F');

PL/SQL procedure successfully completed.

SQL> select count(*) from my_mv;

  COUNT(*)                                                                      
----------                                                                      
         9                                                                      

SQL> exec dbms_session.session_trace_disable();

PL/SQL procedure successfully completed.

SQL> select * from my_mv where id  > 999999 order by 1;

        ID ITEM_NAME                                                            
---------- ------------------------------                                       
   1000000 AN_ITEM                                                              
   2000000 ANOTHER_ITEM                                                         
   3000000 THIRD_ITEM                                                           

SQL> 
SQL> -- the Snapshot log on the source table has been cleared
SQL> select count(*) from mlog$_mv_source;

  COUNT(*)                                                                      
----------                                                                      
         0                                                                      

SQL> 

I started with the source table MV_SOURCE and then created MY_MV from this table.  New rows inserted into the source then populated the MV Log on the source.  A FAST REFRESH of the MV was executed as an Incremental Refresh rather than a full scan of the source table again !

Note : Here are some of the interesting SQLs from the trace of the Refresh call :

DELETE FROM "HEMANT"."MY_MV" SNAP$
WHERE
 "ID" IN (SELECT DISTINCT LOG$."ID" FROM (SELECT MLOG$."ID" FROM
  "HEMANT"."MLOG$_MV_SOURCE" MLOG$ WHERE "SNAPTIME$$" > :1 AND ("DMLTYPE$$" !=
   'I')) LOG$ WHERE (LOG$."ID") NOT IN (SELECT MAS_TAB$."ID" FROM "MV_SOURCE"
  "MAS_TAB$" WHERE LOG$."ID" = MAS_TAB$."ID"))


MERGE INTO "HEMANT"."MY_MV" "SNA$" USING (SELECT CURRENT$."ID",
  CURRENT$."ITEM_NAME" FROM (SELECT "MV_SOURCE"."ID" "ID",
  "MV_SOURCE"."ITEM_NAME" "ITEM_NAME" FROM "MV_SOURCE" "MV_SOURCE") CURRENT$,
  (SELECT DISTINCT MLOG$."ID" FROM "HEMANT"."MLOG$_MV_SOURCE" MLOG$ WHERE
  "SNAPTIME$$" > :1 AND ("DMLTYPE$$" != 'D')) LOG$ WHERE CURRENT$."ID" =
  LOG$."ID")"AV$" ON ("SNA$"."ID" = "AV$"."ID") WHEN MATCHED THEN UPDATE  SET
  "SNA$"."ID" = "AV$"."ID","SNA$"."ITEM_NAME" = "AV$"."ITEM_NAME" WHEN NOT
  MATCHED THEN INSERT  (SNA$."ID",SNA$."ITEM_NAME") VALUES (AV$."ID",
  AV$."ITEM_NAME")

Thus, it is possible to do a Fast Refresh on an MV that was defined on a Prebuilt Table.
.
.
.

SQL in Functions

Here's an article "SQL in Functions"  that I had submitted for publication in AIOUG's Sangam Journal in November 2010.
.
.
.

Growing Materialized View (Snapshot) Logs

As I had noted about 5 years ago "Large (Growing) Snapshot Logs indicate that you have a problem", if you have a Fast Refresh Materialized View that hasn't been refreshed for a considerable period of time, you will find that the Materialized View Log ("Snapshot Log" in earlier versions) would keep growing because it patiently expects the MV to come around for the next refresh.  You can end up with very large MV Logs and also performance issues inserting into the base tables as each insert also has to update the MV Logs.  Furthermore, other MVs that do refresh from the same base table may also suffer because they have to contend with larger MV Logs.

Here is a demonstration with two users "ANOTHER_USR" and "LAZY_USR" having created their own Materialized Views against my source table.  If LAZY_USR does not execute a Refresh of his MV, the Snapshot Log on my source table does not get purge.

23:39:21 SQL> --- create two users that will be creating MVs
23:39:21 SQL> drop user another_usr cascade;

User dropped.

23:39:21 SQL> create user another_usr identified by another_usr default tablespace users;

User created.

23:39:21 SQL> grant create session, create table, create materialized view to another_usr;

Grant succeeded.

23:39:21 SQL> alter user another_usr quota unlimited on users;

User altered.

23:39:21 SQL> 
23:39:21 SQL> drop user lazy_usr cascade;

User dropped.

23:39:22 SQL> create user lazy_usr identified by lazy_usr default tablespace users;

User created.

23:39:22 SQL> grant create session, create table, create materialized view to lazy_usr;

Grant succeeded.

23:39:22 SQL> alter user lazy_usr quota unlimited on users;

User altered.

23:39:22 SQL> 
23:39:22 SQL> 
23:39:22 SQL> --- create the source table and mv log on it
23:39:22 SQL> drop table my_data_table purge;

Table dropped.

23:39:22 SQL> create table my_data_table
23:39:22   2  as select object_id as ID_Number, object_name as Data_Item, created as Crtn_date
23:39:22   3  from dba_objects where object_id is not null;

Table created.

23:39:22 SQL> alter table my_data_table modify (ID_Number not null);

Table altered.

23:39:22 SQL> alter table my_data_table add constraint my_data_table_pk primary key (ID_Number);

Table altered.

23:39:22 SQL> 
23:39:22 SQL> create materialized view log on my_data_table ;

Materialized view log created.

23:39:22 SQL> 
23:39:22 SQL> grant select on my_data_table to another_usr;

Grant succeeded.

23:39:22 SQL> grant select on mlog$_my_data_table to another_usr;

Grant succeeded.

23:39:22 SQL> grant select on my_data_table to lazy_usr;

Grant succeeded.

23:39:22 SQL> grant select on mlog$_my_data_table to lazy_usr;

Grant succeeded.

23:39:22 SQL> 
23:39:22 SQL> --- create the mv in the another_usr account
23:39:22 SQL> connect another_usr/another_usr
Connected.
23:39:22 SQL> create materialized view my_mv
23:39:22   2  refresh fast on demand
23:39:22   3  as
23:39:22   4  select rowid as row_identifier, id_number, data_item
23:39:22   5  from hemant.my_data_table
23:39:22   6  /

Materialized view created.

23:39:22 SQL> 
23:39:22 SQL> --- query the data dictionary
23:39:22 SQL> connect hemant/hemant
Connected.
23:39:22 SQL> col owner format a12
23:39:22 SQL> col name format a12
23:39:22 SQL> col snapshot_site format a12
23:39:22 SQL> col refresh_method format a12
23:39:22 SQL> select name from v$database;

NAME                                                                            
------------                                                                    
ORCL                                                                            

23:39:22 SQL> select v.owner, v.name, v.snapshot_site, v.refresh_method,
23:39:22   2        to_char(l.current_snapshots,'DD-MON HH24:MI:SS')
23:39:22   3  from dba_registered_snapshots v, dba_snapshot_logs l
23:39:22   4  where v.snapshot_id = l.snapshot_id
23:39:22   5  and l.log_owner = 'HEMANT'
23:39:22   6  and l.master = 'MY_DATA_TABLE'
23:39:22   7  order by 1,2
23:39:22   8  /

OWNER        NAME         SNAPSHOT_SIT REFRESH_METH TO_CHAR(L.CURRENT_SNAPSH    
------------ ------------ ------------ ------------ ------------------------    
ANOTHER_USR  MY_MV        ORCL         PRIMARY KEY  15-JAN 23:39:23             

23:39:22 SQL> 
23:39:22 SQL> -- insert into the source table
23:39:22 SQL> insert into my_data_table values (1000000,'A DUMMY',sysdate);

1 row created.

23:39:22 SQL> commit;

Commit complete.

23:39:22 SQL> 
23:39:22 SQL> select count(*) from mlog$_my_data_table;

  COUNT(*)                                                                      
----------                                                                      
         1                                                                      

23:39:22 SQL> 
23:39:22 SQL> exec dbms_lock.sleep(30);

PL/SQL procedure successfully completed.

23:39:52 SQL> 
23:39:52 SQL> --- check if the MV has been updated ?!
23:39:52 SQL> select v.owner, v.name, v.snapshot_site, v.refresh_method,
23:39:52   2        to_char(l.current_snapshots,'DD-MON HH24:MI:SS')
23:39:52   3  from dba_registered_snapshots v, dba_snapshot_logs l
23:39:52   4  where v.snapshot_id = l.snapshot_id
23:39:52   5  and l.log_owner = 'HEMANT'
23:39:52   6  and l.master = 'MY_DATA_TABLE'
23:39:52   7  order by 1,2
23:39:52   8  /

OWNER        NAME         SNAPSHOT_SIT REFRESH_METH TO_CHAR(L.CURRENT_SNAPSH    
------------ ------------ ------------ ------------ ------------------------    
ANOTHER_USR  MY_MV        ORCL         PRIMARY KEY  15-JAN 23:39:23             

23:39:52 SQL> 
23:39:52 SQL> exec dbms_lock.sleep(10);

PL/SQL procedure successfully completed.

23:40:02 SQL> 
23:40:02 SQL> -- refresh the MV
23:40:02 SQL> connect another_usr/another_usr
Connected.
23:40:03 SQL> exec dbms_mview.refresh('MY_MV');

PL/SQL procedure successfully completed.

23:40:03 SQL> 
23:40:03 SQL> 
23:40:03 SQL> --- re-query the data dictionary
23:40:03 SQL> connect hemant/hemant
Connected.
23:40:03 SQL> select v.owner, v.name, v.snapshot_site, v.refresh_method,
23:40:03   2        to_char(l.current_snapshots,'DD-MON HH24:MI:SS')
23:40:03   3  from dba_registered_snapshots v, dba_snapshot_logs l
23:40:03   4  where v.snapshot_id = l.snapshot_id
23:40:03   5  and l.log_owner = 'HEMANT'
23:40:03   6  and l.master = 'MY_DATA_TABLE'
23:40:03   7  order by 1,2
23:40:03   8  /

OWNER        NAME         SNAPSHOT_SIT REFRESH_METH TO_CHAR(L.CURRENT_SNAPSH    
------------ ------------ ------------ ------------ ------------------------    
ANOTHER_USR  MY_MV        ORCL         PRIMARY KEY  15-JAN 23:40:03             

23:40:03 SQL> select count(*) from mlog$_my_data_table;

  COUNT(*)                                                                      
----------                                                                      
         0                                                                      

23:40:03 SQL> 
23:40:03 SQL> --- create another mv in the lazy_usr account
23:40:03 SQL> connect lazy_usr/lazy_usr
Connected.
23:40:03 SQL> create materialized view lazy_mv
23:40:03   2  refresh fast on demand
23:40:03   3  as
23:40:03   4  select rowid as row_identifier, id_number, data_item
23:40:03   5  from hemant.my_data_table
23:40:03   6  /

Materialized view created.

23:40:03 SQL> 
23:40:03 SQL> 
23:40:03 SQL> --- insert new data
23:40:03 SQL> connect hemant/hemant
Connected.
23:40:03 SQL> insert into my_data_table values (2000000,'Another dummy',sysdate);

1 row created.

23:40:03 SQL> commit;

Commit complete.

23:40:03 SQL> select count(*) from mlog$_my_data_table;

  COUNT(*)                                                                      
----------                                                                      
         1                                                                      

23:40:03 SQL> 
23:40:03 SQL> exec dbms_lock.sleep(30);

PL/SQL procedure successfully completed.

23:40:33 SQL> 
23:40:33 SQL> -- refresh another_usr's mv only
23:40:33 SQL> connect another_usr/another_usr
Connected.
23:40:33 SQL> exec dbms_mview.refresh('MY_MV');

PL/SQL procedure successfully completed.

23:40:34 SQL> 
23:40:34 SQL> --- requery the data dictionary
23:40:34 SQL> connect hemant/hemant
Connected.
23:40:34 SQL> select v.owner, v.name, v.snapshot_site, v.refresh_method,
23:40:34   2        to_char(l.current_snapshots,'DD-MON HH24:MI:SS')
23:40:34   3  from dba_registered_snapshots v, dba_snapshot_logs l
23:40:34   4  where v.snapshot_id = l.snapshot_id
23:40:34   5  and l.log_owner = 'HEMANT'
23:40:34   6  and l.master = 'MY_DATA_TABLE'
23:40:34   7  order by 1,2
23:40:34   8  /

OWNER        NAME         SNAPSHOT_SIT REFRESH_METH TO_CHAR(L.CURRENT_SNAPSH    
------------ ------------ ------------ ------------ ------------------------    
ANOTHER_USR  MY_MV        ORCL         PRIMARY KEY  15-JAN 23:40:34             
LAZY_USR     LAZY_MV      ORCL         PRIMARY KEY  15-JAN 23:40:04             

23:40:34 SQL> select count(*) from mlog$_my_data_table;

  COUNT(*)                                                                      
----------                                                                      
         1                                                                      

23:40:34 SQL> 

My data dictionary query, at the first execution at 23:39:22, showed that ANOTHER_USR had an MV called "MY_MV" against my table MY_DATA_TABLE.   Inserting a single row in MY_DATA_TABLE caused a corresponding row to be inserted into the MV Log MLOG$_MY_DATA_TABLE.  However, as ANOTHER_USR had not refreshed his MV even as at 23:39:52, the Data Dictionary showed that the MV was still as of 23:39:23.
After ANOTHER_USR did refresh his MV (at 23:40:03), the MV Log MLOG$_MY_DATA_TABLE was purged of the record that was used to track the one row DML against MY_DATA_TABLE.

However, when LAZY_USR created an MV but did not refresh the MV, even as at 23:40:34, the one row in MLOG$_MY_DATA_TABLE  (to capture the insert of "(2000000,'Another dummy',sysdate)), was *not* purged.  Until LAZY_USR executes a Refresh of his MV,  MLOG$_MY_DATA_TABLE will keep growing, even though ANOTHER_USR might be diligently refreshing his MV.
Over time, I will find MLOG$_MY_DATA_TABLE to have grown "excessively large !".

The solution is to identify LAZY_USR (which the query against the Data Dictionary does do) and then :
0  (optional).  Drop LAZY_USR's MV "LAZY_MV"
2.  Purge MLOG$_MY_DATA_TABLE (using either DBMS_MVIEW.PURGE_LOG or a TRUNCATE)
3.  ReCreate or Refersh LAZY_USR's MV "LAZY_MV"

I have seen situations where LAZY_USR is a an account in a "remote" database managed by another application / development / support / DBA team that doesn't bother to inform HEMANT that they are no longer refreshing the MV even as HEMANT's schema continues to grow only to hold entries in MLOG$_MY_DATA_TABLE. 
The example I have posted is of 1 source table and 1 row DML.  In real-life you may have a dozen such tables and tens of thousands of rows before you notice this (and you would notice it only if you are diligently monitoring all the schemas in your database).

.
.
.

Datafiles not Restored -- using V$DATAFILE and V$DATAFILE_HEADER

Building on my previous blog post "Does a STARTUP MOUNT verify datafiles ?",  here's how I can use the V$DATAFILE and V$DATAFILE_HEADER views from the controlfile to identify datafiles that are / are not restored.  This is a case where I have to do a FULL Restore.

I first restore the controlfile :

MAN> startup nomount;

connected to target database (not started)
Oracle instance started

Total System Global Area     313860096 bytes

Fixed Size                     1336232 bytes
Variable Size                281021528 bytes
Database Buffers              25165824 bytes
Redo Buffers                   6336512 bytes

RMAN> restore controlfile from autobackup;

Starting restore at 01-JAN-12
allocated channel: ORA_DISK_1
channel ORA_DISK_1: SID=192 device type=DISK

recovery area destination: /home/oracle/app/oracle/flash_recovery_area
database name (or database unique name) used for search: ORCL
channel ORA_DISK_1: AUTOBACKUP /home/oracle/app/oracle/flash_recovery_area/ORCL/autobackup/2012_01_01/o1_mf_n_771420416_7hznn10m_.bkp found in the recovery area
channel ORA_DISK_1: looking for AUTOBACKUP on day: 20120101
channel ORA_DISK_1: restoring control file from AUTOBACKUP /home/oracle/app/oracle/flash_recovery_area/ORCL/autobackup/2012_01_01/o1_mf_n_771420416_7hznn10m_.bkp
channel ORA_DISK_1: control file restore from AUTOBACKUP complete
output file name=/home/oracle/app/oracle/oradata/orcl/control01.ctl
output file name=/home/oracle/app/oracle/flash_recovery_area/orcl/control02.ctl
Finished restore at 01-JAN-12

RMAN> 
RMAN> alter database mount;

database mounted
released channel: ORA_DISK_1

RMAN> exit


Recovery Manager complete.

I then query the V$DATAFILE and V$DATAFILE_HEADER views. Remember : There are NO datafiles present on this server. I only have the controlfile. I find (see the output below) that V$DATAFILE shows all the files expected to be present but V$DATAFILE_HEADER does not find any files.

oracle@linux64 ~]$ sqlplus '/ as sysdba'

SQL*Plus: Release 11.2.0.1.0 Production on Sun Jan 1 11:34:25 2012

Copyright (c) 1982, 2009, Oracle.  All rights reserved.


Connected to:
Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options

SQL> set pages600       
SQL> select file#, name from v$datafile order by 1;

     FILE#
----------
NAME
--------------------------------------------------------------------------------
         1
/home/oracle/app/oracle/oradata/orcl/system01.dbf

         2
/home/oracle/app/oracle/oradata/orcl/sysaux01.dbf

         3
/home/oracle/app/oracle/oradata/orcl/undotbs01.dbf

         4
/home/oracle/app/oracle/oradata/orcl/users01.dbf

         5
/home/oracle/app/oracle/oradata/orcl/example01.dbf

         6
/home/oracle/app/oracle/oradata/orcl/FLOW_1046101119510758.dbf

         7
/home/oracle/app/oracle/oradata/orcl/FLOW_1146416395631714.dbf

         8
/home/oracle/app/oracle/oradata/orcl/FLOW_1170420963682633.dbf

         9
/home/oracle/app/oracle/oradata/orcl/FLOW_1194425963955800.dbf

        10
/home/oracle/app/oracle/oradata/orcl/FLOW_1218408858999342.dbf

        11
/home/oracle/app/oracle/oradata/orcl/FLOW_1242310449730067.dbf

        12
/home/oracle/app/oracle/oradata/orcl/FLOW_1266412439758696.dbf

        13
/home/oracle/app/oracle/oradata/orcl/APEX_1295922881855015.dbf

        14
/oradata/add_tbs.dbf


14 rows selected.

SQL> 
SQL> select file#, name from v$datafile_header order by 1;

     FILE#
----------
NAME
--------------------------------------------------------------------------------
         1


         2


         3


         4


         5


         6


         7


         8


         9


        10


        11


        12


        13


        14



14 rows selected.

SQL> 
SQL> select file#, nvl(name,'File Not Found') from v$datafile_header order by 1;

     FILE#
----------
NVL(NAME,'FILENOTFOUND')
--------------------------------------------------------------------------------
         1
File Not Found

         2
File Not Found

         3
File Not Found

         4
File Not Found

         5
File Not Found

         6
File Not Found

         7
File Not Found

         8
File Not Found

         9
File Not Found

        10
File Not Found

        11
File Not Found

        12
File Not Found

        13
File Not Found

        14
File Not Found


14 rows selected.

SQL> 
SQL> exit

Thus, all 14 entries are present in V$DATAFILE_HEADER but with a NULL NAME.

I then begin a RESTORE :

[oracle@linux64 ~]$ rman target /

Recovery Manager: Release 11.2.0.1.0 - Production on Sun Jan 1 11:36:07 2012

Copyright (c) 1982, 2009, Oracle and/or its affiliates.  All rights reserved.

connected to target database: ORCL (DBID=1229390655, not open)

RMAN> 
RMAN> restore database;

Starting restore at 01-JAN-12
Starting implicit crosscheck backup at 01-JAN-12
using target database control file instead of recovery catalog
allocated channel: ORA_DISK_1
channel ORA_DISK_1: SID=192 device type=DISK
Crosschecked 12 objects
Finished implicit crosscheck backup at 01-JAN-12

Starting implicit crosscheck copy at 01-JAN-12
using channel ORA_DISK_1
Finished implicit crosscheck copy at 01-JAN-12

searching for all files in the recovery area
cataloging files...
cataloging done

List of Cataloged Files
=======================
File Name: /home/oracle/app/oracle/flash_recovery_area/ORCL/autobackup/2012_01_01/o1_mf_n_771420416_7hznn10m_.bkp

using channel ORA_DISK_1

channel ORA_DISK_1: starting datafile backup set restore
channel ORA_DISK_1: specifying datafile(s) to restore from backup set
channel ORA_DISK_1: restoring datafile 00001 to /home/oracle/app/oracle/oradata/orcl/system01.dbf
channel ORA_DISK_1: restoring datafile 00002 to /home/oracle/app/oracle/oradata/orcl/sysaux01.dbf
channel ORA_DISK_1: restoring datafile 00003 to /home/oracle/app/oracle/oradata/orcl/undotbs01.dbf
channel ORA_DISK_1: restoring datafile 00014 to /oradata/add_tbs.dbf
channel ORA_DISK_1: reading from backup piece /home/oracle/app/oracle/flash_recovery_area/ORCL/backupset/2012_01_01/o1_mf_nnndf_TAG20120101T112516_7hznjx24_.bkp
channel ORA_DISK_1: ORA-19870: error while restoring backup piece /home/oracle/app/oracle/flash_recovery_area/ORCL/backupset/2012_01_01/o1_mf_nnndf_TAG20120101T112516_7hznjx24_.bkp
ORA-19504: failed to create file "/oradata/add_tbs.dbf"
ORA-27037: unable to obtain file status
Linux Error: 13: Permission denied
Additional information: 6

channel ORA_DISK_1: starting datafile backup set restore
channel ORA_DISK_1: specifying datafile(s) to restore from backup set
channel ORA_DISK_1: restoring datafile 00004 to /home/oracle/app/oracle/oradata/orcl/users01.dbf
channel ORA_DISK_1: restoring datafile 00007 to /home/oracle/app/oracle/oradata/orcl/FLOW_1146416395631714.dbf
channel ORA_DISK_1: reading from backup piece /home/oracle/app/oracle/flash_recovery_area/ORCL/backupset/2012_01_01/o1_mf_nnndf_TAG20120101T112516_7hznm84k_.bkp
channel ORA_DISK_1: piece handle=/home/oracle/app/oracle/flash_recovery_area/ORCL/backupset/2012_01_01/o1_mf_nnndf_TAG20120101T112516_7hznm84k_.bkp tag=TAG20120101T112516
channel ORA_DISK_1: restored backup piece 1
channel ORA_DISK_1: restore complete, elapsed time: 00:00:15
channel ORA_DISK_1: starting datafile backup set restore
channel ORA_DISK_1: specifying datafile(s) to restore from backup set
channel ORA_DISK_1: restoring datafile 00005 to /home/oracle/app/oracle/oradata/orcl/example01.dbf
channel ORA_DISK_1: restoring datafile 00006 to /home/oracle/app/oracle/oradata/orcl/FLOW_1046101119510758.dbf
channel ORA_DISK_1: restoring datafile 00008 to /home/oracle/app/oracle/oradata/orcl/FLOW_1170420963682633.dbf
channel ORA_DISK_1: reading from backup piece /home/oracle/app/oracle/flash_recovery_area/ORCL/backupset/2012_01_01/o1_mf_nnndf_TAG20120101T112516_7hznmq8q_.bkp
channel ORA_DISK_1: piece handle=/home/oracle/app/oracle/flash_recovery_area/ORCL/backupset/2012_01_01/o1_mf_nnndf_TAG20120101T112516_7hznmq8q_.bkp tag=TAG20120101T112516
channel ORA_DISK_1: restored backup piece 1
channel ORA_DISK_1: restore complete, elapsed time: 00:00:07
channel ORA_DISK_1: starting datafile backup set restore
channel ORA_DISK_1: specifying datafile(s) to restore from backup set
channel ORA_DISK_1: restoring datafile 00009 to /home/oracle/app/oracle/oradata/orcl/FLOW_1194425963955800.dbf
channel ORA_DISK_1: restoring datafile 00010 to /home/oracle/app/oracle/oradata/orcl/FLOW_1218408858999342.dbf
channel ORA_DISK_1: restoring datafile 00011 to /home/oracle/app/oracle/oradata/orcl/FLOW_1242310449730067.dbf
channel ORA_DISK_1: restoring datafile 00012 to /home/oracle/app/oracle/oradata/orcl/FLOW_1266412439758696.dbf
channel ORA_DISK_1: restoring datafile 00013 to /home/oracle/app/oracle/oradata/orcl/APEX_1295922881855015.dbf
channel ORA_DISK_1: reading from backup piece /home/oracle/app/oracle/flash_recovery_area/ORCL/backupset/2012_01_01/o1_mf_nnndf_TAG20120101T112516_7hznmydw_.bkp
channel ORA_DISK_1: piece handle=/home/oracle/app/oracle/flash_recovery_area/ORCL/backupset/2012_01_01/o1_mf_nnndf_TAG20120101T112516_7hznmydw_.bkp tag=TAG20120101T112516
channel ORA_DISK_1: restored backup piece 1
channel ORA_DISK_1: restore complete, elapsed time: 00:00:01
failover to previous backup

creating datafile file number=14 name=/oradata/add_tbs.dbf
RMAN-00571: ===========================================================
RMAN-00569: =============== ERROR MESSAGE STACK FOLLOWS ===============
RMAN-00571: ===========================================================
RMAN-03002: failure of restore command at 01/01/2012 11:36:45
ORA-01119: error in creating database file '/oradata/add_tbs.dbf'
ORA-27037: unable to obtain file status
Linux Error: 13: Permission denied
Additional information: 6
RMAN-06956: create datafile failed; retry after removing /oradata/add_tbs.dbf from OS

RMAN> 
RMAN> restore database;

Starting restore at 01-JAN-12
using channel ORA_DISK_1

skipping datafile 4; already restored to file /home/oracle/app/oracle/oradata/orcl/users01.dbf
skipping datafile 7; already restored to file /home/oracle/app/oracle/oradata/orcl/FLOW_1146416395631714.dbf
skipping datafile 5; already restored to file /home/oracle/app/oracle/oradata/orcl/example01.dbf
skipping datafile 6; already restored to file /home/oracle/app/oracle/oradata/orcl/FLOW_1046101119510758.dbf
skipping datafile 8; already restored to file /home/oracle/app/oracle/oradata/orcl/FLOW_1170420963682633.dbf
skipping datafile 9; already restored to file /home/oracle/app/oracle/oradata/orcl/FLOW_1194425963955800.dbf
skipping datafile 10; already restored to file /home/oracle/app/oracle/oradata/orcl/FLOW_1218408858999342.dbf
skipping datafile 11; already restored to file /home/oracle/app/oracle/oradata/orcl/FLOW_1242310449730067.dbf
skipping datafile 12; already restored to file /home/oracle/app/oracle/oradata/orcl/FLOW_1266412439758696.dbf
skipping datafile 13; already restored to file /home/oracle/app/oracle/oradata/orcl/APEX_1295922881855015.dbf
channel ORA_DISK_1: starting datafile backup set restore
channel ORA_DISK_1: specifying datafile(s) to restore from backup set
channel ORA_DISK_1: restoring datafile 00001 to /home/oracle/app/oracle/oradata/orcl/system01.dbf
channel ORA_DISK_1: restoring datafile 00002 to /home/oracle/app/oracle/oradata/orcl/sysaux01.dbf
channel ORA_DISK_1: restoring datafile 00003 to /home/oracle/app/oracle/oradata/orcl/undotbs01.dbf
channel ORA_DISK_1: restoring datafile 00014 to /oradata/add_tbs.dbf
channel ORA_DISK_1: reading from backup piece /home/oracle/app/oracle/flash_recovery_area/ORCL/backupset/2012_01_01/o1_mf_nnndf_TAG20120101T112516_7hznjx24_.bkp
channel ORA_DISK_1: ORA-19870: error while restoring backup piece /home/oracle/app/oracle/flash_recovery_area/ORCL/backupset/2012_01_01/o1_mf_nnndf_TAG20120101T112516_7hznjx24_.bkp
ORA-19504: failed to create file "/oradata/add_tbs.dbf"
ORA-27037: unable to obtain file status
Linux Error: 13: Permission denied
Additional information: 6

failover to previous backup

creating datafile file number=14 name=/oradata/add_tbs.dbf
RMAN-00571: ===========================================================
RMAN-00569: =============== ERROR MESSAGE STACK FOLLOWS ===============
RMAN-00571: ===========================================================
RMAN-03002: failure of restore command at 01/01/2012 11:37:42
ORA-01119: error in creating database file '/oradata/add_tbs.dbf'
ORA-27037: unable to obtain file status
Linux Error: 13: Permission denied
Additional information: 6
RMAN-06956: create datafile failed; retry after removing /oradata/add_tbs.dbf from OS

RMAN> 
RMAN> exit

I get an OS permissions error for File #14 ('/oradata/add_tbs.dbf') because oracle does not have write permissions for this directory path on this server !  Very unfortunately, RMAN isn't currently intelligent enough to skip this one file and restore the other files from the same backuppiece. Apparently, all 4 files in the backup piece are not restored !
RMAN does skip over datafiles 4 to 13 that have already been restored and does not attempt to restore these files at the second RESTORE execution.
Before attempting to restore these 4 files, I also use the V$DATAFILE and V$DATAFILE_HEADER views to identify them :

oracle@linux64 ~]$ sqlplus '/ as sysdba'

SQL*Plus: Release 11.2.0.1.0 Production on Sun Jan 1 11:42:06 2012

Copyright (c) 1982, 2009, Oracle.  All rights reserved.


Connected to:
Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options

SQL> set pages600
SQL> select file#, name from v$datafile
  2  minus
  3  select file#, name from v$datafile_header
  4  order by 1;

     FILE#
----------
NAME
--------------------------------------------------------------------------------
         1
/home/oracle/app/oracle/oradata/orcl/system01.dbf

         2
/home/oracle/app/oracle/oradata/orcl/sysaux01.dbf

         3
/home/oracle/app/oracle/oradata/orcl/undotbs01.dbf

        14
/oradata/add_tbs.dbf


SQL> 
SQL> exit

I then RESTORE the 4 files individually :

[oracle@linux64 ~]$ rman target /

Recovery Manager: Release 11.2.0.1.0 - Production on Sun Jan 1 11:42:52 2012

Copyright (c) 1982, 2009, Oracle and/or its affiliates.  All rights reserved.

connected to target database: ORCL (DBID=1229390655, not open)

RMAN> restore datafile 1;

Starting restore at 01-JAN-12
using target database control file instead of recovery catalog
allocated channel: ORA_DISK_1
channel ORA_DISK_1: SID=192 device type=DISK

channel ORA_DISK_1: starting datafile backup set restore
channel ORA_DISK_1: specifying datafile(s) to restore from backup set
channel ORA_DISK_1: restoring datafile 00001 to /home/oracle/app/oracle/oradata/orcl/system01.dbf
channel ORA_DISK_1: reading from backup piece /home/oracle/app/oracle/flash_recovery_area/ORCL/backupset/2012_01_01/o1_mf_nnndf_TAG20120101T112516_7hznjx24_.bkp
channel ORA_DISK_1: piece handle=/home/oracle/app/oracle/flash_recovery_area/ORCL/backupset/2012_01_01/o1_mf_nnndf_TAG20120101T112516_7hznjx24_.bkp tag=TAG20120101T112516
channel ORA_DISK_1: restored backup piece 1
channel ORA_DISK_1: restore complete, elapsed time: 00:01:15
Finished restore at 01-JAN-12

RMAN> restore datafile 2;

Starting restore at 01-JAN-12
using channel ORA_DISK_1

channel ORA_DISK_1: starting datafile backup set restore
channel ORA_DISK_1: specifying datafile(s) to restore from backup set
channel ORA_DISK_1: restoring datafile 00002 to /home/oracle/app/oracle/oradata/orcl/sysaux01.dbf
channel ORA_DISK_1: reading from backup piece /home/oracle/app/oracle/flash_recovery_area/ORCL/backupset/2012_01_01/o1_mf_nnndf_TAG20120101T112516_7hznjx24_.bkp
channel ORA_DISK_1: piece handle=/home/oracle/app/oracle/flash_recovery_area/ORCL/backupset/2012_01_01/o1_mf_nnndf_TAG20120101T112516_7hznjx24_.bkp tag=TAG20120101T112516
channel ORA_DISK_1: restored backup piece 1
channel ORA_DISK_1: restore complete, elapsed time: 00:01:15
Finished restore at 01-JAN-12

RMAN> restore datafile 3;

Starting restore at 01-JAN-12
using channel ORA_DISK_1

channel ORA_DISK_1: starting datafile backup set restore
channel ORA_DISK_1: specifying datafile(s) to restore from backup set
channel ORA_DISK_1: restoring datafile 00003 to /home/oracle/app/oracle/oradata/orcl/undotbs01.dbf
channel ORA_DISK_1: reading from backup piece /home/oracle/app/oracle/flash_recovery_area/ORCL/backupset/2012_01_01/o1_mf_nnndf_TAG20120101T112516_7hznjx24_.bkp
channel ORA_DISK_1: piece handle=/home/oracle/app/oracle/flash_recovery_area/ORCL/backupset/2012_01_01/o1_mf_nnndf_TAG20120101T112516_7hznjx24_.bkp tag=TAG20120101T112516
channel ORA_DISK_1: restored backup piece 1
channel ORA_DISK_1: restore complete, elapsed time: 00:00:15
Finished restore at 01-JAN-12

RMAN> run
2> {set newname for datafile 14 to '/home/oracle/app/oracle/oradata/orcl/add_tbs.dbf';
3> restore datafile 14;
4> }

executing command: SET NEWNAME

Starting restore at 01-JAN-12
using channel ORA_DISK_1

channel ORA_DISK_1: starting datafile backup set restore
channel ORA_DISK_1: specifying datafile(s) to restore from backup set
channel ORA_DISK_1: restoring datafile 00014 to /home/oracle/app/oracle/oradata/orcl/add_tbs.dbf
channel ORA_DISK_1: reading from backup piece /home/oracle/app/oracle/flash_recovery_area/ORCL/backupset/2012_01_01/o1_mf_nnndf_TAG20120101T112516_7hznjx24_.bkp
channel ORA_DISK_1: piece handle=/home/oracle/app/oracle/flash_recovery_area/ORCL/backupset/2012_01_01/o1_mf_nnndf_TAG20120101T112516_7hznjx24_.bkp tag=TAG20120101T112516
channel ORA_DISK_1: restored backup piece 1
channel ORA_DISK_1: restore complete, elapsed time: 00:00:03
Finished restore at 01-JAN-12

RMAN> 

However, since I have used a NEWNAME for datafile #14, I must SWITCH it before I can use RECOVER DATABASE :

RMAN> recover database; 

Starting recover at 01-JAN-12
using channel ORA_DISK_1
RMAN-00571: ===========================================================
RMAN-00569: =============== ERROR MESSAGE STACK FOLLOWS ===============
RMAN-00571: ===========================================================
RMAN-03002: failure of recover command at 01/01/2012 11:48:44
RMAN-06094: datafile 14 must be restored

RMAN> switch datafile 14 to copy;

datafile 14 switched to datafile copy "/home/oracle/app/oracle/oradata/orcl/add_tbs.dbf"

RMAN> recover database;

Starting recover at 01-JAN-12
using channel ORA_DISK_1

starting media recovery

archived log for thread 1 with sequence 2 is already on disk as file /home/oracle/app/oracle/flash_recovery_area/ORCL/archivelog/2012_01_01/o1_mf_1_2_7hznmzh7_.arc
archived log for thread 1 with sequence 3 is already on disk as file /home/oracle/app/oracle/oradata/orcl/redo03.log
archived log file name=/home/oracle/app/oracle/flash_recovery_area/ORCL/archivelog/2012_01_01/o1_mf_1_2_7hznmzh7_.arc thread=1 sequence=2
archived log file name=/home/oracle/app/oracle/oradata/orcl/redo03.log thread=1 sequence=3
media recovery complete, elapsed time: 00:00:00
Finished recover at 01-JAN-12

RMAN> 
RMAN> exit

I now verify the datafiles again, before actually OPENing the database :

[oracle@linux64 ~]$ sqlplus

SQL*Plus: Release 11.2.0.1.0 Production on Sun Jan 1 11:51:23 2012

Copyright (c) 1982, 2009, Oracle.  All rights reserved.

Enter user-name: / as sysdba

Connected to:
Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options

SQL> select file#, name from v$datafile
  2  minus
  3  select file#, name from v$datafile_header
  4  order by 1;

no rows selected

SQL> select name from v$datafile where file#=14;

NAME
--------------------------------------------------------------------------------
/home/oracle/app/oracle/oradata/orcl/add_tbs.dbf

SQL> alter database open resetlogs;

Database altered.

SQL>

Now it should be clear how V$DATAFILE and V$DATAFILE_HEADER are different. V$DATAFILE_HEADER does actually verify the datafile, while V$DATAFILE only reads the controlfile.

.
.
.