Archive for the ‘ Oracle ’ Category

ORA-06553: PLS-306: wrong number or types of arguments in call to ‘OGC_Y’ while exporting table

Recently i had faced “ORA-06553: PLS-306:” error while taking an export using expdp for table using “query” parameter.

$ expdp directory=TEST_DPUMP_DIR  dumpfile=test_url.dmp logfile=test_url.log tables=anand.test_delete_objects query=\"WHERE processed_flag = 'Y'\"

Export: Release 11.2.0.3.0 - Production on Tue May 29 00:24:25 2012

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

Username: system
Password:

Connected to: Oracle Database 11g Enterprise Edition Release 11.2.0.3.0 - 64bit Production
With the Partitioning, Real Application Clusters, OLAP, Data Mining
and Real Application Testing options
Starting "SYSTEM"."SYS_EXPORT_TABLE_01":  system/******** directory=TEST_DPUMP_DIR dumpfile=test_url.dmp logfile=test_url.log tables=anand.test_delete_objects query="WHERE processed_flag = Y"
Estimate in progress using BLOCKS method...
Processing object type TABLE_EXPORT/TABLE/TABLE_DATA
Total estimation using BLOCKS method: 112 MB
Processing object type TABLE_EXPORT/TABLE/TABLE
Processing object type TABLE_EXPORT/TABLE/GRANT/OWNER_GRANT/OBJECT_GRANT
Processing object type TABLE_EXPORT/TABLE/INDEX/INDEX
Processing object type TABLE_EXPORT/TABLE/INDEX/STATISTICS/INDEX_STATISTICS
Processing object type TABLE_EXPORT/TABLE/STATISTICS/TABLE_STATISTICS
ORA-31693: Table data object "ANAND"."TEST_DELETE_OBJECTS" failed to load/unload and is being skipped due to error:
ORA-06553: PLS-306: wrong number or types of arguments in call to 'OGC_Y'
Master table "SYSTEM"."SYS_EXPORT_TABLE_01" successfully loaded/unloaded
******************************************************************************
Dump file set for SYSTEM.SYS_EXPORT_TABLE_01 is:
  /exp/kmportal_dpump_dir/test_url.dmp
Job "SYSTEM"."SYS_EXPORT_TABLE_01" completed with 1 error(s) at 00:25:50

The export completes successfully if we use parfile

$ expdp parfile=test_url.lst

Export: Release 11.2.0.3.0 - Production on Tue May 29 00:53:49 2012

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

Username: system
Password:

Connected to: Oracle Database 11g Enterprise Edition Release 11.2.0.3.0 - 64bit Production
With the Partitioning, Real Application Clusters, OLAP, Data Mining
and Real Application Testing options
Starting "SYSTEM"."SYS_EXPORT_TABLE_01":  system/******** parfile=test_url.lst
Estimate in progress using BLOCKS method...
Processing object type TABLE_EXPORT/TABLE/TABLE_DATA
Total estimation using BLOCKS method: 112 MB
Processing object type TABLE_EXPORT/TABLE/TABLE
Processing object type TABLE_EXPORT/TABLE/GRANT/OWNER_GRANT/OBJECT_GRANT
Processing object type TABLE_EXPORT/TABLE/INDEX/INDEX
Processing object type TABLE_EXPORT/TABLE/INDEX/STATISTICS/INDEX_STATISTICS
Processing object type TABLE_EXPORT/TABLE/STATISTICS/TABLE_STATISTICS
. . exported "ANAND"."TEST_DELETE_OBJECTS"           10.09 KB      38 rows
Master table "SYSTEM"."SYS_EXPORT_TABLE_01" successfully loaded/unloaded
******************************************************************************
Dump file set for SYSTEM.SYS_EXPORT_TABLE_01 is:
  /exp/kmportal_dpump_dir/test_url.dmp
Job "SYSTEM"."SYS_EXPORT_TABLE_01" successfully completed at 00:54:39


$ more test_url.lst
directory=TEST_DPUMP_DIR
dumpfile=test_url.dmp
logfile=test_url.log
tables=anand.test_delete_objects
query="WHERE processed_flag = 'Y'"

So,i was little confused until i came across Jonathan Lewis’s comments on the below blog

http://jonathanlewis.wordpress.com/2010/01/26/aliases/

Unfortunately, if you’ve installed Spatial, there are two functions (called ogc_x and ogc_y) which has been given public synonyms X and Y respectively that move Oracle into the function-call validity checks – which is where the pls error comes from.

SYS > select owner,SYNONYM_NAME,TABLE_OWNER,TABLE_NAME from dba_synonyms where SYNONYM_NAME='Y';

OWNER      SYNONYM_NAME                   TABLE_OWNER                    TABLE_NAME
---------- ------------------------------ ------------------------------ -------------------------
PUBLIC     Y                              MDSYS                          OGC_Y

1 row selected.

SYS > select owner,SYNONYM_NAME,TABLE_OWNER,TABLE_NAME from dba_synonyms where SYNONYM_NAME='X';

OWNER      SYNONYM_NAME                   TABLE_OWNER                    TABLE_NAME
---------- ------------------------------ ------------------------------ -------------------------
PUBLIC     X                              MDSYS                          OGC_X

1 row selected.

So to run it succsfully from the command line

$ expdp directory=TEST_DPUMP_DIR dumpfile=test_url_test.dmp logfile=test_url_test.log tables=anand.test_delete_objects query=\"WHERE processed_flag = \'Y\'\"

Export: Release 11.2.0.3.0 - Production on Tue May 29 01:11:44 2012

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

Username: system
Password:

Connected to: Oracle Database 11g Enterprise Edition Release 11.2.0.3.0 - 64bit Production
With the Partitioning, Real Application Clusters, OLAP, Data Mining
and Real Application Testing options
Starting "SYSTEM"."SYS_EXPORT_TABLE_01":  system/******** directory=TEST_DPUMP_DIR dumpfile=test_url_test.dmp logfile=test_url_test.log tables=anand.test_delete_objects query="WHERE processed_flag = 'Y'"
Estimate in progress using BLOCKS method...
Processing object type TABLE_EXPORT/TABLE/TABLE_DATA
Total estimation using BLOCKS method: 112 MB
Processing object type TABLE_EXPORT/TABLE/TABLE
Processing object type TABLE_EXPORT/TABLE/GRANT/OWNER_GRANT/OBJECT_GRANT
Processing object type TABLE_EXPORT/TABLE/INDEX/INDEX
Processing object type TABLE_EXPORT/TABLE/INDEX/STATISTICS/INDEX_STATISTICS
Processing object type TABLE_EXPORT/TABLE/STATISTICS/TABLE_STATISTICS
. . exported "ANAND"."TEST_DELETE_OBJECTS"           10.09 KB      38 rows
Master table "SYSTEM"."SYS_EXPORT_TABLE_01" successfully loaded/unloaded
******************************************************************************
Dump file set for SYSTEM.SYS_EXPORT_TABLE_01 is:
  /exp/kmportal_dpump_dir/test_url_test.dmp
Job "SYSTEM"."SYS_EXPORT_TABLE_01" successfully completed at 01:12:24

Mining DDL from LogMiner

One may sometimes need to find the ddl which ran on the database at some certain period of time.If auditing is enabled for the you can get the details using various *_audit_* views. In case, its not and the database is in archivelog mode you can try using logminer.Here is an example for it –

From SYS session –

14:57:56 SQL> select supplemental_log_data_min from v$database;

SUPPLEME
--------
YES

14:58:11 SQL>
14:58:11 SQL>
14:58:11 SQL> archive log list
Database log mode              Archive Mode
Automatic archival             Enabled
Archive destination            D:\oracle\archive\catdb
Oldest online log sequence     24
Next log sequence to archive   26
Current log sequence           26
14:58:36 SQL>
14:58:36 SQL>
14:58:36 SQL> alter system switch logfile;

System altered.

14:58:41 SQL> archive log list
Database log mode              Archive Mode
Automatic archival             Enabled
Archive destination            D:\oracle\archive\catdb
Oldest online log sequence     25
Next log sequence to archive   27
Current log sequence           27
14:58:43 SQL>

Logged in as ANAND user and did some DDLs

14:58:59 SQL> show user
USER is "ANAND"
14:59:01 SQL>
14:59:01 SQL>
14:59:01 SQL> create table test_log (a number,b number);

Table created.

14:59:15 SQL>
14:59:15 SQL> insert into test_log values (1,1);

1 row created.

14:59:23 SQL> insert into test_log values (1,2);

1 row created.

14:59:25 SQL> insert into test_log values (2,2);

1 row created.

14:59:27 SQL> insert into test_log values (2,1);

1 row created.

14:59:29 SQL>
14:59:30 SQL>
14:59:30 SQL> commit;

Commit complete.

14:59:31 SQL>
14:59:31 SQL> select * from test_log;

         A          B
---------- ----------
         1          1
         1          2
         2          2
         2          1

14:59:36 SQL>
14:59:37 SQL>
14:59:37 SQL>
15:01:35 SQL>
15:01:35 SQL> alter table test_log add (c number);

Table altered.

15:01:49 SQL>
15:01:49 SQL>
15:01:50 SQL> insert into test_log values (1,1,1);

1 row created.

15:01:55 SQL> insert into test_log values (1,1,2);

1 row created.

15:01:58 SQL> insert into test_log values (1,2,2);

1 row created.

15:02:00 SQL> insert into test_log values (2,2,2);

1 row created.

15:02:03 SQL> insert into test_log values (2,1,1);

1 row created.

15:02:08 SQL> commit;

Commit complete.

15:02:10 SQL>
15:02:10 SQL>
15:02:11 SQL>
15:02:11 SQL> select * from test_log;

         A          B          C
---------- ---------- ----------
         1          1
         1          2
         2          2
         2          1
         1          1          1
         1          1          2
         1          2          2
         2          2          2
         2          1          1

9 rows selected.

15:02:16 SQL>
15:12:02 SQL>
15:12:03 SQL>
16:08:39 SQL>
16:08:39 SQL>
16:08:40 SQL>
16:08:40 SQL> truncate table test_log;

Table truncated.

16:08:50 SQL>
16:08:51 SQL>
16:08:51 SQL>
16:08:51 SQL>
16:21:53 SQL>
16:21:53 SQL>
16:21:53 SQL> drop table test_log;

Table dropped.

As sys user

15:13:27 SQL> archive log list
Database log mode              Archive Mode
Automatic archival             Enabled
Archive destination            D:\oracle\archive\catdb
Oldest online log sequence     25
Next log sequence to archive   27
Current log sequence           27
16:22:01 SQL>
16:22:01 SQL>
16:22:02 SQL> alter system switch logfile;

System altered.

16:22:06 SQL> alter system switch logfile;

System altered.

16:22:27 SQL>

So archive log 27 has the details

16:23:28 SQL> ALTER SESSION SET NLS_DATE_FORMAT = 'DD-MON-YYYY HH24:MI:SS';16:31:35 

SQL> EXECUTE dbms_logmnr.add_logfile(LogFileName=>'D:\oracle\archive\catdb\ARC0000000027_0785160155.0001',OPTIONS => DBMS_LOGMNR.NEW);

PL/SQL procedure successfully completed.

Elapsed: 00:00:00.29
16:31:48 SQL> EXECUTE dbms_logmnr.add_logfile(LogFileName=>'D:\oracle\archive\catdb\ARC0000000028_0785160155.0001',OPTIONS => DBMS_LOGMNR.ADDFILE);

PL/SQL procedure successfully completed.

Elapsed: 00:00:00.01

16:33:21 SQL> select filename,low_time,high_time,DICTIONARY_BEGIN,DICTIONARY_END from v$LOGMNR_LOGS;

FILENAME                                                               LOW_TIME             HIGH_TIME            DIC DIC
---------------------------------------------------------------------- -------------------- -------------------- --- ---
D:\oracle\archive\catdb\ARC0000000027_0785160155.0001                  12-JUN-2012 14:58:41 12-JUN-2012 16:22:06 NO  NO
D:\oracle\archive\catdb\ARC0000000028_0785160155.0001                  12-JUN-2012 16:22:06 12-JUN-2012 16:22:27 NO  NO

16:35:01 SQL> EXECUTE dbms_logmnr.start_logmnr(OPTIONS =>DBMS_LOGMNR.DDL_DICT_TRACKING +DBMS_LOGMNR.PRINT_PRETTY_SQL);

PL/SQL procedure successfully completed.

16:41:44 SQL> select username,OPERATION,TIMESTAMP,TABLE_NAME,SESSION#,SERIAL#,SQL_REDO from  V$LOGMNR_CONTENTS where SEG_OWNER='ANAND';

USERNAME   OPERATION                        TIMESTAMP            TABLE_NAME                         SESSION#    SERIAL# SQL_REDO
---------- -------------------------------- -------------------- -------------------------------- ---------- ---------- ------------------------------------------------------------
ANAND      DDL                              12-JUN-2012 14:59:14 TEST_LOG                             191            95 create table test_log (a number,b number);
ANAND      DDL                              12-JUN-2012 15:01:49 TEST_LOG                             191            95 alter table test_log add (c number);
ANAND      DDL                              12-JUN-2012 16:08:50 TEST_LOG                             191            95 truncate table test_log;
ANAND      DDL                              12-JUN-2012 16:21:58 TEST_LOG                             191            95 ALTER TABLE "ANAND"."TEST_LOG" RENAME TO "BIN$R2yT2OHzRhGspu
                                                                                                                5YAsnXPw==$0" ;

ANAND      DDL                              12-JUN-2012 16:21:58 TEST_LOG                             191            95 drop table test_log AS "BIN$R2yT2OHzRhGspu5YAsnXPw==$0" ;

If supplemental logging is not enabled, some columns of the view would have UNKNOWN value.It could be difficult in that case to identify the user and session information details.

Index Range Scan and db file scattered read as session wait event

I was asked to check a session which was running for more than expected time on 11.2.0.3 single instance database.The session was running a simple select statement

05:03:09 SYS@xx4040 > @sqlid 9kpjtkdz1mzus
old   9:        sql_id = ('&1')
new   9:        sql_id = ('9kpjtkdz1mzus')

SQL_ID        HASH_VALUE SQL_TEXT
------------- ---------- ------------------------------------------------------------------------------------------------------------------------------------------------------
9kpgmndz1mzus 2115632984 SELECT SC.ID FROM user.s_seq_cd SC WHERE SC.TYPE_CD <> 'CMOD' AND SC.URGENCY_CD IS NOT NULL AND SC.STAT_ID = 'Closed'

1 row selected.

Elapsed: 00:00:00.00
old  26:        sql_id = ('&1')
new  26:        sql_id = ('9kpjtkdz1mzus')

 CH# PARENT_HANDLE    OBJECT_HANDLE     PLAN_HASH OPT_COST     PARSES   H_PARSES EXECUTIONS    FETCHES ROWS_PROCESSED     CPU_MS     ELA_MS    AVG_ELA       LIOS       PIOS      SORTS USERS_EXECUTING
---- ---------------- ---------------- ---------- -------- ---------- ---------- ---------- ---------- -------------- ---------- ---------- ---------- ---------- ---------- ---------- ---------------
   0 00000001C76435E8 00000001C7640D80 3122863050    18774          1          1          1         56         229376   1148.076 1659299.43 1659.29943     228000     209064          0        1

1 row selected.
SQL_ID  9kpjtkdz1mzus, child number 0
-------------------------------------
SELECT SC.ID FROM USER.S_SEQ_CD SR WHERE SC.TYPE_CD <>
'CMOD' AND SC.URGENCY_CD IS NOT NULL AND SC.STAT_ID = 'Closed'

Plan hash value: 3122863050

-----------------------------------------------------------------------------------------------
| Id  | Operation                   | Name            | Rows  | Bytes | Cost (%CPU)| Time     |
-----------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT            |                 |       |       | 18774 (100)|          |
|*  1 |  TABLE ACCESS BY INDEX ROWID| S_SEQ_CD        |   630K|    54M| 18774   (1)| 00:03:46 |
|*  2 |   INDEX RANGE SCAN          | S_SEQ_CD_M28_X  |    12M|       |   552   (1)| 00:00:07 |
-----------------------------------------------------------------------------------------------

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

   1 - filter(("SC"."URGENCY_CD" IS NOT NULL AND "SC"."TYPE_CD"<>'CMOD'))
   2 - access("SC"."STAT_ID"='Closed')

On checking the session wait event it showed “db file scattered read”

05:12:01 SYS@xx4040 > @asw

USERNAME               SID    SERIAL# SPID                     MACHINE              EVENT                                    SQL_ID         WAIT_TIME SECONDS_IN_WAIT STATE
--------------- ---------- ---------- ------------------------ -------------------- ---------------------------------------- ------------- ---------- --------------- -------------------
USER                  575        331 9292                     xxxxxxxx              db file scattered read                   9kpjtkdz1mzus          0               0 WAITING

As per the plan i was expecting “db file sequential read” but seeing “db file scattered read” was little shocking to me. Traced the session at 10046 level 12, which showed

.......................
WAIT #47616080937272: nam='db file parallel read' ela= 39297 files=1 blocks=7 requests=7 obj#=55745 tim=1338199998917111
WAIT #47616080937272: nam='db file scattered read' ela= 3226 file#=60 block#=71137 blocks=8 obj#=55745 tim=1338199998920723
WAIT #47616080937272: nam='db file scattered read' ela= 15988 file#=60 block#=71145 blocks=7 obj#=55745 tim=1338199998936973

*** 2012-05-28 05:13:18.945
WAIT #47616080937272: nam='db file scattered read' ela= 7994 file#=60 block#=71152 blocks=9 obj#=55745 tim=1338199998945414
WAIT #47616080937272: nam='db file scattered read' ela= 7164 file#=60 block#=71161 blocks=7 obj#=55745 tim=1338199998952955
WAIT #47616080937272: nam='db file scattered read' ela= 9505 file#=60 block#=71169 blocks=7 obj#=55745 tim=1338199998963139
WAIT #47616080937272: nam='db file sequential read' ela= 5597 file#=60 block#=71168 blocks=1 obj#=55745 tim=1338199998968993
WAIT #47616080937272: nam='db file scattered read' ela= 9685 file#=60 block#=71176 blocks=7 obj#=55745 tim=1338199998978860
WAIT #47616080937272: nam='db file scattered read' ela= 8081 file#=60 block#=71183 blocks=8 obj#=55745 tim=1338199998987329
WAIT #47616080937272: nam='db file sequential read' ela= 5535 file#=30 block#=156495 blocks=1 obj#=55745 tim=1338199998993023
WAIT #47616080937272: nam='db file scattered read' ela= 17117 file#=60 block#=71191 blocks=7 obj#=55745 tim=1338199999010375
WAIT #47616080937272: nam='db file sequential read' ela= 14412 file#=114 block#=475510 blocks=1 obj#=531936 tim=1338199999025129
........................
........................
05:27:25 SYS@xx4040 > select object_name from dba_objects where object_id=531936;

OBJECT_NAME
----------------------------------------
S_SEQ_CD_M28_X

05:20:35 SYS@xx4040 > select object_name from dba_objects where object_id=55745;

OBJECT_NAME
----------------------------------------
S_SEQ_CD

Then i came across

http://www.freelists.org/post/oracle-l/RE-Calculating-LIOs,11

If a regular index index full or range scan causes “multiblock” reads, it is due index prefetching which is up to optimizer to decide.Index prefetching means that when doing a range or full scan, then Oracle will read the index by traversing the index tree, but it reads the tree several blocks at a time (for example, it gets a number of logically
consecutive leaf block addresses from branch block and reads a batch of leafs in).

So this is a *noncontiguous* multiblock read, meaning that Oracle just issues multiple single block read requests in one batch. This should result in a “db file parallel read” wait. So, asynch IO should definitely be used when relying on index prefetch, otherwise your performance might degrade, especially when some of the prefetched blocks don’t get used at all.

CKPT process maintains statistics history in X$KCBKPFS (kernel cache buffer k? pre-fetch statistics) about wasted prefetched blocks.(Luckily this x$ table’s columns are written in english not just abbreviations). So if sessions start hitting a lot of never pinned prefetch blocks, the x$kcbkpfs statistics start to indicate inefficient prefetching, thus causing CBO not to favour it and prefer regular single block reads.

Index full scans are the main candidates which may benefit from prefetch,since a full scan needs to read all leaf blocks anyway, thus not risking with prefetch wastage. However, in order to prefetch batches of leaf blocks
you have to read in the branch blocks “above” it, causing some extra IO (for regular single block index full scan you only have to read in branch blocks from root to first or last leaf block in tree). Note that I’m only concluding my last claim, I’ve not done testing to see whether extra branch blocks actually happen – but I don’t see any other way
how to find out DBAs of next leaf block batch.

You can control prefetching with parameters:

_index_prefetch_factor – defaults to 100, but when changed smaller, the optimizer will favor index prefetching.
_db_file_noncontig_mblock_read_count – maximum number of blocks to be prefetched in one batch. If set to 1, prefetching should be disabled.

There is an event 10299 which traces prefetch operations and if you set it to CKPT process you’ll see some aggregate statistics as well, also there area lot of %prefetch% statistics in v$sesstat & v$sysstat

On checking the session stat for prefetch -

05:45:59 SYS@xx4040 > select name,value from v$sesstat s, v$statname n where s.statistic# = n.statistic# and s.sid = 575 and n.name like '%prefetch%' order by name;

NAME                                                    VALUE
-------------------------------------------------- ----------
index crx upgrade (prefetch)                                0
physical reads cache prefetch                          454875
physical reads prefetch warmup                              0
prefetch clients - 16k                                      0
prefetch clients - 2k                                       0
prefetch clients - 32k                                      0
prefetch clients - 4k                                       0
prefetch clients - 8k                                       0
prefetch clients - default                                  1
prefetch clients - keep                                     0
prefetch clients - recycle                                  0
prefetch warmup blocks aged out before use              26826
prefetch warmup blocks flushed out before use               0
prefetched blocks aged out before use                     468

The value for “physical reads cache prefetch” increased to 533260 and after this consistent value, the session wait started showing db file sequential read.

06:44:18 SYS@xx4040 > select * from X$KCBKPFS where WASTED_BLOCKS > 0;

no rows selected

Elapsed: 00:00:00.00
06:44:27 SYS@xx4040 > select * from X$KCBKPFS where PREFETCH_BLOCKS> 0;

ADDR                   INDX    INST_ID BUFFER_POOL_ID  TIMESTAMP PREFETCH_OPS PREFETCH_BLOCKS WASTED_BLOCKS CLIENTS_PREFETCH PREFETCH_LIMIT
---------------- ---------- ---------- -------------- ---------- ------------ --------------- ------------- ---------------- --------------
00002B70873F6598        100          1              3   14781146          663            4619             0                7           9376
00002B70873F6598        101          1              3   14784346          780            5428             0                7           9376
00002B70873F6598        102          1              3   14788166         1161            8074             0                7           9376
........................
........................
00002B70873F6598        148          1              3   14773386         1159            8077             0                7           9376
00002B70873F6598        149          1              3   14778066         1093            7626             0                7           9376

49 rows selected.

Some important parameters set regarding it -

SYS@xx4040 > @hidden_param
Enter value for parameter: _db_file_noncontig_mblock_read_count
Enter value for 1: _db_file_noncontig_mblock_read_count
old  11: AND    a.ksppinm = DECODE(LOWER('&parameter'), 'all', a.ksppinm, LOWER('&1'))
new  11: AND    a.ksppinm = DECODE(LOWER('_db_file_noncontig_mblock_read_count'), 'all', a.ksppinm, LOWER('_db_file_noncontig_mblock_read_count'))

PARAMETER                             DESCRIPTION                    SESSION_VA INSTANCE_V
------------------------------------- ------------------------------ ---------- ----------
_db_file_noncontig_mblock_read_count  number of noncontiguous db     11         11
                                      blocks to be prefetched


1 row selected.

SYS@xx4040 > /
Enter value for parameter: _db_cache_pre_warm
Enter value for 1: _db_cache_pre_warm
old  11: AND    a.ksppinm = DECODE(LOWER('&parameter'), 'all', a.ksppinm, LOWER('&1'))
new  11: AND    a.ksppinm = DECODE(LOWER('_db_cache_pre_warm'), 'all', a.ksppinm, LOWER('_db_cache_pre_warm'))

PARAMETER                             DESCRIPTION                    SESSION_VA INSTANCE_V
------------------------------------- ------------------------------ ---------- ----------
_db_cache_pre_warm                    Buffer Cache Pre-Warm Enabled  TRUE       TRUE
                                      : hidden parameter


1 row selected.

SYS@xx4040 > /
Enter value for parameter: _index_prefetch_factor
Enter value for 1: _index_prefetch_factor
old  11: AND    a.ksppinm = DECODE(LOWER('&parameter'), 'all', a.ksppinm, LOWER('&1'))
new  11: AND    a.ksppinm = DECODE(LOWER('_index_prefetch_factor'), 'all', a.ksppinm, LOWER('_index_prefetch_factor'))

PARAMETER                             DESCRIPTION                    SESSION_VA INSTANCE_V
------------------------------------- ------------------------------ ---------- ----------
_index_prefetch_factor                index prefetching factor       100        100

1 row selected.

SYS@xx4040 > show parameter sga_target

NAME                                 TYPE        VALUE
------------------------------------ ----------- ------------------------------
sga_target                           big integer 6G

SYS@xx4040 > show parameter multiblock

NAME                                 TYPE        VALUE
------------------------------------ ----------- ------------------------------
db_file_multiblock_read_count        integer     8

05:47:43 SYS@xx4040 > select sum(bytes/1024/1024/1024)GB from dba_segments where segment_name='S_SEQ_CD';

        GB
----------
13.7021484

05:49:57 SYS@xx4040 > select sum(bytes/1024/1024)MB from dba_segments where segment_name='S_SEQ_CD_M28_X';

        MB
----------
   467.125

The database was bounced just before the start of the sql as the box got rebooted.So what is it that the prefetch is cause of empty buffer cache? I am unable to understand this behavior and so it would be great if some of you can put your thoughts as comments on it along with what all more could be checked for.

UPDATE — You can also read the below blog from Tanel Poder which mentions having mutliblock reads for index unique scan.

http://blog.tanelpoder.com/2012/05/02/advanced-oracle-troubleshooting-guide-part-10-index-unique-scan-doing-multiblock-reads/

Index Sample Size

Recently i was asked a question, what would be the sample size percentage for indexes when tables stats are gathered with estimate percent of 5 and cascade set to true.My answer to it was 5 within a second.I had this believe that the sample size percentage for an index is same to the estimate_percent given while gathering the stats.So it was time for some test -

SQL> select * from v$version;
 
BANNER
--------------------------------------------------------------------------------
Oracle Database 11g Enterprise Edition Release 11.2.0.2.0 - Production
PL/SQL Release 11.2.0.2.0 - Production
CORE    11.2.0.2.0      Production
TNS for 32-bit Windows: Version 11.2.0.2.0 - Production
NLSRTL Version 11.2.0.2.0 - Production
 
SQL> drop table STAT_TEST purge;
 
Table dropped.
 
SQL> create table stat_test (
  2  c1 number not null,
  3  c2 number not null,
  4  c3 varchar2(300) not null);
 
Table created.
 
SQL> create index stat_c2_idx on stat_test(c2);
 
Index created.
 
SQL>
SQL> create unique index stat_c1_indx on stat_test(c1);
 
Index created.
 
SQL> create index stat_c3_idx on stat_test(c3);
 
Index created.
 
SQL> insert into stat_test
  2  select
  3  rownum as c1,
  4  1 as c2,
  5  rpad('A',300,'A') as c3
  6  from
  7  dual
  8  connect by
  9  level / 
Enter value for tblown: ANAND
Enter value for tblnm: STAT_TEST
 
SE SORT1                          SORT2                          S INDEX_NAME                     LAST_ANALYZED   NUM_ROWS SAMPLE_PCT DISTINCT_KEYS CLUSTERING_FACTOR FLAGS
-- ------------------------------ ------------------------------ - ------------------------------ ------------- ---------- ---------- ------------- ----------------- ----------
I  ANAND                          STAT_C2_IDX                      STAT_C2_IDX                                                                                N
I  ANAND                          STAT_C1_INDX                     STAT_C1_INDX                                                                               U
I  ANAND                          STAT_C3_IDX                      STAT_C3_IDX                                                                                N

Gathered stats on the index

SQL> exec dbms_stats.gather_index_stats(ownname =>'ANAND',indname =>'STAT_C1_INDX',estimate_percent=>5,degree => DBMS_STATS.AUTO_DEGREE);
 
PL/SQL procedure successfully completed.
 
SQL> exec dbms_stats.gather_index_stats(ownname =>'ANAND',indname =>'STAT_C2_IDX',estimate_percent=>5,degree => DBMS_STATS.AUTO_DEGREE);
 
PL/SQL procedure successfully completed.
 
SQL> exec dbms_stats.gather_index_stats(ownname =>'ANAND',indname =>'STAT_C3_IDX',estimate_percent=>5,degree => DBMS_STATS.AUTO_DEGREE);
 
PL/SQL procedure successfully completed.

As i have given estimate_percent i would expect sample_percentage to be 5%. So lets check -

SQL> / 
Enter value for tblown: ANAND
Enter value for tblnm: STAT_TEST
 
SE SORT1                          SORT2                          S INDEX_NAME                     LAST_ANALYZED   NUM_ROWS SAMPLE_PCT DISTINCT_KEYS CLUSTERING_FACTOR FLAGS
-- ------------------------------ ------------------------------ - ------------------------------ ------------- ---------- ---------- ------------- ----------------- ----------
I  ANAND                          STAT_C2_IDX                      STAT_C2_IDX                    20120518 0035    1011697         40             1             46109 N
I  ANAND                          STAT_C1_INDX                     STAT_C1_INDX                   20120518 0031    1016203         61       1016203             47680 U
I  ANAND                          STAT_C3_IDX                      STAT_C3_IDX                    20120518 0035     998800          5             1             68460 N

Deleted the stats on the index and gathered with dbms_stats.gather_table_stats with estimate
_percentage of 5% to check what happens in such case

SQL> exec dbms_stats.gather_table_stats(ownname =>'ANAND',tabname =>'STAT_TEST',estimate_percent=>5,degree => DBMS_STATS.AUTO_DEGREE);
 
PL/SQL procedure successfully completed.
 
SQL> / 
Enter value for tblown: ANAND
Enter value for tblnm: STAT_TEST
 
SE SORT1                          SORT2                          S INDEX_NAME                     LAST_ANALYZED   NUM_ROWS SAMPLE_PCT DISTINCT_KEYS CLUSTERING_FACTOR FLAGS
-- ------------------------------ ------------------------------ - ------------------------------ ------------- ---------- ---------- ------------- ----------------- ----------
I  ANAND                          STAT_C2_IDX                      STAT_C2_IDX                    20120518 0037    1008329         40             1             45928 N
I  ANAND                          STAT_C1_INDX                     STAT_C1_INDX                   20120518 0037    1007530         61       1007530             47296 U
I  ANAND                          STAT_C3_IDX                      STAT_C3_IDX                    20120518 0037    1008480          5             1             68880 N
 
SQL> select 'T ' seg_type,
  2         t.owner sort1,
  3         t.table_name sort2,
  4         null sort3,
  5         t.table_name,
  6         to_char(t.last_analyzed,'yyyymmdd hh24mi') last_analyzed,
  7         t.num_rows,
  8         -- t.sample_size,
  9         decode(t.num_rows,
 10                null,to_number(null),
 11                0,100,
 12                round((t.sample_size*100)/t.num_rows,0)) sample_pct,
 13    from dba_tables t
 14   where t.owner = upper('&tblown')
 15     and t.table_name like upper('&tblnm')
 16  / 
Enter value for tblown: ANAND
Enter value for tblnm: STAT_TEST
 
SE SORT1                          SORT2                          S TABLE_NAME                LAST_ANALYZED   NUM_ROWS SAMPLE_PCT 
-- ------------------------------ ------------------------------ - ------------------------- ------------- ---------- ---------- -
T  ANAND                          STAT_TEST                        STAT_TEST                 20120518 0037    1001020          5

So the table shows sample_pct as 5% but for indexes is different.

I posted the same on OTN forum and Sir Jonathan Lewis replied –

According to a comment I wrote a couple of years ago ( https://forums.oracle.com/forums/thread.jspa?threadID=1116700 ) Oracle used to have a note on MOS stating that because the data in an index was sorted, and therefore easily able to produce a distorted picture on a small sample, the index sample was adjusted if necessary to aim for a minimum number of leaf blocks which is about 900.

The two indexes where you’ve got large samples very short keys, so the 5% was probably too few blocks. The index where you got a 5% sample was a long key, so maybe the 5% was comfortably over 900.

After which i did few checks and observed that is if an index is having upto ~1100 leaf blocks, then stats with 100% sample is being generated on the index and as the leaf block increase oracle internally determines the estimate percentage for sampling.

Change in Database link – 11gR2

A little change in dblink from 11gR2 -

SQL> conn anand/anand123
Connected.
SQL>
SQL> @db_link

OWNER                          DB_LINK                        USERNAME                       HOST
------------------------------ ------------------------------ ------------------------------ ------------------------------
ANAND                          SCOTT_DBLINK                   SCOTT                          MATSTDBY

SQL> select sysdate from dual@SCOTT_DBLINK;

SYSDATE
---------
11-MAY-12

I login as sys and change scott schema’s password -

SQL> conn / as sysdba
Connected.
SQL>
SQL>
SQL>
SQL> alter user scott identified by abc;

User altered.

Now select using the dblink fails -

SQL> select sysdate from dual@SCOTT_DBLINK;
select sysdate from dual@SCOTT_DBLINK
                         *
ERROR at line 1:
ORA-01017: invalid username/password; logon denied
ORA-02063: preceding line from SCOTT_DBLINK

In prior to 11gR2 release, one had to drop and recreate the dblink with the correct password. From 11gR2 we have “alter database link” command -

SQL> alter database link SCOTT_DBLINK connect to scott identified by abc;
alter database link SCOTT_DBLINK connect to scott identified by abc
                    *
ERROR at line 1:
ORA-01031: insufficient privileges

SQL> conn / as sysdba
Connected.

SQL> grant alter database link to anand;

Grant succeeded.
SQL> conn anand/anand123
Connected.
SQL>
SQL>
SQL>
SQL> alter database link SCOTT_DBLINK connect to scott identified by abc;

Database link altered.

SQL> select * from dual@SCOTT_DBLINK;

D
-
X

ORA-20003: You are not allowed to alter password user

Today while working on UAT database refresh activity, had a step to change all schemas password to a common one.

 begin
  for x in (select username from dba_users ) loop
     execute immediate 'alter user '||x.username||' identified by xxxxxx profile DEFAULT';
  end loop;
end;
/

The above was executed as SYS user and it errored out –

ERROR at line 1:
ORA-20003: You are not allowed to alter password user.
ORA-06512: at line 4
ORA-06512: at line 3

For me it was the first time that something like this happened.It was a little hard to get why was “alter user identified by” sql failing.

After few minutes i started thinking how can this be implemented and the first thing which came to mind was “Triggers”. So started looking out for triggers.

SQL> select trigger_name from dba_triggers where TRIGGERING_EVENT='ALTER';

no rows selected

SQL> select trigger_name from dba_triggers where TRIGGERING_EVENT like '%ALTER%';

TRIGGER_NAME
--------------------------------------------------------------------------------
xxxxxxxxx
xxxxxxxxx
PASS_CHANGE
xxxxxxxxx

Based on the trigger name PASS_CHANGE checked the trigger body which has “after alter on database” event –

SQL> select  trigger_body from dba_triggers where trigger_name='PASS_CHANGE';

TRIGGER_BODY
--------------------------------------------------------------------------------
BEGIN
   IF ora_sysevent='ALTER' and ora_dict_obj_type = 'USER' and  ora_des_encrypted_password is not null
   THEN
        RAISE_APPLICATION_ERROR(-20003,  'You are not allowed to alter password user.');
  END IF;
END;

Simply disabled the trigger and proceeded with the steps. Chaning the default tablespace for the user would also error out -


SQL> alter user scott default tablespace system;
alter user scott default tablespace system
*
ERROR at line 1:
ORA-00604: error occurred at recursive SQL level 1
ORA-20003: You are not allowed to alter password user.
ORA-06512: at line 5

ORA-00600:[kcbsor_2], [3], [2]

Recently we had a node crash of one node in 3-node 11.2.0.3 RAC database configuration.The alert log showed -

Thu Apr 26 00:15:16 2012
Hex dump of (file 488, block 345039) in trace file /u01/oradiag/diag/rdbms/matrix_adc/matrix3/trace/matrix3_dbw1_16218.trc
Corrupt block relative dba: 0x7a0543cf (file 488, block 345039)
Bad header found during preparing block for write
Data in bad block:
 type: 6 format: 2 rdba: 0x644ebb3d
 last change scn: 0x0b7a.f77b7353 seq: 0x1 flg: 0x06
 spare1: 0x0 spare2: 0x0 spare3: 0x0
 consistency value in tail: 0x73530601
 check value in block header: 0x80ae
 computed block checksum: 0x0
Thu Apr 26 00:15:16 2012
Block Corruption Recovery: buf=0x453d5e9b8 seqno=1
Block recovery from logseq 58471, block 224143 to scn 12695053893631
Recovery of Online Redo Log: Thread 3 Group 19 Seq 58471 Reading mem 0
  Mem# 0: /u02/oraredo/matrix/redot3g19m1.rdo
  Mem# 1: /u05/oraredo/matrix/redot3g19m2.rdo
Hex dump of (file 488, block 345039) in trace file /u01/oradiag/diag/rdbms/matrix_adc/matrix3/trace/matrix3_pmon_16123.trc
Reading datafile '/u10/oradata/matrix/test_idx_01_177.dbf' for corruption at rdba: 0x7a0543cf (file 488, block 345039)
Reread (file 488, block 345039) found same corrupt data (logically corrupt)
Errors in file /u01/oradiag/diag/rdbms/matrix_adc/matrix3/trace/matrix3_pmon_16123.trc  (incident=48017):
ORA-00600: internal error code, arguments: [kcbsor_2], [3], [2], [], [], [], [], [], [], [], [], []
Errors in file /u01/oradiag/diag/rdbms/matrix_adc/matrix3/trace/matrix3_pmon_16123.trc:
ORA-00600: internal error code, arguments: [kcbsor_2], [3], [2], [], [], [], [], [], [], [], [], []
PMON (ospid: 16123): terminating the instance due to error 472
Thu Apr 26 00:15:18 2012
opiodr aborting process unknown ospid (30802) as a result of ORA-1092
Thu Apr 26 00:15:18 2012
opiodr aborting process unknown ospid (15384) as a result of ORA-1092
Thu Apr 26 00:15:18 2012
opiodr aborting process unknown ospid (1661) as a result of ORA-1092
Thu Apr 26 00:15:18 2012
System state dump requested by (instance=3, osid=16123 (PMON)), summary=[abnormal instance termination].
Thu Apr 26 00:15:30 2012
Termination issued to instance processes. Waiting for the processes to exit
Thu Apr 26 00:15:33 2012
ORA-1092 : opitsk aborting process

The trace file “/u01/oradiag/diag/rdbms/matrix_adc/matrix3/trace/matrix3_pmon_16123.trc” shows -

PMON: received BCR msg

*** 2012-04-26 00:15:16.373
Block Corruption Recovery: buf=0x453d5e9b8 seqno=1 tries=1
Trying to recover a block. Dump of buffer header.
----------------------------------------------------------
BH (0x453d5e9b8) file#: 488 rdba: 0x7a0543cf (488/345039) class: 1 ba: 0x45321a000
  set: 38 pool: 3 bsz: 8192 bsi: 0 sflg: 1 pwc: 0,25
  dbwrid: 1 obj: 61329 objn: 61329 tsn: 7 afn: 488 hint: f
  hash: [0x83f1fa230,0x83f1fa230] lru-req: [0x8345f9390,0x8345f9390]
  obj-flags: object_ckpt_list
  ckptq: [0x547bd2c78,0xb3cfff70] fileq: [0xdbc48778,0x8395dec88] objq: [0x287d85f68,0x7c833f750] objaq: [0x46bd59140,0x303b53fc8]
  st: XCURRENT md: NULL fpin: 'kdiwh22: kdifind' tch: 1 le: 0x40fdd8170
  flags: buffer_dirty being_written block_written_once corrupt_being_recovered
          redo_since_read remote_transfered
  LRBA: [0xe467.36b8f.0] LSCN: [0xb8b.cc2d7fff] HSCN: [0xb8b.cc2d7fff] HSUB: [1]
GLOBAL CACHE ELEMENT DUMP (address: 0x40fdd8170):
  id1: 0x543cf id2: 0x1e8 pkey: OBJ#61329 block: (488/345039)
  lock: XG rls: 0x0 acq: 0x0 latch: 10
  flags: 0x20 fair: 0 recovery: 0 fpin: 'kdiwh22: kdifind'
  bscn: 0xb8b.cc2bc912 bctx: (nil) write: 0 scan: 0x0
  lcp: (nil) lnk: [NULL] lch: [0x453d5eae8,0x453d5eae8]
  seq: 3347 hist: 225 502 72 257 324 21 143:0 19 16 352 32 197 48 121
  LIST OF BUFFERS LINKED TO THIS GLOBAL CACHE ELEMENT:
    flg: 0x0aa00021 state: XCURRENT tsn: 7 tsh: 1 foq: 4
      addr: 0x453d5e9b8 obj: 61329 cls: DATA bscn: 0xb7a.f77b7353
Trying to recover a block with no users.
Doing block recovery for file 488 block 345039
Block header before block recovery:
buffer tsn: 7 rdba: 0x7a0543cf (488/345039)
scn: 0x0b8b.c8d4d9f4 seq: 0x01 flg: 0x04 tail: 0xd9f40601
frmt: 0x02 chkval: 0xb26b type: 0x06=trans data
Resuming block recovery (PMON) for file 488 block 345039
Block recovery from logseq 58471, block 224143 to scn 12695053893631

*** 2012-04-26 00:15:16.692
Recovery of Online Redo Log: Thread 3 Group 19 Seq 58471 Reading mem 0

*** 2012-04-26 00:15:16.933
CHANGE IN FUTURE OF BLOCK
CHANGE #2 TYP:0 CLS:1 AFN:488 DBA:0x7a0543cf OBJ:61329 SCN:0x0b8b.cc2bc912 SEQ:1 OP:10.2 ENC:0 RBL:0
buffer tsn: 7 rdba: 0x7a0543cf (488/345039)
scn: 0x0b8b.c8d4d9f4 seq: 0x01 flg: 0x04 tail: 0xd9f40601
frmt: 0x02 chkval: 0xb26b type: 0x06=trans data
GLOBAL CACHE ELEMENT DUMP (address: 0x40fdd8170):
  id1: 0x543cf id2: 0x1e8 pkey: OBJ#61329 block: (488/345039)
  lock: X rls: 0x0 acq: 0x0 latch: 10
  flags: 0x20 fair: 0 recovery: 0 fpin: 'kdiwh22: kdifind'
  bscn: 0xb8b.cc2bc912 bctx: (nil) write: 0 scan: 0x0
  lcp: (nil) lnk: [NULL] lch: [0x453d5eae8,0x453d5eae8]
  seq: 3350 hist: 104 147:0 68 225 502 72 257 324 21 143:0 19 16
  LIST OF BUFFERS LINKED TO THIS GLOBAL CACHE ELEMENT:
    flg: 0x0aa00005 state: XCURRENT tsn: 7 tsh: 1 mode: EXCL foq: 4
      pin: 'ktuwh61: ktugus:ktucmt'
      addr: 0x453d5e9b8 obj: 61329 cls: DATA bscn: 0xb8b.c8d4d9f4
kcra_dump_redo_internal: skipped for critical process
Hex dump of (file 488, block 345039)
Dump of memory from 0x000000045321A000 to 0x000000045321C000
45321A000 0000A206 7A0543CF C8D4D9F4 04010B8B  [......z........]
........................
45321BFF0 73736563 FFFFFFFF 4E01FFFF D9F40601  [c.s.......N....]
Reading datafile '/u10/oradata/matrix/test_idx_01_177.dbf' for corruption at rdba: 0x7a0543cf (file 488, block 345039)
Reread (file 488, block 345039) found same corrupt data (logically corrupt)
Reread for stuck block recovery failed
Incident 48017 created, dump file: /u01/oradiag/diag/rdbms/matrix_adc/matrix3/incident/incdir_48017/matrix3_pmon_16123_i48017.trc
ORA-00600: internal error code, arguments: [kcbsor_2], [3], [2], [], [], [], [], [], [], [], [], []

error 472 detected in background process
ORA-00600: internal error code, arguments: [kcbsor_2], [3], [2], [], [], [], [], [], [], [], [], []
kjzduptcctx: Notifying DIAG for crash event
----- Abridged Call Stack Trace -----
ksedsts()+461<-kjzdssdmp()+267<-kjzduptcctx()+232<-kjzdicrshnfy()+53<-ksuitm()+1332<-ksbrdp()+3344<-opirip()+623<-opidrv()+603<-sou2o()+103<-opimai_real()+266<-ssthrdmain()+252<
-main()+201<-__libc_start_main()+244<-_start()+37
----- End of Abridged Call Stack Trace -----

*** 2012-04-26 00:15:18.418
PMON (ospid: 16123): terminating the instance due to error 472

*** 2012-04-26 00:15:20.990
ksuitm: waiting up to [5] seconds before killing DIAG(16141)

This relates to Bug 9451143 where PMON starts online block recovery from a wrong LOW RBA which is provided in the block header.As per the MOS note 9451143.8 , the issue is fixed in 11.2.0.3, though we still had a hit. Instance startup was hung at -

Thu Apr 26 00:47:41 2012
Started redo application at
 Thread 1: logseq 86819, block 358549
 Thread 2: logseq 62762, block 134200
 Thread 3: logseq 58471, block 195623
Recovery of Online Redo Log: Thread 1 Group 2 Seq 86819 Reading mem 0
  Mem# 0: /u02/oraredo/matrix/redot1g2m1.rdo
  Mem# 1: /u05/oraredo/matrix/redot1g2m2.rdo
Recovery of Online Redo Log: Thread 2 Group 6 Seq 62762 Reading mem 0
  Mem# 0: /u02/oraredo/matrix/redot2g6m1.rdo
  Mem# 1: /u05/oraredo/matrix/redot2g6m2.rdo
Recovery of Online Redo Log: Thread 3 Group 19 Seq 58471 Reading mem 0
  Mem# 0: /u02/oraredo/matrix/redot3g19m1.rdo
  Mem# 1: /u05/oraredo/matrix/redot3g19m2.rdo
Thu Apr 26 00:47:42 2012
Hex dump of (file 488, block 345039) in trace file /u01/oradiag/diag/rdbms/matrix_adc/matrix3/trace/matrix3_p000_30168.trc
Reading datafile '/u10/oradata/matrix/test_idx_01_177.dbf' for corruption at rdba: 0x7a0543cf (file 488, block 345039)
Reread (file 488, block 345039) found same corrupt data (logically corrupt)
RECOVERY OF THREAD 3 STUCK AT BLOCK 345039 OF FILE 488

“Logical Corruption happens when a data block has a valid checksum, etc., but the block contents are logically inconsistent. Logical block corruption can also occur when the structure below the beginning of the block (below the block header) is corrupt. In this case, the block checksum is correct but the block structures may be corrupt. Logical corruption can also result from a lost write in which a version of the block that was sent to disk somehow was not actually written. The result is that the version of that block on disk is older than the version in the buffer cache. Lost writes are usually caused by bugs in the operating system or hardware.”

We tried recover datafile 488 block 345039

RMAN>  RECOVER DATAFILE 488 BLOCK  345039;

Starting recover at 26-APR-12
using target database control file instead of recovery catalog
allocated channel: ORA_DISK_1
channel ORA_DISK_1: SID=2550 instance=matrix1 device type=DISK

starting media recovery
media recovery complete, elapsed time: 00:00:00

Finished recover at 26-APR-12
Thu Apr 26 01:13:25 2012
alter database recover datafile list clear
Completed: alter database recover datafile list clear

There wasn’t any error, but media recovery complete showed elapsed time of 00:00:00 , which made us doubtful.We tried starting the instance and again it got stuck at the same “RECOVERY OF THREAD 3 STUCK AT BLOCK 345039 OF FILE 488″. Meanwhile the other 2 instances also got evicted cause of high load average on the server causing downtime.We then performed datafile recovery

Thu Apr 26 01:22:17 2012
ALTER DATABASE RECOVER  datafile '/u10/oradata/matrix/test_idx_01_177.dbf'
Media Recovery Start
Serial Media Recovery started
Recovery of Online Redo Log: Thread 1 Group 2 Seq 86819 Reading mem 0
  Mem# 0: /u02/oraredo/matrix/redot1g2m1.rdo
  Mem# 1: /u05/oraredo/matrix/redot1g2m2.rdo
Recovery of Online Redo Log: Thread 2 Group 5 Seq 62761 Reading mem 0
  Mem# 0: /u02/oraredo/matrix/redot2g5m1.rdo
  Mem# 1: /u05/oraredo/matrix/redot2g5m2.rdo
Recovery of Online Redo Log: Thread 3 Group 22 Seq 58470 Reading mem 0
  Mem# 0: /u02/oraredo/matrix/redot3g22m1.rdo
  Mem# 1: /u05/oraredo/matrix/redot3g22m2.rdo
Thu Apr 26 01:22:50 2012
Recovery of Online Redo Log: Thread 3 Group 19 Seq 58471 Reading mem 0
  Mem# 0: /u02/oraredo/matrix/redot3g19m1.rdo
  Mem# 1: /u05/oraredo/matrix/redot3g19m2.rdo
Recovery of Online Redo Log: Thread 2 Group 6 Seq 62762 Reading mem 0
  Mem# 0: /u02/oraredo/matrix/redot2g6m1.rdo
  Mem# 1: /u05/oraredo/matrix/redot2g6m2.rdo
Thu Apr 26 01:23:22 2012
Recovery of Online Redo Log: Thread 1 Group 3 Seq 86820 Reading mem 0
  Mem# 0: /u02/oraredo/matrix/redot1g3m1.rdo
  Mem# 1: /u05/oraredo/matrix/redot1g3m2.rdo
Media Recovery Complete (matrix1)
Completed: ALTER DATABASE RECOVER  datafile '/u10/oradata/matrix/test_idx_01_177.dbf'

The datafile was recovered and the instance started.All 3-nodes were brought up.

From 11gr2 we have Automatic Block recovery (ABMR) feature, but as per my knowledge it would be useful in physical block corruption scenario only.ABMR requires data guard to be in real-time apply mode and sync or async transport modes.For more read-

http://docs.oracle.com/cd/E11882_01/server.112/e17157/unplanned.htm#BABCECIC

http://emrebaransel.blogspot.com.au/2012/02/automatic-block-media-recovery-on.html

Follow

Get every new post delivered to your Inbox.

Join 463 other followers