diff --git a/docs/server-args.md b/docs/server-args.md index c7399d54310..aeafeb20754 100644 --- a/docs/server-args.md +++ b/docs/server-args.md @@ -16,6 +16,7 @@ All flags are optional, but some are required in conjunction with certain others |`-p`, `--port`|4723|port to listen on|`--port 4723`| |`-dp`, `--device-port`|4724|(Android-only) port to connect to device on|`--device-port 4724`| |`-k`, `--keep-artifacts`|false|(IOS-only) Keep Instruments trace directories|| +|`-r`, `--backend-retries`|3|(iOS-only) How many times to retry launching Instruments before saying it crashed or timed out|`--backend-retries 3`| |`--session-override`|false|Enables session override (clobbering)|| |`--full-reset`|false|(Android-only) Reset app state by uninstalling app instead of clearing app data|| |`--no-reset`|false|Don't reset app state between sessions (IOS: don't delete app plist files; Android: don't uninstall app before new session)|| diff --git a/lib/appium.js b/lib/appium.js index 67552fe2247..e03acc4d9a8 100644 --- a/lib/appium.js +++ b/lib/appium.js @@ -546,6 +546,7 @@ Appium.prototype.initDevice = function() { , isSafariLauncherApp: this.isSafariLauncherApp , desiredCapabilities: this.desiredCapabilities , logNoColors: this.args.logNoColors + , flakeyRetries: this.args.backendRetries }; if (this.desiredCapabilities.safari || this.desiredCapabilities.iwebview) { this.device = new Safari(iosOpts); diff --git a/lib/devices/ios/instruments.js b/lib/devices/ios/instruments.js index fccd6141211..97097547f08 100644 --- a/lib/devices/ios/instruments.js +++ b/lib/devices/ios/instruments.js @@ -2,6 +2,7 @@ "use strict"; var spawn = require('child_process').spawn + , through = require('through') , exec = require('child_process').exec , logger = require('../../server/logger.js').get('appium') , fs = require('fs') @@ -13,9 +14,15 @@ var spawn = require('child_process').spawn , mkdirp = require('mkdirp') , codes = require('../../server/status.js').codes; +var ERR_NEVER_CHECKED_IN = "Instruments never checked in" + , ERR_CRASHED_ON_STARTUP = "Instruments crashed on startup"; + var Instruments = function(opts) { this.app = opts.app; this.launchTimeout = opts.launchTimeout || 90000; + this.flakeyRetries = opts.flakeyRetries; + this.launchTries = 0; + this.neverConnected = false; this.udid = opts.udid; this.isSafariLauncherApp = opts.isSafariLauncherApp; this.bootstrap = opts.bootstrap; @@ -27,20 +34,20 @@ var Instruments = function(opts) { this.commandQueue = []; this.curCommand = null; this.resultHandler = this.defaultResultHandler; - this.readyHandler = this.defaultReadyHandler; + this.launchHandlerCalledBack = false; this.exitHandler = this.defaultExitHandler; + this.socketConnectTimeout = null; this.hasConnected = false; this.traceDir = null; this.proc = null; - this.killProcessCb = null; + this.shutdownCb = null; + this.didLaunch = false; this.debugMode = false; this.onReceiveCommand = null; this.guid = uuid.create(); this.bufferedData = ""; this.instrumentsPath = ""; - this.eventRouter = { - 'cmd': this.commandHandler - }; + this.eventRouter = {'cmd': this.commandHandler}; this.socketServer = null; this.logNoColors = opts.logNoColors; }; @@ -48,159 +55,177 @@ var Instruments = function(opts) { /* INITIALIZATION */ -Instruments.prototype.start = function(readyCb, exitCb) { - if (typeof readyCb !== "undefined") { - this.readyHandler = readyCb; - } - if (typeof exitCb !== "undefined") { - this.exitHandler = exitCb; +Instruments.prototype.start = function(launchCb, unexpectedExitCb) { + if (this.didLaunch) { + return launchCb(new Error("Called start() but we already launched")); } + this.launchHandlerCb = launchCb; + this.exitHandler = unexpectedExitCb; - // remove socket if it currently exists - try { - fs.unlinkSync(this.sock); - } catch (Exception) {} + exec('xcrun -find instruments', function (err, stdout) { + if (typeof stdout === "undefined") stdout = ""; + this.instrumentsPath = stdout.trim(); + if (err || !this.instrumentsPath) { + logger.error("Could not find instruments binary"); + if (err) logger.error(err.message); + return this.launchHandler(new Error("Could not find the instruments " + + "binary. Please ensure `xcrun -find instruments` can locate it.")); + } + logger.info("Instruments is at: " + this.instrumentsPath); + + this.initSocketServer(function(err) { + if (err) return this.launchHandler(err); + this.launch(function(err) { + if (err) return this.launchHandler(err); + // we don't call launchHandler in the success case; it's called + // when instruments checks in, in the conn handler for the socket + // server, or when instruments times out, in onSocketNeverConnect + }); + }.bind(this)); + }.bind(this)); +}; - var onSocketNeverConnect = function() { - logger.error("Instruments socket client never checked in; timing out".red); - if (this.proc !== null) { - this.proc.kill('SIGTERM'); +Instruments.prototype.launchHandler = function(err) { + if (!this.launchHandlerCalledBack) { + clearTimeout(this.socketConnectTimeout); + if (!err) { + this.didLaunch = true; + this.neverConnected = false; + } else { + if (this.launchTries < this.flakeyRetries && + (err.message === ERR_NEVER_CHECKED_IN || + err.message === ERR_CRASHED_ON_STARTUP)) { + this.launchTries++; + logger.info("Attempting to retry launching instruments, this is " + + "retry #" + this.launchTries); + return this.launch(function(err) { + if (err) return this.launchHandler(err); + }.bind(this)); + } + logger.error(err.message); } + this.launchHandlerCalledBack = true; + if (err) this.killProc(); + this.launchHandlerCb(err); + } else { + logger.info("Trying to call back from instruments launch but we " + + "already did"); + } +}; + +Instruments.prototype.killProc = function() { + if (this.proc !== null) { + logger.info("Sending sigterm to instruments"); + this.proc.kill('SIGTERM'); + } +}; + +Instruments.prototype.onSocketNeverConnect = function() { + logger.error("Instruments socket client never checked in; timing out".red); + this.neverConnected = true; + this.killProc(); +}; - this.exitHandler(1); - }; +Instruments.prototype.initSocketServer = function(cb) { + this.socketServer = net.createServer({allowHalfOpen: true}, + this.onSocketConnect.bind(this)); - var socketConnectTimeout = setTimeout(onSocketNeverConnect.bind(this), - this.launchTimeout); + this.socketServer.on('close', function() { + this.debug("Instruments socket server was closed"); + }.bind(this)); - this.socketServer = net.createServer({allowHalfOpen: true}, function(conn) { - if (!this.hasConnected) { - this.hasConnected = true; - this.debug("Instruments is ready to receive commands"); - clearTimeout(socketConnectTimeout); - this.readyHandler(); - this.readyHandler = this.defaultReadyHandler; + // remove socket file if it currently exists + try { + fs.unlinkSync(this.sock); + } catch (err) { + // if we get any error other than "socket doesn't exist", fail + if (err.message.indexOf("ENOENT") === -1) { + return cb(err); } - conn.setEncoding('utf8'); // get strings from sockets rather than buffers + } - conn.on('data', function(data) { - // when data comes in, route it according to the "event" property - this.debug("Socket data received (" + data.length + " bytes)"); - this.bufferedData += data; - }.bind(this)); + this.socketServer.listen(this.sock, function(err) { + if (err) return cb(err); + this.debug("Instruments socket server started at " + this.sock); + cb(); + }.bind(this)); - this.currentSocket = conn; - //this.debug("Socket Connected"); +}; - conn.on('close', function() { - //this.debug("Socket Completely closed"); - this.currentSocket = null; - }.bind(this)); +Instruments.prototype.onSocketConnect = function(conn) { + if (!this.hasConnected) { + this.hasConnected = true; + this.debug("Instruments is ready to receive commands"); + this.launchHandler(); + } + conn.setEncoding('utf8'); // get strings from sockets rather than buffers - conn.on('end', function() { - //this.debug("Socket closed by other side"); - var data = this.bufferedData; - this.bufferedData = ""; - try { - data = JSON.parse(data); - } catch (e) { - logger.error("Couldn't parse JSON data from socket, maybe buffer issue?"); - logger.error(data); - data = { - event: 'cmd' - , result: { - status: codes.UnknownError - , value: "Error parsing socket data from instruments" - } - }; - } - if (!_.has(data, 'event')) { - logger.error("Socket data came in without event, it was:"); - logger.error(JSON.stringify(data)); - } else if (!_.has(this.eventRouter, data.event)) { - logger.error("Socket is asking for event '" + data.event + - "' which doesn't exist"); - } else { - this.debug("Socket data being routed for '" + data.event + "' event"); - this.eventRouter[data.event].bind(this)(data, conn); - } - }.bind(this)); + conn.pipe(through(function(data) { + // when data comes in, route it according to the "event" property + this.debug("Socket data received (" + data.length + " bytes)"); + this.bufferedData += data; + }.bind(this))); - }.bind(this)); + this.currentSocket = conn; - this.socketServer.on('close', function() { - this.debug("Instruments socket server closed"); + conn.on('close', function() { + this.currentSocket = null; }.bind(this)); - exec('xcrun -find instruments', function (err, stdout) { - if (typeof stdout === "undefined") stdout = ""; - this.instrumentsPath = stdout.trim(); - if (err || !this.instrumentsPath) { - logger.error("Could not find instruments binary"); - if (err) logger.error(err.message); - clearTimeout(socketConnectTimeout); - return this.readyHandler(new Error("Could not find the instruments " + - "binary. Please ensure `xcrun -find instruments` can locate it.")); + conn.on('end', function() { + var data = this.bufferedData; + this.bufferedData = ""; + try { + data = JSON.parse(data); + } catch (e) { + logger.error("Couldn't parse JSON data from socket, maybe buffer issue?"); + logger.error(data); + data = { + event: 'cmd' + , result: { + status: codes.UnknownError + , value: "Error parsing socket data from instruments" + } + }; + } + if (!_.has(data, 'event')) { + logger.error("Socket data came in without event, it was:"); + logger.error(JSON.stringify(data)); + } else if (!_.has(this.eventRouter, data.event)) { + logger.error("Socket is asking for event '" + data.event + + "' which doesn't exist"); + } else { + this.debug("Socket data being routed for '" + data.event + "' event"); + this.eventRouter[data.event].bind(this)(data, conn); } - logger.info("Instruments is at: " + this.instrumentsPath); - - this.socketServer.listen(this.sock, function() { - this.debug("Instruments socket server started at " + this.sock); - this.launch(); - }.bind(this)); }.bind(this)); }; -Instruments.prototype.launch = function() { - var self = this; +Instruments.prototype.launch = function(cb) { // prepare temp dir var tmpDir = "/tmp/appium-instruments/"; - rimraf.sync(tmpDir); - mkdirp.sync(tmpDir); - - fs.mkdir(tmpDir, function(e) { - if (!e || (e && e.code === 'EEXIST')) { - self.proc = self.spawnInstruments(tmpDir); - self.proc.stdout.on('data', function(data) { - self.outputStreamHandler(data); - }); - self.proc.stderr.on('data', function(data) { - self.errorStreamHandler(data); - }); + try { + rimraf.sync(tmpDir); + mkdirp.sync(tmpDir); + } catch (err) { + return cb(err); + } - self.proc.on('exit', function(code) { - self.debug("Instruments exited with code " + code); - if (self.killProcessCb !== null) { - self.killProcessCb(); - self.killProcessCb = null; - } - if (self.isSafariLauncherApp){ - self.readyHandler(); - } - if (self.curCommand && self.curCommand.cb) { - self.curCommand.cb({ - status: code, - value: "Instruments exited with code " + code - }); - } - self.exitCode = code; - self.exitHandler(self.exitCode, self.traceDir); - self.proc.stdin.end(); - self.proc = null; - self.exitHandler = self.defaultExitHandler; - self.resultHandler = self.defaultResultHandler; - self.onReceiveCommand = null; - if (self.currentSocket) { - self.debug("Socket closed forcibly due to exit"); - self.currentSocket.end(); - self.currentSocket.destroy(); // close this - self.socketServer.close(); - } - }); - } else { - throw e; - } - }); + try { + this.proc = this.spawnInstruments(tmpDir); + } catch (err) { + return cb(err); + } + // start waiting for instruments to launch successfully + this.socketConnectTimeout = setTimeout( + this.onSocketNeverConnect.bind(this), + this.launchTimeout); + + this.proc.stdout.setEncoding('utf8'); + this.proc.stderr.setEncoding('utf8'); + this.proc.stdout.pipe(through(this.outputStreamHandler.bind(this))); + this.proc.stderr.pipe(through(this.errorStreamHandler.bind(this))); + this.proc.on('exit', this.onInstrumentsExit.bind(this)); }; Instruments.prototype.spawnInstruments = function(tmpDir) { @@ -213,16 +238,16 @@ Instruments.prototype.spawnInstruments = function(tmpDir) { args = args.concat(["-e", "UIASCRIPT", this.bootstrap]); args = args.concat(["-e", "UIARESULTSPATH", tmpDir]); var env = _.clone(process.env); + var buildPath = path.resolve(__dirname, "../../../build"); + var iwdPath = path.resolve(buildPath, "iwd"); + var iwd4Path = path.resolve(buildPath, "iwd4"); env.CA_DEBUG_TRANSACTIONS = 1; if (this.withoutDelay && !this.udid) { var isXcode4 = this.xcodeVersion !== null && this.xcodeVersion[0] === '4'; - env.DYLD_INSERT_LIBRARIES = path.resolve(__dirname, isXcode4 ? - "../../../build/iwd4/InstrumentsShim.dylib" : - "../../../build/iwd/InstrumentsShim.dylib"); + env.DYLD_INSERT_LIBRARIES = path.resolve(isXcode4 ? iwd4Path : iwdPath, + "InstrumentsShim.dylib"); - env.LIB_PATH = path.resolve(__dirname, isXcode4 ? - "../../../build/iwd4" : - "../../../build/iwd"); + env.LIB_PATH = path.resolve(__dirname, isXcode4 ? iwd4Path : iwdPath); } logger.info("Spawning instruments with command: " + this.instrumentsPath + " " + args.join(" ")); @@ -234,6 +259,50 @@ Instruments.prototype.spawnInstruments = function(tmpDir) { return spawn(this.instrumentsPath, args, {env: env}); }; +Instruments.prototype.onInstrumentsExit = function(code) { + this.debug("Instruments exited with code " + code); + + if (this.neverConnected) { + this.neverConnected = false; // reset so we can catch this again + return this.launchHandler(new Error(ERR_NEVER_CHECKED_IN)); + } + + if (!this.didLaunch) { + return this.launchHandler(new Error(ERR_CRASHED_ON_STARTUP)); + } + + this.cleanupInstruments(); + + if (this.isSafariLauncherApp) { + logger.info("Not worrying about instruments exit since we're using " + + "SafariLauncher"); + this.launchHandler(); + } else if (this.shutdownCb !== null) { + this.shutdownCb(); + this.shutdownCb = null; + } else { + this.exitHandler(code, this.traceDir); + } + +}; + +Instruments.prototype.cleanupInstruments = function() { + logger.info("Cleaning up after instruments exit"); + this.proc = null; + // make sure clear out command cbs so we can't have any lingering cbs + // if a socket request makes it through after exit somehow + this.curCommand = null; + this.onReceiveCommand = null; + + if (this.currentSocket) { + this.debug("Closing instruments client socket due to exit"); + this.currentSocket.end(); + this.currentSocket.destroy(); // close this + this.socketServer.close(); + } + +}; + /* COMMAND LIFECYCLE */ @@ -287,8 +356,8 @@ Instruments.prototype.sendCommand = function(cmd, cb) { /* PROCESS MANAGEMENT */ Instruments.prototype.shutdown = function(cb) { - this.proc.kill(); - this.killProcessCb = cb; + this.killProc(); + this.shutdownCb = cb; }; Instruments.prototype.doExit = function() { @@ -349,10 +418,6 @@ Instruments.prototype.defaultResultHandler = function(output) { } }; -Instruments.prototype.defaultReadyHandler = function() { - logger.info("Instruments is ready and waiting!"); -}; - Instruments.prototype.defaultExitHandler = function(code, traceDir) { logger.info("Instruments exited with code " + code + " and trace dir " + traceDir); }; @@ -377,7 +442,4 @@ Instruments.prototype.debug = function(msg) { }; -/* NODE EXPORTS */ - module.exports = Instruments; - diff --git a/lib/devices/ios/ios.js b/lib/devices/ios/ios.js index d546207a268..2f5bd15a037 100644 --- a/lib/devices/ios/ios.js +++ b/lib/devices/ios/ios.js @@ -39,6 +39,7 @@ var IOS = function(args) { IOS.prototype.init = function(args) { this.rest = args.rest; + this.flakeyRetries = args.flakeyRetries; this.version = args.version; this.webSocket = args.webSocket; this.launchTimeout = args.launchTimeout; @@ -69,7 +70,7 @@ IOS.prototype.init = function(args) { this.instruments = null; this.queue = []; this.progress = 0; - this.onStop = function() {}; + this.onInstrumentsDie = function() {}; this.stopping = false; this.cbForCurrentCmd = null; this.remote = null; @@ -175,9 +176,8 @@ IOS.prototype.start = function(cb, onDie) { return cb(new Error(msg)); } - this.instrumentsDidLaunch = false; if (typeof onDie === "function") { - this.onStop = onDie; + this.onInstrumentsDie = onDie; } async.series([ @@ -214,6 +214,7 @@ IOS.prototype.startInstruments = function(cb) { , xcodeVersion: this.xcodeVersion , webSocket: this.webSocket , launchTimeout: this.launchTimeout + , flakeyRetries: this.flakeyRetries }); this.instruments.start(function(err) { if (err) { @@ -227,12 +228,11 @@ IOS.prototype.startInstruments = function(cb) { } cb(); }.bind(this), function(code, tracedir) { - this.onInstrumentsExit(code, tracedir, cb); + this.onUnexpectedInstrumentsExit(code, tracedir); }.bind(this)); }; IOS.prototype.onInstrumentsLaunch = function(cb) { - this.instrumentsDidLaunch = true; logger.info('Instruments launched. Starting poll loop for new commands.'); this.instruments.setDebug(true); cb(); @@ -284,60 +284,19 @@ IOS.prototype.setInitialOrientation = function(cb) { } }; -IOS.prototype.onInstrumentsExit = function(code, traceDir, launchCb) { - if (!this.instrumentsDidLaunch) { - logger.error("Instruments did not launch successfully, failing session"); - return launchCb(new Error("Instruments did not launch successfully--" + - "please check your app paths or bundle IDs " + - "and try again")); - } - +IOS.prototype.onUnexpectedInstrumentsExit = function(code, traceDir) { + logger.info("Instruments exited unexpectedly"); if (typeof this.cbForCurrentCmd === "function") { // we were in the middle of waiting for a command when it died // so let's actually respond with something var error = new UnknownError("Instruments died while responding to " + "command, please check appium logs"); this.cbForCurrentCmd(error, null); - code = 1; // this counts as an error even if instruments doesn't think so - } - this.instruments = null; - - var removeTraceDir = function(cb) { - if (this.removeTraceDir && traceDir) { - rimraf(traceDir, function(err) { - if (err) return cb(err); - logger.info("Deleted tracedir we heard about from instruments (" + - traceDir + ")"); - cb(); - }); - } else { - cb(); - } - if (!this.stopping) { - this.onStop(code); + if (!code) { + code = 1; // this counts as an error even if instruments doesn't think so } - }.bind(this); - - var cleanup = function(cb) { - if (this.stopping) { - this.postCleanup(function() { - this.bundleId = null; - this.onStop(code); - this.onStop = null; - cb(); - }.bind(this)); - } else { - cb(); - } - }.bind(this); - - if (this.logs !== null) { - this.logs.stopCapture(); - this.logs = null; } - - async.series([removeTraceDir, cleanup], function() {}); - + this.shutdown(code, traceDir, this.onInstrumentsDie); }; IOS.prototype.setXcodeFolder = function(cb) { @@ -777,6 +736,12 @@ IOS.prototype.cleanupAppState = function(cb) { IOS.prototype.postCleanup = function(cb) { this.curCoords = null; this.curOrientation = null; + + if (this.logs !== null) { + this.logs.stopCapture(); + this.logs = null; + } + if (this.remote) { this.stopRemote(); } @@ -794,8 +759,6 @@ IOS.prototype.postCleanup = function(cb) { }; - - IOS.prototype.endSimulator = function(cb) { logger.info("Killing the simulator process and daemons"); if (this.iosSimProcess) { @@ -819,7 +782,9 @@ 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); + exec(removeCmd, { maxBuffer: 524288 }, function() { + cb(); + }); }); }; @@ -829,15 +794,34 @@ IOS.prototype.stop = function(cb) { logger.info("Trying to stop instruments but it already exited"); this.postCleanup(cb); } else { - if (cb) { - this.onStop = cb; + this.instruments.shutdown(function(code, traceDir) { + this.shutdown(code, traceDir, cb); + }.bind(this)); + } +}; + +IOS.prototype.shutdown = function(code, traceDir, cb) { + this.queue = []; + this.progress = 0; + this.instruments = null; + + var removeTraceDir = function(cb) { + if (this.removeTraceDir && traceDir) { + rimraf(traceDir, function(err) { + if (err) return cb(err); + logger.info("Deleted tracedir we heard about from instruments (" + + traceDir + ")"); + cb(); + }); + } else { + cb(); } + }.bind(this); + + async.series([removeTraceDir, this.postCleanup.bind(this)], function() { + cb(); + }); - this.stopping = true; - this.instruments.shutdown(function(){}); - this.queue = []; - this.progress = 0; - } }; IOS.prototype.waitForCondition = deviceCommon.waitForCondition; diff --git a/lib/server/parser.js b/lib/server/parser.js index fc975f4a41a..dd9de8d1de4 100644 --- a/lib/server/parser.js +++ b/lib/server/parser.js @@ -67,6 +67,16 @@ var args = [ , nargs: 0 }], + [['-r', '--backend-retries'], { + defaultValue: 3 + , dest: 'backendRetries' + , required: false + , type: 'int' + , example: "3" + , help: '(iOS-only) How many times to retry launching Instruments ' + + 'before saying it crashed or timed out' + }], + [['--session-override'] , { defaultValue: false , dest: 'sessionOverride' diff --git a/lib/server/responses.js b/lib/server/responses.js index 278e96b6a3c..8458dc12ec0 100644 --- a/lib/server/responses.js +++ b/lib/server/responses.js @@ -97,6 +97,8 @@ exports.getResponseHandler = function(req, res) { notImplementedInThisContext(req, res); } else if (err.name == "NotYetImplementedError") { notYetImplemented(req, res); + } else { + respondError(req, res, status.codes.UnknownError.code, err); } } else { var value = response.value; diff --git a/test/functional/testapp/device.js b/test/functional/testapp/device.js index 0473cf5c93f..c9cfe61a4ca 100644 --- a/test/functional/testapp/device.js +++ b/test/functional/testapp/device.js @@ -8,13 +8,12 @@ describeWd('device target actions', function(h) { it("should die in background and respond within (+/- 6 secs)", function(done) { var before = new Date().getTime() / 1000; h.driver.execute("mobile: background", [{seconds: 1}], function(err) { - should.not.exist(err); + should.exist(err); + err.status.should.equal(13); + err.cause.value.message.should.contain("Instruments died"); var after = new Date().getTime() / 1000; should.ok((after - before) <= 10); - h.driver.elementByTagName('button', function(err) { - should.exist(err); - done(); - }); + done(); }); }); });