Hi,
I have an issue with fetching a complex object graph back from the database on Hibernate 2.1.8 and Oracle 8i. I'm trying to use HQL using join fetch to retrieve the data, and it's taking an awfully lot of time (around 60 seconds) to retrieve around 3000 records spanning across various one-to-many associations.
On analyzing the logs, I found that hibernate is issuing unnecessary queries for data already available in earlier queries. To replicate the scenario, I've create a simple example case of department-employee-location scenario.
I have the following object graph:
. Department (1 no)
..... Employee (2 nos)
......... Location (5 nos)
The Departmet has 2 employees, and each employee works in 5 locations. I'm using the following HQL to retrieve the structure from database:
Code:
from Department d join fetch d.employees e join fetch e.locations where d.id=:depId
On executing, I found that the following queries are issued by hibernate:
Code:
1. select department0_.ID as ID0_, employees1_.ID as ID1_, locations2_.ID as ID2_, department0_.NAME as NAME0_, employees1_.NAME as NAME1_, employees1_.DEPT_ID as DEPT_ID1_, locations2_.COUNTRY as COUNTRY2_, locations2_.EMP_ID as EMP_ID2_, locations2_.EMP_ID as EMP_ID__, locations2_.ID as ID__ from DEPARTMENT department0_ inner join EMPLOYEE employees1_ on department0_.ID=employees1_.DEPT_ID inner join LOCATION locations2_ on employees1_.ID=locations2_.EMP_ID where (department0_.ID=? )
Code:
2. select employees0_.DEPT_ID as DEPT_ID__, employees0_.ID as ID__, employees0_.ID as ID0_, employees0_.NAME as NAME0_, employees0_.DEPT_ID as DEPT_ID0_ from EMPLOYEE employees0_ where employees0_.DEPT_ID=?
Note that the first query provides all the required details to populate the object graph, and the second query is actually unnecessary. In real-time, when I have complex object graph with numerous one-to-many associations, the number of such queries issued is high, and hence, impacts performance.
Can somebody explain me why the 2nd query is required, and how can I improve my fetch such that one join query retrieves all the required information?
Find below the necessary mapping and other artifcats.
Hibernate version: 2.1.8 Name and version of the database you are using: Oracle 8iMapping documents:
Code:
<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" inverse="true" outer-join="false">
<key column="DEPT_ID" />
<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" />
<set name="locations" table="LOCATION" cascade="all" inverse="true" outer-join="false">
<key column="EMP_ID" />
<one-to-many class="Location" />
</set>
<many-to-one name="department" column="DEPT_ID" not-null="true" />
</class>
<class name="Location" table="LOCATION">
<id name="id" column="ID">
<generator class="uuid.hex" />
</id>
<property name="country" column="COUNTRY" />
<many-to-one name="employee" column="EMP_ID" not-null="true" />
</class>
</hibernate-mapping>
Code between sessionFactory.openSession() and session.close():
Code:
Session session = HibernateUtil.getSession();
String hql = "from Department d join fetch d.employees e join fetch e.locations where d.id=:depId";
List result = session.createQuery(hql).setParameter("depId", departmentId).list();
HashSet resultSet = new HashSet();
resultSet.addAll(result);
Complete Log:
Code:
opened session
find: from Department d join fetch d.employees e join fetch e.locations where d.id=:depId
named parameters: {depId=8a1b0da91169b957011169b959b80001}
compiling query
flushing session
Flushing entities and processing referenced collections
Processing unreferenced collections
Scheduling collection removes/(re)creates/updates
Flushed: 0 insertions, 0 updates, 0 deletions to 0 objects
Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
Dont need to execute flush
HQL: from test.model.Department d join fetch d.employees e join fetch e.locations where d.id=:depId
SQL: select department0_.ID as ID0_, employees1_.ID as ID1_, locations2_.ID as ID2_, department0_.NAME as NAME0_, employees1_.NAME as NAME1_, employees1_.DEPT_ID as DEPT_ID1_, locations2_.COUNTRY as COUNTRY2_, locations2_.EMP_ID as EMP_ID2_, locations2_.EMP_ID as EMP_ID__, locations2_.ID as ID__ from DEPARTMENT department0_ inner join EMPLOYEE employees1_ on department0_.ID=employees1_.DEPT_ID inner join LOCATION locations2_ on employees1_.ID=locations2_.EMP_ID where (department0_.ID=? )
about to open: 0 open PreparedStatements, 0 open ResultSets
total checked-out connections: 0
using pooled JDBC connection, pool size: 0
select department0_.ID as ID0_, employees1_.ID as ID1_, locations2_.ID as ID2_, department0_.NAME as NAME0_, employees1_.NAME as NAME1_, employees1_.DEPT_ID as DEPT_ID1_, locations2_.COUNTRY as COUNTRY2_, locations2_.EMP_ID as EMP_ID2_, locations2_.EMP_ID as EMP_ID__, locations2_.ID as ID__ from DEPARTMENT department0_ inner join EMPLOYEE employees1_ on department0_.ID=employees1_.DEPT_ID inner join LOCATION locations2_ on employees1_.ID=locations2_.EMP_ID where (department0_.ID=? )
preparing statement
binding '8a1b0da91169b957011169b959b80001' to parameter: 1
processing result set
returning '8a1b0da91169b957011169b959b80001' as column: ID0_
returning '8a1b0da91169b957011169b959b80002' as column: ID1_
returning '8a1b0da91169b957011169b959b80003' as column: ID2_
result row: 8a1b0da91169b957011169b959b80001, 8a1b0da91169b957011169b959b80002, 8a1b0da91169b957011169b959b80003
Initializing object from ResultSet: 8a1b0da91169b957011169b959b80001
Hydrating entity: test.model.Department#8a1b0da91169b957011169b959b80001
returning 'ApplicationDevelopment' as column: NAME0_
Initializing object from ResultSet: 8a1b0da91169b957011169b959b80002
Hydrating entity: test.model.Employee#8a1b0da91169b957011169b959b80002
returning 'MyName1' as column: NAME1_
returning '8a1b0da91169b957011169b959b80001' as column: DEPT_ID1_
Initializing object from ResultSet: 8a1b0da91169b957011169b959b80003
Hydrating entity: test.model.Location#8a1b0da91169b957011169b959b80003
returning 'Country2' as column: COUNTRY2_
returning '8a1b0da91169b957011169b959b80002' as column: EMP_ID2_
returning '8a1b0da91169b957011169b959b80002' as column: EMP_ID__
found row of collection: [test.model.Employee.locations#8a1b0da91169b957011169b959b80002]
new collection: instantiating
returning '8a1b0da91169b957011169b959b80003' as column: ID__
loading [test.model.Location#8a1b0da91169b957011169b959b80003]
attempting to resolve [test.model.Location#8a1b0da91169b957011169b959b80003]
resolved object in session cache [test.model.Location#8a1b0da91169b957011169b959b80003]
returning '8a1b0da91169b957011169b959b80001' as column: ID0_
returning '8a1b0da91169b957011169b959b80002' as column: ID1_
returning '8a1b0da91169b957011169b959b80004' as column: ID2_
result row: 8a1b0da91169b957011169b959b80001, 8a1b0da91169b957011169b959b80002, 8a1b0da91169b957011169b959b80004
Initializing object from ResultSet: 8a1b0da91169b957011169b959b80004
Hydrating entity: test.model.Location#8a1b0da91169b957011169b959b80004
returning 'Country3' as column: COUNTRY2_
returning '8a1b0da91169b957011169b959b80002' as column: EMP_ID2_
returning '8a1b0da91169b957011169b959b80002' as column: EMP_ID__
found row of collection: [test.model.Employee.locations#8a1b0da91169b957011169b959b80002]
reading row
returning '8a1b0da91169b957011169b959b80004' as column: ID__
loading [test.model.Location#8a1b0da91169b957011169b959b80004]
attempting to resolve [test.model.Location#8a1b0da91169b957011169b959b80004]
resolved object in session cache [test.model.Location#8a1b0da91169b957011169b959b80004]
returning '8a1b0da91169b957011169b959b80001' as column: ID0_
returning '8a1b0da91169b957011169b959b80002' as column: ID1_
returning '8a1b0da91169b957011169b959b80005' as column: ID2_
result row: 8a1b0da91169b957011169b959b80001, 8a1b0da91169b957011169b959b80002, 8a1b0da91169b957011169b959b80005
Initializing object from ResultSet: 8a1b0da91169b957011169b959b80005
Hydrating entity: test.model.Location#8a1b0da91169b957011169b959b80005
returning 'Country4' as column: COUNTRY2_
returning '8a1b0da91169b957011169b959b80002' as column: EMP_ID2_
returning '8a1b0da91169b957011169b959b80002' as column: EMP_ID__
found row of collection: [test.model.Employee.locations#8a1b0da91169b957011169b959b80002]
reading row
returning '8a1b0da91169b957011169b959b80005' as column: ID__
loading [test.model.Location#8a1b0da91169b957011169b959b80005]
attempting to resolve [test.model.Location#8a1b0da91169b957011169b959b80005]
resolved object in session cache [test.model.Location#8a1b0da91169b957011169b959b80005]
returning '8a1b0da91169b957011169b959b80001' as column: ID0_
returning '8a1b0da91169b957011169b959b80002' as column: ID1_
returning '8a1b0da91169b957011169b959b80006' as column: ID2_
result row: 8a1b0da91169b957011169b959b80001, 8a1b0da91169b957011169b959b80002, 8a1b0da91169b957011169b959b80006
Initializing object from ResultSet: 8a1b0da91169b957011169b959b80006
Hydrating entity: test.model.Location#8a1b0da91169b957011169b959b80006
returning 'Country5' as column: COUNTRY2_
returning '8a1b0da91169b957011169b959b80002' as column: EMP_ID2_
returning '8a1b0da91169b957011169b959b80002' as column: EMP_ID__
found row of collection: [test.model.Employee.locations#8a1b0da91169b957011169b959b80002]
reading row
returning '8a1b0da91169b957011169b959b80006' as column: ID__
loading [test.model.Location#8a1b0da91169b957011169b959b80006]
attempting to resolve [test.model.Location#8a1b0da91169b957011169b959b80006]
resolved object in session cache [test.model.Location#8a1b0da91169b957011169b959b80006]
returning '8a1b0da91169b957011169b959b80001' as column: ID0_
returning '8a1b0da91169b957011169b959b80002' as column: ID1_
returning '8a1b0da91169b957011169b959b80007' as column: ID2_
result row: 8a1b0da91169b957011169b959b80001, 8a1b0da91169b957011169b959b80002, 8a1b0da91169b957011169b959b80007
Initializing object from ResultSet: 8a1b0da91169b957011169b959b80007
Hydrating entity: test.model.Location#8a1b0da91169b957011169b959b80007
returning 'Country1' as column: COUNTRY2_
returning '8a1b0da91169b957011169b959b80002' as column: EMP_ID2_
returning '8a1b0da91169b957011169b959b80002' as column: EMP_ID__
found row of collection: [test.model.Employee.locations#8a1b0da91169b957011169b959b80002]
reading row
returning '8a1b0da91169b957011169b959b80007' as column: ID__
loading [test.model.Location#8a1b0da91169b957011169b959b80007]
attempting to resolve [test.model.Location#8a1b0da91169b957011169b959b80007]
resolved object in session cache [test.model.Location#8a1b0da91169b957011169b959b80007]
returning '8a1b0da91169b957011169b959b80001' as column: ID0_
returning '8a1b0da91169b957011169b959b80008' as column: ID1_
returning '8a1b0da91169b957011169b959b80009' as column: ID2_
result row: 8a1b0da91169b957011169b959b80001, 8a1b0da91169b957011169b959b80008, 8a1b0da91169b957011169b959b80009
Initializing object from ResultSet: 8a1b0da91169b957011169b959b80008
Hydrating entity: test.model.Employee#8a1b0da91169b957011169b959b80008
returning 'MyName2' as column: NAME1_
returning '8a1b0da91169b957011169b959b80001' as column: DEPT_ID1_
Initializing object from ResultSet: 8a1b0da91169b957011169b959b80009
Hydrating entity: test.model.Location#8a1b0da91169b957011169b959b80009
returning 'Country7' as column: COUNTRY2_
returning '8a1b0da91169b957011169b959b80008' as column: EMP_ID2_
returning '8a1b0da91169b957011169b959b80008' as column: EMP_ID__
found row of collection: [test.model.Employee.locations#8a1b0da91169b957011169b959b80008]
new collection: instantiating
returning '8a1b0da91169b957011169b959b80009' as column: ID__
loading [test.model.Location#8a1b0da91169b957011169b959b80009]
attempting to resolve [test.model.Location#8a1b0da91169b957011169b959b80009]
resolved object in session cache [test.model.Location#8a1b0da91169b957011169b959b80009]
returning '8a1b0da91169b957011169b959b80001' as column: ID0_
returning '8a1b0da91169b957011169b959b80008' as column: ID1_
returning '8a1b0da91169b957011169b959b8000a' as column: ID2_
result row: 8a1b0da91169b957011169b959b80001, 8a1b0da91169b957011169b959b80008, 8a1b0da91169b957011169b959b8000a
Initializing object from ResultSet: 8a1b0da91169b957011169b959b8000a
Hydrating entity: test.model.Location#8a1b0da91169b957011169b959b8000a
returning 'Country9' as column: COUNTRY2_
returning '8a1b0da91169b957011169b959b80008' as column: EMP_ID2_
returning '8a1b0da91169b957011169b959b80008' as column: EMP_ID__
found row of collection: [test.model.Employee.locations#8a1b0da91169b957011169b959b80008]
reading row
returning '8a1b0da91169b957011169b959b8000a' as column: ID__
loading [test.model.Location#8a1b0da91169b957011169b959b8000a]
attempting to resolve [test.model.Location#8a1b0da91169b957011169b959b8000a]
resolved object in session cache [test.model.Location#8a1b0da91169b957011169b959b8000a]
returning '8a1b0da91169b957011169b959b80001' as column: ID0_
returning '8a1b0da91169b957011169b959b80008' as column: ID1_
returning '8a1b0da91169b957011169b959b8000b' as column: ID2_
result row: 8a1b0da91169b957011169b959b80001, 8a1b0da91169b957011169b959b80008, 8a1b0da91169b957011169b959b8000b
Initializing object from ResultSet: 8a1b0da91169b957011169b959b8000b
Hydrating entity: test.model.Location#8a1b0da91169b957011169b959b8000b
returning 'Country10' as column: COUNTRY2_
returning '8a1b0da91169b957011169b959b80008' as column: EMP_ID2_
returning '8a1b0da91169b957011169b959b80008' as column: EMP_ID__
found row of collection: [test.model.Employee.locations#8a1b0da91169b957011169b959b80008]
reading row
returning '8a1b0da91169b957011169b959b8000b' as column: ID__
loading [test.model.Location#8a1b0da91169b957011169b959b8000b]
attempting to resolve [test.model.Location#8a1b0da91169b957011169b959b8000b]
resolved object in session cache [test.model.Location#8a1b0da91169b957011169b959b8000b]
returning '8a1b0da91169b957011169b959b80001' as column: ID0_
returning '8a1b0da91169b957011169b959b80008' as column: ID1_
returning '8a1b0da91169b957011169b959b8000c' as column: ID2_
result row: 8a1b0da91169b957011169b959b80001, 8a1b0da91169b957011169b959b80008, 8a1b0da91169b957011169b959b8000c
Initializing object from ResultSet: 8a1b0da91169b957011169b959b8000c
Hydrating entity: test.model.Location#8a1b0da91169b957011169b959b8000c
returning 'Country8' as column: COUNTRY2_
returning '8a1b0da91169b957011169b959b80008' as column: EMP_ID2_
returning '8a1b0da91169b957011169b959b80008' as column: EMP_ID__
found row of collection: [test.model.Employee.locations#8a1b0da91169b957011169b959b80008]
reading row
returning '8a1b0da91169b957011169b959b8000c' as column: ID__
loading [test.model.Location#8a1b0da91169b957011169b959b8000c]
attempting to resolve [test.model.Location#8a1b0da91169b957011169b959b8000c]
resolved object in session cache [test.model.Location#8a1b0da91169b957011169b959b8000c]
returning '8a1b0da91169b957011169b959b80001' as column: ID0_
returning '8a1b0da91169b957011169b959b80008' as column: ID1_
returning '8a1b0da91169b957011169b959b8000d' as column: ID2_
result row: 8a1b0da91169b957011169b959b80001, 8a1b0da91169b957011169b959b80008, 8a1b0da91169b957011169b959b8000d
Initializing object from ResultSet: 8a1b0da91169b957011169b959b8000d
Hydrating entity: test.model.Location#8a1b0da91169b957011169b959b8000d
returning 'Country6' as column: COUNTRY2_
returning '8a1b0da91169b957011169b959b80008' as column: EMP_ID2_
returning '8a1b0da91169b957011169b959b80008' as column: EMP_ID__
found row of collection: [test.model.Employee.locations#8a1b0da91169b957011169b959b80008]
reading row
returning '8a1b0da91169b957011169b959b8000d' as column: ID__
loading [test.model.Location#8a1b0da91169b957011169b959b8000d]
attempting to resolve [test.model.Location#8a1b0da91169b957011169b959b8000d]
resolved object in session cache [test.model.Location#8a1b0da91169b957011169b959b8000d]
done processing result set (10 rows)
done closing: 0 open PreparedStatements, 0 open ResultSets
closing statement
total objects hydrated: 13
resolving associations for [test.model.Department#8a1b0da91169b957011169b959b80001]
creating collection wrapper:[test.model.Department.employees#8a1b0da91169b957011169b959b80001]
done materializing entity [test.model.Department#8a1b0da91169b957011169b959b80001]
resolving associations for [test.model.Employee#8a1b0da91169b957011169b959b80002]
returning loading collection:[test.model.Employee.locations#8a1b0da91169b957011169b959b80002]
loading [test.model.Department#8a1b0da91169b957011169b959b80001]
attempting to resolve [test.model.Department#8a1b0da91169b957011169b959b80001]
resolved object in session cache [test.model.Department#8a1b0da91169b957011169b959b80001]
done materializing entity [test.model.Employee#8a1b0da91169b957011169b959b80002]
resolving associations for [test.model.Location#8a1b0da91169b957011169b959b80003]
loading [test.model.Employee#8a1b0da91169b957011169b959b80002]
attempting to resolve [test.model.Employee#8a1b0da91169b957011169b959b80002]
resolved object in session cache [test.model.Employee#8a1b0da91169b957011169b959b80002]
done materializing entity [test.model.Location#8a1b0da91169b957011169b959b80003]
resolving associations for [test.model.Location#8a1b0da91169b957011169b959b80004]
loading [test.model.Employee#8a1b0da91169b957011169b959b80002]
attempting to resolve [test.model.Employee#8a1b0da91169b957011169b959b80002]
resolved object in session cache [test.model.Employee#8a1b0da91169b957011169b959b80002]
done materializing entity [test.model.Location#8a1b0da91169b957011169b959b80004]
resolving associations for [test.model.Location#8a1b0da91169b957011169b959b80005]
loading [test.model.Employee#8a1b0da91169b957011169b959b80002]
attempting to resolve [test.model.Employee#8a1b0da91169b957011169b959b80002]
resolved object in session cache [test.model.Employee#8a1b0da91169b957011169b959b80002]
done materializing entity [test.model.Location#8a1b0da91169b957011169b959b80005]
resolving associations for [test.model.Location#8a1b0da91169b957011169b959b80006]
loading [test.model.Employee#8a1b0da91169b957011169b959b80002]
attempting to resolve [test.model.Employee#8a1b0da91169b957011169b959b80002]
resolved object in session cache [test.model.Employee#8a1b0da91169b957011169b959b80002]
done materializing entity [test.model.Location#8a1b0da91169b957011169b959b80006]
resolving associations for [test.model.Location#8a1b0da91169b957011169b959b80007]
loading [test.model.Employee#8a1b0da91169b957011169b959b80002]
attempting to resolve [test.model.Employee#8a1b0da91169b957011169b959b80002]
resolved object in session cache [test.model.Employee#8a1b0da91169b957011169b959b80002]
done materializing entity [test.model.Location#8a1b0da91169b957011169b959b80007]
resolving associations for [test.model.Employee#8a1b0da91169b957011169b959b80008]
returning loading collection:[test.model.Employee.locations#8a1b0da91169b957011169b959b80008]
loading [test.model.Department#8a1b0da91169b957011169b959b80001]
attempting to resolve [test.model.Department#8a1b0da91169b957011169b959b80001]
resolved object in session cache [test.model.Department#8a1b0da91169b957011169b959b80001]
done materializing entity [test.model.Employee#8a1b0da91169b957011169b959b80008]
resolving associations for [test.model.Location#8a1b0da91169b957011169b959b80009]
loading [test.model.Employee#8a1b0da91169b957011169b959b80008]
attempting to resolve [test.model.Employee#8a1b0da91169b957011169b959b80008]
resolved object in session cache [test.model.Employee#8a1b0da91169b957011169b959b80008]
done materializing entity [test.model.Location#8a1b0da91169b957011169b959b80009]
resolving associations for [test.model.Location#8a1b0da91169b957011169b959b8000a]
loading [test.model.Employee#8a1b0da91169b957011169b959b80008]
attempting to resolve [test.model.Employee#8a1b0da91169b957011169b959b80008]
resolved object in session cache [test.model.Employee#8a1b0da91169b957011169b959b80008]
done materializing entity [test.model.Location#8a1b0da91169b957011169b959b8000a]
resolving associations for [test.model.Location#8a1b0da91169b957011169b959b8000b]
loading [test.model.Employee#8a1b0da91169b957011169b959b80008]
attempting to resolve [test.model.Employee#8a1b0da91169b957011169b959b80008]
resolved object in session cache [test.model.Employee#8a1b0da91169b957011169b959b80008]
done materializing entity [test.model.Location#8a1b0da91169b957011169b959b8000b]
resolving associations for [test.model.Location#8a1b0da91169b957011169b959b8000c]
loading [test.model.Employee#8a1b0da91169b957011169b959b80008]
attempting to resolve [test.model.Employee#8a1b0da91169b957011169b959b80008]
resolved object in session cache [test.model.Employee#8a1b0da91169b957011169b959b80008]
done materializing entity [test.model.Location#8a1b0da91169b957011169b959b8000c]
resolving associations for [test.model.Location#8a1b0da91169b957011169b959b8000d]
loading [test.model.Employee#8a1b0da91169b957011169b959b80008]
attempting to resolve [test.model.Employee#8a1b0da91169b957011169b959b80008]
resolved object in session cache [test.model.Employee#8a1b0da91169b957011169b959b80008]
done materializing entity [test.model.Location#8a1b0da91169b957011169b959b8000d]
2 collections were found in result set
collection fully initialized: [test.model.Employee.locations#8a1b0da91169b957011169b959b80008]
collection fully initialized: [test.model.Employee.locations#8a1b0da91169b957011169b959b80002]
2 collections initialized
initializing non-lazy collections
initializing collection [test.model.Department.employees#8a1b0da91169b957011169b959b80001]
checking second-level cache
collection not cached
about to open: 0 open PreparedStatements, 0 open ResultSets
select employees0_.DEPT_ID as DEPT_ID__, employees0_.ID as ID__, employees0_.ID as ID0_, employees0_.NAME as NAME0_, employees0_.DEPT_ID as DEPT_ID0_ from EMPLOYEE employees0_ where employees0_.DEPT_ID=?
preparing statement
binding '8a1b0da91169b957011169b959b80001' to parameter: 1
result set contains (possibly empty) collection: [test.model.Department.employees#8a1b0da91169b957011169b959b80001]
uninitialized collection: initializing
processing result set
returning '8a1b0da91169b957011169b959b80002' as column: ID0_
result row: 8a1b0da91169b957011169b959b80002
returning '8a1b0da91169b957011169b959b80001' as column: DEPT_ID__
found row of collection: [test.model.Department.employees#8a1b0da91169b957011169b959b80001]
reading row
returning '8a1b0da91169b957011169b959b80002' as column: ID__
loading [test.model.Employee#8a1b0da91169b957011169b959b80002]
attempting to resolve [test.model.Employee#8a1b0da91169b957011169b959b80002]
resolved object in session cache [test.model.Employee#8a1b0da91169b957011169b959b80002]
returning '8a1b0da91169b957011169b959b80008' as column: ID0_
result row: 8a1b0da91169b957011169b959b80008
returning '8a1b0da91169b957011169b959b80001' as column: DEPT_ID__
found row of collection: [test.model.Department.employees#8a1b0da91169b957011169b959b80001]
reading row
returning '8a1b0da91169b957011169b959b80008' as column: ID__
loading [test.model.Employee#8a1b0da91169b957011169b959b80008]
attempting to resolve [test.model.Employee#8a1b0da91169b957011169b959b80008]
resolved object in session cache [test.model.Employee#8a1b0da91169b957011169b959b80008]
done processing result set (2 rows)
done closing: 0 open PreparedStatements, 0 open ResultSets
closing statement
total objects hydrated: 0
1 collections were found in result set
collection fully initialized: [test.model.Department.employees#8a1b0da91169b957011169b959b80001]
1 collections initialized
collection initialized
Data Retrieved
closing session
disconnecting session
returning connection to pool, pool size: 1
transaction completion