ingress-nginx: Default-backend is ignored by canary ingress
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: 72ff21ed9e26cb969052c753633049ba8a87ecf9 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
About this issue
- Original URL
- State: open
- Created a year ago
- Comments: 17 (11 by maintainers)
@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!
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
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
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.
I have managed to reproduce this with the following setup:
The following two ingresses:
Main Ingress to the none canary deployment
Canary Deployment Ingress
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
@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
Full ingress and resulting nginx config:
Default Ingress:
Canary-Ingress:
nginx-conf
start server k8s.local
@dfl-aeb can you post the nginx config for carnary setup?
Labeling this as support till @Spazzy757 confirms a bug
/kind support /prority backlog