Category: Wildfly

Installation of Wildfly 8.2

Download Wildfly 8.2 from http://wildfly.org/downloads/

$ cd /home/oracle/WILDFLY
$ unzip  /media/sf_kits/JEE/wildfly-8.2.0.Final.zip

In case you have multiple Wildfly instances runing  you can easily rename top level directory 
$ mv wildfly-8.2.0.Final wildfly-8.2.0.Final_PRODUCITON

Some useful SHELL variables 
export WILDFLY_HOME=/home/oracle/WILDFLY/wildfly-8.2.0.Final_PRODUCITON
alias wf=$WILDFLY_HOME/bin/standalone.sh
alias wfd='cd $WILDFLY_HOME'

Start and stop  Wildfly 
Start WildFly in standalone mode;
[oracle@wls1 local]$ $WILDFLY_HOME/bin/standalone.sh 
=========================================================================

  JBoss Bootstrap Environment
  JBOSS_HOME: /usr/local/wildfly-8.2.0.Final
  JAVA: /usr/java/jdk1.7.0_71/bin/java
  JAVA_OPTS:  -server -Xms64m -Xmx512m -XX:MaxPermSize=256m -Djava.net.preferIPv4Stack=true -Djboss.modules.system.pkgs=org.jboss.byteman -Djava.awt.headless=true
...

Now test that we can display the first WEB Page using the default WILDFLY HTTP PORT number:
$ firefox localhost:8080

Stop the Server 
[oracle@wls1 ~]$ $WILDFLY_HOME/bin/jboss-cli.sh --connect command=:shutdown
{"outcome" => "success"} 

Add an Admin User

$ add-user.sh
What type of user do you wish to add? 
 a) Management User (mgmt-users.properties) 
 b) Application User (application-users.properties)
(a): 
Enter the details of the new user to add.
Using realm 'ManagementRealm' as discovered from the existing property files.
Username : oracle
....

Changing Ports [in case you need to run as 2.nd WILDFLY instance on your System ]

Edit  $WILDFLY_HOME/standalone/configuration/standalone.xml
Change
   <socket-binding-group name="standard-sockets" default-interface="public" port-offset="${jboss.socket.binding.port-offset:0}">
        <socket-binding name="management-http" interface="management" port="${jboss.management.http.port:9990}"/>
        <socket-binding name="management-https" interface="management" port="${jboss.management.https.port:9993}"/>
        <socket-binding name="ajp" port="${jboss.ajp.port:8009}"/>
        <socket-binding name="http" port="${jboss.http.port:8080}"/>
        <socket-binding name="https" port="${jboss.https.port:8443}"/>
        <socket-binding name="txn-recovery-environment" port="4712"/>
        <socket-binding name="txn-status-manager" port="4713"/>
        <outbound-socket-binding name="mail-smtp">
            <remote-destination host="localhost" port="25"/>
        </outbound-socket-binding>
</socket-binding-group>
to 
    <socket-binding-group name="standard-sockets" default-interface="public" port-offset="${jboss.socket.binding.port-offset:0}">
        <socket-binding name="management-http" interface="management" port="${jboss.management.http.port:9980}"/>
        <socket-binding name="management-https" interface="management" port="${jboss.management.https.port:9983}"/>
        <socket-binding name="ajp" port="${jboss.ajp.port:8010}"/>
        <socket-binding name="http" port="${jboss.http.port:8081}"/>
        <socket-binding name="https" port="${jboss.https.port:8444}"/>
        <socket-binding name="txn-recovery-environment" port="4702"/>
        <socket-binding name="txn-status-manager" port="4703"/>
        <outbound-socket-binding name="mail-smtp">
            <remote-destination host="localhost" port="26"/>
        </outbound-socket-binding>
    </socket-binding-group>

Restart your server and verify the new Ports:  
$ $WILDFLY_HOME/bin/jboss-cli.sh  --connect --controller=localhost:9980 command=:shutdown
{"outcome" => "success"}
$ $WILDFLY_HOME/bin/standalone.sh 

$ firefox localhost:8081  --> Should display the Wildfly default page
$ firefox localhost:9980  --> You should be able to successfully login to the Management Console 

Use jboss.cli to connect to new Management Controller 
$ $WILDFLY_HOME/bin/jboss-cli.sh  --connect --controller=localhost:9980 

Server.log should report the changed PORT numbers:
10:58:40,755 INFO  [org.wildfly.extension.undertow] (MSC service thread 1-3) JBAS017519: Undertow HTTP listener default listening on /127.0.0.1:8081
..
10:58:41,737 INFO  [org.jboss.as] (Controller Boot Thread) JBAS015961: Http management interface listening on http://127.0.0.1:9980/management
10:58:41,738 INFO  [org.jboss.as] (Controller Boot Thread) JBAS015951: Admin console listening on http://127.0.0.1:9980

Setup Oracle JDBC driver and a RAC datasource

Step 1: Add Oracle JDBC driver as a module 
[oracle@wls1 WILDFLY]$ cat add_module.cli 
module add --name=com.oracle.ojdbc --resources=/home/oracle/JDBC/Driver/ojdbc7.jar --dependencies=javax.api,javax.transaction.api

$ $WILDFLY_HOME/bin/jboss-cli.sh  --connect --controller=localhost:9980  --file=add_module.cli 

Verify that the proper module.xml was created 
$ ls modules/com/oracle/ojdbc/main/
module.xml  ojdbc7.jar
$ cat  modules/com/oracle/ojdbc/main/module.xml 
<?xml version="1.0" ?>
<module xmlns="urn:jboss:module:1.1" name="com.oracle.ojdbc">
    <resources>
        <resource-root path="ojdbc7.jar"/>
    </resources>
    <dependencies>
        <module name="javax.api"/>
        <module name="javax.transaction.api"/>
    </dependencies>
<module>

Step 2: Deploy the JDBC driver
$ cat add_jdbc_driver.cli
/subsystem=datasources/jdbc-driver=oracle/:add(driver-name=oracle, driver-module-name=com.oracle.ojdbc, driver-xa-datasource-class-name=oracle.jdbc.xa.client.OracleXADataSource) 
$  $WILDFLY_HOME/bin/jboss-cli.sh  --connect --controller=localhost:9980  --file=add_jdbc_driver.cli
{"outcome" => "success"} 

Verify Driver 
[oracle@wls1 WILDFLY]$   $WILDFLY_HOME/bin/jboss-cli.sh  --connect --controller=localhost:9980   /subsystem=datasources:installed-drivers-list
 {
    "outcome" => "success",
    "result" => [
        {
            "driver-name" => "oracle",
            "deployment-name" => undefined,
            "driver-module-name" => "com.oracle.ojdbc",
            "module-slot" => "main",
            "driver-datasource-class-name" => "",
            "driver-xa-datasource-class-name" => "oracle.jdbc.xa.client.OracleXADataSource",
            "driver-class-name" => "oracle.jdbc.OracleDriver",
            "driver-major-version" => 12,
            "driver-minor-version" => 1,
            "jdbc-compliant" => true
        },
..
Verify Server.log :
11:29:33,533 INFO  [org.jboss.as.connector.subsystems.datasources] (management-handler-thread - 4) JBAS010403: Deploying JDBC-compliant driver class oracle.jdbc.OracleDriver (version 12.1)
11:29:33,534 INFO  [org.jboss.as.connector.deployers.jdbc] (MSC service thread 1-6) JBAS010417: Started Driver service with driver-name = oracle

Step 3 : Add and verify a DataSource 
$ cat add_ds.cli
if (outcome != success) of /subsystem=datasources/data-source=myRacDS:read-resource
    data-source add \
        --name=myRacDS \
        --driver-name=oracle \
        --jndi-name=java:jboss/datasources/myRacDS \
        --user-name="scott"\
        --password="tiger"\
        --use-java-context=true \
        --use-ccm=true \
        --min-pool-size=5 \
        --max-pool-size=10 \
        --pool-prefill=true \
        --allocation-retry=1 \
        --prepared-statements-cache-size=32 \
        --share-prepared-statements=true \
        --connection-url="jdbc:oracle:thin:@ract2-scan.grid12c.example.com:1521/banka"
end-if

$ $WILDFLY_HOME/bin/jboss-cli.sh  --connect --controller=localhost:9980  --file=add_ds.cli
$ $WILDFLY_HOME/bin/jboss-cli.sh  --connect --controller=localhost:9980 /subsystem=datasources/data-source=myRacDS:read-resource
{
    "outcome" => "success",
    "result" => {
        "allocation-retry" => 1,
        ...
        "connection-url" => "jdbc:oracle:thin:@ract2-scan.grid12c.example.com:1521/banka",
        "datasource-class" => undefined,
        "driver-class" => undefined,
        "driver-name" => "oracle",
        "enabled" => true,
        ..
        "jndi-name" => "java:jboss/datasources/myRacDS",
        "jta" => true,
        "max-pool-size" => 10,
        "min-pool-size" => 5,
        ...
        }
    }
}

Test the Connection 
-> Ping the SCAN address
[oracle@wls1 WILDFLY]$  ping ract2-scan.grid12c.example.com
PING ract2-scan.grid12c.example.com (192.168.5.221) 56(84) bytes of data.
64 bytes from 192.168.5.221: icmp_seq=1 ttl=64 time=0.534 ms
64 bytes from 192.168.5.221: icmp_seq=2 ttl=64 time=0.298 ms

Test test Connection
$WILDFLY_HOME/bin/jboss-cli.sh  --connect --controller=localhost:9980  /subsystem=datasources/data-source=myRacDS:test-connection-in-pool
{
    "outcome" => "success",
    "result" => [true]
}

Display and change JTA Transaction Timeout

Display JTA Transaction Timeout 
$  $WILDFLY_HOME/bin/jboss-cli.sh  --connect --controller=localhost:9990
      '/subsystem=transactions/:read-attribute(name=default-timeout)'
{
    "outcome" => "success",
    "result" => 30
}
--> JTA Transaction Timeout : 30 seconds

Change JTA Transaction Timeout 
$ $WILDFLY_HOME/bin/jboss-cli.sh  --connect --controller=localhost:9990 
    '/subsystem=transactions/:write-attribute(name=default-timeout,value=60)'
{
    "outcome" => "success",
    "response-headers" => {
        "operation-requires-reload" => true,
        "process-state" => "reload-required"
    }
}

Deploy a compiled Web application project

Assume we have already created and tested WFJPA2EL-1.0.war and want to deploy this to our new Wildfly server :
$ cp WFJPA2EL-1.0.war /home/oracle/WILDFLY/wildfly-8.2.0.Final_PRODUCITON/standalone/deployments 
$ touch /home/oracle/WILDFLY/wildfly-8.2.0.Final_PRODUCITON/standalone/deployments/WFJPA2EL-1.0.war.dodeploy

For Redeployment run:
$  touch /home/oracle/WILDFLY/wildfly-8.2.0.Final_PRODUCITON/standalone/deployments/WFJPA2EL-1.0.war.dodeploy
Server.log should report: 
15:32:08,432 INFO  [org.wildfly.extension.undertow] (MSC service thread 1-4) JBAS017534: Registered web context: /WFJPA2EL-1.0
15:32:08,465 INFO  [org.jboss.as.server] (DeploymentScanner-threads - 1) JBAS018565: Replaced deployment "WFJPA2EL-1.0.war" with deployment "WFJPA2EL-1.0.war"

Now test the project 
$ firefox http://localhost:8081/WFJPA2EL-1.0

15:30:46.253 Calling  getRacInfo() in progress ... 
15:30:46.254 EclipseLink Version: 2.5.2 - [ EclipseLink 2.5.2 == JPA 2.1] 
15:30:46.255 Driver Name             : Oracle JDBC driver
15:30:46.256 Driver Version          : 12.1.0.2.0
15:30:46.257 Database Product Version: Oracle Database 12c Enterprise Edition Release 12.1.0.2.0 - 64bit Production
With the Partitioning, Real Application Clusters, Automatic Storage Management, OLAP,
Advanced Analytics and Real Application Testing options
15:30:46.439 DB Name:  BANKA
15:30:46.440 1. Instance Name: bankA_3 - Host: hract21.example.com
15:30:46.440 Leaving getRacInfo() without Exceptions !

Remove a single prepared transaction from WildFly LOG Store

• Please read the following article

Cleanup Wildfly LOG STORE

• Be careful don’t run thes commands on a production system as you can easily corrupt your system
• These commands should only used on your test system

Check for prepared transactions 

$ cat prepared_xa.cli
/subsystem=transactions/log-store=log-store/:probe()
ls /subsystem=transactions/log-store=log-store/transactions

$  $WILDFLY_HOME/bin/jboss-cli.sh --connect --file=prepared_xa.cli
{"outcome" => "success"}
0:ffffc0a805c9:-18c2b06f:55fac789:137
0:ffffc0a805c9:-18c2b06f:55fac789:145
0:ffffc0a805c9:-18c2b06f:55fac789:153
0:ffffc0a805c9:-18c2b06f:55fac789:fa
0:ffffc0a805c9:35abdaa8:55fbbb60:11b
0:ffffc0a805c9:35abdaa8:55fbbb60:355
0:ffffc0a805c9:35abdaa8:55fbbb60:49
0:ffffc0a805c9:35abdaa8:55fbbb60:5b
0:ffffc0a805c9:35abdaa8:55fbbb60:f1

Verify TX Object Store at File System Level
$ ls -1 ./standalone/data/tx-object-store/ShadowNoFileLockStore/defaultStore/StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction/
0_ffffc0a805c9_-18c2b06f_55fac789_137
0_ffffc0a805c9_-18c2b06f_55fac789_145
0_ffffc0a805c9_-18c2b06f_55fac789_153
0_ffffc0a805c9_-18c2b06f_55fac789_fa
0_ffffc0a805c9_35abdaa8_55fbbb60_11b
0_ffffc0a805c9_35abdaa8_55fbbb60_355
0_ffffc0a805c9_35abdaa8_55fbbb60_49
0_ffffc0a805c9_35abdaa8_55fbbb60_5b
0_ffffc0a805c9_35abdaa8_55fbbb60_f1

Shutdown Wildfly and delete all prepared Transactions 
$WILDFLY_HOME/bin/jboss-cli.sh  --connect --controller=localhost:9990 command=:shutdown
$ rm ./standalone/data/tx-object-store/ShadowNoFileLockStore/defaultStore/StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction/*

Restart Wildfly and verify LOG STORE
$   $WILDFLY_HOME/bin/jboss-cli.sh --connect --file=prepared_xa.cli
{"outcome" => "success"}

Reference

• How to integrate the Oracle JDBC driver as a Wildfly module ?
• Using Eclipselink as a Persistence Provider in a Netbeans/Wildfly project for JTA transaction  

Overview and Key Facts

• JTA uses  javax.transaction.UserTransaction API to manage transaction bounderies
• Each UserTransaction is associated with a Thread and this thread can only  handle 1 active Transaction in parallel
• If a UserTransaction times out the Transaction will be rolled back and Transaction status will be set to :  STATUS_ROLLING_BACK
• To manage Transaction Timout use following API:  ut.setTransactionTimeout(txTimeout)
• In this sample 2 Wildfly we have configured RAC XA datasources : 
  • RAC bankA maintained and running in London
    
  • RAC bankB maintained and running in Frankfurt
    
• A typical XA transaction consists out of at least 3 different processing steps
  • Step 1:  Data processing : xa_start  DML operation xa_end
  • Step 2:  Prepare the transaction:  xa_prepare
  • Step 3:  Commit the transaction: xa_commit
  • Step 2 and 3 are called 2-Phase-Commit or short 2PC
  • If clusterwide XA transaction are enabled any RAC instance can run any of the above steps
• 2PC Commit Protocol details:
  • Prepare phase: The TM asks participating RMs to promise to commit (or rollback) the transaction as requested, even if there is a failure. If any RM cannot prepare, the transaction is rolled back.
  •  Commit phase:  If all RMs respond to the TM that they are prepared, then the TM asks all RMs commit the transaction.
• ut.begin() starts the XA transaction whereas ut.commit() ends, prepares and commits the XA transaction
• DBA_PENDING_TRANSACTIONS describes unresolved transactions (either due to failure or if the coordinator has not sent a commit/rollback).
• DBA_2PC_PENDING  describes in-doubt transactions ( after tx timeout the RAC database records these XA transactions missing a commit/rollback)
• A global XA transaction can span Oracle RAC instances by default ( if not using DTP services ) –
• The GLOBAL_TXN_PROCESSES initialization parameter, which is set to 1 by default, specifies the initial number of GTX n background processes for each Oracle RAC instance.
• If GLOBAL_TXN_PROCESSES > 1 clusterwide XA transactions are enabled.
  

Configuration and Setup

• Test Framework – click on the image below to find out details !

JDK Version:     1.7.0_71
JDBC-Driver:     Oracle JDBC driver - Version: 12.1.0.2.0


DB Name:     BANKA
Running Instances:     
10:06:16.646 Instance Name: bankA_1 - Host: hract22.example.com
10:06:16.647 Instance Name: bankA_3 - Host: hract21.example.com
DB Name:     BANKB
Running Instances:     
10:06:17.029 Instance Name: bankb_3 - Host: hract22.example.com
10:06:17.029 Instance Name: bankb_1 - Host: hract21.example.com

In this tutorial we will test and evaluate a 2-Phase-Commit scenario between: 
  RAC database bankA and RAC database bankB

RAC db version: 12.1.0.2 / Wildfyl 8.0.2 

To run this code you need to create 2 Oracle XA datasources named 
   java:jboss/datasources/xa_rac12g_banka
   java:jboss/datasources/xa_rac12g_bankb

For details creating a XA datasource with Oracle RAC please read following article:
  Setup a XA Datasource by using the RAC SCAN address

Java Code to run the 2-Phase-Commit operation

  
  @Named("xaTestBean")
  @SessionScoped
  public class XaTestBean implements Serializable
    {   
    @Resource(lookup="java:jboss/datasources/xa_rac12g_banka")
    private DataSource ds1;
   
    @Resource(lookup="java:jboss/datasources/xa_rac12g_bankb")
    private DataSource ds2;
 
    @Resource 
    private UserTransaction ut;
    ..   

   public String transferMoney()
      {
        initTopLevel();
        setTxInfo(Tools.add_hmtl_pre_tag("Calling transferMoney() in progress - try getting XA connections !" )) ;
        try 
          {          
            try ( Connection c1 = ds1.getConnection();
                  Connection c2 = ds2.getConnection(); )              
              {                 
               
                setSess1(Tools.add_hmtl_pre_tag(c1.getMetaData().getURL()));
                setSess2(Tools.add_hmtl_pre_tag(c2.getMetaData().getURL()));               
                setSess1(getSess1() + Tools.add_hmtl_pre_tag(getSessionInfo(c1)));
                System.out.println(getSess1()); System.out.flush();
                setSess2(getSess2() + Tools.add_hmtl_pre_tag( getSessionInfo(c2)));
                System.out.println(getSess2() ); System.out.flush();
                          
                setTxInfo(Tools.add_hmtl_pre_tag("No TX active - before ut.begin() "  + returnUtStatus(ut) + " - Transaction Timeout: " + txTimeout )) ;              
                ut.setTransactionTimeout(txTimeout) ;
                setTxInfo(getTxInfo() + Tools.add_hmtl_pre_tag("Setting New Tansaction Timeout : " + txTimeout)); 
                ut.begin();              
                setTxInfo(getTxInfo() + Tools.add_hmtl_pre_tag("After  ut.begin() "  + returnUtStatus(ut) )) ;
                doUpdate(c1, " - Session 1", "update Accounts set balance = balance - 4000");
                doUpdate(c2, " - Session 2", "update Accounts set balance = balance + 4000");
                setTxInfo(getTxInfo() + Tools.add_hmtl_pre_tag("Tx status before ut.commit() - "  + returnUtStatus(ut) + " - Now sleeping : " 
                        + sleepTime + " [ seconds] " )) ;      
                Thread.sleep(1000*sleepTime); 
                ut.commit();
                setTxInfo(getTxInfo() + Tools.add_hmtl_pre_tag("Tx status after ut.commit() "  + returnUtStatus(ut) )) ;                         
                    // Update Status in index.html too 
                setBankOperation(getBankOperation() + Tools.add_hmtl_pre_tag(getAccountinfo(c1)));
                setBankOperation(getBankOperation() + Tools.add_hmtl_pre_tag(getAccountinfo(c2)));
                setBankOperation(getBankOperation() +  Tools.add_hmtl_pre_tag("Leaving transferMoney() without any errors"));
                c1.close();              
                c2.close();
                setTxInfo(getTxInfo() + Tools.add_hmtl_pre_tag("Leaving transferMoney() without any errors")); 
              }
           
          } catch ( Exception ex ) 
          {   
            String e = ex.getMessage();
            genericExp("Error in JSF top level function: transferMoney() - Need to ROLLBACK transaction", ex);
            setBankOperation(getBankOperation()  + Tools.add_hmtl_pre_tag("FATAL ERROR in transferMoney(): " + e )); 
            try 
              {
                 setTxInfo(getTxInfo() + Tools.add_hmtl_pre_tag("FATAL ERROR: "));
                 setTxInfo(getTxInfo() + Tools.add_hmtl_pre_tag(  "Tx status after Exception before ut.rollback(): "  + 
                         returnUtStatus(ut)  + " - Exception: "+ e));              
                ut.rollback();
                setTxInfo(getTxInfo() + Tools.add_hmtl_pre_tag("Tx status after Exception - but  sucessful ut.rollback(): "   + returnUtStatus(ut)  ));               
              } catch( Exception e2 )
                    {
                       setTxInfo(getTxInfo() +Tools.add_hmtl_pre_tag( "Tx status after Exception: FATAL error during ut.rollback() :"  + 
                                returnUtStatus(ut)  + " - Exception: "  +e2));                   
                    }                    
            return "bankInfo";
          }  
        return "bankInfo";
      }

Testing SQL Exceptions in function transferMoney():

Prepared Test case:
Press : 
Press Transfer Money 3x :  

Output from index.xhtml:
09:59:54.830 Calling  checkAccounts() in progress ... 
09:59:54.835 Database Name:BANKA -- Account: User99_at_BANKA -- Balance: 10000.0
09:59:54.839 Database Name:BANKB -- Account: User98_at_BANKB -- Balance: 10000.0
09:59:54.839 Leaving checkAccounts() without any Error 

10:00:12.397 Database Name:BANKA -- Account: User99_at_BANKA -- Balance: 6000.0
10:00:12.405 Database Name:BANKB -- Account: User98_at_BANKB -- Balance: 14000.0
10:00:12.405 Leaving transferMoney() without any errors

10:00:18.232 Database Name:BANKA -- Account: User99_at_BANKA -- Balance: 2000.0
10:00:18.248 Database Name:BANKB -- Account: User98_at_BANKB -- Balance: 18000.0
10:00:18.249 Leaving transferMoney() without any errors

10:00:21.376 FATAL ERROR in transferMoney(): ORA-02290: check constraint (SCOTT.S_LOWER_CHK) violated


Last SQL:     
10:00:21.373 update Accounts set balance = balance - 4000  - Session 1

Last SQL Error:     
10:00:21.373 Exception in Class: com.hhu.XaTestBean - Methode: doUpdate
java.sql.SQLIntegrityConstraintViolationException: ORA-02290: check constraint (SCOTT.S_LOWER_CHK) violated
  Url: jdbc:oracle:thin:@ract2-scan.grid12c.example.com:1521/banka User: SCOTT
   Stmt: update Accounts set balance = balance - 4000   - Session 1

TX Info:     

10:00:21.267 No TX active - before ut.begin() TX status:  6 - STATUS_NO_TRANSACTION - Transaction Timeout: 5
10:00:21.267 Setting New Tansaction Timeout : 5
10:00:21.273 After  ut.begin() TX status:  0 - STATUS_ACTIVE
10:00:21.377 FATAL ERROR: 
10:00:21.377 Tx status after Exception before ut.rollback(): TX status:  0 - STATUS_ACTIVE 
             - Exception: ORA-02290: check constraint (SCOTT.S_LOWER_CHK) violated
10:00:21.383 Tx status after Exception - but  sucessful ut.rollback(): TX status:  6 - STATUS_NO_TRANSACTION

Code Explanation

• After calling transferMoney() a 3rd time the database  check contraint gets fired as our balance moves to a negative value
• Inside the exeception handler the XA transaction was successfully rolled back and our thread ends up with setting its XA status to  : STATUS_NO_TRANSACTION

Testing automatic transaction recovery after a COMMIT record was written to Wildlfly LOG-STORE

• Both XA resources have voted to COMMIT the transaction
• Wildfly has written a COMMIT record to the  Wildlfly LOG-STORE
• After this all transaction branches needs to be committed [ either by application server or by the DB admin ]
• After a system crash Periodic Recovery Thread should use
  XA recover and XA commit to commit this transaction without any user intervention

Setup Testcase :

Press Init Accounts :
11:04:21.039 Calling  checkAccounts() in progress ... 
11:04:21.088 Database Name:BANKA -- Account: User99_at_BANKA -- Balance: 10000.0
11:04:21.128 Database Name:BANKB -- Account: User98_at_BANKB -- Balance: 10000.0
11:04:21.128 Leaving checkAccounts() without any Error 

Breakpoints : Class oracle.jdbc.xa.OracleXAResource : Methode entry for prepare()  and commit()

Start application by pressing                : 

Use debugger and stop processing at Entry to first OracleXAResource.commit call [ Press F5 until you reach this code point ]
Method breakpoint hit in oracle.jdbc.xa.client.OracleXAResource.prepare at line 693 by thread default task-6.
Method breakpoint hit in oracle.jdbc.xa.client.OracleXAResource.prepare at line 693 by thread default task-6.
Method breakpoint hit in oracle.jdbc.xa.client.OracleXAResource.commit at line 553 by thread default task-6.
-> Note:  Wildfly has already written this transaction to its log 

Verify Wildfly LOG-STORE
[oracle@wls1 XA]$  $WILDFLY_HOME/bin/jboss-cli.sh --connect --file=xa.cli
{"outcome" => "success"}
0:ffffc0a805c9:-46761d77:55438636:7ee
-> Wildfly has saved the transaction to its LOG-STORE

Check transaction status at Database level
SQL> select host_name,instance_name from v$instance;
HOST_NAME               INSTANCE_NAME
------------------------------ ----------------
hract22.example.com           bankA_1

SQL> select STATE, LOCAL_TRAN_ID, GLOBAL_TRAN_ID , to_char(FAIL_TIME,'DD-MON-YY HH24:MI:SS') FAIL_TIME,
  2       to_char(FORCE_TIME,'DD-MON-YY HH24:MI:SS') FORCE_TIME,  to_char(RETRY_TIME,'DD-MON-YY HH24:MI:SS') RETRY_TIME,
  3       HOST, OS_USER, COMMIT# from dba_2pc_pending;

STATE         LOCAL_TRAN_ID        GLOBAL_TRAN_ID
---------------- ---------------------- --------------------------------------------------------------------------------
FAIL_TIME       FORCE_TIME          RETRY_TIME     HOST               OS_USER       COMMIT#
------------------ ------------------ ------------------ ------------------------- --------------- ----------------
prepared     7.6.4154        131077.00000000000000000000FFFFC0A805C9B989E28955438636000007EE31
03-MAY-15 08:44:32              03-MAY-15 08:45:05 wls1.example.com       oracle       24656988

SQL> select host_name,instance_name from v$instance;
HOST_NAME               INSTANCE_NAME
------------------------------ ----------------
hract22.example.com           bankb_3

SQL> select STATE, LOCAL_TRAN_ID, GLOBAL_TRAN_ID , to_char(FAIL_TIME,'DD-MON-YY HH24:MI:SS') FAIL_TIME,
  2       to_char(FORCE_TIME,'DD-MON-YY HH24:MI:SS') FORCE_TIME,  to_char(RETRY_TIME,'DD-MON-YY HH24:MI:SS') RETRY_TIME,
  3       HOST, OS_USER, COMMIT# from dba_2pc_pending;

STATE         LOCAL_TRAN_ID        GLOBAL_TRAN_ID
---------------- ---------------------- --------------------------------------------------------------------------------
FAIL_TIME       FORCE_TIME          RETRY_TIME     HOST               OS_USER       COMMIT#
------------------ ------------------ ------------------ ------------------------- --------------- ----------------
prepared     16.17.405        131077.00000000000000000000FFFFC0A805C9B989E28955438636000007EE31
03-MAY-15 08:44:29              03-MAY-15 08:45:20 wls1.example.com       oracle       9841282
**********************************************************
***  -> kill java process/program and restart Wildlfy ****  
**********************************************************
[oracle@wls1 XA]$ ps -elf | grep java
0 S oracle    9264  9210 19  80   0 - 414974 futex_ May02 ?       01:44:51 /usr/java/latest/bin/java -D[Standalone] -Xms128m -Xmx512m -XX:MaxPermSize=256m -server ..
[oracle@wls1 XA]$ kill -9 9264

-> Restart Wildfly - Wildfly Server Log reports 

2015-05-03 08:50:45,017 WARN  [com.arjuna.ats.jta] (Periodic Recovery) ARJUNA016037: 
  Could not find new XAResource to use for recovering non-serializable XAResource XAResourceRecord 
  < resource:null, txid:< formatId=131077, gtrid_length=29, bqual_length=36, 
   tx_uid=0:ffffc0a805c9:-46761d77:55438636:7ee, node_name=1, 
     branch_uid=0:ffffc0a805c9:-46761d77:55438636:7f0, subordinatenodename=null, 
     eis_name=java:jboss/datasources/xa_rac12g_bankb >, 
   heuristic: TwoPhaseOutcome.FINISH_OK, product: 
     Oracle/Oracle Database 12c Enterprise Edition Release 12.1.0.2.0 - 64bit Production
     With the Partitioning, Real Application Clusters, Automatic Storage Management, OLAP,
     Advanced Analytics and Real Application Testing options, 
    jndiName: java:jboss/datasources/xa_rac12g_bankb com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord@519e22cc >

2015-05-03 08:50:45,017 WARN  [com.arjuna.ats.jta] (Periodic Recovery) ARJUNA016037: 
Could not find new XAResource to use for recovering non-serializable XAResource XAResourceRecord 
  < resource:null, txid:< formatId=131077, gtrid_length=29, bqual_length=36, 
   tx_uid=0:ffffc0a805c9:-46761d77:55438636:7ee, node_name=1, 
   branch_uid=0:ffffc0a805c9:-46761d77:55438636:7f3, subordinatenodename=null, 
   eis_name=java:jboss/datasources/xa_rac12g_banka >, 
   heuristic: TwoPhaseOutcome.FINISH_OK, 
     product: Oracle/Oracle Database 12c Enterprise Edition Release 12.1.0.2.0 - 64bit Production
     With the Partitioning, Real Application Clusters, Automatic Storage Management, OLAP,
     Advanced Analytics and Real Application Testing options, 
    jndiName: java:jboss/datasources/xa_rac12g_banka com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord@64fea8f0 >

-> Periodic Recovery Thread successfully re-connects to both databases
   Periodic Recovery Thread calls XA recover to retrieve the prepared XIDs from the server
   Periodic Recovery Thread finally commits the data as Wildfly LOG-STORE confirms that all branches are prepared  

Verify that that the data was really committed 
GLOBAL_NAME
--------------------------------------------------------------------------------
BANKA
ACCOUNT                 BALANCE
-------------------------------- ----------
User99_at_BANKA                6000


GLOBAL_NAME
--------------------------------------------------------------------------------
BANKB
ACCOUNT                 BALANCE
-------------------------------- ----------
User98_at_BANKB               14000

Verify Wildfly log :
[oracle@wls1 XA]$  $WILDFLY_HOME/bin/jboss-cli.sh --connect --file=xa.cli
{"outcome" => "success"}

-> After Wildfly restart the transaction was committed and the Wildfly LOG-Store was cleaned !

Testing automatic transaction recovery before a COMMIT record was written to Wildlfly LOG-STORE

• Only one XA resources have voted to COMMIT the transaction [ ==only 1 prepared  XA transaction branch ]
• Therefore Wildfly has not written a COMMIT record to  the  Wildlfly LOG-STORE
• After a system crash the whole transaction should be rolled back
• After a system crash Periodic Recovery Thread should use  XA recover and  XA rollback to rollback this transaction without any user intervention

Prepare Testcase

Press Init Accounts : 
11:04:21.039 Calling  checkAccounts() in progress ... 
11:04:21.088 Database Name:BANKA -- Account: User99_at_BANKA -- Balance: 10000.0
11:04:21.128 Database Name:BANKB -- Account: User98_at_BANKB -- Balance: 10000.0
11:04:21.128 Leaving checkAccounts() without any Error 

Set Breakpoints : Class oracle.jdbc.xa.OracleXAResource : Methode entry for prepare(), commit() and rollback()
-> Don't forget to set breackpoint for rollback to avoid the Periodic Recovery Thread to rollback the 
   transaction before we have rebooted Wildfly server !

Start Application by pressing: 
Use debugger and stop at Entry of 2.nd  oracle.jdbc.xa.client.OracleXAResource.prepare call
Method breakpoint hit in oracle.jdbc.xa.client.OracleXAResource.prepare at line 693 by thread default task-6.
Method breakpoint hit in oracle.jdbc.xa.client.OracleXAResource.prepare at line 693 by thread default task-6.

Verify Wildfly LOG-STORE
[oracle@wls1 XA]$   $WILDFLY_HOME/bin/jboss-cli.sh --connect --file=xa.cli
{"outcome" => "success"}
-> No transaction reference in Wildfly LOG-STORE

SQL> select host_name,instance_name from v$instance;
HOST_NAME               INSTANCE_NAME
------------------------------ ----------------
hract22.example.com           bankA_1

SQL> select STATE, LOCAL_TRAN_ID, GLOBAL_TRAN_ID , to_char(FAIL_TIME,'DD-MON-YY HH24:MI:SS') FAIL_TIME,
  2       to_char(FORCE_TIME,'DD-MON-YY HH24:MI:SS') FORCE_TIME,  to_char(RETRY_TIME,'DD-MON-YY HH24:MI:SS') RETRY_TIME,
  3       HOST, OS_USER, COMMIT# from dba_2pc_pending;
no rows selected

SQL> set echo off
Connected.
SQL> select host_name,instance_name from v$instance;
HOST_NAME               INSTANCE_NAME
------------------------------ ----------------
hract22.example.com           bankb_3
SQL> select STATE, LOCAL_TRAN_ID, GLOBAL_TRAN_ID , to_char(FAIL_TIME,'DD-MON-YY HH24:MI:SS') FAIL_TIME,
  2       to_char(FORCE_TIME,'DD-MON-YY HH24:MI:SS') FORCE_TIME,  to_char(RETRY_TIME,'DD-MON-YY HH24:MI:SS') RETRY_TIME,
  3       HOST, OS_USER, COMMIT# from dba_2pc_pending;
STATE         LOCAL_TRAN_ID        GLOBAL_TRAN_ID
---------------- ---------------------- --------------------------------------------------------------------------------
FAIL_TIME       FORCE_TIME          RETRY_TIME     HOST               OS_USER       COMMIT#
------------------ ------------------ ------------------ ------------------------- --------------- ----------------
prepared     14.2.389        131077.00000000000000000000FFFFC0A805C9614B927B5545C53A000000A631
03-MAY-15 09:23:47              03-MAY-15 09:26:12 wls1.example.com       oracle       9848205
-> No entry in Wildfls LOG-STORE - only one Transaction Branch is prepared on instance bankb_3

Note : During testing Periodic recovery Threads stops at our breakpoint in oracle.jdbc.xa.client.OracleXAResource.rollback
"Periodic Recovery"
oracle.jdbc.xa.client.OracleXAResource.rollback(OracleXAResource.java:945)
org.jboss.jca.adapters.jdbc.xa.XAManagedConnection.rollback(XAManagedConnection.java:346)
org.jboss.jca.core.tx.jbossts.XAResourceWrapperImpl.rollback(XAResourceWrapperImpl.java:196)
com.arjuna.ats.internal.jta.recovery.arjunacore.XARecoveryModule.handleOrphan(XARecoveryModule.java:786)
com.arjuna.ats.internal.jta.recovery.arjunacore.XARecoveryModule.xaRecoverySecondPass(XARecoveryModule.java:692)
com.arjuna.ats.internal.jta.recovery.arjunacore.XARecoveryModule.bottomUpRecovery(XARecoveryModule.java:431)
com.arjuna.ats.internal.jta.recovery.arjunacore.XARecoveryModule.periodicWorkSecondPass(XARecoveryModule.java:212)
com.arjuna.ats.internal.arjuna.recovery.PeriodicRecovery.doWorkInternal(PeriodicRecovery.java:789)
com.arjuna.ats.internal.arjuna.recovery.PeriodicRecovery.run(PeriodicRecovery.java:371)
-> This means with a breakpoint at rollback() the Periodic Recovery Thread would have already 
   delete this XA transaction. 

Now Kill Java program and verify whether records can be locked  for DML operations: 
[oracle@wls1 XA]$ ps -elf | grep java
0 S oracle   14493 14438 18  80   0 - 413832 futex_ 08:50 ?       00:07:13 /usr/java/latest/bin/java -D[Standalone] -Xms128m -Xmx512m -XX:MaxPermSize=256m -server ...
[oracle@wls1 XA]$ kill -9 14493
GLOBAL_NAME
--------------------------------------------------------------------------------
BANKA
ACCOUNT                 BALANCE
-------------------------------- ----------
User99_at_BANKA               10000
Connected.
--> No problem at bankA

GLOBAL_NAME
--------------------------------------------------------------------------------
BANKB
select * from accounts for update              *
ERROR at line 1:
ORA-01591: lock held by in-doubt distributed transaction 14.2.389
-> As we have only one prepared Transaction - ORA-1591 comes up only at bankB

-> Now Restart Wildfly to fix the ORA-1591 problem 
SQL> @check_it
GLOBAL_NAME
--------------------------------------------------------------------------------
BANKA
ACCOUNT                 BALANCE
-------------------------------- ----------
User99_at_BANKA               10000

GLOBAL_NAME
--------------------------------------------------------------------------------
BANKB
ACCOUNT                 BALANCE
-------------------------------- ----------
User98_at_BANKB               10000
-> After Wildfly restart the transaction was rolled back and we can access 
   both records for DML operations. 

Heuristically committed transaction – A major Pitfall for DBAs

Assume we have following configruation:
System A : RAC database running database bankA running London
System B : RAC database running database bankB running in Frankfurt 
System C : Wildfly application server 

After a network outage all the systems are not able to communicate with each other but 
these systems are still up and running.
 
Now System C - our Wildfly server - is crashing during a 2-Phase-Commit. 
The crash occurs after having prepared both transaction an for database bankA, bankB 
and Wildfly has already written a COMMIT record to its LOG-STAORE.

Setup testcase: 
09:10:41.653 Calling  checkAccounts() in progress ... 
09:10:41.677 Database Name:BANKA -- Account: User99_at_BANKA -- Balance: 10000.0
09:10:41.717 Database Name:BANKB -- Account: User98_at_BANKB -- Balance: 10000.0
09:10:41.719 Leaving checkAccounts() without any Error 

Setup testcase:
Tx Timeout : 60  

-> Set breakpoint in commit() metode of oracle.jdbc.xa.OracleXAResource 
Method breakpoint hit in oracle.jdbc.xa.client.OracleXAResource.commit at line 553 by thread default task-10.
Thread default task-10 stopped at OracleXAResource.java:553.

Start the application by pressing: 
-> Wait until we get ORA-1591 accessing these records:
BANKA:
SQL> connect scott/tiger@ract2-scan.grid12c.example.com:1521/banka
SQL> select * from accounts for update;
select * from accounts for update              *
ERROR at line 1:
ORA-01591: lock held by in-doubt distributed transaction 18.24.2100

BANKB:
SQL> connect scott/tiger@ract2-scan.grid12c.example.com:1521/bankb
Connected.
SQL> select * from accounts for update;
select * from accounts for update
ERROR at line 1:
ORA-01591: lock held by in-doubt distributed transaction 12.26.389

Now a lot of end users calls in and raise complaints to their DBAs that a major application running 
on RAC DB bankA and RAC DB bankB are not working  anymore.

The DBA on bankA ( London)  checks   dba_2pc_pending and found a prepared TX:
SQL> select STATE, LOCAL_TRAN_ID, GLOBAL_TRAN_ID , to_char(FAIL_TIME,'DD-MON-YY HH24:MI:SS') FAIL_TIME,
  2       to_char(FORCE_TIME,'DD-MON-YY HH24:MI:SS') FORCE_TIME,  to_char(RETRY_TIME,'DD-MON-YY HH24:MI:SS') RETRY_TIME,
  3       HOST, OS_USER, COMMIT# from dba_2pc_pending;

STATE         LOCAL_TRAN_ID        GLOBAL_TRAN_ID
---------------- ---------------------- --------------------------------------------------------------------------------
FAIL_TIME       FORCE_TIME          RETRY_TIME     HOST               OS_USER       COMMIT#
------------------ ------------------ ------------------ ------------------------- --------------- ----------------
prepared     18.24.2100        131077.00000000000000000000FFFFC0A805C9B989E289554386360000038B31
02-MAY-15 09:12:03              02-MAY-15 09:17:31 wls1.example.com       oracle       24303841
 
The DBA on bankB ( Frankfurt ) checks  dba_2pc_pending and found a prepared TX: 
SQL> select STATE, LOCAL_TRAN_ID, GLOBAL_TRAN_ID , to_char(FAIL_TIME,'DD-MON-YY HH24:MI:SS') FAIL_TIME,
  2       to_char(FORCE_TIME,'DD-MON-YY HH24:MI:SS') FORCE_TIME,  to_char(RETRY_TIME,'DD-MON-YY HH24:MI:SS') RETRY_TIME,
  3       HOST, OS_USER, COMMIT# from dba_2pc_pending;

STATE         LOCAL_TRAN_ID        GLOBAL_TRAN_ID
---------------- ---------------------- --------------------------------------------------------------------------------
FAIL_TIME       FORCE_TIME          RETRY_TIME     HOST               OS_USER       COMMIT#
------------------ ------------------ ------------------ ------------------------- --------------- ----------------
prepared     12.26.389        131077.00000000000000000000FFFFC0A805C9B989E289554386360000038B31
02-MAY-15 09:12:02              02-MAY-15 09:18:30 wls1.example.com       oracle       9400626

Now things goes wrong. 
-> The database itself does not have any ideas whether Wildfly has written a COMMIT record to the LOG-STORE or not. 
   The DBAs doesn't check the Wildfly LOG-STORE 
   Due to the pressure to get ONLINE asap the  DBA's does the following :

DBA for RAC DB bankA ( London) 
SQL> connect sys/sys@ract2-scan.grid12c.example.com:1521/bankA as sysdba
Connected.
SQL> select STATE, LOCAL_TRAN_ID  from dba_2pc_pending;
STATE         LOCAL_TRAN_ID
---------------- ----------------------
prepared     18.24.2100

SQL> rollback force '18.24.2100';
Rollback complete.

DBA for RAC DB bankB ( Frankfurt) 
SQL>  connect sys/sys@ract2-scan.grid12c.example.com:1521/bankB as sysdba
Connected.
SQL>  select STATE, LOCAL_TRAN_ID  from dba_2pc_pending;
STATE         LOCAL_TRAN_ID
---------------- ----------------------
prepared     12.26.389
SQL> commit force '12.26.389';
Commit complete.

Now both DBAs verify whether we can access these records for DML operation
SQL> connect scott/tiger@ract2-scan.grid12c.example.com:1521/banka
Connected.
SQL> 
SQL> select * from accounts for update;
ACCOUNT                 BALANCE
-------------------------------- ----------
User99_at_BANKA               10000


SQL> connect scott/tiger@ract2-scan.grid12c.example.com:1521/bankb
SQL> select * from accounts for update;
ACCOUNT                 BALANCE
-------------------------------- ----------
User98_at_BANKB               14000

-> Works fine - really ?
   The DBAs have logically corrupted ozr system integrity !!
   We have successfully added the money to User98_at_BANKB but not reduced the money 
   from account  User99_at_BANKA !
   
Note this should never happen at your production system -  or you may loose your DBA job very easily !!
                         
How we can avoid this problem ?
1. Check whether Wildfly has written a commit record 
[oracle@wls1 XA]$  $WILDFLY_HOME/bin/jboss-cli.sh --connect --file=xa.cli
{"outcome" => "success"}
0:ffffc0a805c9:-46761d77:55438636:38b
--> There is a  COMMIT record for XID :  0:ffffc0a805c9:-46761d77:55438636:38b -  so it is save to call : 
       COMMIT FORCE 'Local_Tran_ID'
    If we can't find the XID within Wildfly it is save to call on all involved databases : 
       ROLLBACK FORCE 'Local_Tran_ID';   

A closer look on Exceptions 
ut.commit() fail with :
TX Info:     
10:21:58.711 No TX active - before ut.begin() TX status:  6 - STATUS_NO_TRANSACTION - Transaction Timeout: 60
10:21:58.720 Setting New Tansaction Timeout : 60
10:22:04.640 After  ut.begin() TX status:  0 - STATUS_ACTIVE
10:22:04.709 Tx status before ut.commit() - TX status:  0 - STATUS_ACTIVE - Now sleeping : 1 [ seconds] 
10:28:03.579 FATAL ERROR: 
10:28:03.582 Tx status after Exception before ut.rollback(): TX status:  6 - STATUS_NO_TRANSACTION - Exception: null
10:28:03.585 Tx status after Exception: FATAL error during ut.rollback() :TX status:  6 - STATUS_NO_TRANSACTION 

Java Code throws javax.transaction.HeuristicMixedException : 
10:28:03.558 Error in JSF top level function: transferMoney() - Need to ROLLBACK transaction
10:28:03.576 javax.transaction.HeuristicMixedException
    at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1174)
    at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:126)
    at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:75)
    at org.jboss.tm.usertx.client.ServerVMClientUserTransaction.commit(ServerVMClientUserTransaction.java:173)
    at com.hhu.XaTestBean.transferMoney(XaTestBean.java:778)

Wildfly server.log reports :
2015-05-02 10:27:56,445 WARN  [com.arjuna.ats.jta] (default task-1) 
ARJUNA016036: commit on < formatId=131077, gtrid_length=29, bqual_length=36, 
tx_uid=0:ffffc0a805c9:-46761d77:55438636:4d3, node_name=1, 
branch_uid=0:ffffc0a805c9:-46761d77:55438636:4d5, subordinatenodename=null, 
eis_name=java:jboss/datasources/xa_rac12g_bankb > (XAResourceWrapperImpl@172657b2[xaResource=org.jboss.jca.adapters.jdbc.xa.XAManagedConnection@489e2cb1 pad=false 
  overrideRmValue=null productName=Oracle productVersion=Oracle Database 12c Enterprise Edition Release 12.1.0.2.0 - 64bit Production
With the Partitioning, Real Application Clusters, Automatic Storage Management, OLAP,
Advanced Analytics and Real Application Testing options 
 jndiName=java:jboss/datasources/xa_rac12g_bankb]) 
  failed with exception $XAException.XAER_NOTA: oracle.jdbc.xa.OracleXAException
        at oracle.jdbc.driver.T4CXAResource.kputxrec(T4CXAResource.java:965)
        at oracle.jdbc.driver.T4CXAResource.doCommit(T4CXAResource.java:454)
        at oracle.jdbc.xa.client.OracleXAResource.commit(OracleXAResource.java:583)
        at org.jboss.jca.adapters.jdbc.xa.XAManagedConnection.commit(XAManagedConnection.java:338)
        at org.jboss.jca.core.tx.jbossts.XAResourceWrapperImpl.commit(XAResourceWrapperImpl.java:107)
        at com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord.topLevelCommit(XAResourceRecord.java:461)
        at com.arjuna.ats.arjuna.coordinator.BasicAction.doCommit(BasicAction.java:2810)
        at com.arjuna.ats.arjuna.coordinator.BasicAction.doCommit(BasicAction.java:2726)
        at com.arjuna.ats.arjuna.coordinator.BasicAction.phase2Commit(BasicAction.java:1820)
        at com.arjuna.ats.arjuna.coordinator.BasicAction.End(BasicAction.java:1504)
        at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:96)
        at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:162)
        at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1166)
        at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:126)
        at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:75)
        at org.jboss.tm.usertx.client.ServerVMClientUserTransaction.commit(ServerVMClientUserTransaction.java:173)
        at com.hhu.XaTestBean.transferMoney(XaTestBean.java:778) [classes:]
->  JAVA Code is failing with $XAException.XAER_NOTA: oracle.jdbc.xa.OracleXAException as the related XA transaction is 
    already committed using COMMIT FORCE 'Local_Tran_ID'  or rolled back using ROLLBACK force  'Local_Tran_ID' at Database level.

Cleanup system state after above getting a heuristically committed XA transaction 
 - Try to repair the logical corruption from any logfile we can find tracking SQL change and TX id.
 - Cleanup the system [ Wildfly LOG-STORE and Oracle dba_2pc_pending table ]

Cleanup Wildfly LOG-STORE
Verify currents XA transaction status  
[oracle@wls1 XA]$  $WILDFLY_HOME/bin/jboss-cli.sh --connect --file=xa.cli
{"outcome" => "success"}
0:ffffc0a805c9:-46761d77:55438636:38b
0:ffffc0a805c9:-46761d77:55438636:439
0:ffffc0a805c9:-46761d77:55438636:4d3

SQL> connect sys/sys@ract2-scan.grid12c.example.com:1521/bankb as sysdba
SQL>  select STATE, LOCAL_TRAN_ID, GLOBAL_TRAN_ID from dba_2pc_pending;
STATE         LOCAL_TRAN_ID        GLOBAL_TRAN_ID
---------------- ---------------------- ----------------------------------------------------------------------
forced commit     12.26.389        131077.00000000000000000000FFFFC0A805C9B989E289554386360000038B31
forced commit     17.21.390        131077.00000000000000000000FFFFC0A805C9B989E289554386360000043931
forced commit     14.26.382        131077.00000000000000000000FFFFC0A805C9B989E28955438636000004D331

SQL> connect sys/sys@ract2-scan.grid12c.example.com:1521/banka as sysdba
SQL> select STATE, LOCAL_TRAN_ID, GLOBAL_TRAN_ID from dba_2pc_pending;
STATE         LOCAL_TRAN_ID        GLOBAL_TRAN_ID
---------------- ---------------------- ----------------------------------------------------------------------
forced rollback  18.24.2100        131077.00000000000000000000FFFFC0A805C9B989E289554386360000038B31
forced rollback  14.1.2092        131077.00000000000000000000FFFFC0A805C9B989E289554386360000043931
forced rollback  16.4.2077        131077.00000000000000000000FFFFC0A805C9B989E28955438636000004D331

Purge the XA transaction from Wildfly LOG-STORE
$WILDFLY_HOME/bin/jboss-cli.sh --connect 
   "/subsystem=transactions/log-store=log-store/transactions=0\:ffffc0a805c9\:-46761d77\:55438636\:38b:delete"
{"outcome" => "success"}
[oracle@wls1 XA]$ $WILDFLY_HOME/bin/jboss-cli.sh --connect
    "/subsystem=transactions/log-store=log-store/transactions=0\:ffffc0a805c9\:-46761d77\:55438636\:439:delete"
{"outcome" => "success"}
[oracle@wls1 XA]$  $WILDFLY_HOME/bin/jboss-cli.sh --connect 
     "/subsystem=transactions/log-store=log-store/transactions=0\:ffffc0a805c9\:-46761d77\:55438636\:4d3:delete"
{"outcome" => "success"}
[oracle@wls1 XA]$ $WILDFLY_HOME/bin/jboss-cli.sh --connect --file=xa.cli
{"outcome" => "success"}

Finally purge XA transactions at DB level run on both RAC nodes:
SQL> execute DBMS_TRANSACTION.PURGE_MIXED('18.24.2100');
SQL> execute DBMS_TRANSACTION.PURGE_MIXED('14.1.2092');
SQL> execute DBMS_TRANSACTION.PURGE_MIXED('16.4.2077');

Understanding ORA-1591 : lock held by in-doubt distributed transaction

Change Transaction Timeout: 60   
Set Breakpoints in : oracle.jdbc.xa.OracleXAResource prepare() and commit() functions 
Press F5 untill we reach first Commit breakpoint:
  Method breakpoint hit in oracle.jdbc.xa.client.OracleXAResource.prepare at line 693 by thread default task-1.
  Method breakpoint hit in oracle.jdbc.xa.client.OracleXAResource.prepare at line 693 by thread default task-1.
  Method breakpoint hit in oracle.jdbc.xa.client.OracleXAResource.commit at line 553 by thread default task-1.

Press : 
Transaction status - immediate after stopping: 
Connected.
SQL> select host_name,instance_name from v$instance;
HOST_NAME               INSTANCE_NAME
------------------------------ ----------------
hract22.example.com           bankA_2

SQL> select * from  sys.dba_pending_transactions;
  FORMATID GLOBALID                                                      BRANCHID
---------- ------------------------------------------------------------ -------------------------------------------------------
    131077 00000000000000000000FFFFC0A805C9B989E289554386360000005931    00000000000000000000FFFFC0A805C9B989E289554386360000005
                                                                         E0000000200000000

SQL> select STATE, LOCAL_TRAN_ID, GLOBAL_TRAN_ID , to_char(FAIL_TIME,'DD-MON-YY HH24:MI:SS') FAIL_TIME,
  2       to_char(FORCE_TIME,'DD-MON-YY HH24:MI:SS') FORCE_TIME,  to_char(RETRY_TIME,'DD-MON-YY HH24:MI:SS') RETRY_TIME,
  3       HOST, OS_USER, COMMIT# from dba_2pc_pending;
no rows selected


SQL> select host_name,instance_name from v$instance;
HOST_NAME               INSTANCE_NAME
------------------------------ ----------------
hract22.example.com           bankb_3

SQL> select * from  sys.dba_pending_transactions;
  FORMATID GLOBALID                                                      BRANCHID
---------- ------------------------------------------------------------ -------------------------------------------------------
    131077 00000000000000000000FFFFC0A805C9B989E289554386360000005931    00000000000000000000FFFFC0A805C9B989E289554386360000005
                                                                         B0000000300000000

SQL> select STATE, LOCAL_TRAN_ID, GLOBAL_TRAN_ID , to_char(FAIL_TIME,'DD-MON-YY HH24:MI:SS') FAIL_TIME,
  2       to_char(FORCE_TIME,'DD-MON-YY HH24:MI:SS') FORCE_TIME,  to_char(RETRY_TIME,'DD-MON-YY HH24:MI:SS') RETRY_TIME,
  3       HOST, OS_USER, COMMIT# from dba_2pc_pending;
no rows selected

Script to track XA transactions within Wildfly:
[oracle@wls1 XA]$ cat xa.cli
/subsystem=transactions/log-store=log-store/:probe()
ls /subsystem=transactions/log-store=log-store/transactions

[oracle@wls1 XA]$  $WILDFLY_HOME/bin/jboss-cli.sh --connect --file=xa.cli
{"outcome" => "success"}
0:ffffc0a805c9:-46761d77:55438636:59

-> The prepared transaction branchess are visible in sys.dba_pending_transactions - but not yet in  dba_2pc_pending
   Wildfly reports the transaction in its LOG-STORE

Now wait 60 seconds until Oracle times out the XA Transaction and  creates an in-doubt transaction 
SQL> select host_name,instance_name from v$instance;
HOST_NAME                      INSTANCE_NAME
------------------------------ ----------------
hract22.example.com            bankA_2
SQL> select * from  sys.dba_pending_transactions;
  FORMATID GLOBALID                                                     BRANCHID
---------- ------------------------------------------------------------ -------------------------------------------------------
    131077 00000000000000000000FFFFC0A805C9B989E289554386360000005931    00000000000000000000FFFFC0A805C9B989E289554386360000005
                                                                         E0000000200000000
SQL> select STATE, LOCAL_TRAN_ID, GLOBAL_TRAN_ID , to_char(FAIL_TIME,'DD-MON-YY HH24:MI:SS') FAIL_TIME,
  2       to_char(FORCE_TIME,'DD-MON-YY HH24:MI:SS') FORCE_TIME,  to_char(RETRY_TIME,'DD-MON-YY HH24:MI:SS') RETRY_TIME,
  3       HOST, OS_USER, COMMIT# from dba_2pc_pending;
STATE         LOCAL_TRAN_ID        GLOBAL_TRAN_ID
---------------- ---------------------- --------------------------------------------------------------------------------
FAIL_TIME       FORCE_TIME          RETRY_TIME     HOST               OS_USER       COMMIT#
------------------ ------------------ ------------------ ------------------------- --------------- ----------------
prepared     3.18.4315        131077.00000000000000000000FFFFC0A805C9B989E289554386360000005931
01-MAY-15 16:15:02              01-MAY-15 16:15:35 wls1.example.com       oracle       24161321

SQL> select host_name,instance_name from v$instance;
HOST_NAME               INSTANCE_NAME
------------------------------ ----------------
hract22.example.com           bankb_3

SQL> select * from  sys.dba_pending_transactions;
  FORMATID GLOBALID                                                      BRANCHID
---------- ------------------------------------------------------------ -------------------------------------------------------
    131077 00000000000000000000FFFFC0A805C9B989E289554386360000005931    00000000000000000000FFFFC0A805C9B989E289554386360000005
                                                                         B0000000300000000
SQL> select STATE, LOCAL_TRAN_ID, GLOBAL_TRAN_ID , to_char(FAIL_TIME,'DD-MON-YY HH24:MI:SS') FAIL_TIME,
  2       to_char(FORCE_TIME,'DD-MON-YY HH24:MI:SS') FORCE_TIME,  to_char(RETRY_TIME,'DD-MON-YY HH24:MI:SS') RETRY_TIME,
  3       HOST, OS_USER, COMMIT# from dba_2pc_pending;
STATE         LOCAL_TRAN_ID        GLOBAL_TRAN_ID
---------------- ---------------------- --------------------------------------------------------------------------------
FAIL_TIME       FORCE_TIME          RETRY_TIME     HOST               OS_USER       COMMIT#
------------------ ------------------ ------------------ ------------------------- --------------- ----------------
prepared     15.23.381        131077.00000000000000000000FFFFC0A805C9B989E289554386360000005931
01-MAY-15 16:15:00              01-MAY-15 16:15:51 wls1.example.com       oracle       9263234

-> The prepared transaction branches  are visible in sys.dba_pending_transactions and  dba_2pc_pending
   Wildfly reports the transactions as stored in the log store !

Note: Accessing a record  being part of a prepared distributed transaction will throw ORA-1591 
      and print out the local transaction ID. 

Connected.
select * from accounts for update              *
ERROR at line 1:
ORA-01591: lock held by in-doubt distributed transaction 3.18.4315

Connected.
select * from accounts for update
ERROR at line 1:
ORA-01591: lock held by in-doubt distributed transaction 15.23.381
 
Now Press F5 again until we get back control via our HTML page

Note: Even the entry was in dba_2pc_pending running the commit sucessfully finshed the distributed transaction 
      Entries in  sys.dba_pending_transactions and  dba_2pc_pending are removed and Wildfly LOG-STORE 
      was cleaned up.

Understanding ORA-2049 error: distributed transaction waiting for lock

Lock a record via sqlplus 
SQL>  select BALANCE from Accounts for update;
   BALANCE
----------
     10000
Press:  
 
Generic Error:     
17:05:19.248 Error in JSF top level function: transferMoney() - Need to ROLLBACK transaction
17:05:19.248 ORA-02049: timeout: distributed transaction waiting for lock
17:05:19.249 java.sql.SQLSyntaxErrorException: ORA-02049: timeout: distributed transaction waiting for lock
    at oracle.jdbc.driver.T4CTTIoer.processError(T4CTTIoer.java:450)
    at oracle.jdbc.driver.T4CTTIoer.processError(T4CTTIoer.java:399)
    at oracle.jdbc.driver.T4C8Oall.processError(T4C8Oall.java:1059)
    at oracle.jdbc.driver.T4CTTIfun.receive(T4CTTIfun.java:522)
    at oracle.jdbc.driver.T4CTTIfun.doRPC(T4CTTIfun.java:257)
    at oracle.jdbc.driver.T4C8Oall.doOALL(T4C8Oall.java:587)
    at oracle.jdbc.driver.T4CStatement.doOall8(T4CStatement.java:210)
    at oracle.jdbc.driver.T4CStatement.doOall8(T4CStatement.java:30)
    at oracle.jdbc.driver.T4CStatement.executeForRows(T4CStatement.java:931)
    at oracle.jdbc.driver.OracleStatement.doExecuteWithTimeout(OracleStatement.java:1150)
    at oracle.jdbc.driver.OracleStatement.executeUpdateInternal(OracleStatement.java:1707)
    at oracle.jdbc.driver.OracleStatement.executeUpdate(OracleStatement.java:1670)
    at oracle.jdbc.driver.OracleStatementWrapper.executeUpdate(OracleStatementWrapper.java:310)
    at org.jboss.jca.adapters.jdbc.WrappedStatement.executeUpdate(WrappedStatement.java:375)
    at com.hhu.XaTestBean.doUpdate(XaTestBean.java:603)

Transaction status 
17:04:18.911 No TX active - before ut.begin() TX status:  6 - STATUS_NO_TRANSACTION - Transaction Timeout: 5
17:04:18.911 Setting New Tansaction Timeout : 5
17:04:18.990 After  ut.begin() TX status:  0 - STATUS_ACTIVE
17:05:19.250 FATAL ERROR: 
17:05:19.250 Tx status after Exception before ut.rollback(): TX status:  9 - STATUS_ROLLING_BACK 
            - Exception: ORA-02049: timeout: distributed transaction waiting for lock
17:05:19.284 Tx status after Exception - but  successful ut.rollback(): TX status:  6 - STATUS_NO_TRANSACTION 

Verify the related database init.ora parameter
SQL> show parameter distributed_lock_timeout
NAME                     TYPE     VALUE
------------------------------------ ----------- ------------------------------
distributed_lock_timeout         integer     60


 Note: It's not a good idea to increase distributed_lock_timeout without understanding what is going on.
       In a first approach try to re-run the failed code.
       Any OLTP application should not lock a record for more than 60 seconds
   
       It if a session times out within Oracle, then the Oracle database’s Process Monitor (PMON) will delete 
         the transaction branch if not prepared  or cause the transaction to become in-doubt if prepared.
      
     Generic Timeout Settings : Transaction Timeout for JDBC  <  DISTRIBUTED_LOCK_TIMEOUT . 

Explanation:

• The java code tries to lock the record which is locked by our sqlplus session
• After waiting 60 seconds the SQL processing returns an exception:
        java.sql.SQLSyntaxErrorException: ORA-02049: timeout: distributed transaction waiting for lock
•  This wait time is controlled by the init.ora parameter distributed_lock_timeout
  SQL> show parameter distributed_lock_timeout
  NAME                        TYPE     VALUE
  —————————— ———– —————-
  distributed_lock_timeout         integer     60
• As for any other exception the XA transactions needs to be rolled back. 

Understanding Transaction Timeout

Setup testcase: 
Transaction Timeout: 5         
Sleep Time:         10  
Press                :  

Error Stack 
17:53:21.729 Error in JSF top level function: transferMoney() - Need to ROLLBACK transaction
17:53:21.729 ARJUNA016102: The transaction is not active! Uid is 0:ffffc0a805c9:410b1af0:55424451:c6
17:53:21.730 javax.transaction.RollbackException: ARJUNA016102: The transaction is not active! Uid is 0:ffffc0a805c9:410b1af0:55424451:c6
    at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1156)
    at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:126)
    at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:75)
    at org.jboss.tm.usertx.client.ServerVMClientUserTransaction.commit(ServerVMClientUserTransaction.java:173)
    at com.hhu.XaTestBean.transferMoney(XaTestBean.java:769)

Tx Status:
17:53:11.556 No TX active - before ut.begin() TX status:  6 - STATUS_NO_TRANSACTION - Transaction Timeout: 5
17:53:11.556 Setting New Tansaction Timeout : 5
17:53:11.563 After  ut.begin() TX status:  0 - STATUS_ACTIVE
17:53:11.726 Tx status before ut.commit() - TX status:  0 - STATUS_ACTIVE - Now sleeping : 10 [ seconds] 
17:53:21.730 FATAL ERROR: 
17:53:21.730 Tx status after Exception before ut.rollback(): TX status:  6 - STATUS_NO_TRANSACTION - 
             Exception: ARJUNA016102: The transaction is not active! Uid is 0:ffffc0a805c9:410b1af0:55424451:c6
17:53:21.730 Tx status after Exception: FATAL error during ut.rollback() :TX status:  6 - STATUS_NO_TRANSACTION - 
             Exception: java.lang.IllegalStateException: BaseTransaction.rollback - ARJUNA016074: no transaction!

Note :
  Transaction Timeout for JDBC  <  DISTRIBUTED_LOCK_TIMEOUT ( default : 60 seconds ) .

Code  Explanation:

• After 10 seconds [ our sleeptime ] the transaction processing step has finished and ut.commit() is called
• Because we have reached transaction Timeout of 5 seconds the ut.commit() call fails
• In the exception handler the ut.rollback() call becomes a NOOP as the parent transaction was already deleted.

Debugging  UserTransaction API and XAResource API by using a Netbeans Debugger

Using Netbeans to debug the JAVA XA code more in detail 
1. Start Wildfly in Debug Mode
2. Add Breakpoint: 
   Debugger   : JAVA    Breakpoint Type : Methode
   Class Name :  oracle.jdbc.xa.OracleXAResource       
   Check      : All methods for a given Class
   Method Name: <all methods>
   Stop on    : Method Entry 
3. Debug -> Debug Main Program
4. Set breakpoint at line ut.begin() 
5. Debug -> Run to Cursor  
6. Press F5 until our HTML page gets  back control 

Breakpoint hit at line 762 in class com.hhu.XaTestBean by thread default task-15.
Thread default task-15 stopped at XaTestBean.java:762.

ut.beginn() translates to the following XA calls
Method breakpoint hit in oracle.jdbc.xa.OracleXAResource.setTransactionTimeout at line 1063 by thread default task-15.
Method breakpoint hit in oracle.jdbc.xa.client.OracleXAResource.start at line 163 by thread default task-15.
Method breakpoint hit in oracle.jdbc.xa.OracleXAResource.saveAndAlterAutoCommitModeForGlobalTransaction at line 797 by thread default task-15.
Method breakpoint hit in oracle.jdbc.xa.OracleXAResource.checkError at line 1188 by thread default task-15.
Method breakpoint hit in oracle.jdbc.xa.OracleXAResource.createOrUpdateXid at line 296 by thread default task-15.
Method breakpoint hit in oracle.jdbc.xa.OracleXAResource.getMatchingXidListEntry at line 234 by thread default task-15.
Method breakpoint hit in oracle.jdbc.xa.OracleXAResource.enterGlobalTxnMode at line 1179 by thread default task-15.
Method breakpoint hit in oracle.jdbc.xa.OracleXAResource.isSameRM at line 995 by thread default task-15.
-> Transaction for bankA is started, isSameRM() is used to check whether bankA and bankB are using the same Resource Manager 
   As we have 2 different RAC systems this call should return false ! 

Method breakpoint hit in oracle.jdbc.xa.OracleXAResource.getConnection at line 945 by thread default task-15.
Method breakpoint hit in oracle.jdbc.xa.OracleXAResource.setTransactionTimeout at line 1063 by thread default task-15.
Method breakpoint hit in oracle.jdbc.xa.client.OracleXAResource.start at line 163 by thread default task-15.
Method breakpoint hit in oracle.jdbc.xa.OracleXAResource.saveAndAlterAutoCommitModeForGlobalTransaction at line 797 by thread default task-15.
Method breakpoint hit in oracle.jdbc.xa.OracleXAResource.checkError at line 1188 by thread default task-15.
Method breakpoint hit in oracle.jdbc.xa.OracleXAResource.createOrUpdateXid at line 296 by thread default task-15.
Method breakpoint hit in oracle.jdbc.xa.OracleXAResource.getMatchingXidListEntry at line 234 by thread default task-15.
Method breakpoint hit in oracle.jdbc.xa.OracleXAResource.enterGlobalTxnMode at line 1179 by thread default task-15.
-> Transaction for bankB is started 

ut.commit() translates to the following XA calls 
Method breakpoint hit in oracle.jdbc.xa.client.OracleXAResource.end at line 358 by thread default task-15.
Method breakpoint hit in oracle.jdbc.xa.OracleXAResource.suspendStacked at line 430 by thread default task-15.
Method breakpoint hit in oracle.jdbc.xa.OracleXAResource.isSameXid at line 256 by thread default task-15.
Method breakpoint hit in oracle.jdbc.xa.OracleXAResource.isXidSuspended at line 398 by thread default task-15.
Method breakpoint hit in oracle.jdbc.xa.OracleXAResource.getMatchingXidListEntry at line 234 by thread default task-15.
Method breakpoint hit in oracle.jdbc.xa.OracleXAResource.removeXidFromList at line 244 by thread default task-15.
Method breakpoint hit in oracle.jdbc.xa.OracleXAResource.isSameXid at line 256 by thread default task-15.
Method breakpoint hit in oracle.jdbc.xa.OracleXAResource.isXidListEmpty at line 274 by thread default task-15.
Method breakpoint hit in oracle.jdbc.xa.OracleXAResource.exitGlobalTxnMode at line 1167 by thread default task-15.
Method breakpoint hit in oracle.jdbc.xa.OracleXAResource.checkError at line 1188 by thread default task-15.
Method breakpoint hit in oracle.jdbc.xa.OracleXAResource.restoreAutoCommitModeForGlobalTransaction at line 768 by thread default task-15.
Method breakpoint hit in oracle.jdbc.xa.client.OracleXAResource.prepare at line 693 by thread default task-15.
-> For bankA the XA transaction is finished by OracleXAResource.end() and prepared by OracleXAResource.prepare()

Method breakpoint hit in oracle.jdbc.xa.client.OracleXAResource.end at line 358 by thread default task-15.
Method breakpoint hit in oracle.jdbc.xa.OracleXAResource.suspendStacked at line 430 by thread default task-15.
Method breakpoint hit in oracle.jdbc.xa.OracleXAResource.isSameXid at line 256 by thread default task-15.
Method breakpoint hit in oracle.jdbc.xa.OracleXAResource.isXidSuspended at line 398 by thread default task-15.
Method breakpoint hit in oracle.jdbc.xa.OracleXAResource.getMatchingXidListEntry at line 234 by thread default task-15.
Method breakpoint hit in oracle.jdbc.xa.OracleXAResource.removeXidFromList at line 244 by thread default task-15.
Method breakpoint hit in oracle.jdbc.xa.OracleXAResource.isSameXid at line 256 by thread default task-15.
Method breakpoint hit in oracle.jdbc.xa.OracleXAResource.isXidListEmpty at line 274 by thread default task-15.
Method breakpoint hit in oracle.jdbc.xa.OracleXAResource.exitGlobalTxnMode at line 1167 by thread default task-15.
Method breakpoint hit in oracle.jdbc.xa.OracleXAResource.checkError at line 1188 by thread default task-15.
Method breakpoint hit in oracle.jdbc.xa.OracleXAResource.restoreAutoCommitModeForGlobalTransaction at line 768 by thread default task-15.
Method breakpoint hit in oracle.jdbc.xa.client.OracleXAResource.prepare at line 693 by thread default task-15.
--> For bankB the XA transaction is finished by OracleXAResource.end() and prepared by OracleXAResource.prepare()
    Now as all XA branches are prepared the global transaction can be commited !

Method breakpoint hit in oracle.jdbc.xa.client.OracleXAResource.commit at line 553 by thread default task-15.
Method breakpoint hit in oracle.jdbc.xa.OracleXAResource.removeXidFromList at line 244 by thread default task-15.
Method breakpoint hit in oracle.jdbc.xa.OracleXAResource.isSameXid at line 256 by thread default task-15.
Method breakpoint hit in oracle.jdbc.xa.OracleXAResource.exitGlobalTxnMode at line 1167 by thread default task-15.
--> Commit XA transaction at bankA 

Method breakpoint hit in oracle.jdbc.xa.client.OracleXAResource.commit at line 553 by thread default task-15.
Method breakpoint hit in oracle.jdbc.xa.OracleXAResource.removeXidFromList at line 244 by thread default task-15.
Method breakpoint hit in oracle.jdbc.xa.OracleXAResource.isSameXid at line 256 by thread default task-15.
Method breakpoint hit in oracle.jdbc.xa.OracleXAResource.exitGlobalTxnMode at line 1167 by thread default task-15.
--> Commit XA transaction at bankB 

Note : The Periodic Recovery Thread is also using our XAResources and tries to complete any failed XA transaction
        

SQL Scripts and Wildfly Scripts

Create tables : cr_tab.sql
connect scott/tiger@ract2-scan.grid12c.example.com:1521/banka 
drop table ACCOUNTS;
CREATE TABLE ACCOUNTS
( ACCOUNT varchar2(32) CONSTRAINT ACCOUNTS_PK PRIMARY KEY,
  BALANCE NUMBER(10,2) constraint S_LOWER_CHK  check (BALANCE >= 0)
);
insert into ACCOUNTS values ('User99_at_BANKA', 10000);
commit;
select * from global_name;
select * from accounts;
update Accounts set balance = balance - 11000;
rollback;

connect scott/tiger@ract2-scan.grid12c.example.com:1521/bankb 
drop table ACCOUNTS;
CREATE TABLE ACCOUNTS
( ACCOUNT varchar2(32) CONSTRAINT ACCOUNTS_PK PRIMARY KEY,
  BALANCE NUMBER(10,2) constraint S_LOWER_CHK  check (BALANCE >= 0)
);

insert into ACCOUNTS values ('User98_at_BANKB', 10000);
commit;
select global_name from global_name;
select * from accounts;
update Accounts set balance = balance - 11000;
rollback;

Test whether the records are locked : check_it.sql
connect scott/tiger@ract2-scan.grid12c.example.com:1521/banka 
select * from global_name;
select * from accounts for update;

connect scott/tiger@ract2-scan.grid12c.example.com:1521/bankb 
select global_name from global_name;
select * from accounts for update;

Generic script the test XA staus of both RAC databases: check_xa.sql 
set echo on
connect sys/sys@ract2-scan.grid12c.example.com:1521/banka as sysdba
@tx 
connect sys/sys@ract2-scan.grid12c.example.com:1521/bankb as sysdba
@tx 
exit

Script to display database details for distributed transactions: tx.sql
/*
   If you run a 2PC you need to run  tx.sql on both RAC databases .
   Sample:
    sqlplus  sys/sys@ract2-scan.grid12c.example.com:1521/banka as sysdba @tx
    sqlplus  sys/sys@ract2-scan.grid12c.example.com:1521/bankb as sysdba @tx
*/ 
set echo off
set linesize 132
set pagesize 132
col HOST_NAME format A30
col GLOBAL_TRAN_ID format A80
col GLOBALID format A60
col BRANCHID format A55
col HOST format A25
col OS_USER format A15
set echo on 
select host_name,instance_name from v$instance;
select * from  sys.dba_pending_transactions;
select STATE, LOCAL_TRAN_ID, GLOBAL_TRAN_ID , to_char(FAIL_TIME,'DD-MON-YY HH24:MI:SS') FAIL_TIME,
    to_char(FORCE_TIME,'DD-MON-YY HH24:MI:SS') FORCE_TIME,  to_char(RETRY_TIME,'DD-MON-YY HH24:MI:SS') RETRY_TIME, 
    HOST, OS_USER, COMMIT# from dba_2pc_pending;
set echo off

Script to track XA transactions within Wildfly:
[oracle@wls1 XA]$ cat xa.cli
/subsystem=transactions/log-store=log-store/:probe()
ls /subsystem=transactions/log-store=log-store/transactions

Source Code

  JSF Code: 
        bankInfo.xhtml  - JSF page to display Transaction Info, Exception Info, failed SQL
        index.xhtml     - Main Entry JSF page - displays Account details 
        jdbc_info.xhtml - JSF Page to diplay JDBC driver details, Exceptions, Transaction processing Steps
        rac_info.xhtml  - JSF Page to display RAC instances details

  Maven Project Object Model    
       pom.xml

  JAVA Code:  
       XaTestBean.java

Reference

• http://www.oracle.com/technetwork/products/clustering/overview/distributed-transactions-and
• Setup a XA Datasource by using the RAC SCAN address

• How to integrate the Oracle JDBC driver as a Wildfly module ?

Why you should use Arquillian/Junit ?

• Arquillian simplifies integration testing for Java apps
• Integrates  Test runners like Junit
• Integrates  Containers like JBoss,Glassfish,..
• During the deplyoment step [ @Deployment ] ShrinkWrap utility does the following
  • creates a test archive on the fly like test.war,..
  • adds libraries if needed:  like addAsLibraries(new File(LOCAL_MAVEN_REPO + “/com/oracle/ojdbc7/12.1.0.2/ojdbc7-12.1.0.2.jar”));
  • loads all classes referenced in addPackage method: .addPackage(DriverBean.class.getPackage());
  • adds resources like bean.xml :     .addAsWebInfResource(EmptyAsset.INSTANCE, “beans.xml”) ;
• Arquillian can inject Beans, EBJs by using Jnject annotations [ @Inject DriverBean db ] -> This makes Arquillian to a pretty cool and complete test framework
• Uses @Test annotation to find the test methods to be run

pom.xml Configuration for Arquillian, UCP, ONS and Oracle JDBC driver

    <dependencyManagement>
        <dependencies>
        <!-- Override dependency resolver with latest version.  This must go *BEFORE* the Arquillian BOM. -->
        <dependency>
            <groupId>org.jboss.shrinkwrap.resolver</groupId>
            <artifactId>shrinkwrap-resolver-bom</artifactId>
            <version>2.0.2</version>
            <scope>import</scope>
            <type>pom</type>
        </dependency>    
        <dependency>            
            <groupId>org.jboss.arquillian</groupId>
            <artifactId>arquillian-bom</artifactId>
            <version>1.1.8.Final</version>
            <scope>import</scope>
            <type>pom</type>
        </dependency>         
    </dependencies>
    </dependencyManagement>
    
    <dependencies>
        <dependency>
            <groupId>javax</groupId>
            <artifactId>javaee-web-api</artifactId>
            <version>7.0</version>
            <scope>provided</scope>
        </dependency>
        <dependency>
            <groupId>com.oracle</groupId>
            <artifactId>ojdbc7</artifactId>
            <version>12.1.0.2</version>
             <scope>runtime</scope>
        </dependency>  
        <dependency>
            <groupId>com.oracle</groupId>
            <artifactId>ucp</artifactId>
            <version>12.1.0.2</version>
        </dependency> 
        <dependency>
            <groupId>com.oracle</groupId>
            <artifactId>ons</artifactId>
            <version>12.1.0.2</version>
        </dependency> 
       <dependency>
            <groupId>junit</groupId>
            <artifactId>junit</artifactId>
            <version>4.11</version>
        </dependency> 
        
        <!-- Add support for enterprise feature like Transactions, EJBs  -->
        <dependency>
            <groupId>org.jboss.arquillian.junit</groupId>
            <artifactId>arquillian-junit-container</artifactId>
            <scope>test</scope>
        </dependency> 
        
        <!-- Add support Resolver support to load JDBC, UCP and ONS jar for Unit testing  -->
       <dependency>
            <groupId>org.jboss.shrinkwrap.resolver</groupId>
            <artifactId>shrinkwrap-resolver-depchain</artifactId>      
            <scope>test</scope>
            <type>pom</type>
       </dependency>                
    </dependencies>

Configure  arquillian.xml [ located at src/main/resources ]

<arquillian xmlns="http://jboss.org/schema/arquillian" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
    xsi:schemaLocation="
        http://jboss.org/schema/arquillian
        http://jboss.org/schema/arquillian/arquillian_1_0.xsd">
    <container qualifier="wildfly" default="true">
        <configuration>
            <property name="jbossHome">/usr/local/wildfly-8.2.0.Final</property>
            <property name="modulePath">/usr/local/wildfly-8.2.0.Final/modules</property>
            <!-- <property name="allowConnectingToRunningServer">true</property> -->
           <property name="allowConnectingToRunningServer">true</property>
        </configuration>
    </container>
</arquillian>

Write your JAVA testing class TestDriverBean.java [ located in src/test/java ]

Source Code:
import com.hhu.DriverBean;
import java.io.File;
import javax.inject.Inject;
import org.jboss.arquillian.container.test.api.Deployment;
import org.jboss.arquillian.junit.Arquillian;
import org.jboss.shrinkwrap.api.Archive;
import org.jboss.shrinkwrap.api.ShrinkWrap;
import org.jboss.shrinkwrap.api.asset.EmptyAsset;
import org.jboss.shrinkwrap.api.spec.WebArchive;
import static org.junit.Assert.assertFalse;
import static org.junit.Assert.assertNull;
import org.junit.Test;
import org.junit.runner.RunWith;

@RunWith(Arquillian.class)
public class TestDriverBean
    {
    private static final String LOCAL_MAVEN_REPO =  
         System.getProperty("maven.repo.local") != null ?  
               System.getProperty("maven.repo.local") :  
               (System.getProperty("user.home") + File.separatorChar +  
               ".m2" + File.separatorChar + "repository");
     
   @Deployment
    public static Archive<?> createTestArchive() { 
 
        System.out.println("****************** Inside createTestArchive()" );
        System.out.println("****************** Local Maven Repsository: " + LOCAL_MAVEN_REPO );
        
        WebArchive res = ShrinkWrap.create(WebArchive.class, "testDriverBean.war");
     
        res.addPackage(DriverBean.class.getPackage());    
        res.addAsLibraries(new File(LOCAL_MAVEN_REPO + "/com/oracle/ojdbc7/12.1.0.2/ojdbc7-12.1.0.2.jar"));
        res.addAsLibraries(new File(LOCAL_MAVEN_REPO + "/com/oracle/ucp/12.1.0.2/ucp-12.1.0.2.jar"));
        res.addAsLibraries(new File(LOCAL_MAVEN_REPO + "/com/oracle/ons/12.1.0.2/ons-12.1.0.2.jar"));
        res.addAsWebInfResource(EmptyAsset.INSTANCE, "beans.xml") ;        
        System.out.println(res.toString(true));    
        System.out.println("****************** Leaving createTestArchive()" );
        return res;                
    }
 
    @Inject DriverBean db;
    
    @Test
    public void driverTest() throws Exception
      {
      System.out.println("-------------- driverTest() running ---------------");
      db.setPoolInfo(null);
      db.setJdbcInfo(null);
      db.setExceptInfo(null);
      db.setClname("oracle.jdbc.OracleDriver");  
      String drvRet =db.checkDriver();     
      System.out.println("driverTest() - return         : " + drvRet );
      System.out.println("driverTest() - JDBC INFO      : " + db.getJdbcInfo() );
      System.out.println("driverTest() - Exception INFO : " + db.getExceptInfo() );  
      assertNull( db.getExceptInfo());
      System.out.println("-------------- driverTest() finished --------------");             
      }
    
    @Test
    public void driverTest2() throws Exception
      {
      System.out.println("-------------- driverTest2() running - Creating a Class not found Exception ---------------");   
            // This will trigger a ClassNotFound Exception
      db.setClname("This_is_not_the_Oracle_JDBC_driver_class");  
      db.setPoolInfo(null);
      db.setJdbcInfo(null);
      db.setExceptInfo(null);
      String drvRet = db.checkDriver();
      System.out.println("driverTest2() - return         : " + drvRet );
      System.out.println("driverTest2() - JDBC INFO      : " + db.getJdbcInfo() );
      System.out.println("driverTest2() - Exception INFO : " + db.getExceptInfo() );     
      assertNull( db.getExceptInfo());
      System.out.println("-------------- driverTest2() finished --------------");          
      }
    
    @Test
    public void poolTest() throws Exception
      {
        System.out.println("-------------- poolTest() running ---------------");
        db.setPoolInfo(null);
        db.setExceptInfo(null);
        db.setJdbcInfo(null);
        String drvRet =db.initPool();     
        System.out.println("poolTest() - return         : " + drvRet );
        System.out.println("poolTest() - Pool INFO      : " + db.getPoolInfo() );
        System.out.println("poolTest() - Exception INFO : " + db.getExceptInfo() );
        String RACDB = "RAC DB: BANKB";
        if ( db.getPoolInfo().contains(RACDB))
            System.out.println("poolTest() - found: " + RACDB);
        else
          {
            int idx = db.getPoolInfo().indexOf("RAC DB:");
            String dbFound = db.getPoolInfo().substring( idx + 8 , idx+13);
              // assertFalse will fail if the checked value is ture  and assertTrue will do the opposite
            assertFalse("poolTest() does not found: " + RACDB +  " - found: " + dbFound,true);
          }
        System.out.println("-------------- poolTest() finished --------------");
      }
    }


Code details :

@RunWith(Arquillian.class)
-> Junit will use Arquillian runner to execute this class

private static final String LOCAL_MAVEN_REPO .. 
-> LOCAL_MAVEN_REPO defines our local Maven repository storing JDBC,UCP and ONS Maven archetypes

WebArchive res = ShrinkWrap.create(WebArchive.class, "testDriverBean.war");
-> Creates a Webarchive named testDriverBean.war. This War will be deployed to our Wildfly server  

res.addAsLibraries(new File(LOCAL_MAVEN_REPO + "/com/oracle/ojdbc7/12.1.0.2/ojdbc7-12.1.0.2.jar"));
-> Adds a Maven archetype from our local Maven repository 

System.out.println(res.toString(true));    
-> Display the content of our "testDriverBean.war" War file

@Inject DriverBean db;
--> Inject DriverBean

Run the test Class

Deployment step createTestArchive() should create the following output: 
Running TestDriverBean
****************** Inside createTestArchive()
****************** Local Maven Repsository: /home/oracle/.m2/repository
testDriverBean.war:
/WEB-INF/
/WEB-INF/lib/
/WEB-INF/lib/ons-12.1.0.2.jar
/WEB-INF/lib/ucp-12.1.0.2.jar
/WEB-INF/lib/ojdbc7-12.1.0.2.jar
/WEB-INF/beans.xml
/WEB-INF/classes/
/WEB-INF/classes/com/
/WEB-INF/classes/com/hhu/
/WEB-INF/classes/com/hhu/DriverBean.class
/WEB-INF/classes/com/hhu/Tools.class
****************** Leaving createTestArchive()
 -> Here we can see that our Deploy Step really adds the needed JAR files to use 
    Oracle JDBC driver with ONS and UCP.
 
Running the Maven Unit Tests
$ mvn -e test 
Results :
Failed tests:   
  poolTest(TestDriverBean): poolTest() does not found: RAC DB: BANKB - found: BANKA
  driverTest2(TestDriverBean): expected null, but was:<<pre>Error in checkDriver()</pre><pre>This_is_not_the_Oracle_JDBC_driver_class from [Module "deployment.testDriverBean.war:main" from Service Module Loader]</pre><pre>java.lang.ClassNotFoundException: This_is_not_the_Oracle_JDBC_driver_class from [Module "deployment.testDriverBean.war:main" from Service Module Loader]
Tests run: 3, Failures: 2, Errors: 0, Skipped: 0
  -> Two out of our three tests  failed: 
     The failed test are :  poolTest(TestDriverBean) and   driverTest2(TestDriverBean)

Review driverTest() method
Source Code: 
@Test
    public void driverTest() throws Exception
      {
      System.out.println("-------------- driverTest() running ---------------");
      db.setPoolInfo(null);
      db.setJdbcInfo(null);
      db.setExceptInfo(null);
      db.setClname("oracle.jdbc.OracleDriver");  
      String drvRet =db.checkDriver();     
      System.out.println("driverTest() - return         : " + drvRet );
      System.out.println("driverTest() - JDBC INFO      : " + db.getJdbcInfo() );
      System.out.println("driverTest() - Exception INFO : " + db.getExceptInfo() );  
      assertNull( db.getExceptInfo());
      System.out.println("-------------- driverTest() finished --------------");             
      }
Methode  driverTest() - prints out the following to Wildfly Server logs
14:26:40,760 INFO  [stdout] (default task-4) -------------- driverTest() running ---------------
14:26:40,761 INFO  [stdout] (default task-4) driverTest() - return         : index
14:26:40,762 INFO  [stdout] (default task-4) driverTest() - JDBC INFO      : 
                                            <pre>JDBC Driver Check - Loading Driver class ok : oracle.jdbc.OracleDriver</pre>
                                            <pre>JDK Version: 1.7.0_71</pre>
                                            <pre>ClassPath  : /usr/local/wildfly-8.2.0.Final/jboss-modules.jar</pre>
                                            <pre>Driver Name             : Oracle JDBC driver</pre>
                                            <pre>Driver Version          : 12.1.0.2.0</pre>
                                            <pre>Database Product Version: Oracle Database 12c Enterprise Edition Release 12.1.0.2.0 - 64bit Production
14:26:40,762 INFO  [stdout] (default task-4) With the Partitioning, Real Application Clusters, Automatic Storage Management, OLAP,
14:26:40,762 INFO  [stdout] (default task-4) Advanced Analytics and Real Application Testing options</pre>
14:26:40,762 INFO  [stdout] (default task-4) driverTest() - Exception INFO : null
14:26:40,763 INFO  [stdout] (default task-4) -------------- driverTest() finished --------------
   --> This test runs successfully as we have provided the correct Classname for the Oracle JDBC driver !
    
Review driverTest2() method
Source Code: 
 public void driverTest2() throws Exception
      {
      System.out.println("-------------- driverTest2() running - Creating a Class not found Exception ---------------");   
         // this creates a ClassNotFoundException
      db.setClname("This_is_not_the_Oracle_JDBC_driver_class");  
      db.setPoolInfo(null);
      db.setJdbcInfo(null);
      db.setExceptInfo(null);
      String drvRet = db.checkDriver();
      System.out.println("driverTest2() - return         : " + drvRet );
      System.out.println("driverTest2() - JDBC INFO      : " + db.getJdbcInfo() );
      System.out.println("driverTest2() - Exception INFO : " + db.getExceptInfo() );     
      assertNull( db.getExceptInfo());
      System.out.println("-------------- driverTest2() finished --------------");          
      }
 ->  - db.checkDriver() does not throw an exception as checkDriver() is a top level JSF function.
     - Instead all Exceptions are stored in an Exception String. 
     - If all works  db.getExceptInfo() should be still a null string. 
     - If not  db.getExceptInfo() returns the  Exception and the later  JUnit test:
: 
          assertNull( db.getExceptInfo());  will fail

Methode  driverTest2() - prints out the following to Wildfly Server logs
14:43:14,483 INFO  [stdout] (default task-5) -------------- driverTest2() running - Creating a Class not found Exception ---------------
14:43:14,486 INFO  [stdout] (default task-5) driverTest2() - return         : index
14:43:14,486 INFO  [stdout] (default task-5) driverTest2() - JDBC INFO      : null
14:43:14,486 INFO  [stdout] (default task-5) driverTest2() - Exception INFO : <pre>Error in checkDriver()</pre><pre>This_is_not_the_Oracle_JDBC_driver_class from [Module "deployment.testDriverBean.war:main" from Service Module Loader]</pre><pre>java.lang.ClassNotFoundException: This_is_not_the_Oracle_JDBC_driver_class from [Module "deployment.testDriverBean.war:main" from Service Module Loader]
14:43:14,487 INFO  [stdout] (default task-5)     at org.jboss.modules.ModuleClassLoader.findClass(ModuleClassLoader.java:213)
14:43:14,487 INFO  [stdout] (default task-5)     at org.jboss.modules.ConcurrentClassLoader.performLoadClassUnchecked(ConcurrentClassLoader.java:459)
14:43:14,487 INFO  [stdout] (default task-5)     at org.jboss.modules.ConcurrentClassLoader.performLoadClassChecked(ConcurrentClassLoader.java:408)
14:43:14,487 INFO  [stdout] (default task-5)     at org.jboss.modules.ConcurrentClassLoader.performLoadClass(ConcurrentClassLoader.java:389)
14:43:14,487 INFO  [stdout] (default task-5)     at org.jboss.modules.ConcurrentClassLoader.loadClass(ConcurrentClassLoader.java:134)
14:43:14,487 INFO  [stdout] (default task-5)     at java.lang.Class.forName0(Native Method)
14:43:14,488 INFO  [stdout] (default task-5)     at java.lang.Class.forName(Class.java:191)
14:43:14,488 INFO  [stdout] (default task-5)     at com.hhu.DriverBean.checkDriver(DriverBean.java:163)
--> The stack shows we are failing in line 163 com.hhu.DriverBean.checkDriver because assertNull( db.getExceptInfo()); founds 
    that db.getExceptInfo() is not null 

Review poolTest() method
Source Code: 
    @Test
    public void poolTest() throws Exception
      {
        System.out.println("-------------- poolTest() running ---------------");
        db.setPoolInfo(null);
        db.setExceptInfo(null);
        db.setJdbcInfo(null);
        String drvRet =db.initPool();     
        System.out.println("poolTest() - return         : " + drvRet );
        System.out.println("poolTest() - Pool INFO      : " + db.getPoolInfo() );
        System.out.println("poolTest() - Exception INFO : " + db.getExceptInfo() );
        String RACDB = "RAC DB: BANKB";
        if ( db.getPoolInfo().contains(RACDB))
            System.out.println("poolTest() - found: " + RACDB);
        else
          {
            int idx = db.getPoolInfo().indexOf("RAC DB:");
            String dbFound = db.getPoolInfo().substring( idx + 8 , idx+13);
              // assertFalse will fail if the checked value is ture  and assertTrue will do the opposite
            assertFalse("poolTest() does not found: " + RACDB +  " - found: " + dbFound,true);
          }
        System.out.println("-------------- poolTest() finished --------------");
      }
    }
Methode  poolTest() - prints out the following to Wildfly Server logs
14:43:12,559 INFO  [stdout] (default task-10) -------------- poolTest() running ---------------
14:43:13,129 INFO  [oracle.ucp.common.UniversalConnectionPoolBase] (default task-10) inactive connection timeout timer scheduled
14:43:14,382 INFO  [stdout] (default task-10) poolTest() - return         : index
14:43:14,385 INFO  [stdout] (default task-10) poolTest() - Pool INFO      : <pre>Initializing UCP Pool in progress ...</pre>
            <pre>UCP Pool initialized ! </pre>   RAC DB: BANKA
            <pre>Instance Name:bankA_2 - Host: hract22.example.com</pre>
            <pre>Instance Name:bankA_1 - Host: hract21.example.com</pre>
            <pre>Instance Name:bankA_1 - Session Count 1</pre>
            <pre>Instance Name:bankA_2 - Session Count 49</pre>
14:43:14,386 INFO  [stdout] (default task-10) poolTest() - Exception INFO : null
--> poolTest() found RAC DB: BANKA but tested for Database name BANKB. 
    This makes assertFalse() failing and reporting a test failure !
    Note:  In this case we will not reach the statement : 
        System.out.println("-------------- poolTest() finished --------------");
    The Assert itself reports :  
    Failed tests:   poolTest(TestDriverBean): poolTest() does not found: RAC DB: BANKB - found: BANKA
    

 Summary

• run Maven at least with -e switch to get a stack trace
• careeful read the  Maven test summary :  Tests run: 3, Failures: 2, Errors: 0, Skipped: 0, Time elapsed: 10.197 sec <<< FAILURE! –> Results-> Failed tests
• Check the Server logfile for stack traces

Download Source

Project Object Modul           ./pom.xml
Arquillian Config file         ./src/main/resources/arquillian.xml
JSF file                       ./src/main/webapp/index.xhtml 
Java Test program              ./src/test/java/TestDriverBean.java  
Java Bean                      ./src/main/java/com/hhu/DriverBean.java 

Reference

• Arquillian tutorial
• Arquillian Guides
• Arquillian with Wildfly 8
• Arquillian Guides –  Testing Java Persistence
• JUnit API
• How do I add JAR files to the test archive?
• ShrinkWrap Resolvers
• Java EE7 and Maven project for newbies – part 5
• Maven Dependency Management

Overview

• This Framework is easily extensible to test add. UCP features
• Currently Implemented Features are : FCF, Standard Pool Operations, some Timeouts
• Note: Using XA Datasoruce and UCP does not work with Wildfly !!
  
• The Framework display Instance Status, Session Status, Pool Status and FCF Status
• All top level function starting with jsf* should catch all excepetions and display these Exceptions via an Exception Window
• getConnection() initializes the Pooled Datasource  and returns a Connection object
• getConnection() stores the Pooled Datasource in a static variable and it is only loaded once per JVM during first usage of UCPPoolBean class
• initPool() creates and starts the named UCP pool :   my_ucp_pool
• Following UCP Pool Operations are supported : INIT  STOP  START  DESTROY  PURGE REFRESH
• The JNDI functions creates its own JNDI entry named:  java:global/myUcpDs
• The Code expects that you have created a Datasource named myRacDS
• This Datasource is created via Annotations:  @Resource(lookup=”java:jboss/datasources/myRacDS”)  
• Above mentioned datasource myRACDS is only used in jsfCheckDriver() function and works even without the UCP POOL
• Take A first look on the Operation Panel – Click on the image to see details !

Source Code:  getConnection() –  An important Code Detail

Central part of the Java Code is the getConnection() Function     
public class UcpPoolBean
    {
    private static oracle.ucp.jdbc.PoolDataSource pds = null;
    ..      
    public Connection getConnection() throws Exception
      {
        Connection c = null;
        if (pds == null )
          {
            setPoolStats("UCP POOL not yet initialized - creating  UCP pool in getConection()  !");
            initPool();
              // This is just an informational message that the Pooled Datasource was recreated !              
            genericExp("INFO: UCP pool created via getConnection() as Pooled DataSource == null ! ", null);
          }
        if ( pds == null )
            genericExp("FATAL: Pooled DataSource == null after init in getConnection()  ", null);       
        else
            c = pds.getConnection();
         return c;
      }

Framework: Generic Display Options

Instance status :  

11:51:32.479:    RAC DB: BANKA
Instance Name:bankA_1 - Host: hract21.example.com
Instance Name:bankA_2 - Host: hract22.example.com
Instance Name:bankA_1 - Session Count 5
Instance Name:bankA_2 - Session Count 2

UCP Pool status :    
Press -> Check UCP Pool Status 
11:52:49.906: Intialized Pooled DS: oracle.ucp.jdbc.PoolDataSourceImpl@932eae2
11:52:49.907: Available Pools:  my_ucp_pool
11:52:49.907:   Connection Count : Total : 5 - Available: 5 - Borrowed: 0
11:52:49.907:   Pools Size       : Inital: 5 - Min      : 5 - Max     : 10
11:52:49.907:   PoolLifeCycle state:  Running
11:52:49.907:   InactiveConnectionTimeout: 30 - AbandonedConnectionTimeout: 10
     
Session Info :      
12:04:46.824: Available Connections in UCP POOL: 5
12:04:46.876: Instance Name:bankA_2 - Host: hract22.example.com
12:04:46.944: Instance Name:bankA_1 - Host: hract21.example.com
12:04:46.946: Instance Name:bankA_2 - Host: hract22.example.com
12:04:46.948: Instance Name:bankA_1 - Host: hract21.example.com
12:04:46.950: Instance Name:bankA_2 - Host: hract22.example.com

To display all of the above statistics press : 

Testing Abandon Connection Timeout

The abandoned connection timeout (ACT) enables borrowed connections to be
reclaimed back into the connection pool after a connection has not been used for a
specific amount of time. Abandonment is determined by monitoring calls to the
database. This timeout feature helps maximize connection reuse and conserves system
resources that are otherwise lost on maintaining borrowed connections that are no
longer in use.

Settings:
Set Connection Count         : 5   
Abandoned Connection Timeout : 10 [seconds ]
   
UCP Pool Status:
12:31:41.341: Intialized Pooled DS: oracle.ucp.jdbc.PoolDataSourceImpl@932eae2
12:31:41.341: Available Pools:  my_ucp_pool
12:31:41.341:   Connection Count : Total : 5 - Available: 0 - Borrowed: 5
12:31:41.341:   Pools Size       : Inital: 5 - Min      : 5 - Max     : 10
12:31:41.341:   PoolLifeCycle state:  Running
12:31:41.341:   InactiveConnectionTimeout: 30 - AbandonedConnectionTimeout: 10
12:31:41.341: Connections in static ArrayList  jsfOpenConnections(): 5
12:31:41.341: jsfOpenConnections(): Connection - Opened:  5
-> 5 connections are now in use !

Session INFO :
12:31:41.335: jsfOpenConnections(): Connections newly Opened:  5
12:31:41.335: verifyConnections() - Connections in static ArrayList :
12:31:41.336: Instance Name:bankA_2 - Host: hract22.example.com
12:31:41.336: Instance Name:bankA_2 - Host: hract22.example.com
12:31:41.339: Instance Name:bankA_2 - Host: hract22.example.com
12:31:41.340: Instance Name:bankA_1 - Host: hract21.example.com
12:31:41.340: Instance Name:bankA_2 - Host: hract22.example.com

Now wait about 30 seconds and press : 

12:35:27.493: Intialized Pooled DS: oracle.ucp.jdbc.PoolDataSourceImpl@932eae2
12:35:27.494: Available Pools:  my_ucp_pool
12:35:27.494:   Connection Count : Total : 5 - Available: 5 - Borrowed: 0
12:35:27.494:   Pools Size       : Inital: 5 - Min      : 5 - Max     : 10
12:35:27.494:   PoolLifeCycle state:  Running
12:35:27.494:   InactiveConnectionTimeout: 30 - AbandonedConnectionTimeout: 10
-> The connections are reclaimed by the UCP pool after reaching the timeout

Verify the connection status by pressing : 

Exceptions :
12:37:12.567: Error in retSessionInfo() - Failed SQL:
12:37:12.567: The connection is closed: The connection is closed
12:37:12.568: java.sql.SQLException: The connection is closed: The connection is closed
at oracle.ucp.util.UCPErrorHandler.newSQLException(UCPErrorHandler.java:464)
at oracle.ucp.util.UCPErrorHandler.newSQLException(UCPErrorHandler.java:448)
at oracle.ucp.jdbc.proxy.JDBCConnectionProxyFactory.invoke(JDBCConnectionProxyFactory.java:307)
at oracle.ucp.jdbc.proxy.ConnectionProxyFactory.invoke(ConnectionProxyFactory.java:50)
at com.sun.proxy.$Proxy17.createStatement(Unknown Source)
at UcpPool.UcpPoolBean.retSessionInfo(UcpPoolBean.java:1201)
at UcpPool.UcpPoolBean.verifyConnections(UcpPoolBean.java:1113)
-> The connections are reclaimed by the pool - Note : the above Exception is expected !

Release the stale Connections 
Finally Press   to cleanup the static Connection Pool Array

The Release Operation should report:
12:43:33.146: Connections in static ArrayList  jsfCloseConnections(): 0
12:43:33.146: jsfCloseConnections(): Connections Closed:  1

Testing Inactive Connection Timeout

The inactive connection timeout specifies how long an available connection can remain
idle before it is closed and removed from the pool. This timeout property is only
applicable to available connections and does not affect borrowed connections. This
property helps conserve resources that are otherwise lost on maintaining connections
that are no longer being used. The inactive connection timeout (together with the
Note: UCP for JDBC either cancels or rolls back connections that
have local transactions pending before reclaiming connections for
reuse.

Settings: 
Set Connection Count       :  4  
Inactive Connection Timeout:     30
Press 2x:  
Press 2x:  

UCP Pool Status :     
12:54:32.053: Intialized Pooled DS: oracle.ucp.jdbc.PoolDataSourceImpl@359db23
12:54:32.054: Available Pools:  my_ucp_pool
12:54:32.054:   Connection Count : Total : 8 - Available: 8 - Borrowed: 0
12:54:32.054:   Pools Size       : Inital: 5 - Min      : 5 - Max     : 10
12:54:32.054:   PoolLifeCycle state:  Running
12:54:32.054:   InactiveConnectionTimeout: 30 - AbandonedConnectionTimeout: 10
12:54:32.054: Connections in static ArrayList  jsfCloseConnections(): 0
12:54:32.054: jsfCloseConnections(): Connections Closed:  4

Session Info :     
12:57:24.381: Available Connections in UCP POOL: 8
12:57:24.383: Instance Name:bankA_1 - Host: hract21.example.com
12:57:24.384: Instance Name:bankA_2 - Host: hract22.example.com
12:57:24.385: Instance Name:bankA_2 - Host: hract22.example.com
12:57:24.386: Instance Name:bankA_1 - Host: hract21.example.com
12:57:24.387: Instance Name:bankA_2 - Host: hract22.example.com
12:57:24.388: Instance Name:bankA_2 - Host: hract22.example.com
12:57:24.389: Instance Name:bankA_2 - Host: hract22.example.com
12:57:24.390: Instance Name:bankA_1 - Host: hract21.example.com
-> The UCP Connection Count is increased to 8 !

Now wait about 60 seconds:
UCP Pool status :     
12:58:19.972: Intialized Pooled DS: oracle.ucp.jdbc.PoolDataSourceImpl@359db23
12:58:19.972: Available Pools:  my_ucp_pool
12:58:19.972:   Connection Count : Total : 5 - Available: 5 - Borrowed: 0
12:58:19.972:   Pools Size       : Inital: 5 - Min      : 5 - Max     : 10
12:58:19.973:   PoolLifeCycle state:  Running
12:58:19.973:   InactiveConnectionTimeout: 30 - AbandonedConnectionTimeout: 10
-> UCP Pool has reduced the Connection Count to 5 from 8 

Testing Pool Limits

Settings:
Set Connection Count       :  4  
Press  3x                  : 

UCP Pool status :     
13:00:08.544: Intialized Pooled DS: oracle.ucp.jdbc.PoolDataSourceImpl@359db23
13:00:08.544: Available Pools:  my_ucp_pool
13:00:08.544:   Connection Count : Total : 10 - Available: 0 - Borrowed: 10
13:00:08.544:   Pools Size       : Inital: 5 - Min      : 5 - Max     : 10
13:00:08.544:   PoolLifeCycle state:  Running
13:00:08.544:   InactiveConnectionTimeout: 30 - AbandonedConnectionTimeout: 10
13:00:08.544: Connections in static ArrayList  jsfOpenConnections(): 10
13:00:08.544: jsfOpenConnections(): Connection - Opened:  2   

Exceptions :
13:00:08.531: Error in openConnections() + Already opened Connections: 2
13:00:08.531: Exception occurred while getting connection: oracle.ucp.UniversalConnectionPoolException: 
              All connections in the Universal Connection Pool are in use
13:00:08.531: java.sql.SQLException: Exception occurred while getting connection: oracle.ucp.UniversalConnectionPoolException:
     All connections in the Universal Connection Pool are in use
    at oracle.ucp.util.UCPErrorHandler.newSQLException(UCPErrorHandler.java:479)
    at oracle.ucp.util.UCPErrorHandler.throwSQLException(UCPErrorHandler.java:154)
    at oracle.ucp.jdbc.PoolDataSourceImpl.getConnection(PoolDataSourceImpl.java:1127)
    at oracle.ucp.jdbc.PoolDataSourceImpl.getConnection(PoolDataSourceImpl.java:1031)
-> The lastest Allocate Connection request can only allocate 2 connections. 
   After that the get getConnection() fails with above Exception.

Testing UCP Purge Operation

UCP Pool status after Purge  :     

13:04:23.530: Intialized Pooled DS: oracle.ucp.jdbc.PoolDataSourceImpl@57e31b7
13:04:23.530: Available Pools:  my_ucp_pool
13:04:23.531:   Connection Count : Total : 0 - Available: 0 - Borrowed: 0
13:04:23.531:   Pools Size       : Inital: 5 - Min      : 5 - Max     : 10
13:04:23.531:   PoolLifeCycle state:  Running
13:04:23.531:   InactiveConnectionTimeout: 30 - AbandonedConnectionTimeout: 10
13:04:23.531: Connections in static ArrayList after openConnections(): 0
13:04:23.531: Connections remaining in static ArrayList after closeConnections() : 0
13:04:23.531: checkSessionInPool(): Connection - Opened:  0 - Closed: 10       
 -> After a purge pool operation all connections get closed and the pool  
    Total Connection Count is : 0 even MinPoolSize is set to 5 !

Reallocate the connections :
Set Connection Count       :  5  
Press  1x                  : 
Press  1x                  : 

UCP Pool Status :
13:07:02.775: Intialized Pooled DS: oracle.ucp.jdbc.PoolDataSourceImpl@57e31b7
13:07:02.775: Available Pools:  my_ucp_pool
13:07:02.775:   Connection Count : Total : 5 - Available: 5 - Borrowed: 0
13:07:02.775:   Pools Size       : Inital: 5 - Min      : 5 - Max     : 10
13:07:02.775:   PoolLifeCycle state:  Running
13:07:02.775:   InactiveConnectionTimeout: 30 - AbandonedConnectionTimeout: 10
13:07:02.775: Connections in static ArrayList  jsfCloseConnections(): 0
13:07:02.775: jsfCloseConnections(): Connections Closed:  5    

Testing UCP Refresh Operation

Current Pool Status
13:08:46.268: Intialized Pooled DS: oracle.ucp.jdbc.PoolDataSourceImpl@57e31b7
13:08:46.268: Available Pools:  my_ucp_pool
13:08:46.269:   Connection Count : Total : 5 - Available: 5 - Borrowed: 0
13:08:46.269:   Pools Size       : Inital: 5 - Min      : 5 - Max     : 10
13:08:46.269:   PoolLifeCycle state:  Running
13:08:46.269:   InactiveConnectionTimeout: 30 - AbandonedConnectionTimeout: 10
13:08:46.269: Connections in static ArrayList after openConnections(): 0
13:08:46.269: Connections remaining in static ArrayList after closeConnections() : 0
13:08:46.269: checkSessionInPool(): Connection - Opened:  5 - Closed: 5

Session Info :     
13:08:46.258: Available Connections in UCP POOL: 5
13:08:46.262: Instance Name:bankA_1 - Host: hract21.example.com
13:08:46.264: Instance Name:bankA_2 - Host: hract22.example.com
13:08:46.266: Instance Name:bankA_1 - Host: hract21.example.com
13:08:46.267: Instance Name:bankA_2 - Host: hract22.example.com
13:08:46.268: Instance Name:bankA_1 - Host: hract21.example.com

Press : 
13:10:03.940: Available Connections in UCP POOL: 5
13:10:03.940: Instance Name:bankA_2 - Host: hract22.example.com
13:10:03.942: Instance Name:bankA_2 - Host: hract22.example.com
13:10:03.943: Instance Name:bankA_2 - Host: hract22.example.com
13:10:03.945: Instance Name:bankA_1 - Host: hract21.example.com
13:10:03.945: Instance Name:bankA_2 - Host: hract22.example.com
-> Refresh UCP Pool has closed and recreated the physical Connections 
   The connections point now to different RAC instances.

Testing FCF functionality

Current UCP Pool status :     
11:42:07.415: Intialized Pooled DS: oracle.ucp.jdbc.PoolDataSourceImpl@44d2df43
11:42:07.415: Available Pools:  my_ucp_pool
11:42:07.416:   Connection Count : Total : 5 - Available: 5 - Borrowed: 0
11:42:07.416:   Pools Size       : Inital: 5 - Min      : 5 - Max     : 10
11:42:07.416:   PoolLifeCycle state:  Running
11:42:07.416:   InactiveConnectionTimeout: 30 - AbandonedConnectionTimeout: 10
11:42:07.416: Connections in static ArrayList after openConnections(): 0
11:42:07.416: Connections remaining in static ArrayList after closeConnections() : 0
11:42:07.416: checkSessionInPool(): Connection - Opened:  5 - Closed: 5

Session Info :     
11:42:07.313: Available Connections in UCP POOL: 5
11:42:07.317: Instance Name:bankA_2 - Host: hract22.example.com
11:42:07.319: Instance Name:bankA_2 - Host: hract22.example.com
11:42:07.321: Instance Name:bankA_2 - Host: hract22.example.com
11:42:07.413: Instance Name:bankA_3 - Host: hract21.example.com
11:42:07.415: Instance Name:bankA_3 - Host: hract21.example.com
-> All UCP session are  equally distributed on both available RAC instances 

Now stop one of the instances 
[oracle@hract21 ~]$ srvctl stop instance -db banka -n hract22 -o abort

Verify Session Info again  :     
11:44:39.005: Available Connections in UCP POOL: 5
11:44:39.124: Instance Name:bankA_3 - Host: hract21.example.com
11:44:39.127: Instance Name:bankA_3 - Host: hract21.example.com
11:44:39.129: Instance Name:bankA_3 - Host: hract21.example.com
11:44:39.130: Instance Name:bankA_3 - Host: hract21.example.com
11:44:39.132: Instance Name:bankA_3 - Host: hract21.example.com
-> As expected - all UCP sessions are now pointing to the surviving instance.
   Note: We don't need a server roundtrip for this operation - ONS does a great job here ! 
    
FCF Info:
11:44:39.133:  FCF status:  {Apr 11, 2015 11:44 AM SUCCESS      
    Connections:(Available=5 Opened=2 FailedToProcess=0 MarkedDown=0 Closed=2)(Borrowed=0 FailedToProcess=0 MarkedDown=0 Closed=0)}


Restart Instance  and Refresh the pool
[oracle@hract21 ~]$ srvctl start instance -db banka -n hract22

Press : 
11:57:14.914: Available Connections in UCP POOL: 5
11:57:14.915: Instance Name:bankA_2 - Host: hract22.example.com
11:57:14.916: Instance Name:bankA_3 - Host: hract21.example.com
11:57:14.917: Instance Name:bankA_2 - Host: hract22.example.com
11:57:14.918: Instance Name:bankA_3 - Host: hract21.example.com
11:57:14.919: Instance Name:bankA_2 - Host: hract22.example.com
-> All UCP session are now again equally redistributed on both RAC instances 

Testing  JNDI

• The Framework uses ctx.bind() to temporary create a JNDI entry on the fly
• After ctx.bind() the Framework use ctx.lookup() to create the pooled Datasource
• Run ctx.lookup() only once and store the created Pooled Datasource in a static variable for re-using.
• Note: After a JVM reboot the JNDI resource/UCP Pool must be recreated running rebindPool() and lookupPool()
• The JNDI functions create its own JNDI entry named: java:global/myUcpDs

Complete JAVA Code for JNDI lookup

private static oracle.ucp.jdbc.PoolDataSource pds = null;
   public void lookupPool() throws Exception
      {
        if ( pds != null)
          {
            setPoolStats(Tools.add_hmtl_pre_tag("Pooled Datasource already exist - don't run ctx.lookup() again  "));
            return;
          }    
        cleanAll();
        setPoolStats(Tools.add_hmtl_pre_tag("Testing UPC Pool via JNDI in progress JNDI name: " +  jndiName));
        ctx = new InitialContext();  
        pds = (PoolDataSource)ctx.lookup("java:global/myUcpDs");
        checkAll();
        setPoolStats(getPoolStats() + Tools.add_hmtl_pre_tag("lookupPool(): Pooled Datasource initialized: " + jndiName ));
      }
       
    public void rebindPool() throws Exception
      {
        pds =null;
        cleanAll();                                 
        UniversalConnectionPoolManager ucpMgr = createPoolManager();
        if ( ucpMgr == null)
          {
            setPoolStats(Tools.add_hmtl_pre_tag("Could not create UCP Manager "));
            return;
          }            
        setPoolStats(Tools.add_hmtl_pre_tag("Destroying UCP Pool in progres ..."));
                // We need to destroy the pool first if the pool exist
                // If we recreate the pool without destroying we will get a session leak at the RAC layer
        try
          {    
            ucpMgr.destroyConnectionPool(poolName);
            setPoolStats(getPoolStats() + Tools.add_hmtl_pre_tag("UCP Pool destroyed !"));
          } catch ( Exception e2)         
          {
            setPoolStats(getPoolStats () +Tools.add_hmtl_pre_tag("Exception during delete Pool - [ ignore the error]  "  ));  
                  // genericExp("Execption duringe deleteing pool - If pool does not exists ignore this exception ",  e2);
          }  
        ctx = new InitialContext();
        PoolDataSource lpds = setupPooledDS();
            // ucpMgr.createConnectionPool((UniversalConnectionPoolAdapter)pds);
        ctx.rebind(jndiName, lpds);
        setPoolStats(getPoolStats () +Tools.add_hmtl_pre_tag("JNDI context rebind ok for :  " + jndiName ));  
            // Disable JMX - if needed
             // ucpManager.setJmxEnabled(false);
            // ucpManager.createConnectionPool((UniversalConnectionPoolAdapter)pds);                                                                              
        return;
      }
        
   public  PoolDataSource setupPooledDS() throws Exception
      {
        
        PoolDataSource lpds = oracle.ucp.jdbc.PoolDataSourceFactory.getPoolDataSource();        
         //set the connection properties on the data source and pool properties
        String ONS_CONFIG = "nodes=hract21:6200,hract22:6200,hract23:6200";
        lpds.setONSConfiguration ( ONS_CONFIG);
        lpds.setFastConnectionFailoverEnabled( true);
        lpds.setUser("scott");
        lpds.setPassword("tiger");
        lpds.setURL("jdbc:oracle:thin:@ract2-scan.grid12c.example.com:1521/banka");
        lpds.setConnectionFactoryClassName("oracle.jdbc.pool.OracleDataSource"); 
        lpds.setInitialPoolSize(minPoolSize);
        lpds.setMinPoolSize(minPoolSize);
        lpds.setMaxPoolSize(maxPoolSize);
        lpds.setAbandonedConnectionTimeout(abandonedConnectionTimeout);
        lpds.setInactiveConnectionTimeout(inactiveConnectionTimeout);
        lpds.setTimeoutCheckInterval(10);
        lpds.setConnectionPoolName(poolName);
        return lpds;
      } 

JNDI: Use Case I – Destroy Pooled DS and recreate UCP Pool

Destroy UCP Pool :  my_ucp_pool            [  but don't run Unbind UCP Pool via JNDI ]    
Lookup UCP Pool via JNDI  :       
16:49:48.930: Intialized Pooled DS: oracle.ucp.jdbc.PoolDataSourceImpl@7ffa742a
16:49:48.930: Available Pools:  my_ucp_pool
16:49:48.930:   Connection Count : Total : 5 - Available: 5 - Borrowed: 0
16:49:48.930:   Pools Size       : Inital: 5 - Min      : 5 - Max     : 10
16:49:48.930:   PoolLifeCycle state:  Running
16:49:48.930:   InactiveConnectionTimeout: 30 - AbandonedConnectionTimeout: 10
16:49:48.930: Connections in static ArrayList after openConnections(): 0
16:49:48.930: Connections remaining in static ArrayList after closeConnections() : 0
16:49:48.930: checkSessionInPool(): Connection - Opened:  5 - Closed: 5
16:49:48.930: lookupPool(): Pooled Datasource initialized: java:global/myUcpDs

-> After destruction of UCP pool the pool can be re-created by runing lookupPool()
   Note: A destruction of the UCP pool does not delete the JNDI entry.

JNDI: Use Case II – Destropy Pooled DS, Unbind JNDI and recreate JNDI and UCP Pool

Destroy UCP Pool :  my_ucp_pool          
Unbind JNDI      :  java:global/myUcpDs  
Lookup UCP Pool via JNDI  fails:         

16:28:12.673: Exception inside lookupPool() :  JNDI Lookup 
16:28:12.673: myUcpDs -- service jboss.naming.context.java.global.myUcpDs
16:28:12.673: javax.naming.NameNotFoundException: myUcpDs -- service jboss.naming.context.java.global.myUcpDs
    at org.jboss.as.naming.ServiceBasedNamingStore.lookup(ServiceBasedNamingStore.java:104)
    at org.jboss.as.naming.NamingContext.lookup(NamingContext.java:202)
    at org.jboss.as.naming.NamingContext.lookup(NamingContext.java:179)  
    
Solution: 
Rebind the Pooled Datasource :  
16:29:22.214: Destroying UCP Pool in progres ...
16:29:22.214: Exception during delete Pool - [ ignore the error]  
16:29:22.215: JNDI context rebind ok for :  java:global/myUcpDs

Run JNDI Lookup again :                 
16:29:48.930: Intialized Pooled DS: oracle.ucp.jdbc.PoolDataSourceImpl@7ffa742a
16:29:48.930: Available Pools:  my_ucp_pool
16:29:48.930:   Connection Count : Total : 5 - Available: 5 - Borrowed: 0
16:29:48.930:   Pools Size       : Inital: 5 - Min      : 5 - Max     : 10
16:29:48.930:   PoolLifeCycle state:  Running
16:29:48.930:   InactiveConnectionTimeout: 30 - AbandonedConnectionTimeout: 10
16:29:48.930: Connections in static ArrayList after openConnections(): 0
16:29:48.930: Connections remaining in static ArrayList after closeConnections() : 0
16:29:48.930: checkSessionInPool(): Connection - Opened:  5 - Closed: 5
16:29:48.930: lookupPool(): Pooled Datasource initialized: java:global/myUcpDs
-> After a JVM reboot or after deletion of UPC Pool and JNDI entry the UCP pool must be 
   recreated by calling rebindPool() and lookupPool().

Problem : JNDI lookup fails when calling lookup a 2.nd time

If you re-running the following JNDI code without destryoing the UCP pool first you will get an Exception
    public String lookupPool()
      {  
        cleanAll();
        setPoolStats(Tools.add_hmtl_pre_tag("Testing UPC Pool via JNDI in progress  "));
        genericExp("INFO:  JNDI Lookup doesn't work yet", null);
        try
          {
          ctx = new InitialContext();  
          pds = (PoolDataSource)ctx.lookup("java:global/myUcpDs");
          setPoolStats(getPoolStats() + Tools.add_hmtl_pre_tag("Testing UPC Pool via JNDI - Pooled Datasource initialized "));
          checkAll();
          } catch ( Exception e1)
              {
              genericExp("Exception inside lookupPool() :  JNDI Lookup ", e1);
            
              return "index";
              }
       
        setPoolStats(getPoolStats() + "- JNDI lookup ok  ! ");
        return "index";
      } 


1.st Run ( Note UCP pool was already destroyed )

Instance status :     RAC DB: BANKA
Instance Name:bankA_3 - Host: hract21.example.com
Instance Name:bankA_2 - Host: hract22.example.com
Instance Name:bankA_3 - Session Count 35
Instance Name:bankA_2 - Session Count 35

UCP Pool status :     
15:42:36.773: Initialized Pooled DS: oracle.ucp.jdbc.PoolDataSourceImpl@2daf23a3
15:42:36.773: Available Pools:  my_ucp_pool
15:42:36.773:   Connection Count : Total : 5 - Available: 5 - Borrowed: 0
15:42:36.773:   Pools Size       : Inital: 5 - Min      : 5 - Max     : 10
15:42:36.773:   PoolLifeCycle state:  Running
-> Status: UCP pool was created and started by  JNDI lookup
    
2.nd Run ( Note: UCP pool is already active ! )    
Exceptions :
15:48:09.493: Exception inside lookupPool() :  JNDI Lookup 
15:48:09.493: Unable to start the Universal Connection Pool: oracle.ucp.UniversalConnectionPoolException: 
   Error during pool creation in Universal Connection Pool Manager MBean: oracle.ucp.UniversalConnectionPoolException: 
   Error during pool creation in Universal Connection Pool Manager: oracle.ucp.UniversalConnectionPoolException: 
   Universal Connection Pool already exists in the Universal Connection Pool Manager. 
   Universal Connection Pool cannot be added to the Universal Connection Pool Manager
    at oracle.ucp.util.UCPErrorHandler.newSQLException(UCPErrorHandler.java:479)
    at oracle.ucp.util.UCPErrorHandler.throwSQLException(UCPErrorHandler.java:154)
    at oracle.ucp.jdbc.PoolDataSourceImpl.startPool(PoolDataSourceImpl.java:730)
    at oracle.ucp.jdbc.PoolDataSourceImpl.getConnection(PoolDataSourceImpl.java:1093)
    at oracle.ucp.jdbc.PoolDataSourceImpl.getConnection(PoolDataSourceImpl.java:1031)

Instance Status     
15:49:47.032:    RAC DB: BANKA
Instance Name:bankA_2 - Host: hract22.example.com
Instance Name:bankA_3 - Host: hract21.example.com
Instance Name:bankA_2 - Session Count 38
Instance Name:bankA_3 - Session Count 37    
    
-> The 2.nd run leads to a databases session leak
    
WA : Store the Pooled DataSource in a static variable and run lookup only a single time! 

Using XA Datasource with UCP and Wildfly fails with  loader constraint violation

Init XA Datasource:  
12:20:50.557: Initializing XA UCP Pool in progress ...
12:20:50.561: INFO : Jar File     for XAResource.class:jar:file:/usr/local/wildfly-8.2.0.Final/modules/system/layers/base/javax/transaction/api/main/jboss-transaction-api_1.2_spec-1.0.0.Final.jar!/javax/transaction/xa/XAResource.class
12:20:50.561: INFO : Class Loader for XAResource.class :ModuleClassLoader for Module "javax.transaction.api:main" from local module loader @7fe9a140 (finder: local module finder @4359b25b (roots: /usr/local/wildfly-8.2.0.Final/modules,/usr/local/wildfly-8.2.0.Final/modules/system/layers/base))
12:20:50.784: XA Initializing UCP Pool failed !

Exceptions :
12:20:50.784: Runtime exception in jsfInitPoolXA() : 
12:20:50.785: loader constraint violation: loader (instance of ) previously initiated loading for a different type with name "javax/transaction/xa/XAResource"
12:20:50.787: java.lang.LinkageError: loader constraint violation: loader (instance of ) previously initiated loading for a different type with name "javax/transaction/xa/XAResource"
    at java.lang.Class.getDeclaredMethods0(Native Method)
    at java.lang.Class.privateGetDeclaredMethods(Class.java:2615)
    at java.lang.Class.privateGetPublicMethods(Class.java:2733)
    at java.lang.Class.getMethods(Class.java:1472)
    at sun.misc.ProxyGenerator.generateClassFile(ProxyGenerator.java:426)
    at sun.misc.ProxyGenerator.generateProxyClass(ProxyGenerator.java:323

For Details please check ... 
 Debugging UCP Connection Pool using XA Datasource pointing to a RAC database - http://www.hhutzler.de/blog/debugging-ucp-connection-pool-using-xa-datasource-pointing-to-a-rac-database/

Source Code

 JSF code:   index.xhtml      
 Java Code:  UcpPoolBean.java 

JAVADOC

• UCPPoolBean Javadoc Reference

Reference

• Create and Manage a RAC Datasource with WildFly
• How to integrate the Oracle JDBC driver as a Wildfly module ?
• Wildfly: Testing Oracle JDBC driver UCP Connection pool setup with Arquillian/JUnitWildfly
• Debugging UCP Connection Pool using XA Datasource pointing to a RAC database
• UCP Developers Guide : https://docs.oracle.com/database/121/JJUCP/E49541-01.pdf

Purpose of this tutorial

• Create and test a  RAC datasoure with WildFly jboss-cli.sh command utility
• Deploy and integrate the Oracle JDBC driver as a Wildfly Module
• Run a short Web application to display JDBC driver and Oracle Database version  

Deploying the Oracle JDBC Driver as a Wildfly module

Prepare module.xml and copy ojdbc7.jar to its destination
[oracle@wls1 ~]$ ls /usr/local/wildfly-8.2.0.Final/modules/com/oracle/ojdbc/main/
module.xml  ojdbc7.jar

[oracle@wls1 ~]$ cat /usr/local/wildfly-8.2.0.Final/modules/com/oracle/ojdbc/main/module.xml
?xml version="1.0" ?>
<module xmlns="urn:jboss:module:1.1" name="com.oracle.ojdbc">
    <resources>
        <resource-root path="ojdbc7.jar"/>
    </resources>
    <dependencies>
        <module name="javax.api"/>
        <module name="javax.transaction.api"/>
    </dependencies>
</module>

--> Restart Wildfly and your Datasource and verify the Oracle Driver :

[oracle@wls1 WILDFLY]$ $WILDFLY_HOME/bin/jboss-cli.sh --connect  /subsystem=datasources:installed-drivers-list
{
    "outcome" => "success",
    "result" => [
        {
            "driver-name" => "oracle",
            "deployment-name" => undefined,
            "driver-module-name" => "com.oracle.ojdbc",
            "module-slot" => "main",
            "driver-datasource-class-name" => "",
            "driver-xa-datasource-class-name" => "oracle.jdbc.xa.client.OracleXADataSource",
            "driver-class-name" => "oracle.jdbc.OracleDriver",
            "driver-major-version" => 12,
            "driver-minor-version" => 1,
            "jdbc-compliant" => true
        }

Setup RAC datasource by using the RAC SCAN address
[oracle@wls1 WILDFLY]$ cat add_ds.cli
if (outcome != success) of /subsystem=datasources/data-source=myRacDS:read-resource
    data-source add \
        --name=myRacDS \
        --driver-name=oracle \
        --jndi-name=java:jboss/datasources/myRacDS \
        --user-name="scott"\
        --password="tiger"\
        --use-java-context=true \
        --use-ccm=true \
        --min-pool-size=5 \
        --max-pool-size=10 \
        --pool-prefill=true \
        --allocation-retry=1 \
        --prepared-statements-cache-size=32 \
        --share-prepared-statements=true \
        --connection-url="jdbc:oracle:thin:@ract2-scan.grid12c.example.com:1521/banka"
end-if

[oracle@wls1 WILDFLY]$ $WILDFLY_HOME/bin/jboss-cli.sh --connect --file=add_ds.cli

Test the connection
[oracle@wls1 WILDFLY]$   $WILDFLY_HOME/bin/jboss-cli.sh --connect   /subsystem=datasources/data-source=myRacDS:test-connection-in-pool
{
    "outcome" => "success",
    "result" => [true]
}

Check DS properties

[oracle@wls1 WILDFLY]$ $WILDFLY_HOME/bin/jboss-cli.sh --connect   /subsystem=datasources/data-source=myRacDS:read-resource
{
    "outcome" => "success",
    "result" => {
        "allocation-retry" => 1,
        "allocation-retry-wait-millis" => undefined,
        "allow-multiple-users" => false,
        "background-validation" => undefined,
        "background-validation-millis" => undefined,
        "blocking-timeout-wait-millis" => undefined,
        "capacity-decrementer-class" => undefined,
        "capacity-decrementer-properties" => undefined,
        "capacity-incrementer-class" => undefined,
        "capacity-incrementer-properties" => undefined,
        "check-valid-connection-sql" => undefined,
        "connection-listener-class" => undefined,
        "connection-listener-property" => undefined,
        "connection-properties" => undefined,
        "connection-url" => "jdbc:oracle:thin:@ract2-scan.grid12c.example.com:1521/banka",
        "datasource-class" => undefined,
        "driver-class" => undefined,
        "driver-name" => "oracle",
        "enabled" => true,
        "exception-sorter-class-name" => undefined,
        "exception-sorter-properties" => undefined,
        "flush-strategy" => undefined,
        "idle-timeout-minutes" => undefined,
        "initial-pool-size" => undefined,
        "jndi-name" => "java:jboss/datasources/myRacDS",
        "jta" => true,
        "max-pool-size" => 10,
        "min-pool-size" => 5,
        "new-connection-sql" => undefined,
        "password" => "tiger",
        "pool-prefill" => true,
        "pool-use-strict-min" => undefined,
        "prepared-statements-cache-size" => 32,
        "query-timeout" => undefined,
        "reauth-plugin-class-name" => undefined,
        "reauth-plugin-properties" => undefined,
        "security-domain" => undefined,
        "set-tx-query-timeout" => false,
        "share-prepared-statements" => true,
        "spy" => false,
        "stale-connection-checker-class-name" => undefined,
        "stale-connection-checker-properties" => undefined,
        "track-statements" => "NOWARN",
        "transaction-isolation" => undefined,
        "url-delimiter" => undefined,
        "url-selector-strategy-class-name" => undefined,
        "use-ccm" => true,
        "use-fast-fail" => false,
        "use-java-context" => true,
        "use-try-lock" => undefined,
        "user-name" => "scott",
        "valid-connection-checker-class-name" => undefined,
        "valid-connection-checker-properties" => undefined,
        "validate-on-match" => false,
        "statistics" => {
            "jdbc" => undefined,
            "pool" => undefined
        }
    }
}

If you need to remove the DS run: 
 $WILDFLY_HOME/bin/jboss-cli.sh --connect   /subsystem=datasources/data-source=myRacDS:remove

Test  Oracle JDBC driver from a JBOSS WEB application

Run the following JAVA code: 
 try
          {
            String clname= "oracle.jdbc.OracleDriver";
            Class.forName (clname);  
            setJdbcInfo( StackTraceUtil.add_hmtl_pre_tag( "JDBC Driver Check - Loading Driver class ok : " + clname));
            java.util.Properties props = System.getProperties();
            java.util.Enumeration propNames = props.propertyNames();
            setJdbcInfo(getJdbcInfo()  + StackTraceUtil.add_hmtl_pre_tag("JDK Version: " + props.getProperty("java.version")));
            setJdbcInfo(getJdbcInfo() + StackTraceUtil.add_hmtl_pre_tag( "ClassPath  : "  + props.getProperty("java.class.path")));
            Connection c = ds1.getConnection();
            java.sql.DatabaseMetaData md = c.getMetaData();
            setJdbcInfo(getJdbcInfo()  + StackTraceUtil.add_hmtl_pre_tag( "Driver Name             : "+md.getDriverName()));
            setJdbcInfo(getJdbcInfo()  + StackTraceUtil.add_hmtl_pre_tag( "Driver Version          : "+md.getDriverVersion()));
            setJdbcInfo(getJdbcInfo()  + StackTraceUtil.add_hmtl_pre_tag( "Database Product Version: " +md.getDatabaseProductVersion()));
            c.close();
          
          } catch ( Exception e1)
..
Very likely
Class.forName (clname);   throws the following Exceptions  in checkDriver()

oracle.jdbc.OracleDriver from [Module "deployment.WF_JdbcDriverTest.war:main" from Service Module Loader]
java.lang.ClassNotFoundException: oracle.jdbc.OracleDriver from [Module "deployment.WF_JdbcDriverTest.war:main" from Service Module Loader]
    at org.jboss.modules.ModuleClassLoader.findClass(ModuleClassLoader.java:213)
    at org.jboss.modules.ConcurrentClassLoader.performLoadClassUnchecked(ConcurrentClassLoader.java:459)
    at org.jboss.modules.ConcurrentClassLoader.performLoadClassChecked(ConcurrentClassLoader.java:408)
    at org.jboss.modules.ConcurrentClassLoader.performLoadClass(ConcurrentClassLoader.java:389)
    at org.jboss.modules.ConcurrentClassLoader.loadClass(ConcurrentClassLoader.java:134)
    at java.lang.Class.forName0(Native Method)
    at java.lang.Class.forName(Class.java:191)
    at DriverTest.DriverTestBean.checkDriver(DriverTestBean.java:54)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    at com.sun.el.parser.AstValue.invoke(AstValue.java:292)
    at com.sun.el.MethodExpressionImpl.invoke(MethodExpressionImpl.java:304)
    at com.sun.faces.facelets.el.TagMethodExpression.invoke(TagMethodExpression.java:105

Note if working with Datasources you may see following stack:
Caused by: oracle.ucp.UniversalConnectionPoolException: Error during pool creation in Universal Connection Pool Manager: java.sql.SQLException: Invalid Universal Connection Pool configuration: java.sql.SQLException: Unable to create factory class instance with provided factory class name: java.lang.ClassNotFoundException: oracle.jdbc.pool.OracleDataSource from [Module "deployment.WF_UCPPool.war:main" from Service Module Loader]
    at oracle.ucp.util.UCPErrorHandler.newUniversalConnectionPoolException(UCPErrorHandler.java:359)
    at oracle.ucp.util.UCPErrorHandler.throwUniversalConnectionPoolException(UCPErrorHandler.java:58)
    at oracle.ucp.admin.UniversalConnectionPoolManagerBase.createConnectionPool(UniversalConnectionPoolManagerBase.java:528)
    at UcpPool.UcpPoolBean.rebindPool(UcpPoolBean.java:289)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)

Detailed Problem description:

• Why is Module Loader looking for the JDBC driver ?
• We expect that Wildfly picks up the Oracle JDBC Driver as we have installed the JDBC Driver as a Module

  Note if have configured the  Oracle JDBC driver as a library in your WAR file the above code works fine .

Solution to integrate the Oracle JDBC Driver with Wildfly

Add a dependency to the Oralce JDBC driver module by adding  jboss-deployment-structure.xml 
under your WEB_INF folder:   
<?xml version="1.0" encoding="UTF-8"?>
<!--
To change this license header, choose License Headers in Project Properties.
To change this template file, choose Tools | Templates
and open the template in the editor.
-->

<jboss-deployment-structure>
  <deployment>
    <dependencies>
       <module name="com.oracle.ojdbc" />
    </dependencies>
   </deployment>
</jboss-deployment-structure>

Rerun the test program - ths JSF output should display the following : 

JDBC Driver Check - Loading Driver class ok : oracle.jdbc.OracleDriver
JDK Version: 1.7.0_71
ClassPath  : /usr/local/wildfly-8.2.0.Final/jboss-modules.jar
Driver Name             : Oracle JDBC driver
Driver Version          : 12.1.0.2.0
Database Product Version: Oracle Database 12c Enterprise Edition Release 12.1.0.2.0 - 64bit Production
With the Partitioning, Real Application Clusters, Automatic Storage Management, OLAP,
Advanced Analytics and Real Application Testing options

JSF code : index.xhtml

<?xml version='1.0' encoding='UTF-8' ?>
<!DOCTYPE html PUBLIC "-//W3C//DTD XHTML 1.0 Transitional//EN" "http://www.w3.org/TR/xhtml1/DTD/xhtml1-transitional.dtd">
<html xmlns="http://www.w3.org/1999/xhtml"
xmlns:h="http://xmlns.jcp.org/jsf/html">
<h:head>
<title>JDBC Driver Test</title>
</h:head>
<h:body>
<h:form>
<h:commandButton id="cBnt1" value="JDBC Driver Check"  action="#{driverTestBean.checkDriver}"></h:commandButton>
<hr color="blue"  size="3" width="90%" align="center"/>
<h:panelGrid columns="6" border="3">
<h:outputText style="color: red"  value="JDBC Driver Status :" />
<h:outputText  id="optxt1"  style="color: blue"  value="#{driverTestBean.jdbcInfo}" escape="false" />
</h:panelGrid>
<hr color="blue"  size="3" width="90%" align="center"/>
<h:outputText style="color: red"  value="Exceptions : "  escape="false"  />
<br/>
<h:outputText  id="optxt2"  style="color: red"  value="#{driverTestBean.exceptInfo}" escape="false" />
</h:form>

</h:body>
</html>

JAVA Code:  DriverTestBean.java

package DriverTest;

import java.io.PrintWriter;
import java.io.StringWriter;
import java.io.Writer;
import java.sql.Connection;
import javax.annotation.Resource;
import javax.faces.bean.ManagedBean;
import javax.faces.bean.SessionScoped;
import javax.sql.DataSource;

/**
 *
 * @author Helmut Hutzler 
 */
 @ManagedBean
 @SessionScoped
public class DriverTestBean
    {
    private String exceptInfo="";
    private String jdbcInfo="  -->  please Press JDBC Driver Check Button";
    @Resource(lookup="java:jboss/datasources/myRacDS")
    private DataSource ds1;
      
    public String getJdbcInfo()
      {
        return jdbcInfo;
      }

    public void setJdbcInfo(String jdbcInfo)
      {
        this.jdbcInfo = jdbcInfo;
      }
     
    public String getExceptInfo()
      {
        return exceptInfo;
      }

    public void setExceptInfo(String exceptInfo)
      {
        this.exceptInfo = exceptInfo;
      }
    public String checkDriver() throws Exception
      {
        try
          {
            String clname= "oracle.jdbc.OracleDriver";
            Class.forName (clname);  
            setJdbcInfo( StackTraceUtil.add_hmtl_pre_tag( "JDBC Driver Check - Loading Driver class ok : " + clname));
            java.util.Properties props = System.getProperties();
            java.util.Enumeration propNames = props.propertyNames();
            setJdbcInfo(getJdbcInfo()  + StackTraceUtil.add_hmtl_pre_tag("JDK Version: " + props.getProperty("java.version")));
            setJdbcInfo(getJdbcInfo() + StackTraceUtil.add_hmtl_pre_tag( "ClassPath  : "  + props.getProperty("java.class.path")));
            Connection c = ds1.getConnection();
            java.sql.DatabaseMetaData md = c.getMetaData();
            setJdbcInfo(getJdbcInfo()  + StackTraceUtil.add_hmtl_pre_tag( "Driver Name             : "+md.getDriverName()));
            setJdbcInfo(getJdbcInfo()  + StackTraceUtil.add_hmtl_pre_tag( "Driver Version          : "+md.getDriverVersion()));
            setJdbcInfo(getJdbcInfo()  + StackTraceUtil.add_hmtl_pre_tag( "Database Product Version: " +md.getDatabaseProductVersion()));
            c.close();
          
          } catch ( Exception e1)
              {
                generic_exp("Error in checkDriver()", e1);
              }
      
       return "index";
      }
    
    public void generic_exp(String ip, Exception e1)
      {
        if ( ip != null)
            setExceptInfo( StackTraceUtil.add_hmtl_pre_tag(ip));
        if ( e1 != null)
          {
            setExceptInfo(getExceptInfo() +  StackTraceUtil.add_hmtl_pre_tag(e1.getMessage()));
            setExceptInfo(getExceptInfo() +  StackTraceUtil.add_hmtl_pre_tag( StackTraceUtil.getStackTrace(e1)));
      
          } 
      }  
    
    }

 class StackTraceUtil 
  {

    public static String getStackTrace(Throwable aThrowable) 
      {
        final Writer result = new StringWriter();
        final PrintWriter printWriter = new PrintWriter(result);
        aThrowable.printStackTrace(printWriter);
        return result.toString();
     }
    
    public static String add_hmtl_pre_tag (String ip)
      {
        String op =  "<pre>"  + ip + "</pre>" ; 
        return op;        
      }      
  }

Reference

• https://developer.jboss.org/thread/199067?tstart=0