-->
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.

View unanswered posts | View active topics


Board index » Hibernate & Java Persistence » Hibernate Users

All times are UTC - 5 hours [ DST ]


Forum locked This topic is locked, you cannot edit posts or make further replies.  Page 1 of 1
  [ 5 posts ] 
  Previous topic | Next topic 
Author Message
stolley
 Post subject: Hibernate collection dirty checking causing extra SQL update
PostPosted: Thu Jan 22, 2004 9:00 pm 
Pro
Pro

Joined: Tue Aug 26, 2003 8:07 pm
Posts: 229
Location: Brisbane, Australia
I' ve got a Person object that has a collection of Address objects.
When I save() a brand new Person object (with an empty set of Address objects) Hibernate issues an insert on the person table (good) and then an update on the person table (bad, or at least unnecessary).

I don't understand why Hibernate is issuing the update on the person table. The problem appears to be the definition of the getAddresses() method; the get method will create a new Set if the attribute is null. I know it's the creation of the Set that's causing the issue, becuase if I remove the code that checks for null and creates the Set, I don't get the extra SQL update issued.

I could just remove the code from all my collection getters, but I like the idiom because then I never have to check for nulls anywhere else in my code as long as I always use the getter to get the collection.

But most importantly, I'm just wondering why is Hibernate doing this?

I've looked in the debug log and Hibernate seems to be saying that it detects that the collection is dirty. But I don't understand how Hibernate could know that because until the call to save() Hibernate has never seen the object before!


Here's the relevant part of the Person object:
Code:
/**
     * @return will never return null
     * @hibernate:set
     *      role="addresses"
     *      cascade="all"
     *      inverse="false"
     *      lazy="true"
     * @hibernate:collection-key column = "n_key_person"
     * @hibernate:collection-one-to-many
     *      class="nrm.clas.domain.elvas.contact.ElvasAddress"
     */
    public Set getAddresses() {
        if( addresses == null ){
            addresses = new HashSet();
        }
        return addresses;
    }
   
    public void setAddresses(Set addresses) {
        this.addresses = addresses;
    }
   
    public void addAddress(ElvasAddress address){
        getAddresses().add(address);
    }


Here is the log:
Quote:
10:21:41,889 main DEBUG InteractionPersistenceManagerTest:73 [testInteractionManipulations] save the person
10:21:41,889 main DEBUG JDBCTransaction:37 [testInteractionManipulations] begin
10:21:41,889 main DEBUG JDBCTransaction:41 [testInteractionManipulations] current autocommit status:true
10:21:41,889 main DEBUG JDBCTransaction:43 [testInteractionManipulations] disabling autocommit
10:21:42,124 main DEBUG hibernate-1:175 [testInteractionManipulations] select n_key_next from cl_id_gen for update; (16 milliseconds)
10:21:42,155 main DEBUG hibernate-1:175 [testInteractionManipulations] update cl_id_gen set n_key_next = 2171 where n_key_next = ; (16 milliseconds)
10:21:42,155 main DEBUG TableHiLoGenerator:62 [testInteractionManipulations] new hi value: 2170
10:21:42,155 main DEBUG SessionImpl:786 [testInteractionManipulations] saving [nrm.clas.domain.elvas.contact.Person#279931]
10:21:42,155 main DEBUG Cascades:497 [testInteractionManipulations] processing cascades for: nrm.clas.domain.elvas.contact.Person
10:21:42,155 main DEBUG Cascades:506 [testInteractionManipulations] done processing cascades for: nrm.clas.domain.elvas.contact.Person
10:21:42,186 main DEBUG Cascades:497 [testInteractionManipulations] processing cascades for: nrm.clas.domain.elvas.contact.Person
10:21:42,186 main DEBUG Cascades:524 [testInteractionManipulations] cascading to collection: nrm.clas.domain.elvas.contact.Person.addresses
10:21:42,186 main DEBUG Cascades:506 [testInteractionManipulations] done processing cascades for: nrm.clas.domain.elvas.contact.Person
10:21:42,186 main DEBUG SessionImpl:2193 [testInteractionManipulations] flushing session
10:21:42,186 main DEBUG Cascades:497 [testInteractionManipulations] processing cascades for: nrm.clas.domain.elvas.contact.Person
10:21:42,186 main DEBUG Cascades:524 [testInteractionManipulations] cascading to collection: nrm.clas.domain.elvas.contact.Person.addresses
10:21:42,186 main DEBUG Cascades:506 [testInteractionManipulations] done processing cascades for: nrm.clas.domain.elvas.contact.Person
10:21:42,186 main DEBUG SessionImpl:2321 [testInteractionManipulations] Flushing entities and processing referenced collections
10:21:42,202 main DEBUG WrapVisitor:76 [testInteractionManipulations] Wrapped collection in role: nrm.clas.domain.elvas.contact.Person.addresses
10:21:42,202 main DEBUG AbstractEntityPersister:278 [testInteractionManipulations] nrm.clas.domain.elvas.contact.Person.addresses is dirty
10:21:42,202 main DEBUG SessionImpl:2415 [testInteractionManipulations] Updating entity: [nrm.clas.domain.elvas.contact.Person#279931]
10:21:42,202 main DEBUG Versioning:26 [testInteractionManipulations] Incrementing: 0 to 1
10:21:42,202 main DEBUG SessionImpl:2768 [testInteractionManipulations] Collection found: [nrm.clas.domain.elvas.contact.Person.addresses#279931], was: [<unreferenced>]
10:21:42,202 main DEBUG SessionImpl:2664 [testInteractionManipulations] Processing unreferenced collections
10:21:42,202 main DEBUG SessionImpl:2678 [testInteractionManipulations] Scheduling collection removes/(re)creates/updates
10:21:42,217 main DEBUG SessionImpl:2217 [testInteractionManipulations] Flushed: 1 insertions, 1 updates, 0 deletions to 1 objects
10:21:42,217 main DEBUG SessionImpl:2222 [testInteractionManipulations] Flushed: 1 (re)creations, 0 updates, 0 removals to 1 collections
10:21:42,217 main DEBUG Printer:75 [testInteractionManipulations] listing entities:
10:21:42,217 main DEBUG Printer:82 [testInteractionManipulations] nrm.clas.domain.elvas.contact.Person{addresses=[], abn=abn, surname=surname, personTitle=ElvasPersonTitle#1, communicationMethods=null, decorations=decos, auditInfo=nrm.clas.common.persistence.AuditInfo@7e75d2[lastUpdated=2004-01-23 10:21:42.202,created=2004-01-23 10:21:42.17,updatedBy=5,createdBy=5], soundex=surname, givenNames=given, entityLocation=null, id=279931, version=1}
10:21:42,217 main DEBUG SessionImpl:2258 [testInteractionManipulations] executing flush
10:21:42,217 main DEBUG EntityPersister:454 [testInteractionManipulations] Inserting entity: [nrm.clas.domain.elvas.contact.Person#279931]
10:21:42,217 main DEBUG EntityPersister:455 [testInteractionManipulations] Version: 0
10:21:42,217 main DEBUG BatcherImpl:192 [testInteractionManipulations] about to open: 0 open PreparedStatements, 0 open ResultSets
10:21:42,217 main DEBUG SQL:223 [testInteractionManipulations] insert into cl_person (n_locking_version, t_abn, t_decorations, n_key_entity_locn, t_given_names, n_key_person_title, t_soundex, t_surname, d_updated, d_created, n_key_user_updated, n_key_user_created, n_key_person) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
10:21:42,217 main DEBUG BatcherImpl:227 [testInteractionManipulations] preparing statement
10:21:42,217 main DEBUG EntityPersister:389 [testInteractionManipulations] Dehydrating entity: [nrm.clas.domain.elvas.contact.Person#279931]
10:21:42,233 main DEBUG IntegerType:46 [testInteractionManipulations] binding '0' to parameter: 1
10:21:42,233 main DEBUG StringType:46 [testInteractionManipulations] binding 'abn' to parameter: 2
10:21:42,233 main DEBUG StringType:46 [testInteractionManipulations] binding 'decos' to parameter: 3
10:21:42,233 main DEBUG LongType:41 [testInteractionManipulations] binding null to parameter: 4
10:21:42,233 main DEBUG StringType:46 [testInteractionManipulations] binding 'given' to parameter: 5
10:21:42,233 main DEBUG LongType:46 [testInteractionManipulations] binding '1' to parameter: 6
10:21:42,233 main DEBUG StringType:46 [testInteractionManipulations] binding 'surname' to parameter: 7
10:21:42,233 main DEBUG StringType:46 [testInteractionManipulations] binding 'surname' to parameter: 8
10:21:42,233 main DEBUG TimestampType:46 [testInteractionManipulations] binding '23 January 2004 10:21:42' to parameter: 9
10:21:42,233 main DEBUG TimestampType:46 [testInteractionManipulations] binding '23 January 2004 10:21:42' to parameter: 10
10:21:42,233 main DEBUG LongType:46 [testInteractionManipulations] binding '5' to parameter: 11
10:21:42,233 main DEBUG LongType:46 [testInteractionManipulations] binding '5' to parameter: 12
10:21:42,233 main DEBUG LongType:46 [testInteractionManipulations] binding '279931' to parameter: 13
10:21:42,249 main DEBUG hibernate-1:175 [testInteractionManipulations] insert into cl_person (n_locking_version, t_abn, t_decorations, n_key_entity_locn, t_given_names, n_key_person_title, t_soundex, t_surname, d_updated, d_created, n_key_user_updated, n_key_user_created, n_key_person) values (0, 'abn', 'decos', NULL, 'given', 1, 'surname', 'surname', Timestamp, Timestamp, 5, 5, 279931); (16 milliseconds)
10:21:42,249 main DEBUG BatcherImpl:199 [testInteractionManipulations] done closing: 0 open PreparedStatements, 0 open ResultSets
10:21:42,249 main DEBUG BatcherImpl:240 [testInteractionManipulations] closing statement
10:21:42,249 main DEBUG EntityPersister:631 [testInteractionManipulations] Updating entity: [nrm.clas.domain.elvas.contact.Person#279931]
10:21:42,249 main DEBUG EntityPersister:632 [testInteractionManipulations] Existing version: 0 -> New version: 1
10:21:42,249 main DEBUG BatcherImpl:192 [testInteractionManipulations] about to open: 0 open PreparedStatements, 0 open ResultSets
10:21:42,249 main DEBUG SQL:223 [testInteractionManipulations] update cl_person set n_locking_version=?, t_abn=?, t_decorations=?, n_key_entity_locn=?, t_given_names=?, n_key_person_title=?, t_soundex=?, t_surname=?, d_updated=?, d_created=?, n_key_user_updated=?, n_key_user_created=? where n_key_person=? and n_locking_version=?
10:21:42,264 main DEBUG BatcherImpl:227 [testInteractionManipulations] preparing statement
10:21:42,264 main DEBUG EntityPersister:389 [testInteractionManipulations] Dehydrating entity: [nrm.clas.domain.elvas.contact.Person#279931]
10:21:42,264 main DEBUG IntegerType:46 [testInteractionManipulations] binding '1' to parameter: 1
10:21:42,264 main DEBUG StringType:46 [testInteractionManipulations] binding 'abn' to parameter: 2
10:21:42,264 main DEBUG StringType:46 [testInteractionManipulations] binding 'decos' to parameter: 3
10:21:42,264 main DEBUG LongType:41 [testInteractionManipulations] binding null to parameter: 4
10:21:42,264 main DEBUG StringType:46 [testInteractionManipulations] binding 'given' to parameter: 5
10:21:42,264 main DEBUG LongType:46 [testInteractionManipulations] binding '1' to parameter: 6
10:21:42,264 main DEBUG StringType:46 [testInteractionManipulations] binding 'surname' to parameter: 7
10:21:42,264 main DEBUG StringType:46 [testInteractionManipulations] binding 'surname' to parameter: 8
10:21:42,264 main DEBUG TimestampType:46 [testInteractionManipulations] binding '23 January 2004 10:21:42' to parameter: 9
10:21:42,264 main DEBUG TimestampType:46 [testInteractionManipulations] binding '23 January 2004 10:21:42' to parameter: 10
10:21:42,264 main DEBUG LongType:46 [testInteractionManipulations] binding '5' to parameter: 11
10:21:42,280 main DEBUG LongType:46 [testInteractionManipulations] binding '5' to parameter: 12
10:21:42,280 main DEBUG LongType:46 [testInteractionManipulations] binding '279931' to parameter: 13
10:21:42,280 main DEBUG IntegerType:46 [testInteractionManipulations] binding '0' to parameter: 14
10:21:42,280 main DEBUG hibernate-1:175 [testInteractionManipulations] update cl_person set n_locking_version=1, t_abn='abn', t_decorations='decos', n_key_entity_locn=NULL, t_given_names='given', n_key_person_title=1, t_soundex='surname', t_surname='surname', d_updated=Timestamp, d_created=Timestamp, n_key_user_updated=5, n_key_user_created=5 where n_key_person=279931 and n_locking_version=; (0 milliseconds)
10:21:42,280 main DEBUG BatcherImpl:199 [testInteractionManipulations] done closing: 0 open PreparedStatements, 0 open ResultSets
10:21:42,280 main DEBUG BatcherImpl:240 [testInteractionManipulations] closing statement
10:21:42,280 main DEBUG BasicCollectionPersister:522 [testInteractionManipulations] Inserting collection: [nrm.clas.domain.elvas.contact.Person.addresses#279931]
10:21:42,280 main DEBUG BasicCollectionPersister:553 [testInteractionManipulations] collection was empty
10:21:42,280 main DEBUG SessionImpl:2708 [testInteractionManipulations] post flush
10:21:42,280 main DEBUG JDBCTransaction:59 [testInteractionManipulations] commit
10:21:42,280 main DEBUG SessionImpl:2193 [testInteractionManipulations] flushing session
[/i]

_________________
Cheers,
Shorn.

Top
 Profile  
 
christian
 Post subject:
PostPosted: Thu Jan 22, 2004 9:07 pm 
Hibernate Team
Hibernate Team

Joined: Mon Aug 25, 2003 9:11 pm
Posts: 4592
Location: Switzerland
Use

public class Person {
Set addresses = new HashSet();
...

That way, all initialization is visible in one place and you can easily change implementations. It also prevents null collections efficiently and there is actually no downside.

_________________
JAVA PERSISTENCE WITH HIBERNATE
http://jpwh.org
Get the book, training, and consulting for your Hibernate team.

Top
 Profile  
 
stolley
 Post subject:
PostPosted: Thu Jan 22, 2004 9:41 pm 
Pro
Pro

Joined: Tue Aug 26, 2003 8:07 pm
Posts: 229
Location: Brisbane, Australia
Yeah, Ok. Except that doesn't work when someone calls the setter with a null reference.

But apart from that I just want to know why Hibernate does this.
If I can understand why Hibernate does what it does, maybe I can think up a better way. Or if nothing else I'll understand Hibernate just a little better.

_________________
Cheers,
Shorn.

Top
 Profile  
 
stolley
 Post subject:
PostPosted: Thu Jan 22, 2004 10:02 pm 
Pro
Pro

Joined: Tue Aug 26, 2003 8:07 pm
Posts: 229
Location: Brisbane, Australia
christian wrote:
Use

public class Person {
Set addresses = new HashSet();
...

That way, all initialization is visible in one place and you can easily change implementations. It also prevents null collections efficiently and there is actually no downside.


Well, disregarding my previous post, I tried it your way anyway.
I removed the check in the getter and added the creation to the attribute definition statement.

Same thing. I still get the extra update.

I removed the create from the attribute definition - nor more extra update statement.

(Tried it a couple of times, just in case. The result is repeatable)

_________________
Cheers,
Shorn.

Top
 Profile  
 
anved
 Post subject:
PostPosted: Thu May 06, 2004 10:18 am 
Newbie

Joined: Thu May 06, 2004 10:12 am
Posts: 2
I had same problems with collections, it seems like early initialisation in class make Hibernate thinking that collection has been modified.
May be it will be nice to check initialized flag before marking it dirty ?

Anyway it works with null, and i'm happy because i have no time for waiting of more "elegant" solutions :)
Top
 Profile  
 
Display posts from previous:  Sort by  
Forum locked This topic is locked, you cannot edit posts or make further replies.  Page 1 of 1
  [ 5 posts ] 

Board index » Hibernate & Java Persistence » Hibernate Users

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.