Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

[logging] Format new platform json logging to ECS #71138

Merged
merged 11 commits into from
Jul 15, 2020
Merged

[logging] Format new platform json logging to ECS #71138

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
11 commits
Select commit Hold shift + click to select a range
e5a0992
[logging] Format new platform json logging to ECS
jbudz Jul 8, 2020
5e5c315
update integration tests
jbudz Jul 8, 2020
6dffc2e
Merge branch 'master' into logging/ecs
jbudz Jul 9, 2020
e3e7afd
merge instead of assign
jbudz Jul 13, 2020
e095437
add @timestamp override test
jbudz Jul 13, 2020
7fd0123
add partial merge test against log object
jbudz Jul 13, 2020
62a9d1b
Merge branch 'master' into logging/ecs
jbudz Jul 13, 2020
c419f54
add object level override test
jbudz Jul 13, 2020
557b1c6
Merge branch 'master' into logging/ecs
jbudz Jul 13, 2020
3916e3c
fix type error
jbudz Jul 13, 2020
a9a2fae
Merge branch 'master' into logging/ecs
elasticmachine Jul 14, 2020
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
54 changes: 35 additions & 19 deletions src/core/server/logging/__snapshots__/logging_system.test.ts.snap
View file
Open in desktop

Some generated files are not rendered by default. Learn more about how customized files appear on GitHub.

30 changes: 20 additions & 10 deletions src/core/server/logging/integration_tests/logging.test.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -198,13 +198,17 @@ describe('logging service', () => {
JSON.parse(jsonString)
);
expect(firstCall).toMatchObject({
level: 'DEBUG',
context: 'plugins.myplugin.debug_json',
log: {
level: 'DEBUG',
logger: 'plugins.myplugin.debug_json',
},
message: 'log1',
});
expect(secondCall).toMatchObject({
level: 'INFO',
context: 'plugins.myplugin.debug_json',
log: {
level: 'INFO',
logger: 'plugins.myplugin.debug_json',
},
message: 'log2',
});
});
Expand All @@ -217,8 +221,10 @@ describe('logging service', () => {

expect(mockConsoleLog).toHaveBeenCalledTimes(1);
expect(JSON.parse(mockConsoleLog.mock.calls[0][0])).toMatchObject({
level: 'INFO',
context: 'plugins.myplugin.info_json',
log: {
level: 'INFO',
logger: 'plugins.myplugin.info_json',
},
message: 'log2',
});
});
Expand Down Expand Up @@ -259,14 +265,18 @@ describe('logging service', () => {
const logs = mockConsoleLog.mock.calls.map(([jsonString]) => jsonString);

expect(JSON.parse(logs[0])).toMatchObject({
level: 'DEBUG',
context: 'plugins.myplugin.all',
log: {
level: 'DEBUG',
logger: 'plugins.myplugin.all',
},
message: 'log1',
});
expect(logs[1]).toEqual('CUSTOM - PATTERN [plugins.myplugin.all][DEBUG] log1');
expect(JSON.parse(logs[2])).toMatchObject({
level: 'INFO',
context: 'plugins.myplugin.all',
log: {
level: 'INFO',
logger: 'plugins.myplugin.all',
},
message: 'log2',
});
expect(logs[3]).toEqual('CUSTOM - PATTERN [plugins.myplugin.all][INFO ] log2');
Expand Down
12 changes: 6 additions & 6 deletions src/core/server/logging/layouts/__snapshots__/json_layout.test.ts.snap
View file
Open in desktop

Some generated files are not rendered by default. Learn more about how customized files appear on GitHub.

133 changes: 117 additions & 16 deletions src/core/server/logging/layouts/json_layout.test.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -98,21 +98,27 @@ test('`format()` correctly formats record with meta-data', () => {
timestamp,
pid: 5355,
meta: {
tylersmalley marked this conversation as resolved.
Show resolved Hide resolved
from: 'v7',
to: 'v8',
version: {
from: 'v7',
to: 'v8',
},
},
})
)
).toStrictEqual({
'@timestamp': '2012-02-01T09:30:22.011-05:00',
context: 'context-with-meta',
level: 'DEBUG',
log: {
level: 'DEBUG',
logger: 'context-with-meta',
},
message: 'message-with-meta',
meta: {
version: {
from: 'v7',
to: 'v8',
},
pid: 5355,
process: {
pid: 5355,
},
});
});

Expand All @@ -122,36 +128,131 @@ test('`format()` correctly formats error record with meta-data', () => {
expect(
JSON.parse(
layout.format({
context: 'error-with-meta',
level: LogLevel.Debug,
context: 'error-with-meta',
error: {
message: 'Some error message',
name: 'Some error name',
name: 'Some error type',
stack: 'Some error stack',
tylersmalley marked this conversation as resolved.
Show resolved Hide resolved
},
message: 'Some error message',
timestamp,
pid: 5355,
meta: {
from: 'v7',
to: 'v8',
version: {
from: 'v7',
to: 'v8',
},
},
})
)
).toStrictEqual({
'@timestamp': '2012-02-01T09:30:22.011-05:00',
context: 'error-with-meta',
level: 'DEBUG',
log: {
level: 'DEBUG',
logger: 'error-with-meta',
},
error: {
message: 'Some error message',
name: 'Some error name',
stack: 'Some error stack',
type: 'Some error type',
stack_trace: 'Some error stack',
},
message: 'Some error message',
meta: {
version: {
from: 'v7',
to: 'v8',
},
pid: 5355,
process: {
pid: 5355,
},
});
});

test('format() meta can override @timestamp', () => {
const layout = new JsonLayout();
expect(
JSON.parse(
layout.format({
message: 'foo',
timestamp,
level: LogLevel.Debug,
context: 'bar',
pid: 3,
meta: {
'@timestamp': '2099-05-01T09:30:22.011-05:00',
},
})
)
).toStrictEqual({
'@timestamp': '2099-05-01T09:30:22.011-05:00',
message: 'foo',
log: {
level: 'DEBUG',
logger: 'bar',
},
process: {
pid: 3,
},
});
});

test('format() meta can merge override logs', () => {
const layout = new JsonLayout();
expect(
JSON.parse(
layout.format({
timestamp,
message: 'foo',
level: LogLevel.Error,
context: 'bar',
pid: 3,
meta: {
log: {
kbn_custom_field: 'hello',
},
},
})
)
).toStrictEqual({
'@timestamp': '2012-02-01T09:30:22.011-05:00',
message: 'foo',
log: {
level: 'ERROR',
logger: 'bar',
kbn_custom_field: 'hello',
},
process: {
pid: 3,
},
});
});

test('format() meta can override log level objects', () => {
const layout = new JsonLayout();
expect(
JSON.parse(
layout.format({
timestamp,
context: '123',
message: 'foo',
level: LogLevel.Error,
pid: 3,
meta: {
log: {
level: 'FATAL',
},
},
})
)
).toStrictEqual({
'@timestamp': '2012-02-01T09:30:22.011-05:00',
message: 'foo',
log: {
level: 'FATAL',
logger: '123',
},
process: {
pid: 3,
},
});
});
31 changes: 20 additions & 11 deletions src/core/server/logging/layouts/json_layout.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -18,6 +18,7 @@
*/

import moment from 'moment-timezone';
import { merge } from 'lodash';
import { schema, TypeOf } from '@kbn/config-schema';

import { LogRecord } from '../log_record';
Expand Down Expand Up @@ -46,20 +47,28 @@ export class JsonLayout implements Layout {

return {
message: error.message,
name: error.name,
stack: error.stack,
type: error.name,
stack_trace: error.stack,
};
}

public format(record: LogRecord): string {
return JSON.stringify({
'@timestamp': moment(record.timestamp).format('YYYY-MM-DDTHH:mm:ss.SSSZ'),
context: record.context,
error: JsonLayout.errorToSerializableObject(record.error),
level: record.level.id.toUpperCase(),
message: record.message,
meta: record.meta,
pid: record.pid,
});
return JSON.stringify(
merge(
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'd rather we didn't use lodash.merge. It tripped us up several times with questionable functionality: for example, it merges array. BTW there is custom merge implementation in the repo: https://github.com/restrry/kibana/blob/a9a2fae0fc0e56ed3c7f0985e38e6436e72e160f/src/core/utils/merge.ts#L27

{
'@timestamp': moment(record.timestamp).format('YYYY-MM-DDTHH:mm:ss.SSSZ'),
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

formatting should be applied to the user @timestamp value as well. the same for error, level + tests required

message: record.message,
error: JsonLayout.errorToSerializableObject(record.error),
log: {
level: record.level.id.toUpperCase(),
logger: record.context,
},
process: {
pid: record.pid,
},
},
record.meta
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Similar to other comment, should we be placing record.meta under labels?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

meta might be named incorrectly - i tried to leave internal terminology as intact as possible, but it's closer to fields or something. i could rename it

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Could you create an issue? I'm fine to rename it.

)
);
}
}
Loading