Merge pull request #1619 from penguinho/sim-wait

Adding wait for simulator to launch by waiting for log to populate

lib/devices/ios/ios-log.js

@@ -3,7 +3,9 @@
 var spawn = require('win-spawn')
   , through = require('through')
   , path = require('path')
+  , fs = require('fs')
   , _ = require('underscore')
+  , glob = require('glob')
   , logger = require('../../server/logger.js').get('appium');
 
 // Date-Utils: Polyfills for the Date object
@@ -23,6 +25,12 @@ var IosLog = function(opts) {
   this.logRow = "";
   this.logsSinceLastRequest = [];
   this.logNoColors = opts.logNoColors;
+
+  if (this.xcodeVersion === null) {
+    logger.warn("Xcode version passed into log capture code as null, assuming Xcode 5");
+    this.xcodeVersion = '5.0';
+  }
+
 };
 
 IosLog.prototype.debug = function(msg) {
@@ -46,17 +54,39 @@ IosLog.prototype.startCapture = function(cb) {
     spawnEnv.DYLD_LIBRARY_PATH = limdDir + ":" + process.env.DYLD_LIBRARY_PATH;
     logger.info("Starting iOS device log capture via idevicesyslog");
     this.proc = spawn("idevicesyslog", ["-u", this.udid], {env: spawnEnv});
+    this.finishStartingLogCapture(cb);
   } else {
     if (parseInt(this.xcodeVersion.split(".")[0], 10) >= 5) {
       logger.info("Starting iOS 7.* simulator log capture");
-      var logPath = process.env.HOME + "/Library/Logs/iOS Simulator/7.0/" +
-                    "system.log";
-      this.proc = spawn("tail", ["-f", "-n1", logPath]);
+      var sim7LogsPath = path.resolve(process.env.HOME, "Library", "Logs", "iOS Simulator");
+      glob(sim7LogsPath + "/7.*/system.log", function(err, files) {
+        if (err || files.length < 1) {
+          cb(new Error("Could not start log capture because no iOS 7 simulator logs could be found."));
+        } else {
+          var lastModifiedLogPath = files[0]
+            , lastModifiedLogTime = fs.statSync(files[0]).mtime;
+          _.each(files, function(file) {
+            var mtime = fs.statSync(file).mtime;
+            if (mtime > lastModifiedLogTime) {
+              lastModifiedLogPath = file;
+              lastModifiedLogTime = mtime;
+            }
+          });
+          this.proc = spawn("tail", ["-f", "-n", "1", lastModifiedLogPath]);
+          // -n 1 is used so that tail returns a line that lets this process know that the
+          // first line returned wasn't from stderr so it can tell the tailing was successful
+          this.finishStartingLogCapture(cb);
+        }
+      }.bind(this));
     } else {
       logger.info("Starting iOS 6.* simulator log capture");
-      this.proc = spawn("tail", ["-f", "-n1", "/var/log/system.log"]);
+      this.proc = spawn("tail", ["-f", "-n", "1", "/var/log/system.log"]);
+      this.finishStartingLogCapture(cb);
     }
   }
+};
+
+IosLog.prototype.finishStartingLogCapture = function(cb) {
   this.proc.stdout.setEncoding('utf8');
   this.proc.stderr.setEncoding('utf8');
   this.proc.on('error', function(err) {
@@ -77,10 +107,15 @@ IosLog.prototype.stopCapture = function() {
 };
 
 IosLog.prototype.onStdout = function(data) {
+  if (!this.calledBack) {
+    // don't store the first line of the log because it came before the sim or device was launched
+    this.onOutput(data);
+  } else {
   this.logRow += data;
-  if (data.substr(-1,1) == "\n") {
-    this.onOutput(data, "");
-    this.logRow = "";
+    if (data.substr(-1,1) == "\n") {
+      this.onOutput(data, "");
+      this.logRow = "";
+    }
   }
 };
 
@@ -112,9 +147,9 @@ IosLog.prototype.onOutput = function(data, prefix) {
       // Filter old log rows
       var logRowParts = log.split(" ");
       var logRowDate = new Date(
-        Date.parse(this.iosLogStartTime.getFullYear() + " " + logRowParts[0] + " " + logRowParts[2] + " " + logRowParts[3])
+        Date.parse(this.iosLogStartTime.getFullYear() + " " + logRowParts[0] + " " + logRowParts[1] + " " + logRowParts[2])
       );
-      if (logRowDate.isAfter(this.iosLogStartTime)) {
+      if (!this.udid || logRowDate.isAfter(this.iosLogStartTime)) {
         var logObj = {
           timestamp: Date.now()
           , level: 'ALL'

lib/devices/ios/ios.js

@@ -189,8 +189,8 @@ IOS.prototype.start = function(cb, onDie) {
     this.detectUdid.bind(this),
     this.parseLocalizableStrings.bind(this),
     this.setLocale.bind(this),
-    this.setDeviceAndLaunchSimulator.bind(this),
     this.startLogCapture.bind(this),
+    this.setDeviceAndLaunchSimulator.bind(this),
     this.installToRealDevice.bind(this),
     this.startInstruments.bind(this),
     this.onInstrumentsLaunch.bind(this),
@@ -644,12 +644,22 @@ IOS.prototype.setDeviceAndLaunchSimulator = function(cb) {
         if (err) return cb(err);
         var iosDeviceString = this.getDeviceString();
         var isiPhone = iosDeviceString.toLowerCase().indexOf("ipad") === -1;
-
-        logger.debug("Launching device: " + iosDeviceString);
         var iosSimArgs = ["-SimulateDevice", iosDeviceString];
-        this.iosSimProcess = spawn(iosSimPath, iosSimArgs);
-
-        this.setDeviceTypeInInfoPlist(isiPhone ? 1 : 2, cb);
+        logger.debug("Launching device: " + iosDeviceString);
+        this.setDeviceTypeInInfoPlist(isiPhone ? 1 : 2, function() {
+          this.iosSimProcess = spawn(iosSimPath, iosSimArgs);
+          var waitForSimulatorLogs = function(countdown) {
+            if (countdown <= 0 || this.logs.getAllLogs().length > 0) {
+              logger.info(countdown > 0 ? "Simulator is now ready." : "Waited 10 seconds for simulator to start.");
+              cb();
+            } else {
+              setTimeout(function() {
+                waitForSimulatorLogs(countdown-1);
+              } ,1000);
+            }
+          }.bind(this);
+          waitForSimulatorLogs(10);
+        }.bind(this));
       }.bind(this));
     }
   }
@@ -765,22 +775,33 @@ IOS.prototype.postCleanup = function(cb) {
 
 };
 
+
+
 IOS.prototype.endSimulator = function(cb) {
-  logger.info("Killing the simulator process");
+  logger.info("Killing the simulator process and daemons");
   if (this.iosSimProcess) {
     this.iosSimProcess.kill("SIGHUP");
     this.iosSimProcess = null;
-    cb();
+    this.endSimulatorDaemons(cb);
   } else {
     var cmd = 'killall -9 "iPhone Simulator"';
     exec(cmd, { maxBuffer: 524288 }, function(err) {
       if (err && err.message.indexOf('matching processes') === -1) {
         cb(err);
       } else {
-        cb();
+        this.endSimulatorDaemons(cb);
       }
-    });
+    }.bind(this));
   }
+
+};
+
+IOS.prototype.endSimulatorDaemons = function(cb) {
+  var stopCmd = 'launchctl list | grep com.apple.iphonesimulator.launchd | cut -f 3 | xargs -n 1 launchctl stop';
+  exec(stopCmd, { maxBuffer: 524288 } , function() {
+    var removeCmd = 'launchctl list | grep com.apple.iphonesimulator.launchd | cut -f 3 | xargs -n 1 launchctl remove';
+    exec(removeCmd, { maxBuffer: 524288 }, cb);
+  });
 };
 
 IOS.prototype.stop = function(cb) {