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

[Bug]: Policy objects do not flip to Unready status when an invalid update is applied #1164

Closed
1 task done
diranged opened this issue Feb 19, 2024 · 7 comments
Closed
1 task done

[Bug]: Policy objects do not flip to Unready status when an invalid update is applied #1164

diranged opened this issue Feb 19, 2024 · 7 comments
Labels
bug Something isn't working community is:triaged Indicates that an issue has been reviewed.

Comments

@diranged
Copy link

Is there an existing issue for this?

  • I have searched the existing issues

Affected Resource(s)

iam.aws.upbound.io / Policy

Resource MRs required to reproduce the bug

Good Policy

apiVersion: iam.aws.upbound.io/v1beta1
kind: Policy
metadata:
  name: test-policy
spec:
  deletionPolicy: Delete
  forProvider:
    description: 'test policy'
    path: /
    policy: '{"Statement":[{"Action":["sts:GetCallerIdentity"],"Effect":"Allow","Resource":["*"]}],"Version":"2012-10-17"}'

Bad Policy

apiVersion: iam.aws.upbound.io/v1beta1
kind: Policy
metadata:
  name: test-policy
spec:
  deletionPolicy: Delete
  forProvider:
    description: 'test policy'
    path: /
    policy: '{"Statement":[{"Action":["sts:GetCallerIdentity"],"Effect":"Allow","Resource":["*"]}],"Version":"2012-10-XX"}'

Steps to Reproduce

Create the Policy

Create the working policy first ... everything is fine:

% k apply -f orig.yaml 
policy.iam.aws.upbound.io/test-policy created
% k get policies.iam.aws.upbound.io 
NAME          READY   SYNCED   EXTERNAL-NAME   AGE
test-policy   True    True     test-policy     90s
% k get policies.iam.aws.upbound.io test-policy -o yaml
apiVersion: iam.aws.upbound.io/v1beta1
kind: Policy
metadata:
  annotations:
    crossplane.io/external-create-pending: "2024-02-19T00:30:44Z"
    crossplane.io/external-create-succeeded: "2024-02-19T00:30:44Z"
    crossplane.io/external-name: test-policy
    kubectl.kubernetes.io/last-applied-configuration: |
      {"apiVersion":"iam.aws.upbound.io/v1beta1","kind":"Policy","metadata":{"annotations":{},"name":"test-policy"},"spec":{"deletionPolicy":"Delete","forProvider":{"description":"test policy","path":"/","policy":"{\"Statement\":[{\"Action\":[\"sts:GetCallerIdentity\"],\"Effect\":\"Allow\",\"Resource\":[\"*\"]}],\"Version\":\"2012-10-17\"}"}}}
  creationTimestamp: "2024-02-19T00:30:44Z"
  finalizers:
  - finalizer.managedresource.crossplane.io
  generation: 2
  name: test-policy
  resourceVersion: "8280"
  uid: 8debb4f5-5058-43be-b639-74f0690d28fc
spec:
  deletionPolicy: Delete
  forProvider:
    description: test policy
    path: /
    policy: '{"Statement":[{"Action":["sts:GetCallerIdentity"],"Effect":"Allow","Resource":["*"]}],"Version":"2012-10-17"}'
    tags:
      crossplane-kind: policy.iam.aws.upbound.io
      crossplane-name: test-policy
      crossplane-providerconfig: default
  initProvider: {}
  managementPolicies:
  - '*'
  providerConfigRef:
    name: default
status:
  atProvider:
    arn: arn:aws:iam::000000000000:policy/test-policy
    description: test policy
    id: arn:aws:iam::000000000000:policy/test-policy
    path: /
    policy: '{"Statement":[{"Action":["sts:GetCallerIdentity"],"Effect":"Allow","Resource":["*"]}],"Version":"2012-10-17"}'
    policyId: A5LEUIA1NC6OM4TCKZSDU
    tags:
      crossplane-kind: policy.iam.aws.upbound.io
      crossplane-name: test-policy
      crossplane-providerconfig: default
    tagsAll:
      crossplane-kind: policy.iam.aws.upbound.io
      crossplane-name: test-policy
      crossplane-providerconfig: default
  conditions:
  - lastTransitionTime: "2024-02-19T00:30:44Z"
    reason: Available
    status: "True"
    type: Ready
  - lastTransitionTime: "2024-02-19T00:30:44Z"
    reason: ReconcileSuccess
    status: "True"
    type: Synced
  - lastTransitionTime: "2024-02-19T00:30:44Z"
    reason: Success
    status: "True"
    type: LastAsyncOperation

Now, update the policy with an invalid inlinePolicy

% k get policies.iam.aws.upbound.io
NAME          READY   SYNCED   EXTERNAL-NAME   AGE
test-policy   True    True     test-policy     3m37s
% k describe policies.iam.aws.upbound.io
Name:         test-policy
Namespace:    
Labels:       <none>
Annotations:  crossplane.io/external-create-pending: 2024-02-19T00:30:44Z
              crossplane.io/external-create-succeeded: 2024-02-19T00:30:44Z
              crossplane.io/external-name: test-policy
API Version:  iam.aws.upbound.io/v1beta1
Kind:         Policy
Metadata:
  Creation Timestamp:  2024-02-19T00:30:44Z
  Finalizers:
    finalizer.managedresource.crossplane.io
  Generation:        3
  Resource Version:  8772
  UID:               8debb4f5-5058-43be-b639-74f0690d28fc
Spec:
  Deletion Policy:  Delete
  For Provider:
    Description:  test policy
    Path:         /
    Policy:       {"Statement":[{"Action":["sts:GetCallerIdentity"],"Effect":"Allow","Resource":["*"]}],"Version":"2012-10-XX"}
    Tags:
      Crossplane - Kind:            policy.iam.aws.upbound.io
      Crossplane - Name:            test-policy
      Crossplane - Providerconfig:  default
  Init Provider:
  Management Policies:
    *
  Provider Config Ref:
    Name:  default
Status:
  At Provider:
    Arn:          arn:aws:iam::000000000000:policy/test-policy
    Description:  test policy
    Id:           arn:aws:iam::000000000000:policy/test-policy
    Path:         /
    Policy:       {"Statement":[{"Action":["sts:GetCallerIdentity"],"Effect":"Allow","Resource":["*"]}],"Version":"2012-10-17"}
    Policy Id:    A5LEUIA1NC6OM4TCKZSDU
    Tags:
      Crossplane - Kind:            policy.iam.aws.upbound.io
      Crossplane - Name:            test-policy
      Crossplane - Providerconfig:  default
    Tags All:
      Crossplane - Kind:            policy.iam.aws.upbound.io
      Crossplane - Name:            test-policy
      Crossplane - Providerconfig:  default
  Conditions:
    Last Transition Time:  2024-02-19T00:30:44Z
    Reason:                Available
    Status:                True
    Type:                  Ready
    Last Transition Time:  2024-02-19T00:30:44Z
    Reason:                ReconcileSuccess
    Status:                True
    Type:                  Synced
    Last Transition Time:  2024-02-19T00:34:08Z
    Message:               async update failed: failed to update the resource: [{0 updating IAM Policy (arn:aws:iam::000000000000:policy/test-policy): MalformedPolicyDocument: Syntax errors in policy.
                           status code: 400, request id: 25863eb5-3da6-4aed-9b99-a88311f7db02  []}]
    Reason:                AsyncUpdateFailure
    Status:                False
    Type:                  LastAsyncOperation
Events:
  Type    Reason                   Age                 From                                             Message
  ----    ------                   ----                ----                                             -------
  Normal  CreatedExternalResource  3m39s               managed/iam.aws.upbound.io/v1beta1, kind=policy  Successfully requested creation of external resource
  Normal  UpdatedExternalResource  15s (x13 over 36s)  managed/iam.aws.upbound.io/v1beta1, kind=policy  Successfully requested update of external resource

What happened?

Bug: The policy is still considered Ready

Given that the resource cannot be reconciled - it should go into an Unready state ... but instead it stays Ready. The LastAsyncOperation does flip to False, but that's not enough.. I believe the resource should flip into an unready state.

Relevant Error Output Snippet

No response

Crossplane Version

1.15.0

Provider Version

1.1.0

Kubernetes Version

1.28.0

Kubernetes Distribution

Localstack

Additional Info

Creation Logs

2024-02-19T00:30:44Z	DEBUG	provider-aws	Calling the inner handler for Create event.	{"gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy", "name": "test-policy", "queueLength": 0}
2024-02-19T00:30:44Z	DEBUG	provider-aws	Reconciling	{"controller": "managed/iam.aws.upbound.io/v1beta1, kind=policy", "request": {"name":"test-policy"}}
2024-02-19T00:30:44Z	DEBUG	provider-aws	Calling the inner handler for Update event.	{"gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy", "name": "test-policy", "queueLength": 0}
2024-02-19T00:30:44Z	DEBUG	provider-aws	Connecting to the service provider	{"uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "name": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy"}
2024-02-19T00:30:44Z	DEBUG	provider-aws	Calling the inner handler for Update event.	{"gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy", "name": "test-policy", "queueLength": 0}
2024-02-19T00:30:44Z	DEBUG	provider-aws	Instance state not found in cache, reconstructing...	{"uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "name": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy"}
2024-02-19T00:30:44Z	DEBUG	provider-aws	Observing the external resource	{"uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "name": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy"}
2024/02/19 00:30:44 [DEBUG] Waiting for state to become: [success]
2024/02/19 00:30:44 [WARN] IAM Policy (arn:aws:iam::000000000:policy/test-policy) not found, removing from state
2024-02-19T00:30:44Z	DEBUG	provider-aws	Diff detected	{"uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "name": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy", "instanceDiff": "*terraform.InstanceDiff{mu:sync.Mutex{state:0, sema:0x0}, Attributes:map[string]*terraform.ResourceAttrDiff{\"arn\":*terraform.ResourceAttrDiff{Old:\"\", New:\"\", NewComputed:true, NewRemoved:false, NewExtra:interface {}(nil), RequiresNew:false, Sensitive:false, Type:0x0}, \"description\":*terraform.ResourceAttrDiff{Old:\"\", New:\"test policy\", NewComputed:false, NewRemoved:false, NewExtra:interface {}(nil), RequiresNew:true, Sensitive:false, Type:0x0}, \"name\":*terraform.ResourceAttrDiff{Old:\"\", New:\"test-policy\", NewComputed:false, NewRemoved:false, NewExtra:interface {}(nil), RequiresNew:true, Sensitive:false, Type:0x0}, \"name_prefix\":*terraform.ResourceAttrDiff{Old:\"\", New:\"\", NewComputed:true, NewRemoved:false, NewExtra:interface {}(nil), RequiresNew:true, Sensitive:false, Type:0x0}, \"path\":*terraform.ResourceAttrDiff{Old:\"\", New:\"/\", NewComputed:false, NewRemoved:false, NewExtra:interface {}(nil), RequiresNew:true, Sensitive:false, Type:0x0}, \"policy\":*terraform.ResourceAttrDiff{Old:\"\", New:\"{\\\"Statement\\\":[{\\\"Action\\\":[\\\"sts:GetCallerIdentity\\\"],\\\"Effect\\\":\\\"Allow\\\",\\\"Resource\\\":[\\\"*\\\"]}],\\\"Version\\\":\\\"2012-10-17\\\"}\", NewComputed:false, NewRemoved:false, NewExtra:\"{\\\"Statement\\\":[{\\\"Action\\\":[\\\"sts:GetCallerIdentity\\\"],\\\"Effect\\\":\\\"Allow\\\",\\\"Resource\\\":[\\\"*\\\"]}],\\\"Version\\\":\\\"2012-10-17\\\"}\", RequiresNew:false, Sensitive:false, Type:0x0}, \"policy_id\":*terraform.ResourceAttrDiff{Old:\"\", New:\"\", NewComputed:true, NewRemoved:false, NewExtra:interface {}(nil), RequiresNew:false, Sensitive:false, Type:0x0}, \"tags.%\":*terraform.ResourceAttrDiff{Old:\"0\", New:\"3\", NewComputed:false, NewRemoved:false, NewExtra:interface {}(nil), RequiresNew:false, Sensitive:false, Type:0x0}, \"tags.crossplane-kind\":*terraform.ResourceAttrDiff{Old:\"\", New:\"policy.iam.aws.upbound.io\", NewComputed:false, NewRemoved:false, NewExtra:interface {}(nil), RequiresNew:false, Sensitive:false, Type:0x0}, \"tags.crossplane-name\":*terraform.ResourceAttrDiff{Old:\"\", New:\"test-policy\", NewComputed:false, NewRemoved:false, NewExtra:interface {}(nil), RequiresNew:false, Sensitive:false, Type:0x0}, \"tags.crossplane-providerconfig\":*terraform.ResourceAttrDiff{Old:\"\", New:\"default\", NewComputed:false, NewRemoved:false, NewExtra:interface {}(nil), RequiresNew:false, Sensitive:false, Type:0x0}, \"tags_all.%\":*terraform.ResourceAttrDiff{Old:\"0\", New:\"3\", NewComputed:false, NewRemoved:false, NewExtra:interface {}(nil), RequiresNew:false, Sensitive:false, Type:0x0}, \"tags_all.crossplane-kind\":*terraform.ResourceAttrDiff{Old:\"\", New:\"policy.iam.aws.upbound.io\", NewComputed:false, NewRemoved:false, NewExtra:interface {}(nil), RequiresNew:false, Sensitive:false, Type:0x0}, \"tags_all.crossplane-name\":*terraform.ResourceAttrDiff{Old:\"\", New:\"test-policy\", NewComputed:false, NewRemoved:false, NewExtra:interface {}(nil), RequiresNew:false, Sensitive:false, Type:0x0}, \"tags_all.crossplane-providerconfig\":*terraform.ResourceAttrDiff{Old:\"\", New:\"default\", NewComputed:false, NewRemoved:false, NewExtra:interface {}(nil), RequiresNew:false, Sensitive:false, Type:0x0}}, Destroy:false, DestroyDeposed:false, DestroyTainted:false, RawConfig:cty.NilVal, RawState:cty.NilVal, RawPlan:cty.NilVal, Meta:map[string]interface {}(nil)}"}
2024-02-19T00:30:44Z	DEBUG	provider-aws	Async create starting...	{"trackerUID": "8debb4f5-5058-43be-b639-74f0690d28fc", "resourceName": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy", "tfID": ""}
2024-02-19T00:30:44Z	DEBUG	provider-aws	Creating the external resource	{"uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "name": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy"}
2024-02-19T00:30:44Z	DEBUG	provider-aws	Calling the inner handler for Update event.	{"gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy", "name": "test-policy", "queueLength": 0}
2024-02-19T00:30:44Z	DEBUG	provider-aws	Successfully requested creation of external resource	{"controller": "managed/iam.aws.upbound.io/v1beta1, kind=policy", "request": {"name":"test-policy"}, "uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "version": "8269", "external-name": "", "external-name": "test-policy"}
2024-02-19T00:30:44Z	DEBUG	events	Successfully requested creation of external resource	{"type": "Normal", "object": {"kind":"Policy","name":"test-policy","uid":"8debb4f5-5058-43be-b639-74f0690d28fc","apiVersion":"iam.aws.upbound.io/v1beta1","resourceVersion":"8276"}, "reason": "CreatedExternalResource"}
2024/02/19 00:30:44 [DEBUG] Waiting for state to become: [success]
2024-02-19T00:30:44Z	DEBUG	provider-aws	Reconciling	{"controller": "managed/iam.aws.upbound.io/v1beta1, kind=policy", "request": {"name":"test-policy"}}
2024-02-19T00:30:44Z	DEBUG	provider-aws	Connecting to the service provider	{"uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "name": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy"}
2024-02-19T00:30:44Z	DEBUG	provider-aws	Async create ended.	{"trackerUID": "8debb4f5-5058-43be-b639-74f0690d28fc", "resourceName": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy", "error": null, "tfID": "arn:aws:iam::000000000000:policy/test-policy"}
2024-02-19T00:30:44Z	DEBUG	provider-aws	Reconcile request has been requeued.	{"gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy", "name": "test-policy", "rateLimiterName": "", "when": "0s"}
2024-02-19T00:30:44Z	DEBUG	provider-aws	Observing the external resource	{"uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "name": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy"}
2024/02/19 00:30:44 [DEBUG] Waiting for state to become: [success]
2024-02-19T00:30:44Z	DEBUG	provider-aws	External resource is up to date	{"controller": "managed/iam.aws.upbound.io/v1beta1, kind=policy", "request": {"name":"test-policy"}, "uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "version": "8278", "external-name": "test-policy", "requeue-after": "2024-02-19T00:40:18Z"}
2024-02-19T00:30:44Z	DEBUG	provider-aws	Reconciling	{"controller": "managed/iam.aws.upbound.io/v1beta1, kind=policy", "request": {"name":"test-policy"}}
2024-02-19T00:30:44Z	DEBUG	provider-aws	Connecting to the service provider	{"uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "name": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy"}
2024-02-19T00:30:44Z	DEBUG	provider-aws	Observing the external resource	{"uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "name": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy"}
2024/02/19 00:30:44 [DEBUG] Waiting for state to become: [success]
2024-02-19T00:30:44Z	DEBUG	provider-aws	External resource is up to date	{"controller": "managed/iam.aws.upbound.io/v1beta1, kind=policy", "request": {"name":"test-policy"}, "uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "version": "8279", "external-name": "test-policy", "requeue-after": "2024-02-19T00:40:51Z"}
2024-02-19T00:30:45Z	DEBUG	provider-aws	Reconciling	{"controller": "managed/iam.aws.upbound.io/v1beta1, kind=policy", "request": {"name":"test-policy"}}
2024-02-19T00:30:45Z	DEBUG	provider-aws	Connecting to the service provider	{"uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "name": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy"}
2024-02-19T00:30:45Z	DEBUG	provider-aws	Observing the external resource	{"uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "name": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy"}
2024/02/19 00:30:45 [DEBUG] Waiting for state to become: [success]
2024-02-19T00:30:45Z	DEBUG	provider-aws	External resource is up to date	{"controller": "managed/iam.aws.upbound.io/v1beta1, kind=policy", "request": {"name":"test-policy"}, "uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "version": "8280", "external-name": "test-policy", "requeue-after": "2024-02-19T00:40:16Z"}

Failure Logs after Bad Policy Update

2024-02-19T00:33:47Z	DEBUG	provider-aws	Calling the inner handler for Update event.	{"gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy", "name": "test-policy", "queueLength": 0}
2024-02-19T00:33:47Z	DEBUG	provider-aws	Reconciling	{"controller": "managed/iam.aws.upbound.io/v1beta1, kind=policy", "request": {"name":"test-policy"}}
2024-02-19T00:33:47Z	DEBUG	provider-aws	Connecting to the service provider	{"uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "name": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy"}
2024-02-19T00:33:47Z	DEBUG	provider-aws	Observing the external resource	{"uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "name": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy"}
2024/02/19 00:33:47 [DEBUG] Waiting for state to become: [success]
2024-02-19T00:33:47Z	DEBUG	provider-aws	Diff detected	{"uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "name": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy", "instanceDiff": "*terraform.InstanceDiff{mu:sync.Mutex{state:0, sema:0x0}, Attributes:map[string]*terraform.ResourceAttrDiff{\"policy\":*terraform.ResourceAttrDiff{Old:\"{\\\"Statement\\\":[{\\\"Action\\\":[\\\"sts:GetCallerIdentity\\\"],\\\"Effect\\\":\\\"Allow\\\",\\\"Resource\\\":[\\\"*\\\"]}],\\\"Version\\\":\\\"2012-10-17\\\"}\", New:\"{\\\"Statement\\\":[{\\\"Action\\\":[\\\"sts:GetCallerIdentity\\\"],\\\"Effect\\\":\\\"Allow\\\",\\\"Resource\\\":[\\\"*\\\"]}],\\\"Version\\\":\\\"2012-10-XX\\\"}\", NewComputed:false, NewRemoved:false, NewExtra:\"{\\\"Statement\\\":[{\\\"Action\\\":[\\\"sts:GetCallerIdentity\\\"],\\\"Effect\\\":\\\"Allow\\\",\\\"Resource\\\":[\\\"*\\\"]}],\\\"Version\\\":\\\"2012-10-XX\\\"}\", RequiresNew:false, Sensitive:false, Type:0x0}}, Destroy:false, DestroyDeposed:false, DestroyTainted:false, RawConfig:cty.NilVal, RawState:cty.NilVal, RawPlan:cty.NilVal, Meta:map[string]interface {}(nil)}"}
2024-02-19T00:33:47Z	DEBUG	provider-aws	Successfully requested update of external resource	{"controller": "managed/iam.aws.upbound.io/v1beta1, kind=policy", "request": {"name":"test-policy"}, "uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "version": "8699", "external-name": "test-policy", "requeue-after": "2024-02-19T00:43:20Z"}
2024-02-19T00:33:47Z	DEBUG	provider-aws	Async update starting...	{"trackerUID": "8debb4f5-5058-43be-b639-74f0690d28fc", "resourceName": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy", "tfID": "arn:aws:iam::000000000000:policy/test-policy"}
2024-02-19T00:33:47Z	DEBUG	provider-aws	Updating the external resource	{"uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "name": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy"}
2024-02-19T00:33:47Z	DEBUG	events	Successfully requested update of external resource	{"type": "Normal", "object": {"kind":"Policy","name":"test-policy","uid":"8debb4f5-5058-43be-b639-74f0690d28fc","apiVersion":"iam.aws.upbound.io/v1beta1","resourceVersion":"8699"}, "reason": "UpdatedExternalResource"}
2024-02-19T00:33:47Z	DEBUG	provider-aws	Async update ended.	{"trackerUID": "8debb4f5-5058-43be-b639-74f0690d28fc", "resourceName": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy", "error": "async update failed: failed to update the resource: [{0 updating IAM Policy (arn:aws:iam::000000000000:policy/test-policy): MalformedPolicyDocument: Syntax errors in policy.\n\tstatus code: 400, request id: e4fe9a62-8ebe-43f7-b873-cc5a3e29d677  []}]", "tfID": "arn:aws:iam::000000000000:policy/test-policy"}
2024-02-19T00:33:47Z	DEBUG	provider-aws	Reconcile request has been requeued.	{"gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy", "name": "test-policy", "rateLimiterName": "asyncCallback", "when": "5ms"}
2024-02-19T00:33:47Z	DEBUG	provider-aws	Reconciling	{"controller": "managed/iam.aws.upbound.io/v1beta1, kind=policy", "request": {"name":"test-policy"}}
2024-02-19T00:33:47Z	DEBUG	provider-aws	Connecting to the service provider	{"uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "name": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy"}
2024-02-19T00:33:47Z	DEBUG	provider-aws	Observing the external resource	{"uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "name": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy"}
2024/02/19 00:33:47 [DEBUG] Waiting for state to become: [success]
2024-02-19T00:33:47Z	DEBUG	provider-aws	Diff detected	{"uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "name": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy", "instanceDiff": "*terraform.InstanceDiff{mu:sync.Mutex{state:0, sema:0x0}, Attributes:map[string]*terraform.ResourceAttrDiff{\"policy\":*terraform.ResourceAttrDiff{Old:\"{\\\"Statement\\\":[{\\\"Action\\\":[\\\"sts:GetCallerIdentity\\\"],\\\"Effect\\\":\\\"Allow\\\",\\\"Resource\\\":[\\\"*\\\"]}],\\\"Version\\\":\\\"2012-10-17\\\"}\", New:\"{\\\"Statement\\\":[{\\\"Action\\\":[\\\"sts:GetCallerIdentity\\\"],\\\"Effect\\\":\\\"Allow\\\",\\\"Resource\\\":[\\\"*\\\"]}],\\\"Version\\\":\\\"2012-10-XX\\\"}\", NewComputed:false, NewRemoved:false, NewExtra:\"{\\\"Statement\\\":[{\\\"Action\\\":[\\\"sts:GetCallerIdentity\\\"],\\\"Effect\\\":\\\"Allow\\\",\\\"Resource\\\":[\\\"*\\\"]}],\\\"Version\\\":\\\"2012-10-XX\\\"}\", RequiresNew:false, Sensitive:false, Type:0x0}}, Destroy:false, DestroyDeposed:false, DestroyTainted:false, RawConfig:cty.NilVal, RawState:cty.NilVal, RawPlan:cty.NilVal, Meta:map[string]interface {}(nil)}"}
2024-02-19T00:33:47Z	DEBUG	provider-aws	Successfully requested update of external resource	{"controller": "managed/iam.aws.upbound.io/v1beta1, kind=policy", "request": {"name":"test-policy"}, "uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "version": "8701", "external-name": "test-policy", "requeue-after": "2024-02-19T00:43:21Z"}
2024-02-19T00:33:47Z	DEBUG	provider-aws	Async update starting...	{"trackerUID": "8debb4f5-5058-43be-b639-74f0690d28fc", "resourceName": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy", "tfID": "arn:aws:iam::000000000000:policy/test-policy"}
2024-02-19T00:33:47Z	DEBUG	provider-aws	Updating the external resource	{"uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "name": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy"}
2024-02-19T00:33:47Z	DEBUG	events	Successfully requested update of external resource	{"type": "Normal", "object": {"kind":"Policy","name":"test-policy","uid":"8debb4f5-5058-43be-b639-74f0690d28fc","apiVersion":"iam.aws.upbound.io/v1beta1","resourceVersion":"8701"}, "reason": "UpdatedExternalResource"}
2024-02-19T00:33:47Z	DEBUG	provider-aws	Async update ended.	{"trackerUID": "8debb4f5-5058-43be-b639-74f0690d28fc", "resourceName": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy", "error": "async update failed: failed to update the resource: [{0 updating IAM Policy (arn:aws:iam::000000000000:policy/test-policy): MalformedPolicyDocument: Syntax errors in policy.\n\tstatus code: 400, request id: 13911ca2-abe9-4532-8a8c-aee19259fb67  []}]", "tfID": "arn:aws:iam::000000000000:policy/test-policy"}
2024-02-19T00:33:47Z	DEBUG	provider-aws	Reconcile request has been requeued.	{"gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy", "name": "test-policy", "rateLimiterName": "asyncCallback", "when": "10ms"}
2024-02-19T00:33:47Z	DEBUG	provider-aws	Reconciling	{"controller": "managed/iam.aws.upbound.io/v1beta1, kind=policy", "request": {"name":"test-policy"}}
2024-02-19T00:33:47Z	DEBUG	provider-aws	Connecting to the service provider	{"uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "name": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy"}
2024-02-19T00:33:47Z	DEBUG	provider-aws	Observing the external resource	{"uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "name": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy"}
2024/02/19 00:33:47 [DEBUG] Waiting for state to become: [success]
2024-02-19T00:33:47Z	DEBUG	provider-aws	Diff detected	{"uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "name": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy", "instanceDiff": "*terraform.InstanceDiff{mu:sync.Mutex{state:0, sema:0x0}, Attributes:map[string]*terraform.ResourceAttrDiff{\"policy\":*terraform.ResourceAttrDiff{Old:\"{\\\"Statement\\\":[{\\\"Action\\\":[\\\"sts:GetCallerIdentity\\\"],\\\"Effect\\\":\\\"Allow\\\",\\\"Resource\\\":[\\\"*\\\"]}],\\\"Version\\\":\\\"2012-10-17\\\"}\", New:\"{\\\"Statement\\\":[{\\\"Action\\\":[\\\"sts:GetCallerIdentity\\\"],\\\"Effect\\\":\\\"Allow\\\",\\\"Resource\\\":[\\\"*\\\"]}],\\\"Version\\\":\\\"2012-10-XX\\\"}\", NewComputed:false, NewRemoved:false, NewExtra:\"{\\\"Statement\\\":[{\\\"Action\\\":[\\\"sts:GetCallerIdentity\\\"],\\\"Effect\\\":\\\"Allow\\\",\\\"Resource\\\":[\\\"*\\\"]}],\\\"Version\\\":\\\"2012-10-XX\\\"}\", RequiresNew:false, Sensitive:false, Type:0x0}}, Destroy:false, DestroyDeposed:false, DestroyTainted:false, RawConfig:cty.NilVal, RawState:cty.NilVal, RawPlan:cty.NilVal, Meta:map[string]interface {}(nil)}"}
2024-02-19T00:33:47Z	DEBUG	provider-aws	Successfully requested update of external resource	{"controller": "managed/iam.aws.upbound.io/v1beta1, kind=policy", "request": {"name":"test-policy"}, "uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "version": "8703", "external-name": "test-policy", "requeue-after": "2024-02-19T00:44:10Z"}
2024-02-19T00:33:47Z	DEBUG	provider-aws	Async update starting...	{"trackerUID": "8debb4f5-5058-43be-b639-74f0690d28fc", "resourceName": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy", "tfID": "arn:aws:iam::000000000000:policy/test-policy"}
2024-02-19T00:33:47Z	DEBUG	provider-aws	Updating the external resource	{"uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "name": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy"}
2024-02-19T00:33:47Z	DEBUG	events	Successfully requested update of external resource	{"type": "Normal", "object": {"kind":"Policy","name":"test-policy","uid":"8debb4f5-5058-43be-b639-74f0690d28fc","apiVersion":"iam.aws.upbound.io/v1beta1","resourceVersion":"8703"}, "reason": "UpdatedExternalResource"}
2024-02-19T00:33:47Z	DEBUG	provider-aws	Async update ended.	{"trackerUID": "8debb4f5-5058-43be-b639-74f0690d28fc", "resourceName": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy", "error": "async update failed: failed to update the resource: [{0 updating IAM Policy (arn:aws:iam::000000000000:policy/test-policy): MalformedPolicyDocument: Syntax errors in policy.\n\tstatus code: 400, request id: 7cc9dc22-6639-40c8-93ec-d6137d61d9fa  []}]", "tfID": "arn:aws:iam::000000000000:policy/test-policy"}
2024-02-19T00:33:47Z	DEBUG	provider-aws	Reconcile request has been requeued.	{"gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy", "name": "test-policy", "rateLimiterName": "asyncCallback", "when": "20ms"}
2024-02-19T00:33:47Z	DEBUG	provider-aws	Reconciling	{"controller": "managed/iam.aws.upbound.io/v1beta1, kind=policy", "request": {"name":"test-policy"}}
2024-02-19T00:33:47Z	DEBUG	provider-aws	Connecting to the service provider	{"uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "name": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy"}
2024-02-19T00:33:47Z	DEBUG	provider-aws	Observing the external resource	{"uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "name": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy"}
2024/02/19 00:33:47 [DEBUG] Waiting for state to become: [success]
2024-02-19T00:33:47Z	DEBUG	provider-aws	Diff detected	{"uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "name": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy", "instanceDiff": "*terraform.InstanceDiff{mu:sync.Mutex{state:0, sema:0x0}, Attributes:map[string]*terraform.ResourceAttrDiff{\"policy\":*terraform.ResourceAttrDiff{Old:\"{\\\"Statement\\\":[{\\\"Action\\\":[\\\"sts:GetCallerIdentity\\\"],\\\"Effect\\\":\\\"Allow\\\",\\\"Resource\\\":[\\\"*\\\"]}],\\\"Version\\\":\\\"2012-10-17\\\"}\", New:\"{\\\"Statement\\\":[{\\\"Action\\\":[\\\"sts:GetCallerIdentity\\\"],\\\"Effect\\\":\\\"Allow\\\",\\\"Resource\\\":[\\\"*\\\"]}],\\\"Version\\\":\\\"2012-10-XX\\\"}\", NewComputed:false, NewRemoved:false, NewExtra:\"{\\\"Statement\\\":[{\\\"Action\\\":[\\\"sts:GetCallerIdentity\\\"],\\\"Effect\\\":\\\"Allow\\\",\\\"Resource\\\":[\\\"*\\\"]}],\\\"Version\\\":\\\"2012-10-XX\\\"}\", RequiresNew:false, Sensitive:false, Type:0x0}}, Destroy:false, DestroyDeposed:false, DestroyTainted:false, RawConfig:cty.NilVal, RawState:cty.NilVal, RawPlan:cty.NilVal, Meta:map[string]interface {}(nil)}"}
2024-02-19T00:33:47Z	DEBUG	provider-aws	Successfully requested update of external resource	{"controller": "managed/iam.aws.upbound.io/v1beta1, kind=policy", "request": {"name":"test-policy"}, "uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "version": "8705", "external-name": "test-policy", "requeue-after": "2024-02-19T00:44:15Z"}
2024-02-19T00:33:47Z	DEBUG	provider-aws	Async update starting...	{"trackerUID": "8debb4f5-5058-43be-b639-74f0690d28fc", "resourceName": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy", "tfID": "arn:aws:iam::000000000000:policy/test-policy"}
2024-02-19T00:33:47Z	DEBUG	provider-aws	Updating the external resource	{"uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "name": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy"}
2024-02-19T00:33:47Z	DEBUG	events	Successfully requested update of external resource	{"type": "Normal", "object": {"kind":"Policy","name":"test-policy","uid":"8debb4f5-5058-43be-b639-74f0690d28fc","apiVersion":"iam.aws.upbound.io/v1beta1","resourceVersion":"8705"}, "reason": "UpdatedExternalResource"}
2024-02-19T00:33:47Z	DEBUG	provider-aws	Async update ended.	{"trackerUID": "8debb4f5-5058-43be-b639-74f0690d28fc", "resourceName": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy", "error": "async update failed: failed to update the resource: [{0 updating IAM Policy (arn:aws:iam::000000000000:policy/test-policy): MalformedPolicyDocument: Syntax errors in policy.\n\tstatus code: 400, request id: b8551adb-cbee-46d1-95eb-79341e920882  []}]", "tfID": "arn:aws:iam::000000000000:policy/test-policy"}
2024-02-19T00:33:47Z	DEBUG	provider-aws	Reconcile request has been requeued.	{"gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy", "name": "test-policy", "rateLimiterName": "asyncCallback", "when": "40ms"}
2024-02-19T00:33:47Z	DEBUG	provider-aws	Reconciling	{"controller": "managed/iam.aws.upbound.io/v1beta1, kind=policy", "request": {"name":"test-policy"}}
2024-02-19T00:33:47Z	DEBUG	provider-aws	Connecting to the service provider	{"uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "name": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy"}
2024-02-19T00:33:47Z	DEBUG	provider-aws	Observing the external resource	{"uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "name": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy"}
2024/02/19 00:33:47 [DEBUG] Waiting for state to become: [success]
2024-02-19T00:33:47Z	DEBUG	provider-aws	Diff detected	{"uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "name": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy", "instanceDiff": "*terraform.InstanceDiff{mu:sync.Mutex{state:0, sema:0x0}, Attributes:map[string]*terraform.ResourceAttrDiff{\"policy\":*terraform.ResourceAttrDiff{Old:\"{\\\"Statement\\\":[{\\\"Action\\\":[\\\"sts:GetCallerIdentity\\\"],\\\"Effect\\\":\\\"Allow\\\",\\\"Resource\\\":[\\\"*\\\"]}],\\\"Version\\\":\\\"2012-10-17\\\"}\", New:\"{\\\"Statement\\\":[{\\\"Action\\\":[\\\"sts:GetCallerIdentity\\\"],\\\"Effect\\\":\\\"Allow\\\",\\\"Resource\\\":[\\\"*\\\"]}],\\\"Version\\\":\\\"2012-10-XX\\\"}\", NewComputed:false, NewRemoved:false, NewExtra:\"{\\\"Statement\\\":[{\\\"Action\\\":[\\\"sts:GetCallerIdentity\\\"],\\\"Effect\\\":\\\"Allow\\\",\\\"Resource\\\":[\\\"*\\\"]}],\\\"Version\\\":\\\"2012-10-XX\\\"}\", RequiresNew:false, Sensitive:false, Type:0x0}}, Destroy:false, DestroyDeposed:false, DestroyTainted:false, RawConfig:cty.NilVal, RawState:cty.NilVal, RawPlan:cty.NilVal, Meta:map[string]interface {}(nil)}"}
2024-02-19T00:33:47Z	DEBUG	provider-aws	Successfully requested update of external resource	{"controller": "managed/iam.aws.upbound.io/v1beta1, kind=policy", "request": {"name":"test-policy"}, "uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "version": "8707", "external-name": "test-policy", "requeue-after": "2024-02-19T00:43:55Z"}
2024-02-19T00:33:47Z	DEBUG	provider-aws	Async update starting...	{"trackerUID": "8debb4f5-5058-43be-b639-74f0690d28fc", "resourceName": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy", "tfID": "arn:aws:iam::000000000000:policy/test-policy"}
2024-02-19T00:33:47Z	DEBUG	provider-aws	Updating the external resource	{"uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "name": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy"}
2024-02-19T00:33:47Z	DEBUG	events	Successfully requested update of external resource	{"type": "Normal", "object": {"kind":"Policy","name":"test-policy","uid":"8debb4f5-5058-43be-b639-74f0690d28fc","apiVersion":"iam.aws.upbound.io/v1beta1","resourceVersion":"8707"}, "reason": "UpdatedExternalResource"}
2024-02-19T00:33:47Z	DEBUG	provider-aws	Async update ended.	{"trackerUID": "8debb4f5-5058-43be-b639-74f0690d28fc", "resourceName": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy", "error": "async update failed: failed to update the resource: [{0 updating IAM Policy (arn:aws:iam::000000000000:policy/test-policy): MalformedPolicyDocument: Syntax errors in policy.\n\tstatus code: 400, request id: 257d4ebf-8b7d-4d2a-88f9-e32b4588e637  []}]", "tfID": "arn:aws:iam::000000000000:policy/test-policy"}
2024-02-19T00:33:47Z	DEBUG	provider-aws	Reconcile request has been requeued.	{"gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy", "name": "test-policy", "rateLimiterName": "asyncCallback", "when": "80ms"}
2024-02-19T00:33:47Z	DEBUG	provider-aws	Reconciling	{"controller": "managed/iam.aws.upbound.io/v1beta1, kind=policy", "request": {"name":"test-policy"}}
2024-02-19T00:33:47Z	DEBUG	provider-aws	Connecting to the service provider	{"uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "name": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy"}
2024-02-19T00:33:47Z	DEBUG	provider-aws	Observing the external resource	{"uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "name": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy"}
2024/02/19 00:33:47 [DEBUG] Waiting for state to become: [success]
2024-02-19T00:33:47Z	DEBUG	provider-aws	Diff detected	{"uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "name": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy", "instanceDiff": "*terraform.InstanceDiff{mu:sync.Mutex{state:0, sema:0x0}, Attributes:map[string]*terraform.ResourceAttrDiff{\"policy\":*terraform.ResourceAttrDiff{Old:\"{\\\"Statement\\\":[{\\\"Action\\\":[\\\"sts:GetCallerIdentity\\\"],\\\"Effect\\\":\\\"Allow\\\",\\\"Resource\\\":[\\\"*\\\"]}],\\\"Version\\\":\\\"2012-10-17\\\"}\", New:\"{\\\"Statement\\\":[{\\\"Action\\\":[\\\"sts:GetCallerIdentity\\\"],\\\"Effect\\\":\\\"Allow\\\",\\\"Resource\\\":[\\\"*\\\"]}],\\\"Version\\\":\\\"2012-10-XX\\\"}\", NewComputed:false, NewRemoved:false, NewExtra:\"{\\\"Statement\\\":[{\\\"Action\\\":[\\\"sts:GetCallerIdentity\\\"],\\\"Effect\\\":\\\"Allow\\\",\\\"Resource\\\":[\\\"*\\\"]}],\\\"Version\\\":\\\"2012-10-XX\\\"}\", RequiresNew:false, Sensitive:false, Type:0x0}}, Destroy:false, DestroyDeposed:false, DestroyTainted:false, RawConfig:cty.NilVal, RawState:cty.NilVal, RawPlan:cty.NilVal, Meta:map[string]interface {}(nil)}"}
2024-02-19T00:33:47Z	DEBUG	provider-aws	Successfully requested update of external resource	{"controller": "managed/iam.aws.upbound.io/v1beta1, kind=policy", "request": {"name":"test-policy"}, "uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "version": "8709", "external-name": "test-policy", "requeue-after": "2024-02-19T00:43:44Z"}
2024-02-19T00:33:47Z	DEBUG	provider-aws	Async update starting...	{"trackerUID": "8debb4f5-5058-43be-b639-74f0690d28fc", "resourceName": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy", "tfID": "arn:aws:iam::000000000000:policy/test-policy"}
2024-02-19T00:33:47Z	DEBUG	provider-aws	Updating the external resource	{"uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "name": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy"}
2024-02-19T00:33:47Z	DEBUG	events	Successfully requested update of external resource	{"type": "Normal", "object": {"kind":"Policy","name":"test-policy","uid":"8debb4f5-5058-43be-b639-74f0690d28fc","apiVersion":"iam.aws.upbound.io/v1beta1","resourceVersion":"8709"}, "reason": "UpdatedExternalResource"}
2024-02-19T00:33:47Z	DEBUG	provider-aws	Async update ended.	{"trackerUID": "8debb4f5-5058-43be-b639-74f0690d28fc", "resourceName": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy", "error": "async update failed: failed to update the resource: [{0 updating IAM Policy (arn:aws:iam::000000000000:policy/test-policy): MalformedPolicyDocument: Syntax errors in policy.\n\tstatus code: 400, request id: a0590933-2b49-44b0-bc85-019a6914f2ff  []}]", "tfID": "arn:aws:iam::000000000000:policy/test-policy"}
2024-02-19T00:33:47Z	DEBUG	provider-aws	Reconcile request has been requeued.	{"gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy", "name": "test-policy", "rateLimiterName": "asyncCallback", "when": "160ms"}
2024-02-19T00:33:48Z	DEBUG	provider-aws	Reconciling	{"controller": "managed/iam.aws.upbound.io/v1beta1, kind=policy", "request": {"name":"test-policy"}}
2024-02-19T00:33:48Z	DEBUG	provider-aws	Connecting to the service provider	{"uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "name": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy"}
2024-02-19T00:33:48Z	DEBUG	provider-aws	Observing the external resource	{"uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "name": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy"}
2024/02/19 00:33:48 [DEBUG] Waiting for state to become: [success]
2024-02-19T00:33:48Z	DEBUG	provider-aws	Diff detected	{"uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "name": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy", "instanceDiff": "*terraform.InstanceDiff{mu:sync.Mutex{state:0, sema:0x0}, Attributes:map[string]*terraform.ResourceAttrDiff{\"policy\":*terraform.ResourceAttrDiff{Old:\"{\\\"Statement\\\":[{\\\"Action\\\":[\\\"sts:GetCallerIdentity\\\"],\\\"Effect\\\":\\\"Allow\\\",\\\"Resource\\\":[\\\"*\\\"]}],\\\"Version\\\":\\\"2012-10-17\\\"}\", New:\"{\\\"Statement\\\":[{\\\"Action\\\":[\\\"sts:GetCallerIdentity\\\"],\\\"Effect\\\":\\\"Allow\\\",\\\"Resource\\\":[\\\"*\\\"]}],\\\"Version\\\":\\\"2012-10-XX\\\"}\", NewComputed:false, NewRemoved:false, NewExtra:\"{\\\"Statement\\\":[{\\\"Action\\\":[\\\"sts:GetCallerIdentity\\\"],\\\"Effect\\\":\\\"Allow\\\",\\\"Resource\\\":[\\\"*\\\"]}],\\\"Version\\\":\\\"2012-10-XX\\\"}\", RequiresNew:false, Sensitive:false, Type:0x0}}, Destroy:false, DestroyDeposed:false, DestroyTainted:false, RawConfig:cty.NilVal, RawState:cty.NilVal, RawPlan:cty.NilVal, Meta:map[string]interface {}(nil)}"}
2024-02-19T00:33:48Z	DEBUG	provider-aws	Successfully requested update of external resource	{"controller": "managed/iam.aws.upbound.io/v1beta1, kind=policy", "request": {"name":"test-policy"}, "uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "version": "8712", "external-name": "test-policy", "requeue-after": "2024-02-19T00:43:54Z"}
2024-02-19T00:33:48Z	DEBUG	provider-aws	Async update starting...	{"trackerUID": "8debb4f5-5058-43be-b639-74f0690d28fc", "resourceName": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy", "tfID": "arn:aws:iam::000000000000:policy/test-policy"}
2024-02-19T00:33:48Z	DEBUG	provider-aws	Updating the external resource	{"uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "name": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy"}
2024-02-19T00:33:48Z	DEBUG	events	Successfully requested update of external resource	{"type": "Normal", "object": {"kind":"Policy","name":"test-policy","uid":"8debb4f5-5058-43be-b639-74f0690d28fc","apiVersion":"iam.aws.upbound.io/v1beta1","resourceVersion":"8712"}, "reason": "UpdatedExternalResource"}
2024-02-19T00:33:48Z	DEBUG	provider-aws	Async update ended.	{"trackerUID": "8debb4f5-5058-43be-b639-74f0690d28fc", "resourceName": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy", "error": "async update failed: failed to update the resource: [{0 updating IAM Policy (arn:aws:iam::000000000000:policy/test-policy): MalformedPolicyDocument: Syntax errors in policy.\n\tstatus code: 400, request id: 3d7afdbf-f9a5-40e7-baae-4f8dbc175fd0  []}]", "tfID": "arn:aws:iam::000000000000:policy/test-policy"}
2024-02-19T00:33:48Z	DEBUG	provider-aws	Reconcile request has been requeued.	{"gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy", "name": "test-policy", "rateLimiterName": "asyncCallback", "when": "320ms"}
2024-02-19T00:33:48Z	DEBUG	provider-aws	Reconciling	{"controller": "managed/iam.aws.upbound.io/v1beta1, kind=policy", "request": {"name":"test-policy"}}
2024-02-19T00:33:48Z	DEBUG	provider-aws	Connecting to the service provider	{"uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "name": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy"}
2024-02-19T00:33:48Z	DEBUG	provider-aws	Observing the external resource	{"uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "name": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy"}
2024/02/19 00:33:48 [DEBUG] Waiting for state to become: [success]
2024-02-19T00:33:48Z	DEBUG	provider-aws	Diff detected	{"uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "name": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy", "instanceDiff": "*terraform.InstanceDiff{mu:sync.Mutex{state:0, sema:0x0}, Attributes:map[string]*terraform.ResourceAttrDiff{\"policy\":*terraform.ResourceAttrDiff{Old:\"{\\\"Statement\\\":[{\\\"Action\\\":[\\\"sts:GetCallerIdentity\\\"],\\\"Effect\\\":\\\"Allow\\\",\\\"Resource\\\":[\\\"*\\\"]}],\\\"Version\\\":\\\"2012-10-17\\\"}\", New:\"{\\\"Statement\\\":[{\\\"Action\\\":[\\\"sts:GetCallerIdentity\\\"],\\\"Effect\\\":\\\"Allow\\\",\\\"Resource\\\":[\\\"*\\\"]}],\\\"Version\\\":\\\"2012-10-XX\\\"}\", NewComputed:false, NewRemoved:false, NewExtra:\"{\\\"Statement\\\":[{\\\"Action\\\":[\\\"sts:GetCallerIdentity\\\"],\\\"Effect\\\":\\\"Allow\\\",\\\"Resource\\\":[\\\"*\\\"]}],\\\"Version\\\":\\\"2012-10-XX\\\"}\", RequiresNew:false, Sensitive:false, Type:0x0}}, Destroy:false, DestroyDeposed:false, DestroyTainted:false, RawConfig:cty.NilVal, RawState:cty.NilVal, RawPlan:cty.NilVal, Meta:map[string]interface {}(nil)}"}
2024-02-19T00:33:48Z	DEBUG	provider-aws	Successfully requested update of external resource	{"controller": "managed/iam.aws.upbound.io/v1beta1, kind=policy", "request": {"name":"test-policy"}, "uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "version": "8714", "external-name": "test-policy", "requeue-after": "2024-02-19T00:43:42Z"}
2024-02-19T00:33:48Z	DEBUG	provider-aws	Async update starting...	{"trackerUID": "8debb4f5-5058-43be-b639-74f0690d28fc", "resourceName": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy", "tfID": "arn:aws:iam::000000000000:policy/test-policy"}
2024-02-19T00:33:48Z	DEBUG	provider-aws	Updating the external resource	{"uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "name": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy"}
2024-02-19T00:33:48Z	DEBUG	events	Successfully requested update of external resource	{"type": "Normal", "object": {"kind":"Policy","name":"test-policy","uid":"8debb4f5-5058-43be-b639-74f0690d28fc","apiVersion":"iam.aws.upbound.io/v1beta1","resourceVersion":"8714"}, "reason": "UpdatedExternalResource"}
2024-02-19T00:33:48Z	DEBUG	provider-aws	Async update ended.	{"trackerUID": "8debb4f5-5058-43be-b639-74f0690d28fc", "resourceName": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy", "error": "async update failed: failed to update the resource: [{0 updating IAM Policy (arn:aws:iam::000000000000:policy/test-policy): MalformedPolicyDocument: Syntax errors in policy.\n\tstatus code: 400, request id: 9281b162-b398-456f-a46b-6bcd4be9f380  []}]", "tfID": "arn:aws:iam::000000000000:policy/test-policy"}
2024-02-19T00:33:48Z	DEBUG	provider-aws	Reconcile request has been requeued.	{"gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy", "name": "test-policy", "rateLimiterName": "asyncCallback", "when": "640ms"}
2024-02-19T00:33:49Z	DEBUG	provider-aws	Reconciling	{"controller": "managed/iam.aws.upbound.io/v1beta1, kind=policy", "request": {"name":"test-policy"}}
2024-02-19T00:33:49Z	DEBUG	provider-aws	Connecting to the service provider	{"uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "name": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy"}
2024-02-19T00:33:49Z	DEBUG	provider-aws	Observing the external resource	{"uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "name": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy"}
2024/02/19 00:33:49 [DEBUG] Waiting for state to become: [success]
2024-02-19T00:33:49Z	DEBUG	provider-aws	Diff detected	{"uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "name": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy", "instanceDiff": "*terraform.InstanceDiff{mu:sync.Mutex{state:0, sema:0x0}, Attributes:map[string]*terraform.ResourceAttrDiff{\"policy\":*terraform.ResourceAttrDiff{Old:\"{\\\"Statement\\\":[{\\\"Action\\\":[\\\"sts:GetCallerIdentity\\\"],\\\"Effect\\\":\\\"Allow\\\",\\\"Resource\\\":[\\\"*\\\"]}],\\\"Version\\\":\\\"2012-10-17\\\"}\", New:\"{\\\"Statement\\\":[{\\\"Action\\\":[\\\"sts:GetCallerIdentity\\\"],\\\"Effect\\\":\\\"Allow\\\",\\\"Resource\\\":[\\\"*\\\"]}],\\\"Version\\\":\\\"2012-10-XX\\\"}\", NewComputed:false, NewRemoved:false, NewExtra:\"{\\\"Statement\\\":[{\\\"Action\\\":[\\\"sts:GetCallerIdentity\\\"],\\\"Effect\\\":\\\"Allow\\\",\\\"Resource\\\":[\\\"*\\\"]}],\\\"Version\\\":\\\"2012-10-XX\\\"}\", RequiresNew:false, Sensitive:false, Type:0x0}}, Destroy:false, DestroyDeposed:false, DestroyTainted:false, RawConfig:cty.NilVal, RawState:cty.NilVal, RawPlan:cty.NilVal, Meta:map[string]interface {}(nil)}"}
2024-02-19T00:33:49Z	DEBUG	provider-aws	Successfully requested update of external resource	{"controller": "managed/iam.aws.upbound.io/v1beta1, kind=policy", "request": {"name":"test-policy"}, "uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "version": "8716", "external-name": "test-policy", "requeue-after": "2024-02-19T00:44:07Z"}
2024-02-19T00:33:49Z	DEBUG	provider-aws	Async update starting...	{"trackerUID": "8debb4f5-5058-43be-b639-74f0690d28fc", "resourceName": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy", "tfID": "arn:aws:iam::000000000000:policy/test-policy"}
2024-02-19T00:33:49Z	DEBUG	provider-aws	Updating the external resource	{"uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "name": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy"}
2024-02-19T00:33:49Z	DEBUG	events	Successfully requested update of external resource	{"type": "Normal", "object": {"kind":"Policy","name":"test-policy","uid":"8debb4f5-5058-43be-b639-74f0690d28fc","apiVersion":"iam.aws.upbound.io/v1beta1","resourceVersion":"8716"}, "reason": "UpdatedExternalResource"}
2024-02-19T00:33:49Z	DEBUG	provider-aws	Async update ended.	{"trackerUID": "8debb4f5-5058-43be-b639-74f0690d28fc", "resourceName": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy", "error": "async update failed: failed to update the resource: [{0 updating IAM Policy (arn:aws:iam::000000000000:policy/test-policy): MalformedPolicyDocument: Syntax errors in policy.\n\tstatus code: 400, request id: b6047708-3857-4b4f-b83a-cd5f9a0d694f  []}]", "tfID": "arn:aws:iam::000000000000:policy/test-policy"}
2024-02-19T00:33:49Z	DEBUG	provider-aws	Reconcile request has been requeued.	{"gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy", "name": "test-policy", "rateLimiterName": "asyncCallback", "when": "1.28s"}
2024-02-19T00:33:50Z	DEBUG	provider-aws	Reconciling	{"controller": "managed/iam.aws.upbound.io/v1beta1, kind=policy", "request": {"name":"test-policy"}}
2024-02-19T00:33:50Z	DEBUG	provider-aws	Connecting to the service provider	{"uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "name": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy"}
2024-02-19T00:33:50Z	DEBUG	provider-aws	Observing the external resource	{"uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "name": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy"}
2024/02/19 00:33:50 [DEBUG] Waiting for state to become: [success]
2024-02-19T00:33:50Z	DEBUG	provider-aws	Diff detected	{"uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "name": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy", "instanceDiff": "*terraform.InstanceDiff{mu:sync.Mutex{state:0, sema:0x0}, Attributes:map[string]*terraform.ResourceAttrDiff{\"policy\":*terraform.ResourceAttrDiff{Old:\"{\\\"Statement\\\":[{\\\"Action\\\":[\\\"sts:GetCallerIdentity\\\"],\\\"Effect\\\":\\\"Allow\\\",\\\"Resource\\\":[\\\"*\\\"]}],\\\"Version\\\":\\\"2012-10-17\\\"}\", New:\"{\\\"Statement\\\":[{\\\"Action\\\":[\\\"sts:GetCallerIdentity\\\"],\\\"Effect\\\":\\\"Allow\\\",\\\"Resource\\\":[\\\"*\\\"]}],\\\"Version\\\":\\\"2012-10-XX\\\"}\", NewComputed:false, NewRemoved:false, NewExtra:\"{\\\"Statement\\\":[{\\\"Action\\\":[\\\"sts:GetCallerIdentity\\\"],\\\"Effect\\\":\\\"Allow\\\",\\\"Resource\\\":[\\\"*\\\"]}],\\\"Version\\\":\\\"2012-10-XX\\\"}\", RequiresNew:false, Sensitive:false, Type:0x0}}, Destroy:false, DestroyDeposed:false, DestroyTainted:false, RawConfig:cty.NilVal, RawState:cty.NilVal, RawPlan:cty.NilVal, Meta:map[string]interface {}(nil)}"}
2024-02-19T00:33:50Z	DEBUG	provider-aws	Successfully requested update of external resource	{"controller": "managed/iam.aws.upbound.io/v1beta1, kind=policy", "request": {"name":"test-policy"}, "uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "version": "8720", "external-name": "test-policy", "requeue-after": "2024-02-19T00:43:52Z"}
2024-02-19T00:33:50Z	DEBUG	provider-aws	Async update starting...	{"trackerUID": "8debb4f5-5058-43be-b639-74f0690d28fc", "resourceName": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy", "tfID": "arn:aws:iam::000000000000:policy/test-policy"}
2024-02-19T00:33:50Z	DEBUG	provider-aws	Updating the external resource	{"uid": "8debb4f5-5058-43be-b639-74f0690d28fc", "name": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy"}
2024-02-19T00:33:50Z	DEBUG	events	Successfully requested update of external resource	{"type": "Normal", "object": {"kind":"Policy","name":"test-policy","uid":"8debb4f5-5058-43be-b639-74f0690d28fc","apiVersion":"iam.aws.upbound.io/v1beta1","resourceVersion":"8720"}, "reason": "UpdatedExternalResource"}
2024-02-19T00:33:50Z	DEBUG	provider-aws	Async update ended.	{"trackerUID": "8debb4f5-5058-43be-b639-74f0690d28fc", "resourceName": "test-policy", "gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy", "error": "async update failed: failed to update the resource: [{0 updating IAM Policy (arn:aws:iam::000000000000:policy/test-policy): MalformedPolicyDocument: Syntax errors in policy.\n\tstatus code: 400, request id: a951d1ea-bfae-4596-905a-72b93dc25ed5  []}]", "tfID": "arn:aws:iam::000000000000:policy/test-policy"}
2024-02-19T00:33:50Z	DEBUG	provider-aws	Reconcile request has been requeued.	{"gvk": "iam.aws.upbound.io/v1beta1, Kind=Policy", "name": "test-policy", "rateLimiterName": "asyncCallback", "when": "2.56s"}
@diranged diranged added bug Something isn't working needs:triage labels Feb 19, 2024
@kirek007
Copy link

+1
I think the same, if update failed there must be a very clear indication.

@fernandezcuesta
Copy link

fernandezcuesta commented Mar 13, 2024 •
edited
Loading

Same here, tested with provider-aws versions 0.47.1, 0.47.3 and 1.1.1

@turkenf
Copy link
Collaborator

turkenf commented Mar 15, 2024

Hello folks,

Thank you for bringing up this issue. The issue can be reproduced with provider version 1.2.0.

  conditions:
  - lastTransitionTime: "2024-03-15T12:44:47Z"
    reason: Available
    status: "True"
    type: Ready
  - lastTransitionTime: "2024-03-15T12:44:45Z"
    reason: ReconcileSuccess
    status: "True"
    type: Synced
  - lastTransitionTime: "2024-03-15T12:58:10Z"
    message: "async update failed: failed to update the resource: [{0 updating IAM
      Policy (arn:aws:iam::153891904029:policy/test-policy): MalformedPolicyDocument:
      Syntax errors in policy.\n\tstatus code: 400, request id: df76c3f4-b3a3-4c3c-8e3f-c10ed5855a39
      \ []}]"
    reason: AsyncUpdateFailure
    status: "False"
    type: LastAsyncOperation

Also tried with v0.43.0:

  conditions:
  - lastTransitionTime: "2024-03-15T13:08:41Z"
    reason: Available
    status: "True"
    type: Ready
  - lastTransitionTime: "2024-03-15T13:08:35Z"
    reason: ReconcileSuccess
    status: "True"
    type: Synced
  - lastTransitionTime: "2024-03-15T13:11:19Z"
    message: "apply failed: updating IAM Policy (arn:aws:iam::153891904029:policy/test-policy):
      MalformedPolicyDocument: Syntax errors in policy.\n\tstatus code: 400, request
      id: 53e62d1a-5bc1-41fc-a5df-aecc9c13a292: "
    reason: ApplyFailure
    status: "False"
    type: LastAsyncOperation
  - lastTransitionTime: "2024-03-15T13:08:38Z"
    reason: Finished
    status: "True"
    type: AsyncOperation

@turkenf turkenf added is:triaged Indicates that an issue has been reviewed. and removed needs:triage labels Mar 15, 2024
@alebsack
Copy link

I'm seeing the same issue with provider-azure-storage v1.0.1, when trying to set infrastructureEncryptionEnabled.

Here is the status YAML, showing that the resource is still Synced and Ready:

  conditions:
    - lastTransitionTime: '2024-04-11T18:05:09Z'
      reason: Available
      status: 'True'
      type: Ready
    - lastTransitionTime: '2024-04-11T18:03:46Z'
      reason: ReconcileSuccess
      status: 'True'
      type: Synced
    - lastTransitionTime: '2024-04-11T18:09:08Z'
      message: >-
        async update failed: refuse to update the external resource because the
        following update requires replacing it: cannot change the value of the
        argument "infrastructure_encryption_enabled" from "false" to "true"
      reason: AsyncUpdateFailure
      status: 'False'
      type: LastAsyncOperation

When this failure does not bubble up to the Claim resource, users are led to believe that the change was successful.

@erhancagirici
Copy link
Collaborator

@diranged thanks for reporting this.
this is caused by a current limitation in handling of async operations.

Currently, managed resource reconciler Update() code spawns a goroutine to do the actual cloud resource update and returns. The purpose of the async mode is to execute long-running upstream resource updates that could possibly exceed the MR reconciliation timeouts and avoid early termination of ongoing operation.

From MR reconciler perspective, the update reconciliation is successful, as it successfully completes the Update() call successfully (by spawning the update goroutine) , therefore "synced" state stays true.
The async routine executes a callback when it is completed, updating the LastAsyncOperation condition with the result. In case of an update failure , ideally, as mentioned this should set the Synced condition to False. Currently, synced condition cannot be updated in the callback, as it causes a race between the MR reconciler status updates and the callback status updates.

For the sake of completeness, per Crossplane Resource Model (XRM) this situation should result in synced=false rather than ready=false. The case here is that, the upstream cloud resource is still functional and "ready", however it is "drifted" from the new desired state, and the new desired state causes a reconciliation error, which cannot be "synced". Readiness is more related to the upstream resource health and being operational at upstream cloud (e.g. it is successfully provisioned, can be consumed etc).

Anyways, we consider this as a valid request and investigate possible solutions and address the issue.

@erhancagirici erhancagirici mentioned this issue Apr 16, 2024
Closed
1 task
@diranged
Copy link
Author

Thanks for the thoughtful and helpful response... I appreciate you guys looking into how to make the experience better!

@ulucinar ulucinar mentioned this issue Apr 24, 2024
Merged
3 tasks
@turkenf
Copy link
Collaborator

turkenf commented Apr 25, 2024

I'm closing this issue because we introduced a fix for the issue in provider v1.4.0

@turkenf turkenf closed this as completed Apr 25, 2024
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 community is:triaged Indicates that an issue has been reviewed.
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
7 participants
@alebsack @jeanduplessis @diranged @kirek007 @fernandezcuesta @turkenf @erhancagirici