search

k0sproject / k0s

k0s - The Zero Friction Kubernetes
https://docs.k0sproject.io
Other
3.14k stars 353 forks source link

konnectivity floods the log with "Failed to get a backend" err="No agent available" on normal reboot #4493

Closed Skaronator closed 3 weeks ago

Skaronator commented 1 month ago

Before creating an issue, make sure you've checked the following:

Platform

uname -srvmo; cat /etc/os-release || lsb_release -a
Linux 5.15.0-107-generic #117-Ubuntu SMP Fri Apr 26 12:26:49 UTC 2024 x86_64 GNU/Linux
PRETTY_NAME="Ubuntu 22.04.4 LTS"
NAME="Ubuntu"
VERSION_ID="22.04"
VERSION="22.04.4 LTS (Jammy Jellyfish)"
VERSION_CODENAME=jammy
ID=ubuntu
ID_LIKE=debian
HOME_URL="https://www.ubuntu.com/"
SUPPORT_URL="https://help.ubuntu.com/"
BUG_REPORT_URL="https://bugs.launchpad.net/ubuntu/"
PRIVACY_POLICY_URL="https://www.ubuntu.com/legal/terms-and-policies/privacy-policy"
UBUNTU_CODENAME=jammy

Version

v1.30.0+k0s.0

Sysinfo

`k0s sysinfo` 
fin-kubcp-vm-01:~# k0s sysinfo
Total memory: 5.8 GiB (pass)
Disk space available for /var/lib/k0s: 18.9 GiB (pass)
Name resolution: localhost: [127.0.0.1] (pass)
Operating system: Linux (pass)
  Linux kernel release: 5.15.0-107-generic (pass)
  Max. file descriptors per process: current: 1048576 / max: 1048576 (pass)
  AppArmor: active (pass)
  Executable in PATH: modprobe: /usr/sbin/modprobe (pass)
  Executable in PATH: mount: /usr/bin/mount (pass)
  Executable in PATH: umount: /usr/bin/umount (pass)
  /proc file system: mounted (0x9fa0) (pass)
  Control Groups: version 2 (pass)
    cgroup controller "cpu": available (is a listed root controller) (pass)
    cgroup controller "cpuacct": available (via cpu in version 2) (pass)
    cgroup controller "cpuset": available (is a listed root controller) (pass)
    cgroup controller "memory": available (is a listed root controller) (pass)
    cgroup controller "devices": available (device filters attachable) (pass)
    cgroup controller "freezer": available (cgroup.freeze exists) (pass)
    cgroup controller "pids": available (is a listed root controller) (pass)
    cgroup controller "hugetlb": available (is a listed root controller) (pass)
    cgroup controller "blkio": available (via io in version 2) (pass)
  CONFIG_CGROUPS: Control Group support: built-in (pass)
    CONFIG_CGROUP_FREEZER: Freezer cgroup subsystem: built-in (pass)
    CONFIG_CGROUP_PIDS: PIDs cgroup subsystem: built-in (pass)
    CONFIG_CGROUP_DEVICE: Device controller for cgroups: built-in (pass)
    CONFIG_CPUSETS: Cpuset support: built-in (pass)
    CONFIG_CGROUP_CPUACCT: Simple CPU accounting cgroup subsystem: built-in (pass)
    CONFIG_MEMCG: Memory Resource Controller for Control Groups: built-in (pass)
    CONFIG_CGROUP_HUGETLB: HugeTLB Resource Controller for Control Groups: built-in (pass)
    CONFIG_CGROUP_SCHED: Group CPU scheduler: built-in (pass)
      CONFIG_FAIR_GROUP_SCHED: Group scheduling for SCHED_OTHER: built-in (pass)
        CONFIG_CFS_BANDWIDTH: CPU bandwidth provisioning for FAIR_GROUP_SCHED: built-in (pass)
    CONFIG_BLK_CGROUP: Block IO controller: built-in (pass)
  CONFIG_NAMESPACES: Namespaces support: built-in (pass)
    CONFIG_UTS_NS: UTS namespace: built-in (pass)
    CONFIG_IPC_NS: IPC namespace: built-in (pass)
    CONFIG_PID_NS: PID namespace: built-in (pass)
    CONFIG_NET_NS: Network namespace: built-in (pass)
  CONFIG_NET: Networking support: built-in (pass)
    CONFIG_INET: TCP/IP networking: built-in (pass)
      CONFIG_IPV6: The IPv6 protocol: built-in (pass)
    CONFIG_NETFILTER: Network packet filtering framework (Netfilter): built-in (pass)
      CONFIG_NETFILTER_ADVANCED: Advanced netfilter configuration: built-in (pass)
      CONFIG_NF_CONNTRACK: Netfilter connection tracking support: module (pass)
      CONFIG_NETFILTER_XTABLES: Netfilter Xtables support: module (pass)
        CONFIG_NETFILTER_XT_TARGET_REDIRECT: REDIRECT target support: module (pass)
        CONFIG_NETFILTER_XT_MATCH_COMMENT: "comment" match support: module (pass)
        CONFIG_NETFILTER_XT_MARK: nfmark target and match support: module (pass)
        CONFIG_NETFILTER_XT_SET: set target and match support: module (pass)
        CONFIG_NETFILTER_XT_TARGET_MASQUERADE: MASQUERADE target support: module (pass)
        CONFIG_NETFILTER_XT_NAT: "SNAT and DNAT" targets support: module (pass)
        CONFIG_NETFILTER_XT_MATCH_ADDRTYPE: "addrtype" address type match support: module (pass)
        CONFIG_NETFILTER_XT_MATCH_CONNTRACK: "conntrack" connection tracking match support: module (pass)
        CONFIG_NETFILTER_XT_MATCH_MULTIPORT: "multiport" Multiple port match support: module (pass)
        CONFIG_NETFILTER_XT_MATCH_RECENT: "recent" match support: module (pass)
        CONFIG_NETFILTER_XT_MATCH_STATISTIC: "statistic" match support: module (pass)
      CONFIG_NETFILTER_NETLINK: module (pass)
      CONFIG_NF_NAT: module (pass)
      CONFIG_IP_SET: IP set support: module (pass)
        CONFIG_IP_SET_HASH_IP: hash:ip set support: module (pass)
        CONFIG_IP_SET_HASH_NET: hash:net set support: module (pass)
      CONFIG_IP_VS: IP virtual server support: module (pass)
        CONFIG_IP_VS_NFCT: Netfilter connection tracking: built-in (pass)
        CONFIG_IP_VS_SH: Source hashing scheduling: module (pass)
        CONFIG_IP_VS_RR: Round-robin scheduling: module (pass)
        CONFIG_IP_VS_WRR: Weighted round-robin scheduling: module (pass)
      CONFIG_NF_CONNTRACK_IPV4: IPv4 connetion tracking support (required for NAT): unknown (warning)
      CONFIG_NF_REJECT_IPV4: IPv4 packet rejection: module (pass)
      CONFIG_NF_NAT_IPV4: IPv4 NAT: unknown (warning)
      CONFIG_IP_NF_IPTABLES: IP tables support: module (pass)
        CONFIG_IP_NF_FILTER: Packet filtering: module (pass)
          CONFIG_IP_NF_TARGET_REJECT: REJECT target support: module (pass)
        CONFIG_IP_NF_NAT: iptables NAT support: module (pass)
        CONFIG_IP_NF_MANGLE: Packet mangling: module (pass)
      CONFIG_NF_DEFRAG_IPV4: module (pass)
      CONFIG_NF_CONNTRACK_IPV6: IPv6 connetion tracking support (required for NAT): unknown (warning)
      CONFIG_NF_NAT_IPV6: IPv6 NAT: unknown (warning)
      CONFIG_IP6_NF_IPTABLES: IP6 tables support: module (pass)
        CONFIG_IP6_NF_FILTER: Packet filtering: module (pass)
        CONFIG_IP6_NF_MANGLE: Packet mangling: module (pass)
        CONFIG_IP6_NF_NAT: ip6tables NAT support: module (pass)
      CONFIG_NF_DEFRAG_IPV6: module (pass)
    CONFIG_BRIDGE: 802.1d Ethernet Bridging: module (pass)
      CONFIG_LLC: module (pass)
      CONFIG_STP: module (pass)
  CONFIG_EXT4_FS: The Extended 4 (ext4) filesystem: built-in (pass)
  CONFIG_PROC_FS: /proc file system support: built-in (pass)

What happened?

I have a 3 control plane and 3 worker node cluster. I just installed it freshly and I rebooted a control plane to verify that HA correctly works.

When doing so, the following log one is spammed when the control plane freshly starts:

Look at the timestamp, it's like 1000 lines per second. 

May 25 07:41:38 fin-kubcp-vm-03 k0s[629]: time="2024-05-25 07:41:38" level=info msg="E0525 07:41:38.076911     928 server.go:579] \"Failed to get a backend\" err=\"No agent available\" dialID=4047265240477694804" component=konnectivity stream=stderr
May 25 07:41:38 fin-kubcp-vm-03 k0s[629]: time="2024-05-25 07:41:38" level=info msg="E0525 07:41:38.077146     928 server.go:579] \"Failed to get a backend\" err=\"No agent available\" dialID=4242037983563764689" component=konnectivity stream=stderr
May 25 07:41:38 fin-kubcp-vm-03 k0s[629]: time="2024-05-25 07:41:38" level=info msg="E0525 07:41:38.077241     928 server.go:579] \"Failed to get a backend\" err=\"No agent available\" dialID=8288153441743077910" component=konnectivity stream=stderr
May 25 07:41:38 fin-kubcp-vm-03 k0s[629]: time="2024-05-25 07:41:38" level=info msg="E0525 07:41:38.077338     928 server.go:579] \"Failed to get a backend\" err=\"No agent available\" dialID=2398193572414537277" component=konnectivity stream=stderr
May 25 07:41:38 fin-kubcp-vm-03 k0s[629]: time="2024-05-25 07:41:38" level=info msg="E0525 07:41:38.077438     928 server.go:579] \"Failed to get a backend\" err=\"No agent available\" dialID=2121021763424228099" component=konnectivity stream=stderr
May 25 07:41:38 fin-kubcp-vm-03 k0s[629]: time="2024-05-25 07:41:38" level=info msg="E0525 07:41:38.077531     928 server.go:579] \"Failed to get a backend\" err=\"No agent available\" dialID=4623451356294561059" component=konnectivity stream=stderr
May 25 07:41:38 fin-kubcp-vm-03 k0s[629]: time="2024-05-25 07:41:38" level=info msg="E0525 07:41:38.078148     876 controller.go:146] Error updating APIService \"v1beta1.metrics.k8s.io\" with err: failed to download v1beta1.metrics.k8s.io: failed to retrieve openAPI spec, http error: ResponseCode: 503, Body: error trying to reach service: No agent available" component=kube-apiserver stream=stderr
May 25 07:41:38 fin-kubcp-vm-03 k0s[629]: time="2024-05-25 07:41:38" level=info msg="E0525 07:41:38.078830     928 server.go:579] \"Failed to get a backend\" err=\"No agent available\" dialID=9008888339147975084" component=konnectivity stream=stderr
May 25 07:41:38 fin-kubcp-vm-03 k0s[629]: time="2024-05-25 07:41:38" level=info msg="E0525 07:41:38.087715     876 available_controller.go:460] v1beta1.metrics.k8s.io failed with: failing or missing response from https://10.102.86.38:443/apis/metrics.k8s.io/v1beta1: Get \"https://10.102.86.38:443/apis/metrics.k8s.io/v1beta1\": No agent available" component=kube-apiserver stream=stderr

In fact, when counting them, it's 733 per second!

ssh 172.20.4.58 'cat /var/log/syslog | grep "No agent" | grep 07:41:38 | wc -l'
733

Looking across the 3 control planes:

$  ssh 172.20.4.56 'cat /var/log/syslog | grep "No agent" | wc -l'
448943
$ ssh 172.20.4.57 'cat /var/log/syslog | grep "No agent" | wc -l'
521065
$  ssh 172.20.4.58 'cat /var/log/syslog | grep "No agent" | wc -l'
84013

Its over a million log lines and this cluster exists for like 5 minutes and I restarted control plane 1 and 2 once.

Steps to reproduce

  1. Install k0s in a HA cluster 3 CP, 3 Workers
  2. Reboot a CP
  3. Check /var/log/syslog length

Expected behavior

Only create 1 log line per second at best.

Actual behavior

Creates 700 log lines per second.

Screenshots and logs

No response

Additional context

Our old cluster (over 2 years old) with the latest k0s version had the same behavior. Something is very wrong, but I don't know what.

We just deployed a fresh cluster on 6 fresh Ubuntu 22.04 virtual machines and after rebooting a machine the same issue happened. The main difference: it looks like the fresh cluster fixed itself while the old cluster continue to spam these lines.

The konnectivity Pods on the worker nodes are all running and healthy. No sign of errors there.

Skaronator commented 1 month ago

I have the feeling that the controlPlaneLoadBalancing implementation is broken. My above issue is still valid. This was done using 3 CP + 3 Worker nodes + 1 HA Proxy VM as Loadbalancer for kube-api.

I now turned off the HA Proxy VM and enabled controlPlaneLoadBalancing. Everything looked fine until I rebooted CP1. kubectl stopped working for like 2 seconds and then keeps working again, this is expected since keepalived does it thingi.

But now CP1 spams No agent available forever.

While writing this text:

ssh 172.20.4.56 'cat /var/log/syslog | grep "No agent" | wc -l'
525182
ssh 172.20.4.56 'cat /var/log/syslog | grep "No agent" | wc -l'
526645
ssh 172.20.4.56 'cat /var/log/syslog | grep "No agent" | wc -l'
528153
ssh 172.20.4.56 'cat /var/log/syslog | grep "No agent" | wc -l'
597661
ssh 172.20.4.56 'cat /var/log/syslog | grep "No agent" | wc -l'
624413
ssh 172.20.4.56 'cat /var/log/syslog | grep "No agent" | wc -l'
676964
Skaronator commented 1 month ago

After removing controlPlaneLoadBalancing and restarting the HAProxy VM everything stabilized again.

Here is our k0sctl.yaml. kubernetes-controller.redacted.de points to 172.20.4.54. The HAProxy VM uses the same IP.


apiVersion: k0sctl.k0sproject.io/v1beta1
kind: Cluster
metadata:
  name: main-cluster
spec:
  k0s:
    version: 1.30.0+k0s.0
    config:
      apiVersion: k0sctl.k0sproject.io/v1beta1
      kind: Cluster
      metadata:
        name: main-cluster
      spec:
        api:
          externalAddress: kubernetes-controller.redacted.de
          sans:
            - kubernetes-controller.redacted.de
          extraArgs:
            oidc-issuer-url: https://dex.redacted.de
            oidc-client-id: kubernetes
            oidc-username-claim: preferred_username
            oidc-username-prefix: "oidc:"
            oidc-groups-claim: groups
            oidc-groups-prefix: "oidc:"
        network:
          podCIDR: 10.244.0.0/16
          serviceCIDR: 10.96.0.0/12
          controlPlaneLoadBalancing:
            enabled: true
            type: Keepalived
            keepalived:
              vrrpInstances:
                - virtualIPs: ["172.20.4.54/26"]
                  authPass: kubemain
                  virtualRouterID: 72 # just a unique number on the network
        telemetry:
          enabled: false
  hosts:
  - ssh:
      address: 172.20.4.56
      port: 22
      user: root
      keyPath: ../on-premise-infrastructure/ansible_deploy_key
    role: controller
    installFlags: &controllerInstallFlags
      - --enable-metrics-scraper
  - ssh:
      address: 172.20.4.57
      port: 22
      user: root
      keyPath: ../on-premise-infrastructure/ansible_deploy_key
    role: controller
    installFlags: *controllerInstallFlags
  - ssh:
      address: 172.20.4.58
      port: 22
      user: root
      keyPath: ../on-premise-infrastructure/ansible_deploy_key
    role: controller
    installFlags: *controllerInstallFlags
  - ssh:
      address: 172.20.4.59
      port: 22
      user: root
      keyPath: ../on-premise-infrastructure/ansible_deploy_key
    role: worker
  - ssh:
      address: 172.20.4.60
      port: 22
      user: root
      keyPath: ../on-premise-infrastructure/ansible_deploy_key
    role: worker
  - ssh:
      address: 172.20.4.61
      port: 22
      user: root
      keyPath: ../on-premise-infrastructure/ansible_deploy_key
    role: worker
twz123 commented 1 month ago

The error message comes from konnectivity-server when kube-apiserver attempts to connect to a node, but the node's konnectivity-agent has not yet connected to the controller's konnectivity-server. This is quite normal when a controller is restarted. It takes some time for all worker node agents to reconnect. The number of log lines depends on how often kube-apiserver tries to connect to the non-connected nodes, and is somewhat out of k0s' control, both because k0s doesn't usually initiate node connections through kube-apiserver itself, and because konnectivity reports this as an error each time it happens.

If the problem persists, it means that workers are unable to connect to one or more controllers. Typically, this indicates some sort of network problem. The konnectivity agents rely on the load balancer to eventually provide connections to all controllers. The LB address is used to brute-force open connections until the agent has the desired number of connections to different controller nodes.

From your experiments with CPLB, I'm surprised that the k0s controllers did even start with the configuration you presented. Currently, api.externalAddress and network.controlPlaneLoadBalancing.enabled: true are mutually exclusive and should result in an error during startup.

I had a quick look at the logs when bootstrapping a 3/3 cluster locally, and I only got 3 such log statements per controller :thinking:

Our old cluster (over 2 years old) with the latest k0s version had the same behavior. Something is very wrong, but I don't know what.

We just deployed a fresh cluster on 6 fresh Ubuntu 22.04 virtual machines and after rebooting a machine the same issue happened. The main difference: it looks like the fresh cluster fixed itself while the old cluster continue to spam these lines.

The konnectivity Pods on the worker nodes are all running and healthy. No sign of errors there.

Check that the konnectivity-agents are actually using the load balancer:

kubectl -n kube-system get po -l k8s-app=konnectivity-agent --field-selector=status.phase=Running -o=go-template='
{{- range .items -}}
  {{- $host := "" -}}
  {{- $port := "" -}}
  {{- range (index .spec.containers 0).args -}}
    {{- $prefix := (printf "%.20s" .) }}
    {{- if eq $prefix "--proxy-server-host=" -}}
      {{- $host = (slice . 20) -}}
    {{- else }}
      {{- if eq $prefix "--proxy-server-port=" -}}
          {{- $port = (slice . 20) -}}
      {{- end -}}
    {{- end -}}
  {{- end -}}
  {{- printf "%s on %s connects to %s:%s\n" .metadata.name .spec.nodeName $host $port -}}
{{- end -}}
'

This should yield something like

konnectivity-agent-xxxxx on worker-a connects to kubernetes-controller.redacted.de:8132
konnectivity-agent-yyyyy on worker-b connects to kubernetes-controller.redacted.de:8132
konnectivity-agent-zzzzz on worker-c connects to kubernetes-controller.redacted.de:8132

Check if the load balancer is able to provide connections to all three controllers on port 8132. This might be depending on the load-balancing strategy. Round-robin and random should work. Least-connections or similar may be problematic. Try to restart the konnectivity-agent pods and have a look at to how many servers they connect to. This script could be helpful (extracted from the ostests pre-flight checks):

#!/usr/bin/env sh

set -eu

expectedControllers="${1-3}"
expectedWorkers="${2-3}"

countSeenControllers() {
  kubectl -n kube-system logs "$1" \
    | grep -F '"Start serving"' \
    | sed -E 's/.+serverID="([0-9a-f]+)".+/\1/g' \
    | sort -u \
    | wc -l
}

testKonnectivityPods() {
  pods="$(kubectl -n kube-system get po -l k8s-app=konnectivity-agent --field-selector=status.phase=Running -oname)"

  seenPods=0
  for pod in $pods; do
    seenControllers="$(countSeenControllers "$pod")"
    echo Pod: "$pod", seen controllers: "$seenControllers" >&2
    [ "$seenControllers" -ne "$expectedControllers" ] || seenPods=$((seenPods + 1))
  done

  echo Seen pods with expected amount of controller connections: $seenPods >&2
  [ $seenPods -eq "$expectedWorkers" ]
}

testKonnectivityPods
Skaronator commented 1 month ago

Thanks, Tom, for the thorough response!

So this issue contains two separate issues: The flooding from konnectivity and the controlPlaneLoadBalancing not working as expected.

The first issue with the flooding is part of the kube-api server, which is outside k0s control.

We use 3 control planes, 3 worker nodes and a single VM using HAProxy. Our HAProxy uses the recommended config from the docs. So I don't think there is anything wrong with our setup. Could you enable the metrics-server on your test cluster? I saw a couple of metrics-server errors as well between the many konnectivity errors. Maybe that's the culprit of the spam.

Using your first command reveals that everything looks as expected. The second command didn't work because the konnectivity pods were already running for too long, but I checked Grafana Loki logs and everything looks fine there as well.

The second issue is quite interesting. I wasn't aware that api.externalAddress and network.controlPlaneLoadBalancing.enabled: true are mutually exclusive. The k0s control plane just started successfully with the above posted k0sctl.yaml.

Everything seemed to work just fine, even kubectl can reach the control plane using the virtual IP. After restarting the control plane 1, everything slowly broke down. The VM/Control Plane came back but spammed the log with the konnectivity agent log mentioned above. In our old cluster, we even broke our etcd by repeated reboots to possibly resolve the konnectivity agent issue.

I'll need to retest this setup without defining an api.externalAddress but this will take a couple of days. We're still a bit busy recovering our primary cluster.

Lastly, error handling and documentation.

As a non-native English speaker, the documentation is written a bit confusing with the double negation:

If VirtualServers are used, the cluster configuration mustn't specify a non-empty spec.api.externalAddress. If only VRRPInstances are specified, a non-empty spec.api.externalAddress may be specified.

Here is a better rewording by ChatGPT:

If you are using VirtualServers, you must leave spec.api.externalAddress empty. If you are using only VRRPInstances, you are allowed to specify a value for spec.api.externalAddress.

It would also be great to have a full example. I never really used keepalived on my own, so I'm still not sure if I should use only VRRPInstances or VRRPInstances + VirtualServers. I'm also not sure if the IP in VRRPInstances and VirtualServers should be the same. Even the "Full example using" at the bottom of the page just uses an "External ip address" placeholder.

This is also not the first time that I deployed an invalid configuration. When you try to google the k0s docs, you often land on an older version of the documentation. (This was more painful back then, today you have a giant reminder on top, which is fantastic.)

I used fields in the config that no longer existed and k0sctl just applied then without any warning/error beforehand. There should be a better way of validating the configuration. Instead of just yolo it, there should be an error before even touching/shutting down a worker/controlplane node.

Skaronator commented 1 month ago

Just noticed that I also defined spec.api.externalAddress and VRRPInstances at the same time in my homelab for over two weeks and everything works fine so far (which it shouldn't):

https://github.com/Skaronator/homelab/blob/4762154fda1a7e125b717aecc6773c4154976916/k0sctl.yaml

Edit: Just did an upgrade from 1.30.0 to 1.30.1 and it broke my homelab cluster as well. It seems like migrating from a broken to a correct config completely broke it. I just have a single node but I don't use --single because I plan to add more nodes in the near future.

Looking at the k0s.yaml on my Node, I can see it defining the etcd storage with the VRRPInstances IP as peers but there are no peers in my cluster resulting in (I assume) etcd not starting up due to missing peers?

storage:
    etcd:
      peerAddress: 192.168.0.30

Edit2: Maybe it is not a good idea that peerAddress points to itself when there is just a single node?

Here the logs, they are in reverse (newest on the bottom)

May 28 21:55:19 node1 k0s[479277]: time="2024-05-28 21:55:19" level=info msg="respawning in 5s" component=etcd
May 28 21:55:19 node1 k0s[479277]: time="2024-05-28 21:55:19" level=warning msg="Failed to wait for process" component=etcd error="exit status 1"
May 28 21:55:19 node1 k0s[479277]: time="2024-05-28 21:55:19" level=info msg="{\"level\":\"fatal\",\"ts\":\"2024-05-28T21:55:19.078026+0200\",\"caller\":\"etcdmain/etcd.go:204\",\"msg\":\"discovery failed\",\"error\":\"listen tcp 192.168.0.30:2380: bind: cannot assign requested address\",\"stacktrace\":\"go.etcd.io/etcd/server/v3/etcdmain.startEtcdOrProxyV2\\n\\t/etcd/server/etcdmain/etcd.go:204\\ngo.etcd.io/etcd/server/v3/etcdmain.Main\\n\\t/etcd/se>
May 28 21:55:19 node1 k0s[479277]: time="2024-05-28 21:55:19" level=info msg="{\"level\":\"info\",\"ts\":\"2024-05-28T21:55:19.078013+0200\",\"caller\":\"embed/etcd.go:377\",\"msg\":\"closed etcd server\",\"name\":\"node1\",\"data-dir\":\"/var/lib/k0s/etcd\",\"advertise-peer-urls\":[\"https://192.168.0.30:2380\"],\"advertise-client-urls\":[\"https://127.0.0.1:2379\"]}" component=etcd stream=stderr
May 28 21:55:19 node1 k0s[479277]: time="2024-05-28 21:55:19" level=info msg="{\"level\":\"info\",\"ts\":\"2024-05-28T21:55:19.078004+0200\",\"caller\":\"embed/etcd.go:375\",\"msg\":\"closing etcd server\",\"name\":\"node1\",\"data-dir\":\"/var/lib/k0s/etcd\",\"advertise-peer-urls\":[\"https://192.168.0.30:2380\"],\"advertise-client-urls\":[\"https://127.0.0.1:2379\"]}" component=etcd stream=stderr
May 28 21:55:19 node1 k0s[479277]: time="2024-05-28 21:55:19" level=info msg="{\"level\":\"error\",\"ts\":\"2024-05-28T21:55:19.077916+0200\",\"caller\":\"embed/etcd.go:536\",\"msg\":\"creating peer listener failed\",\"error\":\"listen tcp 192.168.0.30:2380: bind: cannot assign requested address\",\"stacktrace\":\"go.etcd.io/etcd/server/v3/embed.configurePeerListeners\\n\\t/etcd/server/embed/etcd.go:536\\ngo.etcd.io/etcd/server/v3/embed.StartEtcd\\n\>
May 28 21:55:19 node1 k0s[479277]: time="2024-05-28 21:55:19" level=info msg="{\"level\":\"info\",\"ts\":\"2024-05-28T21:55:19.077548+0200\",\"caller\":\"embed/etcd.go:494\",\"msg\":\"starting with peer TLS\",\"tls-info\":\"cert = /var/lib/k0s/pki/etcd/peer.crt, key = /var/lib/k0s/pki/etcd/peer.key, client-cert=, client-key=, trusted-ca = /var/lib/k0s/pki/etcd/ca.crt, client-cert-auth = true, crl-file = \",\"cipher-suites\":[\"TLS_ECDHE_ECDSA_WITH_AE>
May 28 21:55:19 node1 k0s[479277]: time="2024-05-28 21:55:19" level=info msg="{\"level\":\"info\",\"ts\":\"2024-05-28T21:55:19.077519+0200\",\"caller\":\"embed/etcd.go:127\",\"msg\":\"configuring peer listeners\",\"listen-peer-urls\":[\"https://192.168.0.30:2380\"]}" component=etcd stream=stderr
May 28 21:55:19 node1 k0s[479277]: time="2024-05-28 21:55:19" level=info msg="{\"level\":\"warn\",\"ts\":\"2024-05-28T21:55:19.077507+0200\",\"caller\":\"embed/config.go:679\",\"msg\":\"Running http and grpc server on single port. This is not recommended for production.\"}" component=etcd stream=stderr
May 28 21:55:19 node1 k0s[479277]: time="2024-05-28 21:55:19" level=info msg="{\"level\":\"info\",\"ts\":\"2024-05-28T21:55:19.077486+0200\",\"caller\":\"etcdmain/etcd.go:116\",\"msg\":\"server has been already initialized\",\"data-dir\":\"/var/lib/k0s/etcd\",\"dir-type\":\"member\"}" component=etcd stream=stderr
May 28 21:55:19 node1 k0s[479277]: time="2024-05-28 21:55:19" level=info msg="{\"level\":\"info\",\"ts\":\"2024-05-28T21:55:19.077416+0200\",\"caller\":\"etcdmain/etcd.go:73\",\"msg\":\"Running: \",\"args\":[\"/var/lib/k0s/bin/etcd\",\"--client-cert-auth=true\",\"--peer-trusted-ca-file=/var/lib/k0s/pki/etcd/ca.crt\",\"--peer-key-file=/var/lib/k0s/pki/etcd/peer.key\",\"--cipher-suites=TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256,TLS_ECDHE_ECDSA_WITH_AES_25>
May 28 21:55:19 node1 k0s[479277]: time="2024-05-28 21:55:19" level=info msg="{\"level\":\"warn\",\"ts\":\"2024-05-28T21:55:19.077228+0200\",\"caller\":\"embed/config.go:679\",\"msg\":\"Running http and grpc server on single port. This is not recommended for production.\"}" component=etcd stream=stderr
May 28 21:55:19 node1 k0s[479277]: time="2024-05-28 21:55:19" level=info msg="Restarted (22)" component=etcd
juanluisvaladas commented 3 weeks ago

HI @Skaronator there are a few issues going on.

As for the last issue we suspect the peerAddress is being filled automatically by k0sctl, we believe we need to manually exclude the IP address. Can you please provide the full k0s.yaml file for each node? We suspect the issue is

Skaronator commented 3 weeks ago

So using my homelab cluster for now since its simpler to run/debug stuff.

My k0sctl.yaml looks like this:

apiVersion: k0sctl.k0sproject.io/v1beta1
kind: Cluster
metadata:
  name: tardis
spec:
  k0s:
    version: v1.30.1+k0s.0
    config:
      spec:
        api:
          sans:
            - 192.168.0.30
        network:
          podCIDR: 10.244.0.0/16
          serviceCIDR: 10.96.0.0/12
          controlPlaneLoadBalancing:
            enabled: true
            type: Keepalived
            keepalived:
              vrrpInstances:
                - virtualIPs: ["192.168.0.30/23"]
                  authPass: homelab
        telemetry:
          enabled: false
  hosts:
  - ssh:
      address: 192.168.0.5
      user: root
      keyPath: ~/.ssh/id_rsa
    role: controller+worker
    noTaints: true

And results in this config on my one and only host:

# cat /etc/k0s/k0s.yaml
# generated-by-k0sctl 2024-06-12T21:43:50+02:00
apiVersion: k0s.k0sproject.io/v1beta1
kind: ClusterConfig
spec:
  api:
    address: 192.168.0.30
    sans:
    - 192.168.0.30
    - 192.168.0.5
    - 127.0.0.1
  network:
    controlPlaneLoadBalancing:
      enabled: true
      keepalived:
        vrrpInstances:
        - authPass: homelab
          virtualIPs:
          - 192.168.0.30/23
      type: Keepalived
    podCIDR: 10.244.0.0/16
    serviceCIDR: 10.96.0.0/12
  storage:
    etcd:
      peerAddress: 192.168.0.30
  telemetry:
    enabled: false

As you can see, the storage.etcd.peerAddress points to the CPLB. The VIP is not reachable since keepalived is running in the same systemd job which just crashed because etcd cannot reach the peers?

I know CPLB is not really useful with a single node, but I think this is the exact reason why our prod cluster just crashed. It rotated (maybe too quickly) all control plane nodes resulting in not available etcd peers, resulting in crashing the systemd service and just shooting itself in the foot.

jnummelin commented 3 weeks ago

@Skaronator Right, so k0s now picks up the CPLB address as etcd peering mistakenly. This happens because in your case the CPLB/keepalived interface happens to be found before the real interfaces when k0s is doing defaulting for the config.

In k0sctl yaml, you can add spec.hosts[*].privateInterface to specify which interface should be picked up for etcd peering.

There's a fix in flight for this in #4582 which will make k0s itself to ignore CPLB address from defaulting.

Skaronator commented 3 weeks ago

Alright. This fixed it, and the real fix is already included in the next k0s release. I'm going to close this, since the konnectivity agent logs are outside k0s control.

Thanks guys!