K3s startup stuck waiting for apiserver

[brandond]

Mar 01 06:03:30 k8s-1 k3s[2002157]: goroutine 31655 gp=0xc001401a40 m=nil [select]:
Mar 01 06:03:30 k8s-1 k3s[2002157]: runtime.gopark(0xc0131bbde8?, 0x2?, 0x10?, 0xe2?, 0xc0131bbdc4?)
Mar 01 06:03:30 k8s-1 k3s[2002157]:         /usr/local/go/src/runtime/proc.go:402 +0xce fp=0xc01cf07c68 sp=0xc01cf07c48 pc=0x44652e
Mar 01 06:03:30 k8s-1 k3s[2002157]: runtime.selectgo(0xc01cf07de8, 0xc0131bbdc0, 0xc001180ee0?, 0x0, 0xc001180ee0?, 0x1)
Mar 01 06:03:30 k8s-1 k3s[2002157]:         /usr/local/go/src/runtime/select.go:327 +0x725 fp=0xc01cf07d88 sp=0xc01cf07c68 pc=0x458b25
Mar 01 06:03:30 k8s-1 k3s[2002157]: k8s.io/apimachinery/pkg/util/wait.loopConditionUntilContext({0x7740c18, 0xc001180ee0}, {0x77237f0, 0xc01e337160}, 0x1, 0x0, 0xc01cf07f48)
Mar 01 06:03:30 k8s-1 k3s[2002157]:         /go/pkg/mod/github.com/k3s-io/kubernetes/staging/src/k8s.io/apimachinery@v1.31.5-k3s1/pkg/util/wait/loop.go:66 +0x1e6 fp=0xc01cf07e38 sp=0xc01cf07d88 pc=0xd2b866
Mar 01 06:03:30 k8s-1 k3s[2002157]: k8s.io/apimachinery/pkg/util/wait.PollUntilContextTimeout({0x7740ba8?, 0xc0013dd860?}, 0x3b9aca00, 0x1?, 0x1, 0xc016623f48)
Mar 01 06:03:30 k8s-1 k3s[2002157]:         /go/pkg/mod/github.com/k3s-io/kubernetes/staging/src/k8s.io/apimachinery@v1.31.5-k3s1/pkg/util/wait/poll.go:48 +0xa5 fp=0xc01cf07ea8 sp=0xc01cf07e38 pc=0xd2bd85
Mar 01 06:03:30 k8s-1 k3s[2002157]: github.com/k3s-io/k3s/pkg/util.WaitForAPIServerReady({0x7740ba8, 0xc0013dd860}, {0xc001905340?, 0xc0021f9980?}, 0x6fc23ac00)
Mar 01 06:03:30 k8s-1 k3s[2002157]:         /go/src/github.com/k3s-io/k3s/pkg/util/api.go:82 +0x1e5 fp=0xc01cf07f70 sp=0xc01cf07ea8 pc=0x262f265
Mar 01 06:03:30 k8s-1 k3s[2002157]: github.com/k3s-io/k3s/pkg/daemons/control.waitForAPIServerInBackground.func1.1()
Mar 01 06:03:30 k8s-1 k3s[2002157]:         /go/src/github.com/k3s-io/k3s/pkg/daemons/control/server.go:465 +0x37 fp=0xc01cf07fa8 sp=0xc01cf07f70 pc=0x4c152d7
Mar 01 06:03:30 k8s-1 k3s[2002157]: github.com/k3s-io/k3s/pkg/daemons/control.promise.func1()
Mar 01 06:03:30 k8s-1 k3s[2002157]:         /go/src/github.com/k3s-io/k3s/pkg/daemons/control/server.go:481 +0x23 fp=0xc01cf07fe0 sp=0xc01cf07fa8 pc=0x4c15423
Mar 01 06:03:30 k8s-1 k3s[2002157]: runtime.goexit({})
Mar 01 06:03:30 k8s-1 k3s[2002157]:         /usr/local/go/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc01cf07fe8 sp=0xc01cf07fe0 pc=0x4802c1
Mar 01 06:03:30 k8s-1 k3s[2002157]: created by github.com/k3s-io/k3s/pkg/daemons/control.promise in goroutine 4371
Mar 01 06:03:30 k8s-1 k3s[2002157]:         /go/src/github.com/k3s-io/k3s/pkg/daemons/control/server.go:480 +0x78

For some reason it was just stuck in that WaitForAPIServerReady PollUntilContextTimeout loop. It must have been failing at the restClient.Get phase because if it had successfully made the request but got a bad HTTP status we would have seen a log message.

I've never seen this before, but we can add some logging to that path in case this happens again.

Originally posted by @brandond in #11852 (reply in thread)

[brandond]

This turned out to be a bit of a can of worms. There's more I want to fix here than I can get in for this cycle, moving out to April.