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

Borg version is detected too late #2129

Open biochemie opened 1 week ago

biochemie commented 1 week ago

Description

Updating from 0.9.1 to 0.10.0 (via pacman or yay) results in Vorta reporting that borg lacks Zstd compression support. Reverting to 0.9.1 reverts the issue and does not present an error. The version of borg was unchanged between the two versions of Vorta.

Reproduction

OS

EndeavourOS, kernel 6.11.6, Xfce 4.18

Version of Vorta

0.10.0

What did you install Vorta with?

Other

Version of Borg

1.4.0

Logs

[Vorta 0.10.0-1]
2024-11-11 14:04:52,716 - vorta.i18n - DEBUG - Loading translation failed for ['en-Latn-CA', 'en-CA'].
2024-11-11 14:04:52,752 - root - DEBUG - Not a private SSH key file: authorized_keys
2024-11-11 14:04:52,778 - vorta.views.source_tab - DEBUG - Added item number 0 from 1
2024-11-11 14:04:52,971 - root - INFO - Using NetworkManagerMonitor NetworkStatusMonitor implementation.
2024-11-11 14:04:52,980 - vorta.scheduler - INFO - Setting timer for profile 1
2024-11-11 14:04:52,981 - vorta.scheduler - DEBUG - Catching up by running job for Default (1)
2024-11-11 14:04:52,982 - vorta.scheduler - INFO - Starting background backup for Default
2024-11-11 14:04:52,982 - vorta.notifications - DEBUG - success notifications suppressed
2024-11-11 14:04:52,984 - vorta.keyring.abc - DEBUG - No module named 'objc'
2024-11-11 14:04:53,004 - asyncio - DEBUG - Using selector: EpollSelector
2024-11-11 14:04:53,004 - vorta.keyring.abc - DEBUG - Using VortaSecretStorageKeyring
2024-11-11 14:04:53,004 - vorta.borg.borg_job - DEBUG - Using VortaSecretStorageKeyring keyring to store passwords.
2024-11-11 14:04:53,005 - asyncio - DEBUG - Using selector: EpollSelector
2024-11-11 14:04:53,006 - vorta.keyring.secretstorage - DEBUG - Found 1 passwords matching repo URL.
2024-11-11 14:04:53,006 - vorta.keyring.secretstorage - DEBUG - Retrieved password for repo /run/media/$USER/borg/$REPO.borg
2024-11-11 14:04:53,037 - vorta.scheduler - ERROR - Conditions for backup not met. Aborting.
2024-11-11 14:04:53,037 - vorta.scheduler - ERROR - Your current Borg version does not support ZStd compression.
2024-11-11 14:04:53,037 - vorta.notifications - DEBUG - notification not suppressed
2024-11-11 14:04:53,042 - vorta.scheduler - DEBUG - Paused 1 until 2024-11-11 15:04:53
2024-11-11 14:04:53,045 - vorta.scheduler - DEBUG - Nothing scheduled for profile 1 because of timeout until 2024-11-11 15:04:53.
2024-11-11 14:04:53,047 - vorta.scheduler - DEBUG - Nothing scheduled for profile 1 because of timeout until 2024-11-11 15:04:53.
2024-11-11 14:04:53,064 - vorta.borg.jobs_manager - DEBUG - Add job for site default
2024-11-11 14:04:53,065 - vorta.borg.jobs_manager - DEBUG - Start job on site: default
2024-11-11 14:04:53,066 - vorta.borg.borg_job - INFO - Running command /usr/bin/borg --version
2024-11-11 14:04:53,387 - vorta.borg.jobs_manager - DEBUG - Finish job for site: default
2024-11-11 14:04:53,387 - vorta.borg.jobs_manager - DEBUG - No more jobs for site: default
2024-11-11 14:04:53,388 - vorta.scheduler - DEBUG - Refreshing all scheduler timers
2024-11-11 14:04:53,389 - vorta.scheduler - DEBUG - Nothing scheduled for profile 1 because of timeout until 2024-11-11 15:04:53.
2024-11-11 14:07:08,527 - vorta.borg.borg_job - DEBUG - Cancel job on site default
2024-11-11 14:07:08,527 - vorta.borg.jobs_manager - INFO - Finished cancelling all jobs

[Vorta 0.9.1-5]
2024-11-11 14:11:08,483 - vorta.i18n - DEBUG - Loading translation failed for ['en-Latn-CA', 'en-CA'].
2024-11-11 14:11:08,520 - root - DEBUG - Not a private SSH key file: authorized_keys
2024-11-11 14:11:08,546 - vorta.views.source_tab - DEBUG - Added item number 0 from 1
2024-11-11 14:11:08,727 - root - INFO - Using NetworkManagerMonitor NetworkStatusMonitor implementation.
2024-11-11 14:11:08,755 - vorta.borg.jobs_manager - DEBUG - Add job for site default
2024-11-11 14:11:08,756 - vorta.borg.jobs_manager - DEBUG - Start job on site: default
2024-11-11 14:11:08,757 - vorta.borg.borg_job - INFO - Running command /usr/bin/borg --version
2024-11-11 14:11:09,078 - vorta.borg.jobs_manager - DEBUG - Finish job for site: default
2024-11-11 14:11:09,078 - vorta.scheduler - DEBUG - Refreshing all scheduler timers
2024-11-11 14:11:09,078 - vorta.borg.jobs_manager - DEBUG - No more jobs for site: default
2024-11-11 14:11:09,080 - vorta.scheduler - INFO - Setting timer for profile 1
2024-11-11 14:11:09,081 - vorta.scheduler - DEBUG - Catching up by running job for Default (1)
2024-11-11 14:11:09,082 - vorta.scheduler - INFO - Starting background backup for Default
2024-11-11 14:11:09,082 - vorta.notifications - DEBUG - success notifications suppressed
2024-11-11 14:11:09,084 - vorta.keyring.abc - DEBUG - No module named 'objc'
2024-11-11 14:11:09,104 - asyncio - DEBUG - Using selector: EpollSelector
2024-11-11 14:11:09,104 - vorta.keyring.abc - DEBUG - Using VortaSecretStorageKeyring
2024-11-11 14:11:09,104 - vorta.borg.borg_job - DEBUG - Using VortaSecretStorageKeyring keyring to store passwords.
2024-11-11 14:11:09,105 - asyncio - DEBUG - Using selector: EpollSelector
2024-11-11 14:11:09,106 - vorta.keyring.secretstorage - DEBUG - Found 1 passwords matching repo URL.
2024-11-11 14:11:09,106 - vorta.keyring.secretstorage - DEBUG - Retrieved password for repo /run/media/$USER/borg/$REPO.borg
2024-11-11 14:11:09,145 - vorta.scheduler - INFO - Preparation for backup successful.
2024-11-11 14:11:09,145 - vorta.borg.jobs_manager - DEBUG - Add job for site 1
2024-11-11 14:11:09,145 - vorta.borg.jobs_manager - DEBUG - Start job on site: 1
m3nu commented 1 week ago

Sounds like your Borg version isn't detected properly. What version do you see in About > About > Borg version?

biochemie commented 1 week ago

Both versions of Vorta report the same information re: borg vorta_0 10 0 vorta_0 9 1 EDIT: I did not receive the complaint about lack of Zstd support this time, oddly (as I needed to upgrade once again to get the capture). First upgrade to 0.10.0 prompted it. Second upgrade to 0.10.0 after rolling back to 0.9.1 also prompted it (both of which were in the log attached above). This third upgrade did not, and the console/log reflects that (no error line as above).

So I am unclear as to what was different this time (I've only upgraded/downgraded Vorta and no other packages in between).

biochemie commented 1 week ago

Ok. Startup of the machine throwing this error found Vorta reporting the error again.

2024-11-12 15:21:59,342 - vorta.i18n - DEBUG - Loading translation failed for ['en-Latn-CA', 'en-CA'].
2024-11-12 15:21:59,408 - root - DEBUG - Not a private SSH key file: authorized_keys
2024-11-12 15:21:59,436 - vorta.views.source_tab - DEBUG - Added item number 0 from 1
2024-11-12 15:21:59,768 - vorta.application - INFO - An instance of Vorta is already running. Opening main window.
2024-11-12 15:21:59,783 - root - INFO - Using NetworkManagerMonitor NetworkStatusMonitor implementation.
2024-11-12 15:21:59,793 - vorta.scheduler - INFO - Setting timer for profile 1
2024-11-12 15:21:59,794 - vorta.scheduler - DEBUG - Catching up by running job for Default (1)
2024-11-12 15:21:59,795 - vorta.scheduler - INFO - Starting background backup for Default
2024-11-12 15:21:59,795 - vorta.notifications - DEBUG - success notifications suppressed
2024-11-12 15:21:59,798 - vorta.keyring.abc - DEBUG - No module named 'objc'
2024-11-12 15:21:59,837 - asyncio - DEBUG - Using selector: EpollSelector
2024-11-12 15:21:59,838 - vorta.keyring.abc - DEBUG - Using VortaSecretStorageKeyring
2024-11-12 15:21:59,838 - vorta.borg.borg_job - DEBUG - Using VortaSecretStorageKeyring keyring to store passwords.
2024-11-12 15:21:59,838 - asyncio - DEBUG - Using selector: EpollSelector
2024-11-12 15:21:59,839 - vorta.keyring.secretstorage - DEBUG - Found 1 passwords matching repo URL.
2024-11-12 15:21:59,840 - vorta.keyring.secretstorage - DEBUG - Retrieved password for repo /run/media/$USER/borg/$REPO}.borg
2024-11-12 15:22:00,395 - vorta.scheduler - ERROR - Conditions for backup not met. Aborting.
2024-11-12 15:22:00,395 - vorta.scheduler - ERROR - Your current Borg version does not support ZStd compression.
2024-11-12 15:22:00,395 - vorta.notifications - DEBUG - notification not suppressed
2024-11-12 15:22:00,402 - vorta.scheduler - DEBUG - Paused 1 until 2024-11-12 16:22:00
2024-11-12 15:22:00,405 - vorta.scheduler - DEBUG - Nothing scheduled for profile 1 because of timeout until 2024-11-12 16:22:00.
2024-11-12 15:22:00,408 - vorta.scheduler - DEBUG - Nothing scheduled for profile 1 because of timeout until 2024-11-12 16:22:00.
2024-11-12 15:22:00,429 - vorta.borg.jobs_manager - DEBUG - Add job for site default
2024-11-12 15:22:00,429 - vorta.borg.jobs_manager - DEBUG - Start job on site: default
2024-11-12 15:22:00,430 - vorta.borg.borg_job - INFO - Running command /usr/bin/borg --version
2024-11-12 15:22:00,836 - vorta.borg.jobs_manager - DEBUG - Finish job for site: default
2024-11-12 15:22:00,836 - vorta.scheduler - DEBUG - Refreshing all scheduler timers
2024-11-12 15:22:00,836 - vorta.borg.jobs_manager - DEBUG - No more jobs for site: default
2024-11-12 15:22:00,837 - vorta.scheduler - DEBUG - Nothing scheduled for profile 1 because of timeout until 2024-11-12 16:22:00.
2024-11-12 15:22:38,634 - vorta.borg.borg_job - DEBUG - Cancel job on site default
2024-11-12 15:22:38,634 - vorta.borg.jobs_manager - INFO - Finished cancelling all jobs

I booted up initially into the zen kernel (log above), so switched back to the main kernel (log below) to confirm it wasn't kernel related.

2024-11-12 15:23:22,714 - vorta.i18n - DEBUG - Loading translation failed for ['en-Latn-CA', 'en-CA'].
2024-11-12 15:23:22,804 - root - DEBUG - Not a private SSH key file: authorized_keys
2024-11-12 15:23:22,844 - vorta.views.source_tab - DEBUG - Added item number 0 from 1
2024-11-12 15:23:23,163 - vorta.application - INFO - An instance of Vorta is already running. Opening main window.
2024-11-12 15:23:23,239 - root - INFO - Using NetworkManagerMonitor NetworkStatusMonitor implementation.
2024-11-12 15:23:23,252 - vorta.scheduler - INFO - Setting timer for profile 1
2024-11-12 15:23:23,253 - vorta.scheduler - DEBUG - Catching up by running job for Default (1)
2024-11-12 15:23:23,254 - vorta.scheduler - INFO - Starting background backup for Default
2024-11-12 15:23:23,254 - vorta.notifications - DEBUG - success notifications suppressed
2024-11-12 15:23:23,257 - vorta.keyring.abc - DEBUG - No module named 'objc'
2024-11-12 15:23:23,303 - asyncio - DEBUG - Using selector: EpollSelector
2024-11-12 15:23:23,304 - vorta.keyring.abc - DEBUG - Using VortaSecretStorageKeyring
2024-11-12 15:23:23,304 - vorta.borg.borg_job - DEBUG - Using VortaSecretStorageKeyring keyring to store passwords.
2024-11-12 15:23:23,305 - asyncio - DEBUG - Using selector: EpollSelector
2024-11-12 15:23:23,307 - vorta.keyring.secretstorage - DEBUG - Found 1 passwords matching repo URL.
2024-11-12 15:23:23,308 - vorta.keyring.secretstorage - DEBUG - Retrieved password for repo /run/media/$USER/borg/$REPO.borg
2024-11-12 15:23:23,361 - vorta.scheduler - ERROR - Conditions for backup not met. Aborting.
2024-11-12 15:23:23,361 - vorta.scheduler - ERROR - Your current Borg version does not support ZStd compression.
2024-11-12 15:23:23,361 - vorta.notifications - DEBUG - notification not suppressed
2024-11-12 15:23:23,433 - vorta.scheduler - DEBUG - Paused 1 until 2024-11-12 16:23:23
2024-11-12 15:23:23,437 - vorta.scheduler - DEBUG - Nothing scheduled for profile 1 because of timeout until 2024-11-12 16:23:23.
2024-11-12 15:23:23,440 - vorta.scheduler - DEBUG - Nothing scheduled for profile 1 because of timeout until 2024-11-12 16:23:23.
2024-11-12 15:23:23,466 - vorta.borg.jobs_manager - DEBUG - Add job for site default
2024-11-12 15:23:23,466 - vorta.borg.jobs_manager - DEBUG - Start job on site: default
2024-11-12 15:23:23,467 - vorta.borg.borg_job - INFO - Running command /usr/bin/borg --version
2024-11-12 15:23:23,926 - vorta.borg.jobs_manager - DEBUG - Finish job for site: default
2024-11-12 15:23:23,926 - vorta.scheduler - DEBUG - Refreshing all scheduler timers
2024-11-12 15:23:23,926 - vorta.borg.jobs_manager - DEBUG - No more jobs for site: default
2024-11-12 15:23:23,928 - vorta.scheduler - DEBUG - Nothing scheduled for profile 1 because of timeout until 2024-11-12 16:23:23

Vorta client is correctly reporting Vorta and borg versions here in the screen capture: image …I guess it isn't quite resolved?

m3nu commented 1 week ago

Looks like the version check happens AFTER your backup run. Usually the version check happens on startup.

So solution is to ensure scheduled backups only happen after the version was already detected. This issue will only happen if you have automatic jobs to run right after startup.