Merge pull request #419 from carlosms/i-385

Avoid repeated API error messages

provider/github/err_throttler.go

@@ -0,0 +1,48 @@
+package github
+
+import (
+	"time"
+
+	log "gopkg.in/src-d/go-log.v1"
+)
+
+// errThrottlerInterval controls how often repeated ErrGitHubAPI (like 404)
+// are logged with Error level. The rest of the logs will be logged as Debug
+const errThrottlerInterval = 5 * time.Minute
+
+type errThrottlerState struct {
+	lastWhen time.Time
+	lastErr  string
+}
+
+// errThrottlerLogger is a logger that logs repeated error messages as Debug
+// level. An Error level is used once every errThrottlerInterval
+type errThrottlerLogger struct {
+	log.Logger
+	*errThrottlerState
+}
+
+func newErrThrottlerLogger(log log.Logger, state *errThrottlerState) *errThrottlerLogger {
+	return &errThrottlerLogger{log, state}
+}
+
+func (l *errThrottlerLogger) With(f log.Fields) log.Logger {
+	return &errThrottlerLogger{l.Logger.With(f), l.errThrottlerState}
+}
+
+func (l *errThrottlerLogger) Errorf(err error, format string, args ...interface{}) {
+	// log on Error level if the last message was different, or if the last time
+	// was longer than errThrottlerInterval ago
+	asErrLevel := l.lastErr != err.Error() ||
+		time.Now().After(l.lastWhen.Add(errThrottlerInterval))
+
+	if asErrLevel {
+		l.lastErr = err.Error()
+		l.lastWhen = time.Now()
+
+		l.Logger.Errorf(err, format, args...)
+		return
+	}
+
+	l.Logger.With(log.Fields{"error": err.Error()}).Debugf(format, args...)
+}

provider/github/watcher.go

@@ -40,14 +40,17 @@ var (
 type Watcher struct {
 	pool *ClientPool
 	// maps clients to functions that stop watching the client
-	stopFuncs map[*Client]func()
+	stopFuncs               map[*Client]func()
+	lastErrPR, lastErrEvent map[*lookout.RepositoryInfo]*errThrottlerState
 }
 
 // NewWatcher returns a new
 func NewWatcher(pool *ClientPool) (*Watcher, error) {
 	return &Watcher{
-		pool:      pool,
-		stopFuncs: make(map[*Client]func()),
+		pool:         pool,
+		stopFuncs:    make(map[*Client]func()),
+		lastErrPR:    make(map[*lookout.RepositoryInfo]*errThrottlerState),
+		lastErrEvent: make(map[*lookout.RepositoryInfo]*errThrottlerState),
 	}, nil
 }
 
@@ -177,9 +180,18 @@ func (w *Watcher) processRepoPRs(
 ) (time.Duration, error) {
 	resp, prs, err := w.doPRListRequest(ctx, c, repo.Owner, repo.Name)
 	if ErrGitHubAPI.Is(err) {
-		ctxlog.Get(ctx).With(log.Fields{
+		if w.lastErrPR[repo] == nil {
+			w.lastErrPR[repo] = &errThrottlerState{}
+		}
+
+		// go-errors %+v prints the stack trace. Doing this we create a plain
+		// error with no stack trace for the log
+		err := fmt.Errorf("%s", err)
+
+		newErrThrottlerLogger(ctxlog.Get(ctx), w.lastErrPR[repo]).With(log.Fields{
 			"repository": repo.FullName, "response": resp,
 		}).Errorf(err, "request for PR list failed")
+
 		return c.watchMinInterval, nil
 	}
 
@@ -199,9 +211,18 @@ func (w *Watcher) processRepoEvents(
 ) (time.Duration, error) {
 	resp, events, err := w.doEventRequest(ctx, c, repo.Owner, repo.Name)
 	if ErrGitHubAPI.Is(err) {
-		ctxlog.Get(ctx).With(log.Fields{
+		if w.lastErrEvent[repo] == nil {
+			w.lastErrEvent[repo] = &errThrottlerState{}
+		}
+
+		// go-errors %+v prints the stack trace. Doing this we create a plain
+		// error with no stack trace for the log
+		err := fmt.Errorf("%s", err)
+
+		newErrThrottlerLogger(ctxlog.Get(ctx), w.lastErrEvent[repo]).With(log.Fields{
 			"repository": repo.FullName, "response": resp,
 		}).Errorf(err, "request for events list failed")
+
 		return c.PollInterval(eventsCategory), nil
 	}