Ok, before moving on to posting mountains of logs, I believe I've determined
at least one of my problems. As I suspected, I was misunderstanding
something.
There were two different situations where I was encountering the issue
where subordinate objects weren't being eager loaded with "outer-join" being
set to true.
1) The first situation was when I was using Session .find() to load a list of
Assessment objects. Each Assessment object contains a Language object
that is mapped as a many-to-one relationship. The Language objects weren't
being loaded for the Assessments that were being returned in the list.
2) In order to simplify the log files that I was about to report to Steve, I switch
my example so that it would only return a single Assessment object that was
being retrieved with the Session.load() method. What I didn't realize was that
that load() method doesn't actually load the object from the database; it just
loads a proxy! Obviously, the log file I generated and reported in the above
posts would return a Hibernate Exception when it tried to initialize any part of
the Assessment object. So my example log in the above post is basically
useless and it represents a misunderstanding on my part and not an actual
problem.
There's good news.
When I use the load() method to retrieve an Assessment object and then
immediately intialize the object before closing the session, everything works
exactly as one would expect. The Language object is properly intialized. Yay!
That still leaves me with problem #1 as described above. When I load a List
of Assessment objects with the find() method, the subordinate Language
objects are not being properly intialized.
Here's is the entire log for when I pull a list of assessments from the database:
Code:
Oct 11, 2003 4:05:50 PM com.cadtrain.coachlms.app.util.DAOFactory getDAO
INFO: AssessmentDAO.getDAO() entering method
Oct 11, 2003 4:05:50 PM com.cadtrain.coachlms.app.util.DAOFactory getDAO
INFO: DAOFactory.getDAO(): dao=com.cadtrain.coachlms.app.dao.assessment.AssessmentHibernateDAO
Oct 11, 2003 4:05:50 PM com.cadtrain.coachlms.app.util.HibernateSession currentSession
INFO: Opening new Hibernate Session
Oct 11, 2003 4:05:50 PM com.cadtrain.coachlms.app.util.HibernateSession getSessionFactory
INFO: Creating Hibernate Session Factory
16:05:51,445 INFO Environment:403 - Hibernate 2.0.3
16:05:51,459 INFO Environment:432 - hibernate.properties not found
16:05:51,467 INFO Environment:452 - using CGLIB reflection optimizer
16:05:51,470 INFO Environment:462 - JVM proxy support: true
16:05:51,480 INFO Configuration:703 - Configuration resource: /hibernate.cfg.xml
16:05:51,874 DEBUG Configuration:689 - connection.driver_class=org.gjt.mm.mysql.Driver
16:05:51,878 DEBUG Configuration:689 - connection.url=jdbc:mysql://127.0.0.1/coachlms?autoReconnect=true
16:05:51,881 DEBUG Configuration:689 - connection.username=*******
16:05:51,882 DEBUG Configuration:689 - connection.password=*******
16:05:51,885 DEBUG Configuration:689 - show_sql=true
16:05:51,886 DEBUG Configuration:689 - dialect=net.sf.hibernate.dialect.MySQLDialect
16:05:51,887 DEBUG Configuration:689 - use_outer_join=true
16:05:51,890 DEBUG Configuration:689 - c3p0.max_size=10
16:05:51,892 DEBUG Configuration:689 - c3p0.min_size=2
16:05:51,894 DEBUG Configuration:689 - c3p0.timeout=600
16:05:51,896 DEBUG Configuration:689 - c3p0.validate=true
16:05:51,897 DEBUG Configuration:689 - c3p0.max_statements=100
16:05:51,914 DEBUG Configuration:836 - null<-org.dom4j.tree.DefaultAttribute@1aefd7b [Attribute: name resource value "com/cadtrain/coachlms/common/dataobject/AssessmentDO.hbm.xml"]
16:05:51,917 INFO Configuration:270 - Mapping resource: com/cadtrain/coachlms/common/dataobject/AssessmentDO.hbm.xml
16:05:52,460 INFO Binder:178 - Mapping class: com.cadtrain.coachlms.common.dataobject.AssessmentDO -> assessments
16:05:52,722 DEBUG Binder:394 - Mapped property: assessmentID -> assessmentID, type: long
16:05:52,775 DEBUG Binder:394 - Mapped property: name -> name, type: string
16:05:52,778 DEBUG Binder:394 - Mapped property: description -> description, type: string
16:05:52,784 INFO Binder:456 - Mapping collection: com.cadtrain.coachlms.common.dataobject.AssessmentDO.questionGroups -> assessment_questiongroup
16:05:52,817 DEBUG Binder:394 - Mapped property: questionGroups, type: java.util.List
16:05:52,853 DEBUG Binder:394 - Mapped property: providerDO -> provider_id, type: com.cadtrain.scout.common.dataobject.ProviderDO
16:05:52,862 DEBUG Binder:394 - Mapped property: topicDO -> topic_id, type: com.cadtrain.coachlms.common.dataobject.TopicDO
16:05:52,867 DEBUG Binder:394 - Mapped property: languageDO -> language_code, type: com.cadtrain.scout.common.dataobject.LanguageDO
16:05:52,869 DEBUG Configuration:836 - null<-org.dom4j.tree.DefaultAttribute@174f6ce [Attribute: name resource value "com/cadtrain/coachlms/common/dataobject/QuestionGroupDO.hbm.xml"]
16:05:52,884 INFO Configuration:270 - Mapping resource: com/cadtrain/coachlms/common/dataobject/QuestionGroupDO.hbm.xml
16:05:53,248 INFO Binder:178 - Mapping class: com.cadtrain.coachlms.common.dataobject.QuestionGroupDO -> question_groups
16:05:53,251 DEBUG Binder:394 - Mapped property: questionGroupID -> questionGroupID, type: long
16:05:53,253 DEBUG Binder:394 - Mapped property: title -> title, type: string
16:05:53,255 DEBUG Binder:394 - Mapped property: description -> description, type: string
16:05:53,257 DEBUG Binder:394 - Mapped property: providerDO -> provider_id, type: com.cadtrain.scout.common.dataobject.ProviderDO
16:05:53,260 DEBUG Binder:394 - Mapped property: topicDO -> topic_id, type: com.cadtrain.coachlms.common.dataobject.TopicDO
16:05:53,262 DEBUG Binder:394 - Mapped property: languageDO -> language_code, type: com.cadtrain.scout.common.dataobject.LanguageDO
16:05:53,263 DEBUG Configuration:836 - null<-org.dom4j.tree.DefaultAttribute@1e1c66a [Attribute: name resource value "com/cadtrain/scout/common/dataobject/ProviderDO.hbm.xml"]
16:05:53,266 INFO Configuration:270 - Mapping resource: com/cadtrain/scout/common/dataobject/ProviderDO.hbm.xml
16:05:53,608 INFO Binder:178 - Mapping class: com.cadtrain.scout.common.dataobject.ProviderDO -> providers
16:05:53,610 DEBUG Binder:394 - Mapped property: provider_id -> provider_id, type: integer
16:05:53,613 DEBUG Binder:394 - Mapped property: providerCode -> provider_code, type: string
16:05:53,615 DEBUG Binder:394 - Mapped property: providerName -> provider_name, type: string
16:05:53,617 DEBUG Configuration:836 - null<-org.dom4j.tree.DefaultAttribute@1a95a1d [Attribute: name resource value "com/cadtrain/scout/common/dataobject/LanguageDO.hbm.xml"]
16:05:53,618 INFO Configuration:270 - Mapping resource: com/cadtrain/scout/common/dataobject/LanguageDO.hbm.xml
16:05:53,936 INFO Binder:178 - Mapping class: com.cadtrain.scout.common.dataobject.LanguageDO -> iso639languages
16:05:53,941 DEBUG Binder:394 - Mapped property: languageCode -> language_code, type: string
16:05:53,946 DEBUG Binder:394 - Mapped property: languageName -> language_name, type: string
16:05:53,948 DEBUG Binder:394 - Mapped property: available -> available, type: boolean
16:05:53,949 DEBUG Configuration:836 - null<-org.dom4j.tree.DefaultAttribute@15b2cec [Attribute: name resource value "com/cadtrain/coachlms/common/dataobject/TopicDO.hbm.xml"]
16:05:53,952 INFO Configuration:270 - Mapping resource: com/cadtrain/coachlms/common/dataobject/TopicDO.hbm.xml
16:05:54,276 INFO Binder:178 - Mapping class: com.cadtrain.coachlms.common.dataobject.TopicDO -> software
16:05:54,278 DEBUG Binder:394 - Mapped property: topicID -> softver_id, type: long
16:05:54,280 DEBUG Binder:394 - Mapped property: title -> title, type: string
16:05:54,281 DEBUG Binder:394 - Mapped property: version -> version, type: string
16:05:54,282 DEBUG Binder:394 - Mapped property: directory -> directory, type: string
16:05:54,284 DEBUG Binder:394 - Mapped property: active -> active, type: boolean
16:05:54,286 DEBUG Binder:394 - Mapped property: ordinal -> ordinal, type: integer
16:05:54,287 DEBUG Binder:394 - Mapped property: providerID -> provider_id, type: integer
16:05:54,288 INFO Configuration:885 - Configured SessionFactory: null
16:05:54,290 DEBUG Configuration:886 - properties: {java.vendor=Sun Microsystems Inc., show_sql=true, catalina.base=/usr/coachlms/clms2/tomcat, c3p0.min_size=2, hibernate.connection.url=jdbc:mysql://127.0.0.1/coachlms?autoReconnect=true , catalina.useNaming=true, os.name=Linux, sun.boot.class.path=/usr/coachlms/clms2/tomcat/bin/bootstrap.jar:/usr/coachlms/clms2/tomcat/bin/commons-daemon.jar:/usr/coachlms/clms2/tomcat/bin/tomcat-jni.jar:/usr/coachlms/clms2/tomcat/common/endorsed/xml-apis.jar:/usr/coachlms/clms2/tomcat/common/endorsed/xercesImpl-2.0.0.jar:/usr/coachlms/clms2/tomcat/common/endorsed/xalan-2.3.1.jar:/usr/java/j2sdk1.4.2_01/jre/lib/rt.jar:/usr/java/j2sdk1.4.2_01/jre/lib/i18n.jar:/usr/java/j2sdk1.4.2_01/jre/lib/sunrsasign.jar:/usr/java/j2sdk1.4.2_01/jre/lib/jsse.jar:/usr/java/j2sdk1.4.2_01/jre/lib/jce.jar:/usr/java/j2sdk1.4.2_01/jre/lib/charsets.jar:/usr/java/j2sdk1.4.2_01/jre/classes, hibernate.c3p0.max_size=10, sun.java2d.fontpath=, java.vm.specification.vendor=Sun Microsystems Inc., c3p0.max_size=10, java.runtime.version=1.4.2_01-b06, hibernate.c3p0.min_size=2, user.name=mwelch, connection.driver_class=org.gjt.mm.mysql.Driver, hibernate.c3p0.timeout=600, user.language=en, java.naming.factory.initial=org.apache.naming.java.javaURLContextFactory, sun.boot.library.path=/usr/java/j2sdk1.4.2_01/jre/lib/i386, dialect=net.sf.hibernate.dialect.MySQLDialect, java.version=1.4.2_01, c3p0.validate=true, version=2.3.1, user.timezone=America/Mexico_City, sun.arch.data.model=32, hibernate.use_outer_join=true, java.endorsed.dirs=/usr/coachlms/clms2/tomcat/bin:/usr/coachlms/clms2/tomcat/common/endorsed, sun.cpu.isalist=, file.encoding.pkg=sun.io, file.separator=/, java.specification.name=Java Platform API Specification, hibernate.cglib.use_reflection_optimizer=true, java.class.version=48.0, user.country=US, connection.url=jdbc:mysql://127.0.0.1/coachlms?autoReconnect=true , java.home=/usr/java/j2sdk1.4.2_01/jre, java.vm.info=mixed mode, hibernate.c3p0.validate=true, os.version=2.4.20-18.9, path.separator=:, connection.password=coachapp, java.vm.version=1.4.2_01-b06, java.util.prefs.PreferencesFactory=java.util.prefs.FileSystemPreferencesFactory, hibernate.connection.password=coachapp, vendor-url=http://xml.apache.org/xalan-j, java.protocol.handler.pkgs=com.sun.net.ssl.internal.www.protocol, java.awt.printerjob=sun.print.PSPrinterJob, vendor=Apache Software Foundation, sun.io.unicode.encoding=UnicodeLittle, hibernate.connection.username=coachapp, java.naming.factory.url.pkgs=org.apache.naming, user.home=/home/mwelch, java.specification.vendor=Sun Microsystems Inc., org.xml.sax.driver=org.apache.xerces.parsers.SAXParser, java.library.path=/usr/java/j2sdk1.4.2_01/jre/lib/i386/client:/usr/java/j2sdk1.4.2_01/jre/lib/i386:/usr/java/j2sdk1.4.2_01/jre/../lib/i386, java.vendor.url=http://java.sun.com/, hibernate.connection.driver_class=org.gjt.mm.mysql.Driver, connection.username=coachapp, java.vm.vendor=Sun Microsystems Inc., hibernate.dialect=net.sf.hibernate.dialect.MySQLDialect, java.runtime.name=Java(TM) 2 Runtime Environment, Standard Edition, java.class.path=/usr/coachlms/clms2/j2sdk1.4.2_01/lib/tools.jar:/usr/coachlms/clms2/tomcat/bin/bootstrap.jar, use_outer_join=true, c3p0.timeout=600, java.vm.specification.name=Java Virtual Machine Specification, java.vm.specification.version=1.0, catalina.home=/usr/coachlms/clms2/tomcat, sun.cpu.endian=little, sun.os.patch.level=unknown, java.io.tmpdir=/usr/coachlms/clms2/tomcat/temp, java.vendor.url.bug=http://java.sun.com/cgi-bin/bugreport.cgi, os.arch=i386, java.awt.graphicsenv=sun.awt.X11GraphicsEnvironment, java.ext.dirs=/usr/java/j2sdk1.4.2_01/jre/lib/ext, user.dir=/home/mwelch, line.separator=
, java.vm.name=Java HotSpot(TM) Client VM, file.encoding=UTF-8, java.specification.version=1.4, c3p0.max_statements=100, hibernate.c3p0.max_statements=100, hibernate.show_sql=true}
16:05:54,291 INFO Configuration:492 - processing one-to-many association mappings
16:05:54,292 DEBUG Binder:1134 - Second pass for collection: com.cadtrain.coachlms.common.dataobject.AssessmentDO.questionGroups
16:05:54,296 DEBUG Binder:1146 - Mapped collection key: assessmentID, index: ordinal, element: questionGroupID, type: com.cadtrain.coachlms.common.dataobject.QuestionGroupDO
16:05:54,298 INFO Configuration:503 - processing foreign key constraints
16:05:54,299 DEBUG Configuration:513 - resolving reference to class: com.cadtrain.scout.common.dataobject.ProviderDO
16:05:54,300 DEBUG Configuration:513 - resolving reference to class: com.cadtrain.scout.common.dataobject.LanguageDO
16:05:54,301 DEBUG Configuration:513 - resolving reference to class: com.cadtrain.coachlms.common.dataobject.TopicDO
16:05:54,302 DEBUG Configuration:513 - resolving reference to class: com.cadtrain.coachlms.common.dataobject.AssessmentDO
16:05:54,303 DEBUG Configuration:513 - resolving reference to class: com.cadtrain.coachlms.common.dataobject.QuestionGroupDO
16:05:54,314 DEBUG Configuration:513 - resolving reference to class: com.cadtrain.scout.common.dataobject.LanguageDO
16:05:54,315 DEBUG Configuration:513 - resolving reference to class: com.cadtrain.scout.common.dataobject.ProviderDO
16:05:54,316 DEBUG Configuration:513 - resolving reference to class: com.cadtrain.coachlms.common.dataobject.TopicDO
16:05:54,909 DEBUG SessionImpl:2981 - running Session.finalize()
16:05:55,691 INFO SessionFactoryImpl:132 - building session factory
16:05:55,694 DEBUG SessionFactoryImpl:134 - instantiating session factory with properties: {java.vendor=Sun Microsystems Inc., show_sql=true, catalina.base=/usr/coachlms/clms2/tomcat, hibernate.connection.url=jdbc:mysql://127.0.0.1/coachlms?autoReconnect=true , c3p0.min_size=2, catalina.useNaming=true, os.name=Linux, sun.boot.class.path=/usr/coachlms/clms2/tomcat/bin/bootstrap.jar:/usr/coachlms/clms2/tomcat/bin/commons-daemon.jar:/usr/coachlms/clms2/tomcat/bin/tomcat-jni.jar:/usr/coachlms/clms2/tomcat/common/endorsed/xml-apis.jar:/usr/coachlms/clms2/tomcat/common/endorsed/xercesImpl-2.0.0.jar:/usr/coachlms/clms2/tomcat/common/endorsed/xalan-2.3.1.jar:/usr/java/j2sdk1.4.2_01/jre/lib/rt.jar:/usr/java/j2sdk1.4.2_01/jre/lib/i18n.jar:/usr/java/j2sdk1.4.2_01/jre/lib/sunrsasign.jar:/usr/java/j2sdk1.4.2_01/jre/lib/jsse.jar:/usr/java/j2sdk1.4.2_01/jre/lib/jce.jar:/usr/java/j2sdk1.4.2_01/jre/lib/charsets.jar:/usr/java/j2sdk1.4.2_01/jre/classes, hibernate.c3p0.max_size=10, sun.java2d.fontpath=, java.vm.specification.vendor=Sun Microsystems Inc., c3p0.max_size=10, java.runtime.version=1.4.2_01-b06, hibernate.c3p0.min_size=2, user.name=mwelch, connection.driver_class=org.gjt.mm.mysql.Driver, hibernate.c3p0.timeout=600, user.language=en, java.naming.factory.initial=org.apache.naming.java.javaURLContextFactory, sun.boot.library.path=/usr/java/j2sdk1.4.2_01/jre/lib/i386, dialect=net.sf.hibernate.dialect.MySQLDialect, java.version=1.4.2_01, version=2.3.1, c3p0.validate=true, user.timezone=America/Mexico_City, sun.arch.data.model=32, hibernate.use_outer_join=true, java.endorsed.dirs=/usr/coachlms/clms2/tomcat/bin:/usr/coachlms/clms2/tomcat/common/endorsed, sun.cpu.isalist=, file.encoding.pkg=sun.io, file.separator=/, java.specification.name=Java Platform API Specification, hibernate.cglib.use_reflection_optimizer=true, java.class.version=48.0, user.country=US, connection.url=jdbc:mysql://127.0.0.1/coachlms?autoReconnect=true , java.home=/usr/java/j2sdk1.4.2_01/jre, java.vm.info=mixed mode, hibernate.c3p0.validate=true, os.version=2.4.20-18.9, path.separator=:, connection.password=coachapp, java.vm.version=1.4.2_01-b06, java.util.prefs.PreferencesFactory=java.util.prefs.FileSystemPreferencesFactory, hibernate.connection.password=coachapp, vendor-url=http://xml.apache.org/xalan-j, java.protocol.handler.pkgs=com.sun.net.ssl.internal.www.protocol, java.awt.printerjob=sun.print.PSPrinterJob, vendor=Apache Software Foundation, sun.io.unicode.encoding=UnicodeLittle, hibernate.connection.username=coachapp, java.naming.factory.url.pkgs=org.apache.naming, user.home=/home/mwelch, java.specification.vendor=Sun Microsystems Inc., org.xml.sax.driver=org.apache.xerces.parsers.SAXParser, java.library.path=/usr/java/j2sdk1.4.2_01/jre/lib/i386/client:/usr/java/j2sdk1.4.2_01/jre/lib/i386:/usr/java/j2sdk1.4.2_01/jre/../lib/i386, java.vendor.url=http://java.sun.com/, hibernate.connection.driver_class=org.gjt.mm.mysql.Driver, connection.username=coachapp, java.vm.vendor=Sun Microsystems Inc., hibernate.dialect=net.sf.hibernate.dialect.MySQLDialect, java.runtime.name=Java(TM) 2 Runtime Environment, Standard Edition, java.class.path=/usr/coachlms/clms2/j2sdk1.4.2_01/lib/tools.jar:/usr/coachlms/clms2/tomcat/bin/bootstrap.jar, use_outer_join=true, c3p0.timeout=600, java.vm.specification.name=Java Virtual Machine Specification, java.vm.specification.version=1.0, catalina.home=/usr/coachlms/clms2/tomcat, sun.cpu.endian=little, sun.os.patch.level=unknown, java.io.tmpdir=/usr/coachlms/clms2/tomcat/temp, java.vendor.url.bug=http://java.sun.com/cgi-bin/bugreport.cgi, java.awt.graphicsenv=sun.awt.X11GraphicsEnvironment, os.arch=i386, java.ext.dirs=/usr/java/j2sdk1.4.2_01/jre/lib/ext, user.dir=/home/mwelch, line.separator=
, java.vm.name=Java HotSpot(TM) Client VM, file.encoding=UTF-8, java.specification.version=1.4, c3p0.max_statements=100, hibernate.show_sql=true, hibernate.c3p0.max_statements=100}
16:05:55,732 INFO Dialect:83 - Using dialect: net.sf.hibernate.dialect.MySQLDialect
16:05:55,759 INFO C3P0ConnectionProvider:65 - C3P0 using driver: org.gjt.mm.mysql.Driver at URL: jdbc:mysql://127.0.0.1/coachlms?autoReconnect=true
16:05:55,761 INFO C3P0ConnectionProvider:66 - Connection properties: {user=coachapp, password=coachapp}
16:05:55,929 INFO SessionFactoryImpl:162 - Use outer join fetching: true
16:05:56,904 INFO SessionFactoryImpl:185 - Use scrollable result sets: true
16:05:56,906 INFO SessionFactoryImpl:186 - JDBC 2 max batch size: 15
16:05:56,913 INFO SessionFactoryImpl:194 - echoing all SQL to stdout
16:05:57,972 DEBUG SessionFactoryObjectFactory:39 - initializing class SessionFactoryObjectFactory
16:05:57,981 DEBUG SessionFactoryObjectFactory:76 - registered: ff808081f82cf83b00f82cf846c50000 (unnamed)
16:05:57,983 INFO SessionFactoryObjectFactory:82 - no JDNI name configured
16:05:57,984 INFO SessionFactoryImpl:269 - Query language substitutions: {}
16:05:57,986 DEBUG SessionFactoryImpl:281 - instantiated session factory
16:05:58,100 DEBUG SessionImpl:413 - opened session
16:05:58,110 DEBUG JDBCTransaction:36 - begin
16:05:58,113 DEBUG SessionImpl:1328 - find: from com.cadtrain.coachlms.common.dataobject.AssessmentDO
16:05:58,149 DEBUG QueryTranslator:144 - compiling query
16:05:58,186 DEBUG SessionImpl:2011 - flushing session
16:05:58,188 DEBUG SessionImpl:2113 - Flushing entities and processing referenced collections
16:05:58,189 DEBUG SessionImpl:2397 - Processing unreferenced collections
16:05:58,191 DEBUG SessionImpl:2408 - Scheduling collection removes/(re)creates/updates
16:05:58,193 DEBUG SessionImpl:2023 - Flushed: 0 insertions, 0 updates, 0 deletions to 0 objects
16:05:58,197 DEBUG SessionImpl:2028 - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
16:05:58,200 DEBUG SessionImpl:1573 - Dont need to execute flush
16:05:58,203 DEBUG QueryTranslator:200 - HQL: from com.cadtrain.coachlms.common.dataobject.AssessmentDO
16:05:58,204 DEBUG QueryTranslator:201 - SQL: select assessme0_.assessmentID as assessmentID, assessme0_.name as name, assessme0_.description as descript3_, assessme0_.provider_id as provider4_, assessme0_.topic_id as topic_id, assessme0_.language_code as language6_ from assessments assessme0_
16:05:58,213 DEBUG BatcherImpl:166 - about to open: 0 open PreparedStatements, 0 open ResultSets
16:05:58,217 DEBUG SessionFactoryImpl:526 - prepared statement get: select assessme0_.assessmentID as assessmentID, assessme0_.name as name, assessme0_.description as descript3_, assessme0_.provider_id as provider4_, assessme0_.topic_id as topic_id, assessme0_.language_code as language6_ from assessments assessme0_
Hibernate: select assessme0_.assessmentID as assessmentID, assessme0_.name as name, assessme0_.description as descript3_, assessme0_.provider_id as provider4_, assessme0_.topic_id as topic_id, assessme0_.language_code as language6_ from assessments assessme0_
16:05:58,218 DEBUG SessionFactoryImpl:536 - preparing statement
16:05:58,378 DEBUG Loader:148 - processing result set
16:05:58,382 DEBUG Loader:260 - result row: 1
16:05:58,397 DEBUG Loader:357 - Initializing object from ResultSet: 1
16:05:58,406 DEBUG Loader:413 - Hydrating entity: com.cadtrain.coachlms.common.dataobject.AssessmentDO#1
16:05:58,412 DEBUG Loader:260 - result row: 2
16:05:58,414 DEBUG Loader:357 - Initializing object from ResultSet: 2
16:05:58,417 DEBUG Loader:413 - Hydrating entity: com.cadtrain.coachlms.common.dataobject.AssessmentDO#2
16:05:58,420 DEBUG Loader:260 - result row: 3
16:05:58,421 DEBUG Loader:357 - Initializing object from ResultSet: 3
16:05:58,423 DEBUG Loader:413 - Hydrating entity: com.cadtrain.coachlms.common.dataobject.AssessmentDO#3
16:05:58,424 DEBUG Loader:260 - result row: 4
16:05:58,426 DEBUG Loader:357 - Initializing object from ResultSet: 4
16:05:58,427 DEBUG Loader:413 - Hydrating entity: com.cadtrain.coachlms.common.dataobject.AssessmentDO#4
16:05:58,428 DEBUG Loader:260 - result row: 5
16:05:58,430 DEBUG Loader:357 - Initializing object from ResultSet: 5
16:05:58,431 DEBUG Loader:413 - Hydrating entity: com.cadtrain.coachlms.common.dataobject.AssessmentDO#5
16:05:58,433 DEBUG Loader:182 - done processing result set (5 rows)
16:05:58,438 DEBUG BatcherImpl:173 - done closing: 0 open PreparedStatements, 0 open ResultSets
16:05:58,439 DEBUG SessionFactoryImpl:554 - closing statement
16:05:58,441 DEBUG Loader:195 - total objects hydrated: 5
16:05:58,450 DEBUG SessionImpl:1954 - resolving associations for [com.cadtrain.coachlms.common.dataobject.AssessmentDO#1]
16:05:58,474 DEBUG SessionImpl:1752 - loading [com.cadtrain.scout.common.dataobject.ProviderDO#1]
16:05:58,802 DEBUG SessionImpl:1752 - loading [com.cadtrain.coachlms.common.dataobject.TopicDO#100001]
16:05:58,937 DEBUG SessionImpl:1752 - loading [com.cadtrain.scout.common.dataobject.LanguageDO#en]
16:05:59,013 DEBUG SessionImpl:1975 - done materializing entity [com.cadtrain.coachlms.common.dataobject.AssessmentDO#1]
16:05:59,018 DEBUG SessionImpl:1954 - resolving associations for [com.cadtrain.coachlms.common.dataobject.AssessmentDO#2]
16:05:59,022 DEBUG SessionImpl:1752 - loading [com.cadtrain.scout.common.dataobject.ProviderDO#1]
16:05:59,026 DEBUG SessionImpl:1752 - loading [com.cadtrain.coachlms.common.dataobject.TopicDO#100001]
16:05:59,028 DEBUG SessionImpl:1752 - loading [com.cadtrain.scout.common.dataobject.LanguageDO#en]
16:05:59,029 DEBUG SessionImpl:1975 - done materializing entity [com.cadtrain.coachlms.common.dataobject.AssessmentDO#2]
16:05:59,030 DEBUG SessionImpl:1954 - resolving associations for [com.cadtrain.coachlms.common.dataobject.AssessmentDO#3]
16:05:59,031 DEBUG SessionImpl:1752 - loading [com.cadtrain.scout.common.dataobject.ProviderDO#1]
16:05:59,032 DEBUG SessionImpl:1752 - loading [com.cadtrain.coachlms.common.dataobject.TopicDO#100001]
16:05:59,035 DEBUG SessionImpl:1752 - loading [com.cadtrain.scout.common.dataobject.LanguageDO#en]
16:05:59,037 DEBUG SessionImpl:1975 - done materializing entity [com.cadtrain.coachlms.common.dataobject.AssessmentDO#3]
16:05:59,040 DEBUG SessionImpl:1954 - resolving associations for [com.cadtrain.coachlms.common.dataobject.AssessmentDO#4]
16:05:59,041 DEBUG SessionImpl:1752 - loading [com.cadtrain.scout.common.dataobject.ProviderDO#1]
16:05:59,042 DEBUG SessionImpl:1752 - loading [com.cadtrain.coachlms.common.dataobject.TopicDO#100001]
16:05:59,043 DEBUG SessionImpl:1752 - loading [com.cadtrain.scout.common.dataobject.LanguageDO#en]
16:05:59,044 DEBUG SessionImpl:1975 - done materializing entity [com.cadtrain.coachlms.common.dataobject.AssessmentDO#4]
16:05:59,045 DEBUG SessionImpl:1954 - resolving associations for [com.cadtrain.coachlms.common.dataobject.AssessmentDO#5]
16:05:59,047 DEBUG SessionImpl:1752 - loading [com.cadtrain.scout.common.dataobject.ProviderDO#1]
16:05:59,057 DEBUG SessionImpl:1752 - loading [com.cadtrain.coachlms.common.dataobject.TopicDO#100001]
16:05:59,058 DEBUG SessionImpl:1752 - loading [com.cadtrain.scout.common.dataobject.LanguageDO#en]
16:05:59,059 DEBUG SessionImpl:1975 - done materializing entity [com.cadtrain.coachlms.common.dataobject.AssessmentDO#5]
16:05:59,060 DEBUG JDBCTransaction:54 - commit
16:05:59,061 DEBUG SessionImpl:2011 - flushing session
16:05:59,067 DEBUG Cascades:336 - processing cascades for: com.cadtrain.coachlms.common.dataobject.AssessmentDO
16:05:59,070 DEBUG Cascades:344 - done processing cascades for: com.cadtrain.coachlms.common.dataobject.AssessmentDO
16:05:59,071 DEBUG Cascades:336 - processing cascades for: com.cadtrain.coachlms.common.dataobject.AssessmentDO
16:05:59,072 DEBUG Cascades:344 - done processing cascades for: com.cadtrain.coachlms.common.dataobject.AssessmentDO
16:05:59,073 DEBUG Cascades:336 - processing cascades for: com.cadtrain.coachlms.common.dataobject.AssessmentDO
16:05:59,075 DEBUG Cascades:344 - done processing cascades for: com.cadtrain.coachlms.common.dataobject.AssessmentDO
16:05:59,076 DEBUG Cascades:336 - processing cascades for: com.cadtrain.coachlms.common.dataobject.AssessmentDO
16:05:59,077 DEBUG Cascades:344 - done processing cascades for: com.cadtrain.coachlms.common.dataobject.AssessmentDO
16:05:59,078 DEBUG Cascades:336 - processing cascades for: com.cadtrain.coachlms.common.dataobject.AssessmentDO
16:05:59,079 DEBUG Cascades:344 - done processing cascades for: com.cadtrain.coachlms.common.dataobject.AssessmentDO
16:05:59,080 DEBUG SessionImpl:2113 - Flushing entities and processing referenced collections
16:05:59,095 DEBUG SessionImpl:2550 - Collection found: [com.cadtrain.coachlms.common.dataobject.AssessmentDO.questionGroups#1], was: [com.cadtrain.coachlms.common.dataobject.AssessmentDO.questionGroups#1]
16:05:59,097 DEBUG SessionImpl:2550 - Collection found: [com.cadtrain.coachlms.common.dataobject.AssessmentDO.questionGroups#2], was: [com.cadtrain.coachlms.common.dataobject.AssessmentDO.questionGroups#2]
16:05:59,099 DEBUG SessionImpl:2550 - Collection found: [com.cadtrain.coachlms.common.dataobject.AssessmentDO.questionGroups#3], was: [com.cadtrain.coachlms.common.dataobject.AssessmentDO.questionGroups#3]
16:05:59,100 DEBUG SessionImpl:2550 - Collection found: [com.cadtrain.coachlms.common.dataobject.AssessmentDO.questionGroups#4], was: [com.cadtrain.coachlms.common.dataobject.AssessmentDO.questionGroups#4]
16:05:59,102 DEBUG SessionImpl:2550 - Collection found: [com.cadtrain.coachlms.common.dataobject.AssessmentDO.questionGroups#5], was: [com.cadtrain.coachlms.common.dataobject.AssessmentDO.questionGroups#5]
16:05:59,103 DEBUG SessionImpl:2397 - Processing unreferenced collections
16:05:59,105 DEBUG SessionImpl:2408 - Scheduling collection removes/(re)creates/updates
16:05:59,106 DEBUG SessionImpl:2023 - Flushed: 0 insertions, 0 updates, 0 deletions to 5 objects
16:05:59,108 DEBUG SessionImpl:2028 - Flushed: 0 (re)creations, 0 updates, 0 removals to 5 collections
16:05:59,112 DEBUG SessionImpl:2058 - executing flush
16:05:59,123 DEBUG SessionImpl:2428 - post flush
16:05:59,124 DEBUG SessionImpl:447 - transaction completion
Oct 11, 2003 4:05:59 PM com.cadtrain.coachlms.app.util.HibernateSession closeSession
INFO: Closing Hibernate Session
16:05:59,127 DEBUG SessionImpl:435 - closing session
16:05:59,128 DEBUG SessionImpl:2930 - disconnecting session
16:05:59,136 DEBUG SessionImpl:447 - transaction completion
Begin testing
Assessment Name: assessment0
16:05:59,149 ERROR LazyInitializer:57 - Exception initializing proxy
net.sf.hibernate.HibernateException: Could not initialize proxy - the owning Session was closed
at net.sf.hibernate.proxy.LazyInitializer.initialize(LazyInitializer.java:44)
at net.sf.hibernate.proxy.LazyInitializer.initializeWrapExceptions(LazyInitializer.java:54)
at net.sf.hibernate.proxy.LazyInitializer.getImplementation(LazyInitializer.java:152)
at net.sf.hibernate.proxy.CGLIBLazyInitializer.intercept(CGLIBLazyInitializer.java:55)
at com.cadtrain.coachlms.common.dataobject.TopicDO$$EnhancedByCGLIB$$1.getSoftVerLabel(<generated>)
at org.apache.jsp.hibtest2_jsp._jspService(hibtest2_jsp.java:134)
at org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:137)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:853)
at org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:204)
at org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:295)
at org.apache.jasper.servlet.JspServlet.service(JspServlet.java:241)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:853)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:247)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:260)
at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:643)
at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:480)
at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:995)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:643)
at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:480)
at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:995)
at org.apache.catalina.core.StandardContext.invoke(StandardContext.java:2415)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:180)
at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:643)
at org.apache.catalina.valves.ErrorDispatcherValve.invoke(ErrorDispatcherValve.java:170)
at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:172)
at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641)
at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:480)
at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:995)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:174)
at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:643)
at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:480)
at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:995)
at org.apache.coyote.tomcat4.CoyoteAdapter.service(CoyoteAdapter.java:223)
at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:432)
at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.processConnection(Http11Protocol.java:386)
at org.apache.tomcat.util.net.TcpWorkerThread.runIt(PoolTcpEndpoint.java:534)
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:530)
at java.lang.Thread.run(Thread.java:534)
-Matt