Does lazy load work in 1.2.1 or not ? Please help

exp2000 · **Joined:** Tue Oct 16, 2007 9:45 am **Posts:** 93

I really need help with this fast, I am doing a prototype for a very large project. I need to confirm that lazy load works, but I cannot get it to work. Collection get's populated with all instances of the children at once
instead one by one as I iterate through the collection. I even tried explicitly setting the batch-size to 1.

Hibernate version: 1.2.1

Mapping documents:

INVOICE

Code:

<?xml version="1.0" encoding="utf-8"?>
<hibernate-mapping 
      xmlns="urn:nhibernate-mapping-2.2" 
      default-cascade="none" 
      auto-import="true"
      assembly="Core"
      namespace="Core.billing"
      > 
   <class  name="Invoice"  
             table="INVOICE"  
             lazy="true"
             >
    <id name="RecordId" 
        type="Int32"
        column="VEOID"
        access="field.camelcase-underscore">
         <generator class="hilo">
          <param name="table">VE_COUNTERS2</param>
          <param name="column">INVOICE_NUMBER</param>
          <param name="max_lo">100</param>
        </generator> 
      </id>
          
<property name = "number"
              column = "NUMBER" length="255" 
              access="field.camelcase-underscore"
              />
    
<property name = "date"
              column = "INV_DATE"  
              access="field.camelcase-underscore"
              />
    
<property name = "unpaidBalance"
              column = "UNPAID_BALANCE" length="22" 
              access="field.camelcase-underscore"
              />
     <!-- m 4 -->
     <bag name="lineItems" table="LINE_ITEM" cascade="save-update" lazy="true" batch-size="1" generic="true" inverse="true">
       <key column="INVOICE_VEOID"/>
       <one-to-many class="Core.billing.LineItem"/>
     </bag>
     
   </class>
</hibernate-mapping>

LINEITEM

Code:

<?xml version="1.0" encoding="utf-8"?>
<hibernate-mapping
      xmlns="urn:nhibernate-mapping-2.2"
      default-cascade="none"
      auto-import="true"
      assembly="Core"
      namespace="Core.billing"
      >
  <class  name="LineItem"
            table="LINE_ITEM"
            lazy="true"
             >
    <id name="RecordId"
        type="Int32"
        column="VEOID"
        access="field.camelcase-underscore">
      <generator class="hilo">
        <param name="table">VE_COUNTERS2</param>
        <param name="column">LINE_ITEM</param>
        <param name="max_lo">100</param>
      </generator>
    </id>
    <property name = "description"
                  column = "DESCRIPTION" length="255"
                  access="field.camelcase-underscore"
              />
    <property name = "unitPrice"
                  column = "UNIT_PRICE" length="12"
                  access="field.camelcase-underscore"
              />
    <property name = "quantity"
                  column = "QUANTITY" length="10"
                  access="field.camelcase-underscore"
              />
    <!-- nm 10 -->
    <many-to-one name="invoice"
       class="Core.billing.Invoice"
       column="INVOICE_VEOID" not-null="true"
      />
  </class>
</hibernate-mapping>

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

Code:

    [TestFixture]
    public class Tests
    {
        private ISessionFactory _factory;
        private ISession _session;


        [SetUp]
        public void Init()
        {

            Console.WriteLine("Init() start");

            //setup log4net logging
            log4net.Config.XmlConfigurator.Configure();

            //setup NHibernate
            if (_factory == null)
            {
                Configuration config = new Configuration();
               
                config.Configure();
                _factory = config.BuildSessionFactory();
            }

            _session = _factory.OpenSession();

            Console.WriteLine("Init() end");
        }

        [TearDown]
        public void Dispose()
        {
            _session.Close();
        }

        [Test]
        public void TestCreateInvoice()
        {

        }

        [Test]
        public void Test()
        {

            Console.WriteLine("Start Test");

            Console.WriteLine("Begining transaction");

            //BillingRepository br = new BillingRepository();
            ITransaction tx = _session.BeginTransaction();

            try
            {

                //Bag<Invoice> allInvoices = br.AllInvoices();
                IList<Invoice> allInvoices = _session.CreateSQLQuery(
               "Select {i.*} from  INVOICE {i}", "i",
               typeof(Invoice)).List<Invoice>();
                Console.WriteLine("Invoices count:" + allInvoices.Count());

                foreach (Invoice i in allInvoices)
                {
                    Console.WriteLine("Invoice: " + i.ObjectId);
                    //Console.WriteLine(i.lineItems.Count());
                    Console.WriteLine("Bag initialized? " + NHibernate.NHibernateUtil.IsInitialized(i.lineItems));
 

                    foreach (LineItem li in i.lineItems)
                    {
                        Console.WriteLine("   LineItem:" + li.ObjectId.ToString());
                      //  Console.WriteLine("   line items count: " + i.lineItems.Count);
                    }
                }

                Invoice i1 = null;

                if (allInvoices.Count == 0)
                {
                    Console.WriteLine("No Invoices Found");
                    Console.WriteLine("Creating new invoice");

                    i1 = Invoice.CreateInstance();
                    i1.number = "1";
                    i1.date = DateTime.Today;
                }
                else
                {
                    Console.WriteLine("Get the first invoice in the list");
                    i1 = allInvoices.First();
                    Console.WriteLine("Invoice:" + i1.RecordId);
                }

                int liCount = i1.lineItems.Count();
                Console.WriteLine("   line items count: " + liCount);
                Console.WriteLine("Create new line item");

                LineItem liNew = LineItem.CreateInstance();
                liNew.quantity = 5;
                liNew.description = "test line item";
                liNew.unitPrice = 2;

                Console.WriteLine("Created Instance: " + liNew.ObjectId.ToString());

                i1.lineItems.Add(liNew);

                //set up inverse relation manually
                //normally this step will not be necessary as collection will fire an event
                liNew.invoice = i1;

                i1.date = DateTime.Today;
                Console.WriteLine("Added instance into collection");

                Console.WriteLine("Collection type: " + i1.lineItems.GetType().ToString());

                Assert.AreEqual(liNew, i1.lineItems.Last(), "Added Line Item");
                //Assert.AreEqual(liCount, i1.lineItems.Count, "Line items collection count");

                Console.WriteLine("Marking it for SaveOrUpdate");

                
                _session.SaveOrUpdate(i1);

                Console.WriteLine("Before commit");

                tx.Commit();

                Console.WriteLine("After commit");

                Console.WriteLine("RecordId: " + liNew.RecordId.ToString());

                LineItem li2 = (LineItem)_session.Load(typeof(LineItem), liNew.RecordId);
                Console.WriteLine("RecordId: " + liNew.RecordId.ToString());
                Assert.AreEqual(liNew, li2);

            }

            catch (Exception e)
            {
                tx.Rollback();
                Console.WriteLine(e.Message + "\n" + e.InnerException.Message);
                NUnit.Framework.TestCase.Fail(e.Message + "\n" + e.InnerException.Message);
            }
            finally
            {
                _session.Flush();
                _session.Close();
            }
        }

SQL log

Code:

2008-05-16 12:20:16,678 [TestRunnerThread] INFO  NHibernate.Connection.ConnectionProvider - Configuring ConnectionProvider
2008-05-16 12:20:16,680 [TestRunnerThread] INFO  NHibernate.Cfg.SettingsFactory - Transaction factory: NHibernate.Transaction.AdoNetTransactionFactory
2008-05-16 12:20:16,681 [TestRunnerThread] INFO  NHibernate.Cfg.SettingsFactory - Optimize cache for minimal puts: False
2008-05-16 12:20:16,681 [TestRunnerThread] INFO  NHibernate.Cfg.SettingsFactory - Connection release mode: auto
2008-05-16 12:20:16,681 [TestRunnerThread] INFO  NHibernate.Cfg.SettingsFactory - echoing all SQL to stdout
2008-05-16 12:20:16,681 [TestRunnerThread] INFO  NHibernate.Cfg.SettingsFactory - Query translator: NHibernate.Hql.Classic.ClassicQueryTranslatorFactory
2008-05-16 12:20:16,683 [TestRunnerThread] INFO  NHibernate.Cfg.SettingsFactory - Query language substitutions: {}
2008-05-16 12:20:16,683 [TestRunnerThread] INFO  NHibernate.Cfg.SettingsFactory - cache provider: NHibernate.Cache.NoCacheProvider, NHibernate, Version=1.2.1.4000, Culture=neutral, PublicKeyToken=aa95f207798dfdb4
2008-05-16 12:20:16,693 [TestRunnerThread] INFO  NHibernate.Impl.SessionFactoryImpl - building session factory
2008-05-16 12:20:16,915 [TestRunnerThread] INFO  NHibernate.Impl.SessionFactoryObjectFactory - no name configured
2008-05-16 12:20:17,490 [TestRunnerThread] INFO  NHibernate.Loader.Loader - Select i.VEOID as VEOID0_0_, i.NUMBER as NUMBER0_0_, i.INV_DATE as INV3_0_0_, i.UNPAID_BALANCE as UNPAID4_0_0_ from  INVOICE i
2008-05-16 12:20:17,660 [TestRunnerThread] INFO  NHibernate.Loader.Loader - SELECT lineitems0_.INVOICE_VEOID as INVOICE5___1_, lineitems0_.VEOID as VEOID1_, lineitems0_.VEOID as VEOID1_0_, lineitems0_.DESCRIPTION as DESCRIPT2_1_0_, lineitems0_.UNIT_PRICE as UNIT3_1_0_, lineitems0_.QUANTITY as QUANTITY1_0_, lineitems0_.INVOICE_VEOID as INVOICE5_1_0_ FROM LINE_ITEM lineitems0_ WHERE lineitems0_.INVOICE_VEOID=@p0
2008-05-16 12:20:18,009 [TestRunnerThread] INFO  NHibernate.Loader.Loader - SELECT lineitem0_.VEOID as VEOID1_0_, lineitem0_.DESCRIPTION as DESCRIPT2_1_0_, lineitem0_.UNIT_PRICE as UNIT3_1_0_, lineitem0_.QUANTITY as QUANTITY1_0_, lineitem0_.INVOICE_VEOID as INVOICE5_1_0_ FROM LINE_ITEM lineitem0_ WHERE lineitem0_.VEOID=@p0

exp2000 · **Joined:** Tue Oct 16, 2007 9:45 am **Posts:** 93

I did some debugging and it does not seem to work. Here is a stack trace:

Code:

   NHibernate.DLL!NHibernate.Loader.Loader.InitializeEntitiesAndCollections(System.Collections.IList hydratedObjects = Count = 18, object resultSetId = {NHibernate.Driver.NHybridDataReader}, NHibernate.Engine.ISessionImplementor session = {NHibernate.Impl.SessionImpl}) Line 609   C#
    NHibernate.DLL!NHibernate.Loader.Loader.DoQuery(NHibernate.Engine.ISessionImplementor session = {NHibernate.Impl.SessionImpl}, NHibernate.Engine.QueryParameters queryParameters = {NHibernate.Engine.QueryParameters}, bool returnProxies = true) Line 475 + 0x11 bytes   C#
    NHibernate.DLL!NHibernate.Loader.Loader.DoQueryAndInitializeNonLazyCollections(NHibernate.Engine.ISessionImplementor session = {NHibernate.Impl.SessionImpl}, NHibernate.Engine.QueryParameters queryParameters = {NHibernate.Engine.QueryParameters}, bool returnProxies = true) Line 181 + 0x13 bytes   C#
    NHibernate.DLL!NHibernate.Loader.Loader.LoadCollection(NHibernate.Engine.ISessionImplementor session = {NHibernate.Impl.SessionImpl}, object id = 11010, NHibernate.Type.IType type = {NHibernate.Type.Int32Type}) Line 1613 + 0x49 bytes   C#
    NHibernate.DLL!NHibernate.Loader.Collection.CollectionLoader.Initialize(object id = 11010, NHibernate.Engine.ISessionImplementor session = {NHibernate.Impl.SessionImpl}) Line 31 + 0x23 bytes   C#
    NHibernate.DLL!NHibernate.Persister.Collection.AbstractCollectionPersister.Initialize(object key = 11010, NHibernate.Engine.ISessionImplementor session = {NHibernate.Impl.SessionImpl}) Line 414 + 0x1e bytes   C#
    NHibernate.DLL!NHibernate.Impl.SessionImpl.InitializeCollection(NHibernate.Collection.IPersistentCollection collection = {NHibernate.Collection.Generic.PersistentGenericBag<.Core.billing.LineItem>}, bool writing = false) Line 4494 + 0x25 bytes   C#
    NHibernate.DLL!NHibernate.Collection.AbstractPersistentCollection.Initialize(bool writing = false) Line 251 + 0x16 bytes   C#
    NHibernate.DLL!NHibernate.Collection.AbstractPersistentCollection.Read() Line 57 + 0x9 bytes   C#
    NHibernate.DLL!NHibernate.Collection.Generic.PersistentGenericBag<.Core.billing.LineItem>.this[int].get(int index = 0) Line 127 + 0x7 bytes   C#
    NHibernateTests.DLL!.Data.Tests.Tests.Test() Line 83 + 0x1a bytes   C#

wolli · **Posted:** Mon May 19, 2008 1:24 am

I can't find any ObjectId property in your mapping ?

Console.WriteLine("Invoice: " + i.ObjectId);

Hibernate only won't fetch the instance if you access the mapped id property/field. have a look here:

http://forum.hibernate.org/viewtopic.php?t=986520

exp2000 · **Joined:** Tue Oct 16, 2007 9:45 am **Posts:** 93

Wolli,
Thanks for your reply, I was already begining to think that there is nobody out there :)

ObjectId is a transient property, basically GUID that we need for some non-persistence related stuff.

My problem is that NH does not see this collection as being lazy, it just fetches everything. It calls DoQueryAndInitializeNonLazyCollections and it initilizes and hydrates all the objects in the collection, even though collection is marked as lazy.

wolli · **Posted:** Mon May 19, 2008 10:38 am

I think your problem is, that hibernate does not recognize ObjectId as the "Id" property and thus loads the object. Can you try to use the real Id property there (should be RecordId) ? In general it might be a problem, that you don't use access="property" on the id (as mentioned in the ohter thread).

When does hibernate load the bag ? When Invoice is loaded or later during your loop ?

exp2000 · **Joined:** Tue Oct 16, 2007 9:45 am **Posts:** 93

Here is the log that shows what is happening.

2008-05-19 09:50:03,059 [TestRunnerThread] DEBUG NHibernate.Transaction.AdoTransaction - begin
2008-05-19 09:50:03,060 [TestRunnerThread] DEBUG NHibernate.Connection.DriverConnectionProvider - Obtaining IDbConnection from Driver
2008-05-19 09:50:03,460 [TestRunnerThread] DEBUG NHibernate.Loader.Custom.SQLCustomQuery - starting processing of sql query [Select {i.*} from INVOICE {i}]
2008-05-19 09:50:03,464 [TestRunnerThread] DEBUG NHibernate.Loader.Custom.SQLQueryReturnProcessor - mapping alias [i] to entity-suffix [0_]
2008-05-19 09:50:03,490 [TestRunnerThread] DEBUG NHibernate.Impl.SessionImpl - flushing session
2008-05-19 09:50:03,497 [TestRunnerThread] DEBUG NHibernate.Impl.SessionImpl - Flushing entities and processing referenced collections
2008-05-19 09:50:03,500 [TestRunnerThread] DEBUG NHibernate.Impl.SessionImpl - Processing unreferenced collections
2008-05-19 09:50:03,500 [TestRunnerThread] DEBUG NHibernate.Impl.SessionImpl - scheduling collection removes/(re)creates/updates
2008-05-19 09:50:03,500 [TestRunnerThread] DEBUG NHibernate.Impl.SessionImpl - Flushed: 0 insertions, 0 updates, 0 deletions to 0 objects
2008-05-19 09:50:03,500 [TestRunnerThread] DEBUG NHibernate.Impl.SessionImpl - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
2008-05-19 09:50:03,502 [TestRunnerThread] DEBUG NHibernate.Impl.SessionImpl - dont need to execute flush
2008-05-19 09:50:03,522 [TestRunnerThread] DEBUG NHibernate.Impl.BatcherImpl - Opened new IDbCommand, open IDbCommands: 1
2008-05-19 09:50:03,522 [TestRunnerThread] DEBUG NHibernate.Impl.BatcherImpl - Building an IDbCommand object for the SqlString: Select i.VEOID as VEOID0_0_, i.NUMBER as NUMBER0_0_, i.INV_DATE as INV3_0_0_, i.UNPAID_BALANCE as UNPAID4_0_0_ from INVOICE i
2008-05-19 09:50:03,525 [TestRunnerThread] INFO NHibernate.Loader.Loader - Select i.VEOID as VEOID0_0_, i.NUMBER as NUMBER0_0_, i.INV_DATE as INV3_0_0_, i.UNPAID_BALANCE as UNPAID4_0_0_ from INVOICE i
2008-05-19 09:50:03,532 [TestRunnerThread] DEBUG NHibernate.SQL - Select i.VEOID as VEOID0_0_, i.NUMBER as NUMBER0_0_, i.INV_DATE as INV3_0_0_, i.UNPAID_BALANCE as UNPAID4_0_0_ from INVOICE i
2008-05-19 09:50:03,590 [TestRunnerThread] DEBUG NHibernate.Impl.BatcherImpl - Opened IDataReader, open IDataReaders: 1
2008-05-19 09:50:03,592 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - processing result set
2008-05-19 09:50:03,595 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - result set row: 0
2008-05-19 09:50:03,629 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '11010' as column: VEOID0_0_
2008-05-19 09:50:03,633 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - result row: 11010
2008-05-19 09:50:03,639 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - Initializing object from DataReader: [Core.billing.Invoice#11010]
2008-05-19 09:50:03,643 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - Hydrating entity: Core.billing.Invoice#11010
2008-05-19 09:50:03,646 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning '1' as column: NUMBER0_0_
2008-05-19 09:50:03,649 [TestRunnerThread] DEBUG NHibernate.Type.DateTimeType - returning '5/16/2008' as column: INV3_0_0_
2008-05-19 09:50:03,650 [TestRunnerThread] DEBUG NHibernate.Type.DoubleType - returning '0' as column: UNPAID4_0_0_
2008-05-19 09:50:03,658 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - done processing result set (1 rows)
2008-05-19 09:50:03,658 [TestRunnerThread] DEBUG NHibernate.Driver.NHybridDataReader - running NHybridDataReader.Dispose()
2008-05-19 09:50:03,661 [TestRunnerThread] DEBUG NHibernate.Impl.BatcherImpl - Closed IDataReader, open IDataReaders :0
2008-05-19 09:50:03,663 [TestRunnerThread] DEBUG NHibernate.Impl.BatcherImpl - Closed IDbCommand, open IDbCommands: 0
2008-05-19 09:50:03,664 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - total objects hydrated: 1
2008-05-19 09:50:03,667 [TestRunnerThread] DEBUG NHibernate.Impl.SessionImpl - resolving associations for: [Core.billing.Invoice#11010]
2008-05-19 09:50:03,671 [TestRunnerThread] DEBUG NHibernate.Impl.SessionImpl - creating collection wrapper:[Core.billing.Invoice.lineItems#11010]
2008-05-19 09:50:03,683 [TestRunnerThread] DEBUG NHibernate.Impl.SessionImpl - done materializing entity [Core.billing.Invoice#11010]
2008-05-19 09:50:03,684 [TestRunnerThread] DEBUG NHibernate.Impl.SessionImpl - initializing non-lazy collections
2008-05-19 09:50:03,696 [TestRunnerThread] DEBUG NHibernate.Impl.SessionImpl - initializing collection [Core.billing.Invoice.lineItems#11010]
2008-05-19 09:50:03,696 [TestRunnerThread] DEBUG NHibernate.Impl.SessionImpl - checking second-level cache
2008-05-19 09:50:03,698 [TestRunnerThread] DEBUG NHibernate.Impl.SessionImpl - collection not cached
2008-05-19 09:50:03,701 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - loading collection: [Core.billing.Invoice.lineItems#11010]
2008-05-19 09:50:03,708 [TestRunnerThread] DEBUG NHibernate.Impl.BatcherImpl - Opened new IDbCommand, open IDbCommands: 1
2008-05-19 09:50:03,708 [TestRunnerThread] DEBUG NHibernate.Impl.BatcherImpl - Building an IDbCommand object for the SqlString: SELECT lineitems0_.INVOICE_VEOID as INVOICE5___1_, lineitems0_.VEOID as VEOID1_, lineitems0_.VEOID as VEOID1_0_, lineitems0_.DESCRIPTION as DESCRIPT2_1_0_, lineitems0_.UNIT_PRICE as UNIT3_1_0_, lineitems0_.QUANTITY as QUANTITY1_0_, lineitems0_.INVOICE_VEOID as INVOICE5_1_0_ FROM LINE_ITEM lineitems0_ WHERE lineitems0_.INVOICE_VEOID=?
2008-05-19 09:50:03,708 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - binding '11010' to parameter: 0
2008-05-19 09:50:03,710 [TestRunnerThread] INFO NHibernate.Loader.Loader - SELECT lineitems0_.INVOICE_VEOID as INVOICE5___1_, lineitems0_.VEOID as VEOID1_, lineitems0_.VEOID as VEOID1_0_, lineitems0_.DESCRIPTION as DESCRIPT2_1_0_, lineitems0_.UNIT_PRICE as UNIT3_1_0_, lineitems0_.QUANTITY as QUANTITY1_0_, lineitems0_.INVOICE_VEOID as INVOICE5_1_0_ FROM LINE_ITEM lineitems0_ WHERE lineitems0_.INVOICE_VEOID=@p0
2008-05-19 09:50:03,710 [TestRunnerThread] DEBUG NHibernate.SQL - SELECT lineitems0_.INVOICE_VEOID as INVOICE5___1_, lineitems0_.VEOID as VEOID1_, lineitems0_.VEOID as VEOID1_0_, lineitems0_.DESCRIPTION as DESCRIPT2_1_0_, lineitems0_.UNIT_PRICE as UNIT3_1_0_, lineitems0_.QUANTITY as QUANTITY1_0_, lineitems0_.INVOICE_VEOID as INVOICE5_1_0_ FROM LINE_ITEM lineitems0_ WHERE lineitems0_.INVOICE_VEOID=@p0; @p0 = '11010'
2008-05-19 09:50:03,751 [TestRunnerThread] DEBUG NHibernate.Impl.BatcherImpl - Opened IDataReader, open IDataReaders: 1
2008-05-19 09:50:03,752 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - result set contains (possibly empty) collection: [Core.billing.Invoice.lineItems#11010]
2008-05-19 09:50:03,753 [TestRunnerThread] DEBUG NHibernate.Impl.SessionImpl - uninitialized collection: initializing
2008-05-19 09:50:03,756 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - processing result set
2008-05-19 09:50:03,756 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - result set row: 0
2008-05-19 09:50:03,756 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '102' as column: VEOID1_0_
2008-05-19 09:50:03,756 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - result row: 102
2008-05-19 09:50:03,757 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - Initializing object from DataReader: [Core.billing.LineItem#102]
2008-05-19 09:50:03,757 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - Hydrating entity: Core.billing.LineItem#102
2008-05-19 09:50:03,757 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning 'test line item' as column: DESCRIPT2_1_0_
2008-05-19 09:50:03,757 [TestRunnerThread] DEBUG NHibernate.Type.SingleType - returning '2' as column: UNIT3_1_0_
2008-05-19 09:50:03,757 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '5' as column: QUANTITY1_0_
2008-05-19 09:50:03,758 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '11010' as column: INVOICE5_1_0_
2008-05-19 09:50:03,759 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '11010' as column: INVOICE5___1_
2008-05-19 09:50:03,760 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - found row of collection: [Core.billing.Invoice.lineItems#11010]
2008-05-19 09:50:03,760 [TestRunnerThread] DEBUG NHibernate.Impl.SessionImpl - reading row
2008-05-19 09:50:03,761 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '102' as column: VEOID1_
2008-05-19 09:50:03,764 [TestRunnerThread] DEBUG NHibernate.Impl.SessionImpl - loading [LineItem#102]
2008-05-19 09:50:03,767 [TestRunnerThread] DEBUG NHibernate.Impl.SessionImpl - attempting to resolve [LineItem#102]
2008-05-19 09:50:03,769 [TestRunnerThread] DEBUG NHibernate.Impl.SessionImpl - resolved object in session cache [Core.billing.LineItem#102]
2008-05-19 09:50:03,769 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - result set row: 1
2008-05-19 09:50:03,769 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '103' as column: VEOID1_0_
2008-05-19 09:50:03,770 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - result row: 103
2008-05-19 09:50:03,770 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - Initializing object from DataReader: [Core.billing.LineItem#103]
2008-05-19 09:50:03,770 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - Hydrating entity: Core.billing.LineItem#103
2008-05-19 09:50:03,770 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning 'test line item 2' as column: DESCRIPT2_1_0_
2008-05-19 09:50:03,770 [TestRunnerThread] DEBUG NHibernate.Type.SingleType - returning '2' as column: UNIT3_1_0_
2008-05-19 09:50:03,770 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '5' as column: QUANTITY1_0_
2008-05-19 09:50:03,770 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '11010' as column: INVOICE5_1_0_
2008-05-19 09:50:03,770 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '11010' as column: INVOICE5___1_
2008-05-19 09:50:03,770 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - found row of collection: [Core.billing.Invoice.lineItems#11010]
2008-05-19 09:50:03,770 [TestRunnerThread] DEBUG NHibernate.Impl.SessionImpl - reading row
2008-05-19 09:50:03,770 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '103' as column: VEOID1_
2008-05-19 09:50:03,770 [TestRunnerThread] DEBUG NHibernate.Impl.SessionImpl - loading [LineItem#103]
2008-05-19 09:50:03,770 [TestRunnerThread] DEBUG NHibernate.Impl.SessionImpl - attempting to resolve [LineItem#103]
2008-05-19 09:50:03,770 [TestRunnerThread] DEBUG NHibernate.Impl.SessionImpl - resolved object in session cache [Core.billing.LineItem#103]
2008-05-19 09:50:03,770 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - result set row: 2
2008-05-19 09:50:03,770 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '104' as column: VEOID1_0_
2008-05-19 09:50:03,770 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - result row: 104
2008-05-19 09:50:03,770 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - Initializing object from DataReader: [Core.billing.LineItem#104]
2008-05-19 09:50:03,770 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - Hydrating entity: Core.billing.LineItem#104
2008-05-19 09:50:03,770 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning 'test line imtem 3' as column: DESCRIPT2_1_0_
2008-05-19 09:50:03,770 [TestRunnerThread] DEBUG NHibernate.Type.SingleType - returning '2' as column: UNIT3_1_0_
2008-05-19 09:50:03,771 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '5' as column: QUANTITY1_0_
2008-05-19 09:50:03,771 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '11010' as column: INVOICE5_1_0_
2008-05-19 09:50:03,771 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '11010' as column: INVOICE5___1_
2008-05-19 09:50:03,771 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - found row of collection: [Core.billing.Invoice.lineItems#11010]
2008-05-19 09:50:03,771 [TestRunnerThread] DEBUG NHibernate.Impl.SessionImpl - reading row
2008-05-19 09:50:03,771 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '104' as column: VEOID1_
2008-05-19 09:50:03,771 [TestRunnerThread] DEBUG NHibernate.Impl.SessionImpl - loading [LineItem#104]
2008-05-19 09:50:03,771 [TestRunnerThread] DEBUG NHibernate.Impl.SessionImpl - attempting to resolve [LineItem#104]
2008-05-19 09:50:03,771 [TestRunnerThread] DEBUG NHibernate.Impl.SessionImpl - resolved object in session cache [Core.billing.LineItem#104]
2008-05-19 09:50:03,771 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - result set row: 3
2008-05-19 09:50:03,771 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '105' as column: VEOID1_0_
2008-05-19 09:50:03,771 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - result row: 105
2008-05-19 09:50:03,771 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - Initializing object from DataReader: [Core.billing.LineItem#105]
2008-05-19 09:50:03,771 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - Hydrating entity: Core.billing.LineItem#105
2008-05-19 09:50:03,771 [TestRunnerThread] DEBUG NHibernate.Type.StringType - returning 'test line imtem 4' as column: DESCRIPT2_1_0_
2008-05-19 09:50:03,771 [TestRunnerThread] DEBUG NHibernate.Type.SingleType - returning '2' as column: UNIT3_1_0_
2008-05-19 09:50:03,771 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '5' as column: QUANTITY1_0_
2008-05-19 09:50:03,771 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '11010' as column: INVOICE5_1_0_
2008-05-19 09:50:03,771 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '11010' as column: INVOICE5___1_
2008-05-19 09:50:03,771 [TestRunnerThread] DEBUG NHibernate.Loader.Loader - found row of collection: [Core.billing.Invoice.lineItems#11010]
2008-05-19 09:50:03,771 [TestRunnerThread] DEBUG NHibernate.Impl.SessionImpl - reading row
2008-05-19 09:50:03,771 [TestRunnerThread] DEBUG NHibernate.Type.Int32Type - returning '105' as column: VEOID1_
2008-05-19 09:50:03,771 [TestRunnerThread] DEBUG NHibernate.Impl.SessionImpl - loading [LineItem#105]

wolli · **Posted:** Mon May 19, 2008 11:03 am

Have a look at the last post in this thread (not exactly your problem, but result may be the same ...). Try remove generic="true".

exp2000 · **Joined:** Tue Oct 16, 2007 9:45 am **Posts:** 93

I changed the access="property" and changed the code to use RecordId (mapped property) instead of ObjectId in all of the code.
I still get the same result. It loads the collection when first one is requested. I changed the code to use specific index instead of iterator.
It seems to load it first time I access the collection.

It prints that collection is not initialized and then initializing collection and then it builds that select that fetches everything.

Code:

 
                    Console.WriteLine("Invoice: " + i.RecordId);
                    //Console.WriteLine(i.lineItems.Count());
                    Console.WriteLine("Bag initialized? " + NHibernate.NHibernateUtil.IsInitialized(i.lineItems));


                    Console.WriteLine("   LineItem:" + i.lineItems[0].RecordId.ToString());
                    Console.WriteLine("   LineItem:" + i.lineItems[1].RecordId.ToString());
                    Console.WriteLine("   LineItem:" + i.lineItems[2].RecordId.ToString());
                    Console.WriteLine("   LineItem:" + i.lineItems[3].RecordId.ToString());

[/code]

exp2000 · **Joined:** Tue Oct 16, 2007 9:45 am **Posts:** 93

wolli wrote:

Have a look at the last post in this thread (not exactly your problem, but result may be the same ...). Try remove generic="true".

I've done that too already. Here is how the mapping looks like now.

Code:

<?xml version="1.0" encoding="utf-8"?>
<hibernate-mapping
      xmlns="urn:nhibernate-mapping-2.2"
      default-cascade="none"
      auto-import="true"
      assembly="Core"
      namespace="Core.billing"
      default-lazy="true"
      >
  <class  name="Invoice"
            table="INVOICE"
            lazy="true"
             >
    <id name="RecordId"
        type="Int32"
        column="VEOID"
         access="property">
      <generator class="hilo">
        <param name="table">VE_COUNTERS2</param>
        <param name="column">INVOICE_NUMBER</param>
        <param name="max_lo">100</param>
      </generator>
    </id>
    <!--access="nosetter.camelcase-underscore"-->
    <property name = "number"
                  column = "NUMBER" length="255"
                  access="property"
              />

    <property name = "date"
                  column = "INV_DATE"
                   access="property"
              />

    <property name = "unpaidBalance"
                  column = "UNPAID_BALANCE" length="22"
                   access="property"
              />
    <!-- m 4 -->
    <bag name="lineItems" table="LINE_ITEM" cascade="all" lazy="true" batch-size="1"  inverse="true">
      <key column="INVOICE_VEOID"/>
      <one-to-many class="Core.billing.LineItem"/>
    </bag>

  </class>
</hibernate-mapping>

wolli · **Posted:** Mon May 19, 2008 11:45 am

Just to make some things clear, when you have a lazily loaded collection and access one of the items, the whole collection is loaded, not only the item you currently access. Specifiying a batch size does not change that behavior.

See chapter 15.1.5 of the reference doc:

Quote:

You may also enable batch fetching of collections. For example, if each Person has a lazy collection of Cats,
and 10 persons are currently loaded in the ISesssion, iterating through all persons will generate 10 SELECTs,
one for every call to person.Cats. If you enable batch fetching for the Cats collection in the mapping of Person,
NHibernate can pre-fetch collections:

With a batch-size of 3, NHibernate will load 3, 3, 3, 1 collections in four SELECTs. Again, the value of the attribute
depends on the expected number of uninitialized collections in a particular Session.

But executing your code, I wouldn't expect any database access, since you only access the id getter, which shouldn't cause an initialization of the items:

Code:

Console.WriteLine("Invoice: " + i.RecordId);
                    Console.WriteLine("Bag initialized? " + NHibernate.NHibernateUtil.IsInitialized(i.lineItems));

                    Console.WriteLine("   LineItem:" + i.lineItems[0].RecordId.ToString());
                    Console.WriteLine("   LineItem:" + i.lineItems[1].RecordId.ToString());
                    Console.WriteLine("   LineItem:" + i.lineItems[2].RecordId.ToString());
                    Console.WriteLine("   LineItem:" + i.lineItems[3].RecordId.ToString()); 

This line was always commented out ? Because this line will cause an initialization:

Code:

//Console.WriteLine(i.lineItems.Count());

With "It seems to load it first time I access the collection.", you mean this line ?:

Code:

Console.WriteLine(" LineItem:" + i.lineItems[0].RecordId.ToString());

exp2000 · **Joined:** Tue Oct 16, 2007 9:45 am **Posts:** 93

1. Yes, when I get to line that asks for a line item and index 0 then the whole collection gets loaded. I am debuging the code and it does this:
It calls AbstractPersistentCollection.Initialize -> ClollectionLoader.Initialize ->Loader.LoadCollection -> DoQueryandInitializeNonLazyCollection. This last method prepares dbcommand, gets the result set (whole collection) and hydrates the object.
Now next line that is asking for line item at index 1 just calls PersistentGenericBag indexer and returns the line item at index 1.

2. Yes specifing the batch size does not change a thing. That is why I in the begining explicitly set it to 1 to see if that would make a difference.

3. Yes the count line was only enabled in the very begining, as I wanted to see if it would fetch them all.

exp2000 · **Joined:** Tue Oct 16, 2007 9:45 am **Posts:** 93

If I look that the persister that has been loaded for this collection it looks like everything is ok here:

Code:

?ce.LoadedPersister
{OneToManyPersister(Core.billing.Invoice.lineItems)}
    [NHibernate.Persister.Collection.OneToManyPersister]: {OneToManyPersister(Intelliun.Core.billing.Invoice.lineItems)}
    Cache: null
    CollectionMetadata: {OneToManyPersister(Core.billing.Invoice.lineItems)}
    CollectionSpace: "LINE_ITEM"
    CollectionType: {NHibernate.Type.GenericBagType`1[Core.billing.LineItem] for Core.billing.Invoice.lineItems}
    ElementClass: null
    ElementType: {NHibernate.Type.ManyToOneType}
    Factory: {NHibernate.Impl.SessionFactoryImpl}
    HasCache: false
    HasIndex: false
    HasManyToManyOrdering: false
    HasOrdering: false
    HasOrphanDelete: false
    IdentifierGenerator: null
    IdentifierType: null
    IndexType: null
    IsArray: false
    IsInverse: true
    IsLazy: true
    IsOneToMany: true
    IsPrimitiveArray: false
    IsVersioned: false
    KeyType: {NHibernate.Type.Int32Type}
    OwnerClass: {Name = "Invoice" FullName = "Core.billing.Invoice"}
    Role: "Core.billing.Invoice.lineItems"

exp2000 · **Joined:** Tue Oct 16, 2007 9:45 am **Posts:** 93

If I look that the persister that has been loaded for this collection it looks like everything is ok here:

Code:

?ce.LoadedPersister
{OneToManyPersister(Core.billing.Invoice.lineItems)}
    [NHibernate.Persister.Collection.OneToManyPersister]: {OneToManyPersister(Core.billing.Invoice.lineItems)}
    Cache: null
    CollectionMetadata: {OneToManyPersister(Core.billing.Invoice.lineItems)}
    CollectionSpace: "LINE_ITEM"
    CollectionType: {NHibernate.Type.GenericBagType`1[Core.billing.LineItem] for Core.billing.Invoice.lineItems}
    ElementClass: null
    ElementType: {NHibernate.Type.ManyToOneType}
    Factory: {NHibernate.Impl.SessionFactoryImpl}
    HasCache: false
    HasIndex: false
    HasManyToManyOrdering: false
    HasOrdering: false
    HasOrphanDelete: false
    IdentifierGenerator: null
    IdentifierType: null
    IndexType: null
    IsArray: false
    IsInverse: true
    IsLazy: true
    IsOneToMany: true
    IsPrimitiveArray: false
    IsVersioned: false
    KeyType: {NHibernate.Type.Int32Type}
    OwnerClass: {Name = "Invoice" FullName = "Core.billing.Invoice"}
    Role: "Core.billing.Invoice.lineItems"

exp2000 · **Joined:** Tue Oct 16, 2007 9:45 am **Posts:** 93

I don't understand why this method is doing this.

Code:

      /// <summary>
      /// Called by subclasses that load collections
      /// </summary>
      public void LoadCollection(
         ISessionImplementor session,
         object id,
         IType type)
      {
         if (log.IsDebugEnabled)
         {
            log.Debug(
               "loading collection: " +
               MessageHelper.InfoString(CollectionPersisters[0], id)
               );
         }

         object[] ids = new object[] {id};
         try
         {
            DoQueryAndInitializeNonLazyCollections(
               session,
               new QueryParameters(new IType[] {type}, ids, ids),
               true
               );
         }
         catch (HibernateException)
         {
            // Do not call Convert on HibernateExceptions
            throw;
         }
         catch (Exception sqle)
         {
            throw ADOExceptionHelper.Convert(
               sqle,
               "could not initialize a collection: " +
               MessageHelper.InfoString(CollectionPersisters[0], id),
               SqlString
               );
         }

         log.Debug("done loading collection");
      }

wolli · **Posted:** Mon May 19, 2008 12:38 pm

I had a look at the PersistentGenericBag and all properties/methods accessing the items cause an initialization of the collection. But I couldn't instantly find out if this means creating proxies or really loading the items. According to your problems, it seems to be the latter.