node:http: measure the keep-alive idle period on the monotonic clock

src/js/internal/timers.ts

@@ -4,6 +4,16 @@ const NumberIsFinite = Number.isFinite;
 
 const TIMEOUT_MAX = 2 ** 31 - 1;
 
+/**
+ * The real monotonic clock in whole milliseconds, for deadlines the runtime's
+ * own JS keeps (a mark recorded now and compared against when a timer fires).
+ * No JS-visible clock will do: bun:test's `setSystemTime()` overrides
+ * `Date.now()` inside the engine, and `useFakeTimers()` also overrides
+ * `performance.now()` and `process.hrtime()`, so a deadline measured with any
+ * of them freezes or jumps along with the mock.
+ */
+const monotonicNowMs = $newRustFunction("runtime/timer/Timer.rs", "internal_bindings.monotonicNowMs", 0);
+
 function getTimerDuration(msecs, name) {
   validateNumber(msecs, name);
   if (msecs < 0 || !NumberIsFinite(msecs)) {
@@ -29,4 +39,5 @@ export default {
   // tests that inspect socket[kTimeout].
   kTimeout: Symbol.for("::buntimeout::"),
   getTimerDuration,
+  monotonicNowMs,
 };

src/js/node/_http_server.ts

@@ -69,6 +69,7 @@ const {
   validateMsecs,
 } = require("internal/http");
 const { FakeSocket } = require("internal/http/FakeSocket");
+const { monotonicNowMs } = require("internal/timers");
 const NumberIsNaN = Number.isNaN;
 
 const { format } = require("internal/util/inspect");
@@ -120,7 +121,6 @@ const kEmptyBuffer = Buffer.alloc(0);
 const ObjectKeys = Object.keys;
 const MathMin = Math.min;
 const MathFloor = Math.floor;
-const DateNow = Date.now;
 
 let cluster;
 
@@ -1419,7 +1419,8 @@ const kKeepAliveTimeoutSet = Symbol("keepAliveTimeoutSet");
 // When the keep-alive idle period on a connection started (the last response
 // finish). onResponseFinishHandleSocket records this instead of rescheduling
 // the socket timer on every response; onSocketTimeoutTimerExpired reads it to
-// grant the remaining idle budget when the timer actually fires.
+// grant the remaining idle budget when the timer actually fires. Read from
+// monotonicNowMs(), which setSystemTime() / fake timers cannot move.
 const kKeepAliveIdleStart = Symbol("keepAliveIdleStart");
 // HTTP/1.1 pipelining (responses queued behind an in-flight response):
 // - on the socket: array of queued ServerResponses, in arrival order
@@ -1518,7 +1519,7 @@ function onSocketTimeoutTimerExpired(socket) {
   const idleStart = socket[kKeepAliveIdleStart];
   if (idleStart !== undefined && socket[kKeepAliveTimeoutSet]) {
     socket[kKeepAliveIdleStart] = undefined;
-    const remaining = socket.timeout - (DateNow() - idleStart);
+    const remaining = socket.timeout - (monotonicNowMs() - idleStart);
     if (remaining > 0) {
       const existingTimer = socket[kSocketTimeoutTimer];
       if (existingTimer !== undefined) clearTimeout(existingTimer);
@@ -2512,14 +2513,17 @@ function onResponseFinishHandleSocket(server, socket, res) {
     // kept-alive connection), leave it in place and only record when this
     // idle period started; onSocketTimeoutTimerExpired grants the remaining
     // budget if the timer fires early, so the socket still closes after
-    // exactly `total` ms of idle.
+    // exactly `total` ms of idle. The mark is taken before the timer is armed:
+    // both are whole milliseconds, so a timer armed after the mark measures at
+    // least `total` when it fires and closes instead of re-arming for a
+    // rounding millisecond.
+    socket[kKeepAliveIdleStart] = monotonicNowMs();
     const timer = socket[kSocketTimeoutTimer];
     if (timer !== undefined && timer._idleTimeout === total) {
       socket.timeout = total;
     } else {
       socket.setTimeout(total);
     }
-    socket[kKeepAliveIdleStart] = DateNow();
     socket[kKeepAliveTimeoutSet] = true;
   }
 }

src/runtime/timer/Timer.rs

@@ -596,4 +596,16 @@ pub(crate) mod internal_bindings {
         // `js_number(f64)` (i64 → f64 is lossless for the millisecond range).
         Ok(JSValue::js_number(now as f64))
     }
+
+    /// `require("internal/timers").monotonicNowMs()`, documented there. Always
+    /// the real clock, i.e. the one the real timer heap is drained against,
+    /// whatever bun:test has mocked.
+    #[bun_jsc::host_fn]
+    pub(crate) fn monotonic_now_ms(
+        _global_this: &JSGlobalObject,
+        _call_frame: &CallFrame,
+    ) -> JsResult<JSValue> {
+        let now = Timespec::now(TimespecMockMode::ForceRealTime).ms();
+        Ok(JSValue::js_number(now as f64))
+    }
 }

test/js/node/http/node-http-server-timeouts.test.ts

@@ -1,4 +1,4 @@
-import { describe, expect, test } from "bun:test";
+import { describe, expect, jest, setSystemTime, test } from "bun:test";
 import { once } from "node:events";
 import http from "node:http";
 import net from "node:net";
@@ -218,3 +218,142 @@ describe("node:http server timeout enforcement", () => {
     }
   });
 });
+
+// The server notes when a connection's last response finished and, when the
+// socket timer fires, grants whatever is left of the keep-alive budget from
+// that mark. The mark has to be taken on the real monotonic clock: Date.now()
+// follows bun:test's setSystemTime() and useFakeTimers(), and the mocked
+// monotonic clock that useFakeTimers() installs starts over at zero, so a mark
+// taken on either would decide when, or whether, an idle connection is closed.
+//
+// Each probe mocks the clock at some point, waits for the server to close the
+// connection and reports how long after the last response that happened. It
+// is timed with performance.now(), which setSystemTime() leaves alone and
+// useFakeTimers() freezes, so the end is read only after the mocks are
+// undone. Not concurrent: the mocks are process-wide and the tests above time
+// themselves with Date.now().
+describe("keepAliveTimeout idle expiry ignores mocked clocks", () => {
+  const KEEP_ALIVE_MS = 500;
+  // How long the server sits on the second request before answering it. The
+  // socket timer armed by the first response keeps counting down meanwhile,
+  // so it fires KEEP_ALIVE_MS - SLOW_RESPONSE_MS (200ms) into the second
+  // response's idle period and the expiry has to be settled from the mark.
+  const SLOW_RESPONSE_MS = 300;
+  const HOUR_MS = 60 * 60 * 1000;
+
+  async function probeIdleClose(options: {
+    requests: 1 | 2;
+    beforeRequests?: () => void;
+    afterLastResponse?: () => void;
+  }) {
+    // A probe that fails by timing out never reaches its cleanup; do not let
+    // its mocks leak into the next one.
+    jest.useRealTimers();
+    setSystemTime();
+    let requests = 0;
+    // Taken right before each res.end(), i.e. just before the server takes its
+    // own mark, so the idle time reported below can only be longer than what
+    // the server measured, never shorter because the response reached the
+    // client late.
+    let lastResponseEndedAt = 0;
+    const endResponse = (res: http.ServerResponse) => {
+      lastResponseEndedAt = performance.now();
+      res.end("response-body");
+    };
+    const server = http.createServer({ keepAliveTimeoutBuffer: 0 }, (req, res) => {
+      req.resume();
+      if (++requests === 2) {
+        setTimeout(endResponse, SLOW_RESPONSE_MS, res);
+      } else {
+        endResponse(res);
+      }
+    });
+    server.keepAliveTimeout = KEEP_ALIVE_MS;
+    const port = await listen(server);
+    const socket = net.connect(port, "127.0.0.1");
+    try {
+      socket.setNoDelay(true);
+      // An idle keep-alive close is a clean FIN; a reset or any other error
+      // would make this probe fail instead of timing an unrelated close.
+      const { promise: closed, resolve: onClosed, reject: onSocketError } = Promise.withResolvers<void>();
+      socket.on("error", onSocketError);
+      socket.on("close", () => onClosed());
+
+      let received = "";
+      let responsesWanted = 0;
+      let onResponse = () => {};
+      socket.on("data", chunk => {
+        received += chunk.toString("latin1");
+        if (received.split("response-body").length - 1 >= responsesWanted) onResponse();
+      });
+      const request = () => {
+        const { promise, resolve } = Promise.withResolvers<void>();
+        responsesWanted++;
+        onResponse = resolve;
+        socket.write("GET / HTTP/1.1\r\nHost: a\r\n\r\n");
+        return promise;
+      };
+
+      await once(socket, "connect");
+      options.beforeRequests?.();
+      await request();
+      if (options.requests === 2) await request();
+      options.afterLastResponse?.();
+      await closed;
+    } finally {
+      jest.useRealTimers();
+      setSystemTime();
+      socket.destroy();
+      server.closeAllConnections();
+      server.close();
+    }
+    return performance.now() - lastResponseEndedAt;
+  }
+
+  test("a clock moved forwards does not close the connection before its idle budget is used up", async () => {
+    // Settled against Date.now(), the timer fire 200ms into the second idle
+    // period sees an hour of idle time and closes the connection right there.
+    const idleMs = await probeIdleClose({
+      requests: 2,
+      afterLastResponse: () => setSystemTime(new Date(Date.now() + HOUR_MS)),
+    });
+    expect(idleMs).toBeGreaterThanOrEqual(KEEP_ALIVE_MS - 150);
+  });
+
+  test("a pinned clock does not double the idle budget", async () => {
+    // Settled against a Date.now() that never advances, the timer fire sees
+    // no idle time at all and re-arms for the whole budget once more, so the
+    // connection is closed after two budgets. That floor does not depend on
+    // machine speed, which is what makes the upper bound safe.
+    const idleMs = await probeIdleClose({
+      requests: 1,
+      beforeRequests: () => setSystemTime(new Date("2020-01-01T00:00:00Z")),
+    });
+    expect(idleMs).toBeGreaterThanOrEqual(KEEP_ALIVE_MS - 150);
+    expect(idleMs).toBeLessThan(2 * KEEP_ALIVE_MS);
+  });
+
+  test("a clock moved backwards does not keep the idle connection open", async () => {
+    // Settled against Date.now(), the timer fire re-arms the connection for
+    // the budget plus the hour the clock went back, and this probe only
+    // returns once the test times out.
+    const idleMs = await probeIdleClose({
+      requests: 1,
+      afterLastResponse: () => setSystemTime(new Date(Date.now() - HOUR_MS)),
+    });
+    expect(idleMs).toBeGreaterThanOrEqual(KEEP_ALIVE_MS - 150);
+  });
+
+  test("fake timers enabled after the response do not keep the idle connection open", async () => {
+    // The socket timer was armed on real timers, so it still fires on its
+    // own; what fake timers change is the clocks. A mark taken on Date.now()
+    // (pinned when the fake timers were enabled) or on the mocked monotonic
+    // clock (which restarts at zero) makes that fire re-arm the connection,
+    // and the new timer lands in the fake heap, where nothing ever fires it.
+    const idleMs = await probeIdleClose({
+      requests: 1,
+      afterLastResponse: () => jest.useFakeTimers(),
+    });
+    expect(idleMs).toBeGreaterThanOrEqual(KEEP_ALIVE_MS - 150);
+  });
+});