Skip to content

Commit 06208bb

Browse files
authored
fix(bench): attribute unified walk time to per-phase timers (#858)
* fix(bench): attribute unified walk time to per-phase timers The analysis engine runs AST/complexity/CFG/dataflow visitors in a single DFS walk, then delegates to buildXxx functions for DB writes. The walk time was stored in a hidden _unifiedWalkMs field while the reported phase timers only captured the DB-write tail. This made WASM 1-file incremental benchmarks show ~0ms for CFG/dataflow/complexity (the real work was done in the unified walk but never attributed). Now each file's walk time is distributed proportionally among active visitors, and delegateToBuildFunctions accumulates (+=) rather than overwrites (=) so both walk + DB-write time are captured. * fix(bench): clarify timing comments per review feedback - Change "proportionally" to "equally" in walk-distribution comment - Document that _unifiedWalkMs includes setupVisitors overhead and overlaps with per-phase timers (not an additive bucket) - Add JSDoc to _unifiedWalkMs field in AnalysisTiming interface
1 parent 54ba5c0 commit 06208bb

File tree

2 files changed

+33
-5
lines changed

2 files changed

+33
-5
lines changed

src/ast-analysis/engine.ts

Lines changed: 27 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -629,7 +629,7 @@ async function delegateToBuildFunctions(
629629
} catch (err: unknown) {
630630
debug(`buildAstNodes failed: ${toErrorMessage(err)}`);
631631
}
632-
timing.astMs = performance.now() - t0;
632+
timing.astMs += performance.now() - t0;
633633
}
634634

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

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

657657
if (opts.dataflow !== false) {
@@ -662,7 +662,7 @@ async function delegateToBuildFunctions(
662662
} catch (err: unknown) {
663663
debug(`buildDataflowEdges failed: ${toErrorMessage(err)}`);
664664
}
665-
timing.dataflowMs = performance.now() - t0;
665+
timing.dataflowMs += performance.now() - t0;
666666
}
667667
}
668668

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

702-
// Unified pre-walk: run all applicable visitors in a single DFS per file
702+
// Unified pre-walk: run all applicable visitors in a single DFS per file.
703+
// Time each file's walk and distribute equally among active visitors
704+
// so that phase timers (astMs, complexityMs, etc.) reflect real work — not
705+
// just the DB-write tail in delegateToBuildFunctions.
703706
const t0walk = performance.now();
704707

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

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

720+
const walkStart = performance.now();
717721
const results = walkWithVisitors(symbols._tree.rootNode, visitors, langId, walkerOpts);
722+
const walkMs = performance.now() - walkStart;
723+
724+
// Distribute walk time equally among active visitors
725+
const activeCount = [astVisitor, complexityVisitor, cfgVisitor, dataflowVisitor].filter(
726+
Boolean,
727+
).length;
728+
if (activeCount > 0) {
729+
const share = walkMs / activeCount;
730+
if (astVisitor) timing.astMs += share;
731+
if (complexityVisitor) timing.complexityMs += share;
732+
if (cfgVisitor) timing.cfgMs += share;
733+
if (dataflowVisitor) timing.dataflowMs += share;
734+
}
735+
718736
const defs = symbols.definitions || [];
719737

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

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

732754
// Reconcile: apply CFG-derived cyclomatic override for any definitions that have

src/types.ts

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -666,6 +666,12 @@ export interface AnalysisTiming {
666666
complexityMs: number;
667667
cfgMs: number;
668668
dataflowMs: number;
669+
/**
670+
* Diagnostic: total wall-clock time for the unified walk loop (includes
671+
* setupVisitors overhead). Walk time is already distributed equally into
672+
* the per-phase timers above, so this overlaps — it is not an additive
673+
* bucket. Useful for cross-checking that Σ phase timers ≈ this value.
674+
*/
669675
_unifiedWalkMs?: number;
670676
}
671677

0 commit comments

Comments
 (0)