Release: 2.0.9.102 (Canary) 2024-08-02

Have you tried the startup option workaround above to what sounds like the same issue?
Note that the option name inadvertently lost a dash compared to what worked previously.

I don’t use Docker, but the LSIO version has CLI_ARGS to give options to Duplicati server.

I’m trying (with the official docker client, not the one from LSIO), but exposing this via environment variables does not seem to work.

Tried:

    environment:
      - TZ=Europe/Brussels
      - DUPLICATI__WEBSERVICE_ALLOWEDHOSTNAMES=duplicati;duplicati.XXXX.duckdns.org;192.168.0.xxx:8200
      - DUPLICATI__WEBSERVICE_ALLOWED_HOSTNAMES=duplicati;duplicati.XXX.duckdns.org;192.168.0.xxx:8200

Also tried:

    environment:
      - TZ=Europe/Brussels
      - DUPLICATI__WEBSERVICE_ALLOWEDHOSTNAMES=*
      - DUPLICATI__WEBSERVICE_ALLOWED_HOSTNAMES=*

Whatever I do - as soon as I approach duplicati via another way (not localhost or 127.0.0.1), I get the HTTP Error 400. The request hostname is invalid.

I might be using the wrong environment variables - but I could not find documentation around this.

With 2.0.9.102 the Web UI is using a WebSocket to get updates so you cannot see the request directly. The TrayIcon has not been updated to use a WebSocket for the requests.

That is expected. The idea with WebSocket is that it can have a very low overhead when nothing happens, but as soon as something changes it is “instantly” update. I use the pause/resume buttons to trigger a message when testing things.

It originates from DateTime.FromTicks(0) as the ticks are counting from that date.

I found the problem here. The issue is that the previous logic was a bit dirty.
When a request fails with an auth error, a dialog is shown with a message like “Not logged in”.
Clicking “OK” on this takes you to the login page.

The “Connection lost” dialog is implemented in a layer above the normal dialogs so it covers the “Not logged in” dialog.
The previous code was cheating a bit and marking the connection state as connected if an auth error happened and then relied on the dialog being shown.

With the WebSocket error handler, the “Connection lost” dialog is repurposed to show a new message if the connection state is unauthorized. This dialog is then covering the dialog that would lead to the login page. Additionally, in this case the timer was not cleared causing a reconnect to happen each second which makes the browser flicker when showing the dialogs.

A fix is ready and will be included in a new canary build.

Good thing that the browser blocks it! I have registed an issue for this.

Sadly, it is still a manual process to add these warnings. If you roll back the version in the database, make sure to drop the table TokenFamily or it will fail on next upgrade.

The environment variables are not used for this option. It is possible in the next canary build.
The names are the same as the commandline options, so something like this should work in the next canary:

environment:
  - webservice-allowed-hostnames=*

If you set the hostname to cli then the TrayIcon needs to call the server using that name as well. By default it will call localhost:8200 but it needs to call cli:8200.

This is not something that is well supported with the TrayIcon having a hosted server as it is expected to use localhost. You can set it up by adding a host entry for cli = 127.0.0.1 and then starting the server with:

> Duplicati.Server.exe --webservice-allowedhostnames=cli

And then the TrayIcon with:

> Duplicati.GUI.TrayIcon.exe --no-hosted-server --hosturl=http://cli:8200

I agree, it does not at all look related to the TrayIcon.
You can enable extended tracing for Avalonia which is used to host the TrayIcon with the environment variable (Linux syntax):

> DEBUG_AVALONIA=2 duplicati

I think the right way to report that is via the issues. I would say that .NET is looking at the available memory and will not free memory if it sees that there is plenty free memory. The more memory pressure the system has, the more aggressively it will free memory. This can lead to large memory allocations being reported by system tools that do not look at the .NET allocation details.

Thanks - I will revert to previous canary until the next one comes out of the oven.

I just noticed that environment variables cannot have dashes on all systems.
I will change it to use _ instead of -.

The previous long poll scheme has this too, and I find debates over pros and cons.

So I suppose at the moment it’s partly on the long poll and partly on the web socket.

There are update issues in the GUI regardless, e.g. schedules, live log, system info.

estimatedPauseEnd : 0001-01-01T00:00:00 is explained by that. That’s the old one.
estimatedPauseEnd : "0001-01-01T04:56:02.000Z" (new one) is near but different.

I don’t know how much I care, but I thought the odd value here might find some problem.
However it’s computed, it’s consistent across pause/resume, Duplicati restart, and so on.

If you mean as in what hostname command could show or set, I’m not doing such a thing.
This isn’t even Linux, and the line I’m using is right there, trying to set allowed hostnames.

If you mean allowed hostnames, I might be under-assuming the implications of the setting.
If it means that Duplicati will be using it internally (so it better work), I don’t think I had that.
If it means Duplicati will use localhost, I wasn’t messing with that, just trying to be allowed.

Basically, I’m thinking the response was entirely off target, but it’s certainly a messy area.
I still haven’t seen the meaningful rejection message that the old host header check gave.

For Docker, it looked like the Duplicati image doesn’t have anything like LSIO CLI_ARGS.
I was a bit surprised that there’s not more clamor for a general way to pass CLI options in.
Upcoming environment variable support might solve specific cases that need to be solved.

EDIT 1:

I also wondered if Docker could use an /etc/default/duplicati DAEMON_OPTS workaround.
It didn’t look likely, and now I’m wondering how well supported that is without its start script.

EDIT 2:

To clarify, it looks like the variable is in systemd unit file, but smaller systems avoid systemd.
I was worried if the /usr/bin scripts used /etc/default/duplicati, but it looks like they never did.

I am trying to recreate this. Do you mean the initial list of backups on the main page is slow in loading?

Also where is the schedule information missing from?

Can you help me find the location where you are looking for the information that is missing?

I can see some old stuff in the code called ProposedSchedule but it appears it was not used in 2.0.8.1 either.

I’m not the person you’re asking, but I see a delay too on initial list of backups.

For me, status bar is the most obvious location, but About → System info too.

Here’s 2.0.8.1 after adding a schedule of test job for1 PM EDT, so 1700 UTC:

EDIT:

I forgot about the home screen job information. 2.0.8.1 has it there too, showing:

image

With same setup, 2.0.9.102:says “No scheduled tasks” on status bar, job summary has nothing:

image

About → System info has

image

and yet it runs, or at least my daily production backup runs, but there’s no sign of those in GUI.

Job edit does show them. I mean schedule in terms of what’s to come.

For now the websocket is only affecting the long-poll, which is used for “server state”. This is triggered when the configuration is changed or the pause/resume state is activated, when a notification is issues and a few other places.

There are other places, such as live log, system info, progress, etc that is still using a poll-like feature, but this is not long-poll, it is just periodic poll each second or so.

It would be nice if these were also part of the websocket data, but I would really like to update the Angular codebase before diving into this.

Hmm… that one is pretty odd. Could it be some timezone issue if you are +/- 5h from UTC, and then some additional weird extra value?

The regular Docker image does not use/support options like that. We could add it fairly easily.

You can override the entire executable command, including args, so it is not really needed. But, yes, the new environment variables are a bit hacky in the sense that only some are supported as env variables, and it is not immediately clear which are supported and why others are not.

Can you see from “Developer Tools” in the browser where the delay is from? Is there a request that takes several seconds? Is there a request that happens and then the contents appear?

Arh, I was not looking there. Should be easy to replicate then.

That theory would be easy for somebody in a different time zone to test. I’m UTC-4 (UTC-5 and daylight saving time). The value is same on a different OS with a fresh update to 2.0.9.102, still estimatedPauseEnd : “0001-01-01T04:56:02.000Z”. Maybe no big deal, but what do others get?

This would be easier if the Log out button actually showed up. I’ve seen it a little, but not usually.

image

I’ll see what I can do. My first try of just going through login.html was fairly fast, but my delay is seemingly less normally than the other report. I only have two jobs, but I think I’ve seen slower.

2.0.8.1 is basically instant though.

I’m UTC+2 at the moment, and I get:

estimatedPauseEnd : "0000-12-31T23:06:32.000Z"

That confirms the theory, I will keep digging.

You can delete the RefreshToken_8200 cookie, which will force a re-login.
But does the delay only happen on a fresh login? Is it instant when you reload the page?

It is “instant” for me (i.e., less than 1s at least).

I got a few seconds of delay on a reload (normal not hard), but delay is variable. Slow one did:

image

That was a backups request (guessing this is the one). You can see my scheduled job in reply:

        "Schedule": {
            "ID": 2,
            "Tags": [
                "ID=3"
            ],
            "Time": "2024-08-14T17:00:00Z",
            "Repeat": "1D",
            "LastRun": "0001-01-01T05:00:00Z",
            "Rule": "AllowedWeekDays=Monday,Tuesday,Wednesday,Thursday,Friday,Saturday,Sunday",
            "AllowedDays": [
                "Monday",
                "Tuesday",
                "Wednesday",
                "Thursday",
                "Friday",
                "Saturday",
                "Sunday"
            ]
        }

I’ll poke some more.

It seems to do nothing. Checked again later in Edge to see it’s gone. HTTP is:

image

It is some JS weirdness around zero values.
I think moving to UNIX EPOCH would fix a lot.

Note the odd timezone offset of 53 minutes.

> new Date("0001-01-01T00:00:00")
"Mon Jan 01 0001 00:00:00 GMT+0053 (Central European Standard Time)"

So that one starts after 3.87s, pretty slow.
I think this happens because the websocket is set up, and then after getting a response, it will request the backup list. It would be smarter to just request the list in the setup, or send it automatically so there is only one round-trip.

But still… nearly 4s is quite a long time to load.

You still have an active in-memory token, so you need to reload the page, and then you will not get access. The access token expires after some time as well.

Not locking with normal refresh done before, and now still have access after doing hard refresh.

EDIT 1:

I checked to see if token came back during the delay. It had, so I deleted then got same no-lock.

EDIT 2:

I’m not that good at reading the timing info in developer tools, but the now-deleted interaction just before the backups request was a WS notifications response that said Queued at 1.88 or so, even though it also talked about min later on in the timing, so I don’t know when it actually began.

The perceived delay after the password processing had finished seemed to be about 2 seconds, basically looking at a too-blank screen waiting for the jobs to show up. Not a huge deal though…

EDIT 4:

Mentioned earlier, but while it’s granting me free access, it’s also got a steady flow on terminal of

fail: Microsoft.AspNetCore.Diagnostics.ExceptionHandlerMiddleware[1]
      An unhandled exception has occurred while executing the request.
      Duplicati.WebserverCore.Exceptions.UnauthorizedException: Authorization failed due to missing cookie.
         at Duplicati.WebserverCore.Endpoints.V1.Auth.<>c.<<Map>b__3_0>d.MoveNext()
      --- End of stack trace from previous location ---
         at Microsoft.AspNetCore.Http.RequestDelegateFactory.<TaskOfTToValueTaskOfObject>g__ExecuteAwaited|92_0[T](Task`1 task)
         at Duplicati.WebserverCore.Middlewares.LanguageFilter.InvokeAsync(EndpointFilterInvocationContext context, EndpointFilterDelegate next)
         at Microsoft.AspNetCore.Http.RequestDelegateFactory.<ExecuteValueTaskOfObject>g__ExecuteAwaited|129_0(ValueTask`1 valueTask, HttpContext httpContext, JsonTypeInfo`1 jsonTypeInfo)
         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)

EDIT 5:

I should note that I’m just testing the new plan of requiring a password, but it’s not user-friendly. Beyond the need to login and the inability to log out, any rule for timed auto-logouts is not clear.

Not sure what you mean with “granting fee access”. If you do not have a refresh token (cookie) you cannot get a new access token. Any request without an access token will be rejected with 401.

Can you see for one of the requests that got through if it happens to have a header for Authorization: Bearer .... ?
This is the access token that grants actual access.

I think it is being stored somewhere. You can check the call to /api/v1/auth/refresh.
The request needs a Cookie: header which is the refresh token. The response has the access token in the body, and a new refresh token in the Set-Cookie header.

If you can somehow get either a refresh token or an access token without a valid refresh token cookie, something is seriously wrong. I have not been able to replicate this.

I think adding security is often a tradeoff with convenience. But we can always strive to make it better.

The auto-logout should essentially never happen. The idea is that you get the refresh token, which has a long validity period. If the access token expires, the WebUI will detect this and automatically fix it and retry the request. It should be adding a delay less than a second once every hour or so.

The “log out” feature has never been present in the UI but it does exist in the API. I will add it a button to log out.

Just what it says. You’re right in the GUI, without a password and without refresh cookie.

gave an image of the two cookies that went in. I just found the cause of the message flow.
There was a Linux VM doing accesses to the Windows 10 Duplicati, popping up boxes of

Connection lost

Connection to server was rejected due to invalid authentication. Reload browser window to reconnect to server properly.

If this problem persist open this page from the TrayIcon instead.

TrayIcon isn’t there, as this is remote access, reload gives a 15 second break in messages.
Using the login.html workaround allowed a login. I think this has been discussed previously.

Lots has changed with the overnight break and the fiddling above, but I’ll see what I can do.

Then why is it in the 2.0.8.1 UI?

image

It’s not there unless I password-protect, and I didn’t used to, per directions and preference.
I turn it off in Settings, Save, refresh to no avail, finally Log out, and now the left bar shows:

image

Searching for strings is easier in Wireshark. I can also put together a stream in sequence.
The Wireshark capture is port 8200 on all interfaces, but the dialog below is on 127.0.0.1:

GET /ngax/styles/%7B%7Bactive_theme%7D%7D.css HTTP/1.1
Cookie: current-theme=dark; default-theme=ngax

HTTP/1.1 404 Not Found

POST /api/v1/auth/refresh HTTP/1.1
Cookie: RefreshToken_8200=REDACTED; default-theme=ngax

Where did RefreshToken come from? Why did current-theme go away?

HTTP/1.1 200 OK
Set-Cookie: RefreshToken_8200=REDACTED; expires=Fri, 13 Sep 2024 13:43:37 GMT; domain=localhost; path=/api/v1/auth/refresh; samesite=strict; httponly
Transfer-Encoding: chunked

12b
{"AccessToken":"REDACTED"}
0

Refresh token start is very similar to prior one, then last 43 characters after a dot differ.

GET /api/v1/systeminfo HTTP/1.1
Authorization: Bearer REDACTED
Cookie: default-theme=ngax

Seems to replicate pretty well here. I thought maybe a different browser tab was interfering, but I closed the excess Edge ones. Below are the before and after netstat. TrayIcon seems to do lots:

C:\>netstat -ano | findstr 8200
  TCP    0.0.0.0:8200           0.0.0.0:0              LISTENING       20820
  TCP    127.0.0.1:8200         127.0.0.1:58384        ESTABLISHED     20820
  TCP    127.0.0.1:8200         127.0.0.1:58386        ESTABLISHED     20820
  TCP    127.0.0.1:8200         127.0.0.1:59825        ESTABLISHED     20820
  TCP    127.0.0.1:8200         127.0.0.1:60027        ESTABLISHED     20820
  TCP    127.0.0.1:58384        127.0.0.1:8200         ESTABLISHED     15076
  TCP    127.0.0.1:58386        127.0.0.1:8200         ESTABLISHED     15076
  TCP    127.0.0.1:59825        127.0.0.1:8200         ESTABLISHED     15076
  TCP    127.0.0.1:59836        127.0.0.1:8200         TIME_WAIT       0
  TCP    127.0.0.1:60027        127.0.0.1:8200         ESTABLISHED     20820
  TCP    192.168.86.81:8200     192.168.86.104:58290   ESTABLISHED     20820
  TCP    192.168.86.81:8200     192.168.86.104:60400   ESTABLISHED     20820

C:\>netstat -ano | findstr 8200
  TCP    0.0.0.0:8200           0.0.0.0:0              LISTENING       20820
  TCP    127.0.0.1:8200         127.0.0.1:59825        ESTABLISHED     20820
  TCP    127.0.0.1:8200         127.0.0.1:60027        ESTABLISHED     20820
  TCP    127.0.0.1:59825        127.0.0.1:8200         ESTABLISHED     15076
  TCP    127.0.0.1:60027        127.0.0.1:8200         ESTABLISHED     20820
  TCP    192.168.86.81:8200     192.168.86.104:58290   ESTABLISHED     20820
  TCP    192.168.86.81:8200     192.168.86.104:60400   ESTABLISHED     20820

I think it’s usually in some of mess when I wake PC in the morning, but I forget which one exactly. There are enough strange behaviors around that it might be another one. Good to know intention.

I don’t see a replication? Your trace shows that your requests correctly submit a valid refresh token?

If you launch the page from the TrayIcon, another flow is created to avoid the need for a password.
Since the TrayIcon hosts the server, the TrayIcon is a trusted source and I assume it would be difficult for a malicious page to interact with the TrayIcon.

Because the TrayIcon hosts the server, it makes the server issue a special sign-in token.
This token has a very short lifetime (seconds) and can be used to obtain a refresh token instead of using the password. It is passed through the /signin.html page, which should show in traces.

The net effect is that if you click “Open” on the TrayIcon, you are logged in automatically without needing a password. This behavior is intended to be secure and reduce user friction, but can be disabled in settings (from the UI).

The TrayIcon also authenticates with the server via the same mechanisms as the UI flow, so it cannot access any API endpoint without a valid token either.

Yes, I found it! Previously, it was only present if a password login was used, which my testing setup did not have.

It was also broken in the update, because the auth-flow has changed.
I have updated the code to support the button now.

I assume you mean that the UI “loads” in that you can see the logo, menu, etc?
This is served as plain unauthenticated html/js/css files, and contains no sensitive information.
This does not mean you are logged in, it is just the static parts of the UI that are showing.

For this and other issues, I think we should add a loader on the landing page, so it is clear that the connection is not established.

I have updated the message to make it more clear what happens and what to do. 15 seconds seems like a long time to detect the failed login? Is there an heavy latency on the link?

Just an FYI: I decided to revisit this part, so the you can set everything via environment variables. I opted for the slightly longer names, so it would be:

environment:
  - DUPLICATI__WEBSERVICE_ALLOWED_HOSTNAMES=*

Partial replication of

and full refutation of

as explained earlier

It was an existing tab, with the cookie delete and a regular or a hard refresh, per dialog

OTOH if you mean “launch the page” days ago, that is possible, and I don’t know how to tell.
My assumption regardless had been that an existing tab talks to the server. Is that incorrect?

If you’re talking about the blue popup in the center of the screen, I don’t think I saw that, as I refreshed the page. I’ve also seen the signin.html page before, and I don’t think refresh did it.

I’m also not seeing it in dev tools requests (which I kept, and can keep until Windows reboot).

OK, I think the chances are getting high that this is off-target, but it’s still useful reference info.

No. The static parts do come in first, then it somehow authenticates and sends sensitive info

Probably about 0 latency on localhost. The 15 seconds after refresh is the on-screen counter. Seemingly it’s active, and then it swings into the per-second version of “Connection lost” box.

This is actually where my (now two) OK-when-going-to-sleep-overnight tabs are this morning.

image

On refresh, I think it might have flashed one fast blue popup, then the 15 second countdown:

image