The 1.1 microseconds Node charged every request

2026-09-30

On Node, Nifra's plain GET was consistently slower than Fastify's by about a microsecond of user CPU per request. The cause was not in our router, our response writer, or the kernel. It was the moment in the process's life at which one internal Node class was first touched.

The symptom

The gap was small, stable, and would not go away. It showed up as CPU per request rather than as a latency spike, which is the signature of extra work on every request rather than an occasional stall.

BASH
# user CPU per request, bare GET, Linux rig, same machine
nifra (node)   9.28 us
fastify        8.34 - 8.60 us

What it was not

Three suspects were cleared before the real one turned up, and each was cleared by measurement rather than by argument.

  • The kernel. Both servers made the same system calls at the same rate, to three decimal places. Whatever the difference was, it lived in user space.
  • Payload size. The gap stayed between 0.5 and 1.0 us as the response grew from 578 to 3,363 bytes. A cost that does not scale with bytes is not an encoding or a copying cost.
  • Garbage collection and worker threads. Together they accounted for 0.06 us of a 0.84 us difference.
BASH
# syscalls per request, nifra vs fastify
read          1.002   1.002
write         1.002   1.002
writev        1.000   1.000
epoll_pwait   0.126   0.126

The tell

With those gone, the profile had one thing left to say. Nifra's had frames from Node's async-context machinery that Fastify's did not have at all, and the function that drains the microtask and tick queues was spending 2.4 times as long in its own body.

BASH
# CPU profile, frames present in nifra and absent from fastify
exchange  @ async_context_frame
current   @ async_context_frame
set       @ async_context_frame       230 samples

processTicksAndRejections self time   2.4x fastify's

Neither server used AsyncLocalStorage on that route. So why did only one of them show the frames?

The cause

On Node 26, AsyncContextFrame starts out inactive, and its methods are no-ops. The first read of its enabled flag swaps the class over to the active implementation. Every HTTP server triggers that read sooner or later, because closing a socket clears a timer and clearing a timer asks the async-context layer to forget it.

The difference between the two servers was when.

  • Fastify touches it while booting, about 0.2 seconds into the process, before any request has been served.
  • Nifra first touched it when the first connection closed, about 2 seconds in and well into the load.

By then V8 had already optimized the tick loop with the inactive no-op methods inlined. Swapping the implementation underneath it invalidated that code, and the call site stayed slower for the rest of the process's life. Nothing was wrong with either implementation. The order of two events was the whole bug.

The proof took one line: construct an AsyncLocalStorage at boot and do nothing with it. Samples in the tick loop dropped from 449 to 95. Fastify's count on the same run was 89.

The fix

serve() in @nifrajs/node now activates the frame before it starts listening. The general form, for any Node server, is this:

TS
import { AsyncLocalStorage } from "node:async_hooks"

// Before the first request. Constructing one store is enough to make Node
// switch AsyncContextFrame to its active implementation now, while nothing
// that depends on it has been optimized yet.
new AsyncLocalStorage()
BASH
# 6 interleaved pairs, both orders, bare GET
before   9.28 us user CPU / request
after    8.20 us user CPU / request     -1.08 us  (-11.6%)   12 of 12 runs agree

# after the fix
                 bare GET            full middleware stack
nifra (node)     8.34 - 8.59 us      10.68 us
fastify          8.34 - 8.60 us      10.53 us

The bare GET is now inside Fastify's own run-to-run range. The full-stack row is 1.4% apart, which is under the 2 to 5% noise floor of the rig, so we call that a tie and not a win.

Two things we fixed in our own benchmark first

Before trusting any of this, the comparison itself had to be fair, and it was not. Both defects flattered Nifra.

  • The Fastify arm declared its hooks async, which charged it two extra microtasks per request that an idiomatic Fastify app would not pay.
  • The peer servers sent a strict-transport-security header and omitted vary, so the responses differed by 66 bytes.

Both were corrected before the numbers above were taken. A benchmark you maintain yourself drifts in your own favor unless you go looking for the places it does.

What to take from it

If you run a Node HTTP server and do not already create an AsyncLocalStorage at startup, the experiment costs one line and a before-and-after profile. Look for async_context_frame frames and for self time in processTicksAndRejections. The method is in the benchmark notes, and the rig is in the repository.