capture electron console logs and more debug logs (cypress-io#2303)

packages/driver/src/cypress/cy.coffee

@@ -39,12 +39,6 @@ isPromiseLike = (ret) ->
 returnedFalse = (result) ->
   result is false
 
-silenceConsole = (contentWindow) ->
-  if c = contentWindow.console
-    c.log = ->
-    c.warn = ->
-    c.info = ->
-
 getContentWindow = ($autIframe) ->
   $autIframe.prop("contentWindow")
 
@@ -912,12 +906,6 @@ create = (specWindow, Cypress, Cookies, state, config, log) ->
       return null
 
     onBeforeAppWindowLoad: (contentWindow) ->
-      ## we silence the console when running headlessly
-      ## because console logs are kept around in memory for
-      ## inspection via the developer
-      if not config("isInteractive")
-        silenceConsole(contentWindow)
-
       ## we set window / document props before the window load event
       ## so that we properly handle events coming from the application
       ## from the time that happens BEFORE the load event occurs

packages/server/lib/browsers/electron.coffee

@@ -77,6 +77,9 @@ module.exports = {
 
     Promise
     .try =>
+      if options.show is false
+        @_attachDebugger(win.webContents)
+
       if ua = options.userAgent
         @_setUserAgent(win.webContents, ua)
 
@@ -92,6 +95,22 @@ module.exports = {
       win.loadURL(url)
     .return(win)
 
+  _attachDebugger: (webContents) ->
+    try
+      webContents.debugger.attach()
+      debug("debugger attached")
+    catch err
+      debug("debugger attached failed %o", { err })
+
+    webContents.debugger.on "detach", (event, reason) ->
+      debug("debugger detached due to %o", { reason })
+
+    webContents.debugger.on "message", (event, method, params) ->
+      if method is "Console.messageAdded"
+        debug("console message: %o", params.message)
+
+    webContents.debugger.sendCommand("Console.enable")
+
   _getPartition: (options) ->
     if options.isTextTerminal
       ## create dynamic persisted run
@@ -154,6 +173,8 @@ module.exports = {
 
       @_render(url, projectRoot, options)
       .then (win) =>
+        debug("rendered electron window")
+
         ## cause the webview to receive focus so that
         ## native browser focus + blur events fire correctly
         ## https://github.com/cypress-io/cypress/issues/1939
@@ -198,6 +219,8 @@ module.exports = {
           call("removeAllListeners")
           events.emit("exit")
 
+        debug("electron window configuration complete")
+
         return _.extend events, {
           browserWindow:      win
           kill:               call("close")

packages/server/lib/controllers/client.coffee

@@ -1,3 +1,4 @@
+debug = require("debug")("cypress:server:controllers:client")
 socketIo = require("@packages/socket")
 
 ## hold onto the client source + version in memory
@@ -8,6 +9,8 @@ module.exports = {
   handle: (req, res) ->
     etag = req.get("if-none-match")
 
+    debug("serving socket.io client %o", { etag, clientVersion })
+
     if etag and (etag is clientVersion)
       res.sendStatus(304)
     else

packages/server/lib/controllers/spec.coffee

@@ -1,11 +1,11 @@
-log = require("debug")("cypress:server:controllers:spec")
+debug = require("debug")("cypress:server:controllers:spec")
 Promise = require("bluebird")
 errors = require("../errors")
 preprocessor = require("../plugins/preprocessor")
 
 module.exports = {
   handle: (spec, req, res, config, next, project) ->
-    log("request for", spec)
+    debug("request for %o", { spec })
 
     res.set({
       "Cache-Control": "no-cache, no-store, must-revalidate"
@@ -18,7 +18,7 @@ module.exports = {
     preprocessor
     .getFile(spec, config)
     .then (filePath) ->
-      log("send #{filePath}")
+      debug("sending spec %o", { filePath })
       sendFile = Promise.promisify(res.sendFile.bind(res))
       sendFile(filePath)
     .catch { code: "ECONNABORTED" }, (err) ->

packages/server/lib/modes/run.coffee

@@ -169,7 +169,7 @@ displaySpecHeader = (name, curr, total, estimated) ->
 
   if estimated
     estimatedLabel = " ".repeat(PADDING) + "Estimated:"
-    console.log(estimatedLabel, humanTime.long(estimated))
+    console.log(estimatedLabel, gray(humanTime.long(estimated)))
 
 collectTestResults = (obj = {}, estimated) ->
   {
@@ -652,8 +652,12 @@ module.exports = {
               project.emit("exitEarlyWithErr", err.message)
 
   waitForSocketConnection: (project, id) ->
+    debug("waiting for socket connection... %o", { id })
+
     new Promise (resolve, reject) ->
       fn = (socketId) ->
+        debug("got socket connection %o", { id: socketId })
+
         if socketId is id
           ## remove the event listener if we've connected
           project.removeListener("socket:connected", fn)

packages/server/lib/project.coffee

@@ -263,7 +263,7 @@ class Project extends EE
         @emit("socket:connected", id)
 
       onSetRunnables: (runnables) ->
-        debug("recevied runnables %o", runnables)
+        debug("received runnables %o", runnables)
         reporter?.setRunnables(runnables)
 
       onMocha: (event, runnable) =>

packages/server/lib/socket.coffee

@@ -1,6 +1,7 @@
 _             = require("lodash")
 path          = require("path")
 uuid          = require("node-uuid")
+debug         = require('debug')('cypress:server:socket')
 Promise       = require("bluebird")
 socketIo      = require("@packages/socket")
 fs            = require("./util/fs")
@@ -12,10 +13,8 @@ task          = require("./task")
 files         = require("./files")
 fixture       = require("./fixture")
 errors        = require("./errors")
-logger        = require("./logger")
 automation    = require("./automation")
 preprocessor  = require("./plugins/preprocessor")
-log           = require('debug')('cypress:server:socket')
 
 runnerEvents = [
   "reporter:restart:test:run"
@@ -59,21 +58,21 @@ class Socket
       preprocessor.emitter.on("file:updated", @onTestFileChange)
 
   onTestFileChange: (filePath) ->
-    log("test file changed: #{filePath}")
+    debug("test file changed %o", filePath)
 
     fs.statAsync(filePath)
     .then =>
       @io.emit("watched:file:changed")
     .catch ->
-      log("could not find test file that changed: #{filePath}")
+      debug("could not find test file that changed %o", filePath)
 
   ## TODO: clean this up by sending the spec object instead of
   ## the url path
   watchTestFileByPath: (config, originalFilePath, options) ->
     ## files are always sent as integration/foo_spec.js
     ## need to take into account integrationFolder may be different so
     ## integration/foo_spec.js becomes cypress/my-integration-folder/foo_spec.js
-    log("watch test file #{originalFilePath}")
+    debug("watch test file %o", originalFilePath)
     filePath = path.join(config.integrationFolder, originalFilePath.replace("integration/", ""))
     filePath = path.relative(config.projectRoot, filePath)
 
@@ -90,7 +89,7 @@ class Socket
 
     ## store this location
     @testFilePath = filePath
-    log("will watch test file path #{filePath}")
+    debug("will watch test file path %o", filePath)
 
     preprocessor.getFile(filePath, config)
     ## ignore errors b/c we're just setting up the watching. errors
@@ -166,7 +165,7 @@ class Socket
       automation.request(message, data, onAutomationClientRequestCallback)
 
     @io.on "connection", (socket) =>
-      log("socket connected")
+      debug("socket connected")
 
       ## cache the headers so we can access
       ## them at any time
@@ -177,7 +176,7 @@ class Socket
 
         automationClient = socket
 
-        log("automation:client connected")
+        debug("automation:client connected")
 
         ## if our automation disconnects then we're
         ## in trouble and should probably bomb everything
@@ -211,7 +210,7 @@ class Socket
         socket.on "automation:response", automation.response
 
       socket.on "automation:request", (message, data, cb) =>
-        log("automation:request %o", message, data)
+        debug("automation:request %o", message, data)
 
         automationRequest(message, data)
         .then (resp) ->
@@ -287,7 +286,7 @@ class Socket
         ## cb is always the last argument
         cb = args.pop()
 
-        log("backend:request %o", { eventName, args })
+        debug("backend:request %o", { eventName, args })
 
         backendRequest = ->
           switch eventName

packages/server/test/integration/cypress_spec.coffee

@@ -755,6 +755,11 @@ describe "lib/cypress", ->
         ee.loadURL = ->
         ee.focusOnWebView = ->
         ee.webContents = {
+          debugger: {
+            on: sinon.stub()
+            attach: sinon.stub()
+            sendCommand: sinon.stub()
+          }
           setUserAgent: sinon.stub()
           session: {
             clearCache: sinon.stub().yieldsAsync()