Monthly Archives: December 2013

Getting up and running with UCP and Application Continuity

I have already posted a couple of articles on the use of Oracle’s Universal Connection Pool in the past with regards to Workload Management and Oracle RAC 11.2. Since then a lot happened, with the release of Oracle 12c being the most notable event. With 12c you get lots of interesting new features for JDBC, and the one I would like to present today is Application Continuity. This continues the previous post on playing with Application Continuity outside of a midlle-tier environment. Well, if you allow me to call Tomcat 7 “middle-tier” that is.

The aim of this post is to extend my previous posts about setting up UCP with Application Continuity. The basic setup remains unchanged, but this time I tested with JDK 1.6 (build 1.6.0_45-b06) and Tomcat 7.0.47 on Oracle Enterprise Linux 6.4 64bit.

For those of you not remembering straight away what equipment I  was using for the last post, here is a quick summary. I am using the same 2 node RAC cluster which is home to the CDB RAC12C. Both instances, RAC12C1 and RAC12C2 are open. A little PDB, named DEMOPDB (open on both instances too) is used for this demo, mainly because I was curious how Application Continuity works with PDBs. In summary: it does :)

I am not going to repeat all the details about setting up Tomcat for use with UCP, please refer to part 1 and part 2 for the basics. The following example also uses the sample web application.

Necessary Changes for Application Continuity

The first change necessary was to make sure the connection factory returned the required class for the connection. This required a change to the URL property. In addition I had to use the way-more-verbose-connection descriptor as I found in my previous post (independently confirmed by Martin Nash too). Here is the new

[root@oracledev ucp]# cat web/META-INF/context.xml
<Context>
 <Resource
 name="jdbc/UCPPool"
 auth="Container"
 factory="oracle.ucp.jdbc.PoolDataSourceImpl"
 type="oracle.ucp.jdbc.PoolDataSource"
 description="UCP JNDI Connection Pool for Application Continuity"
 connectionFactoryClassName="oracle.jdbc.replay.OracleDataSourceImpl"
 onsConfiguration="nodes=rac12node1:6200,rac12node2:6200"
 initialPoolSize="10"
 minPoolSize="10"
 maxPoolSize="50"
 inactiveConnectionTimeout="20"
 user="martin"
 password="secret"
 url="jdbc:oracle:thin:@(DESCRIPTION = (TRANSPORT_CONNECT_TIMEOUT=3) (RETRY_COUNT=20)(FAILOVER=ON) 
(ADDRESS = (PROTOCOL = TCP)(HOST = rac12scan.gns.example.com)(PORT = 1521)) 
(CONNECT_DATA = (SERVER = DEDICATED) (SERVICE_NAME = ACTEST)))"
 connectionPoolName="UCPPool"
 validateConnectionOnBorrow="true"
 fastConnectionFailoverEnabled="true"
 sqlForValidateConnection="select 1 from DUAL" />
</Context>

Note that I added the initialPoolSize to match the minPoolSize and changed the connectionFactoryClassName plus the aforementioned change to the URL (this has been line wrapped for readability) which was actually all there was to do to change the application.

When reviewing the servlet code I quickly realised that the stored procedure somehow had to be called asynchronously so I spent about 2 hours trying to figure out how to do this in Java with a Java Server Page. I eventually came to the conclusion that it would have to be AJAX so I spent another 30 minutes hacking something together for which I apologise to all web developers. On the upside, it does work and what I needed it to do. As a reminder, here is the code in the stored procedure:

PROCEDURE	   "CANICARRYON" (pi_message varchar2)
as
begin
 insert into acdemotab (message) values (pi_message);
 dbms_lock.sleep(20);
 commit;
end;

I have lowered the sleep to 20 seconds so as not having to wait too long. The service definition has not changed from the first test with Application Continuity, see here for the srvctl syntax. So with all that said, here is what changed. I am using a new JSP “index.jsp” for a welcome page. It in turn uses class UCPHelper to create the connection pool and eventually to execute the stored procedure. Should I find the time I’ll extend it to print pool statistics, for now it is just the basic JNDI lookup. The code is shown here:

package mypackage;

import java.sql.Connection;
import java.sql.SQLException;
import java.sql.Statement;
import oracle.ucp.jdbc.PoolDataSourceFactory;
import oracle.ucp.jdbc.PoolDataSource;
import oracle.ucp.jdbc.ValidConnection;
import java.sql.ResultSet;
import javax.naming.*;

public class UCPHelper {
	PoolDataSource m_pds;

	public Connection getConnection(String jndiName) 
		throws Exception
	{
		Context ctx = new InitialContext();
		Context envContext = (Context) ctx.lookup("java:/comp/env");
		
		m_pds = (PoolDataSource) envContext.lookup (jndiName);

		return m_pds.getConnection();
	}

	public boolean isReplayConnection(Connection conn) {
		if (conn instanceof oracle.jdbc.replay.ReplayableConnection) {
			return true;
		} else {
			return false;
		}
	}

	public void executePLSQL(String message, Connection conn) 
		throws Exception
	{
		java.sql.CallableStatement cstmt = conn.prepareCall("{call canIcarryOn(?)}");
		cstmt.setString(1, message);
		cstmt.execute();
	}

}

The index.jsp contents are shown here:

<!DOCTYPE html>
<%@ page contentType="text/html;charset=UTF-8"%>
<html>
    <head>
        <meta http-equiv="Content-Type" content="text/html; charset=UTF-8"/>
        <title>index</title>
        <script>
          function executeCMD(str) {
              var xreq;

              if (str == "") {
                  document.getElementById("showtext").innerHTML = "<p>Enter a value!</p>";
                  return;
              }
              if (window.XMLHttpRequest) {
                  xreq = new XMLHttpRequest();
              }
              else {
                  xreq = new ActiveXObject("Microsoft.XMLHTTP");
              }
              xreq.onreadystatechange = function () {
                  if (xreq.readyState == 4) {
                      if (xreq.status == 200) {
                         document.getElementById("showtext").innerHTML = xreq.responseText;
                      } else {
                         document.getElementById("showtext").innerHTML = "<p>something went wrong with the request</p>";
                      }
                  }
              }

              xreq.open("get", "getRequest.jsp?q=" + str, "true");
              xreq.send();
              document.getElementById("showtext").innerHTML = "<p>request has been submitted-waiting for answer</p>";
          }
        </script>
    </head>
    <body>
        <h1>A test for Application Continuity</h1>
         
        <form>
            <table>
                <tr>
                    <td>Enter a message to be sent asynchronously to the database</td>
                    <td>
                        <input type="text" id="messageField"/>
                    </td>
                    <td>
                        <input type="button" value="Submit"
                               onclick="executeCMD(document.getElementById('messageField').value)"/>
                    </td>
                </tr>
            </table>
        </form>
        <p>The processing will be performed asynchronously</p>
        <div id="showtext">request has not yet been submitted</div>
    </body>
</html>

The asynchronous part is in the script tag in the html header: the XMLHttpRequest allows me to send data back to the server and wait for the result. The lower div element is updated according to user input. If there is no input, nothing happens and a message “enter a value” is shown. Once the input is present, it is sent off to the server. The response is then parsed. if the readyState is 4, and the HTTP code 200 everything is fine and I print the output from the called JSP, getRequest.jsp. Sometimes with UCP you get HTTP 500 error codes which I am trapping too.

The JSP dealing with the request processing, getRequest (because I’m using a HTTP get) performs all the work with the database. It’s shown here:

<%@ page import="mypackage.*" %>
<%@ page import="java.sql.Connection " %>
<%@ page import="java.sql.SQLException " %>
<%@ page import="java.sql.Statement " %>
<%@ page import="oracle.ucp.jdbc.PoolDataSourceFactory " %>
<%@ page import="oracle.ucp.jdbc.PoolDataSource " %>
<%@ page import="oracle.ucp.jdbc.ValidConnection " %>
<%@ page import="java.sql.ResultSet " %>

<html>
<head>
	<meta http-equiv="Content-Type" content="text/html; charset=UTF-8">
	<title>Application Continuity with RAC 12c Example JSP</title>
</head>
<body bgcolor="white">

	<p>request started</p>

<%
	String message = request.getParameter("q");

	UCPHelper helper = new UCPHelper();
	Connection conn = helper.getConnection("jdbc/UCPPool");

	helper.executePLSQL(message, conn);
%>

	<p>request completed</p>

</body>
</html>

Test

The test was successful although it took a very long time to fail the service over to the “availble” node. Thanks to the fat connection string the connection pool has been re-established with the correct number of sessions. In one scenario I had 20 sessions (10 more than initial/min pool size) and they were all created on the available instance.

I didn’t yet work out where the delay was with the service failover, that’s for another post…

Advertisements

SQLPlus and white space in the output

I finally managed to work around My Most Annoying Problem (TM) with SQLPlus in my career. SQLPlus will mess up my output when I am copying/posting something in wordpress or elsewhere. Here’s an example to show you what I mean. The output in SQLPlus in my terminal window is all nice and pretty (it’s a print screen):

nice output

Many thanks to Jonathan Lewis and his presentation about generating test data by the way!

The above output looks nice at first glance, so I’m copying and pasting this into a document, only to see this (again a print screen; this time from TextWrangler):

not so nice output

Obviously that isn’t great-why is the layout broken there?

What is not immediately visible is that SQLPlus uses TAB characters where in my opinion should use white spaces instead. This can be a problem for me but it is not necessarily one for you. Depending on your tab width in your favourite editor everything can be perfect if your tab-width matches the one used in SQLPlus. If it doesn’t you get the result as shown above.

Solutions

So far I have use the old spool /path/to/spoolfile approach to spool data into a text file and then transferred it to my system. But today I got so annoyed with this that I actually looked into the documentation. And fair enough, I found the reference to this behaviour using the SET TAB option:

[set tab, ed.] Determines how SQL*Plus formats white space in terminal output. OFF uses spaces to format white space in the output. ON uses the TAB character. TAB settings are every eight characters. The default value for TAB is system dependent.

So that’s it then! I don’t like the tabs, they are unpredictable. White spaces are predictable so let’s see what happens:

SQL> show tab
tab ON
SQL> set tab off
SQL> select /*+ gather_plan_statistics monitor */ /* martintest006 */ * from
  2  clustered_lrg where trunc(date_created) =
  3* to_date('2013-08-08','yyyy-mm-dd')  and state = 'RARE';

             ID T_PAD                          DATE_CREA DATE_COMP STATE
--------------- ------------------------------ --------- --------- ------------
         147999 14800000                       08-AUG-13 08-AUG-13 RARE

         149999 15000000                       08-AUG-13 09-AUG-13 RARE

         148999 14900000                       08-AUG-13 08-AUG-13 RARE

3 rows selected.

As you can see everything is aligned perfectly! The same is true for the TextWrangler output although I’m not uploading the screenshot to prove. I hope that this post saves some technical editors some nerves :)

Playing with Application Continuity in RAC 12c

One of the more interesting features in Oracle 12c RAC is application continuity. Why do I believe it is? Because it relieves developers from having to think about retrying connections and catch SQLExceptions in the code. I already thought that Fast Application Notification and Fast Connect Failover (FCF) are great, _but_ they required the developer to understand RAC and Oracle which you can’t take for granted. In fact looking back over the last few years since I co-wrote Pro Oracle Database 11g RAC on Linux the number 1 complaint I got from developers was that RAC was too complex (see for example in this thread on oracle-l)

Now Application Continuity takes away 2 problems I have seen.

  1. You no longer need the OCI libraries
  2. You no longer need to code for session failure

I mention the OCI libraries here because I have seen applications where developers believed they were using Transparent Application but weren’t (if you see “jdbc:oracle:thin:…” in the connection string for an application you can be sure it won’t use TAF). Also I haven’t really seen any real UCP implementation outside/not provided by Oracle. But there is hope!

This is a 2 part post, in the first one I’m just showing how to create a Connection Pool and use Application Continuity. In the second part which I am showing you how to use Tomcat 7/JDK6/Oracle Linux 6.4 to create a Pooled Data Source using JNDI.

The code

The code is rather simple and more or less taken from the Getting started with UCP chapter from the documentation. There was quite some uncertainty around AC for me when I looked at it. Once I realised that AC and UCP are complementary technologies it all made sense. The Data Source you get with AC is for a single session. Only when you combine it with the PoolDataSource can you create a pool. The way UCP creates sessions is based on the Connection Factory class, and this is where the only change in my code was made. Pre-Application Continuity you used oracle.jdbc.pool.OracleDataSource, now it’s oracle.jdbc.replay.OracleDataSourceImpl. Which is good news as you can quite easily change from the 11g model to 12c as you can see in the next post.

Now here’s the Java class I wrote.


import java.sql.Connection;
import java.sql.SQLException;
import java.sql.Statement;
import oracle.ucp.jdbc.PoolDataSourceFactory;
import oracle.ucp.jdbc.PoolDataSource;
import oracle.ucp.jdbc.ValidConnection;
import java.sql.ResultSet;

public class UCPTest {


  public static void main (String[] args)
    throws Exception
  {
    String message;
    
    if (args.length == 0) {
      message = "default";
    } else {
      message = args[0];
    }

    PoolDataSource  pds = PoolDataSourceFactory.getPoolDataSource();
    pds.setConnectionFactoryClassName("oracle.jdbc.replay.OracleDataSourceImpl");

    System.out.println("connection factory set");

    String URL = "jdbc:oracle:thin:@(DESCRIPTION = (TRANSPORT_CONNECT_TIMEOUT=3) (RETRY_COUNT=20)(FAILOVER=ON) " +
     (ADDRESS = (PROTOCOL = TCP)(HOST = rac12scan.gns.example.com)(PORT = 1521)) (CONNECT_DATA = " +
     (SERVER = DEDICATED) (SERVICE_NAME = ACTEST)))";
    System.out.println("Using URL\n" + URL);
    pds.setURL(URL);
    pds.setUser("martin");
    pds.setPassword("***");

    pds.setInitialPoolSize(10);
    pds.setMinPoolSize(10);
    pds.setMaxPoolSize(20);

    // RAC Features
    pds.setConnectionPoolName("Application Continuity Pool");
    pds.setFastConnectionFailoverEnabled(true);
    // use srvctl config nodeapps to get the ONS ports on the cluster
    pds.setONSConfiguration("nodes=192.168.100.30:6200,192.168.100.32:6200");

    System.out.println("pool configured, trying to get a connection");

    Connection conn = pds.getConnection();
    if (conn == null || !((ValidConnection) conn).isValid())  {

      System.out.println("connection is not valid");
      throw new Exception ("invalid connection obtained from the pool");
    }

    if ( conn instanceof oracle.jdbc.replay.ReplayableConnection ) {
      System.out.println("got a replay data source");
    } else {
      System.out.println("this is not a replay data source. Why not?");
    }

    System.out.println("got a connection! Getting some stats if possible");
    oracle.ucp.jdbc.JDBCConnectionPoolStatistics stats = pds.getStatistics();
    System.out.println("\tgetAvailableConnectionsCount() " + stats.getAvailableConnectionsCount());
    System.out.println("\tgetBorrowedConnectionsCount() " + stats.getBorrowedConnectionsCount() );
    System.out.println("\tgetRemainingPoolCapacityCount() " + stats.getRemainingPoolCapacityCount());
    System.out.println("\tgetTotalConnectionsCount() " + stats.getTotalConnectionsCount());

    System.out.println(((oracle.ucp.jdbc.oracle.OracleJDBCConnectionPoolStatistics)pds.getStatistics()).getFCFProcessingInfo());

    System.out.println("Now working");

    java.sql.CallableStatement cstmt = conn.prepareCall("{call canIcarryOn(?)}");
    cstmt.setString(1, message);
    cstmt.execute();

    System.out.println("Statement executed. Now closing down");
    System.out.println("Almost done! Getting some more stats if possible");

    stats = pds.getStatistics();
    System.out.println("\tgetAvailableConnectionsCount() " + stats.getAvailableConnectionsCount());
    System.out.println("\tgetBorrowedConnectionsCount() " + stats.getBorrowedConnectionsCount() );
    System.out.println("\tgetRemainingPoolCapacityCount() " + stats.getRemainingPoolCapacityCount());
    System.out.println("\tgetTotalConnectionsCount() " + stats.getTotalConnectionsCount());

    System.out.println(((oracle.ucp.jdbc.oracle.OracleJDBCConnectionPoolStatistics)pds.getStatistics()).getFCFProcessingInfo());

    cstmt.close();
    conn.close();
    conn = null;
  }
}

I have used the following Classpath to compile it:

CLASSPATH=/m/apache-tomcat-7.0.47/lib/ons.jar
CLASSPATH=$CLASSPATH:/m/apache-tomcat-7.0.47/lib/ojdbc6.jar
CLASSPATH=$CLASSPATH:/m/apache-tomcat-7.0.47/lib/ucp.jar:.
export CLASSPATH

All JAR files are from my 12c RAC installation. The database connection is made against a PDB (open on both instances) and a service defined as follows:

[oracle@rac12node1 ~]$ srvctl add service -db RAC12C -service ACTEST -preferred RAC12C1 \
> -available RAC12C2 -policy automatic -failovertype TRANSACTION -pdb DEMOPDB -clbgoal SHORT \
> -rlbgoal SERVICE_TIME -notification true -commit_outcome TRUE

Also pretty much a copy and paste from the documentation with a preferred and an available instance. The only missing bit is the stored procedure. It simply inserts a message into a table together with a timestamp. It then sleeps for 60 seconds and commits. The sleeping is important because a) allows me to kill smon of the service it runs on and b) demonstrates that the commit will happen even if you killed the session implicitly.

To better understand what was going on I created a log file using the log4j framework. The logging.properties file is shown in the appendix. I used jar -tf to get all that information, then replaced “.class” with “level=ALL” and read it into the file. The class names seem to have changed from 11.2 when I last tested. Be aware that UCP uses MBeans to allow for remote management of the pool, and MBeans are very verbose. This is a research/debug log file, not a production configuration!

The test

The test is simple. I start the pool on the dev machine. As soon as I see the “now working” message I kill the instance the session is running on. Then wait to see what happens :)

The output is shown here

[oracle@oracledev ~]$ java -Djava.util.logging.config.file=logging.properties UCPTest all_out_logging2
connection factory set
Using URL
jdbc:oracle:thin:@(DESCRIPTION = (TRANSPORT_CONNECT_TIMEOUT=3) (RETRY_COUNT=20)(FAILOVER=ON) (ADDRESS = 
(PROTOCOL = TCP)(HOST = rac12scan.gns.example.com)(PORT = 1521)) (CONNECT_DATA = (SERVER = DEDICATED)
(SERVICE_NAME = ACTEST)))
pool configured, trying to get a connection
got a replay data source
got a connection! Getting some stats if possible
	getAvailableConnectionsCount() 9
	getBorrowedConnectionsCount() 1
	getRemainingPoolCapacityCount() 10
	getTotalConnectionsCount() 10

Now working
Statement executed. Now closing down
Almost done! Getting some more stats if possible
	getAvailableConnectionsCount() 9
	getBorrowedConnectionsCount() 1
	getRemainingPoolCapacityCount() 10
	getTotalConnectionsCount() 10
12-Dec-2013 11:33 SUCCESS <Type:SERVICE_UP> <Service:"actest"> <Instance:"null"> <Db:"rac12c"> 
 Connections:(Available=9 Affected=0 FailedToProcess=0 MarkedDown=0 Closed=0)
 (Borrowed=1 Affected=0 FailedToProcess=0 MarkedDown=0 MarkedDeferredClose=0 Closed=0) 
 cardinality=1 targetedToTear=0 tornDown=0 markedToClose=0 targetUpEventNewConns=0 upEventNewConns=0
12-Dec-2013 11:33 SUCCESS <Type:SERVICE_UP> <Service:"actest"> <Instance:"rac12c2"> <Db:"rac12c"> 
 Connections:(Available=0 Affected=0 FailedToProcess=0 MarkedDown=0 Closed=0)
 (Borrowed=1 Affected=0 FailedToProcess=0 MarkedDown=0 MarkedDeferredClose=0 Closed=0) 
 cardinality=1 targetedToTear=0 tornDown=0 markedToClose=0 targetUpEventNewConns=9 upEventNewConns=9
12-Dec-2013 11:33 SUCCESS <Reason:failure> <Type:SERVICE_DOWN> <Service:"actest"> <Instance:"null"> <Db:"rac12c"> 
 Connections:(Available=0 Affected=0 FailedToProcess=0 MarkedDown=0 Closed=0)
 (Borrowed=1 Affected=1 FailedToProcess=0 MarkedDown=1 MarkedDeferredClose=0 Closed=1)
12-Dec-2013 11:33 SUCCESS <Reason:failure> <Type:SERVICE_DOWN> <Service:"actest"> <Instance:"rac12c1"> <Db:"rac12c"> 
 Connections:(Available=9 Affected=9 FailedToProcess=0 MarkedDown=9 Closed=9)
 (Borrowed=1 Affected=1 FailedToProcess=0 MarkedDown=1 MarkedDeferredClose=0 Closed=1)
12-Dec-2013 11:33 FAILURE <Type:NOT_PROCESSED> <Service:"rac12c"> <Instance:"rac12c1"> <Db:"rac12c"> 
 Connections:(Available=0 Affected=0 FailedToProcess=0 MarkedDown=0 Closed=0)
 (Borrowed=0 Affected=0 FailedToProcess=0 MarkedDown=0 MarkedDeferredClose=0 Closed=0)

On the database level I observed this:

SQL> select count(inst_id), inst_id, status from gv$session where username = 'MARTIN' group by inst_id, status

COUNT(INST_ID)	  INST_ID STATUS
-------------- ---------- --------
             9          1 INACTIVE
             1          1 ACTIVE

-- then kill the 1st instance

SQL> r
  1* select count(inst_id), inst_id, status from gv$session where username = 'MARTIN' group by inst_id, status

no rows selected

-- and it automatically fixes itself

SQL> r
  1* select count(inst_id), inst_id, status from gv$session where username = 'MARTIN' group by inst_id, status

COUNT(INST_ID)	  INST_ID STATUS
-------------- ---------- --------
             9          2 INACTIVE
             1          2 ACTIVE

In addition the insert made by the PL/SQL procedure has been performed (replayed) by the previously active session.

Lessons learnt

I first tried the “EZConnect” syntax in the URL which didn’t work as I expected. After the failover the only session that was preserved/failed over was that 1 active session. The pool had 19 sessions available but didn’t get back to the initial pool size after the failover. This didn’t happen with the TNS-like connect string you find in the above example.

Unrelated to UCP/AC I had a few connection reset IO Exceptions. It turned out that all SCAN listeners were on my first node (huh?). Restarting them fixed the Connection Reset errors.

And finally, I have been able to get the most fine-grained logging of UCP with the logging.properties file shown below.

Appendix

The logging properties file for Log4J

handlers = java.util.logging.FileHandler
java.util.logging.FileHandler.pattern=/root/ucp_standalone/ucp.log
java.util.logging.FileHandler.formatter = oracle.ucp.util.logging.UCPFormatter
java.util.logging.FileHandler.limit=10000000
java.util.logging.FileHandler.count=4

.level = FINEST

oracle.ucp.AbandonedConnectionTimeoutCallback.level = ALL
oracle.ucp.ConnectionAffinityCallback$AffinityPolicy.level = ALL
oracle.ucp.ConnectionAffinityCallback.level = ALL
oracle.ucp.ConnectionFactoryAdapter.level = ALL
oracle.ucp.ConnectionHarvestingCallback.level = ALL
oracle.ucp.ConnectionLabelingCallback.level = ALL
oracle.ucp.ConnectionRetrievalInfo.level = ALL
oracle.ucp.NoAvailableConnectionsException.level = ALL
oracle.ucp.TimeToLiveConnectionTimeoutCallback.level = ALL
oracle.ucp.UniversalConnectionPool.level = ALL
oracle.ucp.UniversalConnectionPoolAdapter.level = ALL
oracle.ucp.UniversalConnectionPoolException.level = ALL
oracle.ucp.UniversalConnectionPoolLifeCycleState.level = ALL
oracle.ucp.UniversalConnectionPoolStatistics.level = ALL
oracle.ucp.UniversalPooledConnection.level = ALL
oracle.ucp.UniversalPooledConnectionStatus.level = ALL
oracle.ucp.admin.JDBCUniversalConnectionPoolMBeanImpl.level = ALL
oracle.ucp.admin.MetricsUpdateTimerTask.level = ALL
oracle.ucp.admin.UniversalConnectionPoolMBean.level = ALL
oracle.ucp.admin.UniversalConnectionPoolMBeanBase.level = ALL
oracle.ucp.admin.UniversalConnectionPoolManager.level = ALL
oracle.ucp.admin.UniversalConnectionPoolManagerBase$UCPMetric.level = ALL
oracle.ucp.admin.UniversalConnectionPoolManagerBase.level = ALL
oracle.ucp.admin.UniversalConnectionPoolManagerHelper.level = ALL
oracle.ucp.admin.UniversalConnectionPoolManagerImpl.level = ALL
oracle.ucp.admin.UniversalConnectionPoolManagerMBean.level = ALL
oracle.ucp.admin.UniversalConnectionPoolManagerMBeanImpl.level = ALL
oracle.ucp.common.AbandonedConnectionTimerTask.level = ALL
oracle.ucp.common.AvailableConnections.level = ALL
oracle.ucp.common.AvailableConnectionsBase.level = ALL
oracle.ucp.common.AvailableConnectionsManyCollections.level = ALL
oracle.ucp.common.AvailableConnectionsManyCollectionsWithLabels.level = ALL
oracle.ucp.common.AvailableConnectionsOneCollection.level = ALL
oracle.ucp.common.BorrowRequestQueue$WaitTicket.level = ALL
oracle.ucp.common.BorrowRequestQueue.level = ALL
oracle.ucp.common.ConnectionFactoryAdapterBase.level = ALL
oracle.ucp.common.ConnectionHarvestingComparator.level = ALL
oracle.ucp.common.ConnectionHarvestingTimerTask.level = ALL
oracle.ucp.common.ConnectionsContainer.level = ALL
oracle.ucp.common.FailoverEvent.level = ALL
oracle.ucp.common.FailoverEventHandlerTask.level = ALL
oracle.ucp.common.FailoverEventHandlerTaskBase.level = ALL
oracle.ucp.common.Failoverable.level = ALL
oracle.ucp.common.FailoverableUniversalPooledConnection.level = ALL
oracle.ucp.common.FailoverableUniversalPooledConnectionBase.level = ALL
oracle.ucp.common.InactiveConnectionTimerTask.level = ALL
oracle.ucp.common.TimeToLiveConnectionTimerTask.level = ALL
oracle.ucp.common.UniversalConnectionPoolBase.level = ALL
oracle.ucp.common.UniversalConnectionPoolImpl$ConnCreateTask.level = ALL
oracle.ucp.common.UniversalConnectionPoolImpl$UniversalConnectionPoolInternal.level = ALL
oracle.ucp.common.UniversalConnectionPoolImpl.level = ALL
oracle.ucp.common.UniversalConnectionPoolStatisticsImpl.level = ALL
oracle.ucp.common.UniversalPooledConnectionImpl.level = ALL
oracle.ucp.jdbc.ConnectionConnectionPool.level = ALL
oracle.ucp.jdbc.ConnectionInitializationCallback.level = ALL
oracle.ucp.jdbc.ConnectionLabelingCallback.level = ALL
oracle.ucp.jdbc.ConnectionPoolDataSourceConnectionFactoryAdapter.level = ALL
oracle.ucp.jdbc.ConnectionWithAbandonedTimeout.level = ALL
oracle.ucp.jdbc.ConnectionWithTimeToLiveTimeout.level = ALL
oracle.ucp.jdbc.DataSourceConnectionFactoryAdapter.level = ALL
oracle.ucp.jdbc.DriverConnectionFactoryAdapter.level = ALL
oracle.ucp.jdbc.HarvestableConnection.level = ALL
oracle.ucp.jdbc.JDBCConnectionFactoryAdapter.level = ALL
oracle.ucp.jdbc.JDBCConnectionPool.level = ALL
oracle.ucp.jdbc.JDBCConnectionPoolStatistics.level = ALL
oracle.ucp.jdbc.JDBCConnectionPoolStatisticsImpl.level = ALL
oracle.ucp.jdbc.JDBCConnectionRetrievalInfo.level = ALL
oracle.ucp.jdbc.JDBCUniversalPooledConnection.level = ALL
oracle.ucp.jdbc.LabelableConnection.level = ALL
oracle.ucp.jdbc.PoolDataSource.level = ALL
oracle.ucp.jdbc.PoolDataSourceFactory.level = ALL
oracle.ucp.jdbc.PoolDataSourceImpl$AutoProperty.level = ALL
oracle.ucp.jdbc.PoolDataSourceImpl$AutoPropertyX.level = ALL
oracle.ucp.jdbc.PoolDataSourceImpl.level = ALL
oracle.ucp.jdbc.PoolXADataSource.level = ALL
oracle.ucp.jdbc.PoolXADataSourceImpl.level = ALL
oracle.ucp.jdbc.PooledConnectionConnectionPool.level = ALL
oracle.ucp.jdbc.ValidConnection.level = ALL
oracle.ucp.jdbc.XAConnectionConnectionPool.level = ALL
oracle.ucp.jdbc.XADataSourceConnectionFactoryAdapter.level = ALL
oracle.ucp.jdbc.oracle.Ctag.level = ALL
oracle.ucp.jdbc.oracle.DataBasedConnectionAffinityCallback.level = ALL
oracle.ucp.jdbc.oracle.FailoverActionResult.level = ALL
oracle.ucp.jdbc.oracle.FailoverStatisticsAccumulator.level = ALL
oracle.ucp.jdbc.oracle.FailoverStatisticsCounters.level = ALL
oracle.ucp.jdbc.oracle.FailoverStatisticsItem$Type.level = ALL
oracle.ucp.jdbc.oracle.FailoverStatisticsItem.level = ALL
oracle.ucp.jdbc.oracle.FailoverablePooledConnection.level = ALL
oracle.ucp.jdbc.oracle.FailoverablePooledConnectionHelper$InvocationVector.level = ALL
oracle.ucp.jdbc.oracle.FailoverablePooledConnectionHelper.level = ALL
oracle.ucp.jdbc.oracle.ONSDatabaseEventHandlerTask.level = ALL
oracle.ucp.jdbc.oracle.ONSDatabaseFailoverEvent.level = ALL
oracle.ucp.jdbc.oracle.ONSOracleFailoverEventSubscriber.level = ALL
oracle.ucp.jdbc.oracle.ONSOracleRuntimeLBEventSubscriber.level = ALL
oracle.ucp.jdbc.oracle.ONSRuntimeLBEventHandlerTask.level = ALL
oracle.ucp.jdbc.oracle.ONSSubscriberBase$Mocker.level = ALL
oracle.ucp.jdbc.oracle.ONSSubscriberBase.level = ALL
oracle.ucp.jdbc.oracle.OracleConnectionAffinityContext.level = ALL
oracle.ucp.jdbc.oracle.OracleConnectionConnectionPool.level = ALL
oracle.ucp.jdbc.oracle.OracleConnectionPoolDataSourceConnectionFactoryAdapter.level = ALL
oracle.ucp.jdbc.oracle.OracleDataSourceConnectionFactoryAdapter.level = ALL
oracle.ucp.jdbc.oracle.OracleDriverConnectionFactoryAdapter.level = ALL
oracle.ucp.jdbc.oracle.OracleFailoverEvent.level = ALL
oracle.ucp.jdbc.oracle.OracleFailoverEventImpl.level = ALL
oracle.ucp.jdbc.oracle.OracleFailoverEventNotification.level = ALL
oracle.ucp.jdbc.oracle.OracleFailoverEventSubscriber.level = ALL
oracle.ucp.jdbc.oracle.OracleFailoverablePooledConnection.level = ALL
oracle.ucp.jdbc.oracle.OracleGravitateConnectionPoolTask.level = ALL
oracle.ucp.jdbc.oracle.OracleJDBCConnectionPool.level = ALL
oracle.ucp.jdbc.oracle.OracleJDBCConnectionPoolStatistics.level = ALL
oracle.ucp.jdbc.oracle.OracleJDBCConnectionPoolStatisticsImpl.level = ALL
oracle.ucp.jdbc.oracle.OracleJDBCConnectionRetrievalInfo.level = ALL
oracle.ucp.jdbc.oracle.OracleLoadBalancingEvent$InstanceStatus.level = ALL
oracle.ucp.jdbc.oracle.OracleLoadBalancingEvent.level = ALL
oracle.ucp.jdbc.oracle.OraclePooledConnectionConnectionPool.level = ALL
oracle.ucp.jdbc.oracle.OracleReplayableConnectionConnectionPool.level = ALL
oracle.ucp.jdbc.oracle.OracleUniversalPooledConnection$InvocationVector.level = ALL
oracle.ucp.jdbc.oracle.OracleUniversalPooledConnection.level = ALL
oracle.ucp.jdbc.oracle.OracleXAConnectionConnectionPool.level = ALL
oracle.ucp.jdbc.oracle.OracleXADataSourceConnectionFactoryAdapter.level = ALL
oracle.ucp.jdbc.oracle.RACAffinityContext$AffinityType.level = ALL
oracle.ucp.jdbc.oracle.RACAffinityContext.level = ALL
oracle.ucp.jdbc.oracle.RACAvailableConnections.level = ALL
oracle.ucp.jdbc.oracle.RACCallback.level = ALL
oracle.ucp.jdbc.oracle.RACCallbackGuard.level = ALL
oracle.ucp.jdbc.oracle.RACInstance.level = ALL
oracle.ucp.jdbc.oracle.RACInstanceImpl.level = ALL
oracle.ucp.jdbc.oracle.RACManager.level = ALL
oracle.ucp.jdbc.oracle.RACManagerFactory.level = ALL
oracle.ucp.jdbc.oracle.RACManagerImpl$RACCallbackExtended.level = ALL
oracle.ucp.jdbc.oracle.RACManagerImpl.level = ALL
oracle.ucp.jdbc.oracle.ReplayDataSourceConnectionFactoryAdapter.level = ALL
oracle.ucp.jdbc.oracle.ReplayableRACManagerImpl.level = ALL
oracle.ucp.jdbc.oracle.Similarity.level = ALL
oracle.ucp.jdbc.oracle.SimilarityKey.level = ALL
oracle.ucp.jdbc.oracle.SimilarityList.level = ALL
oracle.ucp.jdbc.oracle.SimilarityMap$Pair.level = ALL
oracle.ucp.jdbc.oracle.SimilarityMap.level = ALL
oracle.ucp.jdbc.oracle.SimilaritySet.level = ALL
oracle.ucp.jdbc.oracle.SimpleSimilarity.level = ALL
oracle.ucp.jdbc.oracle.rlb.ConnectionsDispatcher.level = ALL
oracle.ucp.jdbc.oracle.rlb.FailoverInfo.level = ALL
oracle.ucp.jdbc.oracle.rlb.MetricsAccumulator$Frame.level = ALL
oracle.ucp.jdbc.oracle.rlb.MetricsAccumulator$InstanceStats.level = ALL
oracle.ucp.jdbc.oracle.rlb.MetricsAccumulator.level = ALL
oracle.ucp.jdbc.oracle.rlb.ONSRuntimeLoadBalancingEvent.level = ALL
oracle.ucp.jdbc.oracle.rlb.OracleDatabaseInstanceInfo$RebalancingState.level = ALL
oracle.ucp.jdbc.oracle.rlb.OracleDatabaseInstanceInfo.level = ALL
oracle.ucp.jdbc.oracle.rlb.OracleDatabaseInstanceInfoList$INSTANCE_CATEGORY_FOR_DATA_AFFINITY.level = ALL
oracle.ucp.jdbc.oracle.rlb.OracleDatabaseInstanceInfoList$Instances.level = ALL
oracle.ucp.jdbc.oracle.rlb.OracleDatabaseInstanceInfoList.level = ALL
oracle.ucp.jdbc.oracle.rlb.Policy.level = ALL
oracle.ucp.jdbc.oracle.rlb.PolicyBase.level = ALL
oracle.ucp.jdbc.oracle.rlb.PolicyImpl$SpecificStats.level = ALL
oracle.ucp.jdbc.oracle.rlb.PolicyImpl.level = ALL
oracle.ucp.jdbc.oracle.rlb.RLBInfo$Frame.level = ALL
oracle.ucp.jdbc.oracle.rlb.RLBInfo$InstanceStats.level = ALL
oracle.ucp.jdbc.oracle.rlb.RLBInfo.level = ALL
oracle.ucp.jdbc.proxy.CallableStatementProxyFactory.level = ALL
oracle.ucp.jdbc.proxy.ConnectionProxyFactory.level = ALL
oracle.ucp.jdbc.proxy.JDBCConnectionProxyFactory$SwitchTable.level = ALL
oracle.ucp.jdbc.proxy.JDBCConnectionProxyFactory.level = ALL
oracle.ucp.jdbc.proxy.PreparedStatementProxyFactory.level = ALL
oracle.ucp.jdbc.proxy.ResultSetProxyFactory.level = ALL
oracle.ucp.jdbc.proxy.StatementProxyFactory$SwitchTable.level = ALL
oracle.ucp.jdbc.proxy.StatementProxyFactory.level = ALL
oracle.ucp.jdbc.proxy.XAConnectionProxyFactory.level = ALL
oracle.ucp.util.Collections.level = ALL
oracle.ucp.util.ProlongedTask.level = ALL
oracle.ucp.util.RingBuffer.level = ALL
oracle.ucp.util.Task.level = ALL
oracle.ucp.util.TaskHandle.level = ALL
oracle.ucp.util.TaskManager.level = ALL
oracle.ucp.util.TaskManagerException.level = ALL
oracle.ucp.util.TimerHandle.level = ALL
oracle.ucp.util.TimerManager.level = ALL
oracle.ucp.util.TimerTask.level = ALL
oracle.ucp.util.UCPErrorHandler.level = ALL
oracle.ucp.util.UCPManifestReader.level = ALL
oracle.ucp.util.UCPTaskBase.level = ALL
oracle.ucp.util.UCPTaskManagerImpl.level = ALL
oracle.ucp.util.UCPTimerManagerImpl.level = ALL
oracle.ucp.util.UCPTimerTaskImpl.level = ALL
oracle.ucp.util.UniqueIdentifier.level = ALL

Be aware of these environment variables in .bashrc et al.

This is a quick post about one of my pet peeves-statically setting environment variables in .bashrc or other shell’s equivalents. I have been bitten by this a number of times. Sometimes it’s my own code, as in this story.

Background

Many installation instructions about Oracle version x tell you to add variables to your shell session when you log in. What’s meant well for convenience can backfire. Sure it’s nice to have ORACLE_HOME, ORACLE_SID, LD_LIBRARY_PATH, CLASSPATH etc set automatically without having to find out about them the hard way. However, there are situations where this doesn’t help.

A few years back I migrated Clusterware from 10.2.0.4 to 11.2.0.1. It went pretty well for DEV, INT, UAT, DR. But not for PROD (d’oh!). Why didn’t it? It took a little while to figure out but Oracle assumes that variables such as ORA_CRS_HOME are NOT set when in my case it was. The full story is told on MOS: NETCA & ASMCA Fail during Upgrade of CRS/ASM to Grid Infrastructure 11gR2 (Doc ID 952925.1). Thankfully it was recoverable.

My case

I have a script on my lab servers which allows me to set the environment for a particular database, including ORA_NLS10, NLS_DATE_FORMAT, and the usual suspects such as ORACLE_HOME, ORACLE_SID etc. The bug I identified this morning was that for one of the databases I had a copy and paste error. So instead of pointing to the 11.2.0.3 home where I wanted to create another database the ORA_NLS10 parameter pointed to the database I previously worked on, an 11.2.0.1 home. I didn’t know that though when I performed the following steps:

DBCA crashes

I normally execute dbca in silent mode in a screen session for database creation. In this case, it silently aborted, no error output that I could make out. Checking $ORACLE_BASE/cfgtoollogs/ I noticed the trace file with the following contents:

Could not connect to ASM due to following error:
 ORA-03113: end-of-file on communication channel

Well-that’s no good. There wasn’t a database alert.log available to check, but there were entries in the ASM alert.log for the core dump:

xception [type: SIGSEGV, Address not mapped to object] [ADDR:0x57598BCB] [PC:0xA635B06, lxcsu22m()+22]
 [flags: 0x0, count: 1]
Errors in file /u01/app/oracle/diag/asm/+asm/+ASM1/trace/+ASM1_ora_3742.trc  (incident=281963):
ORA-07445: exception encountered: core dump [lxcsu22m()+22] [SIGSEGV] [ADDR:0x57598BCB]
 [PC:0xA635B06] [Address not mapped to object] []
Incident details in: /u01/app/oracle/diag/asm/+asm/+ASM1/incident/incdir_281963/+ASM1_ora_3742_i281963.trc
Use ADRCI or Support Workbench to package the incident.
See Note 411.1 at My Oracle Support for error and packaging details.

Checking the file it referenced didn’t give me much of a clue, and the callstack in the incident didn’t tell me much either. A quick search on MOS revealed that core dumps with lxcsu22m in the stack hint at invalid NLS settings. I didn’t recall having set NLS parameters in my session when it dawned on me… Using env | grep -i nls revealed that the ORA_NLS10 path was pointing to the 11.2.0.1 home I previously worked on. Unsetting these caused DBCA to complete without error.

Lesson learned

I have added a function to my environment script called cleanEnv() which explicitly unsets all environment variables before setting new ones. It is also called first thing when logging in to avoid this kind of situation. I also assume that ORACLE_HOME is correct and check other paths against it and raise an error if there are mismatches.

Upgrading to Oracle Linux 6.5

This is a very short post to demonstrate how to upgrade to Oracle Linux 6.5. My lab system was reasonably current, Oracle Linux 6.4 with some security patches (but not all). The upgrade to 6.5 (or “latest”) is very simple, and since Oracle announced they had beefed up connectivity it’s a real joy. Instead of 450kb/s I get around 9 MB/s. For those of you who want the ISO image: you can’t currently get it from edelivery, the only update method is YUM/ULN or you download the ISO from My Oracle Support, patch 17860279.

The update itself is rather straight forward. I downloaded the latest repository information from public-yum.oracle.com into /etc/yum.repos.d/ on the lab server and ran a simple “yum upgrade”. Since the “latest” repository is enabled that did the trick for me. After a little while the packages had been updated. To my surprise I didn’t see UEK 3 installed-the installed kernels are all 2.6.32.x and 2.6.39.x. A quick look into the repository file revealed that the UEK Release 3 kernel has its own repository:

[public_ol6_UEKR3_latest]
name=Latest Unbreakable Enterprise Kernel for Oracle Linux $releasever ($basearch)
baseurl=http://public-yum.oracle.com/repo/OracleLinux/OL6/UEKR3/latest/$basearch/
gpgkey=file:///etc/pki/rpm-gpg/RPM-GPG-KEY-oracle
gpgcheck=1
enabled=0

The repository needed to be enabled which I did by switching the flag to 1. You could alternatively use yum install –enablerepo public_ol6_UEKR3_latest on the command line to achieve the same goal.

[root@server1 yum.repos.d]# yum install kernel-uek
Setting up Install Process
Resolving Dependencies
--> Running transaction check
---> Package kernel-uek.x86_64 0:3.8.13-16.2.2.el6uek will be installed
--> Processing Dependency: kernel-firmware = 3.8.13-16.2.2.el6uek for package: kernel-uek-3.8.13-16.2.2.el6uek.x86_64
--> Running transaction check
---> Package kernel-uek-firmware.noarch 0:3.8.13-16.2.2.el6uek will be installed
--> Finished Dependency Resolution
--> Running transaction check
---> Package kernel-uek.x86_64 0:2.6.39-400.109.1.el6uek will be erased
---> Package kernel-uek-firmware.noarch 0:2.6.39-400.109.1.el6uek will be erased
--> Finished Dependency Resolution

Dependencies Resolved

==================================================================================================
 Package                 Arch       Version                     Repository                   Size
==================================================================================================
Installing:
 kernel-uek              x86_64     3.8.13-16.2.2.el6uek        public_ol6_UEKR3_latest      41 M
Removing:
 kernel-uek              x86_64     2.6.39-400.109.1.el6uek     @ol6_UEK_latest             102 M
 kernel-uek-firmware     noarch     2.6.39-400.109.1.el6uek     @ol6_UEK_latest             5.0 M
Installing for dependencies:
 kernel-uek-firmware     noarch     3.8.13-16.2.2.el6uek        public_ol6_UEKR3_latest     1.6 M

Transaction Summary
==================================================================================================
Install       2 Package(s)
Remove        2 Package(s)

Total download size: 43 M
Is this ok [y/N]: y
Downloading Packages:
(1/2): kernel-uek-3.8.13-16.2.2.el6uek.x86_64.rpm                          |  41 MB     00:04
(2/2): kernel-uek-firmware-3.8.13-16.2.2.el6uek.noarch.rpm                 | 1.6 MB     00:00
--------------------------------------------------------------------------------------------------
Total                                                             9.0 MB/s |  43 MB     00:04
Running rpm_check_debug
Running Transaction Test
Transaction Test Succeeded
Running Transaction
  Installing : kernel-uek-firmware-3.8.13-16.2.2.el6uek.noarch                                1/4
  Installing : kernel-uek-3.8.13-16.2.2.el6uek.x86_64                                         2/4
  Cleanup    : kernel-uek-2.6.39-400.109.1.el6uek.x86_64                                      3/4
  Cleanup    : kernel-uek-firmware-2.6.39-400.109.1.el6uek.noarch                             4/4
  Verifying  : kernel-uek-3.8.13-16.2.2.el6uek.x86_64                                         1/4
  Verifying  : kernel-uek-firmware-3.8.13-16.2.2.el6uek.noarch                                2/4
  Verifying  : kernel-uek-firmware-2.6.39-400.109.1.el6uek.noarch                             3/4
  Verifying  : kernel-uek-2.6.39-400.109.1.el6uek.x86_64                                      4/4

Removed:
  kernel-uek.x86_64 0:2.6.39-400.109.1.el6uek
  kernel-uek-firmware.noarch 0:2.6.39-400.109.1.el6uek

Installed:
  kernel-uek.x86_64 0:3.8.13-16.2.2.el6uek

Dependency Installed:
  kernel-uek-firmware.noarch 0:3.8.13-16.2.2.el6uek

Complete!

What’s not shown here is that it removed my kernel modules for Virtual Box, but that’s not a problem as I’m not using it anymore. You may have to review /etc/grub.conf to ensure you boot off the new kernel by default (edit default=x, the first entry in the file is referred to as default=0). The installation kept a few of my older kernels on the system too:

[root@server1 ~]# rpm -qa | egrep "kernel(-uek)?-[23]" | sort
kernel-2.6.32-358.11.1.el6.x86_64
kernel-2.6.32-358.2.1.el6.x86_64
kernel-3.11.7-3.11.y.20131105.ol6.x86_64
kernel-uek-2.6.39-400.210.2.el6uek.x86_64
kernel-uek-2.6.39-400.211.2.el6uek.x86_64
kernel-uek-3.8.13-16.2.2.el6uek.x86_64

So why was I keen to upgrade? Here’s why, taken from the release notes:

  • UEK3 is based on 3.8.13, and I expect changes for some of my favourite tools perf and kvm.
  • Control Groups (cgroups) are a supported feature
  • Virtual Function IO potentially helps reducing latency when accessing storage from virtual machines as it is implemented in userland
  • Lots of NUMA enhancements
  • DTRACE!
  • Support for virtio-scsi as it seems, a modprobe was successful.
  • perf report –gtk and others (see Appendix 10 for more detail)
  • Transparent Huge Pages have been removed (they were no good for me anyway)
  • And numerous others more in Appendix A

Now time for some testing!