grpc.tryShutdown() never return if client close the connection.

[huan]

Version: @grpc/grpc-js@1.4.1

Related issue:

• @grpc/grpc-js: tryShutdown freeze app  grpc/grpc-node#1458

Log messages:

11:41:53 VERB PuppetCacheMixin stop()
11:41:53 VERB CacheAgent stop()
11:41:53 VERB CacheAgent clear()
11:41:53 VERB PuppetMemoryMixin stop()
11:41:53 VERB PuppetSkelton stop()
11:41:53 VERB ServiceCtl<PuppetServiceMixin> stop() super.stop() ... done
11:41:53 VERB StateSwitch <PuppetServiceMixin> inactive(true) <- (pending)
    ok 2 - should clean grpc after stop()
11:41:53 VERB PuppetServer stop()
11:41:53 VERB PuppetServer stop() shuting down gRPC server ...
- 11:26:25 VERB PuppetServer stop() shuting down gRPC server ... done
- 11:26:25 VERB PuppetServer stop() destory URN Registry ...
- 11:26:25 VERB PuppetServer stop() destory URN Registry ... done
-     1..2
- ok 1 - Close eventStream when gRPC breaks # time=202.232ms
- 
- 1..1
- # time=209.014ms

the diff shows the missing(expected) log outputs

Source code:

puppet-service/tests/grpc-stream.spec.ts

Lines 71 to 78 in a764bd2

	// mock grpcClient break
	await puppetService.grpc.client.close()
	await puppetService.stop()
	// get eventStream status
	t.throws(() => puppetService.grpc, 'should clean grpc after stop()')
	await puppetServer.stop()

why-is-node-running report

# TCPWRAP
node:internal/async_hooks:203                                                               
node:internal/http2/core:3256                                                               
/home/huan/git/wechaty/puppet-service/node_modules/@grpc/grpc-js/build/src/subchannel.js:365 - const session = http2.connect(addressScheme + targetAuthority, connectionOptions);
/home/huan/git/wechaty/puppet-service/node_modules/@grpc/grpc-js/build/src/subchannel.js:445 - this.createSession(result);
node:internal/process/task_queues:96                                                        

# TLSWRAP
node:internal/async_hooks:203                                                               
node:internal/http2/core:3256                                                               
/home/huan/git/wechaty/puppet-service/node_modules/@grpc/grpc-js/build/src/subchannel.js:365 - const session = http2.connect(addressScheme + targetAuthority, connectionOptions);
/home/huan/git/wechaty/puppet-service/node_modules/@grpc/grpc-js/build/src/subchannel.js:445 - this.createSession(result);
node:internal/process/task_queues:96                                                        

# TCPWRAP
node:internal/async_hooks:203

# TLSWRAP
node:internal/async_hooks:203

# HTTP2SESSION
node:internal/async_hooks:203
node:internal/http2/core:1018
node:internal/http2/core:1244

# HTTP2STREAM
node:internal/async_hooks:203                                                               
node:internal/http2/core:713                                                                
node:internal/http2/core:1800                                                               
/home/huan/git/wechaty/puppet-service/node_modules/@grpc/grpc-js/build/src/subchannel.js:611 - http2Stream = this.session.request(headers);
/home/huan/git/wechaty/puppet-service/node_modules/@grpc/grpc-js/build/src/channel.js:259    - pickResult.subchannel.startCallStream(finalMetadata, callStream, [...dynamicFilters, ...pickExtraFilters]);
node:internal/process/task_queues:96                                                        

# HTTP2SESSION
node:internal/async_hooks:203
node:internal/http2/core:1018
node:internal/http2/core:1250
node:internal/http2/core:1588
node:internal/http2/core:3038

# HTTP2STREAM
node:internal/async_hooks:203

[huan]

• Http2Server.prototype.close Does Not Work as Expected nodejs/node#28214

I believe this behavior is expected with the Node.js server.close() callback explanation in the above issue:

The grpc.tryShutdown() will call server.close(callback), however, the callback might not be called immediately because the server.close only stop accepting new connections.

There might be other active connections left, which means the callback will be only called after all of them have been closed.

Related grpc-js code

https://github.com/grpc/grpc-node/blob/5a49a93065d9c57da038daaf4b36d01eed589633/packages/grpc-js/src/server.ts#L663-L672

[huan]

Workaround

After testing, it seems that even we have called grpc.forceShutdown(), the promise returned from tryShutdown() still can not be resolved.

So we have to ignore it for now and hope we can find the reason in the future.