Hi,
I am using Hibernate 5.0.4, Ehcache 2.10.1 with Derby DB 10.12.1.1. I have an entity named Forest which has simple fields id, name and version.I have configured Ehcache as my SLC. When I fetch the forest entity for the first time I do see this Forest entity getting cached in the SLC. Then I acquire an optimistic lock and commit the transaction. No changes made to the entity. Subsequently when I create a new hibernate session and load the same forest entity it is resulting in a DB hit. I was expecting it to read the entity from SLC instead of hitting the DB.I have tried with both Optimistic* locks and Pessismistic* lock as well as both NON_STRICT_READ_WRITE and READ_WRITE cache concurrency strategies and the behavior is same.
Is this the right behavior and if I want to make sure that the entity is read from SLC is there any configuration that I am missing.
By the way, If I don't perform that optimistic lock I do see the entity getting read from SLC as expected.
Code:
Session session = HibernateUtil.getSessionFactory().getCurrentSession();
session.getTransaction().begin();
Forest forest = (Forest) session.get(Forest.class, 5);
System.out.println("Locking forest");
//If this below line is removed then the entity is fetched from SLC the next time
session.buildLockRequest(new LockOptions().setLockMode(LockMode.OPTIMISTIC)).lock(forest);
session.getTransaction().commit();
session = HibernateUtil.getSessionFactory().getCurrentSession();
session.getTransaction().begin();
System.out.println("Reading again ");
//This results in a DB hit
forest = (Forest) session.get(Forest.class, 5);
And below is the output with SLC statistic enabled
Quote:
Reading 1298380324
Hibernate: select forest0_.id as id1_0_0_, forest0_.name as name2_0_0_, forest0_.version as version3_0_0_ from Forest forest0_ where forest0_.id=?
Locking forest
Locked
Hibernate: select version from Forest where id =?
Nov 27, 2015 11:03:11 AM org.hibernate.engine.internal.StatisticalLoggingSessionEventListener end
INFO: Session Metrics {
32874 nanoseconds spent acquiring 1 JDBC connections;
0 nanoseconds spent releasing 0 JDBC connections;
2661940 nanoseconds spent preparing 2 JDBC statements;
1836812 nanoseconds spent executing 2 JDBC statements;
0 nanoseconds spent executing 0 JDBC batches;
18020072 nanoseconds spent performing 1 L2C puts;
0 nanoseconds spent performing 0 L2C hits;
691167 nanoseconds spent performing 1 L2C misses;
6224204 nanoseconds spent executing 1 flushes (flushing a total of 1 entities and 0 collections);
0 nanoseconds spent executing 0 partial-flushes (flushing a total of 0 entities and 0 collections)
}
Reading again 1103132232
Hibernate: select forest0_.id as id1_0_0_, forest0_.name as name2_0_0_, forest0_.version as version3_0_0_ from Forest forest0_ where forest0_.id=?
SessionStatistics[entity count=1,collection count=0]
Forest ID :5 Name :Forest-One- Version :5
Done
Nov 27, 2015 11:03:15 AM org.hibernate.engine.internal.StatisticalLoggingSessionEventListener end
INFO: Session Metrics {
11095 nanoseconds spent acquiring 1 JDBC connections;
0 nanoseconds spent releasing 0 JDBC connections;
541181 nanoseconds spent preparing 1 JDBC statements;
503787 nanoseconds spent executing 1 JDBC statements;
0 nanoseconds spent executing 0 JDBC batches;
332023 nanoseconds spent performing 1 L2C puts;
0 nanoseconds spent performing 0 L2C hits;
69856 nanoseconds spent performing 1 L2C misses;
94101 nanoseconds spent executing 1 flushes (flushing a total of 1 entities and 0 collections);
0 nanoseconds spent executing 0 partial-flushes (flushing a total of 0 entities and 0 collections)
}