Hi guys, I found a bug in MyBatis 3.2.2. I'm also using EhCache 2.5.1, and I have lazy loading enabled.
In a project I'm currently working on, the BaseExecutor.queryFromDatabase() method throws a NullPointerException at regular intervals. This method is called because a lazy property of a (proxy) database entity is requested. The exception is thrown when the localCache.putObject() method is called.
BaseExecutor:
private
At that point the ExecutorException is actually being thrown, but the NullpointerException hides it. The ExecutorException originates from BaseExecutor.query():121, because the "close" variable is true. This can only be true if the executor is closed by another thread.
I noticed the bug will only trigger when the executor used, is the original one that is created when the proxy is created.
ResultLoader:
private
This means the executor passes the open test, but somehow the executor gets closed.
After analysis, I located the location where the executor is closed.
SqlSessionManager:
private class SqlSessionInterceptor implements InvocationHandler { public Object invoke(Object proxy, Method method, Object[] args) throws Throwable { final SqlSession sqlSession = SqlSessionManager.this.localSqlSession.get(); if (sqlSession != null) { try { return method.invoke(sqlSession, args); } catch (Throwable t) { throw ExceptionUtil.unwrapThrowable(t); } } else { final SqlSession autoSqlSession = openSession(); try { final Object result = method.invoke(autoSqlSession, args); autoSqlSession.commit(); // Committing data retrieved from the database, but executor not closed! return result; } catch (Throwable t) { autoSqlSession.rollback(); throw ExceptionUtil.unwrapThrowable(t); } finally { autoSqlSession.close(); // Here, the executor is closed. } } } }
This is actually part of the initial call that retrieves the database entities for the first time. The (proxied) entities are created and committed to the cache (EhCache) BEFORE closing the executor. So while this call is still commiting objects to the cache. The already committed objects are actually available for other threads requesting the same (now cached) objects. As long as the close() method is not called, the executor remains open in the proxies of the cached objects. When the close() method is finally called, other threads working with the proxied cached objects break, because of the closed executor.
Comment From: FrantaM
I wouldn't say it's a bug since Executors were never declared as thread-safe. I ran into this issue myself, though.
Comment From: glcheng
I think it is, because I'm an end-user, and not a direct user of Executors. Executors are hidden from me inside the proxied/generated objects that mimic my own domain objects.
I'm only using MyBatis by annotating my mapper interface with MyBatis annotations. The mapper interface is then passed to Guice, which is responsible for creating an object for me. I expect the method calls of this object to be thread-safe, or is that a wrong assumption?
Comment From: glcheng
My workaround is now to enforce single thread access to the mapper.
Comment From: glcheng
Hi FranaM,
First of all, thanks for your help, but I don't think a synchronized version is the solution for this problem. Let me explain. The problem can be explained by looking at a method of CachingExecutor:112.
public void commit(boolean required) throws SQLException { delegate.commit(required); tcm.commit(); // Committing database entities here. dirty = false; }
While the tcm.commit() is executing. Database objects are committed to the cache. Only a write lock is acquired for this, which means committed objects are available for read by other threads. The BaseExcutor is still open at this time, causing the problem.
There are at least two solutions for this: - make sure the committed database entities are not accessed by other threads, while the commit process has not finished for all rows -> full lock on cache - always use a new Executor in ResultLoader.selectList()
Comment From: FrantaM
Write locks are exclusive, i.e. no other locks (even read locks) can be acquired until it's released. I do agree that mine solution is not perfect but it's something we can start with. You can write a test too!
Comment From: glcheng
I've created a test case that demonstrates the bug. Below are the steps to get it into the current source tree.
First, add the EhCache dependency in the pom.xml file.
<dependency>
<groupId>org.mybatis.caches</groupId>
<artifactId>mybatis-ehcache</artifactId>
<version>1.0.2</version>
<scope>test</scope>
</dependency>
Next, we want to put the EhCache configuration file in "src/test/java". The file should be named ehcache.xml and paste the content below into it.
<ehcache xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:noNamespaceSchemaLocation="../config/ehcache.xsd">
<diskStore path="java.io.tmpdir"/>
<defaultCache
maxElementsInMemory="10000"
eternal="false"
timeToIdleSeconds="120"
timeToLiveSeconds="1"
maxElementsOnDisk="10000000"
diskExpiryThreadIntervalSeconds="120"
memoryStoreEvictionPolicy="LRU">
<persistence strategy="localTempSwap"/>
</defaultCache>
</ehcache>
The timeToLiveSeconds is set to 1, so we force reloading the cache every second.
I'm reusing the existing Blog test classes for this, so we have to make sure the classes are Serializable. Otherwise we cannot cache it in EhCache. The Author class is already serializable, but Blog and Post aren't. So we add "implements Serializable" to the class definitions of Blog and Post.
Now, we add some extra code to the BlogMapper:
@Select("SELECT * FROM author WHERE id = #{authorId}")
@Options(useCache = true)
Author getAuthorById(long authorId);
@Select("SELECT * FROM post WHERE blog_id = #{blogId}")
@Options(useCache = true)
List<Post> getPostsByBlogId(long blogId);
@Select("SELECT * FROM blog")
@Results({
@Result(property = "id", column = "id"),
@Result(property = "author", column = "author_id", javaType = Author.class, one = @One(select = "getAuthorById")),
@Result(property = "posts", column = "blog_id", javaType = List.class, many = @Many(select = "getPostsByBlogId"))
})
@Options(useCache = true)
List<Blog> getAllBlogs();
Don't forget to add the "@CacheNamespace(implementation = org.mybatis.caches.ehcache.EhcacheCache.class)" annotation on top of interface definition, in order to enable EhCache.
Next, make a copy of MapperConfig.xml (I called it RacingConditionMapperConfig.xml). Enable lazy loading, but disable aggressive lazy loading.
<setting name="aggressiveLazyLoading" value="false"/>
<setting name="cacheEnabled" value="true"/>
<setting name="lazyLoadingEnabled" value="true"/>
Finally, this is the test case:
public class RaceConditionTest extends BaseDataTest {
private static SqlSessionManager manager;
@BeforeClass
public static void setup() throws Exception {
createBlogDataSource();
final String resource = "org/apache/ibatis/builder/RaceConditionMapperConfig.xml";
final Reader reader = Resources.getResourceAsReader(resource);
manager = SqlSessionManager.newInstance(reader);
}
@Test
public void raceConditionBugTest() throws InterruptedException {
final BlogMapper mapper = manager.getMapper(BlogMapper.class);
final AtomicBoolean bugTriggered = new AtomicBoolean(false);
for (int i = 0; i < 100; i++) {
new Thread(new Runnable() {
@Override
public void run() {
try {
while (!bugTriggered.get()) {
for (Blog blog : mapper.getAllBlogs()) {
blog.getAuthor().getEmail();
}
}
} catch (Exception e) {
e.printStackTrace();
bugTriggered.set(true);
}
}
}).start();
}
Thread.sleep(10000L);
assertFalse(bugTriggered.get());
}
}
If I didn't forget anything, this should be enough to see the bug.
Comment From: glcheng
This is part of the output of the test case:
java.lang.NullPointerException
at org.apache.ibatis.executor.BaseExecutor.queryFromDatabase(BaseExecutor.java:261)
at org.apache.ibatis.executor.BaseExecutor.query(BaseExecutor.java:132)
at org.apache.ibatis.executor.loader.ResultLoader.selectList(ResultLoader.java:76)
at org.apache.ibatis.executor.loader.ResultLoader.loadResult(ResultLoader.java:65)
at org.apache.ibatis.executor.loader.ResultLoaderMap$LoadPair.load(ResultLoaderMap.java:203)
at org.apache.ibatis.executor.loader.ResultLoaderMap$LoadPair.load(ResultLoaderMap.java:168)
at org.apache.ibatis.executor.loader.ResultLoaderMap.load(ResultLoaderMap.java:76)
at org.apache.ibatis.executor.loader.cglib.CglibProxyFactory$EnhancedResultObjectProxyImpl.intercept(CglibProxyFactory.java:144)
at domain.blog.Blog$$EnhancerByCGLIB$$246c9b93.getAuthor(<generated>)
at org.apache.ibatis.session.RaceConditionTest$1.run(RaceConditionTest.java:56)
at java.lang.Thread.run(Thread.java:619)
Comment From: FrantaM
You should really turn this into a pull request so we don't forget anything when recreating your test. (Or you can send a pull request to my branch.)
Also, is this specific to Ehcache or will the test fail with PerpetualCache & ScheduledCache as well?
Comment From: emacarron
Hi guys,
Sorry for the late replay I was on holiday.
Looks like the lazy object starts the query task (selectList) the executor was open and it gets closed before selectList finishes.
private <E> List<E> selectList() throws SQLException {
Executor localExecutor = executor;
if (localExecutor.isClosed()) {
localExecutor = newExecutor();
}
try {
return localExecutor.<E> query(mappedStatement, parameterObject, RowBounds.DEFAULT, Executor.NO_RESULT_HANDLER, cacheKey, boundSql);
} finally {
if (localExecutor != executor) {
localExecutor.close(false);
}
}
}
I think we should create a new executor instead of trying to reuse the "owner". Probably this was designed this way to speed up accesses from the thread that executed the main statement.
So the change is just removing the if (localExecutor.isClosed())
The only side effect I can think of is that executors hold the local cache. Given that the executor will be new, its local cache will be empty. This local cache is not very hepful in a lazy load scenario, so looks there will be no impact.
Can you try with this?
Comment From: glcheng
Thanks, I think this will work.
Comment From: emacarron
In order to keep curren behaviour we could check if the lazy load is being triggered from the original thread or not.
With this pattern: - open a session - execute an statement - access lazy properties - close the session
it is desirable that the session is reused given that it is already open.
The code would be just this:
private <E> List<E> selectList() throws SQLException {
Executor localExecutor = executor;
if (Thread.currentThread() != this.creatorThread || localExecutor.isClosed()) {
localExecutor = newExecutor();
}
try {
return localExecutor.<E> query(mappedStatement, parameterObject, RowBounds.DEFAULT, Executor.NO_RESULT_HANDLER, cacheKey, boundSql);
} finally {
if (localExecutor != executor) {
localExecutor.close(false);
}
}
}
If the original thread is reused (in a different hit to the server) the original executor will be closed so a new one will be created.
What do you think?
I will do the change so you can test it. I will upload a jar to gcode. We would appreciate that you add your test to the project as a PR.
Comment From: emacarron
Can you please confirm the fix worked?
Comment From: glcheng
I used the test case I created earlier to verify if the issue is fixed. A see no NullPointerExceptions anymore. Thanks!
Comment From: emacarron
Thank you!!
Comment From: anludena
Hello Guys:
This fixed is from the latest version of mybatis? or Do I need to create a function in my project for this bug?
Regards Antonio
Comment From: zhanghailang123
Regards
this issue is ten years old