Back-pressure observability: a latched listener says so, and block errors reach real logging - #3831
Merged
Merged
Conversation
…rors reach real logging Three hardenings from chasing a permanently-latched ingest listener (JasperFx/CritterWatch#922 — one 'too busy' line, no resume ever, queue to 288k): - BackPressureAgent logs a periodic warning (about once a minute) while a listener stays latched, carrying the QueueCount and restart threshold the resume decision reads. It used to log exactly one line at latch time and nothing ever again. - The timer-driven back-pressure check is now exception-safe: a throw from StartAsync during an attempted resume was an unobserved ValueTask fault — the listener simply never resumed with nothing in the logs. Now logged and retried on the next interval. - BufferedReceiver/DurableReceiver wire the receiving block's OnError to ILogger, and ShardedExecutionBlock propagates OnError to its slot blocks. The JasperFx default sink is stderr; a terminally-faulted block (#506) freezes QueueCount — which permanently latches a back-pressured listener — so it now logs at Critical. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_016v2Aijyo8MX2AdPUZL5VtG
…3832) CIRabbitMQ failed on this PR with Bug_189...be_able_to_start_up_with_large_number_of_messages_waiting_on_you — System.TimeoutException : The operation has timed out. The test has four separate problems, and together they explain both the failure and why it has never been diagnosable. 1. The retry passed vacuously. Bug189Handler keeps _source, _count and _expected as statics on a static class, and WaitForCompletion never reset them. Those survive for the life of the worker process, and the supervisor retries a failed test inside that same process, so attempt 2 got an already-completed TaskCompletionSource back and returned without receiving a single message. That is how this test reports "passed on attempt 2" on green main runs (e.g. run 30950507401) while re-verifying nothing. WaitForCompletion now resets the count and installs a fresh source, so a retry is a real retry. 2. A failed receiver startup was invisible. receiverTask is deliberately fire-and-forget -- StartAsync can block draining a full queue under ProcessInline -- but it was never observed at all, so a host that failed to start produced no error: the waiter simply ran out its 120 seconds and reported a bare TimeoutException with the real cause discarded, which is exactly the message CI produced. The two are now raced so a startup fault is rethrown as itself, and the task's exception is always observed. 3. _count++ on a volatile int is a read-modify-write, and five inline listeners run the handler concurrently, so increments were being lost. Now Interlocked.Increment. 4. Two threads could both clear the threshold and call SetResult, the second throwing InvalidOperationException from inside a message handler. Now TrySetResult. The timeout message also carries how many messages were actually handled, so the next failure distinguishes "nothing was consumed" from "consumption was slow". Note what this does not claim: locally the test finishes in ~830ms against a 120s budget and is green 5 of 5, so the CI timing failure is not reproducible here and is not asserted to be fixed. What changes is that the next failure will say how far it got instead of nothing at all. Full local Wolverine.RabbitMQ.Tests: 487 passed, Bug_189 among them. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01WHAuhdWS3XeAk16swV9G8m
This was referenced Aug 5, 2026
Merged
This was referenced Aug 5, 2026
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.
Companion to JasperFx/jasperfx#632, both from chasing JasperFx/CritterWatch#922: a console ingest listener latched off with one
too busylog line and never resumed, while the queue grew to 288k. #632 fixes theCountaccounting that the latch/resume decisions read forPartitionProcessingByGroupIdendpoints; this PR makes the whole mechanism observable so the next such failure diagnoses itself.BackPressureAgentlogs a periodic warning (~once a minute) while a listener stays latched, carrying theQueueCountand restart threshold the resume decision is made from. Today it logs exactly one line at latch time and then nothing forever — an operator watching a queue grow for 40 minutes cannot tell "still draining" from "wedged".TimerOnElapsedfiresCheckNowAsync()unawaited; a throw fromStartAsyncduring an attempted resume was an unobservedValueTaskfault — the listener simply never resumed, silently. Now logged and retried on the next 2s interval.BufferedReceiver/DurableReceiverwire the receiving block'sOnErrortoILogger, andShardedExecutionBlockpropagatesOnErrorto its slot blocks. The JasperFxBlockdefault error sink is stderr; a terminally-faulted block (FluentValidation and Middleware ordering #506) freezesQueueCount, which permanently latches a back-pressured listener — that now logs at Critical instead of vanishing.Tests
New
warns_periodically_while_latched_and_not_draining(cadence, reset-on-recovery); existingBackPressureAgentTestsupdated for the logger parameter. CoreTests 2247/2247 on net9.0 + net10.0.🤖 Generated with Claude Code
https://claude.ai/code/session_016v2Aijyo8MX2AdPUZL5VtG