Default-backend is ignored by canary ingress #9944

dfl-aeb · 2023-05-10T14:40:37Z

We are using a custom auth and a custom default-backend for authenticating our frontend apps:

apiVersion: networking.k8s.io/v1
kind: Ingress
metadata:
 annotations:
  nginx.ingress.kubernetes.io/auth-url: 'https://auth-service.local/auth/nginx-auth'
  nginx.ingress.kubernetes.io/custom-http-errors: '401,403'
  nginx.ingress.kubernetes.io/default-backend: default-backend
 name: frontend-app-ingress
spec:
  ingressClassName: nginx
  rules:
    - host: frontend.local
      http:
        paths:
          - backend:
              service:
                name: frontend-svc
                port:
                  number: 80
            path: /frontend 
            pathType: Prefix

The auth responds with a 401 if the user is not authenticated, which is caught by the custom-http-errors: 401,403 annotation and forwarded to the default-backend. There, the redirect to our keycloak is initiated. Once authenticated, the nginx receives a 200 response and forwards to the frontend app.

What happened:
Unfortunately, this no longer works when we want to access the app via a canary ingress. The user is forwarded directly to the frontend app without having to authenticate. The auth is contacted and responds with a 401, but the redirect to the default backend does not happen; instead, it goes directly to the frontend app.

Canary Ingress config:

apiVersion: networking.k8s.io/v1
kind: Ingress
metadata:
 annotations:
    nginx.ingress.kubernetes.io/affinity: cookie
    nginx.ingress.kubernetes.io/affinity-canary-behavior: sticky
    nginx.ingress.kubernetes.io/canary: 'true'
    nginx.ingress.kubernetes.io/canary-by-cookie: canary-cookie
    nginx.ingress.kubernetes.io/canary-weight: '40'
 name: frontend-app-ingress-canary
spec:
  ingressClassName: nginx
  rules:
    - host: frontend.local
      http:
        paths:
          - backend:
              service:
                name: frontend-svc-canary
                port:
                  number: 80
            path: /frontend 
            pathType: Prefix

What you expected to happen:

I expect the ingress to behave the same as when not using a Canary: That the redirect to the default backend is initiated correctly.

I suspect a bug in the Lua balancer. In the logs, you can see that the Nginx sees the 401 from the auth and also wants to initiate a redirect to the default-backend, but then takes the wrong IP and forwards to the frontend app instead. More on this below in the ingress logs.

NGINX Ingress controller
Release: v1.7.0
Build: 72ff21e
Repository: https://github.com/kubernetes/ingress-nginx
nginx version: nginx/1.21.6

Kubernetes version (use kubectl version):
Client Version: v1.27.1
Kustomize Version: v5.0.1
Server Version: v1.26.3

Anything else we need to know:

Ingress logs:

super-long log

// 401 from auth
2023/05/10 12:03:55 [debug] 439#439: *14844 http proxy status 401 "401 Unauthorized"
2023/05/10 12:03:55 [debug] 439#439: *14844 http proxy header: "X-Powered-By: Express"
2023/05/10 12:03:55 [debug] 439#439: *14844 http proxy header: "keep-alive: timeout=45"
2023/05/10 12:03:55 [debug] 439#439: *14844 http proxy header: "Content-Type: text/plain; charset=utf-8"
2023/05/10 12:03:55 [debug] 439#439: *14844 http proxy header: "Content-Length: 12"
2023/05/10 12:03:55 [debug] 439#439: *14844 http proxy header: "Date: Wed, 10 May 2023 12:03:55 GMT"
2023/05/10 12:03:55 [debug] 439#439: *14844 http proxy header: "Connection: close"
2023/05/10 12:03:55 [debug] 439#439: *14844 http proxy header done
2023/05/10 12:03:55 [debug] 439#439: *14844 lua header filter for user lua code, uri "/_external-auth-L2RmbC10ZXN0-Exact"
2023/05/10 12:03:55 [debug] 439#439: *14844 lua capture header filter, uri "/_external-auth-L2RmbC10ZXN0-Exact"
2023/05/10 12:03:55 [debug] 439#439: *14844 headers more header filter, uri "/_external-auth-L2RmbC10ZXN0-Exact"
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 header filter
2023/05/10 12:03:55 [debug] 439#439: *14844 finalize http upstream request: 0
2023/05/10 12:03:55 [debug] 439#439: *14844 finalize http proxy request
2023/05/10 12:03:55 [debug] 439#439: *14844 free rr peer 1 0
2023/05/10 12:03:55 [debug] 439#439: *14844 close http upstream connection: 24
2023/05/10 12:03:55 [debug] 439#439: *14844 free: 00007F8391F43640, unused: 48
2023/05/10 12:03:55 [debug] 439#439: *14844 event timer del: 24: 17417944
2023/05/10 12:03:55 [debug] 439#439: *14844 reusable connection: 0
2023/05/10 12:03:55 [debug] 439#439: *14844 http finalize request: 0, "/_external-auth-L2RmbC10ZXN0-Exact?" a:1, c:2
2023/05/10 12:03:55 [debug] 439#439: *14844 auth request done s:401
2023/05/10 12:03:55 [debug] 439#439: *14844 lua log handler, uri:"/_external-auth-L2RmbC10ZXN0-Exact" c:2
2023/05/10 12:03:55 [debug] 439#439: *14844 http log handler
2023/05/10 12:03:55 [debug] 439#439: *14844 http wake parent request: "/dfl-test?"
2023/05/10 12:03:55 [debug] 439#439: *14844 http posted request: "/dfl-test?"
2023/05/10 12:03:55 [debug] 439#439: *14844 access phase: 11
2023/05/10 12:03:55 [debug] 439#439: *14844 auth request handler
2023/05/10 12:03:55 [debug] 439#439: *14844 auth request set variables
2023/05/10 12:03:55 [debug] 439#439: *14844 http finalize request: 401, "/dfl-test?" a:1, c:1
2023/05/10 12:03:55 [debug] 439#439: *14844 http special response: 401, "/dfl-test?"

// default backend is used as location
2023/05/10 12:03:55 [debug] 439#439: *14844 test location: "@custom_custom-default-backend-dfl-test-rollout-dfl-test-rollout-genc-auth-default-backend_400"
2023/05/10 12:03:55 [debug] 439#439: *14844 test location: "@custom_custom-default-backend-dfl-test-rollout-dfl-test-rollout-genc-auth-default-backend_401"
2023/05/10 12:03:55 [debug] 439#439: *14844 using location: @custom_custom-default-backend-dfl-test-rollout-dfl-test-rollout-genc-auth-default-backend_401 "/dfl-test?"
2023/05/10 12:03:55 [debug] 439#439: *14844 rewrite phase: 3
2023/05/10 12:03:55 [debug] 439#439: *14844 http script value: "custom-default-backend-dfl-test-rollout-dfl-test-rollout-genc-auth-default-backend"
2023/05/10 12:03:55 [debug] 439#439: *14844 http script set $proxy_upstream_name
2023/05/10 12:03:55 [debug] 439#439: 14844 http script regex: "(.)"
2023/05/10 12:03:55 [notice] 439#439: 14844 "(.)" matches "/dfl-test" while sending to client, client: 192.168.49.1, server: k8s.local, request: "GET /dfl-test HTTP/2.0", host: "k8s.local"
2023/05/10 12:03:55 [debug] 439#439: *14844 http script copy: "/"
2023/05/10 12:03:55 [debug] 439#439: *14844 http script regex end
2023/05/10 12:03:55 [notice] 439#439: *14844 rewritten data: "/", args: "" while sending to client, client: 192.168.49.1, server: k8s.local, request: "GET /dfl-test HTTP/2.0", host: "k8s.local"
2023/05/10 12:03:55 [debug] 439#439: *14844 rewrite phase: 4
2023/05/10 12:03:55 [debug] 439#439: *14844 lua rewrite handler, uri:"/" c:2
2023/05/10 12:03:55 [debug] 439#439: *14844 post rewrite phase: 5
2023/05/10 12:03:55 [debug] 439#439: *14844 generic phase: 6
2023/05/10 12:03:55 [debug] 439#439: *14844 generic phase: 7
2023/05/10 12:03:55 [debug] 439#439: *14844 generic phase: 8
2023/05/10 12:03:55 [debug] 439#439: *14844 access phase: 9
2023/05/10 12:03:55 [debug] 439#439: *14844 access phase: 10
2023/05/10 12:03:55 [debug] 439#439: *14844 access phase: 11
2023/05/10 12:03:55 [debug] 439#439: *14844 post access phase: 12
2023/05/10 12:03:55 [debug] 439#439: *14844 generic phase: 13
2023/05/10 12:03:55 [debug] 439#439: *14844 generic phase: 14
2023/05/10 12:03:55 [debug] 439#439: *14844 posix_memalign: 00007F839132B4C0:4096 @16
2023/05/10 12:03:55 [debug] 439#439: *14844 http init upstream, client timer: 0
2023/05/10 12:03:55 [debug] 439#439: *14844 post event 00007F8391F3B818
2023/05/10 12:03:55 [debug] 439#439: *14844 http script copy: "X-Code"
2023/05/10 12:03:55 [debug] 439#439: *14844 http script copy: "401"
2023/05/10 12:03:55 [debug] 439#439: 14844 http script copy: "X-Format"
2023/05/10 12:03:55 [debug] 439#439: 14844 http script var: "text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,image/apng,/;q=0.8,application/signed-exchange;v=b3;q=0.7"
2023/05/10 12:03:55 [debug] 439#439: *14844 http script copy: "X-Original-URI"
2023/05/10 12:03:55 [debug] 439#439: *14844 http script var: "/dfl-test"
2023/05/10 12:03:55 [debug] 439#439: *14844 http script copy: "X-Namespace"
2023/05/10 12:03:55 [debug] 439#439: *14844 http script var: "dfl-test-rollout"
2023/05/10 12:03:55 [debug] 439#439: *14844 http script copy: "X-Ingress-Name"
2023/05/10 12:03:55 [debug] 439#439: *14844 http script var: "dfl-test-rollout"
2023/05/10 12:03:55 [debug] 439#439: *14844 http script copy: "X-Service-Name"
2023/05/10 12:03:55 [debug] 439#439: *14844 http script var: "dfl-test-rollout"
2023/05/10 12:03:55 [debug] 439#439: *14844 http script copy: "X-Service-Port"
2023/05/10 12:03:55 [debug] 439#439: *14844 http script var: "80"
2023/05/10 12:03:55 [debug] 439#439: *14844 http script copy: "X-Request-ID"
2023/05/10 12:03:55 [debug] 439#439: *14844 http script var: "88cdec987d3f62aaa7b27b178aadd2e6"
2023/05/10 12:03:55 [debug] 439#439: *14844 http script copy: "X-Forwarded-For"
2023/05/10 12:03:55 [debug] 439#439: *14844 http script var: "192.168.49.1"
2023/05/10 12:03:55 [debug] 439#439: *14844 http script copy: "Host"
2023/05/10 12:03:55 [debug] 439#439: *14844 http script var: "k8s.local"
2023/05/10 12:03:55 [debug] 439#439: *14844 http script copy: "Connection"
2023/05/10 12:03:55 [debug] 439#439: *14844 http script copy: "close"
2023/05/10 12:03:55 [debug] 439#439: *14844 http script copy: ""
2023/05/10 12:03:55 [debug] 439#439: *14844 http script copy: ""
2023/05/10 12:03:55 [debug] 439#439: *14844 http proxy header: "cache-control: max-age=0"
2023/05/10 12:03:55 [debug] 439#439: *14844 http proxy header: "sec-ch-ua: "Google Chrome";v="113", "Chromium";v="113", "Not-A.Brand";v="24""
2023/05/10 12:03:55 [debug] 439#439: *14844 http proxy header: "sec-ch-ua-mobile: ?0"
2023/05/10 12:03:55 [debug] 439#439: *14844 http proxy header: "sec-ch-ua-platform: "Linux""
2023/05/10 12:03:55 [debug] 439#439: *14844 http proxy header: "upgrade-insecure-requests: 1"
2023/05/10 12:03:55 [debug] 439#439: 14844 http proxy header: "user-agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
2023/05/10 12:03:55 [debug] 439#439: 14844 http proxy header: "accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,image/apng,/;q=0.8,application/signed-exchange;v=b3;q=0.7"
2023/05/10 12:03:55 [debug] 439#439: *14844 http proxy header: "sec-fetch-site: cross-site"
2023/05/10 12:03:55 [debug] 439#439: *14844 http proxy header: "sec-fetch-mode: navigate"
2023/05/10 12:03:55 [debug] 439#439: *14844 http proxy header: "sec-fetch-user: ?1"
2023/05/10 12:03:55 [debug] 439#439: 14844 http proxy header: "sec-fetch-dest: document"
2023/05/10 12:03:55 [debug] 439#439: 14844 http proxy header: "accept-encoding: gzip, deflate, br"
2023/05/10 12:03:55 [debug] 439#439: 14844 http proxy header: "accept-language: en-US,en;q=0.9"
2023/05/10 12:03:55 [debug] 439#439: 14844 http proxy header:
"GET / HTTP/1.0
X-Code: 401
X-Format: text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,image/apng,/;q=0.8,application/signed-exchange;v=b3;q=0.7
X-Original-URI: /dfl-test
X-Namespace: dfl-test-rollout
X-Ingress-Name: dfl-test-rollout
X-Service-Name: dfl-test-rollout
X-Service-Port: 80
X-Request-ID: 88cdec987d3f62aaa7b27b178aadd2e6
X-Forwarded-For: 192.168.49.1
Host: k8s.local
Connection: close
cache-control: max-age=0
sec-ch-ua: "Google Chrome";v="113", "Chromium";v="113", "Not-A.Brand";v="24"
sec-ch-ua-mobile: ?0
sec-ch-ua-platform: "Linux"
upgrade-insecure-requests: 1
user-agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36
accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,image/apng,/;q=0.8,application/signed-exchange;v=b3;q=0.7
sec-fetch-site: cross-site
sec-fetch-mode: navigate
sec-fetch-user: ?1
sec-fetch-dest: document
accept-encoding: gzip, deflate, br
accept-language: en-US,en;q=0.9

"
2023/05/10 12:03:55 [debug] 439#439: *14844 http cleanup add: 00007F8391F22910
2023/05/10 12:03:55 [debug] 439#439: *14844 init keepalive peer
2023/05/10 12:03:55 [debug] 439#439: *14844 get keepalive peer
2023/05/10 12:03:55 [debug] 439#439: *14844 lua balancer peer, tries: 1
2023/05/10 12:03:55 [debug] 439#439: *14844 code cache lookup (key='balancer_by_lua_nhli_0f29762dfd828b8baa4d895affbc4b90', ref=-1)
2023/05/10 12:03:55 [debug] 439#439: *14844 code cache miss (key='balancer_by_lua_nhli_0f29762dfd828b8baa4d895affbc4b90', ref=-1)
2023/05/10 12:03:55 [debug] 439#439: *14844 add cleanup: 00007F839132C1C0
2023/05/10 12:03:55 [debug] 439#439: *14844 stream socket 24
2023/05/10 12:03:55 [debug] 439#439: *14844 epoll add connection: fd:24 ev:80002005

// wrong IP is used 10.244.0.202:80 is frontend-app --> default-backend has 10.244.0.203:8080
2023/05/10 12:03:55 [debug] 439#439: *14844 connect to 10.244.0.202:80, fd:24 #14847
2023/05/10 12:03:55 [debug] 439#439: *14844 http upstream connect: -2
2023/05/10 12:03:55 [debug] 439#439: *14844 posix_memalign: 00007F8391F436D0:128 @16
2023/05/10 12:03:55 [debug] 439#439: *14844 event timer add: 24: 60000:17417948
2023/05/10 12:03:55 [debug] 439#439: *14844 http finalize request: -4, "/?" a:1, c:3
2023/05/10 12:03:55 [debug] 439#439: *14844 http request count:3 blk:0
2023/05/10 12:03:55 [debug] 439#439: *14844 http finalize request: -4, "/?" a:1, c:2
2023/05/10 12:03:55 [debug] 439#439: *14844 http request count:2 blk:0
2023/05/10 12:03:55 [debug] 439#439: *14844 delete posted event 00007F8391F3B818
2023/05/10 12:03:55 [debug] 439#439: *14844 http run request: "/?"
2023/05/10 12:03:55 [debug] 439#439: *14844 http upstream check client, write event:0, "/"
2023/05/10 12:03:55 [debug] 439#439: *14844 http upstream request: "/?"
2023/05/10 12:03:55 [debug] 439#439: *14844 http upstream send request handler
2023/05/10 12:03:55 [debug] 439#439: *14844 http upstream send request
2023/05/10 12:03:55 [debug] 439#439: *14844 http upstream send request body
2023/05/10 12:03:55 [debug] 439#439: *14844 chain writer buf fl:1 s:1053
2023/05/10 12:03:55 [debug] 439#439: *14844 chain writer in: 00007F839132C388
2023/05/10 12:03:55 [debug] 439#439: *14844 writev: 1053 of 1053
2023/05/10 12:03:55 [debug] 439#439: *14844 chain writer out: 0000000000000000
2023/05/10 12:03:55 [debug] 439#439: *14844 event timer del: 24: 17417948
2023/05/10 12:03:55 [debug] 439#439: *14844 event timer add: 24: 60000:17417949
2023/05/10 12:03:55 [debug] 439#439: *14844 http upstream request: "/?"
2023/05/10 12:03:55 [debug] 439#439: *14844 http upstream process header
2023/05/10 12:03:55 [debug] 439#439: *14844 malloc: 00007F839132C700:4096
2023/05/10 12:03:55 [debug] 439#439: *14844 posix_memalign: 00007F839132D940:4096 @16
2023/05/10 12:03:55 [debug] 439#439: *14844 recv: eof:0, avail:-1
2023/05/10 12:03:55 [debug] 439#439: *14844 recv: fd:24 4096 of 4096
2023/05/10 12:03:55 [debug] 439#439: *14844 recv: avail:1136

// frontend app answers with 200 --> ingress allows request
2023/05/10 12:03:55 [debug] 439#439: *14844 http proxy status 200 "200 OK"
2023/05/10 12:03:55 [debug] 439#439: *14844 http proxy header: "Content-Type: application/json; charset=utf-8"
2023/05/10 12:03:55 [debug] 439#439: *14844 http proxy header: "Content-Length: 5044"
2023/05/10 12:03:55 [debug] 439#439: *14844 http proxy header: "ETag: W/"13b4-rrbiVhQemUm4Lbq3t9apWuQP8VI""
2023/05/10 12:03:55 [debug] 439#439: *14844 http proxy header: "Date: Wed, 10 May 2023 12:03:55 GMT"
2023/05/10 12:03:55 [debug] 439#439: *14844 http proxy header: "Connection: close"
2023/05/10 12:03:55 [debug] 439#439: *14844 http proxy header done
2023/05/10 12:03:55 [debug] 439#439: *14844 lua header filter for user lua code, uri "/"
2023/05/10 12:03:55 [debug] 439#439: *14844 lua capture header filter, uri "/"
2023/05/10 12:03:55 [debug] 439#439: *14844 headers more header filter, uri "/"
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 header filter
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 table size update: 0
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 output header: ":status: 200"
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 output header: "date: Wed, 10 May 2023 12:03:55 GMT"
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 output header: "content-type: application/json; charset=utf-8"
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 output header: "content-length: 5044"
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 output header: "set-cookie: aeb-session-canary-cookie=c49d0451adae533f47effb6e25f7f405|2d317eda5e10ca3b2ce38818c7741bd9; Path=/dfl-test; Secure; HttpOnly"
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 output header: "etag: W/"13b4-rrbiVhQemUm4Lbq3t9apWuQP8VI""
2023/05/10 12:03:55 [debug] 439#439: *14844 http2:1 create HEADERS frame 00007F839132DCA8: len:191 fin:0
2023/05/10 12:03:55 [debug] 439#439: *14844 http cleanup add: 00007F839132DDA0
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 frame out: 00007F839132DCA8 sid:1 bl:1 len:191
2023/05/10 12:03:55 [debug] 439#439: *14844 SSL buf copy: 9
2023/05/10 12:03:55 [debug] 439#439: *14844 SSL buf copy: 191
2023/05/10 12:03:55 [debug] 439#439: *14844 http2:1 HEADERS frame 00007F839132DCA8 was sent
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 frame sent: 00007F839132DCA8 sid:1 bl:1 len:191
2023/05/10 12:03:55 [debug] 439#439: *14844 http cacheable: 0
2023/05/10 12:03:55 [debug] 439#439: *14844 http proxy filter init s:200 h:0 c:0 l:5044
2023/05/10 12:03:55 [debug] 439#439: *14844 http upstream process upstream
2023/05/10 12:03:55 [debug] 439#439: *14844 pipe read upstream: 1
2023/05/10 12:03:55 [debug] 439#439: *14844 pipe preread: 3908
2023/05/10 12:03:55 [debug] 439#439: *14844 input buf #0
2023/05/10 12:03:55 [debug] 439#439: *14844 malloc: 00007F8391323050:4096
2023/05/10 12:03:55 [debug] 439#439: *14844 readv: eof:0, avail:1136
2023/05/10 12:03:55 [debug] 439#439: *14844 readv: 1, last:4096
2023/05/10 12:03:55 [debug] 439#439: *14844 readv: avail:0
2023/05/10 12:03:55 [debug] 439#439: *14844 pipe recv chain: 1136
2023/05/10 12:03:55 [debug] 439#439: *14844 pipe buf in s:1 t:1 f:0 00007F839132C700, pos 00007F839132C7BC, size: 3908 file: 0, size: 0
2023/05/10 12:03:55 [debug] 439#439: *14844 pipe buf free s:0 t:1 f:0 00007F8391323050, pos 00007F8391323050, size: 1136 file: 0, size: 0
2023/05/10 12:03:55 [debug] 439#439: *14844 pipe length: 1136
2023/05/10 12:03:55 [debug] 439#439: *14844 input buf #1
2023/05/10 12:03:55 [debug] 439#439: *14844 pipe write downstream: 1
2023/05/10 12:03:55 [debug] 439#439: *14844 pipe write downstream flush in
2023/05/10 12:03:55 [debug] 439#439: *14844 http output filter "/?"
2023/05/10 12:03:55 [debug] 439#439: *14844 http copy filter: "/?"
2023/05/10 12:03:55 [debug] 439#439: *14844 lua body filter for user lua code, uri "/"
2023/05/10 12:03:55 [debug] 439#439: *14844 lua capture body filter, uri "/"
2023/05/10 12:03:55 [debug] 439#439: *14844 http postpone filter "/?" 00007F839132DED0
2023/05/10 12:03:55 [debug] 439#439: *14844 write new buf t:1 f:0 00007F839132C700, pos 00007F839132C7BC, size: 3908 file: 0, size: 0
2023/05/10 12:03:55 [debug] 439#439: *14844 write new buf t:1 f:0 00007F8391323050, pos 00007F8391323050, size: 1136 file: 0, size: 0
2023/05/10 12:03:55 [debug] 439#439: *14844 http write filter: l:0 f:0 s:5044
2023/05/10 12:03:55 [debug] 439#439: *14844 http write filter limit 2097152
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 send chain: 00007F839132E090
2023/05/10 12:03:55 [debug] 439#439: *14844 http2:1 windows: conn:15728640 stream:6291456
2023/05/10 12:03:55 [debug] 439#439: *14844 http2:1 create DATA frame 00007F839132DCA8: len:5044 flags:0
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 frame out: 00007F839132DCA8 sid:1 bl:0 len:5044
2023/05/10 12:03:55 [debug] 439#439: *14844 SSL buf copy: 9
2023/05/10 12:03:55 [debug] 439#439: *14844 SSL buf copy: 3887
2023/05/10 12:03:55 [debug] 439#439: *14844 SSL to write: 4096
2023/05/10 12:03:55 [debug] 439#439: *14844 SSL_write: 4096
2023/05/10 12:03:55 [debug] 439#439: *14844 SSL buf copy: 21
2023/05/10 12:03:55 [debug] 439#439: *14844 SSL buf copy: 1136
2023/05/10 12:03:55 [debug] 439#439: *14844 SSL to write: 1157
2023/05/10 12:03:55 [debug] 439#439: *14844 SSL_write: 1157
2023/05/10 12:03:55 [debug] 439#439: *14844 http2:1 DATA frame 00007F839132DCA8 was sent
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 frame sent: 00007F839132DCA8 sid:1 bl:0 len:5044
2023/05/10 12:03:55 [debug] 439#439: *14844 http write filter 0000000000000000
2023/05/10 12:03:55 [debug] 439#439: *14844 http copy filter: 0 "/?"
2023/05/10 12:03:55 [debug] 439#439: *14844 pipe write downstream done
2023/05/10 12:03:55 [debug] 439#439: *14844 event timer: 24, old: 17417949, new: 17417974
2023/05/10 12:03:55 [debug] 439#439: *14844 http upstream exit: 0000000000000000
2023/05/10 12:03:55 [debug] 439#439: *14844 finalize http upstream request: 0
2023/05/10 12:03:55 [debug] 439#439: *14844 finalize http proxy request
2023/05/10 12:03:55 [debug] 439#439: *14844 free keepalive peer
2023/05/10 12:03:55 [debug] 439#439: *14844 lua balancer free peer, tries: 2
2023/05/10 12:03:55 [debug] 439#439: *14844 close http upstream connection: 24
2023/05/10 12:03:55 [debug] 439#439: *14844 free: 00007F8391F436D0, unused: 48
2023/05/10 12:03:55 [debug] 439#439: *14844 event timer del: 24: 17417949
2023/05/10 12:03:55 [debug] 439#439: *14844 reusable connection: 0
2023/05/10 12:03:55 [debug] 439#439: *14844 http upstream temp fd: -1
2023/05/10 12:03:55 [debug] 439#439: *14844 http output filter "/?"
2023/05/10 12:03:55 [debug] 439#439: *14844 http copy filter: "/?"
2023/05/10 12:03:55 [debug] 439#439: *14844 lua body filter for user lua code, uri "/"
2023/05/10 12:03:55 [debug] 439#439: *14844 lua capture body filter, uri "/"
2023/05/10 12:03:55 [debug] 439#439: *14844 http postpone filter "/?" 00007FFEA59782E0
2023/05/10 12:03:55 [debug] 439#439: *14844 write new buf t:0 f:0 0000000000000000, pos 0000000000000000, size: 0 file: 0, size: 0
2023/05/10 12:03:55 [debug] 439#439: *14844 http write filter: l:1 f:0 s:0
2023/05/10 12:03:55 [debug] 439#439: *14844 http write filter limit 2097152
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 send chain: 00007F839132E080
2023/05/10 12:03:55 [debug] 439#439: *14844 http2:1 create DATA frame 00007F839132DCA8: len:0 flags:1
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 frame out: 00007F839132DCA8 sid:1 bl:0 len:0
2023/05/10 12:03:55 [debug] 439#439: *14844 SSL buf copy: 9
2023/05/10 12:03:55 [debug] 439#439: *14844 SSL to write: 9
2023/05/10 12:03:55 [debug] 439#439: *14844 SSL_write: 9
2023/05/10 12:03:55 [debug] 439#439: *14844 http2:1 DATA frame 00007F839132DCA8 was sent
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 frame sent: 00007F839132DCA8 sid:1 bl:0 len:0
2023/05/10 12:03:55 [debug] 439#439: *14844 http write filter 0000000000000000
2023/05/10 12:03:55 [debug] 439#439: *14844 http copy filter: 0 "/?"
2023/05/10 12:03:55 [debug] 439#439: *14844 http finalize request: 0, "/?" a:1, c:1
2023/05/10 12:03:55 [debug] 439#439: *14844 http request count:1 blk:0
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 close stream 1, queued 0, processing 1, pushing 0
2023/05/10 12:03:55 [debug] 439#439: *14844 http close request
2023/05/10 12:03:55 [debug] 439#439: *14844 lua request cleanup: forcible=0
2023/05/10 12:03:55 [debug] 439#439: *14844 http lua finalize threads
2023/05/10 12:03:55 [debug] 439#439: *14844 lua log handler, uri:"/" c:0
2023/05/10 12:03:55 [debug] 439#439: *14844 code cache lookup (key='log_by_lua_nhli_fba95f808109be0fde8b412423184753', ref=-1)
2023/05/10 12:03:55 [debug] 439#439: *14844 code cache miss (key='log_by_lua_nhli_fba95f808109be0fde8b412423184753', ref=-1)
192.168.49.1 - - [10/May/2023:12:03:55 +0000] "GET /dfl-test HTTP/2.0" 200 5044 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36" 440 0.032 [custom-default-backend-dfl-test-rollout-dfl-test-rollout-genc-auth-default-backend] [dfl-test-rollout-dfl-test-rollout-canary-80] 10.244.0.202:80 5044 0.026 200 88cdec987d3f62aaa7b27b178aadd2e6
2023/05/10 12:03:55 [debug] 439#439: *14844 http log handler
2023/05/10 12:03:55 [debug] 439#439: *14844 http map started
2023/05/10 12:03:55 [debug] 439#439: *14844 http script var: "/dfl-test"
2023/05/10 12:03:55 [debug] 439#439: *14844 http map: "/dfl-test" "1"
2023/05/10 12:03:55 [debug] 439#439: *14844 http script var: "1"
2023/05/10 12:03:55 [debug] 439#439: *14844 run cleanup: 00007F839132C1C0
2023/05/10 12:03:55 [debug] 439#439: *14844 run cleanup: 00007F8391F39DB0
2023/05/10 12:03:55 [debug] 439#439: *14844 free: 00007F8391323050
2023/05/10 12:03:55 [debug] 439#439: *14844 free: 00007F839132C700
2023/05/10 12:03:55 [debug] 439#439: *14844 free: 00007F839132A280
2023/05/10 12:03:55 [debug] 439#439: *14844 free: 00007F8391F3C700, unused: 0
2023/05/10 12:03:55 [debug] 439#439: *14844 free: 00007F8391F39140, unused: 0
2023/05/10 12:03:55 [debug] 439#439: *14844 free: 00007F8391F206F0, unused: 0
2023/05/10 12:03:55 [debug] 439#439: *14844 free: 00007F8391F21930, unused: 0
2023/05/10 12:03:55 [debug] 439#439: *14844 free: 00007F839132B4C0, unused: 2
2023/05/10 12:03:55 [debug] 439#439: *14844 free: 00007F839132D940, unused: 1237
2023/05/10 12:03:55 [debug] 439#439: *14844 free: 00007F838B18E490, unused: 296
2023/05/10 12:03:55 [debug] 439#439: *14844 post event 00007F83919517E0
2023/05/10 12:03:55 [debug] 439#439: *14844 delete posted event 00007F83919517E0
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 handle connection handler
2023/05/10 12:03:55 [debug] 439#439: *14844 event timer add: 22: 75000:17432974
2023/05/10 12:03:55 [debug] 439#439: *14844 reusable connection: 1
2023/05/10 12:03:55 [debug] 439#439: *14844 free: 00007F8391F3B4C0, unused: 2944
2023/05/10 12:03:55 [debug] 439#439: *14844 free: 00007F8391329040
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 idle handler
2023/05/10 12:03:55 [debug] 439#439: *14844 reusable connection: 0
2023/05/10 12:03:55 [debug] 439#439: *14844 posix_memalign: 00007F8391F39150:4096 @16
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 read handler
2023/05/10 12:03:55 [debug] 439#439: *14844 SSL_read: 132
2023/05/10 12:03:55 [debug] 439#439: *14844 SSL_read: -1
2023/05/10 12:03:55 [debug] 439#439: *14844 SSL_get_error: 2
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 frame type:1 f:25 l:123 sid:3
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 HEADERS frame sid:3 depends on 0 excl:1 weight:220
2023/05/10 12:03:55 [debug] 439#439: *14844 posix_memalign: 00007F8387E22280:1024 @16
2023/05/10 12:03:55 [debug] 439#439: *14844 posix_memalign: 00007F83904266A0:512 @16
2023/05/10 12:03:55 [debug] 439#439: *14844 posix_memalign: 00007F8391F3B4D0:4096 @16
2023/05/10 12:03:55 [debug] 439#439: *14844 posix_memalign: 00007F8391F3C710:4096 @16
2023/05/10 12:03:55 [debug] 439#439: *14844 event timer del: 22: 17432974
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 get indexed header: 2
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 header: ":method: GET"
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 get indexed header: 75
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 header: ":authority: k8s.local"
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 get indexed header: 7
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 header: ":scheme: https"
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 get indexed name: 4
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 encoded string, len:9
2023/05/10 12:03:55 [debug] 439#439: *14844 http uri: "/favicon.ico"
2023/05/10 12:03:55 [debug] 439#439: *14844 http args: ""
2023/05/10 12:03:55 [debug] 439#439: *14844 http exten: "ico"
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 header: ":path: /favicon.ico"
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 get indexed header: 73
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 header: "sec-ch-ua: "Google Chrome";v="113", "Chromium";v="113", "Not-A.Brand";v="24""
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 get indexed header: 72
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 header: "sec-ch-ua-mobile: ?0"
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 get indexed header: 69
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 header: "user-agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 get indexed header: 71
2023/05/10 12:03:55 [debug] 439#439: 14844 http2 header: "sec-ch-ua-platform: "Linux""
2023/05/10 12:03:55 [debug] 439#439: 14844 http2 get indexed name: 19
2023/05/10 12:03:55 [debug] 439#439: 14844 http2 encoded string, len:49
2023/05/10 12:03:55 [debug] 439#439: 14844 http2 table add: "accept: image/avif,image/webp,image/apng,image/svg+xml,image/,/;q=0.8"
2023/05/10 12:03:55 [debug] 439#439: 14844 http2 table account: 102 free:3067
2023/05/10 12:03:55 [debug] 439#439: 14844 http2 header: "accept: image/avif,image/webp,image/apng,image/svg+xml,image/,/;q=0.8"
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 get indexed name: 68
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 encoded string, len:8
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 table add: "sec-fetch-site: same-origin"
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 table account: 57 free:2965
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 header: "sec-fetch-site: same-origin"
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 get indexed name: 68
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 encoded string, len:5
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 table add: "sec-fetch-mode: no-cors"
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 table account: 53 free:2908
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 header: "sec-fetch-mode: no-cors"
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 get indexed name: 67
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 encoded string, len:4
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 table add: "sec-fetch-dest: image"
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 table account: 51 free:2855
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 header: "sec-fetch-dest: image"
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 get indexed name: 51
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 encoded string, len:19
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 table add: "referer: https://k8s.local/dfl-test"
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 table account: 65 free:2804
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 header: "referer: https://k8s.local/dfl-test"
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 get indexed header: 68
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 header: "accept-encoding: gzip, deflate, br"
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 get indexed header: 67
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 header: "accept-language: en-US,en;q=0.9"
2023/05/10 12:03:55 [debug] 439#439: *14844 http2 request line: "GET /favicon.ico HTTP/2.0"
2023/05/10 12:03:55 [debug] 439#439: *14844 generic phase: 0
2023/05/10 12:03:55 [debug] 439#439: *14844 rewrite phase: 1
2023/05/10 12:03:55 [debug] 439#439: *14844 http script value: "-"
2023/05/10 12:03:55 [debug] 439#439: *14844 http script set $proxy_upstream_name
2023/05/10 12:03:55 [debug] 439#439: *14844 test location: "/"
2023/05/10 12:03:55 [debug] 439#439: *14844 test location: "dfl-test"
2023/05/10 12:03:55 [debug] 439#439: *14844 test location: "dfl-test/"
2023/05/10 12:03:55 [debug] 439#439: *14844 using configuration "/"
2023/05/10 12:03:55 [debug] 439#439: *14844 http cl:-1 max:1048576
2023/05/10 12:03:55 [debug] 439#439: *14844 rewrite phase: 3
2023/05/10 12:03:55 [debug] 439#439: *14844 http script value: "dfl-test-rollout"
2023/05/10 12:03:55 [debug] 439#439: *14844 http script set $namespace
2023/05/10 12:03:55 [debug] 439#439: *14844 http script value: "dfl-test-rollout-genc-auth"
2023/05/10 12:03:55 [debug] 439#439: *14844 http script set $ingress_name
2023/05/10 12:03:55 [debug] 439#439: *14844 http script value: "dfl-test-rollout-genc-auth"
2023/05/10 12:03:55 [debug] 439#439: *14844 http script set $service_name
2023/05/10 12:03:55 [debug] 439#439: *14844 http script value: "80"
2023/05/10 12:03:55 [debug] 439#439: *14844 http script set $service_port
2023/05/10 12:03:55 [debug] 439#439: *14844 http script value: "/"
2023/05/10 12:03:55 [debug] 439#439: *14844 http script set $location_path
2023/05/10 12:03:55 [debug] 439#439: *14844 http script value: "n"
2023/05/10 12:03:55 [debug] 439#439: *14844 http script set $global_rate_limit_exceeding
2023/05/10 12:03:55 [debug] 439#439: *14844 http script value: "-1"
2023/05/10 12:03:55 [debug] 439#439: *14844 http script set $balancer_ewma_score
2023/05/10 12:03:55 [debug] 439#439: *14844 http script value: "dfl-test-rollout-dfl-test-rollout-genc-auth-80"
2023/05/10 12:03:55 [debug] 439#439: *14844 http script set $proxy_upstream_name
2023/05/10 12:03:55 [debug] 439#439: *14844 http script complex value
2023/05/10 12:03:55 [debug] 439#439: *14844 http script var: "dfl-test-rollout-dfl-test-rollout-genc-auth-80"
2023/05/10 12:03:55 [debug] 439#439: *14844 http script set $proxy_host
2023/05/10 12:03:55 [debug] 439#439: *14844 http script complex value
2023/05/10 12:03:55 [debug] 439#439: *14844 http script var: "https"
2023/05/10 12:03:55 [debug] 439#439: *14844 http script set $pass_access_scheme
2023/05/10 12:03:55 [debug] 439#439: *14844 http script complex value
2023/05/10 12:03:55 [debug] 439#439: *14844 http script var: "443"
2023/05/10 12:03:55 [debug] 439#439: *14844 http script set $pass_server_port
2023/05/10 12:03:55 [debug] 439#439: *14844 http script complex value
2023/05/10 12:03:55 [debug] 439#439: *14844 http script var: "k8s.local"
2023/05/10 12:03:55 [debug] 439#439: *14844 http script set $best_http_host
2023/05/10 12:03:55 [debug] 439#439: *14844 http script complex value
2023/05/10 12:03:55 [debug] 439#439: *14844 http script var: "443"
2023/05/10 12:03:55 [debug] 439#439: *14844 http script set $pass_port
2023/05/10 12:03:55 [debug] 439#439: *14844 http script value: ""
2023/05/10 12:03:55 [debug] 439#439: *14844 http script set $proxy_alternative_upstream_name
2023/05/10 12:03:55 [debug] 439#439: *14844 rewrite phase: 4
2023/05/10 12:03:55 [debug] 439#439: *14844 lua rewrite handler, uri:"/favicon.ico" c:1
2023/05/10 12:03:55 [debug] 439#439: *14844 code cache lookup (key='rewrite_by_lua_nhli_0b5957293aadfec043f3de317a2f03cb', ref=-1)
2023/05/10 12:03:55 [debug] 439#439: *14844 code cache setting ref (key='rewrite_by_lua_nhli_0b5957293aadfec043f3de317a2f03cb', ref=1)
2023/05/10 12:03:55 [debug] 439#439: *14844 code cache hit (key='rewrite_by_lua_nhli_0b5957293aadfec043f3de317a2f03cb', ref=1)
2023/05/10 12:03:55 [debug] 439#439: *14844 lua creating new thread
2023/05/10 12:03:55 [debug] 439#439: *14844 lua reusing cached lua thread 00007F8387D32A70 (ref 3)
2023/05/10 12:03:55 [debug] 439#439: *14844 lua reset ctx
2023/05/10 12:03:55 [debug] 439#439: *14844 http lua finalize threads
2023/05/10 12:03:55 [debug] 439#439: *14844 http cleanup add: 00007F8391F3D350
2023/05/10 12:03:55 [debug] 439#439: *14844 lua run thread, top:0 c:1
2023/05/10 12:03:55 [debug] 439#439: *14844 add cleanup: 00007F8391F3D390
2023/05/10 12:03:55 [debug] 439#439: *14844 lua resume returned 0
2023/05/10 12:03:55 [debug] 439#439: *14844 lua light thread ended normally
2023/05/10 12:03:55 [debug] 439#439: *14844 lua deleting light thread 00007F8387D32A70 (ref 3)
2023/05/10 12:03:55 [debug] 439#439: *14844 lua caching unused lua thread 00007F8387D32A70 (ref 3)
2023/05/10 12:03:55 [debug] 439#439: *14844 post rewrite phase: 5
2023/05/10 12:03:55 [debug] 439#439: *14844 generic phase: 6
2023/05/10 12:03:55 [debug] 439#439: *14844 generic phase: 7
2023/05/10 12:03:55 [debug] 439#439: *14844 generic phase: 8
2023/05/10 12:03:55 [debug] 439#439: *14844 access phase: 9
2023/05/10 12:03:55 [debug] 439#439: *14844 access phase: 10
2023/05/10 12:03:55 [debug] 439#439: *14844 access phase: 11
2023/05/10 12:03:55 [debug] 439#439: *14844 post access phase: 12
2023/05/10 12:03:55 [debug] 439#439: *14844 generic phase: 13
2023/05/10 12:03:55 [debug] 439#439: *14844 generic phase: 14
2023/05/10 12:03:55 [debug] 439#439: *14844 posix_memalign: 00007F8391F20700:4096 @16
2023/05/10 12:03:55 [debug] 439#439: *14844 http init upstream, client timer: 0
2023/05/10 12:03:55 [debug] 439#439: *14844 post event 00007F8391F39290
2023/05/10 12:03:55 [debug] 439#439: *14844 http map started
2023/05/10 12:03:55 [debug] 439#439: *14844 http map: "" ""
2023/05/10 12:03:55 [debug] 439#439: *14844 http map started
2023/05/10 12:03:55 [debug] 439#439: *14844 http script var: "48923cf8243eb94a1a5d26bc8d64781d"
2023/05/10 12:03:55 [debug] 439#439: *14844 http map: "" "48923cf8243eb94a1a5d26bc8d64781d"
2023/05/10 12:03:55 [debug] 439#439: *14844 http script copy: "Host"
2023/05/10 12:03:55 [debug] 439#439: *14844 http script var: "k8s.local"
2023/05/10 12:03:55 [debug] 439#439: *14844 http script copy: ""
2023/05/10 12:03:55 [debug] 439#439: *14844 http script copy: ""
2023/05/10 12:03:55 [debug] 439#439: *14844 http script copy: "X-Request-ID"
2023/05/10 12:03:55 [debug] 439#439: *14844 http script var: "48923cf8243eb94a1a5d26bc8d64781d"
2023/05/10 12:03:55 [debug] 439#439: *14844 http script copy: "X-Real-IP"
2023/05/10 12:03:55 [debug] 439#439: *14844 http script var: "192.168.49.1"
2023/05/10 12:03:55 [debug] 439#439: *14844 http script copy: "X-Forwarded-For"
2023/05/10 12:03:55 [debug] 439#439: *14844 http script var: "192.168.49.1"
2023/05/10 12:03:55 [debug] 439#439: *14844 http script copy: "X-Forwarded-Host"
2023/05/10 12:03:55 [debug] 439#439: *14844 http script var: "k8s.local"
2023/05/10 12:03:55 [debug] 439#439: *14844 http script copy: "X-Forwarded-Port"
2023/05/10 12:03:55 [debug] 439#439: *14844 http script var: "443"
2023/05/10 12:03:55 [debug] 439#439: *14844 http script copy: "X-Forwarded-Proto"
2023/05/10 12:03:55 [debug] 439#439: *14844 http script var: "https"
2023/05/10 12:03:55 [debug] 439#439: *14844 http script copy: "X-Forwarded-Scheme"
2023/05/10 12:03:55 [debug] 439#439: *14844 http script var: "https"
2023/05/10 12:03:55 [debug] 439#439: *14844 http script copy: "X-Scheme"
2023/05/10 12:03:55 [debug] 439#439: *14844 http script var: "https"
2023/05/10 12:03:55 [debug] 439#439: *14844 http script copy: ""
2023/05/10 12:03:55 [debug] 439#439: *14844 http script copy: ""
2023/05/10 12:03:55 [debug] 439#439: *14844 http script copy: ""
2023/05/10 12:03:55 [debug] 439#439: *14844 http proxy header: "sec-ch-ua: "Google Chrome";v="113", "Chromium";v="113", "Not-A.Brand";v="24""
2023/05/10 12:03:55 [debug] 439#439: *14844 http proxy header: "sec-ch-ua-mobile: ?0"
2023/05/10 12:03:55 [debug] 439#439: 14844 http proxy header: "user-agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36"
2023/05/10 12:03:55 [debug] 439#439: 14844 http proxy header: "sec-ch-ua-platform: "Linux""
2023/05/10 12:03:55 [debug] 439#439: 14844 http proxy header: "accept: image/avif,image/webp,image/apng,image/svg+xml,image/,/;q=0.8"
2023/05/10 12:03:55 [debug] 439#439: *14844 http proxy header: "sec-fetch-site: same-origin"
2023/05/10 12:03:55 [debug] 439#439: *14844 http proxy header: "sec-fetch-mode: no-cors"
2023/05/10 12:03:55 [debug] 439#439: *14844 http proxy header: "sec-fetch-dest: image"
2023/05/10 12:03:55 [debug] 439#439: *14844 http proxy header: "referer: https://k8s.local/dfl-test"
2023/05/10 12:03:55 [debug] 439#439: 14844 http proxy header: "accept-encoding: gzip, deflate, br"
2023/05/10 12:03:55 [debug] 439#439: 14844 http proxy header: "accept-language: en-US,en;q=0.9"
2023/05/10 12:03:55 [debug] 439#439: 14844 http proxy header:
"GET /favicon.ico HTTP/1.1
Host: k8s.local
X-Request-ID: 48923cf8243eb94a1a5d26bc8d64781d
X-Real-IP: 192.168.49.1
X-Forwarded-For: 192.168.49.1
X-Forwarded-Host: k8s.local
X-Forwarded-Port: 443
X-Forwarded-Proto: https
X-Forwarded-Scheme: https
X-Scheme: https
sec-ch-ua: "Google Chrome";v="113", "Chromium";v="113", "Not-A.Brand";v="24"
sec-ch-ua-mobile: ?0
user-agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36
sec-ch-ua-platform: "Linux"
accept: image/avif,image/webp,image/apng,image/svg+xml,image/,/;q=0.8
sec-fetch-site: same-origin
sec-fetch-mode: no-cors
sec-fetch-dest: image
referer: https://k8s.local/dfl-test
accept-encoding: gzip, deflate, br
accept-language: en-US,en;q=0.9

The text was updated successfully, but these errors were encountered:

longwuyuan · 2023-05-10T14:49:03Z

/remove-kind bug
I could be wrong, but if the HTTP(s) request matches the canary ingress, then maybe the canary ingress needs the 3 annotations as well

  nginx.ingress.kubernetes.io/auth-url: 'https://auth-service.local/auth/nginx-auth'
  nginx.ingress.kubernetes.io/custom-http-errors: '401,403'
  nginx.ingress.kubernetes.io/default-backend: default-backend

or are you convinced that the canary ingress does not need the 3 annotations because all auth occurs in the main ingress !

dfl-aeb · 2023-05-10T15:07:54Z

According to the docs the annotations are inherited from the main ingress and only certain annotations can be set manually:

Note that if you mark an ingress as a canary, all other non-canary annotations will be ignored (inherited from the corresponding main ingress), except for nginx.ingress.kubernetes.io/load-balance, nginx.ingress.kubernetes.io/upstream-hash-by and annotations related to session affinity. 
If you want to restore the original behaviour of canaries when session affinity was ignored, set the annotation nginx.ingress.kubernetes.io/affinity-canary-behavior with the value legacy to the canary-ingress-definition.

In addition, the call to the auth is initiated (you can see the http 401 in the logs), which means that the auth-annotation definitely takes effect.
Furthermore the default-backend is set as location, but then routed to a wrong IP (the frontends ip instead of the default-backends)
have a look at the provided logs and search for // default backend is used as location and // wrong IP is used

// default backend is used as location
2023/05/10 12:03:55 [debug] 439#439: *14844 test location: "@custom_custom-default-backend-dfl-test-rollout-dfl-test-rollout-genc-auth-default-backend_400"
2023/05/10 12:03:55 [debug] 439#439: *14844 test location: "@custom_custom-default-backend-dfl-test-rollout-dfl-test-rollout-genc-auth-default-backend_401"
2023/05/10 12:03:55 [debug] 439#439: *14844 using location: @custom_custom-default-backend-dfl-test-rollout-dfl-test-rollout-genc-auth-default-backend_401 "/dfl-test?"
...

2023/05/10 12:03:55 [debug] 439#439: *14844 http cleanup add: 00007F8391F22910
2023/05/10 12:03:55 [debug] 439#439: *14844 init keepalive peer
2023/05/10 12:03:55 [debug] 439#439: *14844 get keepalive peer
2023/05/10 12:03:55 [debug] 439#439: *14844 lua balancer peer, tries: 1
2023/05/10 12:03:55 [debug] 439#439: *14844 code cache lookup (key='balancer_by_lua_nhli_0f29762dfd828b8baa4d895affbc4b90', ref=-1)
2023/05/10 12:03:55 [debug] 439#439: *14844 code cache miss (key='balancer_by_lua_nhli_0f29762dfd828b8baa4d895affbc4b90', ref=-1)
2023/05/10 12:03:55 [debug] 439#439: *14844 add cleanup: 00007F839132C1C0
2023/05/10 12:03:55 [debug] 439#439: *14844 stream socket 24
2023/05/10 12:03:55 [debug] 439#439: *14844 epoll add connection: fd:24 ev:80002005

// wrong IP is used 10.244.0.202:80 is frontend-app --> default-backend has 10.244.0.203:8080
2023/05/10 12:03:55 [debug] 439#439: *14844 connect to 10.244.0.202:80, fd:24 #14847
2023/05/10 12:03:55 [debug] 439#439: *14844 http upstream connect: -2
2023/05/10 12:03:55 [debug] 439#439: *14844 posix_memalign: 00007F8391F436D0:128 @16
2023/05/10 12:03:55 [debug] 439#439: *14844 event timer add: 24: 60000:17417948
2023/05/10 12:03:55 [debug] 439#439: *14844 http finalize request: -4, "/?" a:1, c:3
2023/05/10 12:03:55 [debug] 439#439: *14844 http request count:3 blk:0

dfl-aeb · 2023-05-10T15:14:59Z

Can you provide more information about what happens right before the part where it connects to the wrong ip?
Where is the logic that decides where to connect?

longwuyuan · 2023-05-10T15:22:04Z

Apologies, I am not a developer so I don't precisely know.
I can look and update. Several functions are in lua.
The behaviour is undesirable but I think clarity is needed on the flow of the tansaction and you already asked to know the location of the redirect logic.

@Spazzy757 , any comments

Spazzy757 · 2023-05-10T15:31:20Z

I would need to look into this, There very well could be a a clash between how the canary handles routing and the overwriting the auth location. This I would assume would be in the nginx config. I'll need to try reproduce this to understand what the side affects are

strongjz · 2023-05-10T15:55:17Z

@dfl-aeb can you post the nginx config for carnary setup?

Labeling this as support till @Spazzy757 confirms a bug

/kind support
/prority backlog

dfl-aeb · 2023-05-10T18:46:40Z

Full ingress and resulting nginx config:

Default Ingress:

kind: Ingress
apiVersion: networking.k8s.io/v1
metadata:
  name: dfl-test-rollout
  labels:
    app.kubernetes.io/instance: dfl-test-rollout
  annotations:
    nginx.ingress.kubernetes.io/affinity: cookie
    nginx.ingress.kubernetes.io/affinity-canary-behavior: sticky
    nginx.ingress.kubernetes.io/affinity-mode: persistent
    nginx.ingress.kubernetes.io/auth-url: >-
      http://dfl-test-rollout-genc-auth.dfl-test-rollout.svc.cluster.local/nginx-auth
    nginx.ingress.kubernetes.io/configuration-snippet: >
      auth_request_set $next_auth_response_authorization_header
      $upstream_http_authorization;

      proxy_set_header authorization $next_auth_response_authorization_header;
    nginx.ingress.kubernetes.io/custom-http-errors: 400,401,403
    nginx.ingress.kubernetes.io/default-backend: dfl-test-rollout-genc-auth-default-backend
    nginx.ingress.kubernetes.io/session-cookie-name: aeb-session-canary-cookie
spec:
  ingressClassName: nginx
  rules:
    - host: k8s.local
      http:
        paths:
          - path: /dfl-test
            pathType: Prefix
            backend:
              service:
                name: dfl-test-rollout
                port:
                  number: 80

Canary-Ingress:

kind: Ingress
apiVersion: networking.k8s.io/v1
metadata:
  name: dfl-test-rollout-dfl-test-rollout-canary
  annotations:
    nginx.ingress.kubernetes.io/affinity: cookie
    nginx.ingress.kubernetes.io/affinity-canary-behavior: sticky
    nginx.ingress.kubernetes.io/canary: 'true'
    nginx.ingress.kubernetes.io/canary-by-cookie: canary-cookie
    nginx.ingress.kubernetes.io/canary-weight: '40'
spec:
  ingressClassName: nginx
  rules:
    - host: k8s.local
      http:
        paths:
          - path: /dfl-test
            pathType: Prefix
            backend:
              service:
                name: dfl-test-rollout-canary
                port:
                  number: 80

nginx-conf

start server k8s.local

server {
	server_name k8s.local ;
	
	listen 80  ;
	listen 443  ssl http2 ;
	
	set $proxy_upstream_name "-";
	
	ssl_certificate_by_lua_block {
		certificate.call()
	}
	
	location @custom_custom-default-backend-dfl-test-rollout-dfl-test-rollout-genc-auth-default-backend_400 {
		internal;
		
		# Ensure that modsecurity will not run on custom error pages or they might be blocked
		
		proxy_intercept_errors off;
		
		proxy_set_header       X-Code             400;
		proxy_set_header       X-Format           $http_accept;
		proxy_set_header       X-Original-URI     $request_uri;
		proxy_set_header       X-Namespace        $namespace;
		proxy_set_header       X-Ingress-Name     $ingress_name;
		proxy_set_header       X-Service-Name     $service_name;
		proxy_set_header       X-Service-Port     $service_port;
		proxy_set_header       X-Request-ID       $req_id;
		proxy_set_header       X-Forwarded-For    $remote_addr;
		proxy_set_header       Host               $best_http_host;
		
		set $proxy_upstream_name "custom-default-backend-dfl-test-rollout-dfl-test-rollout-genc-auth-default-backend";
		
		rewrite                (.*) / break;
		
		proxy_pass            http://upstream_balancer;
		log_by_lua_block {
			
			monitor.call()
			
		}
	}
	
	location @custom_custom-default-backend-dfl-test-rollout-dfl-test-rollout-genc-auth-default-backend_401 {
		internal;
		
		# Ensure that modsecurity will not run on custom error pages or they might be blocked
		
		proxy_intercept_errors off;
		
		proxy_set_header       X-Code             401;
		proxy_set_header       X-Format           $http_accept;
		proxy_set_header       X-Original-URI     $request_uri;
		proxy_set_header       X-Namespace        $namespace;
		proxy_set_header       X-Ingress-Name     $ingress_name;
		proxy_set_header       X-Service-Name     $service_name;
		proxy_set_header       X-Service-Port     $service_port;
		proxy_set_header       X-Request-ID       $req_id;
		proxy_set_header       X-Forwarded-For    $remote_addr;
		proxy_set_header       Host               $best_http_host;
		
		set $proxy_upstream_name "custom-default-backend-dfl-test-rollout-dfl-test-rollout-genc-auth-default-backend";
		
		rewrite                (.*) / break;
		
		proxy_pass            http://upstream_balancer;
		log_by_lua_block {
			
			monitor.call()
			
		}
	}
	
	location @custom_custom-default-backend-dfl-test-rollout-dfl-test-rollout-genc-auth-default-backend_403 {
		internal;
		
		# Ensure that modsecurity will not run on custom error pages or they might be blocked
		
		proxy_intercept_errors off;
		
		proxy_set_header       X-Code             403;
		proxy_set_header       X-Format           $http_accept;
		proxy_set_header       X-Original-URI     $request_uri;
		proxy_set_header       X-Namespace        $namespace;
		proxy_set_header       X-Ingress-Name     $ingress_name;
		proxy_set_header       X-Service-Name     $service_name;
		proxy_set_header       X-Service-Port     $service_port;
		proxy_set_header       X-Request-ID       $req_id;
		proxy_set_header       X-Forwarded-For    $remote_addr;
		proxy_set_header       Host               $best_http_host;
		
		set $proxy_upstream_name "custom-default-backend-dfl-test-rollout-dfl-test-rollout-genc-auth-default-backend";
		
		rewrite                (.*) / break;
		
		proxy_pass            http://upstream_balancer;
		log_by_lua_block {
			
			monitor.call()
			
		}
	}
	
	location = /_external-auth-L2RmbC10ZXN0Lw-Prefix {
		internal;
		
		access_log off;
		
		# Ensure that modsecurity will not run on an internal location as this is not accessible from outside
		
		# ngx_auth_request module overrides variables in the parent request,
		# therefore we have to explicitly set this variable again so that when the parent request
		# resumes it has the correct value set for this variable so that Lua can pick backend correctly
		set $proxy_upstream_name "dfl-test-rollout-dfl-test-rollout-80";
		
		proxy_pass_request_body     off;
		proxy_set_header            Content-Length          "";
		proxy_set_header            X-Forwarded-Proto       "";
		proxy_set_header            X-Request-ID            $req_id;
		
		proxy_set_header            Host                    dfl-test-rollout-genc-auth.dfl-test-rollout.svc.cluster.local;
		proxy_set_header            X-Original-URL          $scheme://$http_host$request_uri;
		proxy_set_header            X-Original-Method       $request_method;
		proxy_set_header            X-Sent-From             "nginx-ingress-controller";
		proxy_set_header            X-Real-IP               $remote_addr;
		
		proxy_set_header            X-Forwarded-For        $remote_addr;
		
		proxy_set_header            X-Auth-Request-Redirect $request_uri;
		
		proxy_buffering                         off;
		
		proxy_buffer_size                       4k;
		proxy_buffers                           4 4k;
		proxy_request_buffering                 on;
		
		proxy_ssl_server_name       on;
		proxy_pass_request_headers  on;
		
		client_max_body_size        1m;
		
		# Pass the extracted client certificate to the auth provider
		
		proxy_http_version 1.1;
		set $target http://dfl-test-rollout-genc-auth.dfl-test-rollout.svc.cluster.local/nginx-auth;
		
		proxy_pass $target;
	}
	
	location /dfl-test/ {
		
		set $namespace      "dfl-test-rollout";
		set $ingress_name   "dfl-test-rollout";
		set $service_name   "dfl-test-rollout";
		set $service_port   "80";
		set $location_path  "/dfl-test";
		set $global_rate_limit_exceeding n;
		
		rewrite_by_lua_block {
			lua_ingress.rewrite({
				force_ssl_redirect = false,
				ssl_redirect = true,
				force_no_ssl_redirect = false,
				preserve_trailing_slash = false,
				use_port_in_redirects = false,
				global_throttle = { namespace = "", limit = 0, window_size = 0, key = { }, ignored_cidrs = { } },
			})
			balancer.rewrite()
			plugins.run()
		}
		
		# be careful with `access_by_lua_block` and `satisfy any` directives as satisfy any
		# will always succeed when there's `access_by_lua_block` that does not have any lua code doing `ngx.exit(ngx.DECLINED)`
		# other authentication method such as basic auth or external auth useless - all requests will be allowed.
		#access_by_lua_block {
		#}
		
		header_filter_by_lua_block {
			lua_ingress.header()
			plugins.run()
		}
		
		body_filter_by_lua_block {
			plugins.run()
		}
		
		log_by_lua_block {
			balancer.log()
			
			monitor.call()
			
			plugins.run()
		}
		
		port_in_redirect off;
		
		set $balancer_ewma_score -1;
		set $proxy_upstream_name "dfl-test-rollout-dfl-test-rollout-80";
		set $proxy_host          $proxy_upstream_name;
		set $pass_access_scheme  $scheme;
		
		set $pass_server_port    $server_port;
		
		set $best_http_host      $http_host;
		set $pass_port           $pass_server_port;
		
		set $proxy_alternative_upstream_name "";
		
		# this location requires authentication
		
		auth_request        /_external-auth-L2RmbC10ZXN0Lw-Prefix;
		auth_request_set    $auth_cookie $upstream_http_set_cookie;
		
		add_header          Set-Cookie $auth_cookie;
		
		client_max_body_size                    1m;
		
		proxy_set_header Host                   $best_http_host;
		
		# Pass the extracted client certificate to the backend
		
		# Allow websocket connections
		proxy_set_header                        Upgrade           $http_upgrade;
		
		proxy_set_header                        Connection        $connection_upgrade;
		
		proxy_set_header X-Request-ID           $req_id;
		proxy_set_header X-Real-IP              $remote_addr;
		
		proxy_set_header X-Forwarded-For        $remote_addr;
		
		proxy_set_header X-Forwarded-Host       $best_http_host;
		proxy_set_header X-Forwarded-Port       $pass_port;
		proxy_set_header X-Forwarded-Proto      $pass_access_scheme;
		proxy_set_header X-Forwarded-Scheme     $pass_access_scheme;
		
		proxy_set_header X-Scheme               $pass_access_scheme;
		
		# Pass the original X-Forwarded-For
		proxy_set_header X-Original-Forwarded-For $http_x_forwarded_for;
		
		# mitigate HTTPoxy Vulnerability
		# https://www.nginx.com/blog/mitigating-the-httpoxy-vulnerability-with-nginx/
		proxy_set_header Proxy                  "";
		
		# Custom headers to proxied server
		
		proxy_connect_timeout                   5s;
		proxy_send_timeout                      60s;
		proxy_read_timeout                      60s;
		
		proxy_buffering                         off;
		proxy_buffer_size                       4k;
		proxy_buffers                           4 4k;
		
		proxy_max_temp_file_size                1024m;
		
		proxy_request_buffering                 on;
		proxy_http_version                      1.1;
		
		proxy_cookie_domain                     off;
		proxy_cookie_path                       off;
		
		# In case of errors try the next upstream server before returning an error
		proxy_next_upstream                     error timeout;
		proxy_next_upstream_timeout             0;
		proxy_next_upstream_tries               3;
		
		add_header X-Frame-Options "sameorigin";
		add_header content-security-policy "default-src 'self'; script-src 'self' 'unsafe-inline'; style-src 'self' 'unsafe-inline'; font-src 'self' data:; img-src 'self' data:; object-src 'none'";
		auth_request_set $next_auth_response_authorization_header $upstream_http_authorization;
		proxy_set_header authorization $next_auth_response_authorization_header;
		
		# Custom error pages per ingress
		proxy_intercept_errors on;
		
		error_page 400 = @custom_custom-default-backend-dfl-test-rollout-dfl-test-rollout-genc-auth-default-backend_400;
		error_page 401 = @custom_custom-default-backend-dfl-test-rollout-dfl-test-rollout-genc-auth-default-backend_401;
		error_page 403 = @custom_custom-default-backend-dfl-test-rollout-dfl-test-rollout-genc-auth-default-backend_403;
		
		proxy_pass http://upstream_balancer;
		
		proxy_redirect                          off;
		
	}
	
	location = /_external-auth-L2RmbC10ZXN0-Exact {
		internal;
		
		access_log off;
		
		# Ensure that modsecurity will not run on an internal location as this is not accessible from outside
		
		# ngx_auth_request module overrides variables in the parent request,
		# therefore we have to explicitly set this variable again so that when the parent request
		# resumes it has the correct value set for this variable so that Lua can pick backend correctly
		set $proxy_upstream_name "dfl-test-rollout-dfl-test-rollout-80";
		
		proxy_pass_request_body     off;
		proxy_set_header            Content-Length          "";
		proxy_set_header            X-Forwarded-Proto       "";
		proxy_set_header            X-Request-ID            $req_id;
		
		proxy_set_header            Host                    dfl-test-rollout-genc-auth.dfl-test-rollout.svc.cluster.local;
		proxy_set_header            X-Original-URL          $scheme://$http_host$request_uri;
		proxy_set_header            X-Original-Method       $request_method;
		proxy_set_header            X-Sent-From             "nginx-ingress-controller";
		proxy_set_header            X-Real-IP               $remote_addr;
		
		proxy_set_header            X-Forwarded-For        $remote_addr;
		
		proxy_set_header            X-Auth-Request-Redirect $request_uri;
		
		proxy_buffering                         off;
		
		proxy_buffer_size                       4k;
		proxy_buffers                           4 4k;
		proxy_request_buffering                 on;
		
		proxy_ssl_server_name       on;
		proxy_pass_request_headers  on;
		
		client_max_body_size        1m;
		
		# Pass the extracted client certificate to the auth provider
		
		proxy_http_version 1.1;
		set $target http://dfl-test-rollout-genc-auth.dfl-test-rollout.svc.cluster.local/nginx-auth;
		
		proxy_pass $target;
	}
	
	location = /dfl-test {
		
		set $namespace      "dfl-test-rollout";
		set $ingress_name   "dfl-test-rollout";
		set $service_name   "dfl-test-rollout";
		set $service_port   "80";
		set $location_path  "/dfl-test";
		set $global_rate_limit_exceeding n;
		
		rewrite_by_lua_block {
			lua_ingress.rewrite({
				force_ssl_redirect = false,
				ssl_redirect = true,
				force_no_ssl_redirect = false,
				preserve_trailing_slash = false,
				use_port_in_redirects = false,
				global_throttle = { namespace = "", limit = 0, window_size = 0, key = { }, ignored_cidrs = { } },
			})
			balancer.rewrite()
			plugins.run()
		}
		
		# be careful with `access_by_lua_block` and `satisfy any` directives as satisfy any
		# will always succeed when there's `access_by_lua_block` that does not have any lua code doing `ngx.exit(ngx.DECLINED)`
		# other authentication method such as basic auth or external auth useless - all requests will be allowed.
		#access_by_lua_block {
		#}
		
		header_filter_by_lua_block {
			lua_ingress.header()
			plugins.run()
		}
		
		body_filter_by_lua_block {
			plugins.run()
		}
		
		log_by_lua_block {
			balancer.log()
			
			monitor.call()
			
			plugins.run()
		}
		
		port_in_redirect off;
		
		set $balancer_ewma_score -1;
		set $proxy_upstream_name "dfl-test-rollout-dfl-test-rollout-80";
		set $proxy_host          $proxy_upstream_name;
		set $pass_access_scheme  $scheme;
		
		set $pass_server_port    $server_port;
		
		set $best_http_host      $http_host;
		set $pass_port           $pass_server_port;
		
		set $proxy_alternative_upstream_name "";
		
		# this location requires authentication
		
		auth_request        /_external-auth-L2RmbC10ZXN0-Exact;
		auth_request_set    $auth_cookie $upstream_http_set_cookie;
		
		add_header          Set-Cookie $auth_cookie;
		
		client_max_body_size                    1m;
		
		proxy_set_header Host                   $best_http_host;
		
		# Pass the extracted client certificate to the backend
		
		# Allow websocket connections
		proxy_set_header                        Upgrade           $http_upgrade;
		
		proxy_set_header                        Connection        $connection_upgrade;
		
		proxy_set_header X-Request-ID           $req_id;
		proxy_set_header X-Real-IP              $remote_addr;
		
		proxy_set_header X-Forwarded-For        $remote_addr;
		
		proxy_set_header X-Forwarded-Host       $best_http_host;
		proxy_set_header X-Forwarded-Port       $pass_port;
		proxy_set_header X-Forwarded-Proto      $pass_access_scheme;
		proxy_set_header X-Forwarded-Scheme     $pass_access_scheme;
		
		proxy_set_header X-Scheme               $pass_access_scheme;
		
		# Pass the original X-Forwarded-For
		proxy_set_header X-Original-Forwarded-For $http_x_forwarded_for;
		
		# mitigate HTTPoxy Vulnerability
		# https://www.nginx.com/blog/mitigating-the-httpoxy-vulnerability-with-nginx/
		proxy_set_header Proxy                  "";
		
		# Custom headers to proxied server
		
		proxy_connect_timeout                   5s;
		proxy_send_timeout                      60s;
		proxy_read_timeout                      60s;
		
		proxy_buffering                         off;
		proxy_buffer_size                       4k;
		proxy_buffers                           4 4k;
		
		proxy_max_temp_file_size                1024m;
		
		proxy_request_buffering                 on;
		proxy_http_version                      1.1;
		
		proxy_cookie_domain                     off;
		proxy_cookie_path                       off;
		
		# In case of errors try the next upstream server before returning an error
		proxy_next_upstream                     error timeout;
		proxy_next_upstream_timeout             0;
		proxy_next_upstream_tries               3;
		
		add_header X-Frame-Options "sameorigin";
		add_header content-security-policy "default-src 'self'; script-src 'self' 'unsafe-inline'; style-src 'self' 'unsafe-inline'; font-src 'self' data:; img-src 'self' data:; object-src 'none'";
		auth_request_set $next_auth_response_authorization_header $upstream_http_authorization;
		proxy_set_header authorization $next_auth_response_authorization_header;
		
		# Custom error pages per ingress
		proxy_intercept_errors on;
		
		error_page 400 = @custom_custom-default-backend-dfl-test-rollout-dfl-test-rollout-genc-auth-default-backend_400;
		error_page 401 = @custom_custom-default-backend-dfl-test-rollout-dfl-test-rollout-genc-auth-default-backend_401;
		error_page 403 = @custom_custom-default-backend-dfl-test-rollout-dfl-test-rollout-genc-auth-default-backend_403;
		
		proxy_pass http://upstream_balancer;
		
		proxy_redirect                          off;
		
	}
	
	location / {
		
		set $namespace      "dfl-test-rollout";
		set $ingress_name   "dfl-test-rollout-genc-auth";
		set $service_name   "dfl-test-rollout-genc-auth";
		set $service_port   "80";
		set $location_path  "/";
		set $global_rate_limit_exceeding n;
		
		rewrite_by_lua_block {
			lua_ingress.rewrite({
				force_ssl_redirect = false,
				ssl_redirect = true,
				force_no_ssl_redirect = false,
				preserve_trailing_slash = false,
				use_port_in_redirects = false,
				global_throttle = { namespace = "", limit = 0, window_size = 0, key = { }, ignored_cidrs = { } },
			})
			balancer.rewrite()
			plugins.run()
		}
		
		# be careful with `access_by_lua_block` and `satisfy any` directives as satisfy any
		# will always succeed when there's `access_by_lua_block` that does not have any lua code doing `ngx.exit(ngx.DECLINED)`
		# other authentication method such as basic auth or external auth useless - all requests will be allowed.
		#access_by_lua_block {
		#}
		
		header_filter_by_lua_block {
			lua_ingress.header()
			plugins.run()
		}
		
		body_filter_by_lua_block {
			plugins.run()
		}
		
		log_by_lua_block {
			balancer.log()
			
			monitor.call()
			
			plugins.run()
		}
		
		port_in_redirect off;
		
		set $balancer_ewma_score -1;
		set $proxy_upstream_name "dfl-test-rollout-dfl-test-rollout-genc-auth-80";
		set $proxy_host          $proxy_upstream_name;
		set $pass_access_scheme  $scheme;
		
		set $pass_server_port    $server_port;
		
		set $best_http_host      $http_host;
		set $pass_port           $pass_server_port;
		
		set $proxy_alternative_upstream_name "";
		
		client_max_body_size                    1m;
		
		proxy_set_header Host                   $best_http_host;
		
		# Pass the extracted client certificate to the backend
		
		# Allow websocket connections
		proxy_set_header                        Upgrade           $http_upgrade;
		
		proxy_set_header                        Connection        $connection_upgrade;
		
		proxy_set_header X-Request-ID           $req_id;
		proxy_set_header X-Real-IP              $remote_addr;
		
		proxy_set_header X-Forwarded-For        $remote_addr;
		
		proxy_set_header X-Forwarded-Host       $best_http_host;
		proxy_set_header X-Forwarded-Port       $pass_port;
		proxy_set_header X-Forwarded-Proto      $pass_access_scheme;
		proxy_set_header X-Forwarded-Scheme     $pass_access_scheme;
		
		proxy_set_header X-Scheme               $pass_access_scheme;
		
		# Pass the original X-Forwarded-For
		proxy_set_header X-Original-Forwarded-For $http_x_forwarded_for;
		
		# mitigate HTTPoxy Vulnerability
		# https://www.nginx.com/blog/mitigating-the-httpoxy-vulnerability-with-nginx/
		proxy_set_header Proxy                  "";
		
		# Custom headers to proxied server
		
		proxy_connect_timeout                   5s;
		proxy_send_timeout                      60s;
		proxy_read_timeout                      60s;
		
		proxy_buffering                         off;
		proxy_buffer_size                       4k;
		proxy_buffers                           4 4k;
		
		proxy_max_temp_file_size                1024m;
		
		proxy_request_buffering                 on;
		proxy_http_version                      1.1;
		
		proxy_cookie_domain                     off;
		proxy_cookie_path                       off;
		
		# In case of errors try the next upstream server before returning an error
		proxy_next_upstream                     error timeout;
		proxy_next_upstream_timeout             0;
		proxy_next_upstream_tries               3;
		
		add_header X-Frame-Options "sameorigin";
		add_header content-security-policy "default-src 'self'; script-src 'self' 'unsafe-inline'; style-src 'self' 'unsafe-inline'; font-src 'self' data:; img-src 'self' data:; object-src 'none'";
		
		proxy_pass http://upstream_balancer;
		
		proxy_redirect                          off;
		
	}
	
}
## end server k8s.local

Spazzy757 · 2023-05-11T08:58:15Z

I have managed to reproduce this with the following setup:

two instances of HTTPBun deployed in seperate namespaces
custom default backend deployed (I tried deploying it in both namespaces and in the non canary namespace only)

The following two ingresses:

Main Ingress to the none canary deployment

---
apiVersion: networking.k8s.io/v1
kind: Ingress
metadata:
  name: httpbun
  namespace: httpbun
  annotations:
    nginx.ingress.kubernetes.io/custom-http-errors: 400,401,403
    nginx.ingress.kubernetes.io/default-backend: custombackend
spec:
  ingressClassName: nginx
  rules:
  - host: minikube.local
    http:
      paths:
      - path: /
        pathType: Prefix
        backend:
          service:
            name: httpbun
            port:
              number: 80
  tls:
  - hosts:
    - minikube.local
    secretName: tls-secret

Canary Deployment Ingress

---
apiVersion: networking.k8s.io/v1
kind: Ingress
metadata:
  name: httpbun
  namespace: canary
  annotations:
    nginx.ingress.kubernetes.io/canary: 'true'
    nginx.ingress.kubernetes.io/canary-weight: '40'
spec:
  ingressClassName: nginx
  rules:
  - host: minikube.local
    http:
      paths:
      - path: /
        pathType: Prefix
        backend:
          service:
            name: httpbun
            port:
              number: 80
  tls:
  - hosts:
    - minikube.local
    secretName: tls-secret

The expected Understanding from the documentation is that the the canary ingress inherits the annotations from the main one however this is not the case, it also does not work by adding the default backend annotations to the canary ingress

When getting a 401 from the Main deployment I got the default backend:

When hitting the Canary I got a strange behaviour where is seems to be hitting the service at the root path even though I specified a uri

logs of canary Service for the above call

2023/05/11 08:46:50 From ip=127.0.0.1 GET minikube.local/status/401
2023/05/11 08:46:50 Headers incomind map[Accept:[image/avif,image/webp,image/apng,image/svg+xml,image/*,*/*;q=0.8] Accept-Encoding:[gzip, deflate, br] Accept-Language:[en-US,en;q=0.9] Referer:[https://minikube.local/status/401] Sec-Ch-Ua:["Google Chrome";v="113", "Chromium";v="113", "Not-A.Brand";v="24"] Sec-Ch-Ua-Mobile:[?0] Sec-Ch-Ua-Platform:["Linux"] Sec-Fetch-Dest:[image] Sec-Fetch-Mode:[no-cors] Sec-Fetch-Site:[same-origin] User-Agent:[Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36] X-Forwarded-For:[127.0.0.1] X-Forwarded-Host:[minikube.local] X-Forwarded-Port:[443] X-Forwarded-Proto:[https] X-Forwarded-Scheme:[https] X-Real-Ip:[127.0.0.1] X-Request-Id:[9b91a53416084e50ab16cab754ae9d32] X-Scheme:[https]]
2023/05/11 08:46:50 From ip=127.0.0.1 GET minikube.local/favicon.ico
2023/05/11 08:55:28 Headers incomind map[Accept:[text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,image/apng,*/*;q=0.8,application/signed-exchange;v=b3;q=0.7] Accept-Encoding:[gzip, deflate, br] Accept-Language:[en-US,en;q=0.9] Cache-Control:[no-cache] Pragma:[no-cache] Sec-Ch-Ua:["Google Chrome";v="113", "Chromium";v="113", "Not-A.Brand";v="24"] Sec-Ch-Ua-Mobile:[?0] Sec-Ch-Ua-Platform:["Linux"] Sec-Fetch-Dest:[document] Sec-Fetch-Mode:[navigate] Sec-Fetch-Site:[none] Sec-Fetch-User:[?1] Upgrade-Insecure-Requests:[1] User-Agent:[Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36] X-Forwarded-For:[127.0.0.1] X-Forwarded-Host:[minikube.local] X-Forwarded-Port:[443] X-Forwarded-Proto:[https] X-Forwarded-Scheme:[https] X-Real-Ip:[127.0.0.1] X-Request-Id:[6985ca8d27aff2a66e44c12657979064] X-Scheme:[https]]
2023/05/11 08:55:28 From ip=127.0.0.1 GET minikube.local/status/401
2023/05/11 08:55:28 Headers incomind map[Accept:[text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,image/apng,*/*;q=0.8,application/signed-exchange;v=b3;q=0.7] Accept-Encoding:[gzip, deflate, br] Accept-Language:[en-US,en;q=0.9] Cache-Control:[no-cache] Connection:[close] Pragma:[no-cache] Sec-Ch-Ua:["Google Chrome";v="113", "Chromium";v="113", "Not-A.Brand";v="24"] Sec-Ch-Ua-Mobile:[?0] Sec-Ch-Ua-Platform:["Linux"] Sec-Fetch-Dest:[document] Sec-Fetch-Mode:[navigate] Sec-Fetch-Site:[none] Sec-Fetch-User:[?1] Upgrade-Insecure-Requests:[1] User-Agent:[Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36] X-Code:[401] X-Format:[text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,image/apng,*/*;q=0.8,application/signed-exchange;v=b3;q=0.7] X-Forwarded-For:[127.0.0.1] X-Ingress-Name:[httpbun] X-Namespace:[serviceone] X-Original-Uri:[/status/401] X-Request-Id:[6985ca8d27aff2a66e44c12657979064] X-Service-Name:[httpbun] X-Service-Port:[80]]
2023/05/11 08:55:28 From ip=127.0.0.1 GET minikube.local/
2023/05/11 08:55:29 Headers incomind map[Accept:[*/*] Accept-Encoding:[gzip, deflate, br] Accept-Language:[en-US,en;q=0.9] Referer:[https://minikube.local/status/401] Sec-Ch-Ua:["Google Chrome";v="113", "Chromium";v="113", "Not-A.Brand";v="24"] Sec-Ch-Ua-Mobile:[?0] Sec-Ch-Ua-Platform:["Linux"] Sec-Fetch-Dest:[manifest] Sec-Fetch-Mode:[cors] Sec-Fetch-Site:[same-origin] User-Agent:[Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/113.0.0.0 Safari/537.36] X-Forwarded-For:[127.0.0.1] X-Forwarded-Host:[minikube.local] X-Forwarded-Port:[443] X-Forwarded-Proto:[https] X-Forwarded-Scheme:[https] X-Real-Ip:[127.0.0.1] X-Request-Id:[1746aaea33aa802ab7e54ba5e2f272a5] X-Scheme:[https]]
2023/05/11 08:55:29 From ip=127.0.0.1 GET minikube.local/site.webmanifest

@strongjz Is there anything else needed to mark this as a bug and look at triaging?

I have not dug into the Nginx Conf but my current feeling is that this is possibly from a clash there

strongjz · 2023-05-11T13:39:24Z

/kind bug
/triage accepted

dfl-aeb · 2023-05-22T10:10:39Z

@Spazzy757 any news on this?
Is there anything I can do to assist you?

I experienced the same problem, that my custom ingress path was also ignored, as well as my rewrite annotation.

Spazzy757 · 2023-05-22T10:15:26Z

Yes it's currently known bug we trying to get a root cause for, unfortunately we have limited time available to look into it but we are looking into it.

Spazzy757 · 2023-06-08T12:20:04Z

Just an update on this, I think this might be down to our implementation for route_to_alternative_balancer lua plugin, where the weight to the canary is of a higher priority to the backend, but Im still looking for a way to validate this,

I believe it to be in this function

Essentially I believe this due to the following logs:

"GET /status/401 HTTP/2.0" 200 19307 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/114.0.0.0 Safari/537.36" 28 0.002 [custom-default-backend-main-custombackend] [canary-httpbun-80] 10.244.0.9:80 : 10.244.0.8:80 0 : 19307 0.001 : 0.002 401 : 200
"GET /status/401 HTTP/2.0" 200 19307 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/114.0.0.0 Safari/537.36" 454 0.002 [custom-default-backend-main-custombackend] [canary-httpbun-80] 10.244.0.9:80 : 10.244.0.8:80 0 : 19307 0.001 : 0.002 401 : 200
"GET /status/401 HTTP/2.0" 401 1235 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/114.0.0.0 Safari/537.36" 27 0.002 [custom-default-backend-main-custombackend] [] 10.244.0.9:80 : 10.244.0.11:8080 0 : 1235 0.001 : 0.001 401 : 401

You will note when you hit the normal ingress the following I shown:

[custom-default-backend--custombackend] []

However in the case of hitting the canery deployment, we get:

[custom-default-backend-main-custombackend] [canary-httpbun-80]

Which I assume means the canary-httpbun-80 takes precedence where we should infact probably make the canary not take precedence.

@rikatz @strongjz Not sure if you can give me some feedback or views on where/how the custom backend is configured in the above way

Spazzy757 · 2023-06-09T13:28:13Z

Sorry for spamming this issue, but I'm using it to dump info about my investigation into this issue (in case anybody has a better idea on how to solve this).

So I think the core issue is when we use a custom-default-backend we are using an interceptor in the nginx.conf

# Custom error pages per ingress
proxy_intercept_errors on;

error_page 400 = @custom_custom-default-backend-default-custombackend_400;
error_page 401 = @custom_custom-default-backend-default-custombackend_401;
error_page 403 = @custom_custom-default-backend-default-custombackend_403;

proxy_pass http://upstream_balancer;

proxy_redirect                          off;

Now this will update any error rersponse from the upstream, but our lua plugin changes the upstream per request, and the intercept does not seem to work for the canary upstream when it is set as the alternative

Spazzy757 · 2023-06-12T07:37:22Z

@dfl-aeb I have found the root cause and have a pending fix, we just need to validate with some E2E testing and we should be good to go, I will try to push for this to go into the 1.8.2 release (I believe 1.8.1 is almost ready and I don't think this will get there in time). Thank you for your patience!

dfl-aeb · 2023-06-12T08:38:25Z

awesome, thank you so much! 🥳

Spazzy757 · 2023-06-14T12:05:33Z

/kind bug

dfl-aeb · 2023-09-21T13:23:02Z

any news on this @Spazzy757? :)

k8s-triage-robot · 2024-09-20T13:54:20Z

This issue has not been updated in over 1 year, and should be re-triaged.

You can:

Confirm that this issue is still relevant with /triage accepted (org members only)
Close this issue with /close

For more details on the triage process, see https://www.kubernetes.dev/docs/guide/issue-triage/

/remove-triage accepted

dfl-aeb · 2024-09-24T09:02:37Z

WIP in this PR: #10072

Still relevant

dfl-aeb added the kind/bug Categorizes issue or PR as related to a bug. label May 10, 2023

k8s-ci-robot added needs-triage Indicates an issue or PR lacks a `triage/foo` label and requires one. needs-priority labels May 10, 2023

k8s-ci-robot added needs-kind Indicates a PR lacks a `kind/foo` label and requires one. and removed kind/bug Categorizes issue or PR as related to a bug. labels May 10, 2023

k8s-ci-robot added kind/support Categorizes issue or PR as a support question. and removed needs-kind Indicates a PR lacks a `kind/foo` label and requires one. labels May 10, 2023

k8s-ci-robot added triage/accepted Indicates an issue or PR is ready to be actively worked on. and removed needs-triage Indicates an issue or PR lacks a `triage/foo` label and requires one. labels May 11, 2023

Spazzy757 mentioned this issue May 11, 2023

REQUEST: New membership for Spazzy757 kubernetes/org#4209

Closed

9 tasks

Spazzy757 linked a pull request Jun 12, 2023 that will close this issue

fix: issue where canary overwrites default backend #10072

Open

10 tasks

k8s-ci-robot added the kind/bug Categorizes issue or PR as related to a bug. label Jun 14, 2023

k8s-ci-robot added needs-triage Indicates an issue or PR lacks a `triage/foo` label and requires one. and removed triage/accepted Indicates an issue or PR is ready to be actively worked on. labels Sep 20, 2024

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Default-backend is ignored by canary ingress #9944

Default-backend is ignored by canary ingress #9944

dfl-aeb commented May 10, 2023 •

edited

Loading

longwuyuan commented May 10, 2023

dfl-aeb commented May 10, 2023 •

edited

Loading

dfl-aeb commented May 10, 2023

longwuyuan commented May 10, 2023

Spazzy757 commented May 10, 2023

strongjz commented May 10, 2023

dfl-aeb commented May 10, 2023 •

edited

Loading

start server k8s.local

Spazzy757 commented May 11, 2023 •

edited

Loading

strongjz commented May 11, 2023

dfl-aeb commented May 22, 2023

Spazzy757 commented May 22, 2023

Spazzy757 commented Jun 8, 2023 •

edited

Loading

Spazzy757 commented Jun 9, 2023

Spazzy757 commented Jun 12, 2023

dfl-aeb commented Jun 12, 2023

Spazzy757 commented Jun 14, 2023

dfl-aeb commented Sep 21, 2023

k8s-triage-robot commented Sep 20, 2024

dfl-aeb commented Sep 24, 2024

Default-backend is ignored by canary ingress #9944

Default-backend is ignored by canary ingress #9944

Comments

dfl-aeb commented May 10, 2023 • edited Loading

longwuyuan commented May 10, 2023

dfl-aeb commented May 10, 2023 • edited Loading

dfl-aeb commented May 10, 2023

longwuyuan commented May 10, 2023

Spazzy757 commented May 10, 2023

strongjz commented May 10, 2023

dfl-aeb commented May 10, 2023 • edited Loading

start server k8s.local

Spazzy757 commented May 11, 2023 • edited Loading

strongjz commented May 11, 2023

dfl-aeb commented May 22, 2023

Spazzy757 commented May 22, 2023

Spazzy757 commented Jun 8, 2023 • edited Loading

Spazzy757 commented Jun 9, 2023

Spazzy757 commented Jun 12, 2023

dfl-aeb commented Jun 12, 2023

Spazzy757 commented Jun 14, 2023

dfl-aeb commented Sep 21, 2023

k8s-triage-robot commented Sep 20, 2024

dfl-aeb commented Sep 24, 2024

dfl-aeb commented May 10, 2023 •

edited

Loading

dfl-aeb commented May 10, 2023 •

edited

Loading

dfl-aeb commented May 10, 2023 •

edited

Loading

Spazzy757 commented May 11, 2023 •

edited

Loading

Spazzy757 commented Jun 8, 2023 •

edited

Loading