Null references in collection

xtophe31 · **Joined:** Wed Jun 11, 2008 4:43 am **Posts:** 20

I try to set up a cascaded collection. It is a quite simple example (two persisted classes). But when I add a "child" to the parent and flush the parent, a null reference appears in the collection. It is the same when I try to reload the data: I get 2 childs although I added only once and the first is null.

Any idea why this happens?

Hibernate version: 3.2.6

Mapping documents:

Code:

<?xml version="1.0"?>
<!DOCTYPE hibernate-mapping PUBLIC
   "-//Hibernate/Hibernate Mapping DTD 3.0//EN"
   "http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd">
<hibernate-mapping package="org.myapp.tests.hibernate.model">
  <class name="Child">
     <id name="id" column="CHILDID">
        <generator class="increment"></generator>
     </id>
     <property name="name"></property>
     <many-to-one name="parent" column="PERSON_ID" class="Person"></many-to-one>
  </class>
</hibernate-mapping>

Code:

<?xml version="1.0"?>
<!DOCTYPE hibernate-mapping PUBLIC
   "-//Hibernate/Hibernate Mapping DTD 3.0//EN"
   "http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd">
<hibernate-mapping package="org.myapp.tests.hibernate.model">
  <class name="Person" table="PERSONS">
     <id name="id" column="PERSON_ID">
        <generator class="increment"></generator></id>
     <property name="name"></property>
     <list name="childs" cascade="all,delete-orphan" inverse="true">
        <key column="PERSON_ID"></key>
        <index column="CHILDID"></index>
        <one-to-many class="Child" />

     </list></class>
</hibernate-mapping>

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

Code:

package org.myapp.tests.hibernate.model;

import java.util.Iterator;
import java.util.List;

import org.apache.log4j.Logger;
import org.myapp.tests.hibernate.util.HibernateUtil;
import org.hibernate.HibernateException;
import org.hibernate.Session;

public class PersonManager {
   /**
    * A logger
    */
   private static final Logger logger = Logger.getLogger(PersonManager.class);

   private HibernateUtil hibernate;

   public static void main(String[] args) {
      PersonManager mgr = new PersonManager();
      mgr.createAndStoreEvent("My Person");
      mgr.restore();
   }

   public void createAndStoreEvent(String title) {
      HibernateUtil hibernate = new HibernateUtil(true);
      Session session = hibernate.getSessionFactory().getCurrentSession();
      try {
         session.beginTransaction();
         logger.debug("=====================================================");
         Person theEvent = new Person();
         theEvent.setName(title);
         session.save(theEvent);
         session.flush();
         logger.debug("=====================================================");
         session.getTransaction().commit();
      } catch (HibernateException e) {
         e.printStackTrace();
         session.getTransaction().rollback();
      } finally {
         hibernate.getSessionFactory().close();
      }
      hibernate = new HibernateUtil(true);
      session = hibernate.getSessionFactory().getCurrentSession();
      try {
         session.beginTransaction();
         logger.debug("=====================================================");
         Person theEvent = (Person) session.load(Person.class, (Long) 1L);
         Child child;
         child = new Child();
         child.setName("child_001");
         child.setParent(theEvent);
         theEvent.addChild(child);
         session.flush();
         for (Iterator<Child> iter = theEvent.getChilds().iterator();iter.hasNext();) {
            child = iter.next();
            if (child==null) {
               logger.debug("NULL child!!!");
            }
            else {
               logger.debug(child.getName());
            }
         }
         logger.debug("=====================================================");
         session.getTransaction().commit();
      } catch (HibernateException e) {
         e.printStackTrace();
         session.getTransaction().rollback();
      } finally {
         hibernate.getSessionFactory().close();
      }
   }
   
   public void restore() {
      HibernateUtil hibernate = new HibernateUtil(false);
      Session session = hibernate.getSessionFactory().getCurrentSession();
      try {
         session.beginTransaction();
         logger.debug("=====================================================");
         List events = session.createQuery("from Person").list();
         logger.debug("Nb persons: "+events.size());
         for (Iterator<Person> iter2 = events.iterator(); iter2.hasNext();) {
            Person p = iter2.next();
            logger.debug("Nb childs: "+p.getChilds().size());
            for (Iterator<Child> iter = p.getChilds().iterator();iter.hasNext();) {
               Child child = iter.next();
               if (child==null) {
                  logger.debug("NULL child!!!");
               }
               else {
                  logger.debug(child.getName());
               }
            }
         }
         logger.debug("=====================================================");
         session.getTransaction().commit();
      } catch (HibernateException e) {
         session.getTransaction().rollback();
         e.printStackTrace();
      } finally {
         hibernate.getSessionFactory().close();
      }
   }
}

Name and version of the database you are using: HSQLDB 1.8

The generated SQL (show_sql=true):

Code:

Hibernate: select max(PERSON_ID) from PERSONS
Hibernate: insert into PERSONS (name, PERSON_ID) values (?, ?)
Hibernate: select person0_.PERSON_ID as PERSON1_4_0_, person0_.name as name4_0_ from PERSONS person0_ where person0_.PERSON_ID=?
Hibernate: select max(CHILDID) from Child
Hibernate: insert into Child (name, PERSON_ID, CHILDID) values (?, ?, ?)
Hibernate: select childs0_.PERSON_ID as PERSON3_1_, childs0_.CHILDID as CHILDID1_, childs0_.CHILDID as CHILDID5_0_, childs0_.name as name5_0_, childs0_.PERSON_ID as PERSON3_5_0_ from Child childs0_ where childs0_.PERSON_ID=?
Hibernate: select person0_.PERSON_ID as PERSON1_8_, person0_.name as name8_ from PERSONS person0_
Hibernate: select childs0_.PERSON_ID as PERSON3_1_, childs0_.CHILDID as CHILDID1_, childs0_.CHILDID as CHILDID9_0_, childs0_.name as name9_0_, childs0_.PERSON_ID as PERSON3_9_0_ from Child childs0_ where childs0_.PERSON_ID=?

Debug level Hibernate log excerpt:

Code:

48:15,373 DEBUG PersonManager:30 - =====================================================
48:15,373 DEBUG ThreadLocalSessionContext:300 - allowing proxied method [save] to proceed to real session
48:15,389 DEBUG DefaultSaveOrUpdateEventListener:158 - saving transient instance
48:15,389 DEBUG IncrementGenerator:80 - fetching initial value: select max(PERSON_ID) from PERSONS
48:15,482 DEBUG IncrementGenerator:95 - first free id: 1
48:15,482 DEBUG AbstractSaveEventListener:112 - generated identifier: 1, using strategy: org.hibernate.id.IncrementGenerator
48:15,482 DEBUG AbstractSaveEventListener:153 - saving [org.myapp.tests.hibernate.model.Person#1]
48:15,482 DEBUG Cascade:115 - processing cascade ACTION_SAVE_UPDATE for: org.myapp.tests.hibernate.model.Person
48:15,482 DEBUG Cascade:150 - done processing cascade ACTION_SAVE_UPDATE for: org.myapp.tests.hibernate.model.Person
48:15,482 DEBUG WrapVisitor:87 - Wrapped collection in role: org.myapp.tests.hibernate.model.Person.childs
48:15,498 DEBUG Cascade:115 - processing cascade ACTION_SAVE_UPDATE for: org.myapp.tests.hibernate.model.Person
48:15,498 DEBUG Cascade:291 - cascade ACTION_SAVE_UPDATE for collection: org.myapp.tests.hibernate.model.Person.childs
48:15,498 DEBUG Cascade:306 - done cascade ACTION_SAVE_UPDATE for collection: org.myapp.tests.hibernate.model.Person.childs
48:15,498 DEBUG Cascade:317 - deleting orphans for collection: org.myapp.tests.hibernate.model.Person.childs
48:15,498 DEBUG Cascade:327 - done deleting orphans for collection: org.myapp.tests.hibernate.model.Person.childs
48:15,498 DEBUG Cascade:150 - done processing cascade ACTION_SAVE_UPDATE for: org.myapp.tests.hibernate.model.Person
48:15,498 DEBUG ThreadLocalSessionContext:300 - allowing proxied method [flush] to proceed to real session
48:15,498 DEBUG AbstractFlushingEventListener:58 - flushing session
48:15,498 DEBUG AbstractFlushingEventListener:111 - processing flush-time cascades
48:15,498 DEBUG Cascade:115 - processing cascade ACTION_SAVE_UPDATE for: org.myapp.tests.hibernate.model.Person
48:15,498 DEBUG Cascade:291 - cascade ACTION_SAVE_UPDATE for collection: org.myapp.tests.hibernate.model.Person.childs
48:15,498 DEBUG Cascade:306 - done cascade ACTION_SAVE_UPDATE for collection: org.myapp.tests.hibernate.model.Person.childs
48:15,498 DEBUG Cascade:317 - deleting orphans for collection: org.myapp.tests.hibernate.model.Person.childs
48:15,498 DEBUG Cascade:327 - done deleting orphans for collection: org.myapp.tests.hibernate.model.Person.childs
48:15,498 DEBUG Cascade:150 - done processing cascade ACTION_SAVE_UPDATE for: org.myapp.tests.hibernate.model.Person
48:15,498 DEBUG AbstractFlushingEventListener:154 - dirty checking collections
48:15,498 DEBUG AbstractFlushingEventListener:171 - Flushing entities and processing referenced collections
48:15,514 DEBUG Collections:176 - Collection found: [org.myapp.tests.hibernate.model.Person.childs#1], was: [<unreferenced>] (initialized)
48:15,514 DEBUG AbstractFlushingEventListener:210 - Processing unreferenced collections
48:15,514 DEBUG AbstractFlushingEventListener:224 - Scheduling collection removes/(re)creates/updates
48:15,514 DEBUG AbstractFlushingEventListener:85 - Flushed: 1 insertions, 0 updates, 0 deletions to 1 objects
48:15,514 DEBUG AbstractFlushingEventListener:91 - Flushed: 1 (re)creations, 0 updates, 0 removals to 1 collections
48:15,514 DEBUG Printer:83 - listing entities:
48:15,514 DEBUG Printer:90 - org.myapp.tests.hibernate.model.Person{childs=[], name=My Person, id=1}
48:15,514 DEBUG AbstractFlushingEventListener:290 - executing flush
48:15,514 DEBUG AbstractEntityPersister:2209 - Inserting entity: [org.myapp.tests.hibernate.model.Person#1]
48:15,514 DEBUG AbstractEntityPersister:1997 - Dehydrating entity: [org.myapp.tests.hibernate.model.Person#1]
48:15,529 DEBUG AbstractFlushingEventListener:321 - post flush
48:15,529 DEBUG PersonManager:35 - =====================================================
[...]
48:15,701 DEBUG PersonManager:47 - =====================================================
48:15,701 DEBUG ThreadLocalSessionContext:300 - allowing proxied method [load] to proceed to real session
48:15,701 DEBUG DefaultLoadEventListener:171 - loading entity: [org.myapp.tests.hibernate.model.Person#1]
48:15,701 DEBUG DefaultLoadEventListener:255 - creating new proxy for entity
48:15,717 DEBUG SessionImpl:832 - initializing proxy: [org.myapp.tests.hibernate.model.Person#1]
48:15,717 DEBUG DefaultLoadEventListener:332 - attempting to resolve: [org.myapp.tests.hibernate.model.Person#1]
48:15,717 DEBUG DefaultLoadEventListener:369 - object not resolved in any cache: [org.myapp.tests.hibernate.model.Person#1]
48:15,717 DEBUG AbstractEntityPersister:3042 - Fetching entity: [org.myapp.tests.hibernate.model.Person#1]
48:15,717 DEBUG Loader:1852 - loading entity: [org.myapp.tests.hibernate.model.Person#1]
48:15,717 DEBUG Loader:694 - processing result set
48:15,717 DEBUG Loader:699 - result set row: 0
48:15,717 DEBUG Loader:1173 - result row: EntityKey[org.myapp.tests.hibernate.model.Person#1]
48:15,717 DEBUG Loader:1355 - Initializing object from ResultSet: [org.myapp.tests.hibernate.model.Person#1]
48:15,717 DEBUG AbstractEntityPersister:2036 - Hydrating entity: [org.myapp.tests.hibernate.model.Person#1]
48:15,717 DEBUG Loader:721 - done processing result set (1 rows)
48:15,717 DEBUG Loader:851 - total objects hydrated: 1
48:15,717 DEBUG TwoPhaseLoad:111 - resolving associations for [org.myapp.tests.hibernate.model.Person#1]
48:15,717 DEBUG LoadContexts:194 - creating collection wrapper:[org.myapp.tests.hibernate.model.Person.childs#1]
48:15,717 DEBUG TwoPhaseLoad:209 - done materializing entity [org.myapp.tests.hibernate.model.Person#1]
48:15,717 DEBUG StatefulPersistenceContext:837 - initializing non-lazy collections
48:15,717 DEBUG Loader:1883 - done entity load
48:15,732 DEBUG ThreadLocalSessionContext:300 - allowing proxied method [flush] to proceed to real session
48:15,732 DEBUG AbstractFlushingEventListener:58 - flushing session
48:15,732 DEBUG AbstractFlushingEventListener:111 - processing flush-time cascades
48:15,732 DEBUG Cascade:115 - processing cascade ACTION_SAVE_UPDATE for: org.myapp.tests.hibernate.model.Person
48:15,732 DEBUG Cascade:291 - cascade ACTION_SAVE_UPDATE for collection: org.myapp.tests.hibernate.model.Person.childs
48:15,732 DEBUG CascadingAction:216 - cascading to saveOrUpdate: org.myapp.tests.hibernate.model.Child
48:15,732 DEBUG AbstractSaveEventListener:514 - transient instance of: org.myapp.tests.hibernate.model.Child
48:15,732 DEBUG DefaultSaveOrUpdateEventListener:158 - saving transient instance
48:15,732 DEBUG IncrementGenerator:80 - fetching initial value: select max(CHILDID) from Child
48:15,732 DEBUG IncrementGenerator:95 - first free id: 1
48:15,732 DEBUG AbstractSaveEventListener:112 - generated identifier: 1, using strategy: org.hibernate.id.IncrementGenerator
48:15,732 DEBUG AbstractSaveEventListener:153 - saving [org.myapp.tests.hibernate.model.Child#1]
48:15,732 DEBUG Cascade:306 - done cascade ACTION_SAVE_UPDATE for collection: org.myapp.tests.hibernate.model.Person.childs
48:15,732 DEBUG Cascade:317 - deleting orphans for collection: org.myapp.tests.hibernate.model.Person.childs
48:15,732 DEBUG Cascade:327 - done deleting orphans for collection: org.myapp.tests.hibernate.model.Person.childs
48:15,732 DEBUG Cascade:150 - done processing cascade ACTION_SAVE_UPDATE for: org.myapp.tests.hibernate.model.Person
48:15,732 DEBUG AbstractFlushingEventListener:154 - dirty checking collections
48:15,732 DEBUG CollectionEntry:177 - Collection dirty: [org.myapp.tests.hibernate.model.Person.childs#1]
48:15,732 DEBUG AbstractFlushingEventListener:171 - Flushing entities and processing referenced collections
48:15,732 DEBUG Collections:176 - Collection found: [org.myapp.tests.hibernate.model.Person.childs#1], was: [org.myapp.tests.hibernate.model.Person.childs#1] (uninitialized)
48:15,732 DEBUG AbstractFlushingEventListener:210 - Processing unreferenced collections
48:15,732 DEBUG AbstractFlushingEventListener:224 - Scheduling collection removes/(re)creates/updates
48:15,732 DEBUG AbstractFlushingEventListener:85 - Flushed: 1 insertions, 0 updates, 0 deletions to 2 objects
48:15,732 DEBUG AbstractFlushingEventListener:91 - Flushed: 0 (re)creations, 1 updates, 0 removals to 1 collections
48:15,732 DEBUG Printer:83 - listing entities:
48:15,732 DEBUG Printer:90 - org.myapp.tests.hibernate.model.Child{name=child_001, parent=org.myapp.tests.hibernate.model.Person#1, id=1}
48:15,732 DEBUG Printer:90 - org.myapp.tests.hibernate.model.Person{childs=<uninitialized>, name=My Person, id=1}
48:15,732 DEBUG AbstractFlushingEventListener:290 - executing flush
48:15,732 DEBUG AbstractEntityPersister:2209 - Inserting entity: [org.myapp.tests.hibernate.model.Child#1]
48:15,732 DEBUG AbstractEntityPersister:1997 - Dehydrating entity: [org.myapp.tests.hibernate.model.Child#1]
48:15,748 DEBUG AbstractFlushingEventListener:321 - post flush
48:15,748 DEBUG DefaultInitializeCollectionEventListener:44 - initializing collection [org.myapp.tests.hibernate.model.Person.childs#1]
48:15,748 DEBUG DefaultInitializeCollectionEventListener:50 - checking second-level cache
48:15,748 DEBUG DefaultInitializeCollectionEventListener:62 - collection not cached
48:15,748 DEBUG Loader:1986 - loading collection: [org.myapp.tests.hibernate.model.Person.childs#1]
48:15,748 DEBUG Loader:1054 - result set contains (possibly empty) collection: [org.myapp.tests.hibernate.model.Person.childs#1]
48:15,748 DEBUG LoadContexts:167 - constructing collection load context for result set [org.hsqldb.jdbc.jdbcResultSet@caf6c1]
48:15,748 DEBUG CollectionLoadContext:90 - starting attempt to find loading collection [[org.myapp.tests.hibernate.model.Person.childs#1]]
48:15,748 DEBUG CollectionLoadContext:103 - collection not yet initialized; initializing
48:15,748 DEBUG Loader:694 - processing result set
48:15,748 DEBUG Loader:699 - result set row: 0
48:15,748 DEBUG Loader:1173 - result row: EntityKey[org.myapp.tests.hibernate.model.Child#1]
48:15,748 DEBUG Loader:985 - found row of collection: [org.myapp.tests.hibernate.model.Person.childs#1]
48:15,748 DEBUG CollectionLoadContext:90 - starting attempt to find loading collection [[org.myapp.tests.hibernate.model.Person.childs#1]]
48:15,748 DEBUG LoadContexts:269 - attempting to locate loading collection entry [CollectionKey[org.myapp.tests.hibernate.model.Person.childs#1]] in any result-set context
48:15,748 DEBUG LoadContexts:277 - collection [CollectionKey[org.myapp.tests.hibernate.model.Person.childs#1]] located in load context
48:15,748 DEBUG CollectionLoadContext:134 - found loading collection bound to current result set processing; reading row
48:15,748 DEBUG DefaultLoadEventListener:171 - loading entity: [org.myapp.tests.hibernate.model.Child#1]
48:15,748 DEBUG DefaultLoadEventListener:332 - attempting to resolve: [org.myapp.tests.hibernate.model.Child#1]
48:15,748 DEBUG DefaultLoadEventListener:349 - resolved object in session cache: [org.myapp.tests.hibernate.model.Child#1]
48:15,748 DEBUG Loader:721 - done processing result set (1 rows)
48:15,748 DEBUG Loader:851 - total objects hydrated: 0
48:15,748 DEBUG LoadContexts:269 - attempting to locate loading collection entry [CollectionKey[org.myapp.tests.hibernate.model.Person.childs#1]] in any result-set context
48:15,748 DEBUG LoadContexts:277 - collection [CollectionKey[org.myapp.tests.hibernate.model.Person.childs#1]] located in load context
48:15,748 DEBUG CollectionLoadContext:186 - removing collection load entry [org.hibernate.engine.loading.LoadingCollectionEntry<rs=org.hsqldb.jdbc.jdbcResultSet@caf6c1, coll=[org.myapp.tests.hibernate.model.Person.childs#1]>@18e8541]
48:15,748 DEBUG CollectionLoadContext:217 - 1 collections were found in result set for role: org.myapp.tests.hibernate.model.Person.childs
48:15,748 DEBUG CollectionLoadContext:232 - ending loading collection [org.hibernate.engine.loading.LoadingCollectionEntry<rs=org.hsqldb.jdbc.jdbcResultSet@caf6c1, coll=[org.myapp.tests.hibernate.model.Person.childs#1]>@18e8541]
48:15,763 DEBUG CollectionLoadContext:263 - collection fully initialized: [org.myapp.tests.hibernate.model.Person.childs#1]
48:15,763 DEBUG CollectionLoadContext:226 - 1 collections initialized for role: org.myapp.tests.hibernate.model.Person.childs
48:15,763 DEBUG StatefulPersistenceContext:837 - initializing non-lazy collections
48:15,763 DEBUG Loader:2010 - done loading collection
48:15,763 DEBUG DefaultInitializeCollectionEventListener:64 - collection initialized
48:15,763 DEBUG PersonManager:60 - NULL child!!!
48:15,763 DEBUG PersonManager:63 - child_001
48:15,763 DEBUG PersonManager:67 - =====================================================
[...]
48:15,842 DEBUG PersonManager:93 - =====================================================
48:15,842 DEBUG ThreadLocalSessionContext:300 - allowing proxied method [createQuery] to proceed to real session
48:15,857 DEBUG QueryPlanCache:70 - unable to locate HQL query plan in cache; generating (from Person)
48:16,029 DEBUG HQLQueryPlan:269 - HQL param location recognition took 0 mills (from Person)
48:16,029 DEBUG QueryPlanCache:76 - located HQL query plan in cache (from Person)
48:16,029 DEBUG HQLQueryPlan:150 - find: from Person
48:16,029 DEBUG QueryParameters:277 - named parameters: {}
48:16,045 DEBUG Loader:694 - processing result set
48:16,045 DEBUG Loader:699 - result set row: 0
48:16,045 DEBUG Loader:1173 - result row: EntityKey[org.myapp.tests.hibernate.model.Person#1]
48:16,045 DEBUG Loader:1355 - Initializing object from ResultSet: [org.myapp.tests.hibernate.model.Person#1]
48:16,045 DEBUG AbstractEntityPersister:2036 - Hydrating entity: [org.myapp.tests.hibernate.model.Person#1]
48:16,045 DEBUG Loader:721 - done processing result set (1 rows)
48:16,045 DEBUG Loader:851 - total objects hydrated: 1
48:16,045 DEBUG TwoPhaseLoad:111 - resolving associations for [org.myapp.tests.hibernate.model.Person#1]
48:16,045 DEBUG LoadContexts:194 - creating collection wrapper:[org.myapp.tests.hibernate.model.Person.childs#1]
48:16,045 DEBUG TwoPhaseLoad:209 - done materializing entity [org.myapp.tests.hibernate.model.Person#1]
48:16,045 DEBUG StatefulPersistenceContext:837 - initializing non-lazy collections
48:16,045 DEBUG PersonManager:95 - Nb persons: 1
48:16,045 DEBUG DefaultInitializeCollectionEventListener:44 - initializing collection [org.myapp.tests.hibernate.model.Person.childs#1]
48:16,045 DEBUG DefaultInitializeCollectionEventListener:50 - checking second-level cache
48:16,045 DEBUG DefaultInitializeCollectionEventListener:62 - collection not cached
48:16,045 DEBUG Loader:1986 - loading collection: [org.myapp.tests.hibernate.model.Person.childs#1]
48:16,045 DEBUG Loader:1054 - result set contains (possibly empty) collection: [org.myapp.tests.hibernate.model.Person.childs#1]
48:16,045 DEBUG LoadContexts:167 - constructing collection load context for result set [org.hsqldb.jdbc.jdbcResultSet@1980630]
48:16,045 DEBUG CollectionLoadContext:90 - starting attempt to find loading collection [[org.myapp.tests.hibernate.model.Person.childs#1]]
48:16,045 DEBUG CollectionLoadContext:103 - collection not yet initialized; initializing
48:16,045 DEBUG Loader:694 - processing result set
48:16,045 DEBUG Loader:699 - result set row: 0
48:16,045 DEBUG Loader:1173 - result row: EntityKey[org.myapp.tests.hibernate.model.Child#1]
48:16,045 DEBUG Loader:1355 - Initializing object from ResultSet: [org.myapp.tests.hibernate.model.Child#1]
48:16,045 DEBUG AbstractEntityPersister:2036 - Hydrating entity: [org.myapp.tests.hibernate.model.Child#1]
48:16,045 DEBUG Loader:985 - found row of collection: [org.myapp.tests.hibernate.model.Person.childs#1]
48:16,045 DEBUG CollectionLoadContext:90 - starting attempt to find loading collection [[org.myapp.tests.hibernate.model.Person.childs#1]]
48:16,045 DEBUG LoadContexts:269 - attempting to locate loading collection entry [CollectionKey[org.myapp.tests.hibernate.model.Person.childs#1]] in any result-set context
48:16,045 DEBUG LoadContexts:277 - collection [CollectionKey[org.myapp.tests.hibernate.model.Person.childs#1]] located in load context
48:16,045 DEBUG CollectionLoadContext:134 - found loading collection bound to current result set processing; reading row
48:16,045 DEBUG DefaultLoadEventListener:171 - loading entity: [org.myapp.tests.hibernate.model.Child#1]
48:16,045 DEBUG DefaultLoadEventListener:332 - attempting to resolve: [org.myapp.tests.hibernate.model.Child#1]
48:16,045 DEBUG DefaultLoadEventListener:349 - resolved object in session cache: [org.myapp.tests.hibernate.model.Child#1]
48:16,045 DEBUG Loader:721 - done processing result set (1 rows)
48:16,045 DEBUG Loader:851 - total objects hydrated: 1
48:16,045 DEBUG TwoPhaseLoad:111 - resolving associations for [org.myapp.tests.hibernate.model.Child#1]
48:16,045 DEBUG DefaultLoadEventListener:171 - loading entity: [org.myapp.tests.hibernate.model.Person#1]
48:16,060 DEBUG DefaultLoadEventListener:244 - entity found in session cache
48:16,060 DEBUG TwoPhaseLoad:209 - done materializing entity [org.myapp.tests.hibernate.model.Child#1]
48:16,060 DEBUG LoadContexts:269 - attempting to locate loading collection entry [CollectionKey[org.myapp.tests.hibernate.model.Person.childs#1]] in any result-set context
48:16,060 DEBUG LoadContexts:277 - collection [CollectionKey[org.myapp.tests.hibernate.model.Person.childs#1]] located in load context
48:16,060 DEBUG CollectionLoadContext:186 - removing collection load entry [org.hibernate.engine.loading.LoadingCollectionEntry<rs=org.hsqldb.jdbc.jdbcResultSet@1980630, coll=[org.myapp.tests.hibernate.model.Person.childs#1]>@145e2d5]
48:16,060 DEBUG CollectionLoadContext:217 - 1 collections were found in result set for role: org.myapp.tests.hibernate.model.Person.childs
48:16,060 DEBUG CollectionLoadContext:232 - ending loading collection [org.hibernate.engine.loading.LoadingCollectionEntry<rs=org.hsqldb.jdbc.jdbcResultSet@1980630, coll=[org.myapp.tests.hibernate.model.Person.childs#1]>@145e2d5]
48:16,060 DEBUG CollectionLoadContext:263 - collection fully initialized: [org.myapp.tests.hibernate.model.Person.childs#1]
48:16,060 DEBUG CollectionLoadContext:226 - 1 collections initialized for role: org.myapp.tests.hibernate.model.Person.childs
48:16,060 DEBUG StatefulPersistenceContext:837 - initializing non-lazy collections
48:16,060 DEBUG Loader:2010 - done loading collection
48:16,060 DEBUG DefaultInitializeCollectionEventListener:64 - collection initialized
48:16,060 DEBUG PersonManager:98 - Nb childs: 2
48:16,060 DEBUG PersonManager:102 - NULL child!!!
48:16,060 DEBUG PersonManager:105 - child_001
48:16,060 DEBUG PersonManager:109 - =====================================================

Cameron McKenzie · **Posted:** Mon Jun 23, 2008 1:45 pm

Try to save the child side of the relationship:

session.saveOrUpdate(child);

Then see what happens.

This little article gets passed around quite a bit. It's good:

http://en.wikibooks.org/wiki/Java_Persistence/Relationships

Report back!

-Cameron McKenzie

xtophe31 · **Joined:** Wed Jun 11, 2008 4:43 am **Posts:** 20

Ok, I've tried two or three things...
First I tried to save the child before but it did not helped (by the way, the Hibernate guide do not mention to save the child before).
Then I tried to add several childs, flushing after each addition and the NULL reference stays.
Finally, I tried to add several chids and to flush only when I've finished to add them. In this cas, the null reference does not appear after the flush. But when I read the data back, the first child is replaced by a NULL reference.
Any idea on what's happening?

croudet · **Joined:** Mon Apr 19, 2004 6:54 pm **Posts:** 79

I think you use the same column name for the collection index and child id.
Try to change

Code:

with

Code:

Christophe

xtophe31 · **Joined:** Wed Jun 11, 2008 4:43 am **Posts:** 20

Oh thx a lot, you're right... In fact I thought a list-index could be an existing column.
When I flush my collection, the null element does not appear any more. However, when I try to load it throw me a "null index column" exception. Should I populate this column? And if yes, how, as I do not have an attribute for this column?

gibiman · **Joined:** Mon Jul 30, 2007 5:03 am **Posts:** 8

I have the same problem . Actually hibernate inserts null into the list-index column . One work-around would be to insert the value by hand , but that's not an elegant solution .