Skip to content

Commit

Permalink
Browse files Browse the repository at this point in the history
[6.0] [Logging] more tests and added robustness to log formatting (#1…
…5035) (#15163) (#15310)

* [Logging] more tests and added robustness to log formatting (#15035)

* [Logging] more tests and added robustness to log formatting

* empty string for default error message, along with TODO question comment

* try to use stack trace from error when there is no error message

* simplify using the stack as the default error message

* destructure get from lodash

* default no-message to static string instead of error stack

* fix tests

* remove ineligible useUTC tests
  • Loading branch information
tsullivan committed Nov 30, 2017
1 parent 2c0c0bd commit 634bf10
Show file tree
Hide file tree
Showing 2 changed files with 197 additions and 14 deletions.
180 changes: 180 additions & 0 deletions src/server/logging/__tests__/log_format_json.js
@@ -0,0 +1,180 @@
import moment from 'moment';
import expect from 'expect.js';

import {
createListStream,
createPromiseFromStreams,
} from '../../../utils';

import KbnLoggerJsonFormat from '../log_format_json';

const time = +moment('2010-01-01T05:15:59Z', moment.ISO_8601);

const makeEvent = eventType => ({
event: eventType,
timestamp: time,
});

describe('KbnLoggerJsonFormat', () => {
const config = {};

describe('event types and messages', () => {
let format;
beforeEach(() => {
format = new KbnLoggerJsonFormat(config);
});

it('log', async () => {
const result = await createPromiseFromStreams([
createListStream([makeEvent('log')]),
format
]);
const { type, message } = JSON.parse(result);

expect(type).to.be('log');
expect(message).to.be('undefined');
});

it('response', async () => {
const event = {
...makeEvent('response'),
statusCode: 200,
contentLength: 800,
responseTime: 12000,
method: 'GET',
path: '/path/to/resource',
responsePayload: '1234567879890',
source: {
remoteAddress: '127.0.0.1',
userAgent: 'Test Thing',
referer: 'elastic.co',
}
};
const result = await createPromiseFromStreams([
createListStream([event]),
format
]);
const { type, method, statusCode, message } = JSON.parse(result);

expect(type).to.be('response');
expect(method).to.be('GET');
expect(statusCode).to.be(200);
expect(message).to.be('GET /path/to/resource 200 12000ms - 13.0B');
});

it('ops', async () => {
const event = {
...makeEvent('ops'),
os: {
load: [1, 1, 2]
}
};
const result = await createPromiseFromStreams([
createListStream([event]),
format
]);
const { type, message } = JSON.parse(result);

expect(type).to.be('ops');
expect(message).to.be('memory: 0.0B uptime: 0:00:00 load: [1.00 1.00 2.00] delay: 0.000');
});

describe('errors', () => {
it('error type', async () => {
const event = {
...makeEvent('error'),
error: {
message: 'test error 0'
}
};
const result = await createPromiseFromStreams([
createListStream([event]),
format
]);
const { level, message, error } = JSON.parse(result);

expect(level).to.be('error');
expect(message).to.be('test error 0');
expect(error).to.eql({ message: 'test error 0' });
});

it('with no message', async () => {
const event = {
event: 'error',
error: {}
};
const result = await createPromiseFromStreams([
createListStream([event]),
format
]);
const { level, message, error } = JSON.parse(result);

expect(level).to.be('error');
expect(message).to.be('Unknown error (no message)');
expect(error).to.eql({});
});

it('event data instanceof Error', async () => {
const event = {
data: new Error('test error 2'),
};
const result = await createPromiseFromStreams([
createListStream([event]),
format
]);
const { level, message, error } = JSON.parse(result);

expect(level).to.be('error');
expect(message).to.be('test error 2');

expect(error.message).to.be(event.data.message);
expect(error.name).to.be(event.data.name);
expect(error.stack).to.be(event.data.stack);
expect(error.code).to.be(event.data.code);
expect(error.signal).to.be(event.data.signal);
});

it('event data instanceof Error - fatal', async () => {
const event = {
data: new Error('test error 2'),
tags: ['fatal', 'tag2']
};
const result = await createPromiseFromStreams([
createListStream([event]),
format
]);
const { tags, level, message, error } = JSON.parse(result);

expect(tags).to.eql(['fatal', 'tag2']);
expect(level).to.be('fatal');
expect(message).to.be('test error 2');

expect(error.message).to.be(event.data.message);
expect(error.name).to.be(event.data.name);
expect(error.stack).to.be(event.data.stack);
expect(error.code).to.be(event.data.code);
expect(error.signal).to.be(event.data.signal);
});

it('event data instanceof Error, no message', async () => {
const event = {
data: new Error(''),
};
const result = await createPromiseFromStreams([
createListStream([event]),
format
]);
const { level, message, error } = JSON.parse(result);

expect(level).to.be('error');
expect(message).to.be('Unknown error object (no message)');

expect(error.message).to.be(event.data.message);
expect(error.name).to.be(event.data.name);
expect(error.stack).to.be(event.data.stack);
expect(error.code).to.be(event.data.code);
expect(error.signal).to.be(event.data.signal);
});
});
});
});
31 changes: 17 additions & 14 deletions src/server/logging/log_format.js
@@ -1,14 +1,14 @@
import Stream from 'stream';
import moment from 'moment';
import _ from 'lodash';
import { get, _ } from 'lodash';
import numeral from '@elastic/numeral';
import ansicolors from 'ansicolors';
import stringify from 'json-stringify-safe';
import querystring from 'querystring';
import applyFiltersToKeys from './apply_filters_to_keys';
import { inspect } from 'util';

function serializeError(err) {
function serializeError(err = {}) {
return {
message: err.message,
name: err.name,
Expand Down Expand Up @@ -60,13 +60,14 @@ module.exports = class TransformObjStream extends Stream.Transform {
'statusCode'
]));

const source = get(event, 'source', {});
data.req = {
url: event.path,
method: event.method,
method: event.method || '',
headers: event.headers,
remoteAddress: event.source.remoteAddress,
userAgent: event.source.remoteAddress,
referer: event.source.referer
remoteAddress: source.remoteAddress,
userAgent: source.remoteAddress,
referer: source.referer
};

let contentLength = 0;
Expand All @@ -85,8 +86,7 @@ module.exports = class TransformObjStream extends Stream.Transform {
const query = querystring.stringify(event.query);
if (query) data.req.url += '?' + query;


data.message = data.req.method.toUpperCase() + ' ';
data.message = data.req.method.toUpperCase() + ' ';
data.message += data.req.url;
data.message += ' ';
data.message += levelColor(data.res.statusCode);
Expand All @@ -102,30 +102,33 @@ module.exports = class TransformObjStream extends Stream.Transform {
'load'
]));
data.message = ansicolors.brightBlack('memory: ');
data.message += numeral(data.proc.mem.heapUsed).format('0.0b');
data.message += numeral(get(data, 'proc.mem.heapUsed')).format('0.0b');
data.message += ' ';
data.message += ansicolors.brightBlack('uptime: ');
data.message += numeral(data.proc.uptime).format('00:00:00');
data.message += numeral(get(data, 'proc.uptime')).format('00:00:00');
data.message += ' ';
data.message += ansicolors.brightBlack('load: [');
data.message += data.os.load.map(function (val) {
data.message += get(data, 'os.load', []).map(function (val) {
return numeral(val).format('0.00');
}).join(' ');
data.message += ansicolors.brightBlack(']');
data.message += ' ';
data.message += ansicolors.brightBlack('delay: ');
data.message += numeral(data.proc.delay).format('0.000');
data.message += numeral(get(data, 'proc.delay')).format('0.000');
}
else if (data.type === 'error') {
data.level = 'error';
data.message = event.error.message;
data.error = serializeError(event.error);
data.url = event.url;
const message = get(event, 'error.message');
data.message = message || 'Unknown error (no message)';
}
else if (event.data instanceof Error) {
data.type = 'error';
data.level = _.contains(event.tags, 'fatal') ? 'fatal' : 'error';
data.message = event.data.message;
data.error = serializeError(event.data);
const message = get(event, 'data.message');
data.message = message || 'Unknown error object (no message)';
}
else if (_.isPlainObject(event.data) && event.data.tmpl) {
_.assign(data, event.data);
Expand Down

0 comments on commit 634bf10

Please sign in to comment.