prometheus/rules/manager.go

576 lines
15 KiB
Go
Raw Normal View History

// Copyright 2013 The Prometheus Authors
// Licensed under the Apache License, Version 2.0 (the "License");
// you may not use this file except in compliance with the License.
// You may obtain a copy of the License at
//
// http://www.apache.org/licenses/LICENSE-2.0
//
// Unless required by applicable law or agreed to in writing, software
// distributed under the License is distributed on an "AS IS" BASIS,
// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
// See the License for the specific language governing permissions and
// limitations under the License.
package rules
import (
"fmt"
"io/ioutil"
"math"
"net/url"
"path/filepath"
2013-04-17 05:42:15 -07:00
"sync"
"time"
2015-06-30 02:51:05 -07:00
html_template "html/template"
"github.com/prometheus/client_golang/prometheus"
2015-10-03 01:21:43 -07:00
"github.com/prometheus/common/log"
"github.com/prometheus/common/model"
"golang.org/x/net/context"
"github.com/prometheus/prometheus/config"
2016-03-01 03:37:22 -08:00
"github.com/prometheus/prometheus/notifier"
"github.com/prometheus/prometheus/pkg/labels"
"github.com/prometheus/prometheus/pkg/timestamp"
"github.com/prometheus/prometheus/pkg/value"
"github.com/prometheus/prometheus/promql"
"github.com/prometheus/prometheus/storage"
2015-05-29 04:30:30 -07:00
"github.com/prometheus/prometheus/util/strutil"
)
// Constants for instrumentation.
const namespace = "prometheus"
var (
evalDuration = prometheus.NewSummaryVec(
prometheus.SummaryOpts{
Namespace: namespace,
Name: "rule_evaluation_duration_seconds",
Help: "The duration for a rule to execute.",
},
[]string{"rule_type"},
)
evalFailures = prometheus.NewCounterVec(
prometheus.CounterOpts{
Namespace: namespace,
Name: "rule_evaluation_failures_total",
Help: "The total number of rule evaluation failures.",
},
[]string{"rule_type"},
)
evalTotal = prometheus.NewCounterVec(
prometheus.CounterOpts{
Namespace: namespace,
Name: "rule_evaluations_total",
Help: "The total number of rule evaluations.",
},
[]string{"rule_type"},
)
iterationDuration = prometheus.NewSummary(prometheus.SummaryOpts{
Namespace: namespace,
Name: "evaluator_duration_seconds",
Help: "The duration of rule group evaluations.",
2015-01-21 06:42:25 -08:00
Objectives: map[float64]float64{0.01: 0.001, 0.05: 0.005, 0.5: 0.05, 0.90: 0.01, 0.99: 0.001},
})
iterationsSkipped = prometheus.NewCounter(prometheus.CounterOpts{
Namespace: namespace,
Name: "evaluator_iterations_skipped_total",
Help: "The total number of rule group evaluations skipped due to throttled metric storage.",
})
iterationsMissed = prometheus.NewCounter(prometheus.CounterOpts{
Namespace: namespace,
Name: "evaluator_iterations_missed_total",
Help: "The total number of rule group evaluations missed due to slow rule group evaluation.",
})
iterationsScheduled = prometheus.NewCounter(prometheus.CounterOpts{
Namespace: namespace,
Name: "evaluator_iterations_total",
Help: "The total number of scheduled rule group evaluations, whether executed, missed or skipped.",
})
)
func init() {
evalTotal.WithLabelValues(string(ruleTypeAlert))
evalTotal.WithLabelValues(string(ruleTypeRecording))
evalFailures.WithLabelValues(string(ruleTypeAlert))
evalFailures.WithLabelValues(string(ruleTypeRecording))
prometheus.MustRegister(iterationDuration)
prometheus.MustRegister(iterationsScheduled)
prometheus.MustRegister(iterationsSkipped)
prometheus.MustRegister(iterationsMissed)
prometheus.MustRegister(evalFailures)
prometheus.MustRegister(evalDuration)
}
2015-12-14 08:40:40 -08:00
type ruleType string
const (
ruleTypeAlert = "alerting"
ruleTypeRecording = "recording"
)
// A Rule encapsulates a vector expression which is evaluated at a specified
// interval and acted upon (currently either recorded or used for alerting).
type Rule interface {
Name() string
2015-12-14 08:40:40 -08:00
// eval evaluates the rule, including any associated recording or alerting actions.
2017-05-16 07:48:37 -07:00
Eval(context.Context, time.Time, *promql.Engine, *url.URL) (promql.Vector, error)
// String returns a human-readable string representation of the rule.
String() string
// HTMLSnippet returns a human-readable string representation of the rule,
// decorated with HTML elements for use the web frontend.
2015-06-30 02:51:05 -07:00
HTMLSnippet(pathPrefix string) html_template.HTML
}
2015-12-17 02:46:10 -08:00
// Group is a set of rules that have a logical relation.
2015-12-14 08:40:40 -08:00
type Group struct {
name string
interval time.Duration
rules []Rule
seriesInPreviousEval []map[string]labels.Labels // One per Rule.
opts *ManagerOptions
2015-12-14 08:40:40 -08:00
done chan struct{}
terminated chan struct{}
logger log.Logger
2015-12-14 08:40:40 -08:00
}
// NewGroup makes a new Group with the given name, options, and rules.
func NewGroup(name string, interval time.Duration, rules []Rule, opts *ManagerOptions) *Group {
2015-12-14 08:40:40 -08:00
return &Group{
name: name,
interval: interval,
rules: rules,
opts: opts,
seriesInPreviousEval: make([]map[string]labels.Labels, len(rules)),
done: make(chan struct{}),
terminated: make(chan struct{}),
logger: opts.Logger.With("group", name),
2015-12-14 08:40:40 -08:00
}
}
2015-12-14 08:40:40 -08:00
func (g *Group) run() {
defer close(g.terminated)
2015-12-14 08:40:40 -08:00
// Wait an initial amount to have consistently slotted intervals.
select {
case <-time.After(g.offset()):
case <-g.done:
return
}
2015-12-14 08:40:40 -08:00
iter := func() {
iterationsScheduled.Inc()
2015-12-14 08:40:40 -08:00
start := time.Now()
g.Eval(start)
iterationDuration.Observe(time.Since(start).Seconds())
}
lastTriggered := time.Now()
2015-12-14 08:40:40 -08:00
iter()
2015-01-29 06:05:10 -08:00
2015-12-14 08:40:40 -08:00
tick := time.NewTicker(g.interval)
defer tick.Stop()
for {
select {
2015-12-14 08:40:40 -08:00
case <-g.done:
return
2015-01-29 06:05:10 -08:00
default:
select {
2015-12-14 08:40:40 -08:00
case <-g.done:
2015-01-29 06:05:10 -08:00
return
2015-12-14 08:40:40 -08:00
case <-tick.C:
missed := (time.Since(lastTriggered).Nanoseconds() / g.interval.Nanoseconds()) - 1
if missed > 0 {
iterationsMissed.Add(float64(missed))
iterationsScheduled.Add(float64(missed))
}
lastTriggered = time.Now()
2015-12-14 08:40:40 -08:00
iter()
2015-01-29 06:05:10 -08:00
}
}
}
}
2015-12-14 08:40:40 -08:00
func (g *Group) stop() {
close(g.done)
<-g.terminated
}
2015-12-14 08:40:40 -08:00
func (g *Group) fingerprint() model.Fingerprint {
l := model.LabelSet{"name": model.LabelValue(g.name)}
return l.Fingerprint()
}
2015-12-17 02:46:10 -08:00
// offset returns until the next consistently slotted evaluation interval.
2015-12-14 08:40:40 -08:00
func (g *Group) offset() time.Duration {
now := time.Now().UnixNano()
var (
base = now - (now % int64(g.interval))
offset = uint64(g.fingerprint()) % uint64(g.interval)
next = base + int64(offset)
)
if next < now {
next += int64(g.interval)
}
2015-12-14 08:40:40 -08:00
return time.Duration(next - now)
}
// copyState copies the alerting rule and staleness related state from the given group.
//
// Rules are matched based on their name. If there are duplicates, the
// first is matched with the first, second with the second etc.
2015-12-14 08:40:40 -08:00
func (g *Group) copyState(from *Group) {
ruleMap := make(map[string][]int, len(from.rules))
for fi, fromRule := range from.rules {
l, _ := ruleMap[fromRule.Name()]
ruleMap[fromRule.Name()] = append(l, fi)
}
for i, rule := range g.rules {
indexes, ok := ruleMap[rule.Name()]
if len(indexes) == 0 {
continue
}
fi := indexes[0]
g.seriesInPreviousEval[i] = from.seriesInPreviousEval[fi]
ruleMap[rule.Name()] = indexes[1:]
ar, ok := rule.(*AlertingRule)
2015-12-14 08:40:40 -08:00
if !ok {
continue
}
far, ok := from.rules[fi].(*AlertingRule)
if !ok {
continue
}
for fp, a := range far.active {
ar.active[fp] = a
2015-12-14 08:40:40 -08:00
}
}
}
func typeForRule(r Rule) ruleType {
switch r.(type) {
case *AlertingRule:
return ruleTypeAlert
case *RecordingRule:
return ruleTypeRecording
}
panic(fmt.Errorf("unknown rule type: %T", r))
}
// Eval runs a single evaluation cycle in which all rules are evaluated in parallel.
2015-12-17 02:46:10 -08:00
// In the future a single group will be evaluated sequentially to properly handle
// rule dependency.
func (g *Group) Eval(ts time.Time) {
2015-12-14 08:40:40 -08:00
var (
wg sync.WaitGroup
2015-12-14 08:40:40 -08:00
)
for i, rule := range g.rules {
rtyp := string(typeForRule(rule))
2015-12-14 08:40:40 -08:00
wg.Add(1)
// BUG(julius): Look at fixing thundering herd.
go func(i int, rule Rule) {
2015-12-14 08:40:40 -08:00
defer wg.Done()
defer func(t time.Time) {
evalDuration.WithLabelValues(rtyp).Observe(time.Since(t).Seconds())
}(time.Now())
evalTotal.WithLabelValues(rtyp).Inc()
2015-12-14 08:40:40 -08:00
vector, err := rule.Eval(g.opts.Context, ts, g.opts.QueryEngine, g.opts.ExternalURL)
2015-12-14 08:40:40 -08:00
if err != nil {
// Canceled queries are intentional termination of queries. This normally
// happens on shutdown and thus we skip logging of any errors here.
if _, ok := err.(promql.ErrQueryCanceled); !ok {
g.logger.Warnf("Error while evaluating rule %q: %s", rule, err)
}
evalFailures.WithLabelValues(rtyp).Inc()
return
2015-12-14 08:40:40 -08:00
}
if ar, ok := rule.(*AlertingRule); ok {
2016-12-29 08:31:14 -08:00
g.sendAlerts(ar)
2015-12-14 08:40:40 -08:00
}
var (
numOutOfOrder = 0
numDuplicates = 0
)
2017-01-13 05:48:01 -08:00
app, err := g.opts.Appendable.Appender()
if err != nil {
g.logger.With("err", err).Warn("creating appender failed")
2017-01-13 05:48:01 -08:00
return
}
seriesReturned := make(map[string]labels.Labels, len(g.seriesInPreviousEval[i]))
2015-12-14 08:40:40 -08:00
for _, s := range vector {
if _, err := app.Add(s.Metric, s.T, s.V); err != nil {
switch err {
case storage.ErrOutOfOrderSample:
numOutOfOrder++
g.logger.With("sample", s).With("err", err).Debug("Rule evaluation result discarded")
case storage.ErrDuplicateSampleForTimestamp:
numDuplicates++
g.logger.With("sample", s).With("err", err).Debug("Rule evaluation result discarded")
default:
g.logger.With("sample", s).With("err", err).Warn("Rule evaluation result discarded")
}
} else {
seriesReturned[s.Metric.String()] = s.Metric
}
}
if numOutOfOrder > 0 {
g.logger.With("numDropped", numOutOfOrder).Warn("Error on ingesting out-of-order result from rule evaluation")
}
if numDuplicates > 0 {
g.logger.With("numDropped", numDuplicates).Warn("Error on ingesting results from rule evaluation with different value but same timestamp")
2015-12-14 08:40:40 -08:00
}
for metric, lset := range g.seriesInPreviousEval[i] {
if _, ok := seriesReturned[metric]; !ok {
// Series no longer exposed, mark it stale.
_, err = app.Add(lset, timestamp.FromTime(ts), math.Float64frombits(value.StaleNaN))
switch err {
case nil:
case storage.ErrOutOfOrderSample, storage.ErrDuplicateSampleForTimestamp:
// Do not count these in logging, as this is expected if series
// is exposed from a different rule.
default:
g.logger.With("sample", metric).With("err", err).Warn("adding stale sample failed")
}
}
}
2017-01-13 05:48:01 -08:00
if err := app.Commit(); err != nil {
g.logger.With("err", err).Warn("rule sample appending failed")
} else {
g.seriesInPreviousEval[i] = seriesReturned
}
}(i, rule)
2015-12-14 08:40:40 -08:00
}
wg.Wait()
}
2015-12-17 02:46:10 -08:00
// sendAlerts sends alert notifications for the given rule.
2016-12-29 08:31:14 -08:00
func (g *Group) sendAlerts(rule *AlertingRule) error {
var alerts []*notifier.Alert
2015-12-15 10:46:03 -08:00
2015-12-17 02:46:10 -08:00
for _, alert := range rule.currentAlerts() {
2015-12-14 08:40:40 -08:00
// Only send actually firing alerts.
2015-12-15 10:46:03 -08:00
if alert.State == StatePending {
continue
}
a := &notifier.Alert{
2016-12-29 08:31:14 -08:00
StartsAt: alert.ActiveAt.Add(rule.holdDuration),
Labels: alert.Labels,
Annotations: alert.Annotations,
2015-12-14 08:40:40 -08:00
GeneratorURL: g.opts.ExternalURL.String() + strutil.GraphLinkForExpression(rule.vector.String()),
2015-12-15 10:46:03 -08:00
}
2016-12-29 08:31:14 -08:00
if !alert.ResolvedAt.IsZero() {
a.EndsAt = alert.ResolvedAt
2015-12-15 10:46:03 -08:00
}
alerts = append(alerts, a)
}
2015-12-14 08:40:40 -08:00
if len(alerts) > 0 {
2016-03-01 03:37:22 -08:00
g.opts.Notifier.Send(alerts...)
2015-12-14 08:40:40 -08:00
}
2015-12-14 08:40:40 -08:00
return nil
}
2015-12-14 08:40:40 -08:00
// The Manager manages recording and alerting rules.
type Manager struct {
opts *ManagerOptions
groups map[string]*Group
mtx sync.RWMutex
block chan struct{}
logger log.Logger
2015-12-14 08:40:40 -08:00
}
2017-01-13 05:48:01 -08:00
type Appendable interface {
Appender() (storage.Appender, error)
}
2015-12-14 08:40:40 -08:00
// ManagerOptions bundles options for the Manager.
type ManagerOptions struct {
2017-01-13 05:48:01 -08:00
ExternalURL *url.URL
QueryEngine *promql.Engine
Context context.Context
Notifier *notifier.Notifier
Appendable Appendable
Logger log.Logger
2015-12-14 08:40:40 -08:00
}
2015-12-14 08:40:40 -08:00
// NewManager returns an implementation of Manager, ready to be started
// by calling the Run method.
func NewManager(o *ManagerOptions) *Manager {
return &Manager{
2015-12-14 08:40:40 -08:00
groups: map[string]*Group{},
opts: o,
block: make(chan struct{}),
logger: o.Logger,
}
}
// Run starts processing of the rule manager.
func (m *Manager) Run() {
close(m.block)
}
2015-12-14 08:40:40 -08:00
// Stop the rule manager's rule evaluation cycles.
func (m *Manager) Stop() {
rules/manager.go: Fix race between reload and stop On one relatively large Prometheus instance (1.7M series), I noticed that upgrades were frequently resulting in Prometheus undergoing crash recovery on start-up. On closer examination, I found that Prometheus was panicking on shutdown. It seems that our configuration management (or misconfiguration thereof) is reloading Prometheus then immediately restarting it, which I suspect is causing this race: Sep 21 15:12:42 host systemd[1]: Reloading prometheus monitoring system. Sep 21 15:12:42 host prometheus[18734]: time="2016-09-21T15:12:42Z" level=info msg="Loading configuration file /etc/prometheus/config.yaml" source="main.go:221" Sep 21 15:12:42 host systemd[1]: Reloaded prometheus monitoring system. Sep 21 15:12:44 host systemd[1]: Stopping prometheus monitoring system... Sep 21 15:12:44 host prometheus[18734]: time="2016-09-21T15:12:44Z" level=warning msg="Received SIGTERM, exiting gracefully..." source="main.go:203" Sep 21 15:12:44 host prometheus[18734]: time="2016-09-21T15:12:44Z" level=info msg="See you next time!" source="main.go:210" Sep 21 15:12:44 host prometheus[18734]: time="2016-09-21T15:12:44Z" level=info msg="Stopping target manager..." source="targetmanager.go:90" Sep 21 15:12:52 host prometheus[18734]: time="2016-09-21T15:12:52Z" level=info msg="Checkpointing in-memory metrics and chunks..." source="persistence.go:548" Sep 21 15:12:56 host prometheus[18734]: time="2016-09-21T15:12:56Z" level=warning msg="Error on ingesting out-of-order samples" numDropped=1 source="scrape.go:467" Sep 21 15:12:56 host prometheus[18734]: time="2016-09-21T15:12:56Z" level=error msg="Error adding file watch for \"/etc/prometheus/targets\": no such file or directory" source="file.go:84" Sep 21 15:12:56 host prometheus[18734]: time="2016-09-21T15:12:56Z" level=error msg="Error adding file watch for \"/etc/prometheus/targets\": no such file or directory" source="file.go:84" Sep 21 15:13:01 host prometheus[18734]: time="2016-09-21T15:13:01Z" level=info msg="Stopping rule manager..." source="manager.go:366" Sep 21 15:13:01 host prometheus[18734]: time="2016-09-21T15:13:01Z" level=info msg="Rule manager stopped." source="manager.go:372" Sep 21 15:13:01 host prometheus[18734]: time="2016-09-21T15:13:01Z" level=info msg="Stopping notification handler..." source="notifier.go:325" Sep 21 15:13:01 host prometheus[18734]: time="2016-09-21T15:13:01Z" level=info msg="Stopping local storage..." source="storage.go:381" Sep 21 15:13:01 host prometheus[18734]: time="2016-09-21T15:13:01Z" level=info msg="Stopping maintenance loop..." source="storage.go:383" Sep 21 15:13:01 host prometheus[18734]: panic: close of closed channel Sep 21 15:13:01 host prometheus[18734]: goroutine 7686074 [running]: Sep 21 15:13:01 host prometheus[18734]: panic(0xba57a0, 0xc60c42b500) Sep 21 15:13:01 host prometheus[18734]: /usr/local/go/src/runtime/panic.go:500 +0x1a1 Sep 21 15:13:01 host prometheus[18734]: github.com/prometheus/prometheus/rules.(*Manager).ApplyConfig.func1(0xc6645a9901, 0xc420271ef0, 0xc420338ed0, 0xc60c42b4f0, 0xc6645a9900) Sep 21 15:13:01 host prometheus[18734]: /home/build/packages/prometheus/tmp/build/gopath/src/github.com/prometheus/prometheus/rules/manager.go:412 +0x3c Sep 21 15:13:01 host prometheus[18734]: created by github.com/prometheus/prometheus/rules.(*Manager).ApplyConfig Sep 21 15:13:01 host prometheus[18734]: /home/build/packages/prometheus/tmp/build/gopath/src/github.com/prometheus/prometheus/rules/manager.go:423 +0x56b Sep 21 15:13:03 host systemd[1]: prometheus.service: main process exited, code=exited, status=2/INVALIDARGUMENT
2016-09-21 14:03:02 -07:00
m.mtx.Lock()
defer m.mtx.Unlock()
m.logger.Info("Stopping rule manager...")
2015-06-30 02:51:05 -07:00
2015-12-14 08:40:40 -08:00
for _, eg := range m.groups {
eg.stop()
2015-06-30 02:51:05 -07:00
}
m.logger.Info("Rule manager stopped.")
2015-06-30 02:51:05 -07:00
}
// ApplyConfig updates the rule manager's state as the config requires. If
// loading the new rules failed the old rule set is restored.
func (m *Manager) ApplyConfig(conf *config.Config) error {
2015-12-14 08:40:40 -08:00
m.mtx.Lock()
defer m.mtx.Unlock()
2015-12-14 08:40:40 -08:00
// Get all rule files and load the groups they define.
var files []string
for _, pat := range conf.RuleFiles {
fs, err := filepath.Glob(pat)
if err != nil {
// The only error can be a bad pattern.
return fmt.Errorf("error retrieving rule files for %s: %s", pat, err)
}
files = append(files, fs...)
}
2015-12-14 08:40:40 -08:00
// To be replaced with a configurable per-group interval.
groups, err := m.loadGroups(time.Duration(conf.GlobalConfig.EvaluationInterval), files...)
2015-12-14 08:40:40 -08:00
if err != nil {
return fmt.Errorf("error loading rules, previous rule set restored: %s", err)
}
2015-12-14 08:40:40 -08:00
var wg sync.WaitGroup
for _, newg := range groups {
wg.Add(1)
// If there is an old group with the same identifier, stop it and wait for
// it to finish the current iteration. Then copy it into the new group.
2015-12-14 08:40:40 -08:00
oldg, ok := m.groups[newg.name]
delete(m.groups, newg.name)
go func(newg *Group) {
if ok {
oldg.stop()
newg.copyState(oldg)
}
go func() {
// Wait with starting evaluation until the rule manager
// is told to run. This is necessary to avoid running
// queries against a bootstrapping storage.
<-m.block
newg.run()
}()
2015-12-14 08:40:40 -08:00
wg.Done()
}(newg)
}
// Stop remaining old groups.
for _, oldg := range m.groups {
oldg.stop()
}
wg.Wait()
m.groups = groups
return nil
}
2015-12-17 02:46:10 -08:00
// loadGroups reads groups from a list of files.
// As there's currently no group syntax a single group named "default" containing
// all rules will be returned.
func (m *Manager) loadGroups(interval time.Duration, filenames ...string) (map[string]*Group, error) {
rules := []Rule{}
for _, fn := range filenames {
content, err := ioutil.ReadFile(fn)
if err != nil {
2015-12-14 08:40:40 -08:00
return nil, err
}
stmts, err := promql.ParseStmts(string(content))
if err != nil {
2015-12-14 08:40:40 -08:00
return nil, fmt.Errorf("error parsing %s: %s", fn, err)
}
for _, stmt := range stmts {
2015-12-14 08:40:40 -08:00
var rule Rule
switch r := stmt.(type) {
case *promql.AlertStmt:
rule = NewAlertingRule(r.Name, r.Expr, r.Duration, r.Labels, r.Annotations, m.logger)
2015-12-14 08:40:40 -08:00
case *promql.RecordStmt:
2015-12-14 08:40:40 -08:00
rule = NewRecordingRule(r.Name, r.Expr, r.Labels)
default:
panic("retrieval.Manager.LoadRuleFiles: unknown statement type")
}
rules = append(rules, rule)
}
}
2015-12-14 08:40:40 -08:00
// Currently there is no group syntax implemented. Thus all rules
// are read into a single default group.
g := NewGroup("default", interval, rules, m.opts)
groups := map[string]*Group{g.name: g}
2015-12-14 08:40:40 -08:00
return groups, nil
}
2013-06-11 02:00:55 -07:00
// Rules returns the list of the manager's rules.
func (m *Manager) Rules() []Rule {
2015-12-14 08:40:40 -08:00
m.mtx.RLock()
defer m.mtx.RUnlock()
var rules []Rule
for _, g := range m.groups {
rules = append(rules, g.rules...)
}
2013-06-11 02:00:55 -07:00
return rules
}
// AlertingRules returns the list of the manager's alerting rules.
func (m *Manager) AlertingRules() []*AlertingRule {
2015-12-14 08:40:40 -08:00
m.mtx.RLock()
defer m.mtx.RUnlock()
alerts := []*AlertingRule{}
2015-12-14 08:40:40 -08:00
for _, rule := range m.Rules() {
if alertingRule, ok := rule.(*AlertingRule); ok {
alerts = append(alerts, alertingRule)
}
}
return alerts
}