Hibernate脏数据问题异常及解决思路

产品提交测试小组，返回如下异常bug

Hibernate:
    update
        MAILBOX_VIEW
    set
        name=?,
        homedir=?,
        domainid=?,
        groupid=?,
        max_msg_count=?,
        quota=?,
        usagespace=?,
        valid_msg_count=?,
        status=?,
        zone=?,
        scope=?
    where
        id=?
[class/org.hibernate.util.JDBCExceptionReporter] Thread:pool3_thread5 WARN : 2007-10-29 11:31:10 SQL Error: 17008, SQLState: null
[class/org.hibernate.util.JDBCExceptionReporter] Thread:pool3_thread5 ERROR: 2007-10-29 11:31:10 ?????
[class/org.hibernate.event.def.AbstractFlushingEventListener] Thread:pool3_thread5 ERROR: 2007-10-29 11:31:10 Could not synchronize database state with session
org.hibernate.exception.GenericJDBCException: could not update: [com.ceno.mail.mailbox.persistent.MailBoxPO#2000060]
        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.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2360)
        at org.hibernate.persister.entity.AbstractEntityPersister.updateOrInsert(AbstractEntityPersister.java:2242)
        at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2542)
        at org.hibernate.action.EntityUpdateAction.execute(EntityUpdateAction.java:92)
        at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:248)
        at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:232)
        at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:140)
        at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:298)
        at org.hibernate.event.def.DefaultAutoFlushEventListener.onAutoFlush(DefaultAutoFlushEventListener.java:41)
        at org.hibernate.impl.SessionImpl.autoFlushIfRequired(SessionImpl.java:969)
        at org.hibernate.impl.SessionImpl.list(SessionImpl.java:1114)
        at org.hibernate.impl.QueryImpl.list(QueryImpl.java:79)
        at com.ceno.orm.hibernate.HibernateDAOSupport$HibernateTemplate.find(HibernateDAOSupport.java:1291)
        at com.ceno.mail.user.persistent.MailUserDAO.findMailUser(MailUserDAO.java:313)
        at com.ceno.mail.user.persistent.MailUserDAO.getUser(MailUserDAO.java:350)
        at com.ceno.mail.user.implement.MailUserProxyManager.getUserByName(MailUserProxyManager.java:289)
        at com.ceno.mail.user.persistent.MailUserDAO.getUserByName(MailUserDAO.java:400)
        at com.ceno.mail.user.implement.MailUserProxyManager.getUserByName(MailUserProxyManager.java:88)
        at com.ceno.mail.user.MailUserUtil.getUserByName(MailUserUtil.java:70)
        at com.ceno.mail.login.MailUserAuthModule.login(MailUserAuthModule.java:49)
        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:585)

我们在产品试运行期间从没有发现该问题，该异常是在做Query操作抛出的，经分析后做出如下判断：
1、该段代码本身没有对MailBoxViewPO做任何操作，脏数据是之前遗留的。
2、该段代码前面没有任何Hibernate操作调用，脏数据不会是在同一个thread调用引起的。
3、该段代码对HibernateSession的open/close操作是成对出现的，全部hibernate操作都通过HibernateTemplate来调用，不会出现session遗留问题。

那么问题会在什么地方，难道close的时候数据没有清除掉？再看HibernateSessionFactory的实现，每次OpenSession的时候都是new HibernateSessionImpl对象，不存在这个问题。
灵光一现，Session对象不会被复用，但我们的Thread是复用的，而在获取session的时候会把session捆在ThreadLocal里面，getSession的代码如下：

    /**
     * Retrieves the current Session local to the thread.
     * <p/>
     * If no Session is open, opens a new Session for the running thread.
     *
     * @return Session
     */
    public static Session getSession()
    {
        CountSession s = (CountSession) threadSession.get();

        if (s == null) {
            if (log.isDebug()) {
                log.debug("Opening new Session for this thread.");
            }
            s = new CountSession();
            if (getInterceptor() != null) {
                if (log.isDebug()) {
                    log.debug("Using interceptor: " + getInterceptor().getClass());
                }

                s.setSession(getSessionFactory().openSession(getInterceptor()));
            }
            else {
                s.setSession(getSessionFactory().openSession());
            }
            s.setCount(1);
            threadSession.set(s);
        }
        else {
            s.setCount(s.getCount() + 1);
        }
        return s.getSession();
    }

MailUserUtil所在代码模块的Hibernate调用都通过HibernateTemplate来进行，否认该模块会出现没有调用close操作把session从threadLocal里面移走的低级错误。怀疑的重点到业务和管理系统模块的老代码上，查找老代码的HibernateUtil.getSession()，发现所有代码在调用hibernate操作后都会在finally处调用HibernateUtil.closeSession()。
再次陷入无线索状态中，再次仔细检查调用Hibernate操作的老代码，发现如下一些代码：

        Zone[] zones = new BusinessZonePO[0];
        Session session = HibernateUtil.getSession();
        try {
            HibernateUtil.beginTransaction();
            Query query = session.createQuery("from BusinessZonePO where pid=?");
            query.setInteger(0, pid);
            List list = query.list();
            HibernateUtil.commitTransaction();
            if (list != null && list.size() > 0) {
                zones = (Zone[]) list.toArray(zones);
            }
        }
        catch (HibernateException e) {
            HibernateUtil.rollbackTransaction();
            throw e;
        }
        finally {
            HibernateUtil.closeSession();
        }
        return zones;

有一部份类似的调用都是在getSession后，再beginTransaction，这里代码写法明显有问题，如果在begin和commit之间抛出Unchecked Exception，那么commit和rollback都不会执行。把怀疑重点转到这部分代码上来了，调来HibernateUtil.beginTransaction的实现：

        Transaction tx = (Transaction) threadTransaction.get();
        if (tx == null) {
            if (log.isDebug()) {
                log.debug("Starting new database transaction in this thread.");
            }
            tx = getSession().beginTransaction();
            threadTransaction.set(tx);
        }

一看代码基本上有些眉目了，在这个实现里面，再次调用了getSession,在beginTransaction之前已经调用了一次getSession，这意味着这一次getSession调用会从ThreadLocal对旬里面取到CountSession，并把count置为2。
这样如果没有调用commitTransaction，只会调finally一次closeSession，closeSession的代码如下：

        CountSession s = (CountSession) threadSession.get();
        if (s != null) {
            if (s.getCount() <= 1) {
                threadSession.set(null);
                threadTransaction.set(null);
                s.close();
            }
            else {
                s.setCount(s.getCount() - 1);
            }
        }

如果只调用一次closeSession，那么CountSession对象只会把count减1，并不会从ThreadLocal里面移走。这时候思路渐渐清晰了，再检查HibernateUtil.commitTransaction的实现，问题马上就找到了：

        Transaction tx = (Transaction) threadTransaction.get();
        try {
            if (tx != null && !tx.wasCommitted() && !tx.wasRolledBack()) {
                if (log.isDebug()) {
                    log.debug("Committing database transaction of this thread.");
                }
                tx.commit();
            }
            threadTransaction.set(null);
        }
        catch (HibernateException ex) {
            rollbackTransaction();
            throw ex;
        }

原是是怀疑在begin和commit之间抛出Unchecked Exception，导致commit没调用，检查这段代码才发现commit里面根本没有调用closeSession，导致session残留在ThreadLocal对象里面，在thread被回收到thread pool并下一次被取出调用，该session第二次使用，而这时候session里面会残留大量po对象，有些可能为dirty data。

在commitTransaction里面加入finally{closeSession();}，问题解决。

总结：

1、同时使用ThreadLocal和Thread Pool需十分谨慎检查thread回到pool前，确保local对象一定被释放。
2、对于Session或Connection之类的有限资源，必须通过模板机制保证close/open成对出现，原则上不允许调用者自已进行显示的open/close，一旦代码出现问题，会对系统造成十分严重的影响。
3、深入理解catch/finally，Unchecked Exception。