Can't find the source of warning

Support
1

Hi,

I’m getting a wierd behavior in the last few versions (2.0.5.1_beta_2020-01-18 and the beta before) of Duplicati. When I finish a backup, I get an message box indicating 2 warnings. In addition, duplicati-monitoring reports the backup state as unknown. However, if I look at the raw reports, it looks fine. Any ideas?

See bellow for screenshots and logs

Screen Shot 2020-03-11 at 7.51.26 AM
Screen Shot 2020-03-11 at 7.51.26 AM2370×1562 308 KB

Screen Shot 2020-03-11 at 7.56.52 AM
Screen Shot 2020-03-11 at 7.56.52 AM2744×1634 375 KB

Complete Log :

{
“DeletedFiles”: 0,
“DeletedFolders”: 0,
“ModifiedFiles”: 9,
“ExaminedFiles”: 241994,
“OpenedFiles”: 9,
“AddedFiles”: 0,
“SizeOfModifiedFiles”: 17038047,
“SizeOfAddedFiles”: 0,
“SizeOfExaminedFiles”: 658209548942,
“SizeOfOpenedFiles”: 17038055,
“NotProcessedFiles”: 0,
“AddedFolders”: 0,
“TooLargeFiles”: 0,
“FilesWithError”: 0,
“ModifiedFolders”: 0,
“ModifiedSymlinks”: 0,
“AddedSymlinks”: 0,
“DeletedSymlinks”: 0,
“PartialBackup”: false,
“Dryrun”: false,
“MainOperation”: “Backup”,
“CompactResults”: {
“DeletedFileCount”: 46,
“DownloadedFileCount”: 23,
“UploadedFileCount”: 2,
“DeletedFileSize”: 563816134,
“DownloadedFileSize”: 563078891,
“UploadedFileSize”: 446888577,
“Dryrun”: false,
“VacuumResults”: null,
“MainOperation”: “Compact”,
“ParsedResult”: “Success”,
“Version”: “2.0.5.1 (2.0.5.1_beta_2020-01-18)”,
“EndTime”: “2020-03-11T11:46:17.323247Z”,
“BeginTime”: “2020-03-11T11:42:44.815335Z”,
“Duration”: “00:03:32.5079120”,
“MessagesActualLength”: 0,
“WarningsActualLength”: 0,
“ErrorsActualLength”: 0,
“Messages”: null,
“Warnings”: null,
“Errors”: null,
“BackendStatistics”: {
“RemoteCalls”: 79,
“BytesUploaded”: 464909905,
“BytesDownloaded”: 1105709026,
“FilesUploaded”: 5,
“FilesDownloaded”: 26,
“FilesDeleted”: 46,
“FoldersCreated”: 0,
“RetryAttempts”: 0,
“UnknownFileSize”: 4,
“UnknownFileCount”: 1,
“KnownFileCount”: 2298,
“KnownFileSize”: 597501848498,
“LastBackupDate”: “2020-03-11T07:35:49-04:00”,
“BackupListCount”: 12,
“TotalQuotaSpace”: 100770508800,
“FreeQuotaSpace”: 74382315520,
“AssignedQuotaSpace”: -1,
“ReportedQuotaError”: false,
“ReportedQuotaWarning”: false,
“MainOperation”: “Backup”,
“ParsedResult”: “Success”,
“Version”: “2.0.5.1 (2.0.5.1_beta_2020-01-18)”,
“EndTime”: “0001-01-01T00:00:00”,
“BeginTime”: “2020-03-11T11:35:49.053238Z”,
“Duration”: “00:00:00”,
“MessagesActualLength”: 0,
“WarningsActualLength”: 0,
“ErrorsActualLength”: 0,
“Messages”: null,
“Warnings”: null,
“Errors”: null
}
},
“VacuumResults”: null,
“DeleteResults”: {
“DeletedSetsActualLength”: 0,
“DeletedSets”: ,
“Dryrun”: false,
“MainOperation”: “Delete”,
“CompactResults”: {
“DeletedFileCount”: 46,
“DownloadedFileCount”: 23,
“UploadedFileCount”: 2,
“DeletedFileSize”: 563816134,
“DownloadedFileSize”: 563078891,
“UploadedFileSize”: 446888577,
“Dryrun”: false,
“VacuumResults”: null,
“MainOperation”: “Compact”,
“ParsedResult”: “Success”,
“Version”: “2.0.5.1 (2.0.5.1_beta_2020-01-18)”,
“EndTime”: “2020-03-11T11:46:17.323247Z”,
“BeginTime”: “2020-03-11T11:42:44.815335Z”,
“Duration”: “00:03:32.5079120”,
“MessagesActualLength”: 0,
“WarningsActualLength”: 0,
“ErrorsActualLength”: 0,
“Messages”: null,
“Warnings”: null,
“Errors”: null,
“BackendStatistics”: {
“RemoteCalls”: 79,
“BytesUploaded”: 464909905,
“BytesDownloaded”: 1105709026,
“FilesUploaded”: 5,
“FilesDownloaded”: 26,
“FilesDeleted”: 46,
“FoldersCreated”: 0,
“RetryAttempts”: 0,
“UnknownFileSize”: 4,
“UnknownFileCount”: 1,
“KnownFileCount”: 2298,
“KnownFileSize”: 597501848498,
“LastBackupDate”: “2020-03-11T07:35:49-04:00”,
“BackupListCount”: 12,
“TotalQuotaSpace”: 100770508800,
“FreeQuotaSpace”: 74382315520,
“AssignedQuotaSpace”: -1,
“ReportedQuotaError”: false,
“ReportedQuotaWarning”: false,
“MainOperation”: “Backup”,
“ParsedResult”: “Success”,
“Version”: “2.0.5.1 (2.0.5.1_beta_2020-01-18)”,
“EndTime”: “0001-01-01T00:00:00”,
“BeginTime”: “2020-03-11T11:35:49.053238Z”,
“Duration”: “00:00:00”,
“MessagesActualLength”: 0,
“WarningsActualLength”: 0,
“ErrorsActualLength”: 0,
“Messages”: null,
“Warnings”: null,
“Errors”: null
}
},
“ParsedResult”: “Success”,
“Version”: “2.0.5.1 (2.0.5.1_beta_2020-01-18)”,
“EndTime”: “2020-03-11T11:46:17.323602Z”,
“BeginTime”: “2020-03-11T11:42:03.01661Z”,
“Duration”: “00:04:14.3069920”,
“MessagesActualLength”: 0,
“WarningsActualLength”: 0,
“ErrorsActualLength”: 0,
“Messages”: null,
“Warnings”: null,
“Errors”: null,
“BackendStatistics”: {
“RemoteCalls”: 79,
“BytesUploaded”: 464909905,
“BytesDownloaded”: 1105709026,
“FilesUploaded”: 5,
“FilesDownloaded”: 26,
“FilesDeleted”: 46,
“FoldersCreated”: 0,
“RetryAttempts”: 0,
“UnknownFileSize”: 4,
“UnknownFileCount”: 1,
“KnownFileCount”: 2298,
“KnownFileSize”: 597501848498,
“LastBackupDate”: “2020-03-11T07:35:49-04:00”,
“BackupListCount”: 12,
“TotalQuotaSpace”: 100770508800,
“FreeQuotaSpace”: 74382315520,
“AssignedQuotaSpace”: -1,
“ReportedQuotaError”: false,
“ReportedQuotaWarning”: false,
“MainOperation”: “Backup”,
“ParsedResult”: “Success”,
“Version”: “2.0.5.1 (2.0.5.1_beta_2020-01-18)”,
“EndTime”: “0001-01-01T00:00:00”,
“BeginTime”: “2020-03-11T11:35:49.053238Z”,
“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-20200311T113549Z.dlist.zip.aes”,
“Value”:
},
{
“Key”: “duplicati-i210d9027283144ce84d921b7c4d0ce39.dindex.zip.aes”,
“Value”:
},
{
“Key”: “duplicati-b72bb685089e24d128919d2edb1d4c3eb.dblock.zip.aes”,
“Value”:
}
],
“ParsedResult”: “Success”,
“Version”: “2.0.5.1 (2.0.5.1_beta_2020-01-18)”,
“EndTime”: “2020-03-11T11:46:21.207506Z”,
“BeginTime”: “2020-03-11T11:46:17.73882Z”,
“Duration”: “00:00:03.4686860”,
“MessagesActualLength”: 0,
“WarningsActualLength”: 0,
“ErrorsActualLength”: 0,
“Messages”: null,
“Warnings”: null,
“Errors”: null,
“BackendStatistics”: {
“RemoteCalls”: 79,
“BytesUploaded”: 464909905,
“BytesDownloaded”: 1105709026,
“FilesUploaded”: 5,
“FilesDownloaded”: 26,
“FilesDeleted”: 46,
“FoldersCreated”: 0,
“RetryAttempts”: 0,
“UnknownFileSize”: 4,
“UnknownFileCount”: 1,
“KnownFileCount”: 2298,
“KnownFileSize”: 597501848498,
“LastBackupDate”: “2020-03-11T07:35:49-04:00”,
“BackupListCount”: 12,
“TotalQuotaSpace”: 100770508800,
“FreeQuotaSpace”: 74382315520,
“AssignedQuotaSpace”: -1,
“ReportedQuotaError”: false,
“ReportedQuotaWarning”: false,
“MainOperation”: “Backup”,
“ParsedResult”: “Success”,
“Version”: “2.0.5.1 (2.0.5.1_beta_2020-01-18)”,
“EndTime”: “0001-01-01T00:00:00”,
“BeginTime”: “2020-03-11T11:35:49.053238Z”,
“Duration”: “00:00:00”,
“MessagesActualLength”: 0,
“WarningsActualLength”: 0,
“ErrorsActualLength”: 0,
“Messages”: null,
“Warnings”: null,
“Errors”: null
}
},
“ParsedResult”: “Success”,
“Version”: “2.0.5.1 (2.0.5.1_beta_2020-01-18)”,
“EndTime”: “2020-03-11T11:46:21.251855Z”,
“BeginTime”: “2020-03-11T11:35:49.052288Z”,
“Duration”: “00:10:32.1995670”,
“MessagesActualLength”: 167,
“WarningsActualLength”: 0,
“ErrorsActualLength”: 0,
“Messages”: [
“2020-03-11 07:35:49 -04 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started”,
“2020-03-11 07:36:57 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started: ()”,
“2020-03-11 07:36:58 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed: (2.29 KB)”,
“2020-03-11 07:41:37 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-b176f5627341a49b2909325ca3962e207.dblock.zip.aes (112.18 KB)”,
“2020-03-11 07:41:44 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-b176f5627341a49b2909325ca3962e207.dblock.zip.aes (112.18 KB)”,
“2020-03-11 07:41:55 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-i2bd07c3fee964337b6bc057ef8a55f31.dindex.zip.aes (7.28 KB)”,
“2020-03-11 07:41:55 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-i2bd07c3fee964337b6bc057ef8a55f31.dindex.zip.aes (7.28 KB)”,
“2020-03-11 07:42:02 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-20200311T113549Z.dlist.zip.aes (17.07 MB)”,
“2020-03-11 07:42:02 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-20200311T113549Z.dlist.zip.aes (17.07 MB)”,
“2020-03-11 07:42:03 -04 - [Information-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-StartCheck]: Start checking if backups can be removed”,
“2020-03-11 07:42:03 -04 - [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”,
“2020-03-11 07:42:03 -04 - [Information-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-BackupList]: Backups to consider: 03/11/2020 02:00:00, 03/10/2020 02:00:00, 03/09/2020 02:00:00, 03/08/2020 01:00:00, 03/07/2020 01:00:00, 03/06/2020 01:00:00, 03/05/2020 01:00:00, 02/28/2020 01:00:00, 02/21/2020 01:00:00, 02/13/2020 01:00:00, 01/07/2020 08:24:34”,
"2020-03-11 07:42:03 -04 - [Information-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-BackupsToDelete]: Backups outside of all time frames and thus getting deleted: ",
"2020-03-11 07:42:03 -04 - [Information-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-AllBackupsToDelete]: All backups to delete: ",
“2020-03-11 07:42:44 -04 - [Information-Duplicati.Library.Main.Operation.DeleteHandler-DeleteResults]: No remote filesets were deleted”,
“2020-03-11 07:44:14 -04 - [Information-Duplicati.Library.Main.Database.LocalDeleteDatabase-CompactReason]: Compacting because there are 21 small volumes and the maximum is 20”,
“2020-03-11 07:44:15 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-b1995739d1f2747b2b4a2090490c0e470.dblock.zip.aes (143.06 MB)”,
“2020-03-11 07:44:20 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-b1995739d1f2747b2b4a2090490c0e470.dblock.zip.aes (143.06 MB)”,
“2020-03-11 07:44:20 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-ba16dcc3187804ac9bf36e03299a916d6.dblock.zip.aes (386.69 MB)”,
“2020-03-11 07:44:33 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-ba16dcc3187804ac9bf36e03299a916d6.dblock.zip.aes (386.69 MB)”
],
“Warnings”: ,
“Errors”: ,
“BackendStatistics”: {
“RemoteCalls”: 79,
“BytesUploaded”: 464909905,
“BytesDownloaded”: 1105709026,
“FilesUploaded”: 5,
“FilesDownloaded”: 26,
“FilesDeleted”: 46,
“FoldersCreated”: 0,
“RetryAttempts”: 0,
“UnknownFileSize”: 4,
“UnknownFileCount”: 1,
“KnownFileCount”: 2298,
“KnownFileSize”: 597501848498,
“LastBackupDate”: “2020-03-11T07:35:49-04:00”,
“BackupListCount”: 12,
“TotalQuotaSpace”: 100770508800,
“FreeQuotaSpace”: 74382315520,
“AssignedQuotaSpace”: -1,
“ReportedQuotaError”: false,
“ReportedQuotaWarning”: false,
“MainOperation”: “Backup”,
“ParsedResult”: “Success”,
“Version”: “2.0.5.1 (2.0.5.1_beta_2020-01-18)”,
“EndTime”: “0001-01-01T00:00:00”,
“BeginTime”: “2020-03-11T11:35:49.053238Z”,
“Duration”: “00:00:00”,
“MessagesActualLength”: 0,
“WarningsActualLength”: 0,
“ErrorsActualLength”: 0,
“Messages”: null,
“Warnings”: null,
“Errors”: null
}
}

2

Start a backup job and immediately go to About -> Show Log -> Live and set it to Warning. Watch the entries that appear here.

The warnings are probably not part of the backup operation itself, so they don’t show up in the job log. Could be something like a pre or post script issue… do you have those configured? Or any sort of notifications (email, web report, etc)?

3

Thanks to drwtsn32 suggestions, I found my two errors :

  • Apr 10, 2020 10:31 AM: Failed to send message: System.Net.WebException: The remote server returned an error: (408) Request Timeout.

  • Apr 10, 2020 10:31 AM: HTTP Response: 408 - Request Timeout:
    Timeout

    Request Timeout

    Server timeout waiting for the HTTP request from the client.

I am simply try to post the report to duplicati-moniroting. Should I reach out to them?

Cheers

4

I’ve been getting a 503 error quite frequently with duplicati-monitoring lately. 408 error may be something different.

There’s a discussion over here with the guy that runs the site: Duplicati-monitoring.com - central monitoring of multiple Duplicati instances + nice email reports