Skip to content

ApolloServerPluginDrainHttpServer retains closed sockets when close is processed before finish #8222

Description

@kdjun99

Issue Description

Stopper, used by ApolloServerPluginDrainHttpServer, tracks in-flight requests in a
Map<Socket, number> called requestCountPerSocket. The only code that ever removes an entry is
the socket.once('close', ...) listener registered when the connection is opened.

The res.once('finish') callback re-inserts the socket unconditionally:

// packages/server/src/plugin/drainHttpServer/stoppable.ts
socket.once('close', () => this.requestCountPerSocket.delete(socket));   // the only removal
...
res.once('finish', () => {
  const pending = (this.requestCountPerSocket.get(req.socket) ?? 0) - 1;
  this.requestCountPerSocket.set(req.socket, pending);                   // unconditional
  if (this.stopped && pending === 0) req.socket.end();
});

So if a socket's 'close' event is processed before its queued 'finish' callback runs:

  1. the close listener deletes the entry — and is consumed, because it is registered with once();
  2. the 'finish' callback re-inserts the same socket via set();
  3. no close listener remains, so nothing will ever remove it again.

The Map then holds a closed Socket — and everything it references — for the lifetime of the
process. The linked reproduction shows 1000/1000 sockets surviving a forced GC on 5.5.1.

This is not opt-in for NestJS users: @nestjs/apollo (verified in 12.0.7,
drivers/apollo-base.driver.js) appends this plugin to the plugin list automatically for Express
integrations.

How we hit it in production

  • Node 18.20.8, @apollo/server 4.9.3, Express 4, @nestjs/apollo 12.0.7
  • The affected server was reached through a proxy on the same host: for 18,302 of the leaked
    sockets the recorded peer address was localhost (::ffff:127.0.0.1).

Memory grew monotonically until the instance was recycled. A heap snapshot taken before we
applied a workaround:

observation count
Socket objects in the heap 18,314
Socket keys retained by requestCountPerSocket 18,299
leaked sockets whose _events.close holds exactly one listener 18,303
leaked sockets still holding the Stopper's once('close') wrapper 0
leaked sockets whose parser is no longer a parser object 18,302
leaked sockets whose _httpMessage is no longer a message object 18,302

Counts differ by a handful because the heap also contains sockets unrelated to this HTTP
server (outbound connections, etc.). An earlier snapshot showed 48,706 sockets held by the same
Map.

What the snapshot pins down

Premise: the Stopper is constructed when the plugin is created — before the server starts
listening — and its connection handler runs set(socket, 0) immediately followed by
socket.once('close', ...) in the same synchronous block. Node emits connection for an accepted
socket before parsing any request on it. So every socket that reaches the request handler has
already been given the Stopper's once('close') listener.

Given that:

  • 'close' really did fire. Node registers its own permanent close listener on server
    sockets, so a socket whose Stopper once had not yet fired would carry two close listeners
    (_events.close would be an array). Every leaked socket carries exactly one, and none is an
    onceWrapper — so the Stopper's once fired and was consumed, meaning its delete(socket)
    ran. (Sampling those single listeners shows Node's own bound socketOnClose.)
  • The socket is nonetheless a live key in the Map ⇒ it was re-inserted after that delete.
  • The re-insert came from 'finish', not from 'request'. The socket's parser has been
    freed, so no further HTTP request can be parsed on it; the request handler cannot have run
    again. The only remaining set() for that socket is the one inside res.once('finish').

So the ordering was: connectionrequestclosefinish.

Why the existing tests don't catch it

The tests in stoppable.test.ts drive real TCP servers over loopback. In every local experiment
we ran the ordering was finish before close, which self-heals — the close listener deletes the
entry last, so the unguarded re-insert is harmless.

We could not produce the reversed ordering locally, across: a bare http.Server, OpenTelemetry
auto-instrumentation, the full Express + Apollo stack with the real plugin, node:cluster,
induced write backpressure, an event-loop-congested server, and a real reverse proxy in front of
Node on localhost with mid-response client aborts. We do not have a confirmed explanation for why
loopback never produces the reversed ordering; in production the leaked sockets accumulated over
weeks.

That is why the linked reproduction drives the two events directly — the ordering is the input.

Same thing with no dependencies, and with the proposed fix applied (proof-mechanism.js)
'use strict';
// Deterministic proof of the Stopper socket leak, and that the proposed guard fixes it.
//   node proof-mechanism.js
const { EventEmitter } = require('events');

const VARIANTS = {
  // Upstream today: unconditionally re-inserts the socket into the Map.
  original(map, socket) {
    const pending = (map.get(socket) ?? 0) - 1;
    map.set(socket, pending);
  },
  // Proposed fix: never resurrect an entry the close handler removed.
  hasGuard(map, socket) {
    if (!map.has(socket)) return;
    const pending = map.get(socket) - 1;
    map.set(socket, pending);
  },
};

// Stopper's registration logic, verbatim.
function makeStopper(finishHandler) {
  const map = new Map();
  return {
    map,
    onConnection(socket) {
      map.set(socket, 0);
      socket.once('close', () => map.delete(socket));
    },
    onRequest(req, res) {
      map.set(req.socket, (map.get(req.socket) ?? 0) + 1);
      res.once('finish', () => finishHandler(map, req.socket));
    },
  };
}

function lifecycle(stopper, order) {
  const socket = new EventEmitter();
  const res = new EventEmitter();
  stopper.onConnection(socket);
  stopper.onRequest({ socket }, res);
  const close = () => socket.emit('close');
  const finish = () => res.emit('finish');
  if (order === 'finish-first') { finish(); close(); } else { close(); finish(); }
}

const N = 1000;
console.log('order'.padEnd(16) + 'original'.padStart(10) + 'hasGuard'.padStart(10));
for (const order of ['finish-first', 'close-first']) {
  const row = ['original', 'hasGuard'].map((name) => {
    const s = makeStopper(VARIANTS[name]);
    for (let i = 0; i < N; i++) lifecycle(s, order);
    return s.map.size;
  });
  console.log(order.padEnd(16) + String(row[0]).padStart(10) + String(row[1]).padStart(10));
}
order             original  hasGuard
finish-first             0         0
close-first           1000         0

Leaked entries also carry a negative count (0 - 1 = -1): the decrement runs against an entry
that was already deleted, so get() ?? 0 starts from 0 instead of 1.

Prior art

hunterloftis/stoppable#30 (open since
2020) reports unbounded growth of the same Map on the package this file was ported from: "the map
would not be properly maintained, keeping references to thousands of requests". The reporter
reaches it as server._pendingSockets, which is that package's public alias for the same
structure (server._pendingSockets = reqsPerSocket in lib/stoppable.js), and that version has
the same connection/close/finish shape as this file — including the unconditional re-insert.

Two caveats so I don't overstate it: that report has no diagnosis or reproduction, and the
reporter's stack (node-spdy + terminus) differs from ours, so I can't confirm their trigger was
this same ordering. What is verifiable is that the accumulating structure is identical.

Proposed fix

Never create an entry that the close handler already removed:

res.once('finish', () => {
  if (!this.requestCountPerSocket.has(req.socket)) {
    return;
  }
  const pending = this.requestCountPerSocket.get(req.socket)! - 1;
  this.requestCountPerSocket.set(req.socket, pending);
  if (this.stopped && pending === 0) req.socket.end();
});

Behaviour is unchanged for the normal ordering, and skipping socket.end() for an already-closed
socket is correct.

I used has() rather than checking socket.closed/socket.destroyed because socket.closed
does not exist on every Node version this package has supported — @apollo/server 4.9.3 declares
engines.node >= 14.16.0, and net.Socket#closed is undefined on Node 14 and 16 (checked on
14.15.0 and 16.18.1) while socket.destroyed is available throughout. has() also states the
actual invariant: only track sockets the close handler hasn't already reclaimed.

Happy to open a PR with this plus a regression test.

Link to Reproduction

https://github.com/kdjun99/apollo-server-drain-socket-leak-repro

Reproduction Steps

npm ci
npm run repro          # node --expose-gc leak.mjs

Output:

@apollo/server: 5.5.1
node: v22.18.0

ordering: finish before close -> sockets retained after GC:    1/1000
ordering: close before finish -> sockets retained after GC: 1000/1000

The script creates the real plugin (ApolloServerPluginDrainHttpServer({ httpServer })), emits
exactly the events Node emits for an accepted connection and an incoming request, and varies only
their order. It then drops every strong reference, forces a GC, and counts how many sockets are
still reachable via WeakRef — so it reads no private state; anything still alive is retained by
the plugin.

The 1 in the first row is a GC artifact (the most recent iteration can still be reachable from
the stack). The signal is the contrast: 1 vs 1000.

Verified on @apollo/server 5.5.1 (Node 22.18.0) and 4.9.3 (Node 18.20.8).

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions