ISession.Load returns wrong object

di97mni · **Joined:** Wed Jul 11, 2007 1:17 pm **Posts:** 7

Hi,

Short desc: ISession.Get(id) returns correct object but ISession.Load(id) doesn't

Long desc:
What's the difference between ISession.Load and ISession.Get? Is 'Load' throwing an exception if the item doesn't exist? Is one of them by-passing the cache and always fetching from db?

I have a unit test that looks like this:

Code:

# [Test]
1  public void CanSaveAndLoadEmployee()
2  {
3    IEmployeeDao<Employee, int> employeeDao = IoC.Container.Resolve<IEmployeeDao <Employee, int>>();
4    IEmployee employee = new Employee("xxx", "yyy");
5    Assert.IsTrue(employee.Id == 0);
6    employeeDao.Save((Employee)employee);
7    Assert.IsTrue(employee.Id != 0);
8    employeeDao.Flush();
9    employeeDao.Evict((Employee)employee);

10    IEmployee loaded = employeeDao.Get(employee.Id);
11    Assert.AreEqual(employee.Id, loaded.Id);
12    Assert.AreEqual(employee.FirstName, loaded.FirstName);
13    Assert.AreEqual(employee.LastName, loaded.LastName);
14  }

This row (10),

Code:

IEmployee loaded = employeeDao.Get(employee.Id);

will result in

Code:

using (ISession session = sessionManager.OpenSession()) {
  return session.Get<T>(id);
}

If I call session.Get<T>(id) it's working but session.Load<T>(id) will result in a failed test on row 11.

Could someone please explain this to me? Thanks in advance!

Im using following versions of assemblies:
Castle.Facilities.NHibernateIntegration v1.0.1.0
NHibernate 1.2.0.4000
SQLite.Net 0.21.1869.3794

Br,
Martin

karlchu · **Posted:** Wed Jul 11, 2007 1:42 pm

As far as I know, Load() returns a proxy if the mapped entity allows proxy. The database is not queried until a method/property is called. Load(), as you already seem to understand, throws an exception if the given ID does not exist in the database. Get(), on the other hand, would never return a proxy; the database is queried immediately to retrieve the entity. If the ID does not exist, Get() returns null and does not throw exception.

You problem could be in your DAO. Namely, does it close the session in the call to employeeDao.Get(employee.Id)? Please post your exception message.

di97mni · **Joined:** Wed Jul 11, 2007 1:17 pm **Posts:** 7

karlchu, thanks for your reply.

Quote:

Code:

# [Test]
1  public void CanSaveAndLoadEmployee()
2  {
3    IEmployeeDao<Employee, int> employeeDao = IoC.Container.Resolve<IEmployeeDao <Employee, int>>();
4    IEmployee employee = new Employee("xxx", "yyy");
5    Assert.IsTrue(employee.Id == 0);
6    employeeDao.Save((Employee)employee);
7    Assert.IsTrue(employee.Id != 0);
8    employeeDao.Flush();
9    employeeDao.Evict((Employee)employee);

10    IEmployee loaded = employeeDao.Get(employee.Id);
11    Assert.AreEqual(employee.Id, loaded.Id);
12    Assert.AreEqual(employee.FirstName, loaded.FirstName);
13    Assert.AreEqual(employee.LastName, loaded.LastName);
14  } 

Here is a more detailed trace of what happens

This is the interesting row in CanSaveAndLoadEmployee (see my first post above)

Code:

IEmployee loaded = employeeDao.Get(employee.Id);

employeeDao.Get(int id) will call this function and it returns a CProxyTypeTimeReporting_DmlEmployeeDml_NHibernate_ProxyINHibernateProxy1:

Code:

public virtual T Get(TId id)
{
  using (ISession session = GetSession())
  {
    return session.Load<T>(id);
  }
}

So I do not get any exceptions from this function.

When I then access property 'FirstName' on loaded (row 12 in CanSaveAndLoadEmployee) the entity should be loaded from the database? Or? FirstName is null but 'xxx' if I do a session.Get instead.

Any ideas anyone?

Br,
Martin

karlchu · **Posted:** Wed Jul 11, 2007 6:11 pm

When you call Load(id), NHibernate does not go to the database immediately but returns a proxy of the entity instead. When you access the 'FirstName' property, the proxy intercepts the call, and at that time, NHibernate makes the database call. At that time, unfortunately, you have already closed the NHibernate session (by virtue of the "using(session)" statement). NHibernate therefore throws a LazyInitializationFailed exception.

You need to manage the lifetime of the NHibernate session outside of your employeeDao.Get(id) method.

di97mni · **Joined:** Wed Jul 11, 2007 1:17 pm **Posts:** 7

Ok, but then this code should work, or? But it doesn't, still returning 'null' for FirstName.

Code:

#public virtual T Get(TId id)
1 {
2   using (ISession session = GetSession())
3   {
4     T item = session.Load<T>(id);
5     Console.Writeline("FirstName: " + ((Xyz.Dml.Employee) item).FirstName);
6     return item;
7   }
8 }

Note: row 5 above is pseudo code. I cann't reference Employee class in this layer so I execute the row in Immediate window when I hit the breakpoint in Get().

Immediate:
? ((Xyz.Dml.Employee) item).FirstName
null

Br,
Martin

DavyBrion · **Posted:** Thu Jul 12, 2007 8:37 am

di97mni wrote:

Ok, but then this code should work, or? But it doesn't, still returning 'null' for FirstName.

i'd think it should work, unless the record really has null in the firstname column.

But is there a reason why you don't want to use ISession.Get<T> instead of ISession.Load<T>? I always use Get<T> instead of Load<T>...

di97mni · **Joined:** Wed Jul 11, 2007 1:17 pm **Posts:** 7

DavyBrion wrote:

i'd think it should work, unless the record really has null in the firstname column.

It has value 'xxx' in the db.

Quote:

But is there a reason why you don't want to use ISession.Get<T> instead of ISession.Load<T>? I always use Get<T> instead of Load<T>...

No, but it would be nice if Load worked because it does not call the db if not neccessary.

Anyone using NHibernateGenericDao and got Load (NHibernateGenericDao.FindById(id)) to work?

Br,
Martin

karlchu · **Posted:** Thu Jul 12, 2007 10:56 am

Please post your mapping file and the relevant part of the Employee class so we can have a closer look.

di97mni · **Joined:** Wed Jul 11, 2007 1:17 pm **Posts:** 7

Person.hbm.xml

Code:

003 <?xml version="1.0" encoding="utf-8" ?>
004 <hibernate-mapping xmlns="urn:nhibernate-mapping-2.2" 
005            namespace="Xyz.Dml" 
006            assembly="Xyz.Dml">
007   <class name="Xyz.Dml.Person, Xyz.Dml" table="persons">
008     <id name="Id" column="personid" type="Int32" unsaved-value="0">
009       <generator  class="increment" />
010     </id>
011     <discriminator column="persontype" type="String"/>
012     <property name="FirstName" column="firstname"
013            type="String(50)"/>
014     <property name="LastName" column="lastname"
015            type="String(50)"/>
016     <subclass name="Xyz.Dml.Employee, Xyz.Dml" 
017            discriminator-value="employee">
018       <bag name="TimeCards" cascade="all">
019         <key column="cardid" />
020         <one-to-many class="Xyz.Dml.TimeCard, Xyz.Dml"/>
021       </bag>      
022     </subclass>
023   </class>
024 </hibernate-mapping>

Employee.cs

Code:

028 namespace Xyz.Dml
029 {
030   using System.Collections.Generic;
031   using Xyz.Core;
032   using Xyz.Dal;
033 
034   public class Employee : Person, IEmployee
035   {
036     private IList<ITimeCard> timeCards;
037     private readonly IEmployeeDao<Employee, int> employeeDao;
038 
039     public Employee()
040     {
041       employeeDao = IoC.Container.Resolve<IEmployeeDao<Employee, int>>();
042     }
043 
044     public Employee(int id) : base(id)
045     { employeeDao = IoC.Container.Resolve<IEmployeeDao<Employee, int>>(); }
046 
047     public Employee(string firstName, string lastName)
048       : base(firstName, lastName)
049     {
050       employeeDao = IoC.Container.Resolve<IEmployeeDao<Employee, int>>();
051     }
052     #region IEmployee Members
053 
054     public IList<ITimeCard> TimeCards
055     {
056       get { return timeCards; }
057       set { timeCards = value; }
058     }
059 
060     public void Save()
061     {
062       employeeDao.Save(this); 
063     }
064 
065     #endregion
066   }
067 }

EmployeeDao.cs

Code:

071 namespace Xyz.Dal
072 {
073   using Castle.Facilities.NHibernateIntegration;
074 
075    public class EmployeeDao<T, TId> : BaseDao<T, TId>, IEmployeeDao<T, TId>
076     where T : class
077    {
078     public EmployeeDao(ISessionManager sessionManager) : base(sessionManager)
079     {
080     }
081   }
082 }

BaseDao.cs

Code:

086 namespace Xyz.Core.Data
087 {
088   public class BaseDao<T, TId> : NHibernateGenericDao<T, TId>, IBaseDao<T, TId>
089     where T : class
090   {
091     
092     public BaseDao(ISessionManager sessionManager) : base(sessionManager)
093     {
094     }
095 
096     public BaseDao(ISessionManager sessionManager, string sessionFactoryAlias)
097       : base(sessionManager, sessionFactoryAlias)
098     {
099     }
100 
101     public ISession GetSession()
102     {
103       return base.SessionManager.OpenSession();
104     }
105   }
106 }

EmployeeDaoFixture.cs

Code:

110 [Test]
111 public void CanSaveAndLoadEmployee()
112 {
113   IEmployeeDao<Employee, int> employeeDao = IoC.Container.Resolve<IEmployeeDao<Employee, int>>();
114   IEmployee employee = new Employee("xxx", "yyy");
115   Assert.IsTrue(employee.Id == 0);
116   employeeDao.Save((Employee) employee);
117   Assert.IsTrue(employee.Id != 0);
118   employeeDao.Flush();
119   employeeDao.Evict((Employee) employee);
120 
121   IEmployee loaded = employeeDao.FindById(employee.Id);
122   Assert.AreEqual(employee.FirstName, loaded.FirstName);
123   Assert.AreEqual(employee.Id, loaded.Id);
124   Assert.AreEqual(employee.LastName, loaded.LastName);
125 }

Notes:

- Row 122 fails. employee.FirstName = "xxx" and loaded.FirstName = null
- Not getting any exceptions, or at least not before above (122) failed Assert
- typeof loaded (122) is CProxyTypeTimeReporting_DmlEmployeeDml_NHibernate_ProxyINHibernateProxy1
- This is code to help me learning Castle and NHibernate..
- Using
Castle.Facilities.NHibernateIntegration 1.0.1.0
NHibernate 1.2.0.4000
SQLite.NET 0.21.1869.3794
Castle.Core 1.0.0.0
Castle.DynamicProxy2 2.0.0.1
Castle.Windsor 1.0.0.5

Br,
Martin

IgorK · **Posted:** Fri Jul 13, 2007 5:04 am

Hi di97mni!

Can you turn on sql logging (show_sql) and see if NHibernate really produce correct query?

di97mni · **Joined:** Wed Jul 11, 2007 1:17 pm **Posts:** 7

Ok, same test (CanSaveAndLoadEmployee) but as a console program instead. Had some problem with debug output when running as a test.
See notes at the end.

Here we go..

Code:

static void Main(string[] args)
{
    log4net.Config.BasicConfigurator.Configure(new log4net.Appender.FileAppender(new log4net.Layout.PatternLayout("%c - %m%n"), "c:\\Temp\\testfile.log"));
    winsorconfig = ConfigurationManager.AppSettings.Get("windsorconfig");
    IoC.Initialize(winsorconfig);
    DatabaseHelper.CreateDb(winsorconfig);
    IEmployeeDao<Employee, int> employeeDao = IoC.Container.Resolve<IEmployeeDao<Employee, int>>();
    IEmployee employee = new Employee("xxx", "yyy");
    //Console.Out.WriteLine("loaded.FirstName = {0}", loaded.FirstName);
    Log.Info("Before Save");
    employeeDao.Save((Employee)employee);
    Console.Out.WriteLine(Environment.NewLine + "After Save" + Environment.NewLine);
    Log.Info("After Save");
    employeeDao.Flush();
    Log.Info("After Flush");
    employeeDao.Evict((Employee)employee);
    Log.Info("After Evict");
    Log.Info("Before FindById (session.Load..)");
    IEmployee loaded = employeeDao.FindById(employee.Id);
    Log.Info("After FindById (session.Load..)");
    Console.Out.WriteLine(Environment.NewLine + "After FindById (session.Load..)" + Environment.NewLine);
    IEmployee loaded2 = employeeDao.Get(employee.Id);
    Console.Out.WriteLine(Environment.NewLine + "After Get" + Environment.NewLine);
    Log.Info("After Get");
    Console.Out.WriteLine("loaded.FirstName = {0}", loaded.FirstName);
    Console.Out.WriteLine("loaded2.FirstName = {0}", loaded2.FirstName);
    Console.Read();
}

From console output:

Code:

01  drop table persons
02  drop table timecarditems
03  drop table timecards
04  create table persons (
05    personid INTEGER not null,
06     persontype TEXT not null,
07     firstname TEXT,
08     lastname TEXT,
09     primary key (personid)
10  )
11  create table timecarditems (
12    itemid INTEGER not null,
13     noofhours INTEGER,
14     primary key (itemid)
15  )
16  create table timecards (
17    timecardid INTEGER not null,
18     cardid INTEGER,
19     primary key (timecardid)
20  )
21  NHibernate: INSERT INTO persons (firstname, lastname, persontype, personid) VALU
22  ES (@p0, @p1, 'employee', @p2); @p0 = 'xxx', @p1 = 'yyy', @p2 = '1'
23  
24  After Save
25  
26  
27  After FindById (session.Load..)
28  
29  NHibernate: SELECT employee0_.personid as personid0_0_, employee0_.firstname as
30  firstname0_0_, employee0_.lastname as lastname0_0_ FROM persons employee0_ WHERE
31   employee0_.personid=@p0 and employee0_.persontype='employee'; @p0 = '1'
32  
33  After Get
34  
35  loaded.FirstName =
36  loaded2.FirstName = xxx

From log file:

Code:

041  NHibernate.Cfg.Environment - NHibernate 1.2.0.4000 (1.2.0.4000)
042  NHibernate.Cfg.Environment - nhibernate section not found in application configuration file
043  NHibernate.Cfg.Environment - Bytecode provider name : lcg
044  NHibernate.Cfg.Environment - Using reflection optimizer
045  NHibernate.Cfg.Configuration - Searching for mapped documents in assembly: TimeReporting.Dml
046  NHibernate.Cfg.Configuration - Adding embedded mapping document: TimeReporting.Dml.Person.hbm.xml
047  NHibernate.Cfg.Configuration - Mapping resource: TimeReporting.Dml.Person.hbm.xml
048  NHibernate.Dialect.Dialect - Using dialect: NHibernate.Dialect.SQLiteDialect
049  NHibernate.Cfg.HbmBinder - Mapping class: TimeReporting.Dml.Person -> persons
050  NHibernate.Cfg.HbmBinder - Mapped property: Id -> personid, type: Int32
051  NHibernate.Cfg.HbmBinder - Mapped property: FirstName -> firstname, type: String
052  NHibernate.Cfg.HbmBinder - Mapped property: LastName -> lastname, type: String
053  NHibernate.Cfg.HbmBinder - Mapping subclass: TimeReporting.Dml.Employee -> persons
054  NHibernate.Cfg.HbmBinder - Mapped property: TimeCards, type: IList`1
055  NHibernate.Cfg.Configuration - Adding embedded mapping document: TimeReporting.Dml.TimeCard.hbm.xml
056  NHibernate.Cfg.Configuration - Mapping resource: TimeReporting.Dml.TimeCard.hbm.xml
057  NHibernate.Dialect.Dialect - Using dialect: NHibernate.Dialect.SQLiteDialect
058  NHibernate.Cfg.HbmBinder - Mapping class: TimeReporting.Dml.TimeCard -> timecards
059  NHibernate.Cfg.HbmBinder - Mapped property: Id -> timecardid, type: Int32
060  NHibernate.Cfg.HbmBinder - Mapped property: TimeCardItems, type: IList`1
061  NHibernate.Cfg.Configuration - Adding embedded mapping document: TimeReporting.Dml.TimeCardItem.hbm.xml
062  NHibernate.Cfg.Configuration - Mapping resource: TimeReporting.Dml.TimeCardItem.hbm.xml
063  NHibernate.Dialect.Dialect - Using dialect: NHibernate.Dialect.SQLiteDialect
064  NHibernate.Cfg.HbmBinder - Mapping class: TimeReporting.Dml.TimeCardItem -> timecarditems
065  NHibernate.Cfg.HbmBinder - Mapped property: Id -> itemid, type: Int32
066  NHibernate.Cfg.HbmBinder - Mapped property: NoOfHours -> noofhours, type: Int32
067  NHibernate.Cfg.Configuration - processing one-to-many association mappings
068  NHibernate.Cfg.CollectionSecondPass - Second pass for collection: TimeReporting.Dml.Employee.TimeCards
069  NHibernate.Cfg.HbmBinder - mapping collection: TimeReporting.Dml.Employee.TimeCards -> timecards
070  NHibernate.Cfg.CollectionSecondPass - Mapped collection key: cardid, one-to-many: TimeCard
071  NHibernate.Cfg.CollectionSecondPass - Second pass for collection: TimeReporting.Dml.TimeCard.TimeCardItems
072  NHibernate.Cfg.HbmBinder - mapping collection: TimeReporting.Dml.TimeCard.TimeCardItems -> timecarditems
073  NHibernate.Cfg.CollectionSecondPass - Mapped collection key: itemid, one-to-many: TimeCardItem
074  NHibernate.Cfg.Configuration - processing one-to-one association property references
075  NHibernate.Cfg.Configuration - processing foreign key constraints
076  NHibernate.Cfg.Configuration - resolving reference to class: TimeCard
077  NHibernate.Cfg.Configuration - resolving reference to class: Employee
078  NHibernate.Dialect.Dialect - Using dialect: NHibernate.Dialect.SQLiteDialect
079  NHibernate.Connection.ConnectionProviderFactory - Initializing connection provider: NHibernate.Connection.DriverConnectionProvider
080  NHibernate.Connection.ConnectionProvider - Configuring ConnectionProvider
081  NHibernate.Cfg.SettingsFactory - Optimize cache for minimal puts: False
082  NHibernate.Cfg.SettingsFactory - Connection release mode: auto
083  NHibernate.Cfg.SettingsFactory - echoing all SQL to stdout
084  NHibernate.Cfg.SettingsFactory - Query translator: NHibernate.Hql.Classic.ClassicQueryTranslatorFactory
085  NHibernate.Cfg.SettingsFactory - Query language substitutions: {false=0, true=1}
086  NHibernate.Cfg.SettingsFactory - cache provider: NHibernate.Cache.NoCacheProvider, NHibernate, Version=1.2.0.4000, Culture=neutral, PublicKeyToken=aa95f207798dfdb4
087  NHibernate.Impl.SessionFactoryImpl - building session factory
088  NHibernate.Impl.SessionFactoryImpl - instantiating session factory with properties: {hibernate.connection.driver_class=NHibernate.Driver.SQLiteDriver, hibernate.dialect=NHibernate.Dialect.SQLiteDialect, hibernate.connection.connection_string=Data Source=unittest.db;Version=3;New=False;, hibernate.query.substitutions=true=1;false=0, hibernate.use_reflection_optimizer=true, hibernate.show_sql=true, hibernate.connection.provider=NHibernate.Connection.DriverConnectionProvider}
089  NHibernate.Impl.SessionFactoryObjectFactory - initializing class SessionFactoryObjectFactory
090  NHibernate.Impl.SessionFactoryObjectFactory - registered: c7ab3f7df2014a4aae6c34a34e91e620(unnamed)
091  NHibernate.Impl.SessionFactoryObjectFactory - no name configured
092  NHibernate.Loader.Entity.AbstractEntityLoader - Static select for entity TimeReporting.Dml.TimeCard: SELECT timecard0_.timecardid as timecardid1_0_ FROM timecards timecard0_ WHERE timecard0_.timecardid=?
093  NHibernate.Loader.Entity.AbstractEntityLoader - Static select for entity TimeReporting.Dml.TimeCard: SELECT timecard0_.timecardid as timecardid1_0_ FROM timecards timecard0_ WHERE timecard0_.timecardid=?
094  NHibernate.Loader.Entity.AbstractEntityLoader - Static select for entity TimeReporting.Dml.TimeCard: SELECT timecard0_.timecardid as timecardid1_0_ FROM timecards timecard0_ WHERE timecard0_.timecardid=?
095  NHibernate.Loader.Entity.AbstractEntityLoader - Static select for entity TimeReporting.Dml.TimeCard: SELECT timecard0_.timecardid as timecardid1_0_ FROM timecards timecard0_ WHERE timecard0_.timecardid=?
096  NHibernate.SqlCommand.SqlSelectBuilder - The initial capacity was set too low at: 8 for the SelectSqlBuilder that needed a capacity of: 9 for the table persons employee0_
097  NHibernate.Loader.Entity.AbstractEntityLoader - Static select for entity TimeReporting.Dml.Employee: SELECT employee0_.personid as personid0_0_, employee0_.firstname as firstname0_0_, employee0_.lastname as lastname0_0_ FROM persons employee0_ WHERE employee0_.personid=? and employee0_.persontype='employee'
098  NHibernate.SqlCommand.SqlSelectBuilder - The initial capacity was set too low at: 8 for the SelectSqlBuilder that needed a capacity of: 9 for the table persons employee0_
099  NHibernate.Loader.Entity.AbstractEntityLoader - Static select for entity TimeReporting.Dml.Employee: SELECT employee0_.personid as personid0_0_, employee0_.firstname as firstname0_0_, employee0_.lastname as lastname0_0_ FROM persons employee0_ WHERE employee0_.personid=? and employee0_.persontype='employee'
100  NHibernate.SqlCommand.SqlSelectBuilder - The initial capacity was set too low at: 8 for the SelectSqlBuilder that needed a capacity of: 9 for the table persons employee0_
101  NHibernate.Loader.Entity.AbstractEntityLoader - Static select for entity TimeReporting.Dml.Employee: SELECT employee0_.personid as personid0_0_, employee0_.firstname as firstname0_0_, employee0_.lastname as lastname0_0_ FROM persons employee0_ WHERE employee0_.personid=? and employee0_.persontype='employee'
102  NHibernate.SqlCommand.SqlSelectBuilder - The initial capacity was set too low at: 8 for the SelectSqlBuilder that needed a capacity of: 9 for the table persons employee0_
103  NHibernate.Loader.Entity.AbstractEntityLoader - Static select for entity TimeReporting.Dml.Employee: SELECT employee0_.personid as personid0_0_, employee0_.firstname as firstname0_0_, employee0_.lastname as lastname0_0_ FROM persons employee0_ WHERE employee0_.personid=? and employee0_.persontype='employee'
104  NHibernate.Loader.Entity.AbstractEntityLoader - Static select for entity TimeReporting.Dml.TimeCardItem: SELECT timecardit0_.itemid as itemid2_0_, timecardit0_.noofhours as noofhours2_0_ FROM timecarditems timecardit0_ WHERE timecardit0_.itemid=?
105  NHibernate.Loader.Entity.AbstractEntityLoader - Static select for entity TimeReporting.Dml.TimeCardItem: SELECT timecardit0_.itemid as itemid2_0_, timecardit0_.noofhours as noofhours2_0_ FROM timecarditems timecardit0_ WHERE timecardit0_.itemid=?
106  NHibernate.Loader.Entity.AbstractEntityLoader - Static select for entity TimeReporting.Dml.TimeCardItem: SELECT timecardit0_.itemid as itemid2_0_, timecardit0_.noofhours as noofhours2_0_ FROM timecarditems timecardit0_ WHERE timecardit0_.itemid=?
107  NHibernate.Loader.Entity.AbstractEntityLoader - Static select for entity TimeReporting.Dml.TimeCardItem: SELECT timecardit0_.itemid as itemid2_0_, timecardit0_.noofhours as noofhours2_0_ FROM timecarditems timecardit0_ WHERE timecardit0_.itemid=?
108  NHibernate.Loader.Entity.AbstractEntityLoader - Static select for entity TimeReporting.Dml.Person: SELECT person0_.personid as personid0_0_, person0_.firstname as firstname0_0_, person0_.lastname as lastname0_0_, person0_.persontype as persontype0_ FROM persons person0_ WHERE person0_.personid=?
109  NHibernate.Loader.Entity.AbstractEntityLoader - Static select for entity TimeReporting.Dml.Person: SELECT person0_.personid as personid0_0_, person0_.firstname as firstname0_0_, person0_.lastname as lastname0_0_, person0_.persontype as persontype0_ FROM persons person0_ WHERE person0_.personid=?
110  NHibernate.Loader.Entity.AbstractEntityLoader - Static select for entity TimeReporting.Dml.Person: SELECT person0_.personid as personid0_0_, person0_.firstname as firstname0_0_, person0_.lastname as lastname0_0_, person0_.persontype as persontype0_ FROM persons person0_ WHERE person0_.personid=?
111  NHibernate.Loader.Entity.AbstractEntityLoader - Static select for entity TimeReporting.Dml.Person: SELECT person0_.personid as personid0_0_, person0_.firstname as firstname0_0_, person0_.lastname as lastname0_0_, person0_.persontype as persontype0_ FROM persons person0_ WHERE person0_.personid=?
112  NHibernate.Loader.Collection.OneToManyLoader - Static select for one-to-many TimeReporting.Dml.Employee.TimeCards: SELECT timecards0_.cardid as cardid__1_, timecards0_.timecardid as timecardid1_, timecards0_.timecardid as timecardid1_0_ FROM timecards timecards0_ WHERE timecards0_.cardid=?
113  NHibernate.Loader.Collection.OneToManyLoader - Static select for one-to-many TimeReporting.Dml.TimeCard.TimeCardItems: SELECT timecardit0_.itemid as itemid__1_, timecardit0_.itemid as itemid1_, timecardit0_.itemid as itemid2_0_, timecardit0_.noofhours as noofhours2_0_ FROM timecarditems timecardit0_ WHERE timecardit0_.itemid=?
114  NHibernate.Impl.SessionFactoryImpl - Instantiated session factory
115  NHibernate.Cfg.Configuration - Adding embedded mapping document: TimeReporting.Dml.Person.hbm.xml
116  NHibernate.Cfg.Configuration - Mapping resource: TimeReporting.Dml.Person.hbm.xml
117  NHibernate.Dialect.Dialect - Using dialect: NHibernate.Dialect.SQLiteDialect
118  NHibernate.Cfg.HbmBinder - Mapping class: TimeReporting.Dml.Person -> persons
119  NHibernate.Cfg.HbmBinder - Mapped property: Id -> personid, type: Int32
120  NHibernate.Cfg.HbmBinder - Mapped property: FirstName -> firstname, type: String
121  NHibernate.Cfg.HbmBinder - Mapped property: LastName -> lastname, type: String
122  NHibernate.Cfg.HbmBinder - Mapping subclass: TimeReporting.Dml.Employee -> persons
123  NHibernate.Cfg.HbmBinder - Mapped property: TimeCards, type: IList`1
124  NHibernate.Cfg.Configuration - Adding embedded mapping document: TimeReporting.Dml.TimeCard.hbm.xml
125  NHibernate.Cfg.Configuration - Mapping resource: TimeReporting.Dml.TimeCard.hbm.xml
126  NHibernate.Dialect.Dialect - Using dialect: NHibernate.Dialect.SQLiteDialect
127  NHibernate.Cfg.HbmBinder - Mapping class: TimeReporting.Dml.TimeCard -> timecards
128  NHibernate.Cfg.HbmBinder - Mapped property: Id -> timecardid, type: Int32
129  NHibernate.Cfg.HbmBinder - Mapped property: TimeCardItems, type: IList`1
130  NHibernate.Cfg.Configuration - Adding embedded mapping document: TimeReporting.Dml.TimeCardItem.hbm.xml
131  NHibernate.Cfg.Configuration - Mapping resource: TimeReporting.Dml.TimeCardItem.hbm.xml
132  NHibernate.Dialect.Dialect - Using dialect: NHibernate.Dialect.SQLiteDialect
133  NHibernate.Cfg.HbmBinder - Mapping class: TimeReporting.Dml.TimeCardItem -> timecarditems
134  NHibernate.Cfg.HbmBinder - Mapped property: Id -> itemid, type: Int32
135  NHibernate.Cfg.HbmBinder - Mapped property: NoOfHours -> noofhours, type: Int32
136  NHibernate.Dialect.Dialect - Using dialect: NHibernate.Dialect.SQLiteDialect
137  NHibernate.Cfg.Configuration - processing one-to-many association mappings
138  NHibernate.Cfg.CollectionSecondPass - Second pass for collection: TimeReporting.Dml.Employee.TimeCards
139  NHibernate.Cfg.HbmBinder - mapping collection: TimeReporting.Dml.Employee.TimeCards -> timecards
140  NHibernate.Cfg.CollectionSecondPass - Mapped collection key: cardid, one-to-many: TimeCard
141  NHibernate.Cfg.CollectionSecondPass - Second pass for collection: TimeReporting.Dml.TimeCard.TimeCardItems
142  NHibernate.Cfg.HbmBinder - mapping collection: TimeReporting.Dml.TimeCard.TimeCardItems -> timecarditems
143  NHibernate.Cfg.CollectionSecondPass - Mapped collection key: itemid, one-to-many: TimeCardItem
144  NHibernate.Cfg.Configuration - processing one-to-one association property references
145  NHibernate.Cfg.Configuration - processing foreign key constraints
146  NHibernate.Cfg.Configuration - resolving reference to class: TimeCard
147  NHibernate.Cfg.Configuration - resolving reference to class: Employee
148  NHibernate.Cfg.Configuration - processing one-to-many association mappings
149  NHibernate.Cfg.Configuration - processing one-to-one association property references
150  NHibernate.Cfg.Configuration - processing foreign key constraints
151  NHibernate.Cfg.Configuration - resolving reference to class: TimeCard
152  NHibernate.Cfg.Configuration - resolving reference to class: Employee
153  NHibernate.Connection.ConnectionProviderFactory - Initializing connection provider: NHibernate.Connection.DriverConnectionProvider
154  NHibernate.Connection.ConnectionProvider - Configuring ConnectionProvider
155  NHibernate.Connection.DriverConnectionProvider - Obtaining IDbConnection from Driver
156  NHibernate.Tool.hbm2ddl.SchemaExport - drop table persons
157  NHibernate.Tool.hbm2ddl.SchemaExport - Unsuccessful: drop table persons
158  NHibernate.Tool.hbm2ddl.SchemaExport - no such table: persons
159  NHibernate.Tool.hbm2ddl.SchemaExport - drop table timecarditems
160  NHibernate.Tool.hbm2ddl.SchemaExport - Unsuccessful: drop table timecarditems
161  NHibernate.Tool.hbm2ddl.SchemaExport - no such table: timecarditems
162  NHibernate.Tool.hbm2ddl.SchemaExport - drop table timecards
163  NHibernate.Tool.hbm2ddl.SchemaExport - Unsuccessful: drop table timecards
164  NHibernate.Tool.hbm2ddl.SchemaExport - no such table: timecards
165  NHibernate.Tool.hbm2ddl.SchemaExport - create table persons (
166    personid INTEGER not null,
167     persontype TEXT not null,
168     firstname TEXT,
169     lastname TEXT,
170     primary key (personid)
171  )
172  NHibernate.Tool.hbm2ddl.SchemaExport - create table timecarditems (
173    itemid INTEGER not null,
174     noofhours INTEGER,
175     primary key (itemid)
176  )
177  NHibernate.Tool.hbm2ddl.SchemaExport - create table timecards (
178    timecardid INTEGER not null,
179     cardid INTEGER,
180     primary key (timecardid)
181  )
182  NHibernate.Connection.ConnectionProvider - Closing connection
183  NHibernate.Connection.ConnectionProvider - Disposing of ConnectionProvider.
184  ConsoleApplication1.Program - Before Save
185  NHibernate.Impl.SessionImpl - opened session
186  NHibernate.Transaction.AdoTransaction - begin
187  NHibernate.Connection.DriverConnectionProvider - Obtaining IDbConnection from Driver
188  NHibernate.Engine.Cascades - unsaved-value: 0
189  NHibernate.Impl.SessionImpl - SaveOrUpdate() unsaved instance
190  NHibernate.Id.IncrementGenerator - fetching initial value: select max(personid) from persons
191  NHibernate.Connection.DriverConnectionProvider - Obtaining IDbConnection from Driver
192  NHibernate.Id.IncrementGenerator - first free id: 1
193  NHibernate.Connection.ConnectionProvider - Closing connection
194  NHibernate.Impl.SessionImpl - generated identifier: 1
195  NHibernate.Impl.SessionImpl - saving [TimeReporting.Dml.Employee#1]
196  NHibernate.Engine.Cascades - processing cascades for: TimeReporting.Dml.Employee
197  NHibernate.Engine.Cascades - done processing cascades for: TimeReporting.Dml.Employee
198  NHibernate.Engine.Cascades - processing cascades for: TimeReporting.Dml.Employee
199  NHibernate.Engine.Cascades - done processing cascades for: TimeReporting.Dml.Employee
200  NHibernate.Transaction.AdoTransaction - commit
201  NHibernate.Impl.SessionImpl - flushing session
202  NHibernate.Engine.Cascades - processing cascades for: TimeReporting.Dml.Employee
203  NHibernate.Engine.Cascades - done processing cascades for: TimeReporting.Dml.Employee
204  NHibernate.Impl.SessionImpl - Flushing entities and processing referenced collections
205  NHibernate.Impl.AbstractVisitor - Processing collection for role TimeReporting.Dml.Employee.TimeCards
206  NHibernate.Impl.SessionImpl - Processing unreferenced collections
207  NHibernate.Impl.SessionImpl - scheduling collection removes/(re)creates/updates
208  NHibernate.Impl.SessionImpl - Flushed: 1 insertions, 0 updates, 0 deletions to 1 objects
209  NHibernate.Impl.SessionImpl - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
210  NHibernate.Impl.Printer - listing entities:
211  NHibernate.Impl.Printer - TimeReporting.Dml.Employee{TimeCards=null, LastName=yyy, Id=1, FirstName=xxx}
212  NHibernate.Impl.SessionImpl - executing flush
213  NHibernate.Impl.ConnectionManager - registering flush begin
214  NHibernate.Persister.Entity.AbstractEntityPersister - Inserting entity: [TimeReporting.Dml.Employee#1]
215  NHibernate.Impl.BatcherImpl - Opened new IDbCommand, open IDbCommands: 1
216  NHibernate.Impl.BatcherImpl - Building an IDbCommand object for the SqlString: INSERT INTO persons (firstname, lastname, persontype, personid) VALUES (?, ?, 'employee', ?)
217  NHibernate.Persister.Entity.AbstractEntityPersister - Dehydrating entity: [TimeReporting.Dml.Employee#1]
218  NHibernate.Type.StringType - binding 'xxx' to parameter: 0
219  NHibernate.Type.StringType - binding 'yyy' to parameter: 1
220  NHibernate.Type.Int32Type - binding '1' to parameter: 2
221  NHibernate.SQL - INSERT INTO persons (firstname, lastname, persontype, personid) VALUES (@p0, @p1, 'employee', @p2); @p0 = 'xxx', @p1 = 'yyy', @p2 = '1'
222  NHibernate.Impl.BatcherImpl - Closed IDbCommand, open IDbCommands: 0
223  NHibernate.Impl.ConnectionManager - registering flush end
224  NHibernate.Impl.SessionImpl - post flush
225  NHibernate.Impl.SessionImpl - before transaction completion
226  NHibernate.Impl.ConnectionManager - aggressively releasing database connection
227  NHibernate.Connection.ConnectionProvider - Closing connection
228  NHibernate.Impl.SessionImpl - transaction completion
229  NHibernate.Transaction.AdoTransaction - running AdoTransaction.Dispose()
230  NHibernate.Impl.SessionImpl - running ISession.Dispose()
231  NHibernate.Impl.SessionImpl - closing session
232  NHibernate.Impl.BatcherImpl - running BatcherImpl.Dispose(true)
233  ConsoleApplication1.Program - After Save
234  NHibernate.Impl.SessionImpl - opened session
235  NHibernate.Impl.SessionImpl - flushing session
236  NHibernate.Impl.SessionImpl - Flushing entities and processing referenced collections
237  NHibernate.Impl.SessionImpl - Processing unreferenced collections
238  NHibernate.Impl.SessionImpl - scheduling collection removes/(re)creates/updates
239  NHibernate.Impl.SessionImpl - Flushed: 0 insertions, 0 updates, 0 deletions to 0 objects
240  NHibernate.Impl.SessionImpl - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
241  NHibernate.Impl.SessionImpl - executing flush
242  NHibernate.Impl.ConnectionManager - registering flush begin
243  NHibernate.Impl.ConnectionManager - registering flush end
244  NHibernate.Impl.ConnectionManager - aggressively releasing database connection
245  NHibernate.Impl.SessionImpl - post flush
246  NHibernate.Impl.SessionImpl - running ISession.Dispose()
247  NHibernate.Impl.SessionImpl - closing session
248  NHibernate.Impl.BatcherImpl - running BatcherImpl.Dispose(true)
249  ConsoleApplication1.Program - After Flush
250  NHibernate.Impl.SessionImpl - opened session
251  NHibernate.Impl.SessionImpl - running ISession.Dispose()
252  NHibernate.Impl.SessionImpl - closing session
253  NHibernate.Impl.BatcherImpl - running BatcherImpl.Dispose(true)
254  ConsoleApplication1.Program - After Evict
255  ConsoleApplication1.Program - Before FindById (session.Load..)
256  NHibernate.Impl.SessionImpl - opened session
257  NHibernate.Impl.SessionImpl - loading [Employee#1]
258  NHibernate.Impl.ConnectionManager - after autocommit
259  NHibernate.Impl.ConnectionManager - aggressively releasing database connection
260  NHibernate.Impl.SessionImpl - transaction completion
261  NHibernate.Impl.SessionImpl - running ISession.Dispose()
262  NHibernate.Impl.SessionImpl - closing session
263  NHibernate.Impl.BatcherImpl - running BatcherImpl.Dispose(true)
264  ConsoleApplication1.Program - After FindById (session.Load..)
265  NHibernate.Impl.SessionImpl - opened session
266  NHibernate.Impl.SessionImpl - loading [Employee#1]
267  NHibernate.Impl.SessionImpl - attempting to resolve [Employee#1]
268  NHibernate.Impl.SessionImpl - object not resolved in any cache [TimeReporting.Dml.Employee#1]
269  NHibernate.Persister.Entity.AbstractEntityPersister - Fetching entity: [TimeReporting.Dml.Employee#1]
270  NHibernate.Loader.Loader - loading entity: [TimeReporting.Dml.Employee#1]
271  NHibernate.Impl.BatcherImpl - Opened new IDbCommand, open IDbCommands: 1
272  NHibernate.Impl.BatcherImpl - Building an IDbCommand object for the SqlString: SELECT employee0_.personid as personid0_0_, employee0_.firstname as firstname0_0_, employee0_.lastname as lastname0_0_ FROM persons employee0_ WHERE employee0_.personid=? and employee0_.persontype='employee'
273  NHibernate.Type.Int32Type - binding '1' to parameter: 0
274  NHibernate.Loader.Loader - SELECT employee0_.personid as personid0_0_, employee0_.firstname as firstname0_0_, employee0_.lastname as lastname0_0_ FROM persons employee0_ WHERE employee0_.personid=@p0 and employee0_.persontype='employee'
275  NHibernate.SQL - SELECT employee0_.personid as personid0_0_, employee0_.firstname as firstname0_0_, employee0_.lastname as lastname0_0_ FROM persons employee0_ WHERE employee0_.personid=@p0 and employee0_.persontype='employee'; @p0 = '1'
276  NHibernate.Connection.DriverConnectionProvider - Obtaining IDbConnection from Driver
277  NHibernate.Impl.BatcherImpl - Opened IDataReader, open IDataReaders: 1
278  NHibernate.Loader.Loader - processing result set
279  NHibernate.Loader.Loader - result set row: 0
280  NHibernate.Loader.Loader - result row: 1
281  NHibernate.Loader.Loader - Initializing object from DataReader: [TimeReporting.Dml.Employee#1]
282  NHibernate.Loader.Loader - Hydrating entity: TimeReporting.Dml.Employee#1
283  NHibernate.Type.StringType - returning 'xxx' as column: firstname0_0_
284  NHibernate.Type.StringType - returning 'yyy' as column: lastname0_0_
285  NHibernate.Loader.Loader - done processing result set (1 rows)
286  NHibernate.Driver.NHybridDataReader - running NHybridDataReader.Dispose()
287  NHibernate.Impl.BatcherImpl - Closed IDataReader, open IDataReaders :0
288  NHibernate.Impl.BatcherImpl - Closed IDbCommand, open IDbCommands: 0
289  NHibernate.Impl.ConnectionManager - aggressively releasing database connection
290  NHibernate.Connection.ConnectionProvider - Closing connection
291  NHibernate.Loader.Loader - total objects hydrated: 1
292  NHibernate.Impl.SessionImpl - resolving associations for: [TimeReporting.Dml.Employee#1]
293  NHibernate.Impl.SessionImpl - creating collection wrapper:[TimeReporting.Dml.Employee.TimeCards#1]
294  NHibernate.Impl.SessionImpl - done materializing entity [TimeReporting.Dml.Employee#1]
295  NHibernate.Impl.SessionImpl - initializing non-lazy collections
296  NHibernate.Loader.Loader - done entity load
297  NHibernate.Impl.ConnectionManager - after autocommit
298  NHibernate.Impl.ConnectionManager - aggressively releasing database connection
299  NHibernate.Impl.SessionImpl - transaction completion
300  NHibernate.Impl.SessionImpl - running ISession.Dispose()
301  NHibernate.Impl.SessionImpl - closing session
302  NHibernate.Impl.BatcherImpl - running BatcherImpl.Dispose(true)
303  ConsoleApplication1.Program - After Get

Notes:
- No SELECT between 24 and 27, but that's because no db access made, yet (it's a proxy)
- Is row 262 the problem? Shouldn't I get an exception when accessing a property on proxy later?

Any suggestions?

Br,
Martin

karlchu · **Posted:** Sat Jul 14, 2007 11:47 am

I don't know what exactly happens when one calls Load() and then Get() in the same ISession. According to Sergey in this post (http://forum.hibernate.org/viewtopic.ph ... 87#2357987), ISession.Get will never return a proxy. What I wonder is whether calling Get() after Load() somehow invalidates the proxy initially returned by Load(). You may want to put a breakpoint in the get accessor of FirstName to see if it is actually run when you call loaded.FirstName; whether "loaded" is a proxy or not, calling loaded.FirstName should eventually hit that breakpoint.

I also found this post:
http://forum.hibernate.org/viewtopic.ph ... load+proxy
Is the FirstName property declared virtual?

di97mni · **Joined:** Wed Jul 11, 2007 1:17 pm **Posts:** 7

karlchu wrote:

I also found this post:
http://forum.hibernate.org/viewtopic.ph ... load+proxy
Is the FirstName property declared virtual?

I had the same problem as above bug

Thanks all of you who helped me with this issue!

Br,
Martin