I ran it with log-file set to profiling and I am still lost. Here is a portion of the log file that shows the failure happening. It fails on the first attempt and never retries. The failure messages do not provide too much insight… I also included the first and the last line of the log file. They show that everything only took less than 5 min. - hardly enough for Duplicati to even start processing the large file (isoimages.vhdx).
Any ideas?
2019-01-21 06:59:45 -05 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started
...
2019-01-21 07:00:44 -05 - [Verbose-Duplicati.Library.Main.Operation.Backup.FileEnumerationProcess-IncludingPath]: Including path as no filters matched: E:\isoimages.vhdx
2019-01-21 07:00:45 -05 - [Verbose-Duplicati.Library.Main.Operation.Backup.MetadataPreProcess.FileEntry-AddDirectory]: Adding directory E:\
2019-01-21 07:00:45 -05 - [Profiling-Timer.Begin-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteScalarInt64]: Starting - ExecuteScalarInt64: INSERT INTO "Remotevolume" ("OperationID", "Name", "Type", "State", "Size", "VerificationCount", "DeleteGraceTime") VALUES (3, "duplicati-bb68efe1533fb4c5ea893385dd7d3e36d.dblock.zip.aes", "Blocks", "Temporary", -1, 0, 0); SELECT last_insert_rowid();
2019-01-21 07:00:45 -05 - [Profiling-Timer.Finished-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteScalarInt64]: ExecuteScalarInt64: INSERT INTO "Remotevolume" ("OperationID", "Name", "Type", "State", "Size", "VerificationCount", "DeleteGraceTime") VALUES (3, "duplicati-bb68efe1533fb4c5ea893385dd7d3e36d.dblock.zip.aes", "Blocks", "Temporary", -1, 0, 0); SELECT last_insert_rowid(); took 0:00:00:00.000
2019-01-21 07:00:45 -05 - [Verbose-Duplicati.Library.Main.Operation.Backup.MetadataPreProcess.FileEntry-AddDirectory]: Adding directory E:\$RECYCLE.BIN\
2019-01-21 07:00:45 -05 - [Verbose-Duplicati.Library.Main.Operation.Backup.FileEnumerationProcess-IncludingPath]: Including path as no filters matched: E:\$RECYCLE.BIN\S-1-5-21-**********-**********-*********-****\
2019-01-21 07:00:45 -05 - [Verbose-Duplicati.Library.Main.Operation.Backup.FileEnumerationProcess-IncludingPath]: Including path as no filters matched: E:\$RECYCLE.BIN\S-1-5-21-**********-**********-*********-****\
2019-01-21 07:00:45 -05 - [Verbose-Duplicati.Library.Main.Operation.Backup.FileEnumerationProcess-IncludingPath]: Including path as no filters matched: E:\$RECYCLE.BIN\S-1-5-21-**********-**********-**********-****\
2019-01-21 07:00:45 -05 - [Verbose-Duplicati.Library.Main.Operation.Backup.MetadataPreProcess.FileEntry-AddDirectory]: Adding directory E:\$RECYCLE.BIN\S-1-5-21-**********-**********-*********-****\
2019-01-21 07:00:45 -05 - [Verbose-Duplicati.Library.Main.Operation.Backup.FileEnumerationProcess-IncludingPath]: Including path as no filters matched: E:\$RECYCLE.BIN\S-1-5-21-**********-**********-*********-****\desktop.ini
2019-01-21 07:00:46 -05 - [Verbose-Duplicati.Library.Main.Operation.Backup.FilePreFilterProcess.FileEntry-CheckFileForChanges]: Checking file for changes E:\isoimages.vhdx, new: True, timestamp changed: True, size changed: True, metadatachanged: True, 11/25/2018 2:11:35 PM vs 1/1/0001 12:00:00 AM
2019-01-21 07:00:46 -05 - [Verbose-Duplicati.Library.Main.Operation.Backup.FilePreFilterProcess.FileEntry-CheckFileForChanges]: Checking file for changes E:\$RECYCLE.BIN\S-1-5-21-**********-**********-*********-****\desktop.ini, new: True, timestamp changed: True, size changed: True, metadatachanged: True, 11/15/2014 8:11:26 PM vs 1/1/0001 12:00:00 AM
2019-01-21 07:00:46 -05 - [Verbose-Duplicati.Library.Main.Operation.Backup.MetadataPreProcess.FileEntry-AddDirectory]: Adding directory E:\$RECYCLE.BIN\S-1-5-21-**********-**********-*********-****\
2019-01-21 07:00:46 -05 - [Verbose-Duplicati.Library.Main.Operation.Backup.FileEnumerationProcess-IncludingPath]: Including path as no filters matched: E:\$RECYCLE.BIN\S-1-5-21-**********-**********-*********-****\desktop.ini
2019-01-21 07:01:57 -05 - [Profiling-Timer.Begin-Duplicati.Library.Main.Operation.Common.DatabaseCommon-CommitTransactionAsync]: Starting - CommitAddBlockToOutputFlush
2019-01-21 07:02:00 -05 - [Profiling-Timer.Finished-Duplicati.Library.Main.Operation.Common.DatabaseCommon-CommitTransactionAsync]: CommitAddBlockToOutputFlush took 0:00:00:02.328
2019-01-21 07:02:00 -05 - [Profiling-Timer.Begin-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteScalarInt64]: Starting - ExecuteScalarInt64: INSERT INTO "Remotevolume" ("OperationID", "Name", "Type", "State", "Size", "VerificationCount", "DeleteGraceTime") VALUES (3, "duplicati-b5e9da7272be24a749082c797fd14f1fc.dblock.zip.aes", "Blocks", "Temporary", -1, 0, 0); SELECT last_insert_rowid();
2019-01-21 07:02:00 -05 - [Profiling-Timer.Finished-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteScalarInt64]: ExecuteScalarInt64: INSERT INTO "Remotevolume" ("OperationID", "Name", "Type", "State", "Size", "VerificationCount", "DeleteGraceTime") VALUES (3, "duplicati-b5e9da7272be24a749082c797fd14f1fc.dblock.zip.aes", "Blocks", "Temporary", -1, 0, 0); SELECT last_insert_rowid(); took 0:00:00:00.000
2019-01-21 07:02:13 -05 - [Profiling-Timer.Begin-Duplicati.Library.Main.Operation.Common.DatabaseCommon-CommitTransactionAsync]: Starting - CommitAddBlockToOutputFlush
2019-01-21 07:02:13 -05 - [Profiling-Timer.Finished-Duplicati.Library.Main.Operation.Common.DatabaseCommon-CommitTransactionAsync]: CommitAddBlockToOutputFlush took 0:00:00:00.140
2019-01-21 07:02:14 -05 - [Profiling-Timer.Begin-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteScalarInt64]: Starting - ExecuteScalarInt64: INSERT INTO "Remotevolume" ("OperationID", "Name", "Type", "State", "Size", "VerificationCount", "DeleteGraceTime") VALUES (3, "duplicati-b86cb98f0b1f34dae8024e7a139531259.dblock.zip.aes", "Blocks", "Temporary", -1, 0, 0); SELECT last_insert_rowid();
2019-01-21 07:02:14 -05 - [Profiling-Timer.Finished-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteScalarInt64]: ExecuteScalarInt64: INSERT INTO "Remotevolume" ("OperationID", "Name", "Type", "State", "Size", "VerificationCount", "DeleteGraceTime") VALUES (3, "duplicati-b86cb98f0b1f34dae8024e7a139531259.dblock.zip.aes", "Blocks", "Temporary", -1, 0, 0); SELECT last_insert_rowid(); took 0:00:00:00.312
2019-01-21 07:02:28 -05 - [Profiling-Timer.Begin-Duplicati.Library.Main.Operation.Common.DatabaseCommon-CommitTransactionAsync]: Starting - CommitAddBlockToOutputFlush
2019-01-21 07:02:30 -05 - [Profiling-Timer.Finished-Duplicati.Library.Main.Operation.Common.DatabaseCommon-CommitTransactionAsync]: CommitAddBlockToOutputFlush took 0:00:00:02.266
2019-01-21 07:02:41 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-bb68efe1533fb4c5ea893385dd7d3e36d.dblock.zip.aes (49.94 MB)
2019-01-21 07:04:26 -05 - [Retry-Duplicati.Library.Main.Operation.Common.BackendHandler-RetryPut]: Operation Put with file duplicati-bb68efe1533fb4c5ea893385dd7d3e36d.dblock.zip.aes attempt 1 of 5 failed with message: 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.OAuthHttpClient.<SendAsync>d__4.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
...
2019-01-21 07:04:30 -05 - [Profiling-Timer.Finished-Duplicati.Library.Main.Controller-RunBackup]: Running Backup took 0:00:04:44.762