@grpc/grpc-js: tryShutdown freeze app

[GordinMaxim]

Problem description

If client crashes or exits before server calls call.end(), server.tryShutdown(callback) freezes app. Server has http2session which is closed, so maybeCallback doesn't decrement pendingChecks, and callback is never called (if tryShutdown was promisified it never resolves).

Reproduction steps

Create server-side stream (hellostreamingworld.proto), end client app before server calls call.end().
(client - greater_client.js without changes)

const promisify = require("util").promisify;
const log = require('why-is-node-running');
var messages = require('./hellostreamingworld_pb');
var services = require('./hellostreamingworld_grpc_pb');
var grpc = require('@grpc/grpc-js');

function sayHello(call) {
  var num = call.request.getNumGreetings();
  console.log(call.request.toObject());
  console.log(`${num} greetings`);
  function greet() {
        if (num-- < 0) {
  		return;
  	}
	var reply = new messages.HelloReply();
	reply.setMessage('Hello ' + call.request.getName());
    call.write(reply);
    setTimeout(greet, 2000);
  }
  setTimeout(greet, 1000);
  call.end();
}

async function main() {
	var server = new grpc.Server();
	server.addService(services.MultiGreeterService, {sayHello: sayHello});
	await promisify(server.bindAsync.bind(server))('0.0.0.0:50051', grpc.ServerCredentials.createInsecure());
	server.start();
	setTimeout(() => {
		console.log('start server shutdown');
		setTimeout(log, 10000);
		server.tryShutdown(() => {
			console.log("server shutdown");
		});
	}, 10000);
}

main();

Environment

• OS name, version and architecture: ArchLinux x86_64
• Node version: v12.18.0
• Node installation method: nvm
• Package name and version [e.g. "@grpc/grpc-js": "^0.6.16"]

Additional information

server output:

{ name: 'world', numGreetings: 10 }
10 greetings
start server shutdown
There are 8 handle(s) keeping the process running

# TTYWRAP
/home/maxim/code/grpc/examples/node/node_modules/grpc/node_modules/set-blocking/index.js:2 - [process.stdout, process.stderr].forEach(function (stream) {
/home/maxim/code/grpc/examples/node/node_modules/grpc/node_modules/npmlog/log.js:11        - setBlocking(true)

# SIGNALWRAP
/home/maxim/code/grpc/examples/node/node_modules/grpc/node_modules/set-blocking/index.js:2 - [process.stdout, process.stderr].forEach(function (stream) {
/home/maxim/code/grpc/examples/node/node_modules/grpc/node_modules/npmlog/log.js:11        - setBlocking(true)

# TTYWRAP
/home/maxim/code/grpc/examples/node/node_modules/grpc/node_modules/set-blocking/index.js:2 - [process.stdout, process.stderr].forEach(function (stream) {
/home/maxim/code/grpc/examples/node/node_modules/grpc/node_modules/npmlog/log.js:11        - setBlocking(true)

# DNSCHANNEL
(unknown stack trace)

# HTTP2SESSION
(unknown stack trace)

# HTTP2SETTINGS
(unknown stack trace)

# Timeout
/home/maxim/code/grpc/examples/node/static_codegen/greeter_server.js:55 - setTimeout(log, 10000);

# Timeout
/home/maxim/code/grpc/examples/node/static_codegen/greeter_server.js:38 - setTimeout(greet, 2000);

[murgatroid99]

A change that should fix this is now out in version 1.1.0.

[huan]

Today I ran into almost exactly the same problem with @grpc/grpc-js@1.4.1.

I can reproduce it from my repo, and I hope I can make a minimum reproducible code then I'll post it to the issue.

[CMCDragonkai]

I'm facing a similar problem, but tryShutdown doesn't ever finish when the only thing I've done is to create a duplex stream, and then end it from both sides. Both sides report that the stream is destroyed, the client is closed, but then the server continues to wait to shutdown. I have to force shutdown. Seems the tryShutdown is a bit flaky?

[CMCDragonkai]

Is there a way to report what sessions/connections are still live when it's trying to shutdown?

[murgatroid99]

Can you share some code that demonstrates the error you are describing? That seems like a bug.

[huan]

I have some notes in

• grpc.tryShutdown() never return if client close the connection. wechaty/puppet-service#176

And I guess this problem is related to

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

And there have a unit test linked in my issue and it can reproduce the problem.

[murgatroid99]

I cloned your repository and set it up by running

npm install
npm install wechaty-puppet

But I can't get the tests to run. I get these errors:

src/client/puppet-service.ts:383:12 - error TS4113: This member cannot have an 'override' modifier because it is not declared in the base class 'Puppet'.

383   override onDirty (
               ~~~~~~~

src/client/puppet-service.ts:397:28 - error TS2339: Property 'Unspecified' does not exist on type 'typeof PayloadType'.

397       [PUPPET.type.Payload.Unspecified]:  async (id: string) => { throw new Error('Unspecified type with id: ' + id) },
                               ~~~~~~~~~~~

src/client/puppet-service.ts:400:42 - error TS2769: No overload matches this call.
  Overload 1 of 2, '(promise: Promise<any>): void', gave the following error.
    Argument of type '((id: string) => Promise<boolean | undefined>) | ((_: string) => Promise<void>) | ((_: string) => Promise<void>) | ((id: string) => Promise<boolean | undefined>) | ((id: string) => Promise<...>) | undefined' is not assignable to parameter of type 'Promise<any>'.
      Type 'undefined' is not assignable to type 'Promise<any>'.
  Overload 2 of 2, '(asyncFunction: (...args: any[]) => Promise<any>): (...args: any[]) => void', gave the following error.
    Argument of type '((id: string) => Promise<boolean | undefined>) | ((_: string) => Promise<void>) | ((_: string) => Promise<void>) | ((id: string) => Promise<boolean | undefined>) | ((id: string) => Promise<...>) | undefined' is not assignable to parameter of type '(...args: any[]) => Promise<any>'.
      Type 'undefined' is not assignable to type '(...args: any[]) => Promise<any>'.

400     const dirtyFuncSync = this.wrapAsync(dirtyMap[payloadType])
                                             ~~~~~~~~~~~~~~~~~~~~~


src/client/puppet-service.ts:401:5 - error TS2349: This expression is not callable.
  Type 'void' has no call signatures.

401     dirtyFuncSync(payloadId)
        ~~~~~~~~~~~~~

src/client/puppet-service.ts:406:11 - error TS2339: Property 'onDirty' does not exist on type 'Puppet'.

406     super.onDirty({ payloadId, payloadType })

[huan]

@murgatroid99 Thanks for trying to reproduce this problem!

I have just created a branch to reproduce this bug, please see my PR at

• Reproduce: tryShutdown freeze app wechaty/puppet-service#185

Please feel free to let me know if you have any questions, and I really hope we can fix this problem for a better gRPC JS state management.

[murgatroid99]

I was able to get some logs by setting the environment variables GRPC_TRACE=all and GRPC_VERBOSITY=DEBUG when running that test. According to those logs, the client opens two streams, and the second one finishes, but the first one never does. It is intended behavior that the server does not call the callback for tryShutdown until all streams have finished. If you want to force the server to shut down you should call forceShutdown.

In the PR you linked, you are awaiting the result of tryShutdown on line 184. The code will not progress past that point until the server has finished shutting down, so it never actually calls forceShutdown on line 191. If you remove the call to await on line 184 that will probably fix it.