smart-remove and remove not working over ssh to Synology NAS

[TomServo3000]

Describe the problem, feature or ask a question:

I recently noticed that my old snapshots were not being auto removed by the scheduled smart-remove run. Running remove manually shows the following error from rsync:

DEBUG: [common/backintime.py:589 argParse] Arguments: {'debug': True, 'command': 'remove', 'SNAPSHOT_ID': ['20250205-180002-924'], 'func': <function remove at 0x7ad48e126d40>} | unknownArgs: []

Back In Time
Version: 1.4.3

Back In Time comes with ABSOLUTELY NO WARRANTY.
This is free software, and you are welcome to redistribute it
under certain conditions; type `backintime --license' for details.

DEBUG: [common/configfile.py:591 Config.setCurrentProfile] Change current profile: 1=Main profile
DEBUG: [common/tools.py:186 initiate_translation] No language code. Use systems current locale.
DEBUG: [common/backintime.py:677 getConfig] config file: /root/.config/backintime/config
DEBUG: [common/backintime.py:678 getConfig] share path: /root/.local/share/backintime
DEBUG: [common/backintime.py:679 getConfig] profiles: 1=Main profile
DEBUG: [common/pluginmanager.py:245 PluginManager.load] Register plugin path /usr/share/backintime/plugins
DEBUG: [common/pluginmanager.py:249 PluginManager.load] Probing plugin systrayiconplugin.py
DEBUG: [common/tools.py:735 is_Qt5_working] Qt5 probing result: exit code 2
DEBUG: [common/tools.py:738 is_Qt5_working] Qt5 probing stdout:

DEBUG: [common/tools.py:739 is_Qt5_working] Qt5 probing errout:
DEBUG: [common/qt5_probing.py:89 <module>] /usr/share/backintime/common/qt5_probing.py started... Call args: ['/usr/share/backintime/common/qt5_probing.py', '--debug']
DEBUG: [common/qt5_probing.py:90 <module>] Display system: ($XDG_SESSION_TYPE is not set)
DEBUG: [common/qt5_probing.py:91 <module>] XDG_RUNTIME_DIR=($XDG_RUNTIME_DIR is not set)
DEBUG: [common/qt5_probing.py:92 <module>] XAUTHORITY=/home/thomas/.Xauthority
DEBUG: [common/qt5_probing.py:93 <module>] QT_QPA_PLATFORM=($QT_QPA_PLATFORM is not set)
DEBUG: [common/qt5_probing.py:95 <module>] Current euid: 0
QStandardPaths: XDG_RUNTIME_DIR not set, defaulting to '/tmp/runtime-root'
DEBUG: [common/qt5_probing.py:126 <module>] isSystemTrayAvailable for Qt5: True
DEBUG: [common/qt5_probing.py:131 <module>] /usr/share/backintime/common/qt5_probing.py is terminating normally (exit code: 2)

DEBUG: [plugins/systrayiconplugin.py:76 init] System tray is available to show the BiT system tray icon
DEBUG: [common/pluginmanager.py:263 PluginManager.load] Add plugin systrayiconplugin.py
DEBUG: [common/pluginmanager.py:249 PluginManager.load] Probing plugin usercallbackplugin.py
DEBUG: [common/pluginmanager.py:249 PluginManager.load] Probing plugin notifyplugin.py
DEBUG: [common/pluginmanager.py:263 PluginManager.load] Add plugin notifyplugin.py
DEBUG: [common/sshtools.py:296 SSH.startSshAgent] ssh-agent started successful: SSH_AUTH_SOCK=/tmp/ssh-mUZaEEEFqbj9/agent.3977 | SSH_AGENT_PID=3978
DEBUG: [common/sshtools.py:351 SSH.unlockSshAgent] Add private key /home/thomas/.ssh/rsync-key to ssh agent
DEBUG: [common/sshtools.py:361 SSH.unlockSshAgent] Password available: False
DEBUG: [common/mount.py:786 SSH.mountProcessLockAcquire] Acquire mountprocess lock /root/.local/share/backintime/mnt/3971.lock
DEBUG: [common/sshtools.py:693 SSH.checkPingHost] Check ping host
DEBUG: [common/sshtools.py:712 SSH.checkPingHost] Host diskstation is available
DEBUG: [common/sshtools.py:434 SSH.checkLogin] Check login
DEBUG: [common/sshtools.py:608 SSH.checkRemoteFolder] Check remote folder
DEBUG: [common/sshtools.py:635 SSH.checkRemoteFolder] Call command: ssh -o ServerAliveInterval=240 -o LogLevel=Error -o IdentityFile=/home/thomas/.ssh/rsync-key -p 22 thomas@diskstation d=0;test -e "./" || d=1;test $d -eq 1 && mkdir "./"; err=$?;test $d -eq 1 && exit $err;test -d "./" || exit 11;test -w "./" || exit 12;test -x "./" || exit 13;exit 20
DEBUG: [common/sshtools.py:645 SSH.checkRemoteFolder] Command returncode: 20
DEBUG: [common/sshtools.py:199 SSH._mount] Call mount command: sshfs -o ServerAliveInterval=240 -o LogLevel=Error -o IdentityFile=/home/thomas/.ssh/rsync-key -p 22 -o idmap=user -o cache_dir_timeout=2 -o cache_stat_timeout=2 thomas@diskstation:./ /root/.local/share/backintime/mnt/599BBA9E/mountpoint
INFO: [common/mount.py:537 SSH.mount] mount ssh: thomas@diskstation:./ on /root/.local/share/backintime/mnt/599BBA9E/mountpoint
DEBUG: [common/mount.py:811 SSH.mountLockAquire] Set mount lock /root/.local/share/backintime/mnt/599BBA9E/locks/3971.lock
DEBUG: [common/mount.py:797 SSH.mountProcessLockRelease] Release mountprocess lock /root/.local/share/backintime/mnt/3971.lock
Do you really want to remove these snapshots?
2025-02-05 18:00:02
(no/yes): yes
DEBUG: [common/cli.py:55 Execute.remove] Call command "rsync -a --delete -s --rsh=ssh -o ServerAliveInterval=240 -o LogLevel=Error -o IdentityFile=/home/thomas/.ssh/rsync-key -p 22 /tmp/tmpdmm0qfnv/ thomas@diskstation:./backintime/bitbucket/users/profile1/20250205-180002-924"
DEBUG: [common/tools.py:2500 run] Starting command 'rsync -a --delet...'
WARNING: [common/cli.py:55 Execute.remove] Command "rsync -a --delete -s --rsh=ssh -o ServerAliveInterval=240 -o LogLevel=Error -o IdentityFile=/home/thomas/.ssh/rsync-key -p 22 /tmp/tmpdmm0qfnv/ thomas@diskstation:./backintime/bitbucket/users/profile1/20250205-180002-924" returns 12 | Permission denied, please try again.
rsync: connection unexpectedly closed (0 bytes received so far) [sender]
rsync error: error in rsync protocol data stream (code 12) at io.c(232) [sender=3.2.7]
ERROR: [common/snapshots.py:667 remove] Last rsync command failed with return code "12". See previous WARNING message in the logs for details.
DEBUG: [common/sshtools.py:267 SSH.startSshAgent] ssh-agent already running. Skip starting a new one.
DEBUG: [common/sshtools.py:422 SSH.unlockSshAgent] Private key /home/thomas/.ssh/rsync-key is already unlocked in ssh agent
DEBUG: [common/mount.py:786 SSH.mountProcessLockAcquire] Acquire mountprocess lock /root/.local/share/backintime/mnt/3971.lock
INFO: [common/mount.py:577 SSH.umount] unmount ssh: thomas@diskstation:./ from /root/.local/share/backintime/mnt/599BBA9E/mountpoint
DEBUG: [common/mount.py:836 SSH.mountLockRelease] Remove mount lock /root/.local/share/backintime/mnt/599BBA9E/locks/3971.lock
DEBUG: [common/mount.py:797 SSH.mountProcessLockRelease] Release mountprocess lock /root/.local/share/backintime/mnt/3971.lock

The reason this is failing is because rsync to synology NAS requires the --rsync-path="/bin/rsync" option to rsync. I have this added in the "Paste additional options to rsync" config setting in GUI. This setting does take affect on backups so they are working, but for some reason it is left out on remove/smart-remove. It is possible that something changed in a prior update to break this functionality because I know that it has worked in the past. The attached patch to tools.py allows smart-remove and remove to work on my setup. I'm not sure if this is the best way to fix it but it does prove the failure is caused by the missing option and gets past the issue on my setup.

synology_remove.patch

[buhtz]

Hello Tom,

Thank you for taking the time to report the issue and providing the
details. I appreciate your feedback.

The problem that the "additional options" not used on removing actions is known. See #1861.

But I am not aware that this is new or worked in the past.

I am assuming that Synology again modified something (the rsync path) in there system. Please check the FAQ for Synology related issues. Please also ask the Synology support.

Beside #1861 I am not sure if we have a new bug here.

If you have any more details to share, feel free to reach out.

Not sure when we'll find the time to work on it. Please see the projects background information to get an idea about our workflow and priorities:

• Maintenance status
• The team
• Strategy outline / Roadmap

Best regards,
Christian

[TomServo3000]

Yes, this does look like a duplicate of #1861. I didn't see that in my initial search.