Confused by snapshot output on unchanged source folder

axeleroy · November 4, 2020, 8:44am

Hello,

I’m looking for some clarification on the behavior I encountered when doing a snapshot.

Yesterday I set up a repo and made a snapshot of a ~660GB directory, which took almost 4 hours. I then set up a cron job that would make a snapshot of the same folder every night.

Since I haven’t touched the content of the directory, I was expecting a quick snasphot. Yet I was surprised when I checked my cron’s output this morning:

$ export RESTIC_PASSWORD_FILE=/root/restic_pwd.txt
$ restic backup -r /export/backups/photos /export/photos
Files: 68741 new, 0 changed, 0 unmodified
Dirs: 374 new, 0 changed, 0 unmodified
Added to the repo: 752 B

processed 68741 files, 665.526 GiB in 1:37:14
snapshot 5bfc49f2 saved

This raised a few questions:

Why did it marked every files as new instead of unmodified?
It seems it spent 1h37 scanning the entire folder for changes, is there a way to speed up the process?

Thanks

Edit: forgot to specify the version I’m running.

axel@helios64:~$ restic version
restic 0.10.0 compiled with go1.15.2 on linux/arm64

rawtaz · November 4, 2020, 1:47pm

Please edit your post so that the output you show includes the entire command (and any environment variables that you use) and all of its output.

axeleroy · November 4, 2020, 3:03pm

Sure, I added the command and env variable, though since it ran in a cron, the only input I have is in the original post.

rawtaz · November 4, 2020, 3:26pm

Can’t you run it manually (the same command of course) to see if it reproduces that way too (it should, and then you should be able to get the complete output)?

axeleroy · November 4, 2020, 3:46pm

I ran the command a second time expecting it to run for more than an hour and got this:

$ export RESTIC_PASSWORD_FILE=/root/restic_pwd.txt
$ restic backup -r /export/backups/photos /export/photos
repository 23f4efef opened successfully, password is correct

Files: 0 new, 0 changed, 68741 unmodified
Dirs: 0 new, 0 changed, 374 unmodified
Added to the repo: 0 B

processed 68741 files, 665.526 GiB in 0:35
snapshot 780215dc saved

I ran the command through OpenMediaVault (I originally set up the cron with its GUI) to make sure it was not inferring with restic, got the same output as above.

Weird. I enabled the cron, I’ll see if it behaves differently tonight.

rawtaz · November 4, 2020, 4:16pm

Thank you for that. Unfortunately I was missing one thing; Can you please add -v so the command is restic -v backup -r /export/backups/photos /export/photos? That way we can verify that restic uses a parent snapshot, which I presume it does.

axeleroy · November 4, 2020, 4:26pm

Sure:

$ export RESTIC_PASSWORD_FILE=/root/restic_pwd.txt
$ restic backup -v -r /export/backups/photos /export/photos
open repository
repository 23f4efef opened successfully, password is correct
lock repository
load index files
using parent snapshot ec2bd430
start scan on [/export/photos/]
start backup on [/export/photos/]
scan finished in 10.953s: 68741 files, 665.526 GiB>

Files: 0 new, 0 changed, 68741 unmodified
Dirs: 0 new, 0 changed, 374 unmodified
Data Blobs: 0 new
Tree Blobs: 0 new
Added to the repo: 0 B

processed 68741 files, 665.526 GiB in 0:33
snapshot 4f22082e saved

So your hypothesis is that last night’s backup did not use a parent snapshot?

rawtaz · November 4, 2020, 4:33pm

Honestly, if the backup set you used in the cron run was the same as your initial run, then I would totally expect that restic found the parent snapshot. But if it did not, then that is one possible reason why it rescanned the files.

I don’t know what your repo is stored on but you can try using the --ignore-inode option or the --ignore-ctime option in https://github.com/restic/restic/pull/2823 (if you build your restic from that PR, as it’s not in the 0.10.0 version of restic). But it all depends on what the storage is.

Why it took so long to rescan I can’t say, I’d expect that to depend on the performance of your system’s components.

axeleroy · November 4, 2020, 4:41pm

Both the source folder and the repo are stored on MergerFS over ext4.

If I believe Restic detecting (non-existing?) changes result in long backup time, MergerFS does not preserve inodes, so I guess I have my culprit.

Using --ignore-inode should do the trick, right?

rawtaz · November 4, 2020, 5:01pm

Looks like MergerFS has options for the inode management: https://github.com/trapexit/mergerfs#inodecalc

But yes, try --ignore-inode if you see the problem again.

axeleroy · November 4, 2020, 5:07pm

Thank you very much!

I do have one last question: is there any performance penalty by using --ignore-inode?

rawtaz · November 4, 2020, 5:27pm

You’re welcome! Please let us know how it goes in the end

Nope, --ignore-inode just doesn’t take inodes into account when determining what changed.

axeleroy · November 4, 2020, 5:34pm

Well, I set MergerFS’s inodecalc option to path-hash (as it also improves performance on NFS shares) in addition to using --ignore-inode.

axeleroy · November 5, 2020, 8:23am

Small update: tonight’s backup worked like a charm!

$ export RESTIC_PASSWORD_FILE=/root/restic_pwd.txt
$ restic backup -v -r /export/backups/photos /export/photos
open repository
repository 23f4efef opened successfully, password is correct
lock repository
load index files
using parent snapshot 4f22082e
start scan on [/export/photos]
start backup on [/export/photos]
scan finished in 14.189s: 68741 files, 665.526 GiB

Files: 0 new, 0 changed, 68741 unmodified
Dirs: 0 new, 374 changed, 0 unmodified
Data Blobs: 0 new
Tree Blobs: 237 new
Added to the repo: 54.688 MiB

processed 68741 files, 665.526 GiB in 0:36
snapshot 5438d64c saved

rawtaz · November 8, 2020, 1:40pm

Thanks a lot for getting back to everyone and letting us know how what solved the problem!