How to fix "failed: ciphertext verification failed" running 'restic 'prune'

rseffner · December 29, 2020, 3:13am

Hi, I got an repo with following error running “restic prune” (ver 0.11.0, no beta). What to do to “fix” it without another repo-like-sized temp space?

root@host ~ # restic prune
repository 38d9a80c opened successfully, password is correct
counting files in repo
building new index for repo
[1:47] 100.00%  110916 / 110916 packs
incomplete pack file (will be removed): efa095698e940aab1ca53b41a5dec689d2f9ee36a0138b81b58a0d4a7b78a065
incomplete pack file (will be removed): 0957c2545e0c867525349258cc60da70055e5fdf2a9da16d6d7d56d2739bf4cd
repository contains 110914 packs (1997873 blobs) with 522.897 GiB
processed 1997873 blobs: 881 duplicate blobs, 522.512 MiB duplicate
load all snapshots
find data that is still in use for 18 snapshots
[0:47] 83.33%  15 / 18 snapshots
decrypting blob 160f22e79aba064cef867c30b0b9c84b5ac56937a8b4616b93d570c4fe7e1cfe failed: ciphertext verification failed
github.com/restic/restic/internal/repository.(*Repository).LoadBlob
        /restic/internal/repository/repository.go:198
github.com/restic/restic/internal/repository.(*Repository).LoadTree
        /restic/internal/repository/repository.go:723
github.com/restic/restic/internal/restic.FindUsedBlobs
        /restic/internal/restic/find.go:19
github.com/restic/restic/internal/restic.FindUsedBlobs
        /restic/internal/restic/find.go:31
github.com/restic/restic/internal/restic.FindUsedBlobs
        /restic/internal/restic/find.go:31
github.com/restic/restic/internal/restic.FindUsedBlobs
        /restic/internal/restic/find.go:31
github.com/restic/restic/internal/restic.FindUsedBlobs
        /restic/internal/restic/find.go:31
github.com/restic/restic/internal/restic.FindUsedBlobs
        /restic/internal/restic/find.go:31
github.com/restic/restic/internal/restic.FindUsedBlobs
        /restic/internal/restic/find.go:31
main.getUsedBlobs
        /restic/cmd/restic/cmd_prune.go:276
main.pruneRepository
        /restic/cmd/restic/cmd_prune.go:158
main.runPrune
        /restic/cmd/restic/cmd_prune.go:62
main.glob..func19
        /restic/cmd/restic/cmd_prune.go:27
github.com/spf13/cobra.(*Command).execute
        /home/build/go/pkg/mod/github.com/spf13/cobra@v0.0.5/command.go:826
github.com/spf13/cobra.(*Command).ExecuteC
        /home/build/go/pkg/mod/github.com/spf13/cobra@v0.0.5/command.go:914
github.com/spf13/cobra.(*Command).Execute
        /home/build/go/pkg/mod/github.com/spf13/cobra@v0.0.5/command.go:864
main.main
        /restic/cmd/restic/main.go:98
runtime.main
        /usr/local/go/src/runtime/proc.go:204
runtime.goexit
        /usr/local/go/src/runtime/asm_amd64.s:1374

regards, Ronny

rseffner · December 28, 2020, 3:03pm

another try with current beta

root@host ~ # ./restic_v0.11.0-221-g9c41e4a3_linux_amd64 prune
repository 38d9a80c opened successfully, password is correct
loading indexes...
loading all snapshots...
finding data that is still in use for 18 snapshots
[0:48] 88.89%  16 / 18 snapshots
decrypting blob 160f22e79aba064cef867c30b0b9c84b5ac56937a8b4616b93d570c4fe7e1cfe failed: ciphertext verification failed
github.com/restic/restic/internal/repository.(*Repository).LoadBlob
        /home/beta/restic.git/internal/repository/repository.go:204
github.com/restic/restic/internal/repository.(*Repository).LoadTree
        /home/beta/restic.git/internal/repository/repository.go:793
github.com/restic/restic/internal/restic.FindUsedBlobs
        /home/beta/restic.git/internal/restic/find.go:19
github.com/restic/restic/internal/restic.FindUsedBlobs
        /home/beta/restic.git/internal/restic/find.go:31
github.com/restic/restic/internal/restic.FindUsedBlobs
        /home/beta/restic.git/internal/restic/find.go:31
github.com/restic/restic/internal/restic.FindUsedBlobs
        /home/beta/restic.git/internal/restic/find.go:31
github.com/restic/restic/internal/restic.FindUsedBlobs
        /home/beta/restic.git/internal/restic/find.go:31
github.com/restic/restic/internal/restic.FindUsedBlobs
        /home/beta/restic.git/internal/restic/find.go:31
github.com/restic/restic/internal/restic.FindUsedBlobs
        /home/beta/restic.git/internal/restic/find.go:31
main.getUsedBlobs
        /home/beta/restic.git/cmd/restic/cmd_prune.go:552
main.runPruneWithRepo
        /home/beta/restic.git/cmd/restic/cmd_prune.go:168
main.runPrune
        /home/beta/restic.git/cmd/restic/cmd_prune.go:151
main.glob..func19
        /home/beta/restic.git/cmd/restic/cmd_prune.go:35
github.com/spf13/cobra.(*Command).execute
        /home/beta/go/pkg/mod/github.com/spf13/cobra@v0.0.5/command.go:826
github.com/spf13/cobra.(*Command).ExecuteC
        /home/beta/go/pkg/mod/github.com/spf13/cobra@v0.0.5/command.go:914
github.com/spf13/cobra.(*Command).Execute
        /home/beta/go/pkg/mod/github.com/spf13/cobra@v0.0.5/command.go:864
main.main
        /home/beta/restic.git/cmd/restic/main.go:98
runtime.main
        /usr/local/go/src/runtime/proc.go:204
runtime.goexit
        /usr/local/go/src/runtime/asm_amd64.s:1374

gurkan · December 28, 2020, 2:52pm

Did you by any chance copied/moved some snapshots between repositories? Or added/removed keys for this repo?

Restic can’t decrypt which might mean these snapshots have created with a different key.

fd0 · December 28, 2020, 3:06pm

We’ve had a report recently about a memory corruption issue on Linux 5.3.1:

The list of safe (fixed) kernel versions is roughly: 5.3.15+, 5.4.2+, or 5.5+

Which kernel do you run?
Can you run restic check --read-data?

rseffner · December 28, 2020, 3:15pm

@gurkan : 100% sure - one repo, no key changes

rseffner · December 28, 2020, 5:42pm

Hi @fd0,

it seems not 5.3.1 related, because:

root@host ~ # uname -a
Linux host 4.15.0-128-generic #131-Ubuntu SMP Wed Dec 9 06:57:35 UTC 2020 x86_64 x86_64 x86_64 GNU/Linux

restic check --read-data ist already running in a screen-terminal

root@host ~ # ./restic_v0.11.0-221-g9c41e4a3_linux_amd64 check --read-data
using temporary cache in /tmp/restic-check-cache-279017305
repository 38d9a80c opened successfully, password is correct
created new cache in /tmp/restic-check-cache-279017305
create exclusive lock for repository
load indexes
check all packs
pack efa09569: not referenced in any index
pack 0957c254: not referenced in any index
2 additional files were found in the repo, which likely contain duplicate data.
You can run `restic prune` to correct this.
check snapshots, trees and blobs
read all data
pack db62e92e contains 1 errors: [Blob ID does not match, want d0e1c37c, got bf7862f6]
pack 155e4ef2 contains 1 errors: [Blob ID does not match, want a23fc996, got 17143d0a]
[57:40] 26.21%  29073 / 110914 packs

fd0 · December 28, 2020, 5:52pm

Ok, thanks for the confirmation. I don’t know how that happened, the error you’re seeing from check (Blob ID does not match) means that restic tries to decrypt a part of a file, but after decryption it found different data than the one it expects. This is very odd, as the encrypted data is signed, and the signature is correct and matches, and also the name of the file matches its hash.

The other error from prune (ciphertext verification failed) means restic detected modification in the encrypted data. This can happen for example when memory or disk fails and there’s a bit flip. It wouldn’t be the first time restic uncovered hardware issues

Let’s see what errors check returns. We should see both errors there.

You can find the snapshots which reference the data as follows for each ID (e.g. for d0e1c37c):

Find the long ID: restic list blobs | grep d0e1c37c
Find all snapshots which reference the data: restic find --blob <long ID>

Maybe you can see a pattern (a host or time range which is affected).

If you want to repair the repo, you can then go ahead and the remove the affected snapshots with restic forget <id> <id2> [...] and then run prune again

cdhowie · December 29, 2020, 3:15am

I would also strongly suggest immediately powering down this machine and running a full 24-hour cycle of memtest86+ on it. If a memory issue is present, you don’t want this machine to continue doing anything until you can correct that problem, or you risk further corruption on any disk attached to this machine.

rseffner · December 29, 2020, 8:45am

@cdhowie thanks for your hints. after a lot of tests I’ll trust in my server but not in the cloud storage. All I want now is to fix my repo so my script (backup + forget/prune + check) is working again without errors.

rseffner · December 29, 2020, 9:51am

@fd0 thats the results of restic check --read-data

root@mein-traumtag ~ # ./restic_v0.11.0-221-g9c41e4a3_linux_amd64 check --read-data
using temporary cache in /tmp/restic-check-cache-279017305
repository 38d9a80c opened successfully, password is correct
created new cache in /tmp/restic-check-cache-279017305
create exclusive lock for repository
load indexes
check all packs
pack efa09569: not referenced in any index
pack 0957c254: not referenced in any index
2 additional files were found in the repo, which likely contain duplicate data.
You can run `restic prune` to correct this.
check snapshots, trees and blobs
read all data
pack db62e92e contains 1 errors: [Blob ID does not match, want d0e1c37c, got bf7862f6]
pack 155e4ef2 contains 1 errors: [Blob ID does not match, want a23fc996, got 17143d0a]
Pack ID does not match, want 2f3ddb28, got b35d16ef
Pack ID does not match, want c8efffd6, got 41459b40
Pack ID does not match, want 08e9e4b9, got 43c39d0d
[3:39:35] 100.00%  110914 / 110914 packs
Fatal: repository contains errors

rseffner · December 29, 2020, 9:56am

@fd0 while following your hints to find snapshots containing this blob I have to forget all my snapshots. Because this blob touches only one unnecessary file so I’ld like to see a function to forget/prune single files or blobs to keep backups in case of one switched bit in the backend. But maybe this is not possible because of the way restic do its things.

fd0 · December 29, 2020, 9:57am

Ok, that’s what I though, we see the two types of errors.

Did you always run restic on the machine you trusted? The Pack ID does not match error can be caused by data modified at rest in the backend, but for the Blob ID does not match error I can’t imagine how that’d be caused by data modified in the backend. It’s quite deep within restic’s data structures and producing the error requires having the encryption key.

In general, we’ve seen the Blob ID does not match error several times. Sometimes it was caused by the kernel bug I mentioned earlier. Other times, faulty hardware was found (e.g. bad memory). I also cannot completely rule out a bug in restic which may have caused this.

fd0 · December 29, 2020, 9:57am

In general, yes, this could be improved a lot. We’ll probably do something like that sometime

MichaelEischer · December 29, 2020, 10:47pm

There’s already experimental code available for repair this kind of damage. It just requires a lot of work by hand (and finding the places where the instructions are posted).

With the ids of the damaged pack files it would be possible to follow the instructions at Hash does not match id during prune · Issue #1999 · restic/restic · GitHub to recover as much data as possible. And the experimental PR Add repair command by aawsome · Pull Request #2876 · restic/restic · GitHub could help with removing still broken files / folders from a snapshot.

The Blob ID does not match can only happen somewhere between chunking the files to backup and encryption that data. The affected blob must be corrupted after/while calculating the blob hash and encrypting the blob data. Both steps happen nearly immediately after each other in Repository.SaveBlob. So at this point only the CPU and memory of the host creating the backup are involved.

rseffner · January 28, 2021, 11:23am

Meanwhile we got other consistency error on this server so we replaced the RAM and everything works again.