whitemeng commented on issue #588: 超時場景下 Failed to process grpc coordinate command URL: https://github.com/apache/servicecomb-pack/issues/588#issuecomment-552301181 > > > 你的cancel方法中sleep了10秒，但是你在 @Compensable 中声明了cancel方法5秒的调用超时 > > > > > > 對不起，我不太懂您的意思，能否再詳細說明一下，感謝 ! > > 我又看了一下，也不太敢确定，你可以提供一下你自己服务端更详细的错误日志吗 serviceA 程式碼  serviceB 程式碼  測試場景: serviceB 會因為超時而執行補償呼叫 cancel() serviceB 詳細 console log 如下 2019-11-11 13:29:52.861 DEBUG 9180 --- [nio-9001-exec-1] o.a.s.p.o.transaction.TransactionAspect : Updated context OmegaContext{globalTxId=80465bee-caf7-4083-b401-2d149b0d2010, localTxId=af4cbf20-6b08-40d5-83ec-127fc2bcca5b, alphaFeatureAkkaEnabled=false} for compensable method public java.util.List com.example.microserviceB.service.BasicService.getNames() 2019-11-11 13:29:52.867 DEBUG 9180 --- [nio-9001-exec-1] o.a.s.p.o.transaction.DefaultRecovery : Intercepting compensable method public java.util.List com.example.microserviceB.service.BasicService.getNames() with context OmegaContext{globalTxId=80465bee-caf7-4083-b401-2d149b0d2010, localTxId=af4cbf20-6b08-40d5-83ec-127fc2bcca5b, alphaFeatureAkkaEnabled=false} 2019-11-11 13:29:57.868 WARN 9180 --- [ probe] o.a.s.p.o.t.wrapper.TimeoutProb : Thread interrupted on 5001ms timeout (over 5000ms) 2019-11-11 13:29:57.878 ERROR 9180 --- [nio-9001-exec-1] o.a.s.p.o.c.g.c.LoadBalanceSenderAdapter : Retry sending event TxEndedEvent{globalTxId='80465bee-caf7-4083-b401-2d149b0d2010', localTxId='af4cbf20-6b08-40d5-83ec-127fc2bcca5b', parentTxId='80465bee-caf7-4083-b401-2d149b0d2010', compensationMethod='public java.util.List com.example.microserviceB.service.BasicService.cancel()', timeout=0, retryMethod='', retries=0, payloads=[]} due to failure io.grpc.StatusRuntimeException: CANCELLED: Call was interrupted at io.grpc.Status.asRuntimeException(Status.java:517) ~[grpc-core-1.14.0.jar:1.14.0] at io.grpc.stub.ClientCalls.blockingUnaryCall(ClientCalls.java:129) ~[grpc-stub-1.14.0.jar:1.14.0] at org.apache.servicecomb.pack.contract.grpc.TxEventServiceGrpc$TxEventServiceBlockingStub.onTxEvent(TxEventServiceGrpc.java:273) ~[pack-contract-grpc-0.5.0.jar:0.5.0] at org.apache.servicecomb.pack.omega.connector.grpc.saga.GrpcSagaClientMessageSender.send(GrpcSagaClientMessageSender.java:90) ~[omega-connector-grpc-0.5.0.jar:0.5.0] at org.apache.servicecomb.pack.omega.connector.grpc.saga.SagaLoadBalanceSender$1.apply(SagaLoadBalanceSender.java:45) ~[omega-connector-grpc-0.5.0.jar:0.5.0] at org.apache.servicecomb.pack.omega.connector.grpc.saga.SagaLoadBalanceSender$1.apply(SagaLoadBalanceSender.java:42) ~[omega-connector-grpc-0.5.0.jar:0.5.0] at org.apache.servicecomb.pack.omega.connector.grpc.core.LoadBalanceSenderAdapter.doGrpcSend(LoadBalanceSenderAdapter.java:54) ~[omega-connector-grpc-0.5.0.jar:0.5.0] at org.apache.servicecomb.pack.omega.connector.grpc.saga.SagaLoadBalanceSender.send(SagaLoadBalanceSender.java:42) ~[omega-connector-grpc-0.5.0.jar:0.5.0] at org.apache.servicecomb.pack.omega.transaction.CompensableInterceptor.postIntercept(CompensableInterceptor.java:40) ~[omega-transaction-0.5.0.jar:0.5.0] at org.apache.servicecomb.pack.omega.transaction.DefaultRecovery.applyTo(DefaultRecovery.java:70) ~[omega-transaction-0.5.0.jar:0.5.0] at org.apache.servicecomb.pack.omega.transaction.wrapper.RecoveryPolicyTimeoutWrapper.applyTo(RecoveryPolicyTimeoutWrapper.java:111) ~[omega-transaction-0.5.0.jar:0.5.0] at org.apache.servicecomb.pack.omega.transaction.AbstractRecoveryPolicy.apply(AbstractRecoveryPolicy.java:38) ~[omega-transaction-0.5.0.jar:0.5.0] at org.apache.servicecomb.pack.omega.transaction.TransactionAspect.advise(TransactionAspect.java:66) ~[omega-transaction-0.5.0.jar:0.5.0] at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:na] at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:na] at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:na] at java.base/java.lang.reflect.Method.invoke(Method.java:567) ~[na:na] at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:644) ~[spring-aop-5.1.10.RELEASE.jar:5.1.10.RELEASE] at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:633) ~[spring-aop-5.1.10.RELEASE.jar:5.1.10.RELEASE] at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:70) ~[spring-aop-5.1.10.RELEASE.jar:5.1.10.RELEASE] at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:175) ~[spring-aop-5.1.10.RELEASE.jar:5.1.10.RELEASE] at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:93) ~[spring-aop-5.1.10.RELEASE.jar:5.1.10.RELEASE] at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.1.10.RELEASE.jar:5.1.10.RELEASE] at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:689) ~[spring-aop-5.1.10.RELEASE.jar:5.1.10.RELEASE] at com.example.microserviceB.service.BasicService$$EnhancerBySpringCGLIB$$9924eaf.getNames(<generated>) ~[classes/:na] at com.example.microserviceB.controller.BasicController.names(BasicController.java:20) ~[classes/:na] at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:na] at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:na] at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:na] at java.base/java.lang.reflect.Method.invoke(Method.java:567) ~[na:na] at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:190) ~[spring-web-5.1.10.RELEASE.jar:5.1.10.RELEASE] at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:138) ~[spring-web-5.1.10.RELEASE.jar:5.1.10.RELEASE] at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:105) ~[spring-webmvc-5.1.10.RELEASE.jar:5.1.10.RELEASE] at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:893) ~[spring-webmvc-5.1.10.RELEASE.jar:5.1.10.RELEASE] at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:798) ~[spring-webmvc-5.1.10.RELEASE.jar:5.1.10.RELEASE] at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87) ~[spring-webmvc-5.1.10.RELEASE.jar:5.1.10.RELEASE] at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1040) ~[spring-webmvc-5.1.10.RELEASE.jar:5.1.10.RELEASE] at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:943) ~[spring-webmvc-5.1.10.RELEASE.jar:5.1.10.RELEASE] at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006) ~[spring-webmvc-5.1.10.RELEASE.jar:5.1.10.RELEASE] at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:898) ~[spring-webmvc-5.1.10.RELEASE.jar:5.1.10.RELEASE] at javax.servlet.http.HttpServlet.service(HttpServlet.java:634) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883) ~[spring-webmvc-5.1.10.RELEASE.jar:5.1.10.RELEASE] at javax.servlet.http.HttpServlet.service(HttpServlet.java:741) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53) ~[tomcat-embed-websocket-9.0.26.jar:9.0.26] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.springframework.boot.actuate.web.trace.servlet.HttpTraceFilter.doFilterInternal(HttpTraceFilter.java:88) ~[spring-boot-actuator-2.1.9.RELEASE.jar:2.1.9.RELEASE] at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) ~[spring-web-5.1.10.RELEASE.jar:5.1.10.RELEASE] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:100) ~[spring-web-5.1.10.RELEASE.jar:5.1.10.RELEASE] at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) ~[spring-web-5.1.10.RELEASE.jar:5.1.10.RELEASE] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.springframework.web.filter.FormContentFilter.doFilterInternal(FormContentFilter.java:93) ~[spring-web-5.1.10.RELEASE.jar:5.1.10.RELEASE] at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) ~[spring-web-5.1.10.RELEASE.jar:5.1.10.RELEASE] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.springframework.web.filter.HiddenHttpMethodFilter.doFilterInternal(HiddenHttpMethodFilter.java:94) ~[spring-web-5.1.10.RELEASE.jar:5.1.10.RELEASE] at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) ~[spring-web-5.1.10.RELEASE.jar:5.1.10.RELEASE] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.springframework.boot.actuate.metrics.web.servlet.WebMvcMetricsFilter.filterAndRecordMetrics(WebMvcMetricsFilter.java:114) ~[spring-boot-actuator-2.1.9.RELEASE.jar:2.1.9.RELEASE] at org.springframework.boot.actuate.metrics.web.servlet.WebMvcMetricsFilter.doFilterInternal(WebMvcMetricsFilter.java:104) ~[spring-boot-actuator-2.1.9.RELEASE.jar:2.1.9.RELEASE] at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) ~[spring-web-5.1.10.RELEASE.jar:5.1.10.RELEASE] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201) ~[spring-web-5.1.10.RELEASE.jar:5.1.10.RELEASE] at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) ~[spring-web-5.1.10.RELEASE.jar:5.1.10.RELEASE] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:202) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:526) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:139) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:408) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:860) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1589) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) ~[na:na] at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) ~[na:na] at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at java.base/java.lang.Thread.run(Thread.java:835) ~[na:na] Caused by: java.lang.InterruptedException: null at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2056) ~[na:na] at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2090) ~[na:na] at java.base/java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:433) ~[na:na] at io.grpc.stub.ClientCalls$ThreadlessExecutor.waitAndDrain(ClientCalls.java:629) ~[grpc-stub-1.14.0.jar:1.14.0] at io.grpc.stub.ClientCalls.blockingUnaryCall(ClientCalls.java:123) ~[grpc-stub-1.14.0.jar:1.14.0] ... 87 common frames omitted 2019-11-11 13:29:57.880 DEBUG 9180 --- [nio-9001-exec-1] o.a.s.p.o.transaction.TransactionAspect : Restored context back to OmegaContext{globalTxId=80465bee-caf7-4083-b401-2d149b0d2010, localTxId=80465bee-caf7-4083-b401-2d149b0d2010, alphaFeatureAkkaEnabled=false} 2019-11-11 13:29:57.892 ERROR 9180 --- [nio-9001-exec-1] o.a.c.c.C.[.[.[/].[dispatcherServlet] : Servlet.service() for servlet [dispatcherServlet] in context with path [] threw exception [Request processing failed; nested exception is org.apache.servicecomb.pack.omega.transaction.OmegaException: Failed to get reconnected sender] with root cause java.lang.InterruptedException: null at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireInterruptibly(AbstractQueuedSynchronizer.java:1261) ~[na:na] at java.base/java.util.concurrent.locks.ReentrantLock.lockInterruptibly(ReentrantLock.java:317) ~[na:na] at java.base/java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:453) ~[na:na] at org.apache.servicecomb.pack.omega.connector.grpc.core.GrpcOnErrorHandler$GrpcRetryContext$1.get(GrpcOnErrorHandler.java:71) ~[omega-connector-grpc-0.5.0.jar:0.5.0] at org.apache.servicecomb.pack.omega.connector.grpc.core.GrpcOnErrorHandler$GrpcRetryContext$1.get(GrpcOnErrorHandler.java:67) ~[omega-connector-grpc-0.5.0.jar:0.5.0] at org.apache.servicecomb.pack.omega.connector.grpc.core.FastestSender.pick(FastestSender.java:39) ~[omega-connector-grpc-0.5.0.jar:0.5.0] at org.apache.servicecomb.pack.omega.connector.grpc.core.LoadBalanceSenderAdapter.pickMessageSender(LoadBalanceSenderAdapter.java:46) ~[omega-connector-grpc-0.5.0.jar:0.5.0] at org.apache.servicecomb.pack.omega.connector.grpc.saga.SagaLoadBalanceSender.send(SagaLoadBalanceSender.java:41) ~[omega-connector-grpc-0.5.0.jar:0.5.0] at org.apache.servicecomb.pack.omega.transaction.CompensableInterceptor.onError(CompensableInterceptor.java:45) ~[omega-transaction-0.5.0.jar:0.5.0] at org.apache.servicecomb.pack.omega.transaction.DefaultRecovery.applyTo(DefaultRecovery.java:74) ~[omega-transaction-0.5.0.jar:0.5.0] at org.apache.servicecomb.pack.omega.transaction.wrapper.RecoveryPolicyTimeoutWrapper.applyTo(RecoveryPolicyTimeoutWrapper.java:111) ~[omega-transaction-0.5.0.jar:0.5.0] at org.apache.servicecomb.pack.omega.transaction.AbstractRecoveryPolicy.apply(AbstractRecoveryPolicy.java:38) ~[omega-transaction-0.5.0.jar:0.5.0] at org.apache.servicecomb.pack.omega.transaction.TransactionAspect.advise(TransactionAspect.java:66) ~[omega-transaction-0.5.0.jar:0.5.0] at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:na] at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:na] at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:na] at java.base/java.lang.reflect.Method.invoke(Method.java:567) ~[na:na] at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:644) ~[spring-aop-5.1.10.RELEASE.jar:5.1.10.RELEASE] at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:633) ~[spring-aop-5.1.10.RELEASE.jar:5.1.10.RELEASE] at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:70) ~[spring-aop-5.1.10.RELEASE.jar:5.1.10.RELEASE] at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:175) ~[spring-aop-5.1.10.RELEASE.jar:5.1.10.RELEASE] at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:93) ~[spring-aop-5.1.10.RELEASE.jar:5.1.10.RELEASE] at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.1.10.RELEASE.jar:5.1.10.RELEASE] at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:689) ~[spring-aop-5.1.10.RELEASE.jar:5.1.10.RELEASE] at com.example.microserviceB.service.BasicService$$EnhancerBySpringCGLIB$$9924eaf.getNames(<generated>) ~[classes/:na] at com.example.microserviceB.controller.BasicController.names(BasicController.java:20) ~[classes/:na] at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:na] at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:na] at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:na] at java.base/java.lang.reflect.Method.invoke(Method.java:567) ~[na:na] at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:190) ~[spring-web-5.1.10.RELEASE.jar:5.1.10.RELEASE] at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:138) ~[spring-web-5.1.10.RELEASE.jar:5.1.10.RELEASE] at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:105) ~[spring-webmvc-5.1.10.RELEASE.jar:5.1.10.RELEASE] at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:893) ~[spring-webmvc-5.1.10.RELEASE.jar:5.1.10.RELEASE] at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:798) ~[spring-webmvc-5.1.10.RELEASE.jar:5.1.10.RELEASE] at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87) ~[spring-webmvc-5.1.10.RELEASE.jar:5.1.10.RELEASE] at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1040) ~[spring-webmvc-5.1.10.RELEASE.jar:5.1.10.RELEASE] at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:943) ~[spring-webmvc-5.1.10.RELEASE.jar:5.1.10.RELEASE] at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006) ~[spring-webmvc-5.1.10.RELEASE.jar:5.1.10.RELEASE] at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:898) ~[spring-webmvc-5.1.10.RELEASE.jar:5.1.10.RELEASE] at javax.servlet.http.HttpServlet.service(HttpServlet.java:634) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883) ~[spring-webmvc-5.1.10.RELEASE.jar:5.1.10.RELEASE] at javax.servlet.http.HttpServlet.service(HttpServlet.java:741) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53) ~[tomcat-embed-websocket-9.0.26.jar:9.0.26] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.springframework.boot.actuate.web.trace.servlet.HttpTraceFilter.doFilterInternal(HttpTraceFilter.java:88) ~[spring-boot-actuator-2.1.9.RELEASE.jar:2.1.9.RELEASE] at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) ~[spring-web-5.1.10.RELEASE.jar:5.1.10.RELEASE] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:100) ~[spring-web-5.1.10.RELEASE.jar:5.1.10.RELEASE] at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) ~[spring-web-5.1.10.RELEASE.jar:5.1.10.RELEASE] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.springframework.web.filter.FormContentFilter.doFilterInternal(FormContentFilter.java:93) ~[spring-web-5.1.10.RELEASE.jar:5.1.10.RELEASE] at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) ~[spring-web-5.1.10.RELEASE.jar:5.1.10.RELEASE] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.springframework.web.filter.HiddenHttpMethodFilter.doFilterInternal(HiddenHttpMethodFilter.java:94) ~[spring-web-5.1.10.RELEASE.jar:5.1.10.RELEASE] at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) ~[spring-web-5.1.10.RELEASE.jar:5.1.10.RELEASE] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.springframework.boot.actuate.metrics.web.servlet.WebMvcMetricsFilter.filterAndRecordMetrics(WebMvcMetricsFilter.java:114) ~[spring-boot-actuator-2.1.9.RELEASE.jar:2.1.9.RELEASE] at org.springframework.boot.actuate.metrics.web.servlet.WebMvcMetricsFilter.doFilterInternal(WebMvcMetricsFilter.java:104) ~[spring-boot-actuator-2.1.9.RELEASE.jar:2.1.9.RELEASE] at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) ~[spring-web-5.1.10.RELEASE.jar:5.1.10.RELEASE] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201) ~[spring-web-5.1.10.RELEASE.jar:5.1.10.RELEASE] at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) ~[spring-web-5.1.10.RELEASE.jar:5.1.10.RELEASE] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:202) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:526) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:139) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:408) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:860) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1589) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) ~[na:na] at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) ~[na:na] at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) ~[tomcat-embed-core-9.0.26.jar:9.0.26] at java.base/java.lang.Thread.run(Thread.java:835) ~[na:na] 2019-11-11 13:29:58.251 INFO 9180 --- [ault-executor-2] s.p.o.c.g.s.GrpcCompensateStreamObserver : Received compensate command, global tx id: 80465bee-caf7-4083-b401-2d149b0d2010, local tx id: af4cbf20-6b08-40d5-83ec-127fc2bcca5b, compensation method: public java.util.List com.example.microserviceB.service.BasicService.cancel() 2019-11-11 13:29:58.254 INFO 9180 --- [ault-executor-2] c.e.microserviceB.service.BasicService : B BasicService cancel() 2019-11-11 13:29:58.255 INFO 9180 --- [ault-executor-2] o.a.s.p.omega.context.CallbackContext : Callback transaction with global tx id [80465bee-caf7-4083-b401-2d149b0d2010], local tx id [af4cbf20-6b08-40d5-83ec-127fc2bcca5b] 2019-11-11 13:30:06.256 ERROR 9180 --- [ault-executor-2] o.a.s.p.o.c.g.c.ReconnectStreamObserver : Failed to process grpc coordinate command. io.grpc.StatusRuntimeException: CANCELLED: Failed to read message. at io.grpc.Status.asRuntimeException(Status.java:526) ~[grpc-core-1.14.0.jar:1.14.0] at io.grpc.stub.ClientCalls$StreamObserverToCallListenerAdapter.onClose(ClientCalls.java:420) ~[grpc-stub-1.14.0.jar:1.14.0] at io.grpc.PartialForwardingClientCallListener.onClose(PartialForwardingClientCallListener.java:39) ~[grpc-core-1.14.0.jar:1.14.0] at io.grpc.ForwardingClientCallListener.onClose(ForwardingClientCallListener.java:23) ~[grpc-core-1.14.0.jar:1.14.0] at io.grpc.ForwardingClientCallListener$SimpleForwardingClientCallListener.onClose(ForwardingClientCallListener.java:40) ~[grpc-core-1.14.0.jar:1.14.0] at io.grpc.internal.CensusStatsModule$StatsClientInterceptor$1$1.onClose(CensusStatsModule.java:684) ~[grpc-core-1.14.0.jar:1.14.0] at io.grpc.PartialForwardingClientCallListener.onClose(PartialForwardingClientCallListener.java:39) ~[grpc-core-1.14.0.jar:1.14.0] at io.grpc.ForwardingClientCallListener.onClose(ForwardingClientCallListener.java:23) ~[grpc-core-1.14.0.jar:1.14.0] at io.grpc.ForwardingClientCallListener$SimpleForwardingClientCallListener.onClose(ForwardingClientCallListener.java:40) ~[grpc-core-1.14.0.jar:1.14.0] at io.grpc.internal.CensusTracingModule$TracingClientInterceptor$1$1.onClose(CensusTracingModule.java:403) ~[grpc-core-1.14.0.jar:1.14.0] at io.grpc.internal.ClientCallImpl.closeObserver(ClientCallImpl.java:459) ~[grpc-core-1.14.0.jar:1.14.0] at io.grpc.internal.ClientCallImpl.access$300(ClientCallImpl.java:63) ~[grpc-core-1.14.0.jar:1.14.0] at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl.close(ClientCallImpl.java:546) ~[grpc-core-1.14.0.jar:1.14.0] at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl.access$600(ClientCallImpl.java:467) ~[grpc-core-1.14.0.jar:1.14.0] at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl$1MessagesAvailable.runInContext(ClientCallImpl.java:531) ~[grpc-core-1.14.0.jar:1.14.0] at io.grpc.internal.ContextRunnable.run(ContextRunnable.java:37) ~[grpc-core-1.14.0.jar:1.14.0] at io.grpc.internal.SerializingExecutor.run(SerializingExecutor.java:123) ~[grpc-core-1.14.0.jar:1.14.0] at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) ~[na:na] at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) ~[na:na] at java.base/java.lang.Thread.run(Thread.java:835) ~[na:na] Caused by: org.apache.servicecomb.pack.omega.transaction.OmegaException: Failed to get reconnected sender, all alpha server is down. at org.apache.servicecomb.pack.omega.connector.grpc.core.GrpcOnErrorHandler$GrpcRetryContext$1.get(GrpcOnErrorHandler.java:73) ~[omega-connector-grpc-0.5.0.jar:0.5.0] at org.apache.servicecomb.pack.omega.connector.grpc.core.GrpcOnErrorHandler$GrpcRetryContext$1.get(GrpcOnErrorHandler.java:67) ~[omega-connector-grpc-0.5.0.jar:0.5.0] at org.apache.servicecomb.pack.omega.connector.grpc.core.FastestSender.pick(FastestSender.java:39) ~[omega-connector-grpc-0.5.0.jar:0.5.0] at org.apache.servicecomb.pack.omega.connector.grpc.core.LoadBalanceSenderAdapter.pickMessageSender(LoadBalanceSenderAdapter.java:46) ~[omega-connector-grpc-0.5.0.jar:0.5.0] at org.apache.servicecomb.pack.omega.connector.grpc.saga.SagaLoadBalanceSender.send(SagaLoadBalanceSender.java:41) ~[omega-connector-grpc-0.5.0.jar:0.5.0] at org.apache.servicecomb.pack.omega.transaction.CompensationMessageHandler.onReceive(CompensationMessageHandler.java:36) ~[omega-transaction-0.5.0.jar:0.5.0] at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:na] at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:na] at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:na] at java.base/java.lang.reflect.Method.invoke(Method.java:567) ~[na:na] at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:343) ~[spring-aop-5.1.10.RELEASE.jar:5.1.10.RELEASE] at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:205) ~[spring-aop-5.1.10.RELEASE.jar:5.1.10.RELEASE] at com.sun.proxy.$Proxy114.onReceive(Unknown Source) ~[na:na] at org.apache.servicecomb.pack.omega.connector.grpc.saga.GrpcCompensateStreamObserver.onNext(GrpcCompensateStreamObserver.java:52) ~[omega-connector-grpc-0.5.0.jar:0.5.0] at org.apache.servicecomb.pack.omega.connector.grpc.saga.GrpcCompensateStreamObserver.onNext(GrpcCompensateStreamObserver.java:31) ~[omega-connector-grpc-0.5.0.jar:0.5.0] at io.grpc.stub.ClientCalls$StreamObserverToCallListenerAdapter.onMessage(ClientCalls.java:407) ~[grpc-stub-1.14.0.jar:1.14.0] at io.grpc.ForwardingClientCallListener.onMessage(ForwardingClientCallListener.java:33) ~[grpc-core-1.14.0.jar:1.14.0] at io.grpc.ForwardingClientCallListener.onMessage(ForwardingClientCallListener.java:33) ~[grpc-core-1.14.0.jar:1.14.0] at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl$1MessagesAvailable.runInContext(ClientCallImpl.java:519) ~[grpc-core-1.14.0.jar:1.14.0] ... 5 common frames omitted 2019-11-11 13:30:06.259 INFO 9180 --- [pool-1-thread-1] .a.s.p.o.c.g.c.PushBackReconnectRunnable : Retry connecting to alpha at 192.168.205.14:8080 2019-11-11 13:30:06.271 ERROR 9180 --- [pool-1-thread-1] .a.s.p.o.c.g.c.PushBackReconnectRunnable : Failed to reconnect to alpha at 192.168.205.14:8080 io.grpc.StatusRuntimeException: UNKNOWN at io.grpc.stub.ClientCalls.toStatusRuntimeException(ClientCalls.java:222) ~[grpc-stub-1.14.0.jar:1.14.0] at io.grpc.stub.ClientCalls.getUnchecked(ClientCalls.java:203) ~[grpc-stub-1.14.0.jar:1.14.0] at io.grpc.stub.ClientCalls.blockingUnaryCall(ClientCalls.java:132) ~[grpc-stub-1.14.0.jar:1.14.0] at org.apache.servicecomb.pack.contract.grpc.TxEventServiceGrpc$TxEventServiceBlockingStub.onDisconnected(TxEventServiceGrpc.java:280) ~[pack-contract-grpc-0.5.0.jar:0.5.0] at org.apache.servicecomb.pack.omega.connector.grpc.saga.GrpcSagaClientMessageSender.onDisconnected(GrpcSagaClientMessageSender.java:75) ~[omega-connector-grpc-0.5.0.jar:0.5.0] at org.apache.servicecomb.pack.omega.connector.grpc.core.PushBackReconnectRunnable.run(PushBackReconnectRunnable.java:52) ~[omega-connector-grpc-0.5.0.jar:0.5.0] at org.apache.servicecomb.pack.omega.connector.grpc.core.PendingTaskRunner$1.run(PendingTaskRunner.java:44) ~[omega-connector-grpc-0.5.0.jar:0.5.0] at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) ~[na:na] at java.base/java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305) ~[na:na] at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305) ~[na:na] at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) ~[na:na] at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) ~[na:na] at java.base/java.lang.Thread.run(Thread.java:835) ~[na:na] 2019-11-11 13:30:09.272 INFO 9180 --- [pool-1-thread-1] .a.s.p.o.c.g.c.PushBackReconnectRunnable : Retry connecting to alpha at 192.168.205.14:8080 2019-11-11 13:30:09.279 INFO 9180 --- [pool-1-thread-1] .a.s.p.o.c.g.c.PushBackReconnectRunnable : Retry connecting to alpha at 192.168.205.14:8080 is successful alpha-server console log 如下 
---------------------------------------------------------------- This is an automated message from the Apache Git Service. To respond to the message, please log on to GitHub and use the URL above to go to the specific comment. For queries about this service, please contact Infrastructure at: [email protected] With regards, Apache Git Services
