Skip to content

Add wt-perf timeline subcommand for trace capture & rendering#2558

Merged
max-sixty merged 3 commits intomainfrom
alias-speed-model
May 3, 2026
Merged

Add wt-perf timeline subcommand for trace capture & rendering#2558
max-sixty merged 3 commits intomainfrom
alias-speed-model

Conversation

@max-sixty
Copy link
Copy Markdown
Owner

Summary

Adds wt-perf timeline to standardize how we capture and read traces for one-off wt invocations (alias dispatch, wt list, etc.). Replaces the prior RUST_LOG=debug wt … 2>&1 | wt-perf trace > trace.json dance with a single command that runs wt, captures stderr, parses [wt-trace] records, and either pretty-prints a sorted text timeline or emits Chrome Trace Format JSON for Perfetto.

The text mode is the path I expect to use most — it's a column-aligned table sorted by start time, with subprocess totals and an externally-measured wall (spawn → wait) so the unobserved prelude/epilogue is visible:

ts(ms)  dur       tid  kind  name
0.000   11µs      1    span  init_logging
0.043   3.979ms   1    span  prewarm
0.058   3.882ms   1    cmd   git rev-parse --git-common-dir … HEAD [wt-perf-typical-1]
…

3 subprocesses totaling 11.315ms (slowest: 3.882ms git rev-parse … HEAD)
traced: 14.838ms (first → last [wt-trace] record)
wall:   19.367ms (spawn → wait; +4.529ms untraced prelude/epilogue)

What's in the diff

  • tests/helpers/wt-perf/src/main.rs — new Timeline subcommand. Resolves wt as a sibling of current_exe() (Windows-aware via EXE_SUFFIX), optionally invalidates caches with --cold [--repo PATH], runs wt with RUST_LOG=debug, captures stderr, and renders. Uses tabwriter for column alignment, Duration's std Debug for compact unit display, and insta for inline snapshot tests.
  • tests/helpers/wt-perf/Cargo.toml — new deps: tabwriter (release), insta (dev).
  • CLAUDE.md — fixes stale --skip syntax in the Benchmarks section (Criterion takes a positional FILTER, per docs(bench): replace --skip with positional FILTER #2547), replaces the non-existent bench_list_by_worktree_count example, adds a Traces section.
  • benches/CLAUDE.md — leads "Generating traces" with wt-perf timeline; the manual stderr-redirect pipeline is now framed as the path for traces from a log already on disk.
  • src/trace/mod.rs module doc — same usage block update so library doc and CLAUDE.md don't drift.
  • wt-perf setup printed suggestion — hints at wt-perf timeline instead of the manual stderr redirect.

wt-perf trace (stdin/file → Chrome JSON) and wt-perf cache-check are unchanged — they still serve the case where you have a captured log and want to convert or analyze it without re-running.

Test plan

  • cargo run -- hook pre-merge --yes (3432 tests, lints, doctests) passes locally
  • wt-perf timeline -- -C \$REPO stub end-to-end on a typical-1 fixture
  • wt-perf timeline --cold --repo \$REPO -- -C \$REPO stub invalidates and reruns
  • wt-perf timeline --chrome -- -C \$REPO stub produces valid JSON (loaded into python -m json.tool)
  • cargo test -p wt-perf --bin wt-perf — 2 inline insta snapshots pass
  • CI green

🤖 Generated with Claude Code

max-sixty and others added 2 commits May 3, 2026 11:47
Implements `wt-perf timeline` to run a `wt` command with `WORKTRUNK_TRACE=1`,
capture stderr trace records, and render them as a column-aligned timeline or
Chrome Trace Format JSON. Supports `--cold` to invalidate caches before
measurement and `--chrome` for Perfetto-compatible output. Includes helpers
to resolve the wt binary, render sorted timelines with duration summaries,
and tests for timeline formatting and subprocess accounting.
Codex review fixes on top of the prior timeline commit:

- Resolve `wt` with `EXE_SUFFIX` so the sibling-binary lookup finds
  `wt.exe` on Windows, not just `wt` on Unix.
- Update the `Timeline` docstring to describe what the code actually
  does (sets `RUST_LOG=debug` and parses `[wt-trace]` lines), instead
  of referring to a `WORKTRUNK_TRACE` env var that no longer exists.

Lean on existing/upstream crates instead of hand-rolling:

- Drop the 9-line `format_duration` helper; `format!("{:?}", duration)`
  from std produces compact units (`8µs`, `4.5ms`, `1.5s`) directly.
- Use `tabwriter` for column alignment via elastic tabstops; columns
  auto-size and the header off-by-one I had earlier can't recur.
  New dep on wt-perf only; transitive deps already in workspace.
- Rewrite the unit tests with `insta::assert_snapshot!` inline
  snapshots so future format tweaks can be re-accepted via
  `cargo insta test --accept`.

Better wall-time signal:

- The trace can't see prelude (argv parse, dyld, time before
  `init_logging` sets the trace epoch) or epilogue (drop, exit), so
  the prior "wall" line was misleading. Measure spawn → wait
  externally in `wt-perf timeline` and report it as `wall`, with the
  trace-internal span as `traced` and the gap labelled
  "untraced prelude/epilogue". Quantize to microseconds so output
  doesn't mix `4.5ms` and `19.161583ms`.

Docs so future sessions know what to do:

- `CLAUDE.md`: fix stale `--skip` syntax in the Benchmarks section
  (Criterion takes a positional FILTER, per #2547), replace the
  non-existent `bench_list_by_worktree_count` example, add a
  Traces section pointing at `wt-perf timeline`.
- `benches/CLAUDE.md`: lead "Generating traces" with
  `wt-perf timeline`; demote the manual `RUST_LOG=debug | wt-perf
  trace` pipeline to "from a log already on disk", which is its
  actual remaining use case.
- `src/trace/mod.rs` module doc: same usage block update so library
  doc and CLAUDE.md don't drift.
- `wt-perf setup` printed suggestion: hint at `wt-perf timeline`
  instead of the manual stderr redirect.

Co-Authored-By: Claude <noreply@anthropic.com>
Copy link
Copy Markdown
Collaborator

@worktrunk-bot worktrunk-bot left a comment

Choose a reason for hiding this comment

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

One stale-comment nit inline. Separately: this PR fixes the --skip syntax in CLAUDE.md, but benches/list.rs:20-21 still shows cargo bench --bench list -- --skip cold / --skip real in its header comment — that's the same broken syntax (#2547). Worth folding into the same PR so the bench file's own examples agree with the doc this PR rewrites.

Comment thread tests/helpers/wt-perf/src/main.rs Outdated
- `run_timeline`'s leading doc-comment still said `WORKTRUNK_TRACE=1`
  even though the body sets `RUST_LOG=debug`. Update it to match.
- `benches/list.rs` header still showed `cargo bench --bench list --
  --skip cold` / `--skip real` examples — the same syntax #2547
  removed from the docs. Replace with the positional-FILTER form so
  the bench file's examples agree with `benches/CLAUDE.md` and the
  root `CLAUDE.md` Benchmarks section.

Co-Authored-By: Claude <noreply@anthropic.com>
@max-sixty max-sixty merged commit db1beb6 into main May 3, 2026
38 of 41 checks passed
@max-sixty max-sixty deleted the alias-speed-model branch May 3, 2026 20:01
max-sixty pushed a commit that referenced this pull request May 4, 2026
…ile (#2604)

## Problem

The `collect affected coverage` job has been failing on every push to
main since #2558 merged, with the same error shape:

```
FAIL [   0.009s] (3487/3491) wt-perf::bin/wt-perf tests::cmd_failure_annotates_name
    cargo-affected runner-shim: failed to resolve binary_id for /home/runner/work/worktrunk/worktrunk/target/affected/build/debug/deps/wt_perf-01f04725fd165542: binary not found in map (path: /home/runner/work/worktrunk/worktrunk/target/affected/build/debug/deps/wt_perf-01f04725fd165542); target-name basename fallback ambiguous — 2 candidates share target name "wt_perf" ([wt-perf, wt-perf::bin/wt-perf]) and the marker probe matched 0 of them (none; candidates without markers: wt-perf::bin/wt-perf, wt-perf); re-run `cargo affected collect`
```

Root cause: the `[lib] name = "wt_perf"` and `[[bin]] name = "wt-perf"`
artifacts both normalize to the same `wt_perf` basename.
cargo-affected's runner shim disambiguates same-basename test binaries
via a marker probe, but markers only fire for `kind = "test" | "bench" |
"example"` — `lib` and `bin` get none. Once #2558 added inline tests
under `bin/wt-perf`, both candidates appeared in cargo-affected's binary
map without markers, so any hash drift between list and run aborted the
shim with `basename fallback ambiguous`.

Issue #2571 previously diagnosed this as transient, but it has continued
to fail every run since (25295115776, 25301191157, 25303363793,
25309058661,
[25336005330](https://github.com/max-sixty/worktrunk/actions/runs/25336005330))
with the same error shape — it is durable, not transient.

## Solution

Two changes together fix it:

- Move `render_timeline` (and its `describe`/`duration_of` helpers) plus
the inline tests from `src/main.rs` into `src/lib.rs`. The bin no longer
carries any `#[cfg(test)]` items.
- Set `test = false` on the `[[bin]]` in `Cargo.toml` so cargo doesn't
emit a test binary for it. This removes the bin from cargo-affected's
binary map entirely, so even with hash drift the basename fallback finds
a single candidate (the lib). The bin still gets compiled at
`target/debug/wt-perf` because `tests/builds.rs` triggers it.

## Testing

- `cargo build -p wt-perf` — produces the binary at
`target/debug/wt-perf` and `wt-perf --help` works as before.
- `cargo test -p wt-perf` — both timeline tests
(`renders_sorted_timeline_with_summary`, `cmd_failure_annotates_name`)
pass under the lib target; the bin target no longer ships a test binary.
- `cargo clippy -p wt-perf --tests` — clean.

This commit is identical to f168bde on the orphaned
`fix/ci-25289365418` branch (cherry-picked here onto a current main).

---
Automated fix for [failed
run](https://github.com/max-sixty/worktrunk/actions/runs/25336005330)

Co-authored-by: worktrunk-bot <254187624+worktrunk-bot@users.noreply.github.com>
Co-authored-by: Claude <noreply@anthropic.com>
@max-sixty max-sixty mentioned this pull request May 5, 2026
3 tasks
max-sixty added a commit that referenced this pull request May 5, 2026
## Summary
Release v0.48.0. See
[CHANGELOG.md](https://github.com/max-sixty/worktrunk/blob/release/CHANGELOG.md)
for the full notes.

Highlights:
- `--format=json` extends to seven step + hook commands (#2560)
- `wt step commit` / `wt step squash` gain `--dry-run` (#2557)
- New `dirname` / `basename` template filters (#2592, #2605)
- New `[remove] delete-branch` config option (#2589)
- `wt-perf timeline` subcommand (#2558)
- Faster `wt list` on dirty worktrees (#2602) and faster alias dispatch
(#2556, #2573)
- Short-SHA display honors `core.abbrev` (#2576)
- Cleaner `wt config show` shell-integration section for new users

## Test plan
- [x] `cargo run -- hook pre-merge --yes` (3497 tests, lints clean)
- [x] `cargo semver-checks check-release -p worktrunk` consulted; minor
bump confirmed
- [ ] CI green
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants