servicecomb-pack icon indicating copy to clipboard operation
servicecomb-pack copied to clipboard

o.a.s.p.o.c.g.c.ReconnectStreamObserver : Failed to process grpc coordinate command.

Open xuanshu opened this issue 6 years ago • 3 comments

采用的是spring boot 1.X 版本 跨服务调用是采用的是springcloud feign ; jdk 是1.8 ; alpha 打包命令 : mvn clean install -Ppring-boot-1 serviceComb 是0.3.0 版本 (此版本omega-transport-feign 里面的spring.factories 文件需要改成由org.apache.servicecomb.saga.omega.transport.feign.FeignAutoConfiguration 改为org.apache.servicecomb.pack.omega.transport.feign.FeignAutoConfiguration 否则会报FeignAutoConfiguration 类找不到);

会员服务调用消息服务没异常系统saga 不报错 , 有异常则出现下面异常(主服务故意抛出异常,被调用服务则抛出下列异常) `2019-03-04 19:53:20.141 ERROR 53844 --- [ault-executor-2] o.a.s.p.o.c.g.c.ReconnectStreamObserver : Failed to process grpc coordinate command.

io.grpc.StatusRuntimeException: CANCELLED: Failed to read message. at io.grpc.Status.asRuntimeException(Status.java:526) at io.grpc.stub.ClientCalls$StreamObserverToCallListenerAdapter.onClose(ClientCalls.java:420) at io.grpc.PartialForwardingClientCallListener.onClose(PartialForwardingClientCallListener.java:39) at io.grpc.ForwardingClientCallListener.onClose(ForwardingClientCallListener.java:23) at io.grpc.ForwardingClientCallListener$SimpleForwardingClientCallListener.onClose(ForwardingClientCallListener.java:40) at io.grpc.internal.CensusStatsModule$StatsClientInterceptor$1$1.onClose(CensusStatsModule.java:684) at io.grpc.PartialForwardingClientCallListener.onClose(PartialForwardingClientCallListener.java:39) at io.grpc.ForwardingClientCallListener.onClose(ForwardingClientCallListener.java:23) at io.grpc.ForwardingClientCallListener$SimpleForwardingClientCallListener.onClose(ForwardingClientCallListener.java:40) at io.grpc.internal.CensusTracingModule$TracingClientInterceptor$1$1.onClose(CensusTracingModule.java:403) at io.grpc.internal.ClientCallImpl.closeObserver(ClientCallImpl.java:459) at io.grpc.internal.ClientCallImpl.access$300(ClientCallImpl.java:63) at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl.close(ClientCallImpl.java:546) at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl.access$600(ClientCallImpl.java:467) at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl$1MessagesAvailable.runInContext(ClientCallImpl.java:531) at io.grpc.internal.ContextRunnable.run(ContextRunnable.java:37) at io.grpc.internal.SerializingExecutor.run(SerializingExecutor.java:123) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) Caused by: java.lang.NullPointerException: null at org.apache.servicecomb.pack.omega.context.CallbackContext$CallbackContextInternal.access$200(CallbackContext.java:63) at org.apache.servicecomb.pack.omega.context.CallbackContext.apply(CallbackContext.java:50) at org.apache.servicecomb.pack.omega.transaction.CompensationMessageHandler.onReceive(CompensationMessageHandler.java:35) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:333) at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:207) at com.sun.proxy.$Proxy111.onReceive(Unknown Source) at org.apache.servicecomb.pack.omega.connector.grpc.saga.GrpcCompensateStreamObserver.onNext(GrpcCompensateStreamObserver.java:52) at org.apache.servicecomb.pack.omega.connector.grpc.saga.GrpcCompensateStreamObserver.onNext(GrpcCompensateStreamObserver.java:31) at io.grpc.stub.ClientCalls$StreamObserverToCallListenerAdapter.onMessage(ClientCalls.java:407) at io.grpc.ForwardingClientCallListener.onMessage(ForwardingClientCallListener.java:33) at io.grpc.ForwardingClientCallListener.onMessage(ForwardingClientCallListener.java:33) at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl$1MessagesAvailable.runInContext(ClientCallImpl.java:519) ... 5 common frames omitted

03-04 19:53:20.141 ERROR [o.a.s.p.o.c.grpc.core.ReconnectStreamObserver] - Failed to process grpc coordinate command. io.grpc.StatusRuntimeException: CANCELLED: Failed to read message. at io.grpc.Status.asRuntimeException(Status.java:526) at io.grpc.stub.ClientCalls$StreamObserverToCallListenerAdapter.onClose(ClientCalls.java:420) at io.grpc.PartialForwardingClientCallListener.onClose(PartialForwardingClientCallListener.java:39) at io.grpc.ForwardingClientCallListener.onClose(ForwardingClientCallListener.java:23) at io.grpc.ForwardingClientCallListener$SimpleForwardingClientCallListener.onClose(ForwardingClientCallListener.java:40) at io.grpc.internal.CensusStatsModule$StatsClientInterceptor$1$1.onClose(CensusStatsModule.java:684) at io.grpc.PartialForwardingClientCallListener.onClose(PartialForwardingClientCallListener.java:39) at io.grpc.ForwardingClientCallListener.onClose(ForwardingClientCallListener.java:23) at io.grpc.ForwardingClientCallListener$SimpleForwardingClientCallListener.onClose(ForwardingClientCallListener.java:40) at io.grpc.internal.CensusTracingModule$TracingClientInterceptor$1$1.onClose(CensusTracingModule.java:403) at io.grpc.internal.ClientCallImpl.closeObserver(ClientCallImpl.java:459) at io.grpc.internal.ClientCallImpl.access$300(ClientCallImpl.java:63) at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl.close(ClientCallImpl.java:546) at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl.access$600(ClientCallImpl.java:467) at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl$1MessagesAvailable.runInContext(ClientCallImpl.java:531) at io.grpc.internal.ContextRunnable.run(ContextRunnable.java:37) at io.grpc.internal.SerializingExecutor.run(SerializingExecutor.java:123) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) Caused by: java.lang.NullPointerException: null at org.apache.servicecomb.pack.omega.context.CallbackContext$CallbackContextInternal.access$200(CallbackContext.java:63) at org.apache.servicecomb.pack.omega.context.CallbackContext.apply(CallbackContext.java:50) at org.apache.servicecomb.pack.omega.transaction.CompensationMessageHandler.onReceive(CompensationMessageHandler.java:35) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:333) at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:207) at com.sun.proxy.$Proxy111.onReceive(Unknown Source) at org.apache.servicecomb.pack.omega.connector.grpc.saga.GrpcCompensateStreamObserver.onNext(GrpcCompensateStreamObserver.java:52) at org.apache.servicecomb.pack.omega.connector.grpc.saga.GrpcCompensateStreamObserver.onNext(GrpcCompensateStreamObserver.java:31) at io.grpc.stub.ClientCalls$StreamObserverToCallListenerAdapter.onMessage(ClientCalls.java:407) at io.grpc.ForwardingClientCallListener.onMessage(ForwardingClientCallListener.java:33) at io.grpc.ForwardingClientCallListener.onMessage(ForwardingClientCallListener.java:33) at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl$1MessagesAvailable.runInContext(ClientCallImpl.java:519) ... 5 common frames omitted 2019-03-04 19:53:20.146 INFO 53844 --- [pool-1-thread-1] .a.s.p.o.c.g.c.PushBackReconnectRunnable : Retry connecting to alpha at 127.0.0.1:8080 03-04 19:53:20.146 INFO [o.a.s.p.o.c.grpc.core.PushBackReconnectRunnable] - Retry connecting to alpha at 127.0.0.1:8080 2019-03-04 19:53:20.161 ERROR 53844 --- [pool-1-thread-1] .a.s.p.o.c.g.c.PushBackReconnectRunnable : Failed to reconnect to alpha at 127.0.0.1:8080

io.grpc.StatusRuntimeException: UNKNOWN at io.grpc.stub.ClientCalls.toStatusRuntimeException(ClientCalls.java:222) at io.grpc.stub.ClientCalls.getUnchecked(ClientCalls.java:203) at io.grpc.stub.ClientCalls.blockingUnaryCall(ClientCalls.java:132) at org.apache.servicecomb.pack.contract.grpc.TxEventServiceGrpc$TxEventServiceBlockingStub.onDisconnected(TxEventServiceGrpc.java:280) at org.apache.servicecomb.pack.omega.connector.grpc.saga.GrpcSagaClientMessageSender.onDisconnected(GrpcSagaClientMessageSender.java:75) at org.apache.servicecomb.pack.omega.connector.grpc.core.PushBackReconnectRunnable.run(PushBackReconnectRunnable.java:52) at org.apache.servicecomb.pack.omega.connector.grpc.core.PendingTaskRunner$1.run(PendingTaskRunner.java:44) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) at java.util.concurrent.FutureTask.runAndReset$$$capture(FutureTask.java:308) at java.util.concurrent.FutureTask.runAndReset(FutureTask.java) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748)

03-04 19:53:20.161 ERROR [o.a.s.p.o.c.grpc.core.PushBackReconnectRunnable] - Failed to reconnect to alpha at 127.0.0.1:8080 io.grpc.StatusRuntimeException: UNKNOWN at io.grpc.stub.ClientCalls.toStatusRuntimeException(ClientCalls.java:222) at io.grpc.stub.ClientCalls.getUnchecked(ClientCalls.java:203) at io.grpc.stub.ClientCalls.blockingUnaryCall(ClientCalls.java:132) at org.apache.servicecomb.pack.contract.grpc.TxEventServiceGrpc$TxEventServiceBlockingStub.onDisconnected(TxEventServiceGrpc.java:280) at org.apache.servicecomb.pack.omega.connector.grpc.saga.GrpcSagaClientMessageSender.onDisconnected(GrpcSagaClientMessageSender.java:75) at org.apache.servicecomb.pack.omega.connector.grpc.core.PushBackReconnectRunnable.run(PushBackReconnectRunnable.java:52) at org.apache.servicecomb.pack.omega.connector.grpc.core.PendingTaskRunner$1.run(PendingTaskRunner.java:44) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) at java.util.concurrent.FutureTask.runAndReset$$$capture(FutureTask.java:308) at java.util.concurrent.FutureTask.runAndReset(FutureTask.java) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) 2019-03-04 19:53:23.164 INFO 53844 --- [pool-1-thread-1] .a.s.p.o.c.g.c.PushBackReconnectRunnable : Retry connecting to alpha at 127.0.0.1:8080 03-04 19:53:23.164 INFO [o.a.s.p.o.c.grpc.core.PushBackReconnectRunnable] - Retry connecting to alpha at 127.0.0.1:8080 2019-03-04 19:53:23.186 INFO 53844 --- [pool-1-thread-1] .a.s.p.o.c.g.c.PushBackReconnectRunnable : Retry connecting to alpha at 127.0.0.1:8080 is successful 03-04 19:53:23.186 INFO [o.a.s.p.o.c.grpc.core.PushBackReconnectRunnable] - Retry connecting to alpha at 127.0.0.1:8080 is successful`


代码如下 1.主服务 @SagaStart @RequestMapping(value = "/aa") public R test(@RequestParam Integer flag){ NoticeMain noticeMain = new NoticeMain(); noticeMain.setTenantId("00000"); //采用feign 调用 noticeService.addNotice(noticeMain); Member m = new Member(); m.setYmMemberId(flag); // 本地服务 memberService.insert(m); return new R(); } 2.从服务

@Override
@Compensable(compensationMethod="addCancel")
public void add(NoticeMain noticeMain){
    noticeMainMapper.insert(noticeMain);
}

@Override
public void addCancel(NoticeMain noticeMain){
    log.info("addCancel()已经执行");
    noticeMainMapper.deleteById(noticeMain);
}

xuanshu avatar Mar 04 '19 12:03 xuanshu

确实有这个问题,我看0.4.0版本已经修复了,我想0.3.0应该能很快修复

coolbeevip avatar Mar 05 '19 01:03 coolbeevip

Hi,

Thx for report the issue, The omega-transport-feign issue had been fixed in #376 SCB-1110. For the stack trace I found there is an import information,which looks like the omega has some trouble to process the command message from Alpha.

Caused by: java.lang.NullPointerException: null
at org.apache.servicecomb.pack.omega.context.CallbackContext$CallbackContextInternal.access$200(CallbackContext.java:63)
at org.apache.servicecomb.pack.omega.context.CallbackContext.apply(CallbackContext.java:50)
at org.apache.servicecomb.pack.omega.transaction.CompensationMessageHandler.onReceive(CompensationMessageHandler.java:35)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:333)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:207)
at com.sun.proxy.$Proxy111.onReceive(Unknown Source)
at org.apache.servicecomb.pack.omega.connector.grpc.saga.GrpcCompensateStreamObserver.onNext(GrpcCompensateStreamObserver.java:52)
at org.apache.servicecomb.pack.omega.connector.grpc.saga.GrpcCompensateStreamObserver.onNext(GrpcCompensateStreamObserver.java:31)
at io.grpc.stub.ClientCalls$StreamObserverToCallListenerAdapter.onMessage(ClientCalls.java:407)
at io.grpc.ForwardingClientCallListener.onMessage(ForwardingClientCallListener.java:33)
at io.grpc.ForwardingClientCallListener.onMessage(ForwardingClientCallListener.java:33)
at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl$1MessagesAvailable.runInContext(ClientCallImpl.java:519)
... 5 common frames omitted

You may take a look at this FAQ to check if you have the same trouble here.

WillemJiang avatar Mar 05 '19 02:03 WillemJiang

@xuanshu Is there any update for this issue?

WillemJiang avatar Mar 15 '19 08:03 WillemJiang