From d1787a38235cb28275a9a8bae3af5eb214934a92 Mon Sep 17 00:00:00 2001 From: jamesread Date: Thu, 25 Jun 2026 23:05:47 +0100 Subject: [PATCH 1/2] feat: Better prometheus support --- .../advanced_configuration/prometheus.adoc | 52 +++++++++++- .../tests/prometheus/prometheus.mjs | 2 + service/internal/executor/executor.go | 11 +-- service/internal/executor/prometheus.go | 81 +++++++++++++++++++ service/internal/executor/prometheus_test.go | 76 +++++++++++++++++ 5 files changed, 209 insertions(+), 13 deletions(-) create mode 100644 service/internal/executor/prometheus.go create mode 100644 service/internal/executor/prometheus_test.go diff --git a/docs/modules/ROOT/pages/advanced_configuration/prometheus.adoc b/docs/modules/ROOT/pages/advanced_configuration/prometheus.adoc index 7c811e2..a105709 100644 --- a/docs/modules/ROOT/pages/advanced_configuration/prometheus.adoc +++ b/docs/modules/ROOT/pages/advanced_configuration/prometheus.adoc @@ -25,16 +25,60 @@ This will give you metrics available at http://yourserver:1337/metrics. The page [source] ---- # HELP olivetin_actions_requested_count The actions requested count -# TYPE olivetin_actions_requested_count gauge +# TYPE olivetin_actions_requested_count counter olivetin_actions_requested_count 0 +# HELP olivetin_action_executions_total Total number of finished action executions grouped by result. +# TYPE olivetin_action_executions_total counter +olivetin_action_executions_total{result="success"} 0 +olivetin_action_executions_total{result="failed"} 0 +olivetin_action_executions_total{result="blocked"} 0 +olivetin_action_executions_total{result="timeout"} 0 +olivetin_action_executions_total{result="error"} 0 +# HELP olivetin_action_execution_duration_seconds Action execution duration in seconds from start to finish. +# TYPE olivetin_action_execution_duration_seconds histogram +olivetin_action_execution_duration_seconds_bucket{le="0.1"} 0 # HELP olivetin_config_action_count Then number of actions in the config file # TYPE olivetin_config_action_count gauge olivetin_config_action_count 18 # HELP olivetin_config_reloaded_count The number of times the config has been reloaded # TYPE olivetin_config_reloaded_count counter olivetin_config_reloaded_count 1 -# HELP olivetin_sv_count The number entries in the sv map -# TYPE olivetin_sv_count gauge -olivetin_sv_count 49 +---- + +=== Failed job monitoring + +Finished action executions are counted in `olivetin_action_executions_total` with a `result` label: + +[cols="1,2"] +|=== +| `success` | Command finished with exit code 0 +| `failed` | Command ran but exited with a non-zero code +| `timeout` | Command exceeded its configured timeout +| `blocked` | Execution was blocked (ACL, rate limit, concurrency, or queue limit) +| `error` | Execution failed before the command ran (for example, invalid arguments) +|=== + +`olivetin_action_execution_duration_seconds` records how long each finished execution took. + +Example Prometheus alert rules: + +[source,yaml] +---- +groups: + - name: olivetin + rules: + - alert: OliveTinActionFailed + expr: increase(olivetin_action_executions_total{result="failed"}[15m]) > 0 + labels: + severity: warning + annotations: + summary: OliveTin action failed with non-zero exit code + + - alert: OliveTinActionTimedOut + expr: increase(olivetin_action_executions_total{result="timeout"}[15m]) > 0 + labels: + severity: warning + annotations: + summary: OliveTin action timed out ---- diff --git a/integration-tests/tests/prometheus/prometheus.mjs b/integration-tests/tests/prometheus/prometheus.mjs index 7d1f2ea..d9bbba7 100644 --- a/integration-tests/tests/prometheus/prometheus.mjs +++ b/integration-tests/tests/prometheus/prometheus.mjs @@ -8,6 +8,8 @@ import { let metrics = [ {'name': 'olivetin_actions_requested_count', 'type': 'counter', 'desc': 'The actions requested count'}, + {'name': 'olivetin_action_executions_total', 'type': 'counter', 'desc': 'Total number of finished action executions grouped by result\\.'}, + {'name': 'olivetin_action_execution_duration_seconds', 'type': 'histogram', 'desc': 'Action execution duration in seconds from start to finish\\.'}, {'name': 'olivetin_config_action_count', 'type': 'gauge', 'desc': 'The number of actions in the config file'}, {'name': 'olivetin_config_reloaded_count', 'type': 'counter', 'desc': 'The number of times the config has been reloaded'}, ] diff --git a/service/internal/executor/executor.go b/service/internal/executor/executor.go index 605c7ad..af4bb8b 100644 --- a/service/internal/executor/executor.go +++ b/service/internal/executor/executor.go @@ -11,8 +11,6 @@ import ( "github.com/google/uuid" log "github.com/sirupsen/logrus" - "github.com/prometheus/client_golang/prometheus" - "github.com/prometheus/client_golang/prometheus/promauto" "gopkg.in/yaml.v3" "bytes" @@ -40,13 +38,6 @@ func isValidTrackingID(id string) bool { return id != "" && len(id) <= MaxTrackingIDLength && validTrackingIDPattern.MatchString(id) } -var ( - metricActionsRequested = promauto.NewCounter(prometheus.CounterOpts{ - Name: "olivetin_actions_requested_count", - Help: "The actions requested count", - }) -) - type ActionBinding struct { ID string Action *config.Action @@ -705,6 +696,8 @@ func (e *Executor) finishExecChain(req *ExecutionRequest) { entry.ExecutionFinished = true }) + recordExecutionMetrics(req.logEntry) + notifyListenersFinished(req) e.drainGroupQueue() } diff --git a/service/internal/executor/prometheus.go b/service/internal/executor/prometheus.go new file mode 100644 index 0000000..c70be23 --- /dev/null +++ b/service/internal/executor/prometheus.go @@ -0,0 +1,81 @@ +package executor + +import ( + "github.com/prometheus/client_golang/prometheus" + "github.com/prometheus/client_golang/prometheus/promauto" +) + +const ( + executionResultSuccess = "success" + executionResultFailed = "failed" + executionResultBlocked = "blocked" + executionResultTimeout = "timeout" + executionResultError = "error" +) + +var ( + metricActionsRequested = promauto.NewCounter(prometheus.CounterOpts{ + Name: "olivetin_actions_requested_count", + Help: "The actions requested count", + }) + + metricActionExecutionsTotal = promauto.NewCounterVec(prometheus.CounterOpts{ + Name: "olivetin_action_executions_total", + Help: "Total number of finished action executions grouped by result.", + }, []string{"result"}) + + metricActionExecutionDuration = promauto.NewHistogram(prometheus.HistogramOpts{ + Name: "olivetin_action_execution_duration_seconds", + Help: "Action execution duration in seconds from start to finish.", + Buckets: []float64{0.1, 0.5, 1, 2, 5, 10, 30, 60, 120, 300, 600}, + }) +) + +func executionResultLabel(entry *InternalLogEntry) string { + if entry.Blocked { + return executionResultBlocked + } + + return finishedExecutionResultLabel(entry) +} + +func finishedExecutionResultLabel(entry *InternalLogEntry) string { + if entry.TimedOut { + return executionResultTimeout + } + + switch { + case entry.ExitCode == 0: + return executionResultSuccess + case isPreExecutionError(entry): + return executionResultError + default: + return executionResultFailed + } +} + +func isPreExecutionError(entry *InternalLogEntry) bool { + return entry.ExitCode == DefaultExitCodeNotExecuted || !entry.ExecutionStarted +} + +func recordExecutionMetrics(entry *InternalLogEntry) { + if entry == nil || entry.Queued { + return + } + + metricActionExecutionsTotal.WithLabelValues(executionResultLabel(entry)).Inc() + recordExecutionDuration(entry) +} + +func recordExecutionDuration(entry *InternalLogEntry) { + if entry.DatetimeFinished.IsZero() || entry.DatetimeStarted.IsZero() { + return + } + + duration := entry.DatetimeFinished.Sub(entry.DatetimeStarted).Seconds() + if duration < 0 { + return + } + + metricActionExecutionDuration.Observe(duration) +} diff --git a/service/internal/executor/prometheus_test.go b/service/internal/executor/prometheus_test.go new file mode 100644 index 0000000..8bb969c --- /dev/null +++ b/service/internal/executor/prometheus_test.go @@ -0,0 +1,76 @@ +package executor + +import ( + "testing" + + "github.com/stretchr/testify/assert" +) + +func TestExecutionResultLabel(t *testing.T) { + tests := []struct { + name string + entry *InternalLogEntry + want string + }{ + { + name: "success", + entry: &InternalLogEntry{ + ExecutionStarted: true, + ExecutionFinished: true, + ExitCode: 0, + }, + want: executionResultSuccess, + }, + { + name: "failed nonzero exit", + entry: &InternalLogEntry{ + ExecutionStarted: true, + ExecutionFinished: true, + ExitCode: 1, + }, + want: executionResultFailed, + }, + { + name: "blocked", + entry: &InternalLogEntry{ + Blocked: true, + ExecutionFinished: true, + ExitCode: 0, + }, + want: executionResultBlocked, + }, + { + name: "timeout", + entry: &InternalLogEntry{ + ExecutionStarted: true, + ExecutionFinished: true, + TimedOut: true, + ExitCode: -1, + }, + want: executionResultTimeout, + }, + { + name: "error before execution", + entry: &InternalLogEntry{ + ExecutionFinished: true, + ExitCode: DefaultExitCodeNotExecuted, + }, + want: executionResultError, + }, + { + name: "error never started", + entry: &InternalLogEntry{ + ExecutionStarted: false, + ExecutionFinished: true, + ExitCode: 2, + }, + want: executionResultError, + }, + } + + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + assert.Equal(t, tt.want, executionResultLabel(tt.entry)) + }) + } +} From a413f9d6afb601e8053c591e4db4dcd9c1d14f76 Mon Sep 17 00:00:00 2001 From: jamesread Date: Mon, 29 Jun 2026 00:03:31 +0100 Subject: [PATCH 2/2] chore: fix flakey tests --- .../executor/group_concurrency_test.go | 39 +++++++++---------- service/internal/executor/prometheus.go | 14 +++++++ 2 files changed, 32 insertions(+), 21 deletions(-) diff --git a/service/internal/executor/group_concurrency_test.go b/service/internal/executor/group_concurrency_test.go index bd6323a..4828478 100644 --- a/service/internal/executor/group_concurrency_test.go +++ b/service/internal/executor/group_concurrency_test.go @@ -508,36 +508,33 @@ func TestGroupQueueBlocksWhenQueueFull(t *testing.T) { }, ) - trackings, waitGroups := execAllGroupActions(t, e, cfg, actions) + wg1, tracking1 := e.ExecRequest(&ExecutionRequest{ + Binding: e.FindBindingWithNoEntity(actions[0]), + Cfg: cfg, + AuthenticatedUser: auth.UserFromSystem(cfg, "testuser"), + }) + waitUntilExecutionStarted(t, e, tracking1) - require.Eventually(t, func() bool { - return countSnapshots(e, trackings, func(snapshot LogEntrySnapshot) bool { return snapshot.Blocked }) == 1 && - countSnapshots(e, trackings, func(snapshot LogEntrySnapshot) bool { return snapshot.Queued }) == 2 && - countSnapshots(e, trackings, isRunningSnapshot) == 1 - }, 2*time.Second, 20*time.Millisecond) + trackings := []string{tracking1} + waitGroups := []*sync.WaitGroup{wg1} - for _, wg := range waitGroups { - wg.Wait() - } -} - -func execAllGroupActions(t *testing.T, e *Executor, cfg *config.Config, actions []*config.Action) ([]string, []*sync.WaitGroup) { - t.Helper() - - trackings := make([]string, len(actions)) - waitGroups := make([]*sync.WaitGroup, len(actions)) - - for idx, action := range actions { + for _, action := range actions[1:] { wg, tracking := e.ExecRequest(&ExecutionRequest{ Binding: e.FindBindingWithNoEntity(action), Cfg: cfg, AuthenticatedUser: auth.UserFromSystem(cfg, "testuser"), }) - trackings[idx] = tracking - waitGroups[idx] = wg + trackings = append(trackings, tracking) + waitGroups = append(waitGroups, wg) } - return trackings, waitGroups + require.Eventually(t, func() bool { + return groupExecutionDistributionMatches(e, trackings, 1, 2, 1) + }, 2*time.Second, 20*time.Millisecond) + + for _, wg := range waitGroups { + wg.Wait() + } } func groupExecutionDistributionMatches(e *Executor, trackings []string, wantRunning, wantQueued, wantBlocked int) bool { diff --git a/service/internal/executor/prometheus.go b/service/internal/executor/prometheus.go index c70be23..4424633 100644 --- a/service/internal/executor/prometheus.go +++ b/service/internal/executor/prometheus.go @@ -29,8 +29,22 @@ var ( Help: "Action execution duration in seconds from start to finish.", Buckets: []float64{0.1, 0.5, 1, 2, 5, 10, 30, 60, 120, 300, 600}, }) + + executionResultLabels = []string{ + executionResultSuccess, + executionResultFailed, + executionResultBlocked, + executionResultTimeout, + executionResultError, + } ) +func init() { + for _, result := range executionResultLabels { + metricActionExecutionsTotal.WithLabelValues(result) + } +} + func executionResultLabel(entry *InternalLogEntry) string { if entry.Blocked { return executionResultBlocked