Skip to content

fix(hooks): surface a background hook failure on the next command - #3859

Closed
worktrunk-bot wants to merge 4 commits into
mainfrom
fix/issue-3858
Closed

fix(hooks): surface a background hook failure on the next command#3859
worktrunk-bot wants to merge 4 commits into
mainfrom
fix/issue-3858

Conversation

@worktrunk-bot

Copy link
Copy Markdown
Collaborator

Problem

A post-* pipeline step that fails aborts the rest of its pipeline, and nothing says so. The detached wt hook run-pipeline process writes its stderr to runner.log, and the wt command that spawned it has already printed the steps as running and exited 0 — so the abort, the skipped steps, and the failure itself are all invisible unless someone already suspects them and goes reading logs.

Solution

The runner now records each aborted pipeline, and the next foreground wt command in that repo reports it. That's the third of the options in the issue — the deferred note — because it's the only one the detached process can reach: by the time a step fails, the terminal's wt is gone.

  • src/commands/hook_failure.rs (new) owns the channel: the runner appends one JSON line per abort to .git/wt/hook-failures.jsonl; the next invocation drains it and warns. Draining renames the file aside first, so a pipeline failing in the read-then-delete window isn't dropped. Surfaces that latch config::suppress_warnings() (statusline, pickers, completion) and a wt running inside a background hook return without touching the file, so the notice survives to a command that can show it.
  • src/commands/run_pipeline.rs funnels every step exit — the child's non-zero status and the setup ?s alike — through one StepFailure carrying the failing command's label and log stem, so the report can name the step rather than the pipeline. A SIGINT/SIGTERM abort records nothing, matching the project's quiet-cancellation convention.
  • src/main.rs reports before dispatch, reusing the Repository init_command_log already opens.

What it looks like:

▲ Background post-merge hook for main failed: user:sync exited 1; skipped push
↳ Output @ ~/code/myproject/.git/wt/logs/main/user/post-merge/sync.log

The concurrent-table form gets the same treatment (it skips nothing, so the clause is omitted) — the issue notes it was equally silent.

Pipeline semantics are unchanged: a failing step still aborts, and the originating command still exits 0.

Testing

test_background_pipeline_failure_reported_on_next_command in tests/integration_tests/user_hooks.rs reproduces the issue's config — a failing sync followed by push — and asserts the merge succeeds, push never runs, the record lands, the next wt list names both steps, and a second wt list doesn't repeat it. It fails on main at the "record lands" step. Unit tests in the new module pin the rendered warning and the drain semantics (including malformed lines).

Full cargo test --test integration is green except test_copy_ignored_preserves_file_executable_permissions, which fails identically on a clean checkout in this sandbox (umask 002 → 0664 where it expects 0644).

Notes
  • The pending file sits under .git/wt/ beside logs/, cache/, and trash/ rather than inside logs/ — it's state, not a log, and the log layout invariant categorizes top-level entries there by file-vs-directory.
  • No wt config state clear category was added: draining happens on every invocation, so wt config state clear has already reported and removed the file by the time it looks.
  • Docs: the wt hook after_long_help in src/cli/mod.rs gained a paragraph and the example above; the FAQ file inventory gained a row. Generated mirrors re-synced via test_docs_are_in_sync.
  • Whether a post-* failure should stop the pipeline at all is left alone, per the issue.

Closes #3858 — automated triage

A `post-*` pipeline step that fails aborts the rest of the pipeline, but
the detached runner's stderr is a log file and the command that spawned it
has already exited 0 — so the abort, the skipped steps, and the exit code
were all invisible. The only record was `runner.log`.

The runner now appends one record per aborted pipeline to
`.git/wt/hook-failures.jsonl`, and the next foreground `wt` in that repo
drains it and warns, naming the failed step, its exit code, the steps the
abort skipped, and the log to read.

Closes #3858

@worktrunk-bot worktrunk-bot left a comment

Copy link
Copy Markdown
Collaborator Author

Choose a reason for hiding this comment

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

Self-review (bot-authored PR, so COMMENT rather than approve). The mechanism holds up on the paths I traced: WORKTRUNK_FOREGROUND=-1 is set on the detached runner itself (not just its children), so the runner can't drain its own record into runner.log; command_suppresses_warnings latches at main.rs before report() runs, so the statusline and pickers genuinely don't drain; tab completion returns from main before report() is reached at all. wait_first_error was already generic over the error type, so the StepFailure swap needs no change there, and ErrorExt stays used on Windows via exit_code().

Three things worth changing.

1. The source: prefix is doubled for an unnamed step that fails before expansion. Two inline suggestions. template_name is built as format!("{source} {hook_type} hook") for unnamed commands (command_executor.rs), and headline() then renders {source}:{failed} — so a list-form hook whose template fails to expand reports failed: user:user post-merge hook did not run. That path is reachable: vars.* are read fresh per step, expansion is UndefinedBehavior::SemiStrict, so a step referencing a var an earlier step didn't set errors at render time in the runner. Falling back to template instead matches what step_labels already does for unnamed commands, and the post-expansion label already falls back to expanded.

2. A concurrent group that fails during setup under-reports what didn't run. record_failure derives skipped from spec.steps[step_index + 1..], which is right for a serial step but blind to the group's own members. In the spawn_result error path the already-spawned children are killed and the later commands never spawn, and none of them appear in the report. Concretely, with

[post-merge]
a = "echo one"
b = "echo {{ vars.typo }}"
c = "echo three"

b's expansion fails, a is killed mid-flight, c never spawns, and the notice reads failed: user:b did not run with no skipped clause — the same silence this PR exists to remove, one level down. Fixing it means StepFailure carrying the failing command's index within the group so record_failure can extend skipped with the rest of it; not a one-line change, so leaving it as a note rather than a suggestion.

3. codecov/patch is red — 95.16% against a 98.12% auto target (12 missed of 248 patch lines). The gap is real rather than a moved-lines artifact: is_cancellation has no test at all, which means the module's stated "a SIGINT/SIGTERM abort records nothing" contract is unpinned, and step_labels' Concurrent arm and the MAX_REPORTED collapse are likewise unexercised. I'm pushing tests for those three.

Missed patch lines (Codecov compare API, base 9c37aae → head bd89acf)

src/commands/run_pipeline.rs — 7 misses:

  • 200return; in record_failure on the cancellation path
  • 233, 235 — the matches! body of is_cancellation
  • 254257 — the Concurrent arm of step_labels

src/commands/hook_failure.rs — 5 misses:

  • 122, 126record's two best-effort error swallows
  • 158, 161, 163 — the skipped_count > 0 collapse hint

src/main.rs is 8/8. Leaving record's two swallows and record_failure:200 uncovered (no deterministic trigger for a read-only .git/wt or a SIGTERM'd pipeline); the remaining 9 bring the patch to ~98.8%.

One process note: the drain calls fs::remove_file on .git/wt/hook-failures.jsonl in take_pending, which is on the list the repo's review reference asks to hold for a human. The content is duplicated in runner.log and it's worktrunk's own transient state rather than user work, so I don't read it as a real data-loss surface — but flagging it and requesting review from @max-sixty rather than making that call unilaterally.

Comment thread src/commands/run_pipeline.rs Outdated
Comment thread src/commands/run_pipeline.rs Outdated
Split `render` out of `report` and the fallible half out of `record`, so
the batch shapes and I/O errors that a repository can't easily provoke are
reachable from unit tests. Move the cancellation filter to the runner's
step loop, where both branches are on the path every abort takes.

Adds unit coverage for `step_labels` on a concurrent group and for the
SIGINT/SIGTERM-only cancellation rule, plus an integration test that a
signal-killed pipeline queues no report.
A step that aborts before its template expands reported `template_name` as
its label, which already carries the source (`user post-merge hook` for a
list-form hook). The deferred report renders `{source}:{failed}`, so the
warning read `failed: user:user post-merge hook did not run`.

Fall back to the raw template instead, matching what `step_labels` already
does for the unnamed commands an abort skipped; the post-expansion label
keeps falling back to the expanded command.

No test: the label only differs on a setup failure (a template that fails
to expand, an unopenable log file), which has no cheap deterministic
trigger. The changed lines are on the path every pipeline step takes.
A command that fails to *start* aborts its whole group: the siblings
already running are killed and the ones after it never spawn. The
deferred report saw none of that — `record_failure` derives `skipped`
from the steps after the group, which can't see inside it — so a group
of `a`, `b`, `c` whose `b` fails to expand reported `user:b did not run`
with no clause at all, the same silence #3858 removed one level up.

`StepFailure` now carries the group's own casualties, in two lists
rather than one: a killed sibling ran partway and may have had side
effects, so reporting it as "skipped" would say it never ran. A sibling
that had already finished on its own (`try_wait`) is neither — it
completed, and now resolves its trace with its real status instead of
`false`.

    ▲ Background post-merge hook for main failed: user:b did not run; stopped a; skipped c

Also pins the parent commit's unnamed-step label fix with a test:
`{{ vars.never_set }}` is a cheap deterministic setup failure, so the
fallback that rendered `user:user post-merge hook` is reachable from the
suite after all.
@worktrunk-bot

Copy link
Copy Markdown
Collaborator Author

All three review points are addressed; required checks and codecov/patch are green on 45789b0.

1. Doubled source: prefix — both suggestions applied in 77b01bd. That commit said there was no cheap deterministic trigger for a test; there is one — {{ vars.never_set }} fails expansion in the runner every time — so 45789b0 adds test_background_failure_names_an_unnamed_step_by_its_command, which pins what a list-form hook reports.

2. Concurrent group under-reports — fixed in 45789b0. StepFailure now carries the group's own casualties and record_failure puts them ahead of the following steps, so the review's a/b/c case reports failed: user:b did not run; stopped a; skipped c instead of naming nothing. They're two lists rather than one because a killed sibling ran partway and may have had side effects — calling it "skipped" would say it never ran. One refinement over the review's sketch: a sibling that had already finished on its own is neither, so the teardown try_waits first and, when the child is already done, resolves its trace with its real status instead of false.

3. codecov/patch — passes on 45789b0 (it was already green on c6c693e; the new lines here are covered by the group test).

The fs::remove_file in take_pending is unchanged and still wants a maintainer's read — it's worktrunk's own transient state and the content is duplicated in runner.log, but the review flagged it rather than deciding unilaterally, and that's still where it stands.

Verification

Green on 45789b0: test (linux), test (macos), test (windows), fast-checks, lint, check-docs, feature-check, code-coverage, codecov/patch, codecov/project. affected tests (macos|windows, advisory) and the review job were still running when this was written.

Locally: cargo test --bins (987), cargo test --test integration user_hooks (126), cargo test --test integration hook (200), cargo clippy --all-targets --all-features, and test_docs_are_in_sync all pass.

New coverage, both in tests/integration_tests/user_hooks.rs:

  • test_background_concurrent_group_failure_names_what_it_cut_short — a group of slow (a sleep), broken (fails to expand), later, followed by a serial step. Asserts the report names all four, and that the record lands at all, which only happens because the group was torn down rather than left waiting on slow. Unix-only for the sleep: on Windows killing the group leaves the shell's own child holding the worktree open past the test.
  • headline_separates_the_commands_it_cut_short_from_the_ones_that_never_ran in hook_failure.rs pins the rendered clauses.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

automated-fix Automated CI fix

Projects

None yet

Development

Successfully merging this pull request may close these issues.

Nothing surfaces a failed post-merge hook, so the rest of the pipeline is skipped silently

2 participants