fix(context): expect log methods declared via context

ehmpathy · Aug 31, 2024 · 18e2e0d · 18e2e0d
1 parent 868d3d5
commit 18e2e0d
Show file tree

Hide file tree

Showing 4 changed files with 97 additions and 71 deletions.
diff --git a/src/domain/constants.ts 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
@@ -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
@@ -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 <R extends { name: string }>(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
@@ -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<typeof logic>) => any;
-
-          /**
-           * what of the output to log
-           */
-          output?: (value: Awaited<ReturnType<typeof logic>>) => 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<typeof logic>) => any;
+
+      /**
+       * what of the output to log
+       */
+      output?: (value: Awaited<ReturnType<typeof logic>>) => 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<typeof logic>,
-  Omit<ProcedureContext<typeof logic>, 'log'> & { log?: LogMethods },
-  ProcedureOutput<typeof logic>
-> => {
+): 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,48 +94,43 @@ 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<typeof logic>,
-    context: Omit<ProcedureContext<typeof logic>, 'log'> & { log?: LogMethods },
+    context: ProcedureContext<typeof logic>,
   ): ProcedureOutput<typeof logic> => {
     // now log the input
-    logMethods.debug(`${name}.input`, {
+    context.log.debug(`${name}.input`, {
       input: logInputMethod(input, context),
     });
 
     // begin tracking duration
     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<LogMethod>[0],
         metadata: Parameters<LogMethod>[1],
-      ) => logMethods.debug(`${name}.progress: ${message}`, metadata),
+      ) => context.log.debug(`${name}.progress: ${message}`, metadata),
       info: (
         message: Parameters<LogMethod>[0],
         metadata: Parameters<LogMethod>[1],
-      ) => logMethods.info(`${name}.progress: ${message}`, metadata),
+      ) => context.log.info(`${name}.progress: ${message}`, metadata),
       warn: (
         message: Parameters<LogMethod>[0],
         metadata: Parameters<LogMethod>[1],
-      ) => logMethods.warn(`${name}.progress: ${message}`, metadata),
+      ) => context.log.warn(`${name}.progress: ${message}`, metadata),
       error: (
         message: Parameters<LogMethod>[0],
         metadata: Parameters<LogMethod>[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