Unable to run regular backup (manual run ok)

[hamah99]

I've got 3 Pis. 2 Pi3b+ and a Pi 5. The 5 is not successfully running a daily backup (but the 2 3bs are). The Pi3b+ are used to run pihole and unbound containers. The P5 is running a Firefox container. All are configured the same as far as raspiBackup is concerned to run daily rsync backups and retain 3 copies. All are configured to suspend containerd and cron services (in that order). The Pi5 will run proper full backups manually and has run them a few times as scheduled backups as well. I do not get any log in the /home directory showing any problem with an uncompleted backup but I am getting failures reported on raspiBackup systemctl as follows below. Notice the failures can occur from 30 minutes to an hour or more after the backup starts. In both these cases the complaints seem to be about missing or vanishing Firefox files. I'm not sure how to resolve this issue and could use assistance in troubleshooting this further.

× raspiBackup.service - Creation of a Raspberry backup with raspiBackup
Loaded: loaded (/etc/systemd/system/raspiBackup.service; disabled; preset: enabled)
Active: failed (Result: exit-code) since Wed 2024-03-13 06:08:55 PDT; 3h 33min ago
Duration: 1h 8min 10.293s
TriggeredBy: ● raspiBackup.timer
Process: 267340 ExecStart=/usr/local/bin/raspiBackup.sh (code=exited, status=109)
Main PID: 267340 (code=exited, status=109)
CPU: 1min 18.685s

Mar 13 05:00:44 rpi0 systemd[1]: Started raspiBackup.service - Creation of a Raspberry backup with raspiBackup.
Mar 13 05:00:45 rpi0 raspiBackup.sh[267710]: Started 0.6.9.1 (e352f1f)
Mar 13 05:37:50 rpi0 raspiBackup.sh[267419]: file has vanished: "/home/steve/docker/firefox/.mozilla/firefox/333foapu.default-release/storage/default/moz-extension+++f2c70387-151b-4a22-bd09-a84c505ef377^userContextId=4294967295/idb/3647222921wleabcEoxlt-eengsairo.files/69"
Mar 13 05:37:50 rpi0 raspiBackup.sh[267419]: file has vanished: "/home/steve/docker/firefox/.mozilla/firefox/333foapu.default-release/storage/default/moz-extension+++f2c70387-151b-4a22-bd09-a84c505ef377^userContextId=4294967295/idb/3647222921wleabcEoxlt-eengsairo.files/70"
Mar 13 05:48:08 rpi0 raspiBackup.sh[267419]: rsync warning: some files vanished before they could be transferred (code 24) at main.c(1338) [sender=3.2.7]
Mar 13 06:08:55 rpi0 systemd[1]: raspiBackup.service: Main process exited, code=exited, status=109/n/a
Mar 13 06:08:55 rpi0 systemd[1]: raspiBackup.service: Failed with result 'exit-code'.
Mar 13 06:08:55 rpi0 systemd[1]: raspiBackup.service: Consumed 1min 18.685s CPU time.

steve@rpi0:~ $ sudo systemctl status raspiBackup
× raspiBackup.service - Creation of a Raspberry backup with raspiBackup
Loaded: loaded (/etc/systemd/system/raspiBackup.service; disabled; preset: enabled)
Active: failed (Result: exit-code) since Thu 2024-03-14 04:37:29 PDT; 4h 30min ago
Duration: 1h 36min 39.154s
TriggeredBy: ● raspiBackup.timer
Process: 324234 ExecStart=/usr/local/bin/raspiBackup.sh (code=exited, status=109)
Main PID: 324234 (code=exited, status=109)
CPU: 1min 45.616s

Mar 14 03:00:50 rpi0 systemd[1]: Started raspiBackup.service - Creation of a Raspberry backup with raspiBackup.
Mar 14 04:02:59 rpi0 raspiBackup.sh[324313]: file has vanished: "/home/steve/docker/firefox/.mozilla/firefox/333foapu.default-release/storage/default/moz-extension+++f2c70387-151b-4a22-bd09-a84c505ef377^userContextId=4294967295/idb/3647222921wleabcEoxlt-eengsairo.files/77"
Mar 14 04:02:59 rpi0 raspiBackup.sh[324313]: file has vanished: "/home/steve/docker/firefox/.mozilla/firefox/333foapu.default-release/storage/default/moz-extension+++f2c70387-151b-4a22-bd09-a84c505ef377^userContextId=4294967295/idb/3647222921wleabcEoxlt-eengsairo.files/78"
Mar 14 04:14:23 rpi0 raspiBackup.sh[324313]: rsync warning: some files vanished before they could be transferred (code 24) at main.c(1338) [sender=3.2.7]
Mar 14 04:37:28 rpi0 raspiBackup[327004]: Stopped 0.6.9.1 (e352f1f). rc 109
Mar 14 04:37:29 rpi0 systemd[1]: raspiBackup.service: Main process exited, code=exited, status=109/n/a
Mar 14 04:37:29 rpi0 systemd[1]: raspiBackup.service: Failed with result 'exit-code'.
Mar 14 04:37:29 rpi0 systemd[1]: raspiBackup.service: Consumed 1min 45.616s CPU time.

[framps]

rsync complaints about changes on the filesystem.

As far as I can see somebody works with FF when the backup is scheduled. Either create the backup when nobody uses FF or use rsync exclude statements to exclude the directory from the backup. Please see option -n for further details.

[hamah99]

The container is running during the BU but there is nobody actively using it (there are multiple open tabs). Is there any way to script a stop/start of the container itself? If not I'll explore the exclusion option.

BTW thanks for a great and useful piece of software. I attempted to make a crude DIY version of raspiBackup but your work is so much more functional and feature rich.

[framps]

I don't use docker. But a raspiBackup user created two extensions to stop and start the docker container. See here 😉

[hamah99]

I'll take at that pre/post docker script. Thanks for that. In the interim after excluding the entire Firefox container the rsync backup seems to be hung or taking an extraordinarily long time:

From raspiBackup.conf:

DEFAULT_EXCLUDE_LIST="--exclude= /home/steve/docker/firefox/"

Current raspiBackup status:

steve@rpi0:~/docker/firefox $ sudo systemctl status raspiBackup
● raspiBackup.service - Creation of a Raspberry backup with raspiBackup
Loaded: loaded (/etc/systemd/system/raspiBackup.service; disabled; preset: enabled)
Active: active (running) since Fri 2024-03-15 03:01:01 PDT; 5h 40min ago
TriggeredBy: ● raspiBackup.timer
Main PID: 378189 (raspiBackup.sh)
Tasks: 9 (limit: 9262)
CPU: 2min 16.018s
CGroup: /system.slice/raspiBackup.service
├─378189 /bin/bash /usr/local/bin/raspiBackup.sh
├─378268 tee -ia /tmp/raspiBackup.log
├─378269 tee -ia /tmp/raspiBackup.log
├─379451 /bin/bash /usr/local/bin/raspiBackup.sh
├─379452 /bin/bash /usr/local/bin/raspiBackup.sh
├─379453 tee -a /tmp/raspiBackup.msg /tmp/raspiBackup.log
├─379454 rsync "--exclude=/mnt/Kashmir/Backups/" --exclude=/tmp/raspiBackup.log --exclude=/tmp/raspiBackup.msg --exclude=.gvfs "--exclude=/proc/" "--exclude=/lost+found/" "--exclude=/sys/" "--exclude=/dev/>
├─379455 rsync "--exclude=/mnt/Kashmir/Backups/" --exclude=/tmp/raspiBackup.log --exclude=/tmp/raspiBackup.msg --exclude=.gvfs "--exclude=/proc/" "--exclude=/lost+found/" "--exclude=/sys/" "--exclude=/dev/>
└─379456 rsync "--exclude=/mnt/Kashmir/Backups/" --exclude=/tmp/raspiBackup.log --exclude=/tmp/raspiBackup.msg --exclude=.gvfs "--exclude=/proc/" "--exclude=/lost+found/" "--exclude=/sys/" "--exclude=/dev/>

Mar 15 03:01:01 rpi0 systemd[1]: Started raspiBackup.service - Creation of a Raspberry backup with raspiBackup.
lines 1-19/19 (END)

[framps]

rsync backup seems to be hung or taking an extraordinarily long time:

In 99% of cases it's rsync which takes so long.
Keep in mind the first backup is a full backup and will take much longer than any further backups.
I have no idea whether you have attached the backup partition via nfs of use a direct attached device. From time to time I have raspiBackup users who experience like you long backup time when they use nfs. Usually when they tuned the nfs mount options the performance became much better.

[hamah99]

I've been able to run full raspiBackups manually:
sudo bash /usr/local/bin/raspiBackup.sh -t rsync /mnt/Kashmir/Backups
and they've run fine so I'm not sure the problem is rsync.

In other regards NFS is performing well. Here is the relevant entry from fstab:
192.168.0.102:/volume1/data/Backups/raspiBackup /mnt/Kashmir/Backups nfs defaults 0 0
if you have a tuning suggestion please let me know.

The raspiBackup.service has now been running over 12 hours
Unless raspiBackup exits with an error it will be very tough to say what the problem actually is.

I'll try stopping raspiBackup.service and see what happens

[hamah99]

it appears raspiBackup.service timed out on the stop and needed to be killed:

steve@rpi0:/etc $ sudo systemctl status raspiBackup
× raspiBackup.service - Creation of a Raspberry backup with raspiBackup
Loaded: loaded (/etc/systemd/system/raspiBackup.service; disabled; preset: enabled)
Active: failed (Result: timeout) since Fri 2024-03-15 15:05:02 PDT; 2min 14s ago
Duration: 12h 2min 30.961s
TriggeredBy: ● raspiBackup.timer
Process: 378189 ExecStart=/usr/local/bin/raspiBackup.sh (code=killed, signal=KILL)
Main PID: 378189 (code=killed, signal=KILL)
CPU: 2min 17.360s

Mar 15 15:03:32 rpi0 systemd[1]: Stopping raspiBackup.service - Creation of a Raspberry backup with raspiBackup...
Mar 15 15:05:02 rpi0 systemd[1]: raspiBackup.service: State 'stop-sigterm' timed out. Killing.
Mar 15 15:05:02 rpi0 systemd[1]: raspiBackup.service: Killing process 378189 (raspiBackup.sh) with signal SIGKILL.
Mar 15 15:05:02 rpi0 systemd[1]: raspiBackup.service: Killing process 379455 (rsync) with signal SIGKILL.
Mar 15 15:05:02 rpi0 systemd[1]: raspiBackup.service: Killing process 379456 (rsync) with signal SIGKILL.
Mar 15 15:05:02 rpi0 systemd[1]: raspiBackup.service: Killing process 384511 (rm) with signal SIGKILL.
Mar 15 15:05:02 rpi0 systemd[1]: raspiBackup.service: Main process exited, code=killed, status=9/KILL
Mar 15 15:05:02 rpi0 systemd[1]: raspiBackup.service: Failed with result 'timeout'.
Mar 15 15:05:02 rpi0 systemd[1]: Stopped raspiBackup.service - Creation of a Raspberry backup with raspiBackup.
Mar 15 15:05:02 rpi0 systemd[1]: raspiBackup.service: Consumed 2min 17.360s CPU time.

Would this not have caused the script to error out? I don't see a log in my home directory indicating an incomplete backup occured.

[framps]

Please check the debug log. Here it's documented where you will find the log if something went wrong.

Then check the timestamp when rsync was started and when rsync finished (executeRsync) or just check RBK0078I to verify the delay is caused by rsync.

[hamah99]

After rebooting the Synology NAS, stopping the firefox container manually, and then properly configuring the stopping/starting of containerd and cron services in raspiBackupInstallUI, I am now able to run scheduled backup jobs. I will continue testing the scripts for stopping and starting containers as well as recovery from the backup(s).

I do have a few questions around rsync and the exclusion of the contents of /home/steve/docker/firefox that I hope you can help me with.

I was under the impression that the 1st rsync backup would be a full backup but that the following backups would only backup changes in the partitions and root file system to save space. Under "Backup versions" of raspiBackupInstallUI I'm using "Keep a maximum number of backups". Perhaps this "incremental" backup is only the case when using "Smart backup strategy"?

I have tried a number of times to exclude the files and subdirectories of /home/steve/docker/firefox as there are an enormous number of cache files to baackup and recovery of the full firefox container by reinstalling is trivial. However, I always seem to have them being included in the backup. In raspiBackup.conf I've tried the following entries:

DEFAULT_EXCLUDE_LIST="--exclude /home/steve/docker/firefox/*" (hoping this would leave the firefox folder empty and exclude all files and subdirectories)

DEFAULT_EXCLUDE_LIST="--exclude /home/steve/docker/firefox/"

DEFAULT_EXCLUDE_LIST="--exclude /home/steve/docker/firefox"

None of these seem to work. Am I doing something wrong?

[framps]

I am now able to run scheduled backup jobs.

👍

I was under the impression that the 1st rsync backup would be a full backup but that the following backups would only backup changes in the partitions and root file system to save space.

Right. Maybe it's worth to read this page where I explain in detail how rsync and hardlinks work?

How did you check whether hardlinks are used? Please read read FAQ17

[github-actions]

This issue is considered stale now and will be closed in 1 week if there is no activity any more

[hamah99]

Sorry for the delay in responding but I've been travelling and been ill . I'm still chasing down why I seem unable to get a proper backup to complete with the containers running but as this is a separate issue and involves the extension from another user I think this issue should be considered closed. I'll open a separate issue on the 3rd party extension to see if the person the wrote the scripts or yourself might be able to help.

I read though the rsync info and watched your YouTube video on the topic. Excellent work and made the concept very clear to me. Thank you.

I do have one further question on rsync. I'm retaining 3 backups with the oldest being rotated out as the newest is added. What happens when the actual data is rotated out of the retention cycle? Where do the hardlinks point to? As the data is rotated out does the incremental backup now include the "missing" file in the backup? In a static file system would this mean that every 3rd backup would be similar to a full backup as there would be little of the original file system to hardlink the incremental to?

[framps]

Sorry for the delay in responding

No problem. I configured github to consider issues stale if there is no activity for two weeks and close it one week later. That way I get rid of dangling issues. But it's possible to open a closed issue all the time later on :wink

I'll open a separate issue on the 3rd party extension to see if the person the wrote the scripts or yourself might be able to help.

👍

I do have one further question on rsync.

You're not the first one with this question. That's why I created a page where I explain in detail how hardlinks are used by rsync. There you also find a link to a YT video about this topic 😉

I think this issue should be considered closed.

Just close the issue 😃

[hamah99]

Ok, I'll reread the info you posted. It and the video have been very helpful so far but I must have overlooked the mechanics on what happens. I'll confirm but my guess is that in the situation described above, with a fully static file system and a 3 copy retention policy, every 3rd backup would be a "full" backup.

[framps]

every 3rd backup would be a "full" backup.

Right