1. when I add a child to the parent in a bi-directional relationship, hibernate does an sql update on the parent and updates the version even though nothing has changed in the parent row. How do I stop the update?

Is it: optimistoc-lock="false" in the one-to-many children in parent mapping file?


2. when I do a session.merge(obj) this always causes an sql update (version increase) even though the values havn't changed. - using BeanUtils to copy the struts form onto the detached instance.

Is it: callling the setters causes the object to become dirty?

How do I solve this: is there some pattern to check values for "equality" and then NOT to call the detached object setters?

Thank-you

try with

This is because the parent owns the collection. Adding a new child to it changes the parent - hence the version update.
If this is not what you want, then consider setting the collection relationship as reverse in your parent. It will then be owned by the child: the child owns a reference to is parent.


No - this is just normal relationship and versionning management.


First of all, you should run Hibernate with DEBUG log enabled... you will learn a lot about why it is doing what.
Second, your scenario may depend on the actual mapping - so I can't provide any decent answer.
Anyway, when Hibernate first loads an entity from the database, it keeps a copy of its properties in the session (the snapshot). This copy will later be used to determine if changes were made to the session. Changes are something has changed... Turn on debug and you will discover what.

Thank-you for your replies:

pepelnm - I'd like to avoid dynamic-update="true" as I think this causes an extra select on the DB to compare values.

bertrand - I turned on debugging and the update is because it says the collection is dirty. Below is the log after I click 'update' to do the merge. My entity has two collections - one of which I initialize when I load the entity (for this web page). The other collection I dont need and dont initialize. The reality in this case is both collections are empty and I didn't think I touched them - unless BeanUtils is doing something....

Should I provide the mappings for the parent, 2 join tables and 2 child entities, and the hibernate config?


17 Jul 2006 13:20:32,250 DEBUG [jdbc.JDBCContext] - successfully registered Synchronization
17 Jul 2006 13:20:32,250 DEBUG [impl.SessionImpl] - opened session at timestamp: 4723123946496000
17 Jul 2006 13:20:32,250 DEBUG [def.DefaultLoadEventListener] - loading entity: [uni.datatypes.UniUnit#component[uniCode,unitCode]{uniCode=XYZD, unitCode=XYZUNITZZ}]
17 Jul 2006 13:20:32,250 DEBUG [def.DefaultLoadEventListener] - attempting to resolve: [uni.datatypes.UniUnit#component[uniCode,unitCode]{uniCode=XYZD, unitCode=XYZUNITZZ}]
17 Jul 2006 13:20:32,250 DEBUG [cache.ReadWriteCache] - Cache lookup: uni.datatypes.UniUnit# Uni: XYZD Unit: XYZUNITZZ
17 Jul 2006 13:20:32,250 DEBUG [cache.EhCache] - key: uni.datatypes.UniUnit# Uni: XYZD Unit: XYZUNITZZ
17 Jul 2006 13:20:32,250 DEBUG [cache.ReadWriteCache] - Cache hit: uni.datatypes.UniUnit# Uni: XYZD Unit: XYZUNITZZ
17 Jul 2006 13:20:32,250 DEBUG [def.DefaultLoadEventListener] - assembling entity from second-level cache: [uni.datatypes.UniUnit#component[uniCode,unitCode]{uniCode=XYZD, unitCode=XYZUNITZZ}]
17 Jul 2006 13:20:32,250 DEBUG [def.DefaultLoadEventListener] - loading entity: [uni.datatypes.Uni#XYZD]
17 Jul 2006 13:20:32,250 DEBUG [def.DefaultLoadEventListener] - creating new proxy for entity
17 Jul 2006 13:20:32,250 DEBUG [engine.CollectionLoadContext] - creating collection wrapper:[uni.datatypes.UniUnit.assessmentCategoryUnits#component[uniCode,unitCode]{uniCode=XYZD, unitCode=XYZUNITZZ}]
17 Jul 2006 13:20:32,250 DEBUG [engine.CollectionLoadContext] - creating collection wrapper:[uni.datatypes.UniUnit.uniCourseUnits#component[uniCode,unitCode]{uniCode=XYZD, unitCode=XYZUNITZZ}]
17 Jul 2006 13:20:32,250 DEBUG [def.DefaultLoadEventListener] - Cached Version: 0
17 Jul 2006 13:20:32,250 DEBUG [engine.StatefulPersistenceContext] - initializing non-lazy collections
17 Jul 2006 13:20:32,250 DEBUG [def.DefaultLoadEventListener] - resolved object in second-level cache: [uni.datatypes.UniUnit#component[uniCode,unitCode]{uniCode=XYZD, unitCode=XYZUNITZZ}]
17 Jul 2006 13:20:32,250 DEBUG [impl.SessionImpl] - initializing proxy: [uni.datatypes.Uni#XYZD]
17 Jul 2006 13:20:32,250 DEBUG [def.DefaultLoadEventListener] - attempting to resolve: [uni.datatypes.Uni#XYZD]
17 Jul 2006 13:20:32,250 DEBUG [cache.ReadWriteCache] - Cache lookup: uni.datatypes.Uni#XYZD
17 Jul 2006 13:20:32,250 DEBUG [cache.EhCache] - key: uni.datatypes.Uni#XYZD
17 Jul 2006 13:20:32,250 DEBUG [cache.ReadWriteCache] - Cache hit: uni.datatypes.Uni#XYZD
17 Jul 2006 13:20:32,250 DEBUG [def.DefaultLoadEventListener] - assembling entity from second-level cache: [uni.datatypes.Uni#XYZD]
17 Jul 2006 13:20:32,250 DEBUG [engine.CollectionLoadContext] - creating collection wrapper:[uni.datatypesuni.uniUnits#XYZD]
17 Jul 2006 13:20:32,250 DEBUG [engine.CollectionLoadContext] - creating collection wrapper:[uni.datatypesuni.uniCourses#XYZD]
17 Jul 2006 13:20:32,250 DEBUG [def.DefaultLoadEventListener] - Cached Version: 0
17 Jul 2006 13:20:32,250 DEBUG [engine.StatefulPersistenceContext] - initializing non-lazy collections
17 Jul 2006 13:20:32,250 DEBUG [def.DefaultLoadEventListener] - resolved object in second-level cache: [uni.datatypes.Uni#XYZD]
17 Jul 2006 13:20:32,250 DEBUG [def.DefaultInitializeCollectionEventListener] - initializing collection [uni.datatypes.UniUnit.assessmentCategoryUnits#component[uniCode,unitCode]{uniCode=XYZD, unitCode=XYZUNITZZ}]
17 Jul 2006 13:20:32,250 DEBUG [def.DefaultInitializeCollectionEventListener] - checking second-level cache
17 Jul 2006 13:20:32,250 DEBUG [def.DefaultInitializeCollectionEventListener] - collection not cached
17 Jul 2006 13:20:32,250 DEBUG [loader.Loader] - loading collection: [uni.datatypes.UniUnit.assessmentCategoryUnits#component[uniCode,unitCode]{uniCode=XYZD, unitCode=XYZUNITZZ}]
17 Jul 2006 13:20:32,250 DEBUG [jdbc.AbstractBatcher] - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
17 Jul 2006 13:20:32,250 DEBUG [jdbc.ConnectionManager] - opening JDBC connection
17 Jul 2006 13:20:32,250 DEBUG [hibernate.SQL] - select assessment0_.UNI_CODE as UNI2_1_, assessment0_.UNIT_CODE as UNIT3_1_, assessment0_.ASSESSMENT_CATEGORY_ID as ASSESSMENT1_1_, assessment0_.ASSESSMENT_CATEGORY_ID as ASSESSMENT1_1_0_, assessment0_.UNI_CODE as UNI2_1_0_, assessment0_.UNIT_CODE as UNIT3_1_0_, assessment0_.TRANSACTION_ID as TRANSACT4_1_0_ from eatdba.ASSESSMENT_CATEGORY_UNIT assessment0_ where assessment0_.UNI_CODE=? and assessment0_.UNIT_CODE=?
17 Jul 2006 13:20:32,250 DEBUG [jdbc.AbstractBatcher] - preparing statement
17 Jul 2006 13:20:32,250 DEBUG [type.StringType] - binding 'XYZD' to parameter: 1
17 Jul 2006 13:20:32,250 DEBUG [type.StringType] - binding 'XYZUNITZZ' to parameter: 2
17 Jul 2006 13:20:32,781 DEBUG [jdbc.AbstractBatcher] - about to open ResultSet (open ResultSets: 0, globally: 0)
17 Jul 2006 13:20:32,781 DEBUG [loader.Loader] - result set contains (possibly empty) collection: [uni.datatypes.UniUnit.assessmentCategoryUnits#component[uniCode,unitCode]{uniCode=XYZD, unitCode=XYZUNITZZ}]
17 Jul 2006 13:20:32,781 DEBUG [engine.CollectionLoadContext] - uninitialized collection: initializing
17 Jul 2006 13:20:32,781 DEBUG [loader.Loader] - processing result set
17 Jul 2006 13:20:32,781 DEBUG [loader.Loader] - done processing result set (0 rows)
17 Jul 2006 13:20:32,781 DEBUG [jdbc.AbstractBatcher] - about to close ResultSet (open ResultSets: 1, globally: 1)
17 Jul 2006 13:20:32,781 DEBUG [jdbc.AbstractBatcher] - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
17 Jul 2006 13:20:32,781 DEBUG [jdbc.AbstractBatcher] - closing statement
17 Jul 2006 13:20:32,781 DEBUG [jdbc.ConnectionManager] - aggressively releasing JDBC connection
17 Jul 2006 13:20:32,781 DEBUG [jdbc.ConnectionManager] - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
17 Jul 2006 13:20:32,781 DEBUG [loader.Loader] - total objects hydrated: 0
17 Jul 2006 13:20:32,781 DEBUG [engine.CollectionLoadContext] - 1 collections were found in result set for role: uni.datatypes.UniUnit.assessmentCategoryUnits
17 Jul 2006 13:20:32,781 DEBUG [engine.CollectionLoadContext] - collection fully initialized: [uni.datatypes.UniUnit.assessmentCategoryUnits#component[uniCode,unitCode]{uniCode=XYZD, unitCode=XYZUNITZZ}]
17 Jul 2006 13:20:32,781 DEBUG [engine.CollectionLoadContext] - 1 collections initialized for role: uni.datatypes.UniUnit.assessmentCategoryUnits
17 Jul 2006 13:20:32,781 DEBUG [engine.StatefulPersistenceContext] - initializing non-lazy collections
17 Jul 2006 13:20:32,781 DEBUG [loader.Loader] - done loading collection
17 Jul 2006 13:20:32,781 DEBUG [def.DefaultInitializeCollectionEventListener] - collection initialized
17 Jul 2006 13:20:32,781 DEBUG [transaction.CacheSynchronization] - transaction before completion callback
17 Jul 2006 13:20:32,781 DEBUG [transaction.CacheSynchronization] - automatically flushing session
17 Jul 2006 13:20:32,781 DEBUG [impl.SessionImpl] - automatically flushing session
17 Jul 2006 13:20:32,781 DEBUG [def.AbstractFlushingEventListener] - flushing session
17 Jul 2006 13:20:32,781 DEBUG [def.AbstractFlushingEventListener] - processing flush-time cascades
17 Jul 2006 13:20:32,781 DEBUG [def.AbstractFlushingEventListener] - dirty checking collections
17 Jul 2006 13:20:32,781 DEBUG [def.AbstractFlushingEventListener] - Flushing entities and processing referenced collections
17 Jul 2006 13:20:32,781 DEBUG [engine.Collections] - Collection found: [uni.datatypes.UniUnit.assessmentCategoryUnits#component[uniCode,unitCode]{uniCode=XYZD, unitCode=XYZUNITZZ}], was: [uni.datatypes.UniUnit.assessmentCategoryUnits#component[uniCode,unitCode]{uniCode=XYZD, unitCode=XYZUNITZZ}] (initialized)
17 Jul 2006 13:20:32,781 DEBUG [engine.Collections] - Collection found: [uni.datatypes.UniUnit.uniCourseUnits#component[uniCode,unitCode]{uniCode=XYZD, unitCode=XYZUNITZZ}], was: [uni.datatypes.UniUnit.uniCourseUnits#component[uniCode,unitCode]{uniCode=XYZD, unitCode=XYZUNITZZ}] (uninitialized)
17 Jul 2006 13:20:32,781 DEBUG [engine.Collections] - Collection found: [uni.datatypesuni.uniUnits#XYZD], was: [uni.datatypesuni.uniUnits#XYZD] (uninitialized)
17 Jul 2006 13:20:32,781 DEBUG [engine.Collections] - Collection found: [uni.datatypesuni.uniCourses#XYZD], was: [uni.datatypesuni.uniCourses#XYZD] (uninitialized)
17 Jul 2006 13:20:32,781 DEBUG [def.AbstractFlushingEventListener] - Processing unreferenced collections
17 Jul 2006 13:20:32,781 DEBUG [def.AbstractFlushingEventListener] - Scheduling collection removes/(re)creates/updates
17 Jul 2006 13:20:32,781 DEBUG [def.AbstractFlushingEventListener] - Flushed: 0 insertions, 0 updates, 0 deletions to 2 objects
17 Jul 2006 13:20:32,781 DEBUG [def.AbstractFlushingEventListener] - Flushed: 0 (re)creations, 0 updates, 0 removals to 4 collections
17 Jul 2006 13:20:32,781 DEBUG [pretty.Printer] - listing entities:
17 Jul 2006 13:20:32,796 DEBUG [pretty.Printer] - uni.datatypes.UniUnit{transactionId=0, uni=uni.datatypes.Uni#XYZD, assessmentCategoryUnits=[], description=Microeconomics Z, uniCourseUnits=<uninitialized>, weighting=0.3, id=component[uniCode,unitCode]{uniCode=XYZD, unitCode=XYZUNITZZ}}
17 Jul 2006 13:20:32,796 DEBUG [pretty.Printer] - uni.datatypes.Uni{uniCode=XYZD, transactionId=0, description=XYZ UniD, uniUnits=<uninitialized>, uniCourses=<uninitialized>}
17 Jul 2006 13:20:32,796 DEBUG [def.AbstractFlushingEventListener] - executing flush
17 Jul 2006 13:20:32,796 DEBUG [jdbc.ConnectionManager] - registering flush begin
17 Jul 2006 13:20:32,796 DEBUG [jdbc.ConnectionManager] - registering flush end
17 Jul 2006 13:20:32,796 DEBUG [jdbc.ConnectionManager] - aggressively releasing JDBC connection
17 Jul 2006 13:20:32,796 DEBUG [def.AbstractFlushingEventListener] - post flush
17 Jul 2006 13:20:32,796 DEBUG [jdbc.JDBCContext] - before transaction completion
17 Jul 2006 13:20:32,796 DEBUG [impl.SessionImpl] - before transaction completion
17 Jul 2006 13:20:32,968 DEBUG [transaction.CacheSynchronization] - transaction after completion callback, status: 3
17 Jul 2006 13:20:32,968 DEBUG [jdbc.JDBCContext] - after transaction completion
17 Jul 2006 13:20:32,968 DEBUG [impl.SessionImpl] - after transaction completion
17 Jul 2006 13:20:32,968 DEBUG [transaction.CacheSynchronization] - automatically closing session
17 Jul 2006 13:20:32,968 DEBUG [impl.SessionImpl] - automatically closing session
17 Jul 2006 13:20:32,968 DEBUG [impl.SessionImpl] - closing session
17 Jul 2006 13:20:32,968 DEBUG [jdbc.ConnectionManager] - connection already null in cleanup : no action
17 Jul 2006 13:20:32,984 DEBUG [jdbc.JDBCContext] - successfully registered Synchronization
17 Jul 2006 13:20:32,984 DEBUG [impl.SessionImpl] - opened session at timestamp: 4723123949502464
17 Jul 2006 13:20:32,984 DEBUG [jdbc.ConnectionManager] - opening JDBC connection
17 Jul 2006 13:20:33,171 DEBUG [engine.VersionValue] - version unsaved-value strategy NULL
17 Jul 2006 13:20:33,171 DEBUG [def.AbstractSaveEventListener] - detached instance of: uni.datatypes.UniUnit
17 Jul 2006 13:20:33,171 DEBUG [def.DefaultMergeEventListener] - merging detached instance
17 Jul 2006 13:20:33,171 DEBUG [def.DefaultLoadEventListener] - loading entity: [uni.datatypes.UniUnit#component[uniCode,unitCode]{uniCode=XYZD, unitCode=XYZUNITZZ}]
17 Jul 2006 13:20:33,171 DEBUG [def.DefaultLoadEventListener] - attempting to resolve: [uni.datatypes.UniUnit#component[uniCode,unitCode]{uniCode=XYZD, unitCode=XYZUNITZZ}]
17 Jul 2006 13:20:33,171 DEBUG [cache.ReadWriteCache] - Cache lookup: uni.datatypes.UniUnit# Uni: XYZD Unit: XYZUNITZZ
17 Jul 2006 13:20:33,171 DEBUG [cache.EhCache] - key: uni.datatypes.UniUnit# Uni: XYZD Unit: XYZUNITZZ
17 Jul 2006 13:20:33,171 DEBUG [cache.ReadWriteCache] - Cache hit: uni.datatypes.UniUnit# Uni: XYZD Unit: XYZUNITZZ
17 Jul 2006 13:20:33,171 DEBUG [def.DefaultLoadEventListener] - assembling entity from second-level cache: [uni.datatypes.UniUnit#component[uniCode,unitCode]{uniCode=XYZD, unitCode=XYZUNITZZ}]
17 Jul 2006 13:20:33,171 DEBUG [def.DefaultLoadEventListener] - loading entity: [uni.datatypes.Uni#XYZD]
17 Jul 2006 13:20:33,171 DEBUG [def.DefaultLoadEventListener] - creating new proxy for entity
17 Jul 2006 13:20:33,171 DEBUG [engine.CollectionLoadContext] - creating collection wrapper:[uni.datatypes.UniUnit.assessmentCategoryUnits#component[uniCode,unitCode]{uniCode=XYZD, unitCode=XYZUNITZZ}]
17 Jul 2006 13:20:33,171 DEBUG [engine.CollectionLoadContext] - creating collection wrapper:[uni.datatypes.UniUnit.uniCourseUnits#component[uniCode,unitCode]{uniCode=XYZD, unitCode=XYZUNITZZ}]
17 Jul 2006 13:20:33,171 DEBUG [def.DefaultLoadEventListener] - Cached Version: 0
17 Jul 2006 13:20:33,171 DEBUG [engine.StatefulPersistenceContext] - initializing non-lazy collections
17 Jul 2006 13:20:33,171 DEBUG [def.DefaultLoadEventListener] - resolved object in second-level cache: [uni.datatypes.UniUnit#component[uniCode,unitCode]{uniCode=XYZD, unitCode=XYZUNITZZ}]
17 Jul 2006 13:20:33,187 DEBUG [def.DefaultLoadEventListener] - loading entity: [uni.datatypes.Uni#XYZD]
17 Jul 2006 13:20:33,187 DEBUG [def.DefaultLoadEventListener] - entity proxy found in session cache
17 Jul 2006 13:20:33,187 DEBUG [transaction.CacheSynchronization] - transaction before completion callback
17 Jul 2006 13:20:33,187 DEBUG [transaction.CacheSynchronization] - automatically flushing session
17 Jul 2006 13:20:33,187 DEBUG [impl.SessionImpl] - automatically flushing session
17 Jul 2006 13:20:33,187 DEBUG [def.AbstractFlushingEventListener] - flushing session
17 Jul 2006 13:20:33,187 DEBUG [def.AbstractFlushingEventListener] - processing flush-time cascades
17 Jul 2006 13:20:33,187 DEBUG [def.AbstractFlushingEventListener] - dirty checking collections
17 Jul 2006 13:20:33,187 DEBUG [engine.CollectionEntry] - Collection dirty: [uni.datatypes.UniUnit.assessmentCategoryUnits# Uni: XYZD Unit: XYZUNITZZ]
17 Jul 2006 13:20:33,187 DEBUG [def.AbstractFlushingEventListener] - Flushing entities and processing referenced collections
17 Jul 2006 13:20:33,187 DEBUG [def.DefaultFlushEntityEventListener] - Updating entity: [uni.datatypes.UniUnit#component[uniCode,unitCode]{uniCode=XYZD, unitCode=XYZUNITZZ}]
17 Jul 2006 13:20:33,187 DEBUG [engine.Versioning] - Incrementing: 0 to 1
17 Jul 2006 13:20:33,187 DEBUG [engine.Collections] - Collection found: [uni.datatypes.UniUnit.assessmentCategoryUnits#component[uniCode,unitCode]{uniCode=XYZD, unitCode=XYZUNITZZ}], was: [uni.datatypes.UniUnit.assessmentCategoryUnits#component[uniCode,unitCode]{uniCode=XYZD, unitCode=XYZUNITZZ}] (uninitialized)
17 Jul 2006 13:20:33,187 DEBUG [engine.Collections] - Collection found: [uni.datatypes.UniUnit.uniCourseUnits#component[uniCode,unitCode]{uniCode=XYZD, unitCode=XYZUNITZZ}], was: [uni.datatypes.UniUnit.uniCourseUnits#component[uniCode,unitCode]{uniCode=XYZD, unitCode=XYZUNITZZ}] (uninitialized)
17 Jul 2006 13:20:33,187 DEBUG [def.AbstractFlushingEventListener] - Processing unreferenced collections
17 Jul 2006 13:20:33,187 DEBUG [def.AbstractFlushingEventListener] - Scheduling collection removes/(re)creates/updates
17 Jul 2006 13:20:33,187 DEBUG [def.AbstractFlushingEventListener] - Flushed: 0 insertions, 1 updates, 0 deletions to 1 objects
17 Jul 2006 13:20:33,187 DEBUG [def.AbstractFlushingEventListener] - Flushed: 0 (re)creations, 1 updates, 0 removals to 2 collections
17 Jul 2006 13:20:33,187 DEBUG [pretty.Printer] - listing entities:
17 Jul 2006 13:20:33,187 DEBUG [pretty.Printer] - uni.datatypes.UniUnit{transactionId=0, uni=uni.datatypes.Uni#XYZD, assessmentCategoryUnits=<uninitialized>, description=Microeconomics Z, uniCourseUnits=<uninitialized>, weighting=0.3, id=component[uniCode,unitCode]{uniCode=XYZD, unitCode=XYZUNITZZ}}
17 Jul 2006 13:20:33,187 DEBUG [def.AbstractFlushingEventListener] - executing flush
17 Jul 2006 13:20:33,187 DEBUG [jdbc.ConnectionManager] - registering flush begin
17 Jul 2006 13:20:33,187 DEBUG [cache.UpdateTimestampsCache] - Pre-invalidating space [eatdba.UNI_UNIT]
17 Jul 2006 13:20:33,187 DEBUG [cache.ReadWriteCache] - Invalidating: uni.datatypes.UniUnit# Uni: XYZD Unit: XYZUNITZZ
17 Jul 2006 13:20:33,187 DEBUG [cache.EhCache] - key: uni.datatypes.UniUnit# Uni: XYZD Unit: XYZUNITZZ
17 Jul 2006 13:20:33,187 DEBUG [entity.AbstractEntityPersister] - Updating entity: [uni.datatypes.UniUnit#component[uniCode,unitCode]{uniCode=XYZD, unitCode=XYZUNITZZ}]
17 Jul 2006 13:20:33,187 DEBUG [entity.AbstractEntityPersister] - Existing version: 0 -> New version: 1
17 Jul 2006 13:20:33,187 DEBUG [jdbc.AbstractBatcher] - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
17 Jul 2006 13:20:33,187 DEBUG [hibernate.SQL] - update eatdba.UNI_UNIT set TRANSACTION_ID=?, DESCRIPTION=?, WEIGHTING=? where UNI_CODE=? and UNIT_CODE=? and TRANSACTION_ID=?
17 Jul 2006 13:20:33,187 DEBUG [jdbc.AbstractBatcher] - preparing statement
17 Jul 2006 13:20:33,187 DEBUG [entity.AbstractEntityPersister] - Dehydrating entity: [uni.datatypes.UniUnit#component[uniCode,unitCode]{uniCode=XYZD, unitCode=XYZUNITZZ}]
17 Jul 2006 13:20:33,187 DEBUG [type.IntegerType] - binding '1' to parameter: 1
17 Jul 2006 13:20:33,187 DEBUG [type.StringType] - binding 'Microeconomics Z' to parameter: 2
17 Jul 2006 13:20:33,187 DEBUG [type.BigDecimalType] - binding '0.3' to parameter: 3
17 Jul 2006 13:20:33,187 DEBUG [type.StringType] - binding 'XYZD' to parameter: 4
17 Jul 2006 13:20:33,187 DEBUG [type.StringType] - binding 'XYZUNITZZ' to parameter: 5
17 Jul 2006 13:20:33,187 DEBUG [type.IntegerType] - binding '0' to parameter: 6
17 Jul 2006 13:20:33,187 DEBUG [jdbc.AbstractBatcher] - Adding to batch
17 Jul 2006 13:20:33,187 DEBUG [jdbc.AbstractBatcher] - Executing batch size: 1
17 Jul 2006 13:20:33,468 DEBUG [jdbc.AbstractBatcher] - success of batch update unknown: 0
17 Jul 2006 13:20:33,484 DEBUG [jdbc.AbstractBatcher] - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
17 Jul 2006 13:20:33,484 DEBUG [jdbc.AbstractBatcher] - closing statement
17 Jul 2006 13:20:33,484 DEBUG [jdbc.ConnectionManager] - skipping aggressive-release due to flush cycle
17 Jul 2006 13:20:33,484 DEBUG [cache.UpdateTimestampsCache] - Pre-invalidating space [eatdba.ASSESSMENT_CATEGORY_UNIT]
17 Jul 2006 13:20:33,484 DEBUG [jdbc.ConnectionManager] - registering flush end
17 Jul 2006 13:20:33,484 DEBUG [jdbc.ConnectionManager] - aggressively releasing JDBC connection
17 Jul 2006 13:20:33,484 DEBUG [jdbc.ConnectionManager] - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
17 Jul 2006 13:20:33,484 DEBUG [def.AbstractFlushingEventListener] - post flush
17 Jul 2006 13:20:33,484 DEBUG [jdbc.JDBCContext] - before transaction completion
17 Jul 2006 13:20:33,484 DEBUG [impl.SessionImpl] - before transaction completion
17 Jul 2006 13:20:33,625 DEBUG [transaction.CacheSynchronization] - transaction after completion callback, status: 3
17 Jul 2006 13:20:33,625 DEBUG [jdbc.JDBCContext] - after transaction completion
17 Jul 2006 13:20:33,625 DEBUG [impl.SessionImpl] - after transaction completion
17 Jul 2006 13:20:33,625 DEBUG [jdbc.JDBCContext] - no active transaction, could not register Synchronization
17 Jul 2006 13:20:33,625 DEBUG [cache.ReadWriteCache] - Updating: uni.datatypes.UniUnit# Uni: XYZD Unit: XYZUNITZZ
17 Jul 2006 13:20:33,625 DEBUG [cache.EhCache] - key: uni.datatypes.UniUnit# Uni: XYZD Unit: XYZUNITZZ
17 Jul 2006 13:20:33,625 DEBUG [cache.ReadWriteCache] - Updated: uni.datatypes.UniUnit# Uni: XYZD Unit: XYZUNITZZ
17 Jul 2006 13:20:33,625 DEBUG [cache.UpdateTimestampsCache] - Invalidating space [eatdba.UNI_UNIT], timestamp: 4723123952128001
17 Jul 2006 13:20:33,625 DEBUG [cache.UpdateTimestampsCache] - Invalidating space [eatdba.ASSESSMENT_CATEGORY_UNIT], timestamp: 4723123952128002
17 Jul 2006 13:20:33,625 DEBUG [transaction.CacheSynchronization] - automatically closing session
17 Jul 2006 13:20:33,625 DEBUG [impl.SessionImpl] - automatically closing session
17 Jul 2006 13:20:33,625 DEBUG [impl.SessionImpl] - closing session
17 Jul 2006 13:20:33,625 DEBUG [jdbc.ConnectionManager] - connection already null in cleanup : no action
17 Jul 2006 13:20:33,640 DEBUG [jdbc.JDBCContext] - successfully registered Synchronization
17 Jul 2006 13:20:33,640 DEBUG [impl.SessionImpl] - opened session at timestamp: 4723123952189440
17 Jul 2006 13:20:33,640 DEBUG [def.DefaultLoadEventListener] - loading entity: [uni.datatypes.UniUnit#component[uniCode,unitCode]{uniCode=XYZD, unitCode=XYZUNITZZ}]
17 Jul 2006 13:20:33,640 DEBUG [def.DefaultLoadEventListener] - attempting to resolve: [uni.datatypes.UniUnit#component[uniCode,unitCode]{uniCode=XYZD, unitCode=XYZUNITZZ}]
17 Jul 2006 13:20:33,640 DEBUG [cache.ReadWriteCache] - Cache lookup: uni.datatypes.UniUnit# Uni: XYZD Unit: XYZUNITZZ
17 Jul 2006 13:20:33,640 DEBUG [cache.EhCache] - key: uni.datatypes.UniUnit# Uni: XYZD Unit: XYZUNITZZ
17 Jul 2006 13:20:33,640 DEBUG [cache.ReadWriteCache] - Cache hit: uni.datatypes.UniUnit# Uni: XYZD Unit: XYZUNITZZ
17 Jul 2006 13:20:33,640 DEBUG [def.DefaultLoadEventListener] - assembling entity from second-level cache: [uni.datatypes.UniUnit#component[uniCode,unitCode]{uniCode=XYZD, unitCode=XYZUNITZZ}]
17 Jul 2006 13:20:33,640 DEBUG [def.DefaultLoadEventListener] - loading entity: [uni.datatypes.Uni#XYZD]
17 Jul 2006 13:20:33,640 DEBUG [def.DefaultLoadEventListener] - creating new proxy for entity
17 Jul 2006 13:20:33,640 DEBUG [engine.CollectionLoadContext] - creating collection wrapper:[uni.datatypes.UniUnit.assessmentCategoryUnits#component[uniCode,unitCode]{uniCode=XYZD, unitCode=XYZUNITZZ}]
17 Jul 2006 13:20:33,640 DEBUG [engine.CollectionLoadContext] - creating collection wrapper:[uni.datatypes.UniUnit.uniCourseUnits#component[uniCode,unitCode]{uniCode=XYZD, unitCode=XYZUNITZZ}]
17 Jul 2006 13:20:33,640 DEBUG [def.DefaultLoadEventListener] - Cached Version: 1
17 Jul 2006 13:20:33,640 DEBUG [engine.StatefulPersistenceContext] - initializing non-lazy collections
17 Jul 2006 13:20:33,640 DEBUG [def.DefaultLoadEventListener] - resolved object in second-level cache: [uni.datatypes.UniUnit#component[uniCode,unitCode]{uniCode=XYZD, unitCode=XYZUNITZZ}]
17 Jul 2006 13:20:33,640 DEBUG [impl.SessionImpl] - initializing proxy: [uni.datatypes.Uni#XYZD]
17 Jul 2006 13:20:33,640 DEBUG [def.DefaultLoadEventListener] - attempting to resolve: [uni.datatypes.Uni#XYZD]
17 Jul 2006 13:20:33,640 DEBUG [cache.ReadWriteCache] - Cache lookup: uni.datatypes.Uni#XYZD
17 Jul 2006 13:20:33,640 DEBUG [cache.EhCache] - key: uni.datatypes.Uni#XYZD
17 Jul 2006 13:20:33,640 DEBUG [cache.ReadWriteCache] - Cache hit: uni.datatypes.Uni#XYZD
17 Jul 2006 13:20:33,640 DEBUG [def.DefaultLoadEventListener] - assembling entity from second-level cache: [uni.datatypes.Uni#XYZD]
17 Jul 2006 13:20:33,640 DEBUG [engine.CollectionLoadContext] - creating collection wrapper:[uni.datatypesuni.uniUnits#XYZD]
17 Jul 2006 13:20:33,640 DEBUG [engine.CollectionLoadContext] - creating collection wrapper:[uni.datatypesuni.uniCourses#XYZD]
17 Jul 2006 13:20:33,640 DEBUG [def.DefaultLoadEventListener] - Cached Version: 0
17 Jul 2006 13:20:33,640 DEBUG [engine.StatefulPersistenceContext] - initializing non-lazy collections
17 Jul 2006 13:20:33,640 DEBUG [def.DefaultLoadEventListener] - resolved object in second-level cache: [uni.datatypes.Uni#XYZD]
17 Jul 2006 13:20:33,640 DEBUG [def.DefaultInitializeCollectionEventListener] - initializing collection [uni.datatypes.UniUnit.assessmentCategoryUnits#component[uniCode,unitCode]{uniCode=XYZD, unitCode=XYZUNITZZ}]
17 Jul 2006 13:20:33,640 DEBUG [def.DefaultInitializeCollectionEventListener] - checking second-level cache
17 Jul 2006 13:20:33,640 DEBUG [def.DefaultInitializeCollectionEventListener] - collection not cached
17 Jul 2006 13:20:33,640 DEBUG [loader.Loader] - loading collection: [uni.datatypes.UniUnit.assessmentCategoryUnits#component[uniCode,unitCode]{uniCode=XYZD, unitCode=XYZUNITZZ}]
17 Jul 2006 13:20:33,640 DEBUG [jdbc.AbstractBatcher] - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
17 Jul 2006 13:20:33,640 DEBUG [jdbc.ConnectionManager] - opening JDBC connection
17 Jul 2006 13:20:33,640 DEBUG [hibernate.SQL] - select assessment0_.UNI_CODE as UNI2_1_, assessment0_.UNIT_CODE as UNIT3_1_, assessment0_.ASSESSMENT_CATEGORY_ID as ASSESSMENT1_1_, assessment0_.ASSESSMENT_CATEGORY_ID as ASSESSMENT1_1_0_, assessment0_.UNI_CODE as UNI2_1_0_, assessment0_.UNIT_CODE as UNIT3_1_0_, assessment0_.TRANSACTION_ID as TRANSACT4_1_0_ from eatdba.ASSESSMENT_CATEGORY_UNIT assessment0_ where assessment0_.UNI_CODE=? and assessment0_.UNIT_CODE=?
17 Jul 2006 13:20:33,640 DEBUG [jdbc.AbstractBatcher] - preparing statement
17 Jul 2006 13:20:33,640 DEBUG [type.StringType] - binding 'XYZD' to parameter: 1
17 Jul 2006 13:20:33,640 DEBUG [type.StringType] - binding 'XYZUNITZZ' to parameter: 2
17 Jul 2006 13:20:34,187 DEBUG [jdbc.AbstractBatcher] - about to open ResultSet (open ResultSets: 0, globally: 0)
17 Jul 2006 13:20:34,187 DEBUG [loader.Loader] - result set contains (possibly empty) collection: [uni.datatypes.UniUnit.assessmentCategoryUnits#component[uniCode,unitCode]{uniCode=XYZD, unitCode=XYZUNITZZ}]
17 Jul 2006 13:20:34,187 DEBUG [engine.CollectionLoadContext] - uninitialized collection: initializing
17 Jul 2006 13:20:34,187 DEBUG [loader.Loader] - processing result set
17 Jul 2006 13:20:34,187 DEBUG [loader.Loader] - done processing result set (0 rows)
17 Jul 2006 13:20:34,187 DEBUG [jdbc.AbstractBatcher] - about to close ResultSet (open ResultSets: 1, globally: 1)
17 Jul 2006 13:20:34,187 DEBUG [jdbc.AbstractBatcher] - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
17 Jul 2006 13:20:34,187 DEBUG [jdbc.AbstractBatcher] - closing statement
17 Jul 2006 13:20:34,187 DEBUG [jdbc.ConnectionManager] - aggressively releasing JDBC connection
17 Jul 2006 13:20:34,187 DEBUG [jdbc.ConnectionManager] - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
17 Jul 2006 13:20:34,187 DEBUG [loader.Loader] - total objects hydrated: 0
17 Jul 2006 13:20:34,187 DEBUG [engine.CollectionLoadContext] - 1 collections were found in result set for role: uni.datatypes.UniUnit.assessmentCategoryUnits
17 Jul 2006 13:20:34,203 DEBUG [engine.CollectionLoadContext] - collection fully initialized: [uni.datatypes.UniUnit.assessmentCategoryUnits#component[uniCode,unitCode]{uniCode=XYZD, unitCode=XYZUNITZZ}]
17 Jul 2006 13:20:34,203 DEBUG [engine.CollectionLoadContext] - 1 collections initialized for role: uni.datatypes.UniUnit.assessmentCategoryUnits
17 Jul 2006 13:20:34,203 DEBUG [engine.StatefulPersistenceContext] - initializing non-lazy collections
17 Jul 2006 13:20:34,203 DEBUG [loader.Loader] - done loading collection
17 Jul 2006 13:20:34,203 DEBUG [def.DefaultInitializeCollectionEventListener] - collection initialized
17 Jul 2006 13:20:34,203 DEBUG [transaction.CacheSynchronization] - transaction before completion callback
17 Jul 2006 13:20:34,203 DEBUG [transaction.CacheSynchronization] - automatically flushing session
17 Jul 2006 13:20:34,203 DEBUG [impl.SessionImpl] - automatically flushing session
17 Jul 2006 13:20:34,203 DEBUG [def.AbstractFlushingEventListener] - flushing session
17 Jul 2006 13:20:34,203 DEBUG [def.AbstractFlushingEventListener] - processing flush-time cascades
17 Jul 2006 13:20:34,203 DEBUG [def.AbstractFlushingEventListener] - dirty checking collections
17 Jul 2006 13:20:34,203 DEBUG [def.AbstractFlushingEventListener] - Flushing entities and processing referenced collections
17 Jul 2006 13:20:34,203 DEBUG [engine.Collections] - Collection found: [uni.datatypes.UniUnit.assessmentCategoryUnits#component[uniCode,unitCode]{uniCode=XYZD, unitCode=XYZUNITZZ}], was: [uni.datatypes.UniUnit.assessmentCategoryUnits#component[uniCode,unitCode]{uniCode=XYZD, unitCode=XYZUNITZZ}] (initialized)
17 Jul 2006 13:20:34,203 DEBUG [engine.Collections] - Collection found: [uni.datatypes.UniUnit.uniCourseUnits#component[uniCode,unitCode]{uniCode=XYZD, unitCode=XYZUNITZZ}], was: [uni.datatypes.UniUnit.uniCourseUnits#component[uniCode,unitCode]{uniCode=XYZD, unitCode=XYZUNITZZ}] (uninitialized)
17 Jul 2006 13:20:34,203 DEBUG [engine.Collections] - Collection found: [uni.datatypesuni.uniUnits#XYZD], was: [uni.datatypesuni.uniUnits#XYZD] (uninitialized)
17 Jul 2006 13:20:34,203 DEBUG [engine.Collections] - Collection found: [uni.datatypesuni.uniCourses#XYZD], was: [uni.datatypesuni.uniCourses#XYZD] (uninitialized)
17 Jul 2006 13:20:34,203 DEBUG [def.AbstractFlushingEventListener] - Processing unreferenced collections
17 Jul 2006 13:20:34,203 DEBUG [def.AbstractFlushingEventListener] - Scheduling collection removes/(re)creates/updates
17 Jul 2006 13:20:34,203 DEBUG [def.AbstractFlushingEventListener] - Flushed: 0 insertions, 0 updates, 0 deletions to 2 objects
17 Jul 2006 13:20:34,203 DEBUG [def.AbstractFlushingEventListener] - Flushed: 0 (re)creations, 0 updates, 0 removals to 4 collections
17 Jul 2006 13:20:34,203 DEBUG [pretty.Printer] - listing entities:
17 Jul 2006 13:20:34,203 DEBUG [pretty.Printer] - uni.datatypes.UniUnit{transactionId=1, uni=uni.datatypes.Uni#XYZD, assessmentCategoryUnits=[], description=Microeconomics Z, uniCourseUnits=<uninitialized>, weighting=0.3, id=component[uniCode,unitCode]{uniCode=XYZD, unitCode=XYZUNITZZ}}
17 Jul 2006 13:20:34,203 DEBUG [pretty.Printer] - uni.datatypes.Uni{uniCode=XYZD, transactionId=0, description=XYZ UniD, uniUnits=<uninitialized>, uniCourses=<uninitialized>}
17 Jul 2006 13:20:34,203 DEBUG [def.AbstractFlushingEventListener] - executing flush
17 Jul 2006 13:20:34,203 DEBUG [jdbc.ConnectionManager] - registering flush begin
17 Jul 2006 13:20:34,203 DEBUG [jdbc.ConnectionManager] - registering flush end
17 Jul 2006 13:20:34,203 DEBUG [jdbc.ConnectionManager] - aggressively releasing JDBC connection
17 Jul 2006 13:20:34,203 DEBUG [def.AbstractFlushingEventListener] - post flush
17 Jul 2006 13:20:34,203 DEBUG [jdbc.JDBCContext] - before transaction completion
17 Jul 2006 13:20:34,203 DEBUG [impl.SessionImpl] - before transaction completion
17 Jul 2006 13:20:34,359 DEBUG [transaction.CacheSynchronization] - transaction after completion callback, status: 3
17 Jul 2006 13:20:34,359 DEBUG [jdbc.JDBCContext] - after transaction completion
17 Jul 2006 13:20:34,359 DEBUG [impl.SessionImpl] - after transaction completion
17 Jul 2006 13:20:34,359 DEBUG [transaction.CacheSynchronization] - automatically closing session
17 Jul 2006 13:20:34,359 DEBUG [impl.SessionImpl] - automatically closing session
17 Jul 2006 13:20:34,359 DEBUG [impl.SessionImpl] - closing session
17 Jul 2006 13:20:34,359 DEBUG [jdbc.ConnectionManager] - connection already null in cleanup : no action

I think it is select-before-update="true" what does it.

pepelnm - yes you are right, but I dont think this stops the update from occurring, it still updates the VERSION_ID column.

I understand its by design that hibernate updates the parent if the parents collection is altered (add or remove).

Hibernate says the parents collection is dirty, I'll have to figure out what's modifying the collection to make it dirty...(if its not hibernate)

Its still doing an sql update ...here is some code:

session 1.


then straight after...

session 2.




so how does the collection become dirty from this code?

thank-you

I looked through session.merge() code and it looks to take my initialized collection and copy it in:



The end result seems to be that hibernate marks the PersistentSet as dirty (during the copy) and therefore updates the parent entity.

I dont understand why the Set is marked dirty "to remove the collection from the 2nd level cache". Is this a good reason to perform an SQL UPDATE on the parent?

Hi,

Can any hibernate experts out confirm that once a parents collection is initialized then performing will always cause an sql update, even though the application does not change any parent fields or alter the collection in any way.

Hi bertrand, did you mean "...as inverse in your parent."?
e.g.




Thanks,