Release: 2.1.0.116 (Canary) 2025-04-17

I think this is the issue in question.

I thought it was a known issue that was being addressed, but if it isn’t I will certainly provide whatever info I can. I will post info the next time it happens.

I have become a rare case to study. :joy:
I don’t think there are any network problems, if i copy files to OneDrive manually i don’t encounter any problems.

Complete error:

2025-05-12 21:20:01 +02 - [Error-Duplicati.Library.Main.Controller-FailedOperation]: L'operazione Backup non è riuscita con l'errore: Detected 1 volume with missing filesets: VolumeId = 1, Name = duplicati-20250508T112228Z.dlist.zip.aes, State = Temporary
DatabaseInconsistencyException: Detected 1 volume with missing filesets: VolumeId = 1, Name = duplicati-20250508T112228Z.dlist.zip.aes, State = Temporary

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,
  "TimestampChangedFiles": 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.1.0.117 (2.1.0.117_canary_2025-04-25)",
  "EndTime": "2025-05-12T19:20:01.0853061Z",
  "BeginTime": "2025-05-12T19:20:00.9350496Z",
  "Duration": "00:00:00.1502565",
  "MessagesActualLength": 1,
  "WarningsActualLength": 0,
  "ErrorsActualLength": 1,
  "Messages": [
    "2025-05-12 21:20:00 +02 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: L'operazione Backup è iniziata"
  ],
  "Warnings": [],
  "Errors": [
    "2025-05-12 21:20:01 +02 - [Error-Duplicati.Library.Main.Controller-FailedOperation]: L'operazione Backup non è riuscita con l'errore: Detected 1 volume with missing filesets: VolumeId = 1, Name = duplicati-20250508T112228Z.dlist.zip.aes, State = Temporary\r\nDatabaseInconsistencyException: Detected 1 volume with missing filesets: VolumeId = 1, Name = duplicati-20250508T112228Z.dlist.zip.aes, State = Temporary"
  ],
  "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,
    "KnownFilesets": 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.1.0.117 (2.1.0.117_canary_2025-04-25)",
    "EndTime": "0001-01-01T00:00:00",
    "BeginTime": "2025-05-12T19:20:00.9350519Z",
    "Duration": "00:00:00",
    "MessagesActualLength": 0,
    "WarningsActualLength": 0,
    "ErrorsActualLength": 0,
    "Messages": null,
    "Warnings": null,
    "Errors": null
  }
}
        

Stack trace? I don’t know where to find it, if you point me to the steps i will post it.

That is the issue that was discovered for 2.1.0.4 and also some canary.

Yes, thanks for bringing it up. This issue would cause “(n) files missing from remote, please run repair”. I believe it is fixed in this canary.

There is a different issue related to timeout, which seems to cause deadlocks on some backends. The underlying cause of this is not yet discovered.

And yet it happens consistently with Duplicati and consistently works fine directly?

This is a different error message than the previous one? The previous one was about re-using a stream, this is about missing fileset for a remote volume.

I think this new message is related to issue 5862.

Was this an effect of the re-use error? It looks like a leftover temporary file is in the database, I just can’t figure out how to get it into that state.

It is in the UI under “About” then “Logs”.

Yes.

Yes after a few tries that error appeared.

Duplicati.Library.Interface.DatabaseInconsistencyException: Detected 1 volume with missing filesets: VolumeId = 1, Name = duplicati-20250508T112228Z.dlist.zip.aes, State = Temporary
   at Duplicati.Library.Main.Database.LocalDatabase.VerifyConsistencyInner(Int64 blocksize, Int64 hashsize, Boolean verifyfilelists, Boolean laxVerifyForRepair, IDbTransaction transaction)
   at Duplicati.Library.Main.Database.LocalDatabase.VerifyConsistency(Int64 blocksize, Int64 hashsize, Boolean verifyfilelists, IDbTransaction transaction)
   at Duplicati.Library.Main.Operation.Backup.BackupDatabase.<>c__DisplayClass35_0.<VerifyConsistencyAsync>b__0()
   at Duplicati.Library.Main.Operation.Common.SingleRunner.DoRunOnMain[T](Func`1 method)
   at Duplicati.Library.Main.Operation.BackupHandler.PreBackupVerify(Options options, BackupResults result, IBackendManager backendManager)
   at Duplicati.Library.Main.Operation.BackupHandler.RunAsync(String[] sources, IBackendManager backendManager, IFilter filter)
   at Duplicati.Library.Main.Controller.<>c__DisplayClass23_0.<<Backup>b__0>d.MoveNext()
--- End of stack trace from previous location ---
   at Duplicati.Library.Utility.Utility.Await(Task task)
   at Duplicati.Library.Main.Controller.RunAction[T](T result, String[]& paths, IFilter& filter, Func`3 method)
   at Duplicati.Library.Main.Controller.Backup(String[] inputsources, IFilter filter)
   at Duplicati.Server.Runner.Run(IRunnerData data, Boolean fromQueue)

b2 backend.

Error: “Found 2 files that are missing from the remote storage, please run repair”

Log:

            {
  "DeletedFiles": 101606,
  "DeletedFolders": 35852,
  "ModifiedFiles": 381,
  "ExaminedFiles": 464076,
  "OpenedFiles": 109751,
  "AddedFiles": 109370,
  "SizeOfModifiedFiles": 1072924426,
  "SizeOfAddedFiles": 6516872478,
  "SizeOfExaminedFiles": 111435817327,
  "SizeOfOpenedFiles": 7632213000,
  "NotProcessedFiles": 0,
  "AddedFolders": 44970,
  "TooLargeFiles": 0,
  "FilesWithError": 0,
  "TimestampChangedFiles": 0,
  "ModifiedFolders": 107,
  "ModifiedSymlinks": 0,
  "AddedSymlinks": 0,
  "DeletedSymlinks": 0,
  "PartialBackup": false,
  "Dryrun": false,
  "MainOperation": "Backup",
  "CompactResults": {
    "DeletedFileCount": 0,
    "DownloadedFileCount": 0,
    "UploadedFileCount": 0,
    "DeletedFileSize": 0,
    "DownloadedFileSize": 0,
    "UploadedFileSize": 0,
    "Dryrun": false,
    "VacuumResults": null,
    "MainOperation": "Compact",
    "ParsedResult": "Success",
    "Interrupted": false,
    "Version": "2.1.0.116 (2.1.0.116_canary_2025-04-17)",
    "EndTime": "2025-05-15T05:21:04.8128614Z",
    "BeginTime": "2025-05-15T05:20:46.7291244Z",
    "Duration": "00:00:18.0837370",
    "MessagesActualLength": 0,
    "WarningsActualLength": 0,
    "ErrorsActualLength": 0,
    "Messages": null,
    "Warnings": null,
    "Errors": null,
    "BackendStatistics": {
      "RemoteCalls": 59,
      "BytesUploaded": 2851894443,
      "BytesDownloaded": 0,
      "FilesUploaded": 55,
      "FilesDownloaded": 0,
      "FilesDeleted": 1,
      "FoldersCreated": 0,
      "RetryAttempts": 1,
      "UnknownFileSize": 0,
      "UnknownFileCount": 0,
      "KnownFileCount": 1901,
      "KnownFileSize": 97692435737,
      "KnownFilesets": 14,
      "LastBackupDate": "2025-05-15T01:00:00-04:00",
      "BackupListCount": 14,
      "TotalQuotaSpace": 0,
      "FreeQuotaSpace": 0,
      "AssignedQuotaSpace": -1,
      "ReportedQuotaError": false,
      "ReportedQuotaWarning": false,
      "MainOperation": "Backup",
      "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-05-15T05:00:00.0058906Z",
      "Duration": "00:00:00",
      "MessagesActualLength": 0,
      "WarningsActualLength": 0,
      "ErrorsActualLength": 0,
      "Messages": null,
      "Warnings": null,
      "Errors": null
    }
  },
  "VacuumResults": null,
  "DeleteResults": {
    "DeletedSetsActualLength": 1,
    "DeletedSets": [
      {
        "Item1": 6,
        "Item2": "2025-05-08T01:00:00-04:00"
      }
    ],
    "Dryrun": false,
    "MainOperation": "Delete",
    "CompactResults": {
      "DeletedFileCount": 0,
      "DownloadedFileCount": 0,
      "UploadedFileCount": 0,
      "DeletedFileSize": 0,
      "DownloadedFileSize": 0,
      "UploadedFileSize": 0,
      "Dryrun": false,
      "VacuumResults": null,
      "MainOperation": "Compact",
      "ParsedResult": "Success",
      "Interrupted": false,
      "Version": "2.1.0.116 (2.1.0.116_canary_2025-04-17)",
      "EndTime": "2025-05-15T05:21:04.8128614Z",
      "BeginTime": "2025-05-15T05:20:46.7291244Z",
      "Duration": "00:00:18.0837370",
      "MessagesActualLength": 0,
      "WarningsActualLength": 0,
      "ErrorsActualLength": 0,
      "Messages": null,
      "Warnings": null,
      "Errors": null,
      "BackendStatistics": {
        "RemoteCalls": 59,
        "BytesUploaded": 2851894443,
        "BytesDownloaded": 0,
        "FilesUploaded": 55,
        "FilesDownloaded": 0,
        "FilesDeleted": 1,
        "FoldersCreated": 0,
        "RetryAttempts": 1,
        "UnknownFileSize": 0,
        "UnknownFileCount": 0,
        "KnownFileCount": 1901,
        "KnownFileSize": 97692435737,
        "KnownFilesets": 14,
        "LastBackupDate": "2025-05-15T01:00:00-04:00",
        "BackupListCount": 14,
        "TotalQuotaSpace": 0,
        "FreeQuotaSpace": 0,
        "AssignedQuotaSpace": -1,
        "ReportedQuotaError": false,
        "ReportedQuotaWarning": false,
        "MainOperation": "Backup",
        "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-05-15T05:00:00.0058906Z",
        "Duration": "00:00:00",
        "MessagesActualLength": 0,
        "WarningsActualLength": 0,
        "ErrorsActualLength": 0,
        "Messages": null,
        "Warnings": null,
        "Errors": null
      }
    },
    "ParsedResult": "Success",
    "Interrupted": false,
    "Version": "2.1.0.116 (2.1.0.116_canary_2025-04-17)",
    "EndTime": "2025-05-15T05:21:04.8128643Z",
    "BeginTime": "2025-05-15T05:20:21.4826352Z",
    "Duration": "00:00:43.3302291",
    "MessagesActualLength": 0,
    "WarningsActualLength": 0,
    "ErrorsActualLength": 0,
    "Messages": null,
    "Warnings": null,
    "Errors": null,
    "BackendStatistics": {
      "RemoteCalls": 59,
      "BytesUploaded": 2851894443,
      "BytesDownloaded": 0,
      "FilesUploaded": 55,
      "FilesDownloaded": 0,
      "FilesDeleted": 1,
      "FoldersCreated": 0,
      "RetryAttempts": 1,
      "UnknownFileSize": 0,
      "UnknownFileCount": 0,
      "KnownFileCount": 1901,
      "KnownFileSize": 97692435737,
      "KnownFilesets": 14,
      "LastBackupDate": "2025-05-15T01:00:00-04:00",
      "BackupListCount": 14,
      "TotalQuotaSpace": 0,
      "FreeQuotaSpace": 0,
      "AssignedQuotaSpace": -1,
      "ReportedQuotaError": false,
      "ReportedQuotaWarning": false,
      "MainOperation": "Backup",
      "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-05-15T05:00:00.0058906Z",
      "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.116 (2.1.0.116_canary_2025-04-17)",
  "EndTime": "2025-05-15T05:21:08.7436779Z",
  "BeginTime": "2025-05-15T05:00:00.0058876Z",
  "Duration": "00:21:08.7377903",
  "MessagesActualLength": 131,
  "WarningsActualLength": 2,
  "ErrorsActualLength": 3,
  "Messages": [
    "2025-05-15 01:00:00 -04 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started",
    "2025-05-15 01:01:06 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started:  ()",
    "2025-05-15 01:01:08 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed:  (1.81 KiB)",
    "2025-05-15 01:02:00 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-bfb225138800e43019b1bf195876e5400.dblock.zip.aes (100.17 MiB)",
    "2025-05-15 01:02:01 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-b6e0bcd4bc8a04a60ad102cfdee391267.dblock.zip.aes (100.20 MiB)",
    "2025-05-15 01:02:26 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-bfb225138800e43019b1bf195876e5400.dblock.zip.aes (100.17 MiB)",
    "2025-05-15 01:02:26 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-i81e5844175f0484e803c7153cb2d3aba.dindex.zip.aes (219.92 KiB)",
    "2025-05-15 01:02:26 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-i81e5844175f0484e803c7153cb2d3aba.dindex.zip.aes (219.92 KiB)",
    "2025-05-15 01:02:56 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-b6e0bcd4bc8a04a60ad102cfdee391267.dblock.zip.aes (100.20 MiB)",
    "2025-05-15 01:02:56 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-i1959a4dcd375446282ce466c7f6780c6.dindex.zip.aes (227.26 KiB)",
    "2025-05-15 01:02:56 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-i1959a4dcd375446282ce466c7f6780c6.dindex.zip.aes (227.26 KiB)",
    "2025-05-15 01:03:47 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-bbe573c6b17fd48b58c3d4df576712b03.dblock.zip.aes (100.42 MiB)",
    "2025-05-15 01:03:50 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-ba300070011ff4bfea87b53fc0bfbd4ef.dblock.zip.aes (100.39 MiB)",
    "2025-05-15 01:04:13 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-bbe573c6b17fd48b58c3d4df576712b03.dblock.zip.aes (100.42 MiB)",
    "2025-05-15 01:04:13 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-i9156e7d15ff9412c834d48a6732d89f0.dindex.zip.aes (319.72 KiB)",
    "2025-05-15 01:04:13 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-i9156e7d15ff9412c834d48a6732d89f0.dindex.zip.aes (319.72 KiB)",
    "2025-05-15 01:04:34 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-b30fd7a43f1774422aa7dc7e93fff1e8f.dblock.zip.aes (100.24 MiB)",
    "2025-05-15 01:04:36 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-b740e371f1f284bd586c1ac3563bbb4b7.dblock.zip.aes (100.17 MiB)",
    "2025-05-15 01:04:42 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-ba300070011ff4bfea87b53fc0bfbd4ef.dblock.zip.aes (100.39 MiB)",
    "2025-05-15 01:04:42 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-i09251c0c4ad34109bfffbcac50261650.dindex.zip.aes (330.61 KiB)"
  ],
  "Warnings": [
    "2025-05-15 01:21:08 -04 - [Warning-Duplicati.Library.Main.Operation.FilelistProcessor-MissingFile]: Missing file: duplicati-ib6385d7775cd46c7ae78a83db6ed9dd5.dindex.zip.aes",
    "2025-05-15 01:21:08 -04 - [Warning-Duplicati.Library.Main.Operation.FilelistProcessor-MissingFile]: Missing file: duplicati-i3062d432c5be4ed182f06a69a3c8d922.dindex.zip.aes"
  ],
  "Errors": [
    "2025-05-15 01:21:08 -04 - [Error-Duplicati.Library.Main.Operation.FilelistProcessor-MissingRemoteFiles]: Found 2 files that are missing from the remote storage, please run repair",
    "2025-05-15 01:21:08 -04 - [Error-Duplicati.Library.Main.Operation.BackupHandler-FatalError]: Fatal error\r\nRemoteListVerificationException: Found 2 files that are missing from the remote storage, please run repair",
    "2025-05-15 01:21:08 -04 - [Error-Duplicati.Library.Main.Controller-FailedOperation]: The operation Backup has failed with error: Found 2 files that are missing from the remote storage, please run repair\r\nRemoteListVerificationException: Found 2 files that are missing from the remote storage, please run repair"
  ],
  "BackendStatistics": {
    "RemoteCalls": 59,
    "BytesUploaded": 2851894443,
    "BytesDownloaded": 0,
    "FilesUploaded": 55,
    "FilesDownloaded": 0,
    "FilesDeleted": 1,
    "FoldersCreated": 0,
    "RetryAttempts": 1,
    "UnknownFileSize": 0,
    "UnknownFileCount": 0,
    "KnownFileCount": 1901,
    "KnownFileSize": 97692435737,
    "KnownFilesets": 14,
    "LastBackupDate": "2025-05-15T01:00:00-04:00",
    "BackupListCount": 14,
    "TotalQuotaSpace": 0,
    "FreeQuotaSpace": 0,
    "AssignedQuotaSpace": -1,
    "ReportedQuotaError": false,
    "ReportedQuotaWarning": false,
    "MainOperation": "Backup",
    "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-05-15T05:00:00.0058906Z",
    "Duration": "00:00:00",
    "MessagesActualLength": 0,
    "WarningsActualLength": 0,
    "ErrorsActualLength": 0,
    "Messages": null,
    "Warnings": null,
    "Errors": null
  }
}
        

Bug report is in-progress.

EDIT 1:
Bug report sent.

Live log (verbose) of the “repair”:

May 15, 2025 9:13 AM: The operation Repair has completed
May 15, 2025 9:13 AM: Backend event: Put - Completed: duplicati-i3062d432c5be4ed182f06a69a3c8d922.dindex.zip.aes (125.04 KiB)
May 15, 2025 9:13 AM: Backend event: Put - Completed: duplicati-ib6385d7775cd46c7ae78a83db6ed9dd5.dindex.zip.aes (215.81 KiB)
May 15, 2025 9:13 AM: Backend event: Put - Started: duplicati-i3062d432c5be4ed182f06a69a3c8d922.dindex.zip.aes (125.04 KiB)
May 15, 2025 9:13 AM: The empty index file duplicati-i79b301bb286a420c8b8e8e2ffadac383.dindex.zip.aes is larger than expected (266173 bytes), choosing not to delete it
May 15, 2025 9:13 AM: The empty index file duplicati-i28eac7ffff514014a056dd1e9428ebf8.dindex.zip.aes is larger than expected (142797 bytes), choosing not to delete it
May 15, 2025 9:13 AM: The empty index file duplicati-ia3b476a969fb4fa99798b573c76feb04.dindex.zip.aes is larger than expected (338045 bytes), choosing not to delete it
May 15, 2025 9:13 AM: Backend event: Put - Started: duplicati-ib6385d7775cd46c7ae78a83db6ed9dd5.dindex.zip.aes (215.81 KiB)
May 15, 2025 9:13 AM: Removing file listed as Deleting: duplicati-b31ad6d26b7d149358f2cfce22498b46d.dblock.zip.aes
May 15, 2025 9:13 AM: Backend event: List - Completed: (1.86 KiB)
May 15, 2025 9:13 AM: Backend event: List - Started: ()
May 15, 2025 9:12 AM: The operation Repair has started 

Thanks! I have fixed that exact error now based on the details.

Thanks!

1 Like