一次数据库死锁原因分析-优快云博客

线上crm导出一份报表时长时没反应，日志一看：


2017-09-25 13:45:58 [http-nio-8080-exec-60] ERROR: jdbc.sqltiming#exceptionOccured : 1469. PreparedStatement.executeBatch() FAILED! batching 3 statements: 1: update uwc_applyloan_attach set ATTACH_ID=112103 where ID=44602 2:
update uwc_applyloan_attach set ATTACH_ID=112106 where ID=44603 3: update uwc_applyloan_attach
set ATTACH_ID=112109 where ID=44604
 {FAILED after 135899 msec}
java.sql.BatchUpdateException: Lock wait timeout exceeded; try restarting transaction
    at com.mysql.jdbc.SQLError.createBatchUpdateException(SQLError.java:1167)
    at com.mysql.jdbc.PreparedStatement.executeBatchSerially(PreparedStatement.java:1778)
    at com.mysql.jdbc.PreparedStatement.executeBatchInternal(PreparedStatement.java:1262)
    at com.mysql.jdbc.StatementImpl.executeBatch(StatementImpl.java:970)
    at net.sf.log4jdbc.StatementSpy.executeBatch(StatementSpy.java:526)
    at sun.reflect.GeneratedMethodAccessor387.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:601)
    at org.apache.tomcat.jdbc.pool.StatementFacade$StatementProxy.invoke(StatementFacade.java:114)
    at com.sun.proxy.$Proxy33.executeBatch(Unknown Source)
    at org.hibernate.jdbc.BatchingBatcher.doExecuteBatch(BatchingBatcher.java:70)
    at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:268)
    at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:268)
    at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:185)
    at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:321)
    at org.hibernate.event.def.DefaultAutoFlushEventListener.onAutoFlush(DefaultAutoFlushEventListener.java:64)
    at org.hibernate.impl.SessionImpl.autoFlushIfRequired(SessionImpl.java:1185)
    at org.hibernate.impl.SessionImpl.list(SessionImpl.java:1261)
    at org.hibernate.impl.QueryImpl.list(QueryImpl.java:102)
    at com.upg.ucars.framework.base.AbstractHibernateDAO$1.doInHibernate(AbstractHibernateDAO.java:172)
    at org.springframework.orm.hibernate3.HibernateTemplate.doExecute(HibernateTemplate.java:406)
    at org.springframework.orm.hibernate3.HibernateTemplate.executeFind(HibernateTemplate.java:343)
    at com.upg.ucars.framework.base.AbstractHibernateDAO.queryByParam(AbstractHibernateDAO.java:147)
    at com.upg.ucars.framework.base.AbstractHibernateDAO.queryByParam(AbstractHibernateDAO.java:92)
    at com.upg.tenant.yuntao.core.UwcApplyloanAttachDaoImpl.getByApplyId(UwcApplyloanAttachDaoImpl.java:19)
    at com.upg.es.seal.core.EsSealServiceImpl.generateDownloadData(EsSealServiceImpl.java:568)
    at com.upg.es.seal.core.EsSealServiceImpl$$FastClassByCGLIB$$f4dc2f5b.invoke(<generated>)
    at net.sf.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204)
    at org.springframework.aop.framework.Cglib2AopProxy$CglibMethodInvocation.invokeJoinpoint(Cglib2AopProxy.java:689)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
    at org.springframework.aop.framework.adapter.ThrowsAdviceInterceptor.invoke(ThrowsAdviceInterceptor.java:124)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
    at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:110)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
    at org.springframework.aop.framework.adapter.ThrowsAdviceInterceptor.invoke(ThrowsAdviceInterceptor.java:124)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
    at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:110)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
    at org.springframework.aop.framework.adapter.ThrowsAdviceInterceptor.invoke(ThrowsAdviceInterceptor.java:124)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
    at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:110)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
    at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:90)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
    at org.springframework.aop.framework.Cglib2AopProxy$DynamicAdvisedInterceptor.intercept(Cglib2AopProxy.java:622)
    at com.upg.es.seal.core.EsSealServiceImpl$$EnhancerByCGLIB$$1d4e14b1.generateDownloadData(<generated>)

UwcApplyloanAttachDaoImpl.getByApplyId(UwcApplyloanAttachDaoImpl.java:19)这句造成了锁超时，但奇怪的是这个是个查询语句。

分析了下Hibernate源码，原来在查询中还需要先Flush一下，看org.hibernate.impl.SessionImpl源码：


public List list(String query, QueryParameters queryParameters) throws HibernateException {
        errorIfClosed();
        checkTransactionSynchStatus();
        queryParameters.validateParameters();
        HQLQueryPlan plan = getHQLQueryPlan( query, false );
        autoFlushIfRequired( plan.getQuerySpaces() );

        List results = CollectionHelper.EMPTY_LIST;
        boolean success = false;

        dontFlushFromFind++;   //stops flush being called multiple times if this method is recursively called
        try {
            results = plan.performList( queryParameters, this );
            success = true;
        }
        finally {
            dontFlushFromFind--;
            afterOperation(success);
        }
        return results;
    }


/**
     * detect in-memory changes, determine if the changes are to tables
     * named in the query and, if so, complete execution the flush
     */
    protected boolean autoFlushIfRequired(Set querySpaces) throws HibernateException {
        errorIfClosed();
        if ( ! isTransactionInProgress() ) {
            // do not auto-flush while outside a transaction
            return false;
        }
        AutoFlushEvent event = new AutoFlushEvent(querySpaces, this);
        AutoFlushEventListener[] autoFlushEventListener = listeners.getAutoFlushEventListeners();
        for ( int i = 0; i < autoFlushEventListener.length; i++ ) {
            autoFlushEventListener[i].onAutoFlush(event);
        }
        return event.isFlushRequired();
    }

org.hibernate.event.def.AbstractFlushingEventListener


protected void performExecutions(EventSource session) throws HibernateException {

        log.trace("executing flush");

        try {
            session.getJDBCContext().getConnectionManager().flushBeginning();
            // we need to lock the collection caches before
            // executing entity inserts/updates in order to
            // account for bidi associations
            session.getActionQueue().prepareActions();
            session.getActionQueue().executeActions();
        }
        finally {
            session.getJDBCContext().getConnectionManager().flushEnding();
        }
    }

org.hibernate.jdbc.AbstractBatcher


public void executeBatch() throws HibernateException {
        if (batchUpdate!=null) {
            try {
                try {
                    doExecuteBatch(batchUpdate);
                }
                finally {
                    closeStatement(batchUpdate);
                }
            }
            catch (SQLException sqle) {
                throw JDBCExceptionHelper.convert(
                        factory.getSQLExceptionConverter(),
                        sqle,
                        "Could not execute JDBC batch update",
                        batchUpdateSQL
                    );
            }
            finally {
                batchUpdate=null;
                batchUpdateSQL=null;
            }
        }
    }

看到这里就明白了， doExecuteBatch(batchUpdate); 如果有待Flush的update操作存在，前面一次操作的长事务还没结束而同时另外一个长事务操作又开始了，到了getByApplyId这里又去更新同样的记录就得等待锁释放了。