生产系统故障定位-多线程性能优化、数据库连接被关闭-阿里云开发者社区

开发者社区> 数据库> 正文
登录阅读全文

生产系统故障定位-多线程性能优化、数据库连接被关闭

简介: 错误使用spring申明式事务管理器带来的性能降低; 定位多线程中的性能瓶颈; jtds + sqlserver2008r2的一次数据库连接被持续关闭的故障定位

优化一

故障现象

radius认证存在大量的重复请求,radius server在timeout之前无法及时响应。
image

分析过程

1、使用java提供的线程dump工具dump出当前的线程状态,进行分析

Thread: default_authen_thread7(16408500110), State: RUNNABLE
    at java.net.SocketInputStream.socketRead0(SocketInputStream.java:-2)
    at java.net.SocketInputStream.read(SocketInputStream.java:152)
    at java.net.SocketInputStream.read(SocketInputStream.java:122)
    at java.io.DataInputStream.readFully(DataInputStream.java:195)
    at java.io.DataInputStream.readFully(DataInputStream.java:169)
    at net.sourceforge.jtds.jdbc.SharedSocket.readPacket(SharedSocket.java:846)
    at net.sourceforge.jtds.jdbc.SharedSocket.getNetPacket(SharedSocket.java:727)
    at net.sourceforge.jtds.jdbc.ResponseStream.getPacket(ResponseStream.java:466)
    at net.sourceforge.jtds.jdbc.ResponseStream.read(ResponseStream.java:103)
    at net.sourceforge.jtds.jdbc.ResponseStream.peek(ResponseStream.java:88)
    at net.sourceforge.jtds.jdbc.TdsCore.wait(TdsCore.java:3932)
    at net.sourceforge.jtds.jdbc.TdsCore.executeSQL(TdsCore.java:1046)
    at net.sourceforge.jtds.jdbc.TdsCore.submitSQL(TdsCore.java:899)
    at net.sourceforge.jtds.jdbc.ConnectionJDBC2.commit(ConnectionJDBC2.java:2094)
    at com.alibaba.druid.filter.FilterChainImpl.connection_commit(FilterChainImpl.java:180)
    at com.alibaba.druid.filter.FilterAdapter.connection_commit(FilterAdapter.java:780)
    at com.alibaba.druid.filter.FilterChainImpl.connection_commit(FilterChainImpl.java:176)
    at com.alibaba.druid.proxy.jdbc.ConnectionProxyImpl.commit(ConnectionProxyImpl.java:123)
    at com.alibaba.druid.pool.DruidPooledConnection.commit(DruidPooledConnection.java:731)
    at org.hibernate.transaction.JDBCTransaction.commitAndResetAutoCommit(JDBCTransaction.java:170)
    at org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:146)
    at org.springframework.orm.hibernate3.HibernateTransactionManager.doCommit(HibernateTransactionManager.java:655)
    at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:732)
    at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:701)
    at com.ruijie.spl.common.cache2.TransactionManagerWrapper.commit(TransactionManagerWrapper.java:42)
    at org.springframework.transaction.interceptor.TransactionAspectSupport.commitTransactionAfterReturning(TransactionAspectSupport.java:321)
    at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:116)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
    at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
    at com.sun.proxy.$Proxy412.addMacBindInfoTCache(null:-1)
    at com.ruijie.spl.usermanage.service.UserMabCheckServiceImpl.autoStudyTerminalInfo(UserMabCheckServiceImpl.java:249)
    at com.ruijie.spl.radius.author.face.AuthorInterface.verifyForPackageMode(AuthorInterface.java:2860)
    at com.ruijie.spl.radius.author.face.AuthorInterface.verify(AuthorInterface.java:257)
    at com.ruijie.spl.radius.authen.support.eap.AuthenRuleImpl_EAP.doEapMD5Authen(AuthenRuleImpl_EAP.java:374)
    at com.ruijie.spl.radius.authen.support.eap.AuthenRuleImpl_EAP.doAuthen(AuthenRuleImpl_EAP.java:308)
    at com.ruijie.spl.radius.authen.support.RadiusAuthenRule.doAuthen(RadiusAuthenRule.java:56)
    at com.ruijie.spl.radius.authen.process.RadiusProcessor.process(RadiusProcessor.java:490)
    at com.ruijie.spl.common.net.radius.PacketProcessThread.runOnce(PacketProcessThread.java:68)
    at com.ruijie.spl.common.power.AbstractDaemonThread.run(AbstractDaemonThread.java:157)

分析发现,当前的性能瓶颈在数据库,认证过程中发生了数据库的IO操作。
分析代码发现,实质上当前卡住的位置使用的是异步数据库插入、更新策略,不存在数据库IO。

public void update(MacBindInfo info, boolean async) {
        UpdateMacBindInfoTask updateTask = new UpdateMacBindInfoTask(this, info, getTransactionTemplate().getTransactionManager());
        AsyncExecutorManager asyncManager = (AsyncExecutorManager)SpringBeanFinder.findSingleton("asyncExecutorManager");
        if (async && asyncManager.isEnabled()) {
            asyncManager.getExecutor().submit(updateTask);//程序中实质上使用的异步队列
        } else {
            updateTask.run();
        }
        if (Debuger.isDebugEnabled()) {
            Debuger.debug("用户: "+info.getUserId()+" 已经被刷新到数据库");
        }
    }

仔细分析发现,spring的申明式事务管理,对接口进行了动态代理,自动加上了开启事务、提交事务的操作,涉及到数据库IO操作。


<bean id="transactionProxy" abstract="true"
        class="org.springframework.transaction.interceptor.TransactionProxyFactoryBean">
        <property name="transactionManager" ref="TransactionManager" />
        <property name="transactionAttributes">
            <props>
                <prop key="move*">PROPAGATION_REQUIRED,-Exception</prop>
                <prop key="insert*">
                    PROPAGATION_REQUIRED,-Exception
                </prop>
                <prop key="add*">PROPAGATION_REQUIRED,-Exception</prop>
                <prop key="delete*">
                    PROPAGATION_REQUIRED,-Exception
                </prop>
                <prop key="update*">
                    PROPAGATION_REQUIRED,-Exception
                </prop>
                <prop key="save*">PROPAGATION_REQUIRED,-Exception</prop>
                <prop key="find*">PROPAGATION_SUPPORTS,-readOnly</prop>
                <prop key="get*">PROPAGATION_SUPPORTS,-readOnly</prop>
                <prop key="count*">PROPAGATION_SUPPORTS,-readOnly</prop>
                <prop key="check*">PROPAGATION_SUPPORTS,-readOnly</prop>
            </props>
        </property>
    </bean>

业务的解法:分析业务发现,该业务设计的初衷是必须使用异步提交策略,不应该开启事务,结合spring的申明式事务配置机制,对接口重新定义(换个名字)。

2、进行如上优化后,故障并没有明显的缓解,继续进行线程dump分析。

Thread: default_authen_thread31(17414000170), State: WAITING
    at sun.misc.Unsafe.park(Unsafe.java:-2)
    at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:834)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireShared(AbstractQueuedSynchronizer.java:964)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireShared(AbstractQueuedSynchronizer.java:1282)
    at java.util.concurrent.locks.ReentrantReadWriteLock$ReadLock.lock(ReentrantReadWriteLock.java:731)
    at com.ruijie.spl.proxy.pool.StrategySamMapPool.findAll(StrategySamMapPool.java:104)
    at com.ruijie.spl.proxy.service.StrategySamServiceImpl.getStrategyAllByOperatorNmae(StrategySamServiceImpl.java:61)
    at sun.reflect.GeneratedMethodAccessor1891.invoke(null:-1)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:307)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:182)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:149)
    at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:106)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
    at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
    at com.sun.proxy.$Proxy467.getStrategyAllByOperatorNmae(null:-1)operater.strategy.autoregist
    at com.ruijie.spl.proxy.util.StrategyCheckUtil.checkLimitemode(StrategyCheckUtil.java:37)
    at com.ruijie.spl.proxy.mapping.AcceptIntercepter.processAccept(AcceptIntercepter.java:225)
    at com.ruijie.spl.proxy.util.ProxyUtil.acceptIntercept(ProxyUtil.java:1868)
    at com.ruijie.spl.proxy.util.ProxyUtil.processLocalResponse(ProxyUtil.java:1670)
    at com.ruijie.spl.radius.authen.process.RadiusProcessor.authProxyResponseProcess(RadiusProcessor.java:1529)
    at com.ruijie.spl.radius.authen.process.RadiusProcessor.process(RadiusProcessor.java:404)
    at com.ruijie.spl.common.net.radius.PacketProcessThread.runOnce(PacketProcessThread.java:68)
    at com.ruijie.spl.common.power.AbstractDaemonThread.run(AbstractDaemonThread.java:157)

分析发现,认证线程都卡在这个锁的地方,分析代码,代码有个查找全部的方法,加了一个读写锁的读锁。

public List<StrategySam> findAll() {
        lock.readLock().lock();
        try {
            LinkedList<StrategySam> result = new LinkedList<StrategySam>();
            if(null!=strategySamMap.values()&& strategySamMap.values().size()>0){
                result.addAll(strategySamMap.values());
            }
            return result;
        } finally {
            lock.readLock().unlock();
        }
        
    }

查找整个线程dump,写锁并没有锁住,对于读写锁,在没有写锁的情况,读锁多线程可以共享,不应该存在性能瓶颈问题。
findall接口,查找全部并遍历,因为问题在这个地方,看出数据库中的数据,表中存在大量数据。
image

解法:算法优化。


故障二

故障现象

rsa加解密算法性能瓶颈

Thread: PeapEapAuthProcessorThread-19, State: BLOCKED
    at sun.security.rsa.RSACore$BlindingParameters.getBlindingRandomPair(RSACore.java:404)
    at sun.security.rsa.RSACore.getBlindingRandomPair(RSACore.java:445)
    at sun.security.rsa.RSACore.crtCrypt(RSACore.java:178)
    at sun.security.rsa.RSACore.rsa(RSACore.java:122)
    at sun.security.rsa.RSASignature.engineSign(RSASignature.java:177)
    at java.security.Signature$Delegate.engineSign(Signature.java:1205)
    at java.security.Signature.sign(Signature.java:578)
    at sun.security.ssl.HandshakeMessage$ECDH_ServerKeyExchange.<init>(HandshakeMessage.java:1012)
    at sun.security.ssl.ServerHandshaker.clientHello(ServerHandshaker.java:779)
    at sun.security.ssl.ServerHandshaker.processMessage(ServerHandshaker.java:167)
    at sun.security.ssl.Handshaker.processLoop(Handshaker.java:913)
    at sun.security.ssl.Handshaker$1.run(Handshaker.java:853)
    at sun.security.ssl.Handshaker$1.run(Handshaker.java:851)
    at java.security.AccessController.doPrivileged(AccessController.java:-2)
    at sun.security.ssl.Handshaker$DelegatedTask.run(Handshaker.java:1285)
    at com.ruijie.spl.radius.authen.support.tls.TlsEngine.runSslTask(TlsEngine.java:278)
    at com.ruijie.spl.radius.authen.support.tls.TlsEngine.doSSLHandshake(TlsEngine.java:217)
    at com.ruijie.spl.radius.authen.support.tls.TlsEngine.process(TlsEngine.java:139)
    at com.ruijie.spl.radius.authen.support.peap.PeapAuthEngine.doPeap(PeapAuthEngine.java:199)
    at com.ruijie.spl.radius.authen.support.peap.PeapAuthEngine.process(PeapAuthEngine.java:81)
    at com.ruijie.spl.radius.authen.support.peap.PeapAuthEngine.process(PeapAuthEngine.java:70)
    at com.ruijie.spl.radius.authen.support.eap.EapAuthEngine.doInnerAuth(EapAuthEngine.java:176)
    at com.ruijie.spl.radius.authen.support.eap.EapAuthEngine.doAuth(EapAuthEngine.java:136)
    at com.ruijie.spl.radius.authen.support.eap.EapAuthEngine.doAuth(EapAuthEngine.java:59)
    at com.ruijie.spl.radius.authen.support.eap.EapAuthEngine.doAuthen(EapAuthEngine.java:64)
    at com.ruijie.spl.radius.authen.support.eap.AuthenRuleImpl_EAP_PEAP.doAuthen(AuthenRuleImpl_EAP_PEAP.java:136)
    at com.ruijie.spl.radius.authen.support.RadiusAuthenRule.doAuthen(RadiusAuthenRule.java:58)
    at com.ruijie.spl.radius.authen.support.peap.PeapEapAuthProcessorThread.runOnce(PeapEapAuthProcessorThread.java:166)
    at com.ruijie.spl.common.power.AbstractDaemonThread.run(AbstractDaemonThread.java:156)

分析发现,RSA算法加解密需要进行大量计算,JDK底层针对这个问题进行的优化策略是引入缓存。引入缓存后,为解决多线程并发计算的现场安全问题,在计算时进行加锁处理。导致了本次的性能瓶颈
image
image
image

优化方案

由于在业务场景下(无线1x认证,TLS通道加密),必须是RSA算法。同时在网上搜索许久也没有搜到源码。想是JDK真的这部分没有开放源代码。最终想到的是使用反射进行缓存替换,使用线程本地变量,将缓存进行扩充,解决多线程锁的性能消耗。

      final Wireless1XWeakHashMap Wireless1XWeakHashMap = new Wireless1XWeakHashMap();
        Field nameField1 = RSACore.class.getDeclaredField("blindingCache");
        
        Field modifiersField1 = Field.class.getDeclaredField("modifiers"); 
        modifiersField1.setAccessible(true);
        modifiersField1.setInt(nameField1, nameField1.getModifiers() & ~Modifier.FINAL); //解决final无法重新赋值的问题
        
        nameField1.setAccessible(true); 
        nameField1.set(RSACore.class, Wireless1XWeakHashMap);
        System.out.println(nameField1.get(RSACore.class)); 
public class Wireless1XWeakHashMap extends WeakHashMap<BigInteger, Object>{
    /***存储 RSACore。BlindingParameters 类型***/
    ThreadLocal<WeakHashMap<BigInteger, Object>> longLocal = new ThreadLocal<WeakHashMap<BigInteger, Object>>();
    
    public Object get(BigInteger key) {
        WeakHashMap<BigInteger, Object> weakHashMap = longLocal.get();
        if(weakHashMap == null) {
            return null;
        }
        
        return weakHashMap.get(key);
    }
    
    
    public Object put(BigInteger key, Object value) {
        WeakHashMap<BigInteger, Object> weakHashMap = longLocal.get();
        if(weakHashMap == null) {
            longLocal.set(new WeakHashMap<BigInteger, Object>());
        }
        weakHashMap = longLocal.get();
        return weakHashMap.put(key, value);
    }
}

参考:http://blog.51cto.com/nxlhero/1832127

jtds + sqlserver2008r2的一次数据库连接被持续关闭的故障定位

故障现象

系统在运行时,整个系统的业务不定时不正常,包括web页面的访问,在不正常时,后台对应的错误日志为数据库连接被关闭

2018-10-09 20:49:50,029 ERROR [default_authen_thread10] com.ruijie.spl.radius.authen.process.RadiusProcessor - 
org.springframework.transaction.TransactionSystemException: Could not roll back Hibernate transaction; nested exception is org.hibernate.TransactionException: JDBC rollback failed
    at org.springframework.orm.hibernate3.HibernateTransactionManager.doRollback(HibernateTransactionManager.java:677)
    at org.springframework.transaction.support.AbstractPlatformTransactionManager.processRollback(AbstractPlatformTransactionManager.java:823)
    at org.springframework.transaction.support.AbstractPlatformTransactionManager.rollback(AbstractPlatformTransactionManager.java:800)
    at com.ruijie.spl.common.cache2.TransactionManagerWrapper.rollback(TransactionManagerWrapper.java:84)
    at org.springframework.transaction.support.TransactionTemplate.rollbackOnException(TransactionTemplate.java:154)
    at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:132)
    at com.ruijie.spl.onlineuser.service.OnlineUserServiceImpl.directDeleteAndAuthLater(OnlineUserServiceImpl.java:2664)
    at sun.reflect.GeneratedMethodAccessor2565.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:601)
    at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:307)
    at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:198)
    at com.sun.proxy.$Proxy196.directDeleteAndAuthLater(Unknown Source)
    at com.ruijie.spl.radius.authen.support.DirectDeleteFalseOnlineUserAction.execution(DirectDeleteFalseOnlineUserAction.java:13)
    at com.ruijie.spl.radius.authen.process.RadiusProcessor.process(RadiusProcessor.java:689)
    at com.ruijie.spl.common.net.radius.PacketProcessThread.runOnce(PacketProcessThread.java:62)
    at com.ruijie.spl.common.power.AbstractDaemonThread.run(AbstractDaemonThread.java:156)
Caused by: org.hibernate.TransactionException: JDBC rollback failed
    at org.hibernate.transaction.JDBCTransaction.rollback(JDBCTransaction.java:204)
    at org.springframework.orm.hibernate3.HibernateTransactionManager.doRollback(HibernateTransactionManager.java:674)
    ... 16 more
Caused by: java.sql.SQLException: Invalid state, the Connection object is closed.
    at net.sourceforge.jtds.jdbc.ConnectionJDBC2.checkOpen(ConnectionJDBC2.java:1699)
    at net.sourceforge.jtds.jdbc.ConnectionJDBC2.rollback(ConnectionJDBC2.java:2100)
    at org.jboss.resource.adapter.jdbc.BaseWrapperManagedConnection.jdbcRollback(BaseWrapperManagedConnection.java:697)
    at org.jboss.resource.adapter.jdbc.WrappedConnection.rollback(WrappedConnection.java:500)
    at com.ruijie.spl.common.datasource.SplConnection.rollback(SplConnection.java:196)
    at org.hibernate.transaction.JDBCTransaction.rollbackAndResetAutoCommit(JDBCTransaction.java:217)
    at org.hibernate.transaction.JDBCTransaction.rollback(JDBCTransaction.java:196)
    ... 17 more

故障分析

1、查看源码发现,jtds的数据库连接的状态通过boolean 成员变量closed进行控制,在网上查找资料,说1.2.5版本存在一些问题,于是借着这个机会将jtds的版本进行了一次升级。

2、下载jtds的1.3.1的源码进行分析,发现源码变化很大,原本的net.sourceforge.jtds.jdbc.ConnectionJDBC2已经变更为了net.sourceforge.jtds.jdbc.JtdsConnection。分析下源码,将关闭数据库连接的地方都加上调试日志
void setClosed()
synchronized public void close() throws SQLException

3、升级jtds到1.3.1,故障现象依旧,问题依然没有得到解决,但是本地升级机制的将日志加上了,开启log4j的日志,日志报错信息如下

2018-10-15 20:02:02,131 ERROR [default_authen_thread7] net.sourceforge.jtds.jdbc.JtdsConnection - ------------数据库被setClosed关闭-----------
java.lang.Exception
    at net.sourceforge.jtds.jdbc.JtdsConnection.setClosed(JtdsConnection.java:1855)
    at net.sourceforge.jtds.jdbc.TdsCore.tdsDoneToken(TdsCore.java:3698)
    at net.sourceforge.jtds.jdbc.TdsCore.nextToken(TdsCore.java:2472)
    at net.sourceforge.jtds.jdbc.TdsCore.getMoreResults(TdsCore.java:677)
    at net.sourceforge.jtds.jdbc.JtdsStatement.processResults(JtdsStatement.java:613)
    at net.sourceforge.jtds.jdbc.JtdsStatement.executeSQL(JtdsStatement.java:572)
    at net.sourceforge.jtds.jdbc.JtdsPreparedStatement.executeUpdate(JtdsPreparedStatement.java:727)
    at org.jboss.resource.adapter.jdbc.CachedPreparedStatement.executeUpdate(CachedPreparedStatement.java:96)
    at org.jboss.resource.adapter.jdbc.WrappedPreparedStatement.executeUpdate(WrappedPreparedStatement.java:365)
    at org.springframework.jdbc.core.JdbcTemplate$2.doInPreparedStatement(JdbcTemplate.java:798)
    at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:591)
    at org.springframework.jdbc.core.JdbcTemplate.update(JdbcTemplate.java:792)
    at org.springframework.jdbc.core.JdbcTemplate.update(JdbcTemplate.java:850)
    at org.springframework.jdbc.core.JdbcTemplate.update(JdbcTemplate.java:858)
    at com.ruijie.spl.onlineuser.dao.OnlineUserDAOImpl.delete(OnlineUserDAOImpl.java:813)
    at com.ruijie.spl.onlineuser.service.OnlineUserServiceImpl.deleteOnlineUser(OnlineUserServiceImpl.java:396)
    at com.ruijie.spl.onlineuser.service.OnlineUserServiceImpl.dealUserLogout(OnlineUserServiceImpl.java:2481)
    at com.ruijie.spl.onlineuser.service.OnlineUserServiceImpl.billAndLogout(OnlineUserServiceImpl.java:2230)
    at sun.reflect.GeneratedMethodAccessor915.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:601)
    at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:307)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:182)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:149)
    at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:106)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
    at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
    at com.sun.proxy.$Proxy196.billAndLogout(Unknown Source)
    at com.ruijie.spl.onlineuser.interf.OnlineUserForRadiusService.billAndLogout(OnlineUserForRadiusService.java:79)
    at com.ruijie.spl.radius.author.face.InterfFromOnlineuserService$1.doInTransaction(InterfFromOnlineuserService.java:113)
    at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:128)
    at com.ruijie.spl.radius.author.face.InterfFromOnlineuserService.billAndLogout(InterfFromOnlineuserService.java:111)
    at com.ruijie.spl.onlineuser.service.OnlineUserServiceImpl$4.doInTransaction(OnlineUserServiceImpl.java:2669)
    at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:128)
    at com.ruijie.spl.onlineuser.service.OnlineUserServiceImpl.directDeleteAndAuthLater(OnlineUserServiceImpl.java:2664)
    at sun.reflect.GeneratedMethodAccessor984.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:601)
    at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:307)
    at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:198)
    at com.sun.proxy.$Proxy196.directDeleteAndAuthLater(Unknown Source)
    at com.ruijie.spl.radius.authen.support.DirectDeleteFalseOnlineUserAction.execution(DirectDeleteFalseOnlineUserAction.java:13)
    at com.ruijie.spl.radius.authen.process.RadiusProcessor.process(RadiusProcessor.java:689)
    at com.ruijie.spl.common.net.radius.PacketProcessThread.runOnce(PacketProcessThread.java:62)
    at com.ruijie.spl.common.power.AbstractDaemonThread.run(AbstractDaemonThread.java:156)

根据日志信息,结合系统业务,当前执行的sql为

"DELETE FROM ONLINE_USER WHERE ONLINE_USER_UUID=?", new Object[]{onlineUser.getOnlineUserUuid()}

分析sqlserver的日志,服务器上会相对应的记录如下错误信息

日期        2018/10/16 11:35:46
日志        SQL Server (存档编号1 - 2018/10/16 13:14:00)

源        spid57

消息
Database ID 5, Page (1:1729) is marked RestorePending, which may indicate disk corruption. To recover from this state, perform a restore.

说明数据库完整性存在问题。使用如下脚本进行完整性修复

exec sp_dboption DB_, 'single_user', true
DBCC CHECKDB (DB_NAME, repair_allow_data_loss) with NO_INFOMSGS
exec sp_dboption DB_NAME, 'single_user', false

修复完后

修复: 已为数据库 'DB_NAME' 中的对象 'dbo.ONLINE_USER, idx_online_user_nas' 成功地重新生成了 Nonclustered 索引。
修复: 页 (1:1729) 已从对象 ID 410484541,索引 ID 3,分区 ID 72057596299902976,分配单元 ID 72057596354363392 (类型为 In-row data)释放。
消息 8945,级别 16,状态 1,第 2 行
表错误: 将重新生成对象 ID 410484541,索引 ID 3。
        该错误已修复。
消息 8928,级别 16,状态 1,第 2 行
对象 ID 410484541,索引 ID 3,分区 ID 72057596299902976,分配单元 ID 72057596354363392 (类型为 In-row data): 无法处理页 (1:1729)。有关详细信息,请参阅其他错误消息。
        该错误已修复。
消息 8939,级别 16,状态 98,第 2 行
表错误: 对象 ID 410484541,索引 ID 3,分区 ID 72057596299902976,分配单元 ID 72057596354363392 (类型为 In-row data),页 (1:1729)。测试(IS_OFF (BUF_IOERR, pBUF->bstat))失败。值为 12584969 和 -6。
        该错误已修复。
消息 8976,级别 16,状态 1,第 2 行
表错误: 对象 ID 410484541,索引 ID 3,分区 ID 72057596299902976,分配单元 ID 72057596354363392 (类型为 In-row data)。在扫描过程中未发现页 (1:1729),但该页的父级 (1:13283) 和上一页 (1:53014) 都引用了它。请检查以前的错误消息。
        该错误已修复。
消息 8978,级别 16,状态 1,第 2 行
表错误: 对象 ID 410484541,索引 ID 3,分区 ID 72057596299902976,分配单元 ID 72057596354363392 (类型为 In-row data)。页 (1:53008) 缺少上一页 (1:1729) 对它的引用。可能是因为链链接有问题。
        该错误已修复。

至此,问题完美解决。

版权声明:本文内容由阿里云实名注册用户自发贡献,版权归原作者所有,阿里云开发者社区不拥有其著作权,亦不承担相应法律责任。具体规则请查看《阿里云开发者社区用户服务协议》和《阿里云开发者社区知识产权保护指引》。如果您发现本社区中有涉嫌抄袭的内容,填写侵权投诉表单进行举报,一经查实,本社区将立刻删除涉嫌侵权内容。

分享: