Merge pull request #81 from Testy/feature/logging-improvement

Improve standard logger by printing stack on error
Testy · Jul 18, 2021 · eef2c0a · eef2c0a
2 parents 26999b3 + b6a5911
commit eef2c0a
Show file tree

Hide file tree

Showing 17 changed files with 175 additions and 50 deletions.
diff --git a/e2e/expect.js b/e2e/expect.js
@@ -25,21 +25,38 @@ function slice(str, center, width = 20) {
   return str.slice(Math.max(min, 0), Math.min(max, len - 1));
 }
 
-function expect(actual) {
+function expect(actualOutput) {
   return {
-    toEqual: (expected) => {
-      actual = sanitize(actual);
-      expected = sanitize(expected);
+    toEqual: (expectedOutput) => {
+      const expectedLines = expectedOutput
+        .toString()
+        .split(/\r?\n/)
+        .map((x) => sanitize(x))
+        .filter((x) => x.match(/^ *$/) === null);
 
+      const actualLines = actualOutput
+        .toString()
+        .split(/\r?\n/)
+        .map((x) => sanitize(x))
+        .filter((x) => x.match(/^ *$/) === null);
       let isValid = true;
-      for (let i = 0; i < actual.length; ++i) {
-        if (expected[i] !== '#' && actual[i] !== expected[i]) {
-          log.error(`Expected string did not match: ${slice(actual, i)} != ${slice(expected, i)}`);
-          isValid = false;
-          break;
+
+      for (let i = 0; i < actualLines.length; ++i) {
+        let actual = actualLines[i];
+        let expected = expectedLines[i];
+
+        if (expected.split('').every((c) => c === '#' || c === ' ')) {
+          continue;
         }
-      }
 
+        for (let i = 0; i < actual.length; ++i) {
+          if (expected[i] !== '#' && actual[i] !== expected[i]) {
+            log.error(`Expected string did not match: ${slice(actual, i)} != ${slice(expected, i)}`);
+            isValid = false;
+            break;
+          }
+        }
+      }
       return isValid;
     },
   };

diff --git a/e2e/testy.json -- reporter -- standard/.expected_stdout b/e2e/testy.json -- reporter -- standard/.expected_stdout
@@ -2,8 +2,41 @@ Root
   MyTestSuite
     √ pass1
     x fail1 - Expected 2  to equal 3.
+      Error: Expected 2 to equal 3.
+          ############################################################################
+          ##############################################################################################################
+          ###############################
+          ###################################################################################
+          ############################
+          ##############################################################################################
+          #######################################################################################################
+          ###################################################################
+          ###############################
+          #################################################################
     x fail2 - Expected 2  to equal 3.
+      Error: Expected 2 to equal 3.
+          ############################################################################
+          ##############################################################################################################
+          ###############################
+          ###################################################################################
+          ############################
+          ##############################################################################################
+          #######################################################################################################
+          ###################################################################
+          ###############################
+          #################################################################
     x fail3 - Expected 2  to equal 3.
+      Error: Expected 2 to equal 3.
+          ############################################################################
+          ##############################################################################################################
+          ###############################
+          ###################################################################################
+          ############################
+          ##############################################################################################
+          #######################################################################################################
+          ###################################################################
+          ###############################
+          #################################################################
     ! skip1
     ! skip2
 

diff --git a/e2e/testy.json -- standard reporter -- NaN display/.expected_stdout b/e2e/testy.json -- standard reporter -- NaN display/.expected_stdout
@@ -1,5 +1,16 @@
 Root
   MyTestSuite
     x test - Expected NaN to equal 0.
+      Error: Expected NaN to equal 0.
+          ####################################################################
+          ###############################################################################################################
+          ###################################################################
+          ##############################
+          ############################################################
+          ############################
+          ############################################################################
+          #######################################################################################
+          ################################################################################
+          ##############################
 
 Summary: 0/1 passed, 1/1 failed, 0/1 skipped. (#####s)
diff --git a/package-lock.json b/package-lock.json
diff --git a/package.json b/package.json
@@ -1,6 +1,6 @@
 {
   "name": "testyts",
-  "version": "1.5.0",
+  "version": "2.0.0-beta.1",
   "icon": "img/test-icon-128x128.png",
   "description": "Modern test framework for TypeScript.",
   "main": "build/testyCore.js",

diff --git a/src/lib/logger/consoleLogger.ts b/src/lib/logger/consoleLogger.ts
@@ -1,4 +1,5 @@
-import { Logger, Color } from './logger';
+import { TextDecoder } from 'util';
+import { Logger, Color, TextDecoration } from './logger';
 
 export class ConsoleLogger extends Logger {
   private readonly reset = '\x1b[0m';
@@ -12,36 +13,68 @@ export class ConsoleLogger extends Logger {
   }
 
   public warn(message: string = ''): void {
-    console.log(this.color(this.indentation + message, Color.Yellow));
+    console.log(this.format(this.indentation + message, Color.Yellow));
   }
 
   public error(message: string = ''): void {
-    console.log(this.color(this.indentation + message, Color.Red));
+    console.log(this.format(this.indentation + message, Color.Red));
   }
 
-  public color(message: string, color: Color) {
+  public format(message: string, color: Color, textDecorations: TextDecoration[] = []): string {
+    const colorCode = this.getColorCode(color);
+    const textDecorationsCodes = textDecorations.map((x) => this.getTextDecorationCode(x));
+
+    return message
+      .split(' ')
+      .map((x) => colorCode + textDecorationsCodes.join() + x + this.reset)
+      .join(' ');
+  }
+
+  private getColorCode(color: Color) {
     switch (color) {
+      case Color.Black:
+        return ForegroundColorCodes.Black;
+
       case Color.Green:
-        return ForegroundColors.Green + message + this.reset;
+        return ForegroundColorCodes.Green;
 
       case Color.Yellow:
-        return ForegroundColors.Yellow + message + this.reset;
+        return ForegroundColorCodes.Yellow;
 
       case Color.Red:
-        return ForegroundColors.Red + message + this.reset;
+        return ForegroundColorCodes.Red;
 
       case Color.Grey:
-        return ForegroundColors.Grey + message + this.reset;
+        return ForegroundColorCodes.Grey;
+
+      case Color.LightGrey:
+        return ForegroundColorCodes.LightGrey;
+
+      default:
+        return '';
+    }
+  }
+
+  private getTextDecorationCode(textDecoration: TextDecoration) {
+    switch (textDecoration) {
+      case TextDecoration.Bold:
+        return TextDecorationsCodes.Bold;
 
       default:
-        return message + this.reset;
+        return '';
     }
   }
 }
 
-enum ForegroundColors {
+enum TextDecorationsCodes {
+  Bold = '\x1b[1m',
+}
+
+enum ForegroundColorCodes {
+  Black = '\x1b[30m',
   Red = '\x1b[31m',
   Green = '\x1b[32m',
   Yellow = '\x1b[93m',
   Grey = '\x1b[90m',
+  LightGrey = '\x1b[37m',
 }
diff --git a/src/lib/logger/logger.ts b/src/lib/logger/logger.ts
@@ -1,8 +1,14 @@
 export enum Color {
+  Black,
   Red,
   Green,
   Yellow,
   Grey,
+  LightGrey,
+}
+
+export enum TextDecoration {
+  Bold,
 }
 
 export abstract class Logger {
@@ -25,5 +31,5 @@ export abstract class Logger {
   abstract info(message?: string): void;
   abstract warn(message?: string): void;
   abstract error(message?: string): void;
-  abstract color(message: string, color: Color): void;
+  abstract format(message: string, color: Color, textDecorations?: TextDecoration[]): string;
 }
diff --git a/src/lib/reporting/report/failedTestReport.ts b/src/lib/reporting/report/failedTestReport.ts
@@ -6,7 +6,11 @@ export class FailedTestReport extends LeafReport {
     return this._message;
   }
 
-  constructor(name: string, private _message: string, duration: number) {
+  public get stack() {
+    return this._stack;
+  }
+
+  constructor(name: string, private _message: string, private _stack: string, duration: number) {
     super(name, TestResult.Failure, duration);
   }
 }
diff --git a/src/lib/tests/test.ts b/src/lib/tests/test.ts
@@ -25,7 +25,7 @@ export class TestInstance {
   ) {}
 
   public async run(context, config: TestyConfig) {
-    return await new Promise(async (resolve, reject) => {
+    return await new Promise<void>(async (resolve, reject) => {
       try {
         // The timeout is determined like so:
         // 1. If there is a test-level timeout, we use it

diff --git a/src/lib/tests/visitors/decorators/loggerTestReporterDecorator.ts b/src/lib/tests/visitors/decorators/loggerTestReporterDecorator.ts
@@ -1,13 +1,13 @@
-import { Logger, Color } from '../../../logger/logger';
+import { Color, Logger, TextDecoration } from '../../../logger/logger';
 import { CompositeReport } from '../../../reporting/report/compositeReport';
 import { FailedTestReport } from '../../../reporting/report/failedTestReport';
 import { Report } from '../../../reporting/report/report';
 import { TestResult } from '../../../reporting/report/testResult';
+import { RootTestSuite } from '../../rootTestSuite';
 import { TestInstance } from '../../test';
 import { TestSuiteInstance } from '../../testSuite';
 import { TestVisitor } from '../testVisitor';
 import { TestsVisitorDecorator } from './testsVisitorDecorator';
-import { RootTestSuite } from '../../rootTestSuite';
 
 export class LoggerTestReporterDecorator extends TestsVisitorDecorator<Report> {
   private justPrintedTestSuite: boolean;
@@ -20,16 +20,30 @@ export class LoggerTestReporterDecorator extends TestsVisitorDecorator<Report> {
     this.justPrintedTestSuite = false;
     const report = await this.baseVisitTest(test);
 
-    let msg;
+    let title;
+    const details: string[] = [];
     if (report.result === TestResult.Success) {
-      msg = `${this.logger.color('√', Color.Green)} ${this.logger.color(test.name, Color.Grey)}`;
+      title = `${this.logger.format('√', Color.Green)} ${this.logger.format(test.name, Color.Grey)}`;
     } else if (report instanceof FailedTestReport) {
-      msg = this.logger.color(`x ${test.name} - ${report.message}`, Color.Red);
+      title = this.logger.format(`x ${test.name} - ${report.message}`, Color.Red, [TextDecoration.Bold]);
+
+      if (report.stack?.length) {
+        details.push(...report.stack.split(/[\r\n|\n]/).map((x) => this.logger.format(x, Color.Grey)));
+      }
     } else {
-      msg = `${this.logger.color('!', Color.Yellow)} ${this.logger.color(`${test.name}`, Color.Grey)}`;
+      title = `${this.logger.format('!', Color.Yellow)} ${this.logger.format(`${test.name}`, Color.Grey)}`;
     }
 
-    this.logger.info(msg);
+    this.logger.info(title);
+
+    if (details.length) {
+      this.logger.increaseIndentation();
+      for (const detail of details) {
+        this.logger.info(detail);
+      }
+
+      this.logger.decreaseIndentation();
+    }
 
     return report;
   }
@@ -40,7 +54,7 @@ export class LoggerTestReporterDecorator extends TestsVisitorDecorator<Report> {
       this.justPrintedTestSuite = true;
     }
 
-    this.logger.info(tests.name);
+    this.logger.info(this.logger.format(tests.name, Color.Black, [TextDecoration.Bold]));
     this.logger.increaseIndentation();
 
     const returnValue = await this.baseVisitTestSuite(tests);
@@ -65,10 +79,10 @@ export class LoggerTestReporterDecorator extends TestsVisitorDecorator<Report> {
     const skipped = tests.numberOfSkippedTests;
     const total = tests.numberOfTests;
 
-    this.logger.info(
-      `Summary: ${success}/${total} passed, ${failed}/${total} failed, ${skipped}/${total} skipped. (${
-        tests.duration / 1000
-      }s)`
-    );
+    const successMsg = `${success}/${total} ${this.logger.format('passed', success > 0 ? Color.Green : null)}`;
+    const failedMsg = `${failed}/${total} ${this.logger.format('failed', failed > 0 ? Color.Red : null)}`;
+    const skippedMsg = `${skipped}/${total} ${this.logger.format('skipped', skipped > 0 ? Color.Yellow : null)}`;
+
+    this.logger.info(`Summary: ${successMsg}, ${failedMsg}, ${skippedMsg}. (${tests.duration / 1000}s)`);
   }
 }
diff --git a/src/lib/tests/visitors/failedTestsReportVisitor.ts b/src/lib/tests/visitors/failedTestsReportVisitor.ts
@@ -16,7 +16,7 @@ export class FailedTestsReportVisitor implements TestVisitor<Report> {
     const report: LeafReport =
       test.status === TestStatus.Ignored
         ? new SkippedTestReport(test.name)
-        : new FailedTestReport(test.name, this.reason, 0);
+        : new FailedTestReport(test.name, this.reason, '', 0);
 
     return report;
   }

diff --git a/src/lib/tests/visitors/testRunnerVisitor.ts b/src/lib/tests/visitors/testRunnerVisitor.ts
@@ -59,7 +59,12 @@ export class TestRunnerVisitor implements TestVisitor<Report> {
         report = new SuccessfulTestReport(test.name, Math.round(time));
       } catch (err) {
         this.process.exitCode = 1;
-        report = new FailedTestReport(test.name, typeof err === typeof '' ? err : err.message, 0);
+        report = new FailedTestReport(
+          test.name,
+          typeof err === typeof '' ? err : err.message,
+          typeof err === typeof '' ? null : err.stack,
+          0
+        );
       }
     }
 

diff --git a/src/spec/decorators/baseTestSuite/testWithBase.spec.ts b/src/spec/decorators/baseTestSuite/testWithBase.spec.ts
@@ -8,7 +8,7 @@ import { BaseTestSuite, TestSuiteWithBase } from './testSuiteWithBase';
 @TestSuite('Test Suite With Base Test Suite Tests')
 export class BeforeAfterDecoratorsTestSuite extends TestSuiteTestsBase {
   @Test('the base and the actual test suite before and after methods are called.')
-  private async trivialCase() {
+  public async trivialCase() {
     // Arrange
     const testSuite = TestUtils.getInstance(TestSuiteWithBase);
 
@@ -27,7 +27,7 @@ export class BeforeAfterDecoratorsTestSuite extends TestSuiteTestsBase {
   }
 
   @Test('base with multiple children')
-  private async baseWithMultipleChildren() {
+  public async baseWithMultipleChildren() {
     // Arrange
     const a = TestUtils.getInstance(TestSuiteA);
     const b = TestUtils.getInstance(TestSuiteB);

diff --git a/src/spec/tests/testRunnerVisitor.errorMessages.spec.ts b/src/spec/tests/testRunnerVisitor.errorMessages.spec.ts
@@ -24,9 +24,9 @@ export class TestRunnerVisitorErrorMessagesTests {
     const testSuite = TestUtils.getInstance(AsyncTestsFailures);
 
     const expectedReport = new CompositeReport('AsyncTestsFailures');
-    expectedReport.addReport(new FailedTestReport('testA', 'Test has timed out.', 0));
-    expectedReport.addReport(new FailedTestReport('testC', 'Some rejection message!', 0));
-    expectedReport.addReport(new FailedTestReport('testD', 'Some error!', 0));
+    expectedReport.addReport(new FailedTestReport('testA', 'Test has timed out.', null, 0));
+    expectedReport.addReport(new FailedTestReport('testC', 'Some rejection message!', null, 0));
+    expectedReport.addReport(new FailedTestReport('testD', 'Some error!', null, 0));
 
     // Act
     const actualReport = await testSuite.accept(this.testRunnerVisitor);
@@ -42,7 +42,7 @@ export class TestRunnerVisitorErrorMessagesTests {
     const testSuite = TestUtils.getInstance(SyncTestsFailures);
 
     const expectedReport = new CompositeReport('SyncTestsFailures');
-    expectedReport.addReport(new FailedTestReport('error', 'Some error!', 0));
+    expectedReport.addReport(new FailedTestReport('error', 'Some error!', null, 0));
 
     // Act
     const actualReport = await testSuite.accept(this.testRunnerVisitor);