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.

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

KEDA scaler not working on AKS with trigger authentication using pod identity #2178

Closed
iarunpaul opened this issue Oct 10, 2021 · 48 comments
Closed
Assignees
Labels
bug Something isn't working stale All issues that are marked as stale due to inactivity

Comments

@iarunpaul
Copy link

iarunpaul commented Oct 10, 2021

Report

KEDA scaler not scales with scaled object defined with trigger using pod identity for authentication for service bus queue.
I'm following this KEDA service bus triggered scaling project.
The scaling works fine with the connection string, but when I try to scale using the pod identity for KEDA scaler the keda operator fails to get the azure identity bound to it with the following keda operator error message log:

github.com/kedacore/keda/v2/pkg/scaling.(*scaleHandler).isScaledObjectActive
        /workspace/pkg/scaling/scale_handler.go:228
github.com/kedacore/keda/v2/pkg/scaling.(*scaleHandler).checkScalers
        /workspace/pkg/scaling/scale_handler.go:211
github.com/kedacore/keda/v2/pkg/scaling.(*scaleHandler).startScaleLoop
        /workspace/pkg/scaling/scale_handler.go:145
2021-10-10T17:35:53.916Z        ERROR   azure_servicebus_scaler error   {"error": "failed to refresh token, error: adal: Refresh request failed. Status Code = '400'. Response body: {\"error\":\"invalid_request\",\"error_description\":\"Identity not found\"}\n"}

My scaler objects' definition is as below:

apiVersion: keda.sh/v1alpha1
kind: TriggerAuthentication
metadata:
  name: trigger-auth-service-bus-orders
spec:
  podIdentity:
    provider: azure
---
apiVersion: keda.sh/v1alpha1 
kind: ScaledObject
metadata:
  name: order-scaler
spec:
  scaleTargetRef:
    name: order-processor
  # minReplicaCount: 0 Change to define how many minimum replicas you want
  maxReplicaCount: 10
  triggers:
  - type: azure-servicebus
    metadata:
      namespace: demodemobus
      queueName: orders
      messageCount: '5'
    authenticationRef:
      name: trigger-auth-service-bus-orders

Im deploying the azure identity to the namespace keda where my keda deployment resides.
And installs KEDA with the following command to set the pod identity binding using helm:

helm install keda kedacore/keda --set podIdentity.activeDirectory.identity=app-autoscaler --namespace keda

Expected Behavior

The KEDA scaler should have worked fine with the assigned pod identity and access token to perform scaling

Actual Behavior

The KEDA operator could not be able to find the azure identity assigned and scaling fails

Steps to Reproduce the Problem

  1. Create the azure identity and bindings for the KEDA
  2. Install KEDA with the aadpodidentitybinding
  3. Create the scaledobject and triggerauthentication using KEDA pod identity
  4. The scaler fails to authenticate and scale

Logs from KEDA operator

github.com/kedacore/keda/v2/pkg/scaling.(*scaleHandler).isScaledObjectActive
        /workspace/pkg/scaling/scale_handler.go:228
github.com/kedacore/keda/v2/pkg/scaling.(*scaleHandler).checkScalers
        /workspace/pkg/scaling/scale_handler.go:211
github.com/kedacore/keda/v2/pkg/scaling.(*scaleHandler).startScaleLoop
        /workspace/pkg/scaling/scale_handler.go:145
2021-10-10T17:41:54.909Z        ERROR   azure_servicebus_scaler error   {"error": "failed to refresh token, error: adal: Refresh request failed. Status Code = '400'. Response body: {\"error\":\"invalid_request\",\"error_description\":\"Identity not found\"}\n"}

KEDA Version

No response

Kubernetes Version

1.20

Platform

Microsoft Azure

Scaler Details

Azure Service Bus

Anything else?

No response

@iarunpaul iarunpaul added the bug Something isn't working label Oct 10, 2021
@JorTurFer
Copy link
Member

Hi @iarunpaul ,
What version of KEDA are you using? I'll try to take a look at this the week

@iarunpaul
Copy link
Author

iarunpaul commented Nov 6, 2021

Hi @iarunpaul , What version of KEDA are you using? I'll try to take a look at this the week

KEDA 2.4.0

@JorTurFer
Copy link
Member

Hi @iarunpaul,
First, please ignore the github-bot reaction, it's an error in new workflow that we have merged a few days ago. We are working to fix it, but I'd like to apologize.
Second, I will try to test it ASAP. Are you getting this error after some time or directly?

@iarunpaul
Copy link
Author

iarunpaul commented Nov 6, 2021

Hi @iarunpaul, First, please ignore the github-bot reaction, it's an error in new workflow that we have merged a few days ago. We are working to fix it, but I'd like to apologize. Second, I will try to test it ASAP. Are you getting this error after some time or directly?

Hi @JorTurFer Its an immediate failure as we try to change the trigger auth from connection string secret to pod identity of KEDA

@iarunpaul
Copy link
Author

Hi @JorTurFer, Any updates on your run?

@JorTurFer
Copy link
Member

hi @iarunpaul ,
I will take a look during this week sorry, today is Sunday and I don't touch the computer :)

@JorTurFer
Copy link
Member

hi again @iarunpaul ,
Finally I found time to take a look at this. I deployed KEDA (v2.4) using helm in a cluster with AAD Pod Identity (deployed with helm too) and a workload with Service Bus Scaler. It works without any other problem.

Reviewing the logs that you sent, the issue seems that is related with any misconfiguration in AAD Pod Identity side. You should take a look there because probably anything is missing there. Is the MSI correctly assigned to the node virtual machines? Is there any error in the MIC or NMI pod logs (aad-pod-identity)?

For me it is weird that the error says Identity not found 🤔

@iarunpaul
Copy link
Author

Hi @JorTurFer,
I was not using the helm for AAD Pod Identity deployment. I will check it and update

@JorTurFer
Copy link
Member

How did you deploy AAD Pod Identity?
I think that the deployment method could not be important. If the logs in the AAD Pod Identity pods show an error, we have to solve it in order to can use it :)
You should check that them and if you can't see anything strange there, check that the MSI is correctly assigned to the node group VMSS

@iarunpaul
Copy link
Author

I am installing the AAD Pod Identity using helm, assigning required roles for the cluster, "Managed Identity Operator" and "Virtual Machine Contributor"to the and installing keda using helm
kubectl apply -f .\deploy\deploy-app-autoscaling.yaml --namespace keda-dotnet-sample
Still the KEDA operator logs give error as below:

2021-11-08T20:09:17.170Z        ERROR   azure_servicebus_scaler error   {"error": "Get \"http://169.254.169.254/metadata/identity/oauth2/token?api-version=2018-02-01&resource=https%3A%2F%2Fservicebus.azure.net%2F\": context deadline exceeded (Client.Timeout exceeded while awaiting headers)"}
github.com/kedacore/keda/v2/pkg/scaling.(*scaleHandler).isScaledObjectActive
        /workspace/pkg/scaling/scale_handler.go:228
github.com/kedacore/keda/v2/pkg/scaling.(*scaleHandler).checkScalers
        /workspace/pkg/scaling/scale_handler.go:211
github.com/kedacore/keda/v2/pkg/scaling.(*scaleHandler).startScaleLoop
        /workspace/pkg/scaling/scale_handler.go:145

@iarunpaul
Copy link
Author

The pod aad-pod-identity-mic-6497465fcb-6v7x8 logs are:

I1108 18:56:04.264457       1 main.go:114] starting mic process. Version: v1.8.5. Build date: 2021-10-11-23:36
W1108 18:56:04.264644       1 main.go:119] --kubeconfig not passed will use InClusterConfig
I1108 18:56:04.264715       1 main.go:136] kubeconfig () cloudconfig (/etc/kubernetes/azure.json)
I1108 18:56:04.264896       1 main.go:144] running MIC in namespaced mode: false
I1108 18:56:04.264966       1 main.go:148] client QPS set to: 5. Burst to: 5
I1108 18:56:04.265044       1 mic.go:138] starting to create the pod identity client. Version: v1.8.5. Build date: 2021-10-11-23:36
I1108 18:56:04.330080       1 mic.go:144] Kubernetes server version: v1.20.9
I1108 18:56:04.330587       1 cloudprovider.go:122] MIC using user assigned identity: eb1e##### REDACTED #####a204 for authentication.
I1108 18:56:04.334873       1 probes.go:41] initialized health probe on port 8080
I1108 18:56:04.335070       1 probes.go:44] started health probe
I1108 18:56:04.335585       1 metrics.go:341] registered views for metric
I1108 18:56:04.335764       1 prometheus_exporter.go:21] starting Prometheus exporter
I1108 18:56:04.335911       1 metrics.go:347] registered and exported metrics on port 8888
I1108 18:56:04.336009       1 mic.go:242] initiating MIC Leader election
I1108 18:56:04.336102       1 leaderelection.go:248] attempting to acquire leader lease default/aad-pod-identity-mic...

And
for aad-pod-identity-nmi-4gk7k:

I1108 18:56:01.926626       1 main.go:87] starting nmi process. Version: v1.8.5. Build date: 2021-10-11-23:37.
I1108 18:56:01.926676       1 main.go:100] features for scale clusters enabled
I1108 18:56:02.131229       1 crd.go:448] CRD lite informers started
I1108 18:56:02.131275       1 main.go:114] running NMI in namespaced mode: false
I1108 18:56:02.131285       1 nmi.go:53] initializing in standard mode
I1108 18:56:02.131291       1 probes.go:41] initialized health probe on port 8085
I1108 18:56:02.131301       1 probes.go:44] started health probe
I1108 18:56:02.131388       1 metrics.go:341] registered views for metric
I1108 18:56:02.131431       1 prometheus_exporter.go:21] starting Prometheus exporter
I1108 18:56:02.131438       1 metrics.go:347] registered and exported metrics on port 9090
I1108 18:56:02.131523       1 server.go:105] listening on port 2579
W1108 18:56:02.165922       1 iptables.go:123] flushing iptables to add aad-metadata custom chains
E1108 18:56:04.126735       1 server.go:329] metadata header is not specified, req.method=GET reg.path=/metadata/identity/oauth2/token req.remote=10.240.0.10
I1108 18:56:04.126807       1 server.go:199] status (400) took 89402 ns for req.method=GET reg.path=/metadata/identity/oauth2/token req.remote=10.240.0.10
I1108 19:30:55.842402       1 server.go:365] exception pod default/aad-pod-identity-mic-6497465fcb-872ch token handling
I1108 19:30:55.842424       1 server.go:308] fetching token for user assigned MSI for resource: https://management.azure.com/
I1108 19:30:56.269385       1 server.go:199] status (200) took 427067803 ns for req.method=GET reg.path=/metadata/identity/oauth2/token req.remote=10.240.0.10

Not looking promising for me.
Could you please advise where to start digging?

@JorTurFer
Copy link
Member

Hi @iarunpaul ,
The problem is in AAD pod identity side I think seeing these logs. Could you share the logs from the aad-pod-identity-mic pods? Probably there we can find any issue.

@iarunpaul
Copy link
Author

aad-pod-identity-mic-6497465fcb-6v7x8 logs:

I1108 18:56:04.264457       1 main.go:114] starting mic process. Version: v1.8.5. Build date: 2021-10-11-23:36
W1108 18:56:04.264644       1 main.go:119] --kubeconfig not passed will use InClusterConfig
I1108 18:56:04.264715       1 main.go:136] kubeconfig () cloudconfig (/etc/kubernetes/azure.json)
I1108 18:56:04.264896       1 main.go:144] running MIC in namespaced mode: false
I1108 18:56:04.264966       1 main.go:148] client QPS set to: 5. Burst to: 5
I1108 18:56:04.265044       1 mic.go:138] starting to create the pod identity client. Version: v1.8.5. Build date: 2021-10-11-23:36
I1108 18:56:04.330080       1 mic.go:144] Kubernetes server version: v1.20.9
I1108 18:56:04.330587       1 cloudprovider.go:122] MIC using user assigned identity: eb1e##### REDACTED #####a204 for authentication.
I1108 18:56:04.334873       1 probes.go:41] initialized health probe on port 8080
I1108 18:56:04.335070       1 probes.go:44] started health probe
I1108 18:56:04.335585       1 metrics.go:341] registered views for metric
I1108 18:56:04.335764       1 prometheus_exporter.go:21] starting Prometheus exporter
I1108 18:56:04.335911       1 metrics.go:347] registered and exported metrics on port 8888
I1108 18:56:04.336009       1 mic.go:242] initiating MIC Leader election
I1108 18:56:04.336102       1 leaderelection.go:248] attempting to acquire leader lease default/aad-pod-identity-mic...

@JorTurFer
Copy link
Member

JorTurFer commented Nov 8, 2021

hi @iarunpaul
Is there a second instance? I can see that this pod (aad-pod-identity-mic-6497465fcb-6v7x8) is waiting until leader election, so there are 2 options:
1- There is another instance which is the leader (and I will need its logs)
2- There isn't any other instance, so after a few seconds this pod will prompt other messages, and I need them :)

@iarunpaul
Copy link
Author

the logs for aad-pod-identity-mic-6497465fcb-pjn5t:

the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/order-processor-id' or the linked scope(s) are invalid."
E1108 21:03:08.258262       1 mic.go:1129] failed to apply binding keda-dotnet-sample/order-processor-id-binding node aks-agentpool-14229154-vmss000002 for pod keda-dotnet-sample/order-processor-589f9b8645-4s5sm, error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/order-processor-id' or the linked scope(s) are invalid."
I1108 21:03:08.258296       1 mic.go:525] work done: true. Found 1 pods, 1 ids, 1 bindings
I1108 21:03:08.258303       1 mic.go:526] total work cycles: 43, out of which work was done in: 1
I1108 21:03:08.258310       1 stats.go:183] ** stats collected **
I1108 21:03:08.258314       1 stats.go:162] Pod listing: 19.702µs
I1108 21:03:08.258321       1 stats.go:162] AzureIdentity listing: 2.5µs
I1108 21:03:08.258324       1 stats.go:162] AzureIdentityBinding listing: 5.6µs
I1108 21:03:08.258328       1 stats.go:162] AzureAssignedIdentity listing: 600ns
I1108 21:03:08.258331       1 stats.go:162] System: 70.605µs
I1108 21:03:08.258334       1 stats.go:162] CacheSync: 9µs
I1108 21:03:08.258337       1 stats.go:162] Cloud provider GET: 719.766959ms
I1108 21:03:08.258341       1 stats.go:162] Cloud provider PATCH: 0s
I1108 21:03:08.258345       1 stats.go:162] AzureAssignedIdentity creation: 17.568692ms
I1108 21:03:08.258348       1 stats.go:162] AzureAssignedIdentity update: 0s
I1108 21:03:08.258351       1 stats.go:162] AzureAssignedIdentity deletion: 0s
I1108 21:03:08.258355       1 stats.go:170] Number of cloud provider PATCH: 0
I1108 21:03:08.258358       1 stats.go:170] Number of cloud provider GET: 2
I1108 21:03:08.258361       1 stats.go:170] Number of AzureAssignedIdentities created in this sync cycle: 0
I1108 21:03:08.258364       1 stats.go:170] Number of AzureAssignedIdentities updated in this sync cycle: 0
I1108 21:03:08.258367       1 stats.go:170] Number of AzureAssignedIdentities deleted in this sync cycle: 0
I1108 21:03:08.258371       1 stats.go:162] Find AzureAssignedIdentities to create: 0s
I1108 21:03:08.258375       1 stats.go:162] Find AzureAssignedIdentities to delete: 0s
I1108 21:03:08.258380       1 stats.go:162] Total time to assign or update AzureAssignedIdentities: 737.827982ms
I1108 21:03:08.258383       1 stats.go:162] Total: 737.988991ms
I1108 21:03:08.258386       1 stats.go:212] *********************
I1108 21:10:16.119421       1 mic.go:1040] processing node aks-agentpool-14229154-vmss, add [1], del [0], update [0]
I1108 21:10:16.172169       1 cloudprovider.go:215] updating user-assigned identities on aks-agentpool-14229154-vmss, assign [1], unassign [0]
I1108 21:10:16.223346       1 cloudprovider.go:229] removing /subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/order-processor-id from ID list since it is erroneous
E1108 21:10:16.223374       1 mic.go:1111] failed to update user-assigned identities on node aks-agentpool-14229154-vmss (add [1], del [0], update[0]), error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/order-processor-id' or the linked scope(s) are invalid."
E1108 21:10:16.305905       1 mic.go:1129] failed to apply binding keda-dotnet-sample/order-processor-id-binding node aks-agentpool-14229154-vmss000002 for pod keda-dotnet-sample/order-processor-589f9b8645-4s5sm, error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/order-processor-id' or the linked scope(s) are invalid."
I1108 21:10:16.305936       1 mic.go:525] work done: true. Found 1 pods, 2 ids, 1 bindings
I1108 21:10:16.305942       1 mic.go:526] total work cycles: 44, out of which work was done in: 2
I1108 21:10:16.305950       1 stats.go:183] ** stats collected **
I1108 21:10:16.305982       1 stats.go:162] Pod listing: 42.402µs
I1108 21:10:16.306061       1 stats.go:162] AzureIdentity listing: 8.2µs
I1108 21:10:16.306089       1 stats.go:162] AzureIdentityBinding listing: 6.601µs
I1108 21:10:16.306126       1 stats.go:162] AzureAssignedIdentity listing: 59.803µs
I1108 21:10:16.306161       1 stats.go:162] System: 194.511µs
I1108 21:10:16.306181       1 stats.go:162] CacheSync: 12.101µs
I1108 21:10:16.306221       1 stats.go:162] Cloud provider GET: 186.359292ms
I1108 21:10:16.306256       1 stats.go:162] Cloud provider PATCH: 0s
I1108 21:10:16.306306       1 stats.go:162] AzureAssignedIdentity creation: 0s
I1108 21:10:16.306337       1 stats.go:162] AzureAssignedIdentity update: 0s
I1108 21:10:16.306356       1 stats.go:162] AzureAssignedIdentity deletion: 0s
I1108 21:10:16.306371       1 stats.go:170] Number of cloud provider PATCH: 0
I1108 21:10:16.306386       1 stats.go:170] Number of cloud provider GET: 2
I1108 21:10:16.306414       1 stats.go:170] Number of AzureAssignedIdentities created in this sync cycle: 0
I1108 21:10:16.306438       1 stats.go:170] Number of AzureAssignedIdentities updated in this sync cycle: 0
I1108 21:10:16.306454       1 stats.go:170] Number of AzureAssignedIdentities deleted in this sync cycle: 0
I1108 21:10:16.306469       1 stats.go:162] Find AzureAssignedIdentities to create: 5µs
I1108 21:10:16.306484       1 stats.go:162] Find AzureAssignedIdentities to delete: 1.9µs
I1108 21:10:16.306500       1 stats.go:162] Total time to assign or update AzureAssignedIdentities: 186.508ms
I1108 21:10:16.306536       1 stats.go:162] Total: 186.821619ms
I1108 21:10:16.306569       1 stats.go:212] *********************
I1108 21:10:16.598188       1 mic.go:1040] processing node aks-agentpool-14229154-vmss, add [1], del [0], update [0]
I1108 21:10:16.631684       1 cloudprovider.go:215] updating user-assigned identities on aks-agentpool-14229154-vmss, assign [1], unassign [0]
I1108 21:10:16.653486       1 cloudprovider.go:229] removing /subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/order-processor-id from ID list since it is erroneous
E1108 21:10:16.653508       1 mic.go:1111] failed to update user-assigned identities on node aks-agentpool-14229154-vmss (add [1], del [0], update[0]), error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/order-processor-id' or the linked scope(s) are invalid."
E1108 21:10:16.836483       1 mic.go:1129] failed to apply binding keda-dotnet-sample/order-processor-id-binding node aks-agentpool-14229154-vmss000002 for pod keda-dotnet-sample/order-processor-589f9b8645-4s5sm, error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/order-processor-id' or the linked scope(s) are invalid."
I1108 21:10:16.836514       1 mic.go:525] work done: true. Found 1 pods, 2 ids, 2 bindings
I1108 21:10:16.836521       1 mic.go:526] total work cycles: 45, out of which work was done in: 3
I1108 21:10:16.836529       1 stats.go:183] ** stats collected **
I1108 21:10:16.836533       1 stats.go:162] Pod listing: 27.602µs
I1108 21:10:16.836542       1 stats.go:162] AzureIdentity listing: 6.9µs
I1108 21:10:16.836546       1 stats.go:162] AzureIdentityBinding listing: 8.3µs
I1108 21:10:16.836549       1 stats.go:162] AzureAssignedIdentity listing: 6.1µs
I1108 21:10:16.836553       1 stats.go:162] System: 151.309µs
I1108 21:10:16.836717       1 stats.go:162] CacheSync: 8.2µs
I1108 21:10:16.836729       1 stats.go:162] Cloud provider GET: 238.201422ms
I1108 21:10:16.836732       1 stats.go:162] Cloud provider PATCH: 0s
I1108 21:10:16.836737       1 stats.go:162] AzureAssignedIdentity creation: 0s
I1108 21:10:16.836740       1 stats.go:162] AzureAssignedIdentity update: 0s
I1108 21:10:16.836744       1 stats.go:162] AzureAssignedIdentity deletion: 0s
I1108 21:10:16.836748       1 stats.go:170] Number of cloud provider PATCH: 0
I1108 21:10:16.836751       1 stats.go:170] Number of cloud provider GET: 2
I1108 21:10:16.836754       1 stats.go:170] Number of AzureAssignedIdentities created in this sync cycle: 0
I1108 21:10:16.836759       1 stats.go:170] Number of AzureAssignedIdentities updated in this sync cycle: 0
I1108 21:10:16.836763       1 stats.go:170] Number of AzureAssignedIdentities deleted in this sync cycle: 0
I1108 21:10:16.836766       1 stats.go:162] Find AzureAssignedIdentities to create: 4.4µs
I1108 21:10:16.836770       1 stats.go:162] Find AzureAssignedIdentities to delete: 8.801µs
I1108 21:10:16.836774       1 stats.go:162] Total time to assign or update AzureAssignedIdentities: 238.320429ms
I1108 21:10:16.836777       1 stats.go:162] Total: 238.591344ms
I1108 21:10:16.836781       1 stats.go:212] *********************
I1108 21:11:57.907452       1 mic.go:1040] processing node aks-agentpool-14229154-vmss, add [1], del [0], update [0]
I1108 21:11:58.081107       1 cloudprovider.go:215] updating user-assigned identities on aks-agentpool-14229154-vmss, assign [1], unassign [0]
I1108 21:11:58.102308       1 cloudprovider.go:229] removing /subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/order-processor-id from ID list since it is erroneous
E1108 21:11:58.102505       1 mic.go:1111] failed to update user-assigned identities on node aks-agentpool-14229154-vmss (add [1], del [0], update[0]), error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/order-processor-id' or the linked scope(s) are invalid."
E1108 21:11:58.307015       1 mic.go:1129] failed to apply binding keda-dotnet-sample/order-processor-id-binding node aks-agentpool-14229154-vmss000002 for pod keda-dotnet-sample/order-processor-589f9b8645-4s5sm, error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/order-processor-id' or the linked scope(s) are invalid."
I1108 21:11:58.307270       1 mic.go:525] work done: true. Found 1 pods, 2 ids, 2 bindings
I1108 21:11:58.307352       1 mic.go:526] total work cycles: 46, out of which work was done in: 4
I1108 21:11:58.307431       1 stats.go:183] ** stats collected **
I1108 21:11:58.307496       1 stats.go:162] Pod listing: 42.803µs
I1108 21:11:58.307573       1 stats.go:162] AzureIdentity listing: 9.701µs
I1108 21:11:58.307636       1 stats.go:162] AzureIdentityBinding listing: 12.801µs
I1108 21:11:58.307723       1 stats.go:162] AzureAssignedIdentity listing: 6.401µs
I1108 21:11:58.307785       1 stats.go:162] System: 189.212µs
I1108 21:11:58.307890       1 stats.go:162] CacheSync: 50.503µs
I1108 21:11:58.307957       1 stats.go:162] Cloud provider GET: 399.48646ms
I1108 21:11:58.308038       1 stats.go:162] Cloud provider PATCH: 0s
I1108 21:11:58.308104       1 stats.go:162] AzureAssignedIdentity creation: 0s
I1108 21:11:58.308195       1 stats.go:162] AzureAssignedIdentity update: 0s
I1108 21:11:58.308263       1 stats.go:162] AzureAssignedIdentity deletion: 0s
I1108 21:11:58.308340       1 stats.go:170] Number of cloud provider PATCH: 0
I1108 21:11:58.308405       1 stats.go:170] Number of cloud provider GET: 2
I1108 21:11:58.308482       1 stats.go:170] Number of AzureAssignedIdentities created in this sync cycle: 0
I1108 21:11:58.308554       1 stats.go:170] Number of AzureAssignedIdentities updated in this sync cycle: 0
I1108 21:11:58.308631       1 stats.go:170] Number of AzureAssignedIdentities deleted in this sync cycle: 0
I1108 21:11:58.308695       1 stats.go:162] Find AzureAssignedIdentities to create: 5.9µs
I1108 21:11:58.308772       1 stats.go:162] Find AzureAssignedIdentities to delete: 1.9µs
I1108 21:11:58.308838       1 stats.go:162] Total time to assign or update AzureAssignedIdentities: 399.778378ms
I1108 21:11:58.308929       1 stats.go:162] Total: 400.286509ms
I1108 21:11:58.308996       1 stats.go:212] *********************
I1108 21:11:58.510021       1 mic.go:1040] processing node aks-agentpool-14229154-vmss, add [1], del [0], update [0]
I1108 21:11:58.540628       1 cloudprovider.go:215] updating user-assigned identities on aks-agentpool-14229154-vmss, assign [1], unassign [0]
I1108 21:11:58.573215       1 cloudprovider.go:229] removing /subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/order-processor-id from ID list since it is erroneous
E1108 21:11:58.573241       1 mic.go:1111] failed to update user-assigned identities on node aks-agentpool-14229154-vmss (add [1], del [0], update[0]), error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/order-processor-id' or the linked scope(s) are invalid."
E1108 21:11:58.760612       1 mic.go:1129] failed to apply binding keda-dotnet-sample/order-processor-id-binding node aks-agentpool-14229154-vmss000002 for pod keda-dotnet-sample/order-processor-589f9b8645-4s5sm, error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/order-processor-id' or the linked scope(s) are invalid."
I1108 21:11:58.760733       1 mic.go:525] work done: true. Found 1 pods, 2 ids, 2 bindings
I1108 21:11:58.760751       1 mic.go:526] total work cycles: 47, out of which work was done in: 5
I1108 21:11:58.760785       1 stats.go:183] ** stats collected **
I1108 21:11:58.760798       1 stats.go:162] Pod listing: 105.407µs
I1108 21:11:58.760804       1 stats.go:162] AzureIdentity listing: 6.501µs
I1108 21:11:58.760809       1 stats.go:162] AzureIdentityBinding listing: 10.1µs
I1108 21:11:58.760813       1 stats.go:162] AzureAssignedIdentity listing: 4.901µs
I1108 21:11:58.760816       1 stats.go:162] System: 222.414µs
I1108 21:11:58.760821       1 stats.go:162] CacheSync: 15.701µs
I1108 21:11:58.760824       1 stats.go:162] Cloud provider GET: 250.500013ms
I1108 21:11:58.760828       1 stats.go:162] Cloud provider PATCH: 0s
I1108 21:11:58.760832       1 stats.go:162] AzureAssignedIdentity creation: 0s
I1108 21:11:58.760835       1 stats.go:162] AzureAssignedIdentity update: 0s
I1108 21:11:58.760839       1 stats.go:162] AzureAssignedIdentity deletion: 0s
I1108 21:11:58.760843       1 stats.go:170] Number of cloud provider PATCH: 0
I1108 21:11:58.760846       1 stats.go:170] Number of cloud provider GET: 2
I1108 21:11:58.760866       1 stats.go:170] Number of AzureAssignedIdentities created in this sync cycle: 0
I1108 21:11:58.760885       1 stats.go:170] Number of AzureAssignedIdentities updated in this sync cycle: 0
I1108 21:11:58.760894       1 stats.go:170] Number of AzureAssignedIdentities deleted in this sync cycle: 0
I1108 21:11:58.760897       1 stats.go:162] Find AzureAssignedIdentities to create: 4.6µs
I1108 21:11:58.760901       1 stats.go:162] Find AzureAssignedIdentities to delete: 1.4µs
I1108 21:11:58.760905       1 stats.go:162] Total time to assign or update AzureAssignedIdentities: 250.681023ms
I1108 21:11:58.760909       1 stats.go:162] Total: 251.046446ms
I1108 21:11:58.760912       1 stats.go:212] *********************
I1108 21:11:58.962146       1 mic.go:1040] processing node aks-agentpool-14229154-vmss, add [1], del [0], update [0]
I1108 21:11:58.992499       1 cloudprovider.go:215] updating user-assigned identities on aks-agentpool-14229154-vmss, assign [1], unassign [0]
I1108 21:11:59.022449       1 cloudprovider.go:229] removing /subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/order-processor-id from ID list since it is erroneous
E1108 21:11:59.022476       1 mic.go:1111] failed to update user-assigned identities on node aks-agentpool-14229154-vmss (add [1], del [0], update[0]), error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/order-processor-id' or the linked scope(s) are invalid."
E1108 21:11:59.273179       1 mic.go:1129] failed to apply binding keda-dotnet-sample/order-processor-id-binding node aks-agentpool-14229154-vmss000002 for pod keda-dotnet-sample/order-processor-589f9b8645-4s5sm, error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/order-processor-id' or the linked scope(s) are invalid."
I1108 21:11:59.273215       1 mic.go:525] work done: true. Found 1 pods, 2 ids, 2 bindings
I1108 21:11:59.273223       1 mic.go:526] total work cycles: 48, out of which work was done in: 6
I1108 21:11:59.273230       1 stats.go:183] ** stats collected **
I1108 21:11:59.273235       1 stats.go:162] Pod listing: 35.002µs
I1108 21:11:59.273242       1 stats.go:162] AzureIdentity listing: 7.001µs
I1108 21:11:59.273248       1 stats.go:162] AzureIdentityBinding listing: 11.8µs
I1108 21:11:59.273252       1 stats.go:162] AzureAssignedIdentity listing: 8.801µs
I1108 21:11:59.273256       1 stats.go:162] System: 207.613µs
I1108 21:11:59.273260       1 stats.go:162] CacheSync: 42.902µs
I1108 21:11:59.273264       1 stats.go:162] Cloud provider GET: 310.844177ms
I1108 21:11:59.273268       1 stats.go:162] Cloud provider PATCH: 0s
I1108 21:11:59.273273       1 stats.go:162] AzureAssignedIdentity creation: 0s
I1108 21:11:59.273277       1 stats.go:162] AzureAssignedIdentity update: 0s
I1108 21:11:59.273281       1 stats.go:162] AzureAssignedIdentity deletion: 0s
I1108 21:11:59.273285       1 stats.go:170] Number of cloud provider PATCH: 0
I1108 21:11:59.273289       1 stats.go:170] Number of cloud provider GET: 2
I1108 21:11:59.273293       1 stats.go:170] Number of AzureAssignedIdentities created in this sync cycle: 0
I1108 21:11:59.273297       1 stats.go:170] Number of AzureAssignedIdentities updated in this sync cycle: 0
I1108 21:11:59.273300       1 stats.go:170] Number of AzureAssignedIdentities deleted in this sync cycle: 0
I1108 21:11:59.273304       1 stats.go:162] Find AzureAssignedIdentities to create: 4.5µs
I1108 21:11:59.273308       1 stats.go:162] Find AzureAssignedIdentities to delete: 1.8µs
I1108 21:11:59.273312       1 stats.go:162] Total time to assign or update AzureAssignedIdentities: 311.061891ms
I1108 21:11:59.273317       1 stats.go:162] Total: 311.428212ms
I1108 21:11:59.273321       1 stats.go:212] *********************
I1108 21:11:59.474465       1 mic.go:1040] processing node aks-agentpool-14229154-vmss, add [1], del [0], update [0]
I1108 21:11:59.673616       1 cloudprovider.go:215] updating user-assigned identities on aks-agentpool-14229154-vmss, assign [1], unassign [0]
I1108 21:11:59.721002       1 cloudprovider.go:229] removing /subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/order-processor-id from ID list since it is erroneous
E1108 21:11:59.721024       1 mic.go:1111] failed to update user-assigned identities on node aks-agentpool-14229154-vmss (add [1], del [0], update[0]), error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/order-processor-id' or the linked scope(s) are invalid."
E1108 21:11:59.871509       1 mic.go:1129] failed to apply binding keda-dotnet-sample/order-processor-id-binding node aks-agentpool-14229154-vmss000002 for pod keda-dotnet-sample/order-processor-589f9b8645-4s5sm, error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/order-processor-id' or the linked scope(s) are invalid."
I1108 21:11:59.871543       1 mic.go:525] work done: true. Found 1 pods, 2 ids, 2 bindings
I1108 21:11:59.871550       1 mic.go:526] total work cycles: 49, out of which work was done in: 7
I1108 21:11:59.871559       1 stats.go:183] ** stats collected **
I1108 21:11:59.871565       1 stats.go:162] Pod listing: 78.005µs
I1108 21:11:59.871573       1 stats.go:162] AzureIdentity listing: 6.9µs
I1108 21:11:59.871820       1 stats.go:162] AzureIdentityBinding listing: 9.501µs
I1108 21:11:59.871979       1 stats.go:162] AzureAssignedIdentity listing: 6.001µs
I1108 21:11:59.872110       1 stats.go:162] System: 199.513µs
I1108 21:11:59.872230       1 stats.go:162] CacheSync: 54.603µs
I1108 21:11:59.872237       1 stats.go:162] Cloud provider GET: 396.952406ms
I1108 21:11:59.872241       1 stats.go:162] Cloud provider PATCH: 0s
I1108 21:11:59.872245       1 stats.go:162] AzureAssignedIdentity creation: 0s
I1108 21:11:59.872250       1 stats.go:162] AzureAssignedIdentity update: 0s
I1108 21:11:59.872254       1 stats.go:162] AzureAssignedIdentity deletion: 0s
I1108 21:11:59.872259       1 stats.go:170] Number of cloud provider PATCH: 0
I1108 21:11:59.872265       1 stats.go:170] Number of cloud provider GET: 2
I1108 21:11:59.872270       1 stats.go:170] Number of AzureAssignedIdentities created in this sync cycle: 0
I1108 21:11:59.872273       1 stats.go:170] Number of AzureAssignedIdentities updated in this sync cycle: 0
I1108 21:11:59.872277       1 stats.go:170] Number of AzureAssignedIdentities deleted in this sync cycle: 0
I1108 21:11:59.872281       1 stats.go:162] Find AzureAssignedIdentities to create: 3.201µs
I1108 21:11:59.872286       1 stats.go:162] Find AzureAssignedIdentities to delete: 1.6µs
I1108 21:11:59.872290       1 stats.go:162] Total time to assign or update AzureAssignedIdentities: 397.070614ms
I1108 21:11:59.872294       1 stats.go:162] Total: 397.415634ms
I1108 21:11:59.872299       1 stats.go:212] *********************
I1108 21:12:00.146304       1 mic.go:587] pod keda-system/keda-operator-7c9b598554-tchmd has no assigned node yet. it will be ignored
I1108 21:12:00.146495       1 mic.go:1040] processing node aks-agentpool-14229154-vmss, add [1], del [0], update [0]
I1108 21:12:00.187750       1 cloudprovider.go:215] updating user-assigned identities on aks-agentpool-14229154-vmss, assign [1], unassign [0]
I1108 21:12:00.234285       1 cloudprovider.go:229] removing /subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/order-processor-id from ID list since it is erroneous
E1108 21:12:00.234316       1 mic.go:1111] failed to update user-assigned identities on node aks-agentpool-14229154-vmss (add [1], del [0], update[0]), error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/order-processor-id' or the linked scope(s) are invalid."
E1108 21:12:00.313387       1 mic.go:1129] failed to apply binding keda-dotnet-sample/order-processor-id-binding node aks-agentpool-14229154-vmss000002 for pod keda-dotnet-sample/order-processor-589f9b8645-4s5sm, error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/order-processor-id' or the linked scope(s) are invalid."
I1108 21:12:00.313421       1 mic.go:525] work done: true. Found 2 pods, 2 ids, 2 bindings
I1108 21:12:00.313427       1 mic.go:526] total work cycles: 50, out of which work was done in: 8
I1108 21:12:00.313434       1 stats.go:183] ** stats collected **
I1108 21:12:00.313439       1 stats.go:162] Pod listing: 49.703µs
I1108 21:12:00.313446       1 stats.go:162] AzureIdentity listing: 7.601µs
I1108 21:12:00.313449       1 stats.go:162] AzureIdentityBinding listing: 10.3µs
I1108 21:12:00.313452       1 stats.go:162] AzureAssignedIdentity listing: 5.601µs
I1108 21:12:00.313457       1 stats.go:162] System: 169.31µs
I1108 21:12:00.313460       1 stats.go:162] CacheSync: 8.2µs
I1108 21:12:00.313464       1 stats.go:162] Cloud provider GET: 166.740926ms
I1108 21:12:00.313467       1 stats.go:162] Cloud provider PATCH: 0s
I1108 21:12:00.313470       1 stats.go:162] AzureAssignedIdentity creation: 0s
I1108 21:12:00.313473       1 stats.go:162] AzureAssignedIdentity update: 0s
I1108 21:12:00.313476       1 stats.go:162] AzureAssignedIdentity deletion: 0s
I1108 21:12:00.313481       1 stats.go:170] Number of cloud provider PATCH: 0
I1108 21:12:00.313484       1 stats.go:170] Number of cloud provider GET: 2
I1108 21:12:00.313487       1 stats.go:170] Number of AzureAssignedIdentities created in this sync cycle: 0
I1108 21:12:00.313490       1 stats.go:170] Number of AzureAssignedIdentities updated in this sync cycle: 0
I1108 21:12:00.313493       1 stats.go:170] Number of AzureAssignedIdentities deleted in this sync cycle: 0
I1108 21:12:00.313497       1 stats.go:162] Find AzureAssignedIdentities to create: 5.2µs
I1108 21:12:00.313500       1 stats.go:162] Find AzureAssignedIdentities to delete: 1.5µs
I1108 21:12:00.313503       1 stats.go:162] Total time to assign or update AzureAssignedIdentities: 166.916736ms
I1108 21:12:00.313507       1 stats.go:162] Total: 167.31116ms
I1108 21:12:00.313510       1 stats.go:212] *********************
I1108 21:12:00.514228       1 mic.go:1040] processing node aks-agentpool-14229154-vmss, add [3], del [0], update [0]
I1108 21:12:00.514272       1 crd.go:514] creating assigned id keda-system/keda-operator-7c9b598554-tchmd-keda-system-autoscaler-id
I1108 21:12:00.514656       1 crd.go:514] creating assigned id keda-system/keda-operator-metrics-apiserver-97cd665d4-kw4hm-keda-system-autoscaler-id
I1108 21:12:00.587357       1 cloudprovider.go:215] updating user-assigned identities on aks-agentpool-14229154-vmss, assign [2], unassign [0]
I1108 21:12:00.611418       1 cloudprovider.go:229] removing /subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/autoscaler-id from ID list since it is erroneous
I1108 21:12:00.611453       1 cloudprovider.go:229] removing /subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/order-processor-id from ID list since it is erroneous
E1108 21:12:00.611461       1 mic.go:1111] failed to update user-assigned identities on node aks-agentpool-14229154-vmss (add [3], del [0], update[0]), error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/autoscaler-id,/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/order-processor-id' or the linked scope(s) are invalid."
E1108 21:12:00.720299       1 mic.go:1129] failed to apply binding keda-dotnet-sample/order-processor-id-binding node aks-agentpool-14229154-vmss000002 for pod keda-dotnet-sample/order-processor-589f9b8645-4s5sm, error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/autoscaler-id,/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/order-processor-id' or the linked scope(s) are invalid."
E1108 21:12:00.720328       1 mic.go:1129] failed to apply binding keda-system/autoscaler-id-binding node aks-agentpool-14229154-vmss000002 for pod keda-system/keda-operator-metrics-apiserver-97cd665d4-kw4hm, error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/autoscaler-id,/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/order-processor-id' or the linked scope(s) are invalid."
E1108 21:12:00.720341       1 mic.go:1129] failed to apply binding keda-system/autoscaler-id-binding node aks-agentpool-14229154-vmss000002 for pod keda-system/keda-operator-7c9b598554-tchmd, error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/autoscaler-id,/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/order-processor-id' or the linked scope(s) are invalid."
I1108 21:12:00.720357       1 mic.go:525] work done: true. Found 3 pods, 2 ids, 2 bindings
I1108 21:12:00.720363       1 mic.go:526] total work cycles: 51, out of which work was done in: 9
I1108 21:12:00.720373       1 stats.go:183] ** stats collected **
I1108 21:12:00.720377       1 stats.go:162] Pod listing: 103.206µs
I1108 21:12:00.720384       1 stats.go:162] AzureIdentity listing: 6.6µs
I1108 21:12:00.720388       1 stats.go:162] AzureIdentityBinding listing: 11.701µs
I1108 21:12:00.720391       1 stats.go:162] AzureAssignedIdentity listing: 7.4µs
I1108 21:12:00.720395       1 stats.go:162] System: 232.514µs
I1108 21:12:00.720398       1 stats.go:162] CacheSync: 20.801µs
I1108 21:12:00.720402       1 stats.go:162] Cloud provider GET: 189.757123ms
I1108 21:12:00.720405       1 stats.go:162] Cloud provider PATCH: 0s
I1108 21:12:00.720408       1 stats.go:162] AzureAssignedIdentity creation: 16.208684ms
I1108 21:12:00.720412       1 stats.go:162] AzureAssignedIdentity update: 0s
I1108 21:12:00.720415       1 stats.go:162] AzureAssignedIdentity deletion: 0s
I1108 21:12:00.720418       1 stats.go:170] Number of cloud provider PATCH: 0
I1108 21:12:00.720421       1 stats.go:170] Number of cloud provider GET: 2
I1108 21:12:00.720424       1 stats.go:170] Number of AzureAssignedIdentities created in this sync cycle: 0
I1108 21:12:00.720427       1 stats.go:170] Number of AzureAssignedIdentities updated in this sync cycle: 0
I1108 21:12:00.720430       1 stats.go:170] Number of AzureAssignedIdentities deleted in this sync cycle: 0
I1108 21:12:00.720434       1 stats.go:162] Find AzureAssignedIdentities to create: 6.6µs
I1108 21:12:00.720437       1 stats.go:162] Find AzureAssignedIdentities to delete: 3.9µs
I1108 21:12:00.720440       1 stats.go:162] Total time to assign or update AzureAssignedIdentities: 206.122117ms
I1108 21:12:00.720443       1 stats.go:162] Total: 206.50214ms
I1108 21:12:00.720447       1 stats.go:212] *********************
I1108 21:12:00.921440       1 mic.go:1040] processing node aks-agentpool-14229154-vmss, add [3], del [0], update [0]
I1108 21:12:00.964855       1 cloudprovider.go:215] updating user-assigned identities on aks-agentpool-14229154-vmss, assign [2], unassign [0]
I1108 21:12:01.029876       1 cloudprovider.go:229] removing /subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/autoscaler-id from ID list since it is erroneous
I1108 21:12:01.029892       1 cloudprovider.go:229] removing /subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/order-processor-id from ID list since it is erroneous
E1108 21:12:01.029900       1 mic.go:1111] failed to update user-assigned identities on node aks-agentpool-14229154-vmss (add [3], del [0], update[0]), error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/autoscaler-id,/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/order-processor-id' or the linked scope(s) are invalid."
E1108 21:12:01.189490       1 mic.go:1129] failed to apply binding keda-system/autoscaler-id-binding node aks-agentpool-14229154-vmss000002 for pod keda-system/keda-operator-metrics-apiserver-97cd665d4-kw4hm, error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/autoscaler-id,/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/order-processor-id' or the linked scope(s) are invalid."
E1108 21:12:01.189522       1 mic.go:1129] failed to apply binding keda-system/autoscaler-id-binding node aks-agentpool-14229154-vmss000002 for pod keda-system/keda-operator-7c9b598554-tchmd, error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/autoscaler-id,/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/order-processor-id' or the linked scope(s) are invalid."
E1108 21:12:01.189535       1 mic.go:1129] failed to apply binding keda-dotnet-sample/order-processor-id-binding node aks-agentpool-14229154-vmss000002 for pod keda-dotnet-sample/order-processor-589f9b8645-4s5sm, error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/autoscaler-id,/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/order-processor-id' or the linked scope(s) are invalid."
I1108 21:12:01.189552       1 mic.go:525] work done: true. Found 3 pods, 2 ids, 2 bindings
I1108 21:12:01.189568       1 mic.go:526] total work cycles: 52, out of which work was done in: 10
I1108 21:12:01.189579       1 stats.go:183] ** stats collected **
I1108 21:12:01.189583       1 stats.go:162] Pod listing: 50.003µs
I1108 21:12:01.189589       1 stats.go:162] AzureIdentity listing: 5.901µs
I1108 21:12:01.189593       1 stats.go:162] AzureIdentityBinding listing: 8.1µs
I1108 21:12:01.189596       1 stats.go:162] AzureAssignedIdentity listing: 12.3µs
I1108 21:12:01.189599       1 stats.go:162] System: 176.11µs
I1108 21:12:01.189602       1 stats.go:162] CacheSync: 15.701µs
I1108 21:12:01.189605       1 stats.go:162] Cloud provider GET: 267.946272ms
I1108 21:12:01.189609       1 stats.go:162] Cloud provider PATCH: 0s
I1108 21:12:01.189612       1 stats.go:162] AzureAssignedIdentity creation: 0s
I1108 21:12:01.189615       1 stats.go:162] AzureAssignedIdentity update: 0s
I1108 21:12:01.189619       1 stats.go:162] AzureAssignedIdentity deletion: 0s
I1108 21:12:01.189622       1 stats.go:170] Number of cloud provider PATCH: 0
I1108 21:12:01.189625       1 stats.go:170] Number of cloud provider GET: 2
I1108 21:12:01.189628       1 stats.go:170] Number of AzureAssignedIdentities created in this sync cycle: 0
I1108 21:12:01.189631       1 stats.go:170] Number of AzureAssignedIdentities updated in this sync cycle: 0
I1108 21:12:01.189643       1 stats.go:170] Number of AzureAssignedIdentities deleted in this sync cycle: 0
I1108 21:12:01.189647       1 stats.go:162] Find AzureAssignedIdentities to create: 8.701µs
I1108 21:12:01.189650       1 stats.go:162] Find AzureAssignedIdentities to delete: 5.7µs
I1108 21:12:01.189653       1 stats.go:162] Total time to assign or update AzureAssignedIdentities: 268.103682ms
I1108 21:12:01.189656       1 stats.go:162] Total: 268.430601ms
I1108 21:12:01.189659       1 stats.go:212] *********************
I1108 21:12:01.390335       1 mic.go:1040] processing node aks-agentpool-14229154-vmss, add [3], del [0], update [0]
I1108 21:12:01.440228       1 cloudprovider.go:215] updating user-assigned identities on aks-agentpool-14229154-vmss, assign [2], unassign [0]
I1108 21:12:01.472987       1 cloudprovider.go:229] removing /subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/autoscaler-id from ID list since it is erroneous
I1108 21:12:01.473005       1 cloudprovider.go:229] removing /subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/order-processor-id from ID list since it is erroneous
E1108 21:12:01.473012       1 mic.go:1111] failed to update user-assigned identities on node aks-agentpool-14229154-vmss (add [3], del [0], update[0]), error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/autoscaler-id,/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/order-processor-id' or the linked scope(s) are invalid."
E1108 21:12:01.733670       1 mic.go:1129] failed to apply binding keda-system/autoscaler-id-binding node aks-agentpool-14229154-vmss000002 for pod keda-system/keda-operator-7c9b598554-tchmd, error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/autoscaler-id,/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/order-processor-id' or the linked scope(s) are invalid."
E1108 21:12:01.733705       1 mic.go:1129] failed to apply binding keda-dotnet-sample/order-processor-id-binding node aks-agentpool-14229154-vmss000002 for pod keda-dotnet-sample/order-processor-589f9b8645-4s5sm, error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/autoscaler-id,/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/order-processor-id' or the linked scope(s) are invalid."
E1108 21:12:01.733720       1 mic.go:1129] failed to apply binding keda-system/autoscaler-id-binding node aks-agentpool-14229154-vmss000002 for pod keda-system/keda-operator-metrics-apiserver-97cd665d4-kw4hm, error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/autoscaler-id,/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/order-processor-id' or the linked scope(s) are invalid."
I1108 21:12:01.733734       1 mic.go:525] work done: true. Found 3 pods, 2 ids, 2 bindings
I1108 21:12:01.733740       1 mic.go:526] total work cycles: 53, out of which work was done in: 11
I1108 21:12:01.733748       1 stats.go:183] ** stats collected **
I1108 21:12:01.733752       1 stats.go:162] Pod listing: 64.704µs
I1108 21:12:01.733759       1 stats.go:162] AzureIdentity listing: 17.901µs
I1108 21:12:01.733763       1 stats.go:162] AzureIdentityBinding listing: 8.501µs
I1108 21:12:01.733767       1 stats.go:162] AzureAssignedIdentity listing: 13.601µs
I1108 21:12:01.733771       1 stats.go:162] System: 192.412µs
I1108 21:12:01.733775       1 stats.go:162] CacheSync: 14.601µs
I1108 21:12:01.733779       1 stats.go:162] Cloud provider GET: 343.250645ms
I1108 21:12:01.733782       1 stats.go:162] Cloud provider PATCH: 0s
I1108 21:12:01.733786       1 stats.go:162] AzureAssignedIdentity creation: 0s
I1108 21:12:01.733791       1 stats.go:162] AzureAssignedIdentity update: 0s
I1108 21:12:01.733795       1 stats.go:162] AzureAssignedIdentity deletion: 0s
I1108 21:12:01.733799       1 stats.go:170] Number of cloud provider PATCH: 0
I1108 21:12:01.733803       1 stats.go:170] Number of cloud provider GET: 2
I1108 21:12:01.733806       1 stats.go:170] Number of AzureAssignedIdentities created in this sync cycle: 0
I1108 21:12:01.733809       1 stats.go:170] Number of AzureAssignedIdentities updated in this sync cycle: 0
I1108 21:12:01.733813       1 stats.go:170] Number of AzureAssignedIdentities deleted in this sync cycle: 0
I1108 21:12:01.733816       1 stats.go:162] Find AzureAssignedIdentities to create: 9.8µs
I1108 21:12:01.733820       1 stats.go:162] Find AzureAssignedIdentities to delete: 5.201µs
I1108 21:12:01.733823       1 stats.go:162] Total time to assign or update AzureAssignedIdentities: 343.392554ms
I1108 21:12:01.733827       1 stats.go:162] Total: 343.709773ms
I1108 21:12:01.733831       1 stats.go:212] *********************
I1108 21:13:34.885453       1 mic.go:1040] processing node aks-agentpool-14229154-vmss, add [2], del [1], update [0]
I1108 21:13:34.939542       1 cloudprovider.go:215] updating user-assigned identities on aks-agentpool-14229154-vmss, assign [1], unassign [0]
I1108 21:13:34.966974       1 cloudprovider.go:229] removing /subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/autoscaler-id from ID list since it is erroneous
E1108 21:13:34.966999       1 mic.go:1111] failed to update user-assigned identities on node aks-agentpool-14229154-vmss (add [2], del [1], update[0]), error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/autoscaler-id' or the linked scope(s) are invalid."
E1108 21:13:35.079962       1 mic.go:1129] failed to apply binding keda-system/autoscaler-id-binding node aks-agentpool-14229154-vmss000002 for pod keda-system/keda-operator-7c9b598554-tchmd, error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/autoscaler-id' or the linked scope(s) are invalid."
E1108 21:13:35.091393       1 mic.go:1129] failed to apply binding keda-system/autoscaler-id-binding node aks-agentpool-14229154-vmss000002 for pod keda-system/keda-operator-metrics-apiserver-97cd665d4-kw4hm, error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/autoscaler-id' or the linked scope(s) are invalid."
I1108 21:13:35.091476       1 mic.go:1181] updating msis on node aks-agentpool-14229154-vmss000002 failed, but identity keda-dotnet-sample/order-processor-id has successfully been removed from node
I1108 21:13:35.145195       1 mic.go:1189] deleted assigned identity keda-dotnet-sample/order-processor-589f9b8645-4s5sm-keda-dotnet-sample-order-processor-id
I1108 21:13:35.145232       1 mic.go:525] work done: true. Found 2 pods, 2 ids, 2 bindings
I1108 21:13:35.145239       1 mic.go:526] total work cycles: 54, out of which work was done in: 12
I1108 21:13:35.145247       1 stats.go:183] ** stats collected **
I1108 21:13:35.145252       1 stats.go:162] Pod listing: 34.502µs
I1108 21:13:35.145260       1 stats.go:162] AzureIdentity listing: 5.3µs
I1108 21:13:35.145265       1 stats.go:162] AzureIdentityBinding listing: 9.301µs
I1108 21:13:35.145270       1 stats.go:162] AzureAssignedIdentity listing: 18.601µs
I1108 21:13:35.145276       1 stats.go:162] System: 133.608µs
I1108 21:13:35.145280       1 stats.go:162] CacheSync: 8.401µs
I1108 21:13:35.145284       1 stats.go:162] Cloud provider GET: 194.368068ms
I1108 21:13:35.145289       1 stats.go:162] Cloud provider PATCH: 0s
I1108 21:13:35.145293       1 stats.go:162] AzureAssignedIdentity creation: 0s
I1108 21:13:35.145297       1 stats.go:162] AzureAssignedIdentity update: 0s
I1108 21:13:35.145301       1 stats.go:162] AzureAssignedIdentity deletion: 53.673639ms
I1108 21:13:35.145305       1 stats.go:170] Number of cloud provider PATCH: 0
I1108 21:13:35.145309       1 stats.go:170] Number of cloud provider GET: 2
I1108 21:13:35.145313       1 stats.go:170] Number of AzureAssignedIdentities created in this sync cycle: 0
I1108 21:13:35.145317       1 stats.go:170] Number of AzureAssignedIdentities updated in this sync cycle: 0
I1108 21:13:35.145321       1 stats.go:170] Number of AzureAssignedIdentities deleted in this sync cycle: 1
I1108 21:13:35.145325       1 stats.go:162] Find AzureAssignedIdentities to create: 5.3µs
I1108 21:13:35.145329       1 stats.go:162] Find AzureAssignedIdentities to delete: 9.201µs
I1108 21:13:35.145333       1 stats.go:162] Total time to assign or update AzureAssignedIdentities: 259.770893ms
I1108 21:13:35.145338       1 stats.go:162] Total: 260.046309ms
I1108 21:13:35.145343       1 stats.go:212] *********************
I1108 21:21:57.908107       1 mic.go:1040] processing node aks-agentpool-14229154-vmss, add [2], del [0], update [0]
I1108 21:21:58.067495       1 cloudprovider.go:215] updating user-assigned identities on aks-agentpool-14229154-vmss, assign [1], unassign [0]
I1108 21:21:58.098346       1 cloudprovider.go:229] removing /subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/autoscaler-id from ID list since it is erroneous
E1108 21:21:58.098367       1 mic.go:1111] failed to update user-assigned identities on node aks-agentpool-14229154-vmss (add [2], del [0], update[0]), error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/autoscaler-id' or the linked scope(s) are invalid."
E1108 21:21:58.192905       1 mic.go:1129] failed to apply binding keda-system/autoscaler-id-binding node aks-agentpool-14229154-vmss000002 for pod keda-system/keda-operator-metrics-apiserver-97cd665d4-kw4hm, error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/autoscaler-id' or the linked scope(s) are invalid."
E1108 21:21:58.192939       1 mic.go:1129] failed to apply binding keda-system/autoscaler-id-binding node aks-agentpool-14229154-vmss000002 for pod keda-system/keda-operator-7c9b598554-tchmd, error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/autoscaler-id' or the linked scope(s) are invalid."
I1108 21:21:58.192955       1 mic.go:525] work done: true. Found 2 pods, 2 ids, 2 bindings
I1108 21:21:58.192961       1 mic.go:526] total work cycles: 55, out of which work was done in: 13
I1108 21:21:58.192969       1 stats.go:183] ** stats collected **
I1108 21:21:58.192973       1 stats.go:162] Pod listing: 68.304µs
I1108 21:21:58.192980       1 stats.go:162] AzureIdentity listing: 5.6µs
I1108 21:21:58.192984       1 stats.go:162] AzureIdentityBinding listing: 7.4µs
I1108 21:21:58.192988       1 stats.go:162] AzureAssignedIdentity listing: 8.001µs
I1108 21:21:58.192992       1 stats.go:162] System: 173.411µs
I1108 21:21:58.192996       1 stats.go:162] CacheSync: 17.901µs
I1108 21:21:58.192999       1 stats.go:162] Cloud provider GET: 284.676894ms
I1108 21:21:58.193003       1 stats.go:162] Cloud provider PATCH: 0s
I1108 21:21:58.193007       1 stats.go:162] AzureAssignedIdentity creation: 0s
I1108 21:21:58.193010       1 stats.go:162] AzureAssignedIdentity update: 0s
I1108 21:21:58.193014       1 stats.go:162] AzureAssignedIdentity deletion: 0s
I1108 21:21:58.193017       1 stats.go:170] Number of cloud provider PATCH: 0
I1108 21:21:58.193021       1 stats.go:170] Number of cloud provider GET: 2
I1108 21:21:58.193024       1 stats.go:170] Number of AzureAssignedIdentities created in this sync cycle: 0
I1108 21:21:58.193028       1 stats.go:170] Number of AzureAssignedIdentities updated in this sync cycle: 0
I1108 21:21:58.193031       1 stats.go:170] Number of AzureAssignedIdentities deleted in this sync cycle: 0
I1108 21:21:58.193034       1 stats.go:162] Find AzureAssignedIdentities to create: 5.9µs
I1108 21:21:58.193038       1 stats.go:162] Find AzureAssignedIdentities to delete: 3.7µs
I1108 21:21:58.193042       1 stats.go:162] Total time to assign or update AzureAssignedIdentities: 284.841003ms
I1108 21:21:58.193046       1 stats.go:162] Total: 285.144822ms
I1108 21:21:58.193050       1 stats.go:212] *********************
I1108 21:21:58.393649       1 mic.go:1040] processing node aks-agentpool-14229154-vmss, add [2], del [0], update [0]
I1108 21:21:58.427737       1 cloudprovider.go:215] updating user-assigned identities on aks-agentpool-14229154-vmss, assign [1], unassign [0]
I1108 21:21:58.444585       1 cloudprovider.go:229] removing /subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/autoscaler-id from ID list since it is erroneous
E1108 21:21:58.444607       1 mic.go:1111] failed to update user-assigned identities on node aks-agentpool-14229154-vmss (add [2], del [0], update[0]), error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/autoscaler-id' or the linked scope(s) are invalid."
E1108 21:21:58.554743       1 mic.go:1129] failed to apply binding keda-system/autoscaler-id-binding node aks-agentpool-14229154-vmss000002 for pod keda-system/keda-operator-7c9b598554-tchmd, error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/autoscaler-id' or the linked scope(s) are invalid."
E1108 21:21:58.554774       1 mic.go:1129] failed to apply binding keda-system/autoscaler-id-binding node aks-agentpool-14229154-vmss000002 for pod keda-system/keda-operator-metrics-apiserver-97cd665d4-kw4hm, error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/autoscaler-id' or the linked scope(s) are invalid."
I1108 21:21:58.554788       1 mic.go:525] work done: true. Found 2 pods, 2 ids, 2 bindings
I1108 21:21:58.554794       1 mic.go:526] total work cycles: 56, out of which work was done in: 14
I1108 21:21:58.554801       1 stats.go:183] ** stats collected **
I1108 21:21:58.555338       1 stats.go:162] Pod listing: 131.407µs
I1108 21:21:58.555437       1 stats.go:162] AzureIdentity listing: 6.4µs
I1108 21:21:58.555505       1 stats.go:162] AzureIdentityBinding listing: 12.501µs
I1108 21:21:58.555693       1 stats.go:162] AzureAssignedIdentity listing: 8.601µs
I1108 21:21:58.555787       1 stats.go:162] System: 261.816µs
I1108 21:21:58.555827       1 stats.go:162] CacheSync: 23.001µs
I1108 21:21:58.555844       1 stats.go:162] Cloud provider GET: 160.963983ms
I1108 21:21:58.555860       1 stats.go:162] Cloud provider PATCH: 0s
I1108 21:21:58.555893       1 stats.go:162] AzureAssignedIdentity creation: 0s
I1108 21:21:58.555923       1 stats.go:162] AzureAssignedIdentity update: 0s
I1108 21:21:58.555966       1 stats.go:162] AzureAssignedIdentity deletion: 0s
I1108 21:21:58.556037       1 stats.go:170] Number of cloud provider PATCH: 0
I1108 21:21:58.556049       1 stats.go:170] Number of cloud provider GET: 2
I1108 21:21:58.556052       1 stats.go:170] Number of AzureAssignedIdentities created in this sync cycle: 0
I1108 21:21:58.556055       1 stats.go:170] Number of AzureAssignedIdentities updated in this sync cycle: 0
I1108 21:21:58.556058       1 stats.go:170] Number of AzureAssignedIdentities deleted in this sync cycle: 0
I1108 21:21:58.556061       1 stats.go:162] Find AzureAssignedIdentities to create: 7.901µs
I1108 21:21:58.556065       1 stats.go:162] Find AzureAssignedIdentities to delete: 3.4µs
I1108 21:21:58.556069       1 stats.go:162] Total time to assign or update AzureAssignedIdentities: 161.134392ms
I1108 21:21:58.556072       1 stats.go:162] Total: 161.543216ms
I1108 21:21:58.556077       1 stats.go:212] *********************
I1108 21:21:58.757128       1 mic.go:1040] processing node aks-agentpool-14229154-vmss, add [2], del [0], update [0]
I1108 21:21:58.789750       1 cloudprovider.go:215] updating user-assigned identities on aks-agentpool-14229154-vmss, assign [1], unassign [0]
I1108 21:21:58.812879       1 cloudprovider.go:229] removing /subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/autoscaler-id from ID list since it is erroneous
E1108 21:21:58.812901       1 mic.go:1111] failed to update user-assigned identities on node aks-agentpool-14229154-vmss (add [2], del [0], update[0]), error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/autoscaler-id' or the linked scope(s) are invalid."
E1108 21:21:58.878793       1 mic.go:1129] failed to apply binding keda-system/autoscaler-id-binding node aks-agentpool-14229154-vmss000002 for pod keda-system/keda-operator-metrics-apiserver-97cd665d4-kw4hm, error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/autoscaler-id' or the linked scope(s) are invalid."
E1108 21:21:58.878828       1 mic.go:1129] failed to apply binding keda-system/autoscaler-id-binding node aks-agentpool-14229154-vmss000002 for pod keda-system/keda-operator-7c9b598554-tchmd, error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/autoscaler-id' or the linked scope(s) are invalid."
I1108 21:21:58.878842       1 mic.go:525] work done: true. Found 2 pods, 2 ids, 2 bindings
I1108 21:21:58.878848       1 mic.go:526] total work cycles: 57, out of which work was done in: 15
I1108 21:21:58.878856       1 stats.go:183] ** stats collected **
I1108 21:21:58.878860       1 stats.go:162] Pod listing: 34.702µs
I1108 21:21:58.878867       1 stats.go:162] AzureIdentity listing: 6.6µs
I1108 21:21:58.878871       1 stats.go:162] AzureIdentityBinding listing: 9.601µs
I1108 21:21:58.878875       1 stats.go:162] AzureAssignedIdentity listing: 8.3µs
I1108 21:21:58.878879       1 stats.go:162] System: 156.209µs
I1108 21:21:58.878882       1 stats.go:162] CacheSync: 13.601µs
I1108 21:21:58.878886       1 stats.go:162] Cloud provider GET: 121.580487ms
I1108 21:21:58.878889       1 stats.go:162] Cloud provider PATCH: 0s
I1108 21:21:58.878893       1 stats.go:162] AzureAssignedIdentity creation: 0s
I1108 21:21:58.878896       1 stats.go:162] AzureAssignedIdentity update: 0s
I1108 21:21:58.878899       1 stats.go:162] AzureAssignedIdentity deletion: 0s
I1108 21:21:58.878903       1 stats.go:170] Number of cloud provider PATCH: 0
I1108 21:21:58.878906       1 stats.go:170] Number of cloud provider GET: 2
I1108 21:21:58.878909       1 stats.go:170] Number of AzureAssignedIdentities created in this sync cycle: 0
I1108 21:21:58.878912       1 stats.go:170] Number of AzureAssignedIdentities updated in this sync cycle: 0
I1108 21:21:58.878915       1 stats.go:170] Number of AzureAssignedIdentities deleted in this sync cycle: 0
I1108 21:21:58.878918       1 stats.go:162] Find AzureAssignedIdentities to create: 6.901µs
I1108 21:21:58.878921       1 stats.go:162] Find AzureAssignedIdentities to delete: 3.2µs
I1108 21:21:58.878925       1 stats.go:162] Total time to assign or update AzureAssignedIdentities: 121.708795ms
I1108 21:21:58.878928       1 stats.go:162] Total: 121.985311ms
I1108 21:21:58.878932       1 stats.go:212] *********************
I1108 21:21:59.116038       1 mic.go:1040] processing node aks-agentpool-14229154-vmss, add [2], del [0], update [0]
I1108 21:21:59.147501       1 cloudprovider.go:215] updating user-assigned identities on aks-agentpool-14229154-vmss, assign [1], unassign [0]
I1108 21:21:59.175004       1 cloudprovider.go:229] removing /subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/autoscaler-id from ID list since it is erroneous
E1108 21:21:59.175026       1 mic.go:1111] failed to update user-assigned identities on node aks-agentpool-14229154-vmss (add [2], del [0], update[0]), error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/autoscaler-id' or the linked scope(s) are invalid."
E1108 21:21:59.294937       1 mic.go:1129] failed to apply binding keda-system/autoscaler-id-binding node aks-agentpool-14229154-vmss000002 for pod keda-system/keda-operator-metrics-apiserver-97cd665d4-kw4hm, error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/autoscaler-id' or the linked scope(s) are invalid."
E1108 21:21:59.294966       1 mic.go:1129] failed to apply binding keda-system/autoscaler-id-binding node aks-agentpool-14229154-vmss000002 for pod keda-system/keda-operator-7c9b598554-tchmd, error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/autoscaler-id' or the linked scope(s) are invalid."
I1108 21:21:59.294980       1 mic.go:525] work done: true. Found 2 pods, 2 ids, 2 bindings
I1108 21:21:59.294985       1 mic.go:526] total work cycles: 58, out of which work was done in: 16
I1108 21:21:59.294993       1 stats.go:183] ** stats collected **
I1108 21:21:59.294997       1 stats.go:162] Pod listing: 32.002µs
I1108 21:21:59.295003       1 stats.go:162] AzureIdentity listing: 5µs
I1108 21:21:59.295007       1 stats.go:162] AzureIdentityBinding listing: 6.5µs
I1108 21:21:59.295011       1 stats.go:162] AzureAssignedIdentity listing: 8µs
I1108 21:21:59.295015       1 stats.go:162] System: 106.306µs
I1108 21:21:59.295019       1 stats.go:162] CacheSync: 7.5µs
I1108 21:21:59.295022       1 stats.go:162] Cloud provider GET: 178.814123ms
I1108 21:21:59.295026       1 stats.go:162] Cloud provider PATCH: 0s
I1108 21:21:59.295029       1 stats.go:162] AzureAssignedIdentity creation: 0s
I1108 21:21:59.295032       1 stats.go:162] AzureAssignedIdentity update: 0s
I1108 21:21:59.295036       1 stats.go:162] AzureAssignedIdentity deletion: 0s
I1108 21:21:59.295039       1 stats.go:170] Number of cloud provider PATCH: 0
I1108 21:21:59.295042       1 stats.go:170] Number of cloud provider GET: 2
I1108 21:21:59.295045       1 stats.go:170] Number of AzureAssignedIdentities created in this sync cycle: 0
I1108 21:21:59.295048       1 stats.go:170] Number of AzureAssignedIdentities updated in this sync cycle: 0
I1108 21:21:59.295052       1 stats.go:170] Number of AzureAssignedIdentities deleted in this sync cycle: 0
I1108 21:21:59.295055       1 stats.go:162] Find AzureAssignedIdentities to create: 5.601µs
I1108 21:21:59.295059       1 stats.go:162] Find AzureAssignedIdentities to delete: 3µs
I1108 21:21:59.295062       1 stats.go:162] Total time to assign or update AzureAssignedIdentities: 178.93553ms
I1108 21:21:59.295065       1 stats.go:162] Total: 179.140342ms
I1108 21:21:59.295069       1 stats.go:212] *********************
I1108 21:31:57.908577       1 mic.go:1040] processing node aks-agentpool-14229154-vmss, add [2], del [0], update [0]
I1108 21:31:57.950915       1 cloudprovider.go:215] updating user-assigned identities on aks-agentpool-14229154-vmss, assign [1], unassign [0]
I1108 21:31:57.969286       1 cloudprovider.go:229] removing /subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/autoscaler-id from ID list since it is erroneous
E1108 21:31:57.969381       1 mic.go:1111] failed to update user-assigned identities on node aks-agentpool-14229154-vmss (add [2], del [0], update[0]), error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/autoscaler-id' or the linked scope(s) are invalid."
E1108 21:31:58.095188       1 mic.go:1129] failed to apply binding keda-system/autoscaler-id-binding node aks-agentpool-14229154-vmss000002 for pod keda-system/keda-operator-metrics-apiserver-97cd665d4-kw4hm, error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/autoscaler-id' or the linked scope(s) are invalid."
E1108 21:31:58.095217       1 mic.go:1129] failed to apply binding keda-system/autoscaler-id-binding node aks-agentpool-14229154-vmss000002 for pod keda-system/keda-operator-7c9b598554-tchmd, error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/autoscaler-id' or the linked scope(s) are invalid."
I1108 21:31:58.095232       1 mic.go:525] work done: true. Found 2 pods, 2 ids, 2 bindings
I1108 21:31:58.095238       1 mic.go:526] total work cycles: 59, out of which work was done in: 17
I1108 21:31:58.095246       1 stats.go:183] ** stats collected **
I1108 21:31:58.095251       1 stats.go:162] Pod listing: 68.404µs
I1108 21:31:58.095258       1 stats.go:162] AzureIdentity listing: 6.301µs
I1108 21:31:58.095262       1 stats.go:162] AzureIdentityBinding listing: 7.2µs
I1108 21:31:58.095266       1 stats.go:162] AzureAssignedIdentity listing: 10.001µs
I1108 21:31:58.095269       1 stats.go:162] System: 172.11µs
I1108 21:31:58.095510       1 stats.go:162] CacheSync: 10.1µs
I1108 21:31:58.095523       1 stats.go:162] Cloud provider GET: 186.245903ms
I1108 21:31:58.095527       1 stats.go:162] Cloud provider PATCH: 0s
I1108 21:31:58.095530       1 stats.go:162] AzureAssignedIdentity creation: 0s
I1108 21:31:58.095534       1 stats.go:162] AzureAssignedIdentity update: 0s
I1108 21:31:58.095538       1 stats.go:162] AzureAssignedIdentity deletion: 0s
I1108 21:31:58.095541       1 stats.go:170] Number of cloud provider PATCH: 0
I1108 21:31:58.095658       1 stats.go:170] Number of cloud provider GET: 2
I1108 21:31:58.095668       1 stats.go:170] Number of AzureAssignedIdentities created in this sync cycle: 0
I1108 21:31:58.095672       1 stats.go:170] Number of AzureAssignedIdentities updated in this sync cycle: 0
I1108 21:31:58.095675       1 stats.go:170] Number of AzureAssignedIdentities deleted in this sync cycle: 0
I1108 21:31:58.095679       1 stats.go:162] Find AzureAssignedIdentities to create: 5.9µs
I1108 21:31:58.095754       1 stats.go:162] Find AzureAssignedIdentities to delete: 3.8µs
I1108 21:31:58.095764       1 stats.go:162] Total time to assign or update AzureAssignedIdentities: 186.649128ms
I1108 21:31:58.095768       1 stats.go:162] Total: 186.972647ms
I1108 21:31:58.095783       1 stats.go:212] *********************
I1108 21:31:58.297053       1 mic.go:1040] processing node aks-agentpool-14229154-vmss, add [2], del [0], update [0]
I1108 21:31:58.326284       1 cloudprovider.go:215] updating user-assigned identities on aks-agentpool-14229154-vmss, assign [1], unassign [0]
I1108 21:31:58.349202       1 cloudprovider.go:229] removing /subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/autoscaler-id from ID list since it is erroneous
E1108 21:31:58.349402       1 mic.go:1111] failed to update user-assigned identities on node aks-agentpool-14229154-vmss (add [2], del [0], update[0]), error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/autoscaler-id' or the linked scope(s) are invalid."
E1108 21:31:58.460260       1 mic.go:1129] failed to apply binding keda-system/autoscaler-id-binding node aks-agentpool-14229154-vmss000002 for pod keda-system/keda-operator-7c9b598554-tchmd, error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/autoscaler-id' or the linked scope(s) are invalid."
E1108 21:31:58.460288       1 mic.go:1129] failed to apply binding keda-system/autoscaler-id-binding node aks-agentpool-14229154-vmss000002 for pod keda-system/keda-operator-metrics-apiserver-97cd665d4-kw4hm, error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/autoscaler-id' or the linked scope(s) are invalid."
I1108 21:31:58.460302       1 mic.go:525] work done: true. Found 2 pods, 2 ids, 2 bindings
I1108 21:31:58.460309       1 mic.go:526] total work cycles: 60, out of which work was done in: 18
I1108 21:31:58.460317       1 stats.go:183] ** stats collected **
I1108 21:31:58.460321       1 stats.go:162] Pod listing: 31.402µs
I1108 21:31:58.460327       1 stats.go:162] AzureIdentity listing: 4.8µs
I1108 21:31:58.460331       1 stats.go:162] AzureIdentityBinding listing: 9.001µs
I1108 21:31:58.460334       1 stats.go:162] AzureAssignedIdentity listing: 8.901µs
I1108 21:31:58.460338       1 stats.go:162] System: 125.908µs
I1108 21:31:58.460341       1 stats.go:162] CacheSync: 13.201µs
I1108 21:31:58.460345       1 stats.go:162] Cloud provider GET: 163.030195ms
I1108 21:31:58.460348       1 stats.go:162] Cloud provider PATCH: 0s
I1108 21:31:58.460351       1 stats.go:162] AzureAssignedIdentity creation: 0s
I1108 21:31:58.460355       1 stats.go:162] AzureAssignedIdentity update: 0s
I1108 21:31:58.460358       1 stats.go:162] AzureAssignedIdentity deletion: 0s
I1108 21:31:58.460361       1 stats.go:170] Number of cloud provider PATCH: 0
I1108 21:31:58.460364       1 stats.go:170] Number of cloud provider GET: 2
I1108 21:31:58.460367       1 stats.go:170] Number of AzureAssignedIdentities created in this sync cycle: 0
I1108 21:31:58.460371       1 stats.go:170] Number of AzureAssignedIdentities updated in this sync cycle: 0
I1108 21:31:58.460375       1 stats.go:170] Number of AzureAssignedIdentities deleted in this sync cycle: 0
I1108 21:31:58.460378       1 stats.go:162] Find AzureAssignedIdentities to create: 6.401µs
I1108 21:31:58.460381       1 stats.go:162] Find AzureAssignedIdentities to delete: 2.9µs
I1108 21:31:58.460386       1 stats.go:162] Total time to assign or update AzureAssignedIdentities: 163.242707ms
I1108 21:31:58.460389       1 stats.go:162] Total: 163.483322ms
I1108 21:31:58.460392       1 stats.go:212] *********************
I1108 21:31:58.661645       1 mic.go:1040] processing node aks-agentpool-14229154-vmss, add [2], del [0], update [0]
I1108 21:31:58.868573       1 cloudprovider.go:215] updating user-assigned identities on aks-agentpool-14229154-vmss, assign [1], unassign [0]
I1108 21:31:58.907173       1 cloudprovider.go:229] removing /subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/autoscaler-id from ID list since it is erroneous
E1108 21:31:58.907198       1 mic.go:1111] failed to update user-assigned identities on node aks-agentpool-14229154-vmss (add [2], del [0], update[0]), error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/autoscaler-id' or the linked scope(s) are invalid."
E1108 21:31:58.994375       1 mic.go:1129] failed to apply binding keda-system/autoscaler-id-binding node aks-agentpool-14229154-vmss000002 for pod keda-system/keda-operator-metrics-apiserver-97cd665d4-kw4hm, error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/autoscaler-id' or the linked scope(s) are invalid."
E1108 21:31:58.994406       1 mic.go:1129] failed to apply binding keda-system/autoscaler-id-binding node aks-agentpool-14229154-vmss000002 for pod keda-system/keda-operator-7c9b598554-tchmd, error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/autoscaler-id' or the linked scope(s) are invalid."
I1108 21:31:58.994421       1 mic.go:525] work done: true. Found 2 pods, 2 ids, 2 bindings
I1108 21:31:58.994457       1 mic.go:526] total work cycles: 61, out of which work was done in: 19
I1108 21:31:58.994501       1 stats.go:183] ** stats collected **
I1108 21:31:58.994554       1 stats.go:162] Pod listing: 62.304µs
I1108 21:31:58.994575       1 stats.go:162] AzureIdentity listing: 6.2µs
I1108 21:31:58.994591       1 stats.go:162] AzureIdentityBinding listing: 10.401µs
I1108 21:31:58.994607       1 stats.go:162] AzureAssignedIdentity listing: 12.401µs
I1108 21:31:58.994633       1 stats.go:162] System: 233.715µs
I1108 21:31:58.994658       1 stats.go:162] CacheSync: 22.401µs
I1108 21:31:58.994681       1 stats.go:162] Cloud provider GET: 332.554282ms
I1108 21:31:58.994804       1 stats.go:162] Cloud provider PATCH: 0s
I1108 21:31:58.994885       1 stats.go:162] AzureAssignedIdentity creation: 0s
I1108 21:31:58.994967       1 stats.go:162] AzureAssignedIdentity update: 0s
I1108 21:31:58.995035       1 stats.go:162] AzureAssignedIdentity deletion: 0s
I1108 21:31:58.995128       1 stats.go:170] Number of cloud provider PATCH: 0
I1108 21:31:58.995204       1 stats.go:170] Number of cloud provider GET: 2
I1108 21:31:58.995215       1 stats.go:170] Number of AzureAssignedIdentities created in this sync cycle: 0
I1108 21:31:58.995220       1 stats.go:170] Number of AzureAssignedIdentities updated in this sync cycle: 0
I1108 21:31:58.995223       1 stats.go:170] Number of AzureAssignedIdentities deleted in this sync cycle: 0
I1108 21:31:58.995227       1 stats.go:162] Find AzureAssignedIdentities to create: 8.201µs
I1108 21:31:58.995231       1 stats.go:162] Find AzureAssignedIdentities to delete: 4.2µs
I1108 21:31:58.995252       1 stats.go:162] Total time to assign or update AzureAssignedIdentities: 332.771096ms
I1108 21:31:58.995259       1 stats.go:162] Total: 333.226923ms
I1108 21:31:58.995263       1 stats.go:212] *********************
I1108 21:31:59.196570       1 mic.go:1040] processing node aks-agentpool-14229154-vmss, add [2], del [0], update [0]
I1108 21:31:59.231442       1 cloudprovider.go:215] updating user-assigned identities on aks-agentpool-14229154-vmss, assign [1], unassign [0]
I1108 21:31:59.256130       1 cloudprovider.go:229] removing /subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/autoscaler-id from ID list since it is erroneous
E1108 21:31:59.256151       1 mic.go:1111] failed to update user-assigned identities on node aks-agentpool-14229154-vmss (add [2], del [0], update[0]), error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/autoscaler-id' or the linked scope(s) are invalid."
E1108 21:31:59.330975       1 mic.go:1129] failed to apply binding keda-system/autoscaler-id-binding node aks-agentpool-14229154-vmss000002 for pod keda-system/keda-operator-metrics-apiserver-97cd665d4-kw4hm, error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/autoscaler-id' or the linked scope(s) are invalid."
E1108 21:31:59.331009       1 mic.go:1129] failed to apply binding keda-system/autoscaler-id-binding node aks-agentpool-14229154-vmss000002 for pod keda-system/keda-operator-7c9b598554-tchmd, error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/autoscaler-id' or the linked scope(s) are invalid."
I1108 21:31:59.331024       1 mic.go:525] work done: true. Found 2 pods, 2 ids, 2 bindings
I1108 21:31:59.331030       1 mic.go:526] total work cycles: 62, out of which work was done in: 20
I1108 21:31:59.331038       1 stats.go:183] ** stats collected **
I1108 21:31:59.331043       1 stats.go:162] Pod listing: 32.202µs
I1108 21:31:59.331049       1 stats.go:162] AzureIdentity listing: 4.9µs
I1108 21:31:59.331226       1 stats.go:162] AzureIdentityBinding listing: 9.101µs
I1108 21:31:59.331346       1 stats.go:162] AzureAssignedIdentity listing: 9.6µs
I1108 21:31:59.331442       1 stats.go:162] System: 150.309µs
I1108 21:31:59.331529       1 stats.go:162] CacheSync: 19.701µs
I1108 21:31:59.331598       1 stats.go:162] Cloud provider GET: 134.29945ms
I1108 21:31:59.331696       1 stats.go:162] Cloud provider PATCH: 0s
I1108 21:31:59.331709       1 stats.go:162] AzureAssignedIdentity creation: 0s
I1108 21:31:59.331712       1 stats.go:162] AzureAssignedIdentity update: 0s
I1108 21:31:59.331715       1 stats.go:162] AzureAssignedIdentity deletion: 0s
I1108 21:31:59.331720       1 stats.go:170] Number of cloud provider PATCH: 0
I1108 21:31:59.331724       1 stats.go:170] Number of cloud provider GET: 2
I1108 21:31:59.331727       1 stats.go:170] Number of AzureAssignedIdentities created in this sync cycle: 0
I1108 21:31:59.331730       1 stats.go:170] Number of AzureAssignedIdentities updated in this sync cycle: 0
I1108 21:31:59.331733       1 stats.go:170] Number of AzureAssignedIdentities deleted in this sync cycle: 0
I1108 21:31:59.331737       1 stats.go:162] Find AzureAssignedIdentities to create: 7.301µs
I1108 21:31:59.331741       1 stats.go:162] Find AzureAssignedIdentities to delete: 2.8µs
I1108 21:31:59.331745       1 stats.go:162] Total time to assign or update AzureAssignedIdentities: 134.447859ms
I1108 21:31:59.331748       1 stats.go:162] Total: 134.724576ms

@iarunpaul
Copy link
Author

iarunpaul commented Nov 8, 2021

Iran this command to assign roles to the cluster:
curl -s https://raw.githubusercontent.com/Azure/aad-pod-identity/master/hack/role-assignment.sh | bash
and got the result:

I1108 20:52:01.602432       1 main.go:114] starting mic process. Version: v1.8.5. Build date: 2021-10-11-23:36
W1108 20:52:01.602484       1 main.go:119] --kubeconfig not passed will use InClusterConfig
I1108 20:52:01.602491       1 main.go:136] kubeconfig () cloudconfig (/etc/kubernetes/azure.json)
I1108 20:52:01.602591       1 main.go:144] running MIC in namespaced mode: false
I1108 20:52:01.602599       1 main.go:148] client QPS set to: 5. Burst to: 5
I1108 20:52:01.602617       1 mic.go:138] starting to create the pod identity client. Version: v1.8.5. Build date: 2021-10-11-23:36
I1108 20:52:01.629071       1 mic.go:144] Kubernetes server version: v1.20.9
I1108 20:52:01.629331       1 cloudprovider.go:122] MIC using user assigned identity: 45bf##### REDACTED #####9550 for authentication.
I1108 20:52:01.634246       1 probes.go:41] initialized health probe on port 8080
I1108 20:52:01.634295       1 probes.go:44] started health probe
I1108 20:52:01.634417       1 metrics.go:341] registered views for metric
I1108 20:52:01.634639       1 prometheus_exporter.go:21] starting Prometheus exporter
I1108 20:52:01.634677       1 metrics.go:347] registered and exported metrics on port 8888
I1108 20:52:01.634689       1 mic.go:242] initiating MIC Leader election
I1108 20:52:01.634698       1 leaderelection.go:248] attempting to acquire leader lease default/aad-pod-identity-mic...
iarunpaul@DESKTOP-4FLVDKD:~/k8s/manifest-files$ curl -s https://raw.githubusercontent.com/Azure/aad-pod-identity/master/hack/role-assignment.sh | bash
Retrieving your node resource group
WARNING: The behavior of this command has been altered by the following extension: aks-preview
Retrieving your cluster identity ID, which will be used for role assignment
WARNING: The behavior of this command has been altered by the following extension: aks-preview
Checking if the aks cluster is using managed identity
WARNING: The behavior of this command has been altered by the following extension: aks-preview
Assigning 'Managed Identity Operator' role to 45bf18cc-232d-4881-862b-2db0b3e99550
{
  "canDelegate": null,
  "condition": null,
  "conditionVersion": null,
  "description": null,
  "id": "/subscriptions/xxxxx-xxxxx-xxxxx-xxxxx/resourcegroups/MC_Arun_democluster_westeurope/providers/Microsoft.Authorization/roleAssignments/ad1e5e6b-781e-4e5d-b767-a4da0170d3e7",
  "name": "ad1e5e6b-781e-4e5d-b767-a4da0170d3e7",
  "principalId": "fe0d7679-8477-48e3-ae7d-43e2a6fdb957",
  "principalName": "45bf18cc-232d-4881-862b-2db0b3e99550",
  "principalType": "ServicePrincipal",
  "resourceGroup": "MC_Arun_democluster_westeurope",
  "roleDefinitionId": "/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/providers/Microsoft.Authorization/roleDefinitions/f1a07417-d97a-45cb-824c-7a7467783830",
  "roleDefinitionName": "Managed Identity Operator",
  "scope": "/subscriptions/xxxxx-xxxxx-xxxxx-xxxxx/resourcegroups/MC_Arun_democluster_westeurope",
  "type": "Microsoft.Authorization/roleAssignments"
}
Assigning 'Virtual Machine Contributor' role to 45bf18cc-232d-4881-862b-2db0b3e99550
{
  "canDelegate": null,
  "condition": null,
  "conditionVersion": null,
  "description": null,
  "id": "/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/MC_Arun_democluster_westeurope/providers/Microsoft.Authorization/roleAssignments/b7690dc0-485c-4f3c-9d1c-763b0936d5df",
  "name": "b7690dc0-485c-4f3c-9d1c-763b0936d5df",
  "principalId": "fe0d7679-8477-48e3-ae7d-43e2a6fdb957",
  "principalName": "45bf18cc-232d-4881-862b-2db0b3e99550",
  "principalType": "ServicePrincipal",
  "resourceGroup": "MC_Arun_democluster_westeurope",
  "roleDefinitionId": "/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/providers/Microsoft.Authorization/roleDefinitions/9980e02c-c2be-4d73-94e8-173b1dc7cf3c",
  "roleDefinitionName": "Virtual Machine Contributor",
  "scope": "/subscriptions/xxxxx-xxxxx-xxxxx-xxxxx/resourcegroups/MC_Arun_democluster_westeurope",
  "type": "Microsoft.Authorization/roleAssignments"
}

@iarunpaul
Copy link
Author

But still the AAD Pod Identity pods shows roles errors :(

@JorTurFer
Copy link
Member

This line is strange:

E1108 21:03:08.258262       1 mic.go:1129] failed to apply binding keda-dotnet-sample/order-processor-id-binding node aks-agentpool-14229154-vmss000002 for pod keda-dotnet-sample/order-processor-589f9b8645-4s5sm, error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/order-processor-id' or the linked scope(s) are invalid."

The message basically says that your identity can't be assigned to the VMSS.
Please, review that this identity fe0d7679-8477-48e3-ae7d-43e2a6fdb957 (I think that it is inside your nodes' resource group) has the permission to perform Microsoft.Compute/virtualMachineScaleSets/write in the resource group MC_Arun_democluster_westeurope. If I'm not wrong, you can do it with this role Virtual Machine Contributor.

I have several problems in the past configuring AAD Pod Identity. I think that you should also grant the roles and permissions to kubelet MSI (the MSI inside the node resource group). I know that it's not documented, but it's the only way that I found to solve the issue, granting to both MSI (k8s and kubelet) the roles that are in the examples.

Once the role assignment are done (and after giving a few minutes to refresh the tokens and propagate the changes), if you restart the mic pod you should see that now it works

@JorTurFer JorTurFer self-assigned this Nov 8, 2021
@iarunpaul
Copy link
Author

Okay...Is this a rare case while configuring pod identity?
So you mean I have to assign roles to kubelet also to make it work...rt?
But it requires some research for me..
I will check it and update... Thanks for your help @JorTurFer

@iarunpaul
Copy link
Author

This ms documentation, says there is a limitation to bring your own kubelet id on system-assigned managed cluster.
Limitations

  • Only works with a User-Assigned Managed cluster.
    So I would think that I have to create a new cluster like:
az aks create \
    --resource-group myResourceGroup \
    --name myManagedCluster \
    --network-plugin azure \
    --vnet-subnet-id <subnet-id> \
    --docker-bridge-address 172.17.0.1/16 \
    --dns-service-ip 10.2.0.10 \
    --service-cidr 10.2.0.0/24 \
    --enable-managed-identity \
    --assign-identity <identity-id> \
    --assign-kubelet-identity <kubelet-identity-id>

and assign the roles to both cluster id and kubelet id.
Could you please confirm if Im doing it right?

@JorTurFer
Copy link
Member

No no, don't worry about setting the ids.
You can create the cluster as usually, The point is that after cluster creation, inside the resource group where the nodes are created, a system managed identity has been created also. The name of this identity is like {clusterName}-agentpool.
image

This MSI is in your case, which has the id fe0d7679-8477-48e3-ae7d-43e2a6fdb957. Basically that id is used by kubelet and by the AAD Pod Identity to work. My suggestion is granting the role assignments to this MSI in addition of the cluster MSI.

If you can't see any MSI in your nodes' resource group, maybe it's because you have created your cluster using Service Principal instead MSI.

@iarunpaul
Copy link
Author

image

@iarunpaul
Copy link
Author

When I check it the MSI fe0d7679-8477-48e3-ae7d-43e2a6fdb957 is assigned the roles correctly as the screen shot.
I reassigned the cluster roles again restarted the pods. still Im getting the logs with same error..

E1110 02:31:09.031633       1 mic.go:1129] failed to apply binding keda-system/autoscaler-id-binding node aks-agentpool-14229154-vmss000002 for pod keda-system/keda-operator-7c9b598554-tchmd, error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/autoscaler-id' or the linked scope(s) are invalid."
E1110 02:31:09.031664       1 mic.go:1129] failed to apply binding keda-system/autoscaler-id-binding node aks-agentpool-14229154-vmss000002 for pod keda-system/keda-operator-metrics-apiserver-97cd665d4-kw4hm, error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/autoscaler-id' or the linked scope(s) are invalid."
I1110 02:31:09.031680       1 mic.go:525] work done: true. Found 2 pods, 2 ids, 2 bindings
I1110 02:31:09.031686       1 mic.go:526] total work cycles: 17, out of which work was done in: 17
I1110 02:31:09.031735       1 stats.go:183] ** stats collected **
I1110 02:31:09.031740       1 stats.go:162] Pod listing: 30.801µs
I1110 02:31:09.031751       1 stats.go:162] AzureIdentity listing: 6.5µs
I1110 02:31:09.031755       1 stats.go:162] AzureIdentityBinding listing: 9.701µs
I1110 02:31:09.031759       1 stats.go:162] AzureAssignedIdentity listing: 10.601µs
I1110 02:31:09.031763       1 stats.go:162] System: 172.61µs
I1110 02:31:09.031766       1 stats.go:162] CacheSync: 28.801µs
I1110 02:31:09.031770       1 stats.go:162] Cloud provider GET: 321.301165ms
I1110 02:31:09.031774       1 stats.go:162] Cloud provider PATCH: 0s
I1110 02:31:09.031795       1 stats.go:162] AzureAssignedIdentity creation: 0s
I1110 02:31:09.031831       1 stats.go:162] AzureAssignedIdentity update: 0s
I1110 02:31:09.031843       1 stats.go:162] AzureAssignedIdentity deletion: 0s
I1110 02:31:09.031847       1 stats.go:170] Number of cloud provider PATCH: 0
I1110 02:31:09.031862       1 stats.go:170] Number of cloud provider GET: 2
I1110 02:31:09.031865       1 stats.go:170] Number of AzureAssignedIdentities created in this sync cycle: 0
I1110 02:31:09.031868       1 stats.go:170] Number of AzureAssignedIdentities updated in this sync cycle: 0
I1110 02:31:09.031871       1 stats.go:170] Number of AzureAssignedIdentities deleted in this sync cycle: 0
I1110 02:31:09.031874       1 stats.go:162] Find AzureAssignedIdentities to create: 7.1µs
I1110 02:31:09.031878       1 stats.go:162] Find AzureAssignedIdentities to delete: 4.2µs
I1110 02:31:09.031881       1 stats.go:162] Total time to assign or update AzureAssignedIdentities: 321.442873ms
I1110 02:31:09.031884       1 stats.go:162] Total: 321.800194ms
I1110 02:31:09.031926       1 stats.go:212] *********************

@JorTurFer
Copy link
Member

JorTurFer commented Nov 12, 2021

hi @iarunpaul ,
Sorry for the delay. I see that you still have errors in the AAD Pod identity side:

E1110 02:31:09.031633       1 mic.go:1129] failed to apply binding keda-system/autoscaler-id-binding node aks-agentpool-14229154-vmss000002 for pod keda-system/keda-operator-7c9b598554-tchmd, error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/autoscaler-id' or the linked scope(s) are invalid."
E1110 02:31:09.031664       1 mic.go:1129] failed to apply binding keda-system/autoscaler-id-binding node aks-agentpool-14229154-vmss000002 for pod keda-system/keda-operator-metrics-apiserver-97cd665d4-kw4hm, error: failed to update identities for aks-agentpool-14229154-vmss in MC_Arun_democluster_westeurope, error: compute.VirtualMachineScaleSetsClient#Update: Failure sending request: StatusCode=0 -- Original Error: Code="LinkedAuthorizationFailed" Message="The client 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' with object id 'fe0d7679-8477-48e3-ae7d-43e2a6fdb957' has permission to perform action 'Microsoft.Compute/virtualMachineScaleSets/write' on scope '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourceGroups/MC_Arun_democluster_westeurope/providers/Microsoft.Compute/virtualMachineScaleSets/aks-agentpool-14229154-vmss'; however, it does not have permission to perform action 'Microsoft.ManagedIdentity/userAssignedIdentities/assign/action' on the linked scope(s) '/subscriptions/f3786c6b-8dca-417d-af3f-23929e8b4129/resourcegroups/arun/providers/microsoft.managedidentity/userassignedidentities/autoscaler-id' or the linked scope(s) are invalid."

In the end of the lines, you could see the identity id that is trying to assign a permission, and what permission is needed. Before solving these problems, KEDA will not be able to use MSI because it can't get the token from AAD Pod Identity

@iarunpaul
Copy link
Author

Let me create the cluster and install the AAD Pod Id again and update then today!

@stale
Copy link

stale bot commented Jan 11, 2022

This issue has been automatically marked as stale because it has not had recent activity. It will be closed in 7 days if no further activity occurs. Thank you for your contributions.

@stale stale bot added the stale All issues that are marked as stale due to inactivity label Jan 11, 2022
@dariuszbz
Copy link

@JorTurFer when you said:
on Nov 7, 2021
hi again @iarunpaul ,
Finally I found time to take a look at this. I deployed KEDA (v2.4) using helm in a cluster with AAD Pod Identity (deployed with helm too) and a workload with Service Bus Scaler. It works without any other problem.

could you drop installation process, please? I kind of hard to find details around it.

I understand
helm install aad-pod-identity aad-pod-identity/aad-pod-identity
helm install keda kedacore/keda --namespace-keda

is the above correct?
If yes: how did you mange to create ScaledObject and TriggerAuthentication - could you attach you working examples, please?

I'm sure step by step with examples will help Azure geeks to undertsand.

@stale stale bot removed the stale All issues that are marked as stale due to inactivity label Jan 14, 2022
@JorTurFer
Copy link
Member

Hi @dariuszbz ,
There is a sample about how to use KEDA with AAD-Pod-Identity. You could find it here. 😄

@dariuszbz
Copy link

@JorTurFer thank You!

I'm not sure about that:

"After that, we create an orders queue in our namespace:

❯ az servicebus queue create --namespace-name --name orders --resource-group
Next, we need to grant our identities to be able to authenticate to Azure Service Bus.

❯ az servicebus queue create --namespace-name --name orders --resource-group
"

two lines (az command) are the same. Should the second line (az command) be different? both commands does the same.

@JorTurFer
Copy link
Member

I think that you could ignore one of them (it seems a typo) but maybe @tomkerkhove could confirm it

@tomkerkhove
Copy link
Member

Yes, you can leave out the second one

@dariuszbz
Copy link

dariuszbz commented Jan 14, 2022

ok. So to make my life simple I created below .... and it won't work :( what is wrong below?



$resourceGroup = "<node resource group>"
$aksResourceGroup = "<aks resource group>"
$aksName = "<aks name>"


kubectl create namespace aad-pod-identity
helm repo add aad-pod-identity https://raw.githubusercontent.com/Azure/aad-pod-identity/master/charts
helm install aad-pod-identity aad-pod-identity/aad-pod-identity --namespace aad-pod-identity

$resourceGroup_ResourceId = az group show --name $resourceGroup --query id -otsv
$aad_pod_identity_clientid = az aks show -g $aksResourceGroup -n $aksName --query identityProfile.kubeletidentity.clientId -otsv
az role assignment create --role "Managed Identity Operator" --assignee $aad_pod_identity_clientid  --scope $resourceGroup_ResourceId
az role assignment create --role "Virtual Machine Contributor" --assignee $aad_pod_identity_clientid  --scope $resourceGroup_ResourceId

az identity create --name autoscaler-aad-identity --resource-group $resourceGroup
$autoscaler_aad_identity_clientId = az identity show --name autoscaler-aad-identity --resource-group $resourceGroup --query clientId -otsv
$autoscaler_aad_identity_resourceId = az identity show --name autoscaler-aad-identity --resource-group $resourceGroup --query id -otsv

az identity create --name app-aad-identity --resource-group $resourceGroup
$app_aad_identity_clientId = az identity show --name app-aad-identity --resource-group $resourceGroup --query clientId -otsv
$app_aad_identity_resourceId = az identity show --name app-aad-identity --resource-group $resourceGroup --query id -otsv

az servicebus namespace create --name svcbusdebe --resource-group $resourceGroup --sku basic
$servicebus_namespace_resourceId = az servicebus namespace show --name svcbusdebe --resource-group $resourceGroup --query id -otsv

az servicebus queue create --namespace-name svcbusdebe --name orders --resource-group $resourceGroup
$servicebus_queue_resourceId = az servicebus queue show --namespace-name svcbusdebe --name orders --resource-group $resourceGroup --query id -otsv

az role assignment create --role 'Azure Service Bus Data Receiver' --assignee $app_aad_identity_clientId  --scope $servicebus_queue_resourceId

kubectl create namespace keda-dotnet-sample

$app_with_identity_yaml= @"
apiVersion: aadpodidentity.k8s.io/v1
kind: AzureIdentity
metadata:
  name: app-aad-identity
  annotations:
    aadpodidentity.k8s.io/Behavior: namespaced
spec:
  type: 0 # 0 means User-assigned MSI
  resourceID: $app_aad_identity_resourceId
  clientID: $app_aad_identity_clientId
---
apiVersion: aadpodidentity.k8s.io/v1
kind: AzureIdentityBinding
metadata:
  name: app-aad-identity-binding
spec:
  azureIdentity: app-aad-identity
  selector: order-processor
---
apiVersion: apps/v1
kind: Deployment
metadata:
  name: order-processor
  labels:
    app: order-processor
spec:
  selector:
    matchLabels:
      app: order-processor
  template:
    metadata:
      labels:
        app: order-processor
        aadpodidbinding: order-processor
    spec:
      containers:
      - name: order-processor
        image: ghcr.io/kedacore/sample-dotnet-worker-servicebus-queue:latest
        env:
        - name: KEDA_SERVICEBUS_AUTH_MODE
          value: ManagedIdentity
        - name: KEDA_SERVICEBUS_HOST_NAME
          value: svcbusdebe.servicebus.windows.net
        - name: KEDA_SERVICEBUS_QUEUE_NAME
          value: orders
        - name: KEDA_SERVICEBUS_IDENTITY_USERASSIGNEDID
          value: $app_aad_identity_clientId
"@
$app_with_identity_yaml | kubectl apply --namespace keda-dotnet-sample -f -


kubectl create namespace keda-system

$autoscaler_yaml =@"
apiVersion: aadpodidentity.k8s.io/v1
kind: AzureIdentity
metadata:
  name: autoscaler-aad-identity
spec:
  type: 0 # 0 means User-assigned MSI
  resourceID: $autoscaler_aad_identity_resourceId
  clientID: $autoscaler_aad_identity_clientId
---
apiVersion: aadpodidentity.k8s.io/v1
kind: AzureIdentityBinding
metadata:
  name: autoscaler-aad-identity-binding
spec:
  azureIdentity: autoscaler-aad-identity
  selector: app-autoscaler
"@

$autoscaler_yaml | kubectl apply --namespace keda-system -f -

helm install keda kedacore/keda --set podIdentity.activeDirectory.identity=autoscaler-aad-identity --namespace keda-system

az role assignment create --role 'Azure Service Bus Data Owner' --assignee $autoscaler_aad_identity_clientId --scope $servicebus_namespace_resourceId


$aap_autoscaling_yaml = @"
apiVersion: keda.sh/v1alpha1
kind: TriggerAuthentication
metadata:
  name: trigger-auth-service-bus-orders
spec:
  podIdentity:
    provider: azure
---
apiVersion: keda.sh/v1alpha1 
kind: ScaledObject
metadata:
  name: order-scaler
spec:
  scaleTargetRef:
    name: order-processor
  # minReplicaCount: 0 Change to define how many minimum replicas you want
  maxReplicaCount: 10
  triggers:
  - type: azure-servicebus
    metadata:
      namespace: svcbusdebe
      queueName: orders
      messageCount: '5'
    authenticationRef:
      name: trigger-auth-service-bus-orders
"@
$aap_autoscaling_yaml | kubectl apply --namespace keda-dotnet-sample -f -

@JorTurFer
Copy link
Member

Hi @dariuszbz ,
You should troubleshoot the problem, from the script it's too difficult figure out it. Maybe in KEDA logs, but I bet the problem is in aad-pod-identity side. Please check aad-pod-identity mic and nmi and check this thread because the solution surely is already here.
If you can't solve it, please paste the logs here 😄

@iarunpaul
Copy link
Author

@tomkerkhove @dariuszbz @JorTurFer
AAD Pod Identity is disabled by default on Clusters with Kubenet starting from release v1.7.
We need to look at it if the cluster is configured with kubenet.
When I tried to install AAD Pod Id on the cluster with kubenet, with the command,
kubectl apply -f https://raw.githubusercontent.com/Azure/aad-pod-identity/v1.8.4/deploy/infra/deployment-rbac.yaml
the nmi pod CrashLoops with the logs:

F0116 17:04:09.101102       1 main.go:83] AAD Pod Identity is not supported for Kubenet. Review https://azure.github.io/aad-pod-identity/docs/configure/aad_pod_identity_on_kubenet/ for more details.
goroutine 1 [running]:
k8s.io/klog/v2.stacks(0x1)
        /go/pkg/mod/k8s.io/klog/v2@v2.9.0/klog.go:1026 +0x8a
k8s.io/klog/v2.(*loggingT).output(0x2477340, 0x3, {0x0, 0x0}, 0xc00053b180, 0x0, {0x1c269ce, 0xc0000d9600}, 0xc0000d8d00, 0x0)
        /go/pkg/mod/k8s.io/klog/v2@v2.9.0/klog.go:975 +0x63d
k8s.io/klog/v2.(*loggingT).printf(0x4, 0x0, {0x0, 0x0}, {0x0, 0x0}, {0x172bde1, 0x9c}, {0x0, 0x0, ...})
        /go/pkg/mod/k8s.io/klog/v2@v2.9.0/klog.go:753 +0x1e5
k8s.io/klog/v2.Fatalf(...)
        /go/pkg/mod/k8s.io/klog/v2@v2.9.0/klog.go:1514
main.main()
        /go/src/github.com/Azure/aad-pod-identity/cmd/nmi/main.go:83 +0x2da

goroutine 18 [chan receive]:
k8s.io/klog/v2.(*loggingT).flushDaemon(0x0)
        /go/pkg/mod/k8s.io/klog/v2@v2.9.0/klog.go:1169 +0x6a
created by k8s.io/klog/v2.init.0
        /go/pkg/mod/k8s.io/klog/v2@v2.9.0/klog.go:420 +0xfb

goroutine 19 [select]:
go.opencensus.io/stats/view.(*worker).start(0xc0000887d0)
        /go/pkg/mod/go.opencensus.io@v0.22.3/stats/view/worker.go:154 +0xb9
created by go.opencensus.io/stats/view.init.0
        /go/pkg/mod/go.opencensus.io@v0.22.3/stats/view/worker.go:32 +0x87

This is a workaround to read.
I will try to create an aks with CNI or follow the workaround and update

@tomkerkhove
Copy link
Member

Thanks for letting us know, I was not aware of it! Once you have the outcome of CNI I will update our FAQ/troubleshooting.

@iarunpaul
Copy link
Author

iarunpaul commented Jan 17, 2022

I tried the workaround for kubenet , but not in success yet but pretty close, I think!
Here's what I did!

Keda pod id with Managed Identity

Recreate Issue

We create the aks with the commands:

Checked the providers are registered

az provider show -n Microsoft.OperationsManagement -o table
az provider show -n Microsoft.OperationalInsights -o table

Create the cluster

AksResourceGroup="myResourceGroup"
ClusteName="myAksCluster"
az aks create --resource-group $AksResourceGroup --name $ClusteName --node-count 1 --enable-addons monitoring

Install AAD Pod Identity on cluster

kubectl apply -f https://raw.githubusercontent.com/Azure/aad-pod-identity/v1.8.4/deploy/infra/deployment-rbac.yaml

AAD Pod Identity is disabled by default on Clusters with Kubenet starting from release v1.7.

We need to look at it if the cluster is configured with kubenet.
When I tried to install AAD Pod Id on the cluster with kubenet, with the command

kubectl apply -f https://raw.githubusercontent.com/Azure/aad-pod-identity/v1.8.4/deploy/infra/deployment-rbac.yaml
the nmi pod CrashLoops with the logs:

F0116 17:04:09.101102       1 main.go:83] AAD Pod Identity is not supported for Kubenet. Review https://azure.github.io/aad-pod-identity/docs/configure/aad_pod_identity_on_kubenet/ for more details.
goroutine 1 [running]:
k8s.io/klog/v2.stacks(0x1)
        /go/pkg/mod/k8s.io/klog/v2@v2.9.0/klog.go:1026 +0x8a
k8s.io/klog/v2.(*loggingT).output(0x2477340, 0x3, {0x0, 0x0}, 0xc00053b180, 0x0, {0x1c269ce, 0xc0000d9600}, 0xc0000d8d00, 0x0)
        /go/pkg/mod/k8s.io/klog/v2@v2.9.0/klog.go:975 +0x63d
k8s.io/klog/v2.(*loggingT).printf(0x4, 0x0, {0x0, 0x0}, {0x0, 0x0}, {0x172bde1, 0x9c}, {0x0, 0x0, ...})
        /go/pkg/mod/k8s.io/klog/v2@v2.9.0/klog.go:753 +0x1e5
k8s.io/klog/v2.Fatalf(...)
        /go/pkg/mod/k8s.io/klog/v2@v2.9.0/klog.go:1514
main.main()
        /go/src/github.com/Azure/aad-pod-identity/cmd/nmi/main.go:83 +0x2da

goroutine 18 [chan receive]:
k8s.io/klog/v2.(*loggingT).flushDaemon(0x0)
        /go/pkg/mod/k8s.io/klog/v2@v2.9.0/klog.go:1169 +0x6a
created by k8s.io/klog/v2.init.0
        /go/pkg/mod/k8s.io/klog/v2@v2.9.0/klog.go:420 +0xfb

goroutine 19 [select]:
go.opencensus.io/stats/view.(*worker).start(0xc0000887d0)
        /go/pkg/mod/go.opencensus.io@v0.22.3/stats/view/worker.go:154 +0xb9
created by go.opencensus.io/stats/view.init.0
        /go/pkg/mod/go.opencensus.io@v0.22.3/stats/view/worker.go:32 +0x87

This is a workaround to read.

I edited the daemonset nmi and added the flag --allow-network-plugin-kubenet=true and now the nmi pods runs

NAME                   READY   STATUS    RESTARTS   AGE
mic-68c7ccd865-5kvlp   1/1     Running   0          6h2m
mic-68c7ccd865-nc5kz   1/1     Running   0          6h2m
nmi-v25vr              1/1     Running   0          6h1m

Create the required identities

# NodeResourceGroup="MC_myResourceGroup_myAksCluster_centralindia"
NodeResourceGroup=$(az aks show -g myResourceGroup -n myAKSCluster --query nodeResourceGroup -o tsv)

az identity create --name orderprocessor --resource-group $NodeResourceGroup
az identity create --name autoscaler --resource-group $NodeResourceGroup

Assigning roles to the MIs

AutoScalerObjId="$(az identity show --name autoscaler --resource-group $NodeResourceGroup --query "principalId" -o tsv)"

OrderObjId="$(az identity show --name orderprocessor --resource-group $NodeResourceGroup --query "principalId" -o tsv)"

We create the service bus then

ServiceBusNamespace="orderbusnamespace"
QueueName="orders"

az servicebus namespace create --name $ServiceBusNamespace --resource-group $AksResourceGroup --sku basic

az servicebus queue create --namespace-name $ServiceBusNamespace --name $QueueName --resource-group $AksResourceGroup

Assign role to MI

ServiceBusResourceId="$(az servicebus namespace show --name $ServiceBusNamespace --resource-group $AksResourceGroup --query id -o tsv)"
az role assignment create --role 'Azure Service Bus Data Receiver' --assignee $OrderObjId --scope $ServiceBusResourceId

az role assignment create --role 'Azure Service Bus Data Owner' --assignee $AutoScalerObjId --scope $ServiceBusResourceId

Install KEDA using Helm

helm repo add kedacore https://kedacore.github.io/charts
helm repo update

kubectl create namespace keda-system
helm install keda kedacore/keda --set podIdentity.activeDirectory.identity=app-autoscaler --namespace keda-system

Apply autoscaling infrastructure in keda-system namespace

apiVersion: aadpodidentity.k8s.io/v1
kind: AzureIdentity
metadata:
  name: autoscaler-id
spec:
  type: 0 # 0 means User-assigned MSI
  resourceID: /subscriptions/<subscriptio-id>/resourcegroups/MC_myResourceGroup_myAksCluster_centralindia/providers/Microsoft.ManagedIdentity/userAssignedIdentities/autoscaler
  clientID: <client-guid-id>

---
apiVersion: aadpodidentity.k8s.io/v1
kind: AzureIdentityBinding
metadata:
  name: autoscaler-id-binding
spec:
  azureIdentity: autoscaler-id
  selector: app-autoscaler

Apply app auto-scaling objects in keda-dotnet-system

apiVersion: keda.sh/v1alpha1
kind: TriggerAuthentication
metadata:
  name: trigger-auth-service-bus-orders
spec:
  podIdentity:
    provider: azure
---
apiVersion: keda.sh/v1alpha1 
kind: ScaledObject
metadata:
  name: order-scaler
spec:
  scaleTargetRef:
    name: order-processor
  # minReplicaCount: 0 Change to define how many minimum replicas you want
  maxReplicaCount: 10
  triggers:
  - type: azure-servicebus
    metadata:
      namespace: orderbusnamespace
      queueName: orders
      messageCount: '5'
    authenticationRef:
      name: trigger-auth-service-bus-orders

Run the command and check if it reads the KEDA metrics

kubectl get deployments --namespace keda-dotnet-sample -o wide

NAME              READY   UP-TO-DATE   AVAILABLE   AGE   CONTAINERS        IMAGES                                                          SELECTOR
order-processor   0/0     0            0           60m   order-processor   ghcr.io/kedacore/sample-dotnet-worker-servicebus-queue:latest   app=order-processor

Queue some messages

dotnet run --project src/Keda.Samples.Dotnet.OrderGenerator/Keda.Samples.Dotnet.OrderGenerator.csproj

Still no scaling

Checked the scaled object events

Events:
  Type     Reason                      Age                   From           Message
  ----     ------                      ----                  ----           -------
  Normal   KEDAScalersStarted          18m                   keda-operator  Started scalers watch
  Normal   KEDAScaleTargetDeactivated  18m                   keda-operator  Deactivated apps/v1.Deployment keda-dotnet-sample/order-processor from 1 to 0
  Normal   ScaledObjectReady           18m (x2 over 18m)     keda-operator  ScaledObject is ready for scaling
  Warning  KEDAScalerFailed            3m35s (x31 over 18m)  keda-operator  Get "http://169.254.169.254/metadata/identity/oauth2/token?api-version=2018-02-01&resource=https%3A%2F%2Fservicebus.azure.net%2F": context deadline exceeded (Client.Timeout exceeded while awaiting headers)

Checked the KEDA pod logs


2022-01-17T07:59:22.742Z        ERROR   azure_servicebus_scaler error   {"error": "Get \"http://169.254.169.254/metadata/identity/oauth2/token?api-version=2018-02-01&resource=https%3A%2F%2Fservicebus.azure.net%2F\": context deadline exceeded (Client.Timeout exceeded while awaiting headers)"}
github.com/kedacore/keda/v2/pkg/scaling.(*scaleHandler).checkScalers
        /workspace/pkg/scaling/scale_handler.go:261
github.com/kedacore/keda/v2/pkg/scaling.(*scaleHandler).startScaleLoop
        /workspace/pkg/scaling/scale_handler.go:146
2022-01-17T07:59:49.742Z        ERROR   azure_servicebus_scaler error   {"error": "Get \"http://169.254.169.254/metadata/identity/oauth2/token?api-version=2018-02-01&resource=https%3A%2F%2Fservicebus.azure.net%2F\": context deadline exceeded (Client.Timeout exceeded while awaiting headers)"}
github.com/kedacore/keda/v2/pkg/scaling.(*scaleHandler).checkScalers
        /workspace/pkg/scaling/scale_handler.go:261
github.com/kedacore/keda/v2/pkg/scaling.(*scaleHandler).startScaleLoop
        /workspace/pkg/scaling/scale_handler.go:146
2022-01-17T07:59:52.744Z        ERROR   azure_servicebus_scaler error   {"error": "Get \"http://169.254.169.254/metadata/identity/oauth2/token?api-version=2018-02-01&resource=https%3A%2F%2Fservicebus.azure.net%2F\": context deadline exceeded (Client.Timeout exceeded while awaiting headers)"}
github.com/kedacore/keda/v2/pkg/scaling.(*scaleHandler).checkScalers
        /workspace/pkg/scaling/scale_handler.go:261
github.com/kedacore/keda/v2/pkg/scaling.(*scaleHandler).startScaleLoop
        /workspace/pkg/scaling/scale_handler.go:146

Assign the Virtual Machine Contributor and Manage Identity Operator roles on $NodeResourceGroup scope

NodeResourceGroup=$(az aks show -g myResourceGroup -n myAKSCluster --query nodeResourceGroup -o tsv)

ClusterClientId=$(az aks show -g myResourceGroup -n myAKSCluster --query "identity.principalId" -o tsv)

az role assignment create --role 'Virtual Machine Contributor' --assignee $ClusterClientId --scope /subscriptions/<subscriptio-id>/resourceGroups/$NodeResourceGroup

az role assignment create --role 'Managed Identity Operator' --assignee $ClusterClientId --scope /subscriptions/<subscriptio-id>/resourceGroups/$NodeResourceGroup

But still no success and trying !!!

@dariuszbz
Copy link

@JorTurFer I have followed documentation and I have dropped you the e2e script. Let me run that again and I'll drop you logs. Just which logs would you need, please? There is a plenty from K8s :) I don't want to keep you busy for a next few winters ;) as I need to test it and recommend for production or not recommend for productions environments.

@dariuszbz
Copy link

dariuszbz commented Jan 17, 2022

@JorTurFer is it somehow usefull?

0117 09:28:06.034191 1 mic.go:608] No AzureIdentityBinding found for pod keda-system/keda-operator-584cc6777-2fw9j that matches selector: autoscaler-aad-identity. it will be ignored
I0117 09:28:06.034225 1 mic.go:608] No AzureIdentityBinding found for pod keda-system/keda-operator-metrics-apiserver-6978dc5cb6-pcmx9 that matches selector: autoscaler-aad-identity. it will be ignored
I0117 09:28:06.034382 1 mic.go:608] No AzureIdentityBinding found for pod keda-system/keda-operator-metrics-apiserver-6978dc5cb6-pcmx9 that matches selector: autoscaler-aad-identity. it will be ignored

something you can help with? It from: aad-pod-identity namespace, deployment: aad-pod-identity-mic.

keda-system namespace, autoscaler yaml definition:

apiVersion: aadpodidentity.k8s.io/v1
kind: AzureIdentity
metadata:
  name: autoscaler-aad-identity
spec:
  type: 0 # 0 means User-assigned MSI
  resourceID: $autoscaler_aad_identity_resourceId
  clientID: $autoscaler_aad_identity_clientId
---
apiVersion: aadpodidentity.k8s.io/v1
kind: AzureIdentityBinding
metadata:
  name: autoscaler-aad-identity-binding
spec:
  azureIdentity: autoscaler-aad-identity
  selector: app-autoscaler

I think the selector here is somehow problematic, but it is educated guess

@iarunpaul
Copy link
Author

Tring everything I have assigned the myAksCluster-agentpool in the $NodeResourceGroup with the Virtual Machine Contributor and Manage Identity Operator roles on $NodeResourceGroup scope and now my KEDA trigger started working!!!

kubectl get deploy -n keda-dotnet-sample -o wide


NAME              READY   UP-TO-DATE   AVAILABLE   AGE    CONTAINERS        IMAGES                                                          SELECTOR
order-processor   10/10   10           10          166m   order-processor   ghcr.io/kedacore/sample-dotnet-worker-servicebus-queue:latest   app=order-processor

Ofcourse my application is not consuming the messages but the happy moment is that the KEDA works with pod id in AKS!

But I have to recreate and confirm it.

@dariuszbz
Copy link

Hi @iarunpaul contrats! If you have e2e script, could you share with me, please?

@tomkerkhove
Copy link
Member

Your AzureIdentity does not have labels which is why the AzureIdentityBinding is not able to find it.

@dariuszbz
Copy link

dariuszbz commented Jan 17, 2022

@tomkerkhove @JorTurFer educated guess but 100% hit. selector is a problem there. I fixed and it works now. attaching e2e script it does everything except creating aks cluster. prvide aks name, aks rosource group name, node group name, and happy keda-ing :).

$resourceGroup = "MC_K8sScalingDemo_K8sScalingDemo_uksouth"
$aksResourceGroup = "K8sScalingDemo"
$aksName = "K8sScalingDemo"


kubectl create namespace aad-pod-identity
helm repo add aad-pod-identity https://raw.githubusercontent.com/Azure/aad-pod-identity/master/charts
helm install aad-pod-identity aad-pod-identity/aad-pod-identity --namespace aad-pod-identity

$resourceGroup_ResourceId = az group show --name $resourceGroup --query id -otsv
$aad_pod_identity_clientid = az aks show -g $aksResourceGroup -n $aksName --query identityProfile.kubeletidentity.clientId -otsv
az role assignment create --role "Managed Identity Operator" --assignee $aad_pod_identity_clientid  --scope $resourceGroup_ResourceId
az role assignment create --role "Virtual Machine Contributor" --assignee $aad_pod_identity_clientid  --scope $resourceGroup_ResourceId

$autoScaleridentityName = "autoscaler-aad-identity"
az identity create --name $autoScaleridentityName  --resource-group $resourceGroup
$autoscaler_aad_identity_clientId = az identity show --name $autoScaleridentityName  --resource-group $resourceGroup --query clientId -otsv
$autoscaler_aad_identity_resourceId = az identity show --name $autoScaleridentityName  --resource-group $resourceGroup --query id -otsv

$appIdentityName = "app-aad-identity"
az identity create --name app-aad-identity --resource-group $resourceGroup
$app_aad_identity_clientId = az identity show --name $appIdentityName --resource-group $resourceGroup --query clientId -otsv
$app_aad_identity_resourceId = az identity show --name $appIdentityName --resource-group $resourceGroup --query id -otsv

az servicebus namespace create --name svcbusdebe --resource-group $resourceGroup --sku basic
$servicebus_namespace_resourceId = az servicebus namespace show --name svcbusdebe --resource-group $resourceGroup --query id -otsv

az servicebus queue create --namespace-name svcbusdebe --name orders --resource-group $resourceGroup
$servicebus_queue_resourceId = az servicebus queue show --namespace-name svcbusdebe --name orders --resource-group $resourceGroup --query id -otsv

az role assignment create --role 'Azure Service Bus Data Receiver' --assignee $app_aad_identity_clientId  --scope $servicebus_queue_resourceId

kubectl create namespace keda-dotnet-sample

$app_with_identity_yaml= @"
apiVersion: aadpodidentity.k8s.io/v1
kind: AzureIdentity
metadata:
  name: $appIdentityName
  annotations:
    aadpodidentity.k8s.io/Behavior: namespaced
spec:
  type: 0 # 0 means User-assigned MSI
  resourceID: $app_aad_identity_resourceId
  clientID: $app_aad_identity_clientId
---
apiVersion: aadpodidentity.k8s.io/v1
kind: AzureIdentityBinding
metadata:
  name: $appIdentityName-binding
spec:
  azureIdentity: $appIdentityName
  selector: order-processor
---
apiVersion: apps/v1
kind: Deployment
metadata:
  name: order-processor
  labels:
    app: order-processor
spec:
  selector:
    matchLabels:
      app: order-processor
  template:
    metadata:
      labels:
        app: order-processor
        aadpodidbinding: order-processor
    spec:
      containers:
      - name: order-processor
        image: ghcr.io/kedacore/sample-dotnet-worker-servicebus-queue:latest
        env:
        - name: KEDA_SERVICEBUS_AUTH_MODE
          value: ManagedIdentity
        - name: KEDA_SERVICEBUS_HOST_NAME
          value: svcbusdebe.servicebus.windows.net
        - name: KEDA_SERVICEBUS_QUEUE_NAME
          value: orders
        - name: KEDA_SERVICEBUS_IDENTITY_USERASSIGNEDID
          value: $app_aad_identity_clientId
"@
$app_with_identity_yaml | kubectl apply --namespace keda-dotnet-sample -f -


kubectl create namespace keda-system

$autoscaler_yaml =@"
apiVersion: aadpodidentity.k8s.io/v1
kind: AzureIdentity
metadata:
  name: $autoScaleridentityName
spec:
  type: 0 # 0 means User-assigned MSI
  resourceID: $autoscaler_aad_identity_resourceId
  clientID: $autoscaler_aad_identity_clientId
---
apiVersion: aadpodidentity.k8s.io/v1
kind: AzureIdentityBinding
metadata:
  name: $autoScaleridentityName-binding
spec:
  azureIdentity: $autoScaleridentityName
  selector: $autoScaleridentityName
"@

$autoscaler_yaml | kubectl apply --namespace keda-system -f -

helm install keda kedacore/keda --set podIdentity.activeDirectory.identity=autoscaler-aad-identity --namespace keda-system

az role assignment create --role 'Azure Service Bus Data Owner' --assignee $autoscaler_aad_identity_clientId --scope $servicebus_namespace_resourceId


$aap_autoscaling_yaml = @"
apiVersion: keda.sh/v1alpha1
kind: TriggerAuthentication
metadata:
  name: trigger-auth-service-bus-orders
spec:
  podIdentity:
    provider: azure
---
apiVersion: keda.sh/v1alpha1 
kind: ScaledObject
metadata:
  name: order-scaler
spec:
  scaleTargetRef:
    name: order-processor
  # minReplicaCount: 0 Change to define how many minimum replicas you want
  maxReplicaCount: 10
  triggers:
  - type: azure-servicebus
    metadata:
      namespace: svcbusdebe
      queueName: orders
      messageCount: '5'
    authenticationRef:
      name: trigger-auth-service-bus-orders
"@
$aap_autoscaling_yaml | kubectl apply --namespace keda-dotnet-sample -f -

@iarunpaul
Copy link
Author

Your AzureIdentity does not have labels which is why the AzureIdentityBinding is not able to find it.

@tomkerkhove

AzureIdentity doesn't have a Label as of now and made sure that the AzureIdentityBinding has proper selector to find the pods to get the identity asigned to.

Does it really need a label for AzureIdentityBinding to find it.
This is how I apply it.

apiVersion: aadpodidentity.k8s.io/v1
kind: AzureIdentity
metadata:
  name: order-processor-id
  annotations:
    aadpodidentity.k8s.io/Behavior: namespaced
spec:
  type: 0 # 0 means User-assigned MSI
  resourceID: /subscriptions/<subscription-id>/resourceGroups/<ResourceGroup>/providers/Microsoft.ManagedIdentity/userAssignedIdentities/orderprocessor
  clientID: $azure_identity_client_id
---
apiVersion: aadpodidentity.k8s.io/v1
kind: AzureIdentityBinding
metadata:
  name: order-processor-id-binding
spec:
  azureIdentity: order-processor-id
  selector: order-processor
---
apiVersion: apps/v1
kind: Deployment
metadata:
  name: order-processor
  labels:
    app: order-processor
spec:
  selector:
    matchLabels:
      app: order-processor
  template:
    metadata:
      labels:
        app: order-processor
        aadpodidbinding: order-processor
    spec:
      containers:
      - name: order-processor
        image: ghcr.io/kedacore/sample-dotnet-worker-servicebus-queue:latest
        env:
        - name: KEDA_SERVICEBUS_AUTH_MODE
          value: ManagedIdentity
        - name: KEDA_SERVICEBUS_HOST_NAME
          value: <servicebusnamespace>.servicebus.windows.net
        - name: KEDA_SERVICEBUS_QUEUE_NAME
          value: orders
        - name: KEDA_SERVICEBUS_IDENTITY_USERASSIGNEDID
          value:  $azure_identity_client_id

The 'mic` is assigning the identity to the pods correct but the pod fails to process messages.

The mic logs are:

I0118 06:20:31.883390       1 mic.go:1466] reconciling identity assignment for [/subscriptions/<subscription-id>/resourcegroups/MC_Arun_myAksCluster_centralindia/providers/Microsoft.ManagedIdentity/userAssignedIdentities/autoscaler /subscriptions/<subscription-id>/resourceGroups/MC_Arun_myAksCluster_centralindia/providers/Microsoft.ManagedIdentity/userAssignedIdentities/orderprocessor] on node aks-nodepool1-22178597-vmss
I0118 06:23:31.880029       1 mic.go:1466] reconciling identity assignment for [/subscriptions/<subscription-id>/resourceGroups/MC_Arun_myAksCluster_centralindia/providers/Microsoft.ManagedIdentity/userAssignedIdentities/orderprocessor /subscriptions/<subscription-id>/resourcegroups/MC_Arun_myAksCluster_centralindia/providers/Microsoft.ManagedIdentity/userAssignedIdentities/autoscaler] on node aks-nodepool1-22178597-vmss

Though the mic logs look fine the nmi still fails to find the identity for me
The nmi logs are:

E0118 06:26:06.375823       1 server.go:392] failed to get service principal token for pod: keda-dotnet-sample/order-processor-cb6dfd94f-z7bjd, error: failed to refresh token, error: adal: Refresh request failed. Status Code = '400'. Response body: {"error":"invalid_request","error_description":"Identity not found"} Endpoint http://169.254.169.254/metadata/identity/oauth2/token?api-version=2018-02-01&client_id=19e9cbf1-8ca6-4148-86a3-396c66b9cad0&resource=https%3A%2F%2Fservicebus.azure.net
I0118 06:26:06.375832       1 server.go:199] status (403) took 582235536 ns for req.method=GET reg.path=/metadata/identity/oauth2/token req.remote=10.244.0.35
E0118 06:26:06.375908       1 server.go:392] failed to get service principal token for pod: keda-dotnet-sample/order-processor-cb6dfd94f-xc5pr, error: failed to refresh token, error: adal: Refresh request failed. Status Code = '400'. Response body: {"error":"invalid_request","error_description":"Identity not found"} Endpoint http://169.254.169.254/metadata/identity/oauth2/token?api-version=2018-02-01&client_id=19e9cbf1-8ca6-4148-86a3-396c66b9cad0&resource=https%3A%2F%2Fservicebus.azure.net
I0118 06:26:06.376414       1 server.go:199] status (403) took 579813406 ns for req.method=GET reg.path=/metadata/identity/oauth2/token req.remote=10.244.0.37
I0118 06:26:06.383229       1 standard.go:80] clientID in request: 19e9##### REDACTED #####cad0, keda-dotnet-sample/order-processor-cb6dfd94f-z7bjd has been matched with azure identity keda-dotnet-sample/order-processor-id
I0118 06:26:06.383262       1 standard.go:179] matched identityType:0 clientid:19e9##### REDACTED #####cad0 resource:https://servicebus.azure.net
I0118 06:26:06.384999       1 standard.go:80] clientID in request: 19e9##### REDACTED #####cad0, keda-dotnet-sample/order-processor-cb6dfd94f-fpcw5 has been matched with azure identity keda-dotnet-sample/order-processor-id
I0118 06:26:06.385040       1 standard.go:179] matched identityType:0 clientid:19e9##### REDACTED #####cad0 resource:https://servicebus.azure.net
I0118 06:26:06.398199       1 standard.go:80] clientID in request: 19e9##### REDACTED #####cad0, keda-dotnet-sample/order-processor-cb6dfd94f-xc5pr has been matched with azure identity keda-dotnet-sample/order-processor-id
I0118 06:26:06.398230       1 standard.go:179] matched identityType:0 clientid:19e9##### REDACTED #####cad0 resource:https://servicebus.azure.net
E0118 06:26:06.405913       1 server.go:392] failed to get service principal token for pod: keda-dotnet-sample/order-processor-cb6dfd94f-fzd7m, error: failed to refresh token, error: adal: Refresh request failed. Status Code = '400'. Response body: {"error":"invalid_request","error_description":"Identity not found"} Endpoint http://169.254.169.254/metadata/identity/oauth2/token?api-version=2018-02-01&client_id=19e9cbf1-8ca6-4148-86a3-396c66b9cad0&resource=https%3A%2F%2Fservicebus.azure.net
I0118 06:26:06.405947       1 server.go:199] status (403) took 575878558 ns for req.method=GET reg.path=/metadata/identity/oauth2/token req.remote=10.244.0.40
I0118 06:26:06.408408       1 standard.go:80] clientID in request: 19e9##### REDACTED #####cad0, keda-dotnet-sample/order-processor-cb6dfd94f-fzd7m has been matched with azure identity keda-dotnet-sample/order-processor-id
I0118 06:26:06.408440       1 standard.go:179] matched identityType:0 clientid:19e9##### REDACTED #####cad0 resource:https://servicebus.azure.net

The order app fails with:

[06:46:22]fail: Keda.Samples.Dotnet.OrderProcessor.OrdersQueueProcessor[0]
      Unable to process message
Azure.Identity.AuthenticationFailedException: ManagedIdentityCredential authentication failed: Service request failed.
Status: 403 (Forbidden)

Content:
failed to acquire a token using the MSI VM extension, error: MSI not available


Headers:
X-Content-Type-Options: REDACTED
Date: Tue, 18 Jan 2022 06:46:22 GMT
Content-Type: text/plain; charset=utf-8
Content-Length: 79

 ---> Azure.RequestFailedException: Service request failed.
Status: 403 (Forbidden)

Content:
failed to acquire a token using the MSI VM extension, error: MSI not available


Headers:
X-Content-Type-Options: REDACTED
Date: Tue, 18 Jan 2022 06:46:22 GMT
Content-Type: text/plain; charset=utf-8
Content-Length: 79

   at Azure.Identity.ManagedIdentityClient.AuthenticateAsync(String[] scopes, CancellationToken cancellationToken)
   at Azure.Identity.ManagedIdentityCredential.GetTokenImplAsync(Boolean async, TokenRequestContext requestContext, CancellationToken cancellationToken)
   --- End of inner exception stack trace ---
   at Azure.Identity.CredentialDiagnosticScope.FailWrapAndThrow(Exception ex)
   at Azure.Identity.ManagedIdentityCredential.GetTokenImplAsync(Boolean async, TokenRequestContext requestContext, CancellationToken cancellationToken)
   at Azure.Identity.ManagedIdentityCredential.GetTokenAsync(TokenRequestContext requestContext, CancellationToken cancellationToken)
   at Azure.Messaging.ServiceBus.Amqp.CbsTokenProvider.GetTokenAsync(Uri namespaceAddress, String appliesTo, String[] requiredClaims)
   at Microsoft.Azure.Amqp.TaskHelpers.EndAsyncResult(IAsyncResult asyncResult)
   at Microsoft.Azure.Amqp.IteratorAsyncResult`1.StepCallback(IAsyncResult result)
--- End of stack trace from previous location where exception was thrown ---
   at Microsoft.Azure.Amqp.AsyncResult.End[TAsyncResult](IAsyncResult result)
   at Microsoft.Azure.Amqp.AmqpCbsLink.<>c__DisplayClass4_0.<SendTokenAsync>b__1(IAsyncResult a)
   at System.Threading.Tasks.TaskFactory`1.FromAsyncCoreLogic(IAsyncResult iar, Func`2 endFunction, Action`1 endAction, Task`1 promise, Boolean requiresSynchronization)
--- End of stack trace from previous location where exception was thrown ---
   at Azure.Messaging.ServiceBus.Amqp.AmqpConnectionScope.RequestAuthorizationUsingCbsAsync(AmqpConnection connection, CbsTokenProvider tokenProvider, Uri endpoint, String[] audience, String[] requiredClaims, TimeSpan timeout)
   at Azure.Messaging.ServiceBus.Amqp.AmqpConnectionScope.CreateReceivingLinkAsync(String entityPath, AmqpConnection connection, Uri endpoint, TimeSpan timeout, UInt32 prefetchCount, ReceiveMode receiveMode, String sessionId, Boolean isSessionReceiver, CancellationToken cancellationToken)
   at Azure.Messaging.ServiceBus.Amqp.AmqpConnectionScope.CreateReceivingLinkAsync(String entityPath, AmqpConnection connection, Uri endpoint, TimeSpan timeout, UInt32 prefetchCount, ReceiveMode receiveMode, String sessionId, Boolean isSessionReceiver, CancellationToken cancellationToken)
   at Azure.Messaging.ServiceBus.Amqp.AmqpConnectionScope.OpenReceiverLinkAsync(String entityPath, TimeSpan timeout, UInt32 prefetchCount, ReceiveMode receiveMode, String sessionId, Boolean isSessionReceiver, CancellationToken cancellationToken)
   at Azure.Messaging.ServiceBus.Amqp.AmqpReceiver.OpenReceiverLinkAsync(TimeSpan timeout, UInt32 prefetchCount, ReceiveMode receiveMode, Boolean isSessionReceiver)
   at Microsoft.Azure.Amqp.FaultTolerantAmqpObject`1.OnCreateAsync(TimeSpan timeout)
   at Microsoft.Azure.Amqp.Singleton`1.GetOrCreateAsync(TimeSpan timeout)
   at Microsoft.Azure.Amqp.Singleton`1.GetOrCreateAsync(TimeSpan timeout)
   at Azure.Messaging.ServiceBus.Amqp.AmqpReceiver.ReceiveMessagesAsyncInternal(Int32 maxMessages, Nullable`1 maxWaitTime, TimeSpan timeout, CancellationToken cancellationToken)
   at Azure.Messaging.ServiceBus.Amqp.AmqpReceiver.ReceiveMessagesAsyncInternal(Int32 maxMessages, Nullable`1 maxWaitTime, TimeSpan timeout, CancellationToken cancellationToken)
   at Azure.Messaging.ServiceBus.Amqp.AmqpReceiver.<>c__DisplayClass29_0.<<ReceiveMessagesAsync>b__0>d.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at Azure.Messaging.ServiceBus.ServiceBusRetryPolicy.RunOperation(Func`2 operation, TransportConnectionScope scope, CancellationToken cancellationToken)
   at Azure.Messaging.ServiceBus.ServiceBusRetryPolicy.RunOperation(Func`2 operation, TransportConnectionScope scope, CancellationToken cancellationToken)
   at Azure.Messaging.ServiceBus.Amqp.AmqpReceiver.ReceiveMessagesAsync(Int32 maxMessages, Nullable`1 maxWaitTime, CancellationToken cancellationToken)
   at Azure.Messaging.ServiceBus.ServiceBusReceiver.ReceiveMessagesAsync(Int32 maxMessages, Nullable`1 maxWaitTime, CancellationToken cancellationToken)
   at Azure.Messaging.ServiceBus.ServiceBusReceiver.ReceiveMessageAsync(Nullable`1 maxWaitTime, CancellationToken cancellationToken)
   at Azure.Messaging.ServiceBus.ReceiverManager.ReceiveAndProcessMessagesAsync(CancellationToken cancellationToken)

@iarunpaul
Copy link
Author

Finally I found it!
My set up is for a workaround with KEDA for kubenet interface.
I followed the e2e script by @dariuszbz, where my cluster is aks with the default kubenet network plugin.
The order application works fine without any nmi modifications and processes messages using the managed identity assigned to the application.
But when installed KEDA using helm and set the pod identity, keda operator pod fails to get authorized:
Logs are:

  2022-01-23T16:13:17.237Z        INFO    scaleexecutor   Successfully set ScaleTarget replicas count to ScaledObject minReplicaCount     {"scaledobject.Name": "order-scaler", "scaledObject.Namespace": "keda-dotnet-sample", "scaleTarget.Name": "order-processor", "Original Replicas Count": 1, "New Replicas Count": 0}
2022-01-23T16:13:31.982Z        INFO    controller.scaledobject Reconciling ScaledObject        {"reconciler group": "keda.sh", "reconciler kind": "ScaledObject", "name": "order-scaler", "namespace": "keda-dotnet-sample"}
2022-01-23T16:13:47.036Z        ERROR   azure_servicebus_scaler error   {"error": "request failed: 401 Unauthorized"}
github.com/kedacore/keda/v2/pkg/scaling.(*scaleHandler).checkScalers
        /workspace/pkg/scaling/scale_handler.go:261

Then I had to edit nmi command arguement to add --allow-network-plugin-kubenet=true and the nmi starts running...

Now the nmi pod reads:

I0123 16:55:43.377799       1 standard.go:73] no clientID or resourceID in request. keda-system/keda-operator-584cc6777-5xscs has been matched with azure identity keda-system/autoscaler-aad-identity
I0123 16:55:43.377857       1 standard.go:179] matched identityType:0 clientid:1c04##### REDACTED #####7168 resource:https://servicebus.azure.net/
I0123 16:55:43.386639       1 server.go:199] status (200) took 8880095 ns for req.method=GET reg.path=/metadata/identity/oauth2/token req.remote=10.244.1.3
I0123 16:56:13.378683       1 standard.go:73] no clientID or resourceID in request. keda-system/keda-operator-584cc6777-5xscs has been matched with azure identity keda-system/autoscaler-aad-identity
I0123 16:56:13.378762       1 standard.go:179] matched identityType:0 clientid:1c04##### REDACTED #####7168 resource:https://servicebus.azure.net/
I0123 16:56:13.388151       1 server.go:199] status (200) took 9511587 ns for req.method=GET reg.path=/metadata/identity/oauth2/token req.remote=10.244.1.3
I0123 16:56:43.379373       1 standard.go:73] no clientID or resourceID in request. keda-system/keda-operator-584cc6777-5xscs has been matched with azure identity keda-system/autoscaler-aad-identity
I0123 16:56:43.379431       1 standard.go:179] matched identityType:0 clientid:1c04##### REDACTED #####7168 resource:https://servicebus.azure.net/
I0123 16:56:43.389095       1 server.go:199] status (200) took 9787784 ns for req.method=GET reg.path=/metadata/identity/oauth2/token req.remote=10.244.1.3

Still the order application doesn't work. You need to delete and redeploy the application and wait for a few minutes...
And thats it!
Your application scales on KEDA metrics.
Happy scaling!!
Note: Always follow the mitigation steps and configure policies before enabling aad-pod-identity in a cluster with Kubenet.

@dariuszbz
Copy link

@iarunpaul would be nice to see your e2e example for kubenet - it can save some time for other geek :)

@iarunpaul
Copy link
Author

Posting e2e Script for AKS with kubenet plugin, if it is of any assistance to some:

# Define aks name and resource group
$aksResourceGroup = "K8sScalingDemo"
$aksName = "K8sScalingDemo"

# Create resource group
az group create -n $aksResourceGroup -l centralindia

# Create the aks cluster with default kubenet plugin
az aks create -n $aksName -g $aksResourceGroup

# Resourcegroup where the aks resources will be deployed
$resourceGroup = "$(az aks show -g $aksResourceGroup -n $aksName --query nodeResourceGroup -otsv)"

# Set the kubectl context to the newly created aks cluster
az aks get-credentials -n $aksName -g $aksResourceGroup

# Install AAD Pod Identity into the aad-pod-identity namespace using helm
kubectl create namespace aad-pod-identity
helm repo add aad-pod-identity https://raw.githubusercontent.com/Azure/aad-pod-identity/master/charts
helm install aad-pod-identity aad-pod-identity/aad-pod-identity --namespace aad-pod-identity

# Check the status of installation 
kubectl --namespace=aad-pod-identity get pods -l "app.kubernetes.io/component=mic"
kubectl --namespace=aad-pod-identity get pods -l "app.kubernetes.io/component=nmi"

# the nmi components will Crashloop, ignore them for now. We will make them right later

# Get Resourcegroup Id of our $ResourceGroup
$resourceGroup_ResourceId = az group show --name $resourceGroup --query id -otsv

# Get the aks cluster kubeletidentity client id
$aad_pod_identity_clientid = az aks show -g $aksResourceGroup -n $aksName --query identityProfile.kubeletidentity.clientId -otsv

# Assign required roles for cluster over the resourcegroup
az role assignment create --role "Managed Identity Operator" --assignee $aad_pod_identity_clientid  --scope $resourceGroup_ResourceId
az role assignment create --role "Virtual Machine Contributor" --assignee $aad_pod_identity_clientid  --scope $resourceGroup_ResourceId

# Create autoscaler azure identity and get client id and resource id of the autoscaler identity
$autoScaleridentityName = "autoscaler-aad-identity"
az identity create --name $autoScaleridentityName  --resource-group $resourceGroup
$autoscaler_aad_identity_clientId = az identity show --name $autoScaleridentityName  --resource-group $resourceGroup --query clientId -otsv
$autoscaler_aad_identity_resourceId = az identity show --name $autoScaleridentityName  --resource-group $resourceGroup --query id -otsv

# Create the app azure identity and get client id and resource id of the app identity
$appIdentityName = "app-aad-identity"
az identity create --name app-aad-identity --resource-group $resourceGroup
$app_aad_identity_clientId = az identity show --name $appIdentityName --resource-group $resourceGroup --query clientId -otsv
$app_aad_identity_resourceId = az identity show --name $appIdentityName --resource-group $resourceGroup --query id -otsv

# Create service bus and queue
$servicebus = 'svcbusdemo'
az servicebus namespace create --name $servicebus --resource-group $resourceGroup --sku basic
$servicebus_namespace_resourceId = az servicebus namespace show --name $servicebus --resource-group $resourceGroup --query id -otsv

az servicebus queue create --namespace-name $servicebus --name orders --resource-group $resourceGroup
$servicebus_queue_resourceId = az servicebus queue show --namespace-name $servicebus --name orders --resource-group $resourceGroup --query id -otsv

# Assign Service Bus Data Receiver role to the app identity created
az role assignment create --role 'Azure Service Bus Data Receiver' --assignee $app_aad_identity_clientId  --scope $servicebus_queue_resourceId

# Create a namespace for order app deployment
kubectl create namespace keda-dotnet-sample

# Create a yaml deployment configuration variable
$app_with_identity_yaml= @"
apiVersion: aadpodidentity.k8s.io/v1
kind: AzureIdentity
metadata:
  name: $appIdentityName
  annotations:
    aadpodidentity.k8s.io/Behavior: namespaced
spec:
  type: 0 # 0 means User-assigned MSI
  resourceID: $app_aad_identity_resourceId
  clientID: $app_aad_identity_clientId
---
apiVersion: aadpodidentity.k8s.io/v1
kind: AzureIdentityBinding
metadata:
  name: $appIdentityName-binding
spec:
  azureIdentity: $appIdentityName
  selector: order-processor
---
apiVersion: apps/v1
kind: Deployment
metadata:
  name: order-processor
  labels:
    app: order-processor
spec:
  selector:
    matchLabels:
      app: order-processor
  template:
    metadata:
      labels:
        app: order-processor
        aadpodidbinding: order-processor
    spec:
      containers:
      - name: order-processor
        image: ghcr.io/kedacore/sample-dotnet-worker-servicebus-queue:latest
        env:
        - name: KEDA_SERVICEBUS_AUTH_MODE
          value: ManagedIdentity
        - name: KEDA_SERVICEBUS_HOST_NAME
          value: $servicebus.servicebus.windows.net
        - name: KEDA_SERVICEBUS_QUEUE_NAME
          value: orders
        - name: KEDA_SERVICEBUS_IDENTITY_USERASSIGNEDID
          value: $app_aad_identity_clientId
"@

# Create the app deployment with identity bindings using kubectl apply
$app_with_identity_yaml | kubectl apply --namespace keda-dotnet-sample -f -

# Now the order processor app works with the pod identity and 
# processes the queues 
# You can refer the [project ](https://github.com/kedacore/sample-dotnet-worker-servicebus-queue/blob/main/pod-identity.md) for that.

# Now start installation of KEDA in namespace keda-system

kubectl create namespace keda-system

# Create a pod identity and binding for autoscaler azure identity
$autoscaler_yaml =@"
apiVersion: aadpodidentity.k8s.io/v1
kind: AzureIdentity
metadata:
  name: $autoScaleridentityName
spec:
  type: 0 # 0 means User-assigned MSI
  resourceID: $autoscaler_aad_identity_resourceId
  clientID: $autoscaler_aad_identity_clientId
---
apiVersion: aadpodidentity.k8s.io/v1
kind: AzureIdentityBinding
metadata:
  name: $autoScaleridentityName-binding
spec:
  azureIdentity: $autoScaleridentityName
  selector: $autoScaleridentityName
"@
$autoscaler_yaml | kubectl apply --namespace keda-system -f -

# Install KEDA using helm
helm install keda kedacore/keda --set podIdentity.activeDirectory.identity=autoscaler-aad-identity --namespace keda-system

# Assign Service Bus Data Owner role to keda autoscaler identity
az role assignment create --role 'Azure Service Bus Data Owner' --assignee $autoscaler_aad_identity_clientId --scope $servicebus_namespace_resourceId

# Apply scaled object definition and trigger authentication provider as `azure`
$aap_autoscaling_yaml = @"
apiVersion: keda.sh/v1alpha1
kind: TriggerAuthentication
metadata:
  name: trigger-auth-service-bus-orders
spec:
  podIdentity:
    provider: azure
---
apiVersion: keda.sh/v1alpha1 
kind: ScaledObject
metadata:
  name: order-scaler
spec:
  scaleTargetRef:
    name: order-processor
  # minReplicaCount: 0 Change to define how many minimum replicas you want
  maxReplicaCount: 10
  triggers:
  - type: azure-servicebus
    metadata:
      namespace: $servicebus
      queueName: orders
      messageCount: '5'
    authenticationRef:
      name: trigger-auth-service-bus-orders
"@

$aap_autoscaling_yaml | kubectl apply --namespace keda-dotnet-sample -f -

# Now the Keda is getting 401 unauthorized error as the AAD Pod Identity comnponent `nmi` is not runnig on the system
# To fix it edit the daemonset for `nmi` component
# add the container arg `--allow-network-plugin-kubenet=true` by editing the `daemonset.apps/aad-pod-identity-nmi`
kubectl edit daemonset.apps/aad-pod-identity-nmi -n aad-pod-identity

# the containe arg section should look like this after editing:
    spec:
      containers:
      - args:
        - --node=$(NODE_NAME)
        - --http-probe-port=8085
        - --enableScaleFeatures=true
        - --metadata-header-required=true
        - --operation-mode=standard
        - --kubelet-config=/etc/default/kubelet
        - --allow-network-plugin-kubenet=true
        env:

# Now the KEDA is authenticated by aad-pod-identity metadata endpoint and the orderapp should scale up 
# with the queue counts
# If the order app still falls back to errors please delete and redeploy it.
# And that's it you just scaled your app up using KEDA on Kubenet AKS cluster.
Note: Read this instruction before you run AAD Identity On a Kubenet powered AKS.

@stale
Copy link

stale bot commented Mar 25, 2022

This issue has been automatically marked as stale because it has not had recent activity. It will be closed in 7 days if no further activity occurs. Thank you for your contributions.

@stale stale bot added the stale All issues that are marked as stale due to inactivity label Mar 25, 2022
@stale
Copy link

stale bot commented Apr 1, 2022

This issue has been automatically closed due to inactivity.

@stale stale bot closed this as completed Apr 1, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working stale All issues that are marked as stale due to inactivity
Projects
None yet
Development

No branches or pull requests

4 participants