search

roundcube / roundcubemail

The Roundcube Webmail suite
https://roundcube.net
GNU General Public License v3.0
5.63k stars 1.61k forks source link

OAuth login requires multiple tries - expired token #9364

Open kaylee-98 opened 4 months ago

kaylee-98 commented 4 months ago

Hey,

I'm using Roundcube with Authentik and I've set it up as shown here. It does seem to work, but generally logging in will require multiple tries - as in it will fail the first 1-2 times and then work the next.

From the log, 

[21-Feb-2024 04:26:51 +0000]: <hgqchfuc> PHP Error: OAuth token request failed: Client error: `POST https://auth.[domain.com]/application/o/token/` resulted in a `400 Bad Request` response:
{"error": "invalid_grant", "error_description": "The provided authorization grant or refresh token is invalid, expired,  (truncated...)
; shezmu GuzzleHttp/7 - [21/Feb/2024:04:26:51 +0000] "POST /application/o/token/ HTTP/1.1" 400 232 in /var/www/mail/program/include/rcmail_oauth.php on line 321 (GET /index.php/login/oauth?code=99a4b96e08bd42ac8d520a5815022bcf&state=lhGihS3ZhXZW)

This seem to be an issue of Roundcube trying an expired token. I don't know if this is a bug in roundcube or with Authentik, or if something is configured incorrectly, but every other app on my SSO works first time every time. I think this might be similar to #8388, but my tokens don't have the expires_in property.

Thanks for reading :)

alecpl commented 2 months ago

I can only suggest to check the git-master version which got many improvements in this area. There's also a oauth_debug option which could help.

ThomasJ1989 commented 2 months ago

Same to me!!!

chrichrichri commented 1 month ago

It seems I am facing a related issue using Authelia as oauth provider. Login perfectly works fine (also on first try), but after token timeout the authentication fails. Roundcube somehow seems to not request a new token when the old one expires. I am using version 1.6.7 of roundcube. Whenever trying to run the version from master-branch it fails to start with this error: Uncaught Error: Class "GuzzleHttp\Client" not found in etc/roundcube/program/lib/Roundcube/rcube.php:277

Any hints what to do to fix the issue? If any more logs would help, please let me know.

Lifespan of access_token is set to 5min for the example below.

Roundcube oauth-Config:

$config['oauth_provider'] = 'generic';
$config['oauth_provider_name'] = 'Authelia OIDC';
$config['oauth_client_id'] = 'roundcube';
$config['oauth_client_secret'] = <secret>;
$config['oauth_auth_uri'] = 'https://auth.example.com/api/oidc/authorization';
$config['oauth_token_uri'] = 'https://auth.example.com/api/oidc/token';
$config['oauth_identity_uri'] = 'https://auth.example.com/api/oidc/userinfo';
$config['oauth_identity_fields'] = ['email'];
$config['oauth_scope'] = 'email openid profile';
$config['oauth_login_redirect'] = true;

Roundcube Log:

Jun 02 15:09:46 nixos roundcube[1496359]: <hnfg8uki> Session regenerate: k57q95dq0rqlp0emv44ffe36a7 -> hnfg8ukiqqfno869kgjl9iac7e
Jun 02 15:09:46 nixos roundcube[1496359]: <hnfg8uki> Successful login for  mail@example.com (ID: 1) from 37.24.55.210 in session hnfg8ukiqqfno869
Jun 02 15:10:46 nixos roundcube[1500114]: <hnfg8uki> Session auth check failed for hnfg8ukiqqfno869kgjl9iac7e; timeslot = 2024-06-02 13:10:00
Jun 02 15:10:46 nixos roundcube[1500114]: <hnfg8uki> Send new auth cookie for hnfg8ukiqqfno869kgjl9iac7e: IRyHfW8o6VVKVhlk6o3eOL8VJt-1717333500
Jun 02 15:14:46 nixos roundcube[1500114]: <hnfg8uki> IMAP Error: Login failed for mail@example.com against localhost from <ip-address>. AUTHENTICATE XOAUTH2: A0001 NO [AUTHENTICATIONFAILED] Authentication failed. in /nix/store/xdb0d7mz9hsh4dy4rycdmwczf7l0af4d-roundcube-1.6.7/program/lib/Roundcube/rcube_imap.php on line 211 (POST /?_task=mail&_action=refresh)
Jun 02 15:15:44 nixos roundcube[1496358]: <hnfg8uki> Session auth check failed for hnfg8ukiqqfno869kgjl9iac7e; timeslot = 2024-06-02 13:15:00
Jun 02 15:15:44 nixos roundcube[1496358]: <hnfg8uki> Send new auth cookie for hnfg8ukiqqfno869kgjl9iac7e: IRyHfW8o6VVKVhlk6o3eOL8VJt-1717333800
Jun 02 15:15:46 nixos roundcube[1496358]: <hnfg8uki> IMAP Error: Login failed for mail@example.com against localhost from <ip-address>. AUTHENTICATE XOAUTH2: A0001 NO [AUTHENTICATIONFAILED] Authentication failed. in /nix/store/xdb0d7mz9hsh4dy4rycdmwczf7l0af4d-roundcube-1.6.7/program/lib/Roundcube/rcube_imap.php on line 211 (POST /?_task=mail&_action=refresh)

Authelia log:

time="2024-06-02T15:09:46+02:00" level=debug msg="UserInfo Request with id '7b158d0d-c82d-45d2-ba0c-695b4960de65' is being processed" method=GET path=/api/oidc/userinfo remote_ip="***"
time="2024-06-02T15:09:46+02:00" level=debug msg="UserInfo Request with id '7b158d0d-c82d-45d2-ba0c-695b4960de65' on client with id 'roundcube' is being returned unsigned as per the registered client configuration" method=GET path=/api/oidc/userinfo remote_ip="***"
time="2024-06-02T15:09:46+02:00" level=debug msg="UserInfo Request with id '7b158d0d-c82d-45d2-ba0c-695b4960de65' on client with id 'roundcube' was successfully processed" method=GET path=/api/oidc/userinfo remote_ip="***"
time="2024-06-02T15:09:46+02:00" level=debug msg="Introspection Request with id 'a6192159-d72c-48a4-bcb4-d256764121b6' is being processed" method=POST path=/api/oidc/introspection remote_ip="***"
time="2024-06-02T15:09:46+02:00" level=debug msg="UserInfo Request with id '597ef251-d955-4b44-b35c-096d8e8e5456' is being processed" method=GET path=/api/oidc/userinfo remote_ip="***"
time="2024-06-02T15:09:46+02:00" level=debug msg="UserInfo Request with id '597ef251-d955-4b44-b35c-096d8e8e5456' on client with id 'roundcube' is being returned unsigned as per the registered client configuration" method=GET path=/api/oidc/userinfo remote_ip="***
time="2024-06-02T15:09:46+02:00" level=debug msg="UserInfo Request with id '597ef251-d955-4b44-b35c-096d8e8e5456' on client with id 'roundcube' was successfully processed" method=GET path=/api/oidc/userinfo remote_ip="***"
time="2024-06-02T15:09:46+02:00" level=debug msg="Introspection Request with id '4af1457d-c2ba-46fe-8f87-81be12cf7e58' is being processed" method=POST path=/api/oidc/introspection remote_ip="***"
time="2024-06-02T15:09:46+02:00" level=debug msg="UserInfo Request with id '0c02aef2-07f4-4104-b74d-b900af1f5e5f' is being processed" method=GET path=/api/oidc/userinfo remote_ip="***"
time="2024-06-02T15:09:46+02:00" level=debug msg="UserInfo Request with id '0c02aef2-07f4-4104-b74d-b900af1f5e5f' on client with id 'roundcube' is being returned unsigned as per the registered client configuration" method=GET path=/api/oidc/userinfo remote_ip="***"
time="2024-06-02T15:09:46+02:00" level=debug msg="UserInfo Request with id '0c02aef2-07f4-4104-b74d-b900af1f5e5f' on client with id 'roundcube' was successfully processed" method=GET path=/api/oidc/userinfo remote_ip="***"
time="2024-06-02T15:09:46+02:00" level=debug msg="Introspection Request with id '9aa8ec48-5ef6-4caf-a7a0-9899fae9597f' is being processed" method=POST path=/api/oidc/introspection remote_ip="***"
time="2024-06-02T15:09:46+02:00" level=debug msg="UserInfo Request with id '58090472-e4f5-456e-b169-c3340310e4a2' is being processed" method=GET path=/api/oidc/userinfo remote_ip="***"
time="2024-06-02T15:09:46+02:00" level=debug msg="UserInfo Request with id '58090472-e4f5-456e-b169-c3340310e4a2' on client with id 'roundcube' is being returned unsigned as per the registered client configuration" method=GET path=/api/oidc/userinfo remote_ip="***"
time="2024-06-02T15:09:46+02:00" level=debug msg="UserInfo Request with id '58090472-e4f5-456e-b169-c3340310e4a2' on client with id 'roundcube' was successfully processed" method=GET path=/api/oidc/userinfo remote_ip="***"
time="2024-06-02T15:09:46+02:00" level=debug msg="Introspection Request with id 'c365b985-06ee-48ab-97c4-399d4c3ac638' is being processed" method=POST path=/api/oidc/introspection remote_ip="***"
time="2024-06-02T15:09:53+02:00" level=debug msg="UserInfo Request with id '664e5bd0-e090-4852-9624-ab13708d6158' is being processed" method=GET path=/api/oidc/userinfo remote_ip="***"
time="2024-06-02T15:09:53+02:00" level=debug msg="UserInfo Request with id '664e5bd0-e090-4852-9624-ab13708d6158' on client with id 'roundcube' is being returned unsigned as per the registered client configuration" method=GET path=/api/oidc/userinfo remote_ip="***"
time="2024-06-02T15:09:53+02:00" level=debug msg="UserInfo Request with id '664e5bd0-e090-4852-9624-ab13708d6158' on client with id 'roundcube' was successfully processed" method=GET path=/api/oidc/userinfo remote_ip="***"
time="2024-06-02T15:09:53+02:00" level=debug msg="Introspection Request with id 'da86e4b6-9ba9-4018-8d9c-8b4db5aa2211' is being processed" method=POST path=/api/oidc/introspection remote_ip="***"
time="2024-06-02T15:09:54+02:00" level=debug msg="UserInfo Request with id 'e0f08b7b-6147-46d8-8507-33e8f5d045d0' is being processed" method=GET path=/api/oidc/userinfo remote_ip="***"
time="2024-06-02T15:09:54+02:00" level=debug msg="UserInfo Request with id 'e0f08b7b-6147-46d8-8507-33e8f5d045d0' on client with id 'roundcube' is being returned unsigned as per the registered client configuration" method=GET path=/api/oidc/userinfo remote_ip="***"
time="2024-06-02T15:09:54+02:00" level=debug msg="UserInfo Request with id 'e0f08b7b-6147-46d8-8507-33e8f5d045d0' on client with id 'roundcube' was successfully processed" method=GET path=/api/oidc/userinfo remote_ip="***"
time="2024-06-02T15:09:54+02:00" level=debug msg="Introspection Request with id '1e1c9310-b9a8-428a-ab30-3043bd9e67c2' is being processed" method=POST path=/api/oidc/introspection remote_ip="***"
time="2024-06-02T15:10:46+02:00" level=debug msg="UserInfo Request with id 'f4e1b804-7a3b-4462-a332-28bdaa37a273' is being processed" method=GET path=/api/oidc/userinfo remote_ip="***"
time="2024-06-02T15:10:46+02:00" level=debug msg="UserInfo Request with id 'f4e1b804-7a3b-4462-a332-28bdaa37a273' on client with id 'roundcube' is being returned unsigned as per the registered client configuration" method=GET path=/api/oidc/userinfo remote_ip="***"
time="2024-06-02T15:10:46+02:00" level=debug msg="UserInfo Request with id 'f4e1b804-7a3b-4462-a332-28bdaa37a273' on client with id 'roundcube' was successfully processed" method=GET path=/api/oidc/userinfo remote_ip="***"
time="2024-06-02T15:10:46+02:00" level=debug msg="Introspection Request with id '104b3510-d141-4035-be0a-573ff5cf3728' is being processed" method=POST path=/api/oidc/introspection remote_ip="***"
time="2024-06-02T15:11:04+02:00" level=debug msg="UserInfo Request with id 'c87d96d9-d479-4870-b4d6-8bdd273ddb0e' is being processed" method=GET path=/api/oidc/userinfo remote_ip="***"
time="2024-06-02T15:11:04+02:00" level=debug msg="UserInfo Request with id 'c87d96d9-d479-4870-b4d6-8bdd273ddb0e' on client with id 'roundcube' is being returned unsigned as per the registered client configuration" method=GET path=/api/oidc/userinfo remote_ip="***"
time="2024-06-02T15:11:04+02:00" level=debug msg="UserInfo Request with id 'c87d96d9-d479-4870-b4d6-8bdd273ddb0e' on client with id 'roundcube' was successfully processed" method=GET path=/api/oidc/userinfo remote_ip="***"
time="2024-06-02T15:11:04+02:00" level=debug msg="Introspection Request with id '0a54e823-8cd6-422e-99a2-aff322cbe549' is being processed" method=POST path=/api/oidc/introspection remote_ip="***"
time="2024-06-02T15:11:04+02:00" level=debug msg="UserInfo Request with id 'd1468455-7832-4bb7-8b05-328005050ce0' is being processed" method=GET path=/api/oidc/userinfo remote_ip="***"
time="2024-06-02T15:11:04+02:00" level=debug msg="UserInfo Request with id 'd1468455-7832-4bb7-8b05-328005050ce0' on client with id 'roundcube' is being returned unsigned as per the registered client configuration" method=GET path=/api/oidc/userinfo remote_ip="***"
time="2024-06-02T15:11:04+02:00" level=debug msg="UserInfo Request with id 'd1468455-7832-4bb7-8b05-328005050ce0' on client with id 'roundcube' was successfully processed" method=GET path=/api/oidc/userinfo remote_ip="***"
time="2024-06-02T15:11:04+02:00" level=debug msg="Introspection Request with id 'bd7884ec-d3d4-4550-b9e7-73a4ce0dbab7' is being processed" method=POST path=/api/oidc/introspection remote_ip="***"
time="2024-06-02T15:11:04+02:00" level=debug msg="UserInfo Request with id '96015002-8378-46dc-a1f2-ba966f9a9e9a' is being processed" method=GET path=/api/oidc/userinfo remote_ip="***"
time="2024-06-02T15:11:04+02:00" level=debug msg="UserInfo Request with id '96015002-8378-46dc-a1f2-ba966f9a9e9a' on client with id 'roundcube' is being returned unsigned as per the registered client configuration" method=GET path=/api/oidc/userinfo remote_ip="***"
time="2024-06-02T15:11:04+02:00" level=debug msg="UserInfo Request with id '96015002-8378-46dc-a1f2-ba966f9a9e9a' on client with id 'roundcube' was successfully processed" method=GET path=/api/oidc/userinfo remote_ip="***"
time="2024-06-02T15:11:04+02:00" level=debug msg="Introspection Request with id '183c84ed-184f-4d89-a0e4-8ea0b054c365' is being processed" method=POST path=/api/oidc/introspection remote_ip="***"
time="2024-06-02T15:12:04+02:00" level=debug msg="UserInfo Request with id '60616c9a-1c8c-4b88-91ef-326497db9ebb' is being processed" method=GET path=/api/oidc/userinfo remote_ip="***"
time="2024-06-02T15:12:04+02:00" level=debug msg="UserInfo Request with id '60616c9a-1c8c-4b88-91ef-326497db9ebb' on client with id 'roundcube' is being returned unsigned as per the registered client configuration" method=GET path=/api/oidc/userinfo remote_ip="***"
time="2024-06-02T15:12:04+02:00" level=debug msg="UserInfo Request with id '60616c9a-1c8c-4b88-91ef-326497db9ebb' on client with id 'roundcube' was successfully processed" method=GET path=/api/oidc/userinfo remote_ip="***"
time="2024-06-02T15:12:04+02:00" level=debug msg="Introspection Request with id 'dc15dd13-95df-4413-8de8-691f4a1e63b2' is being processed" method=POST path=/api/oidc/introspection remote_ip="***"
time="2024-06-02T15:12:43+02:00" level=debug msg="UserInfo Request with id 'f5e9b24d-9b6c-4ac4-ad9f-cfe12d5d1195' is being processed" method=GET path=/api/oidc/userinfo remote_ip="***"
time="2024-06-02T15:12:43+02:00" level=debug msg="UserInfo Request with id 'f5e9b24d-9b6c-4ac4-ad9f-cfe12d5d1195' on client with id 'roundcube' is being returned unsigned as per the registered client configuration" method=GET path=/api/oidc/userinfo remote_ip="***"
time="2024-06-02T15:12:43+02:00" level=debug msg="UserInfo Request with id 'f5e9b24d-9b6c-4ac4-ad9f-cfe12d5d1195' on client with id 'roundcube' was successfully processed" method=GET path=/api/oidc/userinfo remote_ip="***"
time="2024-06-02T15:12:43+02:00" level=debug msg="Introspection Request with id 'adf00e89-07ef-4fe3-98e4-d5d8282e3740' is being processed" method=POST path=/api/oidc/introspection remote_ip="***"
time="2024-06-02T15:12:43+02:00" level=debug msg="UserInfo Request with id '282c85e6-846d-4ce9-b4f5-ee6e3ef68df7' is being processed" method=GET path=/api/oidc/userinfo remote_ip="***"
time="2024-06-02T15:12:43+02:00" level=debug msg="UserInfo Request with id '282c85e6-846d-4ce9-b4f5-ee6e3ef68df7' on client with id 'roundcube' is being returned unsigned as per the registered client configuration" method=GET path=/api/oidc/userinfo remote_ip="***"
time="2024-06-02T15:12:43+02:00" level=debug msg="UserInfo Request with id '282c85e6-846d-4ce9-b4f5-ee6e3ef68df7' on client with id 'roundcube' was successfully processed" method=GET path=/api/oidc/userinfo remote_ip="***"
time="2024-06-02T15:12:43+02:00" level=debug msg="Introspection Request with id 'a6f80b6d-76c0-4b63-b328-9e658a2867a5' is being processed" method=POST path=/api/oidc/introspection remote_ip="***"
time="2024-06-02T15:12:43+02:00" level=debug msg="UserInfo Request with id '573a7c21-8eff-4d99-a260-137d1af7e9ac' is being processed" method=GET path=/api/oidc/userinfo remote_ip="***"
time="2024-06-02T15:12:43+02:00" level=debug msg="UserInfo Request with id '573a7c21-8eff-4d99-a260-137d1af7e9ac' on client with id 'roundcube' is being returned unsigned as per the registered client configuration" method=GET path=/api/oidc/userinfo remote_ip="***"
time="2024-06-02T15:12:43+02:00" level=debug msg="UserInfo Request with id '573a7c21-8eff-4d99-a260-137d1af7e9ac' on client with id 'roundcube' was successfully processed" method=GET path=/api/oidc/userinfo remote_ip="***"
time="2024-06-02T15:12:43+02:00" level=debug msg="Introspection Request with id '5ae168ed-0673-4fdf-90e8-84d79a7a4aae' is being processed" method=POST path=/api/oidc/introspection remote_ip="***"
time="2024-06-02T15:13:44+02:00" level=debug msg="UserInfo Request with id '809d80f1-946f-47e2-be05-9a60697140e2' is being processed" method=GET path=/api/oidc/userinfo remote_ip="***"
time="2024-06-02T15:13:44+02:00" level=debug msg="UserInfo Request with id '809d80f1-946f-47e2-be05-9a60697140e2' on client with id 'roundcube' is being returned unsigned as per the registered client configuration" method=GET path=/api/oidc/userinfo remote_ip="***"
time="2024-06-02T15:13:44+02:00" level=debug msg="UserInfo Request with id '809d80f1-946f-47e2-be05-9a60697140e2' on client with id 'roundcube' was successfully processed" method=GET path=/api/oidc/userinfo remote_ip="***"
time="2024-06-02T15:13:44+02:00" level=debug msg="Introspection Request with id '242ad5ce-a0d2-44a7-ba45-88780fa51753' is being processed" method=POST path=/api/oidc/introspection remote_ip="***"
time="2024-06-02T15:14:44+02:00" level=debug msg="UserInfo Request with id 'd8dc1294-9ba3-4dac-bad8-46a07c670491' is being processed" method=GET path=/api/oidc/userinfo remote_ip="***"
time="2024-06-02T15:14:44+02:00" level=error msg="UserInfo Request with id 'd8dc1294-9ba3-4dac-bad8-46a07c670491' failed with error: Token expired. Access token expired at '2024-06-02 13:14:38 +0000 UTC'." method=GET path=/api/oidc/userinfo remote_ip="***" stack="github.com/authelia/authelia/v4/internal/handlers/handler_oidc_userinfo.go:44                OpenIDConnectUserinfo\ngithub.com/authelia/authelia/v4/internal/middlewares/http_to_authelia_handler_adaptor.go:114 handleRouter.NewHTTPToAutheliaHandlerAdaptor.func27\ngithub.com/authelia/authelia/v4/internal/middlewares/bridge.go:54                            handleRouter.(*BridgeBuilder).Build.func16.1\ngithub.com/authelia/authelia/v4/internal/middlewares/headers.go:91                           SecurityHeadersNoStore.func1\ngithub.com/valyala/fasthttp@v1.52.0/userdata.go:57                                           (*userData).Get\ngithub.com/authelia/authelia/v4/internal/middlewares/headers.go:30                           SecurityHeadersBase.func1\ngithub.com/authelia/authelia/v4/internal/middlewares/cors.go:216                             handleRouter.(*CORSPolicy).Middleware.func28\ngithub.com/fasthttp/router@v1.5.0/router.go:441                                              (*Router).Handler\ngithub.com/authelia/authelia/v4/internal/middlewares/log_request.go:14                       handleRouter.LogRequest.func40\ngithub.com/authelia/authelia/v4/internal/middlewares/errors.go:38                            RecoverPanic.func1\ngithub.com/valyala/fasthttp@v1.52.0/server.go:2374                                           (*Server).serveConn\ngithub.com/valyala/fasthttp@v1.52.0/workerpool.go:224                                        (*workerPool).workerFunc\ngithub.com/valyala/fasthttp@v1.52.0/workerpool.go:196                                        (*workerPool).getCh.func1\nruntime/asm_amd64.s:1695                                                                     goexit"
time="2024-06-02T15:15:44+02:00" level=debug msg="UserInfo Request with id '0d87f026-9877-4aa8-bcdc-0f9fc7009c6b' is being processed" method=GET path=/api/oidc/userinfo remote_ip="***"
time="2024-06-02T15:15:44+02:00" level=error msg="UserInfo Request with id '0d87f026-9877-4aa8-bcdc-0f9fc7009c6b' failed with error: Token expired. Access token expired at '2024-06-02 13:14:38 +0000 UTC'." method=GET path=/api/oidc/userinfo remote_ip="***" stack="github.com/authelia/authelia/v4/internal/handlers/handler_oidc_userinfo.go:44                OpenIDConnectUserinfo\ngithub.com/authelia/authelia/v4/internal/middlewares/http_to_authelia_handler_adaptor.go:114 handleRouter.NewHTTPToAutheliaHandlerAdaptor.func27\ngithub.com/authelia/authelia/v4/internal/middlewares/bridge.go:54                            handleRouter.(*BridgeBuilder).Build.func16.1\ngithub.com/authelia/authelia/v4/internal/middlewares/headers.go:91                           SecurityHeadersNoStore.func1\ngithub.com/valyala/fasthttp@v1.52.0/userdata.go:57                                           (*userData).Get\ngithub.com/authelia/authelia/v4/internal/middlewares/headers.go:30                           SecurityHeadersBase.func1\ngithub.com/authelia/authelia/v4/internal/middlewares/cors.go:216                             handleRouter.(*CORSPolicy).Middleware.func28\ngithub.com/fasthttp/router@v1.5.0/router.go:441                                              (*Router).Handler\ngithub.com/authelia/authelia/v4/internal/middlewares/log_request.go:14                       handleRouter.LogRequest.func40\ngithub.com/authelia/authelia/v4/internal/middlewares/errors.go:38                            RecoverPanic.func1\ngithub.com/valyala/fasthttp@v1.52.0/server.go:2374                                           (*Server).serveConn\ngithub.com/valyala/fasthttp@v1.52.0/workerpool.go:224                                        (*workerPool).workerFunc\ngithub.com/valyala/fasthttp@v1.52.0/workerpool.go:196                                        (*workerPool).getCh.func1\nruntime/asm_amd64.s:1695                                                                     goexit"
time="2024-06-02T15:16:45+02:00" level=debug msg="UserInfo Request with id '180be465-2038-4b23-9705-d202249b43cb' is being processed" method=GET path=/api/oidc/userinfo remote_ip="***"
time="2024-06-02T15:16:45+02:00" level=error msg="UserInfo Request with id '180be465-2038-4b23-9705-d202249b43cb' failed with error: Token expired. Access token expired at '2024-06-02 13:14:38 +0000 UTC'." method=GET path=/api/oidc/userinfo remote_ip="***" stack="github.com/authelia/authelia/v4/internal/handlers/handler_oidc_userinfo.go:44                OpenIDConnectUserinfo\ngithub.com/authelia/authelia/v4/internal/middlewares/http_to_authelia_handler_adaptor.go:114 handleRouter.NewHTTPToAutheliaHandlerAdaptor.func27\ngithub.com/authelia/authelia/v4/internal/middlewares/bridge.go:54                            handleRouter.(*BridgeBuilder).Build.func16.1\ngithub.com/authelia/authelia/v4/internal/middlewares/headers.go:91                           SecurityHeadersNoStore.func1\ngithub.com/valyala/fasthttp@v1.52.0/userdata.go:57                                           (*userData).Get\ngithub.com/authelia/authelia/v4/internal/middlewares/headers.go:30                           SecurityHeadersBase.func1\ngithub.com/authelia/authelia/v4/internal/middlewares/cors.go:216                             handleRouter.(*CORSPolicy).Middleware.func28\ngithub.com/fasthttp/router@v1.5.0/router.go:441                                              (*Router).Handler\ngithub.com/authelia/authelia/v4/internal/middlewares/log_request.go:14                       handleRouter.LogRequest.func40\ngithub.com/authelia/authelia/v4/internal/middlewares/errors.go:38                            RecoverPanic.func1\ngithub.com/valyala/fasthttp@v1.52.0/server.go:2374                                           (*Server).serveConn\ngithub.com/valyala/fasthttp@v1.52.0/workerpool.go:224                                        (*workerPool).workerFunc\ngithub.com/valyala/fasthttp@v1.52.0/workerpool.go:196                                        (*workerPool).getCh.func1\nruntime/asm_amd64.s:1695                                                                     goexit"