diff --git a/PACKAGES.md b/PACKAGES.md index 7352f52..935e983 100644 --- a/PACKAGES.md +++ b/PACKAGES.md @@ -134,3 +134,32 @@ Personal and work/school accounts are supported; verified email can participate in same-email linking. Unverified email does not establish an account match. [Microsoft configuration and identity checks](examples/better-auth/README.md#microsoft) include the optional ID-token claims needed for email matching. + +## Structured diagnostics + +`pgstencil/diagnostics` provides opt-in JSON diagnostics without a logging dependency. +Wrap your outer request handler with `observeRequest(request, { revision: buildSha }, +async () => app.fetch(request, env, ctx))`. Node `createAuthApp` and the Better Auth +Workers adapter also accept `diagnostics: {}` when no outer wrapper is needed. +Nested wrappers reuse one server-generated UUID, returned in `X-Request-ID`. +Failed OAuth redirects include `request_id` for support; it grants no authority. + +Auth records distinguish state validation, token exchange, key fetching, ID-token +and profile checks, login, logout, rejection and email delivery. Stripe records +verified webhook receipt, committed processing and failures, including the Stripe +event ID. For jobs and webhooks outside a request wrapper, use +`withDiagnostics(options, () => billing.handleWebhook(...))`. The database webhook +ledger remains the durable record; logs are diagnostic and may expire or be lost. + +Only enumerated categories, bounded numbers, booleans and validated correlation +identifiers are emitted. No raw paths, query strings, request bodies, headers, +emails, tokens, SQL, error messages or stacks are serialized. Token-check flags +are untrusted diagnostic hints; they never change authentication decisions. +The default sink writes JSON to console. Cloudflare hosts should enable Workers +Logs, disable automatic invocation logs, and enable query-string redaction. +Other application/platform logging must be configured separately. + +Tests can inject `sink`, `time: DevTime`, and `requestId`. AsyncLocalStorage isolates +concurrent requests; there are no global time patches. Logging sink failures are +ignored so they cannot change authentication or payment outcomes. Successful +static requests are omitted; API completions include status and elapsed time. diff --git a/packages/auth/src/better-auth-oauth.ts b/packages/auth/src/better-auth-oauth.ts index 66695eb..8793f63 100644 --- a/packages/auth/src/better-auth-oauth.ts +++ b/packages/auth/src/better-auth-oauth.ts @@ -1,3 +1,9 @@ +import { + diagnostic, + diagnosticError, + diagnosticRequestId, + type DiagnosticFields, +} from 'pgstencil/diagnostics'; import type { BetterAuthOptions, BetterAuthPlugin } from 'better-auth'; import { verifyProviderIdToken } from 'better-auth/oauth2'; import type { GithubProfile } from 'better-auth/social-providers'; @@ -31,6 +37,26 @@ export const verifiedOidc: BetterAuthPlugin = { id: 'pgstencil-verified-oidc', init(context) { for (const provider of context.socialProviders) { + const name = provider.id as Provider; + const exchange = provider.validateAuthorizationCode.bind(provider); + provider.validateAuthorizationCode = async (data) => { + try { + const tokens = await exchange(data); + diagnostic('auth.oauth.stage', { + provider: name, + stage: 'token_exchange', + }); + return tokens; + } catch (error) { + diagnostic('auth.oauth.failed', { + provider: name, + stage: 'token_exchange', + reason: 'upstream_failure', + ...diagnosticError(error), + }); + throw error; + } + }; if (!['google', 'apple', 'microsoft'].includes(provider.id)) continue; provider.requiresIdTokenNonce = true; if (provider.id !== 'microsoft') @@ -38,8 +64,25 @@ export const verifiedOidc: BetterAuthPlugin = { provider.id === 'google' ? 'https://accounts.google.com' : 'https://appleid.apple.com'; - if (provider.idToken && 'jwks' in provider.idToken) + if (provider.idToken && 'jwks' in provider.idToken) { provider.idToken.algorithms = ['RS256']; + if (typeof provider.idToken.jwks === 'function') { + const keys = provider.idToken.jwks; + provider.idToken.jwks = async (...args) => { + try { + return await keys(...args); + } catch (error) { + diagnostic('auth.oauth.failed', { + provider: name, + stage: 'key_fetch', + reason: 'upstream_failure', + ...diagnosticError(error), + }); + throw error; + } + }; + } + } if (provider.id === 'microsoft') { provider.accountSubject = ({ profile }) => String( @@ -51,9 +94,23 @@ export const verifiedOidc: BetterAuthPlugin = { try { providerSubject('microsoft', claims); } catch { + diagnostic('auth.oauth.failed', { + provider: name, + stage: 'id_token', + reason: 'invalid_provider_subject', + hasTenant: typeof claims.tid === 'string', + hasObjectId: typeof claims.oid === 'string', + }); return false; } - return verifyClaims?.(claims) === true; + const valid = verifyClaims?.(claims) === true; + if (!valid) + diagnostic('auth.oauth.failed', { + provider: name, + stage: 'id_token', + reason: 'provider_claims_rejected', + }); + return valid; }; } } @@ -68,21 +125,96 @@ export const verifiedOidc: BetterAuthPlugin = { }; const info = provider.getUserInfo.bind(provider); provider.getUserInfo = async (tokens) => { - if ( - !tokens.idToken || - !tokens.expectedIdTokenNonce || + let reason: DiagnosticFields['reason']; + if (!tokens.idToken) reason = 'missing_id_token'; + else if (!tokens.expectedIdTokenNonce) reason = 'missing_nonce'; + else if ( !(await verifyProviderIdToken( provider, tokens.idToken, tokens.expectedIdTokenNonce, )) ) + reason = 'id_token_rejected'; + if (reason) { + diagnostic('auth.oauth.failed', { + provider: name, + stage: 'id_token', + reason, + ...tokenDiagnosticFlags( + tokens.idToken, + tokens.expectedIdTokenNonce, + provider.options?.clientId, + provider.id, + ), + }); return null; - return info(tokens); + } + diagnostic('auth.oauth.stage', { provider: name, stage: 'id_token' }); + try { + const profile = await info(tokens); + if (!profile) + diagnostic('auth.oauth.failed', { + provider: name, + stage: 'profile', + reason: 'profile_unavailable', + }); + else + diagnostic('auth.oauth.stage', { + provider: name, + stage: 'profile', + }); + return profile; + } catch (error) { + diagnostic('auth.oauth.failed', { + provider: name, + stage: 'profile', + reason: 'upstream_failure', + ...diagnosticError(error), + }); + throw error; + } }; } }, }; +/** Untrusted token shape is diagnostic only; acceptance still uses the library verifier. */ +function tokenDiagnosticFlags( + token: string | undefined, + nonce: string | undefined, + audience: unknown, + provider: string, +): DiagnosticFields { + if (!token || token.length > 65_536) return {}; + try { + const [header, payload] = token.split('.'); + const h = JSON.parse(Buffer.from(header!, 'base64url').toString()); + const p = JSON.parse(Buffer.from(payload!, 'base64url').toString()); + if (!p || !h) return {}; + const issuer = + provider === 'microsoft' + ? `https://login.microsoftonline.com/${p.tid}/v2.0` + : provider === 'google' + ? 'https://accounts.google.com' + : 'https://appleid.apple.com'; + return { + hasSubject: typeof p.sub === 'string', + hasTenant: typeof p.tid === 'string', + hasObjectId: typeof p.oid === 'string', + nonceMatches: typeof nonce === 'string' && p.nonce === nonce, + audienceMatches: + typeof audience === 'string' && + (p.aud === audience || + (Array.isArray(p.aud) && p.aud.includes(audience))), + issuerMatches: p.iss === issuer, + expired: typeof p.exp === 'number' && p.exp <= Date.now() / 1000, + issuedInFuture: typeof p.iat === 'number' && p.iat > Date.now() / 1000, + algorithmMatches: h.alg === 'RS256', + }; + } catch { + return {}; + } +} export function oauthFromEnvironment( env: Record, ): OAuthSettings { @@ -295,9 +427,20 @@ export async function oauthRequest( }, ): Promise { const path = new URL(request.url).pathname.slice('/api/auth'.length); - const fail = () => { + const callbackProvider = path.slice('/callback/'.length) as Provider; + const fail = ( + reason: DiagnosticFields['reason'], + stage: DiagnosticFields['stage'] = 'state', + ) => { + diagnostic('auth.oauth.failed', { + provider: callbackProvider, + stage, + reason, + }); const url = new URL(options.errorPath ?? '/', options.origin); url.searchParams.set('error', 'oauth_failed'); + const id = diagnosticRequestId(); + if (id) url.searchParams.set('request_id', id); return Response.redirect(url.href, 303); }; if (path === '/sign-in/social' || path === '/link-social') { @@ -339,7 +482,7 @@ export async function oauthRequest( const state = new URL(request.url).searchParams.get('state'); const provider = path.slice('/callback/'.length) as Provider; if (!state || !providers.includes(provider) || !options.oauth?.[provider]) - return fail(); + return fail('missing_state'); const prefix = options.origin.startsWith('https:') ? '__Host-pgstencil' : 'pgstencil'; @@ -357,9 +500,9 @@ export async function oauthRequest( `${state}.${await makeSignature(state, options.secret)}`, ) ) - return fail(); + return fail('invalid_browser_binding'); } catch { - return fail(); + return fail('invalid_browser_binding'); } const result = await sql<{ value: string; @@ -368,7 +511,8 @@ export async function oauthRequest( options.database, ); const row = result.rows[0]; - if (!row || row.expiresAt.getTime() <= Date.now()) return fail(); + if (!row || row.expiresAt.getTime() <= Date.now()) + return fail('expired_state'); let data: { pgstencilProvider?: string; pgstencilSession?: string; @@ -377,10 +521,11 @@ export async function oauthRequest( try { data = JSON.parse(row.value) as typeof data; } catch { - return fail(); + return fail('invalid_state'); } - if (data.pgstencilProvider !== provider) return fail(); - if (data.link && options.accountLinking === 'same-email') return fail(); + if (data.pgstencilProvider !== provider) return fail('provider_mismatch'); + if (data.link && options.accountLinking === 'same-email') + return fail('linking_disabled'); if (data.link) { const session = await auth.api.getSession({ headers: request.headers }); if ( @@ -388,7 +533,7 @@ export async function oauthRequest( session.session.id !== data.pgstencilSession || session.user.id !== data.link.userId ) - return fail(); + return fail('session_mismatch'); } // Upstream checks state but uses separate read/delete calls. Claim it once // in Postgres before exchanging the code, including across Worker isolates. @@ -399,7 +544,7 @@ export async function oauthRequest( await sql`INSERT INTO pgstencil_oauth_claims (key, expires_at) VALUES (${keyed(options.secret, 'oauth-state', state)}, ${row.expiresAt}) ON CONFLICT DO NOTHING RETURNING key`.execute( options.database, ); - if (claim.rows.length !== 1) return fail(); + if (claim.rows.length !== 1) return fail('state_replayed'); } const response = await auth.handler(request); // Do not forward provider error descriptions or codes into URLs, logs or pages. @@ -415,7 +560,13 @@ export async function oauthRequest( url.searchParams.set('provider', path.slice('/callback/'.length)); return Response.redirect(url.href, 303); } - if (redirect.searchParams.has('error')) return fail(); + if (redirect.searchParams.has('error')) { + const reason = + redirect.searchParams.get('error') === 'access_denied' + ? 'provider_cancelled' + : 'provider_error'; + return fail(reason, 'callback'); + } } return response; } diff --git a/packages/auth/src/better-auth-workers.ts b/packages/auth/src/better-auth-workers.ts index 42ef474..9f73cc5 100644 --- a/packages/auth/src/better-auth-workers.ts +++ b/packages/auth/src/better-auth-workers.ts @@ -1,3 +1,8 @@ +import { + diagnostic, + diagnosticError, + observeRequest, +} from 'pgstencil/diagnostics'; import { Hono } from 'hono'; import type { EmailSender } from 'pgstencil'; import { createAuthApp, type AuthAppOptions } from './better-auth.ts'; @@ -22,6 +27,7 @@ export type BetterAuthWorkerBindings = { export function createBetterAuthWorker( options: Pick< AuthAppOptions, + | 'diagnostics' | 'sessionPolicy' | 'accountLinking' | 'trustedEmailProviders' @@ -36,36 +42,45 @@ export function createBetterAuthWorker( ) { const app = new Hono<{ Bindings: E }>(); app.all('*', async (c) => { - if (new URL(c.env.APP_ORIGIN).protocol !== 'https:') - throw new Error('Workers auth requires HTTPS'); - const credentials: Record = {}; - for (const provider of providers) - for (const suffix of ['CLIENT_ID', 'CLIENT_SECRET']) { - const key = `${provider.toUpperCase()}_${suffix}`; - const value = c.env[key as keyof E]; - if (typeof value === 'string') credentials[key] = value; + const handle = async () => { + if (new URL(c.env.APP_ORIGIN).protocol !== 'https:') + throw new Error('Workers auth requires HTTPS'); + const credentials: Record = {}; + for (const provider of providers) + for (const suffix of ['CLIENT_ID', 'CLIENT_SECRET']) { + const key = `${provider.toUpperCase()}_${suffix}`; + const value = c.env[key as keyof E]; + if (typeof value === 'string') credentials[key] = value; + } + const auth = createAuthApp({ + ...options, + databaseUrl: c.env.HYPERDRIVE.connectionString, + origin: c.env.APP_ORIGIN, + secret: c.env.AUTH_SECRET, + email: options.email(c.env), + oauth: oauthFromEnvironment(credentials), + ipAddressHeaders: ['cf-connecting-ip'], + }); + try { + return await auth.app.fetch(c.req.raw); + } finally { + await auth.close(); } - const auth = createAuthApp({ - ...options, - databaseUrl: c.env.HYPERDRIVE.connectionString, - origin: c.env.APP_ORIGIN, - secret: c.env.AUTH_SECRET, - email: options.email(c.env), - oauth: oauthFromEnvironment(credentials), - ipAddressHeaders: ['cf-connecting-ip'], - }); - try { - return await auth.app.fetch(c.req.raw); - } finally { - await auth.close(); - } + }; + return options.diagnostics + ? observeRequest(c.req.raw, options.diagnostics, handle) + : handle(); }); - app.onError((_, c) => - c.json( + app.onError((error, c) => { + diagnostic('request.failed', { + reason: 'unexpected_error', + ...diagnosticError(error), + }); + return c.json( { message: 'Sign-in is temporarily unavailable. Please try again.' }, 503, { 'cache-control': 'no-store' }, - ), - ); + ); + }); return app; } diff --git a/packages/auth/src/better-auth.ts b/packages/auth/src/better-auth.ts index f9ca40d..aec086f 100644 --- a/packages/auth/src/better-auth.ts +++ b/packages/auth/src/better-auth.ts @@ -1,3 +1,10 @@ +import { + diagnostic, + diagnosticError, + observeRequest, + requestOperation, + type DiagnosticOptions, +} from 'pgstencil/diagnostics'; import { betterAuth, type BetterAuthOptions } from 'better-auth'; import { getSessionFromCtx } from 'better-auth/api'; import { lastLoginMethod } from 'better-auth/plugins'; @@ -27,6 +34,7 @@ import { export interface AuthOptions { database: ReturnType; + diagnostics?: DiagnosticOptions; origin: string; secret: string; email: EmailSender; @@ -72,7 +80,15 @@ export function authOptions(options: AuthOptions): BetterAuthOptions { telemetry: { enabled: false }, logger: { disabled: true }, socialProviders: socialProviders(options.oauth, options.allowMissingEmail), - onAPIError: { errorURL: options.origin + (options.errorPath ?? '/') }, + onAPIError: { + errorURL: options.origin + (options.errorPath ?? '/'), + onError: (error) => { + diagnostic('request.failed', { + reason: 'unexpected_error', + ...diagnosticError(error), + }); + }, + }, user: { validateUserInfo: async ({ user, source }, context) => { if (typeof user.email === 'string' && isIdentityEmail(user.email)) { @@ -91,6 +107,11 @@ export function authOptions(options: AuthOptions): BetterAuthOptions { ) ) return; + diagnostic('auth.oauth.failed', { + provider, + stage: 'profile', + reason: 'reserved_email', + }); return { error: 'Reserved email address' }; } if ( @@ -98,8 +119,14 @@ export function authOptions(options: AuthOptions): BetterAuthOptions { (user.emailVerified !== true || typeof user.email !== 'string' || !/^[^\s@<>]+@[^\s@<>]+\.[^\s@<>]+$/.test(user.email)) - ) + ) { + diagnostic('auth.oauth.failed', { + provider: source.oauth?.providerId as Provider, + stage: 'profile', + reason: 'unverified_email', + }); return { error: 'A verified email address is required' }; + } if ( options.accountLinking === 'same-email' && source.method === 'oauth' && @@ -128,8 +155,14 @@ export function authOptions(options: AuthOptions): BetterAuthOptions { options.database, ) ).rows.length - ) + ) { + diagnostic('auth.oauth.failed', { + provider: source.oauth?.providerId as Provider, + stage: 'profile', + reason: 'mailbox_proof_required', + }); return { error: 'email_verification_required' }; + } } } }, @@ -248,15 +281,25 @@ export function authOptions(options: AuthOptions): BetterAuthOptions { if (isIdentityEmail(email)) throw new Error('Not a delivery address'); if (type !== 'sign-in') throw new Error('This example only supports sign-in email'); - await options.email.send({ - from: 'signin@example.test', - to: [email], - subject: options.appName - ? `Your ${options.appName} sign-in code` - : 'Your sign-in code', - text: `Your sign-in code is ${otp}. It expires in 10 minutes.`, - html: `

Your sign-in code is ${otp}.

It expires in 10 minutes.

`, - }); + try { + await options.email.send({ + from: 'signin@example.test', + to: [email], + subject: options.appName + ? `Your ${options.appName} sign-in code` + : 'Your sign-in code', + text: `Your sign-in code is ${otp}. It expires in 10 minutes.`, + html: `

Your sign-in code is ${otp}.

It expires in 10 minutes.

`, + }); + diagnostic('email.delivery.succeeded'); + } catch (error) { + diagnostic('email.delivery.failed', { + stage: 'transport', + reason: 'upstream_failure', + ...diagnosticError(error), + }); + throw error; + } }, }), ], @@ -267,6 +310,45 @@ export function createAuthApp(options: AuthAppOptions) { const db = connectDatabase(options.databaseUrl); const auth = betterAuth(authOptions({ ...options, database: db })); const app = new Hono(); + if (options.diagnostics) + app.use('*', async (c, next) => { + c.res = await observeRequest( + c.req.raw, + options.diagnostics!, + async () => { + await next(); + return c.res; + }, + ); + }); + app.use('*', async (c, next) => { + await next(); + const operation = requestOperation(c.req.raw); + if (c.res.status >= 400) + diagnostic('auth.rejected', { + operation, + status: c.res.status, + reason: c.res.status === 429 ? 'rate_limited' : 'request_rejected', + }); + else if (operation === 'auth.logout') diagnostic('auth.logout'); + else if ( + (operation === 'auth.email.verify' || + operation === 'auth.oauth.callback') && + c.res.headers + .getSetCookie() + .some( + (cookie) => + cookie.includes('.session_token=') && !cookie.includes('Max-Age=0'), + ) + ) + diagnostic('auth.login.succeeded', { + operation, + provider: + operation === 'auth.oauth.callback' + ? (new URL(c.req.url).pathname.split('/').at(-1) as Provider) + : undefined, + }); + }); protectAuth(app, { ...options, database: db }); app.on(['POST', 'GET'], '/api/auth/*', async (c) => publicAuthResponse( @@ -274,9 +356,14 @@ export function createAuthApp(options: AuthAppOptions) { ), ); app.get('/api/providers', (c) => c.json(Object.keys(options.oauth ?? {}))); - app.onError((_error, c) => - c.json({ message: 'Authentication failed; please try again' }, 500), - ); + app.onError((error, c) => { + diagnostic('request.failed', { + operation: requestOperation(c.req.raw), + reason: 'unexpected_error', + ...diagnosticError(error), + }); + return c.json({ message: 'Authentication failed; please try again' }, 500); + }); return { app, auth, diff --git a/packages/auth/src/postmark.ts b/packages/auth/src/postmark.ts index 00d7935..f269ba9 100644 --- a/packages/auth/src/postmark.ts +++ b/packages/auth/src/postmark.ts @@ -1,5 +1,14 @@ import type { EmailSender } from 'pgstencil'; +class EmailDeliveryError extends Error { + constructor( + readonly httpStatus: number, + readonly providerCode?: number, + ) { + super('Email delivery failed'); + } +} + /** Production transport; tests inject EmailDev instead. Provider errors contain no message content. */ export function postmarkEmail(token: string, from: string): EmailSender { if (!token || !from) @@ -32,9 +41,13 @@ export function postmarkEmail(token: string, from: string): EmailSender { : {}), }), }); - if (!response.ok) throw new Error('Email delivery failed'); + if (!response.ok) throw new EmailDeliveryError(response.status); const result = (await response.json()) as { ErrorCode?: number }; - if (result.ErrorCode !== 0) throw new Error('Email delivery failed'); + if (result.ErrorCode !== 0) + throw new EmailDeliveryError( + response.status, + typeof result.ErrorCode === 'number' ? result.ErrorCode : undefined, + ); }, }; } diff --git a/packages/pgstencil/package.json b/packages/pgstencil/package.json index 10905fe..0bec142 100644 --- a/packages/pgstencil/package.json +++ b/packages/pgstencil/package.json @@ -8,7 +8,8 @@ "./database": "./src/database.ts", "./snapshots": "./src/snapshots.ts", "./testing": "./src/testing.ts", - "./postgres": "./src/postgres.ts" + "./postgres": "./src/postgres.ts", + "./diagnostics": "./src/diagnostics.ts" }, "dependencies": { "pg": "^8.16.0", @@ -47,6 +48,10 @@ "./postgres": { "types": "./dist/postgres.d.ts", "import": "./dist/postgres.js" + }, + "./diagnostics": { + "types": "./dist/diagnostics.d.ts", + "import": "./dist/diagnostics.js" } } }, diff --git a/packages/pgstencil/src/diagnostics.ts b/packages/pgstencil/src/diagnostics.ts new file mode 100644 index 0000000..2b21fee --- /dev/null +++ b/packages/pgstencil/src/diagnostics.ts @@ -0,0 +1,357 @@ +import { AsyncLocalStorage } from 'node:async_hooks'; +import { randomUUID } from 'node:crypto'; +import type { Time } from './time.ts'; + +export type DiagnosticEvent = + | 'request.completed' + | 'request.failed' + | 'auth.oauth.stage' + | 'auth.oauth.failed' + | 'auth.login.succeeded' + | 'auth.rejected' + | 'auth.logout' + | 'email.delivery.succeeded' + | 'email.delivery.failed' + | 'billing.webhook.received' + | 'billing.webhook.processed' + | 'billing.webhook.failed'; +const providers = [ + 'google', + 'apple', + 'facebook', + 'github', + 'microsoft', +] as const; +const stages = [ + 'state', + 'token_exchange', + 'key_fetch', + 'id_token', + 'profile', + 'callback', + 'database', + 'transport', +] as const; +const reasons = [ + 'missing_state', + 'invalid_browser_binding', + 'expired_state', + 'invalid_state', + 'provider_mismatch', + 'linking_disabled', + 'session_mismatch', + 'state_replayed', + 'provider_cancelled', + 'provider_error', + 'missing_id_token', + 'missing_nonce', + 'id_token_rejected', + 'provider_claims_rejected', + 'invalid_provider_subject', + 'profile_unavailable', + 'reserved_email', + 'unverified_email', + 'mailbox_proof_required', + 'rate_limited', + 'request_rejected', + 'upstream_failure', + 'unexpected_error', +] as const; +const operations = [ + 'auth.social.start', + 'auth.oauth.callback', + 'auth.email.send', + 'auth.email.verify', + 'auth.session', + 'auth.logout', + 'auth.accounts', + 'auth.csrf', + 'auth.other', + 'health', + 'ready', + 'providers', + 'inbox', + 'api.other', + 'static', +] as const; +const errorTypes = [ + 'Error', + 'TypeError', + 'RangeError', + 'SyntaxError', + 'AbortError', + 'TimeoutError', +] as const; +const errorCodes = [ + 'ERR_JWT_EXPIRED', + 'ERR_JWT_CLAIM_VALIDATION_FAILED', + 'ERR_JWS_SIGNATURE_VERIFICATION_FAILED', + 'ERR_JWKS_NO_MATCHING_KEY', + 'ERR_JWKS_TIMEOUT', + 'ERR_JOSE_ALG_NOT_ALLOWED', + 'ECONNREFUSED', + 'ECONNRESET', + 'ETIMEDOUT', + 'ENOTFOUND', + '23505', + '23503', + '40001', + '40P01', + '53300', + '57P01', + 'invalid_client', + 'invalid_grant', + 'invalid_request', + 'unauthorized_client', + 'access_denied', +] as const; +export interface DiagnosticFields { + provider?: (typeof providers)[number] | undefined; + stage?: (typeof stages)[number] | undefined; + reason?: (typeof reasons)[number] | undefined; + operation?: (typeof operations)[number] | undefined; + status?: number | undefined; + durationMs?: number | undefined; + errorType?: (typeof errorTypes)[number] | undefined; + errorCode?: (typeof errorCodes)[number] | undefined; + httpStatus?: number | undefined; + providerCode?: number | undefined; + stripeEventId?: string | undefined; + hasSubject?: boolean | undefined; + hasTenant?: boolean | undefined; + hasObjectId?: boolean | undefined; + nonceMatches?: boolean | undefined; + audienceMatches?: boolean | undefined; + issuerMatches?: boolean | undefined; + expired?: boolean | undefined; + issuedInFuture?: boolean | undefined; + algorithmMatches?: boolean | undefined; +} +export interface DiagnosticRecord extends DiagnosticFields { + source: 'pgstencil'; + version: 1; + event: DiagnosticEvent; + level: 'info' | 'warn' | 'error'; + timestamp: string; + requestId?: string; + revision?: string; +} +export interface DiagnosticOptions { + sink?: (record: DiagnosticRecord) => void; + time?: Time; + revision?: string; + requestId?: () => string; +} +const contexts = new AsyncLocalStorage(); +const uuid = /^[a-f0-9]{8}-[a-f0-9]{4}-[a-f0-9]{4}-[a-f0-9]{4}-[a-f0-9]{12}$/i; +const enums = { + provider: providers, + stage: stages, + reason: reasons, + operation: operations, + errorType: errorTypes, + errorCode: errorCodes, +}; +const numbers = ['status', 'httpStatus', 'providerCode', 'durationMs'] as const; +const booleans = [ + 'hasSubject', + 'hasTenant', + 'hasObjectId', + 'nonceMatches', + 'audienceMatches', + 'issuerMatches', + 'expired', + 'issuedInFuture', + 'algorithmMatches', +] as const; +const events: DiagnosticEvent[] = [ + 'request.completed', + 'request.failed', + 'auth.oauth.stage', + 'auth.oauth.failed', + 'auth.login.succeeded', + 'auth.rejected', + 'auth.logout', + 'email.delivery.succeeded', + 'email.delivery.failed', + 'billing.webhook.received', + 'billing.webhook.processed', + 'billing.webhook.failed', +]; + +/** Deliberately reconstruct records: callers cannot smuggle arbitrary error bodies or fields into logs. */ +export function diagnostic( + event: DiagnosticEvent, + fields: DiagnosticFields = {}, +) { + const context = contexts.getStore(); + if (!context || !events.includes(event)) return; + try { + const level = + fields.reason === 'provider_cancelled' + ? 'info' + : event.endsWith('.failed') || (fields.status ?? 0) >= 500 + ? 'error' + : event === 'auth.rejected' || (fields.status ?? 0) >= 400 + ? 'warn' + : 'info'; + const record: DiagnosticRecord = { + source: 'pgstencil', + version: 1, + event, + level, + timestamp: (context.time?.now() ?? new Date()).toISOString(), + }; + if (context.id && uuid.test(context.id)) record.requestId = context.id; + if (context.revision && /^[a-f0-9]{40}$/.test(context.revision)) + record.revision = context.revision; + const target = record as unknown as Record; + for (const [key, values] of Object.entries(enums)) { + const value = (fields as Record)[key]; + if ( + typeof value === 'string' && + (values as readonly string[]).includes(value) + ) + target[key] = value; + } + if ( + fields.stripeEventId && + /^evt_[a-zA-Z0-9]{1,128}$/.test(fields.stripeEventId) + ) + record.stripeEventId = fields.stripeEventId; + for (const key of numbers) { + const value = fields[key]; + if ( + typeof value === 'number' && + Number.isFinite(value) && + value >= 0 && + value <= 86_400_000 + ) + target[key] = Math.round(value); + } + for (const key of booleans) + if (typeof fields[key] === 'boolean') target[key] = fields[key]; + (context.sink ?? ((entry) => console[entry.level](JSON.stringify(entry))))( + record, + ); + } catch { + /* Logging must never change authentication or payment outcomes. */ + } +} + +/** Error messages, stacks, causes, SQL, request and response bodies are never serialized. */ +export function diagnosticError(error: unknown): DiagnosticFields { + try { + if (!error || typeof error !== 'object') return {}; + const data = error as Record; + const result: DiagnosticFields = {}; + if (errorTypes.includes(data.name as (typeof errorTypes)[number])) + result.errorType = data.name as DiagnosticFields['errorType']; + const code = data.code ?? data.error; + if (errorCodes.includes(code as (typeof errorCodes)[number])) + result.errorCode = code as DiagnosticFields['errorCode']; + if ( + typeof data.status === 'number' && + Number.isInteger(data.status) && + data.status >= 400 && + data.status <= 599 + ) + result.httpStatus = data.status; + if ( + Array.isArray(data.error_codes) && + typeof data.error_codes[0] === 'number' && + Number.isInteger(data.error_codes[0]) && + data.error_codes[0] >= 0 && + data.error_codes[0] <= 86_400_000 + ) + result.providerCode = data.error_codes[0]; + for (const key of ['httpStatus', 'providerCode'] as const) + if ( + typeof data[key] === 'number' && + Number.isInteger(data[key]) && + data[key] >= 0 && + data[key] <= 86_400_000 + ) + result[key] = data[key]; + return result; + } catch { + return {}; + } +} +export function diagnosticRequestId() { + return contexts.getStore()?.id; +} +export function withDiagnostics( + options: DiagnosticOptions, + run: () => T, +): T { + return contexts.run(options, run); +} +export function requestOperation( + request: Request, +): DiagnosticFields['operation'] { + const path = new URL(request.url).pathname; + const known: Record = { + '/api/auth/sign-in/social': 'auth.social.start', + '/api/auth/link-social': 'auth.social.start', + '/api/auth/email-otp/send-verification-otp': 'auth.email.send', + '/api/auth/sign-in/email-otp': 'auth.email.verify', + '/api/auth/get-session': 'auth.session', + '/api/auth/sign-out': 'auth.logout', + '/api/auth/list-accounts': 'auth.accounts', + '/api/auth/csrf': 'auth.csrf', + '/api/health': 'health', + '/api/ready': 'ready', + '/api/providers': 'providers', + }; + if (Object.hasOwn(known, path)) return known[path]; + if (path.startsWith('/api/auth/callback/')) return 'auth.oauth.callback'; + if (path.startsWith('/api/auth/')) return 'auth.other'; + if (path.startsWith('/dev/') || path.startsWith('/api/dev/')) return 'inbox'; + return path.startsWith('/api/') ? 'api.other' : 'static'; +} +/** One server-generated correlation ID per request; incoming IDs/URLs are not trusted or logged. */ +export function observeRequest( + request: Request, + options: DiagnosticOptions, + handle: () => Promise, +): Promise { + const existing = contexts.getStore(); + if (existing?.id) return handle(); + const candidate = options.requestId?.() ?? randomUUID(); + const id = uuid.test(candidate) ? candidate : randomUUID(); + return contexts.run({ ...options, id }, async () => { + const operation = requestOperation(request); + const started = options.time?.now().getTime() ?? Date.now(); + let response: Response; + try { + response = await handle(); + } catch (error) { + diagnostic('request.failed', { + operation, + reason: 'unexpected_error', + ...diagnosticError(error), + }); + response = Response.json( + { message: 'Temporarily unavailable. Please try again.' }, + { status: 503, headers: { 'cache-control': 'no-store' } }, + ); + } + if (operation !== 'static' || response.status >= 400) + diagnostic('request.completed', { + operation, + status: response.status, + durationMs: Math.max( + 0, + (options.time?.now().getTime() ?? Date.now()) - started, + ), + }); + const headers = new Headers(response.headers); + headers.set('x-request-id', id); + return new Response(response.body, { + status: response.status, + statusText: response.statusText, + headers, + }); + }); +} diff --git a/packages/stripe/src/index.ts b/packages/stripe/src/index.ts index 7f66ed9..86fc773 100644 --- a/packages/stripe/src/index.ts +++ b/packages/stripe/src/index.ts @@ -1,3 +1,4 @@ +import { diagnostic, diagnosticError } from 'pgstencil/diagnostics'; import Stripe from 'stripe'; import { sql, type Kysely, type Transaction } from 'kysely'; import { token, type Time, type RandomSource } from 'pgstencil'; @@ -521,7 +522,18 @@ export class Billing { /** Application database effects join the same commit and retry boundary. */ apply?: (event: Stripe.Event, trx: Transaction) => Promise, ): Promise { - const event = await this.verifyWebhook(body, signature); + let event: Stripe.Event; + try { + event = await this.verifyWebhook(body, signature); + } catch (error) { + diagnostic('billing.webhook.failed', { + stage: 'transport', + reason: 'request_rejected', + ...diagnosticError(error), + }); + throw error; + } + diagnostic('billing.webhook.received', { stripeEventId: event.id }); try { await this.db.transaction().execute(async (trx) => { await trx @@ -575,7 +587,14 @@ export class Billing { .onConflict((c) => c.column('id').doUpdateSet(processed)) .execute(); }); + diagnostic('billing.webhook.processed', { stripeEventId: event.id }); } catch (error) { + diagnostic('billing.webhook.failed', { + stripeEventId: event.id, + stage: 'database', + reason: 'unexpected_error', + ...diagnosticError(error), + }); await this.db .insertInto('events') .values({ diff --git a/tests/integration/better-auth-oauth.test.ts b/tests/integration/better-auth-oauth.test.ts index 05e4d9a..badc19f 100644 --- a/tests/integration/better-auth-oauth.test.ts +++ b/tests/integration/better-auth-oauth.test.ts @@ -1,3 +1,4 @@ +import type { DiagnosticRecord } from '../../packages/pgstencil/src/diagnostics.ts'; import { test, expect } from 'vitest'; import { build } from 'esbuild'; import { builtinModules } from 'node:module'; @@ -46,7 +47,10 @@ async function fixture( accountLinking: 'explicit' | 'same-email' = 'explicit', emailPolicy: Pick< AuthOptions, - 'trustedEmailProviders' | 'allowMissingEmail' | 'rememberLoginMethod' + | 'trustedEmailProviders' + | 'allowMissingEmail' + | 'rememberLoginMethod' + | 'diagnostics' > = {}, ) { const context = await createTestContext({ @@ -942,3 +946,85 @@ test('Microsoft tenant identity and unverified email cannot capture another acco expect(await session(browser)).toBeNull(); } }); + +test('auth diagnostics identify Microsoft token failures without recording credentials or identity', async ({ + onTestFinished, +}) => { + const records: DiagnosticRecord[] = []; + let counter = 0; + const f = await fixture('multiple', 'same-email', { + allowMissingEmail: true, + trustedEmailProviders: ['microsoft'], + diagnostics: { + sink: (entry) => records.push(entry), + requestId: () => + `11111111-1111-4111-8111-${String(++counter).padStart(12, '0')}`, + }, + }); + onTestFinished(() => f.close()); + const browser = await f.browser(); + const attempt = await login(f, browser, 'microsoft', { + email: 'private-person@example.test', + claims: { nonce: 'private-wrong-nonce' }, + }); + expect(attempt.response.headers.get('location')).toContain( + 'error=oauth_failed', + ); + const requestId = attempt.response.headers.get('x-request-id'); + expect(attempt.response.headers.get('location')).toContain( + `request_id=${requestId}`, + ); + expect(records).toEqual( + expect.arrayContaining([ + expect.objectContaining({ + event: 'auth.oauth.stage', + provider: 'microsoft', + stage: 'token_exchange', + requestId, + }), + expect.objectContaining({ + event: 'auth.oauth.failed', + provider: 'microsoft', + stage: 'id_token', + reason: 'id_token_rejected', + nonceMatches: false, + algorithmMatches: true, + audienceMatches: true, + requestId, + }), + ]), + ); + expect(await session(browser)).toBeNull(); + const next = await f.browser(); + await login(f, next, 'microsoft', { email: 'private-person@example.test' }); + expect(records).toEqual( + expect.arrayContaining([ + expect.objectContaining({ + event: 'auth.login.succeeded', + provider: 'microsoft', + }), + ]), + ); + const serialized = JSON.stringify(records); + for (const forbidden of [ + 'private-person', + 'private-wrong-nonce', + 'clientSecret', + 'session_token', + 'accessToken', + 'idToken', + 'cookie', + 'better-auth-local-oauth-secret', + ]) + expect(serialized).not.toContain(forbidden); + await next.post('email-otp/send-verification-otp', { + email: 'private-email@example.test', + type: 'sign-in', + }); + expect(records).toEqual( + expect.arrayContaining([ + expect.objectContaining({ event: 'email.delivery.succeeded' }), + ]), + ); + expect(JSON.stringify(records)).not.toContain('private-email'); +}); diff --git a/tests/integration/billing.test.ts b/tests/integration/billing.test.ts index 313d181..3a8a63b 100644 --- a/tests/integration/billing.test.ts +++ b/tests/integration/billing.test.ts @@ -1,3 +1,7 @@ +import { + withDiagnostics, + type DiagnosticRecord, +} from '../../packages/pgstencil/src/diagnostics.ts'; import { test, expect } from 'vitest'; import { createTestContext } from '../../packages/pgstencil/src/testing.ts'; import { connectDatabase } from '../../packages/pgstencil/src/database.ts'; @@ -318,3 +322,37 @@ billingTest( expect((await f.billing.status('alice')).access).toBe(false); }, ); + +billingTest( + 'payment diagnostics keep verified event IDs and report failure before recovery without payloads', + async ({ f }) => { + const { session } = await f.start(); + f.dev.completeCheckout(session.id); + const event = f.dev.events[0]!; + const signed = f.dev.signed(event); + const records: DiagnosticRecord[] = []; + const options = { + sink: (record: DiagnosticRecord) => records.push(record), + time: f.time, + }; + await expect( + withDiagnostics(options, () => + f.billing.webhook(signed.body, signed.signature, async () => { + throw new Error('private payment payload'); + }), + ), + ).rejects.toThrow(); + expect(records.map((r) => r.event)).toEqual([ + 'billing.webhook.received', + 'billing.webhook.failed', + ]); + expect(records.every((r) => r.stripeEventId === event.id)).toBe(true); + await withDiagnostics(options, () => + f.billing.webhook(signed.body, signed.signature), + ); + expect(records.at(-1)?.event).toBe('billing.webhook.processed'); + expect(JSON.stringify(records)).not.toContain('private payment payload'); + expect(JSON.stringify(records)).not.toContain('alice@example.test'); + expect(JSON.stringify(records)).not.toContain(signed.signature); + }, +); diff --git a/tests/unit/diagnostics.test.ts b/tests/unit/diagnostics.test.ts new file mode 100644 index 0000000..e27ddba --- /dev/null +++ b/tests/unit/diagnostics.test.ts @@ -0,0 +1,172 @@ +import { test, expect } from 'vitest'; +import { + diagnostic, + diagnosticError, + observeRequest, + withDiagnostics, + type DiagnosticFields, + type DiagnosticRecord, +} from '../../packages/pgstencil/src/diagnostics.ts'; +import { DevTime } from '../../packages/pgstencil/src/time.ts'; + +const id = '11111111-1111-4111-8111-111111111111'; +test('diagnostics allowlist drops secrets even in unexpected fields and malformed values', async () => { + const records: DiagnosticRecord[] = []; + const time = new DevTime(); + const secret = 'private-email@example.test secret-token'; + const result = await observeRequest( + new Request( + `https://example.test/api/auth/callback/microsoft?code=${encodeURIComponent(secret)}`, + { + headers: { + cookie: secret, + authorization: secret, + 'x-request-id': secret, + }, + }, + ), + { + sink: (record) => records.push(record), + time, + requestId: () => id, + revision: 'a'.repeat(40), + }, + async () => { + diagnostic('auth.oauth.failed', { + provider: 'microsoft', + stage: 'id_token', + reason: 'id_token_rejected', + nonceMatches: false, + email: secret, + token: secret, + error: new Error(secret), + requestId: secret, + message: secret, + httpStatus: secret, + } as unknown as DiagnosticFields); + diagnostic('auth.oauth.failed', { + provider: secret, + stage: secret, + errorCode: secret, + } as unknown as DiagnosticFields); + time.advanceMilliseconds(25); + return new Response('ok'); + }, + ); + expect(result.headers.get('x-request-id')).toBe(id); + expect(records[0]).toEqual({ + source: 'pgstencil', + version: 1, + event: 'auth.oauth.failed', + level: 'error', + timestamp: '2020-01-01T00:00:00.000Z', + requestId: id, + revision: 'a'.repeat(40), + provider: 'microsoft', + stage: 'id_token', + reason: 'id_token_rejected', + nonceMatches: false, + }); + expect(records.at(-1)).toMatchObject({ + event: 'request.completed', + operation: 'auth.oauth.callback', + durationMs: 25, + status: 200, + }); + expect(JSON.stringify(records)).not.toContain(secret); + expect(records[1]).not.toHaveProperty('provider'); + expect( + diagnosticError( + Object.assign(new Error(secret), { + code: 'ECONNRESET', + cause: secret, + body: secret, + }), + ), + ).toEqual({ errorType: 'Error', errorCode: 'ECONNRESET' }); +}); + +test('concurrent request logs preserve their own context and do not log arbitrary routes', async () => { + const records: DiagnosticRecord[] = []; + await Promise.all( + [1, 2].map(async (n) => + observeRequest( + new Request('https://example.test/private-email@example.test'), + { + sink: (record) => records.push(record), + requestId: () => id.slice(0, -1) + n, + }, + async () => { + await new Promise((resolve) => setTimeout(resolve, n)); + diagnostic('auth.oauth.stage', { + provider: n === 1 ? 'google' : 'microsoft', + stage: 'profile', + }); + return new Response('ok'); + }, + ), + ), + ); + expect( + records.map(({ provider, requestId }) => ({ provider, requestId })), + ).toEqual([ + { provider: 'google', requestId: id.slice(0, -1) + '1' }, + { provider: 'microsoft', requestId: id.slice(0, -1) + '2' }, + ]); + expect(JSON.stringify(records)).not.toContain('private-email'); + const before = records.length; + diagnostic('email.delivery.succeeded'); + expect(records).toHaveLength(before); +}); + +test('a broken sink never changes successful responses or reveals thrown exception text', async () => { + const result = await observeRequest( + new Request('https://example.test/api/health'), + { + sink: () => { + throw new Error('sink failed'); + }, + }, + async () => new Response('healthy'), + ); + expect(await result.text()).toBe('healthy'); + const records: DiagnosticRecord[] = []; + const failure = await observeRequest( + new Request('https://example.test/api/secret'), + { sink: (r) => records.push(r) }, + async () => { + throw new Error('password=private'); + }, + ); + expect(failure.status).toBe(503); + expect(JSON.stringify(records)).not.toContain('password'); + expect(await failure.text()).not.toContain('password'); + withDiagnostics({ sink: (r) => records.push(r) }, () => + diagnostic('auth.oauth.failed', { reason: 'provider_cancelled' }), + ); + expect(records.at(-1)?.level).toBe('info'); +}); + +test('provider error extraction keeps numeric codes and tolerates hostile getters', () => { + expect( + diagnosticError({ + error: 'invalid_client', + error_codes: [7000215], + error_description: 'secret', + }), + ).toEqual({ errorCode: 'invalid_client', providerCode: 7000215 }); + expect( + diagnosticError({ + error: 'invalid_grant', + error_codes: [50173], + error_description: 'secret', + }), + ).toEqual({ errorCode: 'invalid_grant', providerCode: 50173 }); + expect( + diagnosticError({ + get name() { + throw new Error('private'); + }, + }), + ).toEqual({}); +});