Skip to content

Commit

Permalink
[core.logging] Add RewriteAppender for filtering LogMeta. (#91492)
Browse files Browse the repository at this point in the history
  • Loading branch information
lukeelmers committed Feb 24, 2021
1 parent 3471eaa commit 0280d5a
Show file tree
Hide file tree
Showing 20 changed files with 1,031 additions and 13 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -8,5 +8,5 @@
<b>Signature:</b>

```typescript
export declare type AppenderConfigType = ConsoleAppenderConfig | FileAppenderConfig | LegacyAppenderConfig | RollingFileAppenderConfig;
export declare type AppenderConfigType = ConsoleAppenderConfig | FileAppenderConfig | LegacyAppenderConfig | RewriteAppenderConfig | RollingFileAppenderConfig;
```
18 changes: 18 additions & 0 deletions packages/kbn-logging/src/appenders.ts
Original file line number Diff line number Diff line change
Expand Up @@ -15,6 +15,24 @@ import { LogRecord } from './log_record';
*/
export interface Appender {
append(record: LogRecord): void;
/**
* 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: Appender): 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[];
}

/**
Expand Down
136 changes: 134 additions & 2 deletions src/core/server/http/integration_tests/logging.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -251,7 +251,7 @@ describe('request logging', () => {
expect(JSON.parse(meta).http.response.headers.bar).toBe('world');
});

it('filters sensitive request headers', async () => {
it('filters sensitive request headers by default', async () => {
const { http } = await root.setup();

http.createRouter('/').post(
Expand Down Expand Up @@ -283,7 +283,139 @@ describe('request logging', () => {
expect(JSON.parse(meta).http.request.headers.authorization).toBe('[REDACTED]');
});

it('filters sensitive response 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(
{
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 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: {
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(
Expand Down
47 changes: 47 additions & 0 deletions src/core/server/http/logging/get_response_log.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -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({
Expand Down
28 changes: 20 additions & 8 deletions src/core/server/http/logging/get_response_log.ts
Original file line number Diff line number Diff line change
Expand Up @@ -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<string, string | string[]>;

// We are excluding sensitive headers by default, until we have a log filtering mechanism.
function redactSensitiveHeaders(
headers?: Record<string, string | string[]>
): Record<string, string | string[]> {
const result = {} as Record<string, string | string[]>;
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;
Expand All @@ -45,7 +53,11 @@ 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;

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;
Expand All @@ -66,15 +78,15 @@ 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: requestHeaders,
},
response: {
body: {
bytes,
},
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,
},
Expand Down
Loading

0 comments on commit 0280d5a

Please sign in to comment.