diff --git a/Makefile b/Makefile index 74443a00..9fddc49c 100644 --- a/Makefile +++ b/Makefile @@ -327,6 +327,36 @@ test-alerts: ## Lint and unit test the alert rules with promtool. echo "Running unit tests..."; \ promtool test rules --diff "$$tmpdir"/tests/*.yaml +OBS_DEV_NAMESPACE := demo +OBS_DEV_OUT := $(OBS_DIR)/generated/dev +# Extra flags for the simulator, e.g. SIMULATOR_ARGS="-leader=false". +SIMULATOR_ARGS ?= + +.PHONY: observability-render-dev +observability-render-dev: ## Render dashboards and plain rules for the dev stack, with every `for:` shortened to 2m. + @rm -rf $(OBS_DEV_OUT)/alerts/* $(OBS_DEV_OUT)/dashboards/* + @$(MAKE) --no-print-directory dashboards METRIC_NAMESPACE=$(OBS_DEV_NAMESPACE) OBS_OUT=$(OBS_DEV_OUT) + @$(MAKE) --no-print-directory alerts METRIC_NAMESPACE=$(OBS_DEV_NAMESPACE) OBS_OUT=$(OBS_DEV_OUT) ALERT_FORMAT=rules + @for file in $(OBS_DEV_OUT)/alerts/*.yaml; do \ + sed -E 's/^( *for: ).*/\12m/' "$$file" > "$$file.tmp" && mv "$$file.tmp" "$$file"; \ + done + +.PHONY: observability-up +observability-up: observability-render-dev ## Start Prometheus (:9090) and Grafana (:3000) and run the simulator on the host. + docker compose -f $(OBS_DIR)/dev/docker-compose.yaml up -d + @ready=0; for i in $$(seq 1 30); do \ + curl -fsS 127.0.0.1:9090/-/ready >/dev/null 2>&1 && { ready=1; break; }; \ + sleep 1; \ + done; \ + [ "$$ready" = "1" ] || { echo "Error: prometheus did not become ready"; exit 1; }; \ + curl -fsS -X POST 127.0.0.1:9090/-/reload + @echo "Grafana: http://localhost:3000 Prometheus: http://localhost:9090/alerts" + go run ./$(OBS_DIR)/dev/simulator -metric-namespace=$(OBS_DEV_NAMESPACE) $(SIMULATOR_ARGS) + +.PHONY: observability-down +observability-down: ## Stop the local Prometheus and Grafana. + docker compose -f $(OBS_DIR)/dev/docker-compose.yaml down + # go-install-tool will 'go install' any package with custom target and name of binary, if it doesn't exist # $1 - target path with name of binary diff --git a/go.mod b/go.mod index fa7e1b64..ecfa8fb9 100644 --- a/go.mod +++ b/go.mod @@ -8,6 +8,7 @@ require ( github.com/onsi/gomega v1.42.1 github.com/pmezard/go-difflib v1.0.1-0.20181226105442-5d4384ee4fb2 github.com/prometheus/client_golang v1.23.2 + github.com/prometheus/client_model v0.6.2 github.com/sourcehawk/go-crd-condition-metrics v1.1.0 github.com/spf13/cobra v1.10.2 github.com/stretchr/testify v1.11.1 @@ -46,7 +47,6 @@ require ( github.com/modern-go/concurrent v0.0.0-20180306012644-bacd9c7ef1dd // indirect github.com/modern-go/reflect2 v1.0.3-0.20250322232337-35a7c28c31ee // indirect github.com/munnerz/goautoneg v0.0.0-20191010083416-a7dc8b61c822 // indirect - github.com/prometheus/client_model v0.6.2 // indirect github.com/prometheus/common v0.67.5 // indirect github.com/prometheus/procfs v0.19.2 // indirect github.com/sourcehawk/go-prometheus-gaugevecset v1.1.0 // indirect diff --git a/observability/dev/docker-compose.yaml b/observability/dev/docker-compose.yaml new file mode 100644 index 00000000..c692d022 --- /dev/null +++ b/observability/dev/docker-compose.yaml @@ -0,0 +1,29 @@ +# Local Prometheus + Grafana for looking at the dashboards and alerts with the +# simulator's data behind them. Start with `make observability-up`. +services: + prometheus: + image: prom/prometheus:v3.14.0 + command: + - --config.file=/etc/prometheus/prometheus.yml + - --web.enable-lifecycle + ports: + - "127.0.0.1:9090:9090" + volumes: + - ./prometheus/prometheus.yml:/etc/prometheus/prometheus.yml:ro + - ../generated/dev/alerts:/etc/prometheus/rules:ro + extra_hosts: + - "host.docker.internal:host-gateway" + + grafana: + image: grafana/grafana:13.1.4 + ports: + - "127.0.0.1:3000:3000" + environment: + GF_AUTH_ANONYMOUS_ENABLED: "true" + GF_AUTH_ANONYMOUS_ORG_ROLE: Admin + GF_AUTH_DISABLE_LOGIN_FORM: "true" + volumes: + - ./grafana/provisioning:/etc/grafana/provisioning:ro + - ../generated/dev/dashboards:/var/lib/grafana/dashboards:ro + depends_on: + - prometheus diff --git a/observability/dev/grafana/provisioning/dashboards/ocf.yaml b/observability/dev/grafana/provisioning/dashboards/ocf.yaml new file mode 100644 index 00000000..0d6093b6 --- /dev/null +++ b/observability/dev/grafana/provisioning/dashboards/ocf.yaml @@ -0,0 +1,8 @@ +apiVersion: 1 +providers: + - name: ocf + folder: OCF + type: file + disableDeletion: true + options: + path: /var/lib/grafana/dashboards diff --git a/observability/dev/grafana/provisioning/datasources/prometheus.yaml b/observability/dev/grafana/provisioning/datasources/prometheus.yaml new file mode 100644 index 00000000..c988f2da --- /dev/null +++ b/observability/dev/grafana/provisioning/datasources/prometheus.yaml @@ -0,0 +1,9 @@ +apiVersion: 1 +datasources: + - name: Prometheus + type: prometheus + uid: prometheus + access: proxy + url: http://prometheus:9090 + isDefault: true + editable: false diff --git a/observability/dev/prometheus/prometheus.yml b/observability/dev/prometheus/prometheus.yml new file mode 100644 index 00000000..7a99cbdb --- /dev/null +++ b/observability/dev/prometheus/prometheus.yml @@ -0,0 +1,18 @@ +# Scrapes the simulator running on the host. The static `namespace` and `pod` +# target labels collide with the namespace label the condition gauge exports, +# which Prometheus resolves by renaming the exported one to +# `exported_namespace`, exactly as a ServiceMonitor scrape does in a cluster. +global: + scrape_interval: 5s + evaluation_interval: 10s + +rule_files: + - /etc/prometheus/rules/*.yaml + +scrape_configs: + - job_name: demo-operator + static_configs: + - targets: ["host.docker.internal:8080"] + labels: + namespace: operators + pod: demo-operator-0 diff --git a/observability/dev/simulator/main.go b/observability/dev/simulator/main.go new file mode 100644 index 00000000..9501ccb8 --- /dev/null +++ b/observability/dev/simulator/main.go @@ -0,0 +1,77 @@ +// Command simulator exposes a synthetic operator's metrics on /metrics for the +// local observability stack under observability/dev. +// +// The framework's own series (resource applies, conditions) are recorded +// through the real pkg/metrics recorder; controller-runtime, workqueue, REST +// client and leader election series are lookalikes guarded by runtime_test.go. +// The world it plays is described in docs/observability.md. +package main + +import ( + "context" + "errors" + "flag" + "fmt" + "log" + "net/http" + "os" + "os/signal" + "syscall" + "time" + + "github.com/prometheus/client_golang/prometheus" + "github.com/prometheus/client_golang/prometheus/promhttp" + ocm "github.com/sourcehawk/go-crd-condition-metrics/pkg/crd-condition-metrics" + + "github.com/sourcehawk/operator-component-framework/pkg/metrics" +) + +func main() { + if err := run(); err != nil { + log.Fatal(err) + } +} + +// run wires the registry the way an operator would, serves /metrics and plays +// the world until the process is signalled. It returns an error when the +// metrics endpoint failed to serve, so main exits non-zero and +// `make observability-up` fails visibly instead of idling without metrics. +func run() error { + listen := flag.String("listen", ":8080", "address to serve /metrics on") + metricNamespace := flag.String("metric-namespace", "demo", "metric namespace of the condition gauge") + leader := flag.Bool("leader", true, "report this replica as the leader; false shows OperatorLeaderMissing") + flag.Parse() + + reg := prometheus.NewRegistry() + conditions := ocm.NewOperatorConditionsGauge(*metricNamespace) + collectors := metrics.NewCollectors() + reg.MustRegister(conditions, collectors) + rt := newRuntimeMetrics(reg) + + ctx, stop := signal.NotifyContext(context.Background(), os.Interrupt, syscall.SIGTERM) + defer stop() + + mux := http.NewServeMux() + mux.Handle("/metrics", promhttp.HandlerFor(reg, promhttp.HandlerOpts{})) + srv := &http.Server{Addr: *listen, Handler: mux, ReadHeaderTimeout: 5 * time.Second} + serveErr := make(chan error, 1) + go func() { + log.Printf("serving metrics on %s/metrics", *listen) + if err := srv.ListenAndServe(); err != nil && !errors.Is(err, http.ErrServerClosed) { + serveErr <- err + stop() + } + }() + + newWorld(conditions, collectors, rt, *leader).run(ctx) + + shutdown, cancel := context.WithTimeout(context.Background(), 5*time.Second) + defer cancel() + _ = srv.Shutdown(shutdown) + select { + case err := <-serveErr: + return fmt.Errorf("serving metrics: %w", err) + default: + return nil + } +} diff --git a/observability/dev/simulator/runtime.go b/observability/dev/simulator/runtime.go new file mode 100644 index 00000000..f04b7975 --- /dev/null +++ b/observability/dev/simulator/runtime.go @@ -0,0 +1,142 @@ +package main + +import ( + "github.com/prometheus/client_golang/prometheus" + "github.com/prometheus/client_golang/prometheus/collectors" + ctrlmetrics "sigs.k8s.io/controller-runtime/pkg/metrics" +) + +// runtimeMetrics defines the controller-runtime, workqueue, REST client and +// leader election series an operator exposes, with the same names, label sets +// and bucket layouts as the real ones. The real vectors live in +// controller-runtime's internal packages; runtime_test.go guards this copy +// against drift. +type runtimeMetrics struct { + reconcileTotal *prometheus.CounterVec + reconcileErrors *prometheus.CounterVec + reconcilePanics *prometheus.CounterVec + reconcileTime *prometheus.HistogramVec + maxConcurrent *prometheus.GaugeVec + activeWorkers *prometheus.GaugeVec + queueDepth *prometheus.GaugeVec + queueAdds *prometheus.CounterVec + queueDuration *prometheus.HistogramVec + workDuration *prometheus.HistogramVec + queueUnfinished *prometheus.GaugeVec + queueLongestRunning *prometheus.GaugeVec + queueRetries *prometheus.CounterVec + restRequests *prometheus.CounterVec + leader *prometheus.GaugeVec +} + +// Label names and the reconcile result value the lookalike series share with +// controller-runtime. +const ( + labelController = "controller" + labelName = "name" + resultError = "error" +) + +// reconcileTimeBuckets mirrors controller-runtime's ReconcileTime histogram. +var reconcileTimeBuckets = []float64{0.005, 0.01, 0.025, 0.05, 0.1, 0.15, 0.2, 0.25, 0.3, 0.35, 0.4, 0.45, 0.5, 0.6, 0.7, 0.8, 0.9, 1.0, + 1.25, 1.5, 1.75, 2.0, 2.5, 3.0, 3.5, 4.0, 4.5, 5, 6, 7, 8, 9, 10, 15, 20, 25, 30, 40, 50, 60} + +func newRuntimeMetrics(reg prometheus.Registerer) *runtimeMetrics { + m := &runtimeMetrics{ + reconcileTotal: prometheus.NewCounterVec(prometheus.CounterOpts{ + Name: "controller_runtime_reconcile_total", + Help: "Total number of reconciliations per controller", + }, []string{labelController, "result"}), + reconcileErrors: prometheus.NewCounterVec(prometheus.CounterOpts{ + Name: "controller_runtime_reconcile_errors_total", + Help: "Total number of reconciliation errors per controller", + }, []string{labelController}), + reconcilePanics: prometheus.NewCounterVec(prometheus.CounterOpts{ + Name: "controller_runtime_reconcile_panics_total", + Help: "Total number of reconciliation panics per controller", + }, []string{labelController}), + reconcileTime: prometheus.NewHistogramVec(prometheus.HistogramOpts{ + Name: "controller_runtime_reconcile_time_seconds", + Help: "Length of time per reconciliation per controller", + Buckets: reconcileTimeBuckets, + }, []string{labelController}), + maxConcurrent: prometheus.NewGaugeVec(prometheus.GaugeOpts{ + Name: "controller_runtime_max_concurrent_reconciles", + Help: "Maximum number of concurrent reconciles per controller", + }, []string{labelController}), + activeWorkers: prometheus.NewGaugeVec(prometheus.GaugeOpts{ + Name: "controller_runtime_active_workers", + Help: "Number of currently used workers per controller", + }, []string{labelController}), + queueDepth: prometheus.NewGaugeVec(prometheus.GaugeOpts{ + Subsystem: ctrlmetrics.WorkQueueSubsystem, Name: ctrlmetrics.DepthKey, + Help: "Current depth of workqueue by workqueue and priority", + }, []string{labelName, labelController, "priority"}), + queueAdds: prometheus.NewCounterVec(prometheus.CounterOpts{ + Subsystem: ctrlmetrics.WorkQueueSubsystem, Name: ctrlmetrics.AddsKey, + Help: "Total number of adds handled by workqueue", + }, []string{labelName, labelController}), + queueDuration: prometheus.NewHistogramVec(prometheus.HistogramOpts{ + Subsystem: ctrlmetrics.WorkQueueSubsystem, Name: ctrlmetrics.QueueLatencyKey, + Help: "How long in seconds an item stays in workqueue before being requested", + Buckets: prometheus.ExponentialBuckets(10e-9, 10, 12), + }, []string{labelName, labelController}), + workDuration: prometheus.NewHistogramVec(prometheus.HistogramOpts{ + Subsystem: ctrlmetrics.WorkQueueSubsystem, Name: ctrlmetrics.WorkDurationKey, + Help: "How long in seconds processing an item from workqueue takes.", + Buckets: prometheus.ExponentialBuckets(10e-9, 10, 12), + }, []string{labelName, labelController}), + queueUnfinished: prometheus.NewGaugeVec(prometheus.GaugeOpts{ + Subsystem: ctrlmetrics.WorkQueueSubsystem, Name: ctrlmetrics.UnfinishedWorkKey, + Help: "How many seconds of work has been done that " + + "is in progress and hasn't been observed by work_duration. Large " + + "values indicate stuck threads. One can deduce the number of stuck " + + "threads by observing the rate at which this increases.", + }, []string{labelName, labelController}), + queueLongestRunning: prometheus.NewGaugeVec(prometheus.GaugeOpts{ + Subsystem: ctrlmetrics.WorkQueueSubsystem, Name: ctrlmetrics.LongestRunningProcessorKey, + Help: "How many seconds has the longest running " + + "processor for workqueue been running.", + }, []string{labelName, labelController}), + queueRetries: prometheus.NewCounterVec(prometheus.CounterOpts{ + Subsystem: ctrlmetrics.WorkQueueSubsystem, Name: ctrlmetrics.RetriesKey, + Help: "Total number of items added to the workqueue with a non-zero delay (rate-limited requeues, explicit RequeueAfter or AddAfter calls)", + }, []string{labelName, labelController}), + restRequests: prometheus.NewCounterVec(prometheus.CounterOpts{ + Name: "rest_client_requests_total", + Help: "Number of HTTP requests, partitioned by status code, method, and host.", + }, []string{"code", "method", "host"}), + leader: prometheus.NewGaugeVec(prometheus.GaugeOpts{ + Name: "leader_election_master_status", + Help: "Gauge of if the reporting system is master of the relevant lease, 0 indicates backup, 1 indicates master. 'name' is the string used to identify the lease. Please make sure to group by name.", + }, []string{labelName}), + } + reg.MustRegister( + m.reconcileTotal, m.reconcileErrors, m.reconcilePanics, m.reconcileTime, m.maxConcurrent, m.activeWorkers, + m.queueDepth, m.queueAdds, m.queueDuration, m.workDuration, m.queueUnfinished, m.queueLongestRunning, m.queueRetries, + m.restRequests, m.leader, + collectors.NewProcessCollector(collectors.ProcessCollectorOpts{}), + collectors.NewGoCollector(), + ) + return m +} + +// initController creates the zero-valued series controller-runtime creates +// when a controller starts, so panels show a flat line instead of no data. +func (m *runtimeMetrics) initController(name string, maxConcurrent int) { + for _, result := range []string{resultError, "requeue_after", "requeue", "success"} { + m.reconcileTotal.WithLabelValues(name, result).Add(0) + } + m.reconcileErrors.WithLabelValues(name).Add(0) + m.reconcilePanics.WithLabelValues(name).Add(0) + m.reconcileTime.WithLabelValues(name) + m.maxConcurrent.WithLabelValues(name).Set(float64(maxConcurrent)) + m.activeWorkers.WithLabelValues(name).Set(0) + m.queueDepth.WithLabelValues(name, name, "0").Set(0) + m.queueAdds.WithLabelValues(name, name).Add(0) + m.queueDuration.WithLabelValues(name, name) + m.workDuration.WithLabelValues(name, name) + m.queueUnfinished.WithLabelValues(name, name).Set(0) + m.queueLongestRunning.WithLabelValues(name, name).Set(0) + m.queueRetries.WithLabelValues(name, name).Add(0) +} diff --git a/observability/dev/simulator/runtime_test.go b/observability/dev/simulator/runtime_test.go new file mode 100644 index 00000000..f1705c32 --- /dev/null +++ b/observability/dev/simulator/runtime_test.go @@ -0,0 +1,142 @@ +package main + +import ( + "context" + "sort" + "strings" + "sync" + "testing" + "time" + + "github.com/prometheus/client_golang/prometheus" + dto "github.com/prometheus/client_model/go" + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" + "k8s.io/apimachinery/pkg/types" + clientmetrics "k8s.io/client-go/tools/metrics" + "k8s.io/client-go/util/workqueue" + "k8s.io/utils/ptr" + "sigs.k8s.io/controller-runtime/pkg/controller" + ctrlmetrics "sigs.k8s.io/controller-runtime/pkg/metrics" + "sigs.k8s.io/controller-runtime/pkg/reconcile" + "sigs.k8s.io/controller-runtime/pkg/source" +) + +// family is the shape of a metric family that the dashboards and alerts +// depend on: its type, its label names and, for histograms, its buckets. +type family struct { + kind dto.MetricType + labels []string + buckets []float64 +} + +func families(t *testing.T, g prometheus.Gatherer, prefixes ...string) map[string]family { + t.Helper() + mfs, err := g.Gather() + require.NoError(t, err) + out := map[string]family{} + for _, mf := range mfs { + name := mf.GetName() + matched := false + for _, p := range prefixes { + if strings.HasPrefix(name, p) { + matched = true + } + } + if !matched || len(mf.GetMetric()) == 0 { + continue + } + m := mf.GetMetric()[0] + f := family{kind: mf.GetType()} + for _, lp := range m.GetLabel() { + f.labels = append(f.labels, lp.GetName()) + } + sort.Strings(f.labels) + if h := m.GetHistogram(); h != nil { + for _, b := range h.GetBucket() { + f.buckets = append(f.buckets, b.GetUpperBound()) + } + } + out[name] = f + } + return out +} + +// TestRuntimeMetricsMatchControllerRuntime starts a real, unmanaged +// controller-runtime controller (no API server involved) and drives one +// request through its queue so that controller-runtime initialises its +// reconcile and workqueue series, then checks that every lookalike series the +// simulator defines exists in controller-runtime with the same type, label +// names and buckets. +func TestRuntimeMetricsMatchControllerRuntime(t *testing.T) { + reconciled := make(chan struct{}) + var once sync.Once + c, err := controller.NewUnmanaged("parity", controller.Options{ + Reconciler: reconcile.Func(func(context.Context, reconcile.Request) (reconcile.Result, error) { + once.Do(func() { close(reconciled) }) + return reconcile.Result{}, nil + }), + SkipNameValidation: ptr.To(true), + }) + require.NoError(t, err) + require.NoError(t, c.Watch(source.Func(func(_ context.Context, q workqueue.TypedRateLimitingInterface[reconcile.Request]) error { + q.Add(reconcile.Request{NamespacedName: types.NamespacedName{Namespace: "default", Name: "parity"}}) + return nil + }))) + ctx, cancel := context.WithCancel(context.Background()) + defer cancel() + done := make(chan error, 1) + go func() { done <- c.Start(ctx) }() + select { + case <-reconciled: + case <-time.After(10 * time.Second): + require.FailNow(t, "the controller never reconciled the enqueued request") + } + // ReconcileTime is observed after the reconciler returns; wait for the + // family to appear before snapshotting the registry. + require.Eventually(t, func() bool { + mfs, err := ctrlmetrics.Registry.Gather() + if err != nil { + return false + } + for _, mf := range mfs { + if mf.GetName() == "controller_runtime_reconcile_time_seconds" && len(mf.GetMetric()) > 0 { + return true + } + } + return false + }, 10*time.Second, 10*time.Millisecond, "controller-runtime never observed a reconcile duration") + cancel() + require.NoError(t, <-done) + + // client-go creates rest_client_requests_total lazily on the first request; + // controller-runtime's pkg/metrics init installed the adapter, so one + // recorded result materialises the real family in the registry. + clientmetrics.RequestResult.Increment(context.Background(), "200", "GET", "10.96.0.1:443") + + want := families(t, ctrlmetrics.Registry, "controller_runtime_", "workqueue_", "rest_client_", "leader_election_") + + reg := prometheus.NewRegistry() + rm := newRuntimeMetrics(reg) + rm.initController("parity", 1) + rm.restRequests.WithLabelValues("200", "GET", "https://example").Add(0) + rm.leader.WithLabelValues("parity").Set(1) + got := families(t, reg, "controller_runtime_", "workqueue_", "rest_client_", "leader_election_") + + require.NotEmpty(t, got) + for name, g := range got { + w, ok := want[name] + if !ok && strings.HasPrefix(name, "leader_election_") { + // The leader elector creates leader_election_master_status only + // when it runs against an API server. Its definition is kept in + // step with controller-runtime's leaderelection.go by hand. + continue + } + if !assert.True(t, ok, "simulator metric %s does not exist in controller-runtime", name) { + continue + } + assert.Equal(t, w.kind, g.kind, "%s type", name) + assert.Equal(t, w.labels, g.labels, "%s labels", name) + assert.Equal(t, w.buckets, g.buckets, "%s buckets", name) + } +} diff --git a/observability/dev/simulator/world.go b/observability/dev/simulator/world.go new file mode 100644 index 00000000..2fe2e5a4 --- /dev/null +++ b/observability/dev/simulator/world.go @@ -0,0 +1,313 @@ +package main + +import ( + "context" + "fmt" + "math/rand/v2" + "time" + + ocm "github.com/sourcehawk/go-crd-condition-metrics/pkg/crd-condition-metrics" + + "github.com/sourcehawk/operator-component-framework/pkg/component" + "github.com/sourcehawk/operator-component-framework/pkg/component/concepts" + "github.com/sourcehawk/operator-component-framework/pkg/metrics" +) + +// owner is a simulated custom resource. It satisfies ocm.ObjectLike. +type owner struct { + namespace, name string +} + +func (o owner) GetName() string { return o.name } +func (o owner) GetNamespace() string { return o.namespace } + +// resource is one managed resource of a component, as the framework labels it. +type resource struct { + component, identifier, kind string +} + +// controllerSim drives one controller's worth of series: a framework recorder +// for conditions and applies, and the controller-runtime lookalikes. +type controllerSim struct { + name string + ownerKind string + rec *metrics.Recorder + rt *runtimeMetrics +} + +func (c *controllerSim) labels(r resource) component.ResourceMetricLabels { + return component.ResourceMetricLabels{ + OwnerKind: c.ownerKind, Component: r.component, Identifier: r.identifier, Kind: r.kind, + } +} + +// reconcile records one reconcile: the workqueue hand-off, the reconcile +// result and duration, and a few REST calls. apply and condition recording is +// left to the caller, which knows the scenario. +func (c *controllerSim) reconcile(result string, queueWait, duration time.Duration) { + c.rt.queueAdds.WithLabelValues(c.name, c.name).Inc() + c.rt.queueDuration.WithLabelValues(c.name, c.name).Observe(queueWait.Seconds()) + c.rt.workDuration.WithLabelValues(c.name, c.name).Observe(duration.Seconds()) + c.rt.reconcileTime.WithLabelValues(c.name).Observe(duration.Seconds()) + c.rt.reconcileTotal.WithLabelValues(c.name, result).Inc() + if result == resultError { + c.rt.reconcileErrors.WithLabelValues(c.name).Inc() + c.rt.queueRetries.WithLabelValues(c.name, c.name).Inc() + } + c.rt.restRequests.WithLabelValues("200", "GET", "10.96.0.1:443").Add(float64(2 + rand.IntN(3))) + c.rt.restRequests.WithLabelValues("200", "PATCH", "10.96.0.1:443").Add(float64(1 + rand.IntN(4))) + if rand.IntN(20) == 0 { + c.rt.restRequests.WithLabelValues("409", "PATCH", "10.96.0.1:443").Inc() + } +} + +func (c *controllerSim) apply(r resource, op concepts.ConvergingOperation) { + c.rec.RecordResourceApply(c.labels(r), op) +} + +func (c *controllerSim) applyError(r resource) { + c.rec.RecordResourceApplyError(c.labels(r)) +} + +func (c *controllerSim) condition(o owner, conditionType, status, reason string, since time.Time) { + c.rec.RecordConditionFor(c.ownerKind, o, conditionType, status, reason, since) +} + +// world holds every scenario and runs them until ctx is done. +type world struct { + webapp, database *controllerSim + rt *runtimeMetrics + leader bool + start time.Time +} + +func newWorld(conditions *ocm.OperatorConditionsGauge, collectors *metrics.Collectors, rt *runtimeMetrics, leader bool) *world { + w := &world{rt: rt, leader: leader, start: time.Now()} + w.webapp = &controllerSim{ + name: "webapp", ownerKind: "WebApp", rt: rt, + rec: metrics.NewRecorder("webapp", conditions, collectors), + } + w.database = &controllerSim{ + name: "database", ownerKind: "Database", rt: rt, + rec: metrics.NewRecorder("database", conditions, collectors), + } + rt.initController("webapp", 4) + rt.initController("database", 2) + return w +} + +// Component and namespace names reused across the scripted world. +const ( + componentServer = "server" + namespaceShop = "shop" +) + +// Condition reasons the simulated owners report. +const ( + reasonHealthy = "Healthy" + reasonFailing = "Failing" + reasonCreating = "Creating" + reasonUnknown = "Unknown" +) + +var ( + webappDeployment = resource{componentServer, "deployment", "Deployment"} + webappService = resource{componentServer, "service", "Service"} + webappConfigMap = resource{componentServer, "configmap", "ConfigMap"} + webappIngress = resource{"ingress", "ingress", "Ingress"} + + dbStatefulSet = resource{"storage", "statefulset", "StatefulSet"} + dbPVC = resource{"storage", "pvc", "PersistentVolumeClaim"} + dbCronJob = resource{"backup", "cronjob", "CronJob"} +) + +// run starts every scenario goroutine and blocks until ctx is done. +func (w *world) run(ctx context.Context) { + w.rt.leader.WithLabelValues("demo-operator").Set(boolToFloat(w.leader)) + + go w.healthyWebApps(ctx) + go w.hotLoop(ctx) + go w.databases(ctx) + go w.workqueueBacklog(ctx) + go w.panics(ctx) + <-ctx.Done() +} + +func boolToFloat(b bool) float64 { + if b { + return 1 + } + return 0 +} + +// healthyWebApps: fifty owners; one random owner reconciles every six to +// eleven seconds, so each of the fifty is reconciled roughly every five to ten +// minutes on average. All resources converged, Ready=True since the simulator +// started. The hot-loop owner (webapp-01) is among them and is also healthy by +// its conditions. +func (w *world) healthyWebApps(ctx context.Context) { + c := w.webapp + owners := make([]owner, 50) + for i := range owners { + owners[i] = owner{namespace: fmt.Sprintf("team-%c", 'a'+rune(i%5)), name: fmt.Sprintf("webapp-%02d", i+1)} + } + tick := func(o owner) { + c.reconcile("success", time.Duration(rand.IntN(50))*time.Millisecond, time.Duration(50+rand.IntN(250))*time.Millisecond) + for _, r := range []resource{webappDeployment, webappService, webappConfigMap, webappIngress} { + c.apply(r, concepts.ConvergingOperationNone) + } + c.condition(o, "ServerReady", "True", reasonHealthy, w.start) + c.condition(o, "IngressReady", "True", reasonHealthy, w.start) + c.condition(o, "Ready", "True", reasonHealthy, w.start) + } + for _, o := range owners { + tick(o) + } + for { + select { + case <-ctx.Done(): + return + case <-time.After(time.Duration(6+rand.IntN(6)) * time.Second): + tick(owners[rand.IntN(len(owners))]) + } + } +} + +// hotLoop: webapp-01's configmap is rewritten on every reconcile, four times a +// second, the way a non-idempotent mutation behaves once the watch event +// requeues the owner. The other resources of that owner converge. +func (w *world) hotLoop(ctx context.Context) { + c := w.webapp + ticker := time.NewTicker(250 * time.Millisecond) + defer ticker.Stop() + for { + select { + case <-ctx.Done(): + return + case <-ticker.C: + c.reconcile("success", 5*time.Millisecond, time.Duration(30+rand.IntN(40))*time.Millisecond) + c.apply(webappConfigMap, concepts.ConvergingOperationUpdated) + c.apply(webappDeployment, concepts.ConvergingOperationNone) + c.apply(webappService, concepts.ConvergingOperationNone) + } + } +} + +// databases: five owners. orders-db has been Ready=False (Failing) for eight +// hours; users-db is Ready=Unknown; reports-db stays Ready=False while its +// reason flips between Failing and Creating; the rest are healthy. PVC applies +// fail three times out of four, thirty percent of reconciles error, and +// reconcile durations are slow enough for the p99 to cross a minute. +func (w *world) databases(ctx context.Context) { + c := w.database + orders := owner{namespaceShop, "orders-db"} + users := owner{namespaceShop, "users-db"} + reports := owner{"analytics", "reports-db"} + healthy := []owner{{namespaceShop, "carts-db"}, {"analytics", "events-db"}} + stuckSince := w.start.Add(-8 * time.Hour) + unknownSince := w.start.Add(-1 * time.Hour) + flipSince := w.start + flipReason := reasonFailing + + i := 0 + tick := func() { + i++ + result := "success" + if rand.IntN(10) < 3 { + result = resultError + } + duration := time.Duration(5+rand.IntN(60)) * time.Second + if rand.IntN(10) < 2 { + duration = time.Duration(70+rand.IntN(50)) * time.Second + } + c.reconcile(result, time.Duration(rand.IntN(400))*time.Millisecond, duration) + c.apply(dbStatefulSet, concepts.ConvergingOperationNone) + c.apply(dbCronJob, concepts.ConvergingOperationNone) + if i%4 == 0 { + c.apply(dbPVC, concepts.ConvergingOperationNone) + } else { + c.applyError(dbPVC) + } + + if i%60 == 0 { // every three minutes + if flipReason == reasonFailing { + flipReason = reasonCreating + } else { + flipReason = reasonFailing + } + flipSince = time.Now() + } + c.condition(orders, "StorageReady", "False", reasonFailing, stuckSince) + c.condition(orders, "BackupReady", "True", reasonHealthy, stuckSince) + c.condition(orders, "Ready", "False", reasonFailing, stuckSince) + c.condition(users, "StorageReady", "Unknown", reasonUnknown, unknownSince) + c.condition(users, "BackupReady", "True", reasonHealthy, unknownSince) + c.condition(users, "Ready", "Unknown", reasonUnknown, unknownSince) + c.condition(reports, "StorageReady", "False", flipReason, flipSince) + c.condition(reports, "BackupReady", "True", reasonHealthy, w.start) + c.condition(reports, "Ready", "False", flipReason, flipSince) + for _, o := range healthy { + c.condition(o, "StorageReady", "True", reasonHealthy, w.start) + c.condition(o, "BackupReady", "True", reasonHealthy, w.start) + c.condition(o, "Ready", "True", reasonHealthy, w.start) + } + } + tick() + ticker := time.NewTicker(3 * time.Second) + defer ticker.Stop() + for { + select { + case <-ctx.Done(): + return + case <-ticker.C: + tick() + } + } +} + +// workqueueBacklog: the database queue is deep, items wait minutes, and both +// of the database controller's workers stay busy chewing through it, while +// webapp's workers idle between zero and two. A reconcile-scoped flip of +// active_workers would almost never be caught by a 5s scrape, so the gauges +// are modelled as persistent levels instead. +func (w *world) workqueueBacklog(ctx context.Context) { + c := w.database + ticker := time.NewTicker(5 * time.Second) + defer ticker.Stop() + for { + select { + case <-ctx.Done(): + return + case <-ticker.C: + depth := 30 + rand.IntN(20) + c.rt.queueDepth.WithLabelValues(c.name, c.name, "0").Set(float64(depth)) + c.rt.queueDuration.WithLabelValues(c.name, c.name).Observe(float64(200 + rand.IntN(400))) + c.rt.queueUnfinished.WithLabelValues(c.name, c.name).Set(float64(60 + rand.IntN(120))) + c.rt.queueLongestRunning.WithLabelValues(c.name, c.name).Set(float64(30 + rand.IntN(90))) + c.rt.queueDepth.WithLabelValues(w.webapp.name, w.webapp.name, "0").Set(float64(rand.IntN(3))) + c.rt.activeWorkers.WithLabelValues(c.name).Set(2) + c.rt.activeWorkers.WithLabelValues(w.webapp.name).Set(float64(rand.IntN(3))) + } + } +} + +// panics: the database controller panics once every 20 minutes, starting +// one minute in, so ControllerReconcilePanics is visible without waiting long. +func (w *world) panics(ctx context.Context) { + select { + case <-ctx.Done(): + return + case <-time.After(time.Minute): + } + ticker := time.NewTicker(20 * time.Minute) + defer ticker.Stop() + for { + w.database.rt.reconcilePanics.WithLabelValues("database").Inc() + w.database.rt.reconcileTotal.WithLabelValues("database", "error").Inc() + select { + case <-ctx.Done(): + return + case <-ticker.C: + } + } +} diff --git a/observability/dev/simulator/world_test.go b/observability/dev/simulator/world_test.go new file mode 100644 index 00000000..fa8a8b20 --- /dev/null +++ b/observability/dev/simulator/world_test.go @@ -0,0 +1,115 @@ +package main + +import ( + "context" + "testing" + "time" + + "github.com/prometheus/client_golang/prometheus" + dto "github.com/prometheus/client_model/go" + ocm "github.com/sourcehawk/go-crd-condition-metrics/pkg/crd-condition-metrics" + "github.com/stretchr/testify/require" + + "github.com/sourcehawk/operator-component-framework/pkg/metrics" +) + +// seriesValue finds the first series of the named family whose labels are a +// superset of want and returns its gauge or counter value. +func seriesValue(mfs []*dto.MetricFamily, name string, want map[string]string) (float64, bool) { + for _, mf := range mfs { + if mf.GetName() != name { + continue + } + for _, m := range mf.GetMetric() { + labels := map[string]string{} + for _, lp := range m.GetLabel() { + labels[lp.GetName()] = lp.GetValue() + } + matched := true + for k, v := range want { + if labels[k] != v { + matched = false + break + } + } + if !matched { + continue + } + switch { + case m.GetGauge() != nil: + return m.GetGauge().GetValue(), true + case m.GetCounter() != nil: + return m.GetCounter().GetValue(), true + } + return 0, true + } + } + return 0, false +} + +// TestWorldScriptedScenarios wires a registry the way main does, runs the +// world and checks that every scenario's series appear with the shapes the +// dev stack's alerts key on: the stuck Ready condition with its eight hour +// old transition, the failing PVC applies, the hot loop's rising updated +// counter, both controllers reconciling and the leader gauge at one. It then +// cancels the context and requires run to return. +func TestWorldScriptedScenarios(t *testing.T) { + reg := prometheus.NewRegistry() + conditions := ocm.NewOperatorConditionsGauge("demo") + collectors := metrics.NewCollectors() + reg.MustRegister(conditions, collectors) + rt := newRuntimeMetrics(reg) + + ctx, cancel := context.WithCancel(context.Background()) + defer cancel() + done := make(chan struct{}) + w := newWorld(conditions, collectors, rt, true) + go func() { + w.run(ctx) + close(done) + }() + + var firstUpdated float64 + require.Eventually(t, func() bool { + mfs, err := reg.Gather() + if err != nil { + return false + } + stuck, ok := seriesValue(mfs, "demo_controller_condition", map[string]string{ + "kind": "Database", "name": "orders-db", "condition": "Ready", "status": "False", "reason": "Failing", + }) + if !ok || time.Since(time.Unix(int64(stuck), 0)) < 7*time.Hour { + return false + } + if _, ok := seriesValue(mfs, "ocf_resource_apply_errors_total", map[string]string{"resource": "pvc"}); !ok { + return false + } + updated, ok := seriesValue(mfs, "ocf_resource_apply_total", map[string]string{ + "resource": "configmap", "operation": "updated", + }) + if !ok || updated == 0 { + return false + } + if firstUpdated == 0 { + firstUpdated = updated + return false // seen once; wait until it has risen + } + if updated <= firstUpdated { + return false + } + for _, controller := range []string{"webapp", "database"} { + if _, ok := seriesValue(mfs, "controller_runtime_reconcile_total", map[string]string{"controller": controller}); !ok { + return false + } + } + leader, ok := seriesValue(mfs, "leader_election_master_status", map[string]string{"name": "demo-operator"}) + return ok && leader == 1 + }, 5*time.Second, 100*time.Millisecond, "the scripted world never produced the expected series") + + cancel() + select { + case <-done: + case <-time.After(2 * time.Second): + require.FailNow(t, "run did not return after the context was cancelled") + } +}