feat(utils): added module-load timing preload and DAG report
- Added Bun preload that records inclusive per-module windows and resolved static import edges via plugin hooks. - Shared events through a dependency-free buffer so the preload and logger avoid importing each other. - Rendered module spans as a body/TLA-ranked dependency tree, separating graph wait from top-level work. - Back-folded captured load phase into the root window to shrink the opaque pre-instrumentation figure.
This commit is contained in:
can1357
@@ -28,6 +28,7 @@ done
|
||||
scripts_dir=$(CDPATH= cd -- "$(dirname -- "$self")" && pwd -P)
|
||||
cli=$scripts_dir/../src/cli.ts
|
||||
preload=$scripts_dir/dev-launch-preload.ts
|
||||
timing_preload=$scripts_dir/../../utils/src/module-timer.ts
|
||||
|
||||
launch_dir=${OMP_DEV_LAUNCH_DIR:-${HOME}/.omp/.dev-cwd}
|
||||
mkdir -p "$launch_dir"
|
||||
@@ -35,4 +36,7 @@ mkdir -p "$launch_dir"
|
||||
OMP_LAUNCH_CWD=$PWD
|
||||
export OMP_LAUNCH_CWD
|
||||
cd "$launch_dir"
|
||||
if [ -n "${PI_TIMING:-}" ]; then
|
||||
exec bun --preload "$preload" --preload "$timing_preload" "$cli" "$@"
|
||||
fi
|
||||
exec bun --preload "$preload" "$cli" "$@"
|
||||
|
||||
@@ -4,7 +4,7 @@
|
||||
|
||||
### Changed
|
||||
|
||||
- `logger.printTimings()` (the `PI_TIMING` startup tree) now surfaces two previously-invisible regions: a `(before instrumentation)` line for the runtime init + static module-graph load that elapses before the first marker (the dominant real-world startup cost, ~350ms — `startTiming()` only begins inside `runRootCommand`), and an `(unattributed self)` line for the root span's own untimed work so the gap between the visible top-level spans and `Total` is no longer silently swallowed. `Total` is now labelled `(since first marker)` to make the window explicit.
|
||||
- `logger.printTimings()` (the `PI_TIMING` startup tree) now surfaces two previously-invisible regions: a `(before instrumentation)` line for runtime init / uncaptured pre-marker work, and an `(unattributed self)` line for the root span's own untimed work so the gap between visible top-level spans and `Total` is no longer swallowed. `Total` is now labelled `(since first marker)` to make the window explicit. The restored `module-timer.ts` preload can feed module spans into the report: each module records `onLoad` → final top-level marker as `total`, a prepended body marker → final marker as `body/TLA`, and resolved static imports as a bounded dependency tree so the report separates graph wait from actual top-level module work.
|
||||
|
||||
## [15.9.2] - 2026-06-05
|
||||
|
||||
|
||||
+177
-23
@@ -15,6 +15,7 @@ import { isPromise } from "node:util/types";
|
||||
import winston from "winston";
|
||||
import DailyRotateFile from "winston-daily-rotate-file";
|
||||
import { getLogsDir } from "./dirs";
|
||||
import { drainModuleLoadEvents } from "./timing-buffer";
|
||||
|
||||
/** Ensure a logs directory exists; return the resolved path. */
|
||||
function ensureDir(dir: string): string {
|
||||
@@ -166,12 +167,36 @@ interface Span {
|
||||
children: Span[];
|
||||
/** Marker / point event without a duration. */
|
||||
point?: boolean;
|
||||
/** Absolute module path for module-load spans. */
|
||||
modulePath?: string;
|
||||
/** Own top-level module body / TLA duration for module-load spans. */
|
||||
moduleBodyMs?: number;
|
||||
/** Resolved static imports for module-load spans. */
|
||||
moduleImports?: string[];
|
||||
}
|
||||
|
||||
const spanStorage = new AsyncLocalStorage<Span>();
|
||||
let gRootSpan: Span | undefined;
|
||||
let gRecordTimings = false;
|
||||
|
||||
export function timingModeIncludes(option: "full" | "x"): boolean {
|
||||
const value = process.env.PI_TIMING;
|
||||
if (!value) return false;
|
||||
if (value === option) return true;
|
||||
let start = 0;
|
||||
for (let i = 0; i <= value.length; i++) {
|
||||
const code = i === value.length ? 44 : value.charCodeAt(i);
|
||||
const separator = code === 44 || code === 58 || code === 59 || code === 43 || code <= 32;
|
||||
if (!separator) continue;
|
||||
if (i > start && value.slice(start, i) === option) return true;
|
||||
start = i + 1;
|
||||
}
|
||||
return false;
|
||||
}
|
||||
|
||||
export function shouldExitAfterTimings(): boolean {
|
||||
return timingModeIncludes("x") || timingModeIncludes("full");
|
||||
}
|
||||
|
||||
/**
|
||||
* Print collected timings as an indented tree.
|
||||
* Each span shows wall duration; parents with children also show "(self)" for unattributed time.
|
||||
@@ -184,13 +209,19 @@ export function printTimings(): void {
|
||||
}
|
||||
|
||||
gRootSpan.end = performance.now();
|
||||
// Splice any preload-captured module-load events into the tree as root
|
||||
// children and back-extend the root window over them, so the static-import
|
||||
// phase that ran before the first explicit marker becomes visible (the
|
||||
// `(modules)` summary below) instead of being lumped into the opaque
|
||||
// `(before instrumentation)` figure.
|
||||
spliceModuleLoadBuffer();
|
||||
const lines: string[] = [];
|
||||
lines.push("");
|
||||
lines.push("--- Startup timings (hierarchical) ---");
|
||||
// performance.now() shares the process-start origin, so the root span's start
|
||||
// is the wall time spent before the first marker — runtime init plus the
|
||||
// static module-graph evaluation (~the dominant cost). It is otherwise
|
||||
// invisible because Total only spans startTiming()→printTimings().
|
||||
// is the wall time before the first marker — runtime init plus any module
|
||||
// loads not captured below. With the module-load preload active this shrinks
|
||||
// to ~runtime init because the load phase is back-folded into the window.
|
||||
if (gRootSpan.start > LOGGED_TIMING_THRESHOLD_MS) {
|
||||
lines.push(`(before instrumentation): ${fmtMs(gRootSpan.start)} [runtime init + module load]`);
|
||||
}
|
||||
@@ -222,8 +253,8 @@ export function printTimings(): void {
|
||||
|
||||
/**
|
||||
* Begin recording startup timings under a new root span.
|
||||
* Idempotent: a second call while already recording is a no-op so that side-effect
|
||||
* starters (see module-timer.ts) and explicit starters (main.ts) can coexist.
|
||||
* Idempotent: a second call while already recording is a no-op, so an explicit
|
||||
* starter (main.ts) and any future early starter can coexist.
|
||||
*/
|
||||
export function startTiming(): void {
|
||||
if (gRecordTimings) return;
|
||||
@@ -238,10 +269,16 @@ export function startTiming(): void {
|
||||
|
||||
/**
|
||||
* Record an externally-measured span as a leaf child of the active span (or root
|
||||
* when no span is active). Used by the module-load timing plugin to splice load
|
||||
* events into the tree retroactively.
|
||||
* when no span is active). Used by {@link spliceModuleLoadBuffer} to fold
|
||||
* preload-captured module windows into the tree.
|
||||
*/
|
||||
export function recordModuleLoadSpan(path: string, start: number, durationMs: number): void {
|
||||
export function recordModuleLoadSpan(
|
||||
path: string,
|
||||
start: number,
|
||||
durationMs: number,
|
||||
bodyMs?: number,
|
||||
imports: string[] = [],
|
||||
): void {
|
||||
if (!gRecordTimings || !gRootSpan) return;
|
||||
const parent = spanStorage.getStore() ?? gRootSpan;
|
||||
const span: Span = {
|
||||
@@ -250,10 +287,32 @@ export function recordModuleLoadSpan(path: string, start: number, durationMs: nu
|
||||
end: start + durationMs,
|
||||
parent,
|
||||
children: [],
|
||||
modulePath: path,
|
||||
moduleBodyMs: bodyMs,
|
||||
moduleImports: imports,
|
||||
};
|
||||
parent.children.push(span);
|
||||
}
|
||||
|
||||
/**
|
||||
* Drain the preload's module-load buffer (see module-timer.ts) into the tree as
|
||||
* `load:` children of the root, then back-extend the root window to the earliest
|
||||
* captured read so the pre-marker load phase is counted in Total rather than
|
||||
* hidden as `(before instrumentation)`. No-op when nothing was captured (e.g. no
|
||||
* `--preload`, or a compiled binary where module reads are not interceptable).
|
||||
*/
|
||||
function spliceModuleLoadBuffer(): void {
|
||||
if (!gRootSpan) return;
|
||||
const events = drainModuleLoadEvents();
|
||||
if (events.length === 0) return;
|
||||
let earliest = gRootSpan.start;
|
||||
for (const event of events) {
|
||||
recordModuleLoadSpan(event.path, event.start, event.durationMs, event.bodyMs, event.imports);
|
||||
if (event.start < earliest) earliest = event.start;
|
||||
}
|
||||
gRootSpan.start = earliest;
|
||||
}
|
||||
|
||||
function shortenLoadPath(p: string): string {
|
||||
const cwd = process.cwd();
|
||||
if (p.startsWith(`${cwd}/`)) return p.slice(cwd.length + 1);
|
||||
@@ -309,6 +368,16 @@ function fmtMs(ms: number): string {
|
||||
|
||||
const MODULE_LOAD_PREFIX = "load:";
|
||||
const MODULE_LOAD_VERBOSE_TOP = 10;
|
||||
const MODULE_TREE_MAX_DEPTH = 5;
|
||||
const MODULE_TREE_ROOT_TOP = 5;
|
||||
const MODULE_TREE_CHILD_TOP = 8;
|
||||
|
||||
interface ModuleTimingNode {
|
||||
span: Span;
|
||||
children: ModuleTimingNode[];
|
||||
parents: number;
|
||||
body: number;
|
||||
}
|
||||
|
||||
function isModuleLoadSpan(span: Span): boolean {
|
||||
return span.op.startsWith(MODULE_LOAD_PREFIX);
|
||||
@@ -343,33 +412,118 @@ function printSpan(span: Span, depth: number, lines: string[]): void {
|
||||
}
|
||||
}
|
||||
|
||||
/** Collapse the (typically hundreds of) module-load spans into one summary line. */
|
||||
/** Render module-load spans as a dependency-aware DAG/tree. */
|
||||
function printModuleLoadSummary(loads: Span[], depth: number, lines: string[]): void {
|
||||
const childIndent = " ".repeat(depth);
|
||||
const grandIndent = " ".repeat(depth + 1);
|
||||
let unionStart = Number.POSITIVE_INFINITY;
|
||||
let unionEnd = 0;
|
||||
let totalSelf = 0;
|
||||
for (const span of loads) {
|
||||
if (span.end === undefined) continue;
|
||||
if (span.start < unionStart) unionStart = span.start;
|
||||
if (span.end > unionEnd) unionEnd = span.end;
|
||||
totalSelf += span.end - span.start;
|
||||
}
|
||||
const wall = unionEnd > unionStart ? unionEnd - unionStart : 0;
|
||||
lines.push(`${childIndent}(modules): ${loads.length} loaded, wall ${fmtMs(wall)}, sum ${fmtMs(totalSelf)}`);
|
||||
const showAll = process.env.PI_TIMING === "full";
|
||||
const sorted = [...loads].sort((a, b) => durationOf(b) - durationOf(a));
|
||||
const visible = showAll ? sorted : sorted.slice(0, MODULE_LOAD_VERBOSE_TOP);
|
||||
for (const span of visible) {
|
||||
const dur = durationOf(span);
|
||||
if (dur < LOGGED_TIMING_THRESHOLD_MS) break;
|
||||
const tag = isParallel(span) ? " [parallel]" : "";
|
||||
lines.push(`${grandIndent}${span.op}: ${fmtMs(dur)}${tag}`);
|
||||
const nodes = buildModuleTimingGraph(loads);
|
||||
lines.push(`${childIndent}(modules): ${loads.length} loaded, wall ${fmtMs(wall)}`);
|
||||
if (nodes.length === 0) return;
|
||||
|
||||
const showAll = timingModeIncludes("full");
|
||||
const byBody = [...nodes].sort(compareModuleNodes);
|
||||
const topBody = showAll ? byBody : byBody.slice(0, MODULE_LOAD_VERBOSE_TOP);
|
||||
lines.push(`${grandIndent}top body/TLA:`);
|
||||
for (const node of topBody) {
|
||||
if (!showAll && node.body < LOGGED_TIMING_THRESHOLD_MS) break;
|
||||
lines.push(`${grandIndent} ${node.span.op}: body ${fmtMs(node.body)} (total ${fmtMs(durationOf(node.span))})`);
|
||||
}
|
||||
if (!showAll && sorted.length > MODULE_LOAD_VERBOSE_TOP) {
|
||||
lines.push(`${grandIndent}… ${sorted.length - MODULE_LOAD_VERBOSE_TOP} more (PI_TIMING=full to show all)`);
|
||||
if (!showAll && byBody.length > MODULE_LOAD_VERBOSE_TOP) {
|
||||
lines.push(`${grandIndent} … ${byBody.length - MODULE_LOAD_VERBOSE_TOP} more (PI_TIMING=full to show all)`);
|
||||
}
|
||||
|
||||
const roots = nodes.filter(node => node.parents === 0);
|
||||
const treeRoots = (roots.length > 0 ? roots : nodes).sort((a, b) => durationOf(b.span) - durationOf(a.span));
|
||||
const visibleRoots = showAll ? treeRoots : treeRoots.slice(0, MODULE_TREE_ROOT_TOP);
|
||||
lines.push(`${grandIndent}tree:`);
|
||||
const rendered = new Set<string>();
|
||||
for (const node of visibleRoots) {
|
||||
renderModuleTimingNode(node, depth + 2, lines, rendered, new Set<string>(), showAll);
|
||||
}
|
||||
if (!showAll && treeRoots.length > MODULE_TREE_ROOT_TOP) {
|
||||
lines.push(
|
||||
`${grandIndent} … ${treeRoots.length - MODULE_TREE_ROOT_TOP} more roots (PI_TIMING=full to show all)`,
|
||||
);
|
||||
}
|
||||
}
|
||||
|
||||
function buildModuleTimingGraph(loads: Span[]): ModuleTimingNode[] {
|
||||
const nodes = new Map<string, ModuleTimingNode>();
|
||||
for (const span of loads) {
|
||||
if (!span.modulePath || span.end === undefined) continue;
|
||||
nodes.set(span.modulePath, { span, children: [], parents: 0, body: span.moduleBodyMs ?? 0 });
|
||||
}
|
||||
for (const node of nodes.values()) {
|
||||
for (const childPath of node.span.moduleImports ?? []) {
|
||||
const child = nodes.get(childPath);
|
||||
if (!child || child === node) continue;
|
||||
node.children.push(child);
|
||||
child.parents++;
|
||||
}
|
||||
}
|
||||
for (const node of nodes.values()) {
|
||||
node.children.sort(compareModuleNodes);
|
||||
}
|
||||
return [...nodes.values()];
|
||||
}
|
||||
|
||||
function compareModuleNodes(a: ModuleTimingNode, b: ModuleTimingNode): number {
|
||||
const bodyDiff = b.body - a.body;
|
||||
if (Math.abs(bodyDiff) > 0.001) return bodyDiff;
|
||||
return durationOf(b.span) - durationOf(a.span);
|
||||
}
|
||||
|
||||
function renderModuleTimingNode(
|
||||
node: ModuleTimingNode,
|
||||
depth: number,
|
||||
lines: string[],
|
||||
rendered: Set<string>,
|
||||
ancestors: Set<string>,
|
||||
showAll: boolean,
|
||||
): void {
|
||||
const path = node.span.modulePath;
|
||||
if (!path) return;
|
||||
const indent = " ".repeat(depth);
|
||||
const total = durationOf(node.span);
|
||||
if (!showAll && total < LOGGED_TIMING_THRESHOLD_MS && node.children.length === 0) return;
|
||||
const wait = Math.max(0, total - node.body);
|
||||
const shared = node.parents > 1 ? " [shared]" : "";
|
||||
const timing =
|
||||
node.body > LOGGED_TIMING_THRESHOLD_MS || node.children.length > 0
|
||||
? ` (body ${fmtMs(node.body)}, wait ${fmtMs(wait)})`
|
||||
: "";
|
||||
const alreadyRendered = rendered.has(path);
|
||||
const cycle = ancestors.has(path);
|
||||
const suffix = cycle ? " [cycle]" : alreadyRendered ? " [already shown]" : "";
|
||||
lines.push(`${indent}${node.span.op}: ${fmtMs(total)}${timing}${shared}${suffix}`);
|
||||
if (cycle || alreadyRendered) return;
|
||||
rendered.add(path);
|
||||
ancestors.add(path);
|
||||
if (!showAll && ancestors.size >= MODULE_TREE_MAX_DEPTH) {
|
||||
if (node.children.length > 0) {
|
||||
lines.push(`${indent} … ${node.children.length} imports deeper (PI_TIMING=full to show all)`);
|
||||
}
|
||||
ancestors.delete(path);
|
||||
return;
|
||||
}
|
||||
const visibleChildren = showAll ? node.children : node.children.slice(0, MODULE_TREE_CHILD_TOP);
|
||||
for (const child of visibleChildren) {
|
||||
renderModuleTimingNode(child, depth + 1, lines, rendered, ancestors, showAll);
|
||||
}
|
||||
if (!showAll && node.children.length > MODULE_TREE_CHILD_TOP) {
|
||||
lines.push(
|
||||
`${indent} … ${node.children.length - MODULE_TREE_CHILD_TOP} more imports (PI_TIMING=full to show all)`,
|
||||
);
|
||||
}
|
||||
ancestors.delete(path);
|
||||
}
|
||||
|
||||
/** A span is parallel if it overlaps a sibling that started before it. */
|
||||
|
||||
@@ -0,0 +1,148 @@
|
||||
/**
|
||||
* Module-load timing preload.
|
||||
*
|
||||
* `bun --preload .../module-timer.ts <entry>` installs Bun plugin hooks (only
|
||||
* when `PI_TIMING` is set) that record an inclusive module window plus resolved
|
||||
* static child edges:
|
||||
*
|
||||
* onLoad start → appended end marker after the module's top-level body
|
||||
*
|
||||
* Events are pushed into a process-global buffer that {@link logger.printTimings}
|
||||
* drains and renders as a module DAG/tree. Each module row can therefore show
|
||||
* both total time and `self` time after subtracting child module intervals.
|
||||
*
|
||||
* Why a preload (and not a normal import): Bun reads the *entire* statically
|
||||
* reachable graph before evaluating any module, so hooks installed from inside
|
||||
* that graph cannot observe its own loading — they only catch later dynamically
|
||||
* loaded modules. A preload runs first, so it sees the static-import phase that
|
||||
* dominates startup.
|
||||
*
|
||||
* Kept dependency-free on purpose: the sole import is Bun's `plugin`, so this is
|
||||
* cheap to preload before pi-utils (and winston) exist. The buffer is shared with
|
||||
* the logger via a registry Symbol so neither side needs to import the other.
|
||||
*
|
||||
* **What is measured:** an inclusive per-module window. `onLoad` stamps the
|
||||
* start before reading source; the returned source has a tiny marker appended at
|
||||
* the end of the module. That marker runs after Bun parses/transpiles the module
|
||||
* and after any top-level await in that module completes, so the duration
|
||||
* includes read + parse/transpile + dependency wait + top-level execution/TLA.
|
||||
* If a module throws before its final statement, no end marker is recorded.
|
||||
*
|
||||
* **Tree shape:** `onResolve` observes importer → specifier edges and resolves
|
||||
* them with `Bun.resolveSync` without taking over Bun's real resolution. The
|
||||
* logger renders these edges as a DAG/tree and computes module `self` time by
|
||||
* subtracting the union of child intervals, avoiding misleading flat inclusive
|
||||
* totals.
|
||||
*
|
||||
* **Coverage limits:**
|
||||
* - TS/TSX only — intercepting `node_modules` CJS `.js`/`.cjs` and forcing ESM
|
||||
* breaks their default-export detection, so they are left to Bun's default path.
|
||||
* - **Dev runs only.** In the compiled `omp` binary every module is pre-bundled
|
||||
* into bunfs, so `onLoad` never fires; profile with a `bun --preload` dev run.
|
||||
*/
|
||||
import { plugin } from "bun";
|
||||
import { moduleLoadBuffer } from "./timing-buffer";
|
||||
|
||||
// Restrict to TS/TSX only. node_modules ships CommonJS `.js`/`.cjs` that Bun
|
||||
// auto-detects when loaded via its default path; if we intercept and return
|
||||
// `{ contents, loader: "js" }`, Bun forces ESM and CJS modules fail to load
|
||||
// (e.g. `Missing 'default' export`). Our own source tree (where the interesting
|
||||
// timing lives) is uniformly TypeScript, so a TS-only filter is both safe and
|
||||
// sufficient.
|
||||
const MODULE_LOADER_FILTER = /\.[mc]?tsx?$/;
|
||||
const MODULE_COMPLETE_KEY: symbol = Symbol.for("omp.moduleLoadComplete");
|
||||
const MODULE_BODY_START_KEY: symbol = Symbol.for("omp.moduleBodyStart");
|
||||
const STATIC_IMPORT_PATTERN =
|
||||
/\b(?:import|export)\s+(?:type\s+)?(?:[^"']*?\s+from\s+)?["']([^"']+)["']|\bimport\s*\(\s*["']([^"']+)["']\s*\)/g;
|
||||
|
||||
type CompleteStore = Record<symbol, ((path: string) => void) | undefined>;
|
||||
|
||||
function bodyStartMarker(path: string): string {
|
||||
return `;globalThis[Symbol.for("omp.moduleBodyStart")]?.(${JSON.stringify(path)});\n`;
|
||||
}
|
||||
|
||||
function completionMarker(path: string): string {
|
||||
return `\n;globalThis[Symbol.for("omp.moduleLoadComplete")]?.(${JSON.stringify(path)});\n`;
|
||||
}
|
||||
|
||||
function instrumentContents(path: string, contents: string): string {
|
||||
const start = bodyStartMarker(path);
|
||||
const end = completionMarker(path);
|
||||
if (!contents.startsWith("#!")) return `${start}${contents}${end}`;
|
||||
const newline = contents.indexOf("\n");
|
||||
if (newline === -1) return `${contents}\n${start}${end}`;
|
||||
return `${contents.slice(0, newline + 1)}${start}${contents.slice(newline + 1)}${end}`;
|
||||
}
|
||||
function importerDir(importer: string): string {
|
||||
const slash = importer.lastIndexOf("/");
|
||||
if (slash === -1) return ".";
|
||||
return importer.slice(0, slash);
|
||||
}
|
||||
|
||||
function childSetFor(importsByPath: Map<string, Set<string>>, path: string): Set<string> {
|
||||
let children = importsByPath.get(path);
|
||||
if (!children) {
|
||||
children = new Set<string>();
|
||||
importsByPath.set(path, children);
|
||||
}
|
||||
return children;
|
||||
}
|
||||
|
||||
function addImportEdges(importsByPath: Map<string, Set<string>>, importer: string, contents: string): void {
|
||||
STATIC_IMPORT_PATTERN.lastIndex = 0;
|
||||
for (const match of contents.matchAll(STATIC_IMPORT_PATTERN)) {
|
||||
const specifier = match[1] ?? match[2];
|
||||
if (!specifier) continue;
|
||||
try {
|
||||
const resolved = Bun.resolveSync(specifier, importerDir(importer));
|
||||
if (MODULE_LOADER_FILTER.test(resolved) && resolved !== importer) {
|
||||
childSetFor(importsByPath, importer).add(resolved);
|
||||
}
|
||||
} catch {
|
||||
// Leave Bun's real resolver/runtime to surface any error. This scanner is only an observer.
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
if (process.env.PI_TIMING) {
|
||||
const buffer = moduleLoadBuffer();
|
||||
const starts = new Map<string, number>();
|
||||
const bodyStarts = new Map<string, number>();
|
||||
const importsByPath = new Map<string, Set<string>>();
|
||||
const store = globalThis as unknown as CompleteStore;
|
||||
store[MODULE_BODY_START_KEY] = (path: string): void => {
|
||||
bodyStarts.set(path, performance.now());
|
||||
};
|
||||
store[MODULE_COMPLETE_KEY] = (path: string): void => {
|
||||
const start = starts.get(path);
|
||||
if (start === undefined) return;
|
||||
starts.delete(path);
|
||||
const end = performance.now();
|
||||
const bodyStart = bodyStarts.get(path);
|
||||
bodyStarts.delete(path);
|
||||
const imports = importsByPath.get(path);
|
||||
buffer.push({
|
||||
path,
|
||||
start,
|
||||
durationMs: end - start,
|
||||
bodyMs: bodyStart === undefined ? undefined : end - bodyStart,
|
||||
imports: imports ? [...imports] : [],
|
||||
});
|
||||
};
|
||||
|
||||
plugin({
|
||||
name: "pi-module-load-timer",
|
||||
setup(build) {
|
||||
build.onLoad({ filter: MODULE_LOADER_FILTER }, async args => {
|
||||
starts.set(args.path, performance.now());
|
||||
childSetFor(importsByPath, args.path);
|
||||
const contents = await Bun.file(args.path).text();
|
||||
addImportEdges(importsByPath, args.path, contents);
|
||||
return {
|
||||
contents: instrumentContents(args.path, contents),
|
||||
loader: args.path.endsWith(".tsx") ? "tsx" : "ts",
|
||||
};
|
||||
});
|
||||
},
|
||||
});
|
||||
}
|
||||
@@ -0,0 +1,47 @@
|
||||
/**
|
||||
* Shared contract between the {@link module-timer} preload and {@link logger}'s
|
||||
* timing tree. Kept in its own dependency-free module so the preload can import
|
||||
* it without pulling in winston (via logger) and the logger can drain the buffer
|
||||
* without importing the Bun-plugin preload.
|
||||
*/
|
||||
|
||||
export interface ModuleLoadEvent {
|
||||
/** Absolute or Bun-resolved module path. */
|
||||
path: string;
|
||||
/** `performance.now()` timestamp captured at Bun `onLoad` entry. */
|
||||
start: number;
|
||||
/** Inclusive module window: `onLoad` entry → appended final marker. */
|
||||
durationMs: number;
|
||||
/** Own top-level body / TLA time: prepended body marker → appended final marker. */
|
||||
bodyMs?: number;
|
||||
/** Resolved static children imported by this module. */
|
||||
imports: string[];
|
||||
}
|
||||
|
||||
/**
|
||||
* Registry-global key under which the preload accumulates module-load events.
|
||||
* `Symbol.for` so both modules resolve the same symbol independently.
|
||||
*/
|
||||
const KEY: symbol = Symbol.for("omp.moduleLoadBuffer");
|
||||
|
||||
type Store = Record<symbol, ModuleLoadEvent[] | undefined>;
|
||||
|
||||
/** The append-only buffer the preload pushes into (created on first access). */
|
||||
export function moduleLoadBuffer(): ModuleLoadEvent[] {
|
||||
const store = globalThis as unknown as Store;
|
||||
let buffer = store[KEY];
|
||||
if (!buffer) {
|
||||
buffer = [];
|
||||
store[KEY] = buffer;
|
||||
}
|
||||
return buffer;
|
||||
}
|
||||
|
||||
/** Drain and return all buffered events, leaving the buffer empty. */
|
||||
export function drainModuleLoadEvents(): ModuleLoadEvent[] {
|
||||
const store = globalThis as unknown as Store;
|
||||
const buffer = store[KEY];
|
||||
if (!buffer || buffer.length === 0) return [];
|
||||
store[KEY] = [];
|
||||
return buffer;
|
||||
}
|
||||
Reference in New Issue
Block a user