Introduce logging JsonLayout. (#13180)

platform/logging/README.md

@@ -43,12 +43,30 @@ the log record is ignored.
 The _all_ and _off_ levels can be used only in configuration and are just handy shortcuts that allow developer to log every
 log record or disable logging entirely for the specific context.
 
+## Layouts
+
+Every appender should know exactly how to format log messages before they are written to the console or file on the disk.
+This behaviour is controlled by the layouts and configured through `appender.layout` configuration property for every 
+custom appender (see examples in [Configuration](#configuration)). Currently we don't define any default layout for the
+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
+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
+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.
+
+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.
+
 ## Configuration
 
 As any configuration in the platform, logging configuration is validated against the predefined schema and if there are
 any issues with it, Kibana will fail to start with the detailed error message.
 
-Once your code acquired a logger instance it should not care about any runtime changes in the configuration that may
+Once the code acquired a logger instance it should not care about any runtime changes in the configuration that may
 happen: all changes will be applied to existing logger instances under the hood.
 
 Here is the configuration example that can be used to configure _loggers_, _appenders_ and _layouts_:
@@ -63,14 +81,17 @@ logging:
         highlight: true
     file:
       kind: file
-      path: ~/Downloads/kibana.log
+      path: /var/log/kibana.log
       layout:
         kind: pattern
     custom:
       kind: console
       layout:
         kind: pattern
         pattern: [{timestamp}][{level}] {message}
+    json-file-appender:
+      kind: file
+      path: /var/log/kibana-json.log
 
   root:
     appenders: [console, file]
@@ -86,21 +107,26 @@ logging:
       level: fatal
     - context: optimize
       appenders: [console]
+    - context: telemetry
+      level: all
+      appenders: [json-file-appender]
 ```
 
-Here is what you get with the config above:
+Here is what we get with the config above:
 
-| Context       | Appenders     | Level |
-| ------------- |:-------------:| -----:|
-| root          | console, file | error |
-| plugins       | custom        | warn  |
-| plugins.pid   | custom        | info  |
-| server        | console, file | fatal |
-| optimize      | console       | error |
+| Context       | Appenders                | Level |
+| ------------- |:------------------------:| -----:|
+| root          | console, file            | error |
+| plugins       | custom                   | warn  |
+| plugins.pid   | custom                   | info  |
+| server        | console, file            | fatal |
+| optimize      | console                  | error |
+| telemetry     | json-file-appender       | all   |
 
-As you see `root` logger has a dedicated configuration node since this context is special and should always exist. By 
+
+The `root` logger has a dedicated configuration node since this context is special and should always exist. By 
 default `root` is configured with `info` level and `default` appender that is also always available. This is the 
-configuration that all your loggers will use unless you re-configure them explicitly.
+configuration that all custom loggers will use unless they're re-configured explicitly.
 
 For example to see _all_ log messages that fall back on the `root` logger configuration, just add one line to the configuration:
 
@@ -134,7 +160,7 @@ loggerWithNestedContext.trace('Message with `trace` log level.');
 loggerWithNestedContext.debug('Message with `debug` log level.');
 ```
 
-And assuming you're using `console` appender and `trace` level for `server` context, in console you'll see:
+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.
@@ -147,10 +173,9 @@ And assuming you're using `console` appender and `trace` level for `server` cont
 [2017-07-25T18:54:41.639Z][DEBUG][server.http] Message with `debug` log level.
 ```
 
-Obviously your log will be less verbose with `warn` level for the `server` context:
+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.
 ```
-

platform/logging/layouts/JsonLayout.ts

@@ -0,0 +1,32 @@
+import { Schema, typeOfSchema } from '../../types';
+import { LogRecord } from '../LogRecord';
+import { Layout } from './Layouts';
+
+const createSchema = ({ literal, object }: Schema) => {
+  return object({
+    kind: literal('json')
+  });
+};
+
+const schemaType = typeOfSchema(createSchema);
+/** @internal */
+export type JsonLayoutConfigType = typeof schemaType;
+
+/**
+ * Layout that just converts `LogRecord` into JSON string.
+ * @internal
+ */
+export class JsonLayout implements Layout {
+  static createConfigSchema = createSchema;
+
+  format({ timestamp, level, context, message, error, meta }: LogRecord): string {
+    return JSON.stringify({
+      '@timestamp': timestamp.toISOString(),
+      level: level.id.toUpperCase(),
+      context,
+      message,
+      error: error && error.message,
+      meta
+    });
+  }
+}

platform/logging/layouts/Layouts.ts

@@ -1,8 +1,10 @@
+import { assertNever } from '../../lib/utils';
 import { Schema } from '../../types';
+import { JsonLayout, JsonLayoutConfigType } from './JsonLayout';
 import { PatternLayout, PatternLayoutConfigType } from './PatternLayout';
 import { LogRecord } from '../LogRecord';
 
-type LayoutConfigType = PatternLayoutConfigType;
+type LayoutConfigType = PatternLayoutConfigType | JsonLayoutConfigType;
 
 /**
  * Entity that can format `LogRecord` instance into a string.
@@ -15,7 +17,12 @@ export interface Layout {
 /** @internal */
 export class Layouts {
   static createConfigSchema(schema: Schema) {
-    return PatternLayout.createConfigSchema(schema);
+    const { oneOf } = schema;
+
+    return oneOf([
+      JsonLayout.createConfigSchema(schema),
+      PatternLayout.createConfigSchema(schema)
+    ]);
   }
 
   /**
@@ -24,6 +31,13 @@ export class Layouts {
    * @returns Fully constructed `Layout` instance.
    */
   static create(config: LayoutConfigType): Layout {
-    return new PatternLayout(config.pattern, config.highlight);
+    switch (config.kind) {
+      case 'json':
+        return new JsonLayout();
+      case 'pattern':
+        return new PatternLayout(config.pattern, config.highlight);
+      default:
+        return assertNever(config);
+    }
   }
 }

platform/logging/layouts/__tests__/JsonLayout.test.ts

@@ -0,0 +1,59 @@
+import * as mockSchema from '../../../lib/schema';
+
+import { LogLevel } from '../../LogLevel';
+import { LogRecord } from '../../LogRecord';
+import { JsonLayout } from '../JsonLayout';
+
+const records: LogRecord[] = [
+  {
+    timestamp: new Date(2012, 1, 1),
+    message: 'message-1',
+    context: 'context-1',
+    error: new Error('Some error message'),
+    level: LogLevel.Fatal
+  },
+  {
+    timestamp: new Date(2012, 1, 1),
+    message: 'message-2',
+    context: 'context-2',
+    level: LogLevel.Error
+  },
+  {
+    timestamp: new Date(2012, 1, 1),
+    message: 'message-3',
+    context: 'context-3',
+    level: LogLevel.Warn
+  },
+  {
+    timestamp: new Date(2012, 1, 1),
+    message: 'message-4',
+    context: 'context-4',
+    level: LogLevel.Debug
+  },
+  {
+    timestamp: new Date(2012, 1, 1),
+    message: 'message-5',
+    context: 'context-5',
+    level: LogLevel.Info
+  },
+  {
+    timestamp: new Date(2012, 1, 1),
+    message: 'message-6',
+    context: 'context-6',
+    level: LogLevel.Trace
+  }
+];
+
+test('`createConfigSchema()` creates correct schema.', () => {
+  const layoutSchema = JsonLayout.createConfigSchema(mockSchema);
+
+  expect(layoutSchema.validate({ kind: 'json' })).toEqual({ kind: 'json' });
+});
+
+test('`format()` correctly formats record.', () => {
+  const layout = new JsonLayout();
+
+  for (const record of records) {
+    expect(layout.format(record)).toMatchSnapshot();
+  }
+});

platform/logging/layouts/__tests__/Layouts.test.ts

@@ -1,8 +1,9 @@
 import * as mockSchema from '../../../lib/schema';
+import { JsonLayout } from '../JsonLayout';
 import { PatternLayout } from '../PatternLayout';
 import { Layouts } from '../Layouts';
 
-test('`createConfigSchema()` creates correct schema.', () => {
+test('`createConfigSchema()` creates correct schema for `pattern` layout.', () => {
   const layoutsSchema = Layouts.createConfigSchema(mockSchema);
   const validConfigWithOptional = { kind: 'pattern' };
   expect(layoutsSchema.validate(validConfigWithOptional)).toEqual({
@@ -22,18 +23,25 @@ test('`createConfigSchema()` creates correct schema.', () => {
     highlight: true
   });
 
-  const wrongConfig1 = { kind: 'json' };
-  expect(() => layoutsSchema.validate(wrongConfig1)).toThrow();
-
   const wrongConfig2 = { kind: 'pattern', pattern: 1 };
   expect(() => layoutsSchema.validate(wrongConfig2)).toThrow();
 });
 
+test('`createConfigSchema()` creates correct schema for `json` layout.', () => {
+  const layoutsSchema = Layouts.createConfigSchema(mockSchema);
+
+  const validConfig = { kind: 'json' };
+  expect(layoutsSchema.validate(validConfig)).toEqual({ kind: 'json' });
+});
+
 test('`create()` creates correct layout.', () => {
   const patternLayout = Layouts.create({
     kind: 'pattern',
     pattern: '[{timestamp}][{level}][{context}] {message}',
     highlight: false
   });
   expect(patternLayout).toBeInstanceOf(PatternLayout);
+
+  const jsonLayout = Layouts.create({ kind: 'json' });
+  expect(jsonLayout).toBeInstanceOf(JsonLayout);
 });

platform/logging/layouts/__tests__/PatternLayout.test.ts

@@ -9,7 +9,7 @@ const records: LogRecord[] = [
     timestamp: new Date(2012, 1, 1),
     message: 'message-1',
     context: 'context-1',
-    error: new Error('Error'),
+    error: new Error('Some error message'),
     level: LogLevel.Fatal
   },
   {
@@ -76,12 +76,7 @@ test('`format()` correctly formats record with full pattern.', () => {
   const layout = new PatternLayout();
 
   for (const record of records) {
-    const { timestamp, level, context, message } = record;
-    const formattedLevel = level.id.toUpperCase().padEnd(5);
-
-    expect(layout.format(record)).toBe(
-      `[${timestamp.toISOString()}][${formattedLevel}][${context}] ${message}`
-    );
+    expect(layout.format(record)).toMatchSnapshot();
   }
 });
 

platform/logging/layouts/__tests__/__snapshots__/JsonLayout.test.ts.snap

@@ -0,0 +1,13 @@
+// Jest Snapshot v1, https://goo.gl/fbAQLP
+
+exports[`\`format()\` correctly formats record. 1`] = `"{\\"timestamp\\":\\"2012-01-31T23:00:00.000Z\\",\\"message\\":\\"message-1\\",\\"context\\":\\"context-1\\",\\"error\\":\\"Some error message\\",\\"level\\":{\\"id\\":\\"fatal\\",\\"value\\":2}}"`;
+
+exports[`\`format()\` correctly formats record. 2`] = `"{\\"timestamp\\":\\"2012-01-31T23:00:00.000Z\\",\\"message\\":\\"message-2\\",\\"context\\":\\"context-2\\",\\"level\\":{\\"id\\":\\"error\\",\\"value\\":3}}"`;
+
+exports[`\`format()\` correctly formats record. 3`] = `"{\\"timestamp\\":\\"2012-01-31T23:00:00.000Z\\",\\"message\\":\\"message-3\\",\\"context\\":\\"context-3\\",\\"level\\":{\\"id\\":\\"warn\\",\\"value\\":4}}"`;
+
+exports[`\`format()\` correctly formats record. 4`] = `"{\\"timestamp\\":\\"2012-01-31T23:00:00.000Z\\",\\"message\\":\\"message-4\\",\\"context\\":\\"context-4\\",\\"level\\":{\\"id\\":\\"debug\\",\\"value\\":6}}"`;
+
+exports[`\`format()\` correctly formats record. 5`] = `"{\\"timestamp\\":\\"2012-01-31T23:00:00.000Z\\",\\"message\\":\\"message-5\\",\\"context\\":\\"context-5\\",\\"level\\":{\\"id\\":\\"info\\",\\"value\\":5}}"`;
+
+exports[`\`format()\` correctly formats record. 6`] = `"{\\"timestamp\\":\\"2012-01-31T23:00:00.000Z\\",\\"message\\":\\"message-6\\",\\"context\\":\\"context-6\\",\\"level\\":{\\"id\\":\\"trace\\",\\"value\\":7}}"`;