failed: nonce is invalid

[MrMarble]

Hi,
I have volsync configured to run with restic on my k8s cluster, it's been running fine, but I had a problem with the NAS and had to restart it abruptly, after that, restic is failing to create backups, I've tried to follow the troubleshooting guide, but as you can see, no error is found.

Volsync logs

Starting container
VolSync restic container version: v0.8.0+501a07e
backup prune
restic 0.16.2 compiled with go1.20.11 on linux/amd64
Testing mandatory env variables
== Checking directory for content ===
== Initialize Dir =======
ID        Time                 Host        Tags        Paths
------------------------------------------------------------
625fab44  2023-11-23 07:03:23  volsync                 /data
0fa0275d  2023-11-24 07:06:17  volsync                 /data
2b93c880  2023-11-25 07:02:37  volsync                 /data
c7ad7ea0  2023-11-26 07:02:33  volsync                 /data
803f687b  2023-11-27 18:58:09  volsync                 /data
ae3912db  2023-11-27 19:52:19  volsync                 /data
cceda201  2023-11-27 20:58:27  volsync                 /data
3655d835  2023-11-27 21:59:01  volsync                 /data
9f624531  2023-11-27 22:54:10  volsync                 /data
73850e30  2023-11-27 23:49:20  volsync                 /data
1cb1b0f1  2023-11-28 00:53:26  volsync                 /data
435dbdbe  2023-11-28 01:59:58  volsync                 /data
f9a58611  2023-11-28 02:44:57  volsync                 /data
c6bf03a7  2023-11-28 16:51:51  volsync                 /data
80c1d2c9  2023-11-28 17:59:50  volsync                 /data
ba05b77a  2023-11-28 18:00:52  volsync                 /data
b3c00052  2023-11-28 22:54:24  volsync                 /data
0bc26b98  2023-11-28 23:49:57  volsync                 /data
db66904a  2023-11-29 00:58:41  volsync                 /data
b5b9d880  2023-11-29 01:54:11  volsync                 /data
ccc3c446  2023-11-29 02:59:02  volsync                 /data
5ae5c26f  2023-11-29 03:58:40  volsync                 /data
380b538b  2023-11-29 04:54:28  volsync                 /data
629add59  2023-11-29 05:58:16  volsync                 /data
656bbf85  2023-11-29 06:59:14  volsync                 /data
0d3f94b4  2023-11-29 07:59:39  volsync                 /data
634f14fb  2023-11-29 08:59:40  volsync                 /data
eb04be1e  2023-11-29 09:02:55  volsync                 /data
------------------------------------------------------------
28 snapshots
=== Starting backup ===
/data /
using parent snapshot eb04be1e
[0:10] 87.08%  8201 files 968.774 MiB, total 10049 files 1.086 GiB, 0 errors ETA 0:01
/metadata/library/c9/c9bc7b27da76ad8a48dd2cf96a7ad854/chapters/638290151045797554_69307220000.jpg
/metadata/library/c9/c9bc7b27da76ad8a48dd2cf96a7ad854/chapters/638290151045797554_73351270000.jpg

Files:           0 new, 10049 changed,     0 unmodified
Dirs:            0 new,  2779 changed,     0 unmodified
Added to the repository: 4.363 MiB (1.501 MiB stored)

processed 10049 files, 1.086 GiB in 0:11
snapshot 1cab6b36 saved
/
=== Starting forget ===
Applying Policy: keep 24 hourly, 7 daily, 5 weekly snapshots
keep 28 snapshots:
ID        Time                 Host        Tags        Reasons          Paths
-----------------------------------------------------------------------------
625fab44  2023-11-23 07:03:23  volsync                 daily snapshot   /data
                                                       weekly snapshot
0fa0275d  2023-11-24 07:06:17  volsync                 daily snapshot   /data
2b93c880  2023-11-25 07:02:37  volsync                 daily snapshot   /data
c7ad7ea0  2023-11-26 07:02:33  volsync                 daily snapshot   /data
                                                       weekly snapshot
803f687b  2023-11-27 18:58:09  volsync                 hourly snapshot  /data
ae3912db  2023-11-27 19:52:19  volsync                 hourly snapshot  /data
cceda201  2023-11-27 20:58:27  volsync                 hourly snapshot  /data
3655d835  2023-11-27 21:59:01  volsync                 hourly snapshot  /data
9f624531  2023-11-27 22:54:10  volsync                 hourly snapshot  /data
73850e30  2023-11-27 23:49:20  volsync                 hourly snapshot  /data
                                                       daily snapshot
1cb1b0f1  2023-11-28 00:53:26  volsync                 hourly snapshot  /data
435dbdbe  2023-11-28 01:59:58  volsync                 hourly snapshot  /data
f9a58611  2023-11-28 02:44:57  volsync                 hourly snapshot  /data
c6bf03a7  2023-11-28 16:51:51  volsync                 hourly snapshot  /data
80c1d2c9  2023-11-28 17:59:50  volsync                 hourly snapshot  /data
ba05b77a  2023-11-28 18:00:52  volsync                 hourly snapshot  /data
b3c00052  2023-11-28 22:54:24  volsync                 hourly snapshot  /data
0bc26b98  2023-11-28 23:49:57  volsync                 hourly snapshot  /data
                                                       daily snapshot
db66904a  2023-11-29 00:58:41  volsync                 hourly snapshot  /data
b5b9d880  2023-11-29 01:54:11  volsync                 hourly snapshot  /data
ccc3c446  2023-11-29 02:59:02  volsync                 hourly snapshot  /data
5ae5c26f  2023-11-29 03:58:40  volsync                 hourly snapshot  /data
380b538b  2023-11-29 04:54:28  volsync                 hourly snapshot  /data
629add59  2023-11-29 05:58:16  volsync                 hourly snapshot  /data
656bbf85  2023-11-29 06:59:14  volsync                 hourly snapshot  /data
0d3f94b4  2023-11-29 07:59:39  volsync                 hourly snapshot  /data
634f14fb  2023-11-29 08:59:40  volsync                 hourly snapshot  /data
1cab6b36  2023-11-29 09:14:40  volsync                 hourly snapshot  /data
                                                       daily snapshot
                                                       weekly snapshot
-----------------------------------------------------------------------------
28 snapshots

remove 1 snapshots:
ID        Time                 Host        Tags        Paths
------------------------------------------------------------
eb04be1e  2023-11-29 09:02:55  volsync                 /data
------------------------------------------------------------
1 snapshots

[0:00] 100.00%  1 / 1 files deleted

=== Starting prune ===
loading indexes...
loading all snapshots...
finding data that is still in use for 28 snapshots
[0:01] 64.29%  18 / 28 snapshots

decrypting blob f6125923b0e97999dde84370df2280f6b95a499dd1efcfd2b70380d7cfc8f82b failed: nonce is invalid
github.com/restic/restic/internal/repository.(*Repository).LoadBlob
        github.com/restic/restic/internal/repository/repository.go:314
github.com/restic/restic/internal/restic.LoadTree
        github.com/restic/restic/internal/restic/tree.go:115
github.com/restic/restic/internal/restic.loadTreeWorker
        github.com/restic/restic/internal/restic/tree_stream.go:36
github.com/restic/restic/internal/restic.StreamTrees.func1
        github.com/restic/restic/internal/restic/tree_stream.go:176
golang.org/x/sync/errgroup.(*Group).Go.func1
        golang.org/x/[email protected]/errgroup/errgroup.go:75
runtime.goexit
        runtime/asm_amd64.s:1598

restic check output:

restic -r s3:http://192.168.1.25:9000/jellyfin check --read-data
using temporary cache in /tmp/restic-check-cache-3455674126
repository b7fb1679 opened (version 2, compression level auto)
created new cache in /tmp/restic-check-cache-3455674126
create exclusive lock for repository
load indexes
[0:04] 100.00%  65 / 65 index files loaded
check all packs
check snapshots, trees and blobs
[0:02] 100.00%  28 / 28 snapshots
read all data
[0:58] 100.00%  1209 / 1209 packs
no errors were found

restic prune output:

restic -r s3:http://192.168.1.25:9000/jellyfin prune            
repository b7fb1679 opened (version 2, compression level auto)
created new cache in /root/.cache/restic
loading indexes...
[0:04] 100.00%  65 / 65 index files loaded
loading all snapshots...
finding data that is still in use for 28 snapshots
[0:03] 100.00%  28 / 28 snapshots
searching used packs...
collecting packs for deletion and repacking
[0:00] 100.00%  1209 / 1209 packs processed

to repack:          2722 blobs / 285.231 MiB
this removes:       1603 blobs / 178.739 MiB
to delete:       2979327 blobs / 1.441 GiB
total prune:     2980930 blobs / 1.616 GiB
remaining:         88237 blobs / 1.144 GiB
unused size after prune: 58.484 MiB (4.99% of remaining size)

repacking packs
[0:03] 100.00%  22 / 22 packs repacked
rebuilding index
[0:00] 100.00%  115 / 115 packs processed
deleting obsolete index files
[0:00] 100.00%  65 / 65 files deleted
removing 1101 old packs
[0:00] 100.00%  1101 / 1101 files deleted
done

[tesshuflower]

Hi @MrMarble - one thing perhaps that's different from what VolSync is doing vs your manual check/prune is that it's doing a forget before the prune. If you do that manually do you hit any errors?

Before the prune, volsync is doing something like:

restic -r s3:http://192.168.1.25:9000/jellyfin forget --keep-hourly 24 --keep-daily 7 --keep-weekly 5

Are you able to run the forget and then prune manually?

Another possibility I suppose is something is corrupted in the cache pvc used by VolSync.