borgbase / vorta

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

Switching between profiles takes very long #1962

Open daPhipz opened 7 months ago

daPhipz commented 7 months ago

Description

I have two profiles. The first one backs up really critical stuff to my BorgBase remote repo, the second one backs up my entire home directory to a NAS in my home network. Switching between those profiles takes a long time - about 25 seconds. During that time, the program window is unresponsive, Kubuntu greys out the window and says that Vorta "does not react" and offers me to kill the process.

Unfortunately, I can't pinpoint the exact version of Vorta where this issue occurred the first time. I believe it was introduced when the profiles were moved to the left side of the window, but I might be wrong.

Here is a screencast to show how long it takes (Repo location blurred out, of course): https://youtu.be/xVuywsOY4Go?si=yousLqS0vgW8sPF7

Reproduction

OS

Kubuntu 23.10

Version of Vorta

0.9.1

What did you install Vorta with?

Flatpak

Version of Borg

1.2.4

Logs

###### First, I do a manual backup to have a timestamp. (File paths are redacted for privacy reasons, the backup worked as expected)
2024-03-10 19:46:14,443 - vorta.keyring.abc - DEBUG - No module named 'objc'
2024-03-10 19:46:14,446 - vorta.keyring.abc - DEBUG - Using VortaKWallet5Keyring
2024-03-10 19:46:14,447 - vorta.borg.borg_job - DEBUG - Using VortaKWallet5Keyring keyring to store passwords.
2024-03-10 19:46:14,456 - vorta.keyring.kwallet - DEBUG - Retrieved password for repo ssh://user@server/path/to/repo
2024-03-10 19:46:14,689 - vorta.borg.jobs_manager - DEBUG - Add job for site 4
2024-03-10 19:46:14,690 - vorta.borg.jobs_manager - DEBUG - Start job on site: 4
2024-03-10 19:46:14,794 - vorta.borg.borg_job - INFO - Running command /app/bin/borg create --remote-path=/usr/local/bin/borg --list --progress --info --log-json --json --filter=AM -C lz4 --exclude-from /tmp/tmp3o0wty6i ssh://user@server/path/to/repo::archive-name /data/to/back/up
2024-03-10 19:46:16,367 - vorta.borg.borg_job - INFO - Creating archive at "ssh://user@server/path/to/repo::archive-name /data/to/back/up"
2024-03-10 19:47:10,242 - vorta.scheduler - INFO - Setting timer for profile 1
2024-03-10 19:47:10,259 - vorta.scheduler - DEBUG - Scheduling next run for 2024-03-10 20:26:31.443721
2024-03-10 19:47:10,351 - vorta.borg.jobs_manager - DEBUG - Finish job for site: 4
2024-03-10 19:47:10,351 - vorta.borg.jobs_manager - DEBUG - No more jobs for site: 4
###### Backup has finished w/o problems, right after that I clicked on another profile.
2024-03-10 19:47:39,923 - vorta.views.source_tab - DEBUG - Added item number 0 from 1
2024-03-10 19:47:39,924 - vorta.views.source_tab - DEBUG - Added item number 1 from 2
2024-03-10 19:47:39,925 - vorta.views.source_tab - DEBUG - Added item number 2 from 3
2024-03-10 19:47:39,925 - vorta.views.source_tab - DEBUG - Added item number 3 from 4
2024-03-10 19:47:39,926 - vorta.views.source_tab - DEBUG - Added item number 4 from 5
2024-03-10 19:47:39,926 - vorta.views.source_tab - DEBUG - Added item number 5 from 6
2024-03-10 19:47:39,926 - vorta.views.source_tab - DEBUG - Added item number 6 from 7
2024-03-10 19:47:39,927 - vorta.views.source_tab - DEBUG - Added item number 7 from 8
2024-03-10 19:47:39,927 - vorta.views.source_tab - DEBUG - Added item number 8 from 9
2024-03-10 19:47:39,928 - vorta.views.source_tab - DEBUG - Added item number 9 from 10
###### Only now, the profile was actually switched, and I could interact with Vorta again.
m3nu commented 7 months ago

This is extremely slow in your case. I also noticed a delay after recent updates, but it's only 1-2s.

It will re-populate the info in all the tabs on profile change. I guess one of those is a bit slow with too much data. (many logs or archives?)

daPhipz commented 7 months ago

many logs or archives?

The BorgBase repo has ~86~ 14 archives and a total amount of ~8.07~ 7.92 GB actual data on disk (deduped). The NAS backup (Sophos) has 34 archives and a total amount of 1 TB actual data on disk (deduped).

I just noticed that the remote backup did not prune properly for some time now, I edited the numbers above accordingly. The video was recorded with 86 archives in the BorgBase repo.

Switching from Sophos to BorgBase is now considerably faster (about 6 seconds, which I find acceptable). The other way around (BorgBase to Sophos) takes about the same time.

What seems strange to me, however: The visible GUI changes instantly, but you cannot interact with it. For example, I have the "Archives" tab open and click on another profile. I can instantly see (a maybe cached/outdated??) archive list of the profile I switched to, but cannot interact with Vorta at all during the (now 6 second) load time. As a DAU (aka "stupidest user one can think of", as we say in Germany :wink: ), I'd assume once something is displayed, I should be able to interact with it.

Personally, I don’t mind these 6 seconds, but it might be a symptom of a bigger problem/opportunity for improvement, so feel free to close this issue or leave it open. I don't know anything about Vorta code, so I leave this decision up to you :wink:

The specs of my PC as per KDE's system settings:

Operating System: Kubuntu 23.10 KDE Plasma Version: 5.27.8 KDE Frameworks Version: 5.110.0 Qt Version: 5.15.10 Kernel Version: 6.5.0-25-generic (64-bit) Graphics Platform: X11 Processors: 8 × Intel® Core™ i7-6700K CPU @ 4.00GHz Memory: 15.6 GiB of RAM Graphics Processor: NVIDIA GeForce GTX 970/PCIe/SSE2 Manufacturer: Gigabyte Technology Co., Ltd. Product Name: Z170-Gaming K3

daPhipz commented 7 months ago

Switching from Sophos to BorgBase is now considerably faster (about 6 seconds, which I find acceptable). The other way around (BorgBase to Sophos) takes about the same time.

Actually, the time is not always the same: It still goes up to 20-30 seconds sometimes. I tested it multiple times now and got varying results, all under the same background load (8 open tabs in Firefox, Dolphin, Kate and KDE system settings open). I can't spot anything unusual in the logs when switching profiles, only the Added item number X from Y statements as seen above.

Output of free -h at this time:

               total        used        free      shared  buff/cache   available
Mem:            15Gi       4,0Gi       6,0Gi       128Mi       6,0Gi        11Gi
m3nu commented 7 months ago

Will do some debugging later to see if there are some easy wins to be made.

m3nu commented 7 months ago

Found the following:

Wifi and Archive list both use the same widget. Maybe there is a better way to insert items into it. Still looking into that and will push a PR after.

m3nu commented 7 months ago

Couldn't get the Wifi list faster with batch inserting or updating existing items only. So the only way is to use a worker thread for the list. We already do this for folder stats (FilePathInfoAsync).

m3nu commented 7 months ago

I'm close to fixing this by moving the Wifi- and mount processing to separate threads. After this, the GUI updates aren't as blocking: https://github.com/borgbase/vorta/pull/1964#issuecomment-2002067537

github-actions[bot] commented 4 months ago

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.

github-actions[bot] commented 4 months ago

This issue was closed because it has been stalled for 7 days with no activity.

daPhipz commented 4 months ago

@m3nu is this still WIP or really not planned? For me personally, the issue persists. Not as bad as in the video, but I guess it scales with the amount of archives in the repos.

m3nu commented 4 months ago

I spent a day coding the solution, but didn't manage to fix the tests. If you want to test and look at the tests, we could merge it pretty quickly.

https://github.com/borgbase/vorta/pull/1964