Make FollowerLogInformation a class
[controller.git] / opendaylight / md-sal / sal-akka-raft / src / main / java / org / opendaylight / controller / cluster / raft / behaviors / AbstractLeader.java
1 /*
2  * Copyright (c) 2014 Cisco Systems, Inc. and others.  All rights reserved.
3  *
4  * This program and the accompanying materials are made available under the
5  * terms of the Eclipse Public License v1.0 which accompanies this distribution,
6  * and is available at http://www.eclipse.org/legal/epl-v10.html
7  */
8
9 package org.opendaylight.controller.cluster.raft.behaviors;
10
11 import akka.actor.ActorRef;
12 import akka.actor.ActorSelection;
13 import akka.actor.Cancellable;
14 import com.google.common.annotations.VisibleForTesting;
15 import com.google.common.base.Optional;
16 import com.google.common.base.Preconditions;
17 import com.google.common.io.ByteSource;
18 import java.io.IOException;
19 import java.io.ObjectOutputStream;
20 import java.util.Collection;
21 import java.util.Collections;
22 import java.util.HashMap;
23 import java.util.Iterator;
24 import java.util.LinkedList;
25 import java.util.List;
26 import java.util.Map;
27 import java.util.Map.Entry;
28 import java.util.Queue;
29 import java.util.concurrent.TimeUnit;
30 import javax.annotation.Nullable;
31 import org.opendaylight.controller.cluster.io.SharedFileBackedOutputStream;
32 import org.opendaylight.controller.cluster.messaging.MessageSlicer;
33 import org.opendaylight.controller.cluster.messaging.SliceOptions;
34 import org.opendaylight.controller.cluster.raft.ClientRequestTracker;
35 import org.opendaylight.controller.cluster.raft.ClientRequestTrackerImpl;
36 import org.opendaylight.controller.cluster.raft.FollowerLogInformation;
37 import org.opendaylight.controller.cluster.raft.PeerInfo;
38 import org.opendaylight.controller.cluster.raft.RaftActorContext;
39 import org.opendaylight.controller.cluster.raft.RaftState;
40 import org.opendaylight.controller.cluster.raft.ReplicatedLogEntry;
41 import org.opendaylight.controller.cluster.raft.VotingState;
42 import org.opendaylight.controller.cluster.raft.base.messages.CheckConsensusReached;
43 import org.opendaylight.controller.cluster.raft.base.messages.Replicate;
44 import org.opendaylight.controller.cluster.raft.base.messages.SendHeartBeat;
45 import org.opendaylight.controller.cluster.raft.base.messages.SendInstallSnapshot;
46 import org.opendaylight.controller.cluster.raft.messages.AppendEntries;
47 import org.opendaylight.controller.cluster.raft.messages.AppendEntriesReply;
48 import org.opendaylight.controller.cluster.raft.messages.InstallSnapshot;
49 import org.opendaylight.controller.cluster.raft.messages.InstallSnapshotReply;
50 import org.opendaylight.controller.cluster.raft.messages.RaftRPC;
51 import org.opendaylight.controller.cluster.raft.messages.RequestVote;
52 import org.opendaylight.controller.cluster.raft.messages.RequestVoteReply;
53 import org.opendaylight.controller.cluster.raft.messages.UnInitializedFollowerSnapshotReply;
54 import org.opendaylight.controller.cluster.raft.persisted.ServerConfigurationPayload;
55 import org.opendaylight.controller.cluster.raft.persisted.Snapshot;
56 import scala.concurrent.duration.FiniteDuration;
57
58 /**
59  * The behavior of a RaftActor when it is in the Leader state.
60  *
61  * <p>
62  * Leaders:
63  * <ul>
64  * <li> Upon election: send initial empty AppendEntries RPCs
65  * (heartbeat) to each server; repeat during idle periods to
66  * prevent election timeouts (§5.2)
67  * <li> If command received from client: append entry to local log,
68  * respond after entry applied to state machine (§5.3)
69  * <li> If last log index ≥ nextIndex for a follower: send
70  * AppendEntries RPC with log entries starting at nextIndex
71  * <li> If successful: update nextIndex and matchIndex for
72  * follower (§5.3)
73  * <li> If AppendEntries fails because of log inconsistency:
74  * decrement nextIndex and retry (§5.3)
75  * <li> If there exists an N such that N &gt; commitIndex, a majority
76  * of matchIndex[i] ≥ N, and log[N].term == currentTerm:
77  * set commitIndex = N (§5.3, §5.4).
78  * </ul>
79  */
80 public abstract class AbstractLeader extends AbstractRaftActorBehavior {
81     private final Map<String, FollowerLogInformation> followerToLog = new HashMap<>();
82
83     /**
84      * Lookup table for request contexts based on journal index. We could use a {@link Map} here, but we really
85      * expect the entries to be modified in sequence, hence we open-code the lookup.
86      * TODO: Evaluate the use of ArrayDeque(), as that has lower memory overhead. Non-head removals are more costly,
87      *       but we already expect those to be far from frequent.
88      */
89     private final Queue<ClientRequestTracker> trackers = new LinkedList<>();
90
91     /**
92      * Map of serialized AppendEntries output streams keyed by log index. This is used in conjunction with the
93      * appendEntriesMessageSlicer for slicing single ReplicatedLogEntry payloads that exceed the message size threshold.
94      * This Map allows the SharedFileBackedOutputStreams to be reused for multiple followers.
95      */
96     private final Map<Long, SharedFileBackedOutputStream> sharedSerializedAppendEntriesStreams = new HashMap<>();
97     private final MessageSlicer appendEntriesMessageSlicer;
98
99     private Cancellable heartbeatSchedule = null;
100     private Optional<SnapshotHolder> snapshotHolder = Optional.absent();
101     private int minReplicationCount;
102
103     protected AbstractLeader(final RaftActorContext context, final RaftState state,
104             @Nullable final AbstractLeader initializeFromLeader) {
105         super(context, state);
106
107         appendEntriesMessageSlicer = MessageSlicer.builder().logContext(logName())
108             .messageSliceSize(context.getConfigParams().getSnapshotChunkSize())
109             .expireStateAfterInactivity(context.getConfigParams().getElectionTimeOutInterval().toMillis() * 3,
110                     TimeUnit.MILLISECONDS).build();
111
112         if (initializeFromLeader != null) {
113             followerToLog.putAll(initializeFromLeader.followerToLog);
114             snapshotHolder = initializeFromLeader.snapshotHolder;
115             trackers.addAll(initializeFromLeader.trackers);
116         } else {
117             for (PeerInfo peerInfo: context.getPeers()) {
118                 FollowerLogInformation followerLogInformation = new FollowerLogInformation(peerInfo, context);
119                 followerToLog.put(peerInfo.getId(), followerLogInformation);
120             }
121         }
122
123         log.debug("{}: Election: Leader has following peers: {}", logName(), getFollowerIds());
124
125         updateMinReplicaCount();
126
127         // Immediately schedule a heartbeat
128         // Upon election: send initial empty AppendEntries RPCs
129         // (heartbeat) to each server; repeat during idle periods to
130         // prevent election timeouts (§5.2)
131         sendAppendEntries(0, false);
132
133         // It is important to schedule this heartbeat here
134         scheduleHeartBeat(context.getConfigParams().getHeartBeatInterval());
135     }
136
137     protected AbstractLeader(final RaftActorContext context, final RaftState state) {
138         this(context, state, null);
139     }
140
141     /**
142      * Return an immutable collection of follower identifiers.
143      *
144      * @return Collection of follower IDs
145      */
146     public final Collection<String> getFollowerIds() {
147         return followerToLog.keySet();
148     }
149
150     public void addFollower(final String followerId) {
151         FollowerLogInformation followerLogInformation = new FollowerLogInformation(context.getPeerInfo(followerId),
152             context);
153         followerToLog.put(followerId, followerLogInformation);
154
155         if (heartbeatSchedule == null) {
156             scheduleHeartBeat(context.getConfigParams().getHeartBeatInterval());
157         }
158     }
159
160     public void removeFollower(final String followerId) {
161         followerToLog.remove(followerId);
162     }
163
164     public void updateMinReplicaCount() {
165         int numVoting = 0;
166         for (PeerInfo peer: context.getPeers()) {
167             if (peer.isVoting()) {
168                 numVoting++;
169             }
170         }
171
172         minReplicationCount = getMajorityVoteCount(numVoting);
173     }
174
175     protected int getMinIsolatedLeaderPeerCount() {
176       //the isolated Leader peer count will be 1 less than the majority vote count.
177         //this is because the vote count has the self vote counted in it
178         //for e.g
179         //0 peers = 1 votesRequired , minIsolatedLeaderPeerCount = 0
180         //2 peers = 2 votesRequired , minIsolatedLeaderPeerCount = 1
181         //4 peers = 3 votesRequired, minIsolatedLeaderPeerCount = 2
182
183         return minReplicationCount > 0 ? minReplicationCount - 1 : 0;
184     }
185
186     @VisibleForTesting
187     void setSnapshotHolder(@Nullable final SnapshotHolder snapshotHolder) {
188         this.snapshotHolder = Optional.fromNullable(snapshotHolder);
189     }
190
191     @VisibleForTesting
192     boolean hasSnapshot() {
193         return snapshotHolder.isPresent();
194     }
195
196     @Override
197     protected RaftActorBehavior handleAppendEntries(final ActorRef sender,
198         final AppendEntries appendEntries) {
199
200         log.debug("{}: handleAppendEntries: {}", logName(), appendEntries);
201
202         return this;
203     }
204
205     @Override
206     protected RaftActorBehavior handleAppendEntriesReply(final ActorRef sender,
207             final AppendEntriesReply appendEntriesReply) {
208         log.trace("{}: handleAppendEntriesReply: {}", logName(), appendEntriesReply);
209
210         // Update the FollowerLogInformation
211         String followerId = appendEntriesReply.getFollowerId();
212         FollowerLogInformation followerLogInformation = followerToLog.get(followerId);
213
214         if (followerLogInformation == null) {
215             log.error("{}: handleAppendEntriesReply - unknown follower {}", logName(), followerId);
216             return this;
217         }
218
219         if (followerLogInformation.timeSinceLastActivity()
220                 > context.getConfigParams().getElectionTimeOutInterval().toMillis()) {
221             log.warn("{} : handleAppendEntriesReply delayed beyond election timeout, "
222                     + "appendEntriesReply : {}, timeSinceLastActivity : {}, lastApplied : {}, commitIndex : {}",
223                     logName(), appendEntriesReply, followerLogInformation.timeSinceLastActivity(),
224                     context.getLastApplied(), context.getCommitIndex());
225         }
226
227         followerLogInformation.markFollowerActive();
228         followerLogInformation.setPayloadVersion(appendEntriesReply.getPayloadVersion());
229         followerLogInformation.setRaftVersion(appendEntriesReply.getRaftVersion());
230
231         long followerLastLogIndex = appendEntriesReply.getLogLastIndex();
232         long followersLastLogTermInLeadersLog = getLogEntryTerm(followerLastLogIndex);
233         boolean updated = false;
234         if (appendEntriesReply.getLogLastIndex() > context.getReplicatedLog().lastIndex()) {
235             // The follower's log is actually ahead of the leader's log. Normally this doesn't happen
236             // in raft as a node cannot become leader if it's log is behind another's. However, the
237             // non-voting semantics deviate a bit from raft. Only voting members participate in
238             // elections and can become leader so it's possible for a non-voting follower to be ahead
239             // of the leader. This can happen if persistence is disabled and all voting members are
240             // restarted. In this case, the voting leader will start out with an empty log however
241             // the non-voting followers still retain the previous data in memory. On the first
242             // AppendEntries, the non-voting follower returns a successful reply b/c the prevLogIndex
243             // sent by the leader is -1 and thus the integrity checks pass. However the follower's returned
244             // lastLogIndex may be higher in which case we want to reset the follower by installing a
245             // snapshot. It's also possible that the follower's last log index is behind the leader's.
246             // However in this case the log terms won't match and the logs will conflict - this is handled
247             // elsewhere.
248             log.info("{}: handleAppendEntriesReply: follower {} lastIndex {} is ahead of our lastIndex {} "
249                     + "(snapshotIndex {}) - forcing install snaphot", logName(), followerLogInformation.getId(),
250                     appendEntriesReply.getLogLastIndex(), context.getReplicatedLog().lastIndex(),
251                     context.getReplicatedLog().getSnapshotIndex());
252
253             followerLogInformation.setMatchIndex(-1);
254             followerLogInformation.setNextIndex(-1);
255
256             initiateCaptureSnapshot(followerId);
257
258             updated = true;
259         } else if (appendEntriesReply.isSuccess()) {
260             if (followerLastLogIndex >= 0 && followersLastLogTermInLeadersLog >= 0
261                     && followersLastLogTermInLeadersLog != appendEntriesReply.getLogLastTerm()) {
262                 // The follower's last entry is present in the leader's journal but the terms don't match so the
263                 // follower has a conflicting entry. Since the follower didn't report that it's out of sync, this means
264                 // either the previous leader entry sent didn't conflict or the previous leader entry is in the snapshot
265                 // and no longer in the journal. Either way, we set the follower's next index to 1 less than the last
266                 // index reported by the follower. For the former case, the leader will send all entries starting with
267                 // the previous follower's index and the follower will remove and replace the conflicting entries as
268                 // needed. For the latter, the leader will initiate an install snapshot.
269
270                 followerLogInformation.setNextIndex(followerLastLogIndex - 1);
271                 updated = true;
272
273                 log.info("{}: handleAppendEntriesReply: follower {} last log term {} for index {} conflicts with the "
274                         + "leader's {} - set the follower's next index to {}", logName(),
275                         followerId, appendEntriesReply.getLogLastTerm(), appendEntriesReply.getLogLastIndex(),
276                         followersLastLogTermInLeadersLog, followerLogInformation.getNextIndex());
277             } else {
278                 updated = updateFollowerLogInformation(followerLogInformation, appendEntriesReply);
279             }
280         } else {
281             log.info("{}: handleAppendEntriesReply - received unsuccessful reply: {}, leader snapshotIndex: {}",
282                     logName(), appendEntriesReply, context.getReplicatedLog().getSnapshotIndex());
283
284             if (appendEntriesReply.isForceInstallSnapshot()) {
285                 // Reset the followers match and next index. This is to signal that this follower has nothing
286                 // in common with this Leader and so would require a snapshot to be installed
287                 followerLogInformation.setMatchIndex(-1);
288                 followerLogInformation.setNextIndex(-1);
289
290                 // Force initiate a snapshot capture
291                 initiateCaptureSnapshot(followerId);
292             } else if (followerLastLogIndex < 0 || followersLastLogTermInLeadersLog >= 0
293                     && followersLastLogTermInLeadersLog == appendEntriesReply.getLogLastTerm()) {
294                 // The follower's log is empty or the last entry is present in the leader's journal
295                 // and the terms match so the follower is just behind the leader's journal from
296                 // the last snapshot, if any. We'll catch up the follower quickly by starting at the
297                 // follower's last log index.
298
299                 updated = updateFollowerLogInformation(followerLogInformation, appendEntriesReply);
300
301                 log.info("{}: follower {} appears to be behind the leader from the last snapshot - "
302                     + "updated: matchIndex: {}, nextIndex: {}", logName(), followerId,
303                     followerLogInformation.getMatchIndex(), followerLogInformation.getNextIndex());
304             } else {
305                 // The follower's log conflicts with leader's log so decrement follower's next index by 1
306                 // in an attempt to find where the logs match.
307
308                 if (followerLogInformation.decrNextIndex()) {
309                     updated = true;
310
311                     log.info("{}: follower {} last log term {} conflicts with the leader's {} - dec next index to {}",
312                             logName(), followerId, appendEntriesReply.getLogLastTerm(),
313                             followersLastLogTermInLeadersLog, followerLogInformation.getNextIndex());
314                 }
315             }
316         }
317
318         if (log.isTraceEnabled()) {
319             log.trace("{}: handleAppendEntriesReply from {}: commitIndex: {}, lastAppliedIndex: {}, currentTerm: {}",
320                     logName(), followerId, context.getCommitIndex(), context.getLastApplied(), currentTerm());
321         }
322
323         possiblyUpdateCommitIndex();
324
325         //Send the next log entry immediately, if possible, no need to wait for heartbeat to trigger that event
326         sendUpdatesToFollower(followerId, followerLogInformation, false, !updated);
327
328         return this;
329     }
330
331     private void possiblyUpdateCommitIndex() {
332         // Figure out if we can update the the commitIndex as follows:
333         //   If there exists an index N such that N > commitIndex, a majority of matchIndex[i] ≥ N,
334         //     and log[N].term == currentTerm:
335         //   set commitIndex = N (§5.3, §5.4).
336         for (long index = context.getCommitIndex() + 1; ; index++) {
337             ReplicatedLogEntry replicatedLogEntry = context.getReplicatedLog().get(index);
338             if (replicatedLogEntry == null) {
339                 log.trace("{}: ReplicatedLogEntry not found for index {} - snapshotIndex: {}, journal size: {}",
340                         logName(), index, context.getReplicatedLog().getSnapshotIndex(),
341                         context.getReplicatedLog().size());
342                 break;
343             }
344
345             // Count our entry if it has been persisted.
346             int replicatedCount = replicatedLogEntry.isPersistencePending() ? 0 : 1;
347
348             if (replicatedCount == 0) {
349                 // We don't commit and apply a log entry until we've gotten the ack from our local persistence,
350                 // even though there *shouldn't* be any issue with updating the commit index if we get a consensus
351                 // amongst the followers w/o the local persistence ack.
352                 break;
353             }
354
355             log.trace("{}: checking Nth index {}", logName(), index);
356             for (FollowerLogInformation info : followerToLog.values()) {
357                 final PeerInfo peerInfo = context.getPeerInfo(info.getId());
358                 if (info.getMatchIndex() >= index && peerInfo != null && peerInfo.isVoting()) {
359                     replicatedCount++;
360                 } else if (log.isTraceEnabled()) {
361                     log.trace("{}: Not counting follower {} - matchIndex: {}, {}", logName(), info.getId(),
362                             info.getMatchIndex(), peerInfo);
363                 }
364             }
365
366             if (log.isTraceEnabled()) {
367                 log.trace("{}: replicatedCount {}, minReplicationCount: {}", logName(), replicatedCount,
368                         minReplicationCount);
369             }
370
371             if (replicatedCount >= minReplicationCount) {
372                 // Don't update the commit index if the log entry is from a previous term, as per §5.4.1:
373                 // "Raft never commits log entries from previous terms by counting replicas".
374                 // However we keep looping so we can make progress when new entries in the current term
375                 // reach consensus, as per §5.4.1: "once an entry from the current term is committed by
376                 // counting replicas, then all prior entries are committed indirectly".
377                 if (replicatedLogEntry.getTerm() == currentTerm()) {
378                     log.trace("{}: Setting commit index to {}", logName(), index);
379                     context.setCommitIndex(index);
380                 } else {
381                     log.debug("{}: Not updating commit index to {} - retrieved log entry with index {}, "
382                             + "term {} does not match the current term {}", logName(), index,
383                             replicatedLogEntry.getIndex(), replicatedLogEntry.getTerm(), currentTerm());
384                 }
385             } else {
386                 log.trace("{}: minReplicationCount not reached, actual {} - breaking", logName(), replicatedCount);
387                 break;
388             }
389         }
390
391         // Apply the change to the state machine
392         if (context.getCommitIndex() > context.getLastApplied()) {
393             log.debug("{}: Applying to log - commitIndex: {}, lastAppliedIndex: {}", logName(),
394                     context.getCommitIndex(), context.getLastApplied());
395
396             applyLogToStateMachine(context.getCommitIndex());
397         }
398
399         if (!context.getSnapshotManager().isCapturing()) {
400             purgeInMemoryLog();
401         }
402     }
403
404     private boolean updateFollowerLogInformation(final FollowerLogInformation followerLogInformation,
405             final AppendEntriesReply appendEntriesReply) {
406         boolean updated = followerLogInformation.setMatchIndex(appendEntriesReply.getLogLastIndex());
407         updated = followerLogInformation.setNextIndex(appendEntriesReply.getLogLastIndex() + 1) || updated;
408
409         if (updated && log.isDebugEnabled()) {
410             log.debug(
411                 "{}: handleAppendEntriesReply - FollowerLogInformation for {} updated: matchIndex: {}, nextIndex: {}",
412                 logName(), followerLogInformation.getId(), followerLogInformation.getMatchIndex(),
413                 followerLogInformation.getNextIndex());
414         }
415         return updated;
416     }
417
418     private void purgeInMemoryLog() {
419         //find the lowest index across followers which has been replicated to all.
420         // lastApplied if there are no followers, so that we keep clearing the log for single-node
421         // we would delete the in-mem log from that index on, in-order to minimize mem usage
422         // we would also share this info thru AE with the followers so that they can delete their log entries as well.
423         long minReplicatedToAllIndex = followerToLog.isEmpty() ? context.getLastApplied() : Long.MAX_VALUE;
424         for (FollowerLogInformation info : followerToLog.values()) {
425             minReplicatedToAllIndex = Math.min(minReplicatedToAllIndex, info.getMatchIndex());
426         }
427
428         super.performSnapshotWithoutCapture(minReplicatedToAllIndex);
429     }
430
431     @Override
432     protected ClientRequestTracker removeClientRequestTracker(final long logIndex) {
433         final Iterator<ClientRequestTracker> it = trackers.iterator();
434         while (it.hasNext()) {
435             final ClientRequestTracker t = it.next();
436             if (t.getIndex() == logIndex) {
437                 it.remove();
438                 return t;
439             }
440         }
441
442         return null;
443     }
444
445     @Override
446     protected RaftActorBehavior handleRequestVoteReply(final ActorRef sender,
447         final RequestVoteReply requestVoteReply) {
448         return this;
449     }
450
451     protected void beforeSendHeartbeat(){}
452
453     @Override
454     public RaftActorBehavior handleMessage(final ActorRef sender, final Object message) {
455         Preconditions.checkNotNull(sender, "sender should not be null");
456
457         if (appendEntriesMessageSlicer.handleMessage(message)) {
458             return this;
459         }
460
461         if (message instanceof RaftRPC) {
462             RaftRPC rpc = (RaftRPC) message;
463             // If RPC request or response contains term T > currentTerm:
464             // set currentTerm = T, convert to follower (§5.1)
465             // This applies to all RPC messages and responses
466             if (rpc.getTerm() > context.getTermInformation().getCurrentTerm()) {
467                 log.info("{}: Term {} in \"{}\" message is greater than leader's term {} - switching to Follower",
468                         logName(), rpc.getTerm(), rpc, context.getTermInformation().getCurrentTerm());
469
470                 context.getTermInformation().updateAndPersist(rpc.getTerm(), null);
471
472                 // This is a special case. Normally when stepping down as leader we don't process and reply to the
473                 // RaftRPC as per raft. But if we're in the process of transferring leadership and we get a
474                 // RequestVote, process the RequestVote before switching to Follower. This enables the requesting
475                 // candidate node to be elected the leader faster and avoids us possibly timing out in the Follower
476                 // state and starting a new election and grabbing leadership back before the other candidate node can
477                 // start a new election due to lack of responses. This case would only occur if there isn't a majority
478                 // of other nodes available that can elect the requesting candidate. Since we're transferring
479                 // leadership, we should make every effort to get the requesting node elected.
480                 if (message instanceof RequestVote && context.getRaftActorLeadershipTransferCohort() != null) {
481                     log.debug("{}: Leadership transfer in progress - processing RequestVote", logName());
482                     super.handleMessage(sender, message);
483                 }
484
485                 return internalSwitchBehavior(RaftState.Follower);
486             }
487         }
488
489         if (message instanceof SendHeartBeat) {
490             beforeSendHeartbeat();
491             sendHeartBeat();
492             scheduleHeartBeat(context.getConfigParams().getHeartBeatInterval());
493         } else if (message instanceof SendInstallSnapshot) {
494             SendInstallSnapshot sendInstallSnapshot = (SendInstallSnapshot) message;
495             setSnapshotHolder(new SnapshotHolder(sendInstallSnapshot.getSnapshot(),
496                 sendInstallSnapshot.getSnapshotBytes()));
497             sendInstallSnapshot();
498         } else if (message instanceof Replicate) {
499             replicate((Replicate) message);
500         } else if (message instanceof InstallSnapshotReply) {
501             handleInstallSnapshotReply((InstallSnapshotReply) message);
502         } else if (message instanceof CheckConsensusReached) {
503             possiblyUpdateCommitIndex();
504         } else {
505             return super.handleMessage(sender, message);
506         }
507
508         return this;
509     }
510
511     private void handleInstallSnapshotReply(final InstallSnapshotReply reply) {
512         log.debug("{}: handleInstallSnapshotReply: {}", logName(), reply);
513
514         String followerId = reply.getFollowerId();
515         FollowerLogInformation followerLogInformation = followerToLog.get(followerId);
516         if (followerLogInformation == null) {
517             // This can happen during AddServer if it times out.
518             log.error("{}: FollowerLogInformation not found for follower {} in InstallSnapshotReply",
519                     logName(), followerId);
520             return;
521         }
522
523         LeaderInstallSnapshotState installSnapshotState = followerLogInformation.getInstallSnapshotState();
524         if (installSnapshotState == null) {
525             log.error("{}: LeaderInstallSnapshotState not found for follower {} in InstallSnapshotReply",
526                     logName(), followerId);
527             return;
528         }
529
530         followerLogInformation.markFollowerActive();
531
532         if (installSnapshotState.getChunkIndex() == reply.getChunkIndex()) {
533             boolean wasLastChunk = false;
534             if (reply.isSuccess()) {
535                 if (installSnapshotState.isLastChunk(reply.getChunkIndex())) {
536                     //this was the last chunk reply
537
538                     long followerMatchIndex = snapshotHolder.get().getLastIncludedIndex();
539                     followerLogInformation.setMatchIndex(followerMatchIndex);
540                     followerLogInformation.setNextIndex(followerMatchIndex + 1);
541                     followerLogInformation.clearLeaderInstallSnapshotState();
542
543                     log.info("{}: Snapshot successfully installed on follower {} (last chunk {}) - "
544                         + "matchIndex set to {}, nextIndex set to {}", logName(), followerId, reply.getChunkIndex(),
545                         followerLogInformation.getMatchIndex(), followerLogInformation.getNextIndex());
546
547                     if (!anyFollowersInstallingSnapshot()) {
548                         // once there are no pending followers receiving snapshots
549                         // we can remove snapshot from the memory
550                         setSnapshotHolder(null);
551                     }
552
553                     wasLastChunk = true;
554                     if (context.getPeerInfo(followerId).getVotingState() == VotingState.VOTING_NOT_INITIALIZED) {
555                         UnInitializedFollowerSnapshotReply unInitFollowerSnapshotSuccess =
556                                              new UnInitializedFollowerSnapshotReply(followerId);
557                         context.getActor().tell(unInitFollowerSnapshotSuccess, context.getActor());
558                         log.debug("Sent message UnInitializedFollowerSnapshotReply to self");
559                     }
560                 } else {
561                     installSnapshotState.markSendStatus(true);
562                 }
563             } else {
564                 log.warn("{}: Received failed InstallSnapshotReply - will retry: {}", logName(), reply);
565
566                 installSnapshotState.markSendStatus(false);
567             }
568
569             if (wasLastChunk) {
570                 if (!context.getSnapshotManager().isCapturing()) {
571                     // Since the follower is now caught up try to purge the log.
572                     purgeInMemoryLog();
573                 }
574             } else {
575                 ActorSelection followerActor = context.getPeerActorSelection(followerId);
576                 if (followerActor != null) {
577                     sendSnapshotChunk(followerActor, followerLogInformation);
578                 }
579             }
580
581         } else {
582             log.error("{}: Chunk index {} in InstallSnapshotReply from follower {} does not match expected index {}",
583                     logName(), reply.getChunkIndex(), followerId,
584                     installSnapshotState.getChunkIndex());
585
586             if (reply.getChunkIndex() == LeaderInstallSnapshotState.INVALID_CHUNK_INDEX) {
587                 // Since the Follower did not find this index to be valid we should reset the follower snapshot
588                 // so that Installing the snapshot can resume from the beginning
589                 installSnapshotState.reset();
590             }
591         }
592     }
593
594     private boolean anyFollowersInstallingSnapshot() {
595         for (FollowerLogInformation info: followerToLog.values()) {
596             if (info.getInstallSnapshotState() != null) {
597                 return true;
598             }
599
600         }
601
602         return false;
603     }
604
605     private void replicate(final Replicate replicate) {
606         long logIndex = replicate.getReplicatedLogEntry().getIndex();
607
608         log.debug("{}: Replicate message: identifier: {}, logIndex: {}, payload: {}, isSendImmediate: {}", logName(),
609                 replicate.getIdentifier(), logIndex, replicate.getReplicatedLogEntry().getData().getClass(),
610                 replicate.isSendImmediate());
611
612         // Create a tracker entry we will use this later to notify the
613         // client actor
614         if (replicate.getClientActor() != null) {
615             trackers.add(new ClientRequestTrackerImpl(replicate.getClientActor(), replicate.getIdentifier(),
616                     logIndex));
617         }
618
619         boolean applyModificationToState = !context.anyVotingPeers()
620                 || context.getRaftPolicy().applyModificationToStateBeforeConsensus();
621
622         if (applyModificationToState) {
623             context.setCommitIndex(logIndex);
624             applyLogToStateMachine(logIndex);
625         }
626
627         if (replicate.isSendImmediate() && !followerToLog.isEmpty()) {
628             sendAppendEntries(0, false);
629         }
630     }
631
632     protected void sendAppendEntries(final long timeSinceLastActivityInterval, final boolean isHeartbeat) {
633         // Send an AppendEntries to all followers
634         for (Entry<String, FollowerLogInformation> e : followerToLog.entrySet()) {
635             final String followerId = e.getKey();
636             final FollowerLogInformation followerLogInformation = e.getValue();
637             // This checks helps not to send a repeat message to the follower
638             if (!followerLogInformation.isFollowerActive()
639                     || followerLogInformation.timeSinceLastActivity() >= timeSinceLastActivityInterval) {
640                 sendUpdatesToFollower(followerId, followerLogInformation, true, isHeartbeat);
641             }
642         }
643     }
644
645     /**
646      * This method checks if any update needs to be sent to the given follower. This includes append log entries,
647      * sending next snapshot chunk, and initiating a snapshot.
648      */
649     private void sendUpdatesToFollower(final String followerId, final FollowerLogInformation followerLogInformation,
650                                        final boolean sendHeartbeat, final boolean isHeartbeat) {
651
652         ActorSelection followerActor = context.getPeerActorSelection(followerId);
653         if (followerActor != null) {
654             long followerNextIndex = followerLogInformation.getNextIndex();
655             boolean isFollowerActive = followerLogInformation.isFollowerActive();
656             boolean sendAppendEntries = false;
657             List<ReplicatedLogEntry> entries = Collections.emptyList();
658
659             LeaderInstallSnapshotState installSnapshotState = followerLogInformation.getInstallSnapshotState();
660             if (installSnapshotState != null) {
661                 // if install snapshot is in process , then sent next chunk if possible
662                 if (isFollowerActive && installSnapshotState.canSendNextChunk()) {
663                     sendSnapshotChunk(followerActor, followerLogInformation);
664                 } else if (sendHeartbeat) {
665                     // we send a heartbeat even if we have not received a reply for the last chunk
666                     sendAppendEntries = true;
667                 }
668             } else if (followerLogInformation.isLogEntrySlicingInProgress()) {
669                 sendAppendEntries = sendHeartbeat;
670             } else {
671                 long leaderLastIndex = context.getReplicatedLog().lastIndex();
672                 long leaderSnapShotIndex = context.getReplicatedLog().getSnapshotIndex();
673
674                 if (!isHeartbeat && log.isDebugEnabled() || log.isTraceEnabled()) {
675                     log.debug("{}: Checking sendAppendEntries for follower {}: active: {}, followerNextIndex: {}, "
676                             + "leaderLastIndex: {}, leaderSnapShotIndex: {}", logName(), followerId, isFollowerActive,
677                             followerNextIndex, leaderLastIndex, leaderSnapShotIndex);
678                 }
679
680                 if (isFollowerActive && context.getReplicatedLog().isPresent(followerNextIndex)) {
681
682                     log.debug("{}: sendAppendEntries: {} is present for follower {}", logName(),
683                             followerNextIndex, followerId);
684
685                     if (followerLogInformation.okToReplicate()) {
686                         entries = getEntriesToSend(followerLogInformation, followerActor);
687                         sendAppendEntries = true;
688                     }
689                 } else if (isFollowerActive && followerNextIndex >= 0
690                         && leaderLastIndex > followerNextIndex && !context.getSnapshotManager().isCapturing()) {
691                     // if the followers next index is not present in the leaders log, and
692                     // if the follower is just not starting and if leader's index is more than followers index
693                     // then snapshot should be sent
694
695                     // Send heartbeat to follower whenever install snapshot is initiated.
696                     sendAppendEntries = true;
697                     if (canInstallSnapshot(followerNextIndex)) {
698                         log.info("{}: Initiating install snapshot to follower {}: follower nextIndex: {}, leader "
699                                 + "snapshotIndex: {}, leader lastIndex: {}, leader log size: {}", logName(), followerId,
700                                 followerNextIndex, leaderSnapShotIndex, leaderLastIndex,
701                                 context.getReplicatedLog().size());
702
703                         initiateCaptureSnapshot(followerId);
704                     } else {
705                         // It doesn't seem like we should ever reach here - most likely indicates sonething is
706                         // wrong.
707                         log.info("{}: Follower {} is behind but cannot install snapshot: follower nextIndex: {}, "
708                                 + "leader snapshotIndex: {}, leader lastIndex: {}, leader log size: {}", logName(),
709                                 followerId, followerNextIndex, leaderSnapShotIndex, leaderLastIndex,
710                                 context.getReplicatedLog().size());
711                     }
712
713                 } else if (sendHeartbeat) {
714                     // we send an AppendEntries, even if the follower is inactive
715                     // in-order to update the followers timestamp, in case it becomes active again
716                     sendAppendEntries = true;
717                 }
718
719             }
720
721             if (sendAppendEntries) {
722                 sendAppendEntriesToFollower(followerActor, entries, followerLogInformation);
723             }
724         }
725     }
726
727     private List<ReplicatedLogEntry> getEntriesToSend(final FollowerLogInformation followerLogInfo,
728             final ActorSelection followerActor) {
729         // Try to get all the entries in the journal but not exceeding the max data size for a single AppendEntries
730         // message.
731         int maxEntries = (int) context.getReplicatedLog().size();
732         final int maxDataSize = context.getConfigParams().getSnapshotChunkSize();
733         final long followerNextIndex = followerLogInfo.getNextIndex();
734         List<ReplicatedLogEntry> entries = context.getReplicatedLog().getFrom(followerNextIndex,
735                 maxEntries, maxDataSize);
736
737         // If the first entry's size exceeds the max data size threshold, it will be returned from the call above. If
738         // that is the case, then we need to slice it into smaller chunks.
739         if (!(entries.size() == 1 && entries.get(0).getData().size() > maxDataSize)) {
740             // Don't need to slice.
741             return entries;
742         }
743
744         log.debug("{}: Log entry size {} exceeds max payload size {}", logName(), entries.get(0).getData().size(),
745                 maxDataSize);
746
747         // If an AppendEntries has already been serialized for the log index then reuse the
748         // SharedFileBackedOutputStream.
749         final Long logIndex = entries.get(0).getIndex();
750         SharedFileBackedOutputStream fileBackedStream = sharedSerializedAppendEntriesStreams.get(logIndex);
751         if (fileBackedStream == null) {
752             fileBackedStream = context.getFileBackedOutputStreamFactory().newSharedInstance();
753
754             final AppendEntries appendEntries = new AppendEntries(currentTerm(), context.getId(),
755                     getLogEntryIndex(followerNextIndex - 1), getLogEntryTerm(followerNextIndex - 1), entries,
756                     context.getCommitIndex(), getReplicatedToAllIndex(), context.getPayloadVersion());
757
758             log.debug("{}: Serializing {} for slicing for follower {}", logName(), appendEntries,
759                     followerLogInfo.getId());
760
761             try (ObjectOutputStream out = new ObjectOutputStream(fileBackedStream)) {
762                 out.writeObject(appendEntries);
763             } catch (IOException e) {
764                 log.error("{}: Error serializing {}", logName(), appendEntries, e);
765                 fileBackedStream.cleanup();
766                 return Collections.emptyList();
767             }
768
769             sharedSerializedAppendEntriesStreams.put(logIndex, fileBackedStream);
770
771             fileBackedStream.setOnCleanupCallback(index -> {
772                 log.debug("{}: On SharedFileBackedOutputStream cleanup for index {}", logName(), index);
773                 sharedSerializedAppendEntriesStreams.remove(index);
774             }, logIndex);
775         } else {
776             log.debug("{}: Reusing SharedFileBackedOutputStream for follower {}", logName(), followerLogInfo.getId());
777             fileBackedStream.incrementUsageCount();
778         }
779
780         log.debug("{}: Slicing stream for index {}, follower {}", logName(), logIndex, followerLogInfo.getId());
781
782         // Record that slicing is in progress for the follower.
783         followerLogInfo.setSlicedLogEntryIndex(logIndex);
784
785         final FollowerIdentifier identifier = new FollowerIdentifier(followerLogInfo.getId());
786         appendEntriesMessageSlicer.slice(SliceOptions.builder().identifier(identifier)
787                 .fileBackedOutputStream(fileBackedStream).sendTo(followerActor).replyTo(actor())
788                 .onFailureCallback(failure -> {
789                     log.error("{}: Error slicing AppendEntries for follower {}", logName(),
790                             followerLogInfo.getId(), failure);
791                     followerLogInfo.setSlicedLogEntryIndex(FollowerLogInformation.NO_INDEX);
792                 }).build());
793
794         return Collections.emptyList();
795     }
796
797     private void sendAppendEntriesToFollower(final ActorSelection followerActor, final List<ReplicatedLogEntry> entries,
798             final FollowerLogInformation followerLogInformation) {
799         // In certain cases outlined below we don't want to send the actual commit index to prevent the follower from
800         // possibly committing and applying conflicting entries (those with same index, different term) from a prior
801         // term that weren't replicated to a majority, which would be a violation of raft.
802         //     - if the follower isn't active. In this case we don't know the state of the follower and we send an
803         //       empty AppendEntries as a heart beat to prevent election.
804         //     - if we're in the process of installing a snapshot. In this case we don't send any new entries but still
805         //       need to send AppendEntries to prevent election.
806         //     - if we're in the process of slicing an AppendEntries with a large log entry payload. In this case we
807         //       need to send an empty AppendEntries to prevent election.
808         boolean isInstallingSnaphot = followerLogInformation.getInstallSnapshotState() != null;
809         long leaderCommitIndex = isInstallingSnaphot || followerLogInformation.isLogEntrySlicingInProgress()
810                 || !followerLogInformation.isFollowerActive() ? -1 : context.getCommitIndex();
811
812         long followerNextIndex = followerLogInformation.getNextIndex();
813         AppendEntries appendEntries = new AppendEntries(currentTerm(), context.getId(),
814             getLogEntryIndex(followerNextIndex - 1),
815             getLogEntryTerm(followerNextIndex - 1), entries,
816             leaderCommitIndex, super.getReplicatedToAllIndex(), context.getPayloadVersion());
817
818         if (!entries.isEmpty() || log.isTraceEnabled()) {
819             log.debug("{}: Sending AppendEntries to follower {}: {}", logName(), followerLogInformation.getId(),
820                     appendEntries);
821         }
822
823         followerActor.tell(appendEntries, actor());
824     }
825
826     /**
827      * Initiates a snapshot capture to install on a follower.
828      *
829      * <p>
830      * Install Snapshot works as follows
831      *   1. Leader initiates the capture snapshot by calling createSnapshot on the RaftActor.
832      *   2. On receipt of the CaptureSnapshotReply message, the RaftActor persists the snapshot and makes a call to
833      *      the Leader's handleMessage with a SendInstallSnapshot message.
834      *   3. The Leader obtains and stores the Snapshot from the SendInstallSnapshot message and sends it in chunks to
835      *      the Follower via InstallSnapshot messages.
836      *   4. For each chunk, the Follower sends back an InstallSnapshotReply.
837      *   5. On receipt of the InstallSnapshotReply for the last chunk, the Leader marks the install complete for that
838      *      follower.
839      *   6. If another follower requires a snapshot and a snapshot has been collected (via SendInstallSnapshot)
840      *      then send the existing snapshot in chunks to the follower.
841      *
842      * @param followerId the id of the follower.
843      * @return true if capture was initiated, false otherwise.
844      */
845     public boolean initiateCaptureSnapshot(final String followerId) {
846         FollowerLogInformation followerLogInfo = followerToLog.get(followerId);
847         if (snapshotHolder.isPresent()) {
848             // If a snapshot is present in the memory, most likely another install is in progress no need to capture
849             // snapshot. This could happen if another follower needs an install when one is going on.
850             final ActorSelection followerActor = context.getPeerActorSelection(followerId);
851
852             // Note: sendSnapshotChunk will set the LeaderInstallSnapshotState.
853             sendSnapshotChunk(followerActor, followerLogInfo);
854             return true;
855         }
856
857         boolean captureInitiated = context.getSnapshotManager().captureToInstall(context.getReplicatedLog().last(),
858             this.getReplicatedToAllIndex(), followerId);
859         if (captureInitiated) {
860             followerLogInfo.setLeaderInstallSnapshotState(new LeaderInstallSnapshotState(
861                 context.getConfigParams().getSnapshotChunkSize(), logName()));
862         }
863
864         return captureInitiated;
865     }
866
867     private boolean canInstallSnapshot(final long nextIndex) {
868         // If the follower's nextIndex is -1 then we might as well send it a snapshot
869         // Otherwise send it a snapshot only if the nextIndex is not present in the log but is present
870         // in the snapshot
871         return nextIndex == -1 || !context.getReplicatedLog().isPresent(nextIndex)
872                 && context.getReplicatedLog().isInSnapshot(nextIndex);
873
874     }
875
876
877     private void sendInstallSnapshot() {
878         log.debug("{}: sendInstallSnapshot", logName());
879         for (Entry<String, FollowerLogInformation> e : followerToLog.entrySet()) {
880             String followerId = e.getKey();
881             ActorSelection followerActor = context.getPeerActorSelection(followerId);
882             FollowerLogInformation followerLogInfo = e.getValue();
883
884             if (followerActor != null) {
885                 long nextIndex = followerLogInfo.getNextIndex();
886                 if (followerLogInfo.getInstallSnapshotState() != null
887                         || context.getPeerInfo(followerId).getVotingState() == VotingState.VOTING_NOT_INITIALIZED
888                         || canInstallSnapshot(nextIndex)) {
889                     sendSnapshotChunk(followerActor, followerLogInfo);
890                 }
891             }
892         }
893     }
894
895     /**
896      *  Sends a snapshot chunk to a given follower
897      *  InstallSnapshot should qualify as a heartbeat too.
898      */
899     private void sendSnapshotChunk(final ActorSelection followerActor, final FollowerLogInformation followerLogInfo) {
900         if (snapshotHolder.isPresent()) {
901             LeaderInstallSnapshotState installSnapshotState = followerLogInfo.getInstallSnapshotState();
902             if (installSnapshotState == null) {
903                 installSnapshotState = new LeaderInstallSnapshotState(context.getConfigParams().getSnapshotChunkSize(),
904                         logName());
905                 followerLogInfo.setLeaderInstallSnapshotState(installSnapshotState);
906             }
907
908             try {
909                 // Ensure the snapshot bytes are set - this is a no-op.
910                 installSnapshotState.setSnapshotBytes(snapshotHolder.get().getSnapshotBytes());
911
912                 if (!installSnapshotState.canSendNextChunk()) {
913                     return;
914                 }
915
916                 byte[] nextSnapshotChunk = installSnapshotState.getNextChunk();
917
918                 log.debug("{}: next snapshot chunk size for follower {}: {}", logName(), followerLogInfo.getId(),
919                         nextSnapshotChunk.length);
920
921                 int nextChunkIndex = installSnapshotState.incrementChunkIndex();
922                 Optional<ServerConfigurationPayload> serverConfig = Optional.absent();
923                 if (installSnapshotState.isLastChunk(nextChunkIndex)) {
924                     serverConfig = Optional.fromNullable(context.getPeerServerInfo(true));
925                 }
926
927                 followerActor.tell(
928                     new InstallSnapshot(currentTerm(), context.getId(),
929                         snapshotHolder.get().getLastIncludedIndex(),
930                         snapshotHolder.get().getLastIncludedTerm(),
931                         nextSnapshotChunk,
932                         nextChunkIndex,
933                         installSnapshotState.getTotalChunks(),
934                         Optional.of(installSnapshotState.getLastChunkHashCode()),
935                         serverConfig
936                     ).toSerializable(followerLogInfo.getRaftVersion()),
937                     actor()
938                 );
939
940             } catch (IOException e) {
941                 throw new RuntimeException(e);
942             }
943
944             log.debug("{}: InstallSnapshot sent to follower {}, Chunk: {}/{}", logName(), followerActor.path(),
945                 installSnapshotState.getChunkIndex(), installSnapshotState.getTotalChunks());
946         }
947     }
948
949     private void sendHeartBeat() {
950         if (!followerToLog.isEmpty()) {
951             log.trace("{}: Sending heartbeat", logName());
952             sendAppendEntries(context.getConfigParams().getHeartBeatInterval().toMillis(), true);
953
954             appendEntriesMessageSlicer.checkExpiredSlicedMessageState();
955         }
956     }
957
958     private void stopHeartBeat() {
959         if (heartbeatSchedule != null && !heartbeatSchedule.isCancelled()) {
960             heartbeatSchedule.cancel();
961         }
962     }
963
964     private void scheduleHeartBeat(final FiniteDuration interval) {
965         if (followerToLog.isEmpty()) {
966             // Optimization - do not bother scheduling a heartbeat as there are
967             // no followers
968             return;
969         }
970
971         stopHeartBeat();
972
973         // Schedule a heartbeat. When the scheduler triggers a SendHeartbeat
974         // message is sent to itself.
975         // Scheduling the heartbeat only once here because heartbeats do not
976         // need to be sent if there are other messages being sent to the remote
977         // actor.
978         heartbeatSchedule = context.getActorSystem().scheduler().scheduleOnce(
979             interval, context.getActor(), SendHeartBeat.INSTANCE,
980             context.getActorSystem().dispatcher(), context.getActor());
981     }
982
983     @Override
984     public void close() {
985         stopHeartBeat();
986         appendEntriesMessageSlicer.close();
987     }
988
989     @Override
990     public final String getLeaderId() {
991         return context.getId();
992     }
993
994     @Override
995     public final short getLeaderPayloadVersion() {
996         return context.getPayloadVersion();
997     }
998
999     protected boolean isLeaderIsolated() {
1000         int minPresent = getMinIsolatedLeaderPeerCount();
1001         for (FollowerLogInformation followerLogInformation : followerToLog.values()) {
1002             final PeerInfo peerInfo = context.getPeerInfo(followerLogInformation.getId());
1003             if (peerInfo != null && peerInfo.isVoting() && followerLogInformation.isFollowerActive()) {
1004                 --minPresent;
1005                 if (minPresent == 0) {
1006                     return false;
1007                 }
1008             }
1009         }
1010         return minPresent != 0;
1011     }
1012
1013     // called from example-actor for printing the follower-states
1014     public String printFollowerStates() {
1015         final StringBuilder sb = new StringBuilder();
1016
1017         sb.append('[');
1018         for (FollowerLogInformation followerLogInformation : followerToLog.values()) {
1019             sb.append('{');
1020             sb.append(followerLogInformation.getId());
1021             sb.append(" state:");
1022             sb.append(followerLogInformation.isFollowerActive());
1023             sb.append("},");
1024         }
1025         sb.append(']');
1026
1027         return sb.toString();
1028     }
1029
1030     @VisibleForTesting
1031     public FollowerLogInformation getFollower(final String followerId) {
1032         return followerToLog.get(followerId);
1033     }
1034
1035     @VisibleForTesting
1036     public int followerLogSize() {
1037         return followerToLog.size();
1038     }
1039
1040     static class SnapshotHolder {
1041         private final long lastIncludedTerm;
1042         private final long lastIncludedIndex;
1043         private final ByteSource snapshotBytes;
1044
1045         SnapshotHolder(final Snapshot snapshot, final ByteSource snapshotBytes) {
1046             this.lastIncludedTerm = snapshot.getLastAppliedTerm();
1047             this.lastIncludedIndex = snapshot.getLastAppliedIndex();
1048             this.snapshotBytes = snapshotBytes;
1049         }
1050
1051         long getLastIncludedTerm() {
1052             return lastIncludedTerm;
1053         }
1054
1055         long getLastIncludedIndex() {
1056             return lastIncludedIndex;
1057         }
1058
1059         ByteSource getSnapshotBytes() {
1060             return snapshotBytes;
1061         }
1062     }
1063 }