Run missed backups runs before network is ready

[rzeigler]

Description

I've configured Vorta to Run missed backups on startup or wakeup.
Next, my computer goes to sleep.
On wake, Vorta immediately tries to run a backup which fails apparently because the network isn't up yet.

The log files contain the following, which looks like its trying to check on the network status and then failing. I have installed by Flatpak so I went and checked and borgbase does have talk for org.freedesktop.NetworkManager and I haven't made any changes to the default permissions.

Reproduction

• I tried to reproduce the issue.
• I was able to reproduce the issue.

OS

Fedora 41 (Plasma 6.2.3)

Version of Vorta

0.10.1

What did you install Vorta with?

Flatpak

Version of Borg

1.4.0

Logs

2024-11-14 09:38:52,700 - vorta.scheduler - DEBUG - Got login suspend/resume notification
2024-11-14 09:38:52,700 - vorta.scheduler - DEBUG - Refreshing all scheduler timers
2024-11-14 09:38:52,702 - vorta.scheduler - INFO - Setting timer for profile 1
2024-11-14 09:38:52,703 - vorta.scheduler - DEBUG - Catching up by running job for Default (1)
2024-11-14 09:38:52,704 - vorta.scheduler - INFO - Starting background backup for Default
2024-11-14 09:38:52,704 - vorta.notifications - DEBUG - success notifications suppressed
2024-11-14 09:38:52,705 - vorta.keyring.abc - DEBUG - No module named 'objc'
2024-11-14 09:38:52,707 - vorta.keyring.abc - DEBUG - Using VortaKWallet5Keyring
2024-11-14 09:38:52,707 - vorta.borg.borg_job - DEBUG - Using VortaKWallet5Keyring keyring to store passwords.
2024-11-14 09:38:52,710 - vorta.keyring.kwallet - DEBUG - Retrieved password for repo <snip borgbase repo>
2024-11-14 09:38:52,997 - vorta.network_status.network_manager - ERROR - Failed to get currently connected WiFi network, assuming none
Traceback (most recent call last):
  File "/app/lib/python3.11/site-packages/vorta/network_status/network_manager.py", line 35, in get_current_wifi
    active_connection = self._nm.get_active_connection_info(active_connection_path)
                        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/app/lib/python3.11/site-packages/vorta/network_status/network_manager.py", line 135, in get_active_connection_info
    connection=read_dbus_property(active_connection, 'Connection'),
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/app/lib/python3.11/site-packages/vorta/network_status/network_manager.py", line 162, in read_dbus_property
    return get_result(msg)
           ^^^^^^^^^^^^^^^
  File "/app/lib/python3.11/site-packages/vorta/network_status/network_manager.py", line 169, in get_result
    raise DBusException("DBus call failed: {}".format(msg.arguments()))
vorta.network_status.network_manager.DBusException: DBus call failed: ['Object does not exist at path “/”']
2024-11-14 09:38:53,015 - vorta.scheduler - INFO - Preparation for backup successful.
2024-11-14 09:38:53,015 - vorta.borg.jobs_manager - DEBUG - Add job for site 1
2024-11-14 09:38:53,016 - vorta.borg.jobs_manager - DEBUG - Start job on site: 1
2024-11-14 09:38:53,021 - vorta.borg.borg_job - INFO - Running command /app/bin/borg create --list --progress --info --log-json --json --filter=AM -C lz4 --exclude-if-present .nobackup --exclude-if-present CACHEDIR.TAG --exclude-from /tmp/tmpyda4vyoo <snip borgbase repo> /home/<snip username>
2024-11-14 09:38:53,164 - vorta.borg.borg_job - WARNING - Remote: ssh: Could not resolve hostname <snip borgbase host>: Temporary failure in name resolution
2024-11-14 09:38:53,165 - vorta.borg.borg_job - ERROR - Connection closed by remote host. Is borg working on the server?
2024-11-14 09:38:53,281 - vorta.borg.jobs_manager - DEBUG - Finish job for site: 1
2024-11-14 09:38:53,281 - vorta.borg.jobs_manager - DEBUG - No more jobs for site: 1
2024-11-14 09:38:53,282 - vorta.scheduler - INFO - Setting timer for profile 1
2024-11-14 09:38:53,282 - vorta.scheduler - DEBUG - Catching up by running job for Default (1)
2024-11-14 09:38:53,283 - vorta.scheduler - INFO - Starting background backup for Default
2024-11-14 09:38:53,283 - vorta.notifications - DEBUG - success notifications suppressed
2024-11-14 09:38:53,283 - vorta.keyring.abc - DEBUG - No module named 'objc'
2024-11-14 09:38:53,284 - vorta.keyring.abc - DEBUG - Using VortaKWallet5Keyring
2024-11-14 09:38:53,284 - vorta.borg.borg_job - DEBUG - Using VortaKWallet5Keyring keyring to store passwords.
2024-11-14 09:38:53,285 - vorta.keyring.kwallet - DEBUG - Retrieved password for repo <snip borgbase repo>
2024-11-14 09:38:53,286 - vorta.network_status.network_manager - ERROR - Failed to get currently connected WiFi network, assuming none
Traceback (most recent call last):
  File "/app/lib/python3.11/site-packages/vorta/network_status/network_manager.py", line 35, in get_current_wifi
    active_connection = self._nm.get_active_connection_info(active_connection_path)
                        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/app/lib/python3.11/site-packages/vorta/network_status/network_manager.py", line 135, in get_active_connection_info
    connection=read_dbus_property(active_connection, 'Connection'),
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/app/lib/python3.11/site-packages/vorta/network_status/network_manager.py", line 162, in read_dbus_property
    return get_result(msg)
           ^^^^^^^^^^^^^^^
  File "/app/lib/python3.11/site-packages/vorta/network_status/network_manager.py", line 169, in get_result
    raise DBusException("DBus call failed: {}".format(msg.arguments()))
vorta.network_status.network_manager.DBusException: DBus call failed: ['Object does not exist at path “/”']
2024-11-14 09:38:53,289 - vorta.scheduler - INFO - Preparation for backup successful.
2024-11-14 09:38:53,289 - vorta.borg.jobs_manager - DEBUG - Add job for site 1
2024-11-14 09:38:53,289 - vorta.borg.jobs_manager - DEBUG - Start job on site: 1
2024-11-14 09:38:53,292 - vorta.borg.borg_job - INFO - Running command /app/bin/borg create --list --progress --info --log-json --json --filter=AM -C lz4 --exclude-if-present .nobackup --exclude-if-present CACHEDIR.TAG --exclude-from /tmp/tmpxaxthly5 <snip borgbase repo>  /home/<snip username>
2024-11-14 09:38:53,309 - vorta.notifications - DEBUG - notification not suppressed
2024-11-14 09:38:53,310 - vorta.scheduler - ERROR - Error during backup creation.

[goebbe]

This issue also came up recently in the github Discussions, see:#2114
When Vorta tries to catch up missed backups - directly after coming back from sleep, the network (Wifi) is often not (yet) available, since it can take some seconds to reconnect to the network.

The code for schedule_make_up_missed backups is in
/vorta/scheduler.py line 294-304

            if next_time <= dt.now():
                if profile.schedule_make_up_missed:
                    self.lock.release()
                    try:
                        logger.debug(
                            'Catching up by running job for %s (%s)',
                            profile.name,
                            profile_id,
                        )
                        self.create_backup(profile_id)

@real-yfprojects Is it possible to just add a small delay before creating the make_up_missed backup?
E.g. by adding time.sleep(5) ?

[rzeigler]

@goebbe since you suggested the change above, I was wondering if you have any thoughts on the approach I took in the PR.

[goebbe]

@rzeigler Thank you for looking into this!
Sorry, since I don't have enough experience/ skills - I am not able to review this pull request.
Perhaps @ktosiek or @m3nu find the time to review/ comment on pull request #2176 ?

[goebbe]

This is a duplicate of #1815.