From 3e376c44e3a6c336dcff3d8ef5eb3ab040d9a561 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Karol=20S=C3=B3jko?= Date: Fri, 3 Nov 2023 11:23:02 +0100 Subject: [PATCH] fix: retry attempts on session validation and more verbose logs (#898) --- .../src/Controller/AuthMiddleware.ts | 22 ++++++++++++++----- .../src/Service/Http/HttpServiceProxy.ts | 5 ++--- .../src/Service/Http/ServiceProxyInterface.ts | 8 ++++++- .../Service/Proxy/DirectCallServiceProxy.ts | 11 ++++++---- .../src/Domain/UseCase/AuthenticateRequest.ts | 6 +++-- .../Domain/UseCase/AuthenticateUser.spec.ts | 2 ++ .../src/Domain/UseCase/AuthenticateUser.ts | 18 ++++++++++----- 7 files changed, 50 insertions(+), 22 deletions(-) diff --git a/packages/api-gateway/src/Controller/AuthMiddleware.ts b/packages/api-gateway/src/Controller/AuthMiddleware.ts index 40b00618e..f7bf76bd9 100644 --- a/packages/api-gateway/src/Controller/AuthMiddleware.ts +++ b/packages/api-gateway/src/Controller/AuthMiddleware.ts @@ -74,13 +74,16 @@ export abstract class AuthMiddleware extends BaseMiddleware { response.locals.sharedVaultOwnerContext = decodedToken.shared_vault_owner_context response.locals.belongsToSharedVaults = decodedToken.belongs_to_shared_vaults ?? [] } catch (error) { - const errorMessage = (error as AxiosError).isAxiosError - ? JSON.stringify((error as AxiosError).response?.data) - : (error as Error).message + let detailedErrorMessage = (error as Error).message + if (error instanceof AxiosError) { + detailedErrorMessage = `Status: ${error.status}, code: ${error.code}, message: ${error.message}` + } - this.logger.error(`Could not pass the request to sessions/validate on underlying service: ${errorMessage}`) + this.logger.error( + `Could not pass the request to sessions/validate on underlying service: ${detailedErrorMessage}`, + ) - this.logger.debug('Response error: %O', (error as AxiosError).response ?? error) + this.logger.debug(`Response error: ${JSON.stringify(error)}`) if ((error as AxiosError).response?.headers['content-type']) { response.setHeader('content-type', (error as AxiosError).response?.headers['content-type'] as string) @@ -91,7 +94,14 @@ export abstract class AuthMiddleware extends BaseMiddleware { ? +((error as AxiosError).code as string) : 500 - response.status(errorCode).send(errorMessage) + const responseErrorMessage = (error as AxiosError).response?.data + + response + .status(errorCode) + .send( + responseErrorMessage ?? + "Unfortunately, we couldn't handle your request. Please try again or contact our support if the error persists.", + ) return } diff --git a/packages/api-gateway/src/Service/Http/HttpServiceProxy.ts b/packages/api-gateway/src/Service/Http/HttpServiceProxy.ts index f70c06652..6c233a442 100644 --- a/packages/api-gateway/src/Service/Http/HttpServiceProxy.ts +++ b/packages/api-gateway/src/Service/Http/HttpServiceProxy.ts @@ -55,10 +55,9 @@ export class HttpServiceProxy implements ServiceProxyInterface { }, } } catch (error) { - const requestTimedOut = - 'code' in (error as Record) && (error as Record).code === 'ETIMEDOUT' + const requestDidNotMakeIt = this.requestTimedOutOrDidNotReachDestination(error as Record) const tooManyRetryAttempts = retryAttempt && retryAttempt > 2 - if (!tooManyRetryAttempts && requestTimedOut) { + if (!tooManyRetryAttempts && requestDidNotMakeIt) { await this.timer.sleep(50) const nextRetryAttempt = retryAttempt ? retryAttempt + 1 : 1 diff --git a/packages/api-gateway/src/Service/Http/ServiceProxyInterface.ts b/packages/api-gateway/src/Service/Http/ServiceProxyInterface.ts index e7f51cc28..7371c288d 100644 --- a/packages/api-gateway/src/Service/Http/ServiceProxyInterface.ts +++ b/packages/api-gateway/src/Service/Http/ServiceProxyInterface.ts @@ -50,7 +50,13 @@ export interface ServiceProxyInterface { endpointOrMethodIdentifier: string, payload?: Record | string, ): Promise - validateSession(headers: { authorization: string; sharedVaultOwnerContext?: string }): Promise<{ + validateSession( + headers: { + authorization: string + sharedVaultOwnerContext?: string + }, + retryAttempt?: number, + ): Promise<{ status: number data: unknown headers: { diff --git a/packages/api-gateway/src/Service/Proxy/DirectCallServiceProxy.ts b/packages/api-gateway/src/Service/Proxy/DirectCallServiceProxy.ts index fb65eb6b0..fdcf4c1c1 100644 --- a/packages/api-gateway/src/Service/Proxy/DirectCallServiceProxy.ts +++ b/packages/api-gateway/src/Service/Proxy/DirectCallServiceProxy.ts @@ -9,10 +9,13 @@ export class DirectCallServiceProxy implements ServiceProxyInterface { private filesServerUrl: string, ) {} - async validateSession(headers: { - authorization: string - sharedVaultOwnerContext?: string - }): Promise<{ status: number; data: unknown; headers: { contentType: string } }> { + async validateSession( + headers: { + authorization: string + sharedVaultOwnerContext?: string + }, + _retryAttempt?: number, + ): Promise<{ status: number; data: unknown; headers: { contentType: string } }> { const authService = this.serviceContainer.get(ServiceIdentifier.create(ServiceIdentifier.NAMES.Auth).getValue()) if (!authService) { throw new Error('Auth service not found') diff --git a/packages/auth/src/Domain/UseCase/AuthenticateRequest.ts b/packages/auth/src/Domain/UseCase/AuthenticateRequest.ts index d3e44c691..b6edac68e 100644 --- a/packages/auth/src/Domain/UseCase/AuthenticateRequest.ts +++ b/packages/auth/src/Domain/UseCase/AuthenticateRequest.ts @@ -16,7 +16,7 @@ export class AuthenticateRequest implements UseCaseInterface { async execute(dto: AuthenticateRequestDTO): Promise { if (!dto.authorizationHeader) { - this.logger.debug('Authorization header not provided.') + this.logger.debug('[authenticate-request] Authorization header not provided.') return { success: false, @@ -32,7 +32,9 @@ export class AuthenticateRequest implements UseCaseInterface { token: dto.authorizationHeader.replace('Bearer ', ''), }) } catch (error) { - this.logger.error('Error occurred during authentication of a user %o', error) + this.logger.error( + `[authenticate-request] Error occurred during authentication of a user ${(error as Error).message}`, + ) return { success: false, diff --git a/packages/auth/src/Domain/UseCase/AuthenticateUser.spec.ts b/packages/auth/src/Domain/UseCase/AuthenticateUser.spec.ts index 571d122c4..2df8ef75d 100644 --- a/packages/auth/src/Domain/UseCase/AuthenticateUser.spec.ts +++ b/packages/auth/src/Domain/UseCase/AuthenticateUser.spec.ts @@ -23,6 +23,8 @@ describe('AuthenticateUser', () => { beforeEach(() => { logger = {} as jest.Mocked logger.debug = jest.fn() + logger.error = jest.fn() + logger.warn = jest.fn() user = {} as jest.Mocked user.supportsSessions = jest.fn().mockReturnValue(false) diff --git a/packages/auth/src/Domain/UseCase/AuthenticateUser.ts b/packages/auth/src/Domain/UseCase/AuthenticateUser.ts index 17bcbb2e9..ead06f0eb 100644 --- a/packages/auth/src/Domain/UseCase/AuthenticateUser.ts +++ b/packages/auth/src/Domain/UseCase/AuthenticateUser.ts @@ -24,7 +24,7 @@ export class AuthenticateUser implements UseCaseInterface { async execute(dto: AuthenticateUserDTO): Promise { const authenticationMethod = await this.authenticationMethodResolver.resolve(dto.token) if (!authenticationMethod) { - this.logger.debug('No authentication method found for token.') + this.logger.error(`[authenticate-user] No authentication method found for token: ${dto.token}`) return { success: false, @@ -33,6 +33,8 @@ export class AuthenticateUser implements UseCaseInterface { } if (authenticationMethod.type === 'revoked') { + this.logger.warn(`[authenticate-user] Session has been revoked: ${dto.token}`) + return { success: false, failureType: 'REVOKED_SESSION', @@ -41,7 +43,7 @@ export class AuthenticateUser implements UseCaseInterface { const user = authenticationMethod.user if (!user) { - this.logger.debug('No user found for authentication method.') + this.logger.error(`[authenticate-user] No user found for authentication method. Token: ${dto.token}`) return { success: false, @@ -50,7 +52,9 @@ export class AuthenticateUser implements UseCaseInterface { } if (authenticationMethod.type == 'jwt' && user.supportsSessions()) { - this.logger.debug('User supports sessions but is trying to authenticate with a JWT.') + this.logger.error( + `[authenticate-user][${user.uuid}] User supports sessions but is trying to authenticate with a JWT.`, + ) return { success: false, @@ -64,7 +68,7 @@ export class AuthenticateUser implements UseCaseInterface { const encryptedPasswordDigest = crypto.createHash('sha256').update(user.encryptedPassword).digest('hex') if (!pwHash || !crypto.timingSafeEqual(Buffer.from(pwHash), Buffer.from(encryptedPasswordDigest))) { - this.logger.debug('Password hash does not match.') + this.logger.error(`[authenticate-user][${user.uuid}] Password hash does not match.`) return { success: false, @@ -76,7 +80,7 @@ export class AuthenticateUser implements UseCaseInterface { case 'session_token': { const session = authenticationMethod.session if (!session) { - this.logger.debug('No session found for authentication method.') + this.logger.error(`[authenticate-user][${user.uuid}] No session found for authentication method.`) return { success: false, @@ -85,7 +89,7 @@ export class AuthenticateUser implements UseCaseInterface { } if (session.refreshExpiration < this.timer.getUTCDate()) { - this.logger.debug('Session refresh token has expired.') + this.logger.warn(`[authenticate-user][${user.uuid}] Session refresh token has expired.`) return { success: false, @@ -94,6 +98,8 @@ export class AuthenticateUser implements UseCaseInterface { } if (this.sessionIsExpired(session)) { + this.logger.warn(`[authenticate-user][${user.uuid}] Session access token has expired.`) + return { success: false, failureType: 'EXPIRED_TOKEN',