use std::sync::Arc;
#[derive(Debug, Clone, Default, PartialEq, Eq)]
pub struct ReplicationReport {
pub configured: bool,
pub enqueued: u64,
pub synced: u64,
pub failed: u64,
pub bus_gaps: u64,
pub standbys: Vec<StandbyRow>,
pub refs: RefCoverage,
}
impl ReplicationReport {
pub fn alarming(&self) -> impl Iterator<Item = &StandbyRow> {
self.standbys.iter().filter(|row| row.verdict().alarming())
}
}
#[derive(Debug, Clone, Copy, Default, PartialEq, Eq)]
pub struct RefCoverage {
pub total: u64,
pub unmirrored: u64,
}
impl RefCoverage {
pub fn mirrorable(&self) -> u64 {
self.total.saturating_sub(self.unmirrored)
}
pub fn add(&mut self, other: RefCoverage) {
self.total = self.total.saturating_add(other.total);
self.unmirrored = self.unmirrored.saturating_add(other.unmirrored);
}
}
#[derive(Debug, Clone, Copy, Default, PartialEq, Eq)]
pub enum Verdict {
Never,
Stale,
Behind,
Working,
#[default]
Idle,
}
impl Verdict {
pub const fn word(self) -> &'static str {
match self {
Verdict::Never => "NEVER",
Verdict::Stale => "STALE",
Verdict::Behind => "BEHIND",
Verdict::Working => "syncing",
Verdict::Idle => "idle",
}
}
pub const fn alarming(self) -> bool {
matches!(self, Verdict::Never | Verdict::Stale | Verdict::Behind)
}
}
pub fn is_stale(
now_unix_ms: i64,
last_success_unix_ms: i64,
consecutive_failures: u32,
behind: bool,
stale_after_ms: i64,
) -> bool {
if last_success_unix_ms <= 0 {
return false;
}
let struggling = behind || consecutive_failures > 0;
struggling && now_unix_ms.saturating_sub(last_success_unix_ms) > stale_after_ms
}
#[derive(Debug, Clone, Default, PartialEq, Eq)]
pub struct StandbyRow {
pub name: String,
pub remote: String,
pub pending: u64,
pub consecutive_failures: u32,
pub last_error: String,
pub last_success_unix_ms: i64,
pub needs_full_resync: bool,
pub stale: bool,
pub in_flight: String,
pub outstanding_for_ms: i64,
pub behind: bool,
}
impl StandbyRow {
pub fn never_synced(&self) -> bool {
self.last_success_unix_ms <= 0
}
pub fn verdict(&self) -> Verdict {
if self.never_synced() {
Verdict::Never
} else if self.stale {
Verdict::Stale
} else if self.behind {
Verdict::Behind
} else if self.pending > 0 {
Verdict::Working
} else {
Verdict::Idle
}
}
pub fn since_last_success(&self, now_unix_ms: i64) -> Option<i64> {
if self.never_synced() {
return None;
}
Some(((now_unix_ms - self.last_success_unix_ms).max(0)) / 1000)
}
pub fn describe(&self, synced: u64, failed: u64, now_unix_ms: i64) -> String {
let word = match self.verdict() {
Verdict::Behind | Verdict::Working => String::new(),
verdict => format!(" {}", verdict.word()),
};
let head = match self.since_last_success(now_unix_ms) {
Some(secs) => format!(
"{} synced {synced} failed {failed} last {} ago{word}",
self.name,
hms(secs),
),
None => format!(
"{} synced {synced} failed {failed} last successful replication: NEVER",
self.name
),
};
format!("{head}{}", self.outstanding())
}
pub fn outstanding(&self) -> String {
if self.pending == 0 && self.outstanding_for_ms <= 0 {
return String::new();
}
let mut tail = format!(" pending {}", self.pending);
if !self.in_flight.is_empty() {
tail.push_str(&format!(" in flight {}", self.in_flight));
}
if self.outstanding_for_ms > 0 {
tail.push_str(&format!(
" outstanding {}",
hms(self.outstanding_for_ms / 1000)
));
}
if self.behind {
tail.push_str(" BEHIND");
}
tail
}
}
pub fn hms(secs: i64) -> String {
let secs = secs.max(0);
format!(
"{:02}:{:02}:{:02}",
secs / 3600,
(secs % 3600) / 60,
secs % 60
)
}
pub const STALENESS_FACTOR: u32 = 10;
pub const BEHIND_AFTER_RETRY_MAX: u32 = 1;
#[cfg(feature = "replication")]
pub fn report(replicator: &crate::mirror::Replicator) -> ReplicationReport {
let counters = replicator.counters();
let now = gunnar_grpc::bus::now_unix_ms();
let stale_after_ms =
(replicator.config().retry_max_ms as i64).saturating_mul(i64::from(STALENESS_FACTOR));
let behind_after_ms = (replicator.config().retry_max_ms as i64)
.saturating_mul(i64::from(BEHIND_AFTER_RETRY_MAX));
ReplicationReport {
configured: true,
enqueued: counters.enqueued,
synced: counters.succeeded,
failed: counters.failed,
bus_gaps: counters.bus_gaps,
refs: RefCoverage::default(),
standbys: replicator
.status()
.into_iter()
.map(|status| {
let last = status.last_success_unix_ms.unwrap_or(0);
let outstanding_for_ms = status
.outstanding_for
.map(|d| d.as_millis().min(i64::MAX as u128) as i64)
.unwrap_or(0);
let behind = outstanding_for_ms > behind_after_ms;
StandbyRow {
stale: is_stale(
now,
last,
status.consecutive_failures,
behind,
stale_after_ms,
),
behind,
in_flight: status.in_flight.unwrap_or_default(),
outstanding_for_ms,
name: status.name,
remote: status.remote,
pending: status.pending as u64,
consecutive_failures: status.consecutive_failures,
last_error: status.last_error.unwrap_or_default(),
last_success_unix_ms: last,
needs_full_resync: status.needs_full_resync,
}
})
.collect(),
}
}
#[derive(Clone, Default)]
pub struct ReplicationView {
source: Arc<std::sync::OnceLock<Box<dyn Fn() -> ReplicationReport + Send + Sync>>>,
}
impl ReplicationView {
pub fn new() -> Self {
Self::default()
}
pub fn fill(&self, source: impl Fn() -> ReplicationReport + Send + Sync + 'static) {
let _ = self.source.set(Box::new(source));
}
pub fn report(&self) -> ReplicationReport {
match self.source.get() {
Some(source) => source(),
None => ReplicationReport::default(),
}
}
}
impl std::fmt::Debug for ReplicationView {
fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
f.debug_struct("ReplicationView")
.field("filled", &self.source.get().is_some())
.finish()
}
}
pub const STALENESS_POLL: std::time::Duration = std::time::Duration::from_secs(30);
pub fn spawn_staleness_watch(
view: ReplicationView,
bus: std::sync::Arc<gunnar_grpc::EventBus>,
) -> tokio::task::JoinHandle<()> {
tokio::spawn(async move {
let mut alarmed: Vec<String> = Vec::new();
loop {
let report = view.report();
for row in &report.standbys {
let verdict = row.verdict();
let alarming = verdict.alarming();
let was = alarmed.iter().any(|name| name == &row.name);
if alarming && !was {
alarmed.push(row.name.clone());
let reason = if verdict == Verdict::Behind {
tracing::warn!(
target: "gunnar::replication",
event = "replication.behind",
standby = %row.name,
remote = %row.remote,
pending = row.pending,
in_flight = %row.in_flight,
outstanding_for_ms = row.outstanding_for_ms,
"this standby has had work outstanding for longer than the retry \
ceiling. It may be unreachable, or one repository may simply be \
large; the row names which."
);
format!(
"{} repository(ies) outstanding for {}, longer than the retry \
ceiling{}",
row.pending,
hms(row.outstanding_for_ms / 1000),
if row.in_flight.is_empty() {
String::new()
} else {
format!("; in flight: {}", row.in_flight)
}
)
} else if verdict == Verdict::Never {
tracing::error!(
target: "gunnar::replication",
event = "replication.never_synced",
standby = %row.name,
remote = %row.remote,
failed = report.failed,
"LAST SUCCESSFUL REPLICATION: NEVER. This standby has never taken a \
single byte, so there is no second copy of anything on it. Check its \
address, its host key and the deploy key in replication.json."
);
"last successful replication: NEVER — this standby has never taken a byte"
.to_owned()
} else {
tracing::warn!(
target: "gunnar::replication",
event = "replication.stale",
standby = %row.name,
remote = %row.remote,
last_success_unix_ms = row.last_success_unix_ms,
"this standby has not taken a byte for more than {STALENESS_FACTOR}x \
the retry ceiling; its copy is behind by an unknown amount"
);
format!(
"no successful replication for more than {STALENESS_FACTOR}x the \
retry ceiling"
)
};
bus.publish(gunnar_proto::event::Payload::ReplicationFailed(
gunnar_proto::ReplicationFailed {
repo: None,
target: row.name.clone(),
remote_url: row.remote.clone(),
attempt: row.consecutive_failures,
retry_in_ms: 0,
reason,
needs_full_resync: row.needs_full_resync || row.never_synced(),
},
));
} else if !alarming && was {
alarmed.retain(|name| name != &row.name);
tracing::info!(
target: "gunnar::replication",
event = "replication.recovered",
standby = %row.name,
"this standby is taking bytes again"
);
}
}
alarmed.retain(|name| report.standbys.iter().any(|row| &row.name == name));
tokio::time::sleep(STALENESS_POLL).await;
}
})
}
#[cfg(test)]
mod tests {
use super::*;
#[test]
fn a_standby_that_has_never_synced_says_so_in_those_words() {
let never = StandbyRow {
name: "standby".into(),
last_success_unix_ms: 0,
stale: true,
..StandbyRow::default()
};
let line = never.describe(0, 8, 1_000_000);
assert!(
line.contains("last successful replication: NEVER"),
"a standby that has never synced must say so: {line}"
);
assert!(never.never_synced());
assert_eq!(never.since_last_success(1_000_000), None);
let worked = StandbyRow {
name: "standby".into(),
last_success_unix_ms: 997_000,
..StandbyRow::default()
};
let line = worked.describe(105, 40, 1_000_000);
assert!(!line.contains("NEVER"), "{line}");
assert!(line.contains("synced 105"), "{line}");
assert!(line.contains("failed 40"), "{line}");
assert!(line.contains("last 00:00:03 ago"), "{line}");
}
#[test]
fn a_standby_with_work_stuck_on_it_says_so_long_before_it_is_stale() {
let now = 1_000_000_000_000i64;
let dead = StandbyRow {
name: "standby-fi-hel1".into(),
pending: 1,
in_flight: "alice/linux-mirror".into(),
outstanding_for_ms: 60_000,
last_success_unix_ms: now - 61_000,
stale: false,
behind: false,
..StandbyRow::default()
};
let line = dead.describe(105, 0, now);
assert!(
line.contains("pending 1") && line.contains("in flight alice/linux-mirror"),
"the row must name the outstanding work, or `pending 0 failures 0` is all an \
operator sees: {line}"
);
assert!(
line.contains("outstanding 00:01:00"),
"the row must carry the clock that is still ticking: {line}"
);
let behind = StandbyRow {
outstanding_for_ms: 400_000,
behind: true,
..dead.clone()
};
assert!(behind.describe(105, 0, now).contains("BEHIND"));
let report = ReplicationReport {
configured: true,
standbys: vec![dead.clone(), behind.clone()],
..ReplicationReport::default()
};
let alarming: Vec<&str> = report.alarming().map(|r| r.in_flight.as_str()).collect();
assert_eq!(
alarming.len(),
1,
"exactly the BEHIND row must alarm; a row that alarmed on any outstanding work \
would fire on every ordinary push"
);
let idle = StandbyRow {
name: "standby".into(),
last_success_unix_ms: now - 3_000,
..StandbyRow::default()
};
assert_eq!(idle.outstanding(), "");
assert_eq!(
idle.describe(105, 0, now),
"standby synced 105 failed 0 last 00:00:03 ago idle"
);
}
#[test]
fn an_idle_standby_is_not_stale_and_a_stuck_one_still_is() {
let hour = 3_600_000i64;
let now = 1_000_000_000_000i64;
let stale_after = 50 * 60 * 1000;
assert!(
!is_stale(now, now - 6 * hour, 0, false, stale_after),
"a standby with nothing to do read STALE — this is the measured lie"
);
let quiet = StandbyRow {
name: "standby".into(),
last_success_unix_ms: now - 6 * hour,
..StandbyRow::default()
};
assert_eq!(quiet.verdict(), Verdict::Idle);
assert!(!quiet.verdict().alarming());
assert!(quiet.describe(105, 0, now).contains(" idle"));
assert!(
is_stale(now, now - 6 * hour, 0, true, stale_after),
"a standby with work stuck on it for hours must still be STALE"
);
assert!(is_stale(now, now - 6 * hour, 3, false, stale_after));
assert!(!is_stale(now, now - 60_000, 3, true, stale_after));
assert!(!is_stale(now, now - 6 * hour, 0, false, stale_after));
let stuck = StandbyRow {
name: "standby".into(),
pending: 1,
in_flight: "alice/korp".into(),
outstanding_for_ms: 6 * hour,
last_success_unix_ms: now - 6 * hour,
stale: true,
behind: true,
..StandbyRow::default()
};
assert_eq!(stuck.verdict(), Verdict::Stale);
assert!(stuck.verdict().alarming());
assert!(stuck.describe(105, 4, now).contains("STALE"));
let never = StandbyRow {
name: "standby".into(),
..StandbyRow::default()
};
assert_eq!(never.verdict(), Verdict::Never);
assert!(never.verdict().alarming());
assert!(!is_stale(now, 0, 0, false, stale_after));
let working = StandbyRow {
name: "standby".into(),
pending: 1,
outstanding_for_ms: 900,
last_success_unix_ms: now - 3_000,
..StandbyRow::default()
};
assert_eq!(working.verdict(), Verdict::Working);
assert!(!working.verdict().alarming());
}
#[test]
fn ref_coverage_counts_zero_as_a_number() {
let all_carried = RefCoverage {
total: 20,
unmirrored: 0,
};
assert_eq!(all_carried.mirrorable(), 20);
let korp = RefCoverage {
total: 144,
unmirrored: 94,
};
assert_eq!(korp.mirrorable(), 50, "the number `replication list` prints");
let mut server = RefCoverage::default();
server.add(all_carried);
server.add(korp);
assert_eq!((server.total, server.unmirrored), (164, 94));
}
#[test]
fn an_unfilled_view_reports_nothing_configured() {
let view = ReplicationView::new();
let report = view.report();
assert!(!report.configured);
assert!(report.standbys.is_empty());
}
#[test]
fn a_filled_view_reports_what_the_source_says() {
let view = ReplicationView::new();
view.fill(|| ReplicationReport {
configured: true,
synced: 105,
failed: 40,
..ReplicationReport::default()
});
let report = view.report();
assert!(report.configured);
assert_eq!(report.synced, 105);
view.fill(ReplicationReport::default);
assert_eq!(view.report().synced, 105);
}
}