SIGINT/SIGTERM handling doesn't wait for promises

[Sytten]

Since #4273, there is a hook for serverWillStop that is called when the SIGTERM or SIGINT signals are received. For reasons which I still don't understand after reading the PR #4450, the code does the following:

apollo-server/packages/apollo-server-core/src/ApolloServer.ts

Lines 362 to 369 in eb926eb

	const handler: NodeJS.SignalsListener = async () => {
	await this.stop();
	process.kill(process.pid, signal);
	};
	process.once(signal, handler);
	this.toDispose.add(async () => {
	process.removeListener(signal, handler);
	});

If you actually test the thing with a server like express, you will quickly see that a promise that requires the event loop to go around (like let's say the apollo agent..........) will NOT, repeat NOT be executed and the process will be killed by the default signal handler before it can send the data over the network.

Now the fix is pretty simple, you have to capture the signal with process.on instead of process.once, remove the process.removeListener and call process.exit instead on process.kill.
This should take 5m to fix and it should be done ASAP @glasser

[glasser]

Can you be more clear as to what you mean by "a promise that requires the event loop to go around"?

The signal handler awaits the call to server.stop which includes any plugin serverWillStop handlers before going forward with shutdown. When you say "the apollo agent" do you mean the usage reporting plugin? It should block in serverWillStop until the final report is sent, right? This stuff is subtle and quite like has bugs, but I don't understand what you're describing. Can you share some code that demonstrates the issue?

[Sytten]

It means anything that needs another loop of the event loop like IO or setImmediate. Just launch a plain apollo server on express and place a console log before the process.kill, it is never called. As soon as you yield the thread the process gets killed. I can give you a full example tomorrow.

[glasser]

Looking forward to a full reproduction. You're sure your process isn't receiving more than one signal?

…

On Sun, Feb 14, 2021, 10:12 PM Émile Fugulin ***@***.***> wrote: It means anything that needs another loop of the event loop like IO or setImmediate. Just launch a plain apollo server on express and place a console log before the process.kill, it is never called. As soon as you yield the thread the process gets killed. I can give you a full example tomorrow. — You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub <#4931 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AAAECVFEOV5RNTNXCAQQCVLS7C3M7ANCNFSM4XUAGNUQ> .

[Sytten]

Maybe that is the case, because sending only a SIGINT using kill to the process seems to work.
But doing one CTRL+C (which also sends a SIGINT AFAIK), kills the process immediately unless the process handles the SIGINT with a process.on. This is weird.

[Sytten]

Let's compare using this repo: https://github.com/Sytten/repo-apollo-kill

[Sytten]

Interesting enough, yesterday my test showed that it didn't make any difference it was node or ts-node but now I have a different result (not sure why, will investigate).
Seems like the CTRL+C correctly handles the stop if running node directly but not ts-node.

EDIT: it also doesn't work (CTRL+C) if using tsconfig-paths/register with node, but it always works correctly if doing kill -SIGTERM PID.

[Sytten]

So my takeaway is that for some reason, it might be that the SIGTERM is sent more than once so using a process.once is less reliable than using a process.on (which is standard anyway). So while it probably works ok in a container world where a nice SIGTERM is sent only once, it might not work well for setups that use pm2 or nodemon in production.
Sorry for being quite rude last night, I was aggravated by this but I still think this should be changed.

[Sytten]

I did more tests and I found that doing a gzip doesn't work at all with the current system even when sending the signal with kill and removed other parameters (tsconfig-paths and ts-node):

import zlib from 'zlib';
import util from 'util';
const gzip = util.promisify(zlib.gzip);
...
const output = JSON.stringify(data);
const compressed = await gzip(Buffer.from(output));

This tells me that is should be fixed @glasser

[glasser]

Hi! Back from vacation and want to look at this soon.

I did a process.once because the idea was that we should handle the signal by starting 'stop' and then re-signal so that the death can still be "from the signal". However I think you're right that things get funky if the signal gets sent twice. Probably I should use process.on, make the handler do nothing if it's not the first invocation, and removeListener when done.

I can work on this soon, but I'm pretty confused by your final comment. What does gzip have to do with anything? In what context are you running the code in question?

[Sytten]

Hey!

Yup I think this is the better approach.

Not sure to be honest, but I saw a difference in my tests between having only an IO await (like doing a POST) and doing a gzip await. I have no idea why, but doing a kill -SIGTERM $PID correctly waited for the IO but not for the gzip await???
All my code examples ran in a plugin serverWillStop.

[glasser]

@Sytten How does #4991 look?

[Sytten]

Seems fine to me, a bit convoluted with the call of kill but it should do the trick (and it is well documented).
I am guessing this is to give a chance to other potential hooks to also do their cleaning?

[glasser]

Yeah, and I kinda like that the process will exit with an exit status indicating it died due to signal rather than an exit code. Maybe that's silly though.

[Sytten]

Make sense I guess since by default this is on (not sure I agree but thats another topic) so it should be transparent for a user. If it was disabled by default then a standard exit would be correct.

[glasser]

I've published a release with this to version 2.21.2-alpha.0. My plan is to release 2.21.2 in a day or two. If you want to test that this fix works before then, try running the prerelease yourself, and provide feedback on #5037.

[Sytten]

Will do I will test with my plugin!