Difference in reported number/size of files between backup & restore process of same job

redusr · March 11, 2024, 9:14pm

I switched my computer and used Duplicati to transfer my personal files.
It seems to have worked fine (only a couple of warnings, see end of post) but what confuses me is that for the restore run on the new computer, Duplicati reports:

"RestoredFiles": 902869,
  "SizeOfRestoredFiles": 165690858910,

which is different from the metrics reported from the most recent backup run on the old computer before doing the restore:

"ExaminedFiles": 902883,
...
  "SizeOfExaminedFiles": 166831816523,

Should I be worried or can I ignore the differences?

Please find a more comprehensive description of what I did and the warnings below:

Ran the backup job one last time on the old computer.
Installed duplicati (2.0.7.1_beta_2023-05-25 - same release as on old computer) on the new computer.
Copied the backup job file and the server database in C:\Users\user\AppData\Local\Duplicati to the same directory on the new computer.
Started duplicati and ran restore on the job (to original location).

Results:

            {
  "RestoredFiles": 902869,
  "SizeOfRestoredFiles": 165690858910,
  "RestoredFolders": 87908,
  "RestoredSymlinks": 0,
  "PatchedFiles": 0,
  "DeletedFiles": 0,
  "DeletedFolders": 0,
  "DeletedSymlinks": 0,
  "MainOperation": "Restore",
  "RecreateDatabaseResults": null,
  "ParsedResult": "Warning",
  "Version": "2.0.7.1 (2.0.7.1_beta_2023-05-25)",
  "EndTime": "2024-03-11T20:17:18.6318433Z",
  "BeginTime": "2024-03-11T16:18:49.891381Z",
  "Duration": "03:58:28.7404623",
  "MessagesActualLength": 1843,
  "WarningsActualLength": 7,
  "ErrorsActualLength": 0,
  "Messages": [
    "2024-03-11 17:18:49 +01 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: Die Operation Restore wurde gestartet",
    "2024-03-11 17:18:50 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started:  ()",
    "2024-03-11 17:18:54 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed:  (1,81 KB)",
    "2024-03-11 17:18:54 +01 - [Information-Duplicati.Library.Main.Database.LocalRestoreDatabase-SearchingBackup]: Searching backup 0 (11.03.2024 15:01:22) ...",
    "2024-03-11 17:20:59 +01 - [Information-Duplicati.Library.Main.Operation.RestoreHandler-RemoteFileCount]: 919 remote files are required to restore",
    "2024-03-11 17:20:59 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-b75c411d58e0d4c4082c6e26235c946c3.dblock.zip.aes (99,84 MB)",
    "2024-03-11 17:21:04 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-b75c411d58e0d4c4082c6e26235c946c3.dblock.zip.aes (99,84 MB)",
    "2024-03-11 17:21:04 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-b2e5a873129e24543a2ee034069505e74.dblock.zip.aes (99,85 MB)",
    "2024-03-11 17:21:05 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-b2e5a873129e24543a2ee034069505e74.dblock.zip.aes (99,85 MB)",
    "2024-03-11 17:21:05 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-b76260b6ea27a450c8ca3c81a9df6c8a7.dblock.zip.aes (99,84 MB)",
    "2024-03-11 17:21:07 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-b76260b6ea27a450c8ca3c81a9df6c8a7.dblock.zip.aes (99,84 MB)",
    "2024-03-11 17:21:07 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-bcec227a7cf1a4bb7ba2df623fa958fe2.dblock.zip.aes (99,82 MB)",
    "2024-03-11 17:21:09 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-bcec227a7cf1a4bb7ba2df623fa958fe2.dblock.zip.aes (99,82 MB)",
    "2024-03-11 17:21:09 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-bfaa9b62fc3274bd1834abefda7ef6ca2.dblock.zip.aes (99,97 MB)",
    "2024-03-11 17:21:11 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-bfaa9b62fc3274bd1834abefda7ef6ca2.dblock.zip.aes (99,97 MB)",
    "2024-03-11 17:21:11 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-b47245419571b416ca665e2dc9737185e.dblock.zip.aes (99,76 MB)",
    "2024-03-11 17:21:12 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-b47245419571b416ca665e2dc9737185e.dblock.zip.aes (99,76 MB)",
    "2024-03-11 17:21:12 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-bc7b0241426404f43be42740db349bea6.dblock.zip.aes (99,77 MB)",
    "2024-03-11 17:21:14 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-bc7b0241426404f43be42740db349bea6.dblock.zip.aes (99,77 MB)",
    "2024-03-11 17:21:14 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-b76d13602c8524c3a8d02886d86d498f6.dblock.zip.aes (99,79 MB)"
  ],
  "Warnings": [
    "2024-03-11 17:21:53 +01 - [Warning-Duplicati.Library.Main.Operation.RestoreHandler-CreateMissingFolder]: Creating missing folder C:\\Users\\user\\AppData\\Roaming\\Code\\User for  file C:\\Users\\user\\AppData\\Roaming\\Code\\User\\settings.json",
    "2024-03-11 17:21:53 +01 - [Warning-Duplicati.Library.Main.Operation.RestoreHandler-CreateMissingFolder]: Creating missing folder C:\\Users\\user\\AppData\\Roaming\\Nextcloud for  file C:\\Users\\user\\AppData\\Roaming\\Nextcloud\\nextcloud.cfg.backup_20210713_144858_3.2.3stable-Win64 (build 20210624)",
    "2024-03-11 18:42:13 +01 - [Warning-Duplicati.Library.Main.Operation.RestoreHandler-MetadataWriteFailed]: Failed to apply metadata to file: \"C:\\Users\\user\\Anaconda3\\envs\\\", message: Der Prozess kann nicht auf die Datei \"\\\\?\\C:\\Users\\user\\Anaconda3\\envs\" zugreifen, da sie von einem anderen Prozess verwendet wird.",
    "2024-03-11 18:45:50 +01 - [Warning-Duplicati.Library.Main.Operation.RestoreHandler-MetadataWriteFailed]: Failed to apply metadata to file: \"C:\\Users\\user\\AppData\\Roaming\\KP\\\", message: Der Prozess kann nicht auf die Datei \"\\\\?\\C:\\Users\\user\\AppData\\Roaming\\KP\" zugreifen, da sie von einem anderen Prozess verwendet wird.",
    "2024-03-11 18:45:51 +01 - [Warning-Duplicati.Library.Main.Operation.RestoreHandler-MetadataWriteFailed]: Failed to apply metadata to file: \"C:\\Users\\user\\Desktop\\\", message: Der Prozess kann nicht auf die Datei \"\\\\?\\C:\\Users\\user\\Desktop\" zugreifen, da sie von einem anderen Prozess verwendet wird.",
    "2024-03-11 18:45:53 +01 - [Warning-Duplicati.Library.Main.Operation.RestoreHandler-MetadataWriteFailed]: Failed to apply metadata to file: \"C:\\Users\\user\\Downloads\\\", message: Der Prozess kann nicht auf die Datei \"\\\\?\\C:\\Users\\user\\Downloads\" zugreifen, da sie von einem anderen Prozess verwendet wird.",
    "2024-03-11 18:46:18 +01 - [Warning-Duplicati.Library.Main.Operation.RestoreHandler-MetadataWriteFailed]: Failed to apply metadata to file: \"C:\\Users\\user\\AppData\\Roaming\\Mozilla\\Firefox\\Profiles\\\", message: Der Prozess kann nicht auf die Datei \"\\\\?\\C:\\Users\\user\\AppData\\Roaming\\Mozilla\\Firefox\\Profiles\" zugreifen, da sie von einem anderen Prozess verwendet wird."
  ],
  "Errors": [],
  "BackendStatistics": {
    "RemoteCalls": 920,
    "BytesUploaded": 0,
    "BytesDownloaded": 96077425099,
    "FilesUploaded": 0,
    "FilesDownloaded": 919,
    "FilesDeleted": 0,
    "FoldersCreated": 0,
    "RetryAttempts": 0,
    "UnknownFileSize": 0,
    "UnknownFileCount": 0,
    "KnownFileCount": 1854,
    "KnownFileSize": 96573140486,
    "LastBackupDate": "2024-03-11T16:01:22+01:00",
    "BackupListCount": 6,
    "TotalQuotaSpace": 322122280960,
    "FreeQuotaSpace": 135510937600,
    "AssignedQuotaSpace": -1,
    "ReportedQuotaError": false,
    "ReportedQuotaWarning": false,
    "MainOperation": "Restore",
    "ParsedResult": "Success",
    "Version": "2.0.7.1 (2.0.7.1_beta_2023-05-25)",
    "EndTime": "0001-01-01T00:00:00",
    "BeginTime": "2024-03-11T16:18:49.891381Z",
    "Duration": "00:00:00",
    "MessagesActualLength": 0,
    "WarningsActualLength": 0,
    "ErrorsActualLength": 0,
    "Messages": null,
    "Warnings": null,
    "Errors": null
  }
}

The warnings are basically:

New folder had to be created (this is expected as I restored non-existing data to a new computer; I’m only wondering why the warning only occured a couple of times and not for every single folder).
Folder metadata could not be set (the message “Der Prozess kann nicht auf die Datei … zugreifen, da sie von einem anderen Prozess verwendet wird.” means that another process accessed the file and duplicati could thus not access it). Most of the reported folders may indeed have been open in Windows explorer during the restore process.

Both computers run Windows (10 / 11), the source drive on both is formatted as NTFS, similar to the backup drive.

Should I restore or verify the restored data one more time or can I ignore the differences safely? Now that (at least most of) the data seems to be in place, how much faster can I expect another round of the restore process (particulary, copying files & verifying the results) to finish? Especially verifying the restored data took hours, so if it is not necessary I would like to avoid it to be able to start working on the computer as soon as possible.

If you need any additional info, please let me know.
Thanks for your help!

kenkendk · March 12, 2024, 10:18am

Hi @redusr!

This usually happens when the code does not restore the folder, but restores the file. I think it can also happen if there is some issue with the order of operations (i.e. file is incorrectly created before the folder).

Yes, that is how Windows files work, sadly not much to do. It can be any tool running in the background, but it could also be Duplicati itself

It looks like 14 files were examined but not present in the restore.
It is possible that a file is examined but not included in the backup.
If this happens there should be some message in the backup log that explains it.

redusr · March 12, 2024, 11:11am

Thanks for your reply!

Could you elaborate which of the logs is the backup log? When navigating Reporting → Show log → General, there is an expandable entry (this is where I copied the info from for my previous post) but it does not seem to contain all messages. For the most recent backup run, it is:

            {
  "DeletedFiles": 0,
  "DeletedFolders": 0,
  "ModifiedFiles": 0,
  "ExaminedFiles": 902883,
  "OpenedFiles": 0,
  "AddedFiles": 0,
  "SizeOfModifiedFiles": 0,
  "SizeOfAddedFiles": 0,
  "SizeOfExaminedFiles": 166831816523,
  "SizeOfOpenedFiles": 0,
  "NotProcessedFiles": 0,
  "AddedFolders": 0,
  "TooLargeFiles": 0,
  "FilesWithError": 0,
  "ModifiedFolders": 0,
  "ModifiedSymlinks": 0,
  "AddedSymlinks": 0,
  "DeletedSymlinks": 0,
  "PartialBackup": false,
  "Dryrun": false,
  "MainOperation": "Backup",
  "CompactResults": null,
  "VacuumResults": null,
  "DeleteResults": {
    "DeletedSetsActualLength": 0,
    "DeletedSets": [],
    "Dryrun": false,
    "MainOperation": "Delete",
    "CompactResults": null,
    "ParsedResult": "Success",
    "Version": "2.0.7.1 (2.0.7.1_beta_2023-05-25)",
    "EndTime": "2024-03-11T15:59:23.5842296Z",
    "BeginTime": "2024-03-11T15:59:15.5914618Z",
    "Duration": "00:00:07.9927678",
    "MessagesActualLength": 0,
    "WarningsActualLength": 0,
    "ErrorsActualLength": 0,
    "Messages": null,
    "Warnings": null,
    "Errors": null,
    "BackendStatistics": {
      "RemoteCalls": 5,
      "BytesUploaded": 0,
      "BytesDownloaded": 170697703,
      "FilesUploaded": 0,
      "FilesDownloaded": 3,
      "FilesDeleted": 0,
      "FoldersCreated": 0,
      "RetryAttempts": 0,
      "UnknownFileSize": 0,
      "UnknownFileCount": 0,
      "KnownFileCount": 1854,
      "KnownFileSize": 96573140486,
      "LastBackupDate": "2024-03-11T16:01:22+01:00",
      "BackupListCount": 6,
      "TotalQuotaSpace": 322122280960,
      "FreeQuotaSpace": 137579184128,
      "AssignedQuotaSpace": -1,
      "ReportedQuotaError": false,
      "ReportedQuotaWarning": false,
      "MainOperation": "Backup",
      "ParsedResult": "Success",
      "Version": "2.0.7.1 (2.0.7.1_beta_2023-05-25)",
      "EndTime": "0001-01-01T00:00:00",
      "BeginTime": "2024-03-11T15:57:57.516724Z",
      "Duration": "00:00:00",
      "MessagesActualLength": 0,
      "WarningsActualLength": 0,
      "ErrorsActualLength": 0,
      "Messages": null,
      "Warnings": null,
      "Errors": null
    }
  },
  "RepairResults": null,
  "TestResults": {
    "MainOperation": "Test",
    "VerificationsActualLength": 3,
    "Verifications": [
      {
        "Key": "duplicati-20240311T150122Z.dlist.zip.aes",
        "Value": []
      },
      {
        "Key": "duplicati-ia61627e25d904d8f959c311691a7e9c3.dindex.zip.aes",
        "Value": []
      },
      {
        "Key": "duplicati-be80ff0e04a3648c294441f3532837bf0.dblock.zip.aes",
        "Value": []
      }
    ],
    "ParsedResult": "Success",
    "Version": "2.0.7.1 (2.0.7.1_beta_2023-05-25)",
    "EndTime": "2024-03-11T15:59:25.2692452Z",
    "BeginTime": "2024-03-11T15:59:23.6639707Z",
    "Duration": "00:00:01.6052745",
    "MessagesActualLength": 0,
    "WarningsActualLength": 0,
    "ErrorsActualLength": 0,
    "Messages": null,
    "Warnings": null,
    "Errors": null,
    "BackendStatistics": {
      "RemoteCalls": 5,
      "BytesUploaded": 0,
      "BytesDownloaded": 170697703,
      "FilesUploaded": 0,
      "FilesDownloaded": 3,
      "FilesDeleted": 0,
      "FoldersCreated": 0,
      "RetryAttempts": 0,
      "UnknownFileSize": 0,
      "UnknownFileCount": 0,
      "KnownFileCount": 1854,
      "KnownFileSize": 96573140486,
      "LastBackupDate": "2024-03-11T16:01:22+01:00",
      "BackupListCount": 6,
      "TotalQuotaSpace": 322122280960,
      "FreeQuotaSpace": 137579184128,
      "AssignedQuotaSpace": -1,
      "ReportedQuotaError": false,
      "ReportedQuotaWarning": false,
      "MainOperation": "Backup",
      "ParsedResult": "Success",
      "Version": "2.0.7.1 (2.0.7.1_beta_2023-05-25)",
      "EndTime": "0001-01-01T00:00:00",
      "BeginTime": "2024-03-11T15:57:57.516724Z",
      "Duration": "00:00:00",
      "MessagesActualLength": 0,
      "WarningsActualLength": 0,
      "ErrorsActualLength": 0,
      "Messages": null,
      "Warnings": null,
      "Errors": null
    }
  },
  "ParsedResult": "Success",
  "Version": "2.0.7.1 (2.0.7.1_beta_2023-05-25)",
  "EndTime": "2024-03-11T15:59:25.2804644Z",
  "BeginTime": "2024-03-11T15:57:57.516724Z",
  "Duration": "00:01:27.7637404",
  "MessagesActualLength": 17,
  "WarningsActualLength": 0,
  "ErrorsActualLength": 0,
  "Messages": [
    "2024-03-11 16:57:57 +01 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: Die Operation Backup wurde gestartet",
    "2024-03-11 16:58:23 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started:  ()",
    "2024-03-11 16:58:23 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed:  (1,81 KB)",
    "2024-03-11 16:59:15 +01 - [Information-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-StartCheck]: Start checking if backups can be removed",
    "2024-03-11 16:59:15 +01 - [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",
    "2024-03-11 16:59:15 +01 - [Information-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-BackupList]: Backups to consider: 2024-02-27 5:30:55 PM, 2024-02-14 5:43:39 PM, 2024-01-31 6:35:25 PM, 2023-12-20 6:56:17 PM, 2023-11-07 2:20:04 PM",
    "2024-03-11 16:59:15 +01 - [Information-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-BackupsToDelete]: Backups outside of all time frames and thus getting deleted: ",
    "2024-03-11 16:59:15 +01 - [Information-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-AllBackupsToDelete]: All backups to delete: ",
    "2024-03-11 16:59:23 +01 - [Information-Duplicati.Library.Main.Operation.DeleteHandler-DeleteResults]: No remote filesets were deleted",
    "2024-03-11 16:59:23 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started:  ()",
    "2024-03-11 16:59:23 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed:  (1,81 KB)",
    "2024-03-11 16:59:23 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-20240311T150122Z.dlist.zip.aes (62,84 MB)",
    "2024-03-11 16:59:23 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-20240311T150122Z.dlist.zip.aes (62,84 MB)",
    "2024-03-11 16:59:23 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-ia61627e25d904d8f959c311691a7e9c3.dindex.zip.aes (14,56 KB)",
    "2024-03-11 16:59:23 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-ia61627e25d904d8f959c311691a7e9c3.dindex.zip.aes (14,56 KB)",
    "2024-03-11 16:59:23 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-be80ff0e04a3648c294441f3532837bf0.dblock.zip.aes (99,93 MB)",
    "2024-03-11 16:59:25 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-be80ff0e04a3648c294441f3532837bf0.dblock.zip.aes (99,93 MB)"
  ],
  "Warnings": [],
  "Errors": [],
  "BackendStatistics": {
    "RemoteCalls": 5,
    "BytesUploaded": 0,
    "BytesDownloaded": 170697703,
    "FilesUploaded": 0,
    "FilesDownloaded": 3,
    "FilesDeleted": 0,
    "FoldersCreated": 0,
    "RetryAttempts": 0,
    "UnknownFileSize": 0,
    "UnknownFileCount": 0,
    "KnownFileCount": 1854,
    "KnownFileSize": 96573140486,
    "LastBackupDate": "2024-03-11T16:01:22+01:00",
    "BackupListCount": 6,
    "TotalQuotaSpace": 322122280960,
    "FreeQuotaSpace": 137579184128,
    "AssignedQuotaSpace": -1,
    "ReportedQuotaError": false,
    "ReportedQuotaWarning": false,
    "MainOperation": "Backup",
    "ParsedResult": "Success",
    "Version": "2.0.7.1 (2.0.7.1_beta_2023-05-25)",
    "EndTime": "0001-01-01T00:00:00",
    "BeginTime": "2024-03-11T15:57:57.516724Z",
    "Duration": "00:00:00",
    "MessagesActualLength": 0,
    "WarningsActualLength": 0,
    "ErrorsActualLength": 0,
    "Messages": null,
    "Warnings": null,
    "Errors": null
  }
}

I don’t see any messages explaining why more files could have been examined than backed up. Where do I have to look?

Thanks to my impatience, I had the idea to repeat the restore procedure over night when the computer is unattended anyways. Bad idea, right?
Upon return to the computer, Duplicati welcomed me with three error and 9035 warning messages for the 2nd restore run:

            {
  "RestoredFiles": 31169,
  "SizeOfRestoredFiles": 2308875141,
  "RestoredFolders": 1533,
  "RestoredSymlinks": 0,
  "PatchedFiles": 0,
  "DeletedFiles": 0,
  "DeletedFolders": 0,
  "DeletedSymlinks": 0,
  "MainOperation": "Restore",
  "RecreateDatabaseResults": null,
  "ParsedResult": "Error",
  "Version": "2.0.7.1 (2.0.7.1_beta_2023-05-25)",
  "EndTime": "2024-03-11T23:53:31.6966754Z",
  "BeginTime": "2024-03-11T21:50:42.2934575Z",
  "Duration": "02:02:49.4032179",
  "MessagesActualLength": 998,
  "WarningsActualLength": 9035,
  "ErrorsActualLength": 3,
  "Messages": [
    "2024-03-11 22:50:42 +01 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Restore has started",
    "2024-03-11 22:50:43 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started:  ()",
    "2024-03-11 22:50:50 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed:  (1,81 KB)",
    "2024-03-11 22:50:50 +01 - [Information-Duplicati.Library.Main.Database.LocalRestoreDatabase-SearchingBackup]: Searching backup 0 (11.03.2024 15:01:22) ...",
    "2024-03-12 00:30:08 +01 - [Information-Duplicati.Library.Main.Operation.RestoreHandler-RemoteFileCount]: 496 remote files are required to restore",
    "2024-03-12 00:30:08 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-b62a67af2ea44437b84f269c0c902936f.dblock.zip.aes (99,93 MB)",
    "2024-03-12 00:30:13 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-b62a67af2ea44437b84f269c0c902936f.dblock.zip.aes (99,93 MB)",
    "2024-03-12 00:30:13 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-bd6fe1fdd37dd47a7af2f0db320519b0e.dblock.zip.aes (99,93 MB)",
    "2024-03-12 00:30:15 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-bd6fe1fdd37dd47a7af2f0db320519b0e.dblock.zip.aes (99,93 MB)",
    "2024-03-12 00:30:15 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-b95ef751ca12848368f61189ed1bad73d.dblock.zip.aes (99,95 MB)",
    "2024-03-12 00:30:17 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-b95ef751ca12848368f61189ed1bad73d.dblock.zip.aes (99,95 MB)",
    "2024-03-12 00:30:17 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-bac95021afd56481a968516eb9c6e016e.dblock.zip.aes (99,98 MB)",
    "2024-03-12 00:30:19 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-bac95021afd56481a968516eb9c6e016e.dblock.zip.aes (99,98 MB)",
    "2024-03-12 00:30:19 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-b37e3640253e044489da37938d2e6cf70.dblock.zip.aes (99,97 MB)",
    "2024-03-12 00:30:21 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-b37e3640253e044489da37938d2e6cf70.dblock.zip.aes (99,97 MB)",
    "2024-03-12 00:30:21 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-b23a30d583a6d49a5a903ed4839b1aacd.dblock.zip.aes (99,95 MB)",
    "2024-03-12 00:30:23 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-b23a30d583a6d49a5a903ed4839b1aacd.dblock.zip.aes (99,95 MB)",
    "2024-03-12 00:30:23 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-bd48f65d36a684d08bf34f1a39fe1c00e.dblock.zip.aes (99,78 MB)",
    "2024-03-12 00:30:24 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-bd48f65d36a684d08bf34f1a39fe1c00e.dblock.zip.aes (99,78 MB)",
    "2024-03-12 00:30:24 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-b124ecb4df488476caff8a0f769283d47.dblock.zip.aes (99,98 MB)"
  ],
  "Warnings": [
    "2024-03-12 00:46:49 +01 - [Warning-Duplicati.Library.Main.Operation.RestoreHandler-MetadataWriteFailed]: Failed to apply metadata to file: \"C:\\Users\\user\\Documents\\3ds Max 2023\\.git\\objects\\23\\6b93c8b56cb350f167ed7e23132cf629268cdb\", message: Der Zugriff auf den Pfad \"\\\\?\\C:\\Users\\user\\Documents\\3ds Max 2023\\.git\\objects\\23\\6b93c8b56cb350f167ed7e23132cf629268cdb\" wurde verweigert.",
    "2024-03-12 00:46:49 +01 - [Warning-Duplicati.Library.Main.Operation.RestoreHandler-MetadataWriteFailed]: Failed to apply metadata to file: \"C:\\Users\\user\\Documents\\3ds Max 2023\\.git\\objects\\86\\b22609787fa41b1397b8dadb3c8f2a9243275b\", message: Der Zugriff auf den Pfad \"\\\\?\\C:\\Users\\user\\Documents\\3ds Max 2023\\.git\\objects\\86\\b22609787fa41b1397b8dadb3c8f2a9243275b\" wurde verweigert.",
    "2024-03-12 00:46:49 +01 - [Warning-Duplicati.Library.Main.Operation.RestoreHandler-MetadataWriteFailed]: Failed to apply metadata to file: \"C:\\Users\\user\\Documents\\3ds Max 2023\\.git\\objects\\a8\\de2536bfb0c299fda06c788235c755b47bef3a\", message: Der Zugriff auf den Pfad \"\\\\?\\C:\\Users\\user\\Documents\\3ds Max 2023\\.git\\objects\\a8\\de2536bfb0c299fda06c788235c755b47bef3a\" wurde verweigert.",
    "2024-03-12 00:46:49 +01 - [Warning-Duplicati.Library.Main.Operation.RestoreHandler-MetadataWriteFailed]: Failed to apply metadata to file: \"C:\\Users\\user\\Documents\\3ds Max 2023\\.git\\objects\\e1\\aea1232672460ae44a7767f1e3929aedc28b62\", message: Der Zugriff auf den Pfad \"\\\\?\\C:\\Users\\user\\Documents\\3ds Max 2023\\.git\\objects\\e1\\aea1232672460ae44a7767f1e3929aedc28b62\" wurde verweigert.",
    "2024-03-12 00:46:49 +01 - [Warning-Duplicati.Library.Main.Operation.RestoreHandler-MetadataWriteFailed]: Failed to apply metadata to file: \"C:\\Users\\user\\Documents\\3ds Max 2023\\.git\\objects\\00\\ce8554489dbfe3fd9023013cc26335365d3035\", message: Der Zugriff auf den Pfad \"\\\\?\\C:\\Users\\user\\Documents\\3ds Max 2023\\.git\\objects\\00\\ce8554489dbfe3fd9023013cc26335365d3035\" wurde verweigert.",
    "2024-03-12 00:46:49 +01 - [Warning-Duplicati.Library.Main.Operation.RestoreHandler-MetadataWriteFailed]: Failed to apply metadata to file: \"C:\\Users\\user\\Documents\\3ds Max 2023\\.git\\objects\\63\\82c42fb10b26592e82950640186da427a3be6b\", message: Der Zugriff auf den Pfad \"\\\\?\\C:\\Users\\user\\Documents\\3ds Max 2023\\.git\\objects\\63\\82c42fb10b26592e82950640186da427a3be6b\" wurde verweigert.",
    "2024-03-12 00:46:49 +01 - [Warning-Duplicati.Library.Main.Operation.RestoreHandler-MetadataWriteFailed]: Failed to apply metadata to file: \"C:\\Users\\user\\Documents\\3ds Max 2023\\.git\\objects\\c0\\0cc6c1f3cea819342c78dba01839d5c05eaee4\", message: Der Zugriff auf den Pfad \"\\\\?\\C:\\Users\\user\\Documents\\3ds Max 2023\\.git\\objects\\c0\\0cc6c1f3cea819342c78dba01839d5c05eaee4\" wurde verweigert.",
    "2024-03-12 00:46:49 +01 - [Warning-Duplicati.Library.Main.Operation.RestoreHandler-MetadataWriteFailed]: Failed to apply metadata to file: \"C:\\Users\\user\\Documents\\3ds Max 2023\\.git\\objects\\09\\9d9b099d1b2f07dcbe3840c952471d58d497d5\", message: Der Zugriff auf den Pfad \"\\\\?\\C:\\Users\\user\\Documents\\3ds Max 2023\\.git\\objects\\09\\9d9b099d1b2f07dcbe3840c952471d58d497d5\" wurde verweigert.",
    "2024-03-12 00:46:49 +01 - [Warning-Duplicati.Library.Main.Operation.RestoreHandler-MetadataWriteFailed]: Failed to apply metadata to file: \"C:\\Users\\user\\Documents\\3ds Max 2023\\.git\\objects\\6f\\fab5bc83ab0abdaf7ac9fa85538091bf01f035\", message: Der Zugriff auf den Pfad \"\\\\?\\C:\\Users\\user\\Documents\\3ds Max 2023\\.git\\objects\\6f\\fab5bc83ab0abdaf7ac9fa85538091bf01f035\" wurde verweigert.",
    "2024-03-12 00:46:49 +01 - [Warning-Duplicati.Library.Main.Operation.RestoreHandler-MetadataWriteFailed]: Failed to apply metadata to file: \"C:\\Users\\user\\Documents\\3ds Max 2023\\.git\\objects\\cc\\29053677ded5b8d957d1af29c56dfb64a7cb40\", message: Der Zugriff auf den Pfad \"\\\\?\\C:\\Users\\user\\Documents\\3ds Max 2023\\.git\\objects\\cc\\29053677ded5b8d957d1af29c56dfb64a7cb40\" wurde verweigert.",
    "2024-03-12 00:46:49 +01 - [Warning-Duplicati.Library.Main.Operation.RestoreHandler-MetadataWriteFailed]: Failed to apply metadata to file: \"C:\\Users\\user\\Documents\\Blender\\.git\\objects\\0a\\f50b0ba5693b40514b65ed40fe2d63d7d637be\", message: Der Zugriff auf den Pfad \"\\\\?\\C:\\Users\\user\\Documents\\Blender\\.git\\objects\\0a\\f50b0ba5693b40514b65ed40fe2d63d7d637be\" wurde verweigert.",
    "2024-03-12 00:46:49 +01 - [Warning-Duplicati.Library.Main.Operation.RestoreHandler-MetadataWriteFailed]: Failed to apply metadata to file: \"C:\\Users\\user\\Documents\\Blender\\.git\\objects\\0d\\e9c00251589c8fcc5a6ccb9bde86c56e0e88f5\", message: Der Zugriff auf den Pfad \"\\\\?\\C:\\Users\\user\\Documents\\Blender\\.git\\objects\\0d\\e9c00251589c8fcc5a6ccb9bde86c56e0e88f5\" wurde verweigert.",
    "2024-03-12 00:46:49 +01 - [Warning-Duplicati.Library.Main.Operation.RestoreHandler-MetadataWriteFailed]: Failed to apply metadata to file: \"C:\\Users\\user\\Documents\\Blender\\.git\\objects\\23\\54f2a3a717c67c4321fab60537aa3992029fe2\", message: Der Zugriff auf den Pfad \"\\\\?\\C:\\Users\\user\\Documents\\Blender\\.git\\objects\\23\\54f2a3a717c67c4321fab60537aa3992029fe2\" wurde verweigert.",
    "2024-03-12 00:46:49 +01 - [Warning-Duplicati.Library.Main.Operation.RestoreHandler-MetadataWriteFailed]: Failed to apply metadata to file: \"C:\\Users\\user\\Documents\\Blender\\.git\\objects\\23\\e60d016e115537e552fcf428dc3ec4989d07f4\", message: Der Zugriff auf den Pfad \"\\\\?\\C:\\Users\\user\\Documents\\Blender\\.git\\objects\\23\\e60d016e115537e552fcf428dc3ec4989d07f4\" wurde verweigert.",
    "2024-03-12 00:46:49 +01 - [Warning-Duplicati.Library.Main.Operation.RestoreHandler-MetadataWriteFailed]: Failed to apply metadata to file: \"C:\\Users\\user\\Documents\\Blender\\.git\\objects\\31\\d9408d080ad12fbee107798a6c6cbdbf425507\", message: Der Zugriff auf den Pfad \"\\\\?\\C:\\Users\\user\\Documents\\Blender\\.git\\objects\\31\\d9408d080ad12fbee107798a6c6cbdbf425507\" wurde verweigert.",
    "2024-03-12 00:46:49 +01 - [Warning-Duplicati.Library.Main.Operation.RestoreHandler-MetadataWriteFailed]: Failed to apply metadata to file: \"C:\\Users\\user\\Documents\\Blender\\.git\\objects\\3a\\349f9e2a9c3d3c749b6a585bdb1229639be151\", message: Der Zugriff auf den Pfad \"\\\\?\\C:\\Users\\user\\Documents\\Blender\\.git\\objects\\3a\\349f9e2a9c3d3c749b6a585bdb1229639be151\" wurde verweigert.",
    "2024-03-12 00:46:49 +01 - [Warning-Duplicati.Library.Main.Operation.RestoreHandler-MetadataWriteFailed]: Failed to apply metadata to file: \"C:\\Users\\user\\Documents\\Blender\\.git\\objects\\3f\\63af196100ff1559bf66cd19b44878b0e6ae08\", message: Der Zugriff auf den Pfad \"\\\\?\\C:\\Users\\user\\Documents\\Blender\\.git\\objects\\3f\\63af196100ff1559bf66cd19b44878b0e6ae08\" wurde verweigert.",
    "2024-03-12 00:46:49 +01 - [Warning-Duplicati.Library.Main.Operation.RestoreHandler-MetadataWriteFailed]: Failed to apply metadata to file: \"C:\\Users\\user\\Documents\\Blender\\.git\\objects\\4b\\41adc4769aa85f0904e5c8303c672657cf31d5\", message: Der Zugriff auf den Pfad \"\\\\?\\C:\\Users\\user\\Documents\\Blender\\.git\\objects\\4b\\41adc4769aa85f0904e5c8303c672657cf31d5\" wurde verweigert.",
    "2024-03-12 00:46:49 +01 - [Warning-Duplicati.Library.Main.Operation.RestoreHandler-MetadataWriteFailed]: Failed to apply metadata to file: \"C:\\Users\\user\\Documents\\Blender\\.git\\objects\\54\\fb49c70c88576a0e7531fb78e8eed68f9780a2\", message: Der Zugriff auf den Pfad \"\\\\?\\C:\\Users\\user\\Documents\\Blender\\.git\\objects\\54\\fb49c70c88576a0e7531fb78e8eed68f9780a2\" wurde verweigert.",
    "2024-03-12 00:46:49 +01 - [Warning-Duplicati.Library.Main.Operation.RestoreHandler-MetadataWriteFailed]: Failed to apply metadata to file: \"C:\\Users\\user\\Documents\\Blender\\.git\\objects\\62\\d97a7fca9843514fa4f1509dedd8d195b4ed55\", message: Der Zugriff auf den Pfad \"\\\\?\\C:\\Users\\user\\Documents\\Blender\\.git\\objects\\62\\d97a7fca9843514fa4f1509dedd8d195b4ed55\" wurde verweigert."
  ],
  "Errors": [
    "2024-03-12 00:46:48 +01 - [Error-Duplicati.Library.Main.Operation.RestoreHandler-RestoreFileFailed]: Failed to restore empty file: \"C:\\Users\\user\\Nc\\.nextcloudsync.log\". Error message was: Der Zugriff auf den Pfad \"\\\\?\\C:\\Users\\user\\Nc\\.nextcloudsync.log\" wurde verweigert.",
    "2024-03-12 00:46:49 +01 - [Error-Duplicati.Library.Main.Operation.RestoreHandler-RestoreFileFailed]: Failed to restore empty file: \"C:\\Users\\user\\Nc_C\\.nextcloudsync.log\". Error message was: Der Zugriff auf den Pfad \"\\\\?\\C:\\Users\\user\\Nc_C\\.nextcloudsync.log\" wurde verweigert.",
    "2024-03-12 00:46:49 +01 - [Error-Duplicati.Library.Main.Operation.RestoreHandler-RestoreFileFailed]: Failed to restore empty file: \"C:\\Users\\user\\Nc_F\\.nextcloudsync.log\". Error message was: Der Zugriff auf den Pfad \"\\\\?\\C:\\Users\\user\\Nc_F\\.nextcloudsync.log\" wurde verweigert."
  ],
  "BackendStatistics": {
    "RemoteCalls": 497,
    "BytesUploaded": 0,
    "BytesDownloaded": 51748231648,
    "FilesUploaded": 0,
    "FilesDownloaded": 496,
    "FilesDeleted": 0,
    "FoldersCreated": 0,
    "RetryAttempts": 0,
    "UnknownFileSize": 0,
    "UnknownFileCount": 0,
    "KnownFileCount": 1854,
    "KnownFileSize": 96573140486,
    "LastBackupDate": "2024-03-11T16:01:22+01:00",
    "BackupListCount": 6,
    "TotalQuotaSpace": 322122280960,
    "FreeQuotaSpace": 135510937600,
    "AssignedQuotaSpace": -1,
    "ReportedQuotaError": false,
    "ReportedQuotaWarning": false,
    "MainOperation": "Restore",
    "ParsedResult": "Success",
    "Version": "2.0.7.1 (2.0.7.1_beta_2023-05-25)",
    "EndTime": "0001-01-01T00:00:00",
    "BeginTime": "2024-03-11T21:50:42.2934575Z",
    "Duration": "00:00:00",
    "MessagesActualLength": 0,
    "WarningsActualLength": 0,
    "ErrorsActualLength": 0,
    "Messages": null,
    "Warnings": null,
    "Errors": null
  }
}

Even though I hope that the 2nd restore did not worsen the situation (the message “Der Zugriff auf den Pfad … wurde verweigert.” means access denied; so probably no action was performed for the file and thus no damage is to be expected, right?), the number of warnings reported (9035) but not included in the log display leaves me with additional confusion.
How would I proceed to make sure I have a full and correct restore of the data on the new computer? Is there any more verbose log I should check for?

PS: This time, I had closed all other applications before doing the restore. Not sure why permission errors occured this time.

ts678 · March 12, 2024, 2:29pm

While waiting to see if your developer helper has any more advice. I’ll say that my backup matches up on files and total file size between a backup run and a restore run done as a new job with database recreate, attempting to simulate what you’re doing but on one computer, where I put restore in a non-original folder.

I’ll mention I think I found a bug where RestoredSymlinks isn’t counted. RestoredFolders is also odd, however the most important thing for most people is probably the files, so I’ll focus on that worry instead.

With a statistical discrepancy in the logs, one isn’t sure which number to believe, but a tie-breaker can be what the database thinks. I’m not sure if there’s another easy way to get even a count of files in a backup. One hard way is to use The FIND command to make a file, and filter out lines which are not files, such as folder or symbolic links. Only files will have a size. A somewhat simpler method is to look in the database.

If you make a copy (for safety) of your job database (assuming that you did a Repair, not Direct restore), DB Browser for SQLite can open it and give an opinion on what the latest backup has in it for files. It’s a couple of SQL queries, after finding the fileset number. My fileset is 17 in this example (highest ID in the Fileset table), and I can get the number of files I expect restored, and the total size I expect to see there.

SELECT Path FROM FilesetEntry JOIN File ON FileID = ID WHERE FilesetID = 17 AND BlocksetID > 0
6799

SELECT SUM(Length) FROM FilesetEntry JOIN File ON FileID = File.ID JOIN Blockset ON BlocksetID = Blockset.ID WHERE FilesetID = 649 AND BlocksetID > 0
8199317885

Complete log has
“RestoredFiles”: 6799,
“SizeOfRestoredFiles”: 8199317885,

Windows File Explorer has

On the backup side, Complete log has

“ExaminedFiles”: 6799,
“SizeOfExaminedFiles”: 8199317885,

so mine isn’t showing a file difference. If you’re willing to look in the database, but need help, just ask. Beyond that, the restore does do some of its own verification that (I think) file data is what it should be, however if the database has the wrong file count (and I’m not going to guess how), verify won’t notice.

redusr · March 12, 2024, 3:04pm

Thank you for sharing the database-approach of investigating the difference!

Is it possible to examine which files exist in the backup vs. which files have been restored (some kind of diff, spitting out the 14 allegedly missing files)?

One remark here: I copied the server database together with the job database to the new computer and thus assumed that a repair would not be necessary. I expanded the job in the Home view and chose Operations → Restore Files. Should I have done a repair before (or do it now)?

Regarding the job database: I issued following queries to investigate the number of files and their size:

Select id from FileSet Order by timestamp DESC limit 1;

→ ID (used in the subsequent queries): 12

Select Count(Distinct Path) From FilesetEntry Join File On FileID = ID Where FilesetID = 12 And BlocksetID > 0;

→ Number of files (same when removing “distinct” from the query): 902883

Select Sum(Length) From FilesetEntry Join File On FileID = File.ID Join Blockset On BlocksetID = Blockset.ID WHE
RE FilesetID = 12 And BlocksetID > 0;

→ 166831816523
These numbers are identical with the numbers of the last backup run.

The verification part in Windows explorer is a bit more complicated because the restore writes in paths which may or may not already exist on the new computer and may contain other files which are not part of the backup but contribute to the Windows explorer calculation.
What I am trying to allow some kind of Windows explorer based verification is to restore the backup to an empty directory, check the number/size of files reported in the log and then verify that piece of information using the explorer properties window. This will of course not work if the log reports another number/size of restored files.
I can post an update afterwards.

ts678 · March 12, 2024, 3:25pm

Yes, but if you mean actually look in the restore area, you would also need a script. I just made one, but scaling up to almost a million files might stress some things. You’d need to install Python on the system. Comparison is between the database information and the restore area. This is a very crude initial script.

That should be fine, and saves the time of recreating it. In theory, the result should be the same, but as there’s a statistical discrepancy, using the original database rules out the chance that recreate did that.

so that suggests that the discrepancy was on the restore (any expert opinions on all this are welcome).

I was wondering about what you restored to. One thing that throws people off is that Duplicati won’t do a restore if the file in the restore area is already exactly right in terms of its data. This is most obvious from “Restore completed without errors but no files were restored” warning, which confuses some people and seems somewhat alarming. It just means everything was all set already. If yours was partly all set, it may account for some shortage of restores, however if you compare database to destination, all may be OK.

That’s what I did. It avoids the messiness of existing files, active file processing after restore, and so on.

redusr · March 12, 2024, 6:18pm

I’m not afraid of scripts and should also have a python environment available, however my questionable policy of also trying to migrate application configuration to the new computer makes the setup of the environment in my environment manager prior to verifying the restore success of the manager configuration a bit tricky.

That is quite interesting and if it is indeed the case, for the 14 allegedly non-restored files, there would not be a problem at all.

The restore to the empty directory is still verifying but at least the explorer data looks promising:

What I am currently thinking of is manually moving the files restored from the (formerly) empty directory to the designated source location on the new computer, overwriting traces of the original restore. Then I could forget about the initial difference in the number/size of files and the 9035 warnings of the second restore attempt to the source location. Only caveat I can think of is that I originally chose to restore permissions but not for the backup in the empty directory, this may lead to a similar access permission failure as reported by duplicati in the second restore attempt. In that case I would at least have a list of files not moved successfully and could check whether they are identical with the files they should overwrite in the source location. By the way, I did not disable scanning for local blocks, so if I can find out that all data has been copied locally and not from the remote backup, I may even skip copying the data of the empty directory to the designated source location. Is this approach a good idea to get to a consistent and predictable state?

ts678 · March 12, 2024, 6:26pm

This is tough. There are clues in log-file at verbose level, but who wants to look over it all?

You can certainly sample the About → Show log → Live → Verbose to see what it’s saying.

redusr · March 12, 2024, 10:33pm

I think I’m too late for live logs (restore is finished and only a few messages are displayed: a couple of Testing restored file integrity, followed by the final The operation Restore has completed).
Restoring succeeded and the log in the web interface when expanding the job → Reporting → Show log reports the same number/size of files as reported by Windows Explorer and the database. There are again three warnings of type Creating missing folder which may be due to incorrect order of restoring files vs. folders as pointed out by @kenkendk .
I have run the restore operation using the command line option in the web interface and enabled logging to a file with log-level info but I do not see any piece of information that could help investigating the specific question. The log looks very similar to the summary in the web interface when expanding the job → Reporting → Show log but has some additional backend events logged (List & Get).
The status overview on the command line option view generated messages while scanning for local blocks. First one:

611603 files need to be restored (123,02 GB)

Last one:

 7316 files need to be restored (0 bytes)

Directly below, messages similar to the following one appear:

  Downloading file (99,93 MB) ...

I do not know enough about how Duplicati works to infer from that whether the last scanning message may indicate the number of files to be restored from remote.

Do you think moving the files to the designated source location & overwriting potentially existing files will be a straight-forward way to ensure all restored data is present and consistent with the backup?

ts678 · March 12, 2024, 11:29pm

That’s good to know. Maybe the restore that didn’t need to restore 14 files also went cleanly?

Do you have any urgent need to force things back to a just-restored state? What is the need?

You can certainly attempt folder compares with WinMerge or some other tool to find changes.

Or you can probably force files back from the new area, but I’m not sure what the ideal tool is.
Possibly there’s no need to be subtle about it. Maybe just an overwrite, without any questions.

You can also get this if you checkmark-backup some deep files. Parent folders aren’t included.
This means that if the restore is from high, say at the top, intermediate folders may be created.
You can test this idea either with list/find command where files have sizes, folders end in slash
(symlinks might too), or look in database File table. -100 is a folder. If not there, it gets created.

You did this restore without permissions, unlike the first one (is that right?), so maybe a copy-over existing files would work better than a move. You might also need to get enough privilege to do so.

ACLs frequently just inherit down from above, so Duplicati may have no interesting data to restore.

Although an actual compare program is friendlier, you could try using timestamps to spot changes happened after the restore you worry about. File Explorer can do times. So can Everything search.

Duplicati itself does this to spot new and modified files, then you can decide what to do about them.

The COMPARE command
How I can see what files was added to backup?!

If you run a log-file at verbose level, it will tell you a bit more about why it decided to check out a file.

2024-03-11 07:52:30 -04 - [Verbose-Duplicati.Library.Main.Operation.Backup.FilePreFilterProcess.FileEntry-CheckFileForChanges]: Checking file for changes C:\PortableApps\Notepad++Portable\App\Notepad++64\backup\webpages.txt@2024-03-01_200051, new: False, timestamp changed: True, size changed: True, metadatachanged: True, 3/11/2024 12:54:07 AM vs 3/10/2024 8:51:04 PM

ts678 · March 13, 2024, 2:25pm

Security identifiers might be a problem with this combination.

Well-known SIDs should be the same. Regular users, maybe not. You can check security on some restored files to see if they come up with permissions for SIDs that are unknown on new computer, meaning desired effect may not occur. Sadly, working with NTFS ACLs can get pretty complicated.

How to Find a User’s Security Identifier (SID) in Windows can be helpful, especially if old computer remains operational enough to run a wmic useraccount get name,sid to compare with new list. Possibly some of the old SIDs will show up on files due to the permissions restore. I haven’t tested.

redusr · March 13, 2024, 2:52pm

Thanks for the additional advice and your support in the previous days!

My main aim was to be able to start using the new computer without worrying that parts of the required data are missing. If I started without doing any checks, it would be much harder to narrow down what might have gone wrong with the restore because then I may have a mixture of restored-working, restored-possibly corrupt, restored-later modified files spread all across the device.

Thanks for mentioning WinMerge. This appeared to be a easy-to-use piece of software to see whether there are differences between the result of first/second restore to source location and of the third restore to an empty directory. I ran the comparison with two times with different criteria:

size & modified date
binary comparison.

According to the comparisons, only a single .eml file had a wrong modified date (it was set to restore-time) and a few files were changed (probably because I couldn’t avoid that during use of the new computer). So all in all, results appeared promising and I decided that the reported similarity is promising enough to actually start using the new computer and skip overwriting any of the restored files.

Good prediction! When using git for the first time in a restored folder, it reported a “dubious ownership”. Checking the owner in windows explorer revealed that the owner had been set to the computer’s local administrator group whereas the original folder on the old computer had the active user as owner. Changing the owner solved the problem. Interestingly, some restored folders seems to have the user as (correct) owner, others have the administrator group as (wrong) owner.
I changed the ownership of most of the restored folders - due to the number of folders at hand, I did not check each single one for the original owner on the old computer but I hope it will not lead to bigger issues if the active local user is registered as owner. Please correct me if that was a stupid idea or other actions should be taken!

Regarding the original “issue”, I have learned that the reported number/size of restored files can be misleading for novice users (because the default, non-verbose log does not report if a file has been found and thus did not need to restore it) and that there are valid reasons to consider restoring to a different location and without restoring permissions.

ts678 · March 13, 2024, 3:08pm

I think a lot of them just inherit. Usually there are only a few places that actually change.
Individual C:\Users user subfolders is an obvious spot for this. Others are unpredictable.

I don’t have a recipe for a deep study of the system, but a web search might locate one.
I find icacls a bit weak. If you really get into this, SetACL might be a better tool for study.

I agree about misleading, the clearest case being the alarming warning message I cited.
Typically people are probably not reading the actual number very well, as you had done.