Reduce noisy "object has been modified" logs/events (#3289)

* Reduce noisy "object has been modified" logs/events

* Check controller shutdown before requeuing items

client/injection/apiextensions/reconciler/apiextensions/v1/customresourcedefinition/reconciler.go

@@ -309,6 +309,8 @@ func (r *reconcilerImpl) Reconcile(ctx context.Context, key string) error {
 			// This is a wrapped error, don't emit an event.
 		} else if ok, _ := controller.IsRequeueKey(reconcileEvent); ok {
 			// This is a wrapped error, don't emit an event.
+		} else if errors.IsConflict(reconcileEvent) {
+			// Conflict errors are expected, don't emit an event.
 		} else {
 			logger.Errorw("Returned an error", zap.Error(reconcileEvent))
 			r.Recorder.Event(resource, corev1.EventTypeWarning, "InternalError", reconcileEvent.Error())
@@ -418,8 +420,10 @@ func (r *reconcilerImpl) updateFinalizersFilteredServerSideApply(ctx context.Con
 
 	updated, err := patcher.Patch(ctx, resource.Name, types.ApplyPatchType, patch, patchOpts)
 	if err != nil {
-		r.Recorder.Eventf(resource, corev1.EventTypeWarning, "FinalizerUpdateFailed",
-			"Failed to update finalizers for %q via server-side apply: %v", resource.Name, err)
+		if !errors.IsConflict(err) {
+			r.Recorder.Eventf(resource, corev1.EventTypeWarning, "FinalizerUpdateFailed",
+				"Failed to update finalizers for %q via server-side apply: %v", resource.Name, err)
+		}
 	} else {
 		r.Recorder.Eventf(updated, corev1.EventTypeNormal, "FinalizerUpdate",
 			"Updated finalizers for %q via server-side apply", resource.GetName())
@@ -471,8 +475,10 @@ func (r *reconcilerImpl) updateFinalizersFilteredMergePatch(ctx context.Context,
 	resourceName := resource.Name
 	updated, err := patcher.Patch(ctx, resourceName, types.MergePatchType, patch, metav1.PatchOptions{})
 	if err != nil {
-		r.Recorder.Eventf(existing, corev1.EventTypeWarning, "FinalizerUpdateFailed",
-			"Failed to update finalizers for %q: %v", resourceName, err)
+		if !errors.IsConflict(err) {
+			r.Recorder.Eventf(existing, corev1.EventTypeWarning, "FinalizerUpdateFailed",
+				"Failed to update finalizers for %q: %v", resourceName, err)
+		}
 	} else {
 		r.Recorder.Eventf(updated, corev1.EventTypeNormal, "FinalizerUpdate",
 			"Updated %q finalizers", resource.GetName())

client/injection/apiextensions/reconciler/apiextensions/v1beta1/customresourcedefinition/reconciler.go

@@ -309,6 +309,8 @@ func (r *reconcilerImpl) Reconcile(ctx context.Context, key string) error {
 			// This is a wrapped error, don't emit an event.
 		} else if ok, _ := controller.IsRequeueKey(reconcileEvent); ok {
 			// This is a wrapped error, don't emit an event.
+		} else if errors.IsConflict(reconcileEvent) {
+			// Conflict errors are expected, don't emit an event.
 		} else {
 			logger.Errorw("Returned an error", zap.Error(reconcileEvent))
 			r.Recorder.Event(resource, v1.EventTypeWarning, "InternalError", reconcileEvent.Error())
@@ -418,8 +420,10 @@ func (r *reconcilerImpl) updateFinalizersFilteredServerSideApply(ctx context.Con
 
 	updated, err := patcher.Patch(ctx, resource.Name, types.ApplyPatchType, patch, patchOpts)
 	if err != nil {
-		r.Recorder.Eventf(resource, v1.EventTypeWarning, "FinalizerUpdateFailed",
-			"Failed to update finalizers for %q via server-side apply: %v", resource.Name, err)
+		if !errors.IsConflict(err) {
+			r.Recorder.Eventf(resource, v1.EventTypeWarning, "FinalizerUpdateFailed",
+				"Failed to update finalizers for %q via server-side apply: %v", resource.Name, err)
+		}
 	} else {
 		r.Recorder.Eventf(updated, v1.EventTypeNormal, "FinalizerUpdate",
 			"Updated finalizers for %q via server-side apply", resource.GetName())
@@ -471,8 +475,10 @@ func (r *reconcilerImpl) updateFinalizersFilteredMergePatch(ctx context.Context,
 	resourceName := resource.Name
 	updated, err := patcher.Patch(ctx, resourceName, types.MergePatchType, patch, metav1.PatchOptions{})
 	if err != nil {
-		r.Recorder.Eventf(existing, v1.EventTypeWarning, "FinalizerUpdateFailed",
-			"Failed to update finalizers for %q: %v", resourceName, err)
+		if !errors.IsConflict(err) {
+			r.Recorder.Eventf(existing, v1.EventTypeWarning, "FinalizerUpdateFailed",
+				"Failed to update finalizers for %q: %v", resourceName, err)
+		}
 	} else {
 		r.Recorder.Eventf(updated, v1.EventTypeNormal, "FinalizerUpdate",
 			"Updated %q finalizers", resource.GetName())

codegen/cmd/injection-gen/generators/reconciler/reconciler_reconciler.go

@@ -134,6 +134,10 @@ func (g *reconcilerReconcilerGenerator) GenerateType(c *generator.Context, t *ty
 			Package: "k8s.io/apimachinery/pkg/api/errors",
 			Name:    "IsNotFound",
 		}),
+		"apierrsIsConflict": c.Universe.Function(types.Name{
+			Package: "k8s.io/apimachinery/pkg/api/errors",
+			Name:    "IsConflict",
+		}),
 		"metav1GetOptions": c.Universe.Function(types.Name{
 			Package: "k8s.io/apimachinery/pkg/apis/meta/v1",
 			Name:    "GetOptions",
@@ -573,6 +577,8 @@ func (r *reconcilerImpl) Reconcile(ctx {{.contextContext|raw}}, key string) erro
 			// This is a wrapped error, don't emit an event.
 		} else if ok, _ := {{ .controllerIsRequeueKey|raw }}(reconcileEvent); ok {
 			// This is a wrapped error, don't emit an event.
+		} else if {{ .apierrsIsConflict|raw }}(reconcileEvent) {
+			// Conflict errors are expected, don't emit an event.
 		} else {
 			logger.Errorw("Returned an error", zap.Error(reconcileEvent))
 			r.Recorder.Event(resource, {{.corev1EventTypeWarning|raw}}, "InternalError", reconcileEvent.Error())
@@ -698,8 +704,10 @@ func (r *reconcilerImpl) updateFinalizersFilteredServerSideApply(ctx {{.contextC
 
 	updated, err := patcher.Patch(ctx, resource.Name, {{.typesApplyPatchType|raw}}, patch, patchOpts)
 	if err != nil {
-		r.Recorder.Eventf(resource, {{.corev1EventTypeWarning|raw}}, "FinalizerUpdateFailed",
-			"Failed to update finalizers for %q via server-side apply: %v", resource.Name, err)
+		if !{{ .apierrsIsConflict|raw }}(err) {
+			r.Recorder.Eventf(resource, {{.corev1EventTypeWarning|raw}}, "FinalizerUpdateFailed",
+				"Failed to update finalizers for %q via server-side apply: %v", resource.Name, err)
+		}
 	} else {
 		r.Recorder.Eventf(updated, {{.corev1EventTypeNormal|raw}}, "FinalizerUpdate",
 			"Updated finalizers for %q via server-side apply", resource.GetName())
@@ -754,8 +762,10 @@ func (r *reconcilerImpl) updateFinalizersFilteredMergePatch(ctx {{.contextContex
 	resourceName := resource.Name
 	updated, err := patcher.Patch(ctx, resourceName, {{.typesMergePatchType|raw}}, patch, {{.metav1PatchOptions|raw}}{})
 	if err != nil {
-		r.Recorder.Eventf(existing, {{.corev1EventTypeWarning|raw}}, "FinalizerUpdateFailed",
-			"Failed to update finalizers for %q: %v", resourceName, err)
+		if !{{ .apierrsIsConflict|raw }}(err) {
+			r.Recorder.Eventf(existing, {{.corev1EventTypeWarning|raw}}, "FinalizerUpdateFailed",
+				"Failed to update finalizers for %q: %v", resourceName, err)
+		}
 	} else {
 		r.Recorder.Eventf(updated, {{.corev1EventTypeNormal|raw}}, "FinalizerUpdate",
 			"Updated %q finalizers", resource.GetName())

controller/controller.go

@@ -28,6 +28,7 @@ import (
 
 	"go.uber.org/zap"
 	"go.uber.org/zap/zapcore"
+	apierrors "k8s.io/apimachinery/pkg/api/errors"
 	metav1 "k8s.io/apimachinery/pkg/apis/meta/v1"
 	"k8s.io/apimachinery/pkg/runtime/schema"
 	"k8s.io/apimachinery/pkg/types"
@@ -532,23 +533,31 @@ func (c *Impl) processNextWorkItem() bool {
 }
 
 func (c *Impl) handleErr(logger *zap.SugaredLogger, err error, key types.NamespacedName, startTime time.Time) {
-	if IsSkipKey(err) {
+	// Check if we should skip this key or if the queue is shutting down.
+	// We check shutdown here since controller Run might have exited by now
+	// (since while this item was being processed, queue.Len==0).
+	if IsSkipKey(err) || c.workQueue.ShuttingDown() {
 		c.workQueue.Forget(key)
 		return
 	}
+
 	if ok, delay := IsRequeueKey(err); ok {
 		c.workQueue.AddAfter(key, delay)
 		logger.Debugf("Requeuing key %s (by request) after %v (depth: %d)", safeKey(key), delay, c.workQueue.Len())
 		return
 	}
 
+	// Conflict errors are expected, requeue to retry
+	if apierrors.IsConflict(err) {
+		logger.Debugw("Reconcile conflict", zap.Duration("duration", time.Since(startTime)))
+		c.workQueue.AddRateLimited(key)
+		return
+	}
+
 	logger.Errorw("Reconcile error", zap.Duration("duration", time.Since(startTime)), zap.Error(err))
 
 	// Re-queue the key if it's a transient error.
-	// We want to check that the queue is shutting down here
-	// since controller Run might have exited by now (since while this item was
-	// being processed, queue.Len==0).
-	if !IsPermanentError(err) && !c.workQueue.ShuttingDown() {
+	if !IsPermanentError(err) {
 		c.workQueue.AddRateLimited(key)
 		logger.Debugf("Requeuing key %s due to non-permanent error (depth: %d)", safeKey(key), c.workQueue.Len())
 		return