Slow download speed Windows Duplicati

Andrey_SFTDI · November 27, 2023, 1:15pm

Good day, please advise what could be the issue. Every week, or even more frequently, there is a situation where the backup loading speed becomes 76 kilobytes. All the data is stored on a share. I have checked the speed locally on the share, and it is 200 megabits for both uploading and downloading. What could be causing this?
Screenshot_1

ts678 · November 27, 2023, 2:13pm

Welcome to the forum @Andrey_SFTDI

Topic title mentions “download speed”. Perhaps you meant “upload speed”?

It could be completely normal, as Duplicati only uploads changed data, and only starts showing speed after the first upload is done. After that, the question is how long it will be before a next remote volume.

How the backup process works shows how uploads happen when a volume is full, thus ready to store.

A simple approach is to watch the home screen to see if the backup is reading through files constantly. Even if a file is read, there might be little to no change, but no reads means no data, and no uploading, meaning the upload speed will slowly decline until another upload happens, because speed is average.

You could also look at your remote share and try to see if a file grows slowly or appears all of a sudden.

You could also watch Duplicati About → Show log → Live → Information to study the uploading timings.

There are several more complex methods, such as using Profiling information, or About → System info. Those are probably better saved for later, if we find out that it’s not just due to having nothing to upload.

Andrey_SFTDI · November 27, 2023, 4:00pm

I understand you, I will monitor the situation, gather information, and get back to you.

Andrey_SFTDI · December 6, 2023, 6:35am

Look, I have collected a small amount of data. Since the loading takes a long time and there is a lot of information in the system-info, I have roughly highlighted the following.

Dec 3, 2023 3:54 AM: Backend event: Put - Completed: duplicati-b0bea2851ee6648e586cf76a4f202942b.dblock.zip.aes (99,97 MB)
Dec 3, 2023 5:21 AM: Renaming “duplicati-bedd0206721b5484e9977286d9d0c17d1.dblock.zip.aes” to “duplicati-b902fc833633149af93329767be199c47.dblock.zip.aes”

At that moment, the loading became very slow, and in order to check, I switched to duplicates. Then, the information started from the following day.

Dec 4, 2023 2:50 PM: Compacting because there are 665 fully deletable volume(s)

Dec 4, 2023 3:01 PM: The operation Backup has completed

Last successful backup:Today at 3:00 PM (took 1 day(s) and 15:22:58)Run now
Next scheduled run:Today at 11:00 PM
Source:64,93 GB
Backup:1,43 TB / 46 Versions

After it loaded for 1 day and 15 hours, it ran the task again, and then it completed in (03:32:34)

gpatel-fr · December 6, 2023, 7:49am

This is an indication of a backend problem - an upload has failed. Usually the cause is network connection hiccup. It may be a driver reliability issue or the backend itself that is flaky, or even the Dns.
Having to do retries has most often a huge impact on performance. Since you did not give any information about your backend, it’s not possible to even speculate.
Edit: well, you wrote about a ‘share’, so scratch that. However, a share can mean several things. It could even mean an emulated drive on a cloud provider (often not a very reliable setup).

I’m afraid that you are not clear here.

This is not a fast operation. If you routinely insert / delete large amounts of data, this can’t be done quickly for a system that is doing compaction to try to manage space efficiently.

Andrey_SFTDI · December 6, 2023, 11:46am

Please tell me what data needs to be collected to understand what the problem is?

Andrey_SFTDI · December 28, 2023, 8:46am

Look, I encountered an issue with duplicate monitoring and the backup not being performed. I accessed it through the web interface, and as you can see in the screenshot, it stopped on December 26th based on the live logging. As soon as I selected it, it resumed writing logs. Currently, the download speed is 127 kilobytes.

duplicati monit FD1017×59 7.6 KB

Запуск fd.retail1402×697 13.4 KB

Info -

Dec 28, 2023 11:45 AM: Backend event: Put - Started: duplicati-b07bd07d515c944f8b71fb2c5b1273d10.dblock.zip.aes (99,96 MB)
Dec 28, 2023 11:45 AM: Backend event: Put - Completed: duplicati-ibd94dc552313481e94940182921a88c4.dindex.zip.aes (135,40 KB)
Dec 28, 2023 11:45 AM: Backend event: Put - Started: duplicati-ibd94dc552313481e94940182921a88c4.dindex.zip.aes (135,40 KB)
Dec 28, 2023 11:45 AM: Backend event: Put - Completed: duplicati-b0062a666df344928988309f9fc17db76.dblock.zip.aes (99,94 MB)
Dec 28, 2023 11:45 AM: Backend event: Put - Started: duplicati-bb1c6d6ec3ca949e78b05afaa5a832a0d.dblock.zip.aes (99,93 MB)
Dec 28, 2023 11:45 AM: Backend event: Put - Completed: duplicati-ia78e478bf8c64b8082a0932a992218c3.dindex.zip.aes (35,20 KB)
Dec 28, 2023 11:45 AM: Backend event: Put - Started: duplicati-ia78e478bf8c64b8082a0932a992218c3.dindex.zip.aes (35,20 KB)
Dec 28, 2023 11:45 AM: Backend event: Put - Completed: duplicati-b13107b3bf9194e36bcc9e6c06e57e8ee.dblock.zip.aes (99,95 MB)
Dec 28, 2023 11:45 AM: Backend event: Put - Started: duplicati-b81adf791f7e44a9289a237877d8dd8d2.dblock.zip.aes (99,95 MB)
Dec 28, 2023 11:45 AM: Backend event: Put - Completed: duplicati-i0c33ba1b42df46afa25bf3870b0944e6.dindex.zip.aes (35,20 KB)
Dec 28, 2023 11:45 AM: Backend event: Put - Started: duplicati-i0c33ba1b42df46afa25bf3870b0944e6.dindex.zip.aes (35,20 KB)
Dec 28, 2023 11:45 AM: Backend event: Put - Completed: duplicati-b969eaca6182d436cbf07e578d734203a.dblock.zip.aes (99,94 MB)
Dec 28, 2023 11:44 AM: Backend event: Put - Started: duplicati-b13107b3bf9194e36bcc9e6c06e57e8ee.dblock.zip.aes (99,95 MB)
Dec 28, 2023 11:44 AM: Backend event: Put - Completed: duplicati-i192ef3b707f94ea8bf690b8d2613544a.dindex.zip.aes (35,18 KB)
Dec 28, 2023 11:44 AM: Backend event: Put - Started: duplicati-i192ef3b707f94ea8bf690b8d2613544a.dindex.zip.aes (35,18 KB)
Dec 28, 2023 11:44 AM: Backend event: Put - Completed: duplicati-baef3d0b6c2ba485cad6c723fa37b6603.dblock.zip.aes (99,88 MB)
Dec 28, 2023 11:44 AM: Backend event: Put - Started: duplicati-b23fc5b04c5cc40fd9e84b4c43d0a2bfe.dblock.zip.aes (99,88 MB)
Dec 28, 2023 11:44 AM: Backend event: Put - Completed: duplicati-i809cdd998af245989de53616f1dbd3a0.dindex.zip.aes (35,18 KB)
Dec 28, 2023 11:44 AM: Backend event: Put - Started: duplicati-i809cdd998af245989de53616f1dbd3a0.dindex.zip.aes (35,18 KB)
Dec 28, 2023 11:44 AM: Backend event: Put - Completed: duplicati-b76d099ca2b284e3ea9aace78858a5d6a.dblock.zip.aes (99,89 MB)
Dec 28, 2023 11:43 AM: Backend event: Put - Started: duplicati-b969eaca6182d436cbf07e578d734203a.dblock.zip.aes (99,94 MB)
Dec 28, 2023 11:43 AM: Backend event: Put - Completed: duplicati-i8ce0f781e6b14cdf85deafffac0ef616.dindex.zip.aes (135,43 KB)
Dec 28, 2023 11:43 AM: Backend event: Put - Started: duplicati-i8ce0f781e6b14cdf85deafffac0ef616.dindex.zip.aes (135,43 KB)
Dec 28, 2023 11:43 AM: Backend event: Put - Completed: duplicati-bd97d1b520e954e1c86bdf49ac2257e90.dblock.zip.aes (99,87 MB)
Dec 28, 2023 11:43 AM: Backend event: Put - Started: duplicati-b0062a666df344928988309f9fc17db76.dblock.zip.aes (99,94 MB)
Dec 28, 2023 11:43 AM: Backend event: Put - Completed: duplicati-i1066a28fad754ea2a743ba5f46224ca1.dindex.zip.aes (35,20 KB)
Dec 28, 2023 11:43 AM: Backend event: Put - Started: duplicati-i1066a28fad754ea2a743ba5f46224ca1.dindex.zip.aes (35,20 KB)
Dec 28, 2023 11:43 AM: Backend event: Put - Completed: duplicati-b8b13ab270be7408589b05bbf31bbdbb4.dblock.zip.aes (99,89 MB)
Dec 28, 2023 11:42 AM: Backend event: Put - Started: duplicati-baef3d0b6c2ba485cad6c723fa37b6603.dblock.zip.aes (99,88 MB)
Dec 28, 2023 11:42 AM: Backend event: Put - Completed: duplicati-iaa46bc086e074ef3a58f98834e298761.dindex.zip.aes (135,39 KB)
Dec 28, 2023 11:42 AM: Backend event: Put - Started: duplicati-iaa46bc086e074ef3a58f98834e298761.dindex.zip.aes (135,39 KB)
Dec 28, 2023 11:42 AM: Backend event: Put - Completed: duplicati-b0a8bb5e827d247bf93bba926124b9210.dblock.zip.aes (99,90 MB)
Dec 28, 2023 11:42 AM: Backend event: Put - Started: duplicati-b76d099ca2b284e3ea9aace78858a5d6a.dblock.zip.aes (99,89 MB)
Dec 28, 2023 11:42 AM: Backend event: Put - Completed: duplicati-ie4877365321c407c88121d2453356486.dindex.zip.aes (35,23 KB)
Dec 28, 2023 11:42 AM: Backend event: Put - Started: duplicati-ie4877365321c407c88121d2453356486.dindex.zip.aes (35,23 KB)
Dec 28, 2023 11:42 AM: Backend event: Put - Completed: duplicati-b813ec20e40ac42339535e4308f31b068.dblock.zip.aes (99,87 MB)
Dec 28, 2023 11:41 AM: Backend event: Put - Started: duplicati-b0a8bb5e827d247bf93bba926124b9210.dblock.zip.aes (99,90 MB)
Dec 28, 2023 11:41 AM: Backend event: Put - Completed: duplicati-id666cc3ccf8d4115bc9bed57e0f5c7b6.dindex.zip.aes (35,18 KB)
Dec 28, 2023 11:41 AM: Backend event: Put - Started: duplicati-id666cc3ccf8d4115bc9bed57e0f5c7b6.dindex.zip.aes (35,18 KB)
Dec 28, 2023 11:41 AM: Backend event: Put - Completed: duplicati-b8cdf8fa9e25a4f978ac8121483d9cec7.dblock.zip.aes (99,93 MB)
Dec 28, 2023 11:41 AM: Backend event: Put - Started: duplicati-b8b13ab270be7408589b05bbf31bbdbb4.dblock.zip.aes (99,89 MB)
Dec 28, 2023 11:41 AM: Backend event: Put - Completed: duplicati-i3d4585e81bc2471ba0c544fda26e8a47.dindex.zip.aes (135,42 KB)
Dec 28, 2023 11:41 AM: Backend event: Put - Started: duplicati-i3d4585e81bc2471ba0c544fda26e8a47.dindex.zip.aes (135,42 KB)
Dec 28, 2023 11:41 AM: Backend event: Put - Completed: duplicati-b55c8a8e72fa94ce39eda0c36c6a90f5e.dblock.zip.aes (99,96 MB)
Dec 28, 2023 11:40 AM: Backend event: Put - Started: duplicati-bd97d1b520e954e1c86bdf49ac2257e90.dblock.zip.aes (99,87 MB)
Dec 28, 2023 11:40 AM: Backend event: Put - Completed: duplicati-i27868f5cd85b464fb34c00b6942dc6f6.dindex.zip.aes (35,31 KB)
Dec 28, 2023 11:40 AM: Backend event: Put - Started: duplicati-i27868f5cd85b464fb34c00b6942dc6f6.dindex.zip.aes (35,31 KB)
Dec 28, 2023 11:40 AM: Backend event: Put - Completed: duplicati-b76777672fc0148df9b37d81aced38115.dblock.zip.aes (99,96 MB)
Dec 28, 2023 11:40 AM: Backend event: Put - Started: duplicati-b8cdf8fa9e25a4f978ac8121483d9cec7.dblock.zip.aes (99,93 MB)
Dec 28, 2023 11:40 AM: Backend event: Put - Completed: duplicati-i1a95431115f04e8793032e9e917a6fb7.dindex.zip.aes (35,34 KB)
Dec 28, 2023 11:40 AM: Backend event: Put - Started: duplicati-i1a95431115f04e8793032e9e917a6fb7.dindex.zip.aes (35,34 KB)
Dec 28, 2023 11:40 AM: Backend event: Put - Completed: duplicati-b781ba8d09e6344cca46b9f2523089953.dblock.zip.aes (99,96 MB)
Dec 28, 2023 11:40 AM: Backend event: Put - Started: duplicati-b813ec20e40ac42339535e4308f31b068.dblock.zip.aes (99,87 MB)
Dec 28, 2023 11:40 AM: Backend event: Put - Completed: duplicati-i2d983dfc3cc04710a99fe1842e7892c6.dindex.zip.aes (135,53 KB)
Dec 28, 2023 11:40 AM: Backend event: Put - Started: duplicati-i2d983dfc3cc04710a99fe1842e7892c6.dindex.zip.aes (135,53 KB)
Dec 28, 2023 11:40 AM: Backend event: Put - Completed: duplicati-b4ee73452621f423ab930da5ac7316df3.dblock.zip.aes (99,91 MB)
Dec 28, 2023 11:40 AM: Backend event: Put - Started: duplicati-b55c8a8e72fa94ce39eda0c36c6a90f5e.dblock.zip.aes (99,96 MB)
Dec 28, 2023 11:40 AM: Backend event: Put - Completed: duplicati-iba554b691ff04a2eb2ba0c972ff07530.dindex.zip.aes (35,36 KB)
Dec 28, 2023 11:40 AM: Backend event: Put - Started: duplicati-iba554b691ff04a2eb2ba0c972ff07530.dindex.zip.aes (35,36 KB)
Dec 28, 2023 11:40 AM: Backend event: Put - Completed: duplicati-b9679681942b64b7fa41d353f1c181e16.dblock.zip.aes (99,94 MB)
Dec 28, 2023 11:39 AM: Backend event: Put - Started: duplicati-b781ba8d09e6344cca46b9f2523089953.dblock.zip.aes (99,96 MB)
Dec 28, 2023 11:39 AM: Backend event: Put - Completed: duplicati-ic4aa0e7ab085497caabff9236f89077a.dindex.zip.aes (35,20 KB)
Dec 28, 2023 11:39 AM: Backend event: Put - Started: duplicati-ic4aa0e7ab085497caabff9236f89077a.dindex.zip.aes (35,20 KB)
Dec 28, 2023 11:39 AM: Backend event: Put - Completed: duplicati-be3ac27984dda40a1be63316dfb9f4757.dblock.zip.aes (99,88 MB)
Dec 28, 2023 11:38 AM: Backend event: Put - Started: duplicati-b76777672fc0148df9b37d81aced38115.dblock.zip.aes (99,96 MB)
Dec 28, 2023 11:38 AM: Renaming “duplicati-bafebb7afb73c46429a43136f66687b5a.dblock.zip.aes” to “duplicati-b76777672fc0148df9b37d81aced38115.dblock.zip.aes”
Dec 28, 2023 11:38 AM: Backend event: Put - Rename: duplicati-b76777672fc0148df9b37d81aced38115.dblock.zip.aes (99,96 MB)
Dec 28, 2023 11:38 AM: Backend event: Put - Rename: duplicati-bafebb7afb73c46429a43136f66687b5a.dblock.zip.aes (99,96 MB)
Dec 28, 2023 11:37 AM: Backend event: Put - Retrying: duplicati-bafebb7afb73c46429a43136f66687b5a.dblock.zip.aes (99,96 MB)
Dec 28, 2023 11:37 AM: Backend event: Put - Started: duplicati-bafebb7afb73c46429a43136f66687b5a.dblock.zip.aes (99,96 MB)
Dec 28, 2023 11:37 AM: Backend event: Put - Started: duplicati-b4ee73452621f423ab930da5ac7316df3.dblock.zip.aes (99,91 MB)
Dec 28, 2023 11:37 AM: Renaming “duplicati-be311d6a887b149958da7a3101a5b6fb7.dblock.zip.aes” to “duplicati-b4ee73452621f423ab930da5ac7316df3.dblock.zip.aes”
Dec 28, 2023 11:37 AM: Backend event: Put - Rename: duplicati-b4ee73452621f423ab930da5ac7316df3.dblock.zip.aes (99,91 MB)
Dec 28, 2023 11:37 AM: Backend event: Put - Rename: duplicati-be311d6a887b149958da7a3101a5b6fb7.dblock.zip.aes (99,91 MB)
Dec 28, 2023 11:37 AM: Backend event: Put - Started: duplicati-b9679681942b64b7fa41d353f1c181e16.dblock.zip.aes (99,94 MB)
Dec 28, 2023 11:37 AM: Renaming “duplicati-bf2367e65bebc4483a88a99bba9dde500.dblock.zip.aes” to “duplicati-b9679681942b64b7fa41d353f1c181e16.dblock.zip.aes”
Dec 28, 2023 11:37 AM: Backend event: Put - Rename: duplicati-b9679681942b64b7fa41d353f1c181e16.dblock.zip.aes (99,94 MB)
Dec 28, 2023 11:37 AM: Backend event: Put - Rename: duplicati-bf2367e65bebc4483a88a99bba9dde500.dblock.zip.aes (99,94 MB)
Dec 28, 2023 11:37 AM: Backend event: Put - Retrying: duplicati-be311d6a887b149958da7a3101a5b6fb7.dblock.zip.aes (99,91 MB)
Dec 28, 2023 11:37 AM: Backend event: Put - Started: duplicati-be311d6a887b149958da7a3101a5b6fb7.dblock.zip.aes (99,91 MB)
Dec 28, 2023 11:37 AM: Backend event: Put - Retrying: duplicati-bf2367e65bebc4483a88a99bba9dde500.dblock.zip.aes (99,94 MB)
Dec 28, 2023 11:37 AM: Backend event: Put - Started: duplicati-bf2367e65bebc4483a88a99bba9dde500.dblock.zip.aes (99,94 MB)
Dec 28, 2023 11:37 AM: Backend event: Put - Started: duplicati-be3ac27984dda40a1be63316dfb9f4757.dblock.zip.aes (99,88 MB)
Dec 28, 2023 11:37 AM: Renaming “duplicati-bcd630597915f44b79209c5fc16fe89f1.dblock.zip.aes” to “duplicati-be3ac27984dda40a1be63316dfb9f4757.dblock.zip.aes”
Dec 28, 2023 11:37 AM: Backend event: Put - Rename: duplicati-be3ac27984dda40a1be63316dfb9f4757.dblock.zip.aes (99,88 MB)
Dec 28, 2023 11:37 AM: Backend event: Put - Rename: duplicati-bcd630597915f44b79209c5fc16fe89f1.dblock.zip.aes (99,88 MB)
Dec 28, 2023 11:37 AM: Backend event: Put - Retrying: duplicati-bcd630597915f44b79209c5fc16fe89f1.dblock.zip.aes (99,88 MB)
Dec 28, 2023 11:36 AM: Backend event: Put - Started: duplicati-bcd630597915f44b79209c5fc16fe89f1.dblock.zip.aes (99,88 MB)
Dec 26, 2023 1:32 AM: Backend event: Put - Completed: duplicati-i62520bb77f9c4e899f6ee9f1679b5e92.dindex.zip.aes (35,22 KB)
Dec 26, 2023 1:32 AM: Backend event: Put - Started: duplicati-i62520bb77f9c4e899f6ee9f1679b5e92.dindex.zip.aes (35,22 KB)
Dec 26, 2023 1:32 AM: Backend event: Put - Completed: duplicati-b368c638438914b36af9b5f750a302ee7.dblock.zip.aes (99,88 MB)
Dec 26, 2023 1:32 AM: Backend event: Put - Completed: duplicati-i79b4efef049441928bc306146963fbf2.dindex.zip.aes (135,39 KB)
Dec 26, 2023 1:32 AM: Backend event: Put - Started: duplicati-i79b4efef049441928bc306146963fbf2.dindex.zip.aes (135,39 KB)
Dec 26, 2023 1:32 AM: Backend event: Put - Completed: duplicati-b94d93630c8604090ad730a2e1576e126.dblock.zip.aes (99,95 MB)

gpatel-fr · December 28, 2023, 9:35am

This begs the question, what was doing the computer in these 10 hours ? sleeping ? is the computer a Windows or Mac system and if yes, is the advanced option allow-sleep set to true ? if it’s Linux, is sleep mode disallowed at the system level ?

Andrey_SFTDI · December 28, 2023, 9:41am

The server is running Windows Server 2008 R2 Enterprise, it does not go into sleep mode, it is constantly online for 24 hours.

Andrey_SFTDI · December 28, 2023, 9:46am

Here are the latest logs, and the background process finished, but it took a long time.

Dec 28, 2023 12:45 PM: The operation Backup has completed
Dec 28, 2023 12:44 PM: Backend event: Get - Completed: duplicati-b4afcebd2802547a199876b085ad7aa32.dblock.zip.aes (99,87 MB)
Dec 28, 2023 12:44 PM: Backend event: Get - Started: duplicati-b4afcebd2802547a199876b085ad7aa32.dblock.zip.aes (99,87 MB)
Dec 28, 2023 12:44 PM: Backend event: Get - Completed: duplicati-i63a4269335e94b9a993831f30ddc47d4.dindex.zip.aes (35,20 KB)
Dec 28, 2023 12:44 PM: Backend event: Get - Started: duplicati-i63a4269335e94b9a993831f30ddc47d4.dindex.zip.aes (35,20 KB)
Dec 28, 2023 12:44 PM: Backend event: Get - Completed: duplicati-20231218T203148Z.dlist.zip.aes (8,53 KB)
Dec 28, 2023 12:43 PM: Backend event: Get - Started: duplicati-20231218T203148Z.dlist.zip.aes (8,53 KB)
Dec 28, 2023 12:43 PM: removing file listed as Deleting: duplicati-bafebb7afb73c46429a43136f66687b5a.dblock.zip.aes
Dec 28, 2023 12:43 PM: removing file listed as Deleting: duplicati-be311d6a887b149958da7a3101a5b6fb7.dblock.zip.aes
Dec 28, 2023 12:43 PM: removing file listed as Deleting: duplicati-bf2367e65bebc4483a88a99bba9dde500.dblock.zip.aes
Dec 28, 2023 12:43 PM: removing file listed as Deleting: duplicati-bcd630597915f44b79209c5fc16fe89f1.dblock.zip.aes
Dec 28, 2023 12:43 PM: Backend event: List - Completed: (32,68 KB)
Dec 28, 2023 12:42 PM: Backend event: List - Started: ()
Dec 28, 2023 12:42 PM: Compacting not required
Dec 28, 2023 12:35 PM: No remote filesets were deleted

Andrey_SFTDI · December 28, 2023, 9:51am

duplicati-monitoring

gpatel-fr · December 28, 2023, 1:13pm

Very well, your computer is running a server OS - obsolete since 5 years. This does not explain why it as stopped to do any backup work for 10 hours straight. Could it have turned to pause mode for some reason ? The pause mode indicator is not displayed in your screenshots. It’s to the right of the status window (that you have screenshotted).
If not there is still my unanswered questions about the ‘share’ (what it is ? is is networked ? if yes, is it reliable?)

Andrey_SFTDI · December 28, 2023, 1:45pm

The share is using B2 Cloud Storage from BackBlaze, where a large amount of gigabytes is uploaded daily. However, the issue is only with one backup, approximately 1-2 times per month. Pause mode is not enabled (it is visible in the screenshots), and the backups are performed automatically.

ts678 · December 28, 2023, 2:31pm

It looks more like 10 hours plus 2 days. A good question either way though.

Looking at the progress data on the home screen (never shown) might say.
It should show what file it’s reading, and how far into the file it is at the time.
When issue occurs, is there a consistent pattern when looking into Source?

What are the backup file counts in job log, and Source size on home page?

Focus on upload (a.k.a. Put but OP often writes as download) has too little.
My first response suggested other things, but everything still awaits the OP.

It’s hard to say, but every Put - Rename and Renaming in the big live log post probably follows an error. Although the “look” of the possible upload stall is a little unusual, a live log at Retry might provide clues.

I don’t think that one has known upload problems, however it’s an exception to the rule I just described.
What To Do When You Get a B2 503 (or 500) Server Error explains how those may be issued normally.

I suppose you could go to Complete log in job logs to compare FilesUploaded with RetryAttempts, giving you some idea of what’s normal for you, your networks, and the ever-changing Backblaze status.

Is that the backup rate or the rate of issues? Whichever it is, what’s the other rate?
How big is the Source, and how much is changing? Again, many logs provide data.

Examples:

Complete log is not pretty, but has more information on the Destination and how much was changed:

    "BackendStatistics": {
      "RemoteCalls": 11,
      "BytesUploaded": 82740547,
      "BytesDownloaded": 53329367,
      "FilesUploaded": 6,
      "FilesDownloaded": 3,
      "FilesDeleted": 0,
      "FoldersCreated": 0,
      "RetryAttempts": 0,
      "UnknownFileSize": 90162,
      "UnknownFileCount": 1,
      "KnownFileCount": 433,
      "KnownFileSize": 9743114541,
      "LastBackupDate": "2023-12-28T04:20:21-05:00",
      "BackupListCount": 37,

gpatel-fr · December 28, 2023, 6:32pm

Maybe there is a problem in communication here. For me a share implies (under Windows) a letter drive, something accessed mainly through the operating system. I did not understand something like that.

If you are using the B2 backend in Duplicati, your system in talking http over the internet and you have then to ensure that the advanced option http-operation-timeout is set to something like say 120 seconds.

There are problems with the backend dialog for your system, the word ‘retrying’ appears in your logs, so this is not a theoretical problem.

After setting this option, if the dialog get stuck between Duplicati and the backend server it will then be reset after a limited delay.

ts678 · December 28, 2023, 7:42pm

It’s not proven, as 503 is a normal thing on B2, but is a little suspicious due to seeing so many of them.

Looking at log at Retry level would give more info, but it’s strange that the other B2 backups seem fine.

Here’s an example of the dialog one gets when B2 gets full in one spot and so signals to go elsewhere:

2023-09-23 12:23:22 -04 - [Retry-Duplicati.Library.Main.Operation.Backup.BackendUploader-RetryPut]: Operation Put with file duplicati-ia32a71908d124bbcafa2aef46f7acbff.dindex.zip.aes attempt 1 of 1 failed with message: 503 - service_unavailable: no tomes available
System.Exception: 503 - service_unavailable: no tomes available
   at Duplicati.Library.Backend.Backblaze.B2AuthHelper.AttemptParseAndThrowException(Exception ex)
   at Duplicati.Library.JSONWebHelper.<GetResponseAsync>d__40.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Duplicati.Library.JSONWebHelper.<ReadJSONResponseAsync>d__27`1.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Duplicati.Library.JSONWebHelper.<GetJSONDataAsync>d__22`1.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Duplicati.Library.Backend.Backblaze.B2.<PutAsync>d__28.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Duplicati.Library.Main.Operation.Backup.BackendUploader.<DoPut>d__24.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Duplicati.Library.Main.Operation.Backup.BackendUploader.<>c__DisplayClass20_0.<<UploadFileAsync>b__0>d.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at Duplicati.Library.Main.Operation.Backup.BackendUploader.<DoWithRetry>d__21.MoveNext()

and although this isn’t a big backup, I had to go back to September to find that example of B2-normal. Without an actual log such as above, we don’t know what kind of trouble the trouble-backup is seeing.
log-file=<path> log-file-log-level=Retry would be one option, or do About → Show log → Live → Retry

We also know almost nothing about the Source or the backup behavior reading through it. Verbose log shows that, but also picks up file names (is that a problem?), so trying for a gentle start of more info…

One method which would pick up hints for both Source and Destination (but is a little awkward) is copy About → System info → Server state properties (especially long lastPgEvent) the next time work stops.

EDIT:

Please clarify “selected it”. Did you see it not writing logs, then did something (what?) then it wrote logs?
Depending on how often this issue occurs, I’m thinking maybe a log file would be an easier way to log it.
If you choose the live log approach, you might have to click on the error line in order to see error details.
On the other hand, live log is an easy way to flip levels during two and a half day wait, looking for action.
Profiling level is sensitive, but output gets huge. During wait, what was (or was not) observed changing?

Andrey_SFTDI · January 11, 2024, 6:30am

It turns out that when a job stops, for example, when a backup hasn’t run for 2 days but should run daily, it stops writing logs as shown here -

Dec 28, 2023 11:36 AM: Backend event: Put - Started: duplicati-bcd630597915f44b79209c5fc16fe89f1.dblock.zip.aes (99.88 MB)
Dec 26, 2023 1:32 AM: Backend event: Put - Completed: duplicati-i62520bb77f9c4e899f6ee9f1679b5e92.dindex.zip.aes (35.22 KB)

When such a stop occurs, I go to the web interface, navigate to Show Log → Live, and the logging continues. If I don’t access the web interface, the job remains stuck and no logs are written. Currently, there haven’t been any issues, but as soon as there is any new information, I will provide an update with new logs.

ts678 · January 11, 2024, 12:27pm

I don’t know the internals of the live log, or the display mechanism in the browser, but I can say that I’ve seen some unreliable behavior from the live log (basically, missing lines that I know should be present).

What I have not seen is the lack of live log causing a lack of job progress, or any issues in job behavior.

How are you verifying “job remains stuck”? What does the log file from the post before yours show you?

gpatel-fr · January 11, 2024, 8:41pm

me neither; what the problem could be with the server seeming to hang on writing in this buffer IDK. I’m not sure how thorougly Ms is testing .Net with something as utterly obsolete as Server 2008 R2.

Andrey_SFTDI · February 15, 2024, 9:10am

I see the stuck task through duplicati-monitoring. Then I access the server, go to the web interface of duplicati, and I see that the task is hanging, as shown in the screenshots above, with the speed dropping to kilobytes. In the logs, I see something like this:

Feb 9, 2024 1:24 AM: Backend event: Put - Completed: duplicati-ice1321396eca4d4e94c4721652aba538.dindex.zip.aes (136.22 KB)
Feb 9, 2024 1:24 AM: Backend event: Put - Started: duplicati-ice1321396eca4d4e94c4721652aba538.dindex.zip.aes (136.22 KB)

After that, I go to the task, choose to edit it, and press save in the 5th step. After 5 minutes, the task continues to execute. Today I saw the following error after performing the actions described above:

Feb 15, 2024 9:46 AM: Cannot open WMI provider \localhost\root\virtualization. Hyper-V is probably not installed.

After this task completes, it automatically starts again and executes without any problems.