Merge pull request juju#16898 from SimonRichardson/suppress-klog-log-…

…message

juju#16898

The klog log messages are noisy and fill up the logs easily. It then becomes hard to work out what is signal and what is noise. As log messages are probably important, it's worth suppressing the message rather than blanket ignoring it. As the klog might be dumping a lot of messages for large controllers, I've ensured that we only make the request once we have a match.

The only match we have atm is the `Use tokens from the TokenRequest`. We can always add more if we need to.

Work will be required in the future to fix this message completely.

<!-- Why this change is needed and what it does. -->

## Checklist

<!-- If an item is not applicable, use `~strikethrough~`. -->

- [x] Code style: imports ordered, good names, simple structure, etc
- [x] Comments saying why design decisions were made

## QA steps

<!-- Describe steps to verify that the change works. -->

```sh
$ juju bootstrap microk8s test
```

## Links

**Launchpad bug:** https://bugs.launchpad.net/juju/+bug/2038495

**Jira card:** JUJU-5235

caas/kubernetes/provider/klog.go

@@ -5,20 +5,11 @@ package provider
 
 import (
 	"strings"
+	"time"
 
 	"github.com/go-logr/logr"
 	"github.com/juju/loggo"
-)
-
-type KlogMessagePrefixes []string
-
-var (
-	klogIgnorePrefixes = KlogMessagePrefixes{
-		"lost connection to pod",
-		"an error occurred forwarding",
-		"error copying from remote stream to local connection",
-		"error copying from local connection to remote stream",
-	}
+	"golang.org/x/time/rate"
 )
 
 // klogAdapter is an adapter for Kubernetes logger onto juju loggo. We use this
@@ -34,16 +25,15 @@ func newKlogAdapter() logr.Logger {
 	})
 }
 
-func (k *klogAdapter) Init(info logr.RuntimeInfo) {
-}
+func (k *klogAdapter) Init(info logr.RuntimeInfo) {}
 
 // Enabled see https://pkg.go.dev/github.com/go-logr/logr#Logger
 func (k *klogAdapter) Enabled(level int) bool {
 	return true
 }
 
 // Error see https://pkg.go.dev/github.com/go-logr/logr#Logger
-func (k *klogAdapter) Error(err error, msg string, keysAndValues ...interface{}) {
+func (k *klogAdapter) Error(err error, msg string, keysAndValues ...any) {
 	if err != nil {
 		k.Logger.Errorf(msg+": "+err.Error(), keysAndValues...)
 		return
@@ -56,17 +46,13 @@ func (k *klogAdapter) Error(err error, msg string, keysAndValues ...interface{})
 }
 
 // Info see https://pkg.go.dev/github.com/go-logr/logr#Logger
-func (k *klogAdapter) Info(level int, msg string, keysAndValues ...interface{}) {
-	k.Logger.Infof(msg, keysAndValues...)
-}
-
-func (k KlogMessagePrefixes) Matches(log string) bool {
-	for _, v := range k {
-		if strings.HasPrefix(log, v) {
-			return true
-		}
+func (k *klogAdapter) Info(level int, msg string, keysAndValues ...any) {
+	if prefix, ok := klogSuppressedPrefixes.Matches(msg); ok && prefix != nil {
+		prefix.Do(k.Logger.Infof, msg, keysAndValues...)
+		return
 	}
-	return false
+
+	k.Logger.Infof(msg, keysAndValues...)
 }
 
 // V see https://pkg.go.dev/github.com/go-logr/logr#Logger
@@ -75,11 +61,86 @@ func (k *klogAdapter) V(level int) logr.LogSink {
 }
 
 // WithValues see https://pkg.go.dev/github.com/go-logr/logr#Logger
-func (k *klogAdapter) WithValues(keysAndValues ...interface{}) logr.LogSink {
+func (k *klogAdapter) WithValues(keysAndValues ...any) logr.LogSink {
 	return k
 }
 
 // WithName see https://pkg.go.dev/github.com/go-logr/logr#Logger
 func (k *klogAdapter) WithName(name string) logr.LogSink {
 	return k
 }
+
+// klogMessagePrefixes is a list of prefixes to ignore.
+type klogMessagePrefixes []string
+
+var (
+	klogIgnorePrefixes = klogMessagePrefixes{
+		"lost connection to pod",
+		"an error occurred forwarding",
+		"error copying from remote stream to local connection",
+		"error copying from local connection to remote stream",
+	}
+)
+
+func (k klogMessagePrefixes) Matches(log string) bool {
+	for _, v := range k {
+		if strings.HasPrefix(log, v) {
+			return true
+		}
+	}
+	return false
+}
+
+// klogSuppressMessagePrefix is a log suppression type that suppresses log
+// messages with a given prefix at a given rate. If the rate is nil, the
+// suppression is disabled.
+type klogSuppressMessagePrefix struct {
+	prefix string
+	rate   *rate.Sometimes
+}
+
+// Do calls the logger function if the rate allows it. If the rate is nil, the
+// function is called directly, thus bypassing the rate.
+func (k klogSuppressMessagePrefix) Do(loggerFn func(string, ...any), msg string, args ...any) {
+	// If we don't have a rate, just call the function directly.
+	if k.rate == nil {
+		loggerFn(msg, args)
+		return
+	}
+
+	// If we have a rate, use it to suppress the message.
+	k.rate.Do(func() {
+		loggerFn(msg, args)
+	})
+}
+
+// klogSuppressMessagePrefixes is a list of prefixes to suppress and their
+// suppression rates.
+type klogSuppressMessagePrefixes []*klogSuppressMessagePrefix
+
+var (
+	klogSuppressedPrefixes = klogSuppressMessagePrefixes{
+		&klogSuppressMessagePrefix{
+			prefix: "Use tokens from the TokenRequest API or manually created secret-based tokens instead of auto-generated secret-based tokens",
+			// We suppress the message at a rate of 1 per 5 minute, but we
+			// allow the first message to go through.
+			rate: &rate.Sometimes{
+				First:    1,
+				Interval: time.Minute * 5,
+			},
+		},
+	}
+)
+
+// Matches returns the prefix and whether it matches the log message.
+func (k klogSuppressMessagePrefixes) Matches(log string) (*klogSuppressMessagePrefix, bool) {
+	for _, p := range k {
+		if p == nil {
+			continue
+		}
+		if strings.HasPrefix(log, p.prefix) {
+			return p, true
+		}
+	}
+	return nil, false
+}

go.mod

@@ -110,6 +110,7 @@ require (
 	golang.org/x/oauth2 v0.15.0
 	golang.org/x/sync v0.5.0
 	golang.org/x/sys v0.15.0
+	golang.org/x/time v0.5.0
 	golang.org/x/tools v0.16.0
 	google.golang.org/api v0.152.0
 	gopkg.in/check.v1 v1.0.0-20201130134442-10cb98267c6c
@@ -286,7 +287,6 @@ require (
 	golang.org/x/mod v0.14.0 // indirect
 	golang.org/x/term v0.15.0 // indirect
 	golang.org/x/text v0.14.0 // indirect
-	golang.org/x/time v0.5.0 // indirect
 	google.golang.org/appengine v1.6.7 // indirect
 	google.golang.org/genproto/googleapis/rpc v0.0.0-20231120223509-83a465c0220f // indirect
 	google.golang.org/grpc v1.59.0 // indirect