Raft: Check suspect info once per suspect interval

orderer/consensus/etcdraft/chain.go

@@ -369,6 +369,7 @@ func (c *Chain) Start() {
 	c.periodicChecker = &PeriodicCheck{
 		Logger:        c.logger,
 		Report:        es.confirmSuspicion,
+		ReportCleared: es.clearSuspicion,
 		CheckInterval: interval,
 		Condition:     c.suspectEviction,
 	}

orderer/consensus/etcdraft/eviction.go

@@ -26,6 +26,7 @@ type PeriodicCheck struct {
 	CheckInterval       time.Duration
 	Condition           func() bool
 	Report              func(cumulativePeriod time.Duration)
+	ReportCleared       func()
 	conditionHoldsSince time.Time
 	once                sync.Once // Used to prevent double initialization
 	stopped             uint32
@@ -60,6 +61,9 @@ func (pc *PeriodicCheck) check() {
 }
 
 func (pc *PeriodicCheck) conditionNotFulfilled() {
+	if pc.ReportCleared != nil && !pc.conditionHoldsSince.IsZero() {
+		pc.ReportCleared()
+	}
 	pc.conditionHoldsSince = time.Time{}
 }
 
@@ -81,12 +85,20 @@ type evictionSuspector struct {
 	writeBlock                 func(block *common.Block) error
 	triggerCatchUp             func(sn *raftpb.Snapshot)
 	halted                     bool
+	timesTriggered             int
+}
+
+func (es *evictionSuspector) clearSuspicion() {
+	es.timesTriggered = 0
 }
 
 func (es *evictionSuspector) confirmSuspicion(cumulativeSuspicion time.Duration) {
-	if es.evictionSuspicionThreshold > cumulativeSuspicion || es.halted {
+	// The goal here is to only execute the body of the function once every es.evictionSuspicionThreshold
+	if es.evictionSuspicionThreshold*time.Duration(es.timesTriggered+1) > cumulativeSuspicion || es.halted {
 		return
 	}
+	es.timesTriggered++
+
 	es.logger.Infof("Suspecting our own eviction from the channel for %v", cumulativeSuspicion)
 	puller, err := es.createPuller()
 	if err != nil {

orderer/consensus/etcdraft/eviction_test.go

@@ -48,11 +48,18 @@ func TestPeriodicCheck(t *testing.T) {
 		reports <- duration
 	}
 
+	clears := make(chan struct{}, 1000)
+
+	reportCleared := func() {
+		clears <- struct{}{}
+	}
+
 	check := &PeriodicCheck{
 		Logger:        flogging.MustGetLogger("test"),
 		Condition:     condition,
 		CheckInterval: time.Millisecond,
 		Report:        report,
+		ReportCleared: reportCleared,
 	}
 
 	go check.Run()
@@ -85,6 +92,9 @@ func TestPeriodicCheck(t *testing.T) {
 		}
 	}
 
+	g.Eventually(clears).Should(gomega.Receive())
+	g.Consistently(clears).ShouldNot(gomega.Receive())
+
 	// ensure the checks have been made
 	checksDoneSoFar := atomic.LoadUint32(&checkNum)
 	g.Consistently(reports, time.Second*2, time.Millisecond).Should(gomega.BeEmpty())
@@ -107,6 +117,7 @@ func TestPeriodicCheck(t *testing.T) {
 	time.Sleep(check.CheckInterval * 50)
 	// Ensure that we cease checking the condition, hence the PeriodicCheck is stopped.
 	g.Expect(atomic.LoadUint32(&checkNum)).To(gomega.BeNumerically("<", checkCountAfterStop+2))
+	g.Consistently(clears).ShouldNot(gomega.Receive())
 }
 
 func TestEvictionSuspector(t *testing.T) {
@@ -137,13 +148,20 @@ func TestEvictionSuspector(t *testing.T) {
 		blockPuller                 BlockPuller
 		blockPullerErr              error
 		height                      uint64
+		timesTriggered              int
 		halt                        func()
 	}{
 		{
 			description:                "suspected time is lower than threshold",
 			evictionSuspicionThreshold: 11 * time.Minute,
 			halt:                       t.Fail,
 		},
+		{
+			description:                "timesTriggered multiplier prevents threshold",
+			evictionSuspicionThreshold: 6 * time.Minute,
+			timesTriggered:             1,
+			halt:                       t.Fail,
+		},
 		{
 			description:                "puller creation fails",
 			evictionSuspicionThreshold: 10*time.Minute - time.Second,
@@ -219,6 +237,7 @@ func TestEvictionSuspector(t *testing.T) {
 				},
 				logger:         flogging.MustGetLogger("test"),
 				triggerCatchUp: func(sn *raftpb.Snapshot) {},
+				timesTriggered: testCase.timesTriggered,
 			}
 
 			foundExpectedLog := testCase.expectedLog == ""