[jboss-user] [Persistence, JBoss/CMP, Hibernate, Database] - Hibernate and JBOSS JTA failed transactions
smithbstl
do-not-reply at jboss.com
Fri Aug 4 17:34:07 EDT 2006
Using Hibernate 3.1 with JBoss 4.0.4.GA and JTA transactions. I can only get the first transaction to successfully update the database. All subsequent transactions never make it to the database. Hibernate appears to commit the transaction but JTA never commits the JTA transaction. I am a novice when it comes to Hibernate and JTA so I have attached all relevant info I could think of. Does anyone have any idea what is going on? Why these updates/transactions are so hit or miss?
Hibernate version:3.1
Mapping documents:
Har Deployment jboss-service.xml
| <?xml version="1.0" encoding="UTF-8"?>
|
| <!DOCTYPE jboss PUBLIC "-//JBoss//DTD JBOSS 4.0//EN"
| "http://www.jboss.org/j2ee/dtd/jboss-service_4_0.dtd">
|
| <server>
| <mbean code="org.jboss.hibernate.jmx.Hibernate"
| name="jboss.har:service=Hibernate">
| <attribute name="DatasourceName">java:/XAOracleDS</attribute>
| <attribute name="Dialect">org.hibernate.dialect.Oracle9Dialect</attribute>
| <attribute name="SessionFactoryName">java:hibernate/SessionFactory</attribute>
| <attribute name="ShowSqlEnabled">true</attribute>
| </mbean>
| </server>
Oracle Datasource
<?xml version="1.0" encoding="UTF-8"?>
|
| <!-- ===================================================================== -->
| <!-- -->
| <!-- JBoss Server Configuration -->
| <!-- -->
| <!-- ===================================================================== -->
|
| <!-- $Id: oracle-xa-ds.xml,v 1.13 2004/09/15 14:37:40 loubyansky Exp $ -->
|
| <!-- ===================================================================== -->
| <!-- ATTENTION: DO NOT FORGET TO SET Pad=true IN transaction-service.xml -->
| <!-- ===================================================================== -->
|
| <datasources>
| <xa-datasource>
| <jndi-name>XAOracleDS</jndi-name>
| <track-connection-by-tx/>
| <isSameRM-override-value>false</isSameRM-override-value>
| <xa-datasource-class>oracle.jdbc.xa.client.OracleXADataSource</xa-datasource-class>
| <!--<xa-datasource-property name="URL">jdbc:oracle:oci8:@tc</xa-datasource-property>-->
| <!--<xa-datasource-property name="User">scott</xa-datasource-property>-->
| <!--<xa-datasource-property name="Password">tiger</xa-datasource-property>-->
| <xa-datasource-property name="URL">jdbc:oracle:thin:@192.168.193.133:1521:ora1</xa-datasource-property>
| <xa-datasource-property name="User">budget_access</xa-datasource-property>
| <xa-datasource-property name="Password">budget_access</xa-datasource-property>
|
|
| <!-- Uses the pingDatabase method to check a connection is still valid before handing it out from the pool -->
| <!--valid-connection-checker-class-name>org.jboss.resource.adapter.jdbc.vendor.OracleValidConnectionChecker</valid-connection-checker-class-name-->
| <!-- Checks the Oracle error codes and messages for fatal errors -->
| <exception-sorter-class-name>org.jboss.resource.adapter.jdbc.vendor.OracleExceptionSorter</exception-sorter-class-name>
| <!-- Oracles XA datasource cannot reuse a connection outside a transaction once enlisted in a global transaction and vice-versa -->
| <no-tx-separate-pools/>
| <!--pooling parameters-->
| <min-pool-size>1</min-pool-size>
| <max-pool-size>100</max-pool-size>
| <blocking-timeout-millis>5000</blocking-timeout-millis>
| <idle-timeout-minutes>15</idle-timeout-minutes>
| <!-- corresponding type-mapping in the standardjbosscmp-jdbc.xml (optional) -->
| <metadata>
| <type-mapping>Oracle9i</type-mapping>
| </metadata>
| </xa-datasource>
|
| <mbean code="org.jboss.resource.adapter.jdbc.vendor.OracleXAExceptionFormatter"
| name="jboss.jca:service=OracleXAExceptionFormatter">
| <depends optional-attribute-name="TransactionManagerService">jboss:service=TransactionManager</depends>
| </mbean>
|
| </datasources>
Code between sessionFactory.openSession() and session.close():
JNDI Lookups for Session
public static SessionFactory getHibernateSessionFactory(String jndiSessionFactoryName) throws ServiceLocatorException {
| SessionFactory sessionFactory = null;
|
| try {
| Context ctx = new InitialContext();
| sessionFactory = (SessionFactory) ctx.lookup(jndiSessionFactoryName);
|
| } catch (ClassCastException cce) {
| throw new ServiceLocatorException(cce);
| } catch (NamingException ne) {
| throw new ServiceLocatorException(ne);
| }
|
| return sessionFactory;
| }
|
| public static Session getHibernateSession(String jndiSessionFactoryName) throws ServiceLocatorException {
| Session session = null;
|
| try {
| session = getHibernateSessionFactory(jndiSessionFactoryName).openSession();
| }
| catch (Exception e) {
| throw new ServiceLocatorException(e);
| }
| return session;
| }
DAO logic
| public void update(AccountBean acctBean) {
| Session session = null;
| Transaction tx = null;
| try {
| session = ServiceLocator.getHibernateSession(HIBERNATE_SESSION_FACTORY);
| tx = session.beginTransaction();
| session.update(acctBean);
| tx.commit();
| } catch (Exception e) {
| try {
| tx.rollback();
| } catch (Exception e2) {
| System.out.println(e2);
| }
| System.out.println(e);
| } finally {
| try {
| if (session != null) {
| session.close();
| }
| } catch (Exception e) {
| System.out.println(e);
| }
| }
| }
server logs:
Log of successful transaction
2006-08-04 14:42:56,344 INFO [STDOUT] Save Called
2006-08-04 14:42:56,344 INFO [STDOUT] AccountSave: AcctID = 307 AcctNum = 5105 AcctName = Salaries - Tempy Employees
2006-08-04 14:42:56,360 DEBUG [org.hibernate.impl.SessionFactoryObjectFactory] JNDI lookup: hibernate/SessionFactory
2006-08-04 14:42:56,360 DEBUG [org.hibernate.impl.SessionFactoryObjectFactory] lookup: uid=402882a50cdab53f010cdab540a90000
2006-08-04 14:42:56,360 DEBUG [org.hibernate.jdbc.JDBCContext] TransactionFactory reported no active transaction; Synchronization not registered
2006-08-04 14:42:56,360 DEBUG [org.hibernate.impl.SessionImpl] opened session at timestamp: 4729735480770560
2006-08-04 14:42:56,360 DEBUG [org.hibernate.transaction.JTATransaction] Looking for UserTransaction under: UserTransaction
2006-08-04 14:42:56,360 DEBUG [org.hibernate.transaction.JTATransaction] Obtained UserTransaction
2006-08-04 14:42:56,360 DEBUG [org.hibernate.transaction.JTATransaction] begin
2006-08-04 14:42:56,360 DEBUG [org.hibernate.transaction.JTATransaction] Began a new JTA transaction
2006-08-04 14:42:56,360 DEBUG [org.hibernate.jdbc.JDBCContext] successfully registered Synchronization
2006-08-04 14:42:56,375 DEBUG [org.hibernate.transaction.JTATransaction] commit
2006-08-04 14:42:56,375 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] processing flush-time cascades
2006-08-04 14:42:56,375 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] dirty checking collections
2006-08-04 14:42:56,391 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] Flushed: 0 insertions, 1 updates, 0 deletions to 1 objects
2006-08-04 14:42:56,391 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
2006-08-04 14:42:56,391 DEBUG [org.hibernate.pretty.Printer] listing entities:
2006-08-04 14:42:56,391 DEBUG [org.hibernate.pretty.Printer] com.stlouiscity.budget.database.beans.AccountBean{acctNum=5105, acctName=Salaries - Tempy Employees, acctId=307}
2006-08-04 14:42:56,391 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2006-08-04 14:42:56,391 DEBUG [org.hibernate.jdbc.ConnectionManager] opening JDBC connection
2006-08-04 14:42:56,454 DEBUG [org.hibernate.SQL] update Budget.Account set Acct_Num=?, Acct_Name=? where Acct_ID=?
2006-08-04 14:42:56,454 INFO [STDOUT] Hibernate: update Budget.Account set Acct_Num=?, Acct_Name=? where Acct_ID=?
2006-08-04 14:42:56,454 DEBUG [org.hibernate.jdbc.AbstractBatcher] Executing batch size: 1
2006-08-04 14:42:56,454 DEBUG [org.hibernate.jdbc.AbstractBatcher] success of batch update unknown: 0
2006-08-04 14:42:56,454 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2006-08-04 14:42:56,454 DEBUG [org.hibernate.jdbc.ConnectionManager] skipping aggressive-release due to flush cycle
2006-08-04 14:42:56,454 DEBUG [org.hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection
2006-08-04 14:42:56,454 DEBUG [org.hibernate.jdbc.ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
2006-08-04 14:42:56,454 DEBUG [org.hibernate.transaction.JTATransaction] Committed JTA UserTransaction
2006-08-04 14:42:56,454 INFO [STDOUT] org.hibernate.SessionException: Session was already closed
2006-08-04 14:42:56,469 DEBUG [org.hibernate.impl.SessionFactoryObjectFactory] JNDI lookup: hibernate/SessionFactory
2006-08-04 14:42:56,469 DEBUG [org.hibernate.impl.SessionFactoryObjectFactory] lookup: uid=402882a50cdab53f010cdab540a90000
2006-08-04 14:42:56,469 DEBUG [org.hibernate.jdbc.JDBCContext] TransactionFactory reported no active transaction; Synchronization not registered
2006-08-04 14:42:56,469 DEBUG [org.hibernate.impl.SessionImpl] opened session at timestamp: 4729735481217024
2006-08-04 14:42:56,469 DEBUG [org.hibernate.transaction.JTATransaction] Looking for UserTransaction under: UserTransaction
2006-08-04 14:42:56,469 DEBUG [org.hibernate.transaction.JTATransaction] Obtained UserTransaction
2006-08-04 14:42:56,469 DEBUG [org.hibernate.transaction.JTATransaction] begin
2006-08-04 14:42:56,469 DEBUG [org.hibernate.transaction.JTATransaction] Began a new JTA transaction
2006-08-04 14:42:56,469 DEBUG [org.hibernate.jdbc.JDBCContext] successfully registered Synchronization
2006-08-04 14:42:56,469 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2006-08-04 14:42:56,469 DEBUG [org.hibernate.jdbc.ConnectionManager] opening JDBC connection
2006-08-04 14:42:56,469 DEBUG [org.hibernate.SQL] select accountbea0_.Acct_ID as Acct1_0_, accountbea0_.Acct_Num as Acct2_0_, accountbea0_.Acct_Name as Acct3_0_ from Budget.Account accountbea0_ order by accountbea0_.Acct_Num
2006-08-04 14:42:56,469 INFO [STDOUT] Hibernate: select accountbea0_.Acct_ID as Acct1_0_, accountbea0_.Acct_Num as Acct2_0_, accountbea0_.Acct_Name as Acct3_0_ from Budget.Account accountbea0_ order by accountbea0_.Acct_Num
2006-08-04 14:42:56,469 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open ResultSet (open ResultSets: 0, globally: 0)
2006-08-04 14:42:56,469 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[com.stlouiscity.budget.database.beans.AccountBean#164]
2006-08-04 14:42:56,469 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[com.stlouiscity.budget.database.beans.AccountBean#165]
2006-08-04 14:42:56,469 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[com.stlouiscity.budget.database.beans.AccountBean#166]
2006-08-04 14:42:56,469 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[com.stlouiscity.budget.database.beans.AccountBean#167]
2006-08-04 14:42:56,469 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[com.stlouiscity.budget.database.beans.AccountBean#168]
2006-08-04 14:42:56,469 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[com.stlouiscity.budget.database.beans.AccountBean#307]
2006-08-04 14:42:56,469 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close ResultSet (open ResultSets: 1, globally: 1)
2006-08-04 14:42:56,469 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2006-08-04 14:42:56,469 DEBUG [org.hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection
2006-08-04 14:42:56,469 DEBUG [org.hibernate.jdbc.ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
2006-08-04 14:42:56,469 DEBUG [org.hibernate.engine.TwoPhaseLoad] resolving associations for [com.stlouiscity.budget.database.beans.AccountBean#164]
2006-08-04 14:42:56,469 DEBUG [org.hibernate.engine.TwoPhaseLoad] done materializing entity [com.stlouiscity.budget.database.beans.AccountBean#164]
2006-08-04 14:42:56,469 DEBUG [org.hibernate.engine.TwoPhaseLoad] resolving associations for [com.stlouiscity.budget.database.beans.AccountBean#165]
2006-08-04 14:42:56,469 DEBUG [org.hibernate.engine.TwoPhaseLoad] done materializing entity [com.stlouiscity.budget.database.beans.AccountBean#165]
2006-08-04 14:42:56,469 DEBUG [org.hibernate.engine.TwoPhaseLoad] resolving associations for [com.stlouiscity.budget.database.beans.AccountBean#166]
2006-08-04 14:42:56,469 DEBUG [org.hibernate.engine.TwoPhaseLoad] done materializing entity [com.stlouiscity.budget.database.beans.AccountBean#166]
2006-08-04 14:42:56,469 DEBUG [org.hibernate.engine.TwoPhaseLoad] resolving associations for [com.stlouiscity.budget.database.beans.AccountBean#167]
2006-08-04 14:42:56,469 DEBUG [org.hibernate.engine.TwoPhaseLoad] done materializing entity [com.stlouiscity.budget.database.beans.AccountBean#167]
2006-08-04 14:42:56,469 DEBUG [org.hibernate.engine.TwoPhaseLoad] resolving associations for [com.stlouiscity.budget.database.beans.AccountBean#168]
2006-08-04 14:42:56,469 DEBUG [org.hibernate.engine.TwoPhaseLoad] done materializing entity [com.stlouiscity.budget.database.beans.AccountBean#168]
2006-08-04 14:42:56,469 DEBUG [org.hibernate.engine.TwoPhaseLoad] resolving associations for [com.stlouiscity.budget.database.beans.AccountBean#307]
2006-08-04 14:42:56,469 DEBUG [org.hibernate.engine.TwoPhaseLoad] done materializing entity [com.stlouiscity.budget.database.beans.AccountBean#307]
2006-08-04 14:42:56,469 DEBUG [org.hibernate.engine.StatefulPersistenceContext] initializing non-lazy collections
Log of unsuccessful transaction
2006-08-04 14:43:07,891 INFO [STDOUT] Save Called
2006-08-04 14:43:07,891 INFO [STDOUT] AccountSave: AcctID = 167 AcctNum = 5104 AcctName = Salaries - Adjustments
2006-08-04 14:43:07,907 DEBUG [org.hibernate.impl.SessionFactoryObjectFactory] JNDI lookup: hibernate/SessionFactory
2006-08-04 14:43:07,907 DEBUG [org.hibernate.impl.SessionFactoryObjectFactory] lookup: uid=402882a50cdab53f010cdab540a90000
2006-08-04 14:43:07,907 DEBUG [org.hibernate.jdbc.JDBCContext] successfully registered Synchronization
2006-08-04 14:43:07,907 DEBUG [org.hibernate.impl.SessionImpl] opened session at timestamp: 4729735528067072
2006-08-04 14:43:07,907 DEBUG [org.hibernate.transaction.JTATransaction] Looking for UserTransaction under: UserTransaction
2006-08-04 14:43:07,907 DEBUG [org.hibernate.transaction.JTATransaction] Obtained UserTransaction
2006-08-04 14:43:07,907 DEBUG [org.hibernate.transaction.JTATransaction] begin
2006-08-04 14:43:07,907 DEBUG [org.hibernate.transaction.JTATransaction] commit
2006-08-04 14:43:07,907 DEBUG [org.hibernate.impl.SessionFactoryObjectFactory] JNDI lookup: hibernate/SessionFactory
2006-08-04 14:43:07,907 DEBUG [org.hibernate.impl.SessionFactoryObjectFactory] lookup: uid=402882a50cdab53f010cdab540a90000
2006-08-04 14:43:07,907 DEBUG [org.hibernate.jdbc.JDBCContext] successfully registered Synchronization
2006-08-04 14:43:07,907 DEBUG [org.hibernate.impl.SessionImpl] opened session at timestamp: 4729735528067073
2006-08-04 14:43:07,907 DEBUG [org.hibernate.transaction.JTATransaction] Looking for UserTransaction under: UserTransaction
2006-08-04 14:43:07,907 DEBUG [org.hibernate.transaction.JTATransaction] Obtained UserTransaction
2006-08-04 14:43:07,907 DEBUG [org.hibernate.transaction.JTATransaction] begin
2006-08-04 14:43:07,907 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2006-08-04 14:43:07,907 DEBUG [org.hibernate.jdbc.ConnectionManager] opening JDBC connection
2006-08-04 14:43:07,907 DEBUG [org.hibernate.SQL] select accountbea0_.Acct_ID as Acct1_0_, accountbea0_.Acct_Num as Acct2_0_, accountbea0_.Acct_Name as Acct3_0_ from Budget.Account accountbea0_ order by accountbea0_.Acct_Num
2006-08-04 14:43:07,907 INFO [STDOUT] Hibernate: select accountbea0_.Acct_ID as Acct1_0_, accountbea0_.Acct_Num as Acct2_0_, accountbea0_.Acct_Name as Acct3_0_ from Budget.Account accountbea0_ order by accountbea0_.Acct_Num
2006-08-04 14:43:07,907 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open ResultSet (open ResultSets: 0, globally: 0)
2006-08-04 14:43:07,907 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[com.stlouiscity.budget.database.beans.AccountBean#164]
2006-08-04 14:43:07,907 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[com.stlouiscity.budget.database.beans.AccountBean#165]
2006-08-04 14:43:07,907 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[com.stlouiscity.budget.database.beans.AccountBean#166]
2006-08-04 14:43:07,907 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[com.stlouiscity.budget.database.beans.AccountBean#167]
2006-08-04 14:43:07,922 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[com.stlouiscity.budget.database.beans.AccountBean#168]
2006-08-04 14:43:07,922 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[com.stlouiscity.budget.database.beans.AccountBean#307]
2006-08-04 14:43:07,922 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close ResultSet (open ResultSets: 1, globally: 1)
2006-08-04 14:43:07,922 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2006-08-04 14:43:07,922 DEBUG [org.hibernate.jdbc.ConnectionManager] aggressively releasing JDBC connection
2006-08-04 14:43:07,922 DEBUG [org.hibernate.jdbc.ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
2006-08-04 14:43:07,922 DEBUG [org.hibernate.engine.TwoPhaseLoad] resolving associations for [com.stlouiscity.budget.database.beans.AccountBean#164]
2006-08-04 14:43:07,922 DEBUG [org.hibernate.engine.TwoPhaseLoad] done materializing entity [com.stlouiscity.budget.database.beans.AccountBean#164]
2006-08-04 14:43:07,922 DEBUG [org.hibernate.engine.TwoPhaseLoad] resolving associations for [com.stlouiscity.budget.database.beans.AccountBean#165]
2006-08-04 14:43:07,922 DEBUG [org.hibernate.engine.TwoPhaseLoad] done materializing entity [com.stlouiscity.budget.database.beans.AccountBean#165]
2006-08-04 14:43:07,922 DEBUG [org.hibernate.engine.TwoPhaseLoad] resolving associations for [com.stlouiscity.budget.database.beans.AccountBean#166]
2006-08-04 14:43:07,922 DEBUG [org.hibernate.engine.TwoPhaseLoad] done materializing entity [com.stlouiscity.budget.database.beans.AccountBean#166]
2006-08-04 14:43:07,922 DEBUG [org.hibernate.engine.TwoPhaseLoad] resolving associations for [com.stlouiscity.budget.database.beans.AccountBean#167]
2006-08-04 14:43:07,922 DEBUG [org.hibernate.engine.TwoPhaseLoad] done materializing entity [com.stlouiscity.budget.database.beans.AccountBean#167]
2006-08-04 14:43:07,922 DEBUG [org.hibernate.engine.TwoPhaseLoad] resolving associations for [com.stlouiscity.budget.database.beans.AccountBean#168]
2006-08-04 14:43:07,922 DEBUG [org.hibernate.engine.TwoPhaseLoad] done materializing entity [com.stlouiscity.budget.database.beans.AccountBean#168]
2006-08-04 14:43:07,922 DEBUG [org.hibernate.engine.TwoPhaseLoad] resolving associations for [com.stlouiscity.budget.database.beans.AccountBean#307]
2006-08-04 14:43:07,922 DEBUG [org.hibernate.engine.TwoPhaseLoad] done materializing entity [com.stlouiscity.budget.database.beans.AccountBean#307]
2006-08-04 14:43:07,922 DEBUG [org.hibernate.engine.StatefulPersistenceContext] initializing non-lazy collections
Name and version of the database you are using:Oracle 10g Release 1 - JDBC Thin Driver
View the original post : http://www.jboss.com/index.html?module=bb&op=viewtopic&p=3963324#3963324
Reply to the post : http://www.jboss.com/index.html?module=bb&op=posting&mode=reply&p=3963324
More information about the jboss-user
mailing list