Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Continual reconciliation on Azure provider on error #439

Open
stevendborrelli opened this issue Sep 13, 2024 · 1 comment
Open

Continual reconciliation on Azure provider on error #439

stevendborrelli opened this issue Sep 13, 2024 · 1 comment
Labels
bug Something isn't working

Comments

@stevendborrelli
Copy link

What happened?

When trying to provision a resource in error on Azure (due to the issue fixed in #435 we can't see the exact error), the provider constantly tries to create the resource.

With Azure provider 1.2.0, the requeue is increased up to 16m40s, but the object still reconciles a few times a minute:

2024-09-12T23:28:40Z	DEBUG	provider-azure	External resource is up to date	{"controller": "managed/keyvault.azure.upbound.io/v1beta1, kind=key", "request": {"name":"borrelli-test-2"}, "uid": "a03375f7-cc5e-4df2-a04b-e29e7d3f3a1d", "version": "2679", "external-name": "", "requeue-after": "2024-09-12T23:38:22Z"}
2024-09-12T23:28:41Z	DEBUG	provider-azure	External resource is up to date	{"controller": "managed/keyvault.azure.upbound.io/v1beta1, kind=key", "request": {"name":"borrelli-test-2"}, "uid": "a03375f7-cc5e-4df2-a04b-e29e7d3f3a1d", "version": "2679", "external-name": "", "requeue-after": "2024-09-12T23:38:37Z"}
2024-09-12T23:28:42Z	DEBUG	provider-azure	Reconcile request has been requeued.	{"gvk": "keyvault.azure.upbound.io/v1beta1, Kind=Key", "name": "borrelli-test-2", "rateLimiterName": "asyncCallback", "when": "5ms"}
2024-09-12T23:29:15Z	DEBUG	provider-azure	Reconcile request has been requeued.	{"gvk": "keyvault.azure.upbound.io/v1beta1, Kind=Key", "name": "borrelli-test-2", "rateLimiterName": "asyncCallback", "when": "10ms"}
2024-09-12T23:29:16Z	DEBUG	provider-azure	Reconcile request has been requeued.	{"gvk": "keyvault.azure.upbound.io/v1beta1, Kind=Key", "name": "borrelli-test-2", "rateLimiterName": "asyncCallback", "when": "20ms"}
2024-09-12T23:29:17Z	DEBUG	provider-azure	Reconcile request has been requeued.	{"gvk": "keyvault.azure.upbound.io/v1beta1, Kind=Key", "name": "borrelli-test-2", "rateLimiterName": "asyncCallback", "when": "40ms"}
2024-09-12T23:29:18Z	DEBUG	provider-azure	Reconcile request has been requeued.	{"gvk": "keyvault.azure.upbound.io/v1beta1, Kind=Key", "name": "borrelli-test-2", "rateLimiterName": "asyncCallback", "when": "80ms"}
2024-09-12T23:29:19Z	DEBUG	provider-azure	Reconcile request has been requeued.	{"gvk": "keyvault.azure.upbound.io/v1beta1, Kind=Key", "name": "borrelli-test-2", "rateLimiterName": "asyncCallback", "when": "160ms"}
2024-09-12T23:29:20Z	DEBUG	provider-azure	Reconcile request has been requeued.	{"gvk": "keyvault.azure.upbound.io/v1beta1, Kind=Key", "name": "borrelli-test-2", "rateLimiterName": "asyncCallback", "when": "320ms"}
2024-09-12T23:29:22Z	DEBUG	provider-azure	Reconcile request has been requeued.	{"gvk": "keyvault.azure.upbound.io/v1beta1, Kind=Key", "name": "borrelli-test-2", "rateLimiterName": "asyncCallback", "when": "640ms"}
2024-09-12T23:29:24Z	DEBUG	provider-azure	Reconcile request has been requeued.	{"gvk": "keyvault.azure.upbound.io/v1beta1, Kind=Key", "name": "borrelli-test-2", "rateLimiterName": "asyncCallback", "when": "1.28s"}
2024-09-12T23:29:26Z	DEBUG	provider-azure	Reconcile request has been requeued.	{"gvk": "keyvault.azure.upbound.io/v1beta1, Kind=Key", "name": "borrelli-test-2", "rateLimiterName": "asyncCallback", "when": "2.56s"}
2024-09-12T23:29:30Z	DEBUG	provider-azure	Reconcile request has been requeued.	{"gvk": "keyvault.azure.upbound.io/v1beta1, Kind=Key", "name": "borrelli-test-2", "rateLimiterName": "asyncCallback", "when": "5.12s"}
2024-09-12T23:29:36Z	DEBUG	provider-azure	Reconcile request has been requeued.	{"gvk": "keyvault.azure.upbound.io/v1beta1, Kind=Key", "name": "borrelli-test-2", "rateLimiterName": "asyncCallback", "when": "10.24s"}
2024-09-12T23:29:48Z	DEBUG	provider-azure	Reconcile request has been requeued.	{"gvk": "keyvault.azure.upbound.io/v1beta1, Kind=Key", "name": "borrelli-test-2", "rateLimiterName": "asyncCallback", "when": "20.48s"}
2024-09-13T00:12:36Z	DEBUG	provider-azure	External resource is up to date	{"controller": "managed/keyvault.azure.upbound.io/v1beta1, kind=key", "request": {"name":"borrelli-test-2"}, "uid": "c11fb95c-e26a-4473-8b25-f3d662e5cbb8", "version": "3784", "external-name": "", "requeue-after": "2024-09-13T00:22:52Z"}
2024-09-13T00:12:37Z	DEBUG	provider-azure	External resource is up to date	{"controller": "managed/keyvault.azure.upbound.io/v1beta1, kind=key", "request": {"name":"borrelli-test-2"}, "uid": "c11fb95c-e26a-4473-8b25-f3d662e5cbb8", "version": "3784", "external-name": "", "requeue-after": "2024-09-13T00:22:37Z"}
2024-09-13T00:12:37Z	DEBUG	provider-azure	Reconcile request has been requeued.	{"gvk": "keyvault.azure.upbound.io/v1beta1, Kind=Key", "name": "borrelli-test-2", "rateLimiterName": "asyncCallback", "when": "40.96s"}
2024-09-13T00:13:20Z	DEBUG	provider-azure	Reconcile request has been requeued.	{"gvk": "keyvault.azure.upbound.io/v1beta1, Kind=Key", "name": "borrelli-test-2", "rateLimiterName": "asyncCallback", "when": "1m21.92s"}
2024-09-13T00:13:21Z	DEBUG	provider-azure	Reconcile request has been requeued.	{"gvk": "keyvault.azure.upbound.io/v1beta1, Kind=Key", "name": "borrelli-test-2", "rateLimiterName": "asyncCallback", "when": "2m43.84s"}
2024-09-13T00:13:23Z	DEBUG	provider-azure	Reconcile request has been requeued.	{"gvk": "keyvault.azure.upbound.io/v1beta1, Kind=Key", "name": "borrelli-test-2", "rateLimiterName": "asyncCallback", "when": "5m27.68s"}
2024-09-13T00:13:28Z	DEBUG	provider-azure	Reconcile request has been requeued.	{"gvk": "keyvault.azure.upbound.io/v1beta1, Kind=Key", "name": "borrelli-test-2", "rateLimiterName": "asyncCallback", "when": "10m55.36s"}
2024-09-13T00:13:36Z	DEBUG	provider-azure	Reconcile request has been requeued.	{"gvk": "keyvault.azure.upbound.io/v1beta1, Kind=Key", "name": "borrelli-test-2", "rateLimiterName": "asyncCallback", "when": "16m40s"}
2024-09-13T00:13:52Z	DEBUG	provider-azure	Reconcile request has been requeued.	{"gvk": "keyvault.azure.upbound.io/v1beta1, Kind=Key", "name": "borrelli-test-2", "rateLimiterName": "asyncCallback", "when": "16m40s"}
2024-09-13T00:14:24Z	DEBUG	provider-azure	Reconcile request has been requeued.	{"gvk": "keyvault.azure.upbound.io/v1beta1, Kind=Key", "name": "borrelli-test-2", "rateLimiterName": "asyncCallback", "when": "16m40s"}

With Azure provider 1.5.0, it requires at 0s but eventually settles in to checking on the error create every 30s.

2024-09-13T00:28:21Z	DEBUG	provider-azure	Reconcile request has been requeued.	{"gvk": "keyvault.azure.upbound.io/v1beta1, Kind=Key", "name": "borrelli-test-2", "rateLimiterName": "", "when": "0s"}
2024-09-13T00:28:53Z	DEBUG	provider-azure	External resource is up to date	{"controller": "managed/keyvault.azure.upbound.io/v1beta1, kind=key", "request": {"name":"borrelli-test-2"}, "uid": "6577dc44-41df-45bf-9a46-788317f38ac2", "version": "6208", "external-name": "", "requeue-after": "2024-09-13T00:38:52Z"}
2024-09-13T00:28:54Z	DEBUG	provider-azure	Reconcile request has been requeued.	{"gvk": "keyvault.azure.upbound.io/v1beta1, Kind=Key", "name": "borrelli-test-2", "rateLimiterName": "", "when": "0s"}
2024-09-13T00:29:27Z	DEBUG	provider-azure	External resource is up to date	{"controller": "managed/keyvault.azure.upbound.io/v1beta1, kind=key", "request": {"name":"borrelli-test-2"}, "uid": "6577dc44-41df-45bf-9a46-788317f38ac2", "version": "6287", "external-name": "", "requeue-after": "2024-09-13T00:39:00Z"}
2024-09-13T00:29:27Z	DEBUG	provider-azure	Reconcile request has been requeued.	{"gvk": "keyvault.azure.upbound.io/v1beta1, Kind=Key", "name": "borrelli-test-2", "rateLimiterName": "", "when": "0s"}
2024-09-13T00:30:00Z	DEBUG	provider-azure	External resource is up to date	{"controller": "managed/keyvault.azure.upbound.io/v1beta1, kind=key", "request": {"name":"borrelli-test-2"}, "uid": "6577dc44-41df-45bf-9a46-788317f38ac2", "version": "6368", "external-name": "", "requeue-after": "2024-09-13T00:39:43Z"}
2024-09-13T00:30:00Z	DEBUG	provider-azure	Reconcile request has been requeued.	{"gvk": "keyvault.azure.upbound.io/v1beta1, Kind=Key", "name": "borrelli-test-2", "rateLimiterName": "", "when": "0s"}
2024-09-13T00:30:33Z	DEBUG	provider-azure	External resource is up to date	{"controller": "managed/keyvault.azure.upbound.io/v1beta1, kind=key", "request": {"name":"borrelli-test-2"}, "uid": "6577dc44-41df-45bf-9a46-788317f38ac2", "version": "6446", "external-name": "", "requeue-after": "2024-09-13T00:40:12Z"}
2024-09-13T00:30:34Z	DEBUG	provider-azure	Reconcile request has been requeued.	{"gvk": "keyvault.azure.upbound.io/v1beta1, Kind=Key", "name": "borrelli-test-2", "rateLimiterName": "", "when": "0s"}
2024-09-13T00:31:06Z	DEBUG	provider-azure	External resource is up to date	{"controller": "managed/keyvault.azure.upbound.io/v1beta1, kind=key", "request": {"name":"borrelli-test-2"}, "uid": "6577dc44-41df-45bf-9a46-788317f38ac2", "version": "6525", "external-name": "", "requeue-after": "2024-09-13T00:40:50Z"}
2024-09-13T00:31:07Z	DEBUG	provider-azure	Reconcile request has been requeued.	{"gvk": "keyvault.azure.upbound.io/v1beta1, Kind=Key", "name": "borrelli-test-2", "rateLimiterName": "", "when": "0s"}

How can we reproduce it?

Create any resource that has an error in provisioning:

apiVersion: keyvault.azure.upbound.io/v1beta1
kind: Vault
metadata:
  annotations:
    meta.upbound.io/example-id: keyvault/v1beta1/key
  labels:
    testing.upbound.io/example-name: example
  name: borrelli-test-2
spec:
  forProvider:
    location: uksouth
    resourceGroupName: borrelli-test
    skuName: premium
    softDeleteRetentionDays: 7
    tenantId: b9925bc4-8383-4c37-b9d2-fa456d1bb1c7
---
apiVersion: keyvault.azure.upbound.io/v1beta2
kind: Key
metadata:
  annotations:
    meta.upbound.io/example-id: keyvault/v1beta1/key
  labels:
    testing.upbound.io/example-name: example
  name: borrelli-test-2
spec:
  forProvider:
    keyOpts:
      - decrypt
      - encrypt
      - sign
      - unwrapKey
      - verify
      - wrapKey
    keySize: 2048
    keyType: RSA
    keyVaultIdRef:
      name: borrelli-test-2
    name: borrelli-test-2
    rotationPolicy:
      automatic:
        timeBeforeExpiry: P30D
      expireAfter: P90D
      notifyBeforeExpiry: P29D
@stevendborrelli stevendborrelli added the bug Something isn't working label Sep 13, 2024
@stevendborrelli
Copy link
Author

Another example I have found in logs, you can see the reque-after does not seem to be taking effect:

2024-09-12T11:29:43Z	DEBUG	provider-azure	Successfully requested update of external resource	{"controller": "managed/storage.azure.upbound.io/v1beta1, kind=account", "request": {"name":"uksouth-manager-dev-1-azurefile-csi-nfs"}, "uid": "56647f97-72a2-4e1f-ad7d-bdc7e2951e16", "version": "102331389", "external-name": "34a22711534795a757d4841c", "requeue-after": "2024-09-12T11:39:32Z"}
2024-09-12T11:29:44Z	DEBUG	provider-azure	Successfully requested update of external resource	{"controller": "managed/storage.azure.upbound.io/v1beta1, kind=account", "request": {"name":"uksouth-manager-dev-1-azurefile-csi-nfs"}, "uid": "56647f97-72a2-4e1f-ad7d-bdc7e2951e16", "version": "102331389", "external-name": "34a22711534795a757d4841c", "requeue-after": "2024-09-12T11:39:57Z"}
2024-09-12T11:29:46Z	DEBUG	provider-azure	Successfully requested update of external resource	{"controller": "managed/storage.azure.upbound.io/v1beta1, kind=account", "request": {"name":"uksouth-manager-dev-1-azurefile-csi-nfs"}, "uid": "56647f97-72a2-4e1f-ad7d-bdc7e2951e16", "version": "102331389", "external-name": "34a22711534795a757d4841c", "requeue-after": "2024-09-12T11:40:13Z"}
2024-09-12T11:29:48Z	DEBUG	provider-azure	Successfully requested update of external resource	{"controller": "managed/storage.azure.upbound.io/v1beta1, kind=account", "request": {"name":"uksouth-manager-dev-1-azurefile-csi-nfs"}, "uid": "56647f97-72a2-4e1f-ad7d-bdc7e2951e16", "version": "102331389", "external-name": "34a22711534795a757d4841c", "requeue-after": "2024-09-12T11:39:49Z"}

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug Something isn't working
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@stevendborrelli