Microk8s 1.21 fails to start after controlled cluster shutdown and restart

[ncrookston]

Hi all,

I have a 6-node microk8s cluster that’s been running pretty well for several months. We were recently notified that power would be cut to our office for 24 hours, so our IT folks shut down the cluster in a controlled manner before bringing it back up after power was restored. Previously, we’ve rebooted individual nodes without issue, but we never had all shut down at the same time.

Since then, we have been unable to fully restart the k8s services – any kubectl call is met with:

The connection to the server 127.0.0.1:16443 was refused - did you specify the right host or port?

I eventually shut down microk8s on all the cluster nodes before starting it on a single node. My plan is to get microk8s working again on one node before trying to fix them all. When I run microk8s status I get microk8s is not running. Use microk8s inspect for a deeper inspection. When I run microk8s inspect for a deeper inspection I get:

Inspecting Certificates
Inspecting services
  Service snap.microk8s.daemon-cluster-agent is running
  Service snap.microk8s.daemon-containerd is running
  Service snap.microk8s.daemon-apiserver-kicker is running
  Service snap.microk8s.daemon-kubelite is running
  Copy service arguments to the final report tarball
Inspecting AppArmor configuration
Gathering system information
  Copy processes list to the final report tarball
  Copy snap list to the final report tarball
  Copy VM name (or none) to the final report tarball
  Copy disk usage information to the final report tarball
  Copy memory usage information to the final report tarball
  Copy server uptime to the final report tarball
  Copy current linux distribution to the final report tarball
  Copy openSSL information to the final report tarball
  Copy network configuration to the final report tarball
Inspecting kubernetes cluster
  Inspect kubernetes cluster
Inspecting juju
  Inspect Juju
Inspecting kubeflow
  Inspect Kubeflow

Building the report tarball
  Report tarball is at /var/snap/microk8s/3058/inspection-report-20220429_180557.tar.gz

I saw somewhere that there should be a dqlite daemon running, but it doesn’t appear to be. Running sudo journalctl -n 1000 -u snap.microk8s.daemon-k8s-dqlite doesn’t yield any log entries.

kubelite does seem to have some issues where it takes too long to start the API server, though I don’t know where to go from here, based on them:

Apr 29 17:17:30 machine-name microk8s.daemon-kubelite[18093]: + exec /snap/microk8s/3058/kubelite --scheduler-args-file=/var/snap/microk8s/3058/args/kube-scheduler --controller-manager-args-file=/var/snap/microk8s/3058/args/kube-controller-manager --proxy-args-file=/var/snap/microk8s/3058/args/kube-proxy --kubelet-args-file=/var/snap/microk8s/3058/args/kubelet --apiserver-args-file=/var/snap/microk8s/3058/args/kube-apiserver --kubeconfig-file=/var/snap/microk8s/3058/credentials/client.config --start-control-plane=true
Apr 29 17:17:30 machine-name microk8s.daemon-kubelite[18093]: Starting kubelite
Apr 29 17:17:30 machine-name microk8s.daemon-kubelite[18093]: I0429 17:17:30.951688   18093 daemon.go:73] Waiting for the API server
Apr 29 17:17:30 machine-name microk8s.daemon-kubelite[18093]: I0429 17:17:30.954136   18093 daemon.go:65] Starting API Server
Apr 29 17:17:30 machine-name microk8s.daemon-kubelite[18093]: Flag --insecure-port has been deprecated, This flag has no effect now and will be removed in v1.24.
Apr 29 17:17:30 machine-name microk8s.daemon-kubelite[18093]: I0429 17:17:30.959717   18093 server.go:654] external host was not specified, using <ip #6>
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: Error: context deadline exceeded
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: F0429 17:22:32.730316   18093 daemon.go:67] API Server exited context deadline exceeded
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: goroutine 190 [running]:
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: k8s.io/kubernetes/vendor/k8s.io/klog/v2.stacks(0xc000010001, 0xc001242000, 0x58, 0x9a)
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]:         /build/microk8s/parts/k8s-binaries/build/go/src/github.com/kubernetes/kubernetes/_output/local/go/src/k8s.io/kubernetes/vendor/k8s.io/klog/v2/klog.go:1026 +0xb9
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: k8s.io/kubernetes/vendor/k8s.io/klog/v2.(*loggingT).output(0x9860560, 0xc000000003, 0x0, 0x0, 0xc000c49c70, 0x0, 0x7d129e0, 0x9, 0x43, 0x0)
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]:         /build/microk8s/parts/k8s-binaries/build/go/src/github.com/kubernetes/kubernetes/_output/local/go/src/k8s.io/kubernetes/vendor/k8s.io/klog/v2/klog.go:975 +0x1e5
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: k8s.io/kubernetes/vendor/k8s.io/klog/v2.(*loggingT).printf(0x9860560, 0xc000000003, 0x0, 0x0, 0x0, 0x0, 0x5f5d4a6, 0x14, 0xc000e16100, 0x1, ...)
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]:         /build/microk8s/parts/k8s-binaries/build/go/src/github.com/kubernetes/kubernetes/_output/local/go/src/k8s.io/kubernetes/vendor/k8s.io/klog/v2/klog.go:753 +0x19a
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: k8s.io/kubernetes/vendor/k8s.io/klog/v2.Fatalf(...)
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]:         /build/microk8s/parts/k8s-binaries/build/go/src/github.com/kubernetes/kubernetes/_output/local/go/src/k8s.io/kubernetes/vendor/k8s.io/klog/v2/klog.go:1514
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: k8s.io/kubernetes/cmd/kubelite/app/daemons.StartAPIServer(0xc000d62800, 0x19, 0x20, 0xc0013705a0)
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]:         /build/microk8s/parts/k8s-binaries/build/go/src/github.com/kubernetes/kubernetes/_output/local/go/src/k8s.io/kubernetes/cmd/kubelite/app/daemons/daemon.go:67 +0x225
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: created by k8s.io/kubernetes/cmd/kubelite/app.glob..func1
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]:         /build/microk8s/parts/k8s-binaries/build/go/src/github.com/kubernetes/kubernetes/_output/local/go/src/k8s.io/kubernetes/cmd/kubelite/app/server.go:42 +0x177
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: goroutine 1 [select]:
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait.WaitFor(0xc001224c90, 0xc001743c20, 0xc0013709c0, 0x0, 0x0)
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]:         /build/microk8s/parts/k8s-binaries/build/go/src/github.com/kubernetes/kubernetes/_output/local/go/src/k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:539 +0xf1
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait.pollInternal(0xc001224c90, 0xc00133fc20, 0x0, 0x0)
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]:         /build/microk8s/parts/k8s-binaries/build/go/src/github.com/kubernetes/kubernetes/_output/local/go/src/k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:427 +0x87
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait.pollImmediateInternal(0xc001224c90, 0xc00133fc20, 0xc001224c90, 0x463)
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]:         /build/microk8s/parts/k8s-binaries/build/go/src/github.com/kubernetes/kubernetes/_output/local/go/src/k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:452 +0x74
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait.PollImmediate(0x3b9aca00, 0x53d1ac1000, 0xc00133fc20, 0x0, 0x0)
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]:         /build/microk8s/parts/k8s-binaries/build/go/src/github.com/kubernetes/kubernetes/_output/local/go/src/k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:441 +0x4d
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: k8s.io/kubernetes/vendor/k8s.io/controller-manager/app.WaitForAPIServer(0x6a83e68, 0xc000015340, 0x53d1ac1000, 0x0, 0xc000358b40)
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]:         /build/microk8s/parts/k8s-binaries/build/go/src/github.com/kubernetes/kubernetes/_output/local/go/src/k8s.io/kubernetes/vendor/k8s.io/controller-manager/app/helper.go:35 +0x98
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: k8s.io/kubernetes/cmd/kubelite/app/daemons.WaitForAPIServer(0x7ffe6c3ecb0a, 0x31, 0x53d1ac1000)
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]:         /build/microk8s/parts/k8s-binaries/build/go/src/github.com/kubernetes/kubernetes/_output/local/go/src/k8s.io/kubernetes/cmd/kubelite/app/daemons/daemon.go:83 +0x2cc
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: k8s.io/kubernetes/cmd/kubelite/app.glob..func1(0x973a040, 0xc000c49c00, 0x0, 0x7)
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]:         /build/microk8s/parts/k8s-binaries/build/go/src/github.com/kubernetes/kubernetes/_output/local/go/src/k8s.io/kubernetes/cmd/kubelite/app/server.go:43 +0x1a5
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: k8s.io/kubernetes/vendor/github.com/spf13/cobra.(*Command).execute(0x973a040, 0xc000070090, 0x7, 0x7, 0x973a040, 0xc000070090)
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]:         /build/microk8s/parts/k8s-binaries/build/go/src/github.com/kubernetes/kubernetes/_output/local/go/src/k8s.io/kubernetes/vendor/github.com/spf13/cobra/command.go:854 +0x2c2
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: k8s.io/kubernetes/vendor/github.com/spf13/cobra.(*Command).ExecuteC(0x973a040, 0x10, 0xc000000300, 0x7cd78a)
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]:         /build/microk8s/parts/k8s-binaries/build/go/src/github.com/kubernetes/kubernetes/_output/local/go/src/k8s.io/kubernetes/vendor/github.com/spf13/cobra/command.go:958 +0x375
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: k8s.io/kubernetes/vendor/github.com/spf13/cobra.(*Command).Execute(...)
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]:         /build/microk8s/parts/k8s-binaries/build/go/src/github.com/kubernetes/kubernetes/_output/local/go/src/k8s.io/kubernetes/vendor/github.com/spf13/cobra/command.go:895
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: k8s.io/kubernetes/cmd/kubelite/app.Execute()
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]:         /build/microk8s/parts/k8s-binaries/build/go/src/github.com/kubernetes/kubernetes/_output/local/go/src/k8s.io/kubernetes/cmd/kubelite/app/server.go:63 +0x31
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: main.main()
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]:         _output/local/go/src/k8s.io/kubernetes/cmd/kubelite/kubelite.go:26 +0xf3
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: goroutine 6 [chan receive]:
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: k8s.io/kubernetes/vendor/k8s.io/klog/v2.(*loggingT).flushDaemon(0x9860560)
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]:         /build/microk8s/parts/k8s-binaries/build/go/src/github.com/kubernetes/kubernetes/_output/local/go/src/k8s.io/kubernetes/vendor/k8s.io/klog/v2/klog.go:1169 +0x8b
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: created by k8s.io/kubernetes/vendor/k8s.io/klog/v2.init.0
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]:         /build/microk8s/parts/k8s-binaries/build/go/src/github.com/kubernetes/kubernetes/_output/local/go/src/k8s.io/kubernetes/vendor/k8s.io/klog/v2/klog.go:420 +0xdf
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: goroutine 185 [select]:
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: k8s.io/kubernetes/vendor/go.opencensus.io/stats/view.(*worker).start(0xc00078f130)
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]:         /build/microk8s/parts/k8s-binaries/build/go/src/github.com/kubernetes/kubernetes/_output/local/go/src/k8s.io/kubernetes/vendor/go.opencensus.io/stats/view/worker.go:154 +0xcd
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: created by k8s.io/kubernetes/vendor/go.opencensus.io/stats/view.init.0
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]:         /build/microk8s/parts/k8s-binaries/build/go/src/github.com/kubernetes/kubernetes/_output/local/go/src/k8s.io/kubernetes/vendor/go.opencensus.io/stats/view/worker.go:32 +0x57
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: goroutine 186 [select]:
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait.BackoffUntil(0x618db20, 0x69719a0, 0xc000d73bc0, 0x1, 0xc000080120)
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]:         /build/microk8s/parts/k8s-binaries/build/go/src/github.com/kubernetes/kubernetes/_output/local/go/src/k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:167 +0x118
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait.JitterUntil(0x618db20, 0x12a05f200, 0x0, 0x1, 0xc000080120)
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]:         /build/microk8s/parts/k8s-binaries/build/go/src/github.com/kubernetes/kubernetes/_output/local/go/src/k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:133 +0x98
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait.Until(...)
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]:         /build/microk8s/parts/k8s-binaries/build/go/src/github.com/kubernetes/kubernetes/_output/local/go/src/k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:90
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait.Forever(0x618db20, 0x12a05f200)
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]:         /build/microk8s/parts/k8s-binaries/build/go/src/github.com/kubernetes/kubernetes/_output/local/go/src/k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:81 +0x4f
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: created by k8s.io/kubernetes/vendor/k8s.io/component-base/logs.InitLogs
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]:         /build/microk8s/parts/k8s-binaries/build/go/src/github.com/kubernetes/kubernetes/_output/local/go/src/k8s.io/kubernetes/vendor/k8s.io/component-base/logs/logs.go:58 +0x8a
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: goroutine 188 [syscall, 5 minutes]:
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: os/signal.signal_recv(0x0)
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]:         /snap/go/9362/src/runtime/sigqueue.go:168 +0xa5
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: os/signal.loop()
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]:         /snap/go/9362/src/os/signal/signal_unix.go:23 +0x25
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: created by os/signal.Notify.func1.1
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]:         /snap/go/9362/src/os/signal/signal.go:151 +0x45
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: goroutine 189 [chan receive, 5 minutes]:
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: k8s.io/kubernetes/vendor/k8s.io/apiserver/pkg/server.SetupSignalContext.func1(0xc000896b40)
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]:         /build/microk8s/parts/k8s-binaries/build/go/src/github.com/kubernetes/kubernetes/_output/local/go/src/k8s.io/kubernetes/vendor/k8s.io/apiserver/pkg/server/signal.go:48 +0x36
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: created by k8s.io/kubernetes/vendor/k8s.io/apiserver/pkg/server.SetupSignalContext
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]:         /build/microk8s/parts/k8s-binaries/build/go/src/github.com/kubernetes/kubernetes/_output/local/go/src/k8s.io/kubernetes/vendor/k8s.io/apiserver/pkg/server/signal.go:47 +0xf3
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: goroutine 232 [IO wait]:
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: internal/poll.runtime_pollWait(0x7fec6483aef0, 0x72, 0x0)
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]:         /snap/go/9362/src/runtime/netpoll.go:227 +0x55
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: internal/poll.(*pollDesc).wait(0xc000f07818, 0x72, 0x0, 0x0, 0x5f28f87)
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]:         /snap/go/9362/src/internal/poll/fd_poll_runtime.go:87 +0x45
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: internal/poll.(*pollDesc).waitRead(...)
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]:         /snap/go/9362/src/internal/poll/fd_poll_runtime.go:92
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: internal/poll.(*FD).Accept(0xc000f07800, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]:         /snap/go/9362/src/internal/poll/fd_unix.go:401 +0x212
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: net.(*netFD).accept(0xc000f07800, 0x0, 0x0, 0x0)
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]:         /snap/go/9362/src/net/fd_unix.go:172 +0x45
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: net.(*TCPListener).accept(0xc000991bf0, 0xc00179af30, 0xc00179af38, 0x40)
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]:         /snap/go/9362/src/net/tcpsock_posix.go:139 +0x32
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: net.(*TCPListener).Accept(0xc000991bf0, 0x6188248, 0xc0016f7b10, 0x69f5db0, 0xc0016d4600)
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]:         /snap/go/9362/src/net/tcpsock.go:261 +0x65
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: k8s.io/kubernetes/vendor/github.com/canonical/go-dqlite/app.(*App).proxy(0xc0001aab60)
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]:         /build/microk8s/parts/k8s-binaries/build/go/src/github.com/kubernetes/kubernetes/_output/local/go/src/k8s.io/kubernetes/vendor/github.com/canonical/go-dqlite/app/app.go:423 +0xa3
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: created by k8s.io/kubernetes/vendor/github.com/canonical/go-dqlite/app.New
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]:         /build/microk8s/parts/k8s-binaries/build/go/src/github.com/kubernetes/kubernetes/_output/local/go/src/k8s.io/kubernetes/vendor/github.com/canonical/go-dqlite/app/app.go:239 +0x1267
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: goroutine 242 [select]:
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait.poller.func1.1(0xc001370a80, 0x3b9aca00, 0x53d1ac1000, 0xc001370a20)
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]:         /build/microk8s/parts/k8s-binaries/build/go/src/github.com/kubernetes/kubernetes/_output/local/go/src/k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:588 +0x135
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: created by k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait.poller.func1
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]:         /build/microk8s/parts/k8s-binaries/build/go/src/github.com/kubernetes/kubernetes/_output/local/go/src/k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:571 +0x8c
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: goroutine 233 [sleep]:
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: time.Sleep(0x3b9aca00)
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]:         /snap/go/9362/src/runtime/time.go:193 +0xd2
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: k8s.io/kubernetes/vendor/github.com/canonical/go-dqlite/internal/protocol.makeRetryStrategies.func1(0x112, 0x111)
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]:         /build/microk8s/parts/k8s-binaries/build/go/src/github.com/kubernetes/kubernetes/_output/local/go/src/k8s.io/kubernetes/vendor/github.com/canonical/go-dqlite/internal/protocol/connector.go:320 +0x65
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: k8s.io/kubernetes/vendor/github.com/Rican7/retry.shouldAttempt(0x112, 0xc00069b4c8, 0x1, 0x1, 0x9893f01)
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]:         /build/microk8s/parts/k8s-binaries/build/go/src/github.com/kubernetes/kubernetes/_output/local/go/src/k8s.io/kubernetes/vendor/github.com/Rican7/retry/retry.go:32 +0x47
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: k8s.io/kubernetes/vendor/github.com/Rican7/retry.Retry(0xc000e79d40, 0xc00069b4c8, 0x1, 0x1, 0x1, 0x1)
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]:         /build/microk8s/parts/k8s-binaries/build/go/src/github.com/kubernetes/kubernetes/_output/local/go/src/k8s.io/kubernetes/vendor/github.com/Rican7/retry/retry.go:19 +0x9c
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: k8s.io/kubernetes/vendor/github.com/canonical/go-dqlite/internal/protocol.(*Connector).Connect(0xc00179edf0, 0x69f5db0, 0xc000dc83c0, 0x7fec8f464d40, 0x10, 0x10)
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]:         /build/microk8s/parts/k8s-binaries/build/go/src/github.com/kubernetes/kubernetes/_output/local/go/src/k8s.io/kubernetes/vendor/github.com/canonical/go-dqlite/internal/protocol/connector.go:74 +0xc7
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: k8s.io/kubernetes/vendor/github.com/canonical/go-dqlite/client.FindLeader(0x69f5db0, 0xc000dc83c0, 0x697ccc0, 0xc0016d44c0, 0xc00037b8b0, 0x2, 0x2, 0x1d7cb46c039cd, 0xc000430e10, 0xc000aa7da0)
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]:         /build/microk8s/parts/k8s-binaries/build/go/src/github.com/kubernetes/kubernetes/_output/local/go/src/k8s.io/kubernetes/vendor/github.com/canonical/go-dqlite/client/leader.go:26 +0x1ac
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: k8s.io/kubernetes/vendor/github.com/canonical/go-dqlite/app.(*App).Leader(0xc0001aab60, 0x69f5db0, 0xc000dc83c0, 0x0, 0x2, 0x1)
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]:         /build/microk8s/parts/k8s-binaries/build/go/src/github.com/kubernetes/kubernetes/_output/local/go/src/k8s.io/kubernetes/vendor/github.com/canonical/go-dqlite/app/app.go:410 +0x7c
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: k8s.io/kubernetes/vendor/github.com/canonical/go-dqlite/app.(*App).run(0xc0001aab60, 0x69f5db0, 0xc000dc83c0, 0x6fc23ac00, 0x0)
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]:         /build/microk8s/parts/k8s-binaries/build/go/src/github.com/kubernetes/kubernetes/_output/local/go/src/k8s.io/kubernetes/vendor/github.com/canonical/go-dqlite/app/app.go:465 +0x15f
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]: created by k8s.io/kubernetes/vendor/github.com/canonical/go-dqlite/app.New
Apr 29 17:22:32 machine-name microk8s.daemon-kubelite[18093]:         /build/microk8s/parts/k8s-binaries/build/go/src/github.com/kubernetes/kubernetes/_output/local/go/src/k8s.io/kubernetes/vendor/github.com/canonical/go-dqlite/app/app.go:245 +0x105b
Apr 29 17:22:32 machine-name systemd[1]: snap.microk8s.daemon-kubelite.service: Main process exited, code=exited, status=255/n/a
Apr 29 17:22:32 machine-name systemd[1]: snap.microk8s.daemon-kubelite.service: Failed with result 'exit-code'.
Apr 29 17:22:33 machine-name systemd[1]: snap.microk8s.daemon-kubelite.service: Service hold-off time over, scheduling restart.
(repeated many times over several days)

Googling based on what I’m seeing here didn’t yield any smoking guns. The steps recommended in

Recovery of HA MicroK8s Clusters

Recovering failed ha-cluster enabled microk8s deployments Background When using the ha-cluster add-on for microk8s 1.19 and newer, which is now the default microk8s clustering method, microk8s uses an alternate backing store which utilises dqlite instead of etcd. Whilst work is always ongoing to improve the stability and ability to self-heal in both microk8s and dqlite, in case of catastrophic cluster failure or data corruption, you may find yourself in a situation where you have to manually recover your cluster. The process is different to recovering an etcd cluster, but is fairly straight f…

didn’t quite apply since I don’t have any nodes in a usable state, and when I tried its instructions with one node I was still unable to start microk8s successfully. An approach where I isolate a single node and start it by changing the cluster.yaml file (suggested by topic

Recover from lost quorum

By default, a three-node MicroK8s cluster automatically becomes highly available (HA). In HA mode the default datastore (dqlite) implements a Raft based protocol where an elected leader holds the definitive copy of the database. Under normal operation copies of the database are maintained by two more nodes. If you permanently lose the majority of the cluster members that serve as database nodes (for example, if you have a three-node cluster and you lose two of them), the cluster will become unavailable. However, if at least one database node has survived, you will be able to recover the cluste…

) also didn’t work when I tried that on a different node.

Can someone give me some help interpreting the logs posted above, or guidance on where to look next?

[balchua1]

Did you start all the nodes or just 1? If you start 1 node, my guess is that dqlite couldn’t form a quorum and will not serve request from the api server.
Try starting atleast 3 nodes. The separation of k8s-dqlite was started from v1.23.

Also can you create a github issue for this?
Thanks

[ncrookston]

Thanks for the tip! I had tried with all 6 previously, but I didn’t check the logs until I shut down all but one (in an attempt to reduce complexity, or so I thought).

While starting 3 doesn’t allow k8s to respond to kubectl commands, it does lead to a different, more telling error.
On machine 3 it complains:

Apr 30 01:26:37 machine-name-3 microk8s.daemon-kubelite[30539]: I0430 01:26:37.909185   30539 server.go:654] external host was not specified, using <IP #3>
Apr 30 01:26:41 machine-name-3 microk8s.daemon-kubelite[30539]: I0430 01:26:41.309369   30539 log.go:184] [ERROR] dqlite: proxy: first: remote -> local: read <IP #3>:19001-><IP #2>:38944: read: connection reset by peer
Apr 30 01:26:51 machine-name-3 systemd[1]: snap.microk8s.daemon-kubelite.service: Main process exited, code=killed, status=11/SEGV

On machine 2:

Apr 30 02:40:01 machine-name-2 microk8s.daemon-kubelite[42482]: I0430 02:40:01.125471   42482 server.go:654] external host was not specified, using <IP #2>
Apr 30 02:40:06 machine-name-2 microk8s.daemon-kubelite[42482]: I0430 02:40:06.145030   42482 log.go:184] [ERROR] dqlite: proxy: first: remote -> local: read tcp <IP #2>:19001-><IP #1>:41006: read: connection reset by peer

And on machine 1:

Apr 30 02:42:46 machine-name-1 microk8s.daemon-kubelite[48129]: I0430 02:42:46.230307   48129 server.go:654] external host was not specified, using <IP #1>
Apr 30 02:42:50 machine-name-1 microk8s.daemon-kubelite[48129]: I0430 02:42:50.026909   48129 log.go:184] [ERROR] dqlite: proxy: first: remote -> local: read tcp <IP #1>:19001-><IP #2>:42976: read: connection reset by peer
Apr 30 02:43:00 machine-name-1 microk8s.daemon-kubelite[48129]: I0430 02:43:00.483584   48129 log.go:184] [ERROR] dqlite: proxy: first: remote -> local: read tcp <IP #1>:19001-><IP #3>:58952: read: connection reset by peer
Apr 30 02:43:06 machine-name-1 microk8s.daemon-kubelite[48129]: I0430 02:43:06.016426   48129 log.go:184] [ERROR] dqlite: proxy: first: remote -> local: read tcp <IP #1>:19001-><IP #2>:43238: read: connection reset by peer
Apr 30 02:43:12 machine-name-1 microk8s.daemon-kubelite[48129]: I0430 02:43:12.076984   48129 log.go:184] [ERROR] dqlite: proxy: first: remote -> local: read tcp <IP #1>:19001-><IP #2>:43338: read: connection reset by peer
Apr 30 02:43:28 machine-name-1 microk8s.daemon-kubelite[48129]: I0430 02:43:28.466169   48129 log.go:184] [ERROR] dqlite: proxy: first: remote -> local: read tcp <IP #1>:19001-><IP #3>:59424: read: connection reset by peer
Apr 30 02:43:48 machine-name-1 microk8s.daemon-kubelite[48129]: I0430 02:43:48.977108   48129 log.go:184] [ERROR] dqlite: proxy: first: remote -> local: read tcp <IP #1>:19001-><IP #2>:43950: read: connection reset by peer
Apr 30 02:44:13 machine-name-1 microk8s.daemon-kubelite[48129]: I0430 02:44:13.007527   48129 log.go:184] [ERROR] dqlite: proxy: first: remote -> local: read tcp <IP #1>:19001-><IP #2>:44344: read: connection reset by peer

Based on this, I believe the three machines know about each other, but they’re unable to replicate their datastores to each other. The only existing ticket I’ve found that looks similar (node NotReady , microk8s inspect with no errors, random node drop out of cluster · Issue #1868 · canonical/microk8s · GitHub) had a happy but uninformative resolution. I’ve created a new ticket (Microk8s 1.21 fails to start after controlled cluster shutdown and restart · Issue #3114 · canonical/microk8s · GitHub) and attached kubelite log files for each node.

Thanks again!