Error: Unexpected difference in fileset

gdassieu · April 19, 2025, 1:44pm

Hi Everyone,

I’m using duplicati on a ~136GB dataset on an automatic daily backup schedule with 7D:1D,4W:1W,12M:1M,100Y:1Y retention (I have ~18 versions dating as back as 2022).

I’m currently using v2.0.8.1_beta_2024-05-07 (having upgraded several months ago).

Suddenly, yesterday, my backups started failing with error “Unexpected difference in fileset”.

I find several people reporting same error in the forum, but it’s for different versions and not clear “one size fits all” solution.

I’d obviously like to fix the problem but also take the opportunity to contribute to finding the root cause (and therefore preventing or automatically mitigating such a problem in future versions).

I’ll be happy to follow instructions and share data that may contribute to this.

Could you kindly advice?

For information, I’m a software engineer with software development as well as several years of IT infrastructure management experience, and also curious about duplicati’s internal workings, so do not hesitate to speak very technical.

Thanks,

Gaston

Please find below the detailed error message:

2025-04-19 22:26:12 +09 - [Error-Duplicati.Library.Main.Operation.BackupHandler-FatalError]: Fatal error
UserInformationException: Unexpected difference in fileset version 6: 2025-01-08 13:37:30 (database id: 61), found 168203 entries, but expected 168207

Unexpected difference in fileset version 3: 2025-03-22 13:54:17 (database id: 99), found 170259 entries, but expected 170263

Unexpected difference in fileset version 2: 2025-03-30 13:42:19 (database id: 103), found 170260 entries, but expected 170264

Unexpected difference in fileset version 1: 2025-04-13 13:11:13 (database id: 106), found 170258 entries, but expected 170262

And the complete log

            {
  "DeletedFiles": 0,
  "DeletedFolders": 0,
  "ModifiedFiles": 0,
  "ExaminedFiles": 0,
  "OpenedFiles": 0,
  "AddedFiles": 0,
  "SizeOfModifiedFiles": 0,
  "SizeOfAddedFiles": 0,
  "SizeOfExaminedFiles": 0,
  "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": null,
  "RepairResults": null,
  "TestResults": null,
  "ParsedResult": "Fatal",
  "Interrupted": false,
  "Version": "2.0.8.1 (2.0.8.1_beta_2024-05-07)",
  "EndTime": "2025-04-19T13:26:12.5973108Z",
  "BeginTime": "2025-04-19T13:25:38.855818Z",
  "Duration": "00:00:33.7414928",
  "MessagesActualLength": 1,
  "WarningsActualLength": 0,
  "ErrorsActualLength": 2,
  "Messages": [
    "2025-04-19 22:25:38 +09 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started"
  ],
  "Warnings": [],
  "Errors": [
    "2025-04-19 22:26:12 +09 - [Error-Duplicati.Library.Main.Operation.BackupHandler-FatalError]: Fatal error\r\nUserInformationException: Unexpected difference in fileset version 6: 2025-01-08 13:37:30 (database id: 61), found 168203 entries, but expected 168207\n\rUnexpected difference in fileset version 3: 2025-03-22 13:54:17 (database id: 99), found 170259 entries, but expected 170263\n\rUnexpected difference in fileset version 2: 2025-03-30 13:42:19 (database id: 103), found 170260 entries, but expected 170264\n\rUnexpected difference in fileset version 1: 2025-04-13 13:11:13 (database id: 106), found 170258 entries, but expected 170262",
    "2025-04-19 22:26:12 +09 - [Error-Duplicati.Library.Main.Controller-FailedOperation]: The operation Backup has failed with error: Unexpected difference in fileset version 6: 2025-01-08 13:37:30 (database id: 61), found 168203 entries, but expected 168207\n\rUnexpected difference in fileset version 3: 2025-03-22 13:54:17 (database id: 99), found 170259 entries, but expected 170263\n\rUnexpected difference in fileset version 2: 2025-03-30 13:42:19 (database id: 103), found 170260 entries, but expected 170264\n\rUnexpected difference in fileset version 1: 2025-04-13 13:11:13 (database id: 106), found 170258 entries, but expected 170262\r\nUserInformationException: Unexpected difference in fileset version 6: 2025-01-08 13:37:30 (database id: 61), found 168203 entries, but expected 168207\n\rUnexpected difference in fileset version 3: 2025-03-22 13:54:17 (database id: 99), found 170259 entries, but expected 170263\n\rUnexpected difference in fileset version 2: 2025-03-30 13:42:19 (database id: 103), found 170260 entries, but expected 170264\n\rUnexpected difference in fileset version 1: 2025-04-13 13:11:13 (database id: 106), found 170258 entries, but expected 170262"
  ],
  "BackendStatistics": {
    "RemoteCalls": 0,
    "BytesUploaded": 0,
    "BytesDownloaded": 0,
    "FilesUploaded": 0,
    "FilesDownloaded": 0,
    "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": "Backup",
    "ParsedResult": "Success",
    "Interrupted": false,
    "Version": "2.0.8.1 (2.0.8.1_beta_2024-05-07)",
    "EndTime": "0001-01-01T00:00:00",
    "BeginTime": "2025-04-19T13:25:38.855818Z",
    "Duration": "00:00:00",
    "MessagesActualLength": 0,
    "WarningsActualLength": 0,
    "ErrorsActualLength": 0,
    "Messages": null,
    "Warnings": null,
    "Errors": null
  }
}

kenkendk · April 23, 2025, 7:52pm

This has been a problem for a long time, but we have now added safeguards and a repair function.
The safeguards checks for the problem at strategic times, so we can hone in on when it possibly happens. The repair function can clean up the database so it is working again.

These fixes are available in canary 2.1.0.116.

The easy way is to install the canary build, and use the repair method there.
However, since you are on 2.0.8.1, this requires a database upgrade (from 2.1.0.5 stable and forward). The database upgrade is automatic, but downgrade is a manual process.

If you prefer not to do that, then one solution is to use the commandline (either actual commandline, or the commandline emulator from the UI) and delete the defect versions.

Another could be to attempt to recreate the database.

Let me know if you need advice on one of the suggested ways.

gdassieu · April 25, 2025, 2:07pm

Hi Kenkendk,

Thanks! In fact, I was looking for an excuse to upgrade, so this just gave me one

Let me try that and tell you how it went!

gdassieu · April 25, 2025, 2:45pm

Hi Kenkendk,

I upgraded 2.1.0.116_canary_2025-04-17, then ran the repair from the GUI (just click repair button).

It failed with the error seen at the bottom.

It seems to be complaining, if I understand correctly, that for certain user profile data files (e.g. ntuser.dat) their size is not matching what’s on the database.

For information, I run Duplicati as a scheduled task with “highest privileges” option, so that the backup job is able to grab, using Volume Shadow Copy, also files that are locked. Maybe this is somehow related to the error? (ntuser.dat is a locked file for sure…).

Sorry to ask many times! Shall I try to recreate the database?

Thanks !

Gaston

 {
  "MainOperation": "Repair",
  "RecreateDatabaseResults": null,
  "ParsedResult": "Fatal",
  "Interrupted": false,
  "Version": "2.1.0.116 (2.1.0.116_canary_2025-04-17)",
  "EndTime": "2025-04-25T14:24:14.6531732Z",
  "BeginTime": "2025-04-25T14:21:45.0108098Z",
  "Duration": "00:02:29.6423634",
  "MessagesActualLength": 14,
  "WarningsActualLength": 1,
  "ErrorsActualLength": 1,
  "Messages": [
    "2025-04-25 23:21:45 +09 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Repair has started",
    "2025-04-25 23:21:45 +09 - [Information-Duplicati.Library.Main.Operation.RepairHandler-RepairingBrokenFilesets]: Repairing 4 broken filesets",
    "2025-04-25 23:21:45 +09 - [Information-Duplicati.Library.Main.Operation.RepairHandler-RepairingBrokenFileset]: Repairing broken fileset 1 of 4: 2025-01-08 13:37:30",
    "2025-04-25 23:21:45 +09 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-20250108T043730Z.dlist.zip.aes (11.52 MiB)",
    "2025-04-25 23:22:34 +09 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-20250108T043730Z.dlist.zip.aes (11.52 MiB)",
    "2025-04-25 23:22:56 +09 - [Information-Duplicati.Library.Main.Operation.RepairHandler-RepairingBrokenFileset]: Repairing broken fileset 2 of 4: 2025-03-22 13:54:17",
    "2025-04-25 23:22:56 +09 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-20250322T045417Z.dlist.zip.aes (11.69 MiB)",
    "2025-04-25 23:23:01 +09 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-20250322T045417Z.dlist.zip.aes (11.69 MiB)",
    "2025-04-25 23:23:22 +09 - [Information-Duplicati.Library.Main.Operation.RepairHandler-RepairingBrokenFileset]: Repairing broken fileset 3 of 4: 2025-03-30 13:42:19",
    "2025-04-25 23:23:22 +09 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-20250330T044219Z.dlist.zip.aes (11.69 MiB)",
    "2025-04-25 23:23:27 +09 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-20250330T044219Z.dlist.zip.aes (11.69 MiB)",
    "2025-04-25 23:23:48 +09 - [Information-Duplicati.Library.Main.Operation.RepairHandler-RepairingBrokenFileset]: Repairing broken fileset 4 of 4: 2025-04-13 13:11:13",
    "2025-04-25 23:23:48 +09 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-20250413T041113Z.dlist.zip.aes (11.69 MiB)",
    "2025-04-25 23:23:54 +09 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-20250413T041113Z.dlist.zip.aes (11.69 MiB)"
  ],
  "Warnings": [
    "2025-04-25 23:24:14 +09 - [Warning-Duplicati.Library.Main.Backend.DatabaseCollector-FlushingMessagesToLog]: Operation: get File: duplicati-20250108T043730Z.dlist.zip.aes Result: {\"Size\":12078541,\"Hash\":\"cuPmrlrM55kYgAkFksqgMzqtou471DgBLA1tEbo/WVc=\"}\nOperation: get File: duplicati-20250322T045417Z.dlist.zip.aes Result: {\"Size\":12256589,\"Hash\":\"21Gul5B/ckMl04ChhK7xVs2LFhGPGunPiNiJsGJ9ViA=\"}\nOperation: get File: duplicati-20250330T044219Z.dlist.zip.aes Result: {\"Size\":12257021,\"Hash\":\"myCrEPyQU5uXJ\\u002By3NtSmSs5GXmpVyJeQFkgOuUCsm7k=\"}\nOperation: get File: duplicati-20250413T041113Z.dlist.zip.aes Result: {\"Size\":12255069,\"Hash\":\"aVYn21GLJ3zqziFu0ULZqWrcSAisD93Oy8L2/uFlSLY=\"}"
  ],
  "Errors": [
    "2025-04-25 23:24:14 +09 - [Error-Duplicati.Library.Main.Controller-FailedOperation]: The operation Repair has failed with error: Found inconsistency in the following files while validating database: \r\nC:\\Users\\Gaston\\AppData\\Local\\Microsoft\\Windows\\usrClass.dat.LOG1, actual size 1048576, dbsize 0, blocksetid: 524979\r\nC:\\Users\\Gaston\\AppData\\Local\\Microsoft\\Windows\\usrClass.dat.LOG2, actual size 655360, dbsize 0, blocksetid: 524980\r\nC:\\Users\\Gaston\\ntuser.dat.LOG1, actual size 989184, dbsize 0, blocksetid: 524981\r\nC:\\Users\\Gaston\\ntuser.dat.LOG2, actual size 655360, dbsize 0, blocksetid: 524982\r\nC:\\Users\\Gaston\\AppData\\Local\\Microsoft\\Windows\\usrClass.dat.LOG1, actual size 665600, dbsize 0, blocksetid: 524983\r\n... and 6 more. Run repair to fix it.\r\nDatabaseInconsistencyException: Found inconsistency in the following files while validating database: \r\nC:\\Users\\Gaston\\AppData\\Local\\Microsoft\\Windows\\usrClass.dat.LOG1, actual size 1048576, dbsize 0, blocksetid: 524979\r\nC:\\Users\\Gaston\\AppData\\Local\\Microsoft\\Windows\\usrClass.dat.LOG2, actual size 655360, dbsize 0, blocksetid: 524980\r\nC:\\Users\\Gaston\\ntuser.dat.LOG1, actual size 989184, dbsize 0, blocksetid: 524981\r\nC:\\Users\\Gaston\\ntuser.dat.LOG2, actual size 655360, dbsize 0, blocksetid: 524982\r\nC:\\Users\\Gaston\\AppData\\Local\\Microsoft\\Windows\\usrClass.dat.LOG1, actual size 665600, dbsize 0, blocksetid: 524983\r\n... and 6 more. Run repair to fix it."
  ],
  "BackendStatistics": {
    "RemoteCalls": 4,
    "BytesUploaded": 0,
    "BytesDownloaded": 48847220,
    "FilesUploaded": 0,
    "FilesDownloaded": 4,
    "FilesDeleted": 0,
    "FoldersCreated": 0,
    "RetryAttempts": 0,
    "UnknownFileSize": 0,
    "UnknownFileCount": 0,
    "KnownFileCount": 0,
    "KnownFileSize": 0,
    "KnownFilesets": 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.116 (2.1.0.116_canary_2025-04-17)",
    "EndTime": "0001-01-01T00:00:00",
    "BeginTime": "2025-04-25T14:21:45.011012Z",
    "Duration": "00:00:00",
    "MessagesActualLength": 0,
    "WarningsActualLength": 0,
    "ErrorsActualLength": 0,
    "Messages": null,
    "Warnings": null,
    "Errors": null
  }
}

kenkendk · April 30, 2025, 6:42pm

I think this was a problem in earlier versions of Duplicati, where it could cause issues if the file was being written to during the backup.

This error message means that the database is in an inconsistent state. It looks like the file has no data in the database, but the length of the file is larger than zero.
I would think the repair command could fix this?

If not, can you create a bugreport database, upload it somewhere (Dropbox, wetransfer, etc) and send me a link in a PM?

No worries, here to help

If repair does not work, the recreate is usually a fix, but I would prefer if that was not required.
If you can create the bugreport before you recreate, it would be much appreciated.

gdassieu · May 2, 2025, 12:50am

Thanks Kenneth,

Indeed, repair did not work. I just PM’d you the bugreport.

I will keep the database as-is (I will not recreate it) in case you wish to try something on it to isolate the bug.

(I have a 2nd backup to external disk; it’s a manual process vs my other daily backup to Google Drive, but a tolerable amount of risk in order to help get to the bottom of this).

Thanks in advance,

Gaston

kenkendk · May 9, 2025, 12:09pm

Thanks! I have the bugreport secured, and will track it down soon.

You do not need to wait, with the recreate as the bugreport database contains all the hints that could potentially be available. But in case, you can make a copy of the database before you run recreate (see the “Database …” menu for the path).

gdassieu · May 14, 2025, 12:50am

Thanks Kenneth,

Hectic week at work, I’ll do that next weekend and keep you posted.

Best,

Gaston

gdassieu · May 18, 2025, 2:56am

Hi Kenneth,

Just to let you know that I was able to successfully recreate the database and my backups are now running again.

Thanks for that!

I hope the debug trace I shared helps to get to the bottom of this. If you need me to do some additional tests or provide additional data do not hesitate to let me know.

Best regards,

Gaston