backintime icon indicating copy to clipboard operation
backintime copied to clipboard

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

Open RandomLegend opened this issue 1 year ago • 9 comments

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/[email protected]" 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" } }

RandomLegend avatar Apr 19 '24 23:04 RandomLegend

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

buhtz avatar Apr 20 '24 06:04 buhtz

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
[email protected]
scale-horz-marks-after-slider-disabled-dark.png
[email protected]
scale-horz-marks-after-slider-disabled.png
[email protected]
scale-horz-marks-after-slider.png
[email protected]
scale-horz-marks-before-slider-dark.png
[email protected]
scale-horz-marks-before-slider-disabled-dark.png
[email protected]
scale-horz-marks-before-slider-disabled.png
[email protected]
scale-horz-marks-before-slider.png
[email protected]
scale-vert-marks-after-slider-dark.png
[email protected]
scale-vert-marks-after-slider-disabled-dark.png
[email protected]
scale-vert-marks-after-slider-disabled.png
[email protected]
scale-vert-marks-after-slider.png
[email protected]
scale-vert-marks-before-slider-dark.png
[email protected]
scale-vert-marks-before-slider-disabled-dark.png
[email protected]
scale-vert-marks-before-slider-disabled.png
[email protected]
scale-vert-marks-before-slider.png
[email protected]
selectionmode-checkbox-checked-dark.png
[email protected]
selectionmode-checkbox-checked.png
[email protected]
selectionmode-checkbox-unchecked-dark.png
[email protected]
selectionmode-checkbox-unchecked.png
[email protected]
scalable/
scalable/checkbox-checked-symbolic.svg
scalable/[email protected]
scalable/checkbox-mixed-symbolic.svg
scalable/[email protected]
scalable/close-symbolic.svg
scalable/[email protected]
scalable/cursor-handle-symbolic.svg
scalable/maximize-symbolic.svg
scalable/[email protected]
scalable/minimize-symbolic.svg
scalable/[email protected]
scalable/radio-checked-symbolic.svg
scalable/[email protected]
scalable/radio-mixed-symbolic.svg
scalable/[email protected]
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/[email protected]
scalable/small-checkbox-mixed-symbolic.svg
scalable/[email protected]
scalable/small-radio-checked-symbolic.svg
scalable/[email protected]
scalable/small-radio-mixed-symbolic.svg
scalable/[email protected]
scalable/unmaximize-symbolic.svg
scalable/[email protected]

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

  franky  ~ 

RandomLegend avatar Apr 20 '24 08:04 RandomLegend

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?

buhtz avatar Apr 20 '24 08:04 buhtz

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

RandomLegend avatar Apr 20 '24 08:04 RandomLegend

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

buhtz avatar Apr 21 '24 08:04 buhtz

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 avatar Apr 26 '24 12:04 RandomLegend

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.

RandomLegend avatar Apr 27 '24 11:04 RandomLegend

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.

buhtz avatar Apr 27 '24 19:04 buhtz

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.

geeksmith avatar May 10 '24 22:05 geeksmith