Why ParsedResult=Error, then there is no error due warnings


#1

I made some after backup script what analyzed result file. But I wondered that ParsedResult=Error, not warning and backup was made. But I see Warnings in the file:

DeletedFiles: 3
DeletedFolders: 0
ModifiedFiles: 15
ExaminedFiles: 102377
OpenedFiles: 32
AddedFiles: 15
SizeOfModifiedFiles: 3291863939
SizeOfAddedFiles: 903621
SizeOfExaminedFiles: 54623711876
SizeOfOpenedFiles: 3292771591
NotProcessedFiles: 0
AddedFolders: 3
TooLargeFiles: 0
FilesWithError: 2
ModifiedFolders: 0
ModifiedSymlinks: 0
AddedSymlinks: 0
DeletedSymlinks: 0
PartialBackup: False
Dryrun: False
MainOperation: Backup
ParsedResult: Error
EndTime: 09.04.2018 21:36:13 (1523298973)
BeginTime: 09.04.2018 21:30:00 (1523298600)
Duration: 00:06:13.0352785
Messages: [
2018-04-09 21:30:01 +03 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started,
2018-04-09 21:30:03 +03 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started: (),
2018-04-09 21:30:03 +03 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed: (379 bytes),
2018-04-09 21:35:28 +03 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-b33afd37aef3944629dbf373561f47f11.dblock.zip.aes (15,46 MB),
2018-04-09 21:35:28 +03 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-b33afd37aef3944629dbf373561f47f11.dblock.zip.aes (15,46 MB),
2018-04-09 21:35:28 +03 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-icdbd5e8d96ef4f839c12da9afc89cb7b.dindex.zip.aes (955,28 KB),
2018-04-09 21:35:28 +03 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-icdbd5e8d96ef4f839c12da9afc89cb7b.dindex.zip.aes (955,28 KB),
2018-04-09 21:35:49 +03 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-20180409T183001Z.dlist.zip.aes (8,98 MB),
2018-04-09 21:35:49 +03 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-20180409T183001Z.dlist.zip.aes (8,98 MB),
2018-04-09 21:35:49 +03 - [Information-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-StartCheck]: Start checking if backups can be removed,
2018-04-09 21:35:49 +03 - [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,
2018-04-09 21:35:49 +03 - [Information-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-BackupList]: Backups to consider: 08.04.2018 18:48:31, 07.04.2018 21:30:02, 06.04.2018 21:30:02, 04.04.2018 21:30:03, 03.04.2018 21:30:02, 02.04.2018 21:30:01, 31.03.2018 12:09:14,
2018-04-09 21:35:49 +03 - [Information-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-BackupsToDelete]: Backups outside of all time frames and thus getting deleted: ,
2018-04-09 21:35:49 +03 - [Information-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-AllBackupsToDelete]: All backups to delete: 08.04.2018 18:48:31, 02.04.2018 21:30:01,
2018-04-09 21:35:49 +03 - [Information-Duplicati.Library.Main.Operation.DeleteHandler-DeleteRemoteFileset]: Deleting 2 remote fileset(s) …,
2018-04-09 21:36:04 +03 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Delete - Started: duplicati-20180402T183001Z.dlist.zip.aes (8,97 MB),
2018-04-09 21:36:04 +03 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Delete - Completed: duplicati-20180402T183001Z.dlist.zip.aes (8,97 MB),
2018-04-09 21:36:04 +03 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Delete - Started: duplicati-20180408T154831Z.dlist.zip.aes (8,98 MB),
2018-04-09 21:36:04 +03 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Delete - Completed: duplicati-20180408T154831Z.dlist.zip.aes (8,98 MB),
2018-04-09 21:36:04 +03 - [Information-Duplicati.Library.Main.Operation.DeleteHandler-DeleteResults]: Deleted 2 remote fileset(s),
2018-04-09 21:36:09 +03 - [Information-Duplicati.Library.Main.Database.LocalDeleteDatabase-CompactReason]: Compacting not required,
2018-04-09 21:36:09 +03 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started: (),
2018-04-09 21:36:09 +03 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed: (380 bytes),
2018-04-09 21:36:10 +03 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-20180409T183001Z.dlist.zip.aes (8,98 MB),
2018-04-09 21:36:10 +03 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-20180409T183001Z.dlist.zip.aes (8,98 MB),
2018-04-09 21:36:10 +03 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-i32cae75850994b81833a620a84646c46.dindex.zip.aes (189,48 KB),
2018-04-09 21:36:10 +03 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-i32cae75850994b81833a620a84646c46.dindex.zip.aes (189,48 KB),
2018-04-09 21:36:10 +03 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-b4c117c9ae2134395bf048ea91f747cd2.dblock.zip.aes (199,93 MB),
2018-04-09 21:36:12 +03 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-b4c117c9ae2134395bf048ea91f747cd2.dblock.zip.aes (199,93 MB)
]
Warnings: [
2018-04-09 21:31:41 +03 - [Warning-Duplicati.Library.Main.Operation.BackupHandler.FileEntry-PathProcessingFailed]: Failed to process path: D:\SomePath~$SomeFile1.xlsx,
2018-04-09 21:31:41 +03 - [Warning-Duplicati.Library.Main.Operation.BackupHandler.FileEntry-PathProcessingFailed]: Failed to process path: D:\SomePath~$SomeFile1.xlsx
]
Errors: []

The second question is how I can know if it was created backup or not?


Errors and Warnings not showing in job logs
#2

The Failed to process path “warning” is counted as an error (as seen in the FilesWithError: 2 line) and if FilesWithError > 0 the parsed result is set to “Error”.

Whether this is as designed or not I’m not sure, perhaps @kenkendk can confirm.

catch (Exception ex)
{
    Logging.Log.WriteWarningMessage(FILELOGTAG, "PathProcessingFailed", ex, "Failed to process path: {0}", path);
    m_result.FilesWithError++;
}

And:

if ((Errors != null && Errors.Any()) || FilesWithError > 0)
    return ParsedResultType.Error;

As for checking if a backup is created, there’s probably an easier way than this but I would just go to Restore and see when the most recent version was saved. As for checking from within a script, I’m not sure.


#3

Thanks for your work.

The problem is that I analyzed backup result in PowerShell script. Now I don’t check ParsedResult (but I hope that it will be correct) and analyzed only added,modified, deleted files, folders, symblinks and so on. And if one of them is greate than 0, make a compare due know what’s changed.


#4

I struggle a bit with classifying it. In some sense, any failure to back up any file is an error as the user could end up thinking they have a copy of the file, and then discover that is not the case.

On the other hand, if the file is simply a locked shadow copy, temporary file or similar, it should at most be a warning.

Unfortunately, we don’t have any reliable file classification, so I opted for reporting as an error, but I am open to change it.

One new thing is the filter groups, where you can choose to exclude “temporary files” and that should automatically remove such files from the list, an thus also remove the error. (not sure if the groups currently covers the file mentioned here, but maybe it should).


#5

I see. But I think if there is a error, so it have to increase error count, warning - warning.

Yes, it temporary file. But what better: won’t create backup due a locked file or create backup without a file with warning? I think better second variant. Because user can see what’s problem but backup created and it prevents data loss.


#6

My 2 cents:

If a file was not backed up for some reason (locked, no read permissions, whatever), it should be logged as an error, no matter what kind of file it is (including temporary files). If any file is included in the backup source list, it’s up to the user to either exclude the file or fix the problem.

  • Errors that affect one or more individual files, should raise the parsed result level to Warning.
  • Errors that affect all files in the backup (metadata inaccessible, failed to create shadowcopy) should raise the parsed result to Error.
  • Errors that prevent making a backup at all should raise the parsed result to Failed.

#7

Ok, but if ParsedResult = Warning, error text must be in “Warnings” and so on.


#8

Not Necessarily. Although I agree with you that it is less clear if Parsed Result and individual errors/warnings do not match.

If this is a problem, I suppose skipping single (locked) files should be logged as a warning instead of an error:

“Error” for parsed result should be reserved for these situations: “No backup”, “Backup aborted” and “External script returned an errorlevel that tells Duplicati to fail the backup”.
“Warning” should stand for “Incomplete backup”, “Invalid options supplied that were ignored” and “External script returned an errorlevel that tells Duplicati to stamp the result as Warning”.