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

prunestats inconsistent / inaccurate #3918

Closed
jdannenberg opened this issue Sep 6, 2022 · 2 comments · Fixed by #3980
Closed

prunestats inconsistent / inaccurate #3918

jdannenberg opened this issue Sep 6, 2022 · 2 comments · Fixed by #3980
Labels
category: prune state: need investigating cause unknown, need investigating/troubleshooting type: bug

Comments

@jdannenberg
Copy link

jdannenberg commented Sep 6, 2022

What's the version of restic you used? Please include the output of restic version in your bug report.

restic 0.14.0 compiled with go1.19 on linux/amd64

What commands did you execute to get to where the bug occurred?

The starting point is a ~ 3,2 TiB repository pre 0.14.0. I then:

  • updated restic and migrated the repository to v2
  • ran: restic prune --compression max --pack-size 64 --repack-uncompressed --repack-small --no-cache
  • This run got OOM killed at about 50-60%; I upgraded memory and continued
  • ran: restic prune --compression max --pack-size 64 --repack-uncompressed --repack-small --no-cache --dry-run
  • ran: restic prune --compression max --pack-size 64 --repack-uncompressed --repack-small --no-cache

I do not have any logs of the first restic prune run.

What did you expect?

I expected that prune dry-run and wet run behave the same (deterministic) regarding the stats they show. And I expect the numbers to be correct in any case.

What happened instead?

Log of 2nd prune:

loading indexes...                                                                                       
loading all snapshots...                                                                                 
finding data that is still in use for 842 snapshots                                                      
[38:23] 100.00%  842 / 842 snapshots                                                                     
searching used packs...                                                                                                                                                                                            
collecting packs for deletion and repacking                                                              
[7:12] 100.00%  736014 / 736014 packs processed                                                          
                                                                                                         
to repack:      **15759546 blobs / 3.151 TiB**                                                               
this removes:    1146545 blobs / 93.147 GiB                                                              
to delete:       **3723161 blobs / 1.768 TiB**                                                               
total prune:     4869706 blobs / 1.859 TiB                                                               
remaining:      14613001 blobs / 3.060 TiB                                                               
unused size after prune: **16777215.991 TiB** (100.00% of remaining size)

Log of 3rd prune:

loading indexes...                                                                                       
loading all snapshots...                                                                                 
finding data that is still in use for 842 snapshots                                                      
[35:23] 100.00%  842 / 842 snapshots                                                                     
searching used packs...                                                                                  
collecting packs for deletion and repacking                                                              
[7:44] 100.00%  736014 / 736014 packs processed                                                          
                                                                                                         
to repack:      **15828929 blobs / 3.154 TiB**                                                               
this removes:    1215928 blobs / 97.818 GiB                                                              
to delete:       **3653778 blobs / 1.765 TiB**                                                               
total prune:     4869706 blobs / 1.861 TiB                                                                                                                                                                         
remaining:      14613001 blobs / 3.058 TiB                                                               
unused size after prune: **16777215.989 TiB** (100.00% of remaining size)                                                                                                                                              
                                                                                                         
deleting unreferenced packs                                                                              
[23:54] 100.00%  88673 / 88673 files deleted                                                             
repacking packs                                                                                          
[11:53:12] 12.91%  86136 / 667243 packs repacked

There is a discrepancy between dry-run and wet-run in terms of blobs to repack and blobs to delete. Dry-run shows the respective blocks as to delete whereas wet-run shows them as to repack. Additonally, the unused size after prune is definitely inaccurate.

Are you aware of a way to reproduce the bug?

No.

@MichaelEischer MichaelEischer added type: bug category: prune state: need investigating cause unknown, need investigating/troubleshooting labels Sep 9, 2022
@MichaelEischer
Copy link
Member

After a bit of digging, I think I have an explanation for the behavior.

  • The code to handle duplicate blobs may select different pack files to keep each time it runs. That is it is perfectly valid to have small variations in the amount of data that is kept/repacked by prune.
  • The "unused sized after prune" obviously overflows. This is probably caused by a new edge case that only appears when compressing an existing repository: it is now possible for multiple instances of a blob to exist which have a different length. The first instance of a blob is added to the used blob size, whereas all later instance are counted as duplicates. Now, if some instance other than the first blob instance is kept, we have all necessary ingredients. The first instance and the selected instance can now differ in their size and thereby lead to a wrong blob size counter.

The side effects of the blob size accounting problems are limited though: prune will just repack a bit more data than necessary, but the repository won't be damaged in any way.

@jdannenberg
Copy link
Author

Thank you for investigating.

but the repository won't be damaged in any way.

That is reassuring for sure and I can confirm that.

The code to handle duplicate blobs may select different pack files to keep each time it runs. That is it is perfectly valid to have small variations in the amount of data that is kept/repacked by prune.

Is that something restic could inform users (e.g. only for dry-run as that one is likely "repeated") about?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
category: prune state: need investigating cause unknown, need investigating/troubleshooting type: bug
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants