DIME-8714 stacktrace now contains the recursive cause in one string (#76)

Duplicated lines in stack traces are omitted and the whole string is
truncated

Author: balint-barki-sap

README.md

@@ -193,6 +193,8 @@ The separate steps of the logging process can be configured here.
 These modifications affect all the instances of the library.
 With transformers we can alter the data to be logged before passing to the formatter and then to the output.
 It is a perfect place to add the name of the machine is running on or the request id associated with the current thread stored on a continuation local storage. 
+With the 'enhancedStackTrace' option set to true, the error stack traces will include the causes of the errors as well (if any) including their stack traces 
+with a significantly improved truncation limit.
 
 ```javascript
 const { createLogger } = require('@emartech/json-logger');
@@ -201,7 +203,8 @@ createLogger.configure({
   formatter: JSON.stringify,
   output: console.log,
   transformers: [],
-  outputFormat: 'ecs'
+  outputFormat: 'ecs',
+  enhancedStackTrace: true
 });
 
 ```

package-lock.json

@@ -250,7 +250,7 @@ describe('Logger', () => {
     expect(logArguments.http.response.body.content).to.eql(JSON.stringify(error.response?.data));
   });
 
-  it('should log causes', () => {
+  it('should include error causes in stack trace when enhanced stack trace is enabled', () => {
     const rootCause = new Error('Root cause error');
     rootCause.name = 'RootCauseError';
     rootCause.stack = 'RootCauseError: Root cause error\n    at rootFunction()';
@@ -265,21 +265,16 @@ describe('Logger', () => {
     mainError.stack = 'MainError: Main error occurred\n    at mainFunction()';
     mainError.cause = intermediateError;
 
+    Logger.configure({ enhancedStackTrace: true });
+
     logger.fromError('test_action', mainError, { details: 'test details' });
 
     const logArguments = JSON.parse(outputStub.args[0][0]);
     expect(logArguments.error.type).to.eql('MainError');
     expect(logArguments.error.message).to.eql('Main error occurred');
-    expect(logArguments.error.cause).to.eql({
-      type: 'IntermediateError',
-      message: 'Intermediate error',
-      stack_trace: intermediateError.stack,
-      cause: {
-        type: 'RootCauseError',
-        message: 'Root cause error',
-        stack_trace: rootCause.stack,
-      },
-    });
+    expect(logArguments.error.stack_trace).to.eql(
+      [mainError.stack, 'Caused by: ' + intermediateError.stack, 'Caused by: ' + rootCause.stack].join('\n'),
+    );
   });
 
   describe('#customError', () => {
@@ -342,9 +337,9 @@ describe('Logger', () => {
         });
       });
 
-      it('should log error properties from custom error object', () => {
+      it('should log error properties from custom error object with normal stack trace', () => {
         const errorObject = { name: 'Error', message: 'My custom error', stack: 'Stack', data: { value: 1 } };
-
+        Logger.configure({ enhancedStackTrace: false });
         logger.customError('error', 'hi', errorObject, { details: 'here' });
 
         const logArguments = JSON.parse(outputStub.args[0][0]);
@@ -355,6 +350,20 @@ describe('Logger', () => {
         expect(logArguments.error.context).to.eql(JSON.stringify(errorObject.data));
       });
 
+      it('should log error properties from custom error object with enhanced stack trace', () => {
+        const errorObject = { name: 'Error', message: 'My custom error', stack: 'Stack', data: { value: 1 } };
+
+        Logger.configure({ enhancedStackTrace: true });
+        logger.customError('error', 'hi', errorObject, { details: 'here' });
+
+        const logArguments = JSON.parse(outputStub.args[0][0]);
+
+        expect(logArguments.error.type).to.eql(errorObject.name);
+        expect(logArguments.error.stack_trace).to.eql([errorObject.name, errorObject.stack].join('\n'));
+        expect(logArguments.error.message).to.eql(errorObject.message);
+        expect(logArguments.error.context).to.eql(JSON.stringify(errorObject.data));
+      });
+
       it('should not log additional or missing error properties from custom error object', () => {
         const errorObject = { color: 'color', value: 'value' };
 
@@ -414,7 +423,7 @@ describe('Logger', () => {
         throw new Error('should throw');
       } catch (e) {
         expect((e as Error).message).to.eql(
-          'Only the following keys are allowed: output,formatter,transformers,outputFormat',
+          'Only the following keys are allowed: output,formatter,transformers,outputFormat,enhancedStackTrace',
         );
       }
     });

src/logger/logger.spec.ts

@@ -5,8 +5,9 @@ import { consoleOutput } from '../output/console';
 import { Timer } from '../timer/timer';
 
 const STACK_TRACE_LIMIT = 3000;
+const ENHANCED_STACK_TRACE_LIMIT = 15000;
 const DATA_LIMIT = 3000;
-const allowedKeys = ['output', 'formatter', 'transformers', 'outputFormat'];
+const allowedKeys = ['output', 'formatter', 'transformers', 'outputFormat', 'enhancedStackTrace'];
 
 interface ErrorWithData extends Error {
   data: unknown;
@@ -32,6 +33,7 @@ export interface LoggerConfig {
   output: Function;
   transformers: Function[];
   outputFormat: string;
+  enhancedStackTrace: boolean;
 }
 /* eslint-enable @typescript-eslint/no-unsafe-function-type */
 
@@ -62,6 +64,7 @@ export class Logger {
     output: consoleOutput,
     transformers: [],
     outputFormat: 'ecs',
+    enhancedStackTrace: false,
   };
 
   isEnabled() {
@@ -171,32 +174,94 @@ export class Logger {
   }
 
   private getBaseErrorDetails(error: Error) {
+    const shortenedData = this.shortenData((error as ErrorWithData).data);
+
     if (Logger.config.outputFormat === 'legacy') {
       return {
         error_name: error.name,
         error_stack: this.shortenStackTrace(error.stack || ''),
         error_message: error.message,
-        error_data: this.shortenData((error as ErrorWithData).data),
+        error_data: shortenedData,
       };
     }
 
+    const stackTrace = Logger.config.enhancedStackTrace
+      ? this.getEnhancedStackTrace(error)
+      : this.shortenStackTrace(error.stack || '');
+
     return {
-      error: this.extractError(error),
+      error: {
+        type: error.name,
+        message: error.message,
+        ...(shortenedData && { context: shortenedData }),
+        stack_trace: stackTrace,
+      },
       event: {
         reason: error.message,
       },
     };
   }
 
-  private extractError(error: Error): unknown {
-    const shortenedData = this.shortenData((error as ErrorWithData).data);
-    return {
-      type: error.name,
-      message: error.message,
-      ...(shortenedData && { context: shortenedData }),
-      stack_trace: this.shortenStackTrace(error.stack || ''),
-      ...(error.cause instanceof Error && { cause: this.extractError(error.cause) }),
+  private getEnhancedStackTrace(error: Error): string {
+    const getNumberOfCommonFrames = (ownTrace: string[], enclosingTrace: string[]): number => {
+      let m = ownTrace.length - 1;
+      let n = enclosingTrace.length - 1;
+
+      while (m > 0 && n > 0 && ownTrace[m] === enclosingTrace[n]) {
+        m--;
+        n--;
+      }
+      return ownTrace.length - 1 - m;
+    };
+
+    const getEnclosedStackTrace = (error: Error, enclosingTrace: string[], caption: string): string[] => {
+      const output: string[] = [];
+
+      let errorName: string;
+      let errorStack: string[];
+      const errorStackLines = error.stack ? error.stack.split('\n') : [];
+      const firstLine = errorStackLines.at(0);
+
+      if (error.stack) {
+        if (firstLine?.includes(error.name)) {
+          errorName = firstLine!;
+          errorStack = errorStackLines.slice(1);
+        } else {
+          errorName = error.name;
+          errorStack = errorStackLines;
+        }
+      } else {
+        errorName = error.name;
+        errorStack = [];
+      }
+
+      const commonFrames = getNumberOfCommonFrames(errorStack, enclosingTrace);
+      const uniqueFrames = errorStack.length - commonFrames;
+
+      output.push(caption + errorName);
+      errorStack.slice(0, uniqueFrames).forEach((line) => output.push(line));
+      if (commonFrames > 0) {
+        output.push(`\t... ${commonFrames} more`);
+      }
+
+      if (error.cause instanceof Error) {
+        output.push(...getEnclosedStackTrace(error.cause, errorStackLines, 'Caused by: '));
+      }
+
+      return output;
     };
+
+    const stackTrace = getEnclosedStackTrace(error, [], '');
+    const joinedStackTrace = stackTrace.join('\n');
+    let resultStackTraceStr: string;
+
+    if (joinedStackTrace.length > ENHANCED_STACK_TRACE_LIMIT) {
+      resultStackTraceStr = joinedStackTrace.substring(0, ENHANCED_STACK_TRACE_LIMIT) + ' ...';
+    } else {
+      resultStackTraceStr = joinedStackTrace;
+    }
+
+    return resultStackTraceStr;
   }
 
   private getAxiosErrorDetails(error: AxiosError) {