How to troubleshoot unexpected "io.grpc.StatusRuntimeException: UNAVAILABLE: Channel shutdownNow"?

[nicholas...@lucidworks.com]

My team has the following setup, where we have multiple Client nodes connecting to Multiple Server nodes with a channel from client to server of each node, where each channel comprises of multiple persistent streams left open for the lifetime of the process:

When stress testing the system, we see sudden shutdown of all the bi-directional streams:

io.grpc.StatusRuntimeException: UNAVAILABLE: Channel shutdownNow invoked

       at io.grpc.Status.asRuntimeException(Status.java:526) ~[client-support-4.0.0-SNAPSHOT-shadow.jar:?]

    at io.grpc.stub.ClientCalls$StreamObserverToCallListenerAdapter.onClose(ClientCalls.java:418) [grpc-stub-1.8.0.jar:1.8.0]

      at io.grpc.ForwardingClientCallListener.onClose(ForwardingClientCallListener.java:41) [client-support-4.0.0-SNAPSHOT-shadow.jar:?]

     at io.grpc.internal.CensusStatsModule$StatsClientInterceptor$1$1.onClose(CensusStatsModule.java:663) [client-support-4.0.0-SNAPSHOT-shadow.jar:?]

      at io.grpc.ForwardingClientCallListener.onClose(ForwardingClientCallListener.java:41) [client-support-4.0.0-SNAPSHOT-shadow.jar:?]

     at io.grpc.internal.CensusTracingModule$TracingClientInterceptor$1$1.onClose(CensusTracingModule.java:392) [client-support-4.0.0-SNAPSHOT-shadow.jar:?]

at io.grpc.internal.ClientCallImpl.closeObserver(ClientCallImpl.java:443) [client-support-4.0.0-SNAPSHOT-shadow.jar:?]

 at io.grpc.internal.ClientCallImpl.access$300(ClientCallImpl.java:63) [client-support-4.0.0-SNAPSHOT-shadow.jar:?]

     at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl.close(ClientCallImpl.java:525) [client-support-4.0.0-SNAPSHOT-shadow.jar:?]

at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl.access$600(ClientCallImpl.java:446) [client-support-4.0.0-SNAPSHOT-shadow.jar:?]

   at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl$1StreamClosed.runInContext(ClientCallImpl.java:557) [client-support-4.0.0-SNAPSHOT-shadow.jar:?]

   at io.grpc.internal.ContextRunnable.run(ContextRunnable.java:37) [client-support-4.0.0-SNAPSHOT-shadow.jar:?]

  at io.grpc.internal.SerializingExecutor.run(SerializingExecutor.java:123) [client-support-4.0.0-SNAPSHOT-shadow.jar:?]

 at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_141]

       at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_141]

       at java.lang.Thread.run(Thread.java:748) [?:1.8.0_141]

2018-02-16T14:15:41,314 - ERROR - [grpc-default-executor-190:com.lucidworks.fusion.service.connector.ConnectorServerStreamObserver:service.connector.ConnectorServerStreamObserver@298] - {} - Plugin connection error / disconnected

io.grpc.StatusRuntimeException: CANCELLED: cancelled before receiving half close

    at io.grpc.Status.asRuntimeException(Status.java:517) ~[client-support-4.0.0-SNAPSHOT-shadow.jar:?]

    at io.grpc.stub.ServerCalls$StreamingServerCallHandler$StreamingServerCallListener.onCancel(ServerCalls.java:272) [grpc-stub-1.8.0.jar:1.8.0]

  at com.lucidworks.fusion.grpc.interceptors.BroadcastingInterceptor$1.onCancel(BroadcastingInterceptor.java:63) [classes/:?]

    at io.grpc.PartialForwardingServerCallListener.onCancel(PartialForwardingServerCallListener.java:38) [client-support-4.0.0-SNAPSHOT-shadow.jar:?]

      at io.grpc.ForwardingServerCallListener.onCancel(ForwardingServerCallListener.java:23) [client-support-4.0.0-SNAPSHOT-shadow.jar:?]

    at io.grpc.ForwardingServerCallListener$SimpleForwardingServerCallListener.onCancel(ForwardingServerCallListener.java:40) [client-support-4.0.0-SNAPSHOT-shadow.jar:?]

 at io.grpc.internal.ServerCallImpl$ServerStreamListenerImpl.closed(ServerCallImpl.java:281) [client-support-4.0.0-SNAPSHOT-shadow.jar:?]

       at io.grpc.internal.ServerImpl$JumpToApplicationThreadServerStreamListener$1Closed.runInContext(ServerImpl.java:679) [client-support-4.0.0-SNAPSHOT-shadow.jar:?]

      at io.grpc.internal.ContextRunnable.run(ContextRunnable.java:37) [client-support-4.0.0-SNAPSHOT-shadow.jar:?]

  at io.grpc.internal.SerializingExecutor.run(SerializingExecutor.java:123) [client-support-4.0.0-SNAPSHOT-shadow.jar:?]

 at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_141]

       at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_141]

       at java.lang.Thread.run(Thread.java:748) [?:1.8.0_141]

2018-02-16T14:15:41,314 - ERROR - [grpc-default-executor-190:com.lucidworks.fusion.service.connector.controller.endpoints.ConnectEndpoint:controller.endpoints.ConnectEndpoint@49] - {} - connect() error: Received error from plugin: com.lucidworks.fusion.service.connector.ConnectorServerStreamObserver@596aba80

io.grpc.StatusRuntimeException: CANCELLED: cancelled before receiving half close

    at io.grpc.Status.asRuntimeException(Status.java:517) ~[client-support-4.0.0-SNAPSHOT-shadow.jar:?]

    at io.grpc.stub.ServerCalls$StreamingServerCallHandler$StreamingServerCallListener.onCancel(ServerCalls.java:272) [grpc-stub-1.8.0.jar:1.8.0]

  at com.lucidworks.fusion.grpc.interceptors.BroadcastingInterceptor$1.onCancel(BroadcastingInterceptor.java:63) [classes/:?]

    at io.grpc.PartialForwardingServerCallListener.onCancel(PartialForwardingServerCallListener.java:38) [client-support-4.0.0-SNAPSHOT-shadow.jar:?]

      at io.grpc.ForwardingServerCallListener.onCancel(ForwardingServerCallListener.java:23) [client-support-4.0.0-SNAPSHOT-shadow.jar:?]

    at io.grpc.ForwardingServerCallListener$SimpleForwardingServerCallListener.onCancel(ForwardingServerCallListener.java:40) [client-support-4.0.0-SNAPSHOT-shadow.jar:?]

 at io.grpc.internal.ServerCallImpl$ServerStreamListenerImpl.closed(ServerCallImpl.java:281) [client-support-4.0.0-SNAPSHOT-shadow.jar:?]

       at io.grpc.internal.ServerImpl$JumpToApplicationThreadServerStreamListener$1Closed.runInContext(ServerImpl.java:679) [client-support-4.0.0-SNAPSHOT-shadow.jar:?]

      at io.grpc.internal.ContextRunnable.run(ContextRunnable.java:37) [client-support-4.0.0-SNAPSHOT-shadow.jar:?]

  at io.grpc.internal.SerializingExecutor.run(SerializingExecutor.java:123) [client-support-4.0.0-SNAPSHOT-shadow.jar:?]

 at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_141]

       at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_141]

       at java.lang.Thread.run(Thread.java:748) [?:1.8.0_141]

We then have to reconnect each channel + reestablish the streams in order to continue.

To our knowledge, we are *not* shutting down the channels at any point. they need to remain open for the program to live happily. 

But someone is shutting them down somehow. 

What are common ways to troubleshoot this behavior? Is there some sort of timeout that we are victim of causing these sudden shutdowns?

[Eric Anderson]

I responded some on the GitHub issue.

--
You received this message because you are subscribed to the Google Groups "grpc.io" group.
To unsubscribe from this group and stop receiving emails from it, send an email to grpc-io+unsubscribe@googlegroups.com.
To post to this group, send email to grp...@googlegroups.com.
Visit this group at https://groups.google.com/group/grpc-io.
To view this discussion on the web visit https://groups.google.com/d/msgid/grpc-io/d6ca1176-3d4f-4f0b-8562-6c83ab8c84df%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.