Understanding log error

smn.mro · August 18, 2019, 3:40pm

Hello all! I’m new to Duplicati, testing it for the first time. I’m using OneDrive as backup destination.
I’m executing the backup once a day but always getting at least one error which I’m not able to understand from where it comes.

The strange thing is that from the “Home” page it says, as date of the last SUCCESSFUL backup, the one in which the back is completed, as it was without errors. In other words, first it reports an error and then it says the backup was successful.

Can I post here the log? May I get from anybody a little help to understand where is the problem?
I’m running Duplicati 2.0.4.23_beta_2019-07-14, which looks the last one.

Once fixed this, I’ll definitively adopt the system and proceed to donate to support the project which looks very promising.

Many thanks for your kind attentions.
Simon

drwtsn32 · August 19, 2019, 9:55pm

Sure, you can post the log details and we will try to figure out what is going on.

Thanks

smn.mro · August 20, 2019, 7:12am

Many thanks for your reply.
At the end of each backup I always get a notification about one or two errors, when I click to show I’m redirected to the “Log data for <backup_name>”.
Please see below the last result.

Let me know if you need more.

Aug 19, 2019 2:31 PM: Result
DeletedFiles: 3

DeletedFolders: 0

ModifiedFiles: 10

ExaminedFiles: 72136

OpenedFiles: 97

AddedFiles: 87

SizeOfModifiedFiles: 3177870

SizeOfAddedFiles: 622698484

SizeOfExaminedFiles: 325569472496

SizeOfOpenedFiles: 629982646

NotProcessedFiles: 0

AddedFolders: 1

TooLargeFiles: 0

FilesWithError: 0

ModifiedFolders: 0

ModifiedSymlinks: 0

AddedSymlinks: 0

DeletedSymlinks: 0

PartialBackup: False

Dryrun: False

MainOperation: Backup

CompactResults:

DeletedFileCount: 2

DownloadedFileCount: 0

UploadedFileCount: 0

DeletedFileSize: 8055050

DownloadedFileSize: 0

UploadedFileSize: 0

Dryrun: False

MainOperation: Compact

ParsedResult: Error

Version: 2.0.4.23 (2.0.4.23_beta_2019-07-14)

EndTime: 8/19/2019 2:26:13 PM (1566217573)

BeginTime: 8/19/2019 2:25:54 PM (1566217554)

Duration: 00:00:19.0121986

Messages: [

    2019-08-19 14:08:38 +02 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started,

    2019-08-19 14:09:21 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started:  (),

    2019-08-19 14:11:46 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed:  (11.45 KB),

    2019-08-19 14:12:23 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-b3f93cf0f6e424122859d750b5e1f501d.dblock.zip.aes (49.93 MB),

    2019-08-19 14:12:52 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-b3f93cf0f6e424122859d750b5e1f501d.dblock.zip.aes (49.93 MB),

…

]

Warnings: [

    2019-08-19 14:11:50 +02 - [Warning-Duplicati.Library.Main.Operation.Backup.FileBlockProcessor.FileEntry-PathProcessingFailed]: Failed to process path: C:\Users\simon\OneDrive\.849C9593-D756-4E56-8D6E-42412F2A707B

]

Errors: [

    2019-08-19 14:30:27 +02 - [Error-Duplicati.Library.Main.Operation.TestHandler-FailedToProcessFile]: Failed to process file duplicati-20190819T120839Z.dlist.zip.aes

]

BackendStatistics:

    RemoteCalls: 38

    BytesUploaded: 599869237

    BytesDownloaded: 94746603

    FilesUploaded: 25

    FilesDownloaded: 7

    FilesDeleted: 4

    FoldersCreated: 0

    RetryAttempts: 4

    UnknownFileSize: 0

    UnknownFileCount: 0

    KnownFileCount: 11743

    KnownFileSize: 307288020867

    LastBackupDate: 8/19/2019 2:08:39 PM (1566216519)

    BackupListCount: 7

    TotalQuotaSpace: 1104880336896

    FreeQuotaSpace: 797591917946

    AssignedQuotaSpace: -1

    ReportedQuotaError: False

    ReportedQuotaWarning: False

    ParsedResult: Error

    Version: 2.0.4.23 (2.0.4.23_beta_2019-07-14)

    Messages: [

        2019-08-19 14:08:38 +02 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started,

        2019-08-19 14:09:21 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started:  (),

        2019-08-19 14:11:46 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed:  (11.45 KB),

        2019-08-19 14:12:23 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-b3f93cf0f6e424122859d750b5e1f501d.dblock.zip.aes (49.93 MB),

        2019-08-19 14:12:52 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-b3f93cf0f6e424122859d750b5e1f501d.dblock.zip.aes (49.93 MB),

…

    ]

    Warnings: [

        2019-08-19 14:11:50 +02 - [Warning-Duplicati.Library.Main.Operation.Backup.FileBlockProcessor.FileEntry-PathProcessingFailed]: Failed to process path: C:\Users\simon\OneDrive\.849C9593-D756-4E56-8D6E-42412F2A707B

    ]

    Errors: [

        2019-08-19 14:30:27 +02 - [Error-Duplicati.Library.Main.Operation.TestHandler-FailedToProcessFile]: Failed to process file duplicati-20190819T120839Z.dlist.zip.aes

    ]

DeleteResults:

DeletedSets: [

    Item1: 1

    Item2: 8/18/2019 5:22:36 PM (1566141756),

    Item1: 6

    Item2: 8/12/2019 1:00:00 PM (1565607600)

]

Dryrun: False

MainOperation: Delete

ParsedResult: Error

Version: 2.0.4.23 (2.0.4.23_beta_2019-07-14)

EndTime: 8/19/2019 2:26:13 PM (1566217573)

BeginTime: 8/19/2019 2:25:28 PM (1566217528)

Duration: 00:00:45.1742126

Messages: [

    2019-08-19 14:08:38 +02 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started,

    2019-08-19 14:09:21 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started:  (),

    2019-08-19 14:11:46 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed:  (11.45 KB),

    2019-08-19 14:12:23 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-b3f93cf0f6e424122859d750b5e1f501d.dblock.zip.aes (49.93 MB),

    2019-08-19 14:12:52 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-b3f93cf0f6e424122859d750b5e1f501d.dblock.zip.aes (49.93 MB),

…

]

Warnings: [

    2019-08-19 14:11:50 +02 - [Warning-Duplicati.Library.Main.Operation.Backup.FileBlockProcessor.FileEntry-PathProcessingFailed]: Failed to process path: C:\Users\simon\OneDrive\.849C9593-D756-4E56-8D6E-42412F2A707B

]

Errors: [

    2019-08-19 14:30:27 +02 - [Error-Duplicati.Library.Main.Operation.TestHandler-FailedToProcessFile]: Failed to process file duplicati-20190819T120839Z.dlist.zip.aes

]

RepairResults: null

TestResults:

MainOperation: Test

Verifications: [

    Key: duplicati-20190819T120839Z.dlist.zip.aes

    Value: [

        Key: Error

        Value: Hash mismatch on file "C:\Users\simon\AppData\Local\Temp\dup-eb859c3a-735f-49f4-a0b6-7155a2c52ecd", recorded hash: JzSkWV8CRTY+DCGEOC2tb/6QG/7pqVb+VZoWZfiGhfg=, actual hash /HZqoSHwDYYDLdCnsRK8cwLqZutQy5ul1dG2ZNhfzgQ=

    ],

    Key: duplicati-i494ff9274d8d42de896adfa2cb9558cc.dindex.zip.aes

    Value: [],

    Key: duplicati-b3dbb8ce76dfe449ba714deef4b837e58.dblock.zip.aes

    Value: []

]

ParsedResult: Error

Version: 2.0.4.23 (2.0.4.23_beta_2019-07-14)

EndTime: 8/19/2019 2:31:56 PM (1566217916)

BeginTime: 8/19/2019 2:28:23 PM (1566217703)

Duration: 00:03:32.5788584

Messages: [

    2019-08-19 14:08:38 +02 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started,

    2019-08-19 14:09:21 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started:  (),

    2019-08-19 14:11:46 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed:  (11.45 KB),

    2019-08-19 14:12:23 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-b3f93cf0f6e424122859d750b5e1f501d.dblock.zip.aes (49.93 MB),

    2019-08-19 14:12:52 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-b3f93cf0f6e424122859d750b5e1f501d.dblock.zip.aes (49.93 MB),

…

]

Warnings: [

    2019-08-19 14:11:50 +02 - [Warning-Duplicati.Library.Main.Operation.Backup.FileBlockProcessor.FileEntry-PathProcessingFailed]: Failed to process path: C:\Users\simon\OneDrive\.849C9593-D756-4E56-8D6E-42412F2A707B

]

Errors: [

    2019-08-19 14:30:27 +02 - [Error-Duplicati.Library.Main.Operation.TestHandler-FailedToProcessFile]: Failed to process file duplicati-20190819T120839Z.dlist.zip.aes

]

ParsedResult: Error

Version: 2.0.4.23 (2.0.4.23_beta_2019-07-14)

EndTime: 8/19/2019 2:31:56 PM (1566217916)

BeginTime: 8/19/2019 2:08:36 PM (1566216516)

Duration: 00:23:19.5673770

Messages: [

2019-08-19 14:08:38 +02 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started,

2019-08-19 14:09:21 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started:  (),

2019-08-19 14:11:46 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed:  (11.45 KB),

2019-08-19 14:12:23 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-b3f93cf0f6e424122859d750b5e1f501d.dblock.zip.aes (49.93 MB),

2019-08-19 14:12:52 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-b3f93cf0f6e424122859d750b5e1f501d.dblock.zip.aes (49.93 MB),

…

]

Warnings: [

2019-08-19 14:11:50 +02 - [Warning-Duplicati.Library.Main.Operation.Backup.FileBlockProcessor.FileEntry-PathProcessingFailed]: Failed to process path: C:\Users\simon\OneDrive\.849C9593-D756-4E56-8D6E-42412F2A707B

]

Errors: [

2019-08-19 14:30:27 +02 - [Error-Duplicati.Library.Main.Operation.TestHandler-FailedToProcessFile]: Failed to process file duplicati-20190819T120839Z.dlist.zip.aes

]

drwtsn32 · August 20, 2019, 1:50pm

This one is probably because the file is locked. One solution is to use --snapshot-policy to back up open/locked files. Note that you must run the Duplicati process with elevated rights to use snapshots.

But this particular file is probably of no value to back up. Snapshots can be useful if you have other - important files - that are often open during backups.

Another solution is to just not back up your OneDrive folder since it’s already “backed up” by Microsoft.

I have seen other people get this type of error and it was due to them including the Temp directory in the backups. Default Temp directory is C:\Users<username>\AppData\Local\Temp - do you have that included in your backups?

In my opinion there is usually no data of value in AppData\Local so I would not include it. I do include AppData\Roaming though. Your mileage may vary…

smn.mro · August 21, 2019, 2:26pm

Thanks for you message. I could solve one issue with one system hidden file, now excluded.

I still have an error, this time related to an hash mismatch…

I confirm I’m NOT including any AppData folder in the backup.
Instead I need to backup OneDrive, as what Microsoft is actually doing is a sync, not really a backup… and I would like to have a backup of the entire OneDrive folder.

Here the log.

Aug 21, 2019 4:20 PM: Result
DeletedFiles: 0

DeletedFolders: 0

ModifiedFiles: 1

ExaminedFiles: 72114

OpenedFiles: 1

AddedFiles: 0

SizeOfModifiedFiles: 12117

SizeOfAddedFiles: 0

SizeOfExaminedFiles: 325571379419

SizeOfOpenedFiles: 12117

NotProcessedFiles: 0

AddedFolders: 0

TooLargeFiles: 0

FilesWithError: 0

ModifiedFolders: 0

ModifiedSymlinks: 0

AddedSymlinks: 0

DeletedSymlinks: 0

PartialBackup: False

Dryrun: False

MainOperation: Backup

CompactResults:

DeletedFileCount: 0

DownloadedFileCount: 0

UploadedFileCount: 0

DeletedFileSize: 0

DownloadedFileSize: 0

UploadedFileSize: 0

Dryrun: False

MainOperation: Compact

ParsedResult: Error

Version: 2.0.4.23 (2.0.4.23_beta_2019-07-14)

EndTime: 8/21/2019 4:15:26 PM (1566396926)

BeginTime: 8/21/2019 4:15:12 PM (1566396912)

Duration: 00:00:13.9273559

Messages: [

    2019-08-21 16:11:25 +02 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started,

    2019-08-21 16:11:44 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started:  (),

    2019-08-21 16:13:50 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed:  (11.47 KB),

    2019-08-21 16:14:32 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-b0ac9985f1673477fb45fcfeaff921f8d.dblock.zip.aes (10.67 KB),

    2019-08-21 16:14:34 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-b0ac9985f1673477fb45fcfeaff921f8d.dblock.zip.aes (10.67 KB),

…

]

Warnings: []

Errors: [

    2019-08-21 16:19:37 +02 - [Error-Duplicati.Library.Main.Operation.TestHandler-FailedToProcessFile]: Failed to process file duplicati-20190821T141125Z.dlist.zip.aes

]

BackendStatistics:

    RemoteCalls: 13

    BytesUploaded: 8472727

    BytesDownloaded: 94683115

    FilesUploaded: 3

    FilesDownloaded: 7

    FilesDeleted: 1

    FoldersCreated: 0

    RetryAttempts: 4

    UnknownFileSize: 0

    UnknownFileCount: 0

    KnownFileCount: 11751

    KnownFileSize: 307290442875

    LastBackupDate: 8/21/2019 4:11:25 PM (1566396685)

    BackupListCount: 7

    TotalQuotaSpace: 1104880336896

    FreeQuotaSpace: 797589495938

    AssignedQuotaSpace: -1

    ReportedQuotaError: False

    ReportedQuotaWarning: False

    ParsedResult: Error

    Version: 2.0.4.23 (2.0.4.23_beta_2019-07-14)

    Messages: [

        2019-08-21 16:11:25 +02 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started,

        2019-08-21 16:11:44 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started:  (),

        2019-08-21 16:13:50 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed:  (11.47 KB),

        2019-08-21 16:14:32 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-b0ac9985f1673477fb45fcfeaff921f8d.dblock.zip.aes (10.67 KB),

        2019-08-21 16:14:34 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-b0ac9985f1673477fb45fcfeaff921f8d.dblock.zip.aes (10.67 KB),

…

    ]

    Warnings: []

    Errors: [

        2019-08-21 16:19:37 +02 - [Error-Duplicati.Library.Main.Operation.TestHandler-FailedToProcessFile]: Failed to process file duplicati-20190821T141125Z.dlist.zip.aes

    ]

DeleteResults:

DeletedSets: [

    Item1: 1

    Item2: 8/21/2019 1:09:12 PM (1566385752)

]

Dryrun: False

MainOperation: Delete

ParsedResult: Error

Version: 2.0.4.23 (2.0.4.23_beta_2019-07-14)

EndTime: 8/21/2019 4:15:26 PM (1566396926)

BeginTime: 8/21/2019 4:14:53 PM (1566396893)

Duration: 00:00:32.6263875

Messages: [

    2019-08-21 16:11:25 +02 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started,

    2019-08-21 16:11:44 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started:  (),

    2019-08-21 16:13:50 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed:  (11.47 KB),

    2019-08-21 16:14:32 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-b0ac9985f1673477fb45fcfeaff921f8d.dblock.zip.aes (10.67 KB),

    2019-08-21 16:14:34 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-b0ac9985f1673477fb45fcfeaff921f8d.dblock.zip.aes (10.67 KB),

…

]

Warnings: []

Errors: [

    2019-08-21 16:19:37 +02 - [Error-Duplicati.Library.Main.Operation.TestHandler-FailedToProcessFile]: Failed to process file duplicati-20190821T141125Z.dlist.zip.aes

]

RepairResults: null

TestResults:

MainOperation: Test

Verifications: [

    Key: duplicati-20190821T141125Z.dlist.zip.aes

    Value: [

        Key: Error

        Value: Hash mismatch on file "C:\Users\simon\AppData\Local\Temp\dup-96252182-97a0-4d35-ac2b-cce860abdb99", recorded hash: GcGj+0WNDML7AzNl9Rlt7tQ7QPprWn9TVAzJG66XEz8=, actual hash urY8lEOBlq/0u4YB8lHnAg/jw+egJcJElfKKd7zqqd0=

    ],

    Key: duplicati-iff22a5449b914cd6bb952a447ea96fde.dindex.zip.aes

    Value: [],

    Key: duplicati-b8d9e7469f62b456cbdfd0033e0925470.dblock.zip.aes

    Value: []

]

ParsedResult: Error

Version: 2.0.4.23 (2.0.4.23_beta_2019-07-14)

EndTime: 8/21/2019 4:20:53 PM (1566397253)

BeginTime: 8/21/2019 4:17:52 PM (1566397072)

Duration: 00:03:00.9716623

Messages: [

    2019-08-21 16:11:25 +02 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started,

    2019-08-21 16:11:44 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started:  (),

    2019-08-21 16:13:50 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed:  (11.47 KB),

    2019-08-21 16:14:32 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-b0ac9985f1673477fb45fcfeaff921f8d.dblock.zip.aes (10.67 KB),

    2019-08-21 16:14:34 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-b0ac9985f1673477fb45fcfeaff921f8d.dblock.zip.aes (10.67 KB),

…

]

Warnings: []

Errors: [

    2019-08-21 16:19:37 +02 - [Error-Duplicati.Library.Main.Operation.TestHandler-FailedToProcessFile]: Failed to process file duplicati-20190821T141125Z.dlist.zip.aes

]

ParsedResult: Error

Version: 2.0.4.23 (2.0.4.23_beta_2019-07-14)

EndTime: 8/21/2019 4:20:53 PM (1566397253)

BeginTime: 8/21/2019 4:11:25 PM (1566396685)

Duration: 00:09:28.2003906

Messages: [

2019-08-21 16:11:25 +02 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started,

2019-08-21 16:11:44 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started:  (),

2019-08-21 16:13:50 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed:  (11.47 KB),

2019-08-21 16:14:32 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-b0ac9985f1673477fb45fcfeaff921f8d.dblock.zip.aes (10.67 KB),

2019-08-21 16:14:34 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-b0ac9985f1673477fb45fcfeaff921f8d.dblock.zip.aes (10.67 KB),

…

]

Warnings:

Errors: [

2019-08-21 16:19:37 +02 - [Error-Duplicati.Library.Main.Operation.TestHandler-FailedToProcessFile]: Failed to process file duplicati-20190821T141125Z.dlist.zip.aes

]

drwtsn32 · August 21, 2019, 3:15pm

Again, that one looks like the Duplicati temp directory is being included in your backups.

Do you have C:\Users or C:\Users\<username> selected for backup?

smn.mro · August 21, 2019, 4:46pm

Please find attached the screenshot of the sources.

Outlook Files contains the .pst file, and I’m keeping Outlook closed during the backup. Priv.CRYP is an encrypted local folder with personal stuff, OneDrive is the complete OneDrive folder from where I’ve already removed the hidden and system files.

ts678 · August 21, 2019, 4:52pm

Welcome to the forum @smn.mro

If I might try a different angle on this,

Sometimes log errors are hard to interpret, especially if only one line is shown. Fortunately you got more, so I’ll offer another possibility for what is going on. This might take some back-and-forth for further debug.

MainOperation: Test

Verifications: [

    Key: duplicati-20190819T120839Z.dlist.zip.aes

    Value: [

        Key: Error

        Value: Hash mismatch on file "C:\Users\simon\AppData\Local\Temp\dup-eb859c3a-735f-49f4-a0b6-7155a2c52ecd", recorded hash: JzSkWV8CRTY+DCGEOC2tb/6QG/7pqVb+VZoWZfiGhfg=, actual hash /HZqoSHwDYYDLdCnsRK8cwLqZutQy5ul1dG2ZNhfzgQ=

    ],

and

possibly go together. The mentioned test involves a download, and the download gets checked for correct hash. If file is not what was expected, a retry is done. As a long shot, do you have any upload or download speed throttling? There have been some issues fixed, and OneDrive is one backend known to be affected.

Failed to process file … due to HashMismatchException error says more about this idea, including fix link. Whether or not that fix will fix your case is TBD, and far less likely if you are not using any sort of throttling.

EDIT:

Regardless of cause, you can try downloading the file giving the complaint, directly from the OneDrive UI. You can use any zip program to try your luck opening it, if it’s unencrypted. If encrypted, AES Crypt can do decryption (or fail trying, if file is actually bad). If you prefer Duplicati’s CLI tool, please try SharpAESCrypt.

smn.mro · August 22, 2019, 4:37pm

I had in fact a limitation in upload. Disabled, but still some errors are reported… getting frustrated…
Should I delete the complete backup and do all again?

Here the log again:

DeletedFiles: 0

DeletedFolders: 0

ModifiedFiles: 0

ExaminedFiles: 72118

OpenedFiles: 1

AddedFiles: 1

SizeOfModifiedFiles: 0

SizeOfAddedFiles: 1417577472

SizeOfExaminedFiles: 325571436422

SizeOfOpenedFiles: 1417577472

NotProcessedFiles: 0

AddedFolders: 0

TooLargeFiles: 0

FilesWithError: 0

ModifiedFolders: 0

ModifiedSymlinks: 0

AddedSymlinks: 0

DeletedSymlinks: 0

PartialBackup: False

Dryrun: False

MainOperation: Backup

CompactResults:

DeletedFileCount: 0

DownloadedFileCount: 0

UploadedFileCount: 0

DeletedFileSize: 0

DownloadedFileSize: 0

UploadedFileSize: 0

Dryrun: False

MainOperation: Compact

ParsedResult: Error

Version: 2.0.4.23 (2.0.4.23_beta_2019-07-14)

EndTime: 8/22/2019 6:27:08 PM (1566491228)

BeginTime: 8/22/2019 6:26:54 PM (1566491214)

Duration: 00:00:14.0423171

Messages: [

    2019-08-22 18:21:54 +02 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started,

    2019-08-22 18:22:32 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started:  (),

    2019-08-22 18:25:27 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed:  (11.48 KB),

    2019-08-22 18:26:20 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-be74f63999f084f3babb354e9e9b5099c.dblock.zip.aes (2.30 MB),

    2019-08-22 18:26:27 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-be74f63999f084f3babb354e9e9b5099c.dblock.zip.aes (2.30 MB),

…

]

Warnings: []

Errors: [

    2019-08-22 18:30:51 +02 - [Error-Duplicati.Library.Main.Operation.TestHandler-FailedToProcessFile]: Failed to process file duplicati-20190821T070451Z.dlist.zip.aes

]

BackendStatistics:

    RemoteCalls: 13

    BytesUploaded: 11314423

    BytesDownloaded: 94728683

    FilesUploaded: 3

    FilesDownloaded: 7

    FilesDeleted: 1

    FoldersCreated: 0

    RetryAttempts: 4

    UnknownFileSize: 0

    UnknownFileCount: 0

    KnownFileCount: 11755

    KnownFileSize: 307293380335

    LastBackupDate: 8/22/2019 6:21:54 PM (1566490914)

    BackupListCount: 7

    TotalQuotaSpace: 1104880336896

    FreeQuotaSpace: 797586558438

    AssignedQuotaSpace: -1

    ReportedQuotaError: False

    ReportedQuotaWarning: False

    ParsedResult: Error

    Version: 2.0.4.23 (2.0.4.23_beta_2019-07-14)

    Messages: [

        2019-08-22 18:21:54 +02 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started,

        2019-08-22 18:22:32 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started:  (),

        2019-08-22 18:25:27 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed:  (11.48 KB),

        2019-08-22 18:26:20 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-be74f63999f084f3babb354e9e9b5099c.dblock.zip.aes (2.30 MB),

        2019-08-22 18:26:27 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-be74f63999f084f3babb354e9e9b5099c.dblock.zip.aes (2.30 MB),

…

    ]

    Warnings: []

    Errors: [

        2019-08-22 18:30:51 +02 - [Error-Duplicati.Library.Main.Operation.TestHandler-FailedToProcessFile]: Failed to process file duplicati-20190821T070451Z.dlist.zip.aes

    ]

DeleteResults:

DeletedSets: [

    Item1: 5

    Item2: 8/15/2019 3:57:53 PM (1565877473)

]

Dryrun: False

MainOperation: Delete

ParsedResult: Error

Version: 2.0.4.23 (2.0.4.23_beta_2019-07-14)

EndTime: 8/22/2019 6:27:08 PM (1566491228)

BeginTime: 8/22/2019 6:26:34 PM (1566491194)

Duration: 00:00:34.4685051

Messages: [

    2019-08-22 18:21:54 +02 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started,

    2019-08-22 18:22:32 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started:  (),

    2019-08-22 18:25:27 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed:  (11.48 KB),

    2019-08-22 18:26:20 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-be74f63999f084f3babb354e9e9b5099c.dblock.zip.aes (2.30 MB),

    2019-08-22 18:26:27 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-be74f63999f084f3babb354e9e9b5099c.dblock.zip.aes (2.30 MB),

…

]

Warnings: []

Errors: [

    2019-08-22 18:30:51 +02 - [Error-Duplicati.Library.Main.Operation.TestHandler-FailedToProcessFile]: Failed to process file duplicati-20190821T070451Z.dlist.zip.aes

]

RepairResults: null

TestResults:

MainOperation: Test

Verifications: [

    Key: duplicati-20190821T070451Z.dlist.zip.aes

    Value: [

        Key: Error

        Value: Hash mismatch on file "C:\Users\simon\AppData\Local\Temp\dup-f55f01c0-cec8-483e-904a-c15af73f7aa0", recorded hash: TI8X74paQAOLbhrQBJx53gk0RKtbuUZt/7jzspatyaM=, actual hash /kHpDw+kp7mN82pZ3lyBxB3uJIbGZw/sC8fMH9IBkeU=

    ],

    Key: duplicati-ic34b776fb66541abb01dbf4b77c8079c.dindex.zip.aes

    Value: [],

    Key: duplicati-b831dc8f81f2049e986a1ae5ce3505400.dblock.zip.aes

    Value: []

]

ParsedResult: Error

Version: 2.0.4.23 (2.0.4.23_beta_2019-07-14)

EndTime: 8/22/2019 6:31:15 PM (1566491475)

BeginTime: 8/22/2019 6:29:31 PM (1566491371)

Duration: 00:01:43.5708246

Messages: [

    2019-08-22 18:21:54 +02 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started,

    2019-08-22 18:22:32 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started:  (),

    2019-08-22 18:25:27 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed:  (11.48 KB),

    2019-08-22 18:26:20 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-be74f63999f084f3babb354e9e9b5099c.dblock.zip.aes (2.30 MB),

    2019-08-22 18:26:27 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-be74f63999f084f3babb354e9e9b5099c.dblock.zip.aes (2.30 MB),

…

]

Warnings: []

Errors: [

    2019-08-22 18:30:51 +02 - [Error-Duplicati.Library.Main.Operation.TestHandler-FailedToProcessFile]: Failed to process file duplicati-20190821T070451Z.dlist.zip.aes

]

ParsedResult: Error

Version: 2.0.4.23 (2.0.4.23_beta_2019-07-14)

EndTime: 8/22/2019 6:31:15 PM (1566491475)

BeginTime: 8/22/2019 6:21:54 PM (1566490914)

Duration: 00:09:20.9134489

Messages: [

2019-08-22 18:21:54 +02 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started,

2019-08-22 18:22:32 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started:  (),

2019-08-22 18:25:27 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed:  (11.48 KB),

2019-08-22 18:26:20 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-be74f63999f084f3babb354e9e9b5099c.dblock.zip.aes (2.30 MB),

2019-08-22 18:26:27 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-be74f63999f084f3babb354e9e9b5099c.dblock.zip.aes (2.30 MB),

…

]

Warnings:

Errors: [

2019-08-22 18:30:51 +02 - [Error-Duplicati.Library.Main.Operation.TestHandler-FailedToProcessFile]: Failed to process file duplicati-20190821T070451Z.dlist.zip.aes

]

ts678 · August 22, 2019, 7:55pm

Assuming that refers to Duplicati’s speed throttling, that can cause permanent damage to backup files. v2.0.4.22-2.0.4.22_canary_2019-06-30 fixes it, but it’s not in your beta (despite higher version number).

When you post logs, putting three characters ~~~ above and below avoids some formatting confusion, however I think I was able to find these three unique errors, and the last one refers to a day before’s file:

2019-08-19 14:30:27 +02 - [Error-Duplicati.Library.Main.Operation.TestHandler-FailedToProcessFile]: Failed to process file duplicati-20190819T120839Z.dlist.zip.aes

2019-08-21 16:19:37 +02 - [Error-Duplicati.Library.Main.Operation.TestHandler-FailedToProcessFile]: Failed to process file duplicati-20190821T141125Z.dlist.zip.aes

2019-08-22 18:30:51 +02 - [Error-Duplicati.Library.Main.Operation.TestHandler-FailedToProcessFile]: Failed to process file duplicati-20190821T070451Z.dlist.zip.aes

File tests get balanced across the files by a verification count which I think only goes up if it actually works.

You can do the test I mentioned before on any of those three files to see if they are actually bad, but I think dlist (and dindex) files can be rebuilt from the database IF they’re the only files that had anything go wrong.

You can ask Duplicati to test all files to see if it finds any other of this sort of issue, or if you have your files locally on your PC as well (due to OneDrive) there’s a way based on –upload-verification-file and the script DuplicatiVerify.ps1 in your Duplicati utility-scripts folder to verify the entire contents of backup files at once.

This is a pretty big backup, about 325 GB? How’s your upload speed? A fresh backup is safest but slow… Breaking it up into slowly added chunks would be a good idea and also give early evidence of lack of error.

There’s possibly some intermediate way involving version deletion and –no-auto-compact that could also be considered IF the only problem is dlist files. The idea is to just relink files to your already-uploaded files.

I don’t know which ideas have most appeal to you. Of course, ideally the bug would not have been there…