qsyqian
commented
2 months ago The second test.
Before test, compact & defrag to set the cluster to origin state.
Then send the same requests (qps and kv size) , snapshot to one etcd member. Make sure the snapshot process doesn't contain the compact operations. This is the only different.
Then see the logs. (Contains the next compact log after the snapshot operation).
Logs for etcd0:
{"level":"info","ts":"2024-08-27T09:16:00.041086Z","caller":"v3rpc/maintenance.go:126","msg":"sending database snapshot to client","total-bytes":20992471040,"size":"21 GB"}
{"level":"info","ts":"2024-08-27T09:17:51.627652Z","caller":"v3rpc/maintenance.go:166","msg":"sending database sha256 checksum to client","total-bytes":20992471040,"checksum-size":32}
{"level":"info","ts":"2024-08-27T09:17:51.627695Z","caller":"v3rpc/maintenance.go:175","msg":"successfully sent database snapshot to client","total-bytes":20992471040,"size":"21 GB","took":"1 minute ago"}
{"level":"info","ts":"2024-08-27T09:18:18.985499Z","caller":"etcdserver/server.go:1443","msg":"triggering snapshot","local-member-id":"236527662c6439af","local-member-applied-index":2600026,"local-member-snapshot-index":2500025,"local-member-snapshot-count":100000}
{"level":"info","ts":"2024-08-27T09:18:18.998421Z","caller":"etcdserver/server.go:2462","msg":"saved snapshot","snapshot-index":2600026}
{"level":"info","ts":"2024-08-27T09:18:18.998523Z","caller":"etcdserver/server.go:2492","msg":"compacted Raft logs","compact-index":2595026}
{"level":"info","ts":"2024-08-27T09:19:15.782916Z","caller":"mvcc/index.go:214","msg":"compact tree index","revision":2512762}
{"level":"info","ts":"2024-08-27T09:19:19.905582Z","caller":"mvcc/kvstore_compaction.go:68","msg":"finished scheduled compaction","compact-revision":2512762,"took":"4.122138217s","hash":2429156478,"current-db-size-bytes":20992471040,"current-db-size":"21 GB","current-db-size-in-use-bytes":10456432640,"current-db-size-in-use":"10 GB"}
{"level":"info","ts":"2024-08-27T09:19:19.905617Z","caller":"mvcc/hash.go:137","msg":"storing new hash","hash":2429156478,"revision":2512762,"compact-revision":2423174}Logs for etcd1:
{"level":"info","ts":"2024-08-27T09:19:15.7752Z","caller":"v3compactor/periodic.go:134","msg":"starting auto periodic compaction","revision":2512762,"compact-period":"5m0s"}
{"level":"info","ts":"2024-08-27T09:19:15.781344Z","caller":"mvcc/index.go:214","msg":"compact tree index","revision":2512762}
{"level":"info","ts":"2024-08-27T09:19:15.781408Z","caller":"v3compactor/periodic.go:142","msg":"completed auto periodic compaction","revision":2512762,"compact-period":"5m0s","took":"6.179178ms"}
{"level":"info","ts":"2024-08-27T09:19:19.785217Z","caller":"mvcc/kvstore_compaction.go:68","msg":"finished scheduled compaction","compact-revision":2512762,"took":"4.003381407s","hash":2429156478,"current-db-size-bytes":21074321408,"current-db-size":"21 GB","current-db-size-in-use-bytes":10453090304,"current-db-size-in-use":"10 GB"}
{"level":"info","ts":"2024-08-27T09:19:19.785252Z","caller":"mvcc/hash.go:137","msg":"storing new hash","hash":2429156478,"revision":2512762,"compact-revision":2423174}Logs for etcd2:
{"level":"info","ts":"2024-08-27T09:19:15.786751Z","caller":"mvcc/index.go:214","msg":"compact tree index","revision":2512762}
{"level":"info","ts":"2024-08-27T09:19:20.210784Z","caller":"mvcc/kvstore_compaction.go:68","msg":"finished scheduled compaction","compact-revision":2512762,"took":"4.423434677s","hash":2429156478,"current-db-size-bytes":20979462144,"current-db-size":"21 GB","current-db-size-in-use-bytes":10466041856,"current-db-size-in-use":"10 GB"}
{"level":"info","ts":"2024-08-27T09:19:20.210829Z","caller":"mvcc/hash.go:137","msg":"storing new hash","hash":2429156478,"revision":2512762,"compact-revision":2423174}As we can see, nothing is strange. And the db size is all same.
endpoint status -w table
+---------------------------------------------------------------+------------------+---------+---------+-----------+------------+-----------+------------+--------------------+--------+
| ENDPOINT | ID | VERSION | DB SIZE | IS LEADER | IS LEARNER | RAFT TERM | RAFT INDEX | RAFT APPLIED INDEX | ERRORS |
+---------------------------------------------------------------+------------------+---------+---------+-----------+------------+-----------+------------+--------------------+--------+
| https://etcd0.etcd.svc:2379 | 236527662c6439af | 3.5.13 | 21 GB | false | false | 8 | 2798807 | 2798806 | |
| https://etcd1.etcd.svc:2379 | fdd1098ba1bb471 | 3.5.13 | 21 GB | true | false | 8 | 2798812 | 2798812 | |
| https://etcd2.etcd.svc:2379 | 25b4ff1e9b1f0b1b | 3.5.13 | 21 GB | false | false | 8 | 2798815 | 2798814 | |
+---------------------------------------------------------------+------------------+---------+---------+-----------+------------+-----------+------------+--------------------+--------+endpoint status -w json
[{"Endpoint":"https://etcd0.etcd.svc:2379","Status":{"header":{"cluster_id":8776373056027032411,"member_id":2550488083760167343,"revision":2803148,"raft_term":8},"version":"3.5.13","dbSize":20992471040,"leader":1143088128565425265,"raftIndex":2808853,"raftTerm":8,"raftAppliedIndex":2808853,"dbSizeInUse":11611930624}},{"Endpoint":"https://etcd1.etcd.svc:2379","Status":{"header":{"cluster_id":8776373056027032411,"member_id":1143088128565425265,"revision":2803151,"raft_term":8},"version":"3.5.13","dbSize":21074321408,"leader":1143088128565425265,"raftIndex":2808856,"raftTerm":8,"raftAppliedIndex":2808856,"dbSizeInUse":11611930624}},{"Endpoint":"https://etcd2.etcd.svc:2379","Status":{"header":{"cluster_id":8776373056027032411,"member_id":2717076982127856411,"revision":2803153,"raft_term":8},"version":"3.5.13","dbSize":20979462144,"leader":1143088128565425265,"raftIndex":2808861,"raftTerm":8,"raftAppliedIndex":2808858,"dbSizeInUse":11612975104}}]It seems that only the snapshot operation duration contains one compact operation could lead to the db of this member grow up.
olderTaoist
ahrtr
ivanvc
Bug report criteria
What happened?
When snapshot one etcd cluster and i found that the compact does not effect.
Metrics for db and db_in_use:
Snapshot to the etcd0 member, and we can see the etcd0's compaction take effect delayed.
Logs for etcd0: (Please note that the log time should plus 8 for metrics time)
We can see that, after the compaction in time 29:13, the db_inuse is about
"current-db-size-in-use-bytes":19744907264,"current-db-size-in-use":"20 GB".Logs for etcd1:
Logs for etcd2:
For etcd1 and etcd2, after compaction in time 29:13, the db_inuse is about
"current-db-size-in-use-bytes":10467917824,"current-db-size-in-use":"10 GB".The more important is that, after this, the db total size for etcd0 is grow up. Please ignore the db_inuse size, it is because the client stop update and put keys.
What did you expect to happen?
the compact should take effect during snapshot.
How can we reproduce it (as minimally and precisely as possible)?
Anything else we need to know?
auto compaction params:
Etcd version (please run commands below)
v3.5.13
Etcd configuration (command line flags or environment variables)
Etcd debug information (please run commands below, feel free to obfuscate the IP address or FQDN in the output)
Relevant log output
No response