fix(runtime): bound TCP accept failures under file-descriptor pressure - #12282
fix(runtime): bound TCP accept failures under file-descriptor pressure#12282MatejKosec wants to merge 2 commits into
Conversation
The TCP response server retried `listener.accept()` immediately after any error. Once the process hit its file-descriptor ceiling (`EMFILE`/`ENFILE`) that became a busy loop: `accept()` fails deterministically while the table is full, so the loop spun at microsecond cadence, accepted nothing, and wrote the same warning line on every iteration. The error arm also logged twice -- `tracing::warn!` plus an unconditional `eprintln!` -- so rate-limiting only the tracing sink would have left half the flood in place. Introduce `AcceptBackoff`, a private, pure, synchronous policy: it classifies an `accept()` error via `raw_os_error()`, computes a bounded exponential delay (5ms doubling to a 1s ceiling), decides whether a summary is due against a caller-supplied `Instant`, and resets on a successful accept. It reads no clock, performs no I/O and never sleeps -- the caller does both -- which is what lets the retry schedule and the log-rate decision be tested without reproducing the host's file-descriptor limit. Only exhaustion errors take the new path. Every other accept error keeps the pre-existing warn-and-retry-immediately behavior, so genuinely unexpected failures are neither hidden nor slowed. The `eprintln!` is now gated behind `#[cfg(debug_assertions)]`, matching its sibling in `handle_connection`. Operator visibility: at most one structured summary per 5s carrying the error, the current delay and the number of failures suppressed since the last emission, one line on recovery, and a new `dynamo_transport_tcp_accept_backoff_total` counter registered in `ensure_transport_metrics_registered_prometheus`. Adds five tests: bounded growth-and-saturation, reset after recovery, rate-limited logging against an injected clock, a deterministic socket recovery test using an injected `EMFILE` (no host FD limit is touched), and a negative control proving `ConnectionAborted` stays on the ordinary path with no delay and no perturbation of the backoff schedule. Follow-up to ai-dynamo#11801; complementary to the RLIMIT_NOFILE change in ai-dynamo#11802, which raises the ceiling but does not alter accept-loop behavior at it. Closes ai-dynamo#11822 Signed-off-by: svc-glamr@nvidia.com <svc-glamr@nvidia.com>
GitHub Actions
Inactive
GitHub Actions
Inactive
|
👋 Hi MatejKosec! Thank you for contributing to ai-dynamo/dynamo. Just a reminder: The 🚀 |
github-actions
Bot
added
external-contribution
![devin-ai-integration[bot]](https://avatars.githubusercontent.com/in/811515?s=60&v=4){kind=small}
WalkthroughChangesTCP accept backoff
Estimated code review effort: 4 (Complex) | ~45 minutes 🚥 Pre-merge checks | ✅ 5✅ Passed checks (5 passed)
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: 3
🧹 Nitpick comments (1)
lib/runtime/src/pipeline/network/tcp/server.rs (1)
2344-2346: 📐 Maintainability & Code Quality | 🔵 Trivial | 💤 Low valueThese two tests don't need the
unixgate.
accept_backoff_delay_grows_and_saturatesandaccept_backoff_rate_limits_summary_and_reports_suppressed_countexercise only the clock-free policy — nolibc, noemfile_error. Dropping#[cfg(unix)]keeps the schedule/rate-limit coverage on non-unix targets. Theclassify-based andemfile_error-based tests legitimately stay gated.Also applies to: 2423-2425
🤖 Prompt for 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. In `@lib/runtime/src/pipeline/network/tcp/server.rs` around lines 2344 - 2346, Remove the #[cfg(unix)] attributes from accept_backoff_delay_grows_and_saturates and accept_backoff_rate_limits_summary_and_reports_suppressed_count so these clock-free policy tests run on all targets. Leave the classify- and emfile_error-based tests’ Unix gates unchanged.
🤖 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 `@lib/runtime/src/metrics/transport_metrics.rs`:
- Around line 42-45: Update the doc comments for the accept-backoff metric in
lib/runtime/src/metrics/transport_metrics.rs lines 42-45 and
lib/runtime/src/metrics/prometheus_names.rs lines 739-740 to describe one
increment per EMFILE/ENFILE accept failure that triggers a backoff sleep, rather
than per entry into a backoff episode; leave the metric implementation and help
text unchanged.
In `@lib/runtime/src/pipeline/network/tcp/server.rs`:
- Around line 2495-2501: Remove the wall-clock assertion comparing
started.elapsed() with next_if_untouched from the test, since slept ==
Duration::ZERO already verifies no backoff delay. Also remove the now-unused
started binding and any related timing setup, leaving the existing zero-duration
assertion intact.
- Around line 749-754: Update the recovery path around
accept_backoff.record_success() so the tcp recovery warning uses the same
5-second rate-limit window as the failure warning. Pass the required rate-limit
argument at both production and test record_success() call sites, while
preserving suppressed_failures reporting and recovery behavior.
---
Nitpick comments:
In `@lib/runtime/src/pipeline/network/tcp/server.rs`:
- Around line 2344-2346: Remove the #[cfg(unix)] attributes from
accept_backoff_delay_grows_and_saturates and
accept_backoff_rate_limits_summary_and_reports_suppressed_count so these
clock-free policy tests run on all targets. Leave the classify- and
emfile_error-based tests’ Unix gates unchanged.
🪄 Autofix (Beta)
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: Path: .coderabbit.yaml
Review profile: CHILL
Plan: Enterprise
Run ID: c65ed9f4-4226-4465-9ea6-19cdf0113734
📒 Files selected for processing (3)
lib/runtime/src/metrics/prometheus_names.rslib/runtime/src/metrics/transport_metrics.rslib/runtime/src/pipeline/network/tcp/server.rs
![dynamo-review-agent[bot]](https://avatars.githubusercontent.com/u/201626793?s=60&v=4){kind=small}
|
All three CodeRabbit findings are valid. I verified each against the code rather than 1. Recovery log is unbounded ( 2. Metric doc comments are wrong — real. 3. Timing assertion can flake — real. Also adds Not compiled locally (this workspace is not built on my machine); CI is the verification. Patch (3 files, +87/-19)diff --git a/lib/runtime/src/metrics/prometheus_names.rs b/lib/runtime/src/metrics/prometheus_names.rs
index 5cf591dc05..5fdab3edbb 100644
--- a/lib/runtime/src/metrics/prometheus_names.rs
+++ b/lib/runtime/src/metrics/prometheus_names.rs
@@ -736,7 +736,8 @@ pub mod transport {
pub const BYTES_RECEIVED_TOTAL: &str = "tcp_bytes_received_total";
pub const ERRORS_TOTAL: &str = "tcp_errors_total";
pub const SERVER_QUEUE_DEPTH: &str = "tcp_server_queue_depth";
- /// Times the response-server accept loop entered file-descriptor-exhaustion backoff
+ /// Response-server accept failures that triggered a file-descriptor-exhaustion
+ /// backoff sleep; counts per failed accept, not per backoff episode
pub const ACCEPT_BACKOFF_TOTAL: &str = "tcp_accept_backoff_total";
}
pub mod nats {
diff --git a/lib/runtime/src/metrics/transport_metrics.rs b/lib/runtime/src/metrics/transport_metrics.rs
index 6de997c661..591653f154 100644
--- a/lib/runtime/src/metrics/transport_metrics.rs
+++ b/lib/runtime/src/metrics/transport_metrics.rs
@@ -39,10 +39,11 @@ pub static TCP_ERRORS_TOTAL: Lazy<Counter> = Lazy::new(|| {
.expect("tcp_errors_total counter")
});
-/// Incremented once per transition into the accept-loop backoff state, i.e. each time
-/// `listener.accept()` fails with `EMFILE`/`ENFILE` while the process is at its
-/// file-descriptor ceiling. Alertable signal for the condition described in
-/// <https://github.com/ai-dynamo/dynamo/issues/11822>.
+/// Incremented once per `listener.accept()` failure with `EMFILE`/`ENFILE` — that is,
+/// per failed accept while the process is at its file-descriptor ceiling, not once per
+/// backoff episode. A single episode of exhaustion therefore advances this counter many
+/// times, which is what makes it usable as a rate. Alertable signal for the condition
+/// described in <https://github.com/ai-dynamo/dynamo/issues/11822>.
pub static TCP_ACCEPT_BACKOFF_TOTAL: Lazy<Counter> = Lazy::new(|| {
Counter::new(
transport_metric_name(transport::tcp::ACCEPT_BACKOFF_TOTAL),
diff --git a/lib/runtime/src/pipeline/network/tcp/server.rs b/lib/runtime/src/pipeline/network/tcp/server.rs
index f15d6eaa0b..f912779be4 100644
--- a/lib/runtime/src/pipeline/network/tcp/server.rs
+++ b/lib/runtime/src/pipeline/network/tcp/server.rs
@@ -659,14 +659,33 @@ impl AcceptBackoff {
}
/// Record a successful accept. Returns `Some(suppressed)` when this success
- /// ended an exhaustion episode, so the caller can note the recovery once;
- /// `None` during ordinary steady-state accepts.
- fn record_success(&mut self) -> Option<u64> {
+ /// ended an exhaustion episode *and* the same rate-limit window that governs
+ /// the failure warning allows another line; `None` during ordinary
+ /// steady-state accepts, and `None` when a recovery line was emitted too
+ /// recently.
+ ///
+ /// The window matters because at the descriptor ceiling the loop does not
+ /// fail in one long run — it alternates failure, success, failure as
+ /// descriptors are freed and immediately reclaimed. Every one of those
+ /// successes ends an episode, so an unthrottled recovery log would reinstate
+ /// the very storm the failure-side limit exists to bound.
+ fn record_success(&mut self, now: std::time::Instant) -> Option<u64> {
self.current_delay = self.initial_delay;
if !self.in_backoff {
return None;
}
self.in_backoff = false;
+
+ let due = match self.last_log_at {
+ None => true,
+ Some(prev) => now.saturating_duration_since(prev) >= self.log_interval,
+ };
+ if !due {
+ // Keep the tally rolling into the next line that does get emitted
+ // rather than discarding it.
+ return None;
+ }
+ self.last_log_at = Some(now);
Some(std::mem::take(&mut self.suppressed))
}
}
@@ -746,7 +765,8 @@ async fn tcp_listener(
// todo - add counter for outgoing bytes
let (stream, _addr) = match listener.accept().await {
Ok((stream, _addr)) => {
- if let Some(suppressed) = accept_backoff.record_success() {
+ let now = std::time::Instant::now();
+ if let Some(suppressed) = accept_backoff.record_success(now) {
tracing::warn!(
suppressed_failures = suppressed,
"tcp accept recovered from file-descriptor exhaustion"
@@ -2407,7 +2427,7 @@ mod tests {
"precondition: delay should have grown, {grown:?} vs {first:?}"
);
- backoff.record_success();
+ backoff.record_success(now);
let after_recovery = backoff.record_exhaustion(now).delay;
assert_eq!(
@@ -2416,6 +2436,55 @@ mod tests {
);
}
+ /// Recovery lines obey the same rate-limit window as failure lines. At the
+ /// descriptor ceiling the loop alternates failure and success as descriptors
+ /// are freed and immediately reclaimed, so every success ends an episode; an
+ /// unthrottled recovery log would reinstate the storm the failure-side limit
+ /// exists to bound. Deleting the window check makes the second assertion fail.
+ #[cfg(unix)]
+ #[test]
+ fn accept_backoff_rate_limits_recovery_notice() {
+ let mut backoff = AcceptBackoff::default();
+ let t0 = std::time::Instant::now();
+
+ // One failure opens the episode and claims this interval's single line.
+ assert_eq!(
+ backoff.record_exhaustion(t0).log_suppressed,
+ Some(0),
+ "precondition: the first failure emits and claims the window"
+ );
+
+ // A success inside that same window ends the episode but stays silent.
+ assert_eq!(
+ backoff.record_success(t0),
+ None,
+ "a recovery inside the log window must not emit"
+ );
+ // The schedule still reset, silence notwithstanding.
+ assert_eq!(
+ backoff.record_exhaustion(t0).delay,
+ ACCEPT_BACKOFF_INITIAL_DELAY,
+ "recovery must reset the schedule whether or not it logged"
+ );
+
+ // Once the window elapses a recovery is authorized again, and carries
+ // the failures suppressed behind it rather than discarding them.
+ let t1 = t0 + ACCEPT_BACKOFF_LOG_INTERVAL + Duration::from_millis(1);
+ assert_eq!(
+ backoff.record_success(t1),
+ Some(1),
+ "a recovery after the window elapses must emit and report suppressions"
+ );
+
+ // A success outside an episode never emits, window or not.
+ let t2 = t1 + ACCEPT_BACKOFF_LOG_INTERVAL + Duration::from_millis(1);
+ assert_eq!(
+ backoff.record_success(t2),
+ None,
+ "steady-state accepts must never emit a recovery line"
+ );
+ }
+
/// The summary is rate-limited against a caller-supplied clock: exactly one
/// emission per interval, carrying the count of failures suppressed since
/// the previous one, and a fresh emission once the interval elapses.
@@ -2485,20 +2554,17 @@ mod tests {
backoff.record_exhaustion(now);
// An ordinary error in the middle of an episode sleeps for nothing...
- let started = std::time::Instant::now();
+ // `handle_accept_error` returns the duration it actually slept, so that
+ // return value is the whole property; a wall-clock bound on the
+ // surrounding call would only add flakiness, because the measured path
+ // also emits a `tracing::warn!` and, under `debug_assertions`, an
+ // `eprintln!`.
let slept = handle_accept_error(&ordinary, &mut backoff).await;
assert_eq!(
slept,
Duration::ZERO,
"ordinary accept errors must retry immediately"
);
- // Had it been routed through the backoff path it would have slept for
- // the schedule's current delay; anything below that proves it did not.
- assert!(
- started.elapsed() < next_if_untouched,
- "ordinary accept errors must not sleep at all, slept {:?}",
- started.elapsed()
- );
// ...and leaves the exhaustion schedule exactly where it was: the next
// exhaustion failure continues the sequence rather than restarting it.
@@ -2561,7 +2627,7 @@ mod tests {
drop(accepted);
// Recovery resets the schedule, as the loop's Ok(..) arm does.
- backoff.record_success();
+ backoff.record_success(std::time::Instant::now());
assert_eq!(
backoff.record_exhaustion(std::time::Instant::now()).delay,
ACCEPT_BACKOFF_INITIAL_DELAY, |
…ic docs Addresses the three review findings on ai-dynamo#12282. Recovery warning is now rate-limited. `AcceptBackoff::record_success` takes the caller's clock and gates its `Some(suppressed)` return on the same `log_interval` window that `record_exhaustion` already uses. Under sustained descriptor pressure the loop alternates success -> EMFILE -> success, so every accepted connection ended an episode and emitted an unthrottled `warn!` while the failure side was capped at one per 5s -- reinstating the log storm this policy exists to bound. A withheld recovery keeps its suppressed count rather than discarding it, so the next emitted summary on either path still accounts for every failure observed. The schedule reset is unconditional, as before. Metric doc comments corrected. `TCP_ACCEPT_BACKOFF_TOTAL` is `.inc()`d per failed EMFILE/ENFILE accept, not once per backoff episode; both doc comments claimed the latter, so an alert written from them would under-estimate the rate. The counter implementation and its help text are unchanged. Dropped a flaky wall-clock assertion. The `started.elapsed() < next_if_untouched` upper bound in `accept_backoff_leaves_ordinary_errors_undelayed_and_stateless` measures a path that emits a `tracing::warn!` plus a debug-build `eprintln!`, so a loaded runner can exceed it. The `assert_eq!(slept, Duration::ZERO)` above already establishes the property. Adds `accept_backoff_rate_limits_recovery_notice`, which drives the success/EMFILE alternation and asserts silence inside the window plus a rolled-forward count after it. Verified non-tautological: deleting the window check from `record_success` makes it fail with Some(2) vs None. Builds on 211676f by @glamr-agent; history is not rewritten. Validation: cargo check -p dynamo-runtime --lib --all-targets (pass); cargo clippy -p dynamo-runtime --lib --all-targets -- -D warnings (clean); cargo test -p dynamo-runtime --lib accept_backoff (6 passed, 0 failed); cargo fmt and pre-commit on the changed files (clean). Signed-off-by: svc-glamr@nvidia.com <svc-glamr@nvidia.com> Signed-off-by: glamr-agent <svc-glamr@nvidia.com>
GitHub Actions
Inactive
Babysitter round 1 — all three review findings addressedPushed Note the prior comment on this PR parked a patch because it believed it could not push. That was wrong: the head branch lives on Findings addressed
The nitpick about Validation — run locally in this checkout, not delegated to CI:
The test scope is deliberately the Mutation-checked the new test rather than assuming it bites — deleting the window gate from Validation status: incomplete for merge, for reasons outside this branch. Every check on the previous head was already green; nothing was failing. Merge is still gated on a maintainer posting |
CI result — green on
|
|
@MatejKosec can we merge this? |
|
/ok-to-test 211676f |
@MatejKosec, there was an error processing your request: See the following link for more information: https://docs.gha-runners.nvidia.com/cpr/e/2/ |
|
Superseded by #13146. Closing this one. @zhongdaor-nv — answering your question: this PR could not be merged, and not because Since then #10921 rewrote this same accept loop to All review feedback from this thread carries over: the three CodeRabbit findings, and @richardhuo-nv — sorry to ask twice. Your approval here was against the pre-TLS loop, so The underlying bug is still live on |
4 participants
Overview:
The TCP response server retried
listener.accept()immediately after any error. Oncethe process reached its file-descriptor ceiling (
EMFILE/ENFILE), that became a busyloop:
accept()fails deterministically while the descriptor table is full, so the loopspun at microsecond cadence, accepted nothing, and wrote the same warning on every
iteration. The error arm also logged twice —
tracing::warn!plus an unconditionaleprintln!— so rate-limiting only the tracing sink would have left half the flood inplace.
This bounds the spin and the logging without changing behaviour for any other accept
error.
Details:
AcceptBackoffis a private, pure, synchronous policy inlib/runtime/src/pipeline/network/tcp/server.rs. It classifies anaccept()error viaraw_os_error(), computes a bounded exponential delay (5 ms doubling to a 1 s ceiling),decides whether a summary is due against a caller-supplied
Instant, and resets on asuccessful accept. It reads no clock, performs no I/O, and never sleeps — the caller does
both. That is what makes the retry schedule and the log-rate decision testable without
reproducing the host's file-descriptor limit.
Only exhaustion errors take the new path. Every other accept error keeps the pre-existing
warn-and-retry-immediately behaviour, so genuinely unexpected failures are neither hidden
nor slowed. The
eprintln!is now gated behind#[cfg(debug_assertions)], matching itssibling in
handle_connection.Operator visibility: at most one structured summary per 5 s, carrying the error, the
current delay, and the number of failures suppressed since the last emission; one line on
recovery; and a new
dynamo_transport_tcp_accept_backoff_totalcounter registered inensure_transport_metrics_registered_prometheus.Five new tests: bounded growth and saturation, reset after recovery, rate-limited logging
against an injected clock, a deterministic socket recovery test using an injected
EMFILE(no host FD limit is touched), and a negative control proving
ConnectionAbortedstays onthe ordinary path with no delay and no perturbation of the backoff schedule.
Complementary to the
RLIMIT_NOFILEchange in #11802, which raises the ceiling but doesnot alter accept-loop behaviour at it. Follow-up to #11801.
Where should the reviewer start?
lib/runtime/src/pipeline/network/tcp/server.rs(+412/−4) — theAcceptBackoffpolicy,its integration into the accept loop, and the five tests. The policy type and its
classification of
raw_os_error()are the parts worth the closest reading.lib/runtime/src/metrics/transport_metrics.rs(+13/−0) andlib/runtime/src/metrics/prometheus_names.rs(+2/−0) — registration and naming of thenew counter.
Two notes for the reviewer, both about what this PR does not do:
lib/runtime/src/pipeline/network/tcp/shared_tcp_endpoint.rs:389. It is deliberately outof scope here.
cargo test -p dynamo-runtime --librun does not complete on this branch, butthe cause is pre-existing and unrelated:
pipeline::network::egress::push_router::tests::transport_resolution_falls_back_when_selected_instance_disappearshangs, and it hangs identically on a clean
maincheckout with none of this changepresent.
Related Issues
🔗 This PR is linked to an issue:
Summary by CodeRabbit