lib/logger: limit the maximum arg length, which can be emitted to log lines

This should prevent from emitting too long lines when too long args are passed to logger.* functions.
For example, too long MetricsQL queries or too long data samples.

docs/CHANGELOG.md

@@ -43,6 +43,7 @@ The following `tip` changes can be tested by building VictoriaMetrics components
 * FEATURE: [vmauth](https://docs.victoriametrics.com/vmauth.html): added ability to set, override and clear request and response headers on a per-user and per-path basis. See [this i
 ssue](https://github.com/VictoriaMetrics/VictoriaMetrics/issues/4825) and [these docs](https://docs.victoriametrics.com/vmauth.html#auth-config) for details.
 * FEATURE: [vmalert](https://docs.victoriametrics.com/vmalert.html): add `eval_offset` attribute for [Groups](https://docs.victoriametrics.com/vmalert.html#groups). If specified, Group will be evaluated at the exact time offset on the range of [0...evaluationInterval]. The setting might be useful for cron-like rules which must be evaluated at specific moments of time. See [this issue](https://github.com/VictoriaMetrics/VictoriaMetrics/issues/3409) for details.
+* FEATURE: limit the length of string params in log messages to 200 chars. Longer string params are replaced with the `first_100_chars..last_100_chars`. This prevents from too long log lines, which can be emitted by VictoriaMetrics components.
 
 * BUGFIX: [Official Grafana dashboards for VictoriaMetrics](https://grafana.com/orgs/victoriametrics): fix display of ingested rows rate for `Samples ingested/s` and `Samples rate` panels for vmagent's dasbhoard. Previously, not all ingested protocols were accounted in these panels. An extra panel `Rows rate` was added to `Ingestion` section to display the split for rows ingested rate by protocol.
 * BUGFIX: [vmui](https://docs.victoriametrics.com/#vmui): fix the bug causing render looping when switching to heatmap.

lib/logger/logger.go

@@ -93,51 +93,79 @@ func StdErrorLogger() *log.Logger {
 
 // Infof logs info message.
 func Infof(format string, args ...interface{}) {
-	logLevel("INFO", format, args...)
+	logLevel("INFO", format, args)
 }
 
 // Warnf logs warn message.
 func Warnf(format string, args ...interface{}) {
-	logLevel("WARN", format, args...)
+	logLevel("WARN", format, args)
 }
 
 // Errorf logs error message.
 func Errorf(format string, args ...interface{}) {
-	logLevel("ERROR", format, args...)
+	logLevel("ERROR", format, args)
 }
 
 // WarnfSkipframes logs warn message and skips the given number of frames for the caller.
 func WarnfSkipframes(skipframes int, format string, args ...interface{}) {
-	logLevelSkipframes(skipframes, "WARN", format, args...)
+	logLevelSkipframes(skipframes, "WARN", format, args)
 }
 
 // ErrorfSkipframes logs error message and skips the given number of frames for the caller.
 func ErrorfSkipframes(skipframes int, format string, args ...interface{}) {
-	logLevelSkipframes(skipframes, "ERROR", format, args...)
+	logLevelSkipframes(skipframes, "ERROR", format, args)
 }
 
 // Fatalf logs fatal message and terminates the app.
 func Fatalf(format string, args ...interface{}) {
-	logLevel("FATAL", format, args...)
+	logLevel("FATAL", format, args)
 }
 
 // Panicf logs panic message and panics.
 func Panicf(format string, args ...interface{}) {
-	logLevel("PANIC", format, args...)
+	logLevel("PANIC", format, args)
 }
 
-func logLevel(level, format string, args ...interface{}) {
-	logLevelSkipframes(1, level, format, args...)
+func logLevel(level, format string, args []interface{}) {
+	logLevelSkipframes(1, level, format, args)
 }
 
-func logLevelSkipframes(skipframes int, level, format string, args ...interface{}) {
+func logLevelSkipframes(skipframes int, level, format string, args []interface{}) {
 	if shouldSkipLog(level) {
 		return
 	}
-	msg := fmt.Sprintf(format, args...)
+	msg := formatLogMessage(200, format, args)
 	logMessage(level, msg, 3+skipframes)
 }
 
+func formatLogMessage(maxArgLen int, format string, args []interface{}) string {
+	x := format
+	// Limit the length of every string-like arg in order to prevent from too long log messages
+	for i := range args {
+		n := strings.IndexByte(x, '%')
+		if n < 0 {
+			break
+		}
+		x = x[n+1:]
+		if strings.HasPrefix(x, "s") || strings.HasPrefix(x, "q") {
+			s := fmt.Sprintf("%s", args[i])
+			args[i] = limitStringLength(maxArgLen, s)
+		}
+	}
+	return fmt.Sprintf(format, args...)
+}
+
+func limitStringLength(maxLen int, s string) string {
+	if len(s) <= maxLen {
+		return s
+	}
+	n := (maxLen / 2) - 1
+	if n < 0 {
+		n = 0
+	}
+	return s[:n] + ".." + s[len(s)-n:]
+}
+
 func logLimiterCleaner() {
 	for {
 		time.Sleep(time.Second)
@@ -197,7 +225,7 @@ type logWriter struct {
 }
 
 func (lw *logWriter) Write(p []byte) (int, error) {
-	logLevelSkipframes(2, "ERROR", "%s", p)
+	logLevelSkipframes(2, "ERROR", "%s", []interface{}{p})
 	return len(p), nil
 }
 

lib/logger/logger_test.go

@@ -0,0 +1,25 @@
+package logger
+
+import (
+	"fmt"
+	"testing"
+)
+
+func TestFormatLogMessage(t *testing.T) {
+	f := func(format string, args []interface{}, maxArgLen int, expectedResult string) {
+		t.Helper()
+		result := formatLogMessage(maxArgLen, format, args)
+		if result != expectedResult {
+			t.Fatalf("unexpected result; got\n%q\nwant\n%q", result, expectedResult)
+		}
+	}
+
+	// Zero format args
+	f("foobar", nil, 1, "foobar")
+
+	// Format args not exceeding the maxArgLen
+	f("foo: %d, %s, %s, %s", []interface{}{123, "bar", []byte("baz"), fmt.Errorf("abc")}, 3, "foo: 123, bar, baz, abc")
+
+	// Format args exceeding the maxArgLen
+	f("foo: %s, %q, %s", []interface{}{"abcde", fmt.Errorf("foo bar baz"), "xx"}, 4, `foo: a..e, "f..z", xx`)
+}