From 73bbfaf0585046992d464ed38f07f9f4e36ae1d6 Mon Sep 17 00:00:00 2001 From: Brainslug Date: Fri, 24 Mar 2023 15:04:22 +0100 Subject: [PATCH] Fix cookie redaction in logs (#17914) * removed incorrect redaction logic * updated paths that werent working * Added new redaction function * Reverting unintentional change * don't force lowercase provider names * extracted cookieNames * set cookie based on driver settings suggested by ian * add unit test * redact the entire cookie header * updated the tests * move redact text to constants --------- Co-authored-by: Azri Kahar <42867097+azrikahar@users.noreply.github.com> Co-authored-by: Rijk van Zanten --- api/src/constants.ts | 2 + api/src/logger.test.ts | 140 ++++++++++++++++++++ api/src/logger.ts | 46 +++---- api/src/utils/redact-header-cookies.test.ts | 42 ------ api/src/utils/redact-header-cookies.ts | 7 - 5 files changed, 165 insertions(+), 72 deletions(-) create mode 100644 api/src/logger.test.ts delete mode 100644 api/src/utils/redact-header-cookies.test.ts delete mode 100644 api/src/utils/redact-header-cookies.ts diff --git a/api/src/constants.ts b/api/src/constants.ts index 83a9c35845..20bc21c0ac 100644 --- a/api/src/constants.ts +++ b/api/src/constants.ts @@ -62,3 +62,5 @@ export const COOKIE_OPTIONS: CookieOptions = { }; export const OAS_REQUIRED_SCHEMAS = ['Diff', 'Schema', 'Query', 'x-metadata']; + +export const REDACT_TEXT = '--redact--'; diff --git a/api/src/logger.test.ts b/api/src/logger.test.ts new file mode 100644 index 0000000000..a2beb95caf --- /dev/null +++ b/api/src/logger.test.ts @@ -0,0 +1,140 @@ +import { afterEach, beforeEach, describe, expect, test, vi } from 'vitest'; + +const REFRESH_TOKEN_COOKIE_NAME = 'directus_refresh_token'; + +vi.mock('./env', async () => { + const MOCK_ENV = { + AUTH_PROVIDERS: 'ranger,monospace', + AUTH_RANGER_DRIVER: 'oauth2', + AUTH_MONOSPACE_DRIVER: 'openid', + REFRESH_TOKEN_COOKIE_NAME, + LOG_LEVEL: 'info', + LOG_STYLE: 'raw', + }; + return { + default: MOCK_ENV, + getEnv: () => MOCK_ENV, + }; +}); + +import { Writable } from 'node:stream'; +import pino from 'pino'; +import { REDACT_TEXT } from './constants'; +import { httpLoggerOptions } from './logger'; + +const logOutput = vi.fn(); + +let stream: Writable; + +beforeEach(() => { + stream = new Writable({ + write(chunk) { + logOutput(JSON.parse(chunk.toString())); + }, + }); +}); + +afterEach(() => { + vi.clearAllMocks(); +}); + +describe('req.headers.authorization', () => { + test('Should redact bearer token in Authorization header', () => { + const instance = pino(httpLoggerOptions, stream); + instance.info({ + req: { + headers: { + authorization: `Bearer test-access-token-value`, + }, + }, + }); + expect(logOutput.mock.calls[0][0]).toMatchObject({ + req: { + headers: { + authorization: REDACT_TEXT, + }, + }, + }); + }); +}); + +describe('req.headers.cookie', () => { + test('Should redact refresh token when there is only one entry', () => { + const instance = pino(httpLoggerOptions, stream); + instance.info({ + req: { + headers: { + cookie: `${REFRESH_TOKEN_COOKIE_NAME}=test-refresh-token-value`, + }, + }, + }); + expect(logOutput.mock.calls[0][0]).toMatchObject({ + req: { + headers: { + cookie: REDACT_TEXT, + }, + }, + }); + }); + + test('Should redact refresh token with multiple entries', () => { + const instance = pino(httpLoggerOptions, stream); + instance.info({ + req: { + headers: { + cookie: `custom_test_cookie=custom_test_value; access_token=test-access-token-value; oauth2.ranger=test-oauth2-value; openid.monospace=test-openid-value; ${REFRESH_TOKEN_COOKIE_NAME}=test-refresh-token-value`, + }, + }, + }); + expect(logOutput.mock.calls[0][0]).toMatchObject({ + req: { + headers: { + cookie: REDACT_TEXT, + }, + }, + }); + }); +}); + +describe('res.headers', () => { + test('Should redact refresh token when there is only one entry', () => { + const instance = pino(httpLoggerOptions, stream); + instance.info({ + res: { + headers: { + 'set-cookie': `${REFRESH_TOKEN_COOKIE_NAME}=test-refresh-token-value; Max-Age=604800; Path=/; Expires=Tue, 14 Feb 2023 12:00:00 GMT; HttpOnly; SameSite=Lax`, + }, + }, + }); + expect(logOutput.mock.calls[0][0]).toMatchObject({ + res: { + headers: { + 'set-cookie': REDACT_TEXT, + }, + }, + }); + }); + + test('Should redact refresh token with multiple entries', () => { + const instance = pino(httpLoggerOptions, stream); + instance.info({ + res: { + headers: { + 'set-cookie': [ + `access_token=test-access-token-value; Max-Age=604800; Path=/; Expires=Tue, 14 Feb 2023 12:00:00 GMT; HttpOnly; SameSite=Lax`, + `oauth2.ranger=test-oauth2-value; Max-Age=604800; Path=/; Expires=Tue, 14 Feb 2023 12:00:00 GMT; HttpOnly; SameSite=Lax`, + `openid.monospace=test-openid-value; Max-Age=604800; Path=/; Expires=Tue, 14 Feb 2023 12:00:00 GMT; HttpOnly; SameSite=Lax`, + `${REFRESH_TOKEN_COOKIE_NAME}=test-refresh-token-value; Max-Age=604800; Path=/; Expires=Tue, 14 Feb 2023 12:00:00 GMT; HttpOnly; SameSite=Lax`, + ], + }, + }, + }); + expect(logOutput.mock.calls[0][0]).toMatchObject({ + res: { + headers: { + 'set-cookie': REDACT_TEXT, + }, + }, + }); + }); +}); diff --git a/api/src/logger.ts b/api/src/logger.ts index 5f646b41a3..f1199e22a3 100644 --- a/api/src/logger.ts +++ b/api/src/logger.ts @@ -1,25 +1,25 @@ import { toArray } from '@directus/shared/utils'; import { merge } from 'lodash'; -import pino, { LoggerOptions, SerializedResponse } from 'pino'; +import pino, { LoggerOptions } from 'pino'; import type { Request, RequestHandler } from 'express'; import pinoHTTP, { stdSerializers } from 'pino-http'; import { URL } from 'url'; import env from './env'; +import { REDACT_TEXT } from './constants'; import { getConfigFromEnv } from './utils/get-config-from-env'; -import { redactHeaderCookie } from './utils/redact-header-cookies'; const pinoOptions: LoggerOptions = { level: env['LOG_LEVEL'] || 'info', redact: { - paths: ['req.headers.authorization', `req.cookies.${env['REFRESH_TOKEN_COOKIE_NAME']}`], - censor: '--redact--', + paths: ['req.headers.authorization', 'req.headers.cookie'], + censor: REDACT_TEXT, }, }; -const httpLoggerOptions: LoggerOptions = { +export const httpLoggerOptions: LoggerOptions = { level: env['LOG_LEVEL'] || 'info', redact: { - paths: ['req.headers.authorization', `req.cookies.${env['REFRESH_TOKEN_COOKIE_NAME']}`], - censor: '--redact--', + paths: ['req.headers.authorization', 'req.headers.cookie'], + censor: REDACT_TEXT, }, }; @@ -44,6 +44,21 @@ if (env['LOG_STYLE'] !== 'raw') { }, }; } +if (env['LOG_STYLE'] === 'raw') { + httpLoggerOptions.redact = { + paths: ['req.headers.authorization', 'req.headers.cookie', 'res.headers'], + censor: (value, pathParts) => { + const path = pathParts.join('.'); + if (path === 'res.headers') { + if ('set-cookie' in value) { + value['set-cookie'] = REDACT_TEXT; + } + return value; + } + return REDACT_TEXT; + }, + }; +} const loggerEnvConfig = getConfigFromEnv('LOGGER_', 'LOGGER_HTTP'); @@ -87,23 +102,8 @@ export const expressLogger = pinoHTTP({ req(request: Request) { const output = stdSerializers.req(request); output.url = redactQuery(output.url); - if (output.headers?.['cookie']) { - output.headers['cookie'] = redactHeaderCookie(output.headers['cookie'], [ - 'access_token', - `${env['REFRESH_TOKEN_COOKIE_NAME']}`, - ]); - } return output; }, - res(response: SerializedResponse) { - if (response.headers?.['set-cookie']) { - response.headers['set-cookie'] = redactHeaderCookie(response.headers['set-cookie'], [ - 'access_token', - `${env['REFRESH_TOKEN_COOKIE_NAME']}`, - ]); - } - return response; - }, }, }) as RequestHandler; @@ -113,7 +113,7 @@ function redactQuery(originalPath: string) { const url = new URL(originalPath, 'http://example.com/'); if (url.searchParams.has('access_token')) { - url.searchParams.set('access_token', '--redacted--'); + url.searchParams.set('access_token', REDACT_TEXT); } return url.pathname + url.search; diff --git a/api/src/utils/redact-header-cookies.test.ts b/api/src/utils/redact-header-cookies.test.ts deleted file mode 100644 index 475bde5446..0000000000 --- a/api/src/utils/redact-header-cookies.test.ts +++ /dev/null @@ -1,42 +0,0 @@ -import { describe, expect, test } from 'vitest'; -import env from '../env'; -import { redactHeaderCookie } from './redact-header-cookies'; - -describe('redactHeaderCookie', () => { - describe('Given auth cookies', () => { - test('When it finds a refresh_token, it should redact the value', () => { - const tokenKey = env['REFRESH_TOKEN_COOKIE_NAME']; - const cookieHeader = `${tokenKey}=shh;`; - const cookieNames = [`${tokenKey}`]; - - const redactedCookie = redactHeaderCookie(cookieHeader, cookieNames); - expect(redactedCookie).toBe(`${tokenKey}=--redacted--;`); - }); - test('When it finds an access_token, it should redact the value', () => { - const tokenKey = 'access_token'; - const cookieHeader = `${tokenKey}=secret;`; - const cookieNames = [`${tokenKey}`]; - - const redactedCookie = redactHeaderCookie(cookieHeader, cookieNames); - expect(redactedCookie).toBe(`${tokenKey}=--redacted--;`); - }); - test('When it finds both an access_token and refresh_token, it should redact both values', () => { - const cookieHeader = `access_token=secret; ${env['REFRESH_TOKEN_COOKIE_NAME']}=shhhhhhh; randomCookie=Erdtree;`; - const cookieNames = ['access_token', `${env['REFRESH_TOKEN_COOKIE_NAME']}`]; - - const redactedCookie = redactHeaderCookie(cookieHeader, cookieNames); - expect(redactedCookie).toBe( - `access_token=--redacted--; ${env['REFRESH_TOKEN_COOKIE_NAME']}=--redacted--; randomCookie=Erdtree;` - ); - }); - }); - describe('Given negligible cookies', () => { - test('It should return the orignal value', () => { - const originalCookie = `Crown=Swords; Hail=Sithis;`; - const cookieNames = [env['REFRESH_TOKEN_COOKIE_NAME'], 'access_token']; - - const redactedCookie = redactHeaderCookie(originalCookie, cookieNames); - expect(redactedCookie).toBe(originalCookie); - }); - }); -}); diff --git a/api/src/utils/redact-header-cookies.ts b/api/src/utils/redact-header-cookies.ts deleted file mode 100644 index f5fd73f789..0000000000 --- a/api/src/utils/redact-header-cookies.ts +++ /dev/null @@ -1,7 +0,0 @@ -export function redactHeaderCookie(cookieHeader: string, cookieNames: string[]) { - for (const cookieName of cookieNames) { - const re = new RegExp(`(${cookieName}=)([^;]+)`); - cookieHeader = cookieHeader.replace(re, `$1--redacted--`); - } - return cookieHeader; -}