项目

一般

简介

v9企业版部署的应用出现死锁,造成服务器宕机假象

由 he shancai 在 超过 3 年 之前添加

时间:2022.04.01

项目信息:广西xxx

问题现象:

不定期,有的时候一两星期才挂,有的时候可能隔一两天又挂

原因分析:远程看出,进程未挂掉,只是当时中间件进程中的线程HTTPHandler 处于阻塞状态,一直等待锁的释放,一直处于假死状态,并未对外提供服务

日志信息:
 

org.springframework.orm.ObjectOptimisticLockingFailureException: Batch update returned unexpected row count from update [0]; actual row count: 0; expected: 1; nested exception is org.hibernate.StaleStateException: Batch update returned unexpected row count from update [0]; actual row count: 0; expected: 1
    at org.springframework.orm.jpa.vendor.HibernateJpaDialect.convertHibernateAccessException(HibernateJpaDialect.java:299)
    at org.springframework.orm.jpa.vendor.HibernateJpaDialect.translateExceptionIfPossible(HibernateJpaDialect.java:223)
    at org.springframework.orm.jpa.JpaTransactionManager.doCommit(JpaTransactionManager.java:540)
    at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:746)
    at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:714)
    at org.springframework.transaction.interceptor.TransactionAspectSupport.commitTransactionAfterReturning(TransactionAspectSupport.java:532)
    at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:304)
    at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:98)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185)
    at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:688)
    at com.jeecms.auth.service.impl.LoginServiceImpl$$EnhancerBySpringCGLIB$$fe41faf8.tryValidRepeatSession(<generated>)
    at com.jeecms.component.AuthenticationTokenFilter.doFilter(AuthenticationTokenFilter.java:49)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334)
    at org.springframework.security.web.authentication.logout.LogoutFilter.doFilter(LogoutFilter.java:116)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334)
    at org.springframework.security.web.header.HeaderWriterFilter.doFilterInternal(HeaderWriterFilter.java:74)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334)
    at org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:105)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334)
    at org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter.doFilterInternal(WebAsyncManagerIntegrationFilter.java:56)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334)
    at org.springframework.security.web.FilterChainProxy.doFilterInternal(FilterChainProxy.java:215)
    at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:178)
    at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:357)
    at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:270)
    at com.apusic.web.container.FilterComponent.doFilter(FilterComponent.java:65)
    at com.apusic.web.container.FilterChainImpl.performFilter(FilterChainImpl.java:38)
    at com.apusic.web.container.FilterChainImpl.doFilter(FilterChainImpl.java:45)
    at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:99)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
    at com.apusic.web.container.FilterComponent.doFilter(FilterComponent.java:65)
    at com.apusic.web.container.FilterChainImpl.performFilter(FilterChainImpl.java:38)
    at com.apusic.web.container.FilterChainImpl.doFilter(FilterChainImpl.java:45)
    at org.springframework.web.filter.HttpPutFormContentFilter.doFilterInternal(HttpPutFormContentFilter.java:109)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
    at com.apusic.web.container.FilterComponent.doFilter(FilterComponent.java:65)
    at com.apusic.web.container.FilterChainImpl.performFilter(FilterChainImpl.java:38)
    at com.apusic.web.container.FilterChainImpl.doFilter(FilterChainImpl.java:45)
    at org.springframework.web.filter.HiddenHttpMethodFilter.doFilterInternal(HiddenHttpMethodFilter.java:93)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
    at com.apusic.web.container.FilterComponent.doFilter(FilterComponent.java:65)
    at com.apusic.web.container.FilterChainImpl.performFilter(FilterChainImpl.java:38)
    at com.apusic.web.container.FilterChainImpl.doFilter(FilterChainImpl.java:45)
    at org.springframework.boot.actuate.metrics.web.servlet.WebMvcMetricsFilter.filterAndRecordMetrics(WebMvcMetricsFilter.java:117)
    at org.springframework.boot.actuate.metrics.web.servlet.WebMvcMetricsFilter.doFilterInternal(WebMvcMetricsFilter.java:106)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
    at com.apusic.web.container.FilterComponent.doFilter(FilterComponent.java:65)
    at com.apusic.web.container.FilterChainImpl.performFilter(FilterChainImpl.java:38)
    at com.apusic.web.container.FilterChainImpl.doFilter(FilterChainImpl.java:45)
    at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:200)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
    at com.apusic.web.container.FilterComponent.doFilter(FilterComponent.java:65)
    at com.apusic.web.container.FilterChainImpl.performFilter(FilterChainImpl.java:38)
    at com.apusic.web.container.WebContainer.invoke(WebContainer.java:1166)
    at com.apusic.web.container.WebContainer.doProcessRequest(WebContainer.java:947)
    at com.apusic.web.container.WebContainer.processRequest(WebContainer.java:809)
    at com.apusic.web.http.VirtualHost.processRequest(VirtualHost.java:370)
    at com.apusic.web.http.HttpServer.processRequest(HttpServer.java:317)
    at com.apusic.web.http.HttpConnectionHandler.service(HttpConnectionHandler.java:26)
    at com.apusic.web.http.ConnectionHandler.processRequest(ConnectionHandler.java:360)
    at com.apusic.web.http.ConnectionHandler.processConnection(ConnectionHandler.java:138)
    at com.apusic.web.http.ConnectionHandler.run(ConnectionHandler.java:52)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:748)
Caused by: DD[0]; actual row count: 0; expected: 1
    at org.hibernate.jdbc.Expectations$BasicExpectation.checkBatched(Expectations.java:67)
    at org.hibernate.jdbc.Expectations$BasicExpectation.verifyOutcome(Expectations.java:54)
    at org.hibernate.engine.jdbc.batch.internal.NonBatchingBatch.addToBatch(NonBatchingBatch.java:46)
    at org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:3339)
    at org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:3596)
    at org.hibernate.action.internal.EntityDeleteAction.execute(EntityDeleteAction.java:99)
    at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:600)
    at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:474)
    at org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:337)
    at org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:39)
    at org.hibernate.internal.SessionImpl.doFlush(SessionImpl.java:1437)
    at org.hibernate.internal.SessionImpl.managedFlush(SessionImpl.java:494)
    at org.hibernate.internal.SessionImpl.flushBeforeTransactionCompletion(SessionImpl.java:3245)
    at org.hibernate.internal.SessionImpl.beforeTransactionCompletion(SessionImpl.java:2451)
    at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.beforeTransactionCompletion(JdbcCoordinatorImpl.java:473)
    at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.beforeCompletionCallback(JdbcResourceLocalTransactionCoordinatorImpl.java:156)
    at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.access$100(JdbcResourceLocalTransactionCoordinatorImpl.java:38)
    at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.commit(JdbcResourceLocalTransactionCoordinatorImpl.java:231)
    at org.hibernate.engine.transaction.internal.TransactionImpl.commit(TransactionImpl.java:68)
    at org.springframework.orm.jpa.JpaTransactionManager.doCommit(JpaTransactionManager.java:536)

日志分析:可以看出应用与数据库进行交互,正在执行批量修改的操作,可以判断很大可能为应用线程之间出现竞争锁的操作9(抛出了ObjectOptimisticLockingFailureException异常的信息)

ObjectOptimisticLockingFailureException异常:乐观锁失败异常

查看堆栈日志信息:

堆栈日志分析:大量的线程HTTPHandler 处于阻塞状态,后台执行批量更新的sql语句,导致了乐观锁相关的异常,一直等待锁的释放,关于乐观锁的信息可以网上查阅

原因分析:锁的机制多用于处理多并发的环境下,保证数据一致性,有效性。高并发环境下,在同一时间可能会有多个用户更新相同的记录,这会产生冲突,

锁的使用的不当容易造成死锁,从而影响整个机器的性能。

解决:将该问题跟用户反馈后,用户自行去优化相关代码。