lib/logger: add -loggerMaxArgLen command-line flag for fine-tuning the maximum length of logged args

README.md

@@ -2655,6 +2655,8 @@ Pass `-help` to VictoriaMetrics in order to see the list of supported command-li
      Allows renaming fields in JSON formatted logs. Example: "ts:timestamp,msg:message" renames "ts" to "timestamp" and "msg" to "message". Supported fields: ts, level, caller, msg
   -loggerLevel string
      Minimum level of errors to log. Possible values: INFO, WARN, ERROR, FATAL, PANIC (default "INFO")
+  -loggerMaxArgLen int
+     The maximum length of a single logged argument. Longer arguments are replaced with 'arg_start..arg_end', where 'arg_start' and 'arg_end' is prefix and suffix of the arg with the length not exceeding -loggerMaxArgLen / 2 (default 500)
   -loggerOutput string
      Output for the logs. Supported values: stderr, stdout (default "stderr")
   -loggerTimezone string

app/vmselect/promql/eval.go

@@ -23,6 +23,7 @@ import (
 	"github.com/VictoriaMetrics/VictoriaMetrics/lib/memory"
 	"github.com/VictoriaMetrics/VictoriaMetrics/lib/querytracer"
 	"github.com/VictoriaMetrics/VictoriaMetrics/lib/storage"
+	"github.com/VictoriaMetrics/VictoriaMetrics/lib/stringsutil"
 	"github.com/VictoriaMetrics/metrics"
 	"github.com/VictoriaMetrics/metricsql"
 )
@@ -259,7 +260,7 @@ func getTimestamps(start, end, step int64, maxPointsPerSeries int) []int64 {
 func evalExpr(qt *querytracer.Tracer, ec *EvalConfig, e metricsql.Expr) ([]*timeseries, error) {
 	if qt.Enabled() {
 		query := string(e.AppendString(nil))
-		query = bytesutil.LimitStringLen(query, 300)
+		query = stringsutil.LimitStringLen(query, 300)
 		mayCache := ec.mayCache()
 		qt = qt.NewChild("eval: query=%s, timeRange=%s, step=%d, mayCache=%v", query, ec.timeRangeString(), ec.Step, mayCache)
 	}
@@ -1409,6 +1410,10 @@ func evalInstantRollup(qt *querytracer.Tracer, ec *EvalConfig, funcName string,
 }
 
 func hasDuplicateSeries(tss []*timeseries) bool {
+	if len(tss) <= 1 {
+		return false
+	}
+
 	m := make(map[string]struct{}, len(tss))
 	bb := bbPool.Get()
 	defer bbPool.Put(bb)

app/vmselect/promql/rollup_result_cache.go

@@ -17,6 +17,7 @@ import (
 	"github.com/VictoriaMetrics/VictoriaMetrics/lib/memory"
 	"github.com/VictoriaMetrics/VictoriaMetrics/lib/querytracer"
 	"github.com/VictoriaMetrics/VictoriaMetrics/lib/storage"
+	"github.com/VictoriaMetrics/VictoriaMetrics/lib/stringsutil"
 	"github.com/VictoriaMetrics/VictoriaMetrics/lib/workingsetcache"
 	"github.com/VictoriaMetrics/fastcache"
 	"github.com/VictoriaMetrics/metrics"
@@ -205,7 +206,7 @@ func ResetRollupResultCache() {
 func (rrc *rollupResultCache) GetInstantValues(qt *querytracer.Tracer, expr metricsql.Expr, window, step int64, etfss [][]storage.TagFilter) []*timeseries {
 	if qt.Enabled() {
 		query := string(expr.AppendString(nil))
-		query = bytesutil.LimitStringLen(query, 300)
+		query = stringsutil.LimitStringLen(query, 300)
 		qt = qt.NewChild("rollup cache get instant values: query=%s, window=%d, step=%d", query, window, step)
 		defer qt.Done()
 	}
@@ -227,7 +228,7 @@ func (rrc *rollupResultCache) GetInstantValues(qt *querytracer.Tracer, expr metr
 func (rrc *rollupResultCache) PutInstantValues(qt *querytracer.Tracer, expr metricsql.Expr, window, step int64, etfss [][]storage.TagFilter, tss []*timeseries) {
 	if qt.Enabled() {
 		query := string(expr.AppendString(nil))
-		query = bytesutil.LimitStringLen(query, 300)
+		query = stringsutil.LimitStringLen(query, 300)
 		startStr := ""
 		if len(tss) > 0 {
 			startStr = storage.TimestampToHumanReadableFormat(tss[0].Timestamps[0])
@@ -260,7 +261,7 @@ func (rrc *rollupResultCache) DeleteInstantValues(qt *querytracer.Tracer, expr m
 
 	if qt.Enabled() {
 		query := string(expr.AppendString(nil))
-		query = bytesutil.LimitStringLen(query, 300)
+		query = stringsutil.LimitStringLen(query, 300)
 		qt.Printf("rollup result cache delete instant values: query=%s, window=%d, step=%d", query, window, step)
 	}
 }
@@ -268,7 +269,7 @@ func (rrc *rollupResultCache) DeleteInstantValues(qt *querytracer.Tracer, expr m
 func (rrc *rollupResultCache) GetSeries(qt *querytracer.Tracer, ec *EvalConfig, expr metricsql.Expr, window int64) (tss []*timeseries, newStart int64) {
 	if qt.Enabled() {
 		query := string(expr.AppendString(nil))
-		query = bytesutil.LimitStringLen(query, 300)
+		query = stringsutil.LimitStringLen(query, 300)
 		qt = qt.NewChild("rollup cache get series: query=%s, timeRange=%s, window=%d, step=%d", query, ec.timeRangeString(), window, ec.Step)
 		defer qt.Done()
 	}
@@ -353,7 +354,7 @@ var resultBufPool bytesutil.ByteBufferPool
 func (rrc *rollupResultCache) PutSeries(qt *querytracer.Tracer, ec *EvalConfig, expr metricsql.Expr, window int64, tss []*timeseries) {
 	if qt.Enabled() {
 		query := string(expr.AppendString(nil))
-		query = bytesutil.LimitStringLen(query, 300)
+		query = stringsutil.LimitStringLen(query, 300)
 		qt = qt.NewChild("rollup cache put series: query=%s, timeRange=%s, step=%d, window=%d, series=%d", query, ec.timeRangeString(), ec.Step, window, len(tss))
 		defer qt.Done()
 	}

docs/CHANGELOG.md

@@ -81,6 +81,7 @@ The sandbox cluster installation is running under the constant load generated by
 * FEATURE: all: track requests with wrong auth key and wrong basic auth at `vm_http_request_errors_total` [metric](https://docs.victoriametrics.com/#monitoring) with `reason="wrong_auth_key"` and `reason="wrong_basic_auth"`. See [this issue](https://github.com/victoriaMetrics/victoriaMetrics/issues/4590). Thanks to @venkatbvc for the [pull request](https://github.com/VictoriaMetrics/VictoriaMetrics/pull/5166).
 * FEATURE: [vmauth](https://docs.victoriametrics.com/vmauth.html): add `tls_insecure_skip_verify` parameter which allows to disable TLS verification for backend connection. See [this issue](https://github.com/VictoriaMetrics/VictoriaMetrics/issues/5240).
 * FEATURE: `vmstorage`: add `-blockcache.missesBeforeCaching` command-line flag, which can be used for fine-tuning RAM usage for `indexdb/dataBlocks` cache when queries touching big number of time series are executed.
+* FEATURE: add `-loggerMaxArgLen` command-line flag for fine-tuning the maximum lengths of logged args.
 
 * BUGFIX: [vmalert](https://docs.victoriametrics.com/vmalert.html): strip sensitive information such as auth headers or passwords from datasource, remote-read, remote-write or notifier URLs in log messages or UI. This behavior is by default and is controlled via `-datasource.showURL`, `-remoteRead.showURL`, `remoteWrite.showURL` or `-notifier.showURL` cmd-line flags. See [this issue](https://github.com/VictoriaMetrics/VictoriaMetrics/issues/5044).
 * BUGFIX: [vmalert](https://docs.victoriametrics.com/vmalert.html): fix vmalert web UI when running on 32-bit architectures machine.

docs/README.md

@@ -2658,6 +2658,8 @@ Pass `-help` to VictoriaMetrics in order to see the list of supported command-li
      Allows renaming fields in JSON formatted logs. Example: "ts:timestamp,msg:message" renames "ts" to "timestamp" and "msg" to "message". Supported fields: ts, level, caller, msg
   -loggerLevel string
      Minimum level of errors to log. Possible values: INFO, WARN, ERROR, FATAL, PANIC (default "INFO")
+  -loggerMaxArgLen int
+     The maximum length of a single logged argument. Longer arguments are replaced with 'arg_start..arg_end', where 'arg_start' and 'arg_end' is prefix and suffix of the arg with the length not exceeding -loggerMaxArgLen / 2 (default 500)
   -loggerOutput string
      Output for the logs. Supported values: stderr, stdout (default "stderr")
   -loggerTimezone string

docs/Single-server-VictoriaMetrics.md

@@ -2666,6 +2666,8 @@ Pass `-help` to VictoriaMetrics in order to see the list of supported command-li
      Allows renaming fields in JSON formatted logs. Example: "ts:timestamp,msg:message" renames "ts" to "timestamp" and "msg" to "message". Supported fields: ts, level, caller, msg
   -loggerLevel string
      Minimum level of errors to log. Possible values: INFO, WARN, ERROR, FATAL, PANIC (default "INFO")
+  -loggerMaxArgLen int
+     The maximum length of a single logged argument. Longer arguments are replaced with 'arg_start..arg_end', where 'arg_start' and 'arg_end' is prefix and suffix of the arg with the length not exceeding -loggerMaxArgLen / 2 (default 500)
   -loggerOutput string
      Output for the logs. Supported values: stderr, stdout (default "stderr")
   -loggerTimezone string

lib/bytesutil/bytesutil.go

@@ -79,14 +79,3 @@ func ToUnsafeBytes(s string) (b []byte) {
 	slh.Cap = sh.Len
 	return b
 }
-
-// LimitStringLen limits the length of s to maxLen.
-//
-// If len(s) > maxLen, then the function concatenates s prefix with s suffix.
-func LimitStringLen(s string, maxLen int) string {
-	if maxLen <= 4 || len(s) <= maxLen {
-		return s
-	}
-	n := maxLen/2 - 1
-	return s[:n] + ".." + s[len(s)-n:]
-}

lib/logger/logger.go

@@ -13,6 +13,7 @@ import (
 	"time"
 
 	"github.com/VictoriaMetrics/VictoriaMetrics/lib/buildinfo"
+	"github.com/VictoriaMetrics/VictoriaMetrics/lib/stringsutil"
 	"github.com/VictoriaMetrics/metrics"
 )
 
@@ -23,6 +24,8 @@ var (
 	loggerTimezone = flag.String("loggerTimezone", "UTC", "Timezone to use for timestamps in logs. Timezone must be a valid IANA Time Zone. "+
 		"For example: America/New_York, Europe/Berlin, Etc/GMT+3 or Local")
 	disableTimestamps = flag.Bool("loggerDisableTimestamps", false, "Whether to disable writing timestamps in logs")
+	maxLogArgLen      = flag.Int("loggerMaxArgLen", 500, "The maximum length of a single logged argument. Longer arguments are replaced with 'arg_start..arg_end', "+
+		"where 'arg_start' and 'arg_end' is prefix and suffix of the arg with the length not exceeding -loggerMaxArgLen / 2")
 
 	errorsPerSecondLimit = flag.Int("loggerErrorsPerSecondLimit", 0, `Per-second limit on the number of ERROR messages. If more than the given number of errors are emitted per second, the remaining errors are suppressed. Zero values disable the rate limit`)
 	warnsPerSecondLimit  = flag.Int("loggerWarnsPerSecondLimit", 0, `Per-second limit on the number of WARN messages. If more than the given number of warns are emitted per second, then the remaining warns are suppressed. Zero values disable the rate limit`)
@@ -134,7 +137,7 @@ func logLevelSkipframes(skipframes int, level, format string, args []interface{}
 	if shouldSkipLog(level) {
 		return
 	}
-	msg := formatLogMessage(500, format, args)
+	msg := formatLogMessage(*maxLogArgLen, format, args)
 	logMessage(level, msg, 3+skipframes)
 }
 
@@ -149,23 +152,12 @@ func formatLogMessage(maxArgLen int, format string, args []interface{}) string {
 		x = x[n+1:]
 		if strings.HasPrefix(x, "s") || strings.HasPrefix(x, "q") {
 			s := fmt.Sprintf("%s", args[i])
-			args[i] = limitStringLength(maxArgLen, s)
+			args[i] = stringsutil.LimitStringLen(s, maxArgLen)
 		}
 	}
 	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)

lib/storage/search.go

@@ -10,6 +10,7 @@ import (
 	"github.com/VictoriaMetrics/VictoriaMetrics/lib/fasttime"
 	"github.com/VictoriaMetrics/VictoriaMetrics/lib/logger"
 	"github.com/VictoriaMetrics/VictoriaMetrics/lib/querytracer"
+	"github.com/VictoriaMetrics/VictoriaMetrics/lib/stringsutil"
 )
 
 // BlockRef references a Block.
@@ -277,7 +278,7 @@ type TagFilter struct {
 // String returns string representation of tf.
 func (tf *TagFilter) String() string {
 	op := tf.getOp()
-	value := bytesutil.LimitStringLen(string(tf.Value), 60)
+	value := stringsutil.LimitStringLen(string(tf.Value), 60)
 	if len(tf.Key) == 0 {
 		return fmt.Sprintf("__name__%s%q", op, value)
 	}

lib/storage/tag_filters.go

@@ -16,6 +16,7 @@ import (
 	"github.com/VictoriaMetrics/VictoriaMetrics/lib/lrucache"
 	"github.com/VictoriaMetrics/VictoriaMetrics/lib/memory"
 	"github.com/VictoriaMetrics/VictoriaMetrics/lib/regexutil"
+	"github.com/VictoriaMetrics/VictoriaMetrics/lib/stringsutil"
 )
 
 // convertToCompositeTagFilterss converts tfss to composite filters.
@@ -293,7 +294,7 @@ func (tf *tagFilter) Less(other *tagFilter) bool {
 // String returns human-readable tf value.
 func (tf *tagFilter) String() string {
 	op := tf.getOp()
-	value := bytesutil.LimitStringLen(string(tf.value), 60)
+	value := stringsutil.LimitStringLen(string(tf.value), 60)
 	if bytes.Equal(tf.key, graphiteReverseTagKey) {
 		return fmt.Sprintf("__graphite_reverse__%s%q", op, value)
 	}

lib/stringsutil/stringsutil.go

@@ -0,0 +1,16 @@
+package stringsutil
+
+// LimitStringLen limits the length of s with maxLen.
+//
+// If len(s) > maxLen, then s is replaced with "s_prefix..s_suffix",
+// so the total length of the returned string doesn't exceed maxLen.
+func LimitStringLen(s string, maxLen int) string {
+	if len(s) <= maxLen || maxLen <= 4 {
+		return s
+	}
+	n := (maxLen / 2) - 1
+	if n < 0 {
+		n = 0
+	}
+	return s[:n] + ".." + s[len(s)-n:]
+}