It seems that collection overloading does not work propery for table-per-class hierarchy mapping, or a least it is not working the way I want it to. Of course, this is for a legacy system, so I have a limited amount of flexibility in my solution.
I've written a fairly simple unit test that demonstrates this problem. Through debugging, it seems that Hibernate thinks that there are 2 collections for the same role (see bold log entry below). The first collection that is loaded has the data that I want, but it is overwritten by the contents of the second collection, which is empty.
I have mapped a base class BaseDocument which has 2 subclasses, Voucher and Authorization. BaseDocument has a collection of Advance objects, but I want these Advance objects to be loaded differently for Voucher vs. Authorization. For Authorization, I use a simple bag mapping:
Code:
...
<subclass name="org.hibernate.test.a123.Authorization" discriminator-value="AUTH">
<bag name="advances" inverse="false">
<key>
<column name="colKey1" />
<column name="colKey2" />
<column name="DOCTYPE" />
</key>
<one-to-many class="org.hibernate.test.a123.Advance"/>
</bag>
</subclass>
For Voucher, I really want to load the collection of Advances using a custom query:
Code:
...
<subclass name="org.hibernate.test.a123.Voucher" discriminator-value="VCH">
<bag name="advances" inverse="false">
<key>
<column name="colKey1" />
<column name="colKey2" />
<column name="DOCTYPE" />
</key>
<one-to-many class="org.hibernate.test.a123.Advance"/>
<loader query-ref="loadAdvances"/>
</bag>
</subclass>
Voucher has an implicit relationship with Authorization, which is only expressed via another entity called Trip. Voucher's query for the bag of advances uses this join to load the collection:
Code:
<sql-query name="loadAdvances" >
<load-collection alias="a" role="org.hibernate.test.a123.Voucher.advances"/>
<![CDATA[
SELECT
{a.*}
FROM
TRIP t2,
TRIP t1,
VOUCHER v,
ADVANCE a
WHERE
t2.colKey1 = ? AND t2.colKey2 = ? AND t2.DOCTYPE = ?
AND t2.REFNUM = t1.REFNUM
AND t1.DOCTYPE='AUTH'
AND v.colKey1=t1.colKey1 AND v.colKey2=t1.colKey2 AND v.DOCTYPE=t1.DOCTYPE
AND v.colKey1=a.colKey1 AND v.colKey2=a.colKey2 AND v.DOCTYPE=a.DOCTYPE
]]></sql-query>
Hibernate version: 3.1
Mapping documents: See relevant snippets above
Code between sessionFactory.openSession() and session.close():
Voucher v1 = (Voucher)s.load(Voucher.class, vchKey);
assertNotNull(v1);
assertEquals(v1.getAdvances().size(), 1);
List vchAdvances = v1.getAdvances();
System.out.println("*** vchAdvances: " + vchAdvances);
Full stack trace of any exception that occurs:
Name and version of the database you are using:
Oracle, Unit test demonstrating this issue uses HSQL
The generated SQL (show_sql=true): See log excerpt below
Debug level Hibernate log excerpt:
09:01:30,755 DEBUG DefaultLoadEventListener:153 - loading entity: [org.hibernate.test.a123.Voucher#component[key1,key2,documentType]{key1=A, documentType=VCH, key2=A}]
09:01:30,755 DEBUG DefaultLoadEventListener:230 - creating new proxy for entity
09:01:30,765 DEBUG SessionImpl:824 - initializing proxy: [org.hibernate.test.a123.Voucher#component[key1,key2,documentType]{key1=A, documentType=VCH, key2=A}]
09:01:30,765 DEBUG DefaultLoadEventListener:304 - attempting to resolve: [org.hibernate.test.a123.Voucher#component[key1,key2,documentType]{key1=A, documentType=VCH, key2=A}]
09:01:30,765 DEBUG NonstrictReadWriteCache:39 - Cache lookup: org.hibernate.test.a123.BaseDocument#org.hibernate.test.a123.DocumentKey@14bbd
09:01:30,765 DEBUG NonstrictReadWriteCache:46 - Cache miss
09:01:30,765 DEBUG DefaultLoadEventListener:340 - object not resolved in any cache: [org.hibernate.test.a123.Voucher#component[key1,key2,documentType]{key1=A, documentType=VCH, key2=A}]
09:01:30,765 DEBUG AbstractEntityPersister:2723 - Fetching entity: [org.hibernate.test.a123.Voucher#component[key1,key2,documentType]{key1=A, documentType=VCH, key2=A}]
09:01:30,765 DEBUG Loader:1777 - loading entity: [org.hibernate.test.a123.Voucher#component[key1,key2,documentType]{key1=A, documentType=VCH, key2=A}]
09:01:30,765 DEBUG AbstractBatcher:311 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
09:01:30,775 DEBUG SQL:346 -
select
voucher0_.colKey1 as colKey1_0_0_,
voucher0_.colKey2 as colKey2_0_0_,
voucher0_.DOCTYPE as DOCTYPE0_0_
from
VOUCHER voucher0_
where
voucher0_.colKey1=?
and voucher0_.colKey2=?
and voucher0_.DOCTYPE=?
and voucher0_.DOCTYPE='VCH'
09:01:30,805 DEBUG AbstractBatcher:424 - preparing statement
09:01:30,805 DEBUG AbstractBatcher:327 - about to open ResultSet (open ResultSets: 0, globally: 0)
09:01:30,805 DEBUG Loader:682 - processing result set
09:01:30,805 DEBUG Loader:687 - result set row: 0
09:01:30,805 DEBUG Loader:1164 - result row: EntityKey[org.hibernate.test.a123.Voucher#component[key1,key2,documentType]{key1=A, documentType=VCH, key2=A}]
09:01:30,805 DEBUG Loader:1347 - Initializing object from ResultSet: [org.hibernate.test.a123.Voucher#component[key1,key2,documentType]{key1=A, documentType=VCH, key2=A}]
09:01:30,805 DEBUG AbstractEntityPersister:1860 - Hydrating entity: [org.hibernate.test.a123.Voucher#component[key1,key2,documentType]{key1=A, documentType=VCH, key2=A}]
09:01:30,805 DEBUG Loader:709 - done processing result set (1 rows)
09:01:30,805 DEBUG AbstractBatcher:334 - about to close ResultSet (open ResultSets: 1, globally: 1)
09:01:30,815 DEBUG AbstractBatcher:319 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
09:01:30,815 DEBUG AbstractBatcher:470 - closing statement
09:01:30,815 DEBUG Loader:839 - total objects hydrated: 1
09:01:30,815 DEBUG TwoPhaseLoad:104 - resolving associations for [org.hibernate.test.a123.Voucher#component[key1,key2,documentType]{key1=A, documentType=VCH, key2=A}]
09:01:30,815 DEBUG CollectionLoadContext:141 - creating collection wrapper:[org.hibernate.test.a123.Voucher.advances#component[key1,key2,documentType]{key1=A, documentType=VCH, key2=A}]
09:01:30,815 DEBUG StatefulPersistenceContext:767 - addCollection(): role=org.hibernate.test.a123.Voucher.advances, key=org.hibernate.test.a123.DocumentKey@14bbd
09:01:30,815 DEBUG StatefulPersistenceContext:769 - CollectionEntry:
09:01:30,815 DEBUG TwoPhaseLoad:132 - adding entity to second-level cache: [org.hibernate.test.a123.Voucher#component[key1,key2,documentType]{key1=A, documentType=VCH, key2=A}]
09:01:30,815 DEBUG NonstrictReadWriteCache:66 - Caching: org.hibernate.test.a123.BaseDocument#org.hibernate.test.a123.DocumentKey@14bbd
09:01:30,815 DEBUG TwoPhaseLoad:203 - done materializing entity [org.hibernate.test.a123.Voucher#component[key1,key2,documentType]{key1=A, documentType=VCH, key2=A}]
09:01:30,815 DEBUG StatefulPersistenceContext:856 - initializing non-lazy collections
09:01:30,815 DEBUG Loader:1808 - done entity load
09:01:30,825 DEBUG StatefulPersistenceContext:492 - containsCollection(): result=true, role=org.hibernate.test.a123.Voucher.advances, key=org.hibernate.test.a123.DocumentKey@14bbd
09:01:30,825 DEBUG AbstractPersistentCollection:204 - isConnectedToSession(): nullSession=false, session.isOpen()=true, containsCollection=true
09:01:30,825 DEBUG StatefulPersistenceContext:492 - containsCollection(): result=true, role=org.hibernate.test.a123.Voucher.advances, key=org.hibernate.test.a123.DocumentKey@14bbd
09:01:30,825 DEBUG AbstractPersistentCollection:204 - isConnectedToSession(): nullSession=false, session.isOpen()=true, containsCollection=true
09:01:30,825 DEBUG DefaultInitializeCollectionEventListener:41 - initializing collection [org.hibernate.test.a123.Voucher.advances#component[key1,key2,documentType]{key1=A, documentType=VCH, key2=A}]
09:01:30,825 DEBUG DefaultInitializeCollectionEventListener:47 - checking second-level cache
09:01:30,825 DEBUG NonstrictReadWriteCache:39 - Cache lookup: org.hibernate.test.a123.Voucher.advances#org.hibernate.test.a123.DocumentKey@14bbd
09:01:30,825 DEBUG NonstrictReadWriteCache:46 - Cache miss
09:01:30,825 DEBUG DefaultInitializeCollectionEventListener:59 - collection not cached
09:01:30,825 DEBUG NamedQueryCollectionInitializer:34 - initializing collection: org.hibernate.test.a123.Voucher.advances using named query: loadAdvances
09:01:30,835 DEBUG SessionImpl:1230 - setting flush mode to: NEVER
09:01:30,835 DEBUG QueryPlanCache:111 - unable to locate native-sql query plan in cache; generating (SELECT
{a.*}
FROM
TRIP t2,
TRIP t1,
VOUCHER v,
ADVANCE a
WHERE
t2.colKey1 = ? AND t2.colKey2 = ? AND t2.DOCTYPE = ?
AND t2.REFNUM = t1.REFNUM
AND t1.DOCTYPE='AUTH'
AND v.colKey1=t1.colKey1 AND v.colKey2=t1.colKey2 AND v.DOCTYPE=t1.DOCTYPE
AND v.colKey1=a.colKey1 AND v.colKey2=a.colKey2 AND v.DOCTYPE=a.DOCTYPE)
09:01:30,835 DEBUG SessionImpl:1597 - SQL query: SELECT
a.colKey1 as colKey2_0__, a.colKey2 as colKey3_0__, a.DOCTYPE as DOCTYPE0__, a.ID as ID0__, a.ID as ID1_0_, a.colKey1 as colKey2_1_0_, a.colKey2 as colKey3_1_0_, a.DOCTYPE as DOCTYPE1_0_, a.ADVAMT as ADVAMT1_0_
FROM
TRIP t2,
TRIP t1,
VOUCHER v,
ADVANCE a
WHERE
t2.colKey1 = ? AND t2.colKey2 = ? AND t2.DOCTYPE = ?
AND t2.REFNUM = t1.REFNUM
AND t1.DOCTYPE='AUTH'
AND v.colKey1=t1.colKey1 AND v.colKey2=t1.colKey2 AND v.DOCTYPE=t1.DOCTYPE
AND v.colKey1=a.colKey1 AND v.colKey2=a.colKey2 AND v.DOCTYPE=a.DOCTYPE
09:01:30,835 DEBUG AbstractBatcher:311 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
09:01:30,845 DEBUG SQL:346 -
SELECT
a.colKey1 as colKey2_0__,
a.colKey2 as colKey3_0__,
a.DOCTYPE as DOCTYPE0__,
a.ID as ID0__,
a.ID as ID1_0_,
a.colKey1 as colKey2_1_0_,
a.colKey2 as colKey3_1_0_,
a.DOCTYPE as DOCTYPE1_0_,
a.ADVAMT as ADVAMT1_0_
FROM
TRIP t2,
TRIP t1,
VOUCHER v,
ADVANCE a
WHERE
t2.colKey1 = ?
AND t2.colKey2 = ?
AND t2.DOCTYPE = ?
AND t2.REFNUM = t1.REFNUM
AND t1.DOCTYPE='AUTH'
AND v.colKey1=t1.colKey1
AND v.colKey2=t1.colKey2
AND v.DOCTYPE=t1.DOCTYPE
AND v.colKey1=a.colKey1
AND v.colKey2=a.colKey2
AND v.DOCTYPE=a.DOCTYPE
09:01:30,845 DEBUG AbstractBatcher:424 - preparing statement
09:01:30,845 DEBUG AbstractBatcher:327 - about to open ResultSet (open ResultSets: 0, globally: 0)
09:01:30,845 DEBUG Loader:1040 - result set contains (possibly empty) collection: [org.hibernate.test.a123.Voucher.advances#component[key1,key2,documentType]{key1=A, documentType=VCH, key2=A}]
09:01:30,845 DEBUG CollectionLoadContext:84 - uninitialized collection: initializing
09:01:30,845 DEBUG Loader:682 - processing result set
09:01:30,845 DEBUG Loader:687 - result set row: 0
09:01:30,845 DEBUG Loader:1164 - result row: EntityKey[org.hibernate.test.a123.Advance#1]
09:01:30,845 DEBUG Loader:1347 - Initializing object from ResultSet: [org.hibernate.test.a123.Advance#1]
09:01:30,845 DEBUG AbstractEntityPersister:1860 - Hydrating entity: [org.hibernate.test.a123.Advance#1]
09:01:30,845 DEBUG Loader:972 - found row of collection: [org.hibernate.test.a123.Voucher.advances#component[key1,key2,documentType]{key1=A, documentType=AUTH, key2=A}]
09:01:30,845 DEBUG CollectionLoadContext:100 - new collection: instantiating
09:01:30,845 DEBUG DefaultLoadEventListener:153 - loading entity: [org.hibernate.test.a123.Advance#1]
09:01:30,845 DEBUG DefaultLoadEventListener:304 - attempting to resolve: [org.hibernate.test.a123.Advance#1]
09:01:30,845 DEBUG DefaultLoadEventListener:313 - resolved object in session cache: [org.hibernate.test.a123.Advance#1]
09:01:30,845 DEBUG Loader:709 - done processing result set (1 rows)
09:01:30,845 DEBUG AbstractBatcher:334 - about to close ResultSet (open ResultSets: 1, globally: 1)
09:01:30,845 DEBUG AbstractBatcher:319 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
09:01:30,855 DEBUG AbstractBatcher:470 - closing statement
09:01:30,855 DEBUG Loader:839 - total objects hydrated: 1
09:01:30,855 DEBUG TwoPhaseLoad:104 - resolving associations for [org.hibernate.test.a123.Advance#1]
09:01:30,855 DEBUG TwoPhaseLoad:132 - adding entity to second-level cache: [org.hibernate.test.a123.Advance#1]
09:01:30,855 DEBUG NonstrictReadWriteCache:66 - Caching: org.hibernate.test.a123.Advance#1
09:01:30,855 DEBUG TwoPhaseLoad:203 - done materializing entity [org.hibernate.test.a123.Advance#1]
09:01:30,855 DEBUG CollectionLoadContext:262 - 2 collections were found in result set for role: org.hibernate.test.a123.Voucher.advances
09:01:30,855 DEBUG StatefulPersistenceContext:767 - addCollection(): role=org.hibernate.test.a123.Voucher.advances, key=org.hibernate.test.a123.DocumentKey@1ed62a
09:01:30,855 DEBUG StatefulPersistenceContext:769 - CollectionEntry:
09:01:30,855 DEBUG CollectionLoadContext:282 - Caching collection: [org.hibernate.test.a123.Voucher.advances#component[key1,key2,documentType]{key1=A, documentType=AUTH, key2=A}]
09:01:30,855 DEBUG NonstrictReadWriteCache:66 - Caching: org.hibernate.test.a123.Voucher.advances#org.hibernate.test.a123.DocumentKey@1ed62a
09:01:30,855 DEBUG CollectionLoadContext:206 - collection fully initialized: [org.hibernate.test.a123.Voucher.advances#component[key1,key2,documentType]{key1=A, documentType=AUTH, key2=A}]
09:01:30,855 DEBUG CollectionLoadContext:282 - Caching collection: [org.hibernate.test.a123.Voucher.advances#component[key1,key2,documentType]{key1=A, documentType=VCH, key2=A}]
09:01:30,855 DEBUG NonstrictReadWriteCache:66 - Caching: org.hibernate.test.a123.Voucher.advances#org.hibernate.test.a123.DocumentKey@14bbd
09:01:30,855 DEBUG CollectionLoadContext:206 - collection fully initialized: [org.hibernate.test.a123.Voucher.advances#component[key1,key2,documentType]{key1=A, documentType=VCH, key2=A}]
09:01:30,855 DEBUG CollectionLoadContext:272 - 2 collections initialized for role: org.hibernate.test.a123.Voucher.advances
09:01:30,855 DEBUG StatefulPersistenceContext:856 - initializing non-lazy collections
09:01:30,855 DEBUG SessionImpl:1230 - setting flush mode to: AUTO
09:01:30,855 DEBUG DefaultInitializeCollectionEventListener:61 - collection initialized
*** vchAdvances: []
09:01:30,855 DEBUG JDBCTransaction:103 - commit
09:01:30,855 DEBUG SessionImpl:352 - automatically flushing session
09:01:30,855 DEBUG AbstractFlushingEventListener:58 - flushing session
09:01:30,855 DEBUG AbstractFlushingEventListener:111 - processing flush-time cascades
09:01:30,886 DEBUG AbstractFlushingEventListener:153 - dirty checking collections
09:01:30,886 DEBUG AbstractFlushingEventListener:170 - Flushing entities and processing referenced collections
09:01:30,886 DEBUG Collections:176 - Collection found: [org.hibernate.test.a123.Voucher.advances#component[key1,key2,documentType]{key1=A, documentType=VCH, key2=A}], was: [org.hibernate.test.a123.Voucher.advances#component[key1,key2,documentType]{key1=A, documentType=VCH, key2=A}] (initialized)
09:01:30,896 DEBUG AbstractFlushingEventListener:209 - Processing unreferenced collections
09:01:30,896 DEBUG Collections:116 - Found collection with unloaded owner: [org.hibernate.test.a123.Voucher.advances#component[key1,key2,documentType]{key1=A, documentType=AUTH, key2=A}]
09:01:30,896 DEBUG AbstractFlushingEventListener:223 - Scheduling collection removes/(re)creates/updates
09:01:30,896 DEBUG AbstractFlushingEventListener:85 - Flushed: 0 insertions, 0 updates, 0 deletions to 2 objects
09:01:30,896 DEBUG AbstractFlushingEventListener:91 - Flushed: 0 (re)creations, 0 updates, 0 removals to 2 collections
09:01:30,896 DEBUG Printer:83 - listing entities:
09:01:30,896 DEBUG Printer:90 - org.hibernate.test.a123.Voucher{advances=[], documentKey=component[key1,key2,documentType]{key1=A, documentType=VCH, key2=A}}
09:01:30,896 DEBUG Printer:90 - org.hibernate.test.a123.Advance{advanceAmount=100.0, documentKey=component[key1,key2,documentType]{key1=A, documentType=AUTH, key2=A}, id=1}
09:01:30,896 DEBUG AbstractFlushingEventListener:289 - executing flush
09:01:30,896 DEBUG AbstractFlushingEventListener:316 - post flush
09:01:30,896 DEBUG JDBCContext:193 - before transaction completion
09:01:30,896 DEBUG SessionImpl:404 - before transaction completion
09:01:30,896 DEBUG JDBCTransaction:116 - committed JDBC Connection
09:01:30,896 DEBUG JDBCContext:207 - after transaction completion
09:01:30,896 DEBUG ConnectionManager:296 - aggressively releasing JDBC connection
09:01:30,896 DEBUG ConnectionManager:333 - closing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
09:01:30,896 DEBUG DriverManagerConnectionProvider:129 - returning connection to pool, pool size: 1
09:01:30,896 DEBUG SessionImpl:434 - after transaction completion
09:01:30,896 DEBUG SessionImpl:296 - closing session 5924809