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.

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

Use log4j pattern syntax #57433

Merged
merged 13 commits into from
Feb 13, 2020
6 changes: 5 additions & 1 deletion src/core/MIGRATION.md
Original file line number Diff line number Diff line change
Expand Up @@ -56,6 +56,7 @@
- [On the server side](#on-the-server-side)
- [On the client side](#on-the-client-side)
- [Updates an application navlink at runtime](#updates-an-app-navlink-at-runtime)
- [Logging config migration](#logging-config-migration)

Make no mistake, it is going to take a lot of work to move certain plugins to the new platform. Our target is to migrate the entire repo over to the new platform throughout 7.x and to remove the legacy plugin system no later than 8.0, and this is only possible if teams start on the effort now.

Expand Down Expand Up @@ -1654,4 +1655,7 @@ export class MyPlugin implements Plugin {
tooltip: 'Application disabled',
})
}
```
```

### Logging config migration
[Read](./server/logging/README.md#logging-config-migration)
142 changes: 139 additions & 3 deletions src/core/server/logging/README.md
Original file line number Diff line number Diff line change
@@ -1,4 +1,12 @@
# Logging
- [Loggers, Appenders and Layouts](#loggers-appenders-and-layouts)
- [Logger hierarchy](#logger-hierarchy)
- [Log level](#log-level)
- [Layouts](#layouts)
- [Pattern layout](#pattern-layout)
- [JSON layout](#json-layout)
- [Configuration](#configuration)
- [Usage](#usage)

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
Expand Down Expand Up @@ -52,12 +60,68 @@ custom appenders, so one should always make the choice explicitly.

There are two types of layout supported at the moment: `pattern` and `json`.

With `pattern` layout it's possible to define a string pattern with special placeholders wrapped into curly braces that
### 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:
`[{timestamp}][{level}][{context}] {message}`. Also `highlight` option can be enabled for `pattern` layout so that
`[%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.
`pattern` layout uses a sub-set of [log4j2 pattern syntax](https://logging.apache.org/log4j/2.x/manual/layouts.html#PatternLayout)
and **doesn't implement** all `log4j2` capabilities. The conversions that are provided out of the box are:

#### level
Outputs the [level](#log-level) of the logging event.
Example of `%level` output:
```bash
TRACE
DEBUG
INFO
```

##### logger
Outputs the name of the logger that published the logging event.
Example of `%logger` output:
```bash
server
server.http
server.http.Kibana
```

#### message
Outputs the application supplied message associated with the logging event.

#### meta
Outputs the entries of `meta` object data, if one is present in the event.
mshustov marked this conversation as resolved.
Show resolved Hide resolved
Example of `%meta` output:
```bash
// Meta{from: 'v7', to: 'v8'}
'{"from":"v7","to":"v8"}'
// Meta empty object
'{}'
// no Meta provided
''
```

##### 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)
Example of `%date` output:

| Conversion pattern | Example |
| ---------------------------------------- | ---------------------------------------------------------------- |
| `%date` | `2012-02-01T14:30:22.011Z` uses `ISO8601` format by default |
| `%date{ISO8601}` | `2012-02-01T14:30:22.011Z` |
| `%date{ISO8601_TZ}` | `2012-02-01T09:30:22.011-05:00` `ISO8601` with timezone |
| `%date{ISO8601_TZ}{America/Los_Angeles}` | `2012-02-01T06:30:22.011-08:00` |
| `%date{ABSOLUTE}` | `09:30:22.011` |
| `%date{ABSOLUTE}{America/Los_Angeles}` | `06:30:22.011` |
| `%date{UNIX}` | `1328106622` |
| `%date{UNIX_MILLIS}` | `1328106622011` |

#### pid
Outputs the process ID.

### JSON layout
With `json` layout log messages will be formatted as JSON strings that include timestamp, log level, context, message
text and any other metadata that may be associated with the log message itself.

Expand Down Expand Up @@ -88,7 +152,7 @@ logging:
kind: console
layout:
kind: pattern
pattern: [{timestamp}][{level}] {message}
pattern: "[%date][%level] %message"
json-file-appender:
kind: file
path: /var/log/kibana-json.log
Expand Down Expand Up @@ -179,3 +243,75 @@ The log will be less verbose with `warn` level for the `server` context:
[2017-07-25T18:54:41.639Z][ERROR][server] Message with `error` log level.
[2017-07-25T18:54:41.639Z][FATAL][server] Message with `fatal` log level.
```

### Logging config migration
#### logging.dest
By default logs in *stdout*. With new Kibana logging you can use pre-existing `console` appender or
define a custom one.
```yaml
logging:
loggers:
- context: your-plugin
appenders: [console]
```
Logs in a *file* if given file path. You should define a custom appender with `kind: file`
```yaml

logging:
appenders:
file:
kind: file
path: /var/log/kibana.log
layout:
kind: pattern
loggers:
- context: your-plugin
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
with adjusting minimum required [logging level](#log-level)
```yaml
loggers:
- context: my-plugin
appenders: [console]
level: error
# or for all output
logging.root.level: error
```

#### logging.silent:
Suppresses all logging output.
```yaml
logging.root.level: off
```

#### logging.verbose:
Logs all events
```yaml
logging.root.level: all
```

#### logging.timezone
Set to the canonical timezone id to log events using that timezone. New logging config allows
to [specify timezone](#date) for `layout: pattern`.
```yaml
logging:
appenders:
custom-console:
kind: console
layout:
kind: pattern
highlight: true
pattern: "[%level] [%date{ISO8601_TZ}{America/Los_Angeles}][%logger] %message"
```

#### logging.events
Define a custom logger for a specific context.

#### logging.filter
TBD
2 changes: 1 addition & 1 deletion src/core/server/logging/integration_tests/logging.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -29,7 +29,7 @@ function createRoot() {
layout: {
highlight: false,
kind: 'pattern',
pattern: '{level}|{context}|{message}',
pattern: '%level|%logger|%message',
},
},
},
Expand Down

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

Original file line number Diff line number Diff line change
Expand Up @@ -22,7 +22,7 @@ import { last } from 'lodash';
import { Conversion } from './type';
import { LogRecord } from '../../log_record';

const timestampRegExp = /{timestamp({(?<format>[^}]+)})?({(?<timezone>[^}]+)})?}/gi;
const dateRegExp = /%date({(?<format>[^}]+)})?({(?<timezone>[^}]+)})?/g;

const formats = {
ISO8601: 'ISO8601',
Expand Down Expand Up @@ -54,10 +54,11 @@ function formatDate(date: Date, dateFormat: string = formats.ISO8601, timezone?:
}

function validateDateFormat(input: string) {
if (Reflect.has(formats, input)) return;
throw new Error(
`Date format expected one of ${Reflect.ownKeys(formats).join(', ')}, but given: ${input}`
);
if (!Reflect.has(formats, input)) {
throw new Error(
`Date format expected one of ${Reflect.ownKeys(formats).join(', ')}, but given: ${input}`
);
}
}

function validateTimezone(timezone: string) {
Expand All @@ -66,21 +67,27 @@ function validateTimezone(timezone: string) {
}

function validate(rawString: string) {
for (const matched of rawString.matchAll(timestampRegExp)) {
Copy link
Contributor Author

@mshustov mshustov Feb 12, 2020

Choose a reason for hiding this comment

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

TIL matchAll is not polyfilled in runtime. that was a surprise, since it works in tests

Copy link
Contributor

Choose a reason for hiding this comment

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

What was the issue outside of the scope of tests?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

I contacted @elastic/kibana-operations to clarify this. The test and runtime envs should be identical

Copy link
Contributor Author

@mshustov mshustov Feb 12, 2020

Choose a reason for hiding this comment

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

should be fixed in #57467

const { format, timezone } = matched.groups!;
// clone regexp for exec since it's stateful with g flag
const regExp = new RegExp(dateRegExp, 'g');
let matched: RegExpExecArray | null;
do {
matched = regExp.exec(rawString);
if (matched) {
const { format, timezone } = matched.groups!;

if (format) {
validateDateFormat(format);
}
if (timezone) {
validateTimezone(timezone);
if (format) {
validateDateFormat(format);
}
if (timezone) {
validateTimezone(timezone);
}
}
}
} while (matched);
}

export const TimestampConversion: Conversion = {
pattern: timestampRegExp,
formatter(record: LogRecord, highlight: boolean, ...matched: any[]) {
export const DateConversion: Conversion = {
pattern: dateRegExp,
convert(record: LogRecord, highlight: boolean, ...matched: any[]) {
const groups: Record<string, string | undefined> = last(matched);
const { format, timezone } = groups;

Expand Down
26 changes: 26 additions & 0 deletions src/core/server/logging/layouts/conversions/index.ts
Original file line number Diff line number Diff line change
@@ -0,0 +1,26 @@
/*
* Licensed to Elasticsearch B.V. under one or more contributor
* license agreements. See the NOTICE file distributed with
* this work for additional information regarding copyright
* ownership. Elasticsearch B.V. licenses this file to you under
* the Apache License, Version 2.0 (the "License"); you may
* not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing,
* software distributed under the License is distributed on an
* "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
* KIND, either express or implied. See the License for the
* specific language governing permissions and limitations
* under the License.
*/
export { Conversion } from './type';

export { LoggerConversion } from './logger';
export { LevelConversion } from './level';
export { MessageConversion } from './message';
export { MetaConversion } from './meta';
export { PidConversion } from './pid';
export { DateConversion } from './date';
4 changes: 2 additions & 2 deletions src/core/server/logging/layouts/conversions/level.ts
Original file line number Diff line number Diff line change
Expand Up @@ -32,8 +32,8 @@ const LEVEL_COLORS = new Map([
]);

export const LevelConversion: Conversion = {
pattern: /{level}/gi,
formatter(record: LogRecord, highlight: boolean) {
pattern: /%level/g,
convert(record: LogRecord, highlight: boolean) {
let message = record.level.id.toUpperCase().padEnd(5);
if (highlight && LEVEL_COLORS.has(record.level)) {
const color = LEVEL_COLORS.get(record.level)!;
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -22,9 +22,9 @@ import chalk from 'chalk';
import { Conversion } from './type';
import { LogRecord } from '../../log_record';

export const ContextConversion: Conversion = {
pattern: /{context}/gi,
formatter(record: LogRecord, highlight: boolean) {
export const LoggerConversion: Conversion = {
pattern: /%logger/g,
convert(record: LogRecord, highlight: boolean) {
let message = record.context;
if (highlight) {
message = chalk.magenta(message);
Expand Down
4 changes: 2 additions & 2 deletions src/core/server/logging/layouts/conversions/message.ts
Original file line number Diff line number Diff line change
Expand Up @@ -21,8 +21,8 @@ import { Conversion } from './type';
import { LogRecord } from '../../log_record';

export const MessageConversion: Conversion = {
pattern: /{message}/gi,
formatter(record: LogRecord) {
pattern: /%message/g,
convert(record: LogRecord) {
// Error stack is much more useful than just the message.
return (record.error && record.error.stack) || record.message;
},
Expand Down
6 changes: 3 additions & 3 deletions src/core/server/logging/layouts/conversions/meta.ts
Original file line number Diff line number Diff line change
Expand Up @@ -20,8 +20,8 @@ import { Conversion } from './type';
import { LogRecord } from '../../log_record';

export const MetaConversion: Conversion = {
pattern: /{meta}/gi,
formatter(record: LogRecord) {
return record.meta ? `[${JSON.stringify(record.meta)}]` : '';
pattern: /%meta/g,
convert(record: LogRecord) {
return record.meta ? `${JSON.stringify(record.meta)}` : '';
},
};
4 changes: 2 additions & 2 deletions src/core/server/logging/layouts/conversions/pid.ts
Original file line number Diff line number Diff line change
Expand Up @@ -21,8 +21,8 @@ import { Conversion } from './type';
import { LogRecord } from '../../log_record';

export const PidConversion: Conversion = {
pattern: /{pid}/gi,
formatter(record: LogRecord) {
pattern: /%pid/g,
convert(record: LogRecord) {
return String(record.pid);
},
};
2 changes: 1 addition & 1 deletion src/core/server/logging/layouts/conversions/type.ts
Original file line number Diff line number Diff line change
Expand Up @@ -20,6 +20,6 @@ import { LogRecord } from 'kibana/server';

export interface Conversion {
pattern: RegExp;
formatter: (record: LogRecord, highlight: boolean) => string;
convert: (record: LogRecord, highlight: boolean) => string;
validate?: (input: string) => void;
}
Loading