Add a gauge to hold the last restore time that

api.go

@@ -323,6 +323,12 @@ func RecoverCluster(conf *Config, fsm FSM, logs LogStore, stable StableStore,
 			continue
 		}
 
+		// Note this is the one place we call fsm.Restore without the
+		// fsmRestoreAndMeasure wrapper since this function should only be called to
+		// reset state on disk and the FSM passed will not be used for a running
+		// server instance. If the same process will eventually become a Raft peer
+		// then it will call NewRaft and restore again from disk then which will
+		// report metrics.
 		err = fsm.Restore(source)
 		// Close the source after the restore has completed
 		source.Close()
@@ -598,16 +604,16 @@ func (r *Raft) restoreSnapshot() error {
 				continue
 			}
 
-			err = r.fsm.Restore(source)
-			// Close the source after the restore has completed
-			source.Close()
-			if err != nil {
+			if err := fsmRestoreAndMeasure(r.fsm, source); err != nil {
+				source.Close()
 				r.logger.Error("failed to restore snapshot", "id", snapshot.ID, "error", err)
 				continue
 			}
+			source.Close()
 
 			r.logger.Info("restored from snapshot", "id", snapshot.ID)
 		}
+
 		// Update the lastApplied so we don't replay old logs
 		r.setLastApplied(snapshot.Index)
 

fsm.go

@@ -175,16 +175,13 @@ func (r *Raft) runFSM() {
 			req.respond(fmt.Errorf("failed to open snapshot %v: %v", req.ID, err))
 			return
 		}
+		defer source.Close()
 
 		// Attempt to restore
-		start := time.Now()
-		if err := r.fsm.Restore(source); err != nil {
+		if err := fsmRestoreAndMeasure(r.fsm, source); err != nil {
 			req.respond(fmt.Errorf("failed to restore snapshot %v: %v", req.ID, err))
-			source.Close()
 			return
 		}
-		source.Close()
-		metrics.MeasureSince([]string{"raft", "fsm", "restore"}, start)
 
 		// Update the last index and term
 		lastIndex = meta.Index
@@ -233,3 +230,17 @@ func (r *Raft) runFSM() {
 		}
 	}
 }
+
+// fsmRestoreAndMeasure wraps the Restore call on an FSM to consistently measure
+// and report timing metrics. The caller is still responsible for calling Close
+// on the source in all cases.
+func fsmRestoreAndMeasure(fsm FSM, source io.ReadCloser) error {
+	start := time.Now()
+	if err := fsm.Restore(source); err != nil {
+		return err
+	}
+	metrics.MeasureSince([]string{"raft", "fsm", "restore"}, start)
+	metrics.SetGauge([]string{"raft", "fsm", "lastRestoreDuration"},
+		float32(time.Since(start).Milliseconds()))
+	return nil
+}