From 965db7352ddf401c323c33102a8cfda47e4f1b47 Mon Sep 17 00:00:00 2001 From: clauspeterhuebner Date: Thu, 17 Jul 2025 00:56:03 +0200 Subject: [PATCH] introduce method loggers for using addContext with handshakeID --- .../src/federation/authenticateCommunities.ts | 29 ++++---- .../1_0/resolver/AuthenticationResolver.ts | 71 +++++++++--------- .../api/1_0/util/authenticateCommunity.ts | 42 ++++++----- shared/src/jwt/JWT.test.ts | 8 +- shared/src/jwt/JWT.ts | 74 ++++++++++++------- 5 files changed, 125 insertions(+), 99 deletions(-) diff --git a/backend/src/federation/authenticateCommunities.ts b/backend/src/federation/authenticateCommunities.ts index bbfd3c2d6..d8946eb47 100644 --- a/backend/src/federation/authenticateCommunities.ts +++ b/backend/src/federation/authenticateCommunities.ts @@ -17,20 +17,21 @@ const logger = getLogger(`${LOG4JS_BASE_CATEGORY_NAME}.federation.authenticateCo export async function startCommunityAuthentication( fedComB: DbFederatedCommunity, ): Promise { + const methodLogger = getLogger(`${LOG4JS_BASE_CATEGORY_NAME}.federation.authenticateCommunities.startCommunityAuthentication`) const handshakeID = randombytes_random().toString() - logger.addContext('handshakeID', handshakeID) - logger.debug(`startCommunityAuthentication()...`, { + methodLogger.addContext('handshakeID', handshakeID) + methodLogger.debug(`startCommunityAuthentication()...`, { fedComB: new FederatedCommunityLoggingView(fedComB), }) const homeComA = await getHomeCommunity() - logger.debug('homeComA', new CommunityLoggingView(homeComA!)) + methodLogger.debug('homeComA', new CommunityLoggingView(homeComA!)) const homeFedComA = await DbFederatedCommunity.findOneByOrFail({ foreign: false, apiVersion: CONFIG.FEDERATION_BACKEND_SEND_ON_API, }) - logger.debug('homeFedComA', new FederatedCommunityLoggingView(homeFedComA)) + methodLogger.debug('homeFedComA', new FederatedCommunityLoggingView(homeFedComA)) const comB = await DbCommunity.findOneByOrFail({ publicKey: fedComB.publicKey }) - logger.debug('started with comB:', new CommunityLoggingView(comB)) + methodLogger.debug('started with comB:', new CommunityLoggingView(comB)) // check if communityUuid is not a valid v4Uuid try { if ( @@ -40,7 +41,7 @@ export async function startCommunityAuthentication( (!validateUUID(comB.communityUuid) || versionUUID(comB.communityUuid!) !== 4))) ) { - logger.debug('comB.uuid is null or is a not valid v4Uuid...', comB.communityUuid || 'null', comB.authenticatedAt || 'null') + methodLogger.debug('comB.uuid is null or is a not valid v4Uuid...', comB.communityUuid || 'null', comB.authenticatedAt || 'null') const client = AuthenticationClientFactory.getInstance(fedComB) if (client instanceof V1_0_AuthenticationClient) { @@ -51,27 +52,27 @@ export async function startCommunityAuthentication( const payload = new OpenConnectionJwtPayloadType(handshakeID, ensureUrlEndsWithSlash(homeFedComA.endPoint).concat(homeFedComA.apiVersion), ) - logger.debug('payload', payload) + methodLogger.debug('payload', payload) const jws = await encryptAndSign(payload, homeComA!.privateJwtKey!, comB.publicJwtKey!) - logger.debug('jws', jws) + methodLogger.debug('jws', jws) // prepare the args for the client invocation const args = new EncryptedTransferArgs() args.publicKey = homeComA!.publicKey.toString('hex') args.jwt = jws args.handshakeID = handshakeID - logger.debug('before client.openConnection() args:', args) + methodLogger.debug('before client.openConnection() args:', args) const result = await client.openConnection(args) if (result) { - logger.debug(`successful initiated at community:`, fedComB.endPoint) + methodLogger.debug(`successful initiated at community:`, fedComB.endPoint) } else { - logger.error(`can't initiate at community:`, fedComB.endPoint) + methodLogger.error(`can't initiate at community:`, fedComB.endPoint) } } } else { - logger.debug(`comB.communityUuid is already a valid v4Uuid ${ comB.communityUuid || 'null' } and was authenticated at ${ comB.authenticatedAt || 'null'}`) + methodLogger.debug(`comB.communityUuid is already a valid v4Uuid ${ comB.communityUuid || 'null' } and was authenticated at ${ comB.authenticatedAt || 'null'}`) } } catch (err) { - logger.error(`Error:`, err) + methodLogger.error(`Error:`, err) } - logger.removeContext('handshakeID') + methodLogger.removeContext('handshakeID') } diff --git a/federation/src/graphql/api/1_0/resolver/AuthenticationResolver.ts b/federation/src/graphql/api/1_0/resolver/AuthenticationResolver.ts index ae17ecc66..bfec30bc5 100644 --- a/federation/src/graphql/api/1_0/resolver/AuthenticationResolver.ts +++ b/federation/src/graphql/api/1_0/resolver/AuthenticationResolver.ts @@ -22,43 +22,44 @@ export class AuthenticationResolver { @Arg('data') args: EncryptedTransferArgs, ): Promise { - logger.addContext('handshakeID', args.handshakeID) - logger.debug(`openConnection() via apiVersion=1_0:`, args) + const methodLogger = getLogger(`${LOG4JS_BASE_CATEGORY_NAME}.graphql.api.1_0.resolver.AuthenticationResolver.openConnection`) + methodLogger.addContext('handshakeID', args.handshakeID) + methodLogger.debug(`openConnection() via apiVersion=1_0:`, args) const openConnectionJwtPayload = await interpretEncryptedTransferArgs(args) as OpenConnectionJwtPayloadType - logger.debug('openConnectionJwtPayload', openConnectionJwtPayload) + methodLogger.debug('openConnectionJwtPayload', openConnectionJwtPayload) if (!openConnectionJwtPayload) { const errmsg = `invalid OpenConnection payload of requesting community with publicKey` + args.publicKey - logger.error(errmsg) - logger.removeContext('handshakeID') + methodLogger.error(errmsg) + methodLogger.removeContext('handshakeID') throw new Error(errmsg) } if (openConnectionJwtPayload.tokentype !== OpenConnectionJwtPayloadType.OPEN_CONNECTION_TYPE) { const errmsg = `invalid tokentype of community with publicKey` + args.publicKey - logger.error(errmsg) - logger.removeContext('handshakeID') + methodLogger.error(errmsg) + methodLogger.removeContext('handshakeID') throw new Error(errmsg) } if (!openConnectionJwtPayload.url) { const errmsg = `invalid url of community with publicKey` + args.publicKey - logger.error(errmsg) - logger.removeContext('handshakeID') + methodLogger.error(errmsg) + methodLogger.removeContext('handshakeID') throw new Error(errmsg) } - logger.debug(`vor DbFedCommunity.findOneByOrFail()...`, { publicKey: args.publicKey }) + methodLogger.debug(`vor DbFedCommunity.findOneByOrFail()...`, { publicKey: args.publicKey }) const fedComA = await DbFedCommunity.findOneByOrFail({ publicKey: Buffer.from(args.publicKey, 'hex') }) - logger.debug(`nach DbFedCommunity.findOneByOrFail()...`, fedComA) - logger.debug('fedComA', new FederatedCommunityLoggingView(fedComA)) + methodLogger.debug(`nach DbFedCommunity.findOneByOrFail()...`, fedComA) + methodLogger.debug('fedComA', new FederatedCommunityLoggingView(fedComA)) if (!openConnectionJwtPayload.url.startsWith(fedComA.endPoint)) { const errmsg = `invalid url of community with publicKey` + args.publicKey - logger.error(errmsg) - logger.removeContext('handshakeID') + methodLogger.error(errmsg) + methodLogger.removeContext('handshakeID') throw new Error(errmsg) } // no await to respond immediately and invoke callback-request asynchronously void startOpenConnectionCallback(args.handshakeID, args.publicKey, CONFIG.FEDERATION_API) - logger.debug('openConnection() successfully initiated callback and returns true immediately...') - logger.removeContext('handshakeID') + methodLogger.debug('openConnection() successfully initiated callback and returns true immediately...') + methodLogger.removeContext('handshakeID') return true } @@ -67,35 +68,36 @@ export class AuthenticationResolver { @Arg('data') args: EncryptedTransferArgs, ): Promise { - logger.addContext('handshakeID', args.handshakeID) - logger.debug(`openConnectionCallback() via apiVersion=1_0 ...`, args) + const methodLogger = getLogger(`${LOG4JS_BASE_CATEGORY_NAME}.graphql.api.1_0.resolver.AuthenticationResolver.openConnectionCallback`) + methodLogger.addContext('handshakeID', args.handshakeID) + methodLogger.debug(`openConnectionCallback() via apiVersion=1_0 ...`, args) // decrypt args.url with homeCom.privateJwtKey and verify signing with callbackFedCom.publicKey const openConnectionCallbackJwtPayload = await interpretEncryptedTransferArgs(args) as OpenConnectionCallbackJwtPayloadType if (!openConnectionCallbackJwtPayload) { const errmsg = `invalid OpenConnectionCallback payload of requesting community with publicKey` + args.publicKey - logger.error(errmsg) - logger.removeContext('handshakeID') + methodLogger.error(errmsg) + methodLogger.removeContext('handshakeID') throw new Error(errmsg) } const endPoint = openConnectionCallbackJwtPayload.url.slice(0, openConnectionCallbackJwtPayload.url.lastIndexOf('/') + 1) const apiVersion = openConnectionCallbackJwtPayload.url.slice(openConnectionCallbackJwtPayload.url.lastIndexOf('/') + 1, openConnectionCallbackJwtPayload.url.length) - logger.debug(`search fedComB per:`, endPoint, apiVersion) + methodLogger.debug(`search fedComB per:`, endPoint, apiVersion) const fedComB = await DbFedCommunity.findOneBy({ endPoint, apiVersion }) if (!fedComB) { const errmsg = `unknown callback community with url` + openConnectionCallbackJwtPayload.url - logger.error(errmsg) - logger.removeContext('handshakeID') + methodLogger.error(errmsg) + methodLogger.removeContext('handshakeID') throw new Error(errmsg) } - logger.debug( + methodLogger.debug( `found fedComB and start authentication:`, new FederatedCommunityLoggingView(fedComB), ) // no await to respond immediately and invoke authenticate-request asynchronously void startAuthentication(args.handshakeID, openConnectionCallbackJwtPayload.oneTimeCode, fedComB) - logger.debug('openConnectionCallback() successfully initiated authentication and returns true immediately...') - logger.removeContext('handshakeID') + methodLogger.debug('openConnectionCallback() successfully initiated authentication and returns true immediately...') + methodLogger.removeContext('handshakeID') return true } @@ -104,31 +106,32 @@ export class AuthenticationResolver { @Arg('data') args: EncryptedTransferArgs, ): Promise { - logger.addContext('handshakeID', args.handshakeID) - logger.debug(`authenticate() via apiVersion=1_0 ...`, args) + const methodLogger = getLogger(`${LOG4JS_BASE_CATEGORY_NAME}.graphql.api.1_0.resolver.AuthenticationResolver.authenticate`) + methodLogger.addContext('handshakeID', args.handshakeID) + methodLogger.debug(`authenticate() via apiVersion=1_0 ...`, args) const authArgs = await interpretEncryptedTransferArgs(args) as AuthenticationJwtPayloadType if (!authArgs) { const errmsg = `invalid authentication payload of requesting community with publicKey` + args.publicKey - logger.error(errmsg) - logger.removeContext('handshakeID') + methodLogger.error(errmsg) + methodLogger.removeContext('handshakeID') throw new Error(errmsg) } const authCom = await DbCommunity.findOneByOrFail({ communityUuid: authArgs.oneTimeCode }) - logger.debug('found authCom:', new CommunityLoggingView(authCom)) + methodLogger.debug('found authCom:', new CommunityLoggingView(authCom)) if (authCom) { authCom.communityUuid = authArgs.uuid authCom.authenticatedAt = new Date() await DbCommunity.save(authCom) - logger.debug('store authCom.uuid successfully:', new CommunityLoggingView(authCom)) + methodLogger.debug('store authCom.uuid successfully:', new CommunityLoggingView(authCom)) const homeComB = await getHomeCommunity() if (homeComB?.communityUuid) { const responseArgs = new AuthenticationResponseJwtPayloadType(args.handshakeID,homeComB.communityUuid) const responseJwt = await encryptAndSign(responseArgs, homeComB.privateJwtKey!, authCom.publicJwtKey!) - logger.removeContext('handshakeID') + methodLogger.removeContext('handshakeID') return responseJwt } } - logger.removeContext('handshakeID') + methodLogger.removeContext('handshakeID') return null } } diff --git a/federation/src/graphql/api/1_0/util/authenticateCommunity.ts b/federation/src/graphql/api/1_0/util/authenticateCommunity.ts index fdf97379d..c51546c15 100644 --- a/federation/src/graphql/api/1_0/util/authenticateCommunity.ts +++ b/federation/src/graphql/api/1_0/util/authenticateCommunity.ts @@ -23,8 +23,9 @@ export async function startOpenConnectionCallback( publicKey: string, api: string, ): Promise { - logger.addContext('handshakeID', handshakeID) - logger.debug(`Authentication: startOpenConnectionCallback() with:`, { + const methodLogger = getLogger(`${LOG4JS_BASE_CATEGORY_NAME}.graphql.api.1_0.util.authenticateCommunity.startOpenConnectionCallback`) + methodLogger.addContext('handshakeID', handshakeID) + methodLogger.debug(`Authentication: startOpenConnectionCallback() with:`, { publicKey, }) try { @@ -43,7 +44,7 @@ export async function startOpenConnectionCallback( // store oneTimeCode in requestedCom.community_uuid as authenticate-request-identifier comA.communityUuid = oneTimeCode await DbCommunity.save(comA) - logger.debug( + methodLogger.debug( `Authentication: stored oneTimeCode in requestedCom:`, new CommunityLoggingView(comA), ) @@ -56,7 +57,7 @@ export async function startOpenConnectionCallback( : homeFedComB.endPoint + '/' + homeFedComB.apiVersion const callbackArgs = new OpenConnectionCallbackJwtPayloadType(handshakeID, oneTimeCode, url) - logger.debug(`Authentication: start openConnectionCallback with args:`, callbackArgs) + methodLogger.debug(`Authentication: start openConnectionCallback with args:`, callbackArgs) // encrypt callbackArgs with requestedCom.publicJwtKey and sign it with homeCom.privateJwtKey const jwt = await encryptAndSign(callbackArgs, homeComB!.privateJwtKey!, comA.publicJwtKey!) const args = new EncryptedTransferArgs() @@ -65,15 +66,15 @@ export async function startOpenConnectionCallback( args.handshakeID = handshakeID const result = await client.openConnectionCallback(args) if (result) { - logger.debug('startOpenConnectionCallback() successful:', jwt) + methodLogger.debug('startOpenConnectionCallback() successful:', jwt) } else { - logger.error('startOpenConnectionCallback() failed:', jwt) + methodLogger.error('startOpenConnectionCallback() failed:', jwt) } } } catch (err) { - logger.error('error in startOpenConnectionCallback:', err) + methodLogger.error('error in startOpenConnectionCallback:', err) } - logger.removeContext('handshakeID') + methodLogger.removeContext('handshakeID') } export async function startAuthentication( @@ -81,8 +82,9 @@ export async function startAuthentication( oneTimeCode: string, fedComB: DbFedCommunity, ): Promise { - logger.addContext('handshakeID', handshakeID) - logger.debug(`startAuthentication()...`, { + const methodLogger = getLogger(`${LOG4JS_BASE_CATEGORY_NAME}.graphql.api.1_0.util.authenticateCommunity.startAuthentication`) + methodLogger.addContext('handshakeID', handshakeID) + methodLogger.debug(`startAuthentication()...`, { oneTimeCode, fedComB: new FederatedCommunityLoggingView(fedComB), }) @@ -106,36 +108,38 @@ export async function startAuthentication( args.publicKey = homeComA!.publicKey.toString('hex') args.jwt = jwt args.handshakeID = handshakeID - logger.debug(`invoke authenticate() with:`, args) + methodLogger.debug(`invoke authenticate() with:`, args) const responseJwt = await client.authenticate(args) - logger.debug(`response of authenticate():`, responseJwt) + methodLogger.debug(`response of authenticate():`, responseJwt) if (responseJwt !== null) { const payload = await verifyAndDecrypt(handshakeID, responseJwt, homeComA!.privateJwtKey!, comB.publicJwtKey!) as AuthenticationResponseJwtPayloadType - logger.debug( + methodLogger.debug( `received payload from authenticate ComB:`, payload, new FederatedCommunityLoggingView(fedComB), ) if (payload.tokentype !== AuthenticationResponseJwtPayloadType.AUTHENTICATION_RESPONSE_TYPE) { const errmsg = `Invalid tokentype in authenticate-response of community with publicKey` + comB.publicKey - logger.error(errmsg) + methodLogger.error(errmsg) + methodLogger.removeContext('handshakeID') throw new Error(errmsg) } if (!payload.uuid || !validateUUID(payload.uuid) || versionUUID(payload.uuid) !== 4) { const errmsg = `Invalid uuid in authenticate-response of community with publicKey` + comB.publicKey - logger.error(errmsg) + methodLogger.error(errmsg) + methodLogger.removeContext('handshakeID') throw new Error(errmsg) } comB.communityUuid = payload.uuid comB.authenticatedAt = new Date() await DbCommunity.save(comB) - logger.debug('Community Authentication successful:', new CommunityLoggingView(comB)) + methodLogger.debug('Community Authentication successful:', new CommunityLoggingView(comB)) } else { - logger.error('Community Authentication failed:', authenticationArgs) + methodLogger.error('Community Authentication failed:', authenticationArgs) } } } catch (err) { - logger.error('error in startAuthentication:', err) + methodLogger.error('error in startAuthentication:', err) } - logger.removeContext('handshakeID') + methodLogger.removeContext('handshakeID') } diff --git a/shared/src/jwt/JWT.test.ts b/shared/src/jwt/JWT.test.ts index 7c9950cb4..05a143298 100644 --- a/shared/src/jwt/JWT.test.ts +++ b/shared/src/jwt/JWT.test.ts @@ -84,7 +84,7 @@ describe('test JWE encryption and decryption', () => { jweComB = await encrypt(new OpenConnectionJwtPayloadType('handshakeID', 'http://localhost:5002/api/'), keypairComA.publicKey) }) it('decrypt jweComA', async () => { - const decryptedAJwT = await decrypt(jweComA, keypairComB.privateKey) + const decryptedAJwT = await decrypt('handshakeID', jweComA, keypairComB.privateKey) expect(JSON.parse(decryptedAJwT)).toEqual(expect.objectContaining({ tokentype: OpenConnectionJwtPayloadType.OPEN_CONNECTION_TYPE, url: 'http://localhost:5001/api/', @@ -92,7 +92,7 @@ describe('test JWE encryption and decryption', () => { })) }) it('decrypt jweComB', async () => { - const decryptedBJwT = await decrypt(jweComB, keypairComA.privateKey) + const decryptedBJwT = await decrypt('handshakeID', jweComB, keypairComA.privateKey) expect(JSON.parse(decryptedBJwT)).toEqual(expect.objectContaining({ tokentype: OpenConnectionJwtPayloadType.OPEN_CONNECTION_TYPE, url: 'http://localhost:5002/api/', @@ -134,14 +134,14 @@ describe('test encrypted and signed JWT', () => { })) }) it('decrypt jweComA', async () => { - expect(JSON.parse(await decrypt(jweComA, keypairComB.privateKey))).toEqual(expect.objectContaining({ + expect(JSON.parse(await decrypt('handshakeID', jweComA, keypairComB.privateKey))).toEqual(expect.objectContaining({ tokentype: OpenConnectionJwtPayloadType.OPEN_CONNECTION_TYPE, url: 'http://localhost:5001/api/', handshakeID: 'handshakeID', })) }) it('decrypt jweComB', async () => { - expect(JSON.parse(await decrypt(jweComB, keypairComA.privateKey))).toEqual(expect.objectContaining({ + expect(JSON.parse(await decrypt('handshakeID', jweComB, keypairComA.privateKey))).toEqual(expect.objectContaining({ tokentype: OpenConnectionJwtPayloadType.OPEN_CONNECTION_TYPE, url: 'http://localhost:5002/api/', handshakeID: 'handshakeID', diff --git a/shared/src/jwt/JWT.ts b/shared/src/jwt/JWT.ts index 362fa85e3..1af50f5bd 100644 --- a/shared/src/jwt/JWT.ts +++ b/shared/src/jwt/JWT.ts @@ -22,11 +22,13 @@ export const createKeyPair = async (): Promise<{ publicKey: string; privateKey: } export const verify = async (handshakeID: string, token: string, publicKey: string): Promise => { + const methodLogger = getLogger(`${LOG4JS_BASE_CATEGORY_NAME}.auth.jwt.JWT.verify`) + methodLogger.addContext('handshakeID', handshakeID) if (!token) { - logger.error('verify... token is empty') + methodLogger.error('verify... token is empty') throw new Error('401 Unauthorized') } - logger.debug('verify... token, publicKey=', token, publicKey) + methodLogger.debug('verify... token, publicKey=', token, publicKey) try { const importedKey = await importSPKI(publicKey, 'RS256') @@ -40,17 +42,21 @@ export const verify = async (handshakeID: string, token: string, publicKey: stri audience: JwtPayloadType.AUDIENCE, }) payload.handshakeID = handshakeID - logger.debug('verify after jwtVerify... payload=', payload) + methodLogger.debug('verify after jwtVerify... payload=', payload) + methodLogger.removeContext('handshakeID') return payload as JwtPayloadType } catch (err) { - logger.error('verify after jwtVerify... error=', err) + methodLogger.error('verify after jwtVerify... error=', err) + methodLogger.removeContext('handshakeID') return null } } export const encode = async (payload: JwtPayloadType, privatekey: string): Promise => { - logger.debug('encode... payload=', payload) - logger.debug('encode... privatekey=', privatekey.substring(0, 10)) + const methodLogger = getLogger(`${LOG4JS_BASE_CATEGORY_NAME}.auth.jwt.JWT.encode`) + methodLogger.addContext('handshakeID', payload.handshakeID) + methodLogger.debug('encode... payload=', payload) + methodLogger.debug('encode... privatekey=', privatekey.substring(0, 20)) try { const importedKey = await importPKCS8(privatekey, 'RS256') const secret = typeof importedKey === 'string' @@ -67,9 +73,12 @@ export const encode = async (payload: JwtPayloadType, privatekey: string): Promi .setAudience(JwtPayloadType.AUDIENCE) .setExpirationTime(payload.expiration) .sign(secret) + methodLogger.debug('encode... token=', token) + methodLogger.removeContext('handshakeID') return token } catch (e) { - logger.error('Failed to sign JWT:', e) + methodLogger.error('Failed to sign JWT:', e) + methodLogger.removeContext('handshakeID') throw e } } @@ -85,9 +94,10 @@ export const decode = (token: string): JwtPayloadType => { } export const encrypt = async (payload: JwtPayloadType, publicKey: string): Promise => { - logger.addContext('handshakeID', payload.handshakeID) - logger.debug('encrypt... payload=', payload) - logger.debug('encrypt... publicKey=', publicKey) + const methodLogger = getLogger(`${LOG4JS_BASE_CATEGORY_NAME}.auth.jwt.JWT.encrypt`) + methodLogger.addContext('handshakeID', payload.handshakeID) + methodLogger.debug('encrypt... payload=', payload) + methodLogger.debug('encrypt... publicKey=', publicKey) try { const encryptKey = await importSPKI(publicKey, 'RSA-OAEP-256') // Convert the key to JWK format if needed @@ -100,48 +110,56 @@ export const encrypt = async (payload: JwtPayloadType, publicKey: string): Promi ) .setProtectedHeader({ alg: 'RSA-OAEP-256', enc: 'A256GCM' }) .encrypt(recipientKey) - logger.debug('encrypt... jwe=', jwe) + methodLogger.debug('encrypt... jwe=', jwe) + methodLogger.removeContext('handshakeID') return jwe.toString() } catch (e) { - logger.error('Failed to encrypt JWT:', e) + methodLogger.error('Failed to encrypt JWT:', e) + methodLogger.removeContext('handshakeID') throw e } } -export const decrypt = async(jwe: string, privateKey: string): Promise => { - logger.debug('decrypt... jwe=', jwe) - logger.debug('decrypt... privateKey=', privateKey.substring(0, 10)) +export const decrypt = async(handshakeID: string, jwe: string, privateKey: string): Promise => { + const methodLogger = getLogger(`${LOG4JS_BASE_CATEGORY_NAME}.auth.jwt.JWT.decrypt`) + methodLogger.addContext('handshakeID', handshakeID) + methodLogger.debug('decrypt... jwe=', jwe) + methodLogger.debug('decrypt... privateKey=', privateKey.substring(0, 10)) try { const decryptKey = await importPKCS8(privateKey, 'RSA-OAEP-256') const { plaintext, protectedHeader } = await compactDecrypt(jwe, decryptKey) - logger.debug('decrypt... plaintext=', plaintext) - logger.debug('decrypt... protectedHeader=', protectedHeader) + methodLogger.debug('decrypt... plaintext=', plaintext) + methodLogger.debug('decrypt... protectedHeader=', protectedHeader) + methodLogger.removeContext('handshakeID') return new TextDecoder().decode(plaintext) } catch (e) { - logger.error('Failed to decrypt JWT:', e) + methodLogger.error('Failed to decrypt JWT:', e) + methodLogger.removeContext('handshakeID') throw e } } export const encryptAndSign = async (payload: JwtPayloadType, privateKey: string, publicKey: string): Promise => { - logger.addContext('handshakeID', payload.handshakeID) + const methodLogger = getLogger(`${LOG4JS_BASE_CATEGORY_NAME}.auth.jwt.JWT.encryptAndSign`) + methodLogger.addContext('handshakeID', payload.handshakeID) const jwe = await encrypt(payload, publicKey) - logger.debug('encryptAndSign... jwe=', jwe) + methodLogger.debug('encryptAndSign... jwe=', jwe) const jws = await encode(new EncryptedJWEJwtPayloadType(payload.handshakeID, jwe), privateKey) - logger.debug('encryptAndSign... jws=', jws) - logger.removeContext('handshakeID') + methodLogger.debug('encryptAndSign... jws=', jws) + methodLogger.removeContext('handshakeID') return jws } export const verifyAndDecrypt = async (handshakeID: string, token: string, privateKey: string, publicKey: string): Promise => { - logger.addContext('handshakeID', handshakeID) + const methodLogger = getLogger(`${LOG4JS_BASE_CATEGORY_NAME}.auth.jwt.JWT.verifyAndDecrypt`) + methodLogger.addContext('handshakeID', handshakeID) const jweVerifyResult = await verify(handshakeID, token, publicKey) if (!jweVerifyResult) { return null } const jwePayload = jweVerifyResult.payload as EncryptedJWEJwtPayloadType - logger.debug('verifyAndDecrypt... jwePayload=', jwePayload) + methodLogger.debug('verifyAndDecrypt... jwePayload=', jwePayload) if (!jwePayload) { return null } @@ -150,9 +168,9 @@ export const verifyAndDecrypt = async (handshakeID: string, token: string, priva return null } const jwe = jwePayload.jwe - logger.debug('verifyAndDecrypt... jwe=', jwe) - const payload = await decrypt(jwe as string, privateKey) - logger.debug('verifyAndDecrypt... payload=', payload) - logger.removeContext('handshakeID') + methodLogger.debug('verifyAndDecrypt... jwe=', jwe) + const payload = await decrypt(handshakeID, jwe as string, privateKey) + methodLogger.debug('verifyAndDecrypt... payload=', payload) + methodLogger.removeContext('handshakeID') return JSON.parse(payload) as JwtPayloadType }