Archive for the ‘Oracle DBA’ Category

Fast Connection Failover

March 10th, 2013

This topic has consistently come up whenever a database or Real Application Cluster (RAC) node fails. The question is always, “why don’t the applications gracefully failover?” It’s a fair question, and the answer is really that it’s harder than it looks. Oracle has offered Transparent Application Failover (TAF) for a very long time, but TAF only works for OCI based applications like sqlplus and JDBC thick clients. Since the majority of applications seem to use JDBC thin connections TAF isn’t really an option. With JDBC thin connections there is the Fast Connection Failover (FCF) feature. It works in conjunction with a connection cache to provide the ability to recover from a RAC node failure without having to restart the application. And of course with all things Oracle, the connection cache feature has now changed to Universal Connection Pooling (UCP). The other pieces of FCF include Fast Application Notification (FAN) events and Oracle Notification Service (ONS). ONS is used to transport the FAN event notifications.

There is a lot of documentation from Oracle and on the web about how to set up FCF and UCP. There isn’t much documentation though on how to implement it once you have it set up. That’s really what I wanted to talk about, but you do have to understand how to set it up to use it. I have included most of the resources I used to try to understand FCF and UCP at the end of this post. I have also added a working sample to the appsdba.com web site so you can try this out yourself.

To set up the FCF example you will need Java 1.6 and three jar files: ucp.jar, ons.jar, ojdbc6.jar. The jar files are available on otn.oracle.com (OTN) and I used the 11.2.0.3 versions. You can probably use an older version of Java if you can find compatible versions of the jar files, but you’re on your own for that. I’ve only tested with the 11.2.0.3 versions on OTN.

The example from the appsdba.com web site is called FcfExample.java and if you open it up with a text editor there are setup instructions. The instructions are the following:


* To run the test:
*
* Set JAVA_HOME to your Java 1.6 directory
*  (set JAVA_HOME="C:\Program Files (x86)\Java\jdk1.6.0_37\bin")
* Add JAVA_HOME to the path
*  (set PATH="%JAVA_HOME%;%PATH%")
* Add the source directory to the LIBS variable
*  (set LIBS="c:\temp\jdbc_fcf_test")
* Add jar files to the CLASSPATH (ons.jar, ucp.jar, ojdbc6.jar)
*  (set CLASSPATH="c:\temp\jdbc_fcf_test;c:\temp\jdbc_fcf_test\ons.jar;c:\temp\jdbc_fcf_test\ojdbc6.jar;c:\temp\jdbc_fcf_test\
*    ucp.jar"
*
* Compile with: javac FcfExample.java
* Run with: java FcfExample
*
* The idea is to start the script running, then kill the instance or service
* the script is running on (that's why the instance name is listed) and
* the code is written so that the query will restart once a new connection
* is re-established.
*
* An additional file is created called FcfExample.log which lists the FAN
* events coming from ONS during the run. You should see the connection fail
* and then get re-established.

A couple of comments. I created this example using three main sources (i.e. see references [10], [11], [15]), and the example also writes the FAN messages  to a separate log file.

Now the interesting part of the example is the actual code that demonstrates how to recover from a failover.


do {
  try {

    conn = ds.getConnection();
    conn.setAutoCommit(false);
    System.out.println("Obtained a new connection from pool ...");
    System.out.println();

    // Print connection stats
    JDBCConnectionPoolStatistics stats = ds.getStatistics();
    if (stats != null) {
      printStat("AbandonedConnectionsCount", stats);
      printStat("AvailableConnectionsCount", stats);
      printStat("AverageBorrowedConnectionsCount", stats);
      printStat("AverageConnectionWaitTime", stats);
      printStat("BorrowedConnectionsCount", stats);
      printStat("ConnectionsClosedCount", stats);
      printStat("ConnectionsCreatedCount", stats);
      printStat("RemainingPoolCapacityCount", stats);
      printStat("TotalConnectionsCount", stats);
      System.out.println();
      System.out.println("***");
      System.out.println();
    }

    // Start work here, it has been made restartable

    if (retry) {
      if (step == "getBanner") {
        retry = false;
        getBanner(conn);
      }
    } else {
      step = "getBanner";
      getBanner(conn);
    }

    if (retry) {
      if (step == "getInstance") {
        retry = false;
        getInstance(conn);
      }
    } else {
      step = "getInstance";
      getInstance(conn);
    }

    if (retry) {
      if (step == "runQuery") {
        retry = false;
        runQuery(conn);
      }
    } else {
      step = "runQuery";
      runQuery(conn);
    }

    if (retry) {
      if (step == "getInstance") {
        retry = false;
        getInstance(conn);
      }
    } else {
      step = "getInstance";
      getInstance(conn);
    }

  }
  catch (SQLException sqlexc) {
    System.out.println();
    System.out.println("+-------------------------------+");
    System.out.println("| SQL Exception in program      |");
    System.out.println("+-------------------------------+");
    System.out.println("SQL Error Code    : " + sqlexc.getErrorCode());
    System.out.println("SQL Error Message : " + sqlexc.getMessage());
    System.out.println();

    // The recommended way to check connection usability after a
    // RAC-down event triggers UCP FCF actions.
    if (conn == null || !((ValidConnection) conn).isValid()) {
      System.out.println("Connection retry necessary ...");
      try {
        conn.close();
      }
      catch (Exception closeExc) {
        System.out.println("Exception detected when closing connection:");
        closeExc.printStackTrace();
      }
      retry = true;
    }
  }
} while (retry);

Granted this is a simplistic example, but the point is that the application has to handle a failover. This example uses a loop and an exception handler to catch any failures. A retry boolean is used to check to see if there’s been a failure and a step variable records the current step so the code knows where to restart. The proper restart is dependent on the ordering of the steps but this is just a sequential single thread so that’s not a problem.

When this example is run we see a printout of the connection pool stats, then the database banner and instance information, these run quick, and then a longer running query that counts the number of objects in the database up to a limit. It is at this point that you can kill the RAC node the program is running on, that’s why the instance information is listed, and see how the program fails over and re-runs the query.

The following is from a normal run with no failures:


C:\Temp\FCF>java FcfExample
Obtained a new connection from pool ...

AbandonedConnectionsCount          0
AvailableConnectionsCount          9
AverageBorrowedConnectionsCount    0
AverageConnectionWaitTime          0
BorrowedConnectionsCount           1
ConnectionsClosedCount             0
ConnectionsCreatedCount            10
RemainingPoolCapacityCount         15
TotalConnectionsCount              10

***

Oracle Database 11g Enterprise Edition Release 11.2.0.3.0 - 64bit Production
PL/SQL Release 11.2.0.3.0 - Production
CORE    11.2.0.3.0      Production
TNS for Linux: Version 11.2.0.3.0 - Production
NLSRTL Version 11.2.0.3.0 - Production

Instance number: 2
Instance name: ORCL2
Host: racvm2

Object count: 1000000000

Instance number: 2
Instance name: ORCL2
Host: racvm2

Released connection ...

***

AbandonedConnectionsCount          0
AvailableConnectionsCount          10
AverageBorrowedConnectionsCount    0
AverageConnectionWaitTime          0
BorrowedConnectionsCount           0
ConnectionsClosedCount             0
ConnectionsCreatedCount            10
RemainingPoolCapacityCount         15
TotalConnectionsCount              10

C:\Temp\FCF>

We see the connection pool usage and no messages about failures in the run. The FAN event log shows the following:

Feb 5, 2013 7:46:30 PM oracle.ucp.admin.UniversalConnectionPoolManagerMBeanImpl getUniversalConnectionPoolManagerMBean
FINE: Universal Connection Pool Manager MBean created
Feb 5, 2013 7:46:30 PM oracle.ucp.jdbc.PoolDataSourceImpl createPoolWithDefaultProperties
FINE: Connection pool instance is created with default properties
Feb 5, 2013 7:46:30 PM oracle.ucp.jdbc.PoolDataSourceImpl createUniversalConnectionPoolMBean
FINE: JDBC PoolMBean created
Feb 5, 2013 7:46:30 PM oracle.ucp.jdbc.PoolDataSourceImpl startPool
FINE: Connection pool instance is created
Feb 5, 2013 7:46:30 PM oracle.ucp.jdbc.oracle.RACManagerImpl start
FINE: failover started
Feb 5, 2013 7:46:31 PM oracle.ucp.common.UniversalConnectionPoolBase start
FINE: universal connection pool started
Feb 5, 2013 7:46:31 PM oracle.ucp.jdbc.PoolDataSourceImpl startPool
FINE: connection pool is started

Now let’s look at what happens when we stop the node that we’re running from in the middle of the longer running query:


C:\Temp\FCF>java FcfExample
Obtained a new connection from pool ...

AbandonedConnectionsCount          0
AvailableConnectionsCount          9
AverageBorrowedConnectionsCount    0
AverageConnectionWaitTime          0
BorrowedConnectionsCount           1
ConnectionsClosedCount             0
ConnectionsCreatedCount            10
RemainingPoolCapacityCount         15
TotalConnectionsCount              10

***

Oracle Database 11g Enterprise Edition Release 11.2.0.3.0 - 64bit Production
PL/SQL Release 11.2.0.3.0 - Production
CORE    11.2.0.3.0      Production
TNS for Linux: Version 11.2.0.3.0 - Production
NLSRTL Version 11.2.0.3.0 - Production

Instance number: 1
Instance name: ORCL1
Host: racvm1

+-------------------------------+
| SQL Exception in program      |
+-------------------------------+
SQL Error Code    : 1089
SQL Error Message : ORA-01089: immediate shutdown in progress - no operations are permitted

Connection retry necessary ...
Obtained a new connection from pool ...

AbandonedConnectionsCount          0
AvailableConnectionsCount          8
AverageBorrowedConnectionsCount    0
AverageConnectionWaitTime          0
BorrowedConnectionsCount           1
ConnectionsClosedCount             1
ConnectionsCreatedCount            10
RemainingPoolCapacityCount         16
TotalConnectionsCount              9

***

Object count: 1000000000

Instance number: 3
Instance name: ORCL3
Host: racvm3

Released connection ...

***

AbandonedConnectionsCount          0
AvailableConnectionsCount          6
AverageBorrowedConnectionsCount    0
AverageConnectionWaitTime          0
BorrowedConnectionsCount           0
ConnectionsClosedCount             4
ConnectionsCreatedCount            10
RemainingPoolCapacityCount         19
TotalConnectionsCount              6

C:\Temp\FCF>

The RAC node the script was connected to was stopped with the following command:


112:oracle@racvm1:/home/oracle [ORCL1]
$ srvctl stop instance -d ORCL -i ORCL1
113:oracle@racvm1:/home/oracle [ORCL1]
$

And the FAN event log shows that four connections in the UCP were closed and that the ORCL1 instance was shut down:


C:\Temp\FCF>type FcfExample.log
Feb 5, 2013 7:28:08 PM oracle.ucp.admin.UniversalConnectionPoolManagerMBeanImpl getUniversalConnectionPoolManagerMBean
FINE: Universal Connection Pool Manager MBean created
Feb 5, 2013 7:28:08 PM oracle.ucp.jdbc.PoolDataSourceImpl createPoolWithDefaultProperties
FINE: Connection pool instance is created with default properties
Feb 5, 2013 7:28:08 PM oracle.ucp.jdbc.PoolDataSourceImpl createUniversalConnectionPoolMBean
FINE: JDBC PoolMBean created
Feb 5, 2013 7:28:08 PM oracle.ucp.jdbc.PoolDataSourceImpl startPool
FINE: Connection pool instance is created
Feb 5, 2013 7:28:08 PM oracle.ucp.jdbc.oracle.RACManagerImpl start
FINE: failover started
Feb 5, 2013 7:28:10 PM oracle.ucp.common.UniversalConnectionPoolBase start
FINE: universal connection pool started
Feb 5, 2013 7:28:10 PM oracle.ucp.jdbc.PoolDataSourceImpl startPool
FINE: connection pool is started
Feb 5, 2013 7:28:22 PM oracle.ucp.common.UniversalConnectionPoolBase closePhysicalConnection
FINE: closed physical connection
Feb 5, 2013 7:28:33 PM oracle.ucp.common.UniversalConnectionPoolBase closePhysicalConnection
FINE: closed physical connection
Feb 5, 2013 7:28:33 PM oracle.ucp.common.UniversalConnectionPoolBase closePhysicalConnection
FINE: closed physical connection
Feb 5, 2013 7:28:33 PM oracle.ucp.common.UniversalConnectionPoolBase closePhysicalConnection
FINE: closed physical connection
Feb 5, 2013 7:28:33 PM oracle.ucp.jdbc.oracle.ONSDatabaseEventHandlerTask run
FINE: event triggered: Service name: orcl, Instance name: orcl1, Unique name: orcl, Host name: racvm1, Status: down, Cardinality: 0, Reason: user, Event type: database/event/service

Note that in the failure example that the code restarted at the object count step, we don’t see any information about what node we’re connected to until the last two steps run after the “runQuery” step.

References:

[1] Oracle WebLogic Server and Highly Available Oracle Databases: Oracle Integrated Maximum Availability Solutions – Active GridLink

[2] High-Performance Oracle JDBC Programming
Learn how to improve performance of Oracle-driven JDBC programs by leveraging connection and statement pooling features.
By Yuli Vasiliev
Published April 2009

[3] How to Use the Oracle Universal Connection Pool (UCP) ? [ID 759208.1]

[4] Transitioning to Oracle Universal Connection Pool (UCP)

[5] Fast Connection Failover (FCF) Test Client Using 11g JDBC Driver and 11g RAC Cluster [ID 566573.1]

[6] How to Use the Oracle Universal Connection Pool (UCP) ? [ID 759208.1]

[7] Understanding Transparent Application Failover (TAF) and Fast Connection Failover (FCF) [ID 334471.1]

[8] How to Verify Universal Connection Pool (UCP) / Fast Connection Failover (FCF) Setup [ID 1064652.1]

[9] JDBC Fast Connection Failover with Oracle RAC,  Configuring and testing with Tomcat and the Spring framework, February 08, 2010

[10] URL:http://www.drdobbs.com/jvm/jdbc-fast-connection-failover-with-oracl/222700353
Author: Michael Pilone

[11] http://www.idevelopment.info/data/Programming/java/jdbc/High_Availability/FastConnectionFailoverExampleThin.java

[12] Oracle® Database Administrator’s Guide, 11g Release 2 (11.2)

[13] Oracle® Universal Connection Pool for JDBC Developer’s Guide, 11g Release 2 (11.2)

[14] Oracle® Database JDBC Developer’s Guide, 11g Release 2 (11.2)

[15] Oracle Database 11g UCP Downloads, http://www.oracle.com/technetwork/database/enterprise-edition/downloads/ucp-112010-099129.html – ucpdemos.jar (FCFSample.java)

Using OID as a tnsnames Directory

August 5th, 2012

There’s a great presentation on how to use Oracle Internet Directory (OID) as a tnsnames directory. This is basically Oracle’s replacement for the Oracle Names server. The presentation is called “Replacing tnsnames.ora with OID” by Mark Luszczynski, and can be found here at the SLOUG.org site. It’s really done very well and I just had a few things to add:

  1. You can use the Identity Management 11.1.1.6.0 from the Oracle web site and not have to patch. It is a full installation.
  2. Use “sys” for the database ODS schema and not “system” as shown on the slide for 11.1.1.6.0 or you’ll get privilege errors.
  3. Use commas for the Internet Directory realm. The example shows: dc=aci,dc=corp,dc=net
  4. Pay particular attention to the issue with anonymous binds.

DBFS_HS – Database Hierarchical Storage, Part 2

June 21st, 2011

In part 1 we set up a hierarchical store under the user hstest, created a table with SecureFile LOBs, and archived 30 SecureFiles. So what’s going on under the covers and how do we retrieve the data? Is the data even really out of the database? In this article I will try to answer these questions as we continue to explore our hierarchical store.

How it all works

At the simplest level the hierarchical store provides various APIs to accomplish a put, a get, and some informational queries. Intermixed in these functions are the ability to create “links” to archived data such that a query of an archived SecureFile LOB that is no longer in database storage will be retrieved without application intervention (i.e. application transparency). The mechanism of a put involves moving the SecureFile LOB to a cached staging area (i.e. the cache table) until it can be archived out to the store’s defined storage media. Once archived it may be eligible to be “flushed” from the cache table in the database and therefore no longer reside in database storage. Once SecureFile LOB’s are moved to a store cache, or really staging, table they are eventually written to the store’s storage media in batches or “tarballs”. The size of these tarballs is controlled by a property defined for the store in the DBFS_HS$_STOREPROPERTIES table. If a “get” is issued and the SecureFile LOB is in the cache table then it can be retrieved directly. If not then the SecureFile LOB must be recalled from the tarball and written back into the SecureFile LOB’s row in the cache table.

This raises a question about storage. Ideally you would expect to see the cache table steady state at some fairly constant size as the rate of archiving and retrieval evens out. But it seems pretty obvious that the cache table is a good candidate for a dedicated tablespace. Since its space usage is not necessarily predictable it would be nice to keep it separate from other objects so that it’s size could be capped and not allowed to grow uncontrollably. It’s not clear if the cache table could be partitioned, but this would probably only be practical if it was very large. The partitioning scheme would also need to be set in a way that new and old SecureFile LOBs were being read and written to from each partition in order to insure that space was reused. The cache table also seems to be a good candidate for a second tier of storage. If the source table(s) are on a primary storage tier then clearly the cache table is not going to need to meet the same performance criteria, otherwise why archive? Since the actual store will be on a media outside the database this raises the possibility of having at least three storage tiers.

Database Objects

Next let’s look at what objects have been created. The following SYS dictionary tables exist to support dbms_dbfs:

  • DBFS_HS$_BACKUPFILETABLE
  • DBFS_HS$_CONTENTFILEMAPTBL
  • DBFS_HS$_FS
  • DBFS_HS$_PROPERTY
  • DBFS_HS$_SFLOCATORTABLE
  • DBFS_HS$_STORECOMMANDS
  • DBFS_HS$_STOREID2POLICYCTX
  • DBFS_HS$_STOREIDTABLE
  • DBFS_HS$_STOREPROPERTIES
  • DBFS_SFS$_FS
  • DBFS_SFS$_FST
  • DBFS_SFS$_FSTO
  • DBFS_SFS$_FSTP
  • DBFS_SFS$_SNAP
  • DBFS_SFS$_TAB
  • DBFS_SFS$_VOL
  • DBFS$_MOUNTS
  • DBFS$_STATS
  • DBFS$_STORES

Additionally for each store created the following tables are created in the SYS schema:

  • HS$AT<dbname><seq>
  • HS$CT<dbname><seq>
  • HS$DB<dbname><seq>
  • HS$DT<dbname><seq>
  • HS$JT<dbname><seq>
  • HS$TT<dbname><seq>

When a store is created running the dbms_dbfs_hs.createStore procedure a table is created from the “tblname” input parameter. This table is used as a metadata table and stores the SecureFile LOB in the “filedata” column. A second table is also created with the name in the format of SFS$_FSTP_<seq>. This table holds more information about how the SecureFile LOB is archived and provides the gateway into the SYS metadata tables.

A view is also created with the name in the format of VSFS$_<seq> which exposes store based metadata about the archived SecureFile LOB.

In my database the following tables and view have been created:

Store View

The following view can be used to provide a mapping between the archived SecureFile LOB and it’s location in the store and cache. A separate view is required for each store due to the use of separate cache and metadata tables for each store.

create or replace force view hs_store_vas
select
  c.pathname AS path,
  c.item AS name,
  c.std_guid AS guid,
  sf2.propvalue AS file_size,
  dbms_lob.getlength(c.filedata) AS cache_size,
  sf1.propvalue AS contentid,
  l.tarballid,
  b.backupfilename,
  st.storeowner,
  st.storename
from
  hstest.hs_cache c,
  hstest.sfs$_fstp_12 sf1,
  hstest.sfs$_fstp_12 sf2,
  sys.dbfs_hs$_contentfnmaptbl m,
  sys.dbfs_hs$_sflocatortable l,
  sys.dbfs_hs$_backupfiletable b,
  sys.dbfs_hs$_storeidtable st
where
  c.std_guid = sf1.std_guid
  and c.pathtype = 1
  and sf1.propname = 'HS:CONTENTID'
  and sf1.propvalue = m.contentfilename(+)
  and sf1.std_guid = sf2.std_guid
  and sf2.propname = 'HS:FILESIZE'
  and m.archiverefid = l.archiverefid(+)
  and l.tarballid = b.tarballid(+)
  and b.storeid = st.storeid(+);

Usage Examples

Now that everything is setup let’s walk through some examples of how DBFS HS works. First let’s look at what we have. In part 1 of this series I archived 30 SecureFile LOBs and that created one “tarball” operating system file:

380:oracle@testvm:/ora_src/bkup [db11g]
$ ls -lrt
total 8212
-rw-r--r-- 1 oracle oinstall    2136 Jun  6 23:46 Oracle_Disk_SBT_Catalog
-rw-r--r-- 1 oracle oinstall 8388616 Jun  6 23:46 __DB11G_1_A5180F78E736D02AE040A8C057011B2C_1
381:oracle@testvm:/ora_src/bkup [db11g]

Now we’ll archive 15 more SecureFile LOBs, but we’ll just start at the beginning to show that if the SecureFile LOB has already been archived then re-archiving it does not invoke an error:

SQL> SET SERVEROUTPUT ON;
DECLARE
  v_mountpoint         VARCHAR2(32) := '/hs_store/';
  v_LOB                BLOB;
  v_LOBsize            NUMBER;
  v_debug              CHAR(1) := 'N';
BEGIN
  FOR arch_rec IN
  (
    SELECT hs.* FROM hs_lobtable hs
    where dbms_lob.getlength(hs.lobcol) != 0
    and rownum <= 45   )   LOOP     BEGIN       SELECT hs.lobcol       INTO v_LOB       FROM hs_lobtable hs       WHERE hs.id = arch_rec.id FOR UPDATE;       --       v_LOBsize := SYS.DBMS_LOB.GETLENGTH(v_LOB);       DBMS_OUTPUT.PUT_LINE('Archive ID: ' || arch_rec.id);       DBMS_OUTPUT.PUT_LINE('LOB size: ' || v_LOBsize);       --       -- Write the LOB to the store       --       DBMS_LOB.MOVE_TO_DBFS_LINK (         lob_loc => v_LOB,
        storage_path => v_mountpoint || arch_rec.id,
        flags => DBMS_LOB.DBFS_LINK_NOCACHE);
      --
      COMMIT;
    EXCEPTION
      WHEN OTHERS THEN
        ROLLBACK;
        DBMS_OUTPUT.PUT_LINE(DBMS_UTILITY.FORMAT_ERROR_BACKTRACE);
    END;
  END LOOP;
END;
/
SQL>   2    3    4    5    6    7    8    9   10   11   12   13   14   15   16   17   18   19   20   21   22   23   24   25

26   27   28   29   30   31   32   33   34   35   36   37   38   39

Archive ID: 1
LOB size: 16384
Archive ID: 2
LOB size: 16384
Archive ID: 3
LOB size: 16384
Archive ID: 4
LOB size: 16384
Archive ID: 5
LOB size: 16384
Archive ID: 6
LOB size: 16384
Archive ID: 7
LOB size: 16384
Archive ID: 8
LOB size: 16384
Archive ID: 9
LOB size: 16384
Archive ID: 10
LOB size: 16384
Archive ID: 11
LOB size: 16384
Archive ID: 12
LOB size: 16384
Archive ID: 13
LOB size: 16384
Archive ID: 14
LOB size: 16384
Archive ID: 15
LOB size: 16384
Archive ID: 16
LOB size: 16384
Archive ID: 17
LOB size: 16384
Archive ID: 18
LOB size: 16384
Archive ID: 19
LOB size: 16384
Archive ID: 20
LOB size: 16384
Archive ID: 21
LOB size: 16384
Archive ID: 22
LOB size: 16384
Archive ID: 23
LOB size: 16384
Archive ID: 24
LOB size: 16384
Archive ID: 25
LOB size: 16384
Archive ID: 26
LOB size: 16384
Archive ID: 27
LOB size: 16384
Archive ID: 28
LOB size: 16384
Archive ID: 29
LOB size: 16384
Archive ID: 30
LOB size: 16384
Archive ID: 31
LOB size: 16384
Archive ID: 32
LOB size: 16384
Archive ID: 33
LOB size: 16384
Archive ID: 34
LOB size: 16384
Archive ID: 35
LOB size: 16384
Archive ID: 36
LOB size: 16384
Archive ID: 37
LOB size: 16384
Archive ID: 38
LOB size: 16384
Archive ID: 39
LOB size: 16384
Archive ID: 40
LOB size: 16384
Archive ID: 41
LOB size: 16384
Archive ID: 42
LOB size: 16384
Archive ID: 43
LOB size: 16384
Archive ID: 44
LOB size: 16384
Archive ID: 45
LOB size: 16384

PL/SQL procedure successfully completed.

SQL>

Now let’s run a store push and see if we’ve create another archive file:

SQL> DECLARE
  store_name varchar2(32) := 'HS_STORE';
BEGIN
  dbms_dbfs_hs.storePush(store_name) ;
  commit ;
END;
/  2    3    4    5    6    7

PL/SQL procedure successfully completed.

SQL> !ls -lrt
total 16420
-rw-r--r-- 1 oracle oinstall 8388616 Jun  6 23:46 __DB11G_1_A5180F78E736D02AE040A8C057011B2C_1
-rw-r--r-- 1 oracle oinstall    3204 Jun 20 09:17 Oracle_Disk_SBT_Catalog
-rw-r--r-- 1 oracle oinstall 8388616 Jun 20 09:17 __DB11G_2_A6248CC964C16A45E040A8C0570111A4_2

SQL>

OK, we’ve created a new archive file in the OS. Let’s look at what our metadata view says about our store and the cache for the store:

SQL> select name, cache_size, backupfilename from hs_store_v;

NAME            CACHE_SIZE BACKUPFILENAME
--------------- ---------- ------------------------------------------------------------
LOB1                     0 __DB11G_1_A5180F78E736D02AE040A8C057011B2C_1
LOB10                    0 __DB11G_1_A5180F78E736D02AE040A8C057011B2C_1
LOB11                    0 __DB11G_1_A5180F78E736D02AE040A8C057011B2C_1
LOB12                    0 __DB11G_1_A5180F78E736D02AE040A8C057011B2C_1
LOB13                    0 __DB11G_1_A5180F78E736D02AE040A8C057011B2C_1
LOB14                    0 __DB11G_1_A5180F78E736D02AE040A8C057011B2C_1
LOB15                    0 __DB11G_1_A5180F78E736D02AE040A8C057011B2C_1
LOB16                    0 __DB11G_1_A5180F78E736D02AE040A8C057011B2C_1
LOB17                    0 __DB11G_1_A5180F78E736D02AE040A8C057011B2C_1
LOB18                    0 __DB11G_1_A5180F78E736D02AE040A8C057011B2C_1
LOB19                    0 __DB11G_1_A5180F78E736D02AE040A8C057011B2C_1
LOB2                     0 __DB11G_1_A5180F78E736D02AE040A8C057011B2C_1
LOB20                    0 __DB11G_1_A5180F78E736D02AE040A8C057011B2C_1
LOB21                    0 __DB11G_1_A5180F78E736D02AE040A8C057011B2C_1
LOB22                    0 __DB11G_1_A5180F78E736D02AE040A8C057011B2C_1
LOB23                    0 __DB11G_1_A5180F78E736D02AE040A8C057011B2C_1
LOB24                    0 __DB11G_1_A5180F78E736D02AE040A8C057011B2C_1
LOB25                    0 __DB11G_1_A5180F78E736D02AE040A8C057011B2C_1
LOB26                    0 __DB11G_1_A5180F78E736D02AE040A8C057011B2C_1
LOB27                    0 __DB11G_1_A5180F78E736D02AE040A8C057011B2C_1
LOB28                    0 __DB11G_1_A5180F78E736D02AE040A8C057011B2C_1
LOB29                    0 __DB11G_1_A5180F78E736D02AE040A8C057011B2C_1
LOB3                     0 __DB11G_1_A5180F78E736D02AE040A8C057011B2C_1
LOB30                    0 __DB11G_1_A5180F78E736D02AE040A8C057011B2C_1
LOB4                     0 __DB11G_1_A5180F78E736D02AE040A8C057011B2C_1
LOB5                     0 __DB11G_1_A5180F78E736D02AE040A8C057011B2C_1
LOB6                     0 __DB11G_1_A5180F78E736D02AE040A8C057011B2C_1
LOB7                     0 __DB11G_1_A5180F78E736D02AE040A8C057011B2C_1
LOB8                     0 __DB11G_1_A5180F78E736D02AE040A8C057011B2C_1
LOB9                     0 __DB11G_1_A5180F78E736D02AE040A8C057011B2C_1
31                       0 __DB11G_2_A6248CC964C16A45E040A8C0570111A4_2
32                       0 __DB11G_2_A6248CC964C16A45E040A8C0570111A4_2
33                       0 __DB11G_2_A6248CC964C16A45E040A8C0570111A4_2
34                       0 __DB11G_2_A6248CC964C16A45E040A8C0570111A4_2
35                       0 __DB11G_2_A6248CC964C16A45E040A8C0570111A4_2
36                       0 __DB11G_2_A6248CC964C16A45E040A8C0570111A4_2
37                       0 __DB11G_2_A6248CC964C16A45E040A8C0570111A4_2
38                       0 __DB11G_2_A6248CC964C16A45E040A8C0570111A4_2
39                       0 __DB11G_2_A6248CC964C16A45E040A8C0570111A4_2
40                       0 __DB11G_2_A6248CC964C16A45E040A8C0570111A4_2
41                       0 __DB11G_2_A6248CC964C16A45E040A8C0570111A4_2
42                       0 __DB11G_2_A6248CC964C16A45E040A8C0570111A4_2
43                       0 __DB11G_2_A6248CC964C16A45E040A8C0570111A4_2
44                       0 __DB11G_2_A6248CC964C16A45E040A8C0570111A4_2
45                       0 __DB11G_2_A6248CC964C16A45E040A8C0570111A4_2

45 rows selected.

SQL>

It looks like all 45 of our SecureFile LOBs have been archived to a file and are not currently in the cache. Now let’s see if we can access one of the SecureFile LOBs:

SQL> SET SERVEROUTPUT ON;
DECLARE
  l_LOB                BLOB;
  l_buffer             RAW(4000);
  l_ctr                NUMBER := 1;
  l_amount             NUMBER := 100;
  l_id                 NUMBER := 45;
BEGIN
  SELECT hs.lobcol
  INTO l_LOB
  FROM hs_lobtable hs
  WHERE hs.id = l_id;
  --
  dbms_lob.read(l_LOB, l_amount, l_ctr, l_buffer);
  dbms_output.put_line( RAWTOHEX(l_buffer) );
END;
/SQL>   2    3    4    5    6    7    8    9   10   11   12   13   14   15   16
45506C45676E4761545861514265575641797571534A77687A4F79634D5A6E765771484867736C456B634C6845587466566377747A7A4745646A6774
4E7456704E69596857485A6B6146585767704D567275564D5A74417A616F41746C4874784B6A5061

PL/SQL procedure successfully completed.

SQL>

We were able to read the first 100 bytes of the SecureFile LOB with name or id of ’45′. If we query our metadata we now see:

SQL> select name, cache_size, backupfilename from hs_store_v where name = '45';

NAME            CACHE_SIZE BACKUPFILENAME
--------------- ---------- ------------------------------------------------------------
45                   16384 __DB11G_2_A6248CC964C16A45E040A8C0570111A4_2

SQL>

And now the cache_size shows the size of the SecureFile LOB. For those doubters out there I’ll rename the backup file and we’ll try accessing another SecureFile LOB:

SQL> !ls -lrt
total 16420
-rw-r--r-- 1 oracle oinstall 8388616 Jun  6 23:46 __DB11G_1_A5180F78E736D02AE040A8C057011B2C_1
-rw-r--r-- 1 oracle oinstall    3204 Jun 20 09:17 Oracle_Disk_SBT_Catalog
-rw-r--r-- 1 oracle oinstall 8388616 Jun 20 09:17 __DB11G_2_A6248CC964C16A45E040A8C0570111A4_2

SQL> !mv __DB11G_2_A6248CC964C16A45E040A8C0570111A4_2 __DB11G_2_A6248CC964C16A45E040A8C0570111A4_2.BAK

SQL> DECLARE
  l_LOB                BLOB;
  l_buffer             RAW(4000);
  l_ctr                NUMBER := 1;
  l_amount             NUMBER := 100;
  l_id                 NUMBER := 44;
BEGIN
  SELECT hs.lobcol
  INTO l_LOB
  FROM hs_lobtable hs
  WHERE hs.id = l_id;
  --
  dbms_lob.read(l_LOB, l_amount, l_ctr, l_buffer);
  dbms_output.put_line( RAWTOHEX(l_buffer) );
END;
/  2    3    4    5    6    7    8    9   10   11   12   13   14   15   16
DECLARE
*
ERROR at line 1:
ORA-19507: failed to retrieve sequential file, handle="__DB11G_2_A6248CC964C16A45E040A8C0570111A4_2", parms=""
ORA-27029: skgfrtrv: sbtrestore returned error
ORA-19511: Error received from media manager layer, error text:
sbtpvt_open_input: file /ora_src/bkup/__DB11G_2_A6248CC964C16A45E040A8C0570111A4_2 does not exist or cannot be
accessed, errno = 2
ORA-06512: at "SYS.DBMS_APBACKEND", line 60
ORA-06512: at "SYS.DBMS_APBACKEND", line 1378
ORA-06512: at "SYS.DBMS_DBFS_HS", line 1042
ORA-06512: at "SYS.DBMS_DBFS_HS", line 1203
ORA-06512: at "SYS.DBMS_DBFS_HS", line 1481
ORA-06512: at "SYS.DBMS_DBFS_HS", line 1592
ORA-06512: at line 1
ORA-06512: at "SYS.DBMS_DBFS_CONTENT", line 3108
ORA-06512: at "SYS.DBMS_LOB_AM_PRIVATE", line 65
ORA-06512: at line 1
ORA-06512: at "SYS.DBMS_LOB", line 1056
ORA-06512: at line 13

The access failed because the archive file could not be found. This proves that the database is capable of accessing secondary storage to transparently retrieve the SecureFile LOB. Now we’ll rename the file back and see if we can successfully retrieve the SecureFile LOB:

SQL> !mv __DB11G_2_A6248CC964C16A45E040A8C0570111A4_2.BAK __DB11G_2_A6248CC964C16A45E040A8C0570111A4_2

SQL> DECLARE
  l_LOB                BLOB;
  l_buffer             RAW(4000);
  l_ctr                NUMBER := 1;
  l_amount             NUMBER := 100;
  l_id                 NUMBER := 44;
BEGIN
  SELECT hs.lobcol
  INTO l_LOB
  FROM hs_lobtable hs
  WHERE hs.id = l_id;
  --
  dbms_lob.read(l_LOB, l_amount, l_ctr, l_buffer);
  dbms_output.put_line( RAWTOHEX(l_buffer) );
END;
/  2    3    4    5    6    7    8    9   10   11   12   13   14   15   16
6F4A6A796978784F576F54524261634979444256535747644772655952614D4E6646735657675545566B48577762596C43707162426F7975414F5841
594B6242754D6E5948784E546E49724F78664F4968564154504C4966555156757277475077757544

PL/SQL procedure successfully completed.

SQL> select name, cache_size, backupfilename from hs_store_v where name = '44';

NAME            CACHE_SIZE BACKUPFILENAME
--------------- ---------- ------------------------------------------------------------
44                   16384 __DB11G_2_A6248CC964C16A45E040A8C0570111A4_2

SQL>

And we see that we can indeed access the SecureFile LOB and that it has been retrieved back into the cache.

To wrap this up Oracle has made available a feature that can be used to move closer to an ILM environment. One that can transparently support multiple tiers of storage for SecureFile LOBs.

DBFS_HS – Database Hierarchical Storage

June 7th, 2011

Oracle delivered the database file system in 11gR2, but it also slipped in hierarchical storage as part of the feature. In 11.2.0.2 most of the bugs seem to have been worked out. The DBFS_HS package along with the DBMS_LOB package, and SecureFile LOBs delivers application transparent hierarchical storage. A sort of ILM if you will. This has been a while in coming but it finally seems to really work. I’ll walk through an example, and it’s sort of documented (not all quite there yet) in the Oracle documentation. So why is this important? Well there are some customers that have chosen to store a lot of unstructured data in SecureFiles and don’t want to keep it all in premium storage. DBFS_HS provides a mechanism to move that data to different storage tiers. Initially Oracle is supporting RMAN based archiving and Amazon S3.

The following will show the setup on a Linux VM running Oracle 11.2.0.2 using RMAN with disk based SBT (see the post RMAN Tape Simulation). In future posts I’ll explore how it works under the covers and what you can do with it.

I found the examples in the SecureFiles and Large Object’s Developer Guide to be a little cryptic so hopefully this example will do better.

connect / as sysdba

create tablespace hs_tab
datafile
 '/ora_src/oradata/db11g/hs_tab01.dbf'
 size 10m autoextend on next 10m maxsize 2000m;

create user hstest identified by hstest
default tablespace hs_tab
temporary tablespace temp
quota unlimited on hs_tab;

grant create session to hstest;
grant alter session to hstest;
--
grant dbfs_role to hstest;
grant scheduler_admin to hstest;
--
grant create procedure to hstest;
grant create sequence to hstest;
grant create table to hstest;
grant create trigger to hstest;
grant create view to hstest;
--
grant select any dictionary to hstest;
grant select any table to hstest;
--
-- Run the following:
--
connect hstest/hstest
--
declare
 storename varchar2(32) ;
 tblname varchar2(30) ;
 tbsname varchar2(30) ;
 lob_cache_quota number := 0.8 ;
 cachesz number ;
 ots number ;
begin
 cachesz := (100 * 1048576);  -- Minimum size? 3 MB or less errors
 ots := (10 * 1048576);
 storename := 'HS_STORE' ;
 tblname := 'HS_CACHE' ;
 tbsname := 'HS_TAB' ; -- Substitute a valid tablespace name
 --
 -- Create the store.
 -- Here tbsname is the tablespace used for the store,
 -- tblname is the table holding all the store entities,
 -- cachesz is the space used by the store to cache content
 --   in the tablespace,
 -- lob_cache_quota is the fraction of cachesz allocated
 --   to level-1 cache and
 -- ots is minimum amount of content that will be accumulated
 --   in level-2 cache before being stored in AmazonS3
 --
 dbms_dbfs_hs.createStore(
 storename,
 dbms_dbfs_hs.STORETYPE_TAPE,
 tblname, tbsname, cachesz,
 lob_cache_quota, ots) ;
 --
 dbms_dbfs_hs.setstoreproperty(
 storename,
 dbms_dbfs_hs.PROPNAME_SBTLIBRARY,
 'oracle.disksbt, ENV=(BACKUP_DIR=/ora_src/bkup)' );
 --
 dbms_dbfs_hs.setstoreproperty(
 storename,
 dbms_dbfs_hs.PROPNAME_MEDIAPOOL,
 '0') ;  -- Substitute valid value
 --
 dbms_dbfs_hs.setstoreproperty(
 storename,
 dbms_dbfs_hs.PROPNAME_COMPRESSLEVEL,
 'NONE') ;
 --
 -- Insure that the store is streamable. According to Oracle
 -- this must be set to allow links to work correctly.
 --
 dbms_dbfs_hs.setstoreproperty(
 storename,
 dbms_dbfs_hs.PROPNAME_STREAMABLE,
 'TRUE') ;
 --
 -- Please refer to DBMS_DBFS_CONTENT documentation
 -- for details about this method
 --
 dbms_dbfs_content.registerstore(
 storename,
 'HS',
 'dbms_dbfs_hs') ;
 --
 -- Please refer to DBMS_DBFS_CONTENT documentation
 -- for details about this method
 --
 dbms_dbfs_content.mountstore(storename, 'hs_store') ;
 --
 commit;
end ;
/

That will get you a DBFS store that will archive to the backup directory /ora_src/bkup. You may want to change that to fit your system, but these examples use that directory. The next set of statements have to be run because the create store commands don’t properly insert the backup directory since we’re cheating and using the disk sbt for RMAN.

connect / as sysdba

INSERT INTO SYS.DBFS_HS$_STORECOMMANDS
SELECT STOREID, '''ENV=(BACKUP_DIR=/ora_src/bkup)''', 1
FROM SYS.DBFS_HS$_STOREIDTABLE WHERE STORENAME = 'HS_STORE';

INSERT INTO SYS.DBFS_HS$_STORECOMMANDS
SELECT STOREID, '''ENV=(BACKUP_DIR=/ora_src/bkup)''', 2
FROM SYS.DBFS_HS$_STOREIDTABLE WHERE STORENAME = 'HS_STORE';

COMMIT;

Now we’ll create a directory so we can use the store:

connect hstest/hstest
--
declare
 v_properties  dbms_dbfs_content_properties_t;
begin
 v_properties := NULL;
 dbms_dbfs_content.createDirectory(
 path => '/hs_store',
 properties => v_properties,
 store_name => 'HS_STORE' ) ;
 --
 commit;
end;
/

So we’ve got a hierarchical store defined for the user hstest and it will archive to the operating system directory /ora_src/bkup. Now we need a table with SecureFile LOB’s to test it out.

  CREATE TABLE HS_LOBTABLE
   (	"ID" NUMBER,
	"LASTACCESSDATE" DATE,
	"CONTENTTYPE" NUMBER,
	"LOBCOL" BLOB,
	 PRIMARY KEY ("ID")
  USING INDEX COMPUTE STATISTICS
  TABLESPACE "HS_TAB"  ENABLE
   ) SEGMENT CREATION IMMEDIATE
  NOCOMPRESS LOGGING
  TABLESPACE "HS_TAB"
 LOB ("LOBCOL") STORE AS SECUREFILE (
  TABLESPACE "HS_TAB" ENABLE STORAGE IN ROW CHUNK 32768 RETENTION AUTO
  CACHE LOGGING  NOCOMPRESS  KEEP_DUPLICATES
  ) ;
--
-- Add sequence
--
CREATE SEQUENCE hs_seq;

-
-- Load 100 16K LOBs
--
set serveroutput on;
declare
  v_buffer             RAW(16384);
  v_tmpLOB             BLOB;
  v_amount             NUMBER := 16384;
  --
  v_lobnum             NUMBER := 100;
begin
  FOR lobctr IN 1..v_lobnum LOOP
    DBMS_LOB.CREATETEMPORARY(
      lob_loc => v_tmpLOB,
      cache => TRUE,
      dur => DBMS_LOB.CALL);
    --
    DBMS_LOB.OPEN(
      lob_loc => v_tmpLOB,
      open_mode => DBMS_LOB.LOB_READWRITE);
    --
    v_buffer := NULL;
    --
    FOR i IN 1..v_amount LOOP
      v_buffer := v_buffer || utl_raw.cast_to_raw(dbms_random.string('a',1));
    END LOOP;
    --
    dbms_lob.write(v_tmpLOB, v_amount, 1, v_buffer);
    --
    dbms_output.put_line('New LOB length: ' || dbms_lob.getlength(v_tmpLOB));
    --
    INSERT INTO HS_LOBTABLE
    VALUES(hs_seq.nextval, SYSDATE, 1, v_tmpLOB);
    --
    COMMIT;
    DBMS_LOB.CLOSE(lob_loc => v_tmpLOB);
    --
  END LOOP;
END;
/

If you’ve made it this far then all that’s left is to archive some of the SecureFile LOBs. When I set this up I only archived 30 SecureFile LOBs so I had to run a “store push” to force the database to archive the “cached” LOBs to the /ora_src/bkup directory. I’ll spend some more time on what’s going on under the covers in Part 2.

SET SERVEROUTPUT ON;
DECLARE
 v_mountpoint         VARCHAR2(32) := '/hs_store/';
 --
 v_store              VARCHAR2(32) := 'HS_STORE';
 v_LOB                BLOB;
 v_LOBsize            NUMBER;
 --
 prop1                dbms_dbfs_content_properties_t ;
 newcontent           BLOB;
BEGIN
 FOR arch_rec IN
 (
 SELECT id FROM hs_lobtable
 WHERE rownum <= 30
 )
 LOOP
 BEGIN
 SELECT lobcol
 INTO v_LOB
 FROM hs_lobtable
 WHERE id = arch_rec.id FOR UPDATE;
 --
 v_LOBsize := SYS.DBMS_LOB.GETLENGTH(v_LOB);
 DBMS_OUTPUT.PUT_LINE('Archive id: ' || arch_rec.id);
 DBMS_OUTPUT.PUT_LINE('LOB size: ' || v_LOBsize);
 --
 -- Write the LOB to the store
 --
 DBMS_LOB.MOVE_TO_DBFS_LINK (
 lob_loc => v_LOB,
 storage_path => v_mountpoint || 'LOB' || arch_rec.id,
 flags => DBMS_LOB.DBFS_LINK_NOCACHE);
 --
 COMMIT;
 EXCEPTION
 WHEN OTHERS THEN
 ROLLBACK;
 DBMS_OUTPUT.PUT_LINE(DBMS_UTILITY.FORMAT_ERROR_BACKTRACE);
 RAISE;
 END;
 END LOOP;
END;
/
--
-- This will archive LOBs in the "stage table" to the store. It will leave the LOB
-- in the staging table unless a flush is run.
--
--
DECLARE
 store_name varchar2(32) := 'HS_STORE';
BEGIN
 dbms_dbfs_hs.storePush(store_name) ;
 commit ;
END;
/

ORACLE_UNQNAME

June 6th, 2011

New in 11.2 is the environment variable ORACLE_UNQNAME and it is used with the OEM dbconsole. The following are some tests on an 11.2.0.2 Linux system:

$ echo $ORACLE_SID
db11g
314:oracle@testvm:/home/oracle [db11g]
$ echo $ORACLE_UNQNAME
db11g
315:oracle@testvm:/home/oracle [db11g]
$ emctl status dbconsole
Oracle Enterprise Manager 11g Database Control Release 11.2.0.2.0
Copyright (c) 1996, 2010 Oracle Corporation.  All rights reserved.

https://testvm:1158/em/console/aboutApplication

Oracle Enterprise Manager 11g is running.
------------------------------------------------------------------
Logs are generated in directory /app/local/oracle/product/11.2.0.2/db_1/testvm_db11g/sysman/log
316:oracle@testvm:/home/oracle [db11g]
$ unset ORACLE_SID
317:oracle@testvm:/home/oracle []
$ emctl status dbconsole
Oracle Enterprise Manager 11g Database Control Release 11.2.0.2.0
Copyright (c) 1996, 2010 Oracle Corporation.  All rights reserved.

https://testvm:1158/em/console/aboutApplication

Oracle Enterprise Manager 11g is running.
------------------------------------------------------------------
Logs are generated in directory /app/local/oracle/product/11.2.0.2/db_1/testvm_db11g/sysman/log
318:oracle@testvm:/home/oracle []
$ unset ORACLE_UNQNAME
319:oracle@testvm:/home/oracle []
$ emctl status dbconsole
Environment variable ORACLE_UNQNAME not defined. Please set ORACLE_UNQNAME to database unique name.
320:oracle@testvm:/home/oracle []
$ export ORACLE_SID=db11g
321:oracle@testvm:/home/oracle [db11g]
$ emctl status dbconsole
Oracle Enterprise Manager 11g Database Control Release 11.2.0.2.0
Copyright (c) 1996, 2010 Oracle Corporation.  All rights reserved.

https://testvm:1158/em/console/aboutApplication

Oracle Enterprise Manager 11g is running.
------------------------------------------------------------------
Logs are generated in directory /app/local/oracle/product/11.2.0.2/db_1/testvm_db11g/sysman/log
322:oracle@testvm:/home/oracle [db11g]
$

However, when working on an 11.2.0.2 DataGuard database with db_unique_name set I had to have ORACLE_UNQNAME set as well. Also note that in the message from the dbconsole that the OEM directory is $ORACLE_HOME/testvm_db11g which is the hostname and SID, but when using db_unique_name this won’t necessarily be the same. Hence I suspect, and will need to run some more tests to prove, that this was added to handle the situation where the SID and the unique name are different.

ILO Customizations

March 4th, 2011

I’ve been using the Instrumentation Library for Oracle for quite a while now, but I will confess that all I use it for is to set module and action. The fact that the ILO allows task nesting has always been it’s biggest appeal for me. Recently though I’ve been enhancing my PL/SQL logging utility and needed to be able to turn tracing on at the module/action level and come up with a more elegant way to time tasks.

In the ILO documentation it says that the ILO can do both of these things and that the ILO_TIMER package is supplied to do just that. The problem is that the comments in the code are kind of cryptic, at least to me, and there really aren’t any good examples of how to implement either one. Well I finally had enough motivation to actually read the code and figure out what was going on. It turns out to be kind of slick, although it’s heavily dependent on outside code, my logging utility in this case. In the ILO_TIMER package three functions/procedures need to be modified. I modified them with conditional compilation so that I don’t have to maintain more than one version, even if I’m not using my logging package.

Let’s tackle tracing first. The GET_CONFIG procedure is where the ILO provides a “callout” to turn tracing on for a module and action pair. In particular, the ILO_TASK.begin_task procedure calls the ILO_TIMER.get_config procedure to check to see if the boolean “p_trace” is true. If it is it calls ILO_SYSUTIL.turn_trace_on to turn tracing on with the appropriate database call for the version being used. The specific section in the ILO_TIMER package looks like this:


 IF g_all_interesting AND g_ignore_schedule THEN
   p_trace := TRUE;
   P_walltime := TRUE;
   p_rtime := TRUE;
   --If the Module and Action are "interesting"  ...
   --ELSIF call your custom method here THEN
   --
   -- If the Module and Action DON'T exist in the schedule ...
 ELSE
   IF g_all_interesting THEN
     p_trace := TRUE;
     P_walltime := TRUE;
     p_rtime := TRUE;
   ELSE
     p_trace := FALSE;
     P_walltime := FALSE;
     p_rtime := FALSE;
   END IF;
 END IF;

Now since I wanted to use conditional compilation I left this code alone and added my code right after:


 --
 -- If using dblog check to see if tracing should be enabled
 --
 $IF $$dblog $THEN
   --
   -- If dblog exists then always set run time data if it exists.
   --
   p_rtime := TRUE;
   --
   IF dblog.Is_Trace_Enabled(p_module_name => p_module,
     p_action_name => p_action ) = 'Y' THEN
     --
     p_trace := TRUE;
     P_walltime := TRUE;
   END IF;
 $END

Ignore the fact that I moved the “p_rtime” parameter to always be set if using the dblog package. We’ll talk about that in the section on task timing. With this change the ILO_TASK.begin_task call will check to see if tracing is enabled from my logging procedure and if it is, the p_trace boolean will be set to true and the ILO will turn tracing on. Very slick and easy.

Now let’s tackle task timing. The ILO_TIMER package has two calls, a “begin_timed_task” function call and a “end_timed_task” procedure call. The begin_timed_task function simply returns a null and the end_timed_task procedure is just a null statement. It is left up to us to figure out what to do with them. One helpful hint is that these function/procedures are called when tracing (e.g. p_trace) or response time (e.g. p_rtime) booleans have been set (although there are other ways as well). This is why I moved the p_rtime boolean setting up above to always be set when using my logging procedure. The other helpful hint is that it only makes sense when the begin_time/end_time parameters are passed to the begin_task and end_task procedures in the ILO_TASK package. This is effectively how task timing is performed. So, the code then looks like this in the ILO_TIMER package:


FUNCTION begin_timed_task(p_begin_time timestamp) RETURN NUMBER IS
BEGIN
  --
  -- If using dblog return the start time in seconds
  --
  $IF $$dblog $THEN
    IF p_begin_time IS NOT NULL THEN
      RETURN(
        (extract(hour from p_begin_time))*3600+
        (extract(minute from p_begin_time))*60+
        extract(second from p_begin_time)
      );
    END IF;
  $END
  --
  RETURN NULL;
EXCEPTION
  WHEN OTHERS THEN
    if ilo_util.get_raise_exceptions then
      raise;
    else
      RETURN NULL;
    end if;
END begin_timed_task;

PROCEDURE end_timed_task (
  p_stack_rec    ilo_task.stack_rec_t
  ,p_error_num    PLS_INTEGER default 0
  ,p_end_time     timestamp DEFAULT NULL
  ,p_widget_count NUMBER DEFAULT NULL)
IS
BEGIN
  --
  -- If using dblog set the task time
  --
  $IF $$dblog $THEN
    IF (( p_end_time IS NOT NULL ) AND ( p_stack_rec.rtime_active )) THEN
      --
      -- The following can be used as debugging statements
      --
      --dbms_output.put_line('module: ' || p_stack_rec.module );
      --dbms_output.put_line('action: ' || p_stack_rec.action );
      --dbms_output.put_line('SEQUENCE: ' || p_stack_rec.SEQUENCE );
      --dbms_output.put_line('p_end_time: ' || ((extract(hour from p_end_time))*3600+
      --  (extract(minute from p_end_time))*60+ extract(second from p_end_time)) );
      --
      IF ( ( ((extract(hour from p_end_time))*3600+
        (extract(minute from p_end_time))*60+
        extract(second from p_end_time)) - p_stack_rec.SEQUENCE ) >= 0 ) THEN
        --
        dblog.log(
          p_module_name=> p_stack_rec.module,
          p_action_name=> p_stack_rec.action,
          p_tasktime => ( ((extract(hour from p_end_time))*3600+
            (extract(minute from p_end_time))*60+
            extract(second from p_end_time)) - p_stack_rec.SEQUENCE ),
            p_text=> 'Task time' );
      END IF;
    END IF;
  $END
  --
  NULL;
EXCEPTION
  WHEN OTHERS THEN
    if ilo_util.get_raise_exceptions then
      raise;
    else
      NULL;
    end if;
END end_timed_task;

The begin_timed_task function simply returns the timestamp in seconds. The ILO_TASK.begin_task procedure sets this value in a SEQUENCE field of a record for the current stack level (e.g. the task nesting mechanism). When an ILO_TASK.end_task call is made with the end_time parameter the task time is calculated from the current timestamp and the value saved from the corresponding begin_task call.  A call is then made to the logging procedure to save that time as the “tasktime” for the current module and action.

As it turns out is was pretty simple. Of course most of the heavy lifting is being done by the logging package and I will make that available shortly along with some examples of how to put this to real use.

New SQL Execution Tree Utility Posted

September 16th, 2010

Well I’ve finally posted the SQL execution tree utility that I mentioned here. It is available on appsdba.com at the bottom of the Resource Profiler page. I called it the sql_tree utility for lack of a better name. I guess I could have named it the extended SQL trace parse, execute and fetch exclusive time calculator, but sql_tree just seemed easier. In any case it’s available if you want to check it out. I posted a pretty detailed explanation in my original blog post so I won’t repeat it here, but I did add a fairly good size example with the utility on appsdba.com.

ASMLIB and RPM Versions

April 26th, 2010

When determining the proper versions of ASMLIB that should be installed, sometimes it’s useful to know the source RPM as well as the name. Typically I’ll run the rpm command with the “-qa” options:


$ rpm -qa | grep asm
oracleasm-2.6.18-164.0.0.0.1.el5xen-2.0.5-1.el5
oracleasmlib-2.0.4-1.el5
oracleasm-support-2.1.3-1.el5
$

But there are times when deciphering the kernel version that it’s nice to see the source rpm name as well. This can be accomplished with the “-i” option:


$ rpm -q -i -a | grep asm
Name        : oracleasm-2.6.18-164.0.0.0.1.el5xen  Relocations: (not relocatable)
Group       : System Environment/Kernel     Source RPM: oracleasm-2.6.18-164.0.0.0.1.el5-2.0.5-1.el5.src.rpm
URL         : http://oss.oracle.com/projects/oracleasm/
Name        : oracleasmlib                 Relocations: (not relocatable)
Group       : System Environment/Kernel     Source RPM: oracleasmlib-2.0.4-1.el5.src.rpm
Name        : oracleasm-support            Relocations: (not relocatable)
Group       : System Environment/Kernel     Source RPM: oracleasm-support-2.1.3-1.el5.src.rpm
URL         : http://oss.oracle.com/projects/oracleasm/
$

When installing ASMLIB there are three rpms that need to be verified. See http://www.oracle.com/technology/tech/linux/asmlib/driver_matrix.html for more information. There are also two versions available, one for the 2.4 kernel and one for 2.6 kernels. See http://www.oracle.com/technology/tech/linux/asmlib/driver_matrix.html.

When verifying which kernel version to use a “uname -r” command will show the currently running kernel version:


$ uname -r
2.6.18-164.0.0.0.1.el5xen
$

Typically I use “uname -a” for completeness:


$ uname -a
Linux testvm 2.6.18-164.0.0.0.1.el5xen #1 SMP Wed Sep 2 22:48:20 EDT 2009 i686 athlon i386 GNU/Linux
$

To double check the kernel rpms installed:


$ rpm -qa | grep kernel
kernel-xen-devel-2.6.18-164.0.0.0.1.el5
kernel-xen-2.6.18-164.0.0.0.1.el5
kernel-headers-2.6.18-164.0.0.0.1.el5
453:oracle@testvm:/home/oracle []
$

Once the kernel version is established, the appropriate rpm can be downloaded starting from the main ASMLIB page.

The entry for the kernel shown here looks like:

It can get confusing since there are also entries for higher levels:
Notice the 164.2.1, currently there are also 6, 9, 10, 11 and 15 versions available as well so it’s important to verify the exact kernel version.

RMAN Tape Simulation

April 8th, 2010

I needed a way to simulate an SBT channel recently using RMAN and was reminded of a slick technique that is documented in Oracle Support Note: 312737.1, RMAN and Specific Media Managers Environment Variables. The following is a simple example:


$ORACLE_HOME/bin/rman target / nocatalog

run {
allocate channel ch00 device type 'SBT_TAPE'
PARMS="SBT_LIBRARY=oracle.disksbt,
ENV=(BACKUP_DIR=/app/local/oracle/orabkup/db11g/tape)";
backup datafile 1 format='%U';
}

When this backup is run it creates a disk file in the directory listed in the BACKUP_DIR variable that emulates a tape file. This is especially handy if you’re testing the new database file system hierarchical store (e.g. dbfs_hs) features in Oracle 11gR2, since only SBT output is supported.

The following output shows the results of running this in 11.2:


$ $ORACLE_HOME/bin/rman target / nocatalog

Recovery Manager: Release 11.2.0.1.0 - Production on Thu Apr 8 15:00:53 2010

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

connected to target database: DB11G (DBID=179279599)
using target database control file instead of recovery catalog

RMAN> run {
allocate channel ch00 device type 'SBT_TAPE'
PARMS="SBT_LIBRARY=oracle.disksbt,
ENV=(BACKUP_DIR=/app/local/oracle/orabkup/db11g/tape)";
backup datafile 1 format='%U';
}2> 3> 4> 5> 6>

allocated channel: ch00
channel ch00: SID=51 device type=SBT_TAPE
channel ch00: WARNING: Oracle Test Disk API

Starting backup at 08-APR-10
channel ch00: starting full datafile backup set
channel ch00: specifying datafile(s) in backup set
input datafile file number=00001 name=/app/local/oradata/db11g/system01.dbf
channel ch00: starting piece 1 at 08-APR-10
channel ch00: finished piece 1 at 08-APR-10
piece handle=12lak79g_1_1 tag=TAG20100408T150104 comment=API Version 2.0,MMS Version 8.1.3.0
channel ch00: backup set complete, elapsed time: 00:00:35
Finished backup at 08-APR-10

Starting Control File and SPFILE Autobackup at 08-APR-10
piece handle=c-179279599-20100408-01 comment=API Version 2.0,MMS Version 8.1.3.0
Finished Control File and SPFILE Autobackup at 08-APR-10
released channel: ch00

RMAN> exit

Recovery Manager complete.
$

The file output looks like this:


$ ls -lrt
total 610920
-rw-r--r-- 1 oracle oinstall 608174088 Apr  8 15:01 12lak79g_1_1
-rw-r--r-- 1 oracle oinstall      3204 Apr  8 15:01 Oracle_Disk_SBT_Catalog
-rw-r--r-- 1 oracle oinstall  16777224 Apr  8 15:01 c-179279599-20100408-01
447:oracle@testvm:/app/local/oracle/orabkup/db11g/tape [db11g]
$

The file can be read back by Oracle and I’ll have an example of this using the dbfs_content API soon.

The other interesting thing about this is that I believe it’s been around since Oracle8 when RMAN first appeared.

11gR2 RAC Observations – crs_stat

April 3rd, 2010

If you’ve ever used the command “crs_stat -t” then you probably know that the output leaves a little to be desired. Well I stumbled upon this gem of a utility a while back and thought I’d give it a little more attention. It’s called crsstat, appropriately enough, and is a shell script available here:

http://www.rachelp.nl/index_kb.php?menu=scripts&actie=show&id=14

As it turns out, the script is actually buried in Oracle Support Note: 259301.1. Not sure who the original author is, but the script is just great.

The following shows the output of the “crs_stat -t” command:


$ crs_stat -t
Name           Type           Target    State     Host
------------------------------------------------------------
ora....DATA.dg ora....up.type ONLINE    ONLINE    racdb1
ora....GRID.dg ora....up.type ONLINE    ONLINE    racdb1
ora....ER.lsnr ora....er.type ONLINE    ONLINE    racdb1
ora....N1.lsnr ora....er.type ONLINE    ONLINE    racdb2
ora.asm        ora.asm.type   ONLINE    ONLINE    racdb1
ora....SM1.asm application    ONLINE    ONLINE    racdb1
ora....B1.lsnr application    ONLINE    ONLINE    racdb1
ora....db1.gsd application    ONLINE    ONLINE    racdb1
ora....db1.ons application    ONLINE    ONLINE    racdb1
ora....db1.vip ora....t1.type ONLINE    ONLINE    racdb1
ora....SM2.asm application    ONLINE    ONLINE    racdb2
ora....B2.lsnr application    ONLINE    ONLINE    racdb2
ora....db2.gsd application    ONLINE    ONLINE    racdb2
ora....db2.ons application    ONLINE    ONLINE    racdb2
ora....db2.vip ora....t1.type ONLINE    ONLINE    racdb2
ora....SM3.asm application    ONLINE    ONLINE    racdb3
ora....B3.lsnr application    ONLINE    ONLINE    racdb3
ora....db3.gsd application    ONLINE    ONLINE    racdb3
ora....db3.ons application    ONLINE    ONLINE    racdb3
ora....db3.vip ora....t1.type ONLINE    ONLINE    racdb3
ora.racdb.db   ora....se.type ONLINE    ONLINE    racdb2
ora....taf.svc ora....ce.type ONLINE    ONLINE    racdb3
ora....taf.svc ora....ce.type ONLINE    ONLINE    racdb3
ora.eons       ora.eons.type  ONLINE    ONLINE    racdb1
ora.gsd        ora.gsd.type   ONLINE    ONLINE    racdb1
ora....network ora....rk.type ONLINE    ONLINE    racdb1
ora.oc4j       ora.oc4j.type  OFFLINE   OFFLINE
ora.ons        ora.ons.type   ONLINE    ONLINE    racdb1
ora....ry.acfs ora....fs.type ONLINE    ONLINE    racdb1
ora.scan1.vip  ora....ip.type ONLINE    ONLINE    racdb2
$

On the same system with the crsstat script:

$ ./crsstat
HA Resource                                   Target     State
-----------                                   ------     -----
ora.racdbDATA.dg                              ONLINE     ONLINE on racdb1
ora.racdbGRID.dg                              ONLINE     ONLINE on racdb1
ora.LISTENER.lsnr                             ONLINE     ONLINE on racdb1
ora.LISTENER_SCAN1.lsnr                       ONLINE     ONLINE on racdb2
ora.asm                                       ONLINE     ONLINE on racdb1
ora.racdb1.ASM1.asm                           ONLINE     ONLINE on racdb1
ora.racdb1.LISTENER_RACDB1.lsnr               ONLINE     ONLINE on racdb1
ora.racdb1.gsd                                ONLINE     ONLINE on racdb1
ora.racdb1.ons                                ONLINE     ONLINE on racdb1
ora.racdb1.vip                                ONLINE     ONLINE on racdb1
ora.racdb2.ASM2.asm                           ONLINE     ONLINE on racdb2
ora.racdb2.LISTENER_RACDB2.lsnr               ONLINE     ONLINE on racdb2
ora.racdb2.gsd                                ONLINE     ONLINE on racdb2
ora.racdb2.ons                                ONLINE     ONLINE on racdb2
ora.racdb2.vip                                ONLINE     ONLINE on racdb2
ora.racdb3.ASM3.asm                           ONLINE     ONLINE on racdb3
ora.racdb3.LISTENER_RACDB3.lsnr               ONLINE     ONLINE on racdb3
ora.racdb3.gsd                                ONLINE     ONLINE on racdb3
ora.racdb3.ons                                ONLINE     ONLINE on racdb3
ora.racdb3.vip                                ONLINE     ONLINE on racdb3
ora.cmssb.db                                  ONLINE     ONLINE on racdb2
ora.cmssb.pref_all_basictaf.svc               ONLINE     ONLINE on racdb3
ora.cmssb.pref_all_notaf.svc                  ONLINE     ONLINE on racdb3
ora.eons                                      ONLINE     ONLINE on racdb1
ora.gsd                                       ONLINE     ONLINE on racdb1
ora.net1.network                              ONLINE     ONLINE on racdb1
ora.oc4j                                      OFFLINE    OFFLINE
ora.ons                                       ONLINE     ONLINE on racdb1
ora.registry.acfs                             ONLINE     ONLINE on racdb1
ora.scan1.vip                                 ONLINE     ONLINE on racdb2
$

Just a tremendous difference!