If I understand what you are asking for, I don’t have another example. I only have full system backups.
Would you like me to try a new backup job with a small set of files to be backed up?
Yes please, and remove as many options as possible, and use a local file destination. Best would be if it’s simple and universal enough that any other person can reproduce it on any equipment to study it directly.
There’s also a chance you might remove the problem by simplification, thereby narrowing down its cause.
There’s also a chance no backup ever works on this installation, but that also helps determine next steps.
Thanks @ts678 for your continued suggestions.
I attempted a simple backup test using version 2.0.4.5_beta_2018-11-28 that appears to have succeeded.
Here is the configuration
{
"CreatedByVersion": "2.0.4.5",
"Schedule": null,
"Backup": {
"ID": "3",
"Name": "Simple Backup Test 2.0.4.5_beta_2018-11-28",
"Description": "A simple backup testing Duplicati version 2.0.4.5_beta_2018-11-28",
"Tags": [],
"TargetURL": "file:///media/shared/temp/backups/",
"DBPath": "/home/jake/.config/Duplicati/82786987818679897270.sqlite",
"Sources": [
"%MY_DOCUMENTS%/Downloads/"
],
"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": "--no-encryption",
"Value": "true",
"Argument": null
}
],
"Filters": [],
"Metadata": {
"LastBackupDate": "20181219T123849Z",
"BackupListCount": "1",
"TotalQuotaSpace": "2702091218944",
"FreeQuotaSpace": "517687468032",
"AssignedQuotaSpace": "-1",
"TargetFilesSize": "41157743309",
"TargetFilesCount": "1571",
"TargetSizeString": "38.33 GB",
"SourceFilesSize": "41788877727",
"SourceFilesCount": "288",
"SourceSizeString": "38.92 GB",
"LastBackupStarted": "20181219T123846Z",
"LastBackupFinished": "20181219T131814Z",
"LastBackupDuration": "00:39:27.6756940"
},
"IsTemporary": false
},
"DisplayNames": {
"/home/jake/Downloads/": "Downloads"
}
}
And here is the log from the job
DeletedFiles: 0
DeletedFolders: 0
ModifiedFiles: 0
ExaminedFiles: 288
OpenedFiles: 288
AddedFiles: 288
SizeOfModifiedFiles: 0
SizeOfAddedFiles: 41788877727
SizeOfExaminedFiles: 41788877727
SizeOfOpenedFiles: 41788877727
NotProcessedFiles: 0
AddedFolders: 3
TooLargeFiles: 0
FilesWithError: 0
ModifiedFolders: 0
ModifiedSymlinks: 0
AddedSymlinks: 0
DeletedSymlinks: 0
PartialBackup: False
Dryrun: False
MainOperation: Backup
CompactResults: null
DeleteResults: null
RepairResults: null
TestResults:
MainOperation: Test
Verifications: [
Key: duplicati-20181219T123849Z.dlist.zip
Value: [],
Key: duplicati-i8437d49f1ce34f9e9e09c089b3d5cd1b.dindex.zip
Value: [],
Key: duplicati-bc3ad7ce6d1ea4146962bced559fbb119.dblock.zip
Value: []
]
ParsedResult: Success
Version: 2.0.4.5 (2.0.4.5_beta_2018-11-28)
EndTime: 12/19/2018 7:18:14 AM (1545225494)
BeginTime: 12/19/2018 7:18:13 AM (1545225493)
Duration: 00:00:00.8786600
Messages: [
2018-12-19 06:38:46 -06 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started,
2018-12-19 06:38:49 -06 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started: (),
2018-12-19 06:38:49 -06 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed: (),
2018-12-19 06:38:54 -06 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-bc146ba409459406cbca49a4610436059.dblock.zip (49.95 MB),
2018-12-19 06:38:55 -06 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-bc146ba409459406cbca49a4610436059.dblock.zip (49.95 MB),
...
]
Warnings: []
Errors: []
BackendStatistics:
RemoteCalls: 1576
BytesUploaded: 41157743309
BytesDownloaded: 52462392
FilesUploaded: 1571
FilesDownloaded: 3
FilesDeleted: 0
FoldersCreated: 0
RetryAttempts: 0
UnknownFileSize: 0
UnknownFileCount: 0
KnownFileCount: 1571
KnownFileSize: 41157743309
LastBackupDate: 12/19/2018 6:38:49 AM (1545223129)
BackupListCount: 1
TotalQuotaSpace: 2702091218944
FreeQuotaSpace: 517687468032
AssignedQuotaSpace: -1
ReportedQuotaError: False
ReportedQuotaWarning: False
ParsedResult: Success
Version: 2.0.4.5 (2.0.4.5_beta_2018-11-28)
Messages: [
2018-12-19 06:38:46 -06 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started,
2018-12-19 06:38:49 -06 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started: (),
2018-12-19 06:38:49 -06 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed: (),
2018-12-19 06:38:54 -06 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-bc146ba409459406cbca49a4610436059.dblock.zip (49.95 MB),
2018-12-19 06:38:55 -06 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-bc146ba409459406cbca49a4610436059.dblock.zip (49.95 MB),
...
]
Warnings: []
Errors: []
ParsedResult: Success
Version: 2.0.4.5 (2.0.4.5_beta_2018-11-28)
EndTime: 12/19/2018 7:18:14 AM (1545225494)
BeginTime: 12/19/2018 6:38:46 AM (1545223126)
Duration: 00:39:27.6756940
Messages: [
2018-12-19 06:38:46 -06 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started,
2018-12-19 06:38:49 -06 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started: (),
2018-12-19 06:38:49 -06 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed: (),
2018-12-19 06:38:54 -06 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-bc146ba409459406cbca49a4610436059.dblock.zip (49.95 MB),
2018-12-19 06:38:55 -06 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-bc146ba409459406cbca49a4610436059.dblock.zip (49.95 MB),
...
]
Warnings: []
Errors: []
So it appears that version 2.0.4.5_beta_2018-11-28 works with a fresh backup set. But I’m still stuck with my existing backup. Any thoughts on recovery, or should I just scrap it and start over?
Hello, Duplicati community! I’m back again with one last request for help troubleshooting this backup set before I consider it lost.
Is it accurate that because I can’t continue with new backups that I should not consider it reliable for restoring too?
I’m thinking I’ll start over with a new backup set and delete this old corrupted one. It makes me uncomfortable to do that, and I hope that I can consider Duplicati stable enough to recommend to friends who aren’t very technical.
Thoughts?
What problem are we chasing now? The “Object reference not set to an instance of an object” is so generic an error message that it means little in Duplicati terms without a solid understanding of the code area, and a reproducible test to look at. I lack the former (any readers know Duplicati/Server/WebServer/RESTMethods/CommandLine.cs and its WriteLine?). I set up a debugger, but was not even using that code on my backup.
If that problem has somehow vanished, the “Unexpected difference in fileset”, though of unclear origin, has a simple workaround to try, of deleting the troubled fileset (version of the backup) shown in the error message. Here is a recent report of success, however if the original “Object reference” still happens, I can’t help further without additional assistance from the community, or you being able to discover a way that I can reproduce it. Seeing a simple test succeed is encouraging, but the key is figuring out the difference between it and failure.
For additional information on how to use the delete command for the “Unexpected difference” error, see this, and please feel free to clarify the relationship between these two problems and which is the current problem.
1 Like
@ts678 Thanks for the clarification that the “Object reference” was not the relevant error. I’ll continue to pursue the “Unexpected difference in fileset” error to see if that leads to recovery.
I appreciate you linking to tips on deleting the unexpected difference. I’ll give that a shot.
Sorry if I’m unclear about the relationship between the two errors. Frankly, I don’t understand the underlying technology very well, so I’m trying to learn as I go. Thanks for your patience, everyone!
I’m traveling the next few days, so it might be a bit before I can report my progress.
That is probably NOT accurate as Duplicati needs the local database to exist for backups, but can make a new/partial one for restores (using at least dlist files from the destination).
Sorry it you’ve already said this, but have you tried a restore? If a restore from the job menu doesn’t work (as it uses the local database) try they main menu Restore option and choose there one that says something like “Direct from destination”.
If the direct from destination restore works then you’ve got a viable restore source so you could start a fresh job but keep the old one around for historical restores if needed.
Once enough history has been built up in the new job then you can delete the “cold storage” one.
Safe travels!
1 Like
@JonMikelV Thanks for your reply. You are correct. I did try a test restore yesterday, and it was successful. I attempted to restore a single photo from my huge backup set. It took nearly two hours, but it did successfully restore the photo. So that is encouraging!
Is it normal that a restore of a single file would take that long with a backup set as large as mine (Backup: 1.34 TB / 74 Versions) ?
Potentially - it depends on a lot of different things.
If you used the “restore direct from destination” option then Duplicati had to create a temporary mini-database to use to find all the file parts (blocks) needing to be re-assembled. That step can take a while, but we are hoping to optimize it at some point.
Once all the blocks for the file(s) needing to be restored have been identified then the dblock file(s) containing those blocks need to be downloaded.
Remember, your image (let’s say it’s 5MB in size) has been chopped into lots of small blocks (by default 100k so we’ll say that’s 52 blocks). Those blocks get added to a compressed archive dblock file (by default 50MB).
If all your blocks are in the same dblock file then you’ll need to download 50MB to be able to restore your 5M image. But if (worst case) each of your 52 blocks in in a different dblock archive you’d have to download 2.6G (52 x 50MB) to restore your 5M image.
Realistically, that’s unlikely to happen - most blocks are stored together in in as few archive files are possible, however as files are updated the update blocks are stored in new archives.
So if you’re restoring a file that’s been partially updated once since the original backup, you’ll likely have to download 2 dblock archives to restore the latest version of the file. If a different part of the file is then updated and backed up you’d have to download 3 dblock archives to restore the latest version of the file.
So unfortunately yes - it can take a while for restores. 
Hello, Duplicati, community! I’m back with a report of success!
Big thanks to @ts678 who helped me see past the “Object reference” error to the true issue of “Unexpected difference in fileset"
I was able to delete the fileset that had the issue using the delete command last night.
I see after the delete my ailing backup job now reports a successful backup!
I appreciate all the assistance here. The community is the life-blood of an open-source project. And it is good to know we have a good one here!
For rookies like me, here is what the delete command looked like for my situation:
My first attempts at running the command were flawed by the fact that I cleared out too many of the advanced options. I needed to keep in the dppath and passphrase options.
I also recommend using the --dry-run option first to make sure the command will delete what you think it will!
The command logs looked like this for anyone curious:
Jan 10, 2019 10:00 PM: Result
DeletedSets: [
Item1: 73
Item2: 4/6/2018 6:25:30 AM (1523013930)
]
Dryrun: False
MainOperation: Delete
CompactResults:
DeletedFileCount: 2052
DownloadedFileCount: 0
UploadedFileCount: 0
DeletedFileSize: 53796673940
DownloadedFileSize: 0
UploadedFileSize: 0
Dryrun: False
MainOperation: Compact
ParsedResult: Success
Version: 2.0.4.5 (2.0.4.5_beta_2018-11-28)
EndTime: 1/10/2019 10:00:43 PM (1547179243)
BeginTime: 1/10/2019 9:35:40 PM (1547177740)
Duration: 00:25:02.7467920
Messages: [
2019-01-10 21:29:31 -06 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Delete has started,
2019-01-10 21:29:35 -06 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started: (),
2019-01-10 21:30:23 -06 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed: (55.06 KB),
2019-01-10 21:30:25 -06 - [Information-Duplicati.Library.Main.Operation.DeleteHandler-DeleteRemoteFileset]: Deleting 1 remote fileset(s) ...,
2019-01-10 21:35:39 -06 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Delete - Started: duplicati-20180406T112530Z.dlist.zip.aes (20.12 MB),
...
]
Warnings: []
Errors: []
BackendStatistics:
RemoteCalls: 2054
BytesUploaded: 0
BytesDownloaded: 0
FilesUploaded: 0
FilesDownloaded: 0
FilesDeleted: 2053
FoldersCreated: 0
RetryAttempts: 0
UnknownFileSize: 20594688
UnknownFileCount: 1
KnownFileCount: 56380
KnownFileSize: 1476753186748
LastBackupDate: 11/30/2018 12:00:00 AM (1543557600)
BackupListCount: 74
TotalQuotaSpace: 0
FreeQuotaSpace: 0
AssignedQuotaSpace: -1
ReportedQuotaError: False
ReportedQuotaWarning: False
ParsedResult: Success
Version: 2.0.4.5 (2.0.4.5_beta_2018-11-28)
Messages: [
2019-01-10 21:29:31 -06 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Delete has started,
2019-01-10 21:29:35 -06 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started: (),
2019-01-10 21:30:23 -06 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed: (55.06 KB),
2019-01-10 21:30:25 -06 - [Information-Duplicati.Library.Main.Operation.DeleteHandler-DeleteRemoteFileset]: Deleting 1 remote fileset(s) ...,
2019-01-10 21:35:39 -06 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Delete - Started: duplicati-20180406T112530Z.dlist.zip.aes (20.12 MB),
...
]
Warnings: []
Errors: []
ParsedResult: Success
Version: 2.0.4.5 (2.0.4.5_beta_2018-11-28)
EndTime: 1/10/2019 10:00:43 PM (1547179243)
BeginTime: 1/10/2019 9:29:31 PM (1547177371)
Duration: 00:31:12.2504620
Messages: [
2019-01-10 21:29:31 -06 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Delete has started,
2019-01-10 21:29:35 -06 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started: (),
2019-01-10 21:30:23 -06 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed: (55.06 KB),
2019-01-10 21:30:25 -06 - [Information-Duplicati.Library.Main.Operation.DeleteHandler-DeleteRemoteFileset]: Deleting 1 remote fileset(s) ...,
2019-01-10 21:35:39 -06 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Delete - Started: duplicati-20180406T112530Z.dlist.zip.aes (20.12 MB),
...
]
Warnings: []
Errors: []
Hopefully it helps someone!
Also, for the moderators here… Should I change the title of my thread to more accurately reflect the true root cause? The “Object reference” error was not the true source of the issue… Just curious about best practices on that part… Thanks
1 Like