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.
it seems http-operation-timeout has done the trick.
will observe for couple of days and post results.