aganesh-suse
commented
10 months ago Validated on release-1.25 branch with version v1.25.15-rc2+k3s1
Environment Details
Infrastructure
- [x] Cloud
- [ ] Hosted
Node(s) CPU architecture, OS, and Version:
$ cat /etc/os-release
PRETTY_NAME="Ubuntu 22.04.2 LTS"
$ uname -m
x86_64Cluster Configuration:
HA: 3 server/ 1 agentConfig.yaml:
token: xxxx
cluster-init: true
write-kubeconfig-mode: "0644"
node-external-ip: 1.1.1.1
node-label:
- k3s-upgrade=serverTesting Steps
- Copy config.yaml
$ sudo mkdir -p /etc/rancher/k3s && sudo cp config.yaml /etc/rancher/k3s - Install k3s
curl -sfL https://get.k3s.io | sudo INSTALL_K3S_VERSION='v1.25.15-rc2+k3s1' sh -s - server - Verify Cluster Status:
kubectl get nodes -o wide kubectl get pods -A - Apply some workloads
- Save etcd snapshot:
sudo k3s etcd-snapshot save --s3 --s3-bucket=xxxx --s3-folder=xxxx --s3-region=xxxx --s3-access-key=xxxx --s3-secret-key="xxxx" - Kill servers 2 and 3:
sudo k3s-killall.sh - Stop k3s server on server1
sudo systemctl stop k3s - Run cluster reset from s3 snapshot saved:
sudo k3s server --cluster-reset --etcd-s3 --cluster-reset-restore-path=on-demand-ip-1-1-1-1-1698343463 --etcd-s3-bucket=xxxx --etcd-s3-folder=xxxx --etcd-s3-region=xxxx --etcd-s3-access-key=xxxx --etcd-s3-secret-key="xxxx" --token=xxxx - Start k3s services on servers 1, 2 and 3:
sudo systemctl start k3s - Make sure all pods/services are running as expected in the k3s cluster - including the workloads stored in the snapshot
kubectl get nodes -o wide kubectl get pods -A
Validation Results:
- k3s version used for validation:
$ k3s -v k3s version v1.25.15-rc2+k3s1 (d19260dc) go version go1.20.10
Cluster reset with s3 snapshot result:
$ sudo k3s server --cluster-reset --etcd-s3 --cluster-reset-restore-path=on-demand-ip-4-4-4-4-1698514340 --etcd-s3-bucket=xxxx --etcd-s3-folder=xxxx --etcd-s3-region=xxxx --etcd-s3-access-key=xxxx --etcd-s3-secret-key="xxxx" --token=xxxx --debug 2>&1 | tee -a /home/ubuntu/cluster_reset_output-9045
time="2023-10-28T22:17:51Z" level=warning msg="remove /var/lib/rancher/k3s/agent/etc/k3s-agent-load-balancer.json: no such file or directory"
time="2023-10-28T22:17:51Z" level=warning msg="remove /var/lib/rancher/k3s/agent/etc/k3s-api-server-agent-load-balancer.json: no such file or directory"
time="2023-10-28T22:17:51Z" level=info msg="Starting k3s v1.25.15-rc2+k3s1 (d19260dc)"
time="2023-10-28T22:17:51Z" level=info msg="Managed etcd cluster bootstrap already complete and initialized"
time="2023-10-28T22:17:51Z" level=info msg="Starting temporary etcd to reconcile with datastore"
{"level":"info","ts":"2023-10-28T22:17:52.032Z","caller":"embed/etcd.go:131","msg":"configuring peer listeners","listen-peer-urls":["http://127.0.0.1:2400"]}
{"level":"info","ts":"2023-10-28T22:17:52.032Z","caller":"embed/etcd.go:139","msg":"configuring client listeners","listen-client-urls":["http://127.0.0.1:2399"]}
{"level":"info","ts":"2023-10-28T22:17:52.032Z","caller":"embed/etcd.go:308","msg":"starting an etcd server","etcd-version":"3.5.3","git-sha":"Not provided (use ./build instead of go build)","go-version":"go1.20.10","go-os":"linux","go-arch":"amd64","max-cpu-set":2,"max-cpu-available":2,"member-initialized":true,"name":"ip-4-4-4-4-0c50be92","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,"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-size-bytes":2147483648,"pre-vote":true,"initial-corrupt-check":true,"corrupt-check-time-interval":"0s","auto-compaction-mode":"","auto-compaction-retention":"0s","auto-compaction-interval":"0s","discovery-url":"","discovery-proxy":"","downgrade-check-interval":"5s"}
{"level":"info","ts":"2023-10-28T22:17:52.034Z","caller":"etcdserver/backend.go:81","msg":"opened backend db","path":"/var/lib/rancher/k3s/server/db/etcd-tmp/member/snap/db","took":"2.098035ms"}
{"level":"info","ts":"2023-10-28T22:17:52.052Z","caller":"etcdserver/server.go:529","msg":"No snapshot found. Recovering WAL from scratch!"}
{"level":"info","ts":"2023-10-28T22:17:52.088Z","caller":"etcdserver/raft.go:526","msg":"discarding uncommitted WAL entries","entry-index":2761,"commit-index-from-wal":2760,"number-of-discarded-entries":4}
{"level":"info","ts":"2023-10-28T22:17:52.098Z","caller":"etcdserver/raft.go:556","msg":"forcing restart member","cluster-id":"bcbdcaabf4d4714c","local-member-id":"a8142d3343e761f","commit-index":2762}
{"level":"info","ts":"2023-10-28T22:17:52.098Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"a8142d3343e761f switched to configuration voters=()"}
{"level":"info","ts":"2023-10-28T22:17:52.098Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"a8142d3343e761f became follower at term 3"}
{"level":"info","ts":"2023-10-28T22:17:52.098Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"newRaft a8142d3343e761f [peers: [], term: 3, commit: 2762, applied: 0, lastindex: 2762, lastterm: 3]"}
{"level":"warn","ts":"2023-10-28T22:17:52.135Z","caller":"auth/store.go:1220","msg":"simple token is not cryptographically signed"}
{"level":"info","ts":"2023-10-28T22:17:52.148Z","caller":"mvcc/kvstore.go:415","msg":"kvstore restored","current-rev":2522}
{"level":"info","ts":"2023-10-28T22:17:52.150Z","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":"2023-10-28T22:17:52.152Z","caller":"etcdserver/corrupt.go:46","msg":"starting initial corruption check","local-member-id":"a8142d3343e761f","timeout":"15s"}
{"level":"info","ts":"2023-10-28T22:17:52.153Z","caller":"etcdserver/corrupt.go:116","msg":"initial corruption checking passed; no corruption","local-member-id":"a8142d3343e761f"}
{"level":"info","ts":"2023-10-28T22:17:52.153Z","caller":"etcdserver/server.go:851","msg":"starting etcd server","local-member-id":"a8142d3343e761f","local-server-version":"3.5.3","cluster-version":"to_be_decided"}
{"level":"info","ts":"2023-10-28T22:17:52.153Z","caller":"etcdserver/server.go:752","msg":"starting initial election tick advance","election-ticks":10}
{"level":"info","ts":"2023-10-28T22:17:52.153Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"a8142d3343e761f switched to configuration voters=(756959687256995359)"}
{"level":"info","ts":"2023-10-28T22:17:52.153Z","caller":"membership/cluster.go:421","msg":"added member","cluster-id":"bcbdcaabf4d4714c","local-member-id":"a8142d3343e761f","added-peer-id":"a8142d3343e761f","added-peer-peer-urls":["https://172.31.28.17:2380"]}
{"level":"info","ts":"2023-10-28T22:17:52.154Z","caller":"membership/cluster.go:584","msg":"set initial cluster version","cluster-id":"bcbdcaabf4d4714c","local-member-id":"a8142d3343e761f","cluster-version":"3.5"}
{"level":"info","ts":"2023-10-28T22:17:52.154Z","caller":"api/capability.go:75","msg":"enabled capabilities for version","cluster-version":"3.5"}
{"level":"info","ts":"2023-10-28T22:17:52.157Z","caller":"embed/etcd.go:277","msg":"now serving peer/client/metrics","local-member-id":"a8142d3343e761f","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":"2023-10-28T22:17:52.158Z","caller":"embed/etcd.go:581","msg":"serving peer traffic","address":"127.0.0.1:2400"}
{"level":"info","ts":"2023-10-28T22:17:52.158Z","caller":"embed/etcd.go:553","msg":"cmux::serve","address":"127.0.0.1:2400"}
{"level":"info","ts":"2023-10-28T22:17:52.158Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"a8142d3343e761f switched to configuration voters=(756959687256995359) learners=(16006540867300871525)"}
{"level":"info","ts":"2023-10-28T22:17:52.158Z","caller":"membership/cluster.go:421","msg":"added member","cluster-id":"bcbdcaabf4d4714c","local-member-id":"a8142d3343e761f","added-peer-id":"de22a81cce3dcd65","added-peer-peer-urls":["https://1.1.2.2:2380"]}
{"level":"info","ts":"2023-10-28T22:17:52.158Z","caller":"rafthttp/peer.go:133","msg":"starting remote peer","remote-peer-id":"de22a81cce3dcd65"}
{"level":"info","ts":"2023-10-28T22:17:52.158Z","caller":"rafthttp/pipeline.go:72","msg":"started HTTP pipelining with remote peer","local-member-id":"a8142d3343e761f","remote-peer-id":"de22a81cce3dcd65"}
{"level":"info","ts":"2023-10-28T22:17:52.159Z","caller":"rafthttp/stream.go:169","msg":"started stream writer with remote peer","local-member-id":"a8142d3343e761f","remote-peer-id":"de22a81cce3dcd65"}
{"level":"info","ts":"2023-10-28T22:17:52.159Z","caller":"rafthttp/stream.go:169","msg":"started stream writer with remote peer","local-member-id":"a8142d3343e761f","remote-peer-id":"de22a81cce3dcd65"}
{"level":"info","ts":"2023-10-28T22:17:52.159Z","caller":"rafthttp/peer.go:137","msg":"started remote peer","remote-peer-id":"de22a81cce3dcd65"}
{"level":"info","ts":"2023-10-28T22:17:52.159Z","caller":"rafthttp/stream.go:395","msg":"started stream reader with remote peer","stream-reader-type":"stream MsgApp v2","local-member-id":"a8142d3343e761f","remote-peer-id":"de22a81cce3dcd65"}
{"level":"info","ts":"2023-10-28T22:17:52.159Z","caller":"rafthttp/transport.go:317","msg":"added remote peer","local-member-id":"a8142d3343e761f","remote-peer-id":"de22a81cce3dcd65","remote-peer-urls":["https://1.1.2.2:2380"]}
{"level":"info","ts":"2023-10-28T22:17:52.159Z","caller":"rafthttp/stream.go:395","msg":"started stream reader with remote peer","stream-reader-type":"stream Message","local-member-id":"a8142d3343e761f","remote-peer-id":"de22a81cce3dcd65"}
{"level":"info","ts":"2023-10-28T22:17:52.160Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"a8142d3343e761f switched to configuration voters=(756959687256995359 16006540867300871525)"}
{"level":"info","ts":"2023-10-28T22:17:52.160Z","caller":"membership/cluster.go:535","msg":"promote member","cluster-id":"bcbdcaabf4d4714c","local-member-id":"a8142d3343e761f"}
{"level":"info","ts":"2023-10-28T22:17:52.163Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"a8142d3343e761f switched to configuration voters=(756959687256995359 16006540867300871525) learners=(6784854868961235750)"}
{"level":"info","ts":"2023-10-28T22:17:52.163Z","caller":"membership/cluster.go:421","msg":"added member","cluster-id":"bcbdcaabf4d4714c","local-member-id":"a8142d3343e761f","added-peer-id":"5e28a58e3d039326","added-peer-peer-urls":["https://3.3.4.4:2380"]}
{"level":"info","ts":"2023-10-28T22:17:52.163Z","caller":"rafthttp/peer.go:133","msg":"starting remote peer","remote-peer-id":"5e28a58e3d039326"}
{"level":"info","ts":"2023-10-28T22:17:52.163Z","caller":"rafthttp/pipeline.go:72","msg":"started HTTP pipelining with remote peer","local-member-id":"a8142d3343e761f","remote-peer-id":"5e28a58e3d039326"}
{"level":"info","ts":"2023-10-28T22:17:52.163Z","caller":"rafthttp/stream.go:169","msg":"started stream writer with remote peer","local-member-id":"a8142d3343e761f","remote-peer-id":"5e28a58e3d039326"}
{"level":"info","ts":"2023-10-28T22:17:52.163Z","caller":"rafthttp/peer.go:137","msg":"started remote peer","remote-peer-id":"5e28a58e3d039326"}
{"level":"info","ts":"2023-10-28T22:17:52.163Z","caller":"rafthttp/transport.go:317","msg":"added remote peer","local-member-id":"a8142d3343e761f","remote-peer-id":"5e28a58e3d039326","remote-peer-urls":["https://3.3.4.4:2380"]}
{"level":"info","ts":"2023-10-28T22:17:52.163Z","caller":"rafthttp/stream.go:169","msg":"started stream writer with remote peer","local-member-id":"a8142d3343e761f","remote-peer-id":"5e28a58e3d039326"}
{"level":"info","ts":"2023-10-28T22:17:52.163Z","caller":"rafthttp/stream.go:395","msg":"started stream reader with remote peer","stream-reader-type":"stream MsgApp v2","local-member-id":"a8142d3343e761f","remote-peer-id":"5e28a58e3d039326"}
{"level":"info","ts":"2023-10-28T22:17:52.164Z","caller":"rafthttp/stream.go:395","msg":"started stream reader with remote peer","stream-reader-type":"stream Message","local-member-id":"a8142d3343e761f","remote-peer-id":"5e28a58e3d039326"}
{"level":"info","ts":"2023-10-28T22:17:52.165Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"a8142d3343e761f switched to configuration voters=(756959687256995359 6784854868961235750 16006540867300871525)"}
{"level":"info","ts":"2023-10-28T22:17:52.165Z","caller":"membership/cluster.go:535","msg":"promote member","cluster-id":"bcbdcaabf4d4714c","local-member-id":"a8142d3343e761f"}
{"level":"info","ts":"2023-10-28T22:17:52.183Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"a8142d3343e761f switched to configuration voters=(756959687256995359 16006540867300871525)"}
{"level":"info","ts":"2023-10-28T22:17:52.183Z","caller":"membership/cluster.go:472","msg":"removed member","cluster-id":"bcbdcaabf4d4714c","local-member-id":"a8142d3343e761f","removed-remote-peer-id":"5e28a58e3d039326","removed-remote-peer-urls":["https://3.3.4.4:2380"]}
{"level":"info","ts":"2023-10-28T22:17:52.183Z","caller":"rafthttp/peer.go:330","msg":"stopping remote peer","remote-peer-id":"5e28a58e3d039326"}
{"level":"info","ts":"2023-10-28T22:17:52.183Z","caller":"rafthttp/stream.go:294","msg":"stopped TCP streaming connection with remote peer","stream-writer-type":"unknown stream","remote-peer-id":"5e28a58e3d039326"}
{"level":"info","ts":"2023-10-28T22:17:52.183Z","caller":"rafthttp/stream.go:294","msg":"stopped TCP streaming connection with remote peer","stream-writer-type":"unknown stream","remote-peer-id":"5e28a58e3d039326"}
{"level":"info","ts":"2023-10-28T22:17:52.183Z","caller":"rafthttp/pipeline.go:85","msg":"stopped HTTP pipelining with remote peer","local-member-id":"a8142d3343e761f","remote-peer-id":"5e28a58e3d039326"}
{"level":"info","ts":"2023-10-28T22:17:52.183Z","caller":"rafthttp/stream.go:442","msg":"stopped stream reader with remote peer","stream-reader-type":"stream MsgApp v2","local-member-id":"a8142d3343e761f","remote-peer-id":"5e28a58e3d039326"}
{"level":"info","ts":"2023-10-28T22:17:52.183Z","caller":"rafthttp/stream.go:442","msg":"stopped stream reader with remote peer","stream-reader-type":"stream Message","local-member-id":"a8142d3343e761f","remote-peer-id":"5e28a58e3d039326"}
{"level":"info","ts":"2023-10-28T22:17:52.183Z","caller":"rafthttp/peer.go:335","msg":"stopped remote peer","remote-peer-id":"5e28a58e3d039326"}
{"level":"info","ts":"2023-10-28T22:17:52.183Z","caller":"rafthttp/transport.go:355","msg":"removed remote peer","local-member-id":"a8142d3343e761f","removed-remote-peer-id":"5e28a58e3d039326"}
{"level":"info","ts":"2023-10-28T22:17:52.183Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"a8142d3343e761f switched to configuration voters=(756959687256995359)"}
{"level":"info","ts":"2023-10-28T22:17:52.183Z","caller":"membership/cluster.go:472","msg":"removed member","cluster-id":"bcbdcaabf4d4714c","local-member-id":"a8142d3343e761f","removed-remote-peer-id":"de22a81cce3dcd65","removed-remote-peer-urls":["https://1.1.2.2:2380"]}
{"level":"info","ts":"2023-10-28T22:17:52.183Z","caller":"rafthttp/peer.go:330","msg":"stopping remote peer","remote-peer-id":"de22a81cce3dcd65"}
{"level":"info","ts":"2023-10-28T22:17:52.184Z","caller":"rafthttp/stream.go:294","msg":"stopped TCP streaming connection with remote peer","stream-writer-type":"unknown stream","remote-peer-id":"de22a81cce3dcd65"}
{"level":"info","ts":"2023-10-28T22:17:52.184Z","caller":"rafthttp/stream.go:294","msg":"stopped TCP streaming connection with remote peer","stream-writer-type":"unknown stream","remote-peer-id":"de22a81cce3dcd65"}
{"level":"info","ts":"2023-10-28T22:17:52.184Z","caller":"rafthttp/pipeline.go:85","msg":"stopped HTTP pipelining with remote peer","local-member-id":"a8142d3343e761f","remote-peer-id":"de22a81cce3dcd65"}
{"level":"info","ts":"2023-10-28T22:17:52.184Z","caller":"rafthttp/stream.go:442","msg":"stopped stream reader with remote peer","stream-reader-type":"stream MsgApp v2","local-member-id":"a8142d3343e761f","remote-peer-id":"de22a81cce3dcd65"}
{"level":"info","ts":"2023-10-28T22:17:52.184Z","caller":"rafthttp/stream.go:442","msg":"stopped stream reader with remote peer","stream-reader-type":"stream Message","local-member-id":"a8142d3343e761f","remote-peer-id":"de22a81cce3dcd65"}
{"level":"info","ts":"2023-10-28T22:17:52.184Z","caller":"rafthttp/peer.go:335","msg":"stopped remote peer","remote-peer-id":"de22a81cce3dcd65"}
{"level":"info","ts":"2023-10-28T22:17:52.184Z","caller":"rafthttp/transport.go:355","msg":"removed remote peer","local-member-id":"a8142d3343e761f","removed-remote-peer-id":"de22a81cce3dcd65"}
{"level":"info","ts":"2023-10-28T22:18:01.599Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"a8142d3343e761f is starting a new election at term 3"}
{"level":"info","ts":"2023-10-28T22:18:01.599Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"a8142d3343e761f became pre-candidate at term 3"}
{"level":"info","ts":"2023-10-28T22:18:01.599Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"a8142d3343e761f received MsgPreVoteResp from a8142d3343e761f at term 3"}
{"level":"info","ts":"2023-10-28T22:18:01.599Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"a8142d3343e761f became candidate at term 4"}
{"level":"info","ts":"2023-10-28T22:18:01.599Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"a8142d3343e761f received MsgVoteResp from a8142d3343e761f at term 4"}
{"level":"info","ts":"2023-10-28T22:18:01.599Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"a8142d3343e761f became leader at term 4"}
{"level":"info","ts":"2023-10-28T22:18:01.599Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"raft.node: a8142d3343e761f elected leader a8142d3343e761f at term 4"}
{"level":"info","ts":"2023-10-28T22:18:01.600Z","caller":"etcdserver/server.go:2044","msg":"published local member to cluster through raft","local-member-id":"a8142d3343e761f","local-member-attributes":"{Name:ip-4-4-4-4-0c50be92 ClientURLs:[http://127.0.0.1:2399]}","request-path":"/0/members/a8142d3343e761f/attributes","cluster-id":"bcbdcaabf4d4714c","publish-timeout":"15s"}
{"level":"info","ts":"2023-10-28T22:18:01.600Z","caller":"embed/serve.go:98","msg":"ready to serve client requests"}
{"level":"info","ts":"2023-10-28T22:18:01.601Z","caller":"embed/serve.go:140","msg":"serving client traffic insecurely; this is strongly discouraged!","address":"127.0.0.1:2399"}
time="2023-10-28T22:18:01Z" level=info msg="Defragmenting etcd database"
{"level":"info","ts":"2023-10-28T22:18:01.604Z","caller":"v3rpc/maintenance.go:89","msg":"starting defragment"}
{"level":"info","ts":"2023-10-28T22:18:01.608Z","caller":"backend/backend.go:497","msg":"defragmenting","path":"/var/lib/rancher/k3s/server/db/etcd-tmp/member/snap/db","current-db-size-bytes":4718592,"current-db-size":"4.7 MB","current-db-size-in-use-bytes":4706304,"current-db-size-in-use":"4.7 MB"}
{"level":"info","ts":"2023-10-28T22:18:01.715Z","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":-253952,"current-db-size-bytes":4464640,"current-db-size":"4.5 MB","current-db-size-in-use-bytes-diff":-249856,"current-db-size-in-use-bytes":4456448,"current-db-size-in-use":"4.5 MB","took":"109.765703ms"}
{"level":"info","ts":"2023-10-28T22:18:01.715Z","caller":"v3rpc/maintenance.go:95","msg":"finished defragment"}
time="2023-10-28T22:18:01Z" level=info msg="etcd temporary data store connection OK"
time="2023-10-28T22:18:01Z" level=info msg="Reconciling bootstrap data between datastore and disk"
time="2023-10-28T22:18:01Z" level=debug msg="Comparing /bootstrap/2bb80d537b1d to /bootstrap/2bb80d537b1d"
time="2023-10-28T22:18:01Z" level=debug msg="checking bootstrap key /bootstrap/2bb80d537b1d against /bootstrap/2bb80d537b1d"
time="2023-10-28T22:18:01Z" level=debug msg="Reconciling RequestHeaderCAKey at '/var/lib/rancher/k3s/server/tls/request-header-ca.key'"
time="2023-10-28T22:18:01Z" level=debug msg="Reconciling ServerCAKey at '/var/lib/rancher/k3s/server/tls/server-ca.key'"
time="2023-10-28T22:18:01Z" level=debug msg="Reconciling ClientCAKey at '/var/lib/rancher/k3s/server/tls/client-ca.key'"
time="2023-10-28T22:18:01Z" level=debug msg="Reconciling ETCDServerCA at '/var/lib/rancher/k3s/server/tls/etcd/server-ca.crt'"
time="2023-10-28T22:18:01Z" level=debug msg="Reconciling ETCDServerCAKey at '/var/lib/rancher/k3s/server/tls/etcd/server-ca.key'"
time="2023-10-28T22:18:01Z" level=debug msg="Reconciling IPSECKey at '/var/lib/rancher/k3s/server/cred/ipsec.psk'"
time="2023-10-28T22:18:01Z" level=debug msg="Reconciling PasswdFile at '/var/lib/rancher/k3s/server/cred/passwd'"
time="2023-10-28T22:18:01Z" level=debug msg="Reconciling RequestHeaderCA at '/var/lib/rancher/k3s/server/tls/request-header-ca.crt'"
time="2023-10-28T22:18:01Z" level=debug msg="Reconciling ServerCA at '/var/lib/rancher/k3s/server/tls/server-ca.crt'"
time="2023-10-28T22:18:01Z" level=debug msg="Reconciling ServiceKey at '/var/lib/rancher/k3s/server/tls/service.key'"
time="2023-10-28T22:18:01Z" level=debug msg="Reconciling ClientCA at '/var/lib/rancher/k3s/server/tls/client-ca.crt'"
time="2023-10-28T22:18:01Z" level=debug msg="Reconciling ETCDPeerCA at '/var/lib/rancher/k3s/server/tls/etcd/peer-ca.crt'"
time="2023-10-28T22:18:01Z" level=debug msg="Reconciling ETCDPeerCAKey at '/var/lib/rancher/k3s/server/tls/etcd/peer-ca.key'"
time="2023-10-28T22:18:01Z" level=info msg="Cluster reset: backing up certificates directory to /var/lib/rancher/k3s/server/tls-1698531481"
time="2023-10-28T22:18:01Z" level=warning msg="Updating bootstrap data on disk from datastore"
time="2023-10-28T22:18:01Z" level=info msg="stopping etcd"
{"level":"info","ts":"2023-10-28T22:18:01.729Z","caller":"embed/etcd.go:368","msg":"closing etcd server","name":"ip-4-4-4-4-0c50be92","data-dir":"/var/lib/rancher/k3s/server/db/etcd-tmp","advertise-peer-urls":["http://127.0.0.1:2400"],"advertise-client-urls":["http://127.0.0.1:2399"]}
{"level":"info","ts":"2023-10-28T22:18:01.729Z","caller":"etcdserver/server.go:1453","msg":"skipped leadership transfer for single voting member cluster","local-member-id":"a8142d3343e761f","current-leader-member-id":"a8142d3343e761f"}
time="2023-10-28T22:18:01Z" level=info msg="Retrieving etcd snapshot on-demand-ip-4-4-4-4-1698531345 from S3"
time="2023-10-28T22:18:01Z" level=info msg="Checking if S3 bucket xxxx exists"
{"level":"info","ts":"2023-10-28T22:18:01.750Z","caller":"embed/etcd.go:563","msg":"stopping serving peer traffic","address":"127.0.0.1:2400"}
{"level":"info","ts":"2023-10-28T22:18:01.750Z","caller":"embed/etcd.go:568","msg":"stopped serving peer traffic","address":"127.0.0.1:2400"}
{"level":"info","ts":"2023-10-28T22:18:01.750Z","caller":"embed/etcd.go:370","msg":"closed etcd server","name":"ip-4-4-4-4-0c50be92","data-dir":"/var/lib/rancher/k3s/server/db/etcd-tmp","advertise-peer-urls":["http://127.0.0.1:2400"],"advertise-client-urls":["http://127.0.0.1:2399"]}
time="2023-10-28T22:18:01Z" level=info msg="S3 bucket xxxx exists"
time="2023-10-28T22:18:01Z" level=debug msg="Skip setting S3 snapshot cluster ID and token during cluster-reset"
time="2023-10-28T22:18:01Z" level=debug msg="Downloading snapshot from s3://xxxx/xxxx/on-demand-ip-4-4-4-4-1698531345"
time="2023-10-28T22:18:01Z" level=debug msg="Downloading snapshot metadata from s3://xxxx/xxxx/.metadata/on-demand-ip-4-4-4-4-1698531345"
time="2023-10-28T22:18:01Z" level=info msg="S3 download complete for /var/lib/rancher/k3s/server/db/snapshots/on-demand-ip-4-4-4-4-1698531345"
time="2023-10-28T22:18:01Z" level=info msg="Pre-restore etcd database moved to /var/lib/rancher/k3s/server/db/etcd-old-1698531481"
{"level":"info","ts":"2023-10-28T22:18:01.976Z","caller":"snapshot/v3_snapshot.go:248","msg":"restoring snapshot","path":"/var/lib/rancher/k3s/server/db/snapshots/on-demand-ip-4-4-4-4-1698531345","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.3-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:1273\ngithub.com/k3s-io/k3s/pkg/etcd.(*ETCD).Reset\n\t/go/src/github.com/k3s-io/k3s/pkg/etcd/etcd.go:374\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:262\ngithub.com/k3s-io/k3s/pkg/daemons/control.Server\n\t/go/src/github.com/k3s-io/k3s/pkg/daemons/control/server.go:33\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:485\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.12/app.go:524\ngithub.com/urfave/cli.Command.Run\n\t/go/pkg/mod/github.com/urfave/cli@v1.22.12/command.go:175\ngithub.com/urfave/cli.(*App).Run\n\t/go/pkg/mod/github.com/urfave/cli@v1.22.12/app.go:277\nmain.main\n\t/go/src/github.com/k3s-io/k3s/cmd/server/main.go:82\nruntime.main\n\t/usr/local/go/src/runtime/proc.go:250"}
{"level":"info","ts":"2023-10-28T22:18:02.015Z","caller":"membership/store.go:141","msg":"Trimming membership information from the backend..."}
{"level":"info","ts":"2023-10-28T22:18:02.032Z","caller":"membership/cluster.go:421","msg":"added member","cluster-id":"378de42fe12bc35","local-member-id":"0","added-peer-id":"68b452179016861","added-peer-peer-urls":["https://1.11.22.11:2380"]}
{"level":"info","ts":"2023-10-28T22:18:02.046Z","caller":"snapshot/v3_snapshot.go:269","msg":"restored snapshot","path":"/var/lib/rancher/k3s/server/db/snapshots/on-demand-ip-4-4-4-4-1698531345","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"}
time="2023-10-28T22:18:02Z" level=info msg="Starting etcd for new cluster"
{"level":"info","ts":"2023-10-28T22:18:02.047Z","caller":"embed/etcd.go:131","msg":"configuring peer listeners","listen-peer-urls":["https://127.0.0.1:2380"]}
{"level":"info","ts":"2023-10-28T22:18:02.047Z","caller":"embed/etcd.go:479","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":"2023-10-28T22:18:02.047Z","caller":"embed/etcd.go:139","msg":"configuring client listeners","listen-client-urls":["https://127.0.0.1:2379"]}
{"level":"info","ts":"2023-10-28T22:18:02.047Z","caller":"embed/etcd.go:308","msg":"starting an etcd server","etcd-version":"3.5.3","git-sha":"Not provided (use ./build instead of go build)","go-version":"go1.20.10","go-os":"linux","go-arch":"amd64","max-cpu-set":2,"max-cpu-available":2,"member-initialized":true,"name":"ip-4-4-4-4-264802de","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,"snapshot-catchup-entries":5000,"initial-advertise-peer-urls":["https://172.31.28.17: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-size-bytes":2147483648,"pre-vote":true,"initial-corrupt-check":true,"corrupt-check-time-interval":"0s","auto-compaction-mode":"","auto-compaction-retention":"0s","auto-compaction-interval":"0s","discovery-url":"","discovery-proxy":"","downgrade-check-interval":"5s"}
{"level":"info","ts":"2023-10-28T22:18:02.049Z","caller":"etcdserver/backend.go:81","msg":"opened backend db","path":"/var/lib/rancher/k3s/server/db/etcd/member/snap/db","took":"1.204194ms"}
{"level":"info","ts":"2023-10-28T22:18:02.049Z","caller":"etcdserver/server.go:508","msg":"recovered v2 store from snapshot","snapshot-index":1,"snapshot-size":"6.5 kB"}
{"level":"info","ts":"2023-10-28T22:18:02.049Z","caller":"etcdserver/server.go:521","msg":"recovered v3 backend from snapshot","backend-size-bytes":4284416,"backend-size":"4.3 MB","backend-size-in-use-bytes":4263936,"backend-size-in-use":"4.3 MB"}
{"level":"info","ts":"2023-10-28T22:18:02.050Z","caller":"etcdserver/raft.go:556","msg":"forcing restart member","cluster-id":"378de42fe12bc35","local-member-id":"68b452179016861","commit-index":1}
{"level":"info","ts":"2023-10-28T22:18:02.050Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"68b452179016861 switched to configuration voters=(471546596056721505)"}
{"level":"info","ts":"2023-10-28T22:18:02.050Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"68b452179016861 became follower at term 1"}
{"level":"info","ts":"2023-10-28T22:18:02.050Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"newRaft 68b452179016861 [peers: [68b452179016861], term: 1, commit: 1, applied: 1, lastindex: 1, lastterm: 1]"}
{"level":"info","ts":"2023-10-28T22:18:02.050Z","caller":"membership/cluster.go:278","msg":"recovered/added member from store","cluster-id":"378de42fe12bc35","local-member-id":"68b452179016861","recovered-remote-peer-id":"68b452179016861","recovered-remote-peer-urls":["https://172.31.28.17:2380"]}
{"level":"warn","ts":"2023-10-28T22:18:02.051Z","caller":"auth/store.go:1220","msg":"simple token is not cryptographically signed"}
{"level":"info","ts":"2023-10-28T22:18:02.063Z","caller":"mvcc/kvstore.go:415","msg":"kvstore restored","current-rev":2207}
{"level":"info","ts":"2023-10-28T22:18:02.066Z","caller":"etcdserver/corrupt.go:46","msg":"starting initial corruption check","local-member-id":"68b452179016861","timeout":"15s"}
{"level":"info","ts":"2023-10-28T22:18:02.068Z","caller":"etcdserver/corrupt.go:116","msg":"initial corruption checking passed; no corruption","local-member-id":"68b452179016861"}
{"level":"info","ts":"2023-10-28T22:18:02.068Z","caller":"etcdserver/server.go:851","msg":"starting etcd server","local-member-id":"68b452179016861","local-server-version":"3.5.3","cluster-version":"to_be_decided"}
{"level":"info","ts":"2023-10-28T22:18:02.068Z","caller":"etcdserver/server.go:736","msg":"started as single-node; fast-forwarding election ticks","local-member-id":"68b452179016861","forward-ticks":9,"forward-duration":"4.5s","election-ticks":10,"election-timeout":"5s"}
{"level":"info","ts":"2023-10-28T22:18:02.069Z","caller":"embed/etcd.go:688","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":"2023-10-28T22:18:02.069Z","caller":"embed/etcd.go:581","msg":"serving peer traffic","address":"127.0.0.1:2380"}
{"level":"info","ts":"2023-10-28T22:18:02.069Z","caller":"embed/etcd.go:553","msg":"cmux::serve","address":"127.0.0.1:2380"}
{"level":"info","ts":"2023-10-28T22:18:02.069Z","caller":"embed/etcd.go:277","msg":"now serving peer/client/metrics","local-member-id":"68b452179016861","initial-advertise-peer-urls":["https://172.31.28.17: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":"2023-10-28T22:18:02.069Z","caller":"embed/etcd.go:763","msg":"serving metrics","address":"http://127.0.0.1:2381"}
time="2023-10-28T22:18:02Z" level=info msg="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 --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"
time="2023-10-28T22:18:02Z" level=info msg="Server node token is available at /var/lib/rancher/k3s/server/token"
time="2023-10-28T22:18:02Z" level=info msg="To join server node to cluster: k3s server -s https://172.31.28.17:6443 -t ${SERVER_NODE_TOKEN}"
time="2023-10-28T22:18:02Z" level=info msg="Agent node token is available at /var/lib/rancher/k3s/server/agent-token"
time="2023-10-28T22:18:02Z" level=info msg="To join agent node to cluster: k3s agent -s https://172.31.28.17:6443 -t ${AGENT_NODE_TOKEN}"
time="2023-10-28T22:18:02Z" level=info msg="Wrote kubeconfig /etc/rancher/k3s/k3s.yaml"
time="2023-10-28T22:18:02Z" level=info msg="Run: k3s kubectl"
time="2023-10-28T22:18:02Z" level=warning msg="remove /var/lib/rancher/k3s/agent/etc/k3s-agent-load-balancer.json: no such file or directory"
time="2023-10-28T22:18:02Z" level=info msg="Adding server to load balancer k3s-agent-load-balancer: 127.0.0.1:6443"
time="2023-10-28T22:18:02Z" level=info msg="Running load balancer k3s-agent-load-balancer 127.0.0.1:6444 -> [127.0.0.1:6443] [default: 127.0.0.1:6443]"
time="2023-10-28T22:18:02Z" level=info msg="Cluster-Http-Server 2023/10/28 22:18:02 http: TLS handshake error from 127.0.0.1:36200: remote error: tls: bad certificate"
time="2023-10-28T22:18:02Z" level=info msg="Cluster-Http-Server 2023/10/28 22:18:02 http: TLS handshake error from 127.0.0.1:36220: remote error: tls: bad certificate"
time="2023-10-28T22:18:03Z" level=info msg="Password verified locally for node ip-4-4-4-4"
time="2023-10-28T22:18:03Z" level=info msg="certificate CN=ip-4-4-4-4 signed by CN=k3s-server-ca@1698531055: notBefore=2023-10-28 22:10:55 +0000 UTC notAfter=2024-10-27 22:18:03 +0000 UTC"
time="2023-10-28T22:18:04Z" level=info msg="certificate CN=system:node:ip-4-4-4-4,O=system:nodes signed by CN=k3s-client-ca@1698531055: notBefore=2023-10-28 22:10:55 +0000 UTC notAfter=2024-10-27 22:18:04 +0000 UTC"
time="2023-10-28T22:18:06Z" level=debug msg="Tunnel server handing HTTP/1.1 GET request for /v1-k3s/connect from 18.221.175.196:39344"
time="2023-10-28T22:18:06Z" level=info msg="Handling backend connection request [ip-1-1-1-1]"
{"level":"info","ts":"2023-10-28T22:18:07.052Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"68b452179016861 is starting a new election at term 1"}
{"level":"info","ts":"2023-10-28T22:18:07.052Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"68b452179016861 became pre-candidate at term 1"}
{"level":"info","ts":"2023-10-28T22:18:07.052Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"68b452179016861 received MsgPreVoteResp from 68b452179016861 at term 1"}
{"level":"info","ts":"2023-10-28T22:18:07.052Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"68b452179016861 became candidate at term 2"}
{"level":"info","ts":"2023-10-28T22:18:07.052Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"68b452179016861 received MsgVoteResp from 68b452179016861 at term 2"}
{"level":"info","ts":"2023-10-28T22:18:07.052Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"68b452179016861 became leader at term 2"}
{"level":"info","ts":"2023-10-28T22:18:07.052Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"raft.node: 68b452179016861 elected leader 68b452179016861 at term 2"}
{"level":"info","ts":"2023-10-28T22:18:07.054Z","caller":"etcdserver/server.go:2044","msg":"published local member to cluster through raft","local-member-id":"68b452179016861","local-member-attributes":"{Name:ip-4-4-4-4-264802de ClientURLs:[https://127.0.0.1:2379]}","request-path":"/0/members/68b452179016861/attributes","cluster-id":"378de42fe12bc35","publish-timeout":"15s"}
{"level":"info","ts":"2023-10-28T22:18:07.054Z","caller":"embed/serve.go:98","msg":"ready to serve client requests"}
{"level":"info","ts":"2023-10-28T22:18:07.056Z","caller":"etcdserver/server.go:2509","msg":"setting up initial cluster version using v2 API","cluster-version":"3.5"}
{"level":"info","ts":"2023-10-28T22:18:07.057Z","caller":"embed/serve.go:188","msg":"serving client traffic securely","address":"127.0.0.1:2379"}
{"level":"info","ts":"2023-10-28T22:18:07.057Z","caller":"membership/cluster.go:584","msg":"set initial cluster version","cluster-id":"378de42fe12bc35","local-member-id":"68b452179016861","cluster-version":"3.5"}
{"level":"info","ts":"2023-10-28T22:18:07.057Z","caller":"etcdserver/server.go:2533","msg":"cluster version is updated","cluster-version":"3.5"}
time="2023-10-28T22:18:07Z" level=info msg="Defragmenting etcd database"
{"level":"info","ts":"2023-10-28T22:18:07.073Z","caller":"v3rpc/maintenance.go:89","msg":"starting defragment"}
{"level":"info","ts":"2023-10-28T22:18:07.076Z","caller":"backend/backend.go:497","msg":"defragmenting","path":"/var/lib/rancher/k3s/server/db/etcd/member/snap/db","current-db-size-bytes":4284416,"current-db-size":"4.3 MB","current-db-size-in-use-bytes":4268032,"current-db-size-in-use":"4.3 MB"}
{"level":"info","ts":"2023-10-28T22:18:07.160Z","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":-208896,"current-db-size-bytes":4075520,"current-db-size":"4.1 MB","current-db-size-in-use-bytes-diff":-200704,"current-db-size-in-use-bytes":4067328,"current-db-size-in-use":"4.1 MB","took":"86.758528ms"}
{"level":"info","ts":"2023-10-28T22:18:07.160Z","caller":"v3rpc/maintenance.go:95","msg":"finished defragment"}
time="2023-10-28T22:18:07Z" level=info msg="etcd data store connection OK"
time="2023-10-28T22:18:07Z" level=info msg="Saving cluster bootstrap data to datastore"
time="2023-10-28T22:18:07Z" level=info msg="Waiting for API server to become available"
time="2023-10-28T22:18:07Z" level=info msg="ETCD server is now running"
time="2023-10-28T22:18:07Z" level=info msg="k3s is up and running"
time="2023-10-28T22:18:07Z" level=debug msg="Comparing /bootstrap/2bb80d537b1d to /bootstrap/2bb80d537b1d"
time="2023-10-28T22:18:07Z" level=debug msg="checking bootstrap key /bootstrap/2bb80d537b1d against /bootstrap/2bb80d537b1d"
time="2023-10-28T22:18:07Z" level=warning msg="Bootstrap key already exists"
time="2023-10-28T22:18:09Z" level=info msg="Defragmenting etcd database"
{"level":"info","ts":"2023-10-28T22:18:09.700Z","caller":"v3rpc/maintenance.go:89","msg":"starting defragment"}
{"level":"info","ts":"2023-10-28T22:18:09.703Z","caller":"backend/backend.go:497","msg":"defragmenting","path":"/var/lib/rancher/k3s/server/db/etcd/member/snap/db","current-db-size-bytes":4075520,"current-db-size":"4.1 MB","current-db-size-in-use-bytes":4067328,"current-db-size-in-use":"4.1 MB"}
{"level":"info","ts":"2023-10-28T22:18:09.765Z","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":4075520,"current-db-size":"4.1 MB","current-db-size-in-use-bytes-diff":0,"current-db-size-in-use-bytes":4067328,"current-db-size-in-use":"4.1 MB","took":"65.67187ms"}
{"level":"info","ts":"2023-10-28T22:18:09.766Z","caller":"v3rpc/maintenance.go:95","msg":"finished defragment"}
time="2023-10-28T22:18:09Z" level=debug msg="Comparing /bootstrap/2bb80d537b1d to /bootstrap/2bb80d537b1d"
time="2023-10-28T22:18:09Z" level=debug msg="checking bootstrap key /bootstrap/2bb80d537b1d against /bootstrap/2bb80d537b1d"
time="2023-10-28T22:18:09Z" level=info msg="Reconciling bootstrap data between datastore and disk"
time="2023-10-28T22:18:09Z" level=debug msg="Comparing /bootstrap/2bb80d537b1d to /bootstrap/2bb80d537b1d"
time="2023-10-28T22:18:09Z" level=debug msg="checking bootstrap key /bootstrap/2bb80d537b1d against /bootstrap/2bb80d537b1d"
time="2023-10-28T22:18:09Z" level=debug msg="Reconciling ETCDPeerCA at '/var/lib/rancher/k3s/server/tls/etcd/peer-ca.crt'"
time="2023-10-28T22:18:09Z" level=debug msg="Reconciling ETCDServerCA at '/var/lib/rancher/k3s/server/tls/etcd/server-ca.crt'"
time="2023-10-28T22:18:09Z" level=debug msg="Reconciling IPSECKey at '/var/lib/rancher/k3s/server/cred/ipsec.psk'"
time="2023-10-28T22:18:09Z" level=debug msg="Reconciling ServerCA at '/var/lib/rancher/k3s/server/tls/server-ca.crt'"
time="2023-10-28T22:18:09Z" level=debug msg="Reconciling ServiceKey at '/var/lib/rancher/k3s/server/tls/service.key'"
time="2023-10-28T22:18:09Z" level=debug msg="Reconciling RequestHeaderCA at '/var/lib/rancher/k3s/server/tls/request-header-ca.crt'"
time="2023-10-28T22:18:09Z" level=debug msg="Reconciling RequestHeaderCAKey at '/var/lib/rancher/k3s/server/tls/request-header-ca.key'"
time="2023-10-28T22:18:09Z" level=debug msg="Reconciling ServerCAKey at '/var/lib/rancher/k3s/server/tls/server-ca.key'"
time="2023-10-28T22:18:09Z" level=debug msg="Reconciling ClientCA at '/var/lib/rancher/k3s/server/tls/client-ca.crt'"
time="2023-10-28T22:18:09Z" level=debug msg="Reconciling ClientCAKey at '/var/lib/rancher/k3s/server/tls/client-ca.key'"
time="2023-10-28T22:18:09Z" level=debug msg="Reconciling ETCDPeerCAKey at '/var/lib/rancher/k3s/server/tls/etcd/peer-ca.key'"
time="2023-10-28T22:18:09Z" level=debug msg="Reconciling ETCDServerCAKey at '/var/lib/rancher/k3s/server/tls/etcd/server-ca.key'"
time="2023-10-28T22:18:09Z" level=debug msg="Reconciling PasswdFile at '/var/lib/rancher/k3s/server/cred/passwd'"
time="2023-10-28T22:18:09Z" level=info msg="Cluster reset: backing up certificates directory to /var/lib/rancher/k3s/server/tls-1698531489"
time="2023-10-28T22:18:09Z" level=warning msg="Updating bootstrap data on disk from datastore"
time="2023-10-28T22:18:09Z" level=info msg="certificate CN=etcd-peer signed by CN=etcd-peer-ca@1698531055: notBefore=2023-10-28 22:10:55 +0000 UTC notAfter=2024-10-27 22:18:09 +0000 UTC"
time="2023-10-28T22:18:09Z" level=info msg="certificate CN=etcd-server signed by CN=etcd-server-ca@1698531055: notBefore=2023-10-28 22:10:55 +0000 UTC notAfter=2024-10-27 22:18:09 +0000 UTC"
time="2023-10-28T22:18:09Z" level=info msg="stopping etcd"
{"level":"info","ts":"2023-10-28T22:18:09.818Z","caller":"embed/etcd.go:368","msg":"closing etcd server","name":"ip-4-4-4-4-264802de","data-dir":"/var/lib/rancher/k3s/server/db/etcd","advertise-peer-urls":["https://172.31.28.17:2380"],"advertise-client-urls":["https://127.0.0.1:2379"]}
{"level":"info","ts":"2023-10-28T22:18:09.828Z","caller":"etcdserver/server.go:1453","msg":"skipped leadership transfer for single voting member cluster","local-member-id":"68b452179016861","current-leader-member-id":"68b452179016861"}
{"level":"info","ts":"2023-10-28T22:18:09.833Z","caller":"embed/etcd.go:563","msg":"stopping serving peer traffic","address":"127.0.0.1:2380"}
{"level":"info","ts":"2023-10-28T22:18:09.834Z","caller":"embed/etcd.go:568","msg":"stopped serving peer traffic","address":"127.0.0.1:2380"}
{"level":"info","ts":"2023-10-28T22:18:09.834Z","caller":"embed/etcd.go:370","msg":"closed etcd server","name":"ip-4-4-4-4-264802de","data-dir":"/var/lib/rancher/k3s/server/db/etcd","advertise-peer-urls":["https://172.31.28.17:2380"],"advertise-client-urls":["https://127.0.0.1:2379"]}
time="2023-10-28T22:18:14Z" level=info msg="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"K3S Cluster Status:
$ sudo /usr/local/bin/kubectl --kubeconfig /etc/rancher/k3s/k3s.yaml get nodes On SERVER1: 18.116.26.226
NAME STATUS ROLES AGE VERSION
ip-1-1-1-1 Ready <none> 22m v1.25.15-rc2+k3s1
ip-2-2-2-2 Ready control-plane,etcd,master 24m v1.25.15-rc2+k3s1
ip-3-3-3-3 Ready control-plane,etcd,master 23m v1.25.15-rc2+k3s1
ip-4-4-4-4 Ready control-plane,etcd,master 25m v1.25.15-rc2+k3s1
$ sudo /usr/local/bin/kubectl --kubeconfig /etc/rancher/k3s/k3s.yaml get pods -A On SERVER1: 18.116.26.226
NAMESPACE NAME READY STATUS RESTARTS AGE
auto-clusterip test-clusterip-b97b749cb-2dxqz 1/1 Running 0 20m
auto-clusterip test-clusterip-b97b749cb-47r9q 1/1 Running 1 (3m44s ago) 20m
auto-daemonset test-daemonset-28mjm 1/1 Running 0 20m
auto-daemonset test-daemonset-8kwhm 1/1 Running 1 (15m ago) 20m
auto-daemonset test-daemonset-g7z5f 1/1 Running 0 20m
auto-daemonset test-daemonset-xb82t 1/1 Running 1 (3m44s ago) 20m
auto-dns dnsutils 1/1 Running 0 20m
auto-ingress test-ingress-6fc6w 1/1 Running 1 (3m44s ago) 20m
auto-ingress test-ingress-jsc6s 1/1 Running 1 (15m ago) 20m
auto-nodeport test-nodeport-5f5cf78d96-429k8 1/1 Running 1 (3m44s ago) 20m
auto-nodeport test-nodeport-5f5cf78d96-ncq2k 1/1 Running 0 20m
clusterip clusterip-pod-demo 1/1 Running 1 (15m ago) 20m
clusterip clusterip-pod-demo-2 1/1 Running 0 20m
clusterip clusterip-pod-demo-3 1/1 Running 1 (3m44s ago) 20m
default clusterip-pod-demo 1/1 Running 1 (3m44s ago) 20m
default clusterip-pod-demo-2 1/1 Running 0 20m
default clusterip-pod-demo-3 1/1 Running 1 (15m ago) 20m
kube-system coredns-8b9777675-hkv7c 1/1 Running 0 24m
kube-system helm-install-traefik-crd-t5wdm 0/1 Completed 1 24m
kube-system helm-install-traefik-wdbdn 0/1 Completed 1 24m
kube-system local-path-provisioner-69dff9496c-lxdx8 1/1 Running 0 24m
kube-system metrics-server-854c559bd-pwj4m 1/1 Running 0 24m
kube-system svclb-traefik-4efd46f3-77rgw 2/2 Running 0 23m
kube-system svclb-traefik-4efd46f3-k7dv4 2/2 Running 2 (3m44s ago) 22m
kube-system svclb-traefik-4efd46f3-nt9pk 2/2 Running 0 22m
kube-system svclb-traefik-4efd46f3-sshcz 2/2 Running 2 (15m ago) 23m
kube-system traefik-7c48d7b8b4-jzfkj 1/1 Running 1 (15m ago) 23m
Backport fix for Cluster Restore for s3 snapshot fails
8727