Release: 2.1.1.100 (Canary) 2025-08-08

[jberry02]

@jberry02

My Windows 10 system running 2.1.1.100 reported several missing files on 2 backups this morning. This is after running at least 2 “good” backups for each.

This happened again today, however, the root cause was probably related to a local power outage that definitely would have taken down the networking for this system.

[kenkendk]

@Taomyn

I wanted to know first if I should switch away from Minio, does it make a difference for Wasabi or go back to AWS with the switch you mentioned to be safe?

It does not matter. The AWS library is developed by AWS and has (increasingly) many features that only works with AWS S3. The Minio library is developed by MinIO and has a focus on the core protocol so is more likely to be immediately compatible with any non-AWS service.

@jberry02

On my main laptop there are over 3000 empty directories in the “/” tree. This does not include anything under /home, /tmp, or other file systems that are separate from “/”.

There are 3225 empty directories in my home directory tree. Many are firefox, git, and wine.

On another system that is a relative new build with less software my home directory tree has 69 empty directories while the “/” tree has 1945.

So this is the confusion I was trying to address. The “source” refers only to the input path.

A short example:

/
- /tmp
- /tmp/f1
- /home
- /opt

Here, if I choose / as the source, it is not empty (has /tmp, /home, and /opt in it) and the backup will work as expected.

If I choose /home as the source, it is empty and will stop the backup.

In other words, it does not matter how many empty folders are below the source, as there are almost certainly a great number of such folders.

@jberry02

This is normal and IMHO it is a mistake for Duplicati to default to aborting a backup just because it encounters an empty directory.

Agree. Empty directories are very much expected. The new switch only applies to source folders (meaning those explicitly added for backup).

@jberry02

I can live with that

Nice!

@f1assistance

I love the white space (very clean) in the new browser UI.

Thanks!

@Taomyn

It’s a mixture, I have one backup where a specific folder is sometimes used by another application, so most of the time it’s empty but can sometimes have files present that I’d want backed up. Another is a folder I use to backup application data before an upgrade then I delete once it’s not needed - having this backed up means I can still go back after a few months when the files have been deleted and grab any files.

I can see that as a valid use case. I guess the trade-off is annoying users with an expected “sometimes empty” folder versus protecting users who mistakenly make a backup of a mounted folder.

Unfortunately, I do not have any data that shows which situation is most common

Based on your backups, is it an outlier to include empty folders as the source, or is it common?

[jberry02]

@jberry02

@jberry02

My Windows 10 system running 2.1.1.100 reported several missing files on 2 backups this morning. This is after running at least 2 “good” backups for each.

This happened again today, however, the root cause was probably related to a local power outage that definitely would have taken down the networking for this system.

2 backups on a Linux system running 1.100 reported missing files today. Unless these are missing files from 0.125 that weren’t detected until now, there would appear to still be an issue detecting failed uploads.

[Taomyn]

I have maybe 18-20 total jobs and 3 or 4 have empty folders.

Personally I think the check is a feature of the job creation/modification and not the job engine itself. By all means warn about it when trying to add one to the job, just the same way I’m annoyed every time I save my Wasabi S3 jobs because it thinks I need a prefix when I don’t, and then we can take action or ignore it. That’s more useful than failing a backup, perhaps it an informational message in the log - just not a warning or error, which creates it’s own annoyance.

I must test was Veeam does…

[ts678]

@jberry02

there would appear to still be an issue detecting failed uploads.

Uploads to what? At one time we were both having trouble with Backblaze B2 uploads.

“Added option to log http requests” as announced at top could show whether Backblaze gave a success return to the upload, but didn’t actually have the file there. Even without having that information, as long as you have a log-file at at least Information, you’d have some file name to go look for. If you raise level up to Verbose and add the new option of

or in old ngax UI which actually gives the option name (release notice usually also fails)

Having to go read all the pull requests is very unfriendly, but at least the name is there.

Add option to log HTTP and socket requests

There might still be some guessing if you have concurrent uploads, but after you see the name that’s missing, you can look for something like upload completion, then see status.

2025-08-14 09:28:30 -04 - [Verbose-Duplicati.Library.Main.NetworkTrafficLogger.Http-ResponseHeadersStart]: [System.Net.Http] Event: ResponseHeadersStart

2025-08-14 09:28:30 -04 - [Verbose-Duplicati.Library.Main.NetworkTrafficLogger.Http-ResponseHeadersStop]: [System.Net.Http] Event: ResponseHeadersStop
  statusCode          : 200

2025-08-14 09:28:30 -04 - [Verbose-Duplicati.Library.Main.NetworkTrafficLogger.Http-ResponseContentStart]: [System.Net.Http] Event: ResponseContentStart

2025-08-14 09:28:30 -04 - [Verbose-Duplicati.Library.Main.NetworkTrafficLogger.Http-ResponseContentStop]: [System.Net.Http] Event: ResponseContentStop

2025-08-14 09:28:30 -04 - [Verbose-Duplicati.Library.Main.NetworkTrafficLogger.Http-RequestStop]: [System.Net.Http] Event: RequestStop
  statusCode          : 200

2025-08-14 09:28:30 -04 - [Profiling-Duplicati.Library.Main.Backend.PutOperation-UploadSpeed]: Uploaded 9.93 MiB in 00:01:29.4578819, 113.63 KiB/s
2025-08-14 09:28:30 -04 - [Profiling-Timer.Begin-Duplicati.Library.Main.Operation.Common.DatabaseCommon-CommitTransactionAsync]: Starting - FlushBackendMessagesAndCommitAsync
2025-08-14 09:28:30 -04 - [Profiling-Timer.Begin-Duplicati.Library.Main.Database.ReusableTransaction-FlushBackendMessagesAndCommitAsync]: Starting - CommitTransaction: FlushBackendMessagesAndCommitAsync
2025-08-14 09:28:30 -04 - [Profiling-Timer.Finished-Duplicati.Library.Main.Database.ReusableTransaction-FlushBackendMessagesAndCommitAsync]: CommitTransaction: FlushBackendMessagesAndCommitAsync took 0:00:00:00.000
2025-08-14 09:28:30 -04 - [Profiling-Timer.Finished-Duplicati.Library.Main.Operation.Common.DatabaseCommon-CommitTransactionAsync]: FlushBackendMessagesAndCommitAsync took 0:00:00:00.000
2025-08-14 09:28:30 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-b6cfe67514c5b437cad7c829f5acd70a6.dblock.zip.aes (9.93 MiB)

but I’m not sure which 200 to look at. If you can get the log result, maybe dev can help.

You can also run BackendTester, which could cause upload confusion in past releases.

[jberry02]

@ts678

@jberry02

there would appear to still be an issue detecting failed uploads.

Uploads to what? At one time we were both having trouble with Backblaze B2 uploads.

Uploads to Backblaze B2 using native (i.e. not S3).

I have added the –log-http-requests option to the 2 systems running 2.1.1.100, and they should still be doing verbose logs, so we’ll see what happens over the next days.

[jberry02]

Here is log data from a recent “found n missing files, please run repair” error.

The error in the log is

2025-08-17 03:30:59 -04 - [Error-Duplicati.Library.Main.Operation.FilelistProcessor-MissingRemoteFiles]: Found 1 files that are missing from the remote storage, please run repair

grep’ing for missing files we find

2025-08-17 03:30:59 -04 - [Warning-Duplicati.Library.Main.Operation.FilelistProcessor-MissingFile]: Missing file: duplicati-ib81ae893639a4bd9952e7a5a8a39256b.dindex.zip.aes

grep’ing for the filename we find

2025-08-17 03:30:56 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-ib81ae893639a4bd9952e7a5a8a39256b.dindex.zip.aes (5.669 KiB)
2025-08-17 03:30:56 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-ib81ae893639a4bd9952e7a5a8a39256b.dindex.zip.aes (5.669 KiB)
2025-08-17 03:30:59 -04 - [Warning-Duplicati.Library.Main.Operation.FilelistProcessor-MissingFile]: Missing file: duplicati-ib81ae893639a4bd9952e7a5a8a39256b.dindex.zip.aes

So it thinks the “Put” completed, but then the file is missing.

These are the complete log entries (as near as I can tell) for the missing file

2025-08-17 03:30:56 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-ib81ae893639a4bd9952e7a5a8a39256b.dindex.zip.aes (5.669 KiB)
2025-08-17 03:30:56 -04 - [Verbose-Duplicati.Library.Main.NetworkTrafficLogger.Http-RequestStart]: [System.Net.Http] Event: RequestStart
  scheme              : https
  host                : pod-000-1081-04.backblaze.com
  port                : 443
  pathAndQuery        : /b2api/v1/b2_upload_file/[censored]
  versionMajor        : 1
  versionMinor        : 1
  versionPolicy       : 0

2025-08-17 03:30:56 -04 - [Verbose-Duplicati.Library.Main.NetworkTrafficLogger.Http-RequestHeadersStart]: [System.Net.Http] Event: RequestHeadersStart
  connectionId        : 211

2025-08-17 03:30:56 -04 - [Verbose-Duplicati.Library.Main.NetworkTrafficLogger.Http-RequestHeadersStop]: [System.Net.Http] Event: RequestHeadersStop

2025-08-17 03:30:56 -04 - [Verbose-Duplicati.Library.Main.NetworkTrafficLogger.Http-RequestContentStart]: [System.Net.Http] Event: RequestContentStart

2025-08-17 03:30:56 -04 - [Verbose-Duplicati.Library.Main.NetworkTrafficLogger.Http-RequestContentStop]: [System.Net.Http] Event: RequestContentStop
  contentLength       : 5805

2025-08-17 03:30:56 -04 - [Verbose-Duplicati.Library.Main.NetworkTrafficLogger.Http-ResponseHeadersStart]: [System.Net.Http] Event: ResponseHeadersStart

2025-08-17 03:30:56 -04 - [Verbose-Duplicati.Library.Main.NetworkTrafficLogger.Http-ResponseHeadersStop]: [System.Net.Http] Event: ResponseHeadersStop
  statusCode          : 503

2025-08-17 03:30:56 -04 - [Verbose-Duplicati.Library.Main.NetworkTrafficLogger.Http-ResponseContentStart]: [System.Net.Http] Event: ResponseContentStart

2025-08-17 03:30:56 -04 - [Verbose-Duplicati.Library.Main.NetworkTrafficLogger.Http-ResponseContentStop]: [System.Net.Http] Event: ResponseContentStop

2025-08-17 03:30:56 -04 - [Verbose-Duplicati.Library.Main.NetworkTrafficLogger.Http-RequestStop]: [System.Net.Http] Event: RequestStop
  statusCode          : 503

2025-08-17 03:30:56 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-ib81ae893639a4bd9952e7a5a8a39256b.dindex.zip.aes (5.669 KiB)

[jberry02]

Here is the log info for another error

2025-08-15 03:41:46 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-i5a469aa8696c410e97cbf315ac601451.dindex.zip.aes (4.84 KiB)
2025-08-15 03:41:46 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-i5a469aa8696c410e97cbf315ac601451.dindex.zip.aes (4.84 KiB)
2025-08-15 03:59:43 -04 - [Warning-Duplicati.Library.Main.Operation.FilelistProcessor-MissingFile]: Missing file: duplicati-i5a469aa8696c410e97cbf315ac601451.dindex.zip.aes

2025-08-15 03:41:46 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-b34feeccfff8845dcb7589b0a681b49d6.dblock.zip.aes (49.32 MiB)
2025-08-15 03:41:46 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-i5a469aa8696c410e97cbf315ac601451.dindex.zip.aes (4.84 KiB)
2025-08-15 03:41:46 -04 - [Verbose-Duplicati.Library.Main.NetworkTrafficLogger.Http-RequestStart]: [System.Net.Http] Event: RequestStart
  scheme              : https
  host                : pod-000-1085-05.backblaze.com
  port                : 443
  pathAndQuery        : /b2api/v1/b2_upload_file/[censored]
  versionMajor        : 1
  versionMinor        : 1
  versionPolicy       : 0

2025-08-15 03:41:46 -04 - [Verbose-Duplicati.Library.Main.NetworkTrafficLogger.Http-RequestHeadersStart]: [System.Net.Http] Event: RequestHeadersStart
  connectionId        : 85

2025-08-15 03:41:46 -04 - [Verbose-Duplicati.Library.Main.NetworkTrafficLogger.Http-RequestHeadersStop]: [System.Net.Http] Event: RequestHeadersStop

2025-08-15 03:41:46 -04 - [Verbose-Duplicati.Library.Main.NetworkTrafficLogger.Http-RequestContentStart]: [System.Net.Http] Event: RequestContentStart

2025-08-15 03:41:46 -04 - [Verbose-Duplicati.Library.Main.NetworkTrafficLogger.Http-RequestContentStop]: [System.Net.Http] Event: RequestContentStop
  contentLength       : 4957

2025-08-15 03:41:46 -04 - [Verbose-Duplicati.Library.Main.NetworkTrafficLogger.Http-ResponseHeadersStart]: [System.Net.Http] Event: ResponseHeadersStart

2025-08-15 03:41:46 -04 - [Verbose-Duplicati.Library.Main.NetworkTrafficLogger.Http-ResponseHeadersStop]: [System.Net.Http] Event: ResponseHeadersStop
  statusCode          : 503

2025-08-15 03:41:46 -04 - [Verbose-Duplicati.Library.Main.NetworkTrafficLogger.Http-ResponseContentStart]: [System.Net.Http] Event: ResponseContentStart

2025-08-15 03:41:46 -04 - [Verbose-Duplicati.Library.Main.NetworkTrafficLogger.Http-ResponseContentStop]: [System.Net.Http] Event: ResponseContentStop

2025-08-15 03:41:46 -04 - [Verbose-Duplicati.Library.Main.NetworkTrafficLogger.Http-RequestStop]: [System.Net.Http] Event: RequestStop
  statusCode          : 503

2025-08-15 03:41:46 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-i5a469aa8696c410e97cbf315ac601451.dindex.zip.aes (4.84 KiB)

[ts678]

What To Do When You Get a B2 503 (or 500) Server Error explains what 503 means.
Basically the equipment you’re trying to upload into wants you to try again elsewhere.
Problem with trying to repro it is that I think there’s only one way that might force 503.
Integration Checklist shows fail_some_uploads and other header values for testing.
I can test 401 using a read-only key, but that seems OK. Log from CLI includes these:

Backend event: Put - Started: duplicati-ba456f16322374f61b945bcd4832eb7ac.dblock.zip (720 bytes)
  Uploading file duplicati-ba456f16322374f61b945bcd4832eb7ac.dblock.zip (720 bytes) ...
Operation Put with file duplicati-ba456f16322374f61b945bcd4832eb7ac.dblock.zip attempt 1 of 1 failed with message: Backblaze ErrorResponse: 401 - unauthorized:  => Backblaze ErrorResponse: 401 - unauthorized:
Backend event: Put - Retrying: duplicati-ba456f16322374f61b945bcd4832eb7ac.dblock.zip ()
Backend event: Put - Rename: duplicati-ba456f16322374f61b945bcd4832eb7ac.dblock.zip (720 bytes)
Backend event: Put - Rename: duplicati-b23f681e82e6041c19b363607fcacaba8.dblock.zip (720 bytes)
Renaming "duplicati-ba456f16322374f61b945bcd4832eb7ac.dblock.zip" to "duplicati-b23f681e82e6041c19b363607fcacaba8.dblock.zip"
Backend event: Put - Started: duplicati-b23f681e82e6041c19b363607fcacaba8.dblock.zip (720 bytes)
  Uploading file duplicati-b23f681e82e6041c19b363607fcacaba8.dblock.zip (720 bytes) ...
Operation Put with file duplicati-b23f681e82e6041c19b363607fcacaba8.dblock.zip attempt 2 of 1 failed with message: Backblaze ErrorResponse: 401 - unauthorized:  => Backblaze ErrorResponse: 401 - unauthorized:
Backend event: Put - Failed: duplicati-b23f681e82e6041c19b363607fcacaba8.dblock.zip ()
Error in handler: Backblaze ErrorResponse: 401 - unauthorized:  => Backblaze ErrorResponse: 401 - unauthorized:
Fatal error => Backblaze ErrorResponse: 401 - unauthorized:
Backend manager queue runner crashed => One or more errors occurred. (Backblaze ErrorResponse: 401 - unauthorized: )
The operation Backup has failed => Backblaze ErrorResponse: 401 - unauthorized:

ErrorID: BackblazeErrorResponse
Backblaze ErrorResponse: 401 - unauthorized:

I limited it using --number-of-retries=1 and used --console-log-level=retry.
You can check your verbose (which is a superset of retry) logs for any signs of retry.

While it’s conceivable that 503 is treated as success (bad), I don’t know if I see that.
On the other hand, I’m not recently seeing any signs of 503, and I used to get them.
For awhile, I was running with no retries, to encourage failures and to test resilience.

2.1.0.105_canary_2025-01-07 emailed me this error report, as an example of failure:

Failed: 503 - service_unavailable: CPU too busy (503 - service_unavailable: CPU too busy) (One or more errors occurred. (503 - service_unavailable: CPU too busy))
Details: System.AggregateException: 503 - service_unavailable: CPU too busy (503 - service_unavailable: CPU too busy) (One or more errors occurred. (503 - service_unavailable: CPU too busy))
 ---> System.Exception: 503 - service_unavailable: CPU too busy
   at CoCoL.AutomationExtensions.RunTask[T](T channels, Func`2 method, Boolean catchRetiredExceptions)
   at Duplicati.Library.Main.Operation.BackupHandler.FlushBackend(BackupResults result, IWriteChannel`1 uploadtarget, Task uploader)
   at Duplicati.Library.Main.Operation.BackupHandler.RunAsync(String[] sources, IFilter filter)
   --- End of inner exception stack trace ---
   at Duplicati.Library.Main.Operation.BackupHandler.RunAsync(String[] sources, IFilter filter)
   at Duplicati.Library.Utility.Utility.Await(Task task)
   at Duplicati.Library.Main.Controller.<>c__DisplayClass22_0.<Backup>b__0(BackupResults result)
   at Duplicati.Library.Main.Controller.RunAction[T](T result, String[]& paths, IFilter& filter, Action`1 method)
 ---> (Inner Exception #1) System.AggregateException: One or more errors occurred. (503 - service_unavailable: CPU too busy)
 ---> System.Exception: 503 - service_unavailable: CPU too busy
   at CoCoL.AutomationExtensions.RunTask[T](T channels, Func`2 method, Boolean catchRetiredExceptions)
   at Duplicati.Library.Main.Operation.BackupHandler.FlushBackend(BackupResults result, IWriteChannel`1 uploadtarget, Task uploader)
   at Duplicati.Library.Main.Operation.BackupHandler.RunAsync(String[] sources, IFilter filter)
   --- End of inner exception stack trace ---<---

another:

Failed: 503 - service_unavailable: no tomes available (503 - service_unavailable: no tomes available) (One or more errors occurred. (503 - service_unavailable: no tomes available))
Details: System.AggregateException: 503 - service_unavailable: no tomes available (503 - service_unavailable: no tomes available) (One or more errors occurred. (503 - service_unavailable: no tomes available))
 ---> System.Exception: 503 - service_unavailable: no tomes available
   at CoCoL.AutomationExtensions.RunTask[T](T channels, Func`2 method, Boolean catchRetiredExceptions)
   at Duplicati.Library.Main.Operation.BackupHandler.FlushBackend(BackupResults result, IWriteChannel`1 uploadtarget, Task uploader)
   at Duplicati.Library.Main.Operation.BackupHandler.RunAsync(String[] sources, IFilter filter)
   --- End of inner exception stack trace ---
   at Duplicati.Library.Main.Operation.BackupHandler.RunAsync(String[] sources, IFilter filter)
   at Duplicati.Library.Utility.Utility.Await(Task task)
   at Duplicati.Library.Main.Controller.<>c__DisplayClass22_0.<Backup>b__0(BackupResults result)
   at Duplicati.Library.Main.Controller.RunAction[T](T result, String[]& paths, IFilter& filter, Action`1 method)
 ---> (Inner Exception #1) System.AggregateException: One or more errors occurred. (503 - service_unavailable: no tomes available)
 ---> System.Exception: 503 - service_unavailable: no tomes available
   at CoCoL.AutomationExtensions.RunTask[T](T channels, Func`2 method, Boolean catchRetiredExceptions)
   at Duplicati.Library.Main.Operation.BackupHandler.FlushBackend(BackupResults result, IWriteChannel`1 uploadtarget, Task uploader)
   at Duplicati.Library.Main.Operation.BackupHandler.RunAsync(String[] sources, IFilter filter)
   --- End of inner exception stack trace ---<---

At some point I got tired of the errors and went back to a non-zero retry count, but the
profiling logs that I keep (some are deleted) don’t seem to be talking about 503 errors.

I do see odd intermittent failures, but can’t find 503 statusCode even with new logging.

I’m also using the BackendTester to try to get a 503, but that isn’t happening yet either.

Possibly a dev code review or maybe even a special build to request fails might help…

EDIT 1:

For the no_tomes_available one (which I think means it got full), log has a better stack:

2025-01-09 07:22:45 -05 - [Retry-Duplicati.Library.Main.Operation.Backup.BackendUploader-RetryPut]: Operation Put with file duplicati-b6867d96d3eef410885c4a645aa26ff61.dblock.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.Backend.Backblaze.B2AuthHelper.ParseException(Exception ex)
   at Duplicati.Library.JSONWebHelper.GetResponseAsync(AsyncHttpRequest req, CancellationToken cancelToken, Object requestdata)
   at Duplicati.Library.JSONWebHelper.ReadJSONResponseAsync[T](AsyncHttpRequest req, CancellationToken cancelToken, Object requestdata)
   at Duplicati.Library.JSONWebHelper.GetJSONDataAsync[T](String url, CancellationToken cancelToken, Action`1 setup, Func`3 setupbodyreq)
   at Duplicati.Library.Backend.Backblaze.B2.PutAsync(String remotename, Stream stream, CancellationToken cancelToken)
   at Duplicati.Library.Main.Operation.Backup.BackendUploader.DoPut(FileEntryItem item, IBackend backend, CancellationToken cancelToken)
   at Duplicati.Library.Main.Operation.Backup.BackendUploader.<>c__DisplayClass25_0.<<UploadFileAsync>b__0>d.MoveNext()
--- End of stack trace from previous location ---
   at Duplicati.Library.Main.Operation.Backup.BackendUploader.DoWithRetry(Func`1 method, FileEntryItem item, Worker worker, CancellationToken cancelToken)

I think the code that was used to handle 5xx exceptions is below, but is it still correct?
I think there have been some major changes in the backend area.

Duplicati/Library/Backend/Backblaze/B2.cs

[jberry02]

@ts678

While it’s conceivable that 503 is treated as success (bad), I don’t know if I see that.

As per my logs it is being treated as success.

[ts678]

@jberry02

As per my logs it is being treated as success.

Yes, but what are the surrounding circumstances about retries and renames?
Are your retries at default 5? Did it do any on the way to a wrong conclusion?

EDIT 1:

In theory the grep for the filename would have found Rename and Renaming,
meaning it went straight to 503 = success, but it would be worth double check.

EDIT 2:

and after confirming the circumstances more, then I guess dev checks or tests,
maybe with a special build to ask for failures. I haven’t seen details of behavior.

--b2-test-mode is rclone option for that. I don’t think Duplicati has any option.

[ts678]

Since I can’t get a visible 503 yet, here’s an example of weird behavior that I do get:

First, here is an in-order overview of some of the activity:

2025-08-19 21:32:41 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started:  ()
2025-08-19 21:32:43 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed:  (1.07 KiB)
2025-08-19 21:35:31 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-bcd4ad0c8332b44a19ce0eee06b3c1848.dblock.zip.aes (9.96 MiB)
2025-08-19 21:35:31 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-b1129bf2da8aa41ff851b67d22e2023e6.dblock.zip.aes (9.94 MiB)
2025-08-19 21:35:40 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-bcd4ad0c8332b44a19ce0eee06b3c1848.dblock.zip.aes (9.96 MiB)
2025-08-19 21:35:40 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-id5f6348e70824d08986bc1d7eb0e22e3.dindex.zip.aes (5.34 KiB)
2025-08-19 21:35:40 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-b6b8e0de69c604e50b002c68aeef52050.dblock.zip.aes (9.93 MiB)
2025-08-19 21:35:40 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-bf5c390f576c84d4f8138e826800e89f5.dblock.zip.aes (9.97 MiB)
2025-08-19 21:35:42 -04 - [Retry-Duplicati.Library.Main.Backend.Handler-RetryPut]: Operation Put with file duplicati-bcd4ad0c8332b44a19ce0eee06b3c1848.dblock.zip.aes attempt 1 of 0 failed with message: An error occurred while sending the request.
2025-08-19 21:35:42 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Failed: duplicati-bcd4ad0c8332b44a19ce0eee06b3c1848.dblock.zip.aes ()
2025-08-19 21:35:43 -04 - [Retry-Duplicati.Library.Main.Backend.Handler-RetryPut]: Operation Put with file duplicati-b6b8e0de69c604e50b002c68aeef52050.dblock.zip.aes attempt 1 of 0 failed with message: A task was canceled.
2025-08-19 21:35:43 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Failed: duplicati-b6b8e0de69c604e50b002c68aeef52050.dblock.zip.aes ()
2025-08-19 21:35:44 -04 - [Retry-Duplicati.Library.Main.Backend.Handler-RetryPut]: Operation Put with file duplicati-b1129bf2da8aa41ff851b67d22e2023e6.dblock.zip.aes attempt 1 of 0 failed with message: The operation was canceled.
2025-08-19 21:35:44 -04 - [Retry-Duplicati.Library.Main.Backend.Handler-RetryPut]: Operation Put with file duplicati-bf5c390f576c84d4f8138e826800e89f5.dblock.zip.aes attempt 1 of 0 failed with message: The operation was canceled.
2025-08-19 21:35:44 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Failed: duplicati-bf5c390f576c84d4f8138e826800e89f5.dblock.zip.aes ()
2025-08-19 21:35:44 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Failed: duplicati-b1129bf2da8aa41ff851b67d22e2023e6.dblock.zip.aes ()

Then here are details on the files, from separate searches:

duplicati-bcd4ad0c8332b44a19ce0eee06b3c1848.dblock.zip.aes
2025-08-19 21:35:31 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-bcd4ad0c8332b44a19ce0eee06b3c1848.dblock.zip.aes (9.96 MiB)
2025-08-19 21:35:40 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-bcd4ad0c8332b44a19ce0eee06b3c1848.dblock.zip.aes (9.96 MiB)
2025-08-19 21:35:42 -04 - [Retry-Duplicati.Library.Main.Backend.Handler-RetryPut]: Operation Put with file duplicati-bcd4ad0c8332b44a19ce0eee06b3c1848.dblock.zip.aes attempt 1 of 0 failed with message: An error occurred while sending the request.
2025-08-19 21:35:42 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Failed: duplicati-bcd4ad0c8332b44a19ce0eee06b3c1848.dblock.zip.aes ()

Above is weird because it succeeded, then failed.

duplicati-b1129bf2da8aa41ff851b67d22e2023e6.dblock.zip.aes
2025-08-19 21:35:31 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-b1129bf2da8aa41ff851b67d22e2023e6.dblock.zip.aes (9.94 MiB)
2025-08-19 21:35:44 -04 - [Retry-Duplicati.Library.Main.Backend.Handler-RetryPut]: Operation Put with file duplicati-b1129bf2da8aa41ff851b67d22e2023e6.dblock.zip.aes attempt 1 of 0 failed with message: The operation was canceled.
2025-08-19 21:35:44 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Failed: duplicati-b1129bf2da8aa41ff851b67d22e2023e6.dblock.zip.aes ()

duplicati-id5f6348e70824d08986bc1d7eb0e22e3.dindex.zip.aes
2025-08-19 21:35:40 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-id5f6348e70824d08986bc1d7eb0e22e3.dindex.zip.aes (5.34 KiB)

Above is weird because nothing mentions it later.

duplicati-b6b8e0de69c604e50b002c68aeef52050.dblock.zip.aes
2025-08-19 21:35:40 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-b6b8e0de69c604e50b002c68aeef52050.dblock.zip.aes (9.93 MiB)
2025-08-19 21:35:43 -04 - [Retry-Duplicati.Library.Main.Backend.Handler-RetryPut]: Operation Put with file duplicati-b6b8e0de69c604e50b002c68aeef52050.dblock.zip.aes attempt 1 of 0 failed with message: A task was canceled.
2025-08-19 21:35:43 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Failed: duplicati-b6b8e0de69c604e50b002c68aeef52050.dblock.zip.aes ()

duplicati-bf5c390f576c84d4f8138e826800e89f5.dblock.zip.aes
2025-08-19 21:35:40 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-bf5c390f576c84d4f8138e826800e89f5.dblock.zip.aes (9.97 MiB)
2025-08-19 21:35:44 -04 - [Retry-Duplicati.Library.Main.Backend.Handler-RetryPut]: Operation Put with file duplicati-bf5c390f576c84d4f8138e826800e89f5.dblock.zip.aes attempt 1 of 0 failed with message: The operation was canceled.
2025-08-19 21:35:44 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Failed: duplicati-bf5c390f576c84d4f8138e826800e89f5.dblock.zip.aes ()

Looking at more context lines for the success followed by failure.

So first the upload (if I found the right one, but contentLength matches) succeeds:
2025-08-19 21:35:35 -04 - [Verbose-Duplicati.Library.Main.NetworkTrafficLogger.Http-RequestContentStop]: [System.Net.Http] Event: RequestContentStop
  contentLength       : 10445277
2025-08-19 21:35:35 -04 - [Verbose-Duplicati.Library.Main.NetworkTrafficLogger.Http-ResponseHeadersStart]: [System.Net.Http] Event: ResponseHeadersStart
2025-08-19 21:35:35 -04 - [Verbose-Duplicati.Library.Main.NetworkTrafficLogger.Http-ResponseHeadersStop]: [System.Net.Http] Event: ResponseHeadersStop
  statusCode          : 200
2025-08-19 21:35:35 -04 - [Verbose-Duplicati.Library.Main.NetworkTrafficLogger.Http-ResponseContentStart]: [System.Net.Http] Event: ResponseContentStart
2025-08-19 21:35:35 -04 - [Verbose-Duplicati.Library.Main.NetworkTrafficLogger.Http-ResponseContentStop]: [System.Net.Http] Event: ResponseContentStop
2025-08-19 21:35:35 -04 - [Verbose-Duplicati.Library.Main.NetworkTrafficLogger.Http-RequestStop]: [System.Net.Http] Event: RequestStop
  statusCode          : 200
2025-08-19 21:35:35 -04 - [Profiling-Duplicati.Library.Main.Backend.PutOperation-UploadSpeed]: Uploaded 9.96 MiB in 00:00:03.8895406, 2.56 MiB/s
2025-08-19 21:35:40 -04 - [Profiling-Timer.Finished-Duplicati.Library.Main.Database.ReusableTransaction-CommitAddBlockToOutputFlush]: CommitTransaction: CommitAddBlockToOutputFlush took 0:00:00:05.317
2025-08-19 21:35:40 -04 - [Profiling-Timer.Finished-Duplicati.Library.Main.Operation.Common.DatabaseCommon-CommitTransactionAsync]: CommitAddBlockToOutputFlush took 0:00:00:05.317
2025-08-19 21:35:40 -04 - [Profiling-Timer.Begin-Duplicati.Library.Main.Backend.Handler-RemoteOperationPut]: Starting - RemoteOperationPut
...
2025-08-19 21:35:40 -04 - [Profiling-Timer.Begin-Duplicati.Library.Main.Operation.Common.DatabaseCommon-CommitTransactionAsync]: Starting - FlushBackendMessagesAndCommitAsync
2025-08-19 21:35:40 -04 - [Profiling-Timer.Begin-Duplicati.Library.Main.Database.ReusableTransaction-FlushBackendMessagesAndCommitAsync]: Starting - CommitTransaction: FlushBackendMessagesAndCommitAsync
2025-08-19 21:35:40 -04 - [Profiling-Timer.Finished-Duplicati.Library.Main.Database.ReusableTransaction-FlushBackendMessagesAndCommitAsync]: CommitTransaction: FlushBackendMessagesAndCommitAsync took 0:00:00:00.070
2025-08-19 21:35:40 -04 - [Profiling-Timer.Finished-Duplicati.Library.Main.Operation.Common.DatabaseCommon-CommitTransactionAsync]: FlushBackendMessagesAndCommitAsync took 0:00:00:00.070
2025-08-19 21:35:40 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-bcd4ad0c8332b44a19ce0eee06b3c1848.dblock.zip.aes (9.96 MiB)

Then two seconds later same fails. What's with this activity after earlier success?
2025-08-19 21:35:42 -04 - [Retry-Duplicati.Library.Main.Backend.Handler-RetryPut]: Operation Put with file duplicati-bcd4ad0c8332b44a19ce0eee06b3c1848.dblock.zip.aes attempt 1 of 0 failed with message: An error occurred while sending the request.
System.Net.Http.HttpRequestException: An error occurred while sending the request.
 ---> System.IO.IOException: Unable to read data from the transport connection: An existing connection was forcibly closed by the remote host..
 ---> System.Net.Sockets.SocketException (10054): An existing connection was forcibly closed by the remote host.
   at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.CreateException(SocketError error, Boolean forAsyncThrow)
   at System.Net.Sockets.NetworkStream.ReadAsync(Memory`1 buffer, CancellationToken cancellationToken)
   at System.Net.Security.SslStream.EnsureFullTlsFrameAsync[TIOAdapter](CancellationToken cancellationToken, Int32 estimatedSize)
   at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state)
   at System.Net.Sockets.SocketAsyncEventArgs.<>c.<.cctor>b__173_0(UInt32 errorCode, UInt32 numBytes, NativeOverlapped* nativeOverlapped)
   at System.Threading.ThreadPoolTypedWorkItemQueue`2.System.Threading.IThreadPoolWorkItem.Execute()
   at System.Threading.ThreadPoolWorkQueue.Dispatch()
   at System.Threading.PortableThreadPool.WorkerThread.WorkerThreadStart()
--- End of stack trace from previous location ---

   --- End of inner exception stack trace ---
   at System.Net.Security.SslStream.EnsureFullTlsFrameAsync[TIOAdapter](CancellationToken cancellationToken, Int32 estimatedSize)
   at System.Runtime.CompilerServices.PoolingAsyncValueTaskMethodBuilder`1.StateMachineBox`1.System.Threading.Tasks.Sources.IValueTaskSource<TResult>.GetResult(Int16 token)
   at System.Net.Security.SslStream.ReadAsyncInternal[TIOAdapter](Memory`1 buffer, CancellationToken cancellationToken)
   at System.Runtime.CompilerServices.PoolingAsyncValueTaskMethodBuilder`1.StateMachineBox`1.System.Threading.Tasks.Sources.IValueTaskSource<TResult>.GetResult(Int16 token)
   at System.Net.Http.HttpConnection.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   --- End of inner exception stack trace ---
   at System.Net.Http.HttpConnection.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at System.Net.Http.HttpConnectionPool.SendWithVersionDetectionAndRetryAsync(HttpRequestMessage request, Boolean async, Boolean doRequestAuth, CancellationToken cancellationToken)
   at System.Net.Http.DiagnosticsHandler.SendAsyncCore(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at System.Net.Http.RedirectHandler.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at Microsoft.Extensions.Http.Logging.LoggingHttpMessageHandler.<SendCoreAsync>g__Core|4_0(HttpRequestMessage request, Boolean useAsync, CancellationToken cancellationToken)
   at Microsoft.Extensions.Http.Logging.LoggingScopeHttpMessageHandler.<SendCoreAsync>g__Core|4_0(HttpRequestMessage request, Boolean useAsync, CancellationToken cancellationToken)
   at System.Net.Http.HttpClient.<SendAsync>g__Core|83_0(HttpRequestMessage request, HttpCompletionOption completionOption, CancellationTokenSource cts, Boolean disposeCts, CancellationTokenSource pendingRequestsCts, CancellationToken originalCancellationToken)
   at Duplicati.Library.Backend.Backblaze.B2.PutAsync(String remotename, Stream stream, CancellationToken cancelToken)
   at Duplicati.Library.Main.Backend.BackendManager.PutOperation.PerformUpload(IBackend backend, String hash, Int64 size, CancellationToken cancelToken)
   at Duplicati.Library.Main.Backend.BackendManager.PutOperation.ExecuteAsync(IBackend backend, CancellationToken cancelToken)
   at Duplicati.Library.Main.Backend.BackendManager.PutOperation.ExecuteAsync(IBackend backend, CancellationToken cancelToken)
   at Duplicati.Library.Main.Backend.BackendManager.Handler.Execute[TResult](PendingOperation`1 op, CancellationToken cancellationToken)
   at Duplicati.Library.Main.Backend.BackendManager.Handler.Execute(PendingOperationBase op, CancellationToken cancellationToken)
   at Duplicati.Library.Main.Backend.BackendManager.Handler.ExecuteWithRetry(PendingOperationBase op, CancellationToken cancellationToken)

B2 native with --number-of-retries=0 trying to get a 503 failure like before (no luck).
It’s at the default of --asynchronous-concurrent-upload-limit=4 (if that is relevant).

EDIT 1:

duplicati-bcd4ad0c8332b44a19ce0eee06b3c1848.dblock.zip.aes which got the odd reporting of success then failure actually seems to have made it up and on next run Remotevolume table State went to Verified. Run seems to have recovered from fail, although I’m still not sure what happened, or why its reporting seems odd. From log:

2025-08-21 10:01:01 -04 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started
2025-08-21 10:01:31 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started:  ()
2025-08-21 10:01:33 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed:  (1.07 KiB)
2025-08-21 10:01:33 -04 - [Information-Duplicati.Library.Main.Operation.FilelistProcessor-KeepIncompleteFile]: Keeping protected incomplete remote file listed as Temporary: duplicati-20250820T013235Z.dlist.zip.aes
2025-08-21 10:01:33 -04 - [Information-Duplicati.Library.Main.Operation.FilelistProcessor-SchedulingMissingFileForDelete]: Scheduling missing file for deletion, currently listed as Uploading: duplicati-b1129bf2da8aa41ff851b67d22e2023e6.dblock.zip.aes
2025-08-21 10:01:33 -04 - [Information-Duplicati.Library.Main.Operation.FilelistProcessor-SchedulingMissingFileForDelete]: Scheduling missing file for deletion, currently listed as Uploading: duplicati-id5f6348e70824d08986bc1d7eb0e22e3.dindex.zip.aes
2025-08-21 10:01:33 -04 - [Information-Duplicati.Library.Main.Operation.FilelistProcessor-SchedulingMissingFileForDelete]: Scheduling missing file for deletion, currently listed as Uploading: duplicati-i00007e285f1a47b6a825598fd97998e0.dindex.zip.aes
2025-08-21 10:01:33 -04 - [Information-Duplicati.Library.Main.Operation.FilelistProcessor-SchedulingMissingFileForDelete]: Scheduling missing file for deletion, currently listed as Uploading: duplicati-b6b8e0de69c604e50b002c68aeef52050.dblock.zip.aes
2025-08-21 10:01:33 -04 - [Information-Duplicati.Library.Main.Operation.FilelistProcessor-SchedulingMissingFileForDelete]: Scheduling missing file for deletion, currently listed as Uploading: duplicati-bf5c390f576c84d4f8138e826800e89f5.dblock.zip.aes
2025-08-21 10:01:33 -04 - [Information-Duplicati.Library.Main.Operation.FilelistProcessor-SchedulingMissingFileForDelete]: Scheduling missing file for deletion, currently listed as Uploading: duplicati-i3ba7a0692e494b199cf78c627443819a.dindex.zip.aes
2025-08-21 10:01:33 -04 - [Information-Duplicati.Library.Main.Operation.FilelistProcessor-SchedulingMissingFileForDelete]: Scheduling missing file for deletion, currently listed as Uploading: duplicati-b5711521944b84daca2f4bed58360f47e.dblock.zip.aes
2025-08-21 10:01:33 -04 - [Information-Duplicati.Library.Main.Operation.FilelistProcessor-SchedulingMissingFileForDelete]: Scheduling missing file for deletion, currently listed as Uploading: duplicati-i3e9a8728697e4f1ebe150c2bd61cfdc9.dindex.zip.aes
2025-08-21 10:01:33 -04 - [Information-Duplicati.Library.Main.Operation.FilelistProcessor-SchedulingMissingFileForDelete]: Scheduling missing file for deletion, currently listed as Uploading: duplicati-b0aa0fa7d1be5419eb14b10683470f62f.dblock.zip.aes
2025-08-21 10:01:33 -04 - [Information-Duplicati.Library.Main.Operation.FilelistProcessor-RemoteUnwantedMissingFile]: Removing file listed as Temporary: duplicati-i8fdc5fe13255404482f365491c4bcfd1.dindex.zip.aes
2025-08-21 10:01:33 -04 - [Information-Duplicati.Library.Main.Operation.FilelistProcessor-RemoteUnwantedMissingFile]: Removing file listed as Temporary: duplicati-i18da27d5b196492b95301e1b3c3e42e3.dindex.zip.aes
2025-08-21 10:02:43 -04 - [Information-Duplicati.Library.Main.Operation.Backup.UploadSyntheticFilelist-PreviousBackupFilelistUpload]: Uploading filelist from previous interrupted backup
2025-08-21 10:03:11 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-20250820T013236Z.dlist.zip.aes (882.54 KiB)
2025-08-21 10:03:12 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-20250820T013236Z.dlist.zip.aes (882.54 KiB)
2025-08-21 10:03:12 -04 - [Information-Duplicati.Library.Main.Operation.Backup.RecreateMissingIndexFiles-RecreateMissingIndexFile]: Re-creating missing index file for duplicati-bcd4ad0c8332b44a19ce0eee06b3c1848.dblock.zip.aes
2025-08-21 10:03:13 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-i07e2ff56507e46c6a9e5e73c7ce8b21c.dindex.zip.aes (5.34 KiB)
2025-08-21 10:03:14 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-i07e2ff56507e46c6a9e5e73c7ce8b21c.dindex.zip.aes (5.34 KiB)

I’m think that next I’ll switch to the Backblaze S3 interface (just did an rclone copy to a bucket that can do that), to see if I can get elusive (for me) 503 which I’ve seen before.

That will show that Backblaze can send them, even if I haven’t seen a native one lately.

[jberry02]

@ts678

@jberry02

As per my logs it is being treated as success.

Yes, but what are the surrounding circumstances about retries and renames?
Are your retries at default 5? Did it do any on the way to a wrong conclusion?

My reading of the log entries is that it did not do any retries - it received the 503 and called it success. It is always possible that I am reading it wrong, but unless the 503 is somehow out-of-sequence, it is treating 503 as success. If the 503 isn’t the cause, then something else is resulting in the missing file - I acknowledge that correlation != causation .

[ts678]

After not being able to get a 503 on B2 native or B2 S3, I was poking at the recent Minio client topic. Destination screen test was testing fine, but backup might have taken a 400 statusCode as success for 2 out of 11 dblock file uploads. In server log after the backup:

Duplicati.Library.Interface.RemoteListVerificationException: Found 2 files that are missing from the remote storage, please run repair
   at Duplicati.Library.Main.Operation.FilelistProcessor.VerifyRemoteList(IBackendManager backend, Options options, LocalDatabase database, IBackendWriter log, IEnumerable`1 protectedFiles, IEnumerable`1 strictExcemptFiles, Boolean logErrors, VerifyMode verifyMode, CancellationToken cancellationToken)
   at Duplicati.Library.Main.Operation.BackupHandler.PostBackupVerification(String currentFilelistVolume, String previousTemporaryFilelist, IBackendManager backendManager)
   at Duplicati.Library.Main.Operation.BackupHandler.RunAsync(String[] sources, IBackendManager backendManager, IFilter filter)
   at Duplicati.Library.Main.Operation.BackupHandler.RunAsync(String[] sources, IBackendManager backendManager, IFilter filter)
   at Duplicati.Library.Main.Controller.<>c__DisplayClass22_0.<<Backup>b__0>d.MoveNext()
--- End of stack trace from previous location ---
   at Duplicati.Library.Utility.Utility.Await(Task task)
   at Duplicati.Library.Main.Controller.RunAction[T](T result, String[]& paths, IFilter& filter, Func`3 method)
   at Duplicati.Library.Main.Controller.Backup(String[] inputsources, IFilter filter)
   at Duplicati.Server.Runner.RunInternal(Connection databaseConnection, EventPollNotify eventPollNotify, INotificationUpdateService notificationUpdateService, IProgressStateProviderService progressStateProviderService, IApplicationSettings applicationSettings, IRunnerData data, Boolean fromQueue)

It’s not always clear which statusCode goes with which transfer, but I’m going by proximity:

(summary of the now-missing files’ uploading activity using selected lines in original order)

2025-08-26 17:10:52 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-baf96ddb5dd0e4fce855b1a5534fc4dcc.dblock.zip.aes (9.94 MiB)
2025-08-26 17:10:52 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-bd65f07236ed34aaa9e05234c1c817c7f.dblock.zip.aes (9.93 MiB)
  statusCode          : 200
  statusCode          : 200
  pathAndQuery        : ... duplicati-baf96ddb5dd0e4fce855b1a5534fc4dcc.dblock.zip.aes?uploads=
  statusCode          : 200
  statusCode          : 200
  pathAndQuery        : ... duplicati-bd65f07236ed34aaa9e05234c1c817c7f.dblock.zip.aes?uploads=
  statusCode          : 200
  statusCode          : 200
  statusCode          : 200
  statusCode          : 200
  pathAndQuery        : ... duplicati-bd65f07236ed34aaa9e05234c1c817c7f.dblock.zip.aes ...
  pathAndQuery        : ... duplicati-baf96ddb5dd0e4fce855b1a5534fc4dcc.dblock.zip.aes ...
  statusCode          : -1
  statusCode          : -1
  pathAndQuery        : ... duplicati-baf96ddb5dd0e4fce855b1a5534fc4dcc.dblock.zip.aes ...
  pathAndQuery        : ... duplicati-bd65f07236ed34aaa9e05234c1c817c7f.dblock.zip.aes ...
  statusCode          : 400
  statusCode          : 400
  statusCode          : 400
  statusCode          : 400
2025-08-26 17:10:58 -04 - [Profiling-Duplicati.Library.Main.Backend.PutOperation-UploadSpeed]: Uploaded 9.93 MiB in 00:00:06.5485898, 1.52 MiB/s
2025-08-26 17:10:58 -04 - [Profiling-Duplicati.Library.Main.Backend.PutOperation-UploadSpeed]: Uploaded 9.94 MiB in 00:00:06.6684980, 1.49 MiB/s
2025-08-26 17:11:06 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-bd65f07236ed34aaa9e05234c1c817c7f.dblock.zip.aes (9.93 MiB)
2025-08-26 17:11:06 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-baf96ddb5dd0e4fce855b1a5534fc4dcc.dblock.zip.aes (9.94 MiB)
2025-08-26 17:12:21 -04 - [Warning-Duplicati.Library.Main.Operation.FilelistProcessor-MissingFile]: Missing file: duplicati-baf96ddb5dd0e4fce855b1a5534fc4dcc.dblock.zip.aes
2025-08-26 17:12:21 -04 - [Warning-Duplicati.Library.Main.Operation.FilelistProcessor-MissingFile]: Missing file: duplicati-bd65f07236ed34aaa9e05234c1c817c7f.dblock.zip.aes
2025-08-26 17:12:22 -04 - [Error-Duplicati.Library.Main.Controller-FailedOperation]: The operation Backup has failed

Taking the URL to BackendTester for a run worked, so maybe this is an intermittent issue.
Regardless, this backup is probably going to wait a bit before I run purge-broken-files.

[ts678]

I’m more inclined to fix up my production B2 S3 backup now that I got a solid bug repro:

S3 Minio client upload failure status code is treated as success

The repro isn’t 400 status though. That’s still a maybe-random mystery. Repro roughly:

Backup a file to B2 S3 AWS successfully, then make access ID invalid. Set the option upload-unchanged-backups=true so it tries to upload a dlist. number-of-retries=1 is an option which will trim some waiting. You can leave it at 5 if you like, or drop down to 0. Setting log-http-requests=true adds log information. no-backend-verification=true will avoid Duplicati getting alarmed by its upcoming inconsistency after using Minio client.

AWS client looks about like this in ngax Verbose live log:

Aug 28, 2025 7:25 AM: The operation Backup has failed
Aug 28, 2025 7:25 AM: Backend manager queue runner crashed
Aug 28, 2025 7:25 AM: Fatal error
Aug 28, 2025 7:25 AM: Error in handler: Malformed Access Key Id
Aug 28, 2025 7:25 AM: Backend event: Put - Failed: duplicati-20250828T112503Z.dlist.zip ()
Aug 28, 2025 7:25 AM: Operation Put with file duplicati-20250828T112503Z.dlist.zip attempt 2 of 1 failed with message: Malformed Access Key Id
Aug 28, 2025 7:25 AM: [System.Net.Http] Event: RequestStop statusCode : 403
Aug 28, 2025 7:25 AM: [System.Net.Http] Event: ResponseHeadersStop statusCode : 403
Aug 28, 2025 7:25 AM: [System.Net.Http] Event: RequestContentStop contentLength : 895
Aug 28, 2025 7:25 AM: [System.Net.Http] Event: RequestContentStart
Aug 28, 2025 7:25 AM: [System.Net.Http] Event: ResponseHeadersStart
Aug 28, 2025 7:25 AM: [System.Net.Http] Event: RequestHeadersStop
Aug 28, 2025 7:25 AM: [System.Net.Http] Event: RequestHeadersStart connectionId : 63
Aug 28, 2025 7:25 AM: [System.Net.Http] Event: RequestLeftQueue timeOnQueueMilliseconds: 292.0908 versionMajor : 1 versionMinor : 1
Aug 28, 2025 7:25 AM: [System.Net.Http] Event: ConnectionEstablished versionMajor : 1 versionMinor : 1 connectionId : 63 scheme : https host : s3.us-west-001.backblazeb2.com port : 443 remoteAddress : ...
Aug 28, 2025 7:25 AM: [System.Net.Http] Event: RequestStart scheme : https host : s3.us-west-001.backblazeb2.com port : 443 pathAndQuery : ... duplicati-20250828T112503Z.dlist.zip versionMajor : 1 versionMinor : 1 versionPolicy : 0
Aug 28, 2025 7:25 AM: Backend event: Put - Started: duplicati-20250828T112503Z.dlist.zip (721 bytes)
Aug 28, 2025 7:25 AM: Renaming "duplicati-20250828T112502Z.dlist.zip" to "duplicati-20250828T112503Z.dlist.zip"
Aug 28, 2025 7:25 AM: Backend event: Put - Rename: duplicati-20250828T112503Z.dlist.zip (721 bytes)
Aug 28, 2025 7:25 AM: Backend event: Put - Rename: duplicati-20250828T112502Z.dlist.zip (721 bytes)
Aug 28, 2025 7:25 AM: Backend event: Put - Retrying: duplicati-20250828T112502Z.dlist.zip ()
Aug 28, 2025 7:25 AM: Operation Put with file duplicati-20250828T112502Z.dlist.zip attempt 1 of 1 failed with message: Malformed Access Key Id
Aug 28, 2025 7:25 AM: [System.Net.Http] Event: RequestStop statusCode : 403
Aug 28, 2025 7:25 AM: [System.Net.Http] Event: RequestContentStop contentLength : 895
Aug 28, 2025 7:25 AM: [System.Net.Http] Event: ResponseHeadersStop statusCode : 403
Aug 28, 2025 7:25 AM: [System.Net.Http] Event: RequestContentStart
Aug 28, 2025 7:25 AM: [System.Net.Http] Event: ResponseHeadersStart
Aug 28, 2025 7:25 AM: [System.Net.Http] Event: RequestHeadersStop
Aug 28, 2025 7:25 AM: [System.Net.Http] Event: RequestHeadersStart connectionId : 62
Aug 28, 2025 7:25 AM: [System.Net.Http] Event: RequestLeftQueue timeOnQueueMilliseconds: 2478.4685 versionMajor : 1 versionMinor : 1
Aug 28, 2025 7:25 AM: [System.Net.Http] Event: ConnectionEstablished versionMajor : 1 versionMinor : 1 connectionId : 62 scheme : https host : s3.us-west-001.backblazeb2.com port : 443 remoteAddress : ...
Aug 28, 2025 7:25 AM: [System.Net.Http] Event: RequestStart scheme : https host : s3.us-west-001.backblazeb2.com port : 443 pathAndQuery : ... duplicati-20250828T112502Z.dlist.zip versionMajor : 1 versionMinor : 1 versionPolicy : 0
Aug 28, 2025 7:25 AM: Backend event: Put - Started: duplicati-20250828T112502Z.dlist.zip (721 bytes)
Aug 28, 2025 7:25 AM: Skipped checking file, because no metadata was updated C: ...
Aug 28, 2025 7:25 AM: The operation Backup has started

Switch to ngclient:

Aug 28, 2025 7:32 AM: A Task's exception(s) were not observed either by Waiting on the Task or accessing its Exception property. As a result, the unobserved exception was rethrown by the finalizer thread. (The CancellationTokenSource has been disposed.)
System.AggregateException: A Task's exception(s) were not observed either by Waiting on the Task or accessing its Exception property. As a result, the unobserved exception was rethrown by the finalizer thread. (The CancellationTokenSource has been disposed.)
 ---> System.ObjectDisposedException: The CancellationTokenSource has been disposed.
   at Duplicati.Server.Runner.<>c__DisplayClass16_2.<<RunInternal>b__3>d.MoveNext()
   --- End of inner exception stack trace ---
Aug 28, 2025 7:27 AM: The operation Backup has completed
Aug 28, 2025 7:27 AM: Backend event: Put - Completed: duplicati-20250828T112726Z.dlist.zip (722 bytes)
Aug 28, 2025 7:27 AM: [System.Net.Http] Event: RequestStop statusCode : 403
Aug 28, 2025 7:27 AM: [System.Net.Http] Event: ResponseHeadersStop statusCode : 403
Aug 28, 2025 7:27 AM: [System.Net.Http] Event: ResponseHeadersStart
Aug 28, 2025 7:27 AM: [System.Net.Http] Event: RequestContentStop contentLength : 722
Aug 28, 2025 7:27 AM: [System.Net.Http] Event: RequestContentStart
Aug 28, 2025 7:27 AM: [System.Net.Http] Event: RequestHeadersStop
Aug 28, 2025 7:27 AM: [System.Net.Http] Event: RequestHeadersStart connectionId : 65
Aug 28, 2025 7:27 AM: [System.Net.Http] Event: RequestStart scheme : https host : s3.us-west-001.backblazeb2.com port : 443 pathAndQuery :    duplicati-20250828T112726Z.dlist.zip versionMajor : 1 versionMinor : 1 versionPolicy : 0
Aug 28, 2025 7:27 AM: [System.Net.Http] Event: RequestStop statusCode : 403
Aug 28, 2025 7:27 AM: [System.Net.Http] Event: ResponseHeadersStop statusCode : 403
Aug 28, 2025 7:27 AM: [System.Net.Http] Event: ResponseHeadersStart
Aug 28, 2025 7:27 AM: [System.Net.Http] Event: RequestHeadersStop
Aug 28, 2025 7:27 AM: [System.Net.Http] Event: RequestHeadersStart connectionId : 65
Aug 28, 2025 7:27 AM: [System.Net.Http] Event: RequestLeftQueue timeOnQueueMilliseconds: 242.7239 versionMajor : 1 versionMinor : 1
Aug 28, 2025 7:27 AM: [System.Net.Http] Event: ConnectionEstablished versionMajor : 1 versionMinor : 1 connectionId : 65 scheme : https host : s3.us-west-001.backblazeb2.com port : 443 remoteAddress : ...
Aug 28, 2025 7:27 AM: [System.Net.Http] Event: ConnectionClosed versionMajor : 1 versionMinor : 1 connectionId : 64
Aug 28, 2025 7:27 AM: [System.Net.Http] Event: RequestStart scheme : https host : s3.us-west-001.backblazeb2.com port : 443 pathAndQuery : /bucket/ versionMajor : 1 versionMinor : 1 versionPolicy : 0
Aug 28, 2025 7:27 AM: Backend event: Put - Started: duplicati-20250828T112726Z.dlist.zip (722 bytes)
Aug 28, 2025 7:27 AM: Skipped checking file, because no metadata was updated C:\backup source\mini.iso
Aug 28, 2025 7:27 AM: Backend event: Delete - Completed: duplicati-20250828T112502Z.dlist.zip ()
Aug 28, 2025 7:27 AM: [System.Net.Http] Event: RequestStop statusCode : 403
Aug 28, 2025 7:27 AM: [System.Net.Http] Event: ResponseHeadersStop statusCode : 403
Aug 28, 2025 7:27 AM: [System.Net.Http] Event: ResponseHeadersStart
Aug 28, 2025 7:27 AM: [System.Net.Http] Event: RequestHeadersStop
Aug 28, 2025 7:27 AM: [System.Net.Http] Event: RequestHeadersStart connectionId : 64
Aug 28, 2025 7:27 AM: [System.Net.Http] Event: RequestStart scheme : https host : s3.us-west-001.backblazeb2.com port : 443 pathAndQuery : ... duplicati-20250828T112502Z.dlist.zip versionMajor : 1 versionMinor : 1 versionPolicy : 0
Aug 28, 2025 7:27 AM: Backend event: Delete - Started: duplicati-20250828T112502Z.dlist.zip ()
Aug 28, 2025 7:27 AM: Removing remote file listed as Deleting: duplicati-20250828T112502Z.dlist.zip
Aug 28, 2025 7:27 AM: Backend event: Delete - Completed: duplicati-20250828T112503Z.dlist.zip (721 bytes)
Aug 28, 2025 7:27 AM: [System.Net.Http] Event: RequestStop statusCode : 403
Aug 28, 2025 7:27 AM: [System.Net.Http] Event: ResponseHeadersStop statusCode : 403
Aug 28, 2025 7:27 AM: [System.Net.Http] Event: ResponseHeadersStart
Aug 28, 2025 7:27 AM: [System.Net.Http] Event: RequestHeadersStop
Aug 28, 2025 7:27 AM: [System.Net.Http] Event: RequestHeadersStart connectionId : 64
Aug 28, 2025 7:27 AM: [System.Net.Http] Event: RequestLeftQueue timeOnQueueMilliseconds: 243.484 versionMajor : 1 versionMinor : 1
Aug 28, 2025 7:27 AM: [System.Net.Http] Event: ConnectionEstablished versionMajor : 1 versionMinor : 1 connectionId : 64 scheme : https host : s3.us-west-001.backblazeb2.com port : 443 remoteAddress : ...
Aug 28, 2025 7:27 AM: [System.Net.Http] Event: RequestStart scheme : https host : s3.us-west-001.backblazeb2.com port : 443 pathAndQuery : ... duplicati-20250828T112503Z.dlist.zip versionMajor : 1 versionMinor : 1 versionPolicy : 0
Aug 28, 2025 7:27 AM: Backend event: Delete - Started: duplicati-20250828T112503Z.dlist.zip (721 bytes)
Aug 28, 2025 7:27 AM: Removing remote file listed as Uploading: duplicati-20250828T112503Z.dlist.zip
Aug 28, 2025 7:27 AM: The operation Backup has started

The new dlist is State Uploaded but actually it’s not there. Fix access key ID, remove the no-backend-verify, backup, get red popup “Found 5 files that are missing from the remote storage, please run repair” (because I’ve been testing awhile). Live log names file names:

Aug 28, 2025 8:07 AM: Missing file: duplicati-20250828T112726Z.dlist.zip
Aug 28, 2025 8:07 AM: Missing file: duplicati-20250828T003633Z.dlist.zip
Aug 28, 2025 8:07 AM: Missing file: duplicati-20250827T171745Z.dlist.zip
Aug 28, 2025 8:07 AM: Missing file: duplicati-20250827T171322Z.dlist.zip
Aug 28, 2025 8:07 AM: Missing file: duplicati-20250827T170040Z.dlist.zip

Top one there is our latest success-but-missing upload:

Aug 28, 2025 7:27 AM: Backend event: Put - Completed: duplicati-20250828T112726Z.dlist.zip (722 bytes)

Profiling log-file has:

2025-08-28 07:27:36 -04 - [Verbose-Duplicati.Library.Main.NetworkTrafficLogger.Http-ResponseHeadersStop]: [System.Net.Http] Event: ResponseHeadersStop
  statusCode          : 403

2025-08-28 07:27:36 -04 - [Verbose-Duplicati.Library.Main.NetworkTrafficLogger.Http-RequestStop]: [System.Net.Http] Event: RequestStop
  statusCode          : 403

2025-08-28 07:27:36 -04 - [Profiling-Duplicati.Library.Main.Backend.PutOperation-UploadSpeed]: Uploaded 722 bytes in 00:00:00.4348427, 1.62 KiB/s
2025-08-28 07:27:36 -04 - [Profiling-Timer.Begin-Duplicati.Library.Main.Operation.Common.DatabaseCommon-CommitTransactionAsync]: Starting - FlushBackendMessagesAndCommitAsync
2025-08-28 07:27:36 -04 - [Profiling-Timer.Finished-Duplicati.Library.Main.Operation.Common.DatabaseCommon-CommitTransactionAsync]: FlushBackendMessagesAndCommitAsync took 0:00:00:00.261
2025-08-28 07:27:36 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-20250828T112726Z.dlist.zip (722 bytes)
2025-08-28 07:27:36 -04 - [Profiling-Timer.Finished-Duplicati.Library.Main.Backend.Handler-RemoteOperationPut]: RemoteOperationPut took 0:00:00:01.502