appium: Webdriver, iOS - ExecuteAsyncScript is not working

Hi guys,

We are having problems with running driver.executeAsyncScript.

The following example is not returning document.title as expected. Bellow is our example code and output from the appium.

We are using

• latest Appium master build [87a778f121]
• Webdriver v2.42.1
• iOS real device 7.0.1 and iOS simulator 7.1

Thanks for the help!

Cheers,

Andrew

Our test code

var webdriver = require('selenium-webdriver');
var seleniumAddress = 'http://at03n00053:4724/wd/hub';
var caps = {
    'platformName': 'iOS',
    'platformVersion': '7.1',
    'device': 'iPhone Simulator',
    'deviceName': '',
    'browserName': '',
    'app': 'sample-code/apps/WebViewApp/build/Release-iphonesimulator/WebViewApp.app',
    'autoWebview': 'true',
    'nativeWebTap': 'true'
};

var driver = new webdriver.Builder().usingServer(seleniumAddress).withCapabilities(caps).build();

driver.get('http://www.google.com');

driver.executeAsyncScript('return document.title;', 10).
    then(function (title) {
        console.log(title);
    }, function (err) {
        throw 'Error while running test: ' + err.message;
    });

driver.quit();

Our appium log

info: Welcome to Appium v1.2.1 (REV 87a778f121abea06f15989f0859391ffc2a532c0)
info: Appium REST http interface listener started on 0.0.0.0:4724
info: [debug] Non-default server args: {"udid":"OUR_UDID_HERE","port":4724,"sessionOverride":true}
info: LogLevel: debug
info: --> POST /wd/hub/session {"desiredCapabilities":{"platformName":"iOS","platformVersion":"7.1","device":"iPhone Simulator","deviceName":"","browserName":"","app":"sample-code/apps/WebViewApp/build/Release-iphonesimulator/WebViewApp.app","autoWebview":"true","nativeWebTap":"true"}}
warn: Converting cap autoWebview from string to boolean. This might cause unexpected behavior.
warn: Converting cap nativeWebTap from string to boolean. This might cause unexpected behavior.
info: [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. : device
info: [debug] Using local app from desired caps: /Users/bwintest/appium/sample-code/apps/WebViewApp/build/Release-iphonesimulator/WebViewApp.app
info: [debug] Creating new appium session bb29e870-8a59-4f8c-8aca-11db616e6e27
info: [debug] Removing any remaining instruments sockets
info: [debug] Cleaned up instruments socket /tmp/instruments_sock
info: [debug] Setting Xcode folder
info: [debug] Setting Xcode version
info: [debug] Setting iOS SDK Version
info: [debug] iOS SDK Version set to 7.1
info: [debug] Detecting automation tracetemplate
info: [debug] Not auto-detecting udid, running on sim
info: Will try to parse the plist file as XML
warn: Could not parse app Localizable.strings
info: [debug] Not setting locale because we're using a real device
info: [debug] Creating instruments
info: [debug] Preparing uiauto bootstrap
info: [debug] Dynamic bootstrap dir:
info: [debug] Dynamic env:
info: [debug] Dynamic bootstrap code:
info: [debug] Dynamic bootstrap path:
info: [debug] Reusing dynamic bootstrap:
info: [debug] Not setting iOS and app preferences since we're on a real device
info: [debug] Starting iOS device log capture via deviceconsole
info: [debug] Not setting device type since we're connected to a device
info: [debug] Getting bundle ID from app
info: [debug] Parsed app Info.plist (as binary)
info: [debug] Creating iDevice object with udid OUR_UDID_HERE
info: [debug] Couldn't find ideviceinstaller, trying built-in at /Users/bwintest/appium/build/libimobiledevice-macosx/ideviceinstaller
info: [debug] Checking app install status using: /Users/bwintest/appium/build/fruitstrap/fruitstrap isInstalled --id OUR_UDID_HERE --bundle io.appium.WebViewApp
info: [debug] App is installed.
info: [debug] fullReset not requested. No need to install.
info: [debug] Starting command proxy.
info: [debug] Instruments socket server started at /tmp/instruments_sock
info: [debug] Starting instruments
info: [debug] Instruments is at: /Applications/Xcode.app/Contents/Developer/usr/bin/instruments
info: Launching instruments
info: [debug] Attempting to run app on real device with UDID OUR_UDID_HERE
info: [debug] Spawning instruments with command: /Applications/Xcode.app/Contents/Developer/usr/bin/instruments -t /Applications/Xcode.app/Contents/Applications/Instruments.app/Contents/PlugIns/AutomationInstrument.bundle/Contents/Resources/Automation.tracetemplate -D /tmp/appium-instruments/instrumentscli0.trace -w OUR_UDID_HERE /Users/bwintest/appium/sample-code/apps/WebViewApp/build/Release-iphonesimulator/WebViewApp.app -e UIASCRIPT /Users/bwintest/Library/Application Support/appium/bootstrap/bootstrap-63c8820592c3aba3.js -e UIARESULTSPATH /tmp/appium-instruments
info: [debug] And extra without-delay env: {}
info: [debug] And launch timeouts (in ms): {"global":90000}
info: Instruments is ready to receive commands
info: [debug] Instruments launched. Starting poll loop for new commands.
info: [debug] Setting bootstrap config keys/values
info: [debug] Pushing command to appium work queue: "target = $.target();\nau = $;\n$.isVerbose = true;\nautoAcceptAlerts = false;\n"
info: [debug] Sending command to instruments: target = $.target();
au = $;
$.isVerbose = true;
autoAcceptAlerts = false;

info: [debug] Socket data received (2 bytes)
info: [debug] Socket data being routed.
info: [debug] Sending command to instruments: target = $.target();
au = $;
$.isVerbose = true;
autoAcceptAlerts = false;

info: [debug] [INST] 2014-08-25 11:37:27 +0000 Debug: evaluation finished
       
info: [debug] [INST] 2014-08-25 11:37:27 +0000 Debug: responding with:
       
info: [debug] [INST] 2014-08-25 11:37:27 +0000 Debug: Running system command #1: /usr/local/Cellar/node/0.10.29/bin/node /Users/bwintest/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{"status":0,"value":false}...
       
info: [debug] Socket data received (28 bytes)
info: [debug] Socket data being routed.
info: [debug] Got result from instruments: {"status":0,"value":false}
info: [debug] Setting initial orientation to PORTRAIT
info: [debug] Pushing command to appium work queue: "au.setScreenOrientation('PORTRAIT')"
info: [debug] Sending command to instruments: au.setScreenOrientation('PORTRAIT')
info: [debug] Sending command to instruments: au.setScreenOrientation('PORTRAIT')
info: [debug] [INST] 2014-08-25 11:37:28 +0000 Debug: Got new command 1 from instruments: au.setScreenOrientation('PORTRAIT')
       
info: [debug] [INST] 2014-08-25 11:37:28 +0000 Debug: evaluating au.setScreenOrientation('PORTRAIT')
       
info: [debug] [INST] 2014-08-25 11:37:28 +0000 Debug: target.setDeviceOrientation("1")
       
info: [debug] [INST] 2014-08-25 11:37:29 +0000 Debug: evaluation finished
       
info: [debug] [INST] 2014-08-25 11:37:29 +0000 Debug: responding with:
       
info: [debug] [INST] 2014-08-25 11:37:29 +0000 Debug: Running system command #2: /usr/local/Cellar/node/0.10.29/bin/node /Users/bwintest/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{"status":0,"value":"PORTRAIT"}...
       
info: [debug] Socket data received (33 bytes)
info: [debug] Socket data being routed.
info: [debug] Got result from instruments: {"status":0,"value":"PORTRAIT"}
info: [debug] Setting auto webview
info: [debug] Navigating to most recently opened webview
info: [debug] [REMOTE] Getting WebKitRemoteDebugger pageArray
info: [debug] Picking webview WEBVIEW_8
info: [debug] Attempting to set context to 'WEBVIEW_8'
info: [debug] [REMOTE] Debugger web socket connected to url [ws://localhost:27753/devtools/page/8]
info: [debug] [REMOTE] Unregistering from page readiness notifications
info: [debug] Device launched! Ready for commands
info: [debug] Setting command timeout to the default of 60 secs
info: [debug] Appium session started with sessionId bb29e870-8a59-4f8c-8aca-11db616e6e27
info: <-- POST /wd/hub/session 303 17654.905 ms - 9 
info: --> GET /wd/hub/session/bb29e870-8a59-4f8c-8aca-11db616e6e27 {}
info: [debug] Responding to client with success: {"status":0,"value":{"webStorageEnabled":false,"locationContextEnabled":false,"browserName":"","platform":"MAC","javascriptEnabled":true,"databaseEnabled":false,"takesScreenshot":true,"networkConnectionEnabled":false,"warnings":{},"desired":{"platformName":"iOS","platformVersion":"7.1","device":"iPhone Simulator","deviceName":"","browserName":"","app":"sample-code/apps/WebViewApp/build/Release-iphonesimulator/WebViewApp.app","autoWebview":true,"nativeWebTap":true},"platformName":"iOS","platformVersion":"7.1","device":"iPhone Simulator","deviceName":"","app":"sample-code/apps/WebViewApp/build/Release-iphonesimulator/WebViewApp.app","autoWebview":true,"nativeWebTap":true},"sessionId":"bb29e870-8a59-4f8c-8aca-11db616e6e27"}
info: <-- GET /wd/hub/session/bb29e870-8a59-4f8c-8aca-11db616e6e27 200 3.211 ms - 730 {"status":0,"value":{"webStorageEnabled":false,"locationContextEnabled":false,"browserName":"","platform":"MAC","javascriptEnabled":true,"databaseEnabled":false,"takesScreenshot":true,"networkConnectionEnabled":false,"warnings":{},"desired":{"platformName":"iOS","platformVersion":"7.1","device":"iPhone Simulator","deviceName":"","browserName":"","app":"sample-code/apps/WebViewApp/build/Release-iphonesimulator/WebViewApp.app","autoWebview":true,"nativeWebTap":true},"platformName":"iOS","platformVersion":"7.1","device":"iPhone Simulator","deviceName":"","app":"sample-code/apps/WebViewApp/build/Release-iphonesimulator/WebViewApp.app","autoWebview":true,"nativeWebTap":true},"sessionId":"bb29e870-8a59-4f8c-8aca-11db616e6e27"}
info: --> POST /wd/hub/session/bb29e870-8a59-4f8c-8aca-11db616e6e27/url {"url":"http://www.google.com"}
info: [debug] [REMOTE] Navigating to new URL: http://www.google.com
info: [debug] [REMOTE] Remote debugger data sent [{"method":"Page.navigate","params":{"objectGroup":"console","includeCommandLineAPI":true,"doNotPauseOnExceptionsAndMuteConsole":true,"url":"http://www.google.com"},"id":1}]
Debugger web socket received data :  {"result":{},"id":1}
info: [debug] [REMOTE] Debugger got a message for 'Page.navigate' and have no handler, doing nothing.
info: [debug] [REMOTE] Waiting for frame navigated...
info: [debug] [REMOTE] Frame navigated, calling cbs
info: [debug] [REMOTE] Waiting for dom...
info: [debug] [REMOTE] Page loaded, verifying whether ready through readyState
info: [debug] [REMOTE] Checking document readyState
info: [debug] [REMOTE] Sending javascript command
info: [debug] [REMOTE] Remote debugger data sent [{"method":"Runtime.evaluate","params":{"objectGroup":"console","includeCommandLineAPI":true,"doNotPauseOnExceptionsAndMuteConsole":true,"expression":"(function (){return document.readyState;})()","returnByValue":true},"id":2}]
Debugger web socket received data :  {"result":{"result":{"type":"string","value":"complete"},"wasThrown":false},"id":2}
info: [debug] [REMOTE] readyState was complete
info: [debug] [REMOTE] Page is ready, calling onload cbs
info: [debug] Responding to client with success: {"status":0,"value":"","sessionId":"bb29e870-8a59-4f8c-8aca-11db616e6e27"}
info: <-- POST /wd/hub/session/bb29e870-8a59-4f8c-8aca-11db616e6e27/url 200 2030.143 ms - 74 {"status":0,"value":"","sessionId":"bb29e870-8a59-4f8c-8aca-11db616e6e27"}
info: --> POST /wd/hub/session/bb29e870-8a59-4f8c-8aca-11db616e6e27/execute_async {"script":"return document.title;","args":[10]}
info: [debug] Response url for executeAsync is http://0.0.0.0:4724/wd/hub/session/bb29e870-8a59-4f8c-8aca-11db616e6e27/receive_async_response
info: [debug] [REMOTE] Executing atom in default context
info: [debug] [REMOTE] Sending javascript command
info: [debug] [REMOTE] Remote debugger data sent [{"method":"Runtime.evaluate","params":{"objectGroup":"console","includeCommandLineAPI":true,"doNotPauseOnExceptionsAndMuteConsole":true,"expression":"(function(){return function(){var l=this;\nfunction n(a){var b=typeof a;if(\"object\"==b)if(a){if(a instanceof Array)return\"array\";if(a instanceof Object)return b;var c=Object.prototype.toString.call(a);if(\"[object Window]\"==c)return\"object\";if(\"[object Array]\"==c||\"number\"==typeof a.length&&\"undefined\"!=typeof a.splice&&\"undefined\"!=typeof a.propertyIsEnumerable&&!a.propertyIsEnumerable(\"splice\"))return\"array\";if(\"[object Function]\"==c||\"undefined\"!=typeof a.call&&\"undefined\"!=typeof a.propertyIsEnumerable&&!a.propertyIsEnumerable(\"call\"))return\"function\"}else return\"null\";else if(\"function\"==\nb&&\"undefined\"==typeof a.call)return\"object\";return b}function aa(a){var b=n(a);return\"array\"==b||\"object\"==b&&\"number\"==typeof a.length}function ba(a){var b=typeof a;return\"object\"==b&&null!=a||\"function\"==b}function ca(a,b){var c=Array.prototype.slice.call(arguments,1);return function(){var b=Array.prototype.slice.call(arguments);b.unshift.apply(b,c);return a.apply(this,b)}}var p=Date.now||function(){return+new Date};var q=0,r=13;function s(a,b){this.code=a;this.state=u[a]||da;this.message=b||\"\";var c=this.state.replace(/((?:^|\\s+)[a-z])/g,function(a){return a.toUpperCase().replace(/^[\\s\\xa0]+/g,\"\")}),e=c.length-5;if(0>e||c.indexOf(\"Error\",e)!=e)c+=\"Error\";this.name=c;c=Error(this.message);c.name=this.name;this.stack=c.stack||\"\"}(function(){var a=s,b=Error;function c(){}c.prototype=b.prototype;a.d=b.prototype;a.prototype=new c})();\nvar da=\"unknown error\",u={15:\"element not selectable\",11:\"element not visible\",31:\"ime engine activation failed\",30:\"ime not available\",24:\"invalid cookie domain\",29:\"invalid element coordinates\",12:\"invalid element state\",32:\"invalid selector\",51:\"invalid selector\",52:\"invalid selector\",17:\"javascript error\",405:\"unsupported operation\",34:\"move target out of bounds\",27:\"no such alert\",7:\"no such element\",8:\"no such frame\",23:\"no such window\",28:\"script timeout\",33:\"session not created\",10:\"stale element reference\"};\nu[q]=\"success\";u[21]=\"timeout\";u[25]=\"unable to set cookie\";u[26]=\"unexpected alert open\";u[r]=da;u[9]=\"unknown command\";s.prototype.toString=function(){return this.name+\": \"+this.message};function v(a,b){for(var c=0,e=String(a).replace(/^[\\s\\xa0]+|[\\s\\xa0]+$/g,\"\").split(\".\"),f=String(b).replace(/^[\\s\\xa0]+|[\\s\\xa0]+$/g,\"\").split(\".\"),d=Math.max(e.length,f.length),m=0;0==c&&m<d;m++){var t=e[m]||\"\",g=f[m]||\"\",I=RegExp(\"(\\\\d*)(\\\\D*)\",\"g\"),J=RegExp(\"(\\\\d*)(\\\\D*)\",\"g\");do{var k=I.exec(t)||[\"\",\"\",\"\"],h=J.exec(g)||[\"\",\"\",\"\"];if(0==k[0].length&&0==h[0].length)break;c=((0==k[1].length?0:parseInt(k[1],10))<(0==h[1].length?0:parseInt(h[1],10))?-1:(0==k[1].length?0:parseInt(k[1],10))>(0==h[1].length?\n0:parseInt(h[1],10))?1:0)||((0==k[2].length)<(0==h[2].length)?-1:(0==k[2].length)>(0==h[2].length)?1:0)||(k[2]<h[2]?-1:k[2]>h[2]?1:0)}while(0==c)}return c};var w,x,y,z;function A(){return l.navigator?l.navigator.userAgent:null}z=y=x=w=!1;var B;if(B=A()){var ea=l.navigator;w=0==B.indexOf(\"Opera\");x=!w&&-1!=B.indexOf(\"MSIE\");y=!w&&-1!=B.indexOf(\"WebKit\");z=!w&&!y&&\"Gecko\"==ea.product}var C=w,D=x,E=z,fa=y;function ga(){var a=l.document;return a?a.documentMode:void 0}var F;\na:{var G=\"\",H;if(C&&l.opera)var K=l.opera.version,G=\"function\"==typeof K?K():K;else if(E?H=/rv\\:([^\\);]+)(\\)|;)/:D?H=/MSIE\\s+([^\\);]+)(\\)|;)/:fa&&(H=/WebKit\\/(\\S+)/),H)var ha=H.exec(A()),G=ha?ha[1]:\"\";if(D){var ia=ga();if(ia>parseFloat(G)){F=String(ia);break a}}F=G}var ja={};function L(a){return ja[a]||(ja[a]=0<=v(F,a))}var ka=l.document,M=ka&&D?ga()||(\"CSS1Compat\"==ka.compatMode?parseInt(F,10):5):void 0;var N,O,P,Q,R,S,T;T=S=R=Q=P=O=N=!1;var U=A();U&&(-1!=U.indexOf(\"Firefox\")?N=!0:-1!=U.indexOf(\"Camino\")?O=!0:-1!=U.indexOf(\"iPhone\")||-1!=U.indexOf(\"iPod\")?P=!0:-1!=U.indexOf(\"iPad\")?Q=!0:-1!=U.indexOf(\"Android\")?R=!0:-1!=U.indexOf(\"Chrome\")?S=!0:-1!=U.indexOf(\"Safari\")&&(T=!0));var la=N,ma=O,na=P,oa=Q,V=R,pa=S,qa=T;function W(a){return(a=a.exec(A()))?a[1]:\"\"}var ra=function(){if(la)return W(/Firefox\\/([0-9.]+)/);if(D||C)return F;if(pa)return W(/Chrome\\/([0-9.]+)/);if(qa)return W(/Version\\/([0-9.]+)/);if(na||oa){var a=/Version\\/(\\S+).*Mobile\\/(\\S+)/.exec(A());if(a)return a[1]+\".\"+a[2]}else{if(V)return(a=W(/Android\\s+([0-9.]+)/))?a:W(/Version\\/([0-9.]+)/);if(ma)return W(/Camino\\/([0-9.]+)/)}return\"\"}();var sa,ta;function ua(a){va?ta(a):V?v(wa,a):v(ra,a)}var va=function(){if(!E)return!1;var a=l.Components;if(!a)return!1;try{if(!a.classes)return!1}catch(b){return!1}var c=a.classes,a=a.interfaces,e=c[\"@mozilla.org/xpcom/version-comparator;1\"].getService(a.nsIVersionComparator),c=c[\"@mozilla.org/xre/app-info;1\"].getService(a.nsIXULAppInfo),f=c.platformVersion,d=c.version;sa=function(a){return 0<=e.c(f,\"\"+a)};ta=function(a){e.c(d,\"\"+a)};return!0}(),xa;\nif(V){var ya=/Android\\s+([0-9\\.]+)/.exec(A());xa=ya?ya[1]:\"0\"}else xa=\"0\";var wa=xa;V&&ua(2.3);V&&ua(4);qa&&ua(6);function za(){this.a=void 0}\nfunction Aa(a,b,c){switch(typeof b){case \"string\":Ba(b,c);break;case \"number\":c.push(isFinite(b)&&!isNaN(b)?b:\"null\");break;case \"boolean\":c.push(b);break;case \"undefined\":c.push(\"null\");break;case \"object\":if(null==b){c.push(\"null\");break}if(\"array\"==n(b)){var e=b.length;c.push(\"[\");for(var f=\"\",d=0;d<e;d++)c.push(f),f=b[d],Aa(a,a.a?a.a.call(b,String(d),f):f,c),f=\",\";c.push(\"]\");break}c.push(\"{\");e=\"\";for(d in b)Object.prototype.hasOwnProperty.call(b,d)&&(f=b[d],\"function\"!=typeof f&&(c.push(e),\nBa(d,c),c.push(\":\"),Aa(a,a.a?a.a.call(b,d,f):f,c),e=\",\"));c.push(\"}\");break;case \"function\":break;default:throw Error(\"Unknown type: \"+typeof b);}}var Ca={'\"':'\\\\\"',\"\\\\\":\"\\\\\\\\\",\"/\":\"\\\\/\",\"\\b\":\"\\\\b\",\"\\f\":\"\\\\f\",\"\\n\":\"\\\\n\",\"\\r\":\"\\\\r\",\"\\t\":\"\\\\t\",\"\\x0B\":\"\\\\u000b\"},Da=/\\uffff/.test(\"\\uffff\")?/[\\\\\\\"\\x00-\\x1f\\x7f-\\uffff]/g:/[\\\\\\\"\\x00-\\x1f\\x7f-\\xff]/g;\nfunction Ba(a,b){b.push('\"',a.replace(Da,function(a){if(a in Ca)return Ca[a];var b=a.charCodeAt(0),f=\"\\\\u\";16>b?f+=\"000\":256>b?f+=\"00\":4096>b&&(f+=\"0\");return Ca[a]=f+b.toString(16)}),'\"')};fa||C||E&&(va?sa(3.5):D?0<=v(M,3.5):L(3.5))||D&&(va?sa(8):D?v(M,8):L(8));function Ea(a,b){for(var c=a.length,e=Array(c),f=\"string\"==typeof a?a.split(\"\"):a,d=0;d<c;d++)d in f&&(e[d]=b.call(void 0,f[d],d,a));return e};if(E||D){var Fa;if(Fa=D)Fa=D&&9<=M;Fa||E&&L(\"1.9.1\")}D&&L(\"9\");function Ga(a,b){var c={},e;for(e in a)b.call(void 0,a[e],e,a)&&(c[e]=a[e]);return c}function Ha(a,b){var c={},e;for(e in a)c[e]=b.call(void 0,a[e],e,a);return c}function Ia(a,b){for(var c in a)if(b.call(void 0,a[c],c,a))return c};function X(a){switch(n(a)){case \"string\":case \"number\":case \"boolean\":return a;case \"function\":return a.toString();case \"array\":return Ea(a,X);case \"object\":if(\"nodeType\"in a&&(1==a.nodeType||9==a.nodeType)){var b={};b.ELEMENT=Ja(a);return b}if(\"document\"in a)return b={},b.WINDOW=Ja(a),b;if(aa(a))return Ea(a,X);a=Ga(a,function(a,b){return\"number\"==typeof b||\"string\"==typeof b});return Ha(a,X);default:return null}}\nfunction Ka(a,b){return\"array\"==n(a)?Ea(a,function(a){return Ka(a,b)}):ba(a)?\"function\"==typeof a?a:\"ELEMENT\"in a?La(a.ELEMENT,b):\"WINDOW\"in a?La(a.WINDOW,b):Ha(a,function(a){return Ka(a,b)}):a}function Ma(a){a=a||document;var b=a.$wdc_;b||(b=a.$wdc_={},b.b=p());b.b||(b.b=p());return b}function Ja(a){var b=Ma(a.ownerDocument),c=Ia(b,function(b){return b==a});c||(c=\":wdc:\"+b.b++,b[c]=a);return c}\nfunction La(a,b){a=decodeURIComponent(a);var c=b||document,e=Ma(c);if(!(a in e))throw new s(10,\"Element does not exist in cache\");var f=e[a];if(\"setInterval\"in f){if(f.closed)throw delete e[a],new s(23,\"Window has been closed.\");return f}for(var d=f;d;){if(d==c.documentElement)return f;d=d.parentNode}delete e[a];throw new s(10,\"Element is no longer attached to the DOM\");};function Na(a,b,c,e,f,d){function m(a,b){if(!J){g.removeEventListener?g.removeEventListener(\"unload\",t,!0):g.detachEvent(\"onunload\",t);g.clearTimeout(I);if(a!=q){var c=new s(a,b.message||b+\"\");c.stack=b.stack;b={status:\"code\"in c?c.code:r,value:{message:c.message}}}else b={status:q,value:X(b)};var c=e,d;f?(d=[],Aa(new za,b,d),d=d.join(\"\")):d=b;c(d);J=!0}}function t(){m(r,Error(\"Detected a page unload event; asynchronous script execution does not work across page loads.\"))}var g=d||window,I,J=!1;d=\nca(m,r);if(g.closed)d(\"Unable to execute script; the target window is closed.\");else{a=\"string\"==typeof a?new g.Function(a):g==window?a:new g.Function(\"return (\"+a+\").apply(null,arguments);\");b=Ka(b,g.document);b.push(ca(m,q));g.addEventListener?g.addEventListener(\"unload\",t,!0):g.attachEvent(\"onunload\",t);var k=p();try{a.apply(g,b),I=g.setTimeout(function(){m(28,Error(\"Timed out waiting for asyncrhonous script result after \"+(p()-k)+\" ms\"))},Math.max(0,c))}catch(h){m(h.code||r,h)}}}\nvar Y=[\"_\"],Z=l;Y[0]in Z||!Z.execScript||Z.execScript(\"var \"+Y[0]);for(var $;Y.length&&($=Y.shift());)Y.length||void 0===Na?Z=Z[$]?Z[$]:Z[$]={}:Z[$]=Na;; return this._.apply(null,arguments);}.apply({navigator:typeof window!=undefined?window.navigator:null,document:typeof window!=undefined?window.document:null}, arguments);}\n)(\"return document.title;\",[10],0, function (res) { xmlHttp = new XMLHttpRequest(); xmlHttp.open('POST', 'http://0.0.0.0:4724/wd/hub/session/bb29e870-8a59-4f8c-8aca-11db616e6e27/receive_async_response', true);xmlHttp.setRequestHeader('Content-type','application/json'); xmlHttp.send(res); }, true )","returnByValue":true},"id":3}]
Debugger web socket received data :  {"result":{"result":{"type":"undefined"},"wasThrown":false},"id":3}
info: [debug] atom did not return yet, checking to see if we are blocked by an alert
info: [debug] Pushing command to appium work queue: "au.alertIsPresent()"
info: [debug] Sending command to instruments: au.alertIsPresent()
info: [debug] Sending command to instruments: au.alertIsPresent()
info: [debug] [INST] 2014-08-25 11:37:43 +0000 Debug: Got new command 2 from instruments: au.alertIsPresent()
       
info: [debug] [INST] 2014-08-25 11:37:43 +0000 Debug: evaluating au.alertIsPresent()
       
info: [debug] [INST] 2014-08-25 11:37:43 +0000 Debug: evaluation finished
       
info: [debug] [INST] 2014-08-25 11:37:43 +0000 Debug: responding with:
       
info: [debug] [INST] 2014-08-25 11:37:43 +0000 Debug: Running system command #3: /usr/local/Cellar/node/0.10.29/bin/node /Users/bwintest/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{"status":0,"value":false}...
       
info: [debug] Socket data received (28 bytes)
info: [debug] Socket data being routed.
info: [debug] Got result from instruments: {"status":0,"value":false}
info: [debug] atom did not return yet, checking to see if we are blocked by an alert
info: [debug] Pushing command to appium work queue: "au.alertIsPresent()"
info: [debug] Sending command to instruments: au.alertIsPresent()
info: [debug] Sending command to instruments: au.alertIsPresent()
info: [debug] [INST] 2014-08-25 11:37:44 +0000 Debug: Got new command 3 from instruments: au.alertIsPresent()
       
info: [debug] [INST] 2014-08-25 11:37:44 +0000 Debug: evaluating au.alertIsPresent()
       
info: [debug] [INST] 2014-08-25 11:37:44 +0000 Debug: evaluation finished
       
info: [debug] [INST] 2014-08-25 11:37:44 +0000 Debug: responding with:
       
info: [debug] [INST] 2014-08-25 11:37:44 +0000 Debug: Running system command #4: /usr/local/Cellar/node/0.10.29/bin/node /Users/bwintest/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{"status":0,"value":false}...
       
info: [debug] Socket data received (28 bytes)
info: [debug] Socket data being routed.
info: [debug] Got result from instruments: {"status":0,"value":false}
info: [debug] atom did not return yet, checking to see if we are blocked by an alert
info: [debug] Pushing command to appium work queue: "au.alertIsPresent()"
info: [debug] Sending command to instruments: au.alertIsPresent()
info: [debug] Sending command to instruments: au.alertIsPresent()
info: [debug] [INST] 2014-08-25 11:37:45 +0000 Debug: Got new command 4 from instruments: au.alertIsPresent()
       
info: [debug] [INST] 2014-08-25 11:37:45 +0000 Debug: evaluating au.alertIsPresent()
       
info: [debug] [INST] 2014-08-25 11:37:45 +0000 Debug: evaluation finished
       
info: [debug] [INST] 2014-08-25 11:37:45 +0000 Debug: responding with:
       
info: [debug] [INST] 2014-08-25 11:37:45 +0000 Debug: Running system command #5: /usr/local/Cellar/node/0.10.29/bin/node /Users/bwintest/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{"status":0,"value":false}...
       
info: [debug] Socket data received (28 bytes)
info: [debug] Socket data being routed.
info: [debug] Got result from instruments: {"status":0,"value":false}
info: [debug] atom did not return yet, checking to see if we are blocked by an alert
info: [debug] Pushing command to appium work queue: "au.alertIsPresent()"
info: [debug] Sending command to instruments: au.alertIsPresent()
info: [debug] Sending command to instruments: au.alertIsPresent()
info: [debug] [INST] 2014-08-25 11:37:46 +0000 Debug: Got new command 5 from instruments: au.alertIsPresent()
       
info: [debug] [INST] 2014-08-25 11:37:46 +0000 Debug: evaluating au.alertIsPresent()
       
info: [debug] [INST] 2014-08-25 11:37:46 +0000 Debug: evaluation finished
       
info: [debug] [INST] 2014-08-25 11:37:46 +0000 Debug: responding with:
       
info: [debug] [INST] 2014-08-25 11:37:46 +0000 Debug: Running system command #6: /usr/local/Cellar/node/0.10.29/bin/node /Users/bwintest/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{"status":0,"value":false}...
       
info: [debug] Socket data received (28 bytes)
info: [debug] Socket data being routed.
info: [debug] Got result from instruments: {"status":0,"value":false}
info: [debug] atom did not return yet, checking to see if we are blocked by an alert
info: [debug] Pushing command to appium work queue: "au.alertIsPresent()"
info: [debug] Sending command to instruments: au.alertIsPresent()
info: [debug] Sending command to instruments: au.alertIsPresent()
info: [debug] [INST] 2014-08-25 11:37:47 +0000 Debug: Got new command 6 from instruments: au.alertIsPresent()
       
info: [debug] [INST] 2014-08-25 11:37:47 +0000 Debug: evaluating au.alertIsPresent()
       
info: [debug] [INST] 2014-08-25 11:37:47 +0000 Debug: evaluation finished
       
info: [debug] [INST] 2014-08-25 11:37:47 +0000 Debug: responding with:
       
info: [debug] [INST] 2014-08-25 11:37:47 +0000 Debug: Running system command #7: /usr/local/Cellar/node/0.10.29/bin/node /Users/bwintest/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{"status":0,"value":false}...
       
info: [debug] Socket data received (28 bytes)
info: [debug] Socket data being routed.
info: [debug] Got result from instruments: {"status":0,"value":false}
info: [debug] atom did not return yet, checking to see if we are blocked by an alert
info: [debug] Pushing command to appium work queue: "au.alertIsPresent()"
info: [debug] Sending command to instruments: au.alertIsPresent()
info: [debug] Sending command to instruments: au.alertIsPresent()
info: [debug] [INST] 2014-08-25 11:37:48 +0000 Debug: Got new command 7 from instruments: au.alertIsPresent()
       
info: [debug] [INST] 2014-08-25 11:37:48 +0000 Debug: evaluating au.alertIsPresent()
       
info: [debug] [INST] 2014-08-25 11:37:48 +0000 Debug: evaluation finished
       
info: [debug] [INST] 2014-08-25 11:37:48 +0000 Debug: responding with:
       
info: [debug] [INST] 2014-08-25 11:37:49 +0000 Debug: Running system command #8: /usr/local/Cellar/node/0.10.29/bin/node /Users/bwintest/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{"status":0,"value":false}...
       
info: [debug] Socket data received (28 bytes)
info: [debug] Socket data being routed.
info: [debug] Got result from instruments: {"status":0,"value":false}
info: [debug] atom did not return yet, checking to see if we are blocked by an alert
info: [debug] Pushing command to appium work queue: "au.alertIsPresent()"
info: [debug] Sending command to instruments: au.alertIsPresent()
info: [debug] Sending command to instruments: au.alertIsPresent()
info: [debug] [INST] 2014-08-25 11:37:50 +0000 Debug: Got new command 8 from instruments: au.alertIsPresent()
       
info: [debug] [INST] 2014-08-25 11:37:50 +0000 Debug: evaluating au.alertIsPresent()
       
info: [debug] [INST] 2014-08-25 11:37:50 +0000 Debug: evaluation finished
       
info: [debug] [INST] 2014-08-25 11:37:50 +0000 Debug: responding with:
       2014-08-25 11:37:50 +0000 Debug: Running system command #9: /usr/local/Cellar/node/0.10.29/bin/node /Users/bwintest/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{"status":0,"value":false}...

info: [debug] Socket data received (28 bytes)
info: [debug] Socket data being routed.
info: [debug] Got result from instruments: {"status":0,"value":false}
info: [debug] atom did not return yet, checking to see if we are blocked by an alert
info: [debug] Pushing command to appium work queue: "au.alertIsPresent()"
info: [debug] Sending command to instruments: au.alertIsPresent()
info: [debug] Sending command to instruments: au.alertIsPresent()
info: [debug] [INST] 2014-08-25 11:37:51 +0000 Debug: Got new command 9 from instruments: au.alertIsPresent()
       
info: [debug] [INST] 2014-08-25 11:37:51 +0000 Debug: evaluating au.alertIsPresent()
       
info: [debug] [INST] 2014-08-25 11:37:51 +0000 Debug: evaluation finished
       
info: [debug] [INST] 2014-08-25 11:37:51 +0000 Debug: responding with:
       
info: [debug] [INST] 2014-08-25 11:37:51 +0000 Debug: Running system command #10: /usr/local/Cellar/node/0.10.29/bin/node /Users/bwintest/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{"status":0,"value":false}...
       
info: [debug] Socket data received (28 bytes)
info: [debug] Socket data being routed.
info: [debug] Got result from instruments: {"status":0,"value":false}
info: [debug] atom did not return yet, checking to see if we are blocked by an alert
info: [debug] Pushing command to appium work queue: "au.alertIsPresent()"
info: [debug] Sending command to instruments: au.alertIsPresent()
info: [debug] Sending command to instruments: au.alertIsPresent()
info: [debug] [INST] 2014-08-25 11:37:52 +0000 Debug: Got new command 10 from instruments: au.alertIsPresent()
       
info: [debug] [INST] 2014-08-25 11:37:52 +0000 Debug: evaluating au.alertIsPresent()
       
info: [debug] [INST] 2014-08-25 11:37:52 +0000 Debug: evaluation finished
       
info: [debug] [INST] 2014-08-25 11:37:52 +0000 Debug: responding with:
       
info: [debug] [INST] 2014-08-25 11:37:52 +0000 Debug: Running system command #11: /usr/local/Cellar/node/0.10.29/bin/node /Users/bwintest/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{"status":0,"value":false}...
       
info: [debug] Socket data received (28 bytes)
info: [debug] Socket data being routed.
info: [debug] Got result from instruments: {"status":0,"value":false}
info: [debug] atom did not return yet, checking to see if we are blocked by an alert
info: [debug] Pushing command to appium work queue: "au.alertIsPresent()"
info: [debug] Sending command to instruments: au.alertIsPresent()
info: [debug] Sending command to instruments: au.alertIsPresent()
info: [debug] [INST] 2014-08-25 11:37:53 +0000 Debug: Got new command 11 from instruments: au.alertIsPresent()
       
info: [debug] [INST] 2014-08-25 11:37:53 +0000 Debug: evaluating au.alertIsPresent()
       
info: [debug] [INST] 2014-08-25 11:37:53 +0000 Debug: evaluation finished
       
info: [debug] [INST] 2014-08-25 11:37:53 +0000 Debug: responding with:
       
info: [debug] [INST] 2014-08-25 11:37:53 +0000 Debug: Running system command #12: /usr/local/Cellar/node/0.10.29/bin/node /Users/bwintest/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{"status":0,"value":false}...
       
info: [debug] Socket data received (28 bytes)
info: [debug] Socket data being routed.
info: [debug] Got result from instruments: {"status":0,"value":false}
info: [debug] atom did not return yet, checking to see if we are blocked by an alert
info: [debug] Pushing command to appium work queue: "au.alertIsPresent()"
info: [debug] Sending command to instruments: au.alertIsPresent()
info: [debug] Sending command to instruments: au.alertIsPresent()
info: [debug] [INST] 2014-08-25 11:37:54 +0000 Debug: Got new command 12 from instruments: au.alertIsPresent()
       
info: [debug] [INST] 2014-08-25 11:37:54 +0000 Debug: evaluating au.alertIsPresent()
       
info: [debug] [INST] 2014-08-25 11:37:54 +0000 Debug: evaluation finished
       
info: [debug] [INST] 2014-08-25 11:37:54 +0000 Debug: responding with:
       
info: [debug] [INST] 2014-08-25 11:37:54 +0000 Debug: Running system command #13: /usr/local/Cellar/node/0.10.29/bin/node /Users/bwintest/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{"status":0,"value":false}...
       
info: [debug] Socket data received (28 bytes)
info: [debug] Socket data being routed.
info: [debug] Got result from instruments: {"status":0,"value":false}
info: [debug] Didn't get a new command in 60 secs, shutting down...
info: Shutting down appium session
info: [debug] Stopping ios
info: [debug] Destroying instruments client socket.
info: [debug] Closing socket server.
info: [debug] Instruments socket server was closed
info: [debug] Sending sigterm to instruments
info: [debug] [INST] 2014-08-25 11:37:46 +0000 Stopped: Script was stopped by the user
       
info: [debug] [INST] Instruments Trace Complete (Duration : 76.215027s; Output : /tmp/appium-instruments/instrumentscli0.trace)
       
info: [debug] [INSTSERVER] Instruments exited with code 0
info: [debug] Cleaning up after instruments exit
info: [debug] Stopping iOS log capture
info: [debug] Killing the simulator process
info: [debug] [REMOTE] Disconnecting from remote debugger
info: [debug] Killing any other simulator daemons
info: [debug] Cleaning app state.
info: [debug] No folders found to remove
info: [debug] Cleaning up appium session
info: [debug] We shut down because no new commands came in