"Operation not supported" after finishing backup

[CapedBaldy]

After the backup finishes, the raspiBackup script tries to execute some command that results in a "Operation not supported" error:

https://pastebin.com/ShKviL3K

This is likely related to the fact that the backup folder is a FTP server on a Synology NAS.
The user with which the folder is mounted already has all permissions and the mount uses the options uid=1000,gid=1000,umask=0022 in the fstab file.

This is the debug log file: raspiBackup.log

[framps]

According the log the ddz backup was stored

20240216-183019 DBG 2563:                      --- LC_ALL=C dd if=/dev/sdb bs=1M   | gzip  > "/backup/@HOSTNAME@/@HOSTNAME@-ddz-backup-20240216-183001/@HOSTNAME@-ddz-backup-20240216-183001.img.gz"

and at the end raspiBackup tries to move the logs which were created in /tmp into the backup directory also.

20240216-215551 DBG 2170:          --- DEST_LOGFILE: /backup/raspberrypi/raspberrypi-ddz-backup-20240216-183001/raspiBackup.log
20240216-215552 DBG 2171:          --- DEST_MSGFILE: /backup/raspberrypi/raspberrypi-ddz-backup-20240216-183001/raspiBackup.msg
20240216-215552 DBG 2174:          --- Moving Logfile: /tmp/raspiBackup.log

But now there is no write access to the log directory any more.

20240216-215544 DBG 3465:          --> startServices 
20240216-215544 DBG 2052:              --> logSystemServices 
20240216-215544 DBG 2061:              <-- logSystemServices 
20240216-215544 DBG 3477:              --- systemctl start cron && systemctl start cups && systemctl start containerd && systemctl start docker
20240216-215545 DBG 2601:              --> executeShellCommand systemctl start cron && systemctl start cups && systemctl start containerd && systemctl start docker
20240216-215549 DBG 2608:              <-- executeShellCommand 0

That's executed when the backup finished but I don't think these commands change some access rights.

As you already wrote you use ftp with curlftps

20240216-183005 DBG 2037:              curlftpfs#192.168.1.54/BackupRaspberry /backup fuse uid=1000,gid=1000,umask=0022,auto,nofail,noatime,allow_other,user=XXXX:XXXX 0 0
20240216-183005 DBG 2037:              UUID=e33881e7-eb67-4e8c-9d83-1334dcec27dc /buffer ext4 defaults,users,noatime 0 0  

I never tested raspiBackup with curlftps but as far as I understand it should work. In the log I can see you already tested with an ntfs disk already. Did you get there the same issue?

[CapedBaldy]

IIRC I didn't have any issue with the ntfs drive. I will test one more time later to confirm this.
Also, strangely even if the command is considered failed the raspiBackup.log and raspiBackup.msg files have been in fact at least copied to the /backup dir:

Cannot confirm immediately if the copies in the /tmp folder were also deleted since I rebooted the system.

[CapedBaldy]

Tried another manual backup, at the end in the /tmp dir there were these files:
raspiBackupInstallUI.properties raspiBackup.logf raspiBackup.properties raspiBackup.vars

The raspiBackup.logf had this lines:
mv: failed to preserve ownership for '/backup/raspberrypi/raspberrypi-ddz-backup-20240217-163635/raspiBackup.log': Operation not permitted

mv: failed to preserve ownership for '/backup/raspberrypi/raspberrypi-ddz-backup-20240217-163635/raspiBackup.msg': Operation not permitted

chown: changing ownership of '/backup/raspberrypi/raspberrypi-ddz-backup-20240217-163635/raspiBackup.log': Operation not permitted

chown: changing ownership of '/backup/raspberrypi/raspberrypi-ddz-backup-20240217-163635/raspiBackup.msg': Operation not permitted

[CapedBaldy]

So it seems it's an incompatibility between the mv command and the files being transferred to a remote folder with a different permission system. Reading through some stackoverflow threads it's a common problem also with Samba and NFS remote folders.

This reply solves it by doing a cp with some options and then rm:
cp --no-preserve=mode,ownership $backupfile $destination

[framps]

Interesting you found the root cause and a solution 👍

You use curlftpfs. From the debug log I cannot see which filesystem is used by the FTP server. According your link it looks like there is another filesystem than ext4 used. Which filesystem do you use there?

As far as I see another way to save the files is by rsync which I prefer. But I have to test this. In order to reproduce your issue I have to know the details about your ftp Server setup 😉

[CapedBaldy]

The server filesystem is the same as the client system, ext4:

However I don't think Synology's OS follows UNIX rules, because it seems that from version 5 onwards it applies Windows ACL permission system to shared folders by default: https://kb.synology.com/en-us/DSM/help/DSM/AdminCenter/file_share_privilege?version=6.

There's this interesting bit in the Synology KB:
https://kb.synology.com/en-ro/DSM/help/DSM/AdminCenter/file_ftp_general?version=7

Applying Default UNIX Permissions

Click Advanced Settings and tick Apply default UNIX permissions. This option applies the default UNIX permissions when users upload or create files and folders. Applied permissions are the same as permissions applied by the UNIX command umask. When this option is enabled, UNIX permissions are 644 for files and 755 for folders. When this option is disabled, UNIX permissions are 666 for files and 777 for folders. The default umask value is 022.
Note:

For Windows ACL enabled shared folders (all shares excluding "photo" and shares on external drives), please run the chmod command on your Linux or FTP client to change folder and file permission types from Windows ACL to UNIX.
Enabling this option might cause inconsistent permission issues between different protocols. To avoid inconsistencies, we suggest leaving this option disabled.

Will try to enable this and see if it changes anything

[framps]

Will try to enable this and see if it changes anything

Thank you very much you test this. I also have a Synology and I'm puzzled time by time by the way Synology manages access rights. Frankly I suggest to use nfs instead of ftp to access the backup directory. That way you are also able to use rsync and get benefit from the hardlinks used by rsync. This will reduce the backup time and also reduce backup space.

[CapedBaldy]

Unfortunately it didn't change anything, still same errors as before :/

[framps]

I'll create a branch for your issue and will use rsync to copy the log and msg file into the backup space. Will keep you posted when the fix is ready and you can test the fix 😉

[framps]

Here we are: Use curl -s https://raw.githubusercontent.com/framps/raspiBackup/master/scripts/raspiBackupDownloadFromGit.sh | bash -s -- m_739 raspiBackup.sh to download the fix and please test the fix. Please note: The fix is downloaded into current directory and don't forget the leading period to call the fix 😉 Otherwise you will use the installed raspiBackup.

[CapedBaldy]

Strange, I think I started the fix correctly but the output is almost the same: https://pastebin.com/i1Yp81aV

raspiBackup.log

Only these two lines were not present in the /tmp/raspiBackup.logf file this time:
chown: changing ownership of '/backup/raspberrypi/raspberrypi-ddz-backup-20240217-163635/raspiBackup.log': Operation not permitted

chown: changing ownership of '/backup/raspberrypi/raspberrypi-ddz-backup-20240217-163635/raspiBackup.msg': Operation not permitted

[framps]

Ok. We're one step further now.

On pastebin I find
RBK0009I: raspberrypi: raspiBackup.sh V0.6.9.1-hotfix - 2024-02-24 (f263f3b) started at Sat 24 Feb 23:56:23 CET 2024.which is OK.

But in the debug log I find
RBK0009I: @HOSTNAME@: raspiBackup.sh V0.6.9.1 - 2024-01-02 (2e7040a) started at Sun 25 Feb 05:00:04 CET 2024.

So you attached the wrong debug log 😉

[CapedBaldy]

That's true, sorry about that. Strangely though, I can't find the usual .log file in the remote folder:

Going to test once more to confirm this.
BTW I switched to tgz backups.

[framps]

Strangely though, I can't find the usual .log file in the remote folder:

Hm ... that's indeed strange. At the end of the backup run raspiBackup reports the location of the debug log.

[CapedBaldy]

Tried again turns out the log file wasn't moved from the tmp folder:
raspiBackup.log

Also the /tmp/raspiBackup.logf file contained only these lines:
rsync: [receiver] mkstemp "/backup/raspberrypi/raspberrypi-tgz-backup-20240225-154537/.raspiBackup.log.JZGbLK" failed: Operation not supported (95) rsync error: some files/attrs were not transferred (see previous errors) (code 23) at main.c(1333) [sender=3.2.3] rsync: [receiver] mkstemp "/backup/raspberrypi/raspberrypi-tgz-backup-20240225-154537/.raspiBackup.msg.RtBGar" failed: Operation not supported (95) rsync error: some files/attrs were not transferred (see previous errors) (code 23) at main.c(1333) [sender=3.2.3]

[framps]

I have to setup a ftp server and use curlftpfs as my backup space and try to recreate your issue. Otherwise I'm not able to debug and fix your issue.

I suggested to use nfs instead of curlftpfs. Is this not a workaround for you?

[framps]

I was able to reproduces your issue. I have to work on this for next release.