Remote missing files but list-broken-files returns 0

Support
1

Hello,

Backups were failing (I think with missing remote files errors) so I recreated local database to try fix. I now get four missing files errors:

2022-10-30 01:26:25 +02 - [Error-Duplicati.Library.Main.Operation.RecreateDatabaseHandler-MissingFileDetected]: Remote file referenced as duplicati-bc03848b1c9fb4ebd8fc717a2add2111d.dblock.zip.aes by duplicati-i40877ac5bf71420f9fe79e67e8d92ac5.dindex.zip.aes, but not found in list, registering a missing remote file
2022-10-30 01:31:36 +02 - [Error-Duplicati.Library.Main.Operation.RecreateDatabaseHandler-MissingFileDetected]: Remote file referenced as duplicati-bfa587c1587af42ff898ba8f74a83747c.dblock.zip.aes by duplicati-i9825b3711ee0410184ddff852b3bdb9b.dindex.zip.aes, but not found in list, registering a missing remote file
2022-10-30 01:34:56 +02 - [Error-Duplicati.Library.Main.Operation.RecreateDatabaseHandler-MissingFileDetected]: Remote file referenced as duplicati-b7c1b10c39c9543a5a7514e5c5058a91f.dblock.zip.aes by duplicati-id8c5ea8057c14a79917183b9839523f6.dindex.zip.aes, but not found in list, registering a missing remote file
2022-10-30 01:35:46 +02 - [Error-Duplicati.Library.Main.Operation.RecreateDatabaseHandler-MissingFileDetected]: Remote file referenced as duplicati-bee48a75e630d49a0805ba646b4182c42.dblock.zip.aes by duplicati-ie664ec6b022544e1835b8cf9bec72e47.dindex.zip.aes, but not found in list, registering a missing remote file

Iā€™m now trying to purge broken files as per Disaster Recovery - Duplicati 2 User's Manual but the list-broken-files command returns 0.

Any advice much appreciated!

Here are list-broken-files options:

--backup-name=wakabk
--dbpath=/Users/markhashimoto/.config/Duplicati/TIKSYXKPWG.sqlite
--passphrase=XXX
--full-result=true

Here is full log of database recreation:

{
  "MainOperation": "Repair",
  "RecreateDatabaseResults": {
    "MainOperation": "Repair",
    "ParsedResult": "Success",
    "Version": "2.0.6.3 (2.0.6.3_beta_2021-06-17)",
    "EndTime": "2022-10-29T23:43:05.711122Z",
    "BeginTime": "2022-10-29T23:08:14.69798Z",
    "Duration": "00:34:51.0131420",
    "MessagesActualLength": 0,
    "WarningsActualLength": 0,
    "ErrorsActualLength": 0,
    "Messages": null,
    "Warnings": null,
    "Errors": null,
    "BackendStatistics": {
      "RemoteCalls": 1263,
      "BytesUploaded": 0,
      "BytesDownloaded": 870701977,
      "FilesUploaded": 0,
      "FilesDownloaded": 1261,
      "FilesDeleted": 0,
      "FoldersCreated": 0,
      "RetryAttempts": 1,
      "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",
      "Version": "2.0.6.3 (2.0.6.3_beta_2021-06-17)",
      "EndTime": "0001-01-01T00:00:00",
      "BeginTime": "2022-10-29T23:08:14.645282Z",
      "Duration": "00:00:00",
      "MessagesActualLength": 0,
      "WarningsActualLength": 0,
      "ErrorsActualLength": 0,
      "Messages": null,
      "Warnings": null,
      "Errors": null
    }
  },
  "ParsedResult": "Error",
  "Version": "2.0.6.3 (2.0.6.3_beta_2021-06-17)",
  "EndTime": "2022-10-29T23:43:05.924388Z",
  "BeginTime": "2022-10-29T23:08:14.645263Z",
  "Duration": "00:34:51.2791250",
  "MessagesActualLength": 2532,
  "WarningsActualLength": 2,
  "ErrorsActualLength": 4,
  "Messages": [
    "2022-10-30 01:08:14 +02 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Repair has started",
    "2022-10-30 01:08:14 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started:  ()",
    "2022-10-30 01:08:18 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed:  (2.39 KB)",
    "2022-10-30 01:08:21 +02 - [Information-Duplicati.Library.Main.Operation.RecreateDatabaseHandler-RebuildStarted]: Rebuild database started, downloading 44 filelists",
    "2022-10-30 01:08:21 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-20191104T162530Z.dlist.zip.aes (2.80 MB)",
    "2022-10-30 01:08:25 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-20191104T162530Z.dlist.zip.aes (2.80 MB)",
    "2022-10-30 01:08:25 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-20191207T155116Z.dlist.zip.aes (2.80 MB)",
    "2022-10-30 01:08:27 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-20191207T155116Z.dlist.zip.aes (2.80 MB)",
    "2022-10-30 01:08:33 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-20200114T035116Z.dlist.zip.aes (2.80 MB)",
    "2022-10-30 01:08:37 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-20200114T035116Z.dlist.zip.aes (2.80 MB)",
    "2022-10-30 01:08:39 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-20200222T215116Z.dlist.zip.aes (2.82 MB)",
    "2022-10-30 01:08:40 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-20200222T215116Z.dlist.zip.aes (2.82 MB)",
    "2022-10-30 01:08:45 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-20200325T155116Z.dlist.zip.aes (2.83 MB)",
    "2022-10-30 01:09:03 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Retrying: duplicati-20200325T155116Z.dlist.zip.aes (2.83 MB)",
    "2022-10-30 01:09:13 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-20200325T155116Z.dlist.zip.aes (2.83 MB)",
    "2022-10-30 01:09:20 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-20200325T155116Z.dlist.zip.aes (2.83 MB)",
    "2022-10-30 01:09:20 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-20200429T221638Z.dlist.zip.aes (1.44 MB)",
    "2022-10-30 01:09:22 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-20200429T221638Z.dlist.zip.aes (1.44 MB)",
    "2022-10-30 01:09:25 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-20200606T094441Z.dlist.zip.aes (695.76 KB)",
    "2022-10-30 01:09:26 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-20200606T094441Z.dlist.zip.aes (695.76 KB)"
  ],
  "Warnings": [
    "2022-10-30 01:37:32 +02 - [Warning-Duplicati.Library.Main.Database.LocalRecreateDatabase-MissingVolumesDetected]: Found 4 missing volumes; attempting to replace blocks from existing volumes",
    "2022-10-30 01:42:12 +02 - [Warning-Duplicati.Library.Main.Database.LocalRecreateDatabase-MissingVolumesDetected]: Found 4 missing volumes; attempting to replace blocks from existing volumes"
  ],
  "Errors": [
    "2022-10-30 01:26:25 +02 - [Error-Duplicati.Library.Main.Operation.RecreateDatabaseHandler-MissingFileDetected]: Remote file referenced as duplicati-bc03848b1c9fb4ebd8fc717a2add2111d.dblock.zip.aes by duplicati-i40877ac5bf71420f9fe79e67e8d92ac5.dindex.zip.aes, but not found in list, registering a missing remote file",
    "2022-10-30 01:31:36 +02 - [Error-Duplicati.Library.Main.Operation.RecreateDatabaseHandler-MissingFileDetected]: Remote file referenced as duplicati-bfa587c1587af42ff898ba8f74a83747c.dblock.zip.aes by duplicati-i9825b3711ee0410184ddff852b3bdb9b.dindex.zip.aes, but not found in list, registering a missing remote file",
    "2022-10-30 01:34:56 +02 - [Error-Duplicati.Library.Main.Operation.RecreateDatabaseHandler-MissingFileDetected]: Remote file referenced as duplicati-b7c1b10c39c9543a5a7514e5c5058a91f.dblock.zip.aes by duplicati-id8c5ea8057c14a79917183b9839523f6.dindex.zip.aes, but not found in list, registering a missing remote file",
    "2022-10-30 01:35:46 +02 - [Error-Duplicati.Library.Main.Operation.RecreateDatabaseHandler-MissingFileDetected]: Remote file referenced as duplicati-bee48a75e630d49a0805ba646b4182c42.dblock.zip.aes by duplicati-ie664ec6b022544e1835b8cf9bec72e47.dindex.zip.aes, but not found in list, registering a missing remote file"
  ],
  "BackendStatistics": {
    "RemoteCalls": 1263,
    "BytesUploaded": 0,
    "BytesDownloaded": 870701977,
    "FilesUploaded": 0,
    "FilesDownloaded": 1261,
    "FilesDeleted": 0,
    "FoldersCreated": 0,
    "RetryAttempts": 1,
    "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",
    "Version": "2.0.6.3 (2.0.6.3_beta_2021-06-17)",
    "EndTime": "0001-01-01T00:00:00",
    "BeginTime": "2022-10-29T23:08:14.645282Z",
    "Duration": "00:00:00",
    "MessagesActualLength": 0,
    "WarningsActualLength": 0,
    "ErrorsActualLength": 0,
    "Messages": null,
    "Warnings": null,
    "Errors": null
  }
}
2

Welcome to the forum @mhas

In my testing, it seems to be looking at dblock files, so thereā€™s a suggestion that the dindex are extras.
Partially Solved - Missing volumes; attempting to replace blocks from existing volumes has some ideas.
If you want to go deep technically, great. If you want to point to a DB bug report, someone else can help.

EDIT:

On the other hand, such errors may indicate a real problem. Showing the errors would have helped, but
sometimes theyā€™re hard to find. Keeping a copy of the old database would also have helped. Few do so.

EDIT 2:

Sometimes errors are in About ā†’ Show log ā†’ Stored. About ā†’ Show log ā†’ Live ā†’ Warning helps too.
The per-job logs are in the job database which might be gone, but you can see if you have the older logs.
Looking in the database folder is also good. I think thereā€™s at least one case which saves a backup copy.

3

Thanks for the tips @ts678.

I ran affected on the four missing remote files. I got back:

No files are affected

The following related log messages were found:
10/29/2022 11:43:05 PM: {"MainOperation":"Repair","RecreateDatabaseResults":{"MainOperation":"Repair","ParsedResult":"Su ...

Also:

markhashimoto@vaka āžœ  ls -alh ~/.config/Duplicati
total 1.3G
drwxr-xr-x 13 markhashimoto staff  416 Oct 31 21:34  ./
drwxr-xr-x  5 markhashimoto staff  160 Jul 22  2021  ../
-rw-r--r--  1 markhashimoto staff 720K Oct 31 20:53  Duplicati-server.sqlite
-rw-r--r--  1 markhashimoto staff 356K Jul 22  2021  JRKSCELQPR.sqlite
-rw-r--r--  1 markhashimoto staff 120K Jul 22  2021  QMCGUSFFWJ.sqlite
-rw-r--r--  1 markhashimoto staff 196M Jul 22  2021  TIKSYXKPWG.backup
-rw-------  1 markhashimoto staff 759M Oct 31 21:34  TIKSYXKPWG.sqlite
-rw-------  1 markhashimoto staff 120K Jul 22  2021 'backup 20200404010153.sqlite'
-rw-------  1 markhashimoto staff 162M Jul 22  2021 'backup TIKSYXKPWG 20200422102101.sqlite'
-rw-------  1 markhashimoto staff 207M Jul 22  2021 'backup TIKSYXKPWG 20210528104834.sqlite'
drwxr-xr-x  3 markhashimoto staff   96 Oct 30 12:11  control_dir_v2/
-rw-r--r--  1 markhashimoto staff  266 Oct 31 20:58  dbconfig.json
drwxr-xr-x  5 markhashimoto staff  160 Oct 31 21:34  updates/

I scrolled through About ā†’ Show log ā†’ Stored. Here is the backup log just before I noticed a problem on 14 Oct.

Mono.Data.Sqlite.SqliteException (0x80004005): Abort due to constraint violation
UNIQUE constraint failed: Remotevolume.Name, Remotevolume.State
  at Mono.Data.Sqlite.SQLite3.Reset (Mono.Data.Sqlite.SqliteStatement stmt) [0x00084] in <998bafd5334b47318e2be06618c04c59>:0 
  at Mono.Data.Sqlite.SQLite3.Step (Mono.Data.Sqlite.SqliteStatement stmt) [0x0003d] in <998bafd5334b47318e2be06618c04c59>:0 
  at Mono.Data.Sqlite.SqliteDataReader.NextResult () [0x00104] in <998bafd5334b47318e2be06618c04c59>:0 
  at Mono.Data.Sqlite.SqliteDataReader..ctor (Mono.Data.Sqlite.SqliteCommand cmd, System.Data.CommandBehavior behave) [0x0004e] in <998bafd5334b47318e2be06618c04c59>:0 
  at (wrapper remoting-invoke-with-check) Mono.Data.Sqlite.SqliteDataReader..ctor(Mono.Data.Sqlite.SqliteCommand,System.Data.CommandBehavior)
  at Mono.Data.Sqlite.SqliteCommand.ExecuteReader (System.Data.CommandBehavior behavior) [0x00006] in <998bafd5334b47318e2be06618c04c59>:0 
  at Mono.Data.Sqlite.SqliteCommand.ExecuteNonQuery () [0x00000] in <998bafd5334b47318e2be06618c04c59>:0 
  at Duplicati.Library.Main.Database.LocalDatabase.UpdateRemoteVolume (System.String name, Duplicati.Library.Main.RemoteVolumeState state, System.Int64 size, System.String hash, System.Boolean suppressCleanup, System.TimeSpan deleteGraceTime, System.Data.IDbTransaction transaction) [0x00060] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Operation.FilelistProcessor.RemoteListAnalysis (Duplicati.Library.Main.BackendManager backend, Duplicati.Library.Main.Options options, Duplicati.Library.Main.Database.LocalDatabase database, Duplicati.Library.Main.IBackendWriter log, System.Collections.Generic.IEnumerable`1[T] protectedFiles) [0x0085d] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Operation.FilelistProcessor.VerifyRemoteList (Duplicati.Library.Main.BackendManager backend, Duplicati.Library.Main.Options options, Duplicati.Library.Main.Database.LocalDatabase database, Duplicati.Library.Main.IBackendWriter log, System.Collections.Generic.IEnumerable`1[T] protectedFiles) [0x00000] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Operation.BackupHandler.PreBackupVerify (Duplicati.Library.Main.BackendManager backend, System.String protectedfile) [0x0011d] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Operation.BackupHandler.RunAsync (System.String[] sources, Duplicati.Library.Utility.IFilter filter, System.Threading.CancellationToken token) [0x01048] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at CoCoL.ChannelExtensions.WaitForTaskOrThrow (System.Threading.Tasks.Task task) [0x00050] in <9a758ff4db6c48d6b3d4d0e5c2adf6d1>:0 
  at Duplicati.Library.Main.Operation.BackupHandler.Run (System.String[] sources, Duplicati.Library.Utility.IFilter filter, System.Threading.CancellationToken token) [0x00009] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Controller+<>c__DisplayClass14_0.<Backup>b__0 (Duplicati.Library.Main.BackupResults result) [0x0004b] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Controller.RunAction[T] (T result, System.String[]& paths, Duplicati.Library.Utility.IFilter& filter, System.Action`1[T] method) [0x0026f] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Controller.Backup (System.String[] inputsources, Duplicati.Library.Utility.IFilter filter) [0x00074] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Server.Runner.Run (Duplicati.Server.Runner+IRunnerData data, System.Boolean fromQueue) [0x00349] in <156011ea63b34859b4073abdbf0b1573>:0
4

there were same errors every day before that til 5 Oct, when there is this one:

System.AggregateException: One or more errors occurred. (Unexpected result from renaming "duplicati-20221005T060229Z.dlist.zip.aes" to "duplicati-20221005T060230Z.dlist.zip.aes", expected 1 got 2 (Unexpected result from renaming "duplicati-20221005T060229Z.dlist.zip.aes" to "duplicati-20221005T060230Z.dlist.zip.aes", expected 1 got 2) (One or more errors occurred. (Unexpected result from renaming "duplicati-20221005T060229Z.dlist.zip.aes" to "duplicati-20221005T060230Z.dlist.zip.aes", expected 1 got 2))) ---> System.AggregateException: Unexpected result from renaming "duplicati-20221005T060229Z.dlist.zip.aes" to "duplicati-20221005T060230Z.dlist.zip.aes", expected 1 got 2 (Unexpected result from renaming "duplicati-20221005T060229Z.dlist.zip.aes" to "duplicati-20221005T060230Z.dlist.zip.aes", expected 1 got 2) (One or more errors occurred. (Unexpected result from renaming "duplicati-20221005T060229Z.dlist.zip.aes" to "duplicati-20221005T060230Z.dlist.zip.aes", expected 1 got 2)) ---> System.Exception: Unexpected result from renaming "duplicati-20221005T060229Z.dlist.zip.aes" to "duplicati-20221005T060230Z.dlist.zip.aes", expected 1 got 2
  at Duplicati.Library.Main.Database.LocalDatabase.RenameRemoteFile (System.String oldname, System.String newname, System.Data.IDbTransaction transaction) [0x0006d] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Operation.Common.DatabaseCommon+<>c__DisplayClass9_0.<RenameRemoteFileAsync>b__0 () [0x00000] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Operation.Common.SingleRunner+<>c__DisplayClass3_0.<RunOnMain>b__0 () [0x00000] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Operation.Common.SingleRunner.DoRunOnMain[T] (System.Func`1[TResult] method) [0x000b0] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Operation.Backup.BackendUploader.RenameFileAfterErrorAsync (Duplicati.Library.Main.Operation.Common.BackendHandler+FileEntryItem item) [0x00234] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Operation.Backup.BackendUploader+<>c__DisplayClass20_0.<UploadFileAsync>b__0 () [0x0008d] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Operation.Backup.BackendUploader.DoWithRetry (System.Func`1[TResult] method, Duplicati.Library.Main.Operation.Common.BackendHandler+FileEntryItem item, Duplicati.Library.Main.Operation.Backup.BackendUploader+Worker worker, System.Threading.CancellationToken cancelToken) [0x0017c] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Operation.Backup.BackendUploader.DoWithRetry (System.Func`1[TResult] method, Duplicati.Library.Main.Operation.Common.BackendHandler+FileEntryItem item, Duplicati.Library.Main.Operation.Backup.BackendUploader+Worker worker, System.Threading.CancellationToken cancelToken) [0x003a5] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Operation.Backup.BackendUploader.UploadFileAsync (Duplicati.Library.Main.Operation.Common.BackendHandler+FileEntryItem item, Duplicati.Library.Main.Operation.Backup.BackendUploader+Worker worker, System.Threading.CancellationToken cancelToken) [0x000da] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Operation.Backup.BackendUploader.UploadVolumeWriter (Duplicati.Library.Main.Volumes.VolumeWriterBase volumeWriter, Duplicati.Library.Main.Operation.Backup.BackendUploader+Worker worker, System.Threading.CancellationToken cancelToken) [0x000b8] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at CoCoL.AutomationExtensions.RunTask[T] (T channels, System.Func`2[T,TResult] method, System.Boolean catchRetiredExceptions) [0x000d4] in <9a758ff4db6c48d6b3d4d0e5c2adf6d1>:0 
  at Duplicati.Library.Main.Operation.BackupHandler.FlushBackend (Duplicati.Library.Main.BackupResults result, CoCoL.IWriteChannel`1[T] uploadtarget, System.Threading.Tasks.Task uploader) [0x001da] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Operation.BackupHandler.RunAsync (System.String[] sources, Duplicati.Library.Utility.IFilter filter, System.Threading.CancellationToken token) [0x00cb2] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
   --- End of inner exception stack trace ---
  at Duplicati.Library.Main.Operation.BackupHandler.RunAsync (System.String[] sources, Duplicati.Library.Utility.IFilter filter, System.Threading.CancellationToken token) [0x01048] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
   --- End of inner exception stack trace ---
  at CoCoL.ChannelExtensions.WaitForTaskOrThrow (System.Threading.Tasks.Task task) [0x0005d] in <9a758ff4db6c48d6b3d4d0e5c2adf6d1>:0 
  at Duplicati.Library.Main.Operation.BackupHandler.Run (System.String[] sources, Duplicati.Library.Utility.IFilter filter, System.Threading.CancellationToken token) [0x00009] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Controller+<>c__DisplayClass14_0.<Backup>b__0 (Duplicati.Library.Main.BackupResults result) [0x0004b] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Controller.RunAction[T] (T result, System.String[]& paths, Duplicati.Library.Utility.IFilter& filter, System.Action`1[T] method) [0x0026f] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Controller.Backup (System.String[] inputsources, Duplicati.Library.Utility.IFilter filter) [0x00074] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Server.Runner.Run (Duplicati.Server.Runner+IRunnerData data, System.Boolean fromQueue) [0x00349] in <156011ea63b34859b4073abdbf0b1573>:0 
---> (Inner Exception #0) System.AggregateException: Unexpected result from renaming "duplicati-20221005T060229Z.dlist.zip.aes" to "duplicati-20221005T060230Z.dlist.zip.aes", expected 1 got 2 (Unexpected result from renaming "duplicati-20221005T060229Z.dlist.zip.aes" to "duplicati-20221005T060230Z.dlist.zip.aes", expected 1 got 2) (One or more errors occurred. (Unexpected result from renaming "duplicati-20221005T060229Z.dlist.zip.aes" to "duplicati-20221005T060230Z.dlist.zip.aes", expected 1 got 2)) ---> System.Exception: Unexpected result from renaming "duplicati-20221005T060229Z.dlist.zip.aes" to "duplicati-20221005T060230Z.dlist.zip.aes", expected 1 got 2
  at Duplicati.Library.Main.Database.LocalDatabase.RenameRemoteFile (System.String oldname, System.String newname, System.Data.IDbTransaction transaction) [0x0006d] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Operation.Common.DatabaseCommon+<>c__DisplayClass9_0.<RenameRemoteFileAsync>b__0 () [0x00000] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Operation.Common.SingleRunner+<>c__DisplayClass3_0.<RunOnMain>b__0 () [0x00000] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Operation.Common.SingleRunner.DoRunOnMain[T] (System.Func`1[TResult] method) [0x000b0] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Operation.Backup.BackendUploader.RenameFileAfterErrorAsync (Duplicati.Library.Main.Operation.Common.BackendHandler+FileEntryItem item) [0x00234] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Operation.Backup.BackendUploader+<>c__DisplayClass20_0.<UploadFileAsync>b__0 () [0x0008d] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Operation.Backup.BackendUploader.DoWithRetry (System.Func`1[TResult] method, Duplicati.Library.Main.Operation.Common.BackendHandler+FileEntryItem item, Duplicati.Library.Main.Operation.Backup.BackendUploader+Worker worker, System.Threading.CancellationToken cancelToken) [0x0017c] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Operation.Backup.BackendUploader.DoWithRetry (System.Func`1[TResult] method, Duplicati.Library.Main.Operation.Common.BackendHandler+FileEntryItem item, Duplicati.Library.Main.Operation.Backup.BackendUploader+Worker worker, System.Threading.CancellationToken cancelToken) [0x003a5] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Operation.Backup.BackendUploader.UploadFileAsync (Duplicati.Library.Main.Operation.Common.BackendHandler+FileEntryItem item, Duplicati.Library.Main.Operation.Backup.BackendUploader+Worker worker, System.Threading.CancellationToken cancelToken) [0x000da] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Operation.Backup.BackendUploader.UploadVolumeWriter (Duplicati.Library.Main.Volumes.VolumeWriterBase volumeWriter, Duplicati.Library.Main.Operation.Backup.BackendUploader+Worker worker, System.Threading.CancellationToken cancelToken) [0x000b8] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at CoCoL.AutomationExtensions.RunTask[T] (T channels, System.Func`2[T,TResult] method, System.Boolean catchRetiredExceptions) [0x000d4] in <9a758ff4db6c48d6b3d4d0e5c2adf6d1>:0 
  at Duplicati.Library.Main.Operation.BackupHandler.FlushBackend (Duplicati.Library.Main.BackupResults result, CoCoL.IWriteChannel`1[T] uploadtarget, System.Threading.Tasks.Task uploader) [0x001da] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Operation.BackupHandler.RunAsync (System.String[] sources, Duplicati.Library.Utility.IFilter filter, System.Threading.CancellationToken token) [0x00cb2] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
   --- End of inner exception stack trace ---
  at Duplicati.Library.Main.Operation.BackupHandler.RunAsync (System.String[] sources, Duplicati.Library.Utility.IFilter filter, System.Threading.CancellationToken token) [0x01048] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
---> (Inner Exception #0) System.Exception: Unexpected result from renaming "duplicati-20221005T060229Z.dlist.zip.aes" to "duplicati-20221005T060230Z.dlist.zip.aes", expected 1 got 2
  at Duplicati.Library.Main.Database.LocalDatabase.RenameRemoteFile (System.String oldname, System.String newname, System.Data.IDbTransaction transaction) [0x0006d] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Operation.Common.DatabaseCommon+<>c__DisplayClass9_0.<RenameRemoteFileAsync>b__0 () [0x00000] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Operation.Common.SingleRunner+<>c__DisplayClass3_0.<RunOnMain>b__0 () [0x00000] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Operation.Common.SingleRunner.DoRunOnMain[T] (System.Func`1[TResult] method) [0x000b0] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Operation.Backup.BackendUploader.RenameFileAfterErrorAsync (Duplicati.Library.Main.Operation.Common.BackendHandler+FileEntryItem item) [0x00234] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Operation.Backup.BackendUploader+<>c__DisplayClass20_0.<UploadFileAsync>b__0 () [0x0008d] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Operation.Backup.BackendUploader.DoWithRetry (System.Func`1[TResult] method, Duplicati.Library.Main.Operation.Common.BackendHandler+FileEntryItem item, Duplicati.Library.Main.Operation.Backup.BackendUploader+Worker worker, System.Threading.CancellationToken cancelToken) [0x0017c] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Operation.Backup.BackendUploader.DoWithRetry (System.Func`1[TResult] method, Duplicati.Library.Main.Operation.Common.BackendHandler+FileEntryItem item, Duplicati.Library.Main.Operation.Backup.BackendUploader+Worker worker, System.Threading.CancellationToken cancelToken) [0x003a5] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Operation.Backup.BackendUploader.UploadFileAsync (Duplicati.Library.Main.Operation.Common.BackendHandler+FileEntryItem item, Duplicati.Library.Main.Operation.Backup.BackendUploader+Worker worker, System.Threading.CancellationToken cancelToken) [0x000da] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Operation.Backup.BackendUploader.UploadVolumeWriter (Duplicati.Library.Main.Volumes.VolumeWriterBase volumeWriter, Duplicati.Library.Main.Operation.Backup.BackendUploader+Worker worker, System.Threading.CancellationToken cancelToken) [0x000b8] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at CoCoL.AutomationExtensions.RunTask[T] (T channels, System.Func`2[T,TResult] method, System.Boolean catchRetiredExceptions) [0x000d4] in <9a758ff4db6c48d6b3d4d0e5c2adf6d1>:0 
  at Duplicati.Library.Main.Operation.BackupHandler.FlushBackend (Duplicati.Library.Main.BackupResults result, CoCoL.IWriteChannel`1[T] uploadtarget, System.Threading.Tasks.Task uploader) [0x001da] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Operation.BackupHandler.RunAsync (System.String[] sources, Duplicati.Library.Utility.IFilter filter, System.Threading.CancellationToken token) [0x00cb2] in <e60bc008dd1b454d861cfacbdd3760b9>:0 <---

---> (Inner Exception #1) System.AggregateException: One or more errors occurred. (Unexpected result from renaming "duplicati-20221005T060229Z.dlist.zip.aes" to "duplicati-20221005T060230Z.dlist.zip.aes", expected 1 got 2) ---> System.Exception: Unexpected result from renaming "duplicati-20221005T060229Z.dlist.zip.aes" to "duplicati-20221005T060230Z.dlist.zip.aes", expected 1 got 2
  at Duplicati.Library.Main.Database.LocalDatabase.RenameRemoteFile (System.String oldname, System.String newname, System.Data.IDbTransaction transaction) [0x0006d] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Operation.Common.DatabaseCommon+<>c__DisplayClass9_0.<RenameRemoteFileAsync>b__0 () [0x00000] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Operation.Common.SingleRunner+<>c__DisplayClass3_0.<RunOnMain>b__0 () [0x00000] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Operation.Common.SingleRunner.DoRunOnMain[T] (System.Func`1[TResult] method) [0x000b0] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Operation.Backup.BackendUploader.RenameFileAfterErrorAsync (Duplicati.Library.Main.Operation.Common.BackendHandler+FileEntryItem item) [0x00234] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Operation.Backup.BackendUploader+<>c__DisplayClass20_0.<UploadFileAsync>b__0 () [0x0008d] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Operation.Backup.BackendUploader.DoWithRetry (System.Func`1[TResult] method, Duplicati.Library.Main.Operation.Common.BackendHandler+FileEntryItem item, Duplicati.Library.Main.Operation.Backup.BackendUploader+Worker worker, System.Threading.CancellationToken cancelToken) [0x0017c] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Operation.Backup.BackendUploader.DoWithRetry (System.Func`1[TResult] method, Duplicati.Library.Main.Operation.Common.BackendHandler+FileEntryItem item, Duplicati.Library.Main.Operation.Backup.BackendUploader+Worker worker, System.Threading.CancellationToken cancelToken) [0x003a5] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Operation.Backup.BackendUploader.UploadFileAsync (Duplicati.Library.Main.Operation.Common.BackendHandler+FileEntryItem item, Duplicati.Library.Main.Operation.Backup.BackendUploader+Worker worker, System.Threading.CancellationToken cancelToken) [0x000da] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Operation.Backup.BackendUploader.UploadVolumeWriter (Duplicati.Library.Main.Volumes.VolumeWriterBase volumeWriter, Duplicati.Library.Main.Operation.Backup.BackendUploader+Worker worker, System.Threading.CancellationToken cancelToken) [0x000b8] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at CoCoL.AutomationExtensions.RunTask[T] (T channels, System.Func`2[T,TResult] method, System.Boolean catchRetiredExceptions) [0x000d4] in <9a758ff4db6c48d6b3d4d0e5c2adf6d1>:0 
  at Duplicati.Library.Main.Operation.BackupHandler.FlushBackend (Duplicati.Library.Main.BackupResults result, CoCoL.IWriteChannel`1[T] uploadtarget, System.Threading.Tasks.Task uploader) [0x001da] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Operation.BackupHandler.RunAsync (System.String[] sources, Duplicati.Library.Utility.IFilter filter, System.Threading.CancellationToken token) [0x00cb2] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
   --- End of inner exception stack trace ---
---> (Inner Exception #0) System.Exception: Unexpected result from renaming "duplicati-20221005T060229Z.dlist.zip.aes" to "duplicati-20221005T060230Z.dlist.zip.aes", expected 1 got 2
  at Duplicati.Library.Main.Database.LocalDatabase.RenameRemoteFile (System.String oldname, System.String newname, System.Data.IDbTransaction transaction) [0x0006d] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Operation.Common.DatabaseCommon+<>c__DisplayClass9_0.<RenameRemoteFileAsync>b__0 () [0x00000] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Operation.Common.SingleRunner+<>c__DisplayClass3_0.<RunOnMain>b__0 () [0x00000] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Operation.Common.SingleRunner.DoRunOnMain[T] (System.Func`1[TResult] method) [0x000b0] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Operation.Backup.BackendUploader.RenameFileAfterErrorAsync (Duplicati.Library.Main.Operation.Common.BackendHandler+FileEntryItem item) [0x00234] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Operation.Backup.BackendUploader+<>c__DisplayClass20_0.<UploadFileAsync>b__0 () [0x0008d] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Operation.Backup.BackendUploader.DoWithRetry (System.Func`1[TResult] method, Duplicati.Library.Main.Operation.Common.BackendHandler+FileEntryItem item, Duplicati.Library.Main.Operation.Backup.BackendUploader+Worker worker, System.Threading.CancellationToken cancelToken) [0x0017c] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Operation.Backup.BackendUploader.DoWithRetry (System.Func`1[TResult] method, Duplicati.Library.Main.Operation.Common.BackendHandler+FileEntryItem item, Duplicati.Library.Main.Operation.Backup.BackendUploader+Worker worker, System.Threading.CancellationToken cancelToken) [0x003a5] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Operation.Backup.BackendUploader.UploadFileAsync (Duplicati.Library.Main.Operation.Common.BackendHandler+FileEntryItem item, Duplicati.Library.Main.Operation.Backup.BackendUploader+Worker worker, System.Threading.CancellationToken cancelToken) [0x000da] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Operation.Backup.BackendUploader.UploadVolumeWriter (Duplicati.Library.Main.Volumes.VolumeWriterBase volumeWriter, Duplicati.Library.Main.Operation.Backup.BackendUploader+Worker worker, System.Threading.CancellationToken cancelToken) [0x000b8] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at CoCoL.AutomationExtensions.RunTask[T] (T channels, System.Func`2[T,TResult] method, System.Boolean catchRetiredExceptions) [0x000d4] in <9a758ff4db6c48d6b3d4d0e5c2adf6d1>:0 
  at Duplicati.Library.Main.Operation.BackupHandler.FlushBackend (Duplicati.Library.Main.BackupResults result, CoCoL.IWriteChannel`1[T] uploadtarget, System.Threading.Tasks.Task uploader) [0x001da] in <e60bc008dd1b454d861cfacbdd3760b9>:0 
  at Duplicati.Library.Main.Operation.BackupHandler.RunAsync (System.String[] sources, Duplicati.Library.Utility.IFilter filter, System.Threading.CancellationToken token) [0x00cb2] in <e60bc008dd1b454d861cfacbdd3760b9>:0 <---
<---
<---

the log before that, also on 5 Oct is

System.AggregateException: One or more errors occurred. (Unable to read data from the transport connection: The socket has been shut down. (Unable to read data from the transport connection: The socket has been shut down.) (One or more errors occurred. (Unable to read data from the transport connection: The socket has been shut down.))) ---> System.AggregateException: Unable to read data from the transport connection: The socket has been shut down. (Unable to read data from the transport connection: The socket has been shut down.) (One or more errors occurred. (Unable to read data from the transport connection: The socket has been shut down.)) ---> System.IO.IOException: Unable to read data from the transport connection: The socket has been shut down. ---> System.Net.Sockets.SocketException: The socket has been shut down
   --- End of inner exception stack trace ---
  at System.Net.Sockets.Socket+AwaitableSocketAsyncEventArgs.ThrowException (System.Net.Sockets.SocketError error) [0x00007] in <b146cf69d6114167a7409c0f0241bbf4>:0 
  at System.Net.Sockets.Socket+AwaitableSocketAsyncEventArgs.System.Threading.Tasks.Sources.IValueTaskSource.GetResult (System.Int16 token) [0x0001f] in <b146cf69d6114167a7409c0f0241bbf4>:0 
  at System.Threading.Tasks.ValueTask+ValueTaskSourceAsTask+<>c.<.cctor>b__4_0 (System.Object state) [0x00030] in <2340fc16524a4335b1ffb55cb251f8d6>:0 
--- End of stack trace from previous location where exception was thrown ---

------------------------------
TOO LONG TO POST THE REST

Is there a way (and is it a good idea) to tell Duplicati to forget about these missing remote files? I donā€™t really understand well how Duplicati works so not really in a position to judge.

5

The clean affected run adds confidence that there are just some extra dindex files citing useless dblocks. Although I think thatā€™s fairly reliable, more certainty could be achieved by browsing DB or supplying report.

The backup databases donā€™t have any recent dates, so there probably isnā€™t a relevant database any more.

Remote backup task quit working : constraint failed UNIQUE constraint failed: Remotevolume.Name, Remotevolume.State was the most recent chase for that, aided by a database bug report. With logs and database gone here, such an investigation canā€™t be attempted, but even the other one wasnā€™t very certain.

What type of Destination is this? Some have duplicate-filename capabilities that permit special problems.

The rename error likely followed an upload error. The retry gets a new name, but a conflict isnā€™t expected.

Sockets are a network connection. Networks glitch, and retry is needed. This error worries me the least.

Retries of uploads and downloads are also kind of expected, and tolerated unless they get too extensive.
You got one on the DB recreate. The default number-of-retries is 5, but it and other things are adjustable.

You seem to be 2 hours ahead of UTC. A dlist time uses UTC. The rename error had 20221005T060230 meaning 8:02 AM on Oct 5, 2022 after time zone adjustment. If thereā€™s still a backup there, it might merit special attention. Regardless, if you keep using the backup, be sure to run at least some Restore testing.

Do you know how much storage your backup takes? DB recreate downloaded 870701977 bytes, which (unless you have a very small backup) might just be dlist and dindex files. Dblock download is a bad sign
which happens from 70% to 100% on the progress bar. About ā†’ Show log ā†’ Live ā†’ Retry also shows.
Verbose level says even more. The dblock searching is seeking data blocks that werenā€™t in any index file.

6

Thanks again @ts678!

Excuse my ignorance, but what exactly would I be browsing for here?

Backblaze B2. With my current lifecycle settings I think it may keep versions of files with the same name. I guess itā€™s best to keep only latest versions right? As suggested at Setting up retention/versioning with Backblaze B2? - #4 by mohak

So if I understand correctly, if Iā€™m confident that the dindex files are citing useless dblocks (which I can confirm somehow by browsing the DB), I can just delete those four dindex files from B2, recreate DB, and cross my fingers right?

EDIT

Source:
33.81 GB
Backup:
56.28 GB / 45 Versions

Is this reasonable? Or should I check further whether there are dblocks that werenā€™t in any index?

7

Sorry. I thought there were some pictures in the large thread I linked to, but theyā€™re werenā€™t of the DB.

As a first check on the dblock file, type its Name as a Filter in Remotevolume table. Is there an ID?

image

If thereā€™s an ID, use it as a filter for VolumeID in the Block table. If nothing found, its blocks arenā€™t in use.
In a normal backup, Remotevolume table State Verified Type Blocks and Index counts match and also
match IndexBlockLink table which ties the dindex and dblock files together using Remotevolume IDs.
Also study situation from the dindex view. Any dindex not in IndexBlockLink are likely not needed now.

You can delete (or move elsewhere if youā€™re unsure) the dindex files that reference them, then recreate.
If progress bar doesnā€™t slow down in the 70% to 100% range, and all appears good, you might be good.
Testing the backup with a Restore is always a good idea, and especially after having to do hand-repairs.

8

Sorry to barge in but are you by any chance using some kind of ā€˜intelligentā€™ backend ? Itā€™s not recommended with Duplicati using deduplication, because if the backend removes old files it will damage backups. Duplicati is made for dumb backends.

9

Thanks for the instructions.

The missing remote dblocks were not in Remotevolume, which I guess is good.

The dindexs citing the missing dblocks were not in IndexBlackLink which I guess is good.

So I moved the offending dindex out of the b2 bucket and ran database recreation. It completed successfully but it appears that dblocks were being downloaded during the recreation (I saw while watching About ā†’ Show log ā†’ Live ā†’ Profile).

Iā€™m not sure exactly what this means or what to do to fix it. Any tips?

Here is the log from recreation (which doesnā€™t appear to show the dblock downloads):

{
  "MainOperation": "Repair",
  "RecreateDatabaseResults": {
    "MainOperation": "Repair",
    "ParsedResult": "Success",
    "Version": "2.0.6.3 (2.0.6.3_beta_2021-06-17)",
    "EndTime": "2022-11-02T13:02:52.36828Z",
    "BeginTime": "2022-11-02T12:18:24.902644Z",
    "Duration": "00:44:27.4656360",
    "MessagesActualLength": 0,
    "WarningsActualLength": 0,
    "ErrorsActualLength": 0,
    "Messages": null,
    "Warnings": null,
    "Errors": null,
    "BackendStatistics": {
      "RemoteCalls": 1257,
      "BytesUploaded": 0,
      "BytesDownloaded": 859993019,
      "FilesUploaded": 0,
      "FilesDownloaded": 1255,
      "FilesDeleted": 0,
      "FoldersCreated": 0,
      "RetryAttempts": 1,
      "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",
      "Version": "2.0.6.3 (2.0.6.3_beta_2021-06-17)",
      "EndTime": "0001-01-01T00:00:00",
      "BeginTime": "2022-11-02T12:18:24.836606Z",
      "Duration": "00:00:00",
      "MessagesActualLength": 0,
      "WarningsActualLength": 0,
      "ErrorsActualLength": 0,
      "Messages": null,
      "Warnings": null,
      "Errors": null
    }
  },
  "ParsedResult": "Success",
  "Version": "2.0.6.3 (2.0.6.3_beta_2021-06-17)",
  "EndTime": "2022-11-02T13:02:53.267714Z",
  "BeginTime": "2022-11-02T12:18:24.836602Z",
  "Duration": "00:44:28.4311120",
  "MessagesActualLength": 2520,
  "WarningsActualLength": 0,
  "ErrorsActualLength": 0,
  "Messages": [
    "2022-11-02 13:18:24 +01 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Repair has started",
    "2022-11-02 13:18:24 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started:  ()",
    "2022-11-02 13:18:29 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed:  (2.39 KB)",
    "2022-11-02 13:18:32 +01 - [Information-Duplicati.Library.Main.Operation.RecreateDatabaseHandler-RebuildStarted]: Rebuild database started, downloading 43 filelists",
    "2022-11-02 13:18:32 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-20191104T162530Z.dlist.zip.aes (2.80 MB)",
    "2022-11-02 13:18:36 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-20191104T162530Z.dlist.zip.aes (2.80 MB)",
    "2022-11-02 13:18:36 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-20191207T155116Z.dlist.zip.aes (2.80 MB)",
    "2022-11-02 13:18:38 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-20191207T155116Z.dlist.zip.aes (2.80 MB)",
    "2022-11-02 13:18:45 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-20200114T035116Z.dlist.zip.aes (2.80 MB)",
    "2022-11-02 13:18:49 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-20200114T035116Z.dlist.zip.aes (2.80 MB)",
    "2022-11-02 13:18:51 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-20200222T215116Z.dlist.zip.aes (2.82 MB)",
    "2022-11-02 13:18:54 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-20200222T215116Z.dlist.zip.aes (2.82 MB)",
    "2022-11-02 13:18:58 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-20200325T155116Z.dlist.zip.aes (2.83 MB)",
    "2022-11-02 13:19:00 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-20200325T155116Z.dlist.zip.aes (2.83 MB)",
    "2022-11-02 13:19:06 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-20200429T221638Z.dlist.zip.aes (1.44 MB)",
    "2022-11-02 13:19:10 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-20200429T221638Z.dlist.zip.aes (1.44 MB)",
    "2022-11-02 13:19:14 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-20200606T094441Z.dlist.zip.aes (695.76 KB)",
    "2022-11-02 13:19:14 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-20200606T094441Z.dlist.zip.aes (695.76 KB)",
    "2022-11-02 13:19:17 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-20200713T155116Z.dlist.zip.aes (1.67 MB)",
    "2022-11-02 13:19:20 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-20200713T155116Z.dlist.zip.aes (1.67 MB)"
  ],
  "Warnings": [],
  "Errors": [],
  "BackendStatistics": {
    "RemoteCalls": 1257,
    "BytesUploaded": 0,
    "BytesDownloaded": 859993019,
    "FilesUploaded": 0,
    "FilesDownloaded": 1255,
    "FilesDeleted": 0,
    "FoldersCreated": 0,
    "RetryAttempts": 1,
    "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",
    "Version": "2.0.6.3 (2.0.6.3_beta_2021-06-17)",
    "EndTime": "0001-01-01T00:00:00",
    "BeginTime": "2022-11-02T12:18:24.836606Z",
    "Duration": "00:00:00",
    "MessagesActualLength": 0,
    "WarningsActualLength": 0,
    "ErrorsActualLength": 0,
    "Messages": null,
    "Warnings": null,
    "Errors": null
  }
}
10

I am using Backblaze b2. I donā€™t believe that it removes old files, but I think that with the default bucket settings it keeps versions of files when they are uploaded with the same name. I am guessing that this is what @ts678 was referring to here:

I plan to turn off version saving after sorting out this problem.

11

It definitely can do that:

but you would know if you did set up such a ruleā€¦which you should absolutely NOT do.

12

I didnā€™t get into watching logs because it was getting long already, and progress bar implies dblocks.
Information or Retry level would show file downloads, Verbose would give commentary on progress.

Iā€™m not extremely expert on DB recreate (but no other available person is), but I think the idea is that
dlist file says what files you have and what blocks they need, dindex says what dblock block lives in.
Missing dindex may need a search of dblocks to figure out block home via download and inspection.

With a good database, one can delete a dindex, run Repair, and Duplicati will regenerate the dindex.
We donā€™t know how good the old database was, but itā€™s gone. The DB recreate going away happy is
suggesting it found everything, but if it leaves missing dindex, next recreate will suffer slow recreate.

I should note that ā€œslowā€ comes in different levels, and yours might be a tolerable one. Passes are at:

and the 90% to 100% would have caused your entire 56 GB backup to download. That didnā€™t happen.
There might also be some additional logging (if you saved the Profiling log) hinting at what took place.
If nothing else, you would see the messages from the code snippet above showing the three passes.

I suppose you can do the DB row counting to three-way-compare Blocks, Index, and IndexBlockLink.
You could also post a link to a DB bug report to let someone else (maybe me) see what they can get.

13

Thank you, Iā€™d appreciate it. Iā€™m not sure I would know how to do such a comparison. Here is the generated bug report: https://drive.google.com/file/d/1Y6mtG9kQ2XuhdYhRAh8RzbsDIOxvwFJX/view?usp=share_link

14

Thanks for the bug report. It helps some, although some original data was lost in the database recreate.
That downloaded 43 dblocks out of 1197. Iā€™m not sure why, and I guess thereā€™s no profiling log to check?
This looks like a bigger download than the log you posted showed, and it probably cost an extra 2 cents.

After those downloads, Iā€™m not seeing signs of blocks that donā€™t have a known dblock file, so thatā€™s good.
There are some other extra dindex files that at least point to existing dblocks which were double indexed.
That doesnā€™t seem normal either, but further comparison would need you opening up those dindex filesā€¦
Itā€™s just a decrypt and unzip to get the vol file named after the dblock, but then Iā€™d have to puzzle them out.

Unless you want to keep digging, Iā€™d say test Restore, and keep on going. You can start fresh if you prefer.
B2 doesnā€™t charge for uploads, but starting fresh would lose your old backup versions which you may like.

Debug notes follow:

From typing into column Filter headers, and noting row count in bottom left.
Everything is State Verfied maybe because of DB recreate, so I'll ignore it:

1201    IndexBlockLink
1197    Type Blocks
1203    Type Index

Ideally I think all the above row counts would be the same. Try to diagnose.
If there are any SQL experts out there, feel free to improve my SQL queries:

-- Look for dblock without linked dindex
SELECT "Name" FROM "Remotevolume" WHERE "Type" = "Block" AND "ID" NOT IN (SELECT "BlockVolumeID" FROM "IndexBlockLink")
(none)

-- Look for dblock link without a dblock
SELECT "BlockVolumeID" FROM "IndexBlockLink" WHERE "BlockVolumeID" NOT IN (SELECT "ID" FROM "Remotevolume" WHERE "Type" = "Blocks")
(none)

-- Look for dindex without a dblock link
SELECT "Name" FROM "Remotevolume" WHERE "Type" = "Index" AND "ID" NOT IN (SELECT "IndexVolumeID" FROM "IndexBlockLink")
duplicati-i4a993d32a5914627847196c7e13e4229.dindex.zip.aes
duplicati-i9ea0071d317b4dda82411bd98e19f57d.dindex.zip.aes

-- Look for dindex link without a dindex
SELECT "IndexVolumeID" FROM "IndexBlockLink" WHERE "IndexVolumeID" NOT IN (SELECT "ID" FROM "Remotevolume" WHERE "Type" = "Index")
(none)

-- See if DISTINCT dindex count is lower
SELECT "IndexVolumeID" FROM "IndexBlockLink"
(1201 rows)
SELECT DISTINCT "IndexVolumeID" FROM "IndexBlockLink"
(1201 rows)

-- See if DISTINCT dblock count is lower
SELECT "BlockVolumeID" FROM "IndexBlockLink"
(1201 rows)
SELECT DISTINCT "BlockVolumeID" FROM "IndexBlockLink"
(1197 rows)

-- Look for 4 duplicates from above drop
SELECT "BlockVolumeID" FROM "IndexBlockLink" GROUP BY "BlockVolumeID" HAVING COUNT("BlockVolumeID") > 1
174
298
767
1084

Manual lookup values of duplicate dindex
BlockVolumeID   IndexVolumeID   Name
174             1694            duplicati-i5ebf37c910904e9c85c61cc630afad26.dindex.zip.aes      "LastModification":"2022-09-24T14:21:48.058Z","Size":53901
174             1859            duplicati-i7fcb5da6f62e49fc90e41faf2624811e.dindex.zip.aes      "LastModification":"2022-09-02T18:17:41.804Z","Size":55933

298             1585            duplicati-i47c25d1071ac488c9c48f72cd43b96d9.dindex.zip.aes      "LastModification":"2022-08-20T20:05:14.552Z","Size":41709
298             2333            duplicati-iee3cfb0502ff4c9ba3a8138acd18b391.dindex.zip.aes      "LastModification":"2022-09-01T10:07:31.985Z","Size":41421

767             1392            duplicati-i1ec5bb24795d42f296b113ad67162b74.dindex.zip.aes      "LastModification":"2022-06-02T12:45:06.149Z","Size":116173
767             1652            duplicati-i554b170d9b694d63ac8c6cfe724e5b85.dindex.zip.aes      "LastModification":"2022-06-01T13:29:27.124Z","Size":116173

1084            2068            duplicati-iab28f2239bde432b8d65da656987fda5.dindex.zip.aes      "LastModification":"2022-03-20T00:38:29Z","Size":53165
1084            2321            duplicati-ieaf13b8255ec4b1ca507fd22724df428.dindex.zip.aes      "LastModification":"2022-03-24T08:04:13.577Z","Size":53165

Manual lookup values of associated dblock
duplicati-b1cebe9a1a1134b55a7eff7f60eec0a8f.dblock.zip.aes                                      "LastModification":"2022-09-02T18:16:07.483Z","Size":52398893
duplicati-b3a51d163498e461aaae4ac0f13c84a7f.dblock.zip.aes                                      "LastModification":"2022-08-20T20:03:28.277Z","Size":52374573   
duplicati-b9b8ac6fcf3674a3696023bca224e66da.dblock.zip.aes                                      "LastModification":"2022-06-01T13:25:54.641Z","Size":52369389
duplicati-bdb82cc1af5904c1ba7e50156dda8d64f.dblock.zip.aes                                      "LastModification":"2022-03-20T00:36:58Z","Size":52342317

Above seem time stamped near older dindex
What was going on near the duplicate one?
Original DB had this data. It's gone now.

Attempted workaround is to take list Data from RemoteOperation table, convert JSON to CSV.
Open in spreadsheet, sort rows by LastModification, look around near time of newer dindex.
Nothing conclusive, although there seems to be a burst of dindex files, which seems weird.
During backup or compact, the dindex file would be uploaded near a dblock that it indexes.
15

Thanks so much for checking the debug report. I appreciate it. It sounds like there are enough weird things going on in there to justify starting afresh. I will just keep the old bucket for now so that I have a (probably good) version history.

1 Like