Ingress-nginx: Ingress controller created AFTER basic auth enabled results in 503

[Stono]

Hi,
I have a strange problem where if i scale the ingress controller:

kn scale --replicas=2 deployment/nginx-ingress-controller

I get:

❯ kn get pods
NAME                                        READY     STATUS    RESTARTS   AGE
default-http-backend-65d8d5bb9d-7glj9       1/1       Running   0          16h
nginx-ingress-controller-744c655575-6c2sv   1/1       Running   0          16h
nginx-ingress-controller-744c655575-hwz5z   1/1       Running   0          2m

but requests going to the scaled pod 503:

NGINX Ingress controller
  Release:    0.9.0
  Build:      git-6816630
  Repository: https://github.com/kubernetes/ingress-nginx
-------------------------------------------------------------------------------

I0109 09:28:12.231605       8 main.go:227] Creating API client for https://10.168.0.1:443
I0109 09:28:12.243944       8 main.go:239] Running in Kubernetes Cluster version v1.8+ (v1.8.5-gke.0) - git (clean) commit 2c2a807131fa8708abc92f3513fe167126c8cce5 - platform linux/amd64
I0109 09:28:12.247979       8 main.go:83] validated ingress-nginx/default-http-backend as the default backend
I0109 09:28:12.251520       8 main.go:104] service ingress-nginx/ingress-nginx validated as source of Ingress status
I0109 09:28:12.576477       8 stat_collector.go:77] starting new nginx stats collector for Ingress controller running in namespace  (class nginx)
I0109 09:28:12.576549       8 stat_collector.go:78] collector extracting information from port 18080
I0109 09:28:12.595358       8 nginx.go:250] starting Ingress controller
E0109 09:28:12.607240       8 annotations.go:144] error reading BasicDigestAuth annotation in Ingress default/elasticsearch-ingress: unexpected error reading secret default/basic-auth: secret default/basic-auth was not found
I0109 09:28:12.608087       8 event.go:218] Event(v1.ObjectReference{Kind:"Ingress", Namespace:"default", Name:"elasticsearch-ingress", UID:"62005b40-f482-11e7-8777-42010a9a00cd", APIVersion:"extensions", ResourceVersion:"68287", FieldPath:""}): type: 'Normal' reason: 'CREATE' Ingress default/elasticsearch-ingress
I0109 09:28:12.695866       8 nginx.go:255] running initial sync of secrets
I0109 09:28:12.697554       8 backend_ssl.go:64] adding secret default/ingress-tls to the local store
I0109 09:28:12.697656       8 nginx.go:288] starting NGINX process...
I0109 09:28:12.697790       8 leaderelection.go:174] attempting to acquire leader lease...
I0109 09:28:12.698967       8 controller.go:211] backend reload required
I0109 09:28:12.699146       8 stat_collector.go:34] changing prometheus collector from  to default
I0109 09:28:12.701563       8 status.go:196] new leader elected: nginx-ingress-controller-744c655575-nb2sj
I0109 09:28:12.814688       8 controller.go:220] ingress backend successfully reloaded...
I0109 09:28:13.348180       8 backend_ssl.go:160] updating local copy of ssl certificate default/ingress-tls with missing intermediate CA certs
I0109 09:28:15.910354       8 controller.go:211] backend reload required
I0109 09:28:16.124630       8 controller.go:220] ingress backend successfully reloaded...
I0109 09:28:46.531990       8 leaderelection.go:184] successfully acquired lease ingress-nginx/ingress-controller-leader-nginx
I0109 09:28:46.532006       8 status.go:196] new leader elected: nginx-ingress-controller-744c655575-hwz5z
193.243.130.243 - [193.243.130.243] - - [09/Jan/2018:09:29:09 +0000] "GET / HTTP/1.1" 503 213 "-" "curl/7.51.0" 92 0.000 [default-elasticsearch-client-9200] - - - -
193.243.130.243 - [193.243.130.243] - - [09/Jan/2018:09:29:10 +0000] "GET / HTTP/1.1" 503 213 "-" "curl/7.51.0" 92 0.000 [default-elasticsearch-client-9200] - - - -
193.243.130.243 - [193.243.130.243] - - [09/Jan/2018:09:29:10 +0000] "GET / HTTP/1.1" 503 213 "-" "curl/7.51.0" 92 0.000 [default-elasticsearch-client-9200] - - - -
193.243.130.243 - [193.243.130.243] - - [09/Jan/2018:09:29:11 +0000] "GET / HTTP/1.1" 503 213 "-" "curl/7.51.0" 92 0.000 [default-elasticsearch-client-9200] - - - -
193.243.130.243 - [193.243.130.243] - - [09/Jan/2018:09:29:12 +0000] "GET / HTTP/1.1" 503 213 "-" "curl/7.51.0" 92 0.000 [default-elasticsearch-client-9200] - - - -

requests that go to the other pod are fine:

193.243.130.243 - [193.243.130.243] - autotrader [09/Jan/2018:09:20:39 +0000] "GET /_cluster/state HTTP/2.0" 200 17766 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_12_4) AppleWebKit/537.36 (KHTML, like
Gecko) Chrome/63.0.3239.132 Safari/537.36" 27 0.028 [default-elasticsearch-client-9200] 10.167.4.7:9200 17766 0.028 200

[Stono]

I have managed to track this down, and feel it is a bug.

If i deleted all pods and brought them back up, none of them worked, and I was seeing this in the logs:

E0109 09:36:38.427166       7 queue.go:73] could not get key for object default/basic-auth: object has no meta: object does not implement the Object interfaces
E0109 09:37:33.784403       7 queue.go:73] could not get key for object default/basic-auth: object has no meta: object does not implement the Object interfaces

So i tried deleting and recreating the secret, but to no avail.

I noticed in the generated nginx config:

# Location denied. Reason: unexpected error reading secret default/basic-auth: secret default/basic-auth was not found
            return 503;

but it is 100% there. The next thing i did was take the basic auth annotations out of my ingress, and this worked fine, requests started going through.

So i added the annotations back in, and it started working fine (the secret was read fine).

This is consistent and reproducible after a scale. Any pods created after the ingress was created have this issue and the only way to fix it is to disable and re-enable auth on the ingress definition.

I hope these steps help you to debug the issue.

I am using quay.io/aledbf/nginx-ingress-controller:0.304

[Stono]

PS. This is a particularly big problem as when pods are re-scheduled, this error resurfaces. So I am unable to handle maintenance, cluster updates, or horizontal pod autoscaling.

[Stono]

This is further exacerbated by pod failing a liveness check, then coming back up and returning 503 until i disable, then re-enable basic auth on the ingress definition:

  Warning  Unhealthy              4m (x4 over 21m)  kubelet, gke-elastic-dev-custom-pool-0574e546-gh7d  Liveness probe failed: Get http://10.167.3.21:10254/healthz: net/http: request canceled (Client.Timeout exceeded while awaiting headers)
  Warning  Unhealthy              4m (x6 over 5m)   kubelet, gke-elastic-dev-custom-pool-0574e546-gh7d  Readiness probe failed: Get http://10.167.3.21:10254/healthz: net/http: request canceled (Client.Timeout exceeded while awaiting headers)

Same thing:

            # Location denied. Reason: unexpected error reading secret default/basic-auth: secret default/basic-auth was not found
            return 503;

❯ k get secrets
NAME                                     TYPE                                  DATA      AGE
basic-auth                               Opaque                                1         1h

[aledbf]

@Stono in case of any problems with security annotations (like not finding the secrets) we return error 503 in the configured ingress to avoid allowing unrestricted access to the resource.

[Stono]

@aledbf yes i am aware, but if you read through my post you see that the secret IS there, it has been there for over a day. Whenever a pod is restarted it fails to pickup this secret unless i disable and re-enable auth on the ingress

[aledbf]

@Stono please run kubectl get secret basic-auth -o yaml (removing the data section)
The secret contains the auth key in the data section?

[Stono]

apiVersion: v1
data:
  auth: omitted
kind: Secret
metadata:
  annotations:
    kubectl.kubernetes.io/last-applied-configuration: |
      {"apiVersion":"v1","data":{"auth":"omitted"},"kind":"Secret","metadata":{"annotations":{},"name":"basic-auth","namespace":"default"},"type":"Opaque"}
  creationTimestamp: 2018-01-09T09:38:54Z
  name: basic-auth
  namespace: default
  resourceVersion: "173667"
  selfLink: /api/v1/namespaces/default/secrets/basic-auth
  uid: e81f720f-f520-11e7-9178-42010a9a0047
type: Opaque

[Stono]

And here is the behaviour:

❯ curl https://my-site.com
<html>
<head><title>401 Authorization Required</title></head>
<body bgcolor="white">
<center><h1>401 Authorization Required</h1></center>
<hr><center>nginx/1.13.8</center>
</body>
</html>

If I delete the pod, and wait for it to recreate I see this in the logs:

E0109 11:48:17.826556       6 annotations.go:144] error reading BasicDigestAuth annotation in Ingress default/elasticsearch-ingress: unexpected error reading secret default/basic-auth: secret default/basic-auth was not found

And the site 503s:

❯ curl https://my-site.com
<html>
<head><title>503 Service Temporarily Unavailable</title></head>
<body bgcolor="white">
<center><h1>503 Service Temporarily Unavailable</h1></center>
<hr><center>nginx/1.13.8</center>
</body>
</html>

If i edit the ingress to remove basic auth:

❯ k edit ingress
ingress "elasticsearch-ingress" edited

It works:

❯ curl https://my-site.com
{
  "name" : "elasticsearch-master-1",
  "cluster_name" : "docker-cluster",
  "cluster_uuid" : "Ufi9iWaCThi0vvd68-2wrw",

If i re-enable auth:

❯ k edit ingress
ingress "elasticsearch-ingress" edited

Auth works as expected:

❯ curl https://my-site.com
<html>
<head><title>401 Authorization Required</title></head>
<body bgcolor="white">
<center><h1>401 Authorization Required</h1></center>

Therefore this problem is when the pod is create after the ingress is configured to use basic auth

[Stono]

Also confirmed this exists with quay.io/kubernetes-ingress-controller/nginx-ingress-controller:0.9.0

I am running Kubernetes 1.8.5 on GKE

[aledbf]

@Stono please test quay.io/aledbf/nginx-ingress-controller:0.305

Edit: and post the logs

[Stono]

That worked!

Here are the logs anyway:

NGINX Ingress controller
  Release:    0.9.0
  Build:      git-313fdd2d
  Repository: https://github.com/aledbf/ingress
-------------------------------------------------------------------------------

I0109 12:05:48.021937       8 main.go:227] Creating API client for https://10.168.0.1:443
I0109 12:05:48.033274       8 main.go:239] Running in Kubernetes Cluster version v1.8+ (v1.8.5-gke.0) - git (clean) commit 2c2a807131fa8708abc92f3513fe167126c8cce5 - platform linux/amd64
I0109 12:05:48.036824       8 main.go:83] validated ingress-nginx/default-http-backend as the default backend
I0109 12:05:48.048624       8 main.go:104] service ingress-nginx/ingress-nginx validated as source of Ingress status
I0109 12:05:49.172438       8 stat_collector.go:77] starting new nginx stats collector for Ingress controller running in namespace  (class nginx)
I0109 12:05:49.172528       8 stat_collector.go:78] collector extracting information from port 18080
I0109 12:05:49.195185       8 nginx.go:248] starting Ingress controller
E0109 12:05:49.204866       8 queue.go:73] could not get key for object kube-system/replicaset-controller-token-lzbzv: object has no meta: object does not implement the Object interfaces
E0109 12:05:49.204920       8 queue.go:73] could not get key for object default/renew-certificates-account-token-skcqp: object has no meta: object does not implement the Object interfaces
E0109 12:05:49.204934       8 queue.go:73] could not get key for object ingress-nginx/default-token-r2xxs: object has no meta: object does not implement the Object interfaces
E0109 12:05:49.204946       8 queue.go:73] could not get key for object kube-system/cronjob-controller-token-tstrv: object has no meta: object does not implement the Object interfaces
E0109 12:05:49.204957       8 queue.go:73] could not get key for object kube-system/endpoint-controller-token-7bmr6: object has no meta: object does not implement the Object interfaces
E0109 12:05:49.204967       8 queue.go:73] could not get key for object kube-system/job-controller-token-qczdt: object has no meta: object does not implement the Object interfaces
E0109 12:05:49.204997       8 queue.go:73] could not get key for object kube-system/namespace-controller-token-fcs56: object has no meta: object does not implement the Object interfaces
E0109 12:05:49.205020       8 queue.go:73] could not get key for object default/ingress-tls: object has no meta: object does not implement the Object interfaces
E0109 12:05:49.205039       8 queue.go:73] could not get key for object kube-system/generic-garbage-collector-token-pcwxr: object has no meta: object does not implement the Object interfaces
E0109 12:05:49.205059       8 queue.go:73] could not get key for object kube-system/kubernetes-dashboard-certs: object has no meta: object does not implement the Object interfaces
E0109 12:05:49.205080       8 queue.go:73] could not get key for object kube-system/replication-controller-token-zdtxk: object has no meta: object does not implement the Object interfaces
E0109 12:05:49.206066       8 queue.go:73] could not get key for object kube-system/statefulset-controller-token-fh259: object has no meta: object does not implement the Object interfaces
E0109 12:05:49.206136       8 queue.go:73] could not get key for object default/basic-auth: object has no meta: object does not implement the Object interfaces
E0109 12:05:49.206248       8 queue.go:73] could not get key for object kube-system/attachdetach-controller-token-962hp: object has no meta: object does not implement the Object interfaces
E0109 12:05:49.206278       8 queue.go:73] could not get key for object kube-system/disruption-controller-token-8m4hv: object has no meta: object does not implement the Object interfaces
E0109 12:05:49.206306       8 queue.go:73] could not get key for object kube-system/fluentd-gcp-token-k58sc: object has no meta: object does not implement the Object interfaces
E0109 12:05:49.206336       8 queue.go:73] could not get key for object kube-system/horizontal-pod-autoscaler-token-ljqsd: object has no meta: object does not implement the Object interfaces
E0109 12:05:49.206387       8 queue.go:73] could not get key for object kube-system/persistent-volume-binder-token-597kl: object has no meta: object does not implement the Object interfaces
E0109 12:05:49.206417       8 queue.go:73] could not get key for object default/default-token-c5c2z: object has no meta: object does not implement the Object interfaces
E0109 12:05:49.206445       8 queue.go:73] could not get key for object ingress-nginx/nginx-ingress-serviceaccount-token-vjmj7: object has no meta: object does not implement the Object interfaces
E0109 12:05:49.206475       8 queue.go:73] could not get key for object kube-system/daemon-set-controller-token-swfvq: object has no meta: object does not implement the Object interfaces
E0109 12:05:49.206503       8 queue.go:73] could not get key for object kube-system/event-exporter-sa-token-p56wz: object has no meta: object does not implement the Object interfaces
E0109 12:05:49.206534       8 queue.go:73] could not get key for object kube-system/service-account-controller-token-4fnbb: object has no meta: object does not implement the Object interfaces
E0109 12:05:49.206561       8 queue.go:73] could not get key for object kube-system/service-controller-token-2856h: object has no meta: object does not implement the Object interfaces
E0109 12:05:49.206590       8 queue.go:73] could not get key for object kube-public/default-token-xqt7f: object has no meta: object does not implement the Object interfaces
E0109 12:05:49.206620       8 queue.go:73] could not get key for object kube-system/default-token-v2sw4: object has no meta: object does not implement the Object interfaces
E0109 12:05:49.206687       8 queue.go:73] could not get key for object kube-system/node-controller-token-2w6xg: object has no meta: object does not implement the Object interfaces
E0109 12:05:49.206761       8 queue.go:73] could not get key for object kube-system/ttl-controller-token-hx849: object has no meta: object does not implement the Object interfaces
E0109 12:05:49.206791       8 queue.go:73] could not get key for object kube-system/certificate-controller-token-tl6h7: object has no meta: object does not implement the Object interfaces
E0109 12:05:49.206821       8 queue.go:73] could not get key for object kube-system/cloud-provider-token-lgbpp: object has no meta: object does not implement the Object interfaces
E0109 12:05:49.206851       8 queue.go:73] could not get key for object kube-system/deployment-controller-token-zfqtj: object has no meta: object does not implement the Object interfaces
E0109 12:05:49.206883       8 queue.go:73] could not get key for object kube-system/heapster-token-dstc9: object has no meta: object does not implement the Object interfaces
E0109 12:05:49.206914       8 queue.go:73] could not get key for object kube-system/kube-dns-autoscaler-token-fcq28: object has no meta: object does not implement the Object interfaces
E0109 12:05:49.206945       8 queue.go:73] could not get key for object kube-system/kube-dns-token-v8zbd: object has no meta: object does not implement the Object interfaces
E0109 12:05:49.206974       8 queue.go:73] could not get key for object kube-system/tiller-token-2xcwh: object has no meta: object does not implement the Object interfaces
E0109 12:05:49.207000       8 queue.go:73] could not get key for object kube-system/kubernetes-dashboard-key-holder: object has no meta: object does not implement the Object interfaces
E0109 12:05:49.207028       8 queue.go:73] could not get key for object kube-system/kubernetes-dashboard-token-k5xcv: object has no meta: object does not implement the Object interfaces
E0109 12:05:49.207057       8 queue.go:73] could not get key for object kube-system/pod-garbage-collector-token-8j8qz: object has no meta: object does not implement the Object interfaces
E0109 12:05:49.207085       8 queue.go:73] could not get key for object kube-system/resourcequota-controller-token-zpxcj: object has no meta: object does not implement the Object interfaces
I0109 12:05:50.283626       8 event.go:218] Event(v1.ObjectReference{Kind:"Ingress", Namespace:"default", Name:"elasticsearch-ingress", UID:"62005b40-f482-11e7-8777-42010a9a00cd", APIVersion:"extensions", ResourceVersion:"196825", FieldPath:""}): type: 'Normal' reason: 'CREATE' Ingress default/elasticsearch-ingress
I0109 12:05:51.396004       8 nginx.go:253] running initial sync of secrets
I0109 12:05:51.397465       8 backend_ssl.go:64] adding secret default/ingress-tls to the local store
I0109 12:05:51.397586       8 nginx.go:286] starting NGINX process...
I0109 12:05:51.397977       8 leaderelection.go:174] attempting to acquire leader lease...
I0109 12:05:51.399618       8 controller.go:203] backend reload required
I0109 12:05:51.399993       8 stat_collector.go:34] changing prometheus collector from  to default
I0109 12:05:51.412700       8 status.go:189] new leader elected: nginx-ingress-controller-5967554cbc-67mjz
I0109 12:05:52.246815       8 controller.go:212] ingress backend successfully reloaded...
I0109 12:05:52.283435       8 backend_ssl.go:160] updating local copy of ssl certificate default/ingress-tls with missing intermediate CA certs
I0109 12:05:52.506297       8 controller.go:203] backend reload required
I0109 12:05:53.242357       8 controller.go:212] ingress backend successfully reloaded...

[discostur]

@aledbf seeing this issue again with nginx ingress 0.17.1 - could it be that this bug is back again?
Always getting HTTP Error Code 503 with Basic Authentication Enabled (TLS enabled).

[unfor19]

For me the issue was - I've created the basic-auth key in the 'default' namespace, and my service was in another namespace, so it couldn't fetch the basic-auth key.
I had to create a key in my new namespace, and then it worked like a charm

[dvdblk]

Also make sure that the htpasswd auth file is actually named auth.

It's important the file generated is named auth (actually - that the secret has a key data.auth), otherwise the ingress-controller returns a 503.