kube-router icon indicating copy to clipboard operation
kube-router copied to clipboard

kube-router crashloop backoff without obvious cause on brand new cluster

Open Xaelias opened this issue 9 months ago • 5 comments

What happened? Hi. I am in the process of re-installing my homelab k8s cluster from scratch (it was outdated in many ways) and I had kube-router working, but I can't seem to figure out how to set it up again. It keeps crashing (failing liveness probe) without any obvious cause I could find. I'm also trying to enable BGP (which I had setup previously) but that doesn't seem to be the route cause.

What did you expect to happen? I expect kube-router to work, and BGP w/ my firewall to work.

How can we reproduce the behavior you experienced? Steps to reproduce the behavior:

  1. Fresh install of ubuntu 24.04 (swap disabled, ipv4 ip_forward set to 1)
  2. [optional] Set annotations for BGP
❯ kubectl annotate node k8s-master-000 kube-router.io/peer.ips=10.19.90.1
❯ kubectl annotate node k8s-master-000 kube-router.io/peer.asns=64513

(I also tried to set this in the yaml manifest without any change, plus this seem to work) 3. Install kube-router

KUBECONFIG=/etc/kubernetes/admin.conf kubectl apply -f https://raw.githubusercontent.com/cloudnativelabs/kube-router/master/daemonset/kubeadm-kuberouter-all-features.yaml
  1. Watch as kube-router eventually stops itself (liveness probe).

** System Information (please complete the following information):**

  • Kube-Router Version (kube-router --version): Running kube-router version v2.1.1, built on 2024-04-27T21:51:12+0000, go1.21.7
  • Kube-Router Parameters: --run-router=true --run-firewall=true --run-service-proxy=true --bgp-graceful-restart=true --kubeconfig=/var/lib/kube-router/kubeconfig
  • Kubernetes Version (kubectl version) : 1.30.0
  • Cloud Type: bare metal
  • Kubernetes Deployment Type: kubeadm
  • Kube-Router Deployment Type: DaemonSet
  • Cluster Size: 1

** Logs, other output, metrics **

logs
kube-router-gcc7j kube-router 2024-05-12T13:28:03.947391739-05:00 I0512 18:28:03.947202   19577 version.go:66] Running /usr/local/bin/kube-router version v2.1.1, built on 2024-04-27T21:51:12+0000, go1.21.7
kube-router-gcc7j kube-router 2024-05-12T13:28:04.049544598-05:00 I0512 18:28:04.049344   19577 kube-router.go:137] Metrics port must be over 0 and under 65535 in order to be enabled, given port: 0
kube-router-gcc7j kube-router 2024-05-12T13:28:04.049569301-05:00 I0512 18:28:04.049408   19577 kube-router.go:139] Disabling metrics for kube-router, set --metrics-port properly in order to enable
kube-router-gcc7j kube-router 2024-05-12T13:28:04.060999054-05:00 I0512 18:28:04.060783   19577 network_routes_controller.go:1643] Could not find annotation `kube-router.io/bgp-local-addresses` on node object so BGP will listen on node IP: [10.19.91.100] addresses.
kube-router-gcc7j kube-router 2024-05-12T13:28:04.086103370-05:00 I0512 18:28:04.085927   19577 network_services_controller.go:241] Starting network services controller
kube-router-gcc7j kube-router 2024-05-12T13:28:04.090012726-05:00 I0512 18:28:04.089824   19577 network_routes_controller.go:267] Setting MTU of kube-bridge interface to: 1500
kube-router-gcc7j kube-router 2024-05-12T13:28:04.091856484-05:00 I0512 18:28:04.091690   19577 network_routes_controller.go:315] Starting network route controller
kube-router-gcc7j kube-router 2024-05-12T13:28:04.096425450-05:00 I0512 18:28:04.096280   19577 network_routes_controller.go:1297] Could not find BGP peer password info in the node's annotations. Assuming no passwords.
kube-router-gcc7j kube-router 2024-05-12T13:28:04.096439186-05:00 I0512 18:28:04.096324   19577 network_routes_controller.go:1314] Could not find BGP peer local ip info in the node's annotations. Assuming node IP.
kube-router-gcc7j kube-router 2024-05-12T13:28:04.096834679-05:00 time="2024-05-12T18:28:04Z" level=info msg="Add a peer configuration" Key=10.19.90.1 Topic=Peer
kube-router-gcc7j kube-router 2024-05-12T13:28:04.106684737-05:00 I0512 18:28:04.106513   19577 bgp_policies.go:772] Did not match any existing policies, starting import policy with default name: kube_router_export0
kube-router-gcc7j kube-router 2024-05-12T13:28:04.106698798-05:00 I0512 18:28:04.106538   19577 bgp_policies.go:781] Current policy does not appear to match new policy: kube_router_export - creating new policy
kube-router-gcc7j kube-router 2024-05-12T13:28:04.106701891-05:00 I0512 18:28:04.106607   19577 bgp_policies.go:787] Ensuring that policy kube_router_export1 is assigned
kube-router-gcc7j kube-router 2024-05-12T13:28:04.106953321-05:00 I0512 18:28:04.106877   19577 bgp_policies.go:929] Did not match any existing policies, starting import policy with default name: kube_router_import0
kube-router-gcc7j kube-router 2024-05-12T13:28:04.106959598-05:00 I0512 18:28:04.106913   19577 bgp_policies.go:938] Current policy does not appear to match new policy: kube_router_import - creating new policy
kube-router-gcc7j kube-router 2024-05-12T13:28:04.107037775-05:00 I0512 18:28:04.106976   19577 bgp_policies.go:944] Ensuring that policy kube_router_import1 is assigned
kube-router-gcc7j kube-router 2024-05-12T13:28:04.145833414-05:00 I0512 18:28:04.145614   19577 network_policy_controller.go:163] Starting network policy controller
kube-router-gcc7j kube-router 2024-05-12T13:28:04.200385691-05:00 I0512 18:28:04.200186   19577 network_policy_controller.go:175] Starting network policy controller full sync goroutine
kube-router-gcc7j kube-router 2024-05-12T13:28:11.100230681-05:00 time="2024-05-12T18:28:11Z" level=info msg="Peer Up" Key=10.19.90.1 State=BGP_FSM_OPENCONFIRM Topic=Peer
kube-router-gcc7j kube-router 2024-05-12T13:28:11.100276476-05:00 time="2024-05-12T18:28:11Z" level=info msg="sync finished" Key=10.19.90.1 Topic=Server
kube-router-gcc7j kube-router 2024-05-12T13:29:25.538503329-05:00 I0512 18:29:25.538282   19577 kube-router.go:266] Shutting down the controllers
kube-router-gcc7j kube-router 2024-05-12T13:29:25.538559204-05:00 I0512 18:29:25.538430   19577 nodeport_healthcheck.go:170] Stopping all NodePort health checks
kube-router-gcc7j kube-router 2024-05-12T13:29:25.538571990-05:00 I0512 18:29:25.538461   19577 nodeport_healthcheck.go:172] Waiting for all NodePort health checks to finish shutting down
kube-router-gcc7j kube-router 2024-05-12T13:29:25.538592493-05:00 I0512 18:29:25.538471   19577 nodeport_healthcheck.go:174] All NodePort health checks are completely shut down, all done!
kube-router-gcc7j kube-router 2024-05-12T13:29:25.538600956-05:00 I0512 18:29:25.538492   19577 health_controller.go:208] Shutting down health controller
kube-router-gcc7j kube-router 2024-05-12T13:29:25.538608832-05:00 I0512 18:29:25.538503   19577 network_services_controller.go:338] Shutting down network services controller
kube-router-gcc7j kube-router 2024-05-12T13:29:25.538659884-05:00 I0512 18:29:25.538553   19577 network_policy_controller.go:189] Shutting down network policies full sync goroutine
kube-router-gcc7j kube-router 2024-05-12T13:29:25.538677540-05:00 I0512 18:29:25.538573   19577 network_policy_controller.go:204] Shutting down network policies controller
kube-router-gcc7j kube-router 2024-05-12T13:29:25.538684257-05:00 E0512 18:29:25.538570   19577 health_controller.go:199] Health controller error: http: Server closed
kube-router-gcc7j kube-router 2024-05-12T13:29:25.538696533-05:00 I0512 18:29:25.538645   19577 network_routes_controller.go:407] Shutting down network routes controller
kube-router-gcc7j kube-router 2024-05-12T13:29:25.538756684-05:00 I0512 18:29:25.538683   19577 route_sync.go:64] Shutting down local route synchronization
kube-router-gcc7j kube-router 2024-05-12T13:29:25.538773942-05:00 I0512 18:29:25.538703   19577 health_controller.go:224] Shutting down HealthController RunCheck
Events
Events:
  Type     Reason          Age                   From               Message
  ----     ------          ----                  ----               -------
  Normal   Scheduled       12m                   default-scheduler  Successfully assigned kube-system/kube-router-gcc7j to k8s-master-000
  Normal   Pulled          12m                   kubelet            Successfully pulled image "docker.io/cloudnativelabs/kube-router" in 445ms (445ms including waiting). Image size: 102687278 bytes.
  Normal   Pulled          12m                   kubelet            Successfully pulled image "docker.io/cloudnativelabs/kube-router" in 384ms (384ms including waiting). Image size: 102687278 bytes.
  Warning  Unhealthy       11m                   kubelet            Liveness probe failed: Get "http://10.19.91.100:20244/healthz": dial tcp 10.19.91.100:20244: connect: connection refused
  Normal   Pulled          11m                   kubelet            Successfully pulled image "docker.io/cloudnativelabs/kube-router" in 440ms (440ms including waiting). Image size: 102687278 bytes.
  Normal   Pulling         11m (x2 over 12m)     kubelet            Pulling image "docker.io/cloudnativelabs/kube-router"
  Normal   Started         11m (x2 over 12m)     kubelet            Started container kube-router
  Normal   Created         11m (x2 over 12m)     kubelet            Created container kube-router
  Normal   Pulled          11m                   kubelet            Successfully pulled image "docker.io/cloudnativelabs/kube-router" in 413ms (413ms including waiting). Image size: 102687278 bytes.
  Normal   SandboxChanged  10m (x2 over 11m)     kubelet            Pod sandbox changed, it will be killed and re-created.
  Normal   Pulling         10m (x3 over 12m)     kubelet            Pulling image "docker.io/cloudnativelabs/kube-router"
  Normal   Started         10m (x3 over 12m)     kubelet            Started container install-cni
  Normal   Created         10m (x3 over 12m)     kubelet            Created container install-cni
  Normal   Pulled          10m                   kubelet            Successfully pulled image "docker.io/cloudnativelabs/kube-router" in 454ms (454ms including waiting). Image size: 102687278 bytes.
  Normal   Killing         7m21s (x3 over 11m)   kubelet            Stopping container kube-router
  Warning  BackOff         2m36s (x14 over 10m)  kubelet            Back-off restarting failed container kube-router in pod kube-router-gcc7j_kube-system(ddd069bf-e37e-4c9a-8c52-d09eab082d12)

Thanks in advance for the help. LMK if I missed anything. I would happily troubleshoot this myself but with this amount of information I don't know where to start.

Xaelias avatar May 12 '24 18:05 Xaelias

Hmm... That's pretty odd. I agree that you should be seeing some kind of error.

The health of the pod is reported by the health check controller, this is what changes the status of the /healthz endpoint and reports it back to the kubelet that checks it to see if it's healthy. If it is not healthy, I would expect an error in the logs like you can see here: https://github.com/cloudnativelabs/kube-router/blob/master/pkg/healthcheck/health_controller.go#L139-L181

I would try increasing all of the health checks (especially initialDelaySeconds) and see if you can get an error out of the health check controller about what is not healthy. You could also try increasing the verbosity of the logging with the -v flag and see if that gets you anything.

aauren avatar May 12 '24 23:05 aauren

ngl I tried increasing the log level by feeding... things to -v and it was unhappy with any value I tried xD but I'm sure it was a pebcak type of thing. I'll try again while I attempt your suggestion. thx!

[EDIT] re: log level - that was definitely a pebcak I don't know what I was doing...

Xaelias avatar May 12 '24 23:05 Xaelias

Logs `-v=3`, `initialDelaySeconds: 120`
+ kube-router-qx29r › install-cni
kube-router-qx29r install-cni 2024-05-12T19:28:55.437656494-05:00 + '[' '!' -f /etc/cni/net.d/10-kuberouter.conflist ]
kube-router-qx29r install-cni 2024-05-12T19:28:55.437729361-05:00 + '[' -x /usr/local/bin/cni-install ]
kube-router-qx29r install-cni 2024-05-12T19:28:55.437786881-05:00 + /usr/local/bin/cni-install
kube-router-qx29r install-cni 2024-05-12T19:28:55.440715768-05:00 + KUBE_ROUTER_CNI_BINS=("bridge" "portmap" "host-local" "loopback")
kube-router-qx29r install-cni 2024-05-12T19:28:55.440740905-05:00 + LOCAL_BIN_PATH=/usr/libexec/cni
kube-router-qx29r install-cni 2024-05-12T19:28:55.440757252-05:00 + HOST_BIN_PATH=/opt/cni/bin
kube-router-qx29r install-cni 2024-05-12T19:28:55.440946686-05:00 + setup_cni
kube-router-qx29r install-cni 2024-05-12T19:28:55.440975850-05:00 + local cni_bin cni_dst_path cni_loc_path
kube-router-qx29r install-cni 2024-05-12T19:28:55.440990183-05:00 + [[ ! -d /opt/cni/bin ]]
kube-router-qx29r install-cni 2024-05-12T19:28:55.441088452-05:00 + for cni_bin in "${KUBE_ROUTER_CNI_BINS[@]}"
kube-router-qx29r install-cni 2024-05-12T19:28:55.441108767-05:00 + cni_dst_path=/opt/cni/bin/bridge
kube-router-qx29r install-cni 2024-05-12T19:28:55.441118860-05:00 + cni_loc_path=/usr/libexec/cni/bridge
kube-router-qx29r install-cni 2024-05-12T19:28:55.441146550-05:00 + [[ -x /opt/cni/bin/bridge ]]
kube-router-qx29r install-cni 2024-05-12T19:28:55.441235071-05:00 + printf 'CNI binary %s already exists and is executable, skipping\n' /opt/cni/bin/bridge
kube-router-qx29r install-cni 2024-05-12T19:28:55.441259489-05:00 + continue
kube-router-qx29r install-cni 2024-05-12T19:28:55.441262258-05:00 CNI binary /opt/cni/bin/bridge already exists and is executable, skipping
kube-router-qx29r install-cni 2024-05-12T19:28:55.441270606-05:00 + for cni_bin in "${KUBE_ROUTER_CNI_BINS[@]}"
kube-router-qx29r install-cni 2024-05-12T19:28:55.441325853-05:00 + cni_dst_path=/opt/cni/bin/portmap
kube-router-qx29r install-cni 2024-05-12T19:28:55.441344015-05:00 + cni_loc_path=/usr/libexec/cni/portmap
kube-router-qx29r install-cni 2024-05-12T19:28:55.441353213-05:00 + [[ -x /opt/cni/bin/portmap ]]
kube-router-qx29r install-cni 2024-05-12T19:28:55.441429013-05:00 + printf 'CNI binary %s already exists and is executable, skipping\n' /opt/cni/bin/portmap
kube-router-qx29r install-cni 2024-05-12T19:28:55.441444789-05:00 + continue
kube-router-qx29r install-cni 2024-05-12T19:28:55.441450204-05:00 + for cni_bin in "${KUBE_ROUTER_CNI_BINS[@]}"
kube-router-qx29r install-cni 2024-05-12T19:28:55.441444949-05:00 CNI binary /opt/cni/bin/portmap already exists and is executable, skipping
kube-router-qx29r install-cni 2024-05-12T19:28:55.441529302-05:00 + cni_dst_path=/opt/cni/bin/host-local
kube-router-qx29r install-cni 2024-05-12T19:28:55.441543056-05:00 + cni_loc_path=/usr/libexec/cni/host-local
kube-router-qx29r install-cni 2024-05-12T19:28:55.441583183-05:00 + [[ -x /opt/cni/bin/host-local ]]
kube-router-qx29r install-cni 2024-05-12T19:28:55.441653296-05:00 + printf 'CNI binary %s already exists and is executable, skipping\n' /opt/cni/bin/host-local
kube-router-qx29r install-cni 2024-05-12T19:28:55.441658883-05:00 + continue
kube-router-qx29r install-cni 2024-05-12T19:28:55.441657090-05:00 CNI binary /opt/cni/bin/host-local already exists and is executable, skipping
kube-router-qx29r install-cni 2024-05-12T19:28:55.441674926-05:00 + for cni_bin in "${KUBE_ROUTER_CNI_BINS[@]}"
kube-router-qx29r install-cni 2024-05-12T19:28:55.441752227-05:00 + cni_dst_path=/opt/cni/bin/loopback
kube-router-qx29r install-cni 2024-05-12T19:28:55.441768872-05:00 + cni_loc_path=/usr/libexec/cni/loopback
kube-router-qx29r install-cni 2024-05-12T19:28:55.441844167-05:00 + [[ -x /opt/cni/bin/loopback ]]
kube-router-qx29r install-cni 2024-05-12T19:28:55.441901381-05:00 + printf 'CNI binary %s already exists and is executable, skipping\n' /opt/cni/bin/loopback
kube-router-qx29r install-cni 2024-05-12T19:28:55.441914787-05:00 + continue
kube-router-qx29r install-cni 2024-05-12T19:28:55.441922404-05:00 CNI binary /opt/cni/bin/loopback already exists and is executable, skipping
kube-router-qx29r install-cni 2024-05-12T19:28:55.441984723-05:00 + printf 'CNI setup completed successfully!'
kube-router-qx29r install-cni 2024-05-12T19:28:55.442021481-05:00 + return 0
kube-router-qx29r install-cni 2024-05-12T19:28:55.442084813-05:00 + exit 0
kube-router-qx29r install-cni 2024-05-12T19:28:55.442734823-05:00 CNI setup completed successfully!
- kube-router-qx29r › install-cni
+ kube-router-qx29r › kube-router
kube-router-qx29r kube-router 2024-05-12T19:28:56.733176502-05:00 I0513 00:28:56.732923   52913 version.go:66] Running /usr/local/bin/kube-router version v2.1.1, built on 2024-04-27T21:51:12+0000, go1.21.7
kube-router-qx29r kube-router 2024-05-12T19:28:56.734568522-05:00 I0513 00:28:56.734393   52913 reflector.go:289] Starting reflector *v1.Namespace (0s) from pkg/mod/k8s.io/[email protected]/tools/cache/reflector.go:229
kube-router-qx29r kube-router 2024-05-12T19:28:56.734591325-05:00 I0513 00:28:56.734417   52913 reflector.go:325] Listing and watching *v1.Namespace from pkg/mod/k8s.io/[email protected]/tools/cache/reflector.go:229
kube-router-qx29r kube-router 2024-05-12T19:28:56.734644740-05:00 I0513 00:28:56.734567   52913 reflector.go:289] Starting reflector *v1.Node (0s) from pkg/mod/k8s.io/[email protected]/tools/cache/reflector.go:229
kube-router-qx29r kube-router 2024-05-12T19:28:56.734650363-05:00 I0513 00:28:56.734574   52913 reflector.go:289] Starting reflector *v1.Pod (0s) from pkg/mod/k8s.io/[email protected]/tools/cache/reflector.go:229
kube-router-qx29r kube-router 2024-05-12T19:28:56.734654550-05:00 I0513 00:28:56.734620   52913 reflector.go:325] Listing and watching *v1.Node from pkg/mod/k8s.io/[email protected]/tools/cache/reflector.go:229
kube-router-qx29r kube-router 2024-05-12T19:28:56.734658518-05:00 I0513 00:28:56.734627   52913 reflector.go:325] Listing and watching *v1.Pod from pkg/mod/k8s.io/[email protected]/tools/cache/reflector.go:229
kube-router-qx29r kube-router 2024-05-12T19:28:56.734785146-05:00 I0513 00:28:56.734669   52913 reflector.go:289] Starting reflector *v1.Endpoints (0s) from pkg/mod/k8s.io/[email protected]/tools/cache/reflector.go:229
kube-router-qx29r kube-router 2024-05-12T19:28:56.734813843-05:00 I0513 00:28:56.734671   52913 reflector.go:289] Starting reflector *v1.Service (0s) from pkg/mod/k8s.io/[email protected]/tools/cache/reflector.go:229
kube-router-qx29r kube-router 2024-05-12T19:28:56.734820849-05:00 I0513 00:28:56.734675   52913 reflector.go:289] Starting reflector *v1.EndpointSlice (0s) from pkg/mod/k8s.io/[email protected]/tools/cache/reflector.go:229
kube-router-qx29r kube-router 2024-05-12T19:28:56.734847444-05:00 I0513 00:28:56.734739   52913 reflector.go:325] Listing and watching *v1.EndpointSlice from pkg/mod/k8s.io/[email protected]/tools/cache/reflector.go:229
kube-router-qx29r kube-router 2024-05-12T19:28:56.734859701-05:00 I0513 00:28:56.734730   52913 reflector.go:289] Starting reflector *v1.NetworkPolicy (0s) from pkg/mod/k8s.io/[email protected]/tools/cache/reflector.go:229
kube-router-qx29r kube-router 2024-05-12T19:28:56.734863196-05:00 I0513 00:28:56.734764   52913 reflector.go:325] Listing and watching *v1.NetworkPolicy from pkg/mod/k8s.io/[email protected]/tools/cache/reflector.go:229
kube-router-qx29r kube-router 2024-05-12T19:28:56.734882818-05:00 I0513 00:28:56.734726   52913 reflector.go:325] Listing and watching *v1.Service from pkg/mod/k8s.io/[email protected]/tools/cache/reflector.go:229
kube-router-qx29r kube-router 2024-05-12T19:28:56.734926393-05:00 I0513 00:28:56.734714   52913 reflector.go:325] Listing and watching *v1.Endpoints from pkg/mod/k8s.io/[email protected]/tools/cache/reflector.go:229
kube-router-qx29r kube-router 2024-05-12T19:28:56.751079941-05:00 I0513 00:28:56.750885   52913 reflector.go:351] Caches populated for *v1.NetworkPolicy from pkg/mod/k8s.io/[email protected]/tools/cache/reflector.go:229
kube-router-qx29r kube-router 2024-05-12T19:28:56.751096211-05:00 I0513 00:28:56.750929   52913 reflector.go:351] Caches populated for *v1.EndpointSlice from pkg/mod/k8s.io/[email protected]/tools/cache/reflector.go:229
kube-router-qx29r kube-router 2024-05-12T19:28:56.751100411-05:00 I0513 00:28:56.750955   52913 reflector.go:351] Caches populated for *v1.Endpoints from pkg/mod/k8s.io/[email protected]/tools/cache/reflector.go:229
kube-router-qx29r kube-router 2024-05-12T19:28:56.751104451-05:00 I0513 00:28:56.750909   52913 reflector.go:351] Caches populated for *v1.Namespace from pkg/mod/k8s.io/[email protected]/tools/cache/reflector.go:229
kube-router-qx29r kube-router 2024-05-12T19:28:56.751501755-05:00 I0513 00:28:56.751294   52913 reflector.go:351] Caches populated for *v1.Service from pkg/mod/k8s.io/[email protected]/tools/cache/reflector.go:229
kube-router-qx29r kube-router 2024-05-12T19:28:56.751521198-05:00 I0513 00:28:56.751405   52913 reflector.go:351] Caches populated for *v1.Node from pkg/mod/k8s.io/[email protected]/tools/cache/reflector.go:229
kube-router-qx29r kube-router 2024-05-12T19:28:56.760926510-05:00 I0513 00:28:56.760731   52913 reflector.go:351] Caches populated for *v1.Pod from pkg/mod/k8s.io/[email protected]/tools/cache/reflector.go:229
kube-router-qx29r kube-router 2024-05-12T19:28:56.835184228-05:00 I0513 00:28:56.834997   52913 kube-router.go:137] Metrics port must be over 0 and under 65535 in order to be enabled, given port: 0
kube-router-qx29r kube-router 2024-05-12T19:28:56.835207345-05:00 I0513 00:28:56.835020   52913 kube-router.go:139] Disabling metrics for kube-router, set --metrics-port properly in order to enable
kube-router-qx29r kube-router 2024-05-12T19:28:56.848430001-05:00 I0513 00:28:56.848184   52913 network_routes_controller.go:1643] Could not find annotation `kube-router.io/bgp-local-addresses` on node object so BGP will listen on node IP: [10.19.91.100] addresses.
kube-router-qx29r kube-router 2024-05-12T19:28:56.848451864-05:00 I0513 00:28:56.848356   52913 bgp_peers.go:375] Received node 10.19.91.100 added update from watch API so peer with new node
kube-router-qx29r kube-router 2024-05-12T19:28:56.848466861-05:00 I0513 00:28:56.848415   52913 ecmp_vip.go:282] Skipping OnAdd event to endpoint, controller still performing bootup full-sync
kube-router-qx29r kube-router 2024-05-12T19:28:56.848471678-05:00 I0513 00:28:56.848427   52913 ecmp_vip.go:282] Skipping OnAdd event to endpoint, controller still performing bootup full-sync
kube-router-qx29r kube-router 2024-05-12T19:28:56.848477028-05:00 I0513 00:28:56.848420   52913 ecmp_vip.go:207] attempting to update service default:kubernetes
kube-router-qx29r kube-router 2024-05-12T19:28:56.848488981-05:00 I0513 00:28:56.848455   52913 ecmp_vip.go:139] Skipping update to service: default/kubernetes, controller still performing bootup full-sync
kube-router-qx29r kube-router 2024-05-12T19:28:56.848493778-05:00 I0513 00:28:56.848472   52913 ecmp_vip.go:207] attempting to update service kube-system:kube-dns
kube-router-qx29r kube-router 2024-05-12T19:28:56.848522504-05:00 I0513 00:28:56.848479   52913 ecmp_vip.go:139] Skipping update to service: kube-system/kube-dns, controller still performing bootup full-sync
kube-router-qx29r kube-router 2024-05-12T19:28:56.850150159-05:00 I0513 00:28:56.850010   52913 network_routes_controller.go:169] Populating ipsets.
kube-router-qx29r kube-router 2024-05-12T19:28:56.850176176-05:00 I0513 00:28:56.850028   52913 network_routes_controller.go:962] Attempting to attain ipset mutex lock
kube-router-qx29r kube-router 2024-05-12T19:28:56.850181449-05:00 I0513 00:28:56.850036   52913 network_routes_controller.go:964] Attained ipset mutex lock, continuing...
kube-router-qx29r kube-router 2024-05-12T19:28:56.850186866-05:00 I0513 00:28:56.850100   52913 ipset.go:569] ipset restore looks like: create TMP-PRBJ7ASFQM5DJR3Q hash:ip timeout 0
kube-router-qx29r kube-router 2024-05-12T19:28:56.850191696-05:00 flush TMP-PRBJ7ASFQM5DJR3Q
kube-router-qx29r kube-router 2024-05-12T19:28:56.850196399-05:00 add TMP-PRBJ7ASFQM5DJR3Q 10.19.91.100 timeout 0
kube-router-qx29r kube-router 2024-05-12T19:28:56.850200696-05:00 create kube-router-node-ips hash:ip timeout 0
kube-router-qx29r kube-router 2024-05-12T19:28:56.850204896-05:00 swap TMP-PRBJ7ASFQM5DJR3Q kube-router-node-ips
kube-router-qx29r kube-router 2024-05-12T19:28:56.850233639-05:00 flush TMP-PRBJ7ASFQM5DJR3Q
kube-router-qx29r kube-router 2024-05-12T19:28:56.850242379-05:00 create TMP-LP6R7TXZCLIUYMBN hash:net timeout 0
kube-router-qx29r kube-router 2024-05-12T19:28:56.850246639-05:00 flush TMP-LP6R7TXZCLIUYMBN
kube-router-qx29r kube-router 2024-05-12T19:28:56.850251233-05:00 add TMP-LP6R7TXZCLIUYMBN 10.200.0.0/24 timeout 0
kube-router-qx29r kube-router 2024-05-12T19:28:56.850255923-05:00 create kube-router-pod-subnets hash:net timeout 0
kube-router-qx29r kube-router 2024-05-12T19:28:56.850260429-05:00 swap TMP-LP6R7TXZCLIUYMBN kube-router-pod-subnets
kube-router-qx29r kube-router 2024-05-12T19:28:56.850264826-05:00 flush TMP-LP6R7TXZCLIUYMBN
kube-router-qx29r kube-router 2024-05-12T19:28:56.850269069-05:00 destroy TMP-LP6R7TXZCLIUYMBN
kube-router-qx29r kube-router 2024-05-12T19:28:56.850273736-05:00 destroy TMP-PRBJ7ASFQM5DJR3Q
kube-router-qx29r kube-router 2024-05-12T19:28:56.851693139-05:00 I0513 00:28:56.851501   52913 network_routes_controller.go:967] Returned ipset mutex lock
kube-router-qx29r kube-router 2024-05-12T19:28:56.859506173-05:00 I0513 00:28:56.859348   52913 network_routes_controller.go:191] Tunnel Overlay enabled in configuration.
kube-router-qx29r kube-router 2024-05-12T19:28:56.859527543-05:00 I0513 00:28:56.859373   52913 network_routes_controller.go:192] Setting up overlay networking.
kube-router-qx29r kube-router 2024-05-12T19:28:56.859533470-05:00 I0513 00:28:56.859422   52913 linux_routing.go:30] Did not find iproute2's rt_tables in location /etc/iproute2/rt_tables
kube-router-qx29r kube-router 2024-05-12T19:28:56.859549597-05:00 I0513 00:28:56.859492   52913 linux_routing.go:30] Did not find iproute2's rt_tables in location /usr/share/iproute2/rt_tables
kube-router-qx29r kube-router 2024-05-12T19:28:56.864540470-05:00 I0513 00:28:56.864344   52913 network_routes_controller.go:215] Performing cleanup of depreciated rules/ipsets (if needed).
kube-router-qx29r kube-router 2024-05-12T19:28:56.871134775-05:00 I0513 00:28:56.870937   52913 network_routes_controller.go:223] Enabling Pod egress.
kube-router-qx29r kube-router 2024-05-12T19:28:56.873494216-05:00 I0513 00:28:56.873338   52913 pod_egress.go:48] Added iptables rule to masquerade outbound traffic from pods.
kube-router-qx29r kube-router 2024-05-12T19:28:56.874613545-05:00 I0513 00:28:56.874439   52913 network_services_controller.go:241] Starting network services controller
kube-router-qx29r kube-router 2024-05-12T19:28:56.874627516-05:00 I0513 00:28:56.874458   52913 network_services_controller.go:243] Performing cleanup of depreciated masquerade iptables rules (if needed).
kube-router-qx29r kube-router 2024-05-12T19:28:56.874631128-05:00 I0513 00:28:56.874473   52913 network_services_controller.go:857] Received update to service: default/kubernetes from watch API
kube-router-qx29r kube-router 2024-05-12T19:28:56.874637350-05:00 I0513 00:28:56.874501   52913 network_services_controller.go:859] Skipping update to service: default/kubernetes as controller is not ready to process service and endpoints updates
kube-router-qx29r kube-router 2024-05-12T19:28:56.874640991-05:00 I0513 00:28:56.874531   52913 network_services_controller.go:808] Received update to EndpointSlice: default/kubernetes from watch API
kube-router-qx29r kube-router 2024-05-12T19:28:56.874644163-05:00 I0513 00:28:56.874549   52913 network_services_controller.go:810] Skipping update to EndpointSlice: default/kubernetes as controller is not ready to process service and endpoints updates
kube-router-qx29r kube-router 2024-05-12T19:28:56.874647266-05:00 I0513 00:28:56.874562   52913 network_services_controller.go:808] Received update to EndpointSlice: kube-system/kube-dns-ll848 from watch API
kube-router-qx29r kube-router 2024-05-12T19:28:56.874651387-05:00 I0513 00:28:56.874577   52913 network_services_controller.go:810] Skipping update to EndpointSlice: kube-system/kube-dns-ll848 as controller is not ready to process service and endpoints updates
kube-router-qx29r kube-router 2024-05-12T19:28:56.874662543-05:00 I0513 00:28:56.874595   52913 network_services_controller.go:857] Received update to service: kube-system/kube-dns from watch API
kube-router-qx29r kube-router 2024-05-12T19:28:56.874665772-05:00 I0513 00:28:56.874615   52913 network_services_controller.go:859] Skipping update to service: kube-system/kube-dns as controller is not ready to process service and endpoints updates
kube-router-qx29r kube-router 2024-05-12T19:28:56.875113512-05:00 I0513 00:28:56.874984   52913 network_routes_controller.go:267] Setting MTU of kube-bridge interface to: 1500
kube-router-qx29r kube-router 2024-05-12T19:28:56.876899835-05:00 I0513 00:28:56.876743   52913 network_routes_controller.go:315] Starting network route controller
kube-router-qx29r kube-router 2024-05-12T19:28:56.880699219-05:00 I0513 00:28:56.880524   52913 network_routes_controller.go:1145] Did not find any BGP communities on current node's annotations. Not exporting communities.
kube-router-qx29r kube-router 2024-05-12T19:28:56.880715275-05:00 I0513 00:28:56.880567   52913 network_routes_controller.go:1167] Did not find any node.bgp.customimportreject on current node's annotations. Skip configuring it.
kube-router-qx29r kube-router 2024-05-12T19:28:56.881582494-05:00 time="2024-05-13T00:28:56Z" level=info msg="Add a peer configuration" Key=10.19.90.1 Topic=Peer
kube-router-qx29r kube-router 2024-05-12T19:28:56.881613765-05:00 I0513 00:28:56.881541   52913 bgp_peers.go:283] Successfully configured 10.19.90.1 in ASN 64513 as BGP peer to the node
kube-router-qx29r kube-router 2024-05-12T19:28:56.881672448-05:00 I0513 00:28:56.881609   52913 network_routes_controller.go:360] Syncing ipsets
kube-router-qx29r kube-router 2024-05-12T19:28:56.881679021-05:00 I0513 00:28:56.881623   52913 network_routes_controller.go:962] Attempting to attain ipset mutex lock
kube-router-qx29r kube-router 2024-05-12T19:28:56.881683795-05:00 I0513 00:28:56.881634   52913 network_routes_controller.go:964] Attained ipset mutex lock, continuing...
kube-router-qx29r kube-router 2024-05-12T19:28:56.881794202-05:00 I0513 00:28:56.881722   52913 ipset.go:569] ipset restore looks like: create TMP-PRBJ7ASFQM5DJR3Q hash:ip timeout 0
kube-router-qx29r kube-router 2024-05-12T19:28:56.881801852-05:00 flush TMP-PRBJ7ASFQM5DJR3Q
kube-router-qx29r kube-router 2024-05-12T19:28:56.881806569-05:00 add TMP-PRBJ7ASFQM5DJR3Q 10.19.91.100 timeout 0
kube-router-qx29r kube-router 2024-05-12T19:28:56.881811619-05:00 create kube-router-node-ips hash:ip timeout 0
kube-router-qx29r kube-router 2024-05-12T19:28:56.881834382-05:00 swap TMP-PRBJ7ASFQM5DJR3Q kube-router-node-ips
kube-router-qx29r kube-router 2024-05-12T19:28:56.881839499-05:00 flush TMP-PRBJ7ASFQM5DJR3Q
kube-router-qx29r kube-router 2024-05-12T19:28:56.881844802-05:00 create TMP-LP6R7TXZCLIUYMBN hash:net timeout 0
kube-router-qx29r kube-router 2024-05-12T19:28:56.881849072-05:00 flush TMP-LP6R7TXZCLIUYMBN
kube-router-qx29r kube-router 2024-05-12T19:28:56.881853532-05:00 add TMP-LP6R7TXZCLIUYMBN 10.200.0.0/24 timeout 0
kube-router-qx29r kube-router 2024-05-12T19:28:56.881858546-05:00 create kube-router-pod-subnets hash:net timeout 0
kube-router-qx29r kube-router 2024-05-12T19:28:56.881862682-05:00 swap TMP-LP6R7TXZCLIUYMBN kube-router-pod-subnets
kube-router-qx29r kube-router 2024-05-12T19:28:56.881867172-05:00 flush TMP-LP6R7TXZCLIUYMBN
kube-router-qx29r kube-router 2024-05-12T19:28:56.881871232-05:00 destroy TMP-LP6R7TXZCLIUYMBN
kube-router-qx29r kube-router 2024-05-12T19:28:56.881875622-05:00 destroy TMP-PRBJ7ASFQM5DJR3Q
kube-router-qx29r kube-router 2024-05-12T19:28:56.883643081-05:00 I0513 00:28:56.883447   52913 network_routes_controller.go:967] Returned ipset mutex lock
kube-router-qx29r kube-router 2024-05-12T19:28:56.889153260-05:00 I0513 00:28:56.888954   52913 network_services_controller.go:1194] Successfully synced iptables masquerade rule
kube-router-qx29r kube-router 2024-05-12T19:28:56.889811573-05:00 I0513 00:28:56.889620   52913 network_routes_controller.go:379] Performing periodic sync of service VIP routes
kube-router-qx29r kube-router 2024-05-12T19:28:56.889832457-05:00 I0513 00:28:56.889648   52913 ecmp_vip.go:30] Advertising route: '10.201.0.1/32 via 10.19.91.100' to peers
kube-router-qx29r kube-router 2024-05-12T19:28:56.890675407-05:00 I0513 00:28:56.890491   52913 ecmp_vip.go:30] Advertising route: '10.201.0.10/32 via 10.19.91.100' to peers
kube-router-qx29r kube-router 2024-05-12T19:28:56.890707027-05:00 I0513 00:28:56.890639   52913 network_routes_controller.go:383] Performing periodic sync of pod CIDR routes
kube-router-qx29r kube-router 2024-05-12T19:28:56.890712901-05:00 I0513 00:28:56.890660   52913 network_routes_controller.go:505] Advertising route: '10.200.0.0/24 via 10.19.91.100' to peers
kube-router-qx29r kube-router 2024-05-12T19:28:56.891877530-05:00 I0513 00:28:56.890751   52913 network_routes_controller.go:529] Response from adding path: uuid:"\x0f%\xfc\xd4\xc4 K\x02\xb8P\xaf\x9e_H\xdaK"
kube-router-qx29r kube-router 2024-05-12T19:28:56.892499469-05:00 I0513 00:28:56.892318   52913 bgp_policies.go:772] Did not match any existing policies, starting import policy with default name: kube_router_export0
kube-router-qx29r kube-router 2024-05-12T19:28:56.892521483-05:00 I0513 00:28:56.892339   52913 bgp_policies.go:781] Current policy does not appear to match new policy: kube_router_export - creating new policy
kube-router-qx29r kube-router 2024-05-12T19:28:56.892527130-05:00 I0513 00:28:56.892373   52913 bgp_policies.go:787] Ensuring that policy kube_router_export1 is assigned
kube-router-qx29r kube-router 2024-05-12T19:28:56.892641590-05:00 I0513 00:28:56.892578   52913 bgp_policies.go:929] Did not match any existing policies, starting import policy with default name: kube_router_import0
kube-router-qx29r kube-router 2024-05-12T19:28:56.892648693-05:00 I0513 00:28:56.892595   52913 bgp_policies.go:938] Current policy does not appear to match new policy: kube_router_import - creating new policy
kube-router-qx29r kube-router 2024-05-12T19:28:56.892667894-05:00 I0513 00:28:56.892623   52913 bgp_policies.go:944] Ensuring that policy kube_router_import1 is assigned
kube-router-qx29r kube-router 2024-05-12T19:28:56.892714634-05:00 I0513 00:28:56.892667   52913 bgp_peers.go:36] Syncing BGP peers for the node took 5.174µs
kube-router-qx29r kube-router 2024-05-12T19:28:56.892743086-05:00 I0513 00:28:56.892701   52913 health_controller.go:91] Received heartbeat from NRC
kube-router-qx29r kube-router 2024-05-12T19:28:56.931798125-05:00 I0513 00:28:56.931609   52913 network_services_controller.go:1194] Successfully synced iptables masquerade rule
kube-router-qx29r kube-router 2024-05-12T19:28:56.931819816-05:00 I0513 00:28:56.931673   52913 network_services_controller.go:1054] Building endpoint info for EndpointSlice: default/kubernetes
kube-router-qx29r kube-router 2024-05-12T19:28:56.931825142-05:00 I0513 00:28:56.931692   52913 network_services_controller.go:1054] Building endpoint info for EndpointSlice: kube-system/kube-dns-ll848
kube-router-qx29r kube-router 2024-05-12T19:28:56.931830286-05:00 I0513 00:28:56.931741   52913 network_services_controller.go:1351] No IPv4 hairpin-mode enabled services found -- no hairpin rules created
kube-router-qx29r kube-router 2024-05-12T19:28:56.934287161-05:00 I0513 00:28:56.934085   52913 pod.go:53] Received update to pod: kube-system/coredns-7db6d8ff4d-kqbfq
kube-router-qx29r kube-router 2024-05-12T19:28:56.934326687-05:00 I0513 00:28:56.934120   52913 network_policy_controller.go:215] Full sync request queue was empty so a full sync request was successfully sent
kube-router-qx29r kube-router 2024-05-12T19:28:56.934331941-05:00 I0513 00:28:56.934132   52913 pod.go:53] Received update to pod: kube-system/coredns-7db6d8ff4d-ztj72
kube-router-qx29r kube-router 2024-05-12T19:28:56.934336621-05:00 I0513 00:28:56.934142   52913 network_policy_controller.go:217] Full sync request queue was full, skipping...
kube-router-qx29r kube-router 2024-05-12T19:28:56.934340951-05:00 I0513 00:28:56.934175   52913 network_policy_controller.go:163] Starting network policy controller
kube-router-qx29r kube-router 2024-05-12T19:28:56.934345394-05:00 I0513 00:28:56.934178   52913 namespace.go:40] Received update for namespace: default
kube-router-qx29r kube-router 2024-05-12T19:28:56.934350254-05:00 I0513 00:28:56.934228   52913 service_endpoints_sync.go:42] Syncing ClusterIP Services
kube-router-qx29r kube-router 2024-05-12T19:28:56.934366758-05:00 I0513 00:28:56.934235   52913 network_policy_controller.go:217] Full sync request queue was full, skipping...
kube-router-qx29r kube-router 2024-05-12T19:28:56.934371584-05:00 I0513 00:28:56.934289   52913 namespace.go:40] Received update for namespace: kube-node-lease
kube-router-qx29r kube-router 2024-05-12T19:28:56.934376114-05:00 I0513 00:28:56.934299   52913 network_policy_controller.go:217] Full sync request queue was full, skipping...
kube-router-qx29r kube-router 2024-05-12T19:28:56.934380301-05:00 I0513 00:28:56.934309   52913 namespace.go:40] Received update for namespace: kube-public
kube-router-qx29r kube-router 2024-05-12T19:28:56.934384658-05:00 I0513 00:28:56.934315   52913 network_policy_controller.go:217] Full sync request queue was full, skipping...
kube-router-qx29r kube-router 2024-05-12T19:28:56.934389101-05:00 I0513 00:28:56.934320   52913 namespace.go:40] Received update for namespace: kube-system
kube-router-qx29r kube-router 2024-05-12T19:28:56.934393428-05:00 I0513 00:28:56.934333   52913 network_policy_controller.go:217] Full sync request queue was full, skipping...
kube-router-qx29r kube-router 2024-05-12T19:28:56.937254248-05:00 I0513 00:28:56.937028   52913 linux_networking.go:233] Comparing vip (10.201.0.1:10.201.0.10) protocol (6:6) and port (443:53)
kube-router-qx29r kube-router 2024-05-12T19:28:56.937276481-05:00 I0513 00:28:56.937058   52913 linux_networking.go:233] Comparing vip (10.201.0.1:10.201.0.10) protocol (6:17) and port (443:53)
kube-router-qx29r kube-router 2024-05-12T19:28:56.937281801-05:00 I0513 00:28:56.937070   52913 linux_networking.go:233] Comparing vip (10.201.0.1:10.201.0.10) protocol (6:6) and port (443:9153)
kube-router-qx29r kube-router 2024-05-12T19:28:56.937286165-05:00 I0513 00:28:56.937082   52913 linux_networking.go:233] Comparing vip (10.201.0.1:10.201.0.1) protocol (6:6) and port (443:443)
kube-router-qx29r kube-router 2024-05-12T19:28:56.937290972-05:00 I0513 00:28:56.937095   52913 linux_networking.go:236] Service matched VIP
kube-router-qx29r kube-router 2024-05-12T19:28:56.937295882-05:00 I0513 00:28:56.937139   52913 linux_networking.go:272] ipvs service [tcp]:[2]:[10.201.0.1]:[32]:443 (Flags: [hashed entry]) already exists so returning
kube-router-qx29r kube-router 2024-05-12T19:28:56.937367222-05:00 I0513 00:28:56.937292   52913 linux_networking.go:416] ipvs destination 10.19.91.100:6443 (Family: IPv4, Weight: 1) already exists in the ipvs service [tcp]:[2]:[10.201.0.1]:[32]:443 (Flags: [hashed entry]) so not adding destination
kube-router-qx29r kube-router 2024-05-12T19:28:56.939381861-05:00 I0513 00:28:56.939169   52913 linux_networking.go:233] Comparing vip (10.201.0.10:10.201.0.10) protocol (17:6) and port (53:53)
kube-router-qx29r kube-router 2024-05-12T19:28:56.939403085-05:00 I0513 00:28:56.939199   52913 linux_networking.go:233] Comparing vip (10.201.0.10:10.201.0.10) protocol (17:17) and port (53:53)
kube-router-qx29r kube-router 2024-05-12T19:28:56.939408585-05:00 I0513 00:28:56.939227   52913 linux_networking.go:236] Service matched VIP
kube-router-qx29r kube-router 2024-05-12T19:28:56.939413475-05:00 I0513 00:28:56.939256   52913 linux_networking.go:272] ipvs service [udp]:[2]:[10.201.0.10]:[32]:53 (Flags: [hashed entry]) already exists so returning
kube-router-qx29r kube-router 2024-05-12T19:28:56.939435508-05:00 I0513 00:28:56.939361   52913 linux_networking.go:416] ipvs destination 10.200.0.5:53 (Family: IPv4, Weight: 1) already exists in the ipvs service [udp]:[2]:[10.201.0.10]:[32]:53 (Flags: [hashed entry]) so not adding destination
kube-router-qx29r kube-router 2024-05-12T19:28:56.939515062-05:00 I0513 00:28:56.939460   52913 linux_networking.go:416] ipvs destination 10.200.0.4:53 (Family: IPv4, Weight: 1) already exists in the ipvs service [udp]:[2]:[10.201.0.10]:[32]:53 (Flags: [hashed entry]) so not adding destination
kube-router-qx29r kube-router 2024-05-12T19:28:56.941618352-05:00 I0513 00:28:56.941425   52913 network_policy_controller.go:448] Ensuring jump to chain KUBE-ROUTER-INPUT from INPUT at position 1
kube-router-qx29r kube-router 2024-05-12T19:28:56.942279005-05:00 I0513 00:28:56.942069   52913 linux_networking.go:233] Comparing vip (10.201.0.10:10.201.0.10) protocol (6:6) and port (53:53)
kube-router-qx29r kube-router 2024-05-12T19:28:56.942300635-05:00 I0513 00:28:56.942100   52913 linux_networking.go:236] Service matched VIP
kube-router-qx29r kube-router 2024-05-12T19:28:56.942305995-05:00 I0513 00:28:56.942129   52913 linux_networking.go:272] ipvs service [tcp]:[2]:[10.201.0.10]:[32]:53 (Flags: [hashed entry]) already exists so returning
kube-router-qx29r kube-router 2024-05-12T19:28:56.942324852-05:00 I0513 00:28:56.942273   52913 linux_networking.go:416] ipvs destination 10.200.0.4:53 (Family: IPv4, Weight: 1) already exists in the ipvs service [tcp]:[2]:[10.201.0.10]:[32]:53 (Flags: [hashed entry]) so not adding destination
kube-router-qx29r kube-router 2024-05-12T19:28:56.942431079-05:00 I0513 00:28:56.942380   52913 linux_networking.go:416] ipvs destination 10.200.0.5:53 (Family: IPv4, Weight: 1) already exists in the ipvs service [tcp]:[2]:[10.201.0.10]:[32]:53 (Flags: [hashed entry]) so not adding destination
kube-router-qx29r kube-router 2024-05-12T19:28:56.944892291-05:00 I0513 00:28:56.944699   52913 linux_networking.go:233] Comparing vip (10.201.0.10:10.201.0.10) protocol (6:6) and port (9153:53)
kube-router-qx29r kube-router 2024-05-12T19:28:56.944914104-05:00 I0513 00:28:56.944729   52913 linux_networking.go:233] Comparing vip (10.201.0.10:10.201.0.10) protocol (6:17) and port (9153:53)
kube-router-qx29r kube-router 2024-05-12T19:28:56.944919381-05:00 I0513 00:28:56.944741   52913 linux_networking.go:233] Comparing vip (10.201.0.10:10.201.0.10) protocol (6:6) and port (9153:9153)
kube-router-qx29r kube-router 2024-05-12T19:28:56.944924391-05:00 I0513 00:28:56.944754   52913 linux_networking.go:236] Service matched VIP
kube-router-qx29r kube-router 2024-05-12T19:28:56.944929834-05:00 I0513 00:28:56.944784   52913 linux_networking.go:272] ipvs service [tcp]:[2]:[10.201.0.10]:[32]:9153 (Flags: [hashed entry]) already exists so returning
kube-router-qx29r kube-router 2024-05-12T19:28:56.944960203-05:00 I0513 00:28:56.944912   52913 linux_networking.go:416] ipvs destination 10.200.0.5:9153 (Family: IPv4, Weight: 1) already exists in the ipvs service [tcp]:[2]:[10.201.0.10]:[32]:9153 (Flags: [hashed entry]) so not adding destination
kube-router-qx29r kube-router 2024-05-12T19:28:56.945048422-05:00 I0513 00:28:56.944990   52913 linux_networking.go:416] ipvs destination 10.200.0.4:9153 (Family: IPv4, Weight: 1) already exists in the ipvs service [tcp]:[2]:[10.201.0.10]:[32]:9153 (Flags: [hashed entry]) so not adding destination
kube-router-qx29r kube-router 2024-05-12T19:28:56.945057748-05:00 I0513 00:28:56.945005   52913 service_endpoints_sync.go:49] Syncing NodePort Services
kube-router-qx29r kube-router 2024-05-12T19:28:56.945171945-05:00 I0513 00:28:56.945126   52913 service_endpoints_sync.go:56] Syncing ExternalIP Services
kube-router-qx29r kube-router 2024-05-12T19:28:56.945178522-05:00 I0513 00:28:56.945146   52913 service_endpoints_sync.go:362] no external IP addresses returned for service default:kubernetes skipping...
kube-router-qx29r kube-router 2024-05-12T19:28:56.945196509-05:00 I0513 00:28:56.945158   52913 service_endpoints_sync.go:362] no external IP addresses returned for service kube-system:kube-dns skipping...
kube-router-qx29r kube-router 2024-05-12T19:28:56.945201332-05:00 I0513 00:28:56.945169   52913 service_endpoints_sync.go:362] no external IP addresses returned for service kube-system:kube-dns skipping...
kube-router-qx29r kube-router 2024-05-12T19:28:56.945235036-05:00 I0513 00:28:56.945179   52913 service_endpoints_sync.go:362] no external IP addresses returned for service kube-system:kube-dns skipping...
kube-router-qx29r kube-router 2024-05-12T19:28:56.945257219-05:00 I0513 00:28:56.945192   52913 service_endpoints_sync.go:64] Setting up NodePort Health Checks for LB services
kube-router-qx29r kube-router 2024-05-12T19:28:56.945274886-05:00 I0513 00:28:56.945202   52913 nodeport_healthcheck.go:38] Running UpdateServicesInfo for NodePort health check
kube-router-qx29r kube-router 2024-05-12T19:28:56.945298723-05:00 I0513 00:28:56.945228   52913 nodeport_healthcheck.go:70] Finished UpdateServicesInfo for NodePort health check
kube-router-qx29r kube-router 2024-05-12T19:28:56.945321203-05:00 I0513 00:28:56.945245   52913 service_endpoints_sync.go:71] Cleaning Up Stale VIPs from dummy interface
kube-router-qx29r kube-router 2024-05-12T19:28:56.945342346-05:00 I0513 00:28:56.945256   52913 service_endpoints_sync.go:628] Cleaning up if any, old service IPs on dummy interface
kube-router-qx29r kube-router 2024-05-12T19:28:56.945768865-05:00 I0513 00:28:56.945608   52913 service_endpoints_sync.go:649] Found an IP fe80::f420:77ff:fe8b:24b which is no longer needed so cleaning up
kube-router-qx29r kube-router 2024-05-12T19:28:56.945779710-05:00 I0513 00:28:56.945633   52913 linux_networking.go:86] Ignoring link-local IP address: fe80::f420:77ff:fe8b:24b
kube-router-qx29r kube-router 2024-05-12T19:28:56.945783483-05:00 I0513 00:28:56.945650   52913 service_endpoints_sync.go:78] Cleaning Up Stale VIPs from IPVS
kube-router-qx29r kube-router 2024-05-12T19:28:56.945792737-05:00 I0513 00:28:56.945748   52913 service_endpoints_sync.go:692] Cleaning up if any, old ipvs service and servers which are no longer needed
kube-router-qx29r kube-router 2024-05-12T19:28:56.945860605-05:00 I0513 00:28:56.945816   52913 service_endpoints_sync.go:695] Current active service map:
kube-router-qx29r kube-router 2024-05-12T19:28:56.945864697-05:00 {
kube-router-qx29r kube-router 2024-05-12T19:28:56.945867495-05:00       "10.201.0.1-tcp-443": [
kube-router-qx29r kube-router 2024-05-12T19:28:56.945870175-05:00           "10.19.91.100:6443"
kube-router-qx29r kube-router 2024-05-12T19:28:56.945872692-05:00       ],
kube-router-qx29r kube-router 2024-05-12T19:28:56.945875371-05:00       "10.201.0.10-tcp-53": [
kube-router-qx29r kube-router 2024-05-12T19:28:56.945878301-05:00           "10.200.0.4:53",
kube-router-qx29r kube-router 2024-05-12T19:28:56.945880676-05:00           "10.200.0.5:53"
kube-router-qx29r kube-router 2024-05-12T19:28:56.945883384-05:00       ],
kube-router-qx29r kube-router 2024-05-12T19:28:56.945885904-05:00       "10.201.0.10-tcp-9153": [
kube-router-qx29r kube-router 2024-05-12T19:28:56.945888241-05:00           "10.200.0.5:9153",
kube-router-qx29r kube-router 2024-05-12T19:28:56.945890896-05:00           "10.200.0.4:9153"
kube-router-qx29r kube-router 2024-05-12T19:28:56.945893671-05:00       ],
kube-router-qx29r kube-router 2024-05-12T19:28:56.945896189-05:00       "10.201.0.10-udp-53": [
kube-router-qx29r kube-router 2024-05-12T19:28:56.945898572-05:00           "10.200.0.5:53",
kube-router-qx29r kube-router 2024-05-12T19:28:56.945900977-05:00           "10.200.0.4:53"
kube-router-qx29r kube-router 2024-05-12T19:28:56.945903684-05:00       ]
kube-router-qx29r kube-router 2024-05-12T19:28:56.945906137-05:00   }
kube-router-qx29r kube-router 2024-05-12T19:28:56.946186084-05:00 I0513 00:28:56.946139   52913 service_endpoints_sync.go:85] Cleaning Up Stale metrics
kube-router-qx29r kube-router 2024-05-12T19:28:56.946190017-05:00 I0513 00:28:56.946162   52913 service_endpoints_sync.go:88] Syncing IPVS Firewall
kube-router-qx29r kube-router 2024-05-12T19:28:56.946196610-05:00 I0513 00:28:56.946172   52913 network_services_controller.go:628] Attempting to attain ipset mutex lock
kube-router-qx29r kube-router 2024-05-12T19:28:56.946199362-05:00 I0513 00:28:56.946181   52913 network_services_controller.go:630] Attained ipset mutex lock, continuing...
kube-router-qx29r kube-router 2024-05-12T19:28:56.947665691-05:00 I0513 00:28:56.947451   52913 ipset.go:569] ipset restore looks like: create TMP-PRBJ7ASFQM5DJR3Q hash:ip timeout 0
kube-router-qx29r kube-router 2024-05-12T19:28:56.947697191-05:00 flush TMP-PRBJ7ASFQM5DJR3Q
kube-router-qx29r kube-router 2024-05-12T19:28:56.947702921-05:00 add TMP-PRBJ7ASFQM5DJR3Q 127.0.0.1 timeout 0
kube-router-qx29r kube-router 2024-05-12T19:28:56.947707154-05:00 add TMP-PRBJ7ASFQM5DJR3Q 10.19.91.100 timeout 0
kube-router-qx29r kube-router 2024-05-12T19:28:56.947712284-05:00 create kube-router-local-ips hash:ip timeout 0
kube-router-qx29r kube-router 2024-05-12T19:28:56.947717157-05:00 swap TMP-PRBJ7ASFQM5DJR3Q kube-router-local-ips
kube-router-qx29r kube-router 2024-05-12T19:28:56.947721398-05:00 flush TMP-PRBJ7ASFQM5DJR3Q
kube-router-qx29r kube-router 2024-05-12T19:28:56.947725654-05:00 add TMP-PRBJ7ASFQM5DJR3Q 10.201.0.10 timeout 0
kube-router-qx29r kube-router 2024-05-12T19:28:56.947729818-05:00 add TMP-PRBJ7ASFQM5DJR3Q 10.201.0.10 timeout 0
kube-router-qx29r kube-router 2024-05-12T19:28:56.947734601-05:00 add TMP-PRBJ7ASFQM5DJR3Q 10.201.0.10 timeout 0
kube-router-qx29r kube-router 2024-05-12T19:28:56.947739901-05:00 add TMP-PRBJ7ASFQM5DJR3Q 10.201.0.1 timeout 0
kube-router-qx29r kube-router 2024-05-12T19:28:56.947743944-05:00 create kube-router-svip hash:ip timeout 0
kube-router-qx29r kube-router 2024-05-12T19:28:56.947748591-05:00 swap TMP-PRBJ7ASFQM5DJR3Q kube-router-svip
kube-router-qx29r kube-router 2024-05-12T19:28:56.947752774-05:00 flush TMP-PRBJ7ASFQM5DJR3Q
kube-router-qx29r kube-router 2024-05-12T19:28:56.947757698-05:00 create TMP-TF3INM4IEYGA443O hash:ip,port timeout 0
kube-router-qx29r kube-router 2024-05-12T19:28:56.947783831-05:00 flush TMP-TF3INM4IEYGA443O
kube-router-qx29r kube-router 2024-05-12T19:28:56.947788394-05:00 add TMP-TF3INM4IEYGA443O 10.201.0.10,tcp:53 timeout 0
kube-router-qx29r kube-router 2024-05-12T19:28:56.947792708-05:00 add TMP-TF3INM4IEYGA443O 10.201.0.10,udp:53 timeout 0
kube-router-qx29r kube-router 2024-05-12T19:28:56.947797405-05:00 add TMP-TF3INM4IEYGA443O 10.201.0.10,tcp:9153 timeout 0
kube-router-qx29r kube-router 2024-05-12T19:28:56.947801805-05:00 add TMP-TF3INM4IEYGA443O 10.201.0.1,tcp:443 timeout 0
kube-router-qx29r kube-router 2024-05-12T19:28:56.947806185-05:00 create kube-router-svip-prt hash:ip,port timeout 0
kube-router-qx29r kube-router 2024-05-12T19:28:56.947814705-05:00 swap TMP-TF3INM4IEYGA443O kube-router-svip-prt
kube-router-qx29r kube-router 2024-05-12T19:28:56.947819098-05:00 flush TMP-TF3INM4IEYGA443O
kube-router-qx29r kube-router 2024-05-12T19:28:56.947823371-05:00 destroy TMP-PRBJ7ASFQM5DJR3Q
kube-router-qx29r kube-router 2024-05-12T19:28:56.947827631-05:00 destroy TMP-TF3INM4IEYGA443O
kube-router-qx29r kube-router 2024-05-12T19:28:56.949428467-05:00 I0513 00:28:56.949295   52913 network_services_controller.go:633] Returned ipset mutex lock
kube-router-qx29r kube-router 2024-05-12T19:28:56.949444527-05:00 I0513 00:28:56.949333   52913 service_endpoints_sync.go:95] Setting up DSR Services
kube-router-qx29r kube-router 2024-05-12T19:28:56.949448041-05:00 I0513 00:28:56.949344   52913 service_endpoints_sync.go:605] Setting up policy routing required for Direct Server Return functionality.
kube-router-qx29r kube-router 2024-05-12T19:28:56.949451541-05:00 I0513 00:28:56.949369   52913 linux_routing.go:30] Did not find iproute2's rt_tables in location /etc/iproute2/rt_tables
kube-router-qx29r kube-router 2024-05-12T19:28:56.949460547-05:00 I0513 00:28:56.949397   52913 linux_routing.go:30] Did not find iproute2's rt_tables in location /usr/share/iproute2/rt_tables
kube-router-qx29r kube-router 2024-05-12T19:28:56.952177114-05:00 I0513 00:28:56.952034   52913 service_endpoints_sync.go:610] Custom routing table kube-router-dsr required for Direct Server Return is setup as expected.
kube-router-qx29r kube-router 2024-05-12T19:28:56.952223886-05:00 I0513 00:28:56.952057   52913 service_endpoints_sync.go:613] Setting up custom route table required to add routes for external IP's.
kube-router-qx29r kube-router 2024-05-12T19:28:56.952232642-05:00 I0513 00:28:56.952080   52913 linux_routing.go:30] Did not find iproute2's rt_tables in location /etc/iproute2/rt_tables
kube-router-qx29r kube-router 2024-05-12T19:28:56.952238029-05:00 I0513 00:28:56.952105   52913 linux_routing.go:30] Did not find iproute2's rt_tables in location /usr/share/iproute2/rt_tables
kube-router-qx29r kube-router 2024-05-12T19:28:56.952987936-05:00 I0513 00:28:56.952816   52913 network_policy_controller.go:448] Ensuring jump to chain KUBE-ROUTER-FORWARD from FORWARD at position 1
kube-router-qx29r kube-router 2024-05-12T19:28:56.955713322-05:00 I0513 00:28:56.955544   52913 service_endpoints_sync.go:621] Custom routing table required for Direct Server Return (external_ip) is setup as expected.
kube-router-qx29r kube-router 2024-05-12T19:28:56.955734535-05:00 I0513 00:28:56.955580   52913 service_endpoints_sync.go:107] IPVS servers and services are synced to desired state
kube-router-qx29r kube-router 2024-05-12T19:28:56.955739872-05:00 I0513 00:28:56.955590   52913 service_endpoints_sync.go:32] sync ipvs services took 21.386252ms
kube-router-qx29r kube-router 2024-05-12T19:28:56.959718821-05:00 I0513 00:28:56.959549   52913 network_policy_controller.go:448] Ensuring jump to chain KUBE-ROUTER-OUTPUT from OUTPUT at position 1
kube-router-qx29r kube-router 2024-05-12T19:28:56.963955941-05:00 I0513 00:28:56.963762   52913 network_policy_controller.go:462] Allow traffic to ingress towards Cluster IP Range: 10.96.0.0/12 for family: IPv4
kube-router-qx29r kube-router 2024-05-12T19:28:56.978966162-05:00 I0513 00:28:56.978793   52913 network_policy_controller.go:480] Allow TCP traffic to ingress towards node port range: 30000:32767 for family: IPv4
kube-router-qx29r kube-router 2024-05-12T19:28:56.988266056-05:00 I0513 00:28:56.988061   52913 network_policy_controller.go:386] Rule '-p tcp -m comment --comment allow LOCAL TCP traffic to node ports - LR7XO7NXDBGQJD2M -m addrtype --dst-type LOCAL -m multiport --dports 30000:32767 -j RETURN' doesn't exist in chain KUBE-ROUTER-INPUT, inserting at position 2
kube-router-qx29r kube-router 2024-05-12T19:28:56.995530961-05:00 I0513 00:28:56.995361   52913 network_policy_controller.go:493] Allow UDP traffic to ingress towards node port range: 30000:32767 for family: IPv4
kube-router-qx29r kube-router 2024-05-12T19:28:57.007153939-05:00 I0513 00:28:57.006984   52913 network_policy_controller.go:386] Rule '-p udp -m comment --comment allow LOCAL UDP traffic to node ports - 76UCBPIZNGJNWNUZ -m addrtype --dst-type LOCAL -m multiport --dports 30000:32767 -j RETURN' doesn't exist in chain KUBE-ROUTER-INPUT, inserting at position 3
kube-router-qx29r kube-router 2024-05-12T19:28:57.016248132-05:00 I0513 00:28:57.016065   52913 network_policy_controller.go:175] Starting network policy controller full sync goroutine
kube-router-qx29r kube-router 2024-05-12T19:28:57.016268509-05:00 I0513 00:28:57.016094   52913 network_policy_controller.go:200] Requesting periodic sync of iptables to reflect network policies
kube-router-qx29r kube-router 2024-05-12T19:28:57.016273779-05:00 I0513 00:28:57.016104   52913 network_policy_controller.go:217] Full sync request queue was full, skipping...
kube-router-qx29r kube-router 2024-05-12T19:28:57.016278059-05:00 I0513 00:28:57.016129   52913 network_policy_controller.go:192] Received request for a full sync, processing
kube-router-qx29r kube-router 2024-05-12T19:28:57.016282712-05:00 I0513 00:28:57.016144   52913 network_policy_controller.go:240] Starting sync of iptables with version: 1715560137016134875
kube-router-qx29r kube-router 2024-05-12T19:28:57.016297772-05:00 I0513 00:28:57.016171   52913 health_controller.go:91] Received heartbeat from NPC
kube-router-qx29r kube-router 2024-05-12T19:28:57.022145447-05:00 I0513 00:28:57.021968   52913 network_policy_controller.go:448] Ensuring jump to chain KUBE-ROUTER-INPUT from INPUT at position 1
kube-router-qx29r kube-router 2024-05-12T19:28:57.030893198-05:00 I0513 00:28:57.030733   52913 network_policy_controller.go:448] Ensuring jump to chain KUBE-ROUTER-FORWARD from FORWARD at position 1
kube-router-qx29r kube-router 2024-05-12T19:28:57.037006527-05:00 I0513 00:28:57.036846   52913 network_policy_controller.go:448] Ensuring jump to chain KUBE-ROUTER-OUTPUT from OUTPUT at position 1
kube-router-qx29r kube-router 2024-05-12T19:28:57.040456167-05:00 I0513 00:28:57.040335   52913 network_policy_controller.go:462] Allow traffic to ingress towards Cluster IP Range: 10.96.0.0/12 for family: IPv4
kube-router-qx29r kube-router 2024-05-12T19:28:57.054298119-05:00 I0513 00:28:57.054137   52913 network_policy_controller.go:480] Allow TCP traffic to ingress towards node port range: 30000:32767 for family: IPv4
kube-router-qx29r kube-router 2024-05-12T19:28:57.066073975-05:00 I0513 00:28:57.065923   52913 network_policy_controller.go:386] Rule '-p tcp -m comment --comment allow LOCAL TCP traffic to node ports - LR7XO7NXDBGQJD2M -m addrtype --dst-type LOCAL -m multiport --dports 30000:32767 -j RETURN' doesn't exist in chain KUBE-ROUTER-INPUT, inserting at position 2
kube-router-qx29r kube-router 2024-05-12T19:28:57.072265447-05:00 I0513 00:28:57.072113   52913 network_policy_controller.go:493] Allow UDP traffic to ingress towards node port range: 30000:32767 for family: IPv4
kube-router-qx29r kube-router 2024-05-12T19:28:57.085059548-05:00 I0513 00:28:57.084905   52913 network_policy_controller.go:386] Rule '-p udp -m comment --comment allow LOCAL UDP traffic to node ports - 76UCBPIZNGJNWNUZ -m addrtype --dst-type LOCAL -m multiport --dports 30000:32767 -j RETURN' doesn't exist in chain KUBE-ROUTER-INPUT, inserting at position 3
kube-router-qx29r kube-router 2024-05-12T19:28:57.105818610-05:00 I0513 00:28:57.105632   52913 network_policy_controller.go:269] Saving IPv4 iptables rules took 10.310399ms
kube-router-qx29r kube-router 2024-05-12T19:28:57.105837443-05:00 I0513 00:28:57.105676   52913 policy.go:83] Attempting to attain ipset mutex lock
kube-router-qx29r kube-router 2024-05-12T19:28:57.105842283-05:00 I0513 00:28:57.105686   52913 policy.go:85] Attained ipset mutex lock, continuing...
kube-router-qx29r kube-router 2024-05-12T19:28:57.105847230-05:00 I0513 00:28:57.105699   52913 ipset.go:569] ipset restore looks like:
kube-router-qx29r kube-router 2024-05-12T19:28:57.107267243-05:00 I0513 00:28:57.107093   52913 policy.go:163] Restoring IPv4 ipset took 1.385877ms
kube-router-qx29r kube-router 2024-05-12T19:28:57.107286073-05:00 I0513 00:28:57.107135   52913 policy.go:170] Iptables chains in the filter table are synchronized with the network policies.
kube-router-qx29r kube-router 2024-05-12T19:28:57.107291220-05:00 I0513 00:28:57.107151   52913 policy.go:88] Returned ipset mutex lock
kube-router-qx29r kube-router 2024-05-12T19:28:57.107295817-05:00 I0513 00:28:57.107168   52913 policy.go:80] Syncing network policy chains took 1.48757ms
kube-router-qx29r kube-router 2024-05-12T19:28:57.138424927-05:00 I0513 00:28:57.138300   52913 network_policy_controller.go:309] Restoring IPv4 iptables rules took 19.78815ms
kube-router-qx29r kube-router 2024-05-12T19:28:57.138444797-05:00 I0513 00:28:57.138334   52913 network_policy_controller.go:678] Attempting to attain ipset mutex lock
kube-router-qx29r kube-router 2024-05-12T19:28:57.138463221-05:00 I0513 00:28:57.138350   52913 network_policy_controller.go:680] Attained ipset mutex lock, continuing...
kube-router-qx29r kube-router 2024-05-12T19:28:57.140018521-05:00 I0513 00:28:57.139874   52913 network_policy_controller.go:683] Returned ipset mutex lock
kube-router-qx29r kube-router 2024-05-12T19:28:57.140037615-05:00 I0513 00:28:57.139901   52913 network_policy_controller.go:237] sync iptables took 123.754463ms
kube-router-qx29r kube-router 2024-05-12T19:28:57.155925553-05:00 I0513 00:28:57.155752   52913 pod.go:53] Received update to pod: kube-system/kube-router-qx29r
kube-router-qx29r kube-router 2024-05-12T19:28:57.155948150-05:00 I0513 00:28:57.155780   52913 network_policy_controller.go:215] Full sync request queue was empty so a full sync request was successfully sent
kube-router-qx29r kube-router 2024-05-12T19:28:57.155953107-05:00 I0513 00:28:57.155792   52913 network_policy_controller.go:192] Received request for a full sync, processing
kube-router-qx29r kube-router 2024-05-12T19:28:57.155958170-05:00 I0513 00:28:57.155805   52913 network_policy_controller.go:240] Starting sync of iptables with version: 1715560137155797236
kube-router-qx29r kube-router 2024-05-12T19:28:57.155962457-05:00 I0513 00:28:57.155870   52913 health_controller.go:91] Received heartbeat from NPC
kube-router-qx29r kube-router 2024-05-12T19:28:57.161741448-05:00 I0513 00:28:57.161579   52913 network_policy_controller.go:448] Ensuring jump to chain KUBE-ROUTER-INPUT from INPUT at position 1
kube-router-qx29r kube-router 2024-05-12T19:28:57.173121298-05:00 I0513 00:28:57.172975   52913 network_policy_controller.go:448] Ensuring jump to chain KUBE-ROUTER-FORWARD from FORWARD at position 1
kube-router-qx29r kube-router 2024-05-12T19:28:57.179574156-05:00 I0513 00:28:57.179447   52913 network_policy_controller.go:448] Ensuring jump to chain KUBE-ROUTER-OUTPUT from OUTPUT at position 1
kube-router-qx29r kube-router 2024-05-12T19:28:57.183542764-05:00 I0513 00:28:57.183421   52913 network_policy_controller.go:462] Allow traffic to ingress towards Cluster IP Range: 10.96.0.0/12 for family: IPv4
kube-router-qx29r kube-router 2024-05-12T19:28:57.197441433-05:00 I0513 00:28:57.197315   52913 network_policy_controller.go:480] Allow TCP traffic to ingress towards node port range: 30000:32767 for family: IPv4
kube-router-qx29r kube-router 2024-05-12T19:28:57.211562390-05:00 I0513 00:28:57.211441   52913 network_policy_controller.go:386] Rule '-p tcp -m comment --comment allow LOCAL TCP traffic to node ports - LR7XO7NXDBGQJD2M -m addrtype --dst-type LOCAL -m multiport --dports 30000:32767 -j RETURN' doesn't exist in chain KUBE-ROUTER-INPUT, inserting at position 2
kube-router-qx29r kube-router 2024-05-12T19:28:57.216968763-05:00 I0513 00:28:57.216812   52913 network_policy_controller.go:493] Allow UDP traffic to ingress towards node port range: 30000:32767 for family: IPv4
kube-router-qx29r kube-router 2024-05-12T19:28:57.233005935-05:00 I0513 00:28:57.232801   52913 network_policy_controller.go:386] Rule '-p udp -m comment --comment allow LOCAL UDP traffic to node ports - 76UCBPIZNGJNWNUZ -m addrtype --dst-type LOCAL -m multiport --dports 30000:32767 -j RETURN' doesn't exist in chain KUBE-ROUTER-INPUT, inserting at position 3
kube-router-qx29r kube-router 2024-05-12T19:28:57.253687516-05:00 I0513 00:28:57.253527   52913 network_policy_controller.go:269] Saving IPv4 iptables rules took 10.182825ms
kube-router-qx29r kube-router 2024-05-12T19:28:57.253717877-05:00 I0513 00:28:57.253561   52913 policy.go:83] Attempting to attain ipset mutex lock
kube-router-qx29r kube-router 2024-05-12T19:28:57.253725540-05:00 I0513 00:28:57.253570   52913 policy.go:85] Attained ipset mutex lock, continuing...
kube-router-qx29r kube-router 2024-05-12T19:28:57.253743013-05:00 I0513 00:28:57.253641   52913 ipset.go:569] ipset restore looks like: create TMP-BXHY5LLMLSN36WFL hash:ip family inet hashsize 1024 maxelem 65536 timeout 0 bucketsize 12
kube-router-qx29r kube-router 2024-05-12T19:28:57.253750360-05:00 flush TMP-BXHY5LLMLSN36WFL
kube-router-qx29r kube-router 2024-05-12T19:28:57.253756740-05:00 add TMP-BXHY5LLMLSN36WFL 127.0.0.1 timeout 0
kube-router-qx29r kube-router 2024-05-12T19:28:57.253762647-05:00 add TMP-BXHY5LLMLSN36WFL 10.19.91.100 timeout 0
kube-router-qx29r kube-router 2024-05-12T19:28:57.253769314-05:00 create kube-router-local-ips hash:ip family inet hashsize 1024 maxelem 65536 timeout 0 bucketsize 12
kube-router-qx29r kube-router 2024-05-12T19:28:57.253775470-05:00 swap TMP-BXHY5LLMLSN36WFL kube-router-local-ips
kube-router-qx29r kube-router 2024-05-12T19:28:57.253801517-05:00 flush TMP-BXHY5LLMLSN36WFL
kube-router-qx29r kube-router 2024-05-12T19:28:57.253809030-05:00 add TMP-BXHY5LLMLSN36WFL 10.19.91.100 timeout 0
kube-router-qx29r kube-router 2024-05-12T19:28:57.253823267-05:00 create kube-router-node-ips hash:ip family inet hashsize 1024 maxelem 65536 timeout 0 bucketsize 12
kube-router-qx29r kube-router 2024-05-12T19:28:57.253829544-05:00 swap TMP-BXHY5LLMLSN36WFL kube-router-node-ips
kube-router-qx29r kube-router 2024-05-12T19:28:57.253835804-05:00 flush TMP-BXHY5LLMLSN36WFL
kube-router-qx29r kube-router 2024-05-12T19:28:57.253842194-05:00 create TMP-VWYBUB54W7TIO5MX hash:net family inet hashsize 1024 maxelem 65536 timeout 0 bucketsize 12
kube-router-qx29r kube-router 2024-05-12T19:28:57.253848214-05:00 flush TMP-VWYBUB54W7TIO5MX
kube-router-qx29r kube-router 2024-05-12T19:28:57.253854047-05:00 add TMP-VWYBUB54W7TIO5MX 10.200.0.0/24 timeout 0
kube-router-qx29r kube-router 2024-05-12T19:28:57.253859994-05:00 create kube-router-pod-subnets hash:net family inet hashsize 1024 maxelem 65536 timeout 0 bucketsize 12
kube-router-qx29r kube-router 2024-05-12T19:28:57.253866361-05:00 swap TMP-VWYBUB54W7TIO5MX kube-router-pod-subnets
kube-router-qx29r kube-router 2024-05-12T19:28:57.253872457-05:00 flush TMP-VWYBUB54W7TIO5MX
kube-router-qx29r kube-router 2024-05-12T19:28:57.253884611-05:00 add TMP-BXHY5LLMLSN36WFL 10.201.0.10 timeout 0
kube-router-qx29r kube-router 2024-05-12T19:28:57.253890394-05:00 add TMP-BXHY5LLMLSN36WFL 10.201.0.1 timeout 0
kube-router-qx29r kube-router 2024-05-12T19:28:57.253896371-05:00 create kube-router-svip hash:ip family inet hashsize 1024 maxelem 65536 timeout 0 bucketsize 12
kube-router-qx29r kube-router 2024-05-12T19:28:57.253902421-05:00 swap TMP-BXHY5LLMLSN36WFL kube-router-svip
kube-router-qx29r kube-router 2024-05-12T19:28:57.253908261-05:00 flush TMP-BXHY5LLMLSN36WFL
kube-router-qx29r kube-router 2024-05-12T19:28:57.253914318-05:00 create TMP-OS7GGD2P5UDSAXIN hash:ip,port family inet hashsize 1024 maxelem 65536 timeout 0 bucketsize 12
kube-router-qx29r kube-router 2024-05-12T19:28:57.253920251-05:00 flush TMP-OS7GGD2P5UDSAXIN
kube-router-qx29r kube-router 2024-05-12T19:28:57.253926204-05:00 add TMP-OS7GGD2P5UDSAXIN 10.201.0.1,tcp:443 timeout 0
kube-router-qx29r kube-router 2024-05-12T19:28:57.253932494-05:00 add TMP-OS7GGD2P5UDSAXIN 10.201.0.10,tcp:53 timeout 0
kube-router-qx29r kube-router 2024-05-12T19:28:57.253938444-05:00 add TMP-OS7GGD2P5UDSAXIN 10.201.0.10,tcp:9153 timeout 0
kube-router-qx29r kube-router 2024-05-12T19:28:57.253944324-05:00 add TMP-OS7GGD2P5UDSAXIN 10.201.0.10,udp:53 timeout 0
kube-router-qx29r kube-router 2024-05-12T19:28:57.253950354-05:00 create kube-router-svip-prt hash:ip,port family inet hashsize 1024 maxelem 65536 timeout 0 bucketsize 12
kube-router-qx29r kube-router 2024-05-12T19:28:57.253956241-05:00 swap TMP-OS7GGD2P5UDSAXIN kube-router-svip-prt
kube-router-qx29r kube-router 2024-05-12T19:28:57.253962084-05:00 flush TMP-OS7GGD2P5UDSAXIN
kube-router-qx29r kube-router 2024-05-12T19:28:57.253968011-05:00 destroy TMP-BXHY5LLMLSN36WFL
kube-router-qx29r kube-router 2024-05-12T19:28:57.253973874-05:00 destroy TMP-OS7GGD2P5UDSAXIN
kube-router-qx29r kube-router 2024-05-12T19:28:57.253979835-05:00 destroy TMP-VWYBUB54W7TIO5MX
kube-router-qx29r kube-router 2024-05-12T19:28:57.255679629-05:00 I0513 00:28:57.255529   52913 policy.go:163] Restoring IPv4 ipset took 1.94154ms
kube-router-qx29r kube-router 2024-05-12T19:28:57.255710359-05:00 I0513 00:28:57.255558   52913 policy.go:170] Iptables chains in the filter table are synchronized with the network policies.
kube-router-qx29r kube-router 2024-05-12T19:28:57.255717073-05:00 I0513 00:28:57.255567   52913 policy.go:88] Returned ipset mutex lock
kube-router-qx29r kube-router 2024-05-12T19:28:57.255723293-05:00 I0513 00:28:57.255576   52913 policy.go:80] Syncing network policy chains took 2.01614ms
kube-router-qx29r kube-router 2024-05-12T19:28:57.288464144-05:00 I0513 00:28:57.288339   52913 network_policy_controller.go:309] Restoring IPv4 iptables rules took 18.729228ms
kube-router-qx29r kube-router 2024-05-12T19:28:57.288495698-05:00 I0513 00:28:57.288368   52913 network_policy_controller.go:678] Attempting to attain ipset mutex lock
kube-router-qx29r kube-router 2024-05-12T19:28:57.288503565-05:00 I0513 00:28:57.288379   52913 network_policy_controller.go:680] Attained ipset mutex lock, continuing...
kube-router-qx29r kube-router 2024-05-12T19:28:57.290191876-05:00 I0513 00:28:57.290052   52913 network_policy_controller.go:683] Returned ipset mutex lock
kube-router-qx29r kube-router 2024-05-12T19:28:57.290238756-05:00 I0513 00:28:57.290064   52913 network_policy_controller.go:237] sync iptables took 134.263107ms
kube-router-qx29r kube-router 2024-05-12T19:29:04.885885804-05:00 time="2024-05-13T00:29:04Z" level=info msg="Peer Up" Key=10.19.90.1 State=BGP_FSM_OPENCONFIRM Topic=Peer
kube-router-qx29r kube-router 2024-05-12T19:29:04.885926731-05:00 time="2024-05-13T00:29:04Z" level=info msg="sync finished" Key=10.19.90.1 Topic=Server
kube-router-qx29r kube-router 2024-05-12T19:29:56.878125506-05:00 I0513 00:29:56.877961   52913 route_sync.go:41] Running local route table synchronization
kube-router-qx29r kube-router 2024-05-12T19:30:56.877705098-05:00 I0513 00:30:56.877568   52913 route_sync.go:41] Running local route table synchronization
kube-router-qx29r kube-router 2024-05-12T19:31:56.877666013-05:00 I0513 00:31:56.877408   52913 route_sync.go:41] Running local route table synchronization
kube-router-qx29r kube-router 2024-05-12T19:32:49.538585277-05:00 I0513 00:32:49.538392   52913 kube-router.go:266] Shutting down the controllers
kube-router-qx29r kube-router 2024-05-12T19:32:49.538643390-05:00 I0513 00:32:49.538499   52913 health_controller.go:208] Shutting down health controller
kube-router-qx29r kube-router 2024-05-12T19:32:49.538683814-05:00 E0513 00:32:49.538585   52913 health_controller.go:199] Health controller error: http: Server closed
kube-router-qx29r kube-router 2024-05-12T19:32:49.538729961-05:00 I0513 00:32:49.538609   52913 reflector.go:295] Stopping reflector *v1.Node (0s) from pkg/mod/k8s.io/[email protected]/tools/cache/reflector.go:229
kube-router-qx29r kube-router 2024-05-12T19:32:49.538754761-05:00 I0513 00:32:49.538645   52913 nodeport_healthcheck.go:170] Stopping all NodePort health checks
kube-router-qx29r kube-router 2024-05-12T19:32:49.538788218-05:00 I0513 00:32:49.538673   52913 nodeport_healthcheck.go:172] Waiting for all NodePort health checks to finish shutting down
kube-router-qx29r kube-router 2024-05-12T19:32:49.538801641-05:00 I0513 00:32:49.538681   52913 health_controller.go:224] Shutting down HealthController RunCheck
kube-router-qx29r kube-router 2024-05-12T19:32:49.538810558-05:00 I0513 00:32:49.538683   52913 nodeport_healthcheck.go:174] All NodePort health checks are completely shut down, all done!
kube-router-qx29r kube-router 2024-05-12T19:32:49.538818721-05:00 I0513 00:32:49.538682   52913 network_policy_controller.go:189] Shutting down network policies full sync goroutine
kube-router-qx29r kube-router 2024-05-12T19:32:49.538849428-05:00 I0513 00:32:49.538711   52913 route_sync.go:64] Shutting down local route synchronization
kube-router-qx29r kube-router 2024-05-12T19:32:49.538863068-05:00 I0513 00:32:49.538724   52913 network_services_controller.go:338] Shutting down network services controller
kube-router-qx29r kube-router 2024-05-12T19:32:49.538875342-05:00 I0513 00:32:49.538730   52913 reflector.go:295] Stopping reflector *v1.NetworkPolicy (0s) from pkg/mod/k8s.io/[email protected]/tools/cache/reflector.go:229
kube-router-qx29r kube-router 2024-05-12T19:32:49.538887418-05:00 I0513 00:32:49.538784   52913 network_policy_controller.go:204] Shutting down network policies controller
kube-router-qx29r kube-router 2024-05-12T19:32:49.538916378-05:00 I0513 00:32:49.538787   52913 network_routes_controller.go:407] Shutting down network routes controller
kube-router-qx29r kube-router 2024-05-12T19:32:49.538945809-05:00 I0513 00:32:49.538817   52913 reflector.go:295] Stopping reflector *v1.Endpoints (0s) from pkg/mod/k8s.io/[email protected]/tools/cache/reflector.go:229
- kube-router-qx29r › kube-router

Again I don't see anything obviously critical here. Some things about the queue being full but I doubt this is the cause here?

[EDIT1] Even increasing the log level further the end looks like this:

I0513 00:46:44.186486   55210 health_controller.go:229] Health controller tick
time="2024-05-13T00:46:46Z" level=info msg="Peer Up" Key=10.19.90.1 State=BGP_FSM_OPENCONFIRM Topic=Peer
time="2024-05-13T00:46:46Z" level=info msg="sync finished" Key=10.19.90.1 Topic=Server
I0513 00:46:49.184889   55210 health_controller.go:229] Health controller tick
I0513 00:46:54.187385   55210 health_controller.go:229] Health controller tick
I0513 00:46:59.186868   55210 health_controller.go:229] Health controller tick
I0513 00:47:04.187371   55210 health_controller.go:229] Health controller tick
I0513 00:47:09.186820   55210 health_controller.go:229] Health controller tick
I0513 00:47:14.186786   55210 health_controller.go:229] Health controller tick
I0513 00:47:19.184962   55210 health_controller.go:229] Health controller tick
I0513 00:47:24.187327   55210 health_controller.go:229] Health controller tick
I0513 00:47:29.186696   55210 health_controller.go:229] Health controller tick
I0513 00:47:34.187140   55210 health_controller.go:229] Health controller tick
I0513 00:47:39.183448   55210 health_controller.go:229] Health controller tick
I0513 00:47:39.226792   55210 route_sync.go:41] Running local route table synchronization
I0513 00:47:44.182920   55210 health_controller.go:229] Health controller tick
I0513 00:47:49.185422   55210 health_controller.go:229] Health controller tick
I0513 00:47:54.186332   55210 health_controller.go:229] Health controller tick
I0513 00:47:59.186574   55210 health_controller.go:229] Health controller tick
I0513 00:48:04.187059   55210 health_controller.go:229] Health controller tick
I0513 00:48:09.183142   55210 health_controller.go:229] Health controller tick
I0513 00:48:14.186812   55210 health_controller.go:229] Health controller tick
I0513 00:48:19.185447   55210 health_controller.go:229] Health controller tick
I0513 00:48:24.186886   55210 health_controller.go:229] Health controller tick
I0513 00:48:29.187283   55210 health_controller.go:229] Health controller tick
I0513 00:48:34.185537   55210 health_controller.go:229] Health controller tick
I0513 00:48:39.183205   55210 health_controller.go:229] Health controller tick
I0513 00:48:39.226455   55210 route_sync.go:41] Running local route table synchronization
I0513 00:48:44.183011   55210 health_controller.go:229] Health controller tick
I0513 00:48:49.183513   55210 health_controller.go:229] Health controller tick
I0513 00:48:54.184193   55210 health_controller.go:229] Health controller tick
I0513 00:48:59.183682   55210 health_controller.go:229] Health controller tick
I0513 00:49:04.183513   55210 health_controller.go:229] Health controller tick
I0513 00:49:09.184137   55210 health_controller.go:229] Health controller tick
I0513 00:49:14.182913   55210 health_controller.go:229] Health controller tick
I0513 00:49:19.182591   55210 health_controller.go:229] Health controller tick
I0513 00:49:24.184197   55210 health_controller.go:229] Health controller tick
I0513 00:49:29.183680   55210 health_controller.go:229] Health controller tick
I0513 00:49:32.538177   55210 kube-router.go:266] Shutting down the controllers
I0513 00:49:32.538278   55210 health_controller.go:208] Shutting down health controller
I0513 00:49:32.538285   55210 nodeport_healthcheck.go:170] Stopping all NodePort health checks
I0513 00:49:32.538307   55210 nodeport_healthcheck.go:172] Waiting for all NodePort health checks to finish shutting down
I0513 00:49:32.538323   55210 nodeport_healthcheck.go:174] All NodePort health checks are completely shut down, all done!
I0513 00:49:32.538357   55210 network_services_controller.go:338] Shutting down network services controller
I0513 00:49:32.538398   55210 network_policy_controller.go:189] Shutting down network policies full sync goroutine
E0513 00:49:32.538387   55210 health_controller.go:199] Health controller error: http: Server closed
I0513 00:49:32.538419   55210 health_controller.go:224] Shutting down HealthController RunCheck
I0513 00:49:32.538456   55210 network_routes_controller.go:407] Shutting down network routes controller
I0513 00:49:32.538460   55210 route_sync.go:64] Shutting down local route synchronization
I0513 00:49:32.538458   55210 network_policy_controller.go:204] Shutting down network policies controller

[EDIT2] curl localhost:20244/healthz returns OK until the very moment the pod cycles. Which I did not expect.

Xaelias avatar May 13 '24 00:05 Xaelias

hmm... That is pretty odd. Looking back up at your event log, I can see now that it actually says:

  Warning  Unhealthy       11m                   kubelet            Liveness probe failed: Get "http://10.19.91.100:20244/healthz": dial tcp 10.19.91.100:20244: connect: connection refused

So essentially kubelet is saying that its unable to reach that endpoint. I'm assuming that 10.19.91.100 is the node's IP since kube-router should be run within the host network. I would next try increasing the number of liveness checks that Kubernetes has until it kills the service (failureThreshold) and then try to get the exact endpoint that is failing via kubectl describe pod -n kube-system <kube-router-pod-here> and then curling that (from the host where kube-router is running, e.g. the same path that kubelet is using) and seeing if you get a different response?

I'm going to assume that you'll get connection refused or something similar, so then it is going to be more about checking the location of the kube-router IP address and trying to understand if there is something about the system setup that is preventing that from working? Maybe additional system firewall rules or something?

As a very last resort, you could of course run without any liveness checks. This gets rid of a core component of the Kubernetes stability guarantees, but it looks like kube-router is a 100% healthy from all of your logs.

aauren avatar May 13 '24 01:05 aauren

You are correct that is the IP of that node.

The thing is that event is not even consistently in there. The firewall is also disabled on ubuntu (ufw status returns inactive, not that it should matter for local stuff). The curl I mentioned above was run from the host itself. I'm at a loss here...

I would consider disabling the liveness probe if kube-router was working as is. But as far as I can tell the DNS/bgp part is also not working properly since I can't resolve things like kubernetes.default.svc.cluster.local or kube-dns.kube-system.svc.cluster.local unless I dig ... @10.201.0.10 (from that node alone, from another machine it doesn't work since the routes don't seem to be propagated properly).

Xaelias avatar May 13 '24 01:05 Xaelias

Note, that kubelet is not curling localhost to get the health of kube-router, it is using the IP of the interface to the node, so that may be a difference worth looking into on your node. ufw showing inactive, would seem to rule out that as an issue in the first-pass, but there may be other things playing with firewall rules or the like.

One other thing that I noticed, is that you don't seem to be setting --service-cluster-ip-range (see: https://www.kube-router.io/docs/user-guide/#command-line-options for more details) and that your ClusterIP at least for DNS appears to be outside the k8s default range of 10.96.0.0/12 so that may also be causing you problems. I would recommend setting that flag for your cluster as a parameter to kube-router.

So with a cluster size of 1 I don't believe that BGP is going to play a part in the service availability. Within kube-router BGP is only used to propagate routes between multiple nodes within a cluster, or to peer with external peers. I see that you have defined a peer via annotations which should be working, from the logs it looks like a route was established:

kube-router-qx29r kube-router 2024-05-12T19:29:04.885885804-05:00 time="2024-05-13T00:29:04Z" level=info msg="Peer Up" Key=10.19.90.1 State=BGP_FSM_OPENCONFIRM Topic=Peer
kube-router-qx29r kube-router 2024-05-12T19:29:04.885926731-05:00 time="2024-05-13T00:29:04Z" level=info msg="sync finished" Key=10.19.90.1 Topic=Server

DNS is a whole different thing, that is handled by CoreDNS or kube-dns or some other application within the cluster, kube-router only provides the route to the service, so since a dig of the IP address is working, then I would suggest that the kube-router part is working.

If you can provide more information on what specifically is not working with the BGP peering or what services are not available we might be able to dig more into that, but otherwise, from everything I can see kube-router appears to be working and healthy within the cluster.

aauren avatar May 13 '24 17:05 aauren

Hi, thanks for pointing out I was missing the service bit :-)

After another couple install from scratch (I had a few issues with kubernetes absolutely freaking out as I was trying some things).

Anyway, I have a new data point. kube-router only fails as soon as I add --advertise-cluster-ip. So there does seem to be something not clicking with the bgp part of my config :-/

args:
- --run-router=true
- --run-firewall=true
- --run-service-proxy=true
- --bgp-graceful-restart=true
- --kubeconfig=/var/lib/kube-router/kubeconfig
- --service-cluster-ip-range=10.201.0.0/16
- --peer-router-ips=10.19.90.1
- --peer-router-asns=64513
- --advertise-cluster-ip
- --advertise-external-ip
- --advertise-loadbalancer-ip
- --advertise-pod-cidr
- --nodes-full-mesh
- -v=10

Here is what I'm currently trying with.

[EDIT] I'm not getting consistent behavior from kube-router. Now it seems it's willing to crash even with just the router ip/asn set.

Xaelias avatar May 14 '24 01:05 Xaelias

From what I can tell, kube-router isn't crashing, at least not in any of the logs that you've sent so far, it seems to be being killed.

aauren avatar May 14 '24 01:05 aauren