grpc / grpc/grpc-node

gRPC-JS client hangs when target server restarts

Open
#2,785 5 comments 0 reactions 0 assignees View on GitHub
package: @grpc/grpc-js requires reporter action
Dominant language
TypeScript
Stars
4.8k
Forks
716
Avg merge
2d 3h
Merged PRs (30d)
10

Description

### Problem description

gRPC js client freezes on server disconnections, require full client restarts

### Reproduction steps

We have a server (server API is gRPC, using malijs), let's call it **A** which calls a gRPC target proxied by an NLB and nginx gRPC ingress, let's call it **B**. If we go ahead and restart the target instances of **B**, The client might sometime hang, resulting in the application **A** failing to function. All flows calling to A that will result in **A** calling **B** will hang

The moment we restart **A**, it becomes functioning, meaning it's a client state issue.

### Environment

- Debian 11/12 based containers
- Node version: 18.20.x and 22.2.x
- NVM based installation
- gRPC-JS 1.19.15
- Client options: `{ 'grpc.keepalive_time_ms': 10_000, 'grpc.max_receive_message_length': 64 * 1024 * 1024 }`

### Additional context

We've activated gRPC tracing on server **A**

here's what a normal server selection trace looks like:

```
D 2024-07-04T09:37:26.487Z | v1.9.15 29 | subchannel | (157) 10.41.10.107:443 READY -> IDLE
D 2024-07-04T09:37:26.487Z | v1.9.15 29 | subchannel_refcount | (157) 10.41.10.107:443 refcount 2 -> 1
D 2024-07-04T09:37:26.487Z | v1.9.15 29 | pick_first | READY -> IDLE
D 2024-07-04T09:37:26.487Z | v1.9.15 29 | resolving_load_balancer | dns:service-b.internal.com:443 READY -> IDLE
D 2024-07-04T09:37:26.487Z | v1.9.15 29 | connectivity_state | (2) dns:service-b.internal.com:443 READY -> IDLE
D 2024-07-04T09:37:26.487Z | v1.9.15 29 | dns_resolver | Looking up DNS hostname service-b.internal.com
D 2024-07-04T09:37:26.487Z | v1.9.15 29 | resolving_load_balancer | dns:service-b.internal.com:443 IDLE -> CONNECTING
D 2024-07-04T09:37:26.487Z | v1.9.15 29 | connectivity_state | (2) dns:service-b.internal.com:443 IDLE -> CONNECTING
D 2024-07-04T09:37:26.492Z | v1.9.15 29 | dns_resolver | Resolved addresses for target dns:service-b.internal.com:443: [10.41.33.32:443,10.41.22.168:443,10.41.10.107:443]
D 2024-07-04T09:37:26.492Z | v1.9.15 29 | subchannel | (202) 10.41.33.32:443 Subchannel constructed with options {}
D 2024-07-04T09:37:26.492Z | v1.9.15 29 | subchannel_refcount | (202) 10.41.33.32:443 refcount 0 -> 1
D 2024-07-04T09:37:26.492Z | v1.9.15 29 | subchannel | (203) 10.41.22.168:443 Subchannel constructed with options {}
D 2024-07-04T09:37:26.492Z | v1.9.15 29 | subchannel_refcount | (203) 10.41.22.168:443 refcount 0 -> 1
D 2024-07-04T09:37:26.492Z | v1.9.15 29 | subchannel_refcount | (202) 10.41.33.32:443 refcount 1 -> 2
D 2024-07-04T09:37:26.492Z | v1.9.15 29 | subchannel_refcount | (203) 10.41.22.168:443 refcount 1 -> 2
D 2024-07-04T09:37:26.492Z | v1.9.15 29 | subchannel_refcount | (157) 10.41.10.107:443 refcount 1 -> 2
D 2024-07-04T09:37:26.492Z | v1.9.15 29 | pick_first | Start connecting to subchannel with address 10.41.33.32:443
D 2024-07-04T09:37:26.492Z | v1.9.15 29 | pick_first | IDLE -> CONNECTING
D 2024-07-04T09:37:26.492Z | v1.9.15 29 | resolving_load_balancer | dns:service-b.internal.com:443 CONNECTING -> CONNECTING
D 2024-07-04T09:37:26.492Z | v1.9.15 29 | connectivity_state | (2) dns:service-b.internal.com:443 CONNECTING -> CONNECTING
D 2024-07-04T09:37:26.492Z | v1.9.15 29 | subchannel | (202) 10.41.33.32:443 IDLE -> CONNECTING
D 2024-07-04T09:37:26.499Z | v1.9.15 29 | subchannel | (202) 10.41.33.32:443 CONNECTING -> READY
D 2024-07-04T09:37:26.499Z | v1.9.15 29 | pick_first | Pick subchannel with address 10.41.33.32:443
D 2024-07-04T09:37:26.499Z | v1.9.15 29 | subchannel_refcount | (202) 10.41.33.32:443 refcount 2 -> 3
D 2024-07-04T09:37:26.499Z | v1.9.15 29 | subchannel_refcount | (202) 10.41.33.32:443 refcount 3 -> 2
D 2024-07-04T09:37:26.499Z | v1.9.15 29 | subchannel_refcount | (203) 10.41.22.168:443 refcount 2 -> 1
D 2024-07-04T09:37:26.499Z | v1.9.15 29 | subchannel_refcount | (157) 10.41.10.107:443 refcount 2 -> 1
D 2024-07-04T09:37:26.499Z | v1.9.15 29 | pick_first | CONNECTING -> READY
D 2024-07-04T09:37:26.499Z | v1.9.15 29 | resolving_load_balancer | dns:service-b.internal.com:443 CONNECTING -> READY
D 2024-07-04T09:37:26.499Z | v1.9.15 29 | connectivity_state | (2) dns:service-b.internal.com:443 CONNECTING -> READY
D 2024-07-04T09:37:30.637Z | v1.9.15 29 | subchannel_refcount | (157) 10.41.10.107:443 refcount 1 -> 0
```

As expected, connections enter into `TRANSIENT_FAILURE` state once I kill the target pods **B**. When they become responsive again, We get these messages:

```
D 2024-07-04T09:47:31.084Z | v1.9.15 29 | subchannel | (299) 10.41.22.168:443 CONNECTING -> TRANSIENT_FAILURE
D 2024-07-04T09:47:31.084Z | v1.9.15 29 | subchannel | (299) 10.41.22.168:443 TRANSIENT_FAILURE -> IDLE
D 2024-07-04T09:47:31.084Z | v1.9.15 29 | subchannel | (299) 10.41.22.168:443 IDLE -> CONNECTING
D 2024-07-04T09:47:31.084Z | v1.9.15 29 | subchannel | (300) 10.41.33.32:443 CONNECTING -> TRANSIENT_FAILURE
D 2024-07-04T09:47:31.084Z | v1.9.15 29 | subchannel | (300) 10.41.33.32:443 TRANSIENT_FAILURE -> IDLE
D 2024-07-04T09:47:31.084Z | v1.9.15 29 | subchannel | (300) 10.41.33.32:443 IDLE -> CONNECTING
D 2024-07-04T09:47:31.093Z | v1.9.15 29 | subchannel | (300) 10.41.33.32:443 CONNECTING -> READY
D 2024-07-04T09:47:31.094Z | v1.9.15 29 | pick_first | Pick subchannel with address 10.41.33.32:443
D 2024-07-04T09:47:31.094Z | v1.9.15 29 | subchannel_refcount | (300) 10.41.33.32:443 refcount 2 -> 3
D 2024-07-04T09:47:31.094Z | v1.9.15 29 | subchannel_refcount | (275) 10.41.10.107:443 refcount 2 -> 1
D 2024-07-04T09:47:31.094Z | v1.9.15 29 | subchannel_refcount | (300) 10.41.33.32:443 refcount 3 -> 2
D 2024-07-04T09:47:31.094Z | v1.9.15 29 | subchannel_refcount | (299) 10.41.22.168:443 refcount 2 -> 1
D 2024-07-04T09:47:31.094Z | v1.9.15 29 | pick_first | TRANSIENT_FAILURE -> READY
D 2024-07-04T09:47:31.094Z | v1.9.15 29 | resolving_load_balancer | dns:service-b.internal.com:443 TRANSIENT_FAILURE -> READY
D 2024-07-04T09:47:31.094Z | v1.9.15 29 | connectivity_state | (2) dns:service-b.internal.com:443 TRANSIENT_FAILURE -> READY
D 2024-07-04T09:47:31.109Z | v1.9.15 29 | subchannel | (299) 10.41.22.168:443 CONNECTING -> READY
```

And from that moment on, we stop seeing these messages altogether. As though the driver becomes stuck.

We still see these traces
```
D 2024-07-04T09:43:57.000Z | v1.9.15 29 | channel | (2) dns:service-b.internal.com:443 createResolvingCall [272] method="...", deadline=Infinity
D 2024-07-04T09:43:57.001Z | v1.9.15 29 | channel | (2) dns:service-b.internal.com:443 createRetryingCall [273] method="..."
D 2024-07-04T09:43:57.001Z | v1.9.15 29 | channel | (2) dns:service-b.internal.com:443 createLoadBalancingCall [274] method="..."
```

but no request is actuall being sent, the client is completely frozen. Any help will be much obliged

Contributor guide

Open the contributing guide

Assessment

This issue has not been assessed yet.

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.