Inconsistent prune behaviour with --keep-within

Getting Help
1

Hi all, i’m seeing a slightly irritating behaviour when it comes to pruning and using the following settings:
KEEP_DAILY=7
KEEP_MONTHLY=0
KEEP_WEEKLY=0
KEEP_WITHIN=7d
KEEP_YEARLY=0

We’re setting keep_within to the keep_daily value since some weeks. We had keep_within hardcoded to 2 days before and didn’t see the issue, this is happening only since we’re having keep_within = keep_daily.

I’m pasting the backup and prune output below. prune is running directly after the backup, and most of the times it is working as expected, however, there are some hickups. We’re generating metrics from the outputs and these become incomplete with the hickups, which is a bit annoying. On the server i took the example from, for the past 6 days it was : worked, didn’t, worked, worked, worked, didn’t.

The first two days in the log show the missing prune on the 19. On the 20. restic is pruning two snapshots, the one that now is 9 days old, and the 8 days old one. 21. and 22 are working as expected, on the 23., the prune isn’t done.

Complete command is:

  forget \
  --group-by host \
  --tag "${HOSTNAME}" \
  --keep-daily "${KEEP_DAILY}" \
  --keep-weekly "${KEEP_WEEKLY}" \
  --keep-within "${KEEP_WITHIN}" \
  --keep-monthly "${KEEP_MONTHLY}" \
  --keep-yearly "${KEEP_YEARLY}" \
  --prune

Variables are exported in bash and checked if they are set. If unset or missing, our wrapper would bail out.

Log:

2021-12-19T04:02:02+01:00 Starting backup
using parent snapshot b81720cc

Files:          30 new,    56 changed, 1547589 unmodified
Dirs:           14 new,   126 changed, 2635645 unmodified
Added to the repo: 3.952 GiB

processed 1547675 files, 174.186 GiB in 2:17:16
snapshot 901e54bc saved
2021-12-19T06:19:19+01:00 restic backup return code 0
2021-12-19T06:19:19+01:00 Finished backup
2021-12-19T06:19:19+01:00 Starting prune
Applying Policy: keep 7 daily snapshots and all snapshots within 7d of the newest
keep 8 snapshots:
ID        Time                 Host              Tags              Reasons         Paths
-----------------------------------------------------------------------------------------------------
7bd0148d  2021-12-12 04:02:03  myserver  myserver  within 7d       /

cb7f1711  2021-12-13 04:02:02  myserver  myserver  within 7d       /
                                                                   daily snapshot  


1c6e3003  2021-12-14 04:02:02  myserver  myserver  within 7d       /
                                                                   daily snapshot 


295aee42  2021-12-15 04:02:02  myserver  myserver  within 7d       /
                                                                   daily snapshot  


c40d9a0a  2021-12-16 04:02:03  myserver  myserver  within 7d       /
                                                                   daily snapshot 


1ad7861b  2021-12-17 04:02:02  myserver  myserver  within 7d       /
                                                                   daily snapshot  


b81720cc  2021-12-18 04:02:02  myserver  myserver  within 7d       /
                                                                   daily snapshot 


901e54bc  2021-12-19 04:02:02  myserver  myserver  within 7d       /
                                                                   daily snapshot  

-----------------------------------------------------------------------------------------------------
8 snapshots

2021-12-19T06:19:21+01:00 restic prune return code 0
2021-12-19T06:19:21+01:00 Finished prune

-----
2021-12-20T04:02:02+01:00 Starting backup
using parent snapshot 901e54bc

Files:          22 new,    64 changed, 1547586 unmodified
Dirs:            6 new,   131 changed, 2635640 unmodified
Added to the repo: 3.853 GiB

processed 1547672 files, 174.121 GiB in 2:12:52
snapshot 82a80cd4 saved
2021-12-20T06:14:56+01:00 restic backup return code 0
2021-12-20T06:14:56+01:00 Finished backup
2021-12-20T06:14:56+01:00 Starting prune
Applying Policy: keep 7 daily snapshots and all snapshots within 7d of the newest
keep 7 snapshots:
ID        Time                 Host              Tags              Reasons         Paths
-----------------------------------------------------------------------------------------------------
1c6e3003  2021-12-14 04:02:02  myserver  myserver  within 7d       /
                                                                   daily snapshot  


295aee42  2021-12-15 04:02:02  myserver  myserver  within 7d       /
                                                                   daily snapshot  


c40d9a0a  2021-12-16 04:02:03  myserver  myserver  within 7d       /
                                                                   daily snapshot  


1ad7861b  2021-12-17 04:02:02  myserver  myserver  within 7d       /
                                                                   daily snapshot  


b81720cc  2021-12-18 04:02:02  myserver  myserver  within 7d       /
                                                                   daily snapshot  


901e54bc  2021-12-19 04:02:02  myserver  myserver  within 7d       /
                                                                   daily snapshot  


82a80cd4  2021-12-20 04:02:02  myserver  myserver  within 7d       /
                                                                   daily snapshot  

-----------------------------------------------------------------------------------------------------
7 snapshots

remove 2 snapshots:
ID        Time                 Host              Tags              Paths
-------------------------------------------------------------------------------------
7bd0148d  2021-12-12 04:02:03  myserver  myserver  /


cb7f1711  2021-12-13 04:02:02  myserver  myserver  /

-------------------------------------------------------------------------------------
2 snapshots

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

2 snapshots have been removed, running prune
loading indexes...
loading all snapshots...
finding data that is still in use for 7 snapshots
[1:16] 100.00%  7 / 7 snapshots

searching used packs...
collecting packs for deletion and repacking
[0:02] 100.00%  29268 / 29268 packs processed


to repack:      1249757 blobs / 1.012 GiB
this removes       1307 blobs / 18.772 MiB
to delete:         4572 blobs / 7.008 GiB
total prune:       5879 blobs / 7.026 GiB
remaining:      2846528 blobs / 126.995 GiB
unused size after prune: 1.472 GiB (1.16% of remaining size)

repacking packs
[0:21] 100.00%  240 / 240 packs repacked

rebuilding index
[0:09] 100.00%  27857 / 27857 packs processed

deleting obsolete index files
[0:00] 100.00%  60 / 60 files deleted

removing 1646 old packs
[0:01] 100.00%  1646 / 1646 files deleted

done
2021-12-20T06:17:18+01:00 restic prune return code 0
2021-12-20T06:17:18+01:00 Finished prune

-----
2021-12-21T04:02:02+01:00 Starting backup
using parent snapshot 82a80cd4

Files:          45 new,    59 changed, 1547608 unmodified
Dirs:           64 new,   171 changed, 2635606 unmodified
Added to the repo: 7.556 GiB

processed 1547712 files, 177.863 GiB in 2:21:37
snapshot 1075b839 saved
2021-12-21T06:23:41+01:00 restic backup return code 0
2021-12-21T06:23:41+01:00 Finished backup
2021-12-21T06:23:41+01:00 Starting prune
Applying Policy: keep 7 daily snapshots and all snapshots within 7d of the newest
keep 7 snapshots:
ID        Time                 Host              Tags              Reasons         Paths
-----------------------------------------------------------------------------------------------------
295aee42  2021-12-15 04:02:02  myserver  myserver  within 7d       /
                                                                   daily snapshot  

c40d9a0a  2021-12-16 04:02:03  myserver  myserver  within 7d       /
                                                                   daily snapshot  

1ad7861b  2021-12-17 04:02:02  myserver  myserver  within 7d       /
                                                                   daily snapshot  

b81720cc  2021-12-18 04:02:02  myserver  myserver  within 7d       /
                                                                   daily snapshot  

901e54bc  2021-12-19 04:02:02  myserver  myserver  within 7d       /
                                                                   daily snapshot  

82a80cd4  2021-12-20 04:02:02  myserver  myserver  within 7d       /
                                                                   daily snapshot  

1075b839  2021-12-21 04:02:02  myserver  myserver  within 7d       /
                                                                   daily snapshot  
-----------------------------------------------------------------------------------------------------
7 snapshots

remove 1 snapshots:
ID        Time                 Host              Tags              Paths
-------------------------------------------------------------------------------------
1c6e3003  2021-12-14 04:02:02  myserver  myserver  /
                                                                   
-------------------------------------------------------------------------------------
1 snapshots

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

1 snapshots have been removed, running prune
loading indexes...
loading all snapshots...
finding data that is still in use for 7 snapshots
[1:20] 100.00%  7 / 7 snapshots

searching used packs...
collecting packs for deletion and repacking
[0:05] 100.00%  29356 / 29356 packs processed


to repack:      1202558 blobs / 991.531 MiB
this removes        620 blobs / 12.947 MiB
to delete:         2360 blobs / 3.624 GiB
total prune:       2980 blobs / 3.637 GiB
remaining:      2848690 blobs / 130.915 GiB
unused size after prune: 1.487 GiB (1.14% of remaining size)

repacking packs
[0:27] 100.00%  229 / 229 packs repacked

rebuilding index
[0:14] 100.00%  28627 / 28627 packs processed

deleting obsolete index files
[0:00] 100.00%  59 / 59 files deleted

removing 955 old packs
[0:00] 100.00%  955 / 955 files deleted

done
2021-12-21T06:26:23+01:00 restic prune return code 0
2021-12-21T06:26:23+01:00 Finished prune

-----
2021-12-22T04:02:03+01:00 Starting backup
using parent snapshot 1075b839

Files:         237 new,    57 changed, 1547571 unmodified
Dirs:          431 new,   625 changed, 2635216 unmodified
Added to the repo: 3.786 GiB

processed 1547865 files, 174.225 GiB in 2:23:28
snapshot 4cb99479 saved
2021-12-22T06:25:32+01:00 restic backup return code 0
2021-12-22T06:25:32+01:00 Finished backup
2021-12-22T06:25:32+01:00 Starting prune
Applying Policy: keep 7 daily snapshots and all snapshots within 7d of the newest
keep 7 snapshots:
ID        Time                 Host              Tags              Reasons         Paths
-----------------------------------------------------------------------------------------------------
c40d9a0a  2021-12-16 04:02:03  myserver  myserver  within 7d       /
                                                                   daily snapshot  

1ad7861b  2021-12-17 04:02:02  myserver  myserver  within 7d       /
                                                                   daily snapshot  

b81720cc  2021-12-18 04:02:02  myserver  myserver  within 7d       /
                                                                   daily snapshot  

901e54bc  2021-12-19 04:02:02  myserver  myserver  within 7d       /
                                                                   daily snapshot  

82a80cd4  2021-12-20 04:02:02  myserver  myserver  within 7d       /
                                                                   daily snapshot  

1075b839  2021-12-21 04:02:02  myserver  myserver  within 7d       /
                                                                   daily snapshot  

4cb99479  2021-12-22 04:02:03  myserver  myserver  within 7d       /
                                                                   daily snapshot  
-----------------------------------------------------------------------------------------------------
7 snapshots

remove 1 snapshots:
ID        Time                 Host              Tags              Paths
-------------------------------------------------------------------------------------
295aee42  2021-12-15 04:02:02  myserver  myserver  /

-------------------------------------------------------------------------------------
1 snapshots

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

1 snapshots have been removed, running prune
loading indexes...
loading all snapshots...
finding data that is still in use for 7 snapshots
[1:57] 100.00%  7 / 7 snapshots

searching used packs...
collecting packs for deletion and repacking
[0:02] 100.00%  29389 / 29389 packs processed


to repack:      1372899 blobs / 1.095 GiB
this removes        987 blobs / 61.860 MiB
to delete:         4916 blobs / 7.489 GiB
total prune:       5903 blobs / 7.550 GiB
remaining:      2846331 blobs / 127.151 GiB
unused size after prune: 1.512 GiB (1.19% of remaining size)

repacking packs
[0:20] 100.00%  261 / 261 packs repacked

rebuilding index
[0:09] 100.00%  27869 / 27869 packs processed

deleting obsolete index files
[0:00] 100.00%  59 / 59 files deleted

removing 1773 old packs
[0:00] 100.00%  1773 / 1773 files deleted

done
2021-12-22T06:28:35+01:00 restic prune return code 0
2021-12-22T06:28:35+01:00 Finished prune

-----
2021-12-23T04:02:02+01:00 Starting backup
using parent snapshot 4cb99479

Files:         511 new,  2218 changed, 1545576 unmodified
Dirs:          532 new,   644 changed, 2635626 unmodified
Added to the repo: 7.444 GiB

processed 1548305 files, 177.999 GiB in 2:24:34
snapshot 16926b7e saved
2021-12-23T06:26:37+01:00 restic backup return code 0
2021-12-23T06:26:38+01:00 Finished backup
2021-12-23T06:26:38+01:00 Starting prune
Applying Policy: keep 7 daily snapshots and all snapshots within 7d of the newest
keep 8 snapshots:
ID        Time                 Host              Tags              Reasons         Paths
-----------------------------------------------------------------------------------------------------
c40d9a0a  2021-12-16 04:02:03  myserver  myserver  within 7d       /


1ad7861b  2021-12-17 04:02:02  myserver  myserver  within 7d       /
                                                                   daily snapshot  

b81720cc  2021-12-18 04:02:02  myserver  myserver  within 7d       /
                                                                   daily snapshot  

901e54bc  2021-12-19 04:02:02  myserver  myserver  within 7d       /
                                                                   daily snapshot  

82a80cd4  2021-12-20 04:02:02  myserver  myserver  within 7d       /
                                                                   daily snapshot  

1075b839  2021-12-21 04:02:02  myserver  myserver  within 7d       /
                                                                   daily snapshot  

4cb99479  2021-12-22 04:02:03  myserver  myserver  within 7d       /
                                                                   daily snapshot  

16926b7e  2021-12-23 04:02:02  myserver  myserver  within 7d       /
                                                                   daily snapshot  
-----------------------------------------------------------------------------------------------------
8 snapshots

2021-12-23T06:26:39+01:00 restic prune return code 0
2021-12-23T06:26:39+01:00 Finished prune

Thanks for any hints / ideas on this topic.

2

What is the actual problem? You haven’t really said that clearly.

My best guess (without having looked through all of that log) is that you are saying that “sometimes restic prunes and sometimes it doesnt”, is that it?

If so; The forget command with the --prune option only runs/“calls” prune when there were actually any snapshots forgotten.

If you want restic to always prune, regardless of having forgotten anything or not, just run the prune command separately.

3

On the 23rd, the prune may not be removing the 8th snapshot because it is not quite 7 days old yet? If —keep-within is being picky, it looks like that snapshot might be one second too young to be pruned.

4

Gotta love it when people answer questions with questions. Merry christmas! :christmas_tree:

Regarding the 23rd, does the first “note” (the blue area) at Removing backup snapshots — restic 0.16.3 documentation help to clarify why those snapshots were kept?

All calendar related --keep-* options work on the natural time boundaries and not relative to when you run the forget command. Weeks are Monday 00:00 → Sunday 23:59, days 00:00 to 23:59, hours :00 to :59, etc.

5

But is —keep-within considered a “calendar-related” option? I’ve always thought that applied to the *-yearly through *-hourly options. The —keep-within description mentions that the specified duration is relative to the newest snapshot. I guess I’ll need to dig into the code to clear up my confusion.

6

I’ve been expecting something similiar as well.
But i see that it could come down to that one second.

This behaviour, however, is inconsistent too. On the log from 2021-12-21 you see the oldest being removed with a timestamp of 04:02:02, like the newest one taken.

Todays snapshot is from 04:02:02 as well as the oldest one in the repo, however, the oldest did not get removed, putting me at 8 snapshots.

7

Not really. --keep-within 7d first finds the latest snapshot, either 2021-12-19 04:02:02 or 2021-12-20 04:02:02 for the first two log entries, then subtracts the specified duration of 7 days from that timestamp which yields 2021-12-12 04:02:02 an 2021-12-13 04:02:02. restic then deletes everything that has that timestamp or is older. That is the reason why at first 2021-12-12 04:02:03 is kept and is later on deleted together with the next snapshot.

What you probably want to use is --keep-within 6d23h.