All backups got deleted... How?

Tim_Stonesifer · November 25, 2022, 9:18pm

I use Duplicati to backup to a local hard drive and to a remote B2 Backblaze bucket. A month or two ago, I started getting an error log that included:

Duplicati.Library.Main.Operation.Backup.MetadataGenerator.Metadata-MetadataProcessFailed]: Failed to process metadata for “/VaultDriveRoot/vault/”, storing empty metadata

I’ll paste a longer log file in the next comment. I was getting this metadata error for both backups I run. My best bet is that this started when the USB cables to the hard drive got bumped, but I really can’t be certain. Basically, it stopped processing new files, from what I saw.

Today I finally got around to working on this, and I started by rebooting the server. But after running the backups again, saw that there were no backup files at all in both the local and remote B2 destinations.

I’m not trying to get these backups back (I can just re-run the backups), but I would like to find out what in the world could have happened. Does anyone have any insight? Thanks!

Tim_Stonesifer · November 25, 2022, 9:20pm

And here’s a full log from one of the local backups:

Blockquote{
“DeletedFiles”: 0,
“DeletedFolders”: 0,
“ModifiedFiles”: 0,
“ExaminedFiles”: 0,
“OpenedFiles”: 0,
“AddedFiles”: 0,
“SizeOfModifiedFiles”: 0,
“SizeOfAddedFiles”: 0,
“SizeOfExaminedFiles”: 0,
“SizeOfOpenedFiles”: 0,
“NotProcessedFiles”: 0,
“AddedFolders”: 0,
“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”: “2022-11-15T05:06:44.776059Z”,
“BeginTime”: “2022-11-15T05:02:57.417264Z”,
“Duration”: “00:03:47.3587950”,
“MessagesActualLength”: 0,
“WarningsActualLength”: 0,
“ErrorsActualLength”: 0,
“Messages”: null,
“Warnings”: null,
“Errors”: null,
“BackendStatistics”: {
“RemoteCalls”: 5,
“BytesUploaded”: 0,
“BytesDownloaded”: 52436756,
“FilesUploaded”: 0,
“FilesDownloaded”: 3,
“FilesDeleted”: 0,
“FoldersCreated”: 0,
“RetryAttempts”: 0,
“UnknownFileSize”: 0,
“UnknownFileCount”: 0,
“KnownFileCount”: 35967,
“KnownFileSize”: 936336073332,
“LastBackupDate”: “2022-10-20T01:00:00-04:00”,
“BackupListCount”: 3,
“TotalQuotaSpace”: 1612441886720,
“FreeQuotaSpace”: 675840000000,
“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”: “2022-11-15T05:00:00.006062Z”,
“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-20221020T050000Z.dlist.zip”,
“Value”: []
},
{
“Key”: “duplicati-i46cd60729de84be8bf894f33611f7184.dindex.zip”,
“Value”: []
},
{
“Key”: “duplicati-b5c47b67096c64d95b986d6201e636ab3.dblock.zip”,
“Value”: []
}
],
“ParsedResult”: “Success”,
“Version”: “2.0.6.3 (2.0.6.3_beta_2021-06-17)”,
“EndTime”: “2022-11-15T05:07:11.327397Z”,
“BeginTime”: “2022-11-15T05:07:08.611055Z”,
“Duration”: “00:00:02.7163420”,
“MessagesActualLength”: 0,
“WarningsActualLength”: 0,
“ErrorsActualLength”: 0,
“Messages”: null,
“Warnings”: null,
“Errors”: null,
“BackendStatistics”: {
“RemoteCalls”: 5,
“BytesUploaded”: 0,
“BytesDownloaded”: 52436756,
“FilesUploaded”: 0,
“FilesDownloaded”: 3,
“FilesDeleted”: 0,
“FoldersCreated”: 0,
“RetryAttempts”: 0,
“UnknownFileSize”: 0,
“UnknownFileCount”: 0,
“KnownFileCount”: 35967,
“KnownFileSize”: 936336073332,
“LastBackupDate”: “2022-10-20T01:00:00-04:00”,
“BackupListCount”: 3,
“TotalQuotaSpace”: 1612441886720,
“FreeQuotaSpace”: 675840000000,
“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”: “2022-11-15T05:00:00.006062Z”,
“Duration”: “00:00:00”,
“MessagesActualLength”: 0,
“WarningsActualLength”: 0,
“ErrorsActualLength”: 0,
“Messages”: null,
“Warnings”: null,
“Errors”: null
}
},
“ParsedResult”: “Warning”,
“Version”: “2.0.6.3 (2.0.6.3_beta_2021-06-17)”,
“EndTime”: “2022-11-15T05:07:11.34214Z”,
“BeginTime”: “2022-11-15T05:00:00.006049Z”,
“Duration”: “00:07:11.3360910”,
“MessagesActualLength”: 12,
“WarningsActualLength”: 1,
“ErrorsActualLength”: 0,
“Messages”: [
“2022-11-15 00:00:00 -05 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started”,
“2022-11-15 00:01:32 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started: ()”,
“2022-11-15 00:01:50 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed: (35.12 KB)”,
“2022-11-15 00:06:44 -05 - [Information-Duplicati.Library.Main.Operation.DeleteHandler-DeleteResults]: No remote filesets were deleted”,
“2022-11-15 00:06:44 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started: ()”,
“2022-11-15 00:07:00 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed: (35.12 KB)”,
“2022-11-15 00:07:09 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-20221020T050000Z.dlist.zip (573 bytes)”,
“2022-11-15 00:07:09 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-20221020T050000Z.dlist.zip (573 bytes)”,
“2022-11-15 00:07:09 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-i46cd60729de84be8bf894f33611f7184.dindex.zip (17.66 KB)”,
“2022-11-15 00:07:09 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-i46cd60729de84be8bf894f33611f7184.dindex.zip (17.66 KB)”,
“2022-11-15 00:07:09 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-b5c47b67096c64d95b986d6201e636ab3.dblock.zip (49.99 MB)”,
“2022-11-15 00:07:11 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-b5c47b67096c64d95b986d6201e636ab3.dblock.zip (49.99 MB)”
],
“Warnings”: [
“2022-11-15 00:01:57 -05 - [Warning-Duplicati.Library.Main.Operation.Backup.MetadataGenerator.Metadata-MetadataProcessFailed]: Failed to process metadata for "/VaultDriveRoot/vault/", storing empty metadata”
],
“Errors”: [],
“BackendStatistics”: {
“RemoteCalls”: 5,
“BytesUploaded”: 0,
“BytesDownloaded”: 52436756,
“FilesUploaded”: 0,
“FilesDownloaded”: 3,
“FilesDeleted”: 0,
“FoldersCreated”: 0,
“RetryAttempts”: 0,
“UnknownFileSize”: 0,
“UnknownFileCount”: 0,
“KnownFileCount”: 35967,
“KnownFileSize”: 936336073332,
“LastBackupDate”: “2022-10-20T01:00:00-04:00”,
“BackupListCount”: 3,
“TotalQuotaSpace”: 1612441886720,
“FreeQuotaSpace”: 675840000000,
“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”: “2022-11-15T05:00:00.006062Z”,
“Duration”: “00:00:00”,
“MessagesActualLength”: 0,
“WarningsActualLength”: 0,
“ErrorsActualLength”: 0,
“Messages”: null,
“Warnings”: null,
“Errors”: null
}
}

gpatel-fr · November 25, 2022, 11:13pm

Hello

even if I love speculative fiction, I can’t begin to imagine something with so few data.
Can you provide a log from:

one month before the one you provided
one month after - so just before you restarted.

and what is exactly /VaultDriveRoot/vault/ ? I’m not sure if it’s the source or the backend. Or maybe provide the json file for the backup ?

Tim_Stonesifer · November 26, 2022, 1:46am

I’ll focus on just the local backup for now. Here’s my oldest log from the Duplicati web interface (Oct 27), but this was still when it was giving me the metadata error.

{
“DeletedFiles”: 0,
“DeletedFolders”: 0,
“ModifiedFiles”: 0,
“ExaminedFiles”: 0,
“OpenedFiles”: 0,
“AddedFiles”: 0,
“SizeOfModifiedFiles”: 0,
“SizeOfAddedFiles”: 0,
“SizeOfExaminedFiles”: 0,
“SizeOfOpenedFiles”: 0,
“NotProcessedFiles”: 0,
“AddedFolders”: 0,
“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”: “2022-10-27T05:06:31.117838Z”,
“BeginTime”: “2022-10-27T05:02:49.09093Z”,
“Duration”: “00:03:42.0269080”,
“MessagesActualLength”: 0,
“WarningsActualLength”: 0,
“ErrorsActualLength”: 0,
“Messages”: null,
“Warnings”: null,
“Errors”: null,
“BackendStatistics”: {
“RemoteCalls”: 5,
“BytesUploaded”: 0,
“BytesDownloaded”: 83243059,
“FilesUploaded”: 0,
“FilesDownloaded”: 3,
“FilesDeleted”: 0,
“FoldersCreated”: 0,
“RetryAttempts”: 0,
“UnknownFileSize”: 0,
“UnknownFileCount”: 0,
“KnownFileCount”: 35967,
“KnownFileSize”: 936336073332,
“LastBackupDate”: “2022-10-20T01:00:00-04:00”,
“BackupListCount”: 3,
“TotalQuotaSpace”: 1612441886720,
“FreeQuotaSpace”: 675840000000,
“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”: “2022-10-27T05:00:00.020968Z”,
“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-20221017T050000Z.dlist.zip”,
“Value”: []
},
{
“Key”: “duplicati-i52aab9c9010c4a13b600444b0e5b038b.dindex.zip”,
“Value”: []
},
{
“Key”: “duplicati-b28180c76a4ad4f408666e1ec811803b2.dblock.zip”,
“Value”: []
}
],
“ParsedResult”: “Success”,
“Version”: “2.0.6.3 (2.0.6.3_beta_2021-06-17)”,
“EndTime”: “2022-10-27T05:06:58.077556Z”,
“BeginTime”: “2022-10-27T05:06:54.574979Z”,
“Duration”: “00:00:03.5025770”,
“MessagesActualLength”: 0,
“WarningsActualLength”: 0,
“ErrorsActualLength”: 0,
“Messages”: null,
“Warnings”: null,
“Errors”: null,
“BackendStatistics”: {
“RemoteCalls”: 5,
“BytesUploaded”: 0,
“BytesDownloaded”: 83243059,
“FilesUploaded”: 0,
“FilesDownloaded”: 3,
“FilesDeleted”: 0,
“FoldersCreated”: 0,
“RetryAttempts”: 0,
“UnknownFileSize”: 0,
“UnknownFileCount”: 0,
“KnownFileCount”: 35967,
“KnownFileSize”: 936336073332,
“LastBackupDate”: “2022-10-20T01:00:00-04:00”,
“BackupListCount”: 3,
“TotalQuotaSpace”: 1612441886720,
“FreeQuotaSpace”: 675840000000,
“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”: “2022-10-27T05:00:00.020968Z”,
“Duration”: “00:00:00”,
“MessagesActualLength”: 0,
“WarningsActualLength”: 0,
“ErrorsActualLength”: 0,
“Messages”: null,
“Warnings”: null,
“Errors”: null
}
},
“ParsedResult”: “Warning”,
“Version”: “2.0.6.3 (2.0.6.3_beta_2021-06-17)”,
“EndTime”: “2022-10-27T05:06:58.090314Z”,
“BeginTime”: “2022-10-27T05:00:00.020933Z”,
“Duration”: “00:06:58.0693810”,
“MessagesActualLength”: 12,
“WarningsActualLength”: 1,
“ErrorsActualLength”: 0,
“Messages”: [
“2022-10-27 01:00:00 -04 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started”,
“2022-10-27 01:01:28 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started: ()”,
“2022-10-27 01:01:44 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed: (35.12 KB)”,
“2022-10-27 01:06:31 -04 - [Information-Duplicati.Library.Main.Operation.DeleteHandler-DeleteResults]: No remote filesets were deleted”,
“2022-10-27 01:06:31 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started: ()”,
“2022-10-27 01:06:46 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed: (35.12 KB)”,
“2022-10-27 01:06:55 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-20221017T050000Z.dlist.zip (29.38 MB)”,
“2022-10-27 01:06:56 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-20221017T050000Z.dlist.zip (29.38 MB)”,
“2022-10-27 01:06:56 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-i52aab9c9010c4a13b600444b0e5b038b.dindex.zip (17.65 KB)”,
“2022-10-27 01:06:56 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-i52aab9c9010c4a13b600444b0e5b038b.dindex.zip (17.65 KB)”,
“2022-10-27 01:06:56 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-b28180c76a4ad4f408666e1ec811803b2.dblock.zip (49.99 MB)”,
“2022-10-27 01:06:58 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-b28180c76a4ad4f408666e1ec811803b2.dblock.zip (49.99 MB)”
],
“Warnings”: [
“2022-10-27 01:01:51 -04 - [Warning-Duplicati.Library.Main.Operation.Backup.MetadataGenerator.Metadata-MetadataProcessFailed]: Failed to process metadata for "/VaultDriveRoot/vault/", storing empty metadata”
],
“Errors”: [],
“BackendStatistics”: {
“RemoteCalls”: 5,
“BytesUploaded”: 0,
“BytesDownloaded”: 83243059,
“FilesUploaded”: 0,
“FilesDownloaded”: 3,
“FilesDeleted”: 0,
“FoldersCreated”: 0,
“RetryAttempts”: 0,
“UnknownFileSize”: 0,
“UnknownFileCount”: 0,
“KnownFileCount”: 35967,
“KnownFileSize”: 936336073332,
“LastBackupDate”: “2022-10-20T01:00:00-04:00”,
“BackupListCount”: 3,
“TotalQuotaSpace”: 1612441886720,
“FreeQuotaSpace”: 675840000000,
“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”: “2022-10-27T05:00:00.020968Z”,
“Duration”: “00:00:00”,
“MessagesActualLength”: 0,
“WarningsActualLength”: 0,
“ErrorsActualLength”: 0,
“Messages”: null,
“Warnings”: null,
“Errors”: null
}
}

The web interface doesn’t show older logs, but here’s one that was emailed to me in early October, back when things were working properly:

DeletedFiles: 0
DeletedFolders: 0
ModifiedFiles: 0
ExaminedFiles: 342626
OpenedFiles: 68
AddedFiles: 68
SizeOfModifiedFiles: 0
SizeOfAddedFiles: 601794126
SizeOfExaminedFiles: 1102767158106
SizeOfOpenedFiles: 601794126
NotProcessedFiles: 0
AddedFolders: 0
TooLargeFiles: 0
FilesWithError: 0
ModifiedFolders: 0
ModifiedSymlinks: 0
AddedSymlinks: 0
DeletedSymlinks: 0
PartialBackup: False
Dryrun: False
MainOperation: Backup
ParsedResult: Success
Version: 2.0.6.3 (2.0.6.3_beta_2021-06-17)
EndTime: 10/4/2022 1:38:27 AM (1664861907)
BeginTime: 10/4/2022 1:00:00 AM (1664859600)
Duration: 00:38:27.5879360
MessagesActualLength: 66
WarningsActualLength: 0
ErrorsActualLength: 0
LimitedMessages: [
2022-10-04 01:00:00 -04 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started,
2022-10-04 01:01:37 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started: (),
2022-10-04 01:01:52 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed: (34.92 KB),
2022-10-04 01:26:24 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-bd000afb82c014acfa9a4edd4604ce341.dblock.zip (49.99 MB),
2022-10-04 01:26:24 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-b1e14815c73764f60b2a1499ee09a9721.dblock.zip (49.92 MB),
2022-10-04 01:26:26 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-bd000afb82c014acfa9a4edd4604ce341.dblock.zip (49.99 MB),
2022-10-04 01:26:26 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-b1e14815c73764f60b2a1499ee09a9721.dblock.zip (49.92 MB),
2022-10-04 01:26:26 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-i78a1da9e07cd46ea850b61752dc1f686.dindex.zip (33.69 KB),
2022-10-04 01:26:27 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-i7a9cf4d96d574851b8e61a510dbdb223.dindex.zip (35.11 KB),
2022-10-04 01:26:27 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-i78a1da9e07cd46ea850b61752dc1f686.dindex.zip (33.69 KB),
…
]
LimitedWarnings: []
LimitedErrors: []

Tim_Stonesifer · November 26, 2022, 1:49am

Here’s the json config. /VaultDriveRoot/vault/ is the source, mapped in Docker to an external USB hard drive. I’ll reiterate that both of my backups were affected. The other one has a destination in the cloud. Thanks for any ideas you’ve got.

{
“CreatedByVersion”: “2.0.6.3”,
“Schedule”: {
“ID”: 4,
“Tags”: [
“ID=5”
],
“Time”: “2022-11-26T05:00:00Z”,
“Repeat”: “1D”,
“LastRun”: “2022-11-25T05:00:00Z”,
“Rule”: “AllowedWeekDays=Monday,Tuesday,Wednesday,Thursday,Friday,Saturday,Sunday”,
“AllowedDays”: [
“mon”,
“tue”,
“wed”,
“thu”,
“fri”,
“sat”,
“sun”
]
},
“Backup”: {
“ID”: “5”,
“Name”: “Local Vault Backup”,
“Description”: “Backup of Vault to UnionFS external hard drives.”,
“Tags”: [],
“TargetURL”: “file:///UnionBackupDrive/VaultBackup/”,
“DBPath”: “/config/XGCUOFJNTH.sqlite”,
“Sources”: [
“/VaultDriveRoot/vault/”
],
“Settings”: [
{
“Filter”: “”,
“Name”: “encryption-module”,
“Value”: “”,
“Argument”: null
},
{
“Filter”: “”,
“Name”: “compression-module”,
“Value”: “zip”,
“Argument”: null
},
{
“Filter”: “”,
“Name”: “dblock-size”,
“Value”: “50mb”,
“Argument”: null
},
{
“Filter”: “”,
“Name”: “keep-versions”,
“Value”: “3”,
“Argument”: null
},
{
“Filter”: “”,
“Name”: “–no-encryption”,
“Value”: “true”,
“Argument”: null
},
{
“Filter”: “”,
“Name”: “–rebuild-missing-dblock-files”,
“Value”: “true”,
“Argument”: null
}
],
“Filters”: [],
“Metadata”: {
“LastBackupDate”: “20221125T133417Z”,
“BackupListCount”: “4”,
“TotalQuotaSpace”: “1612441886720”,
“FreeQuotaSpace”: “675839967232”,
“AssignedQuotaSpace”: “-1”,
“TargetFilesSize”: “936336104893”,
“TargetFilesCount”: “35968”,
“TargetSizeString”: “872.03 GB”,
“SourceFilesSize”: “159063332516”,
“SourceFilesCount”: “140”,
“SourceSizeString”: “148.14 GB”,
“LastBackupStarted”: “20221125T133416Z”,
“LastBackupFinished”: “20221125T143527Z”,
“LastBackupDuration”: “01:01:10.5149470”,
“LastCompactDuration”: “00:02:14.7000590”,
“LastCompactStarted”: “20221020T050712Z”,
“LastCompactFinished”: “20221020T050926Z”,
“LastErrorDate”: “20211019T050048Z”,
“LastErrorMessage”: “Unexpected difference in fileset version 1: 9/7/2021 8:03:13 PM (database id: 3), found 366002 entries, but expected 366003”
},
“IsTemporary”: false
},
“DisplayNames”: {
“/VaultDriveRoot/vault/”: “vault”
}
}

ts678 · November 26, 2022, 2:30am

How did you see this? On your home screen there are statistics for each backup, for example:

What are yours?

The job log Complete log has these statistics and more. For above small backup, I’m seeing:

 "KnownFileCount": 17,
 "KnownFileSize": 21580
 "LastBackupDate": "2022-11-24T11:25:44-05:00",
 "BackupListCount": 11,

I can also click on <job> → Show log → Remote, and click on list near top to see my 17 files.

For your local backup, Duplicati thinks it sees

“KnownFileCount”: 35967,
“KnownFileSize”: 936336073332,
“LastBackupDate”: “2022-10-20T01:00:00-04:00”,
“BackupListCount”: 3,

and at nearly a TB, this should be perceptible on your local drive. Yet you say no such files exist?
Don’t expect your source files, but there should be many files starting with duplicati-. Search?

“2022-11-15 00:07:00 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed: (35.12 KB)”,

is incorrectly interpreting the list value as a size. It’s actually the count of files seen by Duplicati.
Because you’re not seeing them, are you certain you’re looking at the right files in the right place?

I’d note there are a couple of different times here. I cited your Nov 15, then you posted the Oct 27.
Is there anything newer than Nov 15 in the job logs? How about in <job> → Show log → Remote?

If you need to get something there as a recent test, press the Verify files button, which would
typically do list (which you can click on, but it might be kind of slow given all the files) and 3 get.
If all that works, then you’re looking for files wrong somehow. If files are gone, what came before?

Now you posted a backup from today, it appears, so you should have a nice fresh list to look at.

“TargetFilesSize”: “936336104893”,
“TargetFilesCount”: “35968”,

are probably the same numbers (names may differ) Complete log put in BackendStatistics.
Duplicati checks backup for the expected files unless no-backend-verification is set, and it’s not.

If this flag is set, the local database is not compared to the remote filelist on startup. The intended usage for this option is to work correctly in cases where the filelisting is broken or unavailable.

so I’m pretty sure you have files, but check all of the places I mentioned and see how yours look.

Tim_Stonesifer · November 26, 2022, 4:01am

ts678, thanks for all the info! I have no doubt that if I went through this info you shared yesterday, that this would be exactly the case. However, something seems to have happened after I rebooted the machine today. I’ll share some logs in my next reply.

To answer your questions — Yes, I’m seeing this on the stats on the home screen:

I thought “ok, maybe the config file or something got corrupted”. I used terminal to navigate to the folder, and everything’s gone. Same with checking my B2 account online; that bucket has about 2 KB of data in it. I tried restoring files from previous versions through duplicati, and I just get an empty file structure.

Tim_Stonesifer · November 26, 2022, 4:06am

Here’s a log from today’s backup, after the reboot. Again, I thought this would just add a few of the new files; instead it was starting from scratch.

{
“DeletedFiles”: 0,
“DeletedFolders”: 0,
“ModifiedFiles”: 0,
“ExaminedFiles”: 140,
“OpenedFiles”: 138,
“AddedFiles”: 138,
“SizeOfModifiedFiles”: 0,
“SizeOfAddedFiles”: 155461961162,
“SizeOfExaminedFiles”: 159063332516,
“SizeOfOpenedFiles”: 155461961162,
“NotProcessedFiles”: 0,
“AddedFolders”: 14,
“TooLargeFiles”: 0,
“FilesWithError”: 0,
“ModifiedFolders”: 0,
“ModifiedSymlinks”: 0,
“AddedSymlinks”: 0,
“DeletedSymlinks”: 0,
“PartialBackup”: true,
“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”: “2022-11-25T14:35:02.536921Z”,
“BeginTime”: “2022-11-25T14:32:53.308183Z”,
“Duration”: “00:02:09.2287380”,
“MessagesActualLength”: 0,
“WarningsActualLength”: 0,
“ErrorsActualLength”: 0,
“Messages”: null,
“Warnings”: null,
“Errors”: null,
“BackendStatistics”: {
“RemoteCalls”: 3,
“BytesUploaded”: 31561,
“BytesDownloaded”: 0,
“FilesUploaded”: 1,
“FilesDownloaded”: 0,
“FilesDeleted”: 0,
“FoldersCreated”: 0,
“RetryAttempts”: 0,
“UnknownFileSize”: 0,
“UnknownFileCount”: 0,
“KnownFileCount”: 35968,
“KnownFileSize”: 936336104893,
“LastBackupDate”: “2022-11-25T08:34:17-05:00”,
“BackupListCount”: 4,
“TotalQuotaSpace”: 1612441886720,
“FreeQuotaSpace”: 675839967232,
“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”: “2022-11-25T13:34:16.584221Z”,
“Duration”: “00:00:00”,
“MessagesActualLength”: 0,
“WarningsActualLength”: 0,
“ErrorsActualLength”: 0,
“Messages”: null,
“Warnings”: null,
“Errors”: null
}
},
“RepairResults”: null,
“TestResults”: {
“MainOperation”: “Test”,
“VerificationsActualLength”: 0,
“Verifications”: [],
“ParsedResult”: “Success”,
“Version”: “2.0.6.3 (2.0.6.3_beta_2021-06-17)”,
“EndTime”: “2022-11-25T14:35:27.010468Z”,
“BeginTime”: “2022-11-25T14:35:25.910629Z”,
“Duration”: “00:00:01.0998390”,
“MessagesActualLength”: 0,
“WarningsActualLength”: 0,
“ErrorsActualLength”: 0,
“Messages”: null,
“Warnings”: null,
“Errors”: null,
“BackendStatistics”: {
“RemoteCalls”: 3,
“BytesUploaded”: 31561,
“BytesDownloaded”: 0,
“FilesUploaded”: 1,
“FilesDownloaded”: 0,
“FilesDeleted”: 0,
“FoldersCreated”: 0,
“RetryAttempts”: 0,
“UnknownFileSize”: 0,
“UnknownFileCount”: 0,
“KnownFileCount”: 35968,
“KnownFileSize”: 936336104893,
“LastBackupDate”: “2022-11-25T08:34:17-05:00”,
“BackupListCount”: 4,
“TotalQuotaSpace”: 1612441886720,
“FreeQuotaSpace”: 675839967232,
“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”: “2022-11-25T13:34:16.584221Z”,
“Duration”: “00:00:00”,
“MessagesActualLength”: 0,
“WarningsActualLength”: 0,
“ErrorsActualLength”: 0,
“Messages”: null,
“Warnings”: null,
“Errors”: null
}
},
“ParsedResult”: “Warning”,
“Version”: “2.0.6.3 (2.0.6.3_beta_2021-06-17)”,
“EndTime”: “2022-11-25T14:35:27.097294Z”,
“BeginTime”: “2022-11-25T13:34:16.582347Z”,
“Duration”: “01:01:10.5149470”,
“MessagesActualLength”: 8,
“WarningsActualLength”: 1,
“ErrorsActualLength”: 0,
“Messages”: [
“2022-11-25 08:34:17 -05 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started”,
“2022-11-25 08:35:35 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started: ()”,
“2022-11-25 08:35:50 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed: (35.12 KB)”,
“2022-11-25 09:32:52 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-20221125T133417Z.dlist.zip (30.82 KB)”,
“2022-11-25 09:32:53 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-20221125T133417Z.dlist.zip (30.82 KB)”,
“2022-11-25 09:35:02 -05 - [Information-Duplicati.Library.Main.Operation.DeleteHandler-DeleteResults]: No remote filesets were deleted”,
“2022-11-25 09:35:02 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started: ()”,
“2022-11-25 09:35:19 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed: (35.13 KB)”
],
“Warnings”: [
“2022-11-25 09:31:54 -05 - [Warning-Duplicati.Library.Main.Operation.BackupHandler-CancellationRequested]: Cancellation was requested by user.”
],
“Errors”: [],
“BackendStatistics”: {
“RemoteCalls”: 3,
“BytesUploaded”: 31561,
“BytesDownloaded”: 0,
“FilesUploaded”: 1,
“FilesDownloaded”: 0,
“FilesDeleted”: 0,
“FoldersCreated”: 0,
“RetryAttempts”: 0,
“UnknownFileSize”: 0,
“UnknownFileCount”: 0,
“KnownFileCount”: 35968,
“KnownFileSize”: 936336104893,
“LastBackupDate”: “2022-11-25T08:34:17-05:00”,
“BackupListCount”: 4,
“TotalQuotaSpace”: 1612441886720,
“FreeQuotaSpace”: 675839967232,
“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”: “2022-11-25T13:34:16.584221Z”,
“Duration”: “00:00:00”,
“MessagesActualLength”: 0,
“WarningsActualLength”: 0,
“ErrorsActualLength”: 0,
“Messages”: null,
“Warnings”: null,
“Errors”: null
}
}

Tim_Stonesifer · November 26, 2022, 4:08am

… and I’m going to eat some of my words now… I tried poking around a bit more on the local drive, and I do in fact have hundreds of the duplicati archive files:

So something is there for at least the local backup.

Tim_Stonesifer · November 26, 2022, 4:15am

Ugh, and October 23 it decided to delete everything from my remote B2. Not sure why yet.

{
“DeletedFiles”: 343177,
“DeletedFolders”: 33727,
“ModifiedFiles”: 0,
“ExaminedFiles”: 0,
“OpenedFiles”: 0,
“AddedFiles”: 0,
“SizeOfModifiedFiles”: 0,
“SizeOfAddedFiles”: 0,
“SizeOfExaminedFiles”: 0,
“SizeOfOpenedFiles”: 0,
“NotProcessedFiles”: 0,
“AddedFolders”: 0,
“TooLargeFiles”: 0,
“FilesWithError”: 0,
“ModifiedFolders”: 0,
“ModifiedSymlinks”: 0,
“AddedSymlinks”: 0,
“DeletedSymlinks”: 5819,
“PartialBackup”: false,
“Dryrun”: false,
“MainOperation”: “Backup”,
“CompactResults”: {
“DeletedFileCount”: 35736,
“DownloadedFileCount”: 0,
“UploadedFileCount”: 0,
“DeletedFileSize”: 936098054168,
“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”: “2022-10-23T12:15:44.774294Z”,
“BeginTime”: “2022-10-23T10:47:07.931529Z”,
“Duration”: “01:28:36.8427650”,
“MessagesActualLength”: 0,
“WarningsActualLength”: 0,
“ErrorsActualLength”: 0,
“Messages”: null,
“Warnings”: null,
“Errors”: null,
“BackendStatistics”: {
“RemoteCalls”: 35746,
“BytesUploaded”: 2471,
“BytesDownloaded”: 2471,
“FilesUploaded”: 3,
“FilesDownloaded”: 3,
“FilesDeleted”: 35737,
“FoldersCreated”: 0,
“RetryAttempts”: 1,
“UnknownFileSize”: 0,
“UnknownFileCount”: 1,
“KnownFileCount”: 3,
“KnownFileSize”: 2471,
“LastBackupDate”: “2022-10-23T02:00:00-04:00”,
“BackupListCount”: 1,
“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”: “2022-10-23T06:00:00.00704Z”,
“Duration”: “00:00:00”,
“MessagesActualLength”: 0,
“WarningsActualLength”: 0,
“ErrorsActualLength”: 0,
“Messages”: null,
“Warnings”: null,
“Errors”: null
}
},
“VacuumResults”: null,
“DeleteResults”: {
“DeletedSetsActualLength”: 1,
“DeletedSets”: [
{
“Item1”: 1,
“Item2”: “2022-10-16T02:00:00-04:00”
}
],
“Dryrun”: false,
“MainOperation”: “Delete”,
“CompactResults”: {
“DeletedFileCount”: 35736,
“DownloadedFileCount”: 0,
“UploadedFileCount”: 0,
“DeletedFileSize”: 936098054168,
“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”: “2022-10-23T12:15:44.774294Z”,
“BeginTime”: “2022-10-23T10:47:07.931529Z”,
“Duration”: “01:28:36.8427650”,
“MessagesActualLength”: 0,
“WarningsActualLength”: 0,
“ErrorsActualLength”: 0,
“Messages”: null,
“Warnings”: null,
“Errors”: null,
“BackendStatistics”: {
“RemoteCalls”: 35746,
“BytesUploaded”: 2471,
“BytesDownloaded”: 2471,
“FilesUploaded”: 3,
“FilesDownloaded”: 3,
“FilesDeleted”: 35737,
“FoldersCreated”: 0,
“RetryAttempts”: 1,
“UnknownFileSize”: 0,
“UnknownFileCount”: 1,
“KnownFileCount”: 3,
“KnownFileSize”: 2471,
“LastBackupDate”: “2022-10-23T02:00:00-04:00”,
“BackupListCount”: 1,
“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”: “2022-10-23T06:00:00.00704Z”,
“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”: “2022-10-23T12:15:44.774305Z”,
“BeginTime”: “2022-10-23T06:05:23.519524Z”,
“Duration”: “06:10:21.2547810”,
“MessagesActualLength”: 0,
“WarningsActualLength”: 0,
“ErrorsActualLength”: 0,
“Messages”: null,
“Warnings”: null,
“Errors”: null,
“BackendStatistics”: {
“RemoteCalls”: 35746,
“BytesUploaded”: 2471,
“BytesDownloaded”: 2471,
“FilesUploaded”: 3,
“FilesDownloaded”: 3,
“FilesDeleted”: 35737,
“FoldersCreated”: 0,
“RetryAttempts”: 1,
“UnknownFileSize”: 0,
“UnknownFileCount”: 1,
“KnownFileCount”: 3,
“KnownFileSize”: 2471,
“LastBackupDate”: “2022-10-23T02:00:00-04:00”,
“BackupListCount”: 1,
“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”: “2022-10-23T06:00:00.00704Z”,
“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-20221023T060000Z.dlist.zip.aes”,
“Value”: []
},
{
“Key”: “duplicati-i40fdec2e789345d0b6813ab1ee1b7ef2.dindex.zip.aes”,
“Value”: []
},
{
“Key”: “duplicati-b4238859e5a42487cbb15ad7ce2e73f43.dblock.zip.aes”,
“Value”: []
}
],
“ParsedResult”: “Success”,
“Version”: “2.0.6.3 (2.0.6.3_beta_2021-06-17)”,
“EndTime”: “2022-10-23T12:15:51.375776Z”,
“BeginTime”: “2022-10-23T12:15:48.931612Z”,
“Duration”: “00:00:02.4441640”,
“MessagesActualLength”: 0,
“WarningsActualLength”: 0,
“ErrorsActualLength”: 0,
“Messages”: null,
“Warnings”: null,
“Errors”: null,
“BackendStatistics”: {
“RemoteCalls”: 35746,
“BytesUploaded”: 2471,
“BytesDownloaded”: 2471,
“FilesUploaded”: 3,
“FilesDownloaded”: 3,
“FilesDeleted”: 35737,
“FoldersCreated”: 0,
“RetryAttempts”: 1,
“UnknownFileSize”: 0,
“UnknownFileCount”: 1,
“KnownFileCount”: 3,
“KnownFileSize”: 2471,
“LastBackupDate”: “2022-10-23T02:00:00-04:00”,
“BackupListCount”: 1,
“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”: “2022-10-23T06:00:00.00704Z”,
“Duration”: “00:00:00”,
“MessagesActualLength”: 0,
“WarningsActualLength”: 0,
“ErrorsActualLength”: 0,
“Messages”: null,
“Warnings”: null,
“Errors”: null
}
},
“ParsedResult”: “Warning”,
“Version”: “2.0.6.3 (2.0.6.3_beta_2021-06-17)”,
“EndTime”: “2022-10-23T12:15:51.396372Z”,
“BeginTime”: “2022-10-23T06:00:00.007027Z”,
“Duration”: “06:15:51.3893450”,
“MessagesActualLength”: 71503,
“WarningsActualLength”: 1,
“ErrorsActualLength”: 0,
“Messages”: [
“2022-10-23 02:00:00 -04 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started”,
“2022-10-23 02:01:08 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started: ()”,
“2022-10-23 02:02:06 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed: (34.90 KB)”,
“2022-10-23 02:02:14 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-bed39362e185844c39bb172b03c5c1012.dblock.zip.aes (717 bytes)”,
“2022-10-23 02:03:16 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Retrying: duplicati-bed39362e185844c39bb172b03c5c1012.dblock.zip.aes (717 bytes)”,
“2022-10-23 02:03:26 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Rename: duplicati-bed39362e185844c39bb172b03c5c1012.dblock.zip.aes (717 bytes)”,
“2022-10-23 02:03:26 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Rename: duplicati-b4238859e5a42487cbb15ad7ce2e73f43.dblock.zip.aes (717 bytes)”,
“2022-10-23 02:03:26 -04 - [Information-Duplicati.Library.Main.Operation.Backup.BackendUploader-RenameRemoteTargetFile]: Renaming "duplicati-bed39362e185844c39bb172b03c5c1012.dblock.zip.aes" to "duplicati-b4238859e5a42487cbb15ad7ce2e73f43.dblock.zip.aes"”,
“2022-10-23 02:03:26 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-b4238859e5a42487cbb15ad7ce2e73f43.dblock.zip.aes (717 bytes)”,
“2022-10-23 02:04:25 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-b4238859e5a42487cbb15ad7ce2e73f43.dblock.zip.aes (717 bytes)”,
“2022-10-23 02:04:25 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-i40fdec2e789345d0b6813ab1ee1b7ef2.dindex.zip.aes (877 bytes)”,
“2022-10-23 02:04:25 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-i40fdec2e789345d0b6813ab1ee1b7ef2.dindex.zip.aes (877 bytes)”,
“2022-10-23 02:04:25 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-20221023T060000Z.dlist.zip.aes (877 bytes)”,
“2022-10-23 02:05:23 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-20221023T060000Z.dlist.zip.aes (877 bytes)”,
“2022-10-23 02:05:23 -04 - [Information-Duplicati.Library.Main.Operation.DeleteHandler-DeleteRemoteFileset]: Deleting 1 remote fileset(s) …”,
“2022-10-23 06:46:45 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Delete - Started: duplicati-20221016T060000Z.dlist.zip.aes (29.38 MB)”,
“2022-10-23 06:46:46 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Delete - Completed: duplicati-20221016T060000Z.dlist.zip.aes (29.38 MB)”,
“2022-10-23 06:47:07 -04 - [Information-Duplicati.Library.Main.Operation.DeleteHandler-DeleteResults]: Deleted 1 remote fileset(s)”,
“2022-10-23 06:52:26 -04 - [Information-Duplicati.Library.Main.Database.LocalDeleteDatabase-CompactReason]: Compacting because there are 17868 fully deletable volume(s)”,
“2022-10-23 06:54:54 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Delete - Started: duplicati-b666cc2398ef94f3db6ff28ea7b076435.dblock.zip.aes (50.00 MB)”
],
“Warnings”: [
“2022-10-23 02:02:13 -04 - [Warning-Duplicati.Library.Main.Operation.Backup.MetadataGenerator.Metadata-MetadataProcessFailed]: Failed to process metadata for "/VaultDriveRoot/vault/", storing empty metadata”
],
“Errors”: [],
“BackendStatistics”: {
“RemoteCalls”: 35746,
“BytesUploaded”: 2471,
“BytesDownloaded”: 2471,
“FilesUploaded”: 3,
“FilesDownloaded”: 3,
“FilesDeleted”: 35737,
“FoldersCreated”: 0,
“RetryAttempts”: 1,
“UnknownFileSize”: 0,
“UnknownFileCount”: 1,
“KnownFileCount”: 3,
“KnownFileSize”: 2471,
“LastBackupDate”: “2022-10-23T02:00:00-04:00”,
“BackupListCount”: 1,
“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”: “2022-10-23T06:00:00.00704Z”,
“Duration”: “00:00:00”,
“MessagesActualLength”: 0,
“WarningsActualLength”: 0,
“ErrorsActualLength”: 0,
“Messages”: null,
“Warnings”: null,
“Errors”: null
}
}

ts678 · November 26, 2022, 1:07pm

and 1 version. How many versions is this configured to keep? 2 KB should be enough for 0 byte backup.

Typically (I think), people keep quite a few versions (versions can be quite small) over a long time period, whereas Local Vault Backup config looks like it kept only 3, giving 3 days before older backups delete.

The log posted below that counts only:

“BytesUploaded”: 31561,
“FilesUploaded”: 1,

although you seemingly cut it off early:

“2022-11-25 09:31:54 -05 - [Warning-Duplicati.Library.Main.Operation.BackupHandler-CancellationRequested]: Cancellation was requested by user.”

It did look over most of your files, and this is normal if the files weren’t in previous backup:

“ExaminedFiles”: 140,
“OpenedFiles”: 138,

If file blocks are still in the backup due to a kept version using them, they get reconnected.
Starting from scratch should quickly start uploading dblock and dindex files. Yours did not.

I’m glad you found something, but you should have about 36 thousand, per Duplicati stats.
You should also have recent ones matching backup dates. Could UnionFS give bad view?

All the source files vanished, due to your cable problem or whatever disconnected source:

“DeletedFiles”: 343177,
“ExaminedFiles”: 0,

Again, check your retention setting. If it’s set to 1 version. above empty version is only kept.
All prior versions become wasted space, and compact removes wasted space via deletes.

“BackupListCount”: 1,

Above suggests you had an old version, but are keeping only 1 version, so prior deleted, as:

“FilesDeleted”: 35737,

is looking only at dblock volumes, where source data really exists, but each has a dindex file.
Doubling gives 35736. The 35737 stat probably includes a dlist file from the previous backup.

If it turns out you’re keeping 1 version, maybe that makes sense for your use case if you just
want disaster recovery of the latest version, but if latest version is empty, that’s what you get.

EDIT:

I’m not sure what this means, but if it means you found one backup, Oct 23, empty view, yep.
That might be your 2 KB backup of no source files because none were visible at that backup.

gpatel-fr · November 26, 2022, 1:19pm

you did not post the configuration for the B2 job. From your screenshot, the local job lists 4 version while the B2 one list only one, so maybe the retention configuration differs. It could matter a lot, since it seems that you are backing up a mounted directory. If the mount fails, Duplicati sees an empty directory.

ts678 · November 26, 2022, 1:28pm

and this would also keep Duplicati from stopping with a failure because what was asked for was missing.
allow-missing-source can turn that into warning (so backup continues), but I don’t see that in local config.

Use this option to continue even if some source entries are missing.

If one really wants to see what got backed up (empty folder is a very likely guess though), one can ask with
The FIND command, and this is most easily done in Commandline in GUI. Maybe it will show mount point.

Tim_Stonesifer · November 26, 2022, 7:22pm

Thanks for all the feedback! The B2 backup config is listed below. Yes, I only had B2 as 1 version. I’d love to hear more if I’m doing this wrong, but my idea was that I don’t need the offsite backup for version control. I usually only backup photos from the camera anyway, and these are rarely edited, so that was my thinking behind it. The 3 versions seemed sufficient for the rare edits I do on the local backup.

Yes, I did cut off that backup early, since it wasn’t processing the way I expected. I think these either got reconnected or overwritten (I haven’t dived deep to check yet), but either way the local backup appears fixed.

So tell me more about versions… It sounds like if I had had multiple versions configured, this might not have happened on B2?

Interesting with the empty directory… allow-missing-source sounds very beneficial.

Thank you both very much for your time! I’m feeling much better now about what might have happened, and how to make sure it doesn’t in the future.

{
“CreatedByVersion”: “2.0.6.3”,
“Schedule”: {
“ID”: 5,
“Tags”: [
“ID=6”
],
“Time”: “2022-11-27T06:00:00Z”,
“Repeat”: “1D”,
“LastRun”: “2022-11-20T06:00:00Z”,
“Rule”: “AllowedWeekDays=Sunday”,
“AllowedDays”: [
“sun”
]
},
“Backup”: {
“ID”: “6”,
“Name”: “B2 Vault Backup”,
“Description”: “Backup of Vault to remote Backblaze B2”,
“Tags”: [],
“TargetURL”: “b2://omv-backup-full/Vault?auth-username=xxxxx”,
“DBPath”: “/config/HUWEOZOCDR.sqlite”,
“Sources”: [
“/VaultDriveRoot/vault/”
],
“Settings”: [
{
“Filter”: “”,
“Name”: “encryption-module”,
“Value”: “aes”,
“Argument”: null
},
{
“Filter”: “”,
“Name”: “compression-module”,
“Value”: “zip”,
“Argument”: null
},
{
“Filter”: “”,
“Name”: “dblock-size”,
“Value”: “50mb”,
“Argument”: null
},
{
“Filter”: “”,
“Name”: “keep-versions”,
“Value”: “1”,
“Argument”: null
}
],
“Filters”: [],
“Metadata”: {
“LastErrorDate”: “20220501T064551Z”,
“LastErrorMessage”: “One or more errors occurred. (Connection timed out (Connection timed out) (One or more errors occurred. (Connection timed out)))”,
“LastBackupDate”: “20221023T060000Z”,
“BackupListCount”: “1”,
“TotalQuotaSpace”: “0”,
“FreeQuotaSpace”: “0”,
“AssignedQuotaSpace”: “-1”,
“TargetFilesSize”: “2471”,
“TargetFilesCount”: “3”,
“TargetSizeString”: “2.41 KB”,
“SourceFilesSize”: “0”,
“SourceFilesCount”: “0”,
“SourceSizeString”: “0 bytes”,
“LastBackupStarted”: “20221120T060000Z”,
“LastBackupFinished”: “20221120T060004Z”,
“LastBackupDuration”: “00:00:04.3985950”,
“LastCompactDuration”: “01:28:36.8427650”,
“LastCompactStarted”: “20221023T104707Z”,
“LastCompactFinished”: “20221023T121544Z”
},
“IsTemporary”: false
},
“DisplayNames”: {
“/VaultDriveRoot/vault/”: “vault”
}
}

ts678 · November 26, 2022, 10:26pm

Yes, since if you had a version of files from before the disconnect, the data is kept for restore.
You might even be able to see this in log history which is kept by default for 30 days, e.g. see:

going backwards in time (down the logs page). You might find where Examined files came back.
They are Added because they weren’t there just before, and get opened and read block by block.
If there is an older version that hasn’t aged out yet, deduplication references existing past blocks.
You might be able to find a version where Deleted went to all files, yet backup data was retained.
That would be because you had 3 versions, so the old backup isn’t yet viewed as wasted space.

Processing similar data in How the backup process works talks about how deduplication is done.
If some block isn’t found in any version of any files, a new block has to be uploaded to preserve it.

Features from Duplicati Manual

Incremental backups
Duplicati performs a full backup initially. Afterwards, Duplicati updates the initial backup by adding the changed data only. That means, if only tiny parts of a huge file have changed, only those tiny parts are added to the backup. This saves time and space and the backup size usually grows slowly.

You can get an idea of how much change happens by looking at the upload volume from a backup.
More remote versions allows getting old versions despite local disaster, but will take more storage.
I’m not sure how much. Local backup has 4 versions with a surprisingly large total for source size.
I’d note though that image editing tends to rearrange things heavily, and thereby stop deduplication.

gpatel-fr · November 26, 2022, 10:48pm

Seems probable. You could also write a pre-script:

to check if the mount is correct before attempting to backup.