ORACLE Instance (pid = ) - Error 1578 encountered while recovering transaction (, ) on : ORA-01578: ORACLE data block corrupted (file # , block # )Block corruption after crashed database recovered

There are many cases when automatic crash recovery fails and Oracle database has to be salvaged from manual recovery [without restore and without archive log ] but DB incurrs Data block corruption(fractured blocks) which could not be fixed by just applying current or active redo logs manually. This happens due abrupt outage of all instances of databases during heavy DML, generally due power failure In below case DB had same scenario when crash recovery failed and I had to manually give recover command. I first tried sqlplus but then aborted it as it would require supply different redo log file names at recovery prompt so I switch to RMAN. See bottom of post for alert log snippet and block corruption error. You can notice ORA-01578 appearing every minute while this error is not detected unless these blocks are accessed and in this case since Oracle was trying to rollback block changes of failed (terminated session due outage) transaction and blocks is fractured ORA-01578 is popping even though no user session connected.
  
RMAN> recover database ;

Starting recover at 18-JUN-14
using target database control file instead of recovery catalog
allocated channel: ORA_DISK_1
channel ORA_DISK_1: sid=146 instance=RAC1 devtype=DISK

starting media recovery

archive log thread 1 sequence 874 is already on disk as file +DATA4/redo08.log
archive log thread 2 sequence 1628 is already on disk as file +DATA4/redo14.log
archive log thread 2 sequence 1629 is already on disk as file +DATA4/redo11.log
archive log thread 2 sequence 1630 is already on disk as file +DATA4/redo12.log
archive log thread 3 sequence 368 is already on disk as file +DATA4/redo18.log
archive log thread 3 sequence 369 is already on disk as file +DATA4/redo15.log
archive log thread 3 sequence 370 is already on disk as file +DATA4/redo16.log
archive log filename=+DATA4/redo14.log thread=2 sequence=1628
archive log filename=+DATA4/redo08.log thread=1 sequence=874
archive log filename=+DATA4/redo18.log thread=3 sequence=368
archive log filename=+DATA4/redo15.log thread=3 sequence=369
archive log filename=+DATA4/redo11.log thread=2 sequence=1629
archive log filename=+DATA4/redo16.log thread=3 sequence=370
archive log filename=+DATA4/redo12.log thread=2 sequence=1630
media recovery complete, elapsed time: 00:03:14
Finished recover at 18-JUN-14


RMAN> open resetlogs database ;

database opened

RMAN> exit

[oracle@node1 bdump]$ tail -200f alert_RAC1.log
Wed Jun 18 01:52:17 IST 2014
ALTER DATABASE RECOVER    LOGFILE '+DATA4/redo13.log'
Wed Jun 18 01:52:17 IST 2014
Media Recovery Log +DATA4/redo13.log
Wed Jun 18 01:53:45 IST 2014
Hex dump of (file 7, block 65672) in trace file /u01/app/oracle/admin/RAC/udump/rac1_ora_21662.trc
Corrupt block relative dba: 0x01c10088 (file 7, block 65672)
Fractured block found during media recovery
Data in bad block:
 type: 6 format: 2 rdba: 0x01c10088
 last change scn: 0x0000.01aea031 seq: 0x1 flg: 0x04
 spare1: 0x0 spare2: 0x0 spare3: 0x0
 consistency value in tail: 0x9c190601
 check value in block header: 0x30e7
 computed block checksum: 0x3c28
Reread of rdba: 0x01c10088 (file 7, block 65672) found same corrupted data
ORA-279 signalled during: ALTER DATABASE RECOVER    LOGFILE '+DATA4/redo13.log'  ...
Wed Jun 18 01:53:52 IST 2014
ALTER DATABASE RECOVER    CONTINUE DEFAULT
Wed Jun 18 01:53:52 IST 2014
Media Recovery Log /u01/app/oracle/product/10.2.0/db_1/dbs/arch2_1628_850308178.dbf
Errors with log /u01/app/oracle/product/10.2.0/db_1/dbs/arch2_1628_850308178.dbf
ORA-308 signalled during: ALTER DATABASE RECOVER    CONTINUE DEFAULT  ...
Wed Jun 18 01:53:52 IST 2014
ALTER DATABASE RECOVER CANCEL
ORA-1547 signalled during: ALTER DATABASE RECOVER CANCEL ...
Wed Jun 18 01:53:57 IST 2014
SUCCESS: diskgroup DATA2 was dismounted
SUCCESS: diskgroup DATA3 was dismounted
SUCCESS: diskgroup DATA4 was dismounted
Wed Jun 18 01:54:22 IST 2014
ALTER DATABASE RECOVER  database until cancel using backup controlfile
Wed Jun 18 01:54:22 IST 2014
Media Recovery Start
Wed Jun 18 01:54:23 IST 2014
SUCCESS: diskgroup DATA2 was mounted
SUCCESS: diskgroup DATA3 was mounted
Wed Jun 18 01:54:23 IST 2014
WARNING! Recovering data file 1 from a fuzzy file. If not the current file
it might be an online backup taken without entering the begin backup command.
WARNING! Recovering data file 2 from a fuzzy file. If not the current file
it might be an online backup taken without entering the begin backup command.
WARNING! Recovering data file 3 from a fuzzy file. If not the current file
it might be an online backup taken without entering the begin backup command.
WARNING! Recovering data file 4 from a fuzzy file. If not the current file
it might be an online backup taken without entering the begin backup command.
WARNING! Recovering data file 5 from a fuzzy file. If not the current file
it might be an online backup taken without entering the begin backup command.
WARNING! Recovering data file 6 from a fuzzy file. If not the current file
it might be an online backup taken without entering the begin backup command.
WARNING! Recovering data file 7 from a fuzzy file. If not the current file
it might be an online backup taken without entering the begin backup command.
WARNING! Recovering data file 8 from a fuzzy file. If not the current file
it might be an online backup taken without entering the begin backup command.
ORA-279 signalled during: ALTER DATABASE RECOVER  database until cancel using backup controlfile   ...
Wed Jun 18 01:54:36 IST 2014
ALTER DATABASE RECOVER    LOGFILE '+DATA4/redo14.log'
Wed Jun 18 01:54:36 IST 2014
Media Recovery Log +DATA4/redo14.log
SUCCESS: diskgroup DATA4 was mounted
ORA-279 signalled during: ALTER DATABASE RECOVER    LOGFILE '+DATA4/redo14.log'  ...
Wed Jun 18 01:54:44 IST 2014
ALTER DATABASE RECOVER    LOGFILE '+DATA4/redo08.log'
Wed Jun 18 01:54:44 IST 2014
Media Recovery Log +DATA4/redo08.log
ORA-279 signalled during: ALTER DATABASE RECOVER    LOGFILE '+DATA4/redo08.log'  ...
Wed Jun 18 02:00:26 IST 2014
ALTER DATABASE RECOVER    CONTINUE DEFAULT
Wed Jun 18 02:00:26 IST 2014
Media Recovery Log /u01/app/oracle/product/10.2.0/db_1/dbs/arch3_368_850308178.dbf
Errors with log /u01/app/oracle/product/10.2.0/db_1/dbs/arch3_368_850308178.dbf
ORA-308 signalled during: ALTER DATABASE RECOVER    CONTINUE DEFAULT  ...
Wed Jun 18 02:00:26 IST 2014
ALTER DATABASE RECOVER CANCEL
ORA-1547 signalled during: ALTER DATABASE RECOVER CANCEL ...
Wed Jun 18 02:00:35 IST 2014
SUCCESS: diskgroup DATA2 was dismounted
SUCCESS: diskgroup DATA3 was dismounted
SUCCESS: diskgroup DATA4 was dismounted
Wed Jun 18 02:00:41 IST 2014
ALTER DATABASE RECOVER  database until cancel using backup controlfile
Wed Jun 18 02:00:41 IST 2014
Media Recovery Start
Wed Jun 18 02:00:41 IST 2014
SUCCESS: diskgroup DATA2 was mounted
SUCCESS: diskgroup DATA3 was mounted
Wed Jun 18 02:00:41 IST 2014
WARNING! Recovering data file 1 from a fuzzy file. If not the current file
it might be an online backup taken without entering the begin backup command.
WARNING! Recovering data file 2 from a fuzzy file. If not the current file
it might be an online backup taken without entering the begin backup command.
WARNING! Recovering data file 3 from a fuzzy file. If not the current file
it might be an online backup taken without entering the begin backup command.
WARNING! Recovering data file 4 from a fuzzy file. If not the current file
it might be an online backup taken without entering the begin backup command.
WARNING! Recovering data file 5 from a fuzzy file. If not the current file
it might be an online backup taken without entering the begin backup command.
WARNING! Recovering data file 6 from a fuzzy file. If not the current file
it might be an online backup taken without entering the begin backup command.
WARNING! Recovering data file 7 from a fuzzy file. If not the current file
it might be an online backup taken without entering the begin backup command.
WARNING! Recovering data file 8 from a fuzzy file. If not the current file
it might be an online backup taken without entering the begin backup command.
ORA-279 signalled during: ALTER DATABASE RECOVER  database until cancel using backup controlfile   ...
Wed Jun 18 02:00:57 IST 2014
ALTER DATABASE RECOVER    CANCEL
Wed Jun 18 02:00:57 IST 2014
ORA-1547 signalled during: ALTER DATABASE RECOVER    CANCEL  ...
Wed Jun 18 02:00:57 IST 2014
ALTER DATABASE RECOVER CANCEL
ORA-1112 signalled during: ALTER DATABASE RECOVER CANCEL ...
Wed Jun 18 02:01:02 IST 2014
SUCCESS: diskgroup DATA2 was dismounted
SUCCESS: diskgroup DATA3 was dismounted
Wed Jun 18 02:01:13 IST 2014
SUCCESS: diskgroup DATA2 was mounted
SUCCESS: diskgroup DATA3 was mounted
Wed Jun 18 02:01:14 IST 2014
SUCCESS: diskgroup DATA4 was mounted
Wed Jun 18 02:01:14 IST 2014
SUCCESS: diskgroup DATA2 was dismounted
SUCCESS: diskgroup DATA3 was dismounted
Wed Jun 18 02:01:14 IST 2014
SUCCESS: diskgroup DATA2 was mounted
Wed Jun 18 02:01:14 IST 2014
SUCCESS: diskgroup DATA2 was dismounted
SUCCESS: diskgroup DATA4 was dismounted
Wed Jun 18 02:01:14 IST 2014
SUCCESS: diskgroup DATA3 was mounted
SUCCESS: diskgroup DATA2 was mounted
Wed Jun 18 02:01:15 IST 2014
alter database recover datafile list clear
Wed Jun 18 02:01:15 IST 2014
Completed: alter database recover datafile list clear
Wed Jun 18 02:01:15 IST 2014
alter database recover datafile list
 1 , 2 , 3 , 4 , 5 , 6 , 7 , 8
Completed: alter database recover datafile list
 1 , 2 , 3 , 4 , 5 , 6 , 7 , 8
Wed Jun 18 02:01:15 IST 2014
alter database recover if needed
 start until cancel using backup controlfile
Media Recovery Start
WARNING! Recovering data file 1 from a fuzzy file. If not the current file
it might be an online backup taken without entering the begin backup command.
WARNING! Recovering data file 2 from a fuzzy file. If not the current file
it might be an online backup taken without entering the begin backup command.
WARNING! Recovering data file 3 from a fuzzy file. If not the current file
it might be an online backup taken without entering the begin backup command.
WARNING! Recovering data file 4 from a fuzzy file. If not the current file
it might be an online backup taken without entering the begin backup command.
WARNING! Recovering data file 5 from a fuzzy file. If not the current file
it might be an online backup taken without entering the begin backup command.
WARNING! Recovering data file 6 from a fuzzy file. If not the current file
it might be an online backup taken without entering the begin backup command.
WARNING! Recovering data file 7 from a fuzzy file. If not the current file
it might be an online backup taken without entering the begin backup command.
WARNING! Recovering data file 8 from a fuzzy file. If not the current file
it might be an online backup taken without entering the begin backup command.
ORA-279 signalled during: alter database recover if needed
 start until cancel using backup controlfile
...
SUCCESS: diskgroup DATA4 was mounted
Wed Jun 18 02:01:15 IST 2014
alter database recover logfile '+DATA4/redo14.log'
Wed Jun 18 02:01:15 IST 2014
Media Recovery Log +DATA4/redo14.log
ORA-279 signalled during: alter database recover logfile '+DATA4/redo14.log'...
Wed Jun 18 02:01:15 IST 2014
alter database recover logfile '+DATA4/redo08.log'
Wed Jun 18 02:01:15 IST 2014
Media Recovery Log +DATA4/redo08.log
ORA-279 signalled during: alter database recover logfile '+DATA4/redo08.log'...
Wed Jun 18 02:01:16 IST 2014
alter database recover logfile '+DATA4/redo18.log'
Wed Jun 18 02:01:16 IST 2014
Media Recovery Log +DATA4/redo18.log
Wed Jun 18 02:03:19 IST 2014
ORA-279 signalled during: alter database recover logfile '+DATA4/redo18.log'...
Wed Jun 18 02:03:19 IST 2014
alter database recover logfile '+DATA4/redo15.log'
Wed Jun 18 02:03:19 IST 2014
Media Recovery Log +DATA4/redo15.log
ORA-279 signalled during: alter database recover logfile '+DATA4/redo15.log'...
Wed Jun 18 02:03:27 IST 2014
alter database recover logfile '+DATA4/redo11.log'
Wed Jun 18 02:03:27 IST 2014
Media Recovery Log +DATA4/redo11.log
Wed Jun 18 02:03:51 IST 2014
ORA-279 signalled during: alter database recover logfile '+DATA4/redo11.log'...
Wed Jun 18 02:03:51 IST 2014
alter database recover logfile '+DATA4/redo16.log'
Wed Jun 18 02:03:51 IST 2014
Media Recovery Log +DATA4/redo16.log
Wed Jun 18 02:04:03 IST 2014
ORA-279 signalled during: alter database recover logfile '+DATA4/redo16.log'...
Wed Jun 18 02:04:03 IST 2014
alter database recover logfile '+DATA4/redo12.log'
Wed Jun 18 02:04:03 IST 2014
Media Recovery Log +DATA4/redo12.log
Wed Jun 18 02:04:29 IST 2014
Incomplete recovery applied all redo ever generated.
Recovery completed through change 28235622
Wed Jun 18 02:04:29 IST 2014
Media Recovery Complete (RAC1)
Completed: alter database recover logfile '+DATA4/redo12.log'
Wed Jun 18 02:04:34 IST 2014
SUCCESS: diskgroup DATA3 was dismounted
SUCCESS: diskgroup DATA2 was dismounted
SUCCESS: diskgroup DATA4 was dismounted
Wed Jun 18 02:04:38 IST 2014
alter database open
Wed Jun 18 02:04:38 IST 2014
This instance was first to open
Wed Jun 18 02:04:38 IST 2014
SUCCESS: diskgroup DATA2 was mounted
SUCCESS: diskgroup DATA3 was mounted
Wed Jun 18 02:04:38 IST 2014
SUCCESS: diskgroup DATA2 was dismounted
SUCCESS: diskgroup DATA3 was dismounted
Wed Jun 18 02:04:38 IST 2014
ORA-1589 signalled during: alter database open...
Wed Jun 18 02:04:46 IST 2014
alter database open resetlogs
Wed Jun 18 02:04:46 IST 2014
SUCCESS: diskgroup DATA2 was mounted
SUCCESS: diskgroup DATA3 was mounted
Wed Jun 18 02:04:46 IST 2014
RESETLOGS after complete recovery through change 28235622
Resetting resetlogs activation ID 2438300125 (0x915581dd)
SUCCESS: diskgroup DATA4 was mounted
Wed Jun 18 02:05:13 IST 2014
Setting recovery target incarnation to 3
Wed Jun 18 02:05:13 IST 2014
This instance was first to open
Wed Jun 18 02:05:13 IST 2014
SUCCESS: diskgroup DATA4 was dismounted
Wed Jun 18 02:05:13 IST 2014
Picked broadcast on commit scheme to generate SCNs
Wed Jun 18 02:05:13 IST 2014
Assigning activation ID 2438538385 (0x91592491)
SUCCESS: diskgroup DATA4 was mounted
Thread 1 opened at log sequence 1
  Current log# 7 seq# 1 mem# 0: +DATA4/redo07.log
Successful open of redo thread 1
Wed Jun 18 02:05:14 IST 2014
MTTR advisory is disabled because FAST_START_MTTR_TARGET is not set
Wed Jun 18 02:05:14 IST 2014
SMON: enabling cache recovery
Wed Jun 18 02:05:16 IST 2014
Successfully onlined Undo Tablespace 1.
Dictionary check beginning
Dictionary check complete
Wed Jun 18 02:05:16 IST 2014
SMON: enabling tx recovery
Wed Jun 18 02:05:16 IST 2014
Database Characterset is WE8ISO8859P1
Wed Jun 18 02:05:16 IST 2014
Instance recovery: looking for dead threads
Instance recovery: lock domain invalid but no dead threads
Wed Jun 18 02:05:17 IST 2014
Opening with internal Resource Manager plan
replication_dependency_tracking turned off (no async multimaster replication found)
Starting background process QMNC
QMNC started with pid=27, OS id=30068
Wed Jun 18 02:05:21 IST 2014
LOGSTDBY: Validating controlfile with logical metadata
Wed Jun 18 02:05:22 IST 2014
LOGSTDBY: Validation complete
Completed: alter database open resetlogs
Wed Jun 18 02:05:37 IST 2014
SMON: Restarting fast_start parallel rollback
SMON: ignoring slave err,downgrading to serial rollback
ORACLE Instance RAC1 (pid = 12) - Error 1578 encountered while recovering transaction (13, 35) on object 58984.
Wed Jun 18 02:05:37 IST 2014
Errors in file /u01/app/oracle/admin/RAC/bdump/rac1_smon_21583.trc:
ORA-01578: ORACLE data block corrupted (file # 7, block # 65672)
ORA-01110: data file 7: '+DATA/data01.dbf'
Wed Jun 18 02:05:38 IST 2014
Trace dumping is performing id=[cdmp_20140618020538]
Wed Jun 18 02:05:41 IST 2014
ORACLE Instance RAC1 (pid = 12) - Error 1578 encountered while recovering transaction (13, 35) on object 58984.
Wed Jun 18 02:05:41 IST 2014
Errors in file /u01/app/oracle/admin/RAC/bdump/rac1_smon_21583.trc:
ORA-01578: ORACLE data block corrupted (file # 7, block # 65672)
ORA-01110: data file 7: '+DATA/data01.dbf'Wed Jun 18 02:05:42 IST 2014
Trace dumping is performing id=[cdmp_20140618020542]

In my case as DB was in norachive log mode and it was test database I dropped entire tablespace containing this corrupted block. Another option would be to drop this segment only if corrupted block is not segment header block

ORA-00333: redo log read error block 9167 count 1073

If database is not able to start after failed crash automatic recovery with error you receive ORA-00333: redo log read error block xxxx count xxxx then you should try manually recover the database. 

[oracle@11gRAC1 11g]$ srvctl start database -d ORCL
PRCR-1079 : Failed to start resource ora.orcl.db
CRS-5017: The resource action "ora.orcl.db start" encountered the following erro
ORA-00333: redo log read error block 9167 count 8184
. For details refer to "(:CLSN00107:)" in "/u01/11.2.0/grid/log/11grac1/agent/cr

CRS-2674: Start of 'ora.orcl.db' on '11grac1' failed
CRS-2632: There are no more servers to try to place resource 'ora.orcl.db' on th
CRS-5017: The resource action "ora.orcl.db start" encountered the following erro
ORA-00333: redo log read error block 9167 count 8184
. For details refer to "(:CLSN00107:)" in "/u01/11.2.0/grid/log/11grac2/agent/cr

CRS-2674: Start of 'ora.orcl.db' on '11grac2' failed
[oracle@11gRAC1 11g]$ sqlplus / as sysdba
SQL> startup mount
ORACLE instance started.

Total System Global Area  534519808 bytes
Fixed Size                  2229944 bytes
Variable Size             314575176 bytes
Database Buffers          209715200 bytes
Redo Buffers                7999488 bytes
Database mounted.
SQL> select * from v$log ;

    GROUP#    THREAD#  SEQUENCE#      BYTES  BLOCKSIZE    MEMBERS ARC STATUS           FIRST_CHANGE# FIRST_TIM NEXT_CHANGE# NEXT_TIME
---------- ---------- ---------- ---------- ---------- ---------- --- ---------------- ------------- --------- ------------ ---------
         1          1        195  241172480        512          1 NO  CURRENT               64028116 18-MAY-14   2.8147E+14
         2          1        194  241172480        512          1 NO  INACTIVE              63987815 16-MAY-14     64028116 18-MAY-14
         3          2        151  241172480        512          1 NO  CURRENT               64007840 16-MAY-14   2.8147E+14
         4          2        150  241172480        512          1 NO  INACTIVE              63941096 16-MAY-14     64007840 16-MAY-14

         SQL> select * from v$logfile;

    GROUP# STATUS  TYPE    MEMBER                                             IS_
---------- ------- ------- -------------------------------------------------- ---
         1         ONLINE  +DATA2/orcl/redo01.log                             NO
         2         ONLINE  +DATA2/orcl/redo02.log                             NO
         3         ONLINE  +DATA2/orcl/redo03.log                             NO
         4         ONLINE  +DATA2/orcl/redo04.log                             NO

SQL> recover database ;
ORA-00283: recovery session canceled due to errors
ORA-00333: redo log read error block 8192 count 2048
SQL> select name,state from v$asm_diskgroup ;

NAME                           STATE
------------------------------ -----------
DATA2                          CONNECTED
DATA3                          CONNECTED
DATA                           CONNECTED

SQL> select FILE#,STATUS,ERROR,RECOVER,FUZZY,CHECKPOINT_CHANGE# from v$datafile_header;

Disk group DATA2 ON which redo log resides is mounted and DB has successfully connected to it

     FILE# STATUS  ERROR                                                             REC FUZ CHECKPOINT_CHANGE#
---------- ------- ----------------------------------------------------------------- --- --- ------------------
         1 ONLINE                                                                    NO  YES           63941096
         2 ONLINE                                                                    NO  YES           63941096
         3 ONLINE                                                                    NO  YES           63941096
         4 ONLINE                                                                    NO  YES           63941096
         5 ONLINE                                                                    NO  YES           63941096
         6 ONLINE                                                                    NO  YES           63941096
         7 ONLINE                                                                    NO  YES           63941096

7 rows selected.


 #rebooted  crs but database did not start and both its instances terminated after giving error

SQL> startup mount
ORACLE instance started.

Total System Global Area  534519808 bytes
Fixed Size                  2229944 bytes
Variable Size             314575176 bytes
Database Buffers          209715200 bytes
Redo Buffers                7999488 bytes
Database mounted.
SQL> recover database ;
ORA-00283: recovery session canceled due to errors
ORA-00333: redo log read error block 9167 count 1073

This time block number is different and so is count

SQL> shutdown immediate
startup ORA-01109: database not open
Database dismounted.
ORACLE instance shut down.
SQL> ORACLE instance started.

Total System Global Area  534519808 bytes
Fixed Size                  2229944 bytes
Variable Size             314575176 bytes
Database Buffers          209715200 bytes
Redo Buffers                7999488 bytes
Database mounted.
SQL> recover database until cancel using backup controlfile ;ORA-00279: change 64028117 generated at 05/18/2014 11:34:34 needed for thread 1
ORA-00289: suggestion : /u01/app/oracle/product/11.2.0/db_1/dbs/arch1_195_847218868.dbf
ORA-00280: change 64028117 for thread 1 is in sequence #195

Specify log: {=suggested | filename | AUTO | CANCEL}
+DATA2/orcl/redo01.log
ORA-00279: change 64028117 generated at 05/16/2014 13:06:28 needed for thread 2
ORA-00289: suggestion : /u01/app/oracle/product/11.2.0/db_1/dbs/arch2_151_847218868.dbf
ORA-00280: change 64028117 for thread 2 is in sequence #151

Specify log: {=suggested | filename | AUTO | CANCEL}
+DATA2/orcl/redo03.log
Log applied.
Media recovery complete.



SQL> select distinct FUZZY from v$datafile_header;

FUZ
----
NO

SQL> alter database open resetlogs ;
Database altered.


[ DB is opened and you are done. You may have some corruption in undo tablespaces , data files or index tablespaces- always check alert log even after crash recovery or instance recovery but DB is opened and you can tackle other error errors with available backup or  dropping/recreating undo [if it does not have active and if undo tablespace has active SMU then by marking them to be dropped by hidden parameter, post about this later on ]
-------------------------------------------------------------------------------------------------------
 
####### From alert log

Incomplete read from log member '+DATA2/orcl/redo03.log'. Trying next member.
Abort recovery for domain 0
Aborting crash recovery due to error 333
Errors in file /u01/app/oracle/diag/rdbms/orcl/ORCL1/trace/ORCL1_ora_5083.trc:
ORA-00333: redo log read error block 9167 count 8184
Abort recovery for domain 0
Errors in file /u01/app/oracle/diag/rdbms/orcl/ORCL1/trace/ORCL1_ora_5083.trc:
ORA-00333: redo log read error block 9167 count 8184
ORA-333 signalled during: ALTER DATABASE OPEN /* db agent *//* {1:22317:292} */...
Mon May 19 11:32:05 2014
Shutting down instance (abort)

snippet of trace file : /u01/app/oracle/diag/rdbms/orcl/ORCL1/trace/ORCL1_ora_5083.trc

Successfully allocated 3 recovery slaves
Using 45 overflow buffers per recovery slave
Thread 2 checkpoint: logseq 151, block 2, scn 64033559
  cache-low rba: logseq 151, block 9159
    on-disk rba: logseq 151, block 9190, scn 64078136
  start recovery at logseq 151, block 9159, scn 0
Thread 1 checkpoint: logseq 195, block 2, scn 64028117
  cache-low rba: logseq 195, block 75202
    on-disk rba: logseq 195, block 75256, scn 64077704
  start recovery at logseq 195, block 75202, scn 0
Incomplete read from log member '+DATA2/orcl/redo03.log'. Trying next member.
2014-05-19 11:32:05.362112 : Abort recovery for domain 0, flags = 0x4
2014-05-19 11:32:05.362192 : kjb_abort_recovery: abort recovery for domain 0 @ inc 3 (0)
2014-05-19 11:32:05.362209 : kjb_abort_recovery: domain flags=0x0, valid=0
ORA-00333: redo log read error block 9167 count 8184
2014-05-19 11:32:05.391695 : Abort recovery for domain 0, flags = 0x4
2014-05-19 11:32:05.391717 : aborting recovery of 0 (0) with cluster inc 3 (0) recovery 1
2014-05-19 11:32:05.391730 : kjb_abort_recovery: domain flags=0x0, valid=0
ORA-00333: redo log read error block 9167 count 8184


----------------------------

ORA-01172: recovery of thread 2 stuck at block 224 of file 4

Error ORA-01172 should not come in ideal database It comes when database crashes(all RAC instances crashes) and automatic database crash recovery fails. Oracle first tries to recover with parallels slaves [ as default parallel recovery option is low, if it also fails then it tries serial recovery and it it also fails then gives below message. Instance is not terminated at the end of failed recovery. ]Remedy is to apply recover command manually so that oracle can apply ACTIVE and CURRENT redo logs of all threads. In below case simple recover command did job. [it did not prompt for any redo log file to apply] If you are unlucky (your database is not in archivelog mode and you do not have older but recent archive logs) then recover database or recover database until cancel command won't help you as oracle falsely wants older log sequence to be applied which is not visible in v$log.  Below is lucky one. Unlucky case will be posted sooner. 


SQL> alter database open ;
alter database open
*
ERROR at line 1:
ORA-01172: recovery of thread 2 stuck at block 224 of file 4
ORA-01151: use media recovery to recover block, restore backup if needed


SQL>  select * from v$recover_file;

no rows selected




SQL> recover database ;
Media recovery complete.
SQL> alter database open ;

Database altered.


From alert log , Thu May 29 21:44:40 2014
Hex dump of (file 4, block 224) in trace file /home/oracle/trace/diag/rdbms/orcl/ORCL1/trace/ORCL1_p002_4479.trc
Reading datafile '+DATA/orcl/datafile/undotbs2.274.847998769' for corruption at rdba: 0x010000e0 (file 4, block 224)
Reread (file 4, block 224) found same corrupt data (logically corrupt)
RECOVERY OF THREAD 2 STUCK AT BLOCK 224 OF FILE 4
Slave exiting with ORA-1172 exception
Errors in file /home/oracle/trace/diag/rdbms/orcl/ORCL1/trace/ORCL1_p002_4479.trc:
ORA-01172: recovery of thread 2 stuck at block 224 of file 4
ORA-01151: use media recovery to recover block, restore backup if neededThu May 29 21:44:49 2014
Abort recovery for domain 0
Aborting crash recovery due to slave death, attempting serial crash recovery
Beginning crash recovery of 2 threads
Started redo scan
kcrfr_rnenq: use log nab 201057
kcrfr_rnenq: use log nab 43466
Completed redo scan
 read 351699 KB redo, 13118 data blocks need recovery
Thu May 29 21:45:07 2014
Started redo application at
 Thread 1: logseq 189, block 23667
 Thread 2: logseq 102, block 208354
Recovery of Online Redo Log: Thread 1 Group 5 Seq 189 Reading mem 0
  Mem# 0: +DATA2/orcl/redo05.log
Recovery of Online Redo Log: Thread 2 Group 8 Seq 102 Reading mem 0
  Mem# 0: +DATA2/orcl/redo08.log
Recovery of Online Redo Log: Thread 2 Group 7 Seq 103 Reading mem 0
  Mem# 0: +DATA2/orcl/redo07.log
Hex dump of (file 4, block 224) in trace file /home/oracle/trace/diag/rdbms/orcl/ORCL1/trace/ORCL1_ora_4415.trc
Reading datafile '+DATA/orcl/datafile/undotbs2.274.847998769' for corruption at rdba: 0x010000e0 (file 4, block 224)
Reread (file 4, block 224) found same corrupt data (logically corrupt)
RECOVERY OF THREAD 2 STUCK AT BLOCK 224 OF FILE 4Abort recovery for domain 0
Aborting crash recovery due to error 1172
Errors in file /home/oracle/trace/diag/rdbms/orcl/ORCL1/trace/ORCL1_ora_4415.trc:
ORA-01172: recovery of thread 2 stuck at block 224 of file 4
ORA-01151: use media recovery to recover block, restore backup if needed
Abort recovery for domain 0
Errors in file /home/oracle/trace/diag/rdbms/orcl/ORCL1/trace/ORCL1_ora_4415.trc:
ORA-01172: recovery of thread 2 stuck at block 224 of file 4
ORA-01151: use media recovery to recover block, restore backup if needed
ORA-1172 signalled during: ALTER DATABASE OPEN /* db agent *//* {1:56922:2} */... ]
----------------end alert log snippet ---------



-----------------------------------
[oracle@11gRAC1 trace]$ rman target /

Recovery Manager: Release 11.2.0.3.0 - Production on Thu May 29 21:51:38 2014

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

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

RMAN> backup check logical validate database ;

Starting backup at 29-MAY-14
using target database control file instead of recovery catalog
allocated channel: ORA_DISK_1
channel ORA_DISK_1: SID=135 instance=ORCL1 device type=DISK
allocated channel: ORA_DISK_2
channel ORA_DISK_2: SID=196 instance=ORCL1 device type=DISK
channel ORA_DISK_1: starting full datafile backup set
channel ORA_DISK_1: specifying datafile(s) in backup set
input datafile file number=00007 name=+DATA/orcl/data01.dbf
input datafile file number=00002 name=+DATA/orcl/datafile/sysaux.270.847998745
input datafile file number=00005 name=+DATA/orcl/datafile/users.263.847998771
input datafile file number=00004 name=+DATA/orcl/datafile/undotbs2.274.847998769
channel ORA_DISK_2: starting full datafile backup set
channel ORA_DISK_2: specifying datafile(s) in backup set
input datafile file number=00006 name=+DATA3/orcl/indexes01.dbf
input datafile file number=00001 name=+DATA/orcl/datafile/system.269.847998737
input datafile file number=00003 name=+DATA/orcl/datafile/undotbs1.261.847998757
channel ORA_DISK_1: backup set complete, elapsed time: 00:00:34
List of Datafiles
=================
File Status Marked Corrupt Empty Blocks Blocks Examined High SCN
---- ------ -------------- ------------ --------------- ----------
2    OK     0              12879        76876           30261376
  File Name: +DATA/orcl/datafile/sysaux.270.847998745
  Block Type Blocks Failing Blocks Processed
  ---------- -------------- ----------------
  Data       0              21416
  Index      0              17867
  Other      0              24638

File Status Marked Corrupt Empty Blocks Blocks Examined High SCN
---- ------ -------------- ------------ --------------- ----------
4    OK     0              1            38401           30253503
  File Name: +DATA/orcl/datafile/undotbs2.274.847998769
  Block Type Blocks Failing Blocks Processed
  ---------- -------------- ----------------
  Data       0              0
  Index      0              0
  Other      0              38399

File Status Marked Corrupt Empty Blocks Blocks Examined High SCN
---- ------ -------------- ------------ --------------- ----------
5    OK     0              1            641             19721
  File Name: +DATA/orcl/datafile/users.263.847998771
  Block Type Blocks Failing Blocks Processed
  ---------- -------------- ----------------
  Data       0              0
  Index      0              0
  Other      0              639

File Status Marked Corrupt Empty Blocks Blocks Examined High SCN
---- ------ -------------- ------------ --------------- ----------
7    OK     0              1            131072          30266334
  File Name: +DATA/orcl/data01.dbf
  Block Type Blocks Failing Blocks Processed
  ---------- -------------- ----------------
  Data       0              97510
  Index      0              31833
  Other      0              1728

channel ORA_DISK_1: starting full datafile backup set
channel ORA_DISK_1: specifying datafile(s) in backup set
including current control file in backup set
channel ORA_DISK_1: backup set complete, elapsed time: 00:00:01
List of Control File and SPFILE
===============================
File Type    Status Blocks Failing Blocks Examined
------------ ------ -------------- ---------------
Control File OK     0              1128
channel ORA_DISK_1: starting full datafile backup set
channel ORA_DISK_1: specifying datafile(s) in backup set
including current SPFILE in backup set
channel ORA_DISK_2: backup set complete, elapsed time: 00:00:22
List of Datafiles
=================
File Status Marked Corrupt Empty Blocks Blocks Examined High SCN
---- ------ -------------- ------------ --------------- ----------
1    OK     0              12551        89606           30266212
  File Name: +DATA/orcl/datafile/system.269.847998737
  Block Type Blocks Failing Blocks Processed
  ---------- -------------- ----------------
  Data       0              47836
  Index      0              9749
  Other      0              19464

File Status Marked Corrupt Empty Blocks Blocks Examined High SCN
---- ------ -------------- ------------ --------------- ----------
3    OK     0              1            48641           30248852
  File Name: +DATA/orcl/datafile/undotbs1.261.847998757
  Block Type Blocks Failing Blocks Processed
  ---------- -------------- ----------------
  Data       0              0
  Index      0              0
  Other      0              48639

File Status Marked Corrupt Empty Blocks Blocks Examined High SCN
---- ------ -------------- ------------ --------------- ----------
6    OK     0              438          98561           30265514
  File Name: +DATA3/orcl/indexes01.dbf
  Block Type Blocks Failing Blocks Processed
  ---------- -------------- ----------------
  Data       0              0
  Index      0              89706
  Other      0              8416

channel ORA_DISK_1: backup set complete, elapsed time: 00:00:00
List of Control File and SPFILE
===============================
File Type    Status Blocks Failing Blocks Examined
------------ ------ -------------- ---------------
SPFILE       OK     0              2
Finished backup at 29-MAY-14

-------------------------------------------------

BACKUP , RECOVERY and archive log handling in RAC

Here are few basic points to consider about safe backup and recovery in RAC environment :

• If DB running in archive log mode then archive logs should be placed on a single location(say single ASM directory) in shared disk so that if you ever needs to recover then you do not need to copy all archive logs to a single location or supply archive log file names manually for each log sequence#. Configuring Flash recovery area is so good option for RAC databases.
• If you have less storage available or you want faster archiving only then you should consider archiving logs to local disks of nodes.                                                                                           
• In case all instances crashes(power failure in data centre) then you should bring all nodes one by one. As this way it is not only cluster ware will have safe recovery but also  Database crash recovery will also be safe. 
• Configure RMAN control file auto back-up feature also to shared disks (say OCFS file system,if applicable) as this will allow control file to be restored from any node and hence so recovery also.

• As RAC instances has more shared pool available than single instance you can increase large pool size to increase RMAN buffers for faster backup so you may multiplex more files in backupset and parallelize more if enough CPUs available but remember higher multiplexing can potentially slow down restore.

• To benefit from more CPUs available in RAC than single instance database backup channels can be opened across all RAC nodes this when combines with benefits of compressed backup sets speeds up backup   

ORA-00314: log 3274 of thread 1, expected sequence# 3276 doesn't match 3276

I had power failure while there was heavy DMLs running on my database and after

restating machine I my database(running in noarchive log mode) did not start due 

failed automatic instance recovery due error:  "ORA-00314: log %s of thread %s, 

expected sequence# %s doesn't match %s". 

Strange part was lower log sequence number mentioned in error message was already 

applied fully to database and it was even not appearing in v$log as inactive,it was 

so old though there was another log group active so it means recovery was vital

So,I tried to recover using first broader recovery command preferred to start with as safe practice "recover

database" but it did not succeed then I tried same using RMAN and then using backup 

control file syntax. Recovery prompted for couple of log sequences which I supplied 

after joing and v$ and v$logfile for corresponding thread# and sequence# but recovery 

terminated saying "datafile 1 may need recovery" It just mean I was unlucky as in most

of cases this error is solved by recover database until cancel using backup controlfile

. Then I tried with recreating controlfile and then recovery and then I tried with 

clearing logfiles but it also did not give me any luck. Finally I had to restore from

cold backup. Luckily it was just a test database. 

oerr reasons: 

ORA-00314: log %s of thread %s, expected sequence# %s doesn't match %s
 *Cause:  The online log is corrupted or is an old version.
 *Action: Find and install correct version of log or reset logs.

TNS-12555: TNS:permission denied

This error comes when you want to start the listener service from wrong user. Suppose you have installed 11g2 RAC then you can start listener of grid using grid or oracle user but if you want to start the listener service from any user other than them say as test below then you will get error : TNS-12555: TNS:permission denied
 
[test@node1 ~]$ /u01/11.2.0/grid/bin/lsnrctl start LISTENER
LSNRCTL for Linux: Version 11.2.0.3.0 - Production on 21-SEP-2013 11:42:57
Copyright (c) 1991, 2011, Oracle.  All rights reserved.
Starting /u01/11.2.0/grid/bin/tnslsnr: please wait...
TNSLSNR for Linux: Version 11.2.0.3.0 - Production
System parameter file is /u01/11.2.0/grid/network/admin/listener.ora
Log messages written to /u01/11.2.0/grid/log/diag/tnslsnr/node1/listener/alert/log.xml
Error listening on: (DESCRIPTION=(ADDRESS=(PROTOCOL=IPC)(KEY=LISTENER)))
TNS-12555: TNS:permission denied TNS-12560: TNS:protocol adapter error
  TNS-00525: Insufficient privilege for operation
   Linux Error: 1: Operation not permitted
Listener failed to start. See the error message(s) above...

log file sync wait event

This wait event belongs to commits wait class and implies user session has issued commit but it is not completed as redo log writers has not yet finished writing into the redo log file i.e all redo log buffers are not flushed to redo log file disk. Excessive waits on log file sync wait event indicates either there are too many commits or slow I/O sub system on which redo log files have been placed.

User Actions that should be taken:

• Do not put redo logs on RAID 5. Now a days SSD disks have evolved in much bigger use but NAND flash based SSD disks should not be used to store redo log file as redo log writes are sequential writes for which these disks are not suitable. DDR based SSD can be used to used to store redo logfile.  Place log files on dedicated disks. Consider putting log files on striped disks.

• Be prudent with frequency of commits and commit batch size .  If there are lots of short duration transactions, see if it is possible to BATCH transactions together so there are fewer distinct COMMIT operations. Each commit has to have it confirmed that the relevant REDO is on disk. Although commits can be piggybacked by Oracle, reducing the overall number of commits by batching transactions can have a very beneficial effect.

•Determine whether any activity can safely be done with NOLOGGING / UNRECOVERABLE options. This may be an option in data ware house where data can be reproducabile.

ORA-00054: resource busy and acquire with NOWAIT specified or timeout expired

DDL Wait Option in 11g:

Any DDL operation on table/index in a session can not succeed if table is in used by some transaction(DML,acuired TM lock) by other session

SQL> alter table trans add (tran_code varchar2(10));
But instead of getting  “Table altered”, DBA gets:
alter table trans add (tran_code varchar2(10));
*
ERROR at line 1:
ORA-00054: resource busy and acquire with NOWAIT specified or timeout expired

The error message says the table is being used right now, probably by a transaction(DML), so getting an exclusive lock on the table may be next to impossible. Of course, the rows of the table are not locked forever. When sessions perform commit the locks on those rows are released, but before that unlock period gets very far, other sessions may update some other rows of the table—and thus the slice of time to get the exclusive lock on the table vanishes.

In Oracle Database 11g DBA has a better option: the DDL Wait option. DBA issues:
SQL> alter session set ddl_lock_timeout = 10;
Session altered.

Now, when a DDL statement in the session does not get the exclusive lock, it will not error out. Instead, it will wait for 10 seconds. In that 10 seconds, it continually re-tries the DDL operation until it’s successful or the time expires, whichever comes first. When DBA issues:
SQL>  alter table trans add (tran_code varchar2(10));
the statement hangs and does not error out.  This gets completed as soon as TM lock is released by DDL. If you issue ALTER SYSTEM SET DDL_LOCK_TIMEOUT = 10 it can be set at the system level as well.

rename log file , data file or dropping log files in oracle straight forward

I'm writting this post for beginner DBAs to let them apply concept of redo log file,instance recovery and file management.

There are two ways to acheive rename datafile/redo logfile it:

1) data file and log files both can be renamed at the mount stage of database with same command ALTER DATABASE RENAME FILE OLDNAME TO NEWNAME;

steps #a) shutdown immediate
         #b) copy /path/redolog1 /newpath/redolog1_a
               copy /path/datafile1 /newpath/datafile01              
         #c) startup mount
         #d) alter database rename file '/path1/redolog1' to '/newpath2/redolog1a';
               alter database rename file '/path/datafile1' '/newpath/datafile01'
         #e) alter database open  

2) redo log files can not be renamed while database is open though you can drop redo logfile and create the one with the new path/name. On the other hand datafile can be renamed while the database is open(online) with ALTER TABLESPACE RENAME DATAFILE OLDNAME TO NEWNAME

steps #a) alter tablespace mydata offline;
          #b) host copy /path1/datafile1 /newpath2/datafile_01
          #c)  alter tablespace rename datafile '/path1/datafile1' to '/newpath2/datafie_01'
          #d) alter tablespace mydata online;

SQL> alter database add logfile 'd:\oracle\product\10.2.0\oradata\orcl\REDO04.log' size 50m reuse;
Database altered.

SQL> shutdown immediate
Database closed.
Database dismounted.
ORACLE instance shut down.
SQL> startup mount
ORACLE instance started.
Total System Global Area  234881024 bytes
Fixed Size                  1289916 bytes
Variable Size             163578180 bytes
Database Buffers           62914560 bytes
Redo Buffers                7098368 bytes
Database mounted.
SQL> host copy D:\ORACLE\PRODUCT\10.2.0\ORADATA\ORCL\REDO04.LOG D:\REDO04.log
        1 file(s) copied.

SQL> alter database rename file 'D:\ORACLE\PRODUCT\10.2.0\ORADATA\ORCL\REDO04.LOG' to 'D:\REDO04.log';
Database altered.

SQL> alter database open;
Database altered.

Dropping redo logfile is also pretty straight forward thing. You just need to know active redo log file/group can not be dropped ,similarly current redo logfile/group can not be dropped.


Active redo log can not be dropped as checkpoint of its contents is not complete obviously and current redo log can be dropped because log write process is currently writing into it. Once I found my jumior DBA attempting to drop redo logfile which was active and it failed for above stated reason.So remedy I told her was to issue first Alter System CHECKPOINT. 


And to drop current redo log file group, first issue alter switch logfile command so that it is no longer current redo log group, it now becomes active redo log group and then issue alter system checkpoint command followed by drop logfile group or drop logfile command.

SQL> alter database drop logfile group 2;
alter database drop logfile group 2
*
ERROR at line 1:
ORA-01624: log 2 needed for crash recovery of instance orcl (thread 1)ORA-00312: online log 2 thread 1: 'D:\ORACLE\PRODUCT\10.2.0\ORADATA\ORCL\REDO02.LOG'

SQL> select * from v$log;
    GROUP#    THREAD#  SEQUENCE#      BYTES    MEMBERS ARC STATUS           FIRST_CHANGE# FIRST_TIM
---------- ---------- ---------- ---------- ---------- --- ---------------- ------------- ---------
         1          1        403   52428800          1 YES ACTIVE                 2839841 21-SEP-13
         2          1        404   52428800          1 YES ACTIVE                 2839884 21-SEP-13
         3          1        406   52428800          1 NO  CURRENT                2839888 21-SEP-13
         4          1        405   52428800          1 YES ACTIVE                 2839886 21-SEP-13
SQL> alter system checkpoint ;
System altered.
SQL> select * from v$log;
    GROUP#    THREAD#  SEQUENCE#      BYTES    MEMBERS ARC STATUS           FIRST_CHANGE# FIRST_TIM
---------- ---------- ---------- ---------- ---------- --- ---------------- ------------- ---------
         1          1        403   52428800          1 YES INACTIVE               2839841 21-SEP-13
         2          1        404   52428800          1 YES INACTIVE               2839884 21-SEP-13
         3          1        406   52428800          1 NO  CURRENT                2839888 21-SEP-13
         4          1        405   52428800          1 YES INACTIVE               2839886 21-SEP-13
SQL> alter database drop logfile group 2;
Database altered.

Here alternatively log member of redo log group #2 could be queried and drop logfile command also could be issued: [ select l.group#,l.sequence#,l.status,lf.member,l.bytes/1024/1024 SIZE_MB  from v$log l, v$logfile lf where l.group#=lf.group# order by l.sequence#;

alter database drop logfile '/u05/app/dbf/redo02log';  ]

SQL> select * from v$log;
    GROUP#    THREAD#  SEQUENCE#      BYTES    MEMBERS ARC STATUS           FIRST_CHANGE# FIRST_TIM
---------- ---------- ---------- ---------- ---------- --- ---------------- ------------- ---------
         1          1        410   52428800          1 YES INACTIVE               2839985 21-SEP-13
         3          1        409   52428800          1 YES INACTIVE               2839983 21-SEP-13
         4          1        411   52428800          1 NO  CURRENT                2839987 21-SEP-13
SQL> alter database drop logfile group 4;
alter database drop logfile group 4
*
ERROR at line 1:
ORA-01623: log 4 is current log for instance orcl (thread 1) - cannot drop
ORA-00312: online log 4 thread 1: 'D:\REDO04.LOG'

what is cost in execution plan in oracle

What is meaning of COST in execution plan in Oracle:

COST in execution plan is a relative factor which tells how much single block read,multi block reads, temporay space operations will take place along with , CPU cycles (cpu cycle can differe in various operations). If two costs are closer than it does not mean their execution time will also be closer. Generally index scan needs more CPU cycles than FTS. In same way Nested loop join involves more CPU than Hash Join and Sort Merge join., while hash and sort-merge join needs temporay work area UGA(part of PGA)(as well temp space depends) which is not needed in Nested Loop join.

You should gather system statistics at representative workload so that oracle knows what is single block read time, what is multiblock read time and what is CPU speed etc. This way cost calclulated is absolutely best provided the table,index,columns statistics(histograms, if needed) are accurate.

e.g. Consider below two queries for which cost are closer but execution time is differing a lot

1. select count(*) from (select * from mytab union all select * from mytab); and
2 select sum(c) from (select count(*) c from mytab union all select count(*) c from mytab);

Their cost in execution plan is quite close but execution time of second query is less than half of first query.  Below uses dynamic sampling but it does not make difference.

SQL> conn scott/tiger
Connected.
SQL> create table mytab as select * from all_objects;
Table created.
SQL> explain plan for select count(*) from (select * from mytab union all select * from mytab);
Explained.
SQL> select * from table(dbms_xplan.display);
PLAN_TABLE_OUTPUT
-----------------------------------------------------------------------------------------------
Plan hash value: 1229214271
----------------------------------------------------------------------
| Id | Operation | Name | Rows | Cost (%CPU)| Time |
----------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | 313 (1)| 00:00:04 |
| 1 | SORT AGGREGATE | | 1 | | |
| 2 | VIEW | | 115K| 313 (1)| 00:00:04 |
| 3 | UNION-ALL PARTITION| | | | |
| 4 | TABLE ACCESS FULL | MYTAB  | 46942 | 159 (2)| 00:00:02 |
| 5 | TABLE ACCESS FULL | MYTAB| 46942 | 159 (2)| 00:00:02 |
----------------------------------------------------------------------
Note
-----
- dynamic sampling used for this statement
16 rows selected.
SQL> explain plan for select sum(c) from (select count(*) c from mytab union all select count(*) c from mytab);
Explained.
SQL> select * from table(dbms_xplan.display);
PLAN_TABLE_OUTPUT
-----------------------------------------------------------------------------------------------
Plan hash value: 3291583229
------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | 13 | 316 (1)| 00:00:04 |
| 1 | SORT AGGREGATE | | 1 | 13 | | |
| 2 | VIEW | | 2 | 26 | 316 (1)| 00:00:04 |
| 3 | UNION-ALL | | | | | |
| 4 | SORT AGGREGATE | | 1 | | | |
| 5 | TABLE ACCESS FULL| MYTAB| 46942 | | 158 (1)| 00:00:02 |
| 6 | SORT AGGREGATE | | 1 | | | |
| 7 | TABLE ACCESS FULL| MYTAB  | 46942 | | 158 (1)| 00:00:02 |
------------------------------------------------------------------------------
Note
-----
- dynamic sampling used for this statement
18 rows selected.
SQL> --now alter system flsuh buffer_cache from sys session
SQL> alter session set statistics_level=all;
Session altered.

You notice COST of both queries are very close. Now check actual execution time

SQL> set timing on
SQL> select count(*) from (select * from mytab union all select * from mytab);
COUNT(*)
----------
100192
Elapsed: 00:00:01.77
SQL> select * from table(dbms_xplan.display_cursor(null,null,'allstats last'));
PLAN_TABLE_OUTPUT
-----------------------------------------------------------------------------------------------
SQL_ID 5wn0myv3kcsvs, child number 0
-------------------------------------
select count(*) from (select * from mytab union all select * from mytab)
Plan hash value: 1229214271
----------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows | A-Rows | A-Time | Buffers |
----------------------------------------------------------------------------------------
| 1 | SORT AGGREGATE | | 1 | 1 | 1 |00:00:01.77 | 1386 |
| 2 | VIEW | | 1 | 115K| 100K|00:00:01.60 | 1386 |
| 3 | UNION-ALL PARTITION| | 1 | | 100K|00:00:01.10 | 1386 |
| 4 | TABLE ACCESS FULL | MYTAB  | 1 | 46942 | 50096 |00:00:00.15 | 693 |
| 5 | TABLE ACCESS FULL | MYTAB| 1 | 46942 | 50096 |00:00:00.10 | 693 |
----------------------------------------------------------------------------------------
Note
-----
- dynamic sampling used for this statement

20 rows selected.
Elapsed: 00:00:00.09
SQL> --now alter system flsuh buffer_cache from sys session
SQL> select sum(c) from (select count(*) c from mytab union all select count(*) c from mytab);
SUM(C)
----------
100192
Elapsed: 00:00:00.61
SQL> select * from table(dbms_xplan.display_cursor(null,null,'allstats last'));
PLAN_TABLE_OUTPUT
----------------------------------------------------------------------------------------------------
SQL_ID gq7ca01amc88s, child number 0
-------------------------------------
select sum(c) from (select count(*) c from mytab union all select count(*) c from mytab)
Plan hash value: 3291583229
-------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows | A-Rows | A-Time | Buffers | Reads |
-------------------------------------------------------------------------------------------------
| 1 | SORT AGGREGATE | | 1 | 1 | 1 |00:00:00.60 | 1386 | 689 |
| 2 | VIEW | | 1 | 2 | 2 |00:00:00.60 | 1386 | 689 |
| 3 | UNION-ALL | | 1 | | 2 |00:00:00.60 | 1386 | 689 |
| 4 | SORT AGGREGATE | | 1 | 1 | 1 |00:00:00.35 | 693 | 689 |
| 5 | TABLE ACCESS FULL| MYTAB  | 1 | 46942 | 50096 |00:00:00.27 | 693 | 689 |
| 6 | SORT AGGREGATE | | 1 | 1 | 1 |00:00:00.25 | 693 | 0 |
| 7 | TABLE ACCESS FULL| MYTAB  | 1 | 46942 | 50096 |00:00:00.15 | 693 | 0 |
-------------------------------------------------------------------------------------------------
Note
-----
- dynamic sampling used for this statement

22 rows selected.
Elapsed: 00:00:00.10
SQL> spool off

You see second query is more than twice faster than first query
 

ORA-00020: maximum number of processes (%s) exceeded

If you are not able to log into oracle database because of error ORA-00020: maximum number of processes (%s) exceeded then remedy is open prelim connection as below and issue shutdown command or else try to kill some oracle processes and see if get luckk

sqlplus -prelim / as sysdba
SQL>shutdown immediate
SQL>startup

 

ORA-00845: MEMORY_TARGET not supported on this system - automatic memory management

Oracle error "ORA-00845: MEMORY_TARGET not supported on this system" is encountered in oracle 11g and 12c databases when instance tries to use automatic memory management and tmpfs mount point is less than the value specified in oracle database instance parameter memory_max_target.  Remedy is unmount the tmpfs and mount with increased space for tmps but also recommended is same change in /etc/fstab for permanent effect to take place.

SQL> alter system set memory_max_target=1024m scope=spfile;
System altered.
SQL> startup force
ORA-00845: MEMORY_TARGET not supported on this systemSQL> exit
Disconnected from Oracle Database 12c Enterprise Edition Release 12.1.0.1.0 - 64bit Production
With the Partitioning, OLAP, Advanced Analytics and Real Application Testing options
[oracle@orcl12c ~]$ df -h
Filesystem            Size  Used Avail Use% Mounted on
/dev/sda5              13G   10G  2.2G  83% /
tmpfs                 939M   72K  939M   1% /dev/shm/dev/sda1              73M   29M   41M  41% /boot
/dev/sda2            1008M   43M  915M   5% /tmp
vmshare               1.7T  161G  1.5T  10% /media/sf_vmshare
[oracle@orcl12c ~]$ su -
Password:
[root@orcl12c ~]# umount tmpfs
umount: /dev/shm: device is busy.
        (In some cases useful info about processes that use
         the device is found by lsof(8) or fuser(1))
[root@orcl12c ~]# umount -l tmpfs
[root@orcl12c ~]# mount -t tmpfs  tmpfs -o size=10240m /dev/shm
[root@orcl12c ~]# df -h
Filesystem            Size  Used Avail Use% Mounted on
/dev/sda5              13G   10G  2.2G  83% /
/dev/sda1              73M   29M   41M  41% /boot
/dev/sda2            1008M   43M  915M   5% /tmp
vmshare               1.7T  161G  1.5T  10% /media/sf_vmshare
tmpfs                  10G     0   10G   0% /dev/shm
[root@orcl12c ~]# cat /etc/fstab
.
.
tmpfs                   /dev/shm                tmpfs   defaults        0 0
.
.

[root@orcl12c ~]# vi /etc/fstab
[root@orcl12c ~]# cat /etc/fstab
.
.
#tmpfs                   /dev/shm                tmpfs   defaults        0 0
tmpfs                   /dev/shm                tmpfs   size=1024m      0 0
.
.
[root@orcl12c ~]# exit
logout
[oracle@orcl12c ~]$ sqlplus / as sysdba
SQL*Plus: Release 12.1.0.1.0 Production on Sun Aug 4 15:35:40 2013
Copyright (c) 1982, 2013, Oracle.  All rights reserved.
Connected to an idle instance.
SQL> startup
ORACLE instance started.
Total System Global Area 1068937216 bytes
Fixed Size                  2296576 bytes
Variable Size            1010828544 bytes
Database Buffers           50331648 bytes
Redo Buffers                5480448 bytes
Database mounted.
Database opened.
SQL> show parameter memory_max_target
NAME                                 TYPE        VALUE
------------------------------------ ----------- ------------------------------
memory_max_target                    big integer 1G
SQL> show parameter sga_max_size
NAME                                 TYPE        VALUE
------------------------------------ ----------- ------------------------------
sga_max_size                         big integer 1G
SQL> rem sga_max_size is set automatically equal to the memory_max_target
SQL> show parameter memory_target
NAME                                 TYPE        VALUE
------------------------------------ ----------- ------------------------------
memory_target                        big integer 0
SQL> alter system set memory_target=1024m;
System altered.
SQL>REM now automatic memory management has been configured

shutdown active processes prevent shutdown operation

When shutdown immediate hanged for long I found in user dump a trace file containing messgaes

ksukia: Attempt 1 to re-kill process OS PID=7427.
ksukia: Attempt 2 to re-kill process OS PID=7427..
.
.
.
$ ps -ef grep 7427

...

oracle 7426 11402 0 09:34 pts/1 00:00:00 sqlplus @a.sql

oracle 7427 7426 0 09:34 ? 00:00:00 [oracle] defunct

This process 7427 was defunct (dead) as it appeared defunct. So this could not be killed directly with kill -9, instead its parent process sqlplus was killed and shutdown immediate proceeded

Many guys on interent suggested shutdown abort but that must be avoided.

Oracle full of features but BUGs too ORA-00600: internal error code, arguments: [kcratr1_lostwrt],

SETUP : two node 9i rac 9204 ON ocfs ON WIN 2K

first instance crahed due OCFS bug
now second rtried instance recovery of crashed first instance and it quite successfully recovered the first instance(appareent fro malert log of seconds instance)
but sooner secondnstance crashes too and throws ora-600 internal error.

ORA-00600: internal error code, arguments: [kcratr1_lostwrt], [], [], [], [], [], [], []

I tried to manually start the database but oracle throwing same error and complaining about corrupted logs the lost update. I used first argument of ora-600 here [kcratr1_lostwrt] - searched in metalink using ora-600 lookup tool broadly suggested either that was dangerous situation - required media recovery or that could be BUG with other OS like HP Unix and oracle software versions 9205 onwards. which was not our case.Oracle was spuriously trying to recover in second case and metalink told it can be recovered easily in second case.

I preferred to choose second solution path first over giving recover database command (with out restore from backup/after restore). So I set undocument parameter two_pass=false and opened the database successfully from first instance.then I removed this parameter and opened from first instance and second instance,respectively.

keep watch always on query causing extra I/O becuase of high HWM ..its high high high !!!

while I keep watch always on top resoucre intensive queries I observerd many time

HUGE I/O ON DEF$_AQERROR,THOUGH NO ROW in that CURRENTLY.
Since oracle checks for def error perioidically,it was wasting resource in our case.

for that Query oracle fires internally is below:

select q_name, state, delay, expiration, rowid, msgid,
dequeue_msgid, chain_no, local_order_no, enq_time, enq_tid,
step_no, priority, exception_qschema, exception_queue,
retry_count, corrid, time_manager_info
from SYSTEM.DEF$_AQERROR
where time_manager_info <= :1
and state != :2
for
update skip locked

currently there is no row in SYSTEM.DEF$_AQERROR table.
Though there were some errors seen in DEFERROR view a month ago due
confliction but we deleted them giving command like following for every error transaction.

.
execute dbms_defer_sys.delete_error(destination=>null,deferred_tran_id=>'1.26.1180542');
..
commit;


meanwhile we set parametr refresh_after_errors to true in all mv refreh group and when got all errors
removed from DEFERROR at master site we set back these parameter to default i.e
false.

Now my question was why did we still had reads from DEF$_ERRROR and that was comming in huge physical reads, the highest on instance.

Thouught:

that happening beacuse of HWM of DEF$_AQERROR was not reset by oracle's given error
removal procedure dbms_defer_sys.delete_error.

I took following action.

1. for all master groups
Suspend the master acivity at master site.
SQL> connect repadmin/repadmin
SQL> begin
dbms_repcat.suspend_master_activity(gname=>'REPDBA_MG');
end;
/

2.Truncate the table

SQL>connect SYSTEM/

SQL> truncate table def$aq_error;

3. Resume the master activity for all masterr groups.

SQL> connect repadmin/repadmin
SQL> begin
dbms_repcat.resume_master_activity(gname=>'REPDBA_MG');
end;
/



and I was done.

since then I never saw that query in top SQL

gotcha in distributed transactions

while I was just running a query fetching records from remote master db(MASTERDB), connection failed...resulted in PMON trying to clean this transaction every now and then(indicated from alert log).... I had worries my client DB(DEVDB) instance could be terminated,then I found way to resolve it as follows...

AT CLIENT DB(runing query fetching data from master db using dblink)

SQL> show parameter db_name

NAME TYPE VALUE
------------------------------------ ----------- ------------------------------
db_name string DEVDB
SQL> show user
USER is "SYS"
SQL> set line 300
SQL> SELECT LOCAL_TRAN_ID, GLOBAL_TRAN_ID, STATE, MIXED, HOST, COMMIT#
2 FROM DBA_2PC_PENDING;

LOCAL_TRAN_ID GLOBAL_TRAN_ID STATE MIX
---------------------- ------------------------------------------------------------------------------------------------------------------------------------------------------------------------- ---------------- ---
HOST COMMIT#
-------------------------------------------------------------------------------------------------------------------------------- ----------------
5.6.717654 DEVDB.schemaname.ORG.6c69aa83.5.6.717654 collecting no
schemaname\DEVNODE 3486961816


SQL> set line 80
SQL> desc dba_2pc_pending
Name Null? Type
----------------------------------------- -------- ----------------------------
LOCAL_TRAN_ID NOT NULL VARCHAR2(22)
GLOBAL_TRAN_ID VARCHAR2(169)
STATE NOT NULL VARCHAR2(16)
MIXED VARCHAR2(3)
ADVICE VARCHAR2(1)
TRAN_COMMENT VARCHAR2(255)
FAIL_TIME NOT NULL DATE
FORCE_TIME DATE
RETRY_TIME NOT NULL DATE
OS_USER VARCHAR2(64)
OS_TERMINAL VARCHAR2(255)
HOST VARCHAR2(128)
DB_USER VARCHAR2(30)
COMMIT# VARCHAR2(16)

SQL> col global_tran_id format a35
SQL> /

LOCAL_TRAN_ID GLOBAL_TRAN_ID STATE MIX
---------------------- ----------------------------------- ---------------- ---
HOST
--------------------------------------------------------------------------------
COMMIT#
----------------
5.6.717654 DEVDB.schemaname.ORG.6c69aa83.5.6.717654 collecting no
schemaname\DEVNODE
3486961816


SQL> set line 300
SQL> /

LOCAL_TRAN_ID GLOBAL_TRAN_ID STATE MIX HOST COMMIT#
---------------------- ----------------------------------- ---------------- --- -------------------------------------------------------------------------------------------------------------------------------- ----------------
5.6.717654 DEVDB.schemaname.ORG.6c69aa83.5.6.717654 collecting no schemaname\DEVNODE 3486961816

SQL>
SQL> SELECT LOCAL_TRAN_ID, IN_OUT, DATABASE, INTERFACE
2 FROM DBA_2PC_NEIGHBORS;

LOCAL_TRAN_ID IN_ DATABASE I
---------------------- --- -------------------------------------------------------------------------------------------------------------------------------- -
5.6.717654 in N
5.6.717654 out MASTERDB.schemaname.ORG N

SQL> execute DBMS_TRANSACTION.PURGE_LOST_DB_ENTRY('5.6.717654');
BEGIN DBMS_TRANSACTION.PURGE_LOST_DB_ENTRY('5.6.717654'); END;

*
ERROR at line 1:
ORA-30019: Illegal rollback Segment operation in Automatic Undo mode
ORA-06512: at "SYS.DBMS_TRANSACTION", line 65
ORA-06512: at "SYS.DBMS_TRANSACTION", line 85
ORA-06512: at line 1


SQL> set transaction use rollback segment system
2 ;
set transaction use rollback segment system
*
ERROR at line 1:
ORA-30019: Illegal rollback Segment operation in Automatic Undo mode


SQL> show user;
USER is "SYS"
SQL> alter session set "_smu_debug_mode" = 4;

Session altered.

SQL> execute DBMS_TRANSACTION.PURGE_LOST_DB_ENTRY('5.6.717654');

PL/SQL procedure successfully completed.

SQL> commit;

Commit complete.

SQL> spool off