Skip to content

Commit

Permalink
[Response Ops][Actions] Logging errors from the mustache lambda forma…
Browse files Browse the repository at this point in the history 
…t functions (elastic#176014)

Resolves elastic#173972

## Summary

Changing to log and return error string instead of throwing error inside
the mustache format lambda functions. When an error occurs, the lambda
will return the error message. This allows the rest of the action
message to be rendered, while giving the user some indication an error
occurred and logging the error in a way that is discoverable in the
logs.

## To verify

Create a rule and add a message like:

```
{{alert.id}} - {{#FormatDate}} {{{context.nope}}}  ; America/New_York ; dddd MMM Do YYYY HH:mm:ss.SSS {{/FormatDate}}
```

When the rule runs and triggers and alert, you should see the alert ID
in the notification message along with a `date is empty` message and an
error log indicating that the date formatting was unsuccessful due to
empty date.

---------

Co-authored-by: kibanamachine <[email protected]>
  • Loading branch information
@ymao1 @kibanamachine
ymao1 and kibanamachine authored Feb 5, 2024
1 parent 450f9f6 commit 11593f0
Show file tree
Hide file tree
Showing 33 changed files with 404 additions and 194 deletions.
82 changes: 55 additions & 27 deletions x-pack/plugins/actions/server/lib/mustache_lambdas.test.ts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -6,18 +6,26 @@
*/

import dedent from 'dedent';

import { loggingSystemMock } from '@kbn/core/server/mocks';
import { renderMustacheString } from './mustache_renderer';

const logger = loggingSystemMock.create().get();

describe('mustache lambdas', () => {
beforeEach(() => {
jest.resetAllMocks();
});

describe('FormatDate', () => {
it('date with defaults is successful', () => {
const timeStamp = '2022-11-29T15:52:44Z';
const template = dedent`
{{#FormatDate}} {{timeStamp}} {{/FormatDate}}
`.trim();

expect(renderMustacheString(template, { timeStamp }, 'none')).toEqual('2022-11-29 03:52pm');
expect(renderMustacheString(logger, template, { timeStamp }, 'none')).toEqual(
'2022-11-29 03:52pm'
);
});

it('date with a time zone is successful', () => {
Expand All @@ -26,7 +34,9 @@ describe('mustache lambdas', () => {
{{#FormatDate}} {{timeStamp}} ; America/New_York {{/FormatDate}}
`.trim();

expect(renderMustacheString(template, { timeStamp }, 'none')).toEqual('2022-11-29 10:52am');
expect(renderMustacheString(logger, template, { timeStamp }, 'none')).toEqual(
'2022-11-29 10:52am'
);
});

it('date with a format is successful', () => {
Expand All @@ -35,7 +45,7 @@ describe('mustache lambdas', () => {
{{#FormatDate}} {{timeStamp}} ;; dddd MMM Do YYYY HH:mm:ss.SSS {{/FormatDate}}
`.trim();

expect(renderMustacheString(template, { timeStamp }, 'none')).toEqual(
expect(renderMustacheString(logger, template, { timeStamp }, 'none')).toEqual(
'Tuesday Nov 29th 2022 15:52:44.000'
);
});
Expand All @@ -46,41 +56,48 @@ describe('mustache lambdas', () => {
{{#FormatDate}} {{timeStamp}};America/New_York;dddd MMM Do YYYY HH:mm:ss.SSS {{/FormatDate}}
`.trim();

expect(renderMustacheString(template, { timeStamp }, 'none').trim()).toEqual(
expect(renderMustacheString(logger, template, { timeStamp }, 'none').trim()).toEqual(
'Tuesday Nov 29th 2022 10:52:44.000'
);
});

it('empty date produces error', () => {
it('empty date logs and returns error string', () => {
const timeStamp = '';
const template = dedent`
{{#FormatDate}} {{/FormatDate}}
`.trim();

expect(renderMustacheString(template, { timeStamp }, 'none').trim()).toEqual(
'error rendering mustache template "{{#FormatDate}} {{/FormatDate}}": date is empty'
expect(renderMustacheString(logger, template, { timeStamp }, 'none').trim()).toEqual(
'date is empty'
);
expect(logger.warn).toHaveBeenCalledWith(`mustache render error: date is empty`);
});

it('invalid date produces error', () => {
it('invalid date logs and returns error string', () => {
const timeStamp = 'this is not a d4t3';
const template = dedent`
{{#FormatDate}}{{timeStamp}}{{/FormatDate}}
`.trim();

expect(renderMustacheString(template, { timeStamp }, 'none').trim()).toEqual(
'error rendering mustache template "{{#FormatDate}}{{timeStamp}}{{/FormatDate}}": invalid date "this is not a d4t3"'
expect(renderMustacheString(logger, template, { timeStamp }, 'none').trim()).toEqual(
'invalid date "this is not a d4t3"'
);
expect(logger.warn).toHaveBeenCalledWith(
`mustache render error: invalid date "this is not a d4t3"`
);
});

it('invalid timezone produces error', () => {
it('invalid timezone logs and returns error string', () => {
const timeStamp = '2023-04-10T23:52:39';
const template = dedent`
{{#FormatDate}}{{timeStamp}};NotATime Zone!{{/FormatDate}}
`.trim();

expect(renderMustacheString(template, { timeStamp }, 'none').trim()).toEqual(
'error rendering mustache template "{{#FormatDate}}{{timeStamp}};NotATime Zone!{{/FormatDate}}": unknown timeZone value "NotATime Zone!"'
expect(renderMustacheString(logger, template, { timeStamp }, 'none').trim()).toEqual(
'unknown timeZone value "NotATime Zone!"'
);
expect(logger.warn).toHaveBeenCalledWith(
`mustache render error: unknown timeZone value "NotATime Zone!"`
);
});

Expand All @@ -92,7 +109,7 @@ describe('mustache lambdas', () => {

// not clear how to force an error, it pretty much does something with
// ANY string
expect(renderMustacheString(template, { timeStamp }, 'none').trim()).toEqual(
expect(renderMustacheString(logger, template, { timeStamp }, 'none').trim()).toEqual(
'gamrbamg2' // a => am/pm (so am here); e => day of week
);
});
Expand All @@ -114,11 +131,11 @@ describe('mustache lambdas', () => {
{{/context}}
`.trim();

const result = renderMustacheString(template, vars, 'none');
const result = renderMustacheString(logger, template, vars, 'none');
expect(result).toEqual(`1\n2\n3\n`);
});

it('invalid expression produces error', () => {
it('invalid expression logs and returns error string', () => {
const vars = {
context: {
a: { b: 1 },
Expand All @@ -129,9 +146,12 @@ describe('mustache lambdas', () => {
{{#EvalMath}} ) 1 ++++ 0 ( {{/EvalMath}}
`.trim();

const result = renderMustacheString(template, vars, 'none');
const result = renderMustacheString(logger, template, vars, 'none');
expect(result).toEqual(
`error rendering mustache template "{{#EvalMath}} ) 1 ++++ 0 ( {{/EvalMath}}": error evaluating tinymath expression ") 1 ++++ 0 (": Failed to parse expression. Expected "(", function, literal, or whitespace but ")" found.`
'error evaluating tinymath expression ") 1 ++++ 0 (": Failed to parse expression. Expected "(", function, literal, or whitespace but ")" found.'
);
expect(logger.warn).toHaveBeenCalledWith(
`mustache render error: error evaluating tinymath expression ") 1 ++++ 0 (": Failed to parse expression. Expected "(", function, literal, or whitespace but ")" found.`
);
});
});
Expand All @@ -147,7 +167,7 @@ describe('mustache lambdas', () => {
const hjson = `
{
# specify rate in requests/second (because comments are helpful!)
rate: 1000
rate: 1000
a: {{context.a}}
a_b: {{context.a.b}}
Expand All @@ -166,7 +186,7 @@ describe('mustache lambdas', () => {
{{#ParseHjson}} ${hjson} {{/ParseHjson}}
`.trim();

const result = renderMustacheString(template, vars, 'none');
const result = renderMustacheString(logger, template, vars, 'none');
expect(JSON.parse(result)).toMatchInlineSnapshot(`
Object {
"a": Object {
Expand All @@ -189,13 +209,18 @@ describe('mustache lambdas', () => {
`);
});

it('renders an error message on parse errors', () => {
it('logs an error message and returns error string on parse errors', () => {
const template = dedent`
{{#ParseHjson}} [1,2,3,,] {{/ParseHjson}}
`.trim();

const result = renderMustacheString(template, {}, 'none');
expect(result).toMatch(/^error rendering mustache template .*/);
const result = renderMustacheString(logger, template, {}, 'none');
expect(result).toEqual(
`error parsing Hjson \"[1,2,3,,]\": Found a punctuator character ',' when expecting a quoteless string (check your syntax) at line 1,7 >>>1,2,3,,] ...`
);
expect(logger.warn).toHaveBeenCalledWith(
`mustache render error: error parsing Hjson \"[1,2,3,,]\": Found a punctuator character ',' when expecting a quoteless string (check your syntax) at line 1,7 >>>1,2,3,,] ...`
);
});
});

Expand All @@ -206,16 +231,19 @@ describe('mustache lambdas', () => {
{{#FormatNumber}} {{num}}; en-US; style: currency, currency: EUR {{/FormatNumber}}
`.trim();

expect(renderMustacheString(template, { num }, 'none')).toEqual('€42.00');
expect(renderMustacheString(logger, template, { num }, 'none')).toEqual('€42.00');
});

it('renders an error message on errors', () => {
it('logs an error message and returns empty string on errors', () => {
const num = 'nope;;';
const template = dedent`
{{#FormatNumber}} {{num}} {{/FormatNumber}}
`.trim();

expect(renderMustacheString(template, { num }, 'none')).toEqual(`invalid number: 'nope'`);
expect(renderMustacheString(logger, template, { num }, 'none')).toEqual(
`invalid number: 'nope'`
);
expect(logger.warn).toHaveBeenCalledWith(`mustache render error: invalid number: 'nope'`);
});
});
});
50 changes: 31 additions & 19 deletions x-pack/plugins/actions/server/lib/mustache_lambdas.ts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -8,6 +8,7 @@
import * as tinymath from '@kbn/tinymath';
import { parse as hjsonParse } from 'hjson';
import moment from 'moment-timezone';
import { Logger } from '@kbn/core/server';

import { formatNumber } from './number_formatter';

Expand All @@ -16,96 +17,102 @@ type Variables = Record<string, unknown>;
const DefaultDateTimeZone = 'UTC';
const DefaultDateFormat = 'YYYY-MM-DD hh:mma';

export function getMustacheLambdas(): Variables {
return getLambdas();
export function getMustacheLambdas(logger: Logger): Variables {
return getLambdas(logger);
}

const TimeZoneSet = new Set(moment.tz.names());

type RenderFn = (text: string) => string;

function getLambdas() {
function getLambdas(logger: Logger) {
return {
EvalMath: () =>
// mustache invokes lamdas with `this` set to the current "view" (variables)
function (this: Variables, text: string, render: RenderFn) {
return evalMath(this, render(text.trim()));
return evalMath(this, render(text.trim()), logger);
},
ParseHjson: () =>
function (text: string, render: RenderFn) {
return parseHjson(render(text.trim()));
return parseHjson(render(text.trim()), logger);
},
FormatDate: () =>
function (text: string, render: RenderFn) {
const dateString = render(text.trim()).trim();
return formatDate(dateString);
return formatDate(dateString, logger);
},
FormatNumber: () =>
function (text: string, render: RenderFn) {
const numberString = render(text.trim()).trim();
return formatNumber(numberString);
return formatNumber(logger, numberString);
},
};
}

function evalMath(vars: Variables, o: unknown): string {
function evalMath(vars: Variables, o: unknown, logger: Logger): string {
const expr = `${o}`;
try {
const result = tinymath.evaluate(expr, vars);
return `${result}`;
} catch (err) {
throw new Error(`error evaluating tinymath expression "${expr}": ${err.message}`);
return logAndReturnErr(
logger,
`error evaluating tinymath expression "${expr}": ${err.message}`
);
}
}

function parseHjson(o: unknown): string {
function parseHjson(o: unknown, logger: Logger): string {
const hjsonObject = `${o}`;
let object: unknown;

try {
object = hjsonParse(hjsonObject);
} catch (err) {
throw new Error(`error parsing Hjson "${hjsonObject}": ${err.message}`);
return logAndReturnErr(logger, `error parsing Hjson "${hjsonObject}": ${err.message}`);
}

return JSON.stringify(object);
}

function formatDate(dateString: unknown): string {
function formatDate(dateString: unknown, logger: Logger): string {
const { date, timeZone, format } = splitDateString(`${dateString}`);

if (date === '') {
throw new Error(`date is empty`);
return logAndReturnErr(logger, `date is empty`);
}

if (isNaN(new Date(date).valueOf())) {
throw new Error(`invalid date "${date}"`);
return logAndReturnErr(logger, `invalid date "${date}"`);
}

let mDate: moment.Moment;
try {
mDate = moment(date);
if (!mDate.isValid()) {
throw new Error(`date is invalid`);
return logAndReturnErr(logger, `invalid date "${date}"`);
}
} catch (err) {
throw new Error(`error evaluating moment date "${date}": ${err.message}`);
return logAndReturnErr(logger, `error evaluating moment date "${date}": ${err.message}`);
}

if (!TimeZoneSet.has(timeZone)) {
throw new Error(`unknown timeZone value "${timeZone}"`);
return logAndReturnErr(logger, `unknown timeZone value "${timeZone}"`);
}

try {
mDate.tz(timeZone);
} catch (err) {
throw new Error(`error evaluating moment timeZone "${timeZone}": ${err.message}`);
return logAndReturnErr(
logger,
`error evaluating moment timeZone "${timeZone}": ${err.message}`
);
}

try {
return mDate.format(format);
} catch (err) {
throw new Error(`error evaluating moment format "${format}": ${err.message}`);
return logAndReturnErr(logger, `error evaluating moment format "${format}": ${err.message}`);
}
}

Expand All @@ -118,3 +125,8 @@ function splitDateString(dateString: string) {
format: format || DefaultDateFormat,
};
}

function logAndReturnErr(logger: Logger, errMessage: string): string {
logger.warn(`mustache render error: ${errMessage}`);
return errMessage;
}
Loading

0 comments on commit 11593f0

Please sign in to comment.