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

Co-authored-by: Kibana Machine <[email protected]>

docs/migration/migrate_8_0.asciidoc

@@ -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

docs/setup/settings.asciidoc

@@ -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

src/core/server/config/deprecation/core_deprecations.test.ts

@@ -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([]);
+    });
+  });
 });

src/core/server/config/deprecation/core_deprecations.ts

@@ -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'),
@@ -163,4 +175,5 @@ export const coreDeprecationProvider: ConfigDeprecationProvider = ({ rename, unu
   mapManifestServiceUrlDeprecation,
   opsLoggingEventDeprecation,
   requestLoggingEventDeprecation,
+  timezoneLoggingDeprecation,
 ];

src/core/server/legacy/integration_tests/logging.test.ts

@@ -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",
           ]
         `);
       });
@@ -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",
           ]
         `);
 
@@ -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",
           ]
         `);
 
@@ -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",
           ]
         `);
 

src/core/server/logging/README.md

@@ -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                                                          |
@@ -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
@@ -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:
@@ -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                                        |

src/core/server/logging/layouts/conversions/date.ts

@@ -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,
+  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();

src/core/server/logging/layouts/pattern_layout.test.ts

@@ -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({
@@ -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');
 
   expect(
     layout.format({
@@ -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.', () => {
@@ -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', () => {