Failed to process file FailedToProcessFile

Hello everyone, everything good? I have a one drive account with office 365 family where I have 1tb of storage, using the one drive v2 as the destination for my backup files I have the backup completed but an error message is generated below:

[Error-Duplicati.Library.Main.Operation.TestHandler-FailedToProcessFile]: Failed to process file duplicati-b0c5a2c89d8c944be9e86a32c1086b1c7.dblock.zip.aes

Here is the full backup log:

{
“DeletedFiles”: 0,
“DeletedFolders”: 0,
“ModifiedFiles”: 0,
“ExaminedFiles”: 50956,
“OpenedFiles”: 50956,
“AddedFiles”: 50956,
“SizeOfModifiedFiles”: 0,
“SizeOfAddedFiles”: 96889742343,
“SizeOfExaminedFiles”: 96889742343,
“SizeOfOpenedFiles”: 96889742343,
“NotProcessedFiles”: 0,
“AddedFolders”: 4964,
“TooLargeFiles”: 0,
“FilesWithError”: 0,
“ModifiedFolders”: 0,
“ModifiedSymlinks”: 0,
“AddedSymlinks”: 0,
“DeletedSymlinks”: 0,
“PartialBackup”: false,
“Dryrun”: false,
“MainOperation”: “Backup”,
“CompactResults”: null,
“VacuumResults”: null,
“DeleteResults”: {
“DeletedSetsActualLength”: 0,
“DeletedSets”: [],
“Dryrun”: false,
“MainOperation”: “Delete”,
“CompactResults”: null,
“ParsedResult”: “Success”,
“Version”: “2.0.6.3 (2.0.6.3_beta_2021-06-17)”,
“EndTime”: “2023-01-02T19:33:46.6122307Z”,
“BeginTime”: “2023-01-02T19:33:35.5093515Z”,
“Duration”: “00:00:11.1028792”,
“MessagesActualLength”: 0,
“WarningsActualLength”: 0,
“ErrorsActualLength”: 0,
“Messages”: null,
“Warnings”: null,
“Errors”: null,
“BackendStatistics”: {
“RemoteCalls”: 86,
“BytesUploaded”: 80296589833,
“BytesDownloaded”: 6843914,
“FilesUploaded”: 77,
“FilesDownloaded”: 2,
“FilesDeleted”: 0,
“FoldersCreated”: 0,
“RetryAttempts”: 4,
“UnknownFileSize”: 0,
“UnknownFileCount”: 0,
“KnownFileCount”: 77,
“KnownFileSize”: 80296589833,
“LastBackupDate”: “2023-01-02T13:56:20-03:00”,
“BackupListCount”: 1,
“TotalQuotaSpace”: 1104880336896,
“FreeQuotaSpace”: 1024582673153,
“AssignedQuotaSpace”: -1,
“ReportedQuotaError”: false,
“ReportedQuotaWarning”: false,
“MainOperation”: “Backup”,
“ParsedResult”: “Success”,
“Version”: “2.0.6.3 (2.0.6.3_beta_2021-06-17)”,
“EndTime”: “0001-01-01T00:00:00”,
“BeginTime”: “2023-01-02T16:56:20.5894444Z”,
“Duration”: “00:00:00”,
“MessagesActualLength”: 0,
“WarningsActualLength”: 0,
“ErrorsActualLength”: 0,
“Messages”: null,
“Warnings”: null,
“Errors”: null
}
},
“RepairResults”: null,
“TestResults”: {
“MainOperation”: “Test”,
“VerificationsActualLength”: 3,
“Verifications”: [
{
“Key”: “duplicati-20230102T165620Z.dlist.zip.aes”,
“Value”: []
},
{
“Key”: “duplicati-i02791b795c304d02b7a8b57560182fd1.dindex.zip.aes”,
“Value”: []
},
{
“Key”: “duplicati-b0c5a2c89d8c944be9e86a32c1086b1c7.dblock.zip.aes”,
“Value”: [
{
“Key”: “Error”,
“Value”: “HTTP timeout 00:01:40 exceeded.”
}
]
}
],
“ParsedResult”: “Success”,
“Version”: “2.0.6.3 (2.0.6.3_beta_2021-06-17)”,
“EndTime”: “2023-01-02T19:42:54.3654476Z”,
“BeginTime”: “2023-01-02T19:33:48.2954634Z”,
“Duration”: “00:09:06.0699842”,
“MessagesActualLength”: 0,
“WarningsActualLength”: 0,
“ErrorsActualLength”: 0,
“Messages”: null,
“Warnings”: null,
“Errors”: null,
“BackendStatistics”: {
“RemoteCalls”: 86,
“BytesUploaded”: 80296589833,
“BytesDownloaded”: 6843914,
“FilesUploaded”: 77,
“FilesDownloaded”: 2,
“FilesDeleted”: 0,
“FoldersCreated”: 0,
“RetryAttempts”: 4,
“UnknownFileSize”: 0,
“UnknownFileCount”: 0,
“KnownFileCount”: 77,
“KnownFileSize”: 80296589833,
“LastBackupDate”: “2023-01-02T13:56:20-03:00”,
“BackupListCount”: 1,
“TotalQuotaSpace”: 1104880336896,
“FreeQuotaSpace”: 1024582673153,
“AssignedQuotaSpace”: -1,
“ReportedQuotaError”: false,
“ReportedQuotaWarning”: false,
“MainOperation”: “Backup”,
“ParsedResult”: “Success”,
“Version”: “2.0.6.3 (2.0.6.3_beta_2021-06-17)”,
“EndTime”: “0001-01-01T00:00:00”,
“BeginTime”: “2023-01-02T16:56:20.5894444Z”,
“Duration”: “00:00:00”,
“MessagesActualLength”: 0,
“WarningsActualLength”: 0,
“ErrorsActualLength”: 0,
“Messages”: null,
“Warnings”: null,
“Errors”: null
}
},
“ParsedResult”: “Error”,
“Version”: “2.0.6.3 (2.0.6.3_beta_2021-06-17)”,
“EndTime”: “2023-01-02T19:42:54.4137072Z”,
“BeginTime”: “2023-01-02T16:56:20.5894444Z”,
“Duration”: “02:46:33.8242628”,
“MessagesActualLength”: 179,
“WarningsActualLength”: 0,
“ErrorsActualLength”: 1,
“Messages”: [
“2023-01-02 13:56:20 -03 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: A operação Backup foi iniciada”,
“2023-01-02 13:56:29 -03 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started: ()”,
“2023-01-02 13:56:30 -03 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed: ()”,
“2023-01-02 14:10:50 -03 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-be182e1d2aa4d493b8b8e2dff886b5f8a.dblock.zip.aes (2,00 GB)”,
“2023-01-02 14:10:50 -03 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-b24d96eb5511d443f9ae7601f001c1936.dblock.zip.aes (2,00 GB)”,
“2023-01-02 14:18:12 -03 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-b3921dcb33886455489ce5497b6c0841d.dblock.zip.aes (2,00 GB)”,
“2023-01-02 14:18:14 -03 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-b4af8a1fae97e420c9c5dce79b53f3650.dblock.zip.aes (2,00 GB)”,
“2023-01-02 14:18:54 -03 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-b24d96eb5511d443f9ae7601f001c1936.dblock.zip.aes (2,00 GB)”,
“2023-01-02 14:18:56 -03 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-idf9dacb399b54b3e998550fad3f01487.dindex.zip.aes (1,41 MB)”,
“2023-01-02 14:19:00 -03 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-idf9dacb399b54b3e998550fad3f01487.dindex.zip.aes (1,41 MB)”,
“2023-01-02 14:23:45 -03 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-ba9d171bf7b0342b49e21b71066b037fb.dblock.zip.aes (2,00 GB)”,
“2023-01-02 14:25:09 -03 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-b3921dcb33886455489ce5497b6c0841d.dblock.zip.aes (2,00 GB)”,
“2023-01-02 14:25:09 -03 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-i528f9b89c1ed4aefb7c8bf45e3d15dbc.dindex.zip.aes (1,26 MB)”,
“2023-01-02 14:25:12 -03 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-i528f9b89c1ed4aefb7c8bf45e3d15dbc.dindex.zip.aes (1,26 MB)”,
“2023-01-02 14:25:12 -03 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-bcfe7614d36ff49b18900754dcacc2af8.dblock.zip.aes (2,00 GB)”,
“2023-01-02 14:27:30 -03 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-be182e1d2aa4d493b8b8e2dff886b5f8a.dblock.zip.aes (2,00 GB)”,
“2023-01-02 14:27:31 -03 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-ic728e889369c46ed8e94466b6ea724e2.dindex.zip.aes (1,66 MB)”,
“2023-01-02 14:27:34 -03 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-ic728e889369c46ed8e94466b6ea724e2.dindex.zip.aes (1,66 MB)”,
“2023-01-02 14:27:34 -03 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-b21a9c3ac78eb4c1c9dc75b57292a95eb.dblock.zip.aes (2,00 GB)”,
“2023-01-02 14:32:26 -03 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-b4af8a1fae97e420c9c5dce79b53f3650.dblock.zip.aes (2,00 GB)”
],
“Warnings”: [],
“Errors”: [
“2023-01-02 16:42:54 -03 - [Error-Duplicati.Library.Main.Operation.TestHandler-FailedToProcessFile]: Failed to process file duplicati-b0c5a2c89d8c944be9e86a32c1086b1c7.dblock.zip.aes”
],
“BackendStatistics”: {
“RemoteCalls”: 86,
“BytesUploaded”: 80296589833,
“BytesDownloaded”: 6843914,
“FilesUploaded”: 77,
“FilesDownloaded”: 2,
“FilesDeleted”: 0,
“FoldersCreated”: 0,
“RetryAttempts”: 4,
“UnknownFileSize”: 0,
“UnknownFileCount”: 0,
“KnownFileCount”: 77,
“KnownFileSize”: 80296589833,
“LastBackupDate”: “2023-01-02T13:56:20-03:00”,
“BackupListCount”: 1,
“TotalQuotaSpace”: 1104880336896,
“FreeQuotaSpace”: 1024582673153,
“AssignedQuotaSpace”: -1,
“ReportedQuotaError”: false,
“ReportedQuotaWarning”: false,
“MainOperation”: “Backup”,
“ParsedResult”: “Success”,
“Version”: “2.0.6.3 (2.0.6.3_beta_2021-06-17)”,
“EndTime”: “0001-01-01T00:00:00”,
“BeginTime”: “2023-01-02T16:56:20.5894444Z”,
“Duration”: “00:00:00”,
“MessagesActualLength”: 0,
“WarningsActualLength”: 0,
“ErrorsActualLength”: 0,
“Messages”: null,
“Warnings”: null,
“Errors”: null
}
}

Can you help me? Many thanks in advance!

Detail my remote volume size was set to be 2gb in size

See

That’s 40 times over default. Did you read Choosing sizes in Duplicati for what that hurts?
If nothing else, it means long downloads, which on OneDrive risks time out at 100 seconds:

I “think” the more modern Microsoft Graph interfaces avoid the old 5000 item list view pains.
Suggest increasing http-operation-timeout for download time, but consider smaller volumes.

I’d say only 40 but that’s your call.

Edited to correct. Still too large for the 1:40 allowed, and probably going to mean slower restores.
This depends on nature of the restore. A restore of all files might not mind as much as a few files.
Blocks can eventually get scattered by compacts into different dblock files, increasing downloads.

Hello everyone, I set “http-operation-timeout” to 1 hour and the error stopped happening, apparently everything is working ok now!

Timeouts are there to try to detect an abnormally slow transfer rather than sit around for a long time.
Setting it to 1 hour might cause long wait instead of give-up-and-retry, but if it does, you can lower it.

I’m glad you got file transfer going.

I had also a problem with one drive when I started using it about 2 years ago.

My solution was the same. I added http-operation-timeout=30m as parameter in the URL.

Since I did this no more problems with OneDrive.