Reading the Engine: Traces, Snapshots, Profiles, and Natives

Optimisation and deoptimisation traces

Run any script with node --trace-opt --trace-deopt and V8 narrates chapter 8 in real time. A tier-up line reads like [marking 0x... <JSFunction add (sfi = 0x...)> for optimization to TURBOFAN, ConcurrencyMode::kConcurrent, reason: hot and stable], then [compiling method ... (target TURBOFAN)] and [completed compiling ...] with the time taken. A deoptimisation line reads [bailout (kind: deopt-eager, reason: not a Smi): begin. deoptimizing ..., opt id 3, bytecode offset 12, deopt exit 5, FP to SP delta 32, caller SP 0x..., pc 0x...] followed by the frame it rebuilt. Three fields are the whole story: the kind (eager, lazy, or soft; chapter 8), the reason (not a Smi, wrong map, Insufficient type feedback for call, wrong instance type, out of bounds, Array buffer was detached), and the bytecode offset, which --print-bytecode maps back to the source expression. A function that shows [marking ...] more than a few times is being repeatedly deoptimised and re-optimised; V8 eventually gives up (optimization disabled: too many deopts), and the trace is the only place that decision is visible.

[marking 0x2f8d... <JSFunction add (sfi = 0x1e2a...)> for optimization to MAGLEV, ConcurrencyMode::kConcurrent, reason: hot and stable]
[completed compiling 0x2f8d... <JSFunction add> (target MAGLEV) - took 0.041, 0.312, 0.019 ms]
[marking 0x2f8d... <JSFunction add> for optimization to TURBOFAN, ConcurrencyMode::kConcurrent, reason: hot and stable]
[completed compiling 0x2f8d... <JSFunction add> (target TURBOFAN) - took 0.118, 1.904, 0.061 ms]
[bailout (kind: deopt-eager, reason: not a Smi): begin. deoptimizing 0x2f8d... <JSFunction add>, opt id 2, bytecode offset 2, deopt exit 1, FP to SP delta 32, caller SP 0x7ffd..., pc 0x5583...]
            ;;; deoptimize at <add.js:1:22>, not a Smi
[marking 0x2f8d... <JSFunction add> for optimization to TURBOFAN, ConcurrencyMode::kConcurrent, reason: hot and stable]
[completed compiling 0x2f8d... <JSFunction add> (target TURBOFAN) - took 0.132, 2.417, 0.070 ms]

Natives syntax: asking V8 about its representation directly

V8 exposes several hundred internal functions to JavaScript behind the flag --allow-natives-syntax, invoked with a % prefix. They are not part of the language and have no stability guarantee, but a handful are indispensable for verifying claims that timings can only suggest: %HaveSameMap(a, b) answers whether two objects share a Shape (chapter 3); %HasFastProperties(o) distinguishes fast from dictionary mode; %HasSmiElements, %HasDoubleElements, %HasObjectElements, %HasHoleyElements, and %HasDictionaryElements report elements kinds (chapter 2); %GetOptimizationStatus(f) returns a bitfield saying whether f is interpreted, baseline, Maglev, or TurboFan code; %OptimizeFunctionOnNextCall(f) and %PrepareFunctionForOptimization(f) force tier-up so a test does not depend on heuristics; %DebugPrint(o) dumps the object's Map, elements kind, and property layout to stdout; and %CollectGarbage(null) triggers a full GC so WeakRef and FinalizationRegistry behaviour (chapter 7) can be observed deterministically. test262 does not use them (they are not ECMAScript), but V8's own test suite (mjsunit) is written almost entirely in terms of them, and so are the recordings below.

// Requires: node --allow-natives-syntax. Each %Function is a V8 internal, not JavaScript.
const a = { x: 1, y: 2 }, b = { x: 3, y: 4 }, c = { y: 4, x: 3 };
console.log("same literal shape -> same Map:", %HaveSameMap(a, b));
console.log("different insertion order -> different Map:", %HaveSameMap(a, c));

const d = { x: 1, y: 2, z: 3 };
console.log("fresh object has fast properties:", %HasFastProperties(d));
delete d.y;
console.log("delete -> dictionary mode (fast properties):", %HasFastProperties(d));

const arr = [1, 2, 3];
console.log("packed Smi elements:", %HasSmiElements(arr), "| holey:", %HasHoleyElements(arr));
arr.push(1.5);
console.log("after pushing 1.5 -> double elements:", %HasDoubleElements(arr));
arr.push({});
console.log("after pushing {} -> object elements:", %HasObjectElements(arr), "(and never back)");
const holey = new Array(3);
console.log("new Array(3) is holey:", %HasHoleyElements(holey));
holey[0] = 1; holey[1] = 2; holey[2] = 3;
console.log("filling every slot does not un-hole it:", %HasHoleyElements(holey));

// Optimisation status is a bitfield; decode the interesting bits.
function add(p, q) { return p + q; }
%PrepareFunctionForOptimization(add);
add(1, 2); add(3, 4);
%OptimizeFunctionOnNextCall(add);
add(5, 6);
const status = %GetOptimizationStatus(add);
const bits = { "is function": 1, "never optimize": 2, "always optimize": 4, "maybe deopted": 8, "optimized": 16, "maglevved": 32, "turbofanned": 64, "interpreted": 128, "marked for optimization": 256 };
console.log("optimization status of add:", Object.entries(bits).filter(([, m]) => status & m).map(([k]) => k).join(", "));
add("x", 1);                                          // string + number: the Smi speculation fails
const after = %GetOptimizationStatus(add);
console.log("after a string argument, still turbofanned:", Boolean(after & 64), "| maybe deopted:", Boolean(after & 8));

Heap snapshots: the object graph as a dominator tree

A heap snapshot (DevTools Memory panel, v8.writeHeapSnapshot(), or --heapsnapshot-signal) is a serialisation of every live object as a node with a type, a name, a shallow size, and typed edges (property, element, internal, hidden, weak, context variable) to the objects it references. The tools then compute the dominator tree: object D dominates object O if every path from a root to O passes through D. An object's retained size is the total shallow size of everything it dominates: what would become garbage if it alone were unreachable. That is the number to sort by when hunting a leak, because it points at the object that owns the memory rather than the many small objects that make it up. Every node also has a retainer path, the shortest chain of edges from a GC root; DevTools' "Retainers" panel shows it with edge names, so (closure) → context → big (chapter 5) or Window → listeners → handler → component → detachedNode read as the actual chain of references keeping the object alive. Comparing two snapshots ("Objects allocated between snapshots 1 and 2") isolates the growth; a third snapshot after the supposed cleanup confirms whether the fix worked.

CPU profiles: self time, total time, and what a sample is

A CPU profile (node --cpu-prof, DevTools Performance panel, inspector.Session with Profiler.start) is produced by sampling: every 100 µs to 1 ms a timer interrupts the thread and records the current JavaScript stack. The profile is the histogram of those stacks. Self time of a function is the number of samples in which it was the top frame, that is, time spent in its own code; total time counts samples in which it appears anywhere on the stack, including callees. A function with high total time and low self time is a coordinator; one with high self time is where the work happens. Because sampling is statistical, a function that runs for 20 µs once will usually not appear at all, and inlined callees are attributed to the caller unless the profiler is told to use the deoptimisation metadata to reconstruct inlined frames (V8 does this by default in recent versions, which is why an inlined map callback still shows up). Two artefacts are worth recognising: (garbage collector) samples, which are time the mutator was paused (chapter 7), and (program), which is native time V8 cannot attribute to a JavaScript frame (parsing, compilation on the main thread, ICs missing into the runtime). A profile heavy in (program) is a compilation or IC problem, not a hot loop, and the traces from the first section will show which.

// Sample the call stack from Error().stack at intervals during a workload, then tabulate
// self and total time per function. This is exactly what a real profiler does, minus the interrupt.
const samples = [];
let lastSample = 0;
function sample() {                                          // called at a few points in the hot code
  const now = performance.now();
  if (now - lastSample < 0.2) return;                        // ~200 µs sampling interval
  lastSample = now;
  const frames = new Error().stack.split("\n").slice(2).map((l) => (l.match(/at (\S+)/) || [, "(anonymous)"])[1]).filter((f) => f !== "sample");
  samples.push(frames);
}
function inner(n) { let s = 0; for (let i = 0; i < n; i++) { s += Math.sqrt(i); if ((i & 1023) === 0) sample(); } return s; }
function middle(n) { let s = 0; for (let k = 0; k < 4; k++) s += inner(n); sample(); return s; }
function outer(n) { const r = middle(n) + inner(n / 2); sample(); return r; }
outer(600000);

const self = new Map(), total = new Map();
for (const frames of samples) {
  self.set(frames[0], (self.get(frames[0]) || 0) + 1);
  for (const f of new Set(frames)) total.set(f, (total.get(f) || 0) + 1);
}
const names = ["inner", "middle", "outer"].filter((n) => total.has(n));
console.log(samples.length, "samples");
for (const n of names) console.log(n.padEnd(7), "self:", String(self.get(n) || 0).padStart(4), " total:", String(total.get(n)).padStart(4));
console.log("total time: outer ≥ inner:", (total.get("outer") || 0) >= (total.get("inner") || 0), "| self time concentrates in inner:", (self.get("inner") || 0) > (self.get("outer") || 0));

In the browser: memory measurement and the Performance panel

Cross-origin isolated pages (chapter 11) may call performance.measureUserAgentSpecificMemory(), which returns the memory attributed to the page's agent cluster broken down by container (the top-level page, iframes, workers) and type (JavaScript heap, DOM, canvas). It is asynchronous and rate-limited because the measurement piggybacks on a garbage collection, and it is deliberately coarse so that it cannot be used as a side channel (chapter 16). performance.memory is the older, Chrome-only, synchronous version that reports only the JS heap and excludes ArrayBuffer backing stores, which is why chapter 5's retention probe warned that it may show nothing. The Performance panel records the main thread as a flame chart annotated with tasks, microtask checkpoints, rendering phases, and GC events; reading it against chapter 6 makes the distinction between a long task and many microtasks visible as one wide bar versus a dense comb.

console.log("crossOriginIsolated:", globalThis.crossOriginIsolated);
if (typeof performance.measureUserAgentSpecificMemory === "function") {
  const before = await performance.measureUserAgentSpecificMemory();
  const keep = Array.from({ length: 200000 }, (_, i) => ({ i, s: "x" + i }));          // ~ tens of MB of objects
  const after = await performance.measureUserAgentSpecificMemory();
  console.log("bytes before:", before.bytes.toLocaleString(), "| after allocating 200k objects:", after.bytes.toLocaleString(), "| delta:", ((after.bytes - before.bytes) / 1e6).toFixed(1), "MB");
  console.log("breakdown types:", after.breakdown.map((b) => b.types.join("+") + ":" + (b.bytes / 1e6).toFixed(1) + "MB").join(", "));
  keep.length = 0;
} else if (globalThis.performance?.memory) {
  console.log("performance.memory (Chrome-only, JS heap only):", (performance.memory.usedJSHeapSize / 1e6).toFixed(1), "MB used of", (performance.memory.jsHeapSizeLimit / 1e6).toFixed(0), "MB limit");
} else {
  console.log("No memory measurement API in this context. In Node: process.memoryUsage() and v8.getHeapStatistics().");
}