(Bad USB Controller?) System.Exception: Unexpected number of remote volumes marked as deleted

I’ve installed Duplicati (current BETA release) fresh on a debian amd64 buster (10) VM to backup my data. With fresh backup jobs set-up, the 880 GB data backup ran for over 10 hours and suddenly stopped at ~ 95% completion. I don’t know if that’s a bug yet, because I’ve not yet looked for a way to reproduce it.

The Log says:

System.Exception: Unexpected number of remote volumes marked as deleted. Found 0 filesets, but 1 volumes
  at Duplicati.Library.Main.Database.LocalDeleteDatabase+<DropFilesetsFromTable>d__5.MoveNext () [0x0027e] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at System.Collections.Generic.LargeArrayBuilder`1[T].AddRange (System.Collections.Generic.IEnumerable`1[T] items) [0x00046] in <13c0993ff82548209b09f271bd5e6a78>:0 
  at System.Collections.Generic.EnumerableHelpers.ToArray[T] (System.Collections.Generic.IEnumerable`1[T] source) [0x0003c] in <13c0993ff82548209b09f271bd5e6a78>:0 
  at System.Linq.Enumerable.ToArray[TSource] (System.Collections.Generic.IEnumerable`1[T] source) [0x0002c] in <13c0993ff82548209b09f271bd5e6a78>:0 
  at Duplicati.Library.Main.Operation.DeleteHandler.DoRun (Duplicati.Library.Main.Database.LocalDeleteDatabase db, System.Data.IDbTransaction& transaction, System.Boolean hasVerifiedBackend, System.Boolean forceCompact, Duplicati.Library.Main.BackendManager sharedManager) [0x0018d] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Operation.BackupHandler.CompactIfRequired (Duplicati.Library.Main.BackendManager backend, System.Int64 lastVolumeSize) [0x000a5] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Operation.BackupHandler.RunAsync (System.String[] sources, Duplicati.Library.Utility.IFilter filter, System.Threading.CancellationToken token) [0x01048] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at CoCoL.ChannelExtensions.WaitForTaskOrThrow (System.Threading.Tasks.Task task) [0x00050] in <9a758ff4db6c48d6b3d4d0e5c2adf6d1>:0 
  at Duplicati.Library.Main.Operation.BackupHandler.Run (System.String[] sources, Duplicati.Library.Utility.IFilter filter, System.Threading.CancellationToken token) [0x00009] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Controller+<>c__DisplayClass14_0.<Backup>b__0 (Duplicati.Library.Main.BackupResults result) [0x0004b] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Controller.RunAction[T] (T result, System.String[]& paths, Duplicati.Library.Utility.IFilter& filter, System.Action`1[T] method) [0x0026f] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Controller.Backup (System.String[] inputsources, Duplicati.Library.Utility.IFilter filter) [0x00074] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Server.Runner.Run (Duplicati.Server.Runner+IRunnerData data, System.Boolean fromQueue) [0x00349] in <156011ea63b34859b4073abdbf0b1573>:0

Then my phone beeped because I’m pushing messages for failed backup job executions to Telegram “Backup failed FATAL”.

I’m backing up to a vsftpd FTP-Server. The service wasn’t interrupted while backing up. How can I debug this further? At the moment, I’ve hit the “Start backup now” button to re-execute the job again and see how it goes.

Thank you.

Kind regards,
Catfriend1

Duplicati version: 2.0.6.3_beta_2021-06-17

I’ve started to backup the same 880 GB of data again, this time, I’ve swapped the FTP server target and used local storage instead as target. Unfortunately, I’m getting the same error message again.

image

When I hit the “show” button, nothing comes up.

Is this a bug? What can I do to work around the problem? I’m absolutely clueless why it fails.

Looking in the About / Saved logs tab, it shows:

Did you start completely over, or did you just change where you pointed your backup destination?

If you want to start completely over, and you don’t care about the backup data in your old location, a simple way is to make sure the new target is empty and also delete your local job database. Then when you run a backup it will behave as if it’s the very first backup.

yes, I’ve exactly did that following the UI to delete the job including all files. Double checked, job (ui), sqlite db and files were deleted. I’ve reconfigured the same job again from scratch and ran into the issue again. How can I see more detailed what went wrong? The above error looks a bit generic.

@drwtsn32 I’ve now ran the job a third time exactly generated from scratch like before. Now, it didn’t fail. Verify still needs to be done… to be sure file integrity is correct.

The only thing I’ve changed before the third attempt was adding swap to the machine running duplicati. I’ve had 10 G of physical memory when it reproducibly failed in try 1 and 2. I’ve had 10 G physical + 16 G swap memory with vm.swapiness = 0 when it succeeded in try 3.

Could that be an out of memory issue? I’ve made sure my hardware isn’t bad meanwhilst. If it is OOM , could duplicati please stop with a more precise error message like " couldn’t finish database task because your database is about … MiB and your free memory is getting low with … MiB. please try adding swap or more physical memory and delete / recreate the job to try again. "

I don’t think I’ve seen Duplicati use that much memory, so I’m not sure if that’s the issue. I have seen people have issues with Duplicati when they restrict the memory to something like 512MB. On my NAS I run Duplicati in docker and back up about the same amount of data. I think its memory usage stays under 1GB.

1 Like

If I turn off swap , the error comes up again , but only when I try to freshly redo the whole job. incrementals seem to require less memory than full initial job executions. Also, increasing the system’s mem from 10 to 12 gb ram helps to avoid this problem. I think it is time for a more clear error message like “job failed - please check free memory”.

The error that you’re seeing is usually at the end because it’s cleaning things up after backup is done.
Having suffered through these a few times, does the amount of backup it gets through seem to vary?

I’ll mention logs later, but another way to see if you “finished” a backup is when dlist file is uploaded.
This represents a backup version, and the error message you’re seeing is in backup version cleanup.

Can you do that? There’s lots of experimentation here, but are there any free or used memory figures?

Duplicati does not ordinarily need a large amount of memory to itself. Is yours used up by other things? Possibly such things also run periodically, so a longer term study (e.g. using sar) would be appropriate.

There have been a few memory leaks, meaning process size grows, but they’re usually highly specific.

You can probably take a look at the system with top which has both system info and some per-process.
For process specifics, ps is handy. For system, sar and many other tools can check its memory health.

In addition, the Linux OOM-killer could kill selected processes when memory is exhausted. Is this seen?

Duplicati is coded in C#, and its portable code that is installed is processed by mono except on Windows where it is processed by .NET Framework. It is the runtime’s job to notifify on out of memory (if possible).

Please search OutOfMemoryException at forum.duplicati.com and github.com/duplicati/duplicati/issues for some of the history. There is no guarantee that the interpreter or Duplicati catch all the cases though.

There’s some nice indirect evidence here of something affected by memory, but memory may also affect speed and other things that in turn may affect Duplicati into causing an error-that-shouldn’t-be-happening.

In addition to monitoring process and system memory to try to directly watch for any oddities, set up logs.
log-file=<path> and log-file-log-level at least at Information, with more at Verbose. Profiling will grow huge, unfortunately it might come down to that later. Can you get this on a smaller backup (easier to deal with)?

Also, please try to stay as close to defaults as possible (no Advanced options to wonder about as cause).
The best problem has steps to reproduce that anybody can do with the equipment they have. Then debug becomes more possible. In this sense, testing with a local folder destination was a good idea, and it also reduces some concern about whether there were errors to the destination, as Internet storage often does.

Unexpected number of deleted filesets 1 vs 0 #1583

“Unexpected number of remote volumes marked as deleted. Found 0 filesets, but 1 volumes”

You can see that this is a long-lived seeming catch-all for such errors, but latest report above is like yours.
Order matters. The first number would ordinarily be 0 for new backups, as it’s driven by retention policies. Deleting initial backup makes no sense. Second number is driven by database status which is not directly viewable in the middle of the backup. It has to be inferred by other things, including possibly a detailed log.

1 Like

Ok thanks for the detailed explanation. I’m now happy my prod environment backs up again. But I’ve set a reminder in a few days where I’ll try to find a reproducer, with a smaller backup set and more knowledge on what to look for according to the insights you’d given me :-). My system does not have so many other parts/software involved, I think it’s perfectly possible to use its documentation again to build a test vm.

Ok, on production instance, this looks very bad.

When the System.Exception reported above occurred and I tried to test files, I always got exactly one “dblock.zip.aes” where it said test failed. I’ve did a write test on the drive, swapped drives but didn’t get rid of the problem.

Now, production backup (fully started from scratch with swap enabled) ran successfully in the initial attempt to execute the job. Then it worked okay some days and now the errors are back a little different:

{
  "DeletedFiles": 1,
  "DeletedFolders": 0,
  "ModifiedFiles": 45,
  "ExaminedFiles": 69242,
  "OpenedFiles": 54,
  "AddedFiles": 9,
  "SizeOfModifiedFiles": 5517,
  "SizeOfAddedFiles": 13056069,
  "SizeOfExaminedFiles": 754539488684,
  "SizeOfOpenedFiles": 135931188,
  "NotProcessedFiles": 0,
  "AddedFolders": 1,
  "TooLargeFiles": 0,
  "FilesWithError": 0,
  "ModifiedFolders": 0,
  "ModifiedSymlinks": 0,
  "AddedSymlinks": 0,
  "DeletedSymlinks": 0,
  "PartialBackup": false,
  "Dryrun": false,
  "MainOperation": "Backup",
  "CompactResults": {
    "DeletedFileCount": 2,
    "DownloadedFileCount": 0,
    "UploadedFileCount": 0,
    "DeletedFileSize": 37962,
    "DownloadedFileSize": 0,
    "UploadedFileSize": 0,
    "Dryrun": false,
    "VacuumResults": null,
    "MainOperation": "Compact",
    "ParsedResult": "Success",
    "Version": "2.0.6.3 (2.0.6.3_beta_2021-06-17)",
    "EndTime": "2021-07-16T02:03:04.932437Z",
    "BeginTime": "2021-07-16T02:02:37.586016Z",
    "Duration": "00:00:27.3464210",
    "MessagesActualLength": 0,
    "WarningsActualLength": 0,
    "ErrorsActualLength": 0,
    "Messages": null,
    "Warnings": null,
    "Errors": null,
    "BackendStatistics": {
      "RemoteCalls": 40,
      "BytesUploaded": 20267975,
      "BytesDownloaded": 792146928,
      "FilesUploaded": 3,
      "FilesDownloaded": 32,
      "FilesDeleted": 3,
      "FoldersCreated": 0,
      "RetryAttempts": 4,
      "UnknownFileSize": 0,
      "UnknownFileCount": 0,
      "KnownFileCount": 27466,
      "KnownFileSize": 719781678210,
      "LastBackupDate": "2021-07-16T04:00:00+02:00",
      "BackupListCount": 8,
      "TotalQuotaSpace": 0,
      "FreeQuotaSpace": 0,
      "AssignedQuotaSpace": -1,
      "ReportedQuotaError": false,
      "ReportedQuotaWarning": false,
      "MainOperation": "Backup",
      "ParsedResult": "Success",
      "Version": "2.0.6.3 (2.0.6.3_beta_2021-06-17)",
      "EndTime": "0001-01-01T00:00:00",
      "BeginTime": "2021-07-16T02:00:00.002561Z",
      "Duration": "00:00:00",
      "MessagesActualLength": 0,
      "WarningsActualLength": 0,
      "ErrorsActualLength": 0,
      "Messages": null,
      "Warnings": null,
      "Errors": null
    }
  },
  "VacuumResults": null,
  "DeleteResults": {
    "DeletedSetsActualLength": 1,
    "DeletedSets": [
      {
        "Item1": 7,
        "Item2": "2021-07-09T04:00:00+02:00"
      }
    ],
    "Dryrun": false,
    "MainOperation": "Delete",
    "CompactResults": {
      "DeletedFileCount": 2,
      "DownloadedFileCount": 0,
      "UploadedFileCount": 0,
      "DeletedFileSize": 37962,
      "DownloadedFileSize": 0,
      "UploadedFileSize": 0,
      "Dryrun": false,
      "VacuumResults": null,
      "MainOperation": "Compact",
      "ParsedResult": "Success",
      "Version": "2.0.6.3 (2.0.6.3_beta_2021-06-17)",
      "EndTime": "2021-07-16T02:03:04.932437Z",
      "BeginTime": "2021-07-16T02:02:37.586016Z",
      "Duration": "00:00:27.3464210",
      "MessagesActualLength": 0,
      "WarningsActualLength": 0,
      "ErrorsActualLength": 0,
      "Messages": null,
      "Warnings": null,
      "Errors": null,
      "BackendStatistics": {
        "RemoteCalls": 40,
        "BytesUploaded": 20267975,
        "BytesDownloaded": 792146928,
        "FilesUploaded": 3,
        "FilesDownloaded": 32,
        "FilesDeleted": 3,
        "FoldersCreated": 0,
        "RetryAttempts": 4,
        "UnknownFileSize": 0,
        "UnknownFileCount": 0,
        "KnownFileCount": 27466,
        "KnownFileSize": 719781678210,
        "LastBackupDate": "2021-07-16T04:00:00+02:00",
        "BackupListCount": 8,
        "TotalQuotaSpace": 0,
        "FreeQuotaSpace": 0,
        "AssignedQuotaSpace": -1,
        "ReportedQuotaError": false,
        "ReportedQuotaWarning": false,
        "MainOperation": "Backup",
        "ParsedResult": "Success",
        "Version": "2.0.6.3 (2.0.6.3_beta_2021-06-17)",
        "EndTime": "0001-01-01T00:00:00",
        "BeginTime": "2021-07-16T02:00:00.002561Z",
        "Duration": "00:00:00",
        "MessagesActualLength": 0,
        "WarningsActualLength": 0,
        "ErrorsActualLength": 0,
        "Messages": null,
        "Warnings": null,
        "Errors": null
      }
    },
    "ParsedResult": "Success",
    "Version": "2.0.6.3 (2.0.6.3_beta_2021-06-17)",
    "EndTime": "2021-07-16T02:03:04.932443Z",
    "BeginTime": "2021-07-16T02:02:11.627958Z",
    "Duration": "00:00:53.3044850",
    "MessagesActualLength": 0,
    "WarningsActualLength": 0,
    "ErrorsActualLength": 0,
    "Messages": null,
    "Warnings": null,
    "Errors": null,
    "BackendStatistics": {
      "RemoteCalls": 40,
      "BytesUploaded": 20267975,
      "BytesDownloaded": 792146928,
      "FilesUploaded": 3,
      "FilesDownloaded": 32,
      "FilesDeleted": 3,
      "FoldersCreated": 0,
      "RetryAttempts": 4,
      "UnknownFileSize": 0,
      "UnknownFileCount": 0,
      "KnownFileCount": 27466,
      "KnownFileSize": 719781678210,
      "LastBackupDate": "2021-07-16T04:00:00+02:00",
      "BackupListCount": 8,
      "TotalQuotaSpace": 0,
      "FreeQuotaSpace": 0,
      "AssignedQuotaSpace": -1,
      "ReportedQuotaError": false,
      "ReportedQuotaWarning": false,
      "MainOperation": "Backup",
      "ParsedResult": "Success",
      "Version": "2.0.6.3 (2.0.6.3_beta_2021-06-17)",
      "EndTime": "0001-01-01T00:00:00",
      "BeginTime": "2021-07-16T02:00:00.002561Z",
      "Duration": "00:00:00",
      "MessagesActualLength": 0,
      "WarningsActualLength": 0,
      "ErrorsActualLength": 0,
      "Messages": null,
      "Warnings": null,
      "Errors": null
    }
  },
  "RepairResults": null,
  "TestResults": {
    "MainOperation": "Test",
    "VerificationsActualLength": 28,
    "Verifications": [
      {
        "Key": "duplicati-20210716T020000Z.dlist.zip.aes",
        "Value": []
      },
      {
        "Key": "duplicati-20210711T020000Z.dlist.zip.aes",
        "Value": []
      },
      {
        "Key": "duplicati-20210710T020000Z.dlist.zip.aes",
        "Value": []
      },
      {
        "Key": "duplicati-20210713T020000Z.dlist.zip.aes",
        "Value": []
      },
      {
        "Key": "duplicati-20210714T020000Z.dlist.zip.aes",
        "Value": []
      },
      {
        "Key": "duplicati-20210715T020000Z.dlist.zip.aes",
        "Value": []
      },
      {
        "Key": "duplicati-20210712T020000Z.dlist.zip.aes",
        "Value": []
      },
      {
        "Key": "duplicati-20210707T125044Z.dlist.zip.aes",
        "Value": []
      },
      {
        "Key": "duplicati-i9b6b8305a4414a90899cbc9c9b7ff26e.dindex.zip.aes",
        "Value": []
      },
      {
        "Key": "duplicati-ie68c181faee648e1a0e095a7002be2e8.dindex.zip.aes",
        "Value": []
      },
      {
        "Key": "duplicati-i857d2b416c8545ada64d508767f4a7dc.dindex.zip.aes",
        "Value": []
      },
      {
        "Key": "duplicati-i4113be80549d43c6868abb5ca644d80d.dindex.zip.aes",
        "Value": []
      },
      {
        "Key": "duplicati-i17fb2ea842774092abcd05d8a4030d07.dindex.zip.aes",
        "Value": []
      },
      {
        "Key": "duplicati-i5828fa3ed12d41349c894e836ac831ca.dindex.zip.aes",
        "Value": []
      },
      {
        "Key": "duplicati-i86350b79ecfb44628523e7299524686b.dindex.zip.aes",
        "Value": []
      },
      {
        "Key": "duplicati-i7fbb92382e624e8cbb383edcb60d79ed.dindex.zip.aes",
        "Value": []
      },
      {
        "Key": "duplicati-ied632045e16842e49a3675f5c8948abe.dindex.zip.aes",
        "Value": []
      },
      {
        "Key": "duplicati-ice20671f76514ae7a7ea55cc2ce707ab.dindex.zip.aes",
        "Value": []
      },
      {
        "Key": "duplicati-b807fea1d40344695aa5ebe0f3f0b5907.dblock.zip.aes",
        "Value": []
      },
      {
        "Key": "duplicati-b70b0ce9be1354f17b1a522f58030561d.dblock.zip.aes",
        "Value": []
      }
    ],
    "ParsedResult": "Success",
    "Version": "2.0.6.3 (2.0.6.3_beta_2021-06-17)",
    "EndTime": "2021-07-16T02:03:57.87858Z",
    "BeginTime": "2021-07-16T02:03:08.970637Z",
    "Duration": "00:00:48.9079430",
    "MessagesActualLength": 0,
    "WarningsActualLength": 0,
    "ErrorsActualLength": 0,
    "Messages": null,
    "Warnings": null,
    "Errors": null,
    "BackendStatistics": {
      "RemoteCalls": 40,
      "BytesUploaded": 20267975,
      "BytesDownloaded": 792146928,
      "FilesUploaded": 3,
      "FilesDownloaded": 32,
      "FilesDeleted": 3,
      "FoldersCreated": 0,
      "RetryAttempts": 4,
      "UnknownFileSize": 0,
      "UnknownFileCount": 0,
      "KnownFileCount": 27466,
      "KnownFileSize": 719781678210,
      "LastBackupDate": "2021-07-16T04:00:00+02:00",
      "BackupListCount": 8,
      "TotalQuotaSpace": 0,
      "FreeQuotaSpace": 0,
      "AssignedQuotaSpace": -1,
      "ReportedQuotaError": false,
      "ReportedQuotaWarning": false,
      "MainOperation": "Backup",
      "ParsedResult": "Success",
      "Version": "2.0.6.3 (2.0.6.3_beta_2021-06-17)",
      "EndTime": "0001-01-01T00:00:00",
      "BeginTime": "2021-07-16T02:00:00.002561Z",
      "Duration": "00:00:00",
      "MessagesActualLength": 0,
      "WarningsActualLength": 0,
      "ErrorsActualLength": 0,
      "Messages": null,
      "Warnings": null,
      "Errors": null
    }
  },
  "ParsedResult": "Error",
  "Version": "2.0.6.3 (2.0.6.3_beta_2021-06-17)",
  "EndTime": "2021-07-16T02:03:58.423259Z",
  "BeginTime": "2021-07-16T02:00:00.002551Z",
  "Duration": "00:03:58.4207080",
  "MessagesActualLength": 97,
  "WarningsActualLength": 0,
  "ErrorsActualLength": 1,
  "Messages": [
    "2021-07-16 04:00:00 +02 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: Die Operation Backup wurde gestartet",
    "2021-07-16 04:00:14 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started:  ()",
    "2021-07-16 04:00:20 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed:  (26,82 KB)",
    "2021-07-16 04:02:05 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-bc9f793d3184f4d63970388c6b7fb1b52.dblock.zip.aes (12,43 MB)",
    "2021-07-16 04:02:06 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-bc9f793d3184f4d63970388c6b7fb1b52.dblock.zip.aes (12,43 MB)",
    "2021-07-16 04:02:09 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-icc75df57b68c4b9e82844b2b644a74c7.dindex.zip.aes (13,00 KB)",
    "2021-07-16 04:02:09 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-icc75df57b68c4b9e82844b2b644a74c7.dindex.zip.aes (13,00 KB)",
    "2021-07-16 04:02:11 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-20210716T020000Z.dlist.zip.aes (6,89 MB)",
    "2021-07-16 04:02:11 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-20210716T020000Z.dlist.zip.aes (6,89 MB)",
    "2021-07-16 04:02:11 +02 - [Information-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-StartCheck]: Start checking if backups can be removed",
    "2021-07-16 04:02:11 +02 - [Information-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-FramesAndIntervals]: Time frames and intervals pairs: 7.00:00:00 / 1.00:00:00, 28.00:00:00 / 7.00:00:00, 365.00:00:00 / 31.00:00:00",
    "2021-07-16 04:02:11 +02 - [Information-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-BackupList]: Backups to consider: 15.07.2021 04:00:00, 14.07.2021 04:00:00, 13.07.2021 04:00:00, 12.07.2021 04:00:00, 11.07.2021 04:00:00, 10.07.2021 04:00:00, 09.07.2021 04:00:00, 07.07.2021 14:50:44",
    "2021-07-16 04:02:11 +02 - [Information-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-BackupsToDelete]: Backups outside of all time frames and thus getting deleted: ",
    "2021-07-16 04:02:11 +02 - [Information-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-AllBackupsToDelete]: All backups to delete: 09.07.2021 04:00:00",
    "2021-07-16 04:02:11 +02 - [Information-Duplicati.Library.Main.Operation.DeleteHandler-DeleteRemoteFileset]: Deleting 1 remote fileset(s) ...",
    "2021-07-16 04:02:37 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Delete - Started: duplicati-20210709T020000Z.dlist.zip.aes (6,88 MB)",
    "2021-07-16 04:02:37 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Delete - Completed: duplicati-20210709T020000Z.dlist.zip.aes (6,88 MB)",
    "2021-07-16 04:02:37 +02 - [Information-Duplicati.Library.Main.Operation.DeleteHandler-DeleteResults]: Deleted 1 remote fileset(s)",
    "2021-07-16 04:03:04 +02 - [Information-Duplicati.Library.Main.Database.LocalDeleteDatabase-CompactReason]: Compacting because there are 1 fully deletable volume(s)",
    "2021-07-16 04:03:04 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Delete - Started: duplicati-b51dbfb4242934f6197d163358ed2fc53.dblock.zip.aes (34,67 KB)"
  ],
  "Warnings": [],
  "Errors": [
    "2021-07-16 04:03:56 +02 - [Error-Duplicati.Library.Main.Operation.TestHandler-FailedToProcessFile]: Failed to process file duplicati-b9a5fbc11a1ca44938f82a21da57580a8.dblock.zip.aes"
  ],
  "BackendStatistics": {
    "RemoteCalls": 40,
    "BytesUploaded": 20267975,
    "BytesDownloaded": 792146928,
    "FilesUploaded": 3,
    "FilesDownloaded": 32,
    "FilesDeleted": 3,
    "FoldersCreated": 0,
    "RetryAttempts": 4,
    "UnknownFileSize": 0,
    "UnknownFileCount": 0,
    "KnownFileCount": 27466,
    "KnownFileSize": 719781678210,
    "LastBackupDate": "2021-07-16T04:00:00+02:00",
    "BackupListCount": 8,
    "TotalQuotaSpace": 0,
    "FreeQuotaSpace": 0,
    "AssignedQuotaSpace": -1,
    "ReportedQuotaError": false,
    "ReportedQuotaWarning": false,
    "MainOperation": "Backup",
    "ParsedResult": "Success",
    "Version": "2.0.6.3 (2.0.6.3_beta_2021-06-17)",
    "EndTime": "0001-01-01T00:00:00",
    "BeginTime": "2021-07-16T02:00:00.002561Z",
    "Duration": "00:00:00",
    "MessagesActualLength": 0,
    "WarningsActualLength": 0,
    "ErrorsActualLength": 0,
    "Messages": null,
    "Warnings": null,
    "Errors": null
  }
}

I’ve now ran the backup job manually again (with existing DB + data + backup set) and set the extended option “check-file-count” to “99999999999” in order to check all files.

In the verbose live log, I’m getting a lot of these, but I’m sure the disk is okay. What other causes could that have? I’ve also connected local storage and got hash mismatches (instead of the FTP server with the USB Mass Storage Device).

* 16. Jul. 2021 12:15: Backend event: Get - Retrying: duplicati-b75a5538a51c6457f8345d956399308e9.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:15: Operation Get with file duplicati-b75a5538a51c6457f8345d956399308e9.dblock.zip.aes attempt 1 of 5 failed with message: Fehlerhafter Hash-Wert für Datei "/tmp/dup-3ddcbba4-d236-4abf-8218-ab119151b411", gespeicherter Hash: hzmINioI+xtkMyuwHBB4OM49MU1DZ1X/OeWS7thPXjk=, aktueller Hash pq5OonZl+y0tavSmANUqlelYng7+GB0ih/TkEp3FnSU=

* 16. Jul. 2021 12:15: Backend event: Get - Completed: duplicati-b75a5538a51c6457f8345d956399308e9.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:15: Backend event: Get - Started: duplicati-b75a5538a51c6457f8345d956399308e9.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:15: Backend event: Get - Completed: duplicati-bb2924f70601944daa5b0ed868f1f535b.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:15: Backend event: Get - Started: duplicati-bb2924f70601944daa5b0ed868f1f535b.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:15: Backend event: Get - Completed: duplicati-b919de26337b64971a9c91e3184be30ba.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:15: Backend event: Get - Started: duplicati-b919de26337b64971a9c91e3184be30ba.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:15: Backend event: Get - Completed: duplicati-b9e62696fe4da4959a08995b4b085ed3a.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:15: Backend event: Get - Started: duplicati-b9e62696fe4da4959a08995b4b085ed3a.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:15: Backend event: Get - Completed: duplicati-b817c441971f24edfbd5d8a08aa83cc9d.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Started: duplicati-b817c441971f24edfbd5d8a08aa83cc9d.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Completed: duplicati-b5d0e7aeb917d4244882da9181cc28b0f.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Started: duplicati-b5d0e7aeb917d4244882da9181cc28b0f.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Completed: duplicati-b3b5dd930650b4136aadf9cc3d1f1ae99.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Started: duplicati-b3b5dd930650b4136aadf9cc3d1f1ae99.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Completed: duplicati-b29c37e57044c4397aedb0c3e0a700bf2.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Started: duplicati-b29c37e57044c4397aedb0c3e0a700bf2.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Completed: duplicati-b9fd08d5e4d074e1788d2359a44748126.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Started: duplicati-b9fd08d5e4d074e1788d2359a44748126.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Completed: duplicati-b771a3e94f98b47ad841b3a847acf6140.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Started: duplicati-b771a3e94f98b47ad841b3a847acf6140.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Completed: duplicati-b0f3664998fc240b0996dbe4a45f85c0f.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Started: duplicati-b0f3664998fc240b0996dbe4a45f85c0f.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Completed: duplicati-bb2dbf65d79644e75b223b70f34011131.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Started: duplicati-bb2dbf65d79644e75b223b70f34011131.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Completed: duplicati-b5d7b6519a9d84a52b79cb78c4c06621c.dblock.zip.aes (49,92 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Started: duplicati-b5d7b6519a9d84a52b79cb78c4c06621c.dblock.zip.aes (49,92 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Completed: duplicati-b7de04681bc3346338b32a83f3dded8e3.dblock.zip.aes (49,97 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Started: duplicati-b7de04681bc3346338b32a83f3dded8e3.dblock.zip.aes (49,97 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Completed: duplicati-b36c8d2601bc642b3aa895058f8de80b7.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Started: duplicati-b36c8d2601bc642b3aa895058f8de80b7.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Completed: duplicati-b5e153f8ba37e442db0a0a1e8eb647281.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Started: duplicati-b5e153f8ba37e442db0a0a1e8eb647281.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Completed: duplicati-b5553d6668d5940dc8b80ab1dc48b022e.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Started: duplicati-b5553d6668d5940dc8b80ab1dc48b022e.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Completed: duplicati-baf925f12f0a84d2f96effda8945d35cd.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Started: duplicati-baf925f12f0a84d2f96effda8945d35cd.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Completed: duplicati-ba5a6d1f46ab2442c9f2fb331bc455f67.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Started: duplicati-ba5a6d1f46ab2442c9f2fb331bc455f67.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Completed: duplicati-b54272579a3464b45a4f4c3363f082362.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Started: duplicati-b54272579a3464b45a4f4c3363f082362.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Completed: duplicati-b9c28dec8f94f4cc3a908bcc53789e86d.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Started: duplicati-b9c28dec8f94f4cc3a908bcc53789e86d.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Completed: duplicati-b8b966b058a4e4bf398a31a209c39058b.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Started: duplicati-b8b966b058a4e4bf398a31a209c39058b.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Completed: duplicati-bd8b6f2189ff74c4bbcde0ebf770e796e.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Started: duplicati-bd8b6f2189ff74c4bbcde0ebf770e796e.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Completed: duplicati-b97f3cf6e9f66407eb5ad9b4be3a5cda1.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Started: duplicati-b97f3cf6e9f66407eb5ad9b4be3a5cda1.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Completed: duplicati-ba4da5a70f89544a2a9d0b01254571f63.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Started: duplicati-ba4da5a70f89544a2a9d0b01254571f63.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Completed: duplicati-b871d7b6d1a5b4ed687cbc95271a2e898.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Started: duplicati-b871d7b6d1a5b4ed687cbc95271a2e898.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Completed: duplicati-b9d2412fa6f0b40de936c10602eb3babd.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Started: duplicati-b9d2412fa6f0b40de936c10602eb3babd.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Completed: duplicati-b7decdb88e00f424a9f7a1f01863bd119.dblock.zip.aes (49,95 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Started: duplicati-b7decdb88e00f424a9f7a1f01863bd119.dblock.zip.aes (49,95 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Completed: duplicati-ba1a694674fdc409e91b0ee49adc75a43.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Started: duplicati-ba1a694674fdc409e91b0ee49adc75a43.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Completed: duplicati-bf3b0f2ca7f624bdf8a5afcd623d4858f.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Started: duplicati-bf3b0f2ca7f624bdf8a5afcd623d4858f.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Completed: duplicati-be9d23d9891a14273815f917ab1787c74.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Started: duplicati-be9d23d9891a14273815f917ab1787c74.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Completed: duplicati-bad7abb0c32b447b98d6eeccfb58fa2f9.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Started: duplicati-bad7abb0c32b447b98d6eeccfb58fa2f9.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Completed: duplicati-bb6a1455e6f5b4aa79d7f863fc41648d3.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Started: duplicati-bb6a1455e6f5b4aa79d7f863fc41648d3.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Completed: duplicati-bff3e0333d06b42c895cd95e2884635b9.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Started: duplicati-bff3e0333d06b42c895cd95e2884635b9.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Completed: duplicati-bbaa11726d86748b3b00042e33aa7ede8.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Started: duplicati-bbaa11726d86748b3b00042e33aa7ede8.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Completed: duplicati-bfe1184f3d0c44ba9bb57286f71d92a41.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Started: duplicati-bfe1184f3d0c44ba9bb57286f71d92a41.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Completed: duplicati-b92487875baa64e35bc985b565e0476eb.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Started: duplicati-b92487875baa64e35bc985b565e0476eb.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Completed: duplicati-bf25dd945f8e74c4c80b580d6dcbdd42a.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Started: duplicati-bf25dd945f8e74c4c80b580d6dcbdd42a.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Completed: duplicati-b8f41e117b1d34e9db18c32c0411a3489.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Started: duplicati-b8f41e117b1d34e9db18c32c0411a3489.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Completed: duplicati-b6e15907be1c14ac3b1e7ce7c5b8f890a.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Started: duplicati-b6e15907be1c14ac3b1e7ce7c5b8f890a.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Completed: duplicati-bff1092756825470e9ed9914d4ab5d80e.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Started: duplicati-bff1092756825470e9ed9914d4ab5d80e.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Completed: duplicati-b8fdea56bc80e4cb694ea534c5a324298.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Started: duplicati-b8fdea56bc80e4cb694ea534c5a324298.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Completed: duplicati-b078913d911e24998adb7a5ee8faf2cc7.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Started: duplicati-b078913d911e24998adb7a5ee8faf2cc7.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Completed: duplicati-b5b3642888879491490c37aa90cff4234.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Started: duplicati-b5b3642888879491490c37aa90cff4234.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Completed: duplicati-bc607fb79b0f44dbd9aa5349e6b7b8e21.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Started: duplicati-bc607fb79b0f44dbd9aa5349e6b7b8e21.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Completed: duplicati-b07c6ac26f2cd4af68435231cceaad3d4.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Started: duplicati-b07c6ac26f2cd4af68435231cceaad3d4.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Completed: duplicati-b51379be9e18c4795a89d837ae44b8f8f.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Started: duplicati-b51379be9e18c4795a89d837ae44b8f8f.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Completed: duplicati-ba49ec8933b124a00a17ab6d468e67216.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Started: duplicati-ba49ec8933b124a00a17ab6d468e67216.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Completed: duplicati-b977a52ef559d478f8d3673ebb261b310.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Started: duplicati-b977a52ef559d478f8d3673ebb261b310.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:14: Failed to process file duplicati-bb99e35bea67c4da7b7ed7495ae07b9d5.dblock.zip.aes

* 16. Jul. 2021 12:14: Backend event: Get - Failed: duplicati-bb99e35bea67c4da7b7ed7495ae07b9d5.dblock.zip.aes (49,91 MB)

* 16. Jul. 2021 12:14: Operation Get with file duplicati-bb99e35bea67c4da7b7ed7495ae07b9d5.dblock.zip.aes attempt 5 of 5 failed with message: Fehlerhafter Hash-Wert für Datei "/tmp/dup-69cdfd1a-3561-4f14-ba8b-e293ec7ab3ec", gespeicherter Hash: hj6OKR+nowStdTAp7yduyUQgKQRsBaHTIGv/9Oh70+4=, aktueller Hash ffUPICC8//XlWxROstM9UND8M0kkVX0jVU8MZumBYmU=

* 16. Jul. 2021 12:14: Backend event: Get - Completed: duplicati-bb99e35bea67c4da7b7ed7495ae07b9d5.dblock.zip.aes (49,91 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Started: duplicati-bb99e35bea67c4da7b7ed7495ae07b9d5.dblock.zip.aes (49,91 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Retrying: duplicati-bb99e35bea67c4da7b7ed7495ae07b9d5.dblock.zip.aes (49,91 MB)

* 16. Jul. 2021 12:14: Operation Get with file duplicati-bb99e35bea67c4da7b7ed7495ae07b9d5.dblock.zip.aes attempt 4 of 5 failed with message: Fehlerhafter Hash-Wert für Datei "/tmp/dup-81b1b881-c751-459b-b935-aef51b2b57ee", gespeicherter Hash: hj6OKR+nowStdTAp7yduyUQgKQRsBaHTIGv/9Oh70+4=, aktueller Hash ffUPICC8//XlWxROstM9UND8M0kkVX0jVU8MZumBYmU=

* 16. Jul. 2021 12:14: Backend event: Get - Completed: duplicati-bb99e35bea67c4da7b7ed7495ae07b9d5.dblock.zip.aes (49,91 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Started: duplicati-bb99e35bea67c4da7b7ed7495ae07b9d5.dblock.zip.aes (49,91 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Retrying: duplicati-bb99e35bea67c4da7b7ed7495ae07b9d5.dblock.zip.aes (49,91 MB)

* 16. Jul. 2021 12:14: Operation Get with file duplicati-bb99e35bea67c4da7b7ed7495ae07b9d5.dblock.zip.aes attempt 3 of 5 failed with message: Fehlerhafter Hash-Wert für Datei "/tmp/dup-f8d2c2c8-fd58-4637-b238-61b3058844bc", gespeicherter Hash: hj6OKR+nowStdTAp7yduyUQgKQRsBaHTIGv/9Oh70+4=, aktueller Hash ffUPICC8//XlWxROstM9UND8M0kkVX0jVU8MZumBYmU=

* 16. Jul. 2021 12:14: Backend event: Get - Completed: duplicati-bb99e35bea67c4da7b7ed7495ae07b9d5.dblock.zip.aes (49,91 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Started: duplicati-bb99e35bea67c4da7b7ed7495ae07b9d5.dblock.zip.aes (49,91 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Retrying: duplicati-bb99e35bea67c4da7b7ed7495ae07b9d5.dblock.zip.aes (49,91 MB)

* 16. Jul. 2021 12:14: Operation Get with file duplicati-bb99e35bea67c4da7b7ed7495ae07b9d5.dblock.zip.aes attempt 2 of 5 failed with message: Fehlerhafter Hash-Wert für Datei "/tmp/dup-fbc1e218-c52c-4c02-b52f-fa055197046a", gespeicherter Hash: hj6OKR+nowStdTAp7yduyUQgKQRsBaHTIGv/9Oh70+4=, aktueller Hash ffUPICC8//XlWxROstM9UND8M0kkVX0jVU8MZumBYmU=

* 16. Jul. 2021 12:14: Backend event: Get - Completed: duplicati-bb99e35bea67c4da7b7ed7495ae07b9d5.dblock.zip.aes (49,91 MB)

* 16. Jul. 2021 12:14: Backend event: Get - Started: duplicati-bb99e35bea67c4da7b7ed7495ae07b9d5.dblock.zip.aes (49,91 MB)

* 16. Jul. 2021 12:13: Backend event: Get - Retrying: duplicati-bb99e35bea67c4da7b7ed7495ae07b9d5.dblock.zip.aes (49,91 MB)

* 16. Jul. 2021 12:13: Operation Get with file duplicati-bb99e35bea67c4da7b7ed7495ae07b9d5.dblock.zip.aes attempt 1 of 5 failed with message: Fehlerhafter Hash-Wert für Datei "/tmp/dup-062801cf-a2ef-441a-8c57-ec3c96f69e88", gespeicherter Hash: hj6OKR+nowStdTAp7yduyUQgKQRsBaHTIGv/9Oh70+4=, aktueller Hash ffUPICC8//XlWxROstM9UND8M0kkVX0jVU8MZumBYmU=

* 16. Jul. 2021 12:13: Backend event: Get - Completed: duplicati-bb99e35bea67c4da7b7ed7495ae07b9d5.dblock.zip.aes (49,91 MB)

* 16. Jul. 2021 12:13: Backend event: Get - Started: duplicati-bb99e35bea67c4da7b7ed7495ae07b9d5.dblock.zip.aes (49,91 MB)

* 16. Jul. 2021 12:13: Backend event: Get - Completed: duplicati-beb082e59db474d7c811f73798e985024.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:13: Backend event: Get - Started: duplicati-beb082e59db474d7c811f73798e985024.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:13: Backend event: Get - Completed: duplicati-b349b252e67e14970b9afc62f67fde078.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:13: Backend event: Get - Started: duplicati-b349b252e67e14970b9afc62f67fde078.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:13: Backend event: Get - Completed: duplicati-bfa12d585153547f99fcd3bcbe3101e57.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:13: Backend event: Get - Started: duplicati-bfa12d585153547f99fcd3bcbe3101e57.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:13: Backend event: Get - Completed: duplicati-b67a1558c25a24aa898ac6b731210df77.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:13: Backend event: Get - Started: duplicati-b67a1558c25a24aa898ac6b731210df77.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:13: Backend event: Get - Completed: duplicati-bb311899e468c4bc19fa673c2dc37795d.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:13: Backend event: Get - Started: duplicati-bb311899e468c4bc19fa673c2dc37795d.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:13: Backend event: Get - Completed: duplicati-b865095b91ee4436082f85e9e5f7fcfbb.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:13: Backend event: Get - Started: duplicati-b865095b91ee4436082f85e9e5f7fcfbb.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:13: Backend event: Get - Completed: duplicati-b2b072e460d6440d28acb66620b931a2e.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:13: Backend event: Get - Started: duplicati-b2b072e460d6440d28acb66620b931a2e.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:13: Backend event: Get - Completed: duplicati-bf5212ce2459a49cbb002bb7675876eeb.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:13: Backend event: Get - Started: duplicati-bf5212ce2459a49cbb002bb7675876eeb.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:13: Backend event: Get - Completed: duplicati-bb4317678e31b42349a142d2792510833.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:13: Backend event: Get - Started: duplicati-bb4317678e31b42349a142d2792510833.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:13: Backend event: Get - Completed: duplicati-b077c696c571441968aad3b9f264e3ae9.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:13: Backend event: Get - Started: duplicati-b077c696c571441968aad3b9f264e3ae9.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:13: Backend event: Get - Completed: duplicati-b877a63d3850041e88afeae0b88b48df4.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:13: Backend event: Get - Started: duplicati-b877a63d3850041e88afeae0b88b48df4.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:13: Backend event: Get - Completed: duplicati-bc14317d81bb745bfb23972af3808849a.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:13: Backend event: Get - Started: duplicati-bc14317d81bb745bfb23972af3808849a.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:13: Failed to process file duplicati-be2fc18695d734787b3fd6fef63548f5a.dblock.zip.aes

* 16. Jul. 2021 12:13: Backend event: Get - Failed: duplicati-be2fc18695d734787b3fd6fef63548f5a.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:13: Operation Get with file duplicati-be2fc18695d734787b3fd6fef63548f5a.dblock.zip.aes attempt 5 of 5 failed with message: Fehlerhafter Hash-Wert für Datei "/tmp/dup-39e8caf0-e225-4b49-8cb7-baa857b4e60f", gespeicherter Hash: /Ouh3Ub3u8zeul/9C6j8PEzLItqZUHvMt5J1naN2ur8=, aktueller Hash JBlb67VZ80mXfDxZwdJl07VTrwF8nb0rc5ZS+gpj5VA=

* 16. Jul. 2021 12:13: Backend event: Get - Completed: duplicati-be2fc18695d734787b3fd6fef63548f5a.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:13: Backend event: Get - Started: duplicati-be2fc18695d734787b3fd6fef63548f5a.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:13: Backend event: Get - Retrying: duplicati-be2fc18695d734787b3fd6fef63548f5a.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:13: Operation Get with file duplicati-be2fc18695d734787b3fd6fef63548f5a.dblock.zip.aes attempt 4 of 5 failed with message: Fehlerhafter Hash-Wert für Datei "/tmp/dup-464c3c50-7cd8-4d7d-b8e8-bc63e25d3ac4", gespeicherter Hash: /Ouh3Ub3u8zeul/9C6j8PEzLItqZUHvMt5J1naN2ur8=, aktueller Hash JBlb67VZ80mXfDxZwdJl07VTrwF8nb0rc5ZS+gpj5VA=

* 16. Jul. 2021 12:13: Backend event: Get - Completed: duplicati-be2fc18695d734787b3fd6fef63548f5a.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:13: Backend event: Get - Started: duplicati-be2fc18695d734787b3fd6fef63548f5a.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:13: Backend event: Get - Retrying: duplicati-be2fc18695d734787b3fd6fef63548f5a.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:13: Operation Get with file duplicati-be2fc18695d734787b3fd6fef63548f5a.dblock.zip.aes attempt 3 of 5 failed with message: Fehlerhafter Hash-Wert für Datei "/tmp/dup-e4695e5c-009b-4838-b6d0-0f382c962c58", gespeicherter Hash: /Ouh3Ub3u8zeul/9C6j8PEzLItqZUHvMt5J1naN2ur8=, aktueller Hash JBlb67VZ80mXfDxZwdJl07VTrwF8nb0rc5ZS+gpj5VA=

* 16. Jul. 2021 12:13: Backend event: Get - Completed: duplicati-be2fc18695d734787b3fd6fef63548f5a.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:13: Backend event: Get - Started: duplicati-be2fc18695d734787b3fd6fef63548f5a.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:13: Backend event: Get - Retrying: duplicati-be2fc18695d734787b3fd6fef63548f5a.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:13: Operation Get with file duplicati-be2fc18695d734787b3fd6fef63548f5a.dblock.zip.aes attempt 2 of 5 failed with message: Fehlerhafter Hash-Wert für Datei "/tmp/dup-b65ec11e-ed65-4723-b18b-e127d2b32b61", gespeicherter Hash: /Ouh3Ub3u8zeul/9C6j8PEzLItqZUHvMt5J1naN2ur8=, aktueller Hash JBlb67VZ80mXfDxZwdJl07VTrwF8nb0rc5ZS+gpj5VA=

* 16. Jul. 2021 12:13: Backend event: Get - Completed: duplicati-be2fc18695d734787b3fd6fef63548f5a.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:13: Backend event: Get - Started: duplicati-be2fc18695d734787b3fd6fef63548f5a.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:13: Backend event: Get - Retrying: duplicati-be2fc18695d734787b3fd6fef63548f5a.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:13: Operation Get with file duplicati-be2fc18695d734787b3fd6fef63548f5a.dblock.zip.aes attempt 1 of 5 failed with message: Fehlerhafter Hash-Wert für Datei "/tmp/dup-9de1a751-a21c-42c3-a741-30fb3f387755", gespeicherter Hash: /Ouh3Ub3u8zeul/9C6j8PEzLItqZUHvMt5J1naN2ur8=, aktueller Hash JBlb67VZ80mXfDxZwdJl07VTrwF8nb0rc5ZS+gpj5VA=

* 16. Jul. 2021 12:13: Backend event: Get - Completed: duplicati-be2fc18695d734787b3fd6fef63548f5a.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:13: Backend event: Get - Started: duplicati-be2fc18695d734787b3fd6fef63548f5a.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:13: Backend event: Get - Completed: duplicati-b61637f68aa834c6ca3601b3efb2c2368.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:13: Backend event: Get - Started: duplicati-b61637f68aa834c6ca3601b3efb2c2368.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:13: Backend event: Get - Completed: duplicati-b2224f6d7c3894e6c8e8af20e260213a7.dblock.zip.aes (49,92 MB)

* 16. Jul. 2021 12:13: Backend event: Get - Started: duplicati-b2224f6d7c3894e6c8e8af20e260213a7.dblock.zip.aes (49,92 MB)

* 16. Jul. 2021 12:13: Backend event: Get - Completed: duplicati-ba5dc0e62d8e3438389da2fd39c0401c2.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:13: Backend event: Get - Started: duplicati-ba5dc0e62d8e3438389da2fd39c0401c2.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:13: Backend event: Get - Completed: duplicati-bd9d69ef16a1343c399368567944c3ff1.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:13: Backend event: Get - Started: duplicati-bd9d69ef16a1343c399368567944c3ff1.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:13: Backend event: Get - Completed: duplicati-b0d830a7ee91847c1833a8e44d1b309a0.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:13: Backend event: Get - Started: duplicati-b0d830a7ee91847c1833a8e44d1b309a0.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:13: Failed to process file duplicati-b05ffafc4c72e4bc1a9669e9472f9fb80.dblock.zip.aes

* 16. Jul. 2021 12:13: Backend event: Get - Failed: duplicati-b05ffafc4c72e4bc1a9669e9472f9fb80.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:13: Operation Get with file duplicati-b05ffafc4c72e4bc1a9669e9472f9fb80.dblock.zip.aes attempt 5 of 5 failed with message: Fehlerhafter Hash-Wert für Datei "/tmp/dup-f3627c71-8439-457d-8f57-f2075b975269", gespeicherter Hash: 6kIANmXSeDf9pDRTBuzzxJIriHN78VufE9Zu0xE9llA=, aktueller Hash A5VNfmcTJj7DUHnu1BhhVQuw/Q36ESZx/k5Pcx+ss9w=

* 16. Jul. 2021 12:13: Backend event: Get - Completed: duplicati-b05ffafc4c72e4bc1a9669e9472f9fb80.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:13: Backend event: Get - Started: duplicati-b05ffafc4c72e4bc1a9669e9472f9fb80.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:13: Backend event: Get - Retrying: duplicati-b05ffafc4c72e4bc1a9669e9472f9fb80.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:13: Operation Get with file duplicati-b05ffafc4c72e4bc1a9669e9472f9fb80.dblock.zip.aes attempt 4 of 5 failed with message: Fehlerhafter Hash-Wert für Datei "/tmp/dup-4cd269fa-4f54-4fd3-8a9b-91d87eb8e733", gespeicherter Hash: 6kIANmXSeDf9pDRTBuzzxJIriHN78VufE9Zu0xE9llA=, aktueller Hash A5VNfmcTJj7DUHnu1BhhVQuw/Q36ESZx/k5Pcx+ss9w=

* 16. Jul. 2021 12:13: Backend event: Get - Completed: duplicati-b05ffafc4c72e4bc1a9669e9472f9fb80.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:13: Backend event: Get - Started: duplicati-b05ffafc4c72e4bc1a9669e9472f9fb80.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:12: Backend event: Get - Retrying: duplicati-b05ffafc4c72e4bc1a9669e9472f9fb80.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:12: Operation Get with file duplicati-b05ffafc4c72e4bc1a9669e9472f9fb80.dblock.zip.aes attempt 3 of 5 failed with message: Fehlerhafter Hash-Wert für Datei "/tmp/dup-ba08daf5-65ce-4856-9e70-238035e00b9f", gespeicherter Hash: 6kIANmXSeDf9pDRTBuzzxJIriHN78VufE9Zu0xE9llA=, aktueller Hash A5VNfmcTJj7DUHnu1BhhVQuw/Q36ESZx/k5Pcx+ss9w=

* 16. Jul. 2021 12:12: Backend event: Get - Completed: duplicati-b05ffafc4c72e4bc1a9669e9472f9fb80.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:12: Backend event: Get - Started: duplicati-b05ffafc4c72e4bc1a9669e9472f9fb80.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:12: Backend event: Get - Retrying: duplicati-b05ffafc4c72e4bc1a9669e9472f9fb80.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:12: Operation Get with file duplicati-b05ffafc4c72e4bc1a9669e9472f9fb80.dblock.zip.aes attempt 2 of 5 failed with message: Fehlerhafter Hash-Wert für Datei "/tmp/dup-1cd720f7-7eb9-44ff-a1bf-5a13b3444455", gespeicherter Hash: 6kIANmXSeDf9pDRTBuzzxJIriHN78VufE9Zu0xE9llA=, aktueller Hash A5VNfmcTJj7DUHnu1BhhVQuw/Q36ESZx/k5Pcx+ss9w=

* 16. Jul. 2021 12:12: Backend event: Get - Completed: duplicati-b05ffafc4c72e4bc1a9669e9472f9fb80.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:12: Backend event: Get - Started: duplicati-b05ffafc4c72e4bc1a9669e9472f9fb80.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:12: Backend event: Get - Retrying: duplicati-b05ffafc4c72e4bc1a9669e9472f9fb80.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:12: Operation Get with file duplicati-b05ffafc4c72e4bc1a9669e9472f9fb80.dblock.zip.aes attempt 1 of 5 failed with message: Fehlerhafter Hash-Wert für Datei "/tmp/dup-ecc372ac-300c-402f-bd1b-8705a192e1e9", gespeicherter Hash: 6kIANmXSeDf9pDRTBuzzxJIriHN78VufE9Zu0xE9llA=, aktueller Hash A5VNfmcTJj7DUHnu1BhhVQuw/Q36ESZx/k5Pcx+ss9w=

* 16. Jul. 2021 12:12: Backend event: Get - Completed: duplicati-b05ffafc4c72e4bc1a9669e9472f9fb80.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:12: Backend event: Get - Started: duplicati-b05ffafc4c72e4bc1a9669e9472f9fb80.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:12: Failed to process file duplicati-bc098a680e7944179bf3ce545967cc2fb.dblock.zip.aes

* 16. Jul. 2021 12:12: Backend event: Get - Failed: duplicati-bc098a680e7944179bf3ce545967cc2fb.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:12: Operation Get with file duplicati-bc098a680e7944179bf3ce545967cc2fb.dblock.zip.aes attempt 5 of 5 failed with message: Fehlerhafter Hash-Wert für Datei "/tmp/dup-f24874d6-b207-43c3-87a3-8c3d87c1c3b2", gespeicherter Hash: jL2xsM2eadUloUVBC3GtzslxBKu2p6ggq8tmifIBPTs=, aktueller Hash S72Rz/6nLhw+60n1XGGLN5hH6friKUefo9HxzTnqku0=

* 16. Jul. 2021 12:12: Backend event: Get - Completed: duplicati-bc098a680e7944179bf3ce545967cc2fb.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:12: Backend event: Get - Started: duplicati-bc098a680e7944179bf3ce545967cc2fb.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:12: Backend event: Get - Retrying: duplicati-bc098a680e7944179bf3ce545967cc2fb.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:12: Operation Get with file duplicati-bc098a680e7944179bf3ce545967cc2fb.dblock.zip.aes attempt 4 of 5 failed with message: Fehlerhafter Hash-Wert für Datei "/tmp/dup-3ca9e6f1-c6d8-4bda-a9ef-ef65378dac9a", gespeicherter Hash: jL2xsM2eadUloUVBC3GtzslxBKu2p6ggq8tmifIBPTs=, aktueller Hash S72Rz/6nLhw+60n1XGGLN5hH6friKUefo9HxzTnqku0=

* 16. Jul. 2021 12:12: Backend event: Get - Completed: duplicati-bc098a680e7944179bf3ce545967cc2fb.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:12: Backend event: Get - Started: duplicati-bc098a680e7944179bf3ce545967cc2fb.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:12: Backend event: Get - Retrying: duplicati-bc098a680e7944179bf3ce545967cc2fb.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:12: Operation Get with file duplicati-bc098a680e7944179bf3ce545967cc2fb.dblock.zip.aes attempt 3 of 5 failed with message: Fehlerhafter Hash-Wert für Datei "/tmp/dup-af672e9a-8fb1-498d-adf7-10efb1ba8396", gespeicherter Hash: jL2xsM2eadUloUVBC3GtzslxBKu2p6ggq8tmifIBPTs=, aktueller Hash S72Rz/6nLhw+60n1XGGLN5hH6friKUefo9HxzTnqku0=

* 16. Jul. 2021 12:12: Backend event: Get - Completed: duplicati-bc098a680e7944179bf3ce545967cc2fb.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:12: Backend event: Get - Started: duplicati-bc098a680e7944179bf3ce545967cc2fb.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:11: Backend event: Get - Retrying: duplicati-bc098a680e7944179bf3ce545967cc2fb.dblock.zip.aes (49,99 MB)

* 16. Jul. 2021 12:11: Operation Get with file duplicati-bc098a680e7944179bf3ce545967cc2fb.dblock.zip.aes attempt 2 of 5 failed with message: Fehlerhafter Hash-Wert für Datei "/tmp/dup-4304b8b8-8a47-4639-848b-f8c9f7e31299", gespeicherter Hash: jL2xsM2eadUloUVBC3GtzslxBKu2p6ggq8tmifIBPTs=, aktueller Hash S72Rz/6nLhw+60n1XGGLN5hH6friKUefo9HxzTnqku0=

* 16. Jul. 2021 12:11: Backend event: Get - Completed: duplicati-bc098a680e7944179bf3ce545967cc2fb.dblock.zip.aes (49,99 MB)

I’ve started to Google as being at loss with an explanation for the cause. Does Duplicati set/enforce binary mode on ftp transfers?

and crlf problems:

Are you saying you brought the FTP server drive to the local system, or is that another test? If so, what?

Is the FTP server fairly remote (e.g. going over the Internet or some other maybe less reliable network)?

One FTP weakness is there’s no error detection on the data except for TCP’s fairly weak checksum, i.e.

Transmission Control Protocol Error detection

The TCP checksum is a weak check by modern standards.

I’m not sure how it would enforce it. FTP is required to support binary mode (TYPE I) since at least 1989.
The request for binary mode is below, assuming you use Duplicati FTP, as opposed to FTP (Alternative).

Here’s the log from FileZilla Server on Windows. If you want a vsftpd log, there’s info around on how to do.

(000006)7/16/2021 14:30:08 PM - duplicati (::1)> TYPE I
(000006)7/16/2021 14:30:08 PM - duplicati (::1)> 200 Type set to I
(000006)7/16/2021 14:30:08 PM - duplicati (::1)> EPSV
(000006)7/16/2021 14:30:08 PM - duplicati (::1)> 229 Entering Extended Passive Mode (|||57722|)
(000006)7/16/2021 14:30:08 PM - duplicati (::1)> STOR 2.0.5.114 ftp test 1/duplicati-bb15885d595ee4cf7a029f611ca888816.dblock.zip
(000006)7/16/2021 14:30:08 PM - duplicati (::1)> 150 Opening data channel for file upload to server of "/2.0.5.114 ftp test 1/duplicati-bb15885d595ee4cf7a029f611ca888816.dblock.zip"
(000006)7/16/2021 14:30:09 PM - duplicati (::1)> 226 Successfully transferred "/2.0.5.114 ftp test 1/duplicati-bb15885d595ee4cf7a029f611ca888816.dblock.zip"

If the backup destination being examined is on a system that allows PowerShell or Python, you can verify files with upload-verification-file and use the included utility-scripts/DuplicatiVerify.{ps1,py} to verify locally.

It would be interesting to look at time stamp on any files that fail verification. Is it random, or a new issue?

If the files are quite old, before Duplicati 2.0.5.1 in early 2020, speed-throttling could cause corrupted files, however I’d have expected that the random verification sample after backup would have noticed earlier…

1 Like

@ts678

Are you saying you brought the FTP server drive to the local system, or is that another test?

The setup is as follows: I’ve got a KVM Host with 3 local disks and 1 usb attached storage. Duplicati runs in the VM, a typical file server guest machine. My first attempt was setting up vsftpd on the KVM host machine in order to pass the USB HDD storage on to the virtual machine so Duplicati can write to it. My second attempt should skip the FTP in-between, so I’ve used the KVM 9p virtio-fs passthrough which makes a shared folder available to the guest vm so Duplicati can access it. The shared folder resided on the USB HDD.

If things were not better, I’ve started a third attempt and used vsftpd again and put some swap disk into the guest machine. Which seemed to work okay at first glance - I was so happy about the green check mark “backup succeeded” in Duplicati I didn’t do the verification via CLI of all backup set files. Some days later (see screenshot above) Duplicati said some backup files were corrupt, so all in all: Until there, I could not clearly proof what was wrong with my setup or hardware.

Is the FTP server fairly remote

Just to follow up clearly: It can be considered local as it’s running on eth0 of the KVM host machine. The same eth0 interface is bridged to the guest, so “full-speed”, “no loss expected”.

speed-throttling

I do not use throttling in Duplicati.


Now something odd turned out looking at the KVM host’s dmesg: “xhci … HOST ERROR” after a reboot … and my USB HDD was no longer visible in the debian environment (/dev/sdd missing). The machine does not have USB 3.0 ports on its mainboard, they’re provided by a PCIe expansion card (VLI800 chipset). I’ve started to Google and found, for Debian systems, there may be IOMMU and so on issues with this chipset… some communities had postings like "use one of those recent Renesas cards, especially with a uPD720202 chipset. Now, with a uPD720202 XHCI controller, I re-ran the job from scratch (without existing DB, without existing files in target). I’ve set test-backup-file-count to 9999999 again and got a green check mark after a lot of hours.

Conclusion until now: Maybe the USB 3.0 XHCI controller was faulty. I didn’t expect that, because I cp’ed some large files to my USB HDD for testing and compared sha256 checksums before and after and they were okay. But maybe something was still wrong under the high? load of Duplicati backing up 880 GiB of files?!

How to go on: I’ll observe if the next job executions fail or succeed.

1 Like