gunnar_server/replication_view.rs
1//! **What replication looks like from outside it** — the one shape the console
2//! band, `Admin.Stats` and the log all read.
3//!
4//! # Why this exists rather than a direct reference to the replicator
5//!
6//! Two problems, one answer.
7//!
8//! 1. **Order.** The gRPC control plane is built before the replicator is: the
9//! replicator subscribes to the event bus the server already has, and it is
10//! started last on purpose so that nothing above it can be slowed or failed
11//! by it. A surface that held an `Arc<Replicator>` could not be constructed.
12//! 2. **The feature.** `mirror.rs` is behind `feature = "replication"`, and a
13//! build without it must still be able to say *"no standby is
14//! configured"*. A field that vanishes with a feature makes that sentence
15//! vanish too, and the whole point of this module is that silence is the
16//! bug.
17//!
18//! So the view holds a **closure**, filled once by `serve` when the replicator
19//! exists. Nothing here names `Replicator`, and a build with no replication
20//! answers [`ReplicationReport::default`] — `configured: false`, which is a
21//! fact, not an absence.
22//!
23//! # The number that matters is the one that is missing
24//!
25//! MEASURED: every configured standby received **nothing** from
26//! `e31ab8f4` until the fix on 2026-08-30, and it said so five times out
27//! of five in a log line nobody read. The field that would have caught it on
28//! day one is [`StandbyRow::last_success_unix_ms`] being **zero**, and the
29//! sentence is *"last successful replication: never"* — which is why
30//! [`StandbyRow::never_synced`] is its own predicate and
31//! [`StandbyRow::describe`] gives it its own message rather than folding it
32//! into "stale".
33
34use std::sync::Arc;
35
36/// Everything a surface needs to draw replication, in one snapshot.
37#[derive(Debug, Clone, Default, PartialEq, Eq)]
38pub struct ReplicationReport {
39 /// **Is any standby configured at all?**
40 ///
41 /// False and empty is "nothing to replicate to", which is the ordinary
42 /// state of a single box and is not an alarm. True and empty would be a
43 /// bug, and the band says so rather than drawing nothing.
44 pub configured: bool,
45 /// Jobs that entered a queue.
46 pub enqueued: u64,
47 /// Attempts a standby accepted.
48 pub synced: u64,
49 /// Attempts that failed. Never resets.
50 pub failed: u64,
51 /// Times the event-stream subscription fell behind and lost events.
52 pub bus_gaps: u64,
53 /// One row per configured standby.
54 pub standbys: Vec<StandbyRow>,
55 /// **Refs on this server that no standby carries**, and the total they are
56 /// counted against. See [`RefCoverage`].
57 pub refs: RefCoverage,
58}
59
60impl ReplicationReport {
61 /// Any standby whose [`StandbyRow::verdict`] is an alarm.
62 ///
63 /// `behind` is in here because of the sixty seconds described on
64 /// [`BEHIND_AFTER_RETRY_MAX`]: a standby that has been powered off is not
65 /// stale for the better part of an hour, and an alarm that only watches
66 /// `stale` sees nothing wrong in the meantime.
67 pub fn alarming(&self) -> impl Iterator<Item = &StandbyRow> {
68 self.standbys.iter().filter(|row| row.verdict().alarming())
69 }
70}
71
72/// ★ **How many refs a mirror does not carry** — the number behind
73/// `copied alice/korp 50 refs (94 not mirrored)`.
74///
75/// # The green row that was 56% of the truth
76///
77/// 🔴 MEASURED on the live primary 2026-08-31, during the first restore drill:
78/// across all 24 replicated repositories, **1292 refs exist and 567 of them are
79/// not mirrored** — `alice/korp` alone has 144 refs of which 94 never leave
80/// this box. `gunnar_client::mirror::is_mirrored_ref` carries `refs/heads/*`
81/// and `refs/tags/*` and nothing else, which is a deliberate choice and is not
82/// changed here; what was missing is that **nothing said so**. `replication
83/// list` printed `copied alice/korp 50 refs` and the console drew a green
84/// row: both true, and together they give an operator the impression that the
85/// standby holds the repository. It holds every branch and tag of it.
86///
87/// Most of the difference is `refs/remotes/origin/*` left by pushes from mirror
88/// clones. Not all of it: `refs/superseded/wip-pre-reset-…`,
89/// `refs/salvage/*` and `refs/original/refs` are places somebody parked
90/// work **because it mattered**, and for some of them the primary is the only
91/// copy.
92///
93/// Counted from the PRIMARY's own refs rather than from what an attempt did, so
94/// a repository that has never replicated still has a number, and a repository
95/// whose refs are all branches and tags reports **0** rather than nothing at
96/// all. A counter that only prints when it is non-zero is not a counter.
97#[derive(Debug, Clone, Copy, Default, PartialEq, Eq)]
98pub struct RefCoverage {
99 /// Every ref in the repository — the denominator.
100 pub total: u64,
101 /// Refs outside `refs/heads/` and `refs/tags/`: on this box only.
102 pub unmirrored: u64,
103}
104
105impl RefCoverage {
106 /// Refs a standby can hold: `total - unmirrored`.
107 pub fn mirrorable(&self) -> u64 {
108 self.total.saturating_sub(self.unmirrored)
109 }
110
111 /// Add another repository's count into a server-wide total.
112 pub fn add(&mut self, other: RefCoverage) {
113 self.total = self.total.saturating_add(other.total);
114 self.unmirrored = self.unmirrored.saturating_add(other.unmirrored);
115 }
116}
117
118/// ★ **What one standby's row SAYS, in one word** — decided here and nowhere
119/// else (one implementation), so the CLI row, the console badge, the appliance band and the
120/// alarm cannot disagree about the same standby.
121///
122/// # The alarm that lied
123///
124/// 🔴 MEASURED on the reference appliance 2026-08-31: `gunnar control replication list`
125/// printed `pending 0 · failures 0 · last success <ts> · STALE` on a box with
126/// **nothing wrong with it**. Staleness was `now - last_success > 10x the retry
127/// ceiling` and nothing else, and the last *success* is a clock that stops the
128/// moment there is nothing to replicate — so every standby on a quiet weekend
129/// crossed the threshold and shouted about it. An alarm that fires on a Sunday
130/// is an alarm an operator learns to ignore, which is worse than none.
131///
132/// The distinction the word has to carry is **fallen behind** versus **nothing
133/// to do**, and it is not a question about time since a success. It is a
134/// question about outstanding work:
135///
136/// * [`Verdict::Idle`] — nothing queued, nothing in flight, nothing failing.
137/// There is no work, so the age of the last success measures the weekend and
138/// not the standby.
139/// * [`Verdict::Working`] — work in hand, inside the retry ceiling. An ordinary
140/// push on its way.
141/// * [`Verdict::Behind`] — work outstanding for longer than the retry ceiling
142/// ([`BEHIND_AFTER_RETRY_MAX`]). Five minutes with the shipped defaults.
143/// * [`Verdict::Stale`] — **and** nothing has landed for ten times the ceiling.
144/// Fifty minutes with the shipped defaults, and it is now a statement about
145/// work that is not moving rather than about a quiet box.
146/// * [`Verdict::Never`] — not one byte, ever. Its own word because it needs its
147/// own action: `resync` after fixing the address or the key, not "wait".
148#[derive(Debug, Clone, Copy, Default, PartialEq, Eq)]
149pub enum Verdict {
150 /// Not one byte has ever reached this standby.
151 Never,
152 /// Work is stuck AND nothing has landed for [`STALENESS_FACTOR`]x the
153 /// retry ceiling.
154 Stale,
155 /// Work outstanding longer than the retry ceiling.
156 Behind,
157 /// Work in hand, inside the ceiling.
158 Working,
159 /// Nothing outstanding and nothing failing: there is nothing to do.
160 #[default]
161 Idle,
162}
163
164impl Verdict {
165 /// The word every surface prints. Upper case is an alarm; lower case is
166 /// not, and that is deliberate — the shape of the row says which it is
167 /// before the word is read.
168 pub const fn word(self) -> &'static str {
169 match self {
170 Verdict::Never => "NEVER",
171 Verdict::Stale => "STALE",
172 Verdict::Behind => "BEHIND",
173 Verdict::Working => "syncing",
174 Verdict::Idle => "idle",
175 }
176 }
177
178 /// Does this word deserve somebody's attention tonight?
179 pub const fn alarming(self) -> bool {
180 matches!(self, Verdict::Never | Verdict::Stale | Verdict::Behind)
181 }
182}
183
184/// **Is a standby that HAS synced now stale?** The one computation behind
185/// [`StandbyRow::stale`], as a pure function so it can be seen red without a
186/// live standby (measured, not asserted).
187///
188/// Two conditions, and the second is the fix: nothing has landed for
189/// `stale_after_ms`, **and** there is evidence the standby is not keeping up —
190/// work stuck past the retry ceiling, or an attempt that has already failed.
191/// Without the second condition an idle box reads STALE, which is what it did.
192///
193/// It deliberately does NOT fire on work that has only just arrived. A push
194/// after a quiet weekend is outstanding for a second or two against a last
195/// success that is hours old; calling that stale would flap an alarm on every
196/// ordinary push, and `behind` is the number that separates the two.
197pub fn is_stale(
198 now_unix_ms: i64,
199 last_success_unix_ms: i64,
200 consecutive_failures: u32,
201 behind: bool,
202 stale_after_ms: i64,
203) -> bool {
204 if last_success_unix_ms <= 0 {
205 // NEVER is its own verdict and its own sentence. Saying "stale" about
206 // it too would fold the two back together.
207 return false;
208 }
209 let struggling = behind || consecutive_failures > 0;
210 struggling && now_unix_ms.saturating_sub(last_success_unix_ms) > stale_after_ms
211}
212
213/// One standby's state, flattened.
214#[derive(Debug, Clone, Default, PartialEq, Eq)]
215pub struct StandbyRow {
216 /// The operator's name for it.
217 pub name: String,
218 /// Where it is.
219 pub remote: String,
220 /// Repositories with work outstanding.
221 pub pending: u64,
222 /// Consecutive failures for the job at the head of the queue.
223 pub consecutive_failures: u32,
224 /// The last failure since the last success.
225 pub last_error: String,
226 /// **Zero means NEVER**, and that is the value this whole module exists
227 /// for. Not "unknown", not "just now".
228 pub last_success_unix_ms: i64,
229 /// A hole retrying will not close; `gunnar control replication resync` is
230 /// the fix.
231 pub needs_full_resync: bool,
232 /// **Work is stuck and nothing has landed for [`STALENESS_FACTOR`]x the
233 /// retry ceiling.** See [`is_stale`] — this is NOT "the last success is
234 /// old", which is what it used to be and what made an idle box shout.
235 /// *Never* is not folded in here; it is [`Verdict::Never`].
236 pub stale: bool,
237 /// **The repository an attempt is in flight for**, empty when none.
238 pub in_flight: String,
239 /// **How long the oldest outstanding repository has been outstanding**, ms.
240 /// Zero when there is none.
241 pub outstanding_for_ms: i64,
242 /// Outstanding work older than the retry ceiling. See [`BEHIND_AFTER_RETRY_MAX`].
243 pub behind: bool,
244}
245
246impl StandbyRow {
247 /// **Has a byte ever reached this standby?**
248 ///
249 /// The distinction is not cosmetic. "It has not synced for six hours" is a
250 /// standby that was working and stopped; "it has never synced" is a
251 /// standby that has never worked, and the second one means the durability
252 /// promise on this box does not exist. They need different sentences
253 /// because they need different actions.
254 pub fn never_synced(&self) -> bool {
255 self.last_success_unix_ms <= 0
256 }
257
258 /// **The one word this row says.** See [`Verdict`].
259 ///
260 /// Every surface asks this rather than reading the booleans itself: the
261 /// console badge, the CLI row, the band and the alarm all print what this
262 /// returns, so "is it stale?" has exactly one answer per snapshot.
263 pub fn verdict(&self) -> Verdict {
264 if self.never_synced() {
265 Verdict::Never
266 } else if self.stale {
267 Verdict::Stale
268 } else if self.behind {
269 Verdict::Behind
270 } else if self.pending > 0 {
271 Verdict::Working
272 } else {
273 Verdict::Idle
274 }
275 }
276
277 /// Seconds since the last success, or `None` when there has never been
278 /// one.
279 pub fn since_last_success(&self, now_unix_ms: i64) -> Option<i64> {
280 if self.never_synced() {
281 return None;
282 }
283 Some(((now_unix_ms - self.last_success_unix_ms).max(0)) / 1000)
284 }
285
286 /// The band's row and the log line, one writer (one implementation).
287 ///
288 /// ```text
289 /// standby synced 105 failed 40 last 00:00:03 ago idle
290 /// standby synced 0 failed 8 last successful replication: NEVER
291 /// ```
292 ///
293 /// The word comes from [`Self::verdict`], so `idle` is printed rather than
294 /// left blank: a row with no word on it is a row an operator has to guess
295 /// about, and guessing is what `STALE` on a healthy box taught them to do.
296 /// `BEHIND` is not repeated here — [`Self::outstanding`] carries it beside
297 /// the work it is about.
298 pub fn describe(&self, synced: u64, failed: u64, now_unix_ms: i64) -> String {
299 let word = match self.verdict() {
300 Verdict::Behind | Verdict::Working => String::new(),
301 verdict => format!(" {}", verdict.word()),
302 };
303 let head = match self.since_last_success(now_unix_ms) {
304 Some(secs) => format!(
305 "{} synced {synced} failed {failed} last {} ago{word}",
306 self.name,
307 hms(secs),
308 ),
309 None => format!(
310 "{} synced {synced} failed {failed} last successful replication: NEVER",
311 self.name
312 ),
313 };
314 format!("{head}{}", self.outstanding())
315 }
316
317 /// **The clock that keeps ticking while a standby is dead**, as the tail of
318 /// a row: ` pending 3 in flight alice/x outstanding 00:01:03 BEHIND`.
319 ///
320 /// Empty when nothing is outstanding, so a healthy idle standby's row is
321 /// unchanged.
322 pub fn outstanding(&self) -> String {
323 if self.pending == 0 && self.outstanding_for_ms <= 0 {
324 return String::new();
325 }
326 let mut tail = format!(" pending {}", self.pending);
327 if !self.in_flight.is_empty() {
328 tail.push_str(&format!(" in flight {}", self.in_flight));
329 }
330 if self.outstanding_for_ms > 0 {
331 tail.push_str(&format!(
332 " outstanding {}",
333 hms(self.outstanding_for_ms / 1000)
334 ));
335 }
336 if self.behind {
337 tail.push_str(" BEHIND");
338 }
339 tail
340 }
341}
342
343/// `HH:MM:SS` from a count of seconds, saturating at three digits of hours.
344pub fn hms(secs: i64) -> String {
345 let secs = secs.max(0);
346 format!(
347 "{:02}:{:02}:{:02}",
348 secs / 3600,
349 (secs % 3600) / 60,
350 secs % 60
351 )
352}
353
354/// **How long WITH WORK STUCK ON IT and no success before a standby is STALE.**
355///
356/// Ten times the retry ceiling. A multiple of the retry rather than a
357/// wall-clock constant, because that is the number that separates *"this has
358/// stopped working"* from *"this is between attempts"*: at the cap the worker
359/// tries every `DEFAULT_RETRY_MAX`, so ten missed attempts in a row is not a
360/// slow standby, it is a broken one. With the shipped defaults, 50 minutes.
361///
362/// 🔴 The threshold on its own was the whole test until 2026-08-31, and on its
363/// own it is a clock that stops: with nothing to replicate, every healthy
364/// standby crosses it and the row shouts `STALE` at an operator who has done
365/// nothing wrong. [`is_stale`] is the other half — see [`Verdict`].
366pub const STALENESS_FACTOR: u32 = 10;
367
368/// **How long outstanding work may sit before the standby is BEHIND**, as a
369/// multiple of the retry ceiling.
370///
371/// One. At the ceiling the worker retries every `retry_max`, so a repository
372/// still outstanding after a full ceiling has had at least one whole attempt
373/// cycle fail to converge. With the shipped defaults, **five minutes**.
374///
375/// # Why this exists at all — the fifty minutes that said nothing
376///
377/// 🔴 MEASURED on the reference appliance 2026-08-31: the standby was **hard
378/// powered-off** with a push outstanding, and sixty seconds later its row read
379/// `pending 0 failures 0 last success <a minute ago>`. Every number on it
380/// said healthy. `stale` could not help — it is `STALENESS_FACTOR` × the retry
381/// ceiling, **fifty minutes** with the shipped defaults, and it is measured
382/// from the last *success*, which is a clock that has stopped.
383///
384/// `behind` is measured from the oldest **outstanding work**, which is a clock
385/// that keeps ticking. It is a different fact from `stale` and is reported
386/// separately rather than folded in: *"nothing has landed for fifty minutes"*
387/// and *"something has been trying to land for five"* need different sentences
388/// because a standby can be either without being the other.
389///
390/// It will also fire on a repository that legitimately takes longer than the
391/// ceiling to ship — and that is the right trade. A repository that has been
392/// replicating for five minutes is something an operator should be able to see;
393/// the row names it (`in flight <repo>`) so which of the two it is can be read
394/// off the same line.
395pub const BEHIND_AFTER_RETRY_MAX: u32 = 1;
396
397/// **The one snapshot every surface draws replication from** — the console
398/// band, `Admin.Stats`, and the staleness alarm (one implementation).
399///
400/// A standby that has **never** synced alarms from the moment the replicator
401/// starts, and it is the case this whole module exists for: from `e31ab8f4` to
402/// 2026-08-30 every configured standby on this project received nothing, and
403/// the only thing that said so was a log line nobody read. Waiting out a
404/// threshold before saying so would be the same silence, only shorter. It is
405/// [`Verdict::Never`] rather than [`Verdict::Stale`], because the two need
406/// different actions.
407///
408/// # The threshold uses the CONFIGURED ceiling, not the clamped one
409///
410/// `retry_max_ms` below its `retry_base_ms` is a misconfiguration the worker
411/// clamps for itself. This does not repeat that clamp — a second copy of it
412/// would be a second thing to keep in step (one implementation) — and it does not need to:
413/// a threshold computed from a too-small ceiling makes the alarm fire
414/// *earlier*, which is the safe direction for an alarm.
415///
416/// # It takes a `Replicator`, not a slot or a server
417///
418/// The smallest thing that has the numbers. Replication's lifecycle around it has
419/// been in motion (a live, reconfigurable slot is being built beside it), and
420/// a reporting function pinned to whichever wrapper is current would have to
421/// move every time that does. `Replicator` is the object that holds the
422/// counters and it is not going anywhere.
423#[cfg(feature = "replication")]
424pub fn report(replicator: &crate::mirror::Replicator) -> ReplicationReport {
425 let counters = replicator.counters();
426 let now = gunnar_grpc::bus::now_unix_ms();
427 let stale_after_ms =
428 (replicator.config().retry_max_ms as i64).saturating_mul(i64::from(STALENESS_FACTOR));
429 let behind_after_ms =
430 (replicator.config().retry_max_ms as i64).saturating_mul(i64::from(BEHIND_AFTER_RETRY_MAX));
431 ReplicationReport {
432 configured: true,
433 enqueued: counters.enqueued,
434 synced: counters.succeeded,
435 failed: counters.failed,
436 bus_gaps: counters.bus_gaps,
437 // **No walk here.** This function is the cheap operational report —
438 // counters, verdicts, the "never synced" zero — and every one of its
439 // callers is a POLLED surface (`Admin.Stats`, the appliance band,
440 // `Mirror.ReplicationStatus`). Counting the refs a mirror does not
441 // carry opens every repository's reference database, and a polled
442 // surface paying that on a timer is how a status page became a load.
443 // So `refs` starts at zeros; the surface that wants the number
444 // fills it — `Mirror.ReplicationStatus` with `include_refs` takes a
445 // FRESH walk, and the polled surfaces peek the last one via
446 // [`crate::mirror::Replicator::ref_coverage_cached`] and never walk.
447 refs: RefCoverage::default(),
448 standbys: replicator
449 .status()
450 .into_iter()
451 .map(|status| {
452 let last = status.last_success_unix_ms.unwrap_or(0);
453 let outstanding_for_ms = status
454 .outstanding_for
455 .map(|d| d.as_millis().min(i64::MAX as u128) as i64)
456 .unwrap_or(0);
457 let behind = outstanding_for_ms > behind_after_ms;
458 StandbyRow {
459 stale: is_stale(
460 now,
461 last,
462 status.consecutive_failures,
463 behind,
464 stale_after_ms,
465 ),
466 behind,
467 in_flight: status.in_flight.unwrap_or_default(),
468 outstanding_for_ms,
469 name: status.name,
470 remote: status.remote,
471 pending: status.pending as u64,
472 consecutive_failures: status.consecutive_failures,
473 last_error: status.last_error.unwrap_or_default(),
474 last_success_unix_ms: last,
475 needs_full_resync: status.needs_full_resync,
476 }
477 })
478 .collect(),
479 }
480}
481
482/// A slot `serve` fills once the replicator exists.
483///
484/// Cloneable and cheap: every surface holds the same `Arc`, and the closure is
485/// set exactly once. Reading before it is set answers "nothing configured",
486/// which is what a server with no replication *is*.
487#[derive(Clone, Default)]
488pub struct ReplicationView {
489 source: Arc<std::sync::OnceLock<Box<dyn Fn() -> ReplicationReport + Send + Sync>>>,
490}
491
492impl ReplicationView {
493 /// An empty view. Reads as "nothing configured" until [`Self::fill`].
494 pub fn new() -> Self {
495 Self::default()
496 }
497
498 /// Fill it. The second call is ignored: one server has one replicator, and
499 /// silently replacing the source would make which one is being read depend
500 /// on start-up order.
501 pub fn fill(&self, source: impl Fn() -> ReplicationReport + Send + Sync + 'static) {
502 let _ = self.source.set(Box::new(source));
503 }
504
505 /// The snapshot, now.
506 pub fn report(&self) -> ReplicationReport {
507 match self.source.get() {
508 Some(source) => source(),
509 None => ReplicationReport::default(),
510 }
511 }
512}
513
514impl std::fmt::Debug for ReplicationView {
515 fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
516 f.debug_struct("ReplicationView")
517 .field("filled", &self.source.get().is_some())
518 .finish()
519 }
520}
521
522/// How often the staleness watch looks. Thirty seconds: the threshold is
523/// measured in tens of minutes, so the poll period is noise against it, and it
524/// costs a few atomic loads.
525pub const STALENESS_POLL: std::time::Duration = std::time::Duration::from_secs(30);
526
527/// **The staleness alarm.** One writer for the log line and the event-stream event
528/// (one implementation), so the console, `journalctl`, the UDP narration and every
529/// `Events.Watch`/SSE subscriber say the same thing about the same standby.
530///
531/// **Edge-triggered.** A warning emitted every poll is the log line nobody
532/// read, with more of it: this fires once when a standby goes stale and once
533/// when it comes back. The band draws the state continuously; the alarm marks
534/// the transition.
535///
536/// The event is a `ReplicationFailed` on the existing stream rather than a new
537/// event kind, because that is exactly what it is — a replication that is not
538/// happening — and because a subscriber written before this change already
539/// knows how to render one. `attempt` carries the consecutive-failure count and
540/// `reason` carries the sentence.
541///
542/// `needs_full_resync` is **true for a standby that has never synced**: there
543/// is no partial state to catch up from, and a resync is the operator's next
544/// step once the address or the key is fixed.
545pub fn spawn_staleness_watch(
546 view: ReplicationView,
547 bus: std::sync::Arc<gunnar_grpc::EventBus>,
548) -> tokio::task::JoinHandle<()> {
549 // A32-14, stays a task: its handle is kept by serve and aborted at the server's stop.
550 tokio::spawn(async move {
551 let mut alarmed: Vec<String> = Vec::new();
552 loop {
553 let report = view.report();
554 for row in &report.standbys {
555 let verdict = row.verdict();
556 let alarming = verdict.alarming();
557 let was = alarmed.iter().any(|name| name == &row.name);
558 if alarming && !was {
559 alarmed.push(row.name.clone());
560 let reason = if verdict == Verdict::Behind {
561 // **The sixty seconds that read as healthy.** A standby
562 // that has just been powered off is not stale for the
563 // better part of an hour, and the only number moving in
564 // the meantime is how long its work has been waiting.
565 tracing::warn!(
566 target: "gunnar::replication",
567 event = "replication.behind",
568 standby = %row.name,
569 remote = %row.remote,
570 pending = row.pending,
571 in_flight = %row.in_flight,
572 outstanding_for_ms = row.outstanding_for_ms,
573 "this standby has had work outstanding for longer than the retry \
574 ceiling. It may be unreachable, or one repository may simply be \
575 large; the row names which."
576 );
577 format!(
578 "{} repository(ies) outstanding for {}, longer than the retry \
579 ceiling{}",
580 row.pending,
581 hms(row.outstanding_for_ms / 1000),
582 if row.in_flight.is_empty() {
583 String::new()
584 } else {
585 format!("; in flight: {}", row.in_flight)
586 }
587 )
588 } else if verdict == Verdict::Never {
589 tracing::error!(
590 target: "gunnar::replication",
591 event = "replication.never_synced",
592 standby = %row.name,
593 remote = %row.remote,
594 failed = report.failed,
595 "LAST SUCCESSFUL REPLICATION: NEVER. This standby has never taken a \
596 single byte, so there is no second copy of anything on it. Check its \
597 address, its host key and the deploy key in replication.json."
598 );
599 "last successful replication: NEVER — this standby has never taken a byte"
600 .to_owned()
601 } else {
602 tracing::warn!(
603 target: "gunnar::replication",
604 event = "replication.stale",
605 standby = %row.name,
606 remote = %row.remote,
607 last_success_unix_ms = row.last_success_unix_ms,
608 "this standby has not taken a byte for more than {STALENESS_FACTOR}x \
609 the retry ceiling; its copy is behind by an unknown amount"
610 );
611 format!(
612 "no successful replication for more than {STALENESS_FACTOR}x the \
613 retry ceiling"
614 )
615 };
616 bus.publish(gunnar_proto::event::Payload::ReplicationFailed(
617 gunnar_proto::ReplicationFailed {
618 repo: None,
619 target: row.name.clone(),
620 remote_url: row.remote.clone(),
621 attempt: row.consecutive_failures,
622 retry_in_ms: 0,
623 reason,
624 needs_full_resync: row.needs_full_resync || row.never_synced(),
625 },
626 ));
627 } else if !alarming && was {
628 alarmed.retain(|name| name != &row.name);
629 tracing::info!(
630 target: "gunnar::replication",
631 event = "replication.recovered",
632 standby = %row.name,
633 "this standby is taking bytes again"
634 );
635 }
636 }
637 // A standby that was removed from the configuration stops being
638 // alarming; keeping its name would make a re-added one silent.
639 alarmed.retain(|name| report.standbys.iter().any(|row| &row.name == name));
640 tokio::time::sleep(STALENESS_POLL).await;
641 }
642 })
643}
644
645#[cfg(test)]
646mod tests {
647 use super::*;
648
649 /// **"never" is its own sentence.** The line that would have caught weeks
650 /// of silence on day one, asserted as a string because a string is what an
651 /// operator reads.
652 #[test]
653 fn a_standby_that_has_never_synced_says_so_in_those_words() {
654 let never = StandbyRow {
655 name: "standby".into(),
656 last_success_unix_ms: 0,
657 stale: true,
658 ..StandbyRow::default()
659 };
660 let line = never.describe(0, 8, 1_000_000);
661 assert!(
662 line.contains("last successful replication: NEVER"),
663 "a standby that has never synced must say so: {line}"
664 );
665 assert!(never.never_synced());
666 assert_eq!(never.since_last_success(1_000_000), None);
667
668 // …and one that HAS synced must not say it, or the sentence is noise.
669 let worked = StandbyRow {
670 name: "standby".into(),
671 last_success_unix_ms: 997_000,
672 ..StandbyRow::default()
673 };
674 let line = worked.describe(105, 40, 1_000_000);
675 assert!(!line.contains("NEVER"), "{line}");
676 assert!(line.contains("synced 105"), "{line}");
677 assert!(line.contains("failed 40"), "{line}");
678 assert!(line.contains("last 00:00:03 ago"), "{line}");
679 }
680
681 /// ★ **The sixty seconds that read as healthy.**
682 ///
683 /// 🔴 MEASURED on the reference appliance 2026-08-31: the standby was hard
684 /// powered-off with a push outstanding, and a minute later its row read
685 /// `pending 0 failures 0 last success <a minute ago>` — every number said
686 /// healthy. `stale` could not help: it is `STALENESS_FACTOR` × the retry
687 /// ceiling, **fifty minutes**, measured from the last *success*, which is a
688 /// clock that has stopped.
689 ///
690 /// Both directions are asserted. A row that said BEHIND whenever anything
691 /// was outstanding would flag every ordinary push, so the healthy-but-busy
692 /// case is named by value too.
693 #[test]
694 fn a_standby_with_work_stuck_on_it_says_so_long_before_it_is_stale() {
695 let now = 1_000_000_000_000i64;
696 // A minute after a power-off: the last success is recent, so `stale` is
697 // false and must stay false — this is the state the measurement caught.
698 let dead = StandbyRow {
699 name: "standby-fi-hel1".into(),
700 pending: 1,
701 in_flight: "alice/linux-mirror".into(),
702 outstanding_for_ms: 60_000,
703 last_success_unix_ms: now - 61_000,
704 stale: false,
705 behind: false,
706 ..StandbyRow::default()
707 };
708 let line = dead.describe(105, 0, now);
709 assert!(
710 line.contains("pending 1") && line.contains("in flight alice/linux-mirror"),
711 "the row must name the outstanding work, or `pending 0 failures 0` is all an \
712 operator sees: {line}"
713 );
714 assert!(
715 line.contains("outstanding 00:01:00"),
716 "the row must carry the clock that is still ticking: {line}"
717 );
718
719 // Past the ceiling, it is BEHIND — and that is an alarm, at five
720 // minutes rather than fifty.
721 let behind = StandbyRow {
722 outstanding_for_ms: 400_000,
723 behind: true,
724 ..dead.clone()
725 };
726 assert!(behind.describe(105, 0, now).contains("BEHIND"));
727 let report = ReplicationReport {
728 configured: true,
729 standbys: vec![dead.clone(), behind.clone()],
730 ..ReplicationReport::default()
731 };
732 let alarming: Vec<&str> = report.alarming().map(|r| r.in_flight.as_str()).collect();
733 assert_eq!(
734 alarming.len(),
735 1,
736 "exactly the BEHIND row must alarm; a row that alarmed on any outstanding work \
737 would fire on every ordinary push"
738 );
739
740 // A standby with nothing outstanding says nothing extra at all, or the
741 // tail is noise on every healthy row.
742 let idle = StandbyRow {
743 name: "standby".into(),
744 last_success_unix_ms: now - 3_000,
745 ..StandbyRow::default()
746 };
747 assert_eq!(idle.outstanding(), "");
748 assert_eq!(
749 idle.describe(105, 0, now),
750 "standby synced 105 failed 0 last 00:00:03 ago idle"
751 );
752 }
753
754 /// ★ **The alarm that lied: `STALE` on a healthy idle box.**
755 ///
756 /// 🔴 MEASURED on the reference appliance 2026-08-31 —
757 /// `pending 0 · failures 0 · last success <ts> · STALE`, with nothing wrong
758 /// at all. Staleness was `now - last_success > 10x the retry ceiling` and
759 /// nothing else, and the last *success* is a clock that stops when there is
760 /// nothing left to replicate: a weekend with no pushes takes every standby
761 /// past the threshold.
762 ///
763 /// Seen RED by restoring that one line
764 /// (`stale: last <= 0 || now - last > stale_after_ms`): the first assertion
765 /// below fails, and the two after it — the standby that really IS behind —
766 /// keep passing, which is the half that makes this a fix rather than a
767 /// deleted alarm.
768 #[test]
769 fn an_idle_standby_is_not_stale_and_a_stuck_one_still_is() {
770 let hour = 3_600_000i64;
771 let now = 1_000_000_000_000i64;
772 let stale_after = 50 * 60 * 1000; // the shipped default: 10 x 5 minutes
773
774 // A quiet Sunday: nothing queued, nothing in flight, nothing failing,
775 // and the last success is hours old BECAUSE THERE WAS NOTHING TO DO.
776 assert!(
777 !is_stale(now, now - 6 * hour, 0, false, stale_after),
778 "a standby with nothing to do read STALE — this is the measured lie"
779 );
780 let quiet = StandbyRow {
781 name: "standby".into(),
782 last_success_unix_ms: now - 6 * hour,
783 ..StandbyRow::default()
784 };
785 assert_eq!(quiet.verdict(), Verdict::Idle);
786 assert!(!quiet.verdict().alarming());
787 assert!(quiet.describe(105, 0, now).contains(" idle"));
788
789 // …and the alarm still fires on a standby that has fallen behind:
790 // work stuck past the retry ceiling, nothing landing for ten times it.
791 assert!(
792 is_stale(now, now - 6 * hour, 0, true, stale_after),
793 "a standby with work stuck on it for hours must still be STALE"
794 );
795 // A failed attempt is the other evidence: the queue may be short, but
796 // an attempt that failed is not a quiet Sunday.
797 assert!(is_stale(now, now - 6 * hour, 3, false, stale_after));
798 // Inside the window it is not stale yet, however stuck it is — that is
799 // what `behind` is for, and it fires ten times sooner.
800 assert!(!is_stale(now, now - 60_000, 3, true, stale_after));
801 // And a push that has only just arrived after a quiet weekend must NOT
802 // trip the alarm on its way through: outstanding, but not yet behind.
803 assert!(!is_stale(now, now - 6 * hour, 0, false, stale_after));
804
805 let stuck = StandbyRow {
806 name: "standby".into(),
807 pending: 1,
808 in_flight: "alice/korp".into(),
809 outstanding_for_ms: 6 * hour,
810 last_success_unix_ms: now - 6 * hour,
811 stale: true,
812 behind: true,
813 ..StandbyRow::default()
814 };
815 assert_eq!(stuck.verdict(), Verdict::Stale);
816 assert!(stuck.verdict().alarming());
817 assert!(stuck.describe(105, 4, now).contains("STALE"));
818
819 // NEVER is not folded into stale: it needs a different sentence and a
820 // different action.
821 let never = StandbyRow {
822 name: "standby".into(),
823 ..StandbyRow::default()
824 };
825 assert_eq!(never.verdict(), Verdict::Never);
826 assert!(never.verdict().alarming());
827 assert!(!is_stale(now, 0, 0, false, stale_after));
828
829 // An ordinary push on its way is neither an alarm nor "idle".
830 let working = StandbyRow {
831 name: "standby".into(),
832 pending: 1,
833 outstanding_for_ms: 900,
834 last_success_unix_ms: now - 3_000,
835 ..StandbyRow::default()
836 };
837 assert_eq!(working.verdict(), Verdict::Working);
838 assert!(!working.verdict().alarming());
839 }
840
841 /// The shortfall counter reports **zero**, not a blank, for a repository
842 /// whose refs a mirror carries entirely.
843 #[test]
844 fn ref_coverage_counts_zero_as_a_number() {
845 let all_carried = RefCoverage {
846 total: 20,
847 unmirrored: 0,
848 };
849 assert_eq!(all_carried.mirrorable(), 20);
850 let korp = RefCoverage {
851 total: 144,
852 unmirrored: 94,
853 };
854 assert_eq!(
855 korp.mirrorable(),
856 50,
857 "the number `replication list` prints"
858 );
859 let mut server = RefCoverage::default();
860 server.add(all_carried);
861 server.add(korp);
862 assert_eq!((server.total, server.unmirrored), (164, 94));
863 }
864
865 /// An unfilled view is "nothing configured", not a panic and not an empty
866 /// success that looks like a healthy standby.
867 #[test]
868 fn an_unfilled_view_reports_nothing_configured() {
869 let view = ReplicationView::new();
870 let report = view.report();
871 assert!(!report.configured);
872 assert!(report.standbys.is_empty());
873 }
874
875 #[test]
876 fn a_filled_view_reports_what_the_source_says() {
877 let view = ReplicationView::new();
878 view.fill(|| ReplicationReport {
879 configured: true,
880 synced: 105,
881 failed: 40,
882 ..ReplicationReport::default()
883 });
884 let report = view.report();
885 assert!(report.configured);
886 assert_eq!(report.synced, 105);
887 // A second fill is ignored; one server has one replicator.
888 view.fill(ReplicationReport::default);
889 assert_eq!(view.report().synced, 105);
890 }
891}