diff --git a/api/config/__tests__/parsers.spec.js b/api/config/__tests__/parsers.spec.js index f54675ce3a..4c78360953 100644 --- a/api/config/__tests__/parsers.spec.js +++ b/api/config/__tests__/parsers.spec.js @@ -30,6 +30,18 @@ describe('formatConsoleMeta', () => { expect(meta).toContain('"messagesToRefineCount":42'); }); + it('omits the system tenant sentinel from metadata trailers', () => { + const meta = formatConsoleMeta({ + level: 'warn', + message: 'system task', + timestamp: 'ts', + tenantId: '__SYSTEM__', + userId: 'user-1', + }); + + expect(meta).toBe('{"userId":"user-1"}'); + }); + it('ignores reserved winston keys but preserves legitimate fields like _id', () => { const meta = formatConsoleMeta({ level: 'error', @@ -315,6 +327,66 @@ describe('debugTraverse', () => { expect(tenantMatches.length).toBe(1); }); + it('appends request context metadata for non-debug lines', () => { + const out = runFormatter( + buildInfo('info', { + tenantId: 'tenant-1', + userId: 'user-1', + requestId: 'req-1', + }), + ); + + expect(out).toContain('"tenantId":"tenant-1"'); + expect(out).toContain('"userId":"user-1"'); + expect(out).toContain('"requestId":"req-1"'); + }); + + it('does not append the system tenant sentinel as tenantId', () => { + const out = runFormatter( + buildInfo('info', { + tenantId: '__SYSTEM__', + userId: 'user-1', + requestId: 'req-1', + }), + ); + + expect(out).not.toContain('__SYSTEM__'); + expect(out).not.toContain('"tenantId"'); + expect(out).toContain('"userId":"user-1"'); + expect(out).toContain('"requestId":"req-1"'); + }); + + it('omits the system tenant sentinel from debug object metadata', () => { + const out = runFormatter( + buildInfo('debug', { + tenantId: '__SYSTEM__', + userId: 'user-1', + }), + ); + + expect(out).not.toContain('__SYSTEM__'); + expect(out).not.toMatch(/tenantId:/); + expect(out).toContain('userId'); + }); + + it('appends request context metadata for debug lines without object metadata', () => { + const info = { + level: 'debug', + message: 'prefix:', + timestamp: 'ts', + tenantId: 'tenant-1', + userId: 'user-1', + requestId: 'req-1', + [SPLAT_SYMBOL]: ['detailValueXYZ'], + }; + const out = runFormatter(info); + + expect(out).toContain('detailValueXYZ'); + expect(out).toContain('"tenantId":"tenant-1"'); + expect(out).toContain('"userId":"user-1"'); + expect(out).toContain('"requestId":"req-1"'); + }); + it('omits numeric splat-artifact keys from the traversed output', () => { const info = { level: 'error', diff --git a/api/config/parsers.js b/api/config/parsers.js index 111f3f6a7d..477e371253 100644 --- a/api/config/parsers.js +++ b/api/config/parsers.js @@ -18,6 +18,8 @@ const sensitiveKeys = [ ]; const NUMERIC_KEY_RE = /^\d+$/; +const LOG_CONTEXT_KEYS = ['tenantId', 'userId', 'requestId']; +const SYSTEM_TENANT_ID = '__SYSTEM__'; /** * Redacts sensitive information from a console message and trims it to a specified length if provided. @@ -122,6 +124,9 @@ function extractMetaObject(source) { continue; } const value = source[key]; + if (key === 'tenantId' && value === SYSTEM_TENANT_ID) { + continue; + } if (value === undefined || value === null || value === '') { continue; } @@ -197,6 +202,23 @@ function formatConsoleMeta(info) { } } +function formatRequestContext(info) { + if (info == null || typeof info !== 'object') { + return ''; + } + const context = {}; + for (const key of LOG_CONTEXT_KEYS) { + const value = info[key]; + if (key === 'tenantId' && value === SYSTEM_TENANT_ID) { + continue; + } + if (typeof value === 'string' && value) { + context[key] = value; + } + } + return Object.keys(context).length > 0 ? JSON.stringify(context) : ''; +} + /** * Formats log messages for file and debug-console transports. Three paths: * - `warn` / `error`: append a compact single-line JSON metadata trailer @@ -207,7 +229,7 @@ function formatConsoleMeta(info) { * Redaction on this path is not applied here (debug-file consumers * historically accept raw detail). * - Other levels: return the truncated `" : "` - * line with no metadata. + * line with request context metadata when present. * * @param {Object} options - The options for formatting log messages. * @param {string} options.level - The log level. @@ -245,31 +267,41 @@ const debugTraverse = winston.format.printf(({ level, message, timestamp, ...met try { if (level !== 'debug') { - return msg; + const trailer = formatRequestContext(metadata); + return trailer ? `${msg} ${trailer}` : msg; } if (!metadata) { return msg; } + const appendMetadataTrailer = (line) => { + const trailer = formatRequestContext(metadata); + return trailer ? `${line} ${trailer}` : line; + }; + const debugValue = metadata[SPLAT_SYMBOL]?.[0]; if (!debugValue) { - return msg; + return appendMetadataTrailer(msg); } if (debugValue && Array.isArray(debugValue)) { msg += `\n${JSON.stringify(debugValue.map(condenseArray))}`; - return msg; + return appendMetadataTrailer(msg); } if (typeof debugValue !== 'object') { - return (msg += ` ${debugValue}`); + msg += ` ${debugValue}`; + return appendMetadataTrailer(msg); } msg += '\n{'; const copy = klona(metadata); + if (copy.tenantId === SYSTEM_TENANT_ID) { + delete copy.tenantId; + } traverse(copy).forEach(function (value) { if (typeof this?.key === 'symbol') { return; diff --git a/api/config/winston.js b/api/config/winston.js index c077cf5bf8..163e0b4eab 100644 --- a/api/config/winston.js +++ b/api/config/winston.js @@ -2,6 +2,12 @@ const path = require('path'); const fs = require('fs'); const winston = require('winston'); require('winston-daily-rotate-file'); +const { + getTenantId, + getUserId, + getRequestId, + SYSTEM_TENANT_ID, +} = require('@librechat/data-schemas'); const { redactFormat, redactMessage, @@ -63,6 +69,44 @@ const levels = { silly: 7, }; +const LOG_CONTEXT_KEYS = ['tenantId', 'userId', 'requestId']; + +const getLogTenantId = () => { + const tenantId = getTenantId(); + return tenantId === SYSTEM_TENANT_ID ? undefined : tenantId; +}; + +const requestContextFormat = winston.format((info) => { + 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; +}); + +const formatRequestContext = (info) => { + const context = {}; + 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) : ''; +}; + winston.addColors({ info: 'green', // fontStyle color warn: 'italic yellow', @@ -81,6 +125,7 @@ const fileFormat = winston.format.combine( winston.format.timestamp({ format: () => new Date().toISOString() }), winston.format.errors({ stack: true }), winston.format.splat(), + requestContextFormat(), // redactErrors(), ); @@ -112,20 +157,16 @@ if (useDebugLogging) { const consoleFormat = winston.format.combine( redactFormat(), + requestContextFormat(), winston.format.colorize({ all: true }), winston.format.timestamp({ format: 'YYYY-MM-DD HH:mm:ss' }), // redactErrors(), winston.format.printf((info) => { const base = `${info.timestamp} ${info.level}: ${info.message}`; const isErrorOrWarn = info.level.includes('error') || info.level.includes('warn'); - - if (isErrorOrWarn) { - const metaTrailer = formatConsoleMeta(info); - const line = metaTrailer ? `${base} ${metaTrailer}` : base; - return redactMessage(line); - } - - return base; + const metaTrailer = isErrorOrWarn ? formatConsoleMeta(info) : formatRequestContext(info); + const line = metaTrailer ? `${base} ${metaTrailer}` : base; + return isErrorOrWarn ? redactMessage(line) : line; }), ); diff --git a/api/server/middleware/__tests__/requireJwtAuth.spec.js b/api/server/middleware/__tests__/requireJwtAuth.spec.js index 7f0963398d..4059be2409 100644 --- a/api/server/middleware/__tests__/requireJwtAuth.spec.js +++ b/api/server/middleware/__tests__/requireJwtAuth.spec.js @@ -41,25 +41,42 @@ jest.mock('@librechat/data-schemas', () => { const tenantStorage = new AsyncLocalStorage(); return { getTenantId: () => tenantStorage.getStore()?.tenantId, + getUserId: () => tenantStorage.getStore()?.userId, + getRequestId: () => tenantStorage.getStore()?.requestId, tenantStorage, }; }); // Mock @librechat/api — the real tenantContextMiddleware is TS and cannot be // required directly from CJS tests. This thin wrapper mirrors the real logic -// (read req.user.tenantId, call tenantStorage.run) using the same data-schemas +// (read request context, call tenantStorage.run) using the same 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 normalizeContextValue = (value) => { + const trimmed = value?.trim?.(); + return trimmed || undefined; + }; + const getUserId = (user) => + normalizeContextValue(user?.id?.toString?.()) ?? normalizeContextValue(user?._id?.toString?.()); + const getRequestId = (req) => + normalizeContextValue(req.requestId) ?? + normalizeContextValue(req.id) ?? + normalizeContextValue(req.headers?.['x-request-id']) ?? + normalizeContextValue(req.headers?.['x-correlation-id']); return { isEnabled: jest.fn(() => false), maybeRefreshCloudFrontAuthCookiesMiddleware: jest.fn((req, res, next) => next()), tenantContextMiddleware: (req, res, next) => { - const tenantId = req.user?.tenantId; - if (!tenantId) { + const context = { + tenantId: normalizeContextValue(req.user?.tenantId), + userId: getUserId(req.user), + requestId: getRequestId(req), + }; + if (!context.tenantId && !context.userId && !context.requestId) { return next(); } - return tenantStorage.run({ tenantId }, async () => next()); + return tenantStorage.run(context, async () => next()); }, }; }); @@ -67,7 +84,7 @@ jest.mock('@librechat/api', () => { // ── Helpers ───────────────────────────────────────────────────────────── const requireJwtAuth = require('../requireJwtAuth'); -const { getTenantId } = require('@librechat/data-schemas'); +const { getTenantId, getUserId } = require('@librechat/data-schemas'); const { isEnabled, maybeRefreshCloudFrontAuthCookiesMiddleware } = require('@librechat/api'); const passport = require('passport'); @@ -151,6 +168,27 @@ describe('requireJwtAuth tenant context chaining', () => { expect(next).toHaveBeenCalled(); }); + it('refreshes CloudFront auth cookies inside the request context', () => { + let observedContext; + maybeRefreshCloudFrontAuthCookiesMiddleware.mockImplementationOnce( + (_req, _res, middlewareNext) => { + observedContext = { + tenantId: getTenantId(), + userId: getUserId(), + }; + middlewareNext(); + }, + ); + const req = mockReq({ id: 'user-123', tenantId: 'tenant-abc', role: 'user' }); + const res = mockRes(); + const next = jest.fn(); + + requireJwtAuth(req, res, next); + + expect(observedContext).toEqual({ tenantId: 'tenant-abc', userId: 'user-123' }); + expect(next).toHaveBeenCalled(); + }); + it('ALS tenant context is NOT set when user has no tenantId', async () => { const tenantId = await runAuth({ role: 'user' }); expect(tenantId).toBeUndefined(); diff --git a/api/server/middleware/requireJwtAuth.js b/api/server/middleware/requireJwtAuth.js index e9abbc7fa8..935957e913 100644 --- a/api/server/middleware/requireJwtAuth.js +++ b/api/server/middleware/requireJwtAuth.js @@ -35,8 +35,8 @@ const refreshCloudFrontCookies = * Switches between JWT and OpenID authentication based on cookies and environment settings. * * After successful authentication (req.user populated), automatically chains into - * `tenantContextMiddleware` to propagate `req.user.tenantId` into AsyncLocalStorage - * for downstream Mongoose tenant isolation. + * `tenantContextMiddleware` to propagate request context into AsyncLocalStorage + * for downstream Mongoose tenant isolation and structured logging. */ const requireJwtAuth = (req, res, next) => { const cookieHeader = req.headers.cookie; @@ -71,12 +71,11 @@ const requireJwtAuth = (req, res, next) => { } req.user = user; req.authStrategy = strategy; - refreshCloudFrontCookies(req, res, (refreshErr) => { - if (refreshErr) { - return next(refreshErr); + tenantContextMiddleware(req, res, (tenantErr) => { + if (tenantErr) { + return next(tenantErr); } - // req.user is now populated by passport — set up tenant ALS context - tenantContextMiddleware(req, res, next); + refreshCloudFrontCookies(req, res, next); }); })(req, res, next); }; diff --git a/api/server/services/AuthService.js b/api/server/services/AuthService.js index 943c5a81f6..24374ef4c6 100644 --- a/api/server/services/AuthService.js +++ b/api/server/services/AuthService.js @@ -448,6 +448,8 @@ const getCloudFrontAuthCookieSkipReason = (scope) => { return null; }; +const shouldLogCloudFrontAuthCookieSkip = (reason) => reason !== 'cloudfront_disabled'; + /** * Refreshes CloudFront signed cookies for authenticated image/avatar access. * @param {ServerRequest | null} req @@ -477,15 +479,17 @@ const setCloudFrontAuthCookies = (req, res, user, options = {}) => { }; const skipReason = getCloudFrontAuthCookieSkipReason(scope); if (skipReason) { - logger.debug('[setCloudFrontAuthCookies] CloudFront auth cookies skipped', { - attempted: false, - set: false, - reason: skipReason, - has_user_id: Boolean(scope.userId), - has_tenant_scope: Boolean(scope.tenantId), - has_storage_region: Boolean(scope.storageRegion), - has_previous_scope: Boolean(getPreviousCloudFrontScope(req)?.userId), - }); + if (shouldLogCloudFrontAuthCookieSkip(skipReason)) { + logger.debug('[setCloudFrontAuthCookies] CloudFront auth cookies skipped', { + attempted: false, + set: false, + reason: skipReason, + has_user_id: Boolean(scope.userId), + has_tenant_scope: Boolean(scope.tenantId), + has_storage_region: Boolean(scope.storageRegion), + has_previous_scope: Boolean(getPreviousCloudFrontScope(req)?.userId), + }); + } return false; } diff --git a/api/server/services/AuthService.spec.js b/api/server/services/AuthService.spec.js index c81b78e8e1..95a208c5c8 100644 --- a/api/server/services/AuthService.spec.js +++ b/api/server/services/AuthService.spec.js @@ -576,13 +576,9 @@ describe('CloudFront cookie integration', () => { expect(result).toBe(false); expect(setCloudFrontCookies).not.toHaveBeenCalled(); - expect(logger.debug).toHaveBeenCalledWith( + expect(logger.debug).not.toHaveBeenCalledWith( '[setCloudFrontAuthCookies] CloudFront auth cookies skipped', - expect.objectContaining({ - attempted: false, - set: false, - reason: 'cloudfront_disabled', - }), + expect.any(Object), ); }); diff --git a/packages/api/src/cdn/__tests__/cloudfront-cookies.test.ts b/packages/api/src/cdn/__tests__/cloudfront-cookies.test.ts index b9d22048e3..940dece049 100644 --- a/packages/api/src/cdn/__tests__/cloudfront-cookies.test.ts +++ b/packages/api/src/cdn/__tests__/cloudfront-cookies.test.ts @@ -840,6 +840,10 @@ describe('maybeRefreshCloudFrontAuthCookies', () => { expect(result).toMatchObject({ enabled: false, attempted: false, refreshed: false }); expect(mockGetSignedCookies).not.toHaveBeenCalled(); + expect(mockLogger.debug).not.toHaveBeenCalledWith( + '[maybeRefreshCloudFrontAuthCookies] CloudFront auth cookies skipped', + expect.any(Object), + ); }); it('does not refresh when imageSigning is not cookies', () => { @@ -851,6 +855,10 @@ describe('maybeRefreshCloudFrontAuthCookies', () => { expect(result).toMatchObject({ enabled: false, attempted: false, refreshed: false }); expect(mockGetSignedCookies).not.toHaveBeenCalled(); + expect(mockLogger.debug).not.toHaveBeenCalledWith( + '[maybeRefreshCloudFrontAuthCookies] CloudFront auth cookies skipped', + expect.any(Object), + ); }); it('force-refreshes even when the scope cookie is fresh without calling OIDC refresh', () => { diff --git a/packages/api/src/cdn/cloudfront-cookies.ts b/packages/api/src/cdn/cloudfront-cookies.ts index 98de321043..8f1add221b 100644 --- a/packages/api/src/cdn/cloudfront-cookies.ts +++ b/packages/api/src/cdn/cloudfront-cookies.ts @@ -312,6 +312,10 @@ function getCloudFrontCookieSkipReason(scope: CloudFrontCookieScope): string | n return null; } +function shouldLogCloudFrontCookieSkip(reason: string): boolean { + return reason !== 'cloudfront_disabled'; +} + function getScopeRefreshReason( previousScope: CloudFrontCookieScope | null, currentScope: CloudFrontCookieScope, @@ -540,14 +544,16 @@ export function maybeRefreshCloudFrontAuthCookies( const timing = getCloudFrontCookieTiming(); if (skipReason) { - logger.debug('[maybeRefreshCloudFrontAuthCookies] CloudFront auth cookies skipped', { - attempted: false, - refreshed: false, - reason: skipReason, - has_user_id: Boolean(scope.userId), - has_tenant_scope: Boolean(scope.tenantId), - has_storage_region: Boolean(scope.storageRegion), - }); + if (shouldLogCloudFrontCookieSkip(skipReason)) { + logger.debug('[maybeRefreshCloudFrontAuthCookies] CloudFront auth cookies skipped', { + attempted: false, + refreshed: false, + reason: skipReason, + has_user_id: Boolean(scope.userId), + has_tenant_scope: Boolean(scope.tenantId), + has_storage_region: Boolean(scope.storageRegion), + }); + } return { enabled: false, attempted: false, diff --git a/packages/api/src/middleware/__tests__/tenant.spec.ts b/packages/api/src/middleware/__tests__/tenant.spec.ts index d393cdfe0d..6a78ad3098 100644 --- a/packages/api/src/middleware/__tests__/tenant.spec.ts +++ b/packages/api/src/middleware/__tests__/tenant.spec.ts @@ -1,5 +1,11 @@ import { unlink } from 'fs/promises'; -import { getTenantId, SYSTEM_TENANT_ID } from '@librechat/data-schemas'; +import { + getTenantId, + getUserId, + getRequestId, + SYSTEM_TENANT_ID, + logger, +} from '@librechat/data-schemas'; import type { Response, NextFunction } from 'express'; import type { ServerRequest } from '~/types/http'; // Import directly from source file — _resetTenantMiddlewareStrictCache is intentionally @@ -18,11 +24,18 @@ jest.mock('fs/promises', () => ({ const unlinkMock = unlink as jest.MockedFunction; function mockReq(user?: Record): ServerRequest { - return { user } as unknown as ServerRequest; + return { headers: {}, user } as unknown as ServerRequest; } function mockTenantReq(user?: Record, tenantId?: string): ServerRequest { - return { user, tenantId } as unknown as ServerRequest; + return { headers: {}, user, tenantId } as unknown as ServerRequest; +} + +function mockReqWithHeaders( + user: Record | undefined, + headers: Record, +): ServerRequest { + return { headers, user } as unknown as ServerRequest; } function mockRes(): Response { @@ -43,11 +56,32 @@ function runMiddleware(req: ServerRequest, res: Response): Promise { + return new Promise((resolve) => { + const next: NextFunction = () => { + resolve({ + tenantId: getTenantId(), + userId: getUserId(), + requestId: getRequestId(), + }); + }; + tenantContextMiddleware(req, res, next); + }); +} + describe('tenantContextMiddleware', () => { afterEach(() => { _resetTenantMiddlewareStrictCache(); delete process.env.TENANT_ISOLATION_STRICT; unlinkMock.mockClear(); + jest.restoreAllMocks(); }); it('sets ALS tenant context for authenticated requests with tenantId', async () => { @@ -58,6 +92,22 @@ describe('tenantContextMiddleware', () => { expect(tenantId).toBe('tenant-x'); }); + it('sets ALS user and request context for authenticated tenant requests', async () => { + const req = mockReqWithHeaders( + { id: 'user-123', tenantId: 'tenant-x', role: 'user' }, + { 'x-request-id': 'req-abc' }, + ); + const res = mockRes(); + + const context = await runMiddlewareContext(req, res); + + expect(context).toEqual({ + tenantId: 'tenant-x', + userId: 'user-123', + requestId: 'req-abc', + }); + }); + it('is a no-op for unauthenticated requests (no user)', async () => { const req = mockReq(); const res = mockRes(); @@ -74,6 +124,22 @@ describe('tenantContextMiddleware', () => { expect(tenantId).toBeUndefined(); }); + it('keeps user context in non-strict single-tenant mode', async () => { + const req = mockReqWithHeaders( + { id: 'single-user', role: 'user' }, + { 'x-request-id': 'req-1' }, + ); + const res = mockRes(); + + const context = await runMiddlewareContext(req, res); + + expect(context).toEqual({ + tenantId: undefined, + userId: 'single-user', + requestId: 'req-1', + }); + }); + it('returns 403 when user has no tenantId in strict mode', async () => { process.env.TENANT_ISOLATION_STRICT = 'true'; _resetTenantMiddlewareStrictCache(); @@ -122,6 +188,7 @@ describe('restoreTenantContextFromReq', () => { _resetTenantMiddlewareStrictCache(); delete process.env.TENANT_ISOLATION_STRICT; unlinkMock.mockClear(); + jest.restoreAllMocks(); }); it('restores ALS tenant context from req.user.tenantId', async () => { @@ -139,6 +206,34 @@ describe('restoreTenantContextFromReq', () => { expect(tenantId).toBe('tenant-user'); }); + it('restores user and request context alongside tenant context', async () => { + const req = mockReqWithHeaders( + { id: 'restore-user', tenantId: 'tenant-user', role: 'user' }, + { 'x-correlation-id': 'corr-123' }, + ); + const res = mockRes(); + + const context = await new Promise<{ + tenantId?: string; + userId?: string; + requestId?: string; + }>((resolve) => { + restoreTenantContextFromReq(req, res, () => { + resolve({ + tenantId: getTenantId(), + userId: getUserId(), + requestId: getRequestId(), + }); + }); + }); + + expect(context).toEqual({ + tenantId: 'tenant-user', + userId: 'restore-user', + requestId: 'corr-123', + }); + }); + it('prefers server-resolved req.tenantId over req.user.tenantId', async () => { const req = mockTenantReq({ tenantId: 'tenant-user', role: 'user' }, 'tenant-request'); const res = mockRes(); @@ -187,6 +282,37 @@ describe('restoreTenantContextFromReq', () => { expect(next).not.toHaveBeenCalled(); }); + it('keeps request context while cleaning up rejected strict-mode uploads', async () => { + process.env.TENANT_ISOLATION_STRICT = 'true'; + _resetTenantMiddlewareStrictCache(); + unlinkMock.mockRejectedValueOnce(new Error('unlink failed')); + let observedContext: { userId?: string; requestId?: string } | undefined; + jest.spyOn(logger, 'error').mockImplementation(() => { + observedContext = { + userId: getUserId(), + requestId: getRequestId(), + }; + return logger; + }); + + const req = { + ...mockReqWithHeaders({ id: 'strict-user', role: 'user' }, { 'x-request-id': 'req-strict' }), + file: { path: '/tmp/no-tenant-upload' }, + } as ServerRequest; + const res = mockRes(); + const next: NextFunction = jest.fn(); + + await restoreTenantContextFromReq(req, res, next); + + expect(logger.error).toHaveBeenCalledWith( + '[restoreTenantContextFromReq] Failed to delete rejected upload:', + expect.objectContaining({ path: '/tmp/no-tenant-upload' }), + ); + expect(observedContext).toEqual({ userId: 'strict-user', requestId: 'req-strict' }); + expect(res.status).toHaveBeenCalledWith(403); + expect(next).not.toHaveBeenCalled(); + }); + it('rejects the system tenant sentinel for request-owned work', async () => { const req = mockReq({ tenantId: SYSTEM_TENANT_ID, role: 'user' }); const res = mockRes(); @@ -198,6 +324,37 @@ describe('restoreTenantContextFromReq', () => { expect(next).not.toHaveBeenCalled(); }); + it('rejects a normalized system tenant sentinel for request-owned work', async () => { + const req = mockTenantReq({ role: 'user' }, ` ${SYSTEM_TENANT_ID} `); + const res = mockRes(); + const next: NextFunction = jest.fn(); + + await restoreTenantContextFromReq(req, res, next); + + expect(res.status).toHaveBeenCalledWith(403); + expect(res.json).toHaveBeenCalledWith({ + error: 'System tenant is not allowed for request-scoped routes', + }); + expect(next).not.toHaveBeenCalled(); + }); + + it('rejects blank server-resolved tenant IDs in strict mode', async () => { + process.env.TENANT_ISOLATION_STRICT = 'true'; + _resetTenantMiddlewareStrictCache(); + + const req = mockTenantReq({ role: 'user' }, ' '); + const res = mockRes(); + const next: NextFunction = jest.fn(); + + await restoreTenantContextFromReq(req, res, next); + + expect(res.status).toHaveBeenCalledWith(403); + expect(res.json).toHaveBeenCalledWith( + expect.objectContaining({ error: expect.stringContaining('Tenant context required') }), + ); + expect(next).not.toHaveBeenCalled(); + }); + it('deletes uploaded temp files before rejecting system-tenant requests', async () => { const req = { ...mockReq({ tenantId: SYSTEM_TENANT_ID, role: 'user' }), diff --git a/packages/api/src/middleware/preAuthTenant.spec.ts b/packages/api/src/middleware/preAuthTenant.spec.ts index 669a43c84f..8aeb8b93ba 100644 --- a/packages/api/src/middleware/preAuthTenant.spec.ts +++ b/packages/api/src/middleware/preAuthTenant.spec.ts @@ -1,4 +1,4 @@ -import { getTenantId, logger } from '@librechat/data-schemas'; +import { getTenantId, getRequestId, logger } from '@librechat/data-schemas'; import { preAuthTenantMiddleware } from './preAuthTenant'; import type { Request, Response, NextFunction } from 'express'; @@ -54,6 +54,17 @@ describe('preAuthTenantMiddleware', () => { expect(capturedTenantId).toBe('acme-corp'); }); + it('propagates request ID from pre-auth routes', () => { + req.headers = { 'x-request-id': 'req-preauth' }; + let capturedRequestId: string | undefined; + const capturedNext: NextFunction = () => { + capturedRequestId = getRequestId(); + }; + + preAuthTenantMiddleware(req as Request, res as Response, capturedNext); + expect(capturedRequestId).toBe('req-preauth'); + }); + 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 bab91f3a18..5d59cd8ae9 100644 --- a/packages/api/src/middleware/preAuthTenant.ts +++ b/packages/api/src/middleware/preAuthTenant.ts @@ -1,5 +1,6 @@ -import { tenantStorage, logger, SYSTEM_TENANT_ID } from '@librechat/data-schemas'; +import { logger, SYSTEM_TENANT_ID } from '@librechat/data-schemas'; import type { Request, Response, NextFunction } from 'express'; +import { buildTenantContext, runWithTenantContext } from './tenant'; /** * Pre-authentication tenant context middleware for unauthenticated routes. @@ -27,46 +28,49 @@ import type { Request, Response, NextFunction } from 'express'; * 3. Layer additional resolution on top (e.g., OpenID `tenant` claim → header). * * If no header is present, downstream runs without tenant ALS context (same as - * single-tenant mode). This preserves backward compatibility. + * single-tenant mode), while request logging context can still propagate. */ const MAX_TENANT_ID_LENGTH = 128; 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 }); if (!raw || typeof raw !== 'string') { - next(); + runWithTenantContext(requestContext, next); return; } const tenantId = raw.trim(); if (!tenantId) { - next(); + runWithTenantContext(requestContext, next); return; } if (tenantId === SYSTEM_TENANT_ID) { - logger.warn('[preAuthTenant] Rejected __SYSTEM__ sentinel in X-Tenant-Id header', { - ip: req.ip, - path: req.path, + runWithTenantContext(requestContext, () => { + logger.warn('[preAuthTenant] Rejected __SYSTEM__ sentinel in X-Tenant-Id header', { + ip: req.ip, + path: req.path, + }); + next(); }); - next(); return; } if (tenantId.length > MAX_TENANT_ID_LENGTH || !VALID_TENANT_ID.test(tenantId)) { - logger.warn('[preAuthTenant] Rejected malformed X-Tenant-Id header', { - ip: req.ip, - length: tenantId.length, - path: req.path, + runWithTenantContext(requestContext, () => { + logger.warn('[preAuthTenant] Rejected malformed X-Tenant-Id header', { + ip: req.ip, + length: tenantId.length, + path: req.path, + }); + next(); }); - next(); return; } - return void tenantStorage.run({ tenantId }, async () => { - next(); - }); + runWithTenantContext(buildTenantContext({ headers: req.headers }, tenantId), next); } diff --git a/packages/api/src/middleware/tenant.ts b/packages/api/src/middleware/tenant.ts index d0907e0d65..41af195584 100644 --- a/packages/api/src/middleware/tenant.ts +++ b/packages/api/src/middleware/tenant.ts @@ -1,9 +1,26 @@ import { unlink } from 'fs/promises'; import { isMainThread } from 'worker_threads'; -import { getTenantId, tenantStorage, logger, SYSTEM_TENANT_ID } from '@librechat/data-schemas'; +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'; +type ContextUser = { + tenantId?: string; + id?: string; + _id?: { toString: () => string }; +} | null; + +type ContextRequest = { + headers: ServerRequest['headers']; + tenantId?: string; + user?: ContextUser; + id?: string; + requestId?: string; +}; + +const REQUEST_ID_HEADERS = ['x-request-id', 'x-correlation-id'] as const; + let _checkedThread = false; let _strictMode: boolean | undefined; @@ -17,20 +34,73 @@ export function _resetTenantMiddlewareStrictCache(): void { _strictMode = undefined; } +function normalizeContextValue(value?: string): string | undefined { + const trimmed = value?.trim(); + 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); +} + +export function buildTenantContext( + req: ContextRequest, + tenantId = req.tenantId ?? req.user?.tenantId, +): TenantContext { + return { + tenantId: normalizeContextValue(tenantId), + userId: getUserId(req.user ?? null), + requestId: getRequestId(req), + }; +} + +export function runWithTenantContext(context: TenantContext, next: NextFunction): void { + if (!hasTenantContext(context)) { + next(); + return; + } + return void tenantStorage.run(context, async () => { + next(); + }); +} + /** * Express middleware that propagates the authenticated user's `tenantId` into - * the AsyncLocalStorage context used by the Mongoose tenant-isolation plugin. + * the AsyncLocalStorage context used by the Mongoose tenant-isolation plugin + * and request-scoped logging. * * **Placement**: Chained automatically by `requireJwtAuth` after successful * passport authentication (req.user is populated). Must NOT be registered at * global `app.use()` scope — `req.user` is undefined at that stage. * * Behaviour: - * - Authenticated request with `tenantId` → wraps downstream in `tenantStorage.run({ tenantId })` + * - Authenticated request with context → wraps downstream in `tenantStorage.run(context)` * - Authenticated request **without** `tenantId`: * - Strict mode (`TENANT_ISOLATION_STRICT=true`) → responds 403 - * - Non-strict (default) → passes through without ALS context (backward compat) - * - Unauthenticated request → no-op (calls `next()` directly) + * - Non-strict (default) → passes through with user/request context only + * - Unauthenticated request → propagates request context when available */ export function tenantContextMiddleware( req: ServerRequest, @@ -47,27 +117,26 @@ export function tenantContextMiddleware( } } - const user = req.user as { tenantId?: string } | undefined; + const user = req.user; + const context = buildTenantContext(req); if (!user) { - next(); + runWithTenantContext(context, next); return; } - const tenantId = user.tenantId; + const { tenantId } = context; if (!tenantId) { if (isStrict()) { res.status(403).json({ error: 'Tenant context required in strict isolation mode' }); return; } - next(); + runWithTenantContext(context, next); return; } - return void tenantStorage.run({ tenantId }, async () => { - next(); - }); + runWithTenantContext(context, next); } export type RequestTenantSource = { @@ -137,6 +206,19 @@ async function rejectRequestWithUploadCleanup( res.status(403).json({ error: message }); } +function rejectRequestWithUploadCleanupInContext( + context: TenantContext, + req: ServerRequest, + res: Response, + message: string, +): Promise { + const rejectRequest = () => rejectRequestWithUploadCleanup(req, res, message); + if (!hasTenantContext(context)) { + return rejectRequest(); + } + return tenantStorage.run(context, rejectRequest); +} + /** * Re-enters tenant ALS from the server-resolved request tenant. * @@ -150,20 +232,23 @@ export function restoreTenantContextFromReq( next: NextFunction, ): void | Promise { const tenantId = resolveRequestTenantId(req as RequestTenantSource); + const context = buildTenantContext(req, tenantId); + const resolvedTenantId = context.tenantId; - if (!tenantId) { + if (!resolvedTenantId) { if (isStrict()) { - return rejectRequestWithUploadCleanup( + return rejectRequestWithUploadCleanupInContext( + context, req, res, 'Tenant context required in strict isolation mode', ); } - next(); + runWithTenantContext(context, next); return; } - if (tenantId === SYSTEM_TENANT_ID) { + if (resolvedTenantId === SYSTEM_TENANT_ID) { logger.warn('[restoreTenantContextFromReq] Rejected system tenant for request route', { path: req.path, }); @@ -174,12 +259,15 @@ export function restoreTenantContextFromReq( ); } - if (getTenantId() === tenantId) { + const currentContext = tenantStorage.getStore(); + if ( + currentContext?.tenantId === context.tenantId && + currentContext?.userId === context.userId && + currentContext?.requestId === context.requestId + ) { next(); return; } - return void tenantStorage.run({ tenantId }, async () => { - next(); - }); + return runWithTenantContext(context, next); } diff --git a/packages/data-schemas/src/config/parsers.spec.ts b/packages/data-schemas/src/config/parsers.spec.ts new file mode 100644 index 0000000000..188f42db3c --- /dev/null +++ b/packages/data-schemas/src/config/parsers.spec.ts @@ -0,0 +1,73 @@ +import { debugTraverse } from './parsers'; + +const SPLAT_SYMBOL = Symbol.for('splat'); +const MESSAGE_SYMBOL = Symbol.for('message'); + +type FormatterInfo = Record & { + level: string; + message: string; + timestamp: string; +}; + +function runFormatter(info: FormatterInfo): string { + const transformed = debugTraverse.transform(info); + if (transformed && typeof transformed === 'object') { + const message = (transformed as Record)[MESSAGE_SYMBOL]; + return typeof message === 'string' ? message : String(transformed); + } + return String(transformed); +} + +function buildInfo(level: string, meta: Record): FormatterInfo { + return { + level, + message: 'test', + timestamp: 'ts', + ...meta, + [SPLAT_SYMBOL]: [meta], + }; +} + +describe('debugTraverse request context', () => { + it('appends request context metadata for non-debug lines', () => { + const out = runFormatter( + buildInfo('info', { + tenantId: 'tenant-1', + userId: 'user-1', + requestId: 'req-1', + }), + ); + + expect(out).toContain('"tenantId":"tenant-1"'); + expect(out).toContain('"userId":"user-1"'); + expect(out).toContain('"requestId":"req-1"'); + }); + + it('does not append the system tenant sentinel as tenantId', () => { + const out = runFormatter( + buildInfo('info', { + tenantId: '__SYSTEM__', + userId: 'user-1', + requestId: 'req-1', + }), + ); + + expect(out).not.toContain('__SYSTEM__'); + expect(out).not.toContain('"tenantId"'); + expect(out).toContain('"userId":"user-1"'); + expect(out).toContain('"requestId":"req-1"'); + }); + + it('omits the system tenant sentinel from debug object metadata', () => { + const out = runFormatter( + buildInfo('debug', { + tenantId: '__SYSTEM__', + userId: 'user-1', + }), + ); + + expect(out).not.toContain('__SYSTEM__'); + expect(out).not.toMatch(/tenantId:/); + expect(out).toContain('userId'); + }); +}); diff --git a/packages/data-schemas/src/config/parsers.ts b/packages/data-schemas/src/config/parsers.ts index 80dd9b767c..e21927a72b 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 traverse from '../utils/object-traverse'; +import { SYSTEM_TENANT_ID } from './tenantContext'; import type { TraverseContext } from '../utils/object-traverse'; const SPLAT_SYMBOL = Symbol.for('splat'); @@ -8,6 +9,7 @@ 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 sensitiveKeys: RegExp[] = [ /^(sk-)[^\s]+/, // OpenAI API key pattern @@ -104,6 +106,25 @@ 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. @@ -131,7 +152,7 @@ const debugTraverse = winston.format.printf( try { if (level !== 'debug') { - return msgParts[0]; + return appendRequestContext(msgParts[0], metadata); } if (!metadata) { @@ -144,22 +165,25 @@ const debugTraverse = winston.format.printf( const debugValue = Array.isArray(splatArray) ? splatArray[0] : undefined; if (!debugValue) { - return msgParts[0]; + return appendRequestContext(msgParts[0], metadata); } if (debugValue && Array.isArray(debugValue)) { msgParts.push(`\n${JSON.stringify(debugValue.map(condenseArray))}`); - return msgParts.join(''); + return appendRequestContext(msgParts.join(''), metadata); } if (typeof debugValue !== 'object') { msgParts.push(` ${debugValue}`); - return msgParts.join(''); + return appendRequestContext(msgParts.join(''), metadata); } msgParts.push('\n{'); const copy = klona(metadata); + if (copy.tenantId === SYSTEM_TENANT_ID) { + delete copy.tenantId; + } try { const traversal = traverse(copy); traversal.forEach(function (this: TraverseContext, value: unknown) { diff --git a/packages/data-schemas/src/config/tenantContext.spec.ts b/packages/data-schemas/src/config/tenantContext.spec.ts index 7e6cc0748d..a01e01ff76 100644 --- a/packages/data-schemas/src/config/tenantContext.spec.ts +++ b/packages/data-schemas/src/config/tenantContext.spec.ts @@ -1,4 +1,4 @@ -import { tenantStorage, runAsSystem, scopedCacheKey } from './tenantContext'; +import { tenantStorage, getUserId, getRequestId, runAsSystem, scopedCacheKey } from './tenantContext'; describe('scopedCacheKey', () => { it('returns base key when no ALS context is set', () => { @@ -23,4 +23,21 @@ describe('scopedCacheKey', () => { }); expect(scopedCacheKey('KEY')).toBe('KEY'); }); + + it('reads user and request IDs from ALS context', async () => { + await tenantStorage.run({ userId: 'user-1', requestId: 'req-1' }, async () => { + expect(getUserId()).toBe('user-1'); + expect(getRequestId()).toBe('req-1'); + }); + }); + + it('preserves user and request context inside system tenant operations', async () => { + await tenantStorage.run({ tenantId: 'acme', userId: 'user-1', requestId: 'req-1' }, async () => { + await runAsSystem(async () => { + expect(getUserId()).toBe('user-1'); + expect(getRequestId()).toBe('req-1'); + expect(scopedCacheKey('KEY')).toBe('KEY'); + }); + }); + }); }); diff --git a/packages/data-schemas/src/config/tenantContext.ts b/packages/data-schemas/src/config/tenantContext.ts index eb77edb27d..9dc73f972b 100644 --- a/packages/data-schemas/src/config/tenantContext.ts +++ b/packages/data-schemas/src/config/tenantContext.ts @@ -2,6 +2,8 @@ import { AsyncLocalStorage } from 'async_hooks'; export interface TenantContext { tenantId?: string; + userId?: string; + requestId?: string; } /** Sentinel value for deliberate cross-tenant system operations */ @@ -19,12 +21,23 @@ export function getTenantId(): string | undefined { return tenantStorage.getStore()?.tenantId; } +/** Returns the current user ID from async context, or undefined if none is set */ +export function getUserId(): string | undefined { + return tenantStorage.getStore()?.userId; +} + +/** Returns the current request ID from async context, or undefined if none is set */ +export function getRequestId(): string | undefined { + return tenantStorage.getStore()?.requestId; +} + /** * 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 { - return tenantStorage.run({ tenantId: SYSTEM_TENANT_ID }, fn); + const { requestId, userId } = tenantStorage.getStore() ?? {}; + return tenantStorage.run({ tenantId: SYSTEM_TENANT_ID, requestId, userId }, fn); } /** diff --git a/packages/data-schemas/src/config/winston.ts b/packages/data-schemas/src/config/winston.ts index 24a2c6c987..9bc7652415 100644 --- a/packages/data-schemas/src/config/winston.ts +++ b/packages/data-schemas/src/config/winston.ts @@ -1,6 +1,7 @@ import winston from 'winston'; import 'winston-daily-rotate-file'; import { redactFormat, redactMessage, debugTraverse, jsonTruncateFormat } from './parsers'; +import { getTenantId, getUserId, getRequestId, SYSTEM_TENANT_ID } from './tenantContext'; import { getLogDirectory } from './utils'; const logDir = getLogDirectory(); @@ -24,6 +25,49 @@ 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; +} + winston.addColors({ info: 'green', warn: 'italic yellow', @@ -41,6 +85,7 @@ const fileFormat = winston.format.combine( winston.format.timestamp({ format: () => new Date().toISOString() }), winston.format.errors({ stack: true }), winston.format.splat(), + requestContextFormat(), ); const transports: winston.transport[] = [ @@ -71,11 +116,13 @@ if (useDebugLogging) { const consoleFormat = winston.format.combine( redactFormat(), + requestContextFormat(), winston.format.colorize({ all: true }), winston.format.timestamp({ format: 'YYYY-MM-DD HH:mm:ss' }), winston.format.printf((info) => { const message = `${info.timestamp} ${info.level}: ${info.message}`; - return info.level.includes('error') ? redactMessage(message) : message; + const line = appendRequestContext(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 4156559658..8c95d7f9cc 100644 --- a/packages/data-schemas/src/index.ts +++ b/packages/data-schemas/src/index.ts @@ -23,6 +23,8 @@ export { default as meiliLogger } from './config/meiliLogger'; export { tenantStorage, getTenantId, + getUserId, + getRequestId, runAsSystem, scopedCacheKey, SYSTEM_TENANT_ID,