My backup failing with error - almost all backups

Suddenly i am getting error in many backups.

every time there is problem with one file only (which keeps on changing).

I have studied that throttle creates problem with one drive. I have tried without that also.

current version shown as Duplicati - 2.0.5.1_beta_2020-01-18 - is it because of this version i am just doubting. as

2020-03-04 13:36:35 +05 - [Error-Duplicati.Library.Main.Operation.TestHandler-RemoteFileProcessingFailed]: Failed to process file duplicati-20200229T223901Z.dlist.zip.aes

this thread seems to similar issue which i am facing.

In complete log i can see following message. if this helps.

“Key”: “Error”,
“Value”: “A task was canceled.”

Live View log - below error came but in the end backup shown successful.

Mar 5, 2020 3:03 PM: Operation Get with file duplicati-b8a993ff46fc449a09ee49af50c51da97.dblock.zip.aes attempt 1 of 5 failed with message: A task was canceled.
{“ClassName”:“System.Threading.Tasks.TaskCanceledException”,“Message”:“A task was canceled.”,“Data”:null,“InnerException”:null,“HelpURL”:null,“StackTraceString”:" at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)\r\n at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)\r\n at Duplicati.Library.Backend.MicrosoftGraphBackend.Get(String remotename, Stream stream)\r\n at Duplicati.Library.Main.BackendManager.coreDoGetPiping(FileEntryItem item, IEncryption useDecrypter, Int64& retDownloadSize, String& retHashcode)\r\n at Duplicati.Library.Main.BackendManager.DoGet(FileEntryItem item)\r\n at Duplicati.Library.Main.BackendManager.ThreadRun()",“RemoteStackTraceString”:null,“RemoteStackIndex”:0,“ExceptionMethod”:“8\nThrowForNonSuccess\nmscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089\nSystem.Runtime.CompilerServices.TaskAwaiter\nVoid ThrowForNonSuccess(System.Threading.Tasks.Task)”,“HResult”:-2146233029,“Source”:“mscorlib”,“WatsonBuckets”:null}

I tried to restore file from backup which showing as failed.

I could restore the file , however again it gave message
as below

2020-03-05 16:58:33 +05 - [Error-Duplicati.Library.Main.Operation.RestoreHandler-PatchingFailed]: Failed to patch with remote file: “duplicati-b4c05a8cbece5481a950c06df5ec63bda.dblock.zip.aes”, message: A task was canceled.

Detailed live log view as below.

  • Mar 5, 2020 4:58 PM: The operation Restore has completed

  • Mar 5, 2020 4:58 PM: Failed to patch with remote file: “duplicati-b4c05a8cbece5481a950c06df5ec63bda.dblock.zip.aes”, message: A task was canceled.

{“ClassName”:“System.Threading.Tasks.TaskCanceledException”,“Message”:“A task was canceled.”,“Data”:null,“InnerException”:null,“HelpURL”:null,“StackTraceString”:" at Duplicati.Library.Main.AsyncDownloader.AsyncDownloaderEnumerator.AsyncDownloadedFile.get_TempFile()\r\n at Duplicati.Library.Main.Operation.RestoreHandler.DoRun(LocalDatabase dbparent, IFilter filter, RestoreResults result)",“RemoteStackTraceString”:null,“RemoteStackIndex”:0,“ExceptionMethod”:“8\nget_TempFile\nDuplicati.Library.Main, Version=2.0.5.1, Culture=neutral, PublicKeyToken=null\nDuplicati.Library.Main.AsyncDownloader+AsyncDownloaderEnumerator+AsyncDownloadedFile\nDuplicati.Library.Utility.TempFile get_TempFile()”,“HResult”:-2146233029,“Source”:“Duplicati.Library.Main”,“WatsonBuckets”:null}

  • Mar 5, 2020 4:58 PM: Backend event: Get - Failed: duplicati-b4c05a8cbece5481a950c06df5ec63bda.dblock.zip.aes (150.00 MB)

  • Mar 5, 2020 4:58 PM: Operation Get with file duplicati-b4c05a8cbece5481a950c06df5ec63bda.dblock.zip.aes attempt 5 of 5 failed with message: A task was canceled.

{“ClassName”:“System.Threading.Tasks.TaskCanceledException”,“Message”:“A task was canceled.”,“Data”:null,“InnerException”:null,“HelpURL”:null,“StackTraceString”:" at Duplicati.Library.Main.AsyncDownloader.AsyncDownloaderEnumerator.AsyncDownloadedFile.get_TempFile()\r\n at Duplicati.Library.Main.Operation.RestoreHandler.DoRun(LocalDatabase dbparent, IFilter filter, RestoreResults result)",“RemoteStackTraceString”:null,“RemoteStackIndex”:0,“ExceptionMethod”:“8\nget_TempFile\nDuplicati.Library.Main, Version=2.0.5.1, Culture=neutral, PublicKeyToken=null\nDuplicati.Library.Main.AsyncDownloader+AsyncDownloaderEnumerator+AsyncDownloadedFile\nDuplicati.Library.Utility.TempFile get_TempFile()”,“HResult”:-2146233029,“Source”:“Duplicati.Library.Main”,“WatsonBuckets”:null}

  • Mar 5, 2020 4:56 PM: Backend event: Get - Started: duplicati-b4c05a8cbece5481a950c06df5ec63bda.dblock.zip.aes (150.00 MB)

  • Mar 5, 2020 4:56 PM: Backend event: Get - Retrying: duplicati-b4c05a8cbece5481a950c06df5ec63bda.dblock.zip.aes (150.00 MB)

  • Mar 5, 2020 4:56 PM: Operation Get with file duplicati-b4c05a8cbece5481a950c06df5ec63bda.dblock.zip.aes attempt 4 of 5 failed with message: A task was canceled.

  • Mar 5, 2020 4:55 PM: Backend event: Get - Started: duplicati-b4c05a8cbece5481a950c06df5ec63bda.dblock.zip.aes (150.00 MB)

  • Mar 5, 2020 4:54 PM: Backend event: Get - Retrying: duplicati-b4c05a8cbece5481a950c06df5ec63bda.dblock.zip.aes (150.00 MB)

  • Mar 5, 2020 4:54 PM: Operation Get with file duplicati-b4c05a8cbece5481a950c06df5ec63bda.dblock.zip.aes attempt 3 of 5 failed with message: A task was canceled.

{“ClassName”:“System.Threading.Tasks.TaskCanceledException”,“Message”:“A task was canceled.”,“Data”:null,“InnerException”:null,“HelpURL”:null,“StackTraceString”:" at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)\r\n at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)\r\n at Duplicati.Library.Backend.MicrosoftGraphBackend.Get(String remotename, Stream stream)\r\n at Duplicati.Library.Main.BackendManager.coreDoGetPiping(FileEntryItem item, IEncryption useDecrypter, Int64& retDownloadSize, String& retHashcode)\r\n at Duplicati.Library.Main.BackendManager.DoGet(FileEntryItem item)\r\n at Duplicati.Library.Main.BackendManager.ThreadRun()",“RemoteStackTraceString”:null,“RemoteStackIndex”:0,“ExceptionMethod”:“8\nThrowForNonSuccess\nmscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089\nSystem.Runtime.CompilerServices.TaskAwaiter\nVoid ThrowForNonSuccess(System.Threading.Tasks.Task)”,“HResult”:-2146233029,“Source”:“mscorlib”,“WatsonBuckets”:null}

  • Mar 5, 2020 4:53 PM: Backend event: Get - Started: duplicati-b4c05a8cbece5481a950c06df5ec63bda.dblock.zip.aes (150.00 MB)

  • Mar 5, 2020 4:53 PM: Backend event: Get - Retrying: duplicati-b4c05a8cbece5481a950c06df5ec63bda.dblock.zip.aes (150.00 MB)

  • Mar 5, 2020 4:53 PM: Operation Get with file duplicati-b4c05a8cbece5481a950c06df5ec63bda.dblock.zip.aes attempt 2 of 5 failed with message: A task was canceled.

  • Mar 5, 2020 4:51 PM: Backend event: Get - Started: duplicati-b4c05a8cbece5481a950c06df5ec63bda.dblock.zip.aes (150.00 MB)

  • Mar 5, 2020 4:51 PM: Backend event: Get - Retrying: duplicati-b4c05a8cbece5481a950c06df5ec63bda.dblock.zip.aes (150.00 MB)

  • Mar 5, 2020 4:51 PM: Operation Get with file duplicati-b4c05a8cbece5481a950c06df5ec63bda.dblock.zip.aes attempt 1 of 5 failed with message: A task was canceled.

{“ClassName”:“System.Threading.Tasks.TaskCanceledException”,“Message”:“A task was canceled.”,“Data”:null,“InnerException”:null,“HelpURL”:null,“StackTraceString”:" at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)\r\n at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)\r\n at Duplicati.Library.Backend.MicrosoftGraphBackend.Get(String remotename, Stream stream)\r\n at Duplicati.Library.Main.BackendManager.coreDoGetPiping(FileEntryItem item, IEncryption useDecrypter, Int64& retDownloadSize, String& retHashcode)\r\n at Duplicati.Library.Main.BackendManager.DoGet(FileEntryItem item)\r\n at Duplicati.Library.Main.BackendManager.ThreadRun()",“RemoteStackTraceString”:null,“RemoteStackIndex”:0,“ExceptionMethod”:“8\nThrowForNonSuccess\nmscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089\nSystem.Runtime.CompilerServices.TaskAwaiter\nVoid ThrowForNonSuccess(System.Threading.Tasks.Task)”,“HResult”:-2146233029,“Source”:“mscorlib”,“WatsonBuckets”:null}

  • Mar 5, 2020 4:49 PM: Backend event: Get - Started: duplicati-b4c05a8cbece5481a950c06df5ec63bda.dblock.zip.aes (150.00 MB)

  • Mar 5, 2020 4:49 PM: 1 remote files are required to restore

  • Mar 5, 2020 4:49 PM: Searching backup 0 (29/01/20 7:30:00 AM) …

if someone can help me on the same.

What back end are you using?

2.0.4.16 and on silently drop uploads getting TaskCanceledException from HTTP timeout #3772
possibly is relevant if Throw TimeoutException upon HTTP timeout #3778 only fixed upload side.

–log-file would show seconds, but the magic number for MicrosoftGraphBackend is 100 seconds.
Looking at gap between Started and failed, I see something like 2, 2, 1, 1, 2 minutes, average 96.

Possibly the network connection got slow. Although it’s working oddly on my system recently, set Advanced option –http-operation-timeout to something larger (maybe 5 minutes?) might help this. Alternatively, restarting network equipment can sometimes help, if this is a download speed issue.

If a timeout is suspected, you can push the “Test connection” button on screen 2 Destination while observing in live log at Retry level. The dlist and dindex files are short, and would download, but a dblock at full size (is it 150 MB remote volume size) might see the sort of failure restore is getting.

One hint on live log is that sometimes you can click on the line to get more details about the error.

Similar to issue #3772, the error is confusing because the HttpClient throws an OperationCanceledException when the HTTP timeout is exceeded. However, I believe in issue #3772 the exception was being ignored, where here it is being noticed (but the true reason is hidden).

Pull request #3778 only handled the upload case. We can try and detect the similar situation for GET operations.

It looks like this is now being handled a bit better in .NET Core.

Here’s an attempt to reveal the HTTP timeout in the logs when this happens:

@edp, I would try @ts678’s recommendation of increasing the --http-operation-timeout to see if that helps.

@ts678 ,@warwickmm

will increase http-operation-timeout and post results.

@drwtsn32 - i am using onedrive for backup.

it seems http-operation-timeout has done the trick.

will observe for couple of days and post results.

1 Like

Any news on this?

If I try to download a file with the BackEndTool from OneDrive I get the same error but only on Windows 7, not on Windows 10:

File is about 80MB, Downloadspeed about 400KB/s

Duplicati.CommandLine.BackendTool.exe" GET “onedrivev2://duplicati_onedrive-A01?authid=xxxxxx” duplicati-b7f62c6696d0b4b68aa618132013ed0b2.dblock.zip.aes

Command failed: A task was canceled.
System.Threading.Tasks.TaskCanceledException: A task was canceled.
at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at Duplicati.Library.Backend.MicrosoftGraphBackend.Get(String remotename, Stream stream)
at Duplicati.Library.Backend.MicrosoftGraphBackend.Get(String remotename, String filename)
at Duplicati.CommandLine.BackendTool.Program.RealMain(String _args)

Duplicati version 2.0.5.1_beta_2020-01-18

It seems also that this error always occurs after 100 seconds.

Is there a way to extend the timeout for the backendtool?

–http-operation-timeout=30m does not work for the backendtool

BackendTool unfortunately is quite basic, and supports few options.

I don’t know why Windows version matters. Technically, 7 is retired.

What is the actual problem? Are you in severe need of downloader?

Operations with full Duplicati program should obey a timeout option.

I use the BackendTool.exe in a tool I have written to download each single backup file every 100 days to compare the checksum with the local duplicati database checksum.

The easiest way to download from different clouds was the BackendTool because all the authentification stuff aso. is handled correctly with the string from the duplicati database! No matter if box.com, Google Drive or some others.

But now with OneDrive the verification process fails because the backend tool cannot download the file for checksum creation. :frowning:

Maybe I will change the download inside the tool for OneDrive backends to rclone copy. But nicer would be if BackendTool would work.

The TEST command with all in Duplicati.CommandLine.exe can do that, and has options.
Start with an “Export As Command-line”, then change its syntax from backup form to test.

You could also do your checking gradually (if you prefer) with either backup-test-samples or

  --backup-test-percentage (Integer): The percentage of samples to test after
    a backup
    After a backup is completed, some (dblock, dindex, dlist) files from the
    remote backend are selected for verification. Use this option to specify
    the percentage (between 0 and 100) of files to test. If the
    backup-test-samples option is also provided, the number of samples tested
    is the maximum implied by the two options. If the no-backend-verification
    option is provided, no remote files are verified.
    * default value: 0

Another option is upload-verification-file, then feed that to utility-scripts\DuplicatiVerify.ps1 or such.
Files do need to be accessible to the script, but rclone could get them if you like if you have room.
If you can keep a constant local copy, rclone might even save some bandwidth on unchanged file.

I was lobbying for an increase in the default, but your case where option can’t help is a better case.
Without a user-setting though, it can’t be made to work for all cases. Option might take more work.
Issues is a good place to make the request, to see if a developer would be willing to change things.

Thank you for the advice but my solution fits for my propose more. I check every night from 01:00 to 04:00 and if a file fails it is rechecked the next night and this 3 times and then I will get a mail (happend never so far). Also I can adjust the local checks and checks on clouds are excuted parallel and some other things.

A small database with the last check for each file an a gui showing the current verification rate for each target.

I have changed it yesterday night. If the url is starting with onedrivev2: “rclone copy” is used instead of the backend tool for download the file in a local temp to compute the checksum.