Skip to content

feat(logs): let the sink decide ready_output - #667

Merged
jdx merged 2 commits into
mainfrom
claude/sink-ready-output
Jul 26, 2026
Merged

feat(logs): let the sink decide ready_output#667
jdx merged 2 commits into
mainfrom
claude/sink-ready-output

Conversation

@jdx

@jdx jdx commented Jul 25, 2026

Copy link
Copy Markdown
Owner

The gap

#661 moved log capture out of the supervisor, but ready_output daemons were excluded:

pub(crate) fn is_supported(opts: &RunOptions) -> bool {
    opts.ready_output.is_none() && opts.on_output_hook.is_none() && !opts.pty.unwrap_or(false)
}

The reason was structural — the supervisor had to read the output to match the pattern — but the consequence is that for those daemons nothing about 2.19.0 applies. The supervisor is still the pipe's only reader, so killing it leaves the pipe readerless, the daemon takes SIGPIPE seconds later, and capture dies with it. That is the original #631 failure, still live for anyone using a readiness pattern — which is most people running a server.

The change

The sink gets the pattern (--ready-pattern) and does the matching, since it is the process holding the stream. On the first match it stores and flushes the line, then reports it to the supervisor over IPC (SinkReadyMatch). Ordering matters: the report travels the sink's own queue behind the line itself, so by the time the supervisor hears about it, collect_startup_logs and pitchfork logs can already see the line that caused it.

Supervisor-side, the reported line is relayed into the very same channel the in-process readers feed. The monitoring task cannot tell the difference, so readiness, on_ready, active-port detection and the deadline logic are untouched — the pattern is still matched by the supervisor, so the sink is reporting "look at this line", not asserting readiness itself.

OutputLine carries a persist flag. In-process lines are written to the store by the monitoring task as before; relayed lines are not, because the sink already wrote them. Verified there is exactly one copy.

Two ordering hazards worth calling out, both handled:

  • Registration precedes the sink. The channel is created in run_once before the sink is spawned, so a daemon whose first line matches doesn't report into a void.
  • Withdrawal is ownership-checked. A retry registers attempt N+1's channel as soon as attempt N reports failure, which can happen before attempt N's monitoring task finishes unwinding. An unconditional remove in Drop would delete the new attempt's registration and hang it until its readiness timeout. The guard compares Sender::same_channel before removing, the same revalidate-before-acting pattern used for monitor tokens.

The relay is also dropped explicitly at process exit, before the post-exit drain: it holds a sender, so leaving it registered would keep the channel open and make every drain wait out its full 5s deadline.

Still not covered

on_output hooks and pty = true. Both still use in-process capture and remain crash-vulnerable; the module docs say so. on_output is the natural next step — same plumbing, plus debounce — while PTY needs the sink to be handed a terminal master rather than a pipe.

Tests

  • ready_output is decided by the sink — asserts a sink process owns the stream, that start waited for the line rather than a timer, and that the deciding line is in the store exactly once
  • log capture for a ready_output daemon survives a supervisor crash — SIGKILL the supervisor, daemon lives, log lines keep accruing

Both were mutation-tested: with is_supported reverted to main's version, both fail. 523 unit tests; 96 bats across logs, basic, hooks, port and pty.


This PR was generated by Claude Code.


Note

Medium Risk
Touches daemon startup readiness, IPC, and retry ordering; mistakes could mark daemons ready early or miss readiness, but existing supervisor matching is preserved and tokens guard stale sinks.

Overview
ready_output daemons can use the out-of-process log sink again, so log capture and readiness no longer force the supervisor to own the output pipe (the gap left after moving logging to sinks).

The hidden log-sink command gains --ready-pattern and --relay-token. The sink matches readiness in-process (ANSI stripped, with carry across over-long line splits), persists the matching line before reporting via new IPC SinkReadyMatch. The supervisor relays that line into the same monitoring channel as in-process readers, using OutputLine { persist } so sink-stored lines are not duplicated.

is_supported no longer excludes ready_output; OutputRelay registers per start attempt with token-checked delivery and careful unregister on retry. Integration bats cover sink-owned readiness and supervisor-crash survival for ready_output.

Reviewed by Cursor Bugbot for commit 58c0a41. Bugbot is set up for automated code reviews on this repo. Configure here.

A daemon with `ready_output` kept in-process capture, because the
supervisor had to read the output to match the pattern. That put it back
in the data path for exactly those daemons: killing the supervisor left
the pipe readerless, so the daemon took SIGPIPE moments later and its
output stopped being recorded — the failure the sink exists to prevent.

Give the sink the pattern instead. It matches, stores and flushes the
line, then reports it over IPC; the supervisor relays it into the same
channel in-process readers feed, so readiness, hooks and port detection
run unchanged. Relayed lines are marked not-to-persist, since the sink
has already written them.

Registration happens before the sink starts, so a match in the daemon's
first line has somewhere to go, and withdrawal is ownership-checked so a
retry's registration cannot be removed by its predecessor unwinding.

`on_output` hooks and PTY daemons still use in-process capture.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
@coderabbitai

coderabbitai Bot commented Jul 25, 2026

Copy link
Copy Markdown

Warning

Review limit reached

@jdx, you've reached your PR review limit, so we couldn't start this review.

Next review available in: 27 seconds

Enable usage-based reviews in Billing to review now. Otherwise, wait until the next included review is available.
You're only billed for reviews past your plan's rate limits ($0.25/file).

How can I continue?

After more reviews become available, a review can be triggered using the @coderabbitai review command as a PR comment. Alternatively, push new commits to this PR.

To avoid repeated limits, reduce automatic review volume by pausing incremental auto-reviews earlier, using label-based review opt-in, excluding WIP or generated PR titles, or requesting reviews manually when the PR is ready. If your team needs uninterrupted high-volume reviews, an organization admin can enable usage-based reviews.

How do review limits work?

CodeRabbit enforces per-developer PR review limits for each organization. Most developers receive the normal plan review availability.

For paid Pro and Pro+ PR reviews, CodeRabbit uses adaptive limits for sustained high-volume activity. When a developer's recent PR review activity reaches the 95th percentile or higher among CodeRabbit users, additional reviews become available more gradually as earlier reviews age out of the rolling window.

Please refer docs for additional details.

Review details
⚙️ Run configuration

Configuration used: Central YAML (base), Organization UI (inherited)

Review profile: CHILL

Plan: Pro Plus

Run ID: 0e46fcac-2b43-4304-b02d-fae945f7d7e6

📥 Commits

Reviewing files that changed from the base of the PR and between da5c119 and 58c0a41.

📒 Files selected for processing (10)
  • docs/cli/commands.json
  • pitchfork.usage.kdl
  • src/cli/log_sink.rs
  • src/ipc/client.rs
  • src/ipc/mod.rs
  • src/supervisor/ipc_handlers.rs
  • src/supervisor/lifecycle.rs
  • src/supervisor/log_sink.rs
  • src/supervisor/mod.rs
  • test/logs.bats

Thanks for using CodeRabbit! It's free for OSS, and your support helps us grow. If you like it, consider giving us a shout-out.

❤️ Share

Comment @coderabbitai help to get the list of available commands.

@cursor cursor Bot left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

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

Cursor Bugbot has reviewed your changes and found 1 potential issue.

Fix All in Cursor

❌ Bugbot Autofix is OFF. To automatically fix reported issues with cloud agents, enable autofix in the Cursor dashboard.

Reviewed by Cursor Bugbot for commit c20d6ce. Configure here.

Comment thread src/supervisor/log_sink.rs
@greptile-apps

greptile-apps Bot commented Jul 25, 2026

Copy link
Copy Markdown
Contributor

Greptile Summary

This PR moves ready_output matching into the out-of-process log sink.

  • Adds attempt-scoped relay tokens to prevent stale sink reports from satisfying retries.
  • Relays matched output over IPC after persisting it.
  • Adds bounded cross-fragment matching for lines split by the log sink’s 64 KiB cap.
  • Updates generated CLI metadata and readiness/log-survival tests.

Confidence Score: 3/5

The PR is not yet safe to merge because valid readiness matches spanning more than the retained 4 KiB boundary context can still be missed, causing startup timeout and daemon termination.

The attempt token changes resolve stale cross-retry delivery, but the capped-line fix retains only 4 KiB while ready-output regexes have no equivalent width restriction, leaving the original readiness failure reachable.

Files Needing Attention: src/cli/log_sink.rs

Important Files Changed

Filename Overview
src/cli/log_sink.rs Adds sink-side readiness matching and ordered reporting, but the bounded carry leaves the previously reported long-line matching defect reachable for matches wider than 4 KiB.
src/supervisor/log_sink.rs Adds attempt-scoped relay registration and token validation that correctly rejects stale reports and protects replacement registrations.
src/supervisor/lifecycle.rs Registers sink relays before spawning, consumes relayed lines through the existing readiness path, and drops registrations before post-exit draining.
src/ipc/mod.rs Adds the tokenized SinkReadyMatch request used by the sink-to-supervisor relay.
src/supervisor/ipc_handlers.rs Dispatches readiness reports into the token-validating relay path.
test/logs.bats Covers sink-driven readiness, single persistence, and logging after supervisor failure, but does not exercise a cap-spanning match wider than the carry.

Fix All in Claude Code

Reviews (2): Last reviewed commit: "fix(logs): tie a sink's reports to the s..." | Re-trigger Greptile

Comment thread src/supervisor/log_sink.rs
Comment thread src/cli/log_sink.rs
A sink outlives its daemon — it exits only once every descendant has
closed the pipe — so the sink of a failed attempt can still be draining,
and reporting, while a retry starts. Reports were keyed by daemon id
alone, so that late line was delivered to the new attempt and could mark
a process ready before it had printed anything.

Each registration now carries a token, quoted by the sink and checked
before delivery, the same way monitor registrations are identified.

Also match a readiness pattern across the line-length cap. An over-long
line is emitted in pieces, and a pattern straddling a split matched none
of them, so a daemon that had announced itself was killed at its
readiness timeout instead. A bounded tail of the previous piece is
carried forward, and the text reported is what the pattern matched
against, since the supervisor re-matches it.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
@jdx

jdx commented Jul 25, 2026

Copy link
Copy Markdown
Owner Author

Both P1s were real; fixed in 58c0a41.

Stale reports crossing retries (@cursor, @greptile-apps — same finding). A sink outlives its daemon by design: it exits only at EOF, once every descendant has closed the pipe. So attempt N's sink can still be draining, and reporting, while attempt N+1 is starting — and since the relay was keyed by daemon id alone, N's line was delivered to N+1's channel and could mark a process ready that had printed nothing. I had guarded the withdrawal side of this (same_channel in Drop) but not delivery itself.

Registrations now carry a token, minted per attempt, passed to the sink as --relay-token and quoted back in the report. deliver_reported_line drops anything whose token is not the current one. That is the same idiom as MonitorEntry's token in adopt.rs, for the same reason — PIDs and daemon ids both get reused, tokens don't.

Line cap breaking readiness (@greptile-apps). Confirmed, and it is a divergence from the in-process path, which uses BufReader::lines() and has no cap at all. A line over 64 KiB is emitted in pieces and each was matched alone, so a pattern straddling a split matched nothing and the daemon was killed at its readiness timeout.

ReadyMatcher now carries the tail of a capped piece forward — bounded at 4 KiB, so the memory cap the split exists to enforce still holds — and matches the join. It reports the joined text rather than the piece, which matters because the supervisor re-matches what it is sent; reporting only the fragment would make its re-match fail and readiness never fire.

Six unit tests on the matcher, including the case that must not match: SERVER ending one real line and READY starting the next is two lines, not one, so a pattern spanning them stays unmatched. Also covers the carry staying bounded and never splitting a multi-byte character.

535 unit tests, logs.bats 29/29.

The ci-bats (1) failure is unrelated: PORT environment variable is injected into daemon failed with port 45800 already in use by "process 'unknown' (PID: 0)". That port is hardcoded and used by no other test in the suite, and the daemon involved has neither ready_output nor a hook, so it takes exactly the same code path as on main. Runner-side collision.


This comment was generated by Claude Code.

@greptile-apps

greptile-apps Bot commented Jul 25, 2026

Copy link
Copy Markdown
Contributor

Both fixes look correct and well-implemented.

Stale reports crossing retries: The token threading is thorough — NEXT_RELAY_TOKEN mints per OutputRelay::register(), the same token is stored in SinkPipe and re-passed to every replacement sink within that attempt, and deliver_reported_line short-circuits if relay.token != token. Replacement sinks within the same attempt stay authorized; a finished attempt's sinks are silently dropped. The Drop impl on OutputRelay already had the right shape — token == self.token before removing — so the delivery side now matches it.

Line cap breaking readiness: ReadyMatcher::consider with split_at_cap is the right abstraction. The boundary walk finding the nearest char boundary before carrying is correct, and reporting the full joined candidate (not just the fragment) is critical since the supervisor re-matches what it receives. The test that must not match — "SERVER " then "READY" on a real newline — is the most important one to have and it's there.

One minor note: MATCH_CARRY_BYTES is 4 KiB, MAX_LINE_BYTES is 64 KiB, so the carry is 6.25% of a capped line. That bounds memory but means a readiness pattern can't straddle more than 4 KiB of a split — seems reasonable given patterns are meant to be short anchors, not multiline assertions.

The ci-bats (1) port collision explanation is convincing; hardcoded port 45800 is a runner-level flake unrelated to this change.

LGTM on both fixes. The two P1s are closed.

Comment thread src/cli/log_sink.rs
/// be killed at its readiness timeout despite having announced itself. Keeping
/// the tail of the previous piece closes that for any pattern shorter than this
/// while still bounding what is held.
const MATCH_CARRY_BYTES: usize = 4 * 1024;

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

P1 Bounded carry still loses matches

When a readiness regex needs more than 4 KiB of text from before a 64 KiB split, ReadyMatcher discards the beginning of that match before evaluating the next fragment. The sink never reports the valid match, so the supervisor reaches the readiness deadline and kills an otherwise ready daemon.

Knowledge Base Used: Supervisor Core

Fix in Claude Code

@jdx

jdx commented Jul 25, 2026

Copy link
Copy Markdown
Owner Author

Bounded carry still loses matches — when a readiness regex needs more than 4 KiB of text from before a 64 KiB split, ReadyMatcher discards the beginning of that match.

Accurate, and deliberate. I'm not changing it, for these reasons:

Removing the bound reintroduces what the cap exists to prevent. MAX_LINE_BYTES is there because a daemon emitting an endless stream with no newline — or binary data — would otherwise grow the sink's buffer until the OS killed it, whereupon the supervisor would start another sink and repeat it. A carry that grows to hold "however much a regex might need" is that same unbounded buffer wearing a different hat.

The configuration it fails on does not exist. It requires a single line over 64 KiB and a readiness pattern whose match spans more than 4 KiB of that line. Readiness patterns are things like Listening on, Server started, ready. A 4 KiB one is not a thing anyone writes.

The alternative was worse. Before the carry, any pattern straddling a split failed. Now only patterns longer than 4 KiB do. That is a strict improvement over the state you flagged in the first comment, and over unbounded growth.

Worth noting what the bound is measured against: it is 4 KiB of carried context, not a limit on the pattern. A short pattern is found wherever it lands, including across the split, because the carry always reaches back further than the pattern needs.

The trade-off is documented at the constant. If a pattern that long ever turns out to be real, the fix is to raise MATCH_CARRY_BYTES, not to unbound it.

The other two comments on this PR (Stale sink readiness crosses retries, Line cap breaks readiness matching) are from c20d6ce, re-anchored onto the current diff by GitHub — both were fixed in 58c0a41, and the Bugbot check on that commit passes. All 12 checks are green.


This comment was generated by Claude Code.

@jdx
jdx merged commit 5480bc5 into main Jul 26, 2026
13 checks passed
@jdx
jdx deleted the claude/sink-ready-output branch July 26, 2026 00:02
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.

1 participant