Custom SQL for loading - is this a bug?

cemartins · **Posted:** Fri May 19, 2006 1:58 pm

I have a problem using custom SQL for loading a collection.
coded this small test case just for demonstration purposes, and I have these rows in the database:

Code:

mysql> select * from docsituation;
+----+--------------+------------------------+
| id | operation_id | abrev                  |
+----+--------------+------------------------+
|  1 |            1 | Document situation one |
|  2 |            2 | Document situation two |
+----+--------------+------------------------+

mysql> select * from docitem;
+----+--------------+-----------------+--------------------+
| id | operation_id | docsituation_id | abrev              |
+----+--------------+-----------------+--------------------+
|  1 |            1 |               1 | Document item one  |
|  2 |            1 |               1 | Document item two  |
|  3 |            1 |               1 | Document item tree |
|  4 |            2 |               2 | Document item four |
+----+--------------+-----------------+--------------------+

In teh test case I load the "Docsituation 1" and initialize the collection docItems.
And although the log shows that all three docItems are initialized, the collection turns out with one item only....
Is this a bug?....

Any help will be much appreciated.

Hibernate version: 3.1.3

Mapping documents:
Document Situation:

Code:

<hibernate-mapping>
    <class name="Docsituation" table="docsituation" proxy="Docsituation">
        <comment>Document Situation</comment>
        <id name="id" type="java.lang.Integer">
            <column name="id" />
            <generator class="assigned" />
        </id>
        <many-to-one name="operation" class="Operation">
            <column name="operation_id" />
        </many-to-one>
        <property name="abrev" type="string">
            <column name="abrev">
                <comment></comment>
            </column>
        </property>
        <set name="docItems" inverse="true">
           <key column="id" />
           <one-to-many class="Docitem" />
         <loader query-ref="Docsituation.docItemsQuery"/>           
        </set>
        <sql-query name="docItemsQuery">
           <load-collection lock-mode="read" alias="dn" role="Docsituation.docItems"/>
           <return alias="dn" class="Docitem" />
               (select {dn.*}
               from docitem dn
               where dn.docsituation_id = :id)
      </sql-query>
    </class>
</hibernate-mapping>

Document Item:

Code:

<hibernate-mapping>
    <class name="Docitem" table="docitem" proxy="Docitem">
        <comment>Document Item</comment>
        <id name="id" type="java.lang.Integer">
            <column name="id" />
            <generator class="assigned" />
        </id>
        <many-to-one name="operation" class="Operation">
            <column name="operation_id" />
        </many-to-one>
        <property name="docsituationId" type="java.lang.Integer">
            <column name="docsituation_id">
                <comment></comment>
            </column>
        </property>
        <property name="abrev" type="string">
            <column name="abrev">
                <comment></comment>
            </column>
        </property>
    </class>
</hibernate-mapping>

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

Code:

      Session s = getSession();
      Docsituation ds = (Docsituation) s.load(Docsituation.class, new Integer(1));
      Set docItems = ds.getDocItems();
      Hibernate.initialize(docItems);
      Docitem di;
      logger.info("found document situation: " + ds.getAbrev());
      logger.info("with " + docItems.size() + " documents");
      Iterator i = docItems.iterator();
      while(i.hasNext()) {
         di = (Docitem) i.next();
         logger.info("  item: " + di.getAbrev());
      }

Name and version of the database: MySQL 4.1.12a-nt

Debug level Hibernate log excerpt:

Code:

DEBUG DefaultLoadEventListener:153 - loading entity: [Docsituation#1]
DEBUG DefaultLoadEventListener:230 - creating new proxy for entity
DEBUG JDBCContext:217 - after autocommit
DEBUG ConnectionManager:398 - aggressively releasing JDBC connection
DEBUG SessionImpl:417 - after transaction completion
DEBUG SessionImpl:816 - initializing proxy: [Docsituation#1]
DEBUG DefaultLoadEventListener:304 - attempting to resolve: [Docsituation#1]
DEBUG DefaultLoadEventListener:340 - object not resolved in any cache: [Docsituation#1]
DEBUG AbstractEntityPersister:2723 - Fetching entity: [Docsituation#1]
DEBUG Loader:1777 - loading entity: [Docsituation#1]
DEBUG AbstractBatcher:311 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
DEBUG ConnectionManager:415 - opening JDBC connection
DEBUG DriverManagerConnectionProvider:93 - total checked-out connections: 0
DEBUG DriverManagerConnectionProvider:99 - using pooled JDBC connection, pool size: 0
DEBUG SQL:346 - select docsituati0_.id as id1_0_, docsituati0_.operation_id as operation2_1_0_, docsituati0_.abrev as abrev1_0_ from docsituation docsituati0_ where docsituati0_.id=?
Hibernate: select docsituati0_.id as id1_0_, docsituati0_.operation_id as operation2_1_0_, docsituati0_.abrev as abrev1_0_ from docsituation docsituati0_ where docsituati0_.id=?
DEBUG AbstractBatcher:424 - preparing statement
DEBUG AbstractBatcher:327 - about to open ResultSet (open ResultSets: 0, globally: 0)
DEBUG Loader:682 - processing result set
DEBUG Loader:687 - result set row: 0
DEBUG Loader:1164 - result row: EntityKey[Docsituation#1]
DEBUG Loader:1347 - Initializing object from ResultSet: [Docsituation#1]
DEBUG AbstractEntityPersister:1860 - Hydrating entity: [Docsituation#1]
DEBUG Loader:709 - done processing result set (1 rows)
DEBUG AbstractBatcher:334 - about to close ResultSet (open ResultSets: 1, globally: 1)
DEBUG AbstractBatcher:319 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
DEBUG AbstractBatcher:470 - closing statement
DEBUG Loader:839 - total objects hydrated: 1
DEBUG TwoPhaseLoad:107 - resolving associations for [Docsituation#1]
DEBUG DefaultLoadEventListener:153 - loading entity: [Operation#1]
DEBUG DefaultLoadEventListener:230 - creating new proxy for entity
DEBUG CollectionLoadContext:141 - creating collection wrapper:[Docsituation.docItems#1]
DEBUG TwoPhaseLoad:206 - done materializing entity [Docsituation#1]
DEBUG StatefulPersistenceContext:748 - initializing non-lazy collections
DEBUG Loader:1808 - done entity load
DEBUG DefaultInitializeCollectionEventListener:41 - initializing collection [Docsituation.docItems#1]
DEBUG DefaultInitializeCollectionEventListener:47 - checking second-level cache
DEBUG DefaultInitializeCollectionEventListener:59 - collection not cached
DEBUG NamedQueryCollectionInitializer:34 - initializing collection: Docsituation.docItems using named query: Docsituation.docItemsQuery
DEBUG SessionImpl:1253 - setting flush mode to: NEVER
DEBUG QueryPlanCache:117 - located native-sql query plan in cache ((select {dn.*}
         from docitem dn
         where dn.docsituation_id = :id))
DEBUG SessionImpl:1645 - SQL query: (select dn.id as id0__, dn.id as id0_0_, dn.operation_id as operation2_0_0_, dn.docsituation_id as docsitua3_0_0_, dn.abrev as abrev0_0_
         from docitem dn
         where dn.docsituation_id = ?)
DEBUG AbstractBatcher:311 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
DEBUG SQL:346 - (select dn.id as id0__, dn.id as id0_0_, dn.operation_id as operation2_0_0_, dn.docsituation_id as docsitua3_0_0_, dn.abrev as abrev0_0_
         from docitem dn
         where dn.docsituation_id = ?)
Hibernate: (select dn.id as id0__, dn.id as id0_0_, dn.operation_id as operation2_0_0_, dn.docsituation_id as docsitua3_0_0_, dn.abrev as abrev0_0_
         from docitem dn
         where dn.docsituation_id = ?)
DEBUG AbstractBatcher:424 - preparing statement
DEBUG Loader:1742 - bindNamedParameters() 1 -> id [1]
DEBUG AbstractBatcher:327 - about to open ResultSet (open ResultSets: 0, globally: 0)
DEBUG Loader:1040 - result set contains (possibly empty) collection: [Docsituation.docItems#1]
DEBUG CollectionLoadContext:84 - uninitialized collection: initializing
DEBUG Loader:682 - processing result set
DEBUG Loader:687 - result set row: 0
DEBUG Loader:1164 - result row: EntityKey[Docitem#1]
DEBUG Loader:1347 - Initializing object from ResultSet: [Docitem#1]
DEBUG AbstractEntityPersister:1860 - Hydrating entity: [Docitem#1]
DEBUG Loader:972 - found row of collection: [Docsituation.docItems#1]
DEBUG CollectionLoadContext:112 - reading row
DEBUG DefaultLoadEventListener:153 - loading entity: [Docitem#1]
DEBUG DefaultLoadEventListener:304 - attempting to resolve: [Docitem#1]
DEBUG DefaultLoadEventListener:313 - resolved object in session cache: [Docitem#1]
DEBUG Loader:687 - result set row: 1
DEBUG Loader:1164 - result row: EntityKey[Docitem#2]
DEBUG Loader:1347 - Initializing object from ResultSet: [Docitem#2]
DEBUG AbstractEntityPersister:1860 - Hydrating entity: [Docitem#2]
DEBUG Loader:972 - found row of collection: [Docsituation.docItems#2]
DEBUG CollectionLoadContext:100 - new collection: instantiating
DEBUG DefaultLoadEventListener:153 - loading entity: [Docitem#2]
DEBUG DefaultLoadEventListener:304 - attempting to resolve: [Docitem#2]
DEBUG DefaultLoadEventListener:313 - resolved object in session cache: [Docitem#2]
DEBUG Loader:687 - result set row: 2
DEBUG Loader:1164 - result row: EntityKey[Docitem#3]
DEBUG Loader:1347 - Initializing object from ResultSet: [Docitem#3]
DEBUG AbstractEntityPersister:1860 - Hydrating entity: [Docitem#3]
DEBUG Loader:972 - found row of collection: [Docsituation.docItems#3]
DEBUG CollectionLoadContext:100 - new collection: instantiating
DEBUG DefaultLoadEventListener:153 - loading entity: [Docitem#3]
DEBUG DefaultLoadEventListener:304 - attempting to resolve: [Docitem#3]
DEBUG DefaultLoadEventListener:313 - resolved object in session cache: [Docitem#3]
DEBUG Loader:709 - done processing result set (3 rows)
DEBUG AbstractBatcher:334 - about to close ResultSet (open ResultSets: 1, globally: 1)
DEBUG AbstractBatcher:319 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
DEBUG AbstractBatcher:470 - closing statement
DEBUG Loader:839 - total objects hydrated: 3
DEBUG TwoPhaseLoad:107 - resolving associations for [Docitem#1]
DEBUG DefaultLoadEventListener:153 - loading entity: [Operation#1]
DEBUG DefaultLoadEventListener:196 - entity proxy found in session cache
DEBUG TwoPhaseLoad:206 - done materializing entity [Docitem#1]
DEBUG TwoPhaseLoad:107 - resolving associations for [Docitem#2]
DEBUG DefaultLoadEventListener:153 - loading entity: [Operation#1]
DEBUG DefaultLoadEventListener:196 - entity proxy found in session cache
DEBUG TwoPhaseLoad:206 - done materializing entity [Docitem#2]
DEBUG TwoPhaseLoad:107 - resolving associations for [Docitem#3]
DEBUG DefaultLoadEventListener:153 - loading entity: [Operation#1]
DEBUG DefaultLoadEventListener:196 - entity proxy found in session cache
DEBUG TwoPhaseLoad:206 - done materializing entity [Docitem#3]
DEBUG CollectionLoadContext:262 - 3 collections were found in result set for role: Docsituation.docItems
DEBUG CollectionLoadContext:206 - collection fully initialized: [Docsituation.docItems#1]
DEBUG CollectionLoadContext:206 - collection fully initialized: [Docsituation.docItems#2]
DEBUG CollectionLoadContext:206 - collection fully initialized: [Docsituation.docItems#3]
DEBUG CollectionLoadContext:272 - 3 collections initialized for role: Docsituation.docItems
DEBUG StatefulPersistenceContext:748 - initializing non-lazy collections
DEBUG JDBCContext:217 - after autocommit
DEBUG ConnectionManager:398 - aggressively releasing JDBC connection
DEBUG ConnectionManager:435 - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
DEBUG DriverManagerConnectionProvider:129 - returning connection to pool, pool size: 1
DEBUG SessionImpl:1253 - setting flush mode to: AUTO
DEBUG DefaultInitializeCollectionEventListener:61 - collection initialized
 INFO TestCollectionLoader:58 - found document situation: Document situation one
 INFO TestCollectionLoader:59 - with 1 documents
 INFO TestCollectionLoader:63 -   item: Document item one

kochcp · **Posted:** Fri May 19, 2006 2:27 pm

specify a hashCode method for the DocItems class. If it says 3 items are initialized, the Set's gotta be where they're lost. You can specify which attributes are used by the hashCode method (if you're using hbm2java) by using the <meta attribute="use-in-equals">true</meta>

and I don't know if you know this, but this works also
Hibernate.initialize(ds.getDocItems());

:)

cemartins · **Posted:** Fri May 19, 2006 2:54 pm

Thanks for your help anyway, but I have both equals and hashCode like this:

Code:

   public boolean equals(Object other) {
      if(this == other)
         return true;
      if(!(other instanceof Docitem))
         return false;
      Docitem castOther = (Docitem) other;
      return (castOther.getId().equals(this.getId()));
   }
   
   public int hashCode() {
        if (this.getId() == null) return System.identityHashCode(this);
        return new HashCodeBuilder().append(getId()).append(getAbrev()).toHashCode();

   }