Better timing from first to last log

store/store.go

@@ -125,6 +125,7 @@ type Store struct {
 	boltStore     *raftboltdb.BoltStore     // Physical store.
 
 	lastIdxOnOpen    uint64    // Last index on log when Store opens.
+	firstLogAppliedT time.Time // Time first log is applied
 	appliedOnOpen    uint64    // Number of logs applied at open.
 	openT            time.Time // Timestamp when Store opens.
 
@@ -881,11 +882,16 @@ func (s *Store) Apply(l *raft.Log) interface{} {
 		if l.Index <= s.lastIdxOnOpen {
 			s.appliedOnOpen++
 			if l.Index == s.lastIdxOnOpen {
-				s.logger.Printf("%d committed log entries applied in %s",
-					s.appliedOnOpen, time.Since(s.openT))
+				s.logger.Printf("%d committed log entries applied in %s, took %s since open",
+					s.appliedOnOpen, time.Since(s.firstLogAppliedT), time.Since(s.openT))
 			}
 		}
 	}()
+
+	if s.firstLogAppliedT.IsZero() {
+		s.firstLogAppliedT = time.Now()
+	}
+
 	var c command.Command
 
 	if err := legacy.Unmarshal(l.Data, &c); err != nil {