【release-3.5.4】The damaged db file contains key information after power failure and restart, but no key can be obtained using etcdctl command or bblot

[Niceies]

Bug report criteria

• This bug report is not security related, security issues should be disclosed privately via etcd maintainers.
• This is not a support request or question, support requests or questions should be raised in the etcd discussion forums.
• You have read the etcd bug reporting guidelines.
• Existing open issues along with etcd frequently asked questions have been checked and this is not a duplicate.

What happened?

My single-node etcd cluster (k8s) lost power and the files were damaged. After restoring, I found that all the keys could not be obtained, but the key contents could be seen from the files.

Using etcdctl and bblot to check, the key cannot be obtained

What did you expect to happen?

The key in the file content can be obtained normally

How can we reproduce it (as minimally and precisely as possible)?

Occasional phenomena may be difficult to reproduce

Anything else we need to know?

No response

Etcd version (please run commands below)

$ etcd --version
# paste output here

$ etcdctl version
# paste output here

Etcd configuration (command line flags or environment variables)

paste your configuration here

Etcd debug information (please run commands below, feel free to obfuscate the IP address or FQDN in the output)

$ etcdctl member list -w table
# paste output here

$ etcdctl --endpoints=<member list> endpoint status -w table
# paste output here

Relevant log output

[Niceies]

I used the bbolt command to check the page and it seems that there are indeed many buckets.

./bbolt pages /tmp/etcd/member/snap/db
ID TYPE ITEMS OVRFLW
======== ========== ====== ======
0 meta 0
1 meta 0
2 leaf 3
3 free
4 free
5 free
6 free
7 free
8 free
9 free
10 free
11 free
12 free
13 free
14 free
15 free
16 free
17 free
18 free
19 free
20 free
21 free
22 free
23 free
24 free
25 free
26 free
27 free
28 free
... free

[ivanvc]

Discussed during our bi-weekly triage meeting. @ahrtr, would you be able to help with this? We think you're the best one that could be able to help here.

@Niceies, also noting that you're running an old etcd version. I suggest trying to run a newer version.

[ahrtr]

Thanks for raising this discussion topic.

But it is a typical negative example on how to raise issue or question.

• First, the problem description is vague, and I couldn't clearly understand what the issue is from the user's perspective.

After restoring, I found that all the keys could not be obtained,

Please elaborate what does all the keys could not be obtained mean, what's the exact commands/steps you did what made you get this conclusion?

but the key contents could be seen from the files.

Please only use the official tools (i.e. etcdutl, etcdctl, bbolt etc.), do not open the binary file direclty.

• Second, please avoid posting log screenshots whenever possible; instead, attach the log directly.

Also I see something related to v3 snapshot, but you also mentioned it's single-node cluster which shouldn't send snapshot at all. Was it ever a mutti-node cluster previously? Please also try to use https://github.com/ahrtr/etcd-diagnosis to generate a report

[Niceies]

Thank you for your support。
I just want to confirm whether there is a value by opening the db file directly. The file size is 40M.
I apologize for the incomplete information I provided. Here is what I added to your request:
Startup log：
etcd.log
startup configuration

• etcd
  • --advertise-client-urls=https://10.57.1.119:2379
  • --cert-file=/etc/kubernetes/pki/etcd/server.crt
  • --client-cert-auth=true
  • --data-dir=/var/lib/etcd
  • --experimental-initial-corrupt-check=true
  • --experimental-watch-progress-notify-interval=5s
  • --initial-advertise-peer-urls=https://10.57.1.119:2380
  • --initial-cluster=master-01=https://10.57.1.119:2380
  • --key-file=/etc/kubernetes/pki/etcd/server.key
  • --listen-client-urls=https://127.0.0.1:2379,https://10.57.1.119:2379
  • --listen-metrics-urls=http://127.0.0.1:2381
  • --listen-peer-urls=https://10.57.1.119:2380
  • --name=master-01
  • --peer-cert-file=/etc/kubernetes/pki/etcd/peer.crt
  • --peer-client-cert-auth=true
  • --peer-key-file=/etc/kubernetes/pki/etcd/peer.key
  • --peer-trusted-ca-file=/etc/kubernetes/pki/etcd/ca.crt
  • --snapshot-count=5000
  • --trusted-ca-file=/etc/kubernetes/pki/etcd/ca.crt
  • --log-level=debug
    Try ways to recover：

1. ETCDCTL_API=3 ./etcdctl snapshot restore /tmp/etcd/member/snap/db
   --name master-01
   --initial-cluster "master-01=https://10.57.1.119:2380"
   --initial-cluster-token etcd-cluster
   --initial-advertise-peer-urls https://10.57.1.119:2380
   --data-dir=/etcd_data/data
   --skip-hash-check
2. https://github.com/ahrtr/etcd-issues/blob/d134cb8d07425bf3bf530e6bb509c6e6bc6e7c67/etcd/etcd-db-editor/main.go#L16-L28

These two methods can make etcd start normally, but cannot query any content
Query command used

1. ./etcdctl get '' --from-key --keys-only --endpoints=https://10.57.1.119:2379 --cacert=/etc/kubernetes/pki/etcd/ca.crt --cert=/etc/kubernetes/pki/etcd/server.crt --key=/etc/kubernetes/pki/etcd/server.key

2. Use the following code
   `func blot() {
   // Open the my.db data file in your current directory.
   // It will be created if it doesn't exist.
   db, err := bolt.Open("/var/lib/etcd/member/snap/db", 0600, nil)
   if err != nil {
   log.Fatal(err)
   }
   defer db.Close()
   db.View(func(tx *bolt.Tx) error {
   tx.ForEach(func(name []byte, b *bolt.Bucket) error {
   fmt.Println(string(name))
   fmt.Println(b)
   if b == nil {
   return nil
   }
   c := b.Cursor()

    	for k, _ := c.First(); k != nil; k, _ = c.Next() {
    		fmt.Printf("key=%s\n", k)
    	}
    	return nil
    })
    return nil
   

   })
   }

func main() {
blot()
}`
etcd startup log after recovery：
recover-etcd.log
query results

Looking forward to help
In the new iteration, we will upgrade etcd>=3.5.9 and perform regular backups of etcd. @ivanvc
However, we hope to get a clear conclusion on why this phenomenon occurs and whether it can be restored. @ahrtr

[ahrtr]

2. https://github.com/ahrtr/etcd-issues/blob/d134cb8d07425bf3bf530e6bb509c6e6bc6e7c67/etcd/etcd-db-editor/main.go#L16-L28

Looks like you might have run into the same issue #14382.

Have you tried these manual steps? Note that you don't need to execute etcdctl snapshot restore.

[Niceies]

Yes, I have tried it, but only part of the content was replied. As shown in the picture

When I run fragment compression, it reports an error, and etcd restarts
The following is the log file
etcd.log
The log shows that there are 42M, but only 205kb is actually in use

:"backend/backend.go:497","msg":"defragmenting","path":"/var/lib/etcd/member/snap/db","current-db-size-bytes":41496576,"current-db-size":"42 MB","current-db-size-in-use-bytes":204800,"current-db-size-in-use":"205 kB"}

[Niceies]

bro, is anyone looking at this issue? @ivanvc @ahrtr