Skip to content
This repository has been archived by the owner on Oct 12, 2023. It is now read-only.

kv flex-volume mounting after multiple failures #67

Closed
hjarraya opened this issue Feb 6, 2019 · 6 comments
Closed

kv flex-volume mounting after multiple failures #67

hjarraya opened this issue Feb 6, 2019 · 6 comments
Labels
better docs

Comments

@hjarraya
Copy link

hjarraya commented Feb 6, 2019

Hi,

I am having an issue that I am not able to explain/isolate. When the pod starts it fails to mount and then after few minute it successfully mount the kv-flexvolume, this is not consistent sometimes it never mounts.

Events:
  Type     Reason       Age                   From                             Message
  ----     ------       ----                  ----                             -------
  Normal   Scheduled    12m                   default-scheduler                Successfully assigned externaldns/external-dns-64c4488cd9-7bzkl to aks-default-38594516-0
  Warning  FailedMount  8m45s (x10 over 12m)  kubelet, aks-default-38594516-0  MountVolume.SetUp failed for volume "azurekv" : mount command failed, status: Failure, reason: /etc/kubernetes/volumeplugins/azure~kv/azurekeyvault-flexvolume failed, failed to get key vault
  Warning  FailedMount  8m38s (x2 over 10m)   kubelet, aks-default-38594516-0  Unable to mount volumes for pod "external-dns-64c4488cd9-7bzkl_externaldns(e6f19211-2a35-11e9-8203-32eed183208c)": timeout expired waiting for volumes to attach or mount for pod "externaldns"/"external-dns-64c4488cd9-7bzkl". list of unmounted volumes=[azurekv]. list of unattached volumes=[azurekv external-dns-token-6bbqw]
  Normal   Pulling      6m33s                 kubelet, aks-default-38594516-0  pulling image "registry.opensource.zalan.do/teapot/external-dns:v0.5.9"
  Normal   Pulled       6m32s                 kubelet, aks-default-38594516-0  Successfully pulled image "registry.opensource.zalan.do/teapot/external-dns:v0.5.9"
  Normal   Created      6m29s                 kubelet, aks-default-38594516-0  Created container
  Normal   Started      6m29s                 kubelet, aks-default-38594516-0  Started container

Here is the logs from the aks-default-38594516-0

`XXXX-XXXX-XXXX-XXXX-XXXX
I0206 18:12:01.865336    5671 main.go:98] starting the azurekeyvault-flexvolume, 0.0.6
I0206 18:12:01.865388    5671 main.go:275] subscriptionID: XXXX-XXXX-XXXX-XXXX-XXXX
I0206 18:12:01.865392    5671 main.go:276] vaultName: dev-aurora-vault
I0206 18:12:01.865395    5671 main.go:277] resourceGroup: aurora
I0206 18:12:01.865419    5671 oauth.go:135] azure: using pod identity to retrieve token

[error] failed to get key vault, error: failed to get vault, error: keyvault.VaultsClient#Get: Failure responding to request: StatusCode=401 -- Original Error: autorest/azure: Service returned an error. Status=401 Code="AuthenticationFailed" Message="Authentication failed. The 'Authorization' header is missing."

 failed to get key vault
Wed Feb 6 18:12:01 UTC 2019 ERROR: {"status": "Failure", "message": "/etc/kubernetes/volumeplugins/azure~kv/azurekeyvault-flexvolume failed, failed to get key vault "}
Wed Feb  6 18:12:18 UTC 2019 ismounted | /var/lib/kubelet/pods/a95407df-2a3a-11e9-8203-32eed183208c/volumes/azure~kv/azurekv does not exist
Wed Feb  6 18:12:18 UTC 2019 PODNAME: external-dns-64c4488cd9-jllvm
Wed Feb  6 18:12:18 UTC 2019 EXEC: /etc/kubernetes/volumeplugins/azure~kv/azurekeyvault-flexvolume -logtostderr=1 -vaultName=dev-aurora-vault -vaultObjectNames=azure-config -resourceGroup=aurora -dir=/var/lib/kubelet/pods/a95407df-2a3a-11e9-8203-32eed183208c/volumes/azure~kv/azurekv -subscriptionId=XXXX-XXXX-XXXX-XXXX-XXXX -cloudName= -tenantId=XXXXXX-XXXX-XXXX-XXXX-XXXXXXX -aADClientSecret= -aADClientID= -usePodIdentity=true -podNamespace=ambassador -podName=external-dns-64c4488cd9-jllvm -vaultObjectVersions= -vaultObjectTypes=secret
dev-aurora-vault
azurekeyvault-flexvolume 0.0.6
XXXX-XXXX-XXXX-XXXX-XXXX
I0206 18:12:18.017379    6140 main.go:98] starting the azurekeyvault-flexvolume, 0.0.6
I0206 18:12:18.017441    6140 main.go:275] subscriptionID: XXXX-XXXX-XXXX-XXXX-XXXX
I0206 18:12:18.017446    6140 main.go:276] vaultName: dev-aurora-vault
I0206 18:12:18.017450    6140 main.go:277] resourceGroup: aurora
I0206 18:12:18.017486    6140 oauth.go:135] azure: using pod identity to retrieve token

[error] failed to get key vault, error: failed to get vault, error: keyvault.VaultsClient#Get: Failure responding to request: StatusCode=401 -- Original Error: autorest/azure: Service returned an error. Status=401 Code="AuthenticationFailed" Message="Authentication failed. The 'Authorization' header is missing."

 failed to get key vault
Wed Feb 6 18:12:18 UTC 2019 ERROR: {"status": "Failure", "message": "/etc/kubernetes/volumeplugins/azure~kv/azurekeyvault-flexvolume failed, failed to get key vault "}
Wed Feb  6 18:12:50 UTC 2019 ismounted | /var/lib/kubelet/pods/a95407df-2a3a-11e9-8203-32eed183208c/volumes/azure~kv/azurekv does not exist
Wed Feb  6 18:12:50 UTC 2019 PODNAME: external-dns-64c4488cd9-jllvm
Wed Feb  6 18:12:50 UTC 2019 EXEC: /etc/kubernetes/volumeplugins/azure~kv/azurekeyvault-flexvolume -logtostderr=1 -vaultName=dev-aurora-vault -vaultObjectNames=azure-config -resourceGroup=aurora -dir=/var/lib/kubelet/pods/a95407df-2a3a-11e9-8203-32eed183208c/volumes/azure~kv/azurekv -subscriptionId=XXXX-XXXX-XXXX-XXXX-XXXX -cloudName= -tenantId=XXXXXX-XXXX-XXXX-XXXX-XXXXXXX -aADClientSecret= -aADClientID= -usePodIdentity=true -podNamespace=ambassador -podName=external-dns-64c4488cd9-jllvm -vaultObjectVersions= -vaultObjectTypes=secret
dev-aurora-vault
azurekeyvault-flexvolume 0.0.6
XXXX-XXXX-XXXX-XXXX-XXXX
I0206 18:12:50.208958    6881 main.go:98] starting the azurekeyvault-flexvolume, 0.0.6
I0206 18:12:50.209012    6881 main.go:275] subscriptionID: XXXX-XXXX-XXXX-XXXX-XXXX
I0206 18:12:50.209016    6881 main.go:276] vaultName: dev-aurora-vault
I0206 18:12:50.209019    6881 main.go:277] resourceGroup: aurora
I0206 18:12:50.209043    6881 oauth.go:135] azure: using pod identity to retrieve token

[error] failed to get key vault, error: failed to get vault, error: keyvault.VaultsClient#Get: Failure responding to request: StatusCode=401 -- Original Error: autorest/azure: Service returned an error. Status=401 Code="AuthenticationFailed" Message="Authentication failed. The 'Authorization' header is missing."

 failed to get key vault
Wed Feb 6 18:12:50 UTC 2019 ERROR: {"status": "Failure", "message": "/etc/kubernetes/volumeplugins/azure~kv/azurekeyvault-flexvolume failed, failed to get key vault "}
Wed Feb  6 18:13:54 UTC 2019 ismounted | /var/lib/kubelet/pods/a95407df-2a3a-11e9-8203-32eed183208c/volumes/azure~kv/azurekv does not exist
Wed Feb  6 18:13:54 UTC 2019 PODNAME: external-dns-64c4488cd9-jllvm
Wed Feb  6 18:13:54 UTC 2019 EXEC: /etc/kubernetes/volumeplugins/azure~kv/azurekeyvault-flexvolume -logtostderr=1 -vaultName=dev-aurora-vault -vaultObjectNames=azure-config -resourceGroup=aurora -dir=/var/lib/kubelet/pods/a95407df-2a3a-11e9-8203-32eed183208c/volumes/azure~kv/azurekv -subscriptionId=XXXX-XXXX-XXXX-XXXX-XXXX -cloudName= -tenantId=XXXXXX-XXXX-XXXX-XXXX-XXXXXXX -aADClientSecret= -aADClientID= -usePodIdentity=true -podNamespace=ambassador -podName=external-dns-64c4488cd9-jllvm -vaultObjectVersions= -vaultObjectTypes=secret
dev-aurora-vault
azurekeyvault-flexvolume 0.0.6
XXXX-XXXX-XXXX-XXXX-XXXX
I0206 18:13:54.398159    8254 main.go:98] starting the azurekeyvault-flexvolume, 0.0.6
I0206 18:13:54.398225    8254 main.go:275] subscriptionID: XXXX-XXXX-XXXX-XXXX-XXXX
I0206 18:13:54.398229    8254 main.go:276] vaultName: dev-aurora-vault
I0206 18:13:54.398233    8254 main.go:277] resourceGroup: aurora
I0206 18:13:54.398261    8254 oauth.go:135] azure: using pod identity to retrieve token

[error] failed to get key vault, error: failed to get vault, error: keyvault.VaultsClient#Get: Failure responding to request: StatusCode=401 -- Original Error: autorest/azure: Service returned an error. Status=401 Code="AuthenticationFailed" Message="Authentication failed. The 'Authorization' header is missing."

 failed to get key vault
Wed Feb 6 18:13:54 UTC 2019 ERROR: {"status": "Failure", "message": "/etc/kubernetes/volumeplugins/azure~kv/azurekeyvault-flexvolume failed, failed to get key vault "}
Wed Feb  6 18:15:56 UTC 2019 ismounted | /var/lib/kubelet/pods/a95407df-2a3a-11e9-8203-32eed183208c/volumes/azure~kv/azurekv does not exist
Wed Feb  6 18:15:56 UTC 2019 PODNAME: external-dns-64c4488cd9-jllvm
Wed Feb  6 18:15:56 UTC 2019 EXEC: /etc/kubernetes/volumeplugins/azure~kv/azurekeyvault-flexvolume -logtostderr=1 -vaultName=dev-aurora-vault -vaultObjectNames=azure-config -resourceGroup=aurora -dir=/var/lib/kubelet/pods/a95407df-2a3a-11e9-8203-32eed183208c/volumes/azure~kv/azurekv -subscriptionId=XXXX-XXXX-XXXX-XXXX-XXXX -cloudName= -tenantId=XXXXXX-XXXX-XXXX-XXXX-XXXXXXX -aADClientSecret= -aADClientID= -usePodIdentity=true -podNamespace=ambassador -podName=external-dns-64c4488cd9-jllvm -vaultObjectVersions= -vaultObjectTypes=secret
dev-aurora-vault
azurekeyvault-flexvolume 0.0.6
XXXX-XXXX-XXXX-XXXX-XXXX
I0206 18:15:56.656382   11666 main.go:98] starting the azurekeyvault-flexvolume, 0.0.6
I0206 18:15:56.656482   11666 main.go:275] subscriptionID: XXXX-XXXX-XXXX-XXXX-XXXX
I0206 18:15:56.656486   11666 main.go:276] vaultName: dev-aurora-vault
I0206 18:15:56.656489   11666 main.go:277] resourceGroup: aurora
I0206 18:15:56.656515   11666 oauth.go:135] azure: using pod identity to retrieve token

 accesstoken: eyJ0##### REDACTED #####i3IQ

 clientid: 59f7##### REDACTED #####73e5
I0206 18:15:57.232027   11666 oauth.go:135] azure: using pod identity to retrieve token

 accesstoken: eyJ0##### REDACTED #####QreQ

 clientid: 59f7##### REDACTED #####73e5
I0206 18:15:57.339939   11666 main.go:132] retrieving secret azure-config (version: )
I0206 18:15:57.512055   11666 main.go:176] azure KeyVault wrote secret azure-config at /var/lib/kubelet/pods/a95407df-2a3a-11e9-8203-32eed183208c/volumes/azure~kv/azurekv
Wed Feb  6 18:15:57 UTC 2019 EXEC: ls /var/lib/kubelet/pods/a95407df-2a3a-11e9-8203-32eed183208c/volumes/azure~kv/azurekv
azure-config
Wed Feb 6 18:15:57 UTC 2019 INFO: {"status": "Success"}
@ritazh
Copy link
Member

ritazh commented Feb 7, 2019

@hjarraya The entire AzureAssignedIdentity creation process gets triggered when we create the volume at pod creation time. All these components (find identity, assign identity, retrieve token for key vault) will take time to complete. If volume mount fails, the kubelet will retry. Hence you are seeing errors in the log but looks like eventually all the dependent components got created successfully. So this is expected. Hope this helps.

@ritazh ritazh mentioned this issue Feb 13, 2019
Closed
@juona
Copy link

juona commented Apr 15, 2019

Thank you for the explanation @ritazh , now we know not to investigate this. Gotta second @hjarraya though in that the behaviour does not seem consistent nor reliable; doesn't feel like it's purely a documentation issue.

@ritazh ritazh mentioned this issue May 10, 2019
Merged
@ritazh
Copy link
Member

ritazh commented May 10, 2019

closed via #94

@ritazh ritazh closed this as completed May 10, 2019
@ritazh
Copy link
Member

ritazh commented May 13, 2019

This experience can be improved by fixing issue Azure/aad-pod-identity#181

@kkmsft kkmsft reopened this May 31, 2019
@kkmsft
Copy link

kkmsft commented May 31, 2019 •
edited
Loading

Currently the key vault calls to NMI is not retried by the key vault. The retry is getting added to the NMI calls themselves in Azure/aad-pod-identity#181. Re opening this issue to ensure that we retry in the key vault itself when it tries to attempt reaching the NMI fails. This will give key vault flex volume ability to tune its retry attempts to ensure that the kubelet does not time out the mount attempt and make it more resilient from underlying vm/vmss assignment attempts by aad pod identity.

@ritazh
Copy link
Member

ritazh commented Jun 27, 2019

Closed via #102

@ritazh ritazh closed this as completed Jun 27, 2019
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
better docs
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
4 participants
@ritazh @hjarraya @juona @kkmsft