envoyproxy / java-control-plane

Java implementation of an Envoy gRPC control plane
Apache License 2.0
293 stars 136 forks source link

Discovery server is logging ERROR when client closes connection #83

Closed rieske closed 5 years ago

rieske commented 5 years ago

DiscoveryServer is logging ERROR when client Envoy closes connection.

I have an Envoy connected to my java-control-plane implementation and whenever I restart Envoy, the control plane logs an ERROR from io.envoyproxy.controlplane.server.DiscoveryServer

Strange thing is that the code here: https://github.com/envoyproxy/java-control-plane/blob/master/server/src/main/java/io/envoyproxy/controlplane/server/DiscoveryServer.java#L224-L226 says that it should log ERROR if the status is other than CANCELLED, however in my case, the stack trace says:

io.grpc.StatusRuntimeException: CANCELLED: cancelled before receiving half close
    at io.grpc.Status.asRuntimeException(Status.java:517)
    at io.grpc.stub.ServerCalls$StreamingServerCallHandler$StreamingServerCallListener.onCancel(ServerCalls.java:272)
    at io.grpc.internal.ServerCallImpl$ServerStreamListenerImpl.closed(ServerCallImpl.java:293)
    at io.grpc.internal.ServerImpl$JumpToApplicationThreadServerStreamListener$1Closed.runInContext(ServerImpl.java:741)
    at io.grpc.internal.ContextRunnable.run(ContextRunnable.java:37)
    at io.grpc.internal.SerializingExecutor.run(SerializingExecutor.java:123)
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
    at java.base/java.lang.Thread.run(Thread.java:834)

and the message is [3] stream closed with error together with logger_name io.envoyproxy.controlplane.server.DiscoveryServer, indicating that the log line must be coming from the Discovery server there.

ramaraochavali commented 5 years ago

It is because of how the equals function of gRPC status works. It is a bug. We should actually check like this if (status.getCode() != Status.CANCELLED.getCode()) {

rieske commented 5 years ago

Was just about to write the same :) Replicated in a test and it is due to the description in status object failing the equals check. .getCode() does the trick.

snowp commented 5 years ago

That would explain why we're still logging this even after I thought I fixed it :)

@rieske If you have this fixed /w a test case a PR would be much appreciated