k8s kubectl takes 12 seconds

[nobuto-m]

Summary

$ time sudo k8s kubectl -v=6 get node |& ts -s
00:00:12 I0201 02:28:03.723482 2791472 loader.go:402] Config loaded from file:  /etc/kubernetes/admin.conf
00:00:12 I0201 02:28:03.975911 2791472 round_trippers.go:560] GET https://127.0.0.1:6443/api/v1/nodes?limit=500 200 OK in 105 milliseconds
00:00:12 NAME        STATUS   ROLES                  AGE   VERSION
00:00:12 sunbeam-1   Ready    control-plane,worker   10h   v1.32.0
00:00:12 sunbeam-2   Ready    control-plane,worker   9h    v1.32.0
00:00:12 sunbeam-3   Ready    control-plane,worker   9h    v1.32.0

real    0m12.075s
user    0m0.034s
sys     0m0.029s

It takes 12 seconds before starting loading kubeconfig.

In the meantime, kubectl snap with a pregenerated kubeconfig takes 2.6 seconds.

$ sudo k8s kubectl config view --raw | tee kubeconfig
$ time kubectl --kubeconfig=kubeconfig -v=6 get node |& ts -s
00:00:02 I0201 02:31:10.939495 2803192 loader.go:395] Config loaded from file:  kubeconfig
00:00:02 I0201 02:31:10.994559 2803192 round_trippers.go:553] GET https://127.0.0.1:6443/api/v1/nodes?limit=500 200 OK in 28 milliseconds
00:00:02 NAME        STATUS   ROLES                  AGE   VERSION
00:00:02 sunbeam-1   Ready    control-plane,worker   10h   v1.32.0
00:00:02 sunbeam-2   Ready    control-plane,worker   9h    v1.32.0
00:00:02 sunbeam-3   Ready    control-plane,worker   9h    v1.32.0

real    0m2.696s
user    0m0.199s
sys     0m2.520s

And a bare binary takes 0.5 seconds.

$ time ./kubectl --kubeconfig=kubeconfig -v=6 get node |& ts -s
00:00:00 I0201 02:33:58.727394 2810946 loader.go:402] Config loaded from file:  kubeconfig
00:00:00 I0201 02:33:58.728038 2810946 envvar.go:172] "Feature gate default state" feature="ClientsPreferCBOR" enabled=false
00:00:00 I0201 02:33:58.728068 2810946 envvar.go:172] "Feature gate default state" feature="InformerResourceVersion" enabled=false
00:00:00 I0201 02:33:58.728080 2810946 envvar.go:172] "Feature gate default state" feature="WatchListClient" enabled=false
00:00:00 I0201 02:33:58.728087 2810946 envvar.go:172] "Feature gate default state" feature="ClientsAllowCBOR" enabled=false
00:00:01 I0201 02:33:59.120134 2810946 round_trippers.go:560] GET https://127.0.0.1:6443/api/v1/nodes?limit=500 200 OK in 384 milliseconds
00:00:01 NAME        STATUS   ROLES                  AGE   VERSION
00:00:01 sunbeam-1   Ready    control-plane,worker   10h   v1.32.0
00:00:01 sunbeam-2   Ready    control-plane,worker   9h    v1.32.0
00:00:01 sunbeam-3   Ready    control-plane,worker   9h    v1.32.0

real    0m0.479s
user    0m0.109s
sys     0m0.064s

What Should Happen Instead?

Just taking less than a few seconds is a fair expectation.

Reproduction Steps

As per above.

System information

k8s v1.32.0 1931 latest/stable canonical✓ classic,held

Can you suggest a fix?

No response

Are you interested in contributing with a fix?

No response

[louiseschmidtgen]

Hi @nobuto-m,

Thank you for raising your issue.

The difference that you are seeing is likely a consequence of a check that we run before executing the kubectl command. This check looks if the node that you're on is already part of the cluster, if it is not the user is asked to bootstrap the node.

This check shouldn't be taking seconds to execute. Is this high execution time reproducible?

[nobuto-m]

The difference that you are seeing is likely a consequence of a check that we run before executing the kubectl command. This check looks if the node that you're on is already part of the cluster, if it is not the user is asked to bootstrap the node.

Is there any way to increase the log level to confirm it? Like k8s --debug kubectl?

This check shouldn't be taking seconds to execute. Is this high execution time reproducible?

It's consistent to me although the system is a bit busy. The context is Sunbeam deployment on top of Canonical K8s.

[louiseschmidtgen]

Hi @nobuto-m,

You can run sudo k8s kubectl -v=9 get no to rule out that the kubectl command is taking the time.

You can increase the log-level for k8sd to see more details by adding flags to this file:

#/var/snap/k8s/common/args/k8sd
--state-dir=${SNAP_COMMON}/var/lib/k8sd/state
--debug=true
--verbose=true

run sudo snap restart k8s.k8sd and see journalctl -u snap.k8s.k8sd -f for the debug logs.

Does this point you to the cause?