Ad-hoc module-loading benchmarks for the nodejs/node Module._load resolve-cache change

README.md

Ad-hoc module loading benchmarks for nodejs/node Module._load resolve-cache change

Scripts used to benchmark https://github.com/nodejs/node/compare/main...MarshallOfSound:node:perf/cache-only

Usage

# 1. generate the fixture module graphs (next to these scripts)
python3 fixtures-generate.py        # cjs-app, cjs-pkgs, cjs-exports, esm-app
python3 fixtures-extra.py           # hot loops, lazy pattern, scaling variants

# 2. interleaved A/B matrix (medians of N runs, drift-cancelling A,B,A,B order)
python3 bench-matrix.py /path/to/node-baseline /path/to/node-patched 21

# 3. optional: summarize a --cpu-prof profile by self-time
python3 profile-summary.py isolate.cpuprofile 30

Each fixture self-times its module-loading phase with process.hrtime.bigint() and prints milliseconds, so process startup is excluded from all numbers.

Workload shapes

fixture	shape
cjs-hot	2M cached require() of one module (static specifier)
cjs-manyhot	900k cached requires of 300 distinct children, dynamically built specifiers
cjs-lazy	200 handler modules lazily requiring shared deps inside hot functions
cjs-builtin	2M cached require('os')
cjs-app / -small / -large	500 / 3,000 / 10,000-module cold relative-require trees
cjs-chain	600-deep linear require chain
cjs-wide	5,000 requires from a single parent
cjs-pkgs	150 node_modules packages via main
cjs-exports	150 packages resolved through exports maps
esm-app	3,000-module ESM graph (control; the change is CJS-only)

bench-matrix.py

#!/usr/bin/env python3
"""Interleaved A/B benchmark matrix with stats. Usage: matrix.py <nodeA> <nodeB> <runs>"""
import subprocess, sys, os, statistics, json

A, B, RUNS = sys.argv[1], sys.argv[2], int(sys.argv[3])
FIXDIR = os.path.join(os.path.dirname(os.path.abspath(__file__)), 'fixtures')

CASES = [
    # (name, fixture, main, extra_args, env, runs_override)
    ('cjs-hot (2M cached req, 1 child)', 'cjs-hot', 'main.js', [], {}, None),
    ('cjs-manyhot (900k cached, 300 children)', 'cjs-manyhot', 'main.js', [], {}, None),
    ('cjs-lazy (100k lazy req, server pattern)', 'cjs-lazy', 'main.js', [], {}, None),
    ('cjs-builtin (2M require(os))', 'cjs-builtin', 'main.js', [], {}, None),
    ('cjs-app-small (500 modules cold)', 'cjs-app-small', 'main.js', [], {}, None),
    ('cjs-app (3000 modules cold)', 'cjs-app', 'main.js', [], {}, None),
    ('cjs-app-large (10000 modules cold)', 'cjs-app-large', 'main.js', [], {}, None),
    ('cjs-chain (600 deep chain)', 'cjs-chain', 'main.js', [], {}, None),
    ('cjs-wide (5000 wide flat)', 'cjs-wide', 'main.js', [], {}, None),
    ('cjs-pkgs (150 node_modules pkgs)', 'cjs-pkgs', 'main.js', [], {}, None),
    ('cjs-exports (150 pkgs exports maps)', 'cjs-exports', 'main.js', [], {}, None),
    ('esm-app (3000 ESM, control)', 'esm-app', 'main.mjs', [], {}, None),
    ('cjs-app + NODE_DEBUG=module_timer (feature on)', 'cjs-app-small', 'main.js', [],
     {'NODE_DEBUG': 'module_timer'}, 9),
    ('cjs-app + trace node.module_timer (feature on)', 'cjs-app-small', 'main.js',
     ['--trace-event-categories', 'node.module_timer'], {}, 9),
]

def run(node, case):
    name, fix, main, args, env, _ = case
    e = dict(os.environ, **env)
    cwd = os.path.join(FIXDIR, fix)
    out = subprocess.run([node, *args, main], cwd=cwd, env=e,
                         capture_output=True, text=True)
    if out.returncode != 0:
        raise RuntimeError(f"{name}: {out.stderr[-300:]}")
    # tracing writes node_trace files into cwd; clean
    for f in os.listdir(cwd):
        if f.startswith('node_trace'):
            os.unlink(os.path.join(cwd, f))
    return float(out.stdout.strip().splitlines()[-1])

results = []
for case in CASES:
    runs = case[5] or RUNS
    ta, tb = [], []
    for _ in range(runs):
        ta.append(run(A, case))
        tb.append(run(B, case))
    ma, mb = statistics.median(ta), statistics.median(tb)
    results.append({
        'name': case[0],
        'a_median': ma, 'b_median': mb,
        'a_min': min(ta), 'b_min': min(tb),
        'a_stdev': statistics.stdev(ta), 'b_stdev': statistics.stdev(tb),
        'delta_pct': (mb - ma) / ma * 100,
        'runs': runs,
    })
    r = results[-1]
    print(f"{r['name']}: A={ma:.2f}ms B={mb:.2f}ms ({r['delta_pct']:+.1f}%) "
          f"[min {r['a_min']:.2f}/{r['b_min']:.2f}, sd {r['a_stdev']:.2f}/{r['b_stdev']:.2f}]",
          flush=True)

json.dump(results, open(os.path.join(os.path.dirname(FIXDIR), 'matrix-results.json'), 'w'), indent=1)
print('WROTE matrix-results.json')

fixtures-extra.py

#!/usr/bin/env python3
"""Extra fixtures for the timer-label isolation study."""
import json, os, shutil, sys
sys.path.insert(0, os.path.dirname(os.path.abspath(__file__)))
ROOT = os.path.dirname(os.path.abspath(__file__))
from gen import gen_cjs_app, write

# size-scaled variants of the cold relative-require app
gen_cjs_app(os.path.join(ROOT, "fixtures", "cjs-app-small"), nfiles=500)
gen_cjs_app(os.path.join(ROOT, "fixtures", "cjs-app-large"), nfiles=10000)

# deep linear chain: m0 -> m1 -> ... -> m1999
root = os.path.join(ROOT, "fixtures", "cjs-chain")
shutil.rmtree(root, ignore_errors=True)
N = 2000
for i in range(N):
    nxt = f"exports.next = require('./m{i+1}.js');" if i + 1 < N else ""
    write(os.path.join(root, f"m{i}.js"), f"'use strict';\n{nxt}\nexports.id={i};\n")
write(os.path.join(root, "package.json"), json.dumps({"name": "cjs-chain", "private": True}))
write(os.path.join(root, "main.js"), """'use strict';
const t0 = process.hrtime.bigint();
require('./m0.js');
console.log(Number(process.hrtime.bigint() - t0) / 1e6);
""")

# wide flat: entry requires 5000 siblings directly (one giant parent)
root = os.path.join(ROOT, "fixtures", "cjs-wide")
shutil.rmtree(root, ignore_errors=True)
N = 5000
for i in range(N):
    write(os.path.join(root, "mods", f"m{i}.js"), f"'use strict';\nexports.id={i};\n")
write(os.path.join(root, "package.json"), json.dumps({"name": "cjs-wide", "private": True}))
reqs = "\n".join(f"require('./mods/m{i}.js');" for i in range(N))
write(os.path.join(root, "load.js"), f"'use strict';\n{reqs}\n")
write(os.path.join(root, "main.js"), """'use strict';
const t0 = process.hrtime.bigint();
require('./load.js');
console.log(Number(process.hrtime.bigint() - t0) / 1e6);
""")

# lazy-require server pattern: 200 handler modules, each lazily requires
# from a pool of 20 shared deps inside a hot function; 500 calls each
root = os.path.join(ROOT, "fixtures", "cjs-lazy")
shutil.rmtree(root, ignore_errors=True)
for j in range(20):
    write(os.path.join(root, "shared", f"s{j}.js"), f"'use strict';\nexports.v={j};\n")
for i in range(200):
    deps = ", ".join(f"require('../shared/s{(i + k) % 20}.js').v" for k in range(5))
    write(os.path.join(root, "handlers", f"h{i}.js"),
          f"'use strict';\nexports.handle = function() {{ return [{deps}]; }};\n")
write(os.path.join(root, "package.json"), json.dumps({"name": "cjs-lazy", "private": True}))
handlers = "\n".join(f"handlers.push(require('./handlers/h{i}.js'));" for i in range(200))
write(os.path.join(root, "main.js"), f"""'use strict';
const handlers = [];
{handlers}
const t0 = process.hrtime.bigint();
for (let r = 0; r < 500; r++) {{
  for (const h of handlers) h.handle();
}}
console.log(Number(process.hrtime.bigint() - t0) / 1e6);
""")

# builtin require loop
root = os.path.join(ROOT, "fixtures", "cjs-builtin")
shutil.rmtree(root, ignore_errors=True)
write(os.path.join(root, "package.json"), json.dumps({"name": "cjs-builtin", "private": True}))
write(os.path.join(root, "main.js"), """'use strict';
require('os');
const t0 = process.hrtime.bigint();
for (let i = 0; i < 2000000; i++) require('os');
console.log(Number(process.hrtime.bigint() - t0) / 1e6);
""")

print("done")

fixtures-generate.py

#!/usr/bin/env python3
"""Generate module-loading benchmark fixtures."""
import json, os, shutil, sys

ROOT = os.path.dirname(os.path.abspath(__file__))

def write(p, content):
    os.makedirs(os.path.dirname(p), exist_ok=True)
    with open(p, 'w') as f:
        f.write(content)

# ---------------------------------------------------------------
# Fixture 1: cjs-app — monorepo-ish app, deep dirs, relative requires
# ---------------------------------------------------------------
def gen_cjs_app(root, nfiles=3000, fanout=10):
    shutil.rmtree(root, ignore_errors=True)
    # tree of modules: module i requires children i*fanout+1 .. i*fanout+fanout
    def fname(i):
        # nest dirs to create realistic deep paths
        d1, d2 = i % 13, i % 7
        return f"src/d{d1}/e{d2}/m{i}.js"
    for i in range(nfiles):
        kids = [k for k in range(i * fanout + 1, i * fanout + fanout + 1) if k < nfiles]
        def rel(k, i):
            r = os.path.relpath(os.path.join(root, fname(k)), os.path.join(root, os.path.dirname(fname(i)))).replace(os.sep, '/')
            return r if r.startswith('.') else './' + r
        reqs = "\n".join(f"exports.k{k} = require('{rel(k, i)}');" for k in kids)
        body = f"""'use strict';
{reqs}
exports.id = {i};
exports.fn = function () {{ return {i}; }};
"""
        write(os.path.join(root, fname(i)), body)
    write(os.path.join(root, "package.json"), json.dumps({"name": "cjs-app", "private": True}))
    write(os.path.join(root, "main.js"), """'use strict';
const t0 = process.hrtime.bigint();
require('./src/d0/e0/m0.js');
const t1 = process.hrtime.bigint();
console.log(Number(t1 - t0) / 1e6);
""")

# ---------------------------------------------------------------
# Fixture 2: cjs-pkgs — many node_modules packages, bare requires
# ---------------------------------------------------------------
def gen_cjs_pkgs(root, npkgs=150, files_per_pkg=12):
    shutil.rmtree(root, ignore_errors=True)
    for p in range(npkgs):
        pdir = os.path.join(root, "node_modules", f"pkg{p}")
        deps = [f"pkg{d}" for d in (p * 2 + 1, p * 2 + 2) if d < npkgs]
        write(os.path.join(pdir, "package.json"), json.dumps({
            "name": f"pkg{p}", "version": "1.0.0", "main": "./lib/index.js"}))
        internal = "\n".join(f"exports.f{j} = require('./f{j}.js');" for j in range(1, files_per_pkg))
        bare = "\n".join(f"exports.d{i} = require('{d}');" for i, d in enumerate(deps))
        write(os.path.join(pdir, "lib", "index.js"), f"'use strict';\n{internal}\n{bare}\nexports.name='pkg{p}';\n")
        for j in range(1, files_per_pkg):
            write(os.path.join(pdir, "lib", f"f{j}.js"), f"'use strict';\nexports.v={j};\n")
    write(os.path.join(root, "package.json"), json.dumps({"name": "cjs-pkgs", "private": True}))
    write(os.path.join(root, "main.js"), """'use strict';
const t0 = process.hrtime.bigint();
require('pkg0');
const t1 = process.hrtime.bigint();
console.log(Number(t1 - t0) / 1e6);
""")

# ---------------------------------------------------------------
# Fixture 3: esm-app — same shape as fixture 1 but ESM
# ---------------------------------------------------------------
def gen_esm_app(root, nfiles=3000, fanout=10):
    shutil.rmtree(root, ignore_errors=True)
    def fname(i):
        d1, d2 = i % 13, i % 7
        return f"src/d{d1}/e{d2}/m{i}.mjs"
    for i in range(nfiles):
        kids = [k for k in range(i * fanout + 1, i * fanout + fanout + 1) if k < nfiles]
        def rel(k, i):
            r = os.path.relpath(os.path.join(root, fname(k)), os.path.join(root, os.path.dirname(fname(i)))).replace(os.sep, '/')
            return r if r.startswith('.') else './' + r
        imports = "\n".join(f"import * as k{k} from '{rel(k, i)}';" for k in kids)
        uses = ", ".join(f"k{k}" for k in kids)
        body = f"""{imports}
export const id = {i};
export const deps = [{uses}];
export function fn() {{ return {i}; }}
"""
        write(os.path.join(root, fname(i)), body)
    write(os.path.join(root, "package.json"), json.dumps({"name": "esm-app", "private": True, "type": "module"}))
    write(os.path.join(root, "main.mjs"), """const t0 = process.hrtime.bigint();
await import('./src/d0/e0/m0.mjs');
const t1 = process.hrtime.bigint();
console.log(Number(t1 - t0) / 1e6);
""")

# ---------------------------------------------------------------
# Fixture 4: cjs-pkgs-esm — packages with exports maps, required from CJS
# ---------------------------------------------------------------
def gen_cjs_exports(root, npkgs=150, files_per_pkg=8):
    shutil.rmtree(root, ignore_errors=True)
    for p in range(npkgs):
        pdir = os.path.join(root, "node_modules", f"epkg{p}")
        deps = [f"epkg{d}" for d in (p * 2 + 1, p * 2 + 2) if d < npkgs]
        write(os.path.join(pdir, "package.json"), json.dumps({
            "name": f"epkg{p}", "version": "1.0.0",
            "exports": {
                ".": {"require": "./lib/index.js", "default": "./lib/index.js"},
                "./sub/*": "./lib/sub/*.js",
            }}))
        subs = "\n".join(f"exports.s{j} = require('epkg{p}/sub/s{j}');" for j in range(files_per_pkg))
        bare = "\n".join(f"exports.d{i} = require('{d}');" for i, d in enumerate(deps))
        write(os.path.join(pdir, "lib", "index.js"), f"'use strict';\n{subs}\n{bare}\nexports.name='epkg{p}';\n")
        for j in range(files_per_pkg):
            write(os.path.join(pdir, "lib", "sub", f"s{j}.js"), f"'use strict';\nexports.v={j};\n")
    write(os.path.join(root, "package.json"), json.dumps({"name": "cjs-exports", "private": True}))
    write(os.path.join(root, "main.js"), """'use strict';
const t0 = process.hrtime.bigint();
require('epkg0');
const t1 = process.hrtime.bigint();
console.log(Number(t1 - t0) / 1e6);
""")

gen_cjs_app(os.path.join(ROOT, "fixtures", "cjs-app"))
gen_cjs_pkgs(os.path.join(ROOT, "fixtures", "cjs-pkgs"))
gen_esm_app(os.path.join(ROOT, "fixtures", "esm-app"))
gen_cjs_exports(os.path.join(ROOT, "fixtures", "cjs-exports"))
print("done")

profile-summary.py

#!/usr/bin/env python3
"""Summarize a V8 .cpuprofile: self time per function, top N."""
import json, sys, collections

prof = json.load(open(sys.argv[1]))
nodes = {n['id']: n for n in prof['nodes']}
self_hits = collections.Counter(prof['samples'])
# time per sample ~ total/len
total_us = prof['endTime'] - prof['startTime']
per_sample = total_us / max(1, len(prof['samples']))

agg = collections.Counter()
for node_id, hits in self_hits.items():
    n = nodes.get(node_id)
    if not n:
        continue
    cf = n['callFrame']
    name = cf.get('functionName') or '(anonymous)'
    url = cf.get('url', '')
    key = f"{name}  [{url.split('/')[-1] if url else 'native'}:{cf.get('lineNumber', -1)}]"
    agg[key] += hits

print(f"total: {total_us/1000:.1f} ms, {len(prof['samples'])} samples")
for key, hits in agg.most_common(int(sys.argv[2]) if len(sys.argv) > 2 else 40):
    print(f"{hits*per_sample/1000:8.2f} ms  {hits:6d}  {key}")