Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Bug about @GlobalLock in memory mode #1647

Closed
1 task done
BeiKeJieDeLiuLangMao opened this issue Sep 12, 2019 · 3 comments
Closed
1 task done

Bug about @GlobalLock in memory mode #1647

BeiKeJieDeLiuLangMao opened this issue Sep 12, 2019 · 3 comments
Labels
type: bug Category issues or prs related to bug.

Comments

@BeiKeJieDeLiuLangMao
Copy link
Contributor

Ⅰ. Issue Description

Bug 1: When seata-server runs in memory mode, get global lock failure always happens(seata-server couldn't get the MemoryLocker because branchSession is null).

When i resolve first bug, the second shows up.

Bug 2: I change a sample project(springboot-dubbo-seata), and add a global lock test to it.
When global transaction running, global lock feature will lost retry mechanism, because retry mechanism located in SelectForUpdateExecutor, but it only put the pks in context, and these pks's useability will been checked only if do commit, however at this time, retry process already finished.

This is only a little issue, campare with what i will talk about next.

Bug 3: In description of Bug 2, we already know that global lock will check pks useability when do commit. Now consider follow situation:

  1. I wanna use select for update as a lock(with @GlobalLock)
    2.Another global transaction(GT) is runing too, and phase 1 just finished, but pks' lock is still holding by this global transaction in TC
  2. Now i try to execute select for update in a local transaction(LT), with @GlobalLock
  3. Because GT phase 1 finished, so i get the db's row lock, but because i need to do some jobs with holding this db's lock, so i amn't finish my LT immediately.
  4. Because LT isn't been committed, so seata will not check these pks' lock to TC,now in my view, there isn't concurrent global transaction using these pks' lock, then i do my jobs with holding db's row lock
  5. After i finish my jobs, and do LT commit, a lock conflict exception throwed, but i already finish my jobs

In my opinion, once i use @GlobalLock and select for update, my transaction is in READ_COMMITED level, but actually it isn't.

Ⅱ. Describe what happened

BUG1-TC:

2019-09-12 14:22:25.829 ERROR[ServerHandlerThread_4_500]io.seata.server.lock.AbstractLockManager.isLockable:118 -isLockable error, xid:null, resourceId:jdbc:mysql://localhost:3306/seata, lockKey:t_account:1
java.lang.IllegalArgumentException: branchSession can be null for memory/file locker.
	at io.seata.server.lock.LockerFactory.get(LockerFactory.java:96)
	at io.seata.server.lock.DefaultLockManager.getLocker(DefaultLockManager.java:144)
	at io.seata.server.lock.DefaultLockManager.getLocker(DefaultLockManager.java:134)
	at io.seata.server.lock.DefaultLockManager.isLockable(DefaultLockManager.java:116)
	at io.seata.server.coordinator.DefaultCore.lockQuery(DefaultCore.java:116)
	at io.seata.server.coordinator.DefaultCoordinator.doLockCheck(DefaultCoordinator.java:208)
	at io.seata.server.AbstractTCInboundHandler$6.execute(AbstractTCInboundHandler.java:196)
	at io.seata.server.AbstractTCInboundHandler$6.execute(AbstractTCInboundHandler.java:192)
	at io.seata.core.exception.AbstractExceptionHandler.exceptionHandleTemplate(AbstractExceptionHandler.java:117)
	at io.seata.server.AbstractTCInboundHandler.handle(AbstractTCInboundHandler.java:192)
	at io.seata.core.protocol.transaction.GlobalLockQueryRequest.handle(GlobalLockQueryRequest.java:35)
	at io.seata.server.coordinator.DefaultCoordinator.onRequest(DefaultCoordinator.java:478)
	at io.seata.core.rpc.DefaultServerMessageListenerImpl.onTrxMessage(DefaultServerMessageListenerImpl.java:87)
	at io.seata.core.rpc.netty.RpcServer.dispatch(RpcServer.java:266)
	at io.seata.core.rpc.netty.AbstractRpcRemoting$3.run(AbstractRpcRemoting.java:371)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.lang.Thread.run(Thread.java:745)

BUG1-RM or BUG2-RM log:

### Error committing transaction.  Cause: io.seata.rm.datasource.exec.LockConflictException
### Cause: io.seata.rm.datasource.exec.LockConflictException
; uncategorized SQLException; SQL state [null]; error code [0]; null; nested exception is io.seata.rm.datasource.exec.LockConflictException] with root cause

io.seata.rm.datasource.exec.LockConflictException: null
	at io.seata.rm.datasource.ConnectionProxy.checkLock(ConnectionProxy.java:108) ~[seata-all-0.8.0.jar:0.8.0]
	at io.seata.rm.datasource.ConnectionProxy.processLocalCommitWithGlobalLocks(ConnectionProxy.java:171) ~[seata-all-0.8.0.jar:0.8.0]
	at io.seata.rm.datasource.ConnectionProxy.commit(ConnectionProxy.java:163) ~[seata-all-0.8.0.jar:0.8.0]
	at org.apache.ibatis.transaction.jdbc.JdbcTransaction.commit(JdbcTransaction.java:72) ~[mybatis-3.4.6.jar:3.4.6]
	at org.apache.ibatis.executor.BaseExecutor.commit(BaseExecutor.java:244) ~[mybatis-3.4.6.jar:3.4.6]
	at org.apache.ibatis.executor.CachingExecutor.commit(CachingExecutor.java:119) ~[mybatis-3.4.6.jar:3.4.6]
	at org.apache.ibatis.session.defaults.DefaultSqlSession.commit(DefaultSqlSession.java:224) ~[mybatis-3.4.6.jar:3.4.6]
	at org.mybatis.spring.SqlSessionTemplate$SqlSessionInterceptor.invoke(SqlSessionTemplate.java:437) ~[mybatis-spring-1.3.2.jar:1.3.2]
	at com.sun.proxy.$Proxy85.update(Unknown Source) ~[na:na]
	at org.mybatis.spring.SqlSessionTemplate.update(SqlSessionTemplate.java:294) ~[mybatis-spring-1.3.2.jar:1.3.2]
	at org.apache.ibatis.binding.MapperMethod.execute(MapperMethod.java:63) ~[mybatis-3.4.6.jar:3.4.6]
	at org.apache.ibatis.binding.MapperProxy.invoke(MapperProxy.java:59) ~[mybatis-3.4.6.jar:3.4.6]
	at com.sun.proxy.$Proxy86.testGlobalLock(Unknown Source) ~[na:na]
	at io.seata.samples.integration.account.service.TAccountServiceImpl.testGlobalLock(TAccountServiceImpl.java:42) ~[classes/:na]
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_112]
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_112]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_112]
	at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_112]
	at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:343) ~[spring-aop-5.0.8.RELEASE.jar:5.0.8.RELEASE]
	at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:197) ~[spring-aop-5.0.8.RELEASE.jar:5.0.8.RELEASE]
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) ~[spring-aop-5.0.8.RELEASE.jar:5.0.8.RELEASE]
	at io.seata.spring.annotation.GlobalTransactionalInterceptor.lambda$handleGlobalLock$0(GlobalTransactionalInterceptor.java:87) ~[seata-all-0.8.0.jar:0.8.0]
	at io.seata.rm.GlobalLockTemplate.execute(GlobalLockTemplate.java:46) ~[seata-all-0.8.0.jar:0.8.0]
	at io.seata.spring.annotation.GlobalTransactionalInterceptor.handleGlobalLock(GlobalTransactionalInterceptor.java:85) ~[seata-all-0.8.0.jar:0.8.0]
	at io.seata.spring.annotation.GlobalTransactionalInterceptor.invoke(GlobalTransactionalInterceptor.java:78) ~[seata-all-0.8.0.jar:0.8.0]
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185) ~[spring-aop-5.0.8.RELEASE.jar:5.0.8.RELEASE]
	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212) ~[spring-aop-5.0.8.RELEASE.jar:5.0.8.RELEASE]
	at com.sun.proxy.$Proxy89.testGlobalLock(Unknown Source) ~[na:na]
	at io.seata.samples.integration.account.controller.TAccountController.testGlobalLock(TAccountController.java:43) ~[classes/:na]
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_112]
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_112]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_112]
	at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_112]
	at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:209) ~[spring-web-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:136) ~[spring-web-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:102) ~[spring-webmvc-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:891) ~[spring-webmvc-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:797) ~[spring-webmvc-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87) ~[spring-webmvc-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:991) ~[spring-webmvc-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:925) ~[spring-webmvc-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:981) ~[spring-webmvc-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:873) ~[spring-webmvc-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:635) ~[tomcat-embed-core-8.5.37.jar:8.5.37]
	at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:858) ~[spring-webmvc-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:742) ~[tomcat-embed-core-8.5.37.jar:8.5.37]
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231) ~[tomcat-embed-core-8.5.37.jar:8.5.37]
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-8.5.37.jar:8.5.37]
	at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52) ~[tomcat-embed-websocket-8.5.37.jar:8.5.37]
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-8.5.37.jar:8.5.37]
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-8.5.37.jar:8.5.37]
	at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:99) ~[spring-web-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) ~[spring-web-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-8.5.37.jar:8.5.37]
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-8.5.37.jar:8.5.37]
	at org.springframework.web.filter.HttpPutFormContentFilter.doFilterInternal(HttpPutFormContentFilter.java:109) ~[spring-web-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) ~[spring-web-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-8.5.37.jar:8.5.37]
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-8.5.37.jar:8.5.37]
	at org.springframework.web.filter.HiddenHttpMethodFilter.doFilterInternal(HiddenHttpMethodFilter.java:93) ~[spring-web-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) ~[spring-web-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-8.5.37.jar:8.5.37]
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-8.5.37.jar:8.5.37]
	at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:200) ~[spring-web-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) ~[spring-web-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-8.5.37.jar:8.5.37]
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-8.5.37.jar:8.5.37]
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:198) ~[tomcat-embed-core-8.5.37.jar:8.5.37]
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96) [tomcat-embed-core-8.5.37.jar:8.5.37]
	at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:493) [tomcat-embed-core-8.5.37.jar:8.5.37]
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:140) [tomcat-embed-core-8.5.37.jar:8.5.37]
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:81) [tomcat-embed-core-8.5.37.jar:8.5.37]
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:87) [tomcat-embed-core-8.5.37.jar:8.5.37]
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:342) [tomcat-embed-core-8.5.37.jar:8.5.37]
	at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:800) [tomcat-embed-core-8.5.37.jar:8.5.37]
	at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66) [tomcat-embed-core-8.5.37.jar:8.5.37]
	at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:806) [tomcat-embed-core-8.5.37.jar:8.5.37]
	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1498) [tomcat-embed-core-8.5.37.jar:8.5.37]
	at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) [tomcat-embed-core-8.5.37.jar:8.5.37]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [na:1.8.0_112]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [na:1.8.0_112]
	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) [tomcat-embed-core-8.5.37.jar:8.5.37]
	at java.lang.Thread.run(Thread.java:745) [na:1.8.0_112]

Bug3 log, pay attention to Hi, i got lock, i will do some thing with holding this lock.:

2019-09-12 14:27:15.817  INFO 56067 --- [nio-8102-exec-2] i.s.s.i.a.controller.TAccountController  : testGlobalLock
Hi, i got lock, i will do some thing with holding this lock.
2019-09-12 14:27:18.248  INFO 56067 --- [ing.beat.sender] com.alibaba.nacos.client.naming          : [BEAT] public sending beat to server: {"cluster":"DEFAULT","ip":"10.34.167.16","metadata":{},"port":8102,"scheduled":true,"serviceName":"DEFAULT_GROUP@@dubbo-account-example","weight":1.0}
2019-09-12 14:27:18.248  INFO 56067 --- [ing.beat.sender] com.alibaba.nacos.client.naming          : [BEAT] public sending beat to server: {"ip":"10.34.167.16","metadata":{"side":"provider","methods":"decreaseAccount","dubbo":"2.0.2","pid":"56067","interface":"io.seata.samples.integration.common.dubbo.AccountDubboService","version":"1.0.0","generic":"false","timeout":"3000","revision":"1.0.0","protocol":"dubbo","application":"dubbo-account-example","category":"providers","anyhost":"true","bean.name":"ServiceBean:io.seata.samples.integration.common.dubbo.AccountDubboService:1.0.0","timestamp":"1568269549968"},"port":20880,"scheduled":true,"serviceName":"DEFAULT_GROUP@@providers:io.seata.samples.integration.common.dubbo.AccountDubboService:1.0.0","weight":1.0}
2019-09-12 14:27:18.274 ERROR 56067 --- [nio-8102-exec-2] o.a.c.c.C.[.[.[/].[dispatcherServlet]    : Servlet.service() for servlet [dispatcherServlet] in context with path [] threw exception [Request processing failed; nested exception is org.springframework.transaction.TransactionSystemException: Could not commit JDBC transaction; nested exception is io.seata.rm.datasource.exec.LockConflictException] with root cause

io.seata.rm.datasource.exec.LockConflictException: null
	at io.seata.rm.datasource.ConnectionProxy.checkLock(ConnectionProxy.java:108) ~[seata-all-0.8.0.jar:0.8.0]

Ⅲ. Describe what you expected to happen

@GlobalLock could work in memory mode
@GlobalLock could work with retry mechanism
@GlobalLock could make select for update execute in READ_COMMITED level

Ⅳ. How to reproduce it (as minimally and precisely as possible)

  1. Would you mind merge my seata sample pr sample#235, then you could run my test case
  2. Run sample project(springboot-dubbo-seata) follow the readme guide
  3. take a break point in business service's last line
  4. quey account global lock test: curl -H "Content-Type:application/json" -X GET localhost:8102/account/test_global_lock
  5. you will find a exception in TC and account service, that is bug1
  6. after you resolve bug 1 do step 4 again, you will find bug3
  7. then you need to remove @transactional of io.seata.samples.integration.account.service.TAccountServiceImpl#testGlobalLock and do step 4 again, you will find bug2

Ⅴ. Anything else we need to know?

Bug1 due to #942, i have no idea why exception message is branchSession can be null for memory/file locker., if branch session can be null, why throw a exception?

In the previous version, check pks' lock to TC located in SelectForUpdateExecutor.
But it moved in #498, but this change seems like unnecesary:

改造SelectForUpdateExecutor,使其在GlobalLock状态时不马上向TC查询全局锁状态,而推后到Commit前跟DML构成的LockKey合并一起查询(本修改实际没有必要,当时写的时候以为有xid重入问题,但实际并没有,不过推后合并执行或许在低冲突下能一定层度上提高性能,本修改可以撤销去掉)

Ⅵ. Environment:

  • JDK version : 1.8
  • OS : MacOS
  • Others:
@fescar-robot fescar-robot added the type: bug Category issues or prs related to bug. label Sep 12, 2019
@fescar-robot
Copy link

Hi @BeiKeJieDeLiuLangMao, we detect non-English characters in the issue. This comment is an auto translation from @fescar-robot to help other users to understand this issue.
We encourage you to describe your issue in English which is more friendly to other users.

Bug about @GlobalLock in memory mode

Ⅰ. Issue Description

Bug 1: When seata-server runs in memory mode, get global lock failure always happens(seata-server couldn't get the MemoryLocker because branchSession is null).

When i resolve first bug, the second shows up.

Bug 2: I change a sample project(springboot-dubbo-seata), and add a global lock test to it.
When global transaction running, global lock feature will lost retry mechanism, because retry mechanism located in SelectForUpdateExecutor, but it only put the pks in context, and these pks's useability will been checked only if do commit, however at this time, retry process already finished.

This is only a little issue, campare with what i will talk about next.

Bug 3: In description of Bug 2, we already know that global lock will check pks useability when do commit. Now consider follow situation:

  1. I wanna use select for update as a lock(with @GlobalLock)
    2.Another global transaction(GT) is runing too, and phase 1 just finished, but pks' lock is still holding by this global transaction in TC
  2. Now i try to execute select for update in a local transaction(LT), with @GlobalLock
  3. Because GT phase 1 finished, so i get the db's row lock, but because i need to do some jobs with holding this db's lock, so i amn't finish my LT immediately.
  4. Because LT isn't been committed, so seata will not check these pks' lock to TC,now in my view, there isn't concurrent global transaction using these pks' lock, then i do my jobs with holding db's row lock
  5. After i finish my jobs, and do LT commit, a lock conflict exception throwed, but i already finish my jobs

In my opinion, once i use @GlobalLock and select for update, my transaction is in READ_COMMITED level, but actually it isn't.

Ⅱ. Describe what happened

BUG1-TC:

2019-09-12 14:22:25.829 ERROR[ServerHandlerThread_4_500]io.seata.server.lock.AbstractLockManager.isLockable:118 -isLockable error, xid:null, resourceId:jdbc:mysql://localhost:3306/seata, lockKey:t_account:1
java.lang.IllegalArgumentException: branchSession can be null for memory/file locker.
	at io.seata.server.lock.LockerFactory.get(LockerFactory.java:96)
	at io.seata.server.lock.DefaultLockManager.getLocker(DefaultLockManager.java:144)
	at io.seata.server.lock.DefaultLockManager.getLocker(DefaultLockManager.java:134)
	at io.seata.server.lock.DefaultLockManager.isLockable(DefaultLockManager.java:116)
	at io.seata.server.coordinator.DefaultCore.lockQuery(DefaultCore.java:116)
	at io.seata.server.coordinator.DefaultCoordinator.doLockCheck(DefaultCoordinator.java:208)
	at io.seata.server.AbstractTCInboundHandler$6.execute(AbstractTCInboundHandler.java:196)
	at io.seata.server.AbstractTCInboundHandler$6.execute(AbstractTCInboundHandler.java:192)
	at io.seata.core.exception.AbstractExceptionHandler.exceptionHandleTemplate(AbstractExceptionHandler.java:117)
	at io.seata.server.AbstractTCInboundHandler.handle(AbstractTCInboundHandler.java:192)
	at io.seata.core.protocol.transaction.GlobalLockQueryRequest.handle(GlobalLockQueryRequest.java:35)
	at io.seata.server.coordinator.DefaultCoordinator.onRequest(DefaultCoordinator.java:478)
	at io.seata.core.rpc.DefaultServerMessageListenerImpl.onTrxMessage(DefaultServerMessageListenerImpl.java:87)
	at io.seata.core.rpc.netty.RpcServer.dispatch(RpcServer.java:266)
	at io.seata.core.rpc.netty.AbstractRpcRemoting$3.run(AbstractRpcRemoting.java:371)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.lang.Thread.run(Thread.java:745)

BUG1-RM or BUG2-RM log:

### Error committing transaction.  Cause: io.seata.rm.datasource.exec.LockConflictException
### Cause: io.seata.rm.datasource.exec.LockConflictException
; uncategorized SQLException; SQL state [null]; error code [0]; null; nested exception is io.seata.rm.datasource.exec.LockConflictException] with root cause

io.seata.rm.datasource.exec.LockConflictException: null
	at io.seata.rm.datasource.ConnectionProxy.checkLock(ConnectionProxy.java:108) ~[seata-all-0.8.0.jar:0.8.0]
	at io.seata.rm.datasource.ConnectionProxy.processLocalCommitWithGlobalLocks(ConnectionProxy.java:171) ~[seata-all-0.8.0.jar:0.8.0]
	at io.seata.rm.datasource.ConnectionProxy.commit(ConnectionProxy.java:163) ~[seata-all-0.8.0.jar:0.8.0]
	at org.apache.ibatis.transaction.jdbc.JdbcTransaction.commit(JdbcTransaction.java:72) ~[mybatis-3.4.6.jar:3.4.6]
	at org.apache.ibatis.executor.BaseExecutor.commit(BaseExecutor.java:244) ~[mybatis-3.4.6.jar:3.4.6]
	at org.apache.ibatis.executor.CachingExecutor.commit(CachingExecutor.java:119) ~[mybatis-3.4.6.jar:3.4.6]
	at org.apache.ibatis.session.defaults.DefaultSqlSession.commit(DefaultSqlSession.java:224) ~[mybatis-3.4.6.jar:3.4.6]
	at org.mybatis.spring.SqlSessionTemplate$SqlSessionInterceptor.invoke(SqlSessionTemplate.java:437) ~[mybatis-spring-1.3.2.jar:1.3.2]
	at com.sun.proxy.$Proxy85.update(Unknown Source) ~[na:na]
	at org.mybatis.spring.SqlSessionTemplate.update(SqlSessionTemplate.java:294) ~[mybatis-spring-1.3.2.jar:1.3.2]
	at org.apache.ibatis.binding.MapperMethod.execute(MapperMethod.java:63) ~[mybatis-3.4.6.jar:3.4.6]
	at org.apache.ibatis.binding.MapperProxy.invoke(MapperProxy.java:59) ~[mybatis-3.4.6.jar:3.4.6]
	at com.sun.proxy.$Proxy86.testGlobalLock(Unknown Source) ~[na:na]
	at io.seata.samples.integration.account.service.TAccountServiceImpl.testGlobalLock(TAccountServiceImpl.java:42) ~[classes/:na]
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_112]
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_112]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_112]
	at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_112]
	at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:343) ~[spring-aop-5.0.8.RELEASE.jar:5.0.8.RELEASE]
	at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:197) ~[spring-aop-5.0.8.RELEASE.jar:5.0.8.RELEASE]
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) ~[spring-aop-5.0.8.RELEASE.jar:5.0.8.RELEASE]
	at io.seata.spring.annotation.GlobalTransactionalInterceptor.lambda$handleGlobalLock$0(GlobalTransactionalInterceptor.java:87) ~[seata-all-0.8.0.jar:0.8.0]
	at io.seata.rm.GlobalLockTemplate.execute(GlobalLockTemplate.java:46) ~[seata-all-0.8.0.jar:0.8.0]
	at io.seata.spring.annotation.GlobalTransactionalInterceptor.handleGlobalLock(GlobalTransactionalInterceptor.java:85) ~[seata-all-0.8.0.jar:0.8.0]
	at io.seata.spring.annotation.GlobalTransactionalInterceptor.invoke(GlobalTransactionalInterceptor.java:78) ~[seata-all-0.8.0.jar:0.8.0]
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185) ~[spring-aop-5.0.8.RELEASE.jar:5.0.8.RELEASE]
	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212) ~[spring-aop-5.0.8.RELEASE.jar:5.0.8.RELEASE]
	at com.sun.proxy.$Proxy89.testGlobalLock(Unknown Source) ~[na:na]
	at io.seata.samples.integration.account.controller.TAccountController.testGlobalLock(TAccountController.java:43) ~[classes/:na]
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_112]
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_112]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_112]
	at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_112]
	at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:209) ~[spring-web-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:136) ~[spring-web-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:102) ~[spring-webmvc-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:891) ~[spring-webmvc-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:797) ~[spring-webmvc-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87) ~[spring-webmvc-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:991) ~[spring-webmvc-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:925) ~[spring-webmvc-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:981) ~[spring-webmvc-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:873) ~[spring-webmvc-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:635) ~[tomcat-embed-core-8.5.37.jar:8.5.37]
	at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:858) ~[spring-webmvc-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:742) ~[tomcat-embed-core-8.5.37.jar:8.5.37]
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231) ~[tomcat-embed-core-8.5.37.jar:8.5.37]
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-8.5.37.jar:8.5.37]
	at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52) ~[tomcat-embed-websocket-8.5.37.jar:8.5.37]
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-8.5.37.jar:8.5.37]
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-8.5.37.jar:8.5.37]
	at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:99) ~[spring-web-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) ~[spring-web-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-8.5.37.jar:8.5.37]
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-8.5.37.jar:8.5.37]
	at org.springframework.web.filter.HttpPutFormContentFilter.doFilterInternal(HttpPutFormContentFilter.java:109) ~[spring-web-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) ~[spring-web-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-8.5.37.jar:8.5.37]
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-8.5.37.jar:8.5.37]
	at org.springframework.web.filter.HiddenHttpMethodFilter.doFilterInternal(HiddenHttpMethodFilter.java:93) ~[spring-web-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) ~[spring-web-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-8.5.37.jar:8.5.37]
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-8.5.37.jar:8.5.37]
	at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:200) ~[spring-web-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) ~[spring-web-5.0.12.RELEASE.jar:5.0.12.RELEASE]
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-8.5.37.jar:8.5.37]
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-8.5.37.jar:8.5.37]
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:198) ~[tomcat-embed-core-8.5.37.jar:8.5.37]
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96) [tomcat-embed-core-8.5.37.jar:8.5.37]
	at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:493) [tomcat-embed-core-8.5.37.jar:8.5.37]
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:140) [tomcat-embed-core-8.5.37.jar:8.5.37]
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:81) [tomcat-embed-core-8.5.37.jar:8.5.37]
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:87) [tomcat-embed-core-8.5.37.jar:8.5.37]
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:342) [tomcat-embed-core-8.5.37.jar:8.5.37]
	at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:800) [tomcat-embed-core-8.5.37.jar:8.5.37]
	at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66) [tomcat-embed-core-8.5.37.jar:8.5.37]
	at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:806) [tomcat-embed-core-8.5.37.jar:8.5.37]
	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1498) [tomcat-embed-core-8.5.37.jar:8.5.37]
	at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) [tomcat-embed-core-8.5.37.jar:8.5.37]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [na:1.8.0_112]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [na:1.8.0_112]
	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) [tomcat-embed-core-8.5.37.jar:8.5.37]
	at java.lang.Thread.run(Thread.java:745) [na:1.8.0_112]

Bug3 log, pay attention to Hi, i got lock, i will do some thing with holding this lock.:

2019-09-12 14:27:15.817  INFO 56067 --- [nio-8102-exec-2] i.s.s.i.a.controller.TAccountController  : testGlobalLock
Hi, i got lock, i will do some thing with holding this lock.
2019-09-12 14:27:18.248  INFO 56067 --- [ing.beat.sender] com.alibaba.nacos.client.naming          : [BEAT] public sending beat to server: {"cluster":"DEFAULT","ip":"10.34.167.16","metadata":{},"port":8102,"scheduled":true,"serviceName":"DEFAULT_GROUP@@dubbo-account-example","weight":1.0}
2019-09-12 14:27:18.248  INFO 56067 --- [ing.beat.sender] com.alibaba.nacos.client.naming          : [BEAT] public sending beat to server: {"ip":"10.34.167.16","metadata":{"side":"provider","methods":"decreaseAccount","dubbo":"2.0.2","pid":"56067","interface":"io.seata.samples.integration.common.dubbo.AccountDubboService","version":"1.0.0","generic":"false","timeout":"3000","revision":"1.0.0","protocol":"dubbo","application":"dubbo-account-example","category":"providers","anyhost":"true","bean.name":"ServiceBean:io.seata.samples.integration.common.dubbo.AccountDubboService:1.0.0","timestamp":"1568269549968"},"port":20880,"scheduled":true,"serviceName":"DEFAULT_GROUP@@providers:io.seata.samples.integration.common.dubbo.AccountDubboService:1.0.0","weight":1.0}
2019-09-12 14:27:18.274 ERROR 56067 --- [nio-8102-exec-2] o.a.c.c.C.[.[.[/].[dispatcherServlet]    : Servlet.service() for servlet [dispatcherServlet] in context with path [] threw exception [Request processing failed; nested exception is org.springframework.transaction.TransactionSystemException: Could not commit JDBC transaction; nested exception is io.seata.rm.datasource.exec.LockConflictException] with root cause

io.seata.rm.datasource.exec.LockConflictException: null
	at io.seata.rm.datasource.ConnectionProxy.checkLock(ConnectionProxy.java:108) ~[seata-all-0.8.0.jar:0.8.0]

Ⅲ. Describe what you expected to happen

@GlobalLock could work in memory mode
@GlobalLock could work with retry mechanism
@GlobalLock could make select for update execute in READ_COMMITED level

Ⅳ. How to reproduce it (as minimally and precisely as possible)

  1. Would you mind merge my seata sample pr sample#235, then you could run my test case
  2. Run sample project(springboot-dubbo-seata) follow the readme guide
  3. take a break point in business service's last line
  4. quey account global lock test: curl -H "Content-Type:application/json" -X GET localhost:8102/account/test_global_lock
  5. you will find a exception in TC and account service, that is bug1
  6. after you resolve bug 1 do step 4 again, you will find bug3
  7. then you need to remove @transactional of io.seata.samples.integration.account.service.TAccountServiceImpl#testGlobalLock and do step 4 again, you will find bug2

Ⅴ. Anything else we need to know?

Bug1 due to #942, i have no idea why exception message is branchSession can be null for memory/file locker., if branch session can be null, why throw a exception?

In the previous version, check pks' lock to TC located in SelectForUpdateExecutor.
But it moved in #498, but this change seems like unnecesary:

Transform SelectForUpdateExecutor so that it does not immediately query the global lock state to the TC in the GlobalLock state, and push it back to Commit before the Commit merges with the LockKey consisting of DML. (This modification is actually not necessary. At the time, it was written that there was a problem with xid reentrancy. , but the actual is not, but the post-push merge execution may improve performance in a certain level under low conflicts, this modification can be revoked)

Ⅵ. Environment:

  • JDK version : 1.8
  • OS : MacOS
  • Others:

@xingfudeshi
Copy link
Member

The message may be wrong,it should be "branchSession can't be null for memory/file";

@BeiKeJieDeLiuLangMao
Copy link
Contributor Author

@xingfudeshi
If branchSession is null, MemoryLock do throws NPE when acquireLock or releaseLock, but if only invoke isLockable, it's no business of branchSession.

@zjinlei zjinlei closed this as completed Jan 7, 2020
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
type: bug Category issues or prs related to bug.
Projects
None yet
Development

Successfully merging a pull request may close this issue.

4 participants