Code:
2006-01-10 08:09:47,536 [3708] INFO NHibernate.Cfg.Environment [(null)] <(null)> - NHibernate 1.0.1.0
2006-01-10 08:09:47,566 [3708] INFO NHibernate.Cfg.Environment [(null)] <(null)> - Using reflection optimizer
2006-01-10 08:09:47,566 [3708] INFO NHibernate.Cfg.Configuration [(null)] <(null)> - Searching for mapped documents in assembly: BugProject
2006-01-10 08:09:47,566 [3708] INFO NHibernate.Cfg.Configuration [(null)] <(null)> - Found mapping documents in assembly: BugProject.MappingFiles.Line.hbm.xml
2006-01-10 08:09:47,626 [3708] INFO NHibernate.Dialect.Dialect [(null)] <(null)> - Using dialect: NHibernate.Dialect.MsSql2000Dialect
2006-01-10 08:09:47,656 [3708] INFO NHibernate.Cfg.Binder [(null)] <(null)> - Mapping class: BugProject.ModelClasses.Line -> T_Logical_Rail
2006-01-10 08:09:47,686 [3708] DEBUG NHibernate.Cfg.Binder [(null)] <(null)> - Mapped property: Id -> Path_ID, type: Int32
2006-01-10 08:09:47,716 [3708] DEBUG NHibernate.Cfg.Binder [(null)] <(null)> - Mapped property: X -> X0_Coord, type: Int32
2006-01-10 08:09:47,716 [3708] DEBUG NHibernate.Cfg.Binder [(null)] <(null)> - Mapped property: Y -> Y0_Coord, type: Int32
2006-01-10 08:09:47,737 [3708] DEBUG NHibernate.Persister.GetSetHelperFactory [(null)] <(null)> - Init compiler for class BugProject.ModelClasses.Point
2006-01-10 08:09:47,737 [3708] DEBUG NHibernate.Persister.GetSetHelperFactory [(null)] <(null)> - Adding referenced assembly D:\_Works\_NET\CSharp\BugProject\bin\Debug\NHibernate.dll
2006-01-10 08:09:47,737 [3708] DEBUG NHibernate.Persister.GetSetHelperFactory [(null)] <(null)> - Adding referenced assembly D:\_Works\_NET\CSharp\BugProject\bin\Debug\BugProject.exe
2006-01-10 08:09:47,737 [3708] DEBUG NHibernate.Persister.GetSetHelperFactory [(null)] <(null)> - Adding referenced assembly C:\WINDOWS\Microsoft.NET\Framework\v2.0.50727\mscorlib.dll
2006-01-10 08:09:47,917 [3708] DEBUG NHibernate.Persister.GetSetHelperFactory [(null)] <(null)> - Compiled ok:
using System;
using NHibernate.Property;
namespace NHibernate.Persister {
public class GetSetHelper_BugProject_ModelClasses_Point : IGetSetHelper {
ISetter[] setters;
IGetter[] getters;
public GetSetHelper_BugProject_ModelClasses_Point(ISetter[] setters, IGetter[] getters) {
this.setters = setters;
this.getters = getters;
}
public void SetPropertyValues(object obj, object[] values) {
BugProject.ModelClasses.Point t = (BugProject.ModelClasses.Point)obj;
t.X = values[0] == null ? new System.Int32() : (System.Int32)values[0];
t.Y = values[1] == null ? new System.Int32() : (System.Int32)values[1];
}
public object[] GetPropertyValues(object obj) {
BugProject.ModelClasses.Point t = (BugProject.ModelClasses.Point)obj;
object[] ret = new object[2];
ret[0] = t.X;
ret[1] = t.Y;
return ret;
}
}
}
2006-01-10 08:09:47,917 [3708] DEBUG NHibernate.Cfg.Binder [(null)] <(null)> - Mapped property: StartPoint -> X0_Coord, Y0_Coord, type: Point
2006-01-10 08:09:47,917 [3708] DEBUG NHibernate.Cfg.Binder [(null)] <(null)> - Mapped property: X -> X1_Coord, type: Int32
2006-01-10 08:09:47,917 [3708] DEBUG NHibernate.Cfg.Binder [(null)] <(null)> - Mapped property: Y -> Y1_Coord, type: Int32
2006-01-10 08:09:47,917 [3708] DEBUG NHibernate.Persister.GetSetHelperFactory [(null)] <(null)> - Init compiler for class BugProject.ModelClasses.Point
2006-01-10 08:09:47,917 [3708] DEBUG NHibernate.Persister.GetSetHelperFactory [(null)] <(null)> - Adding referenced assembly D:\_Works\_NET\CSharp\BugProject\bin\Debug\NHibernate.dll
2006-01-10 08:09:47,917 [3708] DEBUG NHibernate.Persister.GetSetHelperFactory [(null)] <(null)> - Adding referenced assembly D:\_Works\_NET\CSharp\BugProject\bin\Debug\BugProject.exe
2006-01-10 08:09:47,917 [3708] DEBUG NHibernate.Persister.GetSetHelperFactory [(null)] <(null)> - Adding referenced assembly C:\WINDOWS\Microsoft.NET\Framework\v2.0.50727\mscorlib.dll
2006-01-10 08:09:48,077 [3708] DEBUG NHibernate.Persister.GetSetHelperFactory [(null)] <(null)> - Compiled ok:
using System;
using NHibernate.Property;
namespace NHibernate.Persister {
public class GetSetHelper_BugProject_ModelClasses_Point : IGetSetHelper {
ISetter[] setters;
IGetter[] getters;
public GetSetHelper_BugProject_ModelClasses_Point(ISetter[] setters, IGetter[] getters) {
this.setters = setters;
this.getters = getters;
}
public void SetPropertyValues(object obj, object[] values) {
BugProject.ModelClasses.Point t = (BugProject.ModelClasses.Point)obj;
t.X = values[0] == null ? new System.Int32() : (System.Int32)values[0];
t.Y = values[1] == null ? new System.Int32() : (System.Int32)values[1];
}
public object[] GetPropertyValues(object obj) {
BugProject.ModelClasses.Point t = (BugProject.ModelClasses.Point)obj;
object[] ret = new object[2];
ret[0] = t.X;
ret[1] = t.Y;
return ret;
}
}
}
2006-01-10 08:09:48,077 [3708] DEBUG NHibernate.Cfg.Binder [(null)] <(null)> - Mapped property: EndPoint -> X1_Coord, Y1_Coord, type: Point
2006-01-10 08:09:48,087 [3708] DEBUG NHibernate.Cfg.Binder [(null)] <(null)> - Mapped property: Model -> Model_Id, type: Model
2006-01-10 08:09:48,087 [3708] INFO NHibernate.Cfg.Configuration [(null)] <(null)> - Found mapping documents in assembly: BugProject.MappingFiles.Model.hbm.xml
2006-01-10 08:09:48,087 [3708] INFO NHibernate.Dialect.Dialect [(null)] <(null)> - Using dialect: NHibernate.Dialect.MsSql2000Dialect
2006-01-10 08:09:48,087 [3708] INFO NHibernate.Cfg.Binder [(null)] <(null)> - Mapping class: BugProject.ModelClasses.Model -> T_Model_Master
2006-01-10 08:09:48,087 [3708] DEBUG NHibernate.Cfg.Binder [(null)] <(null)> - Mapped property: Id -> Model_ID, type: Int32
2006-01-10 08:09:48,087 [3708] DEBUG NHibernate.Cfg.Binder [(null)] <(null)> - Mapped property: Name -> Model_Name, type: String
2006-01-10 08:09:48,087 [3708] DEBUG NHibernate.Cfg.Binder [(null)] <(null)> - Mapped property: Info -> Model_Info, type: String
2006-01-10 08:09:48,087 [3708] DEBUG NHibernate.Cfg.Binder [(null)] <(null)> - Mapped property: Type -> Model_Type, type: Int32
2006-01-10 08:09:48,107 [3708] DEBUG NHibernate.Cfg.Binder [(null)] <(null)> - Mapped property: Lines, type: ISet
2006-01-10 08:09:48,117 [3708] INFO NHibernate.Cfg.Configuration [(null)] <(null)> - processing one-to-many association mappings
2006-01-10 08:09:48,117 [3708] DEBUG NHibernate.Cfg.Binder [(null)] <(null)> - Second pass for collection: BugProject.ModelClasses.Model.Lines
2006-01-10 08:09:48,127 [3708] INFO NHibernate.Cfg.Binder [(null)] <(null)> - mapping collection: BugProject.ModelClasses.Model.Lines -> T_Logical_Rail
2006-01-10 08:09:48,127 [3708] DEBUG NHibernate.Cfg.Binder [(null)] <(null)> - Mapped collection key: Model_Id, one-to-many: Line
2006-01-10 08:09:48,127 [3708] INFO NHibernate.Cfg.Configuration [(null)] <(null)> - processing one-to-one association property references
2006-01-10 08:09:48,127 [3708] INFO NHibernate.Cfg.Configuration [(null)] <(null)> - processing foreign key constraints
2006-01-10 08:09:48,127 [3708] DEBUG NHibernate.Cfg.Configuration [(null)] <(null)> - resolving reference to class: Model
2006-01-10 08:09:48,137 [3708] INFO NHibernate.Dialect.Dialect [(null)] <(null)> - Using dialect: NHibernate.Dialect.MsSql2000Dialect
2006-01-10 08:09:48,147 [3708] INFO NHibernate.Cfg.SettingsFactory [(null)] <(null)> - use outer join fetching: True
2006-01-10 08:09:48,147 [3708] INFO NHibernate.Connection.ConnectionProviderFactory [(null)] <(null)> - Intitializing connection provider: NHibernate.Connection.DriverConnectionProvider
2006-01-10 08:09:48,147 [3708] INFO NHibernate.Connection.ConnectionProvider [(null)] <(null)> - Configuring ConnectionProvider
2006-01-10 08:09:48,147 [3708] INFO NHibernate.Cfg.SettingsFactory [(null)] <(null)> - Optimize cache for minimal puts: False
2006-01-10 08:09:48,147 [3708] INFO NHibernate.Cfg.SettingsFactory [(null)] <(null)> - Query language substitutions: {}
2006-01-10 08:09:48,147 [3708] INFO NHibernate.Cfg.SettingsFactory [(null)] <(null)> - cache provider: NHibernate.Cache.HashtableCacheProvider
2006-01-10 08:09:48,157 [3708] INFO NHibernate.Cfg.Configuration [(null)] <(null)> - instantiating and configuring caches
2006-01-10 08:09:48,157 [3708] INFO NHibernate.Impl.SessionFactoryImpl [(null)] <(null)> - building session factory
2006-01-10 08:09:48,157 [3708] DEBUG NHibernate.Impl.SessionFactoryImpl [(null)] <(null)> - instantiating session factory with properties: {hibernate.connection.driver_class=NHibernate.Driver.SqlClientDriver, hibernate.dialect=NHibernate.Dialect.MsSql2000Dialect, hibernate.connection.provider=NHibernate.Connection.DriverConnectionProvider, hibernate.use_reflection_optimizer=True, hibernate.connection.connection_string=Trusted_Connection=yes; Data Source=localhost; Trusted_Connection=yes; database=BugProject}
2006-01-10 08:09:48,207 [3708] DEBUG NHibernate.Persister.GetSetHelperFactory [(null)] <(null)> - Init compiler for class BugProject.ModelClasses.Line
2006-01-10 08:09:48,207 [3708] DEBUG NHibernate.Persister.GetSetHelperFactory [(null)] <(null)> - Adding referenced assembly D:\_Works\_NET\CSharp\BugProject\bin\Debug\NHibernate.dll
2006-01-10 08:09:48,207 [3708] DEBUG NHibernate.Persister.GetSetHelperFactory [(null)] <(null)> - Adding referenced assembly D:\_Works\_NET\CSharp\BugProject\bin\Debug\BugProject.exe
2006-01-10 08:09:48,347 [3708] DEBUG NHibernate.Persister.GetSetHelperFactory [(null)] <(null)> - Compiled ok:
using System;
using NHibernate.Property;
namespace NHibernate.Persister {
public class GetSetHelper_BugProject_ModelClasses_Line : IGetSetHelper {
ISetter[] setters;
IGetter[] getters;
public GetSetHelper_BugProject_ModelClasses_Line(ISetter[] setters, IGetter[] getters) {
this.setters = setters;
this.getters = getters;
}
public void SetPropertyValues(object obj, object[] values) {
BugProject.ModelClasses.Line t = (BugProject.ModelClasses.Line)obj;
t.StartPoint = (BugProject.ModelClasses.Point)values[0];
t.EndPoint = (BugProject.ModelClasses.Point)values[1];
t.Model = (BugProject.ModelClasses.Model)values[2];
}
public object[] GetPropertyValues(object obj) {
BugProject.ModelClasses.Line t = (BugProject.ModelClasses.Line)obj;
object[] ret = new object[3];
ret[0] = t.StartPoint;
ret[1] = t.EndPoint;
ret[2] = t.Model;
return ret;
}
}
}
2006-01-10 08:09:48,357 [3708] DEBUG NHibernate.Persister.GetSetHelperFactory [(null)] <(null)> - Init compiler for class BugProject.ModelClasses.Model
2006-01-10 08:09:48,357 [3708] DEBUG NHibernate.Persister.GetSetHelperFactory [(null)] <(null)> - Adding referenced assembly D:\_Works\_NET\CSharp\BugProject\bin\Debug\NHibernate.dll
2006-01-10 08:09:48,357 [3708] DEBUG NHibernate.Persister.GetSetHelperFactory [(null)] <(null)> - Adding referenced assembly D:\_Works\_NET\CSharp\BugProject\bin\Debug\BugProject.exe
2006-01-10 08:09:48,357 [3708] DEBUG NHibernate.Persister.GetSetHelperFactory [(null)] <(null)> - Adding referenced assembly C:\WINDOWS\Microsoft.NET\Framework\v2.0.50727\mscorlib.dll
2006-01-10 08:09:48,357 [3708] DEBUG NHibernate.Persister.GetSetHelperFactory [(null)] <(null)> - Adding referenced assembly D:\_Works\_NET\CSharp\BugProject\bin\Debug\Iesi.Collections.dll
2006-01-10 08:09:48,498 [3708] DEBUG NHibernate.Persister.GetSetHelperFactory [(null)] <(null)> - Compiled ok:
using System;
using NHibernate.Property;
namespace NHibernate.Persister {
public class GetSetHelper_BugProject_ModelClasses_Model : IGetSetHelper {
ISetter[] setters;
IGetter[] getters;
public GetSetHelper_BugProject_ModelClasses_Model(ISetter[] setters, IGetter[] getters) {
this.setters = setters;
this.getters = getters;
}
public void SetPropertyValues(object obj, object[] values) {
BugProject.ModelClasses.Model t = (BugProject.ModelClasses.Model)obj;
t.Name = (System.String)values[0];
t.Lines = (Iesi.Collections.ISet)values[1];
t.Type = values[2] == null ? new System.Int32() : (System.Int32)values[2];
t.Info = (System.String)values[3];
}
public object[] GetPropertyValues(object obj) {
BugProject.ModelClasses.Model t = (BugProject.ModelClasses.Model)obj;
object[] ret = new object[4];
ret[0] = t.Name;
ret[1] = t.Lines;
ret[2] = t.Type;
ret[3] = t.Info;
return ret;
}
}
}
2006-01-10 08:09:48,618 [3708] DEBUG NHibernate.Impl.SessionFactoryObjectFactory [(null)] <(null)> - initializing class SessionFactoryObjectFactory
2006-01-10 08:09:48,618 [3708] DEBUG NHibernate.Impl.SessionFactoryObjectFactory [(null)] <(null)> - registered: fd7077b4936e4189b5b177ac487244bc(unnamed)
2006-01-10 08:09:48,618 [3708] INFO NHibernate.Impl.SessionFactoryObjectFactory [(null)] <(null)> - no name configured
2006-01-10 08:09:48,618 [3708] DEBUG NHibernate.Impl.SessionFactoryImpl [(null)] <(null)> - Instantiated session factory
2006-01-10 08:09:48,628 [3708] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - opened session
2006-01-10 08:09:49,669 [3708] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - loading [Model#1]
2006-01-10 08:09:49,679 [3708] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - attempting to resolve [Model#1]
2006-01-10 08:09:49,679 [3708] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - object not resolved in any cache [BugProject.ModelClasses.Model#1]
2006-01-10 08:09:49,689 [3708] DEBUG NHibernate.Persister.EntityPersister [(null)] <(null)> - Materializing entity: BugProject.ModelClasses.Model#1
2006-01-10 08:09:49,729 [3708] DEBUG NHibernate.Impl.BatcherImpl [(null)] <(null)> - Opened new IDbCommand, open IDbCommands :1
2006-01-10 08:09:49,729 [3708] DEBUG NHibernate.Impl.BatcherImpl [(null)] <(null)> - Building an IDbCommand object for the SqlString: SELECT model0_.Model_ID as Model_ID0_, model0_.Model_Name as Model_Name0_, model0_.Model_Type as Model_Type0_, model0_.Model_Info as Model_Info0_ FROM T_Model_Master model0_ WHERE model0_.Model_ID=:Model_ID
2006-01-10 08:09:49,739 [3708] DEBUG NHibernate.Type.Int32Type [(null)] <(null)> - binding '1' to parameter: 0
2006-01-10 08:09:49,739 [3708] INFO NHibernate.Loader.Loader [(null)] <(null)> - SELECT model0_.Model_ID as Model_ID0_, model0_.Model_Name as Model_Name0_, model0_.Model_Type as Model_Type0_, model0_.Model_Info as Model_Info0_ FROM T_Model_Master model0_ WHERE model0_.Model_ID=@p0
2006-01-10 08:09:49,749 [3708] DEBUG NHibernate.SQL [(null)] <(null)> - SELECT model0_.Model_ID as Model_ID0_, model0_.Model_Name as Model_Name0_, model0_.Model_Type as Model_Type0_, model0_.Model_Info as Model_Info0_ FROM T_Model_Master model0_ WHERE model0_.Model_ID=@p0
2006-01-10 08:09:49,749 [3708] DEBUG NHibernate.Connection.DriverConnectionProvider [(null)] <(null)> - Obtaining IDbConnection from Driver
2006-01-10 08:09:49,830 [3708] DEBUG NHibernate.Impl.BatcherImpl [(null)] <(null)> - Opened Reader, open Readers :1
2006-01-10 08:09:49,830 [3708] DEBUG NHibernate.Loader.Loader [(null)] <(null)> - processing result set
2006-01-10 08:09:49,830 [3708] DEBUG NHibernate.Loader.Loader [(null)] <(null)> - result row: 1
2006-01-10 08:09:49,840 [3708] DEBUG NHibernate.Loader.Loader [(null)] <(null)> - Initializing object from DataReader: 1
2006-01-10 08:09:49,840 [3708] DEBUG NHibernate.Loader.Loader [(null)] <(null)> - Hydrating entity: BugProject.ModelClasses.Model#1
2006-01-10 08:09:49,840 [3708] DEBUG NHibernate.Type.StringType [(null)] <(null)> - returning 'Bug model' as column: Model_Name0_
2006-01-10 08:09:49,840 [3708] DEBUG NHibernate.Type.Int32Type [(null)] <(null)> - returning '1' as column: Model_Type0_
2006-01-10 08:09:49,840 [3708] DEBUG NHibernate.Type.StringType [(null)] <(null)> - returning 'Bug model' as column: Model_Info0_
2006-01-10 08:09:49,840 [3708] DEBUG NHibernate.Loader.Loader [(null)] <(null)> - done processing result set (1 rows)
2006-01-10 08:09:49,850 [3708] DEBUG NHibernate.Driver.NHybridDataReader [(null)] <(null)> - running NHybridDataReader.Dispose()
2006-01-10 08:09:49,850 [3708] DEBUG NHibernate.Impl.BatcherImpl [(null)] <(null)> - Closed Reader, open Readers :0
2006-01-10 08:09:49,850 [3708] DEBUG NHibernate.Impl.BatcherImpl [(null)] <(null)> - Closed IDbCommand, open IDbCommands :0
2006-01-10 08:09:49,850 [3708] DEBUG NHibernate.Loader.Loader [(null)] <(null)> - total objects hydrated: 1
2006-01-10 08:09:49,850 [3708] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - resolving associations for: [BugProject.ModelClasses.Model#1]
2006-01-10 08:09:49,850 [3708] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - creating collection wrapper:[BugProject.ModelClasses.Model.Lines#1]
2006-01-10 08:09:49,860 [3708] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - done materializing entity [BugProject.ModelClasses.Model#1]
2006-01-10 08:09:49,860 [3708] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - initializing non-lazy collections
2006-01-10 08:09:49,870 [3708] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - initializing collection [BugProject.ModelClasses.Model.Lines#1]
2006-01-10 08:09:49,870 [3708] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - checking second-level cache
2006-01-10 08:09:49,870 [3708] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - collection not cached
2006-01-10 08:09:49,870 [3708] DEBUG NHibernate.Impl.BatcherImpl [(null)] <(null)> - Opened new IDbCommand, open IDbCommands :1
2006-01-10 08:09:49,870 [3708] DEBUG NHibernate.Impl.BatcherImpl [(null)] <(null)> - Building an IDbCommand object for the SqlString: SELECT lines0_.Model_Id as Model_Id__, lines0_.Path_ID as Path_ID__, lines0_.Path_ID as Path_ID0_, lines0_.X0_Coord as X0_Coord0_, lines0_.Y0_Coord as Y0_Coord0_, lines0_.X1_Coord as X1_Coord0_, lines0_.Y1_Coord as Y1_Coord0_, lines0_.Model_Id as Model_Id0_ FROM T_Logical_Rail lines0_ WHERE lines0_.Model_Id=:Model_Id
2006-01-10 08:09:49,870 [3708] DEBUG NHibernate.Type.Int32Type [(null)] <(null)> - binding '1' to parameter: 0
2006-01-10 08:09:49,870 [3708] INFO NHibernate.Loader.Loader [(null)] <(null)> - SELECT lines0_.Model_Id as Model_Id__, lines0_.Path_ID as Path_ID__, lines0_.Path_ID as Path_ID0_, lines0_.X0_Coord as X0_Coord0_, lines0_.Y0_Coord as Y0_Coord0_, lines0_.X1_Coord as X1_Coord0_, lines0_.Y1_Coord as Y1_Coord0_, lines0_.Model_Id as Model_Id0_ FROM T_Logical_Rail lines0_ WHERE lines0_.Model_Id=@p0
2006-01-10 08:09:49,870 [3708] DEBUG NHibernate.SQL [(null)] <(null)> - SELECT lines0_.Model_Id as Model_Id__, lines0_.Path_ID as Path_ID__, lines0_.Path_ID as Path_ID0_, lines0_.X0_Coord as X0_Coord0_, lines0_.Y0_Coord as Y0_Coord0_, lines0_.X1_Coord as X1_Coord0_, lines0_.Y1_Coord as Y1_Coord0_, lines0_.Model_Id as Model_Id0_ FROM T_Logical_Rail lines0_ WHERE lines0_.Model_Id=@p0
2006-01-10 08:09:49,870 [3708] DEBUG NHibernate.Impl.BatcherImpl [(null)] <(null)> - Opened Reader, open Readers :1
2006-01-10 08:09:49,870 [3708] DEBUG NHibernate.Loader.Loader [(null)] <(null)> - result set contains (possibly empty) collection: [BugProject.ModelClasses.Model.Lines#1]
2006-01-10 08:09:49,870 [3708] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - uninitialized collection: initializing
2006-01-10 08:09:49,870 [3708] DEBUG NHibernate.Loader.Loader [(null)] <(null)> - processing result set
2006-01-10 08:09:49,870 [3708] DEBUG NHibernate.Type.Int32Type [(null)] <(null)> - returning '1' as column: Path_ID0_
2006-01-10 08:09:49,870 [3708] DEBUG NHibernate.Loader.Loader [(null)] <(null)> - result row: 1
2006-01-10 08:09:49,870 [3708] DEBUG NHibernate.Loader.Loader [(null)] <(null)> - Initializing object from DataReader: 1
2006-01-10 08:09:49,870 [3708] DEBUG NHibernate.Loader.Loader [(null)] <(null)> - Hydrating entity: BugProject.ModelClasses.Line#1
2006-01-10 08:09:49,880 [3708] DEBUG NHibernate.Type.Int32Type [(null)] <(null)> - returning '1' as column: X0_Coord0_
2006-01-10 08:09:49,880 [3708] DEBUG NHibernate.Type.Int32Type [(null)] <(null)> - returning '1' as column: Y0_Coord0_
2006-01-10 08:09:49,880 [3708] DEBUG NHibernate.Type.Int32Type [(null)] <(null)> - returning '2' as column: X1_Coord0_
2006-01-10 08:09:49,880 [3708] DEBUG NHibernate.Type.Int32Type [(null)] <(null)> - returning '2' as column: Y1_Coord0_
2006-01-10 08:09:49,880 [3708] DEBUG NHibernate.Type.Int32Type [(null)] <(null)> - returning '1' as column: Model_Id0_
2006-01-10 08:09:49,880 [3708] DEBUG NHibernate.Type.Int32Type [(null)] <(null)> - returning '1' as column: Model_Id__
2006-01-10 08:09:49,880 [3708] DEBUG NHibernate.Loader.Loader [(null)] <(null)> - found row of collection: [BugProject.ModelClasses.Model.Lines#1]
2006-01-10 08:09:49,880 [3708] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - reading row
2006-01-10 08:09:49,880 [3708] DEBUG NHibernate.Type.Int32Type [(null)] <(null)> - returning '1' as column: Path_ID__
2006-01-10 08:09:49,880 [3708] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - loading [Line#1]
2006-01-10 08:09:49,880 [3708] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - attempting to resolve [Line#1]
2006-01-10 08:09:49,880 [3708] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - resolved object in session cache [BugProject.ModelClasses.Line#1]
2006-01-10 08:09:49,880 [3708] DEBUG NHibernate.Type.Int32Type [(null)] <(null)> - returning '2' as column: Path_ID0_
2006-01-10 08:09:49,880 [3708] DEBUG NHibernate.Loader.Loader [(null)] <(null)> - result row: 2
2006-01-10 08:09:49,880 [3708] DEBUG NHibernate.Loader.Loader [(null)] <(null)> - Initializing object from DataReader: 2
2006-01-10 08:09:49,880 [3708] DEBUG NHibernate.Loader.Loader [(null)] <(null)> - Hydrating entity: BugProject.ModelClasses.Line#2
2006-01-10 08:09:49,880 [3708] DEBUG NHibernate.Type.Int32Type [(null)] <(null)> - returning '10' as column: X0_Coord0_
2006-01-10 08:09:49,880 [3708] DEBUG NHibernate.Type.Int32Type [(null)] <(null)> - returning '10' as column: Y0_Coord0_
2006-01-10 08:09:49,880 [3708] DEBUG NHibernate.Type.Int32Type [(null)] <(null)> - returning '20' as column: X1_Coord0_
2006-01-10 08:09:49,880 [3708] DEBUG NHibernate.Type.Int32Type [(null)] <(null)> - returning '20' as column: Y1_Coord0_
2006-01-10 08:09:49,880 [3708] DEBUG NHibernate.Type.Int32Type [(null)] <(null)> - returning '1' as column: Model_Id0_
2006-01-10 08:09:49,880 [3708] DEBUG NHibernate.Type.Int32Type [(null)] <(null)> - returning '1' as column: Model_Id__
2006-01-10 08:09:49,880 [3708] DEBUG NHibernate.Loader.Loader [(null)] <(null)> - found row of collection: [BugProject.ModelClasses.Model.Lines#1]
2006-01-10 08:09:49,880 [3708] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - reading row
2006-01-10 08:09:49,880 [3708] DEBUG NHibernate.Type.Int32Type [(null)] <(null)> - returning '2' as column: Path_ID__
2006-01-10 08:09:49,880 [3708] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - loading [Line#2]
2006-01-10 08:09:49,880 [3708] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - attempting to resolve [Line#2]
2006-01-10 08:09:49,880 [3708] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - resolved object in session cache [BugProject.ModelClasses.Line#2]
2006-01-10 08:09:49,880 [3708] DEBUG NHibernate.Loader.Loader [(null)] <(null)> - done processing result set (2 rows)
2006-01-10 08:09:49,890 [3708] DEBUG NHibernate.Driver.NHybridDataReader [(null)] <(null)> - running NHybridDataReader.Dispose()
2006-01-10 08:09:49,890 [3708] DEBUG NHibernate.Impl.BatcherImpl [(null)] <(null)> - Closed Reader, open Readers :0
2006-01-10 08:09:49,890 [3708] DEBUG NHibernate.Impl.BatcherImpl [(null)] <(null)> - Closed IDbCommand, open IDbCommands :0
2006-01-10 08:09:49,890 [3708] DEBUG NHibernate.Loader.Loader [(null)] <(null)> - total objects hydrated: 2
2006-01-10 08:09:49,890 [3708] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - resolving associations for: [BugProject.ModelClasses.Line#1]
2006-01-10 08:09:49,890 [3708] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - loading [Model#1]
2006-01-10 08:09:49,890 [3708] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - attempting to resolve [Model#1]
2006-01-10 08:09:49,890 [3708] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - resolved object in session cache [BugProject.ModelClasses.Model#1]
2006-01-10 08:09:49,890 [3708] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - done materializing entity [BugProject.ModelClasses.Line#1]
2006-01-10 08:09:49,890 [3708] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - resolving associations for: [BugProject.ModelClasses.Line#2]
2006-01-10 08:09:49,890 [3708] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - loading [Model#1]
2006-01-10 08:09:49,890 [3708] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - attempting to resolve [Model#1]
2006-01-10 08:09:49,890 [3708] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - resolved object in session cache [BugProject.ModelClasses.Model#1]
2006-01-10 08:09:49,890 [3708] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - done materializing entity [BugProject.ModelClasses.Line#2]
2006-01-10 08:09:49,890 [3708] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - 1 collections were found in result set
2006-01-10 08:09:49,900 [3708] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - collection fully initialized: [BugProject.ModelClasses.Model.Lines#1]
2006-01-10 08:09:49,900 [3708] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - 1 collections initialized
2006-01-10 08:09:49,900 [3708] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - collection initialized
2006-01-10 08:09:52,153 [3708] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - loading [Model#1]
2006-01-10 08:09:52,153 [3708] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - attempting to resolve [Model#1]
2006-01-10 08:09:52,153 [3708] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - resolved object in session cache [BugProject.ModelClasses.Model#1]
2006-01-10 08:09:52,153 [3708] DEBUG NHibernate.Transaction.AdoTransaction [(null)] <(null)> - begin
2006-01-10 08:09:52,163 [3708] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - object already associated with session
2006-01-10 08:09:52,163 [3708] DEBUG NHibernate.Transaction.AdoTransaction [(null)] <(null)> - commit
2006-01-10 08:09:52,173 [3708] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - flushing session
2006-01-10 08:09:52,193 [3708] DEBUG NHibernate.Engine.Cascades [(null)] <(null)> - processing cascades for: BugProject.ModelClasses.Model
2006-01-10 08:09:52,203 [3708] DEBUG NHibernate.Engine.Cascades [(null)] <(null)> - cascading to collection: BugProject.ModelClasses.Model.Lines
2006-01-10 08:09:52,203 [3708] DEBUG NHibernate.Engine.Cascades [(null)] <(null)> - done processing cascades for: BugProject.ModelClasses.Model
2006-01-10 08:09:52,203 [3708] DEBUG NHibernate.Engine.Cascades [(null)] <(null)> - processing cascades for: BugProject.ModelClasses.Line
2006-01-10 08:09:52,203 [3708] DEBUG NHibernate.Engine.Cascades [(null)] <(null)> - cascading to SaveOrUpdate()
2006-01-10 08:09:52,213 [3708] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - SaveOrUpdate() persistent instance
2006-01-10 08:09:52,213 [3708] DEBUG NHibernate.Engine.Cascades [(null)] <(null)> - done processing cascades for: BugProject.ModelClasses.Line
2006-01-10 08:09:52,213 [3708] DEBUG NHibernate.Engine.Cascades [(null)] <(null)> - processing cascades for: BugProject.ModelClasses.Line
2006-01-10 08:09:52,213 [3708] DEBUG NHibernate.Engine.Cascades [(null)] <(null)> - cascading to SaveOrUpdate()
2006-01-10 08:09:52,213 [3708] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - SaveOrUpdate() persistent instance
2006-01-10 08:09:52,213 [3708] DEBUG NHibernate.Engine.Cascades [(null)] <(null)> - done processing cascades for: BugProject.ModelClasses.Line
2006-01-10 08:09:52,213 [3708] DEBUG NHibernate.Impl.CollectionEntry [(null)] <(null)> - Collection dirty: [BugProject.ModelClasses.Model.Lines#1]
2006-01-10 08:09:52,213 [3708] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - Flushing entities and processing referenced collections
2006-01-10 08:09:52,253 [3708] DEBUG NHibernate.Impl.AbstractVisitor [(null)] <(null)> - Processing collection for role BugProject.ModelClasses.Model.Lines
2006-01-10 08:09:52,253 [3708] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - Collection found: [BugProject.ModelClasses.Model.Lines#1], was: [BugProject.ModelClasses.Model.Lines#1]
2006-01-10 08:09:52,263 [3708] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - Processing unreferenced collections
2006-01-10 08:09:52,263 [3708] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - scheduling collection removes/(re)creates/updates
2006-01-10 08:09:52,273 [3708] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - Flushed: 0 insertions, 0 updates, 0 deletions to 3 objects
2006-01-10 08:09:52,273 [3708] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - Flushed: 0 (re)creations, 1 updates, 0 removals to 1 collections
2006-01-10 08:09:52,273 [3708] DEBUG NHibernate.Impl.Printer [(null)] <(null)> - listing entities:
2006-01-10 08:09:52,283 [3708] DEBUG NHibernate.Impl.Printer [(null)] <(null)> - BugProject.ModelClasses.Line{StartPoint=Point{X=10, Y=10}, EndPoint=Point{X=20, Y=20}, Model=Model#1, Id=2}
2006-01-10 08:09:52,283 [3708] DEBUG NHibernate.Impl.Printer [(null)] <(null)> - BugProject.ModelClasses.Line{StartPoint=Point{X=1, Y=1}, EndPoint=Point{X=2, Y=2}, Model=Model#1, Id=1}
2006-01-10 08:09:52,283 [3708] DEBUG NHibernate.Impl.Printer [(null)] <(null)> - BugProject.ModelClasses.Model{Name=Bug model, Info=Bug model, Type=1, Lines=[], Id=1}
2006-01-10 08:09:52,293 [3708] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - executing flush
2006-01-10 08:09:52,303 [3708] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - post flush
2006-01-10 08:09:52,313 [3708] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - transaction completion
2006-01-10 08:09:52,313 [3708] DEBUG NHibernate.Transaction.AdoTransaction [(null)] <(null)> - running AdoTransaction.Dispose()
2006-01-10 08:09:55,958 [3708] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - closing session
2006-01-10 08:09:55,968 [3708] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - disconnecting session
2006-01-10 08:09:55,968 [3708] DEBUG NHibernate.Connection.ConnectionProvider [(null)] <(null)> - Closing connection
2006-01-10 08:09:55,968 [3708] DEBUG NHibernate.Impl.SessionImpl [(null)] <(null)> - transaction completion
2006-01-10 08:09:55,978 [3708] INFO NHibernate.Impl.SessionFactoryImpl [(null)] <(null)> - Closing
2006-01-10 08:09:55,978 [3708] DEBUG NHibernate.Connection.ConnectionProvider [(null)] <(null)> - Disposing of ConnectionProvider.
Here is full debug log. Sorry, it the first time I try to use log4net. And I saw that maybe it doesn't have any problems.