Very aggresive rustic prune behaviour

[kapitainsky]

rustic very often tries to repack relatively huge amount of data for very limited gains. I have seen it for some time but finally created some clear case to post here.

I remove two snapshots from my small (about 15GB) test repo:

$ rustic forget
using config ./rustic.toml
[INFO] repository rclone:OD01-ENC:restic-test: password is correct.
[INFO] using cache at /Users/kptsky/Library/Caches/rustic/4f2d3e038efab8e03b2c1b3281e3bda9ae614ee9a03e23baba1a4f380a5ae80c
snapshots for (host [kp-laptop.local], label [], paths [/])

| ID       | Time                | Host            | Label | Tags        | Paths | Action | Reason  |
|----------|---------------------|-----------------|-------|-------------|-------|--------|---------|
| 4f514200 | 2024-01-20 07:45:54 | kp-laptop.local |       | test_rustic | /     | keep   | last    |
|          |                     |                 |       |             |       |        | daily   |
|          |                     |                 |       |             |       |        | weekly  |
|          |                     |                 |       |             |       |        | monthly |
| 3980d1f6 | 2024-01-19 19:41:01 | kp-laptop.local |       | test_rustic | /     | keep   | last    |
|          |                     |                 |       |             |       |        | daily   |
| 6cd6f47c | 2024-01-19 09:58:37 | kp-laptop.local |       | test_rustic | /     | remove |         |
| 105ecbf2 | 2024-01-18 19:50:01 | kp-laptop.local |       | test_rustic | /     | remove |         |
| 2bc5f01c | 2023-12-31 20:44:27 | kp-laptop.local |       | test_rustic | /     | keep   | weekly  |
|          |                     |                 |       |             |       |        | monthly |

and now attempting to run prune - wow - rustic attempts to repack 5 GiB+ to recover 280 MiB, I ctrl-C:

$ rustic prune --instant-delete
using config ./rustic.toml
[INFO] repository rclone:OD01-ENC:restic-test: password is correct.
[INFO] using cache at /Users/kptsky/Library/Caches/rustic/4f2d3e038efab8e03b2c1b3281e3bda9ae614ee9a03e23baba1a4f380a5ae80c
[00:00:00] reading index...               ████████████████████████████████████████          7/7
[00:00:00] reading snapshots...           ████████████████████████████████████████          3/3
[00:00:03] finding used blobs...          ████████████████████████████████████████          3/3
[00:00:30] getting packs from repository...                                                                                                                                               
to repack:        159 packs,      52243 blobs,    5.5 GiB
this removes:                      3357 blobs,  281.2 MiB
to delete:          0 packs,          0 blobs,        0 B
unindexed:          0 packs,         ?? blobs,        0 B
total prune:                       3357 blobs,  281.2 MiB
remaining:                       138083 blobs,   15.5 GiB
unused size after prune:  533.6 MiB (3.36% of remaining size)

packs marked for deletion:          0,        0 B
 - complete deletion:               0,        0 B
 - keep marked:                     0,        0 B
 - recover:                         0,        0 B
[00:00:03] repacking // rebuilding index... ░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░   6.62 MiB/5.18 GiB   1.79 MiB/s   (ETA 40m)                                                        
 ^C

now it gets interesting, I run limited prune - for only 1 GiB worth of data:

$ rustic prune --max-repack 1GiB --instant-delete
using config ./rustic.toml
[INFO] repository rclone:OD01-ENC:restic-test: password is correct.
[INFO] using cache at /Users/kptsky/Library/Caches/rustic/4f2d3e038efab8e03b2c1b3281e3bda9ae614ee9a03e23baba1a4f380a5ae80c
[00:00:00] reading index...               ████████████████████████████████████████          9/9
[00:00:00] reading snapshots...           ████████████████████████████████████████          3/3
[00:00:03] finding used blobs...          ████████████████████████████████████████          3/3
[00:00:12] getting packs from repository...                                                                                                                                               
to repack:         42 packs,      23012 blobs,    1.3 GiB
this removes:                      3788 blobs,  361.0 MiB
to delete:          7 packs,       1428 blobs,  227.2 MiB
unindexed:          1 packs,         ?? blobs,   36.0 MiB
total prune:                       5216 blobs,  624.1 MiB
remaining:                       138685 blobs,   15.6 GiB
unused size after prune:  592.2 MiB (3.72% of remaining size)

packs marked for deletion:          0,        0 B
 - complete deletion:               0,        0 B
 - keep marked:                     0,        0 B
 - recover:                         0,        0 B
[00:00:00] removing unindexed packs...    ████████████████████████████████████████          1/1
[00:33:13] repacking // rebuilding index... ████████████████████████████████████████ 1009.97 MiB/1009.97 MiB 518.77 KiB/s (ETA 0s)
[00:00:00] removing old index files...    ████████████████████████████████████████          8/8
[00:00:01] removing old data packs...     ████████████████████████████████████████         45/45
[00:00:00] removing old tree packs...     ████████████████████████████████████████          4/4

subsequent attempt to prune does not have to do anything. The question is why at the beginning rustic tried to repack 5 GiB but then is perfectly happy with forced repacking 1 GiB only??

$ rustic prune --instant-delete
using config ./rustic.toml
[INFO] repository rclone:OD01-ENC:restic-test: password is correct.
[INFO] using cache at /Users/kptsky/Library/Caches/rustic/4f2d3e038efab8e03b2c1b3281e3bda9ae614ee9a03e23baba1a4f380a5ae80c
[00:00:00] reading index...               ████████████████████████████████████████          8/8
[00:00:00] reading snapshots...           ████████████████████████████████████████          3/3
[00:00:03] finding used blobs...          ████████████████████████████████████████          3/3
[00:00:12] getting packs from repository...                                                                                                                                               
to repack:          0 packs,          0 blobs,        0 B
this removes:                         0 blobs,        0 B
to delete:          0 packs,          0 blobs,        0 B
unindexed:          0 packs,         ?? blobs,        0 B
total prune:                          0 blobs,        0 B
remaining:                       138280 blobs,   15.5 GiB
unused size after prune:  536.7 MiB (3.38% of remaining size)

[kapitainsky]

And one more clean test:

forgetting one snapshot:

$ rustic forget
using config ./rustic.toml
[INFO] repository rclone:OD01-ENC:restic-test: password is correct.
[INFO] using cache at /Users/kptsky/Library/Caches/rustic/4f2d3e038efab8e03b2c1b3281e3bda9ae614ee9a03e23baba1a4f380a5ae80c
snapshots for (host [DB-laptop.local], label [], paths [/])

| ID       | Time                | Host            | Label | Tags        | Paths | Action | Reason  |
|----------|---------------------|-----------------|-------|-------------|-------|--------|---------|
| 97bccb2e | 2024-01-21 10:11:31 | kp-laptop.local |       | test_rustic | /     | keep   | last    |
|          |                     |                 |       |             |       |        | daily   |
|          |                     |                 |       |             |       |        | weekly  |
|          |                     |                 |       |             |       |        | monthly |
| 4f514200 | 2024-01-20 07:45:54 | kp-laptop.local |       | test_rustic | /     | keep   | last    |
|          |                     |                 |       |             |       |        | daily   |
| 3980d1f6 | 2024-01-19 19:41:01 | kp-laptop.local |       | test_rustic | /     | remove |         |
| 2bc5f01c | 2023-12-31 20:44:27 | kp-laptop.local |       | test_rustic | /     | keep   | weekly  |
|          |                     |                 |       |             |       |        | monthly |

[00:00:00] removing snapshots...          ████████████████████████████████████████          1/1

dry-run prune to see how much data has to be repacked - 4.7 GiB

$ rustic prune --instant-delete --dry-run
using config ./rustic.toml
[INFO] repository rclone:OD01-ENC:restic-test: password is correct.
[INFO] using cache at /Users/kptsky/Library/Caches/rustic/4f2d3e038efab8e03b2c1b3281e3bda9ae614ee9a03e23baba1a4f380a5ae80c
[00:00:00] reading index...               ████████████████████████████████████████          8/8
[00:00:00] reading snapshots...           ████████████████████████████████████████          3/3
[00:00:02] finding used blobs...          ████████████████████████████████████████          3/3
[00:00:13] getting packs from repository...    
to repack:        139 packs,      45434 blobs,    4.7 GiB
this removes:                      1349 blobs,   61.8 MiB
to delete:          0 packs,          0 blobs,        0 B
unindexed:          0 packs,         ?? blobs,        0 B
total prune:                       1349 blobs,   61.8 MiB
remaining:                       138825 blobs,   15.5 GiB
unused size after prune:  553.4 MiB (3.48% of remaining size)

packs marked for deletion:          0,        0 B
 - complete deletion:               0,        0 B
 - keep marked:                     0,        0 B
 - recover:                         0,        0 B

asking to repack only 1 GiB

$ rustic prune --max-repack 1GiB --instant-delete
using config ./rustic.toml
[INFO] repository rclone:OD01-ENC:restic-test: password is correct.
[INFO] using cache at /Users/kptsky/Library/Caches/rustic/4f2d3e038efab8e03b2c1b3281e3bda9ae614ee9a03e23baba1a4f380a5ae80c
[00:00:00] reading index...               ████████████████████████████████████████          8/8
[00:00:00] reading snapshots...           ████████████████████████████████████████          3/3
[00:00:03] finding used blobs...          ████████████████████████████████████████          3/3
[00:00:14] getting packs from repository...                                                                                                                                               to repack:         35 packs,      19360 blobs,    1.0 GiB
this removes:                       946 blobs,   37.9 MiB
to delete:          0 packs,          0 blobs,        0 B
unindexed:          0 packs,         ?? blobs,        0 B
total prune:                        946 blobs,   37.9 MiB
remaining:                       139228 blobs,   15.6 GiB
unused size after prune:  577.3 MiB (3.62% of remaining size)

packs marked for deletion:          0,        0 B
 - complete deletion:               0,        0 B
 - keep marked:                     0,        0 B
 - recover:                         0,        0 B

[00:53:36] repacking // rebuilding index... ████████████████████████████████████████ 991.94 MiB/991.94 MiB 315.80 KiB/s (ETA 0s)
[00:00:00] removing old index files...    ████████████████████████████████████████          8/8
[00:00:00] removing old data packs...     ████████████████████████████████████████         29/29
[00:00:00] removing old tree packs...     ████████████████████████████████████████          6/6

and surprise, surprise rustic does not want to repack anything more

$ rustic prune --instant-delete
using config ./rustic.toml
[INFO] repository rclone:OD01-ENC:restic-test: password is correct.
[INFO] using cache at /Users/kptsky/Library/Caches/rustic/4f2d3e038efab8e03b2c1b3281e3bda9ae614ee9a03e23baba1a4f380a5ae80c
[00:00:00] reading index...               ████████████████████████████████████████          9/9
[00:00:00] reading snapshots...           ████████████████████████████████████████          3/3
[00:00:02] finding used blobs...          ████████████████████████████████████████          3/3
[00:00:12] getting packs from repository...                                                                                                                                               to repack:          0 packs,          0 blobs,        0 B
this removes:                         0 blobs,        0 B
to delete:          0 packs,          0 blobs,        0 B
unindexed:          0 packs,         ?? blobs,        0 B
total prune:                          0 blobs,        0 B
remaining:                       139145 blobs,   15.6 GiB
unused size after prune:  562.0 MiB (3.53% of remaining size)

packs marked for deletion:          0,        0 B
 - complete deletion:               0,        0 B
 - keep marked:                     0,        0 B
 - recover:                         0,        0 B
[00:00:02] rebuilding index...
[00:00:00] removing old index files...    ████████████████████████████████████████          5/5

[kapitainsky]

And at last comparison with restic - the same repo:

$ rustic prune --instant-delete --dry-run
[00:00:00] reading index...               ████████████████████████████████████████          8/8
[00:00:00] reading snapshots...           ████████████████████████████████████████          3/3
[00:00:02] finding used blobs...          ████████████████████████████████████████          3/3
[00:00:11] getting packs from repository...                                                                                                                                               to repack:        129 packs,      42773 blobs,    4.3 GiB
this removes:                      1434 blobs,   74.2 MiB
to delete:          0 packs,          0 blobs,        0 B
unindexed:          0 packs,         ?? blobs,        0 B
total prune:                       1434 blobs,   74.2 MiB
remaining:                       139946 blobs,   15.7 GiB
unused size after prune:  594.6 MiB (3.71% of remaining size)

packs marked for deletion:          0,        0 B
 - complete deletion:               0,        0 B
 - keep marked:                     0,        0 B
 - recover:                         0,        0 B

but restic:

$ restic prune --dry-run
repository 4f2d3e03 opened (version 2, compression level max)
loading indexes...
[0:05] 100.00%  8 / 8 index files loaded
loading all snapshots...
finding data that is still in use for 3 snapshots
[0:11] 100.00%  3 / 3 snapshots
searching used packs...
collecting packs for deletion and repacking
[0:12] 100.00%  457 / 457 packs processed

Would have made the following changes:
to repack:         12002 blobs / 9.893 MiB
this removes:        631 blobs / 1.413 MiB
to delete:             0 blobs / 0 B
total prune:         631 blobs / 1.413 MiB
remaining:        140749 blobs / 15.735 GiB
unused size after prune: 667.313 MiB (4.14% of remaining size)

rustic wants to repack 4.3 GiB when restic 9.9 MiB

[aawsome]

I think this is more a documentation/clarification issue. Rustic has a dynamic targeted packsize depending on the repository size.
This means, if you increase the repository size, rustic does create large pack files and prune will try to repack packs with non-matching sizes. The algorithm about determining the target pack size and the thresholds when rustic will try to repack too small or too large sized packs are saved in the repository config file and can be set using rustic config (add --help to see the possible options).
However, I'm not sure if the chosen defaults in the for the tuning parameters can be improved, so feedback about it is highly welcome!

The idea about pack sizes depending on the repository size is that you get a good fit for individual repsoitories without the need to set/guess something optimal. In general, rustic's pack sizes are larger than restics and can go up to almost 4GiB.
The idea about repacking too small / or too large packs is that for a stable situation (periodic backups, periodic forget/prune), your repository size should stay almost constant, while this usually only changes at one-time events like adding new sources etc. And then a one-time prune to correct some pack sizes IMO is OK.

To ignore too small or too large packs, there is prune --no-resize which should behave exactly like restic.

[simonsan]

✅ rustic-rs/docs#56

[aawsome]

And I think we should open an issue about the prune output/statistics - There it should be actually get clear why the packs are repacked, but it can be actually multiple reasons: Not fully used + too small can both apply, for example. I didn't get an idea so far how to present such kind of results in a good way...

[simonsan]

✅ rustic-rs/rustic_core#137

[kapitainsky]

I think this is more a documentation/clarification issue. Rustic has a dynamic targeted packsize depending on the repository size.
This means, if you increase the repository size, rustic does create large pack files and prune will try to repack packs with non-matching sizes. The algorithm about determining the target pack size and the thresholds when rustic will try to repack too small or too large sized packs are saved in the repository config file and can be set using rustic config (add --help to see the possible options).

Sorry but it does not adds up. This is 15GB repository size (very small). And default min_packsize_tolerate_percent is 30. It means that this repo is using 33 MiB pack size. And to remove 200 MiB it should not have to repack 5 GiB as should happily live with even 11 MiB packs.

[aawsome]

Will have to take a closer look on this. Can you give the output of rustic repoinfo for this repository?

[kapitainsky]

If you need any tests or data let me know. I am a big fan of rustic now but still keeping an eye on its performance and behaviour hence this post:)

[kapitainsky]

and please note my first post. When I asked to only repack 1GiB - subsequent runs have nothing to do. It means that running initial 5 GiB repack would be waste?

[aawsome]

Can you give the output of rustic repoinfo for this repository?

[kapitainsky]

File type	Count	Total Size
Key	1	460 B
Snapshot	3	1.7 kiB
Index	8	6.8 MiB
Pack	457	15.7 GiB
Total	469	15.7 GiB

Blob type	Count	Total Size	Total Size in Packs
Tree	33647	63.9 MiB	22.7 MiB
Data	107733	41.6 GiB	15.7 GiB
Total	141380	41.7 GiB	15.7 GiB

Blob type	Pack Count	Minimum Size	Maximum Size
Tree packs	12	350.7 kiB	4.5 MiB
Data packs	445	5.0 MiB	66.8 MiB

[aawsome]

Ah, and I forgot to mention that the default for --max-repack has been changed from unlimited to 10%. (will be in the next release)

Another difference is that rustic always does repack partly used tree pack files. Those should be fast accessible for basically all command and are also in the cache unless it is deactivated. Hence repacking those should be very fast.

But @kapitainsky I agree your results look strange. I need to take a closer look and - as mentioned - we need to add more analysis possibilities in the prune output.
Just one question: Is this a repo which was created and filled by restic or one where you just used rustic?

[kapitainsky]

Ah, and I forgot to mention that the default for --max-repack has been changed from unlimited to 10%.

Then it is even more weird. I thought it is 5%. And this repo right now has less than 5% unused size. So rustic should just do small maintenance (tree packs) and job done.

[aawsome]

The default for --max-unused is and was always 5%.
The default for --max-repack in 0.6.1 is unlimited and will be 10% in 0.7.0.

[kapitainsky]

ok. This is clear now.

[kapitainsky]

Just one question: Is this a repo which was created and filled by restic or one where you just used rustic?

It is used exclusively with rustic. Only restic operations I have tried were with --dry-run to see differences or restic check which does not write anything

[kapitainsky]

In the meantime I will leave this test repo as it is - so I can use it later if you make any changes.

[aawsome]

Can you please also run the above prune command with your self-compiled binary which adds more debug output? Thanks a lot!

[kapitainsky]

I hope rustic-rs/rustic_core#167 will answer it - but I will wait for this change to make into production to test.

[aawsome]

Yes, I think this is solved with rustic-rs/rustic_core#167.
BTW - it is already included in the current main branch and will be in the next official release, too.

[kapitainsky]

I have compiled the latest dev version (main branch) and indeed it is now behaving more as expected. Caveat is to understand that there are two flags --max-unused and --max-repack which influence each other - but this is more docs problem now.

BTW - would it be possible to include e.g. the last git commit number in rustic --version? When playing with different branches I find it really hard to make sure that I am running correct rustic binary.

[aawsome]

BTW - would it be possible to include e.g. the last git commit number in rustic --version? When playing with different branches I find it really hard to make sure that I am running correct rustic binary.

The nightly builds have the commit in the version. If you want to do the same with your own builds, see /~https://github.com/rustic-rs/rustic/blob/main/scripts/build.sh