diff --git a/docs/CHANGELOG.md b/docs/CHANGELOG.md index 55934e212..876e0156d 100644 --- a/docs/CHANGELOG.md +++ b/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. diff --git a/lib/logger/logger.go b/lib/logger/logger.go index 3b973a81c..b30f910a4 100644 --- a/lib/logger/logger.go +++ b/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 } diff --git a/lib/logger/logger_test.go b/lib/logger/logger_test.go new file mode 100644 index 000000000..dc1fcc28b --- /dev/null +++ b/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`) +}