Restore successful but Failed to decrypt data?

Support
#1

I’m experiencing a strange problem when running some test restores from B2. The restore itself seems to work because the recovered file appears in the destination directory as expected, however Duplicati shows messages like these in the restore logs:

2020-03-13 12:31:05 +11 - [Error-Duplicati.Library.Main.Operation.RestoreHandler-PatchingFailed]: Failed to patch with remote file: "duplicati-b0ca4b7f34e6e428d9c80db884d43427c.dblock.zip.aes", message: Failed to decrypt data (invalid passphrase?): Invalid password or corrupted data

What’s strange is that the full restored file seems to appear in the filesystem before anything has been downloaded from B2, according to the live logs. Almost as if Duplicati is sourcing the file locally?

I’ve manually downloaded and successfully decrypted the files using the SharpAESCrypt.exe utility, and the ZIP file they contain also extracts without a problem.

I’m worried that in the case of a full loss I don’t actually have working backups.

Version: 2.0.5.1_beta_2020-01-18
OS: Windows Server 2019 (1809)

Full log:
{
“RestoredFiles”: 1,
“SizeOfRestoredFiles”: 197910528,
“RestoredFolders”: 0,
“RestoredSymlinks”: 0,
“PatchedFiles”: 0,
“DeletedFiles”: 0,
“DeletedFolders”: 0,
“DeletedSymlinks”: 0,
“MainOperation”: “Restore”,
“RecreateDatabaseResults”: null,
“ParsedResult”: “Error”,
“Version”: “2.0.5.1 (2.0.5.1_beta_2020-01-18)”,
“EndTime”: “2020-03-13T01:31:05.8798968Z”,
“BeginTime”: “2020-03-13T01:29:14.2897892Z”,
“Duration”: “00:01:51.5901076”,
“MessagesActualLength”: 15,
“WarningsActualLength”: 0,
“ErrorsActualLength”: 1,
“Messages”: [
“2020-03-13 12:29:14 +11 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Restore has started”,
“2020-03-13 12:29:14 +11 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started: ()”,
“2020-03-13 12:29:21 +11 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed: (5.49 KB)”,
“2020-03-13 12:29:21 +11 - [Information-Duplicati.Library.Main.Database.LocalRestoreDatabase-SearchingBackup]: Searching backup 0 (13/03/2020 12:51:46 AM) …”,
“2020-03-13 12:29:23 +11 - [Information-Duplicati.Library.Main.Operation.RestoreHandler-RemoteFileCount]: 1 remote files are required to restore”,
“2020-03-13 12:29:23 +11 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-b0ca4b7f34e6e428d9c80db884d43427c.dblock.zip.aes (49.92 MB)”,
“2020-03-13 12:29:30 +11 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Retrying: duplicati-b0ca4b7f34e6e428d9c80db884d43427c.dblock.zip.aes (49.92 MB)”,
“2020-03-13 12:29:40 +11 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-b0ca4b7f34e6e428d9c80db884d43427c.dblock.zip.aes (49.92 MB)”,
“2020-03-13 12:29:53 +11 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Retrying: duplicati-b0ca4b7f34e6e428d9c80db884d43427c.dblock.zip.aes (49.92 MB)”,
“2020-03-13 12:30:04 +11 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-b0ca4b7f34e6e428d9c80db884d43427c.dblock.zip.aes (49.92 MB)”,
“2020-03-13 12:30:17 +11 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Retrying: duplicati-b0ca4b7f34e6e428d9c80db884d43427c.dblock.zip.aes (49.92 MB)”,
“2020-03-13 12:30:27 +11 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-b0ca4b7f34e6e428d9c80db884d43427c.dblock.zip.aes (49.92 MB)”,
“2020-03-13 12:30:41 +11 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Retrying: duplicati-b0ca4b7f34e6e428d9c80db884d43427c.dblock.zip.aes (49.92 MB)”,
“2020-03-13 12:30:51 +11 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-b0ca4b7f34e6e428d9c80db884d43427c.dblock.zip.aes (49.92 MB)”,
“2020-03-13 12:31:05 +11 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Failed: duplicati-b0ca4b7f34e6e428d9c80db884d43427c.dblock.zip.aes (49.92 MB)”
],
“Warnings”: ,
“Errors”: [
“2020-03-13 12:31:05 +11 - [Error-Duplicati.Library.Main.Operation.RestoreHandler-PatchingFailed]: Failed to patch with remote file: “duplicati-b0ca4b7f34e6e428d9c80db884d43427c.dblock.zip.aes”, message: Failed to decrypt data (invalid passphrase?): Invalid password or corrupted data”
],
“BackendStatistics”: {
“RemoteCalls”: 6,
“BytesUploaded”: 0,
“BytesDownloaded”: 0,
“FilesUploaded”: 0,
“FilesDownloaded”: 0,
“FilesDeleted”: 0,
“FoldersCreated”: 0,
“RetryAttempts”: 4,
“UnknownFileSize”: 0,
“UnknownFileCount”: 0,
“KnownFileCount”: 5626,
“KnownFileSize”: 147129461586,
“LastBackupDate”: “2020-03-13T11:51:46+11:00”,
“BackupListCount”: 12,
“TotalQuotaSpace”: 0,
“FreeQuotaSpace”: 0,
“AssignedQuotaSpace”: -1,
“ReportedQuotaError”: false,
“ReportedQuotaWarning”: false,
“MainOperation”: “Restore”,
“ParsedResult”: “Success”,
“Version”: “2.0.5.1 (2.0.5.1_beta_2020-01-18)”,
“EndTime”: “0001-01-01T00:00:00”,
“BeginTime”: “2020-03-13T01:29:14.2897892Z”,
“Duration”: “00:00:00”,
“MessagesActualLength”: 0,
“WarningsActualLength”: 0,
“ErrorsActualLength”: 0,
“Messages”: null,
“Warnings”: null,
“Errors”: null
}
}

#2

This is exactly what Duplicati does by default. You can use the --no-local-blocks option to disable the feature. I recommend disabling it and trying again.

#3

OK, that makes sense.

I’ve tried another restore with that option, however it failed completely with the same problem: “Invalid password or corrupted data”.

To be sure the source file is in fact OK, I downloaded bcf65a3b81cfc4c8496f8badda9286e0d.dblock.zip.aes, used SharpAESCrypt.exe to decrypt it, then tested the resulting ZIP file - all OK.

The restore log is below. Any ideas?

{
“RestoredFiles”: 0,
“SizeOfRestoredFiles”: 0,
“RestoredFolders”: 0,
“RestoredSymlinks”: 0,
“PatchedFiles”: 0,
“DeletedFiles”: 0,
“DeletedFolders”: 0,
“DeletedSymlinks”: 0,
“MainOperation”: “Restore”,
“RecreateDatabaseResults”: null,
“ParsedResult”: “Error”,
“Version”: “2.0.5.1 (2.0.5.1_beta_2020-01-18)”,
“EndTime”: “2020-03-15T21:26:41.6333411Z”,
“BeginTime”: “2020-03-15T21:24:44.585007Z”,
“Duration”: “00:01:57.0483341”,
“MessagesActualLength”: 15,
“WarningsActualLength”: 1,
“ErrorsActualLength”: 1,
“Messages”: [
“2020-03-16 08:24:44 +11 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Restore has started”,
“2020-03-16 08:24:50 +11 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started: ()”,
“2020-03-16 08:24:57 +11 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed: (5.51 KB)”,
“2020-03-16 08:24:57 +11 - [Information-Duplicati.Library.Main.Database.LocalRestoreDatabase-SearchingBackup]: Searching backup 0 (15/03/2020 2:00:00 PM) …”,
“2020-03-16 08:24:58 +11 - [Information-Duplicati.Library.Main.Operation.RestoreHandler-RemoteFileCount]: 1 remote files are required to restore”,
“2020-03-16 08:24:58 +11 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-bcf65a3b81cfc4c8496f8badda9286e0d.dblock.zip.aes (49.98 MB)”,
“2020-03-16 08:25:05 +11 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Retrying: duplicati-bcf65a3b81cfc4c8496f8badda9286e0d.dblock.zip.aes (49.98 MB)”,
“2020-03-16 08:25:15 +11 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-bcf65a3b81cfc4c8496f8badda9286e0d.dblock.zip.aes (49.98 MB)”,
“2020-03-16 08:25:28 +11 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Retrying: duplicati-bcf65a3b81cfc4c8496f8badda9286e0d.dblock.zip.aes (49.98 MB)”,
“2020-03-16 08:25:39 +11 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-bcf65a3b81cfc4c8496f8badda9286e0d.dblock.zip.aes (49.98 MB)”,
“2020-03-16 08:25:52 +11 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Retrying: duplicati-bcf65a3b81cfc4c8496f8badda9286e0d.dblock.zip.aes (49.98 MB)”,
“2020-03-16 08:26:02 +11 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-bcf65a3b81cfc4c8496f8badda9286e0d.dblock.zip.aes (49.98 MB)”,
“2020-03-16 08:26:17 +11 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Retrying: duplicati-bcf65a3b81cfc4c8496f8badda9286e0d.dblock.zip.aes (49.98 MB)”,
“2020-03-16 08:26:27 +11 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-bcf65a3b81cfc4c8496f8badda9286e0d.dblock.zip.aes (49.98 MB)”,
“2020-03-16 08:26:41 +11 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Failed: duplicati-bcf65a3b81cfc4c8496f8badda9286e0d.dblock.zip.aes (49.98 MB)”
],
“Warnings”: [
“2020-03-16 08:26:41 +11 - [Warning-Duplicati.Library.Main.Operation.RestoreHandler-NoFilesRestored]: Restore completed without errors but no files were restored”
],
“Errors”: [
“2020-03-16 08:26:41 +11 - [Error-Duplicati.Library.Main.Operation.RestoreHandler-PatchingFailed]: Failed to patch with remote file: “duplicati-bcf65a3b81cfc4c8496f8badda9286e0d.dblock.zip.aes”, message: Failed to decrypt data (invalid passphrase?): Invalid password or corrupted data”
],
“BackendStatistics”: {
“RemoteCalls”: 6,
“BytesUploaded”: 0,
“BytesDownloaded”: 0,
“FilesUploaded”: 0,
“FilesDownloaded”: 0,
“FilesDeleted”: 0,
“FoldersCreated”: 0,
“RetryAttempts”: 4,
“UnknownFileSize”: 0,
“UnknownFileCount”: 0,
“KnownFileCount”: 5639,
“KnownFileSize”: 147332130411,
“LastBackupDate”: “2020-03-16T01:00:00+11:00”,
“BackupListCount”: 15,
“TotalQuotaSpace”: 0,
“FreeQuotaSpace”: 0,
“AssignedQuotaSpace”: -1,
“ReportedQuotaError”: false,
“ReportedQuotaWarning”: false,
“MainOperation”: “Restore”,
“ParsedResult”: “Success”,
“Version”: “2.0.5.1 (2.0.5.1_beta_2020-01-18)”,
“EndTime”: “0001-01-01T00:00:00”,
“BeginTime”: “2020-03-15T21:24:44.585007Z”,
“Duration”: “00:00:00”,
“MessagesActualLength”: 0,
“WarningsActualLength”: 0,
“ErrorsActualLength”: 0,
“Messages”: null,
“Warnings”: null,
“Errors”: null
}
}

#4

Are you doing your backups and restores from the web UI? Or are you doing it with the command line? Just wondering if you are manually supplying the password at some point (besides your SharpAESCrypt test).

#5

I also get a bunch of these, the files get restored but seem corrupt

Errors 1730

  • 2020-03-14 22:40:25 +01 - [Error-Duplicati.Library.Main.Operation.RestoreHandler-PatchingFailed]: Failed to patch with remote file: “duplicati-b7e479e3033be447abffe1b4a84bfeb9d.dblock.zip.aes”, message: Failed to decrypt data (invalid passphrase?): Invalid password or corrupted data

I restore using the web UI but didn’t see any place to enter passphrase?

#6

There was a hidden(!!) field that I could make visible by turning on “inspect” mode in Chrome and editing the html. When the field was visible I could enter the correct password and the restore worked perfectly.

I removed the “ng-hide” seen in the pic

Untitled
Untitled1509×1115 69.3 KB

#7

Normally when restoring from the web UI you don’t have to enter the password, if you are restoring from a defined backup job anyway. It will use the password that’s already saved in that backup job.

#8

Are either of you using a browser-based password manager (could be third party or the one integrated into Chrome, Firefox, etc)? I wonder if it is overriding the hidden encryption password field with another value.

#9

I’m using Chrome which tends to remember filled in fields, not only password fields but other fields too sometimes.

#10

If you’re willing, try deleting any saved passwords in Chrome that correspond to the Duplicati URL, then see if you still have the problem.

1 Like
#11

Wow! That did the trick. Thank you.
I’m using Firefox. After deleting the saved credential all the restores are now working.

Never would have guessed that.

1 Like
#12

FYI

Password saver may autofill too many places, getting --auth-password is not supported #4102
is a similar problem, but in a different spot with a different error. I’m not sure what can be done.
I’m curious if you use a Duplicati Web UI password. That one got filled in too many other fields.

1 Like
#13

I really think this feature/bug/fact (auto fill from browsers/password managers will prevent a restore operation) might should be better documented (or even better, included on the warnings the interface gives). I’ve spent days trying to restore 1 single file from an old backup using the WebUI and only after preventing Chrome and Lastpass (didn’t try any one of them separately, so I am not sure which - or both - are the real culprit) to autofill everything on Localhost I was successful. All other attempts got me the infamous “Invalid password or corrupted data” message.

#14

Welcome to the forum @felipers

Duplicati User’s Manual author may or may not see comments here. The linked page offers this advice:

Corrections/changes/additions may be submitted as a pull request at Github: GitHub - kees-z/DuplicatiDocs: Duplicati User's Manual

Filing an Issue, though not actually recommended in the manual, does seem to be done by some people.

The forum has no ability to track issues, so Duplicati Issues would be another way for issue to be tracked including possible code change. For documentation issues, I see the Documentation label being applied.

#15

Excellent! I made a comment on the newest issue (Password saver may autofill too many places, getting --auth-password is not supported · Issue #4102 · duplicati/duplicati · GitHub). Couldn’t find a troubleshot session on the Manual (and didn’t find appropriate to put this sort of information on the chapter 3 (03-using-the-graphical-user-interface.md).

#16

confirm this issue still happens
Duplicati - 2.0.5.1_beta_2020-01-18
The web GUI is running in Chrome 87.0.4280.88 for Ubuntu 20.04
I removed all passwords from Chrome and it worked
I also enabled no-local-blocks - not sure if I truly understand the value of it as a default on