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.

.
.
.

Trying to understand LAST_CALL_ET -- 1

The LAST_CALL_ET column in V$SESSION is sometimes misunderstood. Is it the Elapsed Time of the Last Call ? What is "Last Call" ? Is it the Last SQL Statement executed ? Or is it the Last Parse/Execute/Fetch Call ?

The documentation states that it is :

If the session STATUS is currently ACTIVE, then the value represents the elapsed time in seconds since the session has become active.

If the session STATUS is currently INACTIVE, then the value represents the elapsed time in seconds since the session has become inactive.

(The 11.2 documentation is no different :

If the session STATUS is currently ACTIVE, then the value represents the elapsed time (in seconds) since the session has become active.

If the session STATUS is currently INACTIVE, then the value represents the elapsed time (in seconds) since the session has become inactive.)

Here is a case where it can be difficult to interpret.
The DBMS_STATS.GATHER_SCHEMA_STATS stored procedure actually executes different SQL statements. The SQL_IDs of those statements appear in V$SESSION but the LAST_CALL_ET does not get reset at the end of each SQL call. It continues to increment until the PLSQL call is completed. (And we are not even talking of the multiple FETCHs that might occur in an SQL SELECT).

From Session 1 (SID 144) I run this :

SQL> set time on
00:01:38 SQL>                                               
00:01:48 SQL> exec dbms_stats.gather_schema_stats('HEMANT');

PL/SQL procedure successfully completed.

00:05:01 SQL> 
00:07:06 SQL> 

What do I see for the Session in the V$SESSION columns SQL_ID and LAST_CALL_ET ?

Here are some "snapshots" gathered from another session that is monitoring SID 144 :
(Note : The schema "HEMANT" has tables list MY_TEST_TABLE, OBJ_LIST, OBJ_LIST_2 and others -- many of which are extracts from DBA_OBJECTS created to test other features. That is why you will see columns that you normally would see in DBA_OBJECTS seeming to appear in the "HEMANT" schema's tables)

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
/
COLLECTION_DATE LAST_CALL_ET STATUS   SQL_ID        SQL_TEXT                                                            
--------------- ------------ -------- ------------- ----------------------------------------------------------------    
16-AUG 00:02:06           16 ACTIVE   cmc06u7m8nu5b insert /*+ append */ into sys.ora_temp_1_ds_234 select /*+ no_pa    
                                               rallel(t) no_parallel_index(t) dbms_stats cursor_sharing_exact u    
                                               se_weak_name_resl dynamic_sampling(0) no_monitoring */"OWNER","O    
                                               BJECT_NAME","SUBOBJECT_NAME","OBJECT_ID","DATA_OBJECT_ID","OBJEC    
                                               T_TYPE","CREATED","LAST_DDL_TIME","TIMESTAMP","STATUS","TEMPORAR    
                                               Y","GENERATED","SECONDARY" from "HEMANT"."MY_TEST_TABLE" sample     
                                               ( 10.9418767507) t 

COLLECTION_DATE LAST_CALL_ET STATUS   SQL_ID        SQL_TEXT                                                             
--------------- ------------ -------- ------------- ----------------------------------------------------------------            
16-AUG 00:02:27           36 ACTIVE   gt3fthdmp0405 select /*+ no_parallel(t) no_parallel_index(t) dbms_stats cursor            
                                                _sharing_exact use_weak_name_resl dynamic_sampling(0) no_monitor     
                                                ing */ count(*),count("OWNER"),count(distinct "OWNER"),sum(sys_o     
                                                p_opnsize("OWNER")),substrb(dump(min("OWNER"),16,0,32),1,120),su     
                                                bstrb(dump(max("OWNER"),16,0,32),1,120),count("OBJECT_NAME"),cou     
                                                nt(distinct "OBJECT_NAME"),sum(sys_op_opnsize("OBJECT_NAME")),su     
                                                bstrb(dump(min(substrb("OBJECT_NAME",1,32)),16,0,32),1,120),subs     
                                                trb(dump(max(substrb("OBJECT_NAME",1,32)),16,0,32),1,120),count(     
                                                "SUBOBJECT_NAME"),count(distinct "SUBOBJECT_NAME"),sum(sys_op_op     
                                                nsize("SUBOBJECT_NAME")),substrb(dump(min("SUBOBJECT_NAME"),16,0     
                                                ,32),1,120),substrb(dump(max("SUBOBJECT_NAME"),16,0,32),1,120),c     
                                                ount("OBJECT_ID"),count(distinct "OBJECT_ID"),sum(sys_op_opnsize     
                                                ("OBJECT_ID")),substrb(dump(min("OBJECT_ID"),16,0,32),1,120),sub     
                                                strb(dump(max("OBJECT_ID"),16,0,32),1,120),count("DATA_OBJECT_ID     
                                                "),count(distinct "DATA_OBJECT_ID"),sum(sys_op_opnsize("DATA_OBJ            
                                                ECT_ID")),substrb(dump(min("DATA_OBJECT_
COLLECTION_DATE LAST_CALL_ET STATUS   SQL_ID        SQL_TEXT                                                             
--------------- ------------ -------- ------------- ----------------------------------------------------------------     
16-AUG 00:03:13           82 ACTIVE   8dhprd5dvwcux select /*+ no_parallel(t) no_parallel_index(t) dbms_stats cursor     
                                                _sharing_exact use_weak_name_resl dynamic_sampling(0) no_monitor     
                                                ing */ count(*),count("OWNER"),count(distinct "OWNER"),sum(sys_o     
                                                p_opnsize("OWNER")),substrb(dump(min("OWNER"),16,0,32),1,120),su     
                                                bstrb(dump(max("OWNER"),16,0,32),1,120),count("OBJECT_NAME"),cou     
                                                nt(distinct "OBJECT_NAME"),sum(sys_op_opnsize("OBJECT_NAME")),su     
                                                bstrb(dump(min(substrb("OBJECT_NAME",1,32)),16,0,32),1,120),subs     
                                                trb(dump(max(substrb("OBJECT_NAME",1,32)),16,0,32),1,120),count(     
                                                "SUBOBJECT_NAME"),count(distinct "SUBOBJECT_NAME"),sum(sys_op_op     
                                                nsize("SUBOBJECT_NAME")),substrb(dump(min("SUBOBJECT_NAME"),16,0     
                                                ,32),1,120),substrb(dump(max("SUBOBJECT_NAME"),16,0,32),1,120),c     
                                                ount("OBJECT_ID"),count(distinct "OBJECT_ID"),sum(sys_op_opnsize     
                                                ("OBJECT_ID")),substrb(dump(min("OBJECT_ID"),16,0,32),1,120),sub     
                                                strb(dump(max("OBJECT_ID"),16,0,32),1,120),count("DATA_OBJECT_ID     
                                                "),count(distinct "DATA_OBJECT_ID"),sum(sys_op_opnsize("DATA_OBJ     
                                                ECT_ID")),substrb(dump(min("DATA_OBJECT_
COLLECTION_DATE LAST_CALL_ET STATUS   SQL_ID        SQL_TEXT                                                             
--------------- ------------ -------- ------------- ----------------------------------------------------------------     
16-AUG 00:03:40          109 ACTIVE   618vpumzuqtrn select /*+ no_parallel(t) no_parallel_index(t) dbms_stats cursor     
                                                _sharing_exact use_weak_name_resl dynamic_sampling(0) no_monitor     
                                                ing */ count(*),count("OBJECT_NAME"),count(distinct "OBJECT_NAME     
                                                "),count("SUBOBJECT_NAME"),count(distinct "SUBOBJECT_NAME"),sum(     
                                                sys_op_opnsize("SUBOBJECT_NAME")),substrb(dump(min("SUBOBJECT_NA     
                                                ME"),16,0,32),1,120),substrb(dump(max("SUBOBJECT_NAME"),16,0,32)     
                                                ,1,120),count("OBJECT_ID"),count(distinct "OBJECT_ID"),count("DA     
                                                TA_OBJECT_ID"),count(distinct "DATA_OBJECT_ID"),sum(sys_op_opnsi     
                                                ze("DATA_OBJECT_ID")),substrb(dump(min("DATA_OBJECT_ID"),16,0,32     
                                                ),1,120),substrb(dump(max("DATA_OBJECT_ID"),16,0,32),1,120) from     
                                                 "HEMANT"."OBJ_LIST_2" sample (   .3397677313) t     

COLLECTION_DATE LAST_CALL_ET STATUS   SQL_ID        SQL_TEXT                                                             
--------------- ------------ -------- ------------- ----------------------------------------------------------------     
16-AUG 00:05:05            2 INACTIVE 579mnkw55uz8w BEGIN dbms_stats.gather_schema_stats('HEMANT'); END;
COLLECTION_DATE LAST_CALL_ET STATUS   SQL_ID        SQL_TEXT                                                             
--------------- ------------ -------- ------------- ----------------------------------------------------------------     
16-AUG 00:05:23           20 INACTIVE 579mnkw55uz8w BEGIN dbms_stats.gather_schema_stats('HEMANT'); END;                        

COLLECTION_DATE LAST_CALL_ET STATUS   SQL_ID        SQL_TEXT                                                             
--------------- ------------ -------- ------------- ----------------------------------------------------------------     
16-AUG 00:07:16          134 INACTIVE 579mnkw55uz8w BEGIN dbms_stats.gather_schema_stats('HEMANT'); END;

SQL> select sql_fulltext from v$sqlstats where sql_id  = '579mnkw55uz8w';                                                
SQL_FULLTEXT                                                                                                             
--------------------------------------------------------------------------------                                         
BEGIN dbms_stats.gather_schema_stats('HEMANT'); END;                                                                     

The DBMS_STATS.GATHER_SCHEMA_STATS procedure actually ran a large number of *separate* SQL statements. I capture a few of them by querying V$SESSION and joining to V$SQLAREA to get the SQL_TEXT.
Even though each SQL execution is a new set of PARSE-EXECUTE-FETCH calls, the LAST_CALL_ET does not reset to zero. It keeps incrementing until the Procedure (GATHER_SCHEMA_STATS) completes execution.
At completion, LAST_CALL_ET is reset to zero. Thereafter, with the session being INACTIVE, it again starts incrementing -- now it shows the Inactive time. (That is, it shows "how many seconds has it been since the last execution completed" when no execution is running !).

I have presented one case where it seems that multiple SQLs are called and yet LAST_CALL_ET shows the total time for *all* the SQLs executed by the DBMS_STATS.GATHER_SCHEMA_STATS procedure. In this case, you will need to remember that the LAST_CALL_ET reports the PLSQL procedure time, not the SQL time.

Later I will present a few other cases.
.
.
.

Oracle Mergers and Acquisitions

The softwareadvice blog has written a list of Oracle Mergers and Acquisitions and attempts to gaze into the crystal ball to identify future acquisitions.

.

.

.

Creating a "Sparse" Index

Without the advantage of segmentless (i.e. zero-sized) index partitions that are available in 11gR2, I still attempt to create "sparse" Index Partitions in this example in 10.2.0.4 :

SQL> drop table MY_ORDERS_TABLE purge;

Table dropped.

SQL> 
SQL> create table MY_ORDERS_TABLE
  2  (order_id     number not null,
  3   order_date   date not null,
  4   customer_id  number not null,
  5   product_id   varchar2(1) not null,
  6   quantity     number,
  7   rate         number,
  8   comments     varchar2(64)
  9  )
 10  partition by range (order_date)
 11  subpartition by list (product_id)
 12   (partition ord_2005 values less than (to_date('01-JAN-2006','DD-MON-YYYY'))
 13     (subpartition ord_2005_a values ('A'),
 14      subpartition ord_2005_b values ('B'),
 15      subpartition ord_2005_c values ('C')),
 16   partition ord_2006 values less than (to_date('01-JAN-2007','DD-MON-YYYY'))
 17     (subpartition ord_2006_a values ('A'),
 18      subpartition ord_2006_b values ('B'),
 19      subpartition ord_2006_c values ('C')),
 20   partition ord_2007 values less than (to_date('01-JAN-2008','DD-MON-YYYY'))
 21     (subpartition ord_2007_a values ('A'),
 22      subpartition ord_2007_b values ('B'),
 23      subpartition ord_2007_c values ('C')),
 24   partition ord_2008 values less than (to_date('01-JAN-2009','DD-MON-YYYY'))
 25     (subpartition ord_2008_a values ('A'),
 26      subpartition ord_2008_b values ('B'),
 27      subpartition ord_2008_c values ('C')))
 28  /

Table created.

SQL> 
SQL> create index MY_ORDERS_IDX on MY_ORDERS_TABLE (order_id,customer_id,product_id) local UNUSABLE;

Index created.

SQL> 
SQL> select partition_name, subpartition_name, status from user_ind_subpartitions
  2  where index_name =  'MY_ORDERS_IDX'
  3  order by 1,2
  4  /

PARTITION_NAME                 SUBPARTITION_NAME              STATUS
------------------------------ ------------------------------ --------
ORD_2005                       ORD_2005_A                     UNUSABLE
ORD_2005                       ORD_2005_B                     UNUSABLE
ORD_2005                       ORD_2005_C                     UNUSABLE
ORD_2006                       ORD_2006_A                     UNUSABLE
ORD_2006                       ORD_2006_B                     UNUSABLE
ORD_2006                       ORD_2006_C                     UNUSABLE
ORD_2007                       ORD_2007_A                     UNUSABLE
ORD_2007                       ORD_2007_B                     UNUSABLE
ORD_2007                       ORD_2007_C                     UNUSABLE
ORD_2008                       ORD_2008_A                     UNUSABLE
ORD_2008                       ORD_2008_B                     UNUSABLE
ORD_2008                       ORD_2008_C                     UNUSABLE

12 rows selected.

SQL> 
SQL> insert into MY_ORDERS_TABLE
  2  select rownum,
  3  to_date('30-JUN-2008','DD-MON-YYYY'),
  4  decode(mod(rownum,100),0,1,200),
  5  decode(mod(rownum,10),0,'A',1,'A',2,'A',3,'A',4,'A',5,'B',6,'B',7,'B',8,'B','C'),
  6  4,
  7  3,
  8  'Orders on 30Jun2008'
  9  from dual connect by level < 35000
 10  /

34999 rows created.

SQL> 
SQL> commit;

Commit complete.

SQL> 
SQL> alter index MY_ORDERS_IDX rebuild subpartition ord_2008_a ;

Index altered.

SQL> alter index MY_ORDERS_IDX rebuild subpartition ord_2008_b ;

Index altered.

SQL> alter index MY_ORDERS_IDX rebuild subpartition ord_2008_c ;

Index altered.

SQL> 
SQL> 
SQL> select partition_name, subpartition_name, status from user_ind_subpartitions
  2  where index_name =  'MY_ORDERS_IDX'
  3  order by 1,2
  4  /

PARTITION_NAME                 SUBPARTITION_NAME              STATUS
------------------------------ ------------------------------ --------
ORD_2005                       ORD_2005_A                     UNUSABLE
ORD_2005                       ORD_2005_B                     UNUSABLE
ORD_2005                       ORD_2005_C                     UNUSABLE
ORD_2006                       ORD_2006_A                     UNUSABLE
ORD_2006                       ORD_2006_B                     UNUSABLE
ORD_2006                       ORD_2006_C                     UNUSABLE
ORD_2007                       ORD_2007_A                     UNUSABLE
ORD_2007                       ORD_2007_B                     UNUSABLE
ORD_2007                       ORD_2007_C                     UNUSABLE
ORD_2008                       ORD_2008_A                     USABLE
ORD_2008                       ORD_2008_B                     USABLE
ORD_2008                       ORD_2008_C                     USABLE

12 rows selected.

SQL> 
SQL> select partition_name, bytes/1024 from user_segments
  2  where segment_type like 'INDEX SUBPARTITION'
  3  order by 1
  4  /

PARTITION_NAME                 BYTES/1024
------------------------------ ----------
ORD_2005_A                             64
ORD_2005_B                             64
ORD_2005_C                             64
ORD_2006_A                             64
ORD_2006_B                             64
ORD_2006_C                             64
ORD_2007_A                             64
ORD_2007_B                             64
ORD_2007_C                             64
ORD_2008_A                            512
ORD_2008_B                            384
ORD_2008_C                            128

12 rows selected.

SQL> 
SQL> exec dbms_stats.gather_table_stats(user,'MY_ORDERS_TABLE',estimate_percent=>100,-
>                                          granularity=>'PARTITION',partname=>'ORD_2008',cascade=>FALSE);

PL/SQL procedure successfully completed.

SQL> exec dbms_stats.gather_index_stats(user,'MY_ORDERS_IDX',estimate_percent=>100,-
>                                          granularity=>'PARTITION',partname=>'ORD_2008');

PL/SQL procedure successfully completed.

SQL> 
SQL> explain plan for
  2  select order_date, customer_id from MY_ORDERS_TABLE
  3  where
  4  order_date = to_date('30-JUN-2008','DD-MON-YYYY')
  5  and
  6  product_id='C'
  7  and order_id between 30 and 100
  8  and customer_id=1
  9  /

Explained.

SQL> 
SQL> select * from table(dbms_xplan.display);

PLAN_TABLE_OUTPUT
------------------------------------------------------------------------------------------------------------------------------------
Plan hash value: 2230053563

-----------------------------------------------------------------------------------------------------------------------
| Id  | Operation                           | Name            | Rows  | Bytes | Cost (%CPU)| Time     | Pstart| Pstop |
-----------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                    |                 |     1 |    37 |     3   (0)| 00:00:01 |       |       |
|   1 |  PARTITION RANGE SINGLE             |                 |     1 |    37 |     3   (0)| 00:00:01 |     4 |     4 |
|   2 |   PARTITION LIST SINGLE             |                 |     1 |    37 |     3   (0)| 00:00:01 |     3 |     3 |
|*  3 |    TABLE ACCESS BY LOCAL INDEX ROWID| MY_ORDERS_TABLE |     1 |    37 |     3   (0)| 00:00:01 |    12 |    12 |
|*  4 |     INDEX RANGE SCAN                | MY_ORDERS_IDX   |     1 |       |     2   (0)| 00:00:01 |    12 |    12 |
-----------------------------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

   3 - filter("ORDER_DATE"=TO_DATE(' 2008-06-30 00:00:00', 'syyyy-mm-dd hh24:mi:ss'))
   4 - access("ORDER_ID">=30 AND "CUSTOMER_ID"=1 AND "PRODUCT_ID"='C' AND "ORDER_ID"<=100)
       filter("CUSTOMER_ID"=1)

Note
-----
   - dynamic sampling used for this statement

22 rows selected.

SQL> 

I have to be very careful with my GATHER_%_STATS calls -- any attempt to permit Global statistics fails as Oracle finds some Index partitions unusable.
Also, in the absence of Global statistics, the optimizer still reverts to Dynamic Sampling.

.
.
.