wechaty / puppet-service

Wechaty Puppet Provider for providing/consuming the Wechaty Puppet Service
https://paka.dev/npm/wechaty-puppet-service
Apache License 2.0
73 stars 18 forks source link

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

Open huan opened 2 years ago

huan commented 2 years ago

Version: @grpc/grpc-js@1.4.1

Related issue:

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:

https://github.com/wechaty/puppet-service/blob/a764bd22655a60117bbd118c64469feb6b16d33a/tests/grpc-stream.spec.ts#L71-L78

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 commented 2 years ago

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 commented 2 years ago

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.