Recreate DB: missing remote files

[avmaksimov]

Hello to everyone! I did recreated DB, but it returned 16 errors:
* 2020-08-02 16:19:52 +03 - [Error-Duplicati.Library.Main.Operation.RecreateDatabaseHandler-MissingFileDetected]: Remote file referenced as duplicati-bc4bb6a751e094c5db5ab15b7dfb3c862.dblock.zip.aes by duplicati-i0492aee415b541c7be4385a8a6d5bd17.dindex.zip.aes, but not found in list, registering a missing remote file
* 2020-08-02 16:19:52 +03 - [Error-Duplicati.Library.Main.Operation.RecreateDatabaseHandler-IndexFileProcessingFailed]: Failed to process index file: duplicati-i0492aee415b541c7be4385a8a6d5bd17.dindex.zip.aes
* 2020-08-02 16:19:58 +03 - [Error-Duplicati.Library.Main.Operation.RecreateDatabaseHandler-MissingFileDetected]: Remote file referenced as duplicati-bc675105f6ecd4af49dd7df5bba286e0a.dblock.zip.aes by duplicati-i25dc76241cd949fe830e8ef226f9e672.dindex.zip.aes, but not found in list, registering a missing remote file
* 2020-08-02 16:19:58 +03 - [Error-Duplicati.Library.Main.Operation.RecreateDatabaseHandler-IndexFileProcessingFailed]: Failed to process index file: duplicati-i25dc76241cd949fe830e8ef226f9e672.dindex.zip.aes
* 2020-08-02 16:19:59 +03 - [Error-Duplicati.Library.Main.Operation.RecreateDatabaseHandler-MissingFileDetected]: Remote file referenced as duplicati-be9a1d5977d734438a9aec3d858fd15e2.dblock.zip.aes by duplicati-i2ded0858922b4cf1982ad5a8f97cce6e.dindex.zip.aes, but not found in list, registering a missing remote file
* 2020-08-02 16:19:59 +03 - [Error-Duplicati.Library.Main.Operation.RecreateDatabaseHandler-IndexFileProcessingFailed]: Failed to process index file: duplicati-i2ded0858922b4cf1982ad5a8f97cce6e.dindex.zip.aes
* 2020-08-02 16:20:43 +03 - [Error-Duplicati.Library.Main.Operation.RecreateDatabaseHandler-MissingFileDetected]: Remote file referenced as duplicati-b836c6b1fc51f446f952e88150d8c3552.dblock.zip.aes by duplicati-ib24de6fc1eb549cea1288cda77e59a28.dindex.zip.aes, but not found in list, registering a missing remote file
* 2020-08-02 16:20:43 +03 - [Error-Duplicati.Library.Main.Operation.RecreateDatabaseHandler-IndexFileProcessingFailed]: Failed to process index file: duplicati-ib24de6fc1eb549cea1288cda77e59a28.dindex.zip.aes
* 2020-08-02 16:20:47 +03 - [Error-Duplicati.Library.Main.Operation.RecreateDatabaseHandler-MissingFileDetected]: Remote file referenced as duplicati-bf58f9fb2cb30442a830250e9d2b54723.dblock.zip.aes by duplicati-ibcb99ba254a04389aa7deddbe9af1157.dindex.zip.aes, but not found in list, registering a missing remote file
* 2020-08-02 16:20:47 +03 - [Error-Duplicati.Library.Main.Operation.RecreateDatabaseHandler-IndexFileProcessingFailed]: Failed to process index file: duplicati-ibcb99ba254a04389aa7deddbe9af1157.dindex.zip.aes
* 2020-08-02 16:20:52 +03 - [Error-Duplicati.Library.Main.Operation.RecreateDatabaseHandler-MissingFileDetected]: Remote file referenced as duplicati-b3429ce15096d45b1975fe607cd5b1d84.dblock.zip.aes by duplicati-ic888fcda76224cd28e54ac6b9ab74180.dindex.zip.aes, but not found in list, registering a missing remote file
* 2020-08-02 16:20:52 +03 - [Error-Duplicati.Library.Main.Operation.RecreateDatabaseHandler-IndexFileProcessingFailed]: Failed to process index file: duplicati-ic888fcda76224cd28e54ac6b9ab74180.dindex.zip.aes
* 2020-08-02 16:20:56 +03 - [Error-Duplicati.Library.Main.Operation.RecreateDatabaseHandler-MissingFileDetected]: Remote file referenced as duplicati-b9b86a34be5274535ae22d0d6cf75ef0a.dblock.zip.aes by duplicati-ice7e59de55294108b2c2af5e1c57e869.dindex.zip.aes, but not found in list, registering a missing remote file
* 2020-08-02 16:20:56 +03 - [Error-Duplicati.Library.Main.Operation.RecreateDatabaseHandler-IndexFileProcessingFailed]: Failed to process index file: duplicati-ice7e59de55294108b2c2af5e1c57e869.dindex.zip.aes
* 2020-08-02 16:21:13 +03 - [Error-Duplicati.Library.Main.Operation.RecreateDatabaseHandler-MissingFileDetected]: Remote file referenced as duplicati-b018f315f416a4576b9d243fdc4868b3b.dblock.zip.aes by duplicati-ife7bcec1593e4e7eb005431cea50e81c.dindex.zip.aes, but not found in list, registering a missing remote file
* 2020-08-02 16:21:13 +03 - [Error-Duplicati.Library.Main.Operation.RecreateDatabaseHandler-IndexFileProcessingFailed]: Failed to process index file: duplicati-ife7bcec1593e4e7eb005431cea50e81c.dindex.zip.aes

I didn’t find this files. But the way, storage is local.After I did “Verify files” and all was OK. Repair and backup all good. But I don’t understand, why this error appears? How can I solve it?

[ts678]

@avmaksimov

I didn’t find this files.

Presumably you refer to the “missing remote files”, which are the dblock files not the dindex files.
While you got 16 error messages, you can see that they’re in pairs, basically about 8 missing files.

@avmaksimov

I did “Verify files” and all was OK

Does “Verify files” full verify all files? explained how this isn’t all files unless you ask for all. Did you?

@avmaksimov

But the way, storage is local.

This could make the initial survey easier. Can you count dblock then dindex files, e.g. File Explorer
file:dindex to get them on the screen, then Control-A to select them and put count in bottom left?

@avmaksimov

But I don’t understand, why this error appears?

Normally there is one dindex file per dblock file, but I suspect this got unbalanced with 8 extra dindex.

403 error during compact forgot a dindex file deletion, getting Missing file error next run. #4129
is one (highly technical) possible answer to your question. There, Compacting files at the backend hit destination error midway through cleanup at end of compact cycle, resulting in undeleted dindex files.

The problem with this as the answer is that your local destination would seem unlikely to give an error.
Still, it should be easy to see if you have more dindex files than dblock files, then studies can continue.

Did you happen to save a copy of the Database before Recreate, or have your own log-file configured?
Explaining any “why” for a specific case such as yours may need some history. Is there anything now?

[avmaksimov]

Thank you for your answering. Yes, I see 8 extra dindex files (343 dblock, 351 dindex and 3 dlist).

I Verified files with parameter All and without --full-remore-verification and it got this results (except records without errors):
…
Downloading file (829 bytes) …
Downloading file (80,31 KB) …
Failed to process file duplicati-i0492aee415b541c7be4385a8a6d5bd17.dindex.zip.aes => Invalid JSON, expected “String”, but got Null,
Downloading file (121,89 KB) …
Downloading file (35,06 KB) …
…
Downloading file (829 bytes) …
Downloading file (29,23 KB) …
Failed to process file duplicati-i25dc76241cd949fe830e8ef226f9e672.dindex.zip.aes => Invalid JSON, expected “String”, but got Null,
Downloading file (198,42 KB) …
Downloading file (55,76 KB) …
Downloading file (35,06 KB) …
Downloading file (829 bytes) …
Downloading file (73,67 KB) …
Failed to process file duplicati-i2ded0858922b4cf1982ad5a8f97cce6e.dindex.zip.aes => Invalid JSON, expected “String”, but got Null,
Downloading file (1,37 KB) …
Downloading file (129,45 KB) …
…
Downloading file (112,51 KB) …
Downloading file (829 bytes) …
Downloading file (35,81 KB) …
Failed to process file duplicati-ib24de6fc1eb549cea1288cda77e59a28.dindex.zip.aes => Invalid JSON, expected “String”, but got Null,
Downloading file (35,04 KB) …
Downloading file (179,39 KB) …
Downloading file (172,48 KB) …
Downloading file (170,22 KB) …
Downloading file (136,31 KB) …
Downloading file (35,04 KB) …
Downloading file (35,04 KB) …
Downloading file (54,34 KB) …
Downloading file (31,97 KB) …
Downloading file (36,03 KB) …
Downloading file (35,06 KB) …
Downloading file (30,12 KB) …
Downloading file (145,22 KB) …
Downloading file (46,11 KB) …
Downloading file (72,76 KB) …
Downloading file (98,14 KB) …
Downloading file (829 bytes) …
Downloading file (39,98 KB) …
Failed to process file duplicati-ibcb99ba254a04389aa7deddbe9af1157.dindex.zip.aes => Invalid JSON, expected “String”, but got Null,
Downloading file (36,47 KB) …
Downloading file (36,28 KB) …
Downloading file (36,61 KB) …
Downloading file (69,23 KB) …
Downloading file (133,26 KB) …
Downloading file (35,04 KB) …
Downloading file (34,70 KB) …
Downloading file (36,73 KB) …
Downloading file (36,97 KB) …
Downloading file (140,73 KB) …
Downloading file (103,54 KB) …
Downloading file (146,93 KB) …
Downloading file (68,70 KB) …
Downloading file (81,48 KB) …
Downloading file (35,03 KB) …
Downloading file (137,93 KB) …
Downloading file (116,76 KB) …
Downloading file (73,67 KB) …
Downloading file (829 bytes) …
Downloading file (127,61 KB) …
Failed to process file duplicati-ic888fcda76224cd28e54ac6b9ab74180.dindex.zip.aes => Invalid JSON, expected “String”, but got Null,
Downloading file (38,28 KB) …
Downloading file (82,97 KB) …
Downloading file (145,58 KB) …
Downloading file (69,23 KB) …
Downloading file (85,81 KB) …
Downloading file (73,73 KB) …
Downloading file (81,03 KB) …
Downloading file (204,22 KB) …
Downloading file (128,20 KB) …
Downloading file (69,25 KB) …
Downloading file (829 bytes) …
Downloading file (10,25 KB) …
Failed to process file duplicati-ice7e59de55294108b2c2af5e1c57e869.dindex.zip.aes => Invalid JSON, expected “String”, but got Null,
Downloading file (80,01 KB) …
Downloading file (36,34 KB) …
Downloading file (88,25 KB) …
…

And I forgot to write a warning with 16 errors:
Warnings 1

* 2020-08-02 16:21:15 +03 - [Warning-Duplicati.Library.Main.Database.LocalRecreateDatabase-MissingVolumesDetected]: Found 8 missing volumes; attempting to replace blocks from existing volumes

So problem in only eight dindex files. May be better to delete them? But why D2 can’t do it for example when compacting files?

[ts678]

@avmaksimov

May be better to delete them?

Essentially, however to be extra safe it would be better to move them completely outside of the Duplicati folder, or if you prefer, hide them from Duplicati by adding another prefix on filenames, such as hidden-

After getting them out of the way, see if you can get a clean Recreate.

I don’t know what’s causing the 7 JSON complaints, but they’re in the 8 files that are “extra”, so should go away with those files. duplicati-ife7bcec1593e4e7eb005431cea50e81c.dindex.zip.aes got no JSON error.

@avmaksimov

But why D2 can’t do it for example when compacting files?

Code is human-written, and error-handling only handles expected errors. I suppose this wasn’t expected.

What’s supposed to happen normally is that dblock and dindex of compacted wasted space are deleted. What actually happened (in my issue – yours is unclear) was an error on deletes which stopped partway. Dblock files were left in a state that next backup would finish delete. The dindex were not set up that way.

Proposal

I wonder if this would have ended better if the dindex files had also been marked Deleting , so they wouldn’t be complaining?

(however there is an additional part of the problem that causes missing files errors for what was deleted, because it forgets it deleted them – possibly the “mark” fix isn’t required if the “forget” problem gets fixed)

Adding clean-up code that deletes things must also be done very carefully to avoid making issues worse. Here we relied on a huge amount of manual analysis and thought about situation first. I said there’s a bug (which I linked to) that can allow the problem situation to happen, and that bug should be fixed. It appears you have no old logs, emails, reports, or databases to tell if yours is explainable by known issue. Do you?

[avmaksimov]

No , I haven’t any logs, dbs and so on… But after I moved all eight files I make “Verify all”, got message with error and suggest to repair db. All was OK. After I ran Recreate and all was OK again. So I think, the problem is solved. So big thank you for all!!!