search

rancher / k3os

Purpose-built OS for Kubernetes, fully managed by Kubernetes.
https://k3os.io
Apache License 2.0
3.5k stars 401 forks source link

Cluster died / fails to start (after upgrade?) #790

Closed mr-onion-2 closed 2 years ago

mr-onion-2 commented 2 years ago

k3os version v0.19.15-k3s2r0 5.4.51-v8+ #1333 SMP PREEMPT Mon Aug 10 16:58:35 BST 2020 aarch64

Hi My cluster has been working flawlessly until about 2am this morning. I could be wrong but I am guessing that it tried to perform auto-upgrade, and now it will not start. The logs point to an invalid bearer token.

k3s --debug server produces the following.

DEBU[0000] Asset dir /var/lib/rancher/k3s/data/9cbaf87b73f0bc19774ba256b577f7a9cf7842dafbf872eb08b2ca2512d44bc5 
DEBU[0000] Running /var/lib/rancher/k3s/data/9cbaf87b73f0bc19774ba256b577f7a9cf7842dafbf872eb08b2ca2512d44bc5/bin/k3s-server [k3s --debug server] 
INFO[2021-10-09T09:42:21.794007215Z] Starting k3s v1.19.15+k3s2 (0fbbc5af)        
INFO[2021-10-09T09:42:21.794968628Z] Managed etcd cluster bootstrap already complete and initialized 
{"level":"info","ts":"2021-10-09T09:42:21.927Z","caller":"embed/etcd.go:117","msg":"configuring peer listeners","listen-peer-urls":["https://xx.xx.xx.200:2380"]}
{"level":"info","ts":"2021-10-09T09:42:21.927Z","caller":"embed/etcd.go:468","msg":"starting with peer TLS","tls-info":"cert = /var/lib/rancher/k3s/server/tls/etcd/peer-server-client.crt, key = /var/lib/rancher/k3s/server/tls/etcd/peer-server-client.key, trusted-ca = /var/lib/rancher/k3s/server/tls/etcd/peer-ca.crt, client-cert-auth = true, crl-file = ","cipher-suites":[]}
{"level":"info","ts":"2021-10-09T09:42:21.929Z","caller":"embed/etcd.go:127","msg":"configuring client listeners","listen-client-urls":["https://xx.xx.xx.200:2379","https://127.0.0.1:2379"]}
{"level":"info","ts":"2021-10-09T09:42:21.930Z","caller":"embed/etcd.go:302","msg":"starting an etcd server","etcd-version":"3.4.13","git-sha":"Not provided (use ./build instead of go build)","go-version":"go1.15.14","go-os":"linux","go-arch":"arm64","max-cpu-set":4,"max-cpu-available":4,"member-initialized":true,"name":"k3s-master-0d1b294d","data-dir":"/var/lib/rancher/k3s/server/db/etcd","wal-dir":"","wal-dir-dedicated":"","member-dir":"/var/lib/rancher/k3s/server/db/etcd/member","force-new-cluster":false,"heartbeat-interval":"500ms","election-timeout":"5s","initial-election-tick-advance":true,"snapshot-count":100000,"snapshot-catchup-entries":5000,"initial-advertise-peer-urls":["http://localhost:2380"],"listen-peer-urls":["https://xx.xx.xx.200:2380"],"advertise-client-urls":["https://xx.xx.xx.200:2379"],"listen-client-urls":["https://xx.xx.xx.200:2379","https://127.0.0.1:2379"],"listen-metrics-urls":["http://127.0.0.1:2381"],"cors":["*"],"host-whitelist":["*"],"initial-cluster":"","initial-cluster-state":"new","initial-cluster-token":"","quota-size-bytes":2147483648,"pre-vote":false,"initial-corrupt-check":false,"corrupt-check-time-interval":"0s","auto-compaction-mode":"","auto-compaction-retention":"0s","auto-compaction-interval":"0s","discovery-url":"","discovery-proxy":""}
INFO[2021-10-09T09:42:22.011014688Z] Cluster-Http-Server 2021/10/09 09:42:22 http: TLS handshake error from xx.xx.xx.203:60910: EOF 
{"level":"info","ts":"2021-10-09T09:42:22.014Z","caller":"etcdserver/backend.go:80","msg":"opened backend db","path":"/var/lib/rancher/k3s/server/db/etcd/member/snap/db","took":"82.285421ms"}
INFO[2021-10-09T09:42:22.071441153Z] Cluster-Http-Server 2021/10/09 09:42:22 http: TLS handshake error from xx.xx.xx.205:39748: EOF 
{"level":"info","ts":"2021-10-09T09:42:25.899Z","caller":"etcdserver/server.go:451","msg":"recovered v2 store from snapshot","snapshot-index":2400028,"snapshot-size":"7.2 kB"}
{"level":"info","ts":"2021-10-09T09:42:25.905Z","caller":"mvcc/kvstore.go:380","msg":"restored last compact revision","meta-bucket-name":"meta","meta-bucket-name-key":"finishedCompactRev","restored-compact-revision":2321765}
{"level":"info","ts":"2021-10-09T09:42:25.988Z","caller":"etcdserver/server.go:469","msg":"recovered v3 backend from snapshot","backend-size-bytes":21590016,"backend-size":"22 MB","backend-size-in-use-bytes":20082688,"backend-size-in-use":"20 MB"}
{"level":"info","ts":"2021-10-09T09:42:28.118Z","caller":"etcdserver/raft.go:536","msg":"restarting local member","cluster-id":"b4b2591d23a36554","local-member-id":"2cca587b7efcef8e","commit-index":2454654}
{"level":"info","ts":"2021-10-09T09:42:28.135Z","caller":"raft/raft.go:1530","msg":"2cca587b7efcef8e switched to configuration voters=(3227489370399109006)"}
{"level":"info","ts":"2021-10-09T09:42:28.135Z","caller":"raft/raft.go:700","msg":"2cca587b7efcef8e became follower at term 831"}
{"level":"info","ts":"2021-10-09T09:42:28.135Z","caller":"raft/raft.go:383","msg":"newRaft 2cca587b7efcef8e [peers: [2cca587b7efcef8e], term: 831, commit: 2454654, applied: 2400028, lastindex: 2454654, lastterm: 831]"}
{"level":"info","ts":"2021-10-09T09:42:28.136Z","caller":"api/capability.go:76","msg":"enabled capabilities for version","cluster-version":"3.4"}
{"level":"info","ts":"2021-10-09T09:42:28.136Z","caller":"membership/cluster.go:256","msg":"recovered/added member from store","cluster-id":"b4b2591d23a36554","local-member-id":"2cca587b7efcef8e","recovered-remote-peer-id":"2cca587b7efcef8e","recovered-remote-peer-urls":["https://xx.xx.xx.200:2380"]}
{"level":"info","ts":"2021-10-09T09:42:28.136Z","caller":"membership/cluster.go:269","msg":"set cluster version from store","cluster-version":"3.4"}
{"level":"warn","ts":"2021-10-09T09:42:28.142Z","caller":"auth/store.go:1366","msg":"simple token is not cryptographically signed"}
{"level":"info","ts":"2021-10-09T09:42:28.147Z","caller":"mvcc/kvstore.go:380","msg":"restored last compact revision","meta-bucket-name":"meta","meta-bucket-name-key":"finishedCompactRev","restored-compact-revision":2321765}
{"level":"info","ts":"2021-10-09T09:42:28.225Z","caller":"etcdserver/quota.go:98","msg":"enabled backend quota with default value","quota-name":"v3-applier","quota-size-bytes":2147483648,"quota-size":"2.1 GB"}
{"level":"info","ts":"2021-10-09T09:42:28.231Z","caller":"etcdserver/server.go:790","msg":"starting etcd server","local-member-id":"2cca587b7efcef8e","local-server-version":"3.4.13","cluster-id":"b4b2591d23a36554","cluster-version":"3.4"}
{"level":"info","ts":"2021-10-09T09:42:28.232Z","caller":"etcdserver/server.go:669","msg":"started as single-node; fast-forwarding election ticks","local-member-id":"2cca587b7efcef8e","forward-ticks":9,"forward-duration":"4.5s","election-ticks":10,"election-timeout":"5s"}
{"level":"info","ts":"2021-10-09T09:42:28.257Z","caller":"embed/etcd.go:579","msg":"serving peer traffic","address":"xx.xx.xx.200:2380"}
{"level":"info","ts":"2021-10-09T09:42:28.258Z","caller":"embed/etcd.go:711","msg":"starting with client TLS","tls-info":"cert = /var/lib/rancher/k3s/server/tls/etcd/server-client.crt, key = /var/lib/rancher/k3s/server/tls/etcd/server-client.key, trusted-ca = /var/lib/rancher/k3s/server/tls/etcd/server-ca.crt, client-cert-auth = true, crl-file = ","cipher-suites":[]}
{"level":"info","ts":"2021-10-09T09:42:28.259Z","caller":"embed/etcd.go:781","msg":"serving metrics","address":"http://127.0.0.1:2381"}
{"level":"info","ts":"2021-10-09T09:42:28.259Z","caller":"embed/etcd.go:244","msg":"now serving peer/client/metrics","local-member-id":"2cca587b7efcef8e","initial-advertise-peer-urls":["http://localhost:2380"],"listen-peer-urls":["https://xx.xx.xx.200:2380"],"advertise-client-urls":["https://xx.xx.xx.200:2379"],"listen-client-urls":["https://xx.xx.xx.200:2379","https://127.0.0.1:2379"],"listen-metrics-urls":["http://127.0.0.1:2381"]}
INFO[2021-10-09T09:42:28.261994543Z] Running kube-apiserver --advertise-port=6443 --allow-privileged=true --anonymous-auth=false --api-audiences=unknown --authorization-mode=Node,RBAC --bind-address=127.0.0.1 --cert-dir=/var/lib/rancher/k3s/server/tls/temporary-certs --client-ca-file=/var/lib/rancher/k3s/server/tls/client-ca.crt --enable-admission-plugins=NodeRestriction --etcd-cafile=/var/lib/rancher/k3s/server/tls/etcd/server-ca.crt --etcd-certfile=/var/lib/rancher/k3s/server/tls/etcd/client.crt --etcd-keyfile=/var/lib/rancher/k3s/server/tls/etcd/client.key --etcd-servers=https://127.0.0.1:2379 --insecure-port=0 --kubelet-certificate-authority=/var/lib/rancher/k3s/server/tls/server-ca.crt --kubelet-client-certificate=/var/lib/rancher/k3s/server/tls/client-kube-apiserver.crt --kubelet-client-key=/var/lib/rancher/k3s/server/tls/client-kube-apiserver.key --profiling=false --proxy-client-cert-file=/var/lib/rancher/k3s/server/tls/client-auth-proxy.crt --proxy-client-key-file=/var/lib/rancher/k3s/server/tls/client-auth-proxy.key --requestheader-allowed-names=system:auth-proxy --requestheader-client-ca-file=/var/lib/rancher/k3s/server/tls/request-header-ca.crt --requestheader-extra-headers-prefix=X-Remote-Extra- --requestheader-group-headers=X-Remote-Group --requestheader-username-headers=X-Remote-User --secure-port=6444 --service-account-issuer=k3s --service-account-key-file=/var/lib/rancher/k3s/server/tls/service.key --service-account-signing-key-file=/var/lib/rancher/k3s/server/tls/service.key --service-cluster-ip-range=10.43.0.0/16 --storage-backend=etcd3 --tls-cert-file=/var/lib/rancher/k3s/server/tls/serving-kube-apiserver.crt --tls-private-key-file=/var/lib/rancher/k3s/server/tls/serving-kube-apiserver.key 
{"level":"warn","ts":"2021-10-09T09:42:29.297Z","caller":"etcdserver/util.go:121","msg":"failed to apply request","took":"402.098µs","request":"header:<ID:17261871192327109545 > lease_revoke:<id:6f8e7c4077f38644>","response":"size:31","error":"lease not found"}
{"level":"info","ts":"2021-10-09T09:42:30.638Z","caller":"raft/raft.go:923","msg":"2cca587b7efcef8e is starting a new election at term 831"}
{"level":"info","ts":"2021-10-09T09:42:30.638Z","caller":"raft/raft.go:713","msg":"2cca587b7efcef8e became candidate at term 832"}
{"level":"info","ts":"2021-10-09T09:42:30.638Z","caller":"raft/raft.go:824","msg":"2cca587b7efcef8e received MsgVoteResp from 2cca587b7efcef8e at term 832"}
{"level":"info","ts":"2021-10-09T09:42:30.638Z","caller":"raft/raft.go:765","msg":"2cca587b7efcef8e became leader at term 832"}
{"level":"info","ts":"2021-10-09T09:42:30.638Z","caller":"raft/node.go:325","msg":"raft.node: 2cca587b7efcef8e elected leader 2cca587b7efcef8e at term 832"}
{"level":"info","ts":"2021-10-09T09:42:30.639Z","caller":"etcdserver/server.go:2039","msg":"published local member to cluster through raft","local-member-id":"2cca587b7efcef8e","local-member-attributes":"{Name:k3s-master-0d1b294d ClientURLs:[https://xx.xx.xx.200:2379]}","request-path":"/0/members/2cca587b7efcef8e/attributes","cluster-id":"b4b2591d23a36554","publish-timeout":"15s"}
{"level":"info","ts":"2021-10-09T09:42:30.646Z","caller":"embed/serve.go:191","msg":"serving client traffic securely","address":"127.0.0.1:2379"}
{"level":"info","ts":"2021-10-09T09:42:30.646Z","caller":"embed/serve.go:191","msg":"serving client traffic securely","address":"xx.xx.xx.200:2379"}
INFO[2021-10-09T09:42:30.684248797Z] etcd data store connection OK                
I1009 09:42:30.694225    6910 server.go:652] external host was not specified, using xx.xx.xx.200
I1009 09:42:30.696252    6910 server.go:177] Version: v1.19.15+k3s2
I1009 09:42:30.748295    6910 plugins.go:158] Loaded 12 mutating admission controller(s) successfully in the following order: NamespaceLifecycle,LimitRanger,ServiceAccount,NodeRestriction,TaintNodesByCondition,Priority,DefaultTolerationSeconds,DefaultStorageClass,StorageObjectInUseProtection,RuntimeClass,DefaultIngressClass,MutatingAdmissionWebhook.
I1009 09:42:30.749112    6910 plugins.go:161] Loaded 10 validating admission controller(s) successfully in the following order: LimitRanger,ServiceAccount,Priority,PersistentVolumeClaimResize,RuntimeClass,CertificateApproval,CertificateSigning,CertificateSubjectRestriction,ValidatingAdmissionWebhook,ResourceQuota.
I1009 09:42:30.756385    6910 plugins.go:158] Loaded 12 mutating admission controller(s) successfully in the following order: NamespaceLifecycle,LimitRanger,ServiceAccount,NodeRestriction,TaintNodesByCondition,Priority,DefaultTolerationSeconds,DefaultStorageClass,StorageObjectInUseProtection,RuntimeClass,DefaultIngressClass,MutatingAdmissionWebhook.
I1009 09:42:30.757206    6910 plugins.go:161] Loaded 10 validating admission controller(s) successfully in the following order: LimitRanger,ServiceAccount,Priority,PersistentVolumeClaimResize,RuntimeClass,CertificateApproval,CertificateSigning,CertificateSubjectRestriction,ValidatingAdmissionWebhook,ResourceQuota.
WARN[2021-10-09T09:42:30.790959070Z] bootstrap key already exists                 
I1009 09:42:30.966853    6910 master.go:271] Using reconciler: lease
INFO[2021-10-09T09:42:32.172530477Z] Cluster-Http-Server 2021/10/09 09:42:32 http: TLS handshake error from xx.xx.xx.203:33286: EOF 
W1009 09:42:34.254183    6910 genericapiserver.go:418] Skipping API batch/v2alpha1 because it has no resources.
W1009 09:42:34.381315    6910 genericapiserver.go:418] Skipping API discovery.k8s.io/v1alpha1 because it has no resources.
W1009 09:42:34.521868    6910 genericapiserver.go:418] Skipping API node.k8s.io/v1alpha1 because it has no resources.
W1009 09:42:34.681832    6910 genericapiserver.go:418] Skipping API rbac.authorization.k8s.io/v1alpha1 because it has no resources.
W1009 09:42:34.711229    6910 genericapiserver.go:418] Skipping API scheduling.k8s.io/v1alpha1 because it has no resources.
W1009 09:42:34.842751    6910 genericapiserver.go:418] Skipping API storage.k8s.io/v1alpha1 because it has no resources.
W1009 09:42:35.006362    6910 genericapiserver.go:418] Skipping API apps/v1beta2 because it has no resources.
W1009 09:42:35.006472    6910 genericapiserver.go:418] Skipping API apps/v1beta1 because it has no resources.
I1009 09:42:35.100575    6910 plugins.go:158] Loaded 12 mutating admission controller(s) successfully in the following order: NamespaceLifecycle,LimitRanger,ServiceAccount,NodeRestriction,TaintNodesByCondition,Priority,DefaultTolerationSeconds,DefaultStorageClass,StorageObjectInUseProtection,RuntimeClass,DefaultIngressClass,MutatingAdmissionWebhook.
I1009 09:42:35.100730    6910 plugins.go:161] Loaded 10 validating admission controller(s) successfully in the following order: LimitRanger,ServiceAccount,Priority,PersistentVolumeClaimResize,RuntimeClass,CertificateApproval,CertificateSigning,CertificateSubjectRestriction,ValidatingAdmissionWebhook,ResourceQuota.
INFO[2021-10-09T09:42:35.304307622Z] Running kube-scheduler --address=127.0.0.1 --bind-address=127.0.0.1 --kubeconfig=/var/lib/rancher/k3s/server/cred/scheduler.kubeconfig --port=10251 --profiling=false --secure-port=0 
I1009 09:42:35.305938    6910 registry.go:173] Registering SelectorSpread plugin
I1009 09:42:35.306041    6910 registry.go:173] Registering SelectorSpread plugin
INFO[2021-10-09T09:42:35.307575925Z] Running kube-controller-manager --address=127.0.0.1 --allocate-node-cidrs=true --bind-address=127.0.0.1 --cluster-cidr=10.42.0.0/16 --cluster-signing-cert-file=/var/lib/rancher/k3s/server/tls/client-ca.crt --cluster-signing-key-file=/var/lib/rancher/k3s/server/tls/client-ca.key --kubeconfig=/var/lib/rancher/k3s/server/cred/controller.kubeconfig --port=10252 --profiling=false --root-ca-file=/var/lib/rancher/k3s/server/tls/server-ca.crt --secure-port=0 --service-account-private-key-file=/var/lib/rancher/k3s/server/tls/service.key --use-service-account-credentials=true 
INFO[2021-10-09T09:42:35.325733661Z] Waiting for API server to become available   
INFO[2021-10-09T09:42:35.337972197Z] Node token is available at /var/lib/rancher/k3s/server/token 
INFO[2021-10-09T09:42:35.338389572Z] To join node to cluster: k3s agent -s https://xx.xx.xx.200:6443 -t ${NODE_TOKEN} 
INFO[2021-10-09T09:42:35.351357918Z] Wrote kubeconfig /etc/rancher/k3s/k3s.yaml   
INFO[2021-10-09T09:42:35.351687834Z] Run: k3s kubectl                             
INFO[2021-10-09T09:42:35.497618478Z] Cluster-Http-Server 2021/10/09 09:42:35 http: TLS handshake error from 127.0.0.1:36826: remote error: tls: bad certificate 
INFO[2021-10-09T09:42:35.538241720Z] Cluster-Http-Server 2021/10/09 09:42:35 http: TLS handshake error from 127.0.0.1:36834: remote error: tls: bad certificate 
INFO[2021-10-09T09:42:35.686613935Z] certificate CN=k3s-master signed by CN=k3s-server-ca@1633169144: notBefore=2021-10-02 10:05:44 +0000 UTC notAfter=2022-10-09 09:42:35 +0000 UTC 
INFO[2021-10-09T09:42:35.718668117Z] certificate CN=system:node:k3s-master,O=system:nodes signed by CN=k3s-client-ca@1633169144: notBefore=2021-10-02 10:05:44 +0000 UTC notAfter=2022-10-09 09:42:35 +0000 UTC 
INFO[2021-10-09T09:42:35.851847891Z] Module overlay was already loaded            
INFO[2021-10-09T09:42:35.852033588Z] Module nf_conntrack was already loaded       
INFO[2021-10-09T09:42:35.852955244Z] Module br_netfilter was already loaded       
INFO[2021-10-09T09:42:35.853398156Z] Module iptable_nat was already loaded        
W1009 09:42:35.853900    6910 sysinfo.go:203] Nodes topology is not available, providing CPU topology
W1009 09:42:35.855464    6910 sysfs.go:348] unable to read /sys/devices/system/cpu/cpu0/online: open /sys/devices/system/cpu/cpu0/online: no such file or directory
W1009 09:42:35.856096    6910 sysfs.go:348] unable to read /sys/devices/system/cpu/cpu1/online: open /sys/devices/system/cpu/cpu1/online: no such file or directory
W1009 09:42:35.856801    6910 sysfs.go:348] unable to read /sys/devices/system/cpu/cpu2/online: open /sys/devices/system/cpu/cpu2/online: no such file or directory
W1009 09:42:35.858435    6910 sysfs.go:348] unable to read /sys/devices/system/cpu/cpu3/online: open /sys/devices/system/cpu/cpu3/online: no such file or directory
DEBU[2021-10-09T09:42:35.858547325Z] getConntrackMax: using conntrack-min         
INFO[2021-10-09T09:42:35.870785213Z] Logging containerd to /var/lib/rancher/k3s/agent/containerd/containerd.log 
INFO[2021-10-09T09:42:35.871520615Z] Running containerd -c /var/lib/rancher/k3s/agent/etc/containerd/config.toml -a /run/k3s/containerd/containerd.sock --state /run/k3s/containerd --root /var/lib/rancher/k3s/agent/containerd 
{"level":"warn","ts":"2021-10-09T09:42:35.871Z","caller":"grpclog/grpclog.go:60","msg":"grpc: addrConn.createTransport failed to connect to {/run/k3s/containerd/containerd.sock  <nil> 0 <nil>}. Err :connection error: desc = \"transport: Error while dialing dial unix /run/k3s/containerd/containerd.sock: connect: connection refused\". Reconnecting..."}
{"level":"warn","ts":"2021-10-09T09:42:36.875Z","caller":"grpclog/grpclog.go:60","msg":"grpc: addrConn.createTransport failed to connect to {/run/k3s/containerd/containerd.sock  <nil> 0 <nil>}. Err :connection error: desc = \"transport: Error while dialing dial unix /run/k3s/containerd/containerd.sock: connect: connection refused\". Reconnecting..."}
INFO[2021-10-09T09:42:36.876155762Z] Waiting for containerd startup: rpc error: code = Unavailable desc = connection error: desc = "transport: Error while dialing dial unix /run/k3s/containerd/containerd.sock: connect: connection refused" 
INFO[2021-10-09T09:42:37.693665762Z] Handling backend connection request [k3s-worker2] 
INFO[2021-10-09T09:42:37.725563955Z] Handling backend connection request [k3s-worker1] 
INFO[2021-10-09T09:42:37.752503804Z] Handling backend connection request [k3s-worker3] 
INFO[2021-10-09T09:42:37.881247001Z] Waiting for containerd startup: rpc error: code = Unknown desc = server is not initialized yet 
INFO[2021-10-09T09:42:38.067729614Z] Handling backend connection request [k3s-worker4] 
INFO[2021-10-09T09:42:38.091566231Z] Handling backend connection request [k3s-worker5] 
INFO[2021-10-09T09:42:38.886461863Z] Containerd is now running                    
INFO[2021-10-09T09:42:38.937600654Z] Connecting to proxy                           url="wss://127.0.0.1:6443/v1-k3s/connect"
INFO[2021-10-09T09:42:38.961534119Z] Handling backend connection request [k3s-master] 
WARN[2021-10-09T09:42:38.964465064Z] Disabling CPU quotas due to missing cpu.cfs_period_us 
INFO[2021-10-09T09:42:38.964838793Z] Running kubelet --address=0.0.0.0 --anonymous-auth=false --authentication-token-webhook=true --authorization-mode=Webhook --cgroup-driver=cgroupfs --client-ca-file=/var/lib/rancher/k3s/agent/client-ca.crt --cloud-provider=external --cluster-dns=10.43.0.10 --cluster-domain=cluster.local --cni-bin-dir=/var/lib/rancher/k3s/data/9cbaf87b73f0bc19774ba256b577f7a9cf7842dafbf872eb08b2ca2512d44bc5/bin --cni-conf-dir=/var/lib/rancher/k3s/agent/etc/cni/net.d --container-runtime-endpoint=/run/k3s/containerd/containerd.sock --container-runtime=remote --containerd=/run/k3s/containerd/containerd.sock --cpu-cfs-quota=false --eviction-hard=imagefs.available<5%,nodefs.available<5% --eviction-minimum-reclaim=imagefs.available=10%,nodefs.available=10% --fail-swap-on=false --healthz-bind-address=127.0.0.1 --hostname-override=k3s-master --kubeconfig=/var/lib/rancher/k3s/agent/kubelet.kubeconfig --node-labels= --pod-manifest-path=/var/lib/rancher/k3s/agent/pod-manifests --read-only-port=0 --resolv-conf=/etc/resolv.conf --serialize-image-pulls=false --tls-cert-file=/var/lib/rancher/k3s/agent/serving-kubelet.crt --tls-private-key-file=/var/lib/rancher/k3s/agent/serving-kubelet.key 
INFO[2021-10-09T09:42:38.968244129Z] Running kube-proxy --cluster-cidr=10.42.0.0/16 --conntrack-max-per-core=0 --conntrack-tcp-timeout-close-wait=0s --conntrack-tcp-timeout-established=0s --healthz-bind-address=127.0.0.1 --hostname-override=k3s-master --kubeconfig=/var/lib/rancher/k3s/agent/kubeproxy.kubeconfig --proxy-mode=iptables 
Flag --cloud-provider has been deprecated, will be removed in 1.23, in favor of removing cloud provider code from Kubelet.
Flag --containerd has been deprecated, This is a cadvisor flag that was mistakenly registered with the Kubelet. Due to legacy concerns, it will follow the standard CLI deprecation timeline before being removed.
W1009 09:42:38.969726    6910 server.go:226] WARNING: all flags other than --config, --write-config-to, and --cleanup are deprecated. Please begin using a config file ASAP.
I1009 09:42:38.972795    6910 server.go:408] Version: v1.19.15+k3s2
INFO[2021-10-09T09:42:39.035732499Z] Node CIDR assigned for: k3s-master           
I1009 09:42:39.037442    6910 flannel.go:92] Determining IP address of default interface
I1009 09:42:39.039366    6910 flannel.go:105] Using interface with name eth0 and address xx.xx.xx.200
I1009 09:42:39.069717    6910 kube.go:117] Waiting 10m0s for node controller to sync
I1009 09:42:39.070331    6910 kube.go:300] Starting kube subnet manager
E1009 09:42:39.099760    6910 node.go:125] Failed to retrieve node info: nodes "k3s-master" is forbidden: User "system:kube-proxy" cannot get resource "nodes" in API group "" at the cluster scope
I1009 09:42:39.173437    6910 dynamic_cafile_content.go:167] Starting client-ca-bundle::/var/lib/rancher/k3s/agent/client-ca.crt
DEBU[2021-10-09T09:42:39.176209515Z] FIXME: Got an status-code for which error does not match any expected type!!!: -1  module=api status_code=-1
DEBU[2021-10-09T09:42:39.176878253Z] FIXME: Got an status-code for which error does not match any expected type!!!: -1  module=api status_code=-1
I1009 09:42:40.070955    6910 kube.go:124] Node controller sync successful
I1009 09:42:40.071310    6910 vxlan.go:121] VXLAN config: VNI=1 Port=0 GBP=false Learning=false DirectRouting=false
E1009 09:42:40.169922    6910 node.go:125] Failed to retrieve node info: nodes "k3s-master" is forbidden: User "system:kube-proxy" cannot get resource "nodes" in API group "" at the cluster scope
DEBU[2021-10-09T09:42:40.177893454Z] FIXME: Got an status-code for which error does not match any expected type!!!: -1  module=api status_code=-1
DEBU[2021-10-09T09:42:41.179107365Z] FIXME: Got an status-code for which error does not match any expected type!!!: -1  module=api status_code=-1
DEBU[2021-10-09T09:42:42.180373547Z] FIXME: Got an status-code for which error does not match any expected type!!!: -1  module=api status_code=-1
E1009 09:42:42.309111    6910 node.go:125] Failed to retrieve node info: nodes "k3s-master" is forbidden: User "system:kube-proxy" cannot get resource "nodes" in API group "" at the cluster scope
DEBU[2021-10-09T09:42:43.181434748Z] FIXME: Got an status-code for which error does not match any expected type!!!: -1  module=api status_code=-1
WARN[2021-10-09T09:42:43.944074935Z] Unable to watch for tunnel endpoints: unknown (get endpoints) 
DEBU[2021-10-09T09:42:43.963543847Z] Wrote ping                                   
W1009 09:42:44.189020    6910 sysinfo.go:203] Nodes topology is not available, providing CPU topology
W1009 09:42:44.191061    6910 sysfs.go:348] unable to read /sys/devices/system/cpu/cpu0/online: open /sys/devices/system/cpu/cpu0/online: no such file or directory
W1009 09:42:44.191684    6910 sysfs.go:348] unable to read /sys/devices/system/cpu/cpu1/online: open /sys/devices/system/cpu/cpu1/online: no such file or directory
W1009 09:42:44.192111    6910 sysfs.go:348] unable to read /sys/devices/system/cpu/cpu2/online: open /sys/devices/system/cpu/cpu2/online: no such file or directory
W1009 09:42:44.192509    6910 sysfs.go:348] unable to read /sys/devices/system/cpu/cpu3/online: open /sys/devices/system/cpu/cpu3/online: no such file or directory
W1009 09:42:44.194294    6910 machine.go:253] Cannot determine CPU /sys/bus/cpu/devices/cpu0 online state, skipping
W1009 09:42:44.194514    6910 machine.go:253] Cannot determine CPU /sys/bus/cpu/devices/cpu1 online state, skipping
W1009 09:42:44.194917    6910 machine.go:253] Cannot determine CPU /sys/bus/cpu/devices/cpu2 online state, skipping
W1009 09:42:44.195084    6910 machine.go:253] Cannot determine CPU /sys/bus/cpu/devices/cpu3 online state, skipping
E1009 09:42:44.195263    6910 machine.go:72] Cannot read number of physical cores correctly, number of cores set to 0
W1009 09:42:44.195819    6910 machine.go:253] Cannot determine CPU /sys/bus/cpu/devices/cpu0 online state, skipping
W1009 09:42:44.196046    6910 machine.go:253] Cannot determine CPU /sys/bus/cpu/devices/cpu1 online state, skipping
W1009 09:42:44.196205    6910 machine.go:253] Cannot determine CPU /sys/bus/cpu/devices/cpu2 online state, skipping
W1009 09:42:44.196401    6910 machine.go:253] Cannot determine CPU /sys/bus/cpu/devices/cpu3 online state, skipping
E1009 09:42:44.196826    6910 machine.go:86] Cannot read number of sockets correctly, number of sockets set to 0
DEBU[2021-10-09T09:42:44.198253435Z] FIXME: Got an status-code for which error does not match any expected type!!!: -1  module=api status_code=-1
DEBU[2021-10-09T09:42:44.198919729Z] FIXME: Got an status-code for which error does not match any expected type!!!: -1  module=api status_code=-1
I1009 09:42:44.199504    6910 server.go:641] --cgroups-per-qos enabled, but --cgroup-root was not specified.  defaulting to /
I1009 09:42:44.201342    6910 container_manager_linux.go:281] container manager verified user specified cgroup-root exists: []
I1009 09:42:44.201509    6910 container_manager_linux.go:286] Creating Container Manager object based on Node Config: {RuntimeCgroupsName: SystemCgroupsName: KubeletCgroupsName: ContainerRuntime:remote CgroupsPerQOS:true CgroupRoot:/ CgroupDriver:cgroupfs KubeletRootDir:/var/lib/kubelet ProtectKernelDefaults:false NodeAllocatableConfig:{KubeReservedCgroupName: SystemReservedCgroupName: ReservedSystemCPUs: EnforceNodeAllocatable:map[pods:{}] KubeReserved:map[] SystemReserved:map[] HardEvictionThresholds:[{Signal:imagefs.available Operator:LessThan Value:{Quantity:<nil> Percentage:0.05} GracePeriod:0s MinReclaim:<nil>} {Signal:nodefs.available Operator:LessThan Value:{Quantity:<nil> Percentage:0.05} GracePeriod:0s MinReclaim:<nil>}]} QOSReserved:map[] ExperimentalCPUManagerPolicy:none ExperimentalCPUManagerReconcilePeriod:10s ExperimentalPodPidsLimit:-1 EnforceCPULimits:false CPUCFSQuotaPeriod:100ms ExperimentalTopologyManagerPolicy:none Rootless:false}
I1009 09:42:44.202188    6910 topology_manager.go:126] [topologymanager] Creating topology manager with none policy
I1009 09:42:44.202435    6910 container_manager_linux.go:316] [topologymanager] Initializing Topology Manager with none policy
I1009 09:42:44.202589    6910 container_manager_linux.go:321] Creating device plugin manager: true
W1009 09:42:44.203152    6910 util_unix.go:103] Using "/run/k3s/containerd/containerd.sock" as endpoint is deprecated, please consider using full url format "unix:///run/k3s/containerd/containerd.sock".
W1009 09:42:44.203524    6910 util_unix.go:103] Using "/run/k3s/containerd/containerd.sock" as endpoint is deprecated, please consider using full url format "unix:///run/k3s/containerd/containerd.sock".
I1009 09:42:44.204159    6910 kubelet.go:394] Attempting to sync node with API server
I1009 09:42:44.204338    6910 kubelet.go:261] Adding pod path: /var/lib/rancher/k3s/agent/pod-manifests
I1009 09:42:44.204545    6910 kubelet.go:273] Adding apiserver pod source
I1009 09:42:44.204786    6910 apiserver.go:43] Waiting for node sync before watching apiserver pods
I1009 09:42:44.231564    6910 kuberuntime_manager.go:214] Container runtime containerd initialized, version: v1.4.11-k3s1, apiVersion: v1alpha2
I1009 09:42:44.233162    6910 server.go:1149] Started kubelet
I1009 09:42:44.250468    6910 server.go:152] Starting to listen on 0.0.0.0:10250
E1009 09:42:44.254106    6910 cri_stats_provider.go:376] Failed to get the info of the filesystem with mountpoint "/var/lib/rancher/k3s/agent/containerd/io.containerd.snapshotter.v1.overlayfs": unable to find data in memory cache.
E1009 09:42:44.254589    6910 kubelet.go:1238] Image garbage collection failed once. Stats initialization may not have completed yet: invalid capacity 0 on image filesystem
I1009 09:42:44.259942    6910 server.go:429] Adding debug handlers to kubelet server.
I1009 09:42:44.267303    6910 fs_resource_analyzer.go:64] Starting FS ResourceAnalyzer
I1009 09:42:44.283850    6910 volume_manager.go:265] Starting Kubelet Volume Manager
I1009 09:42:44.288348    6910 desired_state_of_world_populator.go:139] Desired state populator starts to run
DEBU[2021-10-09T09:42:44.322659197Z] FIXME: Got an status-code for which error does not match any expected type!!!: -1  module=api status_code=-1
W1009 09:42:44.326241    6910 manager.go:949] Error getting perf_event cgroup path: "could not find path for resource \"perf_event\" for container \"/\""
W1009 09:42:44.341373    6910 manager.go:949] Error getting perf_event cgroup path: "could not find path for resource \"perf_event\" for container \"/kubepods/besteffort\""
W1009 09:42:44.344122    6910 manager.go:949] Error getting perf_event cgroup path: "could not find path for resource \"perf_event\" for container \"/kubepods/besteffort/pod7c852c5c-6a05-4f77-b52a-4e2fd36d3100\""
W1009 09:42:44.352131    6910 manager.go:949] Error getting perf_event cgroup path: "could not find path for resource \"perf_event\" for container \"/kubepods/besteffort/podf15bb514-58d1-4908-9c13-235b0519b3d7\""
W1009 09:42:44.355247    6910 manager.go:949] Error getting perf_event cgroup path: "could not find path for resource \"perf_event\" for container \"/kubepods/besteffort/podc3d31a6f-a0f6-4408-b609-22f826b983b6\""
W1009 09:42:44.358353    6910 manager.go:949] Error getting perf_event cgroup path: "could not find path for resource \"perf_event\" for container \"/kubepods\""
W1009 09:42:44.364831    6910 manager.go:949] Error getting perf_event cgroup path: "could not find path for resource \"perf_event\" for container \"/kubepods/burstable\""
W1009 09:42:44.375433    6910 manager.go:949] Error getting perf_event cgroup path: "could not find path for resource \"perf_event\" for container \"/kubepods/besteffort/pod94187467-b10f-44d5-a313-38d2ae0bd11d\""
W1009 09:42:44.378216    6910 manager.go:949] Error getting perf_event cgroup path: "could not find path for resource \"perf_event\" for container \"/kubepods/besteffort/pod390561ad-69e8-4d7a-a35c-b58e4f008e42\""
W1009 09:42:44.380929    6910 manager.go:949] Error getting perf_event cgroup path: "could not find path for resource \"perf_event\" for container \"/kubepods/besteffort/pod0fc8d7bf-f5ca-4c0e-b7a6-32bea47e3a6c\""
DEBU[2021-10-09T09:42:44.397605570Z] FIXME: Got an status-code for which error does not match any expected type!!!: -1  module=api status_code=-1
DEBU[2021-10-09T09:42:44.398868253Z] FIXME: Got an status-code for which error does not match any expected type!!!: -1  module=api status_code=-1
I1009 09:42:44.399671    6910 kuberuntime_manager.go:992] updating runtime config through cri with podcidr 10.42.0.0/24
I1009 09:42:44.407648    6910 kubelet_node_status.go:71] Attempting to register node k3s-master
I1009 09:42:44.408125    6910 kubelet_network.go:77] Setting Pod CIDR:  -> 10.42.0.0/24
I1009 09:42:44.431148    6910 status_manager.go:158] Starting to sync pod status with apiserver
I1009 09:42:44.431293    6910 kubelet.go:1770] Starting kubelet main sync loop.
E1009 09:42:44.431497    6910 kubelet.go:1794] skipping pod synchronization - [container runtime status check may not have completed yet, PLEG is not healthy: pleg has yet to be successful]
I1009 09:42:44.491716    6910 cpu_manager.go:184] [cpumanager] starting with none policy
I1009 09:42:44.491807    6910 cpu_manager.go:185] [cpumanager] reconciling every 10s
I1009 09:42:44.492557    6910 state_mem.go:36] [cpumanager] initializing new in-memory state store
I1009 09:42:44.493746    6910 state_mem.go:88] [cpumanager] updated default cpuset: ""
I1009 09:42:44.494146    6910 state_mem.go:96] [cpumanager] updated cpuset assignments: "map[]"
I1009 09:42:44.494465    6910 policy_none.go:43] [cpumanager] none policy: Start
I1009 09:42:44.503605    6910 plugin_manager.go:114] Starting Kubelet Plugin Manager
{"level":"warn","ts":"2021-10-09T09:42:44.510Z","caller":"grpclog/grpclog.go:60","msg":"grpc: addrConn.createTransport failed to connect to {/var/lib/kubelet/plugins_registry/driver.longhorn.io-reg.sock  <nil> 0 <nil>}. Err :connection error: desc = \"transport: Error while dialing dial unix /var/lib/kubelet/plugins_registry/driver.longhorn.io-reg.sock: connect: connection refused\". Reconnecting..."}
W1009 09:42:44.531857    6910 pod_container_deletor.go:79] Container "ecf0945ca0b8e55f3f8bf3cd70f390ebf0f88bd0b08c02bbf67bd5952a7b258b" not found in pod's containers
W1009 09:42:44.531985    6910 pod_container_deletor.go:79] Container "bb3df341ca8ecf76ec35c50cc05c997f7361f5d46d29bd67cd119f1e80bbb7e3" not found in pod's containers
W1009 09:42:44.532066    6910 pod_container_deletor.go:79] Container "88823a4724899fdf1931324767ca08b7af23ef1819051f6d3266eacc4a161517" not found in pod's containers
W1009 09:42:44.532155    6910 pod_container_deletor.go:79] Container "e6698878ce79f652bfd987968dc752c053e7bf3c8e9172362783fda6d0b4a76e" not found in pod's containers
W1009 09:42:44.532254    6910 pod_container_deletor.go:79] Container "940c2b5c5f585c8fa0832e436a9c84e92fa3e2aa0052bacefb192e4cab05eb91" not found in pod's containers
W1009 09:42:44.532371    6910 pod_container_deletor.go:79] Container "8394d85719fa0fefa995281483be4102e7d4e8504f27c1fbc446444971bc4ce3" not found in pod's containers
W1009 09:42:44.532472    6910 pod_container_deletor.go:79] Container "a6d9610f076adbf211fa14fccca428ce35fe57673444633170122e1cc2256631" not found in pod's containers
W1009 09:42:44.537867    6910 pod_container_deletor.go:79] Container "5ae4a52c18fe4b6d383de2ca46353b026126fbf28b6a956c766669b321d9e0c7" not found in pod's containers
W1009 09:42:44.542642    6910 pod_container_deletor.go:79] Container "dca44f68d9d818e756b2e134e28c1562388cc6e0385832e8a8d1218d424ee92e" not found in pod's containers
I1009 09:42:45.207933    6910 apiserver.go:53] Watching apiserver
I1009 09:42:45.243052    6910 topology_manager.go:235] [topologymanager] Topology Admit Handler
I1009 09:42:45.260970    6910 topology_manager.go:235] [topologymanager] Topology Admit Handler
I1009 09:42:45.267230    6910 topology_manager.go:235] [topologymanager] Topology Admit Handler
I1009 09:42:45.274110    6910 topology_manager.go:235] [topologymanager] Topology Admit Handler
E1009 09:42:45.291757    6910 reflector.go:127] object-"k3os-system"/"k3os-upgrade-token-sjwz6": Failed to watch *v1.Secret: failed to list *v1.Secret: secrets "k3os-upgrade-token-sjwz6" is forbidden: User "system:node:k3s-master" cannot list resource "secrets" in API group "" in the namespace "k3os-system": no relationship found between node 'k3s-master' and this object
I1009 09:42:45.297633    6910 topology_manager.go:235] [topologymanager] Topology Admit Handler
I1009 09:42:45.303140    6910 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "dev" (UniqueName: "kubernetes.io/host-path/f15bb514-58d1-4908-9c13-235b0519b3d7-dev") pod "longhorn-manager-qlwgj" (UID: "f15bb514-58d1-4908-9c13-235b0519b3d7") 
I1009 09:42:45.304352    6910 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "proc" (UniqueName: "kubernetes.io/host-path/f15bb514-58d1-4908-9c13-235b0519b3d7-proc") pod "longhorn-manager-qlwgj" (UID: "f15bb514-58d1-4908-9c13-235b0519b3d7") 
I1009 09:42:45.305081    6910 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "data" (UniqueName: "kubernetes.io/host-path/0fc8d7bf-f5ca-4c0e-b7a6-32bea47e3a6c-data") pod "engine-image-ei-611d1496-mgqn2" (UID: "0fc8d7bf-f5ca-4c0e-b7a6-32bea47e3a6c") 
I1009 09:42:45.305257    6910 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "tmp" (UniqueName: "kubernetes.io/empty-dir/390561ad-69e8-4d7a-a35c-b58e4f008e42-tmp") pod "system-upgrade-controller-c6c9b4c5d-bn6v4" (UID: "390561ad-69e8-4d7a-a35c-b58e4f008e42") 
I1009 09:42:45.305423    6910 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "k3os-upgrade-token-sjwz6" (UniqueName: "kubernetes.io/secret/390561ad-69e8-4d7a-a35c-b58e4f008e42-k3os-upgrade-token-sjwz6") pod "system-upgrade-controller-c6c9b4c5d-bn6v4" (UID: "390561ad-69e8-4d7a-a35c-b58e4f008e42") 
I1009 09:42:45.305583    6910 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "longhorn-service-account-token-s4bjc" (UniqueName: "kubernetes.io/secret/0fc8d7bf-f5ca-4c0e-b7a6-32bea47e3a6c-longhorn-service-account-token-s4bjc") pod "engine-image-ei-611d1496-mgqn2" (UID: "0fc8d7bf-f5ca-4c0e-b7a6-32bea47e3a6c") 
I1009 09:42:45.305725    6910 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "longhorn-default-setting" (UniqueName: "kubernetes.io/configmap/f15bb514-58d1-4908-9c13-235b0519b3d7-longhorn-default-setting") pod "longhorn-manager-qlwgj" (UID: "f15bb514-58d1-4908-9c13-235b0519b3d7") 
I1009 09:42:45.305861    6910 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "longhorn-service-account-token-s4bjc" (UniqueName: "kubernetes.io/secret/f15bb514-58d1-4908-9c13-235b0519b3d7-longhorn-service-account-token-s4bjc") pod "longhorn-manager-qlwgj" (UID: "f15bb514-58d1-4908-9c13-235b0519b3d7") 
I1009 09:42:45.305994    6910 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "kubernetes-csi-dir" (UniqueName: "kubernetes.io/host-path/7c852c5c-6a05-4f77-b52a-4e2fd36d3100-kubernetes-csi-dir") pod "longhorn-csi-plugin-dkvm8" (UID: "7c852c5c-6a05-4f77-b52a-4e2fd36d3100") 
I1009 09:42:45.306121    6910 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "host-dev" (UniqueName: "kubernetes.io/host-path/7c852c5c-6a05-4f77-b52a-4e2fd36d3100-host-dev") pod "longhorn-csi-plugin-dkvm8" (UID: "7c852c5c-6a05-4f77-b52a-4e2fd36d3100") 
I1009 09:42:45.306262    6910 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "host-sys" (UniqueName: "kubernetes.io/host-path/7c852c5c-6a05-4f77-b52a-4e2fd36d3100-host-sys") pod "longhorn-csi-plugin-dkvm8" (UID: "7c852c5c-6a05-4f77-b52a-4e2fd36d3100") 
I1009 09:42:45.306406    6910 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "lib-modules" (UniqueName: "kubernetes.io/host-path/7c852c5c-6a05-4f77-b52a-4e2fd36d3100-lib-modules") pod "longhorn-csi-plugin-dkvm8" (UID: "7c852c5c-6a05-4f77-b52a-4e2fd36d3100") 
I1009 09:42:45.306544    6910 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "longhorn-service-account-token-s4bjc" (UniqueName: "kubernetes.io/secret/7c852c5c-6a05-4f77-b52a-4e2fd36d3100-longhorn-service-account-token-s4bjc") pod "longhorn-csi-plugin-dkvm8" (UID: "7c852c5c-6a05-4f77-b52a-4e2fd36d3100") 
I1009 09:42:45.306694    6910 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "etc-ssl" (UniqueName: "kubernetes.io/host-path/390561ad-69e8-4d7a-a35c-b58e4f008e42-etc-ssl") pod "system-upgrade-controller-c6c9b4c5d-bn6v4" (UID: "390561ad-69e8-4d7a-a35c-b58e4f008e42") 
I1009 09:42:45.306829    6910 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "longhorn" (UniqueName: "kubernetes.io/host-path/f15bb514-58d1-4908-9c13-235b0519b3d7-longhorn") pod "longhorn-manager-qlwgj" (UID: "f15bb514-58d1-4908-9c13-235b0519b3d7") 
I1009 09:42:45.306955    6910 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "registration-dir" (UniqueName: "kubernetes.io/host-path/7c852c5c-6a05-4f77-b52a-4e2fd36d3100-registration-dir") pod "longhorn-csi-plugin-dkvm8" (UID: "7c852c5c-6a05-4f77-b52a-4e2fd36d3100") 
I1009 09:42:45.307092    6910 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "socket-dir" (UniqueName: "kubernetes.io/host-path/7c852c5c-6a05-4f77-b52a-4e2fd36d3100-socket-dir") pod "longhorn-csi-plugin-dkvm8" (UID: "7c852c5c-6a05-4f77-b52a-4e2fd36d3100") 
I1009 09:42:45.307223    6910 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "pods-mount-dir" (UniqueName: "kubernetes.io/host-path/7c852c5c-6a05-4f77-b52a-4e2fd36d3100-pods-mount-dir") pod "longhorn-csi-plugin-dkvm8" (UID: "7c852c5c-6a05-4f77-b52a-4e2fd36d3100") 
I1009 09:42:45.307357    6910 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "host" (UniqueName: "kubernetes.io/host-path/7c852c5c-6a05-4f77-b52a-4e2fd36d3100-host") pod "longhorn-csi-plugin-dkvm8" (UID: "7c852c5c-6a05-4f77-b52a-4e2fd36d3100") 
E1009 09:42:45.309635    6910 reflector.go:127] object-"longhorn-system"/"longhorn-service-account-token-s4bjc": Failed to watch *v1.Secret: failed to list *v1.Secret: secrets "longhorn-service-account-token-s4bjc" is forbidden: User "system:node:k3s-master" cannot list resource "secrets" in API group "" in the namespace "longhorn-system": no relationship found between node 'k3s-master' and this object
E1009 09:42:45.310370    6910 reflector.go:127] object-"k3os-system"/"default-controller-env": Failed to watch *v1.ConfigMap: failed to list *v1.ConfigMap: configmaps "default-controller-env" is forbidden: User "system:node:k3s-master" cannot list resource "configmaps" in API group "" in the namespace "k3os-system": no relationship found between node 'k3s-master' and this object
I1009 09:42:45.313702    6910 topology_manager.go:235] [topologymanager] Topology Admit Handler
E1009 09:42:45.330684    6910 reflector.go:127] object-"default"/"omni-config": Failed to watch *v1.ConfigMap: failed to list *v1.ConfigMap: configmaps "omni-config" is forbidden: User "system:node:k3s-master" cannot list resource "configmaps" in API group "" in the namespace "default": no relationship found between node 'k3s-master' and this object
I1009 09:42:45.331307    6910 topology_manager.go:235] [topologymanager] Topology Admit Handler
INFO[2021-10-09T09:42:45.340942511Z] Waiting for cloudcontroller rbac role to be created 
I1009 09:42:45.341566    6910 topology_manager.go:235] [topologymanager] Topology Admit Handler
E1009 09:42:45.345768    6910 reflector.go:127] object-"default"/"default-token-w7x77": Failed to watch *v1.Secret: failed to list *v1.Secret: secrets "default-token-w7x77" is forbidden: User "system:node:k3s-master" cannot list resource "secrets" in API group "" in the namespace "default": no relationship found between node 'k3s-master' and this object
E1009 09:42:45.349244    6910 reflector.go:127] object-"longhorn-system"/"longhorn-default-setting": Failed to watch *v1.ConfigMap: failed to list *v1.ConfigMap: configmaps "longhorn-default-setting" is forbidden: User "system:node:k3s-master" cannot list resource "configmaps" in API group "" in the namespace "longhorn-system": no relationship found between node 'k3s-master' and this object
E1009 09:42:45.353961    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.355602    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.356950    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.357701    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.358019    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.358164    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.358280    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.358388    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.358494    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.358592    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.358691    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.358789    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.358994    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.359111    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.359225    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.359341    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.359544    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.359640    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.359753    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.359901    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.360010    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.360136    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.360242    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.360342    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.360457    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.360559    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.360753    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.360859    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.360966    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.361057    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.360889    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.361147    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.361167    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.361263    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.361281    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.361373    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.361386    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.361465    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.361487    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.361559    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.361593    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.361654    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.361689    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.361747    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.361791    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.361839    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.361887    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.361932    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.361997    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.362038    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.362092    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.362131    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.362197    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.362225    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.362287    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.362320    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.362394    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.362413    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.355429    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.362490    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.362589    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.362692    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.362859    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.362960    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.362998    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.363078    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.363111    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.363208    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.363312    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.363303    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.363405    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.363422    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.363496    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.363517    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.363585    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.363618    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.363679    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.363713    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.363772    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.363815    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.363864    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.363914    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.363954    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.364018    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
I1009 09:42:45.411423    6910 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "rootfs" (UniqueName: "kubernetes.io/host-path/94187467-b10f-44d5-a313-38d2ae0bd11d-rootfs") pod "omni-metrics-jmxjd" (UID: "94187467-b10f-44d5-a313-38d2ae0bd11d") 
I1009 09:42:45.411623    6910 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "default-token-w7x77" (UniqueName: "kubernetes.io/secret/94187467-b10f-44d5-a313-38d2ae0bd11d-default-token-w7x77") pod "omni-metrics-jmxjd" (UID: "94187467-b10f-44d5-a313-38d2ae0bd11d") 
I1009 09:42:45.411874    6910 reconciler.go:224] operationExecutor.VerifyControllerAttachedVolume started for volume "home-network-metallb-speaker-token-w7gtd" (UniqueName: "kubernetes.io/secret/c3d31a6f-a0f6-4408-b609-22f826b983b6-home-network-metallb-speaker-token-w7gtd") pod "home-network-metallb-speaker-2rxj9" (UID: "c3d31a6f-a0f6-4408-b609-22f826b983b6") 
I1009 09:42:45.412181    6910 reconciler.go:157] Reconciler: start to sync state
E1009 09:42:45.419845    6910 reflector.go:127] object-"home-network"/"home-network-metallb-memberlist": Failed to watch *v1.Secret: failed to list *v1.Secret: secrets "home-network-metallb-memberlist" is forbidden: User "system:node:k3s-master" cannot list resource "secrets" in API group "" in the namespace "home-network": no relationship found between node 'k3s-master' and this object
E1009 09:42:45.488154    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:45.489274    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
{"level":"warn","ts":"2021-10-09T09:42:45.510Z","caller":"grpclog/grpclog.go:60","msg":"grpc: addrConn.createTransport failed to connect to {/var/lib/kubelet/plugins_registry/driver.longhorn.io-reg.sock  <nil> 0 <nil>}. Err :connection error: desc = \"transport: Error while dialing dial unix /var/lib/kubelet/plugins_registry/driver.longhorn.io-reg.sock: connect: connection refused\". Reconnecting..."}
E1009 09:42:45.616880    6910 reflector.go:127] object-"home-network"/"home-network-metallb-speaker-token-w7gtd": Failed to watch *v1.Secret: failed to list *v1.Secret: secrets "home-network-metallb-speaker-token-w7gtd" is forbidden: User "system:node:k3s-master" cannot list resource "secrets" in API group "" in the namespace "home-network": no relationship found between node 'k3s-master' and this object
E1009 09:42:46.134567    6910 reflector.go:127] object-"k3os-system"/"k3os-upgrade-token-sjwz6": Failed to watch *v1.Secret: failed to list *v1.Secret: secrets "k3os-upgrade-token-sjwz6" is forbidden: User "system:node:k3s-master" cannot list resource "secrets" in API group "" in the namespace "k3os-system": no relationship found between node 'k3s-master' and this object
E1009 09:42:46.277635    6910 reflector.go:127] object-"default"/"omni-config": Failed to watch *v1.ConfigMap: failed to list *v1.ConfigMap: configmaps "omni-config" is forbidden: User "system:node:k3s-master" cannot list resource "configmaps" in API group "" in the namespace "default": no relationship found between node 'k3s-master' and this object
E1009 09:42:46.410673    6910 secret.go:195] Couldn't get secret longhorn-system/longhorn-service-account-token-s4bjc: failed to sync secret cache: timed out waiting for the condition
E1009 09:42:46.411195    6910 nestedpendingoperations.go:301] Operation for "{volumeName:kubernetes.io/secret/7c852c5c-6a05-4f77-b52a-4e2fd36d3100-longhorn-service-account-token-s4bjc podName:7c852c5c-6a05-4f77-b52a-4e2fd36d3100 nodeName:}" failed. No retries permitted until 2021-10-09 09:42:46.911031442 +0000 UTC m=+26.578451934 (durationBeforeRetry 500ms). Error: "MountVolume.SetUp failed for volume \"longhorn-service-account-token-s4bjc\" (UniqueName: \"kubernetes.io/secret/7c852c5c-6a05-4f77-b52a-4e2fd36d3100-longhorn-service-account-token-s4bjc\") pod \"longhorn-csi-plugin-dkvm8\" (UID: \"7c852c5c-6a05-4f77-b52a-4e2fd36d3100\") : failed to sync secret cache: timed out waiting for the condition"
E1009 09:42:46.411278    6910 configmap.go:200] Couldn't get configMap longhorn-system/longhorn-default-setting: failed to sync configmap cache: timed out waiting for the condition
E1009 09:42:46.412325    6910 secret.go:195] Couldn't get secret longhorn-system/longhorn-service-account-token-s4bjc: failed to sync secret cache: timed out waiting for the condition
E1009 09:42:46.412320    6910 nestedpendingoperations.go:301] Operation for "{volumeName:kubernetes.io/configmap/f15bb514-58d1-4908-9c13-235b0519b3d7-longhorn-default-setting podName:f15bb514-58d1-4908-9c13-235b0519b3d7 nodeName:}" failed. No retries permitted until 2021-10-09 09:42:46.912166018 +0000 UTC m=+26.579586529 (durationBeforeRetry 500ms). Error: "MountVolume.SetUp failed for volume \"longhorn-default-setting\" (UniqueName: \"kubernetes.io/configmap/f15bb514-58d1-4908-9c13-235b0519b3d7-longhorn-default-setting\") pod \"longhorn-manager-qlwgj\" (UID: \"f15bb514-58d1-4908-9c13-235b0519b3d7\") : failed to sync configmap cache: timed out waiting for the condition"
E1009 09:42:46.412834    6910 nestedpendingoperations.go:301] Operation for "{volumeName:kubernetes.io/secret/f15bb514-58d1-4908-9c13-235b0519b3d7-longhorn-service-account-token-s4bjc podName:f15bb514-58d1-4908-9c13-235b0519b3d7 nodeName:}" failed. No retries permitted until 2021-10-09 09:42:46.912695761 +0000 UTC m=+26.580116216 (durationBeforeRetry 500ms). Error: "MountVolume.SetUp failed for volume \"longhorn-service-account-token-s4bjc\" (UniqueName: \"kubernetes.io/secret/f15bb514-58d1-4908-9c13-235b0519b3d7-longhorn-service-account-token-s4bjc\") pod \"longhorn-manager-qlwgj\" (UID: \"f15bb514-58d1-4908-9c13-235b0519b3d7\") : failed to sync secret cache: timed out waiting for the condition"
E1009 09:42:46.413374    6910 secret.go:195] Couldn't get secret longhorn-system/longhorn-service-account-token-s4bjc: failed to sync secret cache: timed out waiting for the condition
E1009 09:42:46.414048    6910 nestedpendingoperations.go:301] Operation for "{volumeName:kubernetes.io/secret/0fc8d7bf-f5ca-4c0e-b7a6-32bea47e3a6c-longhorn-service-account-token-s4bjc podName:0fc8d7bf-f5ca-4c0e-b7a6-32bea47e3a6c nodeName:}" failed. No retries permitted until 2021-10-09 09:42:46.913907538 +0000 UTC m=+26.581328049 (durationBeforeRetry 500ms). Error: "MountVolume.SetUp failed for volume \"longhorn-service-account-token-s4bjc\" (UniqueName: \"kubernetes.io/secret/0fc8d7bf-f5ca-4c0e-b7a6-32bea47e3a6c-longhorn-service-account-token-s4bjc\") pod \"engine-image-ei-611d1496-mgqn2\" (UID: \"0fc8d7bf-f5ca-4c0e-b7a6-32bea47e3a6c\") : failed to sync secret cache: timed out waiting for the condition"
E1009 09:42:46.414640    6910 secret.go:195] Couldn't get secret k3os-system/k3os-upgrade-token-sjwz6: failed to sync secret cache: timed out waiting for the condition
E1009 09:42:46.415259    6910 nestedpendingoperations.go:301] Operation for "{volumeName:kubernetes.io/secret/390561ad-69e8-4d7a-a35c-b58e4f008e42-k3os-upgrade-token-sjwz6 podName:390561ad-69e8-4d7a-a35c-b58e4f008e42 nodeName:}" failed. No retries permitted until 2021-10-09 09:42:46.915115334 +0000 UTC m=+26.582535808 (durationBeforeRetry 500ms). Error: "MountVolume.SetUp failed for volume \"k3os-upgrade-token-sjwz6\" (UniqueName: \"kubernetes.io/secret/390561ad-69e8-4d7a-a35c-b58e4f008e42-k3os-upgrade-token-sjwz6\") pod \"system-upgrade-controller-c6c9b4c5d-bn6v4\" (UID: \"390561ad-69e8-4d7a-a35c-b58e4f008e42\") : failed to sync secret cache: timed out waiting for the condition"
E1009 09:42:46.417653    6910 reflector.go:127] object-"k3os-system"/"default-controller-env": Failed to watch *v1.ConfigMap: failed to list *v1.ConfigMap: configmaps "default-controller-env" is forbidden: User "system:node:k3s-master" cannot list resource "configmaps" in API group "" in the namespace "k3os-system": no relationship found between node 'k3s-master' and this object
I1009 09:42:46.474295    6910 trace.go:205] Trace[1661725348]: "Update" url:/apis/coordination.k8s.io/v1/namespaces/kube-node-lease/leases/k3s-worker1,user-agent:k3s/v1.19.15+k3s2 (linux/arm64) kubernetes/0fbbc5a,client:xx.xx.xx.201 (09-Oct-2021 09:42:36.472) (total time: 10001ms):
Trace[1661725348]: [10.001696008s] [10.001696008s] END
I1009 09:42:46.477640    6910 trace.go:205] Trace[70651293]: "GuaranteedUpdate etcd3" type:*coordination.Lease (09-Oct-2021 09:42:36.473) (total time: 10003ms):
Trace[70651293]: [10.003553822s] [10.003553822s] END
I1009 09:42:46.478902    6910 trace.go:205] Trace[831940563]: "Update" url:/apis/coordination.k8s.io/v1/namespaces/kube-node-lease/leases/k3s-worker2,user-agent:k3s/v1.19.15+k3s2 (linux/arm64) kubernetes/0fbbc5a,client:xx.xx.xx.202 (09-Oct-2021 09:42:36.473) (total time: 10005ms):
Trace[831940563]: [10.005681773s] [10.005681773s] END
I1009 09:42:46.480160    6910 trace.go:205] Trace[997342066]: "GuaranteedUpdate etcd3" type:*coordination.Lease (09-Oct-2021 09:42:36.473) (total time: 10006ms):
Trace[997342066]: [10.006921957s] [10.006921957s] END
E1009 09:42:46.519389    6910 secret.go:195] Couldn't get secret default/default-token-w7x77: failed to sync secret cache: timed out waiting for the condition
E1009 09:42:46.519872    6910 nestedpendingoperations.go:301] Operation for "{volumeName:kubernetes.io/secret/94187467-b10f-44d5-a313-38d2ae0bd11d-default-token-w7x77 podName:94187467-b10f-44d5-a313-38d2ae0bd11d nodeName:}" failed. No retries permitted until 2021-10-09 09:42:47.019685842 +0000 UTC m=+26.687106316 (durationBeforeRetry 500ms). Error: "MountVolume.SetUp failed for volume \"default-token-w7x77\" (UniqueName: \"kubernetes.io/secret/94187467-b10f-44d5-a313-38d2ae0bd11d-default-token-w7x77\") pod \"omni-metrics-jmxjd\" (UID: \"94187467-b10f-44d5-a313-38d2ae0bd11d\") : failed to sync secret cache: timed out waiting for the condition"
E1009 09:42:46.519389    6910 secret.go:195] Couldn't get secret home-network/home-network-metallb-speaker-token-w7gtd: failed to sync secret cache: timed out waiting for the condition
E1009 09:42:46.520344    6910 nestedpendingoperations.go:301] Operation for "{volumeName:kubernetes.io/secret/c3d31a6f-a0f6-4408-b609-22f826b983b6-home-network-metallb-speaker-token-w7gtd podName:c3d31a6f-a0f6-4408-b609-22f826b983b6 nodeName:}" failed. No retries permitted until 2021-10-09 09:42:47.020198548 +0000 UTC m=+26.687619022 (durationBeforeRetry 500ms). Error: "MountVolume.SetUp failed for volume \"home-network-metallb-speaker-token-w7gtd\" (UniqueName: \"kubernetes.io/secret/c3d31a6f-a0f6-4408-b609-22f826b983b6-home-network-metallb-speaker-token-w7gtd\") pod \"home-network-metallb-speaker-2rxj9\" (UID: \"c3d31a6f-a0f6-4408-b609-22f826b983b6\") : failed to sync secret cache: timed out waiting for the condition"
E1009 09:42:46.617386    6910 reflector.go:127] object-"longhorn-system"/"longhorn-service-account-token-s4bjc": Failed to watch *v1.Secret: failed to list *v1.Secret: secrets "longhorn-service-account-token-s4bjc" is forbidden: User "system:node:k3s-master" cannot list resource "secrets" in API group "" in the namespace "longhorn-system": no relationship found between node 'k3s-master' and this object
E1009 09:42:46.817615    6910 reflector.go:127] object-"home-network"/"home-network-metallb-memberlist": Failed to watch *v1.Secret: failed to list *v1.Secret: secrets "home-network-metallb-memberlist" is forbidden: User "system:node:k3s-master" cannot list resource "secrets" in API group "" in the namespace "home-network": no relationship found between node 'k3s-master' and this object
I1009 09:42:46.836411    6910 trace.go:205] Trace[907982233]: "Update" url:/apis/coordination.k8s.io/v1/namespaces/kube-node-lease/leases/k3s-worker3,user-agent:k3s/v1.20.11+k3s1 (linux/arm64) kubernetes/b247e74,client:xx.xx.xx.203 (09-Oct-2021 09:42:36.833) (total time: 10002ms):
Trace[907982233]: [10.002575812s] [10.002575812s] END
I1009 09:42:46.837392    6910 trace.go:205] Trace[577893911]: "GuaranteedUpdate etcd3" type:*coordination.Lease (09-Oct-2021 09:42:36.834) (total time: 10003ms):
Trace[577893911]: [10.003089278s] [10.003089278s] END
I1009 09:42:46.970944    6910 trace.go:205] Trace[1674367910]: "Update" url:/apis/coordination.k8s.io/v1/namespaces/kube-node-lease/leases/k3s-worker4,user-agent:k3s/v1.21.5+k3s1 (linux/arm) kubernetes/acad8ef,client:xx.xx.xx.204 (09-Oct-2021 09:42:36.968) (total time: 10002ms):
Trace[1674367910]: [10.002506487s] [10.002506487s] END
I1009 09:42:46.972410    6910 trace.go:205] Trace[1731213673]: "GuaranteedUpdate etcd3" type:*coordination.Lease (09-Oct-2021 09:42:36.969) (total time: 10002ms):
Trace[1731213673]: [10.002794497s] [10.002794497s] END
E1009 09:42:46.997157    6910 node.go:125] Failed to retrieve node info: nodes "k3s-master" is forbidden: User "system:kube-proxy" cannot get resource "nodes" in API group "" at the cluster scope
E1009 09:42:47.015380    6910 reflector.go:127] object-"default"/"default-token-w7x77": Failed to watch *v1.Secret: failed to list *v1.Secret: secrets "default-token-w7x77" is forbidden: User "system:node:k3s-master" cannot list resource "secrets" in API group "" in the namespace "default": no relationship found between node 'k3s-master' and this object
{"level":"warn","ts":"2021-10-09T09:42:47.060Z","caller":"grpclog/grpclog.go:60","msg":"grpc: addrConn.createTransport failed to connect to {/var/lib/kubelet/plugins_registry/driver.longhorn.io-reg.sock  <nil> 0 <nil>}. Err :connection error: desc = \"transport: Error while dialing dial unix /var/lib/kubelet/plugins_registry/driver.longhorn.io-reg.sock: connect: connection refused\". Reconnecting..."}
E1009 09:42:47.217216    6910 reflector.go:127] object-"home-network"/"home-network-metallb-speaker-token-w7gtd": Failed to watch *v1.Secret: failed to list *v1.Secret: secrets "home-network-metallb-speaker-token-w7gtd" is forbidden: User "system:node:k3s-master" cannot list resource "secrets" in API group "" in the namespace "home-network": no relationship found between node 'k3s-master' and this object
I1009 09:42:47.272392    6910 trace.go:205] Trace[741004960]: "Update" url:/apis/coordination.k8s.io/v1/namespaces/kube-node-lease/leases/k3s-worker5,user-agent:k3s/v1.21.5+k3s1 (linux/arm) kubernetes/acad8ef,client:xx.xx.xx.205 (09-Oct-2021 09:42:37.269) (total time: 10002ms):
Trace[741004960]: [10.002268515s] [10.002268515s] END
I1009 09:42:47.273823    6910 trace.go:205] Trace[1915289741]: "GuaranteedUpdate etcd3" type:*coordination.Lease (09-Oct-2021 09:42:37.270) (total time: 10003ms):
Trace[1915289741]: [10.003188376s] [10.003188376s] END
E1009 09:42:47.275542    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:47.417210    6910 reflector.go:127] object-"longhorn-system"/"longhorn-default-setting": Failed to watch *v1.ConfigMap: failed to list *v1.ConfigMap: configmaps "longhorn-default-setting" is forbidden: User "system:node:k3s-master" cannot list resource "configmaps" in API group "" in the namespace "longhorn-system": no relationship found between node 'k3s-master' and this object
E1009 09:42:47.948187    6910 secret.go:195] Couldn't get secret longhorn-system/longhorn-service-account-token-s4bjc: failed to sync secret cache: timed out waiting for the condition
E1009 09:42:47.948776    6910 nestedpendingoperations.go:301] Operation for "{volumeName:kubernetes.io/secret/7c852c5c-6a05-4f77-b52a-4e2fd36d3100-longhorn-service-account-token-s4bjc podName:7c852c5c-6a05-4f77-b52a-4e2fd36d3100 nodeName:}" failed. No retries permitted until 2021-10-09 09:42:48.948507799 +0000 UTC m=+28.615928273 (durationBeforeRetry 1s). Error: "MountVolume.SetUp failed for volume \"longhorn-service-account-token-s4bjc\" (UniqueName: \"kubernetes.io/secret/7c852c5c-6a05-4f77-b52a-4e2fd36d3100-longhorn-service-account-token-s4bjc\") pod \"longhorn-csi-plugin-dkvm8\" (UID: \"7c852c5c-6a05-4f77-b52a-4e2fd36d3100\") : failed to sync secret cache: timed out waiting for the condition"
E1009 09:42:47.949037    6910 configmap.go:200] Couldn't get configMap longhorn-system/longhorn-default-setting: failed to sync configmap cache: timed out waiting for the condition
E1009 09:42:47.949477    6910 nestedpendingoperations.go:301] Operation for "{volumeName:kubernetes.io/configmap/f15bb514-58d1-4908-9c13-235b0519b3d7-longhorn-default-setting podName:f15bb514-58d1-4908-9c13-235b0519b3d7 nodeName:}" failed. No retries permitted until 2021-10-09 09:42:48.949291886 +0000 UTC m=+28.616712360 (durationBeforeRetry 1s). Error: "MountVolume.SetUp failed for volume \"longhorn-default-setting\" (UniqueName: \"kubernetes.io/configmap/f15bb514-58d1-4908-9c13-235b0519b3d7-longhorn-default-setting\") pod \"longhorn-manager-qlwgj\" (UID: \"f15bb514-58d1-4908-9c13-235b0519b3d7\") : failed to sync configmap cache: timed out waiting for the condition"
E1009 09:42:47.949986    6910 secret.go:195] Couldn't get secret longhorn-system/longhorn-service-account-token-s4bjc: failed to sync secret cache: timed out waiting for the condition
E1009 09:42:47.950976    6910 nestedpendingoperations.go:301] Operation for "{volumeName:kubernetes.io/secret/0fc8d7bf-f5ca-4c0e-b7a6-32bea47e3a6c-longhorn-service-account-token-s4bjc podName:0fc8d7bf-f5ca-4c0e-b7a6-32bea47e3a6c nodeName:}" failed. No retries permitted until 2021-10-09 09:42:48.950820635 +0000 UTC m=+28.618241109 (durationBeforeRetry 1s). Error: "MountVolume.SetUp failed for volume \"longhorn-service-account-token-s4bjc\" (UniqueName: \"kubernetes.io/secret/0fc8d7bf-f5ca-4c0e-b7a6-32bea47e3a6c-longhorn-service-account-token-s4bjc\") pod \"engine-image-ei-611d1496-mgqn2\" (UID: \"0fc8d7bf-f5ca-4c0e-b7a6-32bea47e3a6c\") : failed to sync secret cache: timed out waiting for the condition"
E1009 09:42:47.950317    6910 secret.go:195] Couldn't get secret longhorn-system/longhorn-service-account-token-s4bjc: failed to sync secret cache: timed out waiting for the condition
E1009 09:42:47.952894    6910 nestedpendingoperations.go:301] Operation for "{volumeName:kubernetes.io/secret/f15bb514-58d1-4908-9c13-235b0519b3d7-longhorn-service-account-token-s4bjc podName:f15bb514-58d1-4908-9c13-235b0519b3d7 nodeName:}" failed. No retries permitted until 2021-10-09 09:42:48.952672226 +0000 UTC m=+28.620092700 (durationBeforeRetry 1s). Error: "MountVolume.SetUp failed for volume \"longhorn-service-account-token-s4bjc\" (UniqueName: \"kubernetes.io/secret/f15bb514-58d1-4908-9c13-235b0519b3d7-longhorn-service-account-token-s4bjc\") pod \"longhorn-manager-qlwgj\" (UID: \"f15bb514-58d1-4908-9c13-235b0519b3d7\") : failed to sync secret cache: timed out waiting for the condition"
E1009 09:42:47.950449    6910 secret.go:195] Couldn't get secret k3os-system/k3os-upgrade-token-sjwz6: failed to sync secret cache: timed out waiting for the condition
E1009 09:42:47.954622    6910 nestedpendingoperations.go:301] Operation for "{volumeName:kubernetes.io/secret/390561ad-69e8-4d7a-a35c-b58e4f008e42-k3os-upgrade-token-sjwz6 podName:390561ad-69e8-4d7a-a35c-b58e4f008e42 nodeName:}" failed. No retries permitted until 2021-10-09 09:42:48.954465541 +0000 UTC m=+28.621886015 (durationBeforeRetry 1s). Error: "MountVolume.SetUp failed for volume \"k3os-upgrade-token-sjwz6\" (UniqueName: \"kubernetes.io/secret/390561ad-69e8-4d7a-a35c-b58e4f008e42-k3os-upgrade-token-sjwz6\") pod \"system-upgrade-controller-c6c9b4c5d-bn6v4\" (UID: \"390561ad-69e8-4d7a-a35c-b58e4f008e42\") : failed to sync secret cache: timed out waiting for the condition"
E1009 09:42:48.049727    6910 secret.go:195] Couldn't get secret default/default-token-w7x77: failed to sync secret cache: timed out waiting for the condition
E1009 09:42:48.051081    6910 nestedpendingoperations.go:301] Operation for "{volumeName:kubernetes.io/secret/94187467-b10f-44d5-a313-38d2ae0bd11d-default-token-w7x77 podName:94187467-b10f-44d5-a313-38d2ae0bd11d nodeName:}" failed. No retries permitted until 2021-10-09 09:42:49.050903738 +0000 UTC m=+28.718324212 (durationBeforeRetry 1s). Error: "MountVolume.SetUp failed for volume \"default-token-w7x77\" (UniqueName: \"kubernetes.io/secret/94187467-b10f-44d5-a313-38d2ae0bd11d-default-token-w7x77\") pod \"omni-metrics-jmxjd\" (UID: \"94187467-b10f-44d5-a313-38d2ae0bd11d\") : failed to sync secret cache: timed out waiting for the condition"
E1009 09:42:48.049728    6910 secret.go:195] Couldn't get secret home-network/home-network-metallb-speaker-token-w7gtd: failed to sync secret cache: timed out waiting for the condition
E1009 09:42:48.053059    6910 nestedpendingoperations.go:301] Operation for "{volumeName:kubernetes.io/secret/c3d31a6f-a0f6-4408-b609-22f826b983b6-home-network-metallb-speaker-token-w7gtd podName:c3d31a6f-a0f6-4408-b609-22f826b983b6 nodeName:}" failed. No retries permitted until 2021-10-09 09:42:49.052891381 +0000 UTC m=+28.720311855 (durationBeforeRetry 1s). Error: "MountVolume.SetUp failed for volume \"home-network-metallb-speaker-token-w7gtd\" (UniqueName: \"kubernetes.io/secret/c3d31a6f-a0f6-4408-b609-22f826b983b6-home-network-metallb-speaker-token-w7gtd\") pod \"home-network-metallb-speaker-2rxj9\" (UID: \"c3d31a6f-a0f6-4408-b609-22f826b983b6\") : failed to sync secret cache: timed out waiting for the condition"
E1009 09:42:48.142582    6910 reflector.go:127] object-"default"/"omni-config": Failed to watch *v1.ConfigMap: failed to list *v1.ConfigMap: configmaps "omni-config" is forbidden: User "system:node:k3s-master" cannot list resource "configmaps" in API group "" in the namespace "default": no relationship found between node 'k3s-master' and this object
E1009 09:42:48.282771    6910 reflector.go:127] object-"k3os-system"/"default-controller-env": Failed to watch *v1.ConfigMap: failed to list *v1.ConfigMap: configmaps "default-controller-env" is forbidden: User "system:node:k3s-master" cannot list resource "configmaps" in API group "" in the namespace "k3os-system": no relationship found between node 'k3s-master' and this object
E1009 09:42:48.336499    6910 reflector.go:127] object-"k3os-system"/"k3os-upgrade-token-sjwz6": Failed to watch *v1.Secret: failed to list *v1.Secret: secrets "k3os-upgrade-token-sjwz6" is forbidden: User "system:node:k3s-master" cannot list resource "secrets" in API group "" in the namespace "k3os-system": no relationship found between node 'k3s-master' and this object
E1009 09:42:48.452009    6910 reflector.go:127] object-"home-network"/"home-network-metallb-memberlist": Failed to watch *v1.Secret: failed to list *v1.Secret: secrets "home-network-metallb-memberlist" is forbidden: User "system:node:k3s-master" cannot list resource "secrets" in API group "" in the namespace "home-network": no relationship found between node 'k3s-master' and this object
E1009 09:42:48.464098    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:48.464283    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:48.464934    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:48.464959    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:48.464108    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:48.464098    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
E1009 09:42:48.465096    6910 authentication.go:53] Unable to authenticate the request due to an error: [invalid bearer token, Token has been invalidated]
I1009 09:42:48.875788    6910 trace.go:205] Trace[2085309366]: "GuaranteedUpdate etcd3" type:*core.Pod (09-Oct-2021 09:42:38.801) (total time: 10073ms):
Trace[2085309366]: [10.073685881s] [10.073685881s] END
I1009 09:42:48.876305    6910 trace.go:205] Trace[1288372931]: "Patch" url:/api/v1/namespaces/default/pods/omni-metrics-zs8jf/status,user-agent:k3s/v1.21.5+k3s1 (linux/arm) kubernetes/acad8ef,client:xx.xx.xx.204 (09-Oct-2021 09:42:38.801) (total time: 10074ms):
Trace[1288372931]: [10.074869196s] [10.074869196s] END
WARN[2021-10-09T09:42:48.951359198Z] Unable to watch for tunnel endpoints: unknown (get endpoints) 
DEBU[2021-10-09T09:42:48.964184507Z] Wrote ping                                   
I1009 09:42:49.134139    6910 trace.go:205] Trace[86451205]: "GuaranteedUpdate etcd3" type:*core.Node (09-Oct-2021 09:42:39.115) (total time: 10018ms):
Trace[86451205]: [10.018628697s] [10.018628697s] END
I1009 09:42:49.134550    6910 trace.go:205] Trace[1905651615]: "Update" url:/api/v1/nodes/k3s-master,user-agent:k3s/v1.19.15+k3s2 (linux/arm64) kubernetes/0fbbc5a,client:127.0.0.1 (09-Oct-2021 09:42:39.112) (total time: 10022ms):
Trace[1905651615]: [10.022099532s] [10.022099532s] END
INFO[2021-10-09T09:42:49.137285825Z] Failed to update node k3s-master: nodes "k3s-master" is forbidden: not yet ready to handle request 
E1009 09:42:49.728891    6910 reflector.go:127] object-"default"/"default-token-w7x77": Failed to watch *v1.Secret: failed to list *v1.Secret: secrets "default-token-w7x77" is forbidden: User "system:node:k3s-master" cannot list resource "secrets" in API group "" in the namespace "default": no relationship found between node 'k3s-master' and this object
E1009 09:42:49.803081    6910 reflector.go:127] object-"longhorn-system"/"longhorn-service-account-token-s4bjc": Failed to watch *v1.Secret: failed to list *v1.Secret: secrets "longhorn-service-account-token-s4bjc" is forbidden: User "system:node:k3s-master" cannot list resource "secrets" in API group "" in the namespace "longhorn-system": no relationship found between node 'k3s-master' and this object
{"level":"warn","ts":"2021-10-09T09:42:49.980Z","caller":"grpclog/grpclog.go:60","msg":"grpc: addrConn.createTransport failed to connect to {/var/lib/kubelet/plugins_registry/driver.longhorn.io-reg.sock  <nil> 0 <nil>}. Err :connection error: desc = \"transport: Error while dialing dial unix /var/lib/kubelet/plugins_registry/driver.longhorn.io-reg.sock: connect: connection refused\". Reconnecting..."}
E1009 09:42:49.987347    6910 secret.go:195] Couldn't get secret longhorn-system/longhorn-service-account-token-s4bjc: failed to sync secret cache: timed out waiting for the condition
E1009 09:42:49.987762    6910 nestedpendingoperations.go:301] Operation for "{volumeName:kubernetes.io/secret/f15bb514-58d1-4908-9c13-235b0519b3d7-longhorn-service-account-token-s4bjc podName:f15bb514-58d1-4908-9c13-235b0519b3d7 nodeName:}" failed. No retries permitted until 2021-10-09 09:42:51.987610305 +0000 UTC m=+31.655030816 (durationBeforeRetry 2s). Error: "MountVolume.SetUp failed for volume \"longhorn-service-account-token-s4bjc\" (UniqueName: \"kubernetes.io/secret/f15bb514-58d1-4908-9c13-235b0519b3d7-longhorn-service-account-token-s4bjc\") pod \"longhorn-manager-qlwgj\" (UID: \"f15bb514-58d1-4908-9c13-235b0519b3d7\") : failed to sync secret cache: timed out waiting for the condition"
E1009 09:42:49.988014    6910 secret.go:195] Couldn't get secret k3os-system/k3os-upgrade-token-sjwz6: failed to sync secret cache: timed out waiting for the condition
E1009 09:42:49.988345    6910 nestedpendingoperations.go:301] Operation for "{volumeName:kubernetes.io/secret/390561ad-69e8-4d7a-a35c-b58e4f008e42-k3os-upgrade-token-sjwz6 podName:390561ad-69e8-4d7a-a35c-b58e4f008e42 nodeName:}" failed. No retries permitted until 2021-10-09 09:42:51.98820499 +0000 UTC m=+31.655625464 (durationBeforeRetry 2s). Error: "MountVolume.SetUp failed for volume \"k3os-upgrade-token-sjwz6\" (UniqueName: \"kubernetes.io/secret/390561ad-69e8-4d7a-a35c-b58e4f008e42-k3os-upgrade-token-sjwz6\") pod \"system-upgrade-controller-c6c9b4c5d-bn6v4\" (UID: \"390561ad-69e8-4d7a-a35c-b58e4f008e42\") : failed to sync secret cache: timed out waiting for the condition"
E1009 09:42:49.988492    6910 secret.go:195] Couldn't get secret longhorn-system/longhorn-service-account-token-s4bjc: failed to sync secret cache: timed out waiting for the condition
E1009 09:42:49.988821    6910 secret.go:195] Couldn't get secret longhorn-system/longhorn-service-account-token-s4bjc: failed to sync secret cache: timed out waiting for the condition
E1009 09:42:49.988852    6910 nestedpendingoperations.go:301] Operation for "{volumeName:kubernetes.io/secret/0fc8d7bf-f5ca-4c0e-b7a6-32bea47e3a6c-longhorn-service-account-token-s4bjc podName:0fc8d7bf-f5ca-4c0e-b7a6-32bea47e3a6c nodeName:}" failed. No retries permitted until 2021-10-09 09:42:51.988735307 +0000 UTC m=+31.656155781 (durationBeforeRetry 2s). Error: "MountVolume.SetUp failed for volume \"longhorn-service-account-token-s4bjc\" (UniqueName: \"kubernetes.io/secret/0fc8d7bf-f5ca-4c0e-b7a6-32bea47e3a6c-longhorn-service-account-token-s4bjc\") pod \"engine-image-ei-611d1496-mgqn2\" (UID: \"0fc8d7bf-f5ca-4c0e-b7a6-32bea47e3a6c\") : failed to sync secret cache: timed out waiting for the condition"
E1009 09:42:49.989023    6910 configmap.go:200] Couldn't get configMap longhorn-system/longhorn-default-setting: failed to sync configmap cache: timed out waiting for the condition
E1009 09:42:49.989192    6910 nestedpendingoperations.go:301] Operation for "{volumeName:kubernetes.io/secret/7c852c5c-6a05-4f77-b52a-4e2fd36d3100-longhorn-service-account-token-s4bjc podName:7c852c5c-6a05-4f77-b52a-4e2fd36d3100 nodeName:}" failed. No retries permitted until 2021-10-09 09:42:51.989029076 +0000 UTC m=+31.656449550 (durationBeforeRetry 2s). Error: "MountVolume.SetUp failed for volume \"longhorn-service-account-token-s4bjc\" (UniqueName: \"kubernetes.io/secret/7c852c5c-6a05-4f77-b52a-4e2fd36d3100-longhorn-service-account-token-s4bjc\") pod \"longhorn-csi-plugin-dkvm8\" (UID: \"7c852c5c-6a05-4f77-b52a-4e2fd36d3100\") : failed to sync secret cache: timed out waiting for the condition"
E1009 09:42:49.989422    6910 nestedpendingoperations.go:301] Operation for "{volumeName:kubernetes.io/configmap/f15bb514-58d1-4908-9c13-235b0519b3d7-longhorn-default-setting podName:f15bb514-58d1-4908-9c13-235b0519b3d7 nodeName:}" failed. No retries permitted until 2021-10-09 09:42:51.989309086 +0000 UTC m=+31.656729578 (durationBeforeRetry 2s). Error: "MountVolume.SetUp failed for volume \"longhorn-default-setting\" (UniqueName: \"kubernetes.io/configmap/f15bb514-58d1-4908-9c13-235b0519b3d7-longhorn-default-setting\") pod \"longhorn-manager-qlwgj\" (UID: \"f15bb514-58d1-4908-9c13-235b0519b3d7\") : failed to sync configmap cache: timed out waiting for the condition"
E1009 09:42:49.990023    6910 reflector.go:127] object-"longhorn-system"/"longhorn-default-setting": Failed to watch *v1.ConfigMap: failed to list *v1.ConfigMap: configmaps "longhorn-default-setting" is forbidden: User "system:node:k3s-master" cannot list resource "configmaps" in API group "" in the namespace "longhorn-system": no relationship found between node 'k3s-master' and this object
E1009 09:42:50.081821    6910 reflector.go:127] object-"home-network"/"home-network-metallb-speaker-token-w7gtd": Failed to watch *v1.Secret: failed to list *v1.Secret: secrets "home-network-metallb-speaker-token-w7gtd" is forbidden: User "system:node:k3s-master" cannot list resource "secrets" in API group "" in the namespace "home-network": no relationship found between node 'k3s-master' and this object
E1009 09:42:50.087919    6910 secret.go:195] Couldn't get secret default/default-token-w7x77: failed to sync secret cache: timed out waiting for the condition
E1009 09:42:50.088296    6910 nestedpendingoperations.go:301] Operation for "{volumeName:kubernetes.io/secret/94187467-b10f-44d5-a313-38d2ae0bd11d-default-token-w7x77 podName:94187467-b10f-44d5-a313-38d2ae0bd11d nodeName:}" failed. No retries permitted until 2021-10-09 09:42:52.088150414 +0000 UTC m=+31.755570869 (durationBeforeRetry 2s). Error: "MountVolume.SetUp failed for volume \"default-token-w7x77\" (UniqueName: \"kubernetes.io/secret/94187467-b10f-44d5-a313-38d2ae0bd11d-default-token-w7x77\") pod \"omni-metrics-jmxjd\" (UID: \"94187467-b10f-44d5-a313-38d2ae0bd11d\") : failed to sync secret cache: timed out waiting for the condition"
E1009 09:42:50.088479    6910 secret.go:195] Couldn't get secret home-network/home-network-metallb-speaker-token-w7gtd: failed to sync secret cache: timed out waiting for the condition
E1009 09:42:50.088802    6910 nestedpendingoperations.go:301] Operation for "{volumeName:kubernetes.io/secret/c3d31a6f-a0f6-4408-b609-22f826b983b6-home-network-metallb-speaker-token-w7gtd podName:c3d31a6f-a0f6-4408-b609-22f826b983b6 nodeName:}" failed. No retries permitted until 2021-10-09 09:42:52.088689842 +0000 UTC m=+31.756110316 (durationBeforeRetry 2s). Error: "MountVolume.SetUp failed for volume \"home-network-metallb-speaker-token-w7gtd\" (UniqueName: \"kubernetes.io/secret/c3d31a6f-a0f6-4408-b609-22f826b983b6-home-network-metallb-speaker-token-w7gtd\") pod \"home-network-metallb-speaker-2rxj9\" (UID: \"c3d31a6f-a0f6-4408-b609-22f826b983b6\") : failed to sync secret cache: timed out waiting for the condition"
I1009 09:42:50.164902    6910 trace.go:205] Trace[939075419]: "GuaranteedUpdate etcd3" type:*core.Node (09-Oct-2021 09:42:40.117) (total time: 10047ms):
Trace[939075419]: [10.047592912s] [10.047592912s] END
I1009 09:42:50.165422    6910 trace.go:205] Trace[2138203240]: "Patch" url:/api/v1/nodes/k3s-master/status,user-agent:k3s/v1.19.15+k3s2 (linux/arm64) kubernetes/0fbbc5a,client:127.0.0.1 (09-Oct-2021 09:42:40.116) (total time: 10048ms):
Trace[2138203240]: [10.048922352s] [10.048922352s] END
FATA[2021-10-09T09:42:50.166663087Z] flannel exited: failed to acquire lease: nodes "k3s-master" is forbidden: not yet ready to handle request

Not sure if this is a problem but k3s check-config shows 6 errors as per below.

k3s-master [~]$ sudo k3s check-config

Verifying binaries in /var/lib/rancher/k3s/data/9cbaf87b73f0bc19774ba256b577f7a9cf7842dafbf872eb08b2ca2512d44bc5/bin:
- sha256sum: good
- links: aux/ip6tables should link to iptables-detect.sh (fail)
- links: aux/ip6tables-restore should link to iptables-detect.sh (fail)
- links: aux/ip6tables-save should link to iptables-detect.sh (fail)
- links: aux/iptables should link to iptables-detect.sh (fail)
- links: aux/iptables-restore should link to iptables-detect.sh (fail)
- links: aux/iptables-save should link to iptables-detect.sh (fail)

System:
- /usr/sbin iptables v1.8.4 (legacy): ok
- swap: disabled
- routes: ok

Limits:
- /proc/sys/kernel/keys/root_maxkeys: 1000000

info: reading kernel config from /proc/config.gz ...

Generally Necessary:
- cgroup hierarchy: properly mounted [/sys/fs/cgroup]
- CONFIG_NAMESPACES: enabled
- CONFIG_NET_NS: enabled
- CONFIG_PID_NS: enabled
- CONFIG_IPC_NS: enabled
- CONFIG_UTS_NS: enabled
- CONFIG_CGROUPS: enabled
- CONFIG_CGROUP_CPUACCT: enabled
- CONFIG_CGROUP_DEVICE: enabled
- CONFIG_CGROUP_FREEZER: enabled
- CONFIG_CGROUP_SCHED: enabled
- CONFIG_CPUSETS: enabled
- CONFIG_MEMCG: enabled
- CONFIG_KEYS: enabled
- CONFIG_VETH: enabled (as module)
- CONFIG_BRIDGE: enabled (as module)
- CONFIG_BRIDGE_NETFILTER: enabled (as module)
- CONFIG_IP_NF_FILTER: enabled (as module)
- CONFIG_IP_NF_TARGET_MASQUERADE: enabled (as module)
- CONFIG_NETFILTER_XT_MATCH_ADDRTYPE: enabled (as module)
- CONFIG_NETFILTER_XT_MATCH_CONNTRACK: enabled (as module)
- CONFIG_NETFILTER_XT_MATCH_IPVS: enabled (as module)
- CONFIG_IP_NF_NAT: enabled (as module)
- CONFIG_NF_NAT: enabled (as module)
- CONFIG_POSIX_MQUEUE: enabled

Optional Features:
- CONFIG_USER_NS: enabled
- CONFIG_SECCOMP: enabled
- CONFIG_CGROUP_PIDS: enabled
- CONFIG_BLK_CGROUP: enabled
- CONFIG_BLK_DEV_THROTTLING: enabled
- CONFIG_CGROUP_PERF: missing
- CONFIG_CGROUP_HUGETLB: missing
- CONFIG_NET_CLS_CGROUP: enabled (as module)
- CONFIG_CGROUP_NET_PRIO: missing
- CONFIG_CFS_BANDWIDTH: missing
- CONFIG_FAIR_GROUP_SCHED: enabled
- CONFIG_RT_GROUP_SCHED: missing
- CONFIG_IP_NF_TARGET_REDIRECT: enabled (as module)
- CONFIG_IP_SET: enabled (as module)
- CONFIG_IP_VS: enabled (as module)
- CONFIG_IP_VS_NFCT: enabled
- CONFIG_IP_VS_PROTO_TCP: enabled
- CONFIG_IP_VS_PROTO_UDP: enabled
- CONFIG_IP_VS_RR: enabled (as module)
- CONFIG_EXT4_FS: enabled
- CONFIG_EXT4_FS_POSIX_ACL: enabled
- CONFIG_EXT4_FS_SECURITY: enabled
- Network Drivers:
  - "overlay":
    - CONFIG_VXLAN: enabled (as module)
      Optional (for encrypted networks):
      - CONFIG_CRYPTO: enabled
      - CONFIG_CRYPTO_AEAD: enabled (as module)
      - CONFIG_CRYPTO_GCM: enabled (as module)
      - CONFIG_CRYPTO_SEQIV: enabled (as module)
      - CONFIG_CRYPTO_GHASH: enabled (as module)
      - CONFIG_XFRM: enabled
      - CONFIG_XFRM_USER: enabled
      - CONFIG_XFRM_ALGO: enabled
      - CONFIG_INET_ESP: enabled (as module)
      - CONFIG_INET_XFRM_MODE_TRANSPORT: missing
- Storage Drivers:
  - "overlay":
    - CONFIG_OVERLAY_FS: enabled (as module)

STATUS: 6 (fail)

Please let me know if I can provide any further information. I did not want to label this as a bug since I have no evidence of that and cannot easily reproduce (for the moment at least)

mr-onion-2 commented 2 years ago

I ended up rebuilding. If it happens again I'll re-open

mr-onion-2 commented 2 years ago

Re-opening since this has occurred again.

The cluster had been working flawlessly since October. This morning I drained and rebooted the master node and it failed to start back up. Same errors in the log as in the original comment. Automatic upgrades were disabled this time, so nothing should have changed :\

mr-onion-2 commented 2 years ago

Closing this again as I believe it was caused by user config :)

I run K3OS on a Pi cluster. I use an internal NTP server but the master node looks to have failed to sync the time successfully. Since Pi's do not have a Real Time Clock, the date was 1970-01-01. I'm guessing this was the reason for the bearer token errors.