fix(observability): bound repeated durable-append failure reports - #97
Open
oxoxDev wants to merge 3 commits into
Open
fix(observability): bound repeated durable-append failure reports#97oxoxDev wants to merge 3 commits into
oxoxDev wants to merge 3 commits into
Conversation
The drain loop reported every failed durable append with a bare `eprintln!`, so a persistent sink failure (read-only volume, full disk) emitted one identical line per arriving observation and drowned the host's stderr. Failed appends were also uncounted, unlike queue-full drops, leaving the flood itself as the only signal that the durable log was losing data. Replace it with a per-worker failure-run state machine local to the drain thread: the first failure of a run reports at ERROR, subsequent failures are counted silently with a WARN reminder at most once per APPEND_REPORT_COOLDOWN (5 minutes) carrying the latest error, the first success emits one WARN recovery summary with the number of observations lost, and a shutdown that is still degraded emits a final WARN so a never-recovering run is not silently quiet. Reporting moves to `tracing` on the `tinyagents::observability` target with a `sink` field, matching the crate's existing emission idiom and removing its only `eprintln!`. Add an `append_failures` counter mirroring `dropped` so durable-log loss has a subscriber-independent signal, and keep attempting every item while degraded: the attempt is what detects recovery, it runs off the run's critical path, and skipping it would turn a transient blip into guaranteed loss of everything still queued. BEHAVIOR CHANGE: the stderr line is gone. An embedder with no tracing subscriber installed now sees nothing on append failure and must read `append_failures` instead. The message keeps the literal substring "durable append failed" so existing log searches still match.
Both module READMEs still described backend errors as "reported to stderr", which the rate-limited tracing reporter makes false. Describe the actual policy: errors are counted in `append_failures` and reported on the `tinyagents::observability` target, rate-limited to one ERROR per failure run plus a WARN reminder per cooldown and a WARN recovery summary, with the worker still attempting every item while degraded. Note that reporting requires a tracing subscriber, so `append_failures` is the subscriber-independent signal.
|
No actionable comments were generated in the recent review. 🎉 ℹ️ Recent review info⚙️ Run configurationConfiguration used: Organization UI Review profile: CHILL Plan: Pro Plus Run ID: 📒 Files selected for processing (2)
🚧 Files skipped from review as they are similar to previous changes (2)
📝 WalkthroughWalkthrough
ChangesAppend failure reporting
Estimated code review effort: 3 (Moderate) | ~20 minutes Sequence Diagram(s)sequenceDiagram
participant AppendWorker
participant AppendSink
participant tracing subscriber
AppendWorker->>AppendSink: append payload
AppendSink-->>AppendWorker: return success or error
AppendWorker->>AppendWorker: update append_failures
AppendWorker->>tracing subscriber: emit rate-limited report
Possibly related issues
Poem
🚥 Pre-merge checks | ✅ 5✅ Passed checks (5 passed)
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. Comment |
![coderabbitai[bot]](https://avatars.githubusercontent.com/in/347564?s=60&v=4){kind=small}
There was a problem hiding this comment.
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/harness/observability/worker.rs`:
- Around line 260-269: Expose the subscriber-free append failure count through
public accessors on both JournalSink and JsonlSink, delegating to
AppendWorker::append_failures; update the corresponding sink definitions at
src/harness/observability/worker.rs:45-48 and :260-269, and update the
documentation at src/harness/observability/README.md:66-75 to describe the
public API. Do not leave the counter documented as crate-internal.
🪄 Autofix
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: Organization UI
Review profile: CHILL
Plan: Pro Plus
Run ID: a93109b3-2c5c-4645-98ed-0906686b3b0d
📒 Files selected for processing (4)
src/graph/observability/README.mdsrc/harness/observability/README.mdsrc/harness/observability/test.rssrc/harness/observability/worker.rs
Both the module docs and the README told embedders to "read append_failures for a subscriber-independent signal". They cannot: like the queue-full `dropped` count it mirrors, the counter is `pub(crate)` and neither `JournalSink` nor `JsonlSink` exposes it. That mattered because it was the stated consolation for removing the stderr line — so the one claim softening the behaviour change was the one that was not true. Say plainly that a host with no subscriber sees nothing, and that installing one is how durable-log loss is observed.
![tinysweeper[bot]](https://avatars.githubusercontent.com/in/4526585?s=60&v=4){kind=small}
There was a problem hiding this comment.
tinysweeper found nothing blocking. Approving.
$0.0487 · 35,866 in / 16,570 out · 28,556 cached (80%) · z-ai/glm-5.2
critique: $0.0271 · 11,479 in / 10,277 out · 9,544 cached (83%) · z-ai/glm-5.2
security: $0.0036 · 7,578 in / 753 out · 6,405 cached (85%) · z-ai/glm-5.2
tests: $0.0061 · 6,850 in / 1,808 out · 5,398 cached (79%) · z-ai/glm-5.2
description: $0.0103 · 8,507 in / 3,252 out · 6,183 cached (73%) · z-ai/glm-5.2
What this change touches4 files, +273 -14 across 2 components. The code graph knows nothing about these files yet — normal for newly added files, and a cold index otherwise. flowchart LR
n0["src/harness/observability<br/>3 files +268 -12"]:::changed
n1["src/graph/observability<br/>1 file +5 -2"]:::changed
classDef changed fill:#0d4429,stroke:#238636,color:#e6edf3
classDef impacted fill:#161b22,stroke:#6e7681,color:#c9d1d9
classDef flagged fill:#5a1e02,stroke:#d93f0b,color:#ffffff
classDef blocking fill:#67060c,stroke:#f85149,color:#ffffff
Green: changed. Grey: untouched, reached through an import or a call. Orange: has findings. Red: has a finding that blocks the merge.
Changed files
|
tinysweeper
Bot
added
the
priority: p3
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
1 participant
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Summary
AppendWorker's drain loop reports every failed durable append witheprintln!— stateless, once per item, with no level and no way for the host application to filter it. Under a persistent sink failure (a volume flips read-only, a disk fills) every queued observation emits the identical line, and the host's stderr becomes that one line repeated.This is the crate's only
eprintln!. Every other diagnostic already goes throughtracingwith a target (e.g.tinyagents::embeddings::ollama), so an embedder can filter everything except this. The fix removes an outlier rather than introducing a logging regime.Failed appends were also uncounted. Queue-full drops have the
droppedcounter, but an append that fails after dequeue was lost with no counter at all — so the only signal that durable-log data was being lost was the noise.The prompting incident was downstream: a 200-line log tail from a live tenant contained this line and nothing else, so an investigation into an unrelated problem could see nothing.
One correction to how this is usually described, in case it shapes review: there is no retry loop here. Each item is attempted once and dropped on
Err. The flood is one line per arriving item, not per retry — so the fix is report-collapse plus a counter, not attempt-suppression. The worker deliberately keeps attempting while degraded: attempts are what detect recovery, they run off the critical path on the dedicated drain thread, and skipping them would turn a transient blip into guaranteed total loss of everything queued behind it.API Or Behavior Changes
Behaviour change, stated up front: the stderr line disappears. An embedder with no
tracingsubscriber installed now sees nothing on append failure. That is the intended contract — the host should control this like every other tinyagents event — but it is silent-by-default for anyone who was relying on the old output, so it should be a deliberate choice rather than a surprise. The newappend_failures()counter is the subscriber-free replacement signal.The literal substring
durable append failedis preserved in all four new messages, so existing log searches keep matching.tracing::error!(targettinyagents::observability,sinkfield). Durable-log data is being lost, and the module docs promise callers a lossless log modulo the counted drop policy.warn!reminder at most everyAPPEND_REPORT_COOLDOWN(300s) carrying the consecutive-failure count and the latest error text — so a changed cause (read-only → disk full) still surfaces within one cooldown without needing per-error keying.warn!reporting how many appends were lost.warn!rather thaninfo!because data was lost.warn!summary, so a run that never recovers is not silently quiet.append_failures: Arc<AtomicU64>+ accessor +Debugfield, mirroring the existingdroppedcounter exactly (sameRelaxedordering, same accessor pattern).No new dependencies —
tracingis already a direct dependency.Public API is unchanged. One addition is
pub(crate):spawn_with_cooldown, whichspawndelegates to with the 300s constant. Reviewer's call, and easy to drop — with the cooldown hardcoded, the reminder emission path is unreachable from a test, so only theshould_reportdecision could be covered and the live log lines would sit uncovered against the 90% gate. If you would rather keep the surface minimal and accept those uncovered lines, say so and I will collapse it.Tests
cargo fmt --all -- --checkcargo clippy --all-targets -- -D warningscargo clippy --all-targets --all-features -- -D warningscargo build --all-targetscargo build --all-targets --all-featurescargo test— 112 suites okcargo test --all-features— 112 okcargo llvm-cov --all-features --workspace --fail-under-lines 90— 92.24%worker.rsitself goes 85.84% → 94.69% lines, 100% function coverage. TheDebug-output assertion is there deliberately: extending an untestedDebugimpl otherwise pushes the file's own coverage down.Three new tests in
src/harness/observability/test.rs, all clock-independent, following the shape of the existingappend_worker_drops_and_counts_when_queue_is_full. Each was proven to fail against the pre-change behaviour before being kept:The third is the one that matters most — it pins that a degraded worker keeps trying, which is the behaviour that makes recovery possible at all.
Documentation
src/harness/observability/README.mdandsrc/graph/observability/README.md— the only two places in the tree claiming failures are "reported to stderr", which this change makes false. (graph'sJournalGraphSinkshares this sameAppendWorker.)mod.rs's "backend errors are reported, not propagated" andtypes.rs's pointer to the drop/error policy stay accurate and were left alone.# Error policysection of theworker.rsmodule docs is rewritten: tracing target, first-failure level, suppression and cooldown, recovery summary, lifetime counter.Related
Pre-existing and deliberately untouched, but worth naming since it is adjacent: if the tokio runtime fails to build, the drain thread runs
while rx.recv().is_ok() {}— silently draining and discarding everything, with no counter and no report. It does not even incrementappend_failures, so that failure mode is completely invisible. Happy to fix it here or in a follow-up, whichever you prefer.Context for why this was found: OpenCompany vendors tinyagents and hit the flood in a tenant container. Tracked there as
tinyhumansai/opencompany#450. That repo's fix is a submodule-pointer bump once this lands; the same flood persists at the openhuman and tinycortex pins until they bump too.Summary by CodeRabbit