Here are the logs when the fetch=join is NOT specified. Please note the statements marked in bold in the logs:
Quote:
2006-04-21 23:13:41,937 DEBUG [com.dbdata.system.persistence.ObjectHandler] ObjectHandler.getObjectById(klass, id)
2006-04-21 23:13:41,937 DEBUG [com.dbdata.system.persistence.ObjectHandler] ObjectHandler.getObjectById(klass, id, loadLobs): (com.dbdata.processingengine.hibernateobject.CrProcessingEngine,com.dbdata.processingengine.hibernateobject.CrProcessingEngineId[id=103, versionId=1])
2006-04-21 23:13:41,937 DEBUG [com.dbdata.system.persistence.SessionHandler] SessionHandler.getHibernateSession()
2006-04-21 23:13:41,937 DEBUG [com.dbdata.system.util.ServiceLocator] getHibernateSessionFactory(): Entering...
2006-04-21 23:13:41,937 DEBUG [com.dbdata.system.util.ServiceLocator] getHibernateSessionFactory(): seeking cache in cache
2006-04-21 23:13:41,937 DEBUG [com.dbdata.system.util.ServiceLocator] getHibernateSessionFactory(): Entering...
2006-04-21 23:13:41,937 DEBUG [com.dbdata.system.util.ServiceLocator] getHibernateSessionFactory(): seeking cache in cache
2006-04-21 23:13:41,937 DEBUG [com.dbdata.system.persistence.SessionHandler] SessionHandler.getConnFromDataSource() for dataSource:java:/CrmDS
2006-04-21 23:13:41,937 DEBUG [com.dbdata.system.persistence.SessionHandler] SessionHandler.getConnFromDataSource returning connection:org.jboss.resource.adapter.jdbc.WrappedConnection@7216df
2006-04-21 23:13:41,937 DEBUG [org.hibernate.impl.SessionImpl] opened session at timestamp: -92233720368547758082006-04-21 23:13:41,937 DEBUG [org.hibernate.jdbc.JDBCContext] successfully registered Synchronization
2006-04-21 23:13:41,937 DEBUG [com.dbdata.system.persistence.SessionHandler] SessionHandler.getHibernateSession returning session:SessionImpl(PersistenceContext[entityKeys=[],collectionKeys=[]];ActionQueue[insertions=[] updates=[] deletions=[] collectionCreations=[] collectionRemovals=[] collectionUpdates=[]])
2006-04-21 23:13:41,937 DEBUG [org.hibernate.event.def.DefaultLoadEventListener] loading entity: [com.dbdata.processingengine.hibernateobject.CrProcessingEngine#component[id,versionId]{versionId=1, id=103}]
2006-04-21 23:13:41,937 DEBUG [org.hibernate.event.def.DefaultLoadEventListener] attempting to resolve: [com.dbdata.processingengine.hibernateobject.CrProcessingEngine#component[id,versionId]{versionId=1, id=103}]
2006-04-21 23:13:41,937 DEBUG [org.hibernate.event.def.DefaultLoadEventListener] object not resolved in any cache: [com.dbdata.processingengine.hibernateobject.CrProcessingEngine#component[id,versionId]{versionId=1, id=103}]
2006-04-21 23:13:41,937 DEBUG [org.hibernate.persister.entity.AbstractEntityPersister] Fetching entity: [com.dbdata.processingengine.hibernateobject.CrProcessingEngine#component[id,versionId]{versionId=1, id=103}]
2006-04-21 23:13:41,937 DEBUG [org.hibernate.loader.Loader] loading entity: [com.dbdata.processingengine.hibernateobject.CrProcessingEngine#component[id,versionId]{versionId=1, id=103}]
2006-04-21 23:13:41,937 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2006-04-21 23:13:41,937 DEBUG [org.hibernate.SQL] select crprocessi0_.PROCESSING_ENGINE_ID as PROCESSING1_241_0_, crprocessi0_.PROCESSING_ENGINE_VERSION_ID as PROCESSING2_241_0_, crprocessi0_.UPDATE_DTTM as UPDATE4_241_0_, crprocessi0_.Name as Name241_0_, crprocessi0_.Description as Descript6_241_0_, crprocessi0_.Status_Cd as Status7_241_0_, crprocessi0_.OWNER_DIVISION_ID as OWNER8_241_0_, crprocessi0_.REFERENCE_TXT as REFERENCE9_241_0_, crprocessi0_.FOLDER_ID as FOLDER10_241_0_, crprocessi0_.SHARED_IND as SHARED11_241_0_, crprocessi0_.SOURCE_ENTITY_ID as SOURCE12_241_0_, crprocessi0_.SOURCE_VERSION_ID as SOURCE13_241_0_, crprocessi0_.Application_Name_Txt as Applica14_241_0_, crprocessi0_.Component_Type_Cd as Component15_241_0_, crprocessi0_.Processing_Type_Cd as Processing3_241_0_, crprocessi0_.Max_Parallel_Streams_Num as Max16_241_0_, crprocessi0_.Allow_One_To_One_Logon_Ind as Allow17_241_0_, crprocessi0_.Tap_Job_Id as Tap18_241_0_, crprocessi0_.Execution_Parameters_Txt as Execution19_241_0_, crprocessi0_.Lock_Cd as Lock20_241_0_, crprocessi0_.Clone_Ind as Clone21_241_0_, crprocessi0_.Externally_Scheduled_Ind as Externally22_241_0_, crprocessi0_.Best_Lead_Order_Cd as Best23_241_0_, crprocessi0_.Channel_Lead_Order_Cd as Channel24_241_0_, crprocessi0_.Default_User as Default25_241_0_, crprocessi0_.Default_Password as Default26_241_0_, crprocessi0_.UPDATE_USER as UPDATE27_241_0_, crprocessi0_.CREATE_USER as CREATE28_241_0_, crprocessi0_.CREATE_DTTM as CREATE29_241_0_, crprocessi0_.ACTIVATE_USER as ACTIVATE30_241_0_, crprocessi0_.ACTIVATE_DTTM as ACTIVATE31_241_0_ from CR_PROCESSING_ENGINE crprocessi0_ where crprocessi0_.PROCESSING_ENGINE_ID=? and crprocessi0_.PROCESSING_ENGINE_VERSION_ID=?
2006-04-21 23:13:41,937 INFO [STDOUT] Hibernate: select crprocessi0_.PROCESSING_ENGINE_ID as PROCESSING1_241_0_, crprocessi0_.PROCESSING_ENGINE_VERSION_ID as PROCESSING2_241_0_, crprocessi0_.UPDATE_DTTM as UPDATE4_241_0_, crprocessi0_.Name as Name241_0_, crprocessi0_.Description as Descript6_241_0_, crprocessi0_.Status_Cd as Status7_241_0_, crprocessi0_.OWNER_DIVISION_ID as OWNER8_241_0_, crprocessi0_.REFERENCE_TXT as REFERENCE9_241_0_, crprocessi0_.FOLDER_ID as FOLDER10_241_0_, crprocessi0_.SHARED_IND as SHARED11_241_0_, crprocessi0_.SOURCE_ENTITY_ID as SOURCE12_241_0_, crprocessi0_.SOURCE_VERSION_ID as SOURCE13_241_0_, crprocessi0_.Application_Name_Txt as Applica14_241_0_, crprocessi0_.Component_Type_Cd as Component15_241_0_, crprocessi0_.Processing_Type_Cd as Processing3_241_0_, crprocessi0_.Max_Parallel_Streams_Num as Max16_241_0_, crprocessi0_.Allow_One_To_One_Logon_Ind as Allow17_241_0_, crprocessi0_.Tap_Job_Id as Tap18_241_0_, crprocessi0_.Execution_Parameters_Txt as Execution19_241_0_, crprocessi0_.Lock_Cd as Lock20_241_0_, crprocessi0_.Clone_Ind as Clone21_241_0_, crprocessi0_.Externally_Scheduled_Ind as Externally22_241_0_, crprocessi0_.Best_Lead_Order_Cd as Best23_241_0_, crprocessi0_.Channel_Lead_Order_Cd as Channel24_241_0_, crprocessi0_.Default_User as Default25_241_0_, crprocessi0_.Default_Password as Default26_241_0_, crprocessi0_.UPDATE_USER as UPDATE27_241_0_, crprocessi0_.CREATE_USER as CREATE28_241_0_, crprocessi0_.CREATE_DTTM as CREATE29_241_0_, crprocessi0_.ACTIVATE_USER as ACTIVATE30_241_0_, crprocessi0_.ACTIVATE_DTTM as ACTIVATE31_241_0_ from CR_PROCESSING_ENGINE crprocessi0_ where crprocessi0_.PROCESSING_ENGINE_ID=? and crprocessi0_.PROCESSING_ENGINE_VERSION_ID=?
2006-04-21 23:13:41,937 DEBUG [org.hibernate.jdbc.AbstractBatcher] preparing statement
2006-04-21 23:13:41,937 DEBUG [org.hibernate.type.IntegerType] binding '103' to parameter: 1
2006-04-21 23:13:41,937 DEBUG [org.hibernate.type.IntegerType] binding '1' to parameter: 2
2006-04-21 23:13:42,671 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open ResultSet (open ResultSets: 0, globally: 0)
2006-04-21 23:13:42,671 DEBUG [org.hibernate.loader.Loader] processing result set
2006-04-21 23:13:42,671 DEBUG [org.hibernate.loader.Loader] result set row: 0
2006-04-21 23:13:42,671 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[com.dbdata.processingengine.hibernateobject.CrProcessingEngine#component[id,versionId]{versionId=1, id=103}]
2006-04-21 23:13:42,671 DEBUG [org.hibernate.type.ShortType] returning '3' as column: Processing3_241_0_
2006-04-21 23:13:42,671 DEBUG [org.hibernate.loader.Loader] Initializing object from ResultSet: [com.dbdata.processingengine.hibernateobject.CustomProcessingEngine#component[id,versionId]{versionId=1, id=103}]
2006-04-21 23:13:42,671 DEBUG [org.hibernate.persister.entity.AbstractEntityPersister] Hydrating entity: [com.dbdata.processingengine.hibernateobject.CustomProcessingEngine#component[id,versionId]{versionId=1, id=103}]
2006-04-21 23:13:42,671 DEBUG [org.hibernate.type.TimestampType] returning '2006-03-17 09:40:03' as column: UPDATE4_241_0_
2006-04-21 23:13:42,671 DEBUG [org.hibernate.type.StringType] returning 'Custom Seg Plan PE' as column: Name241_0_
2006-04-21 23:13:42,671 DEBUG [org.hibernate.type.StringType] returning '' as column: Descript6_241_0_
2006-04-21 23:13:42,671 DEBUG [org.hibernate.type.ShortType] returning '2' as column: Status7_241_0_
2006-04-21 23:13:42,671 DEBUG [org.hibernate.type.IntegerType] returning '1' as column: OWNER8_241_0_
2006-04-21 23:13:42,671 DEBUG [org.hibernate.type.StringType] returning '' as column: REFERENCE9_241_0_
2006-04-21 23:13:42,671 DEBUG [org.hibernate.type.IntegerType] returning null as column: FOLDER10_241_0_
2006-04-21 23:13:42,671 DEBUG [org.hibernate.type.ByteType] returning null as column: SHARED11_241_0_
2006-04-21 23:13:42,671 DEBUG [org.hibernate.type.IntegerType] returning null as column: SOURCE12_241_0_
2006-04-21 23:13:42,671 DEBUG [org.hibernate.type.IntegerType] returning null as column: SOURCE13_241_0_
2006-04-21 23:13:42,671 DEBUG [org.hibernate.type.StringType] returning 'Segment Plan Processing' as column: Applica14_241_0_
2006-04-21 23:13:42,671 DEBUG [org.hibernate.type.ShortType] returning '32' as column: Component15_241_0_
2006-04-21 23:13:42,671 DEBUG [org.hibernate.type.ShortType] returning '3' as column: Processing3_241_0_
2006-04-21 23:13:42,671 DEBUG [org.hibernate.type.IntegerType] returning '5' as column: Max16_241_0_
2006-04-21 23:13:42,671 DEBUG [org.hibernate.type.BooleanType] returning 'false' as column: Allow17_241_0_
2006-04-21 23:13:42,671 DEBUG [org.hibernate.type.IntegerType] returning null as column: Tap18_241_0_
2006-04-21 23:13:42,671 DEBUG [org.hibernate.type.StringType] returning null as column: Execution19_241_0_
2006-04-21 23:13:42,671 DEBUG [org.hibernate.type.BooleanType] returning 'false' as column: Lock20_241_0_
2006-04-21 23:13:42,671 DEBUG [org.hibernate.type.BooleanType] returning 'false' as column: Clone21_241_0_
2006-04-21 23:13:42,671 DEBUG [org.hibernate.type.BooleanType] returning 'false' as column: Externally22_241_0_
2006-04-21 23:13:42,671 DEBUG [org.hibernate.type.ShortType] returning '0' as column: Best23_241_0_
2006-04-21 23:13:42,671 DEBUG [org.hibernate.type.ShortType] returning '0' as column: Channel24_241_0_
2006-04-21 23:13:42,671 DEBUG [org.hibernate.type.StringType] returning 'mstrm600bu' as column: Default25_241_0_
2006-04-21 23:13:42,671 DEBUG [org.hibernate.type.StringType] returning 'baril3' as column: Default26_241_0_
2006-04-21 23:13:42,671 DEBUG [org.hibernate.type.StringType] returning 'tapadmin' as column: UPDATE27_241_0_
2006-04-21 23:13:42,671 DEBUG [org.hibernate.type.StringType] returning 'tapadmin' as column: CREATE28_241_0_
2006-04-21 23:13:42,671 DEBUG [org.hibernate.type.TimestampType] returning '2006-03-17 09:40:02' as column: CREATE29_241_0_
2006-04-21 23:13:42,671 DEBUG [org.hibernate.type.StringType] returning null as column: ACTIVATE30_241_0_
2006-04-21 23:13:42,671 DEBUG [org.hibernate.type.TimestampType] returning null as column: ACTIVATE31_241_0_
2006-04-21 23:13:42,671 DEBUG [org.hibernate.engine.TwoPhaseLoad] Version: 2006-03-17 09:40:03.123
2006-04-21 23:13:42,671 DEBUG [org.hibernate.loader.Loader] done processing result set (1 rows)
2006-04-21 23:13:42,671 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close ResultSet (open ResultSets: 1, globally: 1)
2006-04-21 23:13:42,671 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2006-04-21 23:13:42,671 DEBUG [org.hibernate.jdbc.AbstractBatcher] closing statement
2006-04-21 23:13:42,671 DEBUG [org.hibernate.loader.Loader] total objects hydrated: 1
2006-04-21 23:13:42,671 DEBUG [org.hibernate.engine.TwoPhaseLoad] resolving associations for [com.dbdata.processingengine.hibernateobject.CustomProcessingEngine#component[id,versionId]{versionId=1, id=103}]
2006-04-21 23:13:42,671 DEBUG [org.hibernate.engine.CollectionLoadContext] creating collection wrapper:[com.dbdata.processingengine.hibernateobject.CrProcessingEngine.crExecutionLists#component[id,versionId]{versionId=1, id=103}]
2006-04-21 23:13:42,671 DEBUG [org.hibernate.event.def.DefaultInitializeCollectionEventListener] initializing collection [com.dbdata.processingengine.hibernateobject.CrProcessingEngine.crExecutionLists#component[id,versionId]{versionId=1, id=103}]
2006-04-21 23:13:42,671 DEBUG [org.hibernate.event.def.DefaultInitializeCollectionEventListener] checking second-level cache
2006-04-21 23:13:42,671 DEBUG [org.hibernate.event.def.DefaultInitializeCollectionEventListener] collection not cached
2006-04-21 23:13:42,671 DEBUG [org.hibernate.loader.Loader] loading collection: [com.dbdata.processingengine.hibernateobject.CrProcessingEngine.crExecutionLists#component[id,versionId]{versionId=1, id=103}]
2006-04-21 23:13:42,671 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2006-04-21 23:13:42,671 DEBUG [org.hibernate.SQL] select crexecutio0_.PROCESSING_ENGINE_ID as PROCESSING1_1_, crexecutio0_.PROCESSING_ENGINE_VERSION_ID as PROCESSING2_1_, crexecutio0_.EXECUTION_LIST_ID as EXECUTION3_1_, crexecutio0_.PROCESSING_ENGINE_ID as PROCESSING1_242_0_, crexecutio0_.PROCESSING_ENGINE_VERSION_ID as PROCESSING2_242_0_, crexecutio0_.EXECUTION_LIST_ID as EXECUTION3_242_0_, crexecutio0_.UPDATE_DTTM as UPDATE4_242_0_, crexecutio0_.Component_Id as Component5_242_0_, crexecutio0_.Component_Version_Id as Component6_242_0_, crexecutio0_.Component_Type_Cd as Component7_242_0_, crexecutio0_.Application_Sub_Type_Cd as Applicat8_242_0_, crexecutio0_.Priority_Ord as Priority9_242_0_, crexecutio0_.Logon_User as Logon10_242_0_, crexecutio0_.Logon_Password as Logon11_242_0_, crexecutio0_.Tap_Job_Id as Tap12_242_0_, crexecutio0_.Execution_Parameters_Txt as Execution13_242_0_, crexecutio0_.Lock_Cd as Lock14_242_0_, crexecutio0_.Submitted_Ind as Submitted15_242_0_, crexecutio0_.UPDATE_USER as UPDATE16_242_0_ from CR_EXECUTION_LIST crexecutio0_ where crexecutio0_.PROCESSING_ENGINE_ID=? and crexecutio0_.PROCESSING_ENGINE_VERSION_ID=?
2006-04-21 23:13:42,671 INFO [STDOUT] Hibernate: select crexecutio0_.PROCESSING_ENGINE_ID as PROCESSING1_1_, crexecutio0_.PROCESSING_ENGINE_VERSION_ID as PROCESSING2_1_, crexecutio0_.EXECUTION_LIST_ID as EXECUTION3_1_, crexecutio0_.PROCESSING_ENGINE_ID as PROCESSING1_242_0_, crexecutio0_.PROCESSING_ENGINE_VERSION_ID as PROCESSING2_242_0_, crexecutio0_.EXECUTION_LIST_ID as EXECUTION3_242_0_, crexecutio0_.UPDATE_DTTM as UPDATE4_242_0_, crexecutio0_.Component_Id as Component5_242_0_, crexecutio0_.Component_Version_Id as Component6_242_0_, crexecutio0_.Component_Type_Cd as Component7_242_0_, crexecutio0_.Application_Sub_Type_Cd as Applicat8_242_0_, crexecutio0_.Priority_Ord as Priority9_242_0_, crexecutio0_.Logon_User as Logon10_242_0_, crexecutio0_.Logon_Password as Logon11_242_0_, crexecutio0_.Tap_Job_Id as Tap12_242_0_, crexecutio0_.Execution_Parameters_Txt as Execution13_242_0_, crexecutio0_.Lock_Cd as Lock14_242_0_, crexecutio0_.Submitted_Ind as Submitted15_242_0_, crexecutio0_.UPDATE_USER as UPDATE16_242_0_ from CR_EXECUTION_LIST crexecutio0_ where crexecutio0_.PROCESSING_ENGINE_ID=? and crexecutio0_.PROCESSING_ENGINE_VERSION_ID=?
2006-04-21 23:13:42,671 DEBUG [org.hibernate.jdbc.AbstractBatcher] preparing statement
2006-04-21 23:13:42,687 DEBUG [org.hibernate.type.IntegerType] binding '103' to parameter: 1
2006-04-21 23:13:42,687 DEBUG [org.hibernate.type.IntegerType] binding '1' to parameter: 2
2006-04-21 23:13:42,734 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open ResultSet (open ResultSets: 0, globally: 0)
2006-04-21 23:13:42,734 DEBUG [org.hibernate.loader.Loader] result set contains (possibly empty) collection: [com.dbdata.processingengine.hibernateobject.CrProcessingEngine.crExecutionLists#component[id,versionId]{versionId=1, id=103}]
2006-04-21 23:13:42,734 DEBUG [org.hibernate.engine.CollectionLoadContext] uninitialized collection: initializing
2006-04-21 23:13:42,734 DEBUG [org.hibernate.loader.Loader] processing result set
2006-04-21 23:13:42,734 DEBUG [org.hibernate.loader.Loader] result set row: 0
2006-04-21 23:13:42,734 DEBUG [org.hibernate.type.IntegerType] returning '103' as column: PROCESSING1_242_0_
2006-04-21 23:13:42,734 DEBUG [org.hibernate.type.IntegerType] returning '1' as column: PROCESSING2_242_0_
2006-04-21 23:13:42,734 DEBUG [org.hibernate.type.IntegerType] returning '14' as column: EXECUTION3_242_0_
2006-04-21 23:13:42,734 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[com.dbdata.processingengine.hibernateobject.CrExecutionList#component[id,versionId,executionListId]{executionListId=14, versionId=1, id=103}]
2006-04-21 23:13:42,734 DEBUG [org.hibernate.loader.Loader] Initializing object from ResultSet: [com.dbdata.processingengine.hibernateobject.CrExecutionList#component[id,versionId,executionListId]{executionListId=14, versionId=1, id=103}]
2006-04-21 23:13:42,734 DEBUG [org.hibernate.persister.entity.AbstractEntityPersister] Hydrating entity: [com.dbdata.processingengine.hibernateobject.CrExecutionList#component[id,versionId,executionListId]{executionListId=14, versionId=1, id=103}]
2006-04-21 23:13:42,734 DEBUG [org.hibernate.type.TimestampType] returning '2006-03-22 15:20:15' as column: UPDATE4_242_0_
2006-04-21 23:13:42,734 DEBUG [org.hibernate.type.IntegerType] returning '506' as column: Component5_242_0_
2006-04-21 23:13:42,734 DEBUG [org.hibernate.type.IntegerType] returning '1' as column: Component6_242_0_
2006-04-21 23:13:42,734 DEBUG [org.hibernate.type.ShortType] returning '32' as column: Component7_242_0_
2006-04-21 23:13:42,734 DEBUG [org.hibernate.type.ShortType] returning '2' as column: Applicat8_242_0_
2006-04-21 23:13:42,734 DEBUG [org.hibernate.type.IntegerType] returning null as column: Priority9_242_0_
2006-04-21 23:13:42,734 DEBUG [org.hibernate.type.StringType] returning 'tapdev' as column: Logon10_242_0_
2006-04-21 23:13:42,734 DEBUG [org.hibernate.type.StringType] returning 'tapdev' as column: Logon11_242_0_
2006-04-21 23:13:42,734 DEBUG [org.hibernate.type.IntegerType] returning null as column: Tap12_242_0_
2006-04-21 23:13:42,734 DEBUG [org.hibernate.type.StringType] returning '<map/>' as column: Execution13_242_0_
2006-04-21 23:13:42,734 DEBUG [org.hibernate.type.BooleanType] returning 'false' as column: Lock14_242_0_
2006-04-21 23:13:42,734 DEBUG [org.hibernate.type.BooleanType] returning 'false' as column: Submitted15_242_0_
2006-04-21 23:13:42,734 DEBUG [org.hibernate.type.StringType] returning 'tapdev' as column: UPDATE16_242_0_
2006-04-21 23:13:42,734 DEBUG [org.hibernate.type.IntegerType] returning '103' as column: PROCESSING1_242_0_
2006-04-21 23:13:42,734 DEBUG [org.hibernate.type.IntegerType] returning '1' as column: PROCESSING2_242_0_
2006-04-21 23:13:42,734 DEBUG [org.hibernate.engine.TwoPhaseLoad] Version: 2006-03-22 15:20:15.355
2006-04-21 23:13:42,734 DEBUG [org.hibernate.type.IntegerType] returning '103' as column: PROCESSING1_1_
2006-04-21 23:13:42,734 DEBUG [org.hibernate.type.IntegerType] returning '1' as column: PROCESSING2_1_
2006-04-21 23:13:42,734 DEBUG [org.hibernate.loader.Loader] found row of collection: [com.dbdata.processingengine.hibernateobject.CrProcessingEngine.crExecutionLists#component[id,versionId]{versionId=1, id=103}]
2006-04-21 23:13:42,734 DEBUG [org.hibernate.engine.CollectionLoadContext] reading row
2006-04-21 23:13:42,734 DEBUG [org.hibernate.type.IntegerType] returning '103' as column: PROCESSING1_1_
2006-04-21 23:13:42,734 DEBUG [org.hibernate.type.IntegerType] returning '1' as column: PROCESSING2_1_
2006-04-21 23:13:42,734 DEBUG [org.hibernate.type.IntegerType] returning '14' as column: EXECUTION3_1_
2006-04-21 23:13:42,734 DEBUG [org.hibernate.event.def.DefaultLoadEventListener] loading entity: [com.dbdata.processingengine.hibernateobject.CrExecutionList#component[id,versionId,executionListId]{executionListId=14, versionId=1, id=103}]
2006-04-21 23:13:42,734 DEBUG [org.hibernate.event.def.DefaultLoadEventListener] attempting to resolve: [com.dbdata.processingengine.hibernateobject.CrExecutionList#component[id,versionId,executionListId]{executionListId=14, versionId=1, id=103}]
2006-04-21 23:13:42,734 DEBUG [org.hibernate.event.def.DefaultLoadEventListener] resolved object in session cache: [com.dbdata.processingengine.hibernateobject.CrExecutionList#component[id,versionId,executionListId]{executionListId=14, versionId=1, id=103}]
2006-04-21 23:13:42,765 DEBUG [org.hibernate.loader.Loader] done processing result set (1 rows)
2006-04-21 23:13:42,765 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close ResultSet (open ResultSets: 1, globally: 1)
2006-04-21 23:13:42,765 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2006-04-21 23:13:42,765 DEBUG [org.hibernate.jdbc.AbstractBatcher] closing statement
2006-04-21 23:13:42,765 DEBUG [org.hibernate.loader.Loader] total objects hydrated: 1
2006-04-21 23:13:42,765 DEBUG [org.hibernate.engine.TwoPhaseLoad] resolving associations for [com.dbdata.processingengine.hibernateobject.CrExecutionList#component[id,versionId,executionListId]{executionListId=14, versionId=1, id=103}]
2006-04-21 23:13:42,765 DEBUG [org.hibernate.event.def.DefaultLoadEventListener] loading entity: [com.dbdata.processingengine.hibernateobject.CrProcessingEngine#component[id,versionId]{versionId=1, id=103}]
2006-04-21 23:13:42,765 DEBUG [org.hibernate.event.def.DefaultLoadEventListener] attempting to resolve: [com.dbdata.processingengine.hibernateobject.CrProcessingEngine#component[id,versionId]{versionId=1, id=103}]
2006-04-21 23:13:42,765 DEBUG [org.hibernate.event.def.DefaultLoadEventListener] resolved object in session cache: [com.dbdata.processingengine.hibernateobject.CrProcessingEngine#component[id,versionId]{versionId=1, id=103}]
2006-04-21 23:13:42,765 DEBUG [org.hibernate.engine.TwoPhaseLoad] done materializing entity [com.dbdata.processingengine.hibernateobject.CrExecutionList#component[id,versionId,executionListId]{executionListId=14, versionId=1, id=103}]
2006-04-21 23:13:42,781 DEBUG [org.hibernate.engine.CollectionLoadContext] 1 collections were found in result set for role: com.dbdata.processingengine.hibernateobject.CrProcessingEngine.crExecutionLists
2006-04-21 23:13:42,781 DEBUG [org.hibernate.engine.CollectionLoadContext] collection fully initialized: [com.dbdata.processingengine.hibernateobject.CrProcessingEngine.crExecutionLists#component[id,versionId]{versionId=1, id=103}]
2006-04-21 23:13:42,781 DEBUG [org.hibernate.engine.CollectionLoadContext] 1 collections initialized for role: com.dbdata.processingengine.hibernateobject.CrProcessingEngine.crExecutionLists
2006-04-21 23:13:42,781 DEBUG [org.hibernate.loader.Loader] done loading collection
2006-04-21 23:13:42,781 DEBUG [org.hibernate.event.def.DefaultInitializeCollectionEventListener] collection initialized
2006-04-21 23:13:42,781 DEBUG [org.hibernate.engine.TwoPhaseLoad] done materializing entity [com.dbdata.processingengine.hibernateobject.CustomProcessingEngine#component[id,versionId]{versionId=1, id=103}]
2006-04-21 23:13:42,781 DEBUG [org.hibernate.engine.StatefulPersistenceContext] initializing non-lazy collections
2006-04-21 23:13:42,781 DEBUG [org.hibernate.loader.Loader] done entity load
2006-04-21 23:13:42,781 DEBUG [com.dbdata.system.persistence.ObjectHandler] ObjectHandler.processTapInterfaces(obj,action),action is:1
2006-04-21 23:13:42,781 DEBUG [com.dbdata.system.persistence.SessionHandler] SessionHandler.closeAll()
2006-04-21 23:13:42,781 DEBUG [com.dbdata.system.persistence.SessionHandler] SessionHandler.closeAll - closing session:SessionImpl(PersistenceContext[entityKeys=[EntityKey[com.dbdata.processingengine.hibernateobject.CrExecutionList#component[id,versionId,executionListId]{executionListId=7, versionId=1, id=103}], EntityKey[com.dbdata.processingengine.hibernateobject.CrExecutionList#component[id,versionId,executionListId]{executionListId=5, versionId=1, id=103}], EntityKey[com.dbdata.processingengine.hibernateobject.CrExecutionList#component[id,versionId,executionListId]{executionListId=16, versionId=1, id=103}], EntityKey[com.dbdata.processingengine.hibernateobject.CrExecutionList#component[id,versionId,executionListId]{executionListId=11, versionId=1, id=103}], EntityKey[com.dbdata.processingengine.hibernateobject.CrExecutionList#component[id,versionId,executionListId]{executionListId=1, versionId=1, id=103}], EntityKey[com.dbdata.processingengine.hibernateobject.CrExecutionList#component[id,versionId,executionListId]{executionListId=6, versionId=1, id=103}], EntityKey[com.dbdata.processingengine.hibernateobject.CrExecutionList#component[id,versionId,executionListId]{executionListId=10, versionId=1, id=103}], EntityKey[com.dbdata.processingengine.hibernateobject.CrExecutionList#component[id,versionId,executionListId]{executionListId=14, versionId=1, id=103}], EntityKey[com.dbdata.processingengine.hibernateobject.CrProcessingEngine#component[id,versionId]{versionId=1, id=103}], EntityKey[com.dbdata.processingengine.hibernateobject.CrExecutionList#component[id,versionId,executionListId]{executionListId=2, versionId=1, id=103}], EntityKey[com.dbdata.processingengine.hibernateobject.CrExecutionList#component[id,versionId,executionListId]{executionListId=17, versionId=1, id=103}], EntityKey[com.dbdata.processingengine.hibernateobject.CrExecutionList#component[id,versionId,executionListId]{executionListId=3, versionId=1, id=103}], EntityKey[com.dbdata.processingengine.hibernateobject.CrExecutionList#component[id,versionId,executionListId]{executionListId=9, versionId=1, id=103}], EntityKey[com.dbdata.processingengine.hibernateobject.CrExecutionList#component[id,versionId,executionListId]{executionListId=18, versionId=1, id=103}], EntityKey[com.dbdata.processingengine.hibernateobject.CrExecutionList#component[id,versionId,executionListId]{executionListId=19, versionId=1, id=103}], EntityKey[com.dbdata.processingengine.hibernateobject.CrExecutionList#component[id,versionId,executionListId]{executionListId=13, versionId=1, id=103}], EntityKey[com.dbdata.processingengine.hibernateobject.CrExecutionList#component[id,versionId,executionListId]{executionListId=8, versionId=1, id=103}], EntityKey[com.dbdata.processingengine.hibernateobject.CrExecutionList#component[id,versionId,executionListId]{executionListId=4, versionId=1, id=103}], EntityKey[com.dbdata.processingengine.hibernateobject.CrExecutionList#component[id,versionId,executionListId]{executionListId=15, versionId=1, id=103}], EntityKey[com.dbdata.processingengine.hibernateobject.CrExecutionList#component[id,versionId,executionListId]{executionListId=12, versionId=1, id=103}]],collectionKeys=[CollectionKey[com.dbdata.processingengine.hibernateobject.CrProcessingEngine.crExecutionLists#component[id,versionId]{versionId=1, id=103}]]];ActionQueue[insertions=[] updates=[] deletions=[] collectionCreations=[] collectionRemovals=[] collectionUpdates=[]])
2006-04-21 23:13:42,781 DEBUG [org.hibernate.impl.SessionImpl] closing session
When fetch=join is specified, we see the following log:
Quote:
2006-04-21 19:42:27,328 DEBUG [org.hibernate.loader.Loader] found row of collection: [com.dbdata.processingengine.hibernateobject.CrProcessingEngine.crExecutionLists#component[id,versionId]{versionId=1, id=103}]
2006-04-21 19:42:27,328 DEBUG [org.hibernate.engine.CollectionLoadContext] new collection: instantiating
And when fetch=join is removed, this is what we see:
Quote:
2006-04-21 23:13:42,671 DEBUG [org.hibernate.engine.TwoPhaseLoad] resolving associations for [com.dbdata.processingengine.hibernateobject.CustomProcessingEngine#component[id,versionId]{versionId=1, id=103}]
2006-04-21 23:13:42,671 DEBUG [org.hibernate.engine.CollectionLoadContext] creating collection wrapper:[com.dbdata.processingengine.hibernateobject.CrProcessingEngine.crExecutionLists#component[id,versionId]{versionId=1, id=103}]