Since nobody answered my questions, i turned on debug log level for hibernate and went trough the log output.
I post here only the part of output, which was generated right after i commit transaction.
Code:
11:34:23,714 DEBUG JDBCTransaction:59 - commit
11:34:23,724 DEBUG SessionImpl:2235 - flushing session
11:34:23,754 DEBUG SessionImpl:3379 - running Session.finalize()
11:34:23,754 DEBUG SessionImpl:2428 - Flushing entities and processing referenced collections
11:34:23,754 DEBUG SessionImpl:2522 - Updating entity: [asd.Dummy#608]
11:34:23,834 DEBUG SessionImpl:2522 - Updating entity: [asd.Dummy#709]
11:34:23,844 DEBUG SessionImpl:2522 - Updating entity: [asd.Dummy#710]
11:34:23,844 DEBUG SessionImpl:2522 - Updating entity: [asd.Dummy#809]
11:34:23,854 DEBUG SessionImpl:2771 - Processing unreferenced collections
11:34:23,864 DEBUG SessionImpl:2785 - Scheduling collection removes/(re)creates/updates
11:34:23,864 DEBUG SessionImpl:2259 - Flushed: 1 insertions, 4 updates, 4 deletions to 9 objects
11:34:23,874 DEBUG SessionImpl:2264 - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
11:34:23,884 DEBUG Printer:75 - listing entities:
11:34:23,884 DEBUG Printer:82 - asd.Dummy{age=5, name=qweqweqwe, id=809}
11:34:23,894 DEBUG Printer:82 - asd.Dummy{age=5, name=asd, id=608}
11:34:23,904 DEBUG Printer:82 - asd.Dummy{age=5555, name=asdasdasd, id=709}
11:34:23,914 DEBUG Printer:82 - asd.Dummy{age=5555, name=zxczxzxczxczxc, id=710}
11:34:23,914 DEBUG Printer:82 - asd.Transaction{created=1086161661641, transmittedClassFqcn=asd.Dummy, type=1, removedObjects=0, updatedObjects=0, addedObjects=0, processed=false, id=1921}
11:34:23,924 DEBUG SessionImpl:2348 - executing flush
11:34:23,924 DEBUG EntityPersister:453 - Inserting entity: [asd.Transaction#1921]
11:34:23,934 DEBUG BatcherImpl:196 - about to open: 0 open PreparedStatements, 0 open ResultSets
11:34:23,944 DEBUG SQL:237 - insert into synchro_transaction (TYPE, TRANSMITTED_CLASS_FQCN, CREATED, PROCESSED, ADDED_OBJECTS, REMOVED_OBJECTS, UPDATED_OBJECTS, ID) values (?, ?, ?, ?, ?, ?, ?, ?)
11:34:23,944 DEBUG BatcherImpl:241 - preparing statement
11:34:23,954 DEBUG EntityPersister:388 - Dehydrating entity: [asd.Transaction#1921]
11:34:23,964 DEBUG IntegerType:46 - binding '1' to parameter: 1
11:34:23,964 DEBUG StringType:46 - binding 'asd.Dummy' to parameter: 2
11:34:23,984 DEBUG LongType:46 - binding '1086161661641' to parameter: 3
11:34:23,994 DEBUG BooleanType:46 - binding 'false' to parameter: 4
11:34:23,994 DEBUG IntegerType:46 - binding '0' to parameter: 5
11:34:24,004 DEBUG IntegerType:46 - binding '0' to parameter: 6
11:34:24,014 DEBUG IntegerType:46 - binding '0' to parameter: 7
11:34:24,024 DEBUG LongType:46 - binding '1921' to parameter: 8
11:34:24,024 DEBUG BatcherImpl:203 - done closing: 0 open PreparedStatements, 0 open ResultSets
11:34:24,034 DEBUG BatcherImpl:261 - closing statement
11:34:24,044 DEBUG EntityPersister:646 - Updating entity: [asd.Dummy#608]
11:34:24,044 DEBUG BatcherImpl:196 - about to open: 0 open PreparedStatements, 0 open ResultSets
11:34:24,054 DEBUG SQL:237 - update dummy set NAME=?, AGE=? where ID=?
11:34:24,064 DEBUG BatcherImpl:241 - preparing statement
11:34:24,074 DEBUG EntityPersister:388 - Dehydrating entity: [asd.Dummy#608]
11:34:24,084 DEBUG StringType:46 - binding 'asd' to parameter: 1
11:34:24,094 DEBUG IntegerType:46 - binding '5' to parameter: 2
11:34:24,104 DEBUG LongType:46 - binding '608' to parameter: 3
11:34:24,114 DEBUG EntityPersister:646 - Updating entity: [asd.Dummy#709]
11:34:24,114 DEBUG EntityPersister:388 - Dehydrating entity: [asd.Dummy#709]
11:34:24,124 DEBUG StringType:46 - binding 'asdasdasd' to parameter: 1
11:34:24,134 DEBUG IntegerType:46 - binding '5555' to parameter: 2
11:34:24,134 DEBUG LongType:46 - binding '709' to parameter: 3
11:34:24,144 DEBUG EntityPersister:646 - Updating entity: [asd.Dummy#710]
11:34:24,154 DEBUG EntityPersister:388 - Dehydrating entity: [asd.Dummy#710]
11:34:24,164 DEBUG StringType:46 - binding 'zxczxzxczxczxc' to parameter: 1
11:34:24,174 DEBUG IntegerType:46 - binding '5555' to parameter: 2
11:34:24,174 DEBUG LongType:46 - binding '710' to parameter: 3
11:34:24,184 DEBUG EntityPersister:646 - Updating entity: [asd.Dummy#809]
11:34:24,204 DEBUG EntityPersister:388 - Dehydrating entity: [asd.Dummy#809]
11:34:24,204 DEBUG StringType:46 - binding 'qweqweqwe' to parameter: 1
11:34:24,214 DEBUG IntegerType:46 - binding '5' to parameter: 2
11:34:24,224 DEBUG LongType:46 - binding '809' to parameter: 3
11:34:24,234 DEBUG BatcherImpl:203 - done closing: 0 open PreparedStatements, 0 open ResultSets
11:34:24,234 DEBUG BatcherImpl:261 - closing statement
11:34:24,244 DEBUG EntityPersister:568 - Deleting entity: [asd.Dummy#608]
11:34:24,254 DEBUG BatcherImpl:196 - about to open: 0 open PreparedStatements, 0 open ResultSets
11:34:24,264 DEBUG SQL:237 - delete from dummy where ID=?
11:34:24,264 DEBUG BatcherImpl:241 - preparing statement
11:34:24,274 DEBUG LongType:46 - binding '608' to parameter: 1
11:34:24,284 DEBUG EntityPersister:568 - Deleting entity: [asd.Dummy#709]
11:34:24,294 DEBUG LongType:46 - binding '709' to parameter: 1
11:34:24,304 DEBUG EntityPersister:568 - Deleting entity: [asd.Dummy#710]
11:34:24,314 DEBUG LongType:46 - binding '710' to parameter: 1
11:34:24,324 DEBUG EntityPersister:568 - Deleting entity: [asd.Dummy#809]
11:34:24,324 DEBUG LongType:46 - binding '809' to parameter: 1
11:34:24,334 DEBUG BatcherImpl:203 - done closing: 0 open PreparedStatements, 0 open ResultSets
11:34:24,344 DEBUG BatcherImpl:261 - closing statement
11:34:24,354 DEBUG SessionImpl:2815 - post flush
11:34:24,364 DEBUG SessionImpl:572 - transaction completion
As i understand, rows that say about updating Dummy objects was caused by replicate method. But in my code i call delete BEFORE replicate, and when commit is called, delete is completed after replicate.
Is that bug or normal behaviour?