Backup To WebDAV Completes, But Persistant Warning Message


#1

Hi,
I’m no expert when it comes to this whole ordeal, but i’m learning more every day, so i’ll do my best to retrieve any further data asked for.

So! I’ve got a webdav based backup running to a self hosted nextcloud server, I have full physical access to it, so if need be I can look over any settings etc, though I don’t feel its the issue.

I can set up to connection, it tests great, the backup schedule it setup all good. I can run the entire backup and it seems to run fine, I did run into the issue where the backup would not complete correctly, it spat out XX files missing from backup, so I enabled the “no-backend-verification”. This seem to remedy that issue and the backup bow completes. but once the backup completes I get a message “Warnings While Running Test - Got (X) Warning(s)”. The backup appears to of backed up everything no worries, as I have tested a restore and everything gets restored without a hitch. The files i’m backing up are just some test files, there is only about 20 files, total size is about 200mb. I didn’t want to try anything bigger until I got to the bottom of the warnings. I want to offer the backup service to my family, but with the errors they’ll just bug me all the time about what went wrong, so i’d like to sort it out before that happens.

Here is the log for the backup, it would appear the error is about a file being missing as it has been deleted, this appears to be a required step and it seems to me that the file has been removed correctly and successfully. There errors grow every run to, so I get 2 warnings first attempt, then 4 warnings second attempt, then 6 warnings third attempt and so on, and so forth.

Error Log

DeletedFiles: 0
DeletedFolders: 0
ModifiedFiles: 0
ExaminedFiles: 10
OpenedFiles: 0
AddedFiles: 0
SizeOfModifiedFiles: 0
SizeOfAddedFiles: 0
SizeOfExaminedFiles: 224131240
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
DeleteResults: DeletedSets: []
Dryrun: False
MainOperation: Delete
CompactResults: null
ParsedResult: Warning
EndTime: 4/04/2018 6:13:08 PM (1522829588)
BeginTime: 4/04/2018 6:13:08 PM (1522829588)
Duration: 00:00:00.0312489
Messages: [
2018-04-04 18:13:00 +10 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started, 2018-04-04 18:13:00 +10 - [Information-Duplicati.Library.Main.Operation.FilelistProcessor-RemovingStaleFile]: Removing remote file listed as Deleting: duplicati-b75b72f41493b4438af7d0a042d6aa7ed.dblock.zip.aes,
2018-04-04 18:13:00 +10 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Delete - Started: duplicati-b75b72f41493b4438af7d0a042d6aa7ed.dblock.zip.aes (),
2018-04-04 18:13:01 +10 - [Information-Duplicati.Library.Main.BackendManager-DeleteRemoteFileSuccess]: Listing indicates file duplicati-b75b72f41493b4438af7d0a042d6aa7ed.dblock.zip.aes is deleted correctly, 2018-04-04 18:13:01 +10 - [Information-Duplicati.Library.Main.Operation.FilelistProcessor-RemovingStaleFile]: Removing remote file listed as Deleting: duplicati-i059b1eb0bb3f474d9b556f90a437c944.dindex.zip.aes, … ]

Warnings: [
2018-04-04 18:13:00 +10 - [Warning-Duplicati.Library.Main.BackendManager-DeleteRemoteFileFailed]: Delete operation failed for duplicati-b75b72f41493b4438af7d0a042d6aa7ed.dblock.zip.aes with FileNotFound, listing contents,
2018-04-04 18:13:01 +10 - [Warning-Duplicati.Library.Main.BackendManager-DeleteRemoteFileFailed]: Delete operation failed for duplicati-i059b1eb0bb3f474d9b556f90a437c944.dindex.zip.aes with FileNotFound, listing contents,
2018-04-04 18:13:02 +10 - [Warning-Duplicati.Library.Main.BackendManager-DeleteRemoteFileFailed]: Delete operation failed for duplicati-b9f161a11c26e4c3fa118ac71964370f2.dblock.zip.aes with FileNotFound, listing contents,
2018-04-04 18:13:03 +10 - [Warning-Duplicati.Library.Main.BackendManager-DeleteRemoteFileFailed]: Delete operation failed for duplicati-i4f314092ff4c4dc88f5b37e299619dfd.dindex.zip.aes with FileNotFound, listing contents,
2018-04-04 18:13:05 +10 - [Warning-Duplicati.Library.Main.BackendManager-DeleteRemoteFileFailed]: Delete operation failed for duplicati-b4ee4c0684d8f4c0ca5b85dcb87fa221d.dblock.zip.aes with FileNotFound, listing contents, … ]

Errors: []
BackendStatistics:
RemoteCalls: 8
BytesUploaded: 0
BytesDownloaded: 0
FilesUploaded: 0
FilesDownloaded: 0
FilesDeleted: 0
FoldersCreated: 0
RetryAttempts: 0
UnknownFileSize: 0
UnknownFileCount: 0
KnownFileCount: 21
KnownFileSize: 218718335
LastBackupDate: 4/04/2018 7:53:43 AM (1522792423)
BackupListCount: 1
TotalQuotaSpace: 0
FreeQuotaSpace: 0
AssignedQuotaSpace: -1
ReportedQuotaError: False
ReportedQuotaWarning: False
ParsedResult: Warning Messages: [
2018-04-04 18:13:00 +10 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started,
2018-04-04 18:13:00 +10 - [Information-Duplicati.Library.Main.Operation.FilelistProcessor-RemovingStaleFile]: Removing remote file listed as Deleting: duplicati-b75b72f41493b4438af7d0a042d6aa7ed.dblock.zip.aes,
2018-04-04 18:13:00 +10 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Delete - Started: duplicati-b75b72f41493b4438af7d0a042d6aa7ed.dblock.zip.aes (),
2018-04-04 18:13:01 +10 - [Information-Duplicati.Library.Main.BackendManager-DeleteRemoteFileSuccess]: Listing indicates file duplicati-b75b72f41493b4438af7d0a042d6aa7ed.dblock.zip.aes is deleted correctly,
2018-04-04 18:13:01 +10 - [Information-Duplicati.Library.Main.Operation.FilelistProcessor-RemovingStaleFile]: Removing remote file listed as Deleting: duplicati-i059b1eb0bb3f474d9b556f90a437c944.dindex.zip.aes, … ]

Warnings: [
2018-04-04 18:13:00 +10 - [Warning-Duplicati.Library.Main.BackendManager-DeleteRemoteFileFailed]: Delete operation failed for duplicati-b75b72f41493b4438af7d0a042d6aa7ed.dblock.zip.aes with FileNotFound, listing contents,
2018-04-04 18:13:01 +10 - [Warning-Duplicati.Library.Main.BackendManager-DeleteRemoteFileFailed]: Delete operation failed for duplicati-i059b1eb0bb3f474d9b556f90a437c944.dindex.zip.aes with FileNotFound, listing contents,
2018-04-04 18:13:02 +10 - [Warning-Duplicati.Library.Main.BackendManager-DeleteRemoteFileFailed]: Delete operation failed for duplicati-b9f161a11c26e4c3fa118ac71964370f2.dblock.zip.aes with FileNotFound, listing contents,
2018-04-04 18:13:03 +10 - [Warning-Duplicati.Library.Main.BackendManager-DeleteRemoteFileFailed]: Delete operation failed for duplicati-i4f314092ff4c4dc88f5b37e299619dfd.dindex.zip.aes with FileNotFound, listing contents,
2018-04-04 18:13:05 +10 - [Warning-Duplicati.Library.Main.BackendManager-DeleteRemoteFileFailed]: Delete operation failed for duplicati-b4ee4c0684d8f4c0ca5b85dcb87fa221d.dblock.zip.aes with FileNotFound, listing contents, … ]

Errors: []
RepairResults: null
TestResults: null
ParsedResult: Warning
EndTime: 4/04/2018 6:13:08 PM (1522829588)
BeginTime: 4/04/2018 6:13:00 PM (1522829580)
Duration: 00:00:08.9535568
Messages: [
2018-04-04 18:13:00 +10 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started, 2018-04-04 18:13:00 +10 - [Information-Duplicati.Library.Main.Operation.FilelistProcessor-RemovingStaleFile]: Removing remote file listed as Deleting: duplicati-b75b72f41493b4438af7d0a042d6aa7ed.dblock.zip.aes,
2018-04-04 18:13:00 +10 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Delete - Started: duplicati-b75b72f41493b4438af7d0a042d6aa7ed.dblock.zip.aes (),
2018-04-04 18:13:01 +10 - [Information-Duplicati.Library.Main.BackendManager-DeleteRemoteFileSuccess]: Listing indicates file duplicati-b75b72f41493b4438af7d0a042d6aa7ed.dblock.zip.aes is deleted correctly,
2018-04-04 18:13:01 +10 - [Information-Duplicati.Library.Main.Operation.FilelistProcessor-RemovingStaleFile]: Removing remote file listed as Deleting: duplicati-i059b1eb0bb3f474d9b556f90a437c944.dindex.zip.aes, … ]

Warnings: [
2018-04-04 18:13:00 +10 - [Warning-Duplicati.Library.Main.BackendManager-DeleteRemoteFileFailed]: Delete operation failed for duplicati-b75b72f41493b4438af7d0a042d6aa7ed.dblock.zip.aes with FileNotFound, listing contents,
2018-04-04 18:13:01 +10 - [Warning-Duplicati.Library.Main.BackendManager-DeleteRemoteFileFailed]: Delete operation failed for duplicati-i059b1eb0bb3f474d9b556f90a437c944.dindex.zip.aes with FileNotFound, listing contents,
2018-04-04 18:13:02 +10 - [Warning-Duplicati.Library.Main.BackendManager-DeleteRemoteFileFailed]: Delete operation failed for duplicati-b9f161a11c26e4c3fa118ac71964370f2.dblock.zip.aes with FileNotFound, listing contents,
2018-04-04 18:13:03 +10 - [Warning-Duplicati.Library.Main.BackendManager-DeleteRemoteFileFailed]: Delete operation failed for duplicati-i4f314092ff4c4dc88f5b37e299619dfd.dindex.zip.aes with FileNotFound, listing contents,
2018-04-04 18:13:05 +10 - [Warning-Duplicati.Library.Main.BackendManager-DeleteRemoteFileFailed]: Delete operation failed for duplicati-b4ee4c0684d8f4c0ca5b85dcb87fa221d.dblock.zip.aes with FileNotFound, listing contents, … ]
Errors: []

Any help would be much appreciated!
Thanks!


#2

Hi @JsPhoto, welcome to the forum!

This sounds like something I ran into a while ago (Repeated "Delete operation failed" due to file not found). In my case, I a database REPAIR (not recreate) was all that was needed.

That should also resolve your “missing files” error messages.

Sorry if I missed it in your post, but were you able to “manually” verify that the reported missing files were ACTUALLY no longer on the NextCloud destination?

If it’s still in your logs, try going back a bit further and see if you can find a log entry requesting the deletion of the now-reported-missing files. I believe that’s what happened to me - they were requested to be deleted, they WERE deleted, but then they were requested to be deleted again which started throwing the warnings.


I should note that --no-backend-verification is a good TESTING tool, but not really a good long term solution.


#3

Ok, so I made a new test backup, just to essentially start again.

Without --no-backend-verification disabled on the very first run of just one file, I get a return of 3 files missing. I enabled it, ran the backup, no errors at all.

I hit repair on the original test backup, its still going, seems to just be stuck in “starting”. Its been about 10 mins.

And to confirm, yes, I can check on nextcloud and the files that have been marked as deleted are definitely deleted.


#4

Small update, found a post that suggested flipping the slashes from forward to back and what not, so I did this, it fixed the starting issue and the DB repairs instantly. I still get the warning messages.


Found 114 files that are missing from the remote storage, please run repair
#5

Repairs can be quick but have also been known to run for an hour or more (and Rebuild / Recreate can, but doesn’t always, take days).

If you happen to remember which post that was, please let us know. This may point to a different in how paths are handled in different parts of the code.

So you’re back to the same Delete operation failed warnings even with the forward / back slash change and after the repair on the original (not test) backup?