diff --git a/pkg/controller/operators/catalog/operator.go b/pkg/controller/operators/catalog/operator.go index f57969e8fc..2ab881fab7 100644 --- a/pkg/controller/operators/catalog/operator.go +++ b/pkg/controller/operators/catalog/operator.go @@ -132,6 +132,9 @@ func NewOperator(ctx context.Context, kubeconfigPath string, clock utilclock.Clo // Create an OperatorLister lister := operatorlister.NewLister() + operatorV1alpha1Resolver := resolver.NewOperatorsV1alpha1Resolver(lister, crClient, opClient.KubernetesInterface()) + successMetricsEmitter := metrics.RegisterDependencyResolutionSuccess + failureMetricsEmitter := metrics.RegisterDependencyResolutionFailure // Allocate the new instance of an Operator. op := &Operator{ Operator: queueOperator, @@ -142,7 +145,7 @@ func NewOperator(ctx context.Context, kubeconfigPath string, clock utilclock.Clo client: crClient, lister: lister, namespace: operatorNamespace, - resolver: resolver.NewOperatorsV1alpha1Resolver(lister, crClient, opClient.KubernetesInterface()), + resolver: resolver.NewInstrumentedResolver(operatorV1alpha1Resolver, successMetricsEmitter, failureMetricsEmitter), catsrcQueueSet: queueinformer.NewEmptyResourceQueueSet(), subQueueSet: queueinformer.NewEmptyResourceQueueSet(), ipQueueSet: queueinformer.NewEmptyResourceQueueSet(), diff --git a/pkg/controller/registry/resolver/instrumented_resolver.go b/pkg/controller/registry/resolver/instrumented_resolver.go new file mode 100644 index 0000000000..a5e84b2d08 --- /dev/null +++ b/pkg/controller/registry/resolver/instrumented_resolver.go @@ -0,0 +1,34 @@ +package resolver + +import ( + "time" + + "github.com/operator-framework/api/pkg/operators/v1alpha1" +) + +type InstrumentedResolver struct { + operatorsV1alpha1Resolver Resolver + successMetricsEmitter func(time.Duration) + failureMetricsEmitter func(time.Duration) +} + +var _ Resolver = &OperatorsV1alpha1Resolver{} + +func NewInstrumentedResolver(resolver Resolver, successMetricsEmitter, failureMetricsEmitter func(time.Duration)) *InstrumentedResolver { + return &InstrumentedResolver{ + operatorsV1alpha1Resolver: resolver, + successMetricsEmitter: successMetricsEmitter, + failureMetricsEmitter: failureMetricsEmitter, + } +} + +func (ir *InstrumentedResolver) ResolveSteps(namespace string, sourceQuerier SourceQuerier) ([]*v1alpha1.Step, []v1alpha1.BundleLookup, []*v1alpha1.Subscription, error) { + start := time.Now() + steps, lookups, subs, err := ir.operatorsV1alpha1Resolver.ResolveSteps(namespace, sourceQuerier) + if err != nil { + ir.failureMetricsEmitter(time.Now().Sub(start)) + } else { + ir.successMetricsEmitter(time.Now().Sub(start)) + } + return steps, lookups, subs, err +} diff --git a/pkg/controller/registry/resolver/instrumented_resolver_test.go b/pkg/controller/registry/resolver/instrumented_resolver_test.go new file mode 100644 index 0000000000..3fd8946900 --- /dev/null +++ b/pkg/controller/registry/resolver/instrumented_resolver_test.go @@ -0,0 +1,69 @@ +package resolver + +import ( + "errors" + "testing" + "time" + + "github.com/operator-framework/api/pkg/operators/v1alpha1" + "github.com/stretchr/testify/require" +) + +const ( + failure = time.Duration(0) + success = time.Duration(1) + reset = time.Duration(99999) +) + +type fakeResolverWithError struct{} +type fakeResolverWithoutError struct{} + +func (r *fakeResolverWithError) ResolveSteps(namespace string, sourceQuerier SourceQuerier) ([]*v1alpha1.Step, []v1alpha1.BundleLookup, []*v1alpha1.Subscription, error) { + return nil, nil, nil, errors.New("Fake error") +} + +func (r *fakeResolverWithoutError) ResolveSteps(namespace string, sourceQuerier SourceQuerier) ([]*v1alpha1.Step, []v1alpha1.BundleLookup, []*v1alpha1.Subscription, error) { + return nil, nil, nil, nil +} + +func newFakeResolverWithError() *fakeResolverWithError { + return &fakeResolverWithError{} +} + +func newFakeResolverWithoutError() *fakeResolverWithoutError { + return &fakeResolverWithoutError{} +} + +func TestInstrumentedResolverFailure(t *testing.T) { + result := []time.Duration{} + + changeToFailure := func(num time.Duration) { + result = append(result, failure) + } + + changeToSuccess := func(num time.Duration) { + result = append(result, success) + } + + instrumentedResolver := NewInstrumentedResolver(newFakeResolverWithError(), changeToSuccess, changeToFailure) + instrumentedResolver.ResolveSteps("", nil) + require.Equal(t, len(result), 1) // check that only one call was made to a change function + require.Equal(t, result[0], failure) // check that the call was made to changeToFailure function +} + +func TestInstrumentedResolverSuccess(t *testing.T) { + result := []time.Duration{} + + changeToFailure := func(num time.Duration) { + result = append(result, failure) + } + + changeToSuccess := func(num time.Duration) { + result = append(result, success) + } + + instrumentedResolver := NewInstrumentedResolver(newFakeResolverWithoutError(), changeToSuccess, changeToFailure) + instrumentedResolver.ResolveSteps("", nil) + require.Equal(t, len(result), 1) // check that only one call was made to a change function + require.Equal(t, result[0], success) // check that the call was made to changeToSuccess function +} diff --git a/pkg/metrics/metrics.go b/pkg/metrics/metrics.go index 500f517ad0..af2baa35c3 100644 --- a/pkg/metrics/metrics.go +++ b/pkg/metrics/metrics.go @@ -1,6 +1,8 @@ package metrics import ( + "time" + "github.com/prometheus/client_golang/prometheus" metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" "k8s.io/apimachinery/pkg/labels" @@ -18,6 +20,9 @@ const ( PHASE_LABEL = "phase" REASON_LABEL = "reason" PACKAGE_LABEL = "package" + Outcome = "outcome" + Succeeded = "succeeded" + Failed = "failed" ) type MetricsProvider interface { @@ -59,7 +64,7 @@ func (m *metricsInstallPlan) HandleMetrics() error { } type metricsSubscription struct { - lister v1alpha1.SubscriptionLister + lister v1alpha1.SubscriptionLister } func NewMetricsSubscription(lister v1alpha1.SubscriptionLister) MetricsProvider { @@ -167,6 +172,15 @@ var ( []string{NAMESPACE_LABEL, NAME_LABEL, VERSION_LABEL, PHASE_LABEL, REASON_LABEL}, ) + dependencyResolutionSummary = prometheus.NewSummaryVec( + prometheus.SummaryOpts{ + Name: "olm_resolution_duration_seconds", + Help: "The duration of a dependency resolution attempt", + Objectives: map[float64]float64{0.95: 0.05, 0.9: 0.01, 0.99: 0.001}, + }, + []string{Outcome}, + ) + // subscriptionSyncCounters keeps a record of the promethues counters emitted by // Subscription objects. The key of a record is the Subscription name, while the value // is struct containing label values used in the counter @@ -191,6 +205,7 @@ func RegisterCatalog() { prometheus.MustRegister(subscriptionCount) prometheus.MustRegister(catalogSourceCount) prometheus.MustRegister(SubscriptionSyncCount) + prometheus.MustRegister(dependencyResolutionSummary) } func CounterForSubscription(name, installedCSV, channelName, packageName string) prometheus.Counter { @@ -268,3 +283,11 @@ func UpdateSubsSyncCounterStorage(sub *olmv1alpha1.Subscription) { subscriptionSyncCounters[sub.GetName()] = counterValues } } + +func RegisterDependencyResolutionSuccess(duration time.Duration) { + dependencyResolutionSummary.WithLabelValues(Succeeded).Observe(duration.Seconds()) +} + +func RegisterDependencyResolutionFailure(duration time.Duration) { + dependencyResolutionSummary.WithLabelValues(Failed).Observe(duration.Seconds()) +} diff --git a/test/e2e/like_metric_matcher_test.go b/test/e2e/like_metric_matcher_test.go index 3365de4ea7..19e4bb9051 100644 --- a/test/e2e/like_metric_matcher_test.go +++ b/test/e2e/like_metric_matcher_test.go @@ -80,6 +80,15 @@ func WithValue(v float64) MetricPredicate { } } +func WithValueGreaterThan(v float64) MetricPredicate { + return MetricPredicate{ + name: fmt.Sprintf("WithValueGreaterThan(%g)", v), + f: func(m Metric) bool { + return m.Value > v + }, + } +} + type LikeMetricMatcher struct { Predicates []MetricPredicate } diff --git a/test/e2e/metrics_e2e_test.go b/test/e2e/metrics_e2e_test.go index ccc9181561..c710221e10 100644 --- a/test/e2e/metrics_e2e_test.go +++ b/test/e2e/metrics_e2e_test.go @@ -109,7 +109,7 @@ var _ = Describe("Metrics are generated for OLM managed resources", func() { }) }) - Context("Subscription Metric", func() { + Context("Metrics emitted by objects during operator installation", func() { var ( subscriptionCleanup cleanupFunc subscription *v1alpha1.Subscription @@ -138,6 +138,20 @@ var _ = Describe("Metrics are generated for OLM managed resources", func() { WithPackage(testPackageName), ))) }) + + It("generates dependency_resolution metric", func() { + + // Verify metrics have been emitted for dependency resolution + Eventually(func() bool { + return Eventually(func() []Metric { + return getMetricsFromPod(c, getPodWithLabel(c, "app=catalog-operator"), "8081") + }).Should(ContainElement(LikeMetric( + WithFamily("olm_resolution_duration_seconds"), + WithLabel("outcome", "failed"), + WithValueGreaterThan(0), + ))) + }) + }) }) When("A subscription object is updated after emitting metrics", func() {