Recreate database taking forever

Still looking for some information on what the original problem was that caused repair and later work. Though Duplicati is getting better at not breaking, it can definitely be painful (or impossible) if it does.

These are usually a bad one to see, and the “orphan file(s)” one (while rarer) isn’t encouraging either.
The “no associated blocks” check is another VerifyConsistency check that sees a problem, and stops. There’s at least one bug fix in 2.0.5.1 for this, but I don’t know if older versions can hold a latent error. These consistency errors are very generic, and there can be multiple ways to get to a given situation.

Agreed. An effort to improve Repair was launched once, but hasn’t come out yet. I don’t know if it’s on. Continued progress against breakage is underway (and helped by good bug reports), but there are so many ways that things can go astray in a complex design (which has its benefits) that it’s a tall order…

Unless someone has another idea beyond just trying various previously tried things again to see if the problem eventually clears, it’s probably time to ask @mmck what’s preferred if backup stays broken… Using it for restores might still be possible, especially using Duplicati.CommandLine.RecoveryTool.exe.

Considerations include value of old versions, storage cost of keeping damaged backup, and time with limited Internet speed. I wonder if it’s slower on uploads than downloads? There might be some exotic methods to hook current files up to dblock files again while rebuilding the seemingly bad bookkeeping.

I’m not sure to be honest what caused the problem.

One day it threw the error and wouldn’t run a backup, and told me to run repair/recreate. So I tried repair without too much question/interrogation. It didn’t work. So I ran a recreate. Which progressed through but gave the “missing blocks and 1 broken filelists error”.

It said to try list-broken-files and purge-broken-files. So I tried these which then let me run the backup, but at the end gave the “Unexpected difference in fileset version 0”. Tried list/purge again and its showing the same files each time.

I’ve tried relocating those files (39), and when I run list it still shows them in their original locations. I tried purge and I get:

ErrorID: CannotPurgeWithOrphans

Unable to start the purge process as there are 90 orphan file(s)

Return code: 100

Looking around lots of people seem to suggest a stop now or shutdown without the backup completing may have caused this. Both of which I have definitely done in the past, whether it is the cause of my issues or not I don’t know.

Maybe I’ll have to accept a full fresh backup. But on my horribly slow internet it will take weeks.

Yes, Duplicati does not currently handle that very gracefully, but effort is being made to fix it. For now it should be avoided.

I think the difficulty you are experiencing trying to repair/recover from this is unusual though.

What did you do to “relocate” the files? This was on your B2 bucket?

I just tried relocating them locally out of the backup to see if it would cause Duplicati to somehow stop flagging them.

If you copied them out of your B2 bucket and then tried deleting them, B2 is a bit interesting in how it behaves. Depending how you deleted the files, they may have been “soft deleted” and some programs will still see them. I ran across this over a year ago with Duplicati.

From what I recall the “soft deleted” files will be actually removed after 24 hours. Or you can use a tool like rclone to clean up the bucket.

Maybe that’s the issue you hit in your testing.

I’ve tried going back to an old database backup from December and re-running from that to see how things go.

If this fails I think I’ll give up and go for a new backup… I’m thinking for a new backup it may be best to split up the backups/buckets, so should something like this happen again I don’t need to reupload 200GB+, and instead would be just a smaller portion. But also added benefit should I have to ever recover anything I could easily chose and recover whichever backup I need most urgently first…

The only thought that comes to mind is that if there is any duplication across backups I won’t benefit from deduplication to reduce storage size/cost, but how I would split the backup would probably have little impact on this.

Any other thoughts/impacts I should consider?

The normal advice for initial slow upload used to be similar to your split-up idea, except important data would be backed up first and fully finished before adding another increment. Initial backup wasn’t even visible until it finished. In 2.0.5.1, the Stop button now has a “Stop after current file” version that’s been tested but not so much in the field. It’s kind of a delayed soft stop (work in process has to get finished).

An old database backup will almost certainly complain about extra files that it doesn’t know about, and Repair would regain consistency by deleting the unknown. Probably not the result that you really want. Missing file complaints might mean that Compacting files at the backend has repacked old dblock files (which got too empty) into new ones. I’m not sure what Repair would make of a totally unknown fileset.

I don’t know if @drwtsn32 has ever tried this, but the exotic idea I at least started looking at once was something like using a hand-made dlist file with an empty filelist (possibly just its two square brackets), allowing Duplicati Recreate to dutifully download and record all dindex files, with no dblock downloads.

Next, set –no-auto-compact=true and do a usual backup. Source files would be scanned, and attached onto already-uploaded blocks just like in a normal deduplication scenario without uploading all the data.

This seems like it would straighten out any DB record-keeping weirdness in addition to saving time, but truly missing dblock files could still be a problem, and I’m not sure at what point (if ever) they’d be seen.

The goal here is to see if something close to normal can be achieved. Maybe tools can fix up the rest…

So I tried creating a new backup (around 500mb of data), all seems fine and it starts progressing, but it then fails with the error log below.

Looking online at the bucket shows nothing uploaded. Makes me wonder if I have something more fundamentally broken with Duplicati.

Maybe this should be a new post as I’m now a long way from where I first started. Unless the problems are connected.

1 Mar 2020 21:49: Failed while executing "Backup" with id: 3
System.AggregateException: One or more errors occurred. ---> System.AggregateException: Could not find file 'C:\Users\m\AppData\Local\Temp\dup-4cfc8c71-738f-4102-97d6-938288f24147'. ---> System.IO.FileNotFoundException: Could not find file 'C:\Users\m\AppData\Local\Temp\dup-4cfc8c71-738f-4102-97d6-938288f24147'.
   at System.IO.__Error.WinIOError(Int32 errorCode, String maybeFullPath)
   at System.IO.FileStream.Init(String path, FileMode mode, FileAccess access, Int32 rights, Boolean useRights, FileShare share, Int32 bufferSize, FileOptions options, SECURITY_ATTRIBUTES secAttrs, String msgPath, Boolean bFromProxy, Boolean useLongPath, Boolean checkHost)
   at System.IO.FileStream..ctor(String path, FileMode mode, FileAccess access, FileShare share)
   at Duplicati.Library.Main.Operation.Backup.SpillCollectorProcess.<>c__DisplayClass0_0.<<Run>b__0>d.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 CoCoL.AutomationExtensions.<RunTask>d__10`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.Main.Operation.BackupHandler.<RunMainOperation>d__13.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.BackupHandler.<RunAsync>d__20.MoveNext()
   --- End of inner exception stack trace ---
   at Duplicati.Library.Main.Operation.BackupHandler.<RunAsync>d__20.MoveNext()
   --- End of inner exception stack trace ---
   at CoCoL.ChannelExtensions.WaitForTaskOrThrow(Task task)
   at Duplicati.Library.Main.Controller.<>c__DisplayClass14_0.<Backup>b__0(BackupResults result)
   at Duplicati.Library.Main.Controller.RunAction[T](T result, String[]& paths, IFilter& filter, Action`1 method)
   at Duplicati.Library.Main.Controller.Backup(String[] inputsources, IFilter filter)
   at Duplicati.Server.Runner.Run(IRunnerData data, Boolean fromQueue)
---> (Inner Exception #0) System.AggregateException: Could not find file 'C:\Users\m\AppData\Local\Temp\dup-4cfc8c71-738f-4102-97d6-938288f24147'. ---> System.IO.FileNotFoundException: Could not find file 'C:\Users\m\AppData\Local\Temp\dup-4cfc8c71-738f-4102-97d6-938288f24147'.
   at System.IO.__Error.WinIOError(Int32 errorCode, String maybeFullPath)
   at System.IO.FileStream.Init(String path, FileMode mode, FileAccess access, Int32 rights, Boolean useRights, FileShare share, Int32 bufferSize, FileOptions options, SECURITY_ATTRIBUTES secAttrs, String msgPath, Boolean bFromProxy, Boolean useLongPath, Boolean checkHost)
   at System.IO.FileStream..ctor(String path, FileMode mode, FileAccess access, FileShare share)
   at Duplicati.Library.Main.Operation.Backup.SpillCollectorProcess.<>c__DisplayClass0_0.<<Run>b__0>d.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 CoCoL.AutomationExtensions.<RunTask>d__10`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.Main.Operation.BackupHandler.<RunMainOperation>d__13.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.BackupHandler.<RunAsync>d__20.MoveNext()
   --- End of inner exception stack trace ---
   at Duplicati.Library.Main.Operation.BackupHandler.<RunAsync>d__20.MoveNext()
---> (Inner Exception #0) System.IO.FileNotFoundException: Could not find file 'C:\Users\m\AppData\Local\Temp\dup-4cfc8c71-738f-4102-97d6-938288f24147'.
File name: 'C:\Users\m\AppData\Local\Temp\dup-4cfc8c71-738f-4102-97d6-938288f24147'
   at System.IO.__Error.WinIOError(Int32 errorCode, String maybeFullPath)
   at System.IO.FileStream.Init(String path, FileMode mode, FileAccess access, Int32 rights, Boolean useRights, FileShare share, Int32 bufferSize, FileOptions options, SECURITY_ATTRIBUTES secAttrs, String msgPath, Boolean bFromProxy, Boolean useLongPath, Boolean checkHost)
   at System.IO.FileStream..ctor(String path, FileMode mode, FileAccess access, FileShare share)
   at Duplicati.Library.Main.Operation.Backup.SpillCollectorProcess.<>c__DisplayClass0_0.<<Run>b__0>d.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 CoCoL.AutomationExtensions.<RunTask>d__10`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.Main.Operation.BackupHandler.<RunMainOperation>d__13.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.BackupHandler.<RunAsync>d__20.MoveNext()<---

---> (Inner Exception #1) System.AggregateException: One or more errors occurred. ---> System.IO.IOException: Unable to read data from the transport connection: The connection was closed.
   at System.Net.ConnectStream.EndWrite(IAsyncResult asyncResult)
   at System.IO.Stream.<>c.<BeginEndWriteAsync>b__53_1(Stream stream, IAsyncResult asyncResult)
   at System.Threading.Tasks.TaskFactory`1.FromAsyncTrimPromise`1.Complete(TInstance thisRef, Func`3 endMethod, IAsyncResult asyncResult, Boolean requiresSynchronization)
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at Duplicati.Library.Utility.Utility.<CopyStreamAsync>d__11.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.Utility.Utility.<CopyStreamAsync>d__10.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.<>c__DisplayClass28_0.<<PutAsync>b__1>d.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__21.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__DisplayClass17_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__18.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__18.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.<UploadFileAsync>d__17.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.<UploadBlockAndIndexAsync>d__15.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.<<Run>b__13_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.<<Run>b__13_0>d.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 CoCoL.AutomationExtensions.<RunTask>d__10`1.MoveNext()
   --- End of inner exception stack trace ---
---> (Inner Exception #0) System.IO.IOException: Unable to read data from the transport connection: The connection was closed.
   at System.Net.ConnectStream.EndWrite(IAsyncResult asyncResult)
   at System.IO.Stream.<>c.<BeginEndWriteAsync>b__53_1(Stream stream, IAsyncResult asyncResult)
   at System.Threading.Tasks.TaskFactory`1.FromAsyncTrimPromise`1.Complete(TInstance thisRef, Func`3 endMethod, IAsyncResult asyncResult, Boolean requiresSynchronization)
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at Duplicati.Library.Utility.Utility.<CopyStreamAsync>d__11.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.Utility.Utility.<CopyStreamAsync>d__10.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.<>c__DisplayClass28_0.<<PutAsync>b__1>d.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__21.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__DisplayClass17_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__18.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__18.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.<UploadFileAsync>d__17.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.<UploadBlockAndIndexAsync>d__15.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.<<Run>b__13_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.<<Run>b__13_0>d.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 CoCoL.AutomationExtensions.<RunTask>d__10`1.MoveNext()<---
<---
<---

Looking at the live log I’m getting these errors:

Unable to read data from the transport connection: The connection was closed.

503 - service_unavailable: c000_v0001066_t0046 is too busy

Tried deleting the new backup test and the new B2 bucket and trying again.

It found about 900mb of files, zoomed through progress of 400mb in about 10 seconds (bearing in mind i have about 100 KB/s up this is obviously wrong), then gets stuck and fails again.

Are you using any antimalware software? The software used on my work PC will sometimes block access to Duplicati temp files, causing that type of error message.

On my personal machines I just use the standard antimalware software included in Win10, and I don’t think I’ve ever had it happen.

This is ‘normal’ behavior of B2. Duplicati should re-try and succeed. See this for more info:

What To Do When You Get a B2 503 (or 500) Server Error

Just try again — it’s free, easy, and will work.

If you look at the logs at Retry level or higher, you should see these up to about 5 retries default.

The other error is hard to explain. I don’t get those to my B2. Do these seems to be related at all?

Using just the built in Win10 antimalware.

Yes it tries 5 times and fails. I tried running the backup multiple times with same outcome.

There were two issues reported, “Could not find file” and B2 “is too busy”. Is outcome both?
If so, please post the sequence, maybe a set of 503 plus at least top of “Could not find file”.

Discussion below is to give background and more details than I really need to see, but I need some…

503 errors from B2 should retry per Advanced options –number-of-retries (default 5) with –retry-delay (default 10) seconds in between, with a different upload name each time (assuming this is on upload).

The algorithm at Backblaze should probably generally send you to a different server for the retry, so if that doesn’t happen then it may be their problem. In examples below, note how both names changed:

2020-02-02 21:01:05 -05 - [Retry-Duplicati.Library.Main.Operation.Backup.BackendUploader-RetryPut]: Operation Put with file duplicati-20200203T020000Z.dlist.zip.aes attempt 1 of 5 failed with message: 503 - service_unavailable: c001_v0001113_t0057 is too busy
System.Exception: 503 - service_unavailable: c001_v0001113_t0057 is too busy

2020-02-02 21:01:15 -05 - [Information-Duplicati.Library.Main.Operation.Backup.BackendUploader-RenameRemoteTargetFile]: Renaming “duplicati-20200203T020000Z.dlist.zip.aes” to “duplicati-20200203T020001Z.dlist.zip.aes”

2020-02-02 21:01:20 -05 - [Retry-Duplicati.Library.Main.Operation.Backup.BackendUploader-RetryPut]: Operation Put with file duplicati-20200203T020001Z.dlist.zip.aes attempt 2 of 5 failed with message: 503 - service_unavailable: c001_v0001113_t0030 is too busy
System.Exception: 503 - service_unavailable: c001_v0001113_t0030 is too busy

2020-02-02 21:01:30 -05 - [Information-Duplicati.Library.Main.Operation.Backup.BackendUploader-RenameRemoteTargetFile]: Renaming “duplicati-20200203T020001Z.dlist.zip.aes” to “duplicati-20200203T020002Z.dlist.zip.aes”

2020-02-02 21:01:35 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-20200203T020002Z.dlist.zip.aes (43.29 KB)

For the uploaded filename using a seemingly random name, it’s similar, with a new filename, like:

2020-02-04 07:28:02 -05 - [Retry-Duplicati.Library.Main.Operation.Backup.BackendUploader-RetryPut]: Operation Put with file duplicati-b3331ee4d29ea418e9ed6b2d5061b4854.dblock.zip.aes attempt 1 of 5 failed with message: 503 - service_unavailable: c001_v0001113_t0032 is too busy
System.Exception: 503 - service_unavailable: c001_v0001113_t0032 is too busy

2020-02-04 07:28:12 -05 - [Information-Duplicati.Library.Main.Operation.Backup.BackendUploader-RenameRemoteTargetFile]: Renaming “duplicati-b3331ee4d29ea418e9ed6b2d5061b4854.dblock.zip.aes” to “duplicati-b1211a69d452243ff82b7de8abe1ec033.dblock.zip.aes”

2020-02-04 07:30:48 -05 - [Retry-Duplicati.Library.Main.Operation.Backup.BackendUploader-RetryPut]: Operation Put with file duplicati-b1211a69d452243ff82b7de8abe1ec033.dblock.zip.aes attempt 2 of 5 failed with message: 503 - service_unavailable: c001_v0001113_t0059 is too busy
System.Exception: 503 - service_unavailable: c001_v0001113_t0059 is too busy

2020-02-04 07:30:58 -05 - [Information-Duplicati.Library.Main.Operation.Backup.BackendUploader-RenameRemoteTargetFile]: Renaming “duplicati-b1211a69d452243ff82b7de8abe1ec033.dblock.zip.aes” to “duplicati-b68534a3df77e4f8dbfd56a2452bc8320.dblock.zip.aes”

2020-02-04 07:34:10 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-b68534a3df77e4f8dbfd56a2452bc8320.dblock.zip.aes (14.85 MB)

In above hourly backup log going back to January, B2 never used more than 3 tries, so yours is odd.
What would be even odder would be if B2 always kept directing you to the same “is too busy” server.

Please take a close look at your logs to at least confirm Duplicati and B2 changed names each retry.
And was the missing temporary file at the end? If so, perhaps mystery retry exhaustion can cause it.
If not, where was it? Please either post a view of 503 and “Could not find file” errors, or look yourself.

Yes this was happening.

I have tried creating a new backup this evening. I did a very quick 1 folder / 10mb and it went through okay.

Still no luck on the old backup but think I will persevere with a new backup and split it this time to hopefully minimise potential future corruption.

Admittedly it will all be less of a headache in a few months once I have fibre and can upload at a reasonable speed.

and the B2 server also is different each time? And does the “Could not find file” happen? If so, when?

FWIW I set retries to 0 to see if I could get “Could not find file” from them. I haven’t so far but I did get:

2020-03-02 20:00:37 -05 - [Retry-Duplicati.Library.Main.Operation.Backup.BackendUploader-RetryPut]: Operation Put with file duplicati-bc2c2c5cefa0e47d693f519bbef57528c.dblock.zip.aes attempt 1 of 0 failed with message: 503 - service_unavailable: Tome is overly busy
System.Exception: 503 - service_unavailable: Tome is overly busy

2020-03-03 08:00:47 -05 - [Retry-Duplicati.Library.Main.Operation.Backup.BackendUploader-RetryPut]: Operation Put with file duplicati-b166c77913ac042e7855d4a399923f6bf.dblock.zip.aes attempt 1 of 0 failed with message: 503 - service_unavailable: c001_v0001113_t0005 is too busy
System.Exception: 503 - service_unavailable: c001_v0001113_t0005 is too busy

2020-03-03 12:00:47 -05 - [Retry-Duplicati.Library.Main.Operation.Backup.BackendUploader-RetryPut]: Operation Put with file duplicati-b0beba310cf1843db92254b17256a4a9b.dblock.zip.aes attempt 1 of 0 failed with message: 503 - service_unavailable: c001_v0001113_t0014 is too busy
System.Exception: 503 - service_unavailable: c001_v0001113_t0014 is too busy

2020-03-03 13:03:00 -05 - [Retry-Duplicati.Library.Main.Operation.Backup.BackendUploader-RetryPut]: Operation Put with file duplicati-20200303T180218Z.dlist.zip.aes attempt 1 of 0 failed with message: 503 - service_unavailable: c001_v0001113_t0024 is too busy
System.Exception: 503 - service_unavailable: c001_v0001113_t0024 is too busy

Basically, Backblaze B2 is working as promised for me. If it gets overloaded somewhere, it tells me…
If it’s repeatedly steering you to the same overload, which it’s not for me, you could ask them about it.
Give them what I’m trying to get you to post here, which is proof of the same error from same system.
There’s nothing that I know of in Duplicati that causes B2 503 errors, or avoids them (besides retries).

Or maybe somehow things are OK now? I don’t know why your small backup would do better. Are you using a larger-than-the-50-MB-default remote volume size on screen 5, or any other unusual settings?

Using all the defaults incl. 50MB. Just inputting the basics (bucket id and credentials).

Can’t get the same error as before to appear.

New day, new error:

System.AggregateException: One or more errors occurred. ---> System.AggregateException: The channel "BackendRequests" is retired ---> CoCoL.RetiredException: The channel "BackendRequests" is retired
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at CoCoL.Channel`1.<WriteAsync>d__32.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.BackupHandler.<FlushBackend>d__19.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.BackupHandler.<RunAsync>d__20.MoveNext()
   --- End of inner exception stack trace ---
   at Duplicati.Library.Main.Operation.BackupHandler.<RunAsync>d__20.MoveNext()
   --- End of inner exception stack trace ---
   at CoCoL.ChannelExtensions.WaitForTaskOrThrow(Task task)
   at Duplicati.Library.Main.Controller.<>c__DisplayClass14_0.<Backup>b__0(BackupResults result)
   at Duplicati.Library.Main.Controller.RunAction[T](T result, String[]& paths, IFilter& filter, Action`1 method)
   at Duplicati.Library.Main.Controller.Backup(String[] inputsources, IFilter filter)
   at Duplicati.Server.Runner.Run(IRunnerData data, Boolean fromQueue)
---> (Inner Exception #0) System.AggregateException: The channel "BackendRequests" is retired ---> CoCoL.RetiredException: The channel "BackendRequests" is retired
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at CoCoL.Channel`1.<WriteAsync>d__32.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.BackupHandler.<FlushBackend>d__19.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.BackupHandler.<RunAsync>d__20.MoveNext()
   --- End of inner exception stack trace ---
   at Duplicati.Library.Main.Operation.BackupHandler.<RunAsync>d__20.MoveNext()
---> (Inner Exception #0) CoCoL.RetiredException: The channel "BackendRequests" is retired
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at CoCoL.Channel`1.<WriteAsync>d__32.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.BackupHandler.<FlushBackend>d__19.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.BackupHandler.<RunAsync>d__20.MoveNext()<---

---> (Inner Exception #1) System.AggregateException: One or more errors occurred. ---> System.IO.IOException: Unable to read data from the transport connection: The connection was closed.
   at System.Net.ConnectStream.EndWrite(IAsyncResult asyncResult)
   at System.IO.Stream.<>c.<BeginEndWriteAsync>b__53_1(Stream stream, IAsyncResult asyncResult)
   at System.Threading.Tasks.TaskFactory`1.FromAsyncTrimPromise`1.Complete(TInstance thisRef, Func`3 endMethod, IAsyncResult asyncResult, Boolean requiresSynchronization)
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at Duplicati.Library.Utility.Utility.<CopyStreamAsync>d__11.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.Utility.Utility.<CopyStreamAsync>d__10.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.<>c__DisplayClass28_0.<<PutAsync>b__1>d.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__21.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__DisplayClass17_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__18.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__18.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.<UploadFileAsync>d__17.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.<UploadBlockAndIndexAsync>d__15.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.<<Run>b__13_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.<<Run>b__13_0>d.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 CoCoL.AutomationExtensions.<RunTask>d__10`1.MoveNext()
   --- End of inner exception stack trace ---
---> (Inner Exception #0) System.IO.IOException: Unable to read data from the transport connection: The connection was closed.
   at System.Net.ConnectStream.EndWrite(IAsyncResult asyncResult)
   at System.IO.Stream.<>c.<BeginEndWriteAsync>b__53_1(Stream stream, IAsyncResult asyncResult)
   at System.Threading.Tasks.TaskFactory`1.FromAsyncTrimPromise`1.Complete(TInstance thisRef, Func`3 endMethod, IAsyncResult asyncResult, Boolean requiresSynchronization)
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at Duplicati.Library.Utility.Utility.<CopyStreamAsync>d__11.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.Utility.Utility.<CopyStreamAsync>d__10.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.<>c__DisplayClass28_0.<<PutAsync>b__1>d.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__21.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__DisplayClass17_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__18.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__18.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.<UploadFileAsync>d__17.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.<UploadBlockAndIndexAsync>d__15.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.<<Run>b__13_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.<<Run>b__13_0>d.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 CoCoL.AutomationExtensions.<RunTask>d__10`1.MoveNext()<---
<---
<---

I think “The channel … is retired” means something went wrong earlier, and things are shutting down.

Possibly you can find something else in the log, otherwise I’ll pick on this earlier one that was posted:

---> (Inner Exception #1) System.AggregateException: One or more errors occurred. ---> System.IO.IOException: Unable to read data from the transport connection: The connection was closed.
   at System.Net.ConnectStream.EndWrite(IAsyncResult asyncResult)
   at System.IO.Stream.<>c.<BeginEndWriteAsync>b__53_1(Stream stream, IAsyncResult asyncResult)
   at System.Threading.Tasks.TaskFactory`1.FromAsyncTrimPromise`1.Complete(TInstance thisRef, Func`3 endMethod, IAsyncResult asyncResult, Boolean requiresSynchronization)
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at Duplicati.Library.Utility.Utility.<CopyStreamAsync>d__11.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.Utility.Utility.<CopyStreamAsync>d__10.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.<>c__DisplayClass28_0.<<PutAsync>b__1>d.MoveNext()

is possibly B2 closing the connection on you, or it could be a problem on the network – unlike the 503 exception which almost certainly is from the remote, I suspect this died while trying to read the status.

Reference Source from Microsoft is possibly the routine, but I’m not going to claim to be expert in that.

The rate of these for my backups depends on the backend, with Google Drive perfect, OneDrive got 1, and Backblaze B2 got 5, all since mid-January using the same source files. Recovery was auto-retries:

2020-01-28 23:00:44 -05 - [Retry-Duplicati.Library.Main.Operation.Backup.BackendUploader-RetryPut]: Operation Put with file duplicati-b53b35a0f2e63419b9c9e1703b06a3419.dblock.zip.aes attempt 1 of 5 failed with message: 503 - service_unavailable: c001_v0001113_t0041 is too busy
System.Exception: 503 - service_unavailable: c001_v0001113_t0041 is too busy

2020-01-28 23:00:54 -05 - [Information-Duplicati.Library.Main.Operation.Backup.BackendUploader-RenameRemoteTargetFile]: Renaming "duplicati-b53b35a0f2e63419b9c9e1703b06a3419.dblock.zip.aes" to "duplicati-b7638c52fc7b64354a30fe7cd5966ed3f.dblock.zip.aes"

2020-01-29 08:06:04 -05 - [Retry-Duplicati.Library.Main.Operation.Backup.BackendUploader-RetryPut]: Operation Put with file duplicati-b7638c52fc7b64354a30fe7cd5966ed3f.dblock.zip.aes attempt 2 of 5 failed with message: Unable to read data from the transport connection: The connection was closed.
System.IO.IOException: Unable to read data from the transport connection: The connection was closed.
   at System.Net.ConnectStream.IOError(Exception exception, Boolean willThrow)
   at System.Net.ConnectStream.EndWrite(IAsyncResult asyncResult)
   at System.IO.Stream.<>c.<BeginEndWriteAsync>b__53_1(Stream stream, IAsyncResult asyncResult)
   at System.Threading.Tasks.TaskFactory`1.FromAsyncTrimPromise`1.Complete(TInstance thisRef, Func`3 endMethod, IAsyncResult asyncResult, Boolean requiresSynchronization)
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at Duplicati.Library.Utility.Utility.<CopyStreamAsync>d__11.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.Utility.Utility.<CopyStreamAsync>d__10.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.<>c__DisplayClass28_0.<<PutAsync>b__1>d.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()

2020-01-29 08:06:15 -05 - [Information-Duplicati.Library.Main.Operation.Backup.BackendUploader-RenameRemoteTargetFile]: Renaming "duplicati-b7638c52fc7b64354a30fe7cd5966ed3f.dblock.zip.aes" to "duplicati-b2ce1ef3ef90b42ba87a0384c992fcea5.dblock.zip.aes"

2020-01-29 08:07:35 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-b2ce1ef3ef90b42ba87a0384c992fcea5.dblock.zip.aes (40.46 MB)

is interesting because it got a 503 before “The connection was closed.” My other four stood alone.

I don’t know why yours is losing its connection. It might be B2, or it might be a local network issue.

Network issues can be debugged, but it’s quite advanced stuff, with packet capture and analysis…

Then a Duplicati question is why yours went to “channel is retired”. Were there any earlier retries?

I tried reducing the block size down to 20MB to see if that would help (say if its timing out for some reason due to my slow connection). Anyway same errors. This is an extract from the live log, nothing is getting uploaded looking at B2 bucket online:

* 4 Mar 2020 12:40: Backend event: Put - Started: duplicati-bf0193e85513742b59f69572158ec8bf3.dblock.zip.aes (19.98 MB)

* 4 Mar 2020 12:40: ExecuteScalarInt64: INSERT INTO "Remotevolume" ("OperationID", "Name", "Type", "State", "Size", "VerificationCount", "DeleteGraceTime") VALUES (7, "duplicati-bb3bff12f540e4e3fb9855f6cb1176e09.dblock.zip.aes", "Blocks", "Deleting", -1, 0, 0); SELECT last_insert_rowid(); took 0:00:00:00.000

* 4 Mar 2020 12:40: Starting - ExecuteScalarInt64: INSERT INTO "Remotevolume" ("OperationID", "Name", "Type", "State", "Size", "VerificationCount", "DeleteGraceTime") VALUES (7, "duplicati-bb3bff12f540e4e3fb9855f6cb1176e09.dblock.zip.aes", "Blocks", "Deleting", -1, 0, 0); SELECT last_insert_rowid();

* 4 Mar 2020 12:40: ExecuteScalar: SELECT "Type" FROM "Remotevolume" WHERE "Name" = "duplicati-bf0193e85513742b59f69572158ec8bf3.dblock.zip.aes" took 0:00:00:00.000

* 4 Mar 2020 12:40: Starting - ExecuteScalar: SELECT "Type" FROM "Remotevolume" WHERE "Name" = "duplicati-bf0193e85513742b59f69572158ec8bf3.dblock.zip.aes"

* 4 Mar 2020 12:40: ExecuteNonQuery: UPDATE "Remotevolume" SET "Name" = "duplicati-bf0193e85513742b59f69572158ec8bf3.dblock.zip.aes" WHERE "Name" = "duplicati-bb3bff12f540e4e3fb9855f6cb1176e09.dblock.zip.aes" took 0:00:00:00.000

* 4 Mar 2020 12:40: Starting - ExecuteNonQuery: UPDATE "Remotevolume" SET "Name" = "duplicati-bf0193e85513742b59f69572158ec8bf3.dblock.zip.aes" WHERE "Name" = "duplicati-bb3bff12f540e4e3fb9855f6cb1176e09.dblock.zip.aes"

* 4 Mar 2020 12:40: Renaming "duplicati-bb3bff12f540e4e3fb9855f6cb1176e09.dblock.zip.aes" to "duplicati-bf0193e85513742b59f69572158ec8bf3.dblock.zip.aes"

* 4 Mar 2020 12:40: Backend event: Put - Rename: duplicati-bf0193e85513742b59f69572158ec8bf3.dblock.zip.aes (19.98 MB)

* 4 Mar 2020 12:40: Backend event: Put - Rename: duplicati-bb3bff12f540e4e3fb9855f6cb1176e09.dblock.zip.aes (19.98 MB)

* 4 Mar 2020 12:40: Backend event: Put - Retrying: duplicati-bb3bff12f540e4e3fb9855f6cb1176e09.dblock.zip.aes (19.98 MB)

* 4 Mar 2020 12:40: Operation Put with file duplicati-bb3bff12f540e4e3fb9855f6cb1176e09.dblock.zip.aes attempt 3 of 5 failed with message: Unable to read data from the transport connection: The connection was closed.

* 4 Mar 2020 12:37: Backend event: Put - Started: duplicati-b088aa22572d8424ab19088289434046f.dblock.zip.aes (19.98 MB)

* 4 Mar 2020 12:37: ExecuteScalarInt64: INSERT INTO "Remotevolume" ("OperationID", "Name", "Type", "State", "Size", "VerificationCount", "DeleteGraceTime") VALUES (7, "duplicati-b7a9317d8bb854a91b7a048403f2c072f.dblock.zip.aes", "Blocks", "Deleting", -1, 0, 0); SELECT last_insert_rowid(); took 0:00:00:00.000

* 4 Mar 2020 12:37: Starting - ExecuteScalarInt64: INSERT INTO "Remotevolume" ("OperationID", "Name", "Type", "State", "Size", "VerificationCount", "DeleteGraceTime") VALUES (7, "duplicati-b7a9317d8bb854a91b7a048403f2c072f.dblock.zip.aes", "Blocks", "Deleting", -1, 0, 0); SELECT last_insert_rowid();

* 4 Mar 2020 12:37: ExecuteScalar: SELECT "Type" FROM "Remotevolume" WHERE "Name" = "duplicati-b088aa22572d8424ab19088289434046f.dblock.zip.aes" took 0:00:00:00.000

* 4 Mar 2020 12:37: Starting - ExecuteScalar: SELECT "Type" FROM "Remotevolume" WHERE "Name" = "duplicati-b088aa22572d8424ab19088289434046f.dblock.zip.aes"

* 4 Mar 2020 12:37: ExecuteNonQuery: UPDATE "Remotevolume" SET "Name" = "duplicati-b088aa22572d8424ab19088289434046f.dblock.zip.aes" WHERE "Name" = "duplicati-b7a9317d8bb854a91b7a048403f2c072f.dblock.zip.aes" took 0:00:00:00.000

* 4 Mar 2020 12:37: Starting - ExecuteNonQuery: UPDATE "Remotevolume" SET "Name" = "duplicati-b088aa22572d8424ab19088289434046f.dblock.zip.aes" WHERE "Name" = "duplicati-b7a9317d8bb854a91b7a048403f2c072f.dblock.zip.aes"

* 4 Mar 2020 12:37: Renaming "duplicati-b7a9317d8bb854a91b7a048403f2c072f.dblock.zip.aes" to "duplicati-b088aa22572d8424ab19088289434046f.dblock.zip.aes"

* 4 Mar 2020 12:37: Backend event: Put - Rename: duplicati-b088aa22572d8424ab19088289434046f.dblock.zip.aes (19.98 MB)

* 4 Mar 2020 12:37: Backend event: Put - Rename: duplicati-b7a9317d8bb854a91b7a048403f2c072f.dblock.zip.aes (19.98 MB)

* 4 Mar 2020 12:37: Backend event: Put - Retrying: duplicati-b7a9317d8bb854a91b7a048403f2c072f.dblock.zip.aes (19.98 MB)

* 4 Mar 2020 12:37: Operation Put with file duplicati-b7a9317d8bb854a91b7a048403f2c072f.dblock.zip.aes attempt 3 of 5 failed with message: Unable to read data from the transport connection: The connection was closed.

* 4 Mar 2020 12:37: Backend event: Put - Started: duplicati-bb3bff12f540e4e3fb9855f6cb1176e09.dblock.zip.aes (19.98 MB)

* 4 Mar 2020 12:37: ExecuteScalarInt64: INSERT INTO "Remotevolume" ("OperationID", "Name", "Type", "State", "Size", "VerificationCount", "DeleteGraceTime") VALUES (7, "duplicati-ba102769d04914f0bb8e6276d9a8c3fe2.dblock.zip.aes", "Blocks", "Deleting", -1, 0, 0); SELECT last_insert_rowid(); took 0:00:00:00.000

* 4 Mar 2020 12:37: Starting - ExecuteScalarInt64: INSERT INTO "Remotevolume" ("OperationID", "Name", "Type", "State", "Size", "VerificationCount", "DeleteGraceTime") VALUES (7, "duplicati-ba102769d04914f0bb8e6276d9a8c3fe2.dblock.zip.aes", "Blocks", "Deleting", -1, 0, 0); SELECT last_insert_rowid();

* 4 Mar 2020 12:37: ExecuteScalar: SELECT "Type" FROM "Remotevolume" WHERE "Name" = "duplicati-bb3bff12f540e4e3fb9855f6cb1176e09.dblock.zip.aes" took 0:00:00:00.000

* 4 Mar 2020 12:37: Starting - ExecuteScalar: SELECT "Type" FROM "Remotevolume" WHERE "Name" = "duplicati-bb3bff12f540e4e3fb9855f6cb1176e09.dblock.zip.aes"

* 4 Mar 2020 12:37: ExecuteNonQuery: UPDATE "Remotevolume" SET "Name" = "duplicati-bb3bff12f540e4e3fb9855f6cb1176e09.dblock.zip.aes" WHERE "Name" = "duplicati-ba102769d04914f0bb8e6276d9a8c3fe2.dblock.zip.aes" took 0:00:00:00.000

* 4 Mar 2020 12:37: Starting - ExecuteNonQuery: UPDATE "Remotevolume" SET "Name" = "duplicati-bb3bff12f540e4e3fb9855f6cb1176e09.dblock.zip.aes" WHERE "Name" = "duplicati-ba102769d04914f0bb8e6276d9a8c3fe2.dblock.zip.aes"

* 4 Mar 2020 12:37: Renaming "duplicati-ba102769d04914f0bb8e6276d9a8c3fe2.dblock.zip.aes" to "duplicati-bb3bff12f540e4e3fb9855f6cb1176e09.dblock.zip.aes"

* 4 Mar 2020 12:37: Backend event: Put - Rename: duplicati-bb3bff12f540e4e3fb9855f6cb1176e09.dblock.zip.aes (19.98 MB)

* 4 Mar 2020 12:37: Backend event: Put - Rename: duplicati-ba102769d04914f0bb8e6276d9a8c3fe2.dblock.zip.aes (19.98 MB)

* 4 Mar 2020 12:37: Backend event: Put - Retrying: duplicati-ba102769d04914f0bb8e6276d9a8c3fe2.dblock.zip.aes (19.98 MB)

* 4 Mar 2020 12:37: Operation Put with file duplicati-ba102769d04914f0bb8e6276d9a8c3fe2.dblock.zip.aes attempt 2 of 5 failed with message: Unable to read data from the transport connection: The connection was closed.

* 4 Mar 2020 12:36: Backend event: Put - Started: duplicati-bbe463b3c1cc641c99dd9f90d837766a6.dblock.zip.aes (19.94 MB)

* 4 Mar 2020 12:36: ExecuteScalarInt64: INSERT INTO "Remotevolume" ("OperationID", "Name", "Type", "State", "Size", "VerificationCount", "DeleteGraceTime") VALUES (7, "duplicati-b64c0cd1421694190b40180fb1170d615.dblock.zip.aes", "Blocks", "Deleting", -1, 0, 0); SELECT last_insert_rowid(); took 0:00:00:00.000

* 4 Mar 2020 12:36: Starting - ExecuteScalarInt64: INSERT INTO "Remotevolume" ("OperationID", "Name", "Type", "State", "Size", "VerificationCount", "DeleteGraceTime") VALUES (7, "duplicati-b64c0cd1421694190b40180fb1170d615.dblock.zip.aes", "Blocks", "Deleting", -1, 0, 0); SELECT last_insert_rowid();

* 4 Mar 2020 12:36: ExecuteScalar: SELECT "Type" FROM "Remotevolume" WHERE "Name" = "duplicati-bbe463b3c1cc641c99dd9f90d837766a6.dblock.zip.aes" took 0:00:00:00.000

* 4 Mar 2020 12:36: Starting - ExecuteScalar: SELECT "Type" FROM "Remotevolume" WHERE "Name" = "duplicati-bbe463b3c1cc641c99dd9f90d837766a6.dblock.zip.aes"

* 4 Mar 2020 12:36: ExecuteNonQuery: UPDATE "Remotevolume" SET "Name" = "duplicati-bbe463b3c1cc641c99dd9f90d837766a6.dblock.zip.aes" WHERE "Name" = "duplicati-b64c0cd1421694190b40180fb1170d615.dblock.zip.aes" took 0:00:00:00.000

* 4 Mar 2020 12:36: Starting - ExecuteNonQuery: UPDATE "Remotevolume" SET "Name" = "duplicati-bbe463b3c1cc641c99dd9f90d837766a6.dblock.zip.aes" WHERE "Name" = "duplicati-b64c0cd1421694190b40180fb1170d615.dblock.zip.aes"

* 4 Mar 2020 12:36: Renaming "duplicati-b64c0cd1421694190b40180fb1170d615.dblock.zip.aes" to "duplicati-bbe463b3c1cc641c99dd9f90d837766a6.dblock.zip.aes"

* 4 Mar 2020 12:36: Backend event: Put - Rename: duplicati-bbe463b3c1cc641c99dd9f90d837766a6.dblock.zip.aes (19.94 MB)

* 4 Mar 2020 12:36: Backend event: Put - Rename: duplicati-b64c0cd1421694190b40180fb1170d615.dblock.zip.aes (19.94 MB)

* 4 Mar 2020 12:36: Backend event: Put - Retrying: duplicati-b64c0cd1421694190b40180fb1170d615.dblock.zip.aes (19.94 MB)

* 4 Mar 2020 12:36: Operation Put with file duplicati-b64c0cd1421694190b40180fb1170d615.dblock.zip.aes attempt 2 of 5 failed with message: Unable to read data from the transport connection: The connection was closed.

* 4 Mar 2020 12:35: Backend event: Put - Started: duplicati-b7a9317d8bb854a91b7a048403f2c072f.dblock.zip.aes (19.98 MB)

* 4 Mar 2020 12:35: ExecuteScalarInt64: INSERT INTO "Remotevolume" ("OperationID", "Name", "Type", "State", "Size", "VerificationCount", "DeleteGraceTime") VALUES (7, "duplicati-bafb2f9e34439415f880ecd85692c725c.dblock.zip.aes", "Blocks", "Deleting", -1, 0, 0); SELECT last_insert_rowid(); took 0:00:00:00.000

* 4 Mar 2020 12:35: Starting - ExecuteScalarInt64: INSERT INTO "Remotevolume" ("OperationID", "Name", "Type", "State", "Size", "VerificationCount", "DeleteGraceTime") VALUES (7, "duplicati-bafb2f9e34439415f880ecd85692c725c.dblock.zip.aes", "Blocks", "Deleting", -1, 0, 0); SELECT last_insert_rowid();

* 4 Mar 2020 12:35: ExecuteScalar: SELECT "Type" FROM "Remotevolume" WHERE "Name" = "duplicati-b7a9317d8bb854a91b7a048403f2c072f.dblock.zip.aes" took 0:00:00:00.000

* 4 Mar 2020 12:35: Starting - ExecuteScalar: SELECT "Type" FROM "Remotevolume" WHERE "Name" = "duplicati-b7a9317d8bb854a91b7a048403f2c072f.dblock.zip.aes"

* 4 Mar 2020 12:35: ExecuteNonQuery: UPDATE "Remotevolume" SET "Name" = "duplicati-b7a9317d8bb854a91b7a048403f2c072f.dblock.zip.aes" WHERE "Name" = "duplicati-bafb2f9e34439415f880ecd85692c725c.dblock.zip.aes" took 0:00:00:00.000

* 4 Mar 2020 12:35: Starting - ExecuteNonQuery: UPDATE "Remotevolume" SET "Name" = "duplicati-b7a9317d8bb854a91b7a048403f2c072f.dblock.zip.aes" WHERE "Name" = "duplicati-bafb2f9e34439415f880ecd85692c725c.dblock.zip.aes"

* 4 Mar 2020 12:35: Renaming "duplicati-bafb2f9e34439415f880ecd85692c725c.dblock.zip.aes" to "duplicati-b7a9317d8bb854a91b7a048403f2c072f.dblock.zip.aes"

* 4 Mar 2020 12:35: Backend event: Put - Rename: duplicati-b7a9317d8bb854a91b7a048403f2c072f.dblock.zip.aes (19.98 MB)

* 4 Mar 2020 12:35: Backend event: Put - Rename: duplicati-bafb2f9e34439415f880ecd85692c725c.dblock.zip.aes (19.98 MB)

* 4 Mar 2020 12:35: Backend event: Put - Retrying: duplicati-bafb2f9e34439415f880ecd85692c725c.dblock.zip.aes (19.98 MB)

* 4 Mar 2020 12:35: Operation Put with file duplicati-bafb2f9e34439415f880ecd85692c725c.dblock.zip.aes attempt 2 of 5 failed with message: Unable to read data from the transport connection: The connection was closed.

* 4 Mar 2020 12:32: Backend event: Put - Started: duplicati-ba102769d04914f0bb8e6276d9a8c3fe2.dblock.zip.aes (19.98 MB)

* 4 Mar 2020 12:32: Renaming "duplicati-bf76ba357824547889629dc6687b5f239.dblock.zip.aes" to "duplicati-ba102769d04914f0bb8e6276d9a8c3fe2.dblock.zip.aes"

* 4 Mar 2020 12:32: Backend event: Put - Rename: duplicati-ba102769d04914f0bb8e6276d9a8c3fe2.dblock.zip.aes (19.98 MB)

* 4 Mar 2020 12:32: Backend event: Put - Rename: duplicati-bf76ba357824547889629dc6687b5f239.dblock.zip.aes (19.98 MB)

* 4 Mar 2020 12:32: Backend event: Put - Started: duplicati-b64c0cd1421694190b40180fb1170d615.dblock.zip.aes (19.94 MB)

* 4 Mar 2020 12:32: Renaming "duplicati-b3a0375f5d7424b33882504aa28daca0e.dblock.zip.aes" to "duplicati-b64c0cd1421694190b40180fb1170d615.dblock.zip.aes"

* 4 Mar 2020 12:32: Backend event: Put - Rename: duplicati-b64c0cd1421694190b40180fb1170d615.dblock.zip.aes (19.94 MB)

* 4 Mar 2020 12:32: Backend event: Put - Rename: duplicati-b3a0375f5d7424b33882504aa28daca0e.dblock.zip.aes (19.94 MB)

* 4 Mar 2020 12:32: Backend event: Put - Retrying: duplicati-bf76ba357824547889629dc6687b5f239.dblock.zip.aes (19.98 MB)

* 4 Mar 2020 12:32: Backend event: Put - Retrying: duplicati-b3a0375f5d7424b33882504aa28daca0e.dblock.zip.aes (19.94 MB)

* 4 Mar 2020 12:32: Backend event: Put - Started: duplicati-b94de90c139c94a9ead4a1ad3311d1334.dblock.zip.aes (19.98 MB)