Skip to content

Audit stdout destination blocks Tokio workers when the collector stops reading #1566

Closed

Description

@jeremi

Raised by the Codex review of #1560 and confirmed against the code there. The audit writer lands on main with that PR.

Problem

For audit.destination: stdout, AuditWriter::append calls LineStream::append, which runs a blocking write_all and flush under a std::sync::Mutex directly on the calling Tokio worker (crates/registry-platform-audit/src/writer.rs). If the log collector stays connected but stops reading, the pipe fills and every audited request blocks its worker with no deadline. Enough concurrent requests occupy every worker, and then readiness, shutdown and unrelated requests stop making progress. The contract is to fail closed with AuditUnavailable, but the writer hangs instead.

Why this is not a one-line fix

Wrapping the write in spawn_blocking moves the stall into the blocking pool, which the file destination also uses. A stalled collector would then exhaust that pool instead. A fix that fails closed needs a bounded wait, for example a dedicated writer thread fed by a bounded channel, where append returns AuditUnavailable when an entry is not accepted within a deadline and the stream is then marked unhealthy so readiness reports it.

Decisions needed

  • The deadline value, and whether operators can configure it.
  • Whether one stalled write marks the stream permanently unhealthy, or whether it recovers once the collector drains.

Acceptance

  • A test with a sink that blocks forever shows that append returns AuditUnavailable within the deadline, that ready() turns false, and that other tasks on the runtime keep making progress.

Activity

  1. added
    bugSomething isn't working
    area:platformRegistryStack platform and cross-product ownership.
    rustRust implementation work.
    triage:needs-designNeeds a bounded scope, product decision, or acceptance design before implementation.
    1.0-blockerBlocks the 1.0 release intent.
    on Sep 25, 2026
  2. jeremi commented on Sep 28, 2026

    @jeremi
    MemberAuthor

    Triage 2026-09-28, re-checked against origin/main (60b734f). Still open: LineStream::append is still a blocking write_all/flush under a std Mutex with no deadline, so a stalled collector now exhausts the blocking pool and hangs every audited request. Add a bounded wait that answers AuditUnavailable, and flip readiness when a write stalls (healthy only flips on a write error today).

  3. jeremi commented on Sep 28, 2026

    @jeremi
    MemberAuthor

    Carried over from #1605 (closed as not planned): at shutdown, DetachedLines::drop joins its writer thread, so a stalled stdout (full pipe) hangs shutdown indefinitely, and the detached queue grows without bound while the stream is stalled. GroupCommitFile::drop also writes and fsyncs on whichever runtime thread drops it (crates/registry-platform-audit/src/writer.rs:1190-1200 and :1438-1450). #1566's bounded-wait design should cover the drop paths too.

  4. jeremi commented on Oct 12, 2026

    @jeremi
    MemberAuthor

    Design outcome (2026-10-12)

    What still holds on main

    The stream write has run in spawn_blocking since 2026-09-27, so Tokio workers are no longer blocked and the title is partly out of date. What remains when the collector stops reading:

    • The write holds the stream mutex with no deadline.
    • Every later append parks one blocking-pool thread, and its request waits forever.
    • ready() stays true, because healthy only changes on a write error.
    • BReg holds a pooled database connection across the wait.
    • Shutdown hangs: DetachedLines::drop joins its thread with no bound.
    • The detached queue is unbounded.

    Shape

    One writer thread owns the sink, fed by a bounded queue. It replaces both the mutex plus spawn_blocking path and DetachedLines. The change stays inside registry-platform-audit.

    • append refuses at once when the stream has failed or is stalled, refuses when the queue is full, and otherwise waits for the writer's acknowledgement under the deadline. A caller gets success only after its line was written and flushed.
    • A queued entry whose caller already gave up is skipped, so no entry is written for a request that was refused while it was still queued.
    • ready() is false while the current write is older than the deadline.
    • Dropping the writer waits at most one deadline for the thread.

    The two decisions asked for above

    Deadline: a fixed 5 seconds, not configurable. A healthy pipe write takes microseconds, the value sits below the default request timeout (10 seconds in BReg) so callers get the audit problem and not a generic timeout, and the platform guide says a fix adds no configuration key unless the defect cannot be fixed without one. The audit destination keys are also copied across eight runtimes today; #2006 proposes one shared block, which is where a tunable would land if one is ever needed.

    Recovery: a stall recovers by itself, a write error keeps stopping the writer until restart.

    • A stall loses nothing: the stuck line is written when the collector drains.
    • This matches how comparable systems separate the two cases. HashiCorp Vault completes no requests while its only audit device is blocked and resumes when the device can write. The Kubernetes API server's blocking-strict audit mode fails the request and latches nothing. Linux auditd reserves suspend and halt for write errors and a full disk.
    • A failing readiness probe does not restart a pod, so a latched stall would leave a replica unready until someone intervened, and a restart reconnects to the same collector.

    Three things follow from that choice:

    1. One operational log line when a stall starts and one when it ends.
    2. A contract sentence that separates a stall from a failed write.
    3. A recorded caveat: the one line that was mid-write when the deadline passed is still written later, although its request was refused. That is at most one line per stall, and it over-records.

    Drop paths (the note carried over from #1605)

    • Stream drop is bounded by one deadline, and the detached queue is bounded.
    • GroupCommitFile::drop stays as it is. It runs once, at the final drop, and only when a flush was cancelled; skipping it would lose audit entries. An explicit asynchronous close would have to be called from every runtime's shutdown path, which is a larger change than this issue's stalled-stream case justifies.

    Acceptance, extended

    On top of the test listed above (blocked sink: AuditUnavailable within the deadline, ready() false, other tasks progress): readiness returns when the sink drains, a write error still latches, drop returns within the bound, a full queue refuses, and one consuming runtime shows the readiness change end to end.

  5. jeremi commented on Oct 17, 2026

    @jeremi
    MemberAuthor

    The audit stream writer now has a 5-second write deadline (crates/registry-platform-audit/src/writer.rs:103) and refuses audited requests while the stream is stalled, with tests for the deadline, readiness and drain. Handled by PR #2019. Closing as done.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    area:platformRegistryStack platform and cross-product ownership.bugSomething isn't workingcriticality:p2Priority/criticality P2.rustRust implementation work.triage:needs-designNeeds a bounded scope, product decision, or acceptance design before implementation.

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions