problem with named queries

jbenckert · **Joined:** Tue Mar 18, 2008 11:44 am **Posts:** 5

I'm evaluting nHibernate and having a problem using some named queries to populate my entities. The mapping here seems right but when executing my unit test I'm getting zero results on the SomeDeps property of the Coverage class. Inspecting the log reveals that nHibernate is retrieving the dependents but they're somehow not being populated into the property.

I've looked through the examples in the source and I don't see any holes in what I'm doing here.

Can anyone advise what I may be doing wrong ? Thanks to anyone who can provide assistance.

Below you'll find my mappings and the log.

Hibernate version:1.2

Mapping documents:

Coverage Map:

Code:

<hibernate-mapping xmlns="urn:nhibernate-mapping-2.2" namespace="Trion.Census.Service.WCF.BusinessEntities" assembly="Trion.Census.Service.WCF.BusinessEntities">
   <class name="Coverage">
      <id name="ID" type="Int32" unsaved-value="null" column="COVERAGE_ID">
         <generator class="native"/>
      </id>
      <property name ="BillingIndicator" column="BILLING_INDICATOR" />
      <property name="PFAOverride" column="PFA_OVERRIDE" />
      <property name="Code" column="COVERAGE_CODE" />
      <property name="MinimumTotalDependents" column="MIN_TOTAL_DEPS" />
      <component name="Option" class="BenefitOption">
         <property name="ID" type="string" column="PLAN_ID" />
         <component name="Benefit" class="Benefit">
            <property name="Type" type="string" column="PLAN_TYPE" />
         </component>
      </component>
      <bag name="SomeDeps" lazy="false" inverse="false" cascade="all" access="property">
         <key column="DEPENDENT_ID"/>
         <one-to-many class="Dependent" />
         <loader query-ref="CoveredDependentsQuery"/>
      </bag>
      <loader query-ref="CoverageSelectQuery"/>
   </class>
   <sql-query name="CoverageSelectQuery">
      <return alias="cov" class="Coverage" />
      SELECT      EOL_COVERAGE.COVERAGE_ID,
      EOL_COVERAGE.PLAN_TYPE as PLAN_TYPE,
      EOL_COVERAGE.PLAN_ID as PLAN_ID,
      EOL_COVERAGE.EMPLOYEE_ID AS EMPLOYEE_ID,
      EOL_PLAN_DEFINITION.COVERAGE_CODE AS COVERAGE_CODE,
      EOL_PLAN_DEFINITION.BILLING_INDICATOR AS BILLING_INDICATOR,
      EOL_PLAN_DEFINITION.PFA_OVERRIDE AS PFA_OVERRIDE,
      FTM_COVERAGE_CODE_STD.MIN_TOTAL_DEPS AS MIN_TOTAL_DEPS

      FROM         EOL_COVERAGE INNER JOIN
      EOL_PLAN_DEFINITION ON EOL_COVERAGE.COMPANY_ID = EOL_PLAN_DEFINITION.COMPANY_ID AND
      EOL_COVERAGE.PLAN_TYPE = EOL_PLAN_DEFINITION.PLAN_TYPE

      join  FTM_COVERAGE_CODE_PPLUS on EOL_COVERAGE.COMPANY_ID = FTM_COVERAGE_CODE_PPLUS.COMPANY_ID
      and EOL_COVERAGE.PLAN_YEAR_ID = FTM_COVERAGE_CODE_PPLUS.PLAN_YEAR_ID
      and EOL_COVERAGE.COVERAGE_CODE = FTM_COVERAGE_CODE_PPLUS.COVERAGE_CODE

      join  FTM_COVERAGE_CODE_STD on FTM_COVERAGE_CODE_PPLUS.COVERAGE_CODE_STD_ID = FTM_COVERAGE_CODE_STD.COVERAGE_CODE_STD_ID

      WHERE EOL_COVERAGE.COVERAGE_ID = ?
   </sql-query>
   <sql-query name="CoveredDependentsQuery">
      <load-collection alias="EOL_DEPENDENT" role="Coverage.SomeDeps" />
      
      SELECT      EOL_DEPENDENT.*

      FROM         EOL_COVERAGE left join  
      
      EOL_DEPENDENT on EOL_COVERAGE.EMPLOYEE_ID = EOL_DEPENDENT.EMPLOYEE_ID

      WHERE EOL_COVERAGE.COVERAGE_ID = :id
   </sql-query>
</hibernate-mapping>

Dependent Map:

Code:

<hibernate-mapping xmlns="urn:nhibernate-mapping-2.2" namespace="Trion.Census.Service.WCF.BusinessEntities" assembly="Trion.Census.Service.WCF.BusinessEntities">
  <class name="Dependent" table="EOL_DEPENDENT">
    <id name="ID" column="DEPENDENT_ID" type="Int32" unsaved-value="null">
      <generator class="identity"/>
    </id>
    <property name="LastName" column="LAST_NAME" />
    <property name="SocialSecurityNumber" column="DEPENDENT_SSN" />
    <property name="FirstName" column="FIRST_NAME" />
    <property name="DateofBirth" column="DATE_OF_BIRTH" />
    <property name="MiddleInitial" column="MIDDLE_INIT"/>
    <property name="EmployeeSocialSecurityNumber" column="EMPLOYEE_SSN"/>
    <property name="RelationshipCode" column="RELATIONSHIP_CODE"/>
     

    <component class="AuditInformation" name="AuditInformation">
      <property name="UpdatedBy" column="UPDATED_BY"/>
      <property name="UserType" column="AUD_USER_TYPE"/>
      <property name="UserName" column="AUD_USER_NAME"/>
      <property name="TimeStamp" column="AUD_TIME_STAMP"/>
      <property name="ModuleName" column="AUD_SCRIPT_NAME"/>
      <property name="TransactionID" column="QLE_TRANS_ID"/>
    </component>

   <many-to-one name="Employee" class="Employee" column="EMPLOYEE_ID"/>
    <many-to-one name="Company" class="Company" column="COMPANY_ID"/>
     
  </class>
</hibernate-mapping>

Code between sessionFactory.openSession() and session.close():

Code:

using (ISession session = SessionFactory.OpenSession())
            {
                //ICriteria criteria = session.CreateCriteria(typeof(Coverage));
                //criteria.Add(new EqExpression("ID", Fixtures.CoverageID));

                var coverage = session.Get<Coverage>(Fixtures.CoverageID);
                Console.WriteLine(coverage.SomeDeps.Count().ToString());
                Console.WriteLine(coverage.ToString());
            }

Name and version of the database you are using:sql svr 2005

Debug level Hibernate log excerpt:

10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - resolved object in session cache: [Trion.Census.Service.WCF.BusinessEntities.Dependent#125324]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - result set row: 7
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '125325' as column: DEPENDENT_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - result row: 125325
10:48:59 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - Initializing object from DataReader: [Trion.Census.Service.WCF.BusinessEntities.Dependent#125325]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Persister.Entity.AbstractEntityPersister - Hydrating entity: Trion.Census.Service.WCF.BusinessEntities.Dependent#125325
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning 'PATTON' as column: LAST_NAME
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning '242178535' as column: DEPENDENT_SSN
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning 'CHRISTOPHER' as column: FIRST_NAME
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.DateTimeType - returning '7/11/1960' as column: DATE_OF_BIRTH
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning 'L' as column: MIDDLE_INIT
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning '001581250' as column: EMPLOYEE_SSN
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning 'H' as column: RELATIONSHIP_CODE
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning null as column: UPDATED_BY
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning null as column: AUD_USER_TYPE
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning null as column: AUD_USER_NAME
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.DateTimeType - returning null as column: AUD_TIME_STAMP
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning null as column: AUD_SCRIPT_NAME
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning null as column: QLE_TRANS_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '394548' as column: EMPLOYEE_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '1' as column: COMPANY_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '394548' as column: EMPLOYEE_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - found row of collection: [Trion.Census.Service.WCF.BusinessEntities.Coverage.SomeDeps#394548]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.CollectionLoadContext - starting attempt to find loading collection [[Trion.Census.Service.WCF.BusinessEntities.Coverage.SomeDeps#394548]]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.LoadContexts - attempting to locate loading collection entry [NHibernate.Engine.CollectionKey] in any result-set context
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.LoadContexts - collection [NHibernate.Engine.CollectionKey] not located in load context
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.CollectionLoadContext - found loading collection bound to current result set processing; reading row
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '125325' as column: DEPENDENT_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - loading entity: [Trion.Census.Service.WCF.BusinessEntities.Dependent#125325]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - attempting to resolve: [Trion.Census.Service.WCF.BusinessEntities.Dependent#125325]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - resolved object in session cache: [Trion.Census.Service.WCF.BusinessEntities.Dependent#125325]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - result set row: 8
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '125326' as column: DEPENDENT_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - result row: 125326
10:48:59 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - Initializing object from DataReader: [Trion.Census.Service.WCF.BusinessEntities.Dependent#125326]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Persister.Entity.AbstractEntityPersister - Hydrating entity: Trion.Census.Service.WCF.BusinessEntities.Dependent#125326
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning 'PATTON' as column: LAST_NAME
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning null as column: DEPENDENT_SSN
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning 'CHRISTOPHER' as column: FIRST_NAME
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.DateTimeType - returning '6/20/1985' as column: DATE_OF_BIRTH
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning null as column: MIDDLE_INIT
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning '001581250' as column: EMPLOYEE_SSN
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning 'S' as column: RELATIONSHIP_CODE
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning null as column: UPDATED_BY
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning null as column: AUD_USER_TYPE
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning null as column: AUD_USER_NAME
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.DateTimeType - returning null as column: AUD_TIME_STAMP
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning null as column: AUD_SCRIPT_NAME
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning null as column: QLE_TRANS_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '394548' as column: EMPLOYEE_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '1' as column: COMPANY_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '394548' as column: EMPLOYEE_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - found row of collection: [Trion.Census.Service.WCF.BusinessEntities.Coverage.SomeDeps#394548]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.CollectionLoadContext - starting attempt to find loading collection [[Trion.Census.Service.WCF.BusinessEntities.Coverage.SomeDeps#394548]]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.LoadContexts - attempting to locate loading collection entry [NHibernate.Engine.CollectionKey] in any result-set context
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.LoadContexts - collection [NHibernate.Engine.CollectionKey] not located in load context
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.CollectionLoadContext - found loading collection bound to current result set processing; reading row
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '125326' as column: DEPENDENT_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - loading entity: [Trion.Census.Service.WCF.BusinessEntities.Dependent#125326]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - attempting to resolve: [Trion.Census.Service.WCF.BusinessEntities.Dependent#125326]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - resolved object in session cache: [Trion.Census.Service.WCF.BusinessEntities.Dependent#125326]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - result set row: 9
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '125327' as column: DEPENDENT_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - result row: 125327
10:48:59 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - Initializing object from DataReader: [Trion.Census.Service.WCF.BusinessEntities.Dependent#125327]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Persister.Entity.AbstractEntityPersister - Hydrating entity: Trion.Census.Service.WCF.BusinessEntities.Dependent#125327
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning 'PATTON' as column: LAST_NAME
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning null as column: DEPENDENT_SSN
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning 'ELIZABETH' as column: FIRST_NAME
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.DateTimeType - returning '3/13/1981' as column: DATE_OF_BIRTH
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning null as column: MIDDLE_INIT
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning '001581250' as column: EMPLOYEE_SSN
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning 'D' as column: RELATIONSHIP_CODE
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning null as column: UPDATED_BY
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning null as column: AUD_USER_TYPE
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning null as column: AUD_USER_NAME
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.DateTimeType - returning null as column: AUD_TIME_STAMP
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning null as column: AUD_SCRIPT_NAME
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning null as column: QLE_TRANS_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '394548' as column: EMPLOYEE_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '1' as column: COMPANY_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '394548' as column: EMPLOYEE_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - found row of collection: [Trion.Census.Service.WCF.BusinessEntities.Coverage.SomeDeps#394548]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.CollectionLoadContext - starting attempt to find loading collection [[Trion.Census.Service.WCF.BusinessEntities.Coverage.SomeDeps#394548]]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.LoadContexts - attempting to locate loading collection entry [NHibernate.Engine.CollectionKey] in any result-set context
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.LoadContexts - collection [NHibernate.Engine.CollectionKey] not located in load context
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.CollectionLoadContext - found loading collection bound to current result set processing; reading row
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '125327' as column: DEPENDENT_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - loading entity: [Trion.Census.Service.WCF.BusinessEntities.Dependent#125327]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - attempting to resolve: [Trion.Census.Service.WCF.BusinessEntities.Dependent#125327]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - resolved object in session cache: [Trion.Census.Service.WCF.BusinessEntities.Dependent#125327]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - result set row: 10
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '125328' as column: DEPENDENT_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - result row: 125328
10:48:59 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - Initializing object from DataReader: [Trion.Census.Service.WCF.BusinessEntities.Dependent#125328]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Persister.Entity.AbstractEntityPersister - Hydrating entity: Trion.Census.Service.WCF.BusinessEntities.Dependent#125328
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning 'PATTON' as column: LAST_NAME
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning '111111111' as column: DEPENDENT_SSN
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning 'GENERAL' as column: FIRST_NAME
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.DateTimeType - returning '11/25/2007' as column: DATE_OF_BIRTH
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning null as column: MIDDLE_INIT
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning '001581250' as column: EMPLOYEE_SSN
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning 'S' as column: RELATIONSHIP_CODE
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning 'EOL' as column: UPDATED_BY
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning null as column: AUD_USER_TYPE
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning null as column: AUD_USER_NAME
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.DateTimeType - returning null as column: AUD_TIME_STAMP
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning null as column: AUD_SCRIPT_NAME
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '6' as column: QLE_TRANS_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '394548' as column: EMPLOYEE_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '1' as column: COMPANY_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '394548' as column: EMPLOYEE_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - found row of collection: [Trion.Census.Service.WCF.BusinessEntities.Coverage.SomeDeps#394548]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.CollectionLoadContext - starting attempt to find loading collection [[Trion.Census.Service.WCF.BusinessEntities.Coverage.SomeDeps#394548]]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.LoadContexts - attempting to locate loading collection entry [NHibernate.Engine.CollectionKey] in any result-set context
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.LoadContexts - collection [NHibernate.Engine.CollectionKey] not located in load context
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.CollectionLoadContext - found loading collection bound to current result set processing; reading row
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '125328' as column: DEPENDENT_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - loading entity: [Trion.Census.Service.WCF.BusinessEntities.Dependent#125328]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - attempting to resolve: [Trion.Census.Service.WCF.BusinessEntities.Dependent#125328]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - resolved object in session cache: [Trion.Census.Service.WCF.BusinessEntities.Dependent#125328]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - result set row: 11
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '125329' as column: DEPENDENT_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - result row: 125329
10:48:59 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - Initializing object from DataReader: [Trion.Census.Service.WCF.BusinessEntities.Dependent#125329]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Persister.Entity.AbstractEntityPersister - Hydrating entity: Trion.Census.Service.WCF.BusinessEntities.Dependent#125329
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning 'SIMPSON' as column: LAST_NAME
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning '111111111' as column: DEPENDENT_SSN
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning 'HOMER' as column: FIRST_NAME
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.DateTimeType - returning '1/18/1999' as column: DATE_OF_BIRTH
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning null as column: MIDDLE_INIT
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning '001581250' as column: EMPLOYEE_SSN
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning 'H' as column: RELATIONSHIP_CODE
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning 'EOL' as column: UPDATED_BY
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning null as column: AUD_USER_TYPE
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning null as column: AUD_USER_NAME
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.DateTimeType - returning null as column: AUD_TIME_STAMP
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning null as column: AUD_SCRIPT_NAME
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '11' as column: QLE_TRANS_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '394548' as column: EMPLOYEE_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '1' as column: COMPANY_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '394548' as column: EMPLOYEE_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - found row of collection: [Trion.Census.Service.WCF.BusinessEntities.Coverage.SomeDeps#394548]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.CollectionLoadContext - starting attempt to find loading collection [[Trion.Census.Service.WCF.BusinessEntities.Coverage.SomeDeps#394548]]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.LoadContexts - attempting to locate loading collection entry [NHibernate.Engine.CollectionKey] in any result-set context
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.LoadContexts - collection [NHibernate.Engine.CollectionKey] not located in load context
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.CollectionLoadContext - found loading collection bound to current result set processing; reading row
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '125329' as column: DEPENDENT_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - loading entity: [Trion.Census.Service.WCF.BusinessEntities.Dependent#125329]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - attempting to resolve: [Trion.Census.Service.WCF.BusinessEntities.Dependent#125329]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - resolved object in session cache: [Trion.Census.Service.WCF.BusinessEntities.Dependent#125329]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - result set row: 12
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '125330' as column: DEPENDENT_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - result row: 125330
10:48:59 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - Initializing object from DataReader: [Trion.Census.Service.WCF.BusinessEntities.Dependent#125330]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Persister.Entity.AbstractEntityPersister - Hydrating entity: Trion.Census.Service.WCF.BusinessEntities.Dependent#125330
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning 'SIMPSON' as column: LAST_NAME
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning '111111111' as column: DEPENDENT_SSN
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning 'LISA' as column: FIRST_NAME
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.DateTimeType - returning '11/30/2007' as column: DATE_OF_BIRTH
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning null as column: MIDDLE_INIT
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning '001581250' as column: EMPLOYEE_SSN
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning 'D' as column: RELATIONSHIP_CODE
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning 'EOL' as column: UPDATED_BY
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning null as column: AUD_USER_TYPE
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning null as column: AUD_USER_NAME
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.DateTimeType - returning null as column: AUD_TIME_STAMP
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning null as column: AUD_SCRIPT_NAME
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '14' as column: QLE_TRANS_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '394548' as column: EMPLOYEE_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '1' as column: COMPANY_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '394548' as column: EMPLOYEE_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - found row of collection: [Trion.Census.Service.WCF.BusinessEntities.Coverage.SomeDeps#394548]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.CollectionLoadContext - starting attempt to find loading collection [[Trion.Census.Service.WCF.BusinessEntities.Coverage.SomeDeps#394548]]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.LoadContexts - attempting to locate loading collection entry [NHibernate.Engine.CollectionKey] in any result-set context
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.LoadContexts - collection [NHibernate.Engine.CollectionKey] not located in load context
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.CollectionLoadContext - found loading collection bound to current result set processing; reading row
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '125330' as column: DEPENDENT_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - loading entity: [Trion.Census.Service.WCF.BusinessEntities.Dependent#125330]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - attempting to resolve: [Trion.Census.Service.WCF.BusinessEntities.Dependent#125330]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - resolved object in session cache: [Trion.Census.Service.WCF.BusinessEntities.Dependent#125330]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - result set row: 13
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '125331' as column: DEPENDENT_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - result row: 125331
10:48:59 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - Initializing object from DataReader: [Trion.Census.Service.WCF.BusinessEntities.Dependent#125331]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Persister.Entity.AbstractEntityPersister - Hydrating entity: Trion.Census.Service.WCF.BusinessEntities.Dependent#125331
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning 'SIMPSON' as column: LAST_NAME
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning '111111111' as column: DEPENDENT_SSN
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning 'MAGGIE' as column: FIRST_NAME
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.DateTimeType - returning '1/1/1900' as column: DATE_OF_BIRTH
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning null as column: MIDDLE_INIT
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning '001581250' as column: EMPLOYEE_SSN
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning 'D' as column: RELATIONSHIP_CODE
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning 'EOL' as column: UPDATED_BY
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning null as column: AUD_USER_TYPE
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning null as column: AUD_USER_NAME
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.DateTimeType - returning null as column: AUD_TIME_STAMP
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning null as column: AUD_SCRIPT_NAME
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '12' as column: QLE_TRANS_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '394548' as column: EMPLOYEE_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '1' as column: COMPANY_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '394548' as column: EMPLOYEE_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - found row of collection: [Trion.Census.Service.WCF.BusinessEntities.Coverage.SomeDeps#394548]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.CollectionLoadContext - starting attempt to find loading collection [[Trion.Census.Service.WCF.BusinessEntities.Coverage.SomeDeps#394548]]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.LoadContexts - attempting to locate loading collection entry [NHibernate.Engine.CollectionKey] in any result-set context
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.LoadContexts - collection [NHibernate.Engine.CollectionKey] not located in load context
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.CollectionLoadContext - found loading collection bound to current result set processing; reading row
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '125331' as column: DEPENDENT_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - loading entity: [Trion.Census.Service.WCF.BusinessEntities.Dependent#125331]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - attempting to resolve: [Trion.Census.Service.WCF.BusinessEntities.Dependent#125331]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - resolved object in session cache: [Trion.Census.Service.WCF.BusinessEntities.Dependent#125331]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - result set row: 14
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '125332' as column: DEPENDENT_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - result row: 125332
10:48:59 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - Initializing object from DataReader: [Trion.Census.Service.WCF.BusinessEntities.Dependent#125332]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Persister.Entity.AbstractEntityPersister - Hydrating entity: Trion.Census.Service.WCF.BusinessEntities.Dependent#125332
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning 'PATTON' as column: LAST_NAME
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning null as column: DEPENDENT_SSN
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning 'SHERRY' as column: FIRST_NAME
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.DateTimeType - returning '4/24/1984' as column: DATE_OF_BIRTH
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning null as column: MIDDLE_INIT
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning '001581250' as column: EMPLOYEE_SSN
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning 'D' as column: RELATIONSHIP_CODE
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning null as column: UPDATED_BY
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning null as column: AUD_USER_TYPE
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning null as column: AUD_USER_NAME
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.DateTimeType - returning null as column: AUD_TIME_STAMP
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning null as column: AUD_SCRIPT_NAME
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning null as column: QLE_TRANS_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '394548' as column: EMPLOYEE_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '1' as column: COMPANY_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '394548' as column: EMPLOYEE_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - found row of collection: [Trion.Census.Service.WCF.BusinessEntities.Coverage.SomeDeps#394548]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.CollectionLoadContext - starting attempt to find loading collection [[Trion.Census.Service.WCF.BusinessEntities.Coverage.SomeDeps#394548]]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.LoadContexts - attempting to locate loading collection entry [NHibernate.Engine.CollectionKey] in any result-set context
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.LoadContexts - collection [NHibernate.Engine.CollectionKey] not located in load context
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.CollectionLoadContext - found loading collection bound to current result set processing; reading row
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '125332' as column: DEPENDENT_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - loading entity: [Trion.Census.Service.WCF.BusinessEntities.Dependent#125332]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - attempting to resolve: [Trion.Census.Service.WCF.BusinessEntities.Dependent#125332]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - resolved object in session cache: [Trion.Census.Service.WCF.BusinessEntities.Dependent#125332]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - result set row: 15
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '125333' as column: DEPENDENT_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - result row: 125333
10:48:59 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - Initializing object from DataReader: [Trion.Census.Service.WCF.BusinessEntities.Dependent#125333]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Persister.Entity.AbstractEntityPersister - Hydrating entity: Trion.Census.Service.WCF.BusinessEntities.Dependent#125333
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning 'TEST2' as column: LAST_NAME
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning '111111111' as column: DEPENDENT_SSN
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning 'TEST2' as column: FIRST_NAME
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.DateTimeType - returning '1/1/2007' as column: DATE_OF_BIRTH
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning 'A' as column: MIDDLE_INIT
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning '001581250' as column: EMPLOYEE_SSN
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning 'D' as column: RELATIONSHIP_CODE
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning 'EOL' as column: UPDATED_BY
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning null as column: AUD_USER_TYPE
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning null as column: AUD_USER_NAME
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.DateTimeType - returning null as column: AUD_TIME_STAMP
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning null as column: AUD_SCRIPT_NAME
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '2' as column: QLE_TRANS_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '394548' as column: EMPLOYEE_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '1' as column: COMPANY_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '394548' as column: EMPLOYEE_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - found row of collection: [Trion.Census.Service.WCF.BusinessEntities.Coverage.SomeDeps#394548]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.CollectionLoadContext - starting attempt to find loading collection [[Trion.Census.Service.WCF.BusinessEntities.Coverage.SomeDeps#394548]]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.LoadContexts - attempting to locate loading collection entry [NHibernate.Engine.CollectionKey] in any result-set context
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.LoadContexts - collection [NHibernate.Engine.CollectionKey] not located in load context
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.CollectionLoadContext - found loading collection bound to current result set processing; reading row
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '125333' as column: DEPENDENT_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - loading entity: [Trion.Census.Service.WCF.BusinessEntities.Dependent#125333]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - attempting to resolve: [Trion.Census.Service.WCF.BusinessEntities.Dependent#125333]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - resolved object in session cache: [Trion.Census.Service.WCF.BusinessEntities.Dependent#125333]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - result set row: 16
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '125334' as column: DEPENDENT_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - result row: 125334
10:48:59 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - Initializing object from DataReader: [Trion.Census.Service.WCF.BusinessEntities.Dependent#125334]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Persister.Entity.AbstractEntityPersister - Hydrating entity: Trion.Census.Service.WCF.BusinessEntities.Dependent#125334
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning 'TEST2' as column: LAST_NAME
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning '481245986' as column: DEPENDENT_SSN
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning 'TEST2' as column: FIRST_NAME
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.DateTimeType - returning '5/6/1965' as column: DATE_OF_BIRTH
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning 'A' as column: MIDDLE_INIT
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning '001581250' as column: EMPLOYEE_SSN
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning 'H' as column: RELATIONSHIP_CODE
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning 'EOL' as column: UPDATED_BY
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning null as column: AUD_USER_TYPE
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning null as column: AUD_USER_NAME
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.DateTimeType - returning null as column: AUD_TIME_STAMP
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning null as column: AUD_SCRIPT_NAME
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '1' as column: QLE_TRANS_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '394548' as column: EMPLOYEE_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '1' as column: COMPANY_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '394548' as column: EMPLOYEE_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - found row of collection: [Trion.Census.Service.WCF.BusinessEntities.Coverage.SomeDeps#394548]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.CollectionLoadContext - starting attempt to find loading collection [[Trion.Census.Service.WCF.BusinessEntities.Coverage.SomeDeps#394548]]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.LoadContexts - attempting to locate loading collection entry [NHibernate.Engine.CollectionKey] in any result-set context
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.LoadContexts - collection [NHibernate.Engine.CollectionKey] not located in load context
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.CollectionLoadContext - found loading collection bound to current result set processing; reading row
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '125334' as column: DEPENDENT_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - loading entity: [Trion.Census.Service.WCF.BusinessEntities.Dependent#125334]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - attempting to resolve: [Trion.Census.Service.WCF.BusinessEntities.Dependent#125334]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - resolved object in session cache: [Trion.Census.Service.WCF.BusinessEntities.Dependent#125334]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - result set row: 17
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '125335' as column: DEPENDENT_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - result row: 125335
10:48:59 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - Initializing object from DataReader: [Trion.Census.Service.WCF.BusinessEntities.Dependent#125335]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Persister.Entity.AbstractEntityPersister - Hydrating entity: Trion.Census.Service.WCF.BusinessEntities.Dependent#125335
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning 'PATTON' as column: LAST_NAME
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning null as column: DEPENDENT_SSN
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning 'TRACEY' as column: FIRST_NAME
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.DateTimeType - returning '12/26/1982' as column: DATE_OF_BIRTH
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning null as column: MIDDLE_INIT
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning '001581250' as column: EMPLOYEE_SSN
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning 'D' as column: RELATIONSHIP_CODE
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning null as column: UPDATED_BY
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning null as column: AUD_USER_TYPE
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning null as column: AUD_USER_NAME
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.DateTimeType - returning null as column: AUD_TIME_STAMP
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning null as column: AUD_SCRIPT_NAME
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning null as column: QLE_TRANS_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '394548' as column: EMPLOYEE_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '1' as column: COMPANY_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '394548' as column: EMPLOYEE_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - found row of collection: [Trion.Census.Service.WCF.BusinessEntities.Coverage.SomeDeps#394548]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.CollectionLoadContext - starting attempt to find loading collection [[Trion.Census.Service.WCF.BusinessEntities.Coverage.SomeDeps#394548]]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.LoadContexts - attempting to locate loading collection entry [NHibernate.Engine.CollectionKey] in any result-set context
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.LoadContexts - collection [NHibernate.Engine.CollectionKey] not located in load context
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.CollectionLoadContext - found loading collection bound to current result set processing; reading row
10:48:59 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '125335' as column: DEPENDENT_ID
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - loading entity: [Trion.Census.Service.WCF.BusinessEntities.Dependent#125335]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - attempting to resolve: [Trion.Census.Service.WCF.BusinessEntities.Dependent#125335]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - resolved object in session cache: [Trion.Census.Service.WCF.BusinessEntities.Dependent#125335]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - done processing result set (18 rows)
10:48:59 [TestRunnerThread] DEBUG NHibernate.Driver.NHybridDataReader - running NHybridDataReader.Dispose()
10:48:59 [TestRunnerThread] DEBUG NHibernate.AdoNet.BatcherImpl - Closed IDataReader, open IDataReaders :0
10:48:59 [TestRunnerThread] DEBUG NHibernate.AdoNet.BatcherImpl - Closed IDbCommand, open IDbCommands: 0
10:48:59 [TestRunnerThread] DEBUG NHibernate.AdoNet.ConnectionManager - aggressively releasing database connection
10:48:59 [TestRunnerThread] DEBUG NHibernate.Connection.ConnectionProvider - Closing connection
10:48:59 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - total objects hydrated: 18
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.TwoPhaseLoad - resolving associations for [Trion.Census.Service.WCF.BusinessEntities.Dependent#125318]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - loading entity: [Trion.Census.Service.WCF.BusinessEntities.Employee#394548]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - creating new proxy for entity
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - loading entity: [Trion.Census.Service.WCF.BusinessEntities.Company#1]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - creating new proxy for entity
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.TwoPhaseLoad - done materializing entity [Trion.Census.Service.WCF.BusinessEntities.Dependent#125318]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.TwoPhaseLoad - resolving associations for [Trion.Census.Service.WCF.BusinessEntities.Dependent#125319]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - loading entity: [Trion.Census.Service.WCF.BusinessEntities.Employee#394548]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - entity proxy found in session cache
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - loading entity: [Trion.Census.Service.WCF.BusinessEntities.Company#1]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - entity proxy found in session cache
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.TwoPhaseLoad - done materializing entity [Trion.Census.Service.WCF.BusinessEntities.Dependent#125319]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.TwoPhaseLoad - resolving associations for [Trion.Census.Service.WCF.BusinessEntities.Dependent#125320]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - loading entity: [Trion.Census.Service.WCF.BusinessEntities.Employee#394548]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - entity proxy found in session cache
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - loading entity: [Trion.Census.Service.WCF.BusinessEntities.Company#1]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - entity proxy found in session cache
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.TwoPhaseLoad - done materializing entity [Trion.Census.Service.WCF.BusinessEntities.Dependent#125320]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.TwoPhaseLoad - resolving associations for [Trion.Census.Service.WCF.BusinessEntities.Dependent#125321]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - loading entity: [Trion.Census.Service.WCF.BusinessEntities.Employee#394548]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - entity proxy found in session cache
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - loading entity: [Trion.Census.Service.WCF.BusinessEntities.Company#1]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - entity proxy found in session cache
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.TwoPhaseLoad - done materializing entity [Trion.Census.Service.WCF.BusinessEntities.Dependent#125321]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.TwoPhaseLoad - resolving associations for [Trion.Census.Service.WCF.BusinessEntities.Dependent#125322]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - loading entity: [Trion.Census.Service.WCF.BusinessEntities.Employee#394548]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - entity proxy found in session cache
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - loading entity: [Trion.Census.Service.WCF.BusinessEntities.Company#1]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - entity proxy found in session cache
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.TwoPhaseLoad - done materializing entity [Trion.Census.Service.WCF.BusinessEntities.Dependent#125322]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.TwoPhaseLoad - resolving associations for [Trion.Census.Service.WCF.BusinessEntities.Dependent#125323]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - loading entity: [Trion.Census.Service.WCF.BusinessEntities.Employee#394548]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - entity proxy found in session cache
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - loading entity: [Trion.Census.Service.WCF.BusinessEntities.Company#1]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - entity proxy found in session cache
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.TwoPhaseLoad - done materializing entity [Trion.Census.Service.WCF.BusinessEntities.Dependent#125323]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.TwoPhaseLoad - resolving associations for [Trion.Census.Service.WCF.BusinessEntities.Dependent#125324]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - loading entity: [Trion.Census.Service.WCF.BusinessEntities.Employee#394548]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - entity proxy found in session cache
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - loading entity: [Trion.Census.Service.WCF.BusinessEntities.Company#1]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - entity proxy found in session cache
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.TwoPhaseLoad - done materializing entity [Trion.Census.Service.WCF.BusinessEntities.Dependent#125324]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.TwoPhaseLoad - resolving associations for [Trion.Census.Service.WCF.BusinessEntities.Dependent#125325]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - loading entity: [Trion.Census.Service.WCF.BusinessEntities.Employee#394548]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - entity proxy found in session cache
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - loading entity: [Trion.Census.Service.WCF.BusinessEntities.Company#1]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - entity proxy found in session cache
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.TwoPhaseLoad - done materializing entity [Trion.Census.Service.WCF.BusinessEntities.Dependent#125325]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.TwoPhaseLoad - resolving associations for [Trion.Census.Service.WCF.BusinessEntities.Dependent#125326]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - loading entity: [Trion.Census.Service.WCF.BusinessEntities.Employee#394548]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - entity proxy found in session cache
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - loading entity: [Trion.Census.Service.WCF.BusinessEntities.Company#1]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - entity proxy found in session cache
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.TwoPhaseLoad - done materializing entity [Trion.Census.Service.WCF.BusinessEntities.Dependent#125326]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.TwoPhaseLoad - resolving associations for [Trion.Census.Service.WCF.BusinessEntities.Dependent#125327]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - loading entity: [Trion.Census.Service.WCF.BusinessEntities.Employee#394548]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - entity proxy found in session cache
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - loading entity: [Trion.Census.Service.WCF.BusinessEntities.Company#1]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - entity proxy found in session cache
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.TwoPhaseLoad - done materializing entity [Trion.Census.Service.WCF.BusinessEntities.Dependent#125327]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.TwoPhaseLoad - resolving associations for [Trion.Census.Service.WCF.BusinessEntities.Dependent#125328]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - loading entity: [Trion.Census.Service.WCF.BusinessEntities.Employee#394548]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - entity proxy found in session cache
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - loading entity: [Trion.Census.Service.WCF.BusinessEntities.Company#1]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - entity proxy found in session cache
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.TwoPhaseLoad - done materializing entity [Trion.Census.Service.WCF.BusinessEntities.Dependent#125328]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.TwoPhaseLoad - resolving associations for [Trion.Census.Service.WCF.BusinessEntities.Dependent#125329]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - loading entity: [Trion.Census.Service.WCF.BusinessEntities.Employee#394548]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - entity proxy found in session cache
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - loading entity: [Trion.Census.Service.WCF.BusinessEntities.Company#1]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - entity proxy found in session cache
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.TwoPhaseLoad - done materializing entity [Trion.Census.Service.WCF.BusinessEntities.Dependent#125329]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.TwoPhaseLoad - resolving associations for [Trion.Census.Service.WCF.BusinessEntities.Dependent#125330]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - loading entity: [Trion.Census.Service.WCF.BusinessEntities.Employee#394548]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - entity proxy found in session cache
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - loading entity: [Trion.Census.Service.WCF.BusinessEntities.Company#1]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - entity proxy found in session cache
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.TwoPhaseLoad - done materializing entity [Trion.Census.Service.WCF.BusinessEntities.Dependent#125330]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.TwoPhaseLoad - resolving associations for [Trion.Census.Service.WCF.BusinessEntities.Dependent#125331]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - loading entity: [Trion.Census.Service.WCF.BusinessEntities.Employee#394548]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - entity proxy found in session cache
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - loading entity: [Trion.Census.Service.WCF.BusinessEntities.Company#1]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - entity proxy found in session cache
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.TwoPhaseLoad - done materializing entity [Trion.Census.Service.WCF.BusinessEntities.Dependent#125331]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.TwoPhaseLoad - resolving associations for [Trion.Census.Service.WCF.BusinessEntities.Dependent#125332]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - loading entity: [Trion.Census.Service.WCF.BusinessEntities.Employee#394548]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - entity proxy found in session cache
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - loading entity: [Trion.Census.Service.WCF.BusinessEntities.Company#1]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - entity proxy found in session cache
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.TwoPhaseLoad - done materializing entity [Trion.Census.Service.WCF.BusinessEntities.Dependent#125332]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.TwoPhaseLoad - resolving associations for [Trion.Census.Service.WCF.BusinessEntities.Dependent#125333]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - loading entity: [Trion.Census.Service.WCF.BusinessEntities.Employee#394548]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - entity proxy found in session cache
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - loading entity: [Trion.Census.Service.WCF.BusinessEntities.Company#1]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - entity proxy found in session cache
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.TwoPhaseLoad - done materializing entity [Trion.Census.Service.WCF.BusinessEntities.Dependent#125333]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.TwoPhaseLoad - resolving associations for [Trion.Census.Service.WCF.BusinessEntities.Dependent#125334]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - loading entity: [Trion.Census.Service.WCF.BusinessEntities.Employee#394548]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - entity proxy found in session cache
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - loading entity: [Trion.Census.Service.WCF.BusinessEntities.Company#1]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - entity proxy found in session cache
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.TwoPhaseLoad - done materializing entity [Trion.Census.Service.WCF.BusinessEntities.Dependent#125334]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.TwoPhaseLoad - resolving associations for [Trion.Census.Service.WCF.BusinessEntities.Dependent#125335]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - loading entity: [Trion.Census.Service.WCF.BusinessEntities.Employee#394548]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - entity proxy found in session cache
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - loading entity: [Trion.Census.Service.WCF.BusinessEntities.Company#1]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - entity proxy found in session cache
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.TwoPhaseLoad - done materializing entity [Trion.Census.Service.WCF.BusinessEntities.Dependent#125335]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.LoadContexts - attempting to locate loading collection entry [NHibernate.Engine.CollectionKey] in any result-set context
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.LoadContexts - collection [NHibernate.Engine.CollectionKey] not located in load context
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.CollectionLoadContext - removing collection load entry [NHibernate.Engine.Loading.LoadingCollectionEntry<rs=NHibernate.Driver.NHybridDataReader, coll=[Trion.Census.Service.WCF.BusinessEntities.Coverage.SomeDeps#1304630]>@10b212f]
10:48:59 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.LoadContexts - attempting to locate loading collection entry [NHibernate.Engine.Co

wolli · **Posted:** Tue Mar 18, 2008 2:16 pm

I think the {...} are mandatory. Have you tried:

Code:

<sql-query name="CoveredDependentsQuery">
      <load-collection alias="EOL_DEPENDENT" role="Coverage.SomeDeps"/>
      
      SELECT      {EOL_DEPENDENT.*}
      ...
   </sql-query> 

jbenckert · **Joined:** Tue Mar 18, 2008 11:44 am **Posts:** 5

Wolfgang.

I tried it, same result.

The log still shows that NHibernate is getting the correct data. The property Coverage.SomeDeps is still not getting populated with that data.

Thanks.

wolli · **Posted:** Tue Mar 18, 2008 2:37 pm

Something else you can try. You specifiy an alias name in

<load-collection alias="EOL_DEPENDENT" role="Coverage.SomeDeps"/>

but not in your query. I'm not sure if hibernate automatically generates an alias if you don't specify one. Just to rule that one out:

Code:

<sql-query name="CoveredDependentsQuery">
      <load-collection alias="deps" role="Coverage.SomeDeps" />
      
      SELECT      {deps.*}
      FROM         
         EOL_COVERAGE left join  EOL_DEPENDENT deps 
                    on EOL_COVERAGE.EMPLOYEE_ID = deps.EMPLOYEE_ID

      WHERE EOL_COVERAGE.COVERAGE_ID = :id
   </sql-query> 

jbenckert · **Joined:** Tue Mar 18, 2008 11:44 am **Posts:** 5

I gave it a go. Same result.

wolli · **Posted:** Tue Mar 18, 2008 3:12 pm

What kind of list do you use for SomeDeps ? Just saw your that you call coverage.SomeDeps.Count() in your test case implying, that you use your own list implementation (or do you use the extension mechanism of .Net 3.5 ?). Hibernate relies on IList because it use's it's own list implementation, so maybe you are overwriting the list that hibernate populates.

jbenckert · **Joined:** Tue Mar 18, 2008 11:44 am **Posts:** 5

sorry, should have posted the entity

Code:

public class Coverage
    {

        #region Member variables
        IList<Dependent> _coveredDependents = new List<Dependent>();
        #endregion

        #region Constructors & Finalizers
        #endregion

        #region Nested Enums, Structs, and Classes
        #endregion

        #region Properties
        public virtual BenefitOption Option { get; internal set; }

        /// <summary>
        /// Aka Plan Definition ID
        /// </summary>
        public virtual Int32 ID { get; internal set; }

        public virtual bool BillingIndicator { get; set; }
        public virtual bool PFAOverride { get; set; }
        public virtual string Code { get; internal set; }
        public virtual int MinimumTotalDependents { get; set; }

        public virtual IList<Dependent> SomeDeps
        {
            get { return _coveredDependents; }
            set { _coveredDependents = value; }
        }
        #endregion

        #region Methods
        #endregion

    }

wolli · **Posted:** Tue Mar 18, 2008 3:26 pm

Still don't get it. Where does the Count() method on SomeDeps comes from ? Is that a typo in the post ?

Code:

var coverage = session.Get<Coverage>(Fixtures.CoverageID);
Console.WriteLine(coverage.SomeDeps.Count().ToString());

Since the mapping itself looks good for me, I'll go on with guessing ;-) and ruling out some stuff. Try using a IList instead of IList<Dependant> or specify generic="true" in the mapping. Maybe something goes wrong when hibernate tries to set the collection.

jbenckert · **Joined:** Tue Mar 18, 2008 11:44 am **Posts:** 5

something does seem to be going wrong when setting the collection.

I tried all kinds of different implementations of the Dependents collection (ISet, IList, IList<Dependent>) and none of that helped.

I think I must be missing something small/stupid/fundamental in order to get this to work, so I've dumbed down the entire thing into a small sandbox project and found some interesting things. I've got a Person and Addresses like the examples used in the documentation. I am able to make the association of person to addresses using this example (getting better because the other returned no results). However, it's only returning one record when there are two associated address records in the database.

Note the log again is showing that two records are being retrieved from the database and that nHibernate is instantiating two objects but the following line in bold confuses me a bit

10:35:31 [TestRunnerThread] DEBUG NHibernate.Engine.TwoPhaseLoad - resolving associations for [Objects.Address#1]
10:35:31 [TestRunnerThread] DEBUG NHibernate.Engine.TwoPhaseLoad - done materializing entity [Objects.Address#1]
10:35:31 [TestRunnerThread] DEBUG NHibernate.Engine.TwoPhaseLoad - resolving associations for [Objects.Address#2]
10:35:31 [TestRunnerThread] DEBUG NHibernate.Engine.TwoPhaseLoad - done materializing entity [Objects.Address#2]
10:35:31 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.LoadContexts - attempting to locate loading collection entry [NHibernate.Engine.CollectionKey] in any result-set context
10:35:31 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.LoadContexts - collection [NHibernate.Engine.CollectionKey] not located in load context
10:35:31 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.CollectionLoadContext - removing collection load entry [NHibernate.Engine.Loading.LoadingCollectionEntry<rs=NHibernate.Driver.NHybridDataReader, coll=[Objects.Person.Addresses#1]>@315cfde]
10:35:31 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.LoadContexts - attempting to locate loading collection entry [NHibernate.Engine.CollectionKey] in any result-set context
10:35:31 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.LoadContexts - collection [NHibernate.Engine.CollectionKey] not located in load context
10:35:31 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.CollectionLoadContext - removing collection load entry [NHibernate.Engine.Loading.LoadingCollectionEntry<rs=NHibernate.Driver.NHybridDataReader, coll=[Objects.Person.Addresses#2]>@1214cb8]
10:35:31 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.CollectionLoadContext - 2 collections were found in result set for role: Objects.Person.Addresses

Why does nHibernate state that are two collections?? It should be two entities loaded into one collection.

I realize that I don't need to use named queries to solve the problem in this dumbed down solution. I do, however, need to use the named queries in the 'real' prototype. Am I missing something in my setup here or am I just going about this the wrong way?

Any help is greatly appreciated.

Find all of the relevant code below.

Entities:

Code:

public class Person
    {
        #region member variables
        IList<Address> _addresses;
        #endregion

        #region Properties
        public virtual int ID { get; set; }

        public virtual string FirstName { get; set; }
        public virtual string LastName { get; set; }

        public virtual IList<Address> Addresses
        {
            get { return _addresses; }
            set { _addresses = value; }
        }

        public override string ToString()
        {
            StringBuilder sb = new StringBuilder();
            
            sb.Append("FirstName: ");
            sb.Append(FirstName);
            sb.Append(", ");
            sb.Append("LastName: ");
            sb.AppendLine(LastName);
            
            foreach(Address add in Addresses)
            {
                sb.AppendLine();
                sb.Append(add);
            }

            return sb.ToString();
        }
        #endregion
    }

    public class Address
    {
        #region Properties
        public virtual int ID { get; set; }
        public virtual string Street { get; set; }
        public virtual string City { get; set; }
        public virtual string State { get; set; }
        public virtual string Zip { get; set; }

        #endregion

        #region Methods
        public override string ToString()
        {
            StringBuilder sb = new StringBuilder();

            sb.AppendLine(Street);
            sb.Append(City);
            sb.Append(State);
            sb.Append(", ");
            sb.AppendLine(Zip);

            return sb.ToString();
        }
        #endregion
    }

Mappings:

Code:

<hibernate-mapping xmlns="urn:nhibernate-mapping-2.2" namespace="Objects" assembly="Objects">
   <class name="Person" table="Person">
      <id name="ID" type="Int32" unsaved-value="null" column="PersonID">
         <generator class="native"/>
      </id>
      <property name ="FirstName" column="FirstName" />
      <property name="LastName" column="LastName" />

      <bag name="Addresses" lazy="false" inverse="false" cascade="all" access="property" generic="true">
         <key column="AddressID"/>
         <one-to-many class="Address" />
         <loader query-ref="AddressQuery"/>
      </bag>
   </class>
   <sql-query name="AddressQuery">
      <load-collection alias="adds" role="Person.Addresses" />
      
      SELECT      adds.AddressID, adds.Street, adds.City, adds.State, adds.Zip

      FROM         Address adds 

      WHERE adds.PersonID = :id
   </sql-query>
</hibernate-mapping>

<hibernate-mapping xmlns="urn:nhibernate-mapping-2.2" namespace="Objects" assembly="Objects">
   <class name="Address">
      <id name="ID" type="Int32" unsaved-value="null" column="AddressID">
         <generator class="native"/>
      </id>
      <property name ="Street" column="Street" />
      <property name="City" column="City" />
      <property name="State" column="State" />
      <property name="Zip" column="Zip" />
   </class>
</hibernate-mapping>

Test Code::

Code:

[TestFixture]
    public class SqlTests
    {
        #region Properties
        public ISessionFactory SessionFactory { get; set; }
        #endregion

        #region Methods
        #region Setup/TearDown
        [TestFixtureSetUp]
        public void Setup()
        {
            log4net.Config.XmlConfigurator.Configure();
            NHibernate.Cfg.Configuration cfg = new NHibernate.Cfg.Configuration();
            cfg.Configure();
            SessionFactory = cfg.BuildSessionFactory();
        }

        [TestFixtureTearDown]
        public void TearDown()
        {
            SessionFactory.Dispose();
        }
        #endregion

        #region Tests
        [Test]
        public void TestPersonFunctionality()
        {
            using (ISession session = SessionFactory.OpenSession())
            {
                Person person = session.Get<Person>(1);
                Console.WriteLine(person);
            }
        }
        #endregion
        #endregion
    }

Log:

Code:

35:26 [TestRunnerThread] INFO  NHibernate.Cfg.Environment - NHibernate 2.0.0.1001 (2.0.0.1001)
35:26 [TestRunnerThread] INFO  NHibernate.Cfg.Environment - hibernate-configuration section not found in application configuration file
35:26 [TestRunnerThread] INFO  NHibernate.Cfg.Environment - Bytecode provider name : lcg
35:26 [TestRunnerThread] INFO  NHibernate.Cfg.Environment - Using reflection optimizer
35:26 [TestRunnerThread] DEBUG NHibernate.Cfg.Configuration - show_sql=true
35:26 [TestRunnerThread] DEBUG NHibernate.Cfg.Configuration - dialect=NHibernate.Dialect.MsSql2005Dialect
35:26 [TestRunnerThread] DEBUG NHibernate.Cfg.Configuration - connection.driver_class=NHibernate.Driver.SqlClientDriver
35:26 [TestRunnerThread] DEBUG NHibernate.Cfg.Configuration - connection.connection_string_name=localMachine
35:26 [TestRunnerThread] DEBUG NHibernate.Cfg.Configuration - <-Objects
35:26 [TestRunnerThread] INFO  NHibernate.Cfg.Configuration - Searching for mapped documents in assembly: Objects
35:26 [TestRunnerThread] INFO  NHibernate.Cfg.Configuration - Mapping resource: Objects.Model.Person.hbm.xml
35:26 [TestRunnerThread] INFO  NHibernate.Dialect.Dialect - Using dialect: NHibernate.Dialect.MsSql2005Dialect
35:30 [TestRunnerThread] INFO  NHibernate.Cfg.XmlHbmBinding.Binder - Mapping class: Objects.Person -> Person
35:30 [TestRunnerThread] DEBUG NHibernate.Cfg.XmlHbmBinding.Binder - Mapped property: ID -> PersonID, type: Int32
35:30 [TestRunnerThread] DEBUG NHibernate.Cfg.XmlHbmBinding.Binder - Mapped property: FirstName -> FirstName, type: String
35:30 [TestRunnerThread] DEBUG NHibernate.Cfg.XmlHbmBinding.Binder - Mapped property: LastName -> LastName, type: String
35:30 [TestRunnerThread] DEBUG NHibernate.Cfg.XmlHbmBinding.Binder - Mapped property: Addresses, type: IList`1
35:30 [TestRunnerThread] INFO  NHibernate.Cfg.Configuration - Mapping resource: Objects.Model.Address.hbm.xml
35:30 [TestRunnerThread] INFO  NHibernate.Dialect.Dialect - Using dialect: NHibernate.Dialect.MsSql2005Dialect
35:30 [TestRunnerThread] INFO  NHibernate.Cfg.XmlHbmBinding.Binder - Mapping class: Objects.Address -> Address
35:30 [TestRunnerThread] DEBUG NHibernate.Cfg.XmlHbmBinding.Binder - Mapped property: ID -> AddressID, type: Int32
35:30 [TestRunnerThread] DEBUG NHibernate.Cfg.XmlHbmBinding.Binder - Mapped property: Street -> Street, type: String
35:30 [TestRunnerThread] DEBUG NHibernate.Cfg.XmlHbmBinding.Binder - Mapped property: City -> City, type: String
35:30 [TestRunnerThread] DEBUG NHibernate.Cfg.XmlHbmBinding.Binder - Mapped property: State -> State, type: String
35:30 [TestRunnerThread] DEBUG NHibernate.Cfg.XmlHbmBinding.Binder - Mapped property: Zip -> Zip, type: String
35:30 [TestRunnerThread] DEBUG NHibernate.Cfg.Configuration - properties: System.Collections.Generic.Dictionary`2[System.String,System.String]
35:30 [TestRunnerThread] INFO  NHibernate.Cfg.Configuration - checking mappings queue
35:30 [TestRunnerThread] INFO  NHibernate.Cfg.Configuration - processing one-to-many association mappings
35:30 [TestRunnerThread] DEBUG NHibernate.Cfg.XmlHbmBinding.Binder - Second pass for collection: Objects.Person.Addresses
35:30 [TestRunnerThread] INFO  NHibernate.Cfg.XmlHbmBinding.Binder - mapping collection: Objects.Person.Addresses -> Address
35:30 [TestRunnerThread] DEBUG NHibernate.Cfg.XmlHbmBinding.Binder - Mapped collection key: AddressID, one-to-many: Address
35:30 [TestRunnerThread] DEBUG NHibernate.Cfg.XmlHbmBinding.Binder - Named SQL query: AddressQuery -> SELECT      adds.AddressID, adds.Street, adds.City, adds.State, adds.Zip

      FROM         Address adds 

      WHERE adds.PersonID = :id
35:30 [TestRunnerThread] INFO  NHibernate.Cfg.Configuration - processing one-to-one association property references
35:30 [TestRunnerThread] INFO  NHibernate.Cfg.Configuration - processing foreign key constraints
35:30 [TestRunnerThread] DEBUG NHibernate.Cfg.Configuration - resolving reference to class: Person
35:30 [TestRunnerThread] DEBUG NHibernate.Util.JoinedEnumerable - running JoinedEnumerable.Dispose()
35:30 [TestRunnerThread] DEBUG NHibernate.Util.JoinedEnumerable - running JoinedEnumerable.Dispose()
35:30 [TestRunnerThread] INFO  NHibernate.Dialect.Dialect - Using dialect: NHibernate.Dialect.MsSql2005Dialect
35:30 [TestRunnerThread] INFO  NHibernate.Connection.ConnectionProvider - Configuring ConnectionProvider
35:30 [TestRunnerThread] INFO  NHibernate.Cfg.SettingsFactory - Transaction factory: NHibernate.Transaction.AdoNetTransactionFactory
35:30 [TestRunnerThread] INFO  NHibernate.Cfg.SettingsFactory - Optimize cache for minimal puts: False
35:30 [TestRunnerThread] INFO  NHibernate.Cfg.SettingsFactory - Connection release mode: auto
35:30 [TestRunnerThread] INFO  NHibernate.Cfg.SettingsFactory - echoing all SQL to stdout
35:30 [TestRunnerThread] INFO  NHibernate.Cfg.SettingsFactory - Statistics: disabled
35:30 [TestRunnerThread] INFO  NHibernate.Cfg.SettingsFactory - Query translator: NHibernate.Hql.Classic.ClassicQueryTranslatorFactory
35:30 [TestRunnerThread] INFO  NHibernate.Cfg.SettingsFactory - Query language substitutions: {}
35:30 [TestRunnerThread] INFO  NHibernate.Cfg.SettingsFactory - cache provider: NHibernate.Cache.NoCacheProvider, NHibernate, Version=2.0.0.1001, Culture=neutral, PublicKeyToken=aa95f207798dfdb4
35:30 [TestRunnerThread] DEBUG NHibernate.Cfg.SettingsFactory - Wrap result sets: disabled
35:30 [TestRunnerThread] INFO  NHibernate.Cfg.SettingsFactory - Named query checking : enabled
35:30 [TestRunnerThread] INFO  NHibernate.Impl.SessionFactoryImpl - building session factory
35:30 [TestRunnerThread] DEBUG NHibernate.Impl.SessionFactoryImpl - instantiating session factory with properties: {use_reflection_optimizer=True, show_sql=true, dialect=NHibernate.Dialect.MsSql2005Dialect, connection.driver_class=NHibernate.Driver.SqlClientDriver, connection.connection_string_name=localMachine}
35:30 [TestRunnerThread] DEBUG NHibernate.Util.JoinedEnumerable - running JoinedEnumerable.Dispose()
35:30 [TestRunnerThread] DEBUG NHibernate.Util.JoinedEnumerable - running JoinedEnumerable.Dispose()
35:30 [TestRunnerThread] DEBUG NHibernate.Util.JoinedEnumerable - running JoinedEnumerable.Dispose()
35:30 [TestRunnerThread] DEBUG NHibernate.Util.JoinedEnumerable - running JoinedEnumerable.Dispose()
35:30 [TestRunnerThread] DEBUG NHibernate.Util.JoinedEnumerable - running JoinedEnumerable.Dispose()
35:30 [TestRunnerThread] DEBUG NHibernate.Util.JoinedEnumerable - running JoinedEnumerable.Dispose()
35:31 [TestRunnerThread] DEBUG NHibernate.Util.JoinedEnumerable - running JoinedEnumerable.Dispose()
35:31 [TestRunnerThread] DEBUG NHibernate.Util.JoinedEnumerable - running JoinedEnumerable.Dispose()
35:31 [TestRunnerThread] DEBUG NHibernate.Util.JoinedEnumerable - running JoinedEnumerable.Dispose()
35:31 [TestRunnerThread] DEBUG NHibernate.Util.JoinedEnumerable - running JoinedEnumerable.Dispose()
35:31 [TestRunnerThread] DEBUG NHibernate.Util.JoinedEnumerable - running JoinedEnumerable.Dispose()
35:31 [TestRunnerThread] DEBUG NHibernate.Util.JoinedEnumerable - running JoinedEnumerable.Dispose()
35:31 [TestRunnerThread] DEBUG NHibernate.Util.JoinedEnumerable - running JoinedEnumerable.Dispose()
35:31 [TestRunnerThread] DEBUG NHibernate.Util.JoinedEnumerable - running JoinedEnumerable.Dispose()
35:31 [TestRunnerThread] DEBUG NHibernate.Util.JoinedEnumerable - running JoinedEnumerable.Dispose()
35:31 [TestRunnerThread] DEBUG NHibernate.Util.JoinedEnumerable - running JoinedEnumerable.Dispose()
35:31 [TestRunnerThread] DEBUG NHibernate.Util.JoinedEnumerable - running JoinedEnumerable.Dispose()
35:31 [TestRunnerThread] DEBUG NHibernate.Util.JoinedEnumerable - running JoinedEnumerable.Dispose()
35:31 [TestRunnerThread] DEBUG NHibernate.Util.JoinedEnumerable - running JoinedEnumerable.Dispose()
35:31 [TestRunnerThread] DEBUG NHibernate.Util.JoinedEnumerable - running JoinedEnumerable.Dispose()
35:31 [TestRunnerThread] DEBUG NHibernate.Util.JoinedEnumerable - running JoinedEnumerable.Dispose()
35:31 [TestRunnerThread] DEBUG NHibernate.Util.JoinedEnumerable - running JoinedEnumerable.Dispose()
35:31 [TestRunnerThread] DEBUG NHibernate.Util.JoinedEnumerable - running JoinedEnumerable.Dispose()
35:31 [TestRunnerThread] DEBUG NHibernate.Util.JoinedEnumerable - running JoinedEnumerable.Dispose()
35:31 [TestRunnerThread] DEBUG NHibernate.Util.JoinedEnumerable - running JoinedEnumerable.Dispose()
35:31 [TestRunnerThread] DEBUG NHibernate.Util.JoinedEnumerable - running JoinedEnumerable.Dispose()
35:31 [TestRunnerThread] DEBUG NHibernate.Util.JoinedEnumerable - running JoinedEnumerable.Dispose()
35:31 [TestRunnerThread] DEBUG NHibernate.Util.JoinedEnumerable - running JoinedEnumerable.Dispose()
35:31 [TestRunnerThread] DEBUG NHibernate.Util.JoinedEnumerable - running JoinedEnumerable.Dispose()
35:31 [TestRunnerThread] DEBUG NHibernate.Util.JoinedEnumerable - running JoinedEnumerable.Dispose()
35:31 [TestRunnerThread] DEBUG NHibernate.Util.JoinedEnumerable - running JoinedEnumerable.Dispose()
35:31 [TestRunnerThread] DEBUG NHibernate.Util.JoinedEnumerable - running JoinedEnumerable.Dispose()
35:31 [TestRunnerThread] DEBUG NHibernate.Util.JoinedEnumerable - running JoinedEnumerable.Dispose()
35:31 [TestRunnerThread] DEBUG NHibernate.Util.JoinedEnumerable - running JoinedEnumerable.Dispose()
35:31 [TestRunnerThread] DEBUG NHibernate.Util.JoinedEnumerable - running JoinedEnumerable.Dispose()
35:31 [TestRunnerThread] DEBUG NHibernate.Util.JoinedEnumerable - running JoinedEnumerable.Dispose()
35:31 [TestRunnerThread] DEBUG NHibernate.Util.JoinedEnumerable - running JoinedEnumerable.Dispose()
35:31 [TestRunnerThread] DEBUG NHibernate.Util.JoinedEnumerable - running JoinedEnumerable.Dispose()
35:31 [TestRunnerThread] DEBUG NHibernate.Util.JoinedEnumerable - running JoinedEnumerable.Dispose()
35:31 [TestRunnerThread] DEBUG NHibernate.Util.JoinedEnumerable - running JoinedEnumerable.Dispose()
35:31 [TestRunnerThread] DEBUG NHibernate.Util.JoinedEnumerable - running JoinedEnumerable.Dispose()
35:31 [TestRunnerThread] DEBUG NHibernate.Util.JoinedEnumerable - running JoinedEnumerable.Dispose()
35:31 [TestRunnerThread] DEBUG NHibernate.Util.JoinedEnumerable - running JoinedEnumerable.Dispose()
35:31 [TestRunnerThread] DEBUG NHibernate.Util.JoinedEnumerable - running JoinedEnumerable.Dispose()
35:31 [TestRunnerThread] DEBUG NHibernate.Util.JoinedEnumerable - running JoinedEnumerable.Dispose()
35:31 [TestRunnerThread] DEBUG NHibernate.Util.JoinedEnumerable - running JoinedEnumerable.Dispose()
35:31 [TestRunnerThread] DEBUG NHibernate.Util.JoinedEnumerable - running JoinedEnumerable.Dispose()
35:31 [TestRunnerThread] DEBUG NHibernate.Util.JoinedEnumerable - running JoinedEnumerable.Dispose()
35:31 [TestRunnerThread] DEBUG NHibernate.Util.JoinedEnumerable - running JoinedEnumerable.Dispose()
35:31 [TestRunnerThread] DEBUG NHibernate.Util.JoinedEnumerable - running JoinedEnumerable.Dispose()
35:31 [TestRunnerThread] DEBUG NHibernate.Impl.SessionFactoryObjectFactory - initializing class SessionFactoryObjectFactory
35:31 [TestRunnerThread] DEBUG NHibernate.Impl.SessionFactoryObjectFactory - registered: 5a16be806eae4b58aa89be32e7a5ea1b(unnamed)
35:31 [TestRunnerThread] INFO  NHibernate.Impl.SessionFactoryObjectFactory - no name configured
35:31 [TestRunnerThread] DEBUG NHibernate.Loader.Entity.AbstractEntityLoader - Static select for entity Objects.Address: SELECT address0_.AddressID as AddressID1_0_, address0_.Street as Street1_0_, address0_.City as City1_0_, address0_.State as State1_0_, address0_.Zip as Zip1_0_ FROM Address address0_ WHERE address0_.AddressID=?
35:31 [TestRunnerThread] DEBUG NHibernate.Loader.Entity.AbstractEntityLoader - Static select for entity Objects.Address: SELECT address0_.AddressID as AddressID1_0_, address0_.Street as Street1_0_, address0_.City as City1_0_, address0_.State as State1_0_, address0_.Zip as Zip1_0_ FROM Address address0_ WHERE address0_.AddressID=?
35:31 [TestRunnerThread] DEBUG NHibernate.Loader.Entity.AbstractEntityLoader - Static select for entity Objects.Address: SELECT address0_.AddressID as AddressID1_0_, address0_.Street as Street1_0_, address0_.City as City1_0_, address0_.State as State1_0_, address0_.Zip as Zip1_0_ FROM Address address0_ with (updlock, rowlock) WHERE address0_.AddressID=?
35:31 [TestRunnerThread] DEBUG NHibernate.Loader.Entity.AbstractEntityLoader - Static select for entity Objects.Address: SELECT address0_.AddressID as AddressID1_0_, address0_.Street as Street1_0_, address0_.City as City1_0_, address0_.State as State1_0_, address0_.Zip as Zip1_0_ FROM Address address0_ with (updlock, rowlock) WHERE address0_.AddressID=?
35:31 [TestRunnerThread] DEBUG NHibernate.Loader.Entity.AbstractEntityLoader - Static select for entity Objects.Person: SELECT person0_.PersonID as PersonID0_0_, person0_.FirstName as FirstName0_0_, person0_.LastName as LastName0_0_ FROM Person person0_ WHERE person0_.PersonID=?
35:31 [TestRunnerThread] DEBUG NHibernate.Loader.Entity.AbstractEntityLoader - Static select for entity Objects.Person: SELECT person0_.PersonID as PersonID0_0_, person0_.FirstName as FirstName0_0_, person0_.LastName as LastName0_0_ FROM Person person0_ WHERE person0_.PersonID=?
35:31 [TestRunnerThread] DEBUG NHibernate.Loader.Entity.AbstractEntityLoader - Static select for entity Objects.Person: SELECT person0_.PersonID as PersonID0_0_, person0_.FirstName as FirstName0_0_, person0_.LastName as LastName0_0_ FROM Person person0_ with (updlock, rowlock) WHERE person0_.PersonID=?
35:31 [TestRunnerThread] DEBUG NHibernate.Loader.Entity.AbstractEntityLoader - Static select for entity Objects.Person: SELECT person0_.PersonID as PersonID0_0_, person0_.FirstName as FirstName0_0_, person0_.LastName as LastName0_0_ FROM Person person0_ with (updlock, rowlock) WHERE person0_.PersonID=?
35:31 [TestRunnerThread] DEBUG NHibernate.Impl.SessionFactoryImpl - Instantiated session factory
35:31 [TestRunnerThread] DEBUG NHibernate.Impl.SessionFactoryImpl - Checking 0 named HQL queries
35:31 [TestRunnerThread] DEBUG NHibernate.Impl.SessionFactoryImpl - Checking 1 named SQL queries
35:31 [TestRunnerThread] DEBUG NHibernate.Impl.SessionFactoryImpl - Checking named SQL query: AddressQuery
35:31 [TestRunnerThread] DEBUG NHibernate.Engine.Query.QueryPlanCache - unable to locate native-sql query plan in cache; generating (SELECT      adds.AddressID, adds.Street, adds.City, adds.State, adds.Zip

      FROM         Address adds 

      WHERE adds.PersonID = :id)
35:31 [TestRunnerThread] DEBUG NHibernate.Loader.Custom.Sql.SQLCustomQuery - starting processing of sql query [SELECT      adds.AddressID, adds.Street, adds.City, adds.State, adds.Zip

      FROM         Address adds 

      WHERE adds.PersonID = :id]
35:31 [TestRunnerThread] DEBUG NHibernate.Loader.Custom.Sql.SQLQueryReturnProcessor - mapping alias [adds] to collection-suffix [0__]
35:31 [TestRunnerThread] DEBUG NHibernate.Loader.Custom.Sql.SQLQueryReturnProcessor - mapping alias [adds] to entity-suffix [0_]
35:31 [TestRunnerThread] DEBUG NHibernate.Impl.SessionImpl - opened session
35:31 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - loading entity: [Objects.Person#1]
35:31 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - attempting to resolve: [Objects.Person#1]
35:31 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - object not resolved in any cache: [Objects.Person#1]
35:31 [TestRunnerThread] DEBUG NHibernate.Persister.Entity.AbstractEntityPersister - Fetching entity: [Objects.Person#1]
35:31 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - loading entity: [Objects.Person#1]
35:31 [TestRunnerThread] DEBUG NHibernate.AdoNet.BatcherImpl - Opened new IDbCommand, open IDbCommands: 1
35:31 [TestRunnerThread] DEBUG NHibernate.AdoNet.BatcherImpl - Building an IDbCommand object for the SqlString: SELECT person0_.PersonID as PersonID0_0_, person0_.FirstName as FirstName0_0_, person0_.LastName as LastName0_0_ FROM Person person0_ WHERE person0_.PersonID=?
35:31 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - binding '1' to parameter: 0
35:31 [TestRunnerThread] INFO  NHibernate.Loader.Loader - SELECT person0_.PersonID as PersonID0_0_, person0_.FirstName as FirstName0_0_, person0_.LastName as LastName0_0_ FROM Person person0_ WHERE person0_.PersonID=@p0
35:31 [TestRunnerThread] DEBUG NHibernate.SQL - SELECT person0_.PersonID as PersonID0_0_, person0_.FirstName as FirstName0_0_, person0_.LastName as LastName0_0_ FROM Person person0_ WHERE person0_.PersonID=@p0; @p0 = '1'
35:31 [TestRunnerThread] DEBUG NHibernate.Connection.DriverConnectionProvider - Obtaining IDbConnection from Driver
35:31 [TestRunnerThread] DEBUG NHibernate.AdoNet.BatcherImpl - Opened IDataReader, open IDataReaders: 1
35:31 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - processing result set
35:31 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - result set row: 0
35:31 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - result row: 1
35:31 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - Initializing object from DataReader: [Objects.Person#1]
35:31 [TestRunnerThread] DEBUG NHibernate.Persister.Entity.AbstractEntityPersister - Hydrating entity: Objects.Person#1
35:31 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning 'Joe' as column: FirstName0_0_
35:31 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning 'Benckert' as column: LastName0_0_
35:31 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - done processing result set (1 rows)
35:31 [TestRunnerThread] DEBUG NHibernate.Driver.NHybridDataReader - running NHybridDataReader.Dispose()
35:31 [TestRunnerThread] DEBUG NHibernate.AdoNet.BatcherImpl - Closed IDataReader, open IDataReaders :0
35:31 [TestRunnerThread] DEBUG NHibernate.AdoNet.BatcherImpl - Closed IDbCommand, open IDbCommands: 0
35:31 [TestRunnerThread] DEBUG NHibernate.AdoNet.ConnectionManager - aggressively releasing database connection
35:31 [TestRunnerThread] DEBUG NHibernate.Connection.ConnectionProvider - Closing connection
35:31 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - total objects hydrated: 1
35:31 [TestRunnerThread] DEBUG NHibernate.Engine.TwoPhaseLoad - resolving associations for [Objects.Person#1]
35:31 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.LoadContexts - creating collection wrapper:[Objects.Person.Addresses#1]
35:31 [TestRunnerThread] DEBUG NHibernate.Engine.TwoPhaseLoad - done materializing entity [Objects.Person#1]
35:31 [TestRunnerThread] DEBUG NHibernate.Engine.StatefulPersistenceContext - initializing non-lazy collections
35:31 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultInitializeCollectionEventListener - initializing collection [Objects.Person.Addresses#1]
35:31 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultInitializeCollectionEventListener - checking second-level cache
35:31 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultInitializeCollectionEventListener - collection not cached
35:31 [TestRunnerThread] DEBUG NHibernate.Persister.Collection.NamedQueryCollectionInitializer - initializing collection: Objects.Person.Addresses using named query: AddressQuery
35:31 [TestRunnerThread] DEBUG NHibernate.Loader.Custom.Sql.SQLCustomQuery - starting processing of sql query [SELECT      adds.AddressID, adds.Street, adds.City, adds.State, adds.Zip

      FROM         Address adds 

      WHERE adds.PersonID = :id]
35:31 [TestRunnerThread] DEBUG NHibernate.Loader.Custom.Sql.SQLQueryReturnProcessor - mapping alias [adds] to collection-suffix [0__]
35:31 [TestRunnerThread] DEBUG NHibernate.Loader.Custom.Sql.SQLQueryReturnProcessor - mapping alias [adds] to entity-suffix [0_]
35:31 [TestRunnerThread] DEBUG NHibernate.AdoNet.BatcherImpl - Opened new IDbCommand, open IDbCommands: 1
35:31 [TestRunnerThread] DEBUG NHibernate.AdoNet.BatcherImpl - Building an IDbCommand object for the SqlString: SELECT      adds.AddressID, adds.Street, adds.City, adds.State, adds.Zip

      FROM         Address adds 

      WHERE adds.PersonID = ?
35:31 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - BindNamedParameters() 1 -> id [0]
35:31 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - binding '1' to parameter: 0
35:31 [TestRunnerThread] INFO  NHibernate.Loader.Loader - SELECT      adds.AddressID, adds.Street, adds.City, adds.State, adds.Zip

      FROM         Address adds 

      WHERE adds.PersonID = @p0
35:31 [TestRunnerThread] DEBUG NHibernate.SQL - SELECT      adds.AddressID, adds.Street, adds.City, adds.State, adds.Zip

      FROM         Address adds 

      WHERE adds.PersonID = @p0; @p0 = '1'
35:31 [TestRunnerThread] DEBUG NHibernate.Connection.DriverConnectionProvider - Obtaining IDbConnection from Driver
35:31 [TestRunnerThread] DEBUG NHibernate.AdoNet.BatcherImpl - Opened IDataReader, open IDataReaders: 1
35:31 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - result set contains (possibly empty) collection: [Objects.Person.Addresses#1]
35:31 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.LoadContexts - constructing collection load context for result set [NHibernate.Driver.NHybridDataReader]
35:31 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.CollectionLoadContext - starting attempt to find loading collection [[Objects.Person.Addresses#1]]
35:31 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.CollectionLoadContext - collection not yet initialized; initializing
35:31 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - processing result set
35:31 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - result set row: 0
35:31 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '1' as column: AddressID
35:31 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - result row: 1
35:31 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - Initializing object from DataReader: [Objects.Address#1]
35:31 [TestRunnerThread] DEBUG NHibernate.Persister.Entity.AbstractEntityPersister - Hydrating entity: Objects.Address#1
35:31 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning '2300 Renaissance Blvd' as column: Street
35:31 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning 'King of Prussia' as column: City
35:31 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning 'PA' as column: State
35:31 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning '19406' as column: Zip
35:31 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '1' as column: AddressID
35:31 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - found row of collection: [Objects.Person.Addresses#1]
35:31 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.CollectionLoadContext - starting attempt to find loading collection [[Objects.Person.Addresses#1]]
35:31 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.LoadContexts - attempting to locate loading collection entry [NHibernate.Engine.CollectionKey] in any result-set context
35:31 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.LoadContexts - collection [NHibernate.Engine.CollectionKey] not located in load context
35:31 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.CollectionLoadContext - found loading collection bound to current result set processing; reading row
35:31 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '1' as column: AddressID
35:31 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - loading entity: [Objects.Address#1]
35:31 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - attempting to resolve: [Objects.Address#1]
35:31 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - resolved object in session cache: [Objects.Address#1]
35:31 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - result set row: 1
35:31 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '2' as column: AddressID
35:31 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - result row: 2
35:31 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - Initializing object from DataReader: [Objects.Address#2]
35:31 [TestRunnerThread] DEBUG NHibernate.Persister.Entity.AbstractEntityPersister - Hydrating entity: Objects.Address#2
35:31 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning '102 Carriage Way' as column: Street
35:31 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning 'Deptford' as column: City
35:31 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning 'NJ' as column: State
35:31 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning '08096' as column: Zip
35:31 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '2' as column: AddressID
35:31 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - found row of collection: [Objects.Person.Addresses#2]
35:31 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.CollectionLoadContext - starting attempt to find loading collection [[Objects.Person.Addresses#2]]
35:31 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.LoadContexts - attempting to locate loading collection entry [NHibernate.Engine.CollectionKey] in any result-set context
35:31 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.LoadContexts - collection [NHibernate.Engine.CollectionKey] located in load context
35:31 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.CollectionLoadContext - instantiating new collection [key=2, rs=NHibernate.Driver.NHybridDataReader]
35:31 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '2' as column: AddressID
35:31 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - loading entity: [Objects.Address#2]
35:31 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - attempting to resolve: [Objects.Address#2]
35:31 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultLoadEventListener - resolved object in session cache: [Objects.Address#2]
35:31 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - done processing result set (2 rows)
35:31 [TestRunnerThread] DEBUG NHibernate.Driver.NHybridDataReader - running NHybridDataReader.Dispose()
35:31 [TestRunnerThread] DEBUG NHibernate.AdoNet.BatcherImpl - Closed IDataReader, open IDataReaders :0
35:31 [TestRunnerThread] DEBUG NHibernate.AdoNet.BatcherImpl - Closed IDbCommand, open IDbCommands: 0
35:31 [TestRunnerThread] DEBUG NHibernate.AdoNet.ConnectionManager - aggressively releasing database connection
35:31 [TestRunnerThread] DEBUG NHibernate.Connection.ConnectionProvider - Closing connection
35:31 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - total objects hydrated: 2
35:31 [TestRunnerThread] DEBUG NHibernate.Engine.TwoPhaseLoad - resolving associations for [Objects.Address#1]
35:31 [TestRunnerThread] DEBUG NHibernate.Engine.TwoPhaseLoad - done materializing entity [Objects.Address#1]
35:31 [TestRunnerThread] DEBUG NHibernate.Engine.TwoPhaseLoad - resolving associations for [Objects.Address#2]
35:31 [TestRunnerThread] DEBUG NHibernate.Engine.TwoPhaseLoad - done materializing entity [Objects.Address#2]
35:31 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.LoadContexts - attempting to locate loading collection entry [NHibernate.Engine.CollectionKey] in any result-set context
35:31 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.LoadContexts - collection [NHibernate.Engine.CollectionKey] not located in load context
35:31 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.CollectionLoadContext - removing collection load entry [NHibernate.Engine.Loading.LoadingCollectionEntry<rs=NHibernate.Driver.NHybridDataReader, coll=[Objects.Person.Addresses#1]>@315cfde]
35:31 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.LoadContexts - attempting to locate loading collection entry [NHibernate.Engine.CollectionKey] in any result-set context
35:31 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.LoadContexts - collection [NHibernate.Engine.CollectionKey] not located in load context
35:31 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.CollectionLoadContext - removing collection load entry [NHibernate.Engine.Loading.LoadingCollectionEntry<rs=NHibernate.Driver.NHybridDataReader, coll=[Objects.Person.Addresses#2]>@1214cb8]
35:31 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.CollectionLoadContext - 2 collections were found in result set for role: Objects.Person.Addresses
35:31 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.CollectionLoadContext - ending loading collection [NHibernate.Engine.Loading.LoadingCollectionEntry<rs=NHibernate.Driver.NHybridDataReader, coll=[Objects.Person.Addresses#1]>@315cfde]
35:31 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.CollectionLoadContext - collection fully initialized: [Objects.Person.Addresses#1]
35:31 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.CollectionLoadContext - ending loading collection [NHibernate.Engine.Loading.LoadingCollectionEntry<rs=NHibernate.Driver.NHybridDataReader, coll=[Objects.Person.Addresses#2]>@1214cb8]
35:31 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.CollectionLoadContext - collection fully initialized: [Objects.Person.Addresses#2]
35:31 [TestRunnerThread] DEBUG NHibernate.Engine.Loading.CollectionLoadContext - 2 collections initialized for role: Objects.Person.Addresses
35:31 [TestRunnerThread] DEBUG NHibernate.AdoNet.ConnectionManager - after autocommit
35:31 [TestRunnerThread] DEBUG NHibernate.Impl.SessionImpl - transaction completion
35:31 [TestRunnerThread] DEBUG NHibernate.AdoNet.ConnectionManager - aggressively releasing database connection
35:31 [TestRunnerThread] DEBUG NHibernate.Event.Default.DefaultInitializeCollectionEventListener - collection initialized
35:31 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - done entity load
35:31 [TestRunnerThread] DEBUG NHibernate.AdoNet.ConnectionManager - after autocommit
35:31 [TestRunnerThread] DEBUG NHibernate.Impl.SessionImpl - transaction completion
35:31 [TestRunnerThread] DEBUG NHibernate.AdoNet.ConnectionManager - aggressively releasing database connection
35:31 [TestRunnerThread] DEBUG NHibernate.Impl.SessionImpl - running ISession.Dispose()
35:31 [TestRunnerThread] DEBUG NHibernate.Impl.SessionImpl - closing session
35:31 [TestRunnerThread] DEBUG NHibernate.AdoNet.BatcherImpl - running BatcherImpl.Dispose(true)
35:31 [TestRunnerThread] INFO  NHibernate.Impl.SessionFactoryImpl - Closing
35:31 [TestRunnerThread] DEBUG NHibernate.Connection.ConnectionProvider - Disposing of ConnectionProvider.

wolli · **Posted:** Sun Mar 23, 2008 8:12 am

I think, I found the problem. You use the primary key of your address table as key column in your mapping. I assume that hibernate checks the returned address objects if they meet the foreign key, which results in a comparison of Person.PersonID = Address.AddressId instead of Address.PersonID. If you change the mapping to PersonID and make sure, that PersonID is return from you query (which currently isn't the case) everything should work as you expect.