Fix backoff error never logged after a success

backoff/backoff.go

@@ -17,7 +17,7 @@ type backoff struct {
 // each iterations.  If it hits an error, it exponentially backs
 // off to maxBackoff.  Backoff will log when it backs off, but
 // will stop logging when it reaches maxBackoff.  It will also
-// log on first success.
+// log on first success in the beginning and after errors.
 type Interface interface {
 	Start()
 	Stop()
@@ -65,12 +65,13 @@ func (b *backoff) Start() {
 
 		if err != nil {
 			backoff *= 2
+			shouldLog = true
 			if backoff > b.maxBackoff {
 				backoff = b.maxBackoff
+				shouldLog = false
 			}
-		} else if backoff > b.initialBackoff {
+		} else {
 			backoff = b.initialBackoff
-			shouldLog = true
 		}
 
 		if shouldLog {
@@ -82,9 +83,9 @@ func (b *backoff) Start() {
 			}
 		}
 
-		if backoff >= b.maxBackoff || err == nil {
-			shouldLog = false
-		}
+		// Re-enable logging if we came from an error (suppressed or not)
+		// since we want to log in case a success follows.
+		shouldLog = err != nil
 
 		select {
 		case <-time.After(backoff):

backoff/backoff_test.go

@@ -0,0 +1,56 @@
+package backoff_test
+
+import (
+	"errors"
+	"testing"
+	"time"
+
+	log "github.com/Sirupsen/logrus"
+	"github.com/Sirupsen/logrus/hooks/test"
+	"github.com/weaveworks/common/backoff"
+)
+
+func TestLog(t *testing.T) {
+	hook := test.NewGlobal()
+
+	err := errors.New("sample")
+	cases := []struct {
+		returns           []error
+		expectedLastLevel log.Level
+		expectedCount     int
+	}{
+		{[]error{nil}, log.InfoLevel, 1},
+		{[]error{nil, nil /*x*/}, log.InfoLevel, 1},
+		{[]error{nil, err}, log.WarnLevel, 2},
+		{[]error{nil, err, nil}, log.InfoLevel, 3},
+		{[]error{nil, err, nil, nil /*x*/}, log.InfoLevel, 3},
+		{[]error{nil, err}, log.WarnLevel, 2},
+		{[]error{nil, err, err}, log.WarnLevel, 3},
+		{[]error{nil, err, err, err /*x*/}, log.WarnLevel, 3},
+		{[]error{nil, err, err, err /*x*/, nil}, log.InfoLevel, 4},
+	}
+
+	for ci, c := range cases {
+		hook.Reset()
+
+		ri := 0
+		bo := backoff.New(func() (done bool, err error) {
+			if ri >= len(c.returns) {
+				done, err = true, nil // abort
+			} else {
+				done, err = false, c.returns[ri]
+			}
+			ri++
+			return
+		}, "test")
+		bo.SetInitialBackoff(1 * time.Millisecond)
+		bo.SetMaxBackoff(4 * time.Millisecond) // exceeded at 3rd consecutive error
+		bo.Start()
+
+		if len(hook.Entries) != c.expectedCount {
+			t.Errorf("case #%d failed: expected log count %d but got %d", ci, c.expectedCount, len(hook.Entries))
+		} else if hook.LastEntry().Level != c.expectedLastLevel {
+			t.Errorf("case #%d failed: expected level %d but got %d", ci, c.expectedLastLevel, hook.LastEntry().Level)
+		}
+	}
+}