A deeper dive into JPA, 2-Phase-Commit [ 2PC ] and RAC

Overview JPA and 2-Phase-Commit

Mike Keith Architect at Oracle and Author  Pro JPA 2: Mastering the Java Persistence API (Second edition) summarizes the usage of JPA in a distributed evironment the following :

  • A JPA application will get the 2PC benefits the same as any other application
  • The peristence unit data source is using JTA and  is configured to use an XA data source
  • The XA resources and transaction manager 2PC interactions happen on their own without the JPA EMF knowing or having to be involved.
  • If a 2PC XA tx fails then an exception will be thrown just the same as if the tx was optimized to not have 2PC.

This was enough motivation for me working on Oracle RAC and JDBC projects to have a closer look on JPA and 2PC.

Versions used  / Configuration File persistence.xml

Wildfly:  8.2
Hibernate Version: 4.3.7.Final
--> Collecting Data for RAC database1
    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
    DB Name:  BANKA
    1. Instance Name: bankA_2 - Host: hract21.example.com - Pooled XA Connections: 61

--> Collecting Data for RAC database2
    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
    DB Name:  BANKB
    1. Instance Name: bankb_3 - Host: hract21.example.com - Pooled XA Connections: 62

persistence.xml

<?xml version="1.0"?>
<persistence xmlns="http://java.sun.com/xml/ns/persistence"
             xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
             xsi:schemaLocation="http://java.sun.com/xml/ns/persistence http://java.sun.com/xml/ns/persistence/persistence_2_0.xsd"
             version="2.0">

    <persistence-unit name="RacBankAHibPU" transaction-type="JTA">
        <provider>org.hibernate.ejb.HibernatePersistence</provider>
        <jta-data-source>java:/jboss/datasources/xa_rac12g_banka</jta-data-source>
        <class>com.hhu.wfjpa2pc.Accounts</class>
        <properties>
            <property name="hibernate.transaction.jta.platform"
                 value="org.hibernate.service.jta.platform.internal.JBossAppServerJtaPlatform" />
            <property name="hibernate.show_sql" value="true" />
            <property name="hibernate.dialect" value="org.hibernate.dialect.Oracle10gDialect"/>
        </properties>
    </persistence-unit>
    <persistence-unit name="RacBankBHibPU" transaction-type="JTA">
        <provider>org.hibernate.ejb.HibernatePersistence</provider>
        <jta-data-source>java:/jboss/datasources/xa_rac12g_bankb</jta-data-source>
        <class>com.hhu.wfjpa2pc.Accounts</class>
        <properties>
            <property name="hibernate.transaction.jta.platform"
                 value="org.hibernate.service.jta.platform.internal.JBossAppServerJtaPlatform" />
            <property name="hibernate.show_sql" value="true" />
            <property name="hibernate.dialect" value="org.hibernate.dialect.Oracle10gDialect"/>
        </properties>
    </persistence-unit>
</persistence>

Running a successful 2PC operation with JPA

Call Flow 

- Get EntityManager for RAC Database1 [ em1=getEntityManager1(); ]
- Get EntityManager for RAC Database2 [ em2=getEntityManager2(); ]
- Start as Usertransacation             [ ut.begin(); ]
- Join transaction from EntityManager 1  [ em1.joinTransaction(); ]
- Join transaction from EntityManager 2  [ em2.joinTransaction(); ]
- Chance Balance on both databases
bankA_acct.setBalance( bankA_acct.getBalance().add(b) );
em1.merge(bankA_acct);
if (isEnableFlush() )
em1.flush();

bankB_acct.setBalance( bankB_acct.getBalance().subtract(b) );
em2.merge(bankB_acct);
if (isEnableFlush() )
em2.flush();
- Finally commit the Transaction [ ut.commit(); ]

Application log :
14:51:58.071 transferMoneyImpl():: Found both Entity Managers for PUs : RacBankAHibPU and RacBankBHibPU
14:51:58.074 transferMoneyImpl():: Account at bank A: User99_at_BANKA - Balance: 10000
14:51:58.075 transferMoneyImpl():: Account at bank B: User98_at_BANKB - Balance: 10000
14:51:58.076 transferMoneyImpl():: Both EMs joined our XA Transaction...
14:51:58.092 transferMoneyImpl():: Before Commit ...
14:51:58.160 transferMoneyImpl():: Tx Commit worked !
14:51:58.165 Database Name:BANKA -- Account: User99_at_BANKA -- Balance: 11000.0
14:51:58.168 Database Name:BANKB -- Account: User98_at_BANKB -- Balance: 9000.0
14:51:58.169 transferMoneyImpl():: Leaving with TX Status:: [UT status:  6 - STATUS_NO_TRANSACTION]

-> We successfully managed to transfer some money from bankA to bankB !

Testing Rollback operation with EM flush enabled [ transaction status : STATUS_MARKED_ROLLBACK ]

Account Balance
 transferMoneyImpl():: Account at bank A: User99_at_BANKA - Balance: 20000
 transferMoneyImpl():: Account at bank B: User98_at_BANKB - Balance: 0
Note the next money transfer/transaction should trigger a constraint violation ! 

Call Flow
- Get EntityManager for RAC Database1 [ em1=getEntityManager1(); ]
- Get EntityManager for RAC Database2 [ em2=getEntityManager2(); ]
- Start a User transaction             [ ut.begin(); ] 
- Join transaction from EntityManager 1  [ em1.joinTransaction(); ]
- Join transaction from EntityManager 2  [ em2.joinTransaction(); ]
- Chance Balance on both databases
     bankA_acct.setBalance( bankA_acct.getBalance().add(b) );
        em1.merge(bankA_acct);
        if (isEnableFlush() )
          em1.flush();
                
        bankB_acct.setBalance( bankB_acct.getBalance().subtract(b) );
        em2.merge(bankB_acct);           
        if (isEnableFlush() )
          em2.flush();              
- em2.flush is failing due to a constraint violation and set the TX status to  : STATUS_MARKED_ROLLBACK 
   Error : org.hibernate.exception.ConstraintViolationException: could not execute statement
- Exception handler checks transaction status : STATUS_MARKED_ROLLBACK and is rolling back the TX
       if ( status != javax.transaction.Status.STATUS_NO_TRANSACTION   ) 
         {
         ut.rollback();
         ...
- After rollback() transaction status changed to   STATUS_NO_TRANSACTION                      
  
Application log :
15:11:03.920 transferMoneyImpl():: Found both Entity Managers for PUs : RacBankAHibPU and RacBankBHibPU
15:11:03.929 transferMoneyImpl():: Account at bank A: User99_at_BANKA - Balance: 20000
15:11:03.931 transferMoneyImpl():: Account at bank B: User98_at_BANKB - Balance: 0
15:11:03.931 transferMoneyImpl():: Both EMs joined our XA Transaction... 
15:11:03.960 transferMoneyImpl():: FATAL ERROR - Tx Status : [UT status:  1 - STATUS_MARKED_ROLLBACK]
15:11:03.962 transferMoneyImpl():: Before TX rollback ... 
15:11:03.974 transferMoneyImpl():: TX rollback worked !
15:11:03.974 transferMoneyImpl():: Leaving with TX Status:: [UT status:  6 - STATUS_NO_TRANSACTION]


Exception stack :
15:11:03.960 Error in top level function: transferMoneyImpl():: 
15:11:03.960 org.hibernate.exception.ConstraintViolationException: could not execute statement
15:11:03.961 javax.persistence.PersistenceException: org.hibernate.exception.ConstraintViolationException: could not execute statement
    at org.hibernate.jpa.spi.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1763)
    at org.hibernate.jpa.spi.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1677)
    at org.hibernate.jpa.spi.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1683)
    at org.hibernate.jpa.spi.AbstractEntityManagerImpl.flush(AbstractEntityManagerImpl.java:1338)
    at com.hhu.wfjpa2pc.Jpa2pcTest.transferMoneyImpl(Jpa2pcTest.java:235)
    at com.hhu.wfjpa2pc.Jpa2pcTest.transferMoney(Jpa2pcTest.java:166)
        ..
Caused by: org.hibernate.exception.ConstraintViolationException: could not execute statement
    at org.hibernate.exception.internal.SQLExceptionTypeDelegate.convert(SQLExceptionTypeDelegate.java:72)
    at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java
    ... 
Caused by: java.sql.SQLIntegrityConstraintViolationException: ORA-02290: check constraint (SCOTT.S_LOWER_CHK) violated

Testing Rollback operation without EM flush enabled [ transaction status : STATUS_NO_TRANSACTION  ]

Account Balance
 transferMoneyImpl():: Account at bank A: User99_at_BANKA - Balance: 20000
 transferMoneyImpl():: Account at bank B: User98_at_BANKB - Balance: 0
Note the next money transfer/transaction should trigger a constraint violation ! 

Call Flow
- Get EntityManager for RAC Database1 [ em1=getEntityManager1(); ]
- Get EntityManager for RAC Database2 [ em2=getEntityManager2(); ]
- Start a User transaction            [ ut.begin(); ] 
- Join transaction from EntityManager 1  [ em1.joinTransaction(); ]
- Join transaction from EntityManager 2  [ em2.joinTransaction(); ]
- Chance Balance on both databases
     bankA_acct.setBalance( bankA_acct.getBalance().add(b) );
        em1.merge(bankA_acct);
        if (isEnableFlush() )
          em1.flush();
                
        bankB_acct.setBalance( bankB_acct.getBalance().subtract(b) );
        em2.merge(bankB_acct);           
        if (isEnableFlush() )
          em2.flush();        
- Commit the Transaction [ ut.commit(); ] fails with :  ARJUNA016053: Could not commit transaction.
- As the Commit itself fails Wildfly rollback the transaction 
- Tx Status after COMMIT error :  STATUS_NO_TRANSACTION 
- Exception handler checks transaction status : STATUS_MARKED_ROLLBACK and is not rolling back the TX
       if ( status != javax.transaction.Status.STATUS_NO_TRANSACTION   ) 
         {
         ut.rollback();
         ...
- Here we don't run any rollback operation -> the TX status remains at   STATUS_NO_TRANSACTION                      
  
Application log :
  15:27:53.818 transferMoneyImpl():: Found both Entity Managers for PUs : RacBankAHibPU and RacBankBHibPU
  15:27:53.827 transferMoneyImpl():: Account at bank A: User99_at_BANKA - Balance: 20000
  15:27:53.829 transferMoneyImpl():: Account at bank B: User98_at_BANKB - Balance: 0
  15:27:53.829 transferMoneyImpl():: Both EMs joined our XA Transaction... 
  15:27:53.829 transferMoneyImpl():: Before Commit ... 
  15:27:53.857 transferMoneyImpl():: FATAL ERROR - Tx Status : [UT status:  6 - STATUS_NO_TRANSACTION]
  15:27:53.859 transferMoneyImpl():: TX not active / TX already rolled back
  15:27:53.859 transferMoneyImpl():: Leaving with TX Status:: [UT status:  6 - STATUS_NO_TRANSACTION]

Testing transaction Recovery with JPA

What we are expecting  and what we are testing
  - Transaction Timeout is set to 600 seconds
  - We set a breakpoint at   OracleXAResource.commit
    ==> This means Wildfly has written a COMMIT record to  the  Wildlfly LOG-STORE
  - After stop at the first OracleXAResource.commit breakpoint  we kill the Wildfly server 
  - Both RMs [ Oracle RAC databases ] are now counting down the Transaction Timeout 
  - If Timeout is reached the failed transaction becomes visible in dba_2pc_pending table
  - Trying to get a lock on these records should lead to a ORA-1591 error 
  - After Wildfly restart the Periodic Recovery should run OracleXAResource.commit and release all locks

Preparing and running the test scenario

Start Wildfly in Debug Mode :
Set breakpoint on OracleXAResource.commit and run the application

Stack Trace 
"default task-3"
oracle.jdbc.xa.client.OracleXAResource.commit(OracleXAResource.java:553)
org.jboss.jca.adapters.jdbc.xa.XAManagedConnection.commit(XAManagedConnection.java:338)
org.jboss.jca.core.tx.jbossts.XAResourceWrapperImpl.commit(XAResourceWrapperImpl.java:107)
com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord.topLevelCommit(XAResourceRecord.java:461)
com.arjuna.ats.arjuna.coordinator.BasicAction.doCommit(BasicAction.java:2810)
com.arjuna.ats.arjuna.coordinator.BasicAction.doCommit(BasicAction.java:2726)
com.arjuna.ats.arjuna.coordinator.BasicAction.phase2Commit(BasicAction.java:1820)
com.arjuna.ats.arjuna.coordinator.BasicAction.End(BasicAction.java:1504)
com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:96)
com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:162)
com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1166)
com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:126)
com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:75)
org.jboss.tm.usertx.client.ServerVMClientUserTransaction.commit(ServerVMClientUserTransaction.java:173)
com.hhu.wfjpa2pc.Jpa2pcTest.transferMoneyImpl(Jpa2pcTest.java:242)
com.hhu.wfjpa2pc.Jpa2pcTest.transferMoney(Jpa2pcTest.java:166)

Wildfly Check for prepared transaction 
$ $WILDFLY_HOME/bin/jboss-cli.sh --connect --file=list_prepared_xa_tx.cli
{"outcome" => "success"}
0:ffffc0a805c9:f5a10ef:56039e68:d

Locate and kill JBOSS server process 
0 S oracle    5875  5821  7  80   0 - 413473 futex_ 08:55 ?       00:00:30 
     /usr/java/latest/bin/java .... -Djboss.server.base.dir=/usr/local/wildfly-8.2.0.Final/standalone -c standalone.xml
0 S oracle    6174  5680  0  80   0 - 25827 pipe_w 09:02 pts/1    00:00:00 grep java
[oracle@wls1 WILDFLY]$ kill -9 5875

Now wait [ at lest 600 seconds ] until the Transaction becomes visible in  dba_2pc_pending

SQL> SELECT * FROM GLOBAL_NAME;
GLOBAL_NAME
----------------
BANKA

SQL> select * from dba_2pc_pending;
LOCAL_TRAN_ID           GLOBAL_TRAN_ID                            STATE         MIX A TRAN_COMMENT
---------------------- ---------------------------------------------------------------- ---------------- --- - ----------------
FAIL_TIM FORCE_TI RETRY_TI OS_USER    OS_TERMINAL  HOST          DB_USER       COMMIT#
-------- -------- -------- ------------ ------------ ---------------- ------------ ----------------
9.21.7139           131077.00000000000000000000FFFFC0A805C90F5A10EF56039E680000000D3 prepared     no
               1
09:07:22      09:15:34 oracle    unknown      wls1.example.com           43619336



SQL> SELECT * FROM GLOBAL_NAME;
GLOBAL_NAME
----------------
BANKB

SQL> select * from dba_2pc_pending;
LOCAL_TRAN_ID           GLOBAL_TRAN_ID                            STATE         MIX A TRAN_COMMENT
---------------------- ---------------------------------------------------------------- ---------------- --- - ----------------
FAIL_TIM FORCE_TI RETRY_TI OS_USER    OS_TERMINAL  HOST          DB_USER       COMMIT#
-------- -------- -------- ------------ ------------ ---------------- ------------ ----------------
4.15.3293           131077.00000000000000000000FFFFC0A805C90F5A10EF56039E680000000D3 prepared     no
               1
09:07:22      09:15:34 oracle    unknown      wls1.example.com           20931538

Check for locks 
-> Connected to  scott/tiger@ract2-scan.grid12c.example.com:1521/banka
select * from accounts for update
*
ERROR at line 1:
ORA-01591: lock held by in-doubt distributed transaction 9.21.7139


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


Restart Wildfly in Debug Mode and let the Periodic Recovery Thread commit the transaction 

"Periodic Recovery"
oracle.jdbc.xa.client.OracleXAResource.commit(OracleXAResource.java:553)
org.jboss.jca.adapters.jdbc.xa.XAManagedConnection.commit(XAManagedConnection.java:338)
org.jboss.jca.core.tx.jbossts.XAResourceWrapperImpl.commit(XAResourceWrapperImpl.java:107)
com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord.topLevelCommit(XAResourceRecord.java:461)
com.arjuna.ats.arjuna.coordinator.BasicAction.doCommit(BasicAction.java:2810)
com.arjuna.ats.arjuna.coordinator.BasicAction.doCommit(BasicAction.java:2726)
com.arjuna.ats.arjuna.coordinator.BasicAction.phase2Commit(BasicAction.java:1820)
com.arjuna.ats.arjuna.recovery.RecoverAtomicAction.replayPhase2(RecoverAtomicAction.java:71)
com.arjuna.ats.internal.arjuna.recovery.AtomicActionRecoveryModule.doRecoverTransaction(AtomicActionRecoveryModule.java:152)
com.arjuna.ats.internal.arjuna.recovery.AtomicActionRecoveryModule.processTransactionsStatus(AtomicActionRecoveryModule.java:253)
com.arjuna.ats.internal.arjuna.recovery.AtomicActionRecoveryModule.periodicWorkSecondPass(AtomicActionRecoveryModule.java:109)
com.arjuna.ats.internal.arjuna.recovery.PeriodicRecovery.doWorkInternal(PeriodicRecovery.java:789)
com.arjuna.ats.internal.arjuna.recovery.PeriodicRecovery.run(PeriodicRecovery.java:371)

-> WildFly Thread Periodic Recovery stops at OracleXAResource.commit
-> Press Debugger Command : Continue 
-> WildFly Thread Periodic Recovery has committed Transaction Branch 1
-> WildFly Thread Periodic Recovery stops again  at .OracleXAResource.commit
-> Press Debugger Command : Continue 
-> WildFly Thread Periodic Recovery has committed Transaction Branch 2
-> Complete Transaction is now committed 

Verify Access to the Database records and Wildfly Prepared Transaction Cleanup 
-> Connected to  scott/tiger@ract2-scan.grid12c.example.com:1521/banka
ACCOUNT                 BALANCE
-------------------------------- ----------
User99_at_BANKA               14000


-> Connected to  scott/tiger@ract2-scan.grid12c.example.com:1521/bankb
ACCOUNT                 BALANCE
-------------------------------- ----------
User98_at_BANKB                6000


List prepared Transaction
$  $WILDFLY_HOME/bin/jboss-cli.sh --connect --file=list_prepared_xa_tx.cli
{"outcome" => "success"}

-> After a successful transaction recovery the locks are gone 

 

Java Code

public void transferMoneyImpl()
      {
        String methodName = "transferMoneyImpl():: ";
        EntityManager em1;
        EntityManager em2;
        UserTransaction ut =null;
      try
        {
        setRunTimeInfo(methodName  + "Entering ... ");
            
        HttpSession session = (HttpSession) FacesContext.getCurrentInstance().getExternalContext().getSession(true);
        if ( session == null)
              {
                throw new IllegalArgumentException(methodName+ ": Could not get HTTP session : ");    
              }                        
        final Object lock = session.getId().intern();       
        synchronized(lock) 
              {
                em1=getEntityManager1();
                em2=getEntityManager2();
                    //
                    // Note even we get an EntityManager Object we still not sure that the 
                    // EntityManager Could open connection the underlying JDBC connection !
                    //
                if ( em1 == null )
                    setRunTimeInfo(methodName  + "Faild to get EM for PU: " + EMF.getPU1() );
                else if ( em2 == null )
                    setRunTimeInfo(methodName  + "Faild to get EM for PU: " + EMF.getPU2() );
                else
                    setRunTimeInfo(methodName  + "Found both Entity Managers for PUs : " + 
                       EMF.getPU1()  + " and " +  EMF.getPU2()  ); 
                   
                 
                String bankA_acct_name = "User99_at_BANKA";
                Accounts bankA_acct = em1.find(Accounts.class, bankA_acct_name);
                if ( bankA_acct == null)
                    { 
                    setRunTimeInfo(methodName + "Could not locate Account at bankA : " + bankA_acct_name );
                    return;
                    }
                setRunTimeInfo(methodName  +"Account at bank A: " + bankA_acct.getAccount()  + " - Balance: " +  bankA_acct.getBalance() );
                
                String bankB_acct_name = "User98_at_BANKB";
                Accounts bankB_acct = em2.find(Accounts.class, bankB_acct_name);
                if ( bankB_acct == null)
                    { 
                    setRunTimeInfo(methodName + "Could not locate Account at bankB : " + bankB_acct_name );
                    return;
                    }
                setRunTimeInfo(methodName  +"Account at bank B: " + bankB_acct.getAccount()  + " - Balance: " +  bankB_acct.getBalance() );
              
                ut  = (javax.transaction.UserTransaction)new InitialContext().lookup("java:comp/UserTransaction"); 
                    // Set tranaction time to 120 seconds to avoid any timeouts during testing -
                    // especially when testing transaction recovery by restarting Wildfly server 
                    // Note as we kill the JAVA process both RMs will wait 120 s before Tx becomes visible in dba_2pc_pending 
                int tx_timeout = 120;
                ut.setTransactionTimeout(tx_timeout);
                ut.begin();
                em1.joinTransaction();
                em2.joinTransaction();
                setRunTimeInfo(methodName  + "Both EMs joined our XA Transaction... - TX Timeout: " + tx_timeout );
                BigDecimal b = new BigDecimal(1000);
                bankA_acct.setBalance( bankA_acct.getBalance().add(b) );
                em1.merge(bankA_acct);
                if (isEnableFlush() )
                    em1.flush();
                
                bankB_acct.setBalance( bankB_acct.getBalance().subtract(b) );
                em2.merge(bankB_acct);           
                if (isEnableFlush() )
                    em2.flush();
                
                setRunTimeInfo(methodName  + "Before Commit ... ");                
                ut.commit();
                setRunTimeInfo(methodName  + "Tx Commit worked !");
                checkBalanceImpl();
              }
        } catch ( Throwable t1)
          { 
            try
              {    
              String tx_status = returnTXStatus(ut);
              setRunTimeInfo( methodName  + "FATAL ERROR - Tx Status : " + tx_status  );
                // Use Throwable as we don't want to loose any important imformation
                // Note: Throwable is super class of Exception class          
               genericException("Error in top level function: " + methodName , (Exception)t1);                          
               if ( ut != null )
                  {
                    int status = ut.getStatus();    
                        // rollback transaction if still active - if not do nothing 
                    if ( status != javax.transaction.Status.STATUS_NO_TRANSACTION   ) {
                        setRunTimeInfo(methodName  + "Before TX rollback ... ");
                        ut.rollback();
                        setRunTimeInfo(methodName  + "TX rollback worked !");
                    } else
                        setRunTimeInfo(methodName  + "TX not active / TX already rolled back");
                  }
              }  catch ( Throwable t2)
                 { 
                   genericException(methodName + "FATAL ERROR during ut.rollback() ", (Exception)t2); 
                 } 
          }
        closeEntityManagers();       
        String tx_status_exit = "";
        try
          {    
            tx_status_exit = returnTXStatus(ut);
          }   catch ( Throwable t3)
            { 
              genericException(methodName + " Error during returning TX status ", (Exception)t3); 
            }    
        setRunTimeInfo(methodName  + "Leaving with TX Status:: " + tx_status_exit );
      }

Reference

Hibernate / JPA : Access to DialectResolutionInfo cannot be null

Pom.xml 
        <dependency>
            <groupId>org.hibernate</groupId>
            <artifactId>hibernate-core</artifactId>
            <version>4.3.6.Final</version>
        </dependency>

        <dependency>
            <groupId>org.hibernate</groupId>
            <artifactId>hibernate-entitymanager</artifactId>
            <version>4.3.6.Final</version>
        </dependency>


Error and Cause Determination 

Deploying a new WEBApplication using Hibernate fails with : 
Deploying /usr/local/wildfly-8.2.0.Final/standalone/deployments/WFJPA2PC-1.0.war
"{\"JBAS014671: Failed services\" => {\"jboss.persistenceunit.\\\"WFJPA2PC-1.0.war#RacBankBHibPU\\\"\" 
  => \"org.jboss.msc.service.StartException in service jboss.persistenceunit.\\\"WFJPA2PC-1.0.war#RacBankBHibPU\\\": 
     org.hibernate.HibernateException: Access to DialectResolutionInfo cannot be null when 'hibernate.dialect' not set
     Caused by: org.hibernate.HibernateException: Access to DialectResolutionInfo cannot be null when 'hibernate.dialect' not set\"}}"

Cause : Oracle RAC database was down ! 

Fix : Add hibernate.dialect to your persistence.xml 
   <persistence-unit name="RacBankBHibPU" transaction-type="JTA">
        <provider>org.hibernate.ejb.HibernatePersistence</provider>
        <jta-data-source>java:/jboss/datasources/xa_rac12g_bankb</jta-data-source>
        <class>com.hhu.wfjpa2pc.Accounts</class>
        <properties>
            <property name="hibernate.transaction.jta.platform"
                 value="org.hibernate.service.jta.platform.internal.JBossAppServerJtaPlatform" />
            <property name="hibernate.show_sql" value="true" />
            <property name="hibernate.dialect" value="org.hibernate.dialect.Oracle10gDialect"/>
        </properties>
    </persistence-unit>

-> Now application can be redeployed 
-> Application now starts but throws the following stack 
08:55:04.761 javax.resource.ResourceException: IJ000453: Unable to get managed connection for java:jboss/datasources/xa_rac12g_bankb
08:55:04.762 java.sql.SQLException: javax.resource.ResourceException: IJ000453: Unable to get managed connection for java:jboss/datasources/xa_rac12g_bankb
    at org.jboss.jca.adapters.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:154)
    at com.hhu.wfjpa2pc.Jpa2pcTest.getRacInfoDS(Jpa2pcTest.java:398)
    at com.hhu.wfjpa2pc.Jpa2pcTest.getRacInfo(Jpa2pcTest.java:376)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.

-> With above Stack we easily can figure out that we need to start our RAC DB

Copy a Maven based JPA project to new project folder

New Project Details

ArtifactId                   : WFJPA2PC
New Project Home             : /home/oracle/NetBeansProjects/GIT/WFJPA2PC 
New persistence.xml location :  /home/oracle/NetBeansProjects/GIT/WFJPA2PC/src/main/resources/META-INF/persistence.xml Your old and working project should have a working pom.xml and persistence.xml 

Modify and copy pom,xml

Modify artifactId and name in your pom.xml 
    <artifactId>WFJPA2PC</artifactId>
    <name>WFJPA2PC</name>

Copy pom.xml to your new Project Folder 
$ cp pom.xml   /home/oracle/NetBeansProjects/GIT/WFJPA2PC

Add JSF support to our project 
Project -> Properties -> Framework -> Add JavaServerFaces 
                                   -> Components -> PrimeFaces 

Create new Entity Classes

Create new Entity Classes as needed [ in our sample we use Entity Class : Accounts 

Source package -> New -> EnititY Class form Database 
  -> Select Datasource 
  -> Select Table Name : Accounts  
  -> Add 
  -> Finish 

Create a new JPA persistence.xml and copy over the working persistence.xml

Netbeans : File -> NEW ->  Persistence Unit 

Locate your Persistence Location of persistence.xml:
  /home/oracle/NetBeansProjects/GIT/WFJPA2PC/src/main/resources/META-INF/persistence.xml

-> Copy over your new RAC XA persistence.xml to   src/main/resources/META-INF/persistence.xml
   and add your newly created Entitly Classes    

Sample for a Hibernate persistence.xml with Entity Class : Accounts
<?xml version="1.0"?>
<persistence xmlns="http://java.sun.com/xml/ns/persistence"
             xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
             xsi:schemaLocation="http://java.sun.com/xml/ns/persistence http://java.sun.com/xml/ns/persistence/persistence_2_0.xsd"
             version="2.0">

    <persistence-unit name="RacBankAHibPU" transaction-type="JTA">
        <provider>org.hibernate.ejb.HibernatePersistence</provider>
        <jta-data-source>java:/jboss/datasources/xa_rac12g_banka</jta-data-source>
        <class>com.hhu.wfjpa2pc.Accounts</class>
        <properties>
            <property name="hibernate.transaction.jta.platform"
                 value="org.hibernate.service.jta.platform.internal.JBossAppServerJtaPlatform" />
            <property name="hibernate.show_sql" value="true" />
        </properties>
</persistence>

Details on HttpSession Object

Overview

  • HTTP is a stateless protocol
  • To keep JAVA object available longer than the duration of a HTTP request  each Object is stored within the HTTP session object. This is called Session tracking feature.
  • Typical technical solutions  for Session Tracking are
      • Cookies
      • URL rewriting

    Hidden form fields.

 

Why and how should you protect your HTTP session object

  • HttpSession object is not thread safe
  • Browser Tabbing, Fast Page Reloading  and async. AJAX request may give you concurrent access to the same HttpSession object
  • There is no guarantee that multiple calls to HttpServletRequest.getSession() will return the same HttpSession object .
  • Don’t synchronize on HttpSession object as this object may be recreated by certain containers
  • Synchronize on immutable object returned by :  session.getId().intern()

Reference

Creating a HTTP session using cookies

JSESSIONID cookie is created/sent when session is created. Session is created when your code calls request.getSession() 
or request.getSession(true) for the first time. If you just want get session, but not create it if it doesn't exists, 
use request.getSession(false) -- this will return you a session or null. In this case, new session is not created, 
and JSESSIONID cookie is not sent. (This also means that session isn't necessarily created on first request... you 
and your code is in control when the session is created)

Understanding Browser Session and HTTP Session Object

Using Browser tabbing with firefox  

Start a first Browser session and run their initial  HTTP POST to create the HTTP session by running timeoutTest() :
Session 1:  $ firefox http://localhost:8180/WFJPA2EL-1.0/ 
12:56:42.530 timeoutTest() - NEW Session  - ID zjiDVDLbFkQYhJ4bARWTmP6P - Access Count: 0- i
             JSESSIONID cookie: zjiDVDLbFkQYhJ4bARWTmP6P.wls1 - MaxIncativeInterval:  10 - 
             Last AccessedTime: 12:56:34.636 - Cookie MaxAge: -1

Now start as new Browser Tab using the same URL  and run the HTTP Post request again 
Session 2: $ firefox http://localhost:8180/WFJPA2EL-1.0/
12:56:47.856 timeoutTest() - WELCOME Back Session   - ID zjiDVDLbFkQYhJ4bARWTmP6P - Access Count: 1- 
             JSESSIONID cookie: zjiDVDLbFkQYhJ4bARWTmP6P.wls1 - MaxIncativeInterval:  10 - 
             Last AccessedTime: 12:56:42.547 - Cookie MaxAge: -1

- The second request doesn't create a new HTTP session object
- Instead browser session are uing the HTTP Session object 
- Thats is why you should serialize access to the HTTP session object as multiple threads may use this JAVA object !
 

Using a different Firefox profile or different Host name will create different HTTP Objects:

Session 1: $ firefox http://localhost:8180/WFJPA2EL-1.0/
10:06:59.096 timeoutTest() - NEW Session  - ID O3tl4IqIDCAGWB16O52HO6h6 - Access Count: 0- 
             JSESSIONID cookie: O3tl4IqIDCAGWB16O52HO6h6.wls1 - MaxIncativeInterval:  10 - 
             Last AccessedTime: 10:06:53.374 - Cookie MaxAge: -1

Session 2: $  firefox http://wls1:8180/WFJPA2EL-1.0/
10:07:42.817 timeoutTest() - NEW Session  - ID 6kqRcL-DDpKCywOqrq3wo8yB - Access Count: 0- 
             JSESSIONID cookie: 6kqRcL-DDpKCywOqrq3wo8yB.wls1 - MaxIncativeInterval:  10 - 
             Last AccessedTime: 10:07:37.164 - Cookie MaxAge: -1

- Using a different hostname [ or Firefox Profiles ] will create a new HTTP session object !

HTTP session object details

  • A HTTP Session objects stores data about Cookies and Attributes
  • The JSESSIONID is the cookie for implementing the Session Feature
  • The accessCount attribute tracks how often this session is reused by an HTTP request
10:19:27.673  timeoutTest() - WELCOME Back Session   - ID fwdaf1VInpfsA-20853SiT_F - Access Count: 1- 
              JSESSIONID cookie: fwdaf1VInpfsA-20853SiT_F.wls1 - MaxIncativeInterval:  10 - 
              Last AccessedTime: 10:19:23.205 - Cookie MaxAge: -1
10:19:27.674  attr  = accessCount      value = 1
10:19:27.675  Cookie   name  = JSESSIONID   value = fwdaf1VInpfsA-20853SiT_F.wls1    Cookie MaxAge = -1
Details:
 - Cookie MaxAge = -1       -> No Cookie Timeout
 - MaxIncativeInterval:  10 -> HTTP session timeout [ 10 seconds ] 
 - accsessCount             -> HTTP object stored within HTTP session object 

Java Code to display HTTP session details and set and read attributes

public void trackSession(HttpSession session, String methodName)
      {
        final Object lock = session.getId().intern();  
        synchronized(lock) 
          {
            String heading = null;
            accessCount =    (Integer)session.getAttribute("accessCount");
            if (accessCount == null) 
              {
                accessCount = new Integer(0);
                heading =  methodName + " - NEW Session";
              } 
            else 
              {
                heading =  methodName + " - WELCOME Back Session ";
                accessCount = new Integer(accessCount.intValue() + 1);
              }
            String jSessionId = "JSESSIONID not found";
            int jSessionMaxAge = 0;
            HttpServletRequest req = (HttpServletRequest) FacesContext.getCurrentInstance().getExternalContext().getRequest(); 

                // There no API to return JESSIONID cookie - we need to loop throught the Cookie Arrary 
            Cookie[] cookies = req.getCookies();
            for(Cookie cookie : cookies)
              {
                if("JSESSIONID".equals(cookie.getName()))
                  {    
                    jSessionId = cookie.getValue();
                    jSessionMaxAge = cookie.getMaxAge();
                               }
               }
                       
            session.setAttribute("accessCount", accessCount);
            setSessionInfo(heading +  "  - ID "  + session.getId() + " - Access Count: " + accessCount.intValue() 
                 + "- JSESSIONID cookie: " + jSessionId + " - MaxIncativeInterval:  " + session.getMaxInactiveInterval()
                 + " - Last AccessedTime: " + Tools.getTime2(session.getLastAccessedTime()) + " - Cookie MaxAge: " + jSessionMaxAge);
            
                // display Session details : Cookies and 
            if (displaySessionDetails )
              {   
                Enumeration es = session.getAttributeNames();
                while (es.hasMoreElements())
                  {
                    String attr = (String)es.nextElement();
                    Object value = session.getValue(attr);
                    setSessionInfo("      attr  = "+ attr +"      value = "+ value);
                  } 

                for (Cookie cookie : cookies) 
                  {
                    String cookieName = cookie.getName();
                    String cookieValue = cookie.getValue();
                    setSessionInfo("    Cookie   name  = "+  cookieName+"   value = "+ cookieValue + "    Cookie MaxAge = " +  cookie.getMaxAge());
                  }    
              }
          }                                  
      }

How to deal with HTTP Session Timeout – a JSF sample

  • For security and memory management, sessions need to be invalidated at a certain time
There are two related methods in HttpSession.
- HttpSession.invalidate() 
  By invoking invalidate(), the session will be invalidated immediately. 
  This is useful for the case such as logout.
- HttpSession.setMaxInactiveInterval(int interval)
 The method setMaxInactiveInterval(int interval) allows us to configure the time (in seconds) 
 between client requests before the servlet container will invalidate the session.
 That is, an idle session will be invalidated after the specified time.

See https://weblogs.java.net/blog/swchan2/archive/2013/08/29/when-httpsession-invalidated

HTTP session timemout can be configured via web.xml 

web.xml sample 
 <session-config>
        <session-timeout>
            30
        </session-timeout>
    </session-config>

setMaxInactiveInterval() sample
    HttpSession session = (HttpSession) FacesContext.getCurrentInstance().getExternalContext().getSession(true);
    if ( session == null)
      {
        throw new IllegalArgumentException(methodName+ ": Could not get HTTP session : ");    
      }
    session.setMaxInactiveInterval(5);

Note setMaxInactiveInterval configures the time (in seconds) between client requests 
and before the servlet container will invalidate the session.

After your initial HTTP GET request wait 5 seconds and send a HTTP POST request. 
This HTTP POST request will fail with:   
  javax.faces.application.ViewExpiredException: viewId:/index.xhtml - 
    View /index.xhtml could not be restored.
    at com.sun.faces.lifecycle.RestoreViewPhase.execute(RestoreViewPhase.java:210)
    at com.sun.faces.lifecycle.Phase.doPhase(Phase.java:101)
    at com.sun.faces.lifecycle.RestoreViewPhase.doPhase(RestoreViewPhase.java:121)
    at com.sun.faces.lifecycle.LifecycleImpl.execute(LifecycleImpl.java:198)
    at javax.faces.webapp.FacesServlet.service(FacesServlet.java:646)
    at io.undertow.servlet.handlers.ServletHandler.handleRequest(ServletHandler.java:85)

Fix : You may Add an error page to your web.xml file
    <error-page>
        <exception-type>javax.faces.application.ViewExpiredException</exception-type>
        <location>/faces/index.xhtml</location>
    </error-page> 

Further details on Thread Safety

Never assign any request or session scoped data as an instance variable of a servlet or filter. 
It will be shared among all other requests in other sessions. 
That's threadunsafe! The below example illustrates that:

public class ExampleServlet extends HttpServlet 
  {
    private Object thisIsNOTThreadSafe;
    protected void doGet(HttpServletRequest request, HttpServletResponse response) throws ServletException, IOException
      {
        Object thisIsThreadSafe;

        thisIsNOTThreadSafe = request.getParameter("foo"); // BAD!! Shared among all requests!
        thisIsThreadSafe = request.getParameter("foo"); // OK, this is thread safe.
     } 
 }

Reference

 

 

A deeper dive into Transaction Timeouts with JEE7,Wildfly and Oracle RAC

Potential Transaction Timeouts in a JEE7 / RAC 12.1.0.2 env

  1.  JTA Transaction Timeout triggering an OracleXAResource.rollback operation on our TM side [ Wildfly 8.2 ]
  2. JTA Transaction Timeout occuring on the RM side [ ORA-24756 ]
  3. DISTRIBUTED LOCK TIMEOUT occuring on the RM side [ ORA-2049 ]
  4. HTTPSession Object Timeout

Rule of Thumb

  •  JTA transaction timeout  <  DISTRIBUTED_LOCK_TIMEOUT  <  HTTP Session Timeout
  • In a working JTA env we only want to see JTA timeouts triggered by our TM  [ see 1. ]

Overview Bean Managed Transaction with JTA

  • Each JTA transaction is associated with an Execution Thread
  • Only a single Transaction can be active within an  Execution Thread
  • If one Transaction is active the user can’t start an new one until the TX was committed suspended or rolled back
  • The setTransactionTimeout() method causing  the transaction to roll back after reaching the timeout limit
  • Do not invoke the getRollbackOnly and setRollbackOnly methods of the EJBContext interface in bean-managed transactions [ BMT ]
  • For bean-managed transactions, invoke the getStatus and rollback methods of the UserTransaction interface
  • If a session times out within Oracle, then the Oracle database Process Monitor (PMON) will delete the transaction branch if not prepared or cause the transaction to become in-doubt if prepared.
  • We can track the Transaction Timeout at RM side using Event 10246
         alter system set event=”10246 trace name context forever, level 1″ scope=spfile sid=’*';
  • If the PMON terminates the transaction branch you should get error: ORA-24756: transaction does not exist
  • If the Transaction can’t get a database lock you should get error: ORA-02049: timeout: distributed transaction waiting for lock
  • During this JPA test we use OnePhaseCommit [ means no 2PC / no prepare call ]
  • We always want that our TM is controlling the Transaction
  • If runnig with correct timeout settings we should not see any ORA-2049 or ORA-24756 errors

How to track the XA transaction at database level

  • FORMATID, GLOBALID, BRANCHID build our  XA Xid
  • TIGHTLY COUPLED means we serialize using a DX lock [ can lead to a performance problem ]  and can use RAC ClusterWide Transaction Feature
  • PREPARECOUNT=0 this Tx is not yet prepared
  • STATE ACTIVE means this transaction is active
SQL> select FORMATID, GLOBALID, BRANCHID, BRANCHES, REFCOUNT, PREPARECOUNT, STATE, 
     FLAGS, COUPLING  from v$global_transaction;

  FORMATID GLOBALID
---------- ----------------------------------------------------------------
BRANCHID
--------------------------------------------------------------------------------------------------------------------------------
  BRANCHES   REFCOUNT PREPARECOUNT STATE                       FLAGS COUPLING
---------- ---------- ------------ -------------------------------------- ---------- ---------------
    131077 00000000000000000000FFFFC0A805C935ABDAA855FBBB600000046931
00000000000000000000FFFFC0A805C935ABDAA855FBBB600000046C0000000200000000
     1        1         0 ACTIVE                       0 TIGHTLY COUPLED

TEST 1:  Testing global JTA Timeout

  • The service routine will run 60 seconds before committing the data
  • The JPA timeout will rollback the transaction after the JTA timeout [ 30 seconds ]
  • The Transaction Reaper Wildfly Thread will rollback the transaction after 30 second
  • Later on the commit fails as we don’t run inside a transaction anymore
Setup
HTTP Session Timeout       : 1800 seconds
JTA Timeout                :   30 seconds
ut.setTransactionTimeout() :  not active
Service routine sleep      :   60 seconds 

Setup and verify  JTA Transaction Timeout : 30 seconds:

$ $WILDFLY_HOME/bin/jboss-cli.sh  --connect --controller=localhost:9990 '/subsystem=transactions/:write-attribute(name=default-timeout,value=30)';
{
    "outcome" => "success",
    "result" => 30,
    "response-headers" => {"process-state" => "reload-required"}
}

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

-> Restart Wildfly
-> Run test test case
 
Wildfly Logs:
10:18:52,211 INFO  [stdout] (default task-15) +++ HttpSessionListenerImpl:: sessionCreated()....
10:18:55,489 INFO  [org.eclipse.persistence.connection] (default task-36) 
        Connected: jdbc:oracle:thin:@ract2-scan.grid12c.example.com:1521/banka
    User: SCOTT
    Database: Oracle  Version: Oracle Database 12c Enterprise Edition Release 12.1.0.2.0 - 64bit Production
    Driver: Oracle JDBC driver  Version: 12.1.0.2.0
...
2015-09-17 10:18:55,500 INFO  [org.eclipse.persistence.connection] (default task-17) vfs:/usr/local/wildfly-8.2.0.Final/standalone/deployments/WFJPA2EL-1.0.war/WEB-INF/classes/_jpaELPU login successful
10:19:27,365 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper) ARJUNA012117: TransactionReaper::check timeout for TX 0:ffffc0a805c9:6a216e79:55fa71c5:72 in state  RUN
10:19:27,367 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0) ARJUNA012095: Abort of action id 0:ffffc0a805c9:6a216e79:55fa71c5:72 invoked while multiple threads active within it.
10:19:27,368 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0) ARJUNA012108: CheckedAction::check - atomic action 0:ffffc0a805c9:6a216e79:55fa71c5:72 aborting with 1 threads active!
10:19:27,383 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0) ARJUNA012121: TransactionReaper::doCancellations worker Thread[Transaction Reaper Worker 0,5,main] successfully canceled TX 0:ffffc0a805c9:6a216e79:55fa71c5:72
10:19:57,381 WARN  [com.arjuna.ats.arjuna] (default task-17) ARJUNA012077: Abort called on already aborted atomic action 0:ffffc0a805c9:6a216e79:55fa71c5:72

-> JPA connection returned at 10:18:55
   About 32 seconds later the global JTA timeout kicks in and terminates the transaction a

Stack :
10:19:57.382 Error in top level function: timeoutTest()
10:19:57.384 ARJUNA016102: The transaction is not active! Uid is 0:ffffc0a805c9:6a216e79:55fa71c5:72
10:19:57.385 javax.transaction.RollbackException: ARJUNA016102: The transaction is not active! Uid is 0:ffffc0a805c9:6a216e79:55fa71c5:72
    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.wfjpa2el.JPATestBean.timeoutTest(JPATestBean.java:456)

TEST 2: Overriding global JTA Timeout with  ut.setTransactionTimeout()

  • This test is similar to TEST 1
  • it only overrides the JTA transaction timeout with setTransactionTimeout()
Setup 
HTTP Session Timeout       : 1800 seconds
JTA Timeout                :   30 seconds
ut.setTransactionTimeout() :   15 seconds
Service routine sleep      :   60 seconds 

Java Code 
     ...
     ut  = (UserTransaction)new InitialContext().lookup("java:comp/UserTransaction");          
     ut.setTransactionTimeout(getTxTimeout());                     
     ut.begin();
     ...

Wildfly Log :
2015-09-17 10:58:58,426 INFO  [org.eclipse.persistence.connection] (default task-36) 
        Connected: jdbc:oracle:thin:@ract2-scan.grid12c.example.com:1521/banka
    User: SCOTT
    Database: Oracle  Version: Oracle Database 12c Enterprise Edition Release 12.1.0.2.0 - 64bit Production
    Driver: Oracle JDBC driver  Version: 12.1.0.2.0
2015-09-17 10:58:58,431 INFO  [org.eclipse.persistence.connection] (default task-36) vfs:/usr/local/wildfly-8.2.0.Final/standalone/deployments/WFJPA2EL-1.0.war/WEB-INF/classes/_jpaELPU login successful
2015-09-17 10:59:15,094 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper) ARJUNA012117: TransactionReaper::check timeout for TX 0:ffffc0a805c9:6a216e79:55fa71c5:11a in state  RUN
2015-09-17 10:59:15,096 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0) ARJUNA012095: Abort of action id 0:ffffc0a805c9:6a216e79:55fa71c5:11a invoked while multiple threads active within it.
2015-09-17 10:59:15,097 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0) ARJUNA012108: CheckedAction::check - atomic action 0:ffffc0a805c9:6a216e79:55fa71c5:11a aborting with 1 threads active!
2015-09-17 10:59:15,115 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0) ARJUNA012121: TransactionReaper::doCancellations worker Thread[Transaction Reaper Worker 0,5,main] successfully canceled TX 0:ffffc0a805c9:6a216e79:55fa71c5:11a

-> JPA connection returned at  10:58:58,
-> About 17 seconds later the Timeout value set by ut.setTransactionTimeout()  kicks in and terminates the transaction a
-> As in TEST 1 the commit fail with a similar stack  

TEST 3 : Stop all TM Threads and  let the RM [ Resource Manager ] terminate the transaction

  • In this test set a breakpoint at OracleXAResource.commit to stop all WildFly Threads
  • This will avoid that any WildFly Thread is running a ROLLBACK
  • You may read following article to setup a XA Breakpoints with Netbeans
  • As no client ROLLBACK operation can terminate the transaction PMON takes over control and terminates the TX
Setup 
HTTP Session Timeout       : 1800 seconds
JTA Timeout                :   30 seconds
ut.setTransactionTimeout() :   20 seconds
Service routine sleep      :  not active

PMON Tracing 
Enable PMON tracing   for our RAC 12.1.0.2 database 
SQL> alter system set event="10246 trace name context forever, level 1" scope=spfile sid='*';
SQL> startup force
SQL> show parameter event
SQL>
NAME                                 TYPE        VALUE
------------------------------------ ----------- ------------------------------
even t                                string      10246 trace name context forever, level 1

PMON trace 
*** 2015-09-18 11:47:04.143
 bno=1 timeout=20 dtime=1442569601 ctime=1442569623 ser=1 evt=1
ksuprog() called at ktur.c:3906
[claim lock 0x74cb0100 for dead session/txn in procp 0x76b29430.18437][hist x424224a1]
deleted branch 0x72558fc0 in first attempt
PMON last posted from location=FILE:/ade/b/2502491802/oracle/rdbms/src/hdir/ksa2.h LINE:294 ID:ksasnr, process=47, post_num=41

-> timeout=20  translates to our JTA timing set with  ut.setTransactionTimeout(20); 
-> The RM ( Oracle Database ) has terminated this Transaction 
-> The transaction timeout was to 20 [ timeout=20 ] 

Errors  :
  XA Failure     : XAException.XAER_NOTA: oracle.jdbc.xa.OracleXAException
  ORacle Failure : java.sql.SQLException: ORA-24756: transaction does not exist
 
Java Stack :
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]) 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.topLevelOnePhaseCommit(XAResourceRecord.java:679) [jbossjta-4.16.6.Final.jar:]
    at com.arjuna.ats.arjuna.coordinator.BasicAction.onePhaseCommit(BasicAction.java:2317) [jbossjta-4.16.6.Final.jar:]
    at com.arjuna.ats.arjuna.coordinator.BasicAction.End(BasicAction.java:1475) [jbossjta-4.16.6.Final.jar:]
    at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:96) [jbossjta-4.16.6.Final.jar:]
    at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:162) [jbossjta-4.16.6.Final.jar:]
    at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1166) [jbossjta-4.16.6.Final.jar:]
    at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:126) [jbossjta-4.16.6.Final.jar:]
    at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:75)
    at org.jboss.tm.usertx.client.ServerVMClientUserTransaction.commit(ServerVMClientUserTransaction.java:173)
    at com.hhu.wfjpa2el.JPATestBean.timeoutTest(JPATestBean.java:466) [classes:]

Caused by: java.sql.SQLException: ORA-24756: transaction does not exist
    at oracle.jdbc.driver.T4CTTIoer.processError(T4CTTIoer.java:450)
    at oracle.jdbc.driver.T4CTTIoer.processError(T4CTTIoer.java:392)
    at oracle.jdbc.driver.T4CTTIoer.processError(T4CTTIoer.java:385)
    at oracle.jdbc.driver.T4CTTIfun.processError(T4CTTIfun.java:1018)
    at oracle.jdbc.driver.T4CTTIfun.receive(T4CTTIfun.java:522)
    at oracle.jdbc.driver.T4CTTIfun.doRPC(T4CTTIfun.java:257)
    at oracle.jdbc.driver.T4CTTIOtxen.doOTXEN(T4CTTIOtxen.java:166)
    at oracle.jdbc.driver.T4CXAResource.doTransaction(T4CXAResource.java:757)
    at oracle.jdbc.driver.T4CXAResource.doCommit(T4CXAResource.java:428)

TEST 4 : Understand and Testing DISTRIBUTED_LOCK_TIMEOUT

  • DISTRIBUTED_LOCK_TIMEOUT default value is 60 seconds
  • If a DML can get the lock within DISTRIBUTED_LOCK_TIMEOUT ORA-2049 is thrown
If the locking transaction runs for longer than the database DISTRIBUTED_LOCK_TIMEOUT  (e.g. a single phase trans
action with no timeout) a deadlock  type situation occurs and the XA / Oracle distributed transactions can fail 
with “ORA-02049: timeout: distributed transaction waiting for lock”. If the ordering of timeouts is correct, then 
this error should never be received within a XA distributed transaction since the TM timeout should be exceeded 
before the DISTRIBUTED_LOCK_TIMEOUT is reached

Setup 
HTTP Session Timeout       : 1800 seconds
JTA Timeout                :   30 seconds
ut.setTransactionTimeout() :  120 seconds
DISTRIBUTED_LOCK_TIMEOUT   :   60 seconds

As ut.setTransactionTimeout() < DISTRIBUTED_LOCK_TIMEOUT  the database will throw ORA-2049 errors


Prepare test  
SQL>  show parameter dist
NAME                     TYPE     VALUE
------------------------------------ ----------- ------------------------------
distributed_lock_timeout         integer     60
Note PMON runs only every 60 seconds so we can see a delay between 60 and 120 seconds untill we hot ORA-2049

Lock the records
SQL> select * from emp2 for update;
     EMPNO ENAME      JOB           SAL
---------- ---------- --------- ----------
      9997 Helmut     Progr.         63206

Our JPA code will start a BMT and update the same record resulting in a ORA-2049 error 
  UPDATE EMP2 SET SAL = ? WHERE (EMPNO = ?)

Call flow 
  ut.begin()
  JPA update gets blocked untill we hit ORA-2049 error

Verify the Transation status before getting ORA-2049
SQL> select FORMATID, GLOBALID, BRANCHID, BRANCHES, REFCOUNT, PREPARECOUNT, STATE, FLAGS, COUPLING
           from v$global_transaction;

  FORMATID GLOBALID
---------- ----------------------------------------------------------------
BRANCHID
--------------------------------------------------------------------------------------------------------------------------------
  BRANCHES   REFCOUNT PREPARECOUNT STATE                       FLAGS COUPLING
---------- ---------- ------------ -------------------------------------- ---------- ---------------
    131077 00000000000000000000FFFFC0A805C935ABDAA855FBBB60000003C931
00000000000000000000FFFFC0A805C935ABDAA855FBBB60000003CC0000000200000000
     1        1         0 ACTIVE                       0 TIGHTLY COUPLED


Error Stacks 
12:06:04.535 Error in top level function: timeoutTest()

12:06:04.536 Exception [EclipseLink-4002] (Eclipse Persistence Services - 2.5.2.v20140319-9ad6abd): org.eclipse.persistence.exceptions.DatabaseException
Internal Exception: java.sql.SQLSyntaxErrorException: ORA-02049: timeout: distributed transaction waiting for lock

Error Code: 2049
Call: UPDATE EMP2 SET SAL = ? WHERE (EMPNO = ?)
    bind => [2 parameters bound]
Query: UpdateObjectQuery(com.hhu.wfjpa2el.Emp2[ empno=9997 ])

12:06:04.539 javax.persistence.PersistenceException: Exception [EclipseLink-4002] (Eclipse Persistence Services - 2.5.2.v20140319-9ad6abd): org.eclipse.persistence.exceptions.DatabaseException
Internal Exception: java.sql.SQLSyntaxErrorException: ORA-02049: timeout: distributed transaction waiting for lock

Error Code: 2049
Call: UPDATE EMP2 SET SAL = ? WHERE (EMPNO = ?)
    bind => [2 parameters bound]
Query: UpdateObjectQuery(com.hhu.wfjpa2el.Emp2[ empno=9997 ])
    at org.eclipse.persistence.internal.jpa.EntityManagerImpl.flush(EntityManagerImpl.java:868)
    at com.hhu.wfjpa2el.JPATestBean.timeoutTest(JPATestBean.java:472)
    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)


2015-09-18 12:27:05,295 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:35abdaa8:55fbbb60:49, node_name=1, branch_uid=0:ffffc0a805c9:35abdaa8:55fbbb60:4c, subordinatenodename=null, 
  eis_name=java:jboss/datasources/xa_rac12g_banka >, heuristic:   TwoPhaseOutcome.FINISH_OK, product: 
  Oracle/Oracle Database 12c12:27:05,295 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:35abdaa8:55fbbb60:49, 
       node_name=1, branch_uid=0:ffffc0a805c9:35abdaa8:55fbbb60:4c, 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


As we don't rollback the Transaction in our sample this is done by the Transaction Reaper Wildfly thread 
"Transaction Reaper Worker 1"
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.resources.arjunacore.XAResourceRecord.topLevelAbort(XAResourceRecord.java:355)
com.arjuna.ats.arjuna.coordinator.BasicAction.doAbort(BasicAction.java:2939)
com.arjuna.ats.arjuna.coordinator.BasicAction.doAbort(BasicAction.java:2918)
com.arjuna.ats.arjuna.coordinator.BasicAction.Abort(BasicAction.java:1632)
com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.cancel(TwoPhaseCoordinator.java:116)
com.arjuna.ats.arjuna.AtomicAction.cancel(AtomicAction.java:215)
com.arjuna.ats.arjuna.coordinator.TransactionReaper.doCancellations(TransactionReaper.java:377)
com.arjuna.ats.internal.arjuna.coordinator.ReaperWorkerThread.run(ReaperWorkerThread.java:78)

TEST 5 : Testing HTTP session Timeout

  • In this test the service routine runs 5 seconds longer [ see sleep 20 s ] compared to our HTTP session limit
  • When returned from our service routine the HTTP session object was already deleted
  • Again The XA transaction will be rolled back by the Wildfly Transaction Reaper Worker Thread
Setup :
HTTP Session Timeout                :   15 seconds
JTA Timeout                         :   30 seconds
ut.setTransactionTimeout()          :   not active
Service routine duration/sleep      :   20 seconds 

Java Code : 
  HttpSession session;
  ...
  session.setMaxInactiveInterval(getSessTimeout());

Wildfly Log reports :
15:55:35,839 SEVERE [javax.enterprise.resource.webcontainer.jsf.application] (default task-5) Error Rendering View[/index.xhtml]: java.lang.IllegalStateException: UT000010: Session not found Iu250lTlBLzIu_FlPHWNxq5_
    at io.undertow.server.session.InMemorySessionManager$SessionImpl.getAttribute(InMemorySessionManager.java:353) [undertow-core-1.1.0.Final.jar:1.1.0.Final]
    at io.undertow.servlet.spec.HttpSessionImpl.getAttribute(HttpSessionImpl.java:121) [undertow-servlet-1.1.0.Final.jar:1.1.0.Final]
    at com.sun.faces.context.SessionMap.get(SessionMap.java:118) [jsf-impl-2.2.8-jbossorg-1.jar:]
    at com.sun.faces.application.view.FaceletViewHandlingStrategy.getResponseEncoding(FaceletViewHandlingStrategy.java:1271) [jsf-impl-2.2.8-jbossorg-1.jar:]
    at com.sun.faces.application.view.FaceletViewHandlingStrategy.createResponseWriter(FaceletViewHandlingStrategy.java:1182) [jsf-impl-2.2.8-jbossorg-1.jar:]
    at com.sun.faces.application.view.FaceletViewHandlingStrategy.renderView(FaceletViewHandlingStrategy.java:403) [jsf-impl-2.2.8-jbossorg-1.jar:]
    at com.sun.faces.application.view.MultiViewHandler.renderView(MultiViewHandler.java:133) [jsf-impl-2.2.8-jbossorg-1.jar:]
    at javax.faces.application.ViewHandlerWrapper.renderView(ViewHandlerWrapper.java:337) [jboss-jsf-api_2.2_spec-2.2.8.jar:2.2.8]
    at javax.faces.application.ViewHandlerWrapper.renderView(ViewHandlerWrapper.java:337) [jboss-jsf-api_2.2_spec-2.2.8.jar:2.2.8]
    at com.sun.faces.lifecycle.RenderResponsePhase.execute(RenderResponsePhase.java:120) [jsf-impl-2.2.8-jbossorg-1.jar:]
    at com.sun.faces.lifecycle.Phase.doPhase(Phase.java:101) [jsf-impl-2.2.8-jbossorg-1.jar:]
    at com.sun.faces.lifecycle.LifecycleImpl.render(LifecycleImpl.java:219) [jsf-impl-2.2.8-jbossorg-1.jar:]
    at javax.faces.webapp.FacesServlet.service(FacesServlet.java:647) [jboss-jsf-api_2.2_spec-2.2.8.jar:2.2.8]
    at io.undertow.servlet.handlers.ServletHandler.handleRequest(ServletHandler.java:85) [undertow-servlet-1.1.0.Final.jar:1.1.0.Final]

Which Thread is rolling back the transaction ?

Setting a breakpoint on OracleXAResource.rollback shows that the Transaction Reaper is rolling back the Transaction 
"Transaction Reaper Worker 2"
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.resources.arjunacore.XAResourceRecord.topLevelAbort(XAResourceRecord.java:355)
com.arjuna.ats.arjuna.coordinator.BasicAction.doAbort(BasicAction.java:2939)
com.arjuna.ats.arjuna.coordinator.BasicAction.doAbort(BasicAction.java:2918)
com.arjuna.ats.arjuna.coordinator.BasicAction.Abort(BasicAction.java:1632)
com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.cancel(TwoPhaseCoordinator.java:116)
com.arjuna.ats.arjuna.AtomicAction.cancel(AtomicAction.java:215)
com.arjuna.ats.arjuna.coordinator.TransactionReaper.doCancellations(TransactionReaper.java:377)
com.arjuna.ats.internal.arjuna.coordinator.ReaperWorkerThread.run(ReaperWorkerThread.java:78)

JAVA Test CODE

 public String timeoutTest()  
      {
        EntityManager em;
        String methodName = "timeoutTest()";
        UserTransaction ut =null;
        cleanall();
          try
          {    
            setRunTimeInfo("Calling " + methodName  +  " in progress .. ");
            setRunTimeInfo("Requesting Entity Manager.. ");
            
            HttpSession session = (HttpSession) FacesContext.getCurrentInstance().getExternalContext().getSession(true);
            if ( session == null)
              {
                throw new IllegalArgumentException(methodName+ ": Could not get HTTP session : ");    
              }                        
            /*
                HTTP session object is not thread safe. We need to syncronoise on session id.
                For datails read :  http://yet-another-dev.blogspot.de/2009/08/synchronizing-httpsession.html
            */
            final Object lock = session.getId().intern();  
            Emp2 e = null;
            long eno = -1;
            synchronized(lock) 
              {
                
                if ( getTestMode() == 4)
                  {
                    setSessTimeout(15);
                    setTxTimeout(100); 
                    session.setMaxInactiveInterval(getSessTimeout());
                    setRunTimeInfo("HTTP SessionTimeout() set to: " 
                            + getSessTimeout()  + " seconds");
                  }
                
                if ( getTestMode() == 3)
                  {
                    setTxTimeout(100);  
                    //setSessTimeout(15);
                    setRunTimeInfo("ut.setTransactionTimeout() set to: " 
                            + getTxTimeout()  + " seconds");
                    
                  } 
                
                if ( getTestMode() == 2)
                  {
                    setTxTimeout(20);  
                    //setSessTimeout(15);
                    setRunTimeInfo("Overriding global JTA Timeout : 30 seconds with  ut.setTransactionTimeout() set to: " 
                            + getTxTimeout()  + " seconds");
                    
                  }  
                if ( getTestMode() == 1)
                  {
                    setTxTimeout(15);    
                    setRunTimeInfo("Overriding global JTA Timeout : 30 seconds with  ut.setTransactionTimeout() set to: " 
                            + getTxTimeout()  + " seconds");
                    
                  }    
                if ( getTestMode() == 0)
                  {
                    setRunTimeInfo("Testing global JTA Timeout : 30 seconds");
                  }   
                
                // startAndSuspendSimple(session);
                trackSession(session, methodName );
                em=getEntityManager();
                eno= getEmpno();              
                setRunTimeInfo("Inside " + methodName + " - Empno: " + eno + " - Thread: " +  Thread.currentThread().getName());                             
                e = em.find(Emp2.class, eno );
                checkEntity(e,em);
                e.setSal(e.getSal().add(increaseSalStep1) );
                ut  = (UserTransaction)new InitialContext().lookup("java:comp/UserTransaction");
                String tx_status_before = returnTXStatus(ut);                  
            
                if ( getTestMode() == 1 ||  getTestMode() == 2 || getTestMode() == 3 )
                  {
                    ut.setTransactionTimeout(getTxTimeout());
                    setRunTimeInfo("JTA Transation started with  ut.setTransactionTimeout() set to  : " + getTxTimeout() + " seconds");
                  }    
                ut.begin();
                em.joinTransaction();
                e.setSal(e.getSal().add(increaseSalStep1) );
                em.merge(e);
                    // Update database record 
                em.flush();
                int sleep_time = 20;
                sleep(sleep_time*1000);
               
                ut.commit();
                setRunTimeInfo("Commit Called ");
               
                String tx_status_after = returnTXStatus(ut);     
                setRunTimeInfo(methodName + ": em.flush() // but NO ut.commit   - Before " + tx_status_before
                    + " - After " + tx_status_after);
                checkEntity(e,em);
                setRunTimeInfo("Closing  Entity Manager.. !");
                closeEntityManager();
              }
          } catch ( Throwable t1)
          { 
            // ut.rollback() operation is missing here !           
            setRunTimeInfo("FATAL ERROR in :  "  + methodName  );
                // Use Throwable as we don't want to loose any important imformation
                // Note: Throwable is super class of Exception class          
            genericException("Error in top level function: " + methodName , (Exception)t1);            
          }
        closeEntityManager();            
        setRunTimeInfo("Leaving " + methodName + " - Entity manager  closed !\n");
        return "index";
      }

 

Reference

Debugging XA Calls in a JPA session running BMT with Netbeans 8.0.2

Overview

BMT calls          JDBC Driver calls 
ut.begin()         oracle.jdbc.xa.client.OracleXAResource   
... 
ut.commit()        oracle.jdbc.xa.client.OracleXAResource.end
                   oracle.jdbc.xa.client.OracleXAResource.commit  <--- Here we want to set a Breakpoint 

Prepare the Breakpoint

Class Name           : oracle.jdbc.xa.client.OracleXAResource
Method Name          : commit
Stop on              : Method Entry 
Actions - Suspend    : All Threads
  •  Select suspend all Threads if you want to avoid that any  Wildly Thread is running a rollback
  •  If you want Transaction Recovery takes place by other Wildfly Threads you may select Suspend Breakpoint Thread
  •  Don’t use  oracle.jdbc.xa.OracleXAResource for debugging as this package only defines abstract methods

Start the Netbeans project in DEBUG MODE

Netbeans Debug -> Debug Main Project 
--> Above action will redeploy our project in DEBUG mode

NetBeans: Deploying on WildFly Application Server
    profile mode: false
    debug mode: true
    force redeploy: true
  Undeploying ...
  Initial deploying WFJPA2EL to /usr/local/wildfly-8.2.0.Final/standalone/deployments/WFJPA2EL-1.0.war
  Completed initial distribution of WFJPA2EL
  Deploying /usr/local/wildfly-8.2.0.Final/standalone/deployments/WFJPA2EL-1.0.war
  Application Deployed

Debugger console reports successfully setting the breakpoint in [oracle.jdbc.xa.client.OracleXAResource].commit
  Attaching to localhost:8787
  MethodBreakpoint [oracle.jdbc.xa.client.OracleXAResource].commit successfully submitted.
  User program running

After the program hits a breakpoint runs Debugger Console should report 
Method breakpoint hit in oracle.jdbc.xa.client.OracleXAResource.commit at line 553 by thread default task-3.
Thread default task-3 stopped at OracleXAResource.java:553.

How to Copy the Stack Trace after our Worker Thread stops at a Breakpoint

Select Debugging TAB
  default task-7  [ this Thread was stopped by our Debugger ]
     Hidden Soruce Calls
       OracleXAResource.java:553   <-- Right Click here and select  COPY STACK
Stack Sample 
"default task-7"
oracle.jdbc.xa.client.OracleXAResource.commit(OracleXAResource.java:553)
org.jboss.jca.adapters.jdbc.xa.XAManagedConnection.commit(XAManagedConnection.java:338)
org.jboss.jca.core.tx.jbossts.XAResourceWrapperImpl.commit(XAResourceWrapperImpl.java:107)
com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord.topLevelOnePhaseCommit(XAResourceRecord.java:679)
com.arjuna.ats.arjuna.coordinator.BasicAction.onePhaseCommit(BasicAction.java:2317)
com.arjuna.ats.arjuna.coordinator.BasicAction.End(BasicAction.java:1475)
com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:96)
com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:162)
com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1166)
com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:126)
com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:75)
org.jboss.tm.usertx.client.ServerVMClientUserTransaction.commit(ServerVMClientUserTransaction.java:173)
com.hhu.wfjpa2el.JPATestBean.timeoutTest(JPATestBean.java:466)

JPA: Best practice to get and close EntityManagerFactory to avoid Unknown entity bean class error !

Problem Description

After redeploying a WebApplication using JPA you see the following error:

13:02:18.090 Unknown entity bean class: class com.hhu.wfjpa2el.Emp2, 
 please verify that this class has been marked with the @Entity annotation.

13:02:18.091 java.lang.IllegalArgumentException: Unknown entity bean class: class com.hhu.wfjpa2el.Emp2, 
  please verify that this class has been marked with the @Entity annotation.

Solution

  • Restart your WEBServer   or
  • Install a ServletContextListener and close the EMF during contextDestroyed() Event

JAVA Code for implementing a WebListener

package com.hhu.wfjpa2el;

import javax.persistence.EntityManager;
import javax.persistence.EntityManagerFactory;
import javax.persistence.Persistence;
import javax.servlet.ServletContextEvent;
import javax.servlet.ServletContextListener;
import javax.servlet.annotation.WebListener;
import org.slf4j.LoggerFactory;

@WebListener
public class EMF implements ServletContextListener {

    private static EntityManagerFactory emf;
    final private static String pu = "jpaELPU";
    final static org.slf4j.Logger logger = LoggerFactory.getLogger(ServletContextListenerImpl.class);
    
    @Override
    public void contextInitialized(ServletContextEvent event) {
        logger.info("+++ ServletContextListener : contextInitialized - Inititalizing EMF for PU: " + pu);
        emf = Persistence.createEntityManagerFactory(pu);
        logger.info("+++ ServletContextListener : contextInitialized - Init EMF done for PU: " + pu);
    }

    @Override
    public void contextDestroyed(ServletContextEvent event) {
        logger.info("+++ ServletContextListener : contextDestroyed - Closing EMF for PU: " + pu);
        emf.close();
        logger.info("+++ ServletContextListener : contextDestroyed - Closed EMF done for PU " + pu);
    }

    public static EntityManager createEntityManager() {
        if (emf == null) {
            throw new IllegalStateException("Context is not initialized yet.");
        }
        return emf.createEntityManager();
    }
}

Initialize your Entity Manager by running :  em = EMF.createEntityManager();
Java Code: 
public static EntityManager getEntityManager() 
      {
        EntityManager em = threadLocal.get();
        if (em == null) 
          {
          // setRunTimeInfo(getRunTimeInfo() + Tools.add_hmtl_pre_tag("Creating Entity Manager ! "  ));
            if ( enableLogger )            
                logger.info("Creating Entity Manager Factory ..." );
            em = EMF.createEntityManager();
            threadLocal.set(em);
          }
        return em;
      }

Testing the Code wiht maven deploy/undeploy command

Deploy the WebApplication 
[oracle@wls1 WFJPA2EL]$  mvn wildfly:deploy

Wilfdly Log report:  
13:11:23,170 INFO  [stdout] (MSC service thread 1-4) 13:11:23 [MSC service thread 1-4] INFO  c.h.w.ServletContextListenerImpl - i
                   +++ ServletContextListener : contextInitialized - Init EMF done for PU: jpaELPU
13:11:23,173 INFO  [javax.enterprise.resource.webcontainer.jsf.config] (MSC service thread 1-4) Initializing Mojarra 2.2.8-jbossorg-1 20140822-1131 for context '/WFJPA2EL-1.0'
13:11:23,518 INFO  [org.wildfly.extension.undertow] (MSC service thread 1-4) JBAS017534: Registered web context: /WFJPA2EL-1.0
13:11:24,010 INFO  [org.jboss.as.server] (management-handler-thread - 1) JBAS018559: Deployed "WFJPA2EL-1.0.war" (runtime-name : "WFJPA2EL-1.0.war")

Undeploy the WebApplication 
[oracle@wls1 WFJPA2EL]$   mvn wildfly:undeploy 

Wilfdly Log report:  
13:11:23,170 INFO  [stdout] (MSC service thread 1-4) 13:11:23 [MSC service thread 1-4] INFO  c.h.w.ServletContextListenerImpl - i
                    +++ ServletContextListener : contextInitialized - Init EMF done for PU: jpaELPU
13:11:23,173 INFO  [javax.enterprise.resource.webcontainer.jsf.config] (MSC service thread 1-4) Initializing Mojarra 2.2.8-jbossorg-1 20140822-1131 for context '/WFJPA2EL-1.0'
13:11:23,518 INFO  [org.wildfly.extension.undertow] (MSC service thread 1-4) JBAS017534: Registered web context: /WFJPA2EL-1.0
13:11:24,010 INFO  [org.jboss.as.server] (management-handler-thread - 1) JBAS018559: Deployed "WFJPA2EL-1.0.war" (runtime-name : "WFJPA2EL-1.0.war")
13:13:02,751 INFO  [org.wildfly.extension.undertow] (MSC service thread 1-7) JBAS017535: Unregistered web context: /WFJPA2EL-1.0

 

Reference

JavaScript Features: Ajax and JavaScript Timeout

What is AJAX?

  • AJAX = Asynchronous JavaScript and XML
  • AJAX is a technique for creating fast and dynamic web pages
  • AJAX allows web pages to be updated asynchronously by exchanging small amounts of data with the server behind the scenes
  • This means that it is possible to update parts of a web page, without reloading the whole page
  • Classic web pages, (which do not use AJAX) must reload the entire page if the content should change
  • Examples of applications using AJAX: Google Maps, Gmail, Youtube, and Facebook tabs
  • AJAX is based on Internet Standards, and uses a combination of:
    • XMLHttpRequest object (to exchange data asynchronously with a server)
    • JavaScript/DOM (to display/interact with the information)
    • CSS (to style the data)
    • XML (often used as the format for transferring data)

Ajax Request used in this sample application

  • Javascript code loadXMLDoc() to trigger an Ajax Request
function loadXMLDoc()
{
var xmlhttp;
var xmlf=document.getElementById('xmlf').value;
var txt,x,i;
if (window.XMLHttpRequest)
  {// code for IE7+, Firefox, Chrome, Opera, Safari
  xmlhttp=new XMLHttpRequest();
  }
else
  {// code for IE6, IE5
  xmlhttp=new ActiveXObject("Microsoft.XMLHTTP");
  }

/*
 * Only a specific devision named "myDiv" of our HTTP page will be updated 
 */        
document.getElementById("myDiv").innerHTML="Inside loadXMLDOC -> XML File to load: " + xmlf;  

/*
 *  For details using onreadystatechange Event please read :  
 *  http://www.w3schools.com/ajax/ajax_xmlhttprequest_onreadystatechange.asp 
 */
xmlhttp.onreadystatechange=function()
  {     
  if (xmlhttp.readyState === 4 )
     {
        if ( xmlhttp.status === 200)
            {
            xmlDoc=xmlhttp.responseXML;
            txt="";
            x=xmlDoc.getElementsByTagName("ARTIST");
            for (i=0;i<x.length;i++)
                {
                txt=txt + x[i].childNodes[0].nodeValue + "<br>";
                }
            document.getElementById("myDiv").innerHTML=txt;
            }
         else
            {
            document.getElementById("myDiv").innerHTML='Error loading XML file: ' + xmlf + ' HTTP Status Code: ' + xmlhttp.status;            
            }
     }      
  };
xmlhttp.open("GET",xmlf,true);
xmlhttp.send();
}

Function Details:

  • The function loadXMLDoc() starts an asyncronous  Ajax request
  • Parameter xmls points to XM file cd.xml which gets loaded during this request
  • xmlhttp.open(“GET”,xmlf, true) means we use an HTTP GET request to load cd.xml. True means the load request is asyncronous.
  •  xmlhttp.send() actually sends the HTTP request
  •  xmlhttp.onreadystatechange function() gets invoked when HTTP response is ready
  • x=xmlDoc.getElementsByTagName(“ARTIST”) scans the XML document for ARTISTS attribute
  • txt=txt + x[i].childNodes[0].nodeValue + “<br>” adds the artists to our result string
  •  Finally   document.getElementById(“myDiv”).innerHTML=txt updates the only myDiv part of our WEB page
  •  In case of an error [ You may just change cd.xml to cdd.xml  for testing ]
      document.getElementById(“myDiv”).innerHTML=’Error loading XML file: ‘ + xmlf + ‘ HTTP Status Code: ‘ + xmlhttp.status;
      returns some error like:    Error loading XML file: cdd.xml HTTP Status Code: 404
  • For further details you may read following article :

Implementing a Page TimeOut using JavaScript

  • This is quite simple – For details please read function checkdelay() in JavaScript Code published below.
  • JavaScript Code :
JavaScript Code 
<!DOCTYPE html>
<html>
<head>
<script>
    
function redirect()
{
    window.location="https://google.de";
}

function redirecttohome()
{
    window.location="http://localhost:8180/JavaScriptandAjax-1.0/";
}

function redirectdelay()
{   
   actdelay = delay;
   checkdelay();
}
   
function checkdelay()
{
    /*
     * As long we don't reach the timeout value we need to reschedule checkdelay()
     * every second !
     */
    document.getElementById("myDiv").innerHTML="This page wil be redirected in " + actdelay + " seconds !"; 
    actdelay = actdelay - 1 ;
    if ( actdelay >= 0 )
        setTimeout('checkdelay()', 1000);
    else 
        redirecttohome();
}            


function clean()
{
   document.getElementById("myDiv").innerHTML="";    
}

function loadXMLDoc()
{
var xmlhttp;
var xmlf=document.getElementById('xmlf').value;
var txt,x,i;
if (window.XMLHttpRequest)
  {// code for IE7+, Firefox, Chrome, Opera, Safari
  xmlhttp=new XMLHttpRequest();
  }
else
  {// code for IE6, IE5
  xmlhttp=new ActiveXObject("Microsoft.XMLHTTP");
  }

/*
 * Only a specific devision named "myDiv" of our HTTP page will be updated 
 */        
document.getElementById("myDiv").innerHTML="Inside loadXMLDOC -> XML File to load: " + xmlf;  

/*
 *  For details using onreadystatechange Event please read :  
 *  http://www.w3schools.com/ajax/ajax_xmlhttprequest_onreadystatechange.asp 
 */
xmlhttp.onreadystatechange=function()
  {     
  if (xmlhttp.readyState === 4 )
     {
        if ( xmlhttp.status === 200)
            {
            xmlDoc=xmlhttp.responseXML;
            txt="";
            x=xmlDoc.getElementsByTagName("ARTIST");
            for (i=0;i<x.length;i++)
                {
                txt=txt + x[i].childNodes[0].nodeValue + "<br>";
                }
            document.getElementById("myDiv").innerHTML=txt;
            }
         else
            {
            document.getElementById("myDiv").innerHTML='Error loading XML file: ' + xmlf + ' HTTP Status Code: ' + xmlhttp.status;            
            }
     }      
  };
xmlhttp.open("GET",xmlf,true);
xmlhttp.send();

}
    // global Javascript values 
var delay=10;
var actdeley;
</script>
</head>

<body>

<h2>My CD Collection:</h2>
<input name="XMLFile" type="text" maxlength="16" id="xmlf" value="cd.xml" />
<div id="myDiv"></div>
<button type="button" onclick="loadXMLDoc()">Get my CD collection</button>
<button type="button" onclick="clean()">Clean Display</button>
<button type="button" onclick="redirect()">Page Redirect to Google </button>
<button type="button" onclick="redirectdelay()">Delayed Page Redirect to our Home Page </button>
</body>
</html>

XML File used in this sample : cd.xml

<?xml version="1.0" encoding="ISO-8859-1"?>
<CATALOG>
    <CD>
        <TITLE>Empire Burlesque</TITLE>
        <ARTIST>Bob Dylan</ARTIST>
        <COUNTRY>USA</COUNTRY>
        <COMPANY>Columbia</COMPANY>
        <PRICE>10.90</PRICE>
        <YEAR>1985</YEAR>
    </CD>
    <CD>
        <TITLE>Hide your heart</TITLE>
        <ARTIST>Bonnie Tyler</ARTIST>
        <COUNTRY>UK</COUNTRY>
        <COMPANY>CBS Records</COMPANY>
        <PRICE>9.90</PRICE>
        <YEAR>1988</YEAR>
    </CD>
    <CD>
        <TITLE>Greatest Hits</TITLE>
        <ARTIST>Dolly Parton</ARTIST>
        <COUNTRY>USA</COUNTRY>
        <COMPANY>RCA</COMPANY>
        <PRICE>9.90</PRICE>
        <YEAR>1982</YEAR>
    </CD>
</CATALOG>

Reference

Most Info of this POST are just  copied from:

Using TM API to suspend and resume a JTA transaction to allow JDBC Commits

Assume your project has the following JPA transaction requirements

  • Start long a  running JTA transaction
  • Within the same thread which starts the JTA transaction you need to integrate a JAVA package which runs JDBC initiated COMMITs
  • The transaction outcome of this local transaction should be independent from our global JTA traansaction

Test Environment

12:09:59.294 Hibernate Version: 4.3.7.Final
12:09:59.294 Driver Name             : Oracle JDBC driver
12:09:59.294 Driver Version          : 12.1.0.2.0
12:09:59.294 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
12:10:01.448 DB Name:  BANKA
12:10:01.449 1. Instance Name: bankA_1 - Host: hract21.example.com - Pooled XA Connections: 34
12:10:01.449 2. Instance Name: bankA_3 - Host: hract22.example.com - Pooled XA Connections: 33

Call Flow using UserTransaction API [ not working ]

Global JPA transaction:
  ut  = (UserTransaction)new InitialContext().lookup("java:comp/UserTransaction");
  ut.begin();
  em=getEntityManager();
  em.joinTransaction();
  em.persist(e);
  em.flush();                                // Insert record into our RAC DB 
  em.merge(e);                               // Update new record

Start local transaction which is independent from global transaction !!
  Connection c1 = ds1.getConnection();
  preparedStmt.executeUpdate();
  c1.commit(); 
-> Local Commit fails with following error 
Error 
11:13:57.087 Error in writelog()
11:13:57.090 You cannot commit during a managed transaction!
11:13:57.091 java.sql.SQLException: You cannot commit during a managed transaction!
    at org.jboss.jca.adapters.jdbc.BaseWrapperManagedConnection.jdbcCommit(BaseWrapperManagedConnection.java:1065)
    at org.jboss.jca.adapters.jdbc.WrappedConnection.commit(WrappedConnection.java:758)
    at com.hhu.wfjpa2el.JPATestBean.writeLog(JPATestBean.java:1729)
    at com.hhu.wfjpa2el.JPATestBean.increaseSalary(JPATestBean.java:1221)
    at com.hhu.wfjpa2el.JPATestBean.testSuspend(JPATestBean.java:630)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)

-> Your are not allowed to call commit() or rollback() when a JTA transaction is ACTIVE !

Fix : Use the JEE 6 introduced TM API and suspend/resume the JTA transaction

Call Flow
  tm = (TransactionManager)ctx.lookup("java:/TransactionManager"); 
  tm.setTransactionTimeout(txTimeout);
  tm.begin();
  em=getEntityManager();
  em.joinTransaction();
  em.persist(e);
  em.flush();                                // Insert record into our RAC DB 
  em.merge(e);                               // Update new record
  tx = tm.suspend();                         // Save the transaction handle - we need to resume the transaction again
-> Global Transaction is suspended now

Start local transaction which is independent from global transaction !!
  Connection c1 = ds1.getConnection();
  c1.setAutoCommit(false);
  preparedStmt.executeUpdate();
  c1.commit();
-> Local Transaction is commited 

Resume global JTA transaction
 tm.resume(tx);
 em.merge(e);
 tm.commit();
-> Global JTA transaction is now commited 

Working Log

 
2:14:31.826 Calling increaseSalary() in progress - ID: 9997 - isUseSuspend : true
12:14:31.826  ------- Testing Suspend/Resume Operation ----------
12:14:31.826 Lookup Transactionmanager: ctx.lookup(java:/TransactionManager) - Tx Timeout: 120
12:14:31.827 Begin Transaction: tm.begin() - Before [TM status:  6 - STATUS_NO_TRANSACTION] - After [TM status:  0 - STATUS_ACTIVE]
12:14:41.569 checkEntity() -  :  empno: 1000001 - Record not yet found in Database !
12:14:41.569 :: After First Salary Change - Old Sal : 1000 - Salary Increase I : 500 - Current Salary: 1500
12:14:41.570 Suspended Transaction: tm.suspend() - Before [TM status:  0 - STATUS_ACTIVE] - After [TM status:  6 - STATUS_NO_TRANSACTION]
12:14:41.570 writelog():: Message: 12:14:41.570 :: After First Salary Change - Old Sal : 1000 - Salary Increase I : 500 - Current Salary: 1500 - ENO: 1000001
12:14:41.624 Leaving writelog() without Exceptions - Data commited !
12:14:41.624 Resumed Transaction: tm.resume(transaction)  - Before [TM status:  6 - STATUS_NO_TRANSACTION] - After [TM status:  0 - STATUS_ACTIVE]
12:14:41.692 :: Commit Tx: tm.commit() done   - Before [TM status:  0 - STATUS_ACTIVE] - After [TM status:  6 - STATUS_NO_TRANSACTION]
12:14:41.692 writelog():: Message: 12:14:41.692 :: 2nd Salary Change - Old Sal : 1000 - Salary Increase II : 99 - Current Salary: 1599 Need to Rollback : false - ENO: 1000001
12:14:41.779 Leaving writelog() without Exceptions - Data commited !
12:14:41.780 writelog():: Message: 12:14:41.780 :: Commit Tx: tm.commit() done   - Before [TM status:  0 - STATUS_ACTIVE] - After [TM status:  6 - STATUS_NO_TRANSACTION] - ENO: 1000001
12:14:41.801 Leaving writelog() without Exceptions - Data commited !
12:14:41.801  ------- Clear an reread Entity after TX completion  ----------
12:14:41.848 checkEntity() -  :  empno: 1000001 - Sal: 1599 - Entity Salary Persistence : 1599 - Managed Entity Status : true - STALE Data: false
12:14:41.940 -->readLog(): [empno=1000001] - Found 3 Records
12:14:41.940            : LogID:     20 - 12:14:41.570 :: After First Salary Change - Old Sal : 1000 - Salary Increase I : 500 - Current Salary: 1500 
12:14:41.940            : LogID:     21 - 12:14:41.692 :: 2nd Salary Change - Old Sal : 1000 - Salary Increase II : 99 - Current Salary: 1599 Need to Rollback : false 
12:14:41.940            : LogID:     22 - 12:14:41.780 :: Commit Tx: tm.commit() done   - Before [TM status:  0 - STATUS_ACTIVE] - After [TM status:  6 - STATUS_NO_TRANSACTION] 
12:14:41.940 Leaving increaseSalary() without Exceptions !
12:14:41.940 Leaving increaseSalary() - Entity manager  closed !

RAC performance Tuning with JMeter and AWR

Tuning Steps

  • Run AWR to figure out any RAC specific performance problems   
  • Change your application / Change schema objects
  • Verify performance gains with Jmeter
  • Repeat step 1 to step 3

 

Review current Performance status by using AWR

Reviewing SQL performance and Cluster Wait Time 
SQL ordered by CPU Time (Global)
    Captured SQL account for 54.4% of Total CPU Time (s): 235
    Captured PL/SQL account for 1.0% of Total CPU Time (s): 235
     Total     Per Execution     Percentage of Total      
SQL Id         CPU (s)   Elapsed (s) IOWait (s)   Gets   Reads    Rows    Cluster(s)    Execs   DB CPU  DB time  IO Wait    Gets    Read  Cluster    Execs      SQL Text
5m84n5c8k0k4c    49.37    3,317.61    6.99     319,368    792    30,000    2,023.00    30,000     21.04   41.29     1.80    5.83    2.99    57.73      8.07     Insert into logemp2 values (se...
a1h541jgwjdsj    25.56      533.35    6.66   3,566,809    285    30,000      459.23    10,000     10.89    6.64     1.71   65.06    1.08    13.11      2.69     select logemp2x0_.LOGID as LOG...
1aa2fpqtx557g    11.53       43.59    0.06      94,906     37    30,034       17.74    30,034      4.92    0.54     0.02    1.73    0.14     0.51      8.08     update seq$ set increment$=:2,...
8fv480az2kx9h     7.15      568.46    0.12      34,968     11    17,377      556.21    17,377      3.05    7.08     0.03    0.64    0.04    15.87      4.68     select increment$, minvalue, m...
anxm5vn9kxahy     5.91      289.35    1.71      57,697    151    10,000      266.43    10,000      2.15    1.77     0.08    0.68    0.01     3.77      2.69     select emp2x0_.EMPNO as EMPNO1...
8nrq20tnp5wvx     3.03      75.80      0.83      40,162     22    10,000       68.54    10,000     1.29    0.94     0.21    0.73    0.08     1.96      2.69     update EMP2 set ENAME=:1 , JOB...

Top DB Objects
    Top DB Objects by DB Time with respect to Application, Cluster, User I/O, buffer busy waits and In-Memory DB events only.
    Tablespace name is not available for reports generated from the root PDB of a consolidated database.
Object ID    % Activity    Event                    % Event     Object Name (Type)          Tablespace
99421        11.28         gc current block busy     6.05       SCOTT.LOGEMP2_PK (INDEX)    USERS
                           gc buffer busy release    3.11     
                           gc buffer busy acquire    2.04     
99419          4.82        gc buffer busy acquire    2.04       SCOTT.EMP2_PK (INDEX)       USERS
                           gc cr block busy          1.80     
99420          4.42        gc cr block busy          2.78       SCOTT.LOGEMP2 (TABLE)       USERS

-> Insert into log table logemp2 takes much DB CPU time and also consumers very high cluster Wait time 
   We insert 3x more records into our log table ( 30.000 ) compared the record count for table EMP2 ( 10.000 )

-> Waits for Primay Key SCOTT.LOGEMP2_PK seems to be the major Wait Event and needs to be tuned first 

Review and change/modify DB objects responsible for Logging

Current Object Creation scripts :  
create table logemp2 ( LOGID number, EMPNO number(22),  message varchar(300) );
alter table logemp2 add CONSTRAINT  logemp2_pk  PRIMARY KEY (logid);
desc logemp2;

drop sequence SEQ_LOGEMP2;
create sequence SEQ_LOGEMP2  minvalue 1 maxvalue 9999999999999999999999999999
  start with 1 increment by 1 NOCACHE ORDER;
  
-> First tuning suggestions:  
   Drop Primary Key for table Logemp2  andcreate sequence with CACHE Noorder 
  
New Object creation script :
create table logemp2 ( LOGID number, EMPNO number(22),  message varchar(300) );
desc logemp2;
drop sequence SEQ_LOGEMP2;
create sequence SEQ_LOGEMP2  minvalue 1 maxvalue 9999999999999999999999999999
  start with 1 increment by 1 cache 1000 noorder;    

Rerun JMETER tests and compare results

  • Jmeter Thread Group Configurtion : 10 Threads / Loop Count: 1000
  • Initial Jmeter test results

AWR1

  • Jmeter test results after applying above DDL changes

AWR2

  • This simple change increase the RAC performance by 50 %  . Not bad for 10  minutes tuning

 

Further Tuning steps

  • Lets have a look at the next tuning steps by reviewing AWR
 
Top Events
    Top Events by DB Time
    % Activity is the percentage of DB Time due to the event
Event                       Event Class   Session Type   % Activity  Avg Active Sessions
log file sync               Commit        FOREGROUND      35.32            3.20
log file parallel write     System I/O    BACKGROUND      15.39            1.39
gc buffer busy acquire      Cluster       FOREGROUND       9.06            0.82
gcs log flush sync          Other         BACKGROUND       8.67            0.78
gc cr block busy            Cluster       FOREGROUND      8.15             0.74

-> Using faster REDO LOGS and reduce the number COMMIT may be the next step of tuning

 

Reference