MyBatis cache problem: Error closing transaction. Cause: org.apache.ibatis.cache.CacheException: Error serializing object.

[SashaPaindeaz]

Greetings!
I'm running into a problem with cache, select statement and trying to
close the session.

When I added <cache /> to my xml maper, I'm getting
org.apache.ibatis.exceptions.PersistenceException. If I comment out
session.close() I get no exceptions, but wonder if session remains
opened.

I came across this problem while trying to make sure that MyBatis
cache is working. I have logging set to DEBUG, but find no mention of
anything getting obtained from cache.

Log displays the following:

[DEBUG,Connection,http-8084-6] ooo Connection Opened
[DEBUG,PreparedStatement,http-8084-6] ==> Executing: select * from
story where id = ?
[DEBUG,PreparedStatement,http-8084-6] ==> Parameters: 4(Integer)
[DEBUG,ResultSet,http-8084-6] <== Columns: title, story,
date_created, last_modified, sub_title, category_id, view_link,
completion, home_page, allow_comments, meta_description,
meta_keywords, id

( ... clipped, the actual body of data selected )

[DEBUG,Connection,http-8084-10] xxx Connection Closed

Could anyone kindly shed some light on what I'm looking at or what I'm
missing?
Many thanks in advance.

MAPPER XML:
<?xml version="1.0" encoding="UTF-8" ?><!DOCTYPE mapper PUBLIC "-//
mybatis.org//DTD Mapper 3.0//EN" "http://mybatis.org/dtd/mybatis-3-
mapper.dtd">

<mapper namespace="bap.persistance.interfaces.ArticleMapper">

<cache />

<select id="selectArticle" parameterType="int" resultType="Article"
> select * from story where id = #{id} </select>
</mapper>


TRYING TO EXECUTE THE SELECT:
try {
ArticleMapper mapper = session.getMapper(ArticleMapper.class);
article = mapper.selectArticle(story_id);
} finally {
session.close();
}

EXCEPTION:
org.springframework.web.util.NestedServletException: Request
processing failed; nested exception is
org.apache.ibatis.exceptions.PersistenceException:
### Error closing transaction. Cause:
org.apache.ibatis.cache.CacheException: Error serializing object.
Cause: java.io.NotSerializableException: bap.domain.Article
### Cause: org.apache.ibatis.cache.CacheException: Error serializing
object. Cause: java.io.NotSerializableException: bap.domain.Article

org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:
656)

org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:
549)
javax.servlet.http.HttpServlet.service(HttpServlet.java:617)
javax.servlet.http.HttpServlet.service(HttpServlet.java:717)

org.netbeans.modules.web.monitor.server.MonitorFilter.doFilter(MonitorFilter.java:
390)

(... rest clipped for brevity)

ROOT CAUSE:
org.apache.ibatis.exceptions.PersistenceException:
### Error closing transaction. Cause:
org.apache.ibatis.cache.CacheException: Error serializing object.
Cause: java.io.NotSerializableException: bap.domain.Article
### Cause: org.apache.ibatis.cache.CacheException: Error serializing
object. Cause: java.io.NotSerializableException: bap.domain.Article

(... rest clipped for brevity)

[Richard Yee]

If you are using a cache, you need to make sure your class is serializable.

 

This says it all:

 

### Error closing transaction.  Cause:
org.apache.ibatis.cache.CacheException: Error serializing object.
Cause: java.io.NotSerializableException: bap.domain.Article
### Cause: org.apache.ibatis.cache.CacheException: Error serializing
object.  Cause: java.io.NotSerializableException: bap.domain.Article

 

-Richard

[tomasz brymora]

... thanks, took care of that (what a bonehead morning). However something's still not right.
Any other suggestions?

[Richard Yee]

Are you getting the same exception? What is the new stack trace?

R

[tomasz brymora]

... no exceptions now.

Here's part of log4j prop:

log4j.logger.com.ibatis=DEBUG
log4j.logger.com.ibatis.common.jdbc.SimpleDataSource=DEBUG
log4j.logger.com.ibatis.common.jdbc.ScriptRunner=DEBUG
log4j.logger.com.ibatis.sqlmap.engine.impl.SqlMapClientDelegate=DEBUG
log4j.logger.java.sql.Connection=DEBUG
log4j.logger.java.sql.Statement=DEBUG
log4j.logger.java.sql.PreparedStatement=DEBUG
log4j.logger.java.sql.ResultSet=DEBUG


... what I'm hung up on is seeing something in the log file similar to the way iBats 2.x reported elements getting retrieved from cache.

When I see this:

[DEBUG,Connection,http-8084-8] ooo Connection Opened
[DEBUG,PreparedStatement,http-8084-8] ==>  Executing: select * from story where id = ?
[DEBUG,PreparedStatement,http-8084-8] ==> Parameters: 4(Integer)
[DEBUG,ResultSet,http-8084-8] <==    Columns: title, story, date_created, last_modified, sub_title, category_id, view_link, completion, home_page, allow_comments, meta_description, meta_keywords, id
[DEBUG,ResultSet,http-8084-8] <==        Row: <p>some body copy</p>

, 2008-02-14, 2008-05-22 09:43:26, ... or what a pain in the ass it is, 1, moving_toNb6, f, t, t, , , 4
[DEBUG,Connection,http-8084-8] xxx Connection Closed

... I wonder what's going on.
Does MyBatis do its own connection pooling now? Before logs would indicate connection returning to the pool.

So next I wonder if I'm missing something in the config.xml in regard to data source:

    <environments default="development">
        <environment id="development">

            <transactionManager type="JDBC"/>
            <dataSource type="POOLED" >
                <property name="driver" value="org.postgresql.Driver"/>
                <property name="url" value="jdbc:postgresql://localhost:5432/my_db"/>
                <property name="username" value="usr"/>
                <property name="password" value="pass"/>
            </dataSource>
        </environment>
    </environments>

Thanks again.

[Clinton Begin]

You're using MyBatis 3.0.  So all of your package names are incorrect... they refer to com.ibatis.  They should be org.apache.ibatis.*

Also, sorry for the missing doc on this one...

  private static final Log log = LogFactory.getLog(LoggingCache.class);

Thus enable:

log4j.logger.org.apache.ibatis.cache.decorators.LoggingCache=DEBUG

Clinton

[tomasz brymora]

... Thanks!

Still no luck in the cache department though, at least with the minimum "<cache />" set up.
Logger says:

[DEBUG,PooledDataSource,http-8084-4] PooledDataSource forcefully closed/removed all connections.
[DEBUG,PooledDataSource,http-8084-4] Created connection 9689892.
[DEBUG,Connection,http-8084-4] ooo Connection Opened
[DEBUG,LoggingCache,http-8084-4] Cache Hit Ratio [bap.persistance.interfaces.ArticleMapper]: 0.0

(...)

[DEBUG,Connection,http-8084-4] xxx Connection Closed
[DEBUG,PooledDataSource,http-8084-4] Returned connection 9689892 to pool.

[Clinton Begin]

It looks like it's logging now.  It's just not caching anything yet.

Clinton

[tomasz brymora]

... indeed, that's what I'm stock on now.
Any hints on moving forwards from this point?
I've tried more explicit settings per the pdf manual but to no avail.
This is really embarrassing,  but I'm not sure where to look next.
Thanks

[Clinton Begin]

What version are you using (specifically).  There was a bug way back in one of the betas that stopped anything from being cached...

clinton

[tomasz brymora]

... latest bundle jars:

mybatis-3.0.1.jar
cglib-2.1_3.jar
asm-1.5.3.jar

Thanks

[tomasz brymora]

... I should mention it's a Spring 3.0.2 based project, could this be a factor?
t

[Clinton Begin]

Absolutely. 

Maybe write yourself a small unit test isolating MyBatis to see if you can get the cache to work.  Then add back a piece at a time until it stops working.

Clinton

[tomasz brymora]

...  no joy. I slapped together a plain vanilla servlet project in NetBeans and added just the MyBatis elements to it and the problem is persisting. I'll dig a little deeper into it ad see what turns up. Would anyone be kindly willing to look at the source if I posted in it on Assembla.com?
Thanks