Skip to content

Commit a2abc0a

Browse files
rkistnerrkistner
committed
Populate token details in error logs.
1 parent b0325c9 commit a2abc0a

File tree

6 files changed

+109
-21
lines changed

6 files changed

+109
-21
lines changed

‎packages/service-core/src/auth/KeyStore.ts‎

Lines changed: 5 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -73,7 +73,7 @@ export class KeyStore<Collector extends KeyCollector = KeyCollector> {
7373
throw new AuthorizationError(
7474
ErrorCode.PSYNC_S2105,
7575
`Unexpected "aud" claim value: ${JSON.stringify(tokenPayload.aud)}`,
76-
{ sensitiveDetails: `Current configuration allows these audience values: ${JSON.stringify(audiences)}` }
76+
{ configurationDetails: `Current configuration allows these audience values: ${JSON.stringify(audiences)}` }
7777
);
7878
}
7979

@@ -111,7 +111,7 @@ export class KeyStore<Collector extends KeyCollector = KeyCollector> {
111111
);
112112
return { result, keyOptions: keyOptions! };
113113
} catch (e) {
114-
throw mapAuthError(e);
114+
throw mapAuthError(e, token);
115115
}
116116
}
117117

@@ -125,7 +125,7 @@ export class KeyStore<Collector extends KeyCollector = KeyCollector> {
125125
if (key.kid == kid) {
126126
if (!key.matchesAlgorithm(header.alg)) {
127127
throw new AuthorizationError(ErrorCode.PSYNC_S2101, `Unexpected token algorithm ${header.alg}`, {
128-
sensitiveDetails: `Key kid: ${key.source.kid}, alg: ${key.source.alg}, kty: ${key.source.kty}`
128+
// Token details automatically populated elsewhere
129129
});
130130
}
131131
return key;
@@ -163,7 +163,8 @@ export class KeyStore<Collector extends KeyCollector = KeyCollector> {
163163
ErrorCode.PSYNC_S2101,
164164
'Could not find an appropriate key in the keystore. The key is missing or no key matched the token KID',
165165
{
166-
sensitiveDetails: `Token kid: ${kid}, token algorithm: ${header.alg}, known kid values: ${keys.map((key) => key.kid ?? '*').join(', ')}`
166+
configurationDetails: `Known kid values: ${keys.map((key) => key.kid ?? '*').join(', ')}`
167+
// tokenDetails automatically populated later
167168
}
168169
);
169170
}

‎packages/service-core/src/auth/RemoteJWKSCollector.ts‎

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -64,7 +64,7 @@ export class RemoteJWKSCollector implements KeyCollector {
6464

6565
if (!res.ok) {
6666
throw new AuthorizationError(ErrorCode.PSYNC_S2204, `JWKS request failed with ${res.statusText}`, {
67-
sensitiveDetails: `JWKS URL: ${this.url}`
67+
configurationDetails: `JWKS URL: ${this.url}`
6868
});
6969
}
7070

@@ -82,7 +82,7 @@ export class RemoteJWKSCollector implements KeyCollector {
8282
keys: [],
8383
errors: [
8484
new AuthorizationError(ErrorCode.PSYNC_S2204, `JWKS request failed with ${res.statusText}`, {
85-
sensitiveDetails: `JWKS URL: ${this.url}. Response:\n${JSON.stringify(data, null, 2)}`
85+
configurationDetails: `JWKS URL: ${this.url}. Response:\n${JSON.stringify(data, null, 2)}`
8686
})
8787
]
8888
};

‎packages/service-core/src/auth/utils.ts‎

Lines changed: 68 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -1,33 +1,45 @@
11
import { AuthorizationError, ErrorCode } from '@powersync/lib-services-framework';
22
import * as jose from 'jose';
33

4-
export function mapJoseError(error: jose.errors.JOSEError): AuthorizationError {
5-
// TODO: improved message for exp issues, etc
4+
export function mapJoseError(error: jose.errors.JOSEError, token: string): AuthorizationError {
5+
const tokenDetails = tokenDebugDetails(token);
66
if (error.code === jose.errors.JWSInvalid.code || error.code === jose.errors.JWTInvalid.code) {
7-
throw new AuthorizationError(ErrorCode.PSYNC_S2101, 'Token is not a well-formed JWT. Check the token format.', {
8-
details: error.message
7+
return new AuthorizationError(ErrorCode.PSYNC_S2101, 'Token is not a well-formed JWT. Check the token format.', {
8+
tokenDetails,
9+
cause: error
910
});
1011
} else if (error.code === jose.errors.JWTClaimValidationFailed.code) {
11-
// Example: missing required "sub" claim
12+
// Jose message: missing required "sub" claim
1213
const claim = (error as jose.errors.JWTClaimValidationFailed).claim;
13-
throw new AuthorizationError(
14+
return new AuthorizationError(
1415
ErrorCode.PSYNC_S2101,
1516
`JWT payload is missing a required claim ${JSON.stringify(claim)}`,
1617
{
17-
cause: error
18+
cause: error,
19+
tokenDetails
1820
}
1921
);
22+
} else if (error.code == jose.errors.JWTExpired.code) {
23+
// Jose message: "exp" claim timestamp check failed
24+
return new AuthorizationError(ErrorCode.PSYNC_S2103, `JWT has expired`, {
25+
cause: error,
26+
tokenDetails
27+
});
2028
}
2129
return new AuthorizationError(ErrorCode.PSYNC_S2101, error.message, { cause: error });
2230
}
2331

24-
export function mapAuthError(error: any): AuthorizationError {
32+
export function mapAuthError(error: any, token: string): AuthorizationError {
2533
if (error instanceof AuthorizationError) {
34+
error.tokenDetails ??= tokenDebugDetails(token);
2635
return error;
2736
} else if (error instanceof jose.errors.JOSEError) {
28-
return mapJoseError(error);
37+
return mapJoseError(error, token);
2938
}
30-
return new AuthorizationError(ErrorCode.PSYNC_S2101, error.message, { cause: error });
39+
return new AuthorizationError(ErrorCode.PSYNC_S2101, error.message, {
40+
cause: error,
41+
tokenDetails: tokenDebugDetails(token)
42+
});
3143
}
3244

3345
export function mapJoseConfigError(error: jose.errors.JOSEError): AuthorizationError {
@@ -42,3 +54,49 @@ export function mapAuthConfigError(error: any): AuthorizationError {
4254
}
4355
return new AuthorizationError(ErrorCode.PSYNC_S2201, error.message ?? 'Auth configuration error', { cause: error });
4456
}
57+
58+
/**
59+
* Decode token for debugging purposes.
60+
*
61+
* We use this to add details to our logs. We don't log the entire token, since it may for example
62+
* a password incorrectly used as a token.
63+
*/
64+
function tokenDebugDetails(token: string): string {
65+
try {
66+
// For valid tokens, we return the header and payload
67+
const header = jose.decodeProtectedHeader(token);
68+
const payload = jose.decodeJwt(token);
69+
return `<header: ${JSON.stringify(header)} payload: ${JSON.stringify(payload)}>`;
70+
} catch (e) {
71+
// Token fails to parse. Return some details.
72+
return invalidTokenDetails(token);
73+
}
74+
}
75+
76+
function invalidTokenDetails(token: string): string {
77+
const parts = token.split('.');
78+
if (parts.length !== 3) {
79+
return `<token with ${parts.length} parts (needs 3), length=${token.length}>`;
80+
}
81+
82+
const [headerB64, payloadB64, signatureB64] = parts;
83+
84+
try {
85+
JSON.parse(Buffer.from(headerB64, 'base64url').toString('utf8'));
86+
} catch (e) {
87+
return `<token with unparsable header>`;
88+
}
89+
90+
try {
91+
JSON.parse(Buffer.from(payloadB64, 'base64url').toString('utf8'));
92+
} catch (e) {
93+
return `<token with unparsable payload>`;
94+
}
95+
try {
96+
Buffer.from(signatureB64, 'base64url');
97+
} catch (e) {
98+
return `<token with unparsable signature>`;
99+
}
100+
101+
return `<invalid JWT, length=${token.length}>`;
102+
}

‎packages/service-core/src/routes/auth.ts‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -141,7 +141,7 @@ export async function generateContext(serviceContext: ServiceContext, token: str
141141
} catch (err) {
142142
return {
143143
context: null,
144-
tokenError: auth.mapAuthError(err)
144+
tokenError: auth.mapAuthError(err, token)
145145
};
146146
}
147147
}

‎packages/service-core/test/src/auth.test.ts‎

Lines changed: 18 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -105,6 +105,24 @@ describe('JWT Auth', () => {
105105
maxAge: '5m'
106106
})
107107
).rejects.toThrow('[PSYNC_S2101] JWT payload is missing a required claim "sub"');
108+
109+
// expired token
110+
const d = Math.round(Date.now() / 1000);
111+
const signedJwt3 = await new jose.SignJWT({})
112+
.setProtectedHeader({ alg: 'HS256', kid: 'k1' })
113+
.setSubject('f1')
114+
.setIssuedAt(d - 500)
115+
.setIssuer('tester')
116+
.setAudience('tests')
117+
.setExpirationTime(d - 400)
118+
.sign(signKey);
119+
120+
await expect(
121+
store.verifyJwt(signedJwt3, {
122+
defaultAudiences: ['tests'],
123+
maxAge: '5m'
124+
})
125+
).rejects.toThrow('[PSYNC_S2103] JWT has expired');
108126
});
109127

110128
test('Algorithm validation', async () => {
@@ -356,7 +374,6 @@ describe('JWT Auth', () => {
356374
await cached.addTimeForTests(0);
357375
response = await cached.getKeys();
358376
// Still have the cached key, but also have the error
359-
console.log('e', response.errors[0]);
360377
expect(response.keys[0].kid).toEqual(publicKeyRSA.kid!);
361378
expect(response.errors[0].message).toMatch('[PSYNC_S2201] refresh failed');
362379

‎packages/service-errors/src/errors.ts‎

Lines changed: 15 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -160,18 +160,30 @@ export class ReplicationAbortedError extends ServiceError {
160160
}
161161

162162
export class AuthorizationError extends ServiceError {
163+
/**
164+
* String describing the token. Does not contain the full token, but may help with debugging.
165+
* Safe for logs.
166+
*/
167+
tokenDetails: string | undefined;
168+
/**
169+
* String describing related configuration. Should never be returned to the client.
170+
* Safe for logs.
171+
*/
172+
configurationDetails: string | undefined;
173+
163174
constructor(
164175
code: ErrorCode,
165176
description: string,
166-
options?: Partial<ErrorData> & { sensitiveDetails?: string; cause?: any }
177+
options?: { tokenDetails?: string; configurationDetails?: string; cause?: any }
167178
) {
168179
super({
169180
code,
170181
status: 401,
171-
description,
172-
...options
182+
description
173183
});
174184
this.cause = this.cause;
185+
this.tokenDetails = options?.tokenDetails;
186+
this.configurationDetails = options?.configurationDetails;
175187
}
176188
}
177189

0 commit comments

Comments
 (0)