Hi,

I am currently struggling with Hibernate to perform efficiently for my insert and fetching requirements. I have around 5000 records to insert, and Hibernate is performing poorly in this scenario. On analysis of the logs generated by Hibernate, I found few issues, one of which I would like to clarify in this post.

In this example, I have Department and Employee objects. The Department can have n number of Employees, and hence there's one-to-many relation from Department to Employee. I have created 1 department object, and 3 employee objects under the department.

I say to persist department object into the database. This has generated the hibernate logs below.

On analysing the logs, I found that Hibernate inserts the Employee objects as batch insert using:

But, after that, it tries to update the foreign key value in these records using:
I have highlighted these as red in the attached logs.

I don't understand why this is necessary, the record is inserted in the first statement with the correct foreign key ID, and running these statements again impacts the performance when performing high volume inserts.

Could somebody explain me the reason for this, and how this can be stopped in Hibernate?

Hibernate version: 2.1.8

Mapping documents:

<?xml version="1.0" encoding="US-ASCII"?>
<!DOCTYPE hibernate-mapping PUBLIC "-//Hibernate/Hibernate Mapping DTD 2.0//EN"
"http://hibernate.sourceforge.net/hibernate-mapping-2.0.dtd">
<hibernate-mapping package="test.model">
<class name="Department" table="DEPARTMENT">
<!-- The primary key -->
<id name="id" column="ID">
<generator class="uuid.hex" />
</id>
<property name="name" column="NAME" />
<set name="employees" table="EMPLOYEE" cascade="all">
<key>
<column name="DEPT_ID" not-null="true" />
</key>
<one-to-many class="Employee" />
</set>
</class>
<class name="Employee" table="EMPLOYEE">
<id name="id" column="ID">
<generator class="uuid.hex" />
</id>
<property name="name" column="NAME" />
<many-to-one name="department" class="Department"
column="DEPT_ID" />
</class>
</hibernate-mapping>


Code between sessionFactory.openSession() and session.close():
HibernateUtil.beginTransaction();
Session session = HibernateUtil.getSession();
session.saveOrUpdate(department);
HibernateUtil.commitTransaction();


Name and version of the database you are using: HSQLDB 1.8

Debug level Hibernate log excerpt:
opened session
begin
total checked-out connections: 0
using pooled JDBC connection, pool size: 0
current autocommit status:false
saveOrUpdate() unsaved instance
generated identifier: d2a9cb5c11620ea60111620ea8b70001
saving [test.model.Department#d2a9cb5c11620ea60111620ea8b70001]
processing cascades for: test.model.Department
done processing cascades for: test.model.Department
Wrapped collection in role: test.model.Department.employees
processing cascades for: test.model.Department
cascading to collection: test.model.Department.employees
cascading to saveOrUpdate()
saveOrUpdate() unsaved instance
generated identifier: d2a9cb5c11620ea60111620ea8c70002
saving [test.model.Employee#d2a9cb5c11620ea60111620ea8c70002]
cascading to saveOrUpdate()
saveOrUpdate() unsaved instance
generated identifier: d2a9cb5c11620ea60111620ea8c70003
saving [test.model.Employee#d2a9cb5c11620ea60111620ea8c70003]
cascading to saveOrUpdate()
saveOrUpdate() unsaved instance
generated identifier: d2a9cb5c11620ea60111620ea8c70004
saving [test.model.Employee#d2a9cb5c11620ea60111620ea8c70004]
done processing cascades for: test.model.Department
commit
flushing session
processing cascades for: test.model.Department
cascading to collection: test.model.Department.employees
cascading to saveOrUpdate()
saveOrUpdate() persistent instance
cascading to saveOrUpdate()
saveOrUpdate() persistent instance
cascading to saveOrUpdate()
saveOrUpdate() persistent instance
done processing cascades for: test.model.Department
Flushing entities and processing referenced collections
Collection found: [test.model.Department.employees#d2a9cb5c11620ea60111620ea8b70001], was: [<unreferenced>]
Processing unreferenced collections
Scheduling collection removes/(re)creates/updates
Flushed: 4 insertions, 0 updates, 0 deletions to 4 objects
Flushed: 1 (re)creations, 0 updates, 0 removals to 1 collections
listing entities:
test.model.Employee{name=MyName2, id=d2a9cb5c11620ea60111620ea8c70002, department=Department#d2a9cb5c11620ea60111620ea8b70001}
test.model.Department{employees=[Employee#d2a9cb5c11620ea60111620ea8c70002, Employee#d2a9cb5c11620ea60111620ea8c70003, Employee#d2a9cb5c11620ea60111620ea8c70004], name=ApplicationDevelopment, id=d2a9cb5c11620ea60111620ea8b70001}
test.model.Employee{name=MyName1, id=d2a9cb5c11620ea60111620ea8c70003, department=Department#d2a9cb5c11620ea60111620ea8b70001}
test.model.Employee{name=MyName0, id=d2a9cb5c11620ea60111620ea8c70004, department=Department#d2a9cb5c11620ea60111620ea8b70001}
executing flush
Inserting entity: [test.model.Department#d2a9cb5c11620ea60111620ea8b70001]
about to open: 0 open PreparedStatements, 0 open ResultSets
insert into DEPARTMENT (NAME, ID) values (?, ?)
preparing statement
Dehydrating entity: [test.model.Department#d2a9cb5c11620ea60111620ea8b70001]
binding 'ApplicationDevelopment' to parameter: 1
binding 'd2a9cb5c11620ea60111620ea8b70001' to parameter: 2
Adding to batch
Inserting entity: [test.model.Employee#d2a9cb5c11620ea60111620ea8c70002]
Executing batch size: 1
done closing: 0 open PreparedStatements, 0 open ResultSets
closing statement
about to open: 0 open PreparedStatements, 0 open ResultSets
insert into EMPLOYEE (NAME, DEPT_ID, ID) values (?, ?, ?)
preparing statement
Dehydrating entity: [test.model.Employee#d2a9cb5c11620ea60111620ea8c70002]
binding 'MyName2' to parameter: 1
binding 'd2a9cb5c11620ea60111620ea8b70001' to parameter: 2
binding 'd2a9cb5c11620ea60111620ea8c70002' to parameter: 3
Adding to batch
Inserting entity: [test.model.Employee#d2a9cb5c11620ea60111620ea8c70003]
reusing prepared statement
insert into EMPLOYEE (NAME, DEPT_ID, ID) values (?, ?, ?)
Dehydrating entity: [test.model.Employee#d2a9cb5c11620ea60111620ea8c70003]
binding 'MyName1' to parameter: 1
binding 'd2a9cb5c11620ea60111620ea8b70001' to parameter: 2
binding 'd2a9cb5c11620ea60111620ea8c70003' to parameter: 3
Adding to batch
Inserting entity: [test.model.Employee#d2a9cb5c11620ea60111620ea8c70004]
reusing prepared statement
insert into EMPLOYEE (NAME, DEPT_ID, ID) values (?, ?, ?)
Dehydrating entity: [test.model.Employee#d2a9cb5c11620ea60111620ea8c70004]
binding 'MyName0' to parameter: 1
binding 'd2a9cb5c11620ea60111620ea8b70001' to parameter: 2
binding 'd2a9cb5c11620ea60111620ea8c70004' to parameter: 3
Adding to batch
Executing batch size: 3
done closing: 0 open PreparedStatements, 0 open ResultSets
closing statement
Inserting collection: [test.model.Department.employees#d2a9cb5c11620ea60111620ea8b70001]
about to open: 0 open PreparedStatements, 0 open ResultSets
update EMPLOYEE set DEPT_ID=? where ID=?
preparing statement
binding 'd2a9cb5c11620ea60111620ea8b70001' to parameter: 1
binding 'd2a9cb5c11620ea60111620ea8c70002' to parameter: 2
Adding to batch
reusing prepared statement
update EMPLOYEE set DEPT_ID=? where ID=?
binding 'd2a9cb5c11620ea60111620ea8b70001' to parameter: 1
binding 'd2a9cb5c11620ea60111620ea8c70003' to parameter: 2
Adding to batch
reusing prepared statement
update EMPLOYEE set DEPT_ID=? where ID=?
binding 'd2a9cb5c11620ea60111620ea8b70001' to parameter: 1
binding 'd2a9cb5c11620ea60111620ea8c70004' to parameter: 2
Adding to batch
done inserting collection: 3 rows inserted
Executing batch size: 3
done closing: 0 open PreparedStatements, 0 open ResultSets
closing statement
post flush
transaction completion
closing session
disconnecting session
returning connection to pool, pool size: 1
transaction completion


Thanks

Hi,

Sorry.. I found the answer at http://www.hibernate.org/hib_docs/refer ... child.html

Thanks anyway.