CPU profiling in depth

What a CPU profile tells you

The CPU is the part of a computer that runs code. A CPU profile is a report of where your program spent CPU time during one run. Use one when a page feels slow, a server uses too much CPU, or an animation stutters.

A profile does not tell you what to fix. It tells you where to look first.

Here is a tiny program. One function does a lot of work. Another does almost none.

1function makeTea() {2  let heat = 0;3  for (let cup = 0; cup < 30; cup += 1) heat += cup;4  return heat;5}6 7function serve() {8  return "tea";9}10 11function handleOrder() {12  return `${serve()}: ${makeTea()}`;13}14 15console.log(handleOrder());

Line by line:

• Line 1 starts makeTea.
• Line 3 is a loop. It runs 30 times and adds up the numbers 0 to 29. Line 4 returns the total, 435.
• Line 7 starts serve. It returns "tea" right away.
• Line 11 starts handleOrder. Line 12 calls both functions and joins their results.
• Line 15 prints tea: 435.

The loop keeps makeTea busy for longer than the quick return in serve. So a profile should show makeTea as the busy function. A busy function, together with the chain of calls that leads to it, is called a hot path.

In a real app, the busy loop might read a server response, draw a chart, or filter a long list. The names change. The question stays the same: which function is running most of the time while the slow thing happens?

A profile describes one run only. It cannot tell you whether the result is right. It does not replace what users tell you, either. It gives you a place to look before you change code that only looks slow.

Start with the action that feels slow. For example, click the same button with the same cart three times. When you repeat one action, its busy function shows up again and again. Other work that happens now and then stands out less.

Two ways to collect a profile

A profiler is a tool that makes profiles. There are two main kinds:

• A sampling profiler pauses the program many times a second and takes a quick photo of the call stack. The call stack is the list of functions that have started and not finished yet. Each photo is called a sample.
• An instrumenting profiler adds a small piece of measuring code around every function. It writes down every time a function starts and every time it ends.

An instrumenting profiler counts every call exactly. But its measuring code is extra work, so the program runs slower while you measure it. A sampling profiler adds much less extra work, so the run stays close to normal.

The table compares the two kinds of profiler and the other words you will meet in this lesson. Read each row from left to right.

Here is a very small instrumenting profiler. It wraps one function and counts the call.

let calls = 0;

function measure(name, work) {
  calls += 1;
  const result = work();
  console.log(name, result);
  return result;
}

measure("serve", () => "tea");
console.log(calls);

• Line 1 makes a counter called calls.
• Lines 3 to 8 make measure, a wrapper: a function that runs another function for you and adds its own work around it.
• Line 4 adds 1 to the counter. Line 5 runs the work. Line 6 prints the name and the result.
• Line 10 measures one small function that returns "tea", so it prints serve tea.
• Line 11 prints 1, the number of calls.

The wrapper's own work is the cost. For every call, it adds to a counter and prints a line. A real instrumenting profiler does work like this around every function. That is why the program runs slower while you measure it.

Neither kind is better. Use instrumenting when you need exact counts. Use sampling when you want the run to stay close to normal and you want to find the big costs first.

A small sampling model

This model does not pause a real engine. Instead, it gets a fixed list of photos, so it gives the same answer every time. Each photo lists the calls from the first caller to the function running right then. The model counts two things:

• The self count of a function: how many photos end with it. The last name in a photo is the function that was running right then. Self count measures self time: the time a function spends doing its own work.
• The total count of a function: how many photos include it anywhere. This also counts photos where it was waiting for a function it called. Total count measures total time.

1const stacks = [Run2  ["handleOrder", "makeTea"],3  ["handleOrder", "makeTea"],4  ["handleOrder", "serve"],5];6 7const self = {};8for (const stack of stacks) {9  const leaf = stack.at(-1);10  self[leaf] = (self[leaf] ?? 0) + 1;11}12console.log(self.makeTea);

• Lines 1 to 5 list three photos.
• Line 8 walks through the photos one by one.
• Line 9 picks the last name in each photo.
• Line 10 adds 1 to that function's self count.
• Two photos end in makeTea, so line 12 prints 2.

Two samples does not mean two milliseconds. A sample count is a number of photos, not a time. A real profiler takes photos at a steady rate, so more photos means more time, but only roughly.

Later, the playground lets you take fewer photos. Fewer photos can still show the same big picture. But in a short run, the numbers can change a lot. That is why a profile shows you where to look. It does not prove an exact percentage.

const stacks = [
  ["handleOrder", "makeTea"],
  ["handleOrder", "serve"],
];
const leafs = stacks.map((stack) => stack.at(-1));
console.log(leafs.filter((name) => name === "makeTea").length);

Line 1 lists two photos. Line 5 keeps the last name from each photo. Line 6 counts how many of those names are makeTea, and prints 1. With many photos, this count divided by the number of photos estimates the share of time that makeTea was running.

If photos are taken at a different rate, the profiler may catch different moments. That is normal. When a small difference would change your decision, record for longer. Trust a pattern that shows up again and again more than one thin bar.

Flame charts: calls drawn as bars

A flame chart draws the photos as bars on a timeline. Chrome DevTools, the developer tools built into Chrome, shows one in its Performance panel. Here is how to read it:

• Left to right is time.
• Top to bottom is call depth. Each function sits just below the function that called it.
• A bar's width shows how long that function stayed on the call stack. In a sampling profile, this width is an estimate built from the photos.

1const stacks = [Run2  ["handleOrder", "makeTea"],3  ["handleOrder", "makeTea"],4  ["handleOrder", "serve"],5];6 7const width = {};8for (const stack of stacks) {9  for (const name of stack) width[name] = (width[name] ?? 0) + 1;10}11console.log(width.handleOrder);

This step-through does not draw a real timeline. It merges the photos: it counts how many photos each function is in. That count is the function's total count, and it decides the width of its bar.

• Lines 1 to 5 list the same three photos as before.
• Line 8 walks through the photos one by one.
• Line 9 adds 1 to the width of every function in the photo.
• handleOrder is in all three photos, so line 11 prints 3.

A real flame chart keeps each photo in its own place on the timeline. This merged version only shows widths.

const stacks = [
  ["handleOrder", "makeTea"],
  ["handleOrder", "makeTea"],
  ["handleOrder", "serve"],
  ["handleOrder", "makeTea"],
  ["handleOrder", "makeTea"],
  ["handleOrder", "makeTea"],
];

The playground uses six photos. You change one thing: how often a photo is taken. A tick here is one moment of the scripted run, and Reset goes back to a photo on every tick. When the numbers change, ask whether the same function is still the busiest. If you are not sure, record for longer before you decide.

Self count and total count come from the same photos. makeTea gets a self count each time it is the last name in a photo. handleOrder gets a total count from every photo, because every photo passes through it on the way to makeTea or serve.

This stops a common mistake. A calling function can have the widest bar and still do almost no work itself. Open that wide bar. Then follow its widest child down until you reach a function that keeps showing up as the one running.

Bottom-up: start from the busy function

A bottom-up view lists functions by self time, biggest first. It starts with the function that was running. Then it shows which functions called it. This helps when one small helper is slow but is called from many places.

const rows = [["makeTea", 5], ["serve", 1]];
console.log(rows.sort((a, b) => b[1] - a[1])[0][0]);

Line 1 makes two rows: makeTea with a self count of 5, and serve with a self count of 1. Line 2 sorts the rows from the biggest count to the smallest. Then it takes the first row and prints its name, makeTea. This matches the six photos in the playground: 5 is more than 1.

Use both views together:

• The flame chart shows when work ran, and which functions called it at that moment.
• The bottom-up view adds up how busy each function was by itself.
• A wide caller may do no work itself. All of its time may belong to one function it called.

Say three screens all call makeTea. In the flame chart, those calls sit in three different places, so none of them looks big on its own. The bottom-up view adds them together, so makeTea moves to the top of the list.

Then go back to the callers. A busy helper might need a cache (a saved result you can reuse), smaller inputs, or fewer calls. The bottom-up list tells you which function to understand. It does not tell you how to fix it.

Profiling Node programs

Node runs JavaScript outside the browser. It uses V8, the same JavaScript engine that is inside Chrome. Node has two built-in ways to make a CPU profile:

• --prof writes V8's own log of samples. V8 calls each sample a tick. Then --prof-process turns the log into a text summary.
• --cpu-prof saves a .cpuprofile file that Chrome DevTools can open.

# Node's own profiler: write a log, then sum it up
node --prof app.js
node --prof-process isolate-*.log

# Save a file that Chrome DevTools can open
node --cpu-prof --cpu-prof-dir=profiles app.js

# Linux only: record with the perf tool
perf record -g node --perf-basic-prof app.js

• Line 2 runs app.js with --prof. Line 3 turns the log it wrote into a summary.
• Line 6 runs app.js with --cpu-prof and saves the file in a folder called profiles.
• Line 9 works only on Linux. perf is a Linux tool that can profile any program, and -g asks it to record call stacks. --perf-basic-prof makes Node write down the names of its JavaScript functions, so perf can show them.

The test for this lesson runs a tiny program with --cpu-prof and reads the file it saves. It checks only facts that stay the same on every run:

• A function with a special name appears in the file's nodes list, the list of functions.
• The file's samples list, the list of photos, is not empty.

It never checks a time or an exact number of samples. Those change from run to run.

For node --prof, run the program once. Node writes a log file whose name starts with isolate-. Pass that file to node --prof-process to get a text summary of V8's ticks. Keep the log next to the command that made it, so you can make the same report again later.

For node --cpu-prof, open the file in the Performance panel of Chrome DevTools. The file lists functions and photos, so DevTools can show function names, callers, and a timeline. For most JavaScript teams, this is the easiest file to start with.

When the engine merges functions

While your program runs, V8 can rewrite busy functions into faster machine code. This is called optimizing. One trick it uses is inlining: copying a small function's code into the function that calls it. Then there is no separate call any more. Your program's results stay exactly the same.

function serve() { return "tea"; }
function handleOrder() { return serve(); }

// When this code gets busy, the engine may copy serve's code into handleOrder.
// DevTools can still show a serve bar, using notes about where code came from.
console.log(handleOrder());

• Line 1 makes serve, which returns "tea".
• Line 2 makes handleOrder, which calls serve.
• Lines 4 and 5 are comments.
• Line 6 prints tea.

After inlining, the code of serve runs inside handleOrder. So the profiler may count that time under handleOrder instead of serve.

DevTools often still shows a serve bar. The engine keeps notes about which line of your code each piece of machine code came from. DevTools reads those notes and draws the bar with your function names. So the bar is still useful. Just don't assume that every bar is one real, separate call.

Here is a simple way to picture it. Before inlining, handleOrder calls serve, and serve returns to it. After inlining, the code that returns "tea" sits inside handleOrder. So the time can move up to the caller.

When you check whether a change helped, compare profiles from before and after the change. Look at the whole path around a function, not just one bar.

Time spent inside the engine

Sometimes the time is not in your functions at all. It is in the engine's own jobs. Runtime call stats are counters inside V8 that add up time for each kind of engine job. Chrome's tracing tools can show them. The jobs include:

• Parsing: reading your source code.
• Compiling: turning that code into instructions the machine can run.
• Garbage collection (GC): freeing memory that nothing uses any more.
• Inline-cache misses: an inline cache is a note V8 keeps about the kind of object it saw at one place in your code. A miss means the note didn't match, so V8 looks up the property the slow way.

// Chrome's tracing tools can show V8's runtime call stats.
// They add up engine jobs: parsing, compiling, GC, and inline-cache misses.
// Use them to see where engine time went, not to time one small call.
console.log("record a trace, then inspect RuntimeCallStats");

Lines 1 to 3 are comments, not code that calls the browser. Line 2 lists the kinds of engine jobs. Line 4 prints a reminder: record a trace, then look at the RuntimeCallStats view. A trace is a detailed recording of everything the browser did for a short time.

Use these counters when your own functions don't explain the time. Different engine versions may show different counter names.

For example, a short function in your app might cause a lot of parsing or garbage collection. Runtime call stats help you ask the next question. Is the engine busy compiling new code? Is it cleaning up short-lived objects? Or is it handling inline-cache misses?

Use this tool last. First find the slow user action and the JavaScript functions behind it. Look at engine jobs only when your own functions leave a big part of the time unexplained.

Profiling a slow page

Start with a real action, like typing in a search box, opening a cart, or loading a report. Use realistic data. Record one profile first. This first profile is your baseline: the one you compare against later. Find a busy path that shows up every time. Then change one thing and record again.

• Profile a normal run with real data, not an empty page.
• Use the flame chart to see which function called which. Use the bottom-up view to find the functions that were busy themselves.
• When you time a small piece of code on its own, use its result. Otherwise the engine may skip work whose result is never used.
• Compare profiles of the same action, on the same machine, before and after a change.

function filterOrders(orders, query) {
  return orders.filter((order) => order.name.includes(query));
}

const orders = [{ name: "tea" }, { name: "toast" }, { name: "tea cake" }];
const visible = filterOrders(orders, "tea");
console.log(visible.length);

• Line 1 makes filterOrders, which a search page uses. Line 2 checks the name of every order.
• Line 5 makes three orders.
• Line 6 keeps the orders whose name includes tea.
• Line 7 prints 2.

The code is small on purpose. The same code gets slow when a real page runs it over a long list on every key press.

Find the busy function on a slow page

First, open the slow page with the usual amount of data. Start recording, type one search word, and stop when the results appear. Don't record an empty page if users say the page is slow with a full list.

Second, in the flame chart, follow the wide path from the key press down to a function that repeats. Third, open the bottom-up view and find the function with the biggest self time. If it is filterOrders, check how often it runs and how many orders it checks each time.

Finally, make one change. For example, filter only after the user stops typing for a moment, or stop filtering the same list twice. Record the same action again. Keep the change only if the busy path got smaller and the results are still right.

To check what users feel, use CPU profiles together with measuring performance and the main thread. To learn how the engine makes code faster, go back to optimizing compilers.

Common mistakes

A good profile turns a big question into a smaller one. "Why is the page slow?" becomes "Why is this function running in so many photos during this action?" Then you can answer with facts instead of guesses.

• "The widest bar is always the problem." It may be a caller. All of its time may belong to a function it called, which is doing the work.
• "One profile is a benchmark." A benchmark is a careful timing test that you repeat many times. One profile is just one look at one run.
• "Inlining hides my function names." DevTools can usually still show the inlined function by name. Only its time may move to the caller.
• "A sample count is an exact time." It is an estimate. It depends on how often photos were taken and on that one run.

Each row of this table is a word you see in a profile. Read across to see what it tells you and what it does not tell you.

When two runs disagree, check the data, the machine, and how long you recorded. Do this before you change any code. A new profile is something to compare, not a score to beat.

Practice exercises

const stacks = [["handleOrder", "makeTea"], ["handleOrder", "makeTea"], ["handleOrder", "serve"]];
console.log(stacks.filter((stack) => stack.at(-1) === "makeTea").length);

function serve() { return "tea"; }
function handleOrder() { return serve(); }
console.log(handleOrder());

Check your understanding

Use the same two steps for every question. First ask what the tool saw. Then ask how the view adds it up.

Key takeaways

• A sampling profiler takes photos of the call stack. It estimates where the time went.
• An instrumenting profiler records every call exactly, but it slows the program down.
• A flame chart shows calls over time. A bottom-up view adds up how busy each function was by itself.
• Use node --cpu-prof to get a file that DevTools can open. On Linux, perf can profile Node too.
• Inlining can move time from a small function to its caller. DevTools usually still shows the small function's name.
• Runtime call stats show time spent on engine jobs, not in your own functions.

Coming next: Benchmarking without fooling yourself.