Add diff logging

Adds a `recordDiff` enum parameter to the
`ConfigurationPolicy`. When set to `Log`, it uses
the `go-difflib` package to compare the YAML
marshalled into strings. While `go-difflib` is
unmaintained, it's extensively imported, in
particular by the `stretchr/testify` package here.

For simplicity, the diff for objectDefinitions
without a name specified are not logged.

ref: https://issues.redhat.com/browse/ACM-9072
Signed-off-by: Dale Haiducek <19750917+dhaiducek@users.noreply.github.com>

Makefile

@@ -225,10 +225,6 @@ e2e-test: e2e-dependencies
 e2e-test-coverage: E2E_TEST_ARGS = --json-report=report_e2e.json --label-filter='!hosted-mode && !running-in-cluster' --output-dir=.
 e2e-test-coverage: e2e-run-instrumented e2e-test e2e-stop-instrumented
 
-.PHONY: e2e-test-coverage-foreground
-e2e-test-coverage-foreground: LOG_REDIRECT = 
-e2e-test-coverage-foreground: e2e-test-coverage
-
 .PHONY: e2e-test-hosted-mode-coverage
 e2e-test-hosted-mode-coverage: E2E_TEST_ARGS = --json-report=report_e2e_hosted_mode.json --label-filter="hosted-mode && !running-in-cluster" --output-dir=.
 e2e-test-hosted-mode-coverage: COVERAGE_E2E_OUT = coverage_e2e_hosted_mode.out
@@ -244,9 +240,8 @@ e2e-build-instrumented:
 	go test -covermode=atomic -coverpkg=$(shell cat go.mod | head -1 | cut -d ' ' -f 2)/... -c -tags e2e ./ -o build/_output/bin/$(IMG)-instrumented
 
 .PHONY: e2e-run-instrumented
-LOG_REDIRECT ?= &>build/_output/controller.log
 e2e-run-instrumented: e2e-build-instrumented
-	WATCH_NAMESPACE="$(WATCH_NAMESPACE)" ./build/_output/bin/$(IMG)-instrumented -test.run "^TestRunMain$$" -test.coverprofile=$(COVERAGE_E2E_OUT) $(LOG_REDIRECT) &
+	WATCH_NAMESPACE="$(WATCH_NAMESPACE)" ./build/_output/bin/$(IMG)-instrumented -test.run "^TestRunMain$$" -test.coverprofile=$(COVERAGE_E2E_OUT) 2>&1 | tee ./build/_output/controller.log &
 
 .PHONY: e2e-stop-instrumented
 e2e-stop-instrumented:

api/v1/configurationpolicy_types.go

@@ -187,8 +187,20 @@ type ObjectTemplate struct {
 	// ObjectDefinition defines required fields for the object
 	// +kubebuilder:pruning:PreserveUnknownFields
 	ObjectDefinition runtime.RawExtension `json:"objectDefinition"`
+
+	// RecordDiff specifies whether (and where) to log the diff between the object on the
+	// cluster and the objectDefinition in the policy. Defaults to "None".
+	RecordDiff RecordDiff `json:"recordDiff,omitempty"`
 }
 
+// +kubebuilder:validation:Enum=Log;None
+type RecordDiff string
+
+const (
+	RecordDiffLog  RecordDiff = "Log"
+	RecordDiffNone RecordDiff = "None"
+)
+
 // ConfigurationPolicyStatus defines the observed state of ConfigurationPolicy
 type ConfigurationPolicyStatus struct {
 	ComplianceState   ComplianceState  `json:"compliant,omitempty"`         // Compliant/NonCompliant/UnknownCompliancy
@@ -211,9 +223,6 @@ type CompliancePerClusterStatus struct {
 // ComplianceMap map to hold CompliancePerClusterStatus objects
 type ComplianceMap map[string]*CompliancePerClusterStatus
 
-// ResourceState genric description of a state
-type ResourceState string
-
 //+kubebuilder:object:root=true
 //+kubebuilder:subresource:status
 //+kubebuilder:printcolumn:name="Compliance state",type="string",JSONPath=".status.compliant"

controllers/configurationpolicy_controller.go

@@ -1775,11 +1775,8 @@ func (r *ConfigurationPolicyReconciler) handleSingleObj(
 
 			throwSpecViolation = !compliant
 		} else {
-			compType := strings.ToLower(string(objectT.ComplianceType))
-			mdCompType := strings.ToLower(string(objectT.MetadataComplianceType))
-
 			throwSpecViolation, msg, triedUpdate, updatedObj = r.checkAndUpdateResource(
-				obj, compType, mdCompType, remediation,
+				obj, objectT, remediation,
 			)
 		}
 
@@ -2549,10 +2546,12 @@ type cachedEvaluationResult struct {
 // successfully.
 func (r *ConfigurationPolicyReconciler) checkAndUpdateResource(
 	obj singleObject,
-	complianceType string,
-	mdComplianceType string,
+	objectT *policyv1.ObjectTemplate,
 	remediation policyv1.RemediationAction,
 ) (throwSpecViolation bool, message string, updateNeeded bool, updateSucceeded bool) {
+	complianceType := strings.ToLower(string(objectT.ComplianceType))
+	mdComplianceType := strings.ToLower(string(objectT.MetadataComplianceType))
+
 	log := log.WithValues(
 		"policy", obj.policy.Name, "name", obj.name, "namespace", obj.namespace, "resource", obj.gvr.Resource,
 	)
@@ -2633,16 +2632,6 @@ func (r *ConfigurationPolicyReconciler) checkAndUpdateResource(
 		}
 
 		if keyUpdateNeeded {
-			isInform := strings.EqualFold(string(remediation), string(policyv1.Inform))
-
-			// If a key didn't match but the cluster supports dry run mode, then continue merging the object
-			// and then run a dry run update request to see if the Kubernetes API agrees with the assesment.
-			if isInform && !r.DryRunSupported {
-				r.setEvaluatedObject(obj.policy, obj.existingObj, false)
-
-				return true, "", false, false
-			}
-
 			if isStatus {
 				throwSpecViolation = true
 				statusMismatch = true
@@ -2651,16 +2640,18 @@ func (r *ConfigurationPolicyReconciler) checkAndUpdateResource(
 			} else {
 				updateNeeded = true
 
-				if !isInform {
-					log.Info("Queuing an update for the object due to a value mismatch", "key", key)
+				mismatchLog := "Detected value mismatch for object key: " + key
+				// Add a configuration breadcrumb for users that might be looking in the logs for a diff
+				if objectT.RecordDiff != policyv1.RecordDiffLog {
+					mismatchLog += " (Diff disabled. To log the diff, " +
+						"set 'spec.object-tempates[].recordDiff' to 'Log' for this object-template.)"
 				}
+				log.Info(mismatchLog)
 			}
 		}
 	}
 
 	if updateNeeded {
-		log.V(2).Info("Updating the object based on the template definition")
-
 		// FieldValidation is supported in k8s 1.25 as beta release
 		// so if the version is below 1.25, we need to use client side validation to validate the object
 		if semver.Compare(r.serverVersion, "v1.25.0") < 0 {
@@ -2690,13 +2681,13 @@ func (r *ConfigurationPolicyReconciler) checkAndUpdateResource(
 
 				// If it's a conflict, refetch the object and try again.
 				if k8serrors.IsConflict(err) {
-					log.Info("The object updating during the evaluation. Trying again.")
+					log.Info("The object was updating during the evaluation. Trying again.")
 
 					rv, getErr := res.Get(context.TODO(), obj.existingObj.GetName(), metav1.GetOptions{})
 					if getErr == nil {
 						obj.existingObj = rv
 
-						return r.checkAndUpdateResource(obj, complianceType, mdComplianceType, remediation)
+						return r.checkAndUpdateResource(obj, objectT, remediation)
 					}
 				}
 
@@ -2725,14 +2716,38 @@ func (r *ConfigurationPolicyReconciler) checkAndUpdateResource(
 				return false, "", false, false
 			}
 
-			// The object would have been updated, so if it's inform, return as noncompliant.
-			if strings.EqualFold(string(remediation), string(policyv1.Inform)) {
-				r.setEvaluatedObject(obj.policy, obj.existingObj, false)
+			// Generate and log the diff
+			if objectT.RecordDiff == policyv1.RecordDiffLog {
+				diff, err := generateDiff(existingObjectCopy, dryRunUpdatedObj)
+				if err != nil {
+					log.Info("Failed to generate the diff: " + err.Error())
+				} else {
+					log.Info("Logging the diff:\n" + diff)
+				}
+			}
+		} else if objectT.RecordDiff == policyv1.RecordDiffLog {
+			// Generate and log the diff for when dryrun is unsupported (i.e. OCP v3.11)
+			mergedObjCopy := obj.existingObj.DeepCopy()
+			removeFieldsForComparison(mergedObjCopy)
 
-				return true, "", false, false
+			diff, err := generateDiff(existingObjectCopy, mergedObjCopy)
+			if err != nil {
+				log.Info("Failed to generate the diff: " + err.Error())
+			} else {
+				log.Info("Logging the diff:\n" + diff)
 			}
 		}
 
+		// The object would have been updated, so if it's inform, return as noncompliant.
+		if strings.EqualFold(string(remediation), string(policyv1.Inform)) {
+			r.setEvaluatedObject(obj.policy, obj.existingObj, false)
+
+			return true, "", false, false
+		}
+
+		// If it's not inform (i.e. enforce), update the object
+		log.Info("Updating the object based on the template definition")
+
 		updatedObj, err := res.Update(context.TODO(), obj.existingObj, metav1.UpdateOptions{
 			FieldValidation: metav1.FieldValidationStrict,
 		})
@@ -2744,7 +2759,7 @@ func (r *ConfigurationPolicyReconciler) checkAndUpdateResource(
 				if getErr == nil {
 					obj.existingObj = rv
 
-					return r.checkAndUpdateResource(obj, complianceType, mdComplianceType, remediation)
+					return r.checkAndUpdateResource(obj, objectT, remediation)
 				}
 			}
 

controllers/configurationpolicy_utils.go

@@ -11,11 +11,13 @@ import (
 	"strings"
 
 	gocmp "github.com/google/go-cmp/cmp"
+	"github.com/pmezard/go-difflib/difflib"
 	apiRes "k8s.io/apimachinery/pkg/api/resource"
 	metav1 "k8s.io/apimachinery/pkg/apis/meta/v1"
 	"k8s.io/apimachinery/pkg/apis/meta/v1/unstructured"
 	"k8s.io/apimachinery/pkg/runtime/schema"
 	"k8s.io/apimachinery/pkg/util/json"
+	"sigs.k8s.io/yaml"
 
 	policyv1 "open-cluster-management.io/config-policy-controller/api/v1"
 )
@@ -676,3 +678,45 @@ func containRelated(related []policyv1.RelatedObject, input policyv1.RelatedObje
 
 	return false
 }
+
+// generateDiff takes two unstructured objects and returns the diff between the two embedded objects
+func generateDiff(existingObj, updatedObj *unstructured.Unstructured) (string, error) {
+	// Marshal YAML to []byte and parse object names for logging
+	existingYAML, err := yaml.Marshal(existingObj.Object)
+	if err != nil {
+		return "", fmt.Errorf("failed to marshal existing object to YAML for diff: %w", err)
+	}
+
+	existingYAMLName := existingObj.GetName() + " : existing"
+	if existingObj.GetNamespace() != "" {
+		existingYAMLName = existingObj.GetNamespace() + "/" + existingYAMLName
+	}
+
+	updatedYAML, err := yaml.Marshal(updatedObj.Object)
+	if err != nil {
+		return "", fmt.Errorf("failed to marshal updated object to YAML for diff: %w", err)
+	}
+
+	updatedYAMLName := updatedObj.GetName() + " : updated"
+	if updatedObj.GetNamespace() != "" {
+		updatedYAMLName = updatedObj.GetNamespace() + "/" + updatedYAMLName
+	}
+
+	// Set the diffing configuration
+	// See https://pkg.go.dev/github.com/pmezard/go-difflib/difflib#UnifiedDiff
+	unifiedDiff := difflib.UnifiedDiff{
+		A:        difflib.SplitLines(string(existingYAML)),
+		FromFile: existingYAMLName,
+		B:        difflib.SplitLines(string(updatedYAML)),
+		ToFile:   updatedYAMLName,
+		Context:  1,
+	}
+
+	// Generate and return the diff
+	diff, err := difflib.GetUnifiedDiffString(unifiedDiff)
+	if err != nil {
+		return "", fmt.Errorf("failed to generate diff: %w", err)
+	}
+
+	return diff, nil
+}

controllers/configurationpolicy_utils_test.go

@@ -6,6 +6,7 @@ import (
 	"testing"
 
 	"github.com/stretchr/testify/assert"
+	"k8s.io/apimachinery/pkg/apis/meta/v1/unstructured"
 
 	policyv1 "open-cluster-management.io/config-policy-controller/api/v1"
 )
@@ -197,3 +198,112 @@ func TestEqualObjWithSortEmptyMap(t *testing.T) {
 	assert.True(t, equalObjWithSort(mergedObj, oldObj, true))
 	assert.False(t, equalObjWithSort(mergedObj, oldObj, false))
 }
+
+func TestGenerateDiff(t *testing.T) {
+	t.Parallel()
+
+	tests := map[string]struct {
+		existingObj  map[string]interface{}
+		updatedObj   map[string]interface{}
+		expectedDiff string
+	}{
+		"same object generates no diff": {
+			existingObj: map[string]interface{}{
+				"cities": map[string]interface{}{},
+			},
+			updatedObj: map[string]interface{}{
+				"cities": map[string]interface{}{},
+			},
+		},
+		"object with new child key": {
+			existingObj: map[string]interface{}{
+				"cities": map[string]interface{}{},
+			},
+			updatedObj: map[string]interface{}{
+				"cities": map[string]interface{}{
+					"raleigh": map[string]interface{}{},
+				},
+			},
+			expectedDiff: `
+@@ -1,2 +1,3 @@
+-cities: {}
++cities:
++  raleigh: {}`,
+		},
+		"object with new key": {
+			existingObj: map[string]interface{}{
+				"cities": map[string]interface{}{},
+			},
+			updatedObj: map[string]interface{}{
+				"cities": map[string]interface{}{},
+				"states": map[string]interface{}{},
+			},
+			expectedDiff: `
+@@ -1,2 +1,3 @@
+ cities: {}
++states: {}`,
+		},
+		"array with added item": {
+			existingObj: map[string]interface{}{
+				"cities": []string{
+					"Raleigh",
+				},
+			},
+			updatedObj: map[string]interface{}{
+				"cities": []string{
+					"Raleigh",
+					"Durham",
+				},
+			},
+			expectedDiff: `
+@@ -2,2 +2,3 @@
+ - Raleigh
++- Durham`,
+		},
+		"array with removed item": {
+			existingObj: map[string]interface{}{
+				"cities": []string{
+					"Raleigh",
+					"Durham",
+				},
+			},
+			updatedObj: map[string]interface{}{
+				"cities": []string{
+					"Raleigh",
+				},
+			},
+			expectedDiff: `
+@@ -2,3 +2,2 @@
+ - Raleigh
+-- Durham`,
+		},
+	}
+
+	for testName, test := range tests {
+		test := test
+
+		t.Run(testName, func(t *testing.T) {
+			t.Parallel()
+
+			existingObj := &unstructured.Unstructured{
+				Object: test.existingObj,
+			}
+			updatedObj := &unstructured.Unstructured{
+				Object: test.updatedObj,
+			}
+
+			diff, err := generateDiff(existingObj, updatedObj)
+			if err != nil {
+				t.Fatal(fmt.Errorf("Encountered unexpected error: %w", err))
+			}
+
+			// go-diff adds a trailing newline and whitespace, which gets
+			// chomped when logging, so adding it here just for the test,
+			// along with the common prefix
+			if test.expectedDiff != "" {
+				test.expectedDiff = "---  : existing\n+++  : updated" + test.expectedDiff + "\n \n"
+			}
+			assert.Equal(t, test.expectedDiff, diff)
+		})
+	}
+}

deploy/crds/kustomize_configurationpolicy/policy.open-cluster-management.io_configurationpolicies.yaml

@@ -161,6 +161,14 @@ spec:
                         object
                       type: object
                       x-kubernetes-preserve-unknown-fields: true
+                    recordDiff:
+                      description: RecordDiff specifies whether (and where) to log
+                        the diff between the object on the cluster and the objectDefinition
+                        in the policy. Defaults to "None".
+                      enum:
+                      - Log
+                      - None
+                      type: string
                   required:
                   - complianceType
                   - objectDefinition

deploy/crds/policy.open-cluster-management.io_configurationpolicies.yaml

@@ -168,6 +168,14 @@ spec:
                         object
                       type: object
                       x-kubernetes-preserve-unknown-fields: true
+                    recordDiff:
+                      description: RecordDiff specifies whether (and where) to log
+                        the diff between the object on the cluster and the objectDefinition
+                        in the policy. Defaults to "None".
+                      enum:
+                      - Log
+                      - None
+                      type: string
                   required:
                   - complianceType
                   - objectDefinition