bug: the auto-spawned daemon has NO log — its stderr is /dev/null, so no field failure can ever be diagnosed #92

New issue

Closed

opened 2026-09-03 14:44:59 +02:00 by buildagent · 1 comment

buildagent commented

2026-09-03 14:44:59 +02:00

Member

Found while a customer reported the #88 daemon failure for the third time in one day, again immediately after a full solution build. Their question was simply "do we have a log for this?"

No. And there is no way to turn one on.

Verified three ways

crates/daemon/src/main.rs::setup_logging — tracing_subscriber::fmt().with_writer(std::io::stderr). stderr and nowhere else.
crates/mcp-server/src/main.rs spawns the daemon detached:

cmd.stdin(std::process::Stdio::null())
   .stdout(std::process::Stdio::null())
   .stderr(std::process::Stdio::null());

Every diagnostic the daemon emits is discarded at birth.

No log-file option exists anywhere in crates/*/src. CODE_INDEX_LOG sets the EnvFilter — the filter, never the destination — so CODE_INDEX_LOG=debug produces more output that still goes to /dev/null. The only artefacts surviving a daemon death are daemon.lock, daemon.toml and the database.

Why this outranks the bug it was found under

respawned daemon never became ready within 45s ... likely mid-reconcile is the client's guess about a process it cannot see. It is the entire evidence base for #88, and the word "likely" is load-bearing: nobody knows whether the daemon was alive-and-busy, exited, or never spawned. Those are three different repairs.

So #88 has been stuck at hypotheses not because nobody looked, but because there is nothing to look at. And this generalises past #88: any daemon-side failure a user hits in the field is undiagnosable by construction, on every platform, for every release we have shipped.

A fix for #88 would also be unverifiable in the field. We could ship it, the customer could still fail, and neither side could tell whether the fix worked or a second cause was in play.

What is needed

The auto-spawned daemon writes its log somewhere durable — beside the lockfile under <root>/.code-index/ is the obvious place.
Bounded: a size cap or rotation, so it cannot grow without limit on a long-lived daemon.
No secrets: the RPC auth token must not reach it. Store and project paths are fine.
CODE_INDEX_LOG must actually reach it, so an operator can raise the level and reproduce.
The readiness-failure message should name the path, turning a guess into a next step.

Workaround until then

Run the daemon by hand and capture stderr; the MCP server attaches to a live daemon rather than spawning its own:

code-index-daemon --root <repo> --db <repo>/.code-index/index.db --log debug 2> daemon.log

This is not a fix: the reported failure is specifically on the respawn path, so a hand-started daemon changes the conditions under test.

Acceptance

A daemon started by the MCP server writes a log an operator can find without reading our source.
A test asserts the file exists and contains the daemon's own startup line after a normal spawn — and that it does NOT contain the auth token.
The size bound is measured, not asserted.

Blocks meaningful field diagnosis of #88.

Found while a customer reported the #88 daemon failure for the **third time in one day**, again immediately after a full solution build. Their question was simply *"do we have a log for this?"* **No. And there is no way to turn one on.** ## Verified three ways 1. `crates/daemon/src/main.rs::setup_logging` — `tracing_subscriber::fmt().with_writer(std::io::stderr)`. **stderr and nowhere else.** 2. `crates/mcp-server/src/main.rs` spawns the daemon detached: ```rust cmd.stdin(std::process::Stdio::null()) .stdout(std::process::Stdio::null()) .stderr(std::process::Stdio::null()); ``` **Every diagnostic the daemon emits is discarded at birth.** 3. No log-file option exists anywhere in `crates/*/src`. `CODE_INDEX_LOG` sets the `EnvFilter` — the *filter*, never the *destination* — so `CODE_INDEX_LOG=debug` produces more output that still goes to `/dev/null`. The only artefacts surviving a daemon death are `daemon.lock`, `daemon.toml` and the database. ## Why this outranks the bug it was found under `respawned daemon never became ready within 45s ... likely mid-reconcile` is the **client's guess about a process it cannot see**. It is the entire evidence base for #88, and the word "likely" is load-bearing: nobody knows whether the daemon was alive-and-busy, exited, or never spawned. Those are three different repairs. So #88 has been stuck at hypotheses not because nobody looked, but because **there is nothing to look at**. And this generalises past #88: any daemon-side failure a user hits in the field is undiagnosable by construction, on every platform, for every release we have shipped. **A fix for #88 would also be unverifiable in the field.** We could ship it, the customer could still fail, and neither side could tell whether the fix worked or a second cause was in play. ## What is needed - The auto-spawned daemon writes its log somewhere durable — beside the lockfile under `<root>/.code-index/` is the obvious place. - **Bounded**: a size cap or rotation, so it cannot grow without limit on a long-lived daemon. - **No secrets**: the RPC auth token must not reach it. Store and project paths are fine. - `CODE_INDEX_LOG` must actually reach it, so an operator can raise the level and reproduce. - The readiness-failure message should name the path, turning a guess into a next step. ## Workaround until then Run the daemon by hand and capture stderr; the MCP server attaches to a live daemon rather than spawning its own: ``` code-index-daemon --root <repo> --db <repo>/.code-index/index.db --log debug 2> daemon.log ``` This is not a fix: the reported failure is specifically on the **respawn** path, so a hand-started daemon changes the conditions under test. ## Acceptance - A daemon started by the MCP server writes a log an operator can find without reading our source. - A test asserts the file exists and contains the daemon's own startup line after a normal spawn — and that it does NOT contain the auth token. - The size bound is measured, not asserted. Blocks meaningful field diagnosis of #88.

dhoyer referenced this issue from a commit

2026-09-04 07:02:49 +02:00

chore: v0.26.0

buildagent commented

2026-09-04 09:43:26 +02:00

Author

Member

Shipped in v0.26.0

An MCP-spawned daemon runs with stdin, stdout and stderr on the floor, so for the whole life of any startup defect there was nothing to read. It now writes daemon.log beside its lockfile — bounded, with one rotated backup — and the client's "did not become ready" error names the path.

The capability token is never written to it, and that guard is graded rather than assumed. The test that grades it had been vacuous by construction: the spawn passed CODE_INDEX_DAEMON_NO_AUTH=1, main::run mints no token under that variable in a debug build, cargo test IS a debug build, and the assertion sat inside if let Some(tok) = ... — so it never executed once. Measured control: a mutation that makes the daemon print its token into the log passes the OLD shape of the test. The token is now proven to EXIST before its absence is asserted.

The log immediately earned its keep

daemon_log_e2e then timed out on both CI platforms, and the diagnostic added alongside it answered the question on the first occurrence rather than the fourth (issue #94):

the daemon was still RUNNING throughout — so this is slowness or a wedge, not a crash.
the log EXISTS but is EMPTY

Still running ruled out the crash; present-but-empty ruled out everything after setup_logging. A live process with an empty log is a level filter — both CI workflows set CODE_INDEX_LOG: warn job-wide, and the test asserted an info! line. Reproduced locally byte-identically with one command, fixed with env_remove, and closed as #94.

## Shipped in v0.26.0 An MCP-spawned daemon runs with stdin, stdout and stderr on the floor, so for the whole life of any startup defect there was nothing to read. It now writes `daemon.log` beside its lockfile — bounded, with one rotated backup — and the client's "did not become ready" error names the path. The capability token is never written to it, and that guard is graded rather than assumed. The test that grades it had been **vacuous by construction**: the spawn passed `CODE_INDEX_DAEMON_NO_AUTH=1`, `main::run` mints no token under that variable in a debug build, `cargo test` IS a debug build, and the assertion sat inside `if let Some(tok) = ...` — so it never executed once. Measured control: a mutation that makes the daemon print its token into the log passes the OLD shape of the test. The token is now proven to EXIST before its absence is asserted. ## The log immediately earned its keep `daemon_log_e2e` then timed out on both CI platforms, and the diagnostic added alongside it answered the question on the first occurrence rather than the fourth (issue #94): ``` the daemon was still RUNNING throughout — so this is slowness or a wedge, not a crash. the log EXISTS but is EMPTY ``` Still running ruled out the crash; present-but-empty ruled out everything after `setup_logging`. A live process with an empty log is a level filter — both CI workflows set `CODE_INDEX_LOG: warn` job-wide, and the test asserted an `info!` line. Reproduced locally byte-identically with one command, fixed with `env_remove`, and closed as #94.

buildagent closed this issue

2026-09-04 09:43:31 +02:00

buildagent referenced this issue

2026-09-04 09:45:36 +02:00

Daemon never becomes ready within 45s after a large build churns bin/obj — the top reason a user reaches for grep #88

buildagent referenced this issue

2026-09-04 10:06:07 +02:00

Daemon never becomes ready within 45s after a large build churns bin/obj — the top reason a user reaches for grep #88