pkg/resource: output progress logs in applicators

Signed-off-by: Dr. Stefan Schimanski <stefan.schimanski@upbound.io>

pkg/logging/helpers.go

@@ -0,0 +1,43 @@
+/*
+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 logging
+
+import (
+	"fmt"
+
+	"sigs.k8s.io/controller-runtime/pkg/client"
+)
+
+// ForResource returns logging values for a resource.
+func ForResource(object client.Object) []string {
+	ret := make([]string, 0, 10)
+	gvk := object.GetObjectKind().GroupVersionKind()
+	if gvk.Kind == "" {
+		gvk.Kind = fmt.Sprintf("%T", object) // best effort for native Go types
+	}
+	ret = append(ret,
+		"name", object.GetName(),
+		"kind", gvk.Kind,
+		"version", gvk.Version,
+		"group", gvk.Group,
+	)
+	if ns := object.GetNamespace(); ns != "" {
+		ret = append(ret, "namespace", ns)
+	}
+
+	return ret
+}

pkg/resource/api.go

@@ -29,6 +29,7 @@ import (
 	"sigs.k8s.io/controller-runtime/pkg/client"
 
 	"github.com/crossplane/crossplane-runtime/pkg/errors"
+	"github.com/crossplane/crossplane-runtime/pkg/logging"
 	"github.com/crossplane/crossplane-runtime/pkg/meta"
 )
 
@@ -47,26 +48,39 @@ const (
 // patching it in a Kubernetes API server.
 type APIPatchingApplicator struct {
 	client client.Client
+	log    logging.Logger
 }
 
 // NewAPIPatchingApplicator returns an Applicator that applies changes to an
 // object by either creating or patching it in a Kubernetes API server.
 func NewAPIPatchingApplicator(c client.Client) *APIPatchingApplicator {
-	return &APIPatchingApplicator{client: c}
+	return &APIPatchingApplicator{client: c, log: logging.NewNopLogger()}
+}
+
+// WithLogger sets the logger on the APIPatchingApplicator. The logger logs
+// client operations including diffs of objects that are patched. Diffs of
+// secrets are redacted.
+func (a *APIPatchingApplicator) WithLogger(l logging.Logger) *APIPatchingApplicator {
+	a.log = l
+	return a
 }
 
 // Apply changes to the supplied object. The object will be created if it does
 // not exist, or patched if it does. If the object does exist, it will only be
 // patched if the passed object has the same or an empty resource version.
 func (a *APIPatchingApplicator) Apply(ctx context.Context, obj client.Object, ao ...ApplyOption) error { //nolint:gocyclo // the logic here is crucial and deserves to stay in one method
+	log := a.log.WithValues(logging.ForResource(obj))
+
 	if obj.GetName() == "" && obj.GetGenerateName() != "" {
+		log.Info("creating object")
 		return a.client.Create(ctx, obj)
 	}
 
 	current := obj.DeepCopyObject().(client.Object)
 	err := a.client.Get(ctx, types.NamespacedName{Name: obj.GetName(), Namespace: obj.GetNamespace()}, current)
 	if kerrors.IsNotFound(err) {
 		// TODO(negz): Apply ApplyOptions here too?
+		log.Info("creating object")
 		return a.client.Create(ctx, obj)
 	}
 	if err != nil {
@@ -91,7 +105,24 @@ func (a *APIPatchingApplicator) Apply(ctx context.Context, obj client.Object, ao
 		}
 	}
 
-	return a.client.Patch(ctx, obj, client.MergeFromWithOptions(current, client.MergeFromWithOptimisticLock{}))
+	// log diff
+	patch := client.MergeFromWithOptions(current, client.MergeFromWithOptimisticLock{})
+	patchBytes, err := patch.Data(obj)
+	if err != nil {
+		return errors.Wrapf(err, "failed to diff %s", HumanReadableReference(a.client, obj))
+	}
+	if len(patchBytes) == 0 {
+		return nil
+	}
+	secretGVK := schema.GroupVersionKind{Group: "v1", Version: "Secret", Kind: "Secret"}
+	if obj.GetObjectKind().GroupVersionKind() == secretGVK {
+		// TODO(sttts): be more clever and only redact the secret data
+		log.WithValues("diff", "**REDACTED**").Info("patching object")
+	} else {
+		log.WithValues("diff", string(patchBytes)).Info("patching object")
+	}
+
+	return a.client.Patch(ctx, obj, client.RawPatch(patch.Type(), patchBytes))
 }
 
 func groupResource(c client.Client, o client.Object) (schema.GroupResource, error) {
@@ -141,6 +172,7 @@ func AdditiveMergePatchApplyOption(_ context.Context, current, desired runtime.O
 // updating it in a Kubernetes API server.
 type APIUpdatingApplicator struct {
 	client client.Client
+	log    logging.Logger
 }
 
 // NewAPIUpdatingApplicator returns an Applicator that applies changes to an
@@ -149,20 +181,32 @@ type APIUpdatingApplicator struct {
 // Deprecated: Use NewAPIPatchingApplicator instead. The updating applicator
 // can lead to data-loss if the Golang types in this process are not up-to-date.
 func NewAPIUpdatingApplicator(c client.Client) *APIUpdatingApplicator {
-	return &APIUpdatingApplicator{client: c}
+	return &APIUpdatingApplicator{client: c, log: logging.NewNopLogger()}
+}
+
+// WithLogger sets the logger on the APIUpdatingApplicator. The logger logs
+// client operations including diffs of objects that are patched. Diffs of
+// secrets are redacted.
+func (a *APIUpdatingApplicator) WithLogger(l logging.Logger) *APIUpdatingApplicator {
+	a.log = l
+	return a
 }
 
 // Apply changes to the supplied object. The object will be created if it does
 // not exist, or updated if it does.
 func (a *APIUpdatingApplicator) Apply(ctx context.Context, obj client.Object, ao ...ApplyOption) error {
+	log := a.log.WithValues(logging.ForResource(obj))
+
 	if obj.GetName() == "" && obj.GetGenerateName() != "" {
+		log.Info("creating object")
 		return a.client.Create(ctx, obj)
 	}
 
 	current := obj.DeepCopyObject().(client.Object)
 	err := a.client.Get(ctx, types.NamespacedName{Name: obj.GetName(), Namespace: obj.GetNamespace()}, current)
 	if kerrors.IsNotFound(err) {
 		// TODO(negz): Apply ApplyOptions here too?
+		log.Info("creating object")
 		return a.client.Create(ctx, obj)
 	}
 	if err != nil {
@@ -175,6 +219,23 @@ func (a *APIUpdatingApplicator) Apply(ctx context.Context, obj client.Object, ao
 		}
 	}
 
+	// log diff
+	patch := client.MergeFromWithOptions(current, client.MergeFromWithOptimisticLock{})
+	patchBytes, err := patch.Data(obj)
+	if err != nil {
+		return errors.Wrapf(err, "failed to diff %s", HumanReadableReference(a.client, obj))
+	}
+	if len(patchBytes) == 0 {
+		return nil
+	}
+	secretGVK := schema.GroupVersionKind{Group: "v1", Version: "Secret", Kind: "Secret"}
+	if obj.GetObjectKind().GroupVersionKind() == secretGVK {
+		// TODO(sttts): be more clever and only redact the secret data
+		log.WithValues("diff", "**REDACTED**").Info("patching object")
+	} else {
+		log.WithValues("diff", string(patchBytes)).Info("patching object")
+	}
+
 	return a.client.Update(ctx, obj)
 }
 

pkg/resource/providerconfig.go

@@ -29,6 +29,7 @@ import (
 
 	xpv1 "github.com/crossplane/crossplane-runtime/apis/common/v1"
 	"github.com/crossplane/crossplane-runtime/pkg/errors"
+	"github.com/crossplane/crossplane-runtime/pkg/logging"
 	"github.com/crossplane/crossplane-runtime/pkg/meta"
 )
 
@@ -123,13 +124,22 @@ func (fn TrackerFn) Track(ctx context.Context, mg Managed) error {
 // A ProviderConfigUsageTracker tracks usages of a ProviderConfig by creating or
 // updating the appropriate ProviderConfigUsage.
 type ProviderConfigUsageTracker struct {
-	c  Applicator
-	of ProviderConfigUsage
+	c      Applicator
+	of     ProviderConfigUsage
+	log    logging.Logger
+	client client.Client
 }
 
 // NewProviderConfigUsageTracker creates a ProviderConfigUsageTracker.
 func NewProviderConfigUsageTracker(c client.Client, of ProviderConfigUsage) *ProviderConfigUsageTracker {
-	return &ProviderConfigUsageTracker{c: NewAPIUpdatingApplicator(c), of: of}
+	return &ProviderConfigUsageTracker{c: NewAPIUpdatingApplicator(c), of: of, log: logging.NewNopLogger(), client: c}
+}
+
+// WithLogger adds a logger to the ProviderConfigUsageTracker.
+func (u *ProviderConfigUsageTracker) WithLogger(l logging.Logger) *ProviderConfigUsageTracker {
+	u.log = l
+	u.c = NewAPIUpdatingApplicator(u.client).WithLogger(l)
+	return u
 }
 
 // Track that the supplied Managed resource is using the ProviderConfig it

pkg/resource/providerconfig_test.go

@@ -27,6 +27,7 @@ import (
 
 	xpv1 "github.com/crossplane/crossplane-runtime/apis/common/v1"
 	"github.com/crossplane/crossplane-runtime/pkg/errors"
+	"github.com/crossplane/crossplane-runtime/pkg/logging"
 	"github.com/crossplane/crossplane-runtime/pkg/resource/fake"
 	"github.com/crossplane/crossplane-runtime/pkg/test"
 )
@@ -317,7 +318,7 @@ func TestTrack(t *testing.T) {
 
 	for name, tc := range cases {
 		t.Run(name, func(t *testing.T) {
-			ut := &ProviderConfigUsageTracker{c: tc.fields.c, of: tc.fields.of}
+			ut := &ProviderConfigUsageTracker{c: tc.fields.c, of: tc.fields.of, log: logging.NewNopLogger()}
 			got := ut.Track(tc.args.ctx, tc.args.mg)
 			if diff := cmp.Diff(tc.want, got, test.EquateErrors()); diff != "" {
 				t.Errorf("\n%s\nut.Track(...): -want error, +got error:\n%s\n", tc.reason, diff)