hibernate-issues

[Hibernate-issues] [Hibernate-JIRA] Created: (HHH-1564) Possible bug with deleting versioned object (patch included)

[N C. (JIRA) <no...@at...>]

Possible bug with deleting versioned object (patch included)
------------------------------------------------------------

         Key: HHH-1564
         URL: http://opensource.atlassian.com/projects/hibernate/browse/HHH-1564
     Project: Hibernate3
        Type: Bug

  Components: core  
    Versions: 3.1.2    
 Environment: 3.1rc2
    Reporter: N Clayton


We're seeing an odd problem when trying to delete a row. The code that does this simply creates a new object, commits it, starts a new session, finds the object, deletes it. It dies with a constraint violation on an audit table, because hibernate is issuing an unnecessary update operation (and not incrementing the version either). Further debugging shows that Hibernate thinks that three properties on the object are 'modified'. These three are collections. One is the points collection, one owners and the other is systems. Hibernate seems to think that they are 'different' because null != an empty collection. So, it thinks it needs to update the object.  However; later on - it doesn't increment the version number - because it knows the object is to be deleted. Thus - a problem. 

A complete description is here:
http://forum.hibernate.org/viewtopic.php?t=950225&highlight=collectiontype+isdirty

This appears to be fixed if we change CollectionType.isDirty() to be:

   public boolean isDirty(Object old, Object current, boolean[] checkable, SessionImplementor session)
         throws HibernateException {
        if(checkable.length == 0) {
            // Assume not checkable
            return false;
        }
      return isDirty(old, current, session);
   } 

-- 
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators:
   http://opensource.atlassian.com/projects/hibernate/secure/Administrators.jspa
-
For more information on JIRA, see:
   http://www.atlassian.com/software/jira

[Hibernate-issues] [Hibernate-JIRA] Commented: (HHH-1564) Possible bug with deleting versioned object (patch included)

[Gail B. (JIRA) <no...@at...>]

    [ http://opensource.atlassian.com/projects/hibernate/browse/HHH-1564?page=comments#action_22540 ] 

Gail Badner commented on HHH-1564:
----------------------------------

I noticed that the proposed change to CollectionType.isdirty(Object old, Object current, boolean[] checkable, SessionImplementor session), as it stands, applies only to Hibernate 3.1. The method will not be called in Hibernate 3.0.5 without making other changes because the superclass does not have this method.

I have also verified that applying the fix to hibernate 3.1 seems to work, but it causes unit test org.hibernate.test.legacy.FooBarTest.testVersionedCollections to fail as follows:

Testcase: testVersionedCollections took 0.146 sec
       FAILED
versioned collection before
junit.framework.AssertionFailedError: versioned collection before
       at org.hibernate.test.legacy.FooBarTest.testVersionedCollections(FooBarTest.java:3042)
       at org.hibernate.test.TestCase.runTest(TestCase.java:150)

This failure does not occur using the 3.1 code without this fix.

It seems strange to update a versioned entity without incrementing the version number. It also does not make sense to increment the version number for a delete, since it is the n-th version being deleted, not the (n+1)-th version. I have also verified that updates to an entity's collection are not cascaded if that entity is deleted in the same transaction as the update, so I'm not sure how a collection could ever dirty an entity on a delete requiring an update.

A possible workaround for this issue is to modify the trigger. Since triggers have access to the new and old values for the row, it could be changed to write to the audit table only when the new and old values are different. This may or may not be acceptable for a particular situation but maybe this could work in your case.

This comment will also be entered on the forum.

Gail Badner
SourceLabs, Inc.
Dependable Open Source Systems


> Possible bug with deleting versioned object (patch included)
> ------------------------------------------------------------
>
>          Key: HHH-1564
>          URL: http://opensource.atlassian.com/projects/hibernate/browse/HHH-1564
>      Project: Hibernate3
>         Type: Bug

>   Components: core
>     Versions: 3.1.2
>  Environment: 3.1rc2
>     Reporter: N Clayton

>
>
> We're seeing an odd problem when trying to delete a row. The code that does this simply creates a new object, commits it, starts a new session, finds the object, deletes it. It dies with a constraint violation on an audit table, because hibernate is issuing an unnecessary update operation (and not incrementing the version either). Further debugging shows that Hibernate thinks that three properties on the object are 'modified'. These three are collections. One is the points collection, one owners and the other is systems. Hibernate seems to think that they are 'different' because null != an empty collection. So, it thinks it needs to update the object.  However; later on - it doesn't increment the version number - because it knows the object is to be deleted. Thus - a problem. 
> A complete description is here:
> http://forum.hibernate.org/viewtopic.php?t=950225&highlight=collectiontype+isdirty
> This appears to be fixed if we change CollectionType.isDirty() to be:
>    public boolean isDirty(Object old, Object current, boolean[] checkable, SessionImplementor session)
>          throws HibernateException {
>         if(checkable.length == 0) {
>             // Assume not checkable
>             return false;
>         }
>       return isDirty(old, current, session);
>    } 

-- 
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators:
   http://opensource.atlassian.com/projects/hibernate/secure/Administrators.jspa
-
For more information on JIRA, see:
   http://www.atlassian.com/software/jira

[Hibernate-issues] [Hibernate-JIRA] Commented: (HHH-1564) Possible bug with deleting versioned object (patch included)

[Dave S. (JIRA) <no...@at...>]

    [ http://opensource.atlassian.com/projects/hibernate/browse/HHH-1564?page=comments#action_22833 ] 

Dave Syer commented on HHH-1564:
--------------------------------

We have the same problem (using 3.0) and I have to say it is very irritating.  I'm guessing that the cause may be somewhere else, and that the proposed patch is really just a quick fix for the symptom.  Why does hibernate think these collections are empty?  Someone on the forum post suggested that TypeFactory.deepCopy was being used wrongly, masking out the collection properties so they are not copied.  I have no opinion on this, but I hope that someone else does.

Neil: is your database on a Windows platform, by any chance?  Just an observation: the constraint violation in my system only occurs on Windows but not Solaris.  I assume this is because the OS does not have sufficiently time resolution to distinguish between the times of the update and the delete query (a notorious Windows problem).  If you are not using Windows, try and use the database itself to generate the timestamps - i.e. don't do it in Java because time resolution is limited in the VM as well.  Also, I am using Oracle, and it makes a difference if I use SYSDATE or SYSTIMESTAMP.  I imagine there are similar issues on other platforms.

> Possible bug with deleting versioned object (patch included)
> ------------------------------------------------------------
>
>          Key: HHH-1564
>          URL: http://opensource.atlassian.com/projects/hibernate/browse/HHH-1564
>      Project: Hibernate3
>         Type: Bug

>   Components: core
>     Versions: 3.1.2
>  Environment: 3.1rc2
>     Reporter: N Clayton

>
>
> We're seeing an odd problem when trying to delete a row. The code that does this simply creates a new object, commits it, starts a new session, finds the object, deletes it. It dies with a constraint violation on an audit table, because hibernate is issuing an unnecessary update operation (and not incrementing the version either). Further debugging shows that Hibernate thinks that three properties on the object are 'modified'. These three are collections. One is the points collection, one owners and the other is systems. Hibernate seems to think that they are 'different' because null != an empty collection. So, it thinks it needs to update the object.  However; later on - it doesn't increment the version number - because it knows the object is to be deleted. Thus - a problem. 
> A complete description is here:
> http://forum.hibernate.org/viewtopic.php?t=950225&highlight=collectiontype+isdirty
> This appears to be fixed if we change CollectionType.isDirty() to be:
>    public boolean isDirty(Object old, Object current, boolean[] checkable, SessionImplementor session)
>          throws HibernateException {
>         if(checkable.length == 0) {
>             // Assume not checkable
>             return false;
>         }
>       return isDirty(old, current, session);
>    } 

-- 
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators:
   http://opensource.atlassian.com/projects/hibernate/secure/Administrators.jspa
-
For more information on JIRA, see:
   http://www.atlassian.com/software/jira

[Hibernate-issues] [Hibernate-JIRA] Commented: (HHH-1564) Possible bug with deleting versioned object (patch included)

[N C. (JIRA) <no...@at...>]

    [ http://opensource.atlassian.com/projects/hibernate/browse/HHH-1564?page=comments#action_22834 ] 

N Clayton commented on HHH-1564:
--------------------------------

No, our DB is running on Linux (Oracle).   

I suspect you may be right, that the fix about is really just a workaround, adressing some other issue - but I don't know what that other issue might be.    We did spend about 2 days pairing, looking very carefully (I admit, with limited knowledge of hibernate) at this issue, and certainly tracked it down to the code above, so it's not a 5min hack.

We continue to use the above patch in hibernate, in order to get it to work for us.

> Possible bug with deleting versioned object (patch included)
> ------------------------------------------------------------
>
>          Key: HHH-1564
>          URL: http://opensource.atlassian.com/projects/hibernate/browse/HHH-1564
>      Project: Hibernate3
>         Type: Bug

>   Components: core
>     Versions: 3.1.2
>  Environment: 3.1rc2
>     Reporter: N Clayton

>
>
> We're seeing an odd problem when trying to delete a row. The code that does this simply creates a new object, commits it, starts a new session, finds the object, deletes it. It dies with a constraint violation on an audit table, because hibernate is issuing an unnecessary update operation (and not incrementing the version either). Further debugging shows that Hibernate thinks that three properties on the object are 'modified'. These three are collections. One is the points collection, one owners and the other is systems. Hibernate seems to think that they are 'different' because null != an empty collection. So, it thinks it needs to update the object.  However; later on - it doesn't increment the version number - because it knows the object is to be deleted. Thus - a problem. 
> A complete description is here:
> http://forum.hibernate.org/viewtopic.php?t=950225&highlight=collectiontype+isdirty
> This appears to be fixed if we change CollectionType.isDirty() to be:
>    public boolean isDirty(Object old, Object current, boolean[] checkable, SessionImplementor session)
>          throws HibernateException {
>         if(checkable.length == 0) {
>             // Assume not checkable
>             return false;
>         }
>       return isDirty(old, current, session);
>    } 

-- 
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators:
   http://opensource.atlassian.com/projects/hibernate/secure/Administrators.jspa
-
For more information on JIRA, see:
   http://www.atlassian.com/software/jira

[Hibernate-issues] [Hibernate-JIRA] Updated: (HHH-1564) Possible bug with deleting versioned object (patch included)

[Christian B. (JIRA) <no...@at...>]

     [ http://opensource.atlassian.com/projects/hibernate/browse/HHH-1564?page=all ]

Christian Bauer updated HHH-1564:
---------------------------------

    Attachment: onetomanydelete_test.tar.gz

I can confirm that there is a problem with unnecessary updates for Parent, if cascading to Children collection is enabled. This is related to versioning of the Parent. Test case against latest SVN is attached.

The UPDATE shouldn't happen, it also sets the version from 0 to 0:

10:49:50,751 DEBUG SessionImpl:222 - opened session at timestamp: 4705864051712000
10:49:50,752 DEBUG JDBCTransaction:54 - begin
10:49:50,753 DEBUG ConnectionManager:415 - opening JDBC connection
10:49:50,754 DEBUG DriverManagerConnectionProvider:93 - total checked-out connections: 0
10:49:50,758 DEBUG DriverManagerConnectionProvider:99 - using pooled JDBC connection, pool size: 0
10:49:50,766 DEBUG JDBCTransaction:59 - current autocommit status: false
10:49:50,772 DEBUG JDBCContext:203 - after transaction begin
#### LOADIG PARENT
10:49:50,781 DEBUG DefaultLoadEventListener:154 - loading entity: [org.hibernate.test.onetomanydelete.Parent#1]
10:49:50,783 DEBUG DefaultLoadEventListener:309 - attempting to resolve: [org.hibernate.test.onetomanydelete.Parent#1]
10:49:50,785 DEBUG NonstrictReadWriteCache:41 - Cache lookup: org.hibernate.test.onetomanydelete.Parent#1
10:49:50,789 DEBUG NonstrictReadWriteCache:49 - Cache miss
10:49:50,790 DEBUG DefaultLoadEventListener:345 - object not resolved in any cache: [org.hibernate.test.onetomanydelete.Parent#1]
10:49:50,792 DEBUG AbstractEntityPersister:2814 - Fetching entity: [org.hibernate.test.onetomanydelete.Parent#1]
10:49:50,801 DEBUG Loader:1777 - loading entity: [org.hibernate.test.onetomanydelete.Parent#1]
10:49:50,808 DEBUG AbstractBatcher:358 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
10:49:50,810 DEBUG SQL:393 - 
    select
        parent0_.parent_id as parent1_0_0_,
        parent0_.obj_version as obj2_0_0_,
        parent0_.name as name0_0_ 
    from
        Parent parent0_ 
    where
        parent0_.parent_id=?
10:49:50,812 DEBUG AbstractBatcher:476 - preparing statement
10:49:50,818 DEBUG AbstractBatcher:374 - about to open ResultSet (open ResultSets: 0, globally: 0)
10:49:50,820 DEBUG Loader:682 - processing result set
10:49:50,821 DEBUG Loader:687 - result set row: 0
10:49:50,823 DEBUG Loader:1164 - result row: EntityKey[org.hibernate.test.onetomanydelete.Parent#1]
10:49:50,825 DEBUG Loader:1347 - Initializing object from ResultSet: [org.hibernate.test.onetomanydelete.Parent#1]
10:49:50,830 DEBUG AbstractEntityPersister:1944 - Hydrating entity: [org.hibernate.test.onetomanydelete.Parent#1]
10:49:50,832 DEBUG TwoPhaseLoad:75 - Version: 0
10:49:50,835 DEBUG Loader:709 - done processing result set (1 rows)
10:49:50,837 DEBUG AbstractBatcher:381 - about to close ResultSet (open ResultSets: 1, globally: 1)
10:49:50,838 DEBUG AbstractBatcher:366 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
10:49:50,840 DEBUG AbstractBatcher:525 - closing statement
10:49:50,845 DEBUG Loader:839 - total objects hydrated: 1
10:49:50,846 DEBUG TwoPhaseLoad:107 - resolving associations for [org.hibernate.test.onetomanydelete.Parent#1]
10:49:50,853 DEBUG CollectionLoadContext:141 - creating collection wrapper:[org.hibernate.test.onetomanydelete.Parent.children#1]
10:49:50,856 DEBUG TwoPhaseLoad:135 - adding entity to second-level cache: [org.hibernate.test.onetomanydelete.Parent#1]
10:49:50,859 DEBUG NonstrictReadWriteCache:71 - Caching: org.hibernate.test.onetomanydelete.Parent#1
10:49:50,861 DEBUG TwoPhaseLoad:206 - done materializing entity [org.hibernate.test.onetomanydelete.Parent#1]
10:49:50,862 DEBUG StatefulPersistenceContext:748 - initializing non-lazy collections
10:49:50,865 DEBUG Loader:1808 - done entity load
#### DELETING PARENT
10:49:50,868 DEBUG DefaultDeleteEventListener:90 - deleting a persistent instance
10:49:50,870 DEBUG DefaultDeleteEventListener:127 - deleting [org.hibernate.test.onetomanydelete.Parent#1]
10:49:50,874 DEBUG SessionImpl:1301 - setting cache mode to: GET
10:49:50,875 DEBUG Cascade:237 - processing cascade ACTION_DELETE for: org.hibernate.test.onetomanydelete.Parent
10:49:50,877 DEBUG Cascade:285 - cascade ACTION_DELETE for collection: org.hibernate.test.onetomanydelete.Parent.children
10:49:50,880 DEBUG DefaultInitializeCollectionEventListener:41 - initializing collection [org.hibernate.test.onetomanydelete.Parent.children#1]
10:49:50,882 DEBUG DefaultInitializeCollectionEventListener:47 - checking second-level cache
10:49:50,884 DEBUG NonstrictReadWriteCache:41 - Cache lookup: org.hibernate.test.onetomanydelete.Parent.children#1
10:49:50,885 DEBUG NonstrictReadWriteCache:49 - Cache miss
10:49:50,889 DEBUG DefaultInitializeCollectionEventListener:59 - collection not cached
10:49:50,891 DEBUG Loader:1911 - loading collection: [org.hibernate.test.onetomanydelete.Parent.children#1]
10:49:50,896 DEBUG AbstractBatcher:358 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
10:49:50,903 DEBUG SQL:393 - 
    select
        children0_.parent_id as parent3_1_,
        children0_.child_id as child1_1_,
        children0_.child_id as child1_1_0_,
        children0_.name as name1_0_,
        children0_.parent_id as parent3_1_0_ 
    from
        Child children0_ 
    where
        children0_.parent_id=?
10:49:50,914 DEBUG AbstractBatcher:476 - preparing statement
10:49:50,924 DEBUG AbstractBatcher:374 - about to open ResultSet (open ResultSets: 0, globally: 0)
10:49:50,928 DEBUG Loader:1040 - result set contains (possibly empty) collection: [org.hibernate.test.onetomanydelete.Parent.children#1]
10:49:50,930 DEBUG CollectionLoadContext:84 - uninitialized collection: initializing
10:49:50,933 DEBUG Loader:682 - processing result set
10:49:50,934 DEBUG Loader:687 - result set row: 0
10:49:50,936 DEBUG Loader:1164 - result row: EntityKey[org.hibernate.test.onetomanydelete.Child#1]
10:49:50,939 DEBUG Loader:1347 - Initializing object from ResultSet: [org.hibernate.test.onetomanydelete.Child#1]
10:49:50,941 DEBUG AbstractEntityPersister:1944 - Hydrating entity: [org.hibernate.test.onetomanydelete.Child#1]
10:49:50,944 DEBUG Loader:972 - found row of collection: [org.hibernate.test.onetomanydelete.Parent.children#1]
10:49:50,946 DEBUG CollectionLoadContext:112 - reading row
10:49:50,948 DEBUG DefaultLoadEventListener:154 - loading entity: [org.hibernate.test.onetomanydelete.Child#1]
10:49:50,951 DEBUG DefaultLoadEventListener:309 - attempting to resolve: [org.hibernate.test.onetomanydelete.Child#1]
10:49:50,954 DEBUG DefaultLoadEventListener:318 - resolved object in session cache: [org.hibernate.test.onetomanydelete.Child#1]
10:49:50,956 DEBUG Loader:709 - done processing result set (1 rows)
10:49:50,958 DEBUG AbstractBatcher:381 - about to close ResultSet (open ResultSets: 1, globally: 1)
10:49:50,960 DEBUG AbstractBatcher:366 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
10:49:50,961 DEBUG AbstractBatcher:525 - closing statement
10:49:50,965 DEBUG Loader:839 - total objects hydrated: 1
10:49:50,967 DEBUG TwoPhaseLoad:107 - resolving associations for [org.hibernate.test.onetomanydelete.Child#1]
10:49:50,969 DEBUG DefaultLoadEventListener:154 - loading entity: [org.hibernate.test.onetomanydelete.Parent#1]
10:49:50,970 DEBUG DefaultLoadEventListener:227 - entity found in session cache
10:49:50,972 DEBUG TwoPhaseLoad:206 - done materializing entity [org.hibernate.test.onetomanydelete.Child#1]
10:49:50,981 DEBUG CollectionLoadContext:262 - 1 collections were found in result set for role: org.hibernate.test.onetomanydelete.Parent.children
10:49:50,991 DEBUG CollectionLoadContext:206 - collection fully initialized: [org.hibernate.test.onetomanydelete.Parent.children#1]
10:49:50,993 DEBUG CollectionLoadContext:272 - 1 collections initialized for role: org.hibernate.test.onetomanydelete.Parent.children
10:49:51,001 DEBUG StatefulPersistenceContext:748 - initializing non-lazy collections
10:49:51,003 DEBUG Loader:1935 - done loading collection
10:49:51,005 DEBUG DefaultInitializeCollectionEventListener:61 - collection initialized
10:49:51,015 DEBUG CascadingAction:45 - cascading to delete: org.hibernate.test.onetomanydelete.Child
10:49:51,016 DEBUG DefaultDeleteEventListener:90 - deleting a persistent instance
10:49:51,018 DEBUG DefaultDeleteEventListener:127 - deleting [org.hibernate.test.onetomanydelete.Child#1]
10:49:51,020 DEBUG SessionImpl:1301 - setting cache mode to: GET
10:49:51,021 DEBUG SessionImpl:1301 - setting cache mode to: GET
10:49:51,025 DEBUG SessionImpl:1301 - setting cache mode to: GET
10:49:51,028 DEBUG SessionImpl:1301 - setting cache mode to: GET
10:49:51,029 DEBUG Cascade:300 - done cascade ACTION_DELETE for collection: org.hibernate.test.onetomanydelete.Parent.children
10:49:51,031 DEBUG Cascade:259 - done processing cascade ACTION_DELETE for: org.hibernate.test.onetomanydelete.Parent
10:49:51,032 DEBUG SessionImpl:1301 - setting cache mode to: NORMAL
10:49:51,034 DEBUG SessionImpl:1301 - setting cache mode to: GET
10:49:51,035 DEBUG Cascade:237 - processing cascade ACTION_DELETE for: org.hibernate.test.onetomanydelete.Parent
10:49:51,037 DEBUG Cascade:259 - done processing cascade ACTION_DELETE for: org.hibernate.test.onetomanydelete.Parent
10:49:51,038 DEBUG SessionImpl:1301 - setting cache mode to: NORMAL
#### FLUSHING
10:49:51,040 DEBUG AbstractFlushingEventListener:58 - flushing session
10:49:51,042 DEBUG AbstractFlushingEventListener:111 - processing flush-time cascades
10:49:51,043 DEBUG AbstractFlushingEventListener:153 - dirty checking collections
10:49:51,045 DEBUG AbstractFlushingEventListener:170 - Flushing entities and processing referenced collections
10:49:51,047 DEBUG AbstractEntityPersister:2960 - org.hibernate.test.onetomanydelete.Parent.children is dirty
10:49:51,049 DEBUG DefaultFlushEntityEventListener:223 - Updating deleted entity: [org.hibernate.test.onetomanydelete.Parent#1]
10:49:51,053 DEBUG AbstractFlushingEventListener:209 - Processing unreferenced collections
10:49:51,055 DEBUG Collections:52 - Collection dereferenced: [org.hibernate.test.onetomanydelete.Parent.children#1]
10:49:51,057 DEBUG AbstractFlushingEventListener:223 - Scheduling collection removes/(re)creates/updates
10:49:51,060 DEBUG AbstractFlushingEventListener:85 - Flushed: 0 insertions, 1 updates, 2 deletions to 2 objects
10:49:51,063 DEBUG AbstractFlushingEventListener:91 - Flushed: 0 (re)creations, 0 updates, 1 removals to 1 collections
10:49:51,065 DEBUG Printer:83 - listing entities:
10:49:51,067 DEBUG Printer:90 - org.hibernate.test.onetomanydelete.Child{name=Child One, parent=org.hibernate.test.onetomanydelete.Parent#1, id=1}
10:49:51,069 DEBUG Printer:90 - org.hibernate.test.onetomanydelete.Parent{name=Parent, children=[org.hibernate.test.onetomanydelete.Child#1], id=1, version=0}
10:49:51,071 DEBUG AbstractFlushingEventListener:289 - executing flush
10:49:51,072 DEBUG ConnectionManager:463 - registering flush begin
10:49:51,074 DEBUG AbstractEntityPersister:2211 - Updating entity: [org.hibernate.test.onetomanydelete.Parent#1]
10:49:51,076 DEBUG AbstractEntityPersister:2213 - Existing version: 0 -> New version: 0
10:49:51,077 DEBUG AbstractBatcher:358 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
10:49:51,081 DEBUG SQL:393 - 
    update
        Parent 
    set
        obj_version=?,
        name=? 
    where
        parent_id=? 
        and obj_version=?
10:49:51,083 DEBUG AbstractBatcher:476 - preparing statement
10:49:51,085 DEBUG AbstractEntityPersister:1905 - Dehydrating entity: [org.hibernate.test.onetomanydelete.Parent#1]
10:49:51,087 DEBUG AbstractBatcher:28 - Adding to batch
10:49:51,088 DEBUG NonstrictReadWriteCache:116 - Invalidating: org.hibernate.test.onetomanydelete.Parent#1
10:49:51,090 DEBUG AbstractBatcher:55 - Executing batch size: 1
10:49:51,092 DEBUG AbstractBatcher:366 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
10:49:51,094 DEBUG AbstractBatcher:525 - closing statement
10:49:51,100 DEBUG NonstrictReadWriteCache:116 - Invalidating: org.hibernate.test.onetomanydelete.Parent.children#1
10:49:51,106 DEBUG AbstractEntityPersister:2319 - Deleting entity: [org.hibernate.test.onetomanydelete.Child#1]
10:49:51,109 DEBUG AbstractBatcher:358 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
10:49:51,111 DEBUG SQL:393 - 
    delete 
    from
        Child 
    where
        child_id=?
10:49:51,113 DEBUG AbstractBatcher:476 - preparing statement
10:49:51,115 DEBUG AbstractBatcher:28 - Adding to batch
10:49:51,116 DEBUG NonstrictReadWriteCache:116 - Invalidating: org.hibernate.test.onetomanydelete.Child#1
10:49:51,118 DEBUG AbstractEntityPersister:2319 - Deleting entity: [org.hibernate.test.onetomanydelete.Parent#1]
10:49:51,121 DEBUG AbstractEntityPersister:2321 - Version: 0
10:49:51,122 DEBUG AbstractBatcher:55 - Executing batch size: 1
10:49:51,124 DEBUG AbstractBatcher:366 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
10:49:51,126 DEBUG AbstractBatcher:525 - closing statement
10:49:51,127 DEBUG AbstractBatcher:358 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
10:49:51,130 DEBUG SQL:393 - 
    delete 
    from
        Parent 
    where
        parent_id=? 
        and obj_version=?
10:49:51,132 DEBUG AbstractBatcher:476 - preparing statement
10:49:51,134 DEBUG AbstractBatcher:28 - Adding to batch
10:49:51,137 DEBUG NonstrictReadWriteCache:116 - Invalidating: org.hibernate.test.onetomanydelete.Parent#1
10:49:51,138 DEBUG AbstractBatcher:55 - Executing batch size: 1
10:49:51,139 DEBUG AbstractBatcher:366 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
10:49:51,141 DEBUG AbstractBatcher:525 - closing statement
10:49:51,142 DEBUG ConnectionManager:472 - registering flush end
10:49:51,143 DEBUG AbstractFlushingEventListener:320 - post flush
10:49:51,145 DEBUG JDBCTransaction:103 - commit
10:49:51,148 DEBUG SessionImpl:339 - automatically flushing session
10:49:51,149 DEBUG AbstractFlushingEventListener:58 - flushing session
10:49:51,152 DEBUG AbstractFlushingEventListener:111 - processing flush-time cascades
10:49:51,153 DEBUG AbstractFlushingEventListener:153 - dirty checking collections
10:49:51,155 DEBUG AbstractFlushingEventListener:170 - Flushing entities and processing referenced collections
10:49:51,156 DEBUG AbstractFlushingEventListener:209 - Processing unreferenced collections
10:49:51,158 DEBUG AbstractFlushingEventListener:223 - Scheduling collection removes/(re)creates/updates
10:49:51,159 DEBUG AbstractFlushingEventListener:85 - Flushed: 0 insertions, 0 updates, 0 deletions to 0 objects
10:49:51,161 DEBUG AbstractFlushingEventListener:91 - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
10:49:51,162 DEBUG AbstractFlushingEventListener:289 - executing flush
10:49:51,165 DEBUG ConnectionManager:463 - registering flush begin
10:49:51,166 DEBUG ConnectionManager:472 - registering flush end
10:49:51,168 DEBUG AbstractFlushingEventListener:320 - post flush
10:49:51,170 DEBUG JDBCContext:194 - before transaction completion
10:49:51,171 DEBUG SessionImpl:395 - before transaction completion
10:49:51,172 DEBUG JDBCTransaction:116 - committed JDBC Connection
10:49:51,173 DEBUG JDBCContext:208 - after transaction completion
10:49:51,174 DEBUG ConnectionManager:398 - aggressively releasing JDBC connection
10:49:51,176 DEBUG ConnectionManager:435 - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
10:49:51,177 DEBUG DriverManagerConnectionProvider:129 - returning connection to pool, pool size: 1
10:49:51,179 DEBUG SessionImpl:424 - after transaction completion
10:49:51,180 DEBUG NonstrictReadWriteCache:142 - Invalidating (again): org.hibernate.test.onetomanydelete.Parent#1
10:49:51,182 DEBUG NonstrictReadWriteCache:142 - Invalidating (again): org.hibernate.test.onetomanydelete.Parent.children#1
10:49:51,184 DEBUG NonstrictReadWriteCache:142 - Invalidating (again): org.hibernate.test.onetomanydelete.Child#1
10:49:51,186 DEBUG NonstrictReadWriteCache:142 - Invalidating (again): org.hibernate.test.onetomanydelete.Parent#1
10:49:51,187 DEBUG SessionImpl:275 - closing session
10:49:51,188 DEBUG ConnectionManager:369 - connection already null in cleanup : no action


> Possible bug with deleting versioned object (patch included)
> ------------------------------------------------------------
>
>          Key: HHH-1564
>          URL: http://opensource.atlassian.com/projects/hibernate/browse/HHH-1564
>      Project: Hibernate3
>         Type: Bug

>   Components: core
>     Versions: 3.1.2
>  Environment: 3.1rc2
>     Reporter: N Clayton
>  Attachments: onetomanydelete_test.tar.gz
>
>
> We're seeing an odd problem when trying to delete a row. The code that does this simply creates a new object, commits it, starts a new session, finds the object, deletes it. It dies with a constraint violation on an audit table, because hibernate is issuing an unnecessary update operation (and not incrementing the version either). Further debugging shows that Hibernate thinks that three properties on the object are 'modified'. These three are collections. One is the points collection, one owners and the other is systems. Hibernate seems to think that they are 'different' because null != an empty collection. So, it thinks it needs to update the object.  However; later on - it doesn't increment the version number - because it knows the object is to be deleted. Thus - a problem. 
> A complete description is here:
> http://forum.hibernate.org/viewtopic.php?t=950225&highlight=collectiontype+isdirty
> This appears to be fixed if we change CollectionType.isDirty() to be:
>    public boolean isDirty(Object old, Object current, boolean[] checkable, SessionImplementor session)
>          throws HibernateException {
>         if(checkable.length == 0) {
>             // Assume not checkable
>             return false;
>         }
>       return isDirty(old, current, session);
>    } 

-- 
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators:
   http://opensource.atlassian.com/projects/hibernate/secure/Administrators.jspa
-
For more information on JIRA, see:
   http://www.atlassian.com/software/jira

[Hibernate-issues] [Hibernate-JIRA] Commented: (HHH-1564) Possible bug with deleting versioned object (patch included)

[Dave S. (JIRA) <no...@at...>]

    [ http://opensource.atlassian.com/projects/hibernate/browse/HHH-1564?page=comments#action_23373 ] 

Dave Syer commented on HHH-1564:
--------------------------------

I find that there is another spurious update of the parent object when it is first inserted (also causes the same potential constraint violation in the kind of trigger-driven situation originally outlined in this issue).  Thus:

Bar bar = new Bar(); // Bar is versioned
Foo foo = new Foo();
bar.getFoos().add(foo); // bar.foos are cascaded
session.save(bar);
session.flush();

results in:

INSERT INTO BAR ...
INSERT INTO FOO ...
UPDATE BAR ...

The UPDATE operation increments the version number of bar, but nothing else changes.

Hibernate only thinks that the Bar is dirty because its foos changed from a HashSet before the INSERT into a PersistentBag afterwards.  The java docs for PesistentBag is quite explicit that it doesn't follow the Collection API convention of making an item by item comparison in equals().  If it did, then the UPDATE wouldn't happen because the Bar would not be dirty.

Ironically, while the UPDATE is an issue for me because business users simply cannot see the logic in it, if it went away, an even bigger issue would be the fact the the INSERT statements come in the wrong order to make the audit trail show the Bar with the correct collection of Foos at the time it was created.  The Foos are only properly present in version 1 of bar.  But even worse, if the INSERTs happened the other way round, I might have a null constraint violation on inserting the Foo (it's parent Bar would not be persisted yet).  Maybe that is wrong, or could be addressed in another way?

> Possible bug with deleting versioned object (patch included)
> ------------------------------------------------------------
>
>          Key: HHH-1564
>          URL: http://opensource.atlassian.com/projects/hibernate/browse/HHH-1564
>      Project: Hibernate3
>         Type: Bug

>   Components: core
>     Versions: 3.1.2
>  Environment: 3.1rc2
>     Reporter: N Clayton
>  Attachments: onetomanydelete_test.tar.gz
>
>
> We're seeing an odd problem when trying to delete a row. The code that does this simply creates a new object, commits it, starts a new session, finds the object, deletes it. It dies with a constraint violation on an audit table, because hibernate is issuing an unnecessary update operation (and not incrementing the version either). Further debugging shows that Hibernate thinks that three properties on the object are 'modified'. These three are collections. One is the points collection, one owners and the other is systems. Hibernate seems to think that they are 'different' because null != an empty collection. So, it thinks it needs to update the object.  However; later on - it doesn't increment the version number - because it knows the object is to be deleted. Thus - a problem. 
> A complete description is here:
> http://forum.hibernate.org/viewtopic.php?t=950225&highlight=collectiontype+isdirty
> This appears to be fixed if we change CollectionType.isDirty() to be:
>    public boolean isDirty(Object old, Object current, boolean[] checkable, SessionImplementor session)
>          throws HibernateException {
>         if(checkable.length == 0) {
>             // Assume not checkable
>             return false;
>         }
>       return isDirty(old, current, session);
>    } 

-- 
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators:
   http://opensource.atlassian.com/projects/hibernate/secure/Administrators.jspa
-
For more information on JIRA, see:
   http://www.atlassian.com/software/jira