SparebankenVest / azure-key-vault-to-kubernetes

Azure Key Vault to Kubernetes (akv2k8s for short) makes it simple and secure to use Azure Key Vault secrets, keys and certificates in Kubernetes.
https://akv2k8s.io
Apache License 2.0
432 stars 98 forks source link

[Question] Failing at auth service credentials while injecting secrets. #221

Open pb586b opened 3 years ago

pb586b commented 3 years ago

Note: Make sure to check out known issues (https://github.com/sparebankenvest/azure-key-vault-to-kubernetes#known-issues) before submitting

Your question I'm trying to inject secrets from Key Vault to AKS, while pod starting the injection is failing at auth service with 403 status code. Need assistance to resolve this issue as the secrets are not getting pulled into the pod. I have set policies as well.

To Reproduce Not sure how to.

Logs Pod logs: I0723 16:35:14.389830 1 version.go:31] "version info" version="" commit="a7b2d04" buildDate="2021-03-11T07:33:36Z" component="vaultenv" I0723 16:35:14.389922 1 main.go:176] "azure key vault env injector initializing" I0723 16:35:14.390189 1 main.go:245] "found original container command" cmd="/bin/sh" args=[/bin/sh -c /startService.sh msUsername msPwd] I0723 16:35:14.390236 1 authentication.go:98] "checking if current auth service credentials are stale" url="http://akv2k8s-envinjector.akv2k8s.svc:80/auth/com-att-data360-dev/feedbackemail-1-5-0-d2a-7b5854499d-6xbrj?secret=akv2k8s-feedbackemail-1-5-0-d2a" I0723 16:35:14.474040 1 authentication.go:116] "failed to validate credentials" url="http://akv2k8s-envinjector.akv2k8s.svc:80/auth/com-att-data360-dev/feedbackemail-1-5-0-d2a-7b5854499d-6xbrj?secret=akv2k8s-feedbackemail-1-5-0-d2a" status="403 Forbidden" statusCode=403

AKV-Injector Logs: I0723 15:30:18.293342 1 main.go:143] "found pod to mutate" pod="com-att-data360-dev/" I0723 15:30:18.293374 1 pod.go:285] "creating client certificate to use with auth service" com-att-data360-dev/="(MISSING)" I0723 15:30:18.314513 1 pod.go:292] "mutate init-containers" com-att-data360-dev/="(MISSING)" I0723 15:30:18.314539 1 pod.go:298] "mutate containers" com-att-data360-dev/="(MISSING)" I0723 15:30:18.314548 1 pod.go:116] "found container to mutate" container="com-att-data360-dev/feedbackemail" I0723 15:30:18.314556 1 pod.go:119] "checking for env vars to inject" container="com-att-data360-dev/feedbackemail" I0723 15:30:18.314578 1 pod.go:122] "found env var to inject" env="ampmd-mechid-username-secret@azurekeyvault" container="com-att-data360-dev/feedbackemail" I0723 15:30:18.314590 1 pod.go:122] "found env var to inject" env="ampmd-mechid-password-secret@azurekeyvault" container="com-att-data360-dev/feedbackemail" I0723 15:30:20.414863 1 pod.go:149] "found container arguments to use for env-injector" cmd="/bin/sh -c /startService.sh msUsername msPwd" container="com-att-data360-dev/feedbackemail" I0723 15:30:20.770593 1 pod.go:307] "containers mutated and pod updated with init-container and volumes" pod="com-att-data360-dev/"

Additional context Please provide steps to troubleshoot, I can provide further details

kristeey commented 3 years ago

Could you provide some additional information such as:

  1. Env-injector (webhook) version.
  2. How you installed the tools (e.g. helm chart) and provide the chart values set (e.g. values.yaml).
  3. What kind of AKV authentication you are using (https://akv2k8s.io/security/authentication/#akv-authentication-with-the-env-injector)
  4. If the cluster have any special configurations. Network policies e.t.c, service mesh.
kristeey commented 3 years ago

Could this be related? https://github.com/SparebankenVest/azure-key-vault-to-kubernetes/issues/162

pb586b commented 3 years ago

Could you provide some additional information such as:

  1. Env-injector (webhook) version.
  2. How you installed the tools (e.g. helm chart) and provide the chart values set (e.g. values.yaml).
  3. What kind of AKV authentication you are using (https://akv2k8s.io/security/authentication/#akv-authentication-with-the-env-injector)
  4. If the cluster have any special configurations. Network policies e.t.c, service mesh.
  1. Env-injector version - spvest/azure-keyvault-webhook:1.2.3
  2. For windows - I downloaded helm from releases: https://github.com/helm/helm/releases For Ubuntu - wget https://get.helm.sh/helm-v3.4.1-linux-amd64.tar.gz, I then unpacked it using tar We used proxy settings in deployment.yaml containers: env:
    • name: http_proxy value:
    • name: https_proxy value:
  3. We are using aad-pod-identity. We have multiple namespaces for different envs within the same cluster. Accessing the key vault is done my default AKS cluster Service Principal ID and thus settings policies directly to allow connections from AKS to AKV using the same Service Principal. Helm install command helm upgrade --install akv2k8s spv-charts/akv2k8s --namespace akv2k8s --set addAzurePodIdentityException=true --set keyVaultAuth=azureCloudConfig
  4. No special policies with the AKS cluster.
kristeey commented 3 years ago

The "failed to validate credentials" status="403 Forbidden" is a result of a failed authorization of the request at the env-injector-webhook side after the pod env injector tries to validate the auth service credentials. In other words the cred validation Get request from the app pod reaches the env-injector-webhook pod, but it fails to authorize the request. Could you install akv2k8s with global.logLevel=trace flag set? I.e.

helm upgrade --install akv2k8s spv-charts/akv2k8s --namespace akv2k8s --set addAzurePodIdentityException=true --set keyVaultAuth=azureCloudConfig --set global.logLevel=trace

This will give some additional logging in the env-injector-webhook pod that handles the request. The logs should look something like

I0730 13:14:09.429133       1 version.go:31] "version info" version="1.2.3" commit="a7b2d04" buildDate="2021-03-11T07:33:20Z" component="webhook"
I0730 13:14:09.429223       1 main.go:289] "active settings" httpPort="8080" httpPortExternal="80" tlsPort="8443" tlsPortExternal="443" mtlsPort="9443" mtlsPortExternal="9443" serveMetrics=false authType="azureCloudConfig" useAuthService=true dockerInspectionTimeout=20 cloudConfigPath="/etc/kubernetes/azure.json" logLevel="6" authServiceName="akv2k8s-envinjector" mtlsPortExternal="9443" mtlsPort="9443"
I0730 13:14:09.430754       1 main.go:358] "using cloudConfig for auth - reading credentials" file="/etc/kubernetes/azure.json"
I0730 13:14:09.431123       1 provider.go:274] "azure: using managed identity extension to retrieve access token" id="..."
I0730 13:14:09.431145       1 provider.go:281] "azure: using managed identity extension to retrieve access token" id="..."
I0730 13:14:09.431175       1 main.go:376] "checking credentials by getting authorizer"
I0730 13:14:10.353136       1 auth.go:54] "auth service ca cert" file="/var/ca-cert/tls.crt"
I0730 13:14:10.353164       1 auth.go:55] "auth service ca key" file="/var/ca-cert/tls.key"
I0730 13:14:10.353537       1 main.go:392] "serving auth validation endpoint" path=":8080/auth/{namespace}/{pod}"
I0730 13:14:10.353581       1 main.go:396] "serving health endpoint" path=":8080/healthz"
I0730 13:14:10.353807       1 main.go:443] "serving encrypted auth endpoint" path=":9443/auth"
2021/07/30 13:14:10 [WARN] no tracer active
I0730 13:14:10.354018       1 main.go:419] "serving encrypted webhook endpoint" path=":8443/pods"
I0730 13:14:10.354060       1 main.go:422] "serving encrypted healthz endpoint" path=":8443/healthz"
I0730 13:14:57.396319       1 round_trippers.go:445] GET https://10.0.0.1:443/api/v1/namespaces/akv-test 200 OK in 29 milliseconds
I0730 13:14:57.401114       1 round_trippers.go:445] GET https://10.0.0.1:443/api/v1/namespaces/akv-test/pods/secret-injection-app-77d4d5b7d8-z5c8p 200 OK in 4 milliseconds
I0730 13:14:57.413305       1 round_trippers.go:445] GET https://10.0.0.1:443/api/v1/namespaces/akv-test/pods/secret-injection-app-77d4d5b7d8-z5c8p 200 OK in 4 milliseconds
I0730 13:14:57.413922       1 clientCert.go:25] "creating x509 key pair for ca cert and key"
I0730 13:14:57.414238       1 clientCert.go:32] "parse certificate"
I0730 13:14:57.414355       1 clientCert.go:38] "generating client key"
I0730 13:14:57.445285       1 clientCert.go:44] "generating serial number"
I0730 13:14:57.445475       1 clientCert.go:66] "crating x509 certificate"
I0730 13:14:57.459476       1 round_trippers.go:445] GET https://10.0.0.1:443/api/v1/namespaces/akv-test/secrets/akv2k8s-secret-injection-app 200 OK in 11 milliseconds
I0730 13:14:57.480351       1 round_trippers.go:445] GET https://10.0.0.1:443/api/v1/namespaces/akv-test 200 OK in 7 milliseconds
I0730 13:14:57.484703       1 round_trippers.go:445] GET https://10.0.0.1:443/api/v1/namespaces/akv-test/pods/secret-injection-app-77d4d5b7d8-z5c8p 200 OK in 4 milliseconds
I0730 13:14:57.523238       1 auth.go:154] "served oauth token" pod="secret-injection-app-77d4d5b7d8-z5c8p" namespace="akv-test"

But will give 403 status code instead of 200. Also, ensure that the namespace has the azure-key-vault-env-injection: enabled label.

pb586b commented 3 years ago

Attached webhook logs.

logs-from-webhook-in-akv2k8s-envinjector-6bc7d8b4dd-fwms9.txt

E0802 21:06:01.496531       1 aws_credentials.go:77] while getting AWS credentials NoCredentialProviders: no valid providers in chain. Deprecated.
2021-08-02T21:06:01.496669329Z      For verbose messaging see aws.Config.CredentialsChainVerboseErrors

Don't know why it is trying to check for AWS credentials as I have never provided it anywhere.

Pod Logs:

I0802 21:12:53.843633       1 version.go:31] "version info" version="" commit="a7b2d04" buildDate="2021-03-11T07:33:36Z" component="vaultenv"
I0802 21:12:53.844410       1 main.go:176] "azure key vault env injector initializing"
I0802 21:12:53.844635       1 main.go:245] "found original container command" cmd="/bin/sh" args=[/bin/sh -c /startService.sh msUsername msPwd]
I0802 21:12:53.844683       1 authentication.go:98] "checking if current auth service credentials are stale" url="http://akv2k8s-envinjector.akv2k8s.svc:80/auth/com-att-data360-dev/feedbackemail-1-5-0-d2a-7b5854499d-hrqgp?secret=akv2k8s-feedbackemail-1-5-0-d2a"
I0802 21:12:53.903064       1 authentication.go:116] "failed to validate credentials" url="http://akv2k8s-envinjector.akv2k8s.svc:80/auth/com-att-data360-dev/feedbackemail-1-5-0-d2a-7b5854499d-hrqgp?secret=akv2k8s-feedbackemail-1-5-0-d2a" status="403 Forbidden" statusCode=403

Note: akv2k8s is installed in "akv2k8s" namespace while the pods are in another namespace. (If it helps)

kristeey commented 3 years ago

The AWS credentials error is unrelated to this case.

The webhook logs that you provided indicate that (i) the webhook is able to mutate the application container and update application pod with init-container. This is the first process that the Env-Injector does when it detects a new pod that wants secrets injected in a namespace with azure-key-vault-env-injection: enabled. After this process is done, the init-container starts and copies the azure-keyvault-env executable into /azure-keyvault/ volumepath in the application pod -> (ii) the application pod starts running the mutated container that will execute the azure-keyvault-env command. It gets theAzure Key Vault credentials by sending a GET request to the /auth/... endpoint of the webhook pod (Env-Injector auth service). This should in theory return a oauth token and everything should be good, but this is not the case here. So this means that something funky is happening in (iii) the webhook pod when it receives the GET request and tries to handle it (i.e. in the Auth Validate handler). This fails with StatusCode 403 if the authorize function returns an error, which it does if a K8S api GET requests (to get Pods or Namespace) fails, the namespace (that it gets from the K8s api) somehow does not have the azure-key-vault-env-injection label, the container (in the pod that it gets from the K8S api) does not contain the injector command, or the the pod does not have the env-injector init-container in it.

If we take a look at the timestamps of the logs that you provided, they cover the initial "mutate container" phase (i) of the webhook pod (logs-from-webhook-in-akv2k8s-envinjector-6bc7d8b4dd-fwms9.txt), and the logs of the application pods "mutated container run" phase (ii). We miss the logs from the "authentication handling" phase (iii) in the webhook pod, which I (unfortunately) would guess was handled by the second webhook pod. Hence it is hard to say exactly what happens without this last missing piece.

pb586b commented 3 years ago

I rescaled the webhook pods and obtaining the container logs. logs-from-webhook-in-akv2k8s-envinjector-6bc7d8b4dd-zjxbk.txt

As far as I can tell, it has the same logs. From where can I obtain further logs or how how do we troubleshoot it further?

kristeey commented 3 years ago

Could this be related? https://github.com/SparebankenVest/azure-key-vault-to-kubernetes/issues/175

muwiess commented 3 years ago

Hi @kristeey we applied all the recommendations on #175 https://github.com/SparebankenVest/azure-key-vault-to-kubernetes/issues/175 but we still see the error.

The error is happening when the injector attempts to access the Private ACR to pull the container image, however, when the injection is not applied, the container pulls the image and runs with no issues.

We tested the injection with a public image (not ACR), and the injection works following the recommendation from #175, with the Pod Identity azureidentity and azureidentityBinding but fails when pulling the image from ACR.

We follow the recommendation to add all the roles to the managed Identity but still doesn't work. image

This is an example of what we run using a non-ACR image which is working.

apiVersion: v1 kind: Pod metadata: labels: app: nginx-flex-kv-podid aadpodidbinding: eastus2-amt-nprd-aks-agentpool name: nginx-flex-kv-podid namespace: com-att-amteco-dev

spec: containers:

$ kubectl logs nginx-flex-kv-podid -n com-att-amteco-dev I0820 16:42:56.327515 1 version.go:31] "version info" version="" commit="a375982" buildDate="2021-08-06T06:52:36Z" component="vaultenv" I0820 16:42:56.327736 1 main.go:176] "azure key vault env injector initializing" I0820 16:42:56.327972 1 main.go:245] "found original container command" cmd="/docker-entrypoint.sh" args=[/docker-entrypoint.sh nginx -g daemon off;] I0820 16:42:56.328026 1 authentication.go:98] "checking if current auth service credentials are stale" url="http://akv2k8s-envinjector.akv2k8s.svc:80/auth/com-att-amteco-dev/nginx-flex-kv-podid?secret=akv2k8s-nginx-flex-kv-podid" I0820 16:42:56.388002 1 authentication.go:111] "auth service credentials ok" url="http://akv2k8s-envinjector.akv2k8s.svc:80/auth/com-att-amteco-dev/nginx-flex-kv-podid?secret=akv2k8s-nginx-flex-kv-podid" I0820 16:42:56.388548 1 authentication.go:147] "requesting azure key vault oauth token" url="https://akv2k8s-envinjector.akv2k8s.svc:9443/auth/com-att-amteco-dev/nginx-flex-kv-podid" I0820 16:42:56.421024 1 authentication.go:167] "successfully received oauth token" I0820 16:42:56.595437 1 main.go:342] "secret injected into env var" azurekeyvaultsecret="com-att-amteco-dev/aaf-id-secret-sync" env="AAF_ID" I0820 16:42:56.595494 1 main.go:348] "starting process with secrets in env vars" cmd="/docker-entrypoint.sh" args=[/docker-entrypoint.sh nginx -g daemon off;] /docker-entrypoint.sh: /docker-entrypoint.d/ is not empty, will attempt to perform configuration /docker-entrypoint.sh: Looking for shell scripts in /docker-entrypoint.d/ /docker-entrypoint.sh: Launching /docker-entrypoint.d/10-listen-on-ipv6-by-default.sh 10-listen-on-ipv6-by-default.sh: info: Getting the checksum of /etc/nginx/conf.d/default.conf 10-listen-on-ipv6-by-default.sh: info: Enabled listen on IPv6 in /etc/nginx/conf.d/default.conf /docker-entrypoint.sh: Launching /docker-entrypoint.d/20-envsubst-on-templates.sh /docker-entrypoint.sh: Launching /docker-entrypoint.d/30-tune-worker-processes.sh /docker-entrypoint.sh: Configuration complete; ready for start up 2021/08/20 16:42:56 [notice] 1#1: using the "epoll" event method 2021/08/20 16:42:56 [notice] 1#1: nginx/1.21.1 2021/08/20 16:42:56 [notice] 1#1: built by gcc 8.3.0 (Debian 8.3.0-6) 2021/08/20 16:42:56 [notice] 1#1: OS: Linux 5.4.0-1055-azure 2021/08/20 16:42:56 [notice] 1#1: getrlimit(RLIMIT_NOFILE): 1048576:1048576 2021/08/20 16:42:56 [notice] 1#1: start worker processes 2021/08/20 16:42:56 [notice] 1#1: start worker process 36 2021/08/20 16:42:56 [notice] 1#1: start worker process 37 2021/08/20 16:42:56 [notice] 1#1: start worker process 38 2021/08/20 16:42:56 [notice] 1#1: start worker process 39

The error is only being displayed in the pod logs, but the injector pod doesn't show any error with trace log level.

$ kubectl logs amtadminservice-2-0-6c5ff6c645-b7nzk -n com-att-amteco-dev I0820 18:01:48.942701 1 version.go:31] "version info" version="" commit="a375982" buildDate="2021-08-06T06:52:36Z" component="vaultenv" I0820 18:01:48.942763 1 main.go:176] "azure key vault env injector initializing" I0820 18:01:48.942949 1 main.go:245] "found original container command" cmd="/bin/sh" args=[/bin/sh -c /startService.sh] I0820 18:01:48.942999 1 authentication.go:98] "checking if current auth service credentials are stale" url="http://akv2k8s-envinjector.akv2k8s.svc:80/auth/com-att-amteco-dev/amtadminservice-2-0-6c5ff6c645-b7nzk?secret=akv2k8s-amtadminservice-2-0" E0820 18:01:48.993522 1 authentication.go:116] "failed to validate credentials" url="http://akv2k8s-envinjector.akv2k8s.svc:80/auth/com-att-amteco-dev/amtadminservice-2-0-6c5ff6c645-b7nzk?secret=akv2k8s-amtadminservice-2-0" status="403 Forbidden" statusCode=403 I0820 18:01:48.993624 1 authentication.go:98] "checking if current auth service credentials are stale" url="http://akv2k8s-envinjector.akv2k8s.svc:80/auth/com-att-amteco-dev/amtadminservice-2-0-6c5ff6c645-b7nzk?secret=akv2k8s-amtadminservice-2-0" E0820 18:01:49.008694 1 authentication.go:116] "failed to validate credentials" url="http://akv2k8s-envinjector.akv2k8s.svc:80/auth/com-att-amteco-dev/amtadminservice-2-0-6c5ff6c645-b7nzk?secret=akv2k8s-amtadminservice-2-0" status="403 Forbidden" statusCode=403 I0820 18:01:52.009192 1 authentication.go:98] "checking if current auth service credentials are stale" url="http://akv2k8s-envinjector.akv2k8s.svc:80/auth/com-att-amteco-dev/amtadminservice-2-0-6c5ff6c645-b7nzk?secret=akv2k8s-amtadminservice-2-0" E0820 18:01:52.063410 1 authentication.go:116] "failed to validate credentials" url="http://akv2k8s-envinjector.akv2k8s.svc:80/auth/com-att-amteco-dev/amtadminservice-2-0-6c5ff6c645-b7nzk?secret=akv2k8s-amtadminservice-2-0" status="403 Forbidden" statusCode=403 I0820 18:01:58.067216 1 authentication.go:98] "checking if current auth service credentials are stale" url="http://akv2k8s-envinjector.akv2k8s.svc:80/auth/com-att-amteco-dev/amtadminservice-2-0-6c5ff6c645-b7nzk?secret=akv2k8s-amtadminservice-2-0" E0820 18:01:58.078989 1 authentication.go:116] "failed to validate credentials" url="http://akv2k8s-envinjector.akv2k8s.svc:80/auth/com-att-amteco-dev/amtadminservice-2-0-6c5ff6c645-b7nzk?secret=akv2k8s-amtadminservice-2-0" status="403 Forbidden" statusCode=403 E0820 18:01:58.079064 1 main.go:261] "failed to get credentials" err="failed to validate credentials, got http status code 403" failedTimes=3

kubectl logs akv2k8s-envinjector-85b6d98dc4-99nr7 -n akv2k8s I0820 17:28:14.035605 1 main.go:143] "found pod to mutate" pod="com-att-amteco-dev/" I0820 17:28:14.035631 1 pod.go:285] "creating client certificate to use with auth service" com-att-amteco-dev/="(MISSING)" I0820 17:28:14.035645 1 clientCert.go:25] "creating x509 key pair for ca cert and key" I0820 17:28:14.035836 1 clientCert.go:32] "parse certificate" I0820 17:28:14.035884 1 clientCert.go:38] "generating client key" I0820 17:28:14.056492 1 clientCert.go:44] "generating serial number" I0820 17:28:14.056518 1 clientCert.go:66] "crating x509 certificate" I0820 17:28:14.059012 1 pod.go:292] "mutate init-containers" com-att-amteco-dev/="(MISSING)" I0820 17:28:14.059030 1 pod.go:298] "mutate containers" com-att-amteco-dev/="(MISSING)" I0820 17:28:14.059056 1 pod.go:116] "found container to mutate" container="com-att-amteco-dev/amtadminservice" I0820 17:28:14.059064 1 pod.go:119] "checking for env vars to inject" container="com-att-amteco-dev/amtadminservice" I0820 17:28:14.059103 1 pod.go:122] "found env var to inject" env="aaf-id-secret-sync@azurekeyvault" container="com-att-amteco-dev/amtadminservice" I0820 17:28:14.059117 1 pod.go:122] "found env var to inject" env="aaf-password-secret-sync@azurekeyvault" container="com-att-amteco-dev/amtadminservice" I0820 17:28:14.059126 1 registry.go:30] "getting container command for container" container="com-att-amteco-dev/amtadminservice" I0820 17:28:14.059139 1 registry.go:36] "no cmd override in kubernetes for container, checking docker image configuration for entrypoint and cmd" image="amteastus2crn0rfliie.azurecr.io/com.att.amteco/amtadminservice:2.0.92" container="com-att-amteco-dev/amtadminservice" I0820 17:28:14.059171 1 registry.go:89] "found image in cache" image="amteastus2crn0rfliie.azurecr.io/com.att.amteco/amtadminservice:2.0.92" I0820 17:28:14.059187 1 pod.go:149] "found container arguments to use for env-injector" cmd="/bin/sh -c /startService.sh" container="com-att-amteco-dev/amtadminservice" I0820 17:28:14.307795 1 pod.go:265] "signed arguments to prevent override" container="com-att-amteco-dev/amtadminservice" I0820 17:28:14.307877 1 pod.go:272] "public signing key for argument verification" key="-----BEGIN RSA PUBLIC KEY-----\n\n-----END RSA PUBLIC KEY-----\n" container="com-att-amteco-dev/amtadminservice" I0820 17:28:14.307914 1 pod.go:159] "full exec path" path="/azure-keyvault/azure-keyvault-env" container="com-att-amteco-dev/amtadminservice" I0820 17:28:14.307954 1 pod.go:170] "mounting volume" volume="azure-keyvault-env" path="/azure-keyvault/" container="com-att-amteco-dev/amtadminservice" I0820 17:28:14.356924 1 round_trippers.go:454] POST https://10.0.16.1:443/api/v1/namespaces/com-att-amteco-dev/secrets 409 Conflict in 48 milliseconds I0820 17:28:14.387465 1 round_trippers.go:454] PUT https://10.0.16.1:443/api/v1/namespaces/com-att-amteco-dev/secrets/akv2k8s-amtadminservice-2-0 200 OK in 30 milliseconds I0820 17:28:14.387823 1 pod.go:307] "containers mutated and pod updated with init-container and volumes" pod="com-att-amteco-dev/" 2021/08/20 17:28:14 [DEBUG] json patch for request f080cea5-b8bb-455d-b465-5e213d7c1d15: [{"op":"add","path":"/spec/volumes/4","value":{"name":"azure-keyvault-env","emptyDir":{"medium":"Memory"}}},{"op":"add","path":"/spec/volumes/5","value":{"name":"akv2k8s-client-cert","secret":{"secretName":"akv2k8s-amtadminservice-2-0","defaultMode":420}}},{"op":"add","path":"/spec/initContainers","value":[{"name":"copy-azurekeyvault-env","image":"spvest/azure-keyvault-env:1.3.0","command":["sh","-c","cp /usr/local/bin/azure-keyvault-env /azure-keyvault/"],"resources":{},"volumeMounts":[{"name":"azure-keyvault-env","mountPath":"/azure-keyvault/"}],"imagePullPolicy":"IfNotPresent"}]},{"op":"add","path":"/spec/containers/0/command","value":["/azure-keyvault/azure-keyvault-env"]},{"op":"add","path":"/spec/containers/0/args","value":["/bin/sh","-c","/startService.sh"]},{"op":"add","path":"/spec/containers/0/env/35","value":{"name":"ENV_INJECTOR_ARGS_SIGNATURE","value":"="}},{"op":"add","path":"/spec/containers/0/env/36","value":{"name":"ENV_INJECTOR_ARGS_KEY","value":""}},{"op":"add","path":"/spec/containers/0/env/37","value":{"name":"ENV_INJECTOR_USE_AUTH_SERVICE","value":"true"}},{"op":"add","path":"/spec/containers/0/env/38","value":{"name":"ENV_INJECTOR_POD_NAMESPACE","valueFrom":{"fieldRef":{"fieldPath":"metadata.namespace"}}}},{"op":"add","path":"/spec/containers/0/env/39","value":{"name":"ENV_INJECTOR_POD_NAME","valueFrom":{"fieldRef":{"fieldPath":"metadata.name"}}}},{"op":"add","path":"/spec/containers/0/env/40","value":{"name":"ENV_INJECTOR_CLIENT_CERT_DIR","value":"/var/client-cert/"}},{"op":"add","path":"/spec/containers/0/env/41","value":{"name":"ENV_INJECTOR_AUTH_SERVICE","value":"https://akv2k8s-envinjector.akv2k8s.svc:9443"}},{"op":"add","path":"/spec/containers/0/env/42","value":{"name":"ENV_INJECTOR_AUTH_SERVICE_VALIDATION","value":"http://akv2k8s-envinjector.akv2k8s.svc:80"}},{"op":"add","path":"/spec/containers/0/env/43","value":{"name":"ENV_INJECTOR_AUTH_SERVICE_SECRET","value":"akv2k8s-amtadminservice-2-0"}},{"op":"add","path":"/spec/containers/0/volumeMounts/4","value":{"name":"azure-keyvault-env","readOnly":true,"mountPath":"/azure-keyvault/"}},{"op":"add","path":"/spec/containers/0/volumeMounts/5","value":{"name":"akv2k8s-client-cert","readOnly":true,"mountPath":"/var/client-cert/"}}] 2021/08/20 17:28:52 [DEBUG] reviewing request e0fd0e9f-2870-49c0-9239-16481cf515c9, named: com-att-amteco-dev/

We have tried to set Debug ENV_INJECTOR_LOG_LEVEL to the container but is not working,

apiVersion: apps/v1 kind: Deployment metadata: annotations: deployment.kubernetes.io/revision: "1" meta.helm.sh/release-name: akv2k8s meta.helm.sh/release-namespace: akv2k8s creationTimestamp: "2021-08-20T16:51:09Z" generation: 2 labels: app.kubernetes.io/instance: akv2k8s app.kubernetes.io/managed-by: Helm app.kubernetes.io/name: akv2k8s helm.sh/chart: akv2k8s-2.1.0 name: akv2k8s-envinjector namespace: akv2k8s resourceVersion: "12024461" selfLink: /apis/apps/v1/namespaces/akv2k8s/deployments/akv2k8s-envinjector uid: c5d5a36f-b688-47b1-90ff-20213ed5407e spec: progressDeadlineSeconds: 600 replicas: 1 revisionHistoryLimit: 10 selector: matchLabels: app.kubernetes.io/component: akv2k8s-webhook app.kubernetes.io/instance: akv2k8s app.kubernetes.io/name: akv2k8s strategy: rollingUpdate: maxSurge: 25% maxUnavailable: 25% type: RollingUpdate template: metadata: annotations: checksum/config: 0ccea9dd631ec9849a5a6d1b5888038a0bdb6b72cc47ef532dc2c08835cce9da creationTimestamp: null labels: app.kubernetes.io/component: akv2k8s-webhook app.kubernetes.io/instance: akv2k8s app.kubernetes.io/name: akv2k8s spec: containers:

This is the error that we are only able to capture at the container level:

I0820 18:20:00.969580 1 version.go:31] "version info" version="" commit="a375982" buildDate="2021-08-06T06:52:36Z" component="vaultenv" I0820 18:20:00.970746 1 main.go:176] "azure key vault env injector initializing" I0820 18:20:00.970971 1 main.go:245] "found original container command" cmd="/bin/sh" args=[/bin/sh -c /startService.sh] I0820 18:20:00.971336 1 authentication.go:98] "checking if current auth service credentials are stale" url="http://akv2k8s-envinjector.akv2k8s.svc:80/auth/com-att-amteco-dev/amtadminservice-2-0-6c5ff6c645-mf2sp?secret=akv2k8s-amtadminservice-2-0" E0820 18:20:00.991120 1 authentication.go:116] "failed to validate credentials" url="http://akv2k8s-envinjector.akv2k8s.svc:80/auth/com-att-amteco-dev/amtadminservice-2-0-6c5ff6c645-mf2sp?secret=akv2k8s-amtadminservice-2-0" status="403 Forbidden" statusCode=403 I0820 18:20:00.991250 1 authentication.go:98] "checking if current auth service credentials are stale" url="http://akv2k8s-envinjector.akv2k8s.svc:80/auth/com-att-amteco-dev/amtadminservice-2-0-6c5ff6c645-mf2sp?secret=akv2k8s-amtadminservice-2-0" E0820 18:20:01.044453 1 authentication.go:116] "failed to validate credentials" url="http://akv2k8s-envinjector.akv2k8s.svc:80/auth/com-att-amteco-dev/amtadminservice-2-0-6c5ff6c645-mf2sp?secret=akv2k8s-amtadminservice-2-0" status="403 Forbidden" statusCode=403 I0820 18:20:04.046578 1 authentication.go:98] "checking if current auth service credentials are stale" url="http://akv2k8s-envinjector.akv2k8s.svc:80/auth/com-att-amteco-dev/amtadminservice-2-0-6c5ff6c645-mf2sp?secret=akv2k8s-amtadminservice-2-0" E0820 18:20:04.057490 1 authentication.go:116] "failed to validate credentials" url="http://akv2k8s-envinjector.akv2k8s.svc:80/auth/com-att-amteco-dev/amtadminservice-2-0-6c5ff6c645-mf2sp?secret=akv2k8s-amtadminservice-2-0" status="403 Forbidden" statusCode=403 I0820 18:20:10.061206 1 authentication.go:98] "checking if current auth service credentials are stale" url="http://akv2k8s-envinjector.akv2k8s.svc:80/auth/com-att-amteco-dev/amtadminservice-2-0-6c5ff6c645-mf2sp?secret=akv2k8s-amtadminservice-2-0" E0820 18:20:10.079383 1 authentication.go:116] "failed to validate credentials" url="http://akv2k8s-envinjector.akv2k8s.svc:80/auth/com-att-amteco-dev/amtadminservice-2-0-6c5ff6c645-mf2sp?secret=akv2k8s-amtadminservice-2-0" status="403 Forbidden" statusCode=403 E0820 18:20:10.079481 1 main.go:261] "failed to get credentials" err="failed to validate credentials, got http status code 403" failedTimes=3

**We have enabled the Debug log to the Azure Key Vault, and we can tell that the secrets are being pulled (first log aaf-password) by the injector, but there is also an error in the same scope time that is detected by the injector webhook and is stopping the container.

{ "time": "2021-08-17T17:47:57.1235748Z", "category": "AuditEvent", "operationName": "SecretGet", "resultType": "Success", "correlationId": "0c7c4xxxxxxxxxxxxxx28bc", "callerIpAddress": "10.0.1.75", "identity": {"claim":{"oid":"9cf4b2a4-abb7-446d-a81e-8e2728f6da45","appid":"bcfxxxxxxxxxx1"}}, "properties": {"id":"https://easxxxxkv.vault.azure.net/secrets/aaf-password/xxxxxxx","clientInfo":"Go/go1.16.5 (amd64-linux) go-autorest/v14.2.1 Azure-SDK-For-Go/v55.3.0 keyvault/2016-10-01","subnetId":"(unknown)","privateEndpointId":"/subscriptions/7a85dc6f-83db-4c57-89ee-30a4b0375ef9/resourceGroups/amt-eastus2-nprd-infr-rg/providers/Microsoft.Network/privateEndpoints/privateendpointkeyvault","httpStatusCode":200,"requestUri":"https://eaxxxxxxxxkv.vault.azure.net/secrets/**aaf-password**/?api-version=2016-10-01","isAddressAuthorized":true,"addrAuthType":"PrivateConnection","isAccessPolicyMatch":true}, "resourceId": "/SUBSCRIPTIONS/7xxxxxxxxxx0375EF9/RESOURCEGROUPS/AMT-xxxxxxxxxx-RG/PROVIDERS/MICROSOFT.KEYVAULT/VAULTS/EAXXXXXXXXXXKV", "operationVersion": "2016-10-01", "resultSignature": "OK", "durationMs": "10"}

{ "time": "2021-08-17T17:47:10.9490993Z", "category": "AuditEvent", "operationName": "KeyUnwrap", "resultType": "Success", "resultDescription": "The user, group or application 'name=Microsoft.Storage/storageaccounts;appid=26xxxxxxxca;oid=e84xxxxxx-b006-defe4ec7f410;iss=https://sts.windows.net/e741d71c-c6b6-47b0-803c-0f3b32b07556/' does not have keys unwrapKey permission on key vault 'xeastus2-amt-nprdkv;location=eastus2'. For help resolving this issue, please see https://go.microsoft.com/fwlink/?linkid=2125287", "correlationId": "b2xxxxxxxxxxx7ca", "callerIpAddress": "52.xxxxxx128", "identity": {"claim":{"oid":"e8xxxxxxxxxx410","appid":"266xxxxxxxxxxxxxxx4ca","xms_mirid":"/subscriptions/7a8xxxxxxxxx0a4b0375ef9/resourcegroups/amtxxxxxxxr-rg/providers/Microsoft.Storage/storageAccounts/amteastus2nprdst"}}, "properties": {"id":"https://eastus2-amt-nprdkv.vault.azure.net/keys/amteastus2nprdst/a8f75a4e7d0241e5b058ae503dfabec4","clientInfo":"services_xstore_xfe_HTTP_proxy/1.0","httpStatusCode":403,"requestUri":"https://easxxxxxxxxdkv.vault.azure.net/keys/amteastus2nprdst/a8xxxxxxxxxxxbec4/unwrapkey?api-version=2016-10-01","isAddressAuthorized":false,"isAccessPolicyMatch":false,"trustedService":"Microsoft.Storage/storageaccounts"}, "resourceId": "/SUBSCRIPTIONS/7A8xxxxxxxxxxxxEF9/RESOURCEGROUPS/AMT-xxxxxxxxxxxxx-RG/PROVIDERS/MICROSOFT.KEYVAULT/VAULTS/ExxxxxxxxxxKV", "operationVersion": "2016-10-01", "resultSignature": "Forbidden", "durationMs": "24"}

We tried to --set env_injector.failurePolicy=Ignore to allow the container to continue despite the error, but that option is not being configured. We reported it as bug #235

Few more things that we have tried

Using a local secrets to access the ACR: imagePullSecrets:

env_injector.dockerImageInspection.useAksCredentialsWithACS=false

muwiess commented 2 years ago

Hi, we want to update the issue @kristeey We scanned with tcpdump the pod from the aks node, and we found that the issue was related to a proxy server being pulled when the injector was trying to validate the pod local credentials via:

GET http://akv2k8s-envinjector.akv2k8s.svc:80/auth/com-att-amteco-dev/amtadminservice-2-0-6bbb475756-x5gwl?secret=akv2k8s-amtadminservice-2-0 HTTP/1.1 Host: akv2k8s-envinjector.akv2k8s.svc:80 User-Agent: Go-http-client/1.1 Accept-Encoding: gzip

And since this is an F5 proxy, it was being blocked or 403 error:

.k.8..X.}...(.P..)J3..HTTP/1.0 403 Forbidden Server: BigIP Connection: Keep-Alive Content-Length: 113

Error Code: 402 -- F5-REJECT LinkID: XXXXXX, srcIP: 10.0.1.107 blocked to akv2k8s-envinjector.akv2k8s.svc .

This is because by the time that the docker container starts and the injector pass the parameters and tries to do the validation, apparently, the proxy server is already set and tried to be used to validate the http://akv2k8s-envinjector.akv2k8s.svc:80/auth/.

Fix, example to use the non proxy:

-Dhttp.nonProxyHosts="localhost|127.0.0.1|akv2k8s-envinjector.akv2k8s.svc" \ -Dhttps.nonProxyHosts="localhost|127.0.0.1|akv2k8s-envinjector.akv2k8s.svc" \

kristeey commented 2 years ago

Great job finding a solution to your problem @muwiess! @pb586b Does this help in your case?

pb586b commented 2 years ago

Great job finding a solution to your problem @muwiess! @pb586b Does this help in your case?

Yes, I was able to remove the proxy and receive the oauth token successfully. But now I'm having issue with getting the secrets.

Pod Logs:

2021-08-25T22:08:52.937389061Z I0825 22:08:52.937191 1 authentication.go:167] "successfully received oauth token" 2021-08-25T22:08:52.984580456Z E0825 22:08:52.984475 1 main.go:313] "failed to get azurekeyvaultsecret" err="Get \"https://172.66.0.1:443/apis/spv.no/v2beta1/namespaces/com-att-data360-dev/azurekeyvaultsecrets/ampmd-aaf-password-secret\": Forbidden" azurekeyvaultsecret="com-att-data360-dev/ampmd-aaf-password-secret" 2021-08-25T22:08:52.984616056Z I0825 22:08:52.984502 1 main.go:314] "will retry getting azurekeyvaultsecret" azurekeyvaultsecret="com-att-data360-dev/ampmd-aaf-password-secret" retryTimes=3 delay=3 2021-08-25T22:09:02.108966387Z E0825 22:09:02.107603 1 main.go:326] "error getting azurekeyvaultsecret" err="Get \"https://172.66.0.1:443/apis/spv.no/v2beta1/namespaces/com-att-data360-dev/azurekeyvaultsecrets/ampmd-aaf-password-secret\": Forbidden" azurekeyvaultsecret="com-att-data360-dev/ampmd-aaf-password-secret"