fix(flowcontrol): add bounded request drop summaries#2132
Conversation
Signed-off-by: Ishwar <ishwarcm@iitbhilai.ac.in>
github-actions
Bot
added
size/L
LukeAVanDrie
left a comment
LukeAVanDrie
left a comment
There was a problem hiding this comment.
Thanks! This is almost ready, I just flagged some small edge cases in outcome accounting that should all be small fixes.
Non-blocking, but there is also no test for the sweep path (sweepFinalizedItems -> recordDrop), which is the main channel for TTL/cancellation drops.
We could also consider labeling by priority in the log summary (since this is cardinality bound). Per-flow is probably not worth it. Up to your discretion as I think it is already okay in its current state.
| // Finalize buffered items. | ||
| item.FinalizeWithOutcome(types.QueueOutcomeRejectedOther, | ||
| fmt.Errorf("%w: %w", types.ErrRejected, types.ErrFlowControllerNotRunning)) | ||
| p.recordDrop(types.QueueOutcomeRejectedOther) |
There was a problem hiding this comment.
Everything recorded here and in evictAll() is never flushed. The only flushDropSummary() call site is the sweep ticker, and runCleanupSweep exits on the same ctx.Done() that drives us into shutdown(). The shutdown evictions, plus anything accumulated since the last tick, are counted and then silently discarded.
We can add a final flush at the end of shutdownOnce.Do, after p.evictAll() returns (as the worker pool's wg.Wait() inside processAllQueuesConcurrently guarantees all recordDrop calls have landed by then):
p.evictAll()
p.flushDropSummary()There was a problem hiding this comment.
Done. Added a final flushDropSummary() after evictAll() in shutdown() so any outcomes accumulated since the last sweep (including shutdown evictions) are emitted before exit.
| // Finalization is idempotent; safe to call even if already finalized externally. | ||
| // The per-request log is emitted by EnqueueAndWait when it unblocks. | ||
| item.FinalizeWithOutcome(outcome, errShutdown) | ||
| p.recordDrop(outcome) |
There was a problem hiding this comment.
FinalizeWithOutcome is a sync.Once no-op when the item was already finalized externally, but this line unconditionally records the hardcoded EvictedOther. An item that actually finished as EvictedTTL or
EvictedContextCancelled (finalized by the controller but not yet swept when shutdown drains the queue) gets counted under the wrong bucket.
We can record the authoritative outcome instead (guaranteed non-nil after the finalize call):
| p.recordDrop(outcome) | |
| p.recordDrop(item.FinalState().Outcome) |
There was a problem hiding this comment.
Updated this to record item.FinalState().Outcome so externally finalized items retain their authoritative outcome instead of always being counted as EvictedOther.
| if finalState := outcome; finalState != nil { | ||
| p.logger.V(logutil.TRACE).Info("Item finalized externally before processing, discarding.", | ||
| "outcome", finalState.Outcome, "err", finalState.Err, "flowKey", key, "requestID", req.ID()) | ||
| return |
There was a problem hiding this comment.
Every terminal branch in enqueue() now records its drop except this early return for items finalized externally while buffered in enqueueChan. Those items never enter a queue, so the sweep can't count them either; they're absent from the summary entirely.
Maybe unlikely to trigger in practice, but we can harden against this by adding p.recordDrop(finalState.Outcome) to that branch.
You already guard against Dispatched/NotYetFinalized in recordDrop so this should be safe.
There was a problem hiding this comment.
Added p.recordDrop(finalState.Outcome) to this early-return path so externally finalized items contribute to the aggregate summary as well.
| return | ||
| case <-ticker.C(): | ||
| p.sweepFinalizedItems() | ||
| p.flushDropSummary() |
There was a problem hiding this comment.
note: this binds log frequency to the expiry cleanup interval (1s); that coupling seems reasonable to me and probably doesn't warrant an independent ticker
Signed-off-by: Ishwar <ishwarcm@iitbhilai.ac.in>
Added a test covering the sweep path by verifying that an externally finalized item increments the corresponding drop counter when swept. |
|
Once the linter issue is resolved, I can merge this |
Signed-off-by: Ishwar <ishwarcm@iitbhilai.ac.in>
Fixed. |
Still tripping; can you run go fmt? That seems to be the issue |
Signed-off-by: Ishwar <ishwarcm@iitbhilai.ac.in>
Head branch was pushed to by a user without write access
Ran |
What type of PR is this?
/kind cleanup
What this PR does / why we need it:
This PR addresses the logging improvements tracked in #2101 by:
V(DEFAULT)during processor cleanup sweeps while preserving per-request drop logs atV(VERBOSE)requestIDstoManagedQueuecleanup and drain debug logserrWhich issue(s) this PR fixes:
Fixes #2101
Release note: