论坛首页 Java企业应用论坛

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

浏览 5731 次
精华帖 (0) :: 良好帖 (0) :: 新手帖 (0) :: 隐藏帖 (0)
作者 正文
   发表时间:2007-10-29  

产品提交测试小组,返回如下异常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。

论坛首页 Java企业应用版

跳转论坛:
Global site tag (gtag.js) - Google Analytics