Monday, April 12, 2010

Converting time values in trace files into wall-clock time

There may be cases where you would like to know the exact wall-clock time when a particular wait-event occurred or the SQL was executed by looking at the trace file.
Oracle captures the wall-clock time in the trace files and represents it in the following format:

AIT #2: nam='SQL*Net message from client' ela= 16445143 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1271092519750890

The value, we are interested in is the last one (
tim=1271092519750890).


The tim value can be converted into wall-clock time by using the following:

Take the first 10 digits, and then:

$date -d @1271092519 +"%m-%d-%Y %T"

Example:
tim=1271092519750890, first 10 characters - 1271092519

$date -d @1271092519 +"%m-%d-%Y %T"

04-12-2010 12:15:19


This could be useful in situations where you would like to find out when a user session completed execution, went back to the client to do some other processing and when it came back to database to execute subsequent SQLs.

BTW, there seems to be a difference in how this value is represented in 11g compared previous versions. I could not get the accurate wall-clock time for a tim value from 10g database.


Sunday, February 28, 2010

ORA-27504 while starting 11gR1 database with 11gR2 Grid Infrastructure

I have Oracle11g R2 (11.2.0.1) Grid infrastructure on a two node RAC. Installed 11.1.0.7 binaries and when attempting to create a database, encountered the following errors:

ORA-27504: IPC error creating OSD context
ORA-27300: OS system dependent operation:skgxnqtsz failed with

status: 0
ORA-27301: OS failure message: Error 0
ORA-27302: failure occurred at: SKGXN not av
clsssinit ret = 21
interconnect information is not available from OCR

On researching, found the following solution to fix those errors and was able to create the 11.1.0.7 database with 11gR2 grid infrastructure:

As root:

[root@eletrac01 bin]# ./olsnodes -t -n

eletrac01 1 Unpinned
eletrac02 2 Unpinned


[root@eletrac01 bin]# ./crsctl pin css -n eletrac01 eletrac02
CRS-4664: Node eletrac01 successfully pinned.
CRS-4664: Node eletrac02 successfully pinned.
[root@eletrac01 bin]#

[root@eletrac01 bin]# ./olsnodes -t -n
eletrac01 1 Pinned
eletrac02 2 Pinned
[root@eletrac01 bin]#

Saturday, January 16, 2010

Failed Switchover - Oracle11g

I recently had a situation where we had a failed switchover process. Was able to switch the Primary to Standby successfully, but encountered some issues while switching over standby to primary - therefore ended up having two standbys! The easiest alternative to get out of the situation would be to ACTIVATE one of the standbys and then rebuild the primary - but it's not always desirable (size, efforts, unprotected primary etc..).

We even attempted the oracle provided command to cancel the switchover, but encountered the following (On original primary):

SQL> ALTER DATABASE PREPARE TO SWITCHOVER CANCEL;
ALTER DATABASE PREPARE TO SWITCHOVER CANCEL
*
ERROR at line 1:
ORA-00600: internal error code, arguments: [adbdrv_switch], [384], [], [], [],
[], [], [], [], [], [], []

Here is I ended up doing:

All of these have been performed on original primary:
1. Startup Mount;
SQL> startup force nomount;
ORACLE instance started.

Total System Global Area 238530560 bytes
Fixed Size 1335724 bytes
Variable Size 150998612 bytes
Database Buffers 83886080 bytes
Redo Buffers

2. Recreate the controlfile using the trace (got from standby)
SQL> @scripts/ccf.sql

Control file created.

SQL> alter database open;
alter database open
*
ERROR at line 1:
ORA-01589: must use RESETLOGS or NORESETLOGS option for database open


SQL> alter database open resetlogs;

Database altered.

SQL>
3. That's it…that did it!

SQL> Select open_mode, database_role, switchover_status from V$database;

OPEN_MODE DATABASE_ROLE SWITCHOVER_STATUS
-------------------- ---------------- --------------------
READ WRITE PRIMARY TO STANDBY

SQL>

4. Here are the entries from standby - didn't have to do anything - it continued through RESETLOGS!

RFS[18]: New Archival REDO Branch(resetlogs_id): 708469623 Prior: 708454293
RFS[18]: Archival Activation ID: 0x6fece72a Current: 0x0
RFS[18]: Effect of primary database OPEN RESETLOGS
RFS[18]: Incarnation entry added for Branch(resetlogs_id): 708469623 (ETSI01)
Sat Jan 16 21:08:09 2010
Setting recovery target incarnation to 4
Sat Jan 16 21:08:09 2010
Archived Log entry 33 added for thread 1 sequence 1 ID 0x6fece72a dest 1:
Sat Jan 16 21:08:09 2010
RFS[19]: Assigned to RFS process 5022