feat(usbgadget): suppress duplicate error logs (#630).

Author: ym

internal/usbgadget/hid_keyboard.go

@@ -143,15 +143,21 @@ func (u *UsbGadget) listenKeyboardEvents() {
 			default:
 				l.Trace().Msg("reading from keyboard")
 				if u.keyboardHidFile == nil {
-					l.Error().Msg("keyboardHidFile is nil")
+					u.logWithSupression("keyboardHidFileNil", 100, &l, nil, "keyboardHidFile is nil")
+					// show the error every 100 times to avoid spamming the logs
 					time.Sleep(time.Second)
 					continue
 				}
+				// reset the counter
+				u.resetLogSuppressionCounter("keyboardHidFileNil")
+
 				n, err := u.keyboardHidFile.Read(buf)
 				if err != nil {
-					l.Error().Err(err).Msg("failed to read")
+					u.logWithSupression("keyboardHidFileRead", 100, &l, err, "failed to read")
 					continue
 				}
+				u.resetLogSuppressionCounter("keyboardHidFileRead")
+
 				l.Trace().Int("n", n).Bytes("buf", buf).Msg("got data from keyboard")
 				if n != 1 {
 					l.Trace().Int("n", n).Msg("expected 1 byte, got")
@@ -195,12 +201,12 @@ func (u *UsbGadget) keyboardWriteHidFile(data []byte) error {
 
 	_, err := u.keyboardHidFile.Write(data)
 	if err != nil {
-		u.log.Error().Err(err).Msg("failed to write to hidg0")
+		u.logWithSupression("keyboardWriteHidFile", 100, u.log, err, "failed to write to hidg0")
 		u.keyboardHidFile.Close()
 		u.keyboardHidFile = nil
 		return err
 	}
-
+	u.resetLogSuppressionCounter("keyboardWriteHidFile")
 	return nil
 }
 

internal/usbgadget/hid_mouse_absolute.go

@@ -75,11 +75,12 @@ func (u *UsbGadget) absMouseWriteHidFile(data []byte) error {
 
 	_, err := u.absMouseHidFile.Write(data)
 	if err != nil {
-		u.log.Error().Err(err).Msg("failed to write to hidg1")
+		u.logWithSupression("absMouseWriteHidFile", 100, u.log, err, "failed to write to hidg1")
 		u.absMouseHidFile.Close()
 		u.absMouseHidFile = nil
 		return err
 	}
+	u.resetLogSuppressionCounter("absMouseWriteHidFile")
 	return nil
 }
 

internal/usbgadget/hid_mouse_relative.go

@@ -65,11 +65,12 @@ func (u *UsbGadget) relMouseWriteHidFile(data []byte) error {
 
 	_, err := u.relMouseHidFile.Write(data)
 	if err != nil {
-		u.log.Error().Err(err).Msg("failed to write to hidg2")
+		u.logWithSupression("relMouseWriteHidFile", 100, u.log, err, "failed to write to hidg2")
 		u.relMouseHidFile.Close()
 		u.relMouseHidFile = nil
 		return err
 	}
+	u.resetLogSuppressionCounter("relMouseWriteHidFile")
 	return nil
 }
 

internal/usbgadget/usbgadget.go

@@ -79,6 +79,8 @@ type UsbGadget struct {
 	onKeyboardStateChange *func(state KeyboardState)
 
 	log *zerolog.Logger
+
+	logSuppressionCounter map[string]int
 }
 
 const configFSPath = "/sys/kernel/config"
@@ -126,6 +128,8 @@ func newUsbGadget(name string, configMap map[string]gadgetConfigItem, enabledDev
 
 		strictMode: config.strictMode,
 
+		logSuppressionCounter: make(map[string]int),
+
 		absMouseAccumulatedWheelY: 0,
 	}
 	if err := g.Init(); err != nil {

internal/usbgadget/utils.go

@@ -6,6 +6,8 @@ import (
 	"path/filepath"
 	"strconv"
 	"strings"
+
+	"github.com/rs/zerolog"
 )
 
 func joinPath(basePath string, paths []string) string {
@@ -78,3 +80,27 @@ func compareFileContent(oldContent []byte, newContent []byte, looserMatch bool)
 
 	return false
 }
+
+func (u *UsbGadget) logWithSupression(counterName string, every int, logger *zerolog.Logger, err error, msg string, args ...interface{}) {
+	if _, ok := u.logSuppressionCounter[counterName]; !ok {
+		u.logSuppressionCounter[counterName] = 0
+	} else {
+		u.logSuppressionCounter[counterName]++
+	}
+
+	l := logger.With().Int("counter", u.logSuppressionCounter[counterName]).Logger()
+
+	if u.logSuppressionCounter[counterName]%every == 0 {
+		if err != nil {
+			l.Error().Err(err).Msgf(msg, args...)
+		} else {
+			l.Error().Msgf(msg, args...)
+		}
+	}
+}
+
+func (u *UsbGadget) resetLogSuppressionCounter(counterName string) {
+	if _, ok := u.logSuppressionCounter[counterName]; !ok {
+		u.logSuppressionCounter[counterName] = 0
+	}
+}