Skip to content

refactor(trace): unify in-process trace-trigger surface#2554

Merged
max-sixty merged 2 commits intomainfrom
trace
May 3, 2026
Merged

refactor(trace): unify in-process trace-trigger surface#2554
max-sixty merged 2 commits intomainfrom
trace

Conversation

@max-sixty
Copy link
Copy Markdown
Owner

Three small consolidations in the trace-trigger surface, following up on #2539.

What this changes

1. Cmd::stream() emits [wt-trace] cmd=... natively. Previously only Cmd::run() and Cmd::pipe_into() emitted per-subprocess records — stream() was a hole, which #2539 patched with a Span::new(\"execute_shell_command\") wrapper at the foreground hook/alias call site. The two surrogates aren't equivalent: spans render under cat: \"wt\", subprocess records under cat: \"git\"/\"network\", and spans don't carry the ok flag, so hook/alias child status was invisible in chrome traces. Stream now emits a record at every exit point (spawn fail, stdin write, wait fail, signal-derived exit, SIGPIPE-as-success, non-zero status, success) via a small WtTraceLog helper that mirrors ExternalCommandLog's shape.

2. Drops the Span::new(\"execute_shell_command\") workaround in commands/command_executor.rs. With Cmd::stream() emitting natively, the wrapper is redundant — foreground hook/alias step time is now captured by the canonical subprocess record (cat=git/network/none) instead of a generic span (cat=wt).

3. Re-exports trace::instant from trace::mod alongside Span. Deletes the shell_exec::trace_instant shim (a one-line re-export of trace::emit::instant) and migrates all 14 callers in commands/picker/mod.rs and commands/list/collect/mod.rs to worktrunk::trace::instant. Symmetric public API: trace::Span for scopes, trace::instant for milestones — neither lives under shell_exec anymore, since neither has anything to do with shell execution.

Verification

Smoke-tested with RUST_LOG=debug wt <alias>: cmd=\"echo hello-from-stream\" ok=true and cmd=\"exit 7\" ok=false both fire correctly. Span(\"execute_shell_command\") no longer appears in the trace. Full pre-merge hook (3430 tests + clippy + lints) passes locally.

Three small consolidations in the trace-trigger surface:

- `Cmd::stream()` now emits a `[wt-trace] cmd="..." dur_us=... ok=...`
  record at every exit point (spawn fail, stdin write, wait fail,
  signal-derived exit, SIGPIPE-as-success, non-zero status, success),
  via a small `WtTraceLog` helper that mirrors `ExternalCommandLog`'s
  shape. Closes the gap noted in #2539.
- Drops the `Span::new("execute_shell_command")` workaround in
  `commands/command_executor.rs` — foreground hook/alias step time is
  now captured by the canonical subprocess record (cat=git/network)
  instead of a generic span (cat=wt).
- Re-exports `trace::instant` from `trace::mod` alongside `Span`.
  Deletes the `shell_exec::trace_instant` shim and migrates all 14
  callers in `commands/picker/mod.rs` and `commands/list/collect/mod.rs`
  to `worktrunk::trace::instant`. Symmetric public API: `trace::Span`
  for scopes, `trace::instant` for milestones — neither lives under
  `shell_exec` anymore.

Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
worktrunk-bot
worktrunk-bot previously approved these changes May 3, 2026
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.

codecov/patch is failing — 49/55 hits, 6 misses on src/shell_exec.rs. The uncovered lines are the two new trace_log.errored(&e) calls in the rare error paths inside Cmd::stream():

  • L1335 — stdin.write_all(content) failing with a non-BrokenPipe error
  • L1405-1409 — child.wait() returning Err

Both paths existed before this PR (just returning errors via ? / e.into()); the new code adds a trace_log.errored(&e) call before the same return. They're hard to hit in unit tests — write_all failures other than BrokenPipe need the child to close stdin abnormally mid-write, and child.wait() failing is rarer still.

CLAUDE.md asks to investigate the gap rather than ignore it. Two options I see:

  1. Drop the errored() calls in those two paths and rely on the trace gap being acceptable for paths that already return an error to the caller. The PR's primary motivation (closing the gap that Span::new("execute_shell_command") was working around) is the success and signal/exit paths, which are still fully covered.
  2. Keep them and approve through the codecov failure — they're cheap defensive emissions and the failure modes are real (e.g., a kernel-killed child between spawn and wait).

I'd lean toward (1) for codecov compliance, but happy to push either direction. Dismissing my approval per CLAUDE.md's codecov rule — let me know which way you'd like and I can push the fix.

@worktrunk-bot worktrunk-bot dismissed their stale review May 3, 2026 18:01

codecov/patch failed — 6 uncovered lines in shell_exec.rs error paths

Adds the missing test for the `Err` arm of the spawn match in
`Cmd::stream`, which also exercises `WtTraceLog::errored`. Spawning a
non-existent binary triggers a deterministic spawn failure.

The remaining uncovered paths in the new code (`wait_result` Err arm,
non-BrokenPipe stdin-write Err arm) are genuinely hard to provoke
deterministically — they require the child to be reaped externally or
the stdin pipe to error with something other than EPIPE — and are left
unexercised.

Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
@max-sixty max-sixty merged commit 0b3cf7b into main May 3, 2026
27 of 28 checks passed
@max-sixty max-sixty deleted the trace branch May 3, 2026 18:14
max-sixty added a commit that referenced this pull request May 3, 2026
…es (#2555)

Two follow-ups from #2554.

## Dynamic span names

`Span::new` now accepts `impl Into<Cow<'static, str>>`. Literals stay
borrowed, `format!(...)` produces an owned span — useful when the name
carries dynamic context.

Threaded through the alias/hook surface so chrome traces can finally
attribute time per pipeline:

- `try_alias` → `try_alias:{name}`
- `run_alias` → `run_alias:{name}`
- `prepare_steps` → `prepare_steps:{alias}`
- `template_render` → `template_render:{cmd.label}`, with the
concurrent-group span moved into the `.map()` closure (per-command
render now gets its own span; the previous single span covering the
whole map hid per-command attribution).

## `Cmd::run` / `Cmd::pipe_into` share `WtTraceLog`

`WtTraceLog` (introduced in #2554 for `Cmd::stream`) gains a
`record_result(&Result<Output>)` helper that does trace + `log_output`.
`Cmd::run` and `Cmd::pipe_into` now construct `WtTraceLog::new(...)`
instead of computing `t0`/`ts`/`tid` manually and calling the standalone
`log_command_result`.

`pipe_into` emits each child's record inside `thread::scope` right after
that child reaps — drops the explicit per-child `dur_us` capture and the
post-scope emission step. End times are now recorded at reap rather than
scope-exit (slightly more accurate). Trace tools sort by `ts` so the
change in log-line order is invisible to them.

`log_command_result` deleted. All three `Cmd` modes share one emission
path.

Net: -36 lines.

> _This was written by Claude Code on behalf of @max-sixty_

Co-authored-by: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
max-sixty added a commit that referenced this pull request May 5, 2026
Follow-ups to #2554. The spans there used `&'static str` names, so the
per-call context (which alias, which template) couldn't be attributed in
`wt-perf` output.

- `Span::new` now accepts `impl Into<Cow<'static, str>>` — string
literals stay borrowed, dynamic names are owned. Removes the docs note
"for dynamic names, call `span_completed` directly," which was a worse
API (callers had to reproduce the RAII timing themselves).
- Alias execution spans carry the alias name (`try_alias:deploy`,
`run_alias:deploy`, `prepare_steps:deploy`).
- `template_render` carries the command label, and the concurrent-group
span moved inside the per-command map so each render emits its own
record instead of one outer record covering all of them.
- Consolidated `Cmd::run` / `Cmd::pipe_into` trace emission behind
`WtTraceLog::record_result`, removing the duplicated `t0/ts/tid` capture
and the free `log_command_result` helper. Single source of truth for
finished-command emission.

> _This was written by Claude Code on behalf of Maximilian._

Co-authored-by: Claude <noreply@anthropic.com>
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