Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

tryShutdown results in cancelled Unary GRPCs #2091

Closed
artificial-aidan opened this issue Apr 12, 2022 · 13 comments
Closed

tryShutdown results in cancelled Unary GRPCs #2091

artificial-aidan opened this issue Apr 12, 2022 · 13 comments

Comments

@artificial-aidan
Copy link

Problem description

When using tryShutdown to gracefully shutdown a server, it doesn't let unary RPCs finish successfully.

Reproduction steps

  1. Create GRPC server with unary handler that takes some extended amount of time
  2. Set up a process.on handler for SIGTERM
  3. Call Unary GRPC
  4. Before it completes send SIGTERM to the server process.
  5. Note that client never receives the correct response, just a cancelled call. Even though the server sends the correct data.

Environment

  • OS name, version and architecture: OSX 10.15.7
  • Node version 17.8.0
  • Package name and version [email protected]

Additional context

The normal process for a Unary RPC (that I can deduce from debugging) is as follows:

  1. Client opens stream to Server
  2. Client sends request to Server
  3. Server sends response to Client
  4. Client closes stream.

When using the tryShutdown method the process is different.

  1. Client opens stream to Server
  2. Client sends request to Server
  3. tryShutdown is called
  4. Server calls close on http2 session
  5. Server sends response to Client
  6. Client see's that stream has been cancelled, and errors.

The cancellation appears to be coming from the session destruction happening in tryShutdown. This makes sense for streaming GRPC calls, as they need to be cancelled, but a Unary GRPC should be able to finish its response without the call being cancelled.

Removing the session.close() from tryShutdown fixes the problem for Unary GRPCs, but obviously doesn't for Streaming GRPCs.

@murgatroid99
Copy link
Member

It's definitely not supposed to do that, for unary or streaming RPCs. And the session.close() documentation explicitly says that it doesn't do that, so this sounds like a bug in Node.

Have you tried listening for SIGUSR2 instead of SIGTERM, just to ensure that it's not impacted by some other signal handling? Or even just using a timer to consistently call tryShutdown inline? If that's not the issue, would you mind putting together and sharing a complete reproduction of this failure?

@artificial-aidan
Copy link
Author

I will try SIGUSR2. If that doesn't work I will put together something reproducible.

@artificial-aidan
Copy link
Author

Ok, confirmed with a timer.

https://github.com/artificial-aidan/grpc/tree/aidan/call-cancel

In one terminal run examples/node/static_codegen/greeter_server.js and within a few seconds run greeter_client.js in another terminal. You will get a call cancelled error on the client.

Edit server.js in node_modules and comment out the session closing.

Re-run the test. And you will get a successful message.

(grpc) Aidans-MBP:node aidan$ node static_codegen/greeter_client.js 
Error: 1 CANCELLED: Call cancelled
    at Object.callErrorFromStatus (/Users/aidan/Development/grpc/examples/node/node_modules/@grpc/grpc-js/build/src/call.js:31:26)
    at Object.onReceiveStatus (/Users/aidan/Development/grpc/examples/node/node_modules/@grpc/grpc-js/build/src/client.js:180:52)
    at Object.onReceiveStatus (/Users/aidan/Development/grpc/examples/node/node_modules/@grpc/grpc-js/build/src/client-interceptors.js:365:141)
    at Object.onReceiveStatus (/Users/aidan/Development/grpc/examples/node/node_modules/@grpc/grpc-js/build/src/client-interceptors.js:328:181)
    at /Users/aidan/Development/grpc/examples/node/node_modules/@grpc/grpc-js/build/src/call-stream.js:187:78
    at processTicksAndRejections (node:internal/process/task_queues:78:11) {
  code: 1,
  details: 'Call cancelled',
  metadata: Metadata { internalRepr: Map(0) {}, options: {} }
}

@artificial-aidan
Copy link
Author

artificial-aidan commented Apr 12, 2022

I debugged it to the level of when the stream events were being handled, but didn't go any deeper than that.

With grpc debugging and http2 debugging turned on here is the client and server output:

Server
D 2022-04-12T23:36:30.046Z | index | Loading @grpc/grpc-js version 1.6.3
D 2022-04-12T23:36:30.051Z | server | (1) Server constructed
D 2022-04-12T23:36:30.051Z | dns_resolver | Resolver constructed for target dns:0.0.0.0:50052
D 2022-04-12T23:36:30.053Z | dns_resolver | Returning IP address for target dns:0.0.0.0:50052
D 2022-04-12T23:36:30.055Z | server | (1) Attempting to bind 0.0.0.0:50052
D 2022-04-12T23:36:30.059Z | server | (1) Successfully bound 0.0.0.0:50052
gRPC server listening on port 50052
HTTP2 30362: Http2Session server: received a connection
HTTP2 30362: Http2Session server: setting up session handle
HTTP2 30362: Http2Session server: sending settings
HTTP2 30362: Http2Session server: submitting settings
HTTP2 30362: Http2Session server: created
(node:30362) Warning: Setting the NODE_DEBUG environment variable to 'http2' can expose sensitive data (such as passwords, tokens and authentication headers) in the resulting log.
(Use `node --trace-warnings ...` to show where the warning was created)
HTTP2 30362: Http2Stream 1 [Http2Session server]: headers received
D 2022-04-12T23:36:32.487Z | server | (1) Received call to method /helloworld.Greeter/SayHello at address 0.0.0.0:50052
sleeping
HTTP2 30362: Http2Session server: settings received
shutting down
HTTP2 30362: Http2Session server: marking session closed
HTTP2 30362: Http2Session server: submitting goaway
HTTP2 30362: Http2Session server: goaway 0 received [last stream id: 0]
slept
HTTP2 30362: Http2Stream 1 [Http2Session server]: initiating response
D 2022-04-12T23:36:42.497Z | server_call | Request to method /helloworld.Greeter/SayHello ended with status code: OK details: OK
HTTP2 30362: Http2Stream 1 [Http2Session server]: shutting down writable on _final
HTTP2 30362: Http2Stream 1 [Http2Session server]: sending trailers
HTTP2 30362: Http2Stream 1 [Http2Session server]: closed with code 0, closed false, readable false
HTTP2 30362: Http2Stream 1 [Http2Session server]: destroying stream
HTTP2 30362: Http2Session server: destroying
HTTP2 30362: Http2Session server: start closing/destroying undefined
HTTP2 30362: Http2Session server: finishSessionClose
D 2022-04-12T23:36:42.500Z | server_call | Request to method /helloworld.Greeter/SayHello stream closed with rstCode 0
HTTP2 30362: Http2Session server: finishSessionClose socket end undefined undefined
shutdown
Client
D 2022-04-12T23:36:32.445Z | index | Loading @grpc/grpc-js version 1.6.3
D 2022-04-12T23:36:32.452Z | resolving_load_balancer | dns:localhost:50052 IDLE -> IDLE
D 2022-04-12T23:36:32.452Z | connectivity_state | (1) dns:localhost:50052 IDLE -> IDLE
D 2022-04-12T23:36:32.453Z | dns_resolver | Resolver constructed for target dns:localhost:50052
D 2022-04-12T23:36:32.454Z | channel | (1) dns:localhost:50052 Channel constructed with options {}
D 2022-04-12T23:36:32.454Z | channel_stacktrace | (1) Channel constructed 
    at new ChannelImplementation (/Users/aidan/Development/grpc/examples/node/node_modules/@grpc/grpc-js/build/src/channel.js:189:23)
    at new Client (/Users/aidan/Development/grpc/examples/node/node_modules/@grpc/grpc-js/build/src/client.js:62:36)
    at new ServiceClientImpl (/Users/aidan/Development/grpc/examples/node/node_modules/@grpc/grpc-js/build/src/make-client.js:58:5)
    at main (/Users/aidan/Development/grpc/examples/node/static_codegen/greeter_client.js:35:16)
    at Object.<anonymous> (/Users/aidan/Development/grpc/examples/node/static_codegen/greeter_client.js:51:1)
    at Module._compile (node:internal/modules/cjs/loader:1099:14)
    at Object.Module._extensions..js (node:internal/modules/cjs/loader:1153:10)
    at Module.load (node:internal/modules/cjs/loader:975:32)
    at Function.Module._load (node:internal/modules/cjs/loader:822:12)
    at Function.executeUserEntryPoint [as runMain] (node:internal/modules/run_main:77:12)
D 2022-04-12T23:36:32.456Z | channel | (1) dns:localhost:50052 createCall [0] method="/helloworld.Greeter/SayHello", deadline=Infinity
D 2022-04-12T23:36:32.457Z | call_stream | [0] Sending metadata
D 2022-04-12T23:36:32.458Z | dns_resolver | Looking up DNS hostname localhost
D 2022-04-12T23:36:32.459Z | resolving_load_balancer | dns:localhost:50052 IDLE -> CONNECTING
D 2022-04-12T23:36:32.459Z | connectivity_state | (1) dns:localhost:50052 IDLE -> CONNECTING
D 2022-04-12T23:36:32.459Z | resolving_load_balancer | dns:localhost:50052 CONNECTING -> CONNECTING
D 2022-04-12T23:36:32.459Z | connectivity_state | (1) dns:localhost:50052 CONNECTING -> CONNECTING
D 2022-04-12T23:36:32.460Z | channel | (1) dns:localhost:50052 callRefTimer.ref | configSelectionQueue.length=1 pickQueue.length=0
D 2022-04-12T23:36:32.461Z | call_stream | [0] write() called with message of length 7
D 2022-04-12T23:36:32.461Z | call_stream | [0] end() called
D 2022-04-12T23:36:32.462Z | call_stream | [0] deferring writing data chunk of length 12
D 2022-04-12T23:36:32.464Z | dns_resolver | Resolved addresses for target dns:localhost:50052: [::1:50052,127.0.0.1:50052]
D 2022-04-12T23:36:32.465Z | pick_first | Connect to address list ::1:50052,127.0.0.1:50052
D 2022-04-12T23:36:32.465Z | subchannel | (2) ::1:50052 Subchannel constructed with options {}
D 2022-04-12T23:36:32.465Z | subchannel_refcount | (2) ::1:50052 refcount 0 -> 1
D 2022-04-12T23:36:32.466Z | subchannel | (3) 127.0.0.1:50052 Subchannel constructed with options {}
D 2022-04-12T23:36:32.466Z | subchannel_refcount | (3) 127.0.0.1:50052 refcount 0 -> 1
D 2022-04-12T23:36:32.466Z | subchannel_refcount | (2) ::1:50052 refcount 1 -> 2
D 2022-04-12T23:36:32.466Z | subchannel_refcount | (3) 127.0.0.1:50052 refcount 1 -> 2
D 2022-04-12T23:36:32.466Z | pick_first | Start connecting to subchannel with address ::1:50052
D 2022-04-12T23:36:32.466Z | pick_first | IDLE -> CONNECTING
D 2022-04-12T23:36:32.466Z | resolving_load_balancer | dns:localhost:50052 CONNECTING -> CONNECTING
D 2022-04-12T23:36:32.466Z | channel | (1) dns:localhost:50052 callRefTimer.unref | configSelectionQueue.length=1 pickQueue.length=0
D 2022-04-12T23:36:32.466Z | connectivity_state | (1) dns:localhost:50052 CONNECTING -> CONNECTING
D 2022-04-12T23:36:32.467Z | subchannel | (2) ::1:50052 IDLE -> CONNECTING
D 2022-04-12T23:36:32.467Z | pick_first | CONNECTING -> CONNECTING
D 2022-04-12T23:36:32.467Z | resolving_load_balancer | dns:localhost:50052 CONNECTING -> CONNECTING
D 2022-04-12T23:36:32.467Z | connectivity_state | (1) dns:localhost:50052 CONNECTING -> CONNECTING
D 2022-04-12T23:36:32.468Z | channel | (1) dns:localhost:50052 Pick result for call [0]: QUEUE subchannel: null status: undefined undefined
D 2022-04-12T23:36:32.468Z | channel | (1) dns:localhost:50052 callRefTimer.ref | configSelectionQueue.length=0 pickQueue.length=1
D 2022-04-12T23:36:32.468Z | subchannel | (3) 127.0.0.1:50052 IDLE -> CONNECTING
D 2022-04-12T23:36:32.468Z | pick_first | CONNECTING -> CONNECTING
D 2022-04-12T23:36:32.468Z | resolving_load_balancer | dns:localhost:50052 CONNECTING -> CONNECTING
D 2022-04-12T23:36:32.468Z | channel | (1) dns:localhost:50052 callRefTimer.unref | configSelectionQueue.length=0 pickQueue.length=0
D 2022-04-12T23:36:32.468Z | channel | (1) dns:localhost:50052 Pick result for call [0]: QUEUE subchannel: null status: undefined undefined
D 2022-04-12T23:36:32.468Z | channel | (1) dns:localhost:50052 callRefTimer.ref | configSelectionQueue.length=0 pickQueue.length=1
D 2022-04-12T23:36:32.468Z | connectivity_state | (1) dns:localhost:50052 CONNECTING -> CONNECTING
D 2022-04-12T23:36:32.469Z | subchannel | (2) ::1:50052 creating HTTP/2 session
HTTP2 30370: Http2Session client: created
D 2022-04-12T23:36:32.471Z | subchannel | (3) 127.0.0.1:50052 creating HTTP/2 session
HTTP2 30370: Http2Session client: created
(node:30370) Warning: Setting the NODE_DEBUG environment variable to 'http2' can expose sensitive data (such as passwords, tokens and authentication headers) in the resulting log.
(Use `node --trace-warnings ...` to show where the warning was created)
HTTP2 30370: Http2Session <invalid>: socket error [connect ECONNREFUSED ::1:50052]
HTTP2 30370: Http2Session client: destroying
HTTP2 30370: Http2Session client: start closing/destroying Error: connect ECONNREFUSED ::1:50052
    at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1187:16) {
  errno: -61,
  code: 'ECONNREFUSED',
  syscall: 'connect',
  address: '::1',
  port: 50052
}
HTTP2 30370: Http2Session client: finishSessionClose
D 2022-04-12T23:36:32.477Z | subchannel | (2) ::1:50052 connection closed with error connect ECONNREFUSED ::1:50052
D 2022-04-12T23:36:32.477Z | subchannel | (2) ::1:50052 connection closed
D 2022-04-12T23:36:32.477Z | subchannel | (2) ::1:50052 CONNECTING -> TRANSIENT_FAILURE
D 2022-04-12T23:36:32.478Z | pick_first | CONNECTING -> CONNECTING
D 2022-04-12T23:36:32.478Z | resolving_load_balancer | dns:localhost:50052 CONNECTING -> CONNECTING
D 2022-04-12T23:36:32.478Z | channel | (1) dns:localhost:50052 callRefTimer.unref | configSelectionQueue.length=0 pickQueue.length=0
D 2022-04-12T23:36:32.478Z | channel | (1) dns:localhost:50052 Pick result for call [0]: QUEUE subchannel: null status: undefined undefined
D 2022-04-12T23:36:32.478Z | channel | (1) dns:localhost:50052 callRefTimer.ref | configSelectionQueue.length=0 pickQueue.length=1
D 2022-04-12T23:36:32.478Z | connectivity_state | (1) dns:localhost:50052 CONNECTING -> CONNECTING
HTTP2 30370: Http2Session client: setting up session handle
HTTP2 30370: Http2Session client: sending settings
HTTP2 30370: Http2Session client: submitting settings
D 2022-04-12T23:36:32.480Z | subchannel | (3) 127.0.0.1:50052 CONNECTING -> READY
D 2022-04-12T23:36:32.480Z | pick_first | Pick subchannel with address 127.0.0.1:50052
D 2022-04-12T23:36:32.480Z | pick_first | CONNECTING -> READY
D 2022-04-12T23:36:32.480Z | resolving_load_balancer | dns:localhost:50052 CONNECTING -> READY
D 2022-04-12T23:36:32.480Z | channel | (1) dns:localhost:50052 callRefTimer.unref | configSelectionQueue.length=0 pickQueue.length=0
D 2022-04-12T23:36:32.480Z | channel | (1) dns:localhost:50052 Pick result for call [0]: COMPLETE subchannel: (3) 127.0.0.1:50052 status: undefined undefined
D 2022-04-12T23:36:32.481Z | connectivity_state | (1) dns:localhost:50052 CONNECTING -> READY
D 2022-04-12T23:36:32.481Z | subchannel_refcount | (3) 127.0.0.1:50052 refcount 2 -> 3
D 2022-04-12T23:36:32.481Z | subchannel_refcount | (2) ::1:50052 refcount 2 -> 1
D 2022-04-12T23:36:32.481Z | subchannel_refcount | (3) 127.0.0.1:50052 refcount 3 -> 2
HTTP2 30370: Http2Session client: initiating request
HTTP2 30370: Http2Session client: connected, initializing request
D 2022-04-12T23:36:32.483Z | call_stream | Starting stream [0] on subchannel (3) 127.0.0.1:50052 with headers
                grpc-accept-encoding: identity,deflate,gzip
                accept-encoding: identity
                :authority: localhost:50052
                user-agent: grpc-node-js/1.6.3
                content-type: application/grpc
                :method: POST
                :path: /helloworld.Greeter/SayHello
                te: trailers

D 2022-04-12T23:36:32.483Z | subchannel_flowctrl | (3) 127.0.0.1:50052 local window size: 65535 remote window size: 65535
D 2022-04-12T23:36:32.483Z | subchannel_internals | (3) 127.0.0.1:50052 session.closed=false session.destroyed=false session.socket.destroyed=false
D 2022-04-12T23:36:32.484Z | call_stream | [0] attachHttp2Stream from subchannel 127.0.0.1:50052
D 2022-04-12T23:36:32.484Z | subchannel_refcount | (3) 127.0.0.1:50052 callRefcount 0 -> 1
D 2022-04-12T23:36:32.484Z | call_stream | [0] sending data chunk of length 12 (deferred)
D 2022-04-12T23:36:32.484Z | call_stream | [0] calling end() on HTTP/2 stream
HTTP2 30370: Http2Stream 1 [Http2Session client]: shutting down writable on last write
HTTP2 30370: Http2Stream 1 [Http2Session client]: shutting down writable on _final
HTTP2 30370: Http2Stream 1 [Http2Session client]: shutdownWritable() already called
HTTP2 30370: Http2Session client: new settings received
D 2022-04-12T23:36:32.487Z | subchannel | (3) 127.0.0.1:50052 new settings received: {"headerTableSize":4096,"enablePush":true,"initialWindowSize":65535,"maxFrameSize":16384,"maxConcurrentStreams":4294967295,"maxHeaderListSize":4294967295,"maxHeaderSize":4294967295,"enableConnectProtocol":false}
HTTP2 30370: Http2Session client: settings received
D 2022-04-12T23:36:32.493Z | subchannel | (3) 127.0.0.1:50052 local settings acknowledged by remote: {"headerTableSize":4096,"enablePush":true,"initialWindowSize":65535,"maxFrameSize":16384,"maxConcurrentStreams":4294967295,"maxHeaderListSize":4294967295,"maxHeaderSize":4294967295,"enableConnectProtocol":false}
D 2022-04-12T23:36:33.469Z | subchannel | (2) ::1:50052 TRANSIENT_FAILURE -> CONNECTING
D 2022-04-12T23:36:33.469Z | subchannel | (2) ::1:50052 creating HTTP/2 session
HTTP2 30370: Http2Session client: created
HTTP2 30370: Http2Session <invalid>: socket error [connect ECONNREFUSED ::1:50052]
HTTP2 30370: Http2Session client: destroying
HTTP2 30370: Http2Session client: start closing/destroying Error: connect ECONNREFUSED ::1:50052
    at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1187:16) {
  errno: -61,
  code: 'ECONNREFUSED',
  syscall: 'connect',
  address: '::1',
  port: 50052
}
HTTP2 30370: Http2Session client: finishSessionClose
D 2022-04-12T23:36:33.471Z | subchannel | (2) ::1:50052 connection closed with error connect ECONNREFUSED ::1:50052
D 2022-04-12T23:36:33.471Z | subchannel | (2) ::1:50052 connection closed
D 2022-04-12T23:36:33.471Z | subchannel | (2) ::1:50052 CONNECTING -> TRANSIENT_FAILURE
D 2022-04-12T23:36:33.471Z | subchannel | (2) ::1:50052 TRANSIENT_FAILURE -> IDLE
HTTP2 30370: Http2Session client: goaway 0 received [last stream id: 1]
D 2022-04-12T23:36:35.060Z | subchannel | (3) 127.0.0.1:50052 connection closed by GOAWAY with code 0
D 2022-04-12T23:36:35.060Z | subchannel | (3) 127.0.0.1:50052 READY -> IDLE
HTTP2 30370: Http2Session client: marking session closed
HTTP2 30370: Http2Session client: submitting goaway
D 2022-04-12T23:36:35.060Z | subchannel_refcount | (3) 127.0.0.1:50052 refcount 2 -> 1
D 2022-04-12T23:36:35.060Z | pick_first | READY -> IDLE
D 2022-04-12T23:36:35.060Z | resolving_load_balancer | dns:localhost:50052 READY -> IDLE
D 2022-04-12T23:36:35.060Z | connectivity_state | (1) dns:localhost:50052 READY -> IDLE
D 2022-04-12T23:36:42.472Z | subchannel_refcount | (2) ::1:50052 refcount 1 -> 0
D 2022-04-12T23:36:42.472Z | subchannel_refcount | (3) 127.0.0.1:50052 refcount 1 -> 0
HTTP2 30370: Http2Stream 1 [Http2Session client]: headers received
HTTP2 30370: Http2Stream 1 [Http2Session client]: emitting stream 'response' event
D 2022-04-12T23:36:42.498Z | call_stream | [0] Received server headers:
                :status: 200
                grpc-accept-encoding: identity,deflate,gzip
                grpc-encoding: identity
                content-type: application/grpc+proto
                date: Tue, 12 Apr 2022 23:36:42 GMT

D 2022-04-12T23:36:42.499Z | call_stream | [0] receive HTTP/2 data frame of length 18
D 2022-04-12T23:36:42.499Z | call_stream | [0] parsed message of length 18
D 2022-04-12T23:36:42.499Z | call_stream | [0] filterReceivedMessage of length 18
D 2022-04-12T23:36:42.500Z | call_stream | [0] pushing to reader message of length 13
HTTP2 30370: Http2Session client: socket closed
HTTP2 30370: Http2Stream 1 [Http2Session client]: closed with code 8, closed true, readable true
HTTP2 30370: Http2Stream 1 [Http2Session client]: destroying stream
HTTP2 30370: Http2Session client: destroying
HTTP2 30370: Http2Session client: start closing/destroying undefined
HTTP2 30370: Http2Session client: finishSessionClose
D 2022-04-12T23:36:42.502Z | call_stream | [0] HTTP/2 stream closed with code 8
D 2022-04-12T23:36:42.503Z | call_stream | [0] ended with status: code=1 details="Call cancelled"
D 2022-04-12T23:36:42.503Z | subchannel_refcount | (3) 127.0.0.1:50052 callRefcount 1 -> 0
Error: 1 CANCELLED: Call cancelled
    at Object.callErrorFromStatus (/Users/aidan/Development/grpc/examples/node/node_modules/@grpc/grpc-js/build/src/call.js:31:26)
    at Object.onReceiveStatus (/Users/aidan/Development/grpc/examples/node/node_modules/@grpc/grpc-js/build/src/client.js:180:52)
    at Object.onReceiveStatus (/Users/aidan/Development/grpc/examples/node/node_modules/@grpc/grpc-js/build/src/client-interceptors.js:365:141)
    at Object.onReceiveStatus (/Users/aidan/Development/grpc/examples/node/node_modules/@grpc/grpc-js/build/src/client-interceptors.js:328:181)
    at /Users/aidan/Development/grpc/examples/node/node_modules/@grpc/grpc-js/build/src/call-stream.js:187:78
    at processTicksAndRejections (node:internal/process/task_queues:78:11) {
  code: 1,
  details: 'Call cancelled',
  metadata: Metadata { internalRepr: Map(0) {}, options: {} }
}
/Users/aidan/Development/grpc/examples/node/static_codegen/greeter_client.js:47
    console.log('Greeting:', response.getMessage());
                                      ^

TypeError: Cannot read properties of undefined (reading 'getMessage')
    at Object.callback (/Users/aidan/Development/grpc/examples/node/static_codegen/greeter_client.js:47:39)
    at Object.onReceiveStatus (/Users/aidan/Development/grpc/examples/node/node_modules/@grpc/grpc-js/build/src/client.js:180:36)
    at Object.onReceiveStatus (/Users/aidan/Development/grpc/examples/node/node_modules/@grpc/grpc-js/build/src/client-interceptors.js:365:141)
    at Object.onReceiveStatus (/Users/aidan/Development/grpc/examples/node/node_modules/@grpc/grpc-js/build/src/client-interceptors.js:328:181)
    at /Users/aidan/Development/grpc/examples/node/node_modules/@grpc/grpc-js/build/src/call-stream.js:187:78
    at processTicksAndRejections (node:internal/process/task_queues:78:11)

Node.js v17.8.0

@murgatroid99
Copy link
Member

On my machine, your example works with earlier versions of Node. It looks like they broke something in Node 16.7.

@artificial-aidan
Copy link
Author

I was able to confirm the same.

@murgatroid99
Copy link
Member

I have filed nodejs/node#42713

@aikoven
Copy link

aikoven commented Mar 9, 2023

The linked issue was closed but graceful shutdown still doesn't appear to work even on newer NodeJS versions.

@murgatroid99
Copy link
Member

I have not duplicated that problem in newer versions of Node. Can you share your test code that triggers this problem, so that we can provide more details in that Node issue about when it is still broken?

@aikoven
Copy link

aikoven commented Mar 11, 2023

Sorry, my minimal reproduction did not show any problem. I'm gonna research further.

@eplightning
Copy link

eplightning commented Mar 22, 2023

It seems that this is once again broken on new Node versions (>= 18.15.0 and >= 19.8.0) . They reverted the fix recently... :
nodejs/node#46721

@artificial-aidan
Copy link
Author

Had to upgrade some infra to node 18+, as I read @eplightning's comment, 18.14 should be a safe bet to not have this issue right? I traced through the release notes a bit and think I found that as well, but just double checking.

@murgatroid99
Copy link
Member

This has been fixed in Node 20.10.0.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

4 participants