From 06aa31a1943e7c14103e5afd08f2c4ce73432f62 Mon Sep 17 00:00:00 2001 From: Conrad Lang Date: Mon, 9 Oct 2023 14:07:09 +1100 Subject: [PATCH] feat: Omit specific headers by default (#92) Co-authored-by: Ryan Ling --- .changeset/moody-bobcats-travel.md | 37 ++++++ README.md | 13 +- src/index.test.ts | 102 ++++++++++++++++ src/index.ts | 11 +- src/serializers/index.test.ts | 65 ++++++++-- src/serializers/index.ts | 73 ++++++++--- src/serializers/omitProperties.test.ts | 47 ++++++++ src/serializers/omitProperties.ts | 20 ++++ .../omitPropertiesSerializer.test.ts | 113 ++++++++++++++++++ src/serializers/omitPropertiesSerializer.ts | 19 +++ src/serializers/types.ts | 1 + 11 files changed, 472 insertions(+), 29 deletions(-) create mode 100644 .changeset/moody-bobcats-travel.md create mode 100644 src/serializers/omitProperties.test.ts create mode 100644 src/serializers/omitProperties.ts create mode 100644 src/serializers/omitPropertiesSerializer.test.ts create mode 100644 src/serializers/omitPropertiesSerializer.ts create mode 100644 src/serializers/types.ts diff --git a/.changeset/moody-bobcats-travel.md b/.changeset/moody-bobcats-travel.md new file mode 100644 index 0000000..fc8b137 --- /dev/null +++ b/.changeset/moody-bobcats-travel.md @@ -0,0 +1,37 @@ +--- +'@seek/logger': minor +--- + +Omit request headers + +`@seek/logger` now omits the following properties from `headers` and `req.headers` by default: + +- `x-envoy-attempt-count` +- `x-envoy-decorator-operation` +- `x-envoy-expected-rq-timeout-ms` +- `x-envoy-external-address` +- `x-envoy-internal` +- `x-envoy-peer-metadata` +- `x-envoy-peer-metadata-id` +- `x-envoy-upstream-service-time` + +If you would like to opt out of this behaviours, you can provide an empty list or your own list of request headers to `omitHeaderNames`: + +```diff +const logger = createLogger({ + name: 'my-app', ++ omitHeaderNames: ['dnt', 'sec-fetch-dest'], +}); +``` + +You can also extend the default list like so: + +```diff +- import createLogger from '@seek/logger'; ++ import createLogger, { DEFAULT_OMIT_HEADER_NAMES } from '@seek/logger'; + +const logger = createLogger({ + name: 'my-app', ++ omitHeaderNames: [...DEFAULT_OMIT_HEADER_NAMES, 'dnt', 'sec-fetch-dest'] +}); +``` diff --git a/README.md b/README.md index aa8c09b..4cfd55c 100644 --- a/README.md +++ b/README.md @@ -45,7 +45,7 @@ childLogger.error({ err }, 'Something bad happened'); ### Standardised fields -**@seek/logger** bundles custom `req` and `res` serializers along with [Pino]'s standard set. +**@seek/logger** bundles custom `req`, `res` and `headers` serializers along with [Pino]'s standard set. User-defined serializers will take precedence over predefined ones. Use the following standardised logging fields to benefit from customised serialization: @@ -57,12 +57,21 @@ Use the following standardised logging fields to benefit from customised seriali - `req` for HTTP requests. - The request object is trimmed to a set of essential fields. + The request object is trimmed to a set of essential fields. + Certain headers are omitted by default (e.g. `x-envoy-peer-metadata`). + To opt out of this behavior, set the `omitHeaderNames` logger option to an empty list `[]` + or provide your own list. - `res` for HTTP responses. The response object is trimmed to a set of essential fields. +- `headers` for tracing headers. + + Certain headers are omitted by default (e.g. `x-envoy-peer-metadata`). + To opt out of this behavior, set the `omitHeaderNames` logger option to an empty list `[]` + or provide your own list. + All other fields will be logged directly. ### Typed fields diff --git a/src/index.test.ts b/src/index.test.ts index 5a3fe36..6350ee5 100644 --- a/src/index.test.ts +++ b/src/index.test.ts @@ -1,5 +1,7 @@ import split from 'split2'; +import { DEFAULT_OMIT_HEADER_NAMES } from './serializers'; + import createLogger, { type LoggerOptions } from '.'; const bearerToken = @@ -558,3 +560,103 @@ testLog( maxObjectDepth: 2, }, ); + +const objectWithDefaultOmitHeaderNameKeys = Object.fromEntries( + DEFAULT_OMIT_HEADER_NAMES.map((headerName) => [headerName, 'header value']), +); + +testLog( + 'should omit defaultOmitHeaderNames by default', + { + headers: { + ['authorization']: bearerToken, + ...objectWithDefaultOmitHeaderNameKeys, + ['x-request-id']: 'some-uuid', + }, + req: { + headers: { + ['authorization']: bearerToken, + ...objectWithDefaultOmitHeaderNameKeys, + ['x-request-id']: 'some-uuid', + }, + }, + }, + { + headers: { + ['authorization']: redactedBearer, + ['x-request-id']: 'some-uuid', + }, + req: { + headers: { + ['authorization']: redactedBearer, + ['x-request-id']: 'some-uuid', + }, + }, + }, + 'info', +); + +testLog( + 'should keep defaultOmitHeaderNames when omitHeaderNames option is empty', + { + headers: { + ['authorization']: bearerToken, + ...objectWithDefaultOmitHeaderNameKeys, + ['x-request-id']: 'some-uuid', + }, + req: { + headers: { + ['authorization']: bearerToken, + ...objectWithDefaultOmitHeaderNameKeys, + ['x-request-id']: 'some-uuid', + }, + }, + }, + { + headers: { + ['authorization']: redactedBearer, + ...objectWithDefaultOmitHeaderNameKeys, + ['x-request-id']: 'some-uuid', + }, + req: { + headers: { + ['authorization']: redactedBearer, + ...objectWithDefaultOmitHeaderNameKeys, + ['x-request-id']: 'some-uuid', + }, + }, + }, + 'info', + { omitHeaderNames: [] }, +); + +test('it merges serializers', async () => { + const stream = sink(); + const logger = createLogger( + { + name: 'my-app', + omitHeaderNames: ['omit'], + serializers: { + serialize: () => 'serialized', + }, + }, + stream, + ); + + logger.info( + { req: { headers: { omit: 'raw' } }, serialize: 'raw' }, + 'Test log entry', + ); + const reqLog: any = await once(stream, 'data'); + + expect(reqLog).toHaveProperty('serialize', 'serialized'); + expect(reqLog.req.headers).not.toHaveProperty('omit'); + expect(reqLog).not.toHaveProperty('headers'); + + logger.info({ headers: { omit: 'raw' }, serialize: 'raw' }, 'Test log entry'); + const rootLog: any = await once(stream, 'data'); + + expect(rootLog).toHaveProperty('serialize', 'serialized'); + expect(rootLog.headers).not.toHaveProperty('omit'); + expect(rootLog).not.toHaveProperty('req'); +}); diff --git a/src/index.ts b/src/index.ts index be65d6a..96309ca 100644 --- a/src/index.ts +++ b/src/index.ts @@ -4,11 +4,15 @@ import base from './base'; import { withRedaction } from './destination'; import { type FormatterOptions, createFormatters } from './formatters'; import * as redact from './redact'; -import serializers from './serializers'; +import { type SerializerOptions, createSerializers } from './serializers'; + +export { DEFAULT_OMIT_HEADER_NAMES } from './serializers'; export { pino }; -export type LoggerOptions = pino.LoggerOptions & FormatterOptions; +export type LoggerOptions = pino.LoggerOptions & + FormatterOptions & + SerializerOptions; export type Logger = pino.Logger; /** @@ -25,10 +29,13 @@ export default ( }), ): Logger => { opts.redact = redact.addDefaultRedactPathStrings(opts.redact); + + const serializers = createSerializers(opts); opts.serializers = { ...serializers, ...opts.serializers, }; + const formatters = createFormatters(opts); opts.base = { ...base, diff --git a/src/serializers/index.test.ts b/src/serializers/index.test.ts index 6bc725e..91062d9 100644 --- a/src/serializers/index.test.ts +++ b/src/serializers/index.test.ts @@ -1,4 +1,6 @@ -import serializers from './index'; +import { DEFAULT_OMIT_HEADER_NAMES, createSerializers } from '.'; + +const serializers = createSerializers({}); describe('req', () => { const remoteAddress = '::ffff:123.45.67.89'; @@ -86,7 +88,49 @@ describe('req', () => { `('remoteAddress and remotePort is undefined when $scenario', ({ value }) => { const result = serializers.req(value); - expect(result).toStrictEqual({ ...expectedRequestBase }); + expect(result).toStrictEqual(expectedRequestBase); + }); + + const objectWithDefaultOmitHeaderNameKeys = Object.fromEntries( + DEFAULT_OMIT_HEADER_NAMES.map((headerName) => [headerName, 'header value']), + ); + + it('omits defaultOmitHeaderNames by default', () => { + const request = { + ...requestBase, + headers: { + ...requestBase.headers, + ...objectWithDefaultOmitHeaderNameKeys, + }, + }; + + const result = serializers.req(request); + + expect(result).toStrictEqual(expectedRequestBase); + }); + + it('omits only specified headers when omitHeaderNames is provided', () => { + const request = { + ...requestBase, + headers: { + ...requestBase.headers, + ['omit-me']: 'header value', + ...objectWithDefaultOmitHeaderNameKeys, + }, + }; + + const expectedRequest = { + ...expectedRequestBase, + headers: { + ...requestBase.headers, + ...objectWithDefaultOmitHeaderNameKeys, + }, + }; + + const altSerializers = createSerializers({ omitHeaderNames: ['omit-me'] }); + const result = altSerializers.req(request); + + expect(result).toStrictEqual(expectedRequest); }); }); @@ -124,12 +168,15 @@ describe('res', () => { }); describe('serializers', () => { - test('it exports only err, errWithCause, req, res', () => { - expect(serializers).toStrictEqual({ - err: expect.any(Function), - errWithCause: expect.any(Function), - req: expect.any(Function), - res: expect.any(Function), - }); + test('it exports the expected properties', () => { + expect(serializers).toMatchInlineSnapshot(` + { + "err": [Function], + "errWithCause": [Function], + "headers": [Function], + "req": [Function], + "res": [Function], + } + `); }); }); diff --git a/src/serializers/index.ts b/src/serializers/index.ts index 9188f28..d836ca2 100644 --- a/src/serializers/index.ts +++ b/src/serializers/index.ts @@ -1,5 +1,36 @@ +import type pino from 'pino'; import { err, errWithCause } from 'pino-std-serializers'; +import { createOmitPropertiesSerializer } from './omitPropertiesSerializer'; +import type { SerializerFn } from './types'; + +export const DEFAULT_OMIT_HEADER_NAMES = [ + 'x-envoy-attempt-count', + 'x-envoy-decorator-operation', + 'x-envoy-expected-rq-timeout-ms', + 'x-envoy-external-address', + 'x-envoy-internal', + 'x-envoy-peer-metadata', + 'x-envoy-peer-metadata-id', + 'x-envoy-upstream-service-time', +]; + +export interface SerializerOptions { + /** + * The request headers to omit from serialized logs. + * + * The properties listed will be removed under `headers` and `req.headers`. + * Matching is currently case sensitive. + * You will typically express the header names in lowercase, + * as server frameworks normalise incoming headers. + * + * You can use this option to reduce logging costs. + * Defaults to `DEFAULT_OMIT_HEADER_NAMES`, + * and can be disabled by supplying an empty array `[]`. + */ + omitHeaderNames?: string[]; +} + interface Socket { remoteAddress?: string; remotePort?: string; @@ -8,7 +39,7 @@ interface Request extends Record { method: string; url: string; headers: Record; - socket: Socket; + socket?: Socket; } interface Response extends Record { @@ -26,16 +57,17 @@ const isObject = (value: unknown): boolean => { return value != null && (type === 'object' || type === 'function'); }; -const req = (request: Request) => - isObject(request) - ? { - method: request.method, - url: request.url, - headers: request.headers, - remoteAddress: request?.socket?.remoteAddress, - remotePort: request?.socket?.remotePort, - } - : request; +const createReqSerializer = + (serializeHeaders: SerializerFn) => (request: Request) => + isObject(request) + ? { + method: request.method, + url: request.url, + headers: serializeHeaders(request.headers), + remoteAddress: request?.socket?.remoteAddress, + remotePort: request?.socket?.remotePort, + } + : request; const res = (response: Response) => isObject(response) @@ -45,9 +77,18 @@ const res = (response: Response) => } : response; -export default { - err, - errWithCause, - res, - req, +export const createSerializers = (opts: SerializerOptions) => { + const serializeHeaders = createOmitPropertiesSerializer( + opts.omitHeaderNames ?? DEFAULT_OMIT_HEADER_NAMES, + ); + + const serializers = { + err, + errWithCause, + req: createReqSerializer(serializeHeaders), + res, + headers: serializeHeaders, + } satisfies pino.LoggerOptions['serializers']; + + return serializers; }; diff --git a/src/serializers/omitProperties.test.ts b/src/serializers/omitProperties.test.ts new file mode 100644 index 0000000..c17cb99 --- /dev/null +++ b/src/serializers/omitProperties.test.ts @@ -0,0 +1,47 @@ +import { omitProperties } from './omitProperties'; + +const omitPropertyNames = ['omit-prop', 'omit.prop', '', '0']; + +const createInput = (): Readonly> => + Object.freeze({ + keepProp: 'Some value', + ['omit-prop']: 'omit with dash', + ['omit.prop']: 'omit with dot', + ['']: 'omit with empty key', + ['0']: 'omit number as text key', + omit: { prop: 'DO NOT omit' }, + }); + +it('omits list of keys from object', () => { + const input = createInput(); + + const result = omitProperties(input, omitPropertyNames); + + expect(result).toStrictEqual({ + keepProp: 'Some value', + omit: { prop: 'DO NOT omit' }, + }); +}); + +it('does not alter input object', () => { + const input = createInput(); + + const originalInput = structuredClone(input); + + omitProperties(input, omitPropertyNames); + + expect(input).toEqual(originalInput); +}); + +it.each` + scenario | input + ${'undefined'} | ${undefined} + ${'null'} | ${null} + ${'an empty object'} | ${{}} + ${'not an object'} | ${'key1=value1,key2=value2'} + ${'an array'} | ${[{ key1: 'value1' }, { key2: 'value2' }]} +`('returns input when it is $scenario', ({ input }) => { + const result = omitProperties(input, omitPropertyNames); + + expect(result).toStrictEqual(input); +}); diff --git a/src/serializers/omitProperties.ts b/src/serializers/omitProperties.ts new file mode 100644 index 0000000..96f607b --- /dev/null +++ b/src/serializers/omitProperties.ts @@ -0,0 +1,20 @@ +export const omitProperties = ( + input: unknown, + properties: string[], +): unknown => { + if (!input || typeof input !== 'object' || Array.isArray(input)) { + return input; + } + + // We can get away with a shallow clone as we only touch top-level properties. + const output: Record = { + ...input, + }; + + for (const property of properties) { + // Remove the property from our shallow clone. + delete output[property]; + } + + return output; +}; diff --git a/src/serializers/omitPropertiesSerializer.test.ts b/src/serializers/omitPropertiesSerializer.test.ts new file mode 100644 index 0000000..4f26287 --- /dev/null +++ b/src/serializers/omitPropertiesSerializer.test.ts @@ -0,0 +1,113 @@ +import type { Transform } from 'stream'; + +import split from 'split2'; + +import createLogger from '..'; + +import { createOmitPropertiesSerializer } from './omitPropertiesSerializer'; + +const omitPropertyNamesBase = ['remove-prop', 'remove.prop']; + +it.each` + scenario | omitPropertyNames + ${'undefined'} | ${undefined} + ${'null'} | ${null} + ${'empty'} | ${[]} + ${'list without strings'} | ${[undefined, null, 1, true, false, {}, []]} +`( + 'returns empty object when omitPropertyNames is $scenario', + ({ omitPropertyNames }) => { + const serializer = createOmitPropertiesSerializer(omitPropertyNames); + + expect(serializer({})).toStrictEqual({}); + }, +); + +it('returns object with named property containing function', () => { + const serializer = createOmitPropertiesSerializer(omitPropertyNamesBase); + + expect(serializer).toStrictEqual(expect.any(Function)); +}); + +const sink = () => + split((data) => { + try { + return JSON.parse(data); + } catch (err) { + console.log(err); // eslint-disable-line + console.log(data); // eslint-disable-line + } + }); + +function once(emitter: Transform, name: string) { + return new Promise((resolve, reject) => { + if (name !== 'error') { + emitter.once('error', reject); + } + emitter.once(name, (arg: unknown) => { + emitter.removeListener('error', reject); + resolve(arg); + }); + }); +} + +it('omits properties from logged object', async () => { + const serializer = createOmitPropertiesSerializer(omitPropertyNamesBase); + + const input = { + main: { + keepProp: 'Some value', + ['remove-prop']: 'remove with dash', + ['remove.prop']: 'remove with dot', + remove: { prop: 'DO NOT REMOVE' }, + }, + }; + + const inputString = JSON.stringify(input); + const stream = sink(); + const logger = createLogger( + { name: 'my-app', serializers: { ...serializer } }, + stream, + ); + logger.info(input); + + const log: any = await once(stream, 'data'); + expect(log).toMatchObject({ + main: { + keepProp: 'Some value', + remove: { prop: 'DO NOT REMOVE' }, + }, + }); + expect(inputString).toEqual(JSON.stringify(input)); + expect(log).toHaveProperty('timestamp'); +}); + +it.each` + scenario | value | expected + ${'undefined'} | ${undefined} | ${{}} + ${'null'} | ${null} | ${{ main: null }} + ${'not an object'} | ${123} | ${{ main: 123 }} + ${'an array'} | ${[{ value: 123 }]} | ${{ main: [{ value: 123 }] }} +`( + 'does nothing when top-level property is $scenario', + async ({ value, expected }) => { + const serializer = createOmitPropertiesSerializer(['keepProp']); + + const input = { + main: value, + }; + + const inputString = JSON.stringify(input); + const stream = sink(); + const logger = createLogger( + { name: 'my-app', serializers: { ...serializer } }, + stream, + ); + logger.info(input); + + const log: any = await once(stream, 'data'); + expect(log).toMatchObject(expected); + expect(inputString).toEqual(JSON.stringify(input)); + expect(log).toHaveProperty('timestamp'); + }, +); diff --git a/src/serializers/omitPropertiesSerializer.ts b/src/serializers/omitPropertiesSerializer.ts new file mode 100644 index 0000000..5c4c7e2 --- /dev/null +++ b/src/serializers/omitPropertiesSerializer.ts @@ -0,0 +1,19 @@ +import { omitProperties } from './omitProperties'; +import type { SerializerFn } from './types'; + +export const createOmitPropertiesSerializer = ( + /** + * A list of properties that should not be logged. + */ + properties: string[], +): SerializerFn => { + const uniquePropertySet = new Set(properties); + + if (uniquePropertySet.size === 0) { + return (input) => input; + } + + const uniqueProperties = Array.from(uniquePropertySet); + + return (input) => omitProperties(input, uniqueProperties); +}; diff --git a/src/serializers/types.ts b/src/serializers/types.ts new file mode 100644 index 0000000..356cb88 --- /dev/null +++ b/src/serializers/types.ts @@ -0,0 +1 @@ +export type SerializerFn = (input: unknown) => unknown;