[
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)
