Empty patch requests seen from helm-based operator even when there're no changes, overloading the kube apiserver

[chlam4]

Bug Report

We have an operator built on the operator-sdk and its helm-operator. We have been seeing empty patch requests going to the Kubernetes apiserver even there are no changes. We have a deployment scenario with hundreds of this operator, which caused heavy traffic onto the apiserver.

What did you do?

Follow the procedure here to deploy the operator in a Kubernetes cluster. We also enabled the apiserver audit logging to the "RequestResponse" level, and observed a set of empty patch requests received by the apiserver upon every reconcile event (which is every minute by default). One such patch request is the following; note that the RequestObject is "{}", an empty map.

{
  "kind": "Event",
  "apiVersion": "audit.k8s.io/v1",
  "level": "RequestResponse",
  "auditID": "d0aacbc8-99c4-404b-80f3-31490d8ebf16",
  "stage": "ResponseComplete",
  "requestURI": "/api/v1/namespaces/turbonomic/services/rsyslog",
  "verb": "patch",
  "user": {
    "username": "system:serviceaccount:turbonomic:t8c-operator",
    "uid": "150ad0c5-6122-4bbf-a5f4-253483a88bed",
    "groups": [
      "system:serviceaccounts",
      "system:serviceaccounts:turbonomic",
      "system:authenticated"
    ]
  },
  "sourceIPs": [
    "10.233.90.91"
  ],
  "userAgent": "Go-http-client/2.0",
  "objectRef": {
    "resource": "services",
    "namespace": "turbonomic",
    "name": "rsyslog",
    "apiVersion": "v1"
  },
  "responseStatus": {
    "metadata": {},
    "code": 200
  },
  "requestObject": {},
  "responseObject": {
    "kind": "Service",
    "apiVersion": "v1",
    "metadata": {
      "name": "rsyslog",
      "namespace": "turbonomic",
      "selfLink": "/api/v1/namespaces/turbonomic/services/rsyslog",
      "uid": "a4283672-a418-40c1-b903-162536b8f79e",
      "resourceVersion": "1908",
      "creationTimestamp": "2021-05-06T23:52:02Z",
      "labels": {
        "app.kubernetes.io/instance": "xl-release",
        "app.kubernetes.io/managed-by": "Helm",
        "app.kubernetes.io/name": "rsyslog",
        "zone": "internal"
      },
      "annotations": {
        "meta.helm.sh/release-name": "xl-release",
        "meta.helm.sh/release-namespace": "turbonomic"
      },
      "ownerReferences": [
        {
          "apiVersion": "charts.helm.k8s.io/v1alpha1",
          "kind": "Xl",
          "name": "xl-release",
          "uid": "e40c32e1-7f31-4296-af19-a56485e568e3",
          "controller": true,
          "blockOwnerDeletion": true
        }
      ],
      "managedFields": [
        {
          "manager": "Go-http-client",
          "operation": "Update",
         "apiVersion": "v1",
          "time": "2021-05-06T23:52:02Z",
          "fieldsType": "FieldsV1",
          "fieldsV1": {
            "f:metadata": {
              "f:annotations": {
                ".": {},
                "f:meta.helm.sh/release-name": {},
                "f:meta.helm.sh/release-namespace": {}
              },
              "f:labels": {
                ".": {},
                "f:app.kubernetes.io/instance": {},
                "f:app.kubernetes.io/managed-by": {},
                "f:app.kubernetes.io/name": {},
                "f:zone": {}
              },
              "f:ownerReferences": {
                ".": {},
                "k:{\"uid\":\"e40c32e1-7f31-4296-af19-a56485e568e3\"}": {
                  ".": {},
                  "f:apiVersion": {},
                  "f:blockOwnerDeletion": {},
                  "f:controller": {},
                  "f:kind": {},
                  "f:name": {},
                  "f:uid": {}
                }
              }
            },
            "f:spec": {
              "f:ports": {
                ".": {},
                "k:{\"port\":2514,\"protocol\":\"TCP\"}": {
                  ".": {},
                  "f:name": {},
                  "f:port": {},
                  "f:protocol": {},
                  "f:targetPort": {}
                },
                "k:{\"port\":8080,\"protocol\":\"TCP\"}": {
                  ".": {},
                  "f:name": {},
                  "f:port": {},
                  "f:protocol": {},
                  "f:targetPort": {}
                }
              },
              "f:selector": {
                ".": {},
                "f:app.kubernetes.io/instance": {},
                "f:app.kubernetes.io/name": {}
              },
              "f:sessionAffinity": {},
              "f:type": {}
            }
          }
        }
      ]
    },
    "spec": {
      "ports": [
        {
          "name": "tcp-rsyslog",
          "protocol": "TCP",
          "port": 2514,
          "targetPort": 2514
        },
        {
          "name": "http-rsyslog",
          "protocol": "TCP",
          "port": 8080,
          "targetPort": 8080
        }
      ],
      "selector": {
        "app.kubernetes.io/instance": "xl-release",
        "app.kubernetes.io/name": "rsyslog"
      },
      "clusterIP": "10.233.60.218",
      "type": "ClusterIP",
      "sessionAffinity": "None"
    },
    "status": {
      "loadBalancer": {}
    }
  },
  "requestReceivedTimestamp": "2021-05-20T16:19:53.081128Z",
  "stageTimestamp": "2021-05-20T16:19:53.087555Z",
  "annotations": {
    "authorization.k8s.io/decision": "allow",
    "authorization.k8s.io/reason": "RBAC: allowed by ClusterRoleBinding \"t8c-operator\" of ClusterRole \"t8c-operator\" to ServiceAccount \"t8c-operator/turbonomic\""
  }
}

What did you expect to see?

We expect to see no patch requests being sent to the kube apiserver when there are no changes in the underlying resources.

What did you see instead? Under which circumstances?

We see empty patch requests being sent to the kube apiserver upon every reconcile event even when there are no changes.

Environment

Operator type: /language helm helm-operator

Kubernetes cluster type: vanilla

$ operator-sdk version
operator-sdk version: "v1.7.1-31-gf855bd6d", commit: "f855bd6d866a7f11ab6d145a5bc7939d4300c9bc", kubernetes version: "v1.20.2", go version: "go1.16.3", GOOS: "darwin", GOARCH: "amd64"

$ go version (if language is Go)
N/A

$ kubectl version
Client Version: version.Info{Major:"1", Minor:"21", GitVersion:"v1.21.0", GitCommit:"cb303e613a121a29364f75cc67d3d580833a7479", GitTreeState:"clean", BuildDate:"2021-04-08T21:15:16Z", GoVersion:"go1.16.3", Compiler:"gc", Platform:"darwin/amd64"}
Server Version: version.Info{Major:"1", Minor:"18", GitVersion:"v1.18.10", GitCommit:"62876fc6d93e891aa7fbe19771e6a6c03773b0f7", GitTreeState:"clean", BuildDate:"2020-10-15T01:43:56Z", GoVersion:"go1.13.15", Compiler:"gc", Platform:"linux/amd64"}

Possible Solution

Thanks to the pointer from Josh Manning and his team at RedHat, we have identified the cause. The 3-way merge call here will return a non-nil byte array "{}" when there is no change.

We've tested and confirmed that the following fix works. That's a change to add a check here for the "{}" scenario:

diff --git a/internal/helm/release/manager.go b/internal/helm/release/manager.go
index 2d494f42..5c314ae2 100644
--- a/internal/helm/release/manager.go
+++ b/internal/helm/release/manager.go
@@ -272,7 +272,9 @@ func reconcileRelease(_ context.Context, kubeClient kube.Interface, expectedMani
                        return fmt.Errorf("error creating patch: %w", err)
                }

-               if patch == nil {
+               // An empty patch could be in the form of "{}" which represents an empty map in a 3-way merge for example;
+               // filter them out here too to avoid sending the apiserver empty patch requests.
+               if len(patch) == 0 || bytes.Equal(patch, []byte("{}")) {
                        // nothing to do
                        return nil
                }

We intend to create a PR for the community to review.

[jberkhahn]

Looks like the PR was merged so I'm closing this.