test: print stderr upon test failure (#3448)

test/runner/index.js

@@ -32,6 +32,7 @@ program
   .option('-j, --jobs <jobs>', 'Number of concurrent jobs for --parallel; use 1 to run in serial, default: (number of CPU cores / 2)', Math.ceil(require('os').cpus().length / 2))
   .option('--reporter <reporter>', 'Specify reporter to use', '')
   .option('--trial-run', 'Only collect the matching tests and report them as passing')
+  .option('--dumpio', 'Dump stdout and stderr from workers', false)
   .option('--timeout <timeout>', 'Specify test timeout threshold (in milliseconds), default: 10000', 10000)
   .action(async (command) => {
     // Collect files
@@ -81,8 +82,10 @@ program
 
     // Trial run does not need many workers, use one.
     const jobs = command.trialRun ? 1 : command.jobs;
-    const runner = new Runner(rootSuite, jobs, {
+    const runner = new Runner(rootSuite, {
+      dumpio: command.dumpio,
       grep: command.grep,
+      jobs,
       reporter: command.reporter,
       retries: command.retries,
       timeout: command.timeout,

test/runner/runner.js

@@ -26,15 +26,14 @@ const constants = Mocha.Runner.constants;
 process.setMaxListeners(0);
 
 class Runner extends EventEmitter {
-  constructor(suite, jobs, options) {
+  constructor(suite, options) {
     super();
     this._suite = suite;
-    this._jobs = jobs;
     this._options = options;
     this._workers = new Set();
     this._freeWorkers = [];
     this._workerClaimers = [];
-    this._workerId = 0;
+    this._lastWorkerId = 0;
     this._pendingJobs = 0;
     this.stats = {
       duration: 0,
@@ -76,15 +75,8 @@ class Runner extends EventEmitter {
 
   _runJob(worker, file) {
     ++this._pendingJobs;
-    worker.send({ method: 'run', params: { file, options: this._options } });
+    worker.run(file);
-    const messageListener = (message) => {
+    worker.once('done', params => {
-      const { method, params } = message;
-      if (method !== 'done') {
-        this._messageFromWorker(method, params);
-        return;
-      }
-      worker.off('message', messageListener);
-
       --this._pendingJobs;
       this.stats.duration += params.stats.duration;
       this.stats.failures += params.stats.failures;
@@ -97,8 +89,7 @@ class Runner extends EventEmitter {
         this._workerAvailable(worker);
       if (this._runCompleteCallback && !this._pendingJobs)
         this._runCompleteCallback();
-    };
+    });
-    worker.on('message', messageListener)
   }
 
   async _obtainWorker() {
@@ -106,7 +97,7 @@ class Runner extends EventEmitter {
     if (this._freeWorkers.length)
       return this._freeWorkers.pop();
     // If we can create worker, create it.
-    if (this._workers.size < this._jobs)
+    if (this._workers.size < this._options.jobs)
       this._createWorker();
     // Wait for the next available worker.
     await new Promise(f => this._workerClaimers.push(f));
@@ -122,10 +113,18 @@ class Runner extends EventEmitter {
   }
 
   _createWorker() {
-    const worker = child_process.fork(path.join(__dirname, 'worker.js'), {
+    const worker = new Worker(this);
-      detached: false,
+    worker.on('test', params => this.emit(constants.EVENT_TEST_BEGIN, this._updateTest(params.test)));
-      env: process.env,
+    worker.on('pending', params => this.emit(constants.EVENT_TEST_PENDING, this._updateTest(params.test)));
-      stdio: 'ignore'
+    worker.on('pass', params => this.emit(constants.EVENT_TEST_PASS, this._updateTest(params.test)));
+    worker.on('fail', params => {
+      const out = worker.takeOut();
+      if (out.length)
+        params.error.stack += '\n\x1b[33mstdout: ' + out.join('\n') + '\x1b[0m';
+      const err = worker.takeErr();
+      if (err.length)
+        params.error.stack += '\n\x1b[33mstderr: ' + err.join('\n') + '\x1b[0m';
+      this.emit(constants.EVENT_TEST_FAIL, this._updateTest(params.test), params.error);
     });
     worker.on('exit', () => {
       this._workers.delete(worker);
@@ -133,39 +132,14 @@ class Runner extends EventEmitter {
         this._stopCallback();
     });
     this._workers.add(worker);
-    worker.send({ method: 'init', params: { workerId: ++this._workerId } });
+    worker.init().then(() => this._workerAvailable(worker));
-    worker.once('message', () => {
-      // Ready ack.
-      this._workerAvailable(worker);
-    });
-  }
-
-  _stopWorker(worker) {
-    worker.send({ method: 'stop' });
   }
 
   async _restartWorker(worker) {
-    this._stopWorker(worker);
+    worker.stop();
     this._createWorker();
   }
 
-  _messageFromWorker(method, params) {
-    switch (method) {
-      case 'test':
-        this.emit(constants.EVENT_TEST_BEGIN, this._updateTest(params.test));
-        break;
-      case 'pending':
-        this.emit(constants.EVENT_TEST_PENDING, this._updateTest(params.test));
-        break;
-      case 'pass':
-        this.emit(constants.EVENT_TEST_PASS, this._updateTest(params.test));
-        break;
-      case 'fail':
-        this.emit(constants.EVENT_TEST_FAIL, this._updateTest(params.test), params.error);
-        break;
-    }
-  }
-
   _updateTest(serialized) {
     const test = this._tests.get(serialized.id);
     test.duration = serialized.duration;
@@ -175,9 +149,69 @@ class Runner extends EventEmitter {
   async stop() {
     const result = new Promise(f => this._stopCallback = f);
     for (const worker of this._workers)
-      this._stopWorker(worker);
+      worker.stop();
     await result;
   }
 }
 
+let lastWorkerId = 0;
+
+class Worker extends EventEmitter {
+  constructor(runner) {
+    super();
+    this.runner = runner;
+
+    this.process = child_process.fork(path.join(__dirname, 'worker.js'), {
+      detached: false,
+      env: process.env,
+      stdio: ['ignore', 'pipe', 'pipe', 'ipc']
+    });
+    this.process.on('exit', () => this.emit('exit'));
+    this.process.on('message', message => {
+      const { method, params } = message;
+      this.emit(method, params);
+    });
+    this.stdout = [];
+    this.stderr = [];
+    this.process.stdout.on('data', data => {
+      if (runner._options.dumpio)
+        process.stdout.write(data);
+      else
+        this.stdout.push(data.toString());
+    });
+  
+    this.process.stderr.on('data', data => {
+      if (runner._options.dumpio)
+        process.stderr.write(data);
+      else
+        this.stderr.push(data.toString());
+    });
+  }
+
+  async init() {
+    this.process.send({ method: 'init', params: { workerId: lastWorkerId++ } });
+    await new Promise(f => this.process.once('message', f));  // Ready ack
+  }
+
+  run(file) {
+    this.process.send({ method: 'run', params: { file, options: this.runner._options } });
+  }
+
+  stop() {
+    this.process.send({ method: 'stop' });
+  }
+
+  takeOut() {
+    const result = this.stdout;
+    this.stdout = [];
+    return result;
+  }
+
+  takeErr() {
+    const result = this.stderr;
+    this.stderr = [];
+    return result;
+  }
+}
+
 module.exports = { Runner };