Unexpected number of remote volumes marked as deleted error

Support
1

Hey there,

at the end of the backup, I get the Unexpected number of remote volumes marked as deleted. Found 0 filesets, but 1 volumes error and the backup isn’t marked as successful. As the backup takes three days and other rare topics to this issue (1, 2) suggest manual actions / digging down a bit more, I don’t simply want to restart the backup.

So how shall I proceed, and is there maybe even a way to recover from this without having to redo the full backup?

Preface

I already had a beta version of Duplicati 2 installed on my Windows 10 machine but no backup jobs set up. For doing my full backup, I updated to the recent stable version 2.1.0.5

Setup and first try

I do my backup to a brand new external hard disk (enough free space ensured), formated to ext4 and connected to an OpenWRT router via USB 3. Duplicati is configured to SFTP (SSH) storage type using a private key as authentication.

As this is a local backup, I increased the block size to 250 MiB (and thinking of even increasing it more).

My first backup failed, because access rights for the duplicati user on the router to the hard disk weren’t yet set properly (my fault):

            {
  "DeletedFiles": 0,
  "DeletedFolders": 0,
  "ModifiedFiles": 0,
  "ExaminedFiles": 74,
  "OpenedFiles": 69,
  "AddedFiles": 69,
  "SizeOfModifiedFiles": 0,
  "SizeOfAddedFiles": 233657592,
  "SizeOfExaminedFiles": 8364430648,
  "SizeOfOpenedFiles": 233657592,
  "NotProcessedFiles": 0,
  "AddedFolders": 19,
  "TooLargeFiles": 0,
  "FilesWithError": 0,
  "ModifiedFolders": 0,
  "ModifiedSymlinks": 0,
  "AddedSymlinks": 12,
  "DeletedSymlinks": 0,
  "PartialBackup": false,
  "Dryrun": false,
  "MainOperation": "Backup",
  "CompactResults": null,
  "VacuumResults": null,
  "DeleteResults": null,
  "RepairResults": null,
  "TestResults": null,
  "ParsedResult": "Fatal",
  "Interrupted": false,
  "Version": "2.1.0.5 (2.1.0.5_stable_2025-03-04)",
  "EndTime": "2025-04-08T14:23:53.2169216Z",
  "BeginTime": "2025-04-08T14:22:24.3703881Z",
  "Duration": "00:01:28.8465335",
  "MessagesActualLength": 91,
  "WarningsActualLength": 10,
  "ErrorsActualLength": 2,
  "Messages": [
    "2025-04-08 16:22:24 +02 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: Die Operation Backup wurde gestartet",
    "2025-04-08 16:22:24 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started:  ()",
    "2025-04-08 16:22:25 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed:  ()",
    "2025-04-08 16:22:48 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-ba37b287471cb4bb9bdb4380696b7f7ed.dblock.zip.aes (249,87 MB)",
    "2025-04-08 16:22:48 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-b5b1128db32ac4e2e912fbde10deafb9c.dblock.zip.aes (249,98 MB)",
    "2025-04-08 16:22:49 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Retrying: duplicati-ba37b287471cb4bb9bdb4380696b7f7ed.dblock.zip.aes (249,87 MB)",
    "2025-04-08 16:22:49 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Retrying: duplicati-b5b1128db32ac4e2e912fbde10deafb9c.dblock.zip.aes (249,98 MB)",
    "2025-04-08 16:22:59 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Rename: duplicati-ba37b287471cb4bb9bdb4380696b7f7ed.dblock.zip.aes (249,87 MB)",
    "2025-04-08 16:22:59 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Rename: duplicati-bda08af77afef47a9b55ae4a3851ad45f.dblock.zip.aes (249,87 MB)",
    "2025-04-08 16:22:59 +02 - [Information-Duplicati.Library.Main.Operation.Backup.BackendUploader-RenameRemoteTargetFile]: Renaming \"duplicati-ba37b287471cb4bb9bdb4380696b7f7ed.dblock.zip.aes\" to \"duplicati-bda08af77afef47a9b55ae4a3851ad45f.dblock.zip.aes\"",
    "2025-04-08 16:22:59 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-bda08af77afef47a9b55ae4a3851ad45f.dblock.zip.aes (249,87 MB)",
    "2025-04-08 16:22:59 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Rename: duplicati-b5b1128db32ac4e2e912fbde10deafb9c.dblock.zip.aes (249,98 MB)",
    "2025-04-08 16:22:59 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Rename: duplicati-b3d832d5906c94574af1862e405f39c2c.dblock.zip.aes (249,98 MB)",
    "2025-04-08 16:22:59 +02 - [Information-Duplicati.Library.Main.Operation.Backup.BackendUploader-RenameRemoteTargetFile]: Renaming \"duplicati-b5b1128db32ac4e2e912fbde10deafb9c.dblock.zip.aes\" to \"duplicati-b3d832d5906c94574af1862e405f39c2c.dblock.zip.aes\"",
    "2025-04-08 16:22:59 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-b3d832d5906c94574af1862e405f39c2c.dblock.zip.aes (249,98 MB)",
    "2025-04-08 16:23:00 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Retrying: duplicati-b3d832d5906c94574af1862e405f39c2c.dblock.zip.aes (249,98 MB)",
    "2025-04-08 16:23:00 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Retrying: duplicati-bda08af77afef47a9b55ae4a3851ad45f.dblock.zip.aes (249,87 MB)",
    "2025-04-08 16:23:07 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-b1f5f36331ce242558114109a73fb8d3a.dblock.zip.aes (249,83 MB)",
    "2025-04-08 16:23:09 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-b2c77ed8fc3194c07a5286d8c83281a88.dblock.zip.aes (249,47 MB)",
    "2025-04-08 16:23:09 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Retrying: duplicati-b1f5f36331ce242558114109a73fb8d3a.dblock.zip.aes (249,83 MB)"
  ],
  "Warnings": [
    "2025-04-08 16:22:31 +02 - [Warning-Duplicati.Library.Main.Operation.Backup.FileBlockProcessor.FileEntry-PathProcessingFailed]: Failed to process path: C:\\Users\\[username]\\NTUSER.DAT\r\nIOException: The process cannot access the file '\\\\?\\C:\\Users\\[username]\\NTUSER.DAT' because it is being used by another process.",
    "2025-04-08 16:22:31 +02 - [Warning-Duplicati.Library.Main.Operation.Backup.FileBlockProcessor.FileEntry-PathProcessingFailed]: Failed to process path: C:\\Users\\[username]\\ntuser.dat.LOG1\r\nIOException: The process cannot access the file '\\\\?\\C:\\Users\\[username]\\ntuser.dat.LOG1' because it is being used by another process.",
    "2025-04-08 16:22:31 +02 - [Warning-Duplicati.Library.Main.Operation.Backup.FileBlockProcessor.FileEntry-PathProcessingFailed]: Failed to process path: C:\\Users\\[username]\\ntuser.dat.LOG2\r\nIOException: The process cannot access the file '\\\\?\\C:\\Users\\[username]\\ntuser.dat.LOG2' because it is being used by another process.",
    "2025-04-08 16:23:39 +02 - [Warning-Duplicati.Library.Main.Operation.Backup.FileEnumerationProcess-FileAccessError]: Error reported while accessing file: C:\\Users\\[username]\\AppData\\Local\\Temp\\{2a3655d1-e119-ae4e-91f5-a1d8e9b513d6}\\\r\nUnauthorizedAccessException: Access to the path '\\\\?\\C:\\Users\\[username]\\AppData\\Local\\Temp\\{2a3655d1-e119-ae4e-91f5-a1d8e9b513d6}' is denied.",
    "2025-04-08 16:23:39 +02 - [Warning-Duplicati.Library.Main.Operation.Backup.FileEnumerationProcess-FileAccessError]: Error reported while accessing file: C:\\Users\\[username]\\AppData\\Local\\Temp\\{2a3655d1-e119-ae4e-91f5-a1d8e9b513d6}\\\r\nUnauthorizedAccessException: Access to the path '\\\\?\\C:\\Users\\[username]\\AppData\\Local\\Temp\\{2a3655d1-e119-ae4e-91f5-a1d8e9b513d6}' is denied.",
    "2025-04-08 16:23:40 +02 - [Warning-Duplicati.Library.Main.Operation.Backup.FileEnumerationProcess-FileAccessError]: Error reported while accessing file: C:\\Users\\[username]\\AppData\\Local\\Temp\\msdtadmin\\\r\nUnauthorizedAccessException: Access to the path '\\\\?\\C:\\Users\\[username]\\AppData\\Local\\Temp\\msdtadmin' is denied.",
    "2025-04-08 16:23:40 +02 - [Warning-Duplicati.Library.Main.Operation.Backup.FileEnumerationProcess-FileAccessError]: Error reported while accessing file: C:\\Users\\[username]\\AppData\\Local\\Temp\\msdtadmin\\\r\nUnauthorizedAccessException: Access to the path '\\\\?\\C:\\Users\\[username]\\AppData\\Local\\Temp\\msdtadmin' is denied.",
    "2025-04-08 16:23:49 +02 - [Warning-Duplicati.Library.Main.Operation.Backup.FileEnumerationProcess-FileAccessError]: Error reported while accessing file: C:\\Users\\[username]\\AppData\\Local\\ElevatedDiagnostics\\\r\nUnauthorizedAccessException: Access to the path '\\\\?\\C:\\Users\\[username]\\AppData\\Local\\ElevatedDiagnostics' is denied.",
    "2025-04-08 16:23:49 +02 - [Warning-Duplicati.Library.Main.Operation.Backup.FileEnumerationProcess-FileAccessError]: Error reported while accessing file: C:\\Users\\[username]\\AppData\\Local\\ElevatedDiagnostics\\\r\nUnauthorizedAccessException: Access to the path '\\\\?\\C:\\Users\\[username]\\AppData\\Local\\ElevatedDiagnostics' is denied.",
    "2025-04-08 16:23:53 +02 - [Warning-Duplicati.Library.Main.Operation.Backup.BackendUploader-UploadError]: Error during upload failure: Permission denied\r\nSftpPermissionDeniedException: Permission denied"
  ],
  "Errors": [
    "2025-04-08 16:23:53 +02 - [Error-Duplicati.Library.Main.Operation.BackupHandler-FatalError]: Fatal error\r\nSftpPermissionDeniedException: Permission denied",
    "2025-04-08 16:23:53 +02 - [Error-Duplicati.Library.Main.Controller-FailedOperation]: Die Operation Backup ist mit folgenden Fehler fehlgeschlagen: One or more errors occurred. (Permission denied (Permission denied) (One or more errors occurred. (Permission denied)))\r\nAggregateException: One or more errors occurred. (Permission denied (Permission denied) (One or more errors occurred. (Permission denied)))"
  ],
  "BackendStatistics": {
    "RemoteCalls": 21,
    "BytesUploaded": 0,
    "BytesDownloaded": 0,
    "FilesUploaded": 0,
    "FilesDownloaded": 0,
    "FilesDeleted": 0,
    "FoldersCreated": 0,
    "RetryAttempts": 18,
    "UnknownFileSize": 0,
    "UnknownFileCount": 0,
    "KnownFileCount": 0,
    "KnownFileSize": 0,
    "LastBackupDate": "0001-01-01T00:00:00",
    "BackupListCount": 0,
    "TotalQuotaSpace": 0,
    "FreeQuotaSpace": 0,
    "AssignedQuotaSpace": -1,
    "ReportedQuotaError": false,
    "ReportedQuotaWarning": false,
    "MainOperation": "Backup",
    "ParsedResult": "Success",
    "Interrupted": false,
    "Version": "2.1.0.5 (2.1.0.5_stable_2025-03-04)",
    "EndTime": "0001-01-01T00:00:00",
    "BeginTime": "2025-04-08T14:22:24.3711408Z",
    "Duration": "00:00:00",
    "MessagesActualLength": 0,
    "WarningsActualLength": 0,
    "ErrorsActualLength": 0,
    "Messages": null,
    "Warnings": null,
    "Errors": null
  }
}

Second try

So I fixed the access rights and manually started a new backup run.

At first it looked promising:
image

As the backup continued and time went by, I hibernated my computer (no shutdown, just hibernation) and resumed the next day.

After three days, the backup seemed to finally finish… but the size to go then went negative:
image

After some cleanup steps were ran I was greeted with an error message:

Fatal error
Exception: Unexpected number of remote volumes marked as deleted. Found 0 filesets, but 1 volumes

Full log:

            {
  "DeletedFiles": 0,
  "DeletedFolders": 0,
  "ModifiedFiles": 0,
  "ExaminedFiles": 3246575,
  "OpenedFiles": 3246365,
  "AddedFiles": 3246365,
  "SizeOfModifiedFiles": 0,
  "SizeOfAddedFiles": 3630179613961,
  "SizeOfExaminedFiles": 3630823123654,
  "SizeOfOpenedFiles": 3630179613961,
  "NotProcessedFiles": 0,
  "AddedFolders": 297415,
  "TooLargeFiles": 0,
  "FilesWithError": 0,
  "ModifiedFolders": 0,
  "ModifiedSymlinks": 0,
  "AddedSymlinks": 47,
  "DeletedSymlinks": 0,
  "PartialBackup": false,
  "Dryrun": false,
  "MainOperation": "Backup",
  "CompactResults": null,
  "VacuumResults": null,
  "DeleteResults": {
    "DeletedSetsActualLength": 0,
    "DeletedSets": null,
    "Dryrun": false,
    "MainOperation": "Delete",
    "CompactResults": null,
    "ParsedResult": "Success",
    "Interrupted": false,
    "Version": "2.1.0.5 (2.1.0.5_stable_2025-03-04)",
    "EndTime": "0001-01-01T00:00:00",
    "BeginTime": "2025-04-11T21:21:19.8718504Z",
    "Duration": "00:00:00",
    "MessagesActualLength": 0,
    "WarningsActualLength": 0,
    "ErrorsActualLength": 0,
    "Messages": null,
    "Warnings": null,
    "Errors": null,
    "BackendStatistics": {
      "RemoteCalls": 19372,
      "BytesUploaded": 2532012961047,
      "BytesDownloaded": 0,
      "FilesUploaded": 19363,
      "FilesDownloaded": 0,
      "FilesDeleted": 0,
      "FoldersCreated": 0,
      "RetryAttempts": 8,
      "UnknownFileSize": 0,
      "UnknownFileCount": 0,
      "KnownFileCount": 0,
      "KnownFileSize": 0,
      "LastBackupDate": "0001-01-01T00:00:00",
      "BackupListCount": 1,
      "TotalQuotaSpace": 0,
      "FreeQuotaSpace": 0,
      "AssignedQuotaSpace": -1,
      "ReportedQuotaError": false,
      "ReportedQuotaWarning": false,
      "MainOperation": "Backup",
      "ParsedResult": "Success",
      "Interrupted": false,
      "Version": "2.1.0.5 (2.1.0.5_stable_2025-03-04)",
      "EndTime": "0001-01-01T00:00:00",
      "BeginTime": "2025-04-08T14:26:08.8181136Z",
      "Duration": "00:00:00",
      "MessagesActualLength": 0,
      "WarningsActualLength": 0,
      "ErrorsActualLength": 0,
      "Messages": null,
      "Warnings": null,
      "Errors": null
    }
  },
  "RepairResults": null,
  "TestResults": null,
  "ParsedResult": "Fatal",
  "Interrupted": false,
  "Version": "2.1.0.5 (2.1.0.5_stable_2025-03-04)",
  "EndTime": "2025-04-11T21:23:46.2131319Z",
  "BeginTime": "2025-04-08T14:26:08.8181054Z",
  "Duration": "3.06:57:37.3950265",
  "MessagesActualLength": 38797,
  "WarningsActualLength": 3328,
  "ErrorsActualLength": 2,
  "Messages": [
    "2025-04-08 16:26:08 +02 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: Die Operation Backup wurde gestartet",
    "2025-04-08 16:26:08 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started:  ()",
    "2025-04-08 16:26:09 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed:  ()",
    "2025-04-08 16:26:09 +02 - [Information-Duplicati.Library.Main.Operation.FilelistProcessor-KeepIncompleteFile]: keeping protected incomplete remote file listed as Uploading: duplicati-20250408T142224Z.dlist.zip.aes",
    "2025-04-08 16:26:09 +02 - [Information-Duplicati.Library.Main.Operation.FilelistProcessor-SchedulingMissingFileForDelete]: scheduling missing file for deletion, currently listed as Uploading: duplicati-bddb9340b1db94b4f9ccc3c4f43076106.dblock.zip.aes",
    "2025-04-08 16:26:09 +02 - [Information-Duplicati.Library.Main.Operation.FilelistProcessor-SchedulingMissingFileForDelete]: scheduling missing file for deletion, currently listed as Uploading: duplicati-b6777795662f24ca5bd10be337eaa84f7.dblock.zip.aes",
    "2025-04-08 16:26:09 +02 - [Information-Duplicati.Library.Main.Operation.FilelistProcessor-SchedulingMissingFileForDelete]: scheduling missing file for deletion, currently listed as Uploading: duplicati-b9dd6706547134c33b12b443659ba04d8.dblock.zip.aes",
    "2025-04-08 16:26:09 +02 - [Information-Duplicati.Library.Main.Operation.FilelistProcessor-SchedulingMissingFileForDelete]: scheduling missing file for deletion, currently listed as Uploading: duplicati-baefcfaa0929c4b80b4fae9e7119096a8.dblock.zip.aes",
    "2025-04-08 16:26:09 +02 - [Information-Duplicati.Library.Main.Operation.FilelistProcessor-RemoteUnwantedMissingFile]: removing file listed as Deleting: duplicati-ba37b287471cb4bb9bdb4380696b7f7ed.dblock.zip.aes",
    "2025-04-08 16:26:09 +02 - [Information-Duplicati.Library.Main.Operation.FilelistProcessor-RemoteUnwantedMissingFile]: removing file listed as Deleting: duplicati-b5b1128db32ac4e2e912fbde10deafb9c.dblock.zip.aes",
    "2025-04-08 16:26:09 +02 - [Information-Duplicati.Library.Main.Operation.FilelistProcessor-SchedulingMissingFileForDelete]: scheduling missing file for deletion, currently listed as Uploading: duplicati-ba974c2dc5695446ab5d322bae1f3b215.dblock.zip.aes",
    "2025-04-08 16:26:09 +02 - [Information-Duplicati.Library.Main.Operation.FilelistProcessor-SchedulingMissingFileForDelete]: scheduling missing file for deletion, currently listed as Uploading: duplicati-bb7f0aeedb7fd40bf8de3c2f392d720fa.dblock.zip.aes",
    "2025-04-08 16:26:09 +02 - [Information-Duplicati.Library.Main.Operation.FilelistProcessor-RemoteUnwantedMissingFile]: removing file listed as Deleting: duplicati-bda08af77afef47a9b55ae4a3851ad45f.dblock.zip.aes",
    "2025-04-08 16:26:09 +02 - [Information-Duplicati.Library.Main.Operation.FilelistProcessor-RemoteUnwantedMissingFile]: removing file listed as Deleting: duplicati-b3d832d5906c94574af1862e405f39c2c.dblock.zip.aes",
    "2025-04-08 16:26:09 +02 - [Information-Duplicati.Library.Main.Operation.FilelistProcessor-RemoteUnwantedMissingFile]: removing file listed as Deleting: duplicati-b1f5f36331ce242558114109a73fb8d3a.dblock.zip.aes",
    "2025-04-08 16:26:09 +02 - [Information-Duplicati.Library.Main.Operation.FilelistProcessor-RemoteUnwantedMissingFile]: removing file listed as Deleting: duplicati-b2c77ed8fc3194c07a5286d8c83281a88.dblock.zip.aes",
    "2025-04-08 16:26:09 +02 - [Information-Duplicati.Library.Main.Operation.FilelistProcessor-RemoteUnwantedMissingFile]: removing file listed as Deleting: duplicati-b7be49515486c49d582e8010a27cacf36.dblock.zip.aes",
    "2025-04-08 16:26:09 +02 - [Information-Duplicati.Library.Main.Operation.FilelistProcessor-RemoteUnwantedMissingFile]: removing file listed as Deleting: duplicati-bc7696e261950498b907e72fa7206e0fe.dblock.zip.aes",
    "2025-04-08 16:26:09 +02 - [Information-Duplicati.Library.Main.Operation.FilelistProcessor-RemoteUnwantedMissingFile]: removing file listed as Deleting: duplicati-b98da6273ca6c4c04bca073a27cd885a0.dblock.zip.aes",
    "2025-04-08 16:26:09 +02 - [Information-Duplicati.Library.Main.Operation.FilelistProcessor-RemoteUnwantedMissingFile]: removing file listed as Deleting: duplicati-b8f81c3ca7cba4b3082a378fba4c8954e.dblock.zip.aes"
  ],
  "Warnings": [
    "2025-04-08 16:26:09 +02 - [Warning-Duplicati.Library.Main.Operation.Backup.UploadSyntheticFilelist-MissingTemporaryFilelist]: Expected there to be a temporary fileset for synthetic filelist (1, duplicati-20250408T142224Z.dlist.zip.aes), but none was found?",
    "2025-04-08 16:26:15 +02 - [Warning-Duplicati.Library.Main.Operation.Backup.FileBlockProcessor.FileEntry-PathProcessingFailed]: Failed to process path: C:\\Users\\[username]\\NTUSER.DAT\r\nIOException: The process cannot access the file '\\\\?\\C:\\Users\\[username]\\NTUSER.DAT' because it is being used by another process.",
    "2025-04-08 16:26:15 +02 - [Warning-Duplicati.Library.Main.Operation.Backup.FileBlockProcessor.FileEntry-PathProcessingFailed]: Failed to process path: C:\\Users\\[username]\\ntuser.dat.LOG1\r\nIOException: The process cannot access the file '\\\\?\\C:\\Users\\[username]\\ntuser.dat.LOG1' because it is being used by another process.",
    "2025-04-08 16:26:15 +02 - [Warning-Duplicati.Library.Main.Operation.Backup.FileBlockProcessor.FileEntry-PathProcessingFailed]: Failed to process path: C:\\Users\\[username]\\ntuser.dat.LOG2\r\nIOException: The process cannot access the file '\\\\?\\C:\\Users\\[username]\\ntuser.dat.LOG2' because it is being used by another process.",
    "2025-04-08 16:27:01 +02 - [Warning-Duplicati.Library.Main.Operation.Backup.FileEnumerationProcess-FileAccessError]: Error reported while accessing file: C:\\Users\\[username]\\AppData\\Local\\Temp\\{2a3655d1-e119-ae4e-91f5-a1d8e9b513d6}\\\r\nUnauthorizedAccessException: Access to the path '\\\\?\\C:\\Users\\[username]\\AppData\\Local\\Temp\\{2a3655d1-e119-ae4e-91f5-a1d8e9b513d6}' is denied.",
    "2025-04-08 16:27:01 +02 - [Warning-Duplicati.Library.Main.Operation.Backup.FileEnumerationProcess-FileAccessError]: Error reported while accessing file: C:\\Users\\[username]\\AppData\\Local\\Temp\\{2a3655d1-e119-ae4e-91f5-a1d8e9b513d6}\\\r\nUnauthorizedAccessException: Access to the path '\\\\?\\C:\\Users\\[username]\\AppData\\Local\\Temp\\{2a3655d1-e119-ae4e-91f5-a1d8e9b513d6}' is denied.",
    "2025-04-08 16:27:02 +02 - [Warning-Duplicati.Library.Main.Operation.Backup.FileEnumerationProcess-FileAccessError]: Error reported while accessing file: C:\\Users\\[username]\\AppData\\Local\\Temp\\msdtadmin\\\r\nUnauthorizedAccessException: Access to the path '\\\\?\\C:\\Users\\[username]\\AppData\\Local\\Temp\\msdtadmin' is denied.",
    "2025-04-08 16:27:02 +02 - [Warning-Duplicati.Library.Main.Operation.Backup.FileEnumerationProcess-FileAccessError]: Error reported while accessing file: C:\\Users\\[username]\\AppData\\Local\\Temp\\msdtadmin\\\r\nUnauthorizedAccessException: Access to the path '\\\\?\\C:\\Users\\[username]\\AppData\\Local\\Temp\\msdtadmin' is denied.",
    "2025-04-08 16:27:13 +02 - [Warning-Duplicati.Library.Main.Operation.Backup.FileEnumerationProcess-FileAccessError]: Error reported while accessing file: C:\\Users\\[username]\\AppData\\Local\\ElevatedDiagnostics\\\r\nUnauthorizedAccessException: Access to the path '\\\\?\\C:\\Users\\[username]\\AppData\\Local\\ElevatedDiagnostics' is denied.",
    "2025-04-08 16:27:13 +02 - [Warning-Duplicati.Library.Main.Operation.Backup.FileEnumerationProcess-FileAccessError]: Error reported while accessing file: C:\\Users\\[username]\\AppData\\Local\\ElevatedDiagnostics\\\r\nUnauthorizedAccessException: Access to the path '\\\\?\\C:\\Users\\[username]\\AppData\\Local\\ElevatedDiagnostics' is denied.",
    "2025-04-08 16:43:08 +02 - [Warning-Duplicati.Library.Main.Operation.Backup.FileEnumerationProcess-FileAccessError]: Error reported while accessing file: E:\\System Volume Information\\\r\nUnauthorizedAccessException: Access to the path '\\\\?\\E:\\System Volume Information' is denied.",
    "2025-04-08 16:43:08 +02 - [Warning-Duplicati.Library.Main.Operation.Backup.FileEnumerationProcess-FileAccessError]: Error reported while accessing file: E:\\System Volume Information\\\r\nUnauthorizedAccessException: Access to the path '\\\\?\\E:\\System Volume Information' is denied.",
    "2025-04-08 16:44:30 +02 - [Warning-Duplicati.Library.Main.Operation.Backup.FileEnumerationProcess-FileAccessError]: Error reported while accessing file: E:\\RECYCLER\\S-1-5-21-1123561945-1801674531-839522115-1008\\\r\nUnauthorizedAccessException: Access to the path '\\\\?\\E:\\RECYCLER\\S-1-5-21-1123561945-1801674531-839522115-1008' is denied.",
    "2025-04-08 16:44:30 +02 - [Warning-Duplicati.Library.Main.Operation.Backup.FileEnumerationProcess-FileAccessError]: Error reported while accessing file: E:\\RECYCLER\\S-1-5-21-1123561945-1801674531-839522115-1008\\\r\nUnauthorizedAccessException: Access to the path '\\\\?\\E:\\RECYCLER\\S-1-5-21-1123561945-1801674531-839522115-1008' is denied.",
    "2025-04-08 16:44:30 +02 - [Warning-Duplicati.Library.Main.Operation.Backup.FileEnumerationProcess-FileAccessError]: Error reported while accessing file: E:\\RECYCLER\\S-1-5-21-1078081533-1547161642-725345543-1006\\\r\nUnauthorizedAccessException: Access to the path '\\\\?\\E:\\RECYCLER\\S-1-5-21-1078081533-1547161642-725345543-1006' is denied.",
    "2025-04-08 16:44:30 +02 - [Warning-Duplicati.Library.Main.Operation.Backup.FileEnumerationProcess-FileAccessError]: Error reported while accessing file: E:\\RECYCLER\\S-1-5-21-1078081533-1547161642-725345543-1006\\\r\nUnauthorizedAccessException: Access to the path '\\\\?\\E:\\RECYCLER\\S-1-5-21-1078081533-1547161642-725345543-1006' is denied.",
    "2025-04-08 16:45:53 +02 - [Warning-Duplicati.Library.Main.Operation.Backup.FileEnumerationProcess-FileAccessError]: Error reported while accessing file: E:\\b65dcf5aa1ffe55b95981cb2a5e37f\\i386\\\r\nUnauthorizedAccessException: Access to the path '\\\\?\\E:\\b65dcf5aa1ffe55b95981cb2a5e37f\\i386' is denied.",
    "2025-04-08 16:45:53 +02 - [Warning-Duplicati.Library.Main.Operation.Backup.FileEnumerationProcess-FileAccessError]: Error reported while accessing file: E:\\b65dcf5aa1ffe55b95981cb2a5e37f\\i386\\\r\nUnauthorizedAccessException: Access to the path '\\\\?\\E:\\b65dcf5aa1ffe55b95981cb2a5e37f\\i386' is denied.",
    "2025-04-08 16:45:53 +02 - [Warning-Duplicati.Library.Main.Operation.Backup.FileEnumerationProcess-FileAccessError]: Error reported while accessing file: E:\\b65dcf5aa1ffe55b95981cb2a5e37f\\amd64\\\r\nUnauthorizedAccessException: Access to the path '\\\\?\\E:\\b65dcf5aa1ffe55b95981cb2a5e37f\\amd64' is denied.",
    "2025-04-08 16:45:53 +02 - [Warning-Duplicati.Library.Main.Operation.Backup.FileEnumerationProcess-FileAccessError]: Error reported while accessing file: E:\\b65dcf5aa1ffe55b95981cb2a5e37f\\amd64\\\r\nUnauthorizedAccessException: Access to the path '\\\\?\\E:\\b65dcf5aa1ffe55b95981cb2a5e37f\\amd64' is denied."
  ],
  "Errors": [
    "2025-04-11 23:23:46 +02 - [Error-Duplicati.Library.Main.Operation.BackupHandler-FatalError]: Fatal error\r\nException: Unexpected number of remote volumes marked as deleted. Found 0 filesets, but 1 volumes",
    "2025-04-11 23:23:46 +02 - [Error-Duplicati.Library.Main.Controller-FailedOperation]: Die Operation Backup ist mit folgenden Fehler fehlgeschlagen: Unexpected number of remote volumes marked as deleted. Found 0 filesets, but 1 volumes\r\nException: Unexpected number of remote volumes marked as deleted. Found 0 filesets, but 1 volumes"
  ],
  "BackendStatistics": {
    "RemoteCalls": 19372,
    "BytesUploaded": 2532012961047,
    "BytesDownloaded": 0,
    "FilesUploaded": 19363,
    "FilesDownloaded": 0,
    "FilesDeleted": 0,
    "FoldersCreated": 0,
    "RetryAttempts": 8,
    "UnknownFileSize": 0,
    "UnknownFileCount": 0,
    "KnownFileCount": 0,
    "KnownFileSize": 0,
    "LastBackupDate": "0001-01-01T00:00:00",
    "BackupListCount": 1,
    "TotalQuotaSpace": 0,
    "FreeQuotaSpace": 0,
    "AssignedQuotaSpace": -1,
    "ReportedQuotaError": false,
    "ReportedQuotaWarning": false,
    "MainOperation": "Backup",
    "ParsedResult": "Success",
    "Interrupted": false,
    "Version": "2.1.0.5 (2.1.0.5_stable_2025-03-04)",
    "EndTime": "0001-01-01T00:00:00",
    "BeginTime": "2025-04-08T14:26:08.8181136Z",
    "Duration": "00:00:00",
    "MessagesActualLength": 0,
    "WarningsActualLength": 0,
    "ErrorsActualLength": 0,
    "Messages": null,
    "Warnings": null,
    "Errors": null
  }
}

And the backup is listed as never having been run successfully:
[screenshot skipped because of new user restriction to only 3 media items]

Target directory now contains quite some data:

# df -h
Filesystem                Size      Used Available Use% Mounted on
/dev/sda1                 7.2T      2.3T      4.6T  34% /mnt/sda1

I also tried to verify the files, which ran as “successful” but I guess that no files really were verified:

image
image764×415 23.2 KB

How do I recover from here?

2

Welcome to the forum @dpstef

Thanks for giving a pretty good look at it. One question is – is your retention set to

image

That was the only way I could repro something similar (I used an FTP server set to read-only for my first backup, changed to read-write for second, and got a similar error saying:

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

Have you tried Database screen Repair? That worked on my case. Not sure for yours.

3

Thanks!

My retention policy is set to:
image

I tried a repair which took some seconds, but sadly it showed an output like the test action and changed nothing.
Now I am doing a database recreation, which takes some time and then we will see.

By the way: Today I backed up another computer using nearly the same configuration, and this worked flawlessly. This was a smaller backup, only 225 GB of files.

4

Maybe that could do it too. Help text says “There will remain one backup for each of the last 7 days”, and I think backups go by start time. You started two on April 8, so maybe got thinned.

Regardless, too bad a Repair didn’t work for you, but Recreate would have been next advice. Ideally, these are a lot faster than backup, as only dlist and dindex are read, not dblock which are the big files with the actual data. They’re only read if need be, to find missing data.

5

Nope, sadly recreating the database didn’t help either. Backup is still listed as ‘never’:
image

image
image607×280 18 KB

            {
  "MainOperation": "Repair",
  "RecreateDatabaseResults": {
    "MainOperation": "Repair",
    "ParsedResult": "Success",
    "Interrupted": false,
    "Version": "2.1.0.5 (2.1.0.5_stable_2025-03-04)",
    "EndTime": "2025-04-14T22:35:19.2811052Z",
    "BeginTime": "2025-04-14T21:39:42.7138615Z",
    "Duration": "00:55:36.5672437",
    "MessagesActualLength": 0,
    "WarningsActualLength": 0,
    "ErrorsActualLength": 0,
    "Messages": null,
    "Warnings": null,
    "Errors": null,
    "BackendStatistics": {
      "RemoteCalls": 9683,
      "BytesUploaded": 0,
      "BytesDownloaded": 661574138,
      "FilesUploaded": 0,
      "FilesDownloaded": 9682,
      "FilesDeleted": 0,
      "FoldersCreated": 0,
      "RetryAttempts": 0,
      "UnknownFileSize": 0,
      "UnknownFileCount": 0,
      "KnownFileCount": 0,
      "KnownFileSize": 0,
      "LastBackupDate": "0001-01-01T00:00:00",
      "BackupListCount": 0,
      "TotalQuotaSpace": 0,
      "FreeQuotaSpace": 0,
      "AssignedQuotaSpace": 0,
      "ReportedQuotaError": false,
      "ReportedQuotaWarning": false,
      "MainOperation": "Repair",
      "ParsedResult": "Success",
      "Interrupted": false,
      "Version": "2.1.0.5 (2.1.0.5_stable_2025-03-04)",
      "EndTime": "0001-01-01T00:00:00",
      "BeginTime": "2025-04-14T21:39:42.7113426Z",
      "Duration": "00:00:00",
      "MessagesActualLength": 0,
      "WarningsActualLength": 0,
      "ErrorsActualLength": 0,
      "Messages": null,
      "Warnings": null,
      "Errors": null
    }
  },
  "ParsedResult": "Success",
  "Interrupted": false,
  "Version": "2.1.0.5 (2.1.0.5_stable_2025-03-04)",
  "EndTime": "2025-04-14T22:35:21.9903046Z",
  "BeginTime": "2025-04-14T21:39:42.7113352Z",
  "Duration": "00:55:39.2789694",
  "MessagesActualLength": 19371,
  "WarningsActualLength": 0,
  "ErrorsActualLength": 0,
  "Messages": [
    "2025-04-14 23:39:42 +02 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: Die Operation Repair wurde gestartet",
    "2025-04-14 23:39:42 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started:  ()",
    "2025-04-14 23:39:44 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed:  (18,91 KB)",
    "2025-04-14 23:41:49 +02 - [Information-Duplicati.Library.Main.Operation.RecreateDatabaseHandler-RebuildStarted]: Rebuild database started, downloading 1 filelists",
    "2025-04-14 23:41:49 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-20250408T142608Z.dlist.zip.aes (249,26 MB)",
    "2025-04-14 23:42:02 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-20250408T142608Z.dlist.zip.aes (249,26 MB)",
    "2025-04-15 00:00:56 +02 - [Information-Duplicati.Library.Main.Operation.RecreateDatabaseHandler-FilelistsRestored]: Filelists restored, downloading 9681 index files",
    "2025-04-15 00:00:56 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-if5882c9c119c4cd49caed0828783c8a1.dindex.zip.aes (9,23 KB)",
    "2025-04-15 00:00:57 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-if5882c9c119c4cd49caed0828783c8a1.dindex.zip.aes (9,23 KB)",
    "2025-04-15 00:00:57 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-i3b84292926a744108dd49ea0bbf587f6.dindex.zip.aes (12,62 KB)",
    "2025-04-15 00:00:57 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-i3b84292926a744108dd49ea0bbf587f6.dindex.zip.aes (12,62 KB)",
    "2025-04-15 00:00:57 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-i9e2c9b418e59447eb8e5b2747fce85ca.dindex.zip.aes (15,45 KB)",
    "2025-04-15 00:00:57 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-i9e2c9b418e59447eb8e5b2747fce85ca.dindex.zip.aes (15,45 KB)",
    "2025-04-15 00:00:57 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-ibc56812893644620836fba956131f225.dindex.zip.aes (44,45 KB)",
    "2025-04-15 00:00:57 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-ibc56812893644620836fba956131f225.dindex.zip.aes (44,45 KB)",
    "2025-04-15 00:00:57 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-i8ffc1d27da3d4b578e459a9d2af9d334.dindex.zip.aes (9,25 KB)",
    "2025-04-15 00:00:57 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-i8ffc1d27da3d4b578e459a9d2af9d334.dindex.zip.aes (9,25 KB)",
    "2025-04-15 00:00:57 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-ide613c4169024ae1aa931f6d5088fbdc.dindex.zip.aes (9,45 KB)",
    "2025-04-15 00:00:57 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-ide613c4169024ae1aa931f6d5088fbdc.dindex.zip.aes (9,45 KB)",
    "2025-04-15 00:00:57 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-idd7ee8b14a1445958015664081d306ed.dindex.zip.aes (14,98 KB)"
  ],
  "Warnings": [],
  "Errors": [],
  "BackendStatistics": {
    "RemoteCalls": 9683,
    "BytesUploaded": 0,
    "BytesDownloaded": 661574138,
    "FilesUploaded": 0,
    "FilesDownloaded": 9682,
    "FilesDeleted": 0,
    "FoldersCreated": 0,
    "RetryAttempts": 0,
    "UnknownFileSize": 0,
    "UnknownFileCount": 0,
    "KnownFileCount": 0,
    "KnownFileSize": 0,
    "LastBackupDate": "0001-01-01T00:00:00",
    "BackupListCount": 0,
    "TotalQuotaSpace": 0,
    "FreeQuotaSpace": 0,
    "AssignedQuotaSpace": 0,
    "ReportedQuotaError": false,
    "ReportedQuotaWarning": false,
    "MainOperation": "Repair",
    "ParsedResult": "Success",
    "Interrupted": false,
    "Version": "2.1.0.5 (2.1.0.5_stable_2025-03-04)",
    "EndTime": "0001-01-01T00:00:00",
    "BeginTime": "2025-04-14T21:39:42.7113426Z",
    "Duration": "00:00:00",
    "MessagesActualLength": 0,
    "WarningsActualLength": 0,
    "ErrorsActualLength": 0,
    "Messages": null,
    "Warnings": null,
    "Errors": null
  }
}
6

… but I would be able to restore files:

image
image1194×328 23.1 KB

So something changed.

7

Home page backup stats only update on a successful backup, and you haven’t had one, exactly. First failed from access rights, second from (unknown), and then it was recreate.

It looks like recreate did few (if any) dblock downloads (based on average size), so good.

Possibly all is back together. The restore dropdown is showing second backup start time. Probably that’s the only one. First backup failed on access issue, but you can check for it.

is talking about the number of dlist files around. First backup made none (access error).

So you might be back in business from second backup forward. Care to test another run?

8

It is the only one. Only the second try did write data, the first one couldn’t because of missing permissions.

Sure! As we are now confident that it is repaired, I did another run and… tadaaaa!

That’s what I liked to see:

image
image652×189 15.8 KB

Sadly it still took 10 hours (displaying a data rate of under 1 MB/s in the end), but it worked.

Even the home page now displays two versions:

image
image441×138 6.71 KB

So thanks for guiding me through it!

1 Like