search

cloudnativelabs / kube-router

Kube-router, a turnkey solution for Kubernetes networking.
https://kube-router.io
Apache License 2.0
2.33k stars 471 forks source link

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

Closed Xaelias closed 6 months ago

Xaelias commented 6 months ago

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
  4. Watch as kube-router eventually stops itself (liveness probe).

System Information (please complete the following information):

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.

aauren commented 6 months ago

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.

Xaelias commented 6 months ago

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 commented 6 months ago
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/client-go@v0.29.3/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/client-go@v0.29.3/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/client-go@v0.29.3/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/client-go@v0.29.3/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/client-go@v0.29.3/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/client-go@v0.29.3/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/client-go@v0.29.3/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/client-go@v0.29.3/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/client-go@v0.29.3/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/client-go@v0.29.3/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/client-go@v0.29.3/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/client-go@v0.29.3/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/client-go@v0.29.3/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/client-go@v0.29.3/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/client-go@v0.29.3/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/client-go@v0.29.3/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/client-go@v0.29.3/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/client-go@v0.29.3/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/client-go@v0.29.3/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/client-go@v0.29.3/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/client-go@v0.29.3/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/client-go@v0.29.3/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/client-go@v0.29.3/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/client-go@v0.29.3/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.

aauren commented 6 months ago

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.

Xaelias commented 6 months ago

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).

aauren commented 6 months ago

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.

Xaelias commented 6 months ago

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.

aauren commented 6 months ago

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.