Closed stevefan1999-personal closed 2 years ago
brandond
commented
2 years ago It does automatically compact; this is actually managed by the apiserver. This error indicates that you've exceeded the 2 gigabyte maximum datastore size, which is actually fairly difficult to do. Can you describe a bit more about how you're using this cluster and what you're storing in it?
igas
commented
2 years ago Hi @brandond, I faced a similar issue. I'm not sure if it's related to @stevefan1999-personal issue. But I had a 3 node cluster and one of the nodes started having problems with #3997 I disabled the upgrade on node 2 & 3, but the first node kept failing. I'm not familiar with how k8s/k3s using etcd, and if this failing node could have caused extra info to be written. Now after a few days of first node failing 2 & 3 went down with this issue.
stevefan1999-personal
commented
2 years ago I fixed this by using an emergency etcd setup described in here, but it shouldn't have had been done that way
igas
commented
2 years ago Sadly, my k3s does not start, so etcd is not running to connect to it.
brandond
commented
2 years ago It is extremely unusual to actually have more than 2GB of data in the etcd datastore. I would be curious to know what you've deployed that has pushed the datastore over this limit, if this is not in fact a symptom of some other problem.
ssmall
commented
2 years ago I just started experiencing a similar failure with my 3-node HA k3s cluster -- one master node became unhealthy and after a day or two the other two master nodes went down. They now fail to start with the same error message described in https://github.com/k3s-io/k3s/issues/4787#issue-1084054872
I understand that this may be unusual, but as evidenced by the number of people reporting this same issue it's clearly not unheard of. I'm happy to provide any details that would help you investigate -- I'll even hop on Zoom / Google Meet and we can live debug if that would be helpful. I'd love to get to the bottom of this issue, though, as my cluster is currently unrecoverable.
brandond
commented
2 years ago @ssmall would you be able to describe your cluster and what's running in it? As mentioned above, understanding how K3s is being used when the datastore grows excessively might help us confirm whether there is indeed an issue with how we're managing the etcd datastore, or if there are indeed just some folks storing several GB of data in it. The etcd docs do mention that 8GB is the "suggested maximum", with 2GB just being the default.
On recent releases of K3s, you should be able to start the server with --etcd-arg=quota-backend-bytes=$((8*1024*1024*1024)) to set the max size to 8GB.
ssmall
commented
2 years ago On recent releases of K3s, you should be able to start the server with --etcd-arg=quota-backend-bytes=$((810241024*1024)) to set the max size to 8GB.
I tried adding this to the command line for my master nodes however I'm still seeing the same error on startup.
would you be able to describe your cluster and what's running in it?
I have 3 master nodes and 4 worker nodes for a total of 7. At any given time there are maybe 75-100 pods active, many of which are part of a Longhorn deployment and a couple other daemonsets such as MetalLB. I also run a couple postgresql-ha 3-replica deployments using local storage for persistence. Happy to go more in depth as well if you can give me a hint as to what you're looking for as far as workloads that could be eating up etcd space -- I'm not aware of anything obvious that I'm running which would be using up lots of etcd storage.
brandond
commented
2 years ago Can you post the complete startup logs?
ssmall
commented
2 years ago Please find attached the startup logs from one of the master nodes, big-nuc: syslog.txt
brandond
commented
2 years ago Hmm, I see the increased value being printed out by etcd as it starts:
Feb 17 21:09:37 big-nuc k3s[23771]: {"level":"info","ts":"2022-02-17T21:09:37.956-0800","caller":"embed/etcd.go:307","msg":"starting an etcd server","etcd-version":"3.5.0","git-sha":"Not provided (use ./build instead of go build)","go-version":"go1.16.10","go-os":"linux","go-arch":"amd64","max-cpu-set":12,"max-cpu-available":12,"member-initialized":true,"name":"big-nuc-8337f722","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://192.168.1.31:2380"],"advertise-client-urls":["https://192.168.1.31:2379"],"listen-client-urls":["https://127.0.0.1:2379","https://192.168.1.31: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":8589934592,"pre-vote":true,"initial-corrupt-check":false,"corrupt-check-time-interval":"0s","auto-compaction-mode":"","auto-compaction-retention":"0s","auto-compaction-interval":"0s","discovery-url":"","discovery-proxy":"","downgrade-check-interval":"5s"}
"quota-size-bytes":8589934592
However, it then reports an error when attempting to serve writes:
Feb 17 21:09:43 big-nuc k3s[23771]: {"level":"warn","ts":"2022-02-17T21:09:43.404-0800","caller":"etcdserver/util.go:123","msg":"failed to apply request","took":"14.91µs","request":"header:<ID:16997569082376149769 username:\"etcd-client\" auth_revision:1 > txn:<compare:<target:MOD key:\"/bootstrap/ef5238a9efa0\" mod_revision:0 > success:<request_put:<key:\"/bootstrap/ef5238a9efa0\" value_size:12665 >> failure:<>>","response":"","error":"etcdserver: no space"}
I think the problem is that the no space alarm is not cleared on startup; alarms need to be explicitly cleared but we don't currently have any logic in place to do that, and since K3s will exit almost immediately when the alarm is set there's not much of an opportunity to do so manually.
ssmall
commented
2 years ago Can you recommend a path forward to restore my cluster to a working state? I'm not familiar at all with etcd, but I imagine based on what you've said that there may be a command I could run to clear the alarm state?
ssmall
commented
2 years ago Hi @brandond,
Just wondering if there are any steps I can take manually to clear the alarms. As noted in https://github.com/k3s-io/k3s/issues/4787#issuecomment-1004902531, using etcdctl is not an option because k3s is not actually starting up, so there is no endpoint for etcdctl to connect to. I see that you have already merged a fix for this issue, but it would be great to be able to restore my cluster to a working state without having to wait for the next release. It's already been nearly a month (for me) and at this point if I can't get a solution to this issue I may have to spin up a new cluster (using something other than k3s, since there is currently no release of k3s that contains a fix for this issue).
brandond
commented
2 years ago You might be able to grab a standalone etcd binary, and start it up pointed at your db directory? Either that or use the INSTALL_K3S_COMMIT installer environment variable to install a build that has the fix merged.
ssmall
commented
2 years ago Thanks for the reply.
use the INSTALL_K3S_COMMIT installer environment variable to install a build that has the fix merged
Any tips on the correct commit has to use? I tried a couple different hashes from the master branch but the installation script failed with
[INFO] Using commit 003e094b4526a99aa2f6f97bf987f11429b06d73 as release
[INFO] Downloading hash https://storage.googleapis.com/k3s-ci-builds/k3s-003e094b4526a99aa2f6f97bf987f11429b06d73.sha256sum
FAIL: 22I tried to curl the logged URL and saw
$ curl https://storage.googleapis.com/k3s-ci-builds/k3s-003e094b4526a99aa2f6f97bf987f11429b06d73.sha256sum
<?xml version='1.0' encoding='UTF-8'?><Error><Code>ProjectNotFound</Code><Message>The requested project was not found.</Message><Details>The requested project was not found.</Details></Error>%I think the problem is that the no space alarm is not cleared on startup; alarms need to be explicitly cleared but we don't currently have any logic in place to do that, and since K3s will exit almost immediately when the alarm is set there's not much of an opportunity to do so manually.
I tried the route of pointing a standalone etcd binary at /var/lib/rancher/k3s/server/db and it did not appear that this is the problem. The output of etcdctl alarm list is empty. I tried restarting k3s afterward, just in case starting up the standalone etcd had cleared up the alarm state, but I'm still seeing the same error on k3s startup:
Mar 13 17:21:30 big-nuc k3s[4240]: {"level":"warn","ts":"2022-03-13T17:21:30.783-0700","caller":"etcdserver/util.go:123","msg":"failed to apply request","took":"10.558µs","request":"header:<ID:16997569631274120200 username:\"etcd-client\" auth_revision:1 > txn:<compare:<target:MOD key:\"/bootstrap/ef5238a9efa0\" mod_revision:0 > success:<request_put:<key:\"/bootstrap/ef5238a9efa0\" value_size:12665 >> failure:<>>","response":"","error":"etcdserver: no space"}
Mar 13 17:21:30 big-nuc k3s[4240]: {"level":"warn","ts":"2022-03-13T17:21:30.784-0700","logger":"etcd-client","caller":"v3/retry_interceptor.go:62","msg":"retrying of unary invoker failed","target":"etcd-endpoints://0xc0017ac1c0/#initially=[https://127.0.0.1:2379]","attempt":0,"error":"rpc error: code = ResourceExhausted desc = etcdserver: mvcc: database space exceeded"}
Mar 13 17:21:30 big-nuc k3s[4240]: panic: etcdserver: mvcc: database space exceeded
Mar 13 17:21:30 big-nuc k3s[4240]: goroutine 503 [running]:
Mar 13 17:21:30 big-nuc k3s[4240]: github.com/rancher/k3s/pkg/cluster.(*Cluster).Start.func1(0xc02b0413e0, 0x5959b78, 0xc001812a00, 0xc001521a80)
Mar 13 17:21:30 big-nuc k3s[4240]: /go/src/github.com/rancher/k3s/pkg/cluster/cluster.go:103 +0x1e5
Mar 13 17:21:30 big-nuc k3s[4240]: created by github.com/rancher/k3s/pkg/cluster.(*Cluster).Start
Mar 13 17:21:30 big-nuc k3s[4240]: /go/src/github.com/rancher/k3s/pkg/cluster/cluster.go:98 +0x6bf
Mar 13 17:21:30 big-nuc systemd[1]: k3s.service: Main process exited, code=exited, status=2/INVALIDARGUMENT
-- Subject: Unit process exited
-- Defined-By: systemd
-- Support: https://www.debian.org/support
--
-- An ExecStart= process belonging to unit k3s.service has exited.
--
-- The process' exit code is 'exited' and its exit status is 2.
Mar 13 17:21:30 big-nuc systemd[1]: k3s.service: Failed with result 'exit-code'.
-- Subject: Unit failed
-- Defined-By: systemd
-- Support: https://www.debian.org/support
--
-- The unit k3s.service has entered the 'failed' state with result 'exit-code'.
Mar 13 17:21:30 big-nuc systemd[1]: Failed to start Lightweight Kubernetes.
-- Subject: A start job for unit k3s.service has failed
-- Defined-By: systemd
-- Support: https://www.debian.org/support
--
-- A start job for unit k3s.service has finished with a failure.
--
-- The job identifier is 4797 and the job result is failed.
Mar 13 17:21:35 big-nuc systemd[1]: k3s.service: Service RestartSec=5s expired, scheduling restart.
Mar 13 17:21:35 big-nuc systemd[1]: k3s.service: Scheduled restart job, restart counter is at 10.
-- Subject: Automatic restarting of a unit has been scheduled
-- Defined-By: systemd
-- Support: https://www.debian.org/support
--
-- Automatic restarting of the unit k3s.service has been scheduled, as the result for
-- the configured Restart= setting for the unit.
Mar 13 17:21:35 big-nuc systemd[1]: Stopped Lightweight Kubernetes.
-- Subject: A stop job for unit k3s.service has finished
-- Defined-By: systemd
-- Support: https://www.debian.org/support
--
-- A stop job for unit k3s.service has finished.
--
-- The job identifier is 4923 and the job result is done.Try 4b064b5d22ebd1c746763ddbf335a5acda61438a
ssmall
commented
2 years ago Try 4b064b5
Same result with that commit hash, unfortunately.
$ curl https://storage.googleapis.com/k3s-ci-builds/k3s-4b064b5d22ebd1c746763ddbf335a5acda61438a.sha256sum
<?xml version='1.0' encoding='UTF-8'?><Error><Code>ProjectNotFound</Code><Message>The requested project was not found.</Message><Details>The requested project was not found.</Details></Error>Hmm. They roll off after 30 days I think? It should still be there. Try the most recent master - currently 29c55f5efcd5fb0374c9bd01dfe2ed8a20817216
ssmall
commented
2 years ago That commit hash worked, but now k3s is failing to start up with a new error:
Mar 16 20:30:47 antikythera k3s[19670]: time="2022-03-16T20:30:47-07:00" level=info msg="Starting k3s v1.23.4+k3s-29c55f5e (29c55f5e)"
Mar 16 20:30:47 antikythera k3s[19670]: time="2022-03-16T20:30:47-07:00" level=info msg="Managed etcd cluster bootstrap already complete and initialized"
Mar 16 20:30:47 antikythera k3s[19670]: time="2022-03-16T20:30:47-07:00" level=info msg="Starting temporary etcd to reconcile with datastore"
Mar 16 20:30:48 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:48.718-0700","caller":"embed/etcd.go:131","msg":"configuring peer listeners","listen-peer-urls":["http://127.0.0.1:2400"]}
Mar 16 20:30:48 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:48.718-0700","caller":"embed/etcd.go:139","msg":"configuring client listeners","listen-client-urls":["http://127.0.0.1:2399"]}
Mar 16 20:30:48 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:48.719-0700","caller":"embed/etcd.go:307","msg":"starting an etcd server","etcd-version":"3.5.1","git-sha":"Not provided (use ./build instead of go build)","go-version":"go1.17.5","go-os":"linux","go-arch":"amd64","max-cpu-set":32,"max-cpu-available":32,"member-initialized":true,"name":"antikythera-0948c62a","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":100000,"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":false,"corrupt-check-time-interval":"0s","auto-compaction-mode":"","auto-compaction-retention":"0s","auto-compaction-interval":"0s","discovery-url":"","discovery-proxy":"","downgrade-check-interval":"5s"}
Mar 16 20:30:48 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:48.767-0700","caller":"etcdserver/backend.go:81","msg":"opened backend db","path":"/var/lib/rancher/k3s/server/db/etcd-tmp/member/snap/db","took":"48.706994ms"}
Mar 16 20:30:49 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:49.472-0700","caller":"etcdserver/server.go:508","msg":"recovered v2 store from snapshot","snapshot-index":457052414,"snapshot-size":"406 kB"}
Mar 16 20:30:50 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:50.720-0700","caller":"etcdserver/server.go:518","msg":"recovered v3 backend from snapshot","backend-size-bytes":357355520,"backend-size":"357 MB","backend-size-in-use-bytes":35020800,"backend-size-in-use":"35 MB"}
Mar 16 20:30:51 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:51.216-0700","caller":"etcdserver/raft.go:526","msg":"discarding uncommitted WAL entries","entry-index":457073561,"commit-index-from-wal":457073560,"number-of-discarded-entries":1}
Mar 16 20:30:51 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:51.331-0700","caller":"etcdserver/raft.go:556","msg":"forcing restart member","cluster-id":"d1c8afd71ab75419","local-member-id":"fcfb4c91f4fc885c","commit-index":457073562}
Mar 16 20:30:51 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:51.331-0700","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"fcfb4c91f4fc885c switched to configuration voters=(4601869108914463604 9791417851272883171 18229248106476374108)"}
Mar 16 20:30:51 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:51.331-0700","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"fcfb4c91f4fc885c became follower at term 68393"}
Mar 16 20:30:51 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:51.332-0700","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"newRaft fcfb4c91f4fc885c [peers: [3fdd1f92a3b0a374,87e21aa89889ebe3,fcfb4c91f4fc885c], term: 68393, commit: 457073562, applied: 457052414, lastindex: 457073562, lastterm: 68393]"}
Mar 16 20:30:51 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:51.332-0700","caller":"api/capability.go:75","msg":"enabled capabilities for version","cluster-version":"3.5"}
Mar 16 20:30:51 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:51.332-0700","caller":"membership/cluster.go:278","msg":"recovered/added member from store","cluster-id":"d1c8afd71ab75419","local-member-id":"fcfb4c91f4fc885c","recovered-remote-peer-id":"87e21aa89889ebe3","recovered-remote-peer-urls":["https://192.168.1.31:2380"]}
Mar 16 20:30:51 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:51.332-0700","caller":"membership/cluster.go:278","msg":"recovered/added member from store","cluster-id":"d1c8afd71ab75419","local-member-id":"fcfb4c91f4fc885c","recovered-remote-peer-id":"fcfb4c91f4fc885c","recovered-remote-peer-urls":["https://192.168.1.33:2380"]}
Mar 16 20:30:51 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:51.332-0700","caller":"membership/cluster.go:278","msg":"recovered/added member from store","cluster-id":"d1c8afd71ab75419","local-member-id":"fcfb4c91f4fc885c","recovered-remote-peer-id":"3fdd1f92a3b0a374","recovered-remote-peer-urls":["https://192.168.1.62:2380"]}
Mar 16 20:30:51 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:51.332-0700","caller":"membership/cluster.go:287","msg":"set cluster version from store","cluster-version":"3.5"}
Mar 16 20:30:51 antikythera k3s[19670]: {"level":"warn","ts":"2022-03-16T20:30:51.344-0700","caller":"auth/store.go:1220","msg":"simple token is not cryptographically signed"}
Mar 16 20:30:51 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:51.352-0700","caller":"mvcc/kvstore.go:345","msg":"restored last compact revision","meta-bucket-name":"meta","meta-bucket-name-key":"finishedCompactRev","restored-compact-revision":420398777}
Mar 16 20:30:51 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:51.421-0700","caller":"mvcc/kvstore.go:415","msg":"kvstore restored","current-rev":420403256}
Mar 16 20:30:51 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:51.427-0700","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"}
Mar 16 20:30:51 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:51.436-0700","caller":"rafthttp/peer.go:133","msg":"starting remote peer","remote-peer-id":"3fdd1f92a3b0a374"}
Mar 16 20:30:51 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:51.436-0700","caller":"rafthttp/pipeline.go:72","msg":"started HTTP pipelining with remote peer","local-member-id":"fcfb4c91f4fc885c","remote-peer-id":"3fdd1f92a3b0a374"}
Mar 16 20:30:51 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:51.436-0700","caller":"rafthttp/stream.go:169","msg":"started stream writer with remote peer","local-member-id":"fcfb4c91f4fc885c","remote-peer-id":"3fdd1f92a3b0a374"}
Mar 16 20:30:51 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:51.437-0700","caller":"rafthttp/peer.go:137","msg":"started remote peer","remote-peer-id":"3fdd1f92a3b0a374"}
Mar 16 20:30:51 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:51.437-0700","caller":"rafthttp/transport.go:317","msg":"added remote peer","local-member-id":"fcfb4c91f4fc885c","remote-peer-id":"3fdd1f92a3b0a374","remote-peer-urls":["https://192.168.1.62:2380"]}
Mar 16 20:30:51 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:51.437-0700","caller":"rafthttp/peer.go:133","msg":"starting remote peer","remote-peer-id":"87e21aa89889ebe3"}
Mar 16 20:30:51 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:51.437-0700","caller":"rafthttp/pipeline.go:72","msg":"started HTTP pipelining with remote peer","local-member-id":"fcfb4c91f4fc885c","remote-peer-id":"87e21aa89889ebe3"}
Mar 16 20:30:51 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:51.438-0700","caller":"rafthttp/stream.go:169","msg":"started stream writer with remote peer","local-member-id":"fcfb4c91f4fc885c","remote-peer-id":"3fdd1f92a3b0a374"}
Mar 16 20:30:51 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:51.437-0700","caller":"rafthttp/stream.go:395","msg":"started stream reader with remote peer","stream-reader-type":"stream MsgApp v2","local-member-id":"fcfb4c91f4fc885c","remote-peer-id":"3fdd1f92a3b0a374"}
Mar 16 20:30:51 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:51.439-0700","caller":"rafthttp/peer.go:137","msg":"started remote peer","remote-peer-id":"87e21aa89889ebe3"}
Mar 16 20:30:51 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:51.439-0700","caller":"rafthttp/transport.go:317","msg":"added remote peer","local-member-id":"fcfb4c91f4fc885c","remote-peer-id":"87e21aa89889ebe3","remote-peer-urls":["https://192.168.1.31:2380"]}
Mar 16 20:30:51 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:51.439-0700","caller":"etcdserver/server.go:834","msg":"starting etcd server","local-member-id":"fcfb4c91f4fc885c","local-server-version":"3.5.1","cluster-id":"d1c8afd71ab75419","cluster-version":"3.5"}
Mar 16 20:30:51 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:51.438-0700","caller":"rafthttp/stream.go:395","msg":"started stream reader with remote peer","stream-reader-type":"stream Message","local-member-id":"fcfb4c91f4fc885c","remote-peer-id":"3fdd1f92a3b0a374"}
Mar 16 20:30:51 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:51.439-0700","caller":"rafthttp/stream.go:395","msg":"started stream reader with remote peer","stream-reader-type":"stream MsgApp v2","local-member-id":"fcfb4c91f4fc885c","remote-peer-id":"87e21aa89889ebe3"}
Mar 16 20:30:51 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:51.439-0700","caller":"rafthttp/stream.go:395","msg":"started stream reader with remote peer","stream-reader-type":"stream Message","local-member-id":"fcfb4c91f4fc885c","remote-peer-id":"87e21aa89889ebe3"}
Mar 16 20:30:51 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:51.439-0700","caller":"rafthttp/stream.go:169","msg":"started stream writer with remote peer","local-member-id":"fcfb4c91f4fc885c","remote-peer-id":"87e21aa89889ebe3"}
Mar 16 20:30:51 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:51.439-0700","caller":"etcdserver/server.go:744","msg":"starting initial election tick advance","election-ticks":10}
Mar 16 20:30:51 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:51.441-0700","caller":"rafthttp/stream.go:169","msg":"started stream writer with remote peer","local-member-id":"fcfb4c91f4fc885c","remote-peer-id":"87e21aa89889ebe3"}
Mar 16 20:30:51 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:51.444-0700","caller":"embed/etcd.go:580","msg":"serving peer traffic","address":"127.0.0.1:2400"}
Mar 16 20:30:51 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:51.444-0700","caller":"embed/etcd.go:552","msg":"cmux::serve","address":"127.0.0.1:2400"}
Mar 16 20:30:51 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:51.444-0700","caller":"embed/etcd.go:276","msg":"now serving peer/client/metrics","local-member-id":"fcfb4c91f4fc885c","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":[]}
Mar 16 20:30:51 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:51.786-0700","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"fcfb4c91f4fc885c switched to configuration voters=(9791417851272883171 18229248106476374108)"}
Mar 16 20:30:51 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:51.786-0700","caller":"membership/cluster.go:472","msg":"removed member","cluster-id":"d1c8afd71ab75419","local-member-id":"fcfb4c91f4fc885c","removed-remote-peer-id":"3fdd1f92a3b0a374","removed-remote-peer-urls":["https://192.168.1.62:2380"]}
Mar 16 20:30:51 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:51.786-0700","caller":"rafthttp/peer.go:330","msg":"stopping remote peer","remote-peer-id":"3fdd1f92a3b0a374"}
Mar 16 20:30:51 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:51.786-0700","caller":"rafthttp/stream.go:294","msg":"stopped TCP streaming connection with remote peer","stream-writer-type":"unknown stream","remote-peer-id":"3fdd1f92a3b0a374"}
Mar 16 20:30:51 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:51.786-0700","caller":"rafthttp/stream.go:294","msg":"stopped TCP streaming connection with remote peer","stream-writer-type":"unknown stream","remote-peer-id":"3fdd1f92a3b0a374"}
Mar 16 20:30:51 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:51.786-0700","caller":"rafthttp/pipeline.go:85","msg":"stopped HTTP pipelining with remote peer","local-member-id":"fcfb4c91f4fc885c","remote-peer-id":"3fdd1f92a3b0a374"}
Mar 16 20:30:51 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:51.787-0700","caller":"rafthttp/stream.go:442","msg":"stopped stream reader with remote peer","stream-reader-type":"stream MsgApp v2","local-member-id":"fcfb4c91f4fc885c","remote-peer-id":"3fdd1f92a3b0a374"}
Mar 16 20:30:51 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:51.787-0700","caller":"rafthttp/stream.go:442","msg":"stopped stream reader with remote peer","stream-reader-type":"stream Message","local-member-id":"fcfb4c91f4fc885c","remote-peer-id":"3fdd1f92a3b0a374"}
Mar 16 20:30:51 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:51.787-0700","caller":"rafthttp/peer.go:335","msg":"stopped remote peer","remote-peer-id":"3fdd1f92a3b0a374"}
Mar 16 20:30:51 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:51.787-0700","caller":"rafthttp/transport.go:355","msg":"removed remote peer","local-member-id":"fcfb4c91f4fc885c","removed-remote-peer-id":"3fdd1f92a3b0a374"}
Mar 16 20:30:51 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:51.787-0700","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"fcfb4c91f4fc885c switched to configuration voters=(18229248106476374108)"}
Mar 16 20:30:51 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:51.787-0700","caller":"membership/cluster.go:472","msg":"removed member","cluster-id":"d1c8afd71ab75419","local-member-id":"fcfb4c91f4fc885c","removed-remote-peer-id":"87e21aa89889ebe3","removed-remote-peer-urls":["https://192.168.1.31:2380"]}
Mar 16 20:30:51 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:51.787-0700","caller":"rafthttp/peer.go:330","msg":"stopping remote peer","remote-peer-id":"87e21aa89889ebe3"}
Mar 16 20:30:51 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:51.787-0700","caller":"rafthttp/stream.go:294","msg":"stopped TCP streaming connection with remote peer","stream-writer-type":"unknown stream","remote-peer-id":"87e21aa89889ebe3"}
Mar 16 20:30:51 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:51.787-0700","caller":"rafthttp/stream.go:294","msg":"stopped TCP streaming connection with remote peer","stream-writer-type":"unknown stream","remote-peer-id":"87e21aa89889ebe3"}
Mar 16 20:30:51 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:51.788-0700","caller":"rafthttp/pipeline.go:85","msg":"stopped HTTP pipelining with remote peer","local-member-id":"fcfb4c91f4fc885c","remote-peer-id":"87e21aa89889ebe3"}
Mar 16 20:30:51 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:51.788-0700","caller":"rafthttp/stream.go:442","msg":"stopped stream reader with remote peer","stream-reader-type":"stream MsgApp v2","local-member-id":"fcfb4c91f4fc885c","remote-peer-id":"87e21aa89889ebe3"}
Mar 16 20:30:51 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:51.788-0700","caller":"rafthttp/stream.go:442","msg":"stopped stream reader with remote peer","stream-reader-type":"stream Message","local-member-id":"fcfb4c91f4fc885c","remote-peer-id":"87e21aa89889ebe3"}
Mar 16 20:30:51 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:51.788-0700","caller":"rafthttp/peer.go:335","msg":"stopped remote peer","remote-peer-id":"87e21aa89889ebe3"}
Mar 16 20:30:51 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:30:51.788-0700","caller":"rafthttp/transport.go:355","msg":"removed remote peer","local-member-id":"fcfb4c91f4fc885c","removed-remote-peer-id":"87e21aa89889ebe3"}
Mar 16 20:31:00 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:31:00.333-0700","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"fcfb4c91f4fc885c is starting a new election at term 68393"}
Mar 16 20:31:00 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:31:00.333-0700","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"fcfb4c91f4fc885c became pre-candidate at term 68393"}
Mar 16 20:31:00 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:31:00.333-0700","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"fcfb4c91f4fc885c received MsgPreVoteResp from fcfb4c91f4fc885c at term 68393"}
Mar 16 20:31:00 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:31:00.333-0700","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"fcfb4c91f4fc885c became candidate at term 68394"}
Mar 16 20:31:00 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:31:00.333-0700","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"fcfb4c91f4fc885c received MsgVoteResp from fcfb4c91f4fc885c at term 68394"}
Mar 16 20:31:00 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:31:00.333-0700","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"fcfb4c91f4fc885c became leader at term 68394"}
Mar 16 20:31:00 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:31:00.333-0700","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"raft.node: fcfb4c91f4fc885c elected leader fcfb4c91f4fc885c at term 68394"}
Mar 16 20:31:00 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:31:00.345-0700","caller":"etcdserver/server.go:2029","msg":"published local member to cluster through raft","local-member-id":"fcfb4c91f4fc885c","local-member-attributes":"{Name:antikythera-0948c62a ClientURLs:[http://127.0.0.1:2399]}","request-path":"/0/members/fcfb4c91f4fc885c/attributes","cluster-id":"d1c8afd71ab75419","publish-timeout":"15s"}
Mar 16 20:31:00 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:31:00.346-0700","caller":"embed/serve.go:98","msg":"ready to serve client requests"}
Mar 16 20:31:00 antikythera k3s[19670]: {"level":"info","ts":"2022-03-16T20:31:00.347-0700","caller":"embed/serve.go:140","msg":"serving client traffic insecurely; this is strongly discouraged!","address":"127.0.0.1:2399"}
Mar 16 20:31:00 antikythera k3s[19670]: time="2022-03-16T20:31:00-07:00" level=info msg="etcd temporary data store connection OK"
Mar 16 20:31:00 antikythera k3s[19670]: time="2022-03-16T20:31:00-07:00" level=info msg="Reconciling bootstrap data between datastore and disk"
Mar 16 20:31:00 antikythera k3s[19670]: time="2022-03-16T20:31:00-07:00" level=warning msg=" doesn't exist. continuing..."
Mar 16 20:31:00 antikythera k3s[19670]: time="2022-03-16T20:31:00-07:00" level=warning msg=" doesn't exist. continuing..."
Mar 16 20:31:00 antikythera k3s[19670]: time="2022-03-16T20:31:00-07:00" level=warning msg="updating bootstrap data on disk from datastore"
Mar 16 20:31:00 antikythera k3s[19670]: time="2022-03-16T20:31:00-07:00" level=fatal msg="Failed to reconcile with temporary etcd: failed to write to : open : no such file or directory"
Mar 16 20:31:00 antikythera systemd[1]: k3s.service: Main process exited, code=exited, status=1/FAILURE
Mar 16 20:31:00 antikythera systemd[1]: k3s.service: Failed with result 'exit-code'.
Mar 16 20:31:00 antikythera systemd[1]: Failed to start Lightweight Kubernetes.
Mar 16 20:31:00 antikythera systemd[1]: k3s.service: Consumed 7.674s CPU time.Hmm, that's odd. Just like that, with the empty paths in the error messages at the end?
ssmall
commented
2 years ago Hmm, that's odd. Just like that, with the empty paths in the error messages at the end?
Correct, I haven't redacted anything from the log.
brandond
commented
2 years ago Can you add --debug to your server args, and try 95f66a049a2a567ec4252c8db177ba5062100a1f ? This should output some more information, and hopefully make it past that error.
ssmall
commented
2 years ago That got me a bit farther. Now the first node starts up and waits around for another node to be reachable. As soon as I start up the second node (same arguments including --etcd-arg=quota-backend-bytes=$((8*1024*1024*1024))) they both start failing again with panic: etcdserver: mvcc: database space exceeded (full logs below)
brandond
commented
2 years ago I'm not sure what's going on with etcd but the messages suggest that either you've set it to 10GB or 11GB instead of 8GB, or there's some internal math that etcd is doing on the quota-backend-bytes flag:
Mar 17 09:47:39 antikythera k3s[21881]: {"level":"info","ts":"2022-03-17T09:47:39.642-0700","caller":"embed/etcd.go:307","msg":"starting an etcd server","etcd-version":"3.5.1","git-sha":"Not provided (use ./build instead of go build)","go-version":"go1.17.5","go-os":"linux","go-arch":"amd64","max-cpu-set":32,"max-cpu-available":32,"member-initialized":true,"name":"antikythera-0948c62a","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://192.168.1.33:2380"],"advertise-client-urls":["https://192.168.1.33:2379"],"listen-client-urls":["https://127.0.0.1:2379","https://192.168.1.33: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":10737418240,"pre-vote":true,"initial-corrupt-check":false,"corrupt-check-time-interval":"0s","auto-compaction-mode":"","auto-compaction-retention":"0s","auto-compaction-interval":"0s","discovery-url":"","discovery-proxy":"","downgrade-check-interval":"5s"}
Mar 17 09:47:40 antikythera k3s[21881]: {"level":"warn","ts":"2022-03-17T09:47:40.949-0700","caller":"etcdserver/quota.go:108","msg":"quota exceeds the maximum value","quota-name":"v3-applier","quota-size-bytes":10737418240,"quota-size":"11 GB","quota-maximum-size-bytes":8589934592,"quota-maximum-size":"8.6 GB"}
Mar 17 09:47:40 antikythera k3s[21881]: {"level":"info","ts":"2022-03-17T09:47:40.949-0700","caller":"etcdserver/quota.go:117","msg":"enabled backend quota","quota-name":"v3-applier","quota-size-bytes":10737418240,"quota-size":"11 GB"}Specifically this bit: "msg":"quota exceeds the maximum value","quota-name":"v3-applier","quota-size-bytes":10737418240,"quota-size":"11 GB","quota-maximum-size-bytes":8589934592,"quota-maximum-size":"8.6 GB"
Can you confirm that you're not setting it to anything above 8GB? If so, perhaps try reducing it to 6GB?
ssmall
commented
2 years ago Oh, good catch. I did up it to 10GiB previously when I was trying to debug the issue on my own. It sounds like there is a separate setting (quota-maximum-size?) that I'm running afoul of. What would be the best way to proceed? Should I decrease the quota setting back to 8GiB or change the maximum size?
brandond
commented
2 years ago Try setting it to 8GB instead of 10. If that doesn't work, then we can figure out how to alter that other setting. If it's actually stored anywhere outside the DB itself (and not just calculated from the quota-backend-bytes setting), it would be at /var/lib/rancher/k3s/server/db/etcd/config - maybe take a quick look at that?
ssmall
commented
2 years ago Still having issues on startup after adjusting the quota size back down to 8GiB:
brandond
commented
2 years ago What did you reset the quota to? It looks like it's back to the default of 2GB now:
"quota-size-bytes":2147483648
How much space is your etcd datastore actually consuming? The logs indicate that its only a couple hundred MB:
Mar 17 17:22:30 antikythera k3s[22301]: {"level":"info","ts":"2022-03-17T17:22:30.735-0700","caller":"etcdserver/server.go:518","msg":"recovered v3 backend from snapshot","backend-size-bytes":357355520,"backend-size":"357 MB","backend-size-in-use-bytes":35020800,"backend-size-in-use":"35 MB"}
Can you show the output of:
du -khs /var/lib/rancher/rke2/server/db/etcd/df -kh /var/lib/rancher/rke2/server/db/etcd/Also, if you can attach those logs instead of pasting them inline, my life would be much easier.
ssmall
commented
2 years ago My /etc/systemd/system/k3s.service now has:
ExecStart=/usr/local/bin/k3s \
server \
'--server' \
'https://192.168.1.31:6443' \
'--disable' \
'servicelb,traefik' \
'--debug' \
'--etcd-arg=quota-backend-bytes=8589934592'so I'm not sure why it's going back to the default quota, unless there is a typo in there somewhere (I have looked it over a couple times and it looks good to me but maybe fresh eyes will catch the issue)
Here is the output of the requested commands. All looks reasonable to me:
$ sudo du -khs /var/lib/rancher/k3s/server/db/etcd/
771M /var/lib/rancher/k3s/server/db/etcd/
$ sudo df -kh /var/lib/rancher/k3s/server/db/etcd/
Filesystem Size Used Avail Use% Mounted on
/dev/mapper/vg1-var 29G 15G 13G 54% /varAlso, if you can attach those logs instead of pasting them inline, my life would be much easier.
Roger that, will do.
brandond
commented
2 years ago Yeah, it sure looks like it's not loading the argument.
mdrahman-suse
commented
2 years ago Reproduced the issue in k3s with version v1.23.4+k3s1
curl -sfL https://get.k3s.io | INSTALL_K3S_SKIP_START=true INSTALL_K3S_VERSION=v1.23.4+k3s1 sh -sudo k3s server --cluster-init --etcd-arg=quota-backend-bytes=$((1*1024*1024))...
{"level":"info","ts":"2022-03-23T14:10:05.512Z","caller":"etcdserver/quota.go:117","msg":"enabled backend quota","quota-name":"v3-applier","quota-size-bytes":1048576,"quota-size":"1.0 MB"}
...
{"level":"warn","ts":"2022-03-23T14:10:29.317Z","caller":"etcdserver/apply.go:737","msg":"alarm raised","alarm":"NOSPACE","from":"30bcbaaff266920a"}
{"level":"warn","ts":"2022-03-23T14:10:29.317Z","logger":"etcd-client","caller":"v3@v3.5.1-k3s1/retry_interceptor.go:62","msg":"retrying of unary invoker failed","target":"etcd-endpoints://0xc001a428c0/127.0.0.1:2379","attempt":0,"error":"rpc error: code = ResourceExhausted desc = etcdserver: mvcc: database space exceeded"}
E0323 14:10:29.317817 19730 status.go:71] apiserver received an error that is not an metav1.Status: rpctypes.EtcdError{code:0x8, desc:"etcdserver: mvcc: database space exceeded"}: etcdserver: mvcc: database space exceeded
FATA[0024] flannel exited: failed to acquire lease: etcdserver: mvcc: database space exceededsudo k3s server --cluster-init --etcd-arg=quota-backend-bytes=$((1024*1024*1024))...
{"level":"info","ts":"2022-03-23T14:11:06.781Z","caller":"etcdserver/quota.go:117","msg":"enabled backend quota","quota-name":"v3-applier","quota-size-bytes":1073741824,"quota-size":"1.1 GB"}
...
{"level":"warn","ts":"2022-03-23T14:11:22.373Z","logger":"etcd-client","caller":"v3@v3.5.1-k3s1/retry_interceptor.go:62","msg":"retrying of unary invoker failed","target":"etcd-endpoints://0xc000ca7880/127.0.0.1:2379","attempt":0,"error":"rpc error: code = ResourceExhausted desc = etcdserver: mvcc: database space exceeded"}
panic: etcdserver: mvcc: database space exceededVerified the fix in k3s with v1.23.5-rc1+k3s1
curl -sfL https://get.k3s.io | INSTALL_K3S_SKIP_START=true INSTALL_K3S_VERSION=v1.23.5-rc1+k3s1 sh -sudo k3s server --cluster-init --etcd-arg=quota-backend-bytes=$((1*1024*1024))...
{"level":"info","ts":"2022-03-23T14:12:34.471Z","caller":"etcdserver/quota.go:117","msg":"enabled backend quota","quota-name":"v3-applier","quota-size-bytes":1048576,"quota-size":"1.0 MB"}
...
{"level":"warn","ts":"2022-03-23T14:12:58.063Z","logger":"etcd-client","caller":"v3@v3.5.1-k3s1/retry_interceptor.go:62","msg":"retrying of unary invoker failed","target":"etcd-endpoints://0xc00140ba40/127.0.0.1:2379","attempt":0,"error":"rpc error: code = ResourceExhausted desc = etcdserver: mvcc: database space exceeded"}
E0323 14:12:58.064279 20464 status.go:71] apiserver received an error that is not an metav1.Status: rpctypes.EtcdError{code:0x8, desc:"etcdserver: mvcc: database space exceeded"}: etcdserver: mvcc: database space exceeded
FATA[0023] flannel exited: failed to acquire lease: etcdserver: mvcc: database space exceededsudo k3s server --cluster-init --etcd-arg=quota-backend-bytes=$((1024*1024*1024)){"level":"info","ts":"2022-03-23T14:13:06.434Z","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"}Please advice on this observation @brandond
brandond
commented
2 years ago @mdrahman-suse if you're restarting a node with an existing datastore, we actually start etcd twice. The initial temporary standalone etcd uses a very minimal configuration to extract the bootstrap data, and then we start up another copy with the permanent configuration. Can you confirm that you're looking at the logs from the second etcd startup?
{"level":"info","ts":"2022-03-23T18:03:00.924Z","caller":"embed/etcd.go:307","msg":"starting an etcd server","etcd-version":"3.5.1","git-sha":"Not provided (use ./build instead of go build)","go-version":"go1.17.5","go-os":"linux","go-arch":"amd64","max-cpu-set":8,"max-cpu-available":8,"member-initialized":true,"name":"k3s-server-1-4b4242bb","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":100000,"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":false,"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":"2022-03-23T18:03:00.957Z","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":"2022-03-23T18:03:07.961Z","caller":"embed/etcd.go:307","msg":"starting an etcd server","etcd-version":"3.5.1","git-sha":"Not provided (use ./build instead of go build)","go-version":"go1.17.5","go-os":"linux","go-arch":"amd64","max-cpu-set":8,"max-cpu-available":8,"member-initialized":true,"name":"k3s-server-1-4b4242bb","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://172.17.0.2:2380"],"advertise-client-urls":["https://172.17.0.2:2379"],"listen-client-urls":["https://127.0.0.1:2379","https://172.17.0.2: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":1073741824,"pre-vote":true,"initial-corrupt-check":false,"corrupt-check-time-interval":"0s","auto-compaction-mode":"","auto-compaction-retention":"0s","auto-compaction-interval":"0s","discovery-url":"","discovery-proxy":"","downgrade-check-interval":"5s"}Note that the initial startup has the default quota, and a temporary data-dir: "data-dir":"/var/lib/rancher/k3s/server/db/etcd-tmp". The second has the configured quota and non-temporary data-dir. This is expected.
mdrahman-suse
commented
2 years ago Thanks @brandond for the details, I was able to validate the argument is being read correctly
sudo k3s server --cluster-init --etcd-arg=quota-backend-bytes=$((5*1024*1024*1024)){"level":"info","ts":"2022-03-23T23:32:15.964Z","caller":"etcdserver/quota.go:117","msg":"enabled backend quota","quota-name":"v3-applier","quota-size-bytes":5368709120,"quota-size":"5.4 GB"}It looks like this issue has been closed but I have not been able to restore my existing cluster to a working state after the size of the etcd database exceeded its original limits. Can we re-open this issue or do I need to open a separate one to continue getting assistance?
brandond
commented
2 years ago The last we left off it looked like you weren't starting the service with an acceptable quota value. We're you able to verify that you're setting the correct value in the systemd unit?
ssmall
commented
2 years ago The last we left off it looked like you weren't starting the service with an acceptable quota value. We're you able to verify that you're setting the correct value in the systemd unit?
I don't think that's true, at least to my recollection and what I see here in the comment history. Have a look at https://github.com/k3s-io/k3s/issues/4787#issuecomment-1071922908 and let me know if there's anything wrong with the arguments listed there.
brandond
commented
2 years ago The arguments looks fine, but I'm not sure it's being used. You're sure you did a systemctl daemon-reload before restarting the k3s service? I can't see any way what you're reporting would be happening, other than systemd just not passing the updated arg.
ssmall
commented
2 years ago Yes, I'm certain. I even did a full reboot of the node just to be sure.
You mentioned previously that when k3s starts it uses a temporary etcd instance with a default quota -- is it possible that it's somehow failing at that stage before applying the quota arg I have provided? (Just speculating here since I don't have anything more to go on than what I've already provided)
ssmall
commented
2 years ago It's also suspicious to me that the error now only occurs when I try to start up the second master node (with the same args). Is there something about the etcd cluster synchronization that is not respecting the custom quota?
brandond
commented
2 years ago I think the last logs I saw from you still had the quota set to 10GB. Lets go back to that other issue to follow up on this discussion - can you attach the most recent startup logs from all the etcd nodes to a new comment over on that issue?
ssmall
commented
2 years ago I think the last logs I saw from you still had the quota set to 10GB. Lets go back to that other issue to follow up on this discussion - can you attach the most recent startup logs from all the etcd nodes to a new comment over on that issue?
Sorry, what other issue?
ssmall
commented
2 years ago Please see logs in https://github.com/k3s-io/k3s/issues/4787#issuecomment-1071901452 -- I already adjusted the quota size back to 8GiB as you had previously requested and included new logs. Seems like maybe you've lost some context on where we were with this investigation in the intervening days? Might be worth looking back over the comment history on this issue.
chenxb0715
commented
1 year ago --etcd-arg
but the version v1.19.5+k3s1 didnt hava --etcd-arg parameter
brandond
commented
1 year ago @chenxb0715 v1.19.5 is over two years old. Please upgrade to a supported release - currently 1.23 or newer.
Also, please keep your conversation in the discussion thread, instead of adding on to this closed issue.
Describe the bug: When you ran k3s long enough with etcd store, you are probably going to see this:
Steps To Reproduce: Find a k3s server with large enough etcd store
Expected behavior: k3s should automatically compact etcd store and continue as usual; if not, start a emergency etcd server that allow the operators to do some rescue work.
Actual behavior: It just crash, so I can't even do manual compaction myself
Backporting