Skip to content

fix(bench): attribute unified walk time to per-phase timers #858

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
carlos-alm merged 4 commits into from
Apr 5, 2026
Merged

fix(bench): attribute unified walk time to per-phase timers #858

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
4 commits
Select commit Hold shift + click to select a range
52dc2c4
fix(bench): attribute unified walk time to per-phase timers
carlos-alm Apr 4, 2026
fa5e686
fix(bench): clarify timing comments per review feedback
carlos-alm Apr 5, 2026
e4bb360
Merge main into fix/benchmark-timing-attribution
carlos-alm Apr 5, 2026
2f7f970
Merge branch 'main' into fix/benchmark-timing-attribution
carlos-alm Apr 5, 2026
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
32 changes: 27 additions & 5 deletions src/ast-analysis/engine.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -629,7 +629,7 @@ async function delegateToBuildFunctions(
} catch (err: unknown) {
debug(`buildAstNodes failed: ${toErrorMessage(err)}`);
}
timing.astMs = performance.now() - t0;
timing.astMs += performance.now() - t0;
}

if (opts.complexity !== false) {
Expand All @@ -640,7 +640,7 @@ async function delegateToBuildFunctions(
} catch (err: unknown) {
debug(`buildComplexityMetrics failed: ${toErrorMessage(err)}`);
}
timing.complexityMs = performance.now() - t0;
timing.complexityMs += performance.now() - t0;
}

if (opts.cfg !== false) {
Expand All @@ -651,7 +651,7 @@ async function delegateToBuildFunctions(
} catch (err: unknown) {
debug(`buildCFGData failed: ${toErrorMessage(err)}`);
}
timing.cfgMs = performance.now() - t0;
timing.cfgMs += performance.now() - t0;
}

if (opts.dataflow !== false) {
Expand All @@ -662,7 +662,7 @@ async function delegateToBuildFunctions(
} catch (err: unknown) {
debug(`buildDataflowEdges failed: ${toErrorMessage(err)}`);
}
timing.dataflowMs = performance.now() - t0;
timing.dataflowMs += performance.now() - t0;
}
}

Expand Down Expand Up @@ -699,7 +699,10 @@ export async function runAnalyses(
// WASM pre-parse for files that still need it (AST store, or native gaps)
await ensureWasmTreesIfNeeded(fileSymbols, opts, rootDir);

// Unified pre-walk: run all applicable visitors in a single DFS per file
// Unified pre-walk: run all applicable visitors in a single DFS per file.
// Time each file's walk and distribute equally among active visitors
// so that phase timers (astMs, complexityMs, etc.) reflect real work — not
// just the DB-write tail in delegateToBuildFunctions.
Comment on lines +702 to +705
Copy link
Copy Markdown
Contributor

@greptile-apps greptile-apps bot Apr 4, 2026

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

P2 "Proportionally" vs "equally" in comment

The comment says "distribute proportionally among active visitors" but the implementation divides walkMs equally (walkMs / activeCount). Equal distribution is a valid approximation, but "proportionally" implies the share reflects each visitor's actual work — which it doesn't. This could mislead future readers who then expect e.g. a complexity-heavy visitor to show a larger share.

Suggested change
// Unified pre-walk: run all applicable visitors in a single DFS per file.
// Time each file's walk and distribute proportionally among active visitors
// so that phase timers (astMs, complexityMs, etc.) reflect real work — not
// just the DB-write tail in delegateToBuildFunctions.
// Unified pre-walk: run all applicable visitors in a single DFS per file.
// Time each file's walk and distribute equally among active visitors
// so that phase timers (astMs, complexityMs, etc.) reflect real work — not
// just the DB-write tail in delegateToBuildFunctions.

Copy link
Copy Markdown
Contributor Author

@carlos-alm carlos-alm Apr 5, 2026

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Fixed in fa5e686 — changed "proportionally" to "equally" in the comment, matching what the code actually does.

const t0walk = performance.now();

for (const [relPath, symbols] of fileSymbols) {
Expand All @@ -714,7 +717,22 @@ export async function runAnalyses(

if (visitors.length === 0) continue;

const walkStart = performance.now();
const results = walkWithVisitors(symbols._tree.rootNode, visitors, langId, walkerOpts);
const walkMs = performance.now() - walkStart;

// Distribute walk time equally among active visitors
const activeCount = [astVisitor, complexityVisitor, cfgVisitor, dataflowVisitor].filter(
Boolean,
).length;
if (activeCount > 0) {
const share = walkMs / activeCount;
if (astVisitor) timing.astMs += share;
if (complexityVisitor) timing.complexityMs += share;
if (cfgVisitor) timing.cfgMs += share;
if (dataflowVisitor) timing.dataflowMs += share;
}

const defs = symbols.definitions || [];

if (astVisitor) {
Expand All @@ -727,6 +745,10 @@ export async function runAnalyses(
if (dataflowVisitor) symbols.dataflow = results.dataflow as DataflowResult;
}

// Total wall-clock time for the unified walk loop, including per-file
// setupVisitors overhead. Walk time is already distributed into per-phase
// timers above, so this field overlaps with (astMs + complexityMs + ...).
// It is kept as a diagnostic cross-check, not an additive bucket.
timing._unifiedWalkMs = performance.now() - t0walk;

// Reconcile: apply CFG-derived cyclomatic override for any definitions that have
Expand Down
6 changes: 6 additions & 0 deletions src/types.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -666,6 +666,12 @@ export interface AnalysisTiming {
complexityMs: number;
cfgMs: number;
dataflowMs: number;
/**
* Diagnostic: total wall-clock time for the unified walk loop (includes
* setupVisitors overhead). Walk time is already distributed equally into
* the per-phase timers above, so this overlaps — it is not an additive
* bucket. Useful for cross-checking that Σ phase timers ≈ this value.
*/
_unifiedWalkMs?: number;
}

Expand Down
Loading