Repository navigation
Bound the trace log's fault RATE, not its lifetime total — a spent budget silenced the wedge - #994
Merged
Merged
Conversation
…dget silenced the wedge /tmp/meshweaver-test-trace.log is the only diagnostic that survives a CI wedge: no .trx is written when a shard is killed at its wall-clock cap, ActivityLog nodes are not artifacts, and nothing captures ILogger. That sink capped fault records at 1000 per PROCESS. Two shard-3 processes hit the ceiling in every sampled run of #982's 17-run sample, and past it every later fault was dropped for the rest of the process — so in exactly the long, busy processes where a wedge is most likely, the fault firing next to the wedge had already been discarded. The cap was measuring the wrong quantity. The hazard it exists for is a STORM (a resubscribe loop logging per iteration, filling the runner's disk — the 2026-07 colima ENOSPC failure mode), and a storm is a property of the write RATE. Bounding the lifetime TOTAL bounds a different thing and buys the disk protection by permanently silencing the sink. So the budget now refills: 100 fault records per 10s window (FaultRecordBudget), after which an earlier storm can never silence a later fault. Sized from the #982 measurement rather than guessed — a healthy shard process emits ~1500 records over a <=20-minute shard, order 1.3/s, so 10/s is ~7x headroom and a healthy run never suppresses, while a storm of thousands/s is clamped. The artifact cost is then bounded by wall clock instead of an arbitrary total: ~1.8 MB/min against a shard's own 20-minute cap, so ~36 MB uncompressed worst case, a few MB in the artifact at compression-level 9. Truncation is no longer something a reader can miss. Entering suppression emits one [FAULT-BUDGET] notice per window carrying the running suppressed count, and the first record written after a suppressed stretch names exactly how many were lost in the gap; both say "this log is NOT a complete record of faults". A process killed mid-storm therefore leaves a notice near the tail rather than an unremarkable silence, and `grep FAULT-BUDGET` answers "is this file complete?" over any collected log. Not a ring buffer keeping first-N + last-N: retaining the tail means holding it in memory and flushing at the end, and this sink exists precisely for the case where there is no end. A host killed by `timeout` or a signal never flushes, so every record must reach disk eagerly. The budget is process-static, deliberately, against the no-static-state rule: the sink IS a per-process artifact and its writers (fixture construction, teardown, continuations on background schedulers) belong to no mesh and outlive every mesh in the process. A mesh-scoped budget would reset per test class and so would not bound a storm spanning classes. It needs no Clear()-for-isolation hook: tests drive the policy through their own FaultRecordBudget instances via the AppendFault(budget, now, ...) seam, never through the process one. Fixes #982 Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
…ep in the triage doc Three follow-ups on the fault-budget notice, all in service of the same property — a reader must be able to tell a truncated trace log from a complete one WITHOUT already knowing the sink's internals. * "budget of 1 fault records" read like a bug in the sink. Pluralise both counts. * Format the window with InvariantCulture: a diagnostic whose shape depends on the runner's locale is a diagnostic you cannot grep for. * DebuggingNativeCrashes.md is what a triager reads before opening a collected shard artifact, and it named _meshweaver-test-trace.log without saying the file can be partial. It now leads with `grep FAULT-BUDGET` — nothing back means every fault the process logged is in the file. Also disambiguates two <see cref="AppendFault"/> docs that CS0419 flagged once the budget overload existed. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Contributor
There was a problem hiding this comment.
Pull request overview
This PR addresses issue #982 by changing the CI-critical TestTraceLog fault sink from a lifetime-total cap to a refilling, rate-based budget so that late faults (especially near wedges/timeouts) are not permanently silenced after earlier high-volume periods.
Changes:
- Replace the “N faults per process” cap with a per-window, refilling
FaultRecordBudgetand emit explicit[FAULT-BUDGET]notices when suppression occurs/resumes. - Add targeted tests that pin both “suppression is visible” and “late faults still appear after earlier storms” behaviors.
- Update the native-crash triage documentation to instruct grepping for
[FAULT-BUDGET]markers before reasoning from absences.
Reviewed changes
Copilot reviewed 5 out of 5 changed files in this pull request and generated 2 comments.
Show a summary per file
| File | Description |
|---|---|
src/MeshWeaver.Fixture/TestTraceLog.cs |
Switches fault logging to a refilling, rate-based budget and emits [FAULT-BUDGET] notices. |
src/MeshWeaver.Fixture/FaultRecordBudget.cs |
Introduces the refilling window-budget policy and its notice/verbose semantics. |
test/MeshWeaver.Observability.Test/TestTraceLogFaultTest.cs |
Extends end-to-end tests to assert suppression announcements and late-fault survival in the shared trace log. |
test/MeshWeaver.Observability.Test/FaultRecordBudgetTest.cs |
Adds unit tests pinning the budget mechanics (suppression, notices, refill, clock rollback). |
src/MeshWeaver.Documentation/Data/Architecture/DebuggingNativeCrashes.md |
Documents how to detect whether the collected trace log is complete via grep FAULT-BUDGET. |
💡 Add a code-review agent skill or configure MCP servers for context-aware, tailored reviews. Learn more in the docs.
Contributor
Test Results (shard 3) 11 files ± 0 11 suites ±0 5m 24s ⏱️ -1s Results for commit c5421fd. ± Comparison against base commit 4ec0847. This pull request removes 457 and adds 498 tests. Note that renamed tests count towards both.This pull request removes 3 skipped tests and adds 2 skipped tests. Note that renamed tests count towards both.♻️ This comment has been updated with latest results. |
Contributor
Contributor
Contributor
Test Results (shard 4)1 216 tests - 3 1 208 ✅ - 4 6m 52s ⏱️ +26s Results for commit c5421fd. ± Comparison against base commit 4ec0847. This pull request removes 508 and adds 505 tests. Note that renamed tests count towards both.This pull request removes 2 skipped tests and adds 3 skipped tests. Note that renamed tests count towards both.♻️ This comment has been updated with latest results. |
Contributor
Contributor
Contributor
Test Results 65 files ± 0 65 suites ±0 36m 6s ⏱️ -57s Results for commit c5421fd. ± Comparison against base commit 4ec0847. This pull request removes 22 and adds 60 tests. Note that renamed tests count towards both.♻️ This comment has been updated with latest results. |
Copilot review on #994, both findings real. The notice and the fault record went out as two Append calls. Append takes and releases the file lock per call, and every test host in a shard writes to this one file, so another writer could land between them — stranding a "resuming after suppressing N" line from the record that resumed. That is the exact ambiguity this change exists to remove, so the two lines now go out as a single Append and cannot be split. The end-to-end suppression test also asserted only the generic [FAULT-BUDGET] tag in the tail slice, which a notice from any other writer in the shared file could have satisfied. It now asserts this test's distinctive bound ("1 fault record per 300s"), tying the assertion to its own budget instance. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
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
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.
Fixes #982
The defect
/tmp/meshweaver-test-trace.logis the only diagnostic that reaches CI after a wedge — no.trxis written when a shard is killed at its wall-clock cap, ActivityLog nodes are not artifacts, and nothing capturesILogger. That sink capped fault records at 1000 per process. Two shard-3 processes hit the ceiling in every sampled run of #982's 17-run sample, and past it every later fault was dropped for the rest of the process.So the sink was at its least useful exactly where a wedge is most likely: in a long, busy process, the fault firing next to the wedge had already been discarded before the wedge happened.
Why the cap was the wrong shape, not merely the wrong number
The hazard the cap exists for is a storm — a resubscribe loop logging a fault per iteration, writing until the runner's disk fills (the 2026-07 colima ENOSPC failure mode). A storm is a property of the write rate. The cap bounded the lifetime total, which is a different quantity, and bought the disk protection by permanently silencing the sink. Raising 1000 to 10000 would have moved the ceiling without changing that; it would still be a lifetime total, still spent, still silent afterwards.
The new bound, and what it costs
FaultRecordBudget— 100 fault records per 10-second window, refilling.Sized from the #982 measurement rather than guessed: a healthy shard process emits ~1500 fault records across a ≤20-minute shard, order 1.3/s. The budget is 10/s, ~7× that, so a healthy run never suppresses anything. A genuine storm (thousands/s) is clamped to 10/s.
What is still dropped: the 101st and later fault within any single 10-second window. In practice that means a storm loses repeats of the record it is already storming with — and only for as long as it storms.
What it never drops: a fault after a quiet stretch. The window refills, so an earlier storm cannot silence a later record. That is the #982 property.
Artifact cost is now bounded by wall clock instead of an arbitrary total: 10 records/s × ~3 KB ≈ 1.8 MB/min, and a shard's own 20-minute cap (its projects run sequentially in one loop) puts the ceiling near 36 MB uncompressed — a few MB in the artifact at the workflow's
compression-level: 9. The old cap's ceiling was ~2.5 MB, so this trades a few MB of artifact for never losing the tail.A truncated log can no longer be mistaken for a complete one
Two
[FAULT-BUDGET]lines, both in the same file, written through the sameAppend:grep FAULT-BUDGET collected-logs/_meshweaver-test-trace.log. Nothing back ⇒ the file is complete.DebuggingNativeCrashes.md— what a triager reads before opening a collected shard artifact — now leads with that grep. It previously named the trace log without saying it could be partial.Why not first-N + last-N
Keeping the tail means buffering it in memory and flushing at the end, and this sink exists precisely for the case where there is no end: a host killed by
timeout(exit=124) or dying on a signal never runs a flush. Anything not already on disk is gone. A ring buffer would trade away the one property that makes this file the only diagnostic CI keeps.Static state
The budget is process-static, deliberately, against the no-static-state rule. This sink is a per-process artifact (CI collects one file per runner), and its writers — fixture construction, teardown, and reactive continuations on background schedulers — belong to no mesh and outlive every mesh in the process. A mesh-scoped budget would reset on each test class and so would not bound a storm spanning classes, which is the hazard. It needs no
Clear()-for-isolation hook: tests drive the policy through their ownFaultRecordBudgetinstances via theAppendFault(budget, now, …)seam, never through the process one. No static collection is introduced — the state is scalar counters on one instance.Verification
The CI collection step (
dotnet-test.yml:588-589) is a plain whole-filecpintocollected-logs/_meshweaver-test-trace.log, uploadedif: always()— no trimming, no line limits — so the marker rides the exact same path as[FAULT]records, which #982 already verified empirically (102/102 shard artifacts carried it).The pins were checked against both old behaviours by mutation, not assumed:
ALateFaultAfterAnEarlierStorm_IsStillWrittenand the end-to-endAFaultAfterAnEarlierStorm_StillReachesTheCollectedTraceFileASuppressedFault_IsAnnouncedInTheCollectedTraceFileMeshWeaver.Observability.Test: 67/67 green.src/MeshWeaver.Fixtureand the test project both build clean under-c Release -p:CIRun=true -warnaserror.No What's New entry
Test/CI diagnostic infrastructure with no user-visible effect — skipped deliberately.
🤖 Generated with Claude Code