Friday, August 15, 2014

Flushing Hibernate

Flushing Hibernate

Today I am going to write about Hibernate flushing. Do not worry, I am not going to flush Hibernate to the toilet. I will write about the way, how Hibernate propagates changes to the database.
When you are modifying data using Hibernate, you have to keep in mind that Hibernate uses so called write-behind. It means that Hibernate propagates changes to the database as late as possible. By default this propagation (flushing) happens at the following times
  • when transaction is committed
  • before query is executed
  • when flush() method is called explicitly
Usually such behavior is a good thing. It enables Hibernate to optimize data modifications and allows grouping many changes to one big batch update. But sometimes you can encounter some interesting issues. Lets show it on some example. Lets have following entity class:



01 @Entity
02 public class Client  {
03   
04   @Id @GeneratedValue(strategy=GenerationType.AUTO)
05   private Long id;
06
07   @Column(unique=true,nullable=false)
08   private String personalNumber;
09   
10   @Column
11   private String name;
12   
13   .
13   .
13   .
14 }
We see that a client has id which is used internally as an identifier. Moreover a client has a personal number which we are using as a business key. Then he has some other attributes as name. Notice that the personal number is obligatory and it has to be unique.

01     Client client = new Client(PERSONAL_NUM);
02     LOG.debug("Creating first client");
03     clientDao.createClient(client);
04     
05     LOG.debug("Changing first client");
06     client.setName("Carl von Bahnhof");
07     
08     LOG.debug("Deleting first client");
09     clientDao.deleteClient(client.getId());
10     
11     LOG.debug("Trying to load first client");
12     assertNull(clientDao.loadClientWithPersonalNumberOrReturnNull(PERSONAL_NUM));
13     
14     LOG.debug("Creating second client");
15     clientDao.createClient(new Client(PERSONAL_NUM));

When it is executed on HSQLDB we get following output (we see my logging messages mixed with Hibernate SQL output).

Creating first client
insert into Client (name, personalNumber, id) values (?, ?, ?)
call identity()
Changing first client
Deleting first client
Trying to load first client
delete from Client where id=?
select client0_.id as id2_, client0_.name as name2_, client0_.personalNumber as personal3_2_ from Client client0_ where client0_.personalNumber=?
Creating second client
insert into Client (name, personalNumber, id) values (?, ?, ?)
call identity()
We see that inserts are called at once. They are not postponed until flush. In this case, Hibernate has to call insert at once because it has to get the client id from the database. (remember all non-transient entities have to have id) So inserts can not wait until flush, they have to be executed directly. In order to make our example more clear, we can change id generation strategy to sequence.



01 @Entity
02 public class Client  {
03   
04   @Id @GeneratedValue(strategy=GenerationType.SEQUENCE)
05   private Long id;
06
07   @Column(unique=true,nullable=false)
08   private String personalNumber;
09   
10   @Column
11   private String name;
12   
13   .
14   .
15   .
16 }
To get the client id, insert is not needed any more. It can be postponed until flush and we get following output
Creating first client
select next value for hibernate_sequence from dual_hibernate_sequence
Changing first client
Deleting first client
Trying to load first client
insert into Client (name, personalNumber, id) values (?, ?, ?)
delete from Client where id=?
select client0_.id as id2_, client0_.name as name2_, client0_.personalNumber as personal3_2_ from Client client0_ where client0_.personalNumber=?
Creating second client
insert into Client (name, personalNumber, id) values (?, ?, ?)
As you can see creation of the first client and his deletion is realized just before the select statement. Changes have to be propagated to the DB so the select statement has access to changed data. You can notice, that there is no update, change of the name was already included into the insert statement. So far so good. Where is the problem? Lets comment out the query (You do not have to comment it out, in the real world it can be bypassed by the second-level cache).



01     Client client = new Client(PERSONAL_NUM);
02     LOG.debug("Creating first client");
03     clientDao.createClient(client);
04     
05     LOG.debug("Changing first client");
06     client.setName("Carl von Bahnhof");
07     
08     LOG.debug("Deleting first client");
09     clientDao.deleteClient(client.getId());
10     
11     //LOG.debug("Trying to load first client");
12     //assertNull(clientDao.loadClientWithPersonalNumberOrReturnNull(PERSONAL_NUM));
13     
14     LOG.debug("Creating second client");
15     clientDao.createClient(new Client(PERSONAL_NUM));
We get following output
Creating first client
select next value for hibernate_sequence from dual_hibernate_sequence
Changing first client
Deleting first client
Creating second client
insert into Client (name, personalNumber, id) values (?, ?, ?)
insert into Client (name, personalNumber, id) values (?, ?, ?)
SQL Error: 0, SQLState: null
failed batch
Could not synchronize database state with session
org.hibernate.exception.GenericJDBCException: Could not execute JDBC batch update
at org.hibernate.exception.SQLStateConverter.handledNonSpecificException(SQLStateConverter.java:103)
at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:91)
at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:43)
at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:253)
at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:237)
at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:141)
at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:298)
at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:27)
at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1000)
at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:338)
at org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:106)
at org.hibernate.ejb.TransactionImpl.commit(TransactionImpl.java:54)
at org.springframework.orm.jpa.JpaTransactionManager.doCommit(JpaTransactionManager.java:438)
at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:662)
at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:632)
at org.springframework.test.context.transaction.TransactionalTestExecutionListener.endTransaction(TransactionalTestExecutionListener.java:346)
at org.springframework.test.context.transaction.TransactionalTestExecutionListener.afterTestMethod(TransactionalTestExecutionListener.java:199)
at org.springframework.test.context.TestContextManager.afterTestMethod(TestContextManager.java:340)
at org.springframework.test.context.junit4.SpringMethodRoadie.runAfters(SpringMethodRoadie.java:351)
at org.springframework.test.context.junit4.SpringMethodRoadie.runBeforesThenTestThenAfters(SpringMethodRoadie.java:262)
at org.springframework.test.context.junit4.SpringMethodRoadie.runWithRepetitions(SpringMethodRoadie.java:234)
at org.springframework.test.context.junit4.SpringMethodRoadie.runTest(SpringMethodRoadie.java:204)
at org.springframework.test.context.junit4.SpringMethodRoadie.run(SpringMethodRoadie.java:146)
at org.springframework.test.context.junit4.SpringJUnit4ClassRunner.invokeTestMethod(SpringJUnit4ClassRunner.java:151)
at org.junit.internal.runners.JUnit4ClassRunner.runMethods(JUnit4ClassRunner.java:51)
at org.junit.internal.runners.JUnit4ClassRunner$1.run(JUnit4ClassRunner.java:44)
at org.junit.internal.runners.ClassRoadie.runUnprotected(ClassRoadie.java:27)
at org.junit.internal.runners.ClassRoadie.runProtected(ClassRoadie.java:37)
at org.junit.internal.runners.JUnit4ClassRunner.run(JUnit4ClassRunner.java:42)
at org.eclipse.jdt.internal.junit4.runner.JUnit4TestReference.run(JUnit4TestReference.java:38)
at org.eclipse.jdt.internal.junit.runner.TestExecution.run(TestExecution.java:38)
at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:460)
at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:673)
at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.run(RemoteTestRunner.java:386)
at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.main(RemoteTestRunner.java:196)
Caused by: java.sql.BatchUpdateException: failed batch
at org.hsqldb.jdbc.jdbcStatement.executeBatch(Unknown Source)
at org.hsqldb.jdbc.jdbcPreparedStatement.executeBatch(Unknown Source)
at org.apache.commons.dbcp.DelegatingStatement.executeBatch(DelegatingStatement.java:297)
at org.hibernate.jdbc.BatchingBatcher.doExecuteBatch(BatchingBatcher.java:48)
at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:246)
... 31 more
Wow. It looks like Hibernate is trying to insert both clients with the same personal number without deleting the first one. Lets try to remove uniqueness condition from the client and take a look at the output:
Creating first client
select next value for hibernate_sequence from dual_hibernate_sequence
Changing first client
Deleting first client
Creating second client
insert into Client (name, personalNumber, id) values (?, ?, ?)
insert into Client (name, personalNumber, id) values (?, ?, ?)
delete from Client where id=?
Yes, Hibernate changed order of the commands! Without the unique constraint it does not matter, final result is the same. But with the constraint enabled, we can not use our code any more. Is it a bug? No, it is a feature. If you dig deep into the Hibernate source code, you will find following comment
Execute all SQL and second-level cache updates, in a
special order so that foreign-key constraints cannot
be violated:
  1. Inserts, in the order they were performed
  2. Updates
  3. Deletion of collection elements
  4. Insertion of collection elements
  5. Deletes, in the order they were performed
And that is exactly our case. When flushing, Hibernate executes all inserts before delete statements.
So if we need to run our example, we have to force Hibernate to flush the delete before the second insert. The best way is to call entityManager.flush() explicitly just after the delete.
To reiterate, Hibernate is using write-behind. All data manipulating statements are executed as late as possible. One exception are insert statements. Sometimes Hibernate needs to call insert in order to get the ID of the entity. The important point is, that order of the commands can be changed by Hibernate. Usually it does not matter, since transactions are atomic. But sometimes we can encounter interesting issues. Especially when using database constraints.