Stop writing node records that describe the wrong thing (GH-3698)

src/Testing/CoreTests/Runtime/Agents/ejection_hysteresis_tests.cs

@@ -146,4 +146,50 @@ public async Task the_leadership_lock_holder_may_eject_a_stale_leader()
 
         await assertPeerDeleted(1);
     }
+
+    /// <summary>
+    /// GH-3698. The observer writes one DormantNodeEjected record per node it is handed, and it used to be
+    /// handed the whole stale list — including every node the checks above deliberately spare. A node that
+    /// blipped stale for a single tick and recovered was therefore recorded as ejected while still
+    /// heartbeating, which is exactly the contradiction reported against the production cluster: an
+    /// "ejected" record sitting next to a fresh health_check.
+    /// </summary>
+    [Fact]
+    public async Task records_no_ejection_for_a_peer_still_inside_the_hysteresis_window()
+    {
+        snapshotIs(Self(), Peer(stale: true));
+
+        await tickAsync(); // observed stale, but below the ejection threshold
+
+        await _persistence.DidNotReceive().DeleteAsync(_peerId, Arg.Any<int>());
+        await _runtime.Observer.DidNotReceive().StaleNodes(Arg.Any<IReadOnlyList<WolverineNode>>());
+    }
+
+    [Fact]
+    public async Task records_no_ejection_for_a_stale_leader_a_follower_may_not_delete()
+    {
+        _options.Durability.StaleNodeEjectionThreshold = 1;
+        _persistence.HasLeadershipLock().Returns(false);
+
+        snapshotIs(Self(), Peer(stale: true, isLeader: true));
+
+        await tickAsync();
+
+        await _persistence.DidNotReceive().DeleteAsync(_peerId, Arg.Any<int>());
+        await _runtime.Observer.DidNotReceive().StaleNodes(Arg.Any<IReadOnlyList<WolverineNode>>());
+    }
+
+    [Fact]
+    public async Task records_an_ejection_for_the_peer_it_actually_deleted()
+    {
+        _options.Durability.StaleNodeEjectionThreshold = 1;
+
+        snapshotIs(Self(), Peer(stale: true));
+
+        await tickAsync();
+
+        await assertPeerDeleted(1);
+        await _runtime.Observer.Received(1)
+            .StaleNodes(Arg.Is<IReadOnlyList<WolverineNode>>(x => x.Count == 1 && x[0].NodeId == _peerId));
+    }
 }

src/Testing/CoreTests/Runtime/Agents/node_reregisters_after_ejection.cs

@@ -156,4 +156,23 @@ public Task StopAsync(CancellationToken cancellationToken)
             return Task.CompletedTask;
         }
     }
+
+    /// <summary>
+    /// GH-3698. <c>NodeRecord.For</c> reads <c>Options.Durability.AssignedNodeNumber</c>, and the Balanced
+    /// start path called the observer one line BEFORE adopting the number <c>PersistAsync</c> handed back —
+    /// so every <c>NodeStarted</c> row in a Balanced cluster carried the per-process default,
+    /// <c>Guid.NewGuid().ToString().GetDeterministicHashCode()</c>: a random value unrelated to the node it
+    /// describes. The Solo path already had the two in the right order.
+    /// </summary>
+    [Fact]
+    public async Task the_node_started_record_sees_the_assigned_node_number()
+    {
+        int? numberWhenObserved = null;
+        _runtime.Observer.When(x => x.NodeStarted())
+            .Do(_ => numberWhenObserved = _options.Durability.AssignedNodeNumber);
+
+        await startedControllerAsync();
+
+        numberWhenObserved.ShouldBe(AssignedNumber);
+    }
 }

src/Wolverine/Runtime/Agents/NodeAgentController.HeartBeat.cs

@@ -302,7 +302,8 @@ await _persistence.AddAssignmentAsync(_runtime.Options.UniqueNodeId, LeaderUri,
 
         IsLeader = true;
 
-        _logger.LogInformation("Node {NodeNumber} successfully assumed leadership", _runtime.Options.UniqueNodeId);
+        _logger.LogInformation("Node {NodeNumber} ({NodeId}) successfully assumed leadership",
+            _runtime.Options.Durability.AssignedNodeNumber, _runtime.Options.UniqueNodeId);
 
         await _observer.AssumedLeadership();
 
@@ -335,6 +336,13 @@ private async Task ejectStaleNodes(IReadOnlyList<WolverineNode> staleNodes)
         // blip from destroying a live leader's row, ownership, and assignments.
         var holdsLeadership = _persistence.HasLeadershipLock();
 
+        // GH-3698: only the nodes actually deleted below get a DormantNodeEjected record. Reporting the whole
+        // stale list wrote one for every node the checks here deliberately SPARE -- this node itself, a
+        // leader a follower may not evict, and above all a node inside the GH-3604 hysteresis window. So a
+        // node that blipped stale for one tick and recovered was recorded as ejected while still heartbeating,
+        // which is exactly the contradiction reported: an "ejected" record alongside a fresh health_check.
+        var ejected = new List<WolverineNode>();
+
         // As per GH-1116, don't delete yourself!
         foreach (var staleNode in staleNodes.Where(x => x.AssignedNodeNumber != _runtime.DurabilitySettings.AssignedNodeNumber))
         {
@@ -355,11 +363,12 @@ private async Task ejectStaleNodes(IReadOnlyList<WolverineNode> staleNodes)
 
             await _persistence.DeleteAsync(staleNode.NodeId, staleNode.AssignedNodeNumber);
             _staleObservations.Remove(staleNode.NodeId);
+            ejected.Add(staleNode);
         }
 
-        if (staleNodes.Any())
+        if (ejected.Count != 0)
         {
-            await _observer.StaleNodes(staleNodes);
+            await _observer.StaleNodes(ejected);
         }
     }
 

src/Wolverine/Runtime/Agents/NodeAgentController.StartLocalProcessing.cs

@@ -17,11 +17,16 @@ public async Task<AgentCommands> StartLocalAgentProcessingAsync(WolverineOptions
         _capabilities = current.Capabilities.ToArray();
 
         current.AssignedNodeNumber = await _persistence.PersistAsync(current, _cancellation.Token);
-
-        await _observer.NodeStarted();
 
+        // GH-3698: adopt the assigned number BEFORE the observer writes the NodeStarted record. NodeRecord.For
+        // reads it straight off Options.Durability, which until this line still holds the per-process default
+        // -- Guid.NewGuid().ToString().GetDeterministicHashCode() -- so every NodeStarted row in a Balanced
+        // cluster carried a random node_number unrelated to the node it describes. The Solo path in
+        // StartLocally.cs already sets it first.
         _runtime.Options.Durability.AssignedNodeNumber = current.AssignedNodeNumber;
 
+        await _observer.NodeStarted();
+
         _logger.LogInformation("Starting agents for Node {NodeId} with assigned node id {Id} and Control Uri {ControlUri}",
             options.UniqueNodeId, current.AssignedNodeNumber,current.ControlUri);