Grpc traffic breaks when enabling sidecar on client

I have a client and server which communicate using grpc. The client currently has the sidecar disabled and the server currently has the sidecar enabled. Things work fine until I enabled the client sidecar.

Once I enabled the sidecar on the client side the client throws an exception after receiving the grpc response.

[ERROR] 2019-11-07 23:32:35.897 [nettyCallPool-4-1] TripsKt - callType: TripAssignmentException, requestId: 039d183c-a9b9-4eb3-ab9b-9f3e5b5cddfa, vin: 1FBAX2CG7JDL00196
io.grpc.StatusRuntimeException: INTERNAL: Received unexpected EOS on DATA frame from server.
	at io.grpc.stub.ClientCalls.toStatusRuntimeException(ClientCalls.java:235) ~[bart-1.0.jar:?]
	at io.grpc.stub.ClientCalls.getUnchecked(ClientCalls.java:216) ~[bart-1.0.jar:?]
	at io.grpc.stub.ClientCalls.blockingUnaryCall(ClientCalls.java:141) ~[bart-1.0.jar:?]
	at ai.argo.viaduct.proto.v1.ViaductAPIGrpc$ViaductAPIBlockingStub.query(ViaductAPIGrpc.java:177) ~[bart-1.0.jar:?]
	at ai.argo.viaduct.client.ViaductClientImpl.executeRequestBlocking(ViaductClientImpl.kt:63) ~[bart-1.0.jar:?]
	at ai.argo.overwatch.ovds.utilities.ViaductClientUtilKt.assignTrip(ViaductClientUtil.kt:36) ~[bart-1.0.jar:?]
	at ai.argo.overwatch.bart.api.routes.TripsKt.sendCompleteAssignmentToVehicle(Trips.kt:801) ~[bart-1.0.jar:?]
	at ai.argo.overwatch.bart.api.routes.TripsKt.assignTrip(Trips.kt:570) ~[bart-1.0.jar:?]
	at ai.argo.overwatch.bart.api.routes.TripsKt$trips$1.invokeSuspend(Trips.kt:220) ~[bart-1.0.jar:?]
	at ai.argo.overwatch.bart.api.routes.TripsKt$trips$1.invoke(Trips.kt) ~[bart-1.0.jar:?]
	at io.ktor.util.pipeline.SuspendFunctionGun.loop(PipelineContext.kt:278) ~[bart-1.0.jar:?]
	at io.ktor.util.pipeline.SuspendFunctionGun.access$loop(PipelineContext.kt:63) ~[bart-1.0.jar:?]
	at io.ktor.util.pipeline.SuspendFunctionGun.proceed(PipelineContext.kt:137) ~[bart-1.0.jar:?]
	at io.ktor.util.pipeline.SuspendFunctionGun.execute(PipelineContext.kt:157) ~[bart-1.0.jar:?]
	at io.ktor.util.pipeline.Pipeline.execute(Pipeline.kt:23) ~[bart-1.0.jar:?]
	at io.ktor.routing.Routing.executeResult(Routing.kt:148) ~[bart-1.0.jar:?]
	at io.ktor.routing.Routing.interceptor(Routing.kt:29) ~[bart-1.0.jar:?]
	at io.ktor.routing.Routing$Feature$install$1.invokeSuspend(Routing.kt:93) ~[bart-1.0.jar:?]
	at io.ktor.routing.Routing$Feature$install$1.invoke(Routing.kt) ~[bart-1.0.jar:?]
	at io.ktor.util.pipeline.SuspendFunctionGun.loop(PipelineContext.kt:278) ~[bart-1.0.jar:?]
	at io.ktor.util.pipeline.SuspendFunctionGun.access$loop(PipelineContext.kt:63) ~[bart-1.0.jar:?]
	at io.ktor.util.pipeline.SuspendFunctionGun.proceed(PipelineContext.kt:137) ~[bart-1.0.jar:?]
	at io.ktor.features.ContentNegotiation$Feature$install$1.invokeSuspend(ContentNegotiation.kt:63) ~[bart-1.0.jar:?]
	at io.ktor.features.ContentNegotiation$Feature$install$1.invoke(ContentNegotiation.kt) ~[bart-1.0.jar:?]
	at io.ktor.util.pipeline.SuspendFunctionGun.loop(PipelineContext.kt:278) ~[bart-1.0.jar:?]
	at io.ktor.util.pipeline.SuspendFunctionGun.access$loop(PipelineContext.kt:63) ~[bart-1.0.jar:?]
	at io.ktor.util.pipeline.SuspendFunctionGun.proceed(PipelineContext.kt:137) ~[bart-1.0.jar:?]
	at io.ktor.features.StatusPages$interceptCall$2.invokeSuspend(StatusPages.kt:94) ~[bart-1.0.jar:?]
	at io.ktor.features.StatusPages$interceptCall$2.invoke(StatusPages.kt) ~[bart-1.0.jar:?]
	at kotlinx.coroutines.intrinsics.UndispatchedKt.startUndispatchedOrReturn(Undispatched.kt:91) ~[bart-1.0.jar:?]
	at kotlinx.coroutines.CoroutineScopeKt.coroutineScope(CoroutineScope.kt:180) ~[bart-1.0.jar:?]
	at io.ktor.features.StatusPages.interceptCall(StatusPages.kt:93) ~[bart-1.0.jar:?]
	at io.ktor.features.StatusPages$Feature$install$2.invokeSuspend(StatusPages.kt:133) ~[bart-1.0.jar:?]
	at io.ktor.features.StatusPages$Feature$install$2.invoke(StatusPages.kt) ~[bart-1.0.jar:?]
	at io.ktor.util.pipeline.SuspendFunctionGun.loop(PipelineContext.kt:278) ~[bart-1.0.jar:?]
	at io.ktor.util.pipeline.SuspendFunctionGun.access$loop(PipelineContext.kt:63) ~[bart-1.0.jar:?]
	at io.ktor.util.pipeline.SuspendFunctionGun.proceed(PipelineContext.kt:137) ~[bart-1.0.jar:?]
	at io.ktor.metrics.Metrics$Feature$install$1.invokeSuspend(Metrics.kt:44) ~[bart-1.0.jar:?]
	at io.ktor.metrics.Metrics$Feature$install$1.invoke(Metrics.kt) ~[bart-1.0.jar:?]
	at io.ktor.util.pipeline.SuspendFunctionGun.loop(PipelineContext.kt:278) ~[bart-1.0.jar:?]
	at io.ktor.util.pipeline.SuspendFunctionGun.access$loop(PipelineContext.kt:63) ~[bart-1.0.jar:?]
	at io.ktor.util.pipeline.SuspendFunctionGun.proceed(PipelineContext.kt:137) ~[bart-1.0.jar:?]
	at io.ktor.features.CallLogging$Feature$install$2.invokeSuspend(CallLogging.kt:130) ~[bart-1.0.jar:?]
	at io.ktor.features.CallLogging$Feature$install$2.invoke(CallLogging.kt) ~[bart-1.0.jar:?]
	at io.ktor.util.pipeline.SuspendFunctionGun.loop(PipelineContext.kt:278) ~[bart-1.0.jar:?]
	at io.ktor.util.pipeline.SuspendFunctionGun.access$loop(PipelineContext.kt:63) ~[bart-1.0.jar:?]
	at io.ktor.util.pipeline.SuspendFunctionGun.proceed(PipelineContext.kt:137) ~[bart-1.0.jar:?]
	at io.ktor.util.pipeline.SuspendFunctionGun.execute(PipelineContext.kt:157) ~[bart-1.0.jar:?]
	at io.ktor.util.pipeline.Pipeline.execute(Pipeline.kt:23) ~[bart-1.0.jar:?]
	at io.ktor.server.engine.DefaultEnginePipelineKt$defaultEnginePipeline$2.invokeSuspend(DefaultEnginePipeline.kt:106) ~[bart-1.0.jar:?]
	at io.ktor.server.engine.DefaultEnginePipelineKt$defaultEnginePipeline$2.invoke(DefaultEnginePipeline.kt) ~[bart-1.0.jar:?]
	at io.ktor.util.pipeline.SuspendFunctionGun.loop(PipelineContext.kt:278) ~[bart-1.0.jar:?]
	at io.ktor.util.pipeline.SuspendFunctionGun.access$loop(PipelineContext.kt:63) ~[bart-1.0.jar:?]
	at io.ktor.util.pipeline.SuspendFunctionGun.proceed(PipelineContext.kt:137) ~[bart-1.0.jar:?]
	at io.ktor.util.pipeline.SuspendFunctionGun.execute(PipelineContext.kt:157) ~[bart-1.0.jar:?]
	at io.ktor.util.pipeline.Pipeline.execute(Pipeline.kt:23) ~[bart-1.0.jar:?]
	at io.ktor.server.netty.NettyApplicationCallHandler$handleRequest$1.invokeSuspend(NettyApplicationCallHandler.kt:31) ~[bart-1.0.jar:?]
	at io.ktor.server.netty.NettyApplicationCallHandler$handleRequest$1.invoke(NettyApplicationCallHandler.kt) ~[bart-1.0.jar:?]
	at kotlinx.coroutines.intrinsics.UndispatchedKt.startCoroutineUndispatched(Undispatched.kt:55) ~[bart-1.0.jar:?]
	at kotlinx.coroutines.CoroutineStart.invoke(CoroutineStart.kt:111) ~[bart-1.0.jar:?]
	at kotlinx.coroutines.AbstractCoroutine.start(AbstractCoroutine.kt:154) ~[bart-1.0.jar:?]
	at kotlinx.coroutines.BuildersKt__Builders_commonKt.launch(Builders.common.kt:54) ~[bart-1.0.jar:?]
	at kotlinx.coroutines.BuildersKt.launch(Unknown Source) ~[bart-1.0.jar:?]
	at io.ktor.server.netty.NettyApplicationCallHandler.handleRequest(NettyApplicationCallHandler.kt:22) ~[bart-1.0.jar:?]
	at io.ktor.server.netty.NettyApplicationCallHandler.channelRead(NettyApplicationCallHandler.kt:16) ~[bart-1.0.jar:?]
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:374) ~[bart-1.0.jar:?]
	at io.netty.channel.AbstractChannelHandlerContext.access$600(AbstractChannelHandlerContext.java:56) ~[bart-1.0.jar:?]
	at io.netty.channel.AbstractChannelHandlerContext$7.run(AbstractChannelHandlerContext.java:365) ~[bart-1.0.jar:?]
	at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:163) ~[bart-1.0.jar:?]
	at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:405) ~[bart-1.0.jar:?]
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:500) ~[bart-1.0.jar:?]
	at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:906) ~[bart-1.0.jar:?]
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) ~[bart-1.0.jar:?]
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) ~[bart-1.0.jar:?]
	at java.lang.Thread.run(Thread.java:834) ~[?:?]

After digging into the istio-proxy logs one thing that jumps out as me is that once the client sidecar turns on the grpc request is received by the server sidecar as HTTP 1.1 instead of HTTP2.

Server logs before adding client sidecar

[2019-11-06T21:28:47.504Z] "POST /ai.argo.viaduct.proto.v1.ViaductAPI/Query HTTP/2" 200 - "-" "-" 1169 1208 344 342 "-" "grpc-java-netty/1.21.1" "5f3b5c0c-cebc-9998-aed2-7425a79199a1" "192.168.0.8:8085" "127.0.0.1:8085" inbound|80|grpc|viaduct.overwatch-development.svc.cluster.local - 192.168.0.8:8085 192.168.192.5:36932 -
[2019-11-06T21:28:47.690Z] "POST /ai.argo.viaduct.proto.v1.ViaductAPI/Query HTTP/1.1" 0 DC "-" "-" 1169 0 4995 - "-" "grpc-java-netty/1.21.1" "8e2da41e-0918-94cb-8fd3-b9bffefee266" "192.168.0.8:8085" "127.0.0.1:8085" inbound|80|grpc|viaduct.overwatch-development.svc.cluster.local - 192.168.0.8:8085 192.168.176.8:58552 -
[2019-11-06T21:28:47.735Z] "POST /ai.argo.viaduct.proto.v1.ViaductAPI/Query HTTP/1.1" 0 DC "-" "-" 1169 0 4995 - "-" "grpc-java-netty/1.21.1" "c01c9eb2-7ae7-90bd-a193-c1b1c3c5665e" "192.168.0.8:8085" "127.0.0.1:8085" inbound|80|grpc|viaduct.overwatch-development.svc.cluster.local - 192.168.0.8:8085 192.168.32.12:51976 -

Server logs after adding client sidecar

[2019-11-06T21:11:43.366Z] "POST /ai.argo.viaduct.proto.v1.ViaductAPI/Query HTTP/1.1" 200 - "-" "-" 1241 1280 67 64 "-" "grpc-java-netty/1.21.1" "1f9c8d91-9ed1-950f-b1d5-196c696dd707" "192.168.0.8:8085" "127.0.0.1:8085" inbound|80|grpc|viaduct.overwatch-development.svc.cluster.local - 192.168.0.8:8085 192.168.176.5:48770 -
[2019-11-06T21:11:43.576Z] "POST /ai.argo.viaduct.proto.v1.ViaductAPI/Query HTTP/1.1" 200 - "-" "-" 1241 1280 365 364 "-" "grpc-java-netty/1.21.1" "7c6afb06-cb4c-9517-be63-67b1d7041b07" "192.168.0.8:8085" "127.0.0.1:8085" inbound|80|grpc|viaduct.overwatch-development.svc.cluster.local - 192.168.0.8:8085 192.168.176.5:48786 -
[2019-11-06T21:11:43.898Z] "POST /ai.argo.viaduct.proto.v1.ViaductAPI/Query HTTP/1.1" 200 - "-" "-" 1241 1280 1042 1040 "-" "grpc-java-netty/1.21.1" "24247e09-d01a-9aa6-b027-a9862f0923f5" "192.168.0.8:8085" "127.0.0.1:8085" inbound|80|grpc|viaduct.overwatch-development.svc.cluster.local - 192.168.0.8:8085 192.168.176.8:41686 -
[2019-11-06T21:11:44.082Z] "POST /ai.argo.viaduct.proto.v1.ViaductAPI/Query HTTP/1.1" 200 - "-" "-" 1241 1280 1361 1361 "-" "grpc-java-netty/1.21.1" "5a5e1de6-14eb-96df-be69-59eee032ced4" "192.168.0.8:8085" "127.0.0.1:8085" inbound|80|grpc|viaduct.overwatch-development.svc.cluster.local - 192.168.0.8:8085 192.168.176.5:48786 -
[2019-11-06T21:11:44.454Z] "POST /ai.argo.viaduct.proto.v1.ViaductAPI/Query HTTP/1.1" 200 - "-" "-" 1241 1280 1500 1498 "-" "grpc-java-netty/1.21.1" "cd03ab8d-ffc4-9aa7-bb3f-fb20ecd48420" "192.168.0.8:8085" "127.0.0.1:8085" inbound|80|grpc|viaduct.overwatch-development.svc.cluster.local - 192.168.0.8:8085 192.168.192.3:45588 -
[2019-11-06T21:11:46.121Z] "POST /ai.argo.viaduct.proto.v1.ViaductAPI/Query HTTP/1.1" 200 - "-" "-" 1241 1280 1320 1320 "-" "grpc-java-netty/1.21.1" "8c6a778c-b15f-9b7e-b5df-0aa7a6914259" "192.168.0.8:8085" "127.0.0.1:8085" inbound|80|grpc|viaduct.overwatch-development.svc.cluster.local - 192.168.0.8:8085 192.168.192.3:45588 -
[2019-11-06T21:11:49.127Z] "POST /ai.argo.viaduct.proto.v1.ViaductAPI/Query HTTP/1.1" 200 - "-" "-" 1241 1280 315 315 "-" "grpc-java-netty/1.21.1" "19477b3c-0e70-955e-9d57-af507a58800b" "192.168.0.8:8085" "127.0.0.1:8085" inbound|80|grpc|viaduct.overwatch-development.svc.cluster.local - 192.168.0.8:8085 192.168.192.3:45688 -

What is really strange is that we have a number of other services which speak grpc just fine with sidecars. Can anyone provide any tips on how to debug this?

It appears that the issue is related to the grpc client making requests to the server IP address directly instead of the service name. This routes the traffic to the PassthroughCluster and then somehow it gets messed up when it reaches the server service.