Here is the debug level Hibernate log. I added one property to hibernate.cfg.xml:
<property name="hibernate.jdbc.batch_versioned_data">true</property>
It changed the Exception but basically states the same problem. This line:
DEBUG EntityPersister:649 - Existing version: 2004-09-07 16:30:08.003 -> New version: 2004-09-08 09:48:44.752
shows the correct value for the existing row, so I still suspect that it's a JDBC driver issue.
Code:
DEBUG SessionImpl:555 - opened session
DEBUG SessionImpl:1527 - find: select e from Employee as e
DEBUG QueryParameters:112 - named parameters: {}
DEBUG QueryTranslator:147 - compiling query
DEBUG SessionImpl:2246 - flushing session
DEBUG SessionImpl:2439 - Flushing entities and processing referenced collections
DEBUG SessionImpl:2780 - Processing unreferenced collections
DEBUG SessionImpl:2794 - Scheduling collection removes/(re)creates/updates
DEBUG SessionImpl:2270 - Flushed: 0 insertions, 0 updates, 0 deletions to 0 objects
DEBUG SessionImpl:2275 - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
DEBUG SessionImpl:1818 - Dont need to execute flush
DEBUG QueryTranslator:207 - HQL: select e from Employee as e
DEBUG QueryTranslator:208 - SQL: select employee0_.id as id, employee0_.modify_date as modify_d2_, employee0_.first_name as first_name, employee0_.last_name as last_name from employee employee0_
DEBUG BatcherImpl:200 - about to open: 0 open PreparedStatements, 0 open ResultSets
DEBUG SQL:226 - select top 1 employee0_.id as id, employee0_.modify_date as modify_d2_, employee0_.first_name as first_name, employee0_.last_name as last_name from employee employee0_
Hibernate: select top 1 employee0_.id as id, employee0_.modify_date as modify_d2_, employee0_.first_name as first_name, employee0_.last_name as last_name from employee employee0_
DEBUG BatcherImpl:249 - preparing statement
DEBUG Loader:277 - processing result set
DEBUG IntegerType:68 - returning '1' as column: id
DEBUG Loader:480 - result row: 1
DEBUG Loader:611 - Initializing object from ResultSet: 1
DEBUG Loader:680 - Hydrating entity: Employee#1
DEBUG TimestampType:68 - returning '2004-09-07 16:30:08' as column: modify_d2_
DEBUG StringType:68 - returning 'Darcy' as column: first_name
DEBUG StringType:68 - returning 'Schultz' as column: last_name
DEBUG SessionImpl:1910 - Version: 2004-09-07 16:30:08.003
DEBUG Loader:294 - done processing result set (1 rows)
DEBUG BatcherImpl:207 - done closing: 0 open PreparedStatements, 0 open ResultSets
DEBUG BatcherImpl:269 - closing statement
DEBUG Loader:314 - total objects hydrated: 1
DEBUG SessionImpl:2202 - resolving associations for [Employee#1]
DEBUG SessionImpl:2226 - done materializing entity [Employee#1]
DEBUG SessionImpl:3116 - initializing non-lazy collections
DEBUG SessionImpl:573 - closing session
DEBUG SessionImpl:3336 - disconnecting session
DEBUG SessionImpl:585 - transaction completion
DEBUG SessionImpl:555 - opened session
DEBUG JDBCTransaction:37 - begin
DEBUG JDBCTransaction:41 - current autocommit status:false
DEBUG Cascades:396 - version unsaved-value strategy UNDEFINED
DEBUG Cascades:341 - id unsaved-value strategy NULL
DEBUG SessionImpl:1392 - saveOrUpdate() previously saved instance with id: 1
DEBUG SessionImpl:1440 - updating [Employee#1]
DEBUG SessionImpl:3388 - running Session.finalize()
DEBUG JDBCTransaction:59 - commit
DEBUG SessionImpl:2246 - flushing session
DEBUG SessionImpl:2439 - Flushing entities and processing referenced collections
DEBUG SessionImpl:2533 - Updating entity: [Employee#1]
DEBUG Versioning:26 - Incrementing: 2004-09-07 16:30:08.003 to 2004-09-08 09:48:44.752
DEBUG SessionImpl:2780 - Processing unreferenced collections
DEBUG SessionImpl:2794 - Scheduling collection removes/(re)creates/updates
DEBUG SessionImpl:2270 - Flushed: 0 insertions, 1 updates, 0 deletions to 1 objects
DEBUG SessionImpl:2275 - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
DEBUG Printer:75 - listing entities:
DEBUG Printer:82 - Employee{modifyDate=2004-09-07 16:30:08, firstName=Joe, id=1, lastName=Schultz}
DEBUG SessionImpl:2359 - executing flush
DEBUG EntityPersister:648 - Updating entity: [Employee#1]
DEBUG EntityPersister:649 - Existing version: 2004-09-07 16:30:08.003 -> New version: 2004-09-08 09:48:44.752
DEBUG BatcherImpl:200 - about to open: 0 open PreparedStatements, 0 open ResultSets
DEBUG SQL:226 - update employee set modify_date=?, first_name=?, last_name=? where id=? and modify_date=?
Hibernate: update employee set modify_date=?, first_name=?, last_name=? where id=? and modify_date=?
DEBUG BatcherImpl:249 - preparing statement
DEBUG EntityPersister:388 - Dehydrating entity: [Employee#1]
DEBUG TimestampType:46 - binding '2004-09-08 09:48:44' to parameter: 1
DEBUG StringType:46 - binding 'Joe' to parameter: 2
DEBUG StringType:46 - binding 'Schultz' to parameter: 3
DEBUG IntegerType:46 - binding '1' to parameter: 4
DEBUG TimestampType:46 - binding '2004-09-07 16:30:08' to parameter: 5
ERROR SessionImpl:2379 - Could not synchronize database state with session
net.sf.hibernate.HibernateException: SQL insert, update or delete failed (row not found)
at net.sf.hibernate.impl.NonBatchingBatcher.addToBatch(NonBatchingBatcher.java:25)
at net.sf.hibernate.persister.EntityPersister.update(EntityPersister.java:684)
at net.sf.hibernate.persister.EntityPersister.update(EntityPersister.java:642)
at net.sf.hibernate.impl.ScheduledUpdate.execute(ScheduledUpdate.java:52)
at net.sf.hibernate.impl.SessionImpl.executeAll(SessionImpl.java:2418)
at net.sf.hibernate.impl.SessionImpl.execute(SessionImpl.java:2372)
at net.sf.hibernate.impl.SessionImpl.flush(SessionImpl.java:2240)
at net.sf.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:61)
at EmployeeTest.testUpdate(EmployeeTest.java:58)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:324)
at junit.framework.TestCase.runTest(TestCase.java:154)
at junit.framework.TestCase.runBare(TestCase.java:127)
at junit.framework.TestResult$1.protect(TestResult.java:106)
at junit.framework.TestResult.runProtected(TestResult.java:124)
at junit.framework.TestResult.run(TestResult.java:109)
at junit.framework.TestCase.run(TestCase.java:118)
at junit.framework.TestSuite.runTest(TestSuite.java:208)
at junit.framework.TestSuite.run(TestSuite.java:203)
at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:421)
at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.run(RemoteTestRunner.java:305)
at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.main(RemoteTestRunner.java:186)
DEBUG JDBCTransaction:82 - rollback
DEBUG SessionImpl:585 - transaction completion
DEBUG SessionImpl:573 - closing session
DEBUG SessionImpl:3336 - disconnecting session
DEBUG SessionImpl:585 - transaction completion