Hibernate version:
H3.2.5ga
Mapping documents:
below ...
Code between sessionFactory.openSession() and session.close():
below ...
Full stack trace of any exception that occurs:
no exceptions, but relevant part is posted below ...
Name and version of the database you are using:
Derby 10.2.2 (I also got the same issue on Postgres (8.2.3))
The generated SQL (show_sql=true):
Hibernate: select enrollment0_.ENROL_ID as ENROL1_4_, enrollment0_.VER as VER4_, enrollment0_.status as status4_, enrollment0_.persistDate as persistD4_4_, enrollment0_.enrollmentDate as enrollme5_4_, enrollment0_.isOpen as isOpen4_, enrollment0_.isPassed as isPassed4_, enrollment0_.grade as grade4_, enrollment0_.costCentre as costCentre4_, enrollment0_.notes as notes4_, enrollment0_.studentId as studentId4_, enrollment0_.courseId as courseId4_, enrollment0_.awardId as awardId4_, enrollment0_.PERSON_ID as PERSON14_4_, enrollment0_.COURSE_ID as COURSE15_4_ from Enrollment enrollment0_
Debug level Hibernate log excerpt:
TRACE level log excerpt below ...
My Problem ...
Hello,
I am looking for any advice, but specifically any techniques to get more information from Hibernate as to what it has done during its operation.
This is my second Hibernate project, so I already have some experience of getting it all working reasonably well. I am NOT an expert - but I would claim to be basically competent. I have set the debug level to TRACE, but unfortunately that reveals no extra clues. I have tried this on both Apache-Derby and Postgres with the same result - so I conclude it is not a DB issue.
The weird problem is that a retrieval (mydao.findAll()) fails without Hibernate indicating that there is a failure - it just "dies" and silently skips straight to the "finally" clause. From the logs I can see that all the rows (12 rows) and fields seem to be retrieved OK - but the next thing I know is that the code is running the "finally" section without finishing the try block - or giving any error.
The "domain" is an educational status tracker, so there are domain classes such as ENROLLMENT that link to PERSON (aka student) and COURSE etc.
The really weird thing is that I can work around the problem by NOT using the rich Hibernate links directly to objects, but only to their IDs and manually retrieving the linked objects. So instead of having ..
Code:
private Person student;
private Course course;
but instead have
Code:
private long studentId;
private long courseId;
then I can get it all to work perfectly - however that obviously means we miss out on the rich natural Hibernate access to the linked objects.
Below I have provided the code from
(1) the DAO object (that makes the Hibernate calls)
(2) from the application code (that calls the DAO code)
(3) the logging set to "TRACE"
(4) EnrollmentImpl mapping doc
(5) PersonImpl mapping doc
(6) CourseImpl mapping doc
Any suggestions are greatly appreciated.
Many thanks
-Damian
DAO code snip ... Code:
public List<Enrollment> findAll() throws InfrastructureException {
Collection c;
try {
logger.debug("EnrollmentDAOImpl.findAll(): START");
Query query = EmsHibUtils.getSession().createQuery("from EnrollmentImpl");
logger.debug("EnrollmentDAOImpl.findAll(): 2");
c = query.list(); // <========== DIES IN HERE
logger.debug("EnrollmentDAOImpl.findAll(): 3"); // this line NEVER run
List<Enrollment> enrollments = new ArrayList<Enrollment>();
for (Object o : c) {
if (o instanceof Enrollment) {
Enrollment e = (Enrollment)o;
enrollments.add(e);
}
}
return enrollments;
} catch (HibernateException ex) {
throw new InfrastructureException(ex); // this line NEVER run
}
}
From the application code calling the DAO ...This dodgy code (developed for development testing purposes only) is just counting how many EnrollmentImpl rows are present in the table. There are 12 rows, and (according to the logs) it seems to find them all, but it "dies" in the findAll() call and silently jumps to finally.
Code:
private int enrolCount() {
logger.debug("ImportUtils.enrolCount(): START");
EnrollmentDAO dao = new EnrollmentDAOImpl();
int count = -3;
try {
logger.debug("ImportUtils.enrolCount(): 1 ");
List<Enrollment> enrollments = dao.findAll(); //<=== DIES IN HERE !!!!!!
logger.debug("ImportUtils.enrolCount(): 2 ");// <This line is NEVER run
if (enrollments == null) {logger.debug("ImportAndTest.enrolCount():");}
else count = enrollments.size();
} catch (InfrastructureException ie) {
logger.error("ImportAndTest.enrolCount(): InfEx=" + ie.getMessage() + "<");
count=-1;
} catch (Exception ex) {
logger.error("ImportAndTest.enrolCount(): Ex=" + ex.getMessage());
count=-2;
} finally {
logger.debug("ImportUtils.enrolCount(): 3 finally ");// <== comes here !!!
EmsHibUtils.closeSession();
dao = null;
}
logger.debug("ImportUtils.enrolCount(): END");
return count;
}
FROM THE LOG (set to TRACE) ... Obviously thousands of lines of TRACE logging, but this is the end. You can see the field being loaded for the final "EnrollmentImpl" ...
Code:
87250 [pool-1-thread-1][TRACE]AbstractEntityPersister: Hydrating entity: [com.careymacek.ems.api.domain.impl.EnrollmentImpl#12]
87250 [pool-1-thread-1][TRACE]NullableType: returning '0' as column: VER4_
87250 [pool-1-thread-1][TRACE]NullableType: returning 'ENROLLED' as column: status4_
87250 [pool-1-thread-1][TRACE]NullableType: returning '2007-08-06 14:54:29' as column: persistD4_4_
87250 [pool-1-thread-1][TRACE]NullableType: returning '2008-02-22 14:54:29' as column: enrollme5_4_
87250 [pool-1-thread-1][TRACE]NullableType: returning 'true' as column: isOpen4_
87250 [pool-1-thread-1][TRACE]NullableType: returning 'false' as column: isPassed4_
87250 [pool-1-thread-1][TRACE]NullableType: returning null as column: grade4_
87250 [pool-1-thread-1][TRACE]NullableType: returning null as column: costCentre4_
87250 [pool-1-thread-1][TRACE]NullableType: returning null as column: notes4_
87250 [pool-1-thread-1][TRACE]NullableType: returning '6' as column: studentId4_
87250 [pool-1-thread-1][TRACE]NullableType: returning '4' as column: courseId4_
87250 [pool-1-thread-1][TRACE]NullableType: returning '0' as column: awardId4_
87250 [pool-1-thread-1][TRACE]NullableType: returning '6' as column: PERSON14_4_
87250 [pool-1-thread-1][TRACE]NullableType: returning '4' as column: COURSE15_4_
87266 [pool-1-thread-1][TRACE]TwoPhaseLoad: Version: 0
87266 [pool-1-thread-1][TRACE]Loader: done processing result set (12 rows)
87266 [pool-1-thread-1][DEBUG]AbstractBatcher: about to close ResultSet (open ResultSets: 1, globally: 1)
87266 [pool-1-thread-1][DEBUG]AbstractBatcher: about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
87266 [pool-1-thread-1][TRACE]AbstractBatcher: closing statement
87266 [pool-1-thread-1][TRACE]Loader: total objects hydrated: 12
87266 [pool-1-thread-1][DEBUG]TwoPhaseLoad: resolving associations for [com.careymacek.ems.api.domain.impl.EnrollmentImpl#1]
87266 [pool-1-thread-1][TRACE]DefaultLoadEventListener: loading entity: [com.careymacek.ems.api.domain.impl.PersonImpl#2]
87266 [pool-1-thread-1][TRACE]DefaultLoadEventListener: creating new proxy for entity
87266 [pool-1-thread-1][TRACE]JDBCContext: after autocommit
87266 [pool-1-thread-1][DEBUG]ConnectionManager: aggressively releasing JDBC connection
87266 [pool-1-thread-1][DEBUG]ConnectionManager: releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
87266 [pool-1-thread-1][DEBUG]ImportAndTest: ImportUtils.enrolCount(): 3 finally
87281 [pool-1-thread-1][TRACE]SessionImpl: closing session
87281 [pool-1-thread-1][TRACE]ConnectionManager: connection already null in cleanup : no action
EnrollmentImpl mapping doc ...
Code:
<?xml version="1.0"?>
<!DOCTYPE hibernate-mapping PUBLIC "-//Hibernate/Hibernate Mapping DTD 3.0//EN"
"http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd">
<hibernate-mapping>
<class name="com.careymacek.ems.api.domain.impl.EnrollmentImpl"
table="Enrollment">
<meta attribute="class-description">
@author Damian
</meta>
<id name="id" type="long" column="ENROL_ID">
<generator class="identity"/>
</id>
<version
name="version"
column="VER"/>
<property
name="statusString"
type="string"
length="32"
column="status"
access="field"
/>
<property
name="recordingDate"
type="timestamp"
column="persistDate"
/>
<property
name="enrollmentDate"
type="timestamp"
column="enrollmentDate"
/>
<!--
<property
name="isWithdrawn"
type="boolean"
column="isWithdrawn"
/>
-->
<property
name="isOpen"
type="boolean"
column="isOpen"
/>
<property
name="isPassed"
type="boolean"
column="isPassed"
/>
<property
name="grade"
type="string"
column="grade"
length="100"
/>
<property
name="costCentre"
type="string"
column="costCentre"
length="50"
/>
<property
name="notes"
type="string"
column="notes"
length="32672"
/>
<property
name="studentId"
type="long"
column="studentId"
/>
<property
name="courseId"
type="long"
column="courseId"
/>
<property
name="awardId"
type="long"
column="awardId"
/>
<!--
<many-to-one
name="award"
column="AWARD_ID"
class="com.careymacek.ems.impl.domain.AwardImpl"
not-null="false"
/>
-->
<!-- -->
<many-to-one
name="student"
column="PERSON_ID"
class="com.careymacek.ems.api.domain.impl.PersonImpl"
not-null="false"
/>
<!-- -->
<!--
<many-to-one
name="course"
column="COURSE_ID"
class="com.careymacek.ems.impl.domain.CourseImpl"
not-null="false"
/>
-->
<!-- -->
<many-to-one
name="course"
column="COURSE_ID"
class="com.careymacek.ems.api.domain.impl.CourseImpl"
not-null="false"
/>
<!-- -->
</class>
</hibernate-mapping>
PersonImpl mapping doc
Code:
<?xml version="1.0"?>
<!DOCTYPE hibernate-mapping PUBLIC "-//Hibernate/Hibernate Mapping DTD 3.0//EN"
"http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd">
<hibernate-mapping>
<class name="com.careymacek.ems.api.domain.impl.PersonImpl"
table="Person">
<meta attribute="class-description">
@author Damian
</meta>
<id name="id" type="long" column="PERSON_ID">
<generator class="identity"/>
</id>
<version
name="version"
column="VER"/>
<property name="isActive" type="boolean">
<column name="isActive"/>
</property>
<property name="isEmsAdmin" type="boolean">
<column name="isEmsAdmin"/>
</property>
<property name="isEmsUser" type="boolean">
<column name="isEmsUser"/>
</property>
<property name="isTeacher" type="boolean">
<column name="isTeacher"/>
</property>
<property name="isStudent" type="boolean">
<column name="isStudent"/>
</property>
<property name="isGroupMgr" type="boolean">
<column name="isGroupMgr"/>
</property>
<property name="isOther" type="boolean">
<column name="isOther"/>
</property>
<property name="honorific" type="string">
<column name="honorific" length="16"/>
</property>
<property name="firstName" type="string">
<column name="firstName" length="100"/>
</property>
<property name="lastName" type="string">
<column name="lastName" length="50"/>
</property>
<property name="idNumber" type="string">
<column name="idNumber" length="100"/>
</property>
<property name="prefEmail" type="string">
<column name="prefEmail" length="100"/>
</property>
<property name="altEmail" type="string">
<column name="altEmail" length="100"/>
</property>
<property name="address" type="string">
<column name="address" length="100"/>
</property>
<property name="city" type="string">
<column name="city" length="50"/>
</property>
<property name="country" type="string">
<column name="country" length="50"/>
</property>
<property name="phone1" type="string">
<column name="phone1" length="50"/>
</property>
<property name="phone2" type="string">
<column name="phone2" length="50"/>
</property>
<property name="phone3" type="string">
<column name="phone3" length="50"/>
</property>
<property name="description" type="string">
<column name="description" length="1000"/>
</property>
<property name="emsUserName" type="string">
<column name="emsUserName" length="50"/>
</property>
<property name="emsPwd" type="string">
<column name="emsPwd" length="100"/>
</property>
<property name="extra" type="string">
<column name="extra" length="32672"/>
</property>
<!--
<set name="transcript" inverse="true">
<key column="PERSON_ID"/>
<one-to-many class="com.careymacek.ems.impl.domain.AwardImpl"/>
</set>
-->
<set name="enrollments" inverse="true">
<key column="PERSON_ID"/>
<one-to-many class="com.careymacek.ems.api.domain.impl.EnrollmentImpl"/>
</set>
<property name="groupId" type="long">
<column name="groupId"/>
</property>
</class>
</hibernate-mapping>
CourseImpl mapping doc ...
Code:
<?xml version="1.0"?>
<!DOCTYPE hibernate-mapping PUBLIC "-//Hibernate/Hibernate Mapping DTD 3.0//EN"
"http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd">
<hibernate-mapping>
<class name="com.careymacek.ems.api.domain.impl.CourseImpl"
table="Course">
<meta attribute="class-description">
@author Damian
</meta>
<id name="id" type="long" column="COURSE_ID">
<generator class="identity"/>
</id>
<version
name="version"
column="VER"
/>
<property
name="shortName"
type="string"
column="shortName"
length="100"
/>
<property
name="fullName"
type="string"
column="fullName"
length="250"
/>
<property
name="summary"
type="string"
column="summary"
length="1000"
/>
<property
name="courseRefId"
type="string"
column="courseRefId"
length="50"
/>
<property
name="nominalDuration"
type="float"
column="nomDur"
/>
<property
name="nominalTeacherTime"
type="float"
column="nomTeacherTime"
/>
<property
name="qualString"
type="string"
column="qualString"
length="250"
/>
<property
name="isMandatory"
type="boolean"
column="isMandatory"
/>
<property
name="courseCategory"
type="string"
column="courseCategory"
length="50"
/>
<property
name="isTemplate"
type="boolean"
column="isTemplate"
/>
<property
name="startDate"
type="date"
column="startDate"
/>
<property
name="finishDate"
type="date"
column="finishDate"
/>
<property
name="courseLocation"
type="string"
column="courseLocation"
length="100"
/>
<property
name="notes"
type="string"
column="notes"
length="30000"
/>
<property
name="qualId"
type="long"
column="qualId"
/>
<!-- Award - Unidirectional "-to-one" -->
<!-- An Award may be linked to by many Courses -->
<!-- -->
<many-to-one
name="qualification"
column="qual"
class="com.careymacek.ems.api.domain.impl.AwardImpl"
not-null="false"
/>
<!-- -->
<!--
<join table="COURSE_QUAL" optional="true">
<key column="COURSE_ID"/>
<many-to-one
name="qualification"
column="qual"
class="com.careymacek.ems.impl.domain.AwardImpl"
not-null="true"
unique="true"
/>
</join>
-->
<!-- Person - Unidirectional "-to-one" -->
<!-- An EmsMgr (Person) may be linked to by many Courses -->
<!--
<many-to-one
name="emsMgr"
column="emsMgr"
class="com.careymacek.ems.impl.domain.PersonImpl"
not-null="false"
/>
-->
<!-- Person - Unidirectional "many-to-many" -->
<!-- A Teacher (Person) may be linked to by many Courses -->
<set name="teachers" table="CourseTeachers">
<key column="COURSE_ID"/>
<many-to-many column="PERSON_ID"
class="com.careymacek.ems.api.domain.impl.PersonImpl"/>
</set>
<!-- -->
<set name="enrollments" inverse="true">
<key column="COURSE_ID"/>
<one-to-many class="com.careymacek.ems.api.domain.impl.EnrollmentImpl"/>
</set>
<!-- -->
</class>
</hibernate-mapping>