From dd159c4566d927633e217503f87d92df7a7a63c0 Mon Sep 17 00:00:00 2001 From: Danny Avila Date: Thu, 6 Aug 2026 08:12:00 -0400 Subject: [PATCH] =?UTF-8?q?=F0=9F=94=90=20fix:=20Preserve=20Structured=20J?= =?UTF-8?q?WT=20Auth=20Context=20(#14652)?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit * 🔐 fix: Preserve structured JWT auth context * fix: Omit identity from auth correlation logs * fix: Isolate pre-auth request context * style: Sort auth context imports * fix: Preserve structured auth metadata * fix: Narrow structured log formatter types * fix: Annotate structured log context keys * test: Fix request fixture typing * fix: Namespace request path log context * fix: Namespace request method log context * fix: Preserve captured tenant error paths * style: Sort tenant error imports * fix: Classify bulk tenant isolation failures * fix: Enforce safe request correlation invariants --- api/server/experimental.js | 2 + api/server/index.js | 2 + .../__tests__/requireJwtAuth.spec.js | 276 +++++------------- api/server/middleware/requireJwtAuth.js | 72 +++-- .../src/middleware/__tests__/tenant.spec.ts | 100 +++++++ packages/api/src/middleware/auth.spec.ts | 193 ++++++++++-- packages/api/src/middleware/auth.ts | 229 +++++++++++++-- packages/api/src/middleware/error.spec.ts | 67 ++++- packages/api/src/middleware/error.ts | 17 +- packages/api/src/middleware/index.ts | 1 + .../api/src/middleware/preAuthTenant.spec.ts | 25 +- packages/api/src/middleware/preAuthTenant.ts | 6 +- packages/api/src/middleware/tenant.ts | 68 +++-- .../data-schemas/src/config/parsers.spec.ts | 73 ++++- packages/data-schemas/src/config/parsers.ts | 29 +- .../src/config/requestLogContext.spec.ts | 109 +++++++ .../src/config/requestLogContext.ts | 160 ++++++++++ .../data-schemas/src/config/tenantContext.ts | 19 +- packages/data-schemas/src/config/winston.ts | 47 +-- packages/data-schemas/src/index.ts | 2 + 20 files changed, 1104 insertions(+), 393 deletions(-) create mode 100644 packages/data-schemas/src/config/requestLogContext.spec.ts create mode 100644 packages/data-schemas/src/config/requestLogContext.ts diff --git a/api/server/experimental.js b/api/server/experimental.js index aa387616c4..d99b9ca12b 100644 --- a/api/server/experimental.js +++ b/api/server/experimental.js @@ -23,6 +23,7 @@ const { loadToolApprovalHooks, maybeInjectQueryDevtoolsBootstrap, preAuthTenantMiddleware, + requestContextMiddleware, configureServerTimeouts, configureMessageFilterRegexValidator, } = require('@librechat/api'); @@ -358,6 +359,7 @@ if (cluster.isMaster) { app.get('/health', (_req, res) => res.status(200).send('OK')); /** Middleware */ + app.use(requestContextMiddleware); app.use(noIndex); app.use(express.json({ limit: '3mb' })); app.use(express.urlencoded({ extended: true, limit: '3mb' })); diff --git a/api/server/index.js b/api/server/index.js index 1401f8b9d6..7d9b5d9293 100644 --- a/api/server/index.js +++ b/api/server/index.js @@ -28,6 +28,7 @@ const { loadToolApprovalHooks, maybeInjectQueryDevtoolsBootstrap, preAuthTenantMiddleware, + requestContextMiddleware, registerShutdownTask, configureServerTimeouts, setupGracefulShutdown, @@ -204,6 +205,7 @@ const startServer = async () => { }); /* Middleware */ + app.use(requestContextMiddleware); app.use('/api/agents/chat', agentStartupIngressMiddleware); app.use(metricsMiddleware); app.use(noIndex); diff --git a/api/server/middleware/__tests__/requireJwtAuth.spec.js b/api/server/middleware/__tests__/requireJwtAuth.spec.js index 64e00e4aa4..6e1eba6a82 100644 --- a/api/server/middleware/__tests__/requireJwtAuth.spec.js +++ b/api/server/middleware/__tests__/requireJwtAuth.spec.js @@ -54,152 +54,7 @@ jest.mock('@librechat/data-schemas', () => { // primitives. The real implementation is covered by packages/api tenant.spec.ts. jest.mock('@librechat/api', () => { const { tenantStorage } = require('@librechat/data-schemas'); - const normalizeAuthLogValue = (value) => { - if (value == null) { - return undefined; - } - if (Array.isArray(value)) { - for (const entry of value) { - const normalized = normalizeAuthLogValue(entry); - if (normalized) { - return normalized; - } - } - return undefined; - } - if (typeof value === 'string') { - const trimmed = value.trim(); - return trimmed || undefined; - } - if (typeof value === 'number' || typeof value === 'boolean') { - return String(value); - } - return undefined; - }; - const normalizeAuthLogContextValue = (value) => { - if (value == null) { - return undefined; - } - if (Array.isArray(value)) { - const values = value - .map((entry) => normalizeAuthLogValue(entry)) - .filter((entry) => entry !== undefined); - return values.length > 0 ? values : undefined; - } - if (typeof value === 'string') { - return normalizeAuthLogValue(value); - } - if (typeof value === 'number') { - return Number.isFinite(value) ? value : undefined; - } - if (typeof value === 'boolean') { - return value; - } - return undefined; - }; - const getAuthFailureField = (source, field) => { - if (!source) { - return undefined; - } - if (typeof source === 'string') { - return field === 'message' ? source : undefined; - } - if (typeof source === 'object') { - try { - return source[field]; - } catch { - return undefined; - } - } - return undefined; - }; - const getAuthFailureReason = (err, info, fallback = 'Unauthorized') => - normalizeAuthLogValue(getAuthFailureField(info, 'message')) ?? - normalizeAuthLogValue(getAuthFailureField(err, 'message')) ?? - fallback; - const getAuthFailureErrorName = (err, info) => - normalizeAuthLogValue(getAuthFailureField(info, 'name')) ?? - normalizeAuthLogValue(getAuthFailureField(err, 'name')); - const getSafeTokenProvider = (tokenProvider) => { - const normalized = normalizeAuthLogValue(tokenProvider); - if (!normalized) { - return undefined; - } - return normalized === 'openid' || normalized === 'librechat' ? normalized : 'other'; - }; - const normalizeRoutePath = (path) => { - if (typeof path === 'string') { - return normalizeAuthLogValue(path); - } - if (Array.isArray(path)) { - for (const entry of path) { - const normalized = normalizeRoutePath(entry); - if (normalized) { - return normalized; - } - } - } - return undefined; - }; - const joinRoutePath = (baseUrl, routePath) => { - const normalizedRoute = routePath === '/' ? '' : routePath; - if (!baseUrl) { - return normalizedRoute || '/'; - } - if (!normalizedRoute) { - return baseUrl; - } - return `${baseUrl.replace(/\/$/, '')}/${normalizedRoute.replace(/^\//, '')}`; - }; - const bucketConcretePath = (path) => { - const queryless = path?.split('?')[0]; - if (!queryless) { - return undefined; - } - const segments = queryless.split('/').filter(Boolean); - if (segments.length === 0) { - return '/'; - } - if (segments[0] === 'api' && segments[1]) { - return `/${segments.slice(0, 2).join('/')}`; - } - return `/${segments[0]}`; - }; - const getRequestPath = (req) => { - const baseUrl = normalizeAuthLogValue(req.baseUrl); - const routePath = normalizeRoutePath(req.route?.path); - if (routePath) { - return joinRoutePath(baseUrl, routePath); - } - if (baseUrl) { - return baseUrl; - } - const path = - normalizeAuthLogValue(req.path) ?? normalizeAuthLogValue(req.originalUrl ?? req.url); - return bucketConcretePath(path); - }; - const compactAuthLogContext = (log) => - Object.fromEntries( - Object.entries(log) - .map(([key, value]) => [key, normalizeAuthLogContextValue(value)]) - .filter(([, value]) => value !== undefined), - ); - const buildSafeAuthLogContext = (req, authState, extra = {}) => - compactAuthLogContext({ - ...extra, - request_id: - normalizeAuthLogValue(req.requestId) ?? - normalizeAuthLogValue(req.id) ?? - normalizeAuthLogValue(req.headers?.['x-request-id']) ?? - normalizeAuthLogValue(req.headers?.['x-correlation-id']), - method: normalizeAuthLogValue(req.method), - path: getRequestPath(req), - token_provider: getSafeTokenProvider(authState.tokenProvider), - openid_reuse_enabled: authState.openidReuseEnabled, - openid_jwt_available: authState.openidJwtAvailable, - has_openid_reuse_user_id: authState.hasOpenIdReuseUserId, - }); - const formatAuthLogMessage = (message, context) => `${message} ${JSON.stringify(context)}`; + const actualApi = jest.requireActual('@librechat/api'); const normalizeContextValue = (value) => { const trimmed = value?.trim?.(); return trimmed || undefined; @@ -214,10 +69,8 @@ jest.mock('@librechat/api', () => { return { isEnabled: jest.fn(() => false), recordRumProxyRequest: jest.fn(), - getAuthFailureReason, - getAuthFailureErrorName, - buildSafeAuthLogContext, - formatAuthLogMessage, + getAuthFailureReasonCategory: actualApi.getAuthFailureReasonCategory, + buildSafeAuthLogContext: actualApi.buildSafeAuthLogContext, maybeRefreshCloudFrontAuthCookiesMiddleware: jest.fn((req, res, next) => next()), tenantContextMiddleware: (req, res, next) => { const context = { @@ -371,15 +224,17 @@ describe('requireJwtAuth tenant context chaining', () => { expect(res.status).toHaveBeenCalledWith(401); expect(getTenantId()).toBeUndefined(); expect(logger.debug).toHaveBeenCalledWith( - expect.stringContaining('[requireJwtAuth] Authentication failed after all strategies'), expect.objectContaining({ + message: '[requireJwtAuth] Authentication failed after all strategies', + event_name: 'jwt_auth_rejected', primary_strategy: 'jwt', fallback_attempted: false, fallback_succeeded: false, attempted_strategies: ['jwt'], final_strategy: 'jwt', - reason: 'Unauthorized', - status: 401, + reason_category: 'missing_or_unrecognized_token', + recovery_classification: 'terminal_rejection', + response_status: 401, }), ); expect(logger.warn).not.toHaveBeenCalled(); @@ -393,6 +248,7 @@ describe('requireJwtAuth tenant context chaining', () => { method: 'GET', path: '/api/messages', headers: { + authorization: 'Bearer valid-openid-token', cookie: `token_provider=openid; openid_user_id=${signedOpenIdUserCookie('user-jwt')}`, }, _mockStrategies: { @@ -413,40 +269,40 @@ describe('requireJwtAuth tenant context chaining', () => { expect(req.authStrategy).toBe('jwt'); expect(res.status).not.toHaveBeenCalled(); expect(logger.debug).toHaveBeenCalledWith( - expect.stringContaining('[requireJwtAuth] OpenID JWT auth failed; trying fallback'), expect.objectContaining({ + message: '[requireJwtAuth] OpenID JWT auth failed; trying fallback', + event_name: 'jwt_auth_fallback_attempt', request_id: 'req-expired-success', - method: 'GET', - path: '/api/messages', + request_method: 'GET', + request_path: '/api/messages', token_provider: 'openid', + token_source: 'bearer', openid_reuse_enabled: true, openid_jwt_available: true, has_openid_reuse_user_id: true, primary_strategy: 'openidJwt', fallback_strategy: 'jwt', fallback_attempted: true, - reason: 'jwt expired', - error_name: 'TokenExpiredError', - status: 401, + reason_category: 'expired_jwt', + recovery_classification: 'fallback_attempted', + strategy_status: 401, }), ); expect(logger.debug).toHaveBeenCalledWith( - expect.stringContaining('[requireJwtAuth] JWT fallback succeeded after OpenID JWT failure'), expect.objectContaining({ + message: '[requireJwtAuth] JWT fallback succeeded after OpenID JWT failure', + event_name: 'jwt_auth_recovered', request_id: 'req-expired-success', auth_strategy: 'jwt', primary_strategy: 'openidJwt', fallback_strategy: 'jwt', fallback_attempted: true, fallback_succeeded: true, - primary_failure_reason: 'jwt expired', - reason: 'jwt expired', - error_name: 'TokenExpiredError', + primary_failure_reason_category: 'expired_jwt', + recovery_classification: 'fallback_succeeded', }), ); - expect(logger.debug.mock.calls[0][0]).toContain('"reason":"jwt expired"'); - expect(logger.debug.mock.calls[0][0]).toContain('"fallback_attempted":true'); - expect(logger.debug.mock.calls[1][0]).toContain('"fallback_succeeded":true'); + expect(JSON.stringify(logger.debug.mock.calls)).not.toContain('jwt expired'); expect(logger.warn).not.toHaveBeenCalled(); }); @@ -491,20 +347,20 @@ describe('requireJwtAuth tenant context chaining', () => { expect(req.authStrategy).toBe('jwt'); expect(res.status).not.toHaveBeenCalled(); expect(logger.debug).toHaveBeenCalledWith( - expect.stringContaining('[requireJwtAuth] OpenID JWT auth failed; trying fallback'), expect.objectContaining({ + message: '[requireJwtAuth] OpenID JWT auth failed; trying fallback', request_id: 'req-malformed-info', fallback_attempted: true, - reason: 'Unauthorized', - status: 401, + reason_category: 'missing_or_unrecognized_token', + strategy_status: 401, }), ); expect(logger.debug).toHaveBeenCalledWith( - expect.stringContaining('[requireJwtAuth] JWT fallback succeeded after OpenID JWT failure'), expect.objectContaining({ + message: '[requireJwtAuth] JWT fallback succeeded after OpenID JWT failure', request_id: 'req-malformed-info', fallback_succeeded: true, - primary_failure_reason: 'Unauthorized', + primary_failure_reason_category: 'missing_or_unrecognized_token', }), ); }); @@ -540,23 +396,24 @@ describe('requireJwtAuth tenant context chaining', () => { expect(next).not.toHaveBeenCalled(); expect(res.status).toHaveBeenCalledWith(401); expect(logger.debug).toHaveBeenCalledWith( - expect.stringContaining('[requireJwtAuth] OpenID JWT auth failed; trying fallback'), expect.objectContaining({ + message: '[requireJwtAuth] OpenID JWT auth failed; trying fallback', + event_name: 'jwt_auth_fallback_attempt', request_id: 'req-expired-fail', - method: 'POST', - path: '/api/ask', + request_method: 'POST', + request_path: '/api/ask', fallback_attempted: true, - reason: 'jwt expired', - error_name: 'TokenExpiredError', - status: 401, + reason_category: 'expired_jwt', + strategy_status: 401, }), ); expect(logger.warn).toHaveBeenCalledWith( - expect.stringContaining('[requireJwtAuth] Authentication failed after all strategies'), expect.objectContaining({ + message: '[requireJwtAuth] Authentication failed after all strategies', + event_name: 'jwt_auth_rejected', request_id: 'req-expired-fail', - method: 'POST', - path: '/api/ask', + request_method: 'POST', + request_path: '/api/ask', token_provider: 'openid', attempted_strategies: ['openidJwt', 'jwt'], final_strategy: 'jwt', @@ -564,24 +421,23 @@ describe('requireJwtAuth tenant context chaining', () => { fallback_strategy: 'jwt', fallback_attempted: true, fallback_succeeded: false, - // The real openidJwt failure is surfaced alongside the fallback's reason so a - // reused-token failure is not misattributed to the `jwt` fallback's error (#14311). - primary_failure_reason: 'jwt expired', - primary_failure_error_name: 'TokenExpiredError', - reason: 'invalid signature', - error_name: 'JsonWebTokenError', - status: 401, + primary_failure_reason_category: 'expired_jwt', + reason_category: 'malformed_jwt', + recovery_classification: 'terminal_rejection', + response_status: 401, }), ); - expect(logger.warn.mock.calls[0][0]).toContain('"reason":"invalid signature"'); - expect(logger.warn.mock.calls[0][0]).toContain('"primary_failure_reason":"jwt expired"'); - expect(logger.warn.mock.calls[0][0]).toContain('"path":"/api/ask"'); + expect(JSON.stringify(logger.warn.mock.calls)).not.toContain('invalid signature'); }); - it('does not fall back to OpenID JWT for bearer-only reuse requests', () => { + it('attributes malformed bearer rejections as structured 401s without an OpenID fallback', () => { isEnabled.mockReturnValue(true); mockRegisteredStrategies.add('openidJwt'); const req = mockReq(undefined, { + id: 'malformed-bearer-401', + method: 'GET', + originalUrl: '/api/banner?access_token=not-logged', + headers: { authorization: 'Bearer malformed-token' }, _mockStrategies: { jwt: { user: false, info: { message: 'invalid signature' }, status: 401 }, openidJwt: { user: { tenantId: 'tenant-openid', role: 'user' } }, @@ -601,6 +457,20 @@ describe('requireJwtAuth tenant context chaining', () => { { session: false }, expect.any(Function), ); + expect(logger.warn).toHaveBeenCalledWith( + expect.objectContaining({ + event_name: 'jwt_auth_rejected', + request_id: 'malformed-bearer-401', + request_method: 'GET', + request_path: '/api/banner', + token_source: 'bearer', + reason_category: 'malformed_jwt', + recovery_classification: 'terminal_rejection', + response_status: 401, + }), + ); + expect(JSON.stringify(logger.warn.mock.calls)).not.toContain('malformed-token'); + expect(JSON.stringify(logger.warn.mock.calls)).not.toContain('invalid signature'); }); it('uses OpenID JWT before LibreChat JWT when the OpenID cookie is present', async () => { @@ -658,25 +528,24 @@ describe('requireJwtAuth tenant context chaining', () => { expect(next).toHaveBeenCalled(); expect(req.authStrategy).toBe('jwt'); expect(logger.debug).toHaveBeenCalledWith( - expect.stringContaining('[requireJwtAuth] OpenID JWT auth failed; trying fallback'), expect.objectContaining({ + message: '[requireJwtAuth] OpenID JWT auth failed; trying fallback', request_id: 'req-mismatch-success', primary_strategy: 'openidJwt', fallback_strategy: 'jwt', fallback_attempted: true, - reason: 'openid user-id mismatch', - status: 401, + reason_category: 'principal_mismatch', + strategy_status: 401, }), ); expect(logger.debug).toHaveBeenCalledWith( - expect.stringContaining('[requireJwtAuth] JWT fallback succeeded after OpenID JWT failure'), expect.objectContaining({ + message: '[requireJwtAuth] JWT fallback succeeded after OpenID JWT failure', request_id: 'req-mismatch-success', auth_strategy: 'jwt', fallback_attempted: true, fallback_succeeded: true, - primary_failure_reason: 'openid user-id mismatch', - reason: 'openid user-id mismatch', + primary_failure_reason_category: 'principal_mismatch', }), ); expect(logger.warn).not.toHaveBeenCalled(); @@ -705,24 +574,25 @@ describe('requireJwtAuth tenant context chaining', () => { expect(next).not.toHaveBeenCalled(); expect(res.status).toHaveBeenCalledWith(401); expect(logger.debug).toHaveBeenCalledWith( - expect.stringContaining('[requireJwtAuth] OpenID JWT auth failed; trying fallback'), expect.objectContaining({ + message: '[requireJwtAuth] OpenID JWT auth failed; trying fallback', request_id: 'req-mismatch-fail', fallback_attempted: true, - reason: 'openid user-id mismatch', - status: 401, + reason_category: 'principal_mismatch', + strategy_status: 401, }), ); expect(logger.warn).toHaveBeenCalledWith( - expect.stringContaining('[requireJwtAuth] Authentication failed after all strategies'), expect.objectContaining({ + message: '[requireJwtAuth] Authentication failed after all strategies', request_id: 'req-mismatch-fail', attempted_strategies: ['openidJwt', 'jwt'], final_strategy: 'jwt', fallback_attempted: true, fallback_succeeded: false, - reason: 'Unauthorized', - status: 401, + primary_failure_reason_category: 'principal_mismatch', + reason_category: 'missing_or_unrecognized_token', + response_status: 401, }), ); }); diff --git a/api/server/middleware/requireJwtAuth.js b/api/server/middleware/requireJwtAuth.js index b4877bcdc5..8457018320 100644 --- a/api/server/middleware/requireJwtAuth.js +++ b/api/server/middleware/requireJwtAuth.js @@ -5,10 +5,8 @@ const { logger } = require('@librechat/data-schemas'); const { isEnabled, tenantContextMiddleware, - getAuthFailureReason, - getAuthFailureErrorName, + getAuthFailureReasonCategory, buildSafeAuthLogContext, - formatAuthLogMessage, maybeRefreshCloudFrontAuthCookiesMiddleware, recordRumProxyRequest, } = require('@librechat/api'); @@ -36,6 +34,12 @@ const getAuthenticatedUserId = (user) => user?.id?.toString?.() ?? user?._id?.to const refreshCloudFrontCookies = maybeRefreshCloudFrontAuthCookiesMiddleware ?? ((_req, _res, next) => next()); +const getAuthTokenSource = (req) => { + const authorization = req.headers.authorization; + const value = Array.isArray(authorization) ? authorization[0] : authorization; + return typeof value === 'string' && /^Bearer\s+/i.test(value) ? 'bearer' : 'none'; +}; + const getAuthStrategies = (req) => { const cookieHeader = req.headers.cookie; const parsedCookies = cookieHeader ? cookies.parse(cookieHeader) : {}; @@ -48,6 +52,7 @@ const getAuthStrategies = (req) => { return { tokenProvider, + tokenSource: getAuthTokenSource(req), openidReuseEnabled, openidJwtAvailable, openIdReuseUserId, @@ -84,57 +89,61 @@ const isOpenIdReuseUser = (strategy, user, openIdReuseUserId) => * for downstream Mongoose tenant isolation and structured logging. */ const requireJwtAuth = (req, res, next) => { - const { tokenProvider, openidReuseEnabled, openidJwtAvailable, openIdReuseUserId, strategies } = - getAuthStrategies(req); + const { + tokenProvider, + tokenSource, + openidReuseEnabled, + openidJwtAvailable, + openIdReuseUserId, + strategies, + } = getAuthStrategies(req); const authLogState = { tokenProvider, + tokenSource, openidReuseEnabled, openidJwtAvailable, hasOpenIdReuseUserId: openIdReuseUserId != null, }; - let primaryFailureReason; - let primaryFailureErrorName; + let primaryFailureReasonCategory; let fallbackAttempted = false; - const logOpenIdFallbackAttempt = ({ fallbackStrategy, reason, errorName, status }) => { - primaryFailureReason = reason; - primaryFailureErrorName = errorName; + const logOpenIdFallbackAttempt = ({ fallbackStrategy, reasonCategory, status }) => { + primaryFailureReasonCategory = reasonCategory; fallbackAttempted = true; const message = '[requireJwtAuth] OpenID JWT auth failed; trying fallback'; const context = buildSafeAuthLogContext(req, authLogState, { + event_name: 'jwt_auth_fallback_attempt', primary_strategy: 'openidJwt', fallback_strategy: fallbackStrategy, fallback_attempted: true, - reason, - error_name: errorName, - status, + reason_category: reasonCategory, + recovery_classification: 'fallback_attempted', + strategy_status: status, }); - logger.debug(formatAuthLogMessage(message, context), context); + logger.debug({ message, ...context }); }; const logAuthenticationFailure = ({ strategy, info, status, err }) => { const message = '[requireJwtAuth] Authentication failed after all strategies'; + const reasonCategory = getAuthFailureReasonCategory(err, info); const context = buildSafeAuthLogContext(req, authLogState, { + event_name: 'jwt_auth_rejected', primary_strategy: strategies[0], fallback_strategy: strategies[1], fallback_attempted: fallbackAttempted, fallback_succeeded: false, attempted_strategies: strategies, final_strategy: strategy, - // Surface the primary (openidJwt) failure alongside the final strategy's reason so a - // reused-token failure is not misattributed to the HS256 `jwt` fallback's "invalid - // algorithm" error, which is the fallback rejecting an RS256 provider token, not the - // real reason openidJwt did not authenticate. ...(fallbackAttempted && { - primary_failure_reason: primaryFailureReason, - primary_failure_error_name: primaryFailureErrorName, + primary_failure_reason_category: primaryFailureReasonCategory, }), - reason: getAuthFailureReason(err, info), - error_name: getAuthFailureErrorName(err, info), - status: status || 401, + reason_category: reasonCategory, + recovery_classification: 'terminal_rejection', + response_status: status || 401, }); - const log = fallbackAttempted ? logger.warn : logger.debug; - log.call(logger, formatAuthLogMessage(message, context), context); + const log = + fallbackAttempted || reasonCategory === 'malformed_jwt' ? logger.warn : logger.debug; + log.call(logger, { message, ...context }); }; const logFallbackSuccess = (strategy) => { @@ -143,16 +152,16 @@ const requireJwtAuth = (req, res, next) => { } const message = '[requireJwtAuth] JWT fallback succeeded after OpenID JWT failure'; const context = buildSafeAuthLogContext(req, authLogState, { + event_name: 'jwt_auth_recovered', auth_strategy: 'jwt', primary_strategy: 'openidJwt', fallback_strategy: 'jwt', fallback_attempted: true, fallback_succeeded: true, - primary_failure_reason: primaryFailureReason, - reason: primaryFailureReason, - error_name: primaryFailureErrorName, + primary_failure_reason_category: primaryFailureReasonCategory, + recovery_classification: 'fallback_succeeded', }); - logger.debug(formatAuthLogMessage(message, context), context); + logger.debug({ message, ...context }); }; const authenticateWithStrategy = (index) => { @@ -165,8 +174,7 @@ const requireJwtAuth = (req, res, next) => { if (index + 1 < strategies.length) { logOpenIdFallbackAttempt({ fallbackStrategy: strategies[index + 1], - reason: getAuthFailureReason(err, info), - errorName: getAuthFailureErrorName(err, info), + reasonCategory: getAuthFailureReasonCategory(err, info), status: status || 401, }); return authenticateWithStrategy(index + 1); @@ -180,7 +188,7 @@ const requireJwtAuth = (req, res, next) => { if (index + 1 < strategies.length) { logOpenIdFallbackAttempt({ fallbackStrategy: strategies[index + 1], - reason: 'openid user-id mismatch', + reasonCategory: 'principal_mismatch', status: 401, }); return authenticateWithStrategy(index + 1); diff --git a/packages/api/src/middleware/__tests__/tenant.spec.ts b/packages/api/src/middleware/__tests__/tenant.spec.ts index ff9ddd1a1a..d21ad2cb2f 100644 --- a/packages/api/src/middleware/__tests__/tenant.spec.ts +++ b/packages/api/src/middleware/__tests__/tenant.spec.ts @@ -3,6 +3,8 @@ import { getTenantId, getUserId, getRequestId, + getRequestMethod, + getRequestPath, SYSTEM_TENANT_ID, logger, } from '@librechat/data-schemas'; @@ -12,6 +14,7 @@ import type { ServerRequest } from '~/types/http'; // excluded from the public barrel export (index.ts). import { tenantContextMiddleware, + requestContextMiddleware, restoreTenantContextFromReq, resolveRequestTenantId, _resetTenantMiddlewareStrictCache, @@ -76,6 +79,103 @@ function runMiddlewareContext( }); } +function runRequestContext(req: Parameters[0]): Promise<{ + tenantId?: string; + userId?: string; + requestId?: string; + method?: string; + path?: string; +}> { + return new Promise((resolve) => { + requestContextMiddleware(req, mockRes(), async () => { + await new Promise((nextTick) => setImmediate(nextTick)); + resolve({ + tenantId: getTenantId(), + userId: getUserId(), + requestId: getRequestId(), + method: getRequestMethod(), + path: getRequestPath(), + }); + }); + }); +} + +describe('requestContextMiddleware', () => { + it('generates a safe request ID when no trusted correlation ID is available', async () => { + const req: Parameters[0] = { + headers: { + 'x-request-id': `${'a'.repeat(24)}.${'b'.repeat(24)}.${'c'.repeat(24)}`, + }, + method: 'GET', + originalUrl: '/api/banner', + }; + + const context = await runRequestContext(req); + + expect(context.requestId).toMatch( + /^[0-9a-f]{8}-[0-9a-f]{4}-4[0-9a-f]{3}-[89ab][0-9a-f]{3}-[0-9a-f]{12}$/, + ); + expect(req.requestId).toBe(context.requestId); + }); + + it('does not trust tenant or user identity before authentication', async () => { + const req: Parameters[0] = { + headers: { 'x-request-id': 'pre-auth-request' }, + method: 'GET', + originalUrl: '/api/auth/me', + tenantId: 'untrusted-tenant', + user: { id: 'untrusted-user', tenantId: 'untrusted-tenant' }, + }; + + const context = await runRequestContext(req); + + expect(context).toEqual({ + tenantId: undefined, + userId: undefined, + requestId: 'pre-auth-request', + method: 'GET', + path: '/api/auth', + }); + expect(req.requestId).toBe('pre-auth-request'); + }); + + it('keeps malformed-auth and parallel page requests independently attributable', async () => { + const malformedAuthRequest = { + headers: { + authorization: 'Bearer malformed-token', + 'x-request-id': 'auth-401-request', + }, + method: 'GET', + originalUrl: '/api/auth/me?access_token=not-logged', + }; + const pageRequest = { + headers: { 'x-request-id': 'page-request' }, + method: 'GET', + originalUrl: '/api/banner?access_token=not-logged', + }; + + const [authContext, pageContext] = await Promise.all([ + runRequestContext(malformedAuthRequest), + runRequestContext(pageRequest), + ]); + + expect(authContext).toEqual({ + tenantId: undefined, + userId: undefined, + requestId: 'auth-401-request', + method: 'GET', + path: '/api/auth', + }); + expect(pageContext).toEqual({ + tenantId: undefined, + userId: undefined, + requestId: 'page-request', + method: 'GET', + path: '/api/banner', + }); + }); +}); + describe('tenantContextMiddleware', () => { afterEach(() => { _resetTenantMiddlewareStrictCache(); diff --git a/packages/api/src/middleware/auth.spec.ts b/packages/api/src/middleware/auth.spec.ts index 1c39b387df..246d64f22e 100644 --- a/packages/api/src/middleware/auth.spec.ts +++ b/packages/api/src/middleware/auth.spec.ts @@ -1,10 +1,12 @@ +import type { AuthLogRequest, AuthLogState } from './auth'; import { buildSafeAuthLogContext, - formatAuthLogMessage, + buildSafeRequestLogContext, + buildTenantIsolationErrorLogContext, getAuthFailureErrorName, getAuthFailureReason, + getAuthFailureReasonCategory, } from './auth'; -import type { AuthLogRequest, AuthLogState } from './auth'; function createRequest(overrides: Partial = {}): AuthLogRequest { return { @@ -19,6 +21,7 @@ function createRequest(overrides: Partial = {}): AuthLogRequest function createAuthState(overrides: Partial = {}): AuthLogState { return { tokenProvider: 'openid', + tokenSource: 'bearer', openidReuseEnabled: true, openidJwtAvailable: true, hasOpenIdReuseUserId: true, @@ -36,29 +39,32 @@ describe('auth middleware logging helpers', () => { }), createAuthState(), { + event_name: 'jwt_auth_rejected', attempted_strategies: ['openidJwt', 'jwt'], fallback_attempted: true, fallback_succeeded: false, - reason: 'jwt expired', - error_name: 'TokenExpiredError', - status: 401, + reason_category: 'expired_jwt', + recovery_classification: 'terminal_rejection', + response_status: 401, }, ); expect(log).toEqual({ request_id: 'request-id', - method: 'GET', - path: '/api/ask', + request_method: 'GET', + request_path: '/api/ask', token_provider: 'openid', + token_source: 'bearer', openid_reuse_enabled: true, openid_jwt_available: true, has_openid_reuse_user_id: true, attempted_strategies: ['openidJwt', 'jwt'], fallback_attempted: true, fallback_succeeded: false, - reason: 'jwt expired', - error_name: 'TokenExpiredError', - status: 401, + event_name: 'jwt_auth_rejected', + reason_category: 'expired_jwt', + recovery_classification: 'terminal_rejection', + response_status: 401, }); expect(JSON.stringify(log)).not.toContain('secret-token'); }); @@ -72,6 +78,7 @@ describe('auth middleware logging helpers', () => { }), createAuthState({ tokenProvider: null, + tokenSource: null, openidReuseEnabled: false, openidJwtAvailable: false, hasOpenIdReuseUserId: false, @@ -80,14 +87,47 @@ describe('auth middleware logging helpers', () => { expect(log).toEqual({ request_id: 'header-request-id', - method: 'GET', - path: '/api/messages', + request_method: 'GET', + request_path: '/api/messages', openid_reuse_enabled: false, openid_jwt_available: false, has_openid_reuse_user_id: false, }); }); + it.each([ + `${'a'.repeat(24)}.${'b'.repeat(24)}.${'c'.repeat(24)}`, + 'header..signature', + 'header.payload.', + 'header..initialization-vector.ciphertext.authentication-tag', + 'a'.repeat(129), + ])('drops credential-shaped or oversized request ID %s', (requestId) => { + const log = buildSafeAuthLogContext( + createRequest({ headers: { 'x-request-id': requestId } }), + createAuthState(), + ); + + expect(log.request_id).toBeUndefined(); + }); + + it('uses the next valid correlation candidate after rejecting an unsafe request ID', () => { + const context = buildSafeRequestLogContext( + createRequest({ + requestId: `${'a'.repeat(24)}.${'b'.repeat(24)}.${'c'.repeat(24)}`, + headers: { 'x-request-id': 'safe-header-request' }, + }), + ); + + expect(context.request_id).toBe('safe-header-request'); + }); + + it('normalizes known request methods and buckets unknown methods', () => { + expect(buildSafeRequestLogContext(createRequest({ method: 'get' })).request_method).toBe('GET'); + expect( + buildSafeRequestLogContext(createRequest({ method: 'CUSTOM_METHOD' })).request_method, + ).toBe('OTHER'); + }); + it('buckets unknown token providers to keep auth logs low-cardinality', () => { const log = buildSafeAuthLogContext( createRequest(), @@ -99,6 +139,15 @@ describe('auth middleware logging helpers', () => { expect(log.token_provider).toBe('other'); }); + it('buckets unknown token sources to keep auth logs low-cardinality', () => { + const log = buildSafeAuthLogContext( + createRequest(), + createAuthState({ tokenSource: 'attacker-controlled-source' }), + ); + + expect(log.token_source).toBe('other'); + }); + it('prefers route buckets over concrete dynamic request paths', () => { const log = buildSafeAuthLogContext( createRequest({ @@ -109,7 +158,7 @@ describe('auth middleware logging helpers', () => { createAuthState(), ); - expect(log.path).toBe('/api/messages'); + expect(log.request_path).toBe('/api/messages'); expect(JSON.stringify(log)).not.toContain('conversation-123'); expect(JSON.stringify(log)).not.toContain('message-456'); expect(JSON.stringify(log)).not.toContain('secret-token'); @@ -125,48 +174,127 @@ describe('auth middleware logging helpers', () => { createAuthState(), ); - expect(log.path).toBe('/api/share/link/:conversationId'); + expect(log.request_path).toBe('/api/share/link/:conversationId'); }); - it('drops unsupported extra values and keeps safe arrays primitive', () => { + it('buckets the original URL when Express leaves an unmounted route template', () => { + const context = buildSafeRequestLogContext( + createRequest({ + baseUrl: '', + path: '/conversation-123', + originalUrl: '/api/convos/conversation-123?access_token=secret-token', + route: { path: '/:id' }, + }), + ); + + expect(context.request_path).toBe('/api/convos'); + expect(JSON.stringify(context)).not.toContain('conversation-123'); + expect(JSON.stringify(context)).not.toContain('secret-token'); + }); + + it('drops unsupported and sensitive extra values while keeping allowed fields', () => { const log = buildSafeAuthLogContext(createRequest({ id: 'request-id' }), createAuthState(), { attempted_strategies: ['openidJwt', '', { strategy: 'jwt' }, 'jwt'], fallback_attempted: true, path: { unsafe: true }, request_id: { unsafe: true }, - status: Number.NaN, + response_status: Number.NaN, unsafe_object: { token: 'secret-token' }, reason: ' jwt expired ', }); expect(log).toEqual({ request_id: 'request-id', - method: 'GET', - path: '/api/messages', + request_method: 'GET', + request_path: '/api/messages', token_provider: 'openid', + token_source: 'bearer', openid_reuse_enabled: true, openid_jwt_available: true, has_openid_reuse_user_id: true, attempted_strategies: ['openidJwt', 'jwt'], fallback_attempted: true, - reason: 'jwt expired', }); expect(JSON.stringify(log)).not.toContain('secret-token'); }); - it('formats auth log messages with serialized safe context for stdout collectors', () => { - const log = buildSafeAuthLogContext(createRequest({ id: 'request-id' }), createAuthState(), { - fallback_attempted: true, - reason: 'jwt expired', - error_name: 'TokenExpiredError', - status: 401, - }); - - expect( - formatAuthLogMessage('[requireJwtAuth] OpenID JWT auth failed; trying fallback', log), - ).toBe( - '[requireJwtAuth] OpenID JWT auth failed; trying fallback {"fallback_attempted":true,"reason":"jwt expired","error_name":"TokenExpiredError","status":401,"request_id":"request-id","method":"GET","path":"/api/messages","token_provider":"openid","openid_reuse_enabled":true,"openid_jwt_available":true,"has_openid_reuse_user_id":true}', + it('builds request context without raw query strings', () => { + const context = buildSafeRequestLogContext( + createRequest({ + id: 'request-id', + path: undefined, + originalUrl: '/api/convos/conversation-123?access_token=secret-token', + }), ); + + expect(context).toEqual({ + request_id: 'request-id', + request_method: 'GET', + request_path: '/api/convos', + }); + expect(JSON.stringify(context)).not.toContain('secret-token'); + }); + + it('builds a safe, joinable context for tenant-isolation errors', () => { + const context = buildTenantIsolationErrorLogContext( + createRequest({ + id: 'request-id', + path: undefined, + originalUrl: '/api/banner?access_token=secret-token', + }), + new Error('[TenantIsolation] Query attempted without tenant context in strict mode'), + ); + + expect(context).toEqual({ + event_name: 'tenant_isolation_error', + error_category: 'tenant_isolation', + error_signature: 'missing_query_context', + response_status: 500, + request_id: 'request-id', + request_method: 'GET', + request_path: '/api/banner', + }); + expect(JSON.stringify(context)).not.toContain('secret-token'); + }); + + it.each([ + [ + '[TenantIsolation] Query attempted without tenant context in strict mode', + 'missing_query_context', + ], + [ + '[TenantIsolation] Aggregate attempted without tenant context in strict mode', + 'missing_aggregate_context', + ], + [ + '[TenantIsolation] Save attempted without tenant context in strict mode', + 'missing_save_context', + ], + [ + '[TenantIsolation] insertMany attempted without tenant context in strict mode', + 'missing_insert_many_context', + ], + [ + '[TenantIsolation] bulkWrite on Message attempted without tenant context in strict mode', + 'missing_bulk_write_context', + ], + [ + '[TenantIsolation] Unknown bulkWrite operation type in strict mode — refusing to pass through without tenant injection', + 'unsupported_bulk_write_operation', + ], + ['[TenantIsolation] Cross-tenant tenantId mutation is not allowed', 'cross_tenant_mutation'], + [ + '[TenantIsolation] Document tenantId does not match current tenant context', + 'tenant_mismatch', + ], + [ + '[TenantIsolation] Modifying tenantId via replacement is not allowed', + 'replacement_tenant_mutation', + ], + ])('classifies known tenant-isolation error %s', (message, errorSignature) => { + const context = buildTenantIsolationErrorLogContext(createRequest(), new Error(message)); + + expect(context?.error_signature).toBe(errorSignature); }); it('prefers Passport info fields for auth failure reason and error name', () => { @@ -175,6 +303,7 @@ describe('auth middleware logging helpers', () => { expect(getAuthFailureReason(err, info)).toBe('jwt expired'); expect(getAuthFailureErrorName(err, info)).toBe('TokenExpiredError'); + expect(getAuthFailureReasonCategory(err, info)).toBe('expired_jwt'); }); it('falls back to Error fields when Passport info is absent', () => { @@ -182,6 +311,7 @@ describe('auth middleware logging helpers', () => { expect(getAuthFailureReason(err, undefined)).toBe('invalid signature'); expect(getAuthFailureErrorName(err, undefined)).toBe('JsonWebTokenError'); + expect(getAuthFailureReasonCategory(err, undefined)).toBe('malformed_jwt'); }); it('does not throw when Passport failure objects expose throwing getters', () => { @@ -202,5 +332,6 @@ describe('auth middleware logging helpers', () => { expect(getAuthFailureReason(err, info)).toBe('invalid signature'); expect(getAuthFailureErrorName(err, info)).toBe('JsonWebTokenError'); + expect(getAuthFailureReasonCategory(err, info)).toBe('malformed_jwt'); }); }); diff --git a/packages/api/src/middleware/auth.ts b/packages/api/src/middleware/auth.ts index 2ae429f6a0..a195ceaaa1 100644 --- a/packages/api/src/middleware/auth.ts +++ b/packages/api/src/middleware/auth.ts @@ -7,6 +7,36 @@ type AuthLogValue = string | number | boolean | readonly string[]; type AuthLogHeaderValue = string | string[] | undefined; type AuthRoutePath = string | RegExp | readonly (string | RegExp)[]; +const COMPACT_JWT_VALUE = + /^[A-Za-z0-9_-]+(?:\.[A-Za-z0-9_-]*){2}$|^[A-Za-z0-9_-]+(?:\.[A-Za-z0-9_-]*){4}$/; +const MAX_REQUEST_ID_LENGTH = 128; +const SAFE_REQUEST_METHODS = new Set([ + 'CONNECT', + 'DELETE', + 'GET', + 'HEAD', + 'OPTIONS', + 'PATCH', + 'POST', + 'PUT', + 'TRACE', +]); +const AUTH_LOG_EXTRA_KEYS = new Set([ + 'event_name', + 'auth_strategy', + 'primary_strategy', + 'fallback_strategy', + 'fallback_attempted', + 'fallback_succeeded', + 'attempted_strategies', + 'final_strategy', + 'primary_failure_reason_category', + 'reason_category', + 'recovery_classification', + 'response_status', + 'strategy_status', +]); + export type AuthLogRequest = { headers?: Record; method?: string; @@ -23,12 +53,26 @@ export type AuthLogRequest = { export type AuthLogState = { tokenProvider?: string | null; + tokenSource?: string | null; openidReuseEnabled: boolean; openidJwtAvailable: boolean; hasOpenIdReuseUserId: boolean; }; -export type AuthLogContext = Record; +export type RequestLogContext = { + request_id?: string; + request_method?: string; + request_path?: string; +}; + +export type AuthLogContext = RequestLogContext & Record; + +export type AuthFailureReasonCategory = + | 'expired_jwt' + | 'malformed_jwt' + | 'principal_mismatch' + | 'missing_or_unrecognized_token' + | 'authentication_error'; function normalizeAuthLogValue(value: unknown): string | undefined { if (value == null) { @@ -85,12 +129,34 @@ function normalizeAuthLogContextValue(value: unknown): AuthLogValue | undefined } function getRequestId(req: AuthLogRequest): string | undefined { - return ( - normalizeAuthLogValue(req.requestId) ?? - normalizeAuthLogValue(req.id) ?? - normalizeAuthLogValue(req.headers?.['x-request-id']) ?? - normalizeAuthLogValue(req.headers?.['x-correlation-id']) - ); + const candidates = [ + req.requestId, + req.id, + req.headers?.['x-request-id'], + req.headers?.['x-correlation-id'], + ]; + + for (const candidate of candidates) { + const requestId = normalizeAuthLogValue(candidate); + if ( + requestId && + requestId.length <= MAX_REQUEST_ID_LENGTH && + !COMPACT_JWT_VALUE.test(requestId) && + /^[A-Za-z0-9_.:-]+$/.test(requestId) + ) { + return requestId; + } + } + + return undefined; +} + +function getRequestMethod(method: unknown): string | undefined { + const normalized = normalizeAuthLogValue(method)?.toUpperCase(); + if (!normalized) { + return undefined; + } + return SAFE_REQUEST_METHODS.has(normalized) ? normalized : 'OTHER'; } function normalizeRoutePath(path: AuthRoutePath | undefined): string | undefined { @@ -138,19 +204,34 @@ function bucketConcretePath(path: string | undefined): string | undefined { } function getRequestPath(req: AuthLogRequest): string | undefined { - const baseUrl = normalizeAuthLogValue(req.baseUrl); + const baseUrl = bucketConcretePath(normalizeAuthLogValue(req.baseUrl)); const routePath = normalizeRoutePath(req.route?.path); - if (routePath) { + if (routePath && baseUrl) { return joinRoutePath(baseUrl, routePath); } if (baseUrl) { return baseUrl; } - const path = normalizeAuthLogValue(req.path) ?? normalizeAuthLogValue(req.originalUrl ?? req.url); + const path = + normalizeAuthLogValue(req.originalUrl) ?? + normalizeAuthLogValue(req.path) ?? + normalizeAuthLogValue(req.url); return bucketConcretePath(path); } +export function buildSafeRequestLogContext(req: AuthLogRequest): RequestLogContext { + const requestId = getRequestId(req); + const requestMethod = getRequestMethod(req.method); + const requestPath = getRequestPath(req); + + return { + ...(requestId && { request_id: requestId }), + ...(requestMethod && { request_method: requestMethod }), + ...(requestPath && { request_path: requestPath }), + }; +} + function getAuthFailureField(source: unknown, field: keyof AuthFailureLike): unknown { if (!source) { return undefined; @@ -168,10 +249,10 @@ function getAuthFailureField(source: unknown, field: keyof AuthFailureLike): unk return undefined; } -function compactAuthLogContext(log: Record): AuthLogContext { +function compactAuthLogContext(log: object): AuthLogContext { const compacted: Partial = {}; - for (const key of Object.keys(log)) { - const value = normalizeAuthLogContextValue(log[key]); + for (const [key, rawValue] of Object.entries(log)) { + const value = normalizeAuthLogContextValue(rawValue); if (value !== undefined) { Object.assign(compacted, { [key]: value }); } @@ -179,6 +260,10 @@ function compactAuthLogContext(log: Record): AuthLogContext { return compacted as AuthLogContext; } +function selectAuthLogExtra(extra: object): object { + return Object.fromEntries(Object.entries(extra).filter(([key]) => AUTH_LOG_EXTRA_KEYS.has(key))); +} + export function getAuthFailureReason( err: unknown, info: unknown, @@ -198,6 +283,39 @@ export function getAuthFailureErrorName(err: unknown, info: unknown): string | u ); } +export function getAuthFailureReasonCategory( + err: unknown, + info: unknown, +): AuthFailureReasonCategory { + const reason = getAuthFailureReason(err, info).toLowerCase(); + const errorName = getAuthFailureErrorName(err, info)?.toLowerCase(); + + if (reason.includes('expired') || errorName === 'tokenexpirederror') { + return 'expired_jwt'; + } + + if (reason.includes('user-id mismatch') || reason.includes('principal mismatch')) { + return 'principal_mismatch'; + } + + if ( + errorName === 'jsonwebtokenerror' || + reason.includes('jwt malformed') || + reason.includes('invalid signature') || + reason.includes('invalid algorithm') || + reason.includes('invalid token') || + reason.includes('invalid key') + ) { + return 'malformed_jwt'; + } + + if (reason === 'unauthorized' || reason.includes('no auth token')) { + return 'missing_or_unrecognized_token'; + } + + return 'authentication_error'; +} + function getSafeTokenProvider(tokenProvider: unknown): string | undefined { const normalized = normalizeAuthLogValue(tokenProvider); if (!normalized) { @@ -206,23 +324,86 @@ function getSafeTokenProvider(tokenProvider: unknown): string | undefined { return normalized === 'openid' || normalized === 'librechat' ? normalized : 'other'; } +function getSafeTokenSource(tokenSource: unknown): string | undefined { + const normalized = normalizeAuthLogValue(tokenSource); + if (!normalized) { + return undefined; + } + + return ['bearer', 'none'].includes(normalized) ? normalized : 'other'; +} + export function buildSafeAuthLogContext( req: AuthLogRequest, authState: AuthLogState, - extra: Record = {}, + extra: object = {}, ): AuthLogContext { - return compactAuthLogContext({ - ...extra, - request_id: getRequestId(req), - method: normalizeAuthLogValue(req.method), - path: getRequestPath(req), - token_provider: getSafeTokenProvider(authState.tokenProvider), - openid_reuse_enabled: authState.openidReuseEnabled, - openid_jwt_available: authState.openidJwtAvailable, - has_openid_reuse_user_id: authState.hasOpenIdReuseUserId, - }); + return { + ...compactAuthLogContext({ + ...selectAuthLogExtra(extra), + token_provider: getSafeTokenProvider(authState.tokenProvider), + token_source: getSafeTokenSource(authState.tokenSource), + openid_reuse_enabled: authState.openidReuseEnabled, + openid_jwt_available: authState.openidJwtAvailable, + has_openid_reuse_user_id: authState.hasOpenIdReuseUserId, + }), + ...buildSafeRequestLogContext(req), + }; } +/** + * @deprecated Pass `{ message, ...context }` to the logger so structured fields + * survive JSON message truncation. Retained for package API compatibility only. + */ export function formatAuthLogMessage(message: string, context: AuthLogContext): string { return `${message} ${JSON.stringify(context)}`; } + +function getTenantIsolationSignature(message: string): string { + if (message.includes('bulkWrite on') && message.includes('without tenant context')) { + return 'missing_bulk_write_context'; + } + if (message.includes('Unknown bulkWrite operation type')) { + return 'unsupported_bulk_write_operation'; + } + if (message.includes('Query attempted without tenant context')) { + return 'missing_query_context'; + } + if (message.includes('Aggregate attempted without tenant context')) { + return 'missing_aggregate_context'; + } + if (message.includes('Save attempted without tenant context')) { + return 'missing_save_context'; + } + if (message.includes('insertMany attempted without tenant context')) { + return 'missing_insert_many_context'; + } + if (message.includes('Cross-tenant')) { + return 'cross_tenant_mutation'; + } + if (message.includes('does not match current tenant context')) { + return 'tenant_mismatch'; + } + if (message.includes('Modifying tenantId via replacement')) { + return 'replacement_tenant_mutation'; + } + return 'tenant_isolation_error'; +} + +export function buildTenantIsolationErrorLogContext( + req: AuthLogRequest, + err: unknown, +): AuthLogContext | undefined { + const message = normalizeAuthLogValue(getAuthFailureField(err, 'message')); + if (!message?.startsWith('[TenantIsolation]')) { + return undefined; + } + + return { + event_name: 'tenant_isolation_error', + error_category: 'tenant_isolation', + error_signature: getTenantIsolationSignature(message), + response_status: 500, + ...buildSafeRequestLogContext(req), + }; +} diff --git a/packages/api/src/middleware/error.spec.ts b/packages/api/src/middleware/error.spec.ts index ee3bc70ec5..90705c8e28 100644 --- a/packages/api/src/middleware/error.spec.ts +++ b/packages/api/src/middleware/error.spec.ts @@ -1,7 +1,7 @@ -import { logger } from '@librechat/data-schemas'; -import { ErrorController } from './error'; +import { logger, tenantStorage } from '@librechat/data-schemas'; import type { Request, Response } from 'express'; import type { ValidationError, MongoServerError, CustomError } from '~/types'; +import { ErrorController } from './error'; // Mock the logger jest.mock('@librechat/data-schemas', () => ({ @@ -231,6 +231,69 @@ describe('ErrorController', () => { expect(mockRes.send).toHaveBeenCalledWith('An unknown error occurred.'); expect(logger.error).toHaveBeenCalledWith('ErrorController => error', genericError); }); + + it('emits a structured, joinable event for tenant-isolation errors', () => { + Object.assign(mockReq, { + id: 'request-123', + method: 'GET', + originalUrl: '/api/banner?access_token=secret-token', + }); + const tenantError = new Error( + '[TenantIsolation] Query attempted without tenant context in strict mode', + ); + + ErrorController(tenantError, mockReq, mockRes, mockNext); + + expect(mockRes.status).toHaveBeenCalledWith(500); + expect(logger.error).toHaveBeenCalledWith({ + message: 'Tenant-isolation request failed', + event_name: 'tenant_isolation_error', + error_category: 'tenant_isolation', + error_signature: 'missing_query_context', + response_status: 500, + request_id: 'request-123', + request_method: 'GET', + request_path: '/api/banner', + }); + expect(JSON.stringify((logger.error as jest.Mock).mock.calls)).not.toContain('secret-token'); + }); + + it('preserves the captured router mount for tenant-isolation errors', () => { + Object.assign(mockReq, { + id: 'request-123', + method: 'GET', + baseUrl: '/api', + route: { path: '/:id' }, + originalUrl: '/api/convos/conversation-123?access_token=secret-token', + }); + const tenantError = new Error( + '[TenantIsolation] Query attempted without tenant context in strict mode', + ); + + tenantStorage.run( + { + requestId: 'request-123', + requestMethod: 'GET', + requestPath: '/api/convos', + }, + () => ErrorController(tenantError, mockReq, mockRes, mockNext), + ); + + expect(logger.error).toHaveBeenCalledWith({ + message: 'Tenant-isolation request failed', + event_name: 'tenant_isolation_error', + error_category: 'tenant_isolation', + error_signature: 'missing_query_context', + response_status: 500, + request_id: 'request-123', + request_method: 'GET', + request_path: '/api/convos', + }); + expect(JSON.stringify((logger.error as jest.Mock).mock.calls)).not.toContain( + 'conversation-123', + ); + expect(JSON.stringify((logger.error as jest.Mock).mock.calls)).not.toContain('secret-token'); + }); }); describe('Catch block handling', () => { diff --git a/packages/api/src/middleware/error.ts b/packages/api/src/middleware/error.ts index 0d17ff5048..5832290fcd 100644 --- a/packages/api/src/middleware/error.ts +++ b/packages/api/src/middleware/error.ts @@ -1,7 +1,8 @@ -import { logger } from '@librechat/data-schemas'; import { ErrorTypes } from 'librechat-data-provider'; +import { logger, tenantStorage } from '@librechat/data-schemas'; import type { NextFunction, Request, Response } from 'express'; import type { MongoServerError, ValidationError, CustomError } from '~/types'; +import { buildTenantIsolationErrorLogContext } from './auth'; const handleDuplicateKeyError = (err: MongoServerError, res: Response) => { logger.warn('Duplicate key error: ' + (err.errmsg || err.message)); @@ -74,7 +75,19 @@ export const ErrorController = ( return res.status(error.statusCode).send(error.body); } - logger.error('ErrorController => error', err); + const tenantIsolationContext = buildTenantIsolationErrorLogContext(req, err); + if (tenantIsolationContext) { + const { requestId, requestMethod, requestPath } = tenantStorage.getStore() ?? {}; + logger.error({ + message: 'Tenant-isolation request failed', + ...tenantIsolationContext, + ...(requestId && { request_id: requestId }), + ...(requestMethod && { request_method: requestMethod }), + ...(requestPath && { request_path: requestPath }), + }); + } else { + logger.error('ErrorController => error', err); + } return res.status(500).send('An unknown error occurred.'); } catch (processingError) { logger.error('ErrorController => processing error', processingError); diff --git a/packages/api/src/middleware/index.ts b/packages/api/src/middleware/index.ts index 1d5fad12a5..60ea6b028f 100644 --- a/packages/api/src/middleware/index.ts +++ b/packages/api/src/middleware/index.ts @@ -8,6 +8,7 @@ export * from './json'; export * from './capabilities'; export * from './auth'; export { + requestContextMiddleware, tenantContextMiddleware, restoreTenantContextFromReq, resolveRequestTenantId, diff --git a/packages/api/src/middleware/preAuthTenant.spec.ts b/packages/api/src/middleware/preAuthTenant.spec.ts index 8aeb8b93ba..51616da1e5 100644 --- a/packages/api/src/middleware/preAuthTenant.spec.ts +++ b/packages/api/src/middleware/preAuthTenant.spec.ts @@ -1,6 +1,6 @@ -import { getTenantId, getRequestId, logger } from '@librechat/data-schemas'; -import { preAuthTenantMiddleware } from './preAuthTenant'; +import { getTenantId, getUserId, getRequestId, logger } from '@librechat/data-schemas'; import type { Request, Response, NextFunction } from 'express'; +import { preAuthTenantMiddleware } from './preAuthTenant'; jest.mock('@librechat/data-schemas', () => ({ ...jest.requireActual('@librechat/data-schemas'), @@ -13,7 +13,13 @@ jest.mock('@librechat/data-schemas', () => ({ })); describe('preAuthTenantMiddleware', () => { - let req: { headers: Record; ip?: string; path?: string }; + let req: { + headers: Record; + ip?: string; + path?: string; + tenantId?: string; + user?: { id: string; tenantId: string }; + }; let res: Partial; beforeEach(() => { @@ -65,6 +71,19 @@ describe('preAuthTenantMiddleware', () => { expect(capturedRequestId).toBe('req-preauth'); }); + it('does not inherit request identity before authentication', () => { + req.tenantId = 'untrusted-tenant'; + req.user = { id: 'untrusted-user', tenantId: 'untrusted-tenant' }; + let capturedContext: { tenantId?: string; userId?: string } = {}; + const capturedNext: NextFunction = () => { + capturedContext = { tenantId: getTenantId(), userId: getUserId() }; + }; + + preAuthTenantMiddleware(req as Request, res as Response, capturedNext); + + expect(capturedContext).toEqual({ tenantId: undefined, userId: undefined }); + }); + it('ignores __SYSTEM__ sentinel and logs warning', () => { req.headers = { 'x-tenant-id': '__SYSTEM__' }; req.ip = '10.0.0.1'; diff --git a/packages/api/src/middleware/preAuthTenant.ts b/packages/api/src/middleware/preAuthTenant.ts index 5d59cd8ae9..d24064af46 100644 --- a/packages/api/src/middleware/preAuthTenant.ts +++ b/packages/api/src/middleware/preAuthTenant.ts @@ -1,6 +1,6 @@ import { logger, SYSTEM_TENANT_ID } from '@librechat/data-schemas'; import type { Request, Response, NextFunction } from 'express'; -import { buildTenantContext, runWithTenantContext } from './tenant'; +import { buildRequestContext, runWithTenantContext } from './tenant'; /** * Pre-authentication tenant context middleware for unauthenticated routes. @@ -35,7 +35,7 @@ const VALID_TENANT_ID = /^[-a-zA-Z0-9_.]+$/; export function preAuthTenantMiddleware(req: Request, res: Response, next: NextFunction): void { const raw = req.headers['x-tenant-id']; - const requestContext = buildTenantContext({ headers: req.headers }); + const requestContext = buildRequestContext(req); if (!raw || typeof raw !== 'string') { runWithTenantContext(requestContext, next); @@ -72,5 +72,5 @@ export function preAuthTenantMiddleware(req: Request, res: Response, next: NextF return; } - runWithTenantContext(buildTenantContext({ headers: req.headers }, tenantId), next); + runWithTenantContext({ ...requestContext, tenantId }, next); } diff --git a/packages/api/src/middleware/tenant.ts b/packages/api/src/middleware/tenant.ts index b78ca8a743..5b41edf9eb 100644 --- a/packages/api/src/middleware/tenant.ts +++ b/packages/api/src/middleware/tenant.ts @@ -1,9 +1,11 @@ +import { randomUUID } from 'crypto'; import { unlink } from 'fs/promises'; import { isMainThread } from 'worker_threads'; import { tenantStorage, logger, SYSTEM_TENANT_ID } from '@librechat/data-schemas'; import type { TenantContext } from '@librechat/data-schemas'; import type { Response, NextFunction } from 'express'; import type { ServerRequest } from '~/types/http'; +import { buildSafeRequestLogContext } from './auth'; type ContextUser = { tenantId?: string; @@ -11,15 +13,22 @@ type ContextUser = { _id?: { toString: () => string }; } | null; -type ContextRequest = { +export type ContextRequest = { headers: ServerRequest['headers']; tenantId?: string; user?: ContextUser; id?: string; requestId?: string; + method?: string; + path?: string; + originalUrl?: string; + url?: string; + baseUrl?: string; + route?: { + path?: string | RegExp | readonly (string | RegExp)[]; + }; }; -const REQUEST_ID_HEADERS = ['x-request-id', 'x-correlation-id'] as const; const SYSTEM_TENANT_REJECTION_MESSAGE = 'System tenant is not allowed for request-scoped routes'; let _checkedThread = false; @@ -40,30 +49,18 @@ function normalizeContextValue(value?: string): string | undefined { return trimmed || undefined; } -function getHeaderValue(value: string | string[] | undefined): string | undefined { - return normalizeContextValue(Array.isArray(value) ? value[0] : value); -} - -function getRequestId(req: ContextRequest): string | undefined { - const requestId = normalizeContextValue(req.requestId) ?? normalizeContextValue(req.id); - if (requestId) { - return requestId; - } - for (const header of REQUEST_ID_HEADERS) { - const value = getHeaderValue(req.headers[header]); - if (value) { - return value; - } - } - return undefined; -} - function getUserId(user: ContextUser): string | undefined { return normalizeContextValue(user?.id) ?? normalizeContextValue(user?._id?.toString()); } function hasTenantContext(context: TenantContext): boolean { - return Boolean(context.tenantId || context.userId || context.requestId); + return Boolean( + context.tenantId || + context.userId || + context.requestId || + context.requestMethod || + context.requestPath, + ); } export function buildTenantContext( @@ -71,12 +68,39 @@ export function buildTenantContext( tenantId: string | undefined = req.tenantId ?? req.user?.tenantId, ): TenantContext { return { + ...buildRequestContext(req), tenantId: normalizeContextValue(tenantId), userId: getUserId(req.user ?? null), - requestId: getRequestId(req), }; } +export function buildRequestContext(req: ContextRequest): TenantContext { + const requestContext = buildSafeRequestLogContext(req); + + return { + requestId: requestContext.request_id, + requestMethod: requestContext.request_method, + requestPath: requestContext.request_path, + }; +} + +/** + * Establishes safe, request-level correlation before authentication. It carries + * no tenant or user identity, so strict tenant isolation remains fail-closed. + */ +export function requestContextMiddleware( + req: ContextRequest, + _res: Response, + next: NextFunction, +): void { + const context = buildRequestContext(req); + if (!context.requestId) { + context.requestId = randomUUID(); + } + req.requestId = context.requestId; + runWithTenantContext(context, next); +} + export function runWithTenantContext(context: TenantContext, next: NextFunction): void { if (!hasTenantContext(context)) { next(); diff --git a/packages/data-schemas/src/config/parsers.spec.ts b/packages/data-schemas/src/config/parsers.spec.ts index b008c0aeb9..5dbf8d9cbc 100644 --- a/packages/data-schemas/src/config/parsers.spec.ts +++ b/packages/data-schemas/src/config/parsers.spec.ts @@ -1,5 +1,5 @@ import winston from 'winston'; -import { debugTraverse, redactFormat, redactMessage } from './parsers'; +import { debugTraverse, jsonTruncateFormat, redactFormat, redactMessage } from './parsers'; const SPLAT_SYMBOL = Symbol.for('splat'); const MESSAGE_SYMBOL = Symbol.for('message'); @@ -319,4 +319,75 @@ describe('debugTraverse request context', () => { expect(out).not.toMatch(/tenantId:/); expect(out).toContain('userId'); }); + + it('preserves structured auth metadata for non-JSON warning output', () => { + const out = runFormatter( + buildInfo('warn', { + event_name: 'jwt_auth_rejected', + request_id: 'request-123', + request_method: 'GET', + request_path: '/api/messages', + token_source: 'bearer', + reason_category: 'malformed_jwt', + recovery_classification: 'terminal_rejection', + response_status: 401, + }), + ); + + expect(out).toContain('"event_name":"jwt_auth_rejected"'); + expect(out).toContain('"request_id":"request-123"'); + expect(out).toContain('"reason_category":"malformed_jwt"'); + expect(out).toContain('"response_status":401'); + }); + + it('does not render application metadata as request correlation context', () => { + const out = runFormatter( + buildInfo('warn', { + method: 'DELETE', + path: '/uploads/tenant-123/user-123/file.txt', + request_method: 'POST', + request_path: '/api/files', + }), + ); + + expect(out).toContain('"request_method":"POST"'); + expect(out).toContain('"request_path":"/api/files"'); + expect(out).not.toContain('"method":"DELETE"'); + expect(out).not.toContain('/uploads/tenant-123/user-123/file.txt'); + }); +}); + +describe('jsonTruncateFormat structured events', () => { + it('preserves short auth correlation fields when the human-readable message is truncated', () => { + const format = jsonTruncateFormat(); + const info = { + level: 'warn', + message: `JWT auth rejected: ${'x'.repeat(300)}`, + event_name: 'jwt_auth_rejected', + request_id: 'request-123', + request_method: 'GET', + request_path: '/api/messages', + token_source: 'bearer', + reason_category: 'malformed_jwt', + recovery_classification: 'terminal_rejection', + response_status: 401, + } satisfies winston.Logform.TransformableInfo; + + const output = format.transform(info, format.options); + if (typeof output !== 'object') { + throw new Error('Expected jsonTruncateFormat to preserve the log record'); + } + + expect(output.message).toBe(`${info.message.slice(0, 255)}...`); + expect(output).toMatchObject({ + event_name: 'jwt_auth_rejected', + request_id: 'request-123', + request_method: 'GET', + request_path: '/api/messages', + token_source: 'bearer', + reason_category: 'malformed_jwt', + recovery_classification: 'terminal_rejection', + response_status: 401, + }); + }); }); diff --git a/packages/data-schemas/src/config/parsers.ts b/packages/data-schemas/src/config/parsers.ts index 2b2db4a692..e54b30f3c5 100644 --- a/packages/data-schemas/src/config/parsers.ts +++ b/packages/data-schemas/src/config/parsers.ts @@ -1,6 +1,7 @@ import { klona } from 'klona'; import winston from 'winston'; import type { TraverseContext } from '../utils/object-traverse'; +import { appendLogContext } from './requestLogContext'; import { SYSTEM_TENANT_ID } from './tenantContext'; import traverse from '../utils/object-traverse'; @@ -9,7 +10,6 @@ const MESSAGE_SYMBOL = Symbol.for('message'); const CONSOLE_JSON_STRING_LENGTH: number = parseInt(process.env.CONSOLE_JSON_STRING_LENGTH || '', 10) || 255; const DEBUG_MESSAGE_LENGTH: number = parseInt(process.env.DEBUG_MESSAGE_LENGTH || '', 10) || 150; -const LOG_CONTEXT_KEYS = ['tenantId', 'userId', 'requestId'] as const; const REDACTED_VALUE = '[REDACTED]'; const REDACTION_TRUNCATED_KEY = '__redaction_truncated__'; const MAX_REDACTION_DEPTH = 8; @@ -396,25 +396,6 @@ const condenseArray = (item: unknown): string | unknown => { return item; }; -function formatRequestContext(metadata: Record): string { - const context: Partial> = {}; - LOG_CONTEXT_KEYS.forEach((key) => { - const value = metadata[key]; - if (key === 'tenantId' && value === SYSTEM_TENANT_ID) { - return; - } - if (typeof value === 'string' && value) { - context[key] = value; - } - }); - return Object.keys(context).length > 0 ? JSON.stringify(context) : ''; -} - -function appendRequestContext(line: string, metadata: Record): string { - const context = formatRequestContext(metadata); - return context ? `${line} ${context}` : line; -} - /** * Formats log messages for debugging purposes. * - Truncates long strings within log messages. @@ -442,7 +423,7 @@ const debugTraverse: winston.Logform.Format = winston.format.printf( try { if (level !== 'debug') { - return appendRequestContext(msgParts[0], metadata); + return appendLogContext(msgParts[0], metadata); } if (!metadata) { @@ -455,17 +436,17 @@ const debugTraverse: winston.Logform.Format = winston.format.printf( const debugValue = Array.isArray(splatArray) ? splatArray[0] : undefined; if (!debugValue) { - return appendRequestContext(msgParts[0], metadata); + return appendLogContext(msgParts[0], metadata); } if (debugValue && Array.isArray(debugValue)) { msgParts.push(`\n${JSON.stringify(debugValue.map(condenseArray))}`); - return appendRequestContext(msgParts.join(''), metadata); + return appendLogContext(msgParts.join(''), metadata); } if (typeof debugValue !== 'object') { msgParts.push(` ${debugValue}`); - return appendRequestContext(msgParts.join(''), metadata); + return appendLogContext(msgParts.join(''), metadata); } msgParts.push('\n{'); diff --git a/packages/data-schemas/src/config/requestLogContext.spec.ts b/packages/data-schemas/src/config/requestLogContext.spec.ts new file mode 100644 index 0000000000..6469a2c23e --- /dev/null +++ b/packages/data-schemas/src/config/requestLogContext.spec.ts @@ -0,0 +1,109 @@ +import { attachRequestContext, formatLogContext } from './requestLogContext'; +import { tenantStorage } from './tenantContext'; + +describe('attachRequestContext', () => { + const context = { + tenantId: 'tenant-123', + userId: 'user-123', + requestId: 'request-123', + requestMethod: 'POST', + requestPath: '/api/example', + }; + + it.each([ + 'jwt_auth_fallback_attempt', + 'jwt_auth_rejected', + 'jwt_auth_recovered', + 'tenant_isolation_error', + ])('omits identity fields from %s while preserving request correlation', (eventName) => + tenantStorage.run(context, () => { + const info = { + level: 'warn', + message: 'event', + event_name: eventName, + reason_category: 'malformed_jwt', + response_status: 401, + tenantId: 'explicit-tenant', + tenant_id: 'explicit-tenant', + userId: 'explicit-user', + user_id: 'explicit-user', + }; + + const result = attachRequestContext(info); + + expect(result).not.toHaveProperty('tenantId'); + expect(result).not.toHaveProperty('tenant_id'); + expect(result).not.toHaveProperty('userId'); + expect(result).not.toHaveProperty('user_id'); + expect(result).toMatchObject({ + requestId: 'request-123', + request_id: 'request-123', + request_method: 'POST', + request_path: '/api/example', + }); + const rendered = formatLogContext(result); + expect(rendered).toContain(`"event_name":"${eventName}"`); + expect(rendered).toContain('"reason_category":"malformed_jwt"'); + expect(rendered).toContain('"response_status":401'); + expect(rendered).not.toContain('explicit-tenant'); + expect(rendered).not.toContain('explicit-user'); + }), + ); + + it('retains identity context on ordinary application logs', () => + tenantStorage.run(context, () => { + const result = attachRequestContext({ level: 'info', message: 'event' }); + + expect(result).toMatchObject({ + tenantId: 'tenant-123', + userId: 'user-123', + requestId: 'request-123', + request_id: 'request-123', + request_method: 'POST', + request_path: '/api/example', + }); + })); + + it('keeps application paths separate from the safe request route', () => + tenantStorage.run(context, () => { + const result = attachRequestContext({ + level: 'error', + message: 'upload cleanup failed', + method: 'DELETE', + path: '/uploads/tenant-123/user-123/file.txt', + }); + + expect(result).toMatchObject({ + method: 'DELETE', + path: '/uploads/tenant-123/user-123/file.txt', + request_method: 'POST', + request_path: '/api/example', + }); + const rendered = formatLogContext(result); + expect(rendered).toContain('"request_method":"POST"'); + expect(rendered).toContain('"request_path":"/api/example"'); + expect(rendered).not.toContain('"method":"DELETE"'); + expect(rendered).not.toContain('/uploads/tenant-123/user-123/file.txt'); + })); + + it('overwrites reserved request fields with the safe ALS correlation context', () => + tenantStorage.run(context, () => { + const result = attachRequestContext({ + level: 'warn', + message: 'event', + requestId: 'header..signature', + request_id: 'header..signature', + request_method: 'DELETE', + request_path: '/unsafe/concrete/path', + }); + + expect(result).toMatchObject({ + requestId: 'request-123', + request_id: 'request-123', + request_method: 'POST', + request_path: '/api/example', + }); + expect(formatLogContext(result)).not.toContain('header..signature'); + expect(formatLogContext(result)).not.toContain('/unsafe/concrete/path'); + })); +}); diff --git a/packages/data-schemas/src/config/requestLogContext.ts b/packages/data-schemas/src/config/requestLogContext.ts new file mode 100644 index 0000000000..11372c790d --- /dev/null +++ b/packages/data-schemas/src/config/requestLogContext.ts @@ -0,0 +1,160 @@ +import type winston from 'winston'; +import { + getTenantId, + getUserId, + getRequestId, + getRequestMethod, + getRequestPath, + SYSTEM_TENANT_ID, +} from './tenantContext'; + +const REQUEST_LOG_CONTEXT_KEYS = [ + 'tenantId', + 'userId', + 'requestId', + 'request_id', + 'request_method', + 'request_path', +] as const; + +const RESERVED_REQUEST_LOG_CONTEXT_KEYS = new Set([ + 'requestId', + 'request_id', + 'request_method', + 'request_path', +]); + +const STRUCTURED_EVENT_LOG_CONTEXT_KEYS = [ + 'event_name', + 'auth_strategy', + 'primary_strategy', + 'fallback_strategy', + 'fallback_attempted', + 'fallback_succeeded', + 'attempted_strategies', + 'final_strategy', + 'primary_failure_reason_category', + 'reason_category', + 'recovery_classification', + 'response_status', + 'strategy_status', + 'token_provider', + 'token_source', + 'openid_reuse_enabled', + 'openid_jwt_available', + 'has_openid_reuse_user_id', + 'error_category', + 'error_signature', +] as const; + +type LogContextKey = + | (typeof REQUEST_LOG_CONTEXT_KEYS)[number] + | (typeof STRUCTURED_EVENT_LOG_CONTEXT_KEYS)[number]; + +const LOG_CONTEXT_KEYS: readonly LogContextKey[] = [ + ...REQUEST_LOG_CONTEXT_KEYS, + ...STRUCTURED_EVENT_LOG_CONTEXT_KEYS, +]; + +const IDENTITY_CONTEXT_KEYS = ['tenantId', 'tenant_id', 'userId', 'user_id'] as const; +const IDENTITY_FREE_EVENT_NAMES = new Set([ + 'jwt_auth_fallback_attempt', + 'jwt_auth_rejected', + 'jwt_auth_recovered', + 'tenant_isolation_error', +]); +const STRUCTURED_EVENT_LOG_CONTEXT_KEY_SET = new Set(STRUCTURED_EVENT_LOG_CONTEXT_KEYS); +const MAX_LOG_CONTEXT_ARRAY_LENGTH = 10; + +type LogContextValue = string | number | boolean | readonly string[]; +type LogContextInfo = + | Partial<{ [Key in LogContextKey]: unknown }> + | winston.Logform.TransformableInfo; + +function isIdentityFreeEvent(eventName: unknown): boolean { + return typeof eventName === 'string' && IDENTITY_FREE_EVENT_NAMES.has(eventName); +} + +function getLogTenantId(): string | undefined { + const tenantId = getTenantId(); + return tenantId === SYSTEM_TENANT_ID ? undefined : tenantId; +} + +function normalizeLogContextValue(value: unknown): LogContextValue | undefined { + if (typeof value === 'string') { + return value || undefined; + } + if (typeof value === 'number') { + return Number.isFinite(value) ? value : undefined; + } + if (typeof value === 'boolean') { + return value; + } + if (!Array.isArray(value)) { + return undefined; + } + + const values = value + .filter((entry): entry is string => typeof entry === 'string' && entry.length > 0) + .slice(0, MAX_LOG_CONTEXT_ARRAY_LENGTH); + return values.length > 0 ? values : undefined; +} + +/** Serializes the allowlisted context rendered by non-JSON log transports. */ +export function formatLogContext(info: LogContextInfo): string { + const context: Partial> = {}; + const omitIdentity = isIdentityFreeEvent(info.event_name); + + LOG_CONTEXT_KEYS.forEach((key) => { + if (STRUCTURED_EVENT_LOG_CONTEXT_KEY_SET.has(key) && !omitIdentity) { + return; + } + if (omitIdentity && (key === 'tenantId' || key === 'userId')) { + return; + } + if (key === 'tenantId' && info[key] === SYSTEM_TENANT_ID) { + return; + } + const value = normalizeLogContextValue(info[key]); + if (value !== undefined) { + context[key] = value; + } + }); + + return Object.keys(context).length > 0 ? JSON.stringify(context) : ''; +} + +export function appendLogContext(line: string, info: LogContextInfo): string { + const context = formatLogContext(info); + return context ? `${line} ${context}` : line; +} + +/** + * Adds request-scoped context to a log record. Authentication and tenant-isolation + * events intentionally omit identity fields while retaining request correlation. + */ +export function attachRequestContext( + info: winston.Logform.TransformableInfo, +): winston.Logform.TransformableInfo { + const omitIdentity = isIdentityFreeEvent(info.event_name); + if (omitIdentity) { + IDENTITY_CONTEXT_KEYS.forEach((key) => delete info[key]); + } else if (info.tenantId === SYSTEM_TENANT_ID) { + delete info.tenantId; + } + + const context = { + tenantId: omitIdentity ? undefined : getLogTenantId(), + userId: omitIdentity ? undefined : getUserId(), + requestId: getRequestId(), + request_id: getRequestId(), + request_method: getRequestMethod(), + request_path: getRequestPath(), + }; + REQUEST_LOG_CONTEXT_KEYS.forEach((key) => { + if (context[key] && (RESERVED_REQUEST_LOG_CONTEXT_KEYS.has(key) || info[key] == null)) { + info[key] = context[key]; + } + }); + return info; +} diff --git a/packages/data-schemas/src/config/tenantContext.ts b/packages/data-schemas/src/config/tenantContext.ts index 00e18603d6..08a1c2b214 100644 --- a/packages/data-schemas/src/config/tenantContext.ts +++ b/packages/data-schemas/src/config/tenantContext.ts @@ -4,6 +4,8 @@ export interface TenantContext { tenantId?: string; userId?: string; requestId?: string; + requestMethod?: string; + requestPath?: string; } /** Sentinel value for deliberate cross-tenant system operations */ @@ -32,13 +34,26 @@ export function getRequestId(): string | undefined { return tenantStorage.getStore()?.requestId; } +/** Returns the safe request method from async context, or undefined if none is set */ +export function getRequestMethod(): string | undefined { + return tenantStorage.getStore()?.requestMethod; +} + +/** Returns the safe request path from async context, or undefined if none is set */ +export function getRequestPath(): string | undefined { + return tenantStorage.getStore()?.requestPath; +} + /** * Runs a function in an explicit cross-tenant system context (bypasses tenant filtering). * The callback MUST be async — sync callbacks returning Mongoose thenables will lose context. */ export function runAsSystem(fn: () => Promise): Promise { - const { requestId, userId } = tenantStorage.getStore() ?? {}; - return tenantStorage.run({ tenantId: SYSTEM_TENANT_ID, requestId, userId }, fn); + const { requestId, userId, requestMethod, requestPath } = tenantStorage.getStore() ?? {}; + return tenantStorage.run( + { tenantId: SYSTEM_TENANT_ID, requestId, userId, requestMethod, requestPath }, + fn, + ); } /** diff --git a/packages/data-schemas/src/config/winston.ts b/packages/data-schemas/src/config/winston.ts index 3b927f7a84..97dab875dc 100644 --- a/packages/data-schemas/src/config/winston.ts +++ b/packages/data-schemas/src/config/winston.ts @@ -7,7 +7,7 @@ import { jsonTruncateFormat, stripHeavyErrorFields, } from './parsers'; -import { getTenantId, getUserId, getRequestId, SYSTEM_TENANT_ID } from './tenantContext'; +import { appendLogContext, attachRequestContext } from './requestLogContext'; import { getLogDirectory } from './utils'; const { NODE_ENV, DEBUG_LOGGING, CONSOLE_JSON, DEBUG_CONSOLE, LOG_TO_FILE } = process.env; @@ -31,48 +31,7 @@ const levels: winston.config.AbstractConfigSetLevels = { silly: 7, }; -const LOG_CONTEXT_KEYS = ['tenantId', 'userId', 'requestId'] as const; - -function getLogTenantId(): string | undefined { - const tenantId = getTenantId(); - return tenantId === SYSTEM_TENANT_ID ? undefined : tenantId; -} - -const requestContextFormat = winston.format((info: winston.Logform.TransformableInfo) => { - if (info.tenantId === SYSTEM_TENANT_ID) { - delete info.tenantId; - } - const context = { - tenantId: getLogTenantId(), - userId: getUserId(), - requestId: getRequestId(), - }; - LOG_CONTEXT_KEYS.forEach((key) => { - if (context[key] && info[key] == null) { - info[key] = context[key]; - } - }); - return info; -}); - -function formatRequestContext(info: winston.Logform.TransformableInfo): string { - const context: Partial> = {}; - LOG_CONTEXT_KEYS.forEach((key) => { - const value = info[key]; - if (key === 'tenantId' && value === SYSTEM_TENANT_ID) { - return; - } - if (typeof value === 'string' && value) { - context[key] = value; - } - }); - return Object.keys(context).length > 0 ? JSON.stringify(context) : ''; -} - -function appendRequestContext(line: string, info: winston.Logform.TransformableInfo): string { - const context = formatRequestContext(info); - return context ? `${line} ${context}` : line; -} +const requestContextFormat = winston.format(attachRequestContext); winston.addColors({ info: 'green', @@ -134,7 +93,7 @@ const consoleFormat = winston.format.combine( winston.format.timestamp({ format: 'YYYY-MM-DD HH:mm:ss' }), winston.format.printf((info) => { const message = `${info.timestamp} ${info.level}: ${info.message}`; - const line = appendRequestContext(message, info); + const line = appendLogContext(message, info); return info.level.includes('error') ? redactMessage(line) : line; }), ); diff --git a/packages/data-schemas/src/index.ts b/packages/data-schemas/src/index.ts index 85ff1b86fc..d844d2086b 100644 --- a/packages/data-schemas/src/index.ts +++ b/packages/data-schemas/src/index.ts @@ -50,6 +50,8 @@ export { getTenantId, getUserId, getRequestId, + getRequestMethod, + getRequestPath, runAsSystem, scopedCacheKey, SYSTEM_TENANT_ID,