perf(logger): stop building a throwaway pino root per child (#2132)

fluxer_api/src/api/auth/services/SsoService.ts

@@ -24,6 +24,7 @@ import {
 } from 'jose';
 import type {ApiContext} from '../../ApiContext';
 import type {UserID} from '../../BrandedTypes';
+import type {ILogger} from '../../ILogger';
 import type {IDiscriminatorService} from '../../infrastructure/DiscriminatorService';
 import type {KVActivityTracker} from '../../infrastructure/KVActivityTracker';
 import {
@@ -100,6 +101,13 @@ const STATE_BYTE_LENGTH = 16;
 const NONCE_BYTE_LENGTH = 16;
 const MOBILE_SSO_REDIRECT_URI = 'fluxer://auth/sso/callback';
 
+let ssoLogger: ILogger | undefined;
+
+function getLogger(): ILogger {
+	ssoLogger ??= Logger.child({logger: 'SsoService'});
+	return ssoLogger;
+}
+
 function randomBase64UrlToken(byteLength: number): string {
 	return randomBytes(byteLength).toString('base64url');
 }
@@ -235,7 +243,6 @@ function isJsonWebKeySet(value: unknown): value is JSONWebKeySet {
 }
 
 export class SsoService {
-	private readonly logger = Logger.child({logger: 'SsoService'});
 	private static readonly STATE_TTL_SECONDS = seconds('10 minutes');
 	private static readonly DISCOVERY_TTL_SECONDS = seconds('1 hour');
 	private static readonly JWKS_CACHE_TTL_MS = ms('1 hour');
@@ -344,12 +351,12 @@ export class SsoService {
 			throw InputValidationError.fromCode('email_verified', ValidationErrorCodes.INVALID_SSO_TOKEN);
 		}
 		const emailLower = claims.email.toLowerCase();
-		this.logger.info({email: emailLower, has_sub: true}, 'SSO login with sub claim');
+		getLogger().info({email: emailLower, has_sub: true}, 'SSO login with sub claim');
 		const identityUserId = await this.ssoIdentityRepository.findUserId(config.providerId, claims.sub);
 		if (identityUserId) {
 			const user = await this.apiContext.services.users.findUnique(identityUserId);
 			if (!user) {
-				this.logger.error(
+				getLogger().error(
 					{user_id: identityUserId.toString()},
 					'SSO identity mapping points at a missing user; refusing reassignment',
 				);
@@ -401,7 +408,7 @@ export class SsoService {
 		if (ownerId?.toString() === userId.toString()) {
 			return;
 		}
-		this.logger.error(
+		getLogger().error(
 			{user_id: userId.toString(), owner_user_id: ownerId?.toString() ?? null},
 			'SSO identity is already linked to another account',
 		);
@@ -413,7 +420,7 @@ export class SsoService {
 		const traits = user.traits;
 		const existingIdentities = Array.from(traits).filter((trait) => trait.startsWith('sso_identity:'));
 		if (existingIdentities.length > 0 && !traits.has(identityTrait)) {
-			this.logger.error({user_id: user.id.toString()}, 'SSO identity claim did not match linked account');
+			getLogger().error({user_id: user.id.toString()}, 'SSO identity claim did not match linked account');
 			throw InputValidationError.fromCode('sub', ValidationErrorCodes.SSO_IDENTITY_MISMATCH);
 		}
 		await this.claimSsoIdentity(user.id, sub, config);
@@ -534,13 +541,13 @@ export class SsoService {
 				}),
 			);
 			void this.kvActivityTracker.updateActivity(user.id, now).catch((error: unknown) => {
-				this.logger.warn({error, userId: user.id}, 'Failed to update real-time user activity');
+				getLogger().warn({error, userId: user.id}, 'Failed to update real-time user activity');
 			});
 			return user;
 		} catch (error) {
 			if (!userCreated) {
 				await this.ssoIdentityRepository.releaseIdentity(config.providerId, claims.sub).catch((releaseError) => {
-					this.logger.error({releaseError}, 'Failed to release SSO identity after user provisioning failed');
+					getLogger().error({releaseError}, 'Failed to release SSO identity after user provisioning failed');
 				});
 			}
 			throw error;
@@ -567,7 +574,7 @@ export class SsoService {
 		let claims: JWTPayload | null = null;
 		if (tokenResponse.id_token) {
 			if (!config.jwksUrl) {
-				this.logger.warn('SSO id_token returned but no JWKS URL is configured; ignoring id_token claims');
+				getLogger().warn('SSO id_token returned but no JWKS URL is configured; ignoring id_token claims');
 			} else {
 				claims = await this.verifyIdToken(tokenResponse.id_token, config, expectedNonce);
 			}
@@ -580,7 +587,7 @@ export class SsoService {
 		const userInfoSub = userInfo ? readStringClaim(userInfo, 'sub') : undefined;
 		if (claims && userInfo) {
 			if (!idTokenSub || !userInfoSub || idTokenSub !== userInfoSub) {
-				this.logger.error('SSO sub mismatch between id_token and userinfo');
+				getLogger().error('SSO sub mismatch between id_token and userinfo');
 				throw InputValidationError.fromCode('sub', ValidationErrorCodes.SSO_IDENTITY_MISMATCH);
 			}
 		}
@@ -597,7 +604,7 @@ export class SsoService {
 		const normalizedIdTokenEmail = idTokenEmail ? normalizeSsoEmail(idTokenEmail) : undefined;
 		const normalizedUserInfoEmail = userInfoEmail ? normalizeSsoEmail(userInfoEmail) : undefined;
 		if (normalizedIdTokenEmail && normalizedUserInfoEmail && normalizedIdTokenEmail !== normalizedUserInfoEmail) {
-			this.logger.error('SSO email mismatch between id_token and userinfo');
+			getLogger().error('SSO email mismatch between id_token and userinfo');
 			throw InputValidationError.fromCode('email', ValidationErrorCodes.SSO_IDENTITY_MISMATCH);
 		}
 		const email =
@@ -634,7 +641,7 @@ export class SsoService {
 				});
 				const nonce = payload['nonce'];
 				if (nonce === undefined) {
-					this.logger.warn('SSO id_token missing required nonce claim');
+					getLogger().warn('SSO id_token missing required nonce claim');
 					throw new Error('nonce missing');
 				}
 				if (typeof nonce !== 'string' || nonce.length === 0 || nonce !== expectedNonce) {
@@ -644,7 +651,7 @@ export class SsoService {
 			}
 			return decodeJwt(idToken);
 		} catch (error) {
-			this.logger.error({error}, 'Failed to verify SSO id_token');
+			getLogger().error({error}, 'Failed to verify SSO id_token');
 			throw InputValidationError.fromCode('id_token', ValidationErrorCodes.INVALID_SSO_TOKEN);
 		}
 	}
@@ -919,7 +926,7 @@ export class SsoService {
 		try {
 			return await this.assertPublicOutboundUrl(rawUrl, fieldName);
 		} catch (error) {
-			this.logger.warn({fieldName, rawUrl, error}, 'Ignoring SSO URL that failed outbound policy validation');
+			getLogger().warn({fieldName, rawUrl, error}, 'Ignoring SSO URL that failed outbound policy validation');
 			return null;
 		}
 	}

packages/logger/package.json

@@ -4,6 +4,8 @@
 	"private": true,
 	"type": "module",
 	"scripts": {
+		"test": "vitest run",
+		"test:watch": "vitest",
 		"typecheck": "tsgo --noEmit"
 	},
 	"dependencies": {
@@ -12,6 +14,8 @@
 	},
 	"devDependencies": {
 		"@types/node": "catalog:",
-		"@typescript/native-preview": "catalog:"
+		"@typescript/native-preview": "catalog:",
+		"vite-tsconfig-paths": "catalog:",
+		"vitest": "catalog:"
 	}
 }

packages/logger/src/Logger.ts

@@ -111,8 +111,13 @@ function createPinoLogger(serviceName: string, options: LoggerOptions = {}): Pin
 export class Logger {
 	private logger: PinoLogger;
 
-	constructor(serviceName: string, options: LoggerOptions = {}) {
-		this.logger = createPinoLogger(serviceName, options);
+	constructor(serviceName: string, options?: LoggerOptions);
+	constructor(pinoLogger: PinoLogger);
+	constructor(serviceNameOrPinoLogger: string | PinoLogger, options: LoggerOptions = {}) {
+		this.logger =
+			typeof serviceNameOrPinoLogger === 'string'
+				? createPinoLogger(serviceNameOrPinoLogger, options)
+				: serviceNameOrPinoLogger;
 	}
 
 	getPinoLogger(): PinoLogger {
@@ -124,9 +129,7 @@ export class Logger {
 	}
 
 	static createWithLogger(logger: PinoLogger): Logger {
-		const childLogger = new Logger('', {});
-		childLogger.setPinoLogger(logger);
-		return childLogger;
+		return new Logger(logger);
 	}
 
 	trace(obj: Record<string, unknown>, msg?: string): void;

packages/logger/src/__tests__/Logger.test.ts

@@ -0,0 +1,39 @@
+// SPDX-License-Identifier: AGPL-3.0-or-later
+
+import {createLogger, Logger} from '@fluxer/logger/src/Logger';
+import pino, {type Logger as PinoLogger} from 'pino';
+import {afterEach, describe, expect, it, vi} from 'vitest';
+
+function readDestination(logger: PinoLogger): unknown {
+	return (logger as unknown as Record<symbol, unknown>)[pino.symbols.streamSym];
+}
+
+describe('Logger.child', () => {
+	afterEach(() => {
+		vi.restoreAllMocks();
+		vi.unstubAllEnvs();
+	});
+
+	it('shares the parent destination instead of opening a new one', () => {
+		const parent = createLogger('logger-test', {environment: 'production'});
+		const child = parent.child({logger: 'ChildService'});
+		expect(child).toBeInstanceOf(Logger);
+		expect(readDestination(child.pino)).toBe(readDestination(parent.pino));
+	});
+
+	it('does not construct a throwaway pino root logger', () => {
+		vi.stubEnv('FLUXER_ENV', 'production');
+		const parent = createLogger('logger-test', {environment: 'production'});
+		const destinationSpy = vi.spyOn(pino, 'destination');
+		const child = parent.child({logger: 'ChildService'});
+		expect(destinationSpy).not.toHaveBeenCalled();
+		expect(child.pino.bindings()['logger']).toBe('ChildService');
+	});
+
+	it('keeps the parent bindings on the child', () => {
+		const parent = createLogger('logger-test', {environment: 'production'});
+		const child = parent.child({logger: 'ChildService'});
+		expect(child.pino.bindings()['service']).toBe('logger-test');
+		expect(child.pino.level).toBe(parent.pino.level);
+	});
+});

packages/logger/vitest.config.ts

@@ -0,0 +1,27 @@
+// SPDX-License-Identifier: AGPL-3.0-or-later
+
+import path from 'node:path';
+import {fileURLToPath} from 'node:url';
+import tsconfigPaths from 'vite-tsconfig-paths';
+import {defineConfig} from 'vitest/config';
+
+const __dirname = path.dirname(fileURLToPath(import.meta.url));
+
+export default defineConfig({
+	plugins: [
+		tsconfigPaths({
+			root: path.resolve(__dirname, '../..'),
+		}),
+	],
+	test: {
+		globals: true,
+		environment: 'node',
+		include: ['**/*.{test,spec}.{ts,tsx}'],
+		exclude: ['node_modules', 'dist'],
+		coverage: {
+			provider: 'v8',
+			reporter: ['text', 'json', 'html'],
+			exclude: ['**/*.test.tsx', '**/*.spec.tsx', 'node_modules/'],
+		},
+	},
+});

pnpm-lock.yaml

@@ -1991,6 +1991,12 @@ importers:
       '@typescript/native-preview':
         specifier: 'catalog:'
         version: 7.0.0-dev.20260224.1
+      vite-tsconfig-paths:
+        specifier: 'catalog:'
+        version: 6.1.1(typescript@5.9.3)(vite@7.3.1(@types/node@25.3.0)(jiti@2.6.1)(lightningcss@1.31.1)(tsx@4.21.0)(yaml@2.8.2))
+      vitest:
+        specifier: 'catalog:'
+        version: 4.0.18(@opentelemetry/api@1.9.0)(@types/node@25.3.0)(@vitest/browser-playwright@4.0.18)(happy-dom@20.7.0)(jiti@2.6.1)(jsdom@28.1.0)(lightningcss@1.31.1)(msw@2.12.10(@types/node@25.3.0)(typescript@5.9.3))(tsx@4.21.0)(yaml@2.8.2)
 
   packages/openapi:
     dependencies: