Understand why `restic backup` skipped a file

Hi,

I’m a long-time restic user and first time poster on this Discourse.

I recently migrated to a new workstation and used this as an opportunity to validate my backup process. I completed one final backup on the old machine and then restored from that snapshot on the new one. Everything was perfect until I invoked my backup script from the new machine and realized that a specific file that I expected to exist was missing.

My backup script first invokes restic --exclude-caches --verbose backup --exclude "$HOME/.cache" --exclude "$HOME/rpmbuild" "$HOME" and then uses rclone to persist the data to the cloud: rclone copy --immutable --progress --stats-one-line "$RESTIC_REPOSITORY" <<<CLOUD PATH>>>.

The backup step completed OK but the rclone failed. I quickly realized rclone was missing its ~/.config/rclone/rclone.conf configuration. I confirmed that rclone.conf wasn’t included in the snapshot but it does exist on the old machine:

> ls -laZ ~/.config/rclone
total 12
drwxrwxr-x.  2 bfallik bfallik unconfined_u:object_r:config_home_t:s0 4096 Aug 23  2020 .
drwx------. 34 bfallik bfallik unconfined_u:object_r:config_home_t:s0 4096 Sep 17 16:34 ..
-rw-------.  1 bfallik bfallik unconfined_u:object_r:config_home_t:s0  106 Aug 23  2020 rclone.conf

I can’t figure out why restic skipped rclone.conf and I’m a bit worried that some other files were missed during the backup+restore cycle. Both old and new PCs use restic version 0.12.0.

Any ideas for how I can debug this further? Thanks in advance!

Do you have a file named CACHEDIR.TAG in $HOME/.config/ or any of its subdirectories? You can check using find $HOME/.config -name CACHEDIR.TAG.

Another thing to check is of course the verbose output you get from the backup run. Make sure to look for restic saying it can’t read a file or similar.

Good guess but no:

> find .config -name CACHEDIR.TAG
>

Unfortunately I didn’t retain the log output from the previous run.

Can’t you run it again though? You can use --dry-run if you want.

PS: You can supply multiple -v to increase verbosity, try e.g. -vvv.

I can re-run it but not against an identical configuration since I already moved the repo disk to the new workstation. Will see if I can reproduce the problem with -vvv and --dry-run and report back. Thx.

You don’t need the repo to do a dry run, as long as the old system is what it was it should be the same regardless where restic thinks it would store and access the repo.

Well that’s too bad:

> restic backup --dry-run
unknown flag: --dry-run

Yeah, sorry, you have to use restic version 0.12.1: Release restic 0.12.1 · restic/restic · GitHub

When I run a test backup on the old machine the file ~/.config/rclone/rclone.conf is added to the repo so I’m dumbfounded why the file isn’t being backed up in my usual repo.

Differences for this test

  • backed up into an empty restic init repo
  • replaced --verbose with -vvv
  • only passed the dir ~/.config to backup instead of ~
    Otherwise everything was the same as prior runs.

Could there be some configuration within the repo itself that is preventing this file from being archived?

Thx,
brian

No, not at all. Please run the “real” or “original” backup on the old host, but with -vvv and --dry-run after upgrading to 0.12.1. Please also show the output of the snapshots command, if you don’t mind.

Hi @rawtaz ,

FYI I don’t think --dry-run was included in 0.12.1. I had to download a more recent binary from https://beta.restic.net/ to find that flag.

❯ ./restic version
restic 0.12.1-dev (compiled manually) compiled with go1.17 on linux/amd64

Anyway, back on topic. I couldn’t easily re-run against the real repo on the old machine since I’ve already moved the repo disk. Instead I re-ran my backup script against the real repo on the new machine. Here’s how I invoked restic:

> ./restic --exclude-caches -vvv backup --dry-run --exclude "$HOME/.cache" --exclude "$HOME/rpmbuild" "$HOME" 1>restic.log 2>&1
...
> grep rclone restic.log
new       /home/bfallik/.config/rclone/rclone.conf, saved in 0.000s (0 B added)
new       /home/bfallik/.config/rclone/, saved in 0.000s (0 B added, 500 B metadata)
> ls -l /home/bfallik/.config/rclone/rclone.conf
-rw-------. 1 bfallik bfallik 106 Dec 14 20:37 /home/bfallik/.config/rclone/rclone.conf

It seems odd that restic seems to think that the file is new but then adds 0 B for it.

Here’s a list of the snapshots (I manually edited the hostnames for anonymity):

repository 194418c1 opened successfully, password is correct
ID        Time                 Host                   Tags        Paths
-------------------------------------------------------------------------------
12a9c15a  2018-06-16 17:15:23  host1                              /home/bfallik
a9d9f122  2018-06-16 17:28:14  host1                              /home/bfallik
bb2c587c  2018-06-16 17:48:15  host1                              /home/bfallik
9b9ed9af  2018-06-17 15:28:27  host1                              /home/bfallik
d857f9ce  2018-07-05 19:04:31  host1                              /home/bfallik
2cf78702  2018-07-07 11:48:48  host1                              /home/bfallik
56aa20e6  2018-07-21 14:19:29  host1                              /home/bfallik
fef5e3b0  2018-08-05 14:03:33  host1                              /home/bfallik
e9b408f6  2018-08-13 23:01:21  host1                              /home/bfallik
44439bb7  2018-08-18 14:24:53  host2                              /home/bfallik
ff67eafe  2018-09-03 17:33:43  host2                              /home/bfallik
c0ad3517  2018-09-23 16:42:00  host2                              /home/bfallik
f98783b6  2018-10-04 20:50:00  host2                              /home/bfallik
041e3813  2018-10-06 16:29:13  host2                              /home/bfallik
6e77a133  2018-11-04 16:09:14  host2                              /home/bfallik
fcd1b3b1  2018-11-17 12:42:10  host2                              /home/bfallik
c594c15e  2018-12-01 12:28:38  host2                              /home/bfallik
02e88947  2018-12-15 11:01:26  host2                              /home/bfallik
bf6c8320  2018-12-30 12:10:46  host2                              /home/bfallik
55c74409  2019-01-13 11:28:23  host2                              /home/bfallik
825b2ded  2019-02-03 09:13:43  host3                              /home/bfallik
9d45a8b5  2019-02-16 11:55:03  host3                              /home/bfallik
1445168f  2019-02-16 11:56:10  host3                              /home/bfallik
4d61f354  2019-02-16 14:36:44  host3                              /home/bfallik
df59cfc2  2019-02-16 14:47:50  host3                              /home/bfallik
6e0dc899  2019-02-24 09:48:01  host3                              /home/bfallik
a20af3d1  2019-03-17 13:07:57  host3                              /home/bfallik
d5bf1274  2019-03-31 16:31:38  host3                              /home/bfallik
f64c91e7  2019-04-06 09:45:36  host3                              /home/bfallik
b4ad44d4  2019-04-13 11:20:43  host3                              /home/bfallik
03b1b456  2019-05-05 08:37:23  host3                              /home/bfallik
a5e41584  2019-05-05 16:08:42  host3                              /home/bfallik
e541c111  2019-05-11 10:13:22  host3                              /home/bfallik
d302858b  2019-05-18 11:22:32  host3                              /home/bfallik
8197a720  2019-05-28 22:04:19  host3                              /home/bfallik
ed9b149f  2019-06-04 19:36:41  host3                              /home/bfallik
e6c8012a  2019-06-08 10:34:22  host3                              /home/bfallik
a4c99bbf  2019-06-16 15:54:08  host3                              /home/bfallik
aec85b7a  2019-07-13 13:07:33  host3                              /home/bfallik
124f6a66  2019-07-30 21:33:12  host3                              /home/bfallik
922e759c  2019-08-11 09:32:50  host3                              /home/bfallik
18293709  2019-08-18 09:29:27  host3                              /home/bfallik
4c02c4c7  2019-09-07 08:11:37  host3                              /home/bfallik
98a890a2  2019-09-21 11:34:56  host3                              /home/bfallik
cd4c685e  2019-10-06 11:05:50  host3                              /home/bfallik
773892d2  2019-10-27 13:59:34  host3                              /home/bfallik
3a9a3189  2019-11-09 16:27:08  host3                              /home/bfallik
f6872cc7  2019-11-24 09:51:35  host3                              /home/bfallik
3ff93a77  2019-12-07 15:24:07  host3                              /home/bfallik
91c3fbe8  2019-12-29 14:46:03  host3                              /home/bfallik
a46d4d95  2020-01-04 12:24:47  host3                              /home/bfallik
3f233584  2020-01-12 10:29:41  host3                              /home/bfallik
3f7a0d2c  2020-01-19 12:22:18  host3                              /home/bfallik
cd8658e1  2020-02-08 12:23:58  host3                              /home/bfallik
391e2263  2020-02-27 19:18:18  host3                              /home/bfallik
07000a08  2020-03-01 12:39:22  host3                              /home/bfallik
8fe6c7c1  2020-03-28 17:37:12  host3                              /home/bfallik
5b78e196  2020-03-30 21:38:04  host3                              /home/bfallik
37c13aa3  2020-04-11 16:08:18  host3                              /home/bfallik
a24d5162  2020-04-25 11:03:48  host3                              /home/bfallik
5a3e5a0b  2020-05-02 10:52:46  host3                              /home/bfallik
0a3bb92d  2020-05-09 11:37:38  host3                              /home/bfallik
463f0c66  2020-05-23 11:55:36  host3                              /home/bfallik
789df949  2020-06-06 17:31:03  host3                              /home/bfallik
a828bc6e  2020-06-14 10:07:27  host3                              /home/bfallik
fd36a01d  2020-06-23 18:15:23  host3                              /home/bfallik
6b235c41  2020-07-11 14:49:12  host3                              /home/bfallik
634d44db  2020-07-18 15:18:00  host3                              /home/bfallik
910172ba  2020-08-02 10:51:26  host3                              /home/bfallik
49b6437b  2020-08-16 12:07:14  host3                              /home/bfallik
ef67d2a0  2020-08-22 11:45:32  host3                              /home/bfallik
514e58c3  2020-08-23 12:39:07  host3                              /home/bfallik
363641ba  2020-08-23 13:16:42  host3                              /home/bfallik
bbf75ade  2020-08-23 13:33:48  host3                              /home/bfallik
e63fe6d7  2020-09-06 12:12:10  host3                              /home/bfallik
b0703650  2020-10-04 17:27:50  host3                              /home/bfallik
9172a338  2020-10-11 12:34:13  host3                              /home/bfallik
bbce71b2  2020-10-18 12:32:43  host3                              /home/bfallik
bf73076e  2020-10-25 12:05:52  host3                              /home/bfallik
80c9f3ce  2020-11-08 16:36:11  host3                              /home/bfallik
421edd48  2020-11-14 11:25:46  host3                              /home/bfallik
0ac755c6  2020-11-23 12:04:00  host3                              /home/bfallik
e2db2556  2020-12-05 13:06:25  host3                              /home/bfallik
28fb3098  2020-12-18 14:34:42  host3                              /home/bfallik
f524dfd4  2021-01-09 11:41:28  host3                              /home/bfallik
d7fe472e  2021-01-24 12:33:38  host3                              /home/bfallik
6dff3876  2021-02-06 12:14:21  host3                              /home/bfallik
6afcaf49  2021-03-06 12:48:35  host3                              /home/bfallik
7644e3e5  2021-03-21 17:15:39  host3                              /home/bfallik
41631dfa  2021-03-28 12:01:20  host3                              /home/bfallik
6b49681d  2021-04-28 18:02:12  host3                              /home/bfallik
4dfcf1f4  2021-05-22 12:43:59  host3                              /home/bfallik
368b6fc2  2021-06-05 17:45:42  host3                              /home/bfallik
c40fece0  2021-06-20 19:13:03  host3                              /home/bfallik
44827a58  2021-07-02 09:43:48  host3                              /home/bfallik
7c5445a8  2021-07-27 10:07:54  host3                              /home/bfallik
30ac671d  2021-08-14 11:33:18  host3                              /home/bfallik
9f86add7  2021-08-29 10:27:29  host3                              /home/bfallik
8c4535ea  2021-08-29 10:29:06  host3                              /home/bfallik
e722f010  2021-08-29 10:33:43  host3                              /home/bfallik
4c3e9d66  2021-09-03 11:29:49  host3                              /home/bfallik
c96c82fc  2021-09-28 14:45:54  host3                              /home/bfallik
f0690541  2021-10-29 12:07:35  host3                              /home/bfallik
c9b701ee  2021-11-06 13:13:10  host3                              /home/bfallik
de65d2ac  2021-11-14 13:09:48  host3                              /home/bfallik
f1f813d5  2021-11-28 11:28:08  host3                              /home/bfallik
bda8c616  2021-12-04 22:44:38  host3                              /home/bfallik
28bc65d1  2021-12-14 20:21:28  host4                              /home/bfallik
-------------------------------------------------------------------------------
108 snapshots

Let me know if I can provide any more details. Thanks!

My bad, sorry about that.

This can happen if restic didn’t find the right parent snapshot but the file contents has been saved before in some snapshot (it’s just one example, I reproduced it that way just now). I don’t see why restic wouldn’t find the correct parent snapshot since you use the same path all the time, but can you please complement/edit your post above so that all the output except the lines listing new/modified/ for each file is printed?

Also, let’s rewind a bit, can you show us the output of ./restic ls <theSnapshotThatYouRestored> | grep rclone? Which snapshot ID was that?

Hi,

To your second question:

> ./restic ls 28bc65d1 | grep rclone
>

where 28bc65d1 is the most recent snapshot.

To your first, here is the log output with new/modified/unmodified info removed:

> grep -v new restic.log | grep -v unchanged | grep -v modified

open repository
lock repository
load index files
using parent snapshot 28bc65d1
start scan on [/home/bfallik]
start backup on [/home/bfallik]
scan finished in 4.425s: 116070 files, 14.648 GiB

Would add to the repo: 950.007 MiB

processed 116070 files, 14.662 GiB in 0:15

Thx.

Can you tell me the exact restore command that you used (on your new PC), and if possible also the output it gave?

Hey Rawtaz,

When I originally encountered this problem I used this simple script to mount the repo:

#!/bin/bash

set -e

set -o allexport
# shellcheck source=/dev/null
source ~/.bfallik-restic-repo.env
set +o allexport

TEMPDIR=$(mktemp -d --tmpdir restic-mount.XXXXXXXXXX)

function cleanup {      
  rmdir -v "${TEMPDIR}"
}

trap cleanup EXIT

restic mount "${TEMPDIR}"

I then looked for the data under the latest snapshot path.

ls /tmp/restic-mount.9Ne7BQXM3R/snapshots/latest/home/bfallik/.config/rclone
ls: cannot access '/tmp/restic-mount.9Ne7BQXM3R/snapshots/latest/home/bfallik/.config/rclone': No such file or directory

Prior in this thread I repeated this process with restic ls <snapshot> and that also failed to find the file using a specific snapshot ID.

Let me know what else I can provide.

Thx.

does ls /tmp/restic-mount.9Ne7BQXM3R/snapshots/*/home/bfallik/.config/rclone print anything?

The ls output in the initial post shows that you’re using SELinux. Did restic have the permissions to read the configuration files?

Hi @MichaelEischer ,

Good question! Running the wildcard ls on the snapshots tree turned up that all of the snapshots but the most recent (from my new machine) contain the .config/rclone directory. This result helps clarify one detail that was incorrect in my original post. It seems that restic didn’t restore this file when I first transitioned to the new machine. The file not existing in the latest snapshot was a red herring since I did re-run the backup script once and that created a new snapshot (without rclone.conf, because that hadn’t been restored) before failing at the rclone step.

I don’t have great records from when I initiated the restore operation. It may just be the case that I forgot to restore this directory myself and didn’t realize that when debugging why rclone failed and also got confused because the file was missing from the most recent snapshot.

At this point I’m willing to chalk this up to operator error (PEBKAC!). Thanks for helping me investigate, @MichaelEischer and @rawtaz !

brian

2 Likes

Ah, that explains a lot :smiley: I think your analysis makes sense - with what you said above there’s IMO no sign that restic hasn’t backed that file up, and as you say you probably just missed it when you were using the mount to grab your files from the repository.