bit-team / backintime

Back In Time - An easy-to-use backup tool for GNU/Linux using rsync in the back
https://backintime.readthedocs.io
GNU General Public License v2.0
2.06k stars 203 forks source link

[E] Error: rsync: [receiver] chgrp "some/path/and/file" failed: Operation not permitted (1) #1693

Open RandomLegend opened 6 months ago

RandomLegend commented 6 months ago

I just setup a new NFS share for my backintime to store on and now i get a few thousand errors like the title. Interestingly enough the errors are on files that don't exist...

Example: [E] Error: rsync: [receiver] chgrp "/mnt/backup1/backintime/frank-garuda/root/1/new_snapshot/backup/home/frank-garuda/.themes/Catppuccin-Latte/gtk-4.0/assets/.selectionmode-checkbox-checked-dark@2.png.7F7123" failed: Operation not permitted (1)

image

See the weird file ending on that aswell. .png.7F7123

All the files that have this error got a random string of numbers and letters and none of them exist. Only the "real" files do (only the .png for example)

I tried running the profile as root aswell, no change in behaviour. Prior to this config i had it run on an iSCSI share without issues but i don't want to use iSCSI anymore, hence the NFS setup with proper id mapping; Everything else works fine.

Diagnostics:

{ "backintime": { "name": "Back In Time", "version": "1.4.3", "latest-config-version": 6, "local-config-file": "/home/UsernameReplaced/.config/backintime/config", "local-config-file-found": true, "global-config-file": "/etc/backintime/config", "global-config-file-found": false, "started-from": "/usr/share/backintime/common", "running-as-root": false, "user-callback": "/home/UsernameReplaced/.config/backintime/user-callback", "keyring-supported": true }, "host-setup": { "platform": "Linux-6.8.7-zen1-1-zen-x86_64-with-glibc2.39", "system": "Linux #1 ZEN SMP PREEMPT_DYNAMIC Wed, 17 Apr 2024 15:20:00 +0000", "OS": { "/etc/os-release": "Garuda Linux", "/etc/lsb-release": "DISTRIB_ID=Garuda\nDISTRIB_RELEASE=Soaring\nDISTRIB_DESCRIPTION=\"Garuda Linux\"\nDISTRIB_CODENAME=\"Spizaetus\"\n", "/etc/arch-release": "\n" }, "display-system": "wayland", "locale": "en_US, UTF-8", "PATH": "/home/UsernameReplaced/.local/bin:/usr/local/sbin:/usr/local/bin:/usr/bin:/opt/android-sdk/platform-tools:/var/lib/flatpak/exports/bin:/usr/lib/jvm/default/bin:/usr/bin/site_perl:/usr/bin/vendor_perl:/usr/bin/core_perl:/opt/rocm/bin", "RSYNC_OLD_ARGS": "(not set)", "RSYNC_PROTECT_ARGS": "(not set)" }, "python-setup": { "python": "3.11.8 main Feb 12 2024 14:50:05 CPython GCC 13.2.1 20230801", "python-executable": "/usr/bin/python", "python-executable-symlink": true, "python-executable-resolved": "/usr/bin/python3.11", "sys.path": [ "/usr/share/backintime/qt/plugins", "/usr/share/backintime/common/plugins", "/usr/share/backintime/plugins", "/usr/share/backintime/common", "/usr/lib/python311.zip", "/usr/lib/python3.11", "/usr/lib/python3.11/lib-dynload", "/usr/lib/python3.11/site-packages" ], "qt": { "Version": "PyQt 5.15.10 / Qt 5.15.11", "Theme": "Gruvbox-Plus-Dark", "Theme Search Paths": [ "/home/UsernameReplaced/.icons", "/home/UsernameReplaced/.local/share/icons", "/var/lib/flatpak/exports/share/icons", "/usr/share/icons", ":/icons" ], "Fallback Theme": "", "Fallback Search Paths": [] } }, "external-programs": { "rsync": { "version": "3.3.0", "protocol": "31.0", "capabilities": { "file_bits": 64, "inum_bits": 64, "timestamp_bits": 64, "long_int_bits": 64, "socketpairs": true, "symlinks": true, "symtimes": true, "hardlinks": true, "hardlink_specials": true, "hardlink_symlinks": true, "IPv6": true, "atimes": true, "batchfiles": true, "inplace": true, "append": true, "ACLs": true, "xattrs": true, "secluded_args": "optional", "iconv": true, "prealloc": true, "stop_at": true, "crtimes": false }, "optimizations": { "SIMD_roll": true, "asm_roll": false, "openssl_crypto": true, "asm_MD5": false }, "checksum_list": [ "xxh128", "xxh3", "xxh64", "md5", "md4", "sha1", "none" ], "compress_list": [ "zstd", "lz4", "zlibx", "zlib", "none" ], "daemon_auth_list": [ "sha512", "sha256", "sha1", "md5", "md4" ] }, "ssh": "OpenSSH_9.7p1, OpenSSL 3.2.1 30 Jan 2024", "sshfs": "3.7.3", "encfs": "(no encfs)", "shell": "/usr/bin/fish", "shell-version": "fish, version 3.7.1" } }

buhtz commented 6 months ago

Do you have a file syncing application (nextCloud, ownCloud, google drive, unison, etc) running on this folders? The file endings looking like temporary files.

RandomLegend commented 6 months ago

That's what i thought too, but no. My nextcloud is not running in these directories.

Similar programs are also not doing anything there.

Running rsync -av manually in the example directory above also doesn't show these "files"

 franky  ~  rsync -av /home/frank-garuda/.themes/Catppuccin-Latte/gtk-4.0/assets/ /home/frank-garuda/Downloads/test
sending incremental file list
created directory /home/frank-garuda/Downloads/test
./
.directory
scale-horz-marks-after-slider-dark.png
scale-horz-marks-after-slider-dark@2.png
scale-horz-marks-after-slider-disabled-dark.png
scale-horz-marks-after-slider-disabled-dark@2.png
scale-horz-marks-after-slider-disabled.png
scale-horz-marks-after-slider-disabled@2.png
scale-horz-marks-after-slider.png
scale-horz-marks-after-slider@2.png
scale-horz-marks-before-slider-dark.png
scale-horz-marks-before-slider-dark@2.png
scale-horz-marks-before-slider-disabled-dark.png
scale-horz-marks-before-slider-disabled-dark@2.png
scale-horz-marks-before-slider-disabled.png
scale-horz-marks-before-slider-disabled@2.png
scale-horz-marks-before-slider.png
scale-horz-marks-before-slider@2.png
scale-vert-marks-after-slider-dark.png
scale-vert-marks-after-slider-dark@2.png
scale-vert-marks-after-slider-disabled-dark.png
scale-vert-marks-after-slider-disabled-dark@2.png
scale-vert-marks-after-slider-disabled.png
scale-vert-marks-after-slider-disabled@2.png
scale-vert-marks-after-slider.png
scale-vert-marks-after-slider@2.png
scale-vert-marks-before-slider-dark.png
scale-vert-marks-before-slider-dark@2.png
scale-vert-marks-before-slider-disabled-dark.png
scale-vert-marks-before-slider-disabled-dark@2.png
scale-vert-marks-before-slider-disabled.png
scale-vert-marks-before-slider-disabled@2.png
scale-vert-marks-before-slider.png
scale-vert-marks-before-slider@2.png
selectionmode-checkbox-checked-dark.png
selectionmode-checkbox-checked-dark@2.png
selectionmode-checkbox-checked.png
selectionmode-checkbox-checked@2.png
selectionmode-checkbox-unchecked-dark.png
selectionmode-checkbox-unchecked-dark@2.png
selectionmode-checkbox-unchecked.png
selectionmode-checkbox-unchecked@2.png
scalable/
scalable/checkbox-checked-symbolic.svg
scalable/checkbox-checked-symbolic@2.svg
scalable/checkbox-mixed-symbolic.svg
scalable/checkbox-mixed-symbolic@2.svg
scalable/close-symbolic.svg
scalable/close-symbolic@2.svg
scalable/cursor-handle-symbolic.svg
scalable/maximize-symbolic.svg
scalable/maximize-symbolic@2.svg
scalable/minimize-symbolic.svg
scalable/minimize-symbolic@2.svg
scalable/radio-checked-symbolic.svg
scalable/radio-checked-symbolic@2.svg
scalable/radio-mixed-symbolic.svg
scalable/radio-mixed-symbolic@2.svg
scalable/scale-horz-marks-after-slider-symbolic.svg
scalable/scale-horz-marks-before-slider-symbolic.svg
scalable/scale-slider-symbolic.svg
scalable/scale-vert-marks-after-slider-symbolic.svg
scalable/scale-vert-marks-before-slider-symbolic.svg
scalable/small-checkbox-checked-symbolic.svg
scalable/small-checkbox-checked-symbolic@2.svg
scalable/small-checkbox-mixed-symbolic.svg
scalable/small-checkbox-mixed-symbolic@2.svg
scalable/small-radio-checked-symbolic.svg
scalable/small-radio-checked-symbolic@2.svg
scalable/small-radio-mixed-symbolic.svg
scalable/small-radio-mixed-symbolic@2.svg
scalable/unmaximize-symbolic.svg
scalable/unmaximize-symbolic@2.svg

sent 70.279 bytes  received 1.436 bytes  143.430,00 bytes/sec
total size is 64.505  speedup is 0,90

  franky  ~ 
buhtz commented 6 months ago

I wonder if rsync do create files with such random suffixes while transferring? Never seen this before but I am not sure. I also have seen this when compressing files using 7zip.

Is the destination an NTFS file system?

RandomLegend commented 6 months ago

So i just tested running another rsync -av with some bigger files and for me it doesn't create those temporary file endings while transfering.

No, the destination is an NFS share from a dataset on my TrueNAS

buhtz commented 6 months ago

I assume there is an third process involved interfering here. But to be sure can you do us a favor and describe your problem on the rsync mailing list (https://rsync.samba.org/lists.html) to be sure that rsync do not create such temporary files.

EDIT: The error output in this older issues looks similar: #1422

RandomLegend commented 6 months ago

Sorry i didn't had time the past days. I can do that with the mailing list, but i'm not sure this is needed.

i just completely removed backintime, updated my whole system, installed backingtime-git reconfigured it from scratch isntead of using an old config and ran it again.

Again the same issue. I then took one of the paths it threw the error and used rsync- av and it didn't create those temporary files. Also this was for a path of orcaslicer which was 100% not running in the moment.

Backintime error: [E] Error: rsync: [receiver] failed to set permissions on "/mnt/backup1/backintime/frank-garuda/root/1/new_snapshot/backup/home/frank-garuda/.config/OrcaSlicer/log/.debug_Sat_Apr_13_19_13_33_636696.log.0.aOQLkF": No such file or directory (2) Manual rsync -av move:

rsync -av /home/frank-garuda/.config/OrcaSlicer/log /mnt/backup1/test
sending incremental file list
log/
log/debug_Fri_Apr_19_14_35_38_587312.log.0
log/debug_Fri_Apr_19_15_49_44_1473902.log.0
log/debug_Fri_Apr_26_09_32_46_4001060.log.0
log/debug_Mon_Apr_08_16_07_38_35787.log.0
log/debug_Mon_Apr_08_16_39_50_386240.log.0
log/debug_Mon_Apr_08_17_11_27_732232.log.0
log/debug_Mon_Apr_08_17_13_30_755669.log.0
log/debug_Mon_Apr_15_12_48_54_2244243.log.0
log/debug_Sat_Apr_06_23_18_19_3199821.log.0
log/debug_Sat_Apr_13_13_55_28_3000700.log.0
log/debug_Sat_Apr_13_17_27_51_119070.log.0
log/debug_Sat_Apr_13_19_13_33_636696.log.0
log/debug_Sat_Apr_20_21_37_25_2035748.log.0
log/debug_Sun_Apr_07_20_39_28_3908380.log.0
log/debug_Sun_Apr_07_20_52_34_3933651.log.0
log/debug_Sun_Apr_21_00_23_03_3142983.log.0
log/debug_Thu_Apr_18_10_38_36_2464549.log.0
log/debug_Thu_Apr_18_10_49_14_2584626.log.0
log/debug_Thu_Apr_18_13_46_19_270424.log.0
log/debug_Thu_Apr_18_14_02_57_466150.log.0
log/debug_Thu_Apr_18_18_08_50_3384627.log.0
log/debug_Thu_Apr_18_18_16_32_3475163.log.0
log/debug_Thu_Apr_18_18_19_06_3504709.log.0
log/debug_Thu_Apr_25_23_36_49_3145672.log.0
log/debug_Wed_Apr_10_22_35_33_2357674.log.0
log/debug_Wed_Apr_10_23_59_27_2516757.log.0
log/debug_Wed_Apr_24_23_28_58_559524.log.0
log/gridfinity-rebuilt-baseplate.3mf
log/schublade-gridfinity.3mf

sent 3.594.638 bytes  received 571 bytes  2.396.806,00 bytes/sec
total size is 3.591.236  speedup is 1,00
RandomLegend commented 6 months ago

So I've meticulously put the handful of folders in the exlude list and let it rerun a couple times. No further issues.

So it's just a handful of directories and files and i can't make any pattern out of it. Completely random. Two directories aren't used by any application but are just folders for me to put some textfiles into and nothing else uses them. So it doesn't make any sense to me at all.

buhtz commented 6 months ago

Thanks for reporting this detail. Labeled the issue as "Heisenbug" to express that we don't know why it happens but also taking it serious.

geeksmith commented 5 months ago

This issue also affects me, has for a long time. I'm saving backups to NFS on a mycloud appliance and it generates tens of thousands of these errors.