Bug 4564: Implement restore from snapshot in RaftActor
[controller.git] / opendaylight / md-sal / sal-akka-raft / src / main / java / org / opendaylight / controller / cluster / raft / RaftActorRecoverySupport.java
1 /*
2  * Copyright (c) 2015 Brocade Communications 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 package org.opendaylight.controller.cluster.raft;
9
10 import akka.persistence.RecoveryCompleted;
11 import akka.persistence.SnapshotOffer;
12 import akka.persistence.SnapshotSelectionCriteria;
13 import com.google.common.base.Stopwatch;
14 import java.io.ByteArrayInputStream;
15 import java.io.ObjectInputStream;
16 import org.opendaylight.controller.cluster.DataPersistenceProvider;
17 import org.opendaylight.controller.cluster.PersistentDataProvider;
18 import org.opendaylight.controller.cluster.raft.base.messages.ApplyJournalEntries;
19 import org.opendaylight.controller.cluster.raft.base.messages.ApplyLogEntries;
20 import org.opendaylight.controller.cluster.raft.base.messages.ApplySnapshot;
21 import org.opendaylight.controller.cluster.raft.base.messages.DeleteEntries;
22 import org.opendaylight.controller.cluster.raft.base.messages.UpdateElectionTerm;
23 import org.opendaylight.controller.cluster.raft.behaviors.RaftActorBehavior;
24 import org.slf4j.Logger;
25
26 /**
27  * Support class that handles persistence recovery for a RaftActor.
28  *
29  * @author Thomas Pantelis
30  */
31 class RaftActorRecoverySupport {
32     private final RaftActorContext context;
33     private final RaftActorBehavior currentBehavior;
34     private final RaftActorRecoveryCohort cohort;
35
36     private int currentRecoveryBatchCount;
37     private boolean dataRecoveredWithPersistenceDisabled;
38     private boolean anyDataRecovered;
39
40     private Stopwatch recoveryTimer;
41     private final Logger log;
42
43     RaftActorRecoverySupport(RaftActorContext context, RaftActorBehavior currentBehavior,
44             RaftActorRecoveryCohort cohort) {
45         this.context = context;
46         this.currentBehavior = currentBehavior;
47         this.cohort = cohort;
48         this.log = context.getLogger();
49     }
50
51     boolean handleRecoveryMessage(Object message, PersistentDataProvider persistentProvider) {
52         log.trace("{}: handleRecoveryMessage: {}", context.getId(), message);
53
54         anyDataRecovered = anyDataRecovered || !(message instanceof RecoveryCompleted);
55
56         boolean recoveryComplete = false;
57         DataPersistenceProvider persistence = context.getPersistenceProvider();
58         if (message instanceof org.opendaylight.controller.cluster.raft.RaftActor.UpdateElectionTerm) {
59             // Handle this message for backwards compatibility with pre-Lithium versions.
60             org.opendaylight.controller.cluster.raft.RaftActor.UpdateElectionTerm update =
61                     (org.opendaylight.controller.cluster.raft.RaftActor.UpdateElectionTerm)message;
62             context.getTermInformation().update(update.getCurrentTerm(), update.getVotedFor());
63         } else if (message instanceof UpdateElectionTerm) {
64             context.getTermInformation().update(((UpdateElectionTerm) message).getCurrentTerm(),
65                     ((UpdateElectionTerm) message).getVotedFor());
66         } else if(persistence.isRecoveryApplicable()) {
67             if (message instanceof SnapshotOffer) {
68                 onRecoveredSnapshot((SnapshotOffer) message);
69             } else if (message instanceof ReplicatedLogEntry) {
70                 onRecoveredJournalLogEntry((ReplicatedLogEntry) message);
71             } else if (message instanceof ApplyLogEntries) {
72                 // Handle this message for backwards compatibility with pre-Lithium versions.
73                 onRecoveredApplyLogEntries(((ApplyLogEntries) message).getToIndex());
74             } else if (message instanceof ApplyJournalEntries) {
75                 onRecoveredApplyLogEntries(((ApplyJournalEntries) message).getToIndex());
76             } else if (message instanceof DeleteEntries) {
77                 replicatedLog().removeFrom(((DeleteEntries) message).getFromIndex());
78             } else if (message instanceof org.opendaylight.controller.cluster.raft.RaftActor.DeleteEntries) {
79                 // Handle this message for backwards compatibility with pre-Lithium versions.
80                 replicatedLog().removeFrom(((org.opendaylight.controller.cluster.raft.RaftActor.DeleteEntries) message).getFromIndex());
81             } else if (message instanceof RecoveryCompleted) {
82                 onRecoveryCompletedMessage();
83                 possiblyRestoreFromSnapshot();
84                 recoveryComplete = true;
85             }
86         } else if (message instanceof RecoveryCompleted) {
87             recoveryComplete = true;
88
89             if(dataRecoveredWithPersistenceDisabled) {
90                 // Data persistence is disabled but we recovered some data entries so we must have just
91                 // transitioned to disabled or a persistence backup was restored. Either way, delete all the
92                 // messages from the akka journal for efficiency and so that we do not end up with consistency
93                 // issues in case persistence is -re-enabled.
94                 persistentProvider.deleteMessages(persistentProvider.getLastSequenceNumber());
95
96                 // Delete all the akka snapshots as they will not be needed
97                 persistentProvider.deleteSnapshots(new SnapshotSelectionCriteria(scala.Long.MaxValue(),
98                         scala.Long.MaxValue()));
99
100                 // Since we cleaned out the journal, we need to re-write the current election info.
101                 context.getTermInformation().updateAndPersist(context.getTermInformation().getCurrentTerm(),
102                         context.getTermInformation().getVotedFor());
103             }
104
105             possiblyRestoreFromSnapshot();
106         } else {
107             boolean isServerConfigPayload = false;
108             if(message instanceof ReplicatedLogEntry){
109                 ReplicatedLogEntry repLogEntry = (ReplicatedLogEntry)message;
110                 if(isServerConfigurationPayload(repLogEntry)){
111                     isServerConfigPayload = true;
112                     context.updatePeerIds((ServerConfigurationPayload)repLogEntry.getData());
113                 }
114             }
115
116             if(!isServerConfigPayload){
117                 dataRecoveredWithPersistenceDisabled = true;
118             }
119         }
120
121         return recoveryComplete;
122     }
123
124     private void possiblyRestoreFromSnapshot() {
125         byte[] restoreFromSnapshot = cohort.getRestoreFromSnapshot();
126         if(restoreFromSnapshot == null) {
127             return;
128         }
129
130         if(anyDataRecovered) {
131             log.warn("{}: The provided restore snapshot was not applied because the persistence store is not empty",
132                     context.getId());
133             return;
134         }
135
136         try(ObjectInputStream ois = new ObjectInputStream(new ByteArrayInputStream(restoreFromSnapshot))) {
137             Snapshot snapshot = (Snapshot) ois.readObject();
138
139             log.debug("{}: Deserialized restore snapshot: {}", context.getId(), snapshot);
140
141             context.getSnapshotManager().apply(new ApplySnapshot(snapshot));
142         } catch(Exception e) {
143             log.error("{}: Error deserializing snapshot restore", context.getId(), e);
144         }
145     }
146
147     private ReplicatedLog replicatedLog() {
148         return context.getReplicatedLog();
149     }
150
151     private void initRecoveryTimer() {
152         if(recoveryTimer == null) {
153             recoveryTimer = Stopwatch.createStarted();
154         }
155     }
156
157     private void onRecoveredSnapshot(SnapshotOffer offer) {
158         if(log.isDebugEnabled()) {
159             log.debug("{}: SnapshotOffer called..", context.getId());
160         }
161
162         initRecoveryTimer();
163
164         Snapshot snapshot = (Snapshot) offer.snapshot();
165
166         // Create a replicated log with the snapshot information
167         // The replicated log can be used later on to retrieve this snapshot
168         // when we need to install it on a peer
169
170         context.setReplicatedLog(ReplicatedLogImpl.newInstance(snapshot, context, currentBehavior));
171         context.setLastApplied(snapshot.getLastAppliedIndex());
172         context.setCommitIndex(snapshot.getLastAppliedIndex());
173         context.getTermInformation().update(snapshot.getElectionTerm(), snapshot.getElectionVotedFor());
174
175         Stopwatch timer = Stopwatch.createStarted();
176
177         // Apply the snapshot to the actors state
178         cohort.applyRecoverySnapshot(snapshot.getState());
179
180         timer.stop();
181         log.info("Recovery snapshot applied for {} in {}: snapshotIndex={}, snapshotTerm={}, journal-size={}",
182                 context.getId(), timer.toString(), replicatedLog().getSnapshotIndex(),
183                 replicatedLog().getSnapshotTerm(), replicatedLog().size());
184     }
185
186     private void onRecoveredJournalLogEntry(ReplicatedLogEntry logEntry) {
187         if(log.isDebugEnabled()) {
188             log.debug("{}: Received ReplicatedLogEntry for recovery: index: {}, size: {}", context.getId(),
189                     logEntry.getIndex(), logEntry.size());
190         }
191
192         if(isServerConfigurationPayload(logEntry)){
193             context.updatePeerIds((ServerConfigurationPayload)logEntry.getData());
194         }
195         replicatedLog().append(logEntry);
196     }
197
198     private void onRecoveredApplyLogEntries(long toIndex) {
199         long lastUnappliedIndex = context.getLastApplied() + 1;
200
201         if(log.isDebugEnabled()) {
202             // it can happen that lastUnappliedIndex > toIndex, if the AJE is in the persistent journal
203             // but the entry itself has made it to that state and recovered via the snapshot
204             log.debug("{}: Received apply journal entries for recovery, applying to state: {} to {}",
205                     context.getId(), lastUnappliedIndex, toIndex);
206         }
207
208         long lastApplied = lastUnappliedIndex - 1;
209         for (long i = lastUnappliedIndex; i <= toIndex; i++) {
210             ReplicatedLogEntry logEntry = replicatedLog().get(i);
211             if(logEntry != null) {
212                 lastApplied++;
213                 batchRecoveredLogEntry(logEntry);
214             } else {
215                 // Shouldn't happen but cover it anyway.
216                 log.error("{}: Log entry not found for index {}", context.getId(), i);
217                 break;
218             }
219         }
220
221         context.setLastApplied(lastApplied);
222         context.setCommitIndex(lastApplied);
223     }
224
225     private void batchRecoveredLogEntry(ReplicatedLogEntry logEntry) {
226         initRecoveryTimer();
227
228         int batchSize = context.getConfigParams().getJournalRecoveryLogBatchSize();
229         if(!isServerConfigurationPayload(logEntry)){
230             if(currentRecoveryBatchCount == 0) {
231                 cohort.startLogRecoveryBatch(batchSize);
232             }
233
234             cohort.appendRecoveredLogEntry(logEntry.getData());
235
236             if(++currentRecoveryBatchCount >= batchSize) {
237                 endCurrentLogRecoveryBatch();
238             }
239         }
240     }
241
242     private void endCurrentLogRecoveryBatch() {
243         cohort.applyCurrentLogRecoveryBatch();
244         currentRecoveryBatchCount = 0;
245     }
246
247     private void onRecoveryCompletedMessage() {
248         if(currentRecoveryBatchCount > 0) {
249             endCurrentLogRecoveryBatch();
250         }
251
252         String recoveryTime = "";
253         if(recoveryTimer != null) {
254             recoveryTimer.stop();
255             recoveryTime = " in " + recoveryTimer.toString();
256             recoveryTimer = null;
257         }
258
259         log.info("Recovery completed" + recoveryTime + " - Switching actor to Follower - " +
260                  "Persistence Id =  " + context.getId() +
261                  " Last index in log = {}, snapshotIndex = {}, snapshotTerm = {}, " +
262                  "journal-size = {}", replicatedLog().lastIndex(), replicatedLog().getSnapshotIndex(),
263                  replicatedLog().getSnapshotTerm(), replicatedLog().size());
264     }
265
266     private boolean isServerConfigurationPayload(ReplicatedLogEntry repLogEntry){
267         return (repLogEntry.getData() instanceof ServerConfigurationPayload);
268     }
269 }