codingapi / codingapi/tx-lcn

浏览器请求调用方服务超时后,数据死锁问题

Open
#556 5 comments 0 reactions 0 assignees View on GitHub
Dominant language
Java
Stars
4.2k
Forks
1.4k
PR merge metrics
No merged PRs in 30d

Description

### 问题描述:
依照下面的代码进行描述,我在调用方服务中设置Thread.sleep(10000)来模拟浏览器调用超时的情况。浏览器请求`controller`,访问调用方服务的`startFlow`方法,第一次请求log如下:
```
18:02:09.730 DEBUG 19228 --- [nio-8120-exec-8] c.z.l.w.p.d.P.selectDetail - ==> Preparing: select dtl.*, ifnull(mb.weight, 0) weight FROM pr_purchase_plan_apply_order_detail dtl left join b_material_basic mb on mb.id = dtl.material_id and mb.tenant_id = ? where dtl.tenant_id = ? and dtl.bus_type = ? and dtl.del_flag = 0 and dtl.order_id in ( ? )
18:02:09.732 DEBUG 19228 --- [nio-8120-exec-8] c.z.l.w.p.d.P.selectDetail - ==> Parameters: b45551e5f8de4efc800e3677ef68cb39(String), b45551e5f8de4efc800e3677ef68cb39(String), 0(String), 768dec70f065d51d23476c4ddea50ad3(String)
18:02:09.740 DEBUG 19228 --- [nio-8120-exec-8] c.z.l.w.p.d.P.selectDetail - <== Total: 1
18:02:09.752 DEBUG 19228 --- [nio-8120-exec-8] c.z.l.w.p.d.P.updateById - ==> Preparing: UPDATE pr_purchase_plan_order SET approval_status=? WHERE id=?
18:02:09.753 DEBUG 19228 --- [nio-8120-exec-8] c.z.l.w.p.d.P.updateById - ==> Parameters: 1(Short), 768dec70f065d51d23476c4ddea50ad3(String)
18:02:09.756 DEBUG 19228 --- [nio-8120-exec-8] c.z.l.w.p.d.P.updateById - <== Updates: 1
18:02:13.719 ERROR 19228 --- [nio-8120-exec-8] c.z.c.e.GlobalExceptionHandler - java.lang.NullPointerException: null
at com.codingapi.txlcn.tc.core.checking.DefaultDTXExceptionHandler.handleNotifyGroupBusinessException(DefaultDTXExceptionHandler.java:93)
at com.codingapi.txlcn.tc.core.template.TransactionControlTemplate.notifyGroup(TransactionControlTemplate.java:156)
at com.codingapi.txlcn.tc.core.transaction.lcn.control.LcnStartingTransaction.postBusinessCode(LcnStartingTransaction.java:69)
at com.codingapi.txlcn.tc.core.DTXServiceExecutor.transactionRunning(DTXServiceExecutor.java:108)
at com.codingapi.txlcn.tc.aspect.weave.DTXLogicWeaver.runTransaction(DTXLogicWeaver.java:96)
at com.codingapi.txlcn.tc.aspect.TransactionAspect.transactionRunning(TransactionAspect.java:83)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:644)
at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:633)
at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:70)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:175)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:749)
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:95)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:749)
at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:691)
at com.zhirui.lmwy.warehouse.purchase_plan_order.service.impl.PurchasePlanOrderServiceImpl$$EnhancerBySpringCGLIB$$f9197350.startFlow()
at com.zhirui.lmwy.warehouse.purchase_plan_order.controller.PurchasePlanOrderController.flowStart(PurchasePlanOrderController.java:54)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:190)
at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:138)
at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:105)
at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:879)
at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:793)
at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87)
at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1040)
at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:943)
at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006)
at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:898)
```
浏览器再次请求,log如下:
```
18:12:23.324 DEBUG 19228 --- [io-8120-exec-10] c.z.l.w.p.d.P.selectDetail - ==> Preparing: select dtl.*, ifnull(mb.weight, 0) weight FROM pr_purchase_plan_apply_order_detail dtl left join b_material_basic mb on mb.id = dtl.material_id and mb.tenant_id = ? where dtl.tenant_id = ? and dtl.bus_type = ? and dtl.del_flag = 0 and dtl.order_id in ( ? )
18:12:23.325 DEBUG 19228 --- [io-8120-exec-10] c.z.l.w.p.d.P.selectDetail - ==> Parameters: b45551e5f8de4efc800e3677ef68cb39(String), b45551e5f8de4efc800e3677ef68cb39(String), 0(String), 768dec70f065d51d23476c4ddea50ad3(String)
18:12:23.331 DEBUG 19228 --- [io-8120-exec-10] c.z.l.w.p.d.P.selectDetail - <== Total: 1
18:12:23.339 DEBUG 19228 --- [io-8120-exec-10] c.z.l.w.p.d.P.updateById - ==> Preparing: UPDATE pr_purchase_plan_order SET approval_status=? WHERE id=?
18:12:23.341 DEBUG 19228 --- [io-8120-exec-10] c.z.l.w.p.d.P.updateById - ==> Parameters: 1(Short), 768dec70f065d51d23476c4ddea50ad3(String)
18:12:26.299 INFO 19228 --- [.12.11.240_8848] c.a.n.c.config.impl.ClientWorker - get changedGroupKeys:[]
18:12:56.413 INFO 19228 --- [.12.11.240_8848] c.a.n.c.config.impl.ClientWorker - get changedGroupKeys:[]
18:13:14.372 ERROR 19228 --- [io-8120-exec-10] c.c.txlcn.tc.core.DTXServiceExecutor - business code error @group(c7a477c4d48537)
18:13:14.376 ERROR 19228 --- [io-8120-exec-10] c.z.c.e.GlobalExceptionHandler - java.lang.NullPointerException: null
at com.codingapi.txlcn.tc.core.checking.DefaultDTXExceptionHandler.handleNotifyGroupBusinessException(DefaultDTXExceptionHandler.java:93)
at com.codingapi.txlcn.tc.core.template.TransactionControlTemplate.notifyGroup(TransactionControlTemplate.java:156)
at com.codingapi.txlcn.tc.core.transaction.lcn.control.LcnStartingTransaction.postBusinessCode(LcnStartingTransaction.java:69)
at com.codingapi.txlcn.tc.core.DTXServiceExecutor.transactionRunning(DTXServiceExecutor.java:108)
at com.codingapi.txlcn.tc.aspect.weave.DTXLogicWeaver.runTransaction(DTXLogicWeaver.java:96)
at com.codingapi.txlcn.tc.aspect.TransactionAspect.transactionRunning(TransactionAspect.java:83)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:644)
at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:633)
at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:70)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:175)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:749)
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:95)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:749)
at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:691)
at com.zhirui.lmwy.warehouse.purchase_plan_order.service.impl.PurchasePlanOrderServiceImpl$$EnhancerBySpringCGLIB$$f9197350.startFlow()
at com.zhirui.lmwy.warehouse.purchase_plan_order.controller.PurchasePlanOrderController.flowStart(PurchasePlanOrderController.java:54)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:190)
at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:138)
at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:105)
at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:879)
at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:793)
at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87)
at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1040)
at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:943)
at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006)
at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:898)
```
debug查看到是卡在`mapper.updateById(order);`这里,在mysql执行`SELECT * FROM INFORMATION_SCHEMA.INNODB_TRX;`可以看到这个的update语句出现了lock wait。等大概20秒左右,lock wait消失,页面请求失败。后面页面每次请求都是这个死锁的情况。

### 调用方代码:
```java
@Transactional(rollbackFor = Exception.class)
@Override
@TxTransaction
public com.zhirui.core.model.result.ResultModel startFlow(String id) {
try {
Thread.sleep(10000);
} catch (Exception e) {
e.printStackTrace();
}
List list = listByAll(searchVO);
// 修改单据状态为审核中
PurchasePlanOrder order = new PurchasePlanOrder();
order.setId(id);
order.setApprovalStatus((short) 1);
mapper.updateById(order);
}
```
```java
@Override
@Transactional(propagation = Propagation.NOT_SUPPORTED)
public List listByAll(PurchasePlanOrderSearchVO searchVO) {
searchVO.setTenantId(UserHelper.getTenantId());
List list = mapper.listByAll(searchVO);
return list;
}
```
### 被调用方代码:
```java
@Override
@TxTransaction
@Transactional(rollbackFor = Exception.class)
public FlowInstanceDTO startProcess(Map map, String tenantId) throws Exception {
// 1.构造业务数据
// 获取当前用户
TUser user = UserHelper.getSecUser();
FlowInstance flowInstance = generateFlowInstance(map, user);

// 2.查询流程定义
ProcessDefinition processDefinition = repositoryService.createProcessDefinitionQuery()
.processDefinitionKey(flowInstance.getProcessKey())
.latestVersion().singleResult();
// 省略...
}
````

Contributor guide

No contributing guide indexed for this repository

Assessment

This issue has not been assessed yet.

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.