-
Notifications
You must be signed in to change notification settings - Fork 29.6k
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
HTTP Server close is taking up to 5 seconds in node 18 #50188
Comments
EDIT: it has the delay also on 18.18.0 |
Related PR: #48383 |
The hot fix: import * as http from "node:http";
import { promisify } from "node:util";
const server = http.createServer(async (req, res) => {
res.writeHead(200, { "Content-Type": "text/plain" });
res.write("Hello world");
res.end();
});
const listenPromisied = promisify(server.listen.bind(server));
const closePromisied = promisify(server.close.bind(server));
await listenPromisied(0, "127.0.0.1");
const address = server.address();
await fetch(`http://${address.address}:${address.port}`);
console.time("server close");
+ server.closeAllConnections();
await closePromisied();
console.timeEnd("server close"); |
Should we bisect or |
The latest behavior is to close all sockets, I think there are some backport issues on 18. Let me see if I can do the backport |
The 19.0.0 looks like the first release without this delay. I will try bisect to see if I can find the commit that fixes the delay and then we can backport. The #48383 was released on 20.4.0, and this issue started on 18.0.0 (or even earlier, I didn't try rewrite the fetch call) |
@himself65 bisect will not help in this case:
From what I understand, 18.x and 19.x have different git histories, so there's no way to find the bad commit using bisect. |
I tried nodejs 16.x. now I think there might have a regression on nodejs 16 -> 18 import * as http from "node:http";
import { promisify } from "node:util";
import fetch from 'node-fetch'
const server = http.createServer(async (req, res) => {
res.writeHead(200, { "Content-Type": "text/plain" });
res.write("Hello world");
res.end();
});
const listenPromisied = promisify(server.listen.bind(server));
const closePromisied = promisify(server.close.bind(server));
await listenPromisied(0, "127.0.0.1");
const address = server.address();
await fetch(`http://${address.address}:${address.port}`);
console.time("server close");
await closePromisied();
console.timeEnd("server close"); ➜ nodejs git:(main) ✗ node index.mjs
server close: 0.158ms
➜ nodejs git:(main) ✗ node -v
v16.20.2 |
It's a regression from 17.x -> 18.x
|
Based on https://github.com/nodejs/node/pull/49091/files#diff-d692ac4524379ec6a1201165e8ff8d3267c8130e07014e8221ebf7e6f80c6641R1560-R1567, and this little change: const server = http.createServer({ keepAliveTimeout: 200 }, async (req, res) => {
@himself65 I think you are right, the #48383 should fix the issue, I thought it landed on 18.18.0 but it did not, sorry for the confusion. Let me know if you will do the backport, if not, I can do that. |
I built 18.18.0 with fix #48383, it solves the delay. |
I might don't have time on backport you can try that. I read some CIGTM code, i have no idea on this #48383 (comment) |
I think I can bring more insights for the problem. I've tried dierent ways of fetching to the server in different node versions. Basically I'm trying with the native fetch (
As you can see, there seems to be a problem with |
I manually implement a function that won't close the connections. Now It's back to 5s in node.js 19/20 import * as http from "node:http";
import { promisify } from "node:util";
import * as net from "node:net";
const server = http.createServer(async (req, res) => {
res.writeHead(200, { "Content-Type": "text/plain" });
res.write("Hello world");
res.end();
});
const listenPromisied = promisify(server.listen.bind(server));
const closePromisied = promisify(net.Server.prototype.close.bind(server));
await listenPromisied(0, "127.0.0.1");
const address = server.address();
await fetch(`http://${address.address}:${address.port}`);
console.time("server close");
await closePromisied();
console.timeEnd("server close"); |
Now I believe this is a kind of bug in undici |
I think this is not a regression. From undici 4.4.1 (first version that has |
Hotfix res.writeHead(200, { 'Content-Type': 'text/plain', 'Connection': 'close' }) |
Thanks to nodejs/undici#2348 (comment) The real reason is keep-alive is by default in somewhere |
The code |
Version
v18.18.2
Platform
Darwin MacBook-Pro-de-Daniel.local 23.0.0 Darwin Kernel Version 23.0.0: Fri Sep 15 14:43:05 PDT 2023; root:xnu-10002.1.13~1/RELEASE_ARM64_T6020 arm64
Subsystem
http
What steps will reproduce the bug?
How often does it reproduce? Is there a required condition?
I have only reproduced the bug in node 18, but is deterministic, it happens every time
What is the expected behavior? Why is that the expected behavior?
In node 19 and 20 it's only taking 0.5 seconds. Thats a normal time that I would expect.
What do you see instead?
I see 5 seconds of delay in order to close
Additional information
I've reproduced the error in this repository with a bare minimum with Github Actions: DanielRamosAcosta/nodejs-close-server-bug
Here is the CI report:
This is affecting to a library I'm maintaining similar to supertest. If you see the CI there, Node 18 tests are taking very long due to the servers being closed.
The text was updated successfully, but these errors were encountered: