Merge pull request #289 from TestArmada/make-nightwatch-err-and-warn-…

…visible-in-stdout

Make nightwatch err and warn visible in stdout

package.json

@@ -1,6 +1,6 @@
 {
   "name": "testarmada-magellan",
-  "version": "11.0.10",
+  "version": "11.0.11",
   "description": "Massively parallel automated testing",
   "main": "src/main",
   "directories": {
@@ -28,6 +28,7 @@
   "scripts": {
     "test": "jest",
     "lint": "eslint src/** bin/**",
+    "lint-fix": "eslint --fix src/** bin/**",
     "upload-coverage": "codecov"
   },
   "dependencies": {
@@ -45,6 +46,7 @@
     "request": "^2.55.0",
     "sanitize-filename": "^1.5.3",
     "slugify": "^1.0.2",
+    "stream-slic3r": "^1.0.0",
     "sync-request": "^4.0.1",
     "testarmada-magellan-local-executor": "^2.0.0",
     "testarmada-tree-kill": "^2.0.0",

src/cli.js

@@ -104,6 +104,19 @@ module.exports = {
                 rootWorkingDirectory: process.cwd()
               });
         }
+        if (settings.framework === "testarmada-magellan-nightwatch-plugin") {
+
+          if (opts.argv.debug) {
+            // if the user has SET the debug flag, that means they want ALL the logs and NOT
+            // filter out anything. we must let the util/ChildProcess.js know this information,
+            // we will use the ENV to relay this information
+            process.env.DEBUG = true; // this tells childProcess.js not to filter out any logs
+          }
+
+          // turn on nightwatch verbose logs so we can capture the nightwatch errors and warns
+          // inside util/childProcess we filter out the verbose info logs of nightwatch
+          opts.argv.debug = true; // this turns on nightwatch verbose logging
+        }
         settings.testFramework.initialize(opts.argv, settings.pluginOptions);
       } catch (e) {
         frameworkInitializationException = e;

src/util/childProcess.js

@@ -3,25 +3,53 @@
 const _ = require("lodash");
 const clc = require("cli-color");
 const EventEmitter = require("events").EventEmitter;
+const StreamSlicer = require("stream-slic3r");
 
 const logger = require("../logger");
 const logStamp = require("./logstamp");
 
 const MESSAGE = "message";
-const DATA = "data";
 const CLOSE = "close";
 
 const NOT_GOOD_ENUFF_ERROR_MESSAGE = "Connection refused! Is selenium server started?";
 const ADDED_ERROR_MESSAGE_CONTEXT = "If running on saucelabs, perhaps " +
     "you're out of capacity and should TRY RUN AGAIN LATER :)";
 
+// MAKE NIGHWATCH ERROR & WARN LOGS VISIBLE IN MAGELLAN STDOUT:
+// ------------------------------------------------------------------------------------------------
+// Currently the "ERROR" and "WARN" logs from nightwatch are suppressed when the "DEBUG" flag is
+// turned OFF.. and our customers ALWAYS use the "DEBUG" off, because if you turn it on your log
+// will be filled with base64 screenshot gobbledegook... Also, with the approach taken, we will
+// see all the "ERRORED" selenium request/response logs in our magellan log
+//
+// relevant code for this feature:
+//   DEBUG, STDOUT_WHITE_LIST, SLICE_ON_TEXT, infoSlicer, isTextWhiteListed
+// ------------------------------------------------------------------------------------------------
+
+// if the "this.handler.stdout" stream of the childprocess does not
+// include atleast one of these tokens then it will not be included in the "this.stdout"
+const STDOUT_WHITE_LIST = ["ERROR", "WARN", "Test Suite", "✖"];
+
+// we slice the VERBOSE nighwatch stdout stream on the purple INFO text that has black background
+const SLICE_ON_TEXT = "\x1B[1;35m\x1B[40mINFO\x1B[0m";
+
 module.exports = class ChildProcess {
   constructor(handler) {
     this.stdout = `${clc.yellowBright(logStamp())} =====> Magellan child process start\n`;
     this.stderr = "";
     this.handler = handler;
-    this.handler.stdout.on(DATA, this.onDataCallback.bind(this));
-    this.handler.stderr.on(DATA, this.onDataCallback.bind(this));
+
+    // create the nightwtach INFO slicer:
+    // if the stdout stream does not contain SLICE_ON_TEXT,
+    // then the entire stdout will be emitted 'data' with nothing sliced out
+    // otherwise the stream will be sliced on nighwatch INFO text (purple with black background)
+    // and each "slice" will be emitted 'data'
+    const infoSlicer = new StreamSlicer(SLICE_ON_TEXT);
+
+    // pipe the stdout stream into the slicer for slicing :)
+    this.handler.stdout.pipe(infoSlicer);
+
+    infoSlicer.on("data", this.onDataCallback.bind(this));
 
     this.emitter = new EventEmitter();
     this.emitter.stdout = handler.stdout;
@@ -48,21 +76,23 @@ module.exports = class ChildProcess {
     }
   }
 
+  isTextWhiteListed(text) {
+    if (process.env.DEBUG) {
+      // in debug mode we do not filter out any text
+      return true;
+    }
+    return STDOUT_WHITE_LIST.some(item => text.includes(item));
+  }
+
   onDataCallback(data) {
-    let text = "" + data;
-    if (!_.isEmpty(text.trim())) {
+    let text = data.toString().trim();
+    if (text.length > 0 && this.isTextWhiteListed(text)) {
       text = text
         .split("\n")
         .filter((line) => !_.isEmpty(line.trim()))
         .map((line) => `${clc.yellowBright(logStamp())} ${line}`)
         .join("\n");
-
-      /* istanbul ignore else */
-      if (!_.isEmpty(text)) {
-        this.stdout += text + "\n";
-      } else {
-        this.stdout += "\n";
-      }
+      this.stdout += text + "\n";
       this.addErrorMessageContext();
     }
   }

test/utils/child_process.test.js

@@ -10,7 +10,8 @@ const handler = {
   stdout: {
     on: () => { },
     removeAllListeners: () => { },
-    unpipe: () => { }
+    unpipe: () => { },
+    pipe: () => { }
   },
   stderr: {
     on: () => { },
@@ -68,8 +69,8 @@ describe('Child process', () => {
   test('should append data to stdout', () => {
     const cp = new ChildProcess(handler);
 
-    cp.onDataCallback('fake data');
-    cp.onDataCallback('real data');
+    cp.onDataCallback('WARN fake data');
+    cp.onDataCallback('WARN real data');
     cp.onDataCallback('');
 
     expect(cp.stdout).toContain('fake data');
@@ -79,9 +80,29 @@ describe('Child process', () => {
   test('should add context to error message', () => {
     const cp = new ChildProcess(handler);
 
-    cp.onDataCallback('Connection refused! Is selenium server started?')
+    cp.onDataCallback('ERROR Connection refused! Is selenium server started?')
 
     expect(cp.stdout).toContain('Connection refused! Is selenium server started?')    
     expect(cp.stdout).toContain(`If running on saucelabs, perhaps you're out of capacity and should TRY RUN AGAIN LATER :)`);
   })
+
+
+  test('should exclude text that is not white listed', () => {
+    const cp = new ChildProcess(handler);
+
+    cp.onDataCallback('This text is not white listed')
+
+    expect(cp.stdout.trim().endsWith('Magellan child process start')).toEqual(true)
+  })
+
+  test('should not exclude any text if env.debug is true', () => {
+    process.env.DEBUG = true
+    const cp = new ChildProcess(handler);
+
+    cp.onDataCallback('This text is not white listed')
+
+    expect(cp.stdout.trim().endsWith('Magellan child process start')).toEqual(false)
+  })
+
+
 });