Backup corrupted

Jojo-1000 · October 20, 2024, 6:34pm

The missing file errors you saw previously (not this instance) might be caused by this:

github.com/duplicati/duplicati

Fix leftover/extra index volume after interrupted upload and more tests

duplicati:master ← Jojo-1000:fix-leftover-index

opened 08:28PM - 08 Oct 23 UTC

Jojo-1000

+692 -43

- Fixes part of #5023 - Also adds more test cases to track some known reproduci…ble issues (those that fail are category "Bug" and explicit only). ## Steps to reproduce - See `IssueTests.Issue5023ReferencedFileMissing` and `RepairHandlerTests.RepairExtraIndexFiles` # Current behavior - After interrupted dindex upload (but the upload finished), no index-block link is created - The next run uploads a new dindex file for the dblock - When repairing with an extra index file, the invalid ID -1 is inserted into the link table # New behavior - Index-block link is always created - The next run recognizes that the dindex file already exists and no extra is uploaded - When repairing with an extra index file, the correct ID is inserted into the link table ## Impact - Order of operations in repair handler was changed to fix the ID bug, but wrapped in a transaction to ensure that no inconsistencies occur. - The index block link is created *before* the upload is known to be completed (instead of after the upload). It will be removed together with the `RemoteVolume` entry at the start of the next run.

The issue was discussed here:

github.com/duplicati/duplicati

recreate "Remote file referenced as ..." error after interrupted backup then compact

opened 01:48PM - 10 Sep 23 UTC

ts678

- [x] I have searched open and closed issues for duplicates. - [x] I have searc…hed the [forum](https://forum.duplicati.com) for related topics. ---------------------------------------- ## Environment info - **Duplicati version**: 2.0.7.2 Canary - **Operating system**: Windows 10 - **Backend**: Local folder ## Description I can reliably (with about 10 minutes on an interrupt test script) get an error like > Remote file referenced as * dblock.zip by * dindex.zip, but not found in list, registering a missing remote file The error here is on recreate, but the one inside some restores can probably hit it. [Remote file referenced ... but not found in list, registering a missing remote file #4586](https://github.com/duplicati/duplicati/issues/4586) is possibly the same problem, but I have a better repro and analysis on this issue. It looks like interrupt after dindex put during backup can leave DB thinking there's a missing dindex even though the dindex put worked. The next backup fixes this, but uses a different dindex name. This is different from the case in repair with just a lost dindex. Possibly here it doesn't know the name because IndexBlockLink didn't get filled out. Regardless, the extra dindex file is harmless until dblock+new dindex from the fix get deleted by a compact. After that, there's old dindex pointing to a dblock that's not there. Before that, maybe recreate was happy because it found two dindex, but both pointed to the same dblock, and had the same information, so no harm done. Just a guess. Seems like a good time to stop for some feedback and questions based on data so far. Here's a high-level log which is now embellished with some output from an SQL query: > SELECT "Name" FROM "Remotevolume" WHERE "Type" = "Index" AND ( "State" = "Verified" OR "State" = "Uploaded" ) AND "ID" NOT IN (SELECT "IndexVolumeID" FROM "IndexBlockLink")' ``` Running backup at 2023-09-10 08:11:30.415663 Exit code 0 Running recreate at 2023-09-10 08:11:38.921437 Running repair at 2023-09-10 08:11:38.921437 Exit code 0 Statistics: started: 18 timeout: 3 missing: 0 extra: 0 marked: 0 Running backup at 2023-09-10 08:11:58.611870 Timed out after 3 seconds Statistics: started: 19 timeout: 4 missing: 0 extra: 0 marked: 0 Running backup at 2023-09-10 08:12:06.945352 Timed out after 4 seconds Statistics: started: 20 timeout: 5 missing: 0 extra: 0 marked: 0 Running backup at 2023-09-10 08:12:16.464174 Timed out after 10 seconds Statistics: started: 21 timeout: 6 missing: 0 extra: 0 marked: 0 Running backup at 2023-09-10 08:12:31.811753 Exit code 0 duplicati-icebfdb6777d24dda8b75fed3787c71ac.dindex.zip Running recreate at 2023-09-10 08:12:39.262241 Running repair at 2023-09-10 08:12:39.262241 Exit code 0 Statistics: started: 22 timeout: 6 missing: 0 extra: 0 marked: 0 Running backup at 2023-09-10 08:13:01.969719 Exit code 0 duplicati-icebfdb6777d24dda8b75fed3787c71ac.dindex.zip Running recreate at 2023-09-10 08:13:09.442398 Running repair at 2023-09-10 08:13:09.442398 Exit code 0 Statistics: started: 23 timeout: 6 missing: 0 extra: 0 marked: 0 Running backup at 2023-09-10 08:13:31.168298 Timed out after 2 seconds Statistics: started: 24 timeout: 7 missing: 0 extra: 0 marked: 0 Running backup at 2023-09-10 08:13:38.449298 Exit code 0 duplicati-icebfdb6777d24dda8b75fed3787c71ac.dindex.zip Running recreate at 2023-09-10 08:13:47.858636 Running repair at 2023-09-10 08:13:47.858636 Exit code 0 Statistics: started: 25 timeout: 7 missing: 0 extra: 0 marked: 0 Running backup at 2023-09-10 08:14:11.596258 Exit code 0 duplicati-icebfdb6777d24dda8b75fed3787c71ac.dindex.zip Running recreate at 2023-09-10 08:14:26.134430 Running repair at 2023-09-10 08:14:26.134430 Exit code 0 Statistics: started: 26 timeout: 7 missing: 0 extra: 0 marked: 0 Running backup at 2023-09-10 08:14:52.249091 Timed out after 6 seconds Statistics: started: 27 timeout: 8 missing: 0 extra: 0 marked: 0 Running backup at 2023-09-10 08:15:03.624671 Exit code 0 duplicati-icebfdb6777d24dda8b75fed3787c71ac.dindex.zip Running recreate at 2023-09-10 08:15:12.084502 Running repair at 2023-09-10 08:15:12.084502 Exit code 0 Statistics: started: 28 timeout: 8 missing: 0 extra: 0 marked: 0 Running backup at 2023-09-10 08:15:37.768793 Exit code 0 duplicati-icebfdb6777d24dda8b75fed3787c71ac.dindex.zip Running recreate at 2023-09-10 08:15:46.206783 Running repair at 2023-09-10 08:15:46.206783 Exit code 0 Statistics: started: 29 timeout: 8 missing: 0 extra: 0 marked: 0 Running backup at 2023-09-10 08:16:09.923359 Exit code 0 duplicati-icebfdb6777d24dda8b75fed3787c71ac.dindex.zip Running recreate at 2023-09-10 08:16:18.360990 Running repair at 2023-09-10 08:16:18.360990 Exit code 0 Statistics: started: 30 timeout: 8 missing: 0 extra: 0 marked: 0 Running backup at 2023-09-10 08:16:45.544337 Timed out after 16 seconds Statistics: started: 31 timeout: 9 missing: 0 extra: 0 marked: 0 Running backup at 2023-09-10 08:17:06.831278 Exit code 0 duplicati-icebfdb6777d24dda8b75fed3787c71ac.dindex.zip Running recreate at 2023-09-10 08:17:13.263109 Running repair at 2023-09-10 08:17:13.263109 Exit code 0 Remote file referenced as duplicati-b6587050dc3b146fa9cfcb1493aaf9751.dblock.zip by duplicati-icebfdb6777d24dda8b75fed3787c71ac.dindex.zip, but not found in list, registering a missing remote file Found 1 missing volumes; attempting to replace blocks from existing volumes Found 1 missing volumes; attempting to replace blocks from existing volumes Statistics: started: 32 timeout: 9 missing: 0 extra: 0 marked: 0 ``` So let's try a `glogg` profiling log search, starting with those two files. Add on the original dindex, and Compacting so we can also get that context: ``` 2023-09-10 08:11:35 -04 - [Information-Duplicati.Library.Main.Database.LocalDeleteDatabase-CompactReason]: Compacting not required 2023-09-10 08:12:09 -04 - [Profiling-Timer.Begin-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteScalarInt64]: Starting - ExecuteScalarInt64: INSERT INTO "Remotevolume" ("OperationID", "Name", "Type", "State", "Size", "VerificationCount", "DeleteGraceTime") VALUES (38, "duplicati-b6587050dc3b146fa9cfcb1493aaf9751.dblock.zip", "Blocks", "Temporary", -1, 0, 0); SELECT last_insert_rowid(); 2023-09-10 08:12:09 -04 - [Profiling-Timer.Finished-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteScalarInt64]: ExecuteScalarInt64: INSERT INTO "Remotevolume" ("OperationID", "Name", "Type", "State", "Size", "VerificationCount", "DeleteGraceTime") VALUES (38, "duplicati-b6587050dc3b146fa9cfcb1493aaf9751.dblock.zip", "Blocks", "Temporary", -1, 0, 0); SELECT last_insert_rowid(); took 0:00:00:00.000 2023-09-10 08:12:09 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-b6587050dc3b146fa9cfcb1493aaf9751.dblock.zip (4.99 MB) 2023-09-10 08:12:09 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-b6587050dc3b146fa9cfcb1493aaf9751.dblock.zip (4.99 MB) 2023-09-10 08:12:10 -04 - [Profiling-Timer.Begin-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteScalarInt64]: Starting - ExecuteScalarInt64: INSERT INTO "Remotevolume" ("OperationID", "Name", "Type", "State", "Size", "VerificationCount", "DeleteGraceTime") VALUES (38, "duplicati-icebfdb6777d24dda8b75fed3787c71ac.dindex.zip", "Index", "Temporary", -1, 0, 0); SELECT last_insert_rowid(); 2023-09-10 08:12:10 -04 - [Profiling-Timer.Finished-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteScalarInt64]: ExecuteScalarInt64: INSERT INTO "Remotevolume" ("OperationID", "Name", "Type", "State", "Size", "VerificationCount", "DeleteGraceTime") VALUES (38, "duplicati-icebfdb6777d24dda8b75fed3787c71ac.dindex.zip", "Index", "Temporary", -1, 0, 0); SELECT last_insert_rowid(); took 0:00:00:00.000 2023-09-10 08:12:10 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-icebfdb6777d24dda8b75fed3787c71ac.dindex.zip (18.09 KB) 2023-09-10 08:12:10 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-icebfdb6777d24dda8b75fed3787c71ac.dindex.zip (18.09 KB) 2023-09-10 08:12:20 -04 - [Information-Duplicati.Library.Main.Operation.Backup.RecreateMissingIndexFiles-RecreateMissingIndexFile]: Re-creating missing index file for duplicati-b6587050dc3b146fa9cfcb1493aaf9751.dblock.zip 2023-09-10 08:12:20 -04 - [Profiling-Timer.Begin-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteScalarInt64]: Starting - ExecuteScalarInt64: INSERT INTO "Remotevolume" ("OperationID", "Name", "Type", "State", "Size", "VerificationCount", "DeleteGraceTime") VALUES (39, "duplicati-i0e19c49bd46b47fdafbb5bc0e2df893a.dindex.zip", "Index", "Temporary", -1, 0, 0); SELECT last_insert_rowid(); 2023-09-10 08:12:20 -04 - [Profiling-Timer.Finished-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteScalarInt64]: ExecuteScalarInt64: INSERT INTO "Remotevolume" ("OperationID", "Name", "Type", "State", "Size", "VerificationCount", "DeleteGraceTime") VALUES (39, "duplicati-i0e19c49bd46b47fdafbb5bc0e2df893a.dindex.zip", "Index", "Temporary", -1, 0, 0); SELECT last_insert_rowid(); took 0:00:00:00.000 2023-09-10 08:12:20 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-i0e19c49bd46b47fdafbb5bc0e2df893a.dindex.zip (2.29 KB) 2023-09-10 08:12:20 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-i0e19c49bd46b47fdafbb5bc0e2df893a.dindex.zip (2.29 KB) 2023-09-10 08:12:25 -04 - [Information-Duplicati.Library.Main.Database.LocalDeleteDatabase-CompactReason]: Compacting not required 2023-09-10 08:12:36 -04 - [Information-Duplicati.Library.Main.Database.LocalDeleteDatabase-CompactReason]: Compacting not required 2023-09-10 08:12:37 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-icebfdb6777d24dda8b75fed3787c71ac.dindex.zip (18.09 KB) 2023-09-10 08:12:37 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-icebfdb6777d24dda8b75fed3787c71ac.dindex.zip (18.09 KB) 2023-09-10 08:12:37 -04 - [Profiling-Timer.Begin-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteNonQuery]: Starting - ExecuteNonQuery: UPDATE "RemoteVolume" SET "VerificationCount" = MAX(1, CASE WHEN "VerificationCount" <= 0 THEN (SELECT MAX("VerificationCount") FROM "RemoteVolume") ELSE "VerificationCount" + 1 END) WHERE "Name" = "duplicati-icebfdb6777d24dda8b75fed3787c71ac.dindex.zip" 2023-09-10 08:12:37 -04 - [Profiling-Timer.Finished-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteNonQuery]: ExecuteNonQuery: UPDATE "RemoteVolume" SET "VerificationCount" = MAX(1, CASE WHEN "VerificationCount" <= 0 THEN (SELECT MAX("VerificationCount") FROM "RemoteVolume") ELSE "VerificationCount" + 1 END) WHERE "Name" = "duplicati-icebfdb6777d24dda8b75fed3787c71ac.dindex.zip" took 0:00:00:00.222 2023-09-10 08:13:06 -04 - [Information-Duplicati.Library.Main.Database.LocalDeleteDatabase-CompactReason]: Compacting because there are 1 fully deletable volume(s) 2023-09-10 08:13:44 -04 - [Information-Duplicati.Library.Main.Database.LocalDeleteDatabase-CompactReason]: Compacting not required 2023-09-10 08:14:16 -04 - [Information-Duplicati.Library.Main.Database.LocalDeleteDatabase-CompactReason]: Compacting because there is 34.15% wasted space and the limit is 25% 2023-09-10 08:14:24 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-i0e19c49bd46b47fdafbb5bc0e2df893a.dindex.zip (2.29 KB) 2023-09-10 08:14:24 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-i0e19c49bd46b47fdafbb5bc0e2df893a.dindex.zip (2.29 KB) 2023-09-10 08:14:24 -04 - [Profiling-Timer.Begin-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteNonQuery]: Starting - ExecuteNonQuery: UPDATE "RemoteVolume" SET "VerificationCount" = MAX(1, CASE WHEN "VerificationCount" <= 0 THEN (SELECT MAX("VerificationCount") FROM "RemoteVolume") ELSE "VerificationCount" + 1 END) WHERE "Name" = "duplicati-i0e19c49bd46b47fdafbb5bc0e2df893a.dindex.zip" 2023-09-10 08:14:25 -04 - [Profiling-Timer.Finished-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteNonQuery]: ExecuteNonQuery: UPDATE "RemoteVolume" SET "VerificationCount" = MAX(1, CASE WHEN "VerificationCount" <= 0 THEN (SELECT MAX("VerificationCount") FROM "RemoteVolume") ELSE "VerificationCount" + 1 END) WHERE "Name" = "duplicati-i0e19c49bd46b47fdafbb5bc0e2df893a.dindex.zip" took 0:00:00:00.184 2023-09-10 08:14:25 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-b6587050dc3b146fa9cfcb1493aaf9751.dblock.zip (4.99 MB) 2023-09-10 08:14:25 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-b6587050dc3b146fa9cfcb1493aaf9751.dblock.zip (4.99 MB) 2023-09-10 08:14:25 -04 - [Profiling-Timer.Begin-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteNonQuery]: Starting - ExecuteNonQuery: UPDATE "RemoteVolume" SET "VerificationCount" = MAX(1, CASE WHEN "VerificationCount" <= 0 THEN (SELECT MAX("VerificationCount") FROM "RemoteVolume") ELSE "VerificationCount" + 1 END) WHERE "Name" = "duplicati-b6587050dc3b146fa9cfcb1493aaf9751.dblock.zip" 2023-09-10 08:14:25 -04 - [Profiling-Timer.Finished-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteNonQuery]: ExecuteNonQuery: UPDATE "RemoteVolume" SET "VerificationCount" = MAX(1, CASE WHEN "VerificationCount" <= 0 THEN (SELECT MAX("VerificationCount") FROM "RemoteVolume") ELSE "VerificationCount" + 1 END) WHERE "Name" = "duplicati-b6587050dc3b146fa9cfcb1493aaf9751.dblock.zip" took 0:00:00:00.069 2023-09-10 08:14:57 -04 - [Information-Duplicati.Library.Main.Database.LocalDeleteDatabase-CompactReason]: Compacting not required 2023-09-10 08:15:08 -04 - [Information-Duplicati.Library.Main.Database.LocalDeleteDatabase-CompactReason]: Compacting not required 2023-09-10 08:15:43 -04 - [Information-Duplicati.Library.Main.Database.LocalDeleteDatabase-CompactReason]: Compacting not required 2023-09-10 08:16:14 -04 - [Information-Duplicati.Library.Main.Database.LocalDeleteDatabase-CompactReason]: Compacting not required 2023-09-10 08:16:49 -04 - [Information-Duplicati.Library.Main.Database.LocalDeleteDatabase-CompactReason]: Compacting because there is 28.32% wasted space and the limit is 25% 2023-09-10 08:16:50 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-b6587050dc3b146fa9cfcb1493aaf9751.dblock.zip (4.99 MB) 2023-09-10 08:16:50 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-b6587050dc3b146fa9cfcb1493aaf9751.dblock.zip (4.99 MB) 2023-09-10 08:16:51 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Delete - Started: duplicati-b6587050dc3b146fa9cfcb1493aaf9751.dblock.zip (4.99 MB) 2023-09-10 08:16:51 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Delete - Completed: duplicati-b6587050dc3b146fa9cfcb1493aaf9751.dblock.zip (4.99 MB) 2023-09-10 08:16:51 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Delete - Started: duplicati-i0e19c49bd46b47fdafbb5bc0e2df893a.dindex.zip (2.29 KB) 2023-09-10 08:16:51 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Delete - Completed: duplicati-i0e19c49bd46b47fdafbb5bc0e2df893a.dindex.zip (2.29 KB) 2023-09-10 08:16:52 -04 - [Profiling-Timer.Begin-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteNonQuery]: Starting - ExecuteNonQuery: UPDATE "RemoteVolume" SET "DeleteGraceTime" = 1694355412 WHERE "Name" = "duplicati-b6587050dc3b146fa9cfcb1493aaf9751.dblock.zip" 2023-09-10 08:16:52 -04 - [Profiling-Timer.Finished-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteNonQuery]: ExecuteNonQuery: UPDATE "RemoteVolume" SET "DeleteGraceTime" = 1694355412 WHERE "Name" = "duplicati-b6587050dc3b146fa9cfcb1493aaf9751.dblock.zip" took 0:00:00:00.000 2023-09-10 08:16:52 -04 - [Profiling-Timer.Begin-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteNonQuery]: Starting - ExecuteNonQuery: UPDATE "RemoteVolume" SET "DeleteGraceTime" = 1694355412 WHERE "Name" = "duplicati-i0e19c49bd46b47fdafbb5bc0e2df893a.dindex.zip" 2023-09-10 08:16:52 -04 - [Profiling-Timer.Finished-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteNonQuery]: ExecuteNonQuery: UPDATE "RemoteVolume" SET "DeleteGraceTime" = 1694355412 WHERE "Name" = "duplicati-i0e19c49bd46b47fdafbb5bc0e2df893a.dindex.zip" took 0:00:00:00.000 2023-09-10 08:16:52 -04 - [Profiling-Timer.Begin-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteScalarInt64]: Starting - ExecuteScalarInt64: SELECT "ID" FROM "Remotevolume" WHERE "Name" = "duplicati-b6587050dc3b146fa9cfcb1493aaf9751.dblock.zip" 2023-09-10 08:16:52 -04 - [Profiling-Timer.Finished-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteScalarInt64]: ExecuteScalarInt64: SELECT "ID" FROM "Remotevolume" WHERE "Name" = "duplicati-b6587050dc3b146fa9cfcb1493aaf9751.dblock.zip" took 0:00:00:00.000 2023-09-10 08:16:52 -04 - [Profiling-Timer.Begin-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteScalarInt64]: Starting - ExecuteScalarInt64: SELECT "ID" FROM "Remotevolume" WHERE "Name" = "duplicati-i0e19c49bd46b47fdafbb5bc0e2df893a.dindex.zip" 2023-09-10 08:16:52 -04 - [Profiling-Timer.Finished-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteScalarInt64]: ExecuteScalarInt64: SELECT "ID" FROM "Remotevolume" WHERE "Name" = "duplicati-i0e19c49bd46b47fdafbb5bc0e2df893a.dindex.zip" took 0:00:00:00.000 2023-09-10 08:17:11 -04 - [Information-Duplicati.Library.Main.Database.LocalDeleteDatabase-CompactReason]: Compacting not required ``` Notable moments: ``` 2023-09-10 08:12:09 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-b6587050dc3b146fa9cfcb1493aaf9751.dblock.zip (4.99 MB) 2023-09-10 08:12:10 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-icebfdb6777d24dda8b75fed3787c71ac.dindex.zip (18.09 KB) 2023-09-10 08:12:20 -04 - [Information-Duplicati.Library.Main.Operation.Backup.RecreateMissingIndexFiles-RecreateMissingIndexFile]: Re-creating missing index file for duplicati-b6587050dc3b146fa9cfcb1493aaf9751.dblock.zip 2023-09-10 08:12:20 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-i0e19c49bd46b47fdafbb5bc0e2df893a.dindex.zip (2.29 KB) Running backup at 2023-09-10 08:12:31.811753 Exit code 0 duplicati-icebfdb6777d24dda8b75fed3787c71ac.dindex.zip 2023-09-10 08:16:49 -04 - [Information-Duplicati.Library.Main.Database.LocalDeleteDatabase-CompactReason]: Compacting because there is 28.32% wasted space and the limit is 25% 2023-09-10 08:16:51 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Delete - Completed: duplicati-b6587050dc3b146fa9cfcb1493aaf9751.dblock.zip (4.99 MB) 2023-09-10 08:16:51 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Delete - Completed: duplicati-i0e19c49bd46b47fdafbb5bc0e2df893a.dindex.zip (2.29 KB) Running backup at 2023-09-10 08:17:06.831278 Exit code 0 duplicati-icebfdb6777d24dda8b75fed3787c71ac.dindex.zip Running recreate at 2023-09-10 08:17:13.263109 Running repair at 2023-09-10 08:17:13.263109 Exit code 0 Remote file referenced as duplicati-b6587050dc3b146fa9cfcb1493aaf9751.dblock.zip by duplicati-icebfdb6777d24dda8b75fed3787c71ac.dindex.zip, but not found in list, registering a missing remote file ``` ## Steps to reproduce 1. Well, there's a still-changing test script `timeout5.py` for Windows that I can provide and explain for someone if they're interested. - **Actual result**: Error, although at least in standalone recreate (rather than restore) it looks like it wasn't fatal. Workaround = hide or delete that file. - **Expected result**: No error ## Screenshots ## Debug log

Essentially it is caused by an interrupted file upload which leaves the database in an incorrect state. The next backup recovers from the interruption, but it leaves the index file with a broken reference.