remake: log expired and missed votes

2 files changed, 61 insertions, 9 deletions

diff --git a/src/remake/local.rs b/src/remake/local.rs
index e94657c..e8fc9eb 100644
--- a/src/remake/local.rs
+++ b/src/remake/local.rs
@@ -60,6 +60,9 @@ struct Inner {
     coordinating: HashSet<String>,
     /// The remake this node is about to vote for, and when (`vote_due`).
     vote_due: Option<(String, UnixMillis)>,
+    /// Remakes this node could have voted for but saw expire first (`vote::cast`), each
+    /// logged once.
+    missed: HashSet<String>,
     /// The actors this node writes or wrote with in the current document: this run's,
     /// and those of earlier runs it knows of (`--document-file`). Its own writes, for a
     /// rejoin. A switch or rejoin starts the list over with the new document's actor, so
@@ -215,6 +218,12 @@ impl RemakeState {
         }
     }
 
+    /// Notes that this node saw `remake` expire without having voted for it: true the
+    /// first time.
+    pub(crate) fn missed(&self, remake: &str) -> bool {
+        self.lock().missed.insert(remake.to_owned())
+    }
+
     fn lock(&self) -> MutexGuard<'_, Inner> {
         self.inner.lock_or_recover()
     }
diff --git a/src/remake/vote.rs b/src/remake/vote.rs
index e5f8dbe..6604ff6 100644
--- a/src/remake/vote.rs
+++ b/src/remake/vote.rs
@@ -240,6 +240,33 @@ pub(crate) fn choice(
         .map(|(id, _)| id.clone())
 }
 
+/// Undecided remakes of `epoch` with `me` in their electorate that expired (by `now`)
+/// before `me` voted for them.
+fn missed(
+    me: &str,
+    epoch: &EpochRecord,
+    all: &[(String, Record)],
+    register: &Register,
+    now: UnixMillis,
+    grace: u64,
+) -> Vec<String> {
+    let voted = |id: &str| {
+        register
+            .get(me)
+            .is_some_and(|votes| votes.iter().any(|vote| vote.remake == id))
+    };
+    all.iter()
+        .filter(|(id, record)| {
+            &record.proposal.from_epoch == epoch
+                && record.decision.is_none()
+                && record.phase(now, grace) == Phase::Expired
+                && record.proposal.electorate.iter().any(|member| member == me)
+                && !voted(id)
+        })
+        .map(|(id, _)| id.clone())
+        .collect()
+}
+
 /// Votes for a remake of the local epoch if this node should. Called by the remake
 /// worker whenever the records change (and on its timer).
 pub(super) async fn cast<H: Host>(host: &H) {
@@ -254,20 +281,36 @@ pub(super) async fn cast<H: Host>(host: &H) {
     // Usually there is nothing to vote on: look first, without writing.
     let (voter, wanted) = (me.clone(), epoch.clone());
     let now = host.now_millis();
-    let due = host
+    let (due, missed) = host
         .read_doc(move |doc| {
             let all = records::load_all(doc);
             let register = records::load_register(doc);
-            let id = choice(&voter, &wanted, &all, &register, started, now, grace)?;
-            let (_, record) = all.iter().find(|(other, _)| *other == id)?;
-            // Enough voted already: ours would only be one more change for everyone.
-            if tally(&id, record, &all, &register).reached() {
-                return None;
-            }
-            let content = record.proposal.content.clone();
-            Some((id, content))
+            let missed = missed(&voter, &wanted, &all, &register, now, grace);
+            let due =
+                choice(&voter, &wanted, &all, &register, started, now, grace).and_then(|id| {
+                    let (_, record) = all.iter().find(|(other, _)| *other == id)?;
+                    // Enough voted already: ours would only be one more change for everyone.
+                    if tally(&id, record, &all, &register).reached() {
+                        return None;
+                    }
+                    let content = record.proposal.content.clone();
+                    Some((id, content))
+                });
+            (due, missed)
         })
         .await;
+    for id in missed {
+        if host.remake().missed(&id) {
+            // By this node's clock: one ahead sees remakes expire that others still vote
+            // on, and on a small swarm, its vote missing keeps them from a majority.
+            let skew = host.clock_skew().await;
+            if skew.off {
+                warn!(remake = %id, offset_ms = skew.offset_ms, "Didn't vote for a remake: it expired by this node's clock, which is off from its peers'");
+            } else {
+                info!(remake = %id, "Didn't vote for a remake: it expired before this node voted");
+            }
+        }
+    }
     let Some((chosen, content)) = due else {
         return;
     };