Manually Add Datafile

I have a database that runs on RAW devices. Whenever I add a datafile to a tablespace, out UNIX Sys Admins must first create the RAW device on the Primary & Standby Server. The other day they created the RAW device on the standby server but forgot to change the ownership of the RAW device to oracle:dba.

The datafile was successfully added to the primary database, but I found the following error in the alert.log of the standby:

File #323 added to control file as 'UNNAMED00323'.

Originally created as:

'/dev/vx/rdsk/oradg1/casprd_SA_I_CMD10'

Recovery was unable to create the file as:

'/dev/vx/rdsk/oradg1_dg/casprd_SA_I_CMD10'

MRP0: Background Media Recovery terminated with error 1119

Mon Mar 9 23:41:44 2010

Errors in file /opt/apps/oracle/admin/caspp/bdump/caspp_mrp0_15261.trc:

ORA-01119: error in creating database file '/dev/vx/rdsk/oradg1_dg/casprd_SA_I_CMD10'

ORA-27040: file create error, unable to create file

HPUX-ia64 Error: 13: Permission denied

Managed Standby Recovery not using Real Time Apply

Some recovered datafiles maybe left media fuzzy

Media recovery may continue but open resetlogs may fail

Mon Mar 9 23:41:45 2010

Errors in file /opt/apps/oracle/admin/caspp/bdump/caspp_mrp0_15261.trc:

ORA-01119: error in creating database file '/dev/vx/rdsk/oradg1_dg/casprd_SA_I_CMD10'

ORA-27040: file create error, unable to create file

HPUX-ia64 Error: 13: Permission denied

I can only qquery some v$ views when a standby database is mounted. So to fix the problem I did the following:

On production get the relevant details

SQL>select ts# from v$tablespace where name = 'SA_I_CMD';

TS#

----------

17

SQL> col name for a80;

SQL> select FILE#, NAME, bytes/1024/1024 MB from v$datafile where ts#=17;

FILE# NAME MB

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

34 /dev/vx/rdsk/oradg/casprd_SA_I_CMD03 32500

35 /dev/vx/rdsk/oradg/casprd_SA_I_CMD 31144

36 /dev/vx/rdsk/oradg/casprd_SA_I_CMD02 30712

37 /dev/vx/rdsk/oradg/casprd_SA_I_CMD01 32360

38 /dev/vx/rdsk/oradg/casprd_SA_I_CMD04 32500

39 /dev/vx/rdsk/oradg/casprd_SA_I_CMD05 30000

201 /dev/vx/rdsk/oradg/casprd_SA_I_CMD06 20000

266 /dev/vx/rdsk/oradg1/casprd_SA_I_CMD07 32500

307 /dev/vx/rdsk/oradg1/casprd_SA_I_CMD08 32500

311 /dev/vx/rdsk/oradg1/casprd_SA_I_CMD09 32500

323 /dev/vx/rdsk/oradg1/casprd_SA_I_CMD10 32500

Lets look at the same query on the standby side

SQL> col name for a80

SQL> select FILE#, NAME, bytes/1024/1024 MB from v$datafile where ts#=17;

FILE# NAME MB

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

34 /dev/vx/rdsk/oradg_dg/casprd_SA_I_CMD03 32500

35 /dev/vx/rdsk/oradg_dg/casprd_SA_I_CMD 31144

36 /dev/vx/rdsk/oradg_dg/casprd_SA_I_CMD02 30712

37 /dev/vx/rdsk/oradg_dg/casprd_SA_I_CMD01 32360

38 /dev/vx/rdsk/oradg_dg/casprd_SA_I_CMD04 32500

39 /dev/vx/rdsk/oradg_dg/casprd_SA_I_CMD05 30000

201 /dev/vx/rdsk/oradg_dg/casprd_SA_I_CMD06 20000

266 /dev/vx/rdsk/oradg1_dg/casprd_SA_I_CMD07 32500

307 /dev/vx/rdsk/oradg1_dg/casprd_SA_I_CMD08 32500

311 /dev/vx/rdsk/oradg1_dg/casprd_SA_I_CMD09 32500

323 /opt/apps/oracle/product/10.2.0.4.0/dbs/UNNAMED00323 0

After the UNIX admin corrected the file permissions of the RAW device I had to manually add it as a datafile to the standby database.

SQL>alter system set STANDBY_FILE_MANAGEMENT=MANUAL;

System altered.

SQL>ALTER DATABASE CREATE DATAFILE ‘/opt/apps/oracle/product/10.2.0.4.0/dbs/UNNAMED00323' as '/dev/vx/rdsk/oradg1_dg/casprd_SA_I_CMD10';

Database altered.

SQL>select FILE#, NAME, bytes/1024/1024 MB from v$datafile where ts#=17;

FILE# NAME MB

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

34 /dev/vx/rdsk/oradg_dg/casprd_SA_I_CMD03 32500

35 /dev/vx/rdsk/oradg_dg/casprd_SA_I_CMD 31144

36 /dev/vx/rdsk/oradg_dg/casprd_SA_I_CMD02 30712

37 /dev/vx/rdsk/oradg_dg/casprd_SA_I_CMD01 32360

38 /dev/vx/rdsk/oradg_dg/casprd_SA_I_CMD04 32500

39 /dev/vx/rdsk/oradg_dg/casprd_SA_I_CMD05 30000

201 /dev/vx/rdsk/oradg_dg/casprd_SA_I_CMD06 20000

266 /dev/vx/rdsk/oradg1_dg/casprd_SA_I_CMD07 32500

307 /dev/vx/rdsk/oradg1_dg/casprd_SA_I_CMD08 32500

311 /dev/vx/rdsk/oradg1_dg/casprd_SA_I_CMD09 32500

323 /dev/vx/rdsk/oradg1_dg/casprd_SA_I_CMD10 32500

11 rows selected.

SQL>alter system set STANDBY_FILE_MANAGEMENT=AUTO;

System altered.

SQL>ALTER DATABASE RECOVER MANAGED STANDBY DATABASE THROUGH ALL SWITCHOVER DISCONNECT USING CURRENT LOGFILE;

Database altered.

Bug when creating a physical standby database in 11G

Creating a physical standby database in 11G became a whole lot easier with just one RMAN command – unless you run into a bug :-)

My primary DB runs on Oracle Managed Files on ASM. My physical standby will also run on Oracle Managed Files on ASM on another server, but the ASM diskgroups are not the same.

I used Arub Nanda’s great article Oracle Database 11g: The Top New Features for DBAs and Developers as a guide. The Data Guard article is number 15 in the series and well worth a read if you want to get up and running quickly.
The RMAN script I used:

run {
allocate channel c1 type disk;
allocate auxiliary channel s1 type disk;

SET NEWNAME FOR DATAFILE 1 TO NEW;
SET NEWNAME FOR DATAFILE 2 TO NEW;
SET NEWNAME FOR DATAFILE 3 TO NEW;
SET NEWNAME FOR DATAFILE 4 TO NEW;
SET NEWNAME FOR DATAFILE 5 TO NEW;
SET NEWNAME FOR DATAFILE 6 TO NEW;
SET NEWNAME FOR DATAFILE 7 TO NEW;
SET NEWNAME FOR DATAFILE 8 TO NEW;
SET NEWNAME FOR DATAFILE 9 TO NEW;
SET NEWNAME FOR DATAFILE 10 TO NEW;
SET NEWNAME FOR DATAFILE 11 TO NEW;
SET NEWNAME FOR DATAFILE 12 TO NEW;
SET NEWNAME FOR TEMPFILE 1 TO NEW;

duplicate target database
for standby
from active database
dorecover
spfile
parameter_value_convert 'adevc','adevt'
set db_unique_name='adevt'
set control_files='/opt/apps/oracle/product/11.1.0.7.0/dbs/control01.ctl'
set fal_client='adevt'
set fal_server='adevc'
set standby_file_management='AUTO'
set log_archive_config='dg_config=(adevc,adevt)'
set log_archive_dest_1='location="/dump/oracle/adevt_archivelogs", valid_for=(ONLINE_LOGFILE,ALL_ROLES)'
set log_archive_dest_2='service=adevc LGWR ASYNC valid_for=(ONLINE_LOGFILES,PRIMARY_ROLE) db_unique_name=casdev'
set log_archive_dest_state_2='enable'
set db_create_file_dest='+TADG1'
set db_create_online_log_dest_1='+TADG1'
;

sql channel c1 'alter system archive log current';
sql channel s1 'alter database recover managed standby database using current logfile disconnect';
}
The error found in the RMAN logfile:
channel c1: starting datafile copy
input datafile file number=00023 name=+CADG1/adevc/datafile/all_ts.408.688130429
RMAN-03009: failure of backup command on c1 channel at 04/30/2010 14:54:55
ORA-19504: failed to create file "+TADG1"
channel c1 disabled, job failed on it will be run on another channel
released channel: c1
released channel: s1
RMAN-00571: ===========================================================
RMAN-00569: =============== ERROR MESSAGE STACK FOLLOWS ===============
RMAN-00571: ===========================================================
RMAN-03002: failure of Duplicate Db command at 04/30/2010 14:54:55
RMAN-03015: error occurred in stored script Memory Script

RMAN-03009: failure of backup command on c1 channel at 04/30/2010 14:54:55
ORA-19504: failed to create file "+TADG1"

I found the root cause of the problem on metalink - Standby DATAFILE Creation Failing with RAC / ASM / OMF [ID 787753.1] It turns out to be Bug:7462589. The workaround for the Bug is that the ASM diskgroups on the standby must also be on the primary. The note states that this will be fixed in 11GR2. So my workaround was to create a temporary ASM diskgroup called TADG1 (with only 1 disk) on the primary database server. After that the restore completed successfully.

Long wait times for cursor: pin S and latch: library cache

On our OLTP db we sometimes experienced short bursts (5-15 seconds) of CPU starvation and waits for cursor: pin S or latch: library cache. Especially during busy times. CPU utilization is normally 65% so we were confident that the waits also cause the CPU starvation and not vice versa. In the past few months we have logged multiple SRs with Oracle for the issue but only made progress with 1 where bug Bug 6904068 - High CPU usage when there are "cursor: pin S" waits [ID 6904068.8] was identified. The problem with the other SRs was a case of wrong scope definition. Even though I would upload all the relevant information (ASH, AWR and OS Watcher stats) Oracle Support would look at the top wait in AWR (“db file sequenctial read”) and suggest that we solve that by doing some query tuning and hopefully the mutex/latch problem will also disappear. Even when I convinced them that the problem is not “db file sequential read” they would ask me to take 3x system state dumps when the problem appears. That was an impossible task as the first sytem state dump would kick in when the problem is already occurring, so we could never give support the info they claimed they needed to diagnose the problem.

We were in the fortunate position to ask Tanel Poder to have a look. He also posted some info about the problem and how he systematically solved it. And with the same info I always give to Oracle support, he could correctly identify the problem in a couple of minutes! Most amazing is that the solution is available in the Oracle Documentation. 10g Release 2 (10.2) for UNIX-Based Operating Systems. B15658-02. Appendix B Administering Oracle Database on HP-UX.

What the documentation says:
On HP-UX, most processes use a time-sharing scheduling policy. Time sharing can have detrimental effects on Oracle performance by descheduling an Oracle process during critical operations, for example, when it is holding a latch. HP-UX has a modified scheduling policy, referred to as SCHED_NOAGE, that specifically addresses this issue. Unlike the normal time-sharing policy, a process scheduled using SCHED_NOAGE does not increase or decrease in priority, nor is it preempted.
This feature is suited to online transaction processing environments because online transaction processing environments can cause competition for critical resources.

So the OS scheduler may deschedule a Oracle process while it is holding a mutex/latch because the OS is not aware of what is going on inside Oracle. Now other processes which happen to use that cursor will fail to get the mutex and start spinning. If the mutex holder process has a lower priority than all the other processes who yielded CPU, then it may not get onto CPU soon enough, so it still holds that mutex and the other processes spin and use CPU trying to get that mutex.

How Tanel proved it:
Below are queries from v$event_histogram for the top 2 problem waits. Notice the number of histogram buckets where the wait time is > 512ms:

EVENT_NAME WAIT_TIME_MILLI WAIT_COUNT WAIT%
------------------------------ --------------- -------------- ------
latch: library cache 1 815,980 52.76
latch: library cache 2 187,232 12.11
latch: library cache 4 168,402 10.89
latch: library cache 8 138,053 8.93
latch: library cache 16 102,906 6.65
latch: library cache 32 69,149 4.47
latch: library cache 64 43,797 2.83
latch: library cache 128 11,916 0.77
latch: library cache 256 3,867 0.25
latch: library cache 512 1,005 0.06
latch: library cache 1,024 1,108 0.07
latch: library cache 2,048 1,516 0.10
latch: library cache 4,096 1,293 0.08
latch: library cache 8,192 351 0.02

EVENT_NAME WAIT_TIME_MILLI WAIT_COUNT WAIT%
------------------------------ --------------- -------------- ------
cursor: pin S 1 59,309,179 86.63
cursor: pin S 2 5,988,534 8.75
cursor: pin S 4 2,313,442 3.38
cursor: pin S 8 675,114 0.99
cursor: pin S 16 113,084 0.17
cursor: pin S 32 23,804 0.03
cursor: pin S 64 15,434 0.02
cursor: pin S 128 9,643 0.01
cursor: pin S 256 4,247 0.01
cursor: pin S 512 2,912 0.00
cursor: pin S 1,024 2,871 0.00
cursor: pin S 2,048 2,626 0.00
cursor: pin S 4,096 1,980 0.00
cursor: pin S 8,192 967 0.00
cursor: pin S 16,384 278 0.00
cursor: pin S 32,768 32 0.00

ps –efl > ps.txt
cat ps.txtgrep ".:..:.."awk '{ printf "%6d %50s\n", $7, $15 }'>ps1.txt
cat ps.txtgrep -v ".:..:.."awk '{ printf "%6d %50s\n", $7, $16 }'>ps2.txt
cat ps1.txt ps2.txtgrep ora.*abcprdsort -nuniq -csort -nbrhead -20

NUM
PROCS PRIO PROCESS_NAME
----- ------ -------------------
1936 154 oracleabcprd
25 148 oracleabcprd
4 241 oracleabcprd
1 240 oracleabcprd
1 235 oracleabcprd
1 229 oracleabcprd
1 223 oracleabcprd
1 207 oracleabcprd
1 195 oracleabcprd
1 187 oracleabcprd
1 181 oracleabcprd
1 179 oracleabcprd
1 154 ora_smon_abcprd
1 154 ora_rvwr_abcprd
1 154 ora_rsm0_abcprd
1 154 ora_reco_abcprd
1 154 ora_rbal_abcprd
1 154 ora_qmnc_abcprd
1 154 ora_q004_abcprd
1 154 ora_q003_abcprd
Note the different priorities of the oracle client processes. After we enabled SCHED_NOAGE for Oracle Database as described in the documentation. The output looked like this:

EVENT_NAME WAIT_TIME_MILLI WAIT_COUNT WAIT%
------------------------------ --------------- -------------- ------
latch: library cache 1 53,212 57.39
latch: library cache 2 10,517 11.34
latch: library cache 4 11,069 11.94
latch: library cache 8 5,308 5.72
latch: library cache 16 3,715 4.01
latch: library cache 32 3,506 3.78
latch: library cache 64 5,254 5.67
latch: library cache 128 131 0.14
latch: library cache 256 5 0.01
latch: library cache 512 7 0.01
latch: library cache 1,024 3 0.00

EVENT_NAME WAIT_TIME_MILLI WAIT_COUNT WAIT%
------------------------------ --------------- -------------- ------
cursor: pin S 1 2,267 15.46
cursor: pin S 2 0 0.00
cursor: pin S 4 0 0.00
cursor: pin S 8 0 0.00
cursor: pin S 16 0 0.00
cursor: pin S 32 0 0.00
cursor: pin S 64 0 0.00
cursor: pin S 128 12,380 84.45
cursor: pin S 256 12 0.08

NUM
PROCS PRIO PROCESS_NAME
----- ------ -------------------
1992 178 oracleabcprd
1 178 ora_smon_abcprd
1 178 ora_rvwr_abcprd
1 178 ora_rsm0_abcprd
1 178 ora_reco_abcprd
1 178 ora_rbal_abcprd
1 178 ora_qmnc_abcprd
1 178 ora_q001_abcprd
1 178 ora_q000_abcprd
1 178 ora_psp0_abcprd
1 178 ora_pmon_abcprd
1 178 ora_p009_abcprd
1 178 ora_p008_abcprd
1 178 ora_p007_abcprd
1 178 ora_p006_abcprd
1 178 ora_p005_abcprd
1 178 ora_p004_abcprd
1 178 ora_p003_abcprd
1 178 ora_p002_abcprd
Note that the number of wait buckets are less. The wait times are sort as it should be. And the process priority report shows that all oracle client processes are on the same priority.

Thanks Tanel!