Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Fatal: number of used blobs is larger than number of available blobs! #2777

Closed
cdzombak opened this issue Jun 9, 2020 · 19 comments
Closed

Comments

@cdzombak
Copy link

cdzombak commented Jun 9, 2020

Output of restic version

restic 0.9.6 compiled with go1.13.4 on linux/amd64

How did you run restic exactly?

Environment:

HOME=/root
LOGNAME=root
PATH=/usr/local/bin:/usr/bin:/bin
LANG=C.UTF-8
SHELL=/bin/sh
LC_ALL=C.UTF-8
PWD=/root

Command:

/usr/bin/flock -n /tmp/root-backup.lock ionice -c2 -n7 nice -n19 /root/backup.sh

backup.sh:

#!/usr/bin/env bash
set -e

export PATH="/usr/local/bin/:$PATH"
source .restic-cfg

# several `restic backup` calls snipped here, which all completed successfully

echo -e "\n\n`date` - Running forget and prune...\n"
restic forget --prune --keep-daily 14 --keep-weekly 8 --keep-monthly 12

.restic-cfg:

export AWS_ACCESS_KEY_ID=xxx
export AWS_SECRET_ACCESS_KEY=xxx
export RESTIC_PASSWORD=xxx
export RESTIC_REPOSITORY="s3:s3.wasabisys.com/xxx/restic2"

restic forget --prune output:

Tue Jun  9 03:30:01 EDT 2020 - Running forget and prune...

Applying Policy: keep the last 14 daily, 8 weekly, 12 monthly snapshots
keep 23 snapshots:
ID        Time                 Host           Tags        Reasons           Paths
--------------------------------------------------------------------------------------------------
68df8dbf  2020-01-31 01:09:52  goliath.local              monthly snapshot  /sharedfolders/general
a6b8e006  2020-02-27 02:10:31  goliath.local              monthly snapshot  /sharedfolders/general
9498abb0  2020-03-31 01:19:01  goliath.local              monthly snapshot  /sharedfolders/general
7b585e25  2020-04-26 01:29:54  goliath.local              weekly snapshot   /sharedfolders/general
82dc71bf  2020-04-30 01:31:52  goliath.local              monthly snapshot  /sharedfolders/general
6aa3e6a9  2020-05-03 03:01:15  goliath.local              weekly snapshot   /sharedfolders/general
71fd6003  2020-05-10 01:36:41  goliath.local              weekly snapshot   /sharedfolders/general
4f148138  2020-05-17 01:29:14  goliath.local              weekly snapshot   /sharedfolders/general
8e200d52  2020-05-24 01:42:51  goliath.local              weekly snapshot   /sharedfolders/general
eadf1d9b  2020-05-27 01:44:05  goliath.local              daily snapshot    /sharedfolders/general
5bbe0d87  2020-05-28 01:28:21  goliath.local              daily snapshot    /sharedfolders/general
80be833d  2020-05-29 01:44:05  goliath.local              daily snapshot    /sharedfolders/general
5267f3e0  2020-05-30 01:46:19  goliath.local              daily snapshot    /sharedfolders/general
84067df1  2020-05-31 01:30:26  goliath.local              daily snapshot    /sharedfolders/general
                                                         weekly snapshot
                                                         monthly snapshot
dbb08afd  2020-06-01 01:45:18  goliath.local              daily snapshot    /sharedfolders/general
9c1b1b63  2020-06-02 01:46:43  goliath.local              daily snapshot    /sharedfolders/general
600d2177  2020-06-03 01:34:37  goliath.local              daily snapshot    /sharedfolders/general
6021e6ba  2020-06-04 01:45:40  goliath.local              daily snapshot    /sharedfolders/general
907e8b45  2020-06-05 01:50:31  goliath.local              daily snapshot    /sharedfolders/general
aa0f45ca  2020-06-06 01:41:51  goliath.local              daily snapshot    /sharedfolders/general
c2c9e539  2020-06-07 05:00:44  goliath.local              daily snapshot    /sharedfolders/general
                                                         weekly snapshot
a4b85e90  2020-06-08 01:33:23  goliath.local              daily snapshot    /sharedfolders/general
650aaa66  2020-06-09 01:50:31  goliath.local              daily snapshot    /sharedfolders/general
                                                         weekly snapshot
                                                         monthly snapshot
--------------------------------------------------------------------------------------------------
23 snapshots

remove 1 snapshots:
ID        Time                 Host           Tags        Paths
--------------------------------------------------------------------------------
f5244b75  2020-05-26 01:38:45  goliath.local              /sharedfolders/general
--------------------------------------------------------------------------------
1 snapshots

keep 23 snapshots:
ID        Time                 Host           Tags        Reasons           Paths
-----------------------------------------------------------------------------------------------
24631de5  2020-01-31 01:11:40  goliath.local              monthly snapshot  /sharedfolders/plex
18addd76  2020-02-27 04:42:28  goliath.local              monthly snapshot  /sharedfolders/plex
008b5c9e  2020-03-31 01:45:22  goliath.local              monthly snapshot  /sharedfolders/plex
006a9e22  2020-04-26 01:40:03  goliath.local              weekly snapshot   /sharedfolders/plex
e3bb5adb  2020-04-30 01:50:51  goliath.local              monthly snapshot  /sharedfolders/plex
eb81c1e1  2020-05-03 03:29:17  goliath.local              weekly snapshot   /sharedfolders/plex
78ee7ffa  2020-05-10 01:45:25  goliath.local              weekly snapshot   /sharedfolders/plex
e66dc35e  2020-05-17 01:37:08  goliath.local              weekly snapshot   /sharedfolders/plex
c70e6a7e  2020-05-24 01:51:27  goliath.local              weekly snapshot   /sharedfolders/plex
2e93df74  2020-05-27 01:53:05  goliath.local              daily snapshot    /sharedfolders/plex
0bc4259c  2020-05-28 01:37:47  goliath.local              daily snapshot    /sharedfolders/plex
f6bf2b98  2020-05-29 01:53:07  goliath.local              daily snapshot    /sharedfolders/plex
686a30ff  2020-05-30 01:54:51  goliath.local              daily snapshot    /sharedfolders/plex
e38eefea  2020-05-31 01:37:26  goliath.local              daily snapshot    /sharedfolders/plex
                                                         weekly snapshot
                                                         monthly snapshot
524e4a6f  2020-06-01 01:53:50  goliath.local              daily snapshot    /sharedfolders/plex
0b101fde  2020-06-02 01:55:22  goliath.local              daily snapshot    /sharedfolders/plex
c8fc305a  2020-06-03 01:42:23  goliath.local              daily snapshot    /sharedfolders/plex
fe843049  2020-06-04 01:54:39  goliath.local              daily snapshot    /sharedfolders/plex
446dea59  2020-06-05 01:59:33  goliath.local              daily snapshot    /sharedfolders/plex
a974da65  2020-06-06 01:50:23  goliath.local              daily snapshot    /sharedfolders/plex
135213c5  2020-06-07 05:25:41  goliath.local              daily snapshot    /sharedfolders/plex
                                                         weekly snapshot
146f39a6  2020-06-08 01:40:19  goliath.local              daily snapshot    /sharedfolders/plex
9805432e  2020-06-09 01:59:29  goliath.local              daily snapshot    /sharedfolders/plex
                                                         weekly snapshot
                                                         monthly snapshot
-----------------------------------------------------------------------------------------------
23 snapshots

remove 1 snapshots:
ID        Time                 Host           Tags        Paths
-----------------------------------------------------------------------------
152465fe  2020-05-26 01:46:55  goliath.local              /sharedfolders/plex
-----------------------------------------------------------------------------
1 snapshots

keep 23 snapshots:
ID        Time                 Host           Tags        Reasons           Paths
---------------------------------------------------------------------------------
8fee51d7  2020-01-31 01:00:14  goliath.local              monthly snapshot  /etc
e18e15be  2020-02-27 01:00:14  goliath.local              monthly snapshot  /etc
1b591f81  2020-03-31 01:00:17  goliath.local              monthly snapshot  /etc
20b80823  2020-04-26 01:00:16  goliath.local              weekly snapshot   /etc
f4777e02  2020-04-30 01:00:15  goliath.local              monthly snapshot  /etc
df083c7c  2020-05-03 01:00:18  goliath.local              weekly snapshot   /etc
2253c0fd  2020-05-10 01:00:15  goliath.local              weekly snapshot   /etc
5ca41bfc  2020-05-17 01:00:17  goliath.local              weekly snapshot   /etc
6f5196dc  2020-05-24 01:00:21  goliath.local              weekly snapshot   /etc
85737e3f  2020-05-27 01:00:18  goliath.local              daily snapshot    /etc
aed45a4c  2020-05-28 01:00:18  goliath.local              daily snapshot    /etc
0e8cbc1c  2020-05-29 01:00:20  goliath.local              daily snapshot    /etc
7530a637  2020-05-30 01:00:20  goliath.local              daily snapshot    /etc
c84d81fd  2020-05-31 01:00:15  goliath.local              daily snapshot    /etc
                                                         weekly snapshot
                                                         monthly snapshot
3e028315  2020-06-01 01:00:19  goliath.local              daily snapshot    /etc
751056fb  2020-06-02 01:00:17  goliath.local              daily snapshot    /etc
031b1434  2020-06-03 01:00:18  goliath.local              daily snapshot    /etc
5376560d  2020-06-04 01:00:18  goliath.local              daily snapshot    /etc
6e966979  2020-06-05 01:00:19  goliath.local              daily snapshot    /etc
4e6234e1  2020-06-06 01:00:15  goliath.local              daily snapshot    /etc
64e4b2c9  2020-06-07 01:00:22  goliath.local              daily snapshot    /etc
                                                         weekly snapshot
9769682d  2020-06-08 01:00:16  goliath.local              daily snapshot    /etc
5fc29df2  2020-06-09 01:00:19  goliath.local              daily snapshot    /etc
                                                         weekly snapshot
                                                         monthly snapshot
---------------------------------------------------------------------------------
23 snapshots

remove 1 snapshots:
ID        Time                 Host           Tags        Paths
---------------------------------------------------------------
e5cf0eb3  2020-05-26 01:00:18  goliath.local              /etc
---------------------------------------------------------------
1 snapshots

keep 21 snapshots:
ID        Time                 Host           Tags        Reasons           Paths
-------------------------------------------------------------------------------------------
887e4bb4  2020-03-31 01:03:11  goliath.local              monthly snapshot  /var/spool/cron
9360aeec  2020-04-26 01:02:34  goliath.local              weekly snapshot   /var/spool/cron
69c7cafe  2020-04-30 01:03:52  goliath.local              monthly snapshot  /var/spool/cron
914fd688  2020-05-03 01:14:54  goliath.local              weekly snapshot   /var/spool/cron
83d0f47f  2020-05-10 01:02:32  goliath.local              weekly snapshot   /var/spool/cron
ae1e5cfb  2020-05-17 01:02:52  goliath.local              weekly snapshot   /var/spool/cron
213361bc  2020-05-24 01:03:54  goliath.local              weekly snapshot   /var/spool/cron
6a6874c2  2020-05-27 01:03:17  goliath.local              daily snapshot    /var/spool/cron
c7ded604  2020-05-28 01:02:50  goliath.local              daily snapshot    /var/spool/cron
bff03f74  2020-05-29 01:04:31  goliath.local              daily snapshot    /var/spool/cron
5bcbcbc2  2020-05-30 01:05:58  goliath.local              daily snapshot    /var/spool/cron
b129cf89  2020-05-31 01:02:47  goliath.local              daily snapshot    /var/spool/cron
                                                         weekly snapshot
                                                         monthly snapshot
5ec60754  2020-06-01 01:03:49  goliath.local              daily snapshot    /var/spool/cron
72f26b3f  2020-06-02 01:05:33  goliath.local              daily snapshot    /var/spool/cron
a6ff3aba  2020-06-03 01:03:27  goliath.local              daily snapshot    /var/spool/cron
0581fd95  2020-06-04 01:03:25  goliath.local              daily snapshot    /var/spool/cron
32c406c6  2020-06-05 01:05:48  goliath.local              daily snapshot    /var/spool/cron
51b2656f  2020-06-06 01:03:35  goliath.local              daily snapshot    /var/spool/cron
fd89ec70  2020-06-07 01:18:09  goliath.local              daily snapshot    /var/spool/cron
                                                         weekly snapshot
3f5bc8f2  2020-06-08 01:03:28  goliath.local              daily snapshot    /var/spool/cron
facbae25  2020-06-09 01:05:46  goliath.local              daily snapshot    /var/spool/cron
                                                         weekly snapshot
                                                         monthly snapshot
-------------------------------------------------------------------------------------------
21 snapshots

remove 1 snapshots:
ID        Time                 Host           Tags        Paths
-------------------------------------------------------------------------
707a1eba  2020-05-26 01:02:48  goliath.local              /var/spool/cron
-------------------------------------------------------------------------
1 snapshots

keep 23 snapshots:
ID        Time                 Host           Tags        Reasons           Paths
------------------------------------------------------------------------------------------------
06adb098  2020-01-31 01:03:21  goliath.local              monthly snapshot  /sharedfolders/arch
d7967d49  2020-02-27 01:05:00  goliath.local              monthly snapshot  /sharedfolders/arch
400f70e0  2020-03-31 01:03:39  goliath.local              monthly snapshot  /sharedfolders/arch
95c3664a  2020-04-26 01:03:03  goliath.local              weekly snapshot   /sharedfolders/arch
4e88f8b9  2020-04-30 01:04:17  goliath.local              monthly snapshot  /sharedfolders/arch
28ac40c3  2020-05-03 01:15:32  goliath.local              weekly snapshot   /sharedfolders/arch
42ad4f5b  2020-05-10 01:03:10  goliath.local              weekly snapshot   /sharedfolders/arch
a29208e7  2020-05-17 01:03:20  goliath.local              weekly snapshot   /sharedfolders/arch
aeda0156  2020-05-24 01:04:23  goliath.local              weekly snapshot   /sharedfolders/arch
fb0864f0  2020-05-27 01:03:48  goliath.local              daily snapshot    /sharedfolders/arch
ff6a94f1  2020-05-28 01:03:20  goliath.local              daily snapshot    /sharedfolders/arch
2d00da20  2020-05-29 01:05:03  goliath.local              daily snapshot    /sharedfolders/arch
eb8ec04a  2020-05-30 01:06:30  goliath.local              daily snapshot    /sharedfolders/arch
ec38729a  2020-05-31 01:03:15  goliath.local              daily snapshot    /sharedfolders/arch
                                                         weekly snapshot
                                                         monthly snapshot
8601defc  2020-06-01 01:04:18  goliath.local              daily snapshot    /sharedfolders/arch
971b330c  2020-06-02 01:06:08  goliath.local              daily snapshot    /sharedfolders/arch
7b39574f  2020-06-03 01:03:58  goliath.local              daily snapshot    /sharedfolders/arch
c475e0ba  2020-06-04 01:04:01  goliath.local              daily snapshot    /sharedfolders/arch
bde30184  2020-06-05 01:06:15  goliath.local              daily snapshot    /sharedfolders/arch
ca8c5481  2020-06-06 01:04:03  goliath.local              daily snapshot    /sharedfolders/arch
9c52af82  2020-06-07 01:18:41  goliath.local              daily snapshot    /sharedfolders/arch
                                                         weekly snapshot
57df1047  2020-06-08 01:03:58  goliath.local              daily snapshot    /sharedfolders/arch
7793976a  2020-06-09 01:06:15  goliath.local              daily snapshot    /sharedfolders/arch
                                                         weekly snapshot
                                                         monthly snapshot
------------------------------------------------------------------------------------------------
23 snapshots

remove 1 snapshots:
ID        Time                 Host           Tags        Paths
------------------------------------------------------------------------------
a39d764c  2020-05-26 01:03:16  goliath.local              /sharedfolders/arch
------------------------------------------------------------------------------
1 snapshots

keep 23 snapshots:
ID        Time                 Host           Tags        Reasons           Paths
--------------------------------------------------------------------------------------
84bdb822  2020-01-31 01:00:23  goliath.local              monthly snapshot  /usr/local
1e16f477  2020-02-27 01:00:27  goliath.local              monthly snapshot  /usr/local
14959dcc  2020-03-31 01:00:31  goliath.local              monthly snapshot  /usr/local
d4d5aa44  2020-04-26 01:00:28  goliath.local              weekly snapshot   /usr/local
f990a097  2020-04-30 01:00:29  goliath.local              monthly snapshot  /usr/local
880e21eb  2020-05-03 01:00:38  goliath.local              weekly snapshot   /usr/local
62fbb735  2020-05-10 01:00:27  goliath.local              weekly snapshot   /usr/local
2f4db3c0  2020-05-17 01:00:32  goliath.local              weekly snapshot   /usr/local
aff31329  2020-05-24 01:00:38  goliath.local              weekly snapshot   /usr/local
aa2eea13  2020-05-27 01:00:37  goliath.local              daily snapshot    /usr/local
700feb66  2020-05-28 01:00:36  goliath.local              daily snapshot    /usr/local
d9c3c717  2020-05-29 01:00:37  goliath.local              daily snapshot    /usr/local
632199ac  2020-05-30 01:00:39  goliath.local              daily snapshot    /usr/local
7faa64e8  2020-05-31 01:00:31  goliath.local              daily snapshot    /usr/local
                                                         weekly snapshot
                                                         monthly snapshot
ba4dcbfc  2020-06-01 01:00:35  goliath.local              daily snapshot    /usr/local
afa2cb6d  2020-06-02 01:00:33  goliath.local              daily snapshot    /usr/local
6f2e61e4  2020-06-03 01:00:35  goliath.local              daily snapshot    /usr/local
ed93e4e7  2020-06-04 01:00:36  goliath.local              daily snapshot    /usr/local
36ad0c4c  2020-06-05 01:00:34  goliath.local              daily snapshot    /usr/local
48f09f7b  2020-06-06 01:00:29  goliath.local              daily snapshot    /usr/local
90b83031  2020-06-07 01:00:38  goliath.local              daily snapshot    /usr/local
                                                         weekly snapshot
84efc1da  2020-06-08 01:00:31  goliath.local              daily snapshot    /usr/local
66e7cde5  2020-06-09 01:00:36  goliath.local              daily snapshot    /usr/local
                                                         weekly snapshot
                                                         monthly snapshot
--------------------------------------------------------------------------------------
23 snapshots

remove 1 snapshots:
ID        Time                 Host           Tags        Paths
--------------------------------------------------------------------
651e6491  2020-05-26 01:00:35  goliath.local              /usr/local
--------------------------------------------------------------------
1 snapshots

keep 23 snapshots:
ID        Time                 Host           Tags        Reasons           Paths
--------------------------------------------------------------------------------------------------------------------
6fb9a4b0  2020-01-31 01:00:33  goliath.local              monthly snapshot  /srv/dev-disk-by-label-storage/plex-data
fbbae875  2020-02-27 01:00:39  goliath.local              monthly snapshot  /srv/dev-disk-by-label-storage/plex-data
96076e0d  2020-03-31 01:00:44  goliath.local              monthly snapshot  /srv/dev-disk-by-label-storage/plex-data
25d333b8  2020-04-26 01:00:41  goliath.local              weekly snapshot   /srv/dev-disk-by-label-storage/plex-data
95933b97  2020-04-30 01:00:42  goliath.local              monthly snapshot  /srv/dev-disk-by-label-storage/plex-data
b9642c34  2020-05-03 01:01:00  goliath.local              weekly snapshot   /srv/dev-disk-by-label-storage/plex-data
46c6f7cb  2020-05-10 01:00:39  goliath.local              weekly snapshot   /srv/dev-disk-by-label-storage/plex-data
71560dc1  2020-05-17 01:00:47  goliath.local              weekly snapshot   /srv/dev-disk-by-label-storage/plex-data
7e08e4ba  2020-05-24 01:00:55  goliath.local              weekly snapshot   /srv/dev-disk-by-label-storage/plex-data
d32ab7f9  2020-05-27 01:00:55  goliath.local              daily snapshot    /srv/dev-disk-by-label-storage/plex-data
e55f0db2  2020-05-28 01:00:52  goliath.local              daily snapshot    /srv/dev-disk-by-label-storage/plex-data
02fffa81  2020-05-29 01:00:56  goliath.local              daily snapshot    /srv/dev-disk-by-label-storage/plex-data
78f403e0  2020-05-30 01:01:02  goliath.local              daily snapshot    /srv/dev-disk-by-label-storage/plex-data
69160f1f  2020-05-31 01:00:46  goliath.local              daily snapshot    /srv/dev-disk-by-label-storage/plex-data
                                                         weekly snapshot
                                                         monthly snapshot
930ed5e1  2020-06-01 01:00:52  goliath.local              daily snapshot    /srv/dev-disk-by-label-storage/plex-data
41a55f47  2020-06-02 01:00:50  goliath.local              daily snapshot    /srv/dev-disk-by-label-storage/plex-data
fac4398d  2020-06-03 01:00:52  goliath.local              daily snapshot    /srv/dev-disk-by-label-storage/plex-data
b3f27fb1  2020-06-04 01:00:51  goliath.local              daily snapshot    /srv/dev-disk-by-label-storage/plex-data
75064386  2020-06-05 01:00:49  goliath.local              daily snapshot    /srv/dev-disk-by-label-storage/plex-data
74d2b6d9  2020-06-06 01:00:43  goliath.local              daily snapshot    /srv/dev-disk-by-label-storage/plex-data
05cfc16c  2020-06-07 01:00:54  goliath.local              daily snapshot    /srv/dev-disk-by-label-storage/plex-data
                                                         weekly snapshot
3935b2fd  2020-06-08 01:00:45  goliath.local              daily snapshot    /srv/dev-disk-by-label-storage/plex-data
246301b9  2020-06-09 01:00:51  goliath.local              daily snapshot    /srv/dev-disk-by-label-storage/plex-data
                                                         weekly snapshot
                                                         monthly snapshot
--------------------------------------------------------------------------------------------------------------------
23 snapshots

remove 1 snapshots:
ID        Time                 Host           Tags        Paths
--------------------------------------------------------------------------------------------------
ceea6a89  2020-05-26 01:00:51  goliath.local              /srv/dev-disk-by-label-storage/plex-data
--------------------------------------------------------------------------------------------------
1 snapshots

keep 23 snapshots:
ID        Time                 Host           Tags        Reasons           Paths
------------------------------------------------------------------------------------------
12dcc9ee  2020-01-31 01:03:10  goliath.local              monthly snapshot  /home/cdzombak
a9dcc35a  2020-02-27 01:04:48  goliath.local              monthly snapshot  /home/cdzombak
e1159dc2  2020-03-31 01:03:25  goliath.local              monthly snapshot  /home/cdzombak
ab650891  2020-04-26 01:02:49  goliath.local              weekly snapshot   /home/cdzombak
0bf7c3e9  2020-04-30 01:04:05  goliath.local              monthly snapshot  /home/cdzombak
28b99758  2020-05-03 01:15:12  goliath.local              weekly snapshot   /home/cdzombak
cd12afa5  2020-05-10 01:02:46  goliath.local              weekly snapshot   /home/cdzombak
75e660b2  2020-05-17 01:03:05  goliath.local              weekly snapshot   /home/cdzombak
13468671  2020-05-24 01:04:08  goliath.local              weekly snapshot   /home/cdzombak
8cfac2c5  2020-05-27 01:03:32  goliath.local              daily snapshot    /home/cdzombak
e9e4be31  2020-05-28 01:03:05  goliath.local              daily snapshot    /home/cdzombak
05f748b8  2020-05-29 01:04:46  goliath.local              daily snapshot    /home/cdzombak
543cdd76  2020-05-30 01:06:13  goliath.local              daily snapshot    /home/cdzombak
da1026cb  2020-05-31 01:03:00  goliath.local              daily snapshot    /home/cdzombak
                                                         weekly snapshot
                                                         monthly snapshot
642faa39  2020-06-01 01:04:03  goliath.local              daily snapshot    /home/cdzombak
f0498345  2020-06-02 01:05:50  goliath.local              daily snapshot    /home/cdzombak
c9df817d  2020-06-03 01:03:41  goliath.local              daily snapshot    /home/cdzombak
f896bc39  2020-06-04 01:03:40  goliath.local              daily snapshot    /home/cdzombak
8616afc5  2020-06-05 01:06:01  goliath.local              daily snapshot    /home/cdzombak
2640ddb0  2020-06-06 01:03:49  goliath.local              daily snapshot    /home/cdzombak
78f2b07d  2020-06-07 01:18:24  goliath.local              daily snapshot    /home/cdzombak
                                                         weekly snapshot
4de7cee3  2020-06-08 01:03:42  goliath.local              daily snapshot    /home/cdzombak
6c8f782c  2020-06-09 01:05:59  goliath.local              daily snapshot    /home/cdzombak
                                                         weekly snapshot
                                                         monthly snapshot
------------------------------------------------------------------------------------------
23 snapshots

remove 1 snapshots:
ID        Time                 Host           Tags        Paths
------------------------------------------------------------------------
6a10130f  2020-05-26 01:03:01  goliath.local              /home/cdzombak
------------------------------------------------------------------------
1 snapshots

keep 23 snapshots:
ID        Time                 Host           Tags        Reasons           Paths
---------------------------------------------------------------------------------
a0a820bb  2020-01-31 01:00:01  goliath.local              monthly snapshot  /root
2e6186b8  2020-02-27 01:00:01  goliath.local              monthly snapshot  /root
ee817240  2020-03-31 01:00:01  goliath.local              monthly snapshot  /root
79e28c7e  2020-04-26 01:00:01  goliath.local              weekly snapshot   /root
3ff0dae9  2020-04-30 01:00:01  goliath.local              monthly snapshot  /root
3f9abac5  2020-05-03 01:00:01  goliath.local              weekly snapshot   /root
3c212711  2020-05-10 01:00:01  goliath.local              weekly snapshot   /root
39cda8ad  2020-05-17 01:00:01  goliath.local              weekly snapshot   /root
36a7d600  2020-05-24 01:00:01  goliath.local              weekly snapshot   /root
4fe292b0  2020-05-27 01:00:01  goliath.local              daily snapshot    /root
7097fa38  2020-05-28 01:00:01  goliath.local              daily snapshot    /root
26fe1e61  2020-05-29 01:00:02  goliath.local              daily snapshot    /root
2637bcec  2020-05-30 01:00:01  goliath.local              daily snapshot    /root
b14627ec  2020-05-31 01:00:01  goliath.local              daily snapshot    /root
                                                         weekly snapshot
                                                         monthly snapshot
1e92ee58  2020-06-01 01:00:02  goliath.local              daily snapshot    /root
f9ec85dd  2020-06-02 01:00:01  goliath.local              daily snapshot    /root
b5b54d88  2020-06-03 01:00:01  goliath.local              daily snapshot    /root
4fd03fa8  2020-06-04 01:00:01  goliath.local              daily snapshot    /root
fff8df64  2020-06-05 01:00:02  goliath.local              daily snapshot    /root
d6255b1c  2020-06-06 01:00:01  goliath.local              daily snapshot    /root
9bd2eec4  2020-06-07 01:00:02  goliath.local              daily snapshot    /root
                                                         weekly snapshot
d67c18a8  2020-06-08 01:00:01  goliath.local              daily snapshot    /root
24fca921  2020-06-09 01:00:02  goliath.local              daily snapshot    /root
                                                         weekly snapshot
                                                         monthly snapshot
---------------------------------------------------------------------------------
23 snapshots

remove 1 snapshots:
ID        Time                 Host           Tags        Paths
---------------------------------------------------------------
c064eed8  2020-05-26 01:00:01  goliath.local              /root
---------------------------------------------------------------
1 snapshots

9 snapshots have been removed, running prune
counting files in repo
building new index for repo
[2:00:20] 100.00%! (MISSING)/ 594774 packs

repository contains 594774 packs (5133325 blobs) with 2.797 TiB
processed 5133325 blobs: 0 duplicate blobs, 0 B duplicate
load all snapshots
find data that is still in use for 205 snapshots
[15:50] 100.00%! (MISSING)/ 205 snapshots

Fatal: number of used blobs is larger than number of available blobs!
Please report this error (along with the output of the 'prune' run) at
https://github.com/restic/restic/issues/new

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

Wasabi

Expected behavior

I expect forget --prune to complete successfully.

Actual behavior

forget --prune reports (MISSING)/ 594774 packs, (MISSING)/ 205 snapshots, and dies with Fatal: number of used blobs is larger than number of available blobs!.

This backup job runs daily. This problem has occurred three times for me: on June 4, June 6, and June 9. (The run output above is from June 9.)

Note this means that forget --prune only fails intermittently. Looking at logs, I can confirm it completed successfully on June 3, 5, 7, and 8.

Steps to reproduce the behavior

I cannot deterministically and consistently reproduce this behavior.

Do you have any idea what may have caused this?

No.

edited to add: Not really. However, after running restic check I notice that a lot, but not all, of the files listed are in folders I recently (probably a couple weeks ago) added to --exclude.

I suspect this is related somehow — maybe a prune bug triggered by pruning files which had been included in old backups but excluded from more recent ones?

Do you have an idea how to solve the issue?

No.

@dimejo
Copy link
Contributor

dimejo commented Jun 9, 2020

Please see #2663

@cdzombak
Copy link
Author

cdzombak commented Jun 10, 2020

Please see #2663

I've tried step 1 in #2663 (comment) , restic check. It produces 20,000 lines of output, indicating that quite some number of trees contain errors.

Skimming through the errors, I notice two things:

  • Most (maybe all?) are either blob 123 size could not be found or blob 12345678: not found in index
  • A lot, but not all, of the files listed are in folders I recently (probably a couple weeks ago) added to --exclude. I suspect this is related somehow.

@MichaelEischer
Copy link
Member

The usual first step is to rebuild the repository index using rebuild-index (please create a backup/copy of the index folder in the repository first). For your repository this will probably take a few hours (less than half a prune run). The index rebuild ensures that restic has an accurate idea of which blobs still exist and which don't. In some cases this already fixes the repository.

The backup command only adds new files to the repository and never removes anything, thus it sounds rather unlikely to be related to the missing blobs.

@cdzombak
Copy link
Author

@MichaelEischer Today, after backing up the index, I ran restic check which completed successfully:

counting files in repo
[1:59:14] 100.00%  594774 / 594774 packs

finding old index files
saved new indexes as […snipped…]
remove 212 old index files

Unfortunately, after that, restic check reports many errors, as before. Its output is the same number of lines as before (~21000), and skimming the diff vs. the last check run, it looks like the same output but in a different order.

@MichaelEischer
Copy link
Member

Hmm, that looks like some pack files disappeared. If you still have some of the affected files, then you can instruct restic to fully back those up again using restic backup --force ....

If I understand your setup correctly you have a single host using that repository and use flock to ensure that the script only runs once?

@cdzombak
Copy link
Author

cdzombak commented Jun 12, 2020

Hmm, that looks like some pack files disappeared. If you still have some of the affected files, then you can instruct restic to fully back those up again using restic backup --force ....

I'll make a copy of my backup script which runs all my restic backup commands with --force, and run it today. Will post results when that's complete.

If I understand your setup correctly you have a single host using that repository and use flock to ensure that the script only runs once?

That is correct.

@cdzombak
Copy link
Author

cdzombak commented Jun 15, 2020

Okay. I ran restic backup --force for each of the restic backup commands I usually run, and those completed successfully, without reporting any errors.

restic check now reports ~11,800 lines of errors. Again, these are entirely blob X size could not be found and blob abcdbeef: not found in index errors.

This time, running grep "error for tree" | uniq | wc -l on the restic check output seems to indicate 66 trees have errors. This is an improvement from before, when it indicated 732 trees had errors.

As before, quickly skimming the restic check output it looks like most files it mentions were in directories I recently added to my backups' --exclude lists. I still wonder if this is potentially related to the bug, since it seems like a big coincidence that this error appeared a few weeks after I added those exclusions.

I am not sure how to proceed on fixing the remaining trees.

@MichaelEischer
Copy link
Member

As the backup source data for the remaining broken trees seems to be no longer available, there are basically two options on how to proceed: Delete the snapshots with missing data. Or try whether you can remove the damaged files from the snapshots using PR #2731 (The PR is still experimental, I haven't had time to take a closer look at it, but I'm pretty sure that it won't cause additional damage to the repository. However, it might be possible that it creates a damaged rewritten snapshot or just doesn't work at all. And you should probably create a backup of the snapshots folder before, just in case).

As before, quickly skimming the restic check output it looks like most files it mentions were in directories I recently added to my backups' --exclude lists. I still wonder if this is potentially related to the bug, since it seems like a big coincidence that this error appeared a few weeks after I added those exclusions.

restic freshly assembles the directory trees in each backup run. The only influence --exclude has on the backup process is that restic skips excluded files while iterating through the directory. And then these files are just not added to the list of directory entries. A backup run also only ever adds files to the repository and never removes anything. If there were a bug hidden somewhere, then it would damage parts of the directory data that does not contain the excluded files.

It's much more likely that the damage to the excluded files has been present for some time before these files were excluded or that a data pack files disappeared afterwards.

@cdzombak
Copy link
Author

As the backup source data for the remaining broken trees seems to be no longer available, there are basically two options on how to proceed: Delete the snapshots with missing data. Or try whether you can remove the damaged files from the snapshots using PR #2731 (The PR is still experimental, I haven't had time to take a closer look at it, but I'm pretty sure that it won't cause additional damage to the repository. However, it might be possible that it creates a damaged rewritten snapshot or just doesn't work at all. And you should probably create a backup of the snapshots folder before, just in case).

I see. Would there be any harm in not removing these snapshots, and simply waiting for them to be pruned out as part of my normal prune schedule? (Just trying to be lazy, here 😉)

I don't feel comfortable running an unmerged PR on my repo, but thank you for the pointer to it. That seems like it will be a useful feature moving forward.

restic freshly assembles the directory trees in each backup run. The only influence --exclude has on the backup process is that restic skips excluded files while iterating through the directory. And then these files are just not added to the list of directory entries. A backup run also only ever adds files to the repository and never removes anything. If there were a bug hidden somewhere, then it would damage parts of the directory data that does not contain the excluded files.

It's much more likely that the damage to the excluded files has been present for some time before these files were excluded or that a data pack files disappeared afterwards.

Thank you for the clear explanation. I appreciate your help on this. I still have no idea what might have caused this damage, but ¯\_(ツ)_/¯

@MichaelEischer
Copy link
Member

I see. Would there be any harm in not removing these snapshots, and simply waiting for them to be pruned out as part of my normal prune schedule? (Just trying to be lazy, here 😉)

Once you've run rebuild-index once and run a full backup rescan backup --force for all backup sets then it should be safe to wait as restic would only use valid snapshots as parent for new backup runs. Check will complain about missing blobs until the affected snapshosts were removed. And prune won't work at all until all damaged snapshots are removed.

@MichaelEischer
Copy link
Member

@cdzombak Has your repository fixed itself by now? I'd like to close this issue as I don't see something we could still investigate here.

@cdzombak
Copy link
Author

cdzombak commented Jan 9, 2021

@MichaelEischer thanks for following up. Unfortunately, it has not — in fact, for a long time now pruning has been failing every day.

I can provide more information Monday, but the output reads:

find data that is still in use for 283 snapshots
[14:09] 100.00%! (MISSING)/ 283 snapshots

Fatal: [<data/a4b61bff> (note from cdzombak: omitting a long, long list here) ] not found in the new index
Data blobs seem to be missing, aborting prune to prevent further data loss!
Please report this error (along with the output of the 'prune' run) at
https://github.com/restic/restic/issues/new/choose

I've intended for a while to write up another bug report, but other priorities have gotten in the way. The gist is, I have not changed how I am running restic, just updated it (currently on restic 0.11.0).

@MichaelEischer
Copy link
Member

As mentioned previously, it is expected behavior that prune fails as long as damaged snapshots exist. And as far as I remember we didn't remove those? As the initially damaged snapshots should have been thinned out quite a bit by now, it might be worth a shot to finally get rid of those. You can use the long list reported by prune to search for affected snapshots: restic find --blob a4b61bff ....

Do you have logs of earlier failing prune runs? It would interesting to compare the blob list reported by the oldest prune run you can find which uses restic >=0.10.0 with the currently reported blob list. My expectation would be that no new blobs ended up in that list.

@cdzombak
Copy link
Author

As mentioned previously, it is expected behavior that prune fails as long as damaged snapshots exist. And as far as I remember we didn't remove those? As the initially damaged snapshots should have been thinned out quite a bit by now, it might be worth a shot to finally get rid of those. You can use the long list reported by prune to search for affected snapshots: restic find --blob a4b61bff ....

I'll start doing this, but restic find for a single blob takes a long time (on the order of 30 minutes, though I didn't think to time it). I'll do that for a couple blobs and remove the snapshots, and see what effect it has on the blob list.

Do you have logs of earlier failing prune runs? It would interesting to compare the blob list reported by the oldest prune run you can find which uses restic >=0.10.0 with the currently reported blob list. My expectation would be that no new blobs ended up in that list.

Unfortunately, the oldest log I have is from October 11, 2020. I think I was running restic 0.10.0 by that time.

Comparing the blob list from October 11 to one from this morning's failure, I do note that no new blobs have appeared. The blob list from oct. 11 has 2583 blobs in it; the one from this morning (Jan. 11, 2021) has 2573.

@MichaelEischer
Copy link
Member

I'll start doing this, but restic find for a single blob takes a long time (on the order of 30 minutes, though I didn't think to time it). I'll do that for a couple blobs and remove the snapshots, and see what effect it has on the blob list.

You can pass a list of blobs to find which should take about as long as it did for a single blob.

Unfortunately, the oldest log I have is from October 11, 2020. I think I was running restic 0.10.0 by that time.

Comparing the blob list from October 11 to one from this morning's failure, I do note that no new blobs have appeared. The blob list from oct. 11 has 2583 blobs in it; the one from this morning (Jan. 11, 2021) has 2573.

So there have been no further disappearing data packs in the last three months. So let's hope that the initial issue was just a one-time problem (although that makes debugging really hard)

@cdzombak
Copy link
Author

You can pass a list of blobs to find which should take about as long as it did for a single blob.

Ah, nice! Suppose I should've checked the docs on that one :)

So there have been no further disappearing data packs in the last three months. So let's hope that the initial issue was just a one-time problem (although that makes debugging really hard)

I think this is likely the case. I've so far searched for one blob and removed the three snapshots which used it. A subsequent search for a second missing blob didn't turn up any references, so perhaps there were just a few broken snapshots left, as you theorized.

I'll go ahead and search for many more blobs at once and see what turns up.

As before, @MichaelEischer, thanks for your help & patience here.

@cdzombak
Copy link
Author

🎉 with some Bash-fu I was able to search for around 300 of the affected blobs and remove the snapshots that used them. In total I ended up removing ~10 snapshots.

Today's scheduled backup and prune job completed successfully. Pruning reported that 843.028 GiB will be freed, which ought to reduce my cloud storage bill :)

@MichaelEischer
Copy link
Member

So I guess we can close the issue for now? If the problem reappears then it would be no problem to reopen the issue.

@cdzombak
Copy link
Author

So I guess we can close the issue for now? If the problem reappears then it would be no problem to reopen the issue.

Agreed. 🍻

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants