Adding a DataFile that had been excluded from a CREATE CONTROLFILE

Here is a scenario where a CREATE CONTROLFILE was used to recover a database but one of the datafiles was (inadvertently) excluded from the CREATE CONTROLFILE statement.
The Database when, OPENed, sets the file as a MISSING file. This is because it is present in the Data Dictionary but not in the Controlfile.
The datafile can be "added" back (if it is really available on disk or has been restored earlier) and "re-recovered".

SQL> REM ########### The controlfile was created without the "example01.dbf" datafile
SQL> REM #### An INCOMPLETE RECOVERy was performed
SQL> REM #### The database was OPENed with RESETLOGS
SQL> REM ##  The datafile has been added back with an ALTER DATABASE RENAME FILE 'MISSING05.DBF' TO 'example01.dbf'

SQL> @create_cntrlfile
SQL> spool create_cntrlfile
SQL> 
SQL> STARTUP NOMOUNT
ORACLE instance started.

Total System Global Area  880803840 bytes
Fixed Size                  2087992 bytes
Variable Size             218104776 bytes
Database Buffers          654311424 bytes
Redo Buffers                6299648 bytes
SQL> CREATE CONTROLFILE REUSE DATABASE "ORT24FS" RESETLOGS  ARCHIVELOG
  2      MAXLOGFILES 16
  3      MAXLOGMEMBERS 3
  4      MAXDATAFILES 100
  5      MAXINSTANCES 8
  6      MAXLOGHISTORY 292
  7  LOGFILE
  8    GROUP 1 '/oracle_fs/Databases/ORT24FS/redo01.dbf'  SIZE 50M,
  9    GROUP 2 '/oracle_fs/Databases/ORT24FS/redo02.dbf'  SIZE 50M,
 10    GROUP 3 '/oracle_fs/Databases/ORT24FS/redo03.dbf'  SIZE 50M,
 11    GROUP 4 '/oracle_fs/Databases/ORT24FS/redo04.dbf'  SIZE 50M,
 12    GROUP 5 '/oracle_fs/Databases/ORT24FS/redo05.dbf'  SIZE 50M
 13  -- STANDBY LOGFILE
 14  DATAFILE
 15    '/oracle_fs/Databases/ORT24FS/system01.dbf',
 16    '/oracle_fs/Databases/ORT24FS/sysaux01.dbf',
 17    '/oracle_fs/Databases/ORT24FS/users01.dbf',
 18    '/oracle_fs/Databases/ORT24FS/undotbs.dbf'
 19  CHARACTER SET WE8ISO8859P1
 20  ;

Control file created.

SQL> -- Configure RMAN configuration record 1
SQL> VARIABLE RECNO NUMBER;
SQL> EXECUTE :RECNO := SYS.DBMS_BACKUP_RESTORE.SETCONFIG('BACKUP OPTIMIZATION','OFF');

PL/SQL procedure successfully completed.

SQL> -- Configure RMAN configuration record 2
SQL> VARIABLE RECNO NUMBER;
SQL> EXECUTE :RECNO := SYS.DBMS_BACKUP_RESTORE.SETCONFIG('CONTROLFILE AUTOBACKUP','ON');

PL/SQL procedure successfully completed.

SQL> -- Configure RMAN configuration record 3
SQL> VARIABLE RECNO NUMBER;
SQL> EXECUTE :RECNO := SYS.DBMS_BACKUP_RESTORE.SETCONFIG('RETENTION POLICY','TO RECOVERY WINDOW OF 8 DAYS');

PL/SQL procedure successfully completed.

SQL> -- Configure RMAN configuration record 4
SQL> VARIABLE RECNO NUMBER;
SQL> EXECUTE :RECNO := SYS.DBMS_BACKUP_RESTORE.SETCONFIG('DEVICE TYPE','DISK PARALLELISM 2 BACKUP TYPE TO BACKUPSET');

PL/SQL procedure successfully completed.

SQL> -- Commands to re-create incarnation table
SQL> -- Below log names MUST be changed to existing filenames on
SQL> -- disk. Any one log file from each branch can be used to
SQL> -- re-create incarnation records.
SQL> -- ALTER DATABASE REGISTER LOGFILE '/oracle_fs/FRAs/ORT24FS/ORT24FS/archivelog/2010_08_25/o1_mf_1_1_%u_.arc';
SQL> -- ALTER DATABASE REGISTER LOGFILE '/oracle_fs/FRAs/ORT24FS/ORT24FS/archivelog/2010_08_25/o1_mf_1_1_%u_.arc';
SQL> -- ALTER DATABASE REGISTER LOGFILE '/oracle_fs/FRAs/ORT24FS/ORT24FS/archivelog/2010_08_25/o1_mf_1_1_%u_.arc';
SQL> -- ALTER DATABASE REGISTER LOGFILE '/oracle_fs/FRAs/ORT24FS/ORT24FS/archivelog/2010_08_25/o1_mf_1_1_%u_.arc';
SQL> -- ALTER DATABASE REGISTER LOGFILE '/oracle_fs/FRAs/ORT24FS/ORT24FS/archivelog/2010_08_25/o1_mf_1_1_%u_.arc';
SQL> -- ALTER DATABASE REGISTER LOGFILE '/oracle_fs/FRAs/ORT24FS/ORT24FS/archivelog/2010_08_25/o1_mf_1_1_%u_.arc';
SQL> -- Recovery is required if any of the datafiles are restored backups,
SQL> -- or if the last shutdown was not normal or immediate.
SQL> RECOVER DATABASE USING BACKUP CONTROLFILE;
ORA-00279: change 4325510 generated at 08/25/2010 16:46:41 needed for thread 1
ORA-00289: suggestion :
/oracle_fs/FRAs/ORT24FS/ORT24FS/archivelog/2010_08_25/o1_mf_1_43_%u_.arc
ORA-00280: change 4325510 for thread 1 is in sequence #43


Specify log: {=suggested | filename | AUTO | CANCEL}
/oracle_fs/ArchiveLogs/ORT24FS/1_43_725069822.dbf
ORA-00279: change 4325717 generated at 08/25/2010 16:54:02 needed for thread 1
ORA-00289: suggestion :
/oracle_fs/FRAs/ORT24FS/ORT24FS/archivelog/2010_08_25/o1_mf_1_44_%u_.arc
ORA-00280: change 4325717 for thread 1 is in sequence #44
ORA-00278: log file '/oracle_fs/ArchiveLogs/ORT24FS/1_43_725069822.dbf' no
longer needed for this recovery


Specify log: {=suggested | filename | AUTO | CANCEL}
CANCEL
Media recovery cancelled.
SQL> alter database open resetlogs;
alter database open resetlogs
*
ERROR at line 1:
ORA-01113: file 1 needs media recovery
ORA-01110: data file 1: '/oracle_fs/Databases/ORT24FS/system01.dbf'


SQL> recover database using backup controlfile until cancel;
ORA-00279: change 4325717 generated at 08/25/2010 16:54:02 needed for thread 1
ORA-00289: suggestion :
/oracle_fs/FRAs/ORT24FS/ORT24FS/archivelog/2010_08_25/o1_mf_1_44_%u_.arc
ORA-00280: change 4325717 for thread 1 is in sequence #44


Specify log: {=suggested | filename | AUTO | CANCEL}
CANCEL
Media recovery cancelled.
SQL> alter database open resetlogs;

Database altered.

SQL> ALTER TABLESPACE TEMP ADD TEMPFILE '/oracle_fs/Databases/ORT24FS/temp01.dbf' REUSE;
ALTER TABLESPACE TEMP ADD TEMPFILE '/oracle_fs/Databases/ORT24FS/temp01.dbf' REUSE
*
ERROR at line 1:
ORA-01119: error in creating database file
'/oracle_fs/Databases/ORT24FS/temp01.dbf'
ORA-17610: file '/oracle_fs/Databases/ORT24FS/temp01.dbf' does not exist and no
size specified
ORA-27037: unable to obtain file status
Linux-x86_64 Error: 2: No such file or directory
Additional information: 3


SQL> ALTER TABLESPACE TEMP ADD TEMPFILE '/oracle_fs/Databases/ORT24FS/temp01.dbf' size 100M autoextend on next 100M maxsize 8000M;

Tablespace altered.

SQL> select file_name from dba_data_files;

FILE_NAME
--------------------------------------------------------------------------------
/oracle_fs/Databases/ORT24FS/undotbs.dbf
/oracle_fs/Databases/ORT24FS/users01.dbf
/oracle_fs/Databases/ORT24FS/sysaux01.dbf
/oracle_fs/Databases/ORT24FS/system01.dbf
/oracle_fs/ora10204/product/10.2.0.4/dbs/MISSING00005

SQL> alter database create datafile '/oracle_fs/ora10204/product/10.2.0.4/dbs/MISSING00005'
  2  as '/oracle_fs/Databases/ORT24FS/example01.dbf';
alter database create datafile '/oracle_fs/ora10204/product/10.2.0.4/dbs/MISSING00005'
*
ERROR at line 1:
ORA-19723: Cannot recreate plugged in read-only datafile 5
ORA-01111: name for data file 5 is unknown - rename to correct file
ORA-01110: data file 5: '/oracle_fs/ora10204/product/10.2.0.4/dbs/MISSING00005'


SQL> alter database rename file '/oracle_fs/ora10204/product/10.2.0.4/dbs/MISSING00005'
  2  to '/oracle_fs/Databases/ORT24FS/example01.dbf'; 

Database altered.

SQL> recover datafile 5;
ORA-00279: change 4325511 generated at 08/25/2010 16:46:41 needed for thread 1
ORA-00289: suggestion :
/oracle_fs/FRAs/ORT24FS/ORT24FS/archivelog/2010_08_25/o1_mf_1_43_%u_.arc
ORA-00280: change 4325511 for thread 1 is in sequence #43


Specify log: {=suggested | filename | AUTO | CANCEL}
/oracle_fs/ArchiveLogs/ORT24FS/1_43_725069822.dbf
Log applied.
Media recovery complete.
SQL> select * from v$recover_file;

no rows selected

SQL> alter database datafile 5 online;

Database altered.

SQL> alter system switch logfile;

System altered.

SQL> select * from v$database_incarnation;

INCARNATION# RESETLOGS_CHANGE# RESETLOGS PRIOR_RESETLOGS_CHANGE# PRIOR_RES
------------ ----------------- --------- ----------------------- ---------
STATUS  RESETLOGS_ID PRIOR_INCARNATION# FLASHBACK_DATABASE_ALLOWED
------- ------------ ------------------ --------------------------
           1           4034914 23-JUL-10                 3632263 04-JUN-10
PARENT     725069822                  0 NO

           2           4325718 25-AUG-10                 4034914 23-JUL-10
CURRENT    727983988                  1 NO


SQL> exit 

The example01.dbf file was not included in the CREATE CONTROLFILE statement although it was present on disk. The OPEN RESETLOGS after the Incomplete Recovery created a new Incarnation of the database. Yet, I was able to "add" the datafile back by RENAMEing the "MISSING" file.

.
.
.

Trying to understand LAST_CALL_ET -- 3

Continuing the previous posts (1) and (2), in both of which I ran PLSQL procedures, I now run a test with a simple SQL select that retrieves close to 27million rows from the database server to the client (the SQLPLUS program).

The first sesion runs a SELECT with termout off but spooling to a file :

select object_id from obj_list; 

Monitoring shows :

SQL> l
1  select to_char(sysdate,'DD-MON HH24:MI:SS') Collection_datestamp, x.last_call_et, x.status, x.sql_id,
2  y.sql_text
3  from v$session x, v$sqlarea y
4  where x.sql_id = y.sql_id(+)
5* and x.sid = &session_id
SQL> /
Enter value for session_id: 141
old   5: and x.sid = &session_id
new   5: and x.sid = 141

COLLECTION_DATE LAST_CALL_ET STATUS   SQL_ID        SQL_TEXT
--------------- ------------ -------- ------------- ----------------------------------------------------------------
22-AUG 15:51:52            0 INACTIVE bxya78ra815js select object_id from obj_list

SQL> /
Enter value for session_id: 141
old   5: and x.sid = &session_id
new   5: and x.sid = 141

COLLECTION_DATE LAST_CALL_ET STATUS   SQL_ID        SQL_TEXT
--------------- ------------ -------- ------------- ----------------------------------------------------------------
22-AUG 15:51:57            0 ACTIVE   bxya78ra815js select object_id from obj_list

SQL> /
Enter value for session_id: 141
old   5: and x.sid = &session_id
new   5: and x.sid = 141

COLLECTION_DATE LAST_CALL_ET STATUS   SQL_ID        SQL_TEXT
--------------- ------------ -------- ------------- ----------------------------------------------------------------
22-AUG 15:52:04            0 ACTIVE   bxya78ra815js select object_id from obj_list

SQL> /
Enter value for session_id: 141
old   5: and x.sid = &session_id
new   5: and x.sid = 141

COLLECTION_DATE LAST_CALL_ET STATUS   SQL_ID        SQL_TEXT
--------------- ------------ -------- ------------- ----------------------------------------------------------------
22-AUG 15:52:13            0 INACTIVE bxya78ra815js select object_id from obj_list

SQL>
SQL> /
Enter value for session_id: 141
old   5: and x.sid = &session_id
new   5: and x.sid = 141

COLLECTION_DATE LAST_CALL_ET STATUS   SQL_ID        SQL_TEXT
--------------- ------------ -------- ------------- ----------------------------------------------------------------
22-AUG 15:53:32            0 INACTIVE bxya78ra815js select object_id from obj_list

SQL>

SQL> select to_char(sysdate,'DD-MON HH24:MI:SS') Collection_Datestamp, executions, buffer_gets, rows_processed
2  from v$sqlstats where sql_id = 'bxya78ra815js';

COLLECTION_DATE EXECUTIONS BUFFER_GETS ROWS_PROCESSED
--------------- ---------- ----------- --------------
22-AUG 15:55:32          1      441971       13190847

SQL>
SQL> /

COLLECTION_DATE EXECUTIONS BUFFER_GETS ROWS_PROCESSED
--------------- ---------- ----------- --------------
22-AUG 15:56:04          1      505590       15090747

SQL>
SQL> /

COLLECTION_DATE EXECUTIONS BUFFER_GETS ROWS_PROCESSED
--------------- ---------- ----------- --------------
22-AUG 15:57:22          1      646127       19291147

SQL>
SQL> /

COLLECTION_DATE EXECUTIONS BUFFER_GETS ROWS_PROCESSED
--------------- ---------- ----------- --------------
22-AUG 15:58:27          1      760275       22702847

SQL>
SQL>
SQL> @sess_sql_statement
Enter value for session_id: 141
old   5: and x.sid = &session_id
new   5: and x.sid = 141

COLLECTION_DATE LAST_CALL_ET STATUS   SQL_ID        SQL_TEXT
--------------- ------------ -------- ------------- ----------------------------------------------------------------
22-AUG 16:00:16           27 INACTIVE

SQL>  

Thus, the LAST_CALL_ET was getting reset at every new FETCH call by the client and STATUS kept switching between 'ACTIVE' and 'INACTIVE'.

The tkprof of the trace shows :

select object_id
from
obj_list


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch   538612     58.38      74.70     363739     900989          0    26930545
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total   538614     58.38      74.70     363739     900989          0    26930545

Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 64

Rows     Row Source Operation
-------  ---------------------------------------------------
26930545  TABLE ACCESS FULL OBJ_LIST (cr=900989 pr=363739 pw=0 time=107722594 us) 

A total of 538,612 FETCH calls from the client (SQLPLUS) to the server. Each FETCH call is a new call to the database server process.

.
.
.

Trying to understand LAST_CALL_ET -- 2

In my previous post I showed how LAST_CALL_ET does not get reset by each invocation of a seperate SQL from a run of the DBMS_STATS.GATHER_SCHEMA_STATS procedure.

Here, I show that this is not restricted to Stored Procedures. I run an anonymous PLSQL block and monitor the session from another terminal.
First, this is the block that I run :

SQL> !cat run_anon_PLSQL_with_SQLs.sql
declare
loop_cntr number;
row_count number;

begin
row_count := 0;
for loop_cntr in 1 .. 100
loop
select count(*) 
into row_count
from 
(select count(*) from dba_objects union all select count(*) from dba_objects)  ;
dbms_output.put_line('Counted : ' || row_count);
dbms_lock.sleep(1);
end loop;
end;
/

23:23:06 SQL> @run_anon_PLSQL_with_SQLs
Counted : 2
.....
Counted : 2

PL/SQL procedure successfully completed.

23:25:27 SQL> 

I then monitor it from another session. These are some of the snapshots :

SQL> !cat sess_sql_statement.sql
rem Display SQL statement being executed by a session

select to_char(sysdate,'DD-MON HH24:MI:SS') Collection_datestamp, x.last_call_et, x.status, x.sql_id,
y.sql_text
from v$session x, v$sqlarea y
where x.sql_address = y.address
and x.sql_hash_value = y.hash_value
and x.sid = &session_id
/

SQL>
SQL> @sess_sql_statement
Enter value for session_id: 145
old   6: and x.sid = &session_id
new   6: and x.sid = 145

COLLECTION_DATE LAST_CALL_ET STATUS   SQL_ID
--------------- ------------ -------- -------------
SQL_TEXT
------------------------------------------------------------------------------------------------------------------------------------
17-AUG 23:23:22            9 ACTIVE   073f1t1h96dub
declare loop_cntr number; row_count number;  begin row_count := 0; for loop_cntr in 1 .. 100 loop select count(*) into row_count fro
m (select count(*) from dba_objects union all select count(*) from dba_objects)  ; dbms_output.put_line('Counted : ' || row_count);
dbms_lock.sleep(1); end loop; end;


SQL>

COLLECTION_DATE LAST_CALL_ET STATUS   SQL_ID
--------------- ------------ -------- -------------
SQL_TEXT
------------------------------------------------------------------------------------------------------------------------------------
17-AUG 23:23:37           24 ACTIVE   710604h01ux6c
SELECT COUNT(*) FROM (SELECT COUNT(*) FROM DBA_OBJECTS UNION ALL SELECT COUNT(*) FROM DBA_OBJECTS)

COLLECTION_DATE LAST_CALL_ET STATUS   SQL_ID
--------------- ------------ -------- -------------
SQL_TEXT
------------------------------------------------------------------------------------------------------------------------------------
17-AUG 23:23:51           39 ACTIVE   073f1t1h96dub
declare loop_cntr number; row_count number;  begin row_count := 0; for loop_cntr in 1 .. 100 loop select count(*) into row_count fro
m (select count(*) from dba_objects union all select count(*) from dba_objects)  ; dbms_output.put_line('Counted : ' || row_count);
dbms_lock.sleep(1); end loop; end;

COLLECTION_DATE LAST_CALL_ET STATUS   SQL_ID
--------------- ------------ -------- -------------
SQL_TEXT
------------------------------------------------------------------------------------------------------------------------------------
17-AUG 23:24:03           51 ACTIVE   710604h01ux6c
SELECT COUNT(*) FROM (SELECT COUNT(*) FROM DBA_OBJECTS UNION ALL SELECT COUNT(*) FROM DBA_OBJECTS)


COLLECTION_DATE LAST_CALL_ET STATUS   SQL_ID
--------------- ------------ -------- -------------
SQL_TEXT
------------------------------------------------------------------------------------------------------------------------------------
17-AUG 23:24:28           75 ACTIVE   073f1t1h96dub
declare loop_cntr number; row_count number;  begin row_count := 0; for loop_cntr in 1 .. 100 loop select count(*) into row_count fro
m (select count(*) from dba_objects union all select count(*) from dba_objects)  ; dbms_output.put_line('Counted : ' || row_count);
dbms_lock.sleep(1); end loop; end;

COLLECTION_DATE LAST_CALL_ET STATUS   SQL_ID
--------------- ------------ -------- -------------
SQL_TEXT
------------------------------------------------------------------------------------------------------------------------------------
17-AUG 23:24:35           84 ACTIVE   710604h01ux6c
SELECT COUNT(*) FROM (SELECT COUNT(*) FROM DBA_OBJECTS UNION ALL SELECT COUNT(*) FROM DBA_OBJECTS)

COLLECTION_DATE LAST_CALL_ET STATUS   SQL_ID
--------------- ------------ -------- -------------
SQL_TEXT
------------------------------------------------------------------------------------------------------------------------------------
17-AUG 23:24:52           99 ACTIVE   710604h01ux6c
SELECT COUNT(*) FROM (SELECT COUNT(*) FROM DBA_OBJECTS UNION ALL SELECT COUNT(*) FROM DBA_OBJECTS)

COLLECTION_DATE LAST_CALL_ET STATUS   SQL_ID
--------------- ------------ -------- -------------
SQL_TEXT
------------------------------------------------------------------------------------------------------------------------------------
17-AUG 23:25:13          120 ACTIVE   073f1t1h96dub
declare loop_cntr number; row_count number;  begin row_count := 0; for loop_cntr in 1 .. 100 loop select count(*) into row_count fro
m (select count(*) from dba_objects union all select count(*) from dba_objects)  ; dbms_output.put_line('Counted : ' || row_count);
dbms_lock.sleep(1); end loop; end;

COLLECTION_DATE LAST_CALL_ET STATUS   SQL_ID
--------------- ------------ -------- -------------
SQL_TEXT
------------------------------------------------------------------------------------------------------------------------------------
17-AUG 23:25:26          135 ACTIVE   073f1t1h96dub
declare loop_cntr number; row_count number;  begin row_count := 0; for loop_cntr in 1 .. 100 loop select count(*) into row_count fro
m (select count(*) from dba_objects union all select count(*) from dba_objects)  ; dbms_output.put_line('Counted : ' || row_count);
dbms_lock.sleep(1); end loop; end;

SQL> select sid, status, last_call_et, sql_id from v$session where sid=145;

     SID STATUS   LAST_CALL_ET SQL_ID
---------- -------- ------------ -------------
     145 INACTIVE           24

SQL> /

SQL> /

     SID STATUS   LAST_CALL_ET SQL_ID
---------- -------- ------------ -------------
     145 INACTIVE           27

SQL> 

Thus, as long as the session is in an ACTIVE state (i.e. running the anonymous PLSQL block), the LAST_CALL_ET is continously incremented and does not get reset -- whether by the SQL executed in the block or the call to DBMS_LOCK.SLEEP. You will also notice that the SQL_ID reported against the session alternates between the PLSQL block and the SQL that it executes.

Further evidence that there really were 100 executions of the SQL but 1 execution of the PLSQL block :

SQL> select sql_id, sql_fulltext, executions from v$sqlstats where sql_id in ('073f1t1h96dub','710604h01ux6c');

SQL_ID        SQL_FULLTEXT                                                                     EXECUTIONS
------------- -------------------------------------------------------------------------------- ----------
073f1t1h96dub declare                                                                                   1
             loop_cntr number;
             row_count number;

             begin
             row_count := 0;
             for loop_cntr in 1 .. 100
             loop
             select count(*)
             into row_count
             from
             (select count(*) from dba_objects union all select count(*) from dba_objects)  ;

             dbms_output.put_line('Counted : ' || row_count);
             dbms_lock.sleep(1);
             end loop;
             end;

710604h01ux6c SELECT COUNT(*) FROM (SELECT COUNT(*) FROM DBA_OBJECTS UNION ALL SELECT COUNT(*)        100
              FROM DBA_OBJECTS)


SQL> 

Therefore : When the session you are monitoring by LAST_CALL_ET is running PLSQL (whether an anonymous block or a stored procedure), be careful to check LAST_CALL_ET -- it may be the runtime of the PLSQL, not the individual SQL executions within the PLSQL. It does not get reset by each SQL execution.


In the next part I will show whether LAST_CALL_ET relates to FETCH calls.

.
.
.