Hibernate version: 3.0.5
database: Oracle 9.2.0.4.0
Appserver: WLS 8.1 SP4
Working with CMT session beans and got a problem with hibernate closing an ongoing nested prepared statement(and the connection). Se log and cfg.xml below. This is happening when we use a JNDI XA datasource/connection from oracle.jdbc.xa.client.OracleXADataSource. But if we use the thin non XA driver oracle.jdbc.driver.OracleDriver it works fine.
It seems to be a similar(or in area of) problem of bug HHH-876,
http://opensource2.atlassian.com/projects/hibernate/browse/HHH-876 . This bug is solved in 3.1 rc1 and issues a problem with method AbstractBatcher.hasOpenResources().
I did some testing with ver. 3.1 rc3 and still have the problem, then I got desperate; I changed the source code in AbstractBatcher.hasOpenResources() to always return true(I said I was desperate…) and then I didn’t got the problem of closing the prepared statement/connection. Looking at the code in AbstractBatcher I noticed that the hashmap statementsToClose that stores ongoing prepared statements does not always store a statement when a statement is created. So AbstractBatcher.hasOpenResources() returns false even if we have a ongoing statement. Closing statements/connection is also depending on what isAggressiveRelease() method is returning.
But in a CMT environment you are supposed to have the property hibernate.connection.release_mode to after_statement or auto. And again looking at the source code in method isAggressiveRelease() I don´t see much difference regardless of the release_mode settings.
Code:
public void afterStatement() {
if ( isAggressiveRelease() ) {
if ( batcher.hasOpenResources() ) {
log.info( "Skipping aggresive-release due to open resources on batcher" );
}
else {
aggressiveRelease();
}
}
}
public boolean isAggressiveRelease() {
boolean inAutoCommitState;
try {
inAutoCommitState = !callback.isTransactionInProgress() && isAutoCommit();
}
catch( SQLException e ) {
// assume we are in an auto-commit state
inAutoCommitState = true;
}
// release connections
return releaseMode == ConnectionReleaseMode.AFTER_STATEMENT ||
( releaseMode == ConnectionReleaseMode.AFTER_TRANSACTION && inAutoCommitState );
}
Hibernate.cfg.xml:
Code:
Mapping documents:
<property name="hibernate.jndi.class">weblogic.jndi.WLInitialContextFactory</property>
<!-- Database options (Oracle) -->
<property name="hibernate.connection.datasource">jdbc/ihanDS</property>
<property name="hibernate.dialect">org.hibernate.dialect.Oracle9Dialect</property>
<propertyname="hibernate.query.factory_class">org.hibernate.hql.classic.ClassicQueryTranslatorFactory</property>
<!-- Transaction options -->
<property name="hibernate.transaction.factory_class">org.hibernate.transaction.CMTTransactionFactory</property>
<propertyname="hibernate.transaction.manager_lookup_class">org.hibernate.transaction.WeblogicTransactionManagerLookup</property>
<propertyname="hibernate.transaction.flush_before_completion">true</property>
<property name="hibernate.transaction.auto_close_session">true</property>
<property name="hibernate.connection.release_mode">auto</property>
<!-- Query substitutions, makes HQL more readable -->
<property name="hibernate.query.substitutions">true 1, false 0</property>
<!-- Debuggning options -->
<property name="show_sql">true</property>
<!-- cache options-->
<property name="hibernate.cache.provider_class">org.hibernate.cache.EhCacheProvider</property>
<property name="hibernate.cache.use_query_cache">false</property>
(Error) Log:
Code:
Full stack trace of any exception that occurs:
DEBUG hibernate.jdbc.ConnectionManager - opening JDBC connection
DEBUG org.hibernate.SQL - insert into HDOM_INSKRIVNING_VERSION_MAP (KEY_INSKRIVNING, NUMBER_PERSPECTIVE, dagboksnr, enligtIfr, version_nr, inskrivningsstatus, GALLANDEBESLUT_CLASS, GALLANDEBESLUT_ID, KEY_AFFARSHANDELSE) values (?, ?, ?, ?, ?, ?, ?, ?, ?)
DEBUG hibernate.jdbc.AbstractBatcher - preparing statement
DEBUG hibernate.type.LongType - binding '30' to parameter: 1
… etc …
DEBUG hibernate.type.LongType - binding null to parameter: 6
DEBUG hibernate.impl.SessionImpl - initializing proxy: [se.lantmateriet.ir.ihan.bo.domain.GallandeBeslutExternDO#24]
DEBUG event.def.DefaultLoadEventListener - attempting to resolve: [se.lantmateriet.ir.ihan.bo.domain.GallandeBeslutExternDO#24]
DEBUG event.def.DefaultLoadEventListener - object not resolved in any cache: [se.lantmateriet.ir.ihan.bo.domain.GallandeBeslutExternDO#24]
DEBUG persister.entity.BasicEntityPersister - Materializing entity: [se.lantmateriet.ir.ihan.bo.domain.GallandeBeslutExternDO#24]
DEBUG hibernate.loader.Loader - loading entity: [se.lantmateriet.ir.ihan.bo.domain.GallandeBeslutExternDO#24]
DEBUG hibernate.jdbc.AbstractBatcher - about to open PreparedStatement (open PreparedStatements: 1, globally: 3)
DEBUG org.hibernate.SQL - select gallandebe0_.KEY_GALLANDEBESLUTEXTERN as KEY1_0_, gallandebe0_.VER as VER28_0_, gallandebe0_.DNR_IM as DNR3_28_0_, gallandebe0_.DNR_AR as DNR4_28_0_, gallandebe0_.DNR_NR as DNR5_28_0_, gallandebe0_.aktnr as aktnr28_0_, gallandebe0_.dagboksnr as dagboksnr28_0_, gallandebe0_.inskrivningsdag as inskrivn8_28_0_, gallandebe0_.beslutstyp as beslutstyp28_0_ from HDOM_GALLANDEBESLUTEXTERN gallandebe0_ where gallandebe0_.KEY_GALLANDEBESLUTEXTERN=?
DEBUG hibernate.jdbc.AbstractBatcher - preparing statement
DEBUG hibernate.type.LongType - binding '24' to parameter: 1
… etc …
DEBUG hibernate.loader.Loader - done processing result set (1 rows)
DEBUG hibernate.jdbc.AbstractBatcher - about to close ResultSet (open ResultSets: 1, globally: 1)
DEBUG hibernate.jdbc.AbstractBatcher - about to close PreparedStatement (open PreparedStatements: 2, globally: 4)
DEBUG hibernate.jdbc.AbstractBatcher - closing statement
DEBUG hibernate.jdbc.ConnectionManager - aggressively releasing JDBC connection
DEBUG hibernate.jdbc.ConnectionManager - closing JDBC connection [ (open PreparedStatements: 1, globally: 3) (open ResultSets: 0, globally: 0)]
DEBUG hibernate.loader.Loader - total objects hydrated: 1
DEBUG hibernate.engine.TwoPhaseLoad - resolving associations for [se.lantmateriet.ir.ihan.bo.domain.GallandeBeslutExternDO#24]
DEBUG event.def.DefaultLoadEventListener - loading entity: [se.lantmateriet.ir.ihan.bo.domain.konstant.KonstantDO#70]
DEBUG event.def.DefaultLoadEventListener - entity found in session cache
DEBUG hibernate.engine.TwoPhaseLoad - done materializing entity [se.lantmateriet.ir.ihan.bo.domain.GallandeBeslutExternDO#24]
DEBUG hibernate.engine.PersistenceContext - initializing non-lazy collections
DEBUG hibernate.loader.Loader - done entity load
DEBUG hibernate.type.StringType - binding 'se.lantmateriet.ir.ihan.bo.domain.GallandeBeslutExternDO' to parameter: 7
DEBUG hibernate.jdbc.AbstractBatcher - about to close PreparedStatement (open PreparedStatements: 1, globally: 3)
DEBUG hibernate.jdbc.AbstractBatcher - closing statement
DEBUG hibernate.jdbc.ConnectionManager - aggressively releasing JDBC connection
DEBUG hibernate.util.JDBCExceptionReporter - could not insert collection rows: [se.lantmateriet.ir.ihan.bo.domain.InskrivningDO.inskrivningDOVersionMap#30] [insert into HDOM_INSKRIVNING_VERSION_MAP (KEY_INSKRIVNING, NUMBER_PERSPECTIVE, dagboksnr, enligtIfr, version_nr, inskrivningsstatus, GALLANDEBESLUT_CLASS, GALLANDEBESLUT_ID, KEY_AFFARSHANDELSE) values (?, ?, ?, ?, ?, ?, ?, ?, ?)]
java.sql.SQLException: Connection closed
at weblogic.jdbc.wrapper.JTAConnection.getXAConn(JTAConnection.java:193)
at weblogic.jdbc.wrapper.JTAConnection.checkConnection(JTAConnection.java:84)
at weblogic.jdbc.wrapper.Statement.checkStatement(Statement.java:234)
at weblogic.jdbc.wrapper.PreparedStatement.setString(PreparedStatement.java:636)
at org.hibernate.type.StringType.set(StringType.java:24)
at org.hibernate.type.NullableType.nullSafeSet(NullableType.java:62)
at org.hibernate.type.NullableType.nullSafeSet(NullableType.java:44)
at org.hibernate.type.MetaType.nullSafeSet(MetaType.java:73)
at org.hibernate.type.AnyType.nullSafeSet(AnyType.java:135)
at org.hibernate.type.AnyType.nullSafeSet(AnyType.java:118)
at org.hibernate.type.ComponentType.nullSafeSet(ComponentType.java:218)
at org.hibernate.persister.collection.AbstractCollectionPersister.writeElement(AbstractCollectionPersister.java:652)
at org.hibernate.persister.collection.AbstractCollectionPersister.insertRows(AbstractCollectionPersister.java:1071)
at org.hibernate.action.CollectionUpdateAction.execute(CollectionUpdateAction.java:48)
at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:239)
at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:223)
at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:139)
at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:274)
at org.hibernate.event.def.DefaultAutoFlushEventListener.onAutoFlush(DefaultAutoFlushEventListener.java:48)
at org.hibernate.impl.SessionImpl.autoFlushIfRequired(SessionImpl.java:711)
at org.hibernate.impl.SessionImpl.prepareQueries(SessionImpl.java:895)
at org.hibernate.impl.SessionImpl.getQueries(SessionImpl.java:885)
at org.hibernate.impl.SessionImpl.list(SessionImpl.java:834)
at org.hibernate.impl.QueryImpl.list(QueryImpl.java:74)
at org.hibernate.impl.AbstractQueryImpl.uniqueResult(AbstractQueryImpl.java:603)
at se.lantmateriet.ir.ihan.bo.hibernate.HibernateRepository.findFastighetByFnr(HibernateRepository.java:78)
at se.lantmateriet.ir.ihan.bo.assembler.FastighetAssembler.updateDO(FastighetAssembler.java:105)
at se.lantmateriet.ir.ihan.bo.assembler.LagfartAssembler.updateLagfartDO(LagfartAssembler.java:98)
at se.lantmateriet.ir.ihan.bo.assembler.LagfartAssembler.updateDO(LagfartAssembler.java:83)
at se.lantmateriet.ir.ihan.bo.assembler.FastighetAssembler.updateFastighetDO(FastighetAssembler.java:171)
at se.lantmateriet.ir.ihan.bo.assembler.FastighetAssembler.updateDO(FastighetAssembler.java:120)
at se.lantmateriet.ir.ihan.bo.assembler.FastighetArendeAssembler.updateFastighetArendeDO(FastighetArendeAssembler.java:119)
at se.lantmateriet.ir.ihan.bo.assembler.FastighetArendeAssembler.updateDO(FastighetArendeAssembler.java:98)
at se.lantmateriet.ir.ihan.bo.assembler.AtgardAssembler.updateAtgardDO(AtgardAssembler.java:214)
at se.lantmateriet.ir.ihan.bo.assembler.AtgardAssembler.updateDO(AtgardAssembler.java:123)
at se.lantmateriet.ir.ihan.bo.assembler.InskrivningsarendeAssembler.updateInskrivningsarendeDO(InskrivningsarendeAssembler.java:118)
at se.lantmateriet.ir.ihan.bo.assembler.InskrivningsarendeAssembler.updateDO(InskrivningsarendeAssembler.java:83)
at se.lantmateriet.ir.ihan.bo.assembler.ArendeAssembler.updateDO(ArendeAssembler.java:52)
at se.lantmateriet.ir.ihan.bo.assembler.ImArendeAssembler.updateImArendeDO(ImArendeAssembler.java:226)
at se.lantmateriet.ir.ihan.bo.assembler.ImArendeAssembler.updateDO(ImArendeAssembler.java:135)
at se.lantmateriet.ir.ihan.bo.assembler.AssemblerFacade.updateImArende(AssemblerFacade.java:67)
at se.lantmateriet.ir.ihan.bs.imarendeservice.ImArendeService.sparaImArende(ImArendeService.java:105)
at se.lantmateriet.ir.ihan.bs.imarendeservice.ejb.ImArendeServiceBean.sparaImArende(ImArendeServiceBean.java:50)
at se.lantmateriet.ir.ihan.bs.imarendeservice.ejb.IhanIMarendeService_s1qjr0_EOImpl.sparaImArende(IhanIMarendeService_s1qjr0_EOImpl.java:254)
at se.lantmateriet.ir.ihan.bs.imarendeservice.ejb.IhanIMarendeService_s1qjr0_EOImpl_WLSkel.invoke(Unknown Source)
at weblogic.rmi.internal.BasicServerRef.invoke(BasicServerRef.java:477)
at weblogic.rmi.cluster.ReplicaAwareServerRef.invoke(ReplicaAwareServerRef.java:108)
at weblogic.rmi.internal.BasicServerRef$1.run(BasicServerRef.java:420)
at weblogic.security.acl.internal.AuthenticatedSubject.doAs(AuthenticatedSubject.java:363)
at weblogic.security.service.SecurityManager.runAs(SecurityManager.java:147)
at weblogic.rmi.internal.BasicServerRef.handleRequest(BasicServerRef.java:415)
at weblogic.rmi.internal.BasicExecuteRequest.execute(BasicExecuteRequest.java:30)
at weblogic.kernel.ExecuteThread.execute(ExecuteThread.java:219)
at weblogic.kernel.ExecuteThread.run(ExecuteThread.java:178)
WARN hibernate.util.JDBCExceptionReporter - SQL Error: 0, SQLState: null
ERROR hibernate.util.JDBCExceptionReporter - Connection closed