test: improve tests log output (#114)

Author: robertsLando

.github/workflows/ci.yml

@@ -30,4 +30,6 @@ jobs:
         run: yarn lint
       - run: yarn build
       - run: yarn test
+        env:
+          CI: true
         timeout-minutes: 30

test/.eslintrc.json

@@ -5,6 +5,7 @@
   "rules": {
     "no-var": "off",
     "prefer-const": "off",
-    "vars-on-top": "off"
+    "vars-on-top": "off",
+    "no-plusplus": "off"
   }
 }

test/test.js

@@ -6,6 +6,7 @@ const path = require('path');
 const pc = require('picocolors');
 const { globSync } = require('tinyglobby');
 const utils = require('./utils.js');
+const { spawn } = require('child_process');
 const host = 'node' + utils.getNodeMajorVersion();
 let target = process.argv[2] || 'host';
 if (target === 'host') target = host;
@@ -17,6 +18,8 @@ if (target === 'host') target = host;
 
 const flavor = process.env.FLAVOR || process.argv[3] || 'all';
 
+const isCI = process.env.CI === 'true';
+
 console.log('');
 console.log('*************************************');
 console.log(target + ' ' + flavor);
@@ -86,18 +89,156 @@ if (flavor.match(/^test/)) {
 
 const files = globSync(list, { ignore });
 
-files.sort().some(function (file) {
-  file = path.resolve(file);
-  try {
-    utils.spawn.sync('node', [path.basename(file), target], {
+function msToHumanDuration(ms) {
+  if (ms < 1000) return `${ms}ms`;
+  const seconds = Math.floor(ms / 1000);
+  const minutes = Math.floor(seconds / 60);
+  const hours = Math.floor(minutes / 60);
+  const human = [];
+  if (hours > 0) human.push(`${hours}h`);
+  if (minutes > 0) human.push(`${minutes % 60}m`);
+  if (seconds > 0) human.push(`${seconds % 60}s`);
+  return human.join(' ');
+}
+
+/** @type {Array<import('child_process').ChildProcessWithoutNullStreams>} */
+const activeProcesses = [];
+
+function runTest(file) {
+  return new Promise((resolve, reject) => {
+    const process = spawn('node', [path.basename(file), target], {
       cwd: path.dirname(file),
-      stdio: 'inherit',
+      stdio: 'pipe',
+    });
+
+    activeProcesses.push(process);
+
+    const removeProcess = () => {
+      const index = activeProcesses.indexOf(process);
+      if (index !== -1) {
+        activeProcesses.splice(index, 1);
+      }
+    };
+
+    const output = [];
+
+    const rejectWithError = (error) => {
+      error.logOutput = `${error.message}\n${output.join('')}`;
+      reject(error);
+    };
+
+    process.on('close', (code) => {
+      removeProcess();
+      if (code !== 0) {
+        rejectWithError(new Error(`Process exited with code ${code}`));
+      } else {
+        resolve();
+      }
     });
-  } catch (error) {
-    console.log();
-    console.log(`> ${pc.red('Error!')} ${error.message}`);
-    console.log(`> ${pc.red('Error!')} ${file} FAILED (in ${target})`);
+
+    process.stdout.on('data', (data) => {
+      output.push(data.toString());
+    });
+
+    process.stderr.on('data', (data) => {
+      output.push(data.toString());
+    });
+
+    process.on('error', (error) => {
+      removeProcess();
+      rejectWithError(error);
+    });
+  });
+}
+
+const clearLastLine = () => {
+  if (isCI) return;
+  process.stdout.moveCursor(0, -1); // up one line
+  process.stdout.clearLine(1); // from cursor to end
+};
+
+async function run() {
+  let done = 0;
+  let ok = 0;
+  let failed = [];
+  const start = Date.now();
+
+  function addLog(log, isError = false) {
+    clearLastLine();
+    if (isError) {
+      console.error(log);
+    } else {
+      console.log(log);
+    }
+  }
+
+  const promises = files.sort().map((file) => async () => {
+    file = path.resolve(file);
+    const startTest = Date.now();
+    try {
+      if (!isCI) {
+        console.log(pc.gray(`⏳ ${file} - ${done}/${files.length}`));
+      }
+      await runTest(file);
+      ok++;
+      addLog(
+        pc.green(
+          `✔ ${file} ok - ${msToHumanDuration(Date.now() - startTest)}`,
+        ),
+      );
+    } catch (error) {
+      failed.push({
+        file,
+        error: error.message,
+        output: error.logOutput,
+      });
+      addLog(
+        pc.red(
+          `✖ ${file} FAILED (in ${target}) - ${msToHumanDuration(Date.now() - startTest)}\n${error.message}`,
+        ),
+        true,
+      );
+    }
+
+    done++;
+  });
+
+  for (let i = 0; i < promises.length; i++) {
+    await promises[i]();
+  }
+
+  const end = Date.now();
+
+  console.log('');
+  console.log('*************************************');
+  console.log('Summary');
+  console.log('*************************************');
+  console.log('');
+
+  console.log(`Total: ${done}`);
+  console.log(`Ok: ${ok}`);
+  console.log(`Failed: ${failed.length}`);
+  // print failed tests
+  for (const { file, error, output } of failed) {
+    console.log('');
+    console.log(`--- ${file} ---`);
+    console.log(pc.red(error));
+    console.log(pc.red(output));
+  }
+  console.log(`Time: ${msToHumanDuration(end - start)}`);
+
+  if (failed.length > 0) {
     process.exit(2);
   }
-  console.log(file, 'ok');
-});
+}
+
+function cleanup() {
+  for (const process of activeProcesses) {
+    process.kill();
+  }
+}
+
+process.on('SIGINT', cleanup);
+process.on('SIGTERM', cleanup);
+
+run();