Problem with leaked connections from passivated/activated SF

[kahliburke]

OK, here we go with a first post to the JBoss forums...

I've searched through the forums and JIRA and can't find anything about this. Forgive me if this problem is due to my own lack of understanding. This may be more appropriate for the EJB 3 forum, just let me know.

I am using the following:

JBoss 4.0.5 with EJB profile
Seam 1.1CR1

Basically, the problem I'm having occurs when I have an EntityManger with persistence type PersistenceContextType.EXTENDED, in a stateful session bean, which has been passivated and then activated again. When the entity manager is used again, JBoss complains about a leaked connection, assuming the debug connection monitoring is turned on in the JBoss JCA configuration (it is on by default). I get the following exception:

[CachedConnectionManager] Closing a connection for you. Please close them yourself: org.jboss.resource.adapter.jdbc.WrappedConnection@65d4c6
java.lang.Throwable: STACKTRACE
 at org.jboss.resource.connectionmanager.CachedConnectionManager.registerConnection(CachedConnectionManager.java:290)
 at org.jboss.resource.connectionmanager.BaseConnectionManager2.allocateConnection(BaseConnectionManager2.java:417)
 at org.jboss.resource.connectionmanager.BaseConnectionManager2$ConnectionManagerProxy.allocateConnection(BaseConnectionManager2.java:842)
 at org.jboss.resource.adapter.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:88)
 at org.hibernate.connection.DatasourceConnectionProvider.getConnection(DatasourceConnectionProvider.java:69)
 at org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:417)
 at org.hibernate.jdbc.ConnectionManager.getConnection(ConnectionManager.java:144)
 at org.hibernate.jdbc.AbstractBatcher.prepareQueryStatement(AbstractBatcher.java:139)
 at org.hibernate.loader.Loader.prepareQueryStatement(Loader.java:1560)
 at org.hibernate.loader.Loader.doQuery(Loader.java:661)
 at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:224)
 at org.hibernate.loader.Loader.loadEntity(Loader.java:1784)
 at org.hibernate.loader.entity.AbstractEntityLoader.load(AbstractEntityLoader.java:48)
 at org.hibernate.loader.entity.AbstractEntityLoader.load(AbstractEntityLoader.java:42)
 at org.hibernate.persister.entity.AbstractEntityPersister.load(AbstractEntityPersister.java:2977)
 at org.hibernate.event.def.DefaultLoadEventListener.loadFromDatasource(DefaultLoadEventListener.java:393)
 at org.hibernate.event.def.DefaultLoadEventListener.doLoad(DefaultLoadEventListener.java:374)
 at org.hibernate.event.def.DefaultLoadEventListener.load(DefaultLoadEventListener.java:137)
 at org.hibernate.event.def.DefaultLoadEventListener.proxyOrLoad(DefaultLoadEventListener.java:193)
 at org.hibernate.event.def.DefaultLoadEventListener.onLoad(DefaultLoadEventListener.java:101)
 at org.hibernate.impl.SessionImpl.fireLoad(SessionImpl.java:878)
 at org.hibernate.impl.SessionImpl.get(SessionImpl.java:815)
 at org.hibernate.impl.SessionImpl.get(SessionImpl.java:808)
 at org.hibernate.ejb.AbstractEntityManagerImpl.find(AbstractEntityManagerImpl.java:174)
 at org.jboss.ejb3.entity.ExtendedEntityManager.find(ExtendedEntityManager.java:119)
 at test.StatefulImpl.doSomething(StatefulImpl.java:52)

If I try to use the component after that, I'll get another exception because the connection has been closed:

00:27:49,328 INFO [STDOUT] Hibernate: select testentity0_.id as id10_0_ from TestEntity testentity0_ where testentity0_.id=?
00:27:49,351 WARN [JDBCExceptionReporter] SQL Error: 0, SQLState: null
00:27:49,351 ERROR [JDBCExceptionReporter] Connection handle has been closed and is unusable
00:27:49,351 INFO [DefaultLoadEventListener] Error performing load command
org.hibernate.exception.GenericJDBCException: could not load an entity: [test.TestEntity#1]
 at org.hibernate.exception.SQLStateConverter.handledNonSpecificException(SQLStateConverter.java:103)
 at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:91)
 at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:43)
 at org.hibernate.loader.Loader.loadEntity(Loader.java:1798)
 at org.hibernate.loader.entity.AbstractEntityLoader.load(AbstractEntityLoader.java:48)
 at org.hibernate.loader.entity.AbstractEntityLoader.load(AbstractEntityLoader.java:42)
 at org.hibernate.persister.entity.AbstractEntityPersister.load(AbstractEntityPersister.java:2977)
 at org.hibernate.event.def.DefaultLoadEventListener.loadFromDatasource(DefaultLoadEventListener.java:393)
 at org.hibernate.event.def.DefaultLoadEventListener.doLoad(DefaultLoadEventListener.java:374)
 at org.hibernate.event.def.DefaultLoadEventListener.load(DefaultLoadEventListener.java:137)
 at org.hibernate.event.def.DefaultLoadEventListener.proxyOrLoad(DefaultLoadEventListener.java:193)
 at org.hibernate.event.def.DefaultLoadEventListener.onLoad(DefaultLoadEventListener.java:101)
 at org.hibernate.impl.SessionImpl.fireLoad(SessionImpl.java:878)
 at org.hibernate.impl.SessionImpl.get(SessionImpl.java:815)
 at org.hibernate.impl.SessionImpl.get(SessionImpl.java:808)
 at org.hibernate.ejb.AbstractEntityManagerImpl.find(AbstractEntityManagerImpl.java:174)
 at org.jboss.ejb3.entity.ExtendedEntityManager.find(ExtendedEntityManager.java:119)
 at test.StatefulImpl.doSomething(StatefulImpl.java:52)

I've tried changing configuration to get around this. I tried turning off the debug connection monitoring, based on a page I read somewhere that indicated Hibernate could confuse the debug monitoring and lead to spurious connection closed warnings. If I turn this off I don't get these exceptions, but I do see connections really leaking. I'm not sure if a connection is leaked every request but it is definitely occurring. Eventually I run out and get an exception that a connection could not be obtained from the pool.

I tried to simplify the case as much as I could to make sure it wasn't something in my code. Eventually I tried a fresh clean JBoss installation, modified the booking example and changed the HotelSearchingAction to use an extended persistence context and also configured the passivation timeout with @CacheConfig(idleTimeoutSeconds=2). I can see this with the default timeout, but I can see the problem much more quickly this way. I'm using MySQL for my app, but I was able to reproduce on Hypersonic as well. So if I make those changes, log in and hit the search page, I can see this problem readily.

My understanding is that there is not anything special I need to do when passivating a session bean with an extended persistence context. Is this incorrect? Is there a requirement that the entity manager be flushed or otherwise modified in a @PrePassivate method? Is there some configuration I've missed?

I can post example code but I thought since only 2 small changes are needed in the booking example it might be easier to look at that way. Hopefully I've provided enough information in case this is a JBoss bug. If not please let me know and I will provide more.

Any direction on whether this is a bug or my own fault would be greatly appreciated.

Thanks.

[gavin.king]

You would be better to direct this question to the EJB3 forum, and it would be even better if you could produce a test case that shows this happening w/o Seam, and just EJB3 beans, since I doubt it has anything to do with Seam.

Does the problem still occur if you use a Seam-managed persistence context?

[epbernard]

The team has identified a bug in the EJB3 container regarding passivation and PC). Have a look at the JIRA issues (EJBTHREE)

[epbernard]

Actually it's http://opensource.atlassian.com/projects/hibernate/browse/HHH-2206

[kahliburke]

Thank you for the information on the Hibernate bug. I had not searched on the Atlassian JIRA, just on the JBoss one. I'll keep that in mind in the future.

I downloaded the 3.2.1 release of Hibernate Core and copied that library into my JBoss installation. That error does not occur and more and I don't see connections being leaked anymore.

Thank you for the quick response guys!