Release: 2.1.0.110 (Canary) 2025-02-28

[Taomyn]

@ts678

What’s the oldest log there? If pre-Recreate, maybe Recreate didn’t actually start.

Under the job I ran the Repair job there are currently no logs:

And I know it started and was processing because I saw the same as I am seeing now in the live log:

@ts678

You can sometimes also find useful messages in server log at About → Show log.

This is all there is

[ts678]

@Taomyn

This is all there is

Sounds pretty weird from a timing basis based on history (which sounds painful):

@Taomyn

I ask because I was running a Repair (database delete and recreate) for my Wasabi S3 storage job, and it was going to take a few days as it has done before.

But if Recreate hadn’t finished, you wouldn’t have a database to give complaints.

Probably need developer input (and live log question, asked twice, also needs it).

[Taomyn]

It completed with some warning, but it doesn’t confirm if the missing files were successfully recreated:

“Messages”: [
“2025-03-14 05:22:13 +01 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Repair has started”,
“2025-03-14 05:22:14 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started: ()”,
“2025-03-14 05:22:17 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed: (15.673 KiB)”,
“2025-03-14 05:23:50 +01 - [Information-Duplicati.Library.Main.Operation.RecreateDatabaseHandler-RebuildStarted]: Rebuild database started, downloading 13 filelists”,
“2025-03-14 05:23:50 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-20241025T105649Z.dlist.zip.aes (3.656 MiB)”,
“2025-03-14 05:23:51 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-20241025T105649Z.dlist.zip.aes (3.656 MiB)”,
“2025-03-14 05:23:51 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-20241030T053609Z.dlist.zip.aes (3.669 MiB)”,
“2025-03-14 05:23:51 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-20241030T053609Z.dlist.zip.aes (3.669 MiB)”,
“2025-03-14 05:24:58 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-20241126T022326Z.dlist.zip.aes (1.090 MiB)”,
“2025-03-14 05:24:59 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-20241126T022326Z.dlist.zip.aes (1.090 MiB)”,
“2025-03-14 05:25:17 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-20241228T021256Z.dlist.zip.aes (4.658 MiB)”,
“2025-03-14 05:25:17 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-20241228T021256Z.dlist.zip.aes (4.658 MiB)”,
“2025-03-14 05:25:24 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-20250129T020449Z.dlist.zip.aes (4.375 MiB)”,
“2025-03-14 05:25:25 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-20250129T020449Z.dlist.zip.aes (4.375 MiB)”,
“2025-03-14 05:25:57 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-20250213T020609Z.dlist.zip.aes (4.716 MiB)”,
“2025-03-14 05:25:58 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-20250213T020609Z.dlist.zip.aes (4.716 MiB)”,
“2025-03-14 05:26:21 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-20250220T020641Z.dlist.zip.aes (4.736 MiB)”,
“2025-03-14 05:26:21 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-20250220T020641Z.dlist.zip.aes (4.736 MiB)”,
“2025-03-14 05:26:47 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-20250301T020638Z.dlist.zip.aes (4.967 MiB)”,
“2025-03-14 05:26:47 +01 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-20250301T020638Z.dlist.zip.aes (4.967 MiB)”
],
“Warnings”: [
“2025-03-14 05:39:19 +01 - [Warning-Duplicati.Library.Main.Operation.RecreateDatabaseHandler-MissingFileDetected]: Remote file referenced as duplicati-bb8e36868c0ee49eb852889b5f59d617a.dblock.zip.aes by duplicati-i4fb558ccb6f648e78065300ab7012046.dindex.zip.aes, but not found in list, registering a missing remote file”,
“2025-03-14 05:58:07 +01 - [Warning-Duplicati.Library.Main.Operation.RecreateDatabaseHandler-MissingFileDetected]: Remote file referenced as duplicati-b0d7db3c279cf46c6a1bc4042bf347e0b.dblock.zip.aes by duplicati-idde25e0f759d4dc18f0b81d7ca05f5b9.dindex.zip.aes, but not found in list, registering a missing remote file”,
“2025-03-14 06:03:17 +01 - [Warning-Duplicati.Library.Main.Database.LocalRecreateDatabase-MissingVolumesDetected]: Found 2 missing volumes; attempting to replace blocks from existing volumes”,
“2025-03-15 02:09:32 +01 - [Warning-Duplicati.Library.Main.Database.LocalRecreateDatabase-MissingVolumesDetected]: Found 2 missing volumes; attempting to replace blocks from existing volumes”
],

I searched for the two files it shows as missing and they are still not on the storage - perhaps it’s created them with new names.

[Taomyn]

I decided to try running the backup against the new database, but it fails with

• 2025-03-17 13:01:53 +01 - [Error-Duplicati.Library.Main.Controller-FailedOperation]: The operation Backup has failed with error: Detected 306 file(s) in FilesetEntry without corresponding FileLookup entry DatabaseInconsistencyException: Detected 306 file(s) in FilesetEntry without corresponding FileLookup entry

Any ideas what’s going on? Couldn’t find this message in the forum, and I’ve tried to rebuild the database twice now which takes a very long time with the destination being on Wasabi S3. A repair does nothing.

I get the feeling I’m going to have to purge the entire backup off Wasabi S3 and start again.

[kenkendk]

@jberry02

Clicking on “Repair” results in the message:
“”"
The remote files are newer (3/12/2025 6:00:00 AM) than the local
database (3/12/2025 2:00:00 AM), this is likely because the
database is outdated. Consider deleting the local database and
run the repair operation again.
“”"

Thanks for reporting. There is a switch in 2.1.0.111 called --repair-ignore-outdated-database that will make the check become a warning. The underlying issue was not fixed.

@ts678

Remote file times are 4 hours ahead, likely due to UTC. Local 2:30 isn’t here yet.
I’m not sure what time zone the unit tests run in, e.g. UTC+1 might not see this…

Exactly. I am on UTC+1 so I do not see the issue, and our CI is running on UTC so no help there either.

I have made a fix for the issue you reported on this.

@ts678

I’m not certain about this (need developer help), but the Canary and Beta releases lack some of the urgent fixes that led to 2.1.0.5 Stable. Not sure if that will be fixed.

The canary builds fixed the problems that discovered in 2.1.0.4 before they were known, so there is no need to merge these fixes into the canary builds. For the beta builds I have currently set it up so anyone on experimental or beta is seeing the 2.1.0.5 release.

@ts678

First stuck tab remains inconsistent in status data:

Did you see if this state was caused by incorrect data reported to the browser or a bug in the UI code? Usually the stuck state is fixed with a reload of the page, but I have not yet figured out if the problem is that the server sends the wrong state or if the frontend is showing it wrong.

@jberry02

Maybe the issue is with displaying the new UI when remote? Or maybe only when remote and prompting for the password?

That would explain why I have not been able to reproduce it. If you log out and try to open the browser, can you look in the developer tools to see if there is some kind of error message?

@Taomyn

Will the live log come back or has it moved elsewhere?

Yes, that will be back. I have registered [an issue for it].(Support "live log" area · Issue #136 · duplicati/ngclient · GitHub)

@Taomyn

Could “today” and “yesterday” be used again for “Last successful backup”, and the “Next schedule run”?

Yes, thanks. I have also registered an issue for that.

@jberry02

Side question - with the new UI how does one get to the “live log”?

I missed that part. It will be added soon.

@jberry02

the new interface needed more clarity as to what value should be set

Thanks for reporting. I have added an issue for that.

@webipsum

In the settings, there is no Brazilian Portuguese language in the drop-down menu. Is there a plan to include it?

Yes. I need to get the whole Transifex translation store set up, so we can get translations for all the languages that are currently supported in Duplicati.

@webipsum

I have 4 backups configured. When I run a backup, the date/time does not appear automatically. I need to refresh your browser to see the date/time of the backup performed.

Thanks for reporting. I have created an issue.

@Taomyn

Do scheduled jobs override any other running non-job tasks?

Anything that is running from the WebUI is put into the runner queue and processed one at a time. So as long as the repair job is running it will prevent scheduled backups from running, but they will be queued and run as soon as the repair job is finished.

@ts678

For some reason status bar reverted to just Loading

Ok, I have created an issue for that.

@ts678

This proves that the Repair refusal doesn’t go away when local time catches UTC.

This should be fixed in 2.1.0.112.

@ts678

But if Recreate hadn’t finished, you wouldn’t have a database to give complaints.

Good point. But even a recreate should create logs in the database logs?
Since it is also not showing the backup attempt (which is logged elsewhere) I am thinking that something is preventing the display of messages from the local database.
Do you see any errors from the Developer tools? Can you look in the database in the table “Operation” or “LogData” to see if anything is there?

@Taomyn

The operation Backup has failed with error: Detected 306 file(s) in FilesetEntry without corresponding FileLookup entry DatabaseInconsistencyException: Detected 306 file(s) in FilesetEntry without corresponding FileLookup entry

I don’t recall seeing that problem before. It means that some entries are listed but there is no path to the entries, which is fairly problematic. Not sure I can debug this properly, but if you can create a bugreport database, then I can see if there is some pattern that I can find that explains it.

[Taomyn]

@kenkendk

@ts678

But if Recreate hadn’t finished, you wouldn’t have a database to give complaints.

Good point. But even a recreate should create logs in the database logs?
Since it is also not showing the backup attempt (which is logged elsewhere) I am thinking that something is preventing the display of messages from the local database.
Do you see any errors from the Developer tools? Can you look in the database in the table “Operation” or “LogData” to see if anything is there?

I will take a look and let you know

@kenkendk

@Taomyn

The operation Backup has failed with error: Detected 306 file(s) in FilesetEntry without corresponding FileLookup entry DatabaseInconsistencyException: Detected 306 file(s) in FilesetEntry without corresponding FileLookup entry

I don’t recall seeing that problem before. It means that some entries are listed but there is no path to the entries, which is fairly problematic. Not sure I can debug this properly, but if you can create a bugreport database, then I can see if there is some pattern that I can find that explains it.

Done, hopefully I can figure out how to pm you a link to the file as it’s nearly 1GB in size.

[ts678]

@kenkendk

@ts678

First stuck tab remains inconsistent in status data:

Did you see if this state was caused by incorrect data reported to the browser or a bug in the UI code? Usually the stuck state is fixed with a reload of the page,

That had further update below the quote (on the far side of the image though):

@ts678

I’ll see if refresh solves this.
It does, so not much left to do with this one. Close it to quiet things for second tab.

@kenkendk

but I have not yet figured out if the problem is that the server sends the wrong state or if the frontend is showing it wrong.

Server send was posted as was friendly display and About → System info details. Perhaps you can comment on whether server send should be displayed as seen? Server and lastPgEvent at least agree on the dblock mentioned. Phase Backup_Complete seems to match status bar. I’ll mention that on a backup that’s running a long script after, I’m used to seeing Backup complete awhile, but there’s not an equivalent script after this one. If you need another run, I can get more info.

[jberry02]

@kenkendk

@jberry02

Clicking on “Repair” results in the message:
“”"
The remote files are newer (3/12/2025 6:00:00 AM) than the local
database (3/12/2025 2:00:00 AM), this is likely because the
database is outdated. Consider deleting the local database and
run the repair operation again.
“”"

Thanks for reporting. There is a switch in 2.1.0.111 called --repair-ignore-outdated-database that will make the check become a warning. The underlying issue was not fixed.

You’re welcome.

Last night’s backup (Duplicati - 2.1.0.110_canary_2025-02-28) failed with:

Found 1 files that are missing from the remote storage, please run repair

Note that this is with the --read-write-timeout set to 5 minutes.

The suggested repair failed (as expected) with:

The remote files are newer (3/17/2025 6:00:00 AM) than the local
database (3/17/2025 2:00:00 AM), this is likely because the
database is outdated. Consider deleting the local database and
run the repair operation again.

Upgraded to Duplicati - 2.1.0.111_canary_2025-03-15, re-attempted the backup which again failed (as expected) with:

Found 1 files that are missing from the remote storage, please run repair

Repair now reports:

The remote files are newer (3/17/2025 6:00:00 AM) than the local
database (3/17/2025 2:00:00 AM), this is likely because the
database is outdated. Consider deleting the local database and
run the repair operation again. If this is expected, set the
option "--repair-ignore-outdated-database"

Set the --repair-ignore-outdated-database option as suggested, re-run repair, which now reports:

Warning: 2025-03-17 10:29:16 -04 - [Warning-Duplicati.Library.Main.Operation.Re\
pairHandler-RemoteFilesNewerThanLocalDatabase]
: The remote files are newer (3/17/2025 6:00:00 AM) than the
local database (3/17/2025 2:00:00 AM), this is likely because
the database is outdated. Continuing as the options force
ignoring this.

Running the backup is now working.

EDIT 1 - backup completed without any reported errors.

[jberry02]

@kenkendk

@jberry02

Maybe the issue is with displaying the new UI when remote? Or maybe only when remote and prompting for the password?

That would explain why I have not been able to reproduce it. If you log out and try to open the browser, can you look in the developer tools to see if there is some kind of error message?

I will try to do this test later today. I did check the browser console to see if there was anything of note there while I was getting the blank screen, and I’m not sure if what it was showing was relevant as I have many browser windows and tabs open. I plan to try from a system I don’t normally use so that any console info will be known to be relevant.

[webipsum]

@kenkendk

Congratulations on your excellent Duplicati application.

1. Is there any plan to make the icons white for better viewing or

2. Where can I find the icons in the application folders to adapt them by changing the colors to white? Is this possible? Are they PNG files or is it a compiled file?

In my case, I would only need to adjust the Duplicati icon that is in the macOS Menu Bar. The submenu (Open, Pause and Quit) is visible and would not need to be changed.

Thank you very much for your continued attention!

[ts678]

@Taomyn

It makes it very quick to see at a glance if backups have not run when they should have or about to

But does the “today” turn into “yesterday” when the next day comes?
I had to check a 2.0.8.1 log today, as I wasn’t sure “Today” was right.

FWIW there’s a documented option for this, but I’m not sure it works:

  --force-actual-date (Boolean): Force the display of the actual date instead of calendar date
    By default, dates are displayed in the calendar format, meaning "Today" or "Last Thursday". By setting this
    option, only the actual dates are displayed, "Nov 12, 2018, 8:01 AM" for example.
    * default value: false

[jberry02]

@ts678

FWIW there’s a documented option for this, but I’m not sure it works:

  --force-actual-date (Boolean): Force the display of the actual date instead of calendar date
    By default, dates are displayed in the calendar format, meaning "Today" or "Last Thursday". By setting this
    option, only the actual dates are displayed, "Nov 12, 2018, 8:01 AM" for example.
    * default value: false

I use --force-actual-date on all my backups specifically to avoid the yesterday/today ambiguity. Works great.

[Taomyn]

I would never expect to see “today”, “yesterday” or anything similar like “last week” to appear in actual logs, only on the GUI where it’s giving a dynamic current job status. In the actual logs it should always be the exact date in full, otherwise they’re useless, but if that’s the case then they need to be fixed in my opinion.

[ts678]

@jberry02

I use --force-actual-date on all my backups specifically to avoid the yesterday/today ambiguity. Works great.

Where in the many outputs of Duplicati is a change visible? I have it on in 2.0.8.1

System was left up overnight with Duplicati tab open, to prevent browser sleep:

The Today is actually leftover from yesterday. It’s not yet 2:40 today, so it’s not completely ambiguous if one knows the time. In another day of this, it would be.

[jberry02]

@ts678

@jberry02

I use --force-actual-date on all my backups specifically to avoid the yesterday/today ambiguity. Works great.

Where in the many outputs of Duplicati is a change visible? I have it on in 2.0.8.1

I’ve been using the global setting --force-actual-date since at least Duplicati - 2.0.7.103_canary_2024-04-19. In my case it shows the actual date of the backup in the web UI as intended [ex.]:

Last successful backup:
    Mar 18, 2025 2:18 AM (took 00:00:58)
    Run now 
Next scheduled run:
    Mar 19, 2025 2:05 AM
Source:
    49.78 GB
Backup:
    48.44 GB / 16 Versions

[jberry02]

@jberry02

@kenkendk

@jberry02

Maybe the issue is with displaying the new UI when remote? Or maybe only when remote and prompting for the password?

That would explain why I have not been able to reproduce it. If you log out and try to open the browser, can you look in the developer tools to see if there is some kind of error message?

I will try to do this test later today. I did check the browser console to see if there was anything of note there while I was getting the blank screen, and I’m not sure if what it was showing was relevant as I have many browser windows and tabs open. I plan to try from a system I don’t normally use so that any console info will be known to be relevant.

I have not yet had a chance to do the requested test. However, I note that since upgrading to .111, instead of a blank screen it now shows “Loading …”

[ts678]

@jberry02

I’ve been using the global setting --force-actual-date

That seems to work in 2.0.8.1. When done in job, it doesn’t.
This seems a bit atypical, but maybe home page is special?

Thanks for saying what works.

[jberry02]

@jberry02

@jberry02

@kenkendk

That would explain why I have not been able to reproduce it. If you log out and try to open the browser, can you look in the developer tools to see if there is some kind of error message?

I will try to do this test later today. I did check the browser console to see if there was anything of note there while I was getting the blank screen, and I’m not sure if what it was showing was relevant as I have many browser windows and tabs open. I plan to try from a system I don’t normally use so that any console info will be known to be relevant.

I have not yet had a chance to do the requested test. However, I note that since upgrading to .111, instead of a blank screen it now shows “Loading …”

We have an error!

Uncaught TypeError: crypto.randomUUID is not a function
    <anonymous> http://deleted:8200/ngclient/main-GMFQCDBZ.js:1
main-GMFQCDBZ.js:1:4956

Note that the browser is Firefox running on a Fedora Linux system, and Duplicati is running on a Windows 10 system. I am not logged in to Duplicati from this system.

[ts678]

@kenkendk

I have not yet figured out if the problem is that the server sends the wrong state or if the frontend is showing it wrong.

I commented on that earlier (based on prior posted evidence), but now have more.

After an easy repro (except for less odd status bar) of the stuck GUI, I’m trimming back. Original case was two tabs with three scheduled jobs on different schedules, with a collision at top of hour. Case hanging overnight was one tab on Server not TrayIcon because TrayIcon adds more noise to Wireshark view. Two tabs leads to mixing up tab requests and possibly adding out-of-order responses from request timings, due to HTTP 1.1 and a socket pool that’s used. I also removed the job schedule conflict, running two jobs at 10 minute schedule, with a 5 minute stagger between jobs, and no actual new version. Previously I had used upload-unchanged-backups. Results:

All the Today are actually Yesterday now, but that discussion was done above.

I got a better handle on watching WebSocket work. Edge devtools has last as:

{"ActiveTask":null,"ProgramState":"Running","SchedulerQueueIds":[],"ProposedSchedule":[{"Item1":"1","Item2":"2025-03-19T02:20:00Z"},{"Item1":"2","Item2":"2025-03-19T02:25:00Z"}],"HasWarning":false,"HasError":false,"SuggestedStatusIcon":"Ready","EstimatedPauseEnd":"0001-01-01T00:00:00","LastEventID":430,"LastDataUpdateID":96,"LastNotificationUpdateID":0,"UpdatedVersion":"2.1.0.111","UpdaterState":"Waiting","UpdateDownloadLink":"https://updates.duplicati.com/canary/duplicati-2.1.0.111_canary_2025-03-15-win-x64-gui.zip","UpdateDownloadProgress":0.0}

which seems to match GUI main screen display. I’m not sure where they’re from. Above final WS update was at 10:19:59 PM, which is a second before schedule. Local time is (due to DST) 4 hours behind UTC. Final non-WS action looked like:

Final WS message as seen in Wireshark was:

{"ActiveTask":null,"ProgramState":"Running","SchedulerQueueIds":[],"ProposedSchedule":[{"Item1":"1","Item2":"2025-03-19T02:20:00Z"},{"Item1":"2","Item2":"2025-03-19T02:25:00Z"}],"HasWarning":false,"HasError":false,"SuggestedStatusIcon":"Ready","EstimatedPauseEnd":"0001-01-01T00:00:00","LastEventID":430,"LastDataUpdateID":96,"LastNotificationUpdateID":0,"UpdatedVersion":"2.1.0.111","UpdaterState":"Waiting","UpdateDownloadLink":"https://updates.duplicati.com/canary/duplicati-2.1.0.111_canary_2025-03-15-win-x64-gui.zip","UpdateDownloadProgress":0.0}

Arrival Time: Mar 18, 2025 22:19:59.999199000 Eastern Daylight Time

Was that supposed to get GUI to update display? If so, it doesn’t seem to have. Wireshark agrees with dev tools about lack of queries to server for information.

Both jobs databases are updating. The latest has last Operation table backup at

March 19, 2025 8:20:01 AM GMT-04:00 DST

Although I’m almost certain that tab refresh would fix hang, I duplicated it and got

EDIT 1:

@ts678

After an easy repro (except for less odd status bar) of the stuck GUI

Repro with added stuck in Backup complete status bar is pretty easy too.
I’m actually in 2.1.0.111 now, as I’m leaving 2.1.0.110 stuck for debugging.

Rather than a scheduled job (which at least at GUI won’t do fast schedule,
I supplemented a 6 minute schedule with manual runs. After about 20, got:

From a log file, the backups have been running, with last run done at 6:35.
Web UI is getting progressstate every 2 seconds. I’m not watching WS.

[kenkendk]

@ts678

activeTask : {"Item1":37,"Item2":"1"}

This is the part that is “stuck”. Since no task is running, this is supposed to be null.
What I recall is that a refresh of the page will reset this value, indicating that the problem is somewhere around updating this value.

The value will be pushed over a websocket when it changes, but I can see that the task list and the poll are not guarded by the same lock, so it is possible that this is a race where the task data is not updated when the notification is sent, but is then changed shortly after the data is sent.

This would cause no new messages to be sent, but the state seen by the FE is incorrect. Fixing it is a bigger problem because this is written in a way that is not really compatible with the ASP.NET way of working. A rewrite of the queue, runner, API and general notification system is needed.

Short term fix is probably to request fresh data periodically, to avoid these long periods of stale data.