Experiencing degraded performance and increased load on kubernetes api server for Crossplane 1.14+ about crossplane

[aridelsante]

@turkenh 💡 thanks, I can see this happening. Like mentioned above, we had previously moved to DeploymentRuntimeConfigs still using the shared service account (with a shared runtime config) and we still faced the issue then. It turns out the issue was relying on a crossplane managed service account.

This was the DeploymentRuntimeConfig causing issues:

apiVersion: pkg.crossplane.io/v1beta1
kind: DeploymentRuntimeConfig
metadata:
  creationTimestamp: "2024-03-15T09:54:26Z"
  generation: 2
  name: aws-runtime-config
spec:
  deploymentTemplate:
    spec:
      selector: {}
      template:
        spec:
          containers:
          - name: package-runtime
            resources:
              limits:
                memory: 700Mi
              requests:
                cpu: 450m
                memory: 700Mi
  serviceAccountTemplate:
    metadata:
      annotations:
        eks.amazonaws.com/role-arn: arn:aws:iam::xxx:role/example
      name: crossplane-generic-provider

Managing the SA externally (removing the serviceAccountTemplate), and passing the serviceAccountName to DeploymentRuntimeConfig instead fixed it.

Thank you all very much for the help here 🙇‍♀️

[turkenh]

Ok, I think I found the problem 🕵️

You're using a shared service account between providers, crossplane-generic-provider, and indeed hitting #4552 which we fixed with DeploymentRuntimeConfigs.

The gist of the problem is both providers trying to exclusively own the shared service account and adding their ownerRefs while removing the other and constantly fighting. Changes in the SA triggers reconciliation on both revisions...

So, the solution is to switch DeploymentRuntimeConfigs, #4908 is also related, and I believe you can use the example there.

[jbw976]

This issue seems related to #5074 (comment), as @turkenh was investigating an increased number of update calls on CRDs there too

[negz]

PUT request being repetitively done

Sounds like a possible package manager bug. Can you try:

• kubectl describe pkg
• kubectl describe pkgrev

See if there are any suspicious events or status conditions relating to provider packages.

[jbw976]

Also curious if you are seeing this on v1.15.0 @aridelsante?

[aridelsante]

On 1.14.6 nothing seems to standout:

• kubectl describe pkg most have no events at all, there are some warning on package unhealthy (we had some of those before too - perhaps not at this rate):

[...]
Status:
  Conditions:
    Last Transition Time:  2024-03-08T11:25:45Z
    Reason:                HealthyPackageRevision
    Status:                True
    Type:                  Healthy
    Last Transition Time:  2023-10-19T12:36:35Z
    Reason:                ActivePackageRevision
    Status:                True
    Type:                  Installed
  Current Identifier:      xpkg.upbound.io/upbound/provider-aws-sqs:v1.1.0
  Current Revision:        provider-aws-sqs-7adc75b751a1
Events:
  Type     Reason                  Age                 From                                 Message
  ----     ------                  ----                ----                                 -------
  Warning  InstallPackageRevision  22m (x14 over 89m)  packages/provider.pkg.crossplane.io  current package revision is unhealthy
  Normal   InstallPackageRevision  21m (x7 over 89m)   packages/provider.pkg.crossplane.io  Successfully installed package revision

• kubectl describe pkgrev here too, for most there are no events, there are some pkgrev with warnings:

Events:
  Type     Reason       Age                 From                                         Message
  ----     ------       ----                ----                                         -------
  Warning  SyncPackage  21m (x77 over 69m)  packages/providerrevision.pkg.crossplane.io  post establish runtime hook failed for package: provider package deployment is unavailable with message: Deployment does not have minimum availability.

Overall, for all the providers, we get the same rate of requests, eg. for provider-aws-ecr (with no package health warnings) we get:

Mar 8 13:06:28 crossplane-6f49c7dc8c-4wp2k crossplane info I0308 12:06:28.599085       1 request.go:697] Waited for 1.015821016s due to client-side throttling, not priority and fairness, request: PUT:https://172.20.0.1:443/apis/apiextensions.k8s.io/v1/customresourcedefinitions/registrypolicies.ecr.aws.upbound.io
Mar 8 13:08:06 crossplane-6f49c7dc8c-4wp2k crossplane info I0308 12:08:06.978596       1 request.go:697] Waited for 1.010203178s due to client-side throttling, not priority and fairness, request: PUT:https://172.20.0.1:443/apis/apiextensions.k8s.io/v1/customresourcedefinitions/repositories.ecr.aws.upbound.io
Mar 8 13:08:27 crossplane-6f49c7dc8c-4wp2k crossplane info I0308 12:08:27.599223       1 request.go:697] Waited for 1.007273815s due to client-side throttling, not priority and fairness, request: PUT:https://172.20.0.1:443/apis/apiextensions.k8s.io/v1/customresourcedefinitions/replicationconfigurations.ecr.aws.upbound.io?dryRun=All
Mar 8 13:13:13 crossplane-67c7d8955c-lr6w6 crossplane info I0308 12:13:13.366268       1 request.go:697] Waited for 1.077255732s due to client-side throttling, not priority and fairness, request: PUT:https://172.20.0.1:443/apis/apiextensions.k8s.io/v1/customresourcedefinitions/pullthroughcacherules.ecr.aws.upbound.io
Mar 8 13:13:23 crossplane-67c7d8955c-lr6w6 crossplane info I0308 12:13:23.366791       1 request.go:697] Waited for 1.121441414s due to client-side throttling, not priority and fairness, request: PUT:https://172.20.0.1:443/apis/apiextensions.k8s.io/v1/customresourcedefinitions/repositorypolicies.ecr.aws.upbound.io

[aridelsante]

Also curious if you are seeing this on v1.15.0 @aridelsante?

@jbw976 Yes we are seeing this also for v1.15.0

[negz]

@aridelsante Can you kubectl get crds and let me know how many CRDs are installed?

v1.13.0...v1.14.6#diff-06600f72058989fdb963f9d269e653185da0bf86b3aa1f0a494a7c4a8f0b5c81

It certainly sounds like Crossplane is applying provider CRDs more often than I would expect. I can't link directly to the file diff, but if you look for pkg/revision/establisher.go in the above diff that shows what changed between v1.13 and v1.14. I can't immediately see a culprit.

[aridelsante]

@negz specifically from upbound providers we have 90 CRDs in total. Here is the rate of throttled requests logs for 2 different CRDs:

[..]
Mar 8 11:23:29 crossplane-6f49c7dc8c-4wp2k crossplane info I0308 10:23:29.438595       1 request.go:697] Waited for 1.002053863s due to client-side throttling, not priority and fairness, request: PUT:https://172.20.0.1:443/apis/apiextensions.k8s.io/v1/customresourcedefinitions/originaccesscontrols.cloudfront.aws.upbound.io?dryRun=All
Mar 8 11:25:06 crossplane-6f49c7dc8c-4wp2k crossplane info I0308 10:25:06.139043       1 request.go:697] Waited for 1.011662846s due to client-side throttling, not priority and fairness, request: PUT:https://172.20.0.1:443/apis/apiextensions.k8s.io/v1/customresourcedefinitions/originaccesscontrols.cloudfront.aws.upbound.io
Mar 8 11:31:03 crossplane-6f49c7dc8c-4wp2k crossplane info I0308 10:31:03.137828       1 request.go:697] Waited for 1.085041763s due to client-side throttling, not priority and fairness, request: PUT:https://172.20.0.1:443/apis/apiextensions.k8s.io/v1/customresourcedefinitions/originaccesscontrols.cloudfront.aws.upbound.io?dryRun=All
Mar 8 11:38:23 crossplane-6f49c7dc8c-4wp2k crossplane info I0308 10:38:23.838453       1 request.go:697] Waited for 1.017588757s due to client-side throttling, not priority and fairness, request: PUT:https://172.20.0.1:443/apis/apiextensions.k8s.io/v1/customresourcedefinitions/originaccesscontrols.cloudfront.aws.upbound.io
Mar 8 11:54:19 crossplane-6f49c7dc8c-4wp2k crossplane info I0308 10:54:19.798342       1 request.go:697] Waited for 1.004610063s due to client-side throttling, not priority and fairness, request: PUT:https://172.20.0.1:443/apis/apiextensions.k8s.io/v1/customresourcedefinitions/originaccesscontrols.cloudfront.aws.upbound.io?dryRun=All
Mar 8 11:59:57 crossplane-6f49c7dc8c-4wp2k crossplane info I0308 10:59:57.678652       1 request.go:697] Waited for 1.0149307s due to client-side throttling, not priority and fairness, request: PUT:https://172.20.0.1:443/apis/apiextensions.k8s.io/v1/customresourcedefinitions/originaccesscontrols.cloudfront.aws.upbound.io?dryRun=All
Mar 8 12:03:31 crossplane-6f49c7dc8c-4wp2k crossplane info I0308 11:03:31.999266       1 request.go:697] Waited for 1.016598113s due to client-side throttling, not priority and fairness, request: PUT:https://172.20.0.1:443/apis/apiextensions.k8s.io/v1/customresourcedefinitions/originaccesscontrols.cloudfront.aws.upbound.io

[..]
Mar 8 12:16:02 crossplane-6f49c7dc8c-4wp2k crossplane info I0308 11:16:02.322868       1 request.go:697] Waited for 1.158554807s due to client-side throttling, not priority and fairness, request: PUT:https://172.20.0.1:443/apis/apiextensions.k8s.io/v1/customresourcedefinitions/repositories.ecr.aws.upbound.io?dryRun=All
Mar 8 12:20:55 crossplane-6f49c7dc8c-4wp2k crossplane info I0308 11:20:55.618672       1 request.go:697] Waited for 1.06723943s due to client-side throttling, not priority and fairness, request: PUT:https://172.20.0.1:443/apis/apiextensions.k8s.io/v1/customresourcedefinitions/repositories.ecr.aws.upbound.io
Mar 8 12:49:31 crossplane-6f49c7dc8c-4wp2k crossplane info I0308 11:49:31.338487       1 request.go:697] Waited for 1.076130469s due to client-side throttling, not priority and fairness, request: PUT:https://172.20.0.1:443/apis/apiextensions.k8s.io/v1/customresourcedefinitions/repositories.ecr.aws.upbound.io
Mar 8 12:54:35 crossplane-6f49c7dc8c-4wp2k crossplane info I0308 11:54:35.559003       1 request.go:697] Waited for 1.010599378s due to client-side throttling, not priority and fairness, request: PUT:https://172.20.0.1:443/apis/apiextensions.k8s.io/v1/customresourcedefinitions/repositories.ecr.aws.upbound.io?dryRun=All
Mar 8 12:55:58 crossplane-6f49c7dc8c-4wp2k crossplane info I0308 11:55:58.839196       1 request.go:697] Waited for 1.016197549s due to client-side throttling, not priority and fairness, request: PUT:https://172.20.0.1:443/apis/apiextensions.k8s.io/v1/customresourcedefinitions/repositories.ecr.aws.upbound.io?dryRun=All
Mar 8 13:08:06 crossplane-6f49c7dc8c-4wp2k crossplane info I0308 12:08:06.978596       1 request.go:697] Waited for 1.010203178s due to client-side throttling, not priority and fairness, request: PUT:https://172.20.0.1:443/apis/apiextensions.k8s.io/v1/customresourcedefinitions/repositories.ecr.aws.upbound.io

Not sure if related but we had (previously) also enabled debug logs for a short while and noticed the rate at which crossplane keeps reconciling providerrevisions resources (eg. with route53 provider) 👀 :

[..]
Mar 6 13:56:40 crossplane-68cfdc8cf4-n45wn crossplane DEBUG crossplane	Reconciling	{"controller": "packages/providerrevision.pkg.crossplane.io", "request": {"name":"provider-aws-route53-c6f8c245452c"}}
Mar 6 13:56:42 crossplane-68cfdc8cf4-n45wn crossplane DEBUG crossplane	Reconciling	{"controller": "packages/providerrevision.pkg.crossplane.io", "request": {"name":"provider-aws-route53-c6f8c245452c"}}
Mar 6 13:56:45 crossplane-68cfdc8cf4-n45wn crossplane DEBUG crossplane	Reconciling	{"controller": "packages/providerrevision.pkg.crossplane.io", "request": {"name":"provider-aws-route53-c6f8c245452c"}}
Mar 6 13:56:47 crossplane-68cfdc8cf4-n45wn crossplane DEBUG crossplane	Reconciling	{"controller": "packages/providerrevision.pkg.crossplane.io", "request": {"name":"provider-aws-route53-c6f8c245452c"}}
Mar 6 13:56:49 crossplane-68cfdc8cf4-n45wn crossplane DEBUG crossplane	Reconciling	{"controller": "packages/providerrevision.pkg.crossplane.io", "request": {"name":"provider-aws-route53-c6f8c245452c"}}
Mar 6 13:56:51 crossplane-68cfdc8cf4-n45wn crossplane DEBUG crossplane	Reconciling	{"controller": "packages/providerrevision.pkg.crossplane.io", "request": {"name":"provider-aws-route53-c6f8c245452c"}}
Mar 6 13:56:53 crossplane-68cfdc8cf4-n45wn crossplane DEBUG crossplane	Reconciling	{"controller": "packages/providerrevision.pkg.crossplane.io", "request": {"name":"provider-aws-route53-c6f8c245452c"}}
Mar 6 13:56:55 crossplane-68cfdc8cf4-n45wn crossplane DEBUG crossplane	Reconciling	{"controller": "packages/providerrevision.pkg.crossplane.io", "request": {"name":"provider-aws-route53-c6f8c245452c"}}
Mar 6 13:56:57 crossplane-68cfdc8cf4-n45wn crossplane DEBUG crossplane	Reconciling	{"controller": "packages/providerrevision.pkg.crossplane.io", "request": {"name":"provider-aws-route53-c6f8c245452c"}}
Mar 6 13:56:59 crossplane-68cfdc8cf4-n45wn crossplane DEBUG crossplane	Reconciling	{"controller": "packages/providerrevision.pkg.crossplane.io", "request": {"name":"provider-aws-route53-c6f8c245452c"}}
Mar 6 13:57:02 crossplane-68cfdc8cf4-n45wn crossplane DEBUG crossplane	Reconciling	{"controller": "packages/providerrevision.pkg.crossplane.io", "request": {"name":"provider-aws-route53-c6f8c245452c"}}
Mar 6 13:57:04 crossplane-68cfdc8cf4-n45wn crossplane DEBUG crossplane	Reconciling	{"controller": "packages/providerrevision.pkg.crossplane.io", "request": {"name":"provider-aws-route53-c6f8c245452c"}}
Mar 6 13:57:04 crossplane-68cfdc8cf4-n45wn crossplane DEBUG crossplane	Reconciling	{"controller": "packages/providerrevision.pkg.crossplane.io", "request": {"name":"provider-aws-route53-c6f8c245452c"}}
[..]

[negz]

@aridelsante Are you using ControllerConfigs or DeploymentRuntimeConfigs with your Providers, by any chance?

[aridelsante]

@aridelsante Are you using ControllerConfigs or DeploymentRuntimeConfigs with your Providers, by any chance?

We are using ControllerConfigs right now, when we first tried to upgrade to 1.15.0 we also migrated to DeploymentRuntimeConfigs, (worked around #5068) but reverted back the change, and tested upgrading keeping ControllerConfigs instead. So for us this issue is happening no matter ControllerConfigs or DeploymentRuntimeConfigs.

[turkenh]

With a very simple setup, I couldn't reproduce it with Crossplane v1.15.0. I don't see the providerrevision reconciler keeping reconciling, so there should be something different triggering that behavior:

@aridelsante would you mind sharing your controlllerconfig and provider definiton? It would be super helpful if you could share a minimal setup/instructions to reproduce the issue on our side.

[aridelsante]

@turkenh below are our live definitions for the different components. One thing I noticed is that, although we set --enable-deployment-runtime-configs=false the providers still have runtimeConfigRef set to use the default one (as well as controllerConfigRef) 🤔

1. Crossplane v1.15.0 deployed via the official helm chart with --enable-deployment-runtime-configs=false:

apiVersion: apps/v1
kind: Deployment
[..]
spec:
  template:
    spec:
      containers:
      - args:
        - core
        - start
        - --enable-deployment-runtime-configs=false
        - --debug
        image: xpkg.upbound.io/crossplane/crossplane:v1.15.0
        imagePullPolicy: IfNotPresent
        name: crossplane
        [..]

2. ControllerConfig:

apiVersion: pkg.crossplane.io/v1alpha1
kind: ControllerConfig
[..]
spec:
  args:
  - --poll=10m
  podSecurityContext:
    fsGroup: 2000
  resources:
    limits:
      memory: 700Mi
    requests:
      cpu: 450m
      memory: 700Mi
  securityContext:
    allowPrivilegeEscalation: false
    runAsNonRoot: true
  serviceAccountName: crossplane-generic-provider

3. Provider

apiVersion: pkg.crossplane.io/v1
kind: Provider
metadata:
  name: provider-aws-route53
spec:
  controllerConfigRef:
    name: generic-provider
  ignoreCrossplaneConstraints: false
  package: xpkg.upbound.io/upbound/provider-aws-route53:v1.1.0
  packagePullPolicy: IfNotPresent
  revisionActivationPolicy: Automatic
  revisionHistoryLimit: 1
  runtimeConfigRef:
    apiVersion: pkg.crossplane.io/v1beta1
    kind: DeploymentRuntimeConfig
    name: default
  skipDependencyResolution: true

4. Providerrevision

apiVersion: pkg.crossplane.io/v1
kind: ProviderRevision
  name: provider-aws-route53-c6f8c245452c
spec:
  controllerConfigRef:
    name: generic-provider
  desiredState: Active
  ignoreCrossplaneConstraints: false
  image: xpkg.upbound.io/upbound/provider-aws-route53:v1.1.0
  packagePullPolicy: IfNotPresent
  revision: 3
  runtimeConfigRef:
    apiVersion: pkg.crossplane.io/v1beta1
    kind: DeploymentRuntimeConfig
    name: default
  skipDependencyResolution: true
  tlsClientSecretName: provider-aws-route53-tls-client
  tlsServerSecretName: provider-aws-route53-tls-server

[turkenh]

@aridelsante, thanks for the manifests.

I just tried on my side but, unfortunately, I couldn't reproduce the problem. I am specifically trying to see the "debug" logs indicating providerrevision is being reconciled too frequently. Tried both with --enable-deployment-runtime-configs=false and without it. This is all I get in XP logs:

2024-03-15T06:09:18Z	INFO	crossplane	Beta feature enabled	{"flag": "EnableBetaCompositionFunctions"}
2024-03-15T06:09:18Z	INFO	crossplane	Beta feature enabled	{"flag": "EnableBetaCompositionFunctionsExtraResources"}
2024-03-15T06:09:18Z	INFO	crossplane	Beta feature enabled	{"flag": "EnableBetaCompositionWebhookSchemaValidation"}
I0315 06:09:18.870148       1 leaderelection.go:250] attempting to acquire leader lease crossplane-system/crossplane-leader-election-core...
I0315 06:09:18.874381       1 leaderelection.go:260] successfully acquired lease crossplane-system/crossplane-leader-election-core
2024-03-15T06:09:18Z	DEBUG	crossplane	Event(v1.ObjectReference{Kind:"Lease", Namespace:"crossplane-system", Name:"crossplane-leader-election-core", UID:"7754c1eb-81ea-4538-984e-8c7bc4434032", APIVersion:"coordination.k8s.io/v1", ResourceVersion:"1612", FieldPath:""}): type: 'Normal' reason: 'LeaderElection' crossplane-657b644c8c-j262n_34e75dfc-1c0b-4dac-bd87-487b1b37f783 became leader
Warning: ControllerConfig.pkg.crossplane.io/v1alpha1 is deprecated. Use DeploymentRuntimeConfig from pkg.crossplane.io/v1beta1 instead.
2024-03-15T06:09:19Z	DEBUG	crossplane	Reconciling	{"controller": "packages/providerrevision.pkg.crossplane.io", "request": {"name":"provider-aws-route53-c6f8c245452c"}}
2024-03-15T06:09:19Z	DEBUG	crossplane	Reconciling	{"controller": "packages/provider.pkg.crossplane.io", "request": {"name":"provider-aws-route53"}}
2024-03-15T06:09:19Z	DEBUG	crossplane	Reconciling	{"controller": "packages/lock.pkg.crossplane.io", "request": {"name":"lock"}}

❯ kubectl get controllerconfig
Warning: ControllerConfig.pkg.crossplane.io/v1alpha1 is deprecated. Use DeploymentRuntimeConfig from pkg.crossplane.io/v1beta1 instead.
NAME               AGE
generic-provider   11m
❯ kubectl -n crossplane-system get providers.pkg.crossplane.io
NAME                   INSTALLED   HEALTHY   PACKAGE                                               AGE
provider-aws-route53   True        True      xpkg.upbound.io/upbound/provider-aws-route53:v1.1.0   9m55s
❯ kubectl -n crossplane-system get providerrevisions.pkg.crossplane.io
NAME                                HEALTHY   REVISION   IMAGE                                                 STATE    DEP-FOUND   DEP-INSTALLED   AGE
provider-aws-route53-c6f8c245452c   True      1          xpkg.upbound.io/upbound/provider-aws-route53:v1.1.0   Active                               9m58s

One thing I noticed is that, although we set --enable-deployment-runtime-configs=false the providers still have runtimeConfigRef set to use the default one (as well as controllerConfigRef) 🤔

This is expected, and you can ignore it. We do the defaulting at the kube API level which happens before the flag is processed. The package manager ignores that field when the feature is not enabled.

[turkenh]

One thing I noticed, the provider revision reconciler watches the serviceaccount and a reconciliation is triggered whenever there is a change on it. For example, if I add a random label to the crossplane-generic-provider serviceaccount, I am seeing a reconciliation log. So, I am wondering if there is an external controller/process making changes on the service account ? 🤔

Can you check what happens if you watch the SA:

❯ kubectl -n crossplane-system get sa crossplane-generic-provider -w
NAME                          SECRETS   AGE
crossplane-generic-provider   0         14m

Similarly wondering what happens if you watch the providerrevisions, and secrets/services in crossplane-system namespace which will also trigger reconciliation:

❯ kubectl get providerrevisions -w
NAME                                HEALTHY   REVISION   IMAGE                                                 STATE    DEP-FOUND   DEP-INSTALLED   AGE
provider-aws-route53-c6f8c245452c   True      1          xpkg.upbound.io/upbound/provider-aws-route53:v1.1.0   Active                               16m

❯ kubectl -n crossplane-system get secrets -w
...

❯ kubectl -n crossplane-system get svc -w
...

Wondering if all watches are stable or you're getting quick updates on any of the above.

[turkenh]

Glad to hear that it helped, so closing this issue as fixed 🎉

[negz]

Nice sleuthing folks!