Skip to content

noded: a log chunk's job record counts the log it was read from - #48

Merged
rlrs merged 1 commit into
mainfrom
fix/noded-held-read-early-return
Oct 24, 2026
Merged

rlrs merged 1 commit into
mainfrom
fix/noded-held-read-early-return

Conversation

@rlrs

@rlrs rlrs commented Oct 24, 2026

Copy link
Copy Markdown
Owner

thousands_of_held_reads_wait_on_one_watch_and_disconnects_free_them failed in CI: one read answered with stdout_bytes 0 after the one-byte append.

Root cause

Held reads do not return early. The bug is in what a logs read sends back. read_pass built the job record first (StateDir::record opens the running job's logs to get their sizes) and then opened the stream's log a second time to read the chunk. If an append landed between the two opens, the chunk held the new byte while the record still said 0. In the test, the appender's create and write overlap the woken re-reads, so this can happen. Status reads take their cursor and counts from a single record, so they can't show this.

Reproduced locally:

  • Under load (16 parallel runs, 60 CPU hogs), an instrumented copy of the test showed a logs read answering data "eA==", next_offset 1, job.stdout_bytes 0.
  • A scratch route test (not committed) read logs while a thread appended. Before the fix, 321 of 3000 chunks had data past their record. After the fix, none did.

Fix

The record a chunk carries now takes the stream's count from the size the chunk was read against (JobRecord::read_against) while the job runs. Once the job is terminal, the persisted counts stand. The state is still read before the log, so a terminal record never undercounts a final log.

Production impact

  • Clients long-polling job status or logs never got spurious early returns.
  • For a running job, a logs response could carry a job record (stdout_bytes/stderr_bytes, cursor) older than its own data, and the gateway cached that record as the job's state. The counts are a lower bound, so cached answers during lifecycle transitions could be stale but not wrong.
  • The SDK does not read the record from log chunks.

Tests

  • New deterministic unit test a_chunks_record_counts_the_log_it_was_read_from (jobs/files.rs).
  • cargo test --locked --manifest-path runtime/noded/Cargo.toml passes.
  • The held-read test passed 60 of 60 runs (10 in parallel, 50 CPU hogs, 30 cores).
  • At the heavier repro load (16 parallel, 60 hogs), the instrumented test showed no stale-record failures. The only failures there came from overload itself: the test's 20 s hold deadline and loopback connect timeouts while 48k sockets were open. Those were present before the fix too.
  • scripts/check_test_rules.py is clean.

🤖 Generated with Claude Code

thousands_of_held_reads_wait_on_one_watch_and_disconnects_free_them
failed in CI with a read answering stdout_bytes 0 after the one-byte
append. Held reads do not return early: a logs read wakes on the append,
re-reads and returns because its chunk is non-empty. But read_pass built
the record first (StateDir::record sizes the running job's logs by
opening them) and then opened the stream's log again for the chunk. An
append landing between the two opens (the appender's create and write
straddle the woken re-reads) produced a chunk with the new byte next to
a record that still said 0. Status reads take their cursor and counts
from one record, so they cannot show this.

Reproduced locally: under load the instrumented test showed a logs read
answering data "eA==", next_offset 1, job.stdout_bytes 0; a scratch
route test reading logs while a thread appends saw 321 of 3000 chunks run
past their record before this change and none after.

The record a chunk carries now takes the stream's count from the size
the chunk was read against (JobRecord::read_against) while the job runs;
once terminal the persisted counts stand. The state is still read before
the log, so a terminal record never undercounts a final log.

Production impact: no spurious early returns for clients long-polling
status or logs. A running job's logs response could carry a job record
(stdout_bytes/stderr_bytes, cursor) older than its own data, and the
gateway cached that record as the job's state; the counts are a lower
bound, so cached answers during lifecycle transitions were at worst
stale, not wrong. The SDK does not read the record from log chunks.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
@rlrs
rlrs force-pushed the fix/noded-held-read-early-return branch from b32dffc to 02cef28 Compare October 24, 2026 12:23
@rlrs
rlrs merged commit 0aa6309 into main Oct 24, 2026
4 checks passed
@rlrs
rlrs deleted the fix/noded-held-read-early-return branch October 24, 2026 12:30
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