I've got a problem using the open-session-in-view pattern with a TreeCache for my second level cache. I have a lazy-loaded/proxied entity in the view. When I call a method on it, the proxy is initialized using the Session available courtesy of the open-session-in-view pattern. No problems here. After the entity is initilialized, Hibernate puts it in the cache. This is where the problem comes in. The TreeCache attempts to suspend the current transaction before doing a put. Since this happened outside of any transactions, an exception is thrown by the TransactionManager.
Has anyone else encountered this? Why does the TreeCache suspend the transaction in the first place? I'm running OC4J 10.1.2 and using the OC4JTransactionManagerLookup. Should there be a transaction there?
Hibernate version:
3.1.3
Mapping documents:
Code:
<hibernate-mapping default-access="field">
<class name="rds.cluster.Foo">
<cache usage="transactional"/>
<id name="id">
<generator class="increment"/>
</id>
<property name="x"/>
<property name="s"/>
</class>
</hibernate-mapping>
It's not quite that simple. This is a web application using the open-session-in-view pattern and Spring providing declarative transaction management. Here is what the relevant code (or pseudo-code) would look like if it were all lined up:
Code:
Open session
Begin transaction
Foo foo = (Foo) session.load(Foo.class, new Integer(id))
Commit transaction
foo.getX();
Close session
Full stack trace of any exception that occurs:Code:
java.lang.IllegalStateException: No active Transaction
at com.evermind[Oracle Application Server Containers for J2EE 10g (10.1.2.0.2)].server.ApplicationServerTransactionManager.suspend(ApplicationServerTransactionManager.java:542)
at org.hibernate.cache.TreeCache.suspend(TreeCache.java:101)
at org.hibernate.cache.TreeCache.put(TreeCache.java:71)
at org.hibernate.cache.TransactionalCache.put(TransactionalCache.java:50)
at org.hibernate.engine.TwoPhaseLoad.initializeEntity(TwoPhaseLoad.java:156)
at org.hibernate.loader.Loader.initializeEntitiesAndCollections(Loader.java:842)
at org.hibernate.loader.Loader.doQuery(Loader.java:717)
at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:224)
at org.hibernate.loader.Loader.loadEntity(Loader.java:1785)
at org.hibernate.loader.entity.AbstractEntityLoader.load(AbstractEntityLoader.java:47)
at org.hibernate.loader.entity.AbstractEntityLoader.load(AbstractEntityLoader.java:41)
at org.hibernate.persister.entity.AbstractEntityPersister.load(AbstractEntityPersister.java:2730)
at org.hibernate.event.def.DefaultLoadEventListener.loadFromDatasource(DefaultLoadEventListener.java:365)
at org.hibernate.event.def.DefaultLoadEventListener.doLoad(DefaultLoadEventListener.java:346)
at org.hibernate.event.def.DefaultLoadEventListener.load(DefaultLoadEventListener.java:123)
at org.hibernate.event.def.DefaultLoadEventListener.onLoad(DefaultLoadEventListener.java:82)
at org.hibernate.impl.SessionImpl.fireLoad(SessionImpl.java:862)
at org.hibernate.impl.SessionImpl.immediateLoad(SessionImpl.java:820)
at org.hibernate.proxy.AbstractLazyInitializer.initialize(AbstractLazyInitializer.java:62)
at org.hibernate.proxy.AbstractLazyInitializer.getImplementation(AbstractLazyInitializer.java:98)
at org.hibernate.proxy.CGLIBLazyInitializer.intercept(CGLIBLazyInitializer.java:158)
at rds.cluster.Foo$$EnhancerByCGLIB$$c6284d1a.getX(<generated>)
at _web_2d_inf._sortaservlets._cacheFoo._jspService(_cacheFoo.java:59)
[SRC:/WEB-INF/sortaServlets/cacheFoo.jsp:15]
at com.orionserver[Oracle Application Server Containers for J2EE 10g (10.1.2.0.2)].http.OrionHttpJspPage.service(OrionHttpJspPage.java:56)
at com.evermind[Oracle Application Server Containers for J2EE 10g (10.1.2.0.2)].server.http.ResourceFilterChain.doFilter(ResourceFilterChain.java:65)
at org.springframework.orm.hibernate3.support.OpenSessionInViewFilter.doFilterInternal(OpenSessionInViewFilter.java:174)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:76)
at com.evermind[Oracle Application Server Containers for J2EE 10g (10.1.2.0.2)].server.http.ServletRequestDispatcher.invoke(ServletRequestDispatcher.java:663)
at com.evermind[Oracle Application Server Containers for J2EE 10g (10.1.2.0.2)].server.http.ServletRequestDispatcher.forwardInternal(ServletRequestDispatcher.java:330)
at com.evermind[Oracle Application Server Containers for J2EE 10g (10.1.2.0.2)].server.http.HttpRequestHandler.processRequest(HttpRequestHandler.java:830)
at com.evermind[Oracle Application Server Containers for J2EE 10g (10.1.2.0.2)].server.http.HttpRequestHandler.run(HttpRequestHandler.java:285)
at com.evermind[Oracle Application Server Containers for J2EE 10g (10.1.2.0.2)].server.http.HttpRequestHandler.run(HttpRequestHandler.java:126)
at com.evermind[Oracle Application Server Containers for J2EE 10g (10.1.2.0.2)].util.ReleasableResourcePooledExecutor$MyWorker.run(ReleasableResourcePooledExecutor.java:186)
at java.lang.Thread.run(Thread.java:595)
Debug level Hibernate log excerpt:Code:
opened session at timestamp: 11456362828 11:18:02,890 DEBUG SessionImpl(219)
no active transaction, could not register Synchronization 11:18:02,890 DEBUG JDBCContext(159)
setting flush mode to: NEVER 11:18:02,890 DEBUG SessionImpl(1253)
no active transaction, could not register Synchronization 11:18:02,890 DEBUG JDBCContext(159)
no active transaction, could not register Synchronization 11:18:02,890 DEBUG JDBCContext(159)
no active transaction, could not register Synchronization 11:18:02,890 DEBUG JDBCContext(159)
setting flush mode to: AUTO 11:18:02,890 DEBUG SessionImpl(1253)
begin 11:18:02,890 DEBUG JDBCTransaction(54)
opening JDBC connection 11:18:02,890 DEBUG ConnectionManager(415)
no active transaction, could not register Synchronization 11:18:02,906 DEBUG JDBCContext(159)
current autocommit status: true 11:18:02,906 DEBUG JDBCTransaction(59)
disabling autocommit 11:18:02,906 DEBUG JDBCTransaction(62)
after transaction begin 11:18:02,906 DEBUG JDBCContext(194)
loading entity: [rds.cluster.Foo#1] 11:18:02,906 DEBUG DefaultLoadEventListener(153)
creating new proxy for entity 11:18:02,906 DEBUG DefaultLoadEventListener(230)
commit 11:18:02,906 DEBUG JDBCTransaction(103)
automatically flushing session 11:18:02,906 DEBUG SessionImpl(332)
before transaction completion 11:18:02,921 DEBUG JDBCContext(185)
before transaction completion 11:18:02,921 DEBUG SessionImpl(388)
re-enabling autocommit 11:18:02,921 DEBUG JDBCTransaction(193)
committed JDBC Connection 11:18:02,921 DEBUG JDBCTransaction(116)
after transaction completion 11:18:02,921 DEBUG JDBCContext(199)
transaction completed on session with on_close connection release mode; be sure to close the session to release JDBC resources! 11:18:02,921 DEBUG ConnectionManager(296)
after transaction completion 11:18:02,921 DEBUG SessionImpl(417)
no active transaction, could not register Synchronization 11:18:02,921 DEBUG JDBCContext(159)
no active transaction, could not register Synchronization 11:18:02,921 DEBUG JDBCContext(159)
no active transaction, could not register Synchronization 11:18:02,921 DEBUG JDBCContext(159)
setting flush mode to: NEVER 11:18:02,921 DEBUG SessionImpl(1253)
no active transaction, could not register Synchronization 11:18:02,921 DEBUG JDBCContext(159)
no active transaction, could not register Synchronization 11:18:02,921 DEBUG JDBCContext(159)
no active transaction, could not register Synchronization 11:18:02,921 DEBUG JDBCContext(159)
initializing proxy: [rds.cluster.Foo#1] 11:18:02,921 DEBUG SessionImpl(816)
no active transaction, could not register Synchronization 11:18:02,921 DEBUG JDBCContext(159)
no active transaction, could not register Synchronization 11:18:02,921 DEBUG JDBCContext(159)
attempting to resolve: [rds.cluster.Foo#1] 11:18:02,921 DEBUG DefaultLoadEventListener(304)
no active transaction, could not register Synchronization 11:18:02,921 DEBUG JDBCContext(159)
no active transaction, could not register Synchronization 11:18:02,921 DEBUG JDBCContext(159)
no active transaction, could not register Synchronization 11:18:02,921 DEBUG JDBCContext(159)
cache lookup: rds.cluster.Foo#1 11:18:02,921 DEBUG TransactionalCache(28)
cache miss 11:18:02,921 DEBUG TransactionalCache(31)
object not resolved in any cache: [rds.cluster.Foo#1] 11:18:02,921 DEBUG DefaultLoadEventListener(340)
Fetching entity: [rds.cluster.Foo#1] 11:18:02,921 DEBUG AbstractEntityPersister(2723)
no active transaction, could not register Synchronization 11:18:02,921 DEBUG JDBCContext(159)
no active transaction, could not register Synchronization 11:18:02,937 DEBUG JDBCContext(159)
loading entity: [rds.cluster.Foo#1] 11:18:02,937 DEBUG Loader(1777)
no active transaction, could not register Synchronization 11:18:02,937 DEBUG JDBCContext(159)
no active transaction, could not register Synchronization 11:18:02,937 DEBUG JDBCContext(159)
no active transaction, could not register Synchronization 11:18:02,937 DEBUG JDBCContext(159)
about to open PreparedStatement (open PreparedStatements: 0, globally: 0) 11:18:02,937 DEBUG AbstractBatcher(311)
select foo0_.id as id0_0_, foo0_.x as x0_0_, foo0_.s as s0_0_ from Foo foo0_ where foo0_.id=? 11:18:02,937 DEBUG AbstractBatcher(346)
preparing statement 11:18:02,937 DEBUG AbstractBatcher(424)
binding '1' to parameter: 1 11:18:02,937 DEBUG NullableType(80)
no active transaction, could not register Synchronization 11:18:02,937 DEBUG JDBCContext(159)
about to open ResultSet (open ResultSets: 0, globally: 0) 11:18:02,937 DEBUG AbstractBatcher(327)
processing result set 11:18:02,937 DEBUG Loader(682)
result set row: 0 11:18:02,937 DEBUG Loader(687)
no active transaction, could not register Synchronization 11:18:02,937 DEBUG JDBCContext(159)
result row: EntityKey[rds.cluster.Foo#1] 11:18:02,937 DEBUG Loader(1164)
no active transaction, could not register Synchronization 11:18:02,937 DEBUG JDBCContext(159)
Initializing object from ResultSet: [rds.cluster.Foo#1] 11:18:02,937 DEBUG Loader(1347)
no active transaction, could not register Synchronization 11:18:02,937 DEBUG JDBCContext(159)
no active transaction, could not register Synchronization 11:18:02,937 DEBUG JDBCContext(159)
Hydrating entity: [rds.cluster.Foo#1] 11:18:02,937 DEBUG AbstractEntityPersister(1860)
returning '1' as column: x0_0_ 11:18:02,937 DEBUG NullableType(122)
returning 'a' as column: s0_0_ 11:18:02,937 DEBUG NullableType(122)
no active transaction, could not register Synchronization 11:18:02,937 DEBUG JDBCContext(159)
no active transaction, could not register Synchronization 11:18:02,953 DEBUG JDBCContext(159)
done processing result set (1 rows) 11:18:02,953 DEBUG Loader(709)
no active transaction, could not register Synchronization 11:18:02,953 DEBUG JDBCContext(159)
about to close ResultSet (open ResultSets: 1, globally: 1) 11:18:02,953 DEBUG AbstractBatcher(334)
about to close PreparedStatement (open PreparedStatements: 1, globally: 1) 11:18:02,953 DEBUG AbstractBatcher(319)
closing statement 11:18:02,953 DEBUG AbstractBatcher(470)
no active transaction, could not register Synchronization 11:18:02,953 DEBUG JDBCContext(159)
total objects hydrated: 1 11:18:02,953 DEBUG Loader(839)
no active transaction, could not register Synchronization 11:18:02,953 DEBUG JDBCContext(159)
resolving associations for [rds.cluster.Foo#1] 11:18:02,953 DEBUG TwoPhaseLoad(107)
no active transaction, could not register Synchronization 11:18:02,953 DEBUG JDBCContext(159)
no active transaction, could not register Synchronization 11:18:02,953 DEBUG JDBCContext(159)
no active transaction, could not register Synchronization 11:18:02,953 DEBUG JDBCContext(159)
no active transaction, could not register Synchronization 11:18:02,953 DEBUG JDBCContext(159)
adding entity to second-level cache: [rds.cluster.Foo#1] 11:18:02,953 DEBUG TwoPhaseLoad(135)
no active transaction, could not register Synchronization 11:18:02,953 DEBUG JDBCContext(159)
no active transaction, could not register Synchronization 11:18:02,953 DEBUG JDBCContext(159)
no active transaction, could not register Synchronization 11:18:02,953 DEBUG JDBCContext(159)
no active transaction, could not register Synchronization 11:18:02,953 DEBUG JDBCContext(159)
no active transaction, could not register Synchronization 11:18:02,953 DEBUG JDBCContext(159)
caching: rds.cluster.Foo#1 11:18:02,953 DEBUG TransactionalCache(49)
closing session 11:18:02,953 DEBUG SessionImpl(268)
performing cleanup 11:18:02,953 DEBUG ConnectionManager(374)
releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)] 11:18:02,953 DEBUG ConnectionManager(435)
after transaction completion 11:18:02,953 DEBUG JDBCContext(199)
transaction completed on session with on_close connection release mode; be sure to close the session to release JDBC resources! 11:18:02,968 DEBUG ConnectionManager(296)
after transaction completion 11:18:02,968 DEBUG SessionImpl(417)
Login
FAQ
Search
