Performance Profiling

A program can perform poorly without leaking memory at all. What the user sees is not a memory graph, it is an interface that responds late to a click, or a service whose response time fluctuates.

This lesson’s criterion is different from memory: how long the thread stays locked onto a single job. The blocking concept from the course’s first lesson becomes measurable here.

No duration value will be printed throughout the lesson; durations vary by machine and load and are misleading when written down. What is measured is order, what is shown is method.

Long Task

On every turn, the event loop takes one job from the task queue and runs it to completion. If this job takes a long time, during that whole time no click is handled, no response is parsed, no frame is drawn.

Tasks that exceed a given threshold are called a long task. The threshold is defined by the environment; fifty milliseconds is a common bound in browser measurement interfaces. What matters is not the number itself but the reasoning behind it: for user interaction to be counted as smooth, the thread has to become free at regular intervals.

A long task’s second measure is called event loop lag. Its method is direct: a timer is set up with a known delay, and how much later the callback actually runs is observed. The gap is the measure of how busy the thread was at that moment. On the server side, this value is the first indicator that explains fluctuation in response times.

Splitting and Yielding

Speeding up a long job is not always possible; but splitting it is possible most of the time. A split job yields to the event loop between pieces, and pending tasks get to interleave.

function busyWait(duration) {
  const deadline = Date.now() + duration;
  while (Date.now() < deadline) {
    // Deliberately keeps the thread busy.
  }
}

function yieldTurn() {
  return new Promise((resolve) => setTimeout(resolve, 0));
}

async function processInOnePiece() {
  setTimeout(() => console.log("  interleaving task"), 0);
  busyWait(60);
  console.log("  processing finished");
  await yieldTurn();
}

async function processInPieces() {
  setTimeout(() => console.log("  interleaving task"), 0);
  for (let i = 1; i <= 3; i += 1) {
    busyWait(20);
    console.log("  piece", i, "finished");
    await yieldTurn();
  }
}

console.log("single-piece processing:");
await processInOnePiece();

console.log("split processing:");
await processInPieces();

single-piece processing:
  processing finished
  interleaving task
split processing:
  piece 1 finished
  interleaving task
  piece 2 finished
  piece 3 finished

In single-piece processing, the pending task was left until the very end; in split processing, it interleaved right after the first piece. The total work is the same — there is sixty milliseconds of busy time in both cases. What changes is how long the pending task waits.

Here it is also visible that yielding a turn cannot be done with a microtask. Per the rule from the Event Loop lesson, the microtask queue is drained completely; queueMicrotask or awaiting an already-settled promise does not yield a turn to the task queue. A real turn is given only by returning to the task queue.

Splitting has a cost too: as piece count grows, a per-round overhead is paid and total duration lengthens. The right piece size is the balance between “staying responsive” and “working efficiently.” If the computational load is genuinely heavy, the right answer is not splitting the response but moving the work to a separate execution context.

Measurement Marks

To see where time is spent, the intervals to be measured first need to be named. The standard measurement interface offers two concepts: a mark, which marks a specific moment, and a measure, which names the span between two marks.

import { PerformanceObserver, performance } from "node:perf_hooks";

function busyWait(duration) {
  const deadline = Date.now() + duration;
  while (Date.now() < deadline) {
    // Deliberately keeps the thread busy.
  }
}

const observer = new PerformanceObserver((list) => {
  for (const entry of list.getEntries()) {
    console.log("entry:", entry.entryType, "—", entry.name, "— was duration measured:", entry.duration > 0);
  }
});
observer.observe({ entryTypes: ["measure"] });

performance.mark("parsing-started");
busyWait(20);
performance.mark("parsing-finished");
busyWait(10);
performance.mark("write-finished");

performance.measure("parsing", "parsing-started", "parsing-finished");
performance.measure("write", "parsing-finished", "write-finished");
performance.measure("total", "parsing-started", "write-finished");

await new Promise((resolve) => setTimeout(resolve, 10));
observer.disconnect();

entry: measure — parsing — was duration measured: true
entry: measure — total — was duration measured: true
entry: measure — write — was duration measured: true

Duration values were not printed; only that the measurement took place was confirmed. The output order is instructive too: entries are ordered not by creation order but by start moment. The “total” measure was created last, but because it starts from the same mark as “parsing,” it appears second.

Marks’ value is that they make measurement embedded in the code and named. In an asynchronous flow, an operation’s start and end happen in different turns; without a mark, these two moments cannot be tied together by the same measurement.

Sampling Profile

Placing a mark works when you know where to look. When you do not, a profiler is used.

The common method is sampling: the profiler takes a snapshot of the call stack at regular intervals. The result tells which function was at the top of the stack in how many samples; this gives a statistical estimate of the time share falling to each function.

Two properties of the method determine how the result should be read. The measurement is approximate — a function that runs very briefly may fall into no sample at all. In exchange, its cost is low and it does not noticeably change the program’s behavior.

The profile is taken from the runtime’s debugging interface, and its nodes carry call frame information.

import { Session } from "node:inspector/promises";

function busyWait(duration) {
  const deadline = Date.now() + duration;
  while (Date.now() < deadline) {
    // Deliberately keeps the thread busy.
  }
}

const session = new Session();
session.connect();
await session.post("Profiler.enable");
await session.post("Profiler.start");

busyWait(60);

const { profile } = await session.post("Profiler.stop");
session.disconnect();

console.log("profile fields:", Object.keys(profile).sort().join(", "));
console.log("was a sample taken:", profile.samples.length > 0);
console.log("is our own function among the nodes:", profile.nodes.some((d) => d.callFrame.functionName === "busyWait"));

profile fields: endTime, nodes, samples, startTime, timeDeltas
was a sample taken: true
is our own function among the nodes: true

The field names explain the profile’s structure. nodes are the call tree’s nodes; each node represents a function and its call frame. samples is, for every sample taken, the id of the node at the top of the stack. timeDeltas is the duration between consecutive samples. The flame chart interface-based tools draw is nothing more than a visualization of these three arrays.

The rule for reading the chart follows from this too: width is duration, height is call depth. A wide, short block shows a single function running for a long time; a narrow, deep stack shows many short calls.

What Not to Measure

Three common mistakes render results unusable.

The duration of a single run does not count as a measurement. The first run carries compilation and cache-warming cost; the measurement has to be repeated and the distribution examined.

An average alone is not enough. What determines user experience is the outliers; slow percentiles need to be tracked separately.

An asynchronous flow’s “duration” is not the total running time of its functions. Time spent waiting does not occupy the thread; it is invisible in the profile but real for the user. For this reason a profile is read together with end-to-end measurement.

Summary

• A long task is a task that locks the thread onto a single job and delays every pending job; event loop lag is its measure.
• Splitting a long job and yielding to the task queue lets pending jobs interleave; a turn cannot be yielded with a microtask.
• The mark and measure interface binds moments falling on different turns in an asynchronous flow into named intervals; entries are ordered by start moment.
• A sampling profiler takes a copy of the call stack at regular intervals; its result consists of call-tree nodes, samples, and time deltas.
• A single run, an average alone, and profile data alone are all misleading; measurement is read together with repetition, distribution, and end-to-end duration.

Next Step

Measurement tells you where time is spent, but not what is wrong. The course’s last lesson takes up the second half of diagnostic tools: stopping a program at a specific point and examining its state. Breakpoints, stepping, watch expressions, and reading asynchronous call stacks — all will be shown on the same instance of the measurement stream.