Timshel/vaultwarden

Very short session time

ArturKokoszka opened this issue ยท 11 comments

Hello, I'm using vaultwarden OIDC with Azure (Entra ID). Works like a charm, but after update from 2024.0 to 2024.5 I'm constantly logged out from both browser and plugin with message like "your session expired/timed out". It's very annoying as sometimes I have to re-login three times per day. Is there any way to increase the session time?

You probably have issues with the refresh token.

I woud check the logs to see if there is any warnings. Then you can try to log the tokens returned by your provider to check their expiration date.

There should be some mention on how to do that in the doc or past issues (not easy to write much since I'll have only my phone for the next 10days ^^).

I'm also facing the same behavior with Authentik, and need to login once a day.

I correctly receive a IdToken, followed by an AccessToken & RefreshToken, with a seemingly valid expiration date

2024-06-20T08:48:03.293723007Z [2024-06-20 08:48:03.293][vaultwarden::sso][DEBUG] Access token: eyJhbGciOiJSUzI1NiIsImtpZCI6ImU4NDJmNDBlMmM2YmU0N2NlMzY5
OGYxZmRkZWMxMWFjIiwidHlwIjoiSldUIn0.REDACTED.REDACTED
2024-06-20T08:48:03.294463268Z [2024-06-20 08:48:03.293][vaultwarden::sso][DEBUG] Refresh token: Some("REDACTED")
2024-06-20T08:48:03.298363698Z [2024-06-20 08:48:03.294][vaultwarden::sso][DEBUG] Expiration time: Some(3600s)
2024-06-20T08:48:03.336869932Z [2024-06-20 08:48:03.336][vaultwarden::sso][DEBUG] Non jwt refresh_token (expiration set to 1721465283)

Only suspicious thing I see is multiple connection to my Authentik OIDC:

2024-06-20T08:47:54.811510059Z [2024-06-20 08:47:54.811][reqwest::connect][DEBUG] starting new connection: https://go.authentik.instance.com/
2024-06-20T08:47:56.939918337Z [2024-06-20 08:47:56.934][reqwest::connect][DEBUG] starting new connection: https://go.authentik.instance.com/
2024-06-20T08:47:59.146204905Z [2024-06-20 08:47:59.144][reqwest::connect][DEBUG] starting new connection: https://go.authentik.instance.com/
2024-06-20T08:48:03.125000858Z [2024-06-20 08:48:03.124][reqwest::connect][DEBUG] starting new connection: https://go.authentik.instance.com/

And I also see 3 refresh tokens on my Authentik Dashboard being issued at that time.

Here are my logs (LOG_LEVEL=debug):

[2024-06-21 13:30:34.596][request][INFO] POST /identity/connect/token
[2024-06-21 13:30:34.597][vaultwarden::auth][ERROR] Token has expired
[2024-06-21 13:30:34.597][vaultwarden::auth][ERROR] Impossible to read refresh_token: {"ErrorModel":{"Message":"Token has expired","Object":"error"},"ExceptionMessage":null,"ExceptionStackTrace":null,"InnerExceptionMessage":null,"Message":"Token has expired","Object":"error","ValidationErrors":{"":["Token has expired"]},"error":"","error_description":""}
[2024-06-21 13:30:34.597][vaultwarden::api::identity][ERROR] {"ErrorModel":{"Message":"Impossible to read refresh_token: {\"ErrorModel\":{\"Message\":\"Token has expired\",\"Object\":\"error\"},\"ExceptionMessage\":null,\"ExceptionStackTrace\":null,\"InnerExceptionMessage\":null,\"Message\":\"Token has expired\",\"Object\":\"error\",\"ValidationErrors\":{\"\":[\"Token has expired\"]},\"error\":\"\",\"error_description\":\"\"}","Object":"error"},"ExceptionMessage":null,"ExceptionStackTrace":null,"InnerExceptionMessage":null,"Message":"Impossible to read refresh_token: {\"ErrorModel\":{\"Message\":\"Token has expired\",\"Object\":\"error\"},\"ExceptionMessage\":null,\"ExceptionStackTrace\":null,\"InnerExceptionMessage\":null,\"Message\":\"Token has expired\",\"Object\":\"error\",\"ValidationErrors\":{\"\":[\"Token has expired\"]},\"error\":\"\",\"error_description\":\"\"}","Object":"error","ValidationErrors":{"":["Impossible to read refresh_token: {\"ErrorModel\":{\"Message\":\"Token has expired\",\"Object\":\"error\"},\"ExceptionMessage\":null,\"ExceptionStackTrace\":null,\"InnerExceptionMessage\":null,\"Message\":\"Token has expired\",\"Object\":\"error\",\"ValidationErrors\":{\"\":[\"Token has expired\"]},\"error\":\"\",\"error_description\":\"\"}"]},"error":"","error_description":""}
[2024-06-21 13:30:34.597][response][INFO] (login) POST /identity/connect/token => 401 Unauthorized
[2024-06-21 13:30:34.602][request][INFO] POST /identity/connect/token
[2024-06-21 13:30:34.603][vaultwarden::auth][ERROR] Token has expired
[2024-06-21 13:30:34.603][vaultwarden::auth][ERROR] Impossible to read refresh_token: {"ErrorModel":{"Message":"Token has expired","Object":"error"},"ExceptionMessage":null,"ExceptionStackTrace":null,"InnerExceptionMessage":null,"Message":"Token has expired","Object":"error","ValidationErrors":{"":["Token has expired"]},"error":"","error_description":""}
[2024-06-21 13:30:34.603][vaultwarden::api::identity][ERROR] {"ErrorModel":{"Message":"Impossible to read refresh_token: {\"ErrorModel\":{\"Message\":\"Token has expired\",\"Object\":\"error\"},\"ExceptionMessage\":null,\"ExceptionStackTrace\":null,\"InnerExceptionMessage\":null,\"Message\":\"Token has expired\",\"Object\":\"error\",\"ValidationErrors\":{\"\":[\"Token has expired\"]},\"error\":\"\",\"error_description\":\"\"}","Object":"error"},"ExceptionMessage":null,"ExceptionStackTrace":null,"InnerExceptionMessage":null,"Message":"Impossible to read refresh_token: {\"ErrorModel\":{\"Message\":\"Token has expired\",\"Object\":\"error\"},\"ExceptionMessage\":null,\"ExceptionStackTrace\":null,\"InnerExceptionMessage\":null,\"Message\":\"Token has expired\",\"Object\":\"error\",\"ValidationErrors\":{\"\":[\"Token has expired\"]},\"error\":\"\",\"error_description\":\"\"}","Object":"error","ValidationErrors":{"":["Impossible to read refresh_token: {\"ErrorModel\":{\"Message\":\"Token has expired\",\"Object\":\"error\"},\"ExceptionMessage\":null,\"ExceptionStackTrace\":null,\"InnerExceptionMessage\":null,\"Message\":\"Token has expired\",\"Object\":\"error\",\"ValidationErrors\":{\"\":[\"Token has expired\"]},\"error\":\"\",\"error_description\":\"\"}"]},"error":"","error_description":""}
[2024-06-21 13:30:34.603][response][INFO] (login) POST /identity/connect/token => 401 Unauthorized
[2024-06-21 13:30:34.623][request][INFO] POST /identity/connect/token
[2024-06-21 13:30:34.623][vaultwarden::auth][ERROR] Token has expired
[2024-06-21 13:30:34.623][vaultwarden::auth][ERROR] Impossible to read refresh_token: {"ErrorModel":{"Message":"Token has expired","Object":"error"},"ExceptionMessage":null,"ExceptionStackTrace":null,"InnerExceptionMessage":null,"Message":"Token has expired","Object":"error","ValidationErrors":{"":["Token has expired"]},"error":"","error_description":""}
[2024-06-21 13:30:34.623][vaultwarden::api::identity][ERROR] {"ErrorModel":{"Message":"Impossible to read refresh_token: {\"ErrorModel\":{\"Message\":\"Token has expired\",\"Object\":\"error\"},\"ExceptionMessage\":null,\"ExceptionStackTrace\":null,\"InnerExceptionMessage\":null,\"Message\":\"Token has expired\",\"Object\":\"error\",\"ValidationErrors\":{\"\":[\"Token has expired\"]},\"error\":\"\",\"error_description\":\"\"}","Object":"error"},"ExceptionMessage":null,"ExceptionStackTrace":null,"InnerExceptionMessage":null,"Message":"Impossible to read refresh_token: {\"ErrorModel\":{\"Message\":\"Token has expired\",\"Object\":\"error\"},\"ExceptionMessage\":null,\"ExceptionStackTrace\":null,\"InnerExceptionMessage\":null,\"Message\":\"Token has expired\",\"Object\":\"error\",\"ValidationErrors\":{\"\":[\"Token has expired\"]},\"error\":\"\",\"error_description\":\"\"}","Object":"error","ValidationErrors":{"":["Impossible to read refresh_token: {\"ErrorModel\":{\"Message\":\"Token has expired\",\"Object\":\"error\"},\"ExceptionMessage\":null,\"ExceptionStackTrace\":null,\"InnerExceptionMessage\":null,\"Message\":\"Token has expired\",\"Object\":\"error\",\"ValidationErrors\":{\"\":[\"Token has expired\"]},\"error\":\"\",\"error_description\":\"\"}"]},"error":"","error_description":""}
[2024-06-21 13:30:34.623][response][INFO] (login) POST /identity/connect/token => 401 Unauthorized

Looks like an issue on vaultwarden-side, not idp-side.

@ArturKokoszka back to a keyboard.

The idp refresh_token is wrapped in another "refresh_token" issued by vaultwarden (those you can see in your browser debugger in response calls to /idenity/connect/token).

The failure here is that the JWT wrapper has expired when we try to read it, this expiration is either :

  • If your provider sent a JWT refresh_token then the expiration is used. (I don't believe it's the case for Entra)
  • Otherwise it uses the default of 30days.
  • If there is no refresh_token then we wrap the access token and reuse its expiration

From the description of your problem I would guess that the issue is that no refresh token was retuned.

In addition to LOG_LEVEL=debug can you run with SSO_DEBUG_TOKENS=true.

@Baspar I'm guessing you have a different problem can you open a separate issue please :).

After I added SSO_DEBUG_TOKENS=true the output is the same, but during login I see: No refresh_token present.

[2024-06-28 20:39:31.322][reqwest::connect][DEBUG] starting new connection: https://login.microsoftonline.com/
[2024-06-28 20:39:31.582][reqwest::connect][DEBUG] starting new connection: https://login.microsoftonline.com/
[2024-06-28 20:39:31.754][response][INFO] (authorize) GET /identity/connect/authorize?<data..> => 307 Temporary Redirect
[2024-06-28 20:39:36.654][request][INFO] GET /identity/connect/oidc-signin?code=0.ARAAyW6C-EcQXUy9FRfHPX8
[2024-06-28 20:39:36.657][vaultwarden::api::identity][DEBUG] Redirection to https://<truncated>
[2024-06-28 20:39:36.657][response][INFO] (oidcsignin) GET /identity/connect/oidc-signin?<code>&<state> => 307 Temporary Redirect
[2024-06-28 20:39:37.537][request][INFO] GET /sso-connector.html?code=eyJ0eXAiOiJKV1QiLCJhbGciO
[2024-06-28 20:39:37.537][response][INFO] (web_files) GET /<p..> [10] => 200 OK
[2024-06-28 20:39:43.823][vaultwarden::api::core::two_factor][DEBUG] Sending notifications for incomplete 2FA logins
[2024-06-28 20:39:43.823][vaultwarden::api::core::accounts][DEBUG] Purging auth requests
[2024-06-28 20:39:49.165][request][INFO] POST /identity/connect/token
[2024-06-28 20:39:49.204][reqwest::connect][DEBUG] starting new connection: https://login.microsoftonline.com/
[2024-06-28 20:39:49.417][reqwest::connect][DEBUG] starting new connection: https://login.microsoftonline.com/
[2024-06-28 20:39:49.664][reqwest::connect][DEBUG] starting new connection: https://login.microsoftonline.com/
[2024-06-28 20:39:49.929][reqwest::connect][DEBUG] starting new connection: https://graph.microsoft.com/
[2024-06-28 20:39:50.135][request][INFO] GET /alive
[2024-06-28 20:39:50.135][response][INFO] (alive) GET /alive => 200 OK
[2024-06-28 20:39:50.180][vaultwarden::sso][DEBUG] No refresh_token present

Did you add the offline_access scope (in the API permission and the Vaultwarden scopes) ?

Cf https://github.com/Timshel/vaultwarden/blob/sso-support/SSO.md#microsoft-entra-id

I think I'm seeing this issue, but perhaps it's different. The twist in my case is that all the session tokens seem to be lost on restart of the vaultwarden instance. In other words, each time vaultwarden is restarted, all of my clients are logged out.

[2024-06-29 21:12:21.162][vaultwarden::auth][ERROR] Error decoding JWT
[2024-06-29 21:12:21.162][vaultwarden::auth][ERROR] Impossible to read refresh_token: {"error":"","errorModel":{"message":"Error decoding JWT","object":"error"},"error_description":"","exceptionMessage":null,"exceptionStackTrace":null,"innerExceptionMessage":null,"message":"Error decoding JWT","object":"error","validationErrors":{"":["Error decoding JWT"]}}
[2024-06-29 21:12:21.162][vaultwarden::api::identity][ERROR] {"error":"","errorModel":{"message":"Impossible to read refresh_token: {\"error\":\"\",\"errorModel\":{\"message\":\"Error decoding JWT\",\"object\":\"error\"},\"error_description\":\"\",\"exceptionMessage\":null,\"exceptionStackTrace\":null,\"innerExceptionMessage\":null,\"message\":\"Error decoding JWT\",\"object\":\"error\",\"validationErrors\":{\"\":[\"Error decoding JWT\"]}}","object":"error"},"error_description":"","exceptionMessage":null,"exceptionStackTrace":null,"innerExceptionMessage":null,"message":"Impossible to read refresh_token: {\"error\":\"\",\"errorModel\":{\"message\":\"Error decoding JWT\",\"object\":\"error\"},\"error_description\":\"\",\"exceptionMessage\":null,\"exceptionStackTrace\":null,\"innerExceptionMessage\":null,\"message\":\"Error decoding JWT\",\"object\":\"error\",\"validationErrors\":{\"\":[\"Error decoding JWT\"]}}","object":"error","validationErrors":{"":["Impossible to read refresh_token: {\"error\":\"\",\"errorModel\":{\"message\":\"Error decoding JWT\",\"object\":\"error\"},\"error_description\":\"\",\"exceptionMessage\":null,\"exceptionStackTrace\":null,\"innerExceptionMessage\":null,\"message\":\"Error decoding JWT\",\"object\":\"error\",\"validationErrors\":{\"\":[\"Error decoding JWT\"]}}"]}}

@craigcabrey I'm guessing you are running in docker and not persisting the data folder which contain the key used to sign the JWT token.

If that does not fix it please open a separate issue.

Thanks, that resolved it. I had it in my head that everything auth-related was in the db.

It seems that adding offline_access scope to my config resolved the issue. Sorry for bothering you, I didn't notice the instructions in SSO.md were updated (I configured my Vaultwarden back in 2023 when the offline_access scope wasn't required). One thing to add: you can't use quotes for SSO_SCOPES variable as it interprets the qoutes as part of scope name and it gives an error upon login (tested with both ' and "). Please update docs removing quotes. Thank you for help, @Timshel and for your hard work with SSO integration for Vaultwarden.

@ArturKokoszka not sure what you are using but the quotes are valid in the .env file.
I know there are issues if written directly in docker-compose.yml file (no issue if env_file is used).