reconciler/managed: add crossplane_resource_drift_seconds metric

Author: sttts

go.mod

@@ -8,6 +8,7 @@ require (
 	github.com/go-logr/logr v1.2.4
 	github.com/google/go-cmp v0.5.9
 	github.com/hashicorp/vault/api v1.9.2
+	github.com/prometheus/client_golang v1.15.1
 	github.com/spf13/afero v1.9.5
 	golang.org/x/time v0.3.0
 	google.golang.org/grpc v1.57.0
@@ -93,7 +94,6 @@ require (
 	github.com/pkg/browser v0.0.0-20210911075715-681adbf594b8 // indirect
 	github.com/pkg/errors v0.9.1 // indirect
 	github.com/pkg/profile v1.7.0 // indirect
-	github.com/prometheus/client_golang v1.15.1 // indirect
 	github.com/prometheus/client_model v0.4.0 // indirect
 	github.com/prometheus/common v0.44.0 // indirect
 	github.com/prometheus/procfs v0.10.0 // indirect

pkg/reconciler/managed/metrics.go

@@ -0,0 +1,97 @@
+/*
+Copyright 2023 The Crossplane 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 managed
+
+import (
+	"context"
+	"sync"
+	"time"
+
+	"github.com/prometheus/client_golang/prometheus"
+	"k8s.io/apimachinery/pkg/runtime/schema"
+	"k8s.io/client-go/tools/cache"
+	"sigs.k8s.io/controller-runtime/pkg/cluster"
+	"sigs.k8s.io/controller-runtime/pkg/manager"
+	"sigs.k8s.io/controller-runtime/pkg/metrics"
+
+	"github.com/crossplane/crossplane-runtime/pkg/resource"
+)
+
+func init() {
+	metrics.Registry.MustRegister(drift)
+}
+
+var subSystem = "crossplane"
+
+var (
+	drift = prometheus.NewHistogramVec(prometheus.HistogramOpts{
+		Subsystem: subSystem,
+		Name:      "resource_resource_drift_seconds",
+		Help:      "How long since the previous reconcile when a resource was found to be out of sync; excludes restart of the provider",
+		Buckets:   prometheus.ExponentialBuckets(10e-9, 10, 10),
+	}, []string{"group", "kind", "retries"})
+)
+
+// driftRecorder records the time since the last observation of a resource
+// and records the time since on update as a metric. This represents an upper
+// bound for the duration the drift existed.
+type driftRecorder struct {
+	lastObservation sync.Map
+	gvk             schema.GroupVersionKind
+
+	cluster cluster.Cluster
+}
+
+var _ manager.Runnable = &driftRecorder{}
+
+func (r *driftRecorder) Start(ctx context.Context) error {
+	inf, err := r.cluster.GetCache().GetInformerForKind(ctx, r.gvk)
+	if err != nil {
+		return err
+	}
+
+	registered, err := inf.AddEventHandler(cache.ResourceEventHandlerFuncs{
+		DeleteFunc: func(obj interface{}) {
+			if final, ok := obj.(cache.DeletedFinalStateUnknown); ok {
+				obj = final.Obj
+			}
+			managed := obj.(resource.Managed)
+			r.lastObservation.Delete(managed.GetName())
+		},
+	})
+	if err != nil {
+		return err
+	}
+	defer inf.RemoveEventHandler(registered) //nolint:errcheck // this happens on destruction. We cannot do anything anyway.
+
+	<-ctx.Done()
+
+	return nil
+}
+
+func (r *driftRecorder) recordUnchanged(name string) {
+	r.lastObservation.Store(name, time.Now())
+}
+
+func (r *driftRecorder) recordUpdate(name string) {
+	last, ok := r.lastObservation.Load(name)
+	if !ok {
+		return
+	}
+
+	drift.WithLabelValues(r.gvk.Group, r.gvk.Kind).Observe(time.Since(last.(time.Time)).Seconds())
+}

pkg/reconciler/managed/reconciler.go

@@ -482,6 +482,8 @@ type Reconciler struct {
 
 	features feature.Flags
 
+	driftRecorder driftRecorder
+
 	// The below structs embed the set of interfaces used to implement the
 	// managed resource reconciler. We do this primarily for readability, so
 	// that the reconciler logic reads r.external.Connect(),
@@ -671,6 +673,7 @@ func NewReconciler(m manager.Manager, of resource.ManagedKind, o ...ReconcilerOp
 		creationGracePeriod:         defaultGracePeriod,
 		timeout:                     reconcileTimeout,
 		managed:                     defaultMRManaged(m),
+		driftRecorder:               driftRecorder{cluster: m},
 		external:                    defaultMRExternal(),
 		supportedManagementPolicies: defaultSupportedManagementPolicies(),
 		log:                         logging.NewNopLogger(),
@@ -681,6 +684,11 @@ func NewReconciler(m manager.Manager, of resource.ManagedKind, o ...ReconcilerOp
 		ro(r)
 	}
 
+	if err := m.Add(&r.driftRecorder); err != nil {
+		r.log.Info("unable to register drift recorder with controller manager", "error", err)
+		// no way to recover from this
+	}
+
 	return r
 }
 
@@ -1079,6 +1087,13 @@ func (r *Reconciler) Reconcile(ctx context.Context, req reconcile.Request) (reco
 		// https://github.com/crossplane/crossplane/issues/289
 		log.Debug("External resource is up to date", "requeue-after", time.Now().Add(r.pollInterval))
 		managed.SetConditions(xpv1.ReconcileSuccess())
+
+		// record that we intentionally did not update the managed resource
+		// because no drift was detected. We call this so late in the reconcile
+		// because all the cases above could contribute (for different reasons)
+		// that the external object would not have been updated.
+		r.driftRecorder.recordUnchanged(managed.GetName())
+
 		return reconcile.Result{RequeueAfter: r.pollInterval}, errors.Wrap(r.client.Status().Update(ctx, managed), errUpdateManagedStatus)
 	}
 
@@ -1106,6 +1121,9 @@ func (r *Reconciler) Reconcile(ctx context.Context, req reconcile.Request) (reco
 		return reconcile.Result{Requeue: true}, errors.Wrap(r.client.Status().Update(ctx, managed), errUpdateManagedStatus)
 	}
 
+	// record the drift after the successful update.
+	r.driftRecorder.recordUpdate(managed.GetName())
+
 	if _, err := r.managed.PublishConnection(ctx, managed, update.ConnectionDetails); err != nil {
 		// If this is the first time we encounter this issue we'll be requeued
 		// implicitly when we update our status with the new error condition. If

pkg/resource/fake/mocks.go

@@ -480,6 +480,11 @@ func (m *Manager) GetRESTMapper() meta.RESTMapper { return m.RESTMapper }
 // GetLogger returns the logger.
 func (m *Manager) GetLogger() logr.Logger { return m.Logger }
 
+// Add adds a runnable to the manager.
+func (m *Manager) Add(_ manager.Runnable) error {
+	return nil // do nothing
+}
+
 // GV returns a mock schema.GroupVersion.
 var GV = schema.GroupVersion{Group: "g", Version: "v"}