cli, fixes #921, #1113, #1126, #1127, make DEBUG logs work, show error when xvfb exits with status code 1, force tty in linux, handle colors in windows, enable logging cypress:xvfb stderr

* cli: fixes #838 start cypress in dev by routing through the CLI

- matches how we run in production better to keep parity and consistency

* cli: add coerceFalse for clarity

* cli: add global flag, update to work with windows

* server: bring into parity with root scripts

* cli: just execute start script directly to work with windows

* cli: if colors are supported then force them via env vars

- this fixes windows not displaying colors from electron because by
default isTTY is false (due to electron)

* cli: fixes #921 don't ignore stderr, inherit stdio on everything except when linux + xvfb

- filter out stderr messages coming from Xlib or libudev (from xvfb)

* cli, server: force stderr tty so that normalize tty behavior when piping

* server: drop in supports color so debug outputs more colors!

* server: remove empty line

* root: refer to cypress not monorepo

* cli: make util.supportsColor return boolean

* cl: add tests around spawn behavior with forcing colors, tty, and stdio configuration

* cli: handle xvfb onStderrData callback to output debug information

* cli: handle non zero exit code error from xvfb with special message

cli/__snapshots__/errors_spec.js

@@ -1,4 +1,5 @@
 exports['errors individual has the following errors 1'] = [
+  "nonZeroExitCodeXvfb",
   "missingXvfb",
   "missingApp",
   "missingDependency",

cli/lib/errors.js

@@ -33,6 +33,15 @@ const missingApp = {
   `,
 }
 
+const nonZeroExitCodeXvfb = {
+  description: 'XVFB exited with a non zero exit code.',
+  solution: stripIndent`
+    There was a problem spawning Xvfb.
+
+    This is likely a problem with your system, permissions, or installation of Xvfb.
+    `,
+}
+
 const missingXvfb = {
   description: 'Your system is missing the dependency: XVFB',
   solution: stripIndent`
@@ -168,6 +177,7 @@ module.exports = {
   formErrorText,
   throwFormErrorText,
   errors: {
+    nonZeroExitCodeXvfb,
     missingXvfb,
     missingApp,
     missingDependency,

cli/lib/exec/spawn.js

@@ -1,32 +1,45 @@
 const _ = require('lodash')
 const os = require('os')
 const cp = require('child_process')
+const tty = require('tty')
 const path = require('path')
 const Promise = require('bluebird')
-const devNull = require('dev-null')
 const debug = require('debug')('cypress:cli')
 
+const util = require('../util')
 const info = require('../tasks/info')
 const xvfb = require('./xvfb')
 const { throwFormErrorText, errors } = require('../errors')
 
-function getStdio () {
-  // https://github.com/cypress-io/cypress/issues/717
-  // need to switch this else windows crashes
-  if (os.platform() === 'win32') {
-    return ['inherit', 'pipe', 'pipe']
+const isXlibOrLibudevRe = /^(Xlib|libudev)/
+
+function needsStderrPipe (needsXvfb) {
+  return needsXvfb && os.platform() === 'linux'
+}
+
+function getStdio (needsXvfb) {
+  // https://github.com/cypress-io/cypress/issues/921
+  if (needsStderrPipe(needsXvfb)) {
+    // returning pipe here so we can massage stderr
+    // and remove garbage from Xlib and libuv
+    // due to starting the XVFB process on linux
+    return ['inherit', 'inherit', 'pipe']
   }
 
-  return ['inherit', 'inherit', 'ignore']
+  return 'inherit'
 }
 
 module.exports = {
   start (args, options = {}) {
+    const needsXvfb = xvfb.isNeeded()
+
+    debug('needs XVFB?', needsXvfb)
+
     args = [].concat(args)
 
     _.defaults(options, {
       detached: false,
-      stdio: getStdio(),
+      stdio: getStdio(needsXvfb),
     })
 
     const spawn = () => {
@@ -46,13 +59,48 @@ module.exports = {
         // strip dev out of child process options
         options = _.omit(options, 'dev')
 
+        // when running in electron in windows
+        // it never supports color but we're
+        // going to force it anyway as long
+        // as our parent cli process can support
+        // colors!
+        //
+        // also when we are in linux and using the 'pipe'
+        // option our process.stderr.isTTY will not be true
+        // which ends up disabling the colors =(
+        if (util.supportsColor()) {
+          process.env.FORCE_COLOR = 1
+          process.env.DEBUG_COLORS = 1
+          process.env.MOCHA_COLORS = 1
+        }
+
+        // if we needed to pipe stderr and we're currently
+        // a tty on stderr
+        if (needsStderrPipe(needsXvfb) && tty.isatty(2)) {
+          // then force stderr tty
+          //
+          // this is necessary because we want our child
+          // electron browser to behave _THE SAME WAY_ as
+          // if we aren't using pipe. pipe is necessary only
+          // to filter out garbage on stderr -____________-
+          process.env.FORCE_STDERR_TTY = 1
+        }
+
         const child = cp.spawn(cypressPath, args, options)
         child.on('close', resolve)
         child.on('error', reject)
 
-        // if these are defined then we manually pipe for windows
-        child.stdout && child.stdout.pipe(process.stdout)
-        child.stderr && child.stderr.pipe(devNull())
+        // if this is defined then we are manually piping for linux
+        // to filter out the garbage
+        child.stderr && child.stderr.on('data', (data) => {
+          // bail if this is a line from xlib or libudev
+          if (isXlibOrLibudevRe.test(data.toString())) {
+            return
+          }
+
+          // else pass it along!
+          process.stderr.write(data)
+        })
 
         if (options.detached) {
           child.unref()
@@ -63,9 +111,6 @@ module.exports = {
     const userFriendlySpawn = () =>
       spawn().catch(throwFormErrorText(errors.unexpected))
 
-    const needsXvfb = xvfb.isNeeded()
-    debug('needs XVFB?', needsXvfb)
-
     if (needsXvfb) {
       return xvfb.start()
       .then(userFriendlySpawn)

cli/lib/exec/xvfb.js

@@ -3,17 +3,33 @@ const Promise = require('bluebird')
 const Xvfb = require('@cypress/xvfb')
 const R = require('ramda')
 const debug = require('debug')('cypress:cli')
+const debugXvfb = require('debug')('cypress:xvfb')
 const { throwFormErrorText, errors } = require('../errors')
 
-const xvfb = Promise.promisifyAll(new Xvfb({ silent: true }))
+const xvfb = Promise.promisifyAll(new Xvfb({
+  onStderrData (data) {
+    if (debugXvfb.enabled) {
+      debugXvfb(data.toString())
+    }
+  },
+}))
 
 module.exports = {
+  _debugXvfb: debugXvfb, // expose for testing
+
   _xvfb: xvfb, // expose for testing
 
   start () {
     debug('Starting XVFB')
     return xvfb.startAsync()
-    .catch(throwFormErrorText(errors.missingXvfb))
+    .catch({ nonZeroExitCode: true }, throwFormErrorText(errors.nonZeroExitCodeXvfb))
+    .catch((err) => {
+      if (err.known) {
+        throw err
+      }
+
+      return throwFormErrorText(errors.missingXvfb)(err)
+    })
   },
 
   stop () {

cli/lib/util.js

@@ -3,6 +3,7 @@ const R = require('ramda')
 const path = require('path')
 const isCi = require('is-ci')
 const chalk = require('chalk')
+const supportsColor = require('supports-color')
 const isInstalledGlobally = require('is-installed-globally')
 const pkg = require(path.join(__dirname, '..', 'package.json'))
 const logger = require('./logger')
@@ -38,6 +39,12 @@ const util = {
     return isCi
   },
 
+  supportsColor () {
+    // we only care about stderr supporting color
+    // since thats what our DEBUG logs use
+    return Boolean(supportsColor.stderr)
+  },
+
   cwd () {
     return process.cwd()
   },

cli/package.json

@@ -26,7 +26,7 @@
   "types": "types",
   "dependencies": {
     "@cypress/listr-verbose-renderer": "0.4.1",
-    "@cypress/xvfb": "1.0.4",
+    "@cypress/xvfb": "1.1.0",
     "@types/blob-util": "1.3.3",
     "@types/bluebird": "3.5.18",
     "@types/chai": "4.0.8",
@@ -43,7 +43,6 @@
     "commander": "2.11.0",
     "common-tags": "1.4.0",
     "debug": "3.1.0",
-    "dev-null": "0.1.1",
     "extract-zip": "1.6.6",
     "fs-extra": "4.0.1",
     "getos": "2.8.4",
@@ -58,6 +57,7 @@
     "ramda": "0.24.1",
     "request": "2.81.0",
     "request-progress": "0.3.1",
+    "supports-color": "5.1.0",
     "tmp": "0.0.31",
     "url": "0.11.0",
     "yauzl": "2.8.0"

cli/test/lib/exec/spawn_spec.js

@@ -2,11 +2,13 @@ require('../../spec_helper')
 
 const cp = require('child_process')
 const os = require('os')
+const tty = require('tty')
 const path = require('path')
 
 const info = require(`${lib}/tasks/info`)
 const xvfb = require(`${lib}/exec/xvfb`)
 const spawn = require(`${lib}/exec/spawn`)
+const util = require(`${lib}/util.js`)
 
 describe('exec spawn', function () {
   beforeEach(function () {
@@ -14,21 +16,25 @@ describe('exec spawn', function () {
     this.spawnedProcess = this.sandbox.stub({
       on: () => {},
       unref: () => {},
-      stdout: {
-        pipe: () => {},
-      },
-      stderr: {
-        pipe: () => {},
-      },
+      stderr: this.sandbox.stub({
+        on: () => {},
+      }),
     })
     this.sandbox.stub(cp, 'spawn').returns(this.spawnedProcess)
     this.sandbox.stub(xvfb, 'start').resolves()
     this.sandbox.stub(xvfb, 'stop').resolves()
-    this.sandbox.stub(xvfb, 'isNeeded').returns(true)
+    this.sandbox.stub(xvfb, 'isNeeded').returns(false)
     this.sandbox.stub(info, 'getPathToExecutable').returns('/path/to/cypress')
   })
 
   context('.start', function () {
+    afterEach(() => {
+      delete process.env.FORCE_COLOR
+      delete process.env.DEBUG_COLORS
+      delete process.env.MOCHA_COLORS
+      delete process.env.FORCE_STDERR_TTY
+    })
+
     it('passes args + options to spawn', function () {
       this.spawnedProcess.on.withArgs('close').yieldsAsync(0)
 
@@ -50,6 +56,8 @@ describe('exec spawn', function () {
     })
 
     it('starts xvfb when needed', function () {
+      xvfb.isNeeded.returns(true)
+
       this.spawnedProcess.on.withArgs('close').yieldsAsync(0)
 
       return spawn.start('--foo')
@@ -59,8 +67,6 @@ describe('exec spawn', function () {
     })
 
     it('does not start xvfb when its not needed', function () {
-      xvfb.isNeeded.returns(false)
-
       this.spawnedProcess.on.withArgs('close').yieldsAsync(0)
 
       return spawn.start('--foo')
@@ -70,6 +76,8 @@ describe('exec spawn', function () {
     })
 
     it('stops xvfb when spawn closes', function () {
+      xvfb.isNeeded.returns(true)
+
       this.spawnedProcess.on.withArgs('close').yieldsAsync(0)
       this.spawnedProcess.on.withArgs('close').yields()
 
@@ -118,22 +126,125 @@ describe('exec spawn', function () {
       })
     })
 
-    it('uses inherit/inherit/ignore when not windows', function () {
-      this.sandbox.stub(os, 'platform').returns('darwin')
-
+    it('forces colors when colors are supported', function () {
       this.spawnedProcess.on.withArgs('close').yieldsAsync(0)
 
+      this.sandbox.stub(util, 'supportsColor').returns(true)
+
       return spawn.start()
       .then(() => {
-        expect(cp.spawn.firstCall.args[2]).to.deep.eq({
-          detached: false,
-          stdio: ['inherit', 'inherit', 'ignore'],
+        'FORCE_COLOR DEBUG_COLORS MOCHA_COLORS'.split(' ').forEach((prop) => {
+          expect(process.env[prop], prop).to.eq('1')
         })
       })
     })
 
-    it('uses inherit/pipe/pipe when windows', function () {
-      this.sandbox.stub(os, 'platform').returns('win32')
+    it('does not force colors when colors are not supported', function () {
+      this.spawnedProcess.on.withArgs('close').yieldsAsync(0)
+
+      this.sandbox.stub(util, 'supportsColor').returns(false)
+
+      return spawn.start()
+      .then(() => {
+        'FORCE_COLOR DEBUG_COLORS MOCHA_COLORS'.split(' ').forEach((prop) => {
+          expect(process.env[prop], prop).to.be.undefined
+        })
+      })
+    })
+
+    it('forces stderr tty when needs xvfb and stderr is tty', function () {
+      this.spawnedProcess.on.withArgs('close').yieldsAsync(0)
+
+      this.sandbox.stub(tty, 'isatty').returns(true)
+      this.sandbox.stub(os, 'platform').returns('linux')
+      xvfb.isNeeded.returns(true)
+
+      return spawn.start()
+      .then(() => {
+        expect(process.env.FORCE_STDERR_TTY, 'FORCE_STDERR_TTY').to.eq('1')
+      })
+    })
+
+    it('does not force stderr tty when needs xvfb isnt needed', function () {
+      this.spawnedProcess.on.withArgs('close').yieldsAsync(0)
+
+      this.sandbox.stub(tty, 'isatty').returns(true)
+      this.sandbox.stub(os, 'platform').returns('linux')
+
+      return spawn.start()
+      .then(() => {
+        expect(process.env.FORCE_STDERR_TTY).to.be.undefined
+      })
+    })
+
+    it('does not force stderr tty when stderr is not currently tty', function () {
+      this.spawnedProcess.on.withArgs('close').yieldsAsync(0)
+
+      this.sandbox.stub(tty, 'isatty').returns(false)
+      this.sandbox.stub(os, 'platform').returns('linux')
+      xvfb.isNeeded.returns(true)
+
+      return spawn.start()
+      .then(() => {
+        expect(process.env.FORCE_STDERR_TTY).to.be.undefined
+      })
+    })
+
+    it('writes to process.stderr when piping', function () {
+      const buf1 = new Buffer('asdf')
+
+      this.spawnedProcess.stderr.on
+      .withArgs('data')
+      .yields(buf1)
+
+      xvfb.isNeeded.returns(true)
+
+      this.spawnedProcess.on.withArgs('close').yieldsAsync(0)
+
+      this.sandbox.stub(process.stderr, 'write')
+      this.sandbox.stub(tty, 'isatty').returns(false)
+      this.sandbox.stub(os, 'platform').returns('linux')
+      xvfb.isNeeded.returns(true)
+
+      return spawn.start()
+      .then(() => {
+        expect(process.stderr.write).to.be.calledWith(buf1)
+      })
+    })
+
+    it('does not write to process.stderr when from xlib or libudev', function () {
+      const buf1 = new Buffer('Xlib: something foo')
+      const buf2 = new Buffer('libudev something bar')
+
+      this.spawnedProcess.stderr.on
+      .withArgs('data')
+      .onFirstCall()
+      .yields(buf1)
+      .onSecondCall()
+      .yields(buf2)
+
+      xvfb.isNeeded.returns(true)
+
+      this.spawnedProcess.on.withArgs('close').yieldsAsync(0)
+
+      this.sandbox.stub(process.stderr, 'write')
+      this.sandbox.stub(tty, 'isatty').returns(false)
+      this.sandbox.stub(os, 'platform').returns('linux')
+      xvfb.isNeeded.returns(true)
+
+      return spawn.start()
+      .then(() => {
+        expect(process.stderr.write).not.to.be.calledWith(buf1)
+        expect(process.stderr.write).not.to.be.calledWith(buf2)
+      })
+    })
+
+    it('filters out process.stderr when piping')
+
+    it('uses inherit/inherit/pipe when linux and xvfb is needed', function () {
+      xvfb.isNeeded.returns(true)
+
+      this.sandbox.stub(os, 'platform').returns('linux')
 
       this.spawnedProcess.on.withArgs('close').yieldsAsync(0)
 
@@ -141,7 +252,23 @@ describe('exec spawn', function () {
       .then(() => {
         expect(cp.spawn.firstCall.args[2]).to.deep.eq({
           detached: false,
-          stdio: ['inherit', 'pipe', 'pipe'],
+          stdio: ['inherit', 'inherit', 'pipe'],
+        })
+      })
+    })
+
+    ;['win32', 'darwin', 'linux'].forEach((platform) => {
+      it(`uses inherit when '${platform}' and xvfb is not needed`, function () {
+        this.sandbox.stub(os, 'platform').returns(platform)
+
+        this.spawnedProcess.on.withArgs('close').yieldsAsync(0)
+
+        return spawn.start()
+        .then(() => {
+          expect(cp.spawn.firstCall.args[2]).to.deep.eq({
+            detached: false,
+            stdio: 'inherit',
+          })
         })
       })
     })

cli/test/lib/exec/xvfb_spec.js

@@ -4,6 +4,28 @@ const os = require('os')
 const xvfb = require(`${lib}/exec/xvfb`)
 
 describe('exec xvfb', function () {
+  context('debugXvfb', function () {
+    it('outputs when enabled', function () {
+      this.sandbox.stub(process.stderr, 'write')
+      this.sandbox.stub(xvfb._debugXvfb, 'enabled').value(true)
+
+      xvfb._xvfb._onStderrData('asdf')
+
+      expect(process.stderr.write).to.be.calledWithMatch('cypress:xvfb')
+      expect(process.stderr.write).to.be.calledWithMatch('asdf')
+    })
+
+    it('does not output when disabled', function () {
+      this.sandbox.stub(process.stderr, 'write')
+      this.sandbox.stub(xvfb._debugXvfb, 'enabled').value(false)
+
+      xvfb._xvfb._onStderrData('asdf')
+
+      expect(process.stderr.write).not.to.be.calledWithMatch('cypress:xvfb')
+      expect(process.stderr.write).not.to.be.calledWithMatch('asdf')
+    })
+  })
+
   context('#start', function () {
     it('passes', function () {
       this.sandbox.stub(xvfb._xvfb, 'startAsync').resolves()
@@ -14,11 +36,29 @@ describe('exec xvfb', function () {
       const message = 'nope'
       this.sandbox.stub(xvfb._xvfb, 'startAsync').rejects(new Error(message))
       return xvfb.start()
-        .then(() => {
-          throw new Error('Should have thrown an error')
-        }, (err) => {
-          expect(err.message).to.include(message)
-        })
+      .then(() => {
+        throw new Error('Should have thrown an error')
+      })
+      .catch((err) => {
+        expect(err.message).to.include(message)
+      })
+    })
+
+    it('fails when xvfb exited with non zero exit code', function () {
+      const e = new Error('something bad happened')
+      e.nonZeroExitCode = true
+
+      this.sandbox.stub(xvfb._xvfb, 'startAsync').rejects(e)
+
+      return xvfb.start()
+      .then(() => {
+        throw new Error('Should have thrown an error')
+      })
+      .catch((err) => {
+        expect(err.known).to.be.true
+        expect(err.message).to.include('something bad happened')
+        expect(err.message).to.include('XVFB exited with a non zero exit code.')
+      })
     })
   })
 

cli/test/lib/util_spec.js

@@ -1,8 +1,10 @@
 require('../spec_helper')
 
+const snapshot = require('snap-shot-it')
+const supportsColor = require('supports-color')
+
 const util = require(`${lib}/util`)
 const logger = require(`${lib}/logger`)
-const snapshot = require('snap-shot-it')
 
 describe('util', function () {
   beforeEach(function () {
@@ -10,7 +12,7 @@ describe('util', function () {
     this.sandbox.stub(logger, 'error')
   })
 
-  context('stdoutLineMatches', () => {
+  context('.stdoutLineMatches', () => {
     const { stdoutLineMatches } = util
 
     it('is a function', () => {
@@ -41,7 +43,7 @@ describe('util', function () {
     })
   })
 
-  context('normalizeModuleOptions', () => {
+  context('.normalizeModuleOptions', () => {
     const { normalizeModuleOptions } = util
 
     it('does not change other properties', () => {
@@ -90,6 +92,21 @@ describe('util', function () {
     })
   })
 
+  context('.supportsColor', function () {
+    it('is true on obj return for stderr', function () {
+      const obj = {}
+      this.sandbox.stub(supportsColor, 'stderr').value(obj)
+
+      expect(util.supportsColor()).to.be.true
+    })
+
+    it('is false on false return for stderr', function () {
+      this.sandbox.stub(supportsColor, 'stderr').value(false)
+
+      expect(util.supportsColor()).to.be.false
+    })
+  })
+
   it('.exit', function () {
     util.exit(2)
     expect(process.exit).to.be.calledWith(2)

packages/server/index.js

@@ -1,3 +1,6 @@
+// override tty if we're being forced to
+require('./lib/util/tty').override()
+
 // if we are running in electron
 // we must hack around busted timers
 if (process.versions.electron) {

packages/server/lib/modes/headless.coffee

@@ -234,7 +234,6 @@ module.exports = {
     new Promise (resolve) ->
       return if exit is false
 
-
       onEarlyExit = (errMsg) ->
         ## probably should say we ended
         ## early too: (Ended Early: true)

packages/server/lib/util/tty.js

@@ -0,0 +1,25 @@
+const tty = require('tty')
+
+const override = () => {
+  // if we're being told to force STDERR
+  if (process.env.FORCE_STDERR_TTY === '1') {
+    const isatty = tty.isatty
+    const _fd = process.stderr.fd
+
+    process.stderr.isTTY = true
+
+    tty.isatty = function (fd) {
+      if (fd === _fd) {
+        // force stderr to return true
+        return true
+      }
+
+      // else pass through
+      return isatty.call(this, fd)
+    }
+  }
+}
+
+module.exports = {
+  override,
+}

packages/server/package.json

@@ -149,6 +149,7 @@
     "sinon-as-promised": "3.0.1",
     "string-to-stream": "^1.0.1",
     "strip-ansi": "^3.0.1",
+    "supports-color": "^5.1.0",
     "syntax-error": "^1.1.4",
     "tar-fs": "^1.11.1",
     "through": "2.3.6",

packages/server/test/unit/tty_spec.coffee

@@ -0,0 +1,48 @@
+require("../spec_helper")
+
+tty = require("tty")
+ttyUtil = require("#{root}lib/util/tty")
+
+isTTY = process.stderr.isTTY
+
+describe "lib/util/tty", ->
+  context ".override", ->
+    beforeEach ->
+      process.env.FORCE_STDERR_TTY = '1'
+
+      ## do this so can we see when its modified
+      process.stderr.isTTY = undefined
+
+    afterEach ->
+      ## restore sanity
+      delete process.env.FORCE_STDERR_TTY
+      process.stderr.isTTY = isTTY
+
+    it "is noop when not process.env.FORCE_STDERR_TTY", ->
+      delete process.env.FORCE_STDERR_TTY
+
+      expect(ttyUtil.override()).to.be.undefined
+
+      expect(process.stderr.isTTY).to.be.undefined
+
+    it "forces process.stderr.isTTY to be true", ->
+      ttyUtil.override()
+
+      expect(process.stderr.isTTY).to.be.true
+
+    it "modies isatty calls for stderr", ->
+      fd0 = tty.isatty(0)
+      fd1 = tty.isatty(1)
+
+      isatty = @sandbox.spy(tty, 'isatty')
+
+      ttyUtil.override()
+
+      expect(tty.isatty(0)).to.eq(fd0)
+      expect(isatty.firstCall).to.be.calledWith(0)
+
+      expect(tty.isatty(1)).to.eq(fd1)
+      expect(isatty.secondCall).to.be.calledWith(1)
+
+      expect(tty.isatty(2)).to.be.true
+      expect(isatty).not.to.be.calledThrice

scripts/run-docker-local.sh

@@ -1,17 +1,17 @@
 set e+x
 
-echo "This script should be run from monorepo's root"
+echo "This script should be run from cypress's root"
 
 name=cypress/browsers:chrome62
 echo "Pulling CI container $name"
 
 docker pull $name
 
-echo "Starting Docker image with monorepo volume attached"
+echo "Starting Docker image with cypress volume attached"
 echo "You should be able to edit files locally"
 echo "but execute the code in the container"
 
-docker run -v $PWD:/home/person/cypress-monorepo \
-  -w /home/person/cypress-monorepo \
+docker run -v $PWD:/home/person/cypress \
+  -w /home/person/cypress \
   -it $name \
   /bin/bash