From 752bdf1a5778979099884cebefa357cbdaf7e559 Mon Sep 17 00:00:00 2001 From: Luke Elmers Date: Tue, 16 Feb 2021 07:48:25 -0700 Subject: [PATCH 01/24] Add RewriteAppender with a 'meta' rewrite policy. --- packages/kbn-logging/src/appenders.ts | 1 + .../logging/appenders/legacy_appender.ts | 7 ++ .../server/logging/appenders/appenders.ts | 5 + .../appenders/buffer/buffer_appender.ts | 7 ++ .../appenders/console/console_appender.ts | 7 ++ .../logging/appenders/file/file_appender.ts | 7 ++ .../appenders/rewrite/policies/index.ts | 45 ++++++++ .../appenders/rewrite/policies/meta/index.ts | 13 +++ .../rewrite/policies/meta/meta_policy.ts | 103 ++++++++++++++++++ .../appenders/rewrite/policies/policy.ts | 19 ++++ .../appenders/rewrite/rewrite_appender.ts | 92 ++++++++++++++++ .../rolling_file/rolling_file_appender.ts | 7 ++ src/core/server/logging/logger.test.ts | 5 +- src/core/server/logging/logging_system.ts | 7 ++ 14 files changed, 324 insertions(+), 1 deletion(-) create mode 100644 src/core/server/logging/appenders/rewrite/policies/index.ts create mode 100644 src/core/server/logging/appenders/rewrite/policies/meta/index.ts create mode 100644 src/core/server/logging/appenders/rewrite/policies/meta/meta_policy.ts create mode 100644 src/core/server/logging/appenders/rewrite/policies/policy.ts create mode 100644 src/core/server/logging/appenders/rewrite/rewrite_appender.ts diff --git a/packages/kbn-logging/src/appenders.ts b/packages/kbn-logging/src/appenders.ts index 1b128c0f292018..5b0bc4fb95fcc8 100644 --- a/packages/kbn-logging/src/appenders.ts +++ b/packages/kbn-logging/src/appenders.ts @@ -15,6 +15,7 @@ import { LogRecord } from './log_record'; */ export interface Appender { append(record: LogRecord): void; + update(config: { appenders?: Map }): void; } /** diff --git a/src/core/server/legacy/logging/appenders/legacy_appender.ts b/src/core/server/legacy/logging/appenders/legacy_appender.ts index a89441a5671b55..6da4b845be61c3 100644 --- a/src/core/server/legacy/logging/appenders/legacy_appender.ts +++ b/src/core/server/legacy/logging/appenders/legacy_appender.ts @@ -47,6 +47,13 @@ export class LegacyAppender implements DisposableAppender { this.loggingServer.log(record); } + /** + * Updates `LegacyAppender` configuration. + */ + public update() { + // noop + } + public dispose() { this.loggingServer.stop(); } diff --git a/src/core/server/logging/appenders/appenders.ts b/src/core/server/logging/appenders/appenders.ts index a41a6a2f68fa1b..88df355bd5ebef 100644 --- a/src/core/server/logging/appenders/appenders.ts +++ b/src/core/server/logging/appenders/appenders.ts @@ -17,6 +17,7 @@ import { import { Layouts } from '../layouts/layouts'; import { ConsoleAppender, ConsoleAppenderConfig } from './console/console_appender'; import { FileAppender, FileAppenderConfig } from './file/file_appender'; +import { RewriteAppender, RewriteAppenderConfig } from './rewrite/rewrite_appender'; import { RollingFileAppender, RollingFileAppenderConfig, @@ -32,6 +33,7 @@ export const appendersSchema = schema.oneOf([ ConsoleAppender.configSchema, FileAppender.configSchema, LegacyAppender.configSchema, + RewriteAppender.configSchema, RollingFileAppender.configSchema, ]); @@ -40,6 +42,7 @@ export type AppenderConfigType = | ConsoleAppenderConfig | FileAppenderConfig | LegacyAppenderConfig + | RewriteAppenderConfig | RollingFileAppenderConfig; /** @internal */ @@ -57,6 +60,8 @@ export class Appenders { return new ConsoleAppender(Layouts.create(config.layout)); case 'file': return new FileAppender(Layouts.create(config.layout), config.fileName); + case 'rewrite': + return new RewriteAppender(config); case 'rolling-file': return new RollingFileAppender(config); case 'legacy-appender': diff --git a/src/core/server/logging/appenders/buffer/buffer_appender.ts b/src/core/server/logging/appenders/buffer/buffer_appender.ts index bfd9537becfe8d..9239a437040092 100644 --- a/src/core/server/logging/appenders/buffer/buffer_appender.ts +++ b/src/core/server/logging/appenders/buffer/buffer_appender.ts @@ -27,6 +27,13 @@ export class BufferAppender implements DisposableAppender { this.buffer.push(record); } + /** + * Updates `BufferAppender` configuration. + */ + public update() { + // noop + } + /** * Clears buffer and returns all records that it had. */ diff --git a/src/core/server/logging/appenders/console/console_appender.ts b/src/core/server/logging/appenders/console/console_appender.ts index 739068ff0a126c..5f1b57827a32f5 100644 --- a/src/core/server/logging/appenders/console/console_appender.ts +++ b/src/core/server/logging/appenders/console/console_appender.ts @@ -43,6 +43,13 @@ export class ConsoleAppender implements DisposableAppender { console.log(this.layout.format(record)); } + /** + * Updates `ConsoleAppender` configuration. + */ + public update() { + // noop + } + /** * Disposes `ConsoleAppender`. */ diff --git a/src/core/server/logging/appenders/file/file_appender.ts b/src/core/server/logging/appenders/file/file_appender.ts index be46c261dc9965..7f96220c5274d3 100644 --- a/src/core/server/logging/appenders/file/file_appender.ts +++ b/src/core/server/logging/appenders/file/file_appender.ts @@ -56,6 +56,13 @@ export class FileAppender implements DisposableAppender { this.outputStream.write(`${this.layout.format(record)}\n`); } + /** + * Updates `FileAppender` configuration. + */ + public update() { + // noop + } + /** * Disposes `FileAppender`. Waits for the underlying file stream to be completely flushed and closed. */ diff --git a/src/core/server/logging/appenders/rewrite/policies/index.ts b/src/core/server/logging/appenders/rewrite/policies/index.ts new file mode 100644 index 00000000000000..5d0c4ccaaa8ecf --- /dev/null +++ b/src/core/server/logging/appenders/rewrite/policies/index.ts @@ -0,0 +1,45 @@ +/* + * Copyright Elasticsearch B.V. and/or licensed to Elasticsearch B.V. under one + * or more contributor license agreements. Licensed under the Elastic License + * 2.0 and the Server Side Public License, v 1; you may not use this file except + * in compliance with, at your election, the Elastic License 2.0 or the Server + * Side Public License, v 1. + */ + +import { schema } from '@kbn/config-schema'; +import { assertNever } from '@kbn/std'; +import { RewritePolicy } from './policy'; +import { MetaRewritePolicy, MetaRewritePolicyConfig, metaRewritePolicyConfigSchema } from './meta'; + +export { RewritePolicy }; + +/** + * Available rewrite policies which specify what part of a {@link LogRecord} + * can be modified. + */ +export type RewritePolicyConfig = MetaRewritePolicyConfig; + +const REDACTED_HEADER_TEXT = '[REDACTED]'; + +const defaultPolicy: MetaRewritePolicyConfig = { + type: 'meta', + mode: 'update', + properties: [ + { path: 'http.request.headers.authorization', value: REDACTED_HEADER_TEXT }, + { path: 'http.request.headers.cookie', value: REDACTED_HEADER_TEXT }, + { path: 'http.response.headers.set-cookie', value: REDACTED_HEADER_TEXT }, + ], +}; + +export const rewritePolicyConfigSchema = schema.oneOf([metaRewritePolicyConfigSchema], { + defaultValue: defaultPolicy, +}); + +export const createRewritePolicy = (config: RewritePolicyConfig): RewritePolicy => { + switch (config.type) { + case 'meta': + return new MetaRewritePolicy(config); + default: + return assertNever(config.type); + } +}; diff --git a/src/core/server/logging/appenders/rewrite/policies/meta/index.ts b/src/core/server/logging/appenders/rewrite/policies/meta/index.ts new file mode 100644 index 00000000000000..afdfd6fb709d3e --- /dev/null +++ b/src/core/server/logging/appenders/rewrite/policies/meta/index.ts @@ -0,0 +1,13 @@ +/* + * Copyright Elasticsearch B.V. and/or licensed to Elasticsearch B.V. under one + * or more contributor license agreements. Licensed under the Elastic License + * 2.0 and the Server Side Public License, v 1; you may not use this file except + * in compliance with, at your election, the Elastic License 2.0 or the Server + * Side Public License, v 1. + */ + +export { + MetaRewritePolicy, + MetaRewritePolicyConfig, + metaRewritePolicyConfigSchema, +} from './meta_policy'; diff --git a/src/core/server/logging/appenders/rewrite/policies/meta/meta_policy.ts b/src/core/server/logging/appenders/rewrite/policies/meta/meta_policy.ts new file mode 100644 index 00000000000000..abdbcb54b73197 --- /dev/null +++ b/src/core/server/logging/appenders/rewrite/policies/meta/meta_policy.ts @@ -0,0 +1,103 @@ +/* + * Copyright Elasticsearch B.V. and/or licensed to Elasticsearch B.V. under one + * or more contributor license agreements. Licensed under the Elastic License + * 2.0 and the Server Side Public License, v 1; you may not use this file except + * in compliance with, at your election, the Elastic License 2.0 or the Server + * Side Public License, v 1. + */ + +import { schema } from '@kbn/config-schema'; +import { LogRecord } from '@kbn/logging'; +import { set } from '@elastic/safer-lodash-set'; +import { has, unset } from 'lodash'; +import { assertNever } from '@kbn/std'; +import { RewritePolicy } from '../policy'; + +const META_PATH = 'meta'; + +export interface MetaRewritePolicyConfig { + type: 'meta'; + + /** + * The 'mode' specifies what action to perform on the + * specified properties. + * + * @remarks + * - 'add' creates a new property at the provided 'path', skipping properties which already exist. + * - 'update' updates an existing property at the provided 'path' without creating new properties. + * - 'remove' removes an existing property at the provided 'path'. + */ + mode: 'add' | 'remove' | 'update'; + + /** + * The properties to add, remove, or update. + * + * @remarks + * Each provided 'path' is relative to the record's {@link LogMeta}. + * For the 'remove' mode, no 'value' is provided. + */ + properties: Array<{ path: string; value?: string | number | boolean | null }>; +} + +export const metaRewritePolicyConfigSchema = schema.object({ + type: schema.literal('meta'), + mode: schema.oneOf([schema.literal('add'), schema.literal('update'), schema.literal('remove')], { + defaultValue: 'update', + }), + properties: schema.arrayOf( + schema.object({ + path: schema.string(), + value: schema.maybe( + schema.nullable(schema.oneOf([schema.string(), schema.number(), schema.boolean()])) + ), + }) + ), +}); + +/** + * A rewrite policy which can add, remove, or update properties + * from a record's {@link LogMeta}. + */ +export class MetaRewritePolicy implements RewritePolicy { + constructor(private readonly config: MetaRewritePolicyConfig) {} + + transform(record: LogRecord): LogRecord { + switch (this.config.mode) { + case 'add': + return this.add(record); + case 'update': + return this.update(record); + case 'remove': + return this.remove(record); + default: + return assertNever(this.config.mode); + } + } + + private add(record: LogRecord) { + for (const { path, value } of this.config.properties) { + if (has(record, `${META_PATH}.${path}`)) { + continue; // don't overwrite properties which already exist + } + set(record, `${META_PATH}.${path}`, value); + } + return record; + } + + private update(record: LogRecord) { + for (const { path, value } of this.config.properties) { + if (!has(record, `${META_PATH}.${path}`)) { + continue; // don't add properties which don't already exist + } + set(record, `${META_PATH}.${path}`, value); + } + return record; + } + + private remove(record: LogRecord) { + for (const { path } of this.config.properties) { + unset(record, `${META_PATH}.${path}`); + } + return record; + } +} diff --git a/src/core/server/logging/appenders/rewrite/policies/policy.ts b/src/core/server/logging/appenders/rewrite/policies/policy.ts new file mode 100644 index 00000000000000..aa2a5ea0774a90 --- /dev/null +++ b/src/core/server/logging/appenders/rewrite/policies/policy.ts @@ -0,0 +1,19 @@ +/* + * Copyright Elasticsearch B.V. and/or licensed to Elasticsearch B.V. under one + * or more contributor license agreements. Licensed under the Elastic License + * 2.0 and the Server Side Public License, v 1; you may not use this file except + * in compliance with, at your election, the Elastic License 2.0 or the Server + * Side Public License, v 1. + */ + +import { LogRecord } from '@kbn/logging'; + +/** + * A policy used to determine how to transform the provided {@link LogRecord}. + */ +export interface RewritePolicy { + /** + * Transforms a {@link LogRecord} based on the policy's configuration. + **/ + transform(record: LogRecord): LogRecord; +} diff --git a/src/core/server/logging/appenders/rewrite/rewrite_appender.ts b/src/core/server/logging/appenders/rewrite/rewrite_appender.ts new file mode 100644 index 00000000000000..f3c44ce267705b --- /dev/null +++ b/src/core/server/logging/appenders/rewrite/rewrite_appender.ts @@ -0,0 +1,92 @@ +/* + * Copyright Elasticsearch B.V. and/or licensed to Elasticsearch B.V. under one + * or more contributor license agreements. Licensed under the Elastic License + * 2.0 and the Server Side Public License, v 1; you may not use this file except + * in compliance with, at your election, the Elastic License 2.0 or the Server + * Side Public License, v 1. + */ + +import { schema } from '@kbn/config-schema'; +import { LogRecord, Appender, DisposableAppender } from '@kbn/logging'; +import { + createRewritePolicy, + rewritePolicyConfigSchema, + RewritePolicy, + RewritePolicyConfig, +} from './policies'; + +export interface RewriteAppenderConfig { + type: 'rewrite'; + /** + * The {@link Appender | appender(s) } to pass the log event to after + * implementing the specified rewrite policy. + */ + appenders: string[]; + /** + * The {@link RewritePolicy | policy} to use to manipulate the provided data. + */ + policy: RewritePolicyConfig; +} + +/** + * Appender that can modify the `LogRecord` instances it receives before passing + * them along to another {@link Appender}. + * @internal + */ +export class RewriteAppender implements DisposableAppender { + public static configSchema = schema.object({ + type: schema.literal('rewrite'), + appenders: schema.arrayOf(schema.string(), { defaultValue: [] }), + policy: rewritePolicyConfigSchema, + }); + + private appenders: Map = new Map(); + private readonly policy: RewritePolicy; + + constructor(private readonly config: RewriteAppenderConfig) { + this.policy = createRewritePolicy(config.policy); + } + + /** + * Modifies the `record` and passes it to the specified appender. + * @param record `LogRecord` instance to be logged. + */ + public append(record: LogRecord) { + const transformedRecord = this.policy.transform(record); + this.config.appenders.forEach((appenderName) => { + const appender = this.appenders.get(appenderName); + if (!appender) { + throw new Error( + `Rewrite Appender could not find appender key "${appenderName}". ` + + 'Be sure `appender.update()` is called before `appender.append()`.' + ); + } + appender.append(transformedRecord); + }); + } + + /** + * Updates `RewriteAppender` configuration. + */ + public update({ appenders }: { appenders: Map }) { + this.appenders = appenders; + + // Ensure config only contains valid appenders. + const unknownAppenderKey = this.config.appenders.find( + (appenderKey) => !this.appenders.has(appenderKey) + ); + + if (unknownAppenderKey) { + throw new Error( + `Rewrite Appender config contains unknown appender key "${unknownAppenderKey}".` + ); + } + } + + /** + * Disposes `RewriteAppender`. + */ + public dispose() { + // noop + } +} diff --git a/src/core/server/logging/appenders/rolling_file/rolling_file_appender.ts b/src/core/server/logging/appenders/rolling_file/rolling_file_appender.ts index 452d9493359544..faaa0080083754 100644 --- a/src/core/server/logging/appenders/rolling_file/rolling_file_appender.ts +++ b/src/core/server/logging/appenders/rolling_file/rolling_file_appender.ts @@ -103,6 +103,13 @@ export class RollingFileAppender implements DisposableAppender { this.fileManager.write(`${this.layout.format(record)}\n`); } + /** + * Updates `RollingFileAppender` configuration. + */ + public update() { + // noop + } + /** * Disposes the appender. * If a rollout is currently in progress, it will be awaited. diff --git a/src/core/server/logging/logger.test.ts b/src/core/server/logging/logger.test.ts index b7f224e73cb8b9..86dc46434ea9cb 100644 --- a/src/core/server/logging/logger.test.ts +++ b/src/core/server/logging/logger.test.ts @@ -21,7 +21,10 @@ const timestamp = new Date(2012, 1, 1); beforeEach(() => { jest.spyOn(global, 'Date').mockImplementation(() => timestamp); - appenderMocks = [{ append: jest.fn() }, { append: jest.fn() }]; + appenderMocks = [ + { append: jest.fn(), update: jest.fn() }, + { append: jest.fn(), update: jest.fn() }, + ]; logger = new BaseLogger(context, LogLevel.All, appenderMocks, factory); }); diff --git a/src/core/server/logging/logging_system.ts b/src/core/server/logging/logging_system.ts index 9ae434aff41d3c..f6e607be930e48 100644 --- a/src/core/server/logging/logging_system.ts +++ b/src/core/server/logging/logging_system.ts @@ -167,6 +167,13 @@ export class LoggingSystem implements LoggerFactory { this.appenders.set(appenderKey, Appenders.create(appenderConfig)); } + // Once all appenders have been created, update them with a reference to + // the other configured appenders. This enables appenders to act as a sort + // of middleware and call `append` on each other if needed. + for (const [, appenderConfig] of this.appenders) { + appenderConfig.update({ appenders: this.appenders }); + } + for (const [loggerKey, loggerAdapter] of this.loggers) { loggerAdapter.updateLogger(this.createLogger(loggerKey, computedConfig)); } From 71e46ce4a208b05b41d1c69e2fde261f543cc776 Mon Sep 17 00:00:00 2001 From: Luke Elmers Date: Tue, 16 Feb 2021 14:38:57 -0700 Subject: [PATCH 02/24] Add unit tests. --- .../server/logging/appenders/rewrite/mocks.ts | 20 ++ .../rewrite/policies/meta/meta_policy.test.ts | 228 ++++++++++++++++++ .../rewrite/rewrite_appender.test.mocks.ts | 19 ++ .../rewrite/rewrite_appender.test.ts | 159 ++++++++++++ 4 files changed, 426 insertions(+) create mode 100644 src/core/server/logging/appenders/rewrite/mocks.ts create mode 100644 src/core/server/logging/appenders/rewrite/policies/meta/meta_policy.test.ts create mode 100644 src/core/server/logging/appenders/rewrite/rewrite_appender.test.mocks.ts create mode 100644 src/core/server/logging/appenders/rewrite/rewrite_appender.test.ts diff --git a/src/core/server/logging/appenders/rewrite/mocks.ts b/src/core/server/logging/appenders/rewrite/mocks.ts new file mode 100644 index 00000000000000..ae1d9a58ed0e2a --- /dev/null +++ b/src/core/server/logging/appenders/rewrite/mocks.ts @@ -0,0 +1,20 @@ +/* + * Copyright Elasticsearch B.V. and/or licensed to Elasticsearch B.V. under one + * or more contributor license agreements. Licensed under the Elastic License + * 2.0 and the Server Side Public License, v 1; you may not use this file except + * in compliance with, at your election, the Elastic License 2.0 or the Server + * Side Public License, v 1. + */ + +import type { RewritePolicy } from './policies/policy'; + +const createPolicyMock = () => { + const mock: jest.Mocked = { + transform: jest.fn((x) => x), + }; + return mock; +}; + +export const rewriteAppenderMocks = { + createPolicy: createPolicyMock, +}; diff --git a/src/core/server/logging/appenders/rewrite/policies/meta/meta_policy.test.ts b/src/core/server/logging/appenders/rewrite/policies/meta/meta_policy.test.ts new file mode 100644 index 00000000000000..dff79f47a4da9c --- /dev/null +++ b/src/core/server/logging/appenders/rewrite/policies/meta/meta_policy.test.ts @@ -0,0 +1,228 @@ +/* + * Copyright Elasticsearch B.V. and/or licensed to Elasticsearch B.V. under one + * or more contributor license agreements. Licensed under the Elastic License + * 2.0 and the Server Side Public License, v 1; you may not use this file except + * in compliance with, at your election, the Elastic License 2.0 or the Server + * Side Public License, v 1. + */ + +import { LogRecord, LogLevel, LogMeta } from '@kbn/logging'; +import { MetaRewritePolicy, MetaRewritePolicyConfig } from './meta_policy'; + +describe('MetaRewritePolicy', () => { + const createPolicy = ( + mode: MetaRewritePolicyConfig['mode'], + properties: MetaRewritePolicyConfig['properties'] + ) => new MetaRewritePolicy({ type: 'meta', mode, properties }); + + const createLogRecord = (meta: LogMeta = {}): LogRecord => ({ + timestamp: new Date(), + level: LogLevel.Info, + context: 'context', + message: 'just a log', + pid: 42, + meta, + }); + + describe('mode: add', () => { + it('adds new properties to LogMeta', () => { + const policy = createPolicy('add', [{ path: 'foo', value: 'bar' }]); + const log = createLogRecord(); + expect(policy.transform(log).meta).toMatchInlineSnapshot(` + Object { + "foo": "bar", + } + `); + }); + + it('adds nested properties to LogMeta', () => { + const policy = createPolicy('add', [ + { path: 'a.b', value: 'foo' }, + { path: 'a.c[1]', value: 'bar' }, + ]); + const log = createLogRecord(); + expect(policy.transform(log).meta).toMatchInlineSnapshot(` + Object { + "a": Object { + "b": "foo", + "c": Array [ + undefined, + "bar", + ], + }, + } + `); + }); + + it('handles string, number, boolean, null', () => { + const policy = createPolicy('add', [ + { path: 'boolean', value: false }, + { path: 'null', value: null }, + { path: 'number', value: 123 }, + { path: 'string', value: 'hi' }, + ]); + const log = createLogRecord(); + expect(policy.transform(log).meta).toMatchInlineSnapshot(` + Object { + "boolean": false, + "null": null, + "number": 123, + "string": "hi", + } + `); + }); + + it('does not overwrite properties which already exist', () => { + const policy = createPolicy('add', [ + { path: 'a.b', value: 'foo' }, + { path: 'a.c', value: 'bar' }, + ]); + const log = createLogRecord({ a: { b: 'existing meta' } }); + const { meta } = policy.transform(log); + expect(meta!.a.b).toBe('existing meta'); + expect(meta!.a.c).toBe('bar'); + }); + + it('does not touch anything outside of LogMeta', () => { + const policy = createPolicy('add', [{ path: 'foo', value: 'bar' }]); + const message = Symbol(); + expect(policy.transform(({ message } as unknown) as LogRecord).message).toBe(message); + expect(policy.transform(({ message } as unknown) as LogRecord)).toMatchInlineSnapshot(` + Object { + "message": Symbol(), + "meta": Object { + "foo": "bar", + }, + } + `); + }); + }); + + describe('mode: update', () => { + it('updates existing properties in LogMeta', () => { + const log = createLogRecord({ a: 'before' }); + const policy = createPolicy('update', [{ path: 'a', value: 'after' }]); + expect(policy.transform(log).meta!.a).toBe('after'); + }); + + it('updates nested properties in LogMeta', () => { + const log = createLogRecord({ a: 'before a', b: { c: 'before b.c' }, d: [0, 1] }); + const policy = createPolicy('update', [ + { path: 'a', value: 'after a' }, + { path: 'b.c', value: 'after b.c' }, + { path: 'd[1]', value: 2 }, + ]); + expect(policy.transform(log).meta).toMatchInlineSnapshot(` + Object { + "a": "after a", + "b": Object { + "c": "after b.c", + }, + "d": Array [ + 0, + 2, + ], + } + `); + }); + + it('handles string, number, boolean, null', () => { + const policy = createPolicy('update', [ + { path: 'a', value: false }, + { path: 'b', value: null }, + { path: 'c', value: 123 }, + { path: 'd', value: 'hi' }, + ]); + const log = createLogRecord({ + a: 'a', + b: 'b', + c: 'c', + d: 'd', + }); + expect(policy.transform(log).meta).toMatchInlineSnapshot(` + Object { + "a": false, + "b": null, + "c": 123, + "d": "hi", + } + `); + }); + + it(`does not add properties which don't exist yet`, () => { + const policy = createPolicy('update', [ + { path: 'a.b', value: 'foo' }, + { path: 'a.c', value: 'bar' }, + ]); + const log = createLogRecord({ a: { b: 'existing meta' } }); + const { meta } = policy.transform(log); + expect(meta!.a.b).toBe('foo'); + expect(meta!.a.c).toBeUndefined(); + }); + + it('does not touch anything outside of LogMeta', () => { + const policy = createPolicy('update', [{ path: 'a', value: 'bar' }]); + const message = Symbol(); + expect( + policy.transform(({ message, meta: { a: 'foo' } } as unknown) as LogRecord).message + ).toBe(message); + expect(policy.transform(({ message, meta: { a: 'foo' } } as unknown) as LogRecord)) + .toMatchInlineSnapshot(` + Object { + "message": Symbol(), + "meta": Object { + "a": "bar", + }, + } + `); + }); + }); + + describe('mode: remove', () => { + it('removes existing properties in LogMeta', () => { + const log = createLogRecord({ a: 'goodbye' }); + const policy = createPolicy('remove', [{ path: 'a' }]); + expect(policy.transform(log).meta!.a).toBeUndefined(); + }); + + it('removes nested properties in LogMeta', () => { + const log = createLogRecord({ a: 'a', b: { c: 'b.c' }, d: [0, 1] }); + const policy = createPolicy('remove', [{ path: 'b.c' }, { path: 'd[1]' }]); + expect(policy.transform(log).meta).toMatchInlineSnapshot(` + Object { + "a": "a", + "b": Object {}, + "d": Array [ + 0, + undefined, + ], + } + `); + }); + + it('has no effect if property does not exist', () => { + const log = createLogRecord({ a: 'a' }); + const policy = createPolicy('remove', [{ path: 'b' }]); + expect(policy.transform(log).meta).toMatchInlineSnapshot(` + Object { + "a": "a", + } + `); + }); + + it('does not touch anything outside of LogMeta', () => { + const policy = createPolicy('remove', [{ path: 'a' }]); + const message = Symbol(); + expect( + policy.transform(({ message, meta: { a: 'foo' } } as unknown) as LogRecord).message + ).toBe(message); + expect(policy.transform(({ message, meta: { a: 'foo' } } as unknown) as LogRecord)) + .toMatchInlineSnapshot(` + Object { + "message": Symbol(), + "meta": Object {}, + } + `); + }); + }); +}); diff --git a/src/core/server/logging/appenders/rewrite/rewrite_appender.test.mocks.ts b/src/core/server/logging/appenders/rewrite/rewrite_appender.test.mocks.ts new file mode 100644 index 00000000000000..9d29a683057922 --- /dev/null +++ b/src/core/server/logging/appenders/rewrite/rewrite_appender.test.mocks.ts @@ -0,0 +1,19 @@ +/* + * Copyright Elasticsearch B.V. and/or licensed to Elasticsearch B.V. under one + * or more contributor license agreements. Licensed under the Elastic License + * 2.0 and the Server Side Public License, v 1; you may not use this file except + * in compliance with, at your election, the Elastic License 2.0 or the Server + * Side Public License, v 1. + */ + +import { schema } from '@kbn/config-schema'; + +export const createRewritePolicyMock = jest.fn(); +jest.doMock('./policies', () => ({ + rewritePolicyConfigSchema: schema.any(), + createRewritePolicy: createRewritePolicyMock, +})); + +export const resetAllMocks = () => { + createRewritePolicyMock.mockReset(); +}; diff --git a/src/core/server/logging/appenders/rewrite/rewrite_appender.test.ts b/src/core/server/logging/appenders/rewrite/rewrite_appender.test.ts new file mode 100644 index 00000000000000..d3df269931b4d2 --- /dev/null +++ b/src/core/server/logging/appenders/rewrite/rewrite_appender.test.ts @@ -0,0 +1,159 @@ +/* + * Copyright Elasticsearch B.V. and/or licensed to Elasticsearch B.V. under one + * or more contributor license agreements. Licensed under the Elastic License + * 2.0 and the Server Side Public License, v 1; you may not use this file except + * in compliance with, at your election, the Elastic License 2.0 or the Server + * Side Public License, v 1. + */ + +import type { MockedKeys } from '@kbn/utility-types/jest'; +import { createRewritePolicyMock, resetAllMocks } from './rewrite_appender.test.mocks'; +import { rewriteAppenderMocks } from './mocks'; +import { LogLevel, LogRecord, LogMeta, DisposableAppender } from '@kbn/logging'; +import { RewriteAppender, RewriteAppenderConfig } from './rewrite_appender'; + +// Helper to ensure tuple is typed [A, B] instead of Array +const toTuple = (a: A, b: B): [A, B] => [a, b]; + +const createAppenderMock = (name: string) => { + const appenderMock: MockedKeys = { + append: jest.fn(), + update: jest.fn(), + dispose: jest.fn(), + }; + + return toTuple(name, appenderMock); +}; + +const createConfig = (appenderNames: string[]): RewriteAppenderConfig => ({ + type: 'rewrite', + appenders: appenderNames, + policy: { + type: 'meta', + mode: 'update', + properties: [{ path: 'foo', value: 'bar' }], + }, +}); + +const createLogRecord = (meta: LogMeta = {}): LogRecord => ({ + timestamp: new Date(), + level: LogLevel.Info, + context: 'context', + message: 'just a log', + pid: 42, + meta, +}); + +describe('RewriteAppender', () => { + let policy: ReturnType; + + beforeEach(() => { + policy = rewriteAppenderMocks.createPolicy(); + createRewritePolicyMock.mockReturnValue(policy); + }); + + afterEach(() => { + jest.clearAllMocks(); + }); + + afterAll(() => { + resetAllMocks(); + }); + + it('creates a rewrite policy with the provided config', () => { + const config = createConfig([]); + new RewriteAppender(config); + expect(createRewritePolicyMock).toHaveBeenCalledTimes(1); + expect(createRewritePolicyMock).toHaveBeenCalledWith(config.policy); + }); + + describe('#update', () => { + it('updates the map of available appenders', () => { + const config = createConfig(['mock1']); + const appender = new RewriteAppender(config); + appender.update({ + appenders: new Map([createAppenderMock('mock1')]), + }); + expect(() => { + appender.append(createLogRecord()); + }).not.toThrowError(); + }); + + it('throws if an appender is configured with an unknown key', () => { + const config = createConfig(['mock1', 'missing_appender']); + const appender = new RewriteAppender(config); + expect(() => { + appender.update({ + appenders: new Map([createAppenderMock('mock1')]), + }); + }).toThrowErrorMatchingInlineSnapshot( + `"Rewrite Appender config contains unknown appender key \\"missing_appender\\"."` + ); + }); + }); + + describe('#append', () => { + it('calls the configured appenders with the provided LogRecord', () => { + const config = createConfig(['mock1', 'mock2']); + const appenderMocks = new Map([createAppenderMock('mock1'), createAppenderMock('mock2')]); + + const appender = new RewriteAppender(config); + appender.update({ appenders: appenderMocks }); + + const log1 = createLogRecord({ a: 'b' }); + const log2 = createLogRecord({ c: 'd' }); + + appender.append(log1); + + expect(appenderMocks.get('mock1')!.append).toHaveBeenCalledTimes(1); + expect(appenderMocks.get('mock2')!.append).toHaveBeenCalledTimes(1); + expect(appenderMocks.get('mock1')!.append).toHaveBeenCalledWith(log1); + expect(appenderMocks.get('mock2')!.append).toHaveBeenCalledWith(log1); + + appender.append(log2); + + expect(appenderMocks.get('mock1')!.append).toHaveBeenCalledTimes(2); + expect(appenderMocks.get('mock2')!.append).toHaveBeenCalledTimes(2); + expect(appenderMocks.get('mock1')!.append).toHaveBeenCalledWith(log2); + expect(appenderMocks.get('mock2')!.append).toHaveBeenCalledWith(log2); + }); + + it('calls `transform` on the configured policy', () => { + const config = createConfig(['mock1']); + const appenderMocks = new Map([createAppenderMock('mock1')]); + + const appender = new RewriteAppender(config); + appender.update({ appenders: appenderMocks }); + + const log1 = createLogRecord({ a: 'b' }); + const log2 = createLogRecord({ c: 'd' }); + + appender.append(log1); + + expect(policy.transform).toHaveBeenCalledTimes(1); + expect(policy.transform.mock.calls).toEqual([[log1]]); + + appender.append(log2); + + expect(policy.transform).toHaveBeenCalledTimes(2); + expect(policy.transform.mock.calls).toEqual([[log1], [log2]]); + }); + + it('throws if an appender key cannot be found', () => { + const config = createConfig(['mock1']); + const appender = new RewriteAppender(config); + const appenderMocks = new Map([createAppenderMock('mock1')]); + + appender.update({ appenders: appenderMocks }); + + // intentionally corrupt the provided Map + appenderMocks.delete('mock1'); + + expect(() => { + appender.append(createLogRecord()); + }).toThrowErrorMatchingInlineSnapshot( + `"Rewrite Appender could not find appender key \\"mock1\\". Be sure \`appender.update()\` is called before \`appender.append()\`."` + ); + }); + }); +}); From e1c64025dea68131bd3c2e102aecc78b746ce4ad Mon Sep 17 00:00:00 2001 From: Luke Elmers Date: Tue, 16 Feb 2021 20:03:27 -0700 Subject: [PATCH 03/24] Filter sensitive headers using rewrite appender. --- .../http/integration_tests/logging.test.ts | 72 ++++++++++++++++++- .../http/logging/get_response_log.test.ts | 48 ------------- .../server/http/logging/get_response_log.ts | 19 +---- .../appenders/rewrite/policies/index.ts | 16 +---- .../server/logging/logging_config.test.ts | 28 +++++++- src/core/server/logging/logging_config.ts | 31 ++++++++ 6 files changed, 129 insertions(+), 85 deletions(-) diff --git a/src/core/server/http/integration_tests/logging.test.ts b/src/core/server/http/integration_tests/logging.test.ts index fcf2cd2ba3372d..c4bfa96ac365ee 100644 --- a/src/core/server/http/integration_tests/logging.test.ts +++ b/src/core/server/http/integration_tests/logging.test.ts @@ -251,7 +251,42 @@ describe('request logging', () => { expect(JSON.parse(meta).http.response.headers.bar).toBe('world'); }); - it('filters sensitive request headers', async () => { + it('filters sensitive request headers when RewriteAppender is configured', async () => { + root = kbnTestServer.createRoot({ + logging: { + silent: true, + appenders: { + 'test-console': { + type: 'console', + layout: { + type: 'pattern', + pattern: '%level|%logger|%message|%meta', + }, + }, + rewrite: { + type: 'rewrite', + appenders: ['test-console'], + policy: { + type: 'meta', + mode: 'update', + properties: [ + { path: 'http.request.headers.authorization', value: '[REDACTED]' }, + ], + }, + }, + }, + loggers: [ + { + name: 'http.server.response', + appenders: ['rewrite'], + level: 'debug', + }, + ], + }, + plugins: { + initialize: false, + }, + }); const { http } = await root.setup(); http.createRouter('/').post( @@ -283,7 +318,40 @@ describe('request logging', () => { expect(JSON.parse(meta).http.request.headers.authorization).toBe('[REDACTED]'); }); - it('filters sensitive response headers', async () => { + it('filters sensitive response headers when RewriteAppender is configured', async () => { + root = kbnTestServer.createRoot({ + logging: { + silent: true, + appenders: { + 'test-console': { + type: 'console', + layout: { + type: 'pattern', + pattern: '%level|%logger|%message|%meta', + }, + }, + rewrite: { + type: 'rewrite', + appenders: ['test-console'], + policy: { + type: 'meta', + mode: 'update', + properties: [{ path: 'http.response.headers.set-cookie', value: '[REDACTED]' }], + }, + }, + }, + loggers: [ + { + name: 'http.server.response', + appenders: ['rewrite'], + level: 'debug', + }, + ], + }, + plugins: { + initialize: false, + }, + }); const { http } = await root.setup(); http.createRouter('/').post( diff --git a/src/core/server/http/logging/get_response_log.test.ts b/src/core/server/http/logging/get_response_log.test.ts index 46c4f1d95e3be0..a876aea91ed4e4 100644 --- a/src/core/server/http/logging/get_response_log.test.ts +++ b/src/core/server/http/logging/get_response_log.test.ts @@ -148,54 +148,6 @@ describe('getEcsResponseLog', () => { expect(result.http.response.status_code).toBe(400); }); - describe('filters sensitive headers', () => { - test('redacts Authorization and Cookie headers by default', () => { - const req = createMockHapiRequest({ - headers: { authorization: 'a', cookie: 'b', 'user-agent': 'hi' }, - response: { headers: { 'content-length': 123, 'set-cookie': 'c' } }, - }); - const result = getEcsResponseLog(req, logger); - expect(result.http.request.headers).toMatchInlineSnapshot(` - Object { - "authorization": "[REDACTED]", - "cookie": "[REDACTED]", - "user-agent": "hi", - } - `); - expect(result.http.response.headers).toMatchInlineSnapshot(` - Object { - "content-length": 123, - "set-cookie": "[REDACTED]", - } - `); - }); - - test('does not mutate original headers', () => { - const reqHeaders = { authorization: 'a', cookie: 'b', 'user-agent': 'hi' }; - const resHeaders = { headers: { 'content-length': 123, 'set-cookie': 'c' } }; - const req = createMockHapiRequest({ - headers: reqHeaders, - response: { headers: resHeaders }, - }); - getEcsResponseLog(req, logger); - expect(reqHeaders).toMatchInlineSnapshot(` - Object { - "authorization": "a", - "cookie": "b", - "user-agent": "hi", - } - `); - expect(resHeaders).toMatchInlineSnapshot(` - Object { - "headers": Object { - "content-length": 123, - "set-cookie": "c", - }, - } - `); - }); - }); - describe('ecs', () => { test('specifies correct ECS version', () => { const req = createMockHapiRequest(); diff --git a/src/core/server/http/logging/get_response_log.ts b/src/core/server/http/logging/get_response_log.ts index f75acde93bf405..27f6a63fcf1004 100644 --- a/src/core/server/http/logging/get_response_log.ts +++ b/src/core/server/http/logging/get_response_log.ts @@ -15,21 +15,6 @@ import { EcsEvent, Logger } from '../../logging'; import { getResponsePayloadBytes } from './get_payload_size'; const ECS_VERSION = '1.7.0'; -const FORBIDDEN_HEADERS = ['authorization', 'cookie', 'set-cookie']; -const REDACTED_HEADER_TEXT = '[REDACTED]'; - -// We are excluding sensitive headers by default, until we have a log filtering mechanism. -function redactSensitiveHeaders( - headers?: Record -): Record { - const result = {} as Record; - if (headers) { - for (const key of Object.keys(headers)) { - result[key] = FORBIDDEN_HEADERS.includes(key) ? REDACTED_HEADER_TEXT : headers[key]; - } - } - return result; -} /** * Converts a hapi `Request` into ECS-compliant `LogMeta` for logging. @@ -66,7 +51,7 @@ export function getEcsResponseLog(request: Request, log: Logger): LogMeta { mime_type: request.mime, referrer: request.info.referrer, // @ts-expect-error Headers are not yet part of ECS: https://github.com/elastic/ecs/issues/232. - headers: redactSensitiveHeaders(request.headers), + headers: request.headers, }, response: { body: { @@ -74,7 +59,7 @@ export function getEcsResponseLog(request: Request, log: Logger): LogMeta { }, status_code, // @ts-expect-error Headers are not yet part of ECS: https://github.com/elastic/ecs/issues/232. - headers: redactSensitiveHeaders(responseHeaders), + headers: responseHeaders, // responseTime is a custom non-ECS field responseTime: !isNaN(responseTime) ? responseTime : undefined, }, diff --git a/src/core/server/logging/appenders/rewrite/policies/index.ts b/src/core/server/logging/appenders/rewrite/policies/index.ts index 5d0c4ccaaa8ecf..ec95a88579ae2b 100644 --- a/src/core/server/logging/appenders/rewrite/policies/index.ts +++ b/src/core/server/logging/appenders/rewrite/policies/index.ts @@ -19,21 +19,7 @@ export { RewritePolicy }; */ export type RewritePolicyConfig = MetaRewritePolicyConfig; -const REDACTED_HEADER_TEXT = '[REDACTED]'; - -const defaultPolicy: MetaRewritePolicyConfig = { - type: 'meta', - mode: 'update', - properties: [ - { path: 'http.request.headers.authorization', value: REDACTED_HEADER_TEXT }, - { path: 'http.request.headers.cookie', value: REDACTED_HEADER_TEXT }, - { path: 'http.response.headers.set-cookie', value: REDACTED_HEADER_TEXT }, - ], -}; - -export const rewritePolicyConfigSchema = schema.oneOf([metaRewritePolicyConfigSchema], { - defaultValue: defaultPolicy, -}); +export const rewritePolicyConfigSchema = schema.oneOf([metaRewritePolicyConfigSchema]); export const createRewritePolicy = (config: RewritePolicyConfig): RewritePolicy => { switch (config.type) { diff --git a/src/core/server/logging/logging_config.test.ts b/src/core/server/logging/logging_config.test.ts index 2cb5831a8fb4ce..bd3c307648ffdf 100644 --- a/src/core/server/logging/logging_config.test.ts +++ b/src/core/server/logging/logging_config.test.ts @@ -48,13 +48,35 @@ test('`getLoggerContext()` returns correct joined context name.', () => { test('correctly fills in default config.', () => { const configValue = new LoggingConfig(config.schema.validate({})); - expect(configValue.appenders.size).toBe(2); + expect(configValue.appenders.size).toBe(3); expect(configValue.appenders.get('default')).toEqual({ type: 'console', layout: { type: 'pattern', highlight: true }, }); expect(configValue.appenders.get('console')).toEqual({ + type: 'rewrite', + appenders: ['stdout'], + policy: { + type: 'meta', + mode: 'update', + properties: [ + { + path: 'http.request.headers.authorization', + value: '[REDACTED]', + }, + { + path: 'http.request.headers.cookie', + value: '[REDACTED]', + }, + { + path: 'http.response.headers.set-cookie', + value: '[REDACTED]', + }, + ], + }, + }); + expect(configValue.appenders.get('stdout')).toEqual({ type: 'console', layout: { type: 'pattern', highlight: true }, }); @@ -72,13 +94,12 @@ test('correctly fills in custom `appenders` config.', () => { }) ); - expect(configValue.appenders.size).toBe(2); + expect(configValue.appenders.size).toBe(3); expect(configValue.appenders.get('default')).toEqual({ type: 'console', layout: { type: 'pattern', highlight: true }, }); - expect(configValue.appenders.get('console')).toEqual({ type: 'console', layout: { type: 'pattern' }, @@ -190,6 +211,7 @@ describe('extend', () => { expect([...mergedConfigValue.appenders.keys()]).toEqual([ 'default', 'console', + 'stdout', 'file1', 'file2', ]); diff --git a/src/core/server/logging/logging_config.ts b/src/core/server/logging/logging_config.ts index 24496289fb4c84..fc891cbf5462ca 100644 --- a/src/core/server/logging/logging_config.ts +++ b/src/core/server/logging/logging_config.ts @@ -28,6 +28,20 @@ const ROOT_CONTEXT_NAME = 'root'; */ const DEFAULT_APPENDER_NAME = 'default'; +/** + * Sensitive `LogMeta` paths that we want to censor by default. + */ +const SENSITIVE_META_PATHS = [ + 'http.request.headers.authorization', + 'http.request.headers.cookie', + 'http.response.headers.set-cookie', +]; + +/** + * Replacement text to use when censoring SENSITIVE_META_PATHS. + */ +const REDACTED_META_TEXT = '[REDACTED]'; + const levelSchema = schema.oneOf( [ schema.literal('all'), @@ -153,7 +167,24 @@ export class LoggingConfig { } as AppenderConfigType, ], [ + // By default, we transparently rewrite `LogMeta` sent to the + // console appender to remove potentially sensitive keys. + // This can be overridden in a logger's configuration. 'console', + { + type: 'rewrite', + appenders: ['stdout'], + policy: { + type: 'meta', + mode: 'update', + properties: SENSITIVE_META_PATHS.map((path) => ({ path, value: REDACTED_META_TEXT })), + }, + } as AppenderConfigType, + ], + [ + // This is our actual console appender which the rewrite appender + // sends its records to. + 'stdout', { type: 'console', layout: { type: 'pattern', highlight: true }, From ae5facc750098f477a76d3240ed84a3af65d1662 Mon Sep 17 00:00:00 2001 From: Luke Elmers Date: Tue, 16 Feb 2021 20:55:55 -0700 Subject: [PATCH 04/24] Update generated docs. --- .../kibana-plugin-core-server.appenderconfigtype.md | 2 +- ...plugin-core-server.savedobjectsfindresult.sort.md | 2 +- ....savedobjectsrepository.openpointintimefortype.md | 12 ++++-------- src/core/server/server.api.md | 3 ++- 4 files changed, 8 insertions(+), 11 deletions(-) diff --git a/docs/development/core/server/kibana-plugin-core-server.appenderconfigtype.md b/docs/development/core/server/kibana-plugin-core-server.appenderconfigtype.md index a50df950628b3a..f6de959589eca7 100644 --- a/docs/development/core/server/kibana-plugin-core-server.appenderconfigtype.md +++ b/docs/development/core/server/kibana-plugin-core-server.appenderconfigtype.md @@ -8,5 +8,5 @@ Signature: ```typescript -export declare type AppenderConfigType = ConsoleAppenderConfig | FileAppenderConfig | LegacyAppenderConfig | RollingFileAppenderConfig; +export declare type AppenderConfigType = ConsoleAppenderConfig | FileAppenderConfig | LegacyAppenderConfig | RewriteAppenderConfig | RollingFileAppenderConfig; ``` diff --git a/docs/development/core/server/kibana-plugin-core-server.savedobjectsfindresult.sort.md b/docs/development/core/server/kibana-plugin-core-server.savedobjectsfindresult.sort.md index 3cc02c404c8d71..17f52687243321 100644 --- a/docs/development/core/server/kibana-plugin-core-server.savedobjectsfindresult.sort.md +++ b/docs/development/core/server/kibana-plugin-core-server.savedobjectsfindresult.sort.md @@ -25,7 +25,7 @@ const page1 = await savedObjectsClient.find({ type: 'visualization', sortField: 'updated_at', sortOrder: 'asc', - pit, + pit: { id }, }); const lastHit = page1.saved_objects[page1.saved_objects.length - 1]; const page2 = await savedObjectsClient.find({ diff --git a/docs/development/core/server/kibana-plugin-core-server.savedobjectsrepository.openpointintimefortype.md b/docs/development/core/server/kibana-plugin-core-server.savedobjectsrepository.openpointintimefortype.md index 63956ebee68f7b..6b668824845202 100644 --- a/docs/development/core/server/kibana-plugin-core-server.savedobjectsrepository.openpointintimefortype.md +++ b/docs/development/core/server/kibana-plugin-core-server.savedobjectsrepository.openpointintimefortype.md @@ -29,19 +29,16 @@ openPointInTimeForType(type: string | string[], { keepAlive, preference }?: Save ```ts -const repository = coreStart.savedObjects.createInternalRepository(); - -const { id } = await repository.openPointInTimeForType( - type: 'index-pattern', - { keepAlive: '2m' }, +const { id } = await savedObjectsClient.openPointInTimeForType( + type: 'visualization', + { keepAlive: '5m' }, ); const page1 = await savedObjectsClient.find({ type: 'visualization', sortField: 'updated_at', sortOrder: 'asc', - pit, + pit: { id, keepAlive: '2m' }, }); - const lastHit = page1.saved_objects[page1.saved_objects.length - 1]; const page2 = await savedObjectsClient.find({ type: 'visualization', @@ -50,7 +47,6 @@ const page2 = await savedObjectsClient.find({ pit: { id: page1.pit_id }, searchAfter: lastHit.sort, }); - await savedObjectsClient.closePointInTime(page2.pit_id); ``` diff --git a/src/core/server/server.api.md b/src/core/server/server.api.md index 377cd2bc2068a9..e91f5ee9f4ee4c 100644 --- a/src/core/server/server.api.md +++ b/src/core/server/server.api.md @@ -180,10 +180,11 @@ export interface AppCategory { // Warning: (ae-forgotten-export) The symbol "ConsoleAppenderConfig" needs to be exported by the entry point index.d.ts // Warning: (ae-forgotten-export) The symbol "FileAppenderConfig" needs to be exported by the entry point index.d.ts // Warning: (ae-forgotten-export) The symbol "LegacyAppenderConfig" needs to be exported by the entry point index.d.ts +// Warning: (ae-forgotten-export) The symbol "RewriteAppenderConfig" needs to be exported by the entry point index.d.ts // Warning: (ae-forgotten-export) The symbol "RollingFileAppenderConfig" needs to be exported by the entry point index.d.ts // // @public (undocumented) -export type AppenderConfigType = ConsoleAppenderConfig | FileAppenderConfig | LegacyAppenderConfig | RollingFileAppenderConfig; +export type AppenderConfigType = ConsoleAppenderConfig | FileAppenderConfig | LegacyAppenderConfig | RewriteAppenderConfig | RollingFileAppenderConfig; // @public @deprecated (undocumented) export interface AssistanceAPIResponse { From 03a0397eebcd3795b1718452d9cbc6cbd26d6dba Mon Sep 17 00:00:00 2001 From: Luke Elmers Date: Wed, 17 Feb 2021 15:18:56 -0700 Subject: [PATCH 05/24] Rename policy.transform to policy.rewrite for consistency with log4j. --- .../server/logging/appenders/rewrite/mocks.ts | 2 +- .../rewrite/policies/meta/meta_policy.test.ts | 34 +++++++++---------- .../rewrite/policies/meta/meta_policy.ts | 2 +- .../appenders/rewrite/policies/policy.ts | 4 +-- .../rewrite/rewrite_appender.test.ts | 10 +++--- .../appenders/rewrite/rewrite_appender.ts | 4 +-- 6 files changed, 28 insertions(+), 28 deletions(-) diff --git a/src/core/server/logging/appenders/rewrite/mocks.ts b/src/core/server/logging/appenders/rewrite/mocks.ts index ae1d9a58ed0e2a..a19756e25bf8ea 100644 --- a/src/core/server/logging/appenders/rewrite/mocks.ts +++ b/src/core/server/logging/appenders/rewrite/mocks.ts @@ -10,7 +10,7 @@ import type { RewritePolicy } from './policies/policy'; const createPolicyMock = () => { const mock: jest.Mocked = { - transform: jest.fn((x) => x), + rewrite: jest.fn((x) => x), }; return mock; }; diff --git a/src/core/server/logging/appenders/rewrite/policies/meta/meta_policy.test.ts b/src/core/server/logging/appenders/rewrite/policies/meta/meta_policy.test.ts index dff79f47a4da9c..0ca4568d2cb3d8 100644 --- a/src/core/server/logging/appenders/rewrite/policies/meta/meta_policy.test.ts +++ b/src/core/server/logging/appenders/rewrite/policies/meta/meta_policy.test.ts @@ -28,7 +28,7 @@ describe('MetaRewritePolicy', () => { it('adds new properties to LogMeta', () => { const policy = createPolicy('add', [{ path: 'foo', value: 'bar' }]); const log = createLogRecord(); - expect(policy.transform(log).meta).toMatchInlineSnapshot(` + expect(policy.rewrite(log).meta).toMatchInlineSnapshot(` Object { "foo": "bar", } @@ -41,7 +41,7 @@ describe('MetaRewritePolicy', () => { { path: 'a.c[1]', value: 'bar' }, ]); const log = createLogRecord(); - expect(policy.transform(log).meta).toMatchInlineSnapshot(` + expect(policy.rewrite(log).meta).toMatchInlineSnapshot(` Object { "a": Object { "b": "foo", @@ -62,7 +62,7 @@ describe('MetaRewritePolicy', () => { { path: 'string', value: 'hi' }, ]); const log = createLogRecord(); - expect(policy.transform(log).meta).toMatchInlineSnapshot(` + expect(policy.rewrite(log).meta).toMatchInlineSnapshot(` Object { "boolean": false, "null": null, @@ -78,7 +78,7 @@ describe('MetaRewritePolicy', () => { { path: 'a.c', value: 'bar' }, ]); const log = createLogRecord({ a: { b: 'existing meta' } }); - const { meta } = policy.transform(log); + const { meta } = policy.rewrite(log); expect(meta!.a.b).toBe('existing meta'); expect(meta!.a.c).toBe('bar'); }); @@ -86,8 +86,8 @@ describe('MetaRewritePolicy', () => { it('does not touch anything outside of LogMeta', () => { const policy = createPolicy('add', [{ path: 'foo', value: 'bar' }]); const message = Symbol(); - expect(policy.transform(({ message } as unknown) as LogRecord).message).toBe(message); - expect(policy.transform(({ message } as unknown) as LogRecord)).toMatchInlineSnapshot(` + expect(policy.rewrite(({ message } as unknown) as LogRecord).message).toBe(message); + expect(policy.rewrite(({ message } as unknown) as LogRecord)).toMatchInlineSnapshot(` Object { "message": Symbol(), "meta": Object { @@ -102,7 +102,7 @@ describe('MetaRewritePolicy', () => { it('updates existing properties in LogMeta', () => { const log = createLogRecord({ a: 'before' }); const policy = createPolicy('update', [{ path: 'a', value: 'after' }]); - expect(policy.transform(log).meta!.a).toBe('after'); + expect(policy.rewrite(log).meta!.a).toBe('after'); }); it('updates nested properties in LogMeta', () => { @@ -112,7 +112,7 @@ describe('MetaRewritePolicy', () => { { path: 'b.c', value: 'after b.c' }, { path: 'd[1]', value: 2 }, ]); - expect(policy.transform(log).meta).toMatchInlineSnapshot(` + expect(policy.rewrite(log).meta).toMatchInlineSnapshot(` Object { "a": "after a", "b": Object { @@ -139,7 +139,7 @@ describe('MetaRewritePolicy', () => { c: 'c', d: 'd', }); - expect(policy.transform(log).meta).toMatchInlineSnapshot(` + expect(policy.rewrite(log).meta).toMatchInlineSnapshot(` Object { "a": false, "b": null, @@ -155,7 +155,7 @@ describe('MetaRewritePolicy', () => { { path: 'a.c', value: 'bar' }, ]); const log = createLogRecord({ a: { b: 'existing meta' } }); - const { meta } = policy.transform(log); + const { meta } = policy.rewrite(log); expect(meta!.a.b).toBe('foo'); expect(meta!.a.c).toBeUndefined(); }); @@ -164,9 +164,9 @@ describe('MetaRewritePolicy', () => { const policy = createPolicy('update', [{ path: 'a', value: 'bar' }]); const message = Symbol(); expect( - policy.transform(({ message, meta: { a: 'foo' } } as unknown) as LogRecord).message + policy.rewrite(({ message, meta: { a: 'foo' } } as unknown) as LogRecord).message ).toBe(message); - expect(policy.transform(({ message, meta: { a: 'foo' } } as unknown) as LogRecord)) + expect(policy.rewrite(({ message, meta: { a: 'foo' } } as unknown) as LogRecord)) .toMatchInlineSnapshot(` Object { "message": Symbol(), @@ -182,13 +182,13 @@ describe('MetaRewritePolicy', () => { it('removes existing properties in LogMeta', () => { const log = createLogRecord({ a: 'goodbye' }); const policy = createPolicy('remove', [{ path: 'a' }]); - expect(policy.transform(log).meta!.a).toBeUndefined(); + expect(policy.rewrite(log).meta!.a).toBeUndefined(); }); it('removes nested properties in LogMeta', () => { const log = createLogRecord({ a: 'a', b: { c: 'b.c' }, d: [0, 1] }); const policy = createPolicy('remove', [{ path: 'b.c' }, { path: 'd[1]' }]); - expect(policy.transform(log).meta).toMatchInlineSnapshot(` + expect(policy.rewrite(log).meta).toMatchInlineSnapshot(` Object { "a": "a", "b": Object {}, @@ -203,7 +203,7 @@ describe('MetaRewritePolicy', () => { it('has no effect if property does not exist', () => { const log = createLogRecord({ a: 'a' }); const policy = createPolicy('remove', [{ path: 'b' }]); - expect(policy.transform(log).meta).toMatchInlineSnapshot(` + expect(policy.rewrite(log).meta).toMatchInlineSnapshot(` Object { "a": "a", } @@ -214,9 +214,9 @@ describe('MetaRewritePolicy', () => { const policy = createPolicy('remove', [{ path: 'a' }]); const message = Symbol(); expect( - policy.transform(({ message, meta: { a: 'foo' } } as unknown) as LogRecord).message + policy.rewrite(({ message, meta: { a: 'foo' } } as unknown) as LogRecord).message ).toBe(message); - expect(policy.transform(({ message, meta: { a: 'foo' } } as unknown) as LogRecord)) + expect(policy.rewrite(({ message, meta: { a: 'foo' } } as unknown) as LogRecord)) .toMatchInlineSnapshot(` Object { "message": Symbol(), diff --git a/src/core/server/logging/appenders/rewrite/policies/meta/meta_policy.ts b/src/core/server/logging/appenders/rewrite/policies/meta/meta_policy.ts index abdbcb54b73197..5461c8ab2a3606 100644 --- a/src/core/server/logging/appenders/rewrite/policies/meta/meta_policy.ts +++ b/src/core/server/logging/appenders/rewrite/policies/meta/meta_policy.ts @@ -61,7 +61,7 @@ export const metaRewritePolicyConfigSchema = schema.object({ export class MetaRewritePolicy implements RewritePolicy { constructor(private readonly config: MetaRewritePolicyConfig) {} - transform(record: LogRecord): LogRecord { + rewrite(record: LogRecord): LogRecord { switch (this.config.mode) { case 'add': return this.add(record); diff --git a/src/core/server/logging/appenders/rewrite/policies/policy.ts b/src/core/server/logging/appenders/rewrite/policies/policy.ts index aa2a5ea0774a90..5afe7e5939a467 100644 --- a/src/core/server/logging/appenders/rewrite/policies/policy.ts +++ b/src/core/server/logging/appenders/rewrite/policies/policy.ts @@ -9,11 +9,11 @@ import { LogRecord } from '@kbn/logging'; /** - * A policy used to determine how to transform the provided {@link LogRecord}. + * A policy used to determine how to rewrite the provided {@link LogRecord}. */ export interface RewritePolicy { /** * Transforms a {@link LogRecord} based on the policy's configuration. **/ - transform(record: LogRecord): LogRecord; + rewrite(record: LogRecord): LogRecord; } diff --git a/src/core/server/logging/appenders/rewrite/rewrite_appender.test.ts b/src/core/server/logging/appenders/rewrite/rewrite_appender.test.ts index d3df269931b4d2..4bb1f9f76a56d3 100644 --- a/src/core/server/logging/appenders/rewrite/rewrite_appender.test.ts +++ b/src/core/server/logging/appenders/rewrite/rewrite_appender.test.ts @@ -118,7 +118,7 @@ describe('RewriteAppender', () => { expect(appenderMocks.get('mock2')!.append).toHaveBeenCalledWith(log2); }); - it('calls `transform` on the configured policy', () => { + it('calls `rewrite` on the configured policy', () => { const config = createConfig(['mock1']); const appenderMocks = new Map([createAppenderMock('mock1')]); @@ -130,13 +130,13 @@ describe('RewriteAppender', () => { appender.append(log1); - expect(policy.transform).toHaveBeenCalledTimes(1); - expect(policy.transform.mock.calls).toEqual([[log1]]); + expect(policy.rewrite).toHaveBeenCalledTimes(1); + expect(policy.rewrite.mock.calls).toEqual([[log1]]); appender.append(log2); - expect(policy.transform).toHaveBeenCalledTimes(2); - expect(policy.transform.mock.calls).toEqual([[log1], [log2]]); + expect(policy.rewrite).toHaveBeenCalledTimes(2); + expect(policy.rewrite.mock.calls).toEqual([[log1], [log2]]); }); it('throws if an appender key cannot be found', () => { diff --git a/src/core/server/logging/appenders/rewrite/rewrite_appender.ts b/src/core/server/logging/appenders/rewrite/rewrite_appender.ts index f3c44ce267705b..6a5c0857489c2a 100644 --- a/src/core/server/logging/appenders/rewrite/rewrite_appender.ts +++ b/src/core/server/logging/appenders/rewrite/rewrite_appender.ts @@ -52,7 +52,7 @@ export class RewriteAppender implements DisposableAppender { * @param record `LogRecord` instance to be logged. */ public append(record: LogRecord) { - const transformedRecord = this.policy.transform(record); + const rewriteedRecord = this.policy.rewrite(record); this.config.appenders.forEach((appenderName) => { const appender = this.appenders.get(appenderName); if (!appender) { @@ -61,7 +61,7 @@ export class RewriteAppender implements DisposableAppender { 'Be sure `appender.update()` is called before `appender.append()`.' ); } - appender.append(transformedRecord); + appender.append(rewriteedRecord); }); } From 61d445034f89c68d6a99b6060e3d145198dd9946 Mon Sep 17 00:00:00 2001 From: Luke Elmers Date: Thu, 18 Feb 2021 13:10:26 -0700 Subject: [PATCH 06/24] Address initial feedback. --- .../logging/appenders/rewrite/policies/index.ts | 3 +-- .../rewrite/policies/meta/meta_policy.test.ts | 10 +++++----- .../rewrite/policies/meta/meta_policy.ts | 17 ++++++----------- .../appenders/rewrite/rewrite_appender.ts | 4 ++-- src/core/server/logging/logging_config.test.ts | 6 +++--- src/core/server/logging/logging_config.ts | 6 +++--- 6 files changed, 20 insertions(+), 26 deletions(-) diff --git a/src/core/server/logging/appenders/rewrite/policies/index.ts b/src/core/server/logging/appenders/rewrite/policies/index.ts index ec95a88579ae2b..ae3be1e4de916a 100644 --- a/src/core/server/logging/appenders/rewrite/policies/index.ts +++ b/src/core/server/logging/appenders/rewrite/policies/index.ts @@ -6,7 +6,6 @@ * Side Public License, v 1. */ -import { schema } from '@kbn/config-schema'; import { assertNever } from '@kbn/std'; import { RewritePolicy } from './policy'; import { MetaRewritePolicy, MetaRewritePolicyConfig, metaRewritePolicyConfigSchema } from './meta'; @@ -19,7 +18,7 @@ export { RewritePolicy }; */ export type RewritePolicyConfig = MetaRewritePolicyConfig; -export const rewritePolicyConfigSchema = schema.oneOf([metaRewritePolicyConfigSchema]); +export const rewritePolicyConfigSchema = metaRewritePolicyConfigSchema; export const createRewritePolicy = (config: RewritePolicyConfig): RewritePolicy => { switch (config.type) { diff --git a/src/core/server/logging/appenders/rewrite/policies/meta/meta_policy.test.ts b/src/core/server/logging/appenders/rewrite/policies/meta/meta_policy.test.ts index 0ca4568d2cb3d8..be0e15ae95b85a 100644 --- a/src/core/server/logging/appenders/rewrite/policies/meta/meta_policy.test.ts +++ b/src/core/server/logging/appenders/rewrite/policies/meta/meta_policy.test.ts @@ -84,14 +84,14 @@ describe('MetaRewritePolicy', () => { }); it('does not touch anything outside of LogMeta', () => { - const policy = createPolicy('add', [{ path: 'foo', value: 'bar' }]); + const policy = createPolicy('add', [{ path: 'message', value: 'bar' }]); const message = Symbol(); expect(policy.rewrite(({ message } as unknown) as LogRecord).message).toBe(message); expect(policy.rewrite(({ message } as unknown) as LogRecord)).toMatchInlineSnapshot(` Object { "message": Symbol(), "meta": Object { - "foo": "bar", + "message": "bar", }, } `); @@ -211,12 +211,12 @@ describe('MetaRewritePolicy', () => { }); it('does not touch anything outside of LogMeta', () => { - const policy = createPolicy('remove', [{ path: 'a' }]); + const policy = createPolicy('remove', [{ path: 'message' }]); const message = Symbol(); expect( - policy.rewrite(({ message, meta: { a: 'foo' } } as unknown) as LogRecord).message + policy.rewrite(({ message, meta: { message: 'foo' } } as unknown) as LogRecord).message ).toBe(message); - expect(policy.rewrite(({ message, meta: { a: 'foo' } } as unknown) as LogRecord)) + expect(policy.rewrite(({ message, meta: { message: 'foo' } } as unknown) as LogRecord)) .toMatchInlineSnapshot(` Object { "message": Symbol(), diff --git a/src/core/server/logging/appenders/rewrite/policies/meta/meta_policy.ts b/src/core/server/logging/appenders/rewrite/policies/meta/meta_policy.ts index 5461c8ab2a3606..4bcc15dcfffec6 100644 --- a/src/core/server/logging/appenders/rewrite/policies/meta/meta_policy.ts +++ b/src/core/server/logging/appenders/rewrite/policies/meta/meta_policy.ts @@ -13,16 +13,11 @@ import { has, unset } from 'lodash'; import { assertNever } from '@kbn/std'; import { RewritePolicy } from '../policy'; -const META_PATH = 'meta'; - export interface MetaRewritePolicyConfig { type: 'meta'; /** - * The 'mode' specifies what action to perform on the - * specified properties. - * - * @remarks + * The 'mode' specifies what action to perform on the specified properties. * - 'add' creates a new property at the provided 'path', skipping properties which already exist. * - 'update' updates an existing property at the provided 'path' without creating new properties. * - 'remove' removes an existing property at the provided 'path'. @@ -76,27 +71,27 @@ export class MetaRewritePolicy implements RewritePolicy { private add(record: LogRecord) { for (const { path, value } of this.config.properties) { - if (has(record, `${META_PATH}.${path}`)) { + if (has(record, `meta.${path}`)) { continue; // don't overwrite properties which already exist } - set(record, `${META_PATH}.${path}`, value); + set(record, `meta.${path}`, value); } return record; } private update(record: LogRecord) { for (const { path, value } of this.config.properties) { - if (!has(record, `${META_PATH}.${path}`)) { + if (!has(record, `meta.${path}`)) { continue; // don't add properties which don't already exist } - set(record, `${META_PATH}.${path}`, value); + set(record, `meta.${path}`, value); } return record; } private remove(record: LogRecord) { for (const { path } of this.config.properties) { - unset(record, `${META_PATH}.${path}`); + unset(record, `meta.${path}`); } return record; } diff --git a/src/core/server/logging/appenders/rewrite/rewrite_appender.ts b/src/core/server/logging/appenders/rewrite/rewrite_appender.ts index 6a5c0857489c2a..435aacb7d103bd 100644 --- a/src/core/server/logging/appenders/rewrite/rewrite_appender.ts +++ b/src/core/server/logging/appenders/rewrite/rewrite_appender.ts @@ -52,7 +52,7 @@ export class RewriteAppender implements DisposableAppender { * @param record `LogRecord` instance to be logged. */ public append(record: LogRecord) { - const rewriteedRecord = this.policy.rewrite(record); + const rewrittenRecord = this.policy.rewrite(record); this.config.appenders.forEach((appenderName) => { const appender = this.appenders.get(appenderName); if (!appender) { @@ -61,7 +61,7 @@ export class RewriteAppender implements DisposableAppender { 'Be sure `appender.update()` is called before `appender.append()`.' ); } - appender.append(rewriteedRecord); + appender.append(rewrittenRecord); }); } diff --git a/src/core/server/logging/logging_config.test.ts b/src/core/server/logging/logging_config.test.ts index bd3c307648ffdf..13ed9a72839ed2 100644 --- a/src/core/server/logging/logging_config.test.ts +++ b/src/core/server/logging/logging_config.test.ts @@ -56,7 +56,7 @@ test('correctly fills in default config.', () => { }); expect(configValue.appenders.get('console')).toEqual({ type: 'rewrite', - appenders: ['stdout'], + appenders: ['rewrite-console'], policy: { type: 'meta', mode: 'update', @@ -76,7 +76,7 @@ test('correctly fills in default config.', () => { ], }, }); - expect(configValue.appenders.get('stdout')).toEqual({ + expect(configValue.appenders.get('rewrite-console')).toEqual({ type: 'console', layout: { type: 'pattern', highlight: true }, }); @@ -211,7 +211,7 @@ describe('extend', () => { expect([...mergedConfigValue.appenders.keys()]).toEqual([ 'default', 'console', - 'stdout', + 'rewrite-console', 'file1', 'file2', ]); diff --git a/src/core/server/logging/logging_config.ts b/src/core/server/logging/logging_config.ts index fc891cbf5462ca..58159e645a7f1b 100644 --- a/src/core/server/logging/logging_config.ts +++ b/src/core/server/logging/logging_config.ts @@ -35,7 +35,7 @@ const SENSITIVE_META_PATHS = [ 'http.request.headers.authorization', 'http.request.headers.cookie', 'http.response.headers.set-cookie', -]; +] as const; /** * Replacement text to use when censoring SENSITIVE_META_PATHS. @@ -173,7 +173,7 @@ export class LoggingConfig { 'console', { type: 'rewrite', - appenders: ['stdout'], + appenders: ['rewrite-console'], policy: { type: 'meta', mode: 'update', @@ -184,7 +184,7 @@ export class LoggingConfig { [ // This is our actual console appender which the rewrite appender // sends its records to. - 'stdout', + 'rewrite-console', { type: 'console', layout: { type: 'pattern', highlight: true }, From 0dc0afcfb0f40089e4852e3134bf8b0d675dda87 Mon Sep 17 00:00:00 2001 From: Luke Elmers Date: Thu, 18 Feb 2021 15:08:45 -0700 Subject: [PATCH 07/24] Switch from appenders.update to appenders.addAppender to align with log4j. --- packages/kbn-logging/src/appenders.ts | 19 +++++- .../logging/appenders/legacy_appender.ts | 7 --- .../appenders/buffer/buffer_appender.ts | 7 --- .../appenders/console/console_appender.ts | 7 --- .../logging/appenders/file/file_appender.ts | 7 --- .../rewrite/rewrite_appender.test.ts | 62 ++++++------------- .../appenders/rewrite/rewrite_appender.ts | 50 +++++++++------ .../rolling_file/rolling_file_appender.ts | 7 --- src/core/server/logging/logger.test.ts | 5 +- src/core/server/logging/logging_system.ts | 9 ++- 10 files changed, 77 insertions(+), 103 deletions(-) diff --git a/packages/kbn-logging/src/appenders.ts b/packages/kbn-logging/src/appenders.ts index 5b0bc4fb95fcc8..08ca5b7ebfba6e 100644 --- a/packages/kbn-logging/src/appenders.ts +++ b/packages/kbn-logging/src/appenders.ts @@ -15,7 +15,6 @@ import { LogRecord } from './log_record'; */ export interface Appender { append(record: LogRecord): void; - update(config: { appenders?: Map }): void; } /** @@ -26,4 +25,22 @@ export interface Appender { */ export interface DisposableAppender extends Appender { dispose: () => void | Promise; + /** + * Appenders can be "attached" to one another so that they are able to act + * as a sort of middleware by calling `append` on a different appender. + * + * As appenders cannot be attached to each other until they are configured, + * the `addAppender` method can be used to pass in a newly configured appender + * to attach. + */ + addAppender?(appenderRef: string, appender: DisposableAppender): void; + /** + * For appenders which implement `addAppender`, they should declare a list of + * `appenderRefs`, which specify the names of the appenders that their configuration + * depends on. + * + * Note that these are the appender key names that the user specifies in their + * config, _not_ the names of the appender types themselves. + */ + appenderRefs?: string[]; } diff --git a/src/core/server/legacy/logging/appenders/legacy_appender.ts b/src/core/server/legacy/logging/appenders/legacy_appender.ts index 6da4b845be61c3..a89441a5671b55 100644 --- a/src/core/server/legacy/logging/appenders/legacy_appender.ts +++ b/src/core/server/legacy/logging/appenders/legacy_appender.ts @@ -47,13 +47,6 @@ export class LegacyAppender implements DisposableAppender { this.loggingServer.log(record); } - /** - * Updates `LegacyAppender` configuration. - */ - public update() { - // noop - } - public dispose() { this.loggingServer.stop(); } diff --git a/src/core/server/logging/appenders/buffer/buffer_appender.ts b/src/core/server/logging/appenders/buffer/buffer_appender.ts index 9239a437040092..bfd9537becfe8d 100644 --- a/src/core/server/logging/appenders/buffer/buffer_appender.ts +++ b/src/core/server/logging/appenders/buffer/buffer_appender.ts @@ -27,13 +27,6 @@ export class BufferAppender implements DisposableAppender { this.buffer.push(record); } - /** - * Updates `BufferAppender` configuration. - */ - public update() { - // noop - } - /** * Clears buffer and returns all records that it had. */ diff --git a/src/core/server/logging/appenders/console/console_appender.ts b/src/core/server/logging/appenders/console/console_appender.ts index 5f1b57827a32f5..739068ff0a126c 100644 --- a/src/core/server/logging/appenders/console/console_appender.ts +++ b/src/core/server/logging/appenders/console/console_appender.ts @@ -43,13 +43,6 @@ export class ConsoleAppender implements DisposableAppender { console.log(this.layout.format(record)); } - /** - * Updates `ConsoleAppender` configuration. - */ - public update() { - // noop - } - /** * Disposes `ConsoleAppender`. */ diff --git a/src/core/server/logging/appenders/file/file_appender.ts b/src/core/server/logging/appenders/file/file_appender.ts index 7f96220c5274d3..be46c261dc9965 100644 --- a/src/core/server/logging/appenders/file/file_appender.ts +++ b/src/core/server/logging/appenders/file/file_appender.ts @@ -56,13 +56,6 @@ export class FileAppender implements DisposableAppender { this.outputStream.write(`${this.layout.format(record)}\n`); } - /** - * Updates `FileAppender` configuration. - */ - public update() { - // noop - } - /** * Disposes `FileAppender`. Waits for the underlying file stream to be completely flushed and closed. */ diff --git a/src/core/server/logging/appenders/rewrite/rewrite_appender.test.ts b/src/core/server/logging/appenders/rewrite/rewrite_appender.test.ts index 4bb1f9f76a56d3..2913dcdfa01527 100644 --- a/src/core/server/logging/appenders/rewrite/rewrite_appender.test.ts +++ b/src/core/server/logging/appenders/rewrite/rewrite_appender.test.ts @@ -18,7 +18,6 @@ const toTuple = (a: A, b: B): [A, B] => [a, b]; const createAppenderMock = (name: string) => { const appenderMock: MockedKeys = { append: jest.fn(), - update: jest.fn(), dispose: jest.fn(), }; @@ -67,92 +66,71 @@ describe('RewriteAppender', () => { expect(createRewritePolicyMock).toHaveBeenCalledWith(config.policy); }); - describe('#update', () => { + describe('#addAppender', () => { it('updates the map of available appenders', () => { const config = createConfig(['mock1']); const appender = new RewriteAppender(config); - appender.update({ - appenders: new Map([createAppenderMock('mock1')]), - }); + appender.addAppender(...createAppenderMock('mock1')); expect(() => { appender.append(createLogRecord()); }).not.toThrowError(); }); - - it('throws if an appender is configured with an unknown key', () => { - const config = createConfig(['mock1', 'missing_appender']); - const appender = new RewriteAppender(config); - expect(() => { - appender.update({ - appenders: new Map([createAppenderMock('mock1')]), - }); - }).toThrowErrorMatchingInlineSnapshot( - `"Rewrite Appender config contains unknown appender key \\"missing_appender\\"."` - ); - }); }); describe('#append', () => { it('calls the configured appenders with the provided LogRecord', () => { const config = createConfig(['mock1', 'mock2']); - const appenderMocks = new Map([createAppenderMock('mock1'), createAppenderMock('mock2')]); + const appenderMocks = [createAppenderMock('mock1'), createAppenderMock('mock2')]; const appender = new RewriteAppender(config); - appender.update({ appenders: appenderMocks }); + appenderMocks.forEach((mock) => appender.addAppender(...mock)); const log1 = createLogRecord({ a: 'b' }); const log2 = createLogRecord({ c: 'd' }); appender.append(log1); - expect(appenderMocks.get('mock1')!.append).toHaveBeenCalledTimes(1); - expect(appenderMocks.get('mock2')!.append).toHaveBeenCalledTimes(1); - expect(appenderMocks.get('mock1')!.append).toHaveBeenCalledWith(log1); - expect(appenderMocks.get('mock2')!.append).toHaveBeenCalledWith(log1); + expect(appenderMocks[0][1].append).toHaveBeenCalledTimes(1); + expect(appenderMocks[1][1].append).toHaveBeenCalledTimes(1); + expect(appenderMocks[0][1].append).toHaveBeenCalledWith(log1); + expect(appenderMocks[1][1].append).toHaveBeenCalledWith(log1); appender.append(log2); - expect(appenderMocks.get('mock1')!.append).toHaveBeenCalledTimes(2); - expect(appenderMocks.get('mock2')!.append).toHaveBeenCalledTimes(2); - expect(appenderMocks.get('mock1')!.append).toHaveBeenCalledWith(log2); - expect(appenderMocks.get('mock2')!.append).toHaveBeenCalledWith(log2); + expect(appenderMocks[0][1].append).toHaveBeenCalledTimes(2); + expect(appenderMocks[1][1].append).toHaveBeenCalledTimes(2); + expect(appenderMocks[0][1].append).toHaveBeenCalledWith(log2); + expect(appenderMocks[1][1].append).toHaveBeenCalledWith(log2); }); - it('calls `rewrite` on the configured policy', () => { + it('calls `transform` on the configured policy', () => { const config = createConfig(['mock1']); - const appenderMocks = new Map([createAppenderMock('mock1')]); const appender = new RewriteAppender(config); - appender.update({ appenders: appenderMocks }); + appender.addAppender(...createAppenderMock('mock1')); const log1 = createLogRecord({ a: 'b' }); const log2 = createLogRecord({ c: 'd' }); appender.append(log1); - expect(policy.rewrite).toHaveBeenCalledTimes(1); - expect(policy.rewrite.mock.calls).toEqual([[log1]]); + expect(policy.transform).toHaveBeenCalledTimes(1); + expect(policy.transform.mock.calls).toEqual([[log1]]); appender.append(log2); - expect(policy.rewrite).toHaveBeenCalledTimes(2); - expect(policy.rewrite.mock.calls).toEqual([[log1], [log2]]); + expect(policy.transform).toHaveBeenCalledTimes(2); + expect(policy.transform.mock.calls).toEqual([[log1], [log2]]); }); it('throws if an appender key cannot be found', () => { - const config = createConfig(['mock1']); + const config = createConfig(['oops']); const appender = new RewriteAppender(config); - const appenderMocks = new Map([createAppenderMock('mock1')]); - - appender.update({ appenders: appenderMocks }); - - // intentionally corrupt the provided Map - appenderMocks.delete('mock1'); expect(() => { appender.append(createLogRecord()); }).toThrowErrorMatchingInlineSnapshot( - `"Rewrite Appender could not find appender key \\"mock1\\". Be sure \`appender.update()\` is called before \`appender.append()\`."` + `"Rewrite Appender could not find appender key \\"oops\\". Be sure \`appender.addAppender()\` was called before \`appender.append()\`."` ); }); }); diff --git a/src/core/server/logging/appenders/rewrite/rewrite_appender.ts b/src/core/server/logging/appenders/rewrite/rewrite_appender.ts index 435aacb7d103bd..47d12df28c5f5d 100644 --- a/src/core/server/logging/appenders/rewrite/rewrite_appender.ts +++ b/src/core/server/logging/appenders/rewrite/rewrite_appender.ts @@ -47,6 +47,34 @@ export class RewriteAppender implements DisposableAppender { this.policy = createRewritePolicy(config.policy); } + /** + * List of appenders that are dependencies of this appender. + * + * `addAppender` will throw an error when called with an appender + * reference that isn't in this list. + */ + public get appenderRefs() { + return this.config.appenders; + } + + /** + * Appenders can be "attached" to this one so that the RewriteAppender + * is able to act as a sort of middleware by calling `append` other appenders. + * + * As appenders cannot be attached to each other until they are created, + * the `addAppender` method is used to pass in a configured appender. + */ + public addAppender(appenderRef: string, appender: DisposableAppender) { + if (!this.appenderRefs.includes(appenderRef)) { + throw new Error( + `addAppender was called with an appender key that is missing from the appenderRefs: "${appenderRef}".` + ); + } + // TODO: check circular refs + + this.appenders.set(appenderRef, appender); + } + /** * Modifies the `record` and passes it to the specified appender. * @param record `LogRecord` instance to be logged. @@ -58,35 +86,17 @@ export class RewriteAppender implements DisposableAppender { if (!appender) { throw new Error( `Rewrite Appender could not find appender key "${appenderName}". ` + - 'Be sure `appender.update()` is called before `appender.append()`.' + 'Be sure `appender.addAppender()` was called before `appender.append()`.' ); } appender.append(rewrittenRecord); }); } - /** - * Updates `RewriteAppender` configuration. - */ - public update({ appenders }: { appenders: Map }) { - this.appenders = appenders; - - // Ensure config only contains valid appenders. - const unknownAppenderKey = this.config.appenders.find( - (appenderKey) => !this.appenders.has(appenderKey) - ); - - if (unknownAppenderKey) { - throw new Error( - `Rewrite Appender config contains unknown appender key "${unknownAppenderKey}".` - ); - } - } - /** * Disposes `RewriteAppender`. */ public dispose() { - // noop + this.appenders.clear(); } } diff --git a/src/core/server/logging/appenders/rolling_file/rolling_file_appender.ts b/src/core/server/logging/appenders/rolling_file/rolling_file_appender.ts index faaa0080083754..452d9493359544 100644 --- a/src/core/server/logging/appenders/rolling_file/rolling_file_appender.ts +++ b/src/core/server/logging/appenders/rolling_file/rolling_file_appender.ts @@ -103,13 +103,6 @@ export class RollingFileAppender implements DisposableAppender { this.fileManager.write(`${this.layout.format(record)}\n`); } - /** - * Updates `RollingFileAppender` configuration. - */ - public update() { - // noop - } - /** * Disposes the appender. * If a rollout is currently in progress, it will be awaited. diff --git a/src/core/server/logging/logger.test.ts b/src/core/server/logging/logger.test.ts index 86dc46434ea9cb..b7f224e73cb8b9 100644 --- a/src/core/server/logging/logger.test.ts +++ b/src/core/server/logging/logger.test.ts @@ -21,10 +21,7 @@ const timestamp = new Date(2012, 1, 1); beforeEach(() => { jest.spyOn(global, 'Date').mockImplementation(() => timestamp); - appenderMocks = [ - { append: jest.fn(), update: jest.fn() }, - { append: jest.fn(), update: jest.fn() }, - ]; + appenderMocks = [{ append: jest.fn() }, { append: jest.fn() }]; logger = new BaseLogger(context, LogLevel.All, appenderMocks, factory); }); diff --git a/src/core/server/logging/logging_system.ts b/src/core/server/logging/logging_system.ts index f6e607be930e48..99b32f03739276 100644 --- a/src/core/server/logging/logging_system.ts +++ b/src/core/server/logging/logging_system.ts @@ -171,7 +171,14 @@ export class LoggingSystem implements LoggerFactory { // the other configured appenders. This enables appenders to act as a sort // of middleware and call `append` on each other if needed. for (const [, appenderConfig] of this.appenders) { - appenderConfig.update({ appenders: this.appenders }); + if (!appenderConfig.addAppender || !appenderConfig.appenderRefs) continue; + for (const ref of appenderConfig.appenderRefs) { + const foundAppender = this.appenders.get(ref); + if (!foundAppender) { + throw new Error(`Appender config contains unknown appender key "${ref}".`); + } + appenderConfig.addAppender(ref, foundAppender); + } } for (const [loggerKey, loggerAdapter] of this.loggers) { From 44d1440c969a559826447c41df56fb715788c4ea Mon Sep 17 00:00:00 2001 From: Luke Elmers Date: Thu, 18 Feb 2021 15:23:39 -0700 Subject: [PATCH 08/24] Fix missed transform > rewrite rename. --- .../logging/appenders/rewrite/rewrite_appender.test.ts | 10 +++++----- 1 file changed, 5 insertions(+), 5 deletions(-) diff --git a/src/core/server/logging/appenders/rewrite/rewrite_appender.test.ts b/src/core/server/logging/appenders/rewrite/rewrite_appender.test.ts index 2913dcdfa01527..72a54b5012ce54 100644 --- a/src/core/server/logging/appenders/rewrite/rewrite_appender.test.ts +++ b/src/core/server/logging/appenders/rewrite/rewrite_appender.test.ts @@ -103,7 +103,7 @@ describe('RewriteAppender', () => { expect(appenderMocks[1][1].append).toHaveBeenCalledWith(log2); }); - it('calls `transform` on the configured policy', () => { + it('calls `rewrite` on the configured policy', () => { const config = createConfig(['mock1']); const appender = new RewriteAppender(config); @@ -114,13 +114,13 @@ describe('RewriteAppender', () => { appender.append(log1); - expect(policy.transform).toHaveBeenCalledTimes(1); - expect(policy.transform.mock.calls).toEqual([[log1]]); + expect(policy.rewrite).toHaveBeenCalledTimes(1); + expect(policy.rewrite.mock.calls).toEqual([[log1]]); appender.append(log2); - expect(policy.transform).toHaveBeenCalledTimes(2); - expect(policy.transform.mock.calls).toEqual([[log1], [log2]]); + expect(policy.rewrite).toHaveBeenCalledTimes(2); + expect(policy.rewrite.mock.calls).toEqual([[log1], [log2]]); }); it('throws if an appender key cannot be found', () => { From 524cc31cf7772a5c1c98fb2745a2e41a38afc1dd Mon Sep 17 00:00:00 2001 From: Luke Elmers Date: Thu, 18 Feb 2021 15:40:09 -0700 Subject: [PATCH 09/24] Shallow clone http request/response headers. --- src/core/server/http/logging/get_response_log.ts | 9 +++++++-- 1 file changed, 7 insertions(+), 2 deletions(-) diff --git a/src/core/server/http/logging/get_response_log.ts b/src/core/server/http/logging/get_response_log.ts index 27f6a63fcf1004..cb0ae380620dd9 100644 --- a/src/core/server/http/logging/get_response_log.ts +++ b/src/core/server/http/logging/get_response_log.ts @@ -30,7 +30,12 @@ export function getEcsResponseLog(request: Request, log: Logger): LogMeta { // eslint-disable-next-line @typescript-eslint/naming-convention const status_code = isBoom(response) ? response.output.statusCode : response.statusCode; - const responseHeaders = isBoom(response) ? response.output.headers : response.headers; + + // shallow clone the headers so they are not mutated if filtered by a RewriteAppender + const requestHeaders = { ...request.headers }; + const responseHeaders = isBoom(response) + ? { ...response.output.headers } + : { ...response.headers }; // borrowed from the hapi/good implementation const responseTime = (request.info.completed || request.info.responded) - request.info.received; @@ -51,7 +56,7 @@ export function getEcsResponseLog(request: Request, log: Logger): LogMeta { mime_type: request.mime, referrer: request.info.referrer, // @ts-expect-error Headers are not yet part of ECS: https://github.com/elastic/ecs/issues/232. - headers: request.headers, + headers: requestHeaders, }, response: { body: { From c72c75bdbdea850c32de7f454c567f714a55c207 Mon Sep 17 00:00:00 2001 From: Luke Elmers Date: Thu, 18 Feb 2021 21:28:08 -0700 Subject: [PATCH 10/24] Test for circular refs between appenders. --- .../appenders/rewrite/rewrite_appender.ts | 16 +++-- .../server/logging/logging_system.test.ts | 63 +++++++++++++++++++ src/core/server/logging/logging_system.ts | 39 +++++++++--- 3 files changed, 101 insertions(+), 17 deletions(-) diff --git a/src/core/server/logging/appenders/rewrite/rewrite_appender.ts b/src/core/server/logging/appenders/rewrite/rewrite_appender.ts index 47d12df28c5f5d..af3ca3089d3a00 100644 --- a/src/core/server/logging/appenders/rewrite/rewrite_appender.ts +++ b/src/core/server/logging/appenders/rewrite/rewrite_appender.ts @@ -7,7 +7,7 @@ */ import { schema } from '@kbn/config-schema'; -import { LogRecord, Appender, DisposableAppender } from '@kbn/logging'; +import { LogRecord, DisposableAppender } from '@kbn/logging'; import { createRewritePolicy, rewritePolicyConfigSchema, @@ -18,7 +18,7 @@ import { export interface RewriteAppenderConfig { type: 'rewrite'; /** - * The {@link Appender | appender(s) } to pass the log event to after + * The {@link Appender | appender(s)} to pass the log event to after * implementing the specified rewrite policy. */ appenders: string[]; @@ -40,7 +40,7 @@ export class RewriteAppender implements DisposableAppender { policy: rewritePolicyConfigSchema, }); - private appenders: Map = new Map(); + private appenders: Map = new Map(); private readonly policy: RewritePolicy; constructor(private readonly config: RewriteAppenderConfig) { @@ -70,27 +70,25 @@ export class RewriteAppender implements DisposableAppender { `addAppender was called with an appender key that is missing from the appenderRefs: "${appenderRef}".` ); } - // TODO: check circular refs this.appenders.set(appenderRef, appender); } /** * Modifies the `record` and passes it to the specified appender. - * @param record `LogRecord` instance to be logged. */ public append(record: LogRecord) { const rewrittenRecord = this.policy.rewrite(record); - this.config.appenders.forEach((appenderName) => { - const appender = this.appenders.get(appenderName); + for (const appenderRef of this.appenderRefs) { + const appender = this.appenders.get(appenderRef); if (!appender) { throw new Error( - `Rewrite Appender could not find appender key "${appenderName}". ` + + `Rewrite Appender could not find appender key "${appenderRef}". ` + 'Be sure `appender.addAppender()` was called before `appender.append()`.' ); } appender.append(rewrittenRecord); - }); + } } /** diff --git a/src/core/server/logging/logging_system.test.ts b/src/core/server/logging/logging_system.test.ts index f68d6c6a97fbc4..0a3643e20edd83 100644 --- a/src/core/server/logging/logging_system.test.ts +++ b/src/core/server/logging/logging_system.test.ts @@ -134,6 +134,69 @@ test('uses `root` logger if context name is not specified.', async () => { expect(mockConsoleLog.mock.calls).toMatchSnapshot(); }); +test('attaches appenders to appenders that declare refs', async () => { + await system.upgrade( + config.schema.validate({ + appenders: { + console: { type: 'console', layout: { type: 'pattern' } }, + file: { type: 'file', layout: { type: 'pattern' }, fileName: 'path' }, + rewrite: { + type: 'rewrite', + appenders: ['console', 'file'], + policy: { type: 'meta', mode: 'remove', properties: [{ path: 'b' }] }, + }, + }, + loggers: [{ name: 'tests', level: 'warn', appenders: ['rewrite'] }], + }) + ); + + const testLogger = system.get('tests'); + testLogger.warn('This message goes to a test context.', { a: 'hi', b: 'remove me' }); + + expect(mockConsoleLog).toHaveBeenCalledTimes(1); + expect(mockConsoleLog.mock.calls[0][0]).toMatchInlineSnapshot( + `"[2012-01-30T22:33:22.011-05:00][WARN ][tests]{\\"a\\":\\"hi\\"} This message goes to a test context."` + ); + + expect(mockStreamWrite).toHaveBeenCalledTimes(1); + expect(mockStreamWrite.mock.calls[0][0]).toMatchInlineSnapshot(` + "[2012-01-30T17:33:22.011-05:00][WARN ][tests]{\\"a\\":\\"hi\\"} This message goes to a test context. + " + `); +}); + +test('throws if a circular appender reference is detected', async () => { + expect(async () => { + await system.upgrade( + config.schema.validate({ + appenders: { + console: { type: 'console', layout: { type: 'pattern' } }, + a: { + type: 'rewrite', + appenders: ['b'], + policy: { type: 'meta', mode: 'remove', properties: [{ path: 'b' }] }, + }, + b: { + type: 'rewrite', + appenders: ['c'], + policy: { type: 'meta', mode: 'remove', properties: [{ path: 'b' }] }, + }, + c: { + type: 'rewrite', + appenders: ['console', 'a'], + policy: { type: 'meta', mode: 'remove', properties: [{ path: 'b' }] }, + }, + }, + loggers: [{ name: 'tests', level: 'warn', appenders: ['a'] }], + }) + ); + }).rejects.toThrowErrorMatchingInlineSnapshot( + `"Circular appender reference detected: [b -> c -> a -> b]"` + ); + + expect(mockConsoleLog).toHaveBeenCalledTimes(0); +}); + test('`stop()` disposes all appenders.', async () => { await system.upgrade( config.schema.validate({ diff --git a/src/core/server/logging/logging_system.ts b/src/core/server/logging/logging_system.ts index 99b32f03739276..4963fc20f64683 100644 --- a/src/core/server/logging/logging_system.ts +++ b/src/core/server/logging/logging_system.ts @@ -146,6 +146,26 @@ export class LoggingSystem implements LoggerFactory { return this.getLoggerConfigByContext(config, LoggingConfig.getParentLoggerContext(context)); } + /** + * Retrieves an appender by the provided key, after first checking that no circular + * dependencies exist between appender refs. + */ + private getAppenderByRef(appenderRef: string) { + const checkCircularRefs = (key: string, stack: string[]) => { + if (stack.includes(key)) { + throw new Error(`Circular appender reference detected: [${stack.join(' -> ')} -> ${key}]`); + } + stack.push(key); + const appender = this.appenders.get(key); + if (appender?.appenderRefs) { + appender.appenderRefs.forEach((ref) => checkCircularRefs(ref, [...stack])); + } + return appender; + }; + + return checkCircularRefs(appenderRef, []); + } + private async applyBaseConfig(newBaseConfig: LoggingConfig) { const computedConfig = [...this.contextConfigs.values()].reduce( (baseConfig, contextConfig) => baseConfig.extend(contextConfig), @@ -167,17 +187,20 @@ export class LoggingSystem implements LoggerFactory { this.appenders.set(appenderKey, Appenders.create(appenderConfig)); } - // Once all appenders have been created, update them with a reference to - // the other configured appenders. This enables appenders to act as a sort - // of middleware and call `append` on each other if needed. - for (const [, appenderConfig] of this.appenders) { - if (!appenderConfig.addAppender || !appenderConfig.appenderRefs) continue; - for (const ref of appenderConfig.appenderRefs) { - const foundAppender = this.appenders.get(ref); + // Once all appenders have been created, check for any that have explicitly + // declared `appenderRefs` dependencies, and look up those dependencies to + // attach to the appender. This enables appenders to act as a sort of + // middleware and call `append` on each other if needed. + for (const [, appender] of this.appenders) { + if (!appender.addAppender || !appender.appenderRefs) { + continue; + } + for (const ref of appender.appenderRefs) { + const foundAppender = this.getAppenderByRef(ref); if (!foundAppender) { throw new Error(`Appender config contains unknown appender key "${ref}".`); } - appenderConfig.addAppender(ref, foundAppender); + appender.addAppender(ref, foundAppender); } } From 7cbe3473f1cf50197f64658e726c870341088d3e Mon Sep 17 00:00:00 2001 From: Luke Elmers Date: Thu, 18 Feb 2021 22:00:51 -0700 Subject: [PATCH 11/24] Update README with documentation. --- src/core/server/logging/README.md | 119 ++++++++++++++++++++++++++++++ 1 file changed, 119 insertions(+) diff --git a/src/core/server/logging/README.md b/src/core/server/logging/README.md index 385d1fd91a5d75..c1e72d5985111c 100644 --- a/src/core/server/logging/README.md +++ b/src/core/server/logging/README.md @@ -264,6 +264,125 @@ The maximum number of files to keep. Once this number is reached, oldest files w The default value is `7` +### Rewrite Appender + +*This appender is currently considered experimental and is not intended +for public consumption. The API is subject to change at any time.* + +Similar to log4j's `RewriteAppender`, this appender serves as a sort of middleware, +modifying the provided log events before passing them along to another +appender. + +The most common use case for the `RewriteAppender` is when you want to +filter or censor sensitive data that may be contained in a log entry. +In fact, with a default configuration, Kibana will automatically redact +any `authorization`, `cookie`, or `set-cookie` headers when logging http +requests & responses. + +To configure additional rewrite rules, you'll need to specify a `RewritePolicy`. + +#### Rewrite Policies + +Rewrite policies exist to indicate which parts of a log record can be +modified within the rewrite appender. + +**Meta** + +The `meta` rewrite policy can read and modify any data contained in the +`LogMeta` before passing it along to a destination appender. + +```yaml +logging: + appenders: + my-rewrite-appender: + type: rewrite + appenders: [console, file] # name of "destination" appender(s) + policy: + # ... +``` + +Meta policies must specify one of three modes, which indicate which action +to perform on the configured properties: +- `add` creates a new property at the provided `path`, skipping properties which already exist. +- `update` updates an existing property at the provided `path` without creating new properties. +- `remove` removes an existing property at the provided `path`. + +The `properties` are listed as a `path` and `value` pair, where `path` is +the dot-delimited path to the target property in the `LogMeta` object, and +`value` is the value to add or update in that target property. When using +the `remove` mode, a `value` is not necessary. + +```yaml +logging: + appenders: + my-rewrite-appender: + type: rewrite + appenders: [console] + policy: + type: meta # indicates that we want to rewrite the LogMeta + mode: update # will update an existing property only + properties: + - path: "http.request.headers.cookie" # path to property + value: "[REDACTED]" # value to replace at path +``` + +Rewrite appenders can even be passed to other rewrite appenders to apply +multiple filter policies/modes, as long as it doesn't create a circular +reference. +```yaml +logging: + appenders: + remove-stuff: + type: rewrite + appenders: [add-stuff] # redirect to the next rewrite appender + policy: + type: meta + mode: remove + properties: + - path: "http.request.headers.authorization" + - path: "http.request.headers.cookie" + - path: "http.request.headers.set-cookie" + add-stuff: + type: rewrite + appenders: [console] # output to console + policy: + type: meta + mode: add + properties: + - path: "hello" + value: "world" # creates { hello: 'world' } at the LogMeta root +``` + +#### Complete Example +```yaml +logging: + appenders: + console: + type: console + layout: + type: pattern + highlight: true + pattern: "[%date][%level][%logger] %message %meta" + file: + type: file + fileName: ./kibana.log + layout: + type: json + censor: + type: rewrite + appenders: [console, file] + policy: + type: meta + mode: update + properties: + - path: "http.request.headers.cookie" + value: "[REDACTED]" + loggers: + - name: http.server.response + appenders: [censor] # pass these logs to our rewrite appender + level: debug +``` + ## Configuration As any configuration in the platform, logging configuration is validated against the predefined schema and if there are From 8fb040e47086295a96dba3b8f293a46dccec30ec Mon Sep 17 00:00:00 2001 From: Luke Elmers Date: Fri, 19 Feb 2021 09:59:26 -0700 Subject: [PATCH 12/24] Take Appender inside addAppender --- packages/kbn-logging/src/appenders.ts | 22 +++++++++---------- .../appenders/rewrite/rewrite_appender.ts | 6 ++--- 2 files changed, 14 insertions(+), 14 deletions(-) diff --git a/packages/kbn-logging/src/appenders.ts b/packages/kbn-logging/src/appenders.ts index 08ca5b7ebfba6e..48422db34b3365 100644 --- a/packages/kbn-logging/src/appenders.ts +++ b/packages/kbn-logging/src/appenders.ts @@ -15,16 +15,6 @@ import { LogRecord } from './log_record'; */ export interface Appender { append(record: LogRecord): void; -} - -/** - * This interface should be additionally implemented by the `Appender`'s if they are supposed - * to be properly disposed. It's intentionally separated from `Appender` interface so that `Logger` - * that interacts with `Appender` doesn't have control over appender lifetime. - * @internal - */ -export interface DisposableAppender extends Appender { - dispose: () => void | Promise; /** * Appenders can be "attached" to one another so that they are able to act * as a sort of middleware by calling `append` on a different appender. @@ -33,7 +23,7 @@ export interface DisposableAppender extends Appender { * the `addAppender` method can be used to pass in a newly configured appender * to attach. */ - addAppender?(appenderRef: string, appender: DisposableAppender): void; + addAppender?(appenderRef: string, appender: Appender): void; /** * For appenders which implement `addAppender`, they should declare a list of * `appenderRefs`, which specify the names of the appenders that their configuration @@ -44,3 +34,13 @@ export interface DisposableAppender extends Appender { */ appenderRefs?: string[]; } + +/** + * This interface should be additionally implemented by the `Appender`'s if they are supposed + * to be properly disposed. It's intentionally separated from `Appender` interface so that `Logger` + * that interacts with `Appender` doesn't have control over appender lifetime. + * @internal + */ +export interface DisposableAppender extends Appender { + dispose: () => void | Promise; +} diff --git a/src/core/server/logging/appenders/rewrite/rewrite_appender.ts b/src/core/server/logging/appenders/rewrite/rewrite_appender.ts index af3ca3089d3a00..e480858c9677f4 100644 --- a/src/core/server/logging/appenders/rewrite/rewrite_appender.ts +++ b/src/core/server/logging/appenders/rewrite/rewrite_appender.ts @@ -7,7 +7,7 @@ */ import { schema } from '@kbn/config-schema'; -import { LogRecord, DisposableAppender } from '@kbn/logging'; +import { LogRecord, Appender, DisposableAppender } from '@kbn/logging'; import { createRewritePolicy, rewritePolicyConfigSchema, @@ -40,7 +40,7 @@ export class RewriteAppender implements DisposableAppender { policy: rewritePolicyConfigSchema, }); - private appenders: Map = new Map(); + private appenders: Map = new Map(); private readonly policy: RewritePolicy; constructor(private readonly config: RewriteAppenderConfig) { @@ -64,7 +64,7 @@ export class RewriteAppender implements DisposableAppender { * As appenders cannot be attached to each other until they are created, * the `addAppender` method is used to pass in a configured appender. */ - public addAppender(appenderRef: string, appender: DisposableAppender) { + public addAppender(appenderRef: string, appender: Appender) { if (!this.appenderRefs.includes(appenderRef)) { throw new Error( `addAppender was called with an appender key that is missing from the appenderRefs: "${appenderRef}".` From 88397a5ea0d2ddbc06ac3e7e29a6e285ff179b2e Mon Sep 17 00:00:00 2001 From: Luke Elmers Date: Fri, 19 Feb 2021 10:02:25 -0700 Subject: [PATCH 13/24] Clean up policy comments --- .../server/logging/appenders/rewrite/policies/policy.ts | 7 ++----- 1 file changed, 2 insertions(+), 5 deletions(-) diff --git a/src/core/server/logging/appenders/rewrite/policies/policy.ts b/src/core/server/logging/appenders/rewrite/policies/policy.ts index 5afe7e5939a467..f8aef887965fd2 100644 --- a/src/core/server/logging/appenders/rewrite/policies/policy.ts +++ b/src/core/server/logging/appenders/rewrite/policies/policy.ts @@ -9,11 +9,8 @@ import { LogRecord } from '@kbn/logging'; /** - * A policy used to determine how to rewrite the provided {@link LogRecord}. - */ + * Rewrites a {@link LogRecord} based on the policy's configuration. + **/ export interface RewritePolicy { - /** - * Transforms a {@link LogRecord} based on the policy's configuration. - **/ rewrite(record: LogRecord): LogRecord; } From a6632ee06b46a22f2267373b50df0e93f83b12dc Mon Sep 17 00:00:00 2001 From: Luke Elmers Date: Fri, 19 Feb 2021 10:04:05 -0700 Subject: [PATCH 14/24] Update snapshots --- .../logging/__snapshots__/logging_system.test.ts.snap | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/src/core/server/logging/__snapshots__/logging_system.test.ts.snap b/src/core/server/logging/__snapshots__/logging_system.test.ts.snap index 81321a3b1fe44c..e3ecd860fc5a90 100644 --- a/src/core/server/logging/__snapshots__/logging_system.test.ts.snap +++ b/src/core/server/logging/__snapshots__/logging_system.test.ts.snap @@ -14,7 +14,7 @@ exports[`appends records via multiple appenders.: file logs 2`] = ` exports[`asLoggerFactory() only allows to create new loggers. 1`] = ` Object { - "@timestamp": "2012-01-30T22:33:22.011-05:00", + "@timestamp": "2012-01-30T12:33:22.011-05:00", "log": Object { "level": "TRACE", "logger": "test.context", @@ -28,7 +28,7 @@ Object { exports[`asLoggerFactory() only allows to create new loggers. 2`] = ` Object { - "@timestamp": "2012-01-30T17:33:22.011-05:00", + "@timestamp": "2012-01-30T07:33:22.011-05:00", "log": Object { "level": "INFO", "logger": "test.context", @@ -43,7 +43,7 @@ Object { exports[`asLoggerFactory() only allows to create new loggers. 3`] = ` Object { - "@timestamp": "2012-01-30T12:33:22.011-05:00", + "@timestamp": "2012-01-30T02:33:22.011-05:00", "log": Object { "level": "FATAL", "logger": "test.context", From 0516db30f98f568aec2c8c625b219a8dc00bb590 Mon Sep 17 00:00:00 2001 From: Luke Elmers Date: Sun, 21 Feb 2021 14:21:27 -0700 Subject: [PATCH 15/24] Re-add hardcoded headers filtering to http logs. --- .../http/integration_tests/logging.test.ts | 64 +++++++++++++++++++ .../http/logging/get_response_log.test.ts | 48 ++++++++++++++ .../server/http/logging/get_response_log.ts | 19 +++++- src/core/server/logging/logging_config.ts | 5 +- 4 files changed, 133 insertions(+), 3 deletions(-) diff --git a/src/core/server/http/integration_tests/logging.test.ts b/src/core/server/http/integration_tests/logging.test.ts index c4bfa96ac365ee..62cb699bc49f6b 100644 --- a/src/core/server/http/integration_tests/logging.test.ts +++ b/src/core/server/http/integration_tests/logging.test.ts @@ -251,6 +251,38 @@ describe('request logging', () => { expect(JSON.parse(meta).http.response.headers.bar).toBe('world'); }); + it('filters sensitive request headers by default', async () => { + const { http } = await root.setup(); + + http.createRouter('/').post( + { + path: '/ping', + validate: { + body: schema.object({ message: schema.string() }), + }, + options: { + authRequired: 'optional', + body: { + accepts: ['application/json'], + }, + timeout: { payload: 100 }, + }, + }, + (context, req, res) => res.ok({ body: { message: req.body.message } }) + ); + await root.start(); + + await kbnTestServer.request + .post(root, '/ping') + .set('content-type', 'application/json') + .set('authorization', 'abc') + .send({ message: 'hi' }) + .expect(200); + expect(mockConsoleLog).toHaveBeenCalledTimes(1); + const [, , , meta] = mockConsoleLog.mock.calls[0][0].split('|'); + expect(JSON.parse(meta).http.request.headers.authorization).toBe('[REDACTED]'); + }); + it('filters sensitive request headers when RewriteAppender is configured', async () => { root = kbnTestServer.createRoot({ logging: { @@ -318,6 +350,38 @@ describe('request logging', () => { expect(JSON.parse(meta).http.request.headers.authorization).toBe('[REDACTED]'); }); + it('filters sensitive response headers by defaut', async () => { + const { http } = await root.setup(); + + http.createRouter('/').post( + { + path: '/ping', + validate: { + body: schema.object({ message: schema.string() }), + }, + options: { + authRequired: 'optional', + body: { + accepts: ['application/json'], + }, + timeout: { payload: 100 }, + }, + }, + (context, req, res) => + res.ok({ headers: { 'set-cookie': ['123'] }, body: { message: req.body.message } }) + ); + await root.start(); + + await kbnTestServer.request + .post(root, '/ping') + .set('Content-Type', 'application/json') + .send({ message: 'hi' }) + .expect(200); + expect(mockConsoleLog).toHaveBeenCalledTimes(1); + const [, , , meta] = mockConsoleLog.mock.calls[0][0].split('|'); + expect(JSON.parse(meta).http.response.headers['set-cookie']).toBe('[REDACTED]'); + }); + it('filters sensitive response headers when RewriteAppender is configured', async () => { root = kbnTestServer.createRoot({ logging: { diff --git a/src/core/server/http/logging/get_response_log.test.ts b/src/core/server/http/logging/get_response_log.test.ts index a876aea91ed4e4..46c4f1d95e3be0 100644 --- a/src/core/server/http/logging/get_response_log.test.ts +++ b/src/core/server/http/logging/get_response_log.test.ts @@ -148,6 +148,54 @@ describe('getEcsResponseLog', () => { expect(result.http.response.status_code).toBe(400); }); + describe('filters sensitive headers', () => { + test('redacts Authorization and Cookie headers by default', () => { + const req = createMockHapiRequest({ + headers: { authorization: 'a', cookie: 'b', 'user-agent': 'hi' }, + response: { headers: { 'content-length': 123, 'set-cookie': 'c' } }, + }); + const result = getEcsResponseLog(req, logger); + expect(result.http.request.headers).toMatchInlineSnapshot(` + Object { + "authorization": "[REDACTED]", + "cookie": "[REDACTED]", + "user-agent": "hi", + } + `); + expect(result.http.response.headers).toMatchInlineSnapshot(` + Object { + "content-length": 123, + "set-cookie": "[REDACTED]", + } + `); + }); + + test('does not mutate original headers', () => { + const reqHeaders = { authorization: 'a', cookie: 'b', 'user-agent': 'hi' }; + const resHeaders = { headers: { 'content-length': 123, 'set-cookie': 'c' } }; + const req = createMockHapiRequest({ + headers: reqHeaders, + response: { headers: resHeaders }, + }); + getEcsResponseLog(req, logger); + expect(reqHeaders).toMatchInlineSnapshot(` + Object { + "authorization": "a", + "cookie": "b", + "user-agent": "hi", + } + `); + expect(resHeaders).toMatchInlineSnapshot(` + Object { + "headers": Object { + "content-length": 123, + "set-cookie": "c", + }, + } + `); + }); + }); + describe('ecs', () => { test('specifies correct ECS version', () => { const req = createMockHapiRequest(); diff --git a/src/core/server/http/logging/get_response_log.ts b/src/core/server/http/logging/get_response_log.ts index cb0ae380620dd9..ded24337869636 100644 --- a/src/core/server/http/logging/get_response_log.ts +++ b/src/core/server/http/logging/get_response_log.ts @@ -15,6 +15,21 @@ import { EcsEvent, Logger } from '../../logging'; import { getResponsePayloadBytes } from './get_payload_size'; const ECS_VERSION = '1.7.0'; +const FORBIDDEN_HEADERS = ['authorization', 'cookie', 'set-cookie']; +const REDACTED_HEADER_TEXT = '[REDACTED]'; + +// We are excluding sensitive headers by default, until we have a log filtering mechanism. +function redactSensitiveHeaders( + headers?: Record +): Record { + const result = {} as Record; + if (headers) { + for (const key of Object.keys(headers)) { + result[key] = FORBIDDEN_HEADERS.includes(key) ? REDACTED_HEADER_TEXT : headers[key]; + } + } + return result; +} /** * Converts a hapi `Request` into ECS-compliant `LogMeta` for logging. @@ -56,7 +71,7 @@ export function getEcsResponseLog(request: Request, log: Logger): LogMeta { mime_type: request.mime, referrer: request.info.referrer, // @ts-expect-error Headers are not yet part of ECS: https://github.com/elastic/ecs/issues/232. - headers: requestHeaders, + headers: redactSensitiveHeaders(requestHeaders), }, response: { body: { @@ -64,7 +79,7 @@ export function getEcsResponseLog(request: Request, log: Logger): LogMeta { }, status_code, // @ts-expect-error Headers are not yet part of ECS: https://github.com/elastic/ecs/issues/232. - headers: responseHeaders, + headers: redactSensitiveHeaders(responseHeaders), // responseTime is a custom non-ECS field responseTime: !isNaN(responseTime) ? responseTime : undefined, }, diff --git a/src/core/server/logging/logging_config.ts b/src/core/server/logging/logging_config.ts index 58159e645a7f1b..8f40524cdff795 100644 --- a/src/core/server/logging/logging_config.ts +++ b/src/core/server/logging/logging_config.ts @@ -30,6 +30,7 @@ const DEFAULT_APPENDER_NAME = 'default'; /** * Sensitive `LogMeta` paths that we want to censor by default. + * These paths are only filtered in a default logging configuration. */ const SENSITIVE_META_PATHS = [ 'http.request.headers.authorization', @@ -169,7 +170,9 @@ export class LoggingConfig { [ // By default, we transparently rewrite `LogMeta` sent to the // console appender to remove potentially sensitive keys. - // This can be overridden in a logger's configuration. + // This logic is also hardcoded in the http response logger + // itself, but included here as an additional measure for + // other loggers which might be logging the same data. 'console', { type: 'rewrite', From c777305acb55cdd5c4cc5b3cbfdc9e5e32fa6f4f Mon Sep 17 00:00:00 2001 From: Luke Elmers Date: Sun, 21 Feb 2021 14:31:09 -0700 Subject: [PATCH 16/24] Use fixed timestamp in meta policy tests. --- .../logging/appenders/rewrite/policies/meta/meta_policy.test.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/core/server/logging/appenders/rewrite/policies/meta/meta_policy.test.ts b/src/core/server/logging/appenders/rewrite/policies/meta/meta_policy.test.ts index be0e15ae95b85a..8bd5e2aa5bfe81 100644 --- a/src/core/server/logging/appenders/rewrite/policies/meta/meta_policy.test.ts +++ b/src/core/server/logging/appenders/rewrite/policies/meta/meta_policy.test.ts @@ -16,7 +16,7 @@ describe('MetaRewritePolicy', () => { ) => new MetaRewritePolicy({ type: 'meta', mode, properties }); const createLogRecord = (meta: LogMeta = {}): LogRecord => ({ - timestamp: new Date(), + timestamp: new Date(Date.UTC(2012, 1, 1, 14, 30, 22, 11)), level: LogLevel.Info, context: 'context', message: 'just a log', From e0f4c583954c6a382a0417391ce581ec2846630f Mon Sep 17 00:00:00 2001 From: Luke Elmers Date: Sun, 21 Feb 2021 14:33:05 -0700 Subject: [PATCH 17/24] Clean up documentation. --- src/core/server/logging/README.md | 24 ++++++++++--------- .../appenders/rewrite/rewrite_appender.ts | 2 +- 2 files changed, 14 insertions(+), 12 deletions(-) diff --git a/src/core/server/logging/README.md b/src/core/server/logging/README.md index c1e72d5985111c..2c234d25cc2575 100644 --- a/src/core/server/logging/README.md +++ b/src/core/server/logging/README.md @@ -273,6 +273,16 @@ Similar to log4j's `RewriteAppender`, this appender serves as a sort of middlewa modifying the provided log events before passing them along to another appender. +```yaml +logging: + appenders: + my-rewrite-appender: + type: rewrite + appenders: [console, file] # name of "destination" appender(s) + policy: + # ... +``` + The most common use case for the `RewriteAppender` is when you want to filter or censor sensitive data that may be contained in a log entry. In fact, with a default configuration, Kibana will automatically redact @@ -291,16 +301,6 @@ modified within the rewrite appender. The `meta` rewrite policy can read and modify any data contained in the `LogMeta` before passing it along to a destination appender. -```yaml -logging: - appenders: - my-rewrite-appender: - type: rewrite - appenders: [console, file] # name of "destination" appender(s) - policy: - # ... -``` - Meta policies must specify one of three modes, which indicate which action to perform on the configured properties: - `add` creates a new property at the provided `path`, skipping properties which already exist. @@ -312,6 +312,8 @@ the dot-delimited path to the target property in the `LogMeta` object, and `value` is the value to add or update in that target property. When using the `remove` mode, a `value` is not necessary. +Here's an example of how you would replace any `cookie` header values with `[REDACTED]`: + ```yaml logging: appenders: @@ -328,7 +330,7 @@ logging: Rewrite appenders can even be passed to other rewrite appenders to apply multiple filter policies/modes, as long as it doesn't create a circular -reference. +reference. Each rewrite appender is applied sequentially (one after the other). ```yaml logging: appenders: diff --git a/src/core/server/logging/appenders/rewrite/rewrite_appender.ts b/src/core/server/logging/appenders/rewrite/rewrite_appender.ts index e480858c9677f4..e54d8ba40ebfcc 100644 --- a/src/core/server/logging/appenders/rewrite/rewrite_appender.ts +++ b/src/core/server/logging/appenders/rewrite/rewrite_appender.ts @@ -59,7 +59,7 @@ export class RewriteAppender implements DisposableAppender { /** * Appenders can be "attached" to this one so that the RewriteAppender - * is able to act as a sort of middleware by calling `append` other appenders. + * is able to act as a sort of middleware by calling `append` on other appenders. * * As appenders cannot be attached to each other until they are created, * the `addAppender` method is used to pass in a configured appender. From 11b55125fb82fde0b39f4029191cab4b44c68ce7 Mon Sep 17 00:00:00 2001 From: Luke Elmers Date: Mon, 22 Feb 2021 13:38:41 -0700 Subject: [PATCH 18/24] Prevent mutating array headers. --- .../http/logging/get_response_log.test.ts | 47 +++++++++++++++++++ .../server/http/logging/get_response_log.ts | 31 +++++++----- 2 files changed, 66 insertions(+), 12 deletions(-) diff --git a/src/core/server/http/logging/get_response_log.test.ts b/src/core/server/http/logging/get_response_log.test.ts index 46c4f1d95e3be0..64241ff44fc6ba 100644 --- a/src/core/server/http/logging/get_response_log.test.ts +++ b/src/core/server/http/logging/get_response_log.test.ts @@ -171,6 +171,53 @@ describe('getEcsResponseLog', () => { }); test('does not mutate original headers', () => { + const reqHeaders = { a: 'foo', b: ['hello', 'world'] }; + const resHeaders = { headers: { c: 'bar' } }; + const req = createMockHapiRequest({ + headers: reqHeaders, + response: { headers: resHeaders }, + }); + + const responseLog = getEcsResponseLog(req, logger); + expect(reqHeaders).toMatchInlineSnapshot(` + Object { + "a": "foo", + "b": Array [ + "hello", + "world", + ], + } + `); + expect(resHeaders).toMatchInlineSnapshot(` + Object { + "headers": Object { + "c": "bar", + }, + } + `); + + responseLog.http.request.headers.a = 'testA'; + responseLog.http.request.headers.b[1] = 'testB'; + responseLog.http.request.headers.c = 'testC'; + expect(reqHeaders).toMatchInlineSnapshot(` + Object { + "a": "foo", + "b": Array [ + "hello", + "world", + ], + } + `); + expect(resHeaders).toMatchInlineSnapshot(` + Object { + "headers": Object { + "c": "bar", + }, + } + `); + }); + + test('does not mutate original headers when redacting sensitive data', () => { const reqHeaders = { authorization: 'a', cookie: 'b', 'user-agent': 'hi' }; const resHeaders = { headers: { 'content-length': 123, 'set-cookie': 'c' } }; const req = createMockHapiRequest({ diff --git a/src/core/server/http/logging/get_response_log.ts b/src/core/server/http/logging/get_response_log.ts index ded24337869636..57c02e05bebff2 100644 --- a/src/core/server/http/logging/get_response_log.ts +++ b/src/core/server/http/logging/get_response_log.ts @@ -18,14 +18,22 @@ const ECS_VERSION = '1.7.0'; const FORBIDDEN_HEADERS = ['authorization', 'cookie', 'set-cookie']; const REDACTED_HEADER_TEXT = '[REDACTED]'; +type HapiHeaders = Record; + // We are excluding sensitive headers by default, until we have a log filtering mechanism. -function redactSensitiveHeaders( - headers?: Record -): Record { - const result = {} as Record; +function redactSensitiveHeaders(key: string, value: string | string[]): string | string[] { + return FORBIDDEN_HEADERS.includes(key) ? REDACTED_HEADER_TEXT : value; +} + +// Shallow clone the headers so they are not mutated if filtered by a RewriteAppender. +function cloneAndFilterHeaders(headers?: HapiHeaders) { + const result = {} as HapiHeaders; if (headers) { for (const key of Object.keys(headers)) { - result[key] = FORBIDDEN_HEADERS.includes(key) ? REDACTED_HEADER_TEXT : headers[key]; + result[key] = redactSensitiveHeaders( + key, + Array.isArray(headers[key]) ? [...headers[key]] : headers[key] + ); } } return result; @@ -46,11 +54,10 @@ export function getEcsResponseLog(request: Request, log: Logger): LogMeta { // eslint-disable-next-line @typescript-eslint/naming-convention const status_code = isBoom(response) ? response.output.statusCode : response.statusCode; - // shallow clone the headers so they are not mutated if filtered by a RewriteAppender - const requestHeaders = { ...request.headers }; - const responseHeaders = isBoom(response) - ? { ...response.output.headers } - : { ...response.headers }; + const requestHeaders = cloneAndFilterHeaders(request.headers); + const responseHeaders = cloneAndFilterHeaders( + isBoom(response) ? (response.output.headers as HapiHeaders) : response.headers + ); // borrowed from the hapi/good implementation const responseTime = (request.info.completed || request.info.responded) - request.info.received; @@ -71,7 +78,7 @@ export function getEcsResponseLog(request: Request, log: Logger): LogMeta { mime_type: request.mime, referrer: request.info.referrer, // @ts-expect-error Headers are not yet part of ECS: https://github.com/elastic/ecs/issues/232. - headers: redactSensitiveHeaders(requestHeaders), + headers: requestHeaders, }, response: { body: { @@ -79,7 +86,7 @@ export function getEcsResponseLog(request: Request, log: Logger): LogMeta { }, status_code, // @ts-expect-error Headers are not yet part of ECS: https://github.com/elastic/ecs/issues/232. - headers: redactSensitiveHeaders(responseHeaders), + headers: responseHeaders, // responseTime is a custom non-ECS field responseTime: !isNaN(responseTime) ? responseTime : undefined, }, From b46e404181380ccfc9373bcf2472bc83bd2f4fcc Mon Sep 17 00:00:00 2001 From: Luke Elmers Date: Mon, 22 Feb 2021 13:41:44 -0700 Subject: [PATCH 19/24] Extract inline types from MetaRewritePolicy. --- .../logging/appenders/rewrite/policies/meta/meta_policy.ts | 7 ++++++- 1 file changed, 6 insertions(+), 1 deletion(-) diff --git a/src/core/server/logging/appenders/rewrite/policies/meta/meta_policy.ts b/src/core/server/logging/appenders/rewrite/policies/meta/meta_policy.ts index 4bcc15dcfffec6..5e780b2a447cf7 100644 --- a/src/core/server/logging/appenders/rewrite/policies/meta/meta_policy.ts +++ b/src/core/server/logging/appenders/rewrite/policies/meta/meta_policy.ts @@ -13,6 +13,11 @@ import { has, unset } from 'lodash'; import { assertNever } from '@kbn/std'; import { RewritePolicy } from '../policy'; +type MetaRewritePolicyConfigProperties = Array<{ + path: string; + value?: string | number | boolean | null; +}>; + export interface MetaRewritePolicyConfig { type: 'meta'; @@ -31,7 +36,7 @@ export interface MetaRewritePolicyConfig { * Each provided 'path' is relative to the record's {@link LogMeta}. * For the 'remove' mode, no 'value' is provided. */ - properties: Array<{ path: string; value?: string | number | boolean | null }>; + properties: MetaRewritePolicyConfigProperties; } export const metaRewritePolicyConfigSchema = schema.object({ From f6ae2ea7ac63affa022055e625c830de5b244e42 Mon Sep 17 00:00:00 2001 From: Luke Elmers Date: Mon, 22 Feb 2021 13:44:48 -0700 Subject: [PATCH 20/24] Clean up unknown appender error message. --- src/core/server/logging/logging_system.ts | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/src/core/server/logging/logging_system.ts b/src/core/server/logging/logging_system.ts index 4963fc20f64683..d7c34b48c41012 100644 --- a/src/core/server/logging/logging_system.ts +++ b/src/core/server/logging/logging_system.ts @@ -191,14 +191,14 @@ export class LoggingSystem implements LoggerFactory { // declared `appenderRefs` dependencies, and look up those dependencies to // attach to the appender. This enables appenders to act as a sort of // middleware and call `append` on each other if needed. - for (const [, appender] of this.appenders) { + for (const [key, appender] of this.appenders) { if (!appender.addAppender || !appender.appenderRefs) { continue; } for (const ref of appender.appenderRefs) { const foundAppender = this.getAppenderByRef(ref); if (!foundAppender) { - throw new Error(`Appender config contains unknown appender key "${ref}".`); + throw new Error(`Appender "${key}" config contains unknown appender key "${ref}".`); } appender.addAppender(ref, foundAppender); } From 353d8e5eeb0b22be7831147c862c89290bc27f73 Mon Sep 17 00:00:00 2001 From: Luke Elmers Date: Mon, 22 Feb 2021 13:51:08 -0700 Subject: [PATCH 21/24] Resolve merge conflicts. --- .../server/logging/{README.md => README.mdx} | 72 ++++++++++++------- 1 file changed, 48 insertions(+), 24 deletions(-) rename src/core/server/logging/{README.md => README.mdx} (93%) diff --git a/src/core/server/logging/README.md b/src/core/server/logging/README.mdx similarity index 93% rename from src/core/server/logging/README.md rename to src/core/server/logging/README.mdx index 2c234d25cc2575..fde69a6de0196e 100644 --- a/src/core/server/logging/README.md +++ b/src/core/server/logging/README.mdx @@ -1,3 +1,13 @@ +--- +id: kibCoreLogging +slug: /kibana-dev-docs/services/logging +title: Logging system +image: https://source.unsplash.com/400x175/?Logging +summary: Core logging contains the system and service for Kibana logs. +date: 2020-12-02 +tags: ['kibana','dev', 'contributor', 'api docs'] +--- + # Logging - [Loggers, Appenders and Layouts](#loggers-appenders-and-layouts) - [Logger hierarchy](#logger-hierarchy) @@ -12,10 +22,11 @@ - [Configuration](#configuration) - [Usage](#usage) - [Logging config migration](#logging-config-migration) +- [Logging configuration via CLI](#logging-configuration-via-CLI) - [Log record format changes](#log-record-format-changes) The way logging works in Kibana is inspired by `log4j 2` logging framework used by [Elasticsearch](https://www.elastic.co/guide/en/elasticsearch/reference/current/settings.html#logging). -The main idea is to have consistent logging behaviour (configuration, log format etc.) across the entire Elastic Stack +The main idea is to have consistent logging behaviour (configuration, log format etc.) across the entire Elastic Stack where possible. ## Loggers, Appenders and Layouts @@ -33,16 +44,17 @@ __Layouts__ define how log messages are formatted and what type of information t ## Logger hierarchy -Every logger has its unique context name that follows hierarchical naming rule. The logger is considered to be an +Every logger has its unique context name that follows hierarchical naming rule. The logger is considered to be an ancestor of another logger if its name followed by a `.` is a prefix of the descendant logger name. For example logger with `a.b` context name is an ancestor of logger with `a.b.c` context name. All top-level loggers are descendants of special -logger with `root` context name that resides at the top of the logger hierarchy. This logger always exists and +logger with `root` context name that resides at the top of the logger hierarchy. This logger always exists and fully configured. Developer can configure _log level_ and _appenders_ that should be used within particular context name. If logger configuration -specifies only _log level_ then _appenders_ configuration will be inherited from the ancestor logger. +specifies only _log level_ then _appenders_ configuration will be inherited from the ancestor logger. -__Note:__ in the current implementation log messages are only forwarded to appenders configured for a particular logger +__Note:__ +In the current implementation log messages are only forwarded to appenders configured for a particular logger context name or to appenders of the closest ancestor if current logger doesn't have any appenders configured. That means that we __don't support__ so called _appender additivity_ when log messages are forwarded to _every_ distinct appender within ancestor chain including `root`. @@ -50,8 +62,10 @@ ancestor chain including `root`. ## Log level Currently we support the following log levels: _all_, _fatal_, _error_, _warn_, _info_, _debug_, _trace_, _off_. + Levels are ordered, so _all_ > _fatal_ > _error_ > _warn_ > _info_ > _debug_ > _trace_ > _off_. -A log record is being logged by the logger if its level is higher than or equal to the level of its logger. Otherwise, + +A log record is being logged by the logger if its level is higher than or equal to the level of its logger. Otherwise, the log record is ignored. The _all_ and _off_ levels can be used only in configuration and are just handy shortcuts that allow developer to log every @@ -60,15 +74,15 @@ log record or disable logging entirely for the specific context name. ## Layouts Every appender should know exactly how to format log messages before they are written to the console or file on the disk. -This behaviour is controlled by the layouts and configured through `appender.layout` configuration property for every +This behaviour is controlled by the layouts and configured through `appender.layout` configuration property for every custom appender (see examples in [Configuration](#configuration)). Currently we don't define any default layout for the custom appenders, so one should always make the choice explicitly. -There are two types of layout supported at the moment: `pattern` and `json`. +There are two types of layout supported at the moment: `pattern` and `json`. ### Pattern layout With `pattern` layout it's possible to define a string pattern with special placeholders `%conversion_pattern` (see the table below) that -will be replaced with data from the actual log message. By default the following pattern is used: +will be replaced with data from the actual log message. By default the following pattern is used: `[%date][%level][%logger]%meta %message`. Also `highlight` option can be enabled for `pattern` layout so that some parts of the log message are highlighted with different colors that may be quite handy if log messages are forwarded to the terminal with color support. @@ -110,7 +124,7 @@ Example of `%meta` output: ##### date Outputs the date of the logging event. The date conversion specifier may be followed by a set of braces containing a name of predefined date format and canonical timezone name. -Timezone name is expected to be one from [TZ database name](https://en.wikipedia.org/wiki/List_of_tz_database_time_zones). +Timezone name is expected to be one from [TZ database name](https://en.wikipedia.org/wiki/List_of_tz_database_time_zones). Timezone defaults to the host timezone when not explicitly specified. Example of `%date` output: @@ -129,7 +143,7 @@ Example of `%date` output: Outputs the process ID. ### JSON layout -With `json` layout log messages will be formatted as JSON strings that include timestamp, log level, context name, message +With `json` layout log messages will be formatted as JSON strings that include timestamp, log level, context name, message text and any other metadata that may be associated with the log message itself. ## Appenders @@ -159,7 +173,7 @@ logging: type: size-limit size: 50mb strategy: - //... + //... layout: type: pattern ``` @@ -187,7 +201,7 @@ logging: interval: 10s modulate: true strategy: - //... + //... layout: type: pattern ``` @@ -201,10 +215,10 @@ How often a rollover should occur. The default value is `24h` - `modulate` - + Whether the interval should be adjusted to cause the next rollover to occur on the interval boundary. - -For example, when true, if the interval is `4h` and the current hour is 3 am then the first rollover will occur at 4 am + +For example, when true, if the interval is `4h` and the current hour is 3 am then the first rollover will occur at 4 am and then next ones will occur at 8 am, noon, 4pm, etc. The default value is `true`. @@ -452,8 +466,8 @@ Here is what we get with the config above: | metrics.ops | console | debug | -The `root` logger has a dedicated configuration node since this context name is special and should always exist. By -default `root` is configured with `info` level and `default` appender that is also always available. This is the +The `root` logger has a dedicated configuration node since this context name is special and should always exist. By +default `root` is configured with `info` level and `default` appender that is also always available. This is the configuration that all custom loggers will use unless they're re-configured explicitly. For example to see _all_ log messages that fall back on the `root` logger configuration, just add one line to the configuration: @@ -512,8 +526,8 @@ The message contains some high-level information, and the corresponding log meta ## Usage -Usage is very straightforward, one should just get a logger for a specific context name and use it to log messages with -different log level. +Usage is very straightforward, one should just get a logger for a specific context name and use it to log messages with +different log level. ```typescript const logger = kibana.logger.get('server'); @@ -556,7 +570,7 @@ All log messages handled by `root` context are forwarded to the legacy logging s root appenders, make sure that it contains `default` appender to provide backward compatibility. **Note**: If you define an appender for a context name, the log messages aren't handled by the `root` context anymore and not forwarded to the legacy logging service. - + #### logging.dest By default logs in *stdout*. With new Kibana logging you can use pre-existing `console` appender or define a custom one. @@ -566,7 +580,7 @@ logging: - name: plugins.myPlugin appenders: [console] ``` -Logs in a *file* if given file path. You should define a custom appender with `type: file` +Logs in a *file* if given file path. You should define a custom appender with `type: file` ```yaml logging: @@ -579,13 +593,13 @@ logging: loggers: - name: plugins.myPlugin appenders: [file] -``` +``` #### logging.json Defines the format of log output. Logs in JSON if `true`. With new logging config you can adjust the output format with [layouts](#layouts). #### logging.quiet -Suppresses all logging output other than error messages. With new logging, config can be achieved +Suppresses all logging output other than error messages. With new logging, config can be achieved with adjusting minimum required [logging level](#log-level). ```yaml loggers: @@ -648,6 +662,16 @@ and you can enable them by adjusting the minimum required [logging level](#log-l #### logging.filter TBD +### Logging configuration via CLI + +| legacy logging | Kibana Platform logging| +|-|-| +|--verbose| --logging.root.level=debug --logging.root.appenders[0]=default --logging.root.appenders[1]=console| +|--quiet| --logging.root.level=error --logging.root.appenders[0]=default --logging.root.appenders[1]=console| +|--silent| --logging.root.level=off| + +*note that you have to pass the `default` appender until the legacy logging system is removed in v8.0 + ### Log record format changes | Parameter | Platform log record in **pattern** format | Legacy Platform log record **text** format | From f9f28dd57e5a8fa2a140c7dc64862295632a36b1 Mon Sep 17 00:00:00 2001 From: Luke Elmers Date: Tue, 23 Feb 2021 15:37:43 -0700 Subject: [PATCH 22/24] Remove MetaRewritePolicy 'add' mode. --- src/core/server/logging/README.mdx | 19 ++--- .../rewrite/policies/meta/meta_policy.test.ts | 74 ------------------- .../rewrite/policies/meta/meta_policy.ts | 21 +----- 3 files changed, 12 insertions(+), 102 deletions(-) diff --git a/src/core/server/logging/README.mdx b/src/core/server/logging/README.mdx index fde69a6de0196e..922d01c9d8b81c 100644 --- a/src/core/server/logging/README.mdx +++ b/src/core/server/logging/README.mdx @@ -317,8 +317,7 @@ The `meta` rewrite policy can read and modify any data contained in the Meta policies must specify one of three modes, which indicate which action to perform on the configured properties: -- `add` creates a new property at the provided `path`, skipping properties which already exist. -- `update` updates an existing property at the provided `path` without creating new properties. +- `update` updates an existing property at the provided `path`. - `remove` removes an existing property at the provided `path`. The `properties` are listed as a `path` and `value` pair, where `path` is @@ -348,25 +347,23 @@ reference. Each rewrite appender is applied sequentially (one after the other). ```yaml logging: appenders: - remove-stuff: + remove-request-headers: type: rewrite - appenders: [add-stuff] # redirect to the next rewrite appender + appenders: [censor-response-headers] # redirect to the next rewrite appender policy: type: meta mode: remove properties: - - path: "http.request.headers.authorization" - - path: "http.request.headers.cookie" - - path: "http.request.headers.set-cookie" - add-stuff: + - path: "http.request.headers" # remove all request headers + censor-response-headers: type: rewrite appenders: [console] # output to console policy: type: meta - mode: add + mode: update properties: - - path: "hello" - value: "world" # creates { hello: 'world' } at the LogMeta root + - path: "http.response.headers.set-cookie" + value: "[REDACTED]" ``` #### Complete Example diff --git a/src/core/server/logging/appenders/rewrite/policies/meta/meta_policy.test.ts b/src/core/server/logging/appenders/rewrite/policies/meta/meta_policy.test.ts index 8bd5e2aa5bfe81..52b88331a75bee 100644 --- a/src/core/server/logging/appenders/rewrite/policies/meta/meta_policy.test.ts +++ b/src/core/server/logging/appenders/rewrite/policies/meta/meta_policy.test.ts @@ -24,80 +24,6 @@ describe('MetaRewritePolicy', () => { meta, }); - describe('mode: add', () => { - it('adds new properties to LogMeta', () => { - const policy = createPolicy('add', [{ path: 'foo', value: 'bar' }]); - const log = createLogRecord(); - expect(policy.rewrite(log).meta).toMatchInlineSnapshot(` - Object { - "foo": "bar", - } - `); - }); - - it('adds nested properties to LogMeta', () => { - const policy = createPolicy('add', [ - { path: 'a.b', value: 'foo' }, - { path: 'a.c[1]', value: 'bar' }, - ]); - const log = createLogRecord(); - expect(policy.rewrite(log).meta).toMatchInlineSnapshot(` - Object { - "a": Object { - "b": "foo", - "c": Array [ - undefined, - "bar", - ], - }, - } - `); - }); - - it('handles string, number, boolean, null', () => { - const policy = createPolicy('add', [ - { path: 'boolean', value: false }, - { path: 'null', value: null }, - { path: 'number', value: 123 }, - { path: 'string', value: 'hi' }, - ]); - const log = createLogRecord(); - expect(policy.rewrite(log).meta).toMatchInlineSnapshot(` - Object { - "boolean": false, - "null": null, - "number": 123, - "string": "hi", - } - `); - }); - - it('does not overwrite properties which already exist', () => { - const policy = createPolicy('add', [ - { path: 'a.b', value: 'foo' }, - { path: 'a.c', value: 'bar' }, - ]); - const log = createLogRecord({ a: { b: 'existing meta' } }); - const { meta } = policy.rewrite(log); - expect(meta!.a.b).toBe('existing meta'); - expect(meta!.a.c).toBe('bar'); - }); - - it('does not touch anything outside of LogMeta', () => { - const policy = createPolicy('add', [{ path: 'message', value: 'bar' }]); - const message = Symbol(); - expect(policy.rewrite(({ message } as unknown) as LogRecord).message).toBe(message); - expect(policy.rewrite(({ message } as unknown) as LogRecord)).toMatchInlineSnapshot(` - Object { - "message": Symbol(), - "meta": Object { - "message": "bar", - }, - } - `); - }); - }); - describe('mode: update', () => { it('updates existing properties in LogMeta', () => { const log = createLogRecord({ a: 'before' }); diff --git a/src/core/server/logging/appenders/rewrite/policies/meta/meta_policy.ts b/src/core/server/logging/appenders/rewrite/policies/meta/meta_policy.ts index 5e780b2a447cf7..2215b3489539fa 100644 --- a/src/core/server/logging/appenders/rewrite/policies/meta/meta_policy.ts +++ b/src/core/server/logging/appenders/rewrite/policies/meta/meta_policy.ts @@ -23,14 +23,13 @@ export interface MetaRewritePolicyConfig { /** * The 'mode' specifies what action to perform on the specified properties. - * - 'add' creates a new property at the provided 'path', skipping properties which already exist. - * - 'update' updates an existing property at the provided 'path' without creating new properties. + * - 'update' updates an existing property at the provided 'path'. * - 'remove' removes an existing property at the provided 'path'. */ - mode: 'add' | 'remove' | 'update'; + mode: 'remove' | 'update'; /** - * The properties to add, remove, or update. + * The properties to modify. * * @remarks * Each provided 'path' is relative to the record's {@link LogMeta}. @@ -41,7 +40,7 @@ export interface MetaRewritePolicyConfig { export const metaRewritePolicyConfigSchema = schema.object({ type: schema.literal('meta'), - mode: schema.oneOf([schema.literal('add'), schema.literal('update'), schema.literal('remove')], { + mode: schema.oneOf([schema.literal('update'), schema.literal('remove')], { defaultValue: 'update', }), properties: schema.arrayOf( @@ -63,8 +62,6 @@ export class MetaRewritePolicy implements RewritePolicy { rewrite(record: LogRecord): LogRecord { switch (this.config.mode) { - case 'add': - return this.add(record); case 'update': return this.update(record); case 'remove': @@ -74,16 +71,6 @@ export class MetaRewritePolicy implements RewritePolicy { } } - private add(record: LogRecord) { - for (const { path, value } of this.config.properties) { - if (has(record, `meta.${path}`)) { - continue; // don't overwrite properties which already exist - } - set(record, `meta.${path}`, value); - } - return record; - } - private update(record: LogRecord) { for (const { path, value } of this.config.properties) { if (!has(record, `meta.${path}`)) { From 3d2a945f142d96848247c2420ae79fbd3368a2db Mon Sep 17 00:00:00 2001 From: Luke Elmers Date: Tue, 23 Feb 2021 15:43:32 -0700 Subject: [PATCH 23/24] Remove default rewrite-appender. --- .../server/logging/logging_config.test.ts | 27 ++------------- src/core/server/logging/logging_config.ts | 34 ------------------- 2 files changed, 2 insertions(+), 59 deletions(-) diff --git a/src/core/server/logging/logging_config.test.ts b/src/core/server/logging/logging_config.test.ts index 13ed9a72839ed2..83f3c139e371af 100644 --- a/src/core/server/logging/logging_config.test.ts +++ b/src/core/server/logging/logging_config.test.ts @@ -48,35 +48,13 @@ test('`getLoggerContext()` returns correct joined context name.', () => { test('correctly fills in default config.', () => { const configValue = new LoggingConfig(config.schema.validate({})); - expect(configValue.appenders.size).toBe(3); + expect(configValue.appenders.size).toBe(2); expect(configValue.appenders.get('default')).toEqual({ type: 'console', layout: { type: 'pattern', highlight: true }, }); expect(configValue.appenders.get('console')).toEqual({ - type: 'rewrite', - appenders: ['rewrite-console'], - policy: { - type: 'meta', - mode: 'update', - properties: [ - { - path: 'http.request.headers.authorization', - value: '[REDACTED]', - }, - { - path: 'http.request.headers.cookie', - value: '[REDACTED]', - }, - { - path: 'http.response.headers.set-cookie', - value: '[REDACTED]', - }, - ], - }, - }); - expect(configValue.appenders.get('rewrite-console')).toEqual({ type: 'console', layout: { type: 'pattern', highlight: true }, }); @@ -94,7 +72,7 @@ test('correctly fills in custom `appenders` config.', () => { }) ); - expect(configValue.appenders.size).toBe(3); + expect(configValue.appenders.size).toBe(2); expect(configValue.appenders.get('default')).toEqual({ type: 'console', @@ -211,7 +189,6 @@ describe('extend', () => { expect([...mergedConfigValue.appenders.keys()]).toEqual([ 'default', 'console', - 'rewrite-console', 'file1', 'file2', ]); diff --git a/src/core/server/logging/logging_config.ts b/src/core/server/logging/logging_config.ts index 8f40524cdff795..24496289fb4c84 100644 --- a/src/core/server/logging/logging_config.ts +++ b/src/core/server/logging/logging_config.ts @@ -28,21 +28,6 @@ const ROOT_CONTEXT_NAME = 'root'; */ const DEFAULT_APPENDER_NAME = 'default'; -/** - * Sensitive `LogMeta` paths that we want to censor by default. - * These paths are only filtered in a default logging configuration. - */ -const SENSITIVE_META_PATHS = [ - 'http.request.headers.authorization', - 'http.request.headers.cookie', - 'http.response.headers.set-cookie', -] as const; - -/** - * Replacement text to use when censoring SENSITIVE_META_PATHS. - */ -const REDACTED_META_TEXT = '[REDACTED]'; - const levelSchema = schema.oneOf( [ schema.literal('all'), @@ -168,26 +153,7 @@ export class LoggingConfig { } as AppenderConfigType, ], [ - // By default, we transparently rewrite `LogMeta` sent to the - // console appender to remove potentially sensitive keys. - // This logic is also hardcoded in the http response logger - // itself, but included here as an additional measure for - // other loggers which might be logging the same data. 'console', - { - type: 'rewrite', - appenders: ['rewrite-console'], - policy: { - type: 'meta', - mode: 'update', - properties: SENSITIVE_META_PATHS.map((path) => ({ path, value: REDACTED_META_TEXT })), - }, - } as AppenderConfigType, - ], - [ - // This is our actual console appender which the rewrite appender - // sends its records to. - 'rewrite-console', { type: 'console', layout: { type: 'pattern', highlight: true }, From fb23cb1672e71bc2c3775fe8c473ab2d6b5f20fa Mon Sep 17 00:00:00 2001 From: Luke Elmers Date: Wed, 24 Feb 2021 13:24:43 -0700 Subject: [PATCH 24/24] Fix logging system jest tests. --- .../__snapshots__/logging_system.test.ts.snap | 6 +++--- src/core/server/logging/logging_system.test.ts | 15 +++++++++++---- 2 files changed, 14 insertions(+), 7 deletions(-) diff --git a/src/core/server/logging/__snapshots__/logging_system.test.ts.snap b/src/core/server/logging/__snapshots__/logging_system.test.ts.snap index e3ecd860fc5a90..81321a3b1fe44c 100644 --- a/src/core/server/logging/__snapshots__/logging_system.test.ts.snap +++ b/src/core/server/logging/__snapshots__/logging_system.test.ts.snap @@ -14,7 +14,7 @@ exports[`appends records via multiple appenders.: file logs 2`] = ` exports[`asLoggerFactory() only allows to create new loggers. 1`] = ` Object { - "@timestamp": "2012-01-30T12:33:22.011-05:00", + "@timestamp": "2012-01-30T22:33:22.011-05:00", "log": Object { "level": "TRACE", "logger": "test.context", @@ -28,7 +28,7 @@ Object { exports[`asLoggerFactory() only allows to create new loggers. 2`] = ` Object { - "@timestamp": "2012-01-30T07:33:22.011-05:00", + "@timestamp": "2012-01-30T17:33:22.011-05:00", "log": Object { "level": "INFO", "logger": "test.context", @@ -43,7 +43,7 @@ Object { exports[`asLoggerFactory() only allows to create new loggers. 3`] = ` Object { - "@timestamp": "2012-01-30T02:33:22.011-05:00", + "@timestamp": "2012-01-30T12:33:22.011-05:00", "log": Object { "level": "FATAL", "logger": "test.context", diff --git a/src/core/server/logging/logging_system.test.ts b/src/core/server/logging/logging_system.test.ts index 0a3643e20edd83..8a6fe71bc62220 100644 --- a/src/core/server/logging/logging_system.test.ts +++ b/src/core/server/logging/logging_system.test.ts @@ -138,8 +138,15 @@ test('attaches appenders to appenders that declare refs', async () => { await system.upgrade( config.schema.validate({ appenders: { - console: { type: 'console', layout: { type: 'pattern' } }, - file: { type: 'file', layout: { type: 'pattern' }, fileName: 'path' }, + console: { + type: 'console', + layout: { type: 'pattern', pattern: '[%logger] %message %meta' }, + }, + file: { + type: 'file', + layout: { type: 'pattern', pattern: '[%logger] %message %meta' }, + fileName: 'path', + }, rewrite: { type: 'rewrite', appenders: ['console', 'file'], @@ -155,12 +162,12 @@ test('attaches appenders to appenders that declare refs', async () => { expect(mockConsoleLog).toHaveBeenCalledTimes(1); expect(mockConsoleLog.mock.calls[0][0]).toMatchInlineSnapshot( - `"[2012-01-30T22:33:22.011-05:00][WARN ][tests]{\\"a\\":\\"hi\\"} This message goes to a test context."` + `"[tests] This message goes to a test context. {\\"a\\":\\"hi\\"}"` ); expect(mockStreamWrite).toHaveBeenCalledTimes(1); expect(mockStreamWrite.mock.calls[0][0]).toMatchInlineSnapshot(` - "[2012-01-30T17:33:22.011-05:00][WARN ][tests]{\\"a\\":\\"hi\\"} This message goes to a test context. + "[tests] This message goes to a test context. {\\"a\\":\\"hi\\"} " `); });