Skip to content

chore(bench): per-iteration phase trace for #1054 diagnosis [DO NOT MERGE]#1062

Closed
carlos-alm wants to merge 3 commits into
mainfrom
chore/issue-1054-timing-trace
Closed

chore(bench): per-iteration phase trace for #1054 diagnosis [DO NOT MERGE]#1062
carlos-alm wants to merge 3 commits into
mainfrom
chore/issue-1054-timing-trace

Conversation

@carlos-alm
Copy link
Copy Markdown
Contributor

Purpose

Throwaway diagnostic branch. Do not merge.

The pre-publish gate shows a flat ~2-second-per-call native overhead in CI that doesn't reproduce locally on Windows or in Docker Linux. The .tf drops (#1054) explain part of the picture but not this — even with backfill firing locally, no-op rebuild is ~7ms; in CI it's 2307ms.

This branch adds per-iteration phase breakdown to `benchmark.ts` and `incremental-benchmark.ts`. Every full / no-op / 1-file iteration prints a line like:

```
[1054-trace] native.noop[0] total=2307ms setup=? collect=? detect=? parse=? insert=? resolve=? edges=? structure=? roles=? ast=? complexity=? cfg=? dataflow=? finalize=?
```

When the gate runs against this branch, the log will show which specific stage (or stages) eats the 2 seconds — `parseMs`, `edgesMs`, `rolesMs`, `structureMs`, etc. That'll tell us where to dig next.

Plan

  1. Dispatch `publish.yml` against this branch.
  2. Read the gate log, grep for `[1054-trace]`.
  3. Identify the dominant phase.
  4. Open the actual fix in a focused PR.
  5. Close this PR without merging.

Why diagnostic prints don't go to main

The trace lines go to stderr only and don't affect the JSON the gate consumes, so the gate's regression-guard verdict is unchanged. But committing diagnostic prints to mainline benchmarks pollutes future runs and obscures real signal. Hence the throwaway-branch shape.

Refs #1054

…ERGE]

Adds [1054-trace] log lines to incremental-benchmark.ts and benchmark.ts
that print the buildGraph PipelineTiming phase breakdown for every full,
no-op, and 1-file iteration to stderr. The CI gate currently shows a
flat ~2s/call native overhead that doesn't reproduce locally; with this
trace the gate log will show exactly which phase (parseMs, edgesMs,
rolesMs, etc.) eats that 2s.

Throwaway branch — dispatch the publish workflow against it, read the
log, then close. The trace lines go to stderr only and don't affect the
JSON the gate consumes, but committing diagnostic prints to mainline
benchmarks is the wrong shape long-term.

Refs #1054
@claude
Copy link
Copy Markdown

claude Bot commented May 4, 2026

Claude finished @carlos-alm's task —— View job


PR Review Analysis

Analyzing this diagnostic PR for issue #1054...

Todo List:

  • Read and analyze changed files
  • Phase 1: Root cause analysis
  • Phase 2: Configuration change detection
  • Phase 3: Test integrity assessment
  • Phase 4: Code quality review
  • Phase 5: Backlog compliance evaluation
  • Provide structured review feedback

Root Cause Analysis

Problem Being Solved: Investigating a 2-second native engine overhead in CI that doesn't reproduce locally (flat 2307ms vs 7ms). Issue #1054 shows backfill behavior explains part of the problem but not this specific overhead.

Why This Approach: Adding per-iteration phase breakdown to identify which specific build stage consumes the 2 seconds - parseMs, edgesMs, rolesMs, etc. This is a legitimate diagnostic strategy to pinpoint the bottleneck before implementing a fix.

Risk Assessment: ✅ LOW RISK - This is a proper throwaway diagnostic branch with clear intention not to merge. The trace output goes to stderr only and doesn't affect the JSON benchmark results that CI consumes.

Backlog Compliance

  • Zero-dep: ✅ — No new dependencies added
  • Foundation-aligned: ✅ — Pure diagnostic instrumentation, no architectural changes
  • Problem-fit: 4/5 — Directly addresses performance investigation to help AI agents avoid wasted tokens on slow operations
  • Breaking: No — No changes to public APIs, CLI output, or behavior
  • Tier: 1 (zero-dep ✓ + foundation-aligned ✓)

Code Quality Assessment

Strengths:

  1. Clean implementation: The logTrace() function is well-structured and consistent across both files
  2. Non-invasive: Only adds stderr logging without affecting benchmark JSON output or behavior
  3. Temporary by design: Clear comments indicate this is issue perf(native): ~2 second flat overhead added to rebuild operations in v3.10.0 #1054 one-off instrumentation
  4. Comprehensive coverage: Instruments all build scenarios (full, noop, 1-file) across both benchmark scripts
  5. Safe error handling: Uses ?? operator for missing phase data

Technical Details:

  • Logs format: [1054-trace] engine.scenario[iter] total=XXXms setup=? collect=? parse=? ...
  • Phase order matches expected build pipeline stages
  • Preserves median calculation for timing accuracy
  • stderr routing ensures CI JSON parsing is unaffected

Minor Observations:

  1. Duplicate code between files could be extracted to shared utility, but acceptable for throwaway diagnostic
  2. TypeScript any type for phases parameter is imprecise but acceptable for temporary code
  3. Function is properly scoped and doesn't leak into production paths

Critical Concerns

None identified. This is a well-executed diagnostic approach for a specific CI performance issue.

Final Recommendation

  • Rating: ⭐⭐⭐⭐☆ (4/5)
  • Action: APPROVE WITH CONDITIONS
  • Reasoning: This is exactly the right approach for diagnosing the CI performance issue. The implementation is clean, non-invasive, and clearly temporary. The author has properly documented the throwaway nature and disposal plan.

Approval Conditions:

  1. ✅ Confirmed this will not be merged to main (explicitly stated in PR description)
  2. ✅ Only to be used for gathering diagnostic data from CI gate
  3. ✅ PR will be closed after analysis without merging

Recommended Next Steps:

  1. Run the publish.yml workflow against this branch
  2. Grep gate logs for [1054-trace] to identify the dominant phase
  3. Open focused fix PR based on findings
  4. Close this PR without merging as planned

@greptile-apps
Copy link
Copy Markdown
Contributor

greptile-apps Bot commented May 4, 2026

Greptile Summary

This throwaway diagnostic branch adds a logTrace helper to both benchmark scripts that writes [1054-trace] per-iteration phase breakdowns to stderr on every buildGraph call. The traces are correctly scoped to stderr and do not touch the JSON stdout path that the gate regression guard reads. No functional or behavioral changes to the benchmark output.

Confidence Score: 5/5

PR is explicitly marked DO NOT MERGE; changes are safe and isolated to stderr diagnostics only.

No functional changes to benchmark output, no P0/P1 issues, all trace output goes to stderr and doesn't affect the JSON the gate consumes.

No files require special attention.

Important Files Changed

Filename Overview
scripts/benchmark.ts Adds logTrace helper and per-iteration trace calls for full/noop/1-file build scenarios; all output is scoped to stderr and does not touch the JSON stdout path.
scripts/incremental-benchmark.ts Mirrors the same logTrace instrumentation pattern across all three build tiers; correctly captures elapsed time before pushing to timing arrays, consistent with benchmark.ts.

Flowchart

%%{init: {'theme': 'neutral'}}%%
flowchart TD
    A[buildGraph call] --> B[capture elapsed]
    B --> C[push to timing array]
    B --> D[logTrace to stderr]
    D --> E["[1054-trace] engine.scenario[i] total=Xms phase=Y..."]
    C --> F[median / result JSON to stdout]
    E --> G[CI log — grep for 1054-trace]
Loading

Reviews (3): Last reviewed commit: "Merge branch 'main' into chore/issue-105..." | Re-trigger Greptile

@github-actions
Copy link
Copy Markdown
Contributor

github-actions Bot commented May 4, 2026

Codegraph Impact Analysis

2 functions changed2 callers affected across 2 files

  • logTrace in scripts/benchmark.ts:132 (1 transitive callers)
  • logTrace in scripts/incremental-benchmark.ts:174 (1 transitive callers)

@carlos-alm
Copy link
Copy Markdown
Contributor Author

Thanks for the review. Acknowledged the minor observations:

  • Duplicate logTrace between benchmark.ts and incremental-benchmark.ts: intentional — this is throwaway diagnostic code that will be deleted once we read the gate log and identify the dominant phase. Extracting a shared util would just mean more cleanup churn when we revert.
  • any type for phases: same rationale — kept loose because the trace just stringifies whatever the build returns.

No code changes needed. The branch will be closed without merging once the CI gate log gives us the phase breakdown we need to open the focused fix PR.

@carlos-alm
Copy link
Copy Markdown
Contributor Author

Closing unmerged in favor of #1064, which is the actual fix for #1054.

This branch was created as a diagnostic timing-trace harness to investigate why native incremental no-op rebuilds were ~2s in CI. The investigation produced the JS-side fast-skip implemented in #1064 (now ready to merge). The per-iteration phase tracing here was a one-shot diagnostic tool and is no longer needed.

Branch will not be deleted in case the trace harness is useful for future investigations.

@carlos-alm carlos-alm closed this May 5, 2026
@github-actions github-actions Bot locked and limited conversation to collaborators May 5, 2026
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant