"Failed while attempting to add unmodified file to database" with HyperV VMs

I was receiving a tonne of failures uploading to Google Drive the last month or two so decided to shift the existing backups on Google Drive to another location, making the existing folder blank, Delete the Database and Recreate it, then run a manual backup.

I do see files on Google Drive, but I’m getting a bunch of warnings, both when run manually and when scheduled;

Summary - I get these two messages for every VM being backed up;

  • 2021-10-31 05:19:14 +00 - [Warning-Duplicati.Library.Main.Operation.Backup.FilePreFilterProcess.FileEntry-FailedToAddFile]: Failed while attempting to add unmodified file to database: D:\Virtual Hard Disks\Win10 Test.vhdx
  • 2021-10-31 05:36:58 +00 - [Warning-Duplicati.Library.Main.Operation.Backup.FileBlockProcessor.FileEntry-PathProcessingFailed]: Failed to process path: D:\Virtual Machines\Win10 Test\Virtual Machines\B637EA1C-6CEF-421F-A669-6380BBBB77F2.xml

How can I resolve these? The HyperV advanced option is enabled in the backup settings.

Welcome to the forum @Sutnyul

Meaning Google Drive was empty?

Please confirm by looking at the job configuration that it no longer uses Google Drive as Destination.
If that was true at time of backup, I don’t know why any files went there. Does it look like full backup?
What (if anything) went to the new location?

is exactly the reason not much can be said, at least by me. The one-line log messages trim off detail.
Can you get a view using About → Show log → Live → Warning? Might need to click line to expand it.

Hi

Meaning Google Drive was empty?

I made the folder on Google Drive, which Duplicati is normally backing up to, Empty.

Please confirm by looking at the job configuration that it no longer uses Google Drive as Destination.
If that was true at time of backup, I don’t know why any files went there. Does it look like full backup?
What (if anything) went to the new location?

It IS configured to use Google Drive as its Destination, as that’s what I want it to be. Going by the amount of files that are being placed there, it looks like a full backup is being performed.

is exactly the reason not much can be said, at least by me. The one-line log messages trim off detail.
Can you get a view using About → Show log → Live → Warning? Might need to click line to expand it.

So I repeated what I did previously; moved existing backups out of the Google Drive folder, deleted the database both in Home > Advanced > Database > Delete and by removing the sqlite files in C:\Program Files\Duplicati 2\data

And then started a backup manually by clicking Run Now.

I’m now getting the following error upon completion;

10 Nov 2021 16:08: Request for http://hyperv03:8200/api/v1/backup/1/log?pagesize=15 gave error
code = Error (1), message = System.Data.SQLite.SQLiteException (0x800007BF): SQL logic error
no such table: LogData
   at System.Data.SQLite.SQLite3.Prepare(SQLiteConnection cnn, String strSql, SQLiteStatement previous, UInt32 timeoutMS, String& strRemain)
   at System.Data.SQLite.SQLiteCommand.BuildNextCommand()
   at System.Data.SQLite.SQLiteDataReader.NextResult()
   at System.Data.SQLite.SQLiteDataReader..ctor(SQLiteCommand cmd, CommandBehavior behave)
   at System.Data.SQLite.SQLiteCommand.ExecuteReader(CommandBehavior behavior)
   at Duplicati.Server.WebServer.RESTMethods.LogData.DumpTable(IDbCommand cmd, String tablename, String pagingfield, String offset_str, String pagesize_str)
   at Duplicati.Server.WebServer.RESTMethods.Backup.FetchLogData(IBackup backup, RequestInfo info)
   at Duplicati.Server.WebServer.RESTHandler.DoProcess(RequestInfo info, String method, String module, String key)
10 Nov 2021 16:08: Reporting error gave error
System.ObjectDisposedException: Cannot write to a closed TextWriter.
   at System.IO.__Error.WriterClosed()
   at System.IO.StreamWriter.Flush(Boolean flushStream, Boolean flushEncoder)
   at Duplicati.Server.WebServer.RESTHandler.DoProcess(RequestInfo info, String method, String module, String key)

The complete log says the following;

{
  "DeletedFiles": 0,
  "DeletedFolders": 0,
  "ModifiedFiles": 0,
  "ExaminedFiles": 45,
  "OpenedFiles": 45,
  "AddedFiles": 38,
  "SizeOfModifiedFiles": 0,
  "SizeOfAddedFiles": 1419417971996,
  "SizeOfExaminedFiles": 1419417971996,
  "SizeOfOpenedFiles": 1419417971996,
  "NotProcessedFiles": 0,
  "AddedFolders": 56,
  "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.100 (2.0.6.100_canary_2021-08-11)",
    "EndTime": "2021-11-11T00:57:56.5236154Z",
    "BeginTime": "2021-11-11T00:57:34.0234481Z",
    "Duration": "00:00:22.5001673",
    "MessagesActualLength": 0,
    "WarningsActualLength": 0,
    "ErrorsActualLength": 0,
    "Messages": null,
    "Warnings": null,
    "Errors": null,
    "BackendStatistics": {
      "RemoteCalls": 86,
      "BytesUploaded": 428819984349,
      "BytesDownloaded": 10746955479,
      "FilesUploaded": 81,
      "FilesDownloaded": 3,
      "FilesDeleted": 0,
      "FoldersCreated": 0,
      "RetryAttempts": 0,
      "UnknownFileSize": 0,
      "UnknownFileCount": 0,
      "KnownFileCount": 81,
      "KnownFileSize": 428819984349,
      "LastBackupDate": "2021-11-10T16:08:53+00:00",
      "BackupListCount": 1,
      "TotalQuotaSpace": 15277416953134,
      "FreeQuotaSpace": 10995116277760,
      "AssignedQuotaSpace": -1,
      "ReportedQuotaError": false,
      "ReportedQuotaWarning": false,
      "MainOperation": "Backup",
      "ParsedResult": "Success",
      "Version": "2.0.6.100 (2.0.6.100_canary_2021-08-11)",
      "EndTime": "0001-01-01T00:00:00",
      "BeginTime": "2021-11-10T16:08:51.8573565Z",
      "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": "randomdigits.aes",
        "Value": []
      },
      {
        "Key": "randomdigits.aes",
        "Value": []
      },
      {
        "Key": "randomdigits.aes",
        "Value": []
      }
    ],
    "ParsedResult": "Success",
    "Version": "2.0.6.100 (2.0.6.100_canary_2021-08-11)",
    "EndTime": "2021-11-11T01:05:48.315138Z",
    "BeginTime": "2021-11-11T00:57:58.4771083Z",
    "Duration": "00:07:49.8380297",
    "MessagesActualLength": 0,
    "WarningsActualLength": 0,
    "ErrorsActualLength": 0,
    "Messages": null,
    "Warnings": null,
    "Errors": null,
    "BackendStatistics": {
      "RemoteCalls": 86,
      "BytesUploaded": 428819984349,
      "BytesDownloaded": 10746955479,
      "FilesUploaded": 81,
      "FilesDownloaded": 3,
      "FilesDeleted": 0,
      "FoldersCreated": 0,
      "RetryAttempts": 0,
      "UnknownFileSize": 0,
      "UnknownFileCount": 0,
      "KnownFileCount": 81,
      "KnownFileSize": 428819984349,
      "LastBackupDate": "2021-11-10T16:08:53+00:00",
      "BackupListCount": 1,
      "TotalQuotaSpace": 15277416953134,
      "FreeQuotaSpace": 10995116277760,
      "AssignedQuotaSpace": -1,
      "ReportedQuotaError": false,
      "ReportedQuotaWarning": false,
      "MainOperation": "Backup",
      "ParsedResult": "Success",
      "Version": "2.0.6.100 (2.0.6.100_canary_2021-08-11)",
      "EndTime": "0001-01-01T00:00:00",
      "BeginTime": "2021-11-10T16:08:51.8573565Z",
      "Duration": "00:00:00",
      "MessagesActualLength": 0,
      "WarningsActualLength": 0,
      "ErrorsActualLength": 0,
      "Messages": null,
      "Warnings": null,
      "Errors": null
    }
  },
  "ParsedResult": "Warning",
  "Version": "2.0.6.100 (2.0.6.100_canary_2021-08-11)",
  "EndTime": "2021-11-11T01:05:48.315138Z",
  "BeginTime": "2021-11-10T16:08:51.8573565Z",
  "Duration": "08:56:56.4577815",
  "MessagesActualLength": 192,
  "WarningsActualLength": 7,
  "ErrorsActualLength": 0,
  "Messages": [
    "2021-11-10 16:08:51 +00 - [Information-Duplicati.Library.Modules.Builtin.HyperVOptions-StartingHyperVQuery]: Starting to gather Hyper-V information",
    "2021-11-10 16:08:53 +00 - [Information-Duplicati.Library.Modules.Builtin.HyperVOptions-HyperVMachineCount]: Found 7 virtual machines on Hyper-V",
    "2021-11-10 16:08:53 +00 - [Information-Duplicati.Library.Modules.Builtin.HyperVOptions-IncludeHyperV]: For VM PROSRV03 - adding D:\\Virtual Machines\\PROSRV03\\Virtual Machines\\2F94605A-B7E5-44D5-BA86-5F064D03504D.xml",
    "2021-11-10 16:08:53 +00 - [Information-Duplicati.Library.Modules.Builtin.HyperVOptions-IncludeHyperV]: For VM PROSRV03 - adding D:\\virtual hard disks\\PROSRV03.vhdx",
    "2021-11-10 16:08:53 +00 - [Information-Duplicati.Library.Modules.Builtin.HyperVOptions-IncludeHyperV]: For VM PROSRV03 - adding D:\\virtual hard disks\\software.vhdx",
    "2021-11-10 16:08:53 +00 - [Information-Duplicati.Library.Modules.Builtin.HyperVOptions-IncludeHyperV]: For VM Ops - adding D:\\virtual machines\\Virtual Machines\\40DD3749-117D-4593-B02B-3D76AAFB13B4.xml",
    "2021-11-10 16:08:53 +00 - [Information-Duplicati.Library.Modules.Builtin.HyperVOptions-IncludeHyperV]: For VM Ops - adding D:\\virtual hard disks\\Ops.vhdx",
    "2021-11-10 16:08:53 +00 - [Information-Duplicati.Library.Modules.Builtin.HyperVOptions-IncludeHyperV]: For VM DC01 - adding D:\\Virtual Machines\\DC01\\Virtual Machines\\44AB0F4B-0D69-4368-B8A8-1C6CFF62163E.xml",
    "2021-11-10 16:08:53 +00 - [Information-Duplicati.Library.Modules.Builtin.HyperVOptions-IncludeHyperV]: For VM DC01 - adding D:\\virtual hard disks\\dc01.new (generation 2).vhdx",
    "2021-11-10 16:08:53 +00 - [Information-Duplicati.Library.Modules.Builtin.HyperVOptions-IncludeHyperV]: For VM DC02 - adding D:\\virtual machines\\Virtual Machines\\81FC3E68-BF80-482A-ADD0-E45B9B79F283.xml",
    "2021-11-10 16:08:53 +00 - [Information-Duplicati.Library.Modules.Builtin.HyperVOptions-IncludeHyperV]: For VM DC02 - adding D:\\virtual hard disks\\DC02 (Generation 2).vhdx",
    "2021-11-10 16:08:53 +00 - [Information-Duplicati.Library.Modules.Builtin.HyperVOptions-IncludeHyperV]: For VM Gitlab-LCI-1 - adding C:\\hyperv\\lci-1\\Virtual Machine\\Virtual Machines\\99075D1B-B1E6-4507-B4EA-F680D960D30E.xml",
    "2021-11-10 16:08:53 +00 - [Information-Duplicati.Library.Modules.Builtin.HyperVOptions-IncludeHyperV]: For VM Gitlab-LCI-1 - adding C:\\hyperv\\lci-1\\Virtual Hard Disks\\Gitlab-LCI-1.vhdx",
    "2021-11-10 16:08:53 +00 - [Information-Duplicati.Library.Modules.Builtin.HyperVOptions-IncludeHyperV]: For VM PROSRV02 - adding D:\\Virtual Machines\\PROSRV02\\Virtual Machines\\CF8190C5-E6BD-4C87-8FE8-B04BF131C5AC.xml",
    "2021-11-10 16:08:53 +00 - [Information-Duplicati.Library.Modules.Builtin.HyperVOptions-IncludeHyperV]: For VM PROSRV02 - adding D:\\virtual hard disks\\PROSRV02.vhdx",
    "2021-11-10 16:08:53 +00 - [Information-Duplicati.Library.Modules.Builtin.HyperVOptions-IncludeHyperV]: For VM PROSRV02 - adding D:\\virtual hard disks\\software.vhdx",
    "2021-11-10 16:08:53 +00 - [Information-Duplicati.Library.Modules.Builtin.HyperVOptions-IncludeHyperV]: For VM KMS - adding D:\\virtual machines\\KMS\\Virtual Machines\\D7910B21-B7DC-47AF-B908-51EA11264CB9.xml",
    "2021-11-10 16:08:53 +00 - [Information-Duplicati.Library.Modules.Builtin.HyperVOptions-IncludeHyperV]: For VM KMS - adding D:\\virtual hard disks\\kms.vhdx",
    "2021-11-10 16:08:53 +00 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started",
    "2021-11-10 16:09:04 +00 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started:  ()"
  ],
  "Warnings": [
    "2021-11-10 23:40:42 +00 - [Warning-Duplicati.Library.Main.Operation.Backup.FileBlockProcessor.FileEntry-PathProcessingFailed]: Failed to process path: D:\\virtual hard disks\\DC02 (Generation 2).vhdx",
    "2021-11-10 23:52:04 +00 - [Warning-Duplicati.Library.Main.Operation.Backup.FileBlockProcessor.FileEntry-PathProcessingFailed]: Failed to process path: D:\\virtual hard disks\\Ops.vhdx",
    "2021-11-10 23:55:37 +00 - [Warning-Duplicati.Library.Main.Operation.Backup.FileBlockProcessor.FileEntry-PathProcessingFailed]: Failed to process path: D:\\virtual hard disks\\PROSRV02.vhdx",
    "2021-11-10 23:59:47 +00 - [Warning-Duplicati.Library.Main.Operation.Backup.FileBlockProcessor.FileEntry-PathProcessingFailed]: Failed to process path: D:\\virtual hard disks\\PROSRV03.vhdx",
    "2021-11-11 00:01:51 +00 - [Warning-Duplicati.Library.Main.Operation.Backup.FileBlockProcessor.FileEntry-PathProcessingFailed]: Failed to process path: D:\\Virtual Machines\\DC01\\Virtual Machines\\44AB0F4B-0D69-4368-B8A8-1C6CFF62163E.xml",
    "2021-11-11 00:01:51 +00 - [Warning-Duplicati.Library.Main.Operation.Backup.FileBlockProcessor.FileEntry-PathProcessingFailed]: Failed to process path: D:\\Virtual Machines\\PROSRV02\\Virtual Machines\\CF8190C5-E6BD-4C87-8FE8-B04BF131C5AC.xml",
    "2021-11-11 00:01:51 +00 - [Warning-Duplicati.Library.Main.Operation.Backup.FileBlockProcessor.FileEntry-PathProcessingFailed]: Failed to process path: D:\\Virtual Machines\\PROSRV03\\Virtual Machines\\2F94605A-B7E5-44D5-BA86-5F064D03504D.xml"
  ],
  "Errors": [],
  "BackendStatistics": {
    "RemoteCalls": 86,
    "BytesUploaded": 428819984349,
    "BytesDownloaded": 10746955479,
    "FilesUploaded": 81,
    "FilesDownloaded": 3,
    "FilesDeleted": 0,
    "FoldersCreated": 0,
    "RetryAttempts": 0,
    "UnknownFileSize": 0,
    "UnknownFileCount": 0,
    "KnownFileCount": 81,
    "KnownFileSize": 428819984349,
    "LastBackupDate": "2021-11-10T16:08:53+00:00",
    "BackupListCount": 1,
    "TotalQuotaSpace": 15277416953134,
    "FreeQuotaSpace": 10995116277760,
    "AssignedQuotaSpace": -1,
    "ReportedQuotaError": false,
    "ReportedQuotaWarning": false,
    "MainOperation": "Backup",
    "ParsedResult": "Success",
    "Version": "2.0.6.100 (2.0.6.100_canary_2021-08-11)",
    "EndTime": "0001-01-01T00:00:00",
    "BeginTime": "2021-11-10T16:08:51.8573565Z",
    "Duration": "00:00:00",
    "MessagesActualLength": 0,
    "WarningsActualLength": 0,
    "ErrorsActualLength": 0,
    "Messages": null,
    "Warnings": null,
    "Errors": null
  }
}

Looking at Google Drive, there are files there, so something is being uploaded. I click Verify in Duplicati but no errors, so I’m really not sure what’s wrong.