-->
These old forums are deprecated now and set to read-only. We are waiting for you on our new forums!
More modern, Discourse-based and with GitHub/Google/Twitter authentication built-in.

All times are UTC - 5 hours [ DST ]



Forum locked This topic is locked, you cannot edit posts or make further replies.  [ 1 post ] 
Author Message
 Post subject: Unidirectional 1:N bag loads entire collection on insert
PostPosted: Tue Jun 14, 2005 8:02 am 
Newbie

Joined: Mon Jun 13, 2005 4:42 pm
Posts: 1
Hibernate version:
3.0.4

Mapping documents:
Child:
Code:
<?xml version="1.0" encoding="UTF-8"?>

<!DOCTYPE hibernate-mapping PUBLIC
    "-//Hibernate/Hibernate Mapping DTD 3.0//EN"
    "http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd">

<hibernate-mapping
>
    <class
        name="test.Child"
    >

        <id
            name="id"
            column="id"
            type="java.lang.Long"
        >
            <generator class="native">
              <!-- 
                  To add non XDoclet generator parameters, create a file named
                  hibernate-generator-params-Child.xml
                  containing the additional parameters and place it in your merge dir.
              -->
            </generator>
        </id>

        <!--
            To add non XDoclet property mappings, create a file named
                hibernate-properties-Child.xml
            containing the additional properties and place it in your merge dir.
        -->

    </class>

</hibernate-mapping>


Parent:
Code:
<?xml version="1.0" encoding="UTF-8"?>

<!DOCTYPE hibernate-mapping PUBLIC
    "-//Hibernate/Hibernate Mapping DTD 3.0//EN"
    "http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd">

<hibernate-mapping
>
    <class
        name="test.Parent"
    >

        <id
            name="id"
            column="id"
            type="java.lang.Long"
        >
            <generator class="native">
              <!-- 
                  To add non XDoclet generator parameters, create a file named
                  hibernate-generator-params-Parent.xml
                  containing the additional parameters and place it in your merge dir.
              -->
            </generator>
        </id>

        <bag
            name="children"
            lazy="true"
            inverse="false"
            cascade="all"
        >

            <key
                column="parent"
            >
            </key>

            <one-to-many
                  class="test.Child"
            />

      </bag>

        <!--
            To add non XDoclet property mappings, create a file named
                hibernate-properties-Parent.xml
            containing the additional properties and place it in your merge dir.
        -->

    </class>

</hibernate-mapping>


Code between sessionFactory.openSession() and session.close():
Code:
Parent parent = (Parent)session.createQuery("from Parent").list().get(0);
Child child = new Child();
parent.getChildren().add(child);
child.setParent(parent);


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

Debug level Hibernate log excerpt:
Code:
18:39:42,296 DEBUG SessionImpl:829 - find: from Parent
18:39:42,296 DEBUG QueryParameters:220 - named parameters: {}
18:39:42,500 DEBUG QueryTranslatorImpl:207 - parse() - HQL: from test.Parent
18:39:42,531 DEBUG AST:223 - --- HQL AST ---
\-[QUERY] 'query'
    \-[SELECT_FROM] 'SELECT_FROM'
       \-[FROM] 'from'
          \-[RANGE] 'RANGE'
             \-[DOT] '.'
                +-[IDENT] 'test'
                \-[IDENT] 'Parent'

18:39:42,531 DEBUG ErrorCounter:72 - throwQueryException() : no errors
18:39:42,656 DEBUG HqlSqlBaseWalker:120 - query() << begin, level = 1
18:39:42,734 DEBUG FromElement:88 - FromClause{level=1} :  test.Parent (no alias) -> parent0_
18:39:42,734 DEBUG HqlSqlBaseWalker:125 - query() : finishing up , level = 1
18:39:42,750 DEBUG HqlSqlWalker:331 - processQuery() :  ( SELECT ( FromClause{level=1} Parent parent0_ ) )
18:39:42,781 DEBUG HqlSqlWalker:451 - Derived SELECT clause created.
18:39:42,796 DEBUG JoinProcessor:112 - Using FROM fragment [Parent parent0_]
18:39:42,796 DEBUG HqlSqlBaseWalker:128 - query() >> end, level = 1
18:39:42,812 DEBUG AST:193 - --- SQL AST ---
\-[SELECT] QueryNode: 'SELECT'  querySpaces (Parent)
    +-[SELECT_CLAUSE] SelectClause: '{derived select clause}'
    |  \-[SELECT_EXPR] SelectExpressionImpl: 'parent0_.id as id' {FromElement{explicit,not a collection join,not a fetch join,fetch non-lazy properties,classAlias=null,role=null,tableName=Parent,tableAlias=parent0_,colums={,className=test.Parent}}}
    \-[FROM] FromClause: 'from' FromClause{level=1, fromElementCounter=1, fromElements=1, fromElementByClassAlias=[], fromElementByTableAlias=[parent0_], fromElementsByPath=[], collectionJoinFromElementsByPath=[], impliedElements=[]}
       \-[FROM_FRAGMENT] FromElement: 'Parent parent0_' FromElement{explicit,not a collection join,not a fetch join,fetch non-lazy properties,classAlias=null,role=null,tableName=Parent,tableAlias=parent0_,colums={,className=test.Parent}}

18:39:42,812 DEBUG ErrorCounter:72 - throwQueryException() : no errors
18:39:42,859 DEBUG QueryTranslatorImpl:177 - HQL: from test.Parent
18:39:42,859 DEBUG QueryTranslatorImpl:178 - SQL: select parent0_.id as id from Parent parent0_
18:39:42,859 DEBUG ErrorCounter:72 - throwQueryException() : no errors
18:39:42,875 DEBUG AbstractBatcher:290 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
18:39:42,875 DEBUG SQL:324 - select parent0_.id as id from Parent parent0_
Hibernate: select parent0_.id as id from Parent parent0_
18:39:42,875 DEBUG AbstractBatcher:378 - preparing statement
18:39:42,984 DEBUG AbstractBatcher:306 - about to open ResultSet (open ResultSets: 0, globally: 0)
18:39:42,984 DEBUG Loader:398 - processing result set
18:39:42,984 DEBUG Loader:403 - result set row: 0
18:39:42,984 DEBUG LongType:86 - returning '1' as column: id
18:39:43,000 DEBUG Loader:821 - result row: EntityKey[test.Parent#1]
18:39:43,000 DEBUG Loader:971 - Initializing object from ResultSet: [test.Parent#1]
18:39:43,000 DEBUG BasicEntityPersister:1651 - Hydrating entity: [test.Parent#1]
18:39:43,015 DEBUG Loader:422 - done processing result set (1 rows)
18:39:43,015 DEBUG AbstractBatcher:313 - about to close ResultSet (open ResultSets: 1, globally: 1)
18:39:43,015 DEBUG AbstractBatcher:298 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
18:39:43,015 DEBUG AbstractBatcher:416 - closing statement
18:39:43,015 DEBUG Loader:521 - total objects hydrated: 1
18:39:43,031 DEBUG TwoPhaseLoad:96 - resolving associations for [test.Parent#1]
18:39:43,046 DEBUG CollectionLoadContext:141 - creating collection wrapper:[test.Parent.children#1]
18:39:43,046 DEBUG TwoPhaseLoad:167 - done materializing entity [test.Parent#1]
18:39:43,046 DEBUG PersistenceContext:789 - initializing non-lazy collections
18:39:43,046 DEBUG DefaultInitializeCollectionEventListener:42 - initializing collection [test.Parent.children#1]
18:39:43,046 DEBUG DefaultInitializeCollectionEventListener:47 - checking second-level cache
18:39:43,046 DEBUG DefaultInitializeCollectionEventListener:59 - collection not cached
18:39:43,046 DEBUG Loader:1419 - loading collection: [test.Parent.children#1]
18:39:43,062 DEBUG AbstractBatcher:290 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
18:39:43,062 DEBUG SQL:324 - select children0_.parent as parent1_, children0_.id as id1_, children0_.id as id0_ from Child children0_ where children0_.parent=?
Hibernate: select children0_.parent as parent1_, children0_.id as id1_, children0_.id as id0_ from Child children0_ where children0_.parent=?
18:39:43,062 DEBUG AbstractBatcher:378 - preparing statement
18:39:43,062 DEBUG LongType:59 - binding '1' to parameter: 1
18:39:43,062 DEBUG AbstractBatcher:306 - about to open ResultSet (open ResultSets: 0, globally: 0)
18:39:43,078 DEBUG Loader:711 - result set contains (possibly empty) collection: [test.Parent.children#1]
18:39:43,078 DEBUG CollectionLoadContext:85 - uninitialized collection: initializing
18:39:43,078 DEBUG Loader:398 - processing result set
18:39:43,078 DEBUG Loader:403 - result set row: 0
18:39:43,078 DEBUG LongType:86 - returning '1' as column: id0_
18:39:43,078 DEBUG Loader:821 - result row: EntityKey[test.Child#1]
18:39:43,078 DEBUG Loader:971 - Initializing object from ResultSet: [test.Child#1]
18:39:43,078 DEBUG BasicEntityPersister:1651 - Hydrating entity: [test.Child#1]
18:39:43,093 DEBUG LongType:86 - returning '1' as column: parent1_
18:39:43,093 DEBUG Loader:647 - found row of collection: [test.Parent.children#1]
18:39:43,109 DEBUG CollectionLoadContext:112 - reading row
18:39:43,109 DEBUG LongType:86 - returning '1' as column: id1_
18:39:43,109 DEBUG DefaultLoadEventListener:143 - loading entity: [test.Child#1]
18:39:43,109 DEBUG DefaultLoadEventListener:290 - attempting to resolve: [test.Child#1]
18:39:43,125 DEBUG DefaultLoadEventListener:299 - resolved object in session cache: [test.Child#1]
18:39:43,125 DEBUG Loader:422 - done processing result set (1 rows)
18:39:43,125 DEBUG AbstractBatcher:313 - about to close ResultSet (open ResultSets: 1, globally: 1)
18:39:43,125 DEBUG AbstractBatcher:298 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
18:39:43,125 DEBUG AbstractBatcher:416 - closing statement
18:39:43,140 DEBUG Loader:521 - total objects hydrated: 1
18:39:43,140 DEBUG TwoPhaseLoad:96 - resolving associations for [test.Child#1]
18:39:43,140 DEBUG TwoPhaseLoad:167 - done materializing entity [test.Child#1]
18:39:43,140 DEBUG CollectionLoadContext:262 - 1 collections were found in result set for role: test.Parent.children
18:39:43,140 DEBUG CollectionLoadContext:206 - collection fully initialized: [test.Parent.children#1]
18:39:43,140 DEBUG CollectionLoadContext:272 - 1 collections initialized for role: test.Parent.children
18:39:43,140 DEBUG PersistenceContext:789 - initializing non-lazy collections
18:39:43,187 DEBUG Loader:1443 - done loading collection
18:39:43,187 DEBUG DefaultInitializeCollectionEventListener:61 - collection initialized
18:39:43,218 DEBUG JDBCTransaction:83 - commit
18:39:43,218 DEBUG SessionImpl:323 - automatically flushing session
18:39:43,234 DEBUG AbstractFlushingEventListener:52 - flushing session
18:39:43,234 DEBUG AbstractFlushingEventListener:102 - processing flush-time cascades
18:39:43,234 DEBUG Cascades:836 - processing cascade ACTION_SAVE_UPDATE for: test.Parent
18:39:43,234 DEBUG Cascades:890 - cascade ACTION_SAVE_UPDATE for collection: test.Parent.children
18:39:43,234 DEBUG Cascades:153 - cascading to saveOrUpdate: test.Child
18:39:43,234 DEBUG AbstractSaveEventListener:393 - persistent instance of: test.Child
18:39:43,234 DEBUG DefaultSaveOrUpdateEventListener:103 - ignoring persistent instance
18:39:43,234 DEBUG DefaultSaveOrUpdateEventListener:140 - object already associated with session: [test.Child#1]
18:39:43,250 DEBUG Cascades:153 - cascading to saveOrUpdate: test.Child
18:39:43,250 DEBUG AbstractSaveEventListener:409 - transient instance of: test.Child
18:39:43,250 DEBUG DefaultSaveOrUpdateEventListener:159 - saving transient instance
18:39:43,250 DEBUG AbstractSaveEventListener:89 - generated identifier: , using strategy: org.hibernate.id.IdentityGenerator
18:39:43,265 DEBUG AbstractSaveEventListener:132 - saving [test.Child#<null>]
18:39:43,265 DEBUG AbstractSaveEventListener:194 - executing insertions
18:39:43,265 DEBUG BasicEntityPersister:1732 - Inserting entity: test.Child (native id)
18:39:43,265 DEBUG AbstractBatcher:290 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
18:39:43,265 DEBUG SQL:324 - insert into Child (id) values (null)
Hibernate: insert into Child (id) values (null)
18:39:43,281 DEBUG AbstractBatcher:378 - preparing statement
18:39:43,281 DEBUG BasicEntityPersister:1612 - Dehydrating entity: [test.Child#<null>]
18:39:43,281 DEBUG AbstractBatcher:298 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
18:39:43,281 DEBUG AbstractBatcher:416 - closing statement
18:39:43,281 DEBUG SQL:39 - call identity()
18:39:43,281 DEBUG AbstractBatcher:290 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
18:39:43,281 DEBUG SQL:324 - call identity()
Hibernate: call identity()
18:39:43,296 DEBUG AbstractBatcher:378 - preparing statement
18:39:43,296 DEBUG IdentifierGeneratorFactory:37 - Natively generated identity: 2
18:39:43,296 DEBUG AbstractBatcher:298 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
18:39:43,296 DEBUG AbstractBatcher:416 - closing statement
18:39:43,296 DEBUG Cascades:908 - done cascade ACTION_SAVE_UPDATE for collection: test.Parent.children
18:39:43,312 DEBUG Cascades:861 - done processing cascade ACTION_SAVE_UPDATE for: test.Parent
18:39:43,312 DEBUG AbstractFlushingEventListener:150 - dirty checking collections
18:39:43,312 DEBUG CollectionEntry:115 - Collection dirty: [test.Parent.children#1]
18:39:43,312 DEBUG AbstractFlushingEventListener:167 - Flushing entities and processing referenced collections
18:39:43,312 DEBUG Collections:140 - Collection found: [test.Parent.children#1], was: [test.Parent.children#1] (initialized)
18:39:43,312 DEBUG AbstractFlushingEventListener:203 - Processing unreferenced collections
18:39:43,312 DEBUG AbstractFlushingEventListener:217 - Scheduling collection removes/(re)creates/updates
18:39:43,328 DEBUG AbstractFlushingEventListener:79 - Flushed: 0 insertions, 0 updates, 0 deletions to 3 objects
18:39:43,328 DEBUG AbstractFlushingEventListener:85 - Flushed: 0 (re)creations, 1 updates, 0 removals to 1 collections
18:39:43,343 DEBUG Printer:83 - listing entities:
18:39:43,343 DEBUG Printer:90 - test.Child{id=1}
18:39:43,343 DEBUG Printer:90 - test.Child{id=2}
18:39:43,343 DEBUG Printer:90 - test.Parent{children=[test.Child#1, test.Child#2], id=1}
18:39:43,343 DEBUG AbstractFlushingEventListener:267 - executing flush
18:39:43,343 DEBUG AbstractCollectionPersister:956 - Deleting rows of collection: [test.Parent.children#1]
18:39:43,343 DEBUG AbstractCollectionPersister:1010 - no rows to delete
18:39:43,359 DEBUG AbstractCollectionPersister:1035 - Inserting rows of collection: [test.Parent.children#1]
18:39:43,359 DEBUG AbstractBatcher:290 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
18:39:43,359 DEBUG SQL:324 - update Child set parent=? where id=?
Hibernate: update Child set parent=? where id=?
18:39:43,359 DEBUG AbstractBatcher:378 - preparing statement
18:39:43,359 DEBUG LongType:59 - binding '1' to parameter: 1
18:39:43,375 DEBUG LongType:59 - binding '2' to parameter: 2
18:39:43,375 DEBUG AbstractBatcher:27 - Adding to batch
18:39:43,375 DEBUG AbstractCollectionPersister:1079 - done inserting rows: 1 inserted
18:39:43,375 DEBUG AbstractBatcher:54 - Executing batch size: 1
18:39:43,375 DEBUG AbstractBatcher:298 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
18:39:43,375 DEBUG AbstractBatcher:416 - closing statement
18:39:43,375 DEBUG AbstractFlushingEventListener:294 - post flush
18:39:43,390 DEBUG JDBCContext:277 - before transaction completion
18:39:43,406 DEBUG SessionImpl:372 - before transaction completion
18:39:43,406 DEBUG JDBCTransaction:96 - committed JDBC Connection
18:39:43,406 DEBUG JDBCContext:282 - after transaction completion
18:39:43,406 DEBUG SessionImpl:403 - after transaction completion
18:39:43,406 DEBUG SessionImpl:269 - closing session
18:39:43,406 DEBUG ConnectionManager:317 - closing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
18:39:43,406 DEBUG DriverManagerConnectionProvider:129 - returning connection to pool, pool size: 1
18:39:43,421 DEBUG JDBCContext:282 - after transaction completion
18:39:43,421 DEBUG SessionImpl:403 - after transaction completion


The generated SQL (show_sql=true):
Code:
Hibernate: select parent0_.id as id from Parent parent0_
Hibernate: select children0_.parent as parent1_, children0_.id as id1_, children0_.id as id0_ from Child children0_ where children0_.parent=?
Hibernate: insert into Child (id) values (null)
Hibernate: call identity()
Hibernate: update Child set parent=? where id=?


As you can see in the generated SQL, the entire collection gets loaded when an insert (add) is being made. This strange behavior goes away when I do the relation bidirectional:

Mapping documents:
Child:
Code:
<?xml version="1.0" encoding="UTF-8"?>

<!DOCTYPE hibernate-mapping PUBLIC
    "-//Hibernate/Hibernate Mapping DTD 3.0//EN"
    "http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd">

<hibernate-mapping
>
    <class
        name="test.Child"
    >

        <id
            name="id"
            column="id"
            type="java.lang.Long"
        >
            <generator class="native">
              <!-- 
                  To add non XDoclet generator parameters, create a file named
                  hibernate-generator-params-Child.xml
                  containing the additional parameters and place it in your merge dir.
              -->
            </generator>
        </id>

        <many-to-one
            name="parent"
            class="test.Parent"
            cascade="none"
            outer-join="auto"
            update="true"
            insert="true"
            column="parent"
        />

        <!--
            To add non XDoclet property mappings, create a file named
                hibernate-properties-Child.xml
            containing the additional properties and place it in your merge dir.
        -->

    </class>

</hibernate-mapping>


Parent:
Code:
<?xml version="1.0" encoding="UTF-8"?>

<!DOCTYPE hibernate-mapping PUBLIC
    "-//Hibernate/Hibernate Mapping DTD 3.0//EN"
    "http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd">

<hibernate-mapping
>
    <class
        name="test.Parent"
    >

        <id
            name="id"
            column="id"
            type="java.lang.Long"
        >
            <generator class="native">
              <!-- 
                  To add non XDoclet generator parameters, create a file named
                  hibernate-generator-params-Parent.xml
                  containing the additional parameters and place it in your merge dir.
              -->
            </generator>
        </id>

        <bag
            name="children"
            lazy="true"
            inverse="true"
            cascade="all"
        >

            <key
                column="parent"
            >
            </key>

            <one-to-many
                  class="test.Child"
            />

      </bag>

        <!--
            To add non XDoclet property mappings, create a file named
                hibernate-properties-Parent.xml
            containing the additional properties and place it in your merge dir.
        -->

    </class>

</hibernate-mapping>


Debug level Hibernate log excerpt:
Code:
18:37:40,015 DEBUG SessionImpl:829 - find: from Parent
18:37:40,031 DEBUG QueryParameters:220 - named parameters: {}
18:37:40,265 DEBUG QueryTranslatorImpl:207 - parse() - HQL: from test.Parent
18:37:40,328 DEBUG AST:223 - --- HQL AST ---
\-[QUERY] 'query'
    \-[SELECT_FROM] 'SELECT_FROM'
       \-[FROM] 'from'
          \-[RANGE] 'RANGE'
             \-[DOT] '.'
                +-[IDENT] 'test'
                \-[IDENT] 'Parent'

18:37:40,328 DEBUG ErrorCounter:72 - throwQueryException() : no errors
18:37:40,453 DEBUG HqlSqlBaseWalker:120 - query() << begin, level = 1
18:37:40,515 DEBUG FromElement:88 - FromClause{level=1} :  test.Parent (no alias) -> parent0_
18:37:40,515 DEBUG HqlSqlBaseWalker:125 - query() : finishing up , level = 1
18:37:40,515 DEBUG HqlSqlWalker:331 - processQuery() :  ( SELECT ( FromClause{level=1} Parent parent0_ ) )
18:37:40,546 DEBUG HqlSqlWalker:451 - Derived SELECT clause created.
18:37:40,578 DEBUG JoinProcessor:112 - Using FROM fragment [Parent parent0_]
18:37:40,578 DEBUG HqlSqlBaseWalker:128 - query() >> end, level = 1
18:37:40,593 DEBUG AST:193 - --- SQL AST ---
\-[SELECT] QueryNode: 'SELECT'  querySpaces (Parent)
    +-[SELECT_CLAUSE] SelectClause: '{derived select clause}'
    |  \-[SELECT_EXPR] SelectExpressionImpl: 'parent0_.id as id' {FromElement{explicit,not a collection join,not a fetch join,fetch non-lazy properties,classAlias=null,role=null,tableName=Parent,tableAlias=parent0_,colums={,className=test.Parent}}}
    \-[FROM] FromClause: 'from' FromClause{level=1, fromElementCounter=1, fromElements=1, fromElementByClassAlias=[], fromElementByTableAlias=[parent0_], fromElementsByPath=[], collectionJoinFromElementsByPath=[], impliedElements=[]}
       \-[FROM_FRAGMENT] FromElement: 'Parent parent0_' FromElement{explicit,not a collection join,not a fetch join,fetch non-lazy properties,classAlias=null,role=null,tableName=Parent,tableAlias=parent0_,colums={,className=test.Parent}}

18:37:40,593 DEBUG ErrorCounter:72 - throwQueryException() : no errors
18:37:40,640 DEBUG QueryTranslatorImpl:177 - HQL: from test.Parent
18:37:40,640 DEBUG QueryTranslatorImpl:178 - SQL: select parent0_.id as id from Parent parent0_
18:37:40,640 DEBUG ErrorCounter:72 - throwQueryException() : no errors
18:37:40,656 DEBUG AbstractBatcher:290 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
18:37:40,671 DEBUG SQL:324 - select parent0_.id as id from Parent parent0_
Hibernate: select parent0_.id as id from Parent parent0_
18:37:40,671 DEBUG AbstractBatcher:378 - preparing statement
18:37:40,796 DEBUG AbstractBatcher:306 - about to open ResultSet (open ResultSets: 0, globally: 0)
18:37:40,796 DEBUG Loader:398 - processing result set
18:37:40,796 DEBUG Loader:403 - result set row: 0
18:37:40,796 DEBUG LongType:86 - returning '1' as column: id
18:37:40,812 DEBUG Loader:821 - result row: EntityKey[test.Parent#1]
18:37:40,812 DEBUG Loader:971 - Initializing object from ResultSet: [test.Parent#1]
18:37:40,812 DEBUG BasicEntityPersister:1651 - Hydrating entity: [test.Parent#1]
18:37:40,812 DEBUG Loader:422 - done processing result set (1 rows)
18:37:40,812 DEBUG AbstractBatcher:313 - about to close ResultSet (open ResultSets: 1, globally: 1)
18:37:40,828 DEBUG AbstractBatcher:298 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
18:37:40,828 DEBUG AbstractBatcher:416 - closing statement
18:37:40,828 DEBUG Loader:521 - total objects hydrated: 1
18:37:40,828 DEBUG TwoPhaseLoad:96 - resolving associations for [test.Parent#1]
18:37:40,843 DEBUG CollectionLoadContext:141 - creating collection wrapper:[test.Parent.children#1]
18:37:40,843 DEBUG TwoPhaseLoad:167 - done materializing entity [test.Parent#1]
18:37:40,843 DEBUG PersistenceContext:789 - initializing non-lazy collections
18:37:40,843 DEBUG JDBCTransaction:83 - commit
18:37:40,843 DEBUG SessionImpl:323 - automatically flushing session
18:37:40,859 DEBUG AbstractFlushingEventListener:52 - flushing session
18:37:40,859 DEBUG AbstractFlushingEventListener:102 - processing flush-time cascades
18:37:40,859 DEBUG Cascades:836 - processing cascade ACTION_SAVE_UPDATE for: test.Parent
18:37:40,859 DEBUG Cascades:890 - cascade ACTION_SAVE_UPDATE for collection: test.Parent.children
18:37:40,859 DEBUG Cascades:153 - cascading to saveOrUpdate: test.Child
18:37:40,859 DEBUG AbstractSaveEventListener:409 - transient instance of: test.Child
18:37:40,859 DEBUG DefaultSaveOrUpdateEventListener:159 - saving transient instance
18:37:40,859 DEBUG AbstractSaveEventListener:89 - generated identifier: , using strategy: org.hibernate.id.IdentityGenerator
18:37:40,875 DEBUG AbstractSaveEventListener:132 - saving [test.Child#<null>]
18:37:40,875 DEBUG AbstractSaveEventListener:194 - executing insertions
18:37:40,875 DEBUG BasicEntityPersister:1732 - Inserting entity: test.Child (native id)
18:37:40,875 DEBUG AbstractBatcher:290 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
18:37:40,875 DEBUG SQL:324 - insert into Child (parent, id) values (?, null)
Hibernate: insert into Child (parent, id) values (?, null)
18:37:40,890 DEBUG AbstractBatcher:378 - preparing statement
18:37:40,890 DEBUG BasicEntityPersister:1612 - Dehydrating entity: [test.Child#<null>]
18:37:40,890 DEBUG LongType:59 - binding '1' to parameter: 1
18:37:40,890 DEBUG AbstractBatcher:298 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
18:37:40,890 DEBUG AbstractBatcher:416 - closing statement
18:37:40,890 DEBUG SQL:39 - call identity()
18:37:40,906 DEBUG AbstractBatcher:290 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
18:37:40,906 DEBUG SQL:324 - call identity()
Hibernate: call identity()
18:37:40,906 DEBUG AbstractBatcher:378 - preparing statement
18:37:40,906 DEBUG IdentifierGeneratorFactory:37 - Natively generated identity: 2
18:37:40,921 DEBUG AbstractBatcher:298 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
18:37:40,921 DEBUG AbstractBatcher:416 - closing statement
18:37:40,921 DEBUG Cascades:908 - done cascade ACTION_SAVE_UPDATE for collection: test.Parent.children
18:37:40,921 DEBUG Cascades:861 - done processing cascade ACTION_SAVE_UPDATE for: test.Parent
18:37:40,921 DEBUG AbstractFlushingEventListener:150 - dirty checking collections
18:37:40,921 DEBUG CollectionEntry:115 - Collection dirty: [test.Parent.children#1]
18:37:40,937 DEBUG AbstractFlushingEventListener:167 - Flushing entities and processing referenced collections
18:37:40,937 DEBUG Collections:140 - Collection found: [test.Parent.children#1], was: [test.Parent.children#1] (uninitialized)
18:37:40,937 DEBUG AbstractFlushingEventListener:203 - Processing unreferenced collections
18:37:40,937 DEBUG AbstractFlushingEventListener:217 - Scheduling collection removes/(re)creates/updates
18:37:40,937 DEBUG AbstractFlushingEventListener:79 - Flushed: 0 insertions, 0 updates, 0 deletions to 2 objects
18:37:40,953 DEBUG AbstractFlushingEventListener:85 - Flushed: 0 (re)creations, 1 updates, 0 removals to 1 collections
18:37:40,953 DEBUG Printer:83 - listing entities:
18:37:40,953 DEBUG Printer:90 - test.Child{parent=test.Parent#1, id=2}
18:37:40,953 DEBUG Printer:90 - test.Parent{children=<uninitialized>, id=1}
18:37:40,953 DEBUG AbstractFlushingEventListener:267 - executing flush
18:37:40,953 DEBUG AbstractFlushingEventListener:294 - post flush
18:37:40,953 DEBUG JDBCContext:277 - before transaction completion
18:37:40,953 DEBUG SessionImpl:372 - before transaction completion
18:37:41,000 DEBUG JDBCTransaction:96 - committed JDBC Connection
18:37:41,000 DEBUG JDBCContext:282 - after transaction completion
18:37:41,000 DEBUG SessionImpl:403 - after transaction completion
18:37:41,046 DEBUG SessionImpl:269 - closing session
18:37:41,046 DEBUG ConnectionManager:317 - closing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
18:37:41,046 DEBUG DriverManagerConnectionProvider:129 - returning connection to pool, pool size: 1
18:37:41,046 DEBUG JDBCContext:282 - after transaction completion
18:37:41,046 DEBUG SessionImpl:403 - after transaction completion


The generated SQL (show_sql=true):
Code:
Hibernate: select parent0_.id as id from Parent parent0_
Hibernate: insert into Child (parent, id) values (?, null)
Hibernate: call identity()


Now the behavior is correct.

Is this difference in behavior when relation is unidirectional expected, or is it a bug?


Top
 Profile  
 
Display posts from previous:  Sort by  
Forum locked This topic is locked, you cannot edit posts or make further replies.  [ 1 post ] 

All times are UTC - 5 hours [ DST ]


You cannot post new topics in this forum
You cannot reply to topics in this forum
You cannot edit your posts in this forum
You cannot delete your posts in this forum

Search for:
© Copyright 2014, Red Hat Inc. All rights reserved. JBoss and Hibernate are registered trademarks and servicemarks of Red Hat, Inc.