🧾 feat: Add Structured Logging Context (#13110)

* feat: add structured logging context

* fix: reduce cloudfront disabled logging

* fix: preserve strict reject logging context

* chore: format auth middleware test

* fix: omit system tenant from log context

* fix: type parser spec formatter info

* fix: normalize tenant guard before reject checks
This commit is contained in:
Danny Avila 2026-05-13 19:17:39 -04:00 committed by GitHub
parent 9e8b8c3705
commit 7f58e4c2ed
No known key found for this signature in database
GPG key ID: B5690EEEBB952194
19 changed files with 727 additions and 95 deletions

View file

@ -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',

View file

@ -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 `"<timestamp> <level>: <message>"`
* 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;

View file

@ -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;
}),
);

View file

@ -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();

View file

@ -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);
};

View file

@ -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;
}

View file

@ -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),
);
});

View file

@ -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', () => {

View file

@ -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,

View file

@ -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<typeof unlink>;
function mockReq(user?: Record<string, unknown>): ServerRequest {
return { user } as unknown as ServerRequest;
return { headers: {}, user } as unknown as ServerRequest;
}
function mockTenantReq(user?: Record<string, unknown>, tenantId?: string): ServerRequest {
return { user, tenantId } as unknown as ServerRequest;
return { headers: {}, user, tenantId } as unknown as ServerRequest;
}
function mockReqWithHeaders(
user: Record<string, unknown> | undefined,
headers: Record<string, string>,
): ServerRequest {
return { headers, user } as unknown as ServerRequest;
}
function mockRes(): Response {
@ -43,11 +56,32 @@ function runMiddleware(req: ServerRequest, res: Response): Promise<string | unde
});
}
function runMiddlewareContext(
req: ServerRequest,
res: Response,
): Promise<{
tenantId?: string;
userId?: string;
requestId?: string;
}> {
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' }),

View file

@ -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';

View file

@ -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);
}

View file

@ -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<void> {
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<void> {
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);
}

View file

@ -0,0 +1,73 @@
import { debugTraverse } from './parsers';
const SPLAT_SYMBOL = Symbol.for('splat');
const MESSAGE_SYMBOL = Symbol.for('message');
type FormatterInfo = Record<string | symbol, unknown> & {
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<string | symbol, unknown>)[MESSAGE_SYMBOL];
return typeof message === 'string' ? message : String(transformed);
}
return String(transformed);
}
function buildInfo(level: string, meta: Record<string, unknown>): 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');
});
});

View file

@ -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, unknown>): string {
const context: Partial<Record<(typeof LOG_CONTEXT_KEYS)[number], string>> = {};
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, unknown>): 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) {

View file

@ -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');
});
});
});
});

View file

@ -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<T>(fn: () => Promise<T>): Promise<T> {
return tenantStorage.run({ tenantId: SYSTEM_TENANT_ID }, fn);
const { requestId, userId } = tenantStorage.getStore() ?? {};
return tenantStorage.run({ tenantId: SYSTEM_TENANT_ID, requestId, userId }, fn);
}
/**

View file

@ -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<Record<(typeof LOG_CONTEXT_KEYS)[number], string>> = {};
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;
}),
);

View file

@ -23,6 +23,8 @@ export { default as meiliLogger } from './config/meiliLogger';
export {
tenantStorage,
getTenantId,
getUserId,
getRequestId,
runAsSystem,
scopedCacheKey,
SYSTEM_TENANT_ID,