restic: Crash bug in prune

Output of restic version

restic 0.9.2 compiled with go1.10.4 on linux/amd64

How did you run restic exactly?

restic -vvvvv prune

(with the following environment variables:)

XDG_CACHE_HOME=/mnt/backups/manual/restic_caches
RESTIC_PASSWORD_FILE="/etc/restic/restic-pw.txt"
B2_ACCOUNT_ID="{private stuff}"
B2_ACCOUNT_KEY="{more private stuff}"
B2_CONNECTIONS=10
RESTIC_REPOSITORY="b2:dude-backups-automatic"
RETENTION_DAYS=14
RETENTION_WEEKS=1
RETENTION_MONTHS=12
RETENTION_YEARS=5
BACKUP_PATHS="/mnt/backups/automatic"
BACKUP_EXCLUDES="--exclude-file /mnt/backups/automatic/.backup_exclude"
BACKUP_TAG=systemd.timer

What backend/server/service did you use to store the repository?

Backblaze B2

Expected behavior

Restic is reporting that my repo has errors or is damaged, and suggests running ‘prune’:

# restic -vvv check
pack 4b0119b9: not referenced in any index
pack c6dd3096: not referenced in any index
pack 6d1feec0: not referenced in any index
pack a8559f97: not referenced in any index
{ many hundreds of similar messages }
pack 4c25ee20: not referenced in any index
pack 9464bd60: not referenced in any index
pack aca11b78: not referenced in any index
62435 additional files were found in the repo, which likely contain duplicate data.
62435 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
error for tree bbf3cce6:
  tree bbf3cce6b4e9f127b04a0c226ce4fd4d2fb8a5962f77f67f06ce827218589115 not found in repository
error for tree 86f4ea98:
  tree 86f4ea9847c8662f7314e93b2ac95cfc18819061d206c330459ef91a51684dda not found in repository
error for tree 9e75689a:
  tree 9e75689a13b7be36a60b2bfc347415d2ddd90fb6b77bc7852ddec37001515d14 not found in repository
error for tree ab8d0a26:
  tree ab8d0a262700d457997b95fb9beaf48e684b9a5ae3df715a0fd4bee5fbb270de not found in repository
error for tree 77b4cad7:
  tree 77b4cad7dfc01f7473d47e62e0150c40f859ae6f60708fcfe17512550640625d not found in repository
error for tree 99874edd:
  tree 99874edd1701a33733234c6ee8766135dba00a4d9a6401c0dee5f0ab0b3798d2 not found in repository
Fatal: repository contains errors

Actual behavior

Restic crashes during a ‘prune’ operation. It produces lots of errors during ‘check’:

# restic -vvvvv prune
repository 29eb829d opened successfully, password is correct
counting files in repo
building new index for repo
[5:13:31] 100.00%  122024 / 122024 packs
repository contains 122024 packs (831980 blobs) with 587.437 GiB
processed 831980 blobs: 266660 duplicate blobs, 205.001 GiB duplicate
load all snapshots
find data that is still in use for 24 snapshots
tree bbf3cce6b4e9f127b04a0c226ce4fd4d2fb8a5962f77f67f06ce827218589115 not found in repository
github.com/restic/restic/internal/repository.(*Repository).LoadTree
        /build/restic-eUvzEK/restic-0.9.2+ds/obj-x86_64-linux-gnu/src/github.com/restic/restic/internal/repository/repository.go:654
github.com/restic/restic/internal/restic.FindUsedBlobs
        /build/restic-eUvzEK/restic-0.9.2+ds/obj-x86_64-linux-gnu/src/github.com/restic/restic/internal/restic/find.go:11
main.pruneRepository
        /build/restic-eUvzEK/restic-0.9.2+ds/obj-x86_64-linux-gnu/src/github.com/restic/restic/cmd/restic/cmd_prune.go:191
main.runPrune
        /build/restic-eUvzEK/restic-0.9.2+ds/obj-x86_64-linux-gnu/src/github.com/restic/restic/cmd/restic/cmd_prune.go:85
main.glob..func18
        /build/restic-eUvzEK/restic-0.9.2+ds/obj-x86_64-linux-gnu/src/github.com/restic/restic/cmd/restic/cmd_prune.go:25
github.com/spf13/cobra.(*Command).execute
        /build/restic-eUvzEK/restic-0.9.2+ds/obj-x86_64-linux-gnu/src/github.com/spf13/cobra/command.go:762
github.com/spf13/cobra.(*Command).ExecuteC
        /build/restic-eUvzEK/restic-0.9.2+ds/obj-x86_64-linux-gnu/src/github.com/spf13/cobra/command.go:852
github.com/spf13/cobra.(*Command).Execute
        /build/restic-eUvzEK/restic-0.9.2+ds/obj-x86_64-linux-gnu/src/github.com/spf13/cobra/command.go:800
main.main
        /build/restic-eUvzEK/restic-0.9.2+ds/obj-x86_64-linux-gnu/src/github.com/restic/restic/cmd/restic/main.go:86
runtime.main
        /usr/lib/go-1.10/src/runtime/proc.go:198
runtime.goexit
        /usr/lib/go-1.10/src/runtime/asm_amd64.s:2361

I’ve been seeing this trace in my logs from systemd. I manually ran the commands, and during ‘check’ it said that my repo was damaged. So I manually ran prune, and got the same traceback.

The repo is about 630.8GB according to the control panel at B2. The data it’s backing up is only about 266G, so prune has been failing for a while. The data changes extremely rarely, and when it does, it’s just kilo- or mega- bytes at a time.

Steps to reproduce the behavior

I can’t deduce what’s gone wrong. I’ve looked into some of the snapshots, doesn’t seem like there’s much wrong.

Do you have any idea what may have caused this?

I’ve seen some other bug discussions about memory use; I have an old box, but I watched as ‘prune’ ran, and it only ever ate about 4% of RAM.

Do you have an idea how to solve the issue?

Did restic help you or made you happy in any way?

I’m very happy with restic, and came to it after much research and reading. I’m no pro, but I’m grateful to have such good tools.