TT Lab
Get started
Learn Learning paths Courses

It Wasn't One Request - Everything Got Slow

If Everything Slowed Down At Once, There Is Only One Lane

Continue in TT Lab

In one line

In Node, JavaScript runs in a single lane. So "this API is slow" and "everything is slow" are usually not different events but two faces of the same event, and you can measure how long that lane was stalled without a profiler.

Why this was needed

A report always points at one place: "The payment confirmation API sometimes takes 3 seconds." You open that API's code and look at the query, the index, and the external calls. Nothing looks wrong. What you should do then is not dig further into that API, but check whether the latency of other APIs went up at the same time.

If it did, the culprit is not that API. Inside a Node process there is only one lane that runs JavaScript, and that lane is handed to no one until the callback currently running gives it back itself. It is not preemptive scheduling, where the operating system slices time and takes it away; it is cooperative, where each party yields on its own. So if one callback holds the CPU for 300ms, every request that arrives in that time waits 300ms. There is nothing wrong with the code of those requests. They were just standing in line.

This structure is not a defect but a choice. Because it does not start a thread per request, it can handle tens of thousands of connections with little memory. In exchange comes the rule that you must not do long work in one go. To check whether you are keeping the rule you have to measure, which is why the first tool in this course is not a profiler but a ruler.

How it works

The event loop goes around in several phases. The order is: a phase that checks whether timers (setTimeout·setInterval) have expired, a phase that calls completed I/O callbacks, a poll phase that waits for new events, and a check phase that calls setImmediate. The detailed order is laid out in the official guide The Event Loop, Timers, and process.nextTick(). What matters is not the names of the phases but the fact that to move between phases, the current callback has to finish.

This is where the way of measuring comes from. If a timer set to fire every 20ms actually fired after 320ms, then for the 300ms in between the loop was held by other work. The official documentation gives the same grounds: "the execution of timers is tied to the lifetime of the libuv event loop, so a delay in the loop shows up as a delay in timers" (perf_hooks).

let last = Date.now();
setInterval(() => {
  const now = Date.now();
  const lagMs = Math.max(0, now - last - 20);   // 간격을 뺀 나머지가 지연이다
  last = now;
}, 20);

Node also provides a built-in tool that does the same job. perf_hooks.monitorEventLoopDelay() produces a histogram, and there are two things to know before using it. The unit of the values is nanoseconds, and the default sampling interval (resolution) is 10ms. So even in a process where nothing is going on, the median of this histogram comes out near 10ms, not 0. When measured on Node 22.11.0 in the lab image, the p50 in a quiet state was 10.5ms. If you read this value as "our service is always 10ms behind," you end up chasing a problem that does not exist. If you build the ruler yourself, you get a feel for where that floor comes from.

What it looks like in the field

The nastiest property of this incident is that the average barely moves. Of 44 samples taken at 20ms intervals over 1.2 seconds, only one exceeded 100ms, and the average was 7.7ms (measured on Node 22.11.0, 2 cores). A dashboard that plots average latency stays flat even while this incident is happening. The only things that move are the maximum and p99.

The second property is that there are multiple victims. Under the same conditions, I sent 10 requests at once and made only the third one hold the CPU for 300ms; the 7 requests other than itself all took more than 300ms as well. The log shows 8 slow requests, and only 1 of them is the real cause. No amount of staring at the code of the other 7 will give you the answer.

So an outage investigation for a Node service should start not with "find the slow endpoint" but with "look at what else slowed down at the same time." If things slowed down together, it means there is one lane, and the only question after that is "who held that lane?"

What you will do in the next lab

You will build the ruler that measures the latency distribution yourself. First pin down the rule for counting percentiles, collect the amount by which the timer was late as samples, insert one synchronous job, and confirm that only the tail moves. Then send ten requests at once and count how many are delayed by the stall of a single one, and finally turn those numbers into a judgment: "how many times did we exceed the budget?"

The grader recomputes the p50, p99, and max you wrote from the samples and compares them, and it runs the function you built once more to see whether the same properties appear. Writing plausible-looking numbers alone will not pass.