Merge pull request #2953 from sebv/better-logging

Logging improvements

lib/appium.js

@@ -376,7 +376,7 @@ Appium.prototype.stop = function (cb) {
     return cb();
   }
 
-  logger.debug('Shutting down appium session...');
+  logger.info('Shutting down appium session');
   this.device.stop(function (code) {
     var err;
     if (code && code > 0) {

lib/devices/android/android-common.js

@@ -345,6 +345,7 @@ androidCommon.prepareActiveDevice = function (cb) {
     // deviceId is already setted
     return cb();
   }
+  logger.info('Retrieving device');
   this.adb.getDevicesWithRetry(function (err, devices) {
     if (err) return cb(err);
     var deviceId = null;
@@ -359,6 +360,7 @@ androidCommon.prepareActiveDevice = function (cb) {
       var emPort = this.adb.getPortFromEmulatorString(deviceId);
       this.adb.setEmulatorPort(emPort);
     }
+    logger.info('Found device', deviceId);
     this.adb.setDeviceId(deviceId);
     cb();
   }.bind(this));
@@ -441,8 +443,10 @@ androidCommon.installApp = function (cb) {
       // err is set if the remote apk doesn't exist so don't check it.
       this.adb.isAppInstalled(this.args.appPackage, function (err, installed) {
         if (installed && this.args.fastReset && remoteApk) {
+          logger.info('App is already installed, resetting app');
           this.resetApp(cb);
         } else if (!installed || (this.args.fastReset && !remoteApk)) {
+          logger.info('Installing App');
           this.adb.mkdir(this.remoteTempPath(), function (err) {
             if (err) return cb(err);
             this.getRemoteApk(function (err, remoteApk, md5Hash) {
@@ -606,6 +610,7 @@ androidCommon.unlockScreen = function (cb) {
   this.adb.isScreenLocked(function (err, isLocked) {
     if (err) return cb(err);
     if (isLocked) {
+      logger.info("Unlocking screen");
       var timeoutMs = 10000;
       var start = Date.now();
       var unlockAndCheck = function () {
@@ -643,12 +648,12 @@ androidCommon.unlockScreen = function (cb) {
 
 androidCommon.packageAndLaunchActivityFromManifest = function (cb) {
   if (!this.args.app) {
-    logger.info("No app capability, can't parse package/activity");
+    logger.warn("No app capability, can't parse package/activity");
     return cb();
   }
   if (this.args.appPackage && this.args.appActivity) return cb();
 
-  logger.info("Parsing package and activity from app manifest");
+  logger.debug("Parsing package and activity from app manifest");
   this.adb.packageAndLaunchActivityFromManifest(this.args.app, function (err, pkg, act) {
     if (err) {
       logger.error("Problem parsing package and activity from manifest: " +
@@ -659,7 +664,7 @@ androidCommon.packageAndLaunchActivityFromManifest = function (cb) {
     if (act && !this.args.appActivity) this.args.appActivity = act;
     if (!this.args.appWaitPackage) this.args.appWaitPackage = this.args.appPackage;
     if (!this.args.appWaitActivity) this.args.appWaitActivity = this.args.appActivity;
-    logger.info("Parsed package and activity are: " + pkg + "/" + act);
+    logger.debug("Parsed package and activity are: " + pkg + "/" + act);
     cb();
   }.bind(this));
 };
@@ -720,7 +725,7 @@ androidCommon.getCurrentActivity = function (cb) {
 androidCommon.getDeviceLanguage = function (cb) {
   this.adb.shell("getprop persist.sys.language", function (err, stdout) {
     if (err) {
-      logger.warn("Error getting device language: " + err);
+      logger.error("Error getting device language: " + err);
       cb(err, null);
     } else {
       logger.debug("Current device language: " + stdout.trim());

lib/devices/android/android-context-controller.js

@@ -35,7 +35,7 @@ androidContextController.getContexts = function (cb) {
   this.listWebviews(function (err, webviews) {
     if (err) return cb(err);
     this.contexts = _.union([this.NATIVE_WIN], webviews);
-    logger.info("Available contexts: " + this.contexts);
+    logger.debug("Available contexts: " + this.contexts);
     cb(null, {
       status: status.codes.Success.code
     , value: this.contexts

lib/devices/android/android-controller.js

@@ -359,7 +359,7 @@ androidController.getPageSource = function (cb) {
         logger.debug('transferPageSourceXML command: ' + cmd);
         exec(cmd, { maxBuffer: 524288 }, function (err, stdout, stderr) {
           if (err) {
-            logger.warn(stderr);
+            logger.error(stderr);
             return cb(err);
           }
           cb(null);

lib/devices/android/android-hybrid.js

@@ -83,9 +83,9 @@ androidHybrid.getProcessNameFromWebview = function (webview, cb) {
   var pid = webview.match(/\d+$/);
   if (!pid) return cb("No pid for webview " + webview);
   pid = pid[0];
-  logger.info(webview + " mapped to pid " + pid);
+  logger.debug(webview + " mapped to pid " + pid);
 
-  logger.info("Getting process name for webview");
+  logger.debug("Getting process name for webview");
   this.adb.shell("ps", function (err, out) {
     if (err) return cb(err);
     var pkg = "unknown";
@@ -111,7 +111,7 @@ androidHybrid.getProcessNameFromWebview = function (webview, cb) {
       }
     });
 
-    logger.info("returning process name: " + pkg);
+    logger.debug("returning process name: " + pkg);
     cb(null, pkg);
   });
 };

lib/devices/android/android.js

@@ -82,7 +82,7 @@ Android.prototype.start = function (cb, onDie) {
 
   if (this.adb === null) {
     // Pass Android opts and Android ref to adb.
-    logger.debug("Starting android appium");
+    logger.info("Starting android appium");
     this.adb = new ADB(this.args);
     this.uiautomator = new UiAutomator(this.adb, this.args);
     this.uiautomator.setExitHandler(this.onUiautomatorExit.bind(this));
@@ -257,7 +257,7 @@ Android.prototype.checkShouldRelaunch = function (launchErr) {
 Android.prototype.checkApiLevel = function (cb) {
   this.adb.getApiLevel(function (err, apiLevel) {
     if (err) return cb(err);
-
+    logger.info('Device API level is:', parseInt(apiLevel, 10));
     if (parseInt(apiLevel) < 17) {
       var msg = "Android devices must be of API level 17 or higher. Please change your device to Selendroid or upgrade Android on your device.";
       logger.error(msg); // logs the error when we encounter it

lib/devices/android/bootstrap/src/io/appium/android/bootstrap/AndroidElement.java

@@ -233,12 +233,12 @@ public class AndroidElement {
 
   public boolean setText(final String text) throws UiObjectNotFoundException {
     if (UnicodeEncoder.needsEncoding(text)) {
-      Logger.info("Sending Unicode text to element: " + text);
+      Logger.debug("Sending Unicode text to element: " + text);
       String encodedText = UnicodeEncoder.encode(text);
       Logger.debug("Encoded text: " + encodedText);
       return el.setText(encodedText);
     } else {
-      Logger.info("Sending plain text to element: " + text);
+      Logger.debug("Sending plain text to element: " + text);
       return el.setText(text);
     }
   }

lib/devices/android/bootstrap/src/io/appium/android/bootstrap/AndroidElementsHash.java

@@ -110,16 +110,16 @@ public class AndroidElementsHash {
     int counter = 0;
     while (keepSearching) {
       if (baseEl == null) {
-        Logger.info("Element[" + key + "] is null: (" + counter + ")");
+        Logger.debug("Element[" + key + "] is null: (" + counter + ")");
         if (useIndex) {
-          Logger.info("  using index...");
+          Logger.debug("  using index...");
           tmp = sel.index(counter);
         } else {
           tmp = sel.instance(counter);
         }
         lastFoundObj = new UiObject(tmp);
       } else {
-        Logger.info("Element[" + key + "] is " + baseEl.getId() + ", counter: "
+        Logger.debug("Element[" + key + "] is " + baseEl.getId() + ", counter: "
             + counter);
         lastFoundObj = baseEl.getChild(sel.instance(counter));
       }

lib/devices/android/bootstrap/src/io/appium/android/bootstrap/SocketServer.java

@@ -40,7 +40,7 @@ class SocketServer {
     executor = new AndroidCommandExecutor();
     try {
       server = new ServerSocket(port);
-      Logger.info("Socket opened on port " + port);
+      Logger.debug("Socket opened on port " + port);
     } catch (final IOException e) {
       throw new SocketServerException(
           "Could not start socket server listening on " + port);
@@ -81,12 +81,12 @@ class SocketServer {
         input.append((char) a);
       }
       String inputString = input.toString();
-      Logger.info("Got data from client: " + inputString);
+      Logger.debug("Got data from client: " + inputString);
       try {
         AndroidCommand cmd = getCommand(inputString);
-        Logger.info("Got command of type " + cmd.commandType().toString());
+        Logger.debug("Got command of type " + cmd.commandType().toString());
         res = runCommand(cmd);
-        Logger.info("Returning result: " + res);
+        Logger.debug("Returning result: " + res);
       } catch (final CommandTypeException e) {
         res = new AndroidCommandResult(WDStatus.UNKNOWN_ERROR, e.getMessage())
             .toString();
@@ -109,7 +109,7 @@ class SocketServer {
    * @throws SocketServerException
    */
   public void listenForever() throws SocketServerException {
-    Logger.info("Appium Socket Server Ready");
+    Logger.debug("Appium Socket Server Ready");
     UpdateStrings.loadStringsJson();
     dismissCrashAlerts();
     final TimerTask updateWatchers = new TimerTask() {
@@ -125,7 +125,7 @@ class SocketServer {
 
     try {
       client = server.accept();
-      Logger.info("Client connected");
+      Logger.debug("Client connected");
       in = new BufferedReader(new InputStreamReader(client.getInputStream(), "UTF-8"));
       out = new BufferedWriter(new OutputStreamWriter(client.getOutputStream(), "UTF-8"));
       while (keepListening) {
@@ -134,7 +134,7 @@ class SocketServer {
       in.close();
       out.close();
       client.close();
-      Logger.info("Closed client connection");
+      Logger.debug("Closed client connection");
     } catch (final IOException e) {
       throw new SocketServerException("Error when client was trying to connect");
     }
@@ -143,9 +143,9 @@ class SocketServer {
   public void dismissCrashAlerts() {
     try {
       new UiWatchers().registerAnrAndCrashWatchers();
-      Logger.info("Registered crash watchers.");
+      Logger.debug("Registered crash watchers.");
     } catch (Exception e) {
-      Logger.info("Unable to register crash watchers.");
+      Logger.debug("Unable to register crash watchers.");
     }
   }
 

lib/devices/android/bootstrap/src/io/appium/android/bootstrap/handler/Drag.java

@@ -72,7 +72,7 @@ public class Drag extends CommandHandler {
       return getErrorResult(e.getMessage());
     }
 
-    Logger.info("Dragging from " + absStartPos.toString() + " to "
+    Logger.debug("Dragging from " + absStartPos.toString() + " to "
         + absEndPos.toString() + " with steps: " + dragArgs.steps.toString());
     final boolean rv = device.drag(absStartPos.x.intValue(),
         absStartPos.y.intValue(), absEndPos.x.intValue(),
@@ -93,7 +93,7 @@ public class Drag extends CommandHandler {
         return getErrorResult(e.getMessage());
       }
 
-      Logger.info("Dragging the element with id " + dragArgs.el.getId()
+      Logger.debug("Dragging the element with id " + dragArgs.el.getId()
           + " to " + absEndPos.toString() + " with steps: "
           + dragArgs.steps.toString());
       try {
@@ -109,7 +109,7 @@ public class Drag extends CommandHandler {
             + e.getMessage());
       }
     } else {
-      Logger.info("Dragging the element with id " + dragArgs.el.getId()
+      Logger.debug("Dragging the element with id " + dragArgs.el.getId()
           + " to destination element with id " + dragArgs.destEl.getId()
           + " with steps: " + dragArgs.steps);
       try {

lib/devices/android/bootstrap/src/io/appium/android/bootstrap/handler/Flick.java

@@ -95,7 +95,7 @@ public class Flick extends CommandHandler {
     }
 
     steps = Math.abs(steps);
-    Logger.info("Flicking from " + start.toString() + " to " + end.toString()
+    Logger.debug("Flicking from " + start.toString() + " to " + end.toString()
         + " with steps: " + steps.intValue());
     final boolean res = d.swipe(start.x.intValue(), start.y.intValue(),
         end.x.intValue(), end.y.intValue(), steps.intValue());

lib/devices/android/bootstrap/src/io/appium/android/bootstrap/handler/Orientation.java

@@ -90,7 +90,7 @@ public class Orientation extends CommandHandler {
         .getDisplayRotation());
 
     Logger.debug("Desired orientation: " + orientation);
-    Logger.info("Current rotation: " + current);
+    Logger.debug("Current rotation: " + current);
 
     if (orientation.equalsIgnoreCase("LANDSCAPE")) {
       switch (current) {

lib/devices/android/bootstrap/src/io/appium/android/bootstrap/handler/Pinch.java

@@ -43,7 +43,7 @@ public class Pinch extends CommandHandler {
       return getErrorResult("Unknown error:" + e.getMessage());
     }
 
-    Logger.info("Pinching " + direction + " " + percent.toString() + "%"
+    Logger.debug("Pinching " + direction + " " + percent.toString() + "%"
         + " with steps: " + steps.toString());
     boolean res;
     if (direction.equals("in")) {

lib/devices/android/bootstrap/src/io/appium/android/bootstrap/handler/SetText.java

@@ -36,7 +36,7 @@ public class SetText extends CommandHandler {
         if (text.endsWith("\\n")) {
           pressEnter = true;
           text = text.replace("\\n", "");
-          Logger.info("Will press enter after setting text");
+          Logger.debug("Will press enter after setting text");
         }
         final Boolean result = el.setText(text);
         if (pressEnter) {

lib/devices/android/bootstrap/src/io/appium/android/bootstrap/handler/Swipe.java

@@ -58,7 +58,7 @@ public class Swipe extends CommandHandler {
       }
     }
 
-    Logger.info("Swiping from " + absStartPos.toString() + " to "
+    Logger.debug("Swiping from " + absStartPos.toString() + " to "
         + absEndPos.toString() + " with steps: " + steps.toString());
     final boolean rv = device.swipe(absStartPos.x.intValue(),
         absStartPos.y.intValue(), absEndPos.x.intValue(),

lib/devices/android/bootstrap/src/io/appium/android/bootstrap/handler/UpdateStrings.java

@@ -33,7 +33,7 @@ public class UpdateStrings extends CommandHandler {
   }
 
   public static boolean loadStringsJson() {
-    Logger.info("Loading json...");
+    Logger.debug("Loading json...");
     try {
       String filePath = "/data/local/tmp/strings.json";
       final File jsonFile = new File(filePath);
@@ -50,7 +50,7 @@ public class UpdateStrings extends CommandHandler {
       dataInput.close();
       final String jsonString = new String(jsonBytes, "UTF-8");
       Find.apkStrings = new JSONObject(jsonString);
-      Logger.info("json loading complete.");
+      Logger.debug("json loading complete.");
     } catch (final Exception e) {
       Logger.error("Error loading json: " + e.getMessage());
       return false;

lib/devices/android/bootstrap/src/io/appium/android/bootstrap/utils/TheWatchers.java

@@ -18,7 +18,7 @@ public class TheWatchers {
   public boolean check() {
     // Send only one alert message...
     if (isDialogPresent() && (!alerted)) {
-      Logger.info("Emitting system alert message");
+      Logger.debug("Emitting system alert message");
       alerted = true;
     }
 

lib/devices/android/uiautomator.js

@@ -23,6 +23,7 @@ var UiAutomator = function (adb, opts) {
 };
 
 UiAutomator.prototype.start = function (readyCb) {
+  logger.info("Starting App");
   this.adb.killProcessesByName('uiautomator', function (err) {
     if (err) return readyCb(err);
     logger.debug("Running bootstrap");

lib/devices/ios/ios.js

@@ -336,7 +336,11 @@ IOS.prototype.startInstruments = function (cb) {
 };
 
 IOS.prototype.makeInstruments = function (cb) {
-  prepareBootstrap({ verboseInstruments: !this.args.quiet }).then(
+  // at the moment all the logging in uiauto is at debug level
+  // TODO: be able to use info in appium-uiauto
+  prepareBootstrap({
+    verboseInstruments: logger.appiumLoglevel === 'debug'
+  }).then(
     function (bootstrapPath) {
       var instruments = new Instruments({
         app: this.args.app || this.args.bundleId

lib/devices/ios/settings.js

@@ -142,7 +142,7 @@ var getSafari7Dirs = function (sdk) {
     if (safariDir) {
       safariDirs.push(safariDir);
     } else {
-      logger.info("Could not find MobileSafari in sim applications at " +
+      logger.warn("Could not find MobileSafari in sim applications at " +
                   appsDir);
     }
   });

lib/server/capabilities.js

@@ -123,7 +123,7 @@ Capabilities.prototype.checkValidity = function (deviceType, strictMode) {
     var allValidCaps = [].concat(generalCaps, androidCaps, iosCaps);
     var unknownCaps = _.difference(capsUsed, allValidCaps);
     if (unknownCaps.length > 0) {
-      logger.info('The following desired capabilities were provided, but not recognized by appium.' +
+      logger.debug('The following desired capabilities were provided, but not recognized by appium.' +
         ' They will be passed on to any other services running on this server. : ' +
         unknownCaps.join(', '));
     }

lib/server/helpers.js

@@ -177,7 +177,7 @@ module.exports.startListening = function (server, args, parser, appiumVer, appiu
     }
     var showArgs = getNonDefaultArgs(parser, args);
     if (_.size(showArgs)) {
-      logger.info("Non-default server args: " + JSON.stringify(showArgs));
+      logger.debug("Non-default server args: " + JSON.stringify(showArgs));
     }
   });
   server.on('error', function (err) {
@@ -201,3 +201,31 @@ module.exports.startListening = function (server, args, parser, appiumVer, appiu
     }
   }, 1000);
 };
+
+// Copied the morgan compile function over so that cooler formats
+// may be configured
+function compile(fmt) {
+  fmt = fmt.replace(/"/g, '\\"');
+  var js = '  return "' + fmt.replace(/:([-\w]{2,})(?:\[([^\]]+)\])?/g,
+    function (_, name, arg) {
+      return '"\n    + (tokens["' + name + '"](req, res, "' + arg + '") || "-") + "';
+    }) + '";';
+  // jshint evil:true
+  return new Function('tokens, req, res', js);
+}
+module.exports.requestStartLoggingFormat = compile('-->'.white + ' ' + ':method'.white + ' ' +
+  ':url'.white);
+// Copied the morgan format.dev function, modified to use colors package
+// and custom logging line
+module.exports.requestEndLoggingFormat = function (tokens, req, res) {
+  var status = res.statusCode;
+  var statusStr = ':status';
+  if (status >= 500) statusStr = statusStr.red;
+  else if (status >= 400) statusStr = statusStr.yellow;
+  else if (status >= 300) statusStr = statusStr.cyan;
+  else statusStr = statusStr.green;
+  var fn = compile('<-- :method :url '.white + statusStr +
+    ' :response-time ms - :res[content-length]'.grey);
+  return fn(tokens, req, res);
+};
+

lib/server/logger.js

@@ -1,8 +1,6 @@
 "use strict";
 
-var winston = require('winston')
-  , _ = require('underscore')
-  , defaults = {colorize: true, timestamp: false};
+var winston = require('winston');
 
 var levels = {
   debug: 1
@@ -21,45 +19,51 @@ var colors = {
 var logger = null;
 
 module.exports.init = function (args) {
-  var options = _.extend(_.clone(defaults), {
-    timestamp: args.logTimestamp
-  , handleExceptions: true
-  , exitOnError: false
-  , json: false
-  , level: 'debug'
-  });
-
-  var winstonOptions = {
-    console:
-      _.extend({
-        colorize: !args.logNoColors
-      }, options)
-    };
+  var loglevel = args.logLevel ? args.logLevel :
+     (args.quiet ? 'warn' : 'info');
 
   winston.addColors(colors);
-  winston.loggers.add('appium', winstonOptions);
+  winston.loggers.add('appium', {
+    console: {
+        timestamp: args.logTimestamp ? true : false
+      , colorize: args.logNoColors ? false : true
+      , handleExceptions: true
+      , exitOnError: false
+      , json: false
+      , level: loglevel
+    }
+  });
   logger = winston.loggers.get('appium');
   logger.setLevels(levels);
   logger.stripColors = args.logNoColors;
+  logger.appiumLoglevel = loglevel;
 
-  logger.transports.console.level = args.logLevel ||
-    (args.quiet ? 'warn' : null) || 'info';
-
+  var fileLogger = null;
   if (args.log) {
-    winstonOptions.file = _.extend({
-      filename: args.log
-    , colorize: false
-    , maxFiles: 1
-    }, options);
-
     try {
-      logger.add(winston.transports.File, winstonOptions.file);
+      winston.loggers.add('appium-file', {
+        file: {
+            timestamp: true
+          , colorize: false
+          , filename: args.log
+          , maxFiles: 1
+          , level: loglevel
+          , handleExceptions: true
+          , exitOnError: false
+          , json: false
+          }
+        }
+      );
+      fileLogger = winston.loggers.get('appium-file');
+      fileLogger.setLevels(levels);
+      fileLogger.stripColors = true;
     } catch (e) {
       logger.debug("Tried to attach logging to file " + args.log +
                   " but an error occurred");
     }
   }
 
+  var webhookLogger = null;
   if (args.webhook) {
     var host = args.webhook;
     var port = 9003;
@@ -74,15 +78,32 @@ module.exports.init = function (args) {
     host = host || '127.0.0.1';
     port = port || 9003;
     try {
-      logger.add(winston.transports.Webhook, { 'host': host, 'port': port,
-        'path': '/' });
+      winston.loggers.add('appium-webhook', { webhook: {
+          host: host
+        , port: port
+        , path: '/'
+        , level: loglevel
+        , handleExceptions: true
+        , exitOnError: false
+        , json: false
+        }
+      });
+      webhookLogger = winston.loggers.get('appium-webhook');
+      webhookLogger.setLevels(levels);
+      webhookLogger.stripColors = true;
     } catch (e) {
       logger.debug("Tried to attach logging to webhook at " + host +
                   " but an error occurred");
     }
   }
+
+  logger.on('logging', function (transport, level, msg, meta) {
+    if (fileLogger) fileLogger.log(level, msg, meta);
+    if (webhookLogger) webhookLogger.log(level, msg, meta);
+  });
 };
 
+
 module.exports.get = function () {
   if (logger === null) {
     exports.init({});

lib/server/main.js

@@ -6,8 +6,9 @@ var parser = require('./parser.js')()
   , fs = require('fs')
   , path = require('path')
   , _ = require('underscore')
-  , noPermsCheck = false
-  , colors = require('colors');
+  , noPermsCheck = false;
+
+require('colors');
 
 process.chdir(path.resolve(__dirname, '../..'));
 
@@ -60,12 +61,13 @@ var http = require('http')
   , allowCrossDomain = helpers.allowCrossDomain
   , catchAllHandler = helpers.catchAllHandler
   , checkArgs = helpers.checkArgs
-  , winstonStream = helpers.winstonStream
   , configureServer = helpers.configureServer
   , startListening = helpers.startListening
   , conditionallyPreLaunch = helpers.conditionallyPreLaunch
   , prepareTmpDir = helpers.prepareTmpDir
-  , noColorLogger = helpers.noColorLogger;
+  , requestStartLoggingFormat = require('./helpers.js').requestStartLoggingFormat
+  , requestEndLoggingFormat = require('./helpers.js').requestEndLoggingFormat;
+
 
 var main = function (args, readyCb, doneCb) {
 
@@ -86,25 +88,26 @@ var main = function (args, readyCb, doneCb) {
   var rest = express()
     , server = http.createServer(rest);
 
+  rest.use(morgan(function (tokens, req, res) {
+    // morgan output is redirected straight to winston
+    logger.info(requestEndLoggingFormat(tokens, req, res),
+      (res.jsonResp || '').grey);
+  }));
   rest.use(favicon(path.join(__dirname, 'static/favicon.ico')));
   rest.use(express.static(path.join(__dirname, 'static')));
   rest.use(allowCrossDomain);
-  if (!args.quiet) {
-    if (args.logNoColors) {
-      rest.use(morgan(noColorLogger));
-    } else {
-      rest.use(morgan('dev'));
-    }
-  }
-  if (args.log || args.webhook) {
-    rest.use(morgan({stream: winstonStream}));
-  }
-  if (args.logNoColors || args.log) {
-    colors.mode = "none";
-  }
   rest.use(parserWrap);
   rest.use(bodyParser.urlencoded({extended: true}));
   rest.use(bodyParser.json());
+  rest.use(morgan({format: function (tokens, req, res) {
+    // morgan output is redirected straight to winston
+    var data = '';
+    try {
+      if (req.body) data = JSON.stringify(req.body).substring(0, 1000);
+    } catch (ign) {}
+    logger.info(requestStartLoggingFormat(tokens, req, res), data.grey);
+  }, immediate: true}));
+
   rest.use(methodOverride());
 
   // Instantiate the appium instance

lib/server/parser.js

@@ -148,7 +148,8 @@ var args = [
 
   [['--log-level'], {
     choices: ['debug','info','warn', 'error']
-  , defaultValue: 'debug'
+  // TODO: enable this once we got rid of --quiet
+  //, defaultValue: 'info'
   , dest: 'logLevel'
   , required: false
   , example: "debug"

lib/server/responses.js

@@ -78,7 +78,8 @@ var respondSuccess = exports.respondSuccess = function (req, res, value, sid) {
       printResponse.value.length > maxLen) {
     printResponse.value = printResponse.value.slice(0, maxLen) + "...";
   }
-  logger.debug("Responding to client with success: " + JSON.stringify(printResponse));
+  res.jsonResp = JSON.stringify(printResponse);
+  logger.debug("Responding to client with success: " + res.jsonResp);
   res.send(response);
 };
 

package.json

@@ -41,10 +41,10 @@
   },
   "dependencies": {
     "adm-zip": "~0.4.4",
-    "appium-adb": "~1.2.2",
+    "appium-adb": "~1.3.0",
     "appium-atoms": "~0.0.5",
-    "appium-instruments": "~1.1.2",
-    "appium-uiauto": "~1.2.1",
+    "appium-instruments": "~1.2.0",
+    "appium-uiauto": "~1.3.0",
     "argparse": "~0.1.15",
     "async": "~0.9.0",
     "binary-cookies": "~0.1.1",