grpc / grpc-java

The Java gRPC implementation. HTTP/2 based RPC
https://grpc.io/docs/languages/java/
Apache License 2.0
11.41k stars 3.84k forks source link

Cross service call with grpc-xds v1.67.1 #11611

Open anuragagarwal561994 opened 1 week ago

anuragagarwal561994 commented 1 week ago

What version of gRPC-Java are you using?

v1.67.1

What is your environment?

jdk 21 eclipse temurin

What did you expect to see?

We are using istio version 1.20.1 and with this we are using grpc-proxyless setup for client side load balancing with grpc-xds in production in a multi-cluster environment. This setup has been working fine up until now.

Our service connects to several grpc targets which are present in other cluster, so we expect the routing is done correctly to each services as they have different service endpoints.

What did you see instead?

We see that the request is mixing between the services which are present in other cluster.

We were receiving status code as 12, when we turned on the debug logs and tried investigating further, we saw that the requests that were supposed to go on service A, few of the request were going to service B and vice versa. We are not sure why this is happening and it is not easier to reproduce as well as it happens randomly on different pods and persists for a longer time.

Lets say when a call to service A is going to service B, we identified the IP and killed that pod. Post that it picked up another IP of service B and started sending it request.

Since there were lots of changes related to load-balancing and also XDS fallback where XDS client was seaprated for each target, I am suspecting some issues in these modules.

We verified by reverting and upgrading multiple times that this is only happening for version > 1.66

kannanjgithub commented 4 days ago

Can you attach the debug logs?

anuragagarwal561994 commented 3 days ago
10 Oct 2024 14:21:56.229 DEBUG [grpc-default-worker-ELG-1-3] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0x570b03f2, L:/10.23.8.245:46916 - R:10.51.241.228/10.51.241.228:9090] OUTBOUND HEADERS: streamId=1909 headers=GrpcHttp2OutboundHeaders[:authority: dynamic-bid-floor.dynamic-bid-floor-prod.svc.cluster.local:9090, :path: /dynamicbidfloor.DynamicBidFloorService/GetDynamicBidFloor, :method: POST, :scheme: http, content-type: application/grpc, te: trailers, user-agent: grpc-java-netty/1.67.1, traceparent: 00-fd93b22fd62d5d1b9cb24016db4ac1ce-038ade7d2d36318e-00, grpc-accept-encoding: gzip] streamDependency=0 weight=16 exclusive=false padding=0 endStream=false
10 Oct 2024 14:21:56.230 DEBUG [grpc-default-worker-ELG-1-3] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0x570b03f2, L:/10.23.8.245:46916 - R:10.51.241.228/10.51.241.228:9090] OUTBOUND DATA: streamId=1909 padding=0 endStream=true length=281 bytes=00000001140a093843554b303336335210bc0118042a0b7175697a6c65742e636f6d32024e593865420c6578706c6f69746174696f6e4800526668747470733a...
10 Oct 2024 14:21:56.230 DEBUG [grpc-default-worker-ELG-1-3] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0x570b03f2, L:/10.23.8.245:46916 - R:10.51.241.228/10.51.241.228:9090] INBOUND WINDOW_UPDATE: streamId=0 windowSizeIncrement=281
10 Oct 2024 14:21:56.230 DEBUG [grpc-default-worker-ELG-1-3] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0x570b03f2, L:/10.23.8.245:46916 - R:10.51.241.228/10.51.241.228:9090] INBOUND PING: ack=false bytes=145258749040133895
10 Oct 2024 14:21:56.230 DEBUG [grpc-default-worker-ELG-1-3] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0x570b03f2, L:/10.23.8.245:46916 - R:10.51.241.228/10.51.241.228:9090] OUTBOUND PING: ack=true bytes=145258749040133895
10 Oct 2024 14:21:56.230 DEBUG [grpc-default-worker-ELG-1-3] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0x570b03f2, L:/10.23.8.245:46916 - R:10.51.241.228/10.51.241.228:9090] INBOUND HEADERS: streamId=1909 headers=GrpcHttp2ResponseHeaders[:status: 200, content-type: application/grpc] padding=0 endStream=false
10 Oct 2024 14:21:56.230 DEBUG [grpc-default-worker-ELG-1-3] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0x570b03f2, L:/10.23.8.245:46916 - R:10.51.241.228/10.51.241.228:9090] INBOUND DATA: streamId=1909 padding=0 endStream=false length=104 bytes=00000000630a610a093837313330383531351203616c6c1a190a03616c6c121209295c8fc2f5280440117ced9925019a49401a190a0332323912120966666666...
10 Oct 2024 14:21:56.230 DEBUG [grpc-default-worker-ELG-1-3] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0x570b03f2, L:/10.23.8.245:46916 - R:10.51.241.228/10.51.241.228:9090] INBOUND HEADERS: streamId=1909 headers=GrpcHttp2ResponseHeaders[grpc-status: 0, grpc-message: ] padding=0 endStream=true
10 Oct 2024 14:21:57.239 DEBUG [grpc-default-worker-ELG-1-3] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0x570b03f2, L:/10.23.8.245:46916 - R:10.51.241.228/10.51.241.228:9090] OUTBOUND HEADERS: streamId=1911 headers=GrpcHttp2OutboundHeaders[:authority: dynamic-bid-floor.dynamic-bid-floor-prod.svc.cluster.local:9090, :path: /dynamicbidfloor.DynamicBidFloorService/GetDynamicBidFloor, :method: POST, :scheme: http, content-type: application/grpc, te: trailers, user-agent: grpc-java-netty/1.67.1, traceparent: 00-f28e58f354b594a92fff2bc91a4c72a1-69481ed4e7354996-00, grpc-accept-encoding: gzip] streamDependency=0 weight=16 exclusive=false padding=0 endStream=false
10 Oct 2024 14:21:57.239 DEBUG [grpc-default-worker-ELG-1-3] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0x570b03f2, L:/10.23.8.245:46916 - R:10.51.241.228/10.51.241.228:9090] OUTBOUND DATA: streamId=1911 padding=0 endStream=true length=238 bytes=00000000e90a093843554b354235354c10890218042a0e6d61696c2e7961686f6f2e636f6d32024b533865420c6578706c6f69746174696f6e48015216687474...
10 Oct 2024 14:21:57.239 DEBUG [grpc-default-worker-ELG-1-3] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0x570b03f2, L:/10.23.8.245:46916 - R:10.51.241.228/10.51.241.228:9090] INBOUND WINDOW_UPDATE: streamId=0 windowSizeIncrement=238
10 Oct 2024 14:21:57.239 DEBUG [grpc-default-worker-ELG-1-3] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0x570b03f2, L:/10.23.8.245:46916 - R:10.51.241.228/10.51.241.228:9090] INBOUND PING: ack=false bytes=145258749040133895
10 Oct 2024 14:21:57.239 DEBUG [grpc-default-worker-ELG-1-3] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0x570b03f2, L:/10.23.8.245:46916 - R:10.51.241.228/10.51.241.228:9090] OUTBOUND PING: ack=true bytes=145258749040133895
10 Oct 2024 14:21:57.240 DEBUG [grpc-default-worker-ELG-1-3] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0x570b03f2, L:/10.23.8.245:46916 - R:10.51.241.228/10.51.241.228:9090] INBOUND HEADERS: streamId=1911 headers=GrpcHttp2ResponseHeaders[:status: 200, content-type: application/grpc] padding=0 endStream=false
10 Oct 2024 14:21:57.240 DEBUG [grpc-default-worker-ELG-1-3] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0x570b03f2, L:/10.23.8.245:46916 - R:10.51.241.228/10.51.241.228:9090] INBOUND DATA: streamId=1911 padding=0 endStream=false length=50 bytes=000000002d0a2b0a093539353832343031351203616c6c1a190a03616c6c1212099a9999999999fd3f1105172b6a30453440
10 Oct 2024 14:21:57.240 DEBUG [grpc-default-worker-ELG-1-3] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0x570b03f2, L:/10.23.8.245:46916 - R:10.51.241.228/10.51.241.228:9090] INBOUND HEADERS: streamId=1911 headers=GrpcHttp2ResponseHeaders[grpc-status: 0, grpc-message: ] padding=0 endStream=true
10 Oct 2024 14:21:58.408 DEBUG [grpc-default-worker-ELG-1-3] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0x570b03f2, L:/10.23.8.245:46916 - R:10.51.241.228/10.51.241.228:9090] OUTBOUND HEADERS: streamId=1913 headers=GrpcHttp2OutboundHeaders[:authority: dynamic-bid-floor.dynamic-bid-floor-prod.svc.cluster.local:9090, :path: /dynamicbidfloor.DynamicBidFloorService/GetDynamicBidFloor, :method: POST, :scheme: http, content-type: application/grpc, te: trailers, user-agent: grpc-java-netty/1.67.1, traceparent: 00-d207e075875e6aeee19c6bd08c5dc843-c37b85e37014a5c5-00, grpc-accept-encoding: gzip] streamDependency=0 weight=16 exclusive=false padding=0 endStream=false
10 Oct 2024 14:21:58.408 DEBUG [grpc-default-worker-ELG-1-3] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0x570b03f2, L:/10.23.8.245:46916 - R:10.51.241.228/10.51.241.228:9090] OUTBOUND DATA: streamId=1913 padding=0 endStream=true length=245 bytes=00000000f00a093843554b303336335210890218042a0b7175697a6c65742e636f6d32024e4a384d420c6578706c6f69746174696f6e4800524268747470733a...
10 Oct 2024 14:21:58.408 DEBUG [grpc-default-worker-ELG-1-3] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0x570b03f2, L:/10.23.8.245:46916 - R:10.51.241.228/10.51.241.228:9090] INBOUND WINDOW_UPDATE: streamId=0 windowSizeIncrement=245
10 Oct 2024 14:21:58.408 DEBUG [grpc-default-worker-ELG-1-3] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0x570b03f2, L:/10.23.8.245:46916 - R:10.51.241.228/10.51.241.228:9090] INBOUND PING: ack=false bytes=145258749040133895
10 Oct 2024 14:21:58.408 DEBUG [grpc-default-worker-ELG-1-3] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0x570b03f2, L:/10.23.8.245:46916 - R:10.51.241.228/10.51.241.228:9090] OUTBOUND PING: ack=true bytes=145258749040133895
10 Oct 2024 14:21:58.409 DEBUG [grpc-default-worker-ELG-1-3] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0x570b03f2, L:/10.23.8.245:46916 - R:10.51.241.228/10.51.241.228:9090] INBOUND HEADERS: streamId=1913 headers=GrpcHttp2ResponseHeaders[:status: 200, content-type: application/grpc] padding=0 endStream=false
10 Oct 2024 14:21:58.409 DEBUG [grpc-default-worker-ELG-1-3] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0x570b03f2, L:/10.23.8.245:46916 - R:10.51.241.228/10.51.241.228:9090] INBOUND DATA: streamId=1913 padding=0 endStream=false length=104 bytes=00000000630a610a093837313330383531351203616c6c1a190a033232391212097b14ae47e17a843f1100000000000059401a190a033239341212097b14ae47...
10 Oct 2024 14:21:58.409 DEBUG [grpc-default-worker-ELG-1-3] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0x570b03f2, L:/10.23.8.245:46916 - R:10.51.241.228/10.51.241.228:9090] INBOUND HEADERS: streamId=1913 headers=GrpcHttp2ResponseHeaders[grpc-status: 0, grpc-message: ] padding=0 endStream=true
10 Oct 2024 14:21:59.803 DEBUG [grpc-default-worker-ELG-1-3] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0x570b03f2, L:/10.23.8.245:46916 - R:10.51.241.228/10.51.241.228:9090] OUTBOUND HEADERS: streamId=1915 headers=GrpcHttp2OutboundHeaders[:authority: dynamic-bid-floor.dynamic-bid-floor-prod.svc.cluster.local:9090, :path: /dynamicbidfloor.DynamicBidFloorService/GetDynamicBidFloor, :method: POST, :scheme: http, content-type: application/grpc, te: trailers, user-agent: grpc-java-netty/1.67.1, traceparent: 00-10b97cfefb5a2a1c6573111ed7cbb131-2b6aec4fb66c5ed3-00, grpc-accept-encoding: gzip] streamDependency=0 weight=16 exclusive=false padding=0 endStream=false
10 Oct 2024 14:21:59.803 DEBUG [grpc-default-worker-ELG-1-3] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0x570b03f2, L:/10.23.8.245:46916 - R:10.51.241.228/10.51.241.228:9090] OUTBOUND DATA: streamId=1915 padding=0 endStream=true length=242 bytes=00000000ed0a093843554b303336335210890218042a0b7175697a6c65742e636f6d32024e593865420c6578706c6f69746174696f6e4800524468747470733a...
10 Oct 2024 14:21:59.803 DEBUG [grpc-default-worker-ELG-1-3] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0x570b03f2, L:/10.23.8.245:46916 - R:10.51.241.228/10.51.241.228:9090] INBOUND WINDOW_UPDATE: streamId=0 windowSizeIncrement=242
10 Oct 2024 14:21:59.803 DEBUG [grpc-default-worker-ELG-1-3] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0x570b03f2, L:/10.23.8.245:46916 - R:10.51.241.228/10.51.241.228:9090] INBOUND PING: ack=false bytes=145258749040133895
10 Oct 2024 14:21:59.803 DEBUG [grpc-default-worker-ELG-1-3] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0x570b03f2, L:/10.23.8.245:46916 - R:10.51.241.228/10.51.241.228:9090] OUTBOUND PING: ack=true bytes=145258749040133895
10 Oct 2024 14:21:59.804 DEBUG [grpc-default-worker-ELG-1-3] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0x570b03f2, L:/10.23.8.245:46916 - R:10.51.241.228/10.51.241.228:9090] INBOUND HEADERS: streamId=1915 headers=GrpcHttp2ResponseHeaders[:status: 200, content-type: application/grpc] padding=0 endStream=false
10 Oct 2024 14:21:59.804 DEBUG [grpc-default-worker-ELG-1-3] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0x570b03f2, L:/10.23.8.245:46916 - R:10.51.241.228/10.51.241.228:9090] INBOUND DATA: streamId=1915 padding=0 endStream=false length=77 bytes=00000000480a460a093238323435343632361203616c6c1a190a03616c6c1212099a9999999999b93f11c3b645990d722c401a190a033232391212099a999999...
10 Oct 2024 14:21:59.804 DEBUG [grpc-default-worker-ELG-1-3] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0x570b03f2, L:/10.23.8.245:46916 - R:10.51.241.228/10.51.241.228:9090] INBOUND HEADERS: streamId=1915 headers=GrpcHttp2ResponseHeaders[grpc-status: 0, grpc-message: ] padding=0 endStream=true

Here if you notice the server IP: 10.51.241.228 is correctly sending and receiving requests via service dynamic-bid-floor.dynamic-bid-floor-prod.svc.cluster.local

But just after the last timestamp:

10 Oct 2024 14:21:59.071 DEBUG [grpc-default-worker-ELG-1-7] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0xbc1a6b74, L:/10.23.8.245:33726 - R:10.51.241.228/10.51.241.228:9090] OUTBOUND HEADERS: streamId=119177 headers=GrpcHttp2OutboundHeaders[:authority: dmm-grpc.dmm-prod.svc.cluster.local:9090, :path: /dmm.DMMService/GetBid, :method: POST, :scheme: http, content-type: application/grpc, te: trailers, user-agent: grpc-java-netty/1.67.1, itype: nimbus, customer: 8CUPW8R2P, app_type: common, traceparent: 00-e726fe924bf27a8c480be6524005becf-96e0ac190114eb51-00, grpc-accept-encoding: gzip] streamDependency=0 weight=16 exclusive=false padding=0 endStream=false
10 Oct 2024 14:21:59.071 DEBUG [grpc-default-worker-ELG-1-7] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0xbc1a6b74, L:/10.23.8.245:33726 - R:10.51.241.228/10.51.241.228:9090] OUTBOUND DATA: streamId=119177 padding=0 endStream=true length=714 bytes=00000002c509333333333333c33f110ad7a3703d0ac73f2207333030783235303201333a1b3931323339303638372d6e696d6275732d6170702e696d6e617070...
10 Oct 2024 14:21:59.072 DEBUG [grpc-default-worker-ELG-1-7] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0xbc1a6b74, L:/10.23.8.245:33726 - R:10.51.241.228/10.51.241.228:9090] INBOUND WINDOW_UPDATE: streamId=0 windowSizeIncrement=714
10 Oct 2024 14:21:59.072 DEBUG [grpc-default-worker-ELG-1-7] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0xbc1a6b74, L:/10.23.8.245:33726 - R:10.51.241.228/10.51.241.228:9090] INBOUND PING: ack=false bytes=145258749040133895
10 Oct 2024 14:21:59.072 DEBUG [grpc-default-worker-ELG-1-7] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0xbc1a6b74, L:/10.23.8.245:33726 - R:10.51.241.228/10.51.241.228:9090] OUTBOUND PING: ack=true bytes=145258749040133895
10 Oct 2024 14:21:59.072 DEBUG [grpc-default-worker-ELG-1-7] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0xbc1a6b74, L:/10.23.8.245:33726 - R:10.51.241.228/10.51.241.228:9090] INBOUND HEADERS: streamId=119177 headers=GrpcHttp2ResponseHeaders[:status: 200, content-type: application/grpc, grpc-status: 12, grpc-message: unknown service dmm.DMMService] padding=0 endStream=true
10 Oct 2024 14:21:59.089 DEBUG [grpc-default-worker-ELG-1-7] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0xbc1a6b74, L:/10.23.8.245:33726 - R:10.51.241.228/10.51.241.228:9090] OUTBOUND HEADERS: streamId=119179 headers=GrpcHttp2OutboundHeaders[:authority: dmm-grpc.dmm-prod.svc.cluster.local:9090, :path: /dmm.DMMService/GetBid, :method: POST, :scheme: http, content-type: application/grpc, te: trailers, user-agent: grpc-java-netty/1.67.1, itype: prebid, customer: 8CU92U75D, app_type: common, traceparent: 00-80865e35f9929b2f6de281484443fd69-e2af58d0931f6ba2-00, grpc-accept-encoding: gzip] streamDependency=0 weight=16 exclusive=false padding=0 endStream=false
10 Oct 2024 14:21:59.089 DEBUG [grpc-default-worker-ELG-1-7] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0xbc1a6b74, L:/10.23.8.245:33726 - R:10.51.241.228/10.51.241.228:9090] OUTBOUND DATA: streamId=119179 padding=0 endStream=true length=954 bytes=00000003b5097b14ae47e17a843f11bdc62e51bd35a83f2207333230783130303201333a126265737463726f7373776f7264732e636f6d42526265737463726f...
10 Oct 2024 14:21:59.090 DEBUG [grpc-default-worker-ELG-1-7] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0xbc1a6b74, L:/10.23.8.245:33726 - R:10.51.241.228/10.51.241.228:9090] INBOUND WINDOW_UPDATE: streamId=0 windowSizeIncrement=954
10 Oct 2024 14:21:59.090 DEBUG [grpc-default-worker-ELG-1-7] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0xbc1a6b74, L:/10.23.8.245:33726 - R:10.51.241.228/10.51.241.228:9090] INBOUND PING: ack=false bytes=145258749040133895
10 Oct 2024 14:21:59.090 DEBUG [grpc-default-worker-ELG-1-7] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0xbc1a6b74, L:/10.23.8.245:33726 - R:10.51.241.228/10.51.241.228:9090] OUTBOUND PING: ack=true bytes=145258749040133895
10 Oct 2024 14:21:59.090 DEBUG [grpc-default-worker-ELG-1-7] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0xbc1a6b74, L:/10.23.8.245:33726 - R:10.51.241.228/10.51.241.228:9090] INBOUND HEADERS: streamId=119179 headers=GrpcHttp2ResponseHeaders[:status: 200, content-type: application/grpc, grpc-status: 12, grpc-message: unknown service dmm.DMMService] padding=0 endStream=true
10 Oct 2024 14:21:59.117 DEBUG [grpc-default-worker-ELG-1-7] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0xbc1a6b74, L:/10.23.8.245:33726 - R:10.51.241.228/10.51.241.228:9090] OUTBOUND HEADERS: streamId=119181 headers=GrpcHttp2OutboundHeaders[:authority: dmm-grpc.dmm-prod.svc.cluster.local:9090, :path: /dmm.DMMService/GetBid, :method: POST, :scheme: http, content-type: application/grpc, te: trailers, user-agent: grpc-java-netty/1.67.1, itype: prebid, customer: 8CUPK277N, app_type: common, traceparent: 00-6fd7c2aaf70a5c5f5279b81bfb045bc7-cda97fdd945a787e-00, grpc-accept-encoding: gzip] streamDependency=0 weight=16 exclusive=false padding=0 endStream=false
10 Oct 2024 14:21:59.117 DEBUG [grpc-default-worker-ELG-1-7] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0xbc1a6b74, L:/10.23.8.245:33726 - R:10.51.241.228/10.51.241.228:9090] OUTBOUND DATA: streamId=119181 padding=0 endStream=true length=2805 bytes=0000000af0099a9999999999b93f11cdccccccccccdc3f19cdccccccccccdc3f22063332307835303201333a146d65646963616c6e657773746f6461792e636f...
10 Oct 2024 14:21:59.117 DEBUG [grpc-default-worker-ELG-1-7] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0xbc1a6b74, L:/10.23.8.245:33726 - R:10.51.241.228/10.51.241.228:9090] INBOUND WINDOW_UPDATE: streamId=0 windowSizeIncrement=2805
10 Oct 2024 14:21:59.117 DEBUG [grpc-default-worker-ELG-1-7] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0xbc1a6b74, L:/10.23.8.245:33726 - R:10.51.241.228/10.51.241.228:9090] INBOUND PING: ack=false bytes=145258749040133895
10 Oct 2024 14:21:59.117 DEBUG [grpc-default-worker-ELG-1-7] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0xbc1a6b74, L:/10.23.8.245:33726 - R:10.51.241.228/10.51.241.228:9090] OUTBOUND PING: ack=true bytes=145258749040133895
10 Oct 2024 14:21:59.117 DEBUG [grpc-default-worker-ELG-1-7] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0xbc1a6b74, L:/10.23.8.245:33726 - R:10.51.241.228/10.51.241.228:9090] INBOUND HEADERS: streamId=119181 headers=GrpcHttp2ResponseHeaders[:status: 200, content-type: application/grpc, grpc-status: 12, grpc-message: unknown service dmm.DMMService] padding=0 endStream=true
10 Oct 2024 14:21:59.118 DEBUG [grpc-default-worker-ELG-1-7] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0xbc1a6b74, L:/10.23.8.245:33726 - R:10.51.241.228/10.51.241.228:9090] OUTBOUND HEADERS: streamId=119183 headers=GrpcHttp2OutboundHeaders[:authority: dmm-grpc.dmm-prod.svc.cluster.local:9090, :path: /dmm.DMMService/GetBid, :method: POST, :scheme: http, content-type: application/grpc, te: trailers, user-agent: grpc-java-netty/1.67.1, itype: prebid, customer: 8CU4WQK98, app_type: common, traceparent: 00-0f7609092a888850ebc2ca801dc10889-22eda93eaea3b9cd-00, grpc-accept-encoding: gzip] streamDependency=0 weight=16 exclusive=false padding=0 endStream=false
10 Oct 2024 14:21:59.118 DEBUG [grpc-default-worker-ELG-1-7] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0xbc1a6b74, L:/10.23.8.245:33726 - R:10.51.241.228/10.51.241.228:9090] OUTBOUND DATA: streamId=119183 padding=0 endStream=true length=837 bytes=00000003400900000000000000001196438b6ce7fbed3f2207333030783235303201333a0b6e7974696d65732e636f6d42466e7974696d65732e636f6d2f6c69...
10 Oct 2024 14:21:59.118 DEBUG [grpc-default-worker-ELG-1-7] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0xbc1a6b74, L:/10.23.8.245:33726 - R:10.51.241.228/10.51.241.228:9090] INBOUND WINDOW_UPDATE: streamId=0 windowSizeIncrement=837
10 Oct 2024 14:21:59.118 DEBUG [grpc-default-worker-ELG-1-7] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0xbc1a6b74, L:/10.23.8.245:33726 - R:10.51.241.228/10.51.241.228:9090] INBOUND PING: ack=false bytes=145258749040133895
10 Oct 2024 14:21:59.118 DEBUG [grpc-default-worker-ELG-1-7] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0xbc1a6b74, L:/10.23.8.245:33726 - R:10.51.241.228/10.51.241.228:9090] OUTBOUND PING: ack=true bytes=145258749040133895
10 Oct 2024 14:21:59.118 DEBUG [grpc-default-worker-ELG-1-7] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0xbc1a6b74, L:/10.23.8.245:33726 - R:10.51.241.228/10.51.241.228:9090] INBOUND HEADERS: streamId=119183 headers=GrpcHttp2ResponseHeaders[:status: 200, content-type: application/grpc, grpc-status: 12, grpc-message: unknown service dmm.DMMService] padding=0 endStream=true
10 Oct 2024 14:21:59.122 DEBUG [grpc-default-worker-ELG-1-7] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0xbc1a6b74, L:/10.23.8.245:33726 - R:10.51.241.228/10.51.241.228:9090] OUTBOUND HEADERS: streamId=119185 headers=GrpcHttp2OutboundHeaders[:authority: dmm-grpc.dmm-prod.svc.cluster.local:9090, :path: /dmm.DMMService/GetBid, :method: POST, :scheme: http, content-type: application/grpc, te: trailers, user-agent: grpc-java-netty/1.67.1, itype: prebid, customer: 8CUUIR166, app_type: common, traceparent: 00-5fd62d54469a2d10bf99202d32d6fc76-9cabdae243ed9dcf-00, grpc-accept-encoding: gzip] streamDependency=0 weight=16 exclusive=false padding=0 endStream=false
10 Oct 2024 14:21:59.122 DEBUG [grpc-default-worker-ELG-1-7] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0xbc1a6b74, L:/10.23.8.245:33726 - R:10.51.241.228/10.51.241.228:9090] OUTBOUND DATA: streamId=119185 padding=0 endStream=true length=920 bytes=000000039309000000000000000011986e1283c0cae53f2207333336783238303201333a127477656e747974776f776f7264732e636f6d424c7477656e747974...
10 Oct 2024 14:21:59.122 DEBUG [grpc-default-worker-ELG-1-7] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0xbc1a6b74, L:/10.23.8.245:33726 - R:10.51.241.228/10.51.241.228:9090] INBOUND WINDOW_UPDATE: streamId=0 windowSizeIncrement=920
10 Oct 2024 14:21:59.122 DEBUG [grpc-default-worker-ELG-1-7] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0xbc1a6b74, L:/10.23.8.245:33726 - R:10.51.241.228/10.51.241.228:9090] INBOUND PING: ack=false bytes=145258749040133895
10 Oct 2024 14:21:59.122 DEBUG [grpc-default-worker-ELG-1-7] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0xbc1a6b74, L:/10.23.8.245:33726 - R:10.51.241.228/10.51.241.228:9090] OUTBOUND PING: ack=true bytes=145258749040133895
10 Oct 2024 14:21:59.122 DEBUG [grpc-default-worker-ELG-1-7] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0xbc1a6b74, L:/10.23.8.245:33726 - R:10.51.241.228/10.51.241.228:9090] INBOUND HEADERS: streamId=119185 headers=GrpcHttp2ResponseHeaders[:status: 200, content-type: application/grpc, grpc-status: 12, grpc-message: unknown service dmm.DMMService] padding=0 endStream=true
10 Oct 2024 14:21:59.151 DEBUG [grpc-default-worker-ELG-1-7] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0xbc1a6b74, L:/10.23.8.245:33726 - R:10.51.241.228/10.51.241.228:9090] OUTBOUND HEADERS: streamId=119187 headers=GrpcHttp2OutboundHeaders[:authority: dmm-grpc.dmm-prod.svc.cluster.local:9090, :path: /dmm.DMMService/GetBid, :method: POST, :scheme: http, content-type: application/grpc, te: trailers, user-agent: grpc-java-netty/1.67.1, itype: nimbus, customer: 8CUV26P79, app_type: common, traceparent: 00-7c2a2e26d8a5d77cc759bfb4b7ff3445-d15da4b3a6579fc8-00, grpc-accept-encoding: gzip] streamDependency=0 weight=16 exclusive=false padding=0 endStream=false
10 Oct 2024 14:21:59.151 DEBUG [grpc-default-worker-ELG-1-7] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0xbc1a6b74, L:/10.23.8.245:33726 - R:10.51.241.228/10.51.241.228:9090] OUTBOUND DATA: streamId=119187 padding=0 endStream=true length=826 bytes=0000000335097b14ae47e17ac43f11ba490c022b87c63f2207333230783438303201333a1c636f6d2d74696e6465722d6e696d6275732d6170702e616d6e6170...
10 Oct 2024 14:21:59.153 DEBUG [grpc-default-worker-ELG-1-7] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0xbc1a6b74, L:/10.23.8.245:33726 - R:10.51.241.228/10.51.241.228:9090] INBOUND WINDOW_UPDATE: streamId=0 windowSizeIncrement=826
10 Oct 2024 14:21:59.153 DEBUG [grpc-default-worker-ELG-1-7] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0xbc1a6b74, L:/10.23.8.245:33726 - R:10.51.241.228/10.51.241.228:9090] INBOUND PING: ack=false bytes=145258749040133895
10 Oct 2024 14:21:59.153 DEBUG [grpc-default-worker-ELG-1-7] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0xbc1a6b74, L:/10.23.8.245:33726 - R:10.51.241.228/10.51.241.228:9090] OUTBOUND PING: ack=true bytes=145258749040133895
10 Oct 2024 14:21:59.153 DEBUG [grpc-default-worker-ELG-1-7] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0xbc1a6b74, L:/10.23.8.245:33726 - R:10.51.241.228/10.51.241.228:9090] INBOUND HEADERS: streamId=119187 headers=GrpcHttp2ResponseHeaders[:status: 200, content-type: application/grpc, grpc-status: 12, grpc-message: unknown service dmm.DMMService] padding=0 endStream=true
10 Oct 2024 14:21:59.154 DEBUG [grpc-default-worker-ELG-1-7] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0xbc1a6b74, L:/10.23.8.245:33726 - R:10.51.241.228/10.51.241.228:9090] OUTBOUND HEADERS: streamId=119189 headers=GrpcHttp2OutboundHeaders[:authority: dmm-grpc.dmm-prod.svc.cluster.local:9090, :path: /dmm.DMMService/GetBid, :method: POST, :scheme: http, content-type: application/grpc, te: trailers, user-agent: grpc-java-netty/1.67.1, itype: mediavine, customer: 8CUG3CC31, app_type: common, traceparent: 00-d5e29a41e072bc09e93b5ed921c51ce5-feec25b038859701-00, grpc-accept-encoding: gzip] streamDependency=0 weight=16 exclusive=false padding=0 endStream=false
10 Oct 2024 14:21:59.154 DEBUG [grpc-default-worker-ELG-1-7] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0xbc1a6b74, L:/10.23.8.245:33726 - R:10.51.241.228/10.51.241.228:9090] OUTBOUND DATA: streamId=119189 padding=0 endStream=true length=907 bytes=000000038609295c8fc2f528bc3f119eefa7c64b37c93f22033178313201333a146672657368617072696c666c6f7572732e636f6d422c667265736861707269...
10 Oct 2024 14:21:59.156 DEBUG [grpc-default-worker-ELG-1-7] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0xbc1a6b74, L:/10.23.8.245:33726 - R:10.51.241.228/10.51.241.228:9090] INBOUND WINDOW_UPDATE: streamId=0 windowSizeIncrement=907
10 Oct 2024 14:21:59.156 DEBUG [grpc-default-worker-ELG-1-7] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0xbc1a6b74, L:/10.23.8.245:33726 - R:10.51.241.228/10.51.241.228:9090] INBOUND PING: ack=false bytes=145258749040133895
10 Oct 2024 14:21:59.156 DEBUG [grpc-default-worker-ELG-1-7] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0xbc1a6b74, L:/10.23.8.245:33726 - R:10.51.241.228/10.51.241.228:9090] OUTBOUND PING: ack=true bytes=145258749040133895
10 Oct 2024 14:21:59.156 DEBUG [grpc-default-worker-ELG-1-7] io.grpc.netty.shaded.io.grpc.netty.NettyClientHandler - [id: 0xbc1a6b74, L:/10.23.8.245:33726 - R:10.51.241.228/10.51.241.228:9090] INBOUND HEADERS: streamId=119189 headers=GrpcHttp2ResponseHeaders[:status: 200, content-type: application/grpc, grpc-status: 12, grpc-message: unknown service dmm.DMMService] padding=0 endStream=true

it starts calling dmm-grpc.dmm-prod.svc.cluster.local for the same IP, while as you can see both the services are presnet in different namespaces (although in the same cluster). Also the since the server is responding with status code 12 hence it is live and the IP is not re-assigned to the other service or anything.

The same is not happening for the version 1.66

ejona86 commented 2 days ago

Istio is broken with gRPC Java 1.67+: https://github.com/istio/istio/issues/53532 . I wonder if it can send responses on the wrong stream, in addition to closing other streams. (... although the resource names would also have to be wrong...)