Release: 2.0.9.107 (Canary) 2024-09-11

[kenkendk]

2.0.9.107_canary_2024-09-11

This release is a canary release intended to be used for testing in preparation of a later stable release.

Unlike regular canary builds, this one has a major change in the build system, so it now runs on .NET8.

For that reason, the updater in previous canary builds does not detect this update yet, but this can be activated at a later time.

The builds are self-contained so Mono or .NET installations are not required to install.

Important changes from last Beta

• Updated to .NET8 with OS specific builds
• Using Kestrel as the API/UI server
• Mandatory password and new authentication scheme for server
• Settings database version updated to v8

Please see list of known issues related to .NET8/Kestrel upgrade:

Followup .NET8 canary • duplicati

New tool to manage a running server

Due to incompatibility with duplicati_client a new tool is included, named Duplicati.CommandLine.ServerUtil.exe/duplicati-server-util.

Upgrade from v2.0.9.105

If you are upgrading from 2.0.9.105 please see the release notes from 2.0.9.106 for how to prepare the database.
Upgrades from other versions do not need special steps.

Detailed list of changes:

• Prepared some additional localization strings
• Fixed a bug with server-util not finding backups by name
• Added support for insecure connections from server-util
• Embedding backwards compatible ARMv7 binaries in builds
• Another fix for MSI packages breaking on upgrade
• Improved Swagger output to include types
• Replaced WebRequest for WebDAV with HttpClient
• Reduced log output from server-util and TrayIcon
• Microfix for USN parsing
• Fixed a case where almost identical files could cause broken index files, thanks @Jojo-1000
• Also improved handling when reading index files with broken lists, thanks @Jojo-1000
• Fixed auto-repair failing due to locked databases, thanks @Jojo-1000

[Taomyn]

Attempted upgrades on my test Windows 2022 server and my RPI-4 (arm7), both are working nicely so far (still need to run backups), but:

• Upgrade Windows 2022 .106->.107 the MSI is still not working well, after the upgrade was left with this:
  
  
  
  Note the size of .107
  I uninstalled both and re-run my installer again and it was fine
  
  
  
  Service and tray icon started fine afterwards, looks good so far
  Update check seems to be confused, was running .106 at the time
  
  After upgrade
  
• Upgrade RPI-4 (arm7) .106->.107 - no issue to report, service started without any intervention to library files so those work nicely. Update check also confused
  

Both installations set as “Default” for update channel.

I might try another couple of servers, Win2022/Fedora 40, if backups go well with the other two later.

[Sami_Lehtinen]

Now for me the x64 Windows MSI packages worked well and there were no missing dependencies. Tested on Windows 10 and 11.

[ts678]

@Sami_Lehtinen

Now for me the x64 Windows MSI packages worked well and there were no missing dependencies.

Mine worked on Windows 10 on an upgrade over 2.0.9.106, even if I tried to provoke it by leaving 2.0.9.106 running. With TrayIcon up, it gave a lot of complaints but wound up working OK anyway.

I chose the default Close, but it couldn’t. I was impressed at the end result, at least temporarily. Duplicati GUI was a little confused, but I view that as reasonable, given that I installed under it.

About said You are currently running unknown even though I’m pretty sure it was still 2.0.9.106.

I think doing the same test with 2.0.9.106 Windows service up didn’t see it. What does it check?

Service GUI says

You are currently running Duplicati - 2.0.9.106_canary_2024-09-03
Update 2.0.9.104 is available. Download now
Check for updates now

and at screen bottom a popup (likely persisted from the last time I ran Windows service) has

I think update check is rate-limited, but Check for updates now says 2.0.9.107 is available. Interestingly that’s only in the text at top. It left its Found update at the bottom for v2.0.9.104.

@Taomyn

Update check seems to be confused, was running .106 at the time

How so? Did you leave .106 up when updating to .107? Regardless, I can’t repro missing files.

EDIT:

Correction on Windows service test, as it had not been running Program Files copy of Duplicati.

is what happens when it is, then I try to upgrade to 2.0.9.107 while leaving 2.0.9.106 service up. Things look fine, comparing files against a .zip folder full of the files that I expected.msi to make.

[Sami_Lehtinen]

Btw. I’m very happy to close this long important term issue of backup restore failing with this version.

[Taomyn]

Upgraded another RPi-4, ARM64 this time, from 2.0.8beta, and all is working fine so far.

[Taomyn]

I just did a restore test on this machine, choosing a random small file (that hadn’t changed for a long time, 2023) and choosing to restore to original location and “Save different versions with timestamp in file name”, but it says nothing was restored and no sign of the restored file. The log from the job is:

            {
  "RestoredFiles": 0,
  "SizeOfRestoredFiles": 0,
  "RestoredFolders": 0,
  "RestoredSymlinks": 0,
  "PatchedFiles": 0,
  "DeletedFiles": 0,
  "DeletedFolders": 0,
  "DeletedSymlinks": 0,
  "MainOperation": "Restore",
  "RecreateDatabaseResults": null,
  "ParsedResult": "Warning",
  "Interrupted": false,
  "Version": "2.0.9.107 (2.0.9.107_canary_2024-09-11)",
  "EndTime": "2024-09-18T08:58:16.3689708Z",
  "BeginTime": "2024-09-18T08:58:09.3150303Z",
  "Duration": "00:00:07.0539405",
  "MessagesActualLength": 7,
  "WarningsActualLength": 1,
  "ErrorsActualLength": 0,
  "Messages": [
    "2024-09-18 10:58:09 +02 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Restore has started",
    "2024-09-18 10:58:09 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started:  ()",
    "2024-09-18 10:58:10 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed:  (46.771 KB)",
    "2024-09-18 10:58:13 +02 - [Information-Duplicati.Library.Main.Database.LocalRestoreDatabase-SearchingBackup]: Searching backup 0 (17/09/2024 22:24:47) ...",
    "2024-09-18 10:58:16 +02 - [Information-Duplicati.Library.Main.Operation.RestoreHandler-RemoteFileCount]: 1 remote files are required to restore",
    "2024-09-18 10:58:16 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-b2d13a2a993ca43da8fccec778a621db4.dblock.zip.aes (980.981 KB)",
    "2024-09-18 10:58:16 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-b2d13a2a993ca43da8fccec778a621db4.dblock.zip.aes (980.981 KB)"
  ],
  "Warnings": [
    "2024-09-18 10:58:16 +02 - [Warning-Duplicati.Library.Main.Operation.RestoreHandler-NoFilesRestored]: Restore completed without errors but no files were restored"
  ],
  "Errors": [],
  "BackendStatistics": {
    "RemoteCalls": 2,
    "BytesUploaded": 0,
    "BytesDownloaded": 1004525,
    "FilesUploaded": 0,
    "FilesDownloaded": 1,
    "FilesDeleted": 0,
    "FoldersCreated": 0,
    "RetryAttempts": 0,
    "UnknownFileSize": 0,
    "UnknownFileCount": 0,
    "KnownFileCount": 47894,
    "KnownFileSize": 24442435630,
    "LastBackupDate": "2024-09-18T00:24:47+02:00",
    "BackupListCount": 5,
    "TotalQuotaSpace": 125726552064,
    "FreeQuotaSpace": 82076151808,
    "AssignedQuotaSpace": -1,
    "ReportedQuotaError": false,
    "ReportedQuotaWarning": false,
    "MainOperation": "Restore",
    "ParsedResult": "Success",
    "Interrupted": false,
    "Version": "2.0.9.107 (2.0.9.107_canary_2024-09-11)",
    "EndTime": "0001-01-01T00:00:00",
    "BeginTime": "2024-09-18T08:58:09.315048Z",
    "Duration": "00:00:00",
    "MessagesActualLength": 0,
    "WarningsActualLength": 0,
    "ErrorsActualLength": 0,
    "Messages": null,
    "Warnings": null,
    "Errors": null
  }
}

Any idea why?

[ts678]

@Taomyn

Save different versions with timestamp in file name

is not very precise, but it means version of a file, for example the content changed, so

@Taomyn

file (that hadn’t changed for a long time, 2023) and choosing to restore to original location

makes me wonder if the file you wanted was already there and correct. If so, no restore.

@Taomyn

it says nothing was restored

is the frequently confusing result for people who try to restore when restore isn’t needed.

@Taomyn

no sign of the restored file

Does this refer to the original location? If file is fine, don’t expect another with timestamp.

[Taomyn]

Ok, so expected behaviour but personally it feels wrong - so I guess I need to choose another location to force it to download it then?

[ts678]

@Taomyn

I guess I need to choose another location to force it to download it then?

You could also modify the original file location (maybe make a copy first) then restore to it.
Or you can do that in the other location, to test “How do you want to restore existing files”.

[Taomyn]

On my Windows Server 2022, the backup job to Wasabi S3 for some reason failed last night, had been fine for many days. I retried and it failed again so I decided to recreate the database. However this is now failing:

            {
  "MainOperation": "Repair",
  "RecreateDatabaseResults": {
    "MainOperation": "Repair",
    "ParsedResult": "Success",
    "Interrupted": false,
    "Version": "2.0.9.107 (2.0.9.107_canary_2024-09-11)",
    "EndTime": "0001-01-01T00:00:00",
    "BeginTime": "2024-09-21T06:52:45.1876596Z",
    "Duration": "00:00:00",
    "MessagesActualLength": 0,
    "WarningsActualLength": 0,
    "ErrorsActualLength": 0,
    "Messages": null,
    "Warnings": null,
    "Errors": null,
    "BackendStatistics": {
      "RemoteCalls": 12964,
      "BytesUploaded": 0,
      "BytesDownloaded": 632850295,
      "FilesUploaded": 0,
      "FilesDownloaded": 12963,
      "FilesDeleted": 0,
      "FoldersCreated": 0,
      "RetryAttempts": 0,
      "UnknownFileSize": 0,
      "UnknownFileCount": 0,
      "KnownFileCount": 0,
      "KnownFileSize": 0,
      "LastBackupDate": "0001-01-01T00:00:00",
      "BackupListCount": 0,
      "TotalQuotaSpace": 0,
      "FreeQuotaSpace": 0,
      "AssignedQuotaSpace": 0,
      "ReportedQuotaError": false,
      "ReportedQuotaWarning": false,
      "MainOperation": "Repair",
      "ParsedResult": "Success",
      "Interrupted": false,
      "Version": "2.0.9.107 (2.0.9.107_canary_2024-09-11)",
      "EndTime": "0001-01-01T00:00:00",
      "BeginTime": "2024-09-21T06:52:44.7399291Z",
      "Duration": "00:00:00",
      "MessagesActualLength": 0,
      "WarningsActualLength": 0,
      "ErrorsActualLength": 0,
      "Messages": null,
      "Warnings": null,
      "Errors": null
    }
  },
  "ParsedResult": "Fatal",
  "Interrupted": false,
  "Version": "2.0.9.107 (2.0.9.107_canary_2024-09-11)",
  "EndTime": "2024-09-21T08:00:51.2556651Z",
  "BeginTime": "2024-09-21T06:52:44.7399246Z",
  "Duration": "01:08:06.5157405",
  "MessagesActualLength": 25931,
  "WarningsActualLength": 2,
  "ErrorsActualLength": 6,
  "Messages": [
    "2024-09-21 08:52:45 +02 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Repair has started",
    "2024-09-21 08:52:47 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started:  ()",
    "2024-09-21 08:52:48 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed:  (25.29 KB)",
    "2024-09-21 09:15:58 +02 - [Information-Duplicati.Library.Main.Operation.RecreateDatabaseHandler-RebuildStarted]: Rebuild database started, downloading 20 filelists",
    "2024-09-21 09:15:58 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-20231029T094536Z.dlist.zip.aes (3.52 MB)",
    "2024-09-21 09:15:59 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-20231029T094536Z.dlist.zip.aes (3.52 MB)",
    "2024-09-21 09:15:59 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-20231206T060635Z.dlist.zip.aes (3.62 MB)",
    "2024-09-21 09:15:59 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-20231206T060635Z.dlist.zip.aes (3.62 MB)",
    "2024-09-21 09:16:02 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-20240115T051158Z.dlist.zip.aes (3.41 MB)",
    "2024-09-21 09:16:02 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-20240115T051158Z.dlist.zip.aes (3.41 MB)",
    "2024-09-21 09:16:05 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-20240219T052413Z.dlist.zip.aes (3.96 MB)",
    "2024-09-21 09:16:05 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-20240219T052413Z.dlist.zip.aes (3.96 MB)",
    "2024-09-21 09:16:07 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-20240322T051936Z.dlist.zip.aes (3.62 MB)",
    "2024-09-21 09:16:07 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-20240322T051936Z.dlist.zip.aes (3.62 MB)",
    "2024-09-21 09:16:10 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-20240413T042638Z.dlist.zip.aes (3.64 MB)",
    "2024-09-21 09:16:11 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-20240413T042638Z.dlist.zip.aes (3.64 MB)",
    "2024-09-21 09:16:14 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-20240429T041648Z.dlist.zip.aes (3.62 MB)",
    "2024-09-21 09:16:14 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-20240429T041648Z.dlist.zip.aes (3.62 MB)",
    "2024-09-21 09:16:17 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-20240601T040259Z.dlist.zip.aes (3.48 MB)",
    "2024-09-21 09:16:17 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-20240601T040259Z.dlist.zip.aes (3.48 MB)"
  ],
  "Warnings": [
    "2024-09-21 09:20:17 +02 - [Warning-Duplicati.Library.Main.Operation.RecreateDatabaseHandler-WrongBlocklistHashes]: duplicati-i1a38dada64b94dceb380c3a37b6d3125.dindex.zip.aes had invalid blocklists which could not be used. Consider deleting this index file and run repair to recreate it.",
    "2024-09-21 09:49:08 +02 - [Warning-Duplicati.Library.Main.Database.LocalRecreateDatabase-MissingVolumesDetected]: Found 5 missing volumes; attempting to replace blocks from existing volumes"
  ],
  "Errors": [
    "2024-09-21 09:19:55 +02 - [Error-Duplicati.Library.Main.Operation.RecreateDatabaseHandler-MissingFileDetected]: Remote file referenced as duplicati-b9e1f5e121479444d9fcc23ee8bd51872.dblock.zip.aes by duplicati-i16453320ee34465ca2e893331ee64171.dindex.zip.aes, but not found in list, registering a missing remote file",
    "2024-09-21 09:26:45 +02 - [Error-Duplicati.Library.Main.Operation.RecreateDatabaseHandler-MissingFileDetected]: Remote file referenced as duplicati-bc56973137cb642259676363069a849c5.dblock.zip.aes by duplicati-i6394beb6d51c496791743d885dd9d1b2.dindex.zip.aes, but not found in list, registering a missing remote file",
    "2024-09-21 09:30:21 +02 - [Error-Duplicati.Library.Main.Operation.RecreateDatabaseHandler-MissingFileDetected]: Remote file referenced as duplicati-b7a8359a5b95344d9b37675eab5fc4998.dblock.zip.aes by duplicati-i8ee561ff09f44db2887eca334055adaf.dindex.zip.aes, but not found in list, registering a missing remote file",
    "2024-09-21 09:31:40 +02 - [Error-Duplicati.Library.Main.Operation.RecreateDatabaseHandler-MissingFileDetected]: Remote file referenced as duplicati-bad2983f366a04e2c9bf3b3409182b286.dblock.zip.aes by duplicati-i9ea561cec92b4e4b8034b868cacd474f.dindex.zip.aes, but not found in list, registering a missing remote file",
    "2024-09-21 09:37:21 +02 - [Error-Duplicati.Library.Main.Operation.RecreateDatabaseHandler-MissingFileDetected]: Remote file referenced as duplicati-b600e2240b0984ce5b20c13a96c1a6181.dblock.zip.aes by duplicati-ie48cec5542ac490690ff70d0ef0d829c.dindex.zip.aes, but not found in list, registering a missing remote file",
    "2024-09-21 10:00:51 +02 - [Error-Duplicati.Library.Main.Controller-FailedOperation]: The operation Repair has failed with error: SQL logic error\r\nno such column: Temporary\r\nSQLiteException: SQL logic error\r\nno such column: Temporary"
  ],
  "BackendStatistics": {
    "RemoteCalls": 12964,
    "BytesUploaded": 0,
    "BytesDownloaded": 632850295,
    "FilesUploaded": 0,
    "FilesDownloaded": 12963,
    "FilesDeleted": 0,
    "FoldersCreated": 0,
    "RetryAttempts": 0,
    "UnknownFileSize": 0,
    "UnknownFileCount": 0,
    "KnownFileCount": 0,
    "KnownFileSize": 0,
    "LastBackupDate": "0001-01-01T00:00:00",
    "BackupListCount": 0,
    "TotalQuotaSpace": 0,
    "FreeQuotaSpace": 0,
    "AssignedQuotaSpace": 0,
    "ReportedQuotaError": false,
    "ReportedQuotaWarning": false,
    "MainOperation": "Repair",
    "ParsedResult": "Success",
    "Interrupted": false,
    "Version": "2.0.9.107 (2.0.9.107_canary_2024-09-11)",
    "EndTime": "0001-01-01T00:00:00",
    "BeginTime": "2024-09-21T06:52:44.7399291Z",
    "Duration": "00:00:00",
    "MessagesActualLength": 0,
    "WarningsActualLength": 0,
    "ErrorsActualLength": 0,
    "Messages": null,
    "Warnings": null,
    "Errors": null
  }
}
        

Any ideas how I can repair this backup job?

[ts678]

Looks like one update of an SQL string from double-quoted (now illegal) to single got missed.

"Remotevolume"."State" = "Temporary"

2024-09-21 09:09:28 -04 - [Profiling-Timer.Begin-Duplicati.Library.Main.Database.ExtensionMethods-ExecuteNonQuery]: Starting - ExecuteNonQuery: CREATE TEMPORARY TABLE "SwapBlocks-A593DDE69D1BCB4889F19349B5679F41" AS SELECT "A"."ID" AS "BlockID", "A"."VolumeID" AS "SourceVolumeID", "A"."State" AS "SourceVolumeState", "B"."VolumeID" AS "TargetVolumeID", "B"."State" AS "TargetVolumeState" FROM (SELECT "Block"."ID", "Block"."VolumeID", "Remotevolume"."State" FROM "Block", "Remotevolume" WHERE "Block"."VolumeID" = "Remotevolume"."ID" and "Remotevolume"."State" = "Temporary") A, (SELECT "DuplicateBlock"."BlockID", "DuplicateBlock"."VolumeID", "Remotevolume"."State" FROM "DuplicateBlock", "Remotevolume" WHERE "DuplicateBlock"."VolumeID" = "Remotevolume"."ID" and "Remotevolume"."State" = 'Verified') B WHERE "A"."ID" = "B"."BlockID";

duplicati/duplicati/blob/2827be6bb81a5694a9d6750a4b737fbb1f486253/Duplicati/Library/Main/Database/LocalRecreateDatabase.cs#L685-L697

While waiting for developer input, how old are the dindex files whose dblock files are missing?

EDIT:

BTW a repro for the bug was to copy a dindex file into another backup, then recreate other DB.

Example usage of CleanupMissingVolumes:

duplicati/duplicati/blob/2827be6bb81a5694a9d6750a4b737fbb1f486253/Duplicati/Library/Main/Operation/RecreateDatabaseHandler.cs#L469-L471

You wouldn’t happen to be using log-file option, would you? Database logs are less reliable.

[ts678]

Although I wound up using log-file, above test found a silent failure to turn the live log on.
I’d duplicated Duplicati Edge tab, set About → Show log → Live → Profiling. It stayed silent.

Watching in developer tools, it looked like the api poll was getting 500 Internal Server Error.

Console output is hard to match to action, but this is possibly what log setup failure caused:

fail: Microsoft.AspNetCore.Diagnostics.ExceptionHandlerMiddleware[1]
      An unhandled exception has occurred while executing the request.
      System.NotSupportedException: Serialization and deserialization of 'System.Reflection.MethodBase' instances is not supported. Path: $.Exception.TargetSite.
       ---> System.NotSupportedException: Serialization and deserialization of 'System.Reflection.MethodBase' instances is not supported.
         at System.Text.Json.Serialization.Converters.UnsupportedTypeConverter`1.Write(Utf8JsonWriter writer, T value, JsonSerializerOptions options)
         at System.Text.Json.Serialization.JsonConverter`1.TryWrite(Utf8JsonWriter writer, T& value, JsonSerializerOptions options, WriteStack& state)
         at System.Text.Json.Serialization.Metadata.JsonPropertyInfo`1.GetMemberAndWriteJson(Object obj, WriteStack& state, Utf8JsonWriter writer)
         at System.Text.Json.Serialization.Converters.ObjectDefaultConverter`1.OnTryWrite(Utf8JsonWriter writer, T value, JsonSerializerOptions options, WriteStack& state)
         at System.Text.Json.Serialization.JsonConverter`1.TryWrite(Utf8JsonWriter writer, T& value, JsonSerializerOptions options, WriteStack& state)
         at System.Text.Json.Serialization.Metadata.JsonPropertyInfo`1.GetMemberAndWriteJson(Object obj, WriteStack& state, Utf8JsonWriter writer)
         at System.Text.Json.Serialization.Converters.ObjectDefaultConverter`1.OnTryWrite(Utf8JsonWriter writer, T value, JsonSerializerOptions options, WriteStack& state)
         at System.Text.Json.Serialization.JsonConverter`1.TryWrite(Utf8JsonWriter writer, T& value, JsonSerializerOptions options, WriteStack& state)
         at System.Text.Json.Serialization.Converters.ArrayConverter`2.OnWriteResume(Utf8JsonWriter writer, TElement[] array, JsonSerializerOptions options, WriteStack& state)
         at System.Text.Json.Serialization.JsonCollectionConverter`2.OnTryWrite(Utf8JsonWriter writer, TCollection value, JsonSerializerOptions options, WriteStack& state)
         at System.Text.Json.Serialization.JsonConverter`1.TryWrite(Utf8JsonWriter writer, T& value, JsonSerializerOptions options, WriteStack& state)
         at System.Text.Json.Serialization.JsonConverter`1.WriteCore(Utf8JsonWriter writer, T& value, JsonSerializerOptions options, WriteStack& state)
         --- End of inner exception stack trace ---
         at System.Text.Json.ThrowHelper.ThrowNotSupportedException(WriteStack& state, NotSupportedException ex)
         at System.Text.Json.Serialization.JsonConverter`1.WriteCore(Utf8JsonWriter writer, T& value, JsonSerializerOptions options, WriteStack& state)
         at System.Text.Json.Serialization.Metadata.JsonTypeInfo`1.SerializeAsync(Stream utf8Json, T rootValue, CancellationToken cancellationToken, Object rootValueBoxed)
         at System.Text.Json.Serialization.Metadata.JsonTypeInfo`1.SerializeAsync(Stream utf8Json, T rootValue, CancellationToken cancellationToken, Object rootValueBoxed)
         at System.Text.Json.Serialization.Metadata.JsonTypeInfo`1.SerializeAsync(Stream utf8Json, T rootValue, CancellationToken cancellationToken, Object rootValueBoxed)
         at System.Text.Json.Serialization.Metadata.JsonTypeInfo`1.SerializeAsync(Stream utf8Json, T rootValue, CancellationToken cancellationToken, Object rootValueBoxed)
         at Microsoft.AspNetCore.Http.HttpResponseJsonExtensions.WriteAsJsonAsyncSlow[TValue](Stream body, TValue value, JsonSerializerOptions options, CancellationToken cancellationToken)
         at Duplicati.WebserverCore.Middlewares.WebsocketExtensions.<>c__DisplayClass0_0.<<UseNotifications>b__0>d.MoveNext()
      --- End of stack trace from previous location ---
         at Microsoft.AspNetCore.Diagnostics.ExceptionHandlerMiddlewareImpl.<Invoke>g__Awaited|10_0(ExceptionHandlerMiddlewareImpl middleware, HttpContext context, Task task)

Wireshark sees:

GET /api/v1/logdata/poll?level=Information&id=0&pagesize=100 HTTP/1.1
Host: localhost:8200
Connection: keep-alive
sec-ch-ua: "Chromium";v="128", "Not;A=Brand";v="24", "Microsoft Edge";v="128"
Pragma: no-cache
sec-ch-ua-mobile: ?0
Authorization: Bearer REDACTED
User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/128.0.0.0 Safari/537.36 Edg/128.0.0.0
Accept: application/json, text/plain, */*
Cache-Control: no-cache
sec-ch-ua-platform: "Windows"
Sec-Fetch-Site: same-origin
Sec-Fetch-Mode: cors
Sec-Fetch-Dest: empty
Referer: http://localhost:8200/ngax/index.html
Accept-Encoding: gzip, deflate, br, zstd
Accept-Language: en-US,en;q=0.9
Cookie: default-theme=ngax; xsrf-token=REDACTED; session-auth=REDACTED


HTTP/1.1 500 Internal Server Error
Content-Type: application/json
Date: Sat, 21 Sep 2024 14:03:33 GMT
Server: Kestrel
Cache-Control: no-cache,no-store
Expires: -1
Pragma: no-cache
Transfer-Encoding: chunked

{"Error":"An error occurred","Code":500}

At first it seemed like the error popup mattered, but I can get the problem without it sometimes.
Above was Information level, so I don’t think live log level matters. I’ve tried Retry level as well.

[Taomyn]

No idea how old the files are, I’d have to connect directly to the Wasabi S3 bucket to see.

No, I don’t use the log-option, but maybe I’ll try that out once the issue you discovered is fixed.

I have another issue to report, after trying to upgrade to this version from an earlier beta, but I’m still gathering information - for some reason it can’t open the main database because of it’s version, but every copy I’ve tried does the same nor can I open it in DB Browser (the backup job DBs are fine to open)

[Taomyn]

I tried to get Duplicati upgraded on my final Win11 machine, it was running v2.0.8.1 and worked fine the last time I used it and I was able to check the GUI was ok. I then performed the same steps as five previous Windows machines: stopped the service, uninstalled Duplicati, amended the service to use the new parameters for password and encryption, amended the tray icon shortcut, performed the upgrade with my deployment server. This seemed to go well but the service would not start.

I did notice that in Programs & Features, it was showing v2.0.7.something but I’ve seen this happen before where the upgrade didn’t update the registry and I know that the GUI was showing v2.0.8.1. When I tried to run it from the command-line I get:

A serious error occurred in Duplicati: System.Exception: Failed to create, open or upgrade the database.
Error message:
The database has version 8 but the largest supported version is 6.

This is likely caused by upgrading to a newer version and then downgrading.
If this is the case, there is likely a backup file of the previous database version in the folder C:\Users\fernando\AppData\Local\Duplicati.
   at Duplicati.Server.Program.GetDatabaseConnection(Dictionary`2 commandlineOptions)
   at Duplicati.Server.Program.RealMain(String[] _args)

I’ve gone back 3 versions of the database file, earliest was from February this year, including the one it backed up, and none of them work.

When I try to use DB Browser to access the database, it tells me that the file is not a database file, yet the other two files from backup jobs both open just fine. I’ve even checked against the equivalent database on other machines and they all open.

Any idea why Duplicati cannot access the database and what could have changed on this file prevent me even opening it? It such a mystery as even restoring the content of the Program Files folder and the Duplicati data folder leaves me with the same error, I can’t even get back to how it was before.

[Taomyn]

So I made progress in getting the database file to be recognised, both by Duplicati and DB Browser, just don’t ask me how because I don’t know. However, the service will still not start:

C:\Program Files\Duplicati 2>"C:\Program Files\Duplicati 2\Duplicati.Server.exe" /localuser --webservice-password=W<redacted>B -webservice-sslcertificatefile=C:\ProgramData\Duplicati\wiggum.mydomain.com.pfx --webservice-sslcertificatepassword=12345 --disable-db-encryption --log-file=B:\Temp\Duplicati.log --log-file-log-level=ExplicitOnly
A serious error occurred in Duplicati: System.Security.Cryptography.CryptographicException: Key not valid for use in specified state.
   at System.Security.Cryptography.X509Certificates.StorePal.Export(X509ContentType contentType, SafePasswordHandle password)
   at System.Security.Cryptography.X509Certificates.CertificatePal.Export(X509ContentType contentType, SafePasswordHandle password)
   at System.Security.Cryptography.X509Certificates.X509Certificate.Export(X509ContentType contentType, String password)
   at Duplicati.Server.Database.ServerSettings.set_ServerSSLCertificate(X509Certificate2 value)
   at Duplicati.Server.WebServerLoader.TryRunServer[TServer](IReadOnlyDictionary`2 options, Connection connection, Func`2 createServer)
   at Duplicati.Server.Program.StartWebServer(IReadOnlyDictionary`2 options, Connection connection)
   at Duplicati.Server.Program.Main(String[] _args)

It seems to upgrade the database without a problem, but then it shows the above - yes, I am running this in a command-prompt elevated as the system account.

When I check the content of the database, the Option value “server-ssl-certificate” is populated, so I tried the trick I needed once before under Linux to use “–webservice-sslcertificatepassword=” to clear it, then with it back to repopulate it. It made no difference and in fact the “–webservice-sslcertificatepassword=” didn’t clear the option when I tried it again. If I clear the value manually with DB Browser, I get past the error but I can only connect with http. Even with the “–webservice-sslcertificatepassword=” populated, Duplicati is not updating the database and it remains empty.

I have no clue how to get past this one for the moment.

Oh, and this is all I see in the log file:

2024-09-23 11:05:46 +02 - [Information-Duplicati.Server.WebServerLoader-ServerListening]: Server has started and is listening on 0.0.0.0, port 8200
2024-09-23 11:05:46 +02 - [Information-Duplicati.Server.Program-ServerStarted]: Server has started and is listening on port 8200
2024-09-23 11:07:28 +02 - [Information-Duplicati.Server.WebServerLoader-ServerListening]: Server has started and is listening on 0.0.0.0, port 8200
2024-09-23 11:07:28 +02 - [Information-Duplicati.Server.Program-ServerStarted]: Server has started and is listening on port 8200

[ts678]

Some of this needs developer input, but here are some comments to try to cover some points.

@Taomyn

No idea how old the files are, I’d have to connect directly to the Wasabi S3 bucket to see.

Maybe this refers to the below, or some similar S3 client to access bucket over network?

Using Wasabi Explorer for Windows with Wasabi

Other ways may be:

Wasabi Console Features which looks like it can sort by chosen column and even search.

Viewing the log files of a backup job, so <job> → Show log → Remote then click on list.

@Taomyn

every copy I’ve tried does the same nor can I open it in DB Browser

Copy as in Explorer copy? Neither that nor DB Browser for SQLite know Duplicati versioning. Possibly some other message came. If so, what? I’d guess the file was still open in Duplicati. Checking Task Manager for unexpected Duplicati is a way to see if something is still running.
The Performance tab can also start Resource Monitor whose CPU tab has Search Handles.

@Taomyn

after trying to upgrade to this version from an earlier beta

Did you stop the older Duplicati first? If not, I’ve seen Duplicati detect this, but I wasn’t testing upgrade from an earlier Beta. I was testing a Canary-to-Canary. At least I got all my files now.

@Taomyn

amended the service to use the new parameters for password

This is starting to seem a popular way to do it, but it records the password in many local spots, being somewhat equivalent to Linux /etc/default/duplicati which is readable by all users.

@kenkendk

By also requiring a password, this prevents local privilege escalation attacks as well.

but the idea has a big gap in it when anybody on the machine is permitted to get the password. There’s certainly a bit more work to it though, and ultimately local malware usually finds a path:

@kenkendk

Generally, a ransomware attack will escalate privileges until it has root/administrator privieleges.

so I’m still not very happy with the design and documentation on how to set up the new scheme.

@Taomyn

The database has version 8 but the largest supported version is 6.

The jump to 7 looks like 2.0.9.102 when authentication changed. It added the TokenFamily table.

@Taomyn

earliest was from February this year, including the one it backed up, and none of them work.

Same message? Same numbers? February seems like it should have been version 6. 2.0.8.1.

duplicati/duplicati/blob/78ea50c8335772f2684ff39f8e44c22d2836322b/Duplicati/Server/Database/Database schema/Schema.sql#L157

@Taomyn

When I try to use DB Browser to access the database, it tells me that the file is not a database file

Which tool can open encrypted DB

Does anyone know a tool that can open the encrypted Duplicati database file? My “standard” Browser Tool Database Browser ELT-tools.com does not support encrypted SQLite. And DB Browser for SQLite http://sqlitebrowser.org/ asks for password but does not open the database. [image] [image]

Above 2018 post shows a similar error and explains how the database was encrypted, so is not compatible with normal tools. Duplicati Server and TrayIcon on Windows could change that with

--unencrypted-database
Disables database encryption.

@Taomyn

yet the other two files from backup jobs both open just fine.

Databases for specific jobs are not encrypted. Things like credentials are in the server database.

@Taomyn

I’ve even checked against the equivalent database on other machines and they all open.

2.0.9.x Duplicati don’t use the old whole-database encryption. They may encrypt individual fields.
Since you can open these, you can check the Version table to see if DB version is newer (7 or 8).

I’m not going to get into certificates, as I don’t use them and the web server got replaced anyway.

[Taomyn]

Thanks of the tips, plenty to look at regarding the issue with the Wasabi backup, but the one for my Win11 machine is really annoying. I just can’t get any logging, from the command line I get that security error and as a service it just loops. Neither logs anything to the text file regardless of specifying the level, and I tried them all including changing the option value in the database.

Without a log I have no clue where to look for a solution, and nothing I search for comes up with any meaningful suggestions.

[ts678]

@Taomyn

from the command line I get that security error

I’ll assume this refers to sequence below:

@Taomyn

However, the service will still not start:

C:\Program Files\Duplicati 2>"C:\Program Files\Duplicati 2\Duplicati.Server.exe" /localuser --webservice-password=W<redacted>B -webservice-sslcertificatefile=C:\ProgramData\Duplicati\wiggum.mydomain.com.pfx --webservice-sslcertificatepassword=12345 --disable-db-encryption --log-file=B:\Temp\Duplicati.log --log-file-log-level=ExplicitOnly
A serious error occurred in Duplicati: System.Security.Cryptography.CryptographicException: Key not valid for use in specified state.

@Taomyn

and as a service it just loops.

How do you see a loop? As a guess, maybe Duplicati exits on the error, and Windows restarts it.
If so, you should be able to watch Server processes in Task Manager and see old and new PIDs.
This doesn’t solve the issue of the exit though, and might be wrong anyway – needs clarification.

Is this server on a secure enough network that you would be willing to test without certificate and encryption, to see if it starts? Since you probably know where your Duplicati-server.sqlite is, you could even rename it temporarily if having an “empty” Duplicati config feels more secure for tests.

@Taomyn

Neither logs anything to the text file

Possibly it’s too early in the startup sequence. There’s a chance that event viewer has some info.
Look in Windows logs → Application, e.g. for information from Source Duplicati or .NET Runtime.

[Taomyn]

This is how I knew the service was looping, even though there were no restart options enabled in the service settings. Each one is the Duplicati server being restarted, none of them logged as anything other than “information”:

Anyway, do you see anything wrong with the command I was using?

@Taomyn

C:\Program Files\Duplicati 2>"C:\Program Files\Duplicati 2\Duplicati.Server.exe" /localuser --webservice-password=W<redacted>B -webservice-sslcertificatefile=C:\ProgramData\Duplicati\wiggum.mydomain.com.pfx --webservice-sslcertificatepassword=12345 --disable-db-encryption --log-file=B:\Temp\Duplicati.log --log-file-log-level=ExplicitOnly

Un-freaking-believable!!! With all those hyphens spread across the different editors, I never noticed one was missing, and also explains why it was never updating the option in the database.

Once it was able to reprocess the .pfx file and change the value of it in the database it finally worked.

Oh, as for running it without HTTPS, that wouldn’t work until I manually cleared the certificate option in the database, before I knew why that wasn’t working. I could then connect with just http and everything was working.

All except the log to file options which simply not working, which may or may not have helped figure this out sooner.

Now I’m testing it can actualy backup and restore…