Skip to content

Commit

Permalink
test: Add test for FIN mishandling in http agent
Browse files Browse the repository at this point in the history
  • Loading branch information
dhedey committed Jan 21, 2024
1 parent 27d839f commit a7ca64e
Show file tree
Hide file tree
Showing 2 changed files with 210 additions and 0 deletions.
67 changes: 67 additions & 0 deletions test/fixtures/child-process-run-tcp-server.js
@@ -0,0 +1,67 @@
'use strict';

// NOTE: This file was purposefully constructed to run as a child process
// of test-http-agent-fin-handling.js and should be considered a partner
// of this test

const net = require('net');

function plaintextHttpResponse(text) {
return "HTTP/1.1 200 OK\r\n" +
"Content-Type: text/plain\r\n" +
`Content-Length: ${text.length}\r\n` +
"\r\n" +
`${text}`
}

function sendToParent(message) {
process.send(message, undefined, { swallowErrors: true });
}

let socketCount = 0;

// Creates a TCP server (from e.g. test-http-1.0.js)
const server = net.createServer({
// allowHalfOpen setting seems irrelevant
}, function(socket) {
let allReceivedClientData = '';
let finHasBeenSent = false;
let socketNumber = ++socketCount;
process.send(`SERVER_SOCKET_OPEN: ${socketNumber}`);

socket.setEncoding('utf8');
socket.on('data', function(chunk) {
allReceivedClientData += chunk;
if (finHasBeenSent) {
// This isn't actually necessary to trigger the issues
// But is likely behaviour of a server receiving traffic
// after it sent a FIN.
sendToParent(`SERVER_SEND_RESET: ${socketNumber}`);
socket.resetAndDestroy();
return;
}
// Assume it's a GET request...
// Therefore \r\n\r\n marks the end of the request
const isEndOfRequest = allReceivedClientData.endsWith("\r\n\r\n");
if (isEndOfRequest) {
sendToParent(`SERVER_SEND_FIN: ${socketNumber}`);
socket.write(plaintextHttpResponse('Hello, world!'));

// Even if the request comes with Connection: Keep-Alive,
// we ignore it and just end the connection/socket.
finHasBeenSent = true;
socket.end();
}
});
socket.on('end', function() {
sendToParent(`SERVER_SOCKET_CLOSE: ${socketNumber}`);
});
socket.on('error', function() {
sendToParent(`SERVER_SOCKET_ERROR: ${socketNumber}`);
})
});
server.listen(0, function() {
// When we start listening, send the port to the parent:
sendToParent("SERVER_PORT: " + this.address().port);
});
sendToParent("SERVER_LAUNCHED");
143 changes: 143 additions & 0 deletions test/parallel/test-http-agent-fin-handling.js
@@ -0,0 +1,143 @@
'use strict';
const common = require('../common');
const assert = require('assert');
const fork = require('child_process').fork;
const fixtures = require('../common/fixtures');
const http = require('http');

// Note to self: Normal debug has stopped printing debug messages...
// Not sure why. Instead let's implement our own:
// const debug = require('util').debuglog('test');
function debug(message) {
console.log(message);
}

// NOTE:
// Putting the server in a separate process ensures that its
// responses are in a different event loop.
// This enables certain edge cases to happen which wouldn't otherwise be caught.
// I'm not actually 100% sure this is needed, but for now it makes sense
// to get the reproduction.
function runServerInChildProcessWithFreePort(listeningCallback, maxLifetimeMs) {
const cp = fork(fixtures.path('child-process-run-tcp-server.js'));

let messageIndex = 0;

cp.on('message', function messageHandler(message) {
switch (messageIndex++) {
case 0:
assert.strictEqual(message, "SERVER_LAUNCHED");
break;
case 1:
assert.match(message, /SERVER_PORT: \d+/);
const port = +message.split(" ")[1];
listeningCallback(port);
break;
default:
debug(message);
break;
}
});
setTimeout(() => {
cp.kill();
}, maxLifetimeMs);
}

const agent = new http.Agent({
keepAlive: true,
// NOTE:
// > If maxSockets = 1 - second request gets "Error: socket hang up" immediately
// > If maxSockets = 2, we also get this issue always
// > But maxSockets isn't necessary to trigger this bug, so leaving it out
// maxSockets: 1,
});

function formatError(e) {
let out = '';
if (e instanceof AggregateError) {
out += `AggregateError [${e.errors.length} SubError/s]`;
if (e.message) {
out += `- ${e.message}`;
}
for (let i = 0; i < e.errors.length; i++) {
out += `\n> SubError ${i+1} of ${e.errors.length}:\n`
out += formatError(e.errors[i])
}
}
else {
out += e;
if (e.code) {
out += ` (e.code: ${e.code})`;
}
}
return out;
}

let socketCount = 0;

function getRequireSuccess(port, attemptMessage, onReceiveResponse) {
return http.get({
host: 'localhost',
port: port,
agent: agent,
path: "/"
}, function(res) {
res.setEncoding('utf8');
// According to ClientRequest, a data handler is mandatory
res.on('data', common.mustCall((chunk) => {
assert.strictEqual(chunk, "Hello, world!")
}), 1);
res.on('error', () => {
assert.fail(`Response error ${attemptMessage}: ${formatError(e)}`);
});
res.on('end', () => {
debug(`CLIENT_FULL_RESPONSE_RECEIVED: for ${attemptMessage}`)
onReceiveResponse && onReceiveResponse();
});
})
.on('socket', (socket) => {
if (socket.DEBUG_ATTEMPT) {
debug(`CLIENT_SOCKET_REUSED: Socket from ${socket.DEBUG_ATTEMPT} reused for ${attemptMessage}`)
} else {
socket.DEBUG_ATTEMPT = attemptMessage;
socket.on("error", (e) => {
assert.fail(`Socket error at ${attemptMessage}: ${formatError(e)}`);
});
}
})
.on('error', (e) => {
assert.fail(`Request error at ${attemptMessage}: ${formatError(e)}`);
});
}

// If the server lasts less long (e.g. 100ms) we get some
// ECONNRESET from the server being killed too early.
const MAX_SERVER_LIFETIME_MS = 500;

runServerInChildProcessWithFreePort(common.mustCall(function(port) {
debug("CLIENT_PORT_RECEIVED_FROM_SERVER: " + port);

// Any one of these can cause the error (randomly)
// But the probability increases from ~50% to >90% by adding
// a few more. We do this to ensure the test is repeatable.

// This gives an error, with either:
// * Request 1.1 reusing the socket from Request 2
// * Request 2.1 reusing the socket from Request 1
// Either of these appears to cause Error: socket hang up (e.code: ECONNRESET)
// BECAUSE the server has already sent a FIN, which the client recognises, but
// for some reason, still attempts to re-use the socket.

getRequireSuccess(port, "Request 1", () => {
getRequireSuccess(port, "Request 1.1");
});
getRequireSuccess(port, "Request 2", () => {
getRequireSuccess(port, "Request 2.1");
});

// For debugging - uncomment this to force debug messages
// to print even if the test succeeds.
// setTimeout(() => {
// assert.fail("SUCCESS - TRIGGERING DEBUG MESSAGES");
// }, 500);
}), MAX_SERVER_LIFETIME_MS);

0 comments on commit a7ca64e

Please sign in to comment.