Error message via cron mail after a successful backup mail

[FJustinian]

Hi framp,

since three weeks I am getting a cron mail with errors after the succesful backup mail with following content:

/usr/local/bin/raspiBackup.sh: Line 1716: /media/usbdrive/raspibackup/himberrypi/himberrypi-tar-backup-20211031-082301/raspiBackup.log: File or Directory not found
The same for Lines 1717, 1722 and 1725. Of course there was no backup directory saved.

Before the problems occured the raspi system ran perfect and was changed only by installing Jellyfin, but a deinstallation of Jellyin brought no improvement.

I ran then a manually backup. Therefore I am able to provide you with a logfile:
raspiBackup.log

Thank you very much for looking into the issue!!!

[framps]

I check the code and frankly have no clue what's the root cause. Unfortunately there are no debug statements in this code area. I will create dedicated code for you with debug statements. Please be patient.
This is no severe issue. It's just that some optional log statements are missing in the debug log.

[FJustinian]

Yeah I can wait :-)

Best

[framps]

I created a hotfix which includes additional debug statements. Please

1. save old /usr/local/bin/raspiBackup.sh somewhere
2. download https://github.com/framps/raspiBackup/blob/issue384/raspiBackup.sh
3. copy downloaded hotfix into /usr/local/bin
4. Test again
5. Provide the debug log

[FJustinian]

Hi framp,

I ran the bugfix version within the regular backup which went well but there was no:

raspiBackup.log
raspiBackup.msg

in the directory. Then I ran a manually backup and the log was saved in my home directory.

Much obliged!
raspiBackup.log

[framps]

Hm ... strange 🤔

Please execute following steps with patched raspiBackup:

1. execute script raspiBackup.log.verbose
2. execute sudo bash -x raspiBackup.sh
3. execute exit
4. provide raspiBackup.log.verbose

[FJustinian]

Done and attached!

There was no backup saved in the backup directory, but the backup directory changed btw the access date to the backup time. I noticed this phenomenon yesterday after running the backup manually. Due to success message there was no backup saved. After deleting the time based backup with your hotfix, the manually run backup was saved.

Hope these information is helpful. I zipped the verbose log btw because of unsupported file type and I attached the last raspiBackup.log in any case.

With regards

[raspiBackup.log](https://github.com/framps/raspiBackup/files/7481333/raspiBackup.log
raspiBackup.log.verbose.zip

[framps]

I just wanted to check the verbose log and detected it's mostly empty. Step two has to be sudo bash -x raspiBackup.sh. Sorry for the inconvenience.

[FJustinian]

Don't mention it :-)

Attached!
raspiBackup.log.verbose.zip

[framps]

Thank you very much for the verbose log. I found

|1993> 	executeCmd(): logEntry 'Command: tar 		-cpi --one-file-system 		 		 		 		-f "/media/usbdrive/raspibackup/himberrypi/himberrypi-tar-backup-20211107-181442/himberrypi-tar-backup-20211107-181442.tar" 		--warning=no-xdev 		--numeric-owner 		--exclude="/media/usbdrive/raspibackup/*" 		--exclude="/home/pi/raspiBackup.log" 		--exclude="/home/pi/raspiBackup.msg" 		--exclude='\''.gvfs'\'' 		--exclude=/proc/* 		--exclude=/lost+found/* 		--exclude=/sys/* 		--exclude=/dev/* 		--exclude=/tmp/* 		--exclude=/boot/* 		--exclude=/run/* 		 		/'

and at the end of the backup run

||1597> 	logCommand(): ls -la /media/usbdrive/raspibackup/himberrypi/himberrypi-tar-backup-20211107-181442
|1597> 	logCommand(): local 'r=insgesamt 3377280
drwxrwxrwx 1 root root     131072 Nov  7 18:14 .
drwxrwxrwx 1 root root     131072 Nov  7 18:14 ..
-rwxrwxrwx 1 root root  268435456 Nov  7 18:14 himberrypi-backup.img
-rwxrwxrwx 1 root root        512 Nov  7 18:14 himberrypi-backup.mbr
-rwxrwxrwx 1 root root        195 Nov  7 18:14 himberrypi-backup.sfdisk
-rwxrwxrwx 1 root root 3189370880 Nov  7 18:18 himberrypi-tar-backup-20211107-181442.tar'

which does not match with your following statements and proves a backup was created.

But later on I found

|5067> 	applyBackupStrategy(): rm -rf /media/usbdrive/raspibackup/himberrypi/himberrypi-tar-backup-20211107-181442

which proves the Smart Recycle deletes the directory again.

Following backups exist before smart recycle starts:

himberrypi-tar-backup-20201206-050001
himberrypi-tar-backup-20210111-203006
himberrypi-tar-backup-20210207-050001
himberrypi-tar-backup-20210307-050001
himberrypi-tar-backup-20210404-050002
himberrypi-tar-backup-20210502-050001
himberrypi-tar-backup-20210606-050001
himberrypi-tar-backup-20210919-050001
himberrypi-tar-backup-20211003-050001
himberrypi-tar-backup-20211025-000701
himberrypi-tar-backup-20211104-210631'

Your smart recycle options are

DEFAULT_SMART_RECYCLE_OPTIONS="0 4 12 0"

which means to keep last 12 monthly backups and last 4 weekly backups.

You actually have 10 monthly backups and 2 weekly backups (last two). Month 7 and 8 are missing. In your previous debug log I found the two missing monthly backups. Did you manually delete them? Same for 2 missing weekly backups?

As far as I can see there is a misunderstanding of the backup strategy. If you have a weekly backup of current week from Monday and create another backup on one of the following days theses backups are deleted because there exists already a backup of this week (Monday). I will update the doc accordingly to make this clear.

I don't know why there are only 2 weekly backups. Actually there should be 4. Did you manually cleanup some weekly backups? You wrote

After deleting the time based backup with your hotfix,

[FJustinian]

Hi framp,

"You actually have 10 monthly backups and 2 weekly backups (last two). Month 7 and 8 are missing. In your previous debug log I found the two missing monthly backups. Did you manually delete them? Same for 2 missing weekly backups?"

Yes I deleted Month 7 and 8 four days ago because the backup size was 19 GB (should be 3GB) due to a wrong setting in Syncthing. The other two missing backups could be the ones with the UUID Issue and the missing boot data a few weeks ago (which I also deleted).

So this problem should be fixed by itself and deleting smart recycled backups manually is not a good idea ? ;-).

Thank you so much for your effort!

[framps]

So this problem should be fixed by itself and deleting smart recycled backups manually is not a good idea ? ;-).

You can delete backups if you want. Smart recycle will be able to handle the deletion. But the deleted backups are gone and cannot be recreated 😄 . That's why there are 10 monthly backups and 2 weekly backups in your case.

Actually we have two issues here:

1. Error message via cron mail after a successful backup mail
   There is no such message in the verbose log any more. I actually changed some code in the hotfix and think it's now fixed.

2. You mentioned no backup is created. That's because you don't have daily backups enabled and try to create another weekly backup which is deleted by the backup strategy because there already exists a weekly backup. If next week another backup is created this backup will not be deleted. Actually this behavior is documented on this page (See note).

As far as I see #1 is fixed and #2 is a user error 😉

I suggest we keep this issue open for another week and if the message issue is gone you close the issue. Otherwise we'll continue on the message issue.

[FJustinian]

Good evening framp,

Got it! I'll give a feedback about next weeks backup.

Best wishes

[FJustinian]

Hi framp,

the backup went well, just the log and the msg data are missing in the directory. There was no backup log in my homefolder either.

Again thank you for your professionel support! Should I close the issue or do you need it to be open because of the missing log?

With my best regards

[framps]

Should I close the issue or do you need it to be open because of the missing log?

This should be fixed in current code. If you execute sudo raspiBackup.sh -U -S you will grab the latest code. Please check whether this will create the log.

[FJustinian]

Hi framp,

just did it, but still no log.

Best

[framps]

Please show the messages you get when you invoke raspiBackup.

[FJustinian]

The last run was time based with no log. The manually run gave me following messages and a mostly empty log as attached:
raspiBackup.log

--- RBK0009I: himberrypi: raspiBackup V0.6.6.1 (91326c6) So 14. Nov 14:28:19 CET 2021 gestartet.
--- RBK0116I: Konfigurationsdatei /usr/local/etc/raspiBackup.conf wird benutzt.
--- RBK0151I: Backuppfad /media/usbdrive/raspibackup mit Partitionstyp fuseblk wird benutzt.
--- RBK0008I: Services werden gestoppt: 'systemctl stop cron %1%1 systemctl stop pihole-FTL %1%1 systemctl stop openvpn %1%1 systemctl stop smbd %1%1 systemctl stop minidlna'.
--- RBK0081I: Backup vom Typ tar wird in /media/usbdrive/raspibackup/himberrypi/himberrypi-tar-backup-20211114-142818 erstellt.
--- RBK0036I: Partitionslayout wird gesichert.
--- RBK0044I: Backup der Bootpartition wird in /media/usbdrive/raspibackup/himberrypi/himberrypi-tar-backup-20211114-142818/himberrypi-backup.img erstellt.
--- RBK0044I: Backup des Partitionlayouts wird in /media/usbdrive/raspibackup/himberrypi/himberrypi-tar-backup-20211114-142818/himberrypi-backup.sfdisk erstellt.
--- RBK0046I: Backup des Masterbootrecords wird in /media/usbdrive/raspibackup/himberrypi/himberrypi-tar-backup-20211114-142818/himberrypi-backup.mbr erstellt.
--- RBK0158I: tar Backup "/media/usbdrive/raspibackup/himberrypi/himberrypi-tar-backup-20211114-142818/himberrypi-tar-backup-20211114-142818.tar" wird erstellt.
--- RBK0085I: Backuperstellung vom Typ tar gestartet. Bitte Geduld.
--- RBK0078I: Backupzeit: 00:03:24.
--- RBK0033I: Bitte warten bis aufgeräumt wurde.
--- RBK0007I: Services werden gestartet: 'systemctl start minidlna %1%1 systemctl start smbd %1%1 systemctl start openvpn %1%1 systemctl start pihole-FTL %1%1 systemctl start cron'.
--- RBK0218I: Wende smarte Backupstrategie an. Täglich:0 Wöchentlich:4 Monatlich:12 Jährlich:0
--- RBK0219I: Keine Backups werden smart recycled.
--- RBK0017I: Backup erfolgreich beendet.
--- RBK0010I: himberrypi: raspiBackup V0.6.6.1 (91326c6) So 14. Nov 14:31:53 CET 2021 beendet mit Returncode 0.
--- RBK0167I: Eine eMail wird versendet.
--- RBK0026I: Debug Logdatei wurde in /home/pi/raspiBackup.log gesichert.

[framps]

I found the root cause for the mostly empty log. Please execute sudo raspiBackup.sh -U -S and grab the latest code which includes the fix and verify.

[FJustinian]

Hi framp,

nope, unfortunately a time based backup didn't create a logfile. Here's the mailout though:
--- RBK0009I: himberrypi: raspiBackup.sh V0.6.6.1 (2469c21) Do 18. Nov 16:35:03 CET 2021 gestartet.
--- RBK0031I: Prüfe ob eine neue Version von raspiBackup.sh verfügbar ist.
--- RBK0151I: Backuppfad /media/usbdrive/raspibackup mit Partitionstyp fuseblk wird benutzt.
--- RBK0036I: Partitionslayout wird gesichert.
--- RBK0158I: tar Backup "/media/usbdrive/raspibackup/himberrypi/himberrypi-tar-backup-20211118-163501/himberrypi-tar-backup-20211118-163501.tar" wird erstellt.
--- RBK0085I: Backuperstellung vom Typ tar gestartet. Bitte Geduld.
--- RBK0078I: Backupzeit: 00:03:18.
--- RBK0033I: Bitte warten bis aufgeräumt wurde.
--- RBK0218I: Wende smarte Backupstrategie an. Täglich:0 Wöchentlich:4 Monatlich:12 Jährlich:0
--- RBK0219I: Keine Backups werden smart recycled.
--- RBK0017I: Backup erfolgreich beendet.
--- RBK0010I: himberrypi: raspiBackup.sh V0.6.6.1 (2469c21) Do 18. Nov 16:38:32 CET 2021 beendet mit Returncode 0.

But after a manually detailed backup a logfile was created as attached:
raspiBackup.log

If it's ok I'll run a backup after a deinstallation and reinstallation of raspiBackup. But I'll wait for your response :-)

With my best regards

[framps]

It's an SR edge case you face. I created a fix. Please use sudo raspiBackup.sh -U -S and test again 😉

[FJustinian]

Hi framp,

the last update went well 👍 with the time based backup! Thank you so much and I hope I didn't cause to many work for you.
.

With my best wishes!

[framps]

I have to thank you 👍

You reported the issue and were persistent until the issue was fixed. You tested and verified the fixes. This helps me and all raspiBackup users because the logging was rewritten in release 0.6.6.1 and I'm very dependent on the logs. Otherwise I'm unable to fix any issue 😢

[FJustinian]

Glad to help framp!

:-)