Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

K3s does not start after restoration #9305

Closed
GayathriBandaru94 opened this issue Jan 26, 2024 · 3 comments
Closed

K3s does not start after restoration #9305

GayathriBandaru94 opened this issue Jan 26, 2024 · 3 comments

Comments

@GayathriBandaru94
Copy link

Environmental Info:
K3s Version:
v1.28.5+k3s1

Node(s) CPU architecture, OS, and Version:
Linux etcd-test 6.2.0-1018-azure #18~22.04.1-Ubuntu SMP Tue Nov 21 19:25:02 UTC 2023 x86_64 x86_64 x86_64 GNU/Linux

Cluster Configuration:
3 servers 2 agents

Describe the bug:
From my cluster of 3 servers 2 agents the backup snapshots are saved in Wasabi bucket. I have used one of these backup and tried to restore the cluster on a new azure vm.
i have performed the following steps on my new vm:

  1. k3s installation
curl -sfL https://get.k3s.io | sh -s - server --secrets-encryption true
  1. bash systemctl stop k3s

  2. Copied the backup file to the new vm. Restoring the cluster using the following command

k3s server --cluster-init --cluster-reset --cluster-reset-restore-path=<path of the snapshot> --token <token from one of the servers from previous cluster>

Output of the above command:

root@etcd-test:~# k3s server --cluster-init --cluster-reset --cluster-reset-restore-path=/home/azureuser/on-demand-k8s-master000000-1706171454 --token K1047f92ce09941328cf1833ec0faea4c0d5c175cfc834b6b6d1ce295ad357ba18b::server:upAL0AZpDOcEt3tzKcxP9kcZBskL6T8Gdkg9efJxfoRZLB50xVa2E9otRSMg0CuJ
WARN[0000] remove /var/lib/rancher/k3s/agent/etc/k3s-agent-load-balancer.json: no such file or directory 
WARN[0000] remove /var/lib/rancher/k3s/agent/etc/k3s-api-server-agent-load-balancer.json: no such file or directory
INFO[0000] Starting k3s v1.28.5+k3s1 (5b2d1271)
INFO[0000] Managed etcd cluster initializing
INFO[0000] generated self-signed CA certificate CN=k3s-client-ca@1706283004: notBefore=2024-01-26 15:30:04.384582512 +0000 UTC notAfter=2034-01-23 15:30:04.384582512 +0000 UTC
INFO[0000] certificate CN=system:admin,O=system:masters signed by CN=k3s-client-ca@1706283004: notBefore=2024-01-26 15:30:04 +0000 UTC notAfter=2025-01-25 15:30:04 +0000 UTC
INFO[0000] certificate CN=system:k3s-supervisor,O=system:masters signed by CN=k3s-client-ca@1706283004: notBefore=2024-01-26 15:30:04 +0000 UTC notAfter=2025-01-25 15:30:04 +0000 UTC   
INFO[0000] certificate CN=system:kube-controller-manager signed by CN=k3s-client-ca@1706283004: notBefore=2024-01-26 15:30:04 +0000 UTC notAfter=2025-01-25 15:30:04 +0000 UTC
INFO[0000] certificate CN=system:kube-scheduler signed by CN=k3s-client-ca@1706283004: notBefore=2024-01-26 15:30:04 +0000 UTC notAfter=2025-01-25 15:30:04 +0000 UTC
INFO[0000] certificate CN=system:apiserver,O=system:masters signed by CN=k3s-client-ca@1706283004: notBefore=2024-01-26 15:30:04 +0000 UTC notAfter=2025-01-25 15:30:04 +0000 UTC        
INFO[0000] certificate CN=system:kube-proxy signed by CN=k3s-client-ca@1706283004: notBefore=2024-01-26 15:30:04 +0000 UTC notAfter=2025-01-25 15:30:04 +0000 UTC
INFO[0000] certificate CN=system:k3s-controller signed by CN=k3s-client-ca@1706283004: notBefore=2024-01-26 15:30:04 +0000 UTC notAfter=2025-01-25 15:30:04 +0000 UTC
INFO[0000] certificate CN=k3s-cloud-controller-manager signed by CN=k3s-client-ca@1706283004: notBefore=2024-01-26 15:30:04 +0000 UTC notAfter=2025-01-25 15:30:04 +0000 UTC
INFO[0000] generated self-signed CA certificate CN=k3s-server-ca@1706283004: notBefore=2024-01-26 15:30:04.388538964 +0000 UTC notAfter=2034-01-23 15:30:04.388538964 +0000 UTC 
INFO[0000] certificate CN=kube-apiserver signed by CN=k3s-server-ca@1706283004: notBefore=2024-01-26 15:30:04 +0000 UTC notAfter=2025-01-25 15:30:04 +0000 UTC
INFO[0000] generated self-signed CA certificate CN=k3s-request-header-ca@1706283004: notBefore=2024-01-26 15:30:04.389440875 +0000 UTC notAfter=2034-01-23 15:30:04.389440875 +0000 UTC  
INFO[0000] certificate CN=system:auth-proxy signed by CN=k3s-request-header-ca@1706283004: notBefore=2024-01-26 15:30:04 +0000 UTC notAfter=2025-01-25 15:30:04 +0000 UTC
INFO[0000] generated self-signed CA certificate CN=etcd-server-ca@1706283004: notBefore=2024-01-26 15:30:04.390178185 +0000 UTC notAfter=2034-01-23 15:30:04.390178185 +0000 UTC
INFO[0000] certificate CN=etcd-client signed by CN=etcd-server-ca@1706283004: notBefore=2024-01-26 15:30:04 +0000 UTC notAfter=2025-01-25 15:30:04 +0000 UTC
INFO[0000] generated self-signed CA certificate CN=etcd-peer-ca@1706283004: notBefore=2024-01-26 15:30:04.390894794 +0000 UTC notAfter=2034-01-23 15:30:04.390894794 +0000 UTC
INFO[0000] certificate CN=etcd-peer signed by CN=etcd-peer-ca@1706283004: notBefore=2024-01-26 15:30:04 +0000 UTC notAfter=2025-01-25 15:30:04 +0000 UTC
INFO[0000] certificate CN=etcd-server signed by CN=etcd-server-ca@1706283004: notBefore=2024-01-26 15:30:04 +0000 UTC notAfter=2025-01-25 15:30:04 +0000 UTC
INFO[0000] certificate CN=k3s,O=k3s signed by CN=k3s-server-ca@1706283004: notBefore=2024-01-26 15:30:04 +0000 UTC notAfter=2025-01-25 15:30:04 +0000 UTC 
WARN[0000] dynamiclistener [::]:6443: no cached certificate available for preload - deferring certificate load until storage initialization or first client request
INFO[0000] Pre-restore etcd database moved to /var/lib/rancher/k3s/server/db/etcd-old-1706283004
INFO[0000] Active TLS secret / (ver=) (count 10): map[listener.cattle.io/cn-10.1.0.4:10.1.0.4 listener.cattle.io/cn-10.43.0.1:10.43.0.1 listener.cattle.io/cn-127.0.0.1:127.0.0.1 listener.cattle.io/cn-__1-f16284:::1 listener.cattle.io/cn-etcd-test:etcd-test listener.cattle.io/cn-kubernetes:kubernetes listener.cattle.io/cn-kubernetes.default:kubernetes.default listener.cattle.io/cn-kubernetes.default.svc:kubernetes.default.svc listener.cattle.io/cn-kubernetes.default.svc.cluster.local:kubernetes.default.svc.cluster.local listener.cattle.io/cn-localhost:localhost listener.cattle.io/fingerprint:SHA1=83C6FA154943796310F7BD3DADA5BE7F4A8E1855]
{"level":"info","ts":"2024-01-26T15:30:04.939671Z","caller":"snapshot/v3_snapshot.go:248","msg":"restoring snapshot","path":"/home/azureuser/on-demand-k8s-master000000-1706171454","wal-dir":"/var/lib/rancher/k3s/server/db/etcd/member/wal","data-dir":"/var/lib/rancher/k3s/server/db/etcd","snap-dir":"/var/lib/rancher/k3s/server/db/etcd/member/snap","stack":"go.etcd.io/etcd/etcdutl/v3/snapshot.(*v3Manager).Restore\n\t/go/pkg/mod/github.com/k3s-io/etcd/etcdutl/v3@v3.5.9-k3s1/snapshot/v3_snapshot.go:254\ngithub.com/k3s-io/k3s/pkg/etcd.(*ETCD).Restore\n\t/go/src/github.com/k3s-io/k3s/pkg/etcd/etcd.go:1360\ngithub.com/k3s-io/k3s/pkg/etcd.(*ETCD).Reset\n\t/go/src/github.com/k3s-io/k3s/pkg/etcd/etcd.go:381\ngithub.com/k3s-io/k3s/pkg/cluster.(*Cluster).start\n\t/go/src/github.com/k3s-io/k3s/pkg/cluster/managed.go:70\ngithub.com/k3s-io/k3s/pkg/cluster.(*Cluster).Start\n\t/go/src/github.com/k3s-io/k3s/pkg/cluster/cluster.go:75\ngithub.com/k3s-io/k3s/pkg/daemons/control.prepare\n\t/go/src/github.com/k3s-io/k3s/pkg/daemons/control/server.go:273\ngithub.com/k3s-io/k3s/pkg/daemons/control.Server\n\t/go/src/github.com/k3s-io/k3s/pkg/daemons/control/server.go:35\ngithub.com/k3s-io/k3s/pkg/server.StartServer\n\t/go/src/github.com/k3s-io/k3s/pkg/server/server.go:56\ngithub.com/k3s-io/k3s/pkg/cli/server.run\n\t/go/src/github.com/k3s-io/k3s/pkg/cli/server/server.go:481\ngithub.com/k3s-io/k3s/pkg/cli/server.Run\n\t/go/src/github.com/k3s-io/k3s/pkg/cli/server/server.go:41\ngithub.com/urfave/cli.HandleAction\n\t/go/pkg/mod/github.com/urfave/cli@v1.22.14/app.go:524\ngithub.com/urfave/cli.Command.Run\n\t/go/pkg/mod/github.com/urfave/cli@v1.22.14/command.go:175\ngithub.com/urfave/cli.(*App).Run\n\t/go/pkg/mod/github.com/urfave/cli@v1.22.14/app.go:277\nmain.main\n\t/go/src/github.com/k3s-io/k3s/cmd/server/main.go:81\nruntime.main\n\t/usr/local/go/src/runtime/proc.go:250"}
{"level":"info","ts":"2024-01-26T15:30:05.590727Z","caller":"membership/store.go:141","msg":"Trimming membership information from the backend..."}
{"level":"info","ts":"2024-01-26T15:30:06.028732Z","caller":"membership/cluster.go:421","msg":"added member","cluster-id":"8ccd0f608323fe0a","local-member-id":"0","added-peer-id":"fd8a1f8b889e2f52","added-peer-peer-urls":["https://10.1.0.4:2380"]}
{"level":"info","ts":"2024-01-26T15:30:06.079812Z","caller":"snapshot/v3_snapshot.go:269","msg":"restored snapshot","path":"/home/azureuser/on-demand-k8s-master000000-1706171454","wal-dir":"/var/lib/rancher/k3s/server/db/etcd/member/wal","data-dir":"/var/lib/rancher/k3s/server/db/etcd","snap-dir":"/var/lib/rancher/k3s/server/db/etcd/member/snap"}
INFO[0001] Starting etcd for new cluster
{"level":"info","ts":"2024-01-26T15:30:06.081168Z","caller":"embed/etcd.go:127","msg":"configuring peer listeners","listen-peer-urls":["https://127.0.0.1:2380"]}
{"level":"info","ts":"2024-01-26T15:30:06.081212Z","caller":"embed/etcd.go:495","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, client-cert=, 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":"2024-01-26T15:30:06.081484Z","caller":"embed/etcd.go:135","msg":"configuring client listeners","listen-client-urls":["https://127.0.0.1:2379"]}
{"level":"info","ts":"2024-01-26T15:30:06.081587Z","caller":"embed/etcd.go:309","msg":"starting an etcd server","etcd-version":"3.5.9","git-sha":"Not provided (use ./build instead of go build)","go-version":"go1.20.12","go-os":"linux","go-arch":"amd64","max-cpu-set":2,"max-cpu-available":2,"member-initialized":true,"name":"etcd-test-d08e21bb","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":true,"heartbeat-interval":"500ms","election-timeout":"5s","initial-election-tick-advance":true,"snapshot-count":10000,"max-wals":5,"max-snapshots":5,"snapshot-catchup-entries":5000,"initial-advertise-peer-urls":["https://10.1.0.4:2380"],"listen-peer-urls":["https://127.0.0.1:2380"],"advertise-client-urls":["https://127.0.0.1:2379"],"listen-client-urls":["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-backend-bytes":2147483648,"max-request-bytes":1572864,"max-concurrent-streams":4294967295,"pre-vote":true,"initial-corrupt-check":true,"corrupt-check-time-interval":"0s","compact-check-time-enabled":false,"compact-check-time-interval":"1m0s","auto-compaction-mode":"","auto-compaction-retention":"0s","auto-compaction-interval":"0s","discovery-url":"","discovery-proxy":"","downgrade-check-interval":"5s"}
{"level":"info","ts":"2024-01-26T15:30:06.0863Z","caller":"etcdserver/backend.go:81","msg":"opened backend db","path":"/var/lib/rancher/k3s/server/db/etcd/member/snap/db","took":"4.521161ms"}
{"level":"info","ts":"2024-01-26T15:30:06.086865Z","caller":"etcdserver/server.go:509","msg":"recovered v2 store from snapshot","snapshot-index":1,"snapshot-size":"6.5 kB"}
{"level":"info","ts":"2024-01-26T15:30:06.086922Z","caller":"etcdserver/server.go:522","msg":"recovered v3 backend from snapshot","backend-size-bytes":32198656,"backend-size":"32 MB","backend-size-in-use-bytes":15003648,"backend-size-in-use":"15 MB"}
{"level":"info","ts":"2024-01-26T15:30:06.087306Z","caller":"etcdserver/raft.go:603","msg":"forcing restart member","cluster-id":"8ccd0f608323fe0a","local-member-id":"fd8a1f8b889e2f52","commit-index":1}
{"level":"info","ts":"2024-01-26T15:30:06.087368Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"fd8a1f8b889e2f52 switched to configuration voters=(18269449522534821714)"}{"level":"info","ts":"2024-01-26T15:30:06.087476Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"fd8a1f8b889e2f52 became follower at term 1"}
{"level":"info","ts":"2024-01-26T15:30:06.087498Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"newRaft fd8a1f8b889e2f52 [peers: [fd8a1f8b889e2f52], term: 1, commit: 1, applied: 1, lastindex: 1, lastterm: 1]"}
{"level":"info","ts":"2024-01-26T15:30:06.087562Z","caller":"membership/cluster.go:278","msg":"recovered/added member from store","cluster-id":"8ccd0f608323fe0a","local-member-id":"fd8a1f8b889e2f52","recovered-remote-peer-id":"fd8a1f8b889e2f52","recovered-remote-peer-urls":["https://10.1.0.4:2380"]}
{"level":"warn","ts":"2024-01-26T15:30:06.090386Z","caller":"auth/store.go:1238","msg":"simple token is not cryptographically signed"}
{"level":"info","ts":"2024-01-26T15:30:06.100256Z","caller":"mvcc/kvstore.go:323","msg":"restored last compact revision","meta-bucket-name":"meta","meta-bucket-name-key":"finishedCompactRev","restored-compact-revision":189859}
{"level":"info","ts":"2024-01-26T15:30:06.113908Z","caller":"mvcc/kvstore.go:393","msg":"kvstore restored","current-rev":193363}
{"level":"info","ts":"2024-01-26T15:30:06.119998Z","caller":"etcdserver/quota.go:94","msg":"enabled backend quota with default value","quota-name":"v3-applier","quota-size-bytes":2147483648,"quota-size":"2.1 GB"}
{"level":"info","ts":"2024-01-26T15:30:06.124676Z","caller":"etcdserver/corrupt.go:95","msg":"starting initial corruption check","local-member-id":"fd8a1f8b889e2f52","timeout":"15s"}   
{"level":"info","ts":"2024-01-26T15:30:06.12761Z","caller":"etcdserver/corrupt.go:165","msg":"initial corruption checking passed; no corruption","local-member-id":"fd8a1f8b889e2f52"}   
{"level":"info","ts":"2024-01-26T15:30:06.12765Z","caller":"etcdserver/server.go:854","msg":"starting etcd server","local-member-id":"fd8a1f8b889e2f52","local-server-version":"3.5.9","cluster-version":"to_be_decided"}
{"level":"info","ts":"2024-01-26T15:30:06.127948Z","caller":"etcdserver/server.go:738","msg":"started as single-node; fast-forwarding election ticks","local-member-id":"fd8a1f8b889e2f52","forward-ticks":9,"forward-duration":"4.5s","election-ticks":10,"election-timeout":"5s"}
{"level":"info","ts":"2024-01-26T15:30:06.128211Z","caller":"fileutil/purge.go:44","msg":"started to purge file","dir":"/var/lib/rancher/k3s/server/db/etcd/member/snap","suffix":"snap.db","max":5,"interval":"30s"}
{"level":"info","ts":"2024-01-26T15:30:06.128331Z","caller":"fileutil/purge.go:44","msg":"started to purge file","dir":"/var/lib/rancher/k3s/server/db/etcd/member/snap","suffix":"snap","max":5,"interval":"30s"}
{"level":"info","ts":"2024-01-26T15:30:06.128421Z","caller":"fileutil/purge.go:44","msg":"started to purge file","dir":"/var/lib/rancher/k3s/server/db/etcd/member/wal","suffix":"wal","max":5,"interval":"30s"}
{"level":"info","ts":"2024-01-26T15:30:06.129784Z","caller":"embed/etcd.go:726","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, client-cert=, 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":"2024-01-26T15:30:06.12994Z","caller":"embed/etcd.go:278","msg":"now serving peer/client/metrics","local-member-id":"fd8a1f8b889e2f52","initial-advertise-peer-urls":["https://10.1.0.4:2380"],"listen-peer-urls":["https://127.0.0.1:2380"],"advertise-client-urls":["https://127.0.0.1:2379"],"listen-client-urls":["https://127.0.0.1:2379"],"listen-metrics-urls":["http://127.0.0.1:2381"]}
{"level":"info","ts":"2024-01-26T15:30:06.132309Z","caller":"embed/etcd.go:597","msg":"serving peer traffic","address":"127.0.0.1:2380"}
{"level":"info","ts":"2024-01-26T15:30:06.132927Z","caller":"embed/etcd.go:569","msg":"cmux::serve","address":"127.0.0.1:2380"}
{"level":"info","ts":"2024-01-26T15:30:06.134811Z","caller":"embed/etcd.go:855","msg":"serving metrics","address":"http://127.0.0.1:2381"}
INFO[0002] Running cloud-controller-manager --allocate-node-cidrs=true --authentication-kubeconfig=/var/lib/rancher/k3s/server/cred/cloud-controller.kubeconfig --authorization-kubeconfig=/var/lib/rancher/k3s/server/cred/cloud-controller.kubeconfig --bind-address=127.0.0.1 --cloud-config=/var/lib/rancher/k3s/server/etc/cloud-config.yaml --cloud-provider=k3s --cluster-cidr=10.42.0.0/16 --configure-cloud-routes=false --controllers=*,-route,-cloud-node,-cloud-node-lifecycle --feature-gates=CloudDualStackNodeIPs=true --kubeconfig=/var/lib/rancher/k3s/server/cred/cloud-controller.kubeconfig --leader-elect-resource-name=k3s-cloud-controller-manager --node-status-update-frequency=1m0s --profiling=false --secure-port=0
INFO[0002] Server node token is available at /var/lib/rancher/k3s/server/token 
INFO[0002] To join server node to cluster: k3s server -s https://10.1.0.4:6443 -t ${SERVER_NODE_TOKEN}
INFO[0002] Agent node token is available at /var/lib/rancher/k3s/server/agent-token
INFO[0002] To join agent node to cluster: k3s agent -s https://10.1.0.4:6443 -t ${AGENT_NODE_TOKEN}
INFO[0002] Wrote kubeconfig /etc/rancher/k3s/k3s.yaml
INFO[0002] Run: k3s kubectl
WARN[0002] remove /var/lib/rancher/k3s/agent/etc/k3s-agent-load-balancer.json: no such file or directory
INFO[0002] Adding server to load balancer k3s-agent-load-balancer: 127.0.0.1:6443
INFO[0002] Running load balancer k3s-agent-load-balancer 127.0.0.1:6444 -> [127.0.0.1:6443] [default: 127.0.0.1:6443]
INFO[0002] Password verified locally for node etcd-test 
INFO[0002] certificate CN=etcd-test signed by CN=k3s-server-ca@1706283004: notBefore=2024-01-26 15:30:04 +0000 UTC notAfter=2025-01-25 15:30:06 +0000 UTC
INFO[0002] certificate CN=system:node:etcd-test,O=system:nodes signed by CN=k3s-client-ca@1706283004: notBefore=2024-01-26 15:30:04 +0000 UTC notAfter=2025-01-25 15:30:07 +0000 UTC 
{"level":"info","ts":"2024-01-26T15:30:08.088569Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"fd8a1f8b889e2f52 is starting a new election at term 1"}
{"level":"info","ts":"2024-01-26T15:30:08.088623Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"fd8a1f8b889e2f52 became pre-candidate at term 1"}
{"level":"info","ts":"2024-01-26T15:30:08.088728Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"fd8a1f8b889e2f52 received MsgPreVoteResp from fd8a1f8b889e2f52 at term 1"}{"level":"info","ts":"2024-01-26T15:30:08.088745Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"fd8a1f8b889e2f52 became candidate at term 2"}
{"level":"info","ts":"2024-01-26T15:30:08.088755Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"fd8a1f8b889e2f52 received MsgVoteResp from fd8a1f8b889e2f52 at term 2"}   
{"level":"info","ts":"2024-01-26T15:30:08.088772Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"fd8a1f8b889e2f52 became leader at term 2"}
{"level":"info","ts":"2024-01-26T15:30:08.088784Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"raft.node: fd8a1f8b889e2f52 elected leader fd8a1f8b889e2f52 at term 2"}   
{"level":"info","ts":"2024-01-26T15:30:08.094762Z","caller":"etcdserver/server.go:2573","msg":"setting up initial cluster version using v2 API","cluster-version":"3.5"}
{"level":"info","ts":"2024-01-26T15:30:08.100093Z","caller":"membership/cluster.go:584","msg":"set initial cluster version","cluster-id":"8ccd0f608323fe0a","local-member-id":"fd8a1f8b889e2f52","cluster-version":"3.5"}
{"level":"info","ts":"2024-01-26T15:30:08.100173Z","caller":"api/capability.go:75","msg":"enabled capabilities for version","cluster-version":"3.5"}
{"level":"info","ts":"2024-01-26T15:30:08.100232Z","caller":"etcdserver/server.go:2597","msg":"cluster version is updated","cluster-version":"3.5"}
{"level":"info","ts":"2024-01-26T15:30:08.100273Z","caller":"etcdserver/server.go:2064","msg":"published local member to cluster through raft","local-member-id":"fd8a1f8b889e2f52","local-member-attributes":"{Name:etcd-test-d08e21bb ClientURLs:[https://127.0.0.1:2379]}","request-path":"/0/members/fd8a1f8b889e2f52/attributes","cluster-id":"8ccd0f608323fe0a","publish-timeout":"15s"}
{"level":"info","ts":"2024-01-26T15:30:08.100296Z","caller":"embed/serve.go:103","msg":"ready to serve client requests"}
{"level":"info","ts":"2024-01-26T15:30:08.100466Z","caller":"embed/serve.go:103","msg":"ready to serve client requests"}
{"level":"info","ts":"2024-01-26T15:30:08.10098Z","caller":"embed/serve.go:250","msg":"serving client traffic securely","traffic":"http","address":"127.0.0.1:2382"}
{"level":"info","ts":"2024-01-26T15:30:08.1017Z","caller":"embed/serve.go:250","msg":"serving client traffic securely","traffic":"grpc","address":"127.0.0.1:2379"}
INFO[0003] Defragmenting etcd database
{"level":"info","ts":"2024-01-26T15:30:08.113321Z","caller":"v3rpc/maintenance.go:90","msg":"starting defragment"}
{"level":"info","ts":"2024-01-26T15:30:08.125145Z","caller":"backend/backend.go:497","msg":"defragmenting","path":"/var/lib/rancher/k3s/server/db/etcd/member/snap/db","current-db-size-bytes":32198656,"current-db-size":"32 MB","current-db-size-in-use-bytes":15007744,"current-db-size-in-use":"15 MB"}
{"level":"info","ts":"2024-01-26T15:30:08.292022Z","caller":"backend/backend.go:549","msg":"finished defragmenting directory","path":"/var/lib/rancher/k3s/server/db/etcd/member/snap/db","current-db-size-bytes-diff":-18223104,"current-db-size-bytes":13975552,"current-db-size":"14 MB","current-db-size-in-use-bytes-diff":-1040384,"current-db-size-in-use-bytes":13967360,"current-db-size-in-use":"14 MB","took":"178.532588ms"}
{"level":"info","ts":"2024-01-26T15:30:08.292266Z","caller":"v3rpc/maintenance.go:96","msg":"finished defragment"}
INFO[0004] etcd data store connection OK
INFO[0004] Waiting for API server to become available
INFO[0004] Saving cluster bootstrap data to datastore
INFO[0004] ETCD server is now running
INFO[0004] k3s is up and running
WARN[0004] Bootstrap key already exists
INFO[0008] Defragmenting etcd database
{"level":"info","ts":"2024-01-26T15:30:12.494563Z","caller":"v3rpc/maintenance.go:90","msg":"starting defragment"}
{"level":"info","ts":"2024-01-26T15:30:12.505505Z","caller":"backend/backend.go:497","msg":"defragmenting","path":"/var/lib/rancher/k3s/server/db/etcd/member/snap/db","current-db-size-bytes":13975552,"current-db-size":"14 MB","current-db-size-in-use-bytes":13967360,"current-db-size-in-use":"14 MB"}
{"level":"info","ts":"2024-01-26T15:30:12.659629Z","caller":"backend/backend.go:549","msg":"finished defragmenting directory","path":"/var/lib/rancher/k3s/server/db/etcd/member/snap/db","current-db-size-bytes-diff":0,"current-db-size-bytes":13975552,"current-db-size":"14 MB","current-db-size-in-use-bytes-diff":0,"current-db-size-in-use-bytes":13967360,"current-db-size-in-use":"14 MB","took":"165.020408ms"}
{"level":"info","ts":"2024-01-26T15:30:12.659713Z","caller":"v3rpc/maintenance.go:96","msg":"finished defragment"}
INFO[0008] Reconciling bootstrap data between datastore and disk 
WARN[0008] Unable to lookup path to reconcile EncryptionHash
WARN[0008] Unable to lookup path to reconcile EncryptionConfig
INFO[0008] Cluster reset: backing up certificates directory to /var/lib/rancher/k3s/server/tls-1706283012
WARN[0008] Updating bootstrap data on disk from datastore
INFO[0008] certificate CN=system:admin,O=system:masters signed by CN=k3s-client-ca@1706012434: notBefore=2024-01-23 12:20:34 +0000 UTC notAfter=2025-01-25 15:30:12 +0000 UTC 
INFO[0008] certificate CN=system:k3s-supervisor,O=system:masters signed by CN=k3s-client-ca@1706012434: notBefore=2024-01-23 12:20:34 +0000 UTC notAfter=2025-01-25 15:30:12 +0000 UTC   
INFO[0008] certificate CN=system:kube-controller-manager signed by CN=k3s-client-ca@1706012434: notBefore=2024-01-23 12:20:34 +0000 UTC notAfter=2025-01-25 15:30:12 +0000 UTC
INFO[0008] certificate CN=system:kube-scheduler signed by CN=k3s-client-ca@1706012434: notBefore=2024-01-23 12:20:34 +0000 UTC notAfter=2025-01-25 15:30:12 +0000 UTC
INFO[0008] certificate CN=system:apiserver,O=system:masters signed by CN=k3s-client-ca@1706012434: notBefore=2024-01-23 12:20:34 +0000 UTC notAfter=2025-01-25 15:30:12 +0000 UTC        
INFO[0008] certificate CN=system:kube-proxy signed by CN=k3s-client-ca@1706012434: notBefore=2024-01-23 12:20:34 +0000 UTC notAfter=2025-01-25 15:30:12 +0000 UTC 
INFO[0008] certificate CN=system:k3s-controller signed by CN=k3s-client-ca@1706012434: notBefore=2024-01-23 12:20:34 +0000 UTC notAfter=2025-01-25 15:30:12 +0000 UTC
INFO[0008] certificate CN=k3s-cloud-controller-manager signed by CN=k3s-client-ca@1706012434: notBefore=2024-01-23 12:20:34 +0000 UTC notAfter=2025-01-25 15:30:12 +0000 UTC
INFO[0008] certificate CN=kube-apiserver signed by CN=k3s-server-ca@1706012434: notBefore=2024-01-23 12:20:34 +0000 UTC notAfter=2025-01-25 15:30:12 +0000 UTC
INFO[0008] certificate CN=system:auth-proxy signed by CN=k3s-request-header-ca@1706012434: notBefore=2024-01-23 12:20:34 +0000 UTC notAfter=2025-01-25 15:30:12 +0000 UTC
INFO[0008] certificate CN=etcd-client signed by CN=etcd-server-ca@1706012434: notBefore=2024-01-23 12:20:34 +0000 UTC notAfter=2025-01-25 15:30:12 +0000 UTC
INFO[0008] certificate CN=etcd-peer signed by CN=etcd-peer-ca@1706012434: notBefore=2024-01-23 12:20:34 +0000 UTC notAfter=2025-01-25 15:30:12 +0000 UTC
INFO[0008] certificate CN=etcd-server signed by CN=etcd-server-ca@1706012434: notBefore=2024-01-23 12:20:34 +0000 UTC notAfter=2025-01-25 15:30:12 +0000 UTC
INFO[0008] stopping etcd
{"level":"info","ts":"2024-01-26T15:30:12.69782Z","caller":"embed/etcd.go:376","msg":"closing etcd server","name":"etcd-test-d08e21bb","data-dir":"/var/lib/rancher/k3s/server/db/etcd","advertise-peer-urls":["https://10.1.0.4:2380"],"advertise-client-urls":["https://127.0.0.1:2379"]}
{"level":"info","ts":"2024-01-26T15:30:12.698673Z","caller":"etcdserver/server.go:1465","msg":"skipped leadership transfer for single voting member cluster","local-member-id":"fd8a1f8b889e2f52","current-leader-member-id":"fd8a1f8b889e2f52"}
{"level":"info","ts":"2024-01-26T15:30:12.721379Z","caller":"embed/etcd.go:579","msg":"stopping serving peer traffic","address":"127.0.0.1:2380"}
{"level":"info","ts":"2024-01-26T15:30:12.721667Z","caller":"embed/etcd.go:584","msg":"stopped serving peer traffic","address":"127.0.0.1:2380"}
{"level":"info","ts":"2024-01-26T15:30:12.721695Z","caller":"embed/etcd.go:378","msg":"closed etcd server","name":"etcd-test-d08e21bb","data-dir":"/var/lib/rancher/k3s/server/db/etcd","advertise-peer-urls":["https://10.1.0.4:2380"],"advertise-client-urls":["https://127.0.0.1:2379"]}
INFO[0013] Managed etcd cluster membership has been reset, restart without --cluster-reset flag now. Backup and delete ${datadir}/server/db on each peer etcd server and rejoin the nodes

Expected behavior:
Expecting to see the cluster up and running

Actual behavior:
K3s doesnt start.
When i restart my k3s i get the following error

root@etcd-test:~# systemctl restart k3s
Job for k3s.service failed because the control process exited with error code.
See "systemctl status k3s.service" and "journalctl -xeu k3s.service" for details.
root@etcd-test:~# k3s server
INFO[0000] Starting k3s v1.28.5+k3s1 (5b2d1271)
INFO[0000] Managed etcd cluster bootstrap already complete and initialized 
INFO[0000] Starting temporary etcd to reconcile with datastore
{"level":"info","ts":"2024-01-26T15:32:00.968426Z","caller":"embed/etcd.go:127","msg":"configuring peer listeners","listen-peer-urls":["http://127.0.0.1:2400"]}
{"level":"info","ts":"2024-01-26T15:32:00.968611Z","caller":"embed/etcd.go:135","msg":"configuring client listeners","listen-client-urls":["http://127.0.0.1:2399"]}
{"level":"info","ts":"2024-01-26T15:32:00.968731Z","caller":"embed/etcd.go:309","msg":"starting an etcd server","etcd-version":"3.5.9","git-sha":"Not provided (use ./build instead of go build)","go-version":"go1.20.12","go-os":"linux","go-arch":"amd64","max-cpu-set":2,"max-cpu-available":2,"member-initialized":true,"name":"etcd-test-d08e21bb","data-dir":"/var/lib/rancher/k3s/server/db/etcd-tmp","wal-dir":"","wal-dir-dedicated":"","member-dir":"/var/lib/rancher/k3s/server/db/etcd-tmp/member","force-new-cluster":true,"heartbeat-interval":"500ms","election-timeout":"5s","initial-election-tick-advance":true,"snapshot-count":10000,"max-wals":0,"max-snapshots":0,"snapshot-catchup-entries":5000,"initial-advertise-peer-urls":["http://127.0.0.1:2400"],"listen-peer-urls":["http://127.0.0.1:2400"],"advertise-client-urls":["http://127.0.0.1:2399"],"listen-client-urls":["http://127.0.0.1:2399"],"listen-metrics-urls":[],"cors":["*"],"host-whitelist":["*"],"initial-cluster":"","initial-cluster-state":"new","initial-cluster-token":"","quota-backend-bytes":2147483648,"max-request-bytes":1572864,"max-concurrent-streams":4294967295,"pre-vote":true,"initial-corrupt-check":true,"corrupt-check-time-interval":"0s","compact-check-time-enabled":false,"compact-check-time-interval":"1m0s","auto-compaction-mode":"","auto-compaction-retention":"0s","auto-compaction-interval":"0s","discovery-url":"","discovery-proxy":"","downgrade-check-interval":"5s"}
{"level":"info","ts":"2024-01-26T15:32:00.97279Z","caller":"etcdserver/backend.go:81","msg":"opened backend db","path":"/var/lib/rancher/k3s/server/db/etcd-tmp/member/snap/db","took":"3.838639ms"}
{"level":"info","ts":"2024-01-26T15:32:00.973305Z","caller":"etcdserver/server.go:509","msg":"recovered v2 store from snapshot","snapshot-index":1,"snapshot-size":"6.5 kB"}
{"level":"info","ts":"2024-01-26T15:32:00.973344Z","caller":"etcdserver/server.go:522","msg":"recovered v3 backend from snapshot","backend-size-bytes":13991936,"backend-size":"14 MB","backend-size-in-use-bytes":13971456,"backend-size-in-use":"14 MB"}
{"level":"info","ts":"2024-01-26T15:32:00.982006Z","caller":"etcdserver/raft.go:603","msg":"forcing restart member","cluster-id":"8ccd0f608323fe0a","local-member-id":"fd8a1f8b889e2f52","commit-index":8}
{"level":"info","ts":"2024-01-26T15:32:00.982066Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"fd8a1f8b889e2f52 switched to configuration voters=(18269449522534821714)"}{"level":"info","ts":"2024-01-26T15:32:00.982096Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"fd8a1f8b889e2f52 became follower at term 2"}
{"level":"info","ts":"2024-01-26T15:32:00.98211Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"newRaft fd8a1f8b889e2f52 [peers: [fd8a1f8b889e2f52], term: 2, commit: 8, applied: 1, lastindex: 8, lastterm: 2]"}
{"level":"info","ts":"2024-01-26T15:32:00.982193Z","caller":"membership/cluster.go:278","msg":"recovered/added member from store","cluster-id":"8ccd0f608323fe0a","local-member-id":"fd8a1f8b889e2f52","recovered-remote-peer-id":"fd8a1f8b889e2f52","recovered-remote-peer-urls":["https://10.1.0.4:2380"]}
{"level":"warn","ts":"2024-01-26T15:32:01.367785Z","caller":"auth/store.go:1238","msg":"simple token is not cryptographically signed"}
{"level":"info","ts":"2024-01-26T15:32:01.375309Z","caller":"mvcc/kvstore.go:323","msg":"restored last compact revision","meta-bucket-name":"meta","meta-bucket-name-key":"finishedCompactRev","restored-compact-revision":189859}
{"level":"info","ts":"2024-01-26T15:32:01.394318Z","caller":"mvcc/kvstore.go:393","msg":"kvstore restored","current-rev":193364}
{"level":"info","ts":"2024-01-26T15:32:01.39889Z","caller":"etcdserver/quota.go:94","msg":"enabled backend quota with default value","quota-name":"v3-applier","quota-size-bytes":2147483648,"quota-size":"2.1 GB"}
{"level":"info","ts":"2024-01-26T15:32:01.403974Z","caller":"etcdserver/corrupt.go:95","msg":"starting initial corruption check","local-member-id":"fd8a1f8b889e2f52","timeout":"15s"}   
{"level":"info","ts":"2024-01-26T15:32:01.406725Z","caller":"etcdserver/corrupt.go:165","msg":"initial corruption checking passed; no corruption","local-member-id":"fd8a1f8b889e2f52"}  
{"level":"info","ts":"2024-01-26T15:32:01.406766Z","caller":"etcdserver/server.go:854","msg":"starting etcd server","local-member-id":"fd8a1f8b889e2f52","local-server-version":"3.5.9","cluster-version":"to_be_decided"}
{"level":"info","ts":"2024-01-26T15:32:01.407002Z","caller":"etcdserver/server.go:738","msg":"started as single-node; fast-forwarding election ticks","local-member-id":"fd8a1f8b889e2f52","forward-ticks":9,"forward-duration":"4.5s","election-ticks":10,"election-timeout":"5s"}
{"level":"info","ts":"2024-01-26T15:32:01.407283Z","caller":"membership/cluster.go:584","msg":"set initial cluster version","cluster-id":"8ccd0f608323fe0a","local-member-id":"fd8a1f8b889e2f52","cluster-version":"3.5"}
{"level":"info","ts":"2024-01-26T15:32:01.407404Z","caller":"api/capability.go:75","msg":"enabled capabilities for version","cluster-version":"3.5"}
{"level":"info","ts":"2024-01-26T15:32:01.408346Z","caller":"embed/etcd.go:278","msg":"now serving peer/client/metrics","local-member-id":"fd8a1f8b889e2f52","initial-advertise-peer-urls":["http://127.0.0.1:2400"],"listen-peer-urls":["http://127.0.0.1:2400"],"advertise-client-urls":["http://127.0.0.1:2399"],"listen-client-urls":["http://127.0.0.1:2399"],"listen-metrics-urls":[]}
{"level":"info","ts":"2024-01-26T15:32:01.408497Z","caller":"embed/etcd.go:597","msg":"serving peer traffic","address":"127.0.0.1:2400"}
{"level":"info","ts":"2024-01-26T15:32:01.408515Z","caller":"embed/etcd.go:569","msg":"cmux::serve","address":"127.0.0.1:2400"}
{"level":"info","ts":"2024-01-26T15:32:05.48324Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"fd8a1f8b889e2f52 is starting a new election at term 2"}
{"level":"info","ts":"2024-01-26T15:32:05.48329Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"fd8a1f8b889e2f52 became pre-candidate at term 2"}
{"level":"info","ts":"2024-01-26T15:32:05.483349Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"fd8a1f8b889e2f52 received MsgPreVoteResp from fd8a1f8b889e2f52 at term 2"}{"level":"info","ts":"2024-01-26T15:32:05.483366Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"fd8a1f8b889e2f52 became candidate at term 3"}
{"level":"info","ts":"2024-01-26T15:32:05.483374Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"fd8a1f8b889e2f52 received MsgVoteResp from fd8a1f8b889e2f52 at term 3"}   
{"level":"info","ts":"2024-01-26T15:32:05.483386Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"fd8a1f8b889e2f52 became leader at term 3"}
{"level":"info","ts":"2024-01-26T15:32:05.483396Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"raft.node: fd8a1f8b889e2f52 elected leader fd8a1f8b889e2f52 at term 3"}   
{"level":"info","ts":"2024-01-26T15:32:05.496393Z","caller":"etcdserver/server.go:2064","msg":"published local member to cluster through raft","local-member-id":"fd8a1f8b889e2f52","local-member-attributes":"{Name:etcd-test-d08e21bb ClientURLs:[http://127.0.0.1:2399]}","request-path":"/0/members/fd8a1f8b889e2f52/attributes","cluster-id":"8ccd0f608323fe0a","publish-timeout":"15s"}
{"level":"info","ts":"2024-01-26T15:32:05.496443Z","caller":"embed/serve.go:103","msg":"ready to serve client requests"}
{"level":"info","ts":"2024-01-26T15:32:05.496602Z","caller":"embed/serve.go:103","msg":"ready to serve client requests"}
{"level":"info","ts":"2024-01-26T15:32:05.496778Z","caller":"embed/serve.go:187","msg":"serving client traffic insecurely; this is strongly discouraged!","traffic":"http","address":"127.0.0.1:2402"}
{"level":"info","ts":"2024-01-26T15:32:05.497367Z","caller":"embed/serve.go:187","msg":"serving client traffic insecurely; this is strongly discouraged!","traffic":"grpc","address":"127.0.0.1:2399"}
INFO[0004] Defragmenting etcd database
{"level":"info","ts":"2024-01-26T15:32:05.499959Z","caller":"v3rpc/maintenance.go:90","msg":"starting defragment"}
{"level":"info","ts":"2024-01-26T15:32:05.511941Z","caller":"backend/backend.go:497","msg":"defragmenting","path":"/var/lib/rancher/k3s/server/db/etcd-tmp/member/snap/db","current-db-size-bytes":13991936,"current-db-size":"14 MB","current-db-size-in-use-bytes":13975552,"current-db-size-in-use":"14 MB"}
{"level":"info","ts":"2024-01-26T15:32:05.671388Z","caller":"backend/backend.go:549","msg":"finished defragmenting directory","path":"/var/lib/rancher/k3s/server/db/etcd-tmp/member/snap/db","current-db-size-bytes-diff":-12288,"current-db-size-bytes":13979648,"current-db-size":"14 MB","current-db-size-in-use-bytes-diff":-4096,"current-db-size-in-use-bytes":13971456,"current-db-size-in-use":"14 MB","took":"171.389764ms"}
{"level":"info","ts":"2024-01-26T15:32:05.671451Z","caller":"v3rpc/maintenance.go:96","msg":"finished defragment"}
INFO[0004] etcd temporary data store connection OK      
INFO[0004] Reconciling bootstrap data between datastore and disk
WARN[0004] Unable to lookup path to reconcile EncryptionConfig
WARN[0004] Unable to lookup path to reconcile EncryptionHash
FATA[0004] /var/lib/rancher/k3s/server/cred/passwd newer than datastore and could cause a cluster outage. Remove the file(s) from disk and restart to be recreated from datastore. 
k3s
@dereknola
Copy link
Member

Please follow the directions given in the docs. You created a new cluster with your Step 1, then stopped it, and did not clean up with the k3s-killall.sh. Then in Step 3 you included both --cluster-init --cluster-reset, you should only have cluster-reset. Resets are 2 step startup process, you prepare the cluster with the cluster-reset flag and then start the cluster normally afterwards with --cluster-init + regular args.

@GayathriBandaru94
Copy link
Author

GayathriBandaru94 commented Jan 27, 2024

Hello @dereknola @brandond

i have tried and followed the steps you mentioned and I am still getting the same error
Also I get the same error with encryption-config.json and encryption-state.json as well

@caroline-suse-rancher caroline-suse-rancher moved this from New to In Triage in K3s Development Feb 5, 2024
Copy link
Contributor

This repository uses a bot to automatically label issues which have not had any activity (commit/comment/label) for 45 days. This helps us manage the community issues better. If the issue is still relevant, please add a comment to the issue so the bot can remove the label and we know it is still valid. If it is no longer relevant (or possibly fixed in the latest release), the bot will automatically close the issue in 14 days. Thank you for your contributions.

@github-actions github-actions bot closed this as not planned Won't fix, can't repro, duplicate, stale Mar 31, 2024
@github-project-automation github-project-automation bot moved this from In Triage to Done Issue in K3s Development Mar 31, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
Archived in project
Development

No branches or pull requests

2 participants