Hibernate 2.1.6 with DB2 8.1.4

We are trying to use a query cache for a set of methods which query tables frequently. We are finding cases where with the query cache enabled we get LazyInitializationExceptions whereas without the query cache, all is well. How could this happen? Here's a debug log with a simple example. The first transaction happens as part of a page load and the query obviously goes all the way to the database. The second transaction is part of a page reload and gets the results from the query cache.

2004-12-06 21:10:30,655 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - opened session
2004-12-06 21:10:30,655 [thread-pool-21] DEBUG hibernate.transaction.JDBCTransaction - begin
2004-12-06 21:10:30,655 [thread-pool-21] DEBUG hibernate.transaction.JDBCTransaction - current autocommit status:true
2004-12-06 21:10:30,655 [thread-pool-21] DEBUG hibernate.transaction.JDBCTransaction - disabling autocommit
2004-12-06 21:10:30,665 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - find: from TradingPartner tp where tp.hosting = true
2004-12-06 21:10:30,665 [thread-pool-21] DEBUG hibernate.engine.QueryParameters - named parameters: {}
2004-12-06 21:10:30,665 [thread-pool-21] DEBUG hibernate.hql.QueryTranslator - compiling query
2004-12-06 21:10:30,665 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - flushing session
2004-12-06 21:10:30,665 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - Flushing entities and processing referenced collections
2004-12-06 21:10:30,665 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - Processing unreferenced collections
2004-12-06 21:10:30,665 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - Scheduling collection removes/(re)creates/updates
2004-12-06 21:10:30,665 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - Flushed: 0 insertions, 0 updates, 0 deletions to 0 objects
2004-12-06 21:10:30,665 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
2004-12-06 21:10:30,665 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - Dont need to execute flush
2004-12-06 21:10:30,665 [thread-pool-21] DEBUG hibernate.hql.QueryTranslator - HQL: from com.webify.csa.domain.partner.TradingPartner tp where tp.hosting = true
2004-12-06 21:10:30,665 [thread-pool-21] DEBUG hibernate.hql.QueryTranslator - SQL: select tradingpar0_.id as id, tradingpar0_.name as name, tradingpar0_.organization_id as organiza3_, tradingpar0_.tax_id as tax_id, tradingpar0_.partner_key as partner_5_, tradingpar0_.hosting as hosting, tradingpar0_.date_created as date_cre7_, tradingpar0_.date_modified as date_mod8_ from DB2USER.csa_tp tradingpar0_ where (tradingpar0_.hosting='T' )
2004-12-06 21:10:30,665 [thread-pool-21] DEBUG hibernate.cache.StandardQueryCache - checking cached query results in region: net.sf.hibernate.cache.StandardQueryCache
2004-12-06 21:10:30,665 [thread-pool-21] DEBUG hibernate.cache.StandardQueryCache - query results were not found in cache
2004-12-06 21:10:30,665 [thread-pool-21] DEBUG hibernate.impl.BatcherImpl - about to open: 0 open PreparedStatements, 0 open ResultSets
2004-12-06 21:10:30,665 [thread-pool-21] DEBUG sf.hibernate.SQL - select tradingpar0_.id as id, tradingpar0_.name as name, tradingpar0_.organization_id as organiza3_, tradingpar0_.tax_id as tax_id, tradingpar0_.partner_key as partner_5_, tradingpar0_.hosting as hosting, tradingpar0_.date_created as date_cre7_, tradingpar0_.date_modified as date_mod8_ from DB2USER.csa_tp tradingpar0_ where (tradingpar0_.hosting='T' )
2004-12-06 21:10:30,665 [thread-pool-21] DEBUG hibernate.impl.BatcherImpl - preparing statement
2004-12-06 21:10:30,775 [thread-pool-21] DEBUG hibernate.loader.Loader - processing result set
2004-12-06 21:10:30,775 [thread-pool-21] DEBUG hibernate.loader.Loader - result row: 4028828300ab61410100ab6158c30002
2004-12-06 21:10:30,775 [thread-pool-21] DEBUG hibernate.loader.Loader - Initializing object from ResultSet: 4028828300ab61410100ab6158c30002
2004-12-06 21:10:30,775 [thread-pool-21] DEBUG hibernate.loader.Loader - Hydrating entity: com.webify.csa.domain.partner.TradingPartner#4028828300ab61410100ab6158c30002
2004-12-06 21:10:30,775 [thread-pool-21] DEBUG hibernate.loader.Loader - done processing result set (1 rows)
2004-12-06 21:10:30,775 [thread-pool-21] DEBUG hibernate.impl.BatcherImpl - done closing: 0 open PreparedStatements, 0 open ResultSets
2004-12-06 21:10:30,775 [thread-pool-21] DEBUG hibernate.impl.BatcherImpl - closing statement
2004-12-06 21:10:30,775 [thread-pool-21] DEBUG hibernate.loader.Loader - total objects hydrated: 1
2004-12-06 21:10:30,775 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - resolving associations for [com.webify.csa.domain.partner.TradingPartner#4028828300ab61410100ab6158c30002]
2004-12-06 21:10:30,775 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - creating collection wrapper:[com.webify.csa.domain.partner.TradingPartner.divisions#4028828300ab61410100ab6158c30002]
2004-12-06 21:10:30,775 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - adding entity to second-level cache [com.webify.csa.domain.partner.TradingPartner#4028828300ab61410100ab6158c30002]
2004-12-06 21:10:30,775 [thread-pool-21] DEBUG hibernate.cache.NonstrictReadWriteCache - Caching: 4028828300ab61410100ab6158c30002
2004-12-06 21:10:30,775 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - calling onLoad()
2004-12-06 21:10:30,775 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - done materializing entity [com.webify.csa.domain.partner.TradingPartner#4028828300ab61410100ab6158c30002]
2004-12-06 21:10:30,775 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - initializing non-lazy collections
2004-12-06 21:10:30,775 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - initializing collection [com.webify.csa.domain.partner.TradingPartner.divisions#4028828300ab61410100ab6158c30002]
2004-12-06 21:10:30,775 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - checking second-level cache
2004-12-06 21:10:30,775 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - collection not cached
2004-12-06 21:10:30,775 [thread-pool-21] DEBUG hibernate.impl.BatcherImpl - about to open: 0 open PreparedStatements, 0 open ResultSets
2004-12-06 21:10:30,775 [thread-pool-21] DEBUG sf.hibernate.SQL - select divisions0_.tp_id as tp_id__, divisions0_.id as id__, divisions0_.id as id0_, divisions0_.division_type as division2_0_, divisions0_.tp_id as tp_id0_, divisions0_.name as name0_, divisions0_.division_key as division5_0_, divisions0_.date_created as date_cre6_0_, divisions0_.date_modified as date_mod7_0_, divisions0_.archive_type as archive_8_0_ from DB2USER.csa_division divisions0_ where divisions0_.tp_id=?
2004-12-06 21:10:30,775 [thread-pool-21] DEBUG hibernate.impl.BatcherImpl - preparing statement
2004-12-06 21:10:30,775 [thread-pool-21] DEBUG hibernate.loader.Loader - result set contains (possibly empty) collection: [com.webify.csa.domain.partner.TradingPartner.divisions#4028828300ab61410100ab6158c30002]
2004-12-06 21:10:30,775 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - uninitialized collection: initializing
2004-12-06 21:10:30,775 [thread-pool-21] DEBUG hibernate.loader.Loader - processing result set
2004-12-06 21:10:30,775 [thread-pool-21] DEBUG hibernate.loader.Loader - result row: 4028828300ab61610100ab6179130002
2004-12-06 21:10:30,775 [thread-pool-21] DEBUG hibernate.loader.Loader - Initializing object from ResultSet: 4028828300ab61610100ab6179130002
2004-12-06 21:10:30,775 [thread-pool-21] DEBUG hibernate.loader.Loader - Hydrating entity: com.webify.csa.domain.partner.Payer#4028828300ab61610100ab6179130002
2004-12-06 21:10:30,775 [thread-pool-21] DEBUG hibernate.loader.Loader - found row of collection: [com.webify.csa.domain.partner.TradingPartner.divisions#4028828300ab61410100ab6158c30002]
2004-12-06 21:10:30,775 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - reading row
2004-12-06 21:10:30,785 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - loading [com.webify.csa.domain.partner.Division#4028828300ab61610100ab6179130002]
2004-12-06 21:10:30,785 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - attempting to resolve [com.webify.csa.domain.partner.Division#4028828300ab61610100ab6179130002]
2004-12-06 21:10:30,785 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - resolved object in session cache [com.webify.csa.domain.partner.Division#4028828300ab61610100ab6179130002]
2004-12-06 21:10:30,785 [thread-pool-21] DEBUG hibernate.loader.Loader - result row: 4028828300ab61610100ab6179130003
2004-12-06 21:10:30,785 [thread-pool-21] DEBUG hibernate.loader.Loader - Initializing object from ResultSet: 4028828300ab61610100ab6179130003
2004-12-06 21:10:30,785 [thread-pool-21] DEBUG hibernate.loader.Loader - Hydrating entity: com.webify.csa.domain.partner.Payer#4028828300ab61610100ab6179130003
2004-12-06 21:10:30,785 [thread-pool-21] DEBUG hibernate.loader.Loader - found row of collection: [com.webify.csa.domain.partner.TradingPartner.divisions#4028828300ab61410100ab6158c30002]
2004-12-06 21:10:30,955 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - reading row
2004-12-06 21:10:30,955 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - loading [com.webify.csa.domain.partner.Division#4028828300ab61610100ab6179130003]
2004-12-06 21:10:30,955 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - attempting to resolve [com.webify.csa.domain.partner.Division#4028828300ab61610100ab6179130003]
2004-12-06 21:10:30,955 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - resolved object in session cache [com.webify.csa.domain.partner.Division#4028828300ab61610100ab6179130003]
2004-12-06 21:10:30,955 [thread-pool-21] DEBUG hibernate.loader.Loader - result row: 4028828300ab61610100ab6179130004
2004-12-06 21:10:30,955 [thread-pool-21] DEBUG hibernate.loader.Loader - Initializing object from ResultSet: 4028828300ab61610100ab6179130004
2004-12-06 21:10:30,955 [thread-pool-21] DEBUG hibernate.loader.Loader - Hydrating entity: com.webify.csa.domain.partner.Payer#4028828300ab61610100ab6179130004
2004-12-06 21:10:30,955 [thread-pool-21] DEBUG hibernate.loader.Loader - found row of collection: [com.webify.csa.domain.partner.TradingPartner.divisions#4028828300ab61410100ab6158c30002]
2004-12-06 21:10:30,955 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - reading row
2004-12-06 21:10:30,955 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - loading [com.webify.csa.domain.partner.Division#4028828300ab61610100ab6179130004]
2004-12-06 21:10:30,955 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - attempting to resolve [com.webify.csa.domain.partner.Division#4028828300ab61610100ab6179130004]
2004-12-06 21:10:30,955 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - resolved object in session cache [com.webify.csa.domain.partner.Division#4028828300ab61610100ab6179130004]
2004-12-06 21:10:30,955 [thread-pool-21] DEBUG hibernate.loader.Loader - done processing result set (3 rows)
2004-12-06 21:10:30,955 [thread-pool-21] DEBUG hibernate.impl.BatcherImpl - done closing: 0 open PreparedStatements, 0 open ResultSets
2004-12-06 21:10:30,955 [thread-pool-21] DEBUG hibernate.impl.BatcherImpl - closing statement
2004-12-06 21:10:30,955 [thread-pool-21] DEBUG hibernate.loader.Loader - total objects hydrated: 3
2004-12-06 21:10:30,955 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - resolving associations for [com.webify.csa.domain.partner.Payer#4028828300ab61610100ab6179130002]
2004-12-06 21:10:30,955 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - creating collection wrapper:[com.webify.csa.domain.partner.Payer.subscribers#4028828300ab61610100ab6179130002]
2004-12-06 21:10:30,955 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - loading [com.webify.csa.domain.partner.TradingPartner#4028828300ab61410100ab6158c30002]
2004-12-06 21:10:30,955 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - attempting to resolve [com.webify.csa.domain.partner.TradingPartner#4028828300ab61410100ab6158c30002]
2004-12-06 21:10:30,955 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - resolved object in session cache [com.webify.csa.domain.partner.TradingPartner#4028828300ab61410100ab6158c30002]
2004-12-06 21:10:30,955 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - adding entity to second-level cache [com.webify.csa.domain.partner.Payer#4028828300ab61610100ab6179130002]
2004-12-06 21:10:30,955 [thread-pool-21] DEBUG hibernate.cache.NonstrictReadWriteCache - Caching: 4028828300ab61610100ab6179130002
2004-12-06 21:10:30,955 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - calling onLoad()
2004-12-06 21:10:30,955 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - done materializing entity [com.webify.csa.domain.partner.Payer#4028828300ab61610100ab6179130002]
2004-12-06 21:10:30,955 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - resolving associations for [com.webify.csa.domain.partner.Payer#4028828300ab61610100ab6179130003]
2004-12-06 21:10:30,955 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - creating collection wrapper:[com.webify.csa.domain.partner.Payer.subscribers#4028828300ab61610100ab6179130003]
2004-12-06 21:10:30,955 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - loading [com.webify.csa.domain.partner.TradingPartner#4028828300ab61410100ab6158c30002]
2004-12-06 21:10:30,955 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - attempting to resolve [com.webify.csa.domain.partner.TradingPartner#4028828300ab61410100ab6158c30002]
2004-12-06 21:10:30,955 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - resolved object in session cache [com.webify.csa.domain.partner.TradingPartner#4028828300ab61410100ab6158c30002]
2004-12-06 21:10:30,955 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - adding entity to second-level cache [com.webify.csa.domain.partner.Payer#4028828300ab61610100ab6179130003]
2004-12-06 21:10:30,955 [thread-pool-21] DEBUG hibernate.cache.NonstrictReadWriteCache - Caching: 4028828300ab61610100ab6179130003
2004-12-06 21:10:30,955 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - calling onLoad()
2004-12-06 21:10:30,955 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - done materializing entity [com.webify.csa.domain.partner.Payer#4028828300ab61610100ab6179130003]
2004-12-06 21:10:30,955 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - resolving associations for [com.webify.csa.domain.partner.Payer#4028828300ab61610100ab6179130004]
2004-12-06 21:10:30,955 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - creating collection wrapper:[com.webify.csa.domain.partner.Payer.subscribers#4028828300ab61610100ab6179130004]
2004-12-06 21:10:30,955 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - loading [com.webify.csa.domain.partner.TradingPartner#4028828300ab61410100ab6158c30002]
2004-12-06 21:10:30,955 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - attempting to resolve [com.webify.csa.domain.partner.TradingPartner#4028828300ab61410100ab6158c30002]
2004-12-06 21:10:30,955 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - resolved object in session cache [com.webify.csa.domain.partner.TradingPartner#4028828300ab61410100ab6158c30002]
2004-12-06 21:10:30,955 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - adding entity to second-level cache [com.webify.csa.domain.partner.Payer#4028828300ab61610100ab6179130004]
2004-12-06 21:10:30,955 [thread-pool-21] DEBUG hibernate.cache.NonstrictReadWriteCache - Caching: 4028828300ab61610100ab6179130004
2004-12-06 21:10:30,955 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - calling onLoad()
2004-12-06 21:10:30,955 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - done materializing entity [com.webify.csa.domain.partner.Payer#4028828300ab61610100ab6179130004]
2004-12-06 21:10:30,955 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - 1 collections were found in result set
2004-12-06 21:10:30,955 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - collection fully initialized: [com.webify.csa.domain.partner.TradingPartner.divisions#4028828300ab61410100ab6158c30002]
2004-12-06 21:10:30,955 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - 1 collections initialized
2004-12-06 21:10:30,955 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - collection initialized
2004-12-06 21:10:30,955 [thread-pool-21] DEBUG hibernate.cache.StandardQueryCache - caching query results in region: net.sf.hibernate.cache.StandardQueryCache
2004-12-06 21:10:30,955 [thread-pool-21] DEBUG hibernate.transaction.JDBCTransaction - commit
2004-12-06 21:10:30,955 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - flushing session
2004-12-06 21:10:31,196 [thread-pool-21] DEBUG hibernate.engine.Cascades - processing cascades for: com.webify.csa.domain.partner.TradingPartner
2004-12-06 21:10:31,196 [thread-pool-21] DEBUG hibernate.engine.Cascades - cascading to collection: com.webify.csa.domain.partner.TradingPartner.divisions
2004-12-06 21:10:31,196 [thread-pool-21] DEBUG hibernate.engine.Cascades - cascading to saveOrUpdate()
2004-12-06 21:10:31,196 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - saveOrUpdate() persistent instance
2004-12-06 21:10:31,196 [thread-pool-21] DEBUG hibernate.engine.Cascades - cascading to saveOrUpdate()
2004-12-06 21:10:31,196 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - saveOrUpdate() persistent instance
2004-12-06 21:10:31,196 [thread-pool-21] DEBUG hibernate.engine.Cascades - cascading to saveOrUpdate()
2004-12-06 21:10:31,196 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - saveOrUpdate() persistent instance
2004-12-06 21:10:31,196 [thread-pool-21] DEBUG hibernate.engine.Cascades - done processing cascades for: com.webify.csa.domain.partner.TradingPartner
2004-12-06 21:10:31,196 [thread-pool-21] DEBUG hibernate.engine.Cascades - processing cascades for: com.webify.csa.domain.partner.Payer
2004-12-06 21:10:31,196 [thread-pool-21] DEBUG hibernate.engine.Cascades - cascading to collection: com.webify.csa.domain.partner.Payer.subscribers
2004-12-06 21:10:31,196 [thread-pool-21] DEBUG hibernate.engine.Cascades - done processing cascades for: com.webify.csa.domain.partner.Payer
2004-12-06 21:10:31,196 [thread-pool-21] DEBUG hibernate.engine.Cascades - processing cascades for: com.webify.csa.domain.partner.Payer
2004-12-06 21:10:31,196 [thread-pool-21] DEBUG hibernate.engine.Cascades - cascading to collection: com.webify.csa.domain.partner.Payer.subscribers
2004-12-06 21:10:31,196 [thread-pool-21] DEBUG hibernate.engine.Cascades - done processing cascades for: com.webify.csa.domain.partner.Payer
2004-12-06 21:10:31,196 [thread-pool-21] DEBUG hibernate.engine.Cascades - processing cascades for: com.webify.csa.domain.partner.Payer
2004-12-06 21:10:31,196 [thread-pool-21] DEBUG hibernate.engine.Cascades - cascading to collection: com.webify.csa.domain.partner.Payer.subscribers
2004-12-06 21:10:31,196 [thread-pool-21] DEBUG hibernate.engine.Cascades - done processing cascades for: com.webify.csa.domain.partner.Payer
2004-12-06 21:10:31,196 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - Flushing entities and processing referenced collections
2004-12-06 21:10:31,196 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - Collection found: [com.webify.csa.domain.partner.TradingPartner.divisions#4028828300ab61410100ab6158c30002], was: [com.webify.csa.domain.partner.TradingPartner.divisions#4028828300ab61410100ab6158c30002]
2004-12-06 21:10:31,196 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - Collection found: [com.webify.csa.domain.partner.Payer.subscribers#4028828300ab61610100ab6179130002], was: [com.webify.csa.domain.partner.Payer.subscribers#4028828300ab61610100ab6179130002]
2004-12-06 21:10:31,196 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - Collection found: [com.webify.csa.domain.partner.Payer.subscribers#4028828300ab61610100ab6179130003], was: [com.webify.csa.domain.partner.Payer.subscribers#4028828300ab61610100ab6179130003]
2004-12-06 21:10:31,196 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - Collection found: [com.webify.csa.domain.partner.Payer.subscribers#4028828300ab61610100ab6179130004], was: [com.webify.csa.domain.partner.Payer.subscribers#4028828300ab61610100ab6179130004]
2004-12-06 21:10:31,326 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - Processing unreferenced collections
2004-12-06 21:10:31,326 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - Scheduling collection removes/(re)creates/updates
2004-12-06 21:10:31,326 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - Flushed: 0 insertions, 0 updates, 0 deletions to 4 objects
2004-12-06 21:10:31,326 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - Flushed: 0 (re)creations, 0 updates, 0 removals to 4 collections
2004-12-06 21:10:31,326 [thread-pool-21] DEBUG hibernate.impl.Printer - listing entities:
2004-12-06 21:10:31,326 [thread-pool-21] DEBUG hibernate.impl.Printer - com.webify.csa.domain.partner.Payer{dateModified=2004-12-06 20:35:19, divisionKey=BCBS, subscribers=uninitialized, tradingPartner=TradingPartner#4028828300ab61410100ab6158c30002, dateCreated=2004-12-06 20:35:19, name=Blue Cross Blue Shield, id=4028828300ab61610100ab6179130004}
2004-12-06 21:10:31,326 [thread-pool-21] DEBUG hibernate.impl.Printer - com.webify.csa.domain.partner.TradingPartner{taxId=34-234392, hosting=true, partnerKey=TP001, dateModified=2004-12-06 20:35:11, organizationId=4028828300ab5fe40100ab6131ff0088, divisions=[Payer#4028828300ab61610100ab6179130003, Payer#4028828300ab61610100ab6179130004, Payer#4028828300ab61610100ab6179130002], dateCreated=2004-12-06 20:35:11, name=BCBS Arkansas, id=4028828300ab61410100ab6158c30002}
2004-12-06 21:10:31,326 [thread-pool-21] DEBUG hibernate.impl.Printer - com.webify.csa.domain.partner.Payer{dateModified=2004-12-06 20:35:19, divisionKey=BAAA, subscribers=uninitialized, tradingPartner=TradingPartner#4028828300ab61410100ab6158c30002, dateCreated=2004-12-06 20:35:19, name=Blue Advantage, id=4028828300ab61610100ab6179130002}
2004-12-06 21:10:31,326 [thread-pool-21] DEBUG hibernate.impl.Printer - com.webify.csa.domain.partner.Payer{dateModified=2004-12-06 20:35:19, divisionKey=HA, subscribers=uninitialized, tradingPartner=TradingPartner#4028828300ab61410100ab6158c30002, dateCreated=2004-12-06 20:35:19, name=Health Advantage, id=4028828300ab61610100ab6179130003}
2004-12-06 21:10:31,326 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - executing flush
2004-12-06 21:10:31,326 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - post flush
2004-12-06 21:10:31,326 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - transaction completion
2004-12-06 21:10:31,326 [thread-pool-21] DEBUG hibernate.transaction.JDBCTransaction - re-enabling autocommit
2004-12-06 21:10:31,326 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - closing session
2004-12-06 21:10:31,326 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - disconnecting session
2004-12-06 21:10:31,326 [thread-pool-21] DEBUG hibernate.impl.SessionImpl - transaction completion


2004-12-06 21:10:35,792 [thread-pool-22] DEBUG hibernate.impl.SessionImpl - opened session
2004-12-06 21:10:35,792 [thread-pool-22] DEBUG hibernate.transaction.JDBCTransaction - begin
2004-12-06 21:10:35,792 [thread-pool-22] DEBUG hibernate.transaction.JDBCTransaction - current autocommit status:true
2004-12-06 21:10:35,802 [thread-pool-22] DEBUG hibernate.transaction.JDBCTransaction - disabling autocommit
2004-12-06 21:10:35,802 [thread-pool-22] DEBUG hibernate.impl.SessionImpl - find: from TradingPartner tp where tp.hosting = true
2004-12-06 21:10:35,812 [thread-pool-22] DEBUG hibernate.engine.QueryParameters - named parameters: {}
2004-12-06 21:10:35,812 [thread-pool-22] DEBUG hibernate.impl.SessionImpl - flushing session
2004-12-06 21:10:35,812 [thread-pool-22] DEBUG hibernate.impl.SessionImpl - Flushing entities and processing referenced collections
2004-12-06 21:10:35,812 [thread-pool-22] DEBUG hibernate.impl.SessionImpl - Processing unreferenced collections
2004-12-06 21:10:35,812 [thread-pool-22] DEBUG hibernate.impl.SessionImpl - Scheduling collection removes/(re)creates/updates
2004-12-06 21:10:35,812 [thread-pool-22] DEBUG hibernate.impl.SessionImpl - Flushed: 0 insertions, 0 updates, 0 deletions to 0 objects
2004-12-06 21:10:35,812 [thread-pool-22] DEBUG hibernate.impl.SessionImpl - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
2004-12-06 21:10:35,812 [thread-pool-22] DEBUG hibernate.impl.SessionImpl - Dont need to execute flush
2004-12-06 21:10:35,812 [thread-pool-22] DEBUG hibernate.hql.QueryTranslator - HQL: from com.webify.csa.domain.partner.TradingPartner tp where tp.hosting = true
2004-12-06 21:10:35,812 [thread-pool-22] DEBUG hibernate.hql.QueryTranslator - SQL: select tradingpar0_.id as id, tradingpar0_.name as name, tradingpar0_.organization_id as organiza3_, tradingpar0_.tax_id as tax_id, tradingpar0_.partner_key as partner_5_, tradingpar0_.hosting as hosting, tradingpar0_.date_created as date_cre7_, tradingpar0_.date_modified as date_mod8_ from DB2USER.csa_tp tradingpar0_ where (tradingpar0_.hosting='T' )
2004-12-06 21:10:35,812 [thread-pool-22] DEBUG hibernate.cache.StandardQueryCache - checking cached query results in region: net.sf.hibernate.cache.StandardQueryCache
2004-12-06 21:10:35,812 [thread-pool-22] DEBUG hibernate.cache.StandardQueryCache - Checking query spaces for up-to-dateness [[DB2USER.csa_tp]]
2004-12-06 21:10:35,812 [thread-pool-22] DEBUG hibernate.cache.StandardQueryCache - returning cached query results
2004-12-06 21:10:35,812 [thread-pool-22] DEBUG hibernate.impl.SessionImpl - loading [com.webify.csa.domain.partner.TradingPartner#4028828300ab61410100ab6158c30002]
2004-12-06 21:10:35,812 [thread-pool-22] DEBUG hibernate.transaction.JDBCTransaction - commit
2004-12-06 21:10:35,812 [thread-pool-22] DEBUG hibernate.impl.SessionImpl - flushing session
2004-12-06 21:10:35,812 [thread-pool-22] DEBUG hibernate.impl.SessionImpl - Flushing entities and processing referenced collections
2004-12-06 21:10:35,812 [thread-pool-22] DEBUG hibernate.impl.SessionImpl - Processing unreferenced collections
2004-12-06 21:10:35,812 [thread-pool-22] DEBUG hibernate.impl.SessionImpl - Scheduling collection removes/(re)creates/updates
2004-12-06 21:10:35,812 [thread-pool-22] DEBUG hibernate.impl.SessionImpl - Flushed: 0 insertions, 0 updates, 0 deletions to 0 objects
2004-12-06 21:10:35,812 [thread-pool-22] DEBUG hibernate.impl.SessionImpl - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
2004-12-06 21:10:35,812 [thread-pool-22] DEBUG hibernate.impl.SessionImpl - executing flush
2004-12-06 21:10:35,812 [thread-pool-22] DEBUG hibernate.impl.SessionImpl - post flush
2004-12-06 21:10:35,822 [thread-pool-22] DEBUG hibernate.impl.SessionImpl - transaction completion
2004-12-06 21:10:35,822 [thread-pool-22] DEBUG hibernate.transaction.JDBCTransaction - re-enabling autocommit
2004-12-06 21:10:35,822 [thread-pool-22] DEBUG hibernate.impl.SessionImpl - closing session
2004-12-06 21:10:35,822 [thread-pool-22] DEBUG hibernate.impl.SessionImpl - disconnecting session
2004-12-06 21:10:35,942 [thread-pool-22] DEBUG hibernate.impl.SessionImpl - transaction completion
2004-12-06 21:10:35,972 [thread-pool-22] ERROR hibernate.proxy.LazyInitializer - Exception initializing proxy
net.sf.hibernate.HibernateException: Could not initialize proxy - the owning Session was closed
at net.sf.hibernate.proxy.LazyInitializer.initialize(LazyInitializer.java:47)
at net.sf.hibernate.proxy.LazyInitializer.initializeWrapExceptions(LazyInitializer.java:60)
at net.sf.hibernate.proxy.LazyInitializer.getImplementation(LazyInitializer.java:164)
at net.sf.hibernate.proxy.CGLIBLazyInitializer.intercept(CGLIBLazyInitializer.java:108)
at com.webify.csa.domain.partner.TradingPartner$$EnhancerByCGLIB$$62220fb1.toString(<generated>)
at java.lang.String.valueOf(String.java:2131)
at java.util.AbstractCollection.toString(AbstractCollection.java:455)
at java.lang.String.valueOf(String.java:2131)
at java.lang.StringBuffer.append(StringBuffer.java:370)
at com.webify.csa.web.pages.portal.document.DocumentList.getFromPartners(DocumentList.java:264)
at com.webify.csa.web.pages.portal.document.DocumentList.getFromPartnerPsm(DocumentList.java:270)
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:324)
at ognl.OgnlRuntime.invokeMethod(OgnlRuntime.java:320)
at ognl.OgnlRuntime.getMethodValue(OgnlRuntime.java:728)
at ognl.ObjectPropertyAccessor.getPossibleProperty(ObjectPropertyAccessor.java:54)
at ognl.ObjectPropertyAccessor.getProperty(ObjectPropertyAccessor.java:122)
at ognl.OgnlRuntime.getProperty(OgnlRuntime.java:1443)
at ognl.ASTProperty.getValueBody(ASTProperty.java:96)
at ognl.SimpleNode.getValue(SimpleNode.java:192)
at ognl.Ognl.getValue(Ognl.java:335)
at ognl.Ognl.getValue(Ognl.java:310)
at org.apache.tapestry.binding.ExpressionBinding.resolveProperty(ExpressionBinding.java:201)
at org.apache.tapestry.binding.ExpressionBinding.getObject(ExpressionBinding.java:194)
at org.apache.tapestry.binding.AbstractBinding.getObject(AbstractBinding.java:208)
at org.apache.tapestry.param.AbstractParameterConnector.getBindingValue(AbstractParameterConnector.java:105)
at org.apache.tapestry.param.ObjectParameterConnector.setParameter(ObjectParameterConnector.java:53)
at org.apache.tapestry.param.ParameterManager.setParameters(ParameterManager.java:105)
at org.apache.tapestry.AbstractComponent.prepareForRender(AbstractComponent.java:898)
at org.apache.tapestry.AbstractComponent.render(AbstractComponent.java:853)
at org.apache.tapestry.AbstractComponent.renderBody(AbstractComponent.java:624)
at org.apache.tapestry.form.Form.renderComponent(Form.java:362)
at org.apache.tapestry.AbstractComponent.render(AbstractComponent.java:857)
at org.apache.tapestry.form.Form.rewind(Form.java:568)
at org.apache.tapestry.engine.RequestCycle.rewindForm(RequestCycle.java:435)
at org.apache.tapestry.form.Form.trigger(Form.java:582)
at org.apache.tapestry.engine.DirectService.service(DirectService.java:169)
at org.apache.tapestry.engine.AbstractEngine.service(AbstractEngine.java:872)
at com.webify.webapp.web.WebifyEngine.service(WebifyEngine.java:31)
at org.apache.tapestry.ApplicationServlet.doService(ApplicationServlet.java:197)
at org.apache.tapestry.ApplicationServlet.doPost(ApplicationServlet.java:326)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:152)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:90)
at com.caucho.server.dispatch.ServletFilterChain.doFilter(ServletFilterChain.java:99)
at com.caucho.server.webapp.WebAppFilterChain.doFilter(WebAppFilterChain.java:163)
at com.caucho.server.dispatch.ServletInvocation.service(ServletInvocation.java:207)
at com.caucho.server.http.HttpRequest.handleRequest(HttpRequest.java:249)
at com.caucho.server.port.TcpConnection.run(TcpConnection.java:327)
at com.caucho.util.ThreadPool.runTasks(ThreadPool.java:450)
at com.caucho.util.ThreadPool.run(ThreadPool.java:394)
at java.lang.Thread.run(Thread.java:534)