Merge pull request #249 from setlog/feature-log-limit

Feature log limit

Author: dragetd

CHANGES.md

@@ -10,6 +10,7 @@
 * Update dependencies to recent versions: gopsutils, testify, gojsonschema, logrus, prometheus/client_golang, go_ieproxy, fatih/color, golang/x/sys, golang/x/net
 * Do not hide the download speed label, even if the speed is zero.
 * The download-speed label now shows a 3 second average.
+* The same download-related log messages will now be printed at most 5 times (with information about this limit in the last message).
 * `hasher` will no longer blindly overwrite an existing bundleinfo.json but instead error out.
 * `hasher` will now exit with an error when the `pathToHash` has no files to hash.
 ### Features

cmd/launcher/gui/gui_progress_handler.go

@@ -7,7 +7,7 @@ import (
 
 	"net/http"
 
-	log "github.com/sirupsen/logrus"
+	"github.com/setlog/trivrost/pkg/logging"
 )
 
 // Implements fetching.DownloadProgressHandler
@@ -16,10 +16,11 @@ type GuiDownloadProgressHandler struct {
 	progressAccumulator    uint64
 	ongoingProgressBuckets []uint64
 	problemUrl             string
+	log                    *logging.LogLimiter
 }
 
 func NewGuiDownloadProgressHandler(bucketCount int) *GuiDownloadProgressHandler {
-	return &GuiDownloadProgressHandler{progressMutex: &sync.RWMutex{}, ongoingProgressBuckets: make([]uint64, bucketCount)}
+	return &GuiDownloadProgressHandler{progressMutex: &sync.RWMutex{}, ongoingProgressBuckets: make([]uint64, bucketCount), log: logging.NewLogLimiter(5)}
 }
 
 func (handler *GuiDownloadProgressHandler) ResetProgress() {
@@ -61,15 +62,15 @@ func (handler *GuiDownloadProgressHandler) HandleFinishDownload(fromURL string,
 }
 
 func (handler *GuiDownloadProgressHandler) HandleFailDownload(fromURL string, workerId int, err error) {
-	log.Errorf("GET %s failed: %v", fromURL, err)
+	handler.log.Errorf("GET %s failed: %v", fromURL, err)
 	handler.progressMutex.Lock()
 	defer handler.progressMutex.Unlock()
 	handler.problemUrl = fromURL
 	NotifyProblem("Security error", false)
 }
 
 func (handler *GuiDownloadProgressHandler) HandleHttpGetError(fromURL string, err error) {
-	log.Warnf("GET %s could not start: %v", fromURL, err)
+	handler.log.Warnf("GET %s could not start: %v", fromURL, err)
 	handler.progressMutex.Lock()
 	defer handler.progressMutex.Unlock()
 	handler.problemUrl = fromURL
@@ -84,15 +85,15 @@ func (handler *GuiDownloadProgressHandler) HandleHttpGetError(fromURL string, er
 }
 
 func (handler *GuiDownloadProgressHandler) HandleBadHttpResponse(fromURL string, code int) {
-	log.Warnf("GET %s, error %d: %s", fromURL, code, http.StatusText(code))
+	handler.log.Warnf("GET %s, error %d: %s", fromURL, code, http.StatusText(code))
 	handler.progressMutex.Lock()
 	defer handler.progressMutex.Unlock()
 	handler.problemUrl = fromURL
 	NotifyProblem(fmt.Sprintf("HTTP Status %d", code), false)
 }
 
 func (handler *GuiDownloadProgressHandler) HandleReadError(fromURL string, err error, receivedByteCount int64) {
-	log.Warnf("GET %s interrupted after receiving %d bytes: %v.", fromURL, receivedByteCount, err)
+	handler.log.Warnf("GET %s interrupted after receiving %d bytes: %v.", fromURL, receivedByteCount, err)
 	handler.progressMutex.Lock()
 	defer handler.progressMutex.Unlock()
 	handler.problemUrl = fromURL

pkg/fetching/download.go

@@ -72,11 +72,11 @@ type Download struct {
 	firstByteIndex        int64
 	lastByteIndex         int64
 
-	client         *http.Client
-	request        *http.Request
-	cancelRequest  context.CancelFunc
-	cooldownTime   time.Time
-	cooldownStacks int
+	client        *http.Client
+	request       *http.Request
+	cancelRequest context.CancelFunc
+	cooldownTime  time.Time
+	cooldownIndex int
 
 	response       *http.Response
 	responseReader io.Reader
@@ -261,7 +261,7 @@ func (dl *Download) cleanUp() {
 
 func (dl *Download) waitCooldown() {
 	now := time.Now()
-	if dl.cooldownStacks > 0 && dl.cooldownTime.After(now) {
+	if dl.cooldownIndex > 0 && dl.cooldownTime.After(now) {
 		select {
 		case <-time.NewTimer(dl.cooldownTime.Sub(now)).C:
 		case <-dl.ctx.Done():
@@ -272,8 +272,7 @@ func (dl *Download) waitCooldown() {
 
 func (dl *Download) inscribeCooldown() {
 	cooldownIntervalOptions := []time.Duration{1, 1, 2, 3, 5, 8, 13}
-	cooldownOptionIndex := intMin(dl.cooldownStacks, len(cooldownIntervalOptions)-1)
-	cooldownDuration := time.Second * cooldownIntervalOptions[cooldownOptionIndex]
+	cooldownDuration := time.Second * cooldownIntervalOptions[dl.cooldownIndex]
 
 	p := make([]byte, 1)
 	_, err := rand.Read(p)
@@ -285,11 +284,11 @@ func (dl *Download) inscribeCooldown() {
 	}
 
 	dl.cooldownTime = time.Now().Add(cooldownDuration)
-	dl.cooldownStacks++
+	dl.cooldownIndex = intMin(dl.cooldownIndex+1, len(cooldownIntervalOptions)-1)
 }
 
 func (dl *Download) resetCooldown() {
-	dl.cooldownStacks = 0
+	dl.cooldownIndex = 0
 }
 
 func intMin(a, b int) int {

pkg/fetching/helpers.go

@@ -12,7 +12,7 @@ import (
 	"time"
 
 	"github.com/mattn/go-ieproxy"
-	log "github.com/sirupsen/logrus"
+	"github.com/setlog/trivrost/pkg/logging"
 )
 
 func MakeClient() *http.Client {
@@ -35,6 +35,7 @@ func MakeClient() *http.Client {
 
 func GetProxyLoggingFunc() func(req *http.Request) (*url.URL, error) {
 	proxyFunc := ieproxy.GetProxyFunc()
+	log := logging.NewLogLimiter(5)
 	return func(req *http.Request) (*url.URL, error) {
 		proxyURL, err := proxyFunc(req)
 		if err != nil {

pkg/logging/log_limiter.go

@@ -0,0 +1,59 @@
+package logging
+
+import (
+	"fmt"
+	"sync"
+	"sync/atomic"
+
+	log "github.com/sirupsen/logrus"
+)
+
+type LogLimiter struct {
+	limit        int64
+	seenMessages *sync.Map
+}
+
+func NewLogLimiter(limit int) *LogLimiter {
+	return &LogLimiter{limit: int64(limit), seenMessages: &sync.Map{}}
+}
+
+func (l *LogLimiter) Logf(level log.Level, format string, args ...interface{}) {
+	l.Log(level, fmt.Sprintf(format, args...))
+}
+
+func (l *LogLimiter) Log(level log.Level, message string) {
+	var seenCount int64 = 0
+	seenCountP, _ := l.seenMessages.LoadOrStore(message, &seenCount)
+	seenCount = atomic.AddInt64(seenCountP.(*int64), 1)
+	if seenCount <= l.limit {
+		if seenCount == l.limit {
+			log.StandardLogger().Logf(level, "%v (Last log of this message due to excess)", message)
+		} else {
+			log.StandardLogger().Log(level, message)
+		}
+	}
+}
+
+func (l *LogLimiter) Infof(format string, args ...interface{}) {
+	l.Logf(log.InfoLevel, format, args...)
+}
+
+func (l *LogLimiter) Info(message string) {
+	l.Log(log.InfoLevel, message)
+}
+
+func (l *LogLimiter) Warnf(format string, args ...interface{}) {
+	l.Logf(log.WarnLevel, format, args...)
+}
+
+func (l *LogLimiter) Warn(message string) {
+	l.Log(log.WarnLevel, message)
+}
+
+func (l *LogLimiter) Errorf(format string, args ...interface{}) {
+	l.Logf(log.ErrorLevel, format, args...)
+}
+
+func (l *LogLimiter) Error(message string) {
+	l.Log(log.ErrorLevel, message)
+}