public void Apply(TransactionOperationContext context, long uptoInclusive, Leader leader, ServerStore serverStore) { Debug.Assert(context.Transaction != null); var lastAppliedIndex = _parent.GetLastCommitIndex(context); for (var index = lastAppliedIndex + 1; index <= uptoInclusive; index++) { var cmd = _parent.GetEntry(context, index, out RachisEntryFlags flags); if (cmd == null || flags == RachisEntryFlags.Invalid) { throw new InvalidOperationException("Expected to apply entry " + index + " but it isn't stored"); } if (flags != RachisEntryFlags.StateMachineCommand) { continue; } Apply(context, cmd, index, leader, serverStore); } var term = _parent.GetTermForKnownExisting(context, uptoInclusive); _parent.SetLastCommitIndex(context, uptoInclusive, term); }
public long Apply(ClusterOperationContext context, long uptoInclusive, Leader leader, ServerStore serverStore, Stopwatch duration) { Debug.Assert(context.Transaction != null); var lastAppliedIndex = _parent.GetLastCommitIndex(context); var maxTimeAllowedToWaitForApply = _parent.Timeout.TimeoutPeriod / 4; for (var index = lastAppliedIndex + 1; index <= uptoInclusive; index++) { var cmd = _parent.GetEntry(context, index, out RachisEntryFlags flags); if (cmd == null || flags == RachisEntryFlags.Invalid) { throw new InvalidOperationException("Expected to apply entry " + index + " but it isn't stored"); } lastAppliedIndex = index; if (flags != RachisEntryFlags.StateMachineCommand) { _parent.LogHistory.UpdateHistoryLog(context, index, _parent.CurrentTerm, cmd, null, null); var currentIndex = index; context.Transaction.InnerTransaction.LowLevelTransaction.OnDispose += t => { if (t is LowLevelTransaction llt && llt.Committed) { serverStore.Cluster.NotifyAndSetCompleted(currentIndex); } }; continue; } Apply(context, cmd, index, leader, serverStore); if (duration.ElapsedMilliseconds >= maxTimeAllowedToWaitForApply) { // we don't want to spend so much time applying commands that we will time out the leader // so we time this from the follower perspective and abort after applying a single command // or 25% of the time has already passed break; } } var term = _parent.GetTermForKnownExisting(context, lastAppliedIndex); _parent.SetLastCommitIndex(context, lastAppliedIndex, term); return(lastAppliedIndex); }
private void OnVoterConfirmation() { TransactionOperationContext context; if (_hasNewTopology.Lower()) { ClusterTopology clusterTopology; using (_engine.ContextPool.AllocateOperationContext(out context)) using (context.OpenReadTransaction()) { clusterTopology = _engine.GetTopology(context); } if (clusterTopology.Contains(_engine.LeaderTag) == false) { TaskExecutor.CompleteAndReplace(ref _newEntriesArrived); _engine.SetNewState(RachisState.Passive, this, Term, "I was kicked out of the cluster and moved to passive mode"); return; } RefreshAmbassadors(clusterTopology); } var maxIndexOnQuorum = GetMaxIndexOnQuorum(VotersMajority); if (_lastCommit >= maxIndexOnQuorum || maxIndexOnQuorum == 0) { return; // nothing to do here } bool changedFromLeaderElectToLeader; using (_engine.ContextPool.AllocateOperationContext(out context)) using (context.OpenWriteTransaction()) { _lastCommit = _engine.GetLastCommitIndex(context); if (_lastCommit >= maxIndexOnQuorum || maxIndexOnQuorum == 0) { return; // nothing to do here } if (_engine.GetTermForKnownExisting(context, maxIndexOnQuorum) < Term) { return;// can't commit until at least one entry from our term has been published } changedFromLeaderElectToLeader = _engine.TakeOffice(); maxIndexOnQuorum = _engine.Apply(context, maxIndexOnQuorum, this, Stopwatch.StartNew()); context.Transaction.Commit(); _lastCommit = maxIndexOnQuorum; } foreach (var kvp in _entries) { if (kvp.Key > _lastCommit) { continue; } if (_entries.TryRemove(kvp.Key, out CommandState value)) { TaskExecutor.Execute(o => { var tuple = (CommandState)o; if (tuple.OnNotify != null) { tuple.OnNotify(tuple.TaskCompletionSource); return; } tuple.TaskCompletionSource.TrySetResult((tuple.CommandIndex, tuple.Result)); }, value); } } if (_entries.Count != 0) { // we have still items to process, run them in 1 node cluster // and speed up the followers ambassadors if they can _newEntry.Set(); } if (changedFromLeaderElectToLeader) { _engine.LeaderElectToLeaderChanged(); } }
/// <summary> /// This method may run for a long while, as we are trying to get agreement /// from a majority of the cluster /// </summary> private void Run() { try { while (_candidate.Running && _disposed == false) { try { Stream stream; try { using (_engine.ContextPool.AllocateOperationContext(out TransactionOperationContext context)) { stream = _engine.ConnectToPeer(_url, _certificate, context).Result; } if (_candidate.Running == false) { break; } } catch (Exception e) { Status = AmbassadorStatus.FailedToConnect; StatusMessage = $"Failed to connect with {_tag}.{Environment.NewLine} " + e.Message; if (_engine.Log.IsInfoEnabled) { _engine.Log.Info($"CandidateAmbassador {_engine.Tag}: Failed to connect to remote peer: " + _url, e); } // wait a bit _candidate.WaitForChangeInState(); continue; // we'll retry connecting } Status = AmbassadorStatus.Connected; StatusMessage = $"Connected to {_tag}"; Connection = new RemoteConnection(_tag, _engine.Tag, stream); using (_engine.ContextPool.AllocateOperationContext(out TransactionOperationContext context)) { ClusterTopology topology; long lastLogIndex; long lastLogTerm; using (context.OpenReadTransaction()) { topology = _engine.GetTopology(context); lastLogIndex = _engine.GetLastEntryIndex(context); lastLogTerm = _engine.GetTermForKnownExisting(context, lastLogIndex); } Debug.Assert(topology.TopologyId != null); Connection.Send(context, new RachisHello { TopologyId = topology.TopologyId, DebugSourceIdentifier = _engine.Tag, DebugDestinationIdentifier = _tag, InitialMessageType = InitialMessageType.RequestVote }); while (_candidate.Running) { RequestVoteResponse rvr; var currentElectionTerm = _candidate.ElectionTerm; var engineCurrentTerm = _engine.CurrentTerm; if (_candidate.IsForcedElection == false || _candidate.RunRealElectionAtTerm != currentElectionTerm) { Connection.Send(context, new RequestVote { Source = _engine.Tag, Term = currentElectionTerm, IsForcedElection = false, IsTrialElection = true, LastLogIndex = lastLogIndex, LastLogTerm = lastLogTerm }); rvr = Connection.Read <RequestVoteResponse>(context); if (rvr.Term > currentElectionTerm) { var message = $"Candidate ambassador {_engine.Tag}: found election term {rvr.Term} that is higher than ours {currentElectionTerm}"; // we need to abort the current elections _engine.SetNewState(RachisState.Follower, null, engineCurrentTerm, message); if (_engine.Log.IsInfoEnabled) { _engine.Log.Info($"CandidateAmbassador {_engine.Tag}: {message}"); } _engine.FoundAboutHigherTerm(rvr.Term); throw new InvalidOperationException(message); } NotInTopology = rvr.NotInTopology; if (rvr.VoteGranted == false) { if (_engine.Log.IsInfoEnabled) { _engine.Log.Info($"CandidateAmbassador {_engine.Tag}: Got a negative response from {_tag} reason: {rvr.Message}"); } // we go a negative response here, so we can't proceed // we'll need to wait until the candidate has done something, like // change term or given up _candidate.WaitForChangeInState(); continue; } TrialElectionWonAtTerm = rvr.Term; _candidate.WaitForChangeInState(); } Connection.Send(context, new RequestVote { Source = _engine.Tag, Term = currentElectionTerm, IsForcedElection = _candidate.IsForcedElection, IsTrialElection = false, LastLogIndex = lastLogIndex, LastLogTerm = lastLogTerm }); rvr = Connection.Read <RequestVoteResponse>(context); if (rvr.Term > currentElectionTerm) { var message = $"Candidate ambassador {_engine.Tag}: found election term {rvr.Term} that is higher than ours {currentElectionTerm}"; if (_engine.Log.IsInfoEnabled) { _engine.Log.Info($"CandidateAmbassador {_engine.Tag}: {message}"); } // we need to abort the current elections _engine.SetNewState(RachisState.Follower, null, engineCurrentTerm, message); _engine.FoundAboutHigherTerm(rvr.Term); throw new InvalidOperationException(message); } NotInTopology = rvr.NotInTopology; if (rvr.VoteGranted == false) { if (_engine.Log.IsInfoEnabled) { _engine.Log.Info($"CandidateAmbassador {_engine.Tag}: Got a negative response from {_tag} reason: {rvr.Message}"); } // we go a negative response here, so we can't proceed // we'll need to wait until the candidate has done something, like // change term or given up _candidate.WaitForChangeInState(); continue; } RealElectionWonAtTerm = rvr.Term; _candidate.WaitForChangeInState(); } SendElectionResult(); } } catch (OperationCanceledException) { Status = AmbassadorStatus.Closed; StatusMessage = "Closed"; SendElectionResult(); break; } catch (ObjectDisposedException) { Status = AmbassadorStatus.Closed; StatusMessage = "Closed"; SendElectionResult(); break; } catch (AggregateException ae) when(ae.InnerException is OperationCanceledException || ae.InnerException is ObjectDisposedException) { Status = AmbassadorStatus.Closed; StatusMessage = "Closed"; SendElectionResult(); break; } catch (Exception e) { Status = AmbassadorStatus.FailedToConnect; StatusMessage = $"Failed to get vote from {_tag}.{Environment.NewLine}" + e.Message; if (_engine.Log.IsInfoEnabled) { _engine.Log.Info($"CandidateAmbassador {_engine.Tag}: Failed to get vote from remote peer url={_url} tag={_tag}", e); } Connection?.Dispose(); _candidate.WaitForChangeInState(); } } } catch (Exception e) { Status = AmbassadorStatus.FailedToConnect; StatusMessage = $"Failed to talk to {_url}.{Environment.NewLine}" + e; if (_engine.Log.IsInfoEnabled) { _engine.Log.Info("Failed to talk to remote peer: " + _url, e); } } finally { if (_candidate.ElectionResult != ElectionResult.Won) { Connection?.Dispose(); } } }
public void HandleVoteRequest() { try { while (true) { using (_engine.ContextPool.AllocateOperationContext(out TransactionOperationContext context)) { var rv = _connection.Read <RequestVote>(context); if (_engine.Log.IsInfoEnabled) { var election = rv.IsTrialElection ? "Trial" : "Real"; _engine.Log.Info($"Received ({election}) 'RequestVote' from {rv.Source}: Election is {rv.ElectionResult} in term {rv.Term} while our current term is {_engine.CurrentTerm}, " + $"Forced election is {rv.IsForcedElection}. (Sent from:{rv.SendingThread})"); } //We are getting a request to vote for our known leader if (_engine.LeaderTag == rv.Source) { _engine.LeaderTag = null; //If we are followers we want to drop the connection with the leader right away. //We shouldn't be in any other state since if we are candidate our leaderTag should be null but its safer to verify. if (_engine.CurrentState == RachisState.Follower) { _engine.SetNewState(RachisState.Follower, null, _engine.CurrentTerm, $"We got a vote request from our leader {rv.Source} so we switch to leaderless state."); } } ClusterTopology clusterTopology; long lastIndex; long lastTerm; string whoGotMyVoteIn; long lastVotedTerm; using (context.OpenReadTransaction()) { lastIndex = _engine.GetLastEntryIndex(context); lastTerm = _engine.GetTermForKnownExisting(context, lastIndex); (whoGotMyVoteIn, lastVotedTerm) = _engine.GetWhoGotMyVoteIn(context, rv.Term); clusterTopology = _engine.GetTopology(context); } // this should be only the case when we where once in a cluster, then we were brought down and our data was wiped. if (clusterTopology.TopologyId == null) { _connection.Send(context, new RequestVoteResponse { Term = rv.Term, VoteGranted = true, Message = "I might vote for you, because I'm not part of any cluster." }); continue; } if (clusterTopology.Members.ContainsKey(rv.Source) == false && clusterTopology.Promotables.ContainsKey(rv.Source) == false && clusterTopology.Watchers.ContainsKey(rv.Source) == false) { _connection.Send(context, new RequestVoteResponse { Term = _engine.CurrentTerm, VoteGranted = false, // we only report to the node asking for our vote if we are the leader, this gives // the oust node a authorotative confirmation that they were removed from the cluster NotInTopology = _engine.CurrentState == RachisState.Leader, Message = $"Node {rv.Source} is not in my topology, cannot vote for it" }); _connection.Dispose(); return; } var currentTerm = _engine.CurrentTerm; if (rv.Term == currentTerm && rv.ElectionResult == ElectionResult.Won) { _electionWon = true; if (Follower.CheckIfValidLeader(_engine, _connection, out var negotiation)) { var follower = new Follower(_engine, negotiation.Term, _connection); follower.AcceptConnection(negotiation); } return; } if (rv.ElectionResult != ElectionResult.InProgress) { _connection.Dispose(); return; } if (rv.Term <= _engine.CurrentTerm) { _connection.Send(context, new RequestVoteResponse { Term = _engine.CurrentTerm, VoteGranted = false, Message = "My term is higher or equals to yours" }); _connection.Dispose(); return; } if (rv.IsForcedElection == false && ( _engine.CurrentState == RachisState.Leader || _engine.CurrentState == RachisState.LeaderElect ) ) { _connection.Send(context, new RequestVoteResponse { Term = _engine.CurrentLeader.Term, VoteGranted = false, Message = "I'm a leader in good standing, coup will be resisted" }); _connection.Dispose(); return; } if (whoGotMyVoteIn != null && whoGotMyVoteIn != rv.Source) { _connection.Send(context, new RequestVoteResponse { Term = _engine.CurrentTerm, VoteGranted = false, Message = $"Already voted in {rv.LastLogTerm}, for {whoGotMyVoteIn}" }); continue; } if (lastVotedTerm > rv.Term) { _connection.Send(context, new RequestVoteResponse { Term = _engine.CurrentTerm, VoteGranted = false, Message = $"Already voted for another node in {lastVotedTerm}" }); continue; } if (lastTerm > rv.LastLogTerm) { // we aren't going to vote for this guy, but we need to check if it is more up to date // in the state of the cluster than we are if (rv.Term > _engine.CurrentTerm + 1) { // trail election is often done on the current term + 1, but if there is any // election on a term that is greater than the current term plus one, we should // consider this an indication that the cluster was able to move past our term // and update the term accordingly using (context.OpenWriteTransaction()) { // double checking things under the transaction lock if (rv.Term > _engine.CurrentTerm + 1) { _engine.CastVoteInTerm(context, rv.Term - 1, null, "Noticed that the term in the cluster grew beyond what I was familiar with, increasing it"); } context.Transaction.Commit(); } } _connection.Send(context, new RequestVoteResponse { Term = _engine.CurrentTerm, VoteGranted = false, Message = $"My last log entry is of term {lastTerm} / {lastIndex} while yours is {rv.LastLogTerm}, so I'm more up to date" }); continue; } if (rv.IsTrialElection) { if (_engine.Timeout.ExpiredLastDeferral(_engine.ElectionTimeout.TotalMilliseconds / 2, out string currentLeader) == false && string.IsNullOrEmpty(currentLeader) == false) // if we are leaderless we can't refuse to cast our vote. { _connection.Send(context, new RequestVoteResponse { Term = _engine.CurrentTerm, VoteGranted = false, Message = $"My leader {currentLeader} is keeping me up to date, so I don't want to vote for you" }); continue; } if (lastTerm == rv.LastLogTerm && lastIndex > rv.LastLogIndex) { _connection.Send(context, new RequestVoteResponse { Term = _engine.CurrentTerm, VoteGranted = false, Message = $"My log {lastIndex} is more up to date than yours {rv.LastLogIndex}" }); continue; } _connection.Send(context, new RequestVoteResponse { Term = rv.Term, VoteGranted = true, Message = "I might vote for you" }); continue; } HandleVoteResult result; using (context.OpenWriteTransaction()) { result = ShouldGrantVote(context, lastIndex, rv, lastTerm); if (result.DeclineVote == false) { _engine.CastVoteInTerm(context, rv.Term, rv.Source, "Casting vote as elector"); context.Transaction.Commit(); } } if (result.DeclineVote) { _connection.Send(context, new RequestVoteResponse { Term = result.VotedTerm, VoteGranted = false, Message = result.DeclineReason }); } else { _connection.Send(context, new RequestVoteResponse { Term = rv.Term, VoteGranted = true, Message = "I've voted for you" }); } } } } catch (OperationCanceledException) { } catch (ObjectDisposedException) { } catch (AggregateException ae) when(ae.InnerException is OperationCanceledException || ae.InnerException is ObjectDisposedException) { } catch (Exception e) { if (_engine.Log.IsInfoEnabled) { _engine.Log.Info($"Failed to talk to candidate: {_engine.Tag}", e); } } finally { if (_electionWon == false) { _connection.Dispose(); } } }
private bool NegotiateMatchEntryWithLeaderAndApplyEntries(ClusterOperationContext context, RemoteConnection connection, LogLengthNegotiation negotiation) { long minIndex; long maxIndex; long midpointTerm; long midpointIndex; using (context.OpenReadTransaction()) { minIndex = _engine.GetFirstEntryIndex(context); if (minIndex == 0) // no entries at all { RequestAllEntries(context, connection, "No entries at all here, give me everything from the start"); return(true); // leader will know where to start from here } maxIndex = Math.Min( _engine.GetLastEntryIndex(context), // max negotiation.PrevLogIndex ); midpointIndex = (maxIndex + minIndex) / 2; midpointTerm = _engine.GetTermForKnownExisting(context, midpointIndex); } while ((midpointTerm == negotiation.PrevLogTerm && midpointIndex == negotiation.PrevLogIndex) == false) { _engine.Timeout.Defer(_connection.Source); _engine.ValidateTerm(_term); if (midpointIndex == negotiation.PrevLogIndex && midpointTerm != negotiation.PrevLogTerm) { // our appended entries has been diverged, same index with different terms. if (CanHandleLogDivergence(context, negotiation, ref midpointIndex, ref midpointTerm, ref minIndex, ref maxIndex) == false) { RequestAllEntries(context, connection, "all my entries are invalid, will require snapshot."); return(true); } } connection.Send(context, new LogLengthNegotiationResponse { Status = LogLengthNegotiationResponse.ResponseStatus.Negotiation, Message = $"Term/Index mismatch from leader, need to figure out at what point the logs match, range: {maxIndex} - {minIndex} | {midpointIndex} in term {midpointTerm}", CurrentTerm = _term, MaxIndex = maxIndex, MinIndex = minIndex, MidpointIndex = midpointIndex, MidpointTerm = midpointTerm }); negotiation = connection.Read <LogLengthNegotiation>(context); _engine.Timeout.Defer(_connection.Source); if (negotiation.Truncated) { if (_engine.Log.IsInfoEnabled) { _engine.Log.Info($"{ToString()}: Got a truncated response from the leader will request all entries"); } RequestAllEntries(context, connection, "We have entries that are already truncated at the leader, will ask for full snapshot"); return(true); } using (context.OpenReadTransaction()) { if (_engine.GetTermFor(context, negotiation.PrevLogIndex) == negotiation.PrevLogTerm) { minIndex = Math.Min(midpointIndex + 1, maxIndex); } else { maxIndex = Math.Max(midpointIndex - 1, minIndex); } } midpointIndex = (maxIndex + minIndex) / 2; using (context.OpenReadTransaction()) midpointTerm = _engine.GetTermForKnownExisting(context, midpointIndex); } if (_engine.Log.IsInfoEnabled) { _engine.Log.Info($"{ToString()}: agreed upon last matched index = {midpointIndex} on term = {midpointTerm}"); } connection.Send(context, new LogLengthNegotiationResponse { Status = LogLengthNegotiationResponse.ResponseStatus.Acceptable, Message = $"Found a log index / term match at {midpointIndex} with term {midpointTerm}", CurrentTerm = _term, LastLogIndex = midpointIndex, }); return(false); }
public void HandleVoteRequest() { try { while (true) { using (_engine.ContextPool.AllocateOperationContext(out TransactionOperationContext context)) { var rv = _connection.Read <RequestVote>(context); ClusterTopology clusterTopology; long lastIndex; long lastTerm; string whoGotMyVoteIn; using (context.OpenReadTransaction()) { lastIndex = _engine.GetLastEntryIndex(context); lastTerm = _engine.GetTermForKnownExisting(context, lastIndex); whoGotMyVoteIn = _engine.GetWhoGotMyVoteIn(context, rv.Term); clusterTopology = _engine.GetTopology(context); } if (clusterTopology.Members.ContainsKey(rv.Source) == false && clusterTopology.Promotables.ContainsKey(rv.Source) == false && clusterTopology.Watchers.ContainsKey(rv.Source) == false) { _connection.Send(context, new RequestVoteResponse { Term = _engine.CurrentTerm, VoteGranted = false, // we only report to the node asking for our vote if we are the leader, this gives // the oust node a authorotative confirmation that they were removed from the cluster NotInTopology = _engine.CurrentState == RachisConsensus.State.Leader, Message = $"Node {rv.Source} is not in my topology, cannot vote for it" }); _connection.Dispose(); return; } if (rv.Term <= _engine.CurrentTerm) { _connection.Send(context, new RequestVoteResponse { Term = _engine.CurrentTerm, VoteGranted = false, Message = "My term is higher or equals to yours" }); _connection.Dispose(); return; } if (rv.IsForcedElection == false && ( _engine.CurrentState == RachisConsensus.State.Leader || _engine.CurrentState == RachisConsensus.State.LeaderElect ) ) { _connection.Send(context, new RequestVoteResponse { Term = _engine.CurrentTerm, VoteGranted = false, Message = "I'm a leader in good standing, coup will be resisted" }); _connection.Dispose(); return; } if (whoGotMyVoteIn != null && whoGotMyVoteIn != rv.Source) { _connection.Send(context, new RequestVoteResponse { Term = _engine.CurrentTerm, VoteGranted = false, Message = $"Already voted in {rv.LastLogTerm}, for {whoGotMyVoteIn}" }); _connection.Dispose(); return; } if (lastTerm > rv.LastLogTerm) { _connection.Send(context, new RequestVoteResponse { Term = _engine.CurrentTerm, VoteGranted = false, Message = $"My last log entry is of term {lastTerm} / {lastIndex} while yours is {rv.LastLogTerm}, so I'm more up to date" }); _connection.Dispose(); return; } if (lastIndex > rv.LastLogIndex) { _connection.Send(context, new RequestVoteResponse { Term = _engine.CurrentTerm, VoteGranted = false, Message = $"My last log entry is of term {lastTerm} / {lastIndex} while yours is {rv.LastLogTerm} / {rv.LastLogIndex}, so I'm more up to date" }); _connection.Dispose(); return; } if (rv.IsTrialElection) { if (_engine.Timeout.ExpiredLastDeferral(_engine.ElectionTimeout.TotalMilliseconds / 2, out string currentLeader) == false) { _connection.Send(context, new RequestVoteResponse { Term = _engine.CurrentTerm, VoteGranted = false, Message = $"My leader {currentLeader} is keeping me up to date, so I don't want to vote for you" }); _connection.Dispose(); return; } _connection.Send(context, new RequestVoteResponse { Term = rv.Term, VoteGranted = true, Message = "I might vote for you" }); if (_thread == null) // let's wait for this in another thread { _thread = new Thread(HandleVoteRequest) { Name = $"Elector thread for {rv.Source} > {_engine.Tag}", IsBackground = true }; _thread.Start(); return; } continue; } bool alreadyVoted = false; using (context.OpenWriteTransaction()) { whoGotMyVoteIn = _engine.GetWhoGotMyVoteIn(context, rv.Term); if (whoGotMyVoteIn != null && whoGotMyVoteIn != rv.Source) { alreadyVoted = true; } else { _engine.CastVoteInTerm(context, rv.Term, rv.Source); } context.Transaction.Commit(); } if (alreadyVoted) { _connection.Send(context, new RequestVoteResponse { Term = _engine.CurrentTerm, VoteGranted = false, Message = $"Already voted in {rv.LastLogTerm}, for {whoGotMyVoteIn}" }); } else { _connection.Send(context, new RequestVoteResponse { Term = _engine.CurrentTerm, VoteGranted = true, Message = "I've voted for you" }); } _connection.Dispose(); } } } catch (OperationCanceledException) { } catch (ObjectDisposedException) { } catch (AggregateException ae) when(ae.InnerException is OperationCanceledException || ae.InnerException is ObjectDisposedException) { } catch (Exception e) { if (_engine.Log.IsInfoEnabled) { _engine.Log.Info("Failed to talk to candidate: " + _engine.Tag, e); } } }
private void NegotiateMatchEntryWithLeaderAndApplyEntries(TransactionOperationContext context, RemoteConnection connection, LogLengthNegotiation negotiation) { long minIndex; long maxIndex; long midpointTerm; long midpointIndex; using (context.OpenReadTransaction()) { minIndex = _engine.GetFirstEntryIndex(context); if (minIndex == 0) // no entries at all { connection.Send(context, new LogLengthNegotiationResponse { Status = LogLengthNegotiationResponse.ResponseStatus.Acceptable, Message = "No entries at all here, give me everything from the start", CurrentTerm = _term, LastLogIndex = 0 }); return; // leader will know where to start from here } maxIndex = Math.Min( _engine.GetLastEntryIndex(context), // max negotiation.PrevLogIndex ); midpointIndex = (maxIndex + minIndex) / 2; midpointTerm = _engine.GetTermForKnownExisting(context, midpointIndex); } while (minIndex < maxIndex) { _engine.Timeout.Defer(_connection.Source); _engine.ValidateTerm(_term); connection.Send(context, new LogLengthNegotiationResponse { Status = LogLengthNegotiationResponse.ResponseStatus.Negotiation, Message = $"Term/Index mismatch from leader, need to figure out at what point the logs match, range: {maxIndex} - {minIndex} | {midpointIndex} in term {midpointTerm}", CurrentTerm = _term, MaxIndex = maxIndex, MinIndex = minIndex, MidpointIndex = midpointIndex, MidpointTerm = midpointTerm }); var response = connection.Read <LogLengthNegotiation>(context); _engine.Timeout.Defer(_connection.Source); if (response.Truncated) { if (_engine.Log.IsInfoEnabled) { _engine.Log.Info($"{ToString()}: Got a truncated response from the leader will request all entries"); } connection.Send(context, new LogLengthNegotiationResponse { Status = LogLengthNegotiationResponse.ResponseStatus.Acceptable, Message = "We have entries that are already truncated at the leader, will ask for full snapshot", CurrentTerm = _term, LastLogIndex = 0 }); return; } using (context.OpenReadTransaction()) { if (_engine.GetTermFor(context, response.PrevLogIndex) == response.PrevLogTerm) { minIndex = Math.Min(midpointIndex + 1, maxIndex); } else { maxIndex = Math.Max(midpointIndex - 1, minIndex); } } midpointIndex = (maxIndex + minIndex) / 2; using (context.OpenReadTransaction()) midpointTerm = _engine.GetTermForKnownExisting(context, midpointIndex); } if (_engine.Log.IsInfoEnabled) { _engine.Log.Info($"{ToString()}: agreed upon last matched index = {midpointIndex} on term = {_term}"); } connection.Send(context, new LogLengthNegotiationResponse { Status = LogLengthNegotiationResponse.ResponseStatus.Acceptable, Message = $"Found a log index / term match at {midpointIndex} with term {midpointTerm}", CurrentTerm = _term, LastLogIndex = midpointIndex }); }