-->
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.  [ 6 posts ] 
Author Message
 Post subject: Slow inserts with cascade enabled
PostPosted: Thu Jul 12, 2007 5:42 am 
Beginner
Beginner

Joined: Wed Jan 31, 2007 6:54 am
Posts: 22
Hibernate version: 3.2.2

Name and version of the database you are using: JavaDB

Hi,
I have a problem with slow performance when inserting a large number of objects through cascade.

I have an application that generates up to 1000 objects A that should be written to DB. Each object A has a set of 1000 objects B which also should be written to DB. This means up to 1M objects to be inserted.

We have set the mapping so that when we store A, the associated set of B should be stored through cascade.

In our implementation, we split the 1000 A objects in chunks of 10 and store these in different sessions, so out of memory is not a problem, but processing time is (30 minutes++ on a decent machine).

Is it correct to think that the cause of the slowness is that for each object, Hibernate needs to query the database to know if this object is in the database already, thus generating ~2M SQL statements (insert/update for each object)?
It looks like this is the case (running hibernate with debug output). None of the objects are supposed to be in the DB in the first place.

I read in ch 13 in the manual about batch processing that we could use a stateless session, but then the cascade insert wouldnt work, which is one of the good things with hibernate in the first place.

Is this 30 min+ insert time to be expected? Does anyone have suggestions to what I could do to increase performance?

Thanks in advance!


Top
 Profile  
 
 Post subject:
PostPosted: Fri Jul 27, 2007 9:23 am 
Beginner
Beginner

Joined: Wed Jan 31, 2007 6:54 am
Posts: 22
Hi,
sorry for posting on my own thread, but anyone have any advice on this?

Maybe my problem is too little specific, do you need more information to answer?

thanks in advance!


Top
 Profile  
 
 Post subject:
PostPosted: Sat Jul 28, 2007 3:23 pm 
Expert
Expert

Joined: Fri Jul 13, 2007 8:18 am
Posts: 370
Location: london
Hibernate shouldn't need to query the database to determine if the object exists - the lack of a primary key indicates this. What key generation strategy are you using? Objects or primitives? Can you post a small section of the sql.

Are you inserting so many rows at once to create an initial data set or is this a normal operation?

I've done a quick test inserting 100 A records, each containing 1000 B's. Both A and B have 5 String fields populated with about 8 chars of data. The database is local (is yours local or over network?).
Derby: 79s
MYSQL: 71s
Giving around 15 minutes to insert the full 1000 A's.


Top
 Profile  
 
 Post subject:
PostPosted: Tue Aug 14, 2007 5:32 am 
Beginner
Beginner

Joined: Wed Jan 31, 2007 6:54 am
Posts: 22
Hi,
thanks for your reply and your benchmarks!
This operation is done by a user inserting data into an existing database (although an extreme case). I also use Derby.

I am not sure if I follow all of your comments though:
Quote:
Hibernate shouldn't need to query the database to determine if the object exists - the lack of a primary key indicates this.

do you mean that hibernate knows of all existing primary keys in the first
place, so that if this is a new primary key, hbn should know firsthand?

I am using composite keys for both A and B, maybe that is important?
It seems at least to me that hibernate queries the database before saving a new object:

Below I have posted the debug + SQL output from Hibernate that happens when I do
aSession.save(Object object)
on an object (in this case an object of class Observation. Time stamps are strange because I was stepping in debug mode).

Code:
11:09:53,062 DEBUG DefaultSaveOrUpdateEventListener:158 - saving transient instance
11:09:53,078 DEBUG AbstractSaveEventListener:112 - generated identifier: component[nation,platform,survey,observationDate,observationTime,observationType]{observationTime=1212779, observationDate=20031027, platform=2471, survey=7, observationType=3000, nation=578}, using strategy: org.hibernate.id.Assigned
11:09:53,078 DEBUG AbstractSaveEventListener:153 - saving [no.imr.lsss.database.tables.hibernate.Observation#component[nation,platform,survey,observationDate,observationTime,observationType]{observationTime=1212779, observationDate=20031027, platform=2471, survey=7, observationType=3000, nation=578}]
11:09:53,078 DEBUG IdentifierValue:77 - id unsaved-value strategy UNDEFINED
11:10:13,750 DEBUG AbstractEntityPersister:1013 - Getting current persistent state for: [no.imr.lsss.database.tables.hibernate.Survey#component[nation,platform,survey]{platform=2471, survey=7, nation=578}]
11:10:13,765 DEBUG AbstractBatcher:358 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
11:10:13,765 DEBUG SQL:393 - select survey_.Nation, survey_.Platform, survey_.Survey, survey_.SurveyTitle as SurveyTi4_6_, survey_.StartDate as StartDate6_, survey_.StartTime as StartTime6_, survey_.StopDate as StopDate6_, survey_.StopTime as StopTime6_, survey_.Comment as Comment6_, survey_.BoundaryNorth as Boundar10_6_, survey_.BoundarySouth as Boundar11_6_, survey_.BoundaryWest as Boundar12_6_, survey_.BoundaryEast as Boundar13_6_ from survey survey_ where survey_.Nation=? and survey_.Platform=? and survey_.Survey=?
Hibernate: select survey_.Nation, survey_.Platform, survey_.Survey, survey_.SurveyTitle as SurveyTi4_6_, survey_.StartDate as StartDate6_, survey_.StartTime as StartTime6_, survey_.StopDate as StopDate6_, survey_.StopTime as StopTime6_, survey_.Comment as Comment6_, survey_.BoundaryNorth as Boundar10_6_, survey_.BoundarySouth as Boundar11_6_, survey_.BoundaryWest as Boundar12_6_, survey_.BoundaryEast as Boundar13_6_ from survey survey_ where survey_.Nation=? and survey_.Platform=? and survey_.Survey=?
11:10:13,765 DEBUG AbstractBatcher:476 - preparing statement
11:10:13,765 DEBUG ShortType:133 - binding '578' to parameter: 1
11:10:13,781 DEBUG ShortType:133 - binding '2471' to parameter: 2
11:10:13,781 DEBUG IntegerType:133 - binding '7' to parameter: 3
11:10:13,781 DEBUG StringType:172 - returning 'jkl' as column: SurveyTi4_6_
11:10:13,781 DEBUG IntegerType:172 - returning '20070814' as column: StartDate6_
11:10:13,796 DEBUG IntegerType:172 - returning '0' as column: StartTime6_
11:10:13,796 DEBUG IntegerType:172 - returning '20070814' as column: StopDate6_
11:10:13,796 DEBUG IntegerType:172 - returning '23590000' as column: StopTime6_
11:10:13,796 DEBUG StringType:172 - returning '' as column: Comment6_
11:10:13,812 DEBUG FloatType:172 - returning '0.0' as column: Boundar10_6_
11:10:13,812 DEBUG FloatType:172 - returning '0.0' as column: Boundar11_6_
11:10:13,812 DEBUG FloatType:172 - returning '0.0' as column: Boundar12_6_
11:10:13,812 DEBUG FloatType:172 - returning '0.0' as column: Boundar13_6_
11:10:13,812 DEBUG AbstractBatcher:366 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
11:10:13,828 DEBUG AbstractBatcher:525 - closing statement
11:10:24,937 DEBUG IdentifierValue:77 - id unsaved-value strategy UNDEFINED
11:10:25,796 DEBUG AbstractEntityPersister:1013 - Getting current persistent state for: [no.imr.lsss.database.tables.hibernate.Observationtype#3000]
11:10:25,796 DEBUG AbstractBatcher:358 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
11:10:25,796 DEBUG SQL:393 - select observatio_.ObservationType, observatio_.ObservationTypeName as Observat2_17_ from observationtype observatio_ where observatio_.ObservationType=?
Hibernate: select observatio_.ObservationType, observatio_.ObservationTypeName as Observat2_17_ from observationtype observatio_ where observatio_.ObservationType=?
11:10:25,812 DEBUG AbstractBatcher:476 - preparing statement
11:10:25,843 DEBUG ShortType:133 - binding '3000' to parameter: 1
11:10:25,859 DEBUG StringType:172 - returning 'Scattered Fish Data' as column: Observat2_17_
11:10:25,859 DEBUG AbstractBatcher:366 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
11:10:25,859 DEBUG AbstractBatcher:525 - closing statement


I interpret the line
11:10:13,750 DEBUG AbstractEntityPersister:1013 - Getting current persistent state for:
to mean that hibernate is checking with the database if this object already exists?
(the insert is of course done later when I do Transaction:commit() )

Sorry for the long post and thanks in advance.


Top
 Profile  
 
 Post subject:
PostPosted: Tue Aug 14, 2007 5:58 am 
Expert
Expert

Joined: Fri Jul 13, 2007 8:18 am
Posts: 370
Location: london
Quote:
do you mean that hibernate knows of all existing primary keys in the first
place, so that if this is a new primary key, hbn should know firsthand?

No, I mean for example, if the key is a java Long and that Long is null then the ID is not assigned so the object is new and should be inserted.

Composite ids are definitely causing your select before insert problems. Hibernate is trying to determine if your object is new. Because its not possible to define a value for an unassigned composite id, hibernate checks whether the object is already in the database to decide if its new or not.

If you can, switch to a simpler ID type.


Top
 Profile  
 
 Post subject:
PostPosted: Tue Aug 14, 2007 6:02 am 
Beginner
Beginner

Joined: Wed Jan 31, 2007 6:54 am
Posts: 22
Ok, I see.
So with the estimated 15 minutes from your benchmark, and my added overhead of a select for each object, 30+ minutes is not unreasonable for the 1000 A with 1000 B each I guess...

Thanks for the clarification!


Top
 Profile  
 
Display posts from previous:  Sort by  
Forum locked This topic is locked, you cannot edit posts or make further replies.  [ 6 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.