From ba3c0f660acd77bc1f04fb1bb8dbc99a77c2d429 Mon Sep 17 00:00:00 2001 From: laileni Date: Fri, 14 Nov 2025 14:52:05 -0800 Subject: [PATCH 1/3] fix(auth): prevent concurrent token refresh and adding necessary logs --- .../src/auth/sso/ssoAccessTokenProvider.ts | 68 ++++++++++++++++++- 1 file changed, 66 insertions(+), 2 deletions(-) diff --git a/packages/core/src/auth/sso/ssoAccessTokenProvider.ts b/packages/core/src/auth/sso/ssoAccessTokenProvider.ts index e753fb2ef90..89247263e49 100644 --- a/packages/core/src/auth/sso/ssoAccessTokenProvider.ts +++ b/packages/core/src/auth/sso/ssoAccessTokenProvider.ts @@ -59,6 +59,15 @@ export abstract class SsoAccessTokenProvider { private static logIfChanged = onceChanged((s: string) => getLogger().info(s)) private readonly className = 'SsoAccessTokenProvider' + /** + * Prevents concurrent token refresh operations. + * Maps tokenCacheKey to an in-flight refresh promise. + */ + private static refreshPromises = new Map< + string, + Promise<{ token: SsoToken; registration: ClientRegistration; region: string; startUrl: string }> + >() + public static set authSource(val: string) { SsoAccessTokenProvider._authSource = val } @@ -98,6 +107,8 @@ export abstract class SsoAccessTokenProvider { } public async getToken(): Promise { + getLogger().warn(`getToken: CALLED for ${this.tokenCacheKey}`) + const data = await this.cache.token.load(this.tokenCacheKey) SsoAccessTokenProvider.logIfChanged( indent( @@ -108,15 +119,43 @@ export abstract class SsoAccessTokenProvider { true ) ) + if (!data || !isExpired(data.token)) { + getLogger().debug(`getToken: token is valid, returning cached token (key=${this.tokenCacheKey})`) return data?.token } + getLogger().info( + `getToken: bearer token expired (expires at ${data.token.expiresAt}), attempting refresh (key=${this.tokenCacheKey})` + ) + if (data.registration && !isExpired(data.registration) && hasProps(data.token, 'refreshToken')) { - const refreshed = await this.refreshToken(data.token, data.registration) + getLogger().info(`getToken: refresh token available, calling refreshToken() (key=${this.tokenCacheKey})`) + // Check if a refresh is already in progress for this token + const existingRefresh = SsoAccessTokenProvider.refreshPromises.get(this.tokenCacheKey) + if (existingRefresh) { + getLogger().debug( + 'SsoAccessTokenProvider: Token refresh already in progress, waiting for existing refresh' + ) + const refreshed = await existingRefresh + return refreshed.token + } - return refreshed.token + // Start a new refresh and store the promise + const refreshPromise = this.refreshToken(data.token, data.registration) + SsoAccessTokenProvider.refreshPromises.set(this.tokenCacheKey, refreshPromise) + + try { + const refreshed = await refreshPromise + return refreshed.token + } finally { + // Clean up the promise from the map once complete (success or failure) + SsoAccessTokenProvider.refreshPromises.delete(this.tokenCacheKey) + } } else { + getLogger().warn( + `getToken: cannot refresh - registration expired or no refresh token available (key=${this.tokenCacheKey})` + ) await this.invalidate('allCacheExpired') } } @@ -171,11 +210,29 @@ export abstract class SsoAccessTokenProvider { } try { + // TEST: Log when refresh starts WITH STACK TRACE + const stack = new Error().stack + ?.split('\n') + .slice(2, 12) // Skip first 2 lines (Error + refreshToken itself), take next 10 + .map((line) => line.trim()) + .join('\n ') + getLogger().warn( + `refreshToken: Starting OIDC API call for ${this.tokenCacheKey}\n CALL STACK:\n ${stack}` + ) + const clientInfo = selectFrom(registration, 'clientId', 'clientSecret') + getLogger().debug(`refreshToken: calling OIDC createToken API (key=${this.tokenCacheKey})`) const response = await this.oidc.createToken({ ...clientInfo, ...token, grantType: refreshGrantType }) + + getLogger().warn(`refreshToken: got response, now saving to cache...`) + const refreshed = this.formatToken(response, registration) + getLogger().debug(`refreshToken: saving refreshed token to cache (key=${this.tokenCacheKey})`) await this.cache.token.save(this.tokenCacheKey, refreshed) + getLogger().info( + `refreshToken: token refresh successful (key=${this.tokenCacheKey}, new expiry=${response.expiresAt})` + ) telemetry.aws_refreshCredentials.emit({ result: 'Succeeded', requestId: response.requestId, @@ -184,6 +241,10 @@ export abstract class SsoAccessTokenProvider { return refreshed } catch (err) { + getLogger().error( + `refreshToken: token refresh failed (key=${this.tokenCacheKey}): ${getErrorMsg(err as unknown as Error)}` + ) + if (err instanceof DiskCacheError) { /** * Background: @@ -197,6 +258,9 @@ export abstract class SsoAccessTokenProvider { * to the logs where the error was logged. Hopefully they can use this information to fix the issue, * or at least hint for them to provide the logs in a bug report. */ + getLogger().warn( + `refreshToken: DiskCacheError during refresh, not invalidating session (key=${this.tokenCacheKey})` + ) void DiskCacheErrorMessage.instance.showMessageThrottled(err) } else if (!isNetworkError(err)) { const reason = getTelemetryReason(err) From 09be2eefe30da84e359e93a31bd0f2d65df3ab1b Mon Sep 17 00:00:00 2001 From: laileni Date: Mon, 17 Nov 2025 11:54:28 -0800 Subject: [PATCH 2/3] fix: removing some logs used for testing --- .../core/src/auth/sso/ssoAccessTokenProvider.ts | 16 ++-------------- 1 file changed, 2 insertions(+), 14 deletions(-) diff --git a/packages/core/src/auth/sso/ssoAccessTokenProvider.ts b/packages/core/src/auth/sso/ssoAccessTokenProvider.ts index 89247263e49..bec13bed08c 100644 --- a/packages/core/src/auth/sso/ssoAccessTokenProvider.ts +++ b/packages/core/src/auth/sso/ssoAccessTokenProvider.ts @@ -107,8 +107,6 @@ export abstract class SsoAccessTokenProvider { } public async getToken(): Promise { - getLogger().warn(`getToken: CALLED for ${this.tokenCacheKey}`) - const data = await this.cache.token.load(this.tokenCacheKey) SsoAccessTokenProvider.logIfChanged( indent( @@ -130,7 +128,7 @@ export abstract class SsoAccessTokenProvider { ) if (data.registration && !isExpired(data.registration) && hasProps(data.token, 'refreshToken')) { - getLogger().info(`getToken: refresh token available, calling refreshToken() (key=${this.tokenCacheKey})`) + getLogger().debug(`getToken: refresh token available, calling refreshToken() (key=${this.tokenCacheKey})`) // Check if a refresh is already in progress for this token const existingRefresh = SsoAccessTokenProvider.refreshPromises.get(this.tokenCacheKey) if (existingRefresh) { @@ -210,21 +208,11 @@ export abstract class SsoAccessTokenProvider { } try { - // TEST: Log when refresh starts WITH STACK TRACE - const stack = new Error().stack - ?.split('\n') - .slice(2, 12) // Skip first 2 lines (Error + refreshToken itself), take next 10 - .map((line) => line.trim()) - .join('\n ') - getLogger().warn( - `refreshToken: Starting OIDC API call for ${this.tokenCacheKey}\n CALL STACK:\n ${stack}` - ) - const clientInfo = selectFrom(registration, 'clientId', 'clientSecret') getLogger().debug(`refreshToken: calling OIDC createToken API (key=${this.tokenCacheKey})`) const response = await this.oidc.createToken({ ...clientInfo, ...token, grantType: refreshGrantType }) - getLogger().warn(`refreshToken: got response, now saving to cache...`) + getLogger().debug(`refreshToken: got response, now saving to cache...`) const refreshed = this.formatToken(response, registration) getLogger().debug(`refreshToken: saving refreshed token to cache (key=${this.tokenCacheKey})`) From 115723b0d20815c2f3d15df8d9bf7a7f09e593a4 Mon Sep 17 00:00:00 2001 From: laileni Date: Mon, 17 Nov 2025 13:24:19 -0800 Subject: [PATCH 3/3] fix: addressing nits --- .../core/src/auth/sso/ssoAccessTokenProvider.ts | 16 ++++++++-------- 1 file changed, 8 insertions(+), 8 deletions(-) diff --git a/packages/core/src/auth/sso/ssoAccessTokenProvider.ts b/packages/core/src/auth/sso/ssoAccessTokenProvider.ts index bec13bed08c..edf460c6656 100644 --- a/packages/core/src/auth/sso/ssoAccessTokenProvider.ts +++ b/packages/core/src/auth/sso/ssoAccessTokenProvider.ts @@ -119,16 +119,16 @@ export abstract class SsoAccessTokenProvider { ) if (!data || !isExpired(data.token)) { - getLogger().debug(`getToken: token is valid, returning cached token (key=${this.tokenCacheKey})`) + getLogger().debug('Auth: token is valid, returning cached token (key=%s)', this.tokenCacheKey) return data?.token } getLogger().info( - `getToken: bearer token expired (expires at ${data.token.expiresAt}), attempting refresh (key=${this.tokenCacheKey})` + `Auth: bearer token expired (expires at ${data.token.expiresAt}), attempting refresh (key=${this.tokenCacheKey})` ) if (data.registration && !isExpired(data.registration) && hasProps(data.token, 'refreshToken')) { - getLogger().debug(`getToken: refresh token available, calling refreshToken() (key=${this.tokenCacheKey})`) + getLogger().debug(`Auth: refresh token available, calling refreshToken() (key=${this.tokenCacheKey})`) // Check if a refresh is already in progress for this token const existingRefresh = SsoAccessTokenProvider.refreshPromises.get(this.tokenCacheKey) if (existingRefresh) { @@ -209,17 +209,17 @@ export abstract class SsoAccessTokenProvider { try { const clientInfo = selectFrom(registration, 'clientId', 'clientSecret') - getLogger().debug(`refreshToken: calling OIDC createToken API (key=${this.tokenCacheKey})`) + getLogger().debug(`Auth refreshToken: calling OIDC createToken API (key=${this.tokenCacheKey})`) const response = await this.oidc.createToken({ ...clientInfo, ...token, grantType: refreshGrantType }) - getLogger().debug(`refreshToken: got response, now saving to cache...`) + getLogger().debug(`Auth refreshToken: got response, now saving to cache...`) const refreshed = this.formatToken(response, registration) getLogger().debug(`refreshToken: saving refreshed token to cache (key=${this.tokenCacheKey})`) await this.cache.token.save(this.tokenCacheKey, refreshed) getLogger().info( - `refreshToken: token refresh successful (key=${this.tokenCacheKey}, new expiry=${response.expiresAt})` + `Auth refreshToken: token refresh successful (key=${this.tokenCacheKey}, new expiry=${response.expiresAt})` ) telemetry.aws_refreshCredentials.emit({ result: 'Succeeded', @@ -230,7 +230,7 @@ export abstract class SsoAccessTokenProvider { return refreshed } catch (err) { getLogger().error( - `refreshToken: token refresh failed (key=${this.tokenCacheKey}): ${getErrorMsg(err as unknown as Error)}` + `Auth refreshToken: token refresh failed (key=${this.tokenCacheKey}): ${getErrorMsg(err as unknown as Error)}` ) if (err instanceof DiskCacheError) { @@ -247,7 +247,7 @@ export abstract class SsoAccessTokenProvider { * or at least hint for them to provide the logs in a bug report. */ getLogger().warn( - `refreshToken: DiskCacheError during refresh, not invalidating session (key=${this.tokenCacheKey})` + `Auth refreshToken: DiskCacheError during refresh, not invalidating session (key=${this.tokenCacheKey})` ) void DiskCacheErrorMessage.instance.showMessageThrottled(err) } else if (!isNetworkError(err)) {