Invalid: Restic extremely slow on machines with many logical volumes

[nis65]

Output of restic version

restic 0.16.4 compiled with go1.21.6 on linux/amd64

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

Infomaniak "Swiss Backup" S3 compatible

Problem description / Steps to reproduce

I started using restic a few months ago. I already have in place a working backup host that backs up about 25 clients (each into his own subdirectory) with an rsync based solution called "dirvish". I use LVM extensively, all clients have their own LV on the backup host so that I can manage disk space individually. This gives 25 LVs to be restic backed up that are found during lvscan and mounted on startup.

Dirvish creates a new timestamp named directory on the backup host for each backup run. I use restic to mirror the latest run of each client to cloud storage. As restic does not prune the full path, I apply a bind mount on top that mounts the latest directory to bindlatest, so that it is always the same path for restic.

The backup host is powered off after each the backup and woken up on LAN daily.

The restic command is as follows (the ignore parameters are probably not needed any more after this issue is solved):

restic backup -v --ignore-ctime --ignore-inode --no-extra-verify /home/backup/myHOST/bindlatest

The prima vista symptom was that

• whenever I manually run my backup script, it is quite fast (less than 30mins for all hosts),

• but when I let the system run it automatically, it takes 16hours. See this comment of mine. However, this turned out not to be the final truth. I found out later:

• As long as my backup server stays powered, the allocation of minor device numbers is stable, i.e. /dev/mapper/VG_LV will always have the same minor number, even after a reboot, eg:

  • brw-rw---- 1 root disk 253, 7 Apr 7 08:42 /dev/mapper/myVG_myLV

• But when I power cycle the machine, the minor numbers change wildly as they are dynamically assigned during the activation of the LVs.

So, to rephrase my learnings: Using restic with dynamically changing major/minor device ids of the source file systems is to be avoided!

The full output of my restic backup wrapper (after a change of the minor device number): 2h15min

#INF: Repo chosen for milou: s3:https://s3.swiss-backup03.infomaniak.com/restic-pot202403
#INF creating bind mount for /home/backup/milou/20240330-2004 on /home/backup/milou/bindlatest
#INF#Wed Apr  3 05:16:38 AM CEST 2024# restic backup -v --ignore-ctime --ignore-inode --no-extra-verify /home/backup/milou/bindlatest
open repository
lock repository
using parent snapshot 3af862d5
load index files
start scan on [/home/backup/milou/bindlatest]
start backup on [/home/backup/milou/bindlatest]
scan finished in 55.488s: 516965 files, 35.138 GiB

Files:           0 new,     0 changed, 516965 unmodified
Dirs:            0 new,     0 changed, 82420 unmodified
Data Blobs:      0 new
Tree Blobs:      0 new
Added to the repository: 0 B   (0 B   stored)

processed 516965 files, 35.138 GiB in 2:15:50
snapshot e7ffe15c saved
#INF umounting /home/backup/milou/bindlatest
#INF#Wed Apr  3 07:32:31 AM CEST 2024# done

And without a change of the major/minor (and no change in the source data): 1m30sec

#INF: Repo chosen for milou: s3:https://s3.swiss-backup03.infomaniak.com/restic-pot202403
#INF creating bind mount for /home/backup/milou/20240330-2004 on /home/backup/milou/bindlatest
#INF#Wed Apr  3 11:27:08 PM CEST 2024# restic backup -v --ignore-ctime --ignore-inode --no-extra-verify /home/backup/milou/bindlatest
open repository
lock repository
using parent snapshot e7ffe15c
load index files
start scan on [/home/backup/milou/bindlatest]
start backup on [/home/backup/milou/bindlatest]
scan finished in 69.366s: 516965 files, 35.138 GiB

Files:           0 new,     0 changed, 516965 unmodified
Dirs:            0 new,     0 changed, 82420 unmodified
Data Blobs:      0 new
Tree Blobs:      0 new
Added to the repository: 0 B   (0 B   stored)

processed 516965 files, 35.138 GiB in 1:30
snapshot 87c73a40 saved
#INF umounting /home/backup/milou/bindlatest
#INF#Wed Apr  3 11:28:40 PM CEST 2024# done

Expected behavior

When I backup the same path (e.g. /home/backup/myhost) I excpect restic to understand that this is the same data.

Actual behavior

When the same path has new major/minor, restic does not trust that the local and remote data are equal and does the full backup process only to add a few bytes (if at all) after a few hours.

Do you have any idea what may have caused this?

As written above, restic is very sensitive to the device_id. I am just about to try to control the major/minor number of my logical volumes as follows:

lvchange --persistent y --minor $MINOR MV_VG/MY_LV

The red hat docs were helpful. I started with minor 32 for the persistent allocation so that there is enough room below for dynamically allocated ones (like the root or swap file system).

The bind mount mounts an already mounted device again. Therefore the device id of the device under the bind mount is the same as the one under the original mount.

I will be able to confirm if this really was the solution to my issues in about two days, but I am quite optimistic.

Did restic help you today? Did it make you happy in any way?

Restic is fantastic (when you use it the right way, see above). In the first week of my usage with it, I accidently destroyed the local copy of some data but could easily recover it via restic.

[MichaelEischer]

There are multiple major problems with your theory about the root cause of the performance problems:

• The major/minor number of a file's device is stored as part of the directory metadata. Thus, if there is any change to it, then restic would upload new tree blobs and mark all directories as changed. As this is not the case here, I'm pretty sure that major/minor device numbers are not the problem here.
• Why would the minor number of LVs change across power cycles, but remain unchanged across reboots? Enumeration order in the BIOS would explain why PVs change their number after power cycling. But that shouldn't affect the LVs?
• With the flags you've passed to restic, the change detection solely relies on file type, size and mtime (modification time). The backup never uses the device major/minor to decide whether a file must be read again from disk.

Thus, the problem must be caused by something else. Please provide the information I've asked for in #3041 (comment) .

[nis65]

Thanks @MichaelEischer : Your clear words helped to free my own mind of some weird theories.

Before raising wrong flags here (again) just a short update. I think I actually found the issue (and how I - and not restic - was causing it), but it will take me few more days to fully prove the solution. I will likely need to completely reformulate the issue, including the title... 🙈

[nis65]

Hi @MichaelEischer

current state of affairs:

• I was wrong with assuming that it has something to do with reboot / power / etc.
• The root cause was that - depending on how restic was called - restic did or did not manage to identify the cache directory. So of course restic is slow when there is no cache.
• When restic was called as a systemd service (so that it runs automatically after boot), either no or a new cache (did not track down exactly) was used.
• When restic was run from the terminal as root, the cache was used.

I compared the environments (as listed by printenv | sort) and this is the delta I got (the PATH is truncated to make the output more readable)

==================== printenv ========================          ==================== printenv ========================
HOME=/root                                                 |    INVOCATION_ID=9ae5afe877704683b16970f9c82579b4
                                                           >    JOURNAL_STREAM=8:18319
LANG=en_US.UTF-8                                                LANG=en_US.UTF-8
LOGNAME=root                                               <
MAIL=/var/mail/root                                        <
OLDPWD=/usr/local/bin                                      <
PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/        PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/
PWD=/root                                                  |    PWD=/
SHELL=/bin/bash                                            |    SHLVL=1
SHLVL=2                                                    |    SYSTEMD_EXEC_PID=1241
TERM=xterm-256color                                        <
USER=root                                                  <
_=/usr/bin/printenv                                             _=/usr/bin/printenv

With the left side (called from a shell as root), the cache below /root/.cache/restic was used.

With the right side (called from systemd) environment, no cache (or a new on each run) was used.

My setup uses the cache predictably now - independent of how it is called - because I am setting RESTIC_CACHE_DIR explicitly now.

So the only thing that remains to complain about is that I seem to remember to have seen a warning about "very slow without cache" only on very few occasions and I would have wished that restic is more informative when something went wrong (well, what is "wrong"?) with finding a cache. Why not print a message whenever an empty cache is initialized and when no cache is used?

[nis65]

More information:

My "primary" (rsync-based) backup program creates a new directory per backup generation, hard linking all identical files to the previous generation. Unchanged files occupy only a new directory entry, but neither an inode nor a data block - a simple file based "deduplication".

I (wrongly) assumed, that the my "primary" program persists all metadata, but unfortunately the ctime is not properly maintained. See e.g. this backup of /etc/hosts : the directory name represents the start of the backup, the Change timestamp is just a few seconds later (which is of course is not the case on the source system). So although the file stays the same (i.e. same inode), the Change timestamp is (unfortunately) updated on each backup run:

root@kronos:/home/backup/bestla# stat 20240413-0947/tree/etc/hosts
  File: 20240413-0947/tree/etc/hosts
  Size: 401       	Blocks: 8          IO Block: 4096   regular file
Device: 253,32	Inode: 532268      Links: 25
Access: (0644/-rw-r--r--)  Uid: (    0/    root)   Gid: (    0/    root)
Access: 2020-11-29 17:08:02.067626700 +0100
Modify: 2018-04-12 21:08:48.651761056 +0200
Change: 2024-04-13 09:47:29.807098815 +0200
 Birth: 2018-04-13 09:47:17.773669777 +0200

As the bind mounts do not change the inode, I am happy now with

• setting the cache explicitly (so that calling from systemd uses the cache too), see previous comment
• using --ignore-ctime, I don't need --ignore-inode.

With defaults

start scan on [/home/backup/bestla/bindlatest]
start backup on [/home/backup/bestla/bindlatest]
scan finished in 10.889s: 40918 files, 3.162 GiB

Files:           1 new, 40917 changed,     0 unmodified
Dirs:            0 new,  5230 changed,     0 unmodified
Data Blobs:    170 new
Tree Blobs:   4630 new
Added to the repository: 110.155 MiB (24.815 MiB stored)

processed 40918 files, 3.162 GiB in 1:07

With ignore-ctime

start scan on [/home/backup/bestla/bindlatest]
start backup on [/home/backup/bestla/bindlatest]
scan finished in 6.692s: 40918 files, 3.182 GiB

Files:           0 new,    96 changed, 40822 unmodified
Dirs:            4 new,  5226 changed,     0 unmodified
Data Blobs:    182 new
Tree Blobs:   4630 new
Added to the repository: 105.902 MiB (24.695 MiB stored)

processed 40918 files, 3.182 GiB in 0:15

@MichaelEischer I started this ticket with a false assumption, even the title is wrong (now that I know). Do you want me to

• edit this ticket (change the title, add some correcting text)?
• create a new ticket and abandon this one?

I have two intentions:

• Make the tickets helpful to others, especially to people that run restic directly from systemd. I don't think the current state is really helpful.
• Feature request for an explicit warning whenever the cache is not used or a new one is initialized.

[MichaelEischer]

• create a new ticket and abandon this one?

There's too much unrelated information in this issue. Let's create a new one; just make sure to include a link back to this one.

I (wrongly) assumed, that the my "primary" program persists all metadata, but unfortunately the ctime is not properly maintained.

As far as I remember, a user space program cannot modify ctime on Linux. It is always set by the kernel.

• especially to people that run restic directly from systemd.

It would be possible to let restic try whether /var/cache/restic is accessible. However, I'm not sure that is a good idea.

• Feature request for an explicit warning whenever the cache is not used or a new one is initialized.

There should already be an error that gets printed to stderr, see

restic/cmd/restic/global.go

Line 514 in 2173c69

Warnf("unable to open cache: %v\n", err)

. Can you provide a sample of your systemd service?

[nis65]

closing issue here. Too many assumptions, sorry for the noise. Real issue is now in #4775