app/vmalert: follow-up after 8441375da2

- Rename logDebug() to logDebugf() and pass format string together
  with format args directly to logDebugf(). This eliminates fmt.Sprintf()
  overhead at logDebug() call site when debugging is disabled.

- Format labels in debug message in Prometheus format, e.g. {label1="value1",...labelN="valueN"}

Updates https://github.com/VictoriaMetrics/VictoriaMetrics/issues/3025
This commit is contained in:
Aliaksandr Valialkin 2022-09-13 16:33:00 +03:00
parent 8441375da2
commit 0ead64b6cf
No known key found for this signature in database
GPG key ID: A72BEC6CD3D0DED1
2 changed files with 15 additions and 17 deletions

View file

@ -147,11 +147,10 @@ func (ar *AlertingRule) ID() uint64 {
return ar.RuleID
}
func (ar *AlertingRule) logDebug(at time.Time, a *notifier.Alert, msg string) {
func (ar *AlertingRule) logDebugf(at time.Time, a *notifier.Alert, format string, args ...interface{}) {
if !ar.Debug {
return
}
prefix := fmt.Sprintf("DEBUG rule %q:%q (%d) at %v: ",
ar.GroupName, ar.Name, ar.RuleID, at.Format(time.RFC3339))
@ -163,13 +162,14 @@ func (ar *AlertingRule) logDebug(at time.Time, a *notifier.Alert, msg string) {
i++
}
sort.Strings(labelKeys)
var labels string
for _, l := range labelKeys {
labels += fmt.Sprintf("%s=%s,", l, a.Labels[l])
labels := make([]string, len(labelKeys))
for i, l := range labelKeys {
labels[i] = fmt.Sprintf("%s=%q", l, a.Labels[l])
}
labels = strings.TrimRight(labels, ",")
prefix += fmt.Sprintf("alert %d (%s) ", a.ID, labels)
labelsStr := strings.Join(labels, ",")
prefix += fmt.Sprintf("alert %d {%s} ", a.ID, labelsStr)
}
msg := fmt.Sprintf(format, args...)
logger.Infof("%s", prefix+msg)
}
@ -285,13 +285,12 @@ func (ar *AlertingRule) Exec(ctx context.Context, ts time.Time, limit int) ([]pr
return nil, fmt.Errorf("failed to execute query %q: %w", ar.Expr, err)
}
ar.logDebug(ts, nil, fmt.Sprintf("query returned %d samples (elapsed: %s)",
ar.lastExecSamples, ar.lastExecDuration))
ar.logDebugf(ts, nil, "query returned %d samples (elapsed: %s)", ar.lastExecSamples, ar.lastExecDuration)
for h, a := range ar.alerts {
// cleanup inactive alerts from previous Exec
if a.State == notifier.StateInactive && ts.Sub(a.ResolvedAt) > resolvedRetention {
ar.logDebug(ts, a, "deleted as inactive")
ar.logDebugf(ts, a, "deleted as inactive")
delete(ar.alerts, h)
}
}
@ -319,7 +318,7 @@ func (ar *AlertingRule) Exec(ctx context.Context, ts time.Time, limit int) ([]pr
// back to notifier.StatePending
a.State = notifier.StatePending
a.ActiveAt = ts
ar.logDebug(ts, a, "INACTIVE => PENDING")
ar.logDebugf(ts, a, "INACTIVE => PENDING")
}
if a.Value != m.Values[0] {
// update Value field with the latest value
@ -342,7 +341,7 @@ func (ar *AlertingRule) Exec(ctx context.Context, ts time.Time, limit int) ([]pr
a.State = notifier.StatePending
a.ActiveAt = ts
ar.alerts[h] = a
ar.logDebug(ts, a, "created in state PENDING")
ar.logDebugf(ts, a, "created in state PENDING")
}
var numActivePending int
for h, a := range ar.alerts {
@ -353,13 +352,13 @@ func (ar *AlertingRule) Exec(ctx context.Context, ts time.Time, limit int) ([]pr
// alert was in Pending state - it is not
// active anymore
delete(ar.alerts, h)
ar.logDebug(ts, a, "PENDING => DELETED: is absent in current evaluation round")
ar.logDebugf(ts, a, "PENDING => DELETED: is absent in current evaluation round")
continue
}
if a.State == notifier.StateFiring {
a.State = notifier.StateInactive
a.ResolvedAt = ts
ar.logDebug(ts, a, "FIRING => INACTIVE: is absent in current evaluation round")
ar.logDebugf(ts, a, "FIRING => INACTIVE: is absent in current evaluation round")
}
continue
}
@ -368,8 +367,7 @@ func (ar *AlertingRule) Exec(ctx context.Context, ts time.Time, limit int) ([]pr
a.State = notifier.StateFiring
a.Start = ts
alertsFired.Inc()
ar.logDebug(ts, a, fmt.Sprintf("PENDING => FIRING: %s since becoming active at %v",
ts.Sub(a.ActiveAt), a.ActiveAt))
ar.logDebugf(ts, a, "PENDING => FIRING: %s since becoming active at %v", ts.Sub(a.ActiveAt), a.ActiveAt)
}
}
if limit > 0 && numActivePending > limit {

View file

@ -22,7 +22,7 @@ The following tip changes can be tested by building VictoriaMetrics components f
* FEATURE: set the `start` arg to `end - 5 minutes` if isn't passed explicitly to [/api/v1/labels](https://docs.victoriametrics.com/url-examples.html#apiv1labels) and [/api/v1/label/.../values](https://docs.victoriametrics.com/url-examples.html#apiv1labelvalues). See [this pull request](https://github.com/VictoriaMetrics/VictoriaMetrics/pull/3052).
* FEATURE: [vmctl](https://docs.victoriametrics.com/vmctl.html): add `vm-native-step-interval` command line flag for `vm-native` mode. New option allows splitting the import process into chunks by time interval. This helps migrating data sets with high churn rate and provides better control over the process. See [feature request](https://github.com/VictoriaMetrics/VictoriaMetrics/issues/2733).
* FEATURE: [vmui](https://docs.victoriametrics.com/#vmui): add `top queries` tab, which shows various stats for recently executed queries. See [these docs](https://docs.victoriametrics.com/#top-queries) and [this feature request](https://github.com/VictoriaMetrics/VictoriaMetrics/issues/2707).
* FEATURE: [vmalert](https://docs.victoriametrics.com/vmalert.html): add `debug` mode to the alerting rule settings for printing additional information into logs during evaluation. See `debug` param in [alerting rule config](https://docs.victoriametrics.com/vmalert.html#alerting-rules)
* FEATURE: [vmalert](https://docs.victoriametrics.com/vmalert.html): add `debug` mode to the alerting rule settings for printing additional information into logs during evaluation. See `debug` param in [alerting rule config](https://docs.victoriametrics.com/vmalert.html#alerting-rules).
* BUGFIX: [MetricsQL](https://docs.victoriametrics.com/MetricsQL.html): properly calculate `rate_over_sum(m[d])` as `sum_over_time(m[d])/d`. Previously the `sum_over_time(m[d])` could be improperly divided by smaller than `d` time range. See [rate_over_sum() docs](https://docs.victoriametrics.com/MetricsQL.html#rate_over_sum) and [this issue](https://github.com/VictoriaMetrics/VictoriaMetrics/issues/3045).
* BUGFIX: [VictoriaMetrics cluster](https://docs.victoriametrics.com/Cluster-VictoriaMetrics.html): properly calculate query results at `vmselect`. See [this issue](https://github.com/VictoriaMetrics/VictoriaMetrics/issues/3067). The issue has been introduced in [v1.81.0](https://docs.victoriametrics.com/CHANGELOG.html#v1810).