Hi Everyone,
This is not really a big problem right now, I'm mostly curious about the cause of the problem, but a solution would be nice! :)
My problem is that when I have a base object which holds a reference to a collection. The elements that are contained within the collection have a very basic hashCode and equals method implemented (there is a unique string contained within each of these objects that I can query). Whenever I perform a get operation to retrieve the object from the database, hibernate reads the collection, marks it as dirty and deletes and re-inserts all of the entries in the mapping table for this collection.
I placed breakpoints in the hashCode and equals methods of the objects that are being stored in the collection and neither of these methods are ever called throughout this get operation. I did a little bit of investigating and found that this is because my collection is being stored in a PersistentBag which does not honour the list implementation of hashCode but rather called hashCode on java.lang.Object. This, of course, makes sense because we don't want to load that collection just to run a hashCode on it:
Code:
/*public boolean equals(Object other) {
read();
return bag.equals(other);
}
public int hashCode(Object other) {
read();
return bag.hashCode();
}*/
... snip ...
/**
* Bag does not respect the collection API and do an
* JVM instance comparison to do the equals.
* The semantic is broken not to have to initialize a
* collection for a simple equals() operation.
* @see java.lang.Object#equals(java.lang.Object)
*/
public boolean equals(Object obj) {
return super.equals(obj);
}
/**
* @see java.lang.Object#hashCode()
*/
public int hashCode() {
return super.hashCode();
}
This, of course, will call hashCode() on java.lang.Object, which may have different hash codes for the collection depending on where it is stored in memory. Thus, my collections will be marked as dirty.
The net effect for this right now for me is nil as my collections are reconstructed correctly in the database and this is all done in a transaction. My user base is quite small, so there are no performance concerns, I just grew a little concerned when I started seeing deletions and insertions when I was performing a read operation on the database.
Any pointers in the right direction would be appreciated greatly. Below is some of the information requested:
Hibernate version: 3.2.6.ga
Name and version of the database you are using: MySQL 5.1
The generated SQL (show_sql=true):Hibernate: select samples0_.ProteomicsRequest_id as Proteomi1_1_, samples0_.samples_id as samples2_1_, proteomics1_.id as id17_0_, proteomics1_.comment as comment17_0_, proteomics1_.sampleName as sampleName17_0_ from ProteomicsRequest_ProteomicsSample samples0_ left outer join ProteomicsSample proteomics1_ on samples0_.samples_id=proteomics1_.id where samples0_.ProteomicsRequest_id=?
Hibernate: delete from ProteomicsRequest_ProteomicsSample where ProteomicsRequest_id=?
Hibernate: insert into ProteomicsRequest_ProteomicsSample (ProteomicsRequest_id, samples_id) values (?, ?)
Debug level Hibernate log excerpt: (I think this is the relevant bit)
Code:
DEBUG [btpool0-1] AbstractFlushingEventListener.prepareCollectionFlushes(154) | dirty checking collections
DEBUG [btpool0-1] AbstractFlushingEventListener.flushEntities(171) | Flushing entities and processing referenced collections
DEBUG [btpool0-1] Collections.processReachableCollection(176) | Collection found: [package.model.Section.managers#1], was: [package.model.Section.managers#1] (uninitialized)
DEBUG [btpool0-1] Collections.processReachableCollection(176) | Collection found: [package.model.proteomics.ProteomicsProject.logEntries#42], was: [package.model.proteomics.ProteomicsProject.logEntries#42] (uninitialized)
DEBUG [btpool0-1] Collections.processReachableCollection(176) | Collection found: [package.model.proteomics.ProteomicsProject.requests#42], was: [package.model.proteomics.ProteomicsProject.requests#42] (initialized)
DEBUG [btpool0-1] Collections.processReachableCollection(176) | Collection found: [package.model.proteomics.ProteomicsRequest.samples#1], was: [package.model.proteomics.ProteomicsRequest.samples#1] (initialized)
DEBUG [btpool0-1] Collections.processReachableCollection(176) | Collection found: [package.model.User.costCentres#-2], was: [package.model.User.costCentres#-2] (uninitialized)
DEBUG [btpool0-1] Collections.processReachableCollection(176) | Collection found: [package.model.User.roles#-2], was: [package.model.User.roles#-2] (initialized)
DEBUG [btpool0-1] Collections.processReachableCollection(176) | Collection found: [package.model.Section.managers#2], was: [package.model.Section.managers#2] (uninitialized)
DEBUG [btpool0-1] Collections.processReachableCollection(176) | Collection found: [package.model.User.costCentres#-3], was: [package.model.User.costCentres#-3] (uninitialized)
DEBUG [btpool0-1] Collections.processReachableCollection(176) | Collection found: [package.model.User.roles#-3], was: [package.model.User.roles#-3] (initialized)
DEBUG [btpool0-1] AbstractFlushingEventListener.flushCollections(210) | Processing unreferenced collections
DEBUG [btpool0-1] AbstractFlushingEventListener.flushCollections(224) | Scheduling collection removes/(re)creates/updates
DEBUG [btpool0-1] AbstractFlushingEventListener.flushEverythingToExecutions(85) | Flushed: 0 insertions, 0 updates, 0 deletions to 11 objects
DEBUG [btpool0-1] AbstractFlushingEventListener.flushEverythingToExecutions(91) | Flushed: 0 (re)creations, 0 updates, 0 removals to 9 collections
DEBUG [btpool0-1] Printer.toString(83) | listing entities:
DEBUG [btpool0-1] Printer.toString(90) | package.model.proteomics.ProteomicsRequest{costCentre=package.model.CostCentre#1, dateSubmitted=2009-04-15 12:41:56, authorizationNumber=, fixedModifications=, samples=[package.model.proteomics.ProteomicsSample#1, package.model.proteomics.ProteomicsSample#2], id=1, project=package.model.proteomics.ProteomicsProject#42, additionalComments=, variableModifications=, offlineDataFileName=, description=ZXCzxc, purificationMethod=zzXc, estimateAmount=, active=true, injectionVolume=, user=package.model.User#-3}
DEBUG [btpool0-1] Printer.toString(90) | package.model.CostCentre{id=1, dateModified=2008-07-08 14:22:21, costCentre=123, description=test cost centre, active=true, section=package.model.Section#1, updatedBy=package.model.User#-1}
DEBUG [btpool0-1] Printer.toString(90) | package.model.proteomics.ProteomicsSample{id=2, comment=null, sampleName=sdf}
DEBUG [btpool0-1] Printer.toString(90) | package.model.Section{id=1, managers=<uninitialized>, description=test section}
DEBUG [btpool0-1] Printer.toString(90) | package.model.proteomics.ProteomicsSample{id=1, comment=null, sampleName=xcvsdf}
DEBUG [btpool0-1] Printer.toString(90) | package.model.Role{id=3, description=Manager, name=ROLE_MANAGER}
DEBUG [btpool0-1] Printer.toString(90) | package.model.proteomics.ProteomicsProject{numberOfFiles=0, parentProject=null, logEntries=<uninitialized>, earliestFile=null, sizeOnDisk=0, section=package.model.Section#1, id=42, requests=[package.model.proteomics.ProteomicsRequest#1], lastKnownFullDirectoryLocation=xxx, numberOfFilesPercentage=0.0, numberOfWiffs=0, active=true, latestFile=null, baseDirectoryLocation=xxx, wikiLocation=xxx, defaultCostCentre=package.model.CostCentre#1, projectName=SOD1 Oxidation in ALS, sizeOnDiskPercentage=0.0}
DEBUG [btpool0-1] Printer.toString(90) | package.model.User{enabled=true, lastName=Bristow, passwordHint=admin, accountApproved=true, approvedBy=package.model.User#-2, accountExpired=false, password=d033e22ae348aeb5660fc2140aec35850c4da997, section=package.model.Section#2, accountLocked=false, version=1, id=-2, createdOn=2008-07-08 14:22:21, username=admin, phoneNumber=, createdBy=package.model.User#-2, costCentres=<uninitialized>, email=xxx, roles=[package.model.Role#1], credentialsExpired=false, firstName=Franklin}
DEBUG [btpool0-1] Printer.toString(90) | package.model.Section{id=2, managers=<uninitialized>, description=test section 2}
DEBUG [btpool0-1] Printer.toString(90) | package.model.Role{id=1, description=Administrator, name=ROLE_ADMIN}
DEBUG [btpool0-1] Printer.toString(90) | package.model.User{enabled=true, lastName=manager, passwordHint=manager, accountApproved=true, approvedBy=package.model.User#-2, accountExpired=false, password=1a8565a9dc72048ba03b4156be3e569f22771f23, section=package.model.Section#1, accountLocked=false, version=1, id=-3, createdOn=2008-07-08 14:22:21, username=manager, phoneNumber=, createdBy=package.model.User#-2, costCentres=<uninitialized>, email=xxx, roles=[package.model.Role#3], credentialsExpired=false, firstName=manager}
DEBUG [btpool0-1] AbstractFlushingEventListener.performExecutions(290) | executing flush
DEBUG [btpool0-1] ConnectionManager.flushBeginning(469) | registering flush begin
DEBUG [btpool0-1] ConnectionManager.flushEnding(478) | registering flush end
DEBUG [btpool0-1] AbstractFlushingEventListener.postFlush(321) | post flush
DEBUG [btpool0-1] JDBCContext.beforeTransactionCompletion(205) | before transaction completion
DEBUG [btpool0-1] SessionImpl.beforeTransactionCompletion(393) | before transaction completion
DEBUG [btpool0-1] JDBCTransaction.toggleAutoCommit(193) | re-enabling autocommit
DEBUG [btpool0-1] JDBCTransaction.commit(116) | committed JDBC Connection
DEBUG [btpool0-1] JDBCContext.afterTransactionCompletion(219) | after transaction completion
DEBUG [btpool0-1] ConnectionManager.afterTransaction(302) | transaction completed on session with on_close connection release mode; be sure to close the session to release JDBC resources!
DEBUG [btpool0-1] SessionImpl.afterTransactionCompletion(422) | after transaction completion
DEBUG [btpool0-1] SessionImpl.setFlushMode(1289) | setting flush mode to: NEVER
DEBUG [btpool0-1] SessionImpl.disconnect(374) | disconnecting session
DEBUG [btpool0-1] ConnectionManager.cleanup(380) | performing cleanup
DEBUG [btpool0-1] ConnectionManager.closeConnection(441) | releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
DEBUG [btpool0-1] JDBCContext.afterTransactionCompletion(219) | after transaction completion
DEBUG [btpool0-1] ConnectionManager.afterTransaction(302) | transaction completed on session with on_close connection release mode; be sure to close the session to release JDBC resources!
DEBUG [btpool0-1] SessionImpl.afterTransactionCompletion(422) | after transaction completion
DEBUG [btpool0-1] ProteomicsRequest.getSamples(240) | samples hashCode: [1025052758]
DEBUG [btpool0-1] SessionImpl.setFlushMode(1289) | setting flush mode to: AUTO
DEBUG [btpool0-1] JDBCTransaction.begin(54) | begin
DEBUG [btpool0-1] ConnectionManager.openConnection(421) | opening JDBC connection
DEBUG [btpool0-1] JDBCTransaction.begin(59) | current autocommit status: true
DEBUG [btpool0-1] JDBCTransaction.begin(62) | disabling autocommit
DEBUG [btpool0-1] JDBCContext.afterTransactionBegin(214) | after transaction begin
DEBUG [btpool0-1] DefaultLoadEventListener.proxyOrLoad(171) | loading entity: [package.model.proteomics.ProteomicsRequest#1]
DEBUG [btpool0-1] DefaultLoadEventListener.doLoad(332) | attempting to resolve: [package.model.proteomics.ProteomicsRequest#1]
DEBUG [btpool0-1] DefaultLoadEventListener.doLoad(349) | resolved object in session cache: [package.model.proteomics.ProteomicsRequest#1]
DEBUG [btpool0-1] JDBCTransaction.commit(103) | commit
DEBUG [btpool0-1] SessionImpl.managedFlush(337) | automatically flushing session
DEBUG [btpool0-1] AbstractFlushingEventListener.flushEverythingToExecutions(58) | flushing session
DEBUG [btpool0-1] AbstractFlushingEventListener.prepareEntityFlushes(111) | processing flush-time cascades
DEBUG [btpool0-1] Cascade.cascade(115) | processing cascade ACTION_SAVE_UPDATE for: package.model.Section
DEBUG [btpool0-1] Cascade.cascade(150) | done processing cascade ACTION_SAVE_UPDATE for: package.model.Section
DEBUG [btpool0-1] Cascade.cascade(115) | processing cascade ACTION_SAVE_UPDATE for: package.model.proteomics.ProteomicsProject
DEBUG [btpool0-1] Cascade.cascade(150) | done processing cascade ACTION_SAVE_UPDATE for: package.model.proteomics.ProteomicsProject
DEBUG [btpool0-1] Cascade.cascade(115) | processing cascade ACTION_SAVE_UPDATE for: package.model.proteomics.ProteomicsRequest
DEBUG [btpool0-1] Cascade.cascade(150) | done processing cascade ACTION_SAVE_UPDATE for: package.model.proteomics.ProteomicsRequest
DEBUG [btpool0-1] Cascade.cascade(115) | processing cascade ACTION_SAVE_UPDATE for: package.model.Section
DEBUG [btpool0-1] Cascade.cascade(150) | done processing cascade ACTION_SAVE_UPDATE for: package.model.Section
DEBUG [btpool0-1] AbstractFlushingEventListener.prepareCollectionFlushes(154) | dirty checking collections
DEBUG [btpool0-1] CollectionEntry.preFlush(177) | Collection dirty: [package.model.proteomics.ProteomicsRequest.samples#1]
DEBUG [btpool0-1] AbstractFlushingEventListener.flushEntities(171) | Flushing entities and processing referenced collections
DEBUG [btpool0-1] Collections.processReachableCollection(176) | Collection found: [package.model.Section.managers#1], was: [package.model.Section.managers#1] (uninitialized)
DEBUG [btpool0-1] Collections.processReachableCollection(176) | Collection found: [package.model.proteomics.ProteomicsProject.logEntries#42], was: [package.model.proteomics.ProteomicsProject.logEntries#42] (uninitialized)
DEBUG [btpool0-1] Collections.processReachableCollection(176) | Collection found: [package.model.proteomics.ProteomicsProject.requests#42], was: [package.model.proteomics.ProteomicsProject.requests#42] (initialized)
DEBUG [btpool0-1] Collections.processReachableCollection(176) | Collection found: [package.model.proteomics.ProteomicsRequest.samples#1], was: [package.model.proteomics.ProteomicsRequest.samples#1] (initialized)
DEBUG [btpool0-1] Collections.processReachableCollection(176) | Collection found: [package.model.User.costCentres#-2], was: [package.model.User.costCentres#-2] (uninitialized)
DEBUG [btpool0-1] Collections.processReachableCollection(176) | Collection found: [package.model.User.roles#-2], was: [package.model.User.roles#-2] (initialized)
DEBUG [btpool0-1] Collections.processReachableCollection(176) | Collection found: [package.model.Section.managers#2], was: [package.model.Section.managers#2] (uninitialized)
DEBUG [btpool0-1] Collections.processReachableCollection(176) | Collection found: [package.model.User.costCentres#-3], was: [package.model.User.costCentres#-3] (uninitialized)
DEBUG [btpool0-1] Collections.processReachableCollection(176) | Collection found: [package.model.User.roles#-3], was: [package.model.User.roles#-3] (initialized)
DEBUG [btpool0-1] AbstractFlushingEventListener.flushCollections(210) | Processing unreferenced collections
DEBUG [btpool0-1] AbstractFlushingEventListener.flushCollections(224) | Scheduling collection removes/(re)creates/updates
DEBUG [btpool0-1] AbstractFlushingEventListener.flushEverythingToExecutions(85) | Flushed: 0 insertions, 0 updates, 0 deletions to 11 objects
DEBUG [btpool0-1] AbstractFlushingEventListener.flushEverythingToExecutions(91) | Flushed: 0 (re)creations, 1 updates, 0 removals to 9 collections
DEBUG [btpool0-1] Printer.toString(83) | listing entities:
DEBUG [btpool0-1] Printer.toString(90) | package.model.proteomics.ProteomicsRequest{costCentre=package.model.CostCentre#1, dateSubmitted=2009-04-15 12:41:56, authorizationNumber=, fixedModifications=, samples=[package.model.proteomics.ProteomicsSample#2, package.model.proteomics.ProteomicsSample#1], id=1, project=package.model.proteomics.ProteomicsProject#42, additionalComments=, variableModifications=, offlineDataFileName=, description=ZXCzxc, purificationMethod=zzXc, estimateAmount=, active=true, injectionVolume=, user=package.model.User#-3}
DEBUG [btpool0-1] Printer.toString(90) | package.model.CostCentre{id=1, dateModified=2008-07-08 14:22:21, costCentre=123, description=test cost centre, active=true, section=package.model.Section#1, updatedBy=package.model.User#-1}
DEBUG [btpool0-1] Printer.toString(90) | package.model.proteomics.ProteomicsSample{id=2, comment=null, sampleName=sdf}
DEBUG [btpool0-1] Printer.toString(90) | package.model.Section{id=1, managers=<uninitialized>, description=test section}
DEBUG [btpool0-1] Printer.toString(90) | package.model.proteomics.ProteomicsSample{id=1, comment=null, sampleName=xcvsdf}
DEBUG [btpool0-1] Printer.toString(90) | package.model.Role{id=3, description=Manager, name=ROLE_MANAGER}
DEBUG [btpool0-1] Printer.toString(90) | package.model.proteomics.ProteomicsProject{numberOfFiles=0, parentProject=null, logEntries=<uninitialized>, earliestFile=null, sizeOnDisk=0, section=package.model.Section#1, id=42, requests=[package.model.proteomics.ProteomicsRequest#1], lastKnownFullDirectoryLocation=xxx, numberOfFilesPercentage=0.0, numberOfWiffs=0, active=true, latestFile=null, baseDirectoryLocation=xxx, xxx defaultCostCentre=package.model.CostCentre#1, projectName=SOD1 Oxidation in ALS, sizeOnDiskPercentage=0.0}
DEBUG [btpool0-1] Printer.toString(90) | package.model.User{enabled=true, lastName=Bristow, passwordHint=admin, accountApproved=true, approvedBy=package.model.User#-2, accountExpired=false, password=d033e22ae348aeb5660fc2140aec35850c4da997, section=package.model.Section#2, accountLocked=false, version=1, id=-2, createdOn=2008-07-08 14:22:21, username=admin, phoneNumber=, createdBy=package.model.User#-2, costCentres=<uninitialized>, email=xxx roles=[package.model.Role#1], credentialsExpired=false, firstName=Franklin}
DEBUG [btpool0-1] Printer.toString(90) | package.model.Section{id=2, managers=<uninitialized>, description=test section 2}
DEBUG [btpool0-1] Printer.toString(90) | package.model.Role{id=1, description=Administrator, name=ROLE_ADMIN}
DEBUG [btpool0-1] Printer.toString(90) | package.model.User{enabled=true, lastName=manager, passwordHint=manager, accountApproved=true, approvedBy=package.model.User#-2, accountExpired=false, password=1a8565a9dc72048ba03b4156be3e569f22771f23, section=package.model.Section#1, accountLocked=false, version=1, id=-3, createdOn=2008-07-08 14:22:21, username=manager, phoneNumber=, createdBy=package.model.User#-2, costCentres=<uninitialized>, email=xxx roles=[package.model.Role#3], credentialsExpired=false, firstName=manager}
DEBUG [btpool0-1] AbstractFlushingEventListener.performExecutions(290) | executing flush
DEBUG [btpool0-1] ConnectionManager.flushBeginning(469) | registering flush begin
DEBUG [btpool0-1] AbstractCollectionPersister.remove(1010) | Deleting collection: [package.model.proteomics.ProteomicsRequest.samples#1]
DEBUG [btpool0-1] AbstractBatcher.logOpenPreparedStatement(366) | about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
DEBUG [btpool0-1] SQL.log(401) | delete from ProteomicsRequest_ProteomicsSample where ProteomicsRequest_id=?