diff --git a/docs/adr/ADR-0012-unresolved-verification-retry-backoff.md b/docs/adr/ADR-0012-unresolved-verification-retry-backoff.md new file mode 100644 index 00000000..5e210b48 --- /dev/null +++ b/docs/adr/ADR-0012-unresolved-verification-retry-backoff.md @@ -0,0 +1,175 @@ +# ADR-0012: Back off and report once when a verification round finds no holder + +- **Status:** Proposed +- **Date:** 2026-08-24 +- **Decision owners:** chrisoneil +- **Reviewers:** TBD +- **Supersedes:** none +- **Superseded by:** none +- **Related:** ADR-0005 (replication repair hardening — owns the verification/fetch pipeline this changes); ADR-0011 (capacity-gated source discovery — adds the flat write-blocked deferral this change deliberately keeps flat). V2-1049 is the issue, V2-1062 tracks the cause, and [saorsa-core #152](https://github.com/WithAutonomi/saorsa-core/pull/152) characterises it. + +## Context + +A pending key whose presence probe finds no holder is put back with +`defer_pending(key, verification_request_timeout)` — a flat 15 seconds — and a +`warn!` is emitted every time. Neither the retry nor the log has any notion of +how many times this key has already failed. + +On the beta cohort this produced **1,153,502 log lines from 2,072 distinct keys +on a single node in ten hours — 557 lines per key**, 98.8% of every WARN the +whole cohort emitted in 24 hours. `PENDING_VERIFY_MAX_AGE` does not bound it: +`evict_stale` drops the entry at 30 minutes, a neighbour re-hints the key +minutes later, it is re-admitted with a fresh `created_at`, and the cycle +restarts. One sampled key ran through fifteen such 30-minute residencies. + +The keys were not a backlog being worked through. They were the same keys, +re-asked of the same peers, receiving the same answer. The node was a first +start, and per saorsa-core #152 a node whose routing table has not converged +"cannot name anyone closer to a distant key than itself, so every consumer +asking *am I among the `w` closest to this key* gets yes for most of the +keyspace". Replaying `is_responsible` against that node's reconstructed routing +table shows it claimed ~1,451 of those keys at bootstrap and only **98** once +the table converged: roughly 95% of the storm was work it should never have +taken on. + +This ADR does not address that cause — see V2-883, whose cold-start half is +still open. It addresses the fact that the symptom is unbounded: the retry and +the log both cost the same on the five-hundredth failure as on the first, and +the log volume masked every other signal in the beta soak. + +## Decision Drivers + +- A retry whose question has not changed will not get a new answer; paying a + verification round trip per key every 15 seconds buys nothing. +- At 2,071 stuck keys the node pushed ~14,500 key references per round to 7 + peers every ~16 seconds. This is responder load on the close group, not only + local noise. +- The first failure for a key is genuine operational information and must not be + suppressed. The five-hundredth is not. +- Whatever the underlying cause, the observable cost of it should be + proportionate to the number of *affected keys*, not to how long the condition + persists. + +## Considered Options + +1. **Leave the cadence, rate-limit the log only.** Fixes the log volume, leaves + the redundant probe traffic. +2. **Raise `VERIFICATION_REQUEST_TIMEOUT`.** One constant, but it is the + per-batch request timeout for every verification round, including rounds that + succeed. It would slow first-attempt discovery for every key to fix a + repeated-failure case. +3. **Drop the key after N failures.** Cheapest, but a key legitimately awaiting a + holder that has not yet come online would be abandoned; the condition is + frequently transient during a node's first hours. +4. **Exponential backoff per entry, plus warn once per entry.** Keeps retrying + indefinitely, but at a cost that decays. + +## Decision + +We will take option 4. + +`VerificationEntry` gains `unresolved_retries`, and deferral splits into two +methods that mean different things: + +- `defer_pending(key, retry_after)` keeps today's flat behaviour, for deferrals + that are **not** a failed round — the write-blocked capacity gate of ADR-0011 + defers without asking anyone, so nothing was learned about the key and neither + the backoff nor the first-failure warning should be consumed. That ADR states + the gate is "applied flat, through the ordinary `defer_pending`"; keeping the + two methods distinct is what preserves that. +- `defer_unresolved(key, base_retry_after)` is the failed-round path. It + increments the counter and returns `DeferralOutcome { attempt, retry_after }`, + where `retry_after` doubles from the base and saturates at a new + `VERIFICATION_RETRY_BACKOFF_MAX` of **5 minutes**, never falling below the + base. + +Both no-holder sites and the inconclusive-quorum deferral use +`defer_unresolved`. + +Reporting is tracked **separately** from the count, by a `no_holder_reported` +flag claimed through `claim_no_holder_report` at the two no-holder sites. The +two answer different questions. The counter asks "how many consecutive rounds +failed", which an inconclusive quorum legitimately advances. The flag asks "have +we told anyone", which only a no-holder result may consume. Deriving the second +from `attempt == 1` would lose the first — and only — warning for any key whose +opening round is inconclusive, which is the common case: a key entering +`PaidForList` after its first quorum round takes the local-paid fast path on the +next cycle. + +A round that *does* find a holder clears both, via `clear_unresolved`. The +round succeeded even where a full fetch queue leaves the key pending, so it must +not inherit the earlier backoff, and a later relapse deserves a fresh warning. +Eviction and re-admission likewise start a fresh episode, so "once per episode" +is literal rather than approximate. + +The per-cycle count is added to the verification cycle summary as `no_holders=`, +so the scale of a backlog stays visible without a line per key per retry. + +## Consequences + +### Positive + +- Inside one 30-minute residency a stuck key is probed roughly **10 times + instead of roughly 110**, cutting both redundant verification traffic and the + responder load it imposes on the close group. +- Per-key WARN volume for a storm of this shape drops from ~557 lines per key to + **1 per episode**. +- The retry is still unbounded, so a holder that appears late is still found. + +### Negative / Trade-offs + +- Worst-case delay in noticing that a holder *has* appeared rises from 15 + seconds to the 5-minute cap. Acceptable: this path is background replica + repair, not a read path, and the key is re-hinted by neighbour sync every + 10–20 minutes regardless. +- The two no-holder messages are unified on the wording + `has no responding holders yet`; the network-verification site previously read + `has no holders yet`. Any saved query matching the old string needs updating. +- A key that oscillates between resolvable and unresolvable warns once per + oscillation rather than once ever. This is deliberate — silence after the + first-ever report would hide a recurrence — but it means the log is not + strictly one line per key. + +### Neutral / Operational + +- `no_holders=` appears in both verification cycle summaries: at `info` when the + cycle exceeds `VERIFICATION_CYCLE_SLOW_LOG_MS`, and at `debug` otherwise. Beta + ships at `info`, so in practice the operational signal is the slow-cycle one — + which is when a backlog is most likely present, but is therefore not a + continuous gauge. If a continuous signal is wanted it belongs in the periodic + replication summary. +- `VerificationEntry` is `pub` with `pub` fields and no `#[non_exhaustive]`, so + the two new fields break downstream struct literals. Nothing outside this + repository is known to construct one, but the PR is marked breaking on that + basis. Adding `#[non_exhaustive]` would stop this recurring; it is itself a + breaking change and so belongs with a deliberate bump, not this one. +- Beta ships at `info`, so the `debug!` follow-ups are dropped at ingest and do + not reach Elasticsearch. + +## Validation + +- Unit tests cover the doubling sequence, saturation at the cap across 64 + further attempts, the `None` result for an unknown key, backoff restart after + eviction and re-admission, and that a base above the cap is never shortened. +- Three tests pin the separations this decision rests on: a non-reporting round + (inconclusive quorum) advances the count without consuming the warning; a flat + `defer_pending` does neither; and a duplicate hint merges into the live entry + rather than replacing it, so it restarts neither the backoff nor the retry + time. The last of these guards a silent revert — a refactor that replaced + instead of merging would undo the fix with every other test still green. +- `VERIFICATION_RETRY_BACKOFF_MAX` is pinned in `config.rs` beside + `CAPACITY_BLOCKED_RETRY`: above the request timeout, and far enough below + `PENDING_VERIFY_MAX_AGE` that a capped retry still gets several looks per + episode. +- The beta cohort is the live check: the next first-start node should produce on + the order of one WARN per affected key per episode instead of hundreds, and + `no_holders=` in the cycle summary should show the affected-key count directly. +- This decision should be revisited if V2-883's cold-start half lands, since a + node that stops over-claiming should rarely reach these sites at all. The + backoff remains correct either way; the log-once rule may then be more + conservative than necessary. + +## Notes for AI-assisted work + +Drafted with AI assistance from the V2-1049 investigation. Not to be marked +Accepted without human review. diff --git a/src/replication/bootstrap.rs b/src/replication/bootstrap.rs index ea2f9f04..764846f6 100644 --- a/src/replication/bootstrap.rs +++ b/src/replication/bootstrap.rs @@ -339,6 +339,8 @@ mod tests { replica_hint_sources: HashSet::from([saorsa_core::identity::PeerId::from_bytes( [0u8; 32], )]), + unresolved_retries: 0, + no_holder_reported: false, }; queues.add_pending_verify(xor_name_from_byte(0x01), entry); diff --git a/src/replication/config.rs b/src/replication/config.rs index 66c8e0bd..88146000 100644 --- a/src/replication/config.rs +++ b/src/replication/config.rs @@ -593,6 +593,26 @@ const VERIFICATION_REQUEST_TIMEOUT_SECS: u64 = 15; pub const VERIFICATION_REQUEST_TIMEOUT: Duration = Duration::from_secs(VERIFICATION_REQUEST_TIMEOUT_SECS); +/// Ceiling on the exponential backoff applied to a pending key that keeps +/// failing to resolve. +/// +/// [`VERIFICATION_REQUEST_TIMEOUT`] is the *first* retry delay, not a flat +/// cadence. A key whose presence probe finds no holder is almost always in that +/// state because the answer has not changed — a new node that claims a slice of +/// the keyspace its routing table cannot yet resolve keeps asking the same peers +/// the same question. Re-asking every 15 seconds costs a verification round trip +/// per key per retry and produces one log line each time, for no new +/// information. +/// +/// Doubling from 15s and capping here gives roughly ten attempts inside one +/// [`PENDING_VERIFY_MAX_AGE`] residency instead of roughly a hundred and ten, +/// while bounding the worst-case delay in noticing that a holder *has* appeared +/// to this value. +const VERIFICATION_RETRY_BACKOFF_MAX_SECS: u64 = 5 * 60; +/// Ceiling on the exponential backoff applied to an unresolved pending key. +pub const VERIFICATION_RETRY_BACKOFF_MAX: Duration = + Duration::from_secs(VERIFICATION_RETRY_BACKOFF_MAX_SECS); + /// Maximum ready hints processed by one verification cycle. /// /// The pending queue may be much larger. Each cycle takes a sender-fair bounded @@ -1866,4 +1886,20 @@ mod tests { "a deferral at or past the entry lifetime is an eviction, not a deferral" ); } + + /// The backoff ceiling sits in the same band, and for the same reasons: far + /// enough above the request timeout to actually cut the repeat cost, far + /// enough below the entry lifetime that a capped retry still gets several + /// looks before stale eviction ends the episode. + #[test] + fn verification_retry_backoff_max_is_between_the_request_timeout_and_the_entry_lifetime() { + assert!( + VERIFICATION_RETRY_BACKOFF_MAX > VERIFICATION_REQUEST_TIMEOUT, + "a ceiling at or below the base delay is not a backoff" + ); + assert!( + VERIFICATION_RETRY_BACKOFF_MAX * 4 <= PENDING_VERIFY_MAX_AGE, + "a capped retry must still get several looks inside one entry lifetime" + ); + } } diff --git a/src/replication/mod.rs b/src/replication/mod.rs index 0b25e38c..edd6f1a9 100644 --- a/src/replication/mod.rs +++ b/src/replication/mod.rs @@ -91,7 +91,7 @@ use crate::replication::protocol::{ }; use crate::replication::quorum::KeyVerificationOutcome; use crate::replication::recent_provers::RecentProvers; -use crate::replication::scheduling::{CapacityDisplacement, ReplicationQueues}; +use crate::replication::scheduling::{CapacityDisplacement, DeferralOutcome, ReplicationQueues}; use crate::replication::types::{ AuditFailureReason, BootstrapClaimObservation, BootstrapState, FailureEvidence, NeighborSyncState, PeerSyncRecord, PresenceEvidence, RepairProofs, VerificationEntry, @@ -2166,6 +2166,8 @@ impl ReplicationEngine { next_verify_at: now, hint_sources: HashSet::from([hinter]), replica_hint_sources: HashSet::from([hinter]), + unresolved_retries: 0, + no_holder_reported: false, }; self.queues .write() @@ -7748,6 +7750,8 @@ fn queue_admitted_hints( // Non-empty: this peer claimed possession, so it is a // fetch-source candidate. Derives HintPipeline::Replica. replica_hint_sources: HashSet::from([*source_peer]), + unresolved_retries: 0, + no_holder_reported: false, }, ); match result { @@ -7775,6 +7779,8 @@ fn queue_admitted_hints( // Empty: a paid hint makes no possession claim, so this peer is // not a fetch source. Derives HintPipeline::PaidOnly. replica_hint_sources: HashSet::new(), + unresolved_retries: 0, + no_holder_reported: false, }, ); match result { @@ -7974,6 +7980,9 @@ async fn run_verification_cycle(ctx: VerificationCycleContext<'_>) { let local_paid_probe_count = local_paid_presence_probe_keys.len(); let keys_needing_network_count = keys_needing_network.len(); + // Keys this cycle put back because no peer claimed possession. Reported in + // aggregate below; the per-key line is warned once per entry, not per retry. + let mut no_holder_deferrals = 0usize; // Step 1b: Local paid-list hit for fetch-eligible keys. Per Section 9 // step 4, authorization succeeds immediately; run a presence-only probe @@ -8008,12 +8017,16 @@ async fn run_verification_cycle(ctx: VerificationCycleContext<'_>) { add_replica_hint_sources(&mut sources, &entry.replica_hint_sources); } if sources.is_empty() { - warn!( - "Locally paid key {} has no responding holders yet; deferring retry", - hex::encode(key) - ); - q.defer_pending(&key, config.verification_request_timeout); + no_holder_deferrals += 1; + let outcome = q.defer_unresolved(&key, config.verification_request_timeout); + let first_report = q.claim_no_holder_report(&key); + report_unresolved_deferral("Locally paid key", &key, outcome, first_report); } else { + // A holder answered, so whatever came before is not a run of + // consecutive failures any more. Clear before promoting: if the + // fetch queue is full the entry stays pending, and it must not + // carry the old backoff. + q.clear_unresolved(&key); let distance = crate::client::xor_distance(&key, p2p_node.peer_id().as_bytes()); // Atomic remove+enqueue: if fetch_queue is at capacity, the // pending entry is preserved and retried next cycle (no @@ -8201,6 +8214,9 @@ async fn run_verification_cycle(ctx: VerificationCycleContext<'_>) { capacity_deferred_promote += 1; } } else if fetch_eligible && !fetch_sources.is_empty() { + // A holder answered; see the matching clear on the + // local-paid path. + q.clear_unresolved(&key); let distance = crate::client::xor_distance(&key, p2p_node.peer_id().as_bytes()); // Atomic remove+enqueue: on fetch_queue capacity miss @@ -8210,11 +8226,15 @@ async fn run_verification_cycle(ctx: VerificationCycleContext<'_>) { // Not terminal — either moved to fetch queue, or // retained as pending until queue drains. } else if fetch_eligible && fetch_sources.is_empty() { - warn!( - "Verified storage-admitted key {} has no holders yet; deferring retry", - hex::encode(key) + no_holder_deferrals += 1; + let outcome = q.defer_unresolved(&key, config.verification_request_timeout); + let first_report = q.claim_no_holder_report(&key); + report_unresolved_deferral( + "Verified storage-admitted key", + &key, + outcome, + first_report, ); - q.defer_pending(&key, config.verification_request_timeout); } else { q.remove_pending(&key); terminal_keys.push(key); @@ -8226,7 +8246,11 @@ async fn run_verification_cycle(ctx: VerificationCycleContext<'_>) { } KeyVerificationOutcome::QuorumInconclusive => { q.set_pending_state(&key, VerificationState::QuorumInconclusive); - q.defer_pending(&key, config.verification_request_timeout); + // Backed off like any other unresolved round, but it does + // NOT claim the no-holder report: nothing yet says this key + // has no holder, so the first round that does say so must + // still be the one that warns. + let _ = q.defer_unresolved(&key, config.verification_request_timeout); } } } @@ -8275,12 +8299,52 @@ async fn run_verification_cycle(ctx: VerificationCycleContext<'_>) { if elapsed_ms >= VERIFICATION_CYCLE_SLOW_LOG_MS { info!( target: "ant_node::replication::verification", - "Slow replication verification cycle: pending_start={initial_pending_count}, capacity_deferred_probe={capacity_deferred_probe}, capacity_deferred_promote={capacity_deferred_promote}, local_paid_probe={local_paid_probe_count}, network_verify={keys_needing_network_count}, terminal={terminal_key_count}, pending_after={pending_after}, fetch_after={fetch_after}, in_flight_after={in_flight_after}, elapsed_ms={elapsed_ms}", + "Slow replication verification cycle: pending_start={initial_pending_count}, capacity_deferred_probe={capacity_deferred_probe}, capacity_deferred_promote={capacity_deferred_promote}, local_paid_probe={local_paid_probe_count}, network_verify={keys_needing_network_count}, terminal={terminal_key_count}, no_holders={no_holder_deferrals}, pending_after={pending_after}, fetch_after={fetch_after}, in_flight_after={in_flight_after}, elapsed_ms={elapsed_ms}", ); } else { debug!( target: "ant_node::replication::verification", - "Replication verification cycle: pending_start={initial_pending_count}, capacity_deferred_probe={capacity_deferred_probe}, capacity_deferred_promote={capacity_deferred_promote}, local_paid_probe={local_paid_probe_count}, network_verify={keys_needing_network_count}, terminal={terminal_key_count}, pending_after={pending_after}, fetch_after={fetch_after}, in_flight_after={in_flight_after}, elapsed_ms={elapsed_ms}", + "Replication verification cycle: pending_start={initial_pending_count}, capacity_deferred_probe={capacity_deferred_probe}, capacity_deferred_promote={capacity_deferred_promote}, local_paid_probe={local_paid_probe_count}, network_verify={keys_needing_network_count}, terminal={terminal_key_count}, no_holders={no_holder_deferrals}, pending_after={pending_after}, fetch_after={fetch_after}, in_flight_after={in_flight_after}, elapsed_ms={elapsed_ms}", + ); + } +} + +/// Report a verification round that left a key without a usable holder. +/// +/// Warns once per entry — the first failure is news, and by the hundredth the +/// node is re-asking peers it has already exhausted. Later failures stay at +/// `debug`, and the per-cycle count is carried in the cycle summary so the +/// scale of a backlog is still visible without a line per key per retry. +/// +/// `first_report` comes from `claim_no_holder_report`, not from the attempt +/// number: a round may advance the count without producing a no-holder result, +/// and such a round must not consume the warning. +/// +/// Eviction at `PENDING_VERIFY_MAX_AGE` drops the entry, and a round that finds +/// a holder clears it, so a later relapse warns again: "once per episode", not +/// "once ever". +fn report_unresolved_deferral( + what: &str, + key: &XorName, + outcome: Option, + first_report: bool, +) { + let Some(outcome) = outcome else { + // The entry left `pending_verify` under the same lock; nothing deferred. + return; + }; + if first_report { + warn!( + "{what} {} has no responding holders yet; deferring retry", + hex::encode(key) + ); + } else { + debug!( + "{what} {} still has no responding holders after {} attempts; \ + retrying in {}s", + hex::encode(key), + outcome.attempt, + outcome.retry_after.as_secs() ); } } @@ -10952,6 +11016,8 @@ mod tests { next_verify_at: now, hint_sources: HashSet::from([peer]), replica_hint_sources: HashSet::from([peer]), + unresolved_retries: 0, + no_holder_reported: false, }, ); super::bootstrap::track_discovered_keys(&bootstrap_state, &HashSet::from([key])).await; @@ -12995,6 +13061,8 @@ mod tests { next_verify_at: now, hint_sources: HashSet::from([hinter]), replica_hint_sources: HashSet::from([hinter]), + unresolved_retries: 0, + no_holder_reported: false, }; assert!(q.add_pending_verify(key, entry).admitted()); assert!(q.promote_pending_to_fetch(key, key, sources)); diff --git a/src/replication/scheduling.rs b/src/replication/scheduling.rs index eae84bef..79724291 100644 --- a/src/replication/scheduling.rs +++ b/src/replication/scheduling.rs @@ -11,11 +11,40 @@ use std::time::{Duration, Instant}; use crate::logging::debug; use crate::ant_protocol::XorName; +use crate::replication::config::VERIFICATION_RETRY_BACKOFF_MAX; use crate::replication::types::{ FetchCandidate, FetchOrder, FetchPayload, VerificationEntry, VerificationState, }; use saorsa_core::identity::PeerId; +/// Result of deferring a pending key to a later verification round. +#[derive(Debug, Clone, Copy, PartialEq, Eq)] +pub struct DeferralOutcome { + /// Consecutive unresolved rounds for this entry, counting this one. `1` is + /// the entry's first failure, which is the one worth reporting. + pub attempt: u32, + /// Delay applied before this key is eligible for another round. + pub retry_after: Duration, +} + +/// Exponential backoff for an unresolved pending key. +/// +/// `attempt` is 1-based, so the first deferral waits `base` and each subsequent +/// one doubles, saturating at [`VERIFICATION_RETRY_BACKOFF_MAX`]. The shift is +/// bounded before it is applied so a long-lived entry cannot overflow into a +/// short delay. +fn backoff_delay(base: Duration, attempt: u32) -> Duration { + // Clamp the exponent before shifting: `1u32 << 32` is undefined behaviour + // territory in release builds, and any base doubled 31 times has long since + // saturated the cap anyway. + let exponent = attempt.saturating_sub(1).min(31); + base.saturating_mul(1u32 << exponent) + .min(VERIFICATION_RETRY_BACKOFF_MAX) + // Never retry faster than the caller asked for, even if a config sets a + // base above the cap. + .max(base) +} + /// Global hard upper bound on the number of keys held in `pending_verify`. /// /// Without a bound, a peer in the local routing table can flood @@ -976,7 +1005,12 @@ impl ReplicationQueues { self.refresh_eviction_candidate(&key); } - /// Defer a pending key before its next verification attempt. + /// Defer a pending key before its next verification attempt, by a flat + /// delay. + /// + /// For deferrals that are *not* a failed round: the caller chose not to ask + /// (a full disk, say), so nothing was learned about the key and the + /// unresolved-round count must not move. pub fn defer_pending(&mut self, key: &XorName, retry_after: Duration) -> bool { let Some(entry) = self.pending_verify.get_mut(key) else { return false; @@ -985,6 +1019,65 @@ impl ReplicationQueues { true } + /// Defer a pending key whose verification round left it unresolved. + /// + /// `base_retry_after` is the delay for the entry's *first* such deferral. + /// Each consecutive one doubles it, capped at + /// [`VERIFICATION_RETRY_BACKOFF_MAX`]. A key that keeps failing is failing + /// for a reason a faster retry cannot change, so the cost of asking decays + /// rather than being paid in full every 15 seconds. + /// + /// Returns `None` if the key is not pending, otherwise the resulting + /// [`DeferralOutcome`], whose `attempt` is 1 on this entry's first + /// unresolved round — the one worth reporting. + pub fn defer_unresolved( + &mut self, + key: &XorName, + base_retry_after: Duration, + ) -> Option { + let entry = self.pending_verify.get_mut(key)?; + entry.unresolved_retries = entry.unresolved_retries.saturating_add(1); + let attempt = entry.unresolved_retries; + let retry_after = backoff_delay(base_retry_after, attempt); + entry.next_verify_at = Instant::now() + retry_after; + Some(DeferralOutcome { + attempt, + retry_after, + }) + } + + /// Claim this entry's single no-holder warning. + /// + /// Returns `true` the first time it is called for a given entry and `false` + /// after, so the caller can warn once and drop to `debug` thereafter. + /// + /// Kept separate from [`Self::defer_unresolved`] on purpose. A round can + /// legitimately advance the failure count without producing a no-holder + /// result — an inconclusive quorum does exactly that — and if the two + /// shared state, such a round would consume the warning before the + /// condition it describes had ever been observed. + pub fn claim_no_holder_report(&mut self, key: &XorName) -> bool { + let Some(entry) = self.pending_verify.get_mut(key) else { + return false; + }; + !std::mem::replace(&mut entry.no_holder_reported, true) + } + + /// Clear an entry's unresolved history after a round that found a holder. + /// + /// The round succeeded even if the key could not move on — a full fetch + /// queue leaves it pending — so it must not inherit the earlier backoff, and + /// a later relapse deserves a fresh warning. Returns whether an entry was + /// present to clear. + pub fn clear_unresolved(&mut self, key: &XorName) -> bool { + let Some(entry) = self.pending_verify.get_mut(key) else { + return false; + }; + entry.unresolved_retries = 0; + entry.no_holder_reported = false; + true + } + /// Number of keys in pending verification. #[must_use] pub fn pending_count(&self) -> usize { @@ -1445,6 +1538,8 @@ mod tests { next_verify_at: now, hint_sources: HashSet::from([peer_id_from_byte(sender_byte)]), replica_hint_sources: HashSet::from([peer_id_from_byte(sender_byte)]), + unresolved_retries: 0, + no_holder_reported: false, } } @@ -2350,6 +2445,217 @@ mod tests { assert_eq!(queues.ready_pending_keys(after_retry), vec![key]); } + #[test] + fn repeated_deferrals_back_off_and_saturate_at_the_cap() { + const BASE: Duration = Duration::from_secs(15); + + let mut queues = ReplicationQueues::new(); + let key = xor_name_from_byte(0xAB); + queues.add_pending_verify(key, test_entry(1)); + + // 15s doubling per consecutive unresolved round. + for (attempt, expected_secs) in [(1, 15), (2, 30), (3, 60), (4, 120), (5, 240)] { + let outcome = queues + .defer_unresolved(&key, BASE) + .expect("pending key should defer"); + assert_eq!(outcome.attempt, attempt); + assert_eq!( + outcome.retry_after, + Duration::from_secs(expected_secs), + "attempt {attempt} should back off to {expected_secs}s" + ); + } + + // Everything past the cap stays at the cap rather than overflowing the + // shift into a short (or zero) delay. + for _ in 0..64 { + let outcome = queues + .defer_unresolved(&key, BASE) + .expect("pending key should defer"); + assert_eq!( + outcome.retry_after, VERIFICATION_RETRY_BACKOFF_MAX, + "backoff must saturate at the cap, never wrap" + ); + } + } + + /// The counter and the warning answer different questions, so a round that + /// advances the count without producing a no-holder result — an + /// inconclusive quorum — must leave the warning unclaimed. Deriving the + /// report from `attempt == 1` loses the first and only warning for every + /// key whose opening round is inconclusive. + #[test] + fn a_non_reporting_round_does_not_consume_the_no_holder_warning() { + const BASE: Duration = Duration::from_secs(15); + + let mut queues = ReplicationQueues::new(); + let key = xor_name_from_byte(0xAE); + queues.add_pending_verify(key, test_entry(1)); + + // Round 1: inconclusive quorum. Backs off, reports nothing. + let first = queues + .defer_unresolved(&key, BASE) + .expect("pending key should defer"); + assert_eq!(first.attempt, 1); + + // Round 2 is the first that actually finds no holder. It is at + // attempt 2, but it is the first report and must still warn. + let second = queues + .defer_unresolved(&key, BASE) + .expect("pending key should defer"); + assert_eq!(second.attempt, 2, "the inconclusive round still counts"); + assert!( + queues.claim_no_holder_report(&key), + "the first no-holder result must warn even at attempt 2" + ); + assert!( + !queues.claim_no_holder_report(&key), + "the warning is claimed exactly once per entry" + ); + } + + /// A round that found a holder ends the run of failures, even when a full + /// fetch queue leaves the key pending. It must not inherit the old backoff, + /// and a later relapse deserves a fresh warning. + #[test] + fn finding_a_holder_clears_the_backoff_and_rearms_the_warning() { + const BASE: Duration = Duration::from_secs(15); + + let mut queues = ReplicationQueues::new(); + let key = xor_name_from_byte(0xAF); + queues.add_pending_verify(key, test_entry(1)); + + for _ in 0..4 { + queues + .defer_unresolved(&key, BASE) + .expect("pending key should defer"); + } + assert!(queues.claim_no_holder_report(&key)); + + assert!(queues.clear_unresolved(&key)); + + let outcome = queues + .defer_unresolved(&key, BASE) + .expect("pending key should defer"); + assert_eq!(outcome.attempt, 1, "a resolved round restarts the run"); + assert_eq!(outcome.retry_after, BASE); + assert!( + queues.claim_no_holder_report(&key), + "a relapse after a good round is reported again" + ); + } + + /// The whole fix rests on a duplicate hint merging into the live entry + /// rather than replacing it. A refactor that replaced would silently revert + /// the backoff with every other test here still green. + #[test] + fn a_duplicate_hint_does_not_reset_the_backoff_or_the_retry_time() { + const BASE: Duration = Duration::from_secs(15); + + let mut queues = ReplicationQueues::new(); + let key = xor_name_from_byte(0xB0); + queues.add_pending_verify(key, test_entry(1)); + + for _ in 0..3 { + queues + .defer_unresolved(&key, BASE) + .expect("pending key should defer"); + } + assert!(queues.claim_no_holder_report(&key)); + let deferred_until = queues.pending_verify[&key].next_verify_at; + + // A second advertiser re-hints the same key. + assert!(!queues.add_pending_verify(key, test_entry(2)).admitted()); + + let entry = &queues.pending_verify[&key]; + assert_eq!( + entry.unresolved_retries, 3, + "a re-hint must not restart the backoff" + ); + assert!( + entry.no_holder_reported, + "a re-hint must not re-arm the warning; only eviction ends an episode" + ); + assert_eq!( + entry.next_verify_at, deferred_until, + "a re-hint must not pull the key forward into an earlier round" + ); + } + + /// The write-blocked capacity gate defers without asking anyone, so it must + /// not consume the entry's first-failure warning or advance its backoff: + /// nothing was learned about the key. + #[test] + fn flat_defer_does_not_advance_the_unresolved_backoff() { + const BASE: Duration = Duration::from_secs(15); + + let mut queues = ReplicationQueues::new(); + let key = xor_name_from_byte(0xAD); + queues.add_pending_verify(key, test_entry(1)); + + for _ in 0..10 { + assert!(queues.defer_pending(&key, Duration::from_secs(300))); + } + + let outcome = queues + .defer_unresolved(&key, BASE) + .expect("pending key should defer"); + assert_eq!( + outcome.attempt, 1, + "a flat deferral is not a failed round and must not consume attempt 1" + ); + assert_eq!(outcome.retry_after, BASE); + assert!( + queues.claim_no_holder_report(&key), + "nor may it consume the warning" + ); + } + + #[test] + fn defer_unresolved_reports_none_for_unknown_key() { + let mut queues = ReplicationQueues::new(); + assert!(queues + .defer_unresolved(&xor_name_from_byte(0xFF), Duration::from_secs(15)) + .is_none()); + } + + #[test] + fn re_admission_after_eviction_restarts_the_backoff() { + const BASE: Duration = Duration::from_secs(15); + + let mut queues = ReplicationQueues::new(); + let key = xor_name_from_byte(0xAC); + queues.add_pending_verify(key, test_entry(1)); + + for _ in 0..5 { + queues + .defer_unresolved(&key, BASE) + .expect("pending key should defer"); + } + + // Stale eviction drops the entry; the next hint admits a fresh one. The + // count lives on the entry, so the episode — and its single warning — + // starts over. + queues.evict_stale(Duration::ZERO); + assert_eq!(queues.pending_count(), 0); + queues.add_pending_verify(key, test_entry(1)); + + let outcome = queues + .defer_unresolved(&key, BASE) + .expect("re-admitted key should defer"); + assert_eq!(outcome.attempt, 1, "re-admission starts a new episode"); + assert_eq!(outcome.retry_after, BASE); + } + + #[test] + fn backoff_never_retries_faster_than_the_caller_base() { + // A base above the cap (an unusual config, but representable) must not + // be shortened into a tighter retry loop than the caller asked for. + let long_base = VERIFICATION_RETRY_BACKOFF_MAX + Duration::from_secs(60); + assert_eq!(backoff_delay(long_base, 1), long_base); + assert_eq!(backoff_delay(long_base, 9), long_base); + } + // -- remove_pending --------------------------------------------------- #[test] @@ -2450,6 +2756,8 @@ mod tests { next_verify_at: Instant::now(), hint_sources: HashSet::from([peer_id_from_byte(1)]), replica_hint_sources: HashSet::from([peer_id_from_byte(1)]), + unresolved_retries: 0, + no_holder_reported: false, }; assert!(queues.add_pending_verify(key, entry).admitted()); @@ -2470,6 +2778,8 @@ mod tests { next_verify_at: Instant::now(), hint_sources: HashSet::from([peer_id_from_byte(2)]), replica_hint_sources: HashSet::new(), + unresolved_retries: 0, + no_holder_reported: false, }; assert!( @@ -2510,6 +2820,8 @@ mod tests { next_verify_at: Instant::now(), hint_sources: HashSet::from([paid_advertiser]), replica_hint_sources: HashSet::new(), + unresolved_retries: 0, + no_holder_reported: false, }; assert!(queues.add_pending_verify(key, paid_entry).admitted()); assert_eq!( @@ -2529,6 +2841,8 @@ mod tests { next_verify_at: Instant::now(), hint_sources: HashSet::from([replica_advertiser]), replica_hint_sources: HashSet::from([replica_advertiser]), + unresolved_retries: 0, + no_holder_reported: false, }; assert!(!queues.add_pending_verify(key, replica_entry).admitted()); @@ -2560,6 +2874,8 @@ mod tests { next_verify_at: Instant::now(), hint_sources: HashSet::from([replica_advertiser, paid_advertiser]), replica_hint_sources: HashSet::from([replica_advertiser]), + unresolved_retries: 0, + no_holder_reported: false, }; assert!(queues.add_pending_verify(key, entry).admitted()); @@ -2599,6 +2915,8 @@ mod tests { next_verify_at: Instant::now(), hint_sources: HashSet::from([peer_id_from_byte(3)]), replica_hint_sources: HashSet::from([peer_id_from_byte(3)]), + unresolved_retries: 0, + no_holder_reported: false, }; assert!( queues.add_pending_verify(key, entry).admitted(), diff --git a/src/replication/types.rs b/src/replication/types.rs index c750506a..040572e5 100644 --- a/src/replication/types.rs +++ b/src/replication/types.rs @@ -99,6 +99,32 @@ pub struct VerificationEntry { /// Subset of [`Self::hint_sources`] that advertised a replica hint and /// therefore claimed chunk possession. Paid-only advertisers are excluded. pub replica_hint_sources: HashSet, + /// Consecutive verification rounds that left this key unresolved. + /// + /// Counts deferrals, not rounds: it advances only when a round ends with no + /// usable holder (or an inconclusive quorum) and the key is put back for a + /// later retry. Zero means the key has not yet failed a round, so the next + /// deferral is its first. + /// + /// Drives the retry backoff. Lifetime is the entry's own — eviction and + /// re-admission start a fresh count. + /// + /// Cleared by a round that *did* find a holder, so it counts consecutive + /// failures rather than lifetime ones: a key held up only by a full fetch + /// queue is making progress and must not inherit an earlier backoff. + pub unresolved_retries: u32, + /// Whether this entry's one no-holder warning has already been emitted. + /// + /// Deliberately **not** derived from [`Self::unresolved_retries`]. The two + /// answer different questions: the counter asks "how many consecutive + /// rounds failed", which an inconclusive quorum legitimately advances, and + /// this asks "have we told anyone", which only a no-holder result may + /// consume. Deriving one from the other loses the first — and only — + /// warning for any key whose opening round is inconclusive. + /// + /// Cleared alongside the counter, so "once per episode" is literal: a key + /// that resolves and later becomes unresolvable again is reported again. + pub no_holder_reported: bool, } impl VerificationEntry { diff --git a/tests/poc_bootstrap_stall.rs b/tests/poc_bootstrap_stall.rs index ff733384..3215aec9 100644 --- a/tests/poc_bootstrap_stall.rs +++ b/tests/poc_bootstrap_stall.rs @@ -37,6 +37,8 @@ fn entry(sources: HashSet) -> VerificationEntry { next_verify_at: now, hint_sources: sources.clone(), replica_hint_sources: sources, + unresolved_retries: 0, + no_holder_reported: false, } } diff --git a/tests/poc_d1_bounded_queues.rs b/tests/poc_d1_bounded_queues.rs index 05397339..d3462f39 100644 --- a/tests/poc_d1_bounded_queues.rs +++ b/tests/poc_d1_bounded_queues.rs @@ -59,6 +59,8 @@ fn entry_from(sender: PeerId) -> VerificationEntry { next_verify_at: now, hint_sources: HashSet::from([sender]), replica_hint_sources: HashSet::from([sender]), + unresolved_retries: 0, + no_holder_reported: false, } }