We are experiencing an issue where, when we perform a delete on a parent object, the delete operation causes an update stmt to be issued against the database when the cascade hydrates the children sets, even if the sets are empty.

The update statement only occurs when a cascade is performed to children. This does not occur with any other objects in our system, only in this one instance we the inverse parent/child relationship occurs.

The result is two DML statements, an update of no value (the timestamp is updated with no other changes in the row) and then the subsequent delete. Our system is sensitive to any DML statement so we want to reduce the overhead as much as possible. How can we eliminate this extra update statement?

Information is below, any advice is extremely appreciated!

Hibernate version: 3.0.5

Mapping documents:

Parent (Non-relevant columns omitted):

<hibernate-mapping>

<class name="com.rc.model.BaseMerchantProduct"table="merchant_product">

<id name="merchantProductId" type="long">
<column name="merchantProductId" scale="10" precision="0" not-null="true" unique="true" sql-type="bigint unsigned"/>
<generator class="native">
<param name="sequence">SEQ_merchantproductid</param>
</generator>
</id>

<timestamp name="updatedDate" column="updatedDate"/>

<property name="createdDate" type="java.util.Date" update="false" not-null="true">
<column name="createdDate" sql-type="timestamp"/>
</property>

<set name="SetOfNormalSubstitution" inverse="true" table="normal_substitution" lazy="true" cascade="all">
<key>
<column name="merchantproductId" scale="10" precision="0" not-null="false"/>
</key>
<one-to-many class="com.rc.model.NormalSubstitution"/>
</set>

<set name="SetOfUniqueSubstitutionFrom" inverse="true" table="unique_substitution" lazy="true" cascade="all">
<key>
<column name="fromId" scale="10" precision="0" not-null="false"/>
</key>
<one-to-many class="com.rc.model.UniqueSubstitution"/>
</set>

<set name="SetOfUniqueSubstitutionTo" inverse="true" table="unique_substitution" lazy="true" cascade="all">
<key>
<column name="toId" scale="10" precision="0" not-null="false"/>
</key>
<one-to-many class="com.rc.model.UniqueSubstitution"/>
</set>

</hibernate-mapping>

Substitution HBM (the child)

<hibernate-mapping>
<!--
Auto-generated mapping file from
the hibernate.org cfg2hbm engine
-->
<class name="com.rc.model.NormalSubstitution" table="normal_substitution" select-before-update="true">
<id name="substitutionId" type="long">
<column name="substitutionid" scale="10" precision="0" not-null="true" unique="true" sql-type="bigint unsigned"/>
<generator class="native">
<param name="sequence">SEQ_normalsubstitutionid</param>
</generator>
</id>
<timestamp name="updatedDate" column="updatedDate"/>
<property name="createdDate" type="java.util.Date" update="false" not-null="true">
<column name="createdDate" sql-type="datetime"/>
</property>

<property name="confidence" type="float">
<column name="confidence" scale="10" precision="2" not-null="false" sql-type="float"/>
</property>

<property name="merchantId" type="int">
<column name="merchantId" scale="10" precision="0" not-null="false" sql-type="int unsigned"/>
</property>

<many-to-one name="goldenProduct" cascade="none" outer-join="false" class="com.rc.model.GoldenProduct">
<column name="goldenProductId" scale="10" precision="0" not-null="false"/>
</many-to-one>

<many-to-one name="merchantProduct" cascade="none" outer-join="false" class="com.rc.model.MerchantProduct">
<column name="merchantProductId" scale="10" precision="0" not-null="false"/>
</many-to-one>
</class>


<class name="com.rc.model.UniqueSubstitution" table="unique_substitution" select-before-update="true">
<id name="uniqueSubstitutionId" type="long">
<column name="uniquesubstitutionid" scale="10" precision="0" not-null="true" unique="true" sql-type="bigint unsigned"/>
<generator class="native">
<param name="sequence">uniquesubstitution</param>
</generator>
</id>

<property name="confidence" type="float">
<column name="confidence" scale="10" precision="2" not-null="false" sql-type="float"/>
</property>

<many-to-one name="substituteProduct" cascade="none" outer-join="false" class="com.rc.model.MerchantProduct">
<column name="toId" scale="10" precision="0" not-null="false"/>
</many-to-one>

<many-to-one name="anchorProduct" cascade="none" outer-join="false" class="com.rc.model.MerchantProduct">
<column name="fromId" scale="10" precision="0" not-null="false"/>
</many-to-one>

<property name="merchantId" type="int">
<column name="merchantId" scale="10" precision="0" not-null="false" sql-type="int unsigned"/>
</property>
</class>
</hibernate-mapping>

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


Full stack trace of any exception that occurs:
No stack trace.

Name and version of the database you are using:
Oracle 10.1

The generated SQL (show_sql=true):

intial select:

Hibernate: select merchantpr0_.merchantProductId as merchant1_0_, merchantpr0_.updatedDate as updatedD3_13_0_ from merchant_product merchantpr0_ where merchantpr0_.merchantProductId=?

extraneous update that occurs on cascade:
Hibernate: update merchant_product set updatedDate=? where merchantProductId=? and updatedDate=?

delete (the target operation called):
Hibernate: delete from merchant_product where merchantProductId=? and updatedDate=?


Debug level Hibernate log excerpt:
12:28:12,065 DEBUG [SessionImpl] opened session at timestamp: 4644413816717312
12:28:12,065 DEBUG [SessionImpl] setting flush mode to: NEVER
12:28:12,081 DEBUG [DefaultLoadEventListener] loading entity: [com.rc.model.MerchantProduct#5]
12:28:12,097 DEBUG [DefaultLoadEventListener] attempting to resolve: [com.rc.model.MerchantProduct#5]
12:28:12,097 DEBUG [DefaultLoadEventListener] object not resolved in any cache: [com.rc.model.MerchantProduct#5]
12:28:12,097 DEBUG [BasicEntityPersister] Materializing entity: [com.rc.model.MerchantProduct#5]
12:28:12,097 DEBUG [Loader] loading entity: [com.rc.model.MerchantProduct#5]
12:28:12,097 DEBUG [AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
12:28:12,097 DEBUG [ConnectionManager] opening JDBC connection

12:28:12,112 DEBUG [SQL] select merchantpr0_.merchantProductId as merchant1_0_, merchantpr0_.updatedDate as updatedD3_13_0_ from merchant_product merchantpr0_ where merchantpr0_.merchantProductId=?
Hibernate: select merchantpr0_.merchantProductId as merchant1_0_, merchantpr0_.updatedDate as updatedD3_13_0_ from merchant_product merchantpr0_ where merchantpr0_.merchantProductId=?
12:28:12,143 DEBUG [AbstractBatcher] preparing statement
12:28:12,878 DEBUG [LongType] binding '5' to parameter: 1
12:28:13,237 DEBUG [AbstractBatcher] about to open ResultSet (open ResultSets: 0, globally: 0)
12:28:13,237 DEBUG [Loader] processing result set
12:28:13,237 DEBUG [Loader] result set row: 0
12:28:13,237 DEBUG [Loader] result row: EntityKey[com.rc.model.MerchantProduct#5]
12:28:13,237 DEBUG [Loader] Initializing object from ResultSet: [com.rc.model.MerchantProduct#5]
12:28:13,268 DEBUG [BasicEntityPersister] Hydrating entity: [com.rc.model.MerchantProduct#5]
12:28:13,425 DEBUG [TimestampType] returning '2005-10-12 02:45:03' as column: updatedD3_13_0_
12:28:13,456 DEBUG [TwoPhaseLoad] Version: 2005-10-12 02:45:03.0
12:28:13,456 DEBUG [Loader] done processing result set (1 rows)
12:28:13,456 DEBUG [AbstractBatcher] about to close ResultSet (open ResultSets: 1, globally: 1)
12:28:13,456 DEBUG [AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
12:28:13,456 DEBUG [AbstractBatcher] closing statement
12:28:13,472 DEBUG [Loader] total objects hydrated: 1
12:28:13,472 DEBUG [TwoPhaseLoad] resolving associations for [com.rc.model.MerchantProduct#5]
12:28:13,534 DEBUG [CollectionLoadContext] creating collection wrapper:[com.rc.model.BaseMerchantProduct.SetOfNormalSubstitution#5]
12:28:13,534 DEBUG [CollectionLoadContext] creating collection wrapper:[com.rc.model.BaseMerchantProduct.SetOfUniqueSubstitutionFrom#5]
12:28:13,534 DEBUG [CollectionLoadContext] creating collection wrapper:[com.rc.model.BaseMerchantProduct.SetOfUniqueSubstitutionTo#5]
12:28:13,534 DEBUG [TwoPhaseLoad] done materializing entity [com.rc.model.MerchantProduct#5]
12:28:13,534 DEBUG [PersistenceContext] initializing non-lazy collections
12:28:13,550 DEBUG [Loader] done entity load
12:28:13,550 DEBUG [JDBCContext] after autocommit
12:28:13,612 DEBUG [TransactionHandler] sending start transaction request now
12:28:13,612 DEBUG [JDBCTransaction] begin
12:28:13,612 DEBUG [JDBCTransaction] current autocommit status: false
12:28:13,612 DEBUG [TransactionHandler] executing the class class com.rc.model.dao.product.backend.ProductDAOImpl Method:deleteMerchantProduct
12:28:13,628 DEBUG [DefaultDeleteEventListener] deleting a persistent instance
12:28:13,628 DEBUG [DefaultDeleteEventListener] deleting [com.rc.model.MerchantProduct#5]
12:28:13,628 DEBUG [SessionImpl] setting cache mode to: GET
12:28:13,628 DEBUG [Cascades] processing cascade ACTION_DELETE for: com.rc.model.MerchantProduct
12:28:13,628 DEBUG [Cascades] cascade ACTION_DELETE for collection: com.rc.model.BaseMerchantProduct.SetOfNormalSubstitution
12:28:13,628 DEBUG [DefaultInitializeCollectionEventListener] initializing collection [com.rc.model.BaseMerchantProduct.SetOfNormalSubstitution#5]
12:28:13,628 DEBUG [DefaultInitializeCollectionEventListener] checking second-level cache
12:28:13,643 DEBUG [DefaultInitializeCollectionEventListener] collection not cached
12:28:13,643 DEBUG [Loader] loading collection: [com.rc.model.BaseMerchantProduct.SetOfNormalSubstitution#5]
12:28:13,643 DEBUG [AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
12:28:13,643 DEBUG [SQL] select setofnorma0_.merchantproductId as merchant9_1_, setofnorma0_.substitutionid as substitu1_1_, setofnorma0_.substitutionid as substitu1_0_, setofnorma0_.updatedDate as updatedD2_14_0_, setofnorma0_.createdDate as createdD3_14_0_, setofnorma0_.confidence as confidence14_0_, setofnorma0_.merchantId as merchantId14_0_, setofnorma0_.goldenProductId as goldenPr6_14_0_, setofnorma0_.merchantProductId as merchant7_14_0_ from normal_substitution setofnorma0_ where setofnorma0_.merchantproductId=?
Hibernate: select setofnorma0_.merchantproductId as merchant9_1_, setofnorma0_.substitutionid as substitu1_1_, setofnorma0_.substitutionid as substitu1_0_, setofnorma0_.updatedDate as updatedD2_14_0_, setofnorma0_.createdDate as createdD3_14_0_, setofnorma0_.confidence as confidence14_0_, setofnorma0_.merchantId as merchantId14_0_, setofnorma0_.goldenProductId as goldenPr6_14_0_, setofnorma0_.merchantProductId as merchant7_14_0_ from normal_substitution setofnorma0_ where setofnorma0_.merchantproductId=?
12:28:13,643 DEBUG [AbstractBatcher] preparing statement
12:28:13,659 DEBUG [LongType] binding '5' to parameter: 1
12:28:13,800 DEBUG [AbstractBatcher] about to open ResultSet (open ResultSets: 0, globally: 0)
12:28:13,800 DEBUG [Loader] result set contains (possibly empty) collection: [com.rc.model.BaseMerchantProduct.SetOfNormalSubstitution#5]
12:28:13,815 DEBUG [CollectionLoadContext] uninitialized collection: initializing
12:28:13,815 DEBUG [Loader] processing result set
12:28:13,815 DEBUG [Loader] done processing result set (0 rows)
12:28:13,831 DEBUG [AbstractBatcher] about to close ResultSet (open ResultSets: 1, globally: 1)
12:28:13,831 DEBUG [AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
12:28:13,831 DEBUG [AbstractBatcher] closing statement
12:28:13,831 DEBUG [Loader] total objects hydrated: 0
12:28:13,831 DEBUG [CollectionLoadContext] 1 collections were found in result set for role: com.rc.model.BaseMerchantProduct.SetOfNormalSubstitution
12:28:13,831 DEBUG [CollectionLoadContext] collection fully initialized: [com.rc.model.BaseMerchantProduct.SetOfNormalSubstitution#5]
12:28:13,831 DEBUG [CollectionLoadContext] 1 collections initialized for role: com.rc.model.BaseMerchantProduct.SetOfNormalSubstitution
12:28:13,831 DEBUG [PersistenceContext] initializing non-lazy collections
12:28:13,831 DEBUG [Loader] done loading collection
12:28:13,831 DEBUG [DefaultInitializeCollectionEventListener] collection initialized
12:28:13,831 DEBUG [Cascades] done cascade ACTION_DELETE for collection: com.rc.model.BaseMerchantProduct.SetOfNormalSubstitution
12:28:13,831 DEBUG [Cascades] cascade ACTION_DELETE for collection: com.rc.model.BaseMerchantProduct.SetOfUniqueSubstitutionFrom
12:28:13,831 DEBUG [DefaultInitializeCollectionEventListener] initializing collection [com.rc.model.BaseMerchantProduct.SetOfUniqueSubstitutionFrom#5]
12:28:13,831 DEBUG [DefaultInitializeCollectionEventListener] checking second-level cache
12:28:13,831 DEBUG [DefaultInitializeCollectionEventListener] collection not cached
12:28:13,847 DEBUG [Loader] loading collection: [com.rc.model.BaseMerchantProduct.SetOfUniqueSubstitutionFrom#5]
12:28:13,847 DEBUG [AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
12:28:13,847 DEBUG [SQL] select setofuniqu0_.fromId as fromId1_, setofuniqu0_.uniquesubstitutionid as uniquesu1_1_, setofuniqu0_.uniquesubstitutionid as uniquesu1_0_, setofuniqu0_.confidence as confidence15_0_, setofuniqu0_.toId as toId15_0_, setofuniqu0_.fromId as fromId15_0_, setofuniqu0_.merchantId as merchantId15_0_ from unique_substitution setofuniqu0_ where setofuniqu0_.fromId=?
Hibernate: select setofuniqu0_.fromId as fromId1_, setofuniqu0_.uniquesubstitutionid as uniquesu1_1_, setofuniqu0_.uniquesubstitutionid as uniquesu1_0_, setofuniqu0_.confidence as confidence15_0_, setofuniqu0_.toId as toId15_0_, setofuniqu0_.fromId as fromId15_0_, setofuniqu0_.merchantId as merchantId15_0_ from unique_substitution setofuniqu0_ where setofuniqu0_.fromId=?
12:28:13,847 DEBUG [AbstractBatcher] preparing statement
12:28:13,847 DEBUG [LongType] binding '5' to parameter: 1
12:28:13,956 DEBUG [AbstractBatcher] about to open ResultSet (open ResultSets: 0, globally: 0)
12:28:13,956 DEBUG [Loader] result set contains (possibly empty) collection: [com.rc.model.BaseMerchantProduct.SetOfUniqueSubstitutionFrom#5]
12:28:13,956 DEBUG [CollectionLoadContext] uninitialized collection: initializing
12:28:13,956 DEBUG [Loader] processing result set
12:28:13,956 DEBUG [Loader] done processing result set (0 rows)
12:28:13,956 DEBUG [AbstractBatcher] about to close ResultSet (open ResultSets: 1, globally: 1)
12:28:13,956 DEBUG [AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
12:28:13,972 DEBUG [AbstractBatcher] closing statement
12:28:13,972 DEBUG [Loader] total objects hydrated: 0
12:28:13,972 DEBUG [CollectionLoadContext] 1 collections were found in result set for role: com.rc.model.BaseMerchantProduct.SetOfUniqueSubstitutionFrom
12:28:13,972 DEBUG [CollectionLoadContext] collection fully initialized: [com.rc.model.BaseMerchantProduct.SetOfUniqueSubstitutionFrom#5]
12:28:13,972 DEBUG [CollectionLoadContext] 1 collections initialized for role: com.rc.model.BaseMerchantProduct.SetOfUniqueSubstitutionFrom
12:28:13,972 DEBUG [PersistenceContext] initializing non-lazy collections
12:28:13,972 DEBUG [Loader] done loading collection
12:28:13,972 DEBUG [DefaultInitializeCollectionEventListener] collection initialized
12:28:13,972 DEBUG [Cascades] done cascade ACTION_DELETE for collection: com.rc.model.BaseMerchantProduct.SetOfUniqueSubstitutionFrom
12:28:13,972 DEBUG [Cascades] cascade ACTION_DELETE for collection: com.rc.model.BaseMerchantProduct.SetOfUniqueSubstitutionTo
12:28:13,972 DEBUG [DefaultInitializeCollectionEventListener] initializing collection [com.rc.model.BaseMerchantProduct.SetOfUniqueSubstitutionTo#5]
12:28:13,972 DEBUG [DefaultInitializeCollectionEventListener] checking second-level cache
12:28:13,972 DEBUG [DefaultInitializeCollectionEventListener] collection not cached
12:28:13,972 DEBUG [Loader] loading collection: [com.rc.model.BaseMerchantProduct.SetOfUniqueSubstitutionTo#5]
12:28:13,972 DEBUG [AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
12:28:13,972 DEBUG [SQL] select setofuniqu0_.toId as toId1_, setofuniqu0_.uniquesubstitutionid as uniquesu1_1_, setofuniqu0_.uniquesubstitutionid as uniquesu1_0_, setofuniqu0_.confidence as confidence15_0_, setofuniqu0_.toId as toId15_0_, setofuniqu0_.fromId as fromId15_0_, setofuniqu0_.merchantId as merchantId15_0_ from unique_substitution setofuniqu0_ where setofuniqu0_.toId=?
Hibernate: select setofuniqu0_.toId as toId1_, setofuniqu0_.uniquesubstitutionid as uniquesu1_1_, setofuniqu0_.uniquesubstitutionid as uniquesu1_0_, setofuniqu0_.confidence as confidence15_0_, setofuniqu0_.toId as toId15_0_, setofuniqu0_.fromId as fromId15_0_, setofuniqu0_.merchantId as merchantId15_0_ from unique_substitution setofuniqu0_ where setofuniqu0_.toId=?
12:28:13,987 DEBUG [AbstractBatcher] preparing statement
12:28:13,987 DEBUG [LongType] binding '5' to parameter: 1
12:28:14,097 DEBUG [AbstractBatcher] about to open ResultSet (open ResultSets: 0, globally: 0)
12:28:14,112 DEBUG [Loader] result set contains (possibly empty) collection: [com.rc.model.BaseMerchantProduct.SetOfUniqueSubstitutionTo#5]
12:28:14,112 DEBUG [CollectionLoadContext] uninitialized collection: initializing
12:28:14,112 DEBUG [Loader] processing result set
12:28:14,112 DEBUG [Loader] done processing result set (0 rows)
12:28:14,112 DEBUG [AbstractBatcher] about to close ResultSet (open ResultSets: 1, globally: 1)
12:28:14,112 DEBUG [AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
12:28:14,112 DEBUG [AbstractBatcher] closing statement
12:28:14,112 DEBUG [Loader] total objects hydrated: 0
12:28:14,112 DEBUG [CollectionLoadContext] 1 collections were found in result set for role: com.rc.model.BaseMerchantProduct.SetOfUniqueSubstitutionTo
12:28:14,112 DEBUG [CollectionLoadContext] collection fully initialized: [com.rc.model.BaseMerchantProduct.SetOfUniqueSubstitutionTo#5]
12:28:14,112 DEBUG [CollectionLoadContext] 1 collections initialized for role: com.rc.model.BaseMerchantProduct.SetOfUniqueSubstitutionTo
12:28:14,112 DEBUG [PersistenceContext] initializing non-lazy collections
12:28:14,112 DEBUG [Loader] done loading collection
12:28:14,112 DEBUG [DefaultInitializeCollectionEventListener] collection initialized
12:28:14,112 DEBUG [Cascades] done cascade ACTION_DELETE for collection: com.rc.model.BaseMerchantProduct.SetOfUniqueSubstitutionTo
12:28:14,112 DEBUG [Cascades] done processing cascade ACTION_DELETE for: com.rc.model.MerchantProduct
12:28:14,128 DEBUG [SessionImpl] setting cache mode to: NORMAL
12:28:14,143 DEBUG [SessionImpl] setting cache mode to: GET
12:28:14,143 DEBUG [Cascades] processing cascade ACTION_DELETE for: com.rc.model.MerchantProduct
12:28:14,143 DEBUG [Cascades] done processing cascade ACTION_DELETE for: com.rc.model.MerchantProduct
12:28:14,143 DEBUG [SessionImpl] setting cache mode to: NORMAL
12:28:14,143 DEBUG [TransactionHandler] Sending commit request now
12:28:14,143 DEBUG [AbstractFlushingEventListener] flushing session
12:28:14,143 DEBUG [AbstractFlushingEventListener] processing flush-time cascades
12:28:14,143 DEBUG [AbstractFlushingEventListener] dirty checking collections
12:28:14,159 DEBUG [AbstractFlushingEventListener] Flushing entities and processing referenced collections
12:28:14,175 DEBUG [BasicEntityPersister] com.rc.model.MerchantProduct.SetOfNormalSubstitution is dirty
12:28:14,175 DEBUG [BasicEntityPersister] com.rc.model.MerchantProduct.SetOfUniqueSubstitutionFrom is dirty
12:28:14,175 DEBUG [BasicEntityPersister] com.rc.model.MerchantProduct.SetOfUniqueSubstitutionTo is dirty
12:28:14,175 DEBUG [DefaultFlushEntityEventListener] Updating deleted entity: [com.rc.model.MerchantProduct#5]
12:28:14,175 DEBUG [AbstractFlushingEventListener] Processing unreferenced collections
12:28:14,190 DEBUG [Collections] Collection dereferenced: [com.rc.model.BaseMerchantProduct.setOfBasketCoupon#5]
12:28:14,190 DEBUG [Collections] Collection dereferenced: [com.rc.model.BaseMerchantProduct.SetOfNormalSubstitution#5]
12:28:14,190 DEBUG [Collections] Collection dereferenced: [com.rc.model.BaseMerchantProduct.SetOfUniqueSubstitutionFrom#5]
12:28:14,190 DEBUG [Collections] Collection dereferenced: [com.rc.model.BaseMerchantProduct.SetOfUniqueSubstitutionTo#5]
12:28:14,190 DEBUG [AbstractFlushingEventListener] Scheduling collection removes/(re)creates/updates
12:28:14,206 DEBUG [AbstractFlushingEventListener] Flushed: 0 insertions, 1 updates, 1 deletions to 1 objects
12:28:14,206 DEBUG [AbstractFlushingEventListener] Flushed: 0 (re)creations, 0 updates, 4 removals to 4 collections
12:28:14,222 DEBUG [Printer] listing entities:
12:28:14,222 DEBUG [Printer] com.rc.model.MerchantProduct{createdDate=2005-10-12 02:45:02, SetOfNormalSubstitution=[], SetOfUniqueSubstitutionTo=[],
SetOfUniqueSubstitutionFrom=[], updatedDate=2005-10-12 02:45:03}
12:28:14,237 DEBUG [AbstractFlushingEventListener] executing flush
12:28:14,237 DEBUG [BasicEntityPersister] Updating entity: [com.rc.model.MerchantProduct#5]
12:28:14,237 DEBUG [BasicEntityPersister] Existing version: 2005-10-12 02:45:03.0 -> New version: 2005-10-12 02:45:03.0
12:28:14,253 DEBUG [AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
12:28:14,253 DEBUG [SQL] update merchant_product set updatedDate=? where merchantProductId=? and updatedDate=?

Hibernate: update merchant_product set updatedDate=? where merchantProductId=? and updatedDate=?

12:28:14,253 DEBUG [AbstractBatcher] preparing statement
12:28:14,253 DEBUG [BasicEntityPersister] Dehydrating entity: [com.rc.model.MerchantProduct#5]
12:28:14,253 DEBUG [TimestampType] binding '2005-10-12 02:45:03' to parameter: 1
12:28:14,253 DEBUG [IntegerType] binding '-1472710003' to parameter: 2
.
.
. omitted extra bind stmts for other not relevant columns
.
.
.
12:28:14,284 DEBUG [AbstractBatcher] Adding to batch
12:28:14,284 DEBUG [AbstractBatcher] Executing batch size: 1
12:28:14,393 DEBUG [AbstractBatcher] success of batch update unknown: 0
12:28:14,393 DEBUG [AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
12:28:14,393 DEBUG [AbstractBatcher] closing statement
12:28:14,409 DEBUG [BasicEntityPersister] Deleting entity: [com.rc.model.MerchantProduct#5]
12:28:14,409 DEBUG [BasicEntityPersister] Version: 2005-10-12 02:45:03.0
12:28:14,409 DEBUG [AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)

12:28:14,409 DEBUG [SQL] delete from merchant_product where merchantProductId=? and updatedDate=?
Hibernate: delete from merchant_product where merchantProductId=? and updatedDate=?

12:28:14,409 DEBUG [AbstractBatcher] preparing statement
12:28:14,409 DEBUG [LongType] binding '5' to parameter: 1
12:28:14,409 DEBUG [TimestampType] binding '2005-10-12 02:45:03' to parameter: 2
12:28:14,409 DEBUG [AbstractBatcher] Adding to batch
12:28:14,425 DEBUG [AbstractBatcher] Executing batch size: 1
12:28:14,581 DEBUG [AbstractBatcher] success of batch update unknown: 0
12:28:14,581 DEBUG [AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
12:28:14,581 DEBUG [AbstractBatcher] closing statement
12:28:14,581 DEBUG [AbstractFlushingEventListener] post flush
12:28:14,581 DEBUG [AbstractFlushingEventListener] flushing session
12:28:14,581 DEBUG [AbstractFlushingEventListener] processing flush-time cascades
12:28:14,581 DEBUG [AbstractFlushingEventListener] dirty checking collections
12:28:14,581 DEBUG [AbstractFlushingEventListener] Flushing entities and processing referenced collections
12:28:14,581 DEBUG [AbstractFlushingEventListener] Processing unreferenced collections
12:28:14,581 DEBUG [AbstractFlushingEventListener] Scheduling collection removes/(re)creates/updates
12:28:14,597 DEBUG [AbstractFlushingEventListener] Flushed: 0 insertions, 0 updates, 0 deletions to 0 objects
12:28:14,597 DEBUG [AbstractFlushingEventListener] Flushed: 0 (re)creations, 0 updates, 0 removals to 4 collections
12:28:14,597 DEBUG [AbstractFlushingEventListener] executing flush
12:28:14,597 DEBUG [AbstractFlushingEventListener] post flush
12:28:14,597 DEBUG [JDBCTransaction] commit
12:28:14,597 DEBUG [JDBCContext] before transaction completion
12:28:14,597 DEBUG [SessionImpl] before transaction completion
12:28:14,643 DEBUG [JDBCTransaction] committed JDBC Connection
12:28:14,643 DEBUG [JDBCContext] after transaction completion
12:28:14,643 DEBUG [SessionImpl] after transaction completion

For now, I disabled the versioning(in your case, the timestamp) and the extra updates stopped happening. See

http://forum.hibernate.org/viewtopic.php?t=950225

for someone else with a similar problem