borgbase / vorta

Desktop Backup Client for Borg Backup
https://vorta.borgbase.com
GNU General Public License v3.0
2.02k stars 134 forks source link

Shell command after backup: The backup will not be completed #2120

Open Golddouble opened 2 weeks ago

Golddouble commented 2 weeks ago

Description

When I put the following after-backup-shell-command into the field, then Vorta never comes to an end with the backup. The command is: sleep 20 && udisksctl unmount -b /dev/disk/by-uuid/f4e0668f-b6f4-4f51-8dec-067f0ca780f7 && udisksctl unmount -b /dev/disk/by-uuid/0CD42CE5D42CD2AE && udisksctl unmount -b /dev/disk/by-uuid/2420F3B520F38BD4 && sleep 2 && udisksctl power-off --block-device $(readlink -e /dev/disk/by-uuid/f4e0668f-b6f4-4f51-8dec-067f0ca780f7| sed 's/[0-9]*$//' ) && sleep 2 && paplay /home/USER/.local/share/sounds_dawe/Fur_Vorta/pluck.wav grafik

What does the command do? It unmounts the external HDD, when the backup is finished and makes a sound. The issue has something to to, that the HDD is no more reachable, although I have sleep 20 at the beginning of the command. But this command was no problem in Vorta 0.7.6 even without "sleep 20" at the beginning of the command. It has just worked in Vorta 0.7.6.

Peek 2024-11-05 10-56

Reproduction

OS

MX-Linux 23.4 Xfce

Version of Vorta

0.9.1

What did you install Vorta with?

Distribution package

Version of Borg

1.4.0

Logs

2024-11-05 10:23:51,054 - vorta.i18n - DEBUG - Loading translation succeeded for ['de-Latn-CH', 'de-CH'].
2024-11-05 10:23:51,189 - vorta.views.source_tab - DEBUG - Added item number 0 from 1
2024-11-05 10:23:51,335 - root - INFO - Using NetworkManagerMonitor NetworkStatusMonitor implementation.
2024-11-05 10:23:51,392 - vorta.borg.jobs_manager - DEBUG - Add job for site default
2024-11-05 10:23:51,392 - vorta.borg.jobs_manager - DEBUG - Start job on site: default
2024-11-05 10:23:51,417 - vorta.borg.borg_job - INFO - Running command /usr/bin/borg --version
2024-11-05 10:23:51,838 - vorta.borg.jobs_manager - DEBUG - Finish job for site: default
2024-11-05 10:23:51,838 - vorta.borg.jobs_manager - DEBUG - No more jobs for site: default
2024-11-05 10:23:51,839 - vorta.scheduler - DEBUG - Refreshing all scheduler timers
2024-11-05 10:23:51,841 - vorta.scheduler - DEBUG - Scheduler for profile 2 is disabled.
2024-11-05 10:23:51,843 - vorta.scheduler - DEBUG - Scheduler for profile 3 is disabled.
2024-11-05 10:23:51,845 - vorta.scheduler - DEBUG - Scheduler for profile 4 is disabled.
2024-11-05 10:23:51,847 - vorta.scheduler - DEBUG - Scheduler for profile 5 is disabled.
2024-11-05 10:23:51,849 - vorta.scheduler - DEBUG - Scheduler for profile 6 is disabled.
2024-11-05 10:23:51,850 - vorta.scheduler - DEBUG - Scheduler for profile 7 is disabled.
2024-11-05 10:23:51,852 - vorta.scheduler - DEBUG - Scheduler for profile 9 is disabled.
2024-11-05 10:23:51,854 - vorta.scheduler - DEBUG - Scheduler for profile 10 is disabled.
2024-11-05 10:24:14,537 - vorta.keyring.abc - DEBUG - No module named 'objc'
2024-11-05 10:24:14,568 - asyncio - DEBUG - Using selector: EpollSelector
2024-11-05 10:24:14,569 - vorta.keyring.abc - DEBUG - Using VortaSecretStorageKeyring
2024-11-05 10:24:14,569 - vorta.borg.borg_job - DEBUG - Using VortaSecretStorageKeyring keyring to store passwords.
2024-11-05 10:24:18,097 - vorta.borg.borg_job - DEBUG - Password not found in primary keyring. Falling back to VortaDBKeyring.
2024-11-05 10:24:18,143 - vorta.borg.jobs_manager - DEBUG - Add job for site 12
2024-11-05 10:24:18,143 - vorta.borg.jobs_manager - DEBUG - Start job on site: 12
2024-11-05 10:24:18,176 - vorta.borg.borg_job - INFO - Running command /usr/bin/borg create --list --progress --info --log-json --json --filter=AM -C lz4 --exclude-from /tmp/tmp_ewrd_el /media/user/Seagate_2TB_ext4/Linux_Home/Vorta/MX-23_Home_ohne_VMs,neue_Vorta_Version::mx-23-Xfce-2024-11-05-102418 /home/user
2024-11-05 10:24:18,664 - vorta.borg.borg_job - INFO - Creating archive at "/media/user/Seagate_2TB_ext4/Linux_Home/Vorta/MX-23_Home_ohne_VMs,neue_Vorta_Version::mx-23-Xfce-2024-11-05-102418"
2024-11-05 10:27:07,681 - vorta.scheduler - DEBUG - Scheduler for profile 10 is disabled.
2024-11-05 10:27:16,056 - vorta.borg.jobs_manager - DEBUG - Finish job for site: 12
2024-11-05 10:27:16,056 - vorta.borg.jobs_manager - DEBUG - No more jobs for site: 12
2024-11-05 10:28:15,158 - vorta.borg.borg_job - DEBUG - Cancel job on site default
2024-11-05 10:28:15,158 - vorta.borg.borg_job - DEBUG - Cancel job on site 12
2024-11-05 10:28:15,158 - vorta.borg.jobs_manager - INFO - Finished cancelling all jobs
2024-11-05 10:28:16,886 - vorta.i18n - DEBUG - Loading translation succeeded for ['de-Latn-CH', 'de-CH'].
2024-11-05 10:28:16,974 - vorta.views.source_tab - DEBUG - Added item number 0 from 1
2024-11-05 10:28:17,119 - root - INFO - Using NetworkManagerMonitor NetworkStatusMonitor implementation.
2024-11-05 10:28:17,173 - vorta.borg.jobs_manager - DEBUG - Add job for site default
2024-11-05 10:28:17,174 - vorta.borg.jobs_manager - DEBUG - Start job on site: default
2024-11-05 10:28:17,200 - vorta.borg.borg_job - INFO - Running command /usr/bin/borg --version
2024-11-05 10:28:17,554 - vorta.borg.jobs_manager - DEBUG - Finish job for site: default
2024-11-05 10:28:17,554 - vorta.scheduler - DEBUG - Refreshing all scheduler timers
2024-11-05 10:28:17,554 - vorta.borg.jobs_manager - DEBUG - No more jobs for site: default
2024-11-05 10:28:17,556 - vorta.scheduler - DEBUG - Scheduler for profile 2 is disabled.
2024-11-05 10:28:17,557 - vorta.scheduler - DEBUG - Scheduler for profile 3 is disabled.
2024-11-05 10:28:17,559 - vorta.scheduler - DEBUG - Scheduler for profile 4 is disabled.
2024-11-05 10:28:17,561 - vorta.scheduler - DEBUG - Scheduler for profile 5 is disabled.
2024-11-05 10:28:17,562 - vorta.scheduler - DEBUG - Scheduler for profile 6 is disabled.
2024-11-05 10:28:17,564 - vorta.scheduler - DEBUG - Scheduler for profile 7 is disabled.
2024-11-05 10:28:17,565 - vorta.scheduler - DEBUG - Scheduler for profile 9 is disabled.
2024-11-05 10:28:17,567 - vorta.scheduler - DEBUG - Scheduler for profile 10 is disabled.
2024-11-05 10:28:26,057 - vorta.keyring.abc - DEBUG - No module named 'objc'
2024-11-05 10:28:26,079 - asyncio - DEBUG - Using selector: EpollSelector
2024-11-05 10:28:26,079 - vorta.keyring.abc - DEBUG - Using VortaSecretStorageKeyring
2024-11-05 10:28:26,079 - vorta.borg.borg_job - DEBUG - Using VortaSecretStorageKeyring keyring to store passwords.
2024-11-05 10:28:29,163 - asyncio - DEBUG - Using selector: EpollSelector
2024-11-05 10:28:29,164 - vorta.keyring.secretstorage - DEBUG - Found 0 passwords matching repo URL.
2024-11-05 10:28:29,164 - vorta.borg.borg_job - DEBUG - Password not found in primary keyring. Falling back to VortaDBKeyring.
2024-11-05 10:28:33,475 - vorta.borg.jobs_manager - DEBUG - Add job for site 12
2024-11-05 10:28:33,475 - vorta.borg.jobs_manager - DEBUG - Start job on site: 12
2024-11-05 10:28:33,510 - vorta.borg.borg_job - INFO - Running command /usr/bin/borg delete --info --log-json /media/user/Seagate_2TB_ext4/Linux_Home/Vorta/MX-23_Home_ohne_VMs,neue_Vorta_Version::mx-23-Xfce-2024-11-05-102418
2024-11-05 10:28:47,028 - vorta.borg.jobs_manager - DEBUG - Finish job for site: 12
2024-11-05 10:28:47,028 - vorta.borg.jobs_manager - DEBUG - No more jobs for site: 12
2024-11-05 10:28:47,029 - vorta.scheduler - DEBUG - Scheduler for profile 10 is disabled.
2024-11-05 10:28:54,267 - vorta.keyring.abc - DEBUG - No module named 'objc'
2024-11-05 10:28:54,268 - asyncio - DEBUG - Using selector: EpollSelector
2024-11-05 10:28:54,269 - vorta.keyring.abc - DEBUG - Using VortaSecretStorageKeyring
2024-11-05 10:28:54,269 - vorta.borg.borg_job - DEBUG - Using VortaSecretStorageKeyring keyring to store passwords.
2024-11-05 10:28:54,270 - asyncio - DEBUG - Using selector: EpollSelector
2024-11-05 10:28:54,270 - vorta.keyring.secretstorage - DEBUG - Found 0 passwords matching repo URL.
2024-11-05 10:28:54,270 - vorta.borg.borg_job - DEBUG - Password not found in primary keyring. Falling back to VortaDBKeyring.
2024-11-05 10:28:54,276 - vorta.borg.jobs_manager - DEBUG - Add job for site 12
2024-11-05 10:28:54,276 - vorta.borg.jobs_manager - DEBUG - Start job on site: 12
2024-11-05 10:28:54,313 - vorta.borg.borg_job - INFO - Running command /usr/bin/borg create --list --progress --info --log-json --json --filter=AM -C lz4 --exclude-from /tmp/tmpbx6sgvho /media/user/Seagate_2TB_ext4/Linux_Home/Vorta/MX-23_Home_ohne_VMs,neue_Vorta_Version::mx-23-Xfce-2024-11-05-102854 /home/user
2024-11-05 10:28:54,618 - vorta.borg.borg_job - INFO - Creating archive at "/media/user/Seagate_2TB_ext4/Linux_Home/Vorta/MX-23_Home_ohne_VMs,neue_Vorta_Version::mx-23-Xfce-2024-11-05-102854"
2024-11-05 10:30:58,026 - vorta.borg.jobs_manager - DEBUG - Finish job for site: 12
2024-11-05 10:30:58,027 - vorta.borg.jobs_manager - DEBUG - No more jobs for site: 12
2024-11-05 10:30:58,027 - vorta.scheduler - DEBUG - Scheduler for profile 10 is disabled.
2024-11-05 10:32:36,163 - vorta.views.source_tab - DEBUG - Added item number 0 from 1
2024-11-05 10:39:45,570 - vorta.views.source_tab - DEBUG - Added item number 0 from 1
2024-11-05 10:40:02,826 - vorta.views.source_tab - DEBUG - Added item number 0 from 1
2024-11-05 10:43:17,240 - vorta.scheduler - DEBUG - Refreshing all scheduler timers
2024-11-05 10:43:17,244 - vorta.scheduler - DEBUG - Scheduler for profile 2 is disabled.
2024-11-05 10:43:17,248 - vorta.scheduler - DEBUG - Scheduler for profile 3 is disabled.
2024-11-05 10:43:17,252 - vorta.scheduler - DEBUG - Scheduler for profile 4 is disabled.
2024-11-05 10:43:17,254 - vorta.scheduler - DEBUG - Scheduler for profile 5 is disabled.
2024-11-05 10:43:17,256 - vorta.scheduler - DEBUG - Scheduler for profile 6 is disabled.
2024-11-05 10:43:17,258 - vorta.scheduler - DEBUG - Scheduler for profile 7 is disabled.
2024-11-05 10:43:17,259 - vorta.scheduler - DEBUG - Scheduler for profile 9 is disabled.
2024-11-05 10:43:17,261 - vorta.scheduler - DEBUG - Scheduler for profile 10 is disabled.
2024-11-05 10:44:31,322 - vorta.views.source_tab - DEBUG - Added item number 0 from 1
2024-11-05 10:44:43,162 - vorta.views.source_tab - DEBUG - Added item number 0 from 1
2024-11-05 10:44:48,451 - vorta.views.source_tab - DEBUG - Added item number 0 from 1
2024-11-05 10:45:16,004 - vorta.keyring.abc - DEBUG - No module named 'objc'
2024-11-05 10:45:16,007 - asyncio - DEBUG - Using selector: EpollSelector
2024-11-05 10:45:16,009 - vorta.keyring.abc - DEBUG - Using VortaSecretStorageKeyring
2024-11-05 10:45:16,009 - vorta.borg.borg_job - DEBUG - Using VortaSecretStorageKeyring keyring to store passwords.
2024-11-05 10:45:16,010 - asyncio - DEBUG - Using selector: EpollSelector
2024-11-05 10:45:16,010 - vorta.keyring.secretstorage - DEBUG - Found 0 passwords matching repo URL.
2024-11-05 10:45:16,010 - vorta.borg.borg_job - DEBUG - Password not found in primary keyring. Falling back to VortaDBKeyring.
2024-11-05 10:45:16,017 - vorta.borg.jobs_manager - DEBUG - Add job for site 12
2024-11-05 10:45:16,018 - vorta.borg.jobs_manager - DEBUG - Start job on site: 12
2024-11-05 10:45:16,051 - vorta.borg.borg_job - INFO - Running command /usr/bin/borg create --list --progress --info --log-json --json --filter=AM -C lz4 --exclude-from /tmp/tmp7vjlkagw /media/user/Seagate_2TB_ext4/Linux_Home/Vorta/MX-23_Home_ohne_VMs,neue_Vorta_Version::mx-23-Xfce-2024-11-05-104516 /home/user
2024-11-05 10:45:16,502 - vorta.borg.borg_job - INFO - Creating archive at "/media/user/Seagate_2TB_ext4/Linux_Home/Vorta/MX-23_Home_ohne_VMs,neue_Vorta_Version::mx-23-Xfce-2024-11-05-104516"
2024-11-05 10:46:53,141 - vorta.scheduler - DEBUG - Scheduler for profile 10 is disabled.
2024-11-05 10:46:53,594 - vorta.borg.jobs_manager - DEBUG - Finish job for site: 12
2024-11-05 10:46:53,595 - vorta.borg.jobs_manager - DEBUG - No more jobs for site: 12
2024-11-05 10:48:08,767 - vorta.borg.borg_job - DEBUG - Cancel job on site default
2024-11-05 10:48:08,767 - vorta.borg.borg_job - DEBUG - Cancel job on site 12
2024-11-05 10:48:08,767 - vorta.borg.jobs_manager - INFO - Finished cancelling all jobs
2024-11-05 10:48:23,261 - vorta.borg.borg_job - DEBUG - Cancel job on site default
2024-11-05 10:48:23,261 - vorta.borg.borg_job - DEBUG - Cancel job on site 12
2024-11-05 10:48:23,261 - vorta.borg.jobs_manager - INFO - Finished cancelling all jobs
2024-11-05 10:48:27,353 - vorta.i18n - DEBUG - Loading translation succeeded for ['de-Latn-CH', 'de-CH'].
2024-11-05 10:48:27,442 - vorta.views.source_tab - DEBUG - Added item number 0 from 1
2024-11-05 10:48:27,591 - root - INFO - Using NetworkManagerMonitor NetworkStatusMonitor implementation.
2024-11-05 10:48:27,645 - vorta.borg.jobs_manager - DEBUG - Add job for site default
2024-11-05 10:48:27,645 - vorta.borg.jobs_manager - DEBUG - Start job on site: default
2024-11-05 10:48:27,672 - vorta.borg.borg_job - INFO - Running command /usr/bin/borg --version
2024-11-05 10:48:28,027 - vorta.borg.jobs_manager - DEBUG - Finish job for site: default
2024-11-05 10:48:28,028 - vorta.borg.jobs_manager - DEBUG - No more jobs for site: default
2024-11-05 10:48:28,028 - vorta.scheduler - DEBUG - Refreshing all scheduler timers
2024-11-05 10:48:28,030 - vorta.scheduler - DEBUG - Scheduler for profile 2 is disabled.
2024-11-05 10:48:28,031 - vorta.scheduler - DEBUG - Scheduler for profile 3 is disabled.
2024-11-05 10:48:28,033 - vorta.scheduler - DEBUG - Scheduler for profile 4 is disabled.
2024-11-05 10:48:28,034 - vorta.scheduler - DEBUG - Scheduler for profile 5 is disabled.
2024-11-05 10:48:28,036 - vorta.scheduler - DEBUG - Scheduler for profile 6 is disabled.
2024-11-05 10:48:28,038 - vorta.scheduler - DEBUG - Scheduler for profile 7 is disabled.
2024-11-05 10:48:28,039 - vorta.scheduler - DEBUG - Scheduler for profile 9 is disabled.
2024-11-05 10:48:28,041 - vorta.scheduler - DEBUG - Scheduler for profile 10 is disabled.
2024-11-05 10:48:35,520 - vorta.keyring.abc - DEBUG - No module named 'objc'
2024-11-05 10:48:35,542 - asyncio - DEBUG - Using selector: EpollSelector
2024-11-05 10:48:35,543 - vorta.keyring.abc - DEBUG - Using VortaSecretStorageKeyring
2024-11-05 10:48:35,543 - vorta.borg.borg_job - DEBUG - Using VortaSecretStorageKeyring keyring to store passwords.
2024-11-05 10:48:35,543 - asyncio - DEBUG - Using selector: EpollSelector
2024-11-05 10:48:35,544 - vorta.keyring.secretstorage - DEBUG - Found 0 passwords matching repo URL.
2024-11-05 10:48:35,544 - vorta.borg.borg_job - DEBUG - Password not found in primary keyring. Falling back to VortaDBKeyring.
2024-11-05 10:48:36,960 - vorta.borg.jobs_manager - DEBUG - Add job for site 12
2024-11-05 10:48:36,961 - vorta.borg.jobs_manager - DEBUG - Start job on site: 12
2024-11-05 10:48:36,998 - vorta.borg.borg_job - INFO - Running command /usr/bin/borg delete --info --log-json /media/user/Seagate_2TB_ext4/Linux_Home/Vorta/MX-23_Home_ohne_VMs,neue_Vorta_Version::mx-23-Xfce-2024-11-05-104516
2024-11-05 10:48:46,853 - vorta.borg.jobs_manager - DEBUG - Finish job for site: 12
2024-11-05 10:48:46,854 - vorta.borg.jobs_manager - DEBUG - No more jobs for site: 12
2024-11-05 10:48:46,854 - vorta.scheduler - DEBUG - Scheduler for profile 10 is disabled.
2024-11-05 10:49:46,162 - vorta.borg.borg_job - DEBUG - Cancel job on site default
2024-11-05 10:49:46,162 - vorta.borg.borg_job - DEBUG - Cancel job on site 12
2024-11-05 10:49:46,162 - vorta.borg.jobs_manager - INFO - Finished cancelling all jobs
2024-11-05 10:49:48,945 - vorta.i18n - DEBUG - Loading translation succeeded for ['de-Latn-CH', 'de-CH'].
2024-11-05 10:49:49,041 - vorta.views.source_tab - DEBUG - Added item number 0 from 1
2024-11-05 10:49:49,188 - root - INFO - Using NetworkManagerMonitor NetworkStatusMonitor implementation.
2024-11-05 10:49:49,244 - vorta.borg.jobs_manager - DEBUG - Add job for site default
2024-11-05 10:49:49,245 - vorta.borg.jobs_manager - DEBUG - Start job on site: default
2024-11-05 10:49:49,271 - vorta.borg.borg_job - INFO - Running command /usr/bin/borg --version
2024-11-05 10:49:49,660 - vorta.borg.jobs_manager - DEBUG - Finish job for site: default
2024-11-05 10:49:49,660 - vorta.borg.jobs_manager - DEBUG - No more jobs for site: default
2024-11-05 10:49:49,661 - vorta.scheduler - DEBUG - Refreshing all scheduler timers
2024-11-05 10:49:49,662 - vorta.scheduler - DEBUG - Scheduler for profile 2 is disabled.
2024-11-05 10:49:49,664 - vorta.scheduler - DEBUG - Scheduler for profile 3 is disabled.
2024-11-05 10:49:49,666 - vorta.scheduler - DEBUG - Scheduler for profile 4 is disabled.
2024-11-05 10:49:49,668 - vorta.scheduler - DEBUG - Scheduler for profile 5 is disabled.
2024-11-05 10:49:49,670 - vorta.scheduler - DEBUG - Scheduler for profile 6 is disabled.
2024-11-05 10:49:49,672 - vorta.scheduler - DEBUG - Scheduler for profile 7 is disabled.
2024-11-05 10:49:49,674 - vorta.scheduler - DEBUG - Scheduler for profile 9 is disabled.
2024-11-05 10:49:49,675 - vorta.scheduler - DEBUG - Scheduler for profile 10 is disabled.
2024-11-05 10:49:55,885 - vorta.keyring.abc - DEBUG - No module named 'objc'
2024-11-05 10:49:55,907 - asyncio - DEBUG - Using selector: EpollSelector
2024-11-05 10:49:55,908 - vorta.keyring.abc - DEBUG - Using VortaSecretStorageKeyring
2024-11-05 10:49:55,908 - vorta.borg.borg_job - DEBUG - Using VortaSecretStorageKeyring keyring to store passwords.
2024-11-05 10:49:55,909 - asyncio - DEBUG - Using selector: EpollSelector
2024-11-05 10:49:55,909 - vorta.keyring.secretstorage - DEBUG - Found 0 passwords matching repo URL.
2024-11-05 10:49:55,909 - vorta.borg.borg_job - DEBUG - Password not found in primary keyring. Falling back to VortaDBKeyring.
2024-11-05 10:49:55,915 - vorta.borg.jobs_manager - DEBUG - Add job for site 12
2024-11-05 10:49:55,916 - vorta.borg.jobs_manager - DEBUG - Start job on site: 12
2024-11-05 10:49:55,953 - vorta.borg.borg_job - INFO - Running command /usr/bin/borg create --list --progress --info --log-json --json --filter=AM -C lz4 --exclude-from /tmp/tmplhwgd1hs /media/user/Seagate_2TB_ext4/Linux_Home/Vorta/MX-23_Home_ohne_VMs,neue_Vorta_Version::mx-23-Xfce-2024-11-05-104955 /home/user
2024-11-05 10:49:56,448 - vorta.borg.borg_job - INFO - Creating archive at "/media/user/Seagate_2TB_ext4/Linux_Home/Vorta/MX-23_Home_ohne_VMs,neue_Vorta_Version::mx-23-Xfce-2024-11-05-104955"
2024-11-05 10:51:38,615 - vorta.scheduler - DEBUG - Scheduler for profile 10 is disabled.
2024-11-05 10:51:47,093 - vorta.borg.jobs_manager - DEBUG - Finish job for site: 12
2024-11-05 10:51:47,093 - vorta.borg.jobs_manager - DEBUG - No more jobs for site: 12
2024-11-05 10:53:53,957 - vorta.borg.borg_job - DEBUG - Cancel job on site default
2024-11-05 10:53:53,957 - vorta.borg.borg_job - DEBUG - Cancel job on site 12
2024-11-05 10:53:53,958 - vorta.borg.jobs_manager - INFO - Finished cancelling all jobs
2024-11-05 10:53:57,391 - vorta.i18n - DEBUG - Loading translation succeeded for ['de-Latn-CH', 'de-CH'].
2024-11-05 10:53:57,479 - vorta.views.source_tab - DEBUG - Added item number 0 from 1
2024-11-05 10:53:57,629 - root - INFO - Using NetworkManagerMonitor NetworkStatusMonitor implementation.
2024-11-05 10:53:57,684 - vorta.borg.jobs_manager - DEBUG - Add job for site default
2024-11-05 10:53:57,685 - vorta.borg.jobs_manager - DEBUG - Start job on site: default
2024-11-05 10:53:57,712 - vorta.borg.borg_job - INFO - Running command /usr/bin/borg --version
2024-11-05 10:53:58,069 - vorta.borg.jobs_manager - DEBUG - Finish job for site: default
2024-11-05 10:53:58,069 - vorta.scheduler - DEBUG - Refreshing all scheduler timers
2024-11-05 10:53:58,070 - vorta.borg.jobs_manager - DEBUG - No more jobs for site: default
2024-11-05 10:53:58,072 - vorta.scheduler - DEBUG - Scheduler for profile 2 is disabled.
2024-11-05 10:53:58,073 - vorta.scheduler - DEBUG - Scheduler for profile 3 is disabled.
2024-11-05 10:53:58,075 - vorta.scheduler - DEBUG - Scheduler for profile 4 is disabled.
2024-11-05 10:53:58,076 - vorta.scheduler - DEBUG - Scheduler for profile 5 is disabled.
2024-11-05 10:53:58,078 - vorta.scheduler - DEBUG - Scheduler for profile 6 is disabled.
2024-11-05 10:53:58,079 - vorta.scheduler - DEBUG - Scheduler for profile 7 is disabled.
2024-11-05 10:53:58,081 - vorta.scheduler - DEBUG - Scheduler for profile 9 is disabled.
2024-11-05 10:53:58,082 - vorta.scheduler - DEBUG - Scheduler for profile 10 is disabled.
2024-11-05 10:54:14,543 - vorta.keyring.abc - DEBUG - No module named 'objc'
2024-11-05 10:54:14,565 - asyncio - DEBUG - Using selector: EpollSelector
2024-11-05 10:54:14,565 - vorta.keyring.abc - DEBUG - Using VortaSecretStorageKeyring
2024-11-05 10:54:14,565 - vorta.borg.borg_job - DEBUG - Using VortaSecretStorageKeyring keyring to store passwords.
2024-11-05 10:54:14,566 - asyncio - DEBUG - Using selector: EpollSelector
2024-11-05 10:54:14,566 - vorta.keyring.secretstorage - DEBUG - Found 0 passwords matching repo URL.
2024-11-05 10:54:14,567 - vorta.borg.borg_job - DEBUG - Password not found in primary keyring. Falling back to VortaDBKeyring.
2024-11-05 10:54:15,667 - vorta.borg.jobs_manager - DEBUG - Add job for site 12
2024-11-05 10:54:15,668 - vorta.borg.jobs_manager - DEBUG - Start job on site: 12
2024-11-05 10:54:15,703 - vorta.borg.borg_job - INFO - Running command /usr/bin/borg delete --info --log-json /media/user/Seagate_2TB_ext4/Linux_Home/Vorta/MX-23_Home_ohne_VMs,neue_Vorta_Version::mx-23-Xfce-2024-11-05-104955
2024-11-05 10:54:25,697 - vorta.borg.jobs_manager - DEBUG - Finish job for site: 12
2024-11-05 10:54:25,698 - vorta.borg.jobs_manager - DEBUG - No more jobs for site: 12
2024-11-05 10:54:25,699 - vorta.scheduler - DEBUG - Scheduler for profile 10 is disabled.
2024-11-05 10:54:34,126 - vorta.keyring.abc - DEBUG - No module named 'objc'
2024-11-05 10:54:34,129 - asyncio - DEBUG - Using selector: EpollSelector
2024-11-05 10:54:34,130 - vorta.keyring.abc - DEBUG - Using VortaSecretStorageKeyring
2024-11-05 10:54:34,130 - vorta.borg.borg_job - DEBUG - Using VortaSecretStorageKeyring keyring to store passwords.
2024-11-05 10:54:34,131 - asyncio - DEBUG - Using selector: EpollSelector
2024-11-05 10:54:34,131 - vorta.keyring.secretstorage - DEBUG - Found 0 passwords matching repo URL.
2024-11-05 10:54:34,131 - vorta.borg.borg_job - DEBUG - Password not found in primary keyring. Falling back to VortaDBKeyring.
2024-11-05 10:54:34,137 - vorta.borg.jobs_manager - DEBUG - Add job for site 12
2024-11-05 10:54:34,137 - vorta.borg.jobs_manager - DEBUG - Start job on site: 12
2024-11-05 10:54:34,173 - vorta.borg.borg_job - INFO - Running command /usr/bin/borg create --list --progress --info --log-json --json --filter=AM -C lz4 --exclude-from /tmp/tmpkjgis7a5 /media/user/Seagate_2TB_ext4/Linux_Home/Vorta/MX-23_Home_ohne_VMs,neue_Vorta_Version::mx-23-Xfce-2024-11-05-105434 /home/user
2024-11-05 10:54:34,481 - vorta.borg.borg_job - INFO - Creating archive at "/media/user/Seagate_2TB_ext4/Linux_Home/Vorta/MX-23_Home_ohne_VMs,neue_Vorta_Version::mx-23-Xfce-2024-11-05-105434"
2024-11-05 10:56:15,113 - vorta.scheduler - DEBUG - Scheduler for profile 10 is disabled.
2024-11-05 10:56:35,598 - vorta.borg.jobs_manager - DEBUG - Finish job for site: 12
2024-11-05 10:56:35,598 - vorta.borg.jobs_manager - DEBUG - No more jobs for site: 12
Golddouble commented 1 week ago

Where you able to reproduce this? If this is not documented good enough: Please tell me what else you need.

mycir commented 1 week ago

I experienced the same issue. Fork your post-backup commands asynchronously, i.e. surround them with (...)&

The problem is that the create.py finished_event handler emits the application.py backup_finished_event before the post-backup commands are run. Consequently, the main_window.py backup_finished_event handler finds that jobs_manager.py is_worker_running() returns true, so the buttons are never toggled. (That's the worker running the post-backup commands.)

Alternatively, in the create.py finished_event handler, you could just move self.pre_post_backup_cmd(self.params, cmd='post_backup_cmd', returncode=result['returncode']) up to the top, so that the commands run before the signal is emitted. Of course this would be philosophically incorrect as yes, the backup itself has indeed finished.

Perhaps there should be a 'post_backup_cmd_finished' signal for main_window.py to handle before it toggles the buttons - probably not a good idea for them to be enabled whilst forked post_backup commands are still running things like fusermount -u, after a pre-backup google-drive-ocamlfuse. (One can imagine collisions if the same backup is started manually, by accident, within seconds.)

m3nu commented 1 week ago

Wanna add a PR for this, @mycir, since you already dissected the code it seems? If you think there is a right way to do it.

mycir commented 1 week ago

Sorry @m3nu but I can't take on the responsibility of a PR at the moment - too little time for coding, my partner gets cross. A few further thoughts though:

It has been said 'Qt signal is ten times slower than a virtual function'. Curious, I ran the same backup 3 times on my laptop, with the following results (time.perf_counter_ns() as ms):

(\<post-backup-commands>)& signal to slot (backup_finished_event)
5.226172ms 124.844042ms
6.031660ms 104.463295ms
4.336029ms 105.748938ms

So the chances of signal to slot beating async fork creation appear to be remote. Therefore, (\<post-backup-commands>)& seems to be a reasonable workaround for the time being. My feeling would be to leave a 'post_backup_cmd_finished' signal as a low priority ideal. Opens a small can of worms: Timeout for stalled PBCs? If so, whether it should be hard-wired or UI configureable? Whether to take on board Kill a Python subprocess and its children when a timeout is reached ?

Golddouble commented 6 days ago

As this command has worked in Version 0.7.6 I guess this is a regression.

Why not have a look at version 0.7.6 and see, why there was no issue in this version and after eliminate the regression?

mycir commented 4 days ago

@m3nu, throw a dog a bone...

Contrary to my previous opinion: Leave misbehaving or interminable pre/post backup commands for the user to sort out. But at least display the PID for them to investigate.

As is, GUI thread blocks when running lengthy pre/post backup commands. So I'm running calls to VortaApp.create_backup_action and VortaScheduler.create_backup in their own thread. I'm also of the opinion that the tray icon should show active whilst pre/post backup commands are running.

Code ready to go, so am happy to accept a PR.

PS @Golddouble, 0.7.6 fundamentally the same where the issue occurs. Guess code changes since affect event timings and you were just lucky.