[Bug]: Silent refresh gets out of step until refresh token expires #1383

Budno · 2022-02-14T14:19:36Z

What Version of the library are you using?
11.6.11

Describe the bug
Intermittently the silent refresh mechanism seems to get out of step and waits much longer than the usual 4 seconds. The delay can range from a few seconds to several minutes. If the refresh token has expired in the meantime, the OIDC provider refuses to refresh it. As a consequence, a roundtrip to the OIDC server becomes necessary. This is observed several times an hour in my application. Sometimes the refresh check even stops altogether.

I have tried to circumvent the problem by increasing renewTimeBeforeTokenExpiresInSeconds from 10 to 150 seconds so that tokens are renewed earlier and can still be updated if a short delay occurs. This made the issue more rare, but it still recurred (with a delay > 150 seconds) after keeping the application open in the browser for 1-2 hours.

I am using silent renew with refresh tokens in a productive application.

To Reproduce
Use the library with silent renew, use refresh tokens that are valid for 120 seconds, set renewTimeBeforeTokenExpiresInSeconds=10 and keep the Angular application open for 1 hour. Then check the server log
Steps to reproduce the behavior:

Use the library with configuration silentRenew: true, useRefreshToken: true, renewTimeBeforeTokenExpiresInSeconds: 10, logLevel: LogLevel.Debug
on the OIDC server, use short-lived refresh and access tokens (e.g. 60 seconds)
Keep the application open in Chrome for 1 hour or until the token refresh fails
-> The console log shows that the refresh check sometimes takes more than 4 seconds and at some point the OIDC refuses to refresh the token because it has expired.

Expected behavior
The silent refresh check should be executed every 4 seconds or at the projected expiration time of the refresh/access token.

Screenshots
Refresh check only after 23 seconds, then after 1 minute:

Refresh check delayed by almost 9 minutes:

Refresh check stopped completely:

Desktop (please complete the following information):

OS: Windows 10
Browser Chrome
Version 98.0

Additional context
When the refresh time starts to become less reliable, the browser often shows warnings about delayed calls to setInterval() or zone-evergreen progress handlers.

soners · 2022-03-14T14:26:40Z

Hello @Budno

We are facing the same problem with a single difference. Check session completely stops working instead of delayed working, which also leads to user has to refresh the page to get the auth flow working again. I was wondering did you find any solutions or workarounds? I tried it with v11.6.11, v12.0.3, 13.1.0

Budno · 2022-03-14T14:48:02Z

Hi @soners ,
Good to hear I am not the only one seeing this happen. Unfortunately I have not found a workaround yet. We are currently coping with it as the problem only occurs from time to time. I have been kind of hoping the issue would magically disappear once we upgrade to Angular 13, but this does not seem to be the case then.

FabianGosebrink · 2022-12-08T13:11:43Z

Is this issue still relevant? Did you upgrade to the latest version?

Budno · 2022-12-12T11:02:08Z

Yes, it is still relevant to us. However, we are currently not able to update to a version higher than v13.0.0 because starting from v13.1.0 the support of http (without https) was dropped and we are currently still dependent on http for on-premise environments.
Is it possible that the issue got fixed in the latest version?

medeirosrich · 2023-01-20T15:38:02Z

I'm also experiencing this issue on version 15.0.2. Seems to be much more likely to happen if the application is open in multiple browser tabs (chrome).

Here are the console logs:

angular-auth-oidc-client.mjs:4248 [DEBUG] /Dev/Portal/ - Checking: silentRenewRunning: false, isCodeFlowInProgress: false - has idToken: true - has userData: true
angular-auth-oidc-client.mjs:4248 [DEBUG] /Dev/Portal/ - Has accessToken expired: false --> expires in 0:14 , 8:26:07 AM > 8:25:53 AM
angular-auth-oidc-client.mjs:4248 [DEBUG] /Dev/Portal/ - silent renew, periodic check finished!
angular-auth-oidc-client.mjs:4248 [DEBUG] /Dev/Portal/ - Checking: silentRenewRunning: false, isCodeFlowInProgress: false - has idToken: true - has userData: true
angular-auth-oidc-client.mjs:4248 [DEBUG] /Dev/Portal/ - Has accessToken expired: false --> expires in 0:10 , 8:26:07 AM > 8:25:57 AM
angular-auth-oidc-client.mjs:4248 [DEBUG] /Dev/Portal/ - silent renew, periodic check finished!
angular-auth-oidc-client.mjs:4248 [DEBUG] /Dev/Portal/ - Checking: silentRenewRunning: false, isCodeFlowInProgress: false - has idToken: true - has userData: true
angular-auth-oidc-client.mjs:4248 [DEBUG] /Dev/Portal/ - Has accessToken expired: false --> expires in 0:06 , 8:26:07 AM > 8:26:01 AM
angular-auth-oidc-client.mjs:4248 [DEBUG] /Dev/Portal/ - silent renew, periodic check finished!
angular-auth-oidc-client.mjs:4248 [DEBUG] /Dev/Portal/ - Checking: silentRenewRunning: false, isCodeFlowInProgress: false - has idToken: true - has userData: true
angular-auth-oidc-client.mjs:4248 [DEBUG] /Dev/Portal/ - Has accessToken expired: false --> expires in 0:02 , 8:26:07 AM > 8:26:05 AM
angular-auth-oidc-client.mjs:4248 [DEBUG] /Dev/Portal/ - silent renew, periodic check finished!
angular-auth-oidc-client.mjs:4248 [DEBUG] /Dev/Portal/ - Checking: silentRenewRunning: false, isCodeFlowInProgress: false - has idToken: true - has userData: true
angular-auth-oidc-client.mjs:4248 [DEBUG] /Dev/Portal/ - Has accessToken expired: true --> expires in -1:0-2 , 8:26:07 AM > 8:26:09 AM
angular-auth-oidc-client.mjs:4248 [DEBUG] /Dev/Portal/ - starting silent renew...
angular-auth-oidc-client.mjs:4248 [DEBUG] /Dev/Portal/ - BEGIN refresh session Authorize
angular-auth-oidc-client.mjs:4248 [DEBUG] /Dev/Portal/ - RefreshSession created. Adding myautostate: 1c6289cdd97e6f8a964a272b077fb62e37R3kU8rc
angular-auth-oidc-client.mjs:4248 [DEBUG] /Dev/Portal/ - found refresh code, obtaining new credentials with refresh code
angular-auth-oidc-client.mjs:4248 [DEBUG] /Dev/Portal/ - Did not find any configured route for route https://localhost/Dev/SecurityServer/connect/token
angular-auth-oidc-client.mjs:4248 [DEBUG] /Dev/Portal/ - token refresh response:  {access_token: '...', token_type: 'Bearer', expires_in: 60, scope: 'openid email profile offline_access roles internal_api external_api', id_token: '...', …}
angular-auth-oidc-client.mjs:4248 [DEBUG] /Dev/Portal/ - history clean up inactive
angular-auth-oidc-client.mjs:4248 [DEBUG] /Dev/Portal/ - AuthResult '{
  "access_token": "...",
  "token_type": "Bearer",
  "expires_in": 60,
  "scope": "openid email profile offline_access roles internal_api external_api",
  "id_token": "...",
angular-auth-oidc-client.mjs:4248 [DEBUG] /Dev/Portal/ - Getting signinkeys from  https://localhost/Dev/SecurityServer/.well-known/jwks
angular-auth-oidc-client.mjs:4248 [DEBUG] /Dev/Portal/ - Did not find any configured route for route https://localhost/Dev/SecurityServer/.well-known/jwks
angular-auth-oidc-client.mjs:4248 [DEBUG] /Dev/Portal/ - ValidateStateFromHashCallback failed, state: 1c6289cdd97e6f8a964a272b077fb62e37R3kU8rc local_state:3922d05bfcb4115e36b893345215867112744rWB6
angular-auth-oidc-client.mjs:4248 [DEBUG] /Dev/Portal/ - authCallback token(s) invalid
angular-auth-oidc-client.mjs:4248 [DEBUG] /Dev/Portal/ - Local Login information cleaned up and event fired
angular-auth-oidc-client.mjs:4248 [DEBUG] /Dev/Portal/ - Local Login information cleaned up and event fired
^
angular-auth-oidc-client stops logging here

Authority is setup with an access token lifetime of 1min and refresh token lifetime of 2mins.

Current OpenIdConfiguration:

const openIdConfiguration: OpenIdConfiguration = {
    configId: configService.baseHref,
    authority: config.SecurityServerUrl,
    redirectUrl: window.location.origin + configService.baseHref,
    postLogoutRedirectUri: window.location.origin + configService.baseHref,
    clientId: 'MyClient',
    scope: 'openid email profile offline_access roles internal_api external_api',
    responseType: 'code',
    useRefreshToken: true,
    silentRenew: true,
    ignoreNonceAfterRefresh: true,
    triggerRefreshWhenIdTokenExpired: false, // required to refresh the browser if id_token is not updated after the first authentication
    renewTimeBeforeTokenExpiresInSeconds: 30,
    secureRoutes: [config.WebApiBaseUrl, config.SecurityServerUrl + '/api/Security'],
    renewUserInfoAfterTokenRenew: true,
    logLevel: LogLevel.Debug
  };

Edit: I should mention that I'm using localStorage which causes all tabs to invalidate

deep-fried-banana · 2023-10-19T23:08:25Z

I am seeing this issue on v13.0.0 with the silentRenew getting out of step/delayed. The issue is more apparent with a lower renewTimeBeforeTokenExpiresInSeconds (30s vs 120s) since our access_token won't get renewed in time before it expires and causes 401 unauthorized errors in the webapp.

Steps to reproduce are somewhat similar to what is suggested here #1841 except instead of just switching tabs I also switch applications altogether (minimize Chrome and switch to Visual Studio Code, for example). I think when I initially tried just switching tabs, I did not have debug logs enabled at the time, I was not getting 401 unauthorized errors so it's possible the silentRenew getting out of step/delayed could have been occurring without triggering 401 unauthorized errors.

Console logs show periodic check changing from every 4 seconds to every 1 minute:

20:32:07.243 angular-auth-oidc-client.mjs:168 [DEBUG] <scrubbed>- Checking: silentRenewRunning: false - has idToken: true - has userData: true
20:32:07.243 angular-auth-oidc-client.mjs:168 [DEBUG] <scrubbed>- Has idToken expired: false --> expires in 28:09 , 9:01:16 PM > 8:33:07 PM
20:32:07.244 angular-auth-oidc-client.mjs:168 [DEBUG] <scrubbed>- Has accessToken expired: false --> expires in 18:08 , 8:51:15 PM > 8:33:07 PM
20:32:07.244 angular-auth-oidc-client.mjs:168 [DEBUG] <scrubbed>- silent renew, periodic check finished!
20:32:09.245 angular-auth-oidc-client.mjs:168 [DEBUG] <scrubbed>- Did not find any configured route for route https://<scrubbed>:443/<scrubbed>
20:32:09.250 angular-auth-oidc-client.mjs:168 [DEBUG] <scrubbed>- Did not find any configured route for route https://<scrubbed>:443/<scrubbed>
20:32:09.252 angular-auth-oidc-client.mjs:168 [DEBUG] <scrubbed>- Did not find any configured route for route https://<scrubbed>:443/<scrubbed>
20:32:11.240 angular-auth-oidc-client.mjs:168 [DEBUG] <scrubbed>- Checking: silentRenewRunning: false - has idToken: true - has userData: true
20:32:11.241 angular-auth-oidc-client.mjs:168 [DEBUG] <scrubbed>- Has idToken expired: false --> expires in 28:05 , 9:01:16 PM > 8:33:11 PM
20:32:11.241 angular-auth-oidc-client.mjs:168 [DEBUG] <scrubbed>- Has accessToken expired: false --> expires in 18:04 , 8:51:15 PM > 8:33:11 PM
20:32:11.241 angular-auth-oidc-client.mjs:168 [DEBUG] <scrubbed>- silent renew, periodic check finished!
20:32:15.235 angular-auth-oidc-client.mjs:168 [DEBUG] <scrubbed>- Checking: silentRenewRunning: false - has idToken: true - has userData: true
20:32:15.235 angular-auth-oidc-client.mjs:168 [DEBUG] <scrubbed>- Has idToken expired: false --> expires in 28:01 , 9:01:16 PM > 8:33:15 PM
20:32:15.236 angular-auth-oidc-client.mjs:168 [DEBUG] <scrubbed>- Has accessToken expired: false --> expires in 18:00 , 8:51:15 PM > 8:33:15 PM
20:32:15.236 angular-auth-oidc-client.mjs:168 [DEBUG] <scrubbed>- silent renew, periodic check finished!
20:32:39.270 angular-auth-oidc-client.mjs:168 [DEBUG] <scrubbed>- Did not find any configured route for route https://<scrubbed>:443/<scrubbed>
20:32:39.272 angular-auth-oidc-client.mjs:168 [DEBUG] <scrubbed>- Did not find any configured route for route https://<scrubbed>:443/<scrubbed>
20:33:09.241 angular-auth-oidc-client.mjs:168 [DEBUG] <scrubbed>- Did not find any configured route for route https://<scrubbed>:443/<scrubbed>
20:33:09.247 angular-auth-oidc-client.mjs:168 [DEBUG] <scrubbed>- Did not find any configured route for route https://<scrubbed>:443/<scrubbed>
20:33:09.249 angular-auth-oidc-client.mjs:168 [DEBUG] <scrubbed>- Did not find any configured route for route https://<scrubbed>:443/<scrubbed>
20:33:15.240 angular-auth-oidc-client.mjs:168 [DEBUG] <scrubbed>- Checking: silentRenewRunning: false - has idToken: true - has userData: true
20:33:15.241 angular-auth-oidc-client.mjs:168 [DEBUG] <scrubbed>- Has idToken expired: false --> expires in 27:01 , 9:01:16 PM > 8:34:15 PM
20:33:15.241 angular-auth-oidc-client.mjs:168 [DEBUG] <scrubbed>- Has accessToken expired: false --> expires in 17:00 , 8:51:15 PM > 8:34:15 PM
20:33:15.242 angular-auth-oidc-client.mjs:168 [DEBUG] <scrubbed>- silent renew, periodic check finished!
20:34:09.236 angular-auth-oidc-client.mjs:168 [DEBUG] <scrubbed>- Did not find any configured route for route https://<scrubbed>:443/<scrubbed>
20:34:15.240 angular-auth-oidc-client.mjs:168 [DEBUG] <scrubbed>- Checking: silentRenewRunning: false - has idToken: true - has userData: true
20:34:15.240 angular-auth-oidc-client.mjs:168 [DEBUG] <scrubbed>- Has idToken expired: false --> expires in 26:01 , 9:01:16 PM > 8:35:15 PM
20:34:15.240 angular-auth-oidc-client.mjs:168 [DEBUG] <scrubbed>- Has accessToken expired: false --> expires in 16:00 , 8:51:15 PM > 8:35:15 PM
20:34:15.241 angular-auth-oidc-client.mjs:168 [DEBUG] <scrubbed>- silent renew, periodic check finished!
20:34:15.243 angular-auth-oidc-client.mjs:168 [DEBUG] <scrubbed>- Did not find any configured route for route https://<scrubbed>:443/<scrubbed>
20:34:15.245 angular-auth-oidc-client.mjs:168 [DEBUG] <scrubbed>- Did not find any configured route for route https://<scrubbed>:443/<scrubbed>
20:35:09.235 angular-auth-oidc-client.mjs:168 [DEBUG] <scrubbed>- Did not find any configured route for route https://<scrubbed>:443/<scrubbed>
20:35:15.272 angular-auth-oidc-client.mjs:168 [DEBUG] <scrubbed>- Checking: silentRenewRunning: false - has idToken: true - has userData: true
20:35:15.273 angular-auth-oidc-client.mjs:168 [DEBUG] <scrubbed>- Has idToken expired: false --> expires in 25:01 , 9:01:16 PM > 8:36:15 PM
20:35:15.273 angular-auth-oidc-client.mjs:168 [DEBUG] <scrubbed>- Has accessToken expired: false --> expires in 15:00 , 8:51:15 PM > 8:36:15 PM
20:35:15.273 angular-auth-oidc-client.mjs:168 [DEBUG] <scrubbed>- silent renew, periodic check finished!

AccessToken expired checks over time:

20:31:15.141 angular-auth-oidc-client.mjs:168 [DEBUG] <scrubbed>- Has accessToken expired: true --> expires in 0:00 , 8:32:15 PM > 8:32:15 PM
20:50:15.263 angular-auth-oidc-client.mjs:168 [DEBUG] <scrubbed>- Has accessToken expired: true --> expires in 0:00 , 8:51:15 PM > 8:51:15 PM
20:59:17.405 <scrubbed> LoggedOut event fired
20:59:24.700 <scrubbed> LoggedIn event fired
21:19:15.241 angular-auth-oidc-client.mjs:168 [DEBUG] <scrubbed>- Has accessToken expired: true --> expires in -1:0-54 , 9:19:21 PM > 9:20:15 PM

Note: I've observed the negative expires in value without logging out and logging back in to the webapp but I included those events in here to explain the gap from the second accessToken expired check to the last accessToken expired.

OpenID Configuration used for the logs:

    authority: <Omitted>,
    redirectUrl: <Omitted>,
    postLoginRoute: <Omitted>,
    postLogoutRedirectUri:<Omitted>,
    clientId: <Omitted>,
    scope: 'openid profile email phone address read:user offline_access',
    responseType: 'code',
    silentRenew: true,
    useRefreshToken: true,
    renewTimeBeforeTokenExpiresInSeconds: 60,
    logLevel: 1,
    authWellknownEndpoints,
    apiServer: <Omitted>,
    userIdKey: <Omitted>,
    storage: new AuthStorage(), // Local storage

Desktop (please complete the following information):

OS: Windows 10 (22H2)
Browser: Chrome
Version(s): 118.0.5993.88, 118.0.5993.89

craigvl · 2023-11-01T00:31:13Z

Same issue here, if getting close to the expiry should just run refresh? On version 13.1.0

deep-fried-banana · 2023-12-06T17:59:28Z

Is this issue still relevant? Did you upgrade to the latest version?

@FabianGosebrink @damienbod Just curious if there has been time to further investigate this issue. Is there a status update available for this issue or is the recommendation to try to upgrade to the latest version?

Budno · 2023-12-07T09:01:04Z

We are currently using v15 and this issue is still there.
On inactive tabs it may be partly caused by Chrome's Memory Saver feature -> https://support.google.com/chrome/answer/12929150?hl=en#zippy=%2Cturn-memory-saver-on-or-off. However, this does not explain why the problem occurs on the active tab which is where I usually see it.

damienbod added the investigate label Feb 15, 2022

damienbod added the version 11 label Mar 15, 2022

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[Bug]: Silent refresh gets out of step until refresh token expires #1383

[Bug]: Silent refresh gets out of step until refresh token expires #1383

Budno commented Feb 14, 2022

soners commented Mar 14, 2022 •

edited

Loading

Budno commented Mar 14, 2022

FabianGosebrink commented Dec 8, 2022

Budno commented Dec 12, 2022

medeirosrich commented Jan 20, 2023 •

edited

Loading

deep-fried-banana commented Oct 19, 2023 •

edited

Loading

craigvl commented Nov 1, 2023

deep-fried-banana commented Dec 6, 2023 •

edited

Loading

Budno commented Dec 7, 2023

[Bug]: Silent refresh gets out of step until refresh token expires #1383

[Bug]: Silent refresh gets out of step until refresh token expires #1383

Comments

Budno commented Feb 14, 2022

soners commented Mar 14, 2022 • edited Loading

Budno commented Mar 14, 2022

FabianGosebrink commented Dec 8, 2022

Budno commented Dec 12, 2022

medeirosrich commented Jan 20, 2023 • edited Loading

deep-fried-banana commented Oct 19, 2023 • edited Loading

craigvl commented Nov 1, 2023

deep-fried-banana commented Dec 6, 2023 • edited Loading

Budno commented Dec 7, 2023

soners commented Mar 14, 2022 •

edited

Loading

medeirosrich commented Jan 20, 2023 •

edited

Loading

deep-fried-banana commented Oct 19, 2023 •

edited

Loading

deep-fried-banana commented Dec 6, 2023 •

edited

Loading