It Wasn't One Request - Everything Got Slow
Build a Ruler for Event Loop Stalls
Goal
Build the ruler that measures how long the event loop was stalled, and confirm with numbers how a single synchronous job delays every request of that process together.
Why it matters
When a report says "the API is slow," you usually look at that API's code first. But in Node, the culprit is often somewhere else. There is only one lane that runs JavaScript, so if one request holds that lane for 300ms, every request that arrives during that time is also delayed by 300ms. There is nothing wrong with the code of the API that got slow.
So the first tool in this course is not a profiler but a ruler. If you look at how late a timer that is set to fire at regular intervals actually fires, you get the time the loop was held by someone else's work in between. The key to this distribution is that the average barely moves and only the tail moves, which is why a dashboard that looks only at the average cannot catch this incident.
Steps
- In
/root/work/loop/lag.mjs, createpct(samples, p). - Create
sample({durationMs, intervalMs})in the same file. - Measure while doing nothing and write it to
/root/work/loop/report.json, underruns.idle. - Create
blockFor(ms), block once in the middle of measuring, and record it inruns.blocked. - Add to
runs.blockedthe count and ratio of samples that exceed 100ms, and the mean. - Handle several requests at once with
queue({n, serviceMs, blockAt, blockMs})and record it inruns.queue. - Create a rule that counts samples over budget with
verdict(run, budgetMs).
Notes
- Percentiles are counted by nearest-rank. After sorting in ascending order, take the
ceil(p/100 * n) - 1-th value, and clamp to the ends if it falls out of range. The grader recomputes with the same rule and compares. - Latency is what is left after subtracting the measured interval. If you store the elapsed time as it is, the median comes out as large as the interval even in a quiet state.
- In
report.json, thenodefield records the version of Node on this Pod (process.version). - A common mistake: thinking that samples keep accumulating while the loop is blocked. When the loop stops, timers stop too, so that stretch shows up as one sample with a large value.
Pin down the percentile first
In /root/work/loop/lag.mjs, export pct(samples, p). Use the nearest-rank rule, and do not sort the array you are given in place.
Sort a copy. Start with [...samples].sort((a, b) => a - b).
The rank is Math.ceil(p / 100 * n) - 1; if it is less than 0 or exceeds n, clamp it to the ends. It is normal for p99 to equal the maximum in a small sample.
How late the timer is equals how long the loop was stalled
Export sample({durationMs, intervalMs}) from the same file. Return a promise containing {intervalMs, durationMs, samples}, and put the late time minus the interval in ms into samples.
Wake up every intervalMs with setInterval, and subtract intervalMs from the difference from the time of the last wake-up. Clamp negative values to 0.
When durationMs has passed, call clearInterval and return the result. The grader takes this ruler and blocks the loop itself, so you must measure real time.
The baseline when nothing is going on
Measure for more than 1 second without doing anything, and in /root/work/loop/report.json record node and runs.idle. runs.idle holds intervalMs·durationMs·samples·p50·p99·max.
Without a baseline, you cannot say whether a number you measure later is large or small.
Compute p50, p99, and max with the pct you built. The grader recomputes them from samples and compares, so editing them by hand will fail.
Block once and measure again
Export blockFor(ms) (it must really hold the loop for that time), insert blockFor(300) just once while measuring, and record it in runs.blocked. Include blockMs as well.
Block only once, after measurement has started, like setTimeout(() => blockFor(300), 300).
await new Promise(r => setTimeout(r, ms)) does not block: the loop is free while you wait. Here you need something that holds the CPU.
Why the average says nothing
Add to runs.blocked the fields over100 (the number of samples over 100ms), over100Ratio (to four decimal places), and mean (the average).
Count how many samples exceed 100ms when you block for 300ms once.
Because of that one, some request stopped completely, yet the average is almost unchanged. The reason a dashboard that looks only at the average cannot catch this incident lies in these two numbers.
It was not just one request that got slow
Export queue({n, serviceMs, blockAt, blockMs}). Start n requests all at once, have each wait serviceMs, block only the blockAt-th one with blockFor(blockMs), and return an array of per-request latencies (ms). Measure with n=10 · serviceMs=20 · blockAt=2 · blockMs=300 and record the following in runs.queue: latencies·p50·p99·victims.
victims is the number of requests, excluding the blocked one, whose latency is at least blockMs * 0.8.
Starting all at once means creating all the promises first and waiting for them with Promise.all. If you write a for loop with an await inside it, the requests are handled one at a time, and what this lab is trying to show disappears.
Turn what you measured into a judgment
Export verdict(run, budgetMs). From run.samples, count the samples that exceed the budget (a value equal to the budget does not count as exceeding) and return {ok, worst, breaches}. If there are no samples, worst is 0.
If you do not decide which side the boundary value falls on, different people will give different answers. Here only > budgetMs is a violation.
With this function you can say "we exceeded the 100ms budget 3 times and the worst was 310ms" instead of "there is some latency." The conditions for an alert come from sentences like this.