Aad-pod-identity: Identity gets assigned, but remains unusable "identity not found" error

[kwaazaar]

Describe the bug
On our production cluster one of manyu managed identities has suddenly become unusable. The AzureAD identity and the AzureIdentity and AzureIdentityBinding existed for months. The identity has been in use all that time. Now suddenly it stopped working with the error message "Identity not found".

When trying to use the identity on another pod (by using the same aadpodidbinding label) doesn't work either: the AssignedAzureIdentity is created and gets status Assigned, but requesting an access token doesn't work. Recreating the AzureIdentity and AzureIdentityBinding didn't make a difference either.

We keep all our identities in a separate resource group where the cluster-sp has the Managed Identity Operator role. Still this single identity is the only one causing problems. This is however the FIRST identity we ever created. Hopefully we don't see this issue in the future for all the other identities as well.

I solved it for now by deploying a new identity with a different name and authorized for the same resources. The problematic identity is therefore no longer in use, but still exists in case you/ms-support may want to analyze the issue. I could also try to see if I get the same results if I assign it to a VM. Let me know if you want to know.

Steps To Reproduce
No clue

Expected behavior
To just keep working

AAD Pod Identity version
1.5.5, installed using yaml

Kubernetes version
AKS, 1.16.7. Old cluster still using availability sets.

Additional context
Logs from NMI:
~
time="2020-07-13T08:30:32Z" level=warning msg="parameter resource cannot be empty" req.method=GET req.path=/metadata/identity/oauth2/token req.remote=10.234.80.224
time="2020-07-13T08:30:32Z" level=info msg="Status (400) took 73200 ns" req.method=GET req.path=/metadata/identity/oauth2/token req.remote=10.234.80.224
time="2020-07-13T08:30:32Z" level=info msg="matched identityType:0 clientid:cc81##### REDACTED #####9230 resource:https://vault.azure.net" req.method=GET req.path=/metadata/identity/oauth2/token req.remote=10.234.80.224
time="2020-07-13T08:30:32Z" level=error msg="failed to get service principal token for pod:productie/msitest, adal: Refresh request failed. Status Code = '400'. Response body: {\"error\":\"invalid_request\",\"error_description\":\"Identity not found\"}" req.method=GET req.path=/metadata/identity/oauth2/token req.remote=10.234.80.224
time="2020-07-13T08:30:32Z" level=info msg="Status (403) took 325594664 ns" req.method=GET req.path=/metadata/identity/oauth2/token req.remote=10.234.80.224
~

[aramase]

@kwaazaar Thank you for opening the issue 👍

Which region is your cluster in? This issue is similar to https://github.com/Azure/aad-pod-identity/issues/606. There was a caching bug in instance metadata server running on the node due to which it returned "identity not found" error even when identity exists on the underlying VMSS. The fix for that is being gradually rolled out to all regions, updating existing VMSS.

[kwaazaar]

The behavior I'm seeing is indeed similar to that described in #606. Region is West Europe.

I need to correct myself: this old cluster is still using availability sets (updated above). Does that make any difference?
I mention this, because we've had other issues with managed identities that were related to availability sets.

[aramase]

@kwaazaar Are the VMs part of this list in your sub?
aks-agentpool-24722116-0, aks-agentpool-20414870-5, aks-agentpool-71662594-13, aks-agentpool-71662594-23, aks-agentpool-71662594-12

I checked internally and these are the VMs that are running an old build of IMDS which doesn't contain the cache fix as mentioned in #606. The rollout is in progress and I see most of the other VMs in the sub have been patched with the right build.

[kwaazaar]

Those are all nodes of 3 different clusters. I'm pretty sure the node where the pod was scheduled on was aks-agentpool-20414870-1. That one is not in your list. I will try to get it scheduled there again.

When can I expect all VMs to have been patched? Does it take days or weeks?

[kwaazaar]

Is the list of nodes you mention supposed to be a complete list? We are currently experiencing the same issue on these nodes:
aks-agentpool-20414870-4
aks-agentpool-20414870-0
aks-agentpool-20414870-10

I'm replacing them now, since this is a production cluster.

[aramase]

I looked at the list of nodes in your sub today and they are all running the latest build which contains the IMDS caching fix. If you're still facing the issue. I'll also check internally with the IMDS team.

Just to confirm does the clientID defined in AzureIdentity match the clientID when the identity is assigned on the node? To find the clientID from the node, you can run az vm identity show -g <rg> -n <vm name>

[aramase]

The Managed identity team were able to look at their logs and saw the identity was deleted and re-created. Just to confirm, was the identity recently deleted and re-created with the same name? The clientID defined in AzureIdentity is used while fetching the token. If the clientID doesn't match the identity.clientID on the node, then that would result in "identity not found" error.

[kwaazaar]

I did not recreate identities. I did run our release pipeline in AzureDevOps which creates the identity and the AzureIdentity and AzureIdentityBinding using the Azure CLI (az identity create), but since the identity already existed, the CLI will not touch it, but maybe still log this as a changes.

Anyway, the issues we ran into yesterday were related to other identities and other nodes. I didn't touch the identities, but replaced the nodes (by scale up, drain nodes, delete VMs, scale back down). All identities work fine again on other nodes.

When the issue reoccurs, I will check the clientids of the assigned identities.

[kwaazaar]

I'm pretty sure that all our nodes have NOT been patched. We are currently experiencing the same issue again, not on a different node again. This time on node aks-agentpool-20414870-7 with client-id 4ff9cf27-01ca-4674-8581-fb12e0478964. The identity is attached to the VM with the correct principalid (I checked with az vm identity show...).

[aramase]

I've created an incident for the Managed Identity team internally requesting them to investigate the issue. Will post here as I get updates from them.

[silasbw]

@aramase, I think I'm seeing this issue also, but I'm not sure how to get more information, how to remediate, or what the right bug reporting path is.

Can you advise? Should I report directly to IMDS? How do I do that? Apologies for the probably naive set of questions.

[aramase]

@silasbw I've opened an incident with the managed identity for this issue and they're investigating. Can you confirm this is true - https://github.com/Azure/aad-pod-identity/issues/606#issuecomment-646727752. If you can confirm the steps in that comment and you're actively facing issue, please open a support ticket that the IMDS team can help take a look.

Can you provide the agentpool/VM name? I can pass it along to the team so they can take a look and unblock you.

[aramase]

@kwaazaar The IMDS team has restarted the metadata server on the node aks-agentpool-20414870-7. Let me know if you're still facing issues. They are also actively investigating the issue.

[timja]

We're also hitting this issue

time="2020-07-21T09:21:08Z" level=info msg="matched identityType:0 clientid:3e90##### REDACTED #####b984 resource:https://vault.azure.net" req.method=GET req.path=/host/token/ req.remote=127.0.0.1
time="2020-07-21T09:21:09Z" level=error msg="failed to get service principal token for pod:ccd/ccd-data-store-api-java-5df4586cd4-6qxnk, adal: Refresh request failed. Status Code = '400'. Response body: {\"error\":\"invalid_request\",\"error_description\":\"Identity not found\"}" req.method=GET req.path=/host/token/ req.remote=127.0.0.1

support request: 120072125001052

[timja]

Support resolved it for us by restarting IMDS on all nodes on our clusters,
Below is the RCA:

IMDS has a caching issue that AKS is highly susceptible due to the identity usage pattern for aad-pod-identity.
Whenever the identity is unassigned and reassigned to the VMs, MSI service will create a new VM entry with a new identifier.
The IMDS caching issue causes the VM to use the prior identifier.
When the VM attempts to request credentials from MSI service and presents the old identifier, MSI will respond with NotFound because the entry for the resource is associated with the new identifier.
IMDS will fall back and attempt to use the prior credentials for the prior identifier, which at this point had expired.
The solution is to restart IMDS on these nodes because that will cause the VM to retrieve the new config with the updated identifier.

[KrishnaKole]

We are also facing same issue on below nodes. Suport request 120071724000618
aks-nodepool1-99109236-2
aks-nodepool1-99109236-10
aks-nodepool1-99109236-11

[kevinwedwards]

We're also seeing this

[kevinwedwards]

So I was able to resolve our issue by doing the following:
1) Stopping the VMs, waiting a bit of time, and restarting the VMs (did 1 first, then 2&3 later, together). ,
2) restarted the MIC deployment and the NMI DaemonSet
kubectl rollout restart deployment mic
* kubectl rollout restart ds nmi
3) Redeployed 'service's deployment'
*kubectl rollout restart deployment [our deplyoment name]

In the process of working thru this. I noticed that before stopping and restarting the nodes:

az vm identity show -g -n
showed me 'old client and principal' IDs (I assume this is from the stale cache)

After stopping the VM and restarting it - running that command again - for VM1... returned nothing. I strongly suspect that this is related to the 'identity not found' when our .NET Core deployable, was attempting to get access to an Azure resource via Managed ID.

Upon restarting, and redeploying the AAD-Pod-ID, the az vm identity show -g -n then returned the latest/correct info for the ManagedID resource.

[aramase]

@kevinwedwards Was the identity deleted and re-created with the same name? To confirm if this is an IMDS caching issue, the steps are here - https://github.com/Azure/aad-pod-identity/issues/606#issuecomment-646727752.

[kevinwedwards]

@aramase yes - the managed ID was deleted and re-created with the same name. I believe this is the root-cause of the IMDS cache not being refreshed.

[rkammara12]

There are three different reasons for the "IdentityNotFound" error:
1) UAI deleted and re-created with the same name (and assigning the same to vmss), but IMDS cache still uses old clientID thereby resulting in the above error.
2) If there is a secretURL change, IMDS still uses old url thereby resulting in the above error.
3) It is observed that in cases of AKS upgrade scenarios and cases where aks-engine is used, the Identities that are assigned before the upgrade are deleted after the upgrade. In this case the issue is with aks-engine and not with IMDS.

Issue1, 2 are IMDS issues and are fixed in later releases, but the third issue is with aks-engine.

In any case to differentiate whether the issue is with IMDS or not please check whether identity is really assigned to the VMSS using the following command from Azure Cli:
az vm identity show -g -n

[chewong]

Thanks for providing your finding. If there is an aks-engine upgrade issue, feel free to open an issue at https://github.com/Azure/aks-engine/issues.

[aramase]

@rkammara12 Can you confirm if issues 1 and 2 are now fixed and rolled out to all regions? We can then close this issue and open new ones if any.

[rkammara12]

@aramase the fix for issue1 is rolled out in all regions, but issue2 is still under deployment.

[aramase]

Thank you for the confirmation @rkammara12. Please let us know on this issue when the deployment is complete and then we can close this.

[rkammara12]

Sure @aramase

[aramase]

@rkammara12 Is the deployment in all regions complete now?

[timja]

@aramase we hit this 5 days ago https://github.com/Azure/aad-pod-identity/issues/880

[aramase]

@timja This issue isn't similar to the one you encountered. This "identity not found" issue was caused even when the identity was not deleted and recreated with the same name.

[rkammara12]

@aramase The deployment is not finished in all regions yet, there has been some delay in IMDS deployments because of some blockers.

[aramase]

@rkammara12 Checking in to see what the status of the rollout is?

[rkammara12]

@aramase Yes it is rolled out in all regions now.

[aramase]

Thank you for the confirmation @rkammara12.

Closing this issue as the IMDS fix rollout is complete. Please feel free to reopen if there are any more issues.

[SnowmanCharles]

Support resolved it for us by restarting IMDS on all nodes on our clusters,
Below is the RCA:

IMDS has a caching issue that AKS is highly susceptible due to the identity usage pattern for aad-pod-identity.
Whenever the identity is unassigned and reassigned to the VMs, MSI service will create a new VM entry with a new identifier.
The IMDS caching issue causes the VM to use the prior identifier.
When the VM attempts to request credentials from MSI service and presents the old identifier, MSI will respond with NotFound because the entry for the resource is associated with the new identifier.
IMDS will fall back and attempt to use the prior credentials for the prior identifier, which at this point had expired.
The solution is to restart IMDS on these nodes because that will cause the VM to retrieve the new config with the updated identifier.

I think this issue have not been resolved by the caching fix. I'm meeting the same issue now. Any instructions on how to restart the MSI server on the Virtual Machine? I can confirm that the client ID and object ID of the ManagedIdentity and the AzureIdentity are the same.

[aramase]

@rkammara12 Seems like this issue has been reoccuring a lot lately. Similar issue: https://github.com/Azure/aad-pod-identity/issues/1085.

Do you know what's the permanent fix for the new issue is?

@SnowmanCharles I don't believe you can restart the IMDS. This is typically done by opening a support ticket and having the IMDS team restart it. @rkammara12 can correct me if I'm wrong.

[SnowmanCharles]

@aramase I suspect the issue is either due to

1. The caching defect of IMDS
2. The IMDS somehow did not store my identity info
   Do you know how to verify which one is the case?

I can confirm that the "az vm show" and "az vm identity show" gives the right identity with the correct object ID and client ID. But still not sure what's the exact info stored in IMDS.

[SnowmanCharles]

In my case, I this is part of a automated system. Thus, to solve this issue by opening a support ticket and having the IMDS team to restart it is unacceptable for me.

[rkammara12]

@SnowmanCharles If the issue is similar to https://github.com/Azure/aad-pod-identity/issues/1085 then it shouldnt have solved after IMDS restart.

For IMDS the Role Configuration File (RCF) on the host is the source of truth in terms identities assigned to the VMSS. If the identity doesnt exist in the RCF file then IMDS cannot fetch tokens for that identity.

There is an existing issue where the RCF artifact is not updated when an User Assigned Identity is assigned to the VMSS and it looks like a race condition issue in the Fabric. The only mitigation is to run "az vmss update -g -n " which triggers RCF file updation.

When the issue is observed again please let me know before any resolution steps like IMDS restart is applied so that I can validate if the issue is same as https://github.com/Azure/aad-pod-identity/issues/1085 or not.

[SnowmanCharles]

@rkammara12 Hi, for me, it's not VMSS, but just on a virtual machine deployed with k8s resources. It's still there and I am going to keep it for investigation. Do you have any suggestions/guidance on how to trouble shooting the VM? I assume similar thing is happening on the VM as those happened in VMSS in related posts.

A few question here to start:

1. How can I determine what's happening on the VM? The only thing I can confirm is that "az vm show" and "az vm identity show" is showing the correct client ID and object ID.
2. Regarding the RCF, I guess I can read that file to see if the identity is included in that file. Where is it located? Do I have access to it?

[rkammara12]

@SnowmanCharles The RCF file resides on the host, I am not sure if you would have access to it. Can you please let me know the resourceId of the VM so that I can check the RCF file on the host?

Also please provide the o/p of "az vm show" and "az vm identity show" commands.

[SnowmanCharles]

@rkammara12
Do you want me to paste the resource ID here? Or is there a more secure way to share?

[rkammara12]

@SnowmanCharles is there a way you could create an ICM? if yes please create one and provide the details there.
@aramase Is there any other secure way to get the details?

[aramase]

@rkammara12 If this is a blocking issue we can request @SnowmanCharles to email the resourceID to us. WDYT?

[rkammara12]

@aramase email is fine for me, what is the recommended way? ICM is better for further communication if @SnowmanCharles has access.

[aramase]

Yeah, that works. @SnowmanCharles could you create a support ticket for this? That should then get routed to @rkammara12's team.

[SnowmanCharles]

@rkammara12 @aramase Created a new issue. https://github.com/Azure/aad-pod-identity/issues/1102. I'm not sure which Repository should it go, so just picked the "aad-pod-identity".

I'm not sure if I have access to ICM. Any guidance on how to start it?

[aramase]

@SnowmanCharles Please open a support ticket in Azure with the details. That'll be routed internally to @rkammara12's team.

[SnowmanCharles]

@rkammara12 @aramase I'm connecting with my team to ask for permission to share these data. Will get back to you soon.