Skip to content

logkeeper: the UART's carrier starts within a bound, whatever the rounds have read - #1228

Merged
Japabu merged 2 commits into
mainfrom
logkeeper-wire-start-bound
Nov 11, 2026
Merged

Japabu merged 2 commits into
mainfrom
logkeeper-wire-start-bound

Conversation

@Japabu

@Japabu Japabu commented Nov 11, 2026 •

Copy link
Copy Markdown
Collaborator

Problem

The console UART's carrier starts where logkeeper's rounds have read past the records the kernel put on the UART itself. Nothing bounded that. A kernel answer naming a position its ring never reaches (a shard of a CPU that never started; fixed at its cause by #1207) left the carrier waiting in Hub::wire_start, and the UART silent for the machine's life with no line saying why. A round with no lines never said the start either. Recorded in issues/logkeepers-uart-carrier-waits-for-its-start-with-no-bound-and-no-report.md, which this closes.

Resulting behaviour

  • The hand-over is one value (Handover in system/logkeeper/src/main.rs): what the kernel spoke, what the rounds so far owe the UART, and a deadline WIRE_START (5 s) after it.
  • Every round, with lines or without, says the start once the rounds have read past the kernel's positions, or at the deadline wherever they have read to. At the deadline it warns, naming both sets of positions, and the carrier starts from there with what the rounds before owe. The kernel's records read later then repeat on the UART.
  • The loop wakes at least every POLL_SLOW (250 ms), so the carrier's wait in Hub::wire_start ends within the bound plus one cadence.

Decisions

  • The bound is on the loop, not on the carrier's condition wait. The awaited event is "the rounds read past the kernel's positions", and the loop owns it together with what the UART is owed. Hub::wire_start keeps waiting on the hub's condition with no timeout of its own; what it waits for now always arrives. The alternative, a wait_timeout in the hub, needs the owed lines moved into the hub or the carrier started from the boot's first line, and a way to tell the loop the start was forced so it stops accumulating. Tradeoff: if the loop itself were wedged the carrier would still not start. Then nothing reaches the replay either, and that is a defect of whatever the loop waits in, not of this start.
  • 5 s. The records the kernel spoke are in its ring before the first round, which reads the ring whole, so a healthy start is said in the first round. The bound is policy, justified at WIRE_START: a false expiry repeats lines, a missed one leaves the UART silent.
  • No manual change: the manual does not describe the carrier's start.

Checks

  • cargo test --manifest-path system/logkeeper/Cargo.toml at 3713400: exit 0, 28 passed, including the new the_wire_starts_at_its_bound_whatever_the_rounds_have_read, which drives Handover with instants it chooses (l1228-test.log; at cd9efbb, logkeeper-test-1.log).
  • Negative control: the deadline taken out of Handover::over makes that test fail (exit 101; logkeeper-control.log, logkeeper-control.patch).
  • cargo clippy --manifest-path system/logkeeper/Cargo.toml --all-targets with the workspace's adopted lints at 3713400 (l1228-clippy.log): the one finding in this change, an unchecked Instant - Duration in the new test, is fixed by 3713400. The five left are in code this branch does not touch and are on main as they are here; no gate lints a guest program (issues/userland-programs-are-never-linted.md).
  • Host checks are logkeeper's own, under the owner's testing policy; the merge queue runs the full host check. An earlier full --ci host at cd9efbb was cut short by the machine's disk filling (logkeeper-ci-host-enospc.log); its host-member tests and lint, which do not include logkeeper, were green but for the known macOS llvm::tests red.
  • Not run: a guest or metal boot. The expiry needs a kernel answer the kernel no longer gives; the wiring from the decision to Hub::set_wire_from is six lines read in review, and the carrier's start from a said position is held by the existing hub tests.

Evidence: ToyOSOrg/evidence pr-1228, at aaa33277 (linked above per check).

Risks

🤖 Generated with Claude Code

…nds have read

The console UART's carrier starts where the rounds have read past the
records the kernel put on the UART itself. Nothing bounded that: a kernel
answer naming a position its ring never reaches (a shard of a CPU that
never started, fixed at its cause by #1207) left the carrier waiting in
`Hub::wire_start` and the UART silent for the machine's life, with no line
saying why. A round with no lines never said the start either.

The loop owns the awaited event, so the bound is the loop's: the hand-over
(`Handover`) carries what the kernel spoke, what the rounds so far owe the
UART and a deadline `WIRE_START` (5 s) after it. Every round, with lines or
without, says the start once the rounds have read past the kernel's
positions, or at the deadline wherever they have read to, with a warning
that names both sets of positions. The carrier then starts from there with
what the rounds before owe; the kernel's records read later repeat on the
UART, which beats a silent one. The loop wakes at least every `POLL_SLOW`,
so the carrier's wait on the hub ends within the bound plus one cadence.

Closes issues/logkeepers-uart-carrier-waits-for-its-start-with-no-bound-and-no-report.md.

Co-Authored-By: Claude Fable 5.2 <noreply@anthropic.com>
…y a checked subtraction

Clippy's adopted `unchecked_time_subtraction` names the bare `Instant -
Duration` in the new test.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Japabu added a commit to ToyOSOrg/evidence that referenced this pull request Nov 11, 2026
@Japabu

Japabu commented Nov 11, 2026

Copy link
Copy Markdown
Collaborator Author

Review of #1228 at 3713400

Architecture

The bound sits with the loop. The loop owns the event being awaited (the rounds' read positions passing what the kernel spoke) and also what the UART is owed. Hub::wire_start keeps its condition wait with no timeout, and that condition now always arrives. The alternative, a timeout in the hub, would have to move the owed lines and a "forced" state into the hub. Handover also turns two fields (spoken, owed_wire) into one Option, which removes a state. The change adds about 60 production lines and 15 test lines, and closes its record.

The wait rule

  • What happens on expiry. At WIRE_START it warns, naming the positions read and the positions spoken. It then starts the carrier from the replay's end with what the rounds owe. The warning is a line in logkeeper's own ring, so it reaches the file, the readers and, now that the carrier has started, the UART. Kernel records read after that point repeat on the UART, as the record's exit accepted. This reports the expiry, which the rule requires (system/logkeeper/src/main.rs:637-649).
  • Whether the bound is justified. Yes, at main.rs:264-270. The spoken records are in the ring before the first round, so a healthy start happens in round one. A false expiry would need written_through to hold a shard below spoken. That needs a spoken record stamped after the first round's cut, which cannot happen for records spoken before logkeeper ran. A slow round does not cause a false warning either: read_past is checked before the deadline. The loop's cadence makes the bound reachable within POLL_SLOW, except while a round is blocked in a /log call. The PR lists that under Risks, and logkeeper: the file is a consumer of the replay, written in batches on its own thread #1232 removes it.
  • Stop interplay (checked). start_wire now also runs during a stop. On main the start was never said there, because the check sat after write's early return for a stop. If the start fires during a stop, the UART carrier gets the owed lines and then the stop's lines. That is benign.
  • The test and its control. The test is deterministic and hermetic: it drives the predicate with instants it chooses. The other half of the defect is that a round with no lines never said the start. That half is held by round calling start_wire every time (main.rs:529), which is direct code and acceptable to read in review. The control moves the deadline 5000 s out and fails at the "started unread at the bound" assertion (exit 101, at cd9efbb). 3713400 changed only the test's subtraction, so the control still applies.

Findings

No blockers.

SUGGESTION (optional):

  • system/logkeeper/src/main.rs:267-268: "a missed one leaves it silent" reads oddly for a bound. "a late one leaves it silent longer" says what is meant.
  • system/logkeeper/src/main.rs:636: "which is said" is ambiguous. "and says so" is clearer.

Evidence

LAND

@Japabu

Japabu commented Nov 11, 2026

Copy link
Copy Markdown
Collaborator Author

Orchestrator: review LAND at 3713400 (no guest or metal owed: the start check is host-tested with a control, and the expiry path is a direct call read in review). The head is unchanged since the review. Queueing; #1232, stacked on it, follows separately.

@Japabu
Japabu marked this pull request as ready for review November 11, 2026 17:06
@Japabu
Japabu added this pull request to the merge queue Nov 11, 2026
Merged via the queue into main with commit dda500c Nov 11, 2026
10 checks passed
@Japabu
Japabu deleted the logkeeper-wire-start-bound branch November 11, 2026 17:20
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