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

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

Merged
merged 10 commits into from
Feb 10, 2021
Merged

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

Show file tree
Hide file tree
Changes from 2 commits
Commits
Show all changes
10 commits
Select commit Hold shift + click to select a range
acbe1fd
Use host timezone as default, updates tests and snapshots
TinaHeiligers Feb 5, 2021
fc509ac
Updates timezone logging settings in docs
TinaHeiligers Feb 5, 2021
a59ca2e
Adds integration test to verify behavior of timezone settings
TinaHeiligers Feb 5, 2021
91f3ffc
simplifies timezone defaults in KP logging
TinaHeiligers Feb 5, 2021
666863a
Adds deprecation notice for logging.timezone
TinaHeiligers Feb 5, 2021
d4dd4d4
reverts adding timezone test
TinaHeiligers Feb 6, 2021
3452ac0
Merge branch 'master' into logging/host-timezone-as-default
kibanamachine Feb 6, 2021
06b656d
Merge branch 'master' into logging/host-timezone-as-default
TinaHeiligers Feb 8, 2021
973095b
Changes logging timezone settings default information in docs
TinaHeiligers Feb 8, 2021
48ca1c9
Updates logging.timezone section in migration guide
TinaHeiligers Feb 9, 2021
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
4 changes: 2 additions & 2 deletions docs/setup/settings.asciidoc
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -306,10 +306,10 @@ the `polling` method could be used enabling that option. *Default: `false`*
suppress all logging output. *Default: `false`*

| `logging.timezone`
| Set to the canonical time zone ID
| Optional. Set to the canonical time zone ID
Copy link
Contributor Author

Choose a reason for hiding this comment

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

The legacy logging timezone default was changed from UTC to the host timezone in #22696. It appears that the documentation wasn't updated to reflect the change. As it stands right now, logging.timezone is actually optional (internally falling back to the local timezone of the host) and we needed to update the docs to reflect that.

Copy link
Member

Choose a reason for hiding this comment

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

As it stands right now, logging.timezone is actually optional (internally falling back to the local timezone of the host)

Are we certain that this is the current behavior?

I see that the changes made in #22696 are no longer present in the legacy logging config schema: https://github.com/elastic/kibana/blob/master/packages/kbn-legacy-logging/src/schema.ts#L61

It seems to me that the current setup docs on master are accurate based on how the system works, but that's a little confusing because this update to the migration doc which was added in #22696 is no longer correct: https://github.com/elastic/kibana/blob/master/docs/migration/migrate_8_0.asciidoc

Copy link
Contributor Author

@TinaHeiligers TinaHeiligers Feb 5, 2021 •
edited
Loading

Choose a reason for hiding this comment

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

@lukeelmers The global logging.timezone is only applied to the legacy logging system. In the KP, this setting is ignored. This PR doesn't make any changes to the legacy logging behavior, it changes the default timezone used in the KP logging system to match the behavior of the legacy logger.

Copy link
Contributor Author

@TinaHeiligers TinaHeiligers Feb 8, 2021 •
edited
Loading

Choose a reason for hiding this comment

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

Update: I removed Optional and replaced *Default: 'UTC'* with "When not set, log events use the host timezone"

(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].

| [[logging-verbose]] `logging.verbose:` {ess-icon}
| Set to `true` to log all events, including system usage information and all
Expand Down
20 changes: 10 additions & 10 deletions src/core/server/legacy/integration_tests/logging.test.ts
View file
Open in desktop
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 •
edited
Loading

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
View file
Open in desktop
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
14 changes: 7 additions & 7 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.

24 changes: 12 additions & 12 deletions src/core/server/logging/layouts/__snapshots__/pattern_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.

8 changes: 7 additions & 1 deletion src/core/server/logging/layouts/conversions/date.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -22,10 +22,16 @@ 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);
} else {
momentDate.tz(moment.tz.guess());
}
TinaHeiligers marked this conversation as resolved.
Show resolved Hide resolved
switch (dateFormat) {
case formats.ISO8601:
Expand Down
12 changes: 7 additions & 5 deletions src/core/server/logging/layouts/pattern_layout.test.ts
View file
Open in desktop
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