apisix-ingress-controller: bug: Ingress controller error: apisix/route.go:117 failed to list routes

Issue description

I’m unable to define routes. But looking at the apisix ingress controller log I see these error:

2022-01-29T08:05:08.842Z | 2022-01-29T16:05:08+08:00 [31merror[0m apisix/plugin.go:46 failed to list plugins' names: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/plugins/list: context canceled
2022-01-29T08:05:08.842Z | 2022-01-29T16:05:08+08:00 [31merror[0m apisix/cluster.go:364 failed to list plugin names in APISIX: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/plugins/list: context canceled
2022-01-29T08:05:08.842Z | 2022-01-29T16:05:08+08:00 [33mwarn[0m apisix/cluster.go:327 failed to sync schema: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/plugins/list: context canceled
2022-01-29T08:05:08.848Z | 2022-01-29T16:05:08+08:00 [34minfo[0m ingress/controller.go:290 LeaderElection {"message": "apisix-ingress-controller-7d5bbf5dd5-fhlz5 became leader", "event_type": "Normal"}
2022-01-29T08:05:08.848Z | I0129 16:05:08.848718 1 leaderelection.go:253] successfully acquired lease apisix/ingress-apisix-leader
2022-01-29T08:05:08.848Z | 2022-01-29T16:05:08+08:00 [34minfo[0m ingress/controller.go:370 controller tries to leading ... {"namespace": "apisix", "pod": "apisix-ingress-controller-7d5bbf5dd5-fhlz5"}
2022-01-29T08:05:08.848Z | 2022-01-29T16:05:08+08:00 [33mwarn[0m apisix/cluster.go:304 waiting cluster default to ready, it may takes a while
2022-01-29T08:05:09.398Z | [GIN] 2022/01/29 - 16:05:09 | 200 | 23.71µs | 127.0.0.6 | GET "/healthz"
2022-01-29T08:05:10.842Z | 2022-01-29T16:05:10+08:00 [31merror[0m apisix/route.go:117 failed to list routes: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-29T08:05:10.842Z | 2022-01-29T16:05:10+08:00 [31merror[0m apisix/cluster.go:197 failed to list route in APISIX: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled

Environment

your apisix-ingress-controller version (output of apisix-ingress-controller version --long):

apache/apisix-ingress-controller:1.3.0 (taken from kubernetes dashboard)

your Kubernetes cluster version (output of kubectl version):

sysop@m01serv:~$ kubectl version
Client Version: version.Info{Major:"1", Minor:"23", GitVersion:"v1.23.1", GitCommit:"86ec240af8cbd1b60bcc4c03c20da9b98005b92e", GitTreeState:"clean", BuildDate:"2021-12-16T11:41:01Z", GoVersion:"go1.17.5", Compiler:"gc", Platform:"linux/amd64"}
Server Version: version.Info{Major:"1", Minor:"22", GitVersion:"v1.22.5+k3s1", GitCommit:"405bf79da97831749733ad99842da638c8ee4802", GitTreeState:"clean", BuildDate:"2021-12-18T00:43:30Z", GoVersion:"go1.16.10", Compiler:"gc", Platform:"linux/amd64"}
sysop@m01serv:~$

if you run apisix-ingress-controller in Bare-metal environment, also show your OS version (uname -a):

sysop@m01km:~$ uname -a
Linux m01km 5.4.0-96-generic #109-Ubuntu SMP Wed Jan 12 16:49:16 UTC 2022 x86_64 x86_64 x86_64 GNU/Linux
sysop@m01km:~$ 
(the OS of the kubernetes nodes hosting apisix)

Minimal test code / Steps to reproduce

on a kubernetes cluster (using K3S) with Istio (and bookinfo demo application) installed, install Apisix with:

kubectl create ns apisix
kubectl label namespace apisix istio-injection=enabled
helm install apisix apisix/apisix \
--set gateway.type=NodePort \
--set ingress-controller.enabled=true \
--set ingress-controller.config.apisix.serviceNamespace=apisix \
--set ingress-controller.config.apisix.serviceName=apisix-admin \
--set dashboard.enabled=true \
--namespace apisix

Wait until all apisix resources are ready

try to create an Apisix route Create a file named productpage-ar.yaml containing

apiVersion: apisix.apache.org/v2beta2
kind: ApisixRoute
metadata:
  name: productpage
spec:
  http:
  - name: rule1
    match:
      hosts:
      - www.m01.net
      paths:
      - /*
    backends:
    - serviceName: productpage
      servicePort: 9080

Create the route with:

kubectl -n bookinfo apply -f productpage-ar.yaml

Verify that, for kubernetes, the route exist with:

sysop@m01serv:~$ kubectl describe apisixroute productpage -n bookinfo
Name:         productpage
Namespace:    bookinfo
Labels:       <none>
Annotations:  <none>
API Version:  apisix.apache.org/v2beta2
Kind:         ApisixRoute
Metadata:
  Creation Timestamp:  2022-01-28T20:05:50Z
  Generation:          1
  Managed Fields:
    API Version:  apisix.apache.org/v2beta2
    Fields Type:  FieldsV1
    fieldsV1:
      f:metadata:
        f:annotations:
          .:
          f:kubectl.kubernetes.io/last-applied-configuration:
      f:spec:
        .:
        f:http:
    Manager:         kubectl-client-side-apply
    Operation:       Update
    Time:            2022-01-28T20:05:50Z
  Resource Version:  246403
  UID:               9ffba506-71ce-4183-880a-290c44087c2e
Spec:
  Http:
    Backends:
      Service Name:  productpage
      Service Port:  9080
    Match:
      Hosts:
        www.m01.net
      Paths:
        /*
    Name:  rule1
Events:    <none>
sysop@m01serv:~$

verify that the roure is not accessible (route not found error)

sysop@m01serv:~$ export NODE_PORT=$(kubectl get --namespace apisix -o jsonpath="{.spec.ports[0].nodePort}" services apisix-gateway)
sysop@m01serv:~$ export NODE_IP=$(kubectl get nodes --namespace apisix -o jsonpath="{.items[0].status.addresses[0].address}")
sysop@m01serv:~$ echo http://$NODE_IP:$NODE_PORT
http://192.168.102.121:30255
sysop@m01serv:~$ curl -I -H "HOST: www.m01.net" http://192.168.102.121:30255/
HTTP/1.1 404 Not Found
date: Sat, 29 Jan 2022 08:55:05 GMT
content-type: text/plain; charset=utf-8
server: istio-envoy
x-envoy-upstream-service-time: 0
x-envoy-decorator-operation: apisix-gateway.apisix.svc.cluster.local:80/*
transfer-encoding: chunked

sysop@m01serv:~$

Verify that in the apisix ingress controller pod there is the error “apisix/cluster.go:197 failed to list route”

2022-01-29T08:56:53.329Z | 2022-01-29T16:56:53+08:00 [31merror[0m apisix/cluster.go:197 failed to list route in APISIX: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-29T08:56:53.329Z | 2022-01-29T16:56:53+08:00 [31merror[0m apisix/plugin.go:46 failed to list plugins' names: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/plugins/list: context canceled
2022-01-29T08:56:53.329Z | 2022-01-29T16:56:53+08:00 [31merror[0m apisix/cluster.go:364 failed to list plugin names in APISIX: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/plugins/list: context canceled
2022-01-29T08:56:53.329Z | 2022-01-29T16:56:53+08:00 [33mwarn[0m apisix/cluster.go:327 failed to sync schema: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/plugins/list: context canceled
2022-01-29T08:56:53.337Z | 2022-01-29T16:56:53+08:00 [34minfo[0m ingress/controller.go:290 LeaderElection {"message": "apisix-ingress-controller-7d5bbf5dd5-fhlz5 became leader", "event_type": "Normal"}
2022-01-29T08:56:53.337Z | I0129 16:56:53.337314 1 leaderelection.go:253] successfully acquired lease apisix/ingress-apisix-leader
2022-01-29T08:56:53.337Z | 2022-01-29T16:56:53+08:00 [34minfo[0m ingress/controller.go:370 controller tries to leading ... {"namespace": "apisix", "pod": "apisix-ingress-controller-7d5bbf5dd5-fhlz5"}
2022-01-29T08:56:53.337Z | 2022-01-29T16:56:53+08:00 [33mwarn[0m apisix/cluster.go:304 waiting cluster default to ready, it may takes a while
2022-01-29T08:56:53.786Z | [GIN] 2022/01/29 - 16:56:53 | 200 | 47.4µs | 127.0.0.6 | GET "/healthz"

Actual result

Route not found

sysop@m01serv:~$ export NODE_PORT=$(kubectl get --namespace apisix -o jsonpath="{.spec.ports[0].nodePort}" services apisix-gateway)
sysop@m01serv:~$ export NODE_IP=$(kubectl get nodes --namespace apisix -o jsonpath="{.items[0].status.addresses[0].address}")
sysop@m01serv:~$ echo http://$NODE_IP:$NODE_PORT
http://192.168.102.121:30255
sysop@m01serv:~$ curl -I -H "HOST: www.m01.net" http://192.168.102.121:30255/
HTTP/1.1 404 Not Found
date: Sat, 29 Jan 2022 08:55:05 GMT
content-type: text/plain; charset=utf-8
server: istio-envoy
x-envoy-upstream-service-time: 0
x-envoy-decorator-operation: apisix-gateway.apisix.svc.cluster.local:80/*
transfer-encoding: chunked

sysop@m01serv:~$

Error log

Error log from the apisix ingress controller pod

2022-01-29T08:56:21.328Z | 2022-01-29T16:56:21+08:00 [33mwarn[0m apisix/cluster.go:304 waiting cluster default to ready, it may takes a while
2022-01-29T08:56:23.324Z | 2022-01-29T16:56:23+08:00 [31merror[0m apisix/route.go:117 failed to list routes: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-29T08:56:23.324Z | 2022-01-29T16:56:23+08:00 [31merror[0m apisix/cluster.go:197 failed to list route in APISIX: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-29T08:56:23.787Z | [GIN] 2022/01/29 - 16:56:23 | 200 | 44.029µs | 127.0.0.6 | GET "/healthz"
2022-01-29T08:56:25.324Z | 2022-01-29T16:56:25+08:00 [31merror[0m apisix/route.go:117 failed to list routes: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-29T08:56:25.324Z | 2022-01-29T16:56:25+08:00 [31merror[0m apisix/cluster.go:197 failed to list route in APISIX: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-29T08:56:27.324Z | 2022-01-29T16:56:27+08:00 [31merror[0m apisix/route.go:117 failed to list routes: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-29T08:56:27.324Z | 2022-01-29T16:56:27+08:00 [31merror[0m apisix/cluster.go:197 failed to list route in APISIX: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-29T08:56:29.325Z | 2022-01-29T16:56:29+08:00 [31merror[0m apisix/route.go:117 failed to list routes: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-29T08:56:29.325Z | 2022-01-29T16:56:29+08:00 [31merror[0m apisix/cluster.go:197 failed to list route in APISIX: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-29T08:56:29.325Z | 2022-01-29T16:56:29+08:00 [31merror[0m apisix/cluster.go:164 failed to sync cache {"cost_time": "8.000909058s", "cluster": "default"}
2022-01-29T08:56:29.325Z | 2022-01-29T16:56:29+08:00 [31merror[0m ingress/controller.go:396 failed to wait the default cluster to be ready: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-29T08:56:29.325Z | 2022-01-29T16:56:29+08:00 [34minfo[0m ingress/controller.go:337 controller now is running as a candidate {"namespace": "apisix", "pod": "apisix-ingress-controller-7d5bbf5dd5-fhlz5"}
2022-01-29T08:56:29.325Z | I0129 16:56:29.325223 1 leaderelection.go:243] attempting to acquire leader lease apisix/ingress-apisix-leader...
2022-01-29T08:56:29.325Z | 2022-01-29T16:56:29+08:00 [34minfo[0m apisix/cluster.go:155 syncing cache {"cluster": "default"}
2022-01-29T08:56:29.325Z | 2022-01-29T16:56:29+08:00 [34minfo[0m apisix/cluster.go:344 syncing schema {"cluster": "default"}
2022-01-29T08:56:29.325Z | 2022-01-29T16:56:29+08:00 [31merror[0m apisix/plugin.go:46 failed to list plugins' names: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/plugins/list: context canceled
2022-01-29T08:56:29.325Z | 2022-01-29T16:56:29+08:00 [31merror[0m apisix/cluster.go:364 failed to list plugin names in APISIX: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/plugins/list: context canceled
2022-01-29T08:56:29.325Z | 2022-01-29T16:56:29+08:00 [33mwarn[0m apisix/cluster.go:327 failed to sync schema: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/plugins/list: context canceled
2022-01-29T08:56:29.325Z | 2022-01-29T16:56:29+08:00 [31merror[0m apisix/route.go:117 failed to list routes: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-29T08:56:29.325Z | 2022-01-29T16:56:29+08:00 [31merror[0m apisix/cluster.go:197 failed to list route in APISIX: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-29T08:56:29.331Z | 2022-01-29T16:56:29+08:00 [34minfo[0m ingress/controller.go:290 LeaderElection {"message": "apisix-ingress-controller-7d5bbf5dd5-fhlz5 became leader", "event_type": "Normal"}
2022-01-29T08:56:29.331Z | I0129 16:56:29.331223 1 leaderelection.go:253] successfully acquired lease apisix/ingress-apisix-leader
2022-01-29T08:56:29.331Z | 2022-01-29T16:56:29+08:00 [34minfo[0m ingress/controller.go:370 controller tries to leading ... {"namespace": "apisix", "pod": "apisix-ingress-controller-7d5bbf5dd5-fhlz5"}
2022-01-29T08:56:29.331Z | 2022-01-29T16:56:29+08:00 [33mwarn[0m apisix/cluster.go:304 waiting cluster default to ready, it may takes a while
2022-01-29T08:56:29.399Z | [GIN] 2022/01/29 - 16:56:29 | 200 | 31.11µs | 127.0.0.6 | GET "/healthz"
2022-01-29T08:56:31.325Z | 2022-01-29T16:56:31+08:00 [31merror[0m apisix/route.go:117 failed to list routes: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-29T08:56:31.325Z | 2022-01-29T16:56:31+08:00 [31merror[0m apisix/cluster.go:197 failed to list route in APISIX: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-29T08:56:33.326Z | 2022-01-29T16:56:33+08:00 [31merror[0m apisix/route.go:117 failed to list routes: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-29T08:56:33.326Z | 2022-01-29T16:56:33+08:00 [31merror[0m apisix/cluster.go:197 failed to list route in APISIX: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-29T08:56:33.786Z | [GIN] 2022/01/29 - 16:56:33 | 200 | 33.32µs | 127.0.0.6 | GET "/healthz"
2022-01-29T08:56:35.326Z | 2022-01-29T16:56:35+08:00 [31merror[0m apisix/route.go:117 failed to list routes: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-29T08:56:35.326Z | 2022-01-29T16:56:35+08:00 [31merror[0m apisix/cluster.go:197 failed to list route in APISIX: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-29T08:56:37.326Z | 2022-01-29T16:56:37+08:00 [31merror[0m apisix/route.go:117 failed to list routes: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-29T08:56:37.326Z | 2022-01-29T16:56:37+08:00 [31merror[0m apisix/cluster.go:197 failed to list route in APISIX: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-29T08:56:37.326Z | 2022-01-29T16:56:37+08:00 [31merror[0m apisix/cluster.go:164 failed to sync cache {"cost_time": "8.001302695s", "cluster": "default"}
2022-01-29T08:56:37.326Z | 2022-01-29T16:56:37+08:00 [31merror[0m ingress/controller.go:396 failed to wait the default cluster to be ready: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-29T08:56:37.326Z | 2022-01-29T16:56:37+08:00 [34minfo[0m ingress/controller.go:337 controller now is running as a candidate {"namespace": "apisix", "pod": "apisix-ingress-controller-7d5bbf5dd5-fhlz5"}
2022-01-29T08:56:37.326Z | I0129 16:56:37.326764 1 leaderelection.go:243] attempting to acquire leader lease apisix/ingress-apisix-leader...
2022-01-29T08:56:37.326Z | 2022-01-29T16:56:37+08:00 [34minfo[0m apisix/cluster.go:155 syncing cache {"cluster": "default"}
2022-01-29T08:56:37.326Z | 2022-01-29T16:56:37+08:00 [31merror[0m apisix/route.go:117 failed to list routes: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-29T08:56:37.326Z | 2022-01-29T16:56:37+08:00 [34minfo[0m apisix/cluster.go:344 syncing schema {"cluster": "default"}
2022-01-29T08:56:37.326Z | 2022-01-29T16:56:37+08:00 [31merror[0m apisix/cluster.go:197 failed to list route in APISIX: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-29T08:56:37.327Z | 2022-01-29T16:56:37+08:00 [31merror[0m apisix/plugin.go:46 failed to list plugins' names: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/plugins/list: context canceled
2022-01-29T08:56:37.327Z | 2022-01-29T16:56:37+08:00 [31merror[0m apisix/cluster.go:364 failed to list plugin names in APISIX: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/plugins/list: context canceled
2022-01-29T08:56:37.327Z | 2022-01-29T16:56:37+08:00 [33mwarn[0m apisix/cluster.go:327 failed to sync schema: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/plugins/list: context canceled
2022-01-29T08:56:37.332Z | 2022-01-29T16:56:37+08:00 [34minfo[0m ingress/controller.go:290 LeaderElection {"message": "apisix-ingress-controller-7d5bbf5dd5-fhlz5 became leader", "event_type": "Normal"}
2022-01-29T08:56:37.332Z | I0129 16:56:37.332392 1 leaderelection.go:253] successfully acquired lease apisix/ingress-apisix-leader
2022-01-29T08:56:37.332Z | 2022-01-29T16:56:37+08:00 [34minfo[0m ingress/controller.go:370 controller tries to leading ... {"namespace": "apisix", "pod": "apisix-ingress-controller-7d5bbf5dd5-fhlz5"}
2022-01-29T08:56:37.332Z | 2022-01-29T16:56:37+08:00 [33mwarn[0m apisix/cluster.go:304 waiting cluster default to ready, it may takes a while
2022-01-29T08:56:39.327Z | 2022-01-29T16:56:39+08:00 [31merror[0m apisix/route.go:117 failed to list routes: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-29T08:56:39.327Z | 2022-01-29T16:56:39+08:00 [31merror[0m apisix/cluster.go:197 failed to list route in APISIX: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-29T08:56:39.399Z | [GIN] 2022/01/29 - 16:56:39 | 200 | 31.55µs | 127.0.0.6 | GET "/healthz"
2022-01-29T08:56:41.327Z | 2022-01-29T16:56:41+08:00 [31merror[0m apisix/route.go:117 failed to list routes: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-29T08:56:41.327Z | 2022-01-29T16:56:41+08:00 [31merror[0m apisix/cluster.go:197 failed to list route in APISIX: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-29T08:56:43.327Z | 2022-01-29T16:56:43+08:00 [31merror[0m apisix/route.go:117 failed to list routes: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-29T08:56:43.327Z | 2022-01-29T16:56:43+08:00 [31merror[0m apisix/cluster.go:197 failed to list route in APISIX: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-29T08:56:43.786Z | [GIN] 2022/01/29 - 16:56:43 | 200 | 47.29µs | 127.0.0.6 | GET "/healthz"
2022-01-29T08:56:45.327Z | 2022-01-29T16:56:45+08:00 [31merror[0m apisix/route.go:117 failed to list routes: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-29T08:56:45.327Z | 2022-01-29T16:56:45+08:00 [31merror[0m apisix/cluster.go:197 failed to list route in APISIX: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-29T08:56:45.327Z | 2022-01-29T16:56:45+08:00 [31merror[0m apisix/cluster.go:164 failed to sync cache {"cost_time": "8.000914828s", "cluster": "default"}
2022-01-29T08:56:45.327Z | 2022-01-29T16:56:45+08:00 [31merror[0m ingress/controller.go:396 failed to wait the default cluster to be ready: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-29T08:56:45.327Z | 2022-01-29T16:56:45+08:00 [34minfo[0m ingress/controller.go:337 controller now is running as a candidate {"namespace": "apisix", "pod": "apisix-ingress-controller-7d5bbf5dd5-fhlz5"}
2022-01-29T08:56:45.327Z | I0129 16:56:45.327952 1 leaderelection.go:243] attempting to acquire leader lease apisix/ingress-apisix-leader...
2022-01-29T08:56:45.328Z | 2022-01-29T16:56:45+08:00 [34minfo[0m apisix/cluster.go:155 syncing cache {"cluster": "default"}
2022-01-29T08:56:45.328Z | 2022-01-29T16:56:45+08:00 [34minfo[0m apisix/cluster.go:344 syncing schema {"cluster": "default"}
2022-01-29T08:56:45.328Z | 2022-01-29T16:56:45+08:00 [31merror[0m apisix/route.go:117 failed to list routes: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-29T08:56:45.328Z | 2022-01-29T16:56:45+08:00 [31merror[0m apisix/plugin.go:46 failed to list plugins' names: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/plugins/list: context canceled
2022-01-29T08:56:45.328Z | 2022-01-29T16:56:45+08:00 [31merror[0m apisix/cluster.go:364 failed to list plugin names in APISIX: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/plugins/list: context canceled
2022-01-29T08:56:45.328Z | 2022-01-29T16:56:45+08:00 [33mwarn[0m apisix/cluster.go:327 failed to sync schema: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/plugins/list: context canceled
2022-01-29T08:56:45.328Z | 2022-01-29T16:56:45+08:00 [31merror[0m apisix/cluster.go:197 failed to list route in APISIX: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-29T08:56:45.334Z | 2022-01-29T16:56:45+08:00 [34minfo[0m ingress/controller.go:290 LeaderElection {"message": "apisix-ingress-controller-7d5bbf5dd5-fhlz5 became leader", "event_type": "Normal"}
2022-01-29T08:56:45.334Z | I0129 16:56:45.334679 1 leaderelection.go:253] successfully acquired lease apisix/ingress-apisix-leader
2022-01-29T08:56:45.334Z | 2022-01-29T16:56:45+08:00 [34minfo[0m ingress/controller.go:370 controller tries to leading ... {"namespace": "apisix", "pod": "apisix-ingress-controller-7d5bbf5dd5-fhlz5"}
2022-01-29T08:56:45.334Z | 2022-01-29T16:56:45+08:00 [33mwarn[0m apisix/cluster.go:304 waiting cluster default to ready, it may takes a while
2022-01-29T08:56:47.328Z | 2022-01-29T16:56:47+08:00 [31merror[0m apisix/route.go:117 failed to list routes: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-29T08:56:47.328Z | 2022-01-29T16:56:47+08:00 [31merror[0m apisix/cluster.go:197 failed to list route in APISIX: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-29T08:56:49.328Z | 2022-01-29T16:56:49+08:00 [31merror[0m apisix/route.go:117 failed to list routes: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-29T08:56:49.328Z | 2022-01-29T16:56:49+08:00 [31merror[0m apisix/cluster.go:197 failed to list route in APISIX: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-29T08:56:49.399Z | [GIN] 2022/01/29 - 16:56:49 | 200 | 35.049µs | 127.0.0.6 | GET "/healthz"
2022-01-29T08:56:51.328Z | 2022-01-29T16:56:51+08:00 [31merror[0m apisix/route.go:117 failed to list routes: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-29T08:56:51.328Z | 2022-01-29T16:56:51+08:00 [31merror[0m apisix/cluster.go:197 failed to list route in APISIX: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-29T08:56:53.329Z | 2022-01-29T16:56:53+08:00 [31merror[0m apisix/route.go:117 failed to list routes: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-29T08:56:53.329Z | 2022-01-29T16:56:53+08:00 [31merror[0m apisix/cluster.go:197 failed to list route in APISIX: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-29T08:56:53.329Z | 2022-01-29T16:56:53+08:00 [31merror[0m apisix/cluster.go:164 failed to sync cache {"cost_time": "8.001004415s", "cluster": "default"}
2022-01-29T08:56:53.329Z | 2022-01-29T16:56:53+08:00 [31merror[0m ingress/controller.go:396 failed to wait the default cluster to be ready: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-29T08:56:53.329Z | 2022-01-29T16:56:53+08:00 [34minfo[0m ingress/controller.go:337 controller now is running as a candidate {"namespace": "apisix", "pod": "apisix-ingress-controller-7d5bbf5dd5-fhlz5"}
2022-01-29T08:56:53.329Z | I0129 16:56:53.329161 1 leaderelection.go:243] attempting to acquire leader lease apisix/ingress-apisix-leader...
2022-01-29T08:56:53.329Z | 2022-01-29T16:56:53+08:00 [34minfo[0m apisix/cluster.go:155 syncing cache {"cluster": "default"}
2022-01-29T08:56:53.329Z | 2022-01-29T16:56:53+08:00 [34minfo[0m apisix/cluster.go:344 syncing schema {"cluster": "default"}
2022-01-29T08:56:53.329Z | 2022-01-29T16:56:53+08:00 [31merror[0m apisix/route.go:117 failed to list routes: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-29T08:56:53.329Z | 2022-01-29T16:56:53+08:00 [31merror[0m apisix/cluster.go:197 failed to list route in APISIX: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-29T08:56:53.329Z | 2022-01-29T16:56:53+08:00 [31merror[0m apisix/plugin.go:46 failed to list plugins' names: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/plugins/list: context canceled
2022-01-29T08:56:53.329Z | 2022-01-29T16:56:53+08:00 [31merror[0m apisix/cluster.go:364 failed to list plugin names in APISIX: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/plugins/list: context canceled
2022-01-29T08:56:53.329Z | 2022-01-29T16:56:53+08:00 [33mwarn[0m apisix/cluster.go:327 failed to sync schema: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/plugins/list: context canceled
2022-01-29T08:56:53.337Z | 2022-01-29T16:56:53+08:00 [34minfo[0m ingress/controller.go:290 LeaderElection {"message": "apisix-ingress-controller-7d5bbf5dd5-fhlz5 became leader", "event_type": "Normal"}
2022-01-29T08:56:53.337Z | I0129 16:56:53.337314 1 leaderelection.go:253] successfully acquired lease apisix/ingress-apisix-leader
2022-01-29T08:56:53.337Z | 2022-01-29T16:56:53+08:00 [34minfo[0m ingress/controller.go:370 controller tries to leading ... {"namespace": "apisix", "pod": "apisix-ingress-controller-7d5bbf5dd5-fhlz5"}
2022-01-29T08:56:53.337Z | 2022-01-29T16:56:53+08:00 [33mwarn[0m apisix/cluster.go:304 waiting cluster default to ready, it may takes a while
2022-01-29T08:56:53.786Z | [GIN] 2022/01/29 - 16:56:53 | 200 | 47.4µs | 127.0.0.6 | GET "/healthz"

Expected result

The route was found and the HTML return code is 200

About this issue

Original URL
State: closed
Created 2 years ago
Reactions: 1
Comments: 23 (14 by maintainers)

Most upvoted comments

If you are running apisix 2.12.0, I found that even though this doc says that stream_proxy is configured if enable_admin: true it appears it does not. I added the snippet from the doc:

apisix:
  stream_proxy: # TCP/UDP proxy
    tcp: # TCP proxy address list
      - 9100
      - "127.0.0.1:9101"
    udp: # UDP proxy address list
      - 9200
      - "127.0.0.1:9211"

and once I restarted apisix, the ingress-controller also started working and those errors went away.

gamer22026 on Jan 31, 2022

UPDATE I reinstalled apisix from scratch and looked at the apisix-ingress-controller log before ever trying to create a route. The pod is trapped in a loop between the “GET /healtz” messages

[GIN] 2022/01/30 - 19:41:39 | 200 | 35.789µs | 127.0.0.6 | GET "/healthz"
[GIN] 2022/01/30 - 19:41:39 | 200 | 819.067µs | 127.0.0.6 | GET "/healthz"
2022-01-30T19:41:41+08:00 [31merror[0m apisix/route.go:117 failed to list routes: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-30T19:41:41+08:00 [31merror[0m apisix/cluster.go:197 failed to list route in APISIX: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-30T19:41:43+08:00 [31merror[0m apisix/route.go:117 failed to list routes: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-30T19:41:43+08:00 [31merror[0m apisix/cluster.go:197 failed to list route in APISIX: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-30T19:41:45+08:00 [31merror[0m apisix/route.go:117 failed to list routes: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-30T19:41:45+08:00 [31merror[0m apisix/cluster.go:197 failed to list route in APISIX: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-30T19:41:45+08:00 [31merror[0m apisix/cluster.go:164 failed to sync cache {"cost_time": "8.000983025s", "cluster": "default"}
2022-01-30T19:41:45+08:00 [31merror[0m ingress/controller.go:396 failed to wait the default cluster to be ready: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-30T19:41:45+08:00 [34minfo[0m ingress/controller.go:337 controller now is running as a candidate {"namespace": "apisix", "pod": "apisix-ingress-controller-7d5bbf5dd5-4dr2m"}
I0130 19:41:45.428676 1 leaderelection.go:243] attempting to acquire leader lease apisix/ingress-apisix-leader...
2022-01-30T19:41:45+08:00 [34minfo[0m apisix/cluster.go:155 syncing cache {"cluster": "default"}
2022-01-30T19:41:45+08:00 [34minfo[0m apisix/cluster.go:344 syncing schema {"cluster": "default"}
2022-01-30T19:41:45+08:00 [31merror[0m apisix/route.go:117 failed to list routes: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-30T19:41:45+08:00 [31merror[0m apisix/cluster.go:197 failed to list route in APISIX: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-30T19:41:45+08:00 [31merror[0m apisix/plugin.go:46 failed to list plugins' names: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/plugins/list: context canceled
2022-01-30T19:41:45+08:00 [31merror[0m apisix/cluster.go:364 failed to list plugin names in APISIX: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/plugins/list: context canceled
2022-01-30T19:41:45+08:00 [33mwarn[0m apisix/cluster.go:327 failed to sync schema: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/plugins/list: context canceled
2022-01-30T19:41:45+08:00 [34minfo[0m ingress/controller.go:290 LeaderElection {"message": "apisix-ingress-controller-7d5bbf5dd5-4dr2m became leader", "event_type": "Normal"}
I0130 19:41:45.432763 1 leaderelection.go:253] successfully acquired lease apisix/ingress-apisix-leader
2022-01-30T19:41:45+08:00 [34minfo[0m ingress/controller.go:370 controller tries to leading ... {"namespace": "apisix", "pod": "apisix-ingress-controller-7d5bbf5dd5-4dr2m"}
2022-01-30T19:41:45+08:00 [33mwarn[0m apisix/cluster.go:304 waiting cluster default to ready, it may takes a while
2022-01-30T19:41:47+08:00 [31merror[0m apisix/route.go:117 failed to list routes: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-30T19:41:47+08:00 [31merror[0m apisix/cluster.go:197 failed to list route in APISIX: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-30T19:41:49+08:00 [31merror[0m apisix/route.go:117 failed to list routes: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
2022-01-30T19:41:49+08:00 [31merror[0m apisix/cluster.go:197 failed to list route in APISIX: Get http://apisix-admin.apisix.svc.cluster.local:9180/apisix/admin/routes: context canceled
[GIN] 2022/01/30 - 19:41:49 | 200 | 31.261µs | 127.0.0.6 | GET "/healthz"
[GIN] 2022/01/30 - 19:41:49 | 200 | 35.169µs | 127.0.0.6 | GET "/healthz"

This loop is repeated continuously. Hope this helps

MirtoBusico on Jan 30, 2022