-->
These old forums are deprecated now and set to read-only. We are waiting for you on our new forums!
More modern, Discourse-based and with GitHub/Google/Twitter authentication built-in.

All times are UTC - 5 hours [ DST ]



Forum locked This topic is locked, you cannot edit posts or make further replies.  [ 2 posts ] 
Author Message
 Post subject: Collection references are deleted and re-inserted
PostPosted: Wed Apr 15, 2009 1:53 pm 
Newbie

Joined: Wed Apr 15, 2009 12:41 pm
Posts: 2
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=?


Top
 Profile  
 
 Post subject: Re: Collection references are deleted and re-inserted
PostPosted: Thu May 14, 2009 12:28 pm 
Newbie

Joined: Wed Apr 15, 2009 12:41 pm
Posts: 2
So, I found one other instances of what I was experiencing:
http://www.mail-archive.com/hibernate-d ... 06430.html

I also found a post that describes a similar symptom with @ManyToMany versus @OneToMany that provided a solution of changing a Collection to a Set:
http://guanyu.info/blog/?p=69
Quote:
Finally, I came cross a post stating that he had the same problem and "change the property type from Collection to Set" solved his problem. I am not sure why it works with Set but not Collection, but it does solve my problem as well. I might be going to do more research on that later.


Having had a little bit of time to try new things, I thought I would change my collection definitions from Lists to Sets. Lo and behold, when I do a retrieval operation on my collection, it is no longer marked as dirty and none of the references are deleted or inserted. Hooray!

The reason that this is happening is that my collections are now being loaded into a PersistentSet instead of a PersistentBag. The hashCode() method in PersistentSet calls a read() on the collection and then uses the hashCode() method of the underlying Set where PersistentBag is calling the hashCode() method on Object. This yields different results from call to call depending upon where the collection resides in memory and was causing Hibernate to think that my collections were dirty. The same person wrote both of these classes (Gavin King). I don't know which is the desired behaviour in this case as PersistentBag has the original hashCode() method commented out to replace it with super.hashCode() that calls on Object and PersistentSet does not have these methods commented out.. Is there someone that can respond to that? I am curious to know if I am simply relying on the behaviour of broken code, and if I can expect that behaviour in the future...

I don't know if this information is useful to anyone, but I know it was useful to me, so if nobody else finds this interesting this is merely a place for me to store this information


Top
 Profile  
 
Display posts from previous:  Sort by  
Forum locked This topic is locked, you cannot edit posts or make further replies.  [ 2 posts ] 

All times are UTC - 5 hours [ DST ]


You cannot post new topics in this forum
You cannot reply to topics in this forum
You cannot edit your posts in this forum
You cannot delete your posts in this forum

Search for:
© Copyright 2014, Red Hat Inc. All rights reserved. JBoss and Hibernate are registered trademarks and servicemarks of Red Hat, Inc.