Recovering from message alteration

obones · December 23, 2021, 2:43pm

Hello,

I’ve been using duplicati for well over 2 years now and it has been working flawlessly for most of that time.
However, lately, one of my backup is oscillating between two possible failures. It starts with this one:

System.Security.Cryptography.CryptographicException: Échec du déchiffrement des données (phrase de passe invalide ?) : Message has been altered, do not trust content ---> SharpAESCrypt.SharpAESCrypt+HashMismatchException: Message has been altered, do not trust content
at SharpAESCrypt.SharpAESCrypt.Read (System.Byte[] buffer, System.Int32 offset, System.Int32 count) [0x00405] in <45c43198e80545aeabaa9b98839b4c7d>:0
at Duplicati.Library.Utility.Utility.CopyStream (System.IO.Stream source, System.IO.Stream target, System.Boolean tryRewindSource, System.Byte[] buf) [0x0003d] in <d644d641ef094b6cbc223bc3a32d53af>:0
at Duplicati.Library.Encryption.EncryptionBase.Decrypt (System.IO.Stream input, System.IO.Stream output) [0x00008] in <2b32bf2e4cc54065bffbbfc47a2d790b>:0

And the next time it runs, it tells me this:

Listing remote folder ...
Missing file: duplicati-id9096b06dc224039a7b4d911b2f30394.dindex.zip.aes
Missing file: duplicati-i884f49b617984697847b9d4074ea19a8.dindex.zip.aes
Missing file: duplicati-i715abaa8432e4244a4e5902b17b956da.dindex.zip.aes
Missing file: duplicati-i6dd1fb1d292c40b3a354b2078f4d7117.dindex.zip.aes
Found 4 files that are missing from the remote storage, please run repair
Fatal error => Found 4 files that are missing from the remote storage, please run repair

If I run repair, it uploads the missing files but then the next run goes back to the first kind of error.

I have read numerous messages here and it seems this is a situation very hard to recover from.
I could trash the entire B2 destination and start anew but I’d like to identify the reason why this happened so that I can prevent it from ever happening again.

What transpired from other threads here is that this could come from faulty RAM modules but shouldn’t duplicati try to work around this? I mean, once it has created and encrypted a block, couldn’t it keep it in RAM and immediately try to read it? This would make sure a different area of memory is used and should increase the probability of finding a corrupted file before it gets stored on the remote backend.
Maybe there already is an option for that, but I could not identify it.

duplicati --help gives me this:

Version:  2.0.6.100_canary_2021-08-11

and I’m runing with mono on an Arch Linux server.

Thanks in advance for your help and suggestions.

drwtsn32 · December 24, 2021, 7:03pm

I don’t think that is necessary, better to identify the root cause.

I guess that’s one possibility, but I would expect faulty RAM to cause all sorts of random issues on your machine… destabilizing other software, crashing the OS, etc. It wouldn’t hurt to run a good RAM testing utility though, like memtest86. Also, I would run good hard drive diagnostics that test the surface of your disk for media errors.

By default the hard drive is used to store the volumes, not RAM, unless you have set up a RAM drive I guess? If I understand the process correctly, after the volume is written, Duplicati re-reads it to calculate the hash before uploading to the back end. Due to all the error handling built in to TCP/IP, I doubt you’d get corruption during transfer to B2. And once the file is in B2 it is extremely unlike to be corrupted there - like most cloud providers, the storage is highly resilient.

So yeah I guess that’s where I’d start: thoroughly test RAM and HDD to make sure there are no issues that could be introducing corruption.

ts678 · December 25, 2021, 10:37pm

There are also Duplicati-level tests you can do, and history that has at least some chance of relevance.

Then you were using it when network throttling could sometimes cause hard-to-spot file corruptions on upload, however routine destination file verification should have run into such any such files unless you turned that off. Never using any network throttling would also destroy the theory, but I mention it anyway.

Any idea where in backup that is (e.g. what does Duplicati status bar show)? Symptoms might be from Deleting unwanted files deciding to do a compact which then chokes on a bad file and loses track. There’s an issue open on that, but there’s not enough information here (yet) to know if your timeline fits.

To get a good look at the failure, you can open a tab to About → Show log → Live → Information and run. Alternatively, you might be able to watch while testing with the Compact now and Verify files buttons.

If you can get names of files that are damaged, then the dates and contents can be looked at. Checking everything is possible with the test command and URL from Export As Command-line, but because B2 charges for downloads, maybe a better place to start is to focus only on files that actually appeared bad.

If you just have a few files that are well-proven to be damaged, those can be deleted at the cost of some versions of some unlucky source files whose data happened to be in those. Recovering by purging files.

Might not get root cause (keep testing other things), but topic subject did say “Recovering”, so I mention.

There are fancier things possible once names are known, for example the database has records of files, although log file is more reliable because the database also discards records when things error midway:

github.com/duplicati/duplicati

Error during compact forgot a dindex file deletion, getting Missing file error next run.

opened 01:08AM - 07 Mar 20 UTC

closed 08:57PM - 21 Sep 23 UTC

ts678

bug backup corruption local database issue

- [x] I have searched open and closed issues for duplicates. ----------------…------------------------ ## Environment info - **Duplicati version**: 2.0.5.1 Beta - **Operating system**: Windows 10 Version 1909 - **Backend**: Google Drive ## Description Fatal error "Found 1 files that are missing from the remote storage, please run repair" at start of regular hourly backup after previous backup failed with "The remote server returned an error: (403) Forbidden." Looking into the databases (I keep a DB history via --run-script-before), the 403 left the DB corrupted. Remote data and profiling log indicate that compact deleted a dblock file and its dindex, however the DB RemoteOperation table lacks those rows (and everything after) for this backup, and Remotevolume table wrongly says that dindex should still be there, yet somehow rightly says that dblock should not... Emails on these were: ``` Failed: The remote server returned an error: (403) Forbidden. Details: System.Net.WebException: The remote server returned an error: (403) Forbidden. at Duplicati.Library.Main.AsyncDownloader.AsyncDownloaderEnumerator.AsyncDownloadedFile.get_TempFile() at Duplicati.Library.Main.Operation.CompactHandler.DoCompact(LocalDeleteDatabase db, Boolean hasVerifiedBackend, IDbTransaction& transaction, BackendManager sharedBackend) at Duplicati.Library.Main.Operation.DeleteHandler.DoRun(LocalDeleteDatabase db, IDbTransaction& transaction, Boolean hasVerifiedBacked, Boolean forceCompact, BackendManager sharedManager) at Duplicati.Library.Main.Operation.BackupHandler.CompactIfRequired(BackendManager backend, Int64 lastVolumeSize) at Duplicati.Library.Main.Operation.BackupHandler.<RunAsync>d__20.MoveNext() --- End of stack trace from previous location where exception was thrown --- at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at CoCoL.ChannelExtensions.WaitForTaskOrThrow(Task task) at Duplicati.Library.Main.Controller.<>c__DisplayClass14_0.<Backup>b__0(BackupResults result) at Duplicati.Library.Main.Controller.RunAction[T](T result, String[]& paths, IFilter& filter, Action`1 method) Log data: 2020-03-03 13:02:17 -05 - [Error-Duplicati.Library.Main.Operation.BackupHandler-FatalError]: Fatal error System.Net.WebException: The remote server returned an error: (403) Forbidden. at Duplicati.Library.Main.AsyncDownloader.AsyncDownloaderEnumerator.AsyncDownloadedFile.get_TempFile() at Duplicati.Library.Main.Operation.CompactHandler.DoCompact(LocalDeleteDatabase db, Boolean hasVerifiedBackend, IDbTransaction& transaction, BackendManager sharedBackend) at Duplicati.Library.Main.Operation.DeleteHandler.DoRun(LocalDeleteDatabase db, IDbTransaction& transaction, Boolean hasVerifiedBacked, Boolean forceCompact, BackendManager sharedManager) at Duplicati.Library.Main.Operation.BackupHandler.CompactIfRequired(BackendManager backend, Int64 lastVolumeSize) at Duplicati.Library.Main.Operation.BackupHandler.<RunAsync>d__20.MoveNext() ``` then ``` Failed: Found 1 files that are missing from the remote storage, please run repair Details: Duplicati.Library.Interface.UserInformationException: Found 1 files that are missing from the remote storage, please run repair at Duplicati.Library.Main.Operation.FilelistProcessor.VerifyRemoteList(BackendManager backend, Options options, LocalDatabase database, IBackendWriter log, String protectedfile) at Duplicati.Library.Main.Operation.BackupHandler.PreBackupVerify(BackendManager backend, String protectedfile) at Duplicati.Library.Main.Operation.BackupHandler.<RunAsync>d__20.MoveNext() --- End of stack trace from previous location where exception was thrown --- at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at CoCoL.ChannelExtensions.WaitForTaskOrThrow(Task task) at Duplicati.Library.Main.Controller.<>c__DisplayClass14_0.<Backup>b__0(BackupResults result) at Duplicati.Library.Main.Controller.RunAction[T](T result, String[]& paths, IFilter& filter, Action`1 method) Log data: 2020-03-03 13:40:30 -05 - [Warning-Duplicati.Library.Main.Operation.FilelistProcessor-MissingFile]: Missing file: duplicati-i3e3b4e6d1bda4b75bf950caec7755556.dindex.zip.aes 2020-03-03 13:40:30 -05 - [Error-Duplicati.Library.Main.Operation.FilelistProcessor-MissingRemoteFiles]: Found 1 files that are missing from the remote storage, please run repair 2020-03-03 13:40:30 -05 - [Error-Duplicati.Library.Main.Operation.BackupHandler-FatalError]: Fatal error Duplicati.Library.Interface.UserInformationException: Found 1 files that are missing from the remote storage, please run repair at Duplicati.Library.Main.Operation.FilelistProcessor.VerifyRemoteList(BackendManager backend, Options options, LocalDatabase database, IBackendWriter log, String protectedfile) at Duplicati.Library.Main.Operation.BackupHandler.PreBackupVerify(BackendManager backend, String protectedfile) at Duplicati.Library.Main.Operation.BackupHandler.<RunAsync>d__20.MoveNext() ``` I'm not seeking to get this going soon, but will leave it alone for awhile for an analysis of the situation. This job was intentionally set with --number-of-retries=1 in the hope that a transient issue would error. I don't know where the 403 is from (possibly OAuth needing a token refresh?), but that seems to have done the breakage job. Possibly a compact operation is more sensitive than other spots in the backup? ## Steps to reproduce EDIT 1: See the Mar 14, 2020 "Developed steps to reproduce this issue well." [post below](https://github.com/duplicati/duplicati/issues/4129#issuecomment-599149786). Also note that this seems to be being reported in the forum more. See references from forum below [starting](https://github.com/duplicati/duplicati/issues/4129#issuecomment-1079014706) at Mar 25, 2022. Original Mar 6 2020 steps to reproduce were "Not really known" as noted below. 1. Not really known. You could try to arrange for a download error during second round of dblock downloads, to see if it will mess with the dblock+dindex delete that came after the first round of dblock downloads and the repackaged dblock+dindex uploads. 2. After above damage, run another backup. The one here was automatic by the same TrayIcon run. - **Actual result**: Failed: Found 1 files that are missing from the remote storage, please run repair - **Expected result**: Recovers and does backup. ## Screenshots ## Debug log Here are the bug report files for DB dated 12:56 PM (email was sent later at 13:02 though) and 13:40 PM. [bugreport.20190303_1256.zip](https://github.com/duplicati/duplicati/files/4301108/bugreport.20190303_1256.zip) [bugreport.20190303_1340.zip](https://github.com/duplicati/duplicati/files/4301112/bugreport.20190303_1340.zip) Here's the ending: ``` 2020-03-03 13:40:30 -05 - [Warning-Duplicati.Library.Main.Operation.FilelistProcessor-MissingFile]: Missing file: duplicati-i3e3b4e6d1bda4b75bf950caec7755556.dindex.zip.aes 2020-03-03 13:40:30 -05 - [Error-Duplicati.Library.Main.Operation.FilelistProcessor-MissingRemoteFiles]: Found 1 files that are missing from the remote storage, please run repair 2020-03-03 13:40:30 -05 - [Profiling-Timer.Finished-Duplicati.Library.Main.Operation.BackupHandler-PreBackupVerify]: PreBackupVerify took 0:00:00:08.333 2020-03-03 13:40:30 -05 - [Error-Duplicati.Library.Main.Operation.BackupHandler-FatalError]: Fatal error Duplicati.Library.Interface.UserInformationException: Found 1 files that are missing from the remote storage, please run repair at Duplicati.Library.Main.Operation.FilelistProcessor.VerifyRemoteList(BackendManager backend, Options options, LocalDatabase database, IBackendWriter log, String protectedfile) at Duplicati.Library.Main.Operation.BackupHandler.PreBackupVerify(BackendManager backend, String protectedfile) at Duplicati.Library.Main.Operation.BackupHandler.<RunAsync>d__20.MoveNext() 2020-03-03 13:40:30 -05 - [Profiling-Timer.Begin-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteNonQuery]: Starting - ExecuteNonQuery: PRAGMA optimize 2020-03-03 13:40:30 -05 - [Profiling-Timer.Finished-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteNonQuery]: ExecuteNonQuery: PRAGMA optimize took 0:00:00:00.000 2020-03-03 13:40:30 -05 - [Profiling-Timer.Finished-Duplicati.Library.Main.Controller-RunBackup]: Running Backup took 0:00:00:30.736 ``` Here's the compact and the 403: ``` 2020-03-03 12:42:05 -05 - [Information-Duplicati.Library.Main.Database.LocalDeleteDatabase-CompactReason]: Compacting because there is 25.24% wasted space and the limit is 25% 2020-03-03 12:42:05 -05 - [Profiling-Timer.Begin-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteScalarInt64]: Starting - ExecuteScalarInt64: INSERT INTO "Remotevolume" ("OperationID", "Name", "Type", "State", "Size", "VerificationCount", "DeleteGraceTime") VALUES (881, "duplicati-bbcbd4187d9cb48b0a22b0fe91722aa0b.dblock.zip.aes", "Blocks", "Temporary", -1, 0, 0); SELECT last_insert_rowid(); 2020-03-03 12:42:05 -05 - [Profiling-Timer.Finished-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteScalarInt64]: ExecuteScalarInt64: INSERT INTO "Remotevolume" ("OperationID", "Name", "Type", "State", "Size", "VerificationCount", "DeleteGraceTime") VALUES (881, "duplicati-bbcbd4187d9cb48b0a22b0fe91722aa0b.dblock.zip.aes", "Blocks", "Temporary", -1, 0, 0); SELECT last_insert_rowid(); took 0:00:00:00.000 2020-03-03 12:42:05 -05 - [Profiling-Timer.Begin-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteScalarInt64]: Starting - ExecuteScalarInt64: INSERT INTO "Remotevolume" ("OperationID", "Name", "Type", "State", "Size", "VerificationCount", "DeleteGraceTime") VALUES (881, "duplicati-i15817fa246ab4f64b5e441d84bafcfe2.dindex.zip.aes", "Index", "Temporary", -1, 0, 0); SELECT last_insert_rowid(); 2020-03-03 12:42:05 -05 - [Profiling-Timer.Finished-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteScalarInt64]: ExecuteScalarInt64: INSERT INTO "Remotevolume" ("OperationID", "Name", "Type", "State", "Size", "VerificationCount", "DeleteGraceTime") VALUES (881, "duplicati-i15817fa246ab4f64b5e441d84bafcfe2.dindex.zip.aes", "Index", "Temporary", -1, 0, 0); SELECT last_insert_rowid(); took 0:00:00:00.000 2020-03-03 12:42:05 -05 - [Profiling-Timer.Begin-Duplicati.Library.Main.BackendManager-RemoteOperationNothing]: Starting - RemoteOperationNothing 2020-03-03 12:42:05 -05 - [Profiling-Timer.Finished-Duplicati.Library.Main.BackendManager-RemoteOperationNothing]: RemoteOperationNothing took 0:00:00:00.000 2020-03-03 12:42:05 -05 - [Profiling-Timer.Begin-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteReader]: Starting - ExecuteReader: SELECT "C"."Name", "B"."Name", "B"."Hash", "B"."Size" FROM "IndexBlockLink" A, "RemoteVolume" B, "RemoteVolume" C WHERE "A"."IndexVolumeID" = "B"."ID" AND "A"."BlockVolumeID" = "C"."ID" AND "B"."Hash" IS NOT NULL AND "B"."Size" IS NOT NULL 2020-03-03 12:42:05 -05 - [Profiling-Timer.Finished-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteReader]: ExecuteReader: SELECT "C"."Name", "B"."Name", "B"."Hash", "B"."Size" FROM "IndexBlockLink" A, "RemoteVolume" B, "RemoteVolume" C WHERE "A"."IndexVolumeID" = "B"."ID" AND "A"."BlockVolumeID" = "C"."ID" AND "B"."Hash" IS NOT NULL AND "B"."Size" IS NOT NULL took 0:00:00:00.000 2020-03-03 12:42:05 -05 - [Profiling-Timer.Begin-Duplicati.Library.Main.BackendManager-RemoteOperationGet]: Starting - RemoteOperationGet 2020-03-03 12:42:05 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-b50fa9e71ec3c4a30a5cf1a769840259b.dblock.zip.aes (50.05 MB) 2020-03-03 12:46:23 -05 - [Profiling-Duplicati.Library.Main.BackendManager-DownloadSpeed]: Downloaded and decrypted 50.05 MB in 00:04:17.9420016, 198.67 KB/s 2020-03-03 12:46:23 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-b50fa9e71ec3c4a30a5cf1a769840259b.dblock.zip.aes (50.05 MB) 2020-03-03 12:46:23 -05 - [Profiling-Timer.Finished-Duplicati.Library.Main.BackendManager-RemoteOperationGet]: RemoteOperationGet took 0:00:04:17.942 2020-03-03 12:46:23 -05 - [Profiling-Timer.Begin-Duplicati.Library.Main.BackendManager-RemoteOperationGet]: Starting - RemoteOperationGet 2020-03-03 12:46:23 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-b52e9039635314dfdb0cc00d7d38bff00.dblock.zip.aes (43.42 MB) 2020-03-03 12:50:08 -05 - [Profiling-Duplicati.Library.Main.BackendManager-DownloadSpeed]: Downloaded and decrypted 43.42 MB in 00:03:44.8483951, 197.75 KB/s 2020-03-03 12:50:08 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-b52e9039635314dfdb0cc00d7d38bff00.dblock.zip.aes (43.42 MB) 2020-03-03 12:50:08 -05 - [Profiling-Timer.Finished-Duplicati.Library.Main.BackendManager-RemoteOperationGet]: RemoteOperationGet took 0:00:03:44.848 2020-03-03 12:50:08 -05 - [Profiling-Timer.Begin-Duplicati.Library.Main.BackendManager-RemoteOperationGet]: Starting - RemoteOperationGet 2020-03-03 12:50:08 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-b2a3eb954e16f422cae85fe3202b56fe2.dblock.zip.aes (20.94 MB) 2020-03-03 12:51:59 -05 - [Profiling-Duplicati.Library.Main.BackendManager-DownloadSpeed]: Downloaded and decrypted 20.94 MB in 00:01:51.3706484, 192.54 KB/s 2020-03-03 12:51:59 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-b2a3eb954e16f422cae85fe3202b56fe2.dblock.zip.aes (20.94 MB) 2020-03-03 12:51:59 -05 - [Profiling-Timer.Finished-Duplicati.Library.Main.BackendManager-RemoteOperationGet]: RemoteOperationGet took 0:00:01:51.370 2020-03-03 12:52:00 -05 - [Profiling-Timer.Begin-Duplicati.Library.Main.BackendManager-RemoteOperationPut]: Starting - RemoteOperationPut 2020-03-03 12:52:00 -05 - [Profiling-Timer.Begin-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteScalarInt64]: Starting - ExecuteScalarInt64: INSERT INTO "Remotevolume" ("OperationID", "Name", "Type", "State", "Size", "VerificationCount", "DeleteGraceTime") VALUES (881, "duplicati-b44bbdf41c6c64fe8bd6c0cd52826827a.dblock.zip.aes", "Blocks", "Temporary", -1, 0, 0); SELECT last_insert_rowid(); 2020-03-03 12:52:00 -05 - [Profiling-Timer.Finished-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteScalarInt64]: ExecuteScalarInt64: INSERT INTO "Remotevolume" ("OperationID", "Name", "Type", "State", "Size", "VerificationCount", "DeleteGraceTime") VALUES (881, "duplicati-b44bbdf41c6c64fe8bd6c0cd52826827a.dblock.zip.aes", "Blocks", "Temporary", -1, 0, 0); SELECT last_insert_rowid(); took 0:00:00:00.000 2020-03-03 12:52:00 -05 - [Profiling-Timer.Begin-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteScalarInt64]: Starting - ExecuteScalarInt64: INSERT INTO "Remotevolume" ("OperationID", "Name", "Type", "State", "Size", "VerificationCount", "DeleteGraceTime") VALUES (881, "duplicati-i3662fdc138524598acc0ac3e2e820378.dindex.zip.aes", "Index", "Temporary", -1, 0, 0); SELECT last_insert_rowid(); 2020-03-03 12:52:00 -05 - [Profiling-Timer.Finished-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteScalarInt64]: ExecuteScalarInt64: INSERT INTO "Remotevolume" ("OperationID", "Name", "Type", "State", "Size", "VerificationCount", "DeleteGraceTime") VALUES (881, "duplicati-i3662fdc138524598acc0ac3e2e820378.dindex.zip.aes", "Index", "Temporary", -1, 0, 0); SELECT last_insert_rowid(); took 0:00:00:00.000 2020-03-03 12:52:00 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-bbcbd4187d9cb48b0a22b0fe91722aa0b.dblock.zip.aes (50.00 MB) 2020-03-03 12:56:23 -05 - [Profiling-Duplicati.Library.Main.BackendManager-UploadSpeed]: Uploaded 50.00 MB in 00:04:22.6503624, 194.95 KB/s 2020-03-03 12:56:23 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-bbcbd4187d9cb48b0a22b0fe91722aa0b.dblock.zip.aes (50.00 MB) 2020-03-03 12:56:23 -05 - [Profiling-Timer.Finished-Duplicati.Library.Main.BackendManager-RemoteOperationPut]: RemoteOperationPut took 0:00:04:22.665 2020-03-03 12:56:23 -05 - [Profiling-Timer.Begin-Duplicati.Library.Main.BackendManager-RemoteOperationPut]: Starting - RemoteOperationPut 2020-03-03 12:56:23 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-i15817fa246ab4f64b5e441d84bafcfe2.dindex.zip.aes (39.56 KB) 2020-03-03 12:56:24 -05 - [Profiling-Duplicati.Library.Main.BackendManager-UploadSpeed]: Uploaded 39.56 KB in 00:00:01.1783834, 33.57 KB/s 2020-03-03 12:56:24 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-i15817fa246ab4f64b5e441d84bafcfe2.dindex.zip.aes (39.56 KB) 2020-03-03 12:56:24 -05 - [Profiling-Timer.Finished-Duplicati.Library.Main.BackendManager-RemoteOperationPut]: RemoteOperationPut took 0:00:00:01.264 2020-03-03 12:56:24 -05 - [Profiling-Timer.Begin-Duplicati.Library.Main.BackendManager-RemoteOperationNothing]: Starting - RemoteOperationNothing 2020-03-03 12:56:24 -05 - [Profiling-Timer.Finished-Duplicati.Library.Main.BackendManager-RemoteOperationNothing]: RemoteOperationNothing took 0:00:00:00.000 2020-03-03 12:56:24 -05 - [Profiling-Timer.Begin-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteReader]: Starting - ExecuteReader: SELECT "C"."Name", "B"."Name", "B"."Hash", "B"."Size" FROM "IndexBlockLink" A, "RemoteVolume" B, "RemoteVolume" C WHERE "A"."IndexVolumeID" = "B"."ID" AND "A"."BlockVolumeID" = "C"."ID" AND "B"."Hash" IS NOT NULL AND "B"."Size" IS NOT NULL 2020-03-03 12:56:24 -05 - [Profiling-Timer.Finished-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteReader]: ExecuteReader: SELECT "C"."Name", "B"."Name", "B"."Hash", "B"."Size" FROM "IndexBlockLink" A, "RemoteVolume" B, "RemoteVolume" C WHERE "A"."IndexVolumeID" = "B"."ID" AND "A"."BlockVolumeID" = "C"."ID" AND "B"."Hash" IS NOT NULL AND "B"."Size" IS NOT NULL took 0:00:00:00.000 2020-03-03 12:56:24 -05 - [Profiling-Timer.Begin-Duplicati.Library.Main.BackendManager-RemoteOperationDelete]: Starting - RemoteOperationDelete 2020-03-03 12:56:24 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Delete - Started: duplicati-b50fa9e71ec3c4a30a5cf1a769840259b.dblock.zip.aes (50.05 MB) 2020-03-03 12:56:26 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Delete - Completed: duplicati-b50fa9e71ec3c4a30a5cf1a769840259b.dblock.zip.aes (50.05 MB) 2020-03-03 12:56:26 -05 - [Profiling-Timer.Finished-Duplicati.Library.Main.BackendManager-RemoteOperationDelete]: RemoteOperationDelete took 0:00:00:01.461 2020-03-03 12:56:26 -05 - [Profiling-Timer.Begin-Duplicati.Library.Main.BackendManager-RemoteOperationDelete]: Starting - RemoteOperationDelete 2020-03-03 12:56:26 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Delete - Started: duplicati-i3e3b4e6d1bda4b75bf950caec7755556.dindex.zip.aes (27.45 KB) 2020-03-03 12:56:29 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Delete - Completed: duplicati-i3e3b4e6d1bda4b75bf950caec7755556.dindex.zip.aes (27.45 KB) 2020-03-03 12:56:29 -05 - [Profiling-Timer.Finished-Duplicati.Library.Main.BackendManager-RemoteOperationDelete]: RemoteOperationDelete took 0:00:00:02.955 2020-03-03 12:56:29 -05 - [Profiling-Timer.Begin-Duplicati.Library.Main.BackendManager-RemoteOperationGet]: Starting - RemoteOperationGet 2020-03-03 12:56:29 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-b3f9da65a8b8040df8cb634523018c2fa.dblock.zip.aes (21.13 MB) 2020-03-03 12:58:17 -05 - [Profiling-Duplicati.Library.Main.BackendManager-DownloadSpeed]: Downloaded and decrypted 21.13 MB in 00:01:48.8213207, 198.86 KB/s 2020-03-03 12:58:17 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-b3f9da65a8b8040df8cb634523018c2fa.dblock.zip.aes (21.13 MB) 2020-03-03 12:58:17 -05 - [Profiling-Timer.Finished-Duplicati.Library.Main.BackendManager-RemoteOperationGet]: RemoteOperationGet took 0:00:01:48.822 2020-03-03 12:58:17 -05 - [Profiling-Timer.Begin-Duplicati.Library.Main.BackendManager-RemoteOperationGet]: Starting - RemoteOperationGet 2020-03-03 12:58:17 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-bad01a725864f499fa129271f01aa4bc1.dblock.zip.aes (16.13 MB) 2020-03-03 12:59:42 -05 - [Profiling-Duplicati.Library.Main.BackendManager-DownloadSpeed]: Downloaded and decrypted 16.13 MB in 00:01:24.0692703, 196.49 KB/s 2020-03-03 12:59:42 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-bad01a725864f499fa129271f01aa4bc1.dblock.zip.aes (16.13 MB) 2020-03-03 12:59:42 -05 - [Profiling-Timer.Finished-Duplicati.Library.Main.BackendManager-RemoteOperationGet]: RemoteOperationGet took 0:00:01:24.070 2020-03-03 12:59:42 -05 - [Profiling-Timer.Begin-Duplicati.Library.Main.BackendManager-RemoteOperationGet]: Starting - RemoteOperationGet 2020-03-03 12:59:42 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-be375389d1eba43708f00bce8ba743ccf.dblock.zip.aes (28.48 MB) 2020-03-03 13:02:09 -05 - [Profiling-Duplicati.Library.Main.BackendManager-DownloadSpeed]: Downloaded and decrypted 28.48 MB in 00:02:27.8752230, 197.18 KB/s 2020-03-03 13:02:09 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-be375389d1eba43708f00bce8ba743ccf.dblock.zip.aes (28.48 MB) 2020-03-03 13:02:09 -05 - [Profiling-Timer.Finished-Duplicati.Library.Main.BackendManager-RemoteOperationGet]: RemoteOperationGet took 0:00:02:27.876 2020-03-03 13:02:09 -05 - [Profiling-Timer.Begin-Duplicati.Library.Main.BackendManager-RemoteOperationGet]: Starting - RemoteOperationGet 2020-03-03 13:02:09 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-b229fdb1d14f44ae98a22f3835f60848b.dblock.zip.aes (47.39 MB) 2020-03-03 13:02:10 -05 - [Profiling-Timer.Finished-Duplicati.Library.Main.BackendManager-RemoteOperationGet]: RemoteOperationGet took 0:00:00:00.075 2020-03-03 13:02:10 -05 - [Retry-Duplicati.Library.Main.BackendManager-RetryGet]: Operation Get with file duplicati-b229fdb1d14f44ae98a22f3835f60848b.dblock.zip.aes attempt 1 of 1 failed with message: The remote server returned an error: (403) Forbidden. System.Net.WebException: The remote server returned an error: (403) Forbidden. at Duplicati.Library.Utility.AsyncHttpRequest.AsyncWrapper.GetResponseOrStream() at Duplicati.Library.Utility.AsyncHttpRequest.GetResponse() at Duplicati.Library.Backend.GoogleDrive.GoogleDrive.Get(String remotename, Stream stream) at Duplicati.Library.Main.BackendManager.coreDoGetPiping(FileEntryItem item, IEncryption useDecrypter, Int64& retDownloadSize, String& retHashcode) at Duplicati.Library.Main.BackendManager.DoGet(FileEntryItem item) at Duplicati.Library.Main.BackendManager.ThreadRun() 2020-03-03 13:02:10 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Failed: duplicati-b229fdb1d14f44ae98a22f3835f60848b.dblock.zip.aes (47.39 MB) 2020-03-03 13:02:10 -05 - [Profiling-Timer.Begin-Duplicati.Library.Main.BackendManager-RemoteOperationGet]: Starting - RemoteOperationGet 2020-03-03 13:02:10 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-b6e794e613caf4a409d2aaf90de1f31bc.dblock.zip.aes (705.39 KB) 2020-03-03 13:02:17 -05 - [Profiling-Duplicati.Library.Main.BackendManager-DownloadSpeed]: Downloaded and decrypted 705.39 KB in 00:00:06.9219081, 101.91 KB/s 2020-03-03 13:02:17 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-b6e794e613caf4a409d2aaf90de1f31bc.dblock.zip.aes (705.39 KB) 2020-03-03 13:02:17 -05 - [Profiling-Timer.Finished-Duplicati.Library.Main.BackendManager-RemoteOperationGet]: RemoteOperationGet took 0:00:00:06.922 2020-03-03 13:02:17 -05 - [Error-Duplicati.Library.Main.Operation.BackupHandler-FatalError]: Fatal error System.Net.WebException: The remote server returned an error: (403) Forbidden. at Duplicati.Library.Main.AsyncDownloader.AsyncDownloaderEnumerator.AsyncDownloadedFile.get_TempFile() at Duplicati.Library.Main.Operation.CompactHandler.DoCompact(LocalDeleteDatabase db, Boolean hasVerifiedBackend, IDbTransaction& transaction, BackendManager sharedBackend) at Duplicati.Library.Main.Operation.DeleteHandler.DoRun(LocalDeleteDatabase db, IDbTransaction& transaction, Boolean hasVerifiedBacked, Boolean forceCompact, BackendManager sharedManager) at Duplicati.Library.Main.Operation.BackupHandler.CompactIfRequired(BackendManager backend, Int64 lastVolumeSize) at Duplicati.Library.Main.Operation.BackupHandler.<RunAsync>d__20.MoveNext() 2020-03-03 13:02:17 -05 - [Profiling-Timer.Begin-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteNonQuery]: Starting - ExecuteNonQuery: PRAGMA optimize 2020-03-03 13:02:17 -05 - [Profiling-Timer.Finished-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteNonQuery]: ExecuteNonQuery: PRAGMA optimize took 0:00:00:00.000 2020-03-03 13:02:17 -05 - [Profiling-Timer.Finished-Duplicati.Library.Main.Controller-RunBackup]: Running Backup took 0:00:22:16.948 ``` Notice how duplicati-b50fa9e71ec3c4a30a5cf1a769840259b.dblock.zip.aes then duplicati-i3e3b4e6d1bda4b75bf950caec7755556.dindex.zip.aes were logged as deleted. In 12:56 DB: duplicati-b50fa9e71ec3c4a30a5cf1a769840259b.dblock.zip.aes Remotevolume table shows Deleting RemoteOperation table does not show delete duplicati-i3e3b4e6d1bda4b75bf950caec7755556.dindex.zip.aes Remotevolume table shows Verified RemoteOperation table does not show delete

Mentioned because yours seems to follow above pattern of an error followed by “missing” dindex next run.
Confirmation of compact (or not) is in the Information level log too. no-auto-compact can also suppress it, however you wouldn’t want to suppress forever because wasted space would accumulate and raise fees.

obones · December 31, 2021, 3:55pm

I already did it once about 6 months ago, in the hopes of fixing that very same issue. It made it disappear for a while, but it came back.

No RAM drive here indeed, and the system appears quite stable indeed. I have done hard drive checks in the past, nothing came up. I’ll see when I can schedule a RAM test, but as you said, it should have other impacts on the system if the RAM was faulty.

I’m (almost) exclusively using the command line so I don’t have a clear answer to that.

Before replying to this message, I ran repair once again, and after that ran the backup command twice in a row.
Those two did not report any error, so I waited for the next night run to occur, and… it did not report any error either!
But this morning, the report email contained the dreaded error message about content alteration.
As I made it run with --console-log-level=information, I received lots of details and it appears that the report occurs not long after “compact” has been attempted.

It’s really big, but here is the full report:

Backup started at 31/12/2021 04:08:16
gpg
L'opération Backup a débuté
Checking remote backup ...
Backend event: List - Started: ()
Listing remote folder ...
Backend event: List - Completed: (19,79 KB)
Scanning local files ...
0 files need to be examined (0 octets)
16038 files need to be examined (8,60 GB) (still counting)
38320 files need to be examined (96,61 GB) (still counting)
56368 files need to be examined (168,93 GB) (still counting)
903546 files need to be examined (349,49 GB) (still counting)
917122 files need to be examined (352,43 GB) (still counting)
927741 files need to be examined (353,48 GB) (still counting)
940187 files need to be examined (357,22 GB) (still counting)
1172325 files need to be examined (393,10 GB) (still counting)
1180925 files need to be examined (394,33 GB) (still counting)
1185455 files need to be examined (394,57 GB)
1184411 files need to be examined (394,56 GB)
1183217 files need to be examined (394,56 GB)
1064508 files need to be examined (390,72 GB)
1063853 files need to be examined (386,83 GB)
Backend event: Put - Started: duplicati-bffaf3af6c269486aa7eca4acf57192db.dblock.zip.aes (49,91 MB)
Uploading file (49,91 MB) ...
Backend event: Put - Started: duplicati-b2edfaa0e267b410ebafaa74fdfd8885c.dblock.zip.aes (49,92 MB)
Uploading file (49,92 MB) ...
Backend event: Put - Started: duplicati-bea7637f0f90049338e6a7bcb6c1f35ab.dblock.zip.aes (49,94 MB)
Uploading file (49,94 MB) ...
Backend event: Put - Started: duplicati-bc051f9736bad468ab266830582e4fb41.dblock.zip.aes (49,95 MB)
Uploading file (49,95 MB) ...
Backend event: Put - Started: duplicati-b0e18e2d03cce410b80d4912deb5c5769.dblock.zip.aes (49,95 MB)
Uploading file (49,95 MB) ...
Backend event: Put - Started: duplicati-b9ae3c8fa024c4cae91e36dc2091c4a2e.dblock.zip.aes (49,92 MB)
Uploading file (49,92 MB) ...
Backend event: Put - Completed: duplicati-bffaf3af6c269486aa7eca4acf57192db.dblock.zip.aes (49,91 MB)
Backend event: Put - Started: duplicati-i704173bbe7ff4652878d434ed2dd589c.dindex.zip.aes (112,84 KB)
Uploading file (112,84 KB) ...
Backend event: Put - Completed: duplicati-i704173bbe7ff4652878d434ed2dd589c.dindex.zip.aes (112,84 KB)
Backend event: Put - Completed: duplicati-b2edfaa0e267b410ebafaa74fdfd8885c.dblock.zip.aes (49,92 MB)
Backend event: Put - Started: duplicati-i3aec586c27534b6c92bffd6de1ddba5b.dindex.zip.aes (46,70 KB)
Uploading file (46,70 KB) ...
Backend event: Put - Completed: duplicati-i3aec586c27534b6c92bffd6de1ddba5b.dindex.zip.aes (46,70 KB)
Backend event: Put - Completed: duplicati-bc051f9736bad468ab266830582e4fb41.dblock.zip.aes (49,95 MB)
Backend event: Put - Started: duplicati-i9a0bc0efa5244e6c8e667a4d82593dcd.dindex.zip.aes (27,97 KB)
Uploading file (27,97 KB) ...
Backend event: Put - Started: duplicati-b5987c58ab0dc40388227cc6581b6e03b.dblock.zip.aes (49,96 MB)
Uploading file (49,96 MB) ...
Backend event: Put - Completed: duplicati-i9a0bc0efa5244e6c8e667a4d82593dcd.dindex.zip.aes (27,97 KB)
Backend event: Put - Started: duplicati-b6c426efade794475abdde3b263743d48.dblock.zip.aes (49,91 MB)
Uploading file (49,91 MB) ...
Backend event: Put - Completed: duplicati-bea7637f0f90049338e6a7bcb6c1f35ab.dblock.zip.aes (49,94 MB)
Backend event: Put - Started: duplicati-i85c0429f2ee14375901a42d5b862f074.dindex.zip.aes (28,01 KB)
Uploading file (28,01 KB) ...
Backend event: Put - Completed: duplicati-i85c0429f2ee14375901a42d5b862f074.dindex.zip.aes (28,01 KB)
Backend event: Put - Completed: duplicati-b5987c58ab0dc40388227cc6581b6e03b.dblock.zip.aes (49,96 MB)
Backend event: Put - Started: duplicati-i992aa28c121b4785b5a5f4c7078b7dc8.dindex.zip.aes (31,04 KB)
Uploading file (31,04 KB) ...
Backend event: Put - Completed: duplicati-i992aa28c121b4785b5a5f4c7078b7dc8.dindex.zip.aes (31,04 KB)
Backend event: Put - Started: duplicati-bec5ee078f3cb4d4cafbeee5bb7562d54.dblock.zip.aes (49,91 MB)
Uploading file (49,91 MB) ...
Backend event: Put - Started: duplicati-ba2c5b0af720140868da1b0e0e94b30ae.dblock.zip.aes (49,90 MB)
Uploading file (49,90 MB) ...
Backend event: Put - Completed: duplicati-b0e18e2d03cce410b80d4912deb5c5769.dblock.zip.aes (49,95 MB)
Backend event: Put - Started: duplicati-i70f08371400c4f11ab19722cf74cd138.dindex.zip.aes (28,50 KB)
Uploading file (28,50 KB) ...
Backend event: Put - Completed: duplicati-i70f08371400c4f11ab19722cf74cd138.dindex.zip.aes (28,50 KB)
Backend event: Put - Completed: duplicati-b6c426efade794475abdde3b263743d48.dblock.zip.aes (49,91 MB)
Backend event: Put - Started: duplicati-i2d98bc63a6f447ee86642de4ae0d4221.dindex.zip.aes (131,17 KB)
Uploading file (131,17 KB) ...
Backend event: Put - Completed: duplicati-i2d98bc63a6f447ee86642de4ae0d4221.dindex.zip.aes (131,17 KB)
Backend event: Put - Completed: duplicati-ba2c5b0af720140868da1b0e0e94b30ae.dblock.zip.aes (49,90 MB)
Backend event: Put - Started: duplicati-i289f78ede2bf431dabc93b2a7598742c.dindex.zip.aes (28,75 KB)
Uploading file (28,75 KB) ...
Backend event: Put - Completed: duplicati-i289f78ede2bf431dabc93b2a7598742c.dindex.zip.aes (28,75 KB)
Backend event: Put - Completed: duplicati-bec5ee078f3cb4d4cafbeee5bb7562d54.dblock.zip.aes (49,91 MB)
Backend event: Put - Started: duplicati-i219f0d6c3a95417191cc3f3fd83c7de6.dindex.zip.aes (28,93 KB)
Uploading file (28,93 KB) ...
Backend event: Put - Completed: duplicati-i219f0d6c3a95417191cc3f3fd83c7de6.dindex.zip.aes (28,93 KB)
Backend event: Put - Completed: duplicati-b9ae3c8fa024c4cae91e36dc2091c4a2e.dblock.zip.aes (49,92 MB)
Backend event: Put - Started: duplicati-ifab3ed5d797346bcbc8913bd40f807da.dindex.zip.aes (128,73 KB)
Uploading file (128,73 KB) ...
Backend event: Put - Completed: duplicati-ifab3ed5d797346bcbc8913bd40f807da.dindex.zip.aes (128,73 KB)
Backend event: Put - Started: duplicati-b9498b4254b3f479b96786b752bc2146e.dblock.zip.aes (49,93 MB)
Uploading file (49,93 MB) ...
Backend event: Put - Started: duplicati-b8731ec0fcffb45b0937bc4c8e9b0e778.dblock.zip.aes (49,95 MB)
Uploading file (49,95 MB) ...
Backend event: Put - Completed: duplicati-b8731ec0fcffb45b0937bc4c8e9b0e778.dblock.zip.aes (49,95 MB)
Backend event: Put - Started: duplicati-ib0fd1d30b540433f8fe92c7a5630bc02.dindex.zip.aes (28,18 KB)
Uploading file (28,18 KB) ...
Backend event: Put - Completed: duplicati-ib0fd1d30b540433f8fe92c7a5630bc02.dindex.zip.aes (28,18 KB)
Backend event: Put - Completed: duplicati-b9498b4254b3f479b96786b752bc2146e.dblock.zip.aes (49,93 MB)
Backend event: Put - Started: duplicati-i01228e07779049a7a5fbf225f9b7c172.dindex.zip.aes (128,29 KB)
Uploading file (128,29 KB) ...
Backend event: Put - Completed: duplicati-i01228e07779049a7a5fbf225f9b7c172.dindex.zip.aes (128,29 KB)
Backend event: Put - Started: duplicati-bf10660d3d636422e8ee753a9c379c418.dblock.zip.aes (49,94 MB)
Uploading file (49,94 MB) ...
Backend event: Put - Started: duplicati-b5f3b021bb6ad477e86992306e0b92015.dblock.zip.aes (49,93 MB)
Uploading file (49,93 MB) ...
Backend event: Put - Completed: duplicati-b5f3b021bb6ad477e86992306e0b92015.dblock.zip.aes (49,93 MB)
Backend event: Put - Started: duplicati-i61df2f93c49b4cb7a619f903add1df9f.dindex.zip.aes (28,25 KB)
Uploading file (28,25 KB) ...
Backend event: Put - Completed: duplicati-i61df2f93c49b4cb7a619f903add1df9f.dindex.zip.aes (28,25 KB)
Backend event: Put - Completed: duplicati-bf10660d3d636422e8ee753a9c379c418.dblock.zip.aes (49,94 MB)
Backend event: Put - Started: duplicati-idcb862e36a214beb81d2aa522304cca0.dindex.zip.aes (28,25 KB)
Uploading file (28,25 KB) ...
Backend event: Put - Completed: duplicati-idcb862e36a214beb81d2aa522304cca0.dindex.zip.aes (28,25 KB)
Backend event: Put - Started: duplicati-b2728cd47d3bd439ebea0b3b34fd90ae7.dblock.zip.aes (49,95 MB)
Uploading file (49,95 MB) ...
Backend event: Put - Retrying: duplicati-b2728cd47d3bd439ebea0b3b34fd90ae7.dblock.zip.aes (49,95 MB)
Backend event: Put - Started: duplicati-bc22f3ca9661d4dc18cf33c93f55ffe11.dblock.zip.aes (49,93 MB)
Uploading file (49,93 MB) ...
Backend event: Put - Rename: duplicati-b2728cd47d3bd439ebea0b3b34fd90ae7.dblock.zip.aes (49,95 MB)
Backend event: Put - Rename: duplicati-b3fd7fed58c134eb3a979e76a71b2c58c.dblock.zip.aes (49,95 MB)
Renaming "duplicati-b2728cd47d3bd439ebea0b3b34fd90ae7.dblock.zip.aes" to "duplicati-b3fd7fed58c134eb3a979e76a71b2c58c.dblock.zip.aes"
Backend event: Put - Started: duplicati-b3fd7fed58c134eb3a979e76a71b2c58c.dblock.zip.aes (49,95 MB)
Uploading file (49,95 MB) ...
Backend event: Put - Completed: duplicati-bc22f3ca9661d4dc18cf33c93f55ffe11.dblock.zip.aes (49,93 MB)
Backend event: Put - Started: duplicati-i43a28724af074bf4b69c52ae883dcc28.dindex.zip.aes (28,78 KB)
Uploading file (28,78 KB) ...
Backend event: Put - Completed: duplicati-i43a28724af074bf4b69c52ae883dcc28.dindex.zip.aes (28,78 KB)
Backend event: Put - Started: duplicati-ba5e10050214e4bb2b888d3aff2b54ea5.dblock.zip.aes (49,96 MB)
Uploading file (49,96 MB) ...
Backend event: Put - Started: duplicati-b6ce579d3eb5347759983fede6245a87c.dblock.zip.aes (49,92 MB)
Uploading file (49,92 MB) ...
Backend event: Put - Completed: duplicati-b6ce579d3eb5347759983fede6245a87c.dblock.zip.aes (49,92 MB)
Backend event: Put - Started: duplicati-ifab50db67d524aa5954f451870b18d4e.dindex.zip.aes (31,43 KB)
Uploading file (31,43 KB) ...
Backend event: Put - Completed: duplicati-ifab50db67d524aa5954f451870b18d4e.dindex.zip.aes (31,43 KB)
Backend event: Put - Completed: duplicati-ba5e10050214e4bb2b888d3aff2b54ea5.dblock.zip.aes (49,96 MB)
Backend event: Put - Started: duplicati-i770521a195914ba9917e38396945f570.dindex.zip.aes (31,70 KB)
Uploading file (31,70 KB) ...
Backend event: Put - Completed: duplicati-i770521a195914ba9917e38396945f570.dindex.zip.aes (31,70 KB)
Backend event: Put - Completed: duplicati-b3fd7fed58c134eb3a979e76a71b2c58c.dblock.zip.aes (49,95 MB)
Backend event: Put - Started: duplicati-i0137c893dbe0461087fb22547bfe8a01.dindex.zip.aes (129,06 KB)
Uploading file (129,06 KB) ...
Backend event: Put - Completed: duplicati-i0137c893dbe0461087fb22547bfe8a01.dindex.zip.aes (129,06 KB)
Backend event: Put - Started: duplicati-baa74c951f9bd4b5c9e97d1b99963c6c9.dblock.zip.aes (49,90 MB)
Uploading file (49,90 MB) ...
Backend event: Put - Started: duplicati-b20e0d37464724198945c8e23abb0ee51.dblock.zip.aes (49,92 MB)
Uploading file (49,92 MB) ...
Backend event: Put - Completed: duplicati-baa74c951f9bd4b5c9e97d1b99963c6c9.dblock.zip.aes (49,90 MB)
Backend event: Put - Started: duplicati-i4b249a1651124d00b7d6ab44c80c9dc4.dindex.zip.aes (42,06 KB)
Uploading file (42,06 KB) ...
Backend event: Put - Completed: duplicati-i4b249a1651124d00b7d6ab44c80c9dc4.dindex.zip.aes (42,06 KB)
Backend event: Put - Completed: duplicati-b20e0d37464724198945c8e23abb0ee51.dblock.zip.aes (49,92 MB)
Backend event: Put - Started: duplicati-ibfc2bc70786b4a1b94f6c93fcd7131fb.dindex.zip.aes (142,93 KB)
Uploading file (142,93 KB) ...
Backend event: Put - Completed: duplicati-ibfc2bc70786b4a1b94f6c93fcd7131fb.dindex.zip.aes (142,93 KB)
Backend event: Put - Started: duplicati-bee778534578e4711ad01cfb9d4b772b7.dblock.zip.aes (49,91 MB)
Uploading file (49,91 MB) ...
Backend event: Put - Started: duplicati-b15f75f6239034f758a55a040491b843e.dblock.zip.aes (49,91 MB)
Uploading file (49,91 MB) ...
Backend event: Put - Completed: duplicati-bee778534578e4711ad01cfb9d4b772b7.dblock.zip.aes (49,91 MB)
Backend event: Put - Started: duplicati-icfeddf36e6a84089b7b10cbf3202b88a.dindex.zip.aes (146,70 KB)
Uploading file (146,70 KB) ...
Backend event: Put - Completed: duplicati-icfeddf36e6a84089b7b10cbf3202b88a.dindex.zip.aes (146,70 KB)
Backend event: Put - Completed: duplicati-b15f75f6239034f758a55a040491b843e.dblock.zip.aes (49,91 MB)
Backend event: Put - Started: duplicati-i48b0c4aae34141d7ac7580aadcbb71c2.dindex.zip.aes (46,90 KB)
Uploading file (46,90 KB) ...
Backend event: Put - Completed: duplicati-i48b0c4aae34141d7ac7580aadcbb71c2.dindex.zip.aes (46,90 KB)
Backend event: Put - Started: duplicati-ba2ffb7ead70942d59ef668c8557a0bb2.dblock.zip.aes (49,94 MB)
Uploading file (49,94 MB) ...
Backend event: Put - Started: duplicati-be8f75baa58e14615ac60e75820bc4fda.dblock.zip.aes (49,93 MB)
Uploading file (49,93 MB) ...
Backend event: Put - Completed: duplicati-ba2ffb7ead70942d59ef668c8557a0bb2.dblock.zip.aes (49,94 MB)
Backend event: Put - Started: duplicati-ifb037d278f384aba827d6346de40973f.dindex.zip.aes (155,12 KB)
Uploading file (155,12 KB) ...
Backend event: Put - Completed: duplicati-ifb037d278f384aba827d6346de40973f.dindex.zip.aes (155,12 KB)
Backend event: Put - Completed: duplicati-be8f75baa58e14615ac60e75820bc4fda.dblock.zip.aes (49,93 MB)
Backend event: Put - Started: duplicati-id7023fb43f8040f3b51c85ba69a793ec.dindex.zip.aes (154,79 KB)
Uploading file (154,79 KB) ...
Backend event: Put - Completed: duplicati-id7023fb43f8040f3b51c85ba69a793ec.dindex.zip.aes (154,79 KB)
1063852 files need to be examined (384,04 GB)
Backend event: Put - Started: duplicati-bc8df2978576341a2bb21e57f86dbfb66.dblock.zip.aes (49,90 MB)
Uploading file (49,90 MB) ...
Backend event: Put - Started: duplicati-bc69bfd8eb0124210b0bad702fc9fee5d.dblock.zip.aes (49,90 MB)
Uploading file (49,90 MB) ...
1063109 files need to be examined (383,77 GB)
1062004 files need to be examined (383,72 GB)
Backend event: Put - Completed: duplicati-bc8df2978576341a2bb21e57f86dbfb66.dblock.zip.aes (49,90 MB)
Backend event: Put - Completed: duplicati-bc69bfd8eb0124210b0bad702fc9fee5d.dblock.zip.aes (49,90 MB)
Backend event: Put - Started: duplicati-ic1ea0bc0323144b5b1db36cdb661d0aa.dindex.zip.aes (139,17 KB)
Uploading file (139,17 KB) ...
Backend event: Put - Started: duplicati-i96828b683f3a4d4094f5940ac82f6edf.dindex.zip.aes (56,06 KB)
Uploading file (56,06 KB) ...
Backend event: Put - Completed: duplicati-ic1ea0bc0323144b5b1db36cdb661d0aa.dindex.zip.aes (139,17 KB)
Backend event: Put - Completed: duplicati-i96828b683f3a4d4094f5940ac82f6edf.dindex.zip.aes (56,06 KB)
1060649 files need to be examined (383,71 GB)
1059850 files need to be examined (383,70 GB)
826109 files need to be examined (370,50 GB)
825587 files need to be examined (370,42 GB)
Backend event: Put - Started: duplicati-b38343a9d8ac54746b75eb3c9c5139e77.dblock.zip.aes (49,92 MB)
Uploading file (49,92 MB) ...
Backend event: Put - Started: duplicati-b1c85ca837d15430fa7263119ff6df98d.dblock.zip.aes (49,93 MB)
Uploading file (49,93 MB) ...
Backend event: Put - Completed: duplicati-b1c85ca837d15430fa7263119ff6df98d.dblock.zip.aes (49,93 MB)
Backend event: Put - Started: duplicati-i0e882d20de1b4b679e4f1d172ec65e25.dindex.zip.aes (434,58 KB)
Uploading file (434,58 KB) ...
Backend event: Put - Completed: duplicati-i0e882d20de1b4b679e4f1d172ec65e25.dindex.zip.aes (434,58 KB)
Backend event: Put - Completed: duplicati-b38343a9d8ac54746b75eb3c9c5139e77.dblock.zip.aes (49,92 MB)
Backend event: Put - Started: duplicati-if751c95838d942299f4a0d625cbf7ca6.dindex.zip.aes (684,95 KB)
Uploading file (684,95 KB) ...
Backend event: Put - Completed: duplicati-if751c95838d942299f4a0d625cbf7ca6.dindex.zip.aes (684,95 KB)
Backend event: Put - Started: duplicati-b53f5b6cadedd46b1a96fba08d4732076.dblock.zip.aes (49,93 MB)
Uploading file (49,93 MB) ...
Backend event: Put - Started: duplicati-bfd804bc10eec48268d876f9aa54a4fe4.dblock.zip.aes (49,93 MB)
Uploading file (49,93 MB) ...
Backend event: Put - Completed: duplicati-bfd804bc10eec48268d876f9aa54a4fe4.dblock.zip.aes (49,93 MB)
Backend event: Put - Started: duplicati-i8724424bacdb4c9690dc1e0af3b16505.dindex.zip.aes (54,00 KB)
Uploading file (54,00 KB) ...
Backend event: Put - Completed: duplicati-b53f5b6cadedd46b1a96fba08d4732076.dblock.zip.aes (49,93 MB)
Backend event: Put - Started: duplicati-i7b85d88401e14322852a715fcf9ec60d.dindex.zip.aes (153,92 KB)
Uploading file (153,92 KB) ...
Backend event: Put - Completed: duplicati-i8724424bacdb4c9690dc1e0af3b16505.dindex.zip.aes (54,00 KB)
Backend event: Put - Completed: duplicati-i7b85d88401e14322852a715fcf9ec60d.dindex.zip.aes (153,92 KB)
823997 files need to be examined (362,00 GB)
384816 files need to be examined (36,78 GB)
211957 files need to be examined (877,34 MB)
201904 files need to be examined (513,80 KB)
Backend event: Put - Started: duplicati-bc01e659587bc40a5b134171c0d45afc7.dblock.zip.aes (47,75 MB)
Uploading file (47,75 MB) ...
0 files need to be examined (0 octets)
Backend event: Put - Completed: duplicati-bc01e659587bc40a5b134171c0d45afc7.dblock.zip.aes (47,75 MB)
Backend event: Put - Started: duplicati-i68124c5134024f7289a150e06b53ba7c.dindex.zip.aes (139,81 KB)
Uploading file (139,81 KB) ...
Backend event: Put - Completed: duplicati-i68124c5134024f7289a150e06b53ba7c.dindex.zip.aes (139,81 KB)
Backend event: Put - Started: duplicati-20211231T030817Z.dlist.zip.aes (76,40 MB)
Uploading file (76,40 MB) ...
Backend event: Put - Completed: duplicati-20211231T030817Z.dlist.zip.aes (76,40 MB)
Start checking if backups can be removed
Time frames and intervals pairs: 7.00:00:00 / 1.00:00:00, 28.00:00:00 / 7.00:00:00, 365.00:00:00 / 31.00:00:00
Backups to consider: 30/12/2021 04:08:41, 29/12/2021 15:02:21, 17/12/2021 04:08:50, 31/10/2021 04:08:04, 01/10/2021 04:07:36, 22/09/2021 04:07:12, 18/08/2021 04:06:31, 11/07/2021 16:50:33, 07/06/2021 04:04:13, 02/06/2021 04:04:20, 01/05/2021 18:46:29, 01/05/2021 16:43:24, 01/05/2021 16:38:12
Backups outside of all time frames and thus getting deleted:
All backups to delete: 30/12/2021 04:08:41
Deleting 1 remote fileset(s) ...
Backend event: Delete - Started: duplicati-20211230T030841Z.dlist.zip.aes (76,40 MB)
Deleting file duplicati-20211230T030841Z.dlist.zip.aes (76,40 MB) ...
Backend event: Delete - Completed: duplicati-20211230T030841Z.dlist.zip.aes (76,40 MB)
Deleted 1 remote fileset(s)
Compacting because there are 62,80 MB in small volumes and the volume size is 50,00 MB
Backend event: Get - Started: duplicati-b8abc82111cbf461fb68479d1c35ce3eb.dblock.zip.aes (49,95 MB)
Downloading file (49,95 MB) ...
Backend event: Get - Completed: duplicati-b8abc82111cbf461fb68479d1c35ce3eb.dblock.zip.aes (49,95 MB)
Backend event: Get - Started: duplicati-bff79b17d485e4f52838a05edac30aed2.dblock.zip.aes (49,93 MB)
Downloading file (49,93 MB) ...
Backend event: Get - Completed: duplicati-bff79b17d485e4f52838a05edac30aed2.dblock.zip.aes (49,93 MB)
Backend event: Get - Started: duplicati-b3595d93f72ff449089a11bed0dc4124f.dblock.zip.aes (49,92 MB)
Downloading file (49,92 MB) ...
Backend event: Get - Completed: duplicati-b3595d93f72ff449089a11bed0dc4124f.dblock.zip.aes (49,92 MB)
Backend event: Get - Started: duplicati-bf948d4319af0440790a3ceab9e6d6213.dblock.zip.aes (49,92 MB)
Downloading file (49,92 MB) ...
Backend event: Get - Completed: duplicati-bf948d4319af0440790a3ceab9e6d6213.dblock.zip.aes (49,92 MB)
Backend event: Get - Started: duplicati-b04a9e83b2f8c4e5a9714abda393d4b79.dblock.zip.aes (49,91 MB)
Downloading file (49,91 MB) ...
Backend event: Get - Completed: duplicati-b04a9e83b2f8c4e5a9714abda393d4b79.dblock.zip.aes (49,91 MB)
Backend event: Get - Started: duplicati-b5a0ba9f7cc454d7e87c9d305b13355c2.dblock.zip.aes (49,92 MB)
Downloading file (49,92 MB) ...
Backend event: Get - Completed: duplicati-b5a0ba9f7cc454d7e87c9d305b13355c2.dblock.zip.aes (49,92 MB)
Backend event: Get - Started: duplicati-b500f63eed0894f94a8b521629a223485.dblock.zip.aes (49,90 MB)
Downloading file (49,90 MB) ...
Backend event: Get - Completed: duplicati-b500f63eed0894f94a8b521629a223485.dblock.zip.aes (49,90 MB)
Backend event: Get - Started: duplicati-b4e85a7c425a84ddfb579402fb610f020.dblock.zip.aes (49,91 MB)
Downloading file (49,91 MB) ...
Backend event: Get - Completed: duplicati-b4e85a7c425a84ddfb579402fb610f020.dblock.zip.aes (49,91 MB)
Backend event: Get - Started: duplicati-b676f988024fe4e909c2a8e62f574d189.dblock.zip.aes (35,14 MB)
Downloading file (35,14 MB) ...
Backend event: Get - Completed: duplicati-b676f988024fe4e909c2a8e62f574d189.dblock.zip.aes (35,14 MB)
Backend event: Get - Started: duplicati-b2b1776cafae64e318bca4221f2bdcde8.dblock.zip.aes (49,95 MB)
Downloading file (49,95 MB) ...
Backend event: Get - Completed: duplicati-b2b1776cafae64e318bca4221f2bdcde8.dblock.zip.aes (49,95 MB)
Backend event: Get - Started: duplicati-b14d5b67f3f7e45699ae4928b2510dbdd.dblock.zip.aes (49,93 MB)
Downloading file (49,93 MB) ...
Backend event: Get - Completed: duplicati-b14d5b67f3f7e45699ae4928b2510dbdd.dblock.zip.aes (49,93 MB)
Backend event: Get - Started: duplicati-b0cc498b9db9e43239fef6d8e566d5f1c.dblock.zip.aes (49,90 MB)
Downloading file (49,90 MB) ...
Backend event: Get - Completed: duplicati-b0cc498b9db9e43239fef6d8e566d5f1c.dblock.zip.aes (49,90 MB)
Backend event: Get - Started: duplicati-bdcb03272f1b843c99756b0ee6d4f4d83.dblock.zip.aes (49,91 MB)
Downloading file (49,91 MB) ...
Backend event: Get - Completed: duplicati-bdcb03272f1b843c99756b0ee6d4f4d83.dblock.zip.aes (49,91 MB)
Backend event: Get - Started: duplicati-b06bac0ef91e44f1393634b5674db7727.dblock.zip.aes (49,92 MB)
Downloading file (49,92 MB) ...
Backend event: Get - Completed: duplicati-b06bac0ef91e44f1393634b5674db7727.dblock.zip.aes (49,92 MB)
Backend event: Get - Started: duplicati-bfa628a85cae44e018ea4959cb6db09aa.dblock.zip.aes (49,92 MB)
Downloading file (49,92 MB) ...
Backend event: Get - Completed: duplicati-bfa628a85cae44e018ea4959cb6db09aa.dblock.zip.aes (49,92 MB)
Backend event: Get - Started: duplicati-b9f00949b381c4aab94266a368f58e8dd.dblock.zip.aes (49,91 MB)
Downloading file (49,91 MB) ...
Backend event: Get - Completed: duplicati-b9f00949b381c4aab94266a368f58e8dd.dblock.zip.aes (49,91 MB)
Backend event: Get - Started: duplicati-b6da1151e29644dbe84b3819f1c6f88dd.dblock.zip.aes (49,94 MB)
Downloading file (49,94 MB) ...
Backend event: Get - Completed: duplicati-b6da1151e29644dbe84b3819f1c6f88dd.dblock.zip.aes (49,94 MB)
Backend event: Get - Started: duplicati-b1d2b22f3968e459da9ce0e5e03774103.dblock.zip.aes (49,97 MB)
Downloading file (49,97 MB) ...
Backend event: Get - Completed: duplicati-b1d2b22f3968e459da9ce0e5e03774103.dblock.zip.aes (49,97 MB)
Backend event: Get - Started: duplicati-b71d0b311be324f5e90c0ad1e5f091b5e.dblock.zip.aes (49,97 MB)
Downloading file (49,97 MB) ...
Backend event: Get - Retrying: duplicati-b71d0b311be324f5e90c0ad1e5f091b5e.dblock.zip.aes (49,97 MB)
Backend event: Get - Started: duplicati-b71d0b311be324f5e90c0ad1e5f091b5e.dblock.zip.aes (49,97 MB)
Downloading file (49,97 MB) ...
Backend event: Get - Retrying: duplicati-b71d0b311be324f5e90c0ad1e5f091b5e.dblock.zip.aes (49,97 MB)
Backend event: Get - Started: duplicati-b71d0b311be324f5e90c0ad1e5f091b5e.dblock.zip.aes (49,97 MB)
Downloading file (49,97 MB) ...
Backend event: Get - Retrying: duplicati-b71d0b311be324f5e90c0ad1e5f091b5e.dblock.zip.aes (49,97 MB)
Backend event: Get - Started: duplicati-b71d0b311be324f5e90c0ad1e5f091b5e.dblock.zip.aes (49,97 MB)
Downloading file (49,97 MB) ...
Backend event: Get - Retrying: duplicati-b71d0b311be324f5e90c0ad1e5f091b5e.dblock.zip.aes (49,97 MB)
Backend event: Get - Started: duplicati-b71d0b311be324f5e90c0ad1e5f091b5e.dblock.zip.aes (49,97 MB)
Downloading file (49,97 MB) ...
Backend event: Get - Failed: duplicati-b71d0b311be324f5e90c0ad1e5f091b5e.dblock.zip.aes (49,97 MB)
Backend event: Get - Started: duplicati-bef2c5536c6b348079705eabb4a5a1cd8.dblock.zip.aes (49,94 MB)
Downloading file (49,94 MB) ...
Fatal error => Échec du déchiffrement des données (phrase de passe invalide ?) : Message has been altered, do not trust content

System.Security.Cryptography.CryptographicException: Échec du déchiffrement des données (phrase de passe invalide ?) : Message has been altered, do not trust content ---> SharpAESCrypt.SharpAESCrypt+HashMismatchException: Message has been altered, do not trust content
at SharpAESCrypt.SharpAESCrypt.Read (System.Byte[] buffer, System.Int32 offset, System.Int32 count) [0x00405] in <45c43198e80545aeabaa9b98839b4c7d>:0
at Duplicati.Library.Utility.Utility.CopyStream (System.IO.Stream source, System.IO.Stream target, System.Boolean tryRewindSource, System.Byte[] buf) [0x0003d] in <d644d641ef094b6cbc223bc3a32d53af>:0
at Duplicati.Library.Encryption.EncryptionBase.Decrypt (System.IO.Stream input, System.IO.Stream output) [0x00008] in <2b32bf2e4cc54065bffbbfc47a2d790b>:0
--- End of inner exception stack trace ---
at Duplicati.Library.Main.AsyncDownloader+AsyncDownloaderEnumerator+AsyncDownloadedFile.get_TempFile () [0x00008] in <1d9349a5d6874088879a75d074c92b62>:0
at Duplicati.Library.Main.Operation.CompactHandler.DoCompact (Duplicati.Library.Main.Database.LocalDeleteDatabase db, System.Boolean hasVerifiedBackend, System.Data.IDbTransaction& transaction, Duplicati.Library.Main.BackendManager sharedBackend) [0x00259] in <1d9349a5d6874088879a75d074c92b62>:0
at Duplicati.Library.Main.Operation.DeleteHandler.DoRun (Duplicati.Library.Main.Database.LocalDeleteDatabase db, System.Data.IDbTransaction& transaction, System.Boolean hasVerifiedBackend, System.Boolean forceCompact, Duplicati.Library.Main.BackendManager sharedManager) [0x003a2] in <1d9349a5d6874088879a75d074c92b62>:0
at Duplicati.Library.Main.Operation.BackupHandler.CompactIfRequired (Duplicati.Library.Main.BackendManager backend, System.Int64 lastVolumeSize) [0x000a5] in <1d9349a5d6874088879a75d074c92b62>:0
at Duplicati.Library.Main.Operation.BackupHandler.RunAsync (System.String[] sources, Duplicati.Library.Utility.IFilter filter, System.Threading.CancellationToken token) [0x01048] in <1d9349a5d6874088879a75d074c92b62>: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 <1d9349a5d6874088879a75d074c92b62>:0
at Duplicati.Library.Main.Controller+<>c__DisplayClass14_0.<Backup>b__0 (Duplicati.Library.Main.BackupResults result) [0x0004b] in <1d9349a5d6874088879a75d074c92b62>: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 <1d9349a5d6874088879a75d074c92b62>:0
at Duplicati.Library.Main.Controller.Backup (System.String[] inputsources, Duplicati.Library.Utility.IFilter filter) [0x00074] in <1d9349a5d6874088879a75d074c92b62>:0
at Duplicati.CommandLine.Commands.Backup (System.IO.TextWriter outwriter, System.Action`1[T] setup, System.Collections.Generic.List`1[T] args, System.Collections.Generic.Dictionary`2[TKey,TValue] options, Duplicati.Library.Utility.IFilter filter) [0x00119] in <3d18b3352444419eba6d6a9e7e773335>:0
at (wrapper delegate-invoke) System.Func`6[System.IO.TextWriter,System.Action`1[Duplicati.Library.Main.Controller],System.Collections.Generic.List`1[System.String],System.Collections.Generic.Dictionary`2[System.String,System.String],Duplicati.Library.Utility.IFilter,System.Int32].invoke_TResult_T1_T2_T3_T4_T5(System.IO.TextWriter,System.Action`1<Duplicati.Library.Main.Controller>,System.Collections.Generic.List`1<string>,System.Collections.Generic.Dictionary`2<string, string>,Duplicati.Library.Utility.IFilter)
at Duplicati.CommandLine.Program.ParseCommandLine (System.IO.TextWriter outwriter, System.Action`1[T] setup, System.Boolean& verboseErrors, System.String[] args) [0x00342] in <3d18b3352444419eba6d6a9e7e773335>:0
at Duplicati.CommandLine.Program.RunCommandLine (System.IO.TextWriter outwriter, System.IO.TextWriter errwriter, System.Action`1[T] setup, System.String[] args) [0x00002] in <3d18b3352444419eba6d6a9e7e773335>:0

The command line used is this (redacted) one:

/usr/bin/mono /opt/duplicati-latest/Duplicati.CommandLine.exe backup --backup-name="Full backup" --dbpath=/var/lib/duplicati/.config/Duplicati/MYDATABASE.sqlite --encryption-module=aes --compression-module=zip --dblock-size=50mb --passphrase="PASS PHRASE" --disable-module=console-password-input --asynchronous-concurrent-upload-limit=10 --retention-policy="1W:1D,4W:1W,12M:1M" --exclude="*lost+found*/" --exclude="*/a/path/to/exclude*/" "b2://bucket-name/?auth-username=userid&auth-password=userpassword" /path/to/backup/

As you can see from the path used, this is running on a linux machine, using the Manjaro distribution and the package from the AUR. I’m mentionning it just in case, but I don’t think it has any impact here.

I really appreciate the time you are spending to help me on this.

ts678 · January 1, 2022, 2:20am

Maybe you have had different ones. The issue on download could be in compact which only runs when needed, and only compacts files with wasted space. Or it could be in sampled test of files after backup.

So at least duplicati-b71d0b311be324f5e90c0ad1e5f091b5e.dblock.zip.aes is having trouble. B2 doesn’t have a great web UI, but I wonder if you could get a timestamp of the file, and a download to try to check although there’s a limited amount possible with an encrypted file because most should look very random.

In addition to timestamp, it might be helpful to know where the file uploaded in the backup uploads series. You can infer this from timestamps if you can find a B2 client that can sort by date. On Windows, maybe Cyberduck would do. I’m not sure what there is for Linux. Another way to find the file’s history is in the DB using sqlitebrowser which I think is in your repo. I could guide you. It looks a bit like spreadsheet tables.

Posting a link to a database bug report would be another way for somebody to look for clues about the file.

obones · January 1, 2022, 11:18am

I already had Cyberduck installed on a Windows workstation, so it was quite easy to get to that file. Its timestamp is set to 2021-08-27 04.:30:55 which sounds right for the time part as the backup script runs around that time of night.
I downloaded it and it has this at its beginning:

So it looks like at least the header is the expected one.

This is what I get:

Well, sqlite3 is something I’m used to, here is the query I ran:

sqlite> select * from Remotevolume where Name="duplicati-b71d0b311be324f5e90c0ad1e5f091b5e.dblock.zip.aes" limit 10;
20127|96|duplicati-b71d0b311be324f5e90c0ad1e5f091b5e.dblock.zip.aes|Blocks|52393629|R5o1CiSclJjMWDPCxKVVTzwn+QUj33b8XdHgO+4B0Yg=|Verified|0|0

But I don’t know the schema well enough to infer anything from this, nor to find the appropriate joins that I could do to get more information.

ts678 · January 1, 2022, 1:00pm

Is there genuinely no dlist file from the Aug 27 backup? That uploads at end of backup. Sample activity:

Yours seems to be doing about the right pairs of dblock and dindex, then it stops. I wonder what that is?
Does your Remotevolume table think that there’s a dlist file associated with the backup (like as above)?
A dlist represents a Fileset. You can look for a fileset. Is IsFullBackup a 1? Maybe it was interrupted.

Is there a log entry made? This is easier to see in a GUI, but GUI is just displaying what database holds:

Do you have lots looking like that? I seem to have 20 of 514 that the small default verify hasn’t sampled.
Sampling can be raised if the problem continues, so at least it may warn earlier rather than in compact.

At least some header errors get a different error message. In spite of the runs of 0-filled lines, you can
hexdump -C or od -c it and pipe to grep '^*$ to see if there are big empty blocks later in encryption.
Checking the file size against DB size might be good, but I think Duplicati is already checking file size.
File content, unfortunately, can’t be checked without downloading the file and seeing if something fails.

AES Crypt or Duplicati’s CLI SharpAESCrypt.exe can be used on that file to confirm that it’s damaged.

obones · January 1, 2022, 4:47pm

No, nor are there many dlist files. In the database, there are only 14 of them, all verified but the one from last night.

No Files type for that operation. What’s strange though, is that RemoteOperation contains data starting December 16, nothing earlier than that.
What I mean is that Operation contains IDs starting at 1 as expected, dated on May 1st 2021, but none of these operations are to be found in RemoteOperation
The RemoteVolume table has those operations however.

The Fileset table only contains 14 rows, as expected from the earlier lookup in RemoteVolume, none which are linked to the operation of interest (96)
In that table, only 4 have IsFullBackup set to 0:

Alas not, only 6 records in that table, and all for very recent operations, just like what can be seen in the RemoteOperation table, it starts at OperationID 226 from December 16th.

Well, I guess I can say yes:

sqlite> select Count(*) from Remotevolume where VerificationCount=0;
20149
sqlite> select Count(*) from Remotevolume;
20384

I used CyberDuck to download the file and ran aescrypt -e -p "PASS PHRASE" on it and got this:

Error: Message has been altered and should not be trusted

Same error message as Duplicati, which is definitely not surprising.

I hope this clarifies the situation a bit

ts678 · January 1, 2022, 6:47pm

That’s not a guaranteed issue. I think the count should match Fileset row count and the Remotevolume Type Files count (ignoring State Deleted). I have 21 expected dlist, which matches my home page’s “21 Versions”.

I forgot about log-retention which will interfere with this and LogData, but default is 30 days, unless changed. Another way to lose old data of this sort is to recreate the database. That gets essentials but not the log info.
Operation table does not seem to be trimmed. Mine goes to Oct 6, but the two trimmed ones go for 30 days.

It might be the RemoteOperation table trimming, but retention trim seems too soon unless you decreased it. Lack of such trimming is another reason why an external log-file is best. It also shows what DB rolls back…

There are some issues where, for example, a compact deletes a dindex, errors out, and rolls back DB data. Actual destination file deletion remains, of course, so next backup thinks it has a missing file, but I digress…

Back to the dlist, your retention policy deletes backup versions, so maybe that’s why there’s no aged dlist. External log at even log-file-log-level=Information is enough to show file deletions. Retry level is a little better.

0 is not exactly an all-went-fine result, but can occur if backup is interrupted. It would list as partial in the GUI.
Converting some Timestamp to UTC, it looks like the Aug 27 backup got deleted by retention. Gap in Fileset:

1629252391 August 18, 2021
1632276432 September 22, 2021

Do you by any chance have log-retention set to 14D?

To have fewer of these (and more verification, and unfortunately more B2 download charges), you can use backup-test-samples or backup-test-percentage to keep a closer eye on the contents of the uploaded files.

The TEST command from Commandline or shell can also test-on-demand as many files as you would like.

I was hoping that more could be gotten from the DB, but there’s too much missing. The damaged dblock is uploaded at end of backup, and even though the dindex files were later, the dblock files might have finished after the dindex did (because they’re larger). I don’t know if future inspection will show issue-at-end pattern.

You can stop file upload from finishing out-of-sequence by setting this option to 1. It may slow upload rates:

  --asynchronous-concurrent-upload-limit (Integer): The number of concurrent
    uploads allowed
    When performing asynchronous uploads, the maximum number of concurrent
    uploads allowed. Set to zero to disable the limit.
    * default value: 4

Free options include increasing log retention, setting up external log file, playing with upload concurrency, looking at damaged files for any interesting patterns (e.g. empty blocks in the middle or at the end of file).

You might be able to correlate errors with something. For example, you might find system boots like this:

 who --boot /var/log/wtmp
         system boot  2021-01-31 19:42
         system boot  2021-01-31 20:13
         system boot  2021-10-08 09:45
         system boot  2021-10-08 10:26
         system boot  2021-11-30 15:14

Would you consider helping any with either SQL queries or issues that might flat-out be SQLite. Scaling to large backups has been a problem, and I’ve seemingly had DB Browser for SQLite read DB for 26 days…
There’s other technical info there, and some concerning reports about SQLite performance dropoffs here.

obones · January 4, 2022, 2:38pm

I do not specify it on the command line, so I believe it has its default value of 30D. But the source data does not change not that often, so it’s completely possible nothing happened between mid November and mid December.

Yes, I ran it on another backup that has a local hard drive as a target, and it worked just fine. Well, it complained about extras, but it appears these are benign and can be ignored

Yes, it slows them to a crawl, B2 is throttling individual uploads.

I can give a hand, yes, of course. That being said, I have never encountered an error in SQLite itself, but always in my own setup of the library, or the queries I run against it.

For the problem at hand, I have created an issue to get the name of the broken file even at default log level. Then I removed the broken file from the backend as it keeps popping up as an error, ran list-broken-files and purge-broken-files to, I hope, get to a fixed situation.

ts678 · January 5, 2022, 2:30am

I never lack a name when I get an error (testing on Windows to local folder though) but errors are erratic. Corrupting an encrypted dblock with Frhed to change some byte in the middle of the file gets hash error:

Running commandline entry
Finished!

            
Backup started at 1/4/2022 8:34:01 PM
Checking remote backup ...
  Listing remote folder ...
Scanning local files ...
  0 files need to be examined (0 bytes)
  Uploading file (1.01 KB) ...
Checking remote backup ...
  Listing remote folder ...
Verifying remote backup ...
Remote backup verification completed
  Downloading file (1.01 KB) ...
  Downloading file (27.22 KB) ...
  Downloading file (39.27 MB) ...
  Downloading file (39.27 MB) ...
  Downloading file (39.27 MB) ...
  Downloading file (39.27 MB) ...
  Downloading file (39.27 MB) ...
Failed to process file duplicati-b630d3bea562145a49486d0a5d8accffa.dblock.zip.aes => Hash mismatch on file "C:\Users\Maintenance\AppData\Local\Temp\dup-ed0bdaf9-a5b1-46bd-93ec-71145eb148d4", recorded hash: KoisxBN3gpcR5yD4nhXETCj3+I2yGX8oRvapbfjzSts=, actual hash 8tJuFk8ridaufnjn/4NX0V9xQg/cW/TWtnDs5MPSaZA=
  Duration of backup: 00:00:42
  Remote files: 4
  Remote size: 39.30 MB
  Total remote quota: 930.97 GB
  Available remote quota: 279.01 GB
  Files added: 0
  Files deleted: 0
  Files changed: 0
  Data uploaded: 1.01 KB
  Data downloaded: 196.37 MB
Backup completed successfully!
Return code: 3

To try to bypass that, I get the SHA-256 sum of the modified dblock (using DigitalVolcano Hash Tool), paste hex to https://cryptii.com/ to convert to RFC 3548 Base64, and edit the result into the Remotevolume table.

This is good enough for the after-backup verification (which I tried to make more realistic by setting upload-unchanged-backups), but I can get a Commandline test to notice the corrupted file and fail but with name:

Running commandline entry
Finished!

            
  Listing remote folder ...
  Downloading file (1.01 KB) ...
  Downloading file (27.22 KB) ...
  Downloading file (39.27 MB) ...
  Downloading file (39.27 MB) ...
  Downloading file (39.27 MB) ...
  Downloading file (39.27 MB) ...
  Downloading file (39.27 MB) ...
Failed to process file duplicati-b630d3bea562145a49486d0a5d8accffa.dblock.zip.aes => Failed to decrypt data (invalid passphrase?): Message has been altered, do not trust content
duplicati-i6505dfd834f14302adc113c3a0cafc54.dindex.zip.aes: 1 errors
	Modified: duplicati-b630d3bea562145a49486d0a5d8accffa.dblock.zip.aes

duplicati-b630d3bea562145a49486d0a5d8accffa.dblock.zip.aes: 1 errors
	Error: Failed to decrypt data (invalid passphrase?): Message has been altered, do not trust content

Return code: 3

I’m not familiar with the code and wouldn’t mind if a developer were willing to help look into verification plan. Preferably they could try Linux or you might try Windows on duplicati-2.0.6.3_beta_2021-06-17.zip from 2.0.6.3_beta_2021-06-17. Passphrase is passphrase and I corrupted offset 0x200 from 0xe9 to 0x00 although the exact contents, hash, etc. will probably vary. There’s a “Created” time field in its manifest file. AES File Format has some header and trailer info that I wanted to miss – hit the middle of 1-dblock backup where default sample size of 1 is going to sample the corrupted dblock without my having to watch names.

obones · January 5, 2022, 4:40pm

Could it be because I’m using parallel upload? This way, the exceptions are “grouped” together in an AggregateException that may not get displayed entirely properly on the command line output.

ts678 · January 5, 2022, 5:56pm

I’m using default of 4 concurrent, as well as default of pretty much everything else that wasn’t stated.

If you’ve got some non-default options, maybe something is doing it, or maybe it’s Linux. I don’t know.

I would hope that the uploads are done by the time file sampling starts, or the file might not be up yet.

Clearly something is behind the different results, but more testing is needed to try to isolate the issue.