You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@servicecomb.apache.org by "Lei Zhang (Jira)" <ji...@apache.org> on 2020/06/16 13:51:00 UTC
[jira] [Updated] (SCB-2004) When the business service startup is
not completed, receiving a compensation request will cause gRPC and alpha
to reconnect
[ https://issues.apache.org/jira/browse/SCB-2004?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Lei Zhang updated SCB-2004:
---------------------------
Description:
h1. If the Alpha's compensation call is received during the business service startup process, compensation failure will occasionally occur
Because at startup, it will be connected to Alpha first, and then all compensation methods will be scanned and put to the class CallbackContext, If business service receives a compensation request before CallbackContext initialization, you will get NullPointerExceptionBecause at startup, it will be connected to Alpha first, and then all compensation methods will be scanned and put to the class CallbackContext, If business service receives a compensation request before CallbackContext initialization, you will get NullPointerException
```java
public void apply(String globalTxId, String localTxId, String parentTxId, String callbackMethod, Object... payloads) { CallbackContextInternal contextInternal = contexts.get(callbackMethod); <----- this is empty String oldGlobalTxId = omegaContext.globalTxId(); String oldLocalTxId = omegaContext.localTxId(); try { omegaContext.setGlobalTxId(globalTxId); omegaContext.setLocalTxId(localTxId); contextInternal.callbackMethod.invoke(contextInternal.target, payloads); if (omegaContext.getAlphaMetas().isAkkaEnabled())
{ sender.send( new TxCompensateAckSucceedEvent(omegaContext.globalTxId(), omegaContext.localTxId(), parentTxId, callbackMethod)); }
```
```20:06:03.549 [background-preinit] INFO org.hibernate.validator.internal.util.Version - HV000001: Hibernate Validator 6.0.17.Final2020-06-16 20:06:03.801 INFO 33012 — [ main] trationDelegate$BeanPostProcessorChecker : Bean 'org.springframework.cloud.autoconfigure.ConfigurationPropertiesRebinderAutoConfiguration' of type [org.springframework.cloud.autoconfigure.ConfigurationPropertiesRebinderAutoConfiguration$$EnhancerBySpringCGLIB$$23824f27] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
. ___ __ __ _ _ /_
_/ ___'_ __ _ _(_)_ _ ___ _ \ \ \ ( ( )___ | '_ | '_| | '_ \/ _` | \ \ \ \_
_/ ___)| |_)| | | | | || (_| | ) ) ) ) ' |____| .__|_| |_|_| |___, | / / / / =========|_|==============|___/=/_/_/_/ :: Spring Boot :: (v2.1.6.RELEASE)
2020-06-16 20:06:04.543 INFO 33012 — [ main] o.a.s.pack.demo.car.Application : No active profile set, falling back to default profiles: default2020-06-16 20:06:05.887 INFO 33012 — [ main] o.s.cloud.context.scope.GenericScope : BeanFactory id=0844c163-505d-340b-8e21-343d5198bae82020-06-16 20:06:06.024 INFO 33012 — [ main] trationDelegate$BeanPostProcessorChecker : Bean 'org.apache.servicecomb.pack.omega.transaction.spring.TransactionAspectConfig' of type [org.apache.servicecomb.pack.omega.transaction.spring.TransactionAspectConfig$$EnhancerBySpringCGLIB$$6fc18c0a] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)2020-06-16 20:06:06.186 INFO 33012 — [ main] trationDelegate$BeanPostProcessorChecker : Bean 'org.apache.servicecomb.pack.omega.spring.OmegaSpringConfig' of type [org.apache.servicecomb.pack.omega.spring.OmegaSpringConfig$$EnhancerBySpringCGLIB$$b6310c32] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)2020-06-16 20:06:06.217 INFO 33012 — [ main] trationDelegate$BeanPostProcessorChecker : Bean 'omegaUniqueIdGenerator' of type [org.apache.servicecomb.pack.omega.context.UniqueIdGenerator] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)2020-06-16 20:06:06.244 INFO 33012 — [ main] trationDelegate$BeanPostProcessorChecker : Bean 'alphaClusterAddress' of type [org.apache.servicecomb.pack.omega.connector.grpc.AlphaClusterDiscovery] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)2020-06-16 20:06:06.259 INFO 33012 — [ main] o.a.s.p.omega.spring.OmegaSpringConfig : Discovery alpha cluster address localhost:8080 from DEFAULT2020-06-16 20:06:06.269 INFO 33012 — [ main] trationDelegate$BeanPostProcessorChecker : Bean 'alphaClusterConfig' of type [org.apache.servicecomb.pack.omega.connector.grpc.AlphaClusterConfig] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)2020-06-16 20:06:06.286 INFO 33012 — [ main] trationDelegate$BeanPostProcessorChecker : Bean 'serviceConfig' of type [org.apache.servicecomb.pack.omega.context.ServiceConfig] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)2020-06-16 20:06:06.640 INFO 33012 — [ main] trationDelegate$BeanPostProcessorChecker : Bean 'sagaLoadContext' of type [org.apache.servicecomb.pack.omega.connector.grpc.core.LoadBalanceContext] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)2020-06-16 20:06:06.711 INFO 33012 — [ main] trationDelegate$BeanPostProcessorChecker : Bean 'sagaLoadBalanceSender' of type [org.apache.servicecomb.pack.omega.connector.grpc.saga.SagaLoadBalanceSender] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)2020-06-16 20:06:07.042 INFO 33012 — [ main] o.a.s.p.o.c.g.c.LoadBalanceSenderAdapter : Alpha configuration is \{AkkaEnabled=true}2020-06-16 20:06:07.045 INFO 33012 — [ main] trationDelegate$BeanPostProcessorChecker : Bean 'omegaContext' of type [org.apache.servicecomb.pack.omega.context.OmegaContext] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)2020-06-16 20:06:07.069 INFO 33012 — [ main] trationDelegate$BeanPostProcessorChecker : Bean 'compensationContext' of type [org.apache.servicecomb.pack.omega.transaction.CallbackContext] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)2020-06-16 20:06:07.085 INFO 33012 — [ main] trationDelegate$BeanPostProcessorChecker : Bean 'coordinateContext' of type [org.apache.servicecomb.pack.omega.transaction.CallbackContext] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)2020-06-16 20:06:07.098 INFO 33012 — [ main] trationDelegate$BeanPostProcessorChecker : Bean 'org.springframework.cloud.autoconfigure.ConfigurationPropertiesRebinderAutoConfiguration' of type [org.springframework.cloud.autoconfigure.ConfigurationPropertiesRebinderAutoConfiguration$$EnhancerBySpringCGLIB$$23824f27] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)2020-06-16 20:06:07.286 INFO 33012 — [ault-executor-1] s.p.o.c.g.s.GrpcCompensateStreamObserver : Received compensate command, global tx id: f8f70b2b-837a-4485-abc2-d99a399fd45f, local tx id: 85d01500-c512-440d-8447-b793a9ca0bec, compensation method: void org.apache.servicecomb.pack.demo.car.CarBookingService.cancel(org.apache.servicecomb.pack.demo.car.CarBooking)2020-06-16 20:06:37.400 ERROR 33012 — [ault-executor-1] 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:533) ~[grpc-api-1.22.0.jar:1.22.0] at io.grpc.stub.ClientCalls$StreamObserverToCallListenerAdapter.onClose(ClientCalls.java:442) [grpc-stub-1.22.0.jar:1.22.0] at io.grpc.PartialForwardingClientCallListener.onClose(PartialForwardingClientCallListener.java:39) [grpc-api-1.22.0.jar:1.22.0] at io.grpc.ForwardingClientCallListener.onClose(ForwardingClientCallListener.java:23) [grpc-api-1.22.0.jar:1.22.0] at io.grpc.ForwardingClientCallListener$SimpleForwardingClientCallListener.onClose(ForwardingClientCallListener.java:40) [grpc-api-1.22.0.jar:1.22.0] at io.grpc.internal.CensusStatsModule$StatsClientInterceptor$1$1.onClose(CensusStatsModule.java:700) [grpc-core-1.22.0.jar:1.22.0] at io.grpc.PartialForwardingClientCallListener.onClose(PartialForwardingClientCallListener.java:39) [grpc-api-1.22.0.jar:1.22.0] at io.grpc.ForwardingClientCallListener.onClose(ForwardingClientCallListener.java:23) [grpc-api-1.22.0.jar:1.22.0] at io.grpc.ForwardingClientCallListener$SimpleForwardingClientCallListener.onClose(ForwardingClientCallListener.java:40) [grpc-api-1.22.0.jar:1.22.0] at io.grpc.internal.CensusTracingModule$TracingClientInterceptor$1$1.onClose(CensusTracingModule.java:399) [grpc-core-1.22.0.jar:1.22.0] at io.grpc.internal.ClientCallImpl.closeObserver(ClientCallImpl.java:507) [grpc-core-1.22.0.jar:1.22.0] at io.grpc.internal.ClientCallImpl.access$300(ClientCallImpl.java:66) [grpc-core-1.22.0.jar:1.22.0] at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl.close(ClientCallImpl.java:627) [grpc-core-1.22.0.jar:1.22.0] at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl.access$700(ClientCallImpl.java:515) [grpc-core-1.22.0.jar:1.22.0] at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl$1MessagesAvailable.runInternal(ClientCallImpl.java:608) [grpc-core-1.22.0.jar:1.22.0] at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl$1MessagesAvailable.runInContext(ClientCallImpl.java:581) [grpc-core-1.22.0.jar:1.22.0] at io.grpc.internal.ContextRunnable.run(ContextRunnable.java:37) [grpc-core-1.22.0.jar:1.22.0] at io.grpc.internal.SerializingExecutor.run(SerializingExecutor.java:123) [grpc-core-1.22.0.jar:1.22.0] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_201] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_201] at java.lang.Thread.run(Thread.java:748) [na:1.8.0_201]Caused by: java.lang.NullPointerException: null at org.apache.servicecomb.pack.omega.transaction.CallbackContext$CallbackContextInternal.access$200(CallbackContext.java:80) ~[classes/:na] at org.apache.servicecomb.pack.omega.transaction.CallbackContext.apply(CallbackContext.java:53) ~[classes/:na] at org.apache.servicecomb.pack.omega.transaction.CompensationMessageHandler.onReceive(CompensationMessageHandler.java:33) ~[classes/:na] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_201] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_201] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_201] at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_201] at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:343) ~[spring-aop-5.1.8.RELEASE.jar:5.1.8.RELEASE] at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:205) ~[spring-aop-5.1.8.RELEASE.jar:5.1.8.RELEASE] at com.sun.proxy.$Proxy99.onReceive(Unknown Source) ~[na:na] at org.apache.servicecomb.pack.omega.connector.grpc.saga.GrpcCompensateStreamObserver.onNext(GrpcCompensateStreamObserver.java:52) ~[classes/:na] at org.apache.servicecomb.pack.omega.connector.grpc.saga.GrpcCompensateStreamObserver.onNext(GrpcCompensateStreamObserver.java:31) ~[classes/:na] at io.grpc.stub.ClientCalls$StreamObserverToCallListenerAdapter.onMessage(ClientCalls.java:429) [grpc-stub-1.22.0.jar:1.22.0] at io.grpc.ForwardingClientCallListener.onMessage(ForwardingClientCallListener.java:33) [grpc-api-1.22.0.jar:1.22.0] at io.grpc.ForwardingClientCallListener.onMessage(ForwardingClientCallListener.java:33) [grpc-api-1.22.0.jar:1.22.0] at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl$1MessagesAvailable.runInternal(ClientCallImpl.java:596) [grpc-core-1.22.0.jar:1.22.0] ... 6 common frames omitted
2020-06-16 20:06:37.402 INFO 33012 — [pool-2-thread-1] .a.s.p.o.c.g.c.PushBackReconnectRunnable : Retry connecting to alpha at localhost:80802020-06-16 20:06:37.409 ERROR 33012 — [pool-2-thread-1] .a.s.p.o.c.g.c.PushBackReconnectRunnable : Failed to reconnect to alpha at localhost:8080
io.grpc.StatusRuntimeException: UNKNOWN at io.grpc.stub.ClientCalls.toStatusRuntimeException(ClientCalls.java:235) ~[grpc-stub-1.22.0.jar:1.22.0] at io.grpc.stub.ClientCalls.getUnchecked(ClientCalls.java:216) ~[grpc-stub-1.22.0.jar:1.22.0] at io.grpc.stub.ClientCalls.blockingUnaryCall(ClientCalls.java:141) ~[grpc-stub-1.22.0.jar:1.22.0] at org.apache.servicecomb.pack.contract.grpc.TxEventServiceGrpc$TxEventServiceBlockingStub.onDisconnected(TxEventServiceGrpc.java:326) ~[classes/:na] at org.apache.servicecomb.pack.omega.connector.grpc.saga.GrpcSagaClientMessageSender.onDisconnected(GrpcSagaClientMessageSender.java:77) ~[classes/:na] at org.apache.servicecomb.pack.omega.connector.grpc.core.PushBackReconnectRunnable.run(PushBackReconnectRunnable.java:52) ~[classes/:na] at org.apache.servicecomb.pack.omega.connector.grpc.core.PendingTaskRunner$1.run(PendingTaskRunner.java:44) [classes/:na] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [na:1.8.0_201] at java.util.concurrent.FutureTask.runAndReset$$$capture(FutureTask.java:308) [na:1.8.0_201] at java.util.concurrent.FutureTask.runAndReset(FutureTask.java) [na:1.8.0_201] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [na:1.8.0_201] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [na:1.8.0_201] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_201] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_201] at java.lang.Thread.run(Thread.java:748) [na:1.8.0_201]
2020-06-16 20:06:37.453 INFO 33012 — [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat initialized with port(s): 9001 (http)2020-06-16 20:06:37.475 INFO 33012 — [ main] o.apache.catalina.core.StandardService : Starting service [Tomcat]2020-06-16 20:06:37.475 INFO 33012 — [ main] org.apache.catalina.core.StandardEngine : Starting Servlet engine: [Apache Tomcat/9.0.21]2020-06-16 20:06:37.654 INFO 33012 — [ main] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring embedded WebApplicationContext2020-06-16 20:06:37.654 INFO 33012 — [ main] o.s.web.context.ContextLoader : Root WebApplicationContext: initialization completed in 33096 ms2020-06-16 20:06:38.049 WARN 33012 — [ main] c.n.c.sources.URLConfigurationSource : No URLs will be polled as dynamic configuration sources.2020-06-16 20:06:38.049 INFO 33012 — [ main] c.n.c.sources.URLConfigurationSource : To enable URLs as dynamic configuration sources, define System property archaius.configurationSource.additionalUrls or make config.properties available on classpath.2020-06-16 20:06:38.059 INFO 33012 — [ main] c.netflix.config.DynamicPropertyFactory : DynamicPropertyFactory is initialized with configuration sources: com.netflix.config.ConcurrentCompositeConfiguration@42066f0d2020-06-16 20:06:41.654 INFO 33012 — [pool-2-thread-1] .a.s.p.o.c.g.c.PushBackReconnectRunnable : Retry connecting to alpha at localhost:80802020-06-16 20:06:41.662 INFO 33012 — [pool-2-thread-1] .a.s.p.o.c.g.c.PushBackReconnectRunnable : Retry connecting to alpha at localhost:8080 is successful2020-06-16 20:06:41.681 WARN 33012 — [ main] c.n.c.sources.URLConfigurationSource : No URLs will be polled as dynamic configuration sources.2020-06-16 20:06:41.681 INFO 33012 — [ main] c.n.c.sources.URLConfigurationSource : To enable URLs as dynamic configuration sources, define System property archaius.configurationSource.additionalUrls or make config.properties available on classpath.2020-06-16 20:06:43.305 INFO 33012 — [ main] o.s.s.concurrent.ThreadPoolTaskExecutor : Initializing ExecutorService 'applicationTaskExecutor'2020-06-16 20:06:45.272 WARN 33012 — [ main] o.s.c.n.core.CoreAutoConfiguration : This module is deprecated. It will be removed in the next major release. Please use spring-cloud-netflix-hystrix instead.2020-06-16 20:06:45.363 INFO 33012 — [ main] o.s.b.a.e.web.EndpointLinksResolver : Exposing 2 endpoint(s) beneath base path '/actuator'2020-06-16 20:06:45.583 INFO 33012 — [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat started on port(s): 9001 (http) with context path ''2020-06-16 20:06:45.586 INFO 33012 — [ main] o.a.s.pack.demo.car.Application : Started Application in 42.974 seconds (JVM running for 43.721)2020-06-16 20:06:45.731 INFO 33012 — [on(1)-127.0.0.1] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring DispatcherServlet 'dispatcherServlet'2020-06-16 20:06:45.731 INFO 33012 — [on(1)-127.0.0.1] o.s.web.servlet.DispatcherServlet : Initializing Servlet 'dispatcherServlet'2020-06-16 20:06:45.776 INFO 33012 — [on(1)-127.0.0.1] o.s.web.servlet.DispatcherServlet : Completed initialization in 45 ms```
was:
h1. If the Alpha's compensation call is received during the business service startup process, compensation failure will occasionally occur
Because at startup, it will be connected to Alpha first, and then all compensation methods will be scanned and put to the class CallbackContext, If business service receives a compensation request before CallbackContext initialization, you will get NullPointerExceptionBecause at startup, it will be connected to Alpha first, and then all compensation methods will be scanned and put to the class CallbackContext, If business service receives a compensation request before CallbackContext initialization, you will get NullPointerException
```java public void apply(String globalTxId, String localTxId, String parentTxId, String callbackMethod, Object... payloads) \{ CallbackContextInternal contextInternal = contexts.get(callbackMethod); <----- this is empty String oldGlobalTxId = omegaContext.globalTxId(); String oldLocalTxId = omegaContext.localTxId(); try { omegaContext.setGlobalTxId(globalTxId); omegaContext.setLocalTxId(localTxId); contextInternal.callbackMethod.invoke(contextInternal.target, payloads); if (omegaContext.getAlphaMetas().isAkkaEnabled()) { sender.send( new TxCompensateAckSucceedEvent(omegaContext.globalTxId(), omegaContext.localTxId(), parentTxId, callbackMethod)); }```
```20:06:03.549 [background-preinit] INFO org.hibernate.validator.internal.util.Version - HV000001: Hibernate Validator 6.0.17.Final2020-06-16 20:06:03.801 INFO 33012 --- [ main] trationDelegate$BeanPostProcessorChecker : Bean 'org.springframework.cloud.autoconfigure.ConfigurationPropertiesRebinderAutoConfiguration' of type [org.springframework.cloud.autoconfigure.ConfigurationPropertiesRebinderAutoConfiguration$$EnhancerBySpringCGLIB$$23824f27] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
. ____ _ __ _ _ /\\ / ___'_ __ _ _(_)_ __ __ _ \ \ \ \( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \ \\/ ___)| |_)| | | | | || (_| | ) ) ) ) ' |____| .__|_| |_|_| |_\__, | / / / / =========|_|==============|___/=/_/_/_/ :: Spring Boot :: (v2.1.6.RELEASE)
2020-06-16 20:06:04.543 INFO 33012 --- [ main] o.a.s.pack.demo.car.Application : No active profile set, falling back to default profiles: default2020-06-16 20:06:05.887 INFO 33012 --- [ main] o.s.cloud.context.scope.GenericScope : BeanFactory id=0844c163-505d-340b-8e21-343d5198bae82020-06-16 20:06:06.024 INFO 33012 --- [ main] trationDelegate$BeanPostProcessorChecker : Bean 'org.apache.servicecomb.pack.omega.transaction.spring.TransactionAspectConfig' of type [org.apache.servicecomb.pack.omega.transaction.spring.TransactionAspectConfig$$EnhancerBySpringCGLIB$$6fc18c0a] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)2020-06-16 20:06:06.186 INFO 33012 --- [ main] trationDelegate$BeanPostProcessorChecker : Bean 'org.apache.servicecomb.pack.omega.spring.OmegaSpringConfig' of type [org.apache.servicecomb.pack.omega.spring.OmegaSpringConfig$$EnhancerBySpringCGLIB$$b6310c32] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)2020-06-16 20:06:06.217 INFO 33012 --- [ main] trationDelegate$BeanPostProcessorChecker : Bean 'omegaUniqueIdGenerator' of type [org.apache.servicecomb.pack.omega.context.UniqueIdGenerator] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)2020-06-16 20:06:06.244 INFO 33012 --- [ main] trationDelegate$BeanPostProcessorChecker : Bean 'alphaClusterAddress' of type [org.apache.servicecomb.pack.omega.connector.grpc.AlphaClusterDiscovery] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)2020-06-16 20:06:06.259 INFO 33012 --- [ main] o.a.s.p.omega.spring.OmegaSpringConfig : Discovery alpha cluster address localhost:8080 from DEFAULT2020-06-16 20:06:06.269 INFO 33012 --- [ main] trationDelegate$BeanPostProcessorChecker : Bean 'alphaClusterConfig' of type [org.apache.servicecomb.pack.omega.connector.grpc.AlphaClusterConfig] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)2020-06-16 20:06:06.286 INFO 33012 --- [ main] trationDelegate$BeanPostProcessorChecker : Bean 'serviceConfig' of type [org.apache.servicecomb.pack.omega.context.ServiceConfig] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)2020-06-16 20:06:06.640 INFO 33012 --- [ main] trationDelegate$BeanPostProcessorChecker : Bean 'sagaLoadContext' of type [org.apache.servicecomb.pack.omega.connector.grpc.core.LoadBalanceContext] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)2020-06-16 20:06:06.711 INFO 33012 --- [ main] trationDelegate$BeanPostProcessorChecker : Bean 'sagaLoadBalanceSender' of type [org.apache.servicecomb.pack.omega.connector.grpc.saga.SagaLoadBalanceSender] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)2020-06-16 20:06:07.042 INFO 33012 --- [ main] o.a.s.p.o.c.g.c.LoadBalanceSenderAdapter : Alpha configuration is \{AkkaEnabled=true}2020-06-16 20:06:07.045 INFO 33012 --- [ main] trationDelegate$BeanPostProcessorChecker : Bean 'omegaContext' of type [org.apache.servicecomb.pack.omega.context.OmegaContext] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)2020-06-16 20:06:07.069 INFO 33012 --- [ main] trationDelegate$BeanPostProcessorChecker : Bean 'compensationContext' of type [org.apache.servicecomb.pack.omega.transaction.CallbackContext] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)2020-06-16 20:06:07.085 INFO 33012 --- [ main] trationDelegate$BeanPostProcessorChecker : Bean 'coordinateContext' of type [org.apache.servicecomb.pack.omega.transaction.CallbackContext] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)2020-06-16 20:06:07.098 INFO 33012 --- [ main] trationDelegate$BeanPostProcessorChecker : Bean 'org.springframework.cloud.autoconfigure.ConfigurationPropertiesRebinderAutoConfiguration' of type [org.springframework.cloud.autoconfigure.ConfigurationPropertiesRebinderAutoConfiguration$$EnhancerBySpringCGLIB$$23824f27] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)2020-06-16 20:06:07.286 INFO 33012 --- [ault-executor-1] s.p.o.c.g.s.GrpcCompensateStreamObserver : Received compensate command, global tx id: f8f70b2b-837a-4485-abc2-d99a399fd45f, local tx id: 85d01500-c512-440d-8447-b793a9ca0bec, compensation method: void org.apache.servicecomb.pack.demo.car.CarBookingService.cancel(org.apache.servicecomb.pack.demo.car.CarBooking)2020-06-16 20:06:37.400 ERROR 33012 --- [ault-executor-1] 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:533) ~[grpc-api-1.22.0.jar:1.22.0] at io.grpc.stub.ClientCalls$StreamObserverToCallListenerAdapter.onClose(ClientCalls.java:442) [grpc-stub-1.22.0.jar:1.22.0] at io.grpc.PartialForwardingClientCallListener.onClose(PartialForwardingClientCallListener.java:39) [grpc-api-1.22.0.jar:1.22.0] at io.grpc.ForwardingClientCallListener.onClose(ForwardingClientCallListener.java:23) [grpc-api-1.22.0.jar:1.22.0] at io.grpc.ForwardingClientCallListener$SimpleForwardingClientCallListener.onClose(ForwardingClientCallListener.java:40) [grpc-api-1.22.0.jar:1.22.0] at io.grpc.internal.CensusStatsModule$StatsClientInterceptor$1$1.onClose(CensusStatsModule.java:700) [grpc-core-1.22.0.jar:1.22.0] at io.grpc.PartialForwardingClientCallListener.onClose(PartialForwardingClientCallListener.java:39) [grpc-api-1.22.0.jar:1.22.0] at io.grpc.ForwardingClientCallListener.onClose(ForwardingClientCallListener.java:23) [grpc-api-1.22.0.jar:1.22.0] at io.grpc.ForwardingClientCallListener$SimpleForwardingClientCallListener.onClose(ForwardingClientCallListener.java:40) [grpc-api-1.22.0.jar:1.22.0] at io.grpc.internal.CensusTracingModule$TracingClientInterceptor$1$1.onClose(CensusTracingModule.java:399) [grpc-core-1.22.0.jar:1.22.0] at io.grpc.internal.ClientCallImpl.closeObserver(ClientCallImpl.java:507) [grpc-core-1.22.0.jar:1.22.0] at io.grpc.internal.ClientCallImpl.access$300(ClientCallImpl.java:66) [grpc-core-1.22.0.jar:1.22.0] at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl.close(ClientCallImpl.java:627) [grpc-core-1.22.0.jar:1.22.0] at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl.access$700(ClientCallImpl.java:515) [grpc-core-1.22.0.jar:1.22.0] at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl$1MessagesAvailable.runInternal(ClientCallImpl.java:608) [grpc-core-1.22.0.jar:1.22.0] at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl$1MessagesAvailable.runInContext(ClientCallImpl.java:581) [grpc-core-1.22.0.jar:1.22.0] at io.grpc.internal.ContextRunnable.run(ContextRunnable.java:37) [grpc-core-1.22.0.jar:1.22.0] at io.grpc.internal.SerializingExecutor.run(SerializingExecutor.java:123) [grpc-core-1.22.0.jar:1.22.0] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_201] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_201] at java.lang.Thread.run(Thread.java:748) [na:1.8.0_201]Caused by: java.lang.NullPointerException: null at org.apache.servicecomb.pack.omega.transaction.CallbackContext$CallbackContextInternal.access$200(CallbackContext.java:80) ~[classes/:na] at org.apache.servicecomb.pack.omega.transaction.CallbackContext.apply(CallbackContext.java:53) ~[classes/:na] at org.apache.servicecomb.pack.omega.transaction.CompensationMessageHandler.onReceive(CompensationMessageHandler.java:33) ~[classes/:na] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_201] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_201] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_201] at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_201] at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:343) ~[spring-aop-5.1.8.RELEASE.jar:5.1.8.RELEASE] at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:205) ~[spring-aop-5.1.8.RELEASE.jar:5.1.8.RELEASE] at com.sun.proxy.$Proxy99.onReceive(Unknown Source) ~[na:na] at org.apache.servicecomb.pack.omega.connector.grpc.saga.GrpcCompensateStreamObserver.onNext(GrpcCompensateStreamObserver.java:52) ~[classes/:na] at org.apache.servicecomb.pack.omega.connector.grpc.saga.GrpcCompensateStreamObserver.onNext(GrpcCompensateStreamObserver.java:31) ~[classes/:na] at io.grpc.stub.ClientCalls$StreamObserverToCallListenerAdapter.onMessage(ClientCalls.java:429) [grpc-stub-1.22.0.jar:1.22.0] at io.grpc.ForwardingClientCallListener.onMessage(ForwardingClientCallListener.java:33) [grpc-api-1.22.0.jar:1.22.0] at io.grpc.ForwardingClientCallListener.onMessage(ForwardingClientCallListener.java:33) [grpc-api-1.22.0.jar:1.22.0] at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl$1MessagesAvailable.runInternal(ClientCallImpl.java:596) [grpc-core-1.22.0.jar:1.22.0] ... 6 common frames omitted
2020-06-16 20:06:37.402 INFO 33012 --- [pool-2-thread-1] .a.s.p.o.c.g.c.PushBackReconnectRunnable : Retry connecting to alpha at localhost:80802020-06-16 20:06:37.409 ERROR 33012 --- [pool-2-thread-1] .a.s.p.o.c.g.c.PushBackReconnectRunnable : Failed to reconnect to alpha at localhost:8080
io.grpc.StatusRuntimeException: UNKNOWN at io.grpc.stub.ClientCalls.toStatusRuntimeException(ClientCalls.java:235) ~[grpc-stub-1.22.0.jar:1.22.0] at io.grpc.stub.ClientCalls.getUnchecked(ClientCalls.java:216) ~[grpc-stub-1.22.0.jar:1.22.0] at io.grpc.stub.ClientCalls.blockingUnaryCall(ClientCalls.java:141) ~[grpc-stub-1.22.0.jar:1.22.0] at org.apache.servicecomb.pack.contract.grpc.TxEventServiceGrpc$TxEventServiceBlockingStub.onDisconnected(TxEventServiceGrpc.java:326) ~[classes/:na] at org.apache.servicecomb.pack.omega.connector.grpc.saga.GrpcSagaClientMessageSender.onDisconnected(GrpcSagaClientMessageSender.java:77) ~[classes/:na] at org.apache.servicecomb.pack.omega.connector.grpc.core.PushBackReconnectRunnable.run(PushBackReconnectRunnable.java:52) ~[classes/:na] at org.apache.servicecomb.pack.omega.connector.grpc.core.PendingTaskRunner$1.run(PendingTaskRunner.java:44) [classes/:na] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [na:1.8.0_201] at java.util.concurrent.FutureTask.runAndReset$$$capture(FutureTask.java:308) [na:1.8.0_201] at java.util.concurrent.FutureTask.runAndReset(FutureTask.java) [na:1.8.0_201] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [na:1.8.0_201] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [na:1.8.0_201] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_201] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_201] at java.lang.Thread.run(Thread.java:748) [na:1.8.0_201]
2020-06-16 20:06:37.453 INFO 33012 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat initialized with port(s): 9001 (http)2020-06-16 20:06:37.475 INFO 33012 --- [ main] o.apache.catalina.core.StandardService : Starting service [Tomcat]2020-06-16 20:06:37.475 INFO 33012 --- [ main] org.apache.catalina.core.StandardEngine : Starting Servlet engine: [Apache Tomcat/9.0.21]2020-06-16 20:06:37.654 INFO 33012 --- [ main] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring embedded WebApplicationContext2020-06-16 20:06:37.654 INFO 33012 --- [ main] o.s.web.context.ContextLoader : Root WebApplicationContext: initialization completed in 33096 ms2020-06-16 20:06:38.049 WARN 33012 --- [ main] c.n.c.sources.URLConfigurationSource : No URLs will be polled as dynamic configuration sources.2020-06-16 20:06:38.049 INFO 33012 --- [ main] c.n.c.sources.URLConfigurationSource : To enable URLs as dynamic configuration sources, define System property archaius.configurationSource.additionalUrls or make config.properties available on classpath.2020-06-16 20:06:38.059 INFO 33012 --- [ main] c.netflix.config.DynamicPropertyFactory : DynamicPropertyFactory is initialized with configuration sources: com.netflix.config.ConcurrentCompositeConfiguration@42066f0d2020-06-16 20:06:41.654 INFO 33012 --- [pool-2-thread-1] .a.s.p.o.c.g.c.PushBackReconnectRunnable : Retry connecting to alpha at localhost:80802020-06-16 20:06:41.662 INFO 33012 --- [pool-2-thread-1] .a.s.p.o.c.g.c.PushBackReconnectRunnable : Retry connecting to alpha at localhost:8080 is successful2020-06-16 20:06:41.681 WARN 33012 --- [ main] c.n.c.sources.URLConfigurationSource : No URLs will be polled as dynamic configuration sources.2020-06-16 20:06:41.681 INFO 33012 --- [ main] c.n.c.sources.URLConfigurationSource : To enable URLs as dynamic configuration sources, define System property archaius.configurationSource.additionalUrls or make config.properties available on classpath.2020-06-16 20:06:43.305 INFO 33012 --- [ main] o.s.s.concurrent.ThreadPoolTaskExecutor : Initializing ExecutorService 'applicationTaskExecutor'2020-06-16 20:06:45.272 WARN 33012 --- [ main] o.s.c.n.core.CoreAutoConfiguration : This module is deprecated. It will be removed in the next major release. Please use spring-cloud-netflix-hystrix instead.2020-06-16 20:06:45.363 INFO 33012 --- [ main] o.s.b.a.e.web.EndpointLinksResolver : Exposing 2 endpoint(s) beneath base path '/actuator'2020-06-16 20:06:45.583 INFO 33012 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat started on port(s): 9001 (http) with context path ''2020-06-16 20:06:45.586 INFO 33012 --- [ main] o.a.s.pack.demo.car.Application : Started Application in 42.974 seconds (JVM running for 43.721)2020-06-16 20:06:45.731 INFO 33012 --- [on(1)-127.0.0.1] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring DispatcherServlet 'dispatcherServlet'2020-06-16 20:06:45.731 INFO 33012 --- [on(1)-127.0.0.1] o.s.web.servlet.DispatcherServlet : Initializing Servlet 'dispatcherServlet'2020-06-16 20:06:45.776 INFO 33012 --- [on(1)-127.0.0.1] o.s.web.servlet.DispatcherServlet : Completed initialization in 45 ms```
> When the business service startup is not completed, receiving a compensation request will cause gRPC and alpha to reconnect
> ---------------------------------------------------------------------------------------------------------------------------
>
> Key: SCB-2004
> URL: https://issues.apache.org/jira/browse/SCB-2004
> Project: Apache ServiceComb
> Issue Type: Bug
> Components: Saga
> Affects Versions: pack-0.6.0
> Reporter: Lei Zhang
> Priority: Major
>
> h1. If the Alpha's compensation call is received during the business service startup process, compensation failure will occasionally occur
>
> Because at startup, it will be connected to Alpha first, and then all compensation methods will be scanned and put to the class CallbackContext, If business service receives a compensation request before CallbackContext initialization, you will get NullPointerExceptionBecause at startup, it will be connected to Alpha first, and then all compensation methods will be scanned and put to the class CallbackContext, If business service receives a compensation request before CallbackContext initialization, you will get NullPointerException
> ```java
> public void apply(String globalTxId, String localTxId, String parentTxId, String callbackMethod, Object... payloads) { CallbackContextInternal contextInternal = contexts.get(callbackMethod); <----- this is empty String oldGlobalTxId = omegaContext.globalTxId(); String oldLocalTxId = omegaContext.localTxId(); try { omegaContext.setGlobalTxId(globalTxId); omegaContext.setLocalTxId(localTxId); contextInternal.callbackMethod.invoke(contextInternal.target, payloads); if (omegaContext.getAlphaMetas().isAkkaEnabled())
> { sender.send( new TxCompensateAckSucceedEvent(omegaContext.globalTxId(), omegaContext.localTxId(), parentTxId, callbackMethod)); }
> ```
> ```20:06:03.549 [background-preinit] INFO org.hibernate.validator.internal.util.Version - HV000001: Hibernate Validator 6.0.17.Final2020-06-16 20:06:03.801 INFO 33012 — [ main] trationDelegate$BeanPostProcessorChecker : Bean 'org.springframework.cloud.autoconfigure.ConfigurationPropertiesRebinderAutoConfiguration' of type [org.springframework.cloud.autoconfigure.ConfigurationPropertiesRebinderAutoConfiguration$$EnhancerBySpringCGLIB$$23824f27] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
> . ___ __ __ _ _ /_
> _/ ___'_ __ _ _(_)_ _ ___ _ \ \ \ ( ( )___ | '_ | '_| | '_ \/ _` | \ \ \ \_
> _/ ___)| |_)| | | | | || (_| | ) ) ) ) ' |____| .__|_| |_|_| |___, | / / / / =========|_|==============|___/=/_/_/_/ :: Spring Boot :: (v2.1.6.RELEASE)
> 2020-06-16 20:06:04.543 INFO 33012 — [ main] o.a.s.pack.demo.car.Application : No active profile set, falling back to default profiles: default2020-06-16 20:06:05.887 INFO 33012 — [ main] o.s.cloud.context.scope.GenericScope : BeanFactory id=0844c163-505d-340b-8e21-343d5198bae82020-06-16 20:06:06.024 INFO 33012 — [ main] trationDelegate$BeanPostProcessorChecker : Bean 'org.apache.servicecomb.pack.omega.transaction.spring.TransactionAspectConfig' of type [org.apache.servicecomb.pack.omega.transaction.spring.TransactionAspectConfig$$EnhancerBySpringCGLIB$$6fc18c0a] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)2020-06-16 20:06:06.186 INFO 33012 — [ main] trationDelegate$BeanPostProcessorChecker : Bean 'org.apache.servicecomb.pack.omega.spring.OmegaSpringConfig' of type [org.apache.servicecomb.pack.omega.spring.OmegaSpringConfig$$EnhancerBySpringCGLIB$$b6310c32] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)2020-06-16 20:06:06.217 INFO 33012 — [ main] trationDelegate$BeanPostProcessorChecker : Bean 'omegaUniqueIdGenerator' of type [org.apache.servicecomb.pack.omega.context.UniqueIdGenerator] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)2020-06-16 20:06:06.244 INFO 33012 — [ main] trationDelegate$BeanPostProcessorChecker : Bean 'alphaClusterAddress' of type [org.apache.servicecomb.pack.omega.connector.grpc.AlphaClusterDiscovery] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)2020-06-16 20:06:06.259 INFO 33012 — [ main] o.a.s.p.omega.spring.OmegaSpringConfig : Discovery alpha cluster address localhost:8080 from DEFAULT2020-06-16 20:06:06.269 INFO 33012 — [ main] trationDelegate$BeanPostProcessorChecker : Bean 'alphaClusterConfig' of type [org.apache.servicecomb.pack.omega.connector.grpc.AlphaClusterConfig] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)2020-06-16 20:06:06.286 INFO 33012 — [ main] trationDelegate$BeanPostProcessorChecker : Bean 'serviceConfig' of type [org.apache.servicecomb.pack.omega.context.ServiceConfig] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)2020-06-16 20:06:06.640 INFO 33012 — [ main] trationDelegate$BeanPostProcessorChecker : Bean 'sagaLoadContext' of type [org.apache.servicecomb.pack.omega.connector.grpc.core.LoadBalanceContext] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)2020-06-16 20:06:06.711 INFO 33012 — [ main] trationDelegate$BeanPostProcessorChecker : Bean 'sagaLoadBalanceSender' of type [org.apache.servicecomb.pack.omega.connector.grpc.saga.SagaLoadBalanceSender] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)2020-06-16 20:06:07.042 INFO 33012 — [ main] o.a.s.p.o.c.g.c.LoadBalanceSenderAdapter : Alpha configuration is \{AkkaEnabled=true}2020-06-16 20:06:07.045 INFO 33012 — [ main] trationDelegate$BeanPostProcessorChecker : Bean 'omegaContext' of type [org.apache.servicecomb.pack.omega.context.OmegaContext] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)2020-06-16 20:06:07.069 INFO 33012 — [ main] trationDelegate$BeanPostProcessorChecker : Bean 'compensationContext' of type [org.apache.servicecomb.pack.omega.transaction.CallbackContext] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)2020-06-16 20:06:07.085 INFO 33012 — [ main] trationDelegate$BeanPostProcessorChecker : Bean 'coordinateContext' of type [org.apache.servicecomb.pack.omega.transaction.CallbackContext] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)2020-06-16 20:06:07.098 INFO 33012 — [ main] trationDelegate$BeanPostProcessorChecker : Bean 'org.springframework.cloud.autoconfigure.ConfigurationPropertiesRebinderAutoConfiguration' of type [org.springframework.cloud.autoconfigure.ConfigurationPropertiesRebinderAutoConfiguration$$EnhancerBySpringCGLIB$$23824f27] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)2020-06-16 20:06:07.286 INFO 33012 — [ault-executor-1] s.p.o.c.g.s.GrpcCompensateStreamObserver : Received compensate command, global tx id: f8f70b2b-837a-4485-abc2-d99a399fd45f, local tx id: 85d01500-c512-440d-8447-b793a9ca0bec, compensation method: void org.apache.servicecomb.pack.demo.car.CarBookingService.cancel(org.apache.servicecomb.pack.demo.car.CarBooking)2020-06-16 20:06:37.400 ERROR 33012 — [ault-executor-1] 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:533) ~[grpc-api-1.22.0.jar:1.22.0] at io.grpc.stub.ClientCalls$StreamObserverToCallListenerAdapter.onClose(ClientCalls.java:442) [grpc-stub-1.22.0.jar:1.22.0] at io.grpc.PartialForwardingClientCallListener.onClose(PartialForwardingClientCallListener.java:39) [grpc-api-1.22.0.jar:1.22.0] at io.grpc.ForwardingClientCallListener.onClose(ForwardingClientCallListener.java:23) [grpc-api-1.22.0.jar:1.22.0] at io.grpc.ForwardingClientCallListener$SimpleForwardingClientCallListener.onClose(ForwardingClientCallListener.java:40) [grpc-api-1.22.0.jar:1.22.0] at io.grpc.internal.CensusStatsModule$StatsClientInterceptor$1$1.onClose(CensusStatsModule.java:700) [grpc-core-1.22.0.jar:1.22.0] at io.grpc.PartialForwardingClientCallListener.onClose(PartialForwardingClientCallListener.java:39) [grpc-api-1.22.0.jar:1.22.0] at io.grpc.ForwardingClientCallListener.onClose(ForwardingClientCallListener.java:23) [grpc-api-1.22.0.jar:1.22.0] at io.grpc.ForwardingClientCallListener$SimpleForwardingClientCallListener.onClose(ForwardingClientCallListener.java:40) [grpc-api-1.22.0.jar:1.22.0] at io.grpc.internal.CensusTracingModule$TracingClientInterceptor$1$1.onClose(CensusTracingModule.java:399) [grpc-core-1.22.0.jar:1.22.0] at io.grpc.internal.ClientCallImpl.closeObserver(ClientCallImpl.java:507) [grpc-core-1.22.0.jar:1.22.0] at io.grpc.internal.ClientCallImpl.access$300(ClientCallImpl.java:66) [grpc-core-1.22.0.jar:1.22.0] at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl.close(ClientCallImpl.java:627) [grpc-core-1.22.0.jar:1.22.0] at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl.access$700(ClientCallImpl.java:515) [grpc-core-1.22.0.jar:1.22.0] at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl$1MessagesAvailable.runInternal(ClientCallImpl.java:608) [grpc-core-1.22.0.jar:1.22.0] at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl$1MessagesAvailable.runInContext(ClientCallImpl.java:581) [grpc-core-1.22.0.jar:1.22.0] at io.grpc.internal.ContextRunnable.run(ContextRunnable.java:37) [grpc-core-1.22.0.jar:1.22.0] at io.grpc.internal.SerializingExecutor.run(SerializingExecutor.java:123) [grpc-core-1.22.0.jar:1.22.0] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_201] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_201] at java.lang.Thread.run(Thread.java:748) [na:1.8.0_201]Caused by: java.lang.NullPointerException: null at org.apache.servicecomb.pack.omega.transaction.CallbackContext$CallbackContextInternal.access$200(CallbackContext.java:80) ~[classes/:na] at org.apache.servicecomb.pack.omega.transaction.CallbackContext.apply(CallbackContext.java:53) ~[classes/:na] at org.apache.servicecomb.pack.omega.transaction.CompensationMessageHandler.onReceive(CompensationMessageHandler.java:33) ~[classes/:na] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_201] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_201] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_201] at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_201] at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:343) ~[spring-aop-5.1.8.RELEASE.jar:5.1.8.RELEASE] at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:205) ~[spring-aop-5.1.8.RELEASE.jar:5.1.8.RELEASE] at com.sun.proxy.$Proxy99.onReceive(Unknown Source) ~[na:na] at org.apache.servicecomb.pack.omega.connector.grpc.saga.GrpcCompensateStreamObserver.onNext(GrpcCompensateStreamObserver.java:52) ~[classes/:na] at org.apache.servicecomb.pack.omega.connector.grpc.saga.GrpcCompensateStreamObserver.onNext(GrpcCompensateStreamObserver.java:31) ~[classes/:na] at io.grpc.stub.ClientCalls$StreamObserverToCallListenerAdapter.onMessage(ClientCalls.java:429) [grpc-stub-1.22.0.jar:1.22.0] at io.grpc.ForwardingClientCallListener.onMessage(ForwardingClientCallListener.java:33) [grpc-api-1.22.0.jar:1.22.0] at io.grpc.ForwardingClientCallListener.onMessage(ForwardingClientCallListener.java:33) [grpc-api-1.22.0.jar:1.22.0] at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl$1MessagesAvailable.runInternal(ClientCallImpl.java:596) [grpc-core-1.22.0.jar:1.22.0] ... 6 common frames omitted
> 2020-06-16 20:06:37.402 INFO 33012 — [pool-2-thread-1] .a.s.p.o.c.g.c.PushBackReconnectRunnable : Retry connecting to alpha at localhost:80802020-06-16 20:06:37.409 ERROR 33012 — [pool-2-thread-1] .a.s.p.o.c.g.c.PushBackReconnectRunnable : Failed to reconnect to alpha at localhost:8080
> io.grpc.StatusRuntimeException: UNKNOWN at io.grpc.stub.ClientCalls.toStatusRuntimeException(ClientCalls.java:235) ~[grpc-stub-1.22.0.jar:1.22.0] at io.grpc.stub.ClientCalls.getUnchecked(ClientCalls.java:216) ~[grpc-stub-1.22.0.jar:1.22.0] at io.grpc.stub.ClientCalls.blockingUnaryCall(ClientCalls.java:141) ~[grpc-stub-1.22.0.jar:1.22.0] at org.apache.servicecomb.pack.contract.grpc.TxEventServiceGrpc$TxEventServiceBlockingStub.onDisconnected(TxEventServiceGrpc.java:326) ~[classes/:na] at org.apache.servicecomb.pack.omega.connector.grpc.saga.GrpcSagaClientMessageSender.onDisconnected(GrpcSagaClientMessageSender.java:77) ~[classes/:na] at org.apache.servicecomb.pack.omega.connector.grpc.core.PushBackReconnectRunnable.run(PushBackReconnectRunnable.java:52) ~[classes/:na] at org.apache.servicecomb.pack.omega.connector.grpc.core.PendingTaskRunner$1.run(PendingTaskRunner.java:44) [classes/:na] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [na:1.8.0_201] at java.util.concurrent.FutureTask.runAndReset$$$capture(FutureTask.java:308) [na:1.8.0_201] at java.util.concurrent.FutureTask.runAndReset(FutureTask.java) [na:1.8.0_201] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [na:1.8.0_201] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [na:1.8.0_201] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_201] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_201] at java.lang.Thread.run(Thread.java:748) [na:1.8.0_201]
> 2020-06-16 20:06:37.453 INFO 33012 — [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat initialized with port(s): 9001 (http)2020-06-16 20:06:37.475 INFO 33012 — [ main] o.apache.catalina.core.StandardService : Starting service [Tomcat]2020-06-16 20:06:37.475 INFO 33012 — [ main] org.apache.catalina.core.StandardEngine : Starting Servlet engine: [Apache Tomcat/9.0.21]2020-06-16 20:06:37.654 INFO 33012 — [ main] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring embedded WebApplicationContext2020-06-16 20:06:37.654 INFO 33012 — [ main] o.s.web.context.ContextLoader : Root WebApplicationContext: initialization completed in 33096 ms2020-06-16 20:06:38.049 WARN 33012 — [ main] c.n.c.sources.URLConfigurationSource : No URLs will be polled as dynamic configuration sources.2020-06-16 20:06:38.049 INFO 33012 — [ main] c.n.c.sources.URLConfigurationSource : To enable URLs as dynamic configuration sources, define System property archaius.configurationSource.additionalUrls or make config.properties available on classpath.2020-06-16 20:06:38.059 INFO 33012 — [ main] c.netflix.config.DynamicPropertyFactory : DynamicPropertyFactory is initialized with configuration sources: com.netflix.config.ConcurrentCompositeConfiguration@42066f0d2020-06-16 20:06:41.654 INFO 33012 — [pool-2-thread-1] .a.s.p.o.c.g.c.PushBackReconnectRunnable : Retry connecting to alpha at localhost:80802020-06-16 20:06:41.662 INFO 33012 — [pool-2-thread-1] .a.s.p.o.c.g.c.PushBackReconnectRunnable : Retry connecting to alpha at localhost:8080 is successful2020-06-16 20:06:41.681 WARN 33012 — [ main] c.n.c.sources.URLConfigurationSource : No URLs will be polled as dynamic configuration sources.2020-06-16 20:06:41.681 INFO 33012 — [ main] c.n.c.sources.URLConfigurationSource : To enable URLs as dynamic configuration sources, define System property archaius.configurationSource.additionalUrls or make config.properties available on classpath.2020-06-16 20:06:43.305 INFO 33012 — [ main] o.s.s.concurrent.ThreadPoolTaskExecutor : Initializing ExecutorService 'applicationTaskExecutor'2020-06-16 20:06:45.272 WARN 33012 — [ main] o.s.c.n.core.CoreAutoConfiguration : This module is deprecated. It will be removed in the next major release. Please use spring-cloud-netflix-hystrix instead.2020-06-16 20:06:45.363 INFO 33012 — [ main] o.s.b.a.e.web.EndpointLinksResolver : Exposing 2 endpoint(s) beneath base path '/actuator'2020-06-16 20:06:45.583 INFO 33012 — [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat started on port(s): 9001 (http) with context path ''2020-06-16 20:06:45.586 INFO 33012 — [ main] o.a.s.pack.demo.car.Application : Started Application in 42.974 seconds (JVM running for 43.721)2020-06-16 20:06:45.731 INFO 33012 — [on(1)-127.0.0.1] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring DispatcherServlet 'dispatcherServlet'2020-06-16 20:06:45.731 INFO 33012 — [on(1)-127.0.0.1] o.s.web.servlet.DispatcherServlet : Initializing Servlet 'dispatcherServlet'2020-06-16 20:06:45.776 INFO 33012 — [on(1)-127.0.0.1] o.s.web.servlet.DispatcherServlet : Completed initialization in 45 ms```
--
This message was sent by Atlassian Jira
(v8.3.4#803005)