lstat No Such file or directory

[TheLastProject]

I wasn't sure if I should've added this to #692 or not, but /proc isn't really a place you want to backup, and this happened on a normal place to backup. I apologize if adding it to that issue was better.

Output of restic version

restic 0.9.3 compiled with go1.11.1 on linux/amd64

How did you run restic exactly?

From cron:

MAILTO=""
SHELL=/bin/sh
PATH=/usr/local/sbin:/usr/local/bin:/sbin:/bin:/usr/sbin:/usr/bin:/usr/local/bin
RESTIC_REPOSITORY=azure:<hidden>
RESTIC_PASSWORD=<hidden>
AZURE_ACCOUNT_NAME=<hidden>
AZURE_ACCOUNT_KEY=<hidden>
0 */4 * * * restic restic backup /var/www/nextcloud/data >>/var/log/restic/restic.log 2>>/var/log/restic/error.log

Stderr output:

error: lstat /var/www/nextcloud/data/test.user/uploads/1036227155/00000005: no such file or directory
error: NodeFromFileInfo: Listxattr: xattr.list /var/www/nextcloud/data/test.user/uploads/1036227155/00000004 : no such file or directory

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

Azure Blob Storage

Expected behavior

Restic not throwing errors.

Actual behavior

Restic throws this error. The backup still seems to have succeeded.

Steps to reproduce the behavior

Unknown

Do you have any idea what may have caused this?

It seems to me that this file was removed from the file system between when restic found out the file existed and tried to back it up. So a race condition.

Do you have an idea how to solve the issue?

It's hard to tell, especially because you probably want to avoid hiding actual errors. But this error message seems to not be an actual issue, so we probably don't want it logged to the error log.

Did restic help you or made you happy in any way?

Yup, it's the first backup solution I've tried in ages that doesn't feel awful to use :)

[BenWiederhake]

I just ran into this issue, as a backup operation and a "tar-then-delete" operation ran concurrently.

Temporary workaround: Change the timing in cron.

As some details were left out, I just re-used the form.

Output of restic version

restic 0.9.5 compiled with go1.12.4 on linux/amd64

How did you run restic exactly?

RESTIC_REPOSITORY=foobar RESTIC_PASSWORD=foobar restic -q --exclude-file /path/to/exclude.lst backup --files-from /path/to/files-and-dirs.lst > /dev/null

(The quieting down happens because I run it as a cronjob, and want no output during a successful run.)

In my case, there was a directory /home/user/workspace/random-tweets/tarchives/tweets/ with roughly 30000 files in the process of being deleted. That took only a second or so, but apparently the fs race took place during that second.

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

sftp

Expected behavior

Restic not throwing errors.

For example, raise some kind of warnings, but do not abort. Also, only raise one kind of warning.

In case it already "does not abort", a final output line would be helpful, something like: "Some errors were encountered. However, all other 12345 files were backed up successfully."

Actual behavior

The following on stderr:

error: lstat /home/user/workspace/random-tweets/tarchives/tweets/819e38353fe9acdd_113XXXXXXXXXXXXXXXX.json: no such file or directory
<SNIP 12532 more lines SNIP>
error: lstat /home/user/workspace/random-tweets/tarchives/tweets/fffd01bb0c2ab58d_113XXXXXXXXXXXXXXXX.json: no such file or directory
error: NodeFromFileInfo: Listxattr: xattr.list /home/user/workspace/random-tweets/tarchives/tweets/819d211a9e937eb8_XXXXXXXXXXXXXXXXXXX.json : no such file or directory
error: NodeFromFileInfo: Listxattr: xattr.list /home/user/workspace/random-tweets/tarchives/tweets/819daa619a526f38_XXXXXXXXXXXXXXXXXXX.json : no such file or directory

The uncensored part is just 8 random bytes. The thousands of error: lstat lines are in lexical order. Note that the error: NodeFromFileInfo: points to a name that would be lexically just before 819e38353fe9acdd. Maybe that helps in localizing the error. 12532 is not an exaggeration. No other lines were omitted. XXXXXXX are the censored Twitter IDs.

Steps to reproduce the behavior

I have not tried to reproduce it, but this is how it probably could be enforced:

• Create a vast amount of files
• Start a backup
• While the backup is running, delete the vast amount of files

Do you have any idea what may have caused this?

Race condition, I agree.

Do you have an idea how to solve the issue?

Uhh.

Try to make only few syscalls that expect a coherent view of the filesystem, and make them as close together in time as possible. I.e., try to keep stat, lstat, xattr stuff together. Then if something goes wrong, handle it as the same kind of error: "File is incoherent" or something.

Did restic help you or made you happy in any way?

Absolutely! For my old backup system, I excluded that folder, because it's too many files. restic just plows through it.

[fortinmike]

I also encounter this. It occurs every time my backup script runs, with the same missing file causing the lstat error each time.

The described possible race condition seems likely as the thing I'm backing up is a Time Machine (Mac) sparse bundle, which contains tons of files that may or may not be removed during Time Machine backup. As Time Machine backup occurs approximately every hour, it's probable that restic and Time Machine ran at the same time at one point, causing this.

The restic backup seems to complete successfully even though this error is logged.

Output of restic version

restic 0.9.6 compiled with go1.13.4 on linux/386

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

Backblaze B2

Expected behavior

No errors occurring in subsequent backups when a file is removed during a backup.

Actual behavior

error: lstat /volumeUSB2/usbshare/MyMac.backupbundle/bands/1c43: no such file or directory

Steps to reproduce the behavior

See above posts.

Do you have any idea what may have caused this?

I also think this could be a race condition.

Do you have an idea how to solve the issue?

Maybe: In the backup logic, do not assume that a previously discovered file is still present on disk when the backup operation actually starts for that file. If that's the cause of the issue.

Did restic help you or made you happy in any way?

Of course! It's awesome. I love how similar to git it feels in many ways: file structure on disk, content integrity validation, versioned snapshots with ids, command-line interface, very flexible, etc. Pretty much the only power-user backup tool I tried that I feel I can trust with my data. It's fast too, which has been an issue with many other solutions I've tried.

[mika]

We're seeing this behavior quite often on systems where the file-system isn't consistent during backup execution (e.g. no LVM snapshot or alike). I'd very much appreciate if restic would support an option like --ignore-vanished-files for the backup execution, which wouldn't cause failing executions due to error: lstat [...]: no such file or directory.

[MichaelEischer]

which wouldn't cause failing executions due to error: lstat [...]: no such file or directory.

How do you arrive at the conclusion that these errors cause the backup to fail? restic continues with the backup even if some of the files cannot be read.

[mika]

@MichaelEischer I might be wrong and the failure might be caused by something else, but our systemd timer service failed as such:

% sudo journalctl -u restic-data-backup
-- Logs begin at Tue 2021-03-23 13:52:29 CET, end at Fri 2021-03-26 09:38:11 CET. --                                                                                                                                                         
Mar 23 23:00:12 server01 systemd[1]: Starting Restic backup of /srv/data (excluding /srv/data/Archive)...
Mar 23 23:00:14 server01 ionice[5200]: unable to open cache: unable to locate cache directory: neither $XDG_CACHE_HOME nor $HOME are defined
Mar 23 23:13:18 server01 ionice[5200]: error: lstat /srv/data/samba-homes/Foobar/Mail2020/~w.foobar_archive.pst.tmp: no such file or directory
Mar 23 23:15:36 server01 ionice[5200]: Files:        2027 new,    46 changed, 956749 unmodified
Mar 23 23:15:36 server01 ionice[5200]: Dirs:          334 new,   200 changed, 62337 unmodified
Mar 23 23:15:36 server01 ionice[5200]: Added to the repo: 234.676 MiB
Mar 23 23:15:36 server01 ionice[5200]: processed 958822 files, 930.780 GiB in 15:22
Mar 23 23:15:36 server01 ionice[5200]: snapshot 8ec6f57a saved
Mar 23 23:15:36 server01 ionice[5200]: Warning: failed to read all source data during backup
Mar 23 23:15:36 server01 systemd[1]: restic-data-backup.service: Main process exited, code=exited, status=3/NOTIMPLEMENTED
Mar 23 23:15:36 server01 systemd[1]: Failed to start Restic backup of /srv/data (excluding /srv/data/Archive).
Mar 23 23:15:36 server01 systemd[1]: restic-data-backup.service: Unit entered failed state.
Mar 23 23:15:36 server01 systemd[1]: restic-data-backup.service: Failed with result 'exit-code'.
Mar 24 23:00:13 server01 systemd[1]: Starting Restic backup of /srv/data (excluding /srv/data/Archive)...
Mar 24 23:00:15 server01 ionice[19179]: unable to open cache: unable to locate cache directory: neither $XDG_CACHE_HOME nor $HOME are defined
Mar 24 23:16:46 server01 ionice[19179]: Files:         196 new,    52 changed, 958732 unmodified
Mar 24 23:16:46 server01 ionice[19179]: Dirs:           20 new,   193 changed, 62675 unmodified
Mar 24 23:16:46 server01 ionice[19179]: Added to the repo: 188.849 MiB
Mar 24 23:16:46 server01 ionice[19179]: processed 958980 files, 931.072 GiB in 16:31
Mar 24 23:16:46 server01 ionice[19179]: snapshot de1b7ac8 saved
Mar 24 23:16:47 server01 systemd[1]: Started Restic backup of /srv/data (excluding /srv/data/Archive).
Mar 25 23:00:01 server01 systemd[1]: Starting Restic backup of /srv/data (excluding /srv/data/Archive)...
Mar 25 23:00:03 server01 ionice[926]: unable to open cache: unable to locate cache directory: neither $XDG_CACHE_HOME nor $HOME are defined
Mar 25 23:13:22 server01 ionice[926]: error: lstat /srv/data/samba-homes/Foobar/Mail2020/~archive.pst.tmp: no such file or directory
Mar 25 23:13:22 server01 ionice[926]: error: lstat /srv/data/samba-homes/Foobar/Mail2020/~archive1.pst.tmp: no such file or directory
Mar 25 23:13:22 server01 ionice[926]: error: lstat /srv/data/samba-homes/Foobar/Mail2020/~archive_2018.pst.tmp: no such file or directory
Mar 25 23:13:22 server01 ionice[926]: error: lstat /srv/data/samba-homes/Foobar/Mail2020/~archive_2018Dez.pst.tmp: no such file or directory
Mar 25 23:13:22 server01 ionice[926]: error: lstat /srv/data/samba-homes/Foobar/Mail2020/~archive_deletedItems.pst.tmp: no such file or directory
Mar 25 23:15:15 server01 ionice[926]: Files:        1323 new,    34 changed, 957773 unmodified
Mar 25 23:15:15 server01 ionice[926]: Dirs:          240 new,   168 changed, 62529 unmodified
Mar 25 23:15:15 server01 ionice[926]: Added to the repo: 177.388 MiB
Mar 25 23:15:15 server01 ionice[926]: processed 959130 files, 931.269 GiB in 15:12
Mar 25 23:15:15 server01 ionice[926]: snapshot a3fbbeb3 saved
Mar 25 23:15:15 server01 ionice[926]: Warning: failed to read all source data during backup
Mar 25 23:15:16 server01 systemd[1]: restic-data-backup.service: Main process exited, code=exited, status=3/NOTIMPLEMENTED

What I also see quite regularly (at another system, running under cron), are changes reported like this:

warning for /var/log/fail2ban.log: expected 1929890 bytes, saved 1930228 bytes            
warning for /var/log/btmp: expected 59261568 bytes, saved 59262720 bytes 

It would be nice if there'd be an option to not list those either (the restic run is using the --quiet option, and the warnings only add noise I'd like to prevent :))

[MichaelEischer]

restic returns exit code 3, in case some files couldn't be accessed during the backup. A fatal backup error returns exit code 1.

warning for /var/log/fail2ban.log: expected 1929890 bytes, saved 1930228 bytes

These lines are only output by a really old version of restic (before 0.9.0).

[pfirsich]

I have seen similar errors in the past, but they were very rare, so I did not care too much, but recently I have added an extension to Firefox, that seemingly creates and deletes files in my Firefox profile directory constantly, so that this error has become a lot more common. If you would add a flag like the proposed --ignore-vanished-files, I would be grateful.

[MichaelEischer]

Related to #3098.