From 18e2e0df90f7433a3ad05e7f6883f99e047d094e Mon Sep 17 00:00:00 2001 From: Ulad Kasach Date: Fri, 30 Aug 2024 18:00:34 -0400 Subject: [PATCH] fix(context): expect log methods declared via context --- src/domain/constants.ts | 5 ++ src/index.ts | 1 + src/logic/withLogTrail.test.ts | 54 +++++++++++++---- src/logic/withLogTrail.ts | 108 +++++++++++++++------------------ 4 files changed, 97 insertions(+), 71 deletions(-) create mode 100644 src/domain/constants.ts diff --git a/src/domain/constants.ts b/src/domain/constants.ts new file mode 100644 index 0000000..121a0ba --- /dev/null +++ b/src/domain/constants.ts @@ -0,0 +1,5 @@ +import type { LogMethods } from 'simple-leveled-log-methods'; + +export interface VisualogicContext { + log: LogMethods & { _orig?: LogMethods }; // todo: support ".scope" as a first class attribute of log methods to avoid having to track original log object +} diff --git a/src/index.ts b/src/index.ts index b08b6ad..fe9ea64 100644 --- a/src/index.ts +++ b/src/index.ts @@ -1,3 +1,4 @@ export * from './logic/withLogTrail'; export * from './logic/getResourceNameFromFileName'; export * from './domain/Procedure'; +export * from './domain/constants'; diff --git a/src/logic/withLogTrail.test.ts b/src/logic/withLogTrail.test.ts index 470e1ff..ab7e2e6 100644 --- a/src/logic/withLogTrail.test.ts +++ b/src/logic/withLogTrail.test.ts @@ -9,17 +9,17 @@ export const sleep = (ms: number) => describe('withLogTrail', () => { beforeEach(() => jest.clearAllMocks()); - describe('input output logging', () => { + describe('input output logs', () => { it('should be log input and output for a sync fn', () => { const castToUpperCase = withLogTrail( ({ name }: { name: string }) => { return name.toUpperCase(); }, - { name: 'castToUpperCase', log: { methods: console } }, + { name: 'castToUpperCase' }, ); // should run like normal - const uppered = castToUpperCase({ name: 'casey' }, {}); + const uppered = castToUpperCase({ name: 'casey' }, { log: console }); expect(uppered).toEqual('CASEY'); // should have logged input and output @@ -38,11 +38,14 @@ describe('withLogTrail', () => { await sleep(100); return name.toUpperCase(); }, - { name: 'castToUpperCase', log: { methods: console } }, + { name: 'castToUpperCase' }, ); // should run like normal - const uppered = await castToUpperCase({ name: 'casey' }, {}); + const uppered = await castToUpperCase( + { name: 'casey' }, + { log: console }, + ); expect(uppered).toEqual('CASEY'); // should have logged input and output @@ -55,6 +58,32 @@ describe('withLogTrail', () => { output: ['CASEY'], }); }); + it('should be log input and output for a generic fn', async () => { + const castToUpperCase = withLogTrail( + async (input: { row: R }) => { + await sleep(100); + return input.row.name.toUpperCase(); + }, + { name: 'castToUpperCase' }, + ); + + // should run like normal + const uppered = await castToUpperCase<{ name: string; exid: string }>( + { row: { name: 'casey', exid: 'bae' } }, + { log: console }, + ); + expect(uppered).toEqual('CASEY'); + + // should have logged input and output + expect(logDebugSpy).toHaveBeenCalledTimes(2); + expect(logDebugSpy).toHaveBeenNthCalledWith(1, 'castToUpperCase.input', { + input: { row: { exid: 'bae', name: 'casey' } }, + }); + expect(logDebugSpy).toHaveBeenNthCalledWith(2, 'castToUpperCase.output', { + input: { row: { exid: 'bae', name: 'casey' } }, + output: ['CASEY'], + }); + }); }); describe('duration reporting', () => { it('should report the duration of an operation if it takes more than 1 second by default', async () => { @@ -63,11 +92,14 @@ describe('withLogTrail', () => { await sleep(1100); return name.toUpperCase(); }, - { name: 'castToUpperCase', log: { methods: console } }, + { name: 'castToUpperCase' }, ); // should run like normal - const uppered = await castToUpperCase({ name: 'casey' }, {}); + const uppered = await castToUpperCase( + { name: 'casey' }, + { log: console }, + ); expect(uppered).toEqual('CASEY'); // should have logged input and output @@ -97,11 +129,11 @@ describe('withLogTrail', () => { context.log.debug('begin uppercasement', { on: name }); return name.toUpperCase(); }, - { name: 'castToUpperCase', log: { methods: console } }, + { name: 'castToUpperCase' }, ); // should run like normal - const uppered = castToUpperCase({ name: 'casey' }, {}); + const uppered = castToUpperCase({ name: 'casey' }, { log: console }); expect(uppered).toEqual('CASEY'); // should have logged input and output @@ -128,13 +160,13 @@ describe('withLogTrail', () => { context.log.debug('begin uppercasement', { on: name }); return name.toUpperCase(); }, - { name: 'castToUpperCase', log: { methods: console } }, + { name: 'castToUpperCase' }, ); // should run like normal const uppered = castToUpperCase( { name: 'casey' }, - { organization: 'superorg' }, + { organization: 'superorg', log: console }, ); expect(uppered).toEqual('CASEY'); diff --git a/src/logic/withLogTrail.ts b/src/logic/withLogTrail.ts index 4372494..0ef37d5 100644 --- a/src/logic/withLogTrail.ts +++ b/src/logic/withLogTrail.ts @@ -1,13 +1,17 @@ import { UnexpectedCodePathError } from '@ehmpathy/error-fns'; -import { LogLevel, LogMethod, LogMethods } from 'simple-leveled-log-methods'; +import type { + LogLevel, + LogMethod, + LogMethods, +} from 'simple-leveled-log-methods'; import { isAPromise } from 'type-fns'; import { - Procedure, ProcedureContext, ProcedureInput, ProcedureOutput, } from '../domain/Procedure'; +import { VisualogicContext } from '../domain/constants'; const noOp = (...input: any) => input; const omitContext = (...input: any) => input[0]; // standard pattern for args = [input, context] @@ -25,14 +29,14 @@ const roundToHundredths = (num: number) => Math.round(num * 100) / 100; // https */ export const withLogTrail = < TInput, - TContext extends { log: LogMethods }, + TContext extends VisualogicContext, TOutput, >( logic: (input: TInput, context: TContext) => TOutput, { name: declaredName, durationReportingThresholdInSeconds = 1, - log: logInput, + log: logOptions, }: { /** * specifies the name of the function, if the function does not have a name assigned already @@ -42,48 +46,37 @@ export const withLogTrail = < /** * enable redacting parts of the input or output from logging */ - log: - | LogMethods - | { - /** - * specifies the log method to use to log with - */ - methods: LogMethods; // TODO: use a logger which leverages async-context to scope all logs created inside of this fn w/ `${name}.progress: ${message}`; at that point, probably stick "inout output tracing" inside of that lib - - /** - * specifies the level to log the trail with - * - * note: - * - defaults to .debug // todo: debug to .trail - */ - level?: LogLevel; - - /** - * what of the input to log - */ - input?: (...value: Parameters) => any; - - /** - * what of the output to log - */ - output?: (value: Awaited>) => any; - - /** - * what of the error to log - */ - error?: (error: Error) => any; - }; + log?: { + /** + * specifies the level to log the trail with + * + * note: + * - defaults to .debug // todo: debug to .trail + */ + level?: LogLevel; + + /** + * what of the input to log + */ + input?: (...value: Parameters) => any; + + /** + * what of the output to log + */ + output?: (value: Awaited>) => any; + + /** + * what of the error to log + */ + error?: (error: Error) => any; + }; /** * specifies the threshold after which a duration will be included on the output log */ durationReportingThresholdInSeconds?: number; }, -): Procedure< - ProcedureInput, - Omit, 'log'> & { log?: LogMethods }, - ProcedureOutput -> => { +): typeof logic => { // cache the name of the function per wrapping const name: string | null = logic.name || declaredName || null; // use `\\` since `logic.name` returns `""` for anonymous functions @@ -101,24 +94,18 @@ export const withLogTrail = < ); // extract the log methods - const logMethods: LogMethods = - 'methods' in logInput ? logInput.methods : logInput; - const logTrailLevel: LogLevel = - ('methods' in logInput ? logInput.level : undefined) ?? LogLevel.DEBUG; - const logInputMethod = - ('methods' in logInput ? logInput.input : undefined) ?? omitContext; - const logOutputMethod = - ('methods' in logInput ? logInput.output : undefined) ?? noOp; - const logErrorMethod = - ('methods' in logInput ? logInput.error : undefined) ?? pickErrorMessage; + const logTrailLevel: LogLevel = logOptions?.level ?? LogLevel.DEBUG; + const logInputMethod = logOptions?.input ?? omitContext; + const logOutputMethod = logOptions?.output ?? noOp; + const logErrorMethod = logOptions?.error ?? pickErrorMessage; // wrap the function return ( input: ProcedureInput, - context: Omit, 'log'> & { log?: LogMethods }, + context: ProcedureContext, ): ProcedureOutput => { // now log the input - logMethods.debug(`${name}.input`, { + context.log.debug(`${name}.input`, { input: logInputMethod(input, context), }); @@ -126,23 +113,24 @@ export const withLogTrail = < const startTimeInMilliseconds = new Date().getTime(); // define the context.log method that will be given to the logic - const logMethodsWithContext: LogMethods = { + const logMethodsWithContext: LogMethods & { _orig: LogMethods } = { + _orig: context.log?._orig ?? context.log, debug: ( message: Parameters[0], metadata: Parameters[1], - ) => logMethods.debug(`${name}.progress: ${message}`, metadata), + ) => context.log.debug(`${name}.progress: ${message}`, metadata), info: ( message: Parameters[0], metadata: Parameters[1], - ) => logMethods.info(`${name}.progress: ${message}`, metadata), + ) => context.log.info(`${name}.progress: ${message}`, metadata), warn: ( message: Parameters[0], metadata: Parameters[1], - ) => logMethods.warn(`${name}.progress: ${message}`, metadata), + ) => context.log.warn(`${name}.progress: ${message}`, metadata), error: ( message: Parameters[0], metadata: Parameters[1], - ) => logMethods.error(`${name}.progress: ${message}`, metadata), + ) => context.log.error(`${name}.progress: ${message}`, metadata), }; // now execute the method @@ -155,7 +143,7 @@ export const withLogTrail = < if (isAPromise(result)) { // define how to log the breach, on breach const onDurationBreach = () => - logMethods[logTrailLevel](`${name}.duration.breach`, { + context.log[logTrailLevel](`${name}.duration.breach`, { input: logInputMethod(input, context), already: { duration: `${durationReportingThresholdInSeconds} sec` }, }); @@ -180,7 +168,7 @@ export const withLogTrail = < const durationInMilliseconds = endTimeInMilliseconds - startTimeInMilliseconds; const durationInSeconds = roundToHundredths(durationInMilliseconds / 1e3); // https://stackoverflow.com/a/53970656/3068233 - logMethods[logTrailLevel](`${name}.output`, { + context.log[logTrailLevel](`${name}.output`, { input: logInputMethod(input, context), output: logOutputMethod(output), ...(durationInSeconds >= durationReportingThresholdInSeconds @@ -195,7 +183,7 @@ export const withLogTrail = < const durationInMilliseconds = endTimeInMilliseconds - startTimeInMilliseconds; const durationInSeconds = roundToHundredths(durationInMilliseconds / 1e3); // https://stackoverflow.com/a/53970656/3068233 - logMethods[logTrailLevel](`${name}.error`, { + context.log[logTrailLevel](`${name}.error`, { input: logInputMethod(input, context), output: logErrorMethod(error), ...(durationInSeconds >= durationReportingThresholdInSeconds