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

[core.logging] Uses host timezone as default #90368

Merged
13 changes: 12 additions & 1 deletion docs/migration/migrate_8_0.asciidoc
Original file line number Diff line number Diff line change
Expand Up @@ -52,7 +52,18 @@ for example, `logstash-*`.
==== Default logging timezone is now the system's timezone
*Details:* In prior releases the timezone used in logs defaulted to UTC. We now use the host machine's timezone by default.

*Impact:* To restore the previous behavior, in kibana.yml set `logging.timezone: UTC`.
*Impact:* To restore the previous behavior, in kibana.yml use the pattern layout, with a date modifier:
[source,yaml]
-------------------
logging:
appenders:
console:
kind: console
layout:
kind: pattern
pattern: "%date{ISO8601_TZ}{UTC}"
-------------------
See https://github.com/elastic/kibana/pull/90368 for more details.

[float]
==== Responses are never logged by default
Expand Down
3 changes: 2 additions & 1 deletion docs/setup/settings.asciidoc
Original file line number Diff line number Diff line change
Expand Up @@ -309,7 +309,8 @@ suppress all logging output. *Default: `false`*
| Set to the canonical time zone ID
(for example, `America/Los_Angeles`) to log events using that time zone.
For possible values, refer to
https://en.wikipedia.org/wiki/List_of_tz_database_time_zones[database time zones]. *Default: `UTC`*
https://en.wikipedia.org/wiki/List_of_tz_database_time_zones[database time zones].
When not set, log events use the host timezone

| [[logging-verbose]] `logging.verbose:` {ess-icon}
| Set to `true` to log all events, including system usage information and all
Expand Down
20 changes: 20 additions & 0 deletions src/core/server/config/deprecation/core_deprecations.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -298,4 +298,24 @@ describe('core deprecations', () => {
expect(messages).toEqual([]);
});
});

describe('logging.timezone', () => {
it('warns when ops events are used', () => {
const { messages } = applyCoreDeprecations({
logging: { timezone: 'GMT' },
});
expect(messages).toMatchInlineSnapshot(`
Array [
"\\"logging.timezone\\" has been deprecated and will be removed in 8.0. To set the timezone moving forward, please add a timezone date modifier to the log pattern in your logging configuration. For more details, see https://github.com/elastic/kibana/blob/master/src/core/server/logging/README.md",
]
`);
});

it('does not warn when other events are configured', () => {
const { messages } = applyCoreDeprecations({
logging: { events: { log: '*' } },
});
expect(messages).toEqual([]);
});
});
});
13 changes: 13 additions & 0 deletions src/core/server/config/deprecation/core_deprecations.ts
Original file line number Diff line number Diff line change
Expand Up @@ -127,6 +127,18 @@ const requestLoggingEventDeprecation: ConfigDeprecation = (settings, fromPath, l
return settings;
};

const timezoneLoggingDeprecation: ConfigDeprecation = (settings, fromPath, log) => {
if (has(settings, 'logging.timezone')) {
log(
'"logging.timezone" has been deprecated and will be removed ' +
'in 8.0. To set the timezone moving forward, please add a timezone date modifier to the log pattern ' +
'in your logging configuration. For more details, see ' +
'https://github.com/elastic/kibana/blob/master/src/core/server/logging/README.md'
);
}
return settings;
};

export const coreDeprecationProvider: ConfigDeprecationProvider = ({ rename, unusedFromRoot }) => [
unusedFromRoot('savedObjects.indexCheckTimeout'),
unusedFromRoot('server.xsrf.token'),
Expand Down Expand Up @@ -163,4 +175,5 @@ export const coreDeprecationProvider: ConfigDeprecationProvider = ({ rename, unu
mapManifestServiceUrlDeprecation,
opsLoggingEventDeprecation,
requestLoggingEventDeprecation,
timezoneLoggingDeprecation,
];
20 changes: 10 additions & 10 deletions src/core/server/legacy/integration_tests/logging.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -87,7 +87,7 @@ describe('logging service', () => {
const loggedString = getPlatformLogsFromMock(mockConsoleLog);
expect(loggedString).toMatchInlineSnapshot(`
Array [
"[xxxx-xx-xxTxx:xx:xx.xxxZ][INFO ][test-file] handled by NP",
"[xxxx-xx-xxTxx:xx:xx.xxx-xx:xx][INFO ][test-file] handled by NP",
Copy link
Contributor Author

@TinaHeiligers TinaHeiligers Feb 5, 2021

Choose a reason for hiding this comment

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

Default format changed from ISO8601 (UTC) to ISO8601_TZ (retains timezone offset) in the Kibana Platform.
This legacy logging test had to be updated for the setup, where we have both the legacy logging and KP logging systems configured.

]
`);
});
Expand Down Expand Up @@ -131,9 +131,9 @@ describe('logging service', () => {

expect(getPlatformLogsFromMock(mockConsoleLog)).toMatchInlineSnapshot(`
Array [
"[xxxx-xx-xxTxx:xx:xx.xxxZ][INFO ][test-file] info",
"[xxxx-xx-xxTxx:xx:xx.xxxZ][WARN ][test-file] warn",
"[xxxx-xx-xxTxx:xx:xx.xxxZ][ERROR][test-file] error",
"[xxxx-xx-xxTxx:xx:xx.xxx-xx:xx][INFO ][test-file] info",
"[xxxx-xx-xxTxx:xx:xx.xxx-xx:xx][WARN ][test-file] warn",
"[xxxx-xx-xxTxx:xx:xx.xxx-xx:xx][ERROR][test-file] error",
]
`);

Expand Down Expand Up @@ -162,9 +162,9 @@ describe('logging service', () => {

expect(getPlatformLogsFromMock(mockConsoleLog)).toMatchInlineSnapshot(`
Array [
"[xxxx-xx-xxTxx:xx:xx.xxxZ][INFO ][test-file] info",
"[xxxx-xx-xxTxx:xx:xx.xxxZ][WARN ][test-file] warn",
"[xxxx-xx-xxTxx:xx:xx.xxxZ][ERROR][test-file] error",
"[xxxx-xx-xxTxx:xx:xx.xxx-xx:xx][INFO ][test-file] info",
"[xxxx-xx-xxTxx:xx:xx.xxx-xx:xx][WARN ][test-file] warn",
"[xxxx-xx-xxTxx:xx:xx.xxx-xx:xx][ERROR][test-file] error",
]
`);

Expand Down Expand Up @@ -199,9 +199,9 @@ describe('logging service', () => {

expect(getPlatformLogsFromMock(mockConsoleLog)).toMatchInlineSnapshot(`
Array [
"[xxxx-xx-xxTxx:xx:xx.xxxZ][INFO ][test-file] info",
"[xxxx-xx-xxTxx:xx:xx.xxxZ][WARN ][test-file] warn",
"[xxxx-xx-xxTxx:xx:xx.xxxZ][ERROR][test-file] error",
"[xxxx-xx-xxTxx:xx:xx.xxx-xx:xx][INFO ][test-file] info",
"[xxxx-xx-xxTxx:xx:xx.xxx-xx:xx][WARN ][test-file] warn",
"[xxxx-xx-xxTxx:xx:xx.xxx-xx:xx][ERROR][test-file] error",
]
`);

Expand Down
31 changes: 16 additions & 15 deletions src/core/server/logging/README.md
Original file line number Diff line number Diff line change
Expand Up @@ -110,7 +110,8 @@ 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:

| Conversion pattern | Example |
Expand Down Expand Up @@ -410,22 +411,22 @@ loggerWithNestedContext.debug('Message with `debug` log level.');

And assuming logger for `server` context with `console` appender and `trace` level was used, console output will look like this:
```bash
[2017-07-25T18:54:41.639Z][TRACE][server] Message with `trace` log level.
[2017-07-25T18:54:41.639Z][DEBUG][server] Message with `debug` log level.
[2017-07-25T18:54:41.639Z][INFO ][server] Message with `info` log level.
[2017-07-25T18:54:41.639Z][WARN ][server] Message with `warn` log level.
[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.

[2017-07-25T18:54:41.639Z][TRACE][server.http] Message with `trace` log level.
[2017-07-25T18:54:41.639Z][DEBUG][server.http] Message with `debug` log level.
[2017-07-25T11:54:41.639-07:00][TRACE][server] Message with `trace` log level.
[2017-07-25T11:54:41.639-07:00][DEBUG][server] Message with `debug` log level.
[2017-07-25T11:54:41.639-07:00][INFO ][server] Message with `info` log level.
[2017-07-25T11:54:41.639-07:00][WARN ][server] Message with `warn` log level.
[2017-07-25T11:54:41.639-07:00][ERROR][server] Message with `error` log level.
[2017-07-25T11:54:41.639-07:00][FATAL][server] Message with `fatal` log level.

[2017-07-25T11:54:41.639-07:00][TRACE][server.http] Message with `trace` log level.
[2017-07-25T11:54:41.639-07:00][DEBUG][server.http] Message with `debug` log level.
```

The log will be less verbose with `warn` level for the `server` context:
```bash
[2017-07-25T18:54:41.639Z][WARN ][server] Message with `warn` log level.
[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.
[2017-07-25T11:54:41.639-07:00][WARN ][server] Message with `warn` log level.
[2017-07-25T11:54:41.639-07:00][ERROR][server] Message with `error` log level.
[2017-07-25T11:54:41.639-07:00][FATAL][server] Message with `fatal` log level.
```

### Logging config migration
Expand Down Expand Up @@ -488,7 +489,7 @@ 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`.
to [specify timezone](#date) for `layout: pattern`. Defaults to host timezone when not specified.
```yaml
logging:
appenders:
Expand Down Expand Up @@ -530,7 +531,7 @@ TBD

| Parameter | Platform log record in **pattern** format | Legacy Platform log record **text** format |
| --------------- | ------------------------------------------ | ------------------------------------------ |
| @timestamp | ISO8601 `2012-01-31T23:33:22.011Z` | Absolute `23:33:22.011` |
| @timestamp | ISO8601_TZ `2012-01-31T23:33:22.011-05:00` | Absolute `23:33:22.011` |
| context | `parent.child` | `['parent', 'child']` |
| level | `DEBUG` | `['debug']` |
| meta | stringified JSON object `{"to": "v8"}` | N/A |
Expand Down

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

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

11 changes: 7 additions & 4 deletions src/core/server/logging/layouts/conversions/date.ts
Original file line number Diff line number Diff line change
Expand Up @@ -22,11 +22,14 @@ const formats = {
UNIX_MILLIS: 'UNIX_MILLIS',
};

function formatDate(date: Date, dateFormat: string = formats.ISO8601, timezone?: string): string {
function formatDate(
date: Date,
dateFormat: string = formats.ISO8601_TZ,
TinaHeiligers marked this conversation as resolved.
Show resolved Hide resolved
timezone?: string
): string {
const momentDate = moment(date);
if (timezone) {
momentDate.tz(timezone);
}
momentDate.tz(timezone ?? moment.tz.guess());

switch (dateFormat) {
case formats.ISO8601:
return momentDate.toISOString();
Expand Down
12 changes: 7 additions & 5 deletions src/core/server/logging/layouts/pattern_layout.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -122,7 +122,9 @@ test('`format()` correctly formats record with meta data.', () => {
to: 'v8',
},
})
).toBe('[2012-02-01T14:30:22.011Z][DEBUG][context-meta]{"from":"v7","to":"v8"} message-meta');
).toBe(
'[2012-02-01T09:30:22.011-05:00][DEBUG][context-meta]{"from":"v7","to":"v8"} message-meta'
);

expect(
layout.format({
Expand All @@ -133,7 +135,7 @@ test('`format()` correctly formats record with meta data.', () => {
pid: 5355,
meta: {},
})
).toBe('[2012-02-01T14:30:22.011Z][DEBUG][context-meta]{} message-meta');
).toBe('[2012-02-01T09:30:22.011-05:00][DEBUG][context-meta]{} message-meta');
lukeelmers marked this conversation as resolved.
Show resolved Hide resolved

expect(
layout.format({
Expand All @@ -143,7 +145,7 @@ test('`format()` correctly formats record with meta data.', () => {
timestamp,
pid: 5355,
})
).toBe('[2012-02-01T14:30:22.011Z][DEBUG][context-meta] message-meta');
).toBe('[2012-02-01T09:30:22.011-05:00][DEBUG][context-meta] message-meta');
});

test('`format()` correctly formats record with highlighting.', () => {
Expand Down Expand Up @@ -187,10 +189,10 @@ describe('format', () => {
timestamp,
pid: 5355,
};
it('uses ISO8601 as default', () => {
it('uses ISO8601_TZ as default', () => {
const layout = new PatternLayout();

expect(layout.format(record)).toBe('[2012-02-01T14:30:22.011Z][DEBUG][context] message');
expect(layout.format(record)).toBe('[2012-02-01T09:30:22.011-05:00][DEBUG][context] message');
});

describe('supports specifying a predefined format', () => {
Expand Down