diff --git a/packages/server/logging/expressLogging.ts b/packages/server/logging/expressLogging.ts index 04851ba237..1805ea54f3 100644 --- a/packages/server/logging/expressLogging.ts +++ b/packages/server/logging/expressLogging.ts @@ -74,7 +74,7 @@ export const LoggingExpressMiddleware = HttpLogger({ }, customSuccessMessage() { - return '{requestPath} request {requestStatus} in {responseTime} ms' + return '{requestPath} request {requestStatus} with status code {responseStatusCode} in {responseTime} ms' }, customSuccessObject(req, res, val: Record) { @@ -83,22 +83,25 @@ export const LoggingExpressMiddleware = HttpLogger({ const requestStatus = isCompleted ? (isError ? 'errored' : 'completed') : 'aborted' const requestPath = getRequestPath(req) || 'unknown' const country = req.headers['cf-ipcountry'] as Optional + const responseStatusCode = res.statusCode return { ...val, requestStatus, requestPath, + responseStatusCode, country, err: req.context?.err } }, customErrorMessage() { - return '{requestPath} request {requestStatus} in {responseTime} ms' + return '{requestPath} request {requestStatus} with status code {responseStatusCode} in {responseTime} ms' }, - customErrorObject(req, _res, err, val: Record) { + customErrorObject(req, res, err, val: Record) { const requestStatus = 'failed' const requestPath = getRequestPath(req) || 'unknown' + const responseStatusCode = res.statusCode const country = req.headers['cf-ipcountry'] as Optional let e: Error | undefined = undefined if (err) e = ensureError(err) @@ -108,6 +111,7 @@ export const LoggingExpressMiddleware = HttpLogger({ ...val, requestStatus, requestPath, + responseStatusCode, country, err: e } diff --git a/packages/server/modules/core/rest/defaultErrorHandler.ts b/packages/server/modules/core/rest/defaultErrorHandler.ts index 155a8a30ae..0efdfb976a 100644 --- a/packages/server/modules/core/rest/defaultErrorHandler.ts +++ b/packages/server/modules/core/rest/defaultErrorHandler.ts @@ -1,6 +1,7 @@ import { BaseError } from '@/modules/shared/errors' import { isDevEnv } from '@/modules/shared/helpers/envHelper' import { getCause } from '@/modules/shared/helpers/errorHelper' +import { prettifyMessage } from '@/modules/shared/utils/messageTemplate' import { Optional, ensureError } from '@speckle/shared' import { ErrorRequestHandler } from 'express' import { get, isNumber } from 'lodash' @@ -21,10 +22,11 @@ const resolveStatusCode = (e: Error): number => { const resolveErrorInfo = (e: Error): Record => { const cause = getCause(e) - const message = e.message + let message = e.message let info = undefined if (e instanceof BaseError) { info = e.info() + message = prettifyMessage(info, e.message) } return { diff --git a/packages/server/modules/shared/utils/messageTemplate.spec.ts b/packages/server/modules/shared/utils/messageTemplate.spec.ts new file mode 100644 index 0000000000..ed3d667cbe --- /dev/null +++ b/packages/server/modules/shared/utils/messageTemplate.spec.ts @@ -0,0 +1,97 @@ +import { expect } from 'chai' +import { prettifyMessage } from '@/modules/shared/utils/messageTemplate' + +describe('messageTemplate', () => { + describe('no templating', () => { + it('should return the message as is', () => { + const messageTemplate = 'This is a message' + const values = {} + const result = prettifyMessage(values, messageTemplate) + expect(result).to.equal('This is a message') + }) + it('should return the message as is, despite the values object', () => { + const messageTemplate = 'This is a message' + const values = { key: 'value' } + const result = prettifyMessage(values, messageTemplate) + expect(result).to.equal('This is a message') + }) + it.skip('should return the message as is, as brackets are escaped', () => { + const messageTemplate = 'This is a message with escaped {{key}}' + const values = { key: 'value' } + const result = prettifyMessage(values, messageTemplate) + expect(result).to.equal('This is a message with escaped \\{key\\}') + }) + }) + describe('simple templating', () => { + it('can handle one string value', () => { + const messageTemplate = 'This is a {key}' + const values = { key: 'value' } + const result = prettifyMessage(values, messageTemplate) + expect(result).to.equal('This is a value') + }) + it('can handle multiple string values', () => { + const messageTemplate = 'This is {key1} and {key2}' + const values = { key1: 'value1', key2: 'value2' } + const result = prettifyMessage(values, messageTemplate) + expect(result).to.equal('This is value1 and value2') + }) + it('can handle array value', () => { + const messageTemplate = 'This is {key}' + const values = { key: ['value1', 'value2'] } + const result = prettifyMessage(values, messageTemplate) + expect(result).to.equal('This is ["value1","value2"]') + }) + it('can handle object value', () => { + const messageTemplate = 'This is {key}' + const values = { key: { subKey: 'value' } } + const result = prettifyMessage(values, messageTemplate) + expect(result).to.equal('This is {"subKey":"value"}') + }) + it('can handle missing value', () => { + const messageTemplate = 'This is {key}' + const values = {} + const result = prettifyMessage(values, messageTemplate) + expect(result).to.equal('This is ') + }) + }) + describe('nested templating', () => { + it('can handle missing value', () => { + const messageTemplate = 'This is {key.subKey}' + const values = {} + const result = prettifyMessage(values, messageTemplate) + expect(result).to.equal('This is ') + }) + it('can handle missing subkey', () => { + const messageTemplate = 'This is {key.subKey}' + const values = { key: {} } + const result = prettifyMessage(values, messageTemplate) + expect(result).to.equal('This is ') + }) + }) + describe('conditional templating', () => { + it('can handle conditional with key inside', () => { + const messageTemplate = 'This is {if key}{key}{end}' + const values = { key: 'propertyValue' } + const result = prettifyMessage(values, messageTemplate) + expect(result).to.equal('This is propertyValue') + }) + it('can handle conditional with random string inside', () => { + const messageTemplate = 'This is {if key}my lovely horse{end}' + const values = { key: 'propertyValue' } + const result = prettifyMessage(values, messageTemplate) + expect(result).to.equal('This is my lovely horse') + }) + it('can handle missing value with line trimming', () => { + const messageTemplate = 'This is {if key}value{end}' + const values = {} + const result = prettifyMessage(values, messageTemplate) + expect(result).to.equal('This is') //lines are trimmed + }) + it('can handle missing value without line trimming', () => { + const messageTemplate = 'This is {if key}value{end} without line trimming' + const values = {} + const result = prettifyMessage(values, messageTemplate) + expect(result).to.equal('This is without line trimming') + }) + }) +}) diff --git a/packages/server/modules/shared/utils/messageTemplate.ts b/packages/server/modules/shared/utils/messageTemplate.ts new file mode 100644 index 0000000000..41c6d3466d --- /dev/null +++ b/packages/server/modules/shared/utils/messageTemplate.ts @@ -0,0 +1,134 @@ +/** + * Replaces a string in pino's template format with the provided values, returning the complete message. + * Note that this is similar but is not the same as messagetemplates.org format. + * To template a string, place the property name between curly brackets. e.g. {key}. + * An improvement over messagetemplates.org is that you can use nested keys e.g. {key.nestedKey.subKey} to deeply access within objects. + * An improvement over messagetemplates.org is that you can use conditional formatting, e.g. {if key}some text{end}. Note that {else} statements are not supported. + * Limitation: Brackets cannot be escaped. + * Limitation: Cannot prefix with @ or $ to control how a property is captured + * Limitation: Property names cannot be suffixed with any optional format, e.g. :000, to control how the property is rendered + * + * This code is modified from: + * - https://github.com/pinojs/pino-pretty/blob/master/lib/utils/prettify-message.js + * - https://github.com/pinojs/pino-pretty/blob/master/lib/utils/get-property-value.js + * - https://github.com/pinojs/pino-pretty/blob/master/lib/utils/interpret-conditionals.js + * - https://github.com/pinojs/pino-pretty/blob/master/lib/utils/split-property-key.js + * Originally licensed under an MIT License: https://github.com/pinojs/pino-pretty?tab=MIT-1-ov-file#readme + */ +export const prettifyMessage = (values: Record, message: string) => { + const parsedMessageFormat = interpretConditionals(message, values) + + const msg = String(parsedMessageFormat).replace(/{([^{}]+)}/g, function (match, p1) { + // Parse nested key access, e.g. `{keyA.subKeyB}`. + return getPropertyValue(values, p1) || '' + }) + + return msg +} + +/** + * Gets a specified property from an object if it exists. + * + * @param {object} obj The object to be searched. + * @param {string|string[]} property A string, or an array of strings, identifying + * the property to be retrieved from the object. + * Accepts nested properties delimited by a `.`. + * Delimiter can be escaped to preserve property names that contain the delimiter. + * e.g. `'prop1.prop2'` or `'prop2\.domain\.corp.prop2'`. + * + * @returns {*} + */ +const getPropertyValue = (obj: unknown, property: string | string[]): string => { + const props = Array.isArray(property) ? property : splitPropertyKey(property) + + for (const prop of props) { + if (!Object.prototype.hasOwnProperty.call(obj, prop)) { + return '' + } + obj = (>obj)[prop] + } + + if (typeof obj === 'string') { + return obj + } + + return JSON.stringify(obj) +} + +/** + * Translates all conditional blocks from within the messageFormat. Translates + * any matching {if key}{key}{end} statements and returns everything between + * if and else blocks if the key provided was found in log. + * + * @param {MessageFormatString|MessageFormatFunction} messageFormat A format + * string or function that defines how the logged message should be + * conditionally formatted. + * @param {object} log The log object to be modified. + * + * @returns {string} The parsed messageFormat. + */ +function interpretConditionals(messageFormat: string, log: Record) { + messageFormat = messageFormat.replace(/{if (.*?)}(.*?){end}/g, replacer) + + // Remove non-terminated if blocks + messageFormat = messageFormat.replace(/{if (.*?)}/g, '') + // Remove floating end blocks + messageFormat = messageFormat.replace(/{end}/g, '') + + return messageFormat.replace(/\s+/g, ' ').trim() + + function replacer(_: unknown, key: string, value: string) { + const propertyValue = getPropertyValue(log, key) + if (propertyValue) { + return value + } else { + return '' + } + } +} + +/** + * Splits the property key delimited by a dot character but not when it is preceded + * by a backslash. + * + * @param {string} key A string identifying the property. + * + * @returns {string[]} Returns a list of string containing each delimited property. + * e.g. `'prop2\.domain\.corp.prop2'` should return [ 'prop2.domain.com', 'prop2' ] + */ +function splitPropertyKey(key: string): string[] { + const result = [] + let backslash = false + let segment = '' + + for (let i = 0; i < key.length; i++) { + const c = key.charAt(i) + + if (c === '\\') { + backslash = true + continue + } + + if (backslash) { + backslash = false + segment += c + continue + } + + /* Non-escaped dot, push to result */ + if (c === '.') { + result.push(segment) + segment = '' + continue + } + + segment += c + } + + /* Push last entry to result */ + if (segment.length) { + result.push(segment) + } + + return result +}