Testing: Pretty output + Silent mode (#314)

testing/mod.ts

@@ -1,17 +1,76 @@
 // Copyright 2018-2019 the Deno authors. All rights reserved. MIT license.
 
-import { green, red } from "../colors/mod.ts";
-
+import {
+  bgRed,
+  white,
+  bold,
+  green,
+  red,
+  gray,
+  yellow,
+  italic
+} from "../colors/mod.ts";
 export type TestFunction = () => void | Promise<void>;
 
 export interface TestDefinition {
   fn: TestFunction;
   name: string;
 }
 
+// Replacement of the global `console` function to be in silent mode
+const noop = function(): void {};
+
+// Clear the current line of the console.
+// see: http://ascii-table.com/ansi-escape-sequences-vt-100.php
+const CLEAR_LINE = "\x1b[2K\r";
+
+// Save Object of the global `console` in case of silent mode
+type Console = typeof window.console;
+// ref https://console.spec.whatwg.org/#console-namespace
+// For historical web-compatibility reasons, the namespace object for
+// console must have as its [[Prototype]] an empty object, created as if
+// by ObjectCreate(%ObjectPrototype%), instead of %ObjectPrototype%.
+const disabledConsole = Object.create({}) as Console;
+Object.assign(disabledConsole, {
+  log: noop,
+  debug: noop,
+  info: noop,
+  dir: noop,
+  warn: noop,
+  error: noop,
+  assert: noop,
+  count: noop,
+  countReset: noop,
+  table: noop,
+  time: noop,
+  timeLog: noop,
+  timeEnd: noop,
+  group: noop,
+  groupCollapsed: noop,
+  groupEnd: noop,
+  clear: noop
+});
+
+const originalConsole = window.console;
+
+function enableConsole(): void {
+  window.console = originalConsole;
+}
+
+function disableConsole(): void {
+  window.console = disabledConsole;
+}
+
+const encoder = new TextEncoder();
+function print(txt: string, newline: boolean = true): void {
+  if (newline) {
+    txt += "\n";
+  }
+  Deno.stdout.writeSync(encoder.encode(`${txt}`));
+}
+
 let filterRegExp: RegExp | null;
 const candidates: TestDefinition[] = [];
-
 let filtered = 0;
 
 // Must be called before any test() that needs to be filtered.
@@ -42,7 +101,7 @@ export function test(t: TestDefinition | TestFunction): void {
 }
 
 const RED_FAILED = red("FAILED");
-const GREEN_OK = green("ok");
+const GREEN_OK = green("OK");
 
 interface TestStats {
   filtered: number;
@@ -53,6 +112,7 @@ interface TestStats {
 }
 
 interface TestResult {
+  timeElapsed?: number;
   name: string;
   error?: Error;
   ok: boolean;
@@ -75,15 +135,32 @@ function createTestResults(tests: TestDefinition[]): TestResults {
   );
 }
 
+function formatTestTime(time: number = 0): string {
+  return `${time.toFixed(2)}ms`;
+}
+
+function promptTestTime(time: number = 0, displayWarning = false): string {
+  // if time > 5s we display a warning
+  // only for test time, not the full runtime
+  if (displayWarning && time >= 5000) {
+    return bgRed(white(bold(`(${formatTestTime(time)})`)));
+  } else {
+    return gray(italic(`(${formatTestTime(time)})`));
+  }
+}
+
 function report(result: TestResult): void {
   if (result.ok) {
-    console.log(`test ${result.name} ... ${GREEN_OK}`);
-  } else if (result.error) {
-    console.error(
-      `test ${result.name} ... ${RED_FAILED}\n${result.error.stack}`
+    print(
+      `${GREEN_OK}     ${result.name} ${promptTestTime(
+        result.timeElapsed,
+        true
+      )}`
     );
+  } else if (result.error) {
+    print(`${RED_FAILED} ${result.name}\n${result.error.stack}`);
   } else {
-    console.log(`test ${result.name} ... unresolved`);
+    print(`test ${result.name} ... unresolved`);
   }
   result.printed = true;
 }
@@ -92,7 +169,8 @@ function printResults(
   stats: TestStats,
   results: TestResults,
   flush: boolean,
-  exitOnFail: boolean
+  exitOnFail: boolean,
+  timeElapsed: number
 ): void {
   if (flush) {
     for (const result of results.cases.values()) {
@@ -105,11 +183,12 @@ function printResults(
     }
   }
   // Attempting to match the output of Rust's test runner.
-  console.log(
+  print(
     `\ntest result: ${stats.failed ? RED_FAILED : GREEN_OK}. ` +
       `${stats.passed} passed; ${stats.failed} failed; ` +
       `${stats.ignored} ignored; ${stats.measured} measured; ` +
-      `${stats.filtered} filtered out\n`
+      `${stats.filtered} filtered out ` +
+      `${promptTestTime(timeElapsed)}\n`
   );
 }
 
@@ -129,9 +208,12 @@ async function createTestCase(
 ): Promise<void> {
   const result: TestResult = results.cases.get(results.keys.get(name)!)!;
   try {
+    const start = performance.now();
     await fn();
+    const end = performance.now();
     stats.passed++;
     result.ok = true;
+    result.timeElapsed = end - start;
   } catch (err) {
     stats.failed++;
     result.error = err;
@@ -170,21 +252,33 @@ async function runTestsParallel(
 async function runTestsSerial(
   stats: TestStats,
   tests: TestDefinition[],
-  exitOnFail: boolean
+  exitOnFail: boolean,
+  disableLog: boolean
 ): Promise<void> {
   for (const { fn, name } of tests) {
-    // See https://github.com/denoland/deno/pull/1452
-    // about this usage of groupCollapsed
-    console.groupCollapsed(`test ${name} `);
+    // Displaying the currently running test if silent mode
+    if (disableLog) {
+      print(`${yellow("RUNNING")} ${name}`, false);
+    }
     try {
+      let start, end;
+      start = performance.now();
       await fn();
+      end = performance.now();
+      if (disableLog) {
+        // Rewriting the current prompt line to erase `running ....`
+        print(CLEAR_LINE, false);
+      }
       stats.passed++;
-      console.log("...", GREEN_OK);
-      console.groupEnd();
+      print(
+        GREEN_OK + "     " + name + " " + promptTestTime(end - start, true)
+      );
     } catch (err) {
-      console.log("...", RED_FAILED);
-      console.groupEnd();
-      console.error(err.stack);
+      if (disableLog) {
+        print(CLEAR_LINE, false);
+      }
+      print(`${RED_FAILED} ${name}`);
+      print(err.stack);
       stats.failed++;
       if (exitOnFail) {
         break;
@@ -199,6 +293,7 @@ export interface RunOptions {
   exitOnFail?: boolean;
   only?: RegExp;
   skip?: RegExp;
+  disableLog?: boolean;
 }
 
 /**
@@ -209,7 +304,8 @@ export async function runTests({
   parallel = false,
   exitOnFail = false,
   only = /[^\s]/,
-  skip = /^\s*$/
+  skip = /^\s*$/,
+  disableLog = false
 }: RunOptions = {}): Promise<void> {
   const tests: TestDefinition[] = candidates.filter(
     ({ name }): boolean => only.test(name) && !skip.test(name)
@@ -222,13 +318,24 @@ export async function runTests({
     failed: 0
   };
   const results: TestResults = createTestResults(tests);
-  console.log(`running ${tests.length} tests`);
+  print(`running ${tests.length} tests`);
+  const start = performance.now();
+  if (Deno.args.includes("--quiet")) {
+    disableLog = true;
+  }
+  if (disableLog) {
+    disableConsole();
+  }
   if (parallel) {
     await runTestsParallel(stats, results, tests, exitOnFail);
   } else {
-    await runTestsSerial(stats, tests, exitOnFail);
+    await runTestsSerial(stats, tests, exitOnFail, disableLog);
+  }
+  const end = performance.now();
+  if (disableLog) {
+    enableConsole();
   }
-  printResults(stats, results, parallel, exitOnFail);
+  printResults(stats, results, parallel, exitOnFail, end - start);
   if (stats.failed) {
     // Use setTimeout to avoid the error being ignored due to unhandled
     // promise rejections being swallowed.