Skip to content

feat(logs): capture daemon output in a sibling process - #661

Merged
jdx merged 13 commits into
mainfrom
claude/log-sink
Jul 25, 2026
Merged

feat(logs): capture daemon output in a sibling process#661
jdx merged 13 commits into
mainfrom
claude/log-sink

Conversation

@jdx

@jdx jdx commented Jul 25, 2026

Copy link
Copy Markdown
Owner

The problem

The supervisor held the read end of every daemon's output pipe, which put it in the data path. Kill it and the pipe has no reader, so the daemon's next write takes SIGPIPE and the daemon usually dies with it. I confirmed this directly before writing any code — a plain echo loop was gone within seconds of its supervisor being killed:

>>> SIGKILL the supervisor
  -> daemon DIED (SIGPIPE on stdout write)

That undermines the re-adoption added in #633: a daemon that logs to stdout rarely survives long enough to be adopted. Anything it had written but the supervisor had not yet read was lost too.

The change

Capture moves to a sibling process — pitchfork log-sink, this binary re-executed — which holds the read end and writes to the log store. A supervisor crash becomes invisible to logging: the daemon keeps writing, the sink keeps recording, nothing is dropped. This is the arrangement runit uses, where runsv "creates a pipe, redirects service/run's standard output to the pipe" and starts a separate log service on the other end, staying out of the stream itself.

The supervisor retains a spare read end. That does two things: a sink that dies cannot leave the pipe readerless and kill the daemon, and its replacement can be handed the same pipe. It deliberately keeps no write end, which would stop the sink from ever seeing end of file. A sink that exits while its daemon is still monitored is replaced (mirroring runsv restarting a log service); one that exits cleanly has reached EOF and is not.

A regression this introduced, and the fix

Failed starts report what the daemon printed by querying the log store, and the in-process path guaranteed the ordering by flushing synchronously before signalling — lifecycle.rs even comments that this is "so collect_startup_logs sees the line". The sink broke that: output reached the store but not the user, losing exactly the diagnostics you need when a daemon won't start.

Restored by having the failure path wait for the sink's final write, bounded at 2s so a daemon whose descendants hold the pipe open cannot stall the caller. This was only caught by chasing the question directly — the existing suite passed 295/295 without noticing, and there's now a test for it.

Scope

Daemons using ready_output, an on_output hook, or pty = true keep the in-process path, because the supervisor itself has to read the stream to serve them, and so remain crash-vulnerable. Teaching the sink to evaluate those and report matches back over IPC is a follow-up — it is a larger change and better reviewed on its own.

Tests

Three new tests in logs.bats, each verified to fail without the corresponding behavior:

  • log capture survives a supervisor crash — the daemon is a plain echo loop with no trap '' PIPE. My pre-change reproduction needed that guard to survive at all; not needing it is the clearest demonstration of the fix.
  • a log sink that dies is replaced — SIGKILL the sink; a different pid takes over, the daemon is unaffected, capture resumes.
  • start failure diagnostics include the daemon's output — guards the ordering above.

Also verified by hand: capture continued across a supervisor SIGKILL (+14 lines written while no supervisor existed), and a killed sink was replaced with capture resuming.

523/523 unit tests, clippy clean under -D warnings, 55/55 log suites, 56/56 basic + hooks. Full suite still running locally as I open this; CI covers it including Windows.

Builds on #660, which fixed the concurrent-open failure this design would otherwise hit with several writers on one store.

🤖 Generated with Claude Code


Note

Medium Risk
Touches core supervisor lifecycle, process/pipe wiring, and shared SQLite log writes; failures could affect daemon startup, log durability, or backpressure behavior, though fallbacks and bounded waits limit blast radius.

Overview
Moves daemon stdout/stderr capture out of the supervisor into a re-execed sibling pitchfork log-sink process, so a supervisor crash no longer drops the pipe reader (avoiding SIGPIPE and lost logs). The supervisor keeps a spare read end, wires eligible daemons to the pipe before spawn, and restarts sinks that exit unexpectedly while the daemon is still monitored; ready_output, on_output, and PTY daemons still use in-process capture.

The hidden log-sink CLI reads stdin asynchronously, batches parsed lines into SQLite, and documents --log-format. SQLite open now sets an explicit busy_timeout, enables WAL with a tolerant race handler, and adds contention tests. Failed starts wait briefly for sink output to land in the store so startup diagnostics stay visible; orphan-adoption docs note logging continues across supervisor restarts.

New logs.bats coverage exercises capture across supervisor SIGKILL, sink replacement, and failure diagnostics.

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

Summary by CodeRabbit

  • New Features
    • Added out-of-process log capture via a hidden log-sink command to keep daemon stdout/stderr logs recording across supervisor crashes and restarts.
    • Log capture continues automatically if the sink process restarts.
    • Added --log-format selection for captured logs (text, json, logfmt, auto).
  • Bug Fixes
    • Improved SQLite concurrency handling to prevent lost log entries under contention.
    • Ensures queued logs are flushed when streams close and preserves daemon start diagnostics on failure.
  • Documentation
    • Updated orphan adoption documentation to clarify stdout/stderr capture behavior after supervisor crashes.
  • Tests
    • Added end-to-end log-sink coverage and additional SQLite contention tests.

jdx and others added 3 commits July 25, 2026 00:17
Opening the log store from two processes at once fails: switching a
database into WAL mode needs an exclusive lock and, unlike ordinary
statements, does not consult the busy handler, so the connection that
loses the race gets SQLITE_BUSY no matter how long its timeout is. The
error surfaced from open() itself, taking the whole store down rather
than one statement.

WAL is recorded in the database header and persists across connections,
so only the first open needs to set it. enable_wal now retries briefly in
case a peer is mid-switch and then carries on regardless: a connection
that never personally set WAL still works correctly, and refusing to open
the log store over a transient pragma race is far worse than running one
connection unoptimised.

Also states busy_timeout explicitly. rusqlite already defaults to the
same 5s, so this changes no behavior today; it records the requirement at
the call site instead of resting on a dependency's default, and the new
contention test guards it.

Prerequisite for moving log writes out of the supervisor process, where
several writers open the same store concurrently.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Without one the scheduler was free to run the workers in sequence, so the
first would enable WAL and the rest would find it already set — never
contending for the journal-mode switch the test exists to guard. It
caught the bug on this machine but was not guaranteed to anywhere else.

Verified by reverting enable_wal: the test now fails on every run rather
than by luck.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
The supervisor held the read end of every daemon's output pipe, which put
it in the data path. Killing it left the pipe with no reader, so the
daemon's next write took SIGPIPE and the daemon usually died with it —
undermining the re-adoption added in #633, since a daemon that logs to
stdout rarely survived long enough to be adopted. Anything written but
not yet read was lost as well.

Capture now happens in a sibling process: `pitchfork log-sink`, this
binary re-executed, holding the read end and writing to the log store.
A supervisor crash is invisible to logging — the daemon keeps writing,
the sink keeps recording, and no line is dropped. This is the arrangement
runit uses, where runsv starts a service alongside its own log service
and stays out of the stream.

The supervisor retains a spare read end, which does two things: a sink
that dies cannot leave the pipe readerless and kill the daemon, and its
replacement can be handed the same pipe. It deliberately keeps no write
end, which would stop the sink from ever seeing end of file. A sink that
exits while its daemon is still monitored is replaced, mirroring runsv
restarting a log service; one that exits cleanly has reached end of file
and is not.

Failed starts report what the daemon printed by querying the log store,
which the in-process path guaranteed by flushing synchronously before
signalling. That ordering is restored by waiting for the sink's final
write, bounded so a daemon whose descendants hold the pipe open cannot
stall the caller.

Daemons using ready_output, an on_output hook, or pty = true keep the
in-process path, because the supervisor itself has to read the stream to
serve them, and so remain vulnerable to a supervisor crash. Teaching the
sink to evaluate those and report matches back is left for a follow-up.

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

coderabbitai Bot commented Jul 25, 2026

Copy link
Copy Markdown

Review Change Stack

Note

Reviews paused

It looks like this branch is under active development. To avoid overwhelming you with review comments due to an influx of new commits, CodeRabbit has automatically paused this review. You can configure this behavior by changing the reviews.auto_review.auto_pause_after_reviewed_commits setting.

Use the following commands to manage reviews:

  • @coderabbitai resume to resume automatic reviews.
  • @coderabbitai review to trigger a single review.

Use the checkboxes below for quick actions:

  • ▶️ Resume reviews
  • 🔍 Trigger review
📝 Walkthrough

Walkthrough

Adds a hidden log-sink CLI command that batches stdin logs into SQLite, supervisor-managed sink processes for daemon output capture, SQLite contention handling, lifecycle integration, and end-to-end crash and replacement tests.

Changes

Out-of-process log capture

Layer / File(s) Summary
Log-sink CLI ingestion
docs/cli/commands.json, pitchfork.usage.kdl, src/cli/*
Defines and routes the hidden log-sink command, which parses newline-delimited stdin, batches entries, and appends them to the log store.
Concurrent log-store writes
src/log_store/sqlite.rs
Adds busy-timeout and WAL initialization handling, plus tests for contended and concurrent writers.
Sink process lifecycle
src/supervisor/log_sink.rs, src/supervisor/adopt.rs, src/supervisor/mod.rs
Creates retained pipes, launches sibling sink processes, polls for output, and respawns sinks while monitoring remains valid.
Daemon wiring and validation
src/supervisor/lifecycle.rs, settings.toml, test/logs.bats
Routes supported daemon output through sinks, waits for final failure output, updates adoption documentation, and tests supervisor crashes, sink replacement, and startup diagnostics.

Estimated code review effort: 4 (Complex) | ~45 minutes

Sequence Diagram(s)

sequenceDiagram
  participant Daemon
  participant Supervisor
  participant LogSink as pitchfork log-sink
  participant LogStore
  Daemon->>Supervisor: start with stdout/stderr pipes
  Supervisor->>LogSink: launch sibling sink process
  Daemon->>LogSink: write output through retained pipe
  LogSink->>LogStore: append parsed log batches
  Supervisor->>LogSink: respawn after sink termination
Loading

Possibly related PRs

  • jdx/pitchfork#620: Changes supervisor output draining and persistence behavior on monitor exit paths.
  • jdx/pitchfork#633: Updates orphan-daemon adoption and monitoring behavior used by sink capture.

Poem

I’m a rabbit with logs in a pipe,
Hopping through crashes both day and night.
Sink siblings nibble each line into store,
And spring back to life when one hops no more.
SQLite waits, then writes with delight!

🚥 Pre-merge checks | ✅ 5
✅ Passed checks (5 passed)
Check name Status Explanation
Docstring Coverage ✅ Passed Docstring coverage is 100.00% which is sufficient. The required threshold is 80.00%.
Linked Issues check ✅ Passed Check skipped because no linked issues were found for this pull request.
Out of Scope Changes check ✅ Passed Check skipped because no linked issues were found for this pull request.
Description Check ✅ Passed Check skipped - CodeRabbit’s high-level summary is enabled.
Title check ✅ Passed The title clearly summarizes the main change: moving daemon output capture to a sibling process.

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.

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

greptile-apps Bot commented Jul 25, 2026

Copy link
Copy Markdown
Contributor

Greptile Summary

Adds out-of-process daemon log capture and supporting lifecycle behavior.

  • Introduces a hidden log-sink command with bounded line processing and batched SQLite writes.
  • Supervises and replaces sink processes while retaining a spare pipe reader.
  • Waits briefly for startup-failure output to reach the log store.
  • Improves SQLite contention handling and adds end-to-end log capture tests.

Confidence Score: 5/5

The PR appears safe to merge, with no blocking failures remaining in the follow-up scope.

No blocking failure remains.

Important Files Changed

Filename Overview
src/cli/log_sink.rs Implements bounded byte-stream parsing and asynchronous batched persistence for the new log-sink process.
src/supervisor/log_sink.rs Implements pipe ownership, sink spawning, replacement supervision, and failed-start output settling.
src/supervisor/lifecycle.rs Wires eligible daemons to sibling log sinks and preserves startup-failure diagnostics.
src/log_store/sqlite.rs Adds explicit lock waiting and retry-tolerant WAL initialization for concurrent log writers.
test/logs.bats Adds coverage for supervisor-crash survival, sink replacement, and startup diagnostics.

Reviews (11): Last reviewed commit: "fix(logs): signal a pending sink synchro..." | Re-trigger Greptile

Comment thread src/supervisor/log_sink.rs Outdated
Comment thread src/supervisor/log_sink.rs Outdated
Comment thread src/cli/log_sink.rs Outdated
jdx and others added 2 commits July 25, 2026 02:21
Three problems, two of which could leave a daemon with no reader at all —
blocking it once the pipe filled and killing it with SIGPIPE once the
sink's own end went.

The retry test also failed, on CI and locally: waiting for the sink's
final write on every attempt both delayed the backoff and widened the
window in which a daemon looks errored and idle. `run` retries inline, so
the background retry checker had time to start an attempt of its own
alongside it, producing five attempts where four were expected and
doubling the elapsed time. The wait now happens only on the attempt that
gives up, which is the only one whose output is reported.

- a sink that cannot be spawned no longer ends supervision. It dropped
  the retained read end while the daemon was already running and writing;
  spawning is now retried for as long as the daemon is monitored.
- the sink reads bytes and converts lossily instead of requiring valid
  UTF-8. A single stray byte used to end the read loop, and because that
  looked like a clean exit the supervisor read it as end of file and
  stopped replacing the sink. Genuine read failures now exit non-zero so
  a replacement starts.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Both were raised in review: stdout and stderr deliberately share one pipe
(as the in-process path effectively did, and as runit does), and an
adopted daemon's sink is not covered by a replacement loop, so one that
dies after adoption is not replaced.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Comment thread src/supervisor/lifecycle.rs
Comment thread src/supervisor/log_sink.rs Outdated
CI caught `retry zero fails immediately with one attempt`, which requires
a failed start to finish in under three seconds. Waiting for the sink
process to exit was costing ~766ms of that budget, and the reason is that
exiting is a poor proxy for having written: it also pays for spawning a
process and opening the log store, hundreds of milliseconds, while the
write itself lands in a few dozen. Measured on the same daemon, the
output was queryable after 36ms.

The failure path now polls for this run's output directly, capped at
400ms, which brings a failed start from ~766ms down to ~33ms. A daemon
that fails without printing anything has nothing to wait for and pays the
cap, which is why it is short.

Sinks are also started before the daemon rather than after it, so a
daemon that exits immediately no longer has to wait for its reader to
come up before anything can be captured, and the supervision loop now
waits on the sink it already holds before consulting the monitor
registry. Checking the registry first abandoned the sink of a daemon that
had already exited, since its monitor entry was gone by then.

This removes the Drained handshake entirely: nothing needs to observe the
sink's exit any more.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Comment thread src/supervisor/log_sink.rs
Comment thread src/cli/log_sink.rs Outdated
CI's lint step failed on formatting: later edits went in without
re-running rustfmt. `mise run lint` now passes locally, which is the
same command CI runs.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Comment thread src/cli/log_sink.rs

@coderabbitai coderabbitai 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.

Actionable comments posted: 2

🤖 Prompt for all review comments with AI agents
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.

Inline comments:
In `@src/cli/log_sink.rs`:
- Around line 21-31: Update the LogSink log_format field’s documentation to
remove “auto” from the advertised formats, leaving only json, logfmt, and text.
Do not change parsing behavior in parse(); ensure the clap help text
consistently reflects the supported values.

In `@src/supervisor/lifecycle.rs`:
- Around line 444-472: Update the early-return handling around cmd.spawn() and
the child.id() None branch in run_once to explicitly reap any already-started
sink_child before returning. Take the sink child and asynchronously await
sink.wait(), preserving the existing error and DaemonFailed return behavior
while preventing dropped sink processes from relying on best-effort cleanup.
🪄 Autofix (Beta)

Fix all unresolved CodeRabbit comments on this PR:

  • Push a commit to this branch (recommended)
  • Create a new PR with the fixes

ℹ️ Review info
⚙️ Run configuration

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

Review profile: CHILL

Plan: Pro Plus

Run ID: 542fb376-9a2c-4b4e-924f-9c2e22739b03

📥 Commits

Reviewing files that changed from the base of the PR and between febcdc4 and 9dcf54e.

📒 Files selected for processing (11)
  • docs/cli/commands.json
  • pitchfork.usage.kdl
  • settings.toml
  • src/cli/log_sink.rs
  • src/cli/mod.rs
  • src/log_store/sqlite.rs
  • src/supervisor/adopt.rs
  • src/supervisor/lifecycle.rs
  • src/supervisor/log_sink.rs
  • src/supervisor/mod.rs
  • test/logs.bats

Comment thread src/cli/log_sink.rs
Comment on lines +21 to +31
#[derive(Debug, clap::Args)]
#[clap(hide = true, verbatim_doc_comment)]
pub struct LogSink {
/// Qualified id of the daemon whose output this is
#[clap(long)]
daemon_id: String,

/// Log format to parse lines with (`json`, `logfmt`, `auto`, or `text`)
#[clap(long, default_value = "text")]
log_format: String,
}

@coderabbitai coderabbitai Bot Jul 25, 2026

Copy link
Copy Markdown

Choose a reason for hiding this comment

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

🎯 Functional Correctness | 🟡 Minor | ⚡ Quick win

🧩 Analysis chain

🏁 Script executed:

#!/bin/bash
rg -n '"auto"' src/log_parse.rs
ast-grep run --pattern 'fn parse($$$) { $$$ }' --lang rust src/log_parse.rs

Repository: jdx/pitchfork

Length of output: 151


🏁 Script executed:

#!/bin/bash
set -euo pipefail

echo "== candidate files =="
fd -a 'log_sink\.rs|log_parse\.rs|commands\.json|usage\.kdl|cli' . | sed 's#^\./##' | head -200

echo
echo "== log_sink occurrences =="
rg -n "LogSink|log_format|auto|json|logfmt|text" -S src log docs 2>/dev/null | head -300

echo
echo "== relevant files sizes =="
for f in $(fd 'log_sink\.rs|log_parse\.rs|commands\.json|usage\.kdl' .); do
  echo -n "$f: "; wc -l "$f"
done

Repository: jdx/pitchfork

Length of output: 28648


🏁 Script executed:

#!/bin/bash
set -euo pipefail

echo "== src/log_sink.rs =="
cat -n src/cli/log_sink.rs

echo
echo "== src/log_parse.rs outline/contents =="
wc -l src/log_parse.rs
cat -n src/log_parse.rs

echo
echo "== commands.json relevant entries =="
python3 - <<'PY'
import json
from pathlib import Path
p=Path('docs/cli/commands.json')
data=json.loads(p.read_text())
# Locate log subcommands containing log_format/help around auto/logfmt
for item in data.get('commands', []):
    if any('log' in str(s).lower() or 'sink' in str(s).lower() for s in [item.get('name',''), item.get('path',''), item.get('id','')]):
        for sec in ['help_text','long_help','arguments','subcommands']:
            if sec in item:
                print(f'--- {sec} ---')
                print(json.dumps(item.get(sec), indent=2)[:2500])
PY

echo
echo "== usage.kdl relevant log sections =="
rg -n -C 5 "log|log_format|auto" pitchfork.usage.kdl docs/cli 2>/dev/null | head -300

echo
echo "== behavior probe of parsed branches in current code by parsing source text =="
python3 - <<'PY'
from pathlib import Path
s=Path('src/log_parse.rs').read_text()
print("contains '\"auto\"' in log_parse.rs:", '"auto"' in s)
print("contains case-insensitive match auto:", 'match' in s and 'auto' in s)
print("'json' branch present:", '\\\"json\\\"' in s or '"json"' in s)
print("'logfmt' branch present:", '\\\"logfmt\\\"' in s or '"logfmt"' in s)
print("plain fallback occurrences:")
for i,line in enumerate(s.splitlines(),1):
    if 'ParsedLog::plain' in line:
        print(f"{i}: {line.strip()}")
PY

Repository: jdx/pitchfork

Length of output: 50371


Remove auto from the documented log formats.

LogSink advertises auto as a supported --log-format, but src/log_parse.rs::parse() only handles "json", "logfmt", and falls every other value to plain-text. --log-format auto therefore acts like --log-format text, so either implement auto-detection or remove it from the argument/help text consistently.

🤖 Prompt for AI Agents
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.

In `@src/cli/log_sink.rs` around lines 21 - 31, Update the LogSink log_format
field’s documentation to remove “auto” from the advertised formats, leaving only
json, logfmt, and text. Do not change parsing behavior in parse(); ensure the
clap help text consistently reflects the supported values.

Copy link
Copy Markdown
Owner Author

Choose a reason for hiding this comment

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

I could not retrieve the body of this comment — the API returns only the analysis chain, with no claim attached, so I may be answering the wrong thing.

Taking it at the line it points to, the --log-format default of text: the supervisor always passes --log-format explicitly, resolved from the daemon's log_format or logs.log_format, so the default only applies if someone runs the hidden subcommand by hand. If the concern was something else, please restate it and I will address it.

This comment was generated by Claude Code.

Copy link
Copy Markdown

Choose a reason for hiding this comment

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

@jdx, the concern is unrelated to the text default.

src/cli/log_sink.rs advertises auto as a supported --log-format value:

json, logfmt, auto, or text

However, src/log_parse.rs::parse() has explicit parsing only for json and logfmt; all other values—including auto and text—fall back to plain-text parsing. So auto is currently not an auto-detect mode.

Please either implement auto-detection or, for the minimal fix, remove auto from the LogSink argument help and generated CLI documentation.

Comment thread src/supervisor/lifecycle.rs
…rves

Four robustness problems, all in the process that is now the only reader
of a daemon's pipe — so each one ends with the daemon blocked or its
output lost.

- reading and writing are separate tasks. The batch write was on the read
  path, so a contended SQLite write, which can now wait out the store's
  five-second busy timeout, stopped the pipe being drained. A bounded
  queue between them keeps backpressure without unbounded growth.
- output containing no newline is split at 64 KiB instead of accumulated
  indefinitely. A daemon emitting an endless stream, or binary data, would
  have grown the buffer until the sink was killed for memory — and the
  supervisor would have started another to repeat it. Verified: 300 KB of
  newline-free output is recorded as bounded lines.
- a sink started for a daemon that then fails to spawn is killed and
  reaped explicitly. Dropping the handle only reaps best-effort, and
  run_once runs per retry attempt, so repeated spawn failures could leave
  several behind.
- the gap before retrying a failed sink spawn drops from 1s to 200ms.
  Nothing drains the pipe meanwhile, so a chatty daemon blocks; blocking
  is the right outcome rather than discarding output, but the gap should
  be brief.

A failed start also waits for its output to settle rather than returning
at the first row, since the sink batches: a daemon printing eight lines
before failing reported only the first. Now all eight, at a cost of
~120ms rather than ~30ms.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Comment thread src/cli/log_sink.rs Outdated
/// before reporting. Typically satisfied in a few dozen milliseconds; a daemon
/// that failed without printing anything waits the whole of it, so keep it
/// short.
const SINK_OUTPUT_TIMEOUT: Duration = Duration::from_millis(400);

Copy link
Copy Markdown

Choose a reason for hiding this comment

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

Startup wait shorter than store lock

Medium Severity

Failed starts call wait_for_output with a 400ms cap while log batches can sit behind SQLite writes that wait up to five seconds on busy_timeout. The CLI may query the store before the sink persists the daemon’s last lines, so startup failure output can be missing under writer contention.

Additional Locations (1)
Fix in Cursor Fix in Web

Reviewed by Cursor Bugbot for commit 621137f. Configure here.

Copy link
Copy Markdown
Owner Author

Choose a reason for hiding this comment

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

True, and I am keeping the 400ms cap deliberately.

Matching the store's five-second busy timeout would mean a failed pitchfork start could pause five seconds before reporting — and the retry zero fails immediately with one attempt test caps a failed start at three seconds, so it is not even available. Under that much write contention no cap I can pick is reliable anyway.

What the cap protects is the common case, which it does: measured ~120ms, and a daemon printing eight lines before failing reports all eight. Under heavy contention the diagnostics degrade to partial or empty, but nothing is lost — the lines are still written and pitchfork logs <daemon> shows them. I would rather have a fast failure with occasionally incomplete inline diagnostics than a start command that can hang for five seconds.

This comment was generated by Claude Code.

@coderabbitai coderabbitai 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.

Actionable comments posted: 4

🤖 Prompt for all review comments with AI agents
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.

Inline comments:
In `@src/supervisor/log_sink.rs`:
- Line 61: Update the retry loop in the supervisor log-sink spawning flow around
SPAWN_RETRY_DELAY to retain the initial 200ms retry, then apply capped
exponential backoff after consecutive spawn failures. Reset the backoff to the
initial delay whenever a replacement sink starts successfully, and continue
honoring the existing monitor-token validity behavior.
- Around line 92-101: Update the polling logic around LogQuery and
LOG_STORE.query so it observes log growth without materializing every matching
LogEntry on each poll. Add or reuse a count/latest-row query, or track an
incremental identifier, while preserving the existing daemon and since filters
and returning the equivalent growth signal used by the poller.
- Around line 97-104: Update the log-count polling around the
tokio::task::spawn_blocking call so SQLite/query errors are propagated rather
than converted to found = 0. On read failure, reset or extend the settling timer
and continue polling until a successful stable read or the existing deadline;
retain the no-new-output behavior only for successful queries.
- Around line 87-104: Update wait_for_output’s polling loop around
LOG_STORE.query and the deadline to enforce the timeout before and during each
SQLite poll, including returning immediately when timeout is zero. Use a
deadline-aware query path or wrap the blocking operation so a slow query cannot
keep the caller waiting beyond the requested deadline, while preserving the
existing polling behavior for queries that complete in time.
🪄 Autofix (Beta)

Fix all unresolved CodeRabbit comments on this PR:

  • Push a commit to this branch (recommended)
  • Create a new PR with the fixes

ℹ️ Review info
⚙️ Run configuration

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

Review profile: CHILL

Plan: Pro Plus

Run ID: d7bca03e-a2e2-489a-9e9a-a394c0292434

📥 Commits

Reviewing files that changed from the base of the PR and between 9dcf54e and 621137f.

📒 Files selected for processing (3)
  • src/cli/log_sink.rs
  • src/supervisor/lifecycle.rs
  • src/supervisor/log_sink.rs
🚧 Files skipped from review as they are similar to previous changes (2)
  • src/supervisor/lifecycle.rs
  • src/cli/log_sink.rs

Comment thread src/supervisor/log_sink.rs
Comment thread src/supervisor/log_sink.rs Outdated
Comment thread src/supervisor/log_sink.rs Outdated
Comment thread src/supervisor/log_sink.rs Outdated
Five issues, four of them introduced by the previous commit's split of
reading from writing.

A queue closed by a dead writer was reported as success, which tells the
supervisor the sink reached end of file — so it would stop replacing a
sink while the daemon was still writing. It is now a read error, which
exits non-zero and gets the sink replaced.

The wait a failed start does for its output had three problems:

- its timeout sat between polls, so a single query waiting out the
  store's five-second busy timeout blew straight through the 400ms cap.
  The cap now wraps the whole loop.
- it counted every entry since the run began on each poll, materializing
  a chatty daemon's whole history every 20ms. It now reads one row: the
  newest entry's id, which is all that growth detection needs.
- a query error counted as zero rows, which reads as a settled stream. An
  unreadable store says nothing about whether the sink has finished
  writing, so it no longer ends the wait early.

Sink spawn failures now back off to five seconds rather than retrying
five times a second for the life of the daemon.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Comment thread src/supervisor/lifecycle.rs Outdated
The branch for a daemon that exits before its PID can be read killed the
sink immediately, discarding whatever was still in the pipe or batched in
it — and since that daemon ran, its output is the only explanation of why
it gave up. Reaping like that is right for a daemon that never started at
all, which is the path it was added for.

Its write end is already closed, so the sink is on its way to end of file:
wait for the output to land, as the other readiness failures do, and reap
afterwards.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Comment thread src/cli/log_sink.rs Outdated
Splitting a line purely by byte count cut multi-byte characters in half at
the 64 KiB cap, and converting each half on its own turned one valid
character into two replacement characters. The split now stops at the last
complete character and carries the partial sequence into the next line.

Emitting at the cap also left the buffer empty, so a newline arriving
immediately afterwards recorded an extra blank row — that newline
terminates the line already written. Blank lines a daemon actually prints
are still recorded.

Verified: a two-byte character straddling the boundary survives intact,
exactly 64 KiB followed by a newline yields two rows rather than three,
and consecutive blank lines are still preserved.

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

@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.

There are 2 total unresolved issues (including 1 from previous review).

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 a097289. Configure here.

Comment thread src/supervisor/lifecycle.rs
Comment thread src/cli/log_sink.rs Outdated
…ectly

Two review follow-ups.

A sink that has been started but not yet handed to `supervise` is now held
by a guard that terminates it when dropped. `run_once` can bail out at
several points in between — stdio failing to wire up, the daemon's spawn
failing, its PID being unreadable — and each one had to remember to reap.
Three findings have now been raised about paths through that gap, so tying
cleanup to the value's lifetime retires the class rather than patching the
next one.

The character-boundary split no longer asks `from_utf8` where the string
stops being valid. That reports the first problem, so an invalid byte
earlier in the line hid an unfinished character at the end and the
character was split anyway. It now inspects the final bytes directly, which
cannot be masked. Verified with an invalid byte early and a two-byte
character straddling the cap: the injected byte alone becomes a
replacement character and the straddling one survives.

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

@coderabbitai coderabbitai 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.

Actionable comments posted: 1

🤖 Prompt for all review comments with AI agents
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.

Inline comments:
In `@src/supervisor/log_sink.rs`:
- Around line 176-182: Replace the unconditional tokio::spawn in
PendingSink::drop with cleanup that does not depend on an active runtime: return
or retain the kill JoinHandle and reap it synchronously where safe, while
scheduling the async kill from the supervisor task and providing a synchronous
fallback when no supervisor is available. Ensure child termination is not
abandoned or panics after runtime shutdown.
🪄 Autofix (Beta)

Fix all unresolved CodeRabbit comments on this PR:

  • Push a commit to this branch (recommended)
  • Create a new PR with the fixes

ℹ️ Review info
⚙️ Run configuration

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

Review profile: CHILL

Plan: Pro Plus

Run ID: b37f625b-998c-4543-974a-937e44d8a7f4

📥 Commits

Reviewing files that changed from the base of the PR and between a097289 and a55839f.

📒 Files selected for processing (3)
  • src/cli/log_sink.rs
  • src/supervisor/lifecycle.rs
  • src/supervisor/log_sink.rs
🚧 Files skipped from review as they are similar to previous changes (2)
  • src/cli/log_sink.rs
  • src/supervisor/lifecycle.rs

Comment thread src/supervisor/log_sink.rs Outdated
`tokio::spawn` in a destructor panics when there is no runtime to spawn
onto, and silently abandons the task if shutdown has already begun — both
reachable while the runtime is going away. `start_kill` needs neither, so
the signal is always delivered; collecting the exit status is left to
tokio's orphan reaping, since a destructor cannot await.

Verified against the case the guard exists for, using a shell binary that
does not exist so the daemon's spawn fails after its sink has started:
five failed starts leave no sinks behind.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
gaojunran added a commit to gaojunran/pitchfork that referenced this pull request Jul 25, 2026
Reflect the log-sink design from PR jdx#661: most daemons now have their
output captured by a sibling `pitchfork log-sink` process that holds
the pipe's read end, surviving supervisor crashes. Daemons using
ready_output, on_output hooks, or pty keep the in-process path.

Updated sections:
- Module layout: add log_sink.rs
- Startup sequence: add sink setup step before spawn
- Readiness detection: clarify two capture paths
- Monitor exit path: note drain applies only to in-process path
- Logging: rewrite with sink-path and in-process-path subsections

Also includes rustfmt formatting from ci-dev (let-chains, remove
unnecessary reference).
@jdx
jdx merged commit 004977c into main Jul 25, 2026
13 checks passed
@jdx
jdx deleted the claude/log-sink branch July 25, 2026 15:29
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