# StopNow(), Backup and cancellation tokens

**URL:** https://forum.duplicati.com/t/stopnow-backup-and-cancellation-tokens/16223
**Category:** Developer
**Created:** [May 4, 2023, 11:28am UTC](https://forum.duplicati.com/t/stopnow-backup-and-cancellation-tokens/16223 "2023-05-04T11:28:14Z")
**Posts on this page:** 20
**Page:** 1

<div class="post-metadata">

### Author: ![mr-russ](https://forum.duplicati.com/user_avatar/forum.duplicati.com/mr-russ/32/8129_2.png) [@mr-russ](https://forum.duplicati.com/u/mr-russ)
#### Post date: [May 4, 2023, 11:28am UTC](https://forum.duplicati.com/t/stopnow-backup-and-cancellation-tokens/16223/1 "2023-05-04T11:28:14Z")

</div>

Hi @gpatel-fr,

I’ve been looking at the StopNow() issue, and attempting like you to looking at the code.

My threading skills around async tasks are not as strong as I’d like. It seems a very complicated setup with channels and multiple threads. What is confusing it I can’t understand how a few of the Tasks ever exit;

```plaintext
Backup.DataBlockProcessor.Run(database, options, taskreader, token),
Backup.FileBlockProcessor.Run(snapshot, options, database, stats, taskreader, token),
Backup.StreamBlockSplitter.Run(options, database, taskreader),
Backup.FileEnumerationProcess.Run(sources, snapshot, journalService,
      options.FileAttributeFilter, sourcefilter, filter, options.SymlinkPolicy,
      options.HardlinkPolicy, options.ExcludeEmptyFolders, options.IgnoreFilenames,
      options.ChangedFilelist, taskreader, token),
Backup.FilePreFilterProcess.Run(snapshot, options, stats, database),
Backup.MetadataPreProcess.Run(snapshot, options, database, lastfilesetid, token),
Backup.SpillCollectorProcess.Run(options, database, taskreader),
Backup.ProgressHandler.Run(result)

```

Some accept cancellation tokens and take action on it.  
Some use the taskreader to await in the while loop.  
Some use while(true), and aside from a thrown exception, I can’t see how they exit. And in some cases, all exceptions are caught and it just continues on.

Now when the main thread ends, these background tasks/threads can/do run in the background. I’ve seen that in my testing on my computer. I don’t know how that’s nice/safe on the database, as it’s supposed to run all queries on the main thread that has exited.

The error I get from running that test is unparsable json

```plaintext
JsonTextReader.ParseValue()
JsonReader.ReadForType(JsonContract contract, Boolean hasConverter)
JsonSerializerInternalReader.Deserialize(JsonReader reader, Type objectType, Boolean checkAdditionalContent)
JsonSerializer.DeserializeInternal(JsonReader reader, Type objectType)
JsonSerializer.Deserialize[T](JsonReader reader)
RestoreHandler.ApplyMetadata(String path, Stream stream, Boolean restorePermissions, Boolean restoreSymlinkMetadata, Boolean dryrun) line 514
RestoreHandler.ApplyStoredMetadata(Options options, RestoreHandlerMetadataStorage metadatastorage) line 303
RestoreHandler.DoRun(LocalDatabase dbparent, IFilter filter, RestoreResults result) line 444
RestoreHandler.Run(String[] paths, IFilter filter) line 113
<cut further stack trace>

```

I have been unable to determine a way this code exists cleanly yet. Have you gotten any further?

---

<div class="post-metadata">

### Author: ![gpatel-fr](https://forum.duplicati.com/letter_avatar_proxy/v4/letter/g/7993a0/32.png) [@gpatel-fr](https://forum.duplicati.com/u/gpatel-fr)
#### Post date: [May 4, 2023, 7:17pm UTC](https://forum.duplicati.com/t/stopnow-backup-and-cancellation-tokens/16223/2 "2023-05-04T19:17:04Z")

</div>

Well, you have been farther than me. At some time it will be necessary to play with CoCol to understand backup code. However, it hangs for you in **restore** code, and CoCol is not referenced in restorehandler.cs. From git blame, it seems that code in RestoreHandler is mostly older than in BackupHandler, maybe it has not been updated to more recent features of Duplicati. That’s me speculating wildly of course.  
It would be interesting to go deeper to see if it always hangs in restore or it happens to hang sometimes in backup.  
While understanding CoCol and multitasking is certainly necessary in the medium term, that’s something I have postponed (in fact that’s mostly what I was talking about ‘understanding the network code’ in my post) because there are so many urgent things, among them getting a beta out. So if you feel the same I understand completely, maybe you could advance something else, because this particular enterprise will require quite some free and mostly uninterrupted time.

---

<div class="post-metadata">

### Author: ![ts678](https://forum.duplicati.com/letter_avatar_proxy/v4/letter/t/8491ac/32.png) [@ts678](https://forum.duplicati.com/u/ts678)
#### Post date: [May 4, 2023, 10:59pm UTC](https://forum.duplicati.com/t/stopnow-backup-and-cancellation-tokens/16223/3 "2023-05-04T22:59:50Z")

</div>

> [@mr-russ](#):
>
> The error I get from running that test is unparsable json

Do you have any exception text? All I see is a ParseValue at the top.

> [@mr-russ](#):
>
> I have been unable to determine a way this code exists cleanly yet.

What code exactly? This is restore, and earlier you pointed to backup.  
I can offer general advice, but I don’t want to look at every bit of code.

As a general guess for those, look at the [CoCoL Hello World example](https://github.com/kenkendk/cocol#hello-world).  
There’s usually a way to recognize an end-of-data situation, e.g. Linux  
[read](https://linux.die.net/man/2/read) returns 0 on end of file. I think CoCoL throws a RetiredException.

> [@mr-russ](#):
>
> And in some cases, all exceptions are caught and it just continues on.

So look at where the exception catch is, relative to the channel reads.  
Any catch has a scope to it, doesn’t it? Are they at high or low levels?

[https://github.com/duplicati/duplicati/blob/master/Duplicati/Library/Main/Operation/Backup/Channels.cs](https://github.com/duplicati/duplicati/blob/master/Duplicati/Library/Main/Operation/Backup/Channels.cs)  
is what you will probably see backup use. That’s the only Channels.cs.

Following Channels.cs into their uses led to a description attempt here:

[Channel Pipeline](https://forum.duplicati.com/t/channel-pipeline/11466/4), which tries to also match the `kenkendk` writeup [here](https://forum.duplicati.com/t/alternative-ftp-failure/7822/10).

> [@gpatel-fr](#):
>
> it seems that code in RestoreHandler is mostly older than in BackupHandler

The big concurrency addition in [2.0.3.6](https://github.com/duplicati/duplicati/releases/tag/v2.0.3.6-2.0.3.6_canary_2018-04-23) looks (if you diff against 2.0.3.5) like BackupHandler.cs,  
and RestoreHandler.cs got [Fixed empty block handling in concurrent\_processing branch #2637](https://github.com/duplicati/duplicati/pull/2637)  
and some interesting commentary on SQL readability, and knowing whether a rewrite is correct.  
IMO this is an important question, because without it, code will get less stable rather than more.

---

<div class="post-metadata">

### Author: ![mr-russ](https://forum.duplicati.com/user_avatar/forum.duplicati.com/mr-russ/32/8129_2.png) [@mr-russ](https://forum.duplicati.com/u/mr-russ)
#### Post date: [May 5, 2023, 12:20am UTC](https://forum.duplicati.com/t/stopnow-backup-and-cancellation-tokens/16223/4 "2023-05-05T00:20:09Z")

</div>

Exception text

```plaintext
Newtonsoft.Json.JsonReaderException : Unexpected character encountered while parsing value: �. Path '', line 0, position 0.

```

Code I’m referring to is the BackupHandler and all the subtasks I posted. Each has own quirks, but many are while (true). Let’s take Duplicati/Library/Main/Operation/Backup/MetadataPreProcess.cs and the Run() method. Explain how that can exit. My guessing from what you’ve said is that ReadAsync() throws a RetiredException. That’s caught in “some” cases, can continues. I would say that readability wise, ReadAsync() being the exit method is not clear. And there are not comments to assist in understanding the flow of while(true) loops.

Now we may be able to exit is a RetiredException is throw. We also can get a ThreadAbortException at any point in the code. Which is less than ideal for handling clean exits. And based on the intermittent failure of the test, I currently suspect we are sometimes processing the ThreadAbortException in ways that produce corrupt data. @tsuckow agrees that cancellations tokens are better, and I’m not sure why we have them, but don’t pass them into each operation of a backup. That way we can finish the process in an acceptable way, in the same way we only finish RetiredException when we are reading new data, not existing data.

I’m still struggling to work out where the json is written to disk. My estimation is that it will be put into a block, and that block written to DB, and to a volume. But with ThreadAbort, I can’t see how we guarantee that the metadata block makes it to disk in a transactional way that all threads either consider a block/file “processed” or not. It is my view for backup, we must be able to provide consistency between db writing, file inclusions, block writing and volumes. Or you easily end up with corruption if you interrupt the process at any point.

Speaking of Cocol, why use that over the standard .NET Channel producer/consumer logic?

---

<div class="post-metadata">

### Author: ![tsuckow](https://forum.duplicati.com/user_avatar/forum.duplicati.com/tsuckow/32/5254_2.png) [@tsuckow](https://forum.duplicati.com/u/tsuckow)
#### Post date: [May 5, 2023, 1:37am UTC](https://forum.duplicati.com/t/stopnow-backup-and-cancellation-tokens/16223/5 "2023-05-05T01:37:31Z")

</div>

> Speaking of Cocol, why use that over the standard .NET Channel producer/consumer logic?

If I’m not mistaken channels aren’t supported in .net Framework

---

<div class="post-metadata">

### Author: ![mr-russ](https://forum.duplicati.com/user_avatar/forum.duplicati.com/mr-russ/32/8129_2.png) [@mr-russ](https://forum.duplicati.com/u/mr-russ)
#### Post date: [May 5, 2023, 7:14am UTC](https://forum.duplicati.com/t/stopnow-backup-and-cancellation-tokens/16223/6 "2023-05-05T07:14:13Z")

</div>

> [@tsuckow](#):
>
> If I’m not mistaken channels aren’t supported in .net Framework

That was probably true 5+ years ago. And would have been the driver of a custom library then.

[NuGet Gallery | System.Threading.Channels 8.0.0](https://www.nuget.org/packages/System.Threading.Channels) and [Channels - .NET | Microsoft Learn](https://learn.microsoft.com/en-us/dotnet/core/extensions/channels) seem to indicate it’s available as long as you use framework 4.6.2 or .net core 2.1. Those aren’t unreasonable. But we have what we have at the moment.

---

<div class="post-metadata">

### Author: ![kenkendk](https://forum.duplicati.com/user_avatar/forum.duplicati.com/kenkendk/32/5305_2.png) [@kenkendk](https://forum.duplicati.com/u/kenkendk)
#### Post date: [May 5, 2023, 7:46am UTC](https://forum.duplicati.com/t/stopnow-backup-and-cancellation-tokens/16223/7 "2023-05-05T07:46:20Z")

</div>

> [@mr-russ](#):
>
> Some accept cancellation tokens and take action on it.  
> Some use the taskreader to await in the while loop.  
> Some use while(true), and aside from a thrown exception, I can’t see how they exit. And in some cases, all exceptions are caught and it just continues on.

As mentioned by @gpatel-fr the restore code was supposed to be updated the same way as the backup process, using the channel model, but other things were prioritized as restore is usually done less frequent than backups.

> [@ts678](#):
>
> As a general guess for those, look at the [CoCoL Hello World example](https://github.com/kenkendk/cocol#hello-world).  
> There’s usually a way to recognize an end-of-data situation, e.g. Linux  
> [read](https://linux.die.net/man/2/read) returns 0 on end of file. I think CoCoL throws a RetiredException.

Yes, CoCoL is based on the concepts of Communicating Sequential Processes (CSP) which uses channels as the exclusive communication pattern and a “poision” that closes the channels. The language around CSP is a bit dated, so I opted to use newer terms, where you “retire” a channel, meaning that no further communication can be done. This causes any reader/writer to get a `RetiredException` when attempting to read and write.

> [@mr-russ](#):
>
> Speaking of Cocol, why use that over the standard .NET Channel producer/consumer logic?

CoCoL was written before [Channels were introduced into C#](https://learn.microsoft.com/en-us/dotnet/core/extensions/channels). Today I would probably use the built-in channels, even though they are lacking some of the more advanced multi-reader/writer features.

> [@mr-russ](#):
>
> Code I’m referring to is the BackupHandler and all the subtasks I posted. Each has own quirks, but many are while (true). Let’s take Duplicati/Library/Main/Operation/Backup/MetadataPreProcess.cs and the Run() method. Explain how that can exit. My guessing from what you’ve said is that ReadAsync() throws a RetiredException. That’s caught in “some” cases, can continues. I would say that readability wise, ReadAsync() being the exit method is not clear. And there are not comments to assist in understanding the flow of while(true) loops.

The logic here is that the task (aka CSP process) is running in a `while(true)` loop, such that it runs “forever”. Some processes will not run forever as they are the initial producers (such as the file system enumeration process). When a non-infinite process is completed, it will `dispose()` the channels that it is using. This will make the channels accept no more input, but allow them to be emptied (aka read). Once the channel is empty, it will throw the `RetiredException` which will case the inifinite-running task to stop. When it stops, it will dispose its own channels. This causes a cascading effect that brings down all the processes. The reason for this design is that it reduces the chance that race conditions in the shutdown process are present.

In other words: each of the `while(true)` tasks run until an exception is thrown. The `RetiredException` is filtered by the `RunProtected()` and not re-thrown. Any other exceptions will be rethrown, so the error is reported to the task that is `awaiting` the process.

> [@mr-russ](#):
>
> Now we may be able to exit is a RetiredException is throw. We also can get a ThreadAbortException at any point in the code. Which is less than ideal for handling clean exits. And based on the intermittent failure of the test, I currently suspect we are sometimes processing the ThreadAbortException in ways that produce corrupt data.

Yes, the use of `ThreadAbort` was an earlier attempt at introducing an cancellation mechanism. I attempted to avoid passing a cancellation token around to all methods, and instead use the thread abort feature. This turned out to be a poor solution, because all code now needs to handle exceptions at arbitrary code points.

> [@mr-russ](#):
>
> I’m still struggling to work out where the json is written to disk. My estimation is that it will be put into a block, and that block written to DB, and to a volume. But with ThreadAbort, I can’t see how we guarantee that the metadata block makes it to disk in a transactional way that all threads either consider a block/file “processed” or not. It is my view for backup, we must be able to provide consistency between db writing, file inclusions, block writing and volumes. Or you easily end up with corruption if you interrupt the process at any point.

The idea with `ThreadAbort` is that it does not allow any guarantees, which is why it [should not be used at all](https://learn.microsoft.com/en-us/dotnet/core/compatibility/core-libraries/5.0/thread-abort-obsolete).

The hard part is then to use the cancellation token, and make sure any long-running tasks, such as DB queries, are running in a task, such that the caller can quit while a query is running. The query code then needs to handle being terminated when it completes.

The error line does not seem to be related to writing json, it is an error that occurs when reading previously stored serialized metadata. The question is then if the json that is in the zip file is corrupted, or the reader somehow messes up.

> [@mr-russ](#):
>
> The error I get from running that test is unparsable json
> 
> ```plaintext
> RestoreHandler.ApplyMetadata(String path, Stream stream, Boolean restorePermissions, Boolean restoreSymlinkMetadata, Boolean dryrun) line 514
> 
> ```

I would put a try/catch around that line and see what the stream contains, maybe that will reveal the issue. But it does sound like a data corruption issue where the contents of the stream are overwritten. Most likely cause is some code that reuses a buffer array to avoid allocations, which then breaks with multiple threads.

---

<div class="post-metadata">

### Author: ![gpatel-fr](https://forum.duplicati.com/letter_avatar_proxy/v4/letter/g/7993a0/32.png) [@gpatel-fr](https://forum.duplicati.com/u/gpatel-fr)
#### Post date: [May 5, 2023, 8:58am UTC](https://forum.duplicati.com/t/stopnow-backup-and-cancellation-tokens/16223/8 "2023-05-05T08:58:07Z")

</div>

> [@mr-russ](#):
>
> I’m still struggling to work out where the json is written to disk. My estimation is that it will be put into a block, and that block written to DB, and to a volume

That’s about it but there are some more finer points. I guess that I’ll have to add to the list of my tasks the compilation of my pages of notes, translate them to english, and getting the result in a general readable form, about the very intricate process that is turning the on disk structure into a database and the reverse process - and I may not have worked out 100% of the funny stuff. It can’t be explained in a few lines.

This is supposed to be expoed in the Duplicati white papers but these sources are not up to date (I guess that Duplicati was not handling metadata when it was written, or metadata handling has been left out for the sake of simplicity), and there are a lot of small things left out. There are also some posts by mostly @ts678 on the subject.

While I’m talking to you, I’ll take the opportunity to point that I may have not answered all your questions these last weeks, sorry about that, I have a limited capability and available time and energy.

---

<div class="post-metadata">

### Author: ![mr-russ](https://forum.duplicati.com/user_avatar/forum.duplicati.com/mr-russ/32/8129_2.png) [@mr-russ](https://forum.duplicati.com/u/mr-russ)
#### Post date: [May 5, 2023, 9:21am UTC](https://forum.duplicati.com/t/stopnow-backup-and-cancellation-tokens/16223/9 "2023-05-05T09:21:27Z")

</div>

> [@gpatel-fr](#):
>
> While I’m talking to you, I’ll take the opportunity to point that I may have not answered all your questions these last weeks, sorry about that, I have a limited capability and available time and energy.

That’s okay, I don’t need all my questions answered. Your comment about the plan aed how to actually help was really helpful. Of the other things, I’m still most interested in how to get code feedback and how something might get merged. I’ll persist on this issue for the moment.

---

<div class="post-metadata">

### Author: ![mr-russ](https://forum.duplicati.com/user_avatar/forum.duplicati.com/mr-russ/32/8129_2.png) [@mr-russ](https://forum.duplicati.com/u/mr-russ)
#### Post date: [May 5, 2023, 9:23am UTC](https://forum.duplicati.com/t/stopnow-backup-and-cancellation-tokens/16223/10 "2023-05-05T09:23:53Z")

</div>

> [@kenkendk](#):
>
> The hard part is then to use the cancellation token, and make sure any long-running tasks, such as DB queries, are running in a task, such that the caller can quit while a query is running. The query code then needs to handle being terminated when it completes.

This is the difficult things. You have to choose fast exit vs consistency. This is a backup tools, and we have talked a lot about stability, I’d pick that.

If there are long running tasks, they need to be looked at when causing problems. The SQL, is… well one of the things that I would like to give some attention to.

---

<div class="post-metadata">

### Author: ![ts678](https://forum.duplicati.com/letter_avatar_proxy/v4/letter/t/8491ac/32.png) [@ts678](https://forum.duplicati.com/u/ts678)
#### Post date: [May 5, 2023, 12:51pm UTC](https://forum.duplicati.com/t/stopnow-backup-and-cancellation-tokens/16223/11 "2023-05-05T12:51:42Z")

</div>

> [@mr-russ](#):
>
> This is a backup tools, and we have talked a lot about stability, I’d pick that.

I agree, however there’s also the legitimate use case of system shutdown or restart at some point. This leaves the destination in a potentially untidy state. The Remotevolume table and its State field has info, and Duplicati has to try to put things back in order on next backup. Calls are before RunMainOperation.

A carefully orchestrated shutdown may leave things tidy, but cleaning up at start may also be an option. From a user perspective, I’d note that the stop flavors of “after current file” and “now” confuse the users. Those wanting “right now” don’t notice that “now” has some fine print on it about work done before then.

There was once a discussion of whether both speeds of stop were needed. IIRC there was a conceived use case for both, but if “stop now” gets too tough, there’s probably an option to redefine or remove it…

Getting back to stability…

Relying on the database for cleanup information is bad when the database is bad. Aside from user error (which should still be mitigated, when possible), my main code question is whether all these concurrent processes modifying the database are breaking each other’s transaction plans by local commit decision.

Or maybe there’s a design plan behind keeping the entire database transactionally consistent at startup after sudden death, or maybe the inconsistencies are known and the mess cleanup logic handles them?

Wondering about the plan leads to hesitation about fixing what might be simple database oversight, e.g.

> <https://github.com/duplicati/duplicati/issues/4129#issuecomment-751882146>
>
> \- \[x\] I have searched open and closed issues for duplicates.
> 
> \----------------…------------------------
> 
> \## Environment info
> 
> 
> \- \*\*Duplicati version\*\*: 2.0.5.1 Beta
> \- \*\*Operating system\*\*: Windows 10 Version 1909
> \- \*\*Backend\*\*: Google Drive
> 
> \## Description
> 
> Fatal error "Found 1 files that are missing from the remote storage, please run repair" at start of regular hourly backup after previous backup failed with "The remote server returned an error: (403) Forbidden."
> 
> Looking into the databases (I keep a DB history via --run-script-before), the 403 left the DB corrupted. Remote data and profiling log indicate that compact deleted a dblock file and its dindex, however the DB RemoteOperation table lacks those rows (and everything after) for this backup, and Remotevolume table wrongly says that dindex should still be there, yet somehow rightly says that dblock should not...
> 
> Emails on these were:
> 
> \`\`\`
> Failed: The remote server returned an error: (403) Forbidden.
> Details: System.Net.WebException: The remote server returned an error: (403) Forbidden.
> at Duplicati.Library.Main.AsyncDownloader.AsyncDownloaderEnumerator.AsyncDownloadedFile.get\_TempFile()
> at Duplicati.Library.Main.Operation.CompactHandler.DoCompact(LocalDeleteDatabase db, Boolean hasVerifiedBackend, IDbTransaction& transaction, BackendManager sharedBackend)
> at Duplicati.Library.Main.Operation.DeleteHandler.DoRun(LocalDeleteDatabase db, IDbTransaction& transaction, Boolean hasVerifiedBacked, Boolean forceCompact, BackendManager sharedManager)
> at Duplicati.Library.Main.Operation.BackupHandler.CompactIfRequired(BackendManager backend, Int64 lastVolumeSize)
> at Duplicati.Library.Main.Operation.BackupHandler.\<RunAsync\>d\_\_20.MoveNext()
> \--- End of stack trace from previous location where exception was thrown ---
> at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
> 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)
> 
> Log data:
> 2020-03-03 13:02:17 -05 - \[Error-Duplicati.Library.Main.Operation.BackupHandler-FatalError\]: Fatal error
> System.Net.WebException: The remote server returned an error: (403) Forbidden.
> at Duplicati.Library.Main.AsyncDownloader.AsyncDownloaderEnumerator.AsyncDownloadedFile.get\_TempFile()
> at Duplicati.Library.Main.Operation.CompactHandler.DoCompact(LocalDeleteDatabase db, Boolean hasVerifiedBackend, IDbTransaction& transaction, BackendManager sharedBackend)
> at Duplicati.Library.Main.Operation.DeleteHandler.DoRun(LocalDeleteDatabase db, IDbTransaction& transaction, Boolean hasVerifiedBacked, Boolean forceCompact, BackendManager sharedManager)
> at Duplicati.Library.Main.Operation.BackupHandler.CompactIfRequired(BackendManager backend, Int64 lastVolumeSize)
> at Duplicati.Library.Main.Operation.BackupHandler.\<RunAsync\>d\_\_20.MoveNext()
> \`\`\`
> 
> then
> 
> \`\`\`
> Failed: Found 1 files that are missing from the remote storage, please run repair
> Details: Duplicati.Library.Interface.UserInformationException: Found 1 files that are missing from the remote storage, please run repair
> at Duplicati.Library.Main.Operation.FilelistProcessor.VerifyRemoteList(BackendManager backend, Options options, LocalDatabase database, IBackendWriter log, String protectedfile)
> at Duplicati.Library.Main.Operation.BackupHandler.PreBackupVerify(BackendManager backend, String protectedfile)
> at Duplicati.Library.Main.Operation.BackupHandler.\<RunAsync\>d\_\_20.MoveNext()
> \--- End of stack trace from previous location where exception was thrown ---
> at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
> 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)
> 
> Log data:
> 2020-03-03 13:40:30 -05 - \[Warning-Duplicati.Library.Main.Operation.FilelistProcessor-MissingFile\]: Missing file: duplicati-i3e3b4e6d1bda4b75bf950caec7755556.dindex.zip.aes
> 2020-03-03 13:40:30 -05 - \[Error-Duplicati.Library.Main.Operation.FilelistProcessor-MissingRemoteFiles\]: Found 1 files that are missing from the remote storage, please run repair
> 2020-03-03 13:40:30 -05 - \[Error-Duplicati.Library.Main.Operation.BackupHandler-FatalError\]: Fatal error
> Duplicati.Library.Interface.UserInformationException: Found 1 files that are missing from the remote storage, please run repair
> at Duplicati.Library.Main.Operation.FilelistProcessor.VerifyRemoteList(BackendManager backend, Options options, LocalDatabase database, IBackendWriter log, String protectedfile)
> at Duplicati.Library.Main.Operation.BackupHandler.PreBackupVerify(BackendManager backend, String protectedfile)
> at Duplicati.Library.Main.Operation.BackupHandler.\<RunAsync\>d\_\_20.MoveNext()
> \`\`\`
> 
> I'm not seeking to get this going soon, but will leave it alone for awhile for an analysis of the situation. This job was intentionally set with --number-of-retries=1 in the hope that a transient issue would error.
> I don't know where the 403 is from (possibly OAuth needing a token refresh?), but that seems to have done the breakage job. Possibly a compact operation is more sensitive than other spots in the backup?
> 
> 
> \## Steps to reproduce
> 
> 
> EDIT 1:
> 
> See the Mar 14, 2020 "Developed steps to reproduce this issue well." \[post below\](https://github.com/duplicati/duplicati/issues/4129#issuecomment-599149786).
> Also note that this seems to be being reported in the forum more. See references from forum below \[starting\](https://github.com/duplicati/duplicati/issues/4129#issuecomment-1079014706) at Mar 25, 2022.
> Original Mar 6 2020 steps to reproduce were "Not really known" as noted below.
> 
> 1. Not really known. You could try to arrange for a download error during second round of dblock downloads, to see if it will mess with the dblock+dindex delete that came after the first round of dblock downloads and the repackaged dblock+dindex uploads.
> 2. After above damage, run another backup. The one here was automatic by the same TrayIcon run.
> 
> 
> 
> \- \*\*Actual result\*\*:
> Failed: Found 1 files that are missing from the remote storage, please run repair
> \- \*\*Expected result\*\*:
> Recovers and does backup.
> 
> \## Screenshots
> 
> 
> 
> \## Debug log
> 
> 
> 
> Here are the bug report files for DB dated 12:56 PM (email was sent later at 13:02 though) and 13:40 PM.
> 
> \[bugreport.20190303\_1256.zip\](https://github.com/duplicati/duplicati/files/4301108/bugreport.20190303\_1256.zip)
> \[bugreport.20190303\_1340.zip\](https://github.com/duplicati/duplicati/files/4301112/bugreport.20190303\_1340.zip)
> 
> Here's the ending:
> 
> \`\`\`
> 2020-03-03 13:40:30 -05 - \[Warning-Duplicati.Library.Main.Operation.FilelistProcessor-MissingFile\]: Missing file: duplicati-i3e3b4e6d1bda4b75bf950caec7755556.dindex.zip.aes
> 2020-03-03 13:40:30 -05 - \[Error-Duplicati.Library.Main.Operation.FilelistProcessor-MissingRemoteFiles\]: Found 1 files that are missing from the remote storage, please run repair
> 2020-03-03 13:40:30 -05 - \[Profiling-Timer.Finished-Duplicati.Library.Main.Operation.BackupHandler-PreBackupVerify\]: PreBackupVerify took 0:00:00:08.333
> 2020-03-03 13:40:30 -05 - \[Error-Duplicati.Library.Main.Operation.BackupHandler-FatalError\]: Fatal error
> Duplicati.Library.Interface.UserInformationException: Found 1 files that are missing from the remote storage, please run repair
> at Duplicati.Library.Main.Operation.FilelistProcessor.VerifyRemoteList(BackendManager backend, Options options, LocalDatabase database, IBackendWriter log, String protectedfile)
> at Duplicati.Library.Main.Operation.BackupHandler.PreBackupVerify(BackendManager backend, String protectedfile)
> at Duplicati.Library.Main.Operation.BackupHandler.\<RunAsync\>d\_\_20.MoveNext()
> 2020-03-03 13:40:30 -05 - \[Profiling-Timer.Begin-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteNonQuery\]: Starting - ExecuteNonQuery: PRAGMA optimize
> 2020-03-03 13:40:30 -05 - \[Profiling-Timer.Finished-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteNonQuery\]: ExecuteNonQuery: PRAGMA optimize took 0:00:00:00.000
> 2020-03-03 13:40:30 -05 - \[Profiling-Timer.Finished-Duplicati.Library.Main.Controller-RunBackup\]: Running Backup took 0:00:00:30.736
> \`\`\`
> 
> Here's the compact and the 403:
> 
> \`\`\`
> 2020-03-03 12:42:05 -05 - \[Information-Duplicati.Library.Main.Database.LocalDeleteDatabase-CompactReason\]: Compacting because there is 25.24% wasted space and the limit is 25%
> 2020-03-03 12:42:05 -05 - \[Profiling-Timer.Begin-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteScalarInt64\]: Starting - ExecuteScalarInt64: INSERT INTO "Remotevolume" ("OperationID", "Name", "Type", "State", "Size", "VerificationCount", "DeleteGraceTime") VALUES (881, "duplicati-bbcbd4187d9cb48b0a22b0fe91722aa0b.dblock.zip.aes", "Blocks", "Temporary", -1, 0, 0); SELECT last\_insert\_rowid();
> 2020-03-03 12:42:05 -05 - \[Profiling-Timer.Finished-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteScalarInt64\]: ExecuteScalarInt64: INSERT INTO "Remotevolume" ("OperationID", "Name", "Type", "State", "Size", "VerificationCount", "DeleteGraceTime") VALUES (881, "duplicati-bbcbd4187d9cb48b0a22b0fe91722aa0b.dblock.zip.aes", "Blocks", "Temporary", -1, 0, 0); SELECT last\_insert\_rowid(); took 0:00:00:00.000
> 2020-03-03 12:42:05 -05 - \[Profiling-Timer.Begin-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteScalarInt64\]: Starting - ExecuteScalarInt64: INSERT INTO "Remotevolume" ("OperationID", "Name", "Type", "State", "Size", "VerificationCount", "DeleteGraceTime") VALUES (881, "duplicati-i15817fa246ab4f64b5e441d84bafcfe2.dindex.zip.aes", "Index", "Temporary", -1, 0, 0); SELECT last\_insert\_rowid();
> 2020-03-03 12:42:05 -05 - \[Profiling-Timer.Finished-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteScalarInt64\]: ExecuteScalarInt64: INSERT INTO "Remotevolume" ("OperationID", "Name", "Type", "State", "Size", "VerificationCount", "DeleteGraceTime") VALUES (881, "duplicati-i15817fa246ab4f64b5e441d84bafcfe2.dindex.zip.aes", "Index", "Temporary", -1, 0, 0); SELECT last\_insert\_rowid(); took 0:00:00:00.000
> 2020-03-03 12:42:05 -05 - \[Profiling-Timer.Begin-Duplicati.Library.Main.BackendManager-RemoteOperationNothing\]: Starting - RemoteOperationNothing
> 2020-03-03 12:42:05 -05 - \[Profiling-Timer.Finished-Duplicati.Library.Main.BackendManager-RemoteOperationNothing\]: RemoteOperationNothing took 0:00:00:00.000
> 2020-03-03 12:42:05 -05 - \[Profiling-Timer.Begin-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteReader\]: Starting - ExecuteReader: SELECT "C"."Name", "B"."Name", "B"."Hash", "B"."Size" FROM "IndexBlockLink" A, "RemoteVolume" B, "RemoteVolume" C WHERE "A"."IndexVolumeID" = "B"."ID" AND "A"."BlockVolumeID" = "C"."ID" AND "B"."Hash" IS NOT NULL AND "B"."Size" IS NOT NULL 
> 2020-03-03 12:42:05 -05 - \[Profiling-Timer.Finished-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteReader\]: ExecuteReader: SELECT "C"."Name", "B"."Name", "B"."Hash", "B"."Size" FROM "IndexBlockLink" A, "RemoteVolume" B, "RemoteVolume" C WHERE "A"."IndexVolumeID" = "B"."ID" AND "A"."BlockVolumeID" = "C"."ID" AND "B"."Hash" IS NOT NULL AND "B"."Size" IS NOT NULL took 0:00:00:00.000
> 2020-03-03 12:42:05 -05 - \[Profiling-Timer.Begin-Duplicati.Library.Main.BackendManager-RemoteOperationGet\]: Starting - RemoteOperationGet
> 2020-03-03 12:42:05 -05 - \[Information-Duplicati.Library.Main.BasicResults-BackendEvent\]: Backend event: Get - Started: duplicati-b50fa9e71ec3c4a30a5cf1a769840259b.dblock.zip.aes (50.05 MB)
> 2020-03-03 12:46:23 -05 - \[Profiling-Duplicati.Library.Main.BackendManager-DownloadSpeed\]: Downloaded and decrypted 50.05 MB in 00:04:17.9420016, 198.67 KB/s
> 2020-03-03 12:46:23 -05 - \[Information-Duplicati.Library.Main.BasicResults-BackendEvent\]: Backend event: Get - Completed: duplicati-b50fa9e71ec3c4a30a5cf1a769840259b.dblock.zip.aes (50.05 MB)
> 2020-03-03 12:46:23 -05 - \[Profiling-Timer.Finished-Duplicati.Library.Main.BackendManager-RemoteOperationGet\]: RemoteOperationGet took 0:00:04:17.942
> 2020-03-03 12:46:23 -05 - \[Profiling-Timer.Begin-Duplicati.Library.Main.BackendManager-RemoteOperationGet\]: Starting - RemoteOperationGet
> 2020-03-03 12:46:23 -05 - \[Information-Duplicati.Library.Main.BasicResults-BackendEvent\]: Backend event: Get - Started: duplicati-b52e9039635314dfdb0cc00d7d38bff00.dblock.zip.aes (43.42 MB)
> 2020-03-03 12:50:08 -05 - \[Profiling-Duplicati.Library.Main.BackendManager-DownloadSpeed\]: Downloaded and decrypted 43.42 MB in 00:03:44.8483951, 197.75 KB/s
> 2020-03-03 12:50:08 -05 - \[Information-Duplicati.Library.Main.BasicResults-BackendEvent\]: Backend event: Get - Completed: duplicati-b52e9039635314dfdb0cc00d7d38bff00.dblock.zip.aes (43.42 MB)
> 2020-03-03 12:50:08 -05 - \[Profiling-Timer.Finished-Duplicati.Library.Main.BackendManager-RemoteOperationGet\]: RemoteOperationGet took 0:00:03:44.848
> 2020-03-03 12:50:08 -05 - \[Profiling-Timer.Begin-Duplicati.Library.Main.BackendManager-RemoteOperationGet\]: Starting - RemoteOperationGet
> 2020-03-03 12:50:08 -05 - \[Information-Duplicati.Library.Main.BasicResults-BackendEvent\]: Backend event: Get - Started: duplicati-b2a3eb954e16f422cae85fe3202b56fe2.dblock.zip.aes (20.94 MB)
> 2020-03-03 12:51:59 -05 - \[Profiling-Duplicati.Library.Main.BackendManager-DownloadSpeed\]: Downloaded and decrypted 20.94 MB in 00:01:51.3706484, 192.54 KB/s
> 2020-03-03 12:51:59 -05 - \[Information-Duplicati.Library.Main.BasicResults-BackendEvent\]: Backend event: Get - Completed: duplicati-b2a3eb954e16f422cae85fe3202b56fe2.dblock.zip.aes (20.94 MB)
> 2020-03-03 12:51:59 -05 - \[Profiling-Timer.Finished-Duplicati.Library.Main.BackendManager-RemoteOperationGet\]: RemoteOperationGet took 0:00:01:51.370
> 2020-03-03 12:52:00 -05 - \[Profiling-Timer.Begin-Duplicati.Library.Main.BackendManager-RemoteOperationPut\]: Starting - RemoteOperationPut
> 2020-03-03 12:52:00 -05 - \[Profiling-Timer.Begin-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteScalarInt64\]: Starting - ExecuteScalarInt64: INSERT INTO "Remotevolume" ("OperationID", "Name", "Type", "State", "Size", "VerificationCount", "DeleteGraceTime") VALUES (881, "duplicati-b44bbdf41c6c64fe8bd6c0cd52826827a.dblock.zip.aes", "Blocks", "Temporary", -1, 0, 0); SELECT last\_insert\_rowid();
> 2020-03-03 12:52:00 -05 - \[Profiling-Timer.Finished-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteScalarInt64\]: ExecuteScalarInt64: INSERT INTO "Remotevolume" ("OperationID", "Name", "Type", "State", "Size", "VerificationCount", "DeleteGraceTime") VALUES (881, "duplicati-b44bbdf41c6c64fe8bd6c0cd52826827a.dblock.zip.aes", "Blocks", "Temporary", -1, 0, 0); SELECT last\_insert\_rowid(); took 0:00:00:00.000
> 2020-03-03 12:52:00 -05 - \[Profiling-Timer.Begin-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteScalarInt64\]: Starting - ExecuteScalarInt64: INSERT INTO "Remotevolume" ("OperationID", "Name", "Type", "State", "Size", "VerificationCount", "DeleteGraceTime") VALUES (881, "duplicati-i3662fdc138524598acc0ac3e2e820378.dindex.zip.aes", "Index", "Temporary", -1, 0, 0); SELECT last\_insert\_rowid();
> 2020-03-03 12:52:00 -05 - \[Profiling-Timer.Finished-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteScalarInt64\]: ExecuteScalarInt64: INSERT INTO "Remotevolume" ("OperationID", "Name", "Type", "State", "Size", "VerificationCount", "DeleteGraceTime") VALUES (881, "duplicati-i3662fdc138524598acc0ac3e2e820378.dindex.zip.aes", "Index", "Temporary", -1, 0, 0); SELECT last\_insert\_rowid(); took 0:00:00:00.000
> 2020-03-03 12:52:00 -05 - \[Information-Duplicati.Library.Main.BasicResults-BackendEvent\]: Backend event: Put - Started: duplicati-bbcbd4187d9cb48b0a22b0fe91722aa0b.dblock.zip.aes (50.00 MB)
> 2020-03-03 12:56:23 -05 - \[Profiling-Duplicati.Library.Main.BackendManager-UploadSpeed\]: Uploaded 50.00 MB in 00:04:22.6503624, 194.95 KB/s
> 2020-03-03 12:56:23 -05 - \[Information-Duplicati.Library.Main.BasicResults-BackendEvent\]: Backend event: Put - Completed: duplicati-bbcbd4187d9cb48b0a22b0fe91722aa0b.dblock.zip.aes (50.00 MB)
> 2020-03-03 12:56:23 -05 - \[Profiling-Timer.Finished-Duplicati.Library.Main.BackendManager-RemoteOperationPut\]: RemoteOperationPut took 0:00:04:22.665
> 2020-03-03 12:56:23 -05 - \[Profiling-Timer.Begin-Duplicati.Library.Main.BackendManager-RemoteOperationPut\]: Starting - RemoteOperationPut
> 2020-03-03 12:56:23 -05 - \[Information-Duplicati.Library.Main.BasicResults-BackendEvent\]: Backend event: Put - Started: duplicati-i15817fa246ab4f64b5e441d84bafcfe2.dindex.zip.aes (39.56 KB)
> 2020-03-03 12:56:24 -05 - \[Profiling-Duplicati.Library.Main.BackendManager-UploadSpeed\]: Uploaded 39.56 KB in 00:00:01.1783834, 33.57 KB/s
> 2020-03-03 12:56:24 -05 - \[Information-Duplicati.Library.Main.BasicResults-BackendEvent\]: Backend event: Put - Completed: duplicati-i15817fa246ab4f64b5e441d84bafcfe2.dindex.zip.aes (39.56 KB)
> 2020-03-03 12:56:24 -05 - \[Profiling-Timer.Finished-Duplicati.Library.Main.BackendManager-RemoteOperationPut\]: RemoteOperationPut took 0:00:00:01.264
> 2020-03-03 12:56:24 -05 - \[Profiling-Timer.Begin-Duplicati.Library.Main.BackendManager-RemoteOperationNothing\]: Starting - RemoteOperationNothing
> 2020-03-03 12:56:24 -05 - \[Profiling-Timer.Finished-Duplicati.Library.Main.BackendManager-RemoteOperationNothing\]: RemoteOperationNothing took 0:00:00:00.000
> 2020-03-03 12:56:24 -05 - \[Profiling-Timer.Begin-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteReader\]: Starting - ExecuteReader: SELECT "C"."Name", "B"."Name", "B"."Hash", "B"."Size" FROM "IndexBlockLink" A, "RemoteVolume" B, "RemoteVolume" C WHERE "A"."IndexVolumeID" = "B"."ID" AND "A"."BlockVolumeID" = "C"."ID" AND "B"."Hash" IS NOT NULL AND "B"."Size" IS NOT NULL 
> 2020-03-03 12:56:24 -05 - \[Profiling-Timer.Finished-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteReader\]: ExecuteReader: SELECT "C"."Name", "B"."Name", "B"."Hash", "B"."Size" FROM "IndexBlockLink" A, "RemoteVolume" B, "RemoteVolume" C WHERE "A"."IndexVolumeID" = "B"."ID" AND "A"."BlockVolumeID" = "C"."ID" AND "B"."Hash" IS NOT NULL AND "B"."Size" IS NOT NULL took 0:00:00:00.000
> 2020-03-03 12:56:24 -05 - \[Profiling-Timer.Begin-Duplicati.Library.Main.BackendManager-RemoteOperationDelete\]: Starting - RemoteOperationDelete
> 2020-03-03 12:56:24 -05 - \[Information-Duplicati.Library.Main.BasicResults-BackendEvent\]: Backend event: Delete - Started: duplicati-b50fa9e71ec3c4a30a5cf1a769840259b.dblock.zip.aes (50.05 MB)
> 2020-03-03 12:56:26 -05 - \[Information-Duplicati.Library.Main.BasicResults-BackendEvent\]: Backend event: Delete - Completed: duplicati-b50fa9e71ec3c4a30a5cf1a769840259b.dblock.zip.aes (50.05 MB)
> 2020-03-03 12:56:26 -05 - \[Profiling-Timer.Finished-Duplicati.Library.Main.BackendManager-RemoteOperationDelete\]: RemoteOperationDelete took 0:00:00:01.461
> 2020-03-03 12:56:26 -05 - \[Profiling-Timer.Begin-Duplicati.Library.Main.BackendManager-RemoteOperationDelete\]: Starting - RemoteOperationDelete
> 2020-03-03 12:56:26 -05 - \[Information-Duplicati.Library.Main.BasicResults-BackendEvent\]: Backend event: Delete - Started: duplicati-i3e3b4e6d1bda4b75bf950caec7755556.dindex.zip.aes (27.45 KB)
> 2020-03-03 12:56:29 -05 - \[Information-Duplicati.Library.Main.BasicResults-BackendEvent\]: Backend event: Delete - Completed: duplicati-i3e3b4e6d1bda4b75bf950caec7755556.dindex.zip.aes (27.45 KB)
> 2020-03-03 12:56:29 -05 - \[Profiling-Timer.Finished-Duplicati.Library.Main.BackendManager-RemoteOperationDelete\]: RemoteOperationDelete took 0:00:00:02.955
> 2020-03-03 12:56:29 -05 - \[Profiling-Timer.Begin-Duplicati.Library.Main.BackendManager-RemoteOperationGet\]: Starting - RemoteOperationGet
> 2020-03-03 12:56:29 -05 - \[Information-Duplicati.Library.Main.BasicResults-BackendEvent\]: Backend event: Get - Started: duplicati-b3f9da65a8b8040df8cb634523018c2fa.dblock.zip.aes (21.13 MB)
> 2020-03-03 12:58:17 -05 - \[Profiling-Duplicati.Library.Main.BackendManager-DownloadSpeed\]: Downloaded and decrypted 21.13 MB in 00:01:48.8213207, 198.86 KB/s
> 2020-03-03 12:58:17 -05 - \[Information-Duplicati.Library.Main.BasicResults-BackendEvent\]: Backend event: Get - Completed: duplicati-b3f9da65a8b8040df8cb634523018c2fa.dblock.zip.aes (21.13 MB)
> 2020-03-03 12:58:17 -05 - \[Profiling-Timer.Finished-Duplicati.Library.Main.BackendManager-RemoteOperationGet\]: RemoteOperationGet took 0:00:01:48.822
> 2020-03-03 12:58:17 -05 - \[Profiling-Timer.Begin-Duplicati.Library.Main.BackendManager-RemoteOperationGet\]: Starting - RemoteOperationGet
> 2020-03-03 12:58:17 -05 - \[Information-Duplicati.Library.Main.BasicResults-BackendEvent\]: Backend event: Get - Started: duplicati-bad01a725864f499fa129271f01aa4bc1.dblock.zip.aes (16.13 MB)
> 2020-03-03 12:59:42 -05 - \[Profiling-Duplicati.Library.Main.BackendManager-DownloadSpeed\]: Downloaded and decrypted 16.13 MB in 00:01:24.0692703, 196.49 KB/s
> 2020-03-03 12:59:42 -05 - \[Information-Duplicati.Library.Main.BasicResults-BackendEvent\]: Backend event: Get - Completed: duplicati-bad01a725864f499fa129271f01aa4bc1.dblock.zip.aes (16.13 MB)
> 2020-03-03 12:59:42 -05 - \[Profiling-Timer.Finished-Duplicati.Library.Main.BackendManager-RemoteOperationGet\]: RemoteOperationGet took 0:00:01:24.070
> 2020-03-03 12:59:42 -05 - \[Profiling-Timer.Begin-Duplicati.Library.Main.BackendManager-RemoteOperationGet\]: Starting - RemoteOperationGet
> 2020-03-03 12:59:42 -05 - \[Information-Duplicati.Library.Main.BasicResults-BackendEvent\]: Backend event: Get - Started: duplicati-be375389d1eba43708f00bce8ba743ccf.dblock.zip.aes (28.48 MB)
> 2020-03-03 13:02:09 -05 - \[Profiling-Duplicati.Library.Main.BackendManager-DownloadSpeed\]: Downloaded and decrypted 28.48 MB in 00:02:27.8752230, 197.18 KB/s
> 2020-03-03 13:02:09 -05 - \[Information-Duplicati.Library.Main.BasicResults-BackendEvent\]: Backend event: Get - Completed: duplicati-be375389d1eba43708f00bce8ba743ccf.dblock.zip.aes (28.48 MB)
> 2020-03-03 13:02:09 -05 - \[Profiling-Timer.Finished-Duplicati.Library.Main.BackendManager-RemoteOperationGet\]: RemoteOperationGet took 0:00:02:27.876
> 2020-03-03 13:02:09 -05 - \[Profiling-Timer.Begin-Duplicati.Library.Main.BackendManager-RemoteOperationGet\]: Starting - RemoteOperationGet
> 2020-03-03 13:02:09 -05 - \[Information-Duplicati.Library.Main.BasicResults-BackendEvent\]: Backend event: Get - Started: duplicati-b229fdb1d14f44ae98a22f3835f60848b.dblock.zip.aes (47.39 MB)
> 2020-03-03 13:02:10 -05 - \[Profiling-Timer.Finished-Duplicati.Library.Main.BackendManager-RemoteOperationGet\]: RemoteOperationGet took 0:00:00:00.075
> 2020-03-03 13:02:10 -05 - \[Retry-Duplicati.Library.Main.BackendManager-RetryGet\]: Operation Get with file duplicati-b229fdb1d14f44ae98a22f3835f60848b.dblock.zip.aes attempt 1 of 1 failed with message: The remote server returned an error: (403) Forbidden.
> System.Net.WebException: The remote server returned an error: (403) Forbidden.
> at Duplicati.Library.Utility.AsyncHttpRequest.AsyncWrapper.GetResponseOrStream()
> at Duplicati.Library.Utility.AsyncHttpRequest.GetResponse()
> at Duplicati.Library.Backend.GoogleDrive.GoogleDrive.Get(String remotename, Stream stream)
> at Duplicati.Library.Main.BackendManager.coreDoGetPiping(FileEntryItem item, IEncryption useDecrypter, Int64& retDownloadSize, String& retHashcode)
> at Duplicati.Library.Main.BackendManager.DoGet(FileEntryItem item)
> at Duplicati.Library.Main.BackendManager.ThreadRun()
> 2020-03-03 13:02:10 -05 - \[Information-Duplicati.Library.Main.BasicResults-BackendEvent\]: Backend event: Get - Failed: duplicati-b229fdb1d14f44ae98a22f3835f60848b.dblock.zip.aes (47.39 MB)
> 2020-03-03 13:02:10 -05 - \[Profiling-Timer.Begin-Duplicati.Library.Main.BackendManager-RemoteOperationGet\]: Starting - RemoteOperationGet
> 2020-03-03 13:02:10 -05 - \[Information-Duplicati.Library.Main.BasicResults-BackendEvent\]: Backend event: Get - Started: duplicati-b6e794e613caf4a409d2aaf90de1f31bc.dblock.zip.aes (705.39 KB)
> 2020-03-03 13:02:17 -05 - \[Profiling-Duplicati.Library.Main.BackendManager-DownloadSpeed\]: Downloaded and decrypted 705.39 KB in 00:00:06.9219081, 101.91 KB/s
> 2020-03-03 13:02:17 -05 - \[Information-Duplicati.Library.Main.BasicResults-BackendEvent\]: Backend event: Get - Completed: duplicati-b6e794e613caf4a409d2aaf90de1f31bc.dblock.zip.aes (705.39 KB)
> 2020-03-03 13:02:17 -05 - \[Profiling-Timer.Finished-Duplicati.Library.Main.BackendManager-RemoteOperationGet\]: RemoteOperationGet took 0:00:00:06.922
> 2020-03-03 13:02:17 -05 - \[Error-Duplicati.Library.Main.Operation.BackupHandler-FatalError\]: Fatal error
> System.Net.WebException: The remote server returned an error: (403) Forbidden.
> at Duplicati.Library.Main.AsyncDownloader.AsyncDownloaderEnumerator.AsyncDownloadedFile.get\_TempFile()
> at Duplicati.Library.Main.Operation.CompactHandler.DoCompact(LocalDeleteDatabase db, Boolean hasVerifiedBackend, IDbTransaction& transaction, BackendManager sharedBackend)
> at Duplicati.Library.Main.Operation.DeleteHandler.DoRun(LocalDeleteDatabase db, IDbTransaction& transaction, Boolean hasVerifiedBacked, Boolean forceCompact, BackendManager sharedManager)
> at Duplicati.Library.Main.Operation.BackupHandler.CompactIfRequired(BackendManager backend, Int64 lastVolumeSize)
> at Duplicati.Library.Main.Operation.BackupHandler.\<RunAsync\>d\_\_20.MoveNext()
> 2020-03-03 13:02:17 -05 - \[Profiling-Timer.Begin-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteNonQuery\]: Starting - ExecuteNonQuery: PRAGMA optimize
> 2020-03-03 13:02:17 -05 - \[Profiling-Timer.Finished-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteNonQuery\]: ExecuteNonQuery: PRAGMA optimize took 0:00:00:00.000
> 2020-03-03 13:02:17 -05 - \[Profiling-Timer.Finished-Duplicati.Library.Main.Controller-RunBackup\]: Running Backup took 0:00:22:16.948
> \`\`\`
> 
> Notice how duplicati-b50fa9e71ec3c4a30a5cf1a769840259b.dblock.zip.aes then duplicati-i3e3b4e6d1bda4b75bf950caec7755556.dindex.zip.aes were logged as deleted. In 12:56 DB:
> 
> duplicati-b50fa9e71ec3c4a30a5cf1a769840259b.dblock.zip.aes
> Remotevolume table shows Deleting
> RemoteOperation table does not show delete
> 
> duplicati-i3e3b4e6d1bda4b75bf950caec7755556.dindex.zip.aes
> Remotevolume table shows Verified
> RemoteOperation table does not show delete

and properly shutting work down on errors and on request seem similar, so might be looked at together.

---

<div class="post-metadata">

### Author: ![mr-russ](https://forum.duplicati.com/user_avatar/forum.duplicati.com/mr-russ/32/8129_2.png) [@mr-russ](https://forum.duplicati.com/u/mr-russ)
#### Post date: [May 5, 2023, 1:56pm UTC](https://forum.duplicati.com/t/stopnow-backup-and-cancellation-tokens/16223/12 "2023-05-05T13:56:19Z")

</div>

I’m not sure what’s best to say that’s helpful and actionable.

DB is not aligned to operations, not updated in ways to show progress through the thread producer/consumer pipeline, uses a single connection, does not allow concurrent reads, does not store data in smaller binary form (hashes), is not optimized for lookups and uses transactions in ways I’ve not understood and appear confusing from my 20 years experience with large DB’s. They don’t usually get interesting until a few hundred GB.

Architecture wise, it needs small transactions that include state information that’s updated when that operation has been successfully completed. Volumes arent “done” or backed up until they are on the remote. This then flows back to files, and blocks. If you know the state information you can easily cleanup on startup of another operation as you know what was successful. You can then have a partial backup that you know what’s complete in it and what data is then just extra garbage and what cannot be deduplicated as it never really got backed up.

At the moment, a block is added to the database and I’ve not seen a guarantee that block is actually backed up. My reading of you issue comment appears to support my view.

Either way, I find this all irrelevant and academic until there is a way to make that kind of change that would then be reviewed aed merged. (Yes, this is the hobby horse I will not be able to get off).

---

<div class="post-metadata">

### Author: ![ts678](https://forum.duplicati.com/letter_avatar_proxy/v4/letter/t/8491ac/32.png) [@ts678](https://forum.duplicati.com/u/ts678)
#### Post date: [May 5, 2023, 7:09pm UTC](https://forum.duplicati.com/t/stopnow-backup-and-cancellation-tokens/16223/13 "2023-05-05T19:09:38Z")

</div>

> [@mr-russ](#):
>
> At the moment, a block is added to the database and I’ve not seen a guarantee that block is actually backed up.

This is getting into the area of those design documents I wish we had, however the design does have concepts such as [asynchronous-upload-limit](https://duplicati.readthedocs.io/en/latest/06-advanced-options/#asynchronous-upload-limit) which allows files to queue while waiting for their upload.

The term “actually backed up” begs the question of how far, but generally it takes the destination at its word until a file list after backup or on next backup finds otherwise, in which case records are reverted.

Here’s a proposed enhanced stack-trace-like theory on how the rollback of Block table might get done:

```plaintext
DELETE FROM ""Block"" WHERE ""VolumeID"" IN ({0})
RemoveRemoteVolumes() LocalDatabase.cs
cleanupRemovedRemoteVolumes.Add(i.Name);
case RemoteVolumeState.Uploading
RemoteListAnalysis() FilelistProcessor.cs
VerifyRemoteList() FilelistProcessor.cs
PreBackupVerify() BackupHandler.cs

```

The use of the `State` field is probably necessary because destination doesn’t do transactions directly.

> <https://github.com/duplicati/duplicati/blob/96b2bd795e7f35ea70a32b12850039938cca7a21/Duplicati/Library/Main/Enums.cs#L54-L57>

> [@mr-russ](#):
>
> Volumes arent “done” or backed up until they are on the remote.

That’s Verified transition in the RemoteVolumeState, unless you don’t feel a need to actually do a list.

> [@mr-russ](#):
>
> If you know the state information you can easily cleanup on startup of another operation as you know what was successful.

Look through the RemoteListAnalysis() cleanup code for how that’s exactly what it’s attempting to do.

---

<div class="post-metadata">

### Author: ![mr-russ](https://forum.duplicati.com/user_avatar/forum.duplicati.com/mr-russ/32/8129_2.png) [@mr-russ](https://forum.duplicati.com/u/mr-russ)
#### Post date: [May 5, 2023, 9:25pm UTC](https://forum.duplicati.com/t/stopnow-backup-and-cancellation-tokens/16223/14 "2023-05-05T21:25:42Z")

</div>

> [@ts678](#):
>
> This is getting into the area of those design documents I wish we had, however the design does have concepts such as [asynchronous-upload-limit](https://duplicati.readthedocs.io/en/latest/06-advanced-options/#asynchronous-upload-limit) which allows files to queue while waiting for their upload.

It is my experience that most of this design should be code comments, the backup handler block of code this thread started with I would love to see 500 lines of comments about how it’s supposed to achieve its goal. Separate docs are great but hard to ensure it’s maintained. And it’s an achievable goal to add them in areas that are understood. It can be done as paat of code changes rather than a large difficult document that is also challenging to verify at the beginning.

It’s true the current code does have the remote volume flag. I can’t believe it works properly as when I use ctrl+c on the cli, I’ve been able to get to and invalid DB that won’t repair. So a documented design for data flow in backuphandler would assist with that.

---

<div class="post-metadata">

### Author: ![ts678](https://forum.duplicati.com/letter_avatar_proxy/v4/letter/t/8491ac/32.png) [@ts678](https://forum.duplicati.com/u/ts678)
#### Post date: [May 5, 2023, 10:25pm UTC](https://forum.duplicati.com/t/stopnow-backup-and-cancellation-tokens/16223/15 "2023-05-05T22:25:54Z")

</div>

> [@mr-russ](#):
>
> Separate docs are great but hard to ensure it’s maintained.

Agree that a separate docs can be hard. I’d like to see a small comment block at the top of each file.  
Giant comment block in one place might go as neglected as a separate doc. Lines all over are hard.

Because the overall architecture is pretty sprawling, and subject to slow change, a design summary possibly is a reasonable separate document, then code comments spread around could add details.

Pretty pictures are nice, but lead to potential difficulty and friction if somebody ever has to change it.

Regardless of form, my goal is to be able to understand the design so we know its problems (or not), giving us some idea of what to change (or maybe dare not change) to accomplish what the goals are.

I wasn’t sure where some of your database comments were heading. SQLite is missing big-database capabilities, but we’re not taking advantage of everything it has yet, as we try to get to stable and fast.

> [@mr-russ](#):
>
> So a documented design for data flow in backuphandler would assist with that.

Agree completely. I wish we had that. Unless we get some aid, is this something you’d like to work on?  
The forum post I wrote is a very high level view, but I’d like to get down a little further to database work.

Regarding Control-C, I was doing automated interrupt testing before using random kill, maybe a repair.

```plaintext
        timeout = random.randint(1, 30)
        count_started += 1
        print('Running backup at', datetime.datetime.now())
        result = subprocess.run(args, timeout=timeout, capture_output=True)
        exit_code = result.returncode
        print('Exit code', exit_code)
        if exit_code >= 100:
            print('stderr was:')
            error = result.stderr.decode()
            print(error)
            if re.search('ErrorID: MissingRemoteFiles', error):
                count_missing += 1
                repair()
            elif re.search('ErrorID: ExtraRemoteFiles', error):
                count_extra += 1
                repair()
            elif re.search('Unexpected number of remote volumes marked as deleted', error):
                count_marked_deleted += 1
 # repair()
 # pass
                break
            else:
                count_unknown += 1
                break

```

which, from where the code landed when I gave up, looks like it was probably two that repair could fix (and I think they have Issues filed), maybe one that it couldn’t, and then some unclassified type of fail.

Some sample statistics from that random kill test script (plus related commentary) can be found [here](https://forum.duplicati.com/t/no-more-backup-because-of-one-missing-file/14403/3).

What kind are you getting? I really dislike the ones that can’t be rescued regardless of extreme efforts.

---

<div class="post-metadata">

### Author: ![mr-russ](https://forum.duplicati.com/user_avatar/forum.duplicati.com/mr-russ/32/8129_2.png) [@mr-russ](https://forum.duplicati.com/u/mr-russ)
#### Post date: [May 5, 2023, 10:45pm UTC](https://forum.duplicati.com/t/stopnow-backup-and-cancellation-tokens/16223/16 "2023-05-05T22:45:32Z")

</div>

> [@ts678](#):
>
> Agree completely. I wish we had that. Unless we get some aid, is this something you’d like to work on?

Not really keen, I want to be changing things at the same time to give best value for the investment and that’s not a priority.

I would like to change the way the DB is managed but is too big a change for the moment.

---

<div class="post-metadata">

### Author: ![ts678](https://forum.duplicati.com/letter_avatar_proxy/v4/letter/t/8491ac/32.png) [@ts678](https://forum.duplicati.com/u/ts678)
#### Post date: [May 5, 2023, 10:52pm UTC](https://forum.duplicati.com/t/stopnow-backup-and-cancellation-tokens/16223/17 "2023-05-05T22:52:58Z")

</div>

> [@mr-russ](#):
>
> changing things at the same time

That blend might work. It also helps the code reviewer, so helps the end goal of better code shipping.

---

<div class="post-metadata">

### Author: ![rinaldi6109](https://forum.duplicati.com/letter_avatar_proxy/v4/letter/r/439d5e/32.png) [@rinaldi6109](https://forum.duplicati.com/u/rinaldi6109)
#### Post date: [May 15, 2023, 5:43pm UTC](https://forum.duplicati.com/t/stopnow-backup-and-cancellation-tokens/16223/18 "2023-05-15T17:43:22Z")

</div>

> [@mr-russ](#):
>
> This is the difficult things. You have to choose fast exit vs consistency. This is a backup tools, and we have talked a lot about stability, I’d pick that.

Thanks to all for your work.  
Here I only want to put in a word for human time (you call it fast exit). Sometimes Duplicati hangs up for days, and I’m forced to kill it. Or I have to turn off the computer, which is the same. I cannot wait days/weeks/years with no clear expected time to complete the job. In such cases, speaking about stability is not a valid alternative.

---

<div class="post-metadata">

### Author: ![gpatel-fr](https://forum.duplicati.com/letter_avatar_proxy/v4/letter/g/7993a0/32.png) [@gpatel-fr](https://forum.duplicati.com/u/gpatel-fr)
#### Post date: [May 15, 2023, 8:37pm UTC](https://forum.duplicati.com/t/stopnow-backup-and-cancellation-tokens/16223/19 "2023-05-15T20:37:53Z")

</div>

> [@rinaldi6109](#):
>
> I cannot ways for dayes/weeks/years with no clear expected time to complete the job.

There is no doubt that there are problems stopping Duplicati cleanly. At the moment there is no clear plan for going forward, however I intend to commit this PR

> <https://github.com/duplicati/duplicati/pull/4929>
>
> Thread.abort is defunt in modern .net versions.
> 
> We need to be good about not …swallowing exceptions blindly, interupted exception needs to be rethrown.
> 
> I have not tested this on master, it is cherry picked from net5-split

in a separate branch in a few days and build binaries based on it for people wanting to help in testing. Hopefully it could get things in a better shape. But it’s not for next beta that’s for sure.

---

<div class="post-metadata">

### Author: ![mr-russ](https://forum.duplicati.com/user_avatar/forum.duplicati.com/mr-russ/32/8129_2.png) [@mr-russ](https://forum.duplicati.com/u/mr-russ)
#### Post date: [May 15, 2023, 9:24pm UTC](https://forum.duplicati.com/t/stopnow-backup-and-cancellation-tokens/16223/20 "2023-05-15T21:24:21Z")

</div>

My understanding of Thread.Interrupt is that it will reduce some errors on exit. But will only interrupt when a sleep occurs. So exit may be slower. I commented out Thread.Abort and it did not appear to have any effect on the exit of the cli. I’ve not been using the web to see any impact there.

[Next page](https://forum.duplicati.com/t/stopnow-backup-and-cancellation-tokens/16223.md?page=2)
