judge-red
commented
3 weeks ago This just happened again and suspiciously it again happened just after the cluster-autoscaler downscaled a nodegroup and had a worker node deleted.
cluster-autoscaler started the scale down at I1030 10:32:24.538958. Most relevant log line seems to be:
I1030 10:32:25.140710 1 actuator.go:215] Scale-down: removing node sck-production-scc-zhw-pool-ubuntu-jammy-1-7b7ffdfdd8-2422k, utilization: {0.1125 0.045306618034575155 0 cpu 0.1125}, pods to reschedule: apiserver-84ccf6f5bc-4tztlLooking at the machine-controller, we can furthermore see that this node was short-lived. It was created at 2024-10-30T10:07:25.023Z and gone by 2024-10-30T10:33:22.458Z, maybe this has something to do with this issue?
{"level":"info","time":"2024-10-30T10:07:25.023Z","logger":"machine-controller","caller":"machine/controller.go:945","msg":"Created machine at cloud provider","machine":"kube-system/sck-production-scc-zhw-pool-ubuntu-jammy-1-7b7ffdfdd8-2422k","provider":"openstack"}
[...]
{"level":"info","time":"2024-10-30T10:33:06.776Z","logger":"machine-controller","caller":"eviction/eviction.go:66","msg":"Starting to evict node","machine":"kube-system/sck-production-scc-zhw-pool-ubuntu-jammy-1-7b7ffdfdd8-2422k","provider":"openstack","node":"sck-production-scc-zhw-pool-ubuntu-jammy-1-7b7ffdfdd8-2422k"}
{"level":"info","time":"2024-10-30T10:33:20.579Z","logger":"machine-controller","caller":"eviction/eviction.go:66","msg":"Starting to evict node","machine":"kube-system/sck-production-scc-zhw-pool-ubuntu-jammy-1-7b7ffdfdd8-2422k","provider":"openstack","node":"sck-production-scc-zhw-pool-ubuntu-jammy-1-7b7ffdfdd8-2422k"}
{"level":"error","time":"2024-10-30T10:33:22.458Z","logger":"machine-controller","caller":"machine/controller.go:410","msg":"Reconciling failed","machine":"kube-system/sck-production-scc-zhw-pool-ubuntu-jammy-1-7b7ffdfdd8-2422k","error":"failed to get machine: Machine.cluster.k8s.io \"sck-production-scc-zhw-pool-ubuntu-jammy-1-7b7ffdfdd8-2422k\" not found"}Now the OCCM last reported on this node at I1030 10:30:49.574364:
I1030 10:30:49.574364 12 instances.go:719] Node 'sck-production-scc-zhw-pool-ubuntu-jammy-1-7b7ffdfdd8-2422k' returns addresses '[{InternalIP 192.168.2.81}]'And it last saw 10 worker nodes at I1030 10:33:22.428119 but only worked with 9 nodes at I1030 10:33:22.428217 already:
I1030 10:33:22.428081 12 controller.go:733] Syncing backends for all LB services.
I1030 10:33:22.428119 12 controller.go:812] Running updateLoadBalancerHosts(len(services)==12, workers==10)
I1030 10:33:22.428190 12 controller.go:770] nodeSyncService started for service cluster-hrs2xpk8sk/front-loadbalancer
I1030 10:33:22.428217 12 controller.go:842] Updating backends for load balancer cluster-hrs2xpk8sk/front-loadbalancer with 9 nodes: [sck-production-scc-zhw-pool-ubuntu-jammy-0-64b85f689c-79gpv sck-production-scc-zhw-pool-ubuntu-jammy-0-64b85f689c-qq9sd sck-production-scc-zhw-pool-ubuntu-jammy-0-64b85f689c-tb52d sck-production-scc-zhw-pool-ubuntu-jammy-0-64b85f689c-xmd8x sck-production-scc-zhw-pool-ubuntu-jammy-0-64b85f689c-zz9z8 sck-production-scc-zhw-pool-ubuntu-jammy-1-7b7ffdfdd8-bvnjz sck-production-scc-zhw-pool-ubuntu-jammy-1-7b7ffdfdd8-h7thw sck-production-scc-zhw-pool-ubuntu-jammy-1-7b7ffdfdd8-nc2zw sck-production-scc-zhw-pool-ubuntu-jammy-2-7c99d48579-xkjwx]All looks good afaict, until it starts deleting security group rules here:
I1030 10:34:07.406719 12 loadbalancer_sg.go:316] Deleting rule 48c429f0-64db-42ef-b535-c11c54461d3b from security group 226cc832-0b14-4a1a-a281-db03b60285ba (lb-sg-aebe6c94-9925-4c60-a492-a97a01dba02c-cluster-imvcnfz7nf-front-loadbalancer)
I1030 10:34:07.485631 12 loadbalancer_sg.go:316] Deleting rule 7ecb6942-dd30-4b2a-ad1a-7f85a1099739 from security group 226cc832-0b14-4a1a-a281-db03b60285ba (lb-sg-aebe6c94-9925-4c60-a492-a97a01dba02c-cluster-imvcnfz7nf-front-loadbalancer)
I1030 10:34:07.565073 12 loadbalancer_sg.go:316] Deleting rule 835b6d3c-2f13-4244-bcc2-a006792fe858 from security group 226cc832-0b14-4a1a-a281-db03b60285ba (lb-sg-aebe6c94-9925-4c60-a492-a97a01dba02c-cluster-imvcnfz7nf-front-loadbalancer)Unfortunately the log, even at -v=5 does not tell us why it deletes those rules (nor any details about the rule itself) at all :(
This is as far as I get, I don't understand why the OCCM does react like this.
zetaab
Is this a BUG REPORT or FEATURE REQUEST?:
What happened:
The OCCM removed all rules from all lb-sg security groups for no reasons. This happened 5 times in total last week on 2 clusters, but never before and never since, not sure what could have triggered this behavior, but it caused a complete downtime on everything exposed by a load balancer. Luckily the resolution is simple and quick, restarting the OCCM leads to immediate recreation of the correct rules.
What you expected to happen:
Don't delete all the security group rules that are (still) required.
How to reproduce it:
Unfortunately, the trigger isn't known. Maybe an action by the cluster-autoscaler was involved - we see in the logs (including the OCCM's log) that a node was added just before this happend, but adding nodes alone doesn't seem to trigger the issue.
use-octavia="true"lb-provider="ovn"manage-security-groups="true"loadBalancerSourceRangesset)Anything else we need to know?:
I'll add the log of the occm that included this happening. Verbosity was set to 4. Unfortunately we only have the log of the last time it occured even though it happened 3 times on the same cluster and 2 times on another cluster. Weirdly it happened at almost the same time (within an hour or so) on both clusters, thus the idea that an overloaded OpenStack API or network or such might have exposed this issue. The third time we had the cluster-autoscaler disabled on one cluster and it only happened on the other cluster, thus the idea that its actions and thus a node addition (or maybe also removal) might also be a contributing factor.
openstack-cloud-controller-manager-kmswx.log
Environment:
Edit: the logs of the comments below can be found in this folder: https://drive.switch.ch/index.php/s/IMoXWTaJWrfdB5Q