HibernateTransactionManager, collections, and no session errors

[esammer]

All:

I'm using Hibernate (core), HibernateTransactionManager, AOP transaction management (via the tx: namespace), and direct SessionFactory#getCurrentSession() in my DAOs. My service object methods are properly advised and transactions are properly begin / committed around each method call. The Hibernate Session is properly opened at the beginning of the transaction and closed at the end. Simple.

The problem / question I have is if the Session scope matches that of the transaction (and it effectively does), why can lazy collections not be traversed without triggering a LazyInitializationException?

Relevant code snippets:

// This is properly advised and wrapped in a transaction with HibernateTransactionManager
public Category loadCategoryAndKeywords(String categoryName, Set<String> keywords) {
  ...
  Category category = categoryDAO.findByName(categoryName);
  ...
  Set<String> categoryKeywords = category.getKeywords();

  // Hibernate.isInitialized(categoryKeywords) returns false

  for (String keyword : keywords) {
    // throws LazyInitializationException
    categoryKeywords.add(keyword);
  }

  ...
}

Exception:

2009-11-10 16:55:23,490 (main) [DEBUG - org.springframework.orm.hibernate3.HibernateTransactionManager] - Creating new transaction with name [com.foo.categoryloader.service.CategoryLoaderService.loadCategoryAndKeywords]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
2009-11-10 16:55:23,490 (main) [DEBUG - org.hibernate.impl.SessionImpl] - opened session at timestamp: 12578901234
2009-11-10 16:55:23,490 (main) [DEBUG - org.springframework.orm.hibernate3.HibernateTransactionManager] - Opened new Session [org.hibernate.impl.SessionImpl@3414a97b] for Hibernate transaction
2009-11-10 16:55:23,490 (main) [DEBUG - org.springframework.orm.hibernate3.HibernateTransactionManager] - Preparing JDBC Connection of Hibernate Session [org.hibernate.impl.SessionImpl@3414a97b]
2009-11-10 16:55:23,491 (main) [DEBUG - org.hibernate.transaction.JDBCTransaction] - begin
2009-11-10 16:55:23,491 (main) [DEBUG - org.hibernate.jdbc.ConnectionManager] - opening JDBC connection
2009-11-10 16:55:23,505 (main) [DEBUG - org.hibernate.transaction.JDBCTransaction] - current autocommit status: true
2009-11-10 16:55:23,505 (main) [DEBUG - org.hibernate.transaction.JDBCTransaction] - disabling autocommit
2009-11-10 16:55:23,505 (main) [DEBUG - org.springframework.orm.hibernate3.HibernateTransactionManager] - Exposing Hibernate transaction as JDBC transaction [com.mysql.jdbc.JDBC4Connection@6fef3212]
2009-11-10 16:55:23,505 (main) [DEBUG - com.foo.categoryloader.service.DefaultCategoryLoaderService] - build category named:Test
2009-11-10 16:55:23,509 (main) [DEBUG - com.foo.categoryloader.service.DefaultCategoryLoaderService] - category:id:52025 name:test longName:test parentId:0 accountId:null
2009-11-10 16:55:23,509 (main) [DEBUG - com.foo.categoryloader.service.DefaultCategoryLoaderService] - cache stats:[  name = cache cacheHits = 5 onDiskHits = 0 inMemoryHits = 5 misses = 0 size = 4 averageGetTime = 0.0 evictionCount = 0 ]
2009-11-10 16:55:23,509 (main) [DEBUG - org.hibernate.jdbc.AbstractBatcher] - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2009-11-10 16:55:23,509 (main) [DEBUG - org.hibernate.SQL] - select  ... from ... where ...
2009-11-10 16:55:23,517 (main) [DEBUG - org.hibernate.jdbc.AbstractBatcher] - about to open ResultSet (open ResultSets: 0, globally: 0)
2009-11-10 16:55:23,518 (main) [DEBUG - org.hibernate.loader.Loader] - result row: EntityKey[com.foo.entity.Keyword#150150]
2009-11-10 16:55:23,518 (main) [DEBUG - org.hibernate.jdbc.AbstractBatcher] - about to close ResultSet (open ResultSets: 1, globally: 1)
2009-11-10 16:55:23,518 (main) [DEBUG - org.hibernate.jdbc.AbstractBatcher] - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2009-11-10 16:55:23,518 (main) [DEBUG - org.hibernate.engine.TwoPhaseLoad] - resolving associations for [com.foo.entity.Keyword#150150]
2009-11-10 16:55:23,518 (main) [DEBUG - org.hibernate.engine.TwoPhaseLoad] - done materializing entity [com.foo.entity.Keyword#150150]
2009-11-10 16:55:23,518 (main) [DEBUG - org.hibernate.engine.StatefulPersistenceContext] - initializing non-lazy collections
2009-11-10 16:55:23,518 (main) [DEBUG - com.foo.categoryloader.service.DefaultCategoryLoaderService] - about to add a keyword to a category
2009-11-10 16:55:23,519 (main) [ERROR - org.hibernate.LazyInitializationException] - failed to lazily initialize a collection of role: com.foo.entity.Category.keywords, no session or session was closed
org.hibernate.LazyInitializationException: failed to lazily initialize a collection of role: com.foo.entity.Category.keywords, no session or session was closed
	at org.hibernate.collection.AbstractPersistentCollection.throwLazyInitializationException(AbstractPersistentCollection.java:380)
	at org.hibernate.collection.AbstractPersistentCollection.throwLazyInitializationExceptionIfNotConnected(AbstractPersistentCollection.java:372)
	at org.hibernate.collection.AbstractPersistentCollection.initialize(AbstractPersistentCollection.java:365)
	at org.hibernate.collection.PersistentSet.add(PersistentSet.java:212)
	at com.foo.dao.hibernate.HibernateCategoryDAO.addKeywordToCategory(HibernateCategoryDAO.java:42)
	at com.foo.categoryloader.service.DefaultCategoryLoaderService.loadCategoryAndKeywords(DefaultCategoryLoaderService.java:103)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:307)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:182)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:149)
	at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:106)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
	at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:89)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
	at $Proxy0.loadCategoryAndKeywords(Unknown Source)
	at com.foo.categoryloader.tool.Application.loadFile(Application.java:95)
	at com.foo.categoryloader.tool.Application.run(Application.java:54)
	at com.foo.categoryloader.tool.Application.main(Application.java:42)
2009-11-10 16:55:23,520 (main) [DEBUG - org.springframework.orm.hibernate3.HibernateTransactionManager] - Initiating transaction rollback
2009-11-10 16:55:23,520 (main) [DEBUG - org.springframework.orm.hibernate3.HibernateTransactionManager] - Rolling back Hibernate transaction on Session [org.hibernate.impl.SessionImpl@3414a97b]
2009-11-10 16:55:23,520 (main) [DEBUG - org.hibernate.transaction.JDBCTransaction] - rollback
2009-11-10 16:55:23,521 (main) [DEBUG - org.hibernate.transaction.JDBCTransaction] - re-enabling autocommit
2009-11-10 16:55:23,521 (main) [DEBUG - org.hibernate.transaction.JDBCTransaction] - rolled back JDBC Connection
2009-11-10 16:55:23,521 (main) [DEBUG - org.hibernate.jdbc.ConnectionManager] - transaction completed on session with on_close connection release mode; be sure to close the session to release JDBC resources!
2009-11-10 16:55:23,521 (main) [DEBUG - org.springframework.orm.hibernate3.HibernateTransactionManager] - Closing Hibernate Session [org.hibernate.impl.SessionImpl@3414a97b] after transaction
2009-11-10 16:55:23,523 (main) [DEBUG - org.springframework.orm.hibernate3.SessionFactoryUtils] - Closing Hibernate Session
2009-11-10 16:55:23,523 (main) [DEBUG - org.hibernate.jdbc.ConnectionManager] - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
2009-11-10 16:55:23,523 (main) [DEBUG - org.hibernate.jdbc.ConnectionManager] - transaction completed on session with on_close connection release mode; be sure to close the session to release JDBC resources!

(Note the TransactionInterceptor / proper AOP advice being applied in the stack trace.)

As I understand it, the Session should be preserved (and according to DEBUG level logging, it is) and all operations within loadCategoryAndKeywords() is performed within a single transaction. In the end, the category instance is detached which doesn't make sense to me.

Provided the same session is open, there's a transaction in play, and I don't explicitly detach an entity, shouldn't this still be attached to the current session?

I know this has been hashed out thousands of times (lazy init exceptions, I mean) so I apologize in advance, but I couldn't find anything addressing this, specifically.

Thanks in advance.

[esammer]

As expected, I had done something silly. I'm documenting this here for posterity (and attrition).

I had been pushing certain categories into an LRU cache to eliminate excessive lookups. Because I was doing this outside of Hibernate (rather than using the second level cache facility) the instance of the Category I retrieved from the cache was retrieved from a since-closed Session. The error was spot on; while I was in *a* Session, I was not in *the* Session and so the entity was (properly) detached.

The reason I wasn't using Hibernate's second level cache and was using EhCache directly is because this initially started with plain ol' JDBC.

Live and learn, it seems.