Ok, on production instance, this looks very bad.
When the System.Exception reported above occurred and I tried to test files, I always got exactly one “dblock.zip.aes” where it said test failed. I’ve did a write test on the drive, swapped drives but didn’t get rid of the problem.
Now, production backup (fully started from scratch with swap enabled) ran successfully in the initial attempt to execute the job. Then it worked okay some days and now the errors are back a little different:
{
"DeletedFiles": 1,
"DeletedFolders": 0,
"ModifiedFiles": 45,
"ExaminedFiles": 69242,
"OpenedFiles": 54,
"AddedFiles": 9,
"SizeOfModifiedFiles": 5517,
"SizeOfAddedFiles": 13056069,
"SizeOfExaminedFiles": 754539488684,
"SizeOfOpenedFiles": 135931188,
"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": 37962,
"DownloadedFileSize": 0,
"UploadedFileSize": 0,
"Dryrun": false,
"VacuumResults": null,
"MainOperation": "Compact",
"ParsedResult": "Success",
"Version": "2.0.6.3 (2.0.6.3_beta_2021-06-17)",
"EndTime": "2021-07-16T02:03:04.932437Z",
"BeginTime": "2021-07-16T02:02:37.586016Z",
"Duration": "00:00:27.3464210",
"MessagesActualLength": 0,
"WarningsActualLength": 0,
"ErrorsActualLength": 0,
"Messages": null,
"Warnings": null,
"Errors": null,
"BackendStatistics": {
"RemoteCalls": 40,
"BytesUploaded": 20267975,
"BytesDownloaded": 792146928,
"FilesUploaded": 3,
"FilesDownloaded": 32,
"FilesDeleted": 3,
"FoldersCreated": 0,
"RetryAttempts": 4,
"UnknownFileSize": 0,
"UnknownFileCount": 0,
"KnownFileCount": 27466,
"KnownFileSize": 719781678210,
"LastBackupDate": "2021-07-16T04:00:00+02:00",
"BackupListCount": 8,
"TotalQuotaSpace": 0,
"FreeQuotaSpace": 0,
"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": "2021-07-16T02:00:00.002561Z",
"Duration": "00:00:00",
"MessagesActualLength": 0,
"WarningsActualLength": 0,
"ErrorsActualLength": 0,
"Messages": null,
"Warnings": null,
"Errors": null
}
},
"VacuumResults": null,
"DeleteResults": {
"DeletedSetsActualLength": 1,
"DeletedSets": [
{
"Item1": 7,
"Item2": "2021-07-09T04:00:00+02:00"
}
],
"Dryrun": false,
"MainOperation": "Delete",
"CompactResults": {
"DeletedFileCount": 2,
"DownloadedFileCount": 0,
"UploadedFileCount": 0,
"DeletedFileSize": 37962,
"DownloadedFileSize": 0,
"UploadedFileSize": 0,
"Dryrun": false,
"VacuumResults": null,
"MainOperation": "Compact",
"ParsedResult": "Success",
"Version": "2.0.6.3 (2.0.6.3_beta_2021-06-17)",
"EndTime": "2021-07-16T02:03:04.932437Z",
"BeginTime": "2021-07-16T02:02:37.586016Z",
"Duration": "00:00:27.3464210",
"MessagesActualLength": 0,
"WarningsActualLength": 0,
"ErrorsActualLength": 0,
"Messages": null,
"Warnings": null,
"Errors": null,
"BackendStatistics": {
"RemoteCalls": 40,
"BytesUploaded": 20267975,
"BytesDownloaded": 792146928,
"FilesUploaded": 3,
"FilesDownloaded": 32,
"FilesDeleted": 3,
"FoldersCreated": 0,
"RetryAttempts": 4,
"UnknownFileSize": 0,
"UnknownFileCount": 0,
"KnownFileCount": 27466,
"KnownFileSize": 719781678210,
"LastBackupDate": "2021-07-16T04:00:00+02:00",
"BackupListCount": 8,
"TotalQuotaSpace": 0,
"FreeQuotaSpace": 0,
"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": "2021-07-16T02:00:00.002561Z",
"Duration": "00:00:00",
"MessagesActualLength": 0,
"WarningsActualLength": 0,
"ErrorsActualLength": 0,
"Messages": null,
"Warnings": null,
"Errors": null
}
},
"ParsedResult": "Success",
"Version": "2.0.6.3 (2.0.6.3_beta_2021-06-17)",
"EndTime": "2021-07-16T02:03:04.932443Z",
"BeginTime": "2021-07-16T02:02:11.627958Z",
"Duration": "00:00:53.3044850",
"MessagesActualLength": 0,
"WarningsActualLength": 0,
"ErrorsActualLength": 0,
"Messages": null,
"Warnings": null,
"Errors": null,
"BackendStatistics": {
"RemoteCalls": 40,
"BytesUploaded": 20267975,
"BytesDownloaded": 792146928,
"FilesUploaded": 3,
"FilesDownloaded": 32,
"FilesDeleted": 3,
"FoldersCreated": 0,
"RetryAttempts": 4,
"UnknownFileSize": 0,
"UnknownFileCount": 0,
"KnownFileCount": 27466,
"KnownFileSize": 719781678210,
"LastBackupDate": "2021-07-16T04:00:00+02:00",
"BackupListCount": 8,
"TotalQuotaSpace": 0,
"FreeQuotaSpace": 0,
"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": "2021-07-16T02:00:00.002561Z",
"Duration": "00:00:00",
"MessagesActualLength": 0,
"WarningsActualLength": 0,
"ErrorsActualLength": 0,
"Messages": null,
"Warnings": null,
"Errors": null
}
},
"RepairResults": null,
"TestResults": {
"MainOperation": "Test",
"VerificationsActualLength": 28,
"Verifications": [
{
"Key": "duplicati-20210716T020000Z.dlist.zip.aes",
"Value": []
},
{
"Key": "duplicati-20210711T020000Z.dlist.zip.aes",
"Value": []
},
{
"Key": "duplicati-20210710T020000Z.dlist.zip.aes",
"Value": []
},
{
"Key": "duplicati-20210713T020000Z.dlist.zip.aes",
"Value": []
},
{
"Key": "duplicati-20210714T020000Z.dlist.zip.aes",
"Value": []
},
{
"Key": "duplicati-20210715T020000Z.dlist.zip.aes",
"Value": []
},
{
"Key": "duplicati-20210712T020000Z.dlist.zip.aes",
"Value": []
},
{
"Key": "duplicati-20210707T125044Z.dlist.zip.aes",
"Value": []
},
{
"Key": "duplicati-i9b6b8305a4414a90899cbc9c9b7ff26e.dindex.zip.aes",
"Value": []
},
{
"Key": "duplicati-ie68c181faee648e1a0e095a7002be2e8.dindex.zip.aes",
"Value": []
},
{
"Key": "duplicati-i857d2b416c8545ada64d508767f4a7dc.dindex.zip.aes",
"Value": []
},
{
"Key": "duplicati-i4113be80549d43c6868abb5ca644d80d.dindex.zip.aes",
"Value": []
},
{
"Key": "duplicati-i17fb2ea842774092abcd05d8a4030d07.dindex.zip.aes",
"Value": []
},
{
"Key": "duplicati-i5828fa3ed12d41349c894e836ac831ca.dindex.zip.aes",
"Value": []
},
{
"Key": "duplicati-i86350b79ecfb44628523e7299524686b.dindex.zip.aes",
"Value": []
},
{
"Key": "duplicati-i7fbb92382e624e8cbb383edcb60d79ed.dindex.zip.aes",
"Value": []
},
{
"Key": "duplicati-ied632045e16842e49a3675f5c8948abe.dindex.zip.aes",
"Value": []
},
{
"Key": "duplicati-ice20671f76514ae7a7ea55cc2ce707ab.dindex.zip.aes",
"Value": []
},
{
"Key": "duplicati-b807fea1d40344695aa5ebe0f3f0b5907.dblock.zip.aes",
"Value": []
},
{
"Key": "duplicati-b70b0ce9be1354f17b1a522f58030561d.dblock.zip.aes",
"Value": []
}
],
"ParsedResult": "Success",
"Version": "2.0.6.3 (2.0.6.3_beta_2021-06-17)",
"EndTime": "2021-07-16T02:03:57.87858Z",
"BeginTime": "2021-07-16T02:03:08.970637Z",
"Duration": "00:00:48.9079430",
"MessagesActualLength": 0,
"WarningsActualLength": 0,
"ErrorsActualLength": 0,
"Messages": null,
"Warnings": null,
"Errors": null,
"BackendStatistics": {
"RemoteCalls": 40,
"BytesUploaded": 20267975,
"BytesDownloaded": 792146928,
"FilesUploaded": 3,
"FilesDownloaded": 32,
"FilesDeleted": 3,
"FoldersCreated": 0,
"RetryAttempts": 4,
"UnknownFileSize": 0,
"UnknownFileCount": 0,
"KnownFileCount": 27466,
"KnownFileSize": 719781678210,
"LastBackupDate": "2021-07-16T04:00:00+02:00",
"BackupListCount": 8,
"TotalQuotaSpace": 0,
"FreeQuotaSpace": 0,
"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": "2021-07-16T02:00:00.002561Z",
"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": "2021-07-16T02:03:58.423259Z",
"BeginTime": "2021-07-16T02:00:00.002551Z",
"Duration": "00:03:58.4207080",
"MessagesActualLength": 97,
"WarningsActualLength": 0,
"ErrorsActualLength": 1,
"Messages": [
"2021-07-16 04:00:00 +02 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: Die Operation Backup wurde gestartet",
"2021-07-16 04:00:14 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started: ()",
"2021-07-16 04:00:20 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed: (26,82 KB)",
"2021-07-16 04:02:05 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-bc9f793d3184f4d63970388c6b7fb1b52.dblock.zip.aes (12,43 MB)",
"2021-07-16 04:02:06 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-bc9f793d3184f4d63970388c6b7fb1b52.dblock.zip.aes (12,43 MB)",
"2021-07-16 04:02:09 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-icc75df57b68c4b9e82844b2b644a74c7.dindex.zip.aes (13,00 KB)",
"2021-07-16 04:02:09 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-icc75df57b68c4b9e82844b2b644a74c7.dindex.zip.aes (13,00 KB)",
"2021-07-16 04:02:11 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-20210716T020000Z.dlist.zip.aes (6,89 MB)",
"2021-07-16 04:02:11 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-20210716T020000Z.dlist.zip.aes (6,89 MB)",
"2021-07-16 04:02:11 +02 - [Information-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-StartCheck]: Start checking if backups can be removed",
"2021-07-16 04:02:11 +02 - [Information-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-FramesAndIntervals]: 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",
"2021-07-16 04:02:11 +02 - [Information-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-BackupList]: Backups to consider: 15.07.2021 04:00:00, 14.07.2021 04:00:00, 13.07.2021 04:00:00, 12.07.2021 04:00:00, 11.07.2021 04:00:00, 10.07.2021 04:00:00, 09.07.2021 04:00:00, 07.07.2021 14:50:44",
"2021-07-16 04:02:11 +02 - [Information-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-BackupsToDelete]: Backups outside of all time frames and thus getting deleted: ",
"2021-07-16 04:02:11 +02 - [Information-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-AllBackupsToDelete]: All backups to delete: 09.07.2021 04:00:00",
"2021-07-16 04:02:11 +02 - [Information-Duplicati.Library.Main.Operation.DeleteHandler-DeleteRemoteFileset]: Deleting 1 remote fileset(s) ...",
"2021-07-16 04:02:37 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Delete - Started: duplicati-20210709T020000Z.dlist.zip.aes (6,88 MB)",
"2021-07-16 04:02:37 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Delete - Completed: duplicati-20210709T020000Z.dlist.zip.aes (6,88 MB)",
"2021-07-16 04:02:37 +02 - [Information-Duplicati.Library.Main.Operation.DeleteHandler-DeleteResults]: Deleted 1 remote fileset(s)",
"2021-07-16 04:03:04 +02 - [Information-Duplicati.Library.Main.Database.LocalDeleteDatabase-CompactReason]: Compacting because there are 1 fully deletable volume(s)",
"2021-07-16 04:03:04 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Delete - Started: duplicati-b51dbfb4242934f6197d163358ed2fc53.dblock.zip.aes (34,67 KB)"
],
"Warnings": [],
"Errors": [
"2021-07-16 04:03:56 +02 - [Error-Duplicati.Library.Main.Operation.TestHandler-FailedToProcessFile]: Failed to process file duplicati-b9a5fbc11a1ca44938f82a21da57580a8.dblock.zip.aes"
],
"BackendStatistics": {
"RemoteCalls": 40,
"BytesUploaded": 20267975,
"BytesDownloaded": 792146928,
"FilesUploaded": 3,
"FilesDownloaded": 32,
"FilesDeleted": 3,
"FoldersCreated": 0,
"RetryAttempts": 4,
"UnknownFileSize": 0,
"UnknownFileCount": 0,
"KnownFileCount": 27466,
"KnownFileSize": 719781678210,
"LastBackupDate": "2021-07-16T04:00:00+02:00",
"BackupListCount": 8,
"TotalQuotaSpace": 0,
"FreeQuotaSpace": 0,
"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": "2021-07-16T02:00:00.002561Z",
"Duration": "00:00:00",
"MessagesActualLength": 0,
"WarningsActualLength": 0,
"ErrorsActualLength": 0,
"Messages": null,
"Warnings": null,
"Errors": null
}
}