After start Appium from test class (jenkins) can't find some elements

I use this command in my Java test class to start the Appium server:

Process appiumServer = Runtime.getRuntime().exec("/usr/local/share/npm/bin/appium --session-override");

When I execute my test class locally (Eclipse) everything is fine. But when I execute my test class from a Jenkins job, things work until I need to access (in iOS simulator) buttons in a UIATabBar. Then the test just hangs. (It is not a problem with my xpaths - things run fine when launched locally)

I suspect that the Appium server requires some environment variables to which it has access when I run locally, but not when launched from Jenkins.

Any ideas?

Here is the log. Line 805 is where I access the element mentioned above.

2014-11-06T20:32:52.480Z - info: Welcome to Appium v1.2.0 (REV e53f49c706a25242e66d36685c268b599cc18da5)
2014-11-06T20:32:52.480Z - info: Appium REST http interface listener started on 0.0.0.0:4723
2014-11-06T20:32:52.482Z - debug: Non-default server args: {“sessionOverride”:true,“log”:"/Users/jblaze/a"}
2014-11-06T20:32:52.482Z - info: LogLevel: debug
2014-11-06T20:32:55.042Z - info: --> POST /wd/hub/session {“desiredCapabilities”:{“newCommandTimeout”:900,“platformVersion”:“7.1”,“app”:"/Users/jblaze/jenkins/workspace/sodaIos_2_build_app_run_tests/soda-ios/com/kabam/ios/build/SodaDev.app",“platformName”:“iOS”,“deviceName”:“iPhone Simulator”,“browserName”:"",“locale”:“en_US”,“language”:“en”}}
2014-11-06T20:32:55.043Z - debug: Appium request initiated at /wd/hub/session
2014-11-06T20:32:55.043Z - debug: Request received with params: {“desiredCapabilities”:{“newCommandTimeout”:900,“platformVersion”:“7.1”,“app”:"/Users/jblaze/jenkins/workspace/sodaIos_2_build_app_run_tests/soda-ios/com/kabam/ios/build/SodaDev.app",“platformName”:“iOS”,“deviceName”:“iPhone Simulator”,“browserName”:"",“locale”:“en_US”,“language”:“en”}}
2014-11-06T20:32:55.046Z - debug: Using local app from desired caps: /Users/jblaze/jenkins/workspace/sodaIos_2_build_app_run_tests/soda-ios/com/kabam/ios/build/SodaDev.app
2014-11-06T20:32:55.047Z - debug: Creating new appium session 6f42936a-e757-4400-90b1-80abfc9f99cf
2014-11-06T20:32:55.049Z - debug: Removing any remaining instruments sockets
2014-11-06T20:32:55.049Z - debug: Cleaned up instruments socket /tmp/instruments_sock
2014-11-06T20:32:55.049Z - debug: Cleaning up any tracedirs
2014-11-06T20:32:55.055Z - debug: Cleaned up /usr/local/share/npm/lib/node_modules/appium/instrumentscli0.trace
2014-11-06T20:32:55.055Z - debug: Setting Xcode folder
2014-11-06T20:32:55.065Z - debug: Setting Xcode version
2014-11-06T20:32:55.115Z - debug: Setting iOS SDK Version
2014-11-06T20:32:55.169Z - debug: iOS SDK Version set to 7.1
2014-11-06T20:32:55.169Z - debug: Detecting automation tracetemplate
2014-11-06T20:32:55.175Z - debug: Not auto-detecting udid, running on sim
2014-11-06T20:32:55.175Z - debug: No Localizable.strings for language ‘en’, getting default strings
2014-11-06T20:32:55.176Z - warn: Could not parse plist file at /Users/jblaze/jenkins/workspace/sodaIos_2_build_app_run_tests/soda-ios/com/kabam/ios/build/SodaDev.app/en.lproj/Localizable.strings
2014-11-06T20:32:55.179Z - debug: Setting locale with command /usr/local/share/npm/lib/node_modules/appium/build/ios-sim-locale -sdk 6.1 -language en -locale en_US
2014-11-06T20:32:55.196Z - debug: Setting locale with command /usr/local/share/npm/lib/node_modules/appium/build/ios-sim-locale -sdk 7.0 -language en -locale en_US
2014-11-06T20:32:55.212Z - debug: Setting locale with command /usr/local/share/npm/lib/node_modules/appium/build/ios-sim-locale -sdk 7.1 -language en -locale en_US
2014-11-06T20:32:55.228Z - debug: Setting locale with command /usr/local/share/npm/lib/node_modules/appium/build/ios-sim-locale -sdk 7.1-64 -language en -locale en_US
2014-11-06T20:32:55.244Z - debug: Locale was set
2014-11-06T20:32:55.244Z - debug: Creating instruments
2014-11-06T20:32:55.245Z - debug: Preparing uiauto bootstrap
2014-11-06T20:32:55.245Z - debug: Dynamic bootstrap dir: /Users/jblaze/Library/Application Support/appium/bootstrap
2014-11-06T20:32:55.245Z - debug: Dynamic env: {“nodePath”:"/usr/local/Cellar/node/0.10.18/bin/node",“commandProxyClientPath”:"/usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js"}
2014-11-06T20:32:55.246Z - debug: Dynamic bootstrap code: // This file is automatically generated. Do not manually modify!

#import “/usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/uiauto/bootstrap.js”;

bootstrap({

nodePath: “/usr/local/Cellar/node/0.10.18/bin/node”,

commandProxyClientPath: “/usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js”,

});
2014-11-06T20:32:55.246Z - debug: Dynamic bootstrap path: /Users/jblaze/Library/Application Support/appium/bootstrap/bootstrap-84502a623cd1caa2.js
2014-11-06T20:32:55.249Z - debug: Reusing dynamic bootstrap: /Users/jblaze/Library/Application Support/appium/bootstrap/bootstrap-84502a623cd1caa2.js
2014-11-06T20:32:55.250Z - debug: No iOS / app preferences to set
2014-11-06T20:32:55.251Z - debug: Starting iOS 7.* simulator log capture
2014-11-06T20:32:55.264Z - debug: Killing the simulator process
2014-11-06T20:32:55.272Z - debug: Killing any other simulator daemons
2014-11-06T20:32:55.301Z - debug: Checking whether instruments supports our device string
2014-11-06T20:32:55.302Z - debug: Getting list of devices instruments supports
2014-11-06T20:32:55.310Z - debug: Instruments is at: /Applications/Xcode.app/Contents/Developer/usr/bin/instruments
2014-11-06T20:32:58.991Z - debug: Cleaning app state.
2014-11-06T20:32:59.039Z - debug: Deleted /Users/jblaze/Library/Application Support/iPhone Simulator/7.1-64/Applications
2014-11-06T20:32:59.039Z - debug: Deleted /Users/jblaze/Library/Application Support/iPhone Simulator/7.1-64/Library/TCC
2014-11-06T20:32:59.040Z - debug: Deleted /Users/jblaze/Library/Application Support/iPhone Simulator/7.1-64/Library/Caches/locationd
2014-11-06T20:32:59.041Z - debug: Deleted /Users/jblaze/Library/Application Support/iPhone Simulator/7.1-64/Media
2014-11-06T20:32:59.042Z - debug: Deleted /Users/jblaze/Library/Application Support/iPhone Simulator/7.1-64/Library/Keychains
2014-11-06T20:32:59.042Z - debug: No device id or app, not installing to real device.
2014-11-06T20:32:59.042Z - debug: Starting command proxy.
2014-11-06T20:32:59.043Z - debug: Instruments socket server started at /tmp/instruments_sock
2014-11-06T20:32:59.043Z - debug: Starting instruments
2014-11-06T20:32:59.052Z - debug: Instruments is at: /Applications/Xcode.app/Contents/Developer/usr/bin/instruments
2014-11-06T20:32:59.052Z - info: Launching instruments
2014-11-06T20:32:59.054Z - debug: Instruments device was changed from:" iPhone - Simulator - iOS 7.1 " to:" iPhone Retina (4-inch 64-bit) - Simulator - iOS 7.1"
2014-11-06T20:32:59.054Z - debug: Attempting to run app on iPhone Retina (4-inch 64-bit) - Simulator - iOS 7.1
2014-11-06T20:32:59.054Z - 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 -w iPhone Retina (4-inch 64-bit) - Simulator - iOS 7.1 /Users/jblaze/jenkins/workspace/sodaIos_2_build_app_run_tests/soda-ios/com/kabam/ios/build/SodaDev.app -e UIASCRIPT /Users/jblaze/Library/Application Support/appium/bootstrap/bootstrap-84502a623cd1caa2.js -e UIARESULTSPATH /tmp/appium-instruments
2014-11-06T20:32:59.054Z - debug: And extra without-delay env: {“DYLD_INSERT_LIBRARIES”:"/usr/local/share/npm/lib/node_modules/appium/node_modules/appium-instruments/thirdparty/iwd/InstrumentsShim.dylib",“LIB_PATH”:"/usr/local/share/npm/lib/node_modules/appium/node_modules/appium-instruments/thirdparty/iwd"}
2014-11-06T20:32:59.054Z - debug: And launch timeouts (in ms): {“global”:90000}
2014-11-06T20:33:02.573Z - debug: [INST STDERR] 2014-11-06 12:33:02.572 ScriptAgent[86214:2e07] CLTilesManagerClient: initialize, sSharedTilesManagerClient

2014-11-06T20:33:02.574Z - debug: [INST STDERR] 2014-11-06 12:33:02.573 ScriptAgent[86214:2e07] CLTilesManagerClient: init
2014-11-06 12:33:02.573 ScriptAgent[86214:2e07] CLTilesManagerClient: reconnecting, 0x10d012570

2014-11-06T20:33:03.106Z - info: Instruments is ready to receive commands
2014-11-06T20:33:03.106Z - debug: Instruments launched. Starting poll loop for new commands.
2014-11-06T20:33:03.106Z - debug: Setting bootstrap config keys/values
2014-11-06T20:33:03.107Z - debug: Pushing command to appium work queue: “target = $.target();\nau = $;\n$.isVerbose = true;\nautoAcceptAlerts = false;\n”
2014-11-06T20:33:03.108Z - debug: Sending command to instruments: target = $.target();
au = $;
$.isVerbose = true;
autoAcceptAlerts = false;

2014-11-06T20:33:03.108Z - debug: Socket data received (2 bytes)
2014-11-06T20:33:03.110Z - debug: Socket data being routed.
2014-11-06T20:33:03.110Z - debug: Sending command to instruments: target = $.target();
au = $;
$.isVerbose = true;
autoAcceptAlerts = false;

2014-11-06T20:33:03.124Z - debug: [INST] 2014-11-06 20:33:03 +0000 Debug: evaluation finished

2014-11-06T20:33:03.124Z - debug: [INST] 2014-11-06 20:33:03 +0000 Debug: Result is not protocol compliant, wrapping
2014-11-06 20:33:03 +0000 Debug: Running system command #1: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:false}…

2014-11-06T20:33:03.183Z - debug: Socket data received (28 bytes)
2014-11-06T20:33:03.184Z - debug: Socket data being routed.
2014-11-06T20:33:03.184Z - debug: Got result from instruments: {“status”:0,“value”:false}
2014-11-06T20:33:03.184Z - debug: Pushing command to appium work queue: “au.bundleId()”
2014-11-06T20:33:03.184Z - debug: Sending command to instruments: au.bundleId()
2014-11-06T20:33:03.184Z - debug: Sending command to instruments: au.bundleId()
2014-11-06T20:33:03.192Z - debug: [INST] 2014-11-06 20:33:03 +0000 Debug: Got new command 1 from instruments: au.bundleId()

2014-11-06T20:33:03.193Z - debug: [INST] 2014-11-06 20:33:03 +0000 Debug: evaluating au.bundleId()

2014-11-06T20:33:03.194Z - debug: [INST] 2014-11-06 20:33:03 +0000 Debug: evaluation finished

2014-11-06T20:33:03.195Z - debug: [INST] 2014-11-06 20:33:03 +0000 Debug: Result is not protocol compliant, wrapping

2014-11-06T20:33:03.196Z - debug: [INST] 2014-11-06 20:33:03 +0000 Debug: Running system command #2: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:“com.kabam.SodaDev”}…

2014-11-06T20:33:03.259Z - debug: Socket data received (42 bytes)
2014-11-06T20:33:03.259Z - debug: Socket data being routed.
2014-11-06T20:33:03.259Z - debug: Got result from instruments: {“status”:0,“value”:“com.kabam.SodaDev”}
2014-11-06T20:33:03.260Z - debug: Bundle ID for open app is com.kabam.SodaDev
2014-11-06T20:33:03.260Z - debug: Setting initial orientation to PORTRAIT
2014-11-06T20:33:03.260Z - debug: Pushing command to appium work queue: “au.setScreenOrientation(‘PORTRAIT’)”
2014-11-06T20:33:03.260Z - debug: Sending command to instruments: au.setScreenOrientation(‘PORTRAIT’)
2014-11-06T20:33:03.260Z - debug: Sending command to instruments: au.setScreenOrientation(‘PORTRAIT’)
2014-11-06T20:33:03.268Z - debug: [INST] 2014-11-06 20:33:03 +0000 Debug: Got new command 2 from instruments: au.setScreenOrientation(‘PORTRAIT’)

2014-11-06T20:33:03.269Z - debug: [INST] 2014-11-06 20:33:03 +0000 Debug: evaluating au.setScreenOrientation(‘PORTRAIT’)

2014-11-06T20:33:03.269Z - debug: [INST] 2014-11-06 20:33:03 +0000 Debug: target.setDeviceOrientation(“1”)

2014-11-06T20:33:03.377Z - debug: [INST] 2014-11-06 20:33:03 +0000 Debug: evaluation finished

2014-11-06T20:33:03.378Z - debug: [INST] 2014-11-06 20:33:03 +0000 Debug: Running system command #3: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:“PORTRAIT”}…

2014-11-06T20:33:03.441Z - debug: Socket data received (33 bytes)
2014-11-06T20:33:03.442Z - debug: Socket data being routed.
2014-11-06T20:33:03.442Z - debug: Got result from instruments: {“status”:0,“value”:“PORTRAIT”}
2014-11-06T20:33:03.442Z - debug: Device launched! Ready for commands
2014-11-06T20:33:03.443Z - debug: Setting command timeout to 900 secs
2014-11-06T20:33:03.443Z - debug: Appium session started with sessionId 6f42936a-e757-4400-90b1-80abfc9f99cf
2014-11-06T20:33:03.447Z - info: <-- POST /wd/hub/session 303 8404.925 ms - 9
2014-11-06T20:33:03.460Z - info: --> GET /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf {}
2014-11-06T20:33:03.461Z - debug: Appium request initiated at /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf
2014-11-06T20:33:03.461Z - debug: Request received with params: {}
2014-11-06T20:33:03.461Z - debug: Responding to client with success: {“status”:0,“value”:{“webStorageEnabled”:false,“locationContextEnabled”:false,“browserName”:"",“platform”:“MAC”,“javascriptEnabled”:true,“databaseEnabled”:false,“takesScreenshot”:true,“warnings”:{},“desired”:{“newCommandTimeout”:900,“platformVersion”:“7.1”,“app”:"/Users/jblaze/jenkins/workspace/sodaIos_2_build_app_run_tests/soda-ios/com/kabam/ios/build/SodaDev.app",“platformName”:“iOS”,“deviceName”:“iPhone Simulator”,“browserName”:"",“locale”:“en_US”,“language”:“en”},“newCommandTimeout”:900,“platformVersion”:“7.1”,“app”:"/Users/jblaze/jenkins/workspace/sodaIos_2_build_app_run_tests/soda-ios/com/kabam/ios/build/SodaDev.app",“platformName”:“iOS”,“deviceName”:“iPhone Simulator”,“locale”:“en_US”,“language”:“en”},“sessionId”:“6f42936a-e757-4400-90b1-80abfc9f99cf”}
2014-11-06T20:33:03.463Z - info: <-- GET /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf 200 2.650 ms - 769 {“status”:0,“value”:{“webStorageEnabled”:false,“locationContextEnabled”:false,“browserName”:"",“platform”:“MAC”,“javascriptEnabled”:true,“databaseEnabled”:false,“takesScreenshot”:true,“warnings”:{},“desired”:{“newCommandTimeout”:900,“platformVersion”:“7.1”,“app”:"/Users/jblaze/jenkins/workspace/sodaIos_2_build_app_run_tests/soda-ios/com/kabam/ios/build/SodaDev.app",“platformName”:“iOS”,“deviceName”:“iPhone Simulator”,“browserName”:"",“locale”:“en_US”,“language”:“en”},“newCommandTimeout”:900,“platformVersion”:“7.1”,“app”:"/Users/jblaze/jenkins/workspace/sodaIos_2_build_app_run_tests/soda-ios/com/kabam/ios/build/SodaDev.app",“platformName”:“iOS”,“deviceName”:“iPhone Simulator”,“locale”:“en_US”,“language”:“en”},“sessionId”:“6f42936a-e757-4400-90b1-80abfc9f99cf”}
2014-11-06T20:33:03.493Z - info: --> POST /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/timeouts/implicit_wait {“ms”:10000}
2014-11-06T20:33:03.493Z - debug: Appium request initiated at /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/timeouts/implicit_wait
2014-11-06T20:33:03.493Z - debug: Request received with params: {“ms”:10000}
2014-11-06T20:33:03.495Z - debug: Set iOS implicit wait to 10000ms
2014-11-06T20:33:03.495Z - debug: Responding to client with success: {“status”:0,“value”:null,“sessionId”:“6f42936a-e757-4400-90b1-80abfc9f99cf”}
2014-11-06T20:33:03.495Z - info: <-- POST /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/timeouts/implicit_wait 200 2.527 ms - 76 {“status”:0,“value”:null,“sessionId”:“6f42936a-e757-4400-90b1-80abfc9f99cf”}
2014-11-06T20:33:03.503Z - info: --> POST /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/element {“using”:“xpath”,“value”:"//UIATextField[@name=‘wskeUrlText’]"}
2014-11-06T20:33:03.503Z - debug: Appium request initiated at /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/element
2014-11-06T20:33:03.503Z - debug: Request received with params: {“using”:“xpath”,“value”:"//UIATextField[@name=‘wskeUrlText’]"}
2014-11-06T20:33:03.504Z - debug: Pushing command to appium work queue: “au.mainApp().getTreeForXML()”
2014-11-06T20:33:03.504Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:33:03.505Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:33:03.512Z - debug: [INST] 2014-11-06 20:33:03 +0000 Debug: Got new command 3 from instruments: au.mainApp().getTreeForXML()

2014-11-06T20:33:03.512Z - debug: [INST] 2014-11-06 20:33:03 +0000 Debug: evaluating au.mainApp().getTreeForXML()

2014-11-06T20:33:03.580Z - debug: [INST] 2014-11-06 20:33:03 +0000 Debug: evaluation finished

2014-11-06T20:33:03.581Z - debug: [INST] 2014-11-06 20:33:03 +0000 Debug: Result is not protocol compliant, wrapping

2014-11-06T20:33:03.582Z - debug: [INST] 2014-11-06 20:33:03 +0000 Debug: Running system command #4: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:{“UIAApplication”:{"@":{“name”:“SodaDev”,“label”:“SodaDev”,“value”:null,“dom”:null,“enabled”:true,“valid”:true,"visi…

2014-11-06T20:33:03.645Z - debug: Socket data received (7976 bytes)
2014-11-06T20:33:03.645Z - debug: Socket data being routed.
2014-11-06T20:33:03.646Z - debug: Got result from instruments: {“status”:0,“value”:{“UIAApplication”:{"@":{“name”:“SodaDev”,“label”:“SodaDev”,“value”:null,“dom”:null,“enabled”:true,“valid”:true,“visible”:true,“hint”:null,“path”:"/0",“x”:0,“y”:20,“width”:320,“height”:548},">":[{“UIAWindow”:{"@":{“name”:null,“label”:null,“value”:null,“dom”:null,“enabled”:true,"va
2014-11-06T20:33:03.666Z - debug: Pushing command to appium work queue: “au.getElementByIndexPath(’/0/0/1/1/0’)”
2014-11-06T20:33:03.666Z - debug: Sending command to instruments: au.getElementByIndexPath(’/0/0/1/1/0’)
2014-11-06T20:33:03.666Z - debug: Sending command to instruments: au.getElementByIndexPath(’/0/0/1/1/0’)
2014-11-06T20:33:03.674Z - debug: [INST] 2014-11-06 20:33:03 +0000 Debug: Got new command 4 from instruments: au.getElementByIndexPath(’/0/0/1/1/0’)

2014-11-06T20:33:03.676Z - debug: [INST] 2014-11-06 20:33:03 +0000 Debug: evaluating au.getElementByIndexPath(’/0/0/1/1/0’)

2014-11-06T20:33:03.680Z - debug: [INST] 2014-11-06 20:33:03 +0000 Debug: Lookup returned [object UIATextField] with the name “wskeUrlText” (id: 0).

2014-11-06T20:33:03.682Z - debug: [INST] 2014-11-06 20:33:03 +0000 Debug: evaluation finished

2014-11-06T20:33:03.683Z - debug: [INST] 2014-11-06 20:33:03 +0000 Debug: Running system command #5: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:{“ELEMENT”:“0”}}…

2014-11-06T20:33:03.745Z - debug: Socket data received (38 bytes)
2014-11-06T20:33:03.745Z - debug: Socket data being routed.
2014-11-06T20:33:03.746Z - debug: Got result from instruments: {“status”:0,“value”:{“ELEMENT”:“0”}}
2014-11-06T20:33:03.746Z - debug: Responding to client with success: {“status”:0,“value”:{“ELEMENT”:“0”},“sessionId”:“6f42936a-e757-4400-90b1-80abfc9f99cf”}
2014-11-06T20:33:03.747Z - info: <-- POST /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/element 200 244.388 ms - 87 {“status”:0,“value”:{“ELEMENT”:“0”},“sessionId”:“6f42936a-e757-4400-90b1-80abfc9f99cf”}
2014-11-06T20:33:03.755Z - info: --> POST /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/element/0/value {“id”:“0”,“value”:[“https://api-beta.wske.kabam.com”]}
2014-11-06T20:33:03.755Z - debug: Appium request initiated at /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/element/0/value
2014-11-06T20:33:03.755Z - debug: Request received with params: {“id”:“0”,“value”:[“https://api-beta.wske.kabam.com”]}
2014-11-06T20:33:03.756Z - debug: Pushing command to appium work queue: “au.getElement(‘0’).setValueByType(‘https:\/\/api-beta.wske.kabam.com’)”
2014-11-06T20:33:03.756Z - debug: Sending command to instruments: au.getElement(‘0’).setValueByType(‘https://api-beta.wske.kabam.com’)
2014-11-06T20:33:03.756Z - debug: Sending command to instruments: au.getElement(‘0’).setValueByType(‘https://api-beta.wske.kabam.com’)
2014-11-06T20:33:03.764Z - debug: [INST] 2014-11-06 20:33:03 +0000 Debug: Got new command 5 from instruments: au.getElement(‘0’).setValueByType(‘https://api-beta.wske.kabam.com’)

2014-11-06T20:33:03.765Z - debug: [INST] 2014-11-06 20:33:03 +0000 Debug: evaluating au.getElement(‘0’).setValueByType(‘https://api-beta.wske.kabam.com’)

2014-11-06T20:33:03.766Z - debug: [INST] 2014-11-06 20:33:03 +0000 Debug: target.frontMostApp().elements()[0].elements()[1].elements()[1].elements()[0].tap()

2014-11-06T20:33:04.366Z - debug: [INST] 2014-11-06 20:33:04 +0000 Debug: target.frontMostApp().keyboard().typeString(“https://api-beta.wske.kabam.com”)

2014-11-06T20:33:08.459Z - debug: [INST] 2014-11-06 20:33:08 +0000 Debug: evaluation finished

2014-11-06T20:33:08.460Z - debug: [INST] 2014-11-06 20:33:08 +0000 Debug: Command executed without response

2014-11-06T20:33:08.462Z - debug: [INST] 2014-11-06 20:33:08 +0000 Debug: Result is not protocol compliant, wrapping

2014-11-06T20:33:08.463Z - debug: [INST] 2014-11-06 20:33:08 +0000 Debug: Running system command #6: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:""}…

2014-11-06T20:33:08.536Z - debug: Socket data received (25 bytes)
2014-11-06T20:33:08.536Z - debug: Socket data being routed.
2014-11-06T20:33:08.536Z - debug: Got result from instruments: {“status”:0,“value”:""}
2014-11-06T20:33:08.536Z - debug: Responding to client with success: {“status”:0,“value”:"",“sessionId”:“6f42936a-e757-4400-90b1-80abfc9f99cf”}
2014-11-06T20:33:08.537Z - info: <-- POST /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/element/0/value 200 4782.682 ms - 74 {“status”:0,“value”:"",“sessionId”:“6f42936a-e757-4400-90b1-80abfc9f99cf”}
2014-11-06T20:33:08.541Z - info: --> POST /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/element {“using”:“xpath”,“value”:"//UIATextField[@name=‘clientIdText’]"}
2014-11-06T20:33:08.542Z - debug: Appium request initiated at /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/element
2014-11-06T20:33:08.542Z - debug: Request received with params: {“using”:“xpath”,“value”:"//UIATextField[@name=‘clientIdText’]"}
2014-11-06T20:33:08.543Z - debug: Pushing command to appium work queue: “au.mainApp().getTreeForXML()”
2014-11-06T20:33:08.543Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:33:08.543Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:33:08.553Z - debug: [INST] 2014-11-06 20:33:08 +0000 Debug: Got new command 6 from instruments: au.mainApp().getTreeForXML()

2014-11-06T20:33:08.554Z - debug: [INST] 2014-11-06 20:33:08 +0000 Debug: evaluating au.mainApp().getTreeForXML()

2014-11-06T20:33:08.640Z - debug: [INST] 2014-11-06 20:33:08 +0000 Debug: evaluation finished

2014-11-06T20:33:08.641Z - debug: [INST] 2014-11-06 20:33:08 +0000 Debug: Result is not protocol compliant, wrapping

2014-11-06T20:33:08.643Z - debug: [INST] 2014-11-06 20:33:08 +0000 Debug: Running system command #7: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:{“UIAApplication”:{"@":{“name”:“SodaDev”,“label”:“SodaDev”,“value”:null,“dom”:null,“enabled”:true,“valid”:true,"visi…

2014-11-06T20:33:08.707Z - debug: Socket data received (8192 bytes)
2014-11-06T20:33:08.707Z - debug: Socket data received (6637 bytes)
2014-11-06T20:33:08.707Z - debug: Socket data being routed.
2014-11-06T20:33:08.708Z - debug: Got result from instruments: {“status”:0,“value”:{“UIAApplication”:{"@":{“name”:“SodaDev”,“label”:“SodaDev”,“value”:null,“dom”:null,“enabled”:true,“valid”:true,“visible”:true,“hint”:null,“path”:"/0",“x”:0,“y”:20,“width”:320,“height”:548},">":[{“UIAWindow”:{"@":{“name”:null,“label”:null,“value”:null,“dom”:null,“enabled”:true,"va
2014-11-06T20:33:08.724Z - debug: Pushing command to appium work queue: “au.getElementByIndexPath(’/0/0/1/3/0’)”
2014-11-06T20:33:08.724Z - debug: Sending command to instruments: au.getElementByIndexPath(’/0/0/1/3/0’)
2014-11-06T20:33:08.724Z - debug: Sending command to instruments: au.getElementByIndexPath(’/0/0/1/3/0’)
2014-11-06T20:33:08.732Z - debug: [INST] 2014-11-06 20:33:08 +0000 Debug: Got new command 7 from instruments: au.getElementByIndexPath(’/0/0/1/3/0’)

2014-11-06T20:33:08.734Z - debug: [INST] 2014-11-06 20:33:08 +0000 Debug: evaluating au.getElementByIndexPath(’/0/0/1/3/0’)

2014-11-06T20:33:08.738Z - debug: [INST] 2014-11-06 20:33:08 +0000 Debug: Lookup returned [object UIATextField] with the name “clientIdText” (id: 1).

2014-11-06T20:33:08.740Z - debug: [INST] 2014-11-06 20:33:08 +0000 Debug: evaluation finished

2014-11-06T20:33:08.742Z - debug: [INST] 2014-11-06 20:33:08 +0000 Debug: Running system command #8: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:{“ELEMENT”:“1”}}…

2014-11-06T20:33:08.805Z - debug: Socket data received (38 bytes)
2014-11-06T20:33:08.805Z - debug: Socket data being routed.
2014-11-06T20:33:08.805Z - debug: Got result from instruments: {“status”:0,“value”:{“ELEMENT”:“1”}}
2014-11-06T20:33:08.805Z - debug: Responding to client with success: {“status”:0,“value”:{“ELEMENT”:“1”},“sessionId”:“6f42936a-e757-4400-90b1-80abfc9f99cf”}
2014-11-06T20:33:08.806Z - info: <-- POST /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/element 200 264.419 ms - 87 {“status”:0,“value”:{“ELEMENT”:“1”},“sessionId”:“6f42936a-e757-4400-90b1-80abfc9f99cf”}
2014-11-06T20:33:08.810Z - info: --> POST /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/element/1/value {“id”:“1”,“value”:[“gam1”]}
2014-11-06T20:33:08.810Z - debug: Appium request initiated at /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/element/1/value
2014-11-06T20:33:08.810Z - debug: Request received with params: {“id”:“1”,“value”:[“gam1”]}
2014-11-06T20:33:08.810Z - debug: Pushing command to appium work queue: “au.getElement(‘1’).setValueByType(‘gam1’)”
2014-11-06T20:33:08.811Z - debug: Sending command to instruments: au.getElement(‘1’).setValueByType(‘gam1’)
2014-11-06T20:33:08.811Z - debug: Sending command to instruments: au.getElement(‘1’).setValueByType(‘gam1’)
2014-11-06T20:33:08.820Z - debug: [INST] 2014-11-06 20:33:08 +0000 Debug: Got new command 8 from instruments: au.getElement(‘1’).setValueByType(‘gam1’)

2014-11-06T20:33:08.821Z - debug: [INST] 2014-11-06 20:33:08 +0000 Debug: evaluating au.getElement(‘1’).setValueByType(‘gam1’)

2014-11-06T20:33:08.822Z - debug: [INST] 2014-11-06 20:33:08 +0000 Debug: target.frontMostApp().elements()[0].elements()[1].elements()[3].elements()[0].tap()

2014-11-06T20:33:09.310Z - debug: [INST] 2014-11-06 20:33:09 +0000 Debug: target.frontMostApp().keyboard().typeString(“gam1”)

2014-11-06T20:33:10.054Z - debug: [INST] 2014-11-06 20:33:10 +0000 Debug: evaluation finished

2014-11-06T20:33:10.058Z - debug: [INST] 2014-11-06 20:33:10 +0000 Debug: Command executed without response

2014-11-06T20:33:10.059Z - debug: [INST] 2014-11-06 20:33:10 +0000 Debug: Result is not protocol compliant, wrapping

2014-11-06T20:33:10.061Z - debug: [INST] 2014-11-06 20:33:10 +0000 Debug: Running system command #9: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:""}…

2014-11-06T20:33:10.121Z - debug: Socket data received (25 bytes)
2014-11-06T20:33:10.122Z - debug: Socket data being routed.
2014-11-06T20:33:10.122Z - debug: Got result from instruments: {“status”:0,“value”:""}
2014-11-06T20:33:10.122Z - debug: Responding to client with success: {“status”:0,“value”:"",“sessionId”:“6f42936a-e757-4400-90b1-80abfc9f99cf”}
2014-11-06T20:33:10.122Z - info: <-- POST /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/element/1/value 200 1312.831 ms - 74 {“status”:0,“value”:"",“sessionId”:“6f42936a-e757-4400-90b1-80abfc9f99cf”}
2014-11-06T20:33:10.126Z - info: --> POST /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/element {“using”:“xpath”,“value”:"//UIAApplication/UIAWindow/UIATableView/UIATableCell/UIATextField[@name=‘serverKeyText’]"}
2014-11-06T20:33:10.126Z - debug: Appium request initiated at /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/element
2014-11-06T20:33:10.126Z - debug: Request received with params: {“using”:“xpath”,“value”:"//UIAApplication/UIAWindow/UIATableView/UIATableCell/UIATextField[@name=‘serverKeyText’]"}
2014-11-06T20:33:10.127Z - debug: Pushing command to appium work queue: “au.mainApp().getTreeForXML()”
2014-11-06T20:33:10.127Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:33:10.127Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:33:10.136Z - debug: [INST] 2014-11-06 20:33:10 +0000 Debug: Got new command 9 from instruments: au.mainApp().getTreeForXML()

2014-11-06T20:33:10.139Z - debug: [INST] 2014-11-06 20:33:10 +0000 Debug: evaluating au.mainApp().getTreeForXML()

2014-11-06T20:33:10.223Z - debug: [INST] 2014-11-06 20:33:10 +0000 Debug: evaluation finished

2014-11-06T20:33:10.225Z - debug: [INST] 2014-11-06 20:33:10 +0000 Debug: Result is not protocol compliant, wrapping

2014-11-06T20:33:10.228Z - debug: [INST] 2014-11-06 20:33:10 +0000 Debug: Running system command #10: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:{“UIAApplication”:{"@":{“name”:“SodaDev”,“label”:“SodaDev”,“value”:null,“dom”:null,“enabled”:true,“valid”:true,"visi…

2014-11-06T20:33:10.289Z - debug: Socket data received (8192 bytes)
2014-11-06T20:33:10.289Z - debug: Socket data received (6364 bytes)
2014-11-06T20:33:10.290Z - debug: Socket data being routed.
2014-11-06T20:33:10.290Z - debug: Got result from instruments: {“status”:0,“value”:{“UIAApplication”:{"@":{“name”:“SodaDev”,“label”:“SodaDev”,“value”:null,“dom”:null,“enabled”:true,“valid”:true,“visible”:true,“hint”:null,“path”:"/0",“x”:0,“y”:20,“width”:320,“height”:548},">":[{“UIAWindow”:{"@":{“name”:null,“label”:null,“value”:null,“dom”:null,“enabled”:true,"va
2014-11-06T20:33:10.321Z - debug: Pushing command to appium work queue: “au.getElementByIndexPath(’/0/0/1/5/0’)”
2014-11-06T20:33:10.321Z - debug: Sending command to instruments: au.getElementByIndexPath(’/0/0/1/5/0’)
2014-11-06T20:33:10.321Z - debug: Sending command to instruments: au.getElementByIndexPath(’/0/0/1/5/0’)
2014-11-06T20:33:10.335Z - debug: [INST] 2014-11-06 20:33:10 +0000 Debug: Got new command 10 from instruments: au.getElementByIndexPath(’/0/0/1/5/0’)

2014-11-06T20:33:10.337Z - debug: [INST] 2014-11-06 20:33:10 +0000 Debug: evaluating au.getElementByIndexPath(’/0/0/1/5/0’)

2014-11-06T20:33:10.339Z - debug: [INST] 2014-11-06 20:33:10 +0000 Debug: Lookup returned [object UIATextField] with the name “serverKeyText” (id: 2).

2014-11-06T20:33:10.341Z - debug: [INST] 2014-11-06 20:33:10 +0000 Debug: evaluation finished

2014-11-06T20:33:10.343Z - debug: [INST] 2014-11-06 20:33:10 +0000 Debug: Running system command #11: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:{“ELEMENT”:“2”}}…

2014-11-06T20:33:10.402Z - debug: Socket data received (38 bytes)
2014-11-06T20:33:10.403Z - debug: Socket data being routed.
2014-11-06T20:33:10.403Z - debug: Got result from instruments: {“status”:0,“value”:{“ELEMENT”:“2”}}
2014-11-06T20:33:10.403Z - debug: Responding to client with success: {“status”:0,“value”:{“ELEMENT”:“2”},“sessionId”:“6f42936a-e757-4400-90b1-80abfc9f99cf”}
2014-11-06T20:33:10.403Z - info: <-- POST /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/element 200 277.424 ms - 87 {“status”:0,“value”:{“ELEMENT”:“2”},“sessionId”:“6f42936a-e757-4400-90b1-80abfc9f99cf”}
2014-11-06T20:33:10.408Z - info: --> POST /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/element/2/value {“id”:“2”,“value”:[“b1470ba3c0e695dcb451aa2835ea74e”]}
2014-11-06T20:33:10.408Z - debug: Appium request initiated at /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/element/2/value
2014-11-06T20:33:10.408Z - debug: Request received with params: {“id”:“2”,“value”:[“b1470ba3c0e695dcb451aa2835ea74e”]}
2014-11-06T20:33:10.408Z - debug: Pushing command to appium work queue: “au.getElement(‘2’).setValueByType(‘b1470ba3c0e695dcb451aa2835ea74e’)”
2014-11-06T20:33:10.408Z - debug: Sending command to instruments: au.getElement(‘2’).setValueByType(‘b1470ba3c0e695dcb451aa2835ea74e’)
2014-11-06T20:33:10.408Z - debug: Sending command to instruments: au.getElement(‘2’).setValueByType(‘b1470ba3c0e695dcb451aa2835ea74e’)
2014-11-06T20:33:10.417Z - debug: [INST] 2014-11-06 20:33:10 +0000 Debug: Got new command 11 from instruments: au.getElement(‘2’).setValueByType(‘b1470ba3c0e695dcb451aa2835ea74e’)

2014-11-06T20:33:10.419Z - debug: [INST] 2014-11-06 20:33:10 +0000 Debug: evaluating au.getElement(‘2’).setValueByType(‘b1470ba3c0e695dcb451aa2835ea74e’)

2014-11-06T20:33:10.421Z - debug: [INST] 2014-11-06 20:33:10 +0000 Debug: target.frontMostApp().elements()[0].elements()[1].elements()[5].elements()[0].tap()

2014-11-06T20:33:10.902Z - debug: [INST] 2014-11-06 20:33:10 +0000 Debug: target.frontMostApp().keyboard().typeString(“b1470ba3c0e695dcb451aa2835ea74e”)

2014-11-06T20:33:15.602Z - debug: [INST] 2014-11-06 20:33:15 +0000 Debug: evaluation finished

2014-11-06T20:33:15.603Z - debug: [INST] 2014-11-06 20:33:15 +0000 Debug: Command executed without response

2014-11-06T20:33:15.605Z - debug: [INST] 2014-11-06 20:33:15 +0000 Debug: Result is not protocol compliant, wrapping

2014-11-06T20:33:15.607Z - debug: [INST] 2014-11-06 20:33:15 +0000 Debug: Running system command #12: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:""}…

2014-11-06T20:33:15.665Z - debug: Socket data received (25 bytes)
2014-11-06T20:33:15.665Z - debug: Socket data being routed.
2014-11-06T20:33:15.665Z - debug: Got result from instruments: {“status”:0,“value”:""}
2014-11-06T20:33:15.665Z - debug: Responding to client with success: {“status”:0,“value”:"",“sessionId”:“6f42936a-e757-4400-90b1-80abfc9f99cf”}
2014-11-06T20:33:15.665Z - info: <-- POST /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/element/2/value 200 5258.021 ms - 74 {“status”:0,“value”:"",“sessionId”:“6f42936a-e757-4400-90b1-80abfc9f99cf”}
2014-11-06T20:33:15.669Z - info: --> POST /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/element {“using”:“xpath”,“value”:"//UIANavigationBar/UIAButton[@name=‘Log In’]"}
2014-11-06T20:33:15.669Z - debug: Appium request initiated at /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/element
2014-11-06T20:33:15.670Z - debug: Request received with params: {“using”:“xpath”,“value”:"//UIANavigationBar/UIAButton[@name=‘Log In’]"}
2014-11-06T20:33:15.670Z - debug: Pushing command to appium work queue: “au.mainApp().getTreeForXML()”
2014-11-06T20:33:15.670Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:33:15.671Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:33:15.679Z - debug: [INST] 2014-11-06 20:33:15 +0000 Debug: Got new command 12 from instruments: au.mainApp().getTreeForXML()

2014-11-06T20:33:15.681Z - debug: [INST] 2014-11-06 20:33:15 +0000 Debug: evaluating au.mainApp().getTreeForXML()

2014-11-06T20:33:15.767Z - debug: [INST] 2014-11-06 20:33:15 +0000 Debug: evaluation finished

2014-11-06T20:33:15.769Z - debug: [INST] 2014-11-06 20:33:15 +0000 Debug: Result is not protocol compliant, wrapping

2014-11-06T20:33:15.771Z - debug: [INST] 2014-11-06 20:33:15 +0000 Debug: Running system command #13: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:{“UIAApplication”:{"@":{“name”:“SodaDev”,“label”:“SodaDev”,“value”:null,“dom”:null,“enabled”:true,“valid”:true,"visi…

2014-11-06T20:33:15.831Z - debug: Socket data received (8192 bytes)
2014-11-06T20:33:15.832Z - debug: Socket data received (6534 bytes)
2014-11-06T20:33:15.832Z - debug: Socket data being routed.
2014-11-06T20:33:15.832Z - debug: Got result from instruments: {“status”:0,“value”:{“UIAApplication”:{"@":{“name”:“SodaDev”,“label”:“SodaDev”,“value”:null,“dom”:null,“enabled”:true,“valid”:true,“visible”:true,“hint”:null,“path”:"/0",“x”:0,“y”:20,“width”:320,“height”:548},">":[{“UIAWindow”:{"@":{“name”:null,“label”:null,“value”:null,“dom”:null,“enabled”:true,"va
2014-11-06T20:33:15.840Z - debug: Pushing command to appium work queue: “au.getElementByIndexPath(’/0/0/0/3’)”
2014-11-06T20:33:15.840Z - debug: Sending command to instruments: au.getElementByIndexPath(’/0/0/0/3’)
2014-11-06T20:33:15.840Z - debug: Sending command to instruments: au.getElementByIndexPath(’/0/0/0/3’)
2014-11-06T20:33:15.850Z - debug: [INST] 2014-11-06 20:33:15 +0000 Debug: Got new command 13 from instruments: au.getElementByIndexPath(’/0/0/0/3’)

2014-11-06T20:33:15.853Z - debug: [INST] 2014-11-06 20:33:15 +0000 Debug: evaluating au.getElementByIndexPath(’/0/0/0/3’)

2014-11-06T20:33:15.855Z - debug: [INST] 2014-11-06 20:33:15 +0000 Debug: Lookup returned [object UIAButton] with the name “Log In” (id: 3).

2014-11-06T20:33:15.858Z - debug: [INST] 2014-11-06 20:33:15 +0000 Debug: evaluation finished

2014-11-06T20:33:15.860Z - debug: [INST] 2014-11-06 20:33:15 +0000 Debug: Running system command #14: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:{“ELEMENT”:“3”}}…

2014-11-06T20:33:15.922Z - debug: Socket data received (38 bytes)
2014-11-06T20:33:15.923Z - debug: Socket data being routed.
2014-11-06T20:33:15.923Z - debug: Got result from instruments: {“status”:0,“value”:{“ELEMENT”:“3”}}
2014-11-06T20:33:15.923Z - debug: Responding to client with success: {“status”:0,“value”:{“ELEMENT”:“3”},“sessionId”:“6f42936a-e757-4400-90b1-80abfc9f99cf”}
2014-11-06T20:33:15.923Z - info: <-- POST /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/element 200 254.552 ms - 87 {“status”:0,“value”:{“ELEMENT”:“3”},“sessionId”:“6f42936a-e757-4400-90b1-80abfc9f99cf”}
2014-11-06T20:33:15.927Z - info: --> POST /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/element/3/click {“id”:“3”}
2014-11-06T20:33:15.927Z - debug: Appium request initiated at /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/element/3/click
2014-11-06T20:33:15.927Z - debug: Request received with params: {“id”:“3”}
2014-11-06T20:33:15.928Z - debug: Pushing command to appium work queue: “au.tapById(‘3’)”
2014-11-06T20:33:15.928Z - debug: Sending command to instruments: au.tapById(‘3’)
2014-11-06T20:33:15.928Z - debug: Sending command to instruments: au.tapById(‘3’)
2014-11-06T20:33:15.937Z - debug: [INST] 2014-11-06 20:33:15 +0000 Debug: Got new command 14 from instruments: au.tapById(‘3’)

2014-11-06T20:33:15.940Z - debug: [INST] 2014-11-06 20:33:15 +0000 Debug: evaluating au.tapById(‘3’)

2014-11-06T20:33:15.942Z - debug: [INST] 2014-11-06 20:33:15 +0000 Debug: target.frontMostApp().elements()[0].elements()[0].elements()[3].tap()

2014-11-06T20:33:16.094Z - debug: [INST] 2014-11-06 20:33:16 +0000 Debug: evaluation finished

2014-11-06T20:33:16.097Z - debug: [INST] 2014-11-06 20:33:16 +0000 Debug: Running system command #15: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:null}…

2014-11-06T20:33:16.164Z - debug: Socket data received (27 bytes)
2014-11-06T20:33:16.164Z - debug: Socket data being routed.
2014-11-06T20:33:16.164Z - debug: Got result from instruments: {“status”:0,“value”:null}
2014-11-06T20:33:16.164Z - debug: Responding to client with success: {“status”:0,“value”:null,“sessionId”:“6f42936a-e757-4400-90b1-80abfc9f99cf”}
2014-11-06T20:33:16.164Z - info: <-- POST /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/element/3/click 200 237.137 ms - 76 {“status”:0,“value”:null,“sessionId”:“6f42936a-e757-4400-90b1-80abfc9f99cf”}
2014-11-06T20:33:19.169Z - info: --> POST /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/element {“using”:“xpath”,“value”:"//UIAApplication/UIAWindow/UIATableView/UIATableCell/UIATextField[@name=‘playerIdTextField’]"}
2014-11-06T20:33:19.170Z - debug: Appium request initiated at /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/element
2014-11-06T20:33:19.170Z - debug: Request received with params: {“using”:“xpath”,“value”:"//UIAApplication/UIAWindow/UIATableView/UIATableCell/UIATextField[@name=‘playerIdTextField’]"}
2014-11-06T20:33:19.170Z - debug: Pushing command to appium work queue: “au.mainApp().getTreeForXML()”
2014-11-06T20:33:19.170Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:33:19.170Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:33:19.182Z - debug: [INST] 2014-11-06 20:33:19 +0000 Debug: Got new command 15 from instruments: au.mainApp().getTreeForXML()

2014-11-06T20:33:19.185Z - debug: [INST] 2014-11-06 20:33:19 +0000 Debug: evaluating au.mainApp().getTreeForXML()

2014-11-06T20:33:19.252Z - debug: [INST] 2014-11-06 20:33:19 +0000 Debug: evaluation finished

2014-11-06T20:33:19.255Z - debug: [INST] 2014-11-06 20:33:19 +0000 Debug: Result is not protocol compliant, wrapping

2014-11-06T20:33:19.258Z - debug: [INST] 2014-11-06 20:33:19 +0000 Debug: Running system command #16: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:{“UIAApplication”:{"@":{“name”:“SodaDev”,“label”:“SodaDev”,“value”:null,“dom”:null,“enabled”:true,“valid”:true,"visi…

2014-11-06T20:33:19.319Z - debug: Socket data received (8192 bytes)
2014-11-06T20:33:19.319Z - debug: Socket data received (1431 bytes)
2014-11-06T20:33:19.319Z - debug: Socket data being routed.
2014-11-06T20:33:19.319Z - debug: Got result from instruments: {“status”:0,“value”:{“UIAApplication”:{"@":{“name”:“SodaDev”,“label”:“SodaDev”,“value”:null,“dom”:null,“enabled”:true,“valid”:true,“visible”:true,“hint”:null,“path”:"/0",“x”:0,“y”:20,“width”:320,“height”:548},">":[{“UIAWindow”:{"@":{“name”:null,“label”:null,“value”:null,“dom”:null,“enabled”:true,"va
2014-11-06T20:33:19.325Z - debug: Pushing command to appium work queue: “au.getElementByIndexPath(’/0/0/1/1/0’)”
2014-11-06T20:33:19.325Z - debug: Sending command to instruments: au.getElementByIndexPath(’/0/0/1/1/0’)
2014-11-06T20:33:19.325Z - debug: Sending command to instruments: au.getElementByIndexPath(’/0/0/1/1/0’)
2014-11-06T20:33:19.334Z - debug: [INST] 2014-11-06 20:33:19 +0000 Debug: Got new command 16 from instruments: au.getElementByIndexPath(’/0/0/1/1/0’)

2014-11-06T20:33:19.337Z - debug: [INST] 2014-11-06 20:33:19 +0000 Debug: evaluating au.getElementByIndexPath(’/0/0/1/1/0’)

2014-11-06T20:33:19.340Z - debug: [INST] 2014-11-06 20:33:19 +0000 Debug: Lookup returned [object UIATextField] with the name “playerIdTextField” (id: 4).

2014-11-06T20:33:19.342Z - debug: [INST] 2014-11-06 20:33:19 +0000 Debug: evaluation finished

2014-11-06T20:33:19.345Z - debug: [INST] 2014-11-06 20:33:19 +0000 Debug: Running system command #17: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:{“ELEMENT”:“4”}}…

2014-11-06T20:33:19.405Z - debug: Socket data received (38 bytes)
2014-11-06T20:33:19.406Z - debug: Socket data being routed.
2014-11-06T20:33:19.406Z - debug: Got result from instruments: {“status”:0,“value”:{“ELEMENT”:“4”}}
2014-11-06T20:33:19.406Z - debug: Responding to client with success: {“status”:0,“value”:{“ELEMENT”:“4”},“sessionId”:“6f42936a-e757-4400-90b1-80abfc9f99cf”}
2014-11-06T20:33:19.406Z - info: <-- POST /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/element 200 236.777 ms - 87 {“status”:0,“value”:{“ELEMENT”:“4”},“sessionId”:“6f42936a-e757-4400-90b1-80abfc9f99cf”}
2014-11-06T20:33:19.410Z - info: --> POST /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/element/4/value {“id”:“4”,“value”:[“jblaze”]}
2014-11-06T20:33:19.410Z - debug: Appium request initiated at /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/element/4/value
2014-11-06T20:33:19.410Z - debug: Request received with params: {“id”:“4”,“value”:[“jblaze”]}
2014-11-06T20:33:19.410Z - debug: Pushing command to appium work queue: “au.getElement(‘4’).setValueByType(‘jblaze’)”
2014-11-06T20:33:19.410Z - debug: Sending command to instruments: au.getElement(‘4’).setValueByType(‘jblaze’)
2014-11-06T20:33:19.410Z - debug: Sending command to instruments: au.getElement(‘4’).setValueByType(‘jblaze’)
2014-11-06T20:33:19.419Z - debug: [INST] 2014-11-06 20:33:19 +0000 Debug: Got new command 17 from instruments: au.getElement(‘4’).setValueByType(‘jblaze’)

2014-11-06T20:33:19.422Z - debug: [INST] 2014-11-06 20:33:19 +0000 Debug: evaluating au.getElement(‘4’).setValueByType(‘jblaze’)

2014-11-06T20:33:19.425Z - debug: [INST] 2014-11-06 20:33:19 +0000 Debug: target.frontMostApp().elements()[0].elements()[1].elements()[1].elements()[0].tap()

2014-11-06T20:33:19.651Z - debug: [INST] 2014-11-06 20:33:19 +0000 Debug: target.frontMostApp().keyboard().typeString(“jblaze”)

2014-11-06T20:33:20.911Z - debug: [INST] 2014-11-06 20:33:20 +0000 Debug: evaluation finished

2014-11-06T20:33:20.914Z - debug: [INST] 2014-11-06 20:33:20 +0000 Debug: Command executed without response

2014-11-06T20:33:20.916Z - debug: [INST] 2014-11-06 20:33:20 +0000 Debug: Result is not protocol compliant, wrapping

2014-11-06T20:33:20.919Z - debug: [INST] 2014-11-06 20:33:20 +0000 Debug: Running system command #18: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:""}…

2014-11-06T20:33:20.974Z - debug: Socket data received (25 bytes)
2014-11-06T20:33:20.975Z - debug: Socket data being routed.
2014-11-06T20:33:20.975Z - debug: Got result from instruments: {“status”:0,“value”:""}
2014-11-06T20:33:20.975Z - debug: Responding to client with success: {“status”:0,“value”:"",“sessionId”:“6f42936a-e757-4400-90b1-80abfc9f99cf”}
2014-11-06T20:33:20.975Z - info: <-- POST /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/element/4/value 200 1565.490 ms - 74 {“status”:0,“value”:"",“sessionId”:“6f42936a-e757-4400-90b1-80abfc9f99cf”}
2014-11-06T20:33:20.979Z - info: --> POST /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/element {“using”:“xpath”,“value”:"//UIAButton[@name=‘logInButton’]"}
2014-11-06T20:33:20.979Z - debug: Appium request initiated at /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/element
2014-11-06T20:33:20.979Z - debug: Request received with params: {“using”:“xpath”,“value”:"//UIAButton[@name=‘logInButton’]"}
2014-11-06T20:33:20.979Z - debug: Pushing command to appium work queue: “au.mainApp().getTreeForXML()”
2014-11-06T20:33:20.980Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:33:20.980Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:33:20.989Z - debug: [INST] 2014-11-06 20:33:20 +0000 Debug: Got new command 18 from instruments: au.mainApp().getTreeForXML()

2014-11-06T20:33:20.993Z - debug: [INST] 2014-11-06 20:33:20 +0000 Debug: evaluating au.mainApp().getTreeForXML()

2014-11-06T20:33:21.090Z - debug: [INST] 2014-11-06 20:33:21 +0000 Debug: evaluation finished

2014-11-06T20:33:21.093Z - debug: [INST] 2014-11-06 20:33:21 +0000 Debug: Result is not protocol compliant, wrapping

2014-11-06T20:33:21.096Z - debug: [INST] 2014-11-06 20:33:21 +0000 Debug: Running system command #19: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:{“UIAApplication”:{"@":{“name”:“SodaDev”,“label”:“SodaDev”,“value”:null,“dom”:null,“enabled”:true,“valid”:true,"visi…

2014-11-06T20:33:21.153Z - debug: Socket data received (8192 bytes)
2014-11-06T20:33:21.153Z - debug: Socket data received (8192 bytes)
2014-11-06T20:33:21.153Z - debug: Socket data received (129 bytes)
2014-11-06T20:33:21.153Z - debug: Socket data being routed.
2014-11-06T20:33:21.153Z - debug: Got result from instruments: {“status”:0,“value”:{“UIAApplication”:{"@":{“name”:“SodaDev”,“label”:“SodaDev”,“value”:null,“dom”:null,“enabled”:true,“valid”:true,“visible”:true,“hint”:null,“path”:"/0",“x”:0,“y”:20,“width”:320,“height”:548},">":[{“UIAWindow”:{"@":{“name”:null,“label”:null,“value”:null,“dom”:null,“enabled”:true,"va
2014-11-06T20:33:21.161Z - debug: Pushing command to appium work queue: “au.getElementByIndexPath(’/0/0/1/3/0’)”
2014-11-06T20:33:21.161Z - debug: Sending command to instruments: au.getElementByIndexPath(’/0/0/1/3/0’)
2014-11-06T20:33:21.161Z - debug: Sending command to instruments: au.getElementByIndexPath(’/0/0/1/3/0’)
2014-11-06T20:33:21.170Z - debug: [INST] 2014-11-06 20:33:21 +0000 Debug: Got new command 19 from instruments: au.getElementByIndexPath(’/0/0/1/3/0’)

2014-11-06T20:33:21.174Z - debug: [INST] 2014-11-06 20:33:21 +0000 Debug: evaluating au.getElementByIndexPath(’/0/0/1/3/0’)

2014-11-06T20:33:21.177Z - debug: [INST] 2014-11-06 20:33:21 +0000 Debug: Lookup returned [object UIAButton] with the name “logInButton” (id: 5).

2014-11-06T20:33:21.179Z - debug: [INST] 2014-11-06 20:33:21 +0000 Debug: evaluation finished

2014-11-06T20:33:21.182Z - debug: [INST] 2014-11-06 20:33:21 +0000 Debug: Running system command #20: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:{“ELEMENT”:“5”}}…

2014-11-06T20:33:21.240Z - debug: Socket data received (38 bytes)
2014-11-06T20:33:21.240Z - debug: Socket data being routed.
2014-11-06T20:33:21.241Z - debug: Got result from instruments: {“status”:0,“value”:{“ELEMENT”:“5”}}
2014-11-06T20:33:21.241Z - debug: Responding to client with success: {“status”:0,“value”:{“ELEMENT”:“5”},“sessionId”:“6f42936a-e757-4400-90b1-80abfc9f99cf”}
2014-11-06T20:33:21.241Z - info: <-- POST /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/element 200 262.043 ms - 87 {“status”:0,“value”:{“ELEMENT”:“5”},“sessionId”:“6f42936a-e757-4400-90b1-80abfc9f99cf”}
2014-11-06T20:33:21.245Z - info: --> POST /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/element/5/click {“id”:“5”}
2014-11-06T20:33:21.245Z - debug: Appium request initiated at /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/element/5/click
2014-11-06T20:33:21.245Z - debug: Request received with params: {“id”:“5”}
2014-11-06T20:33:21.246Z - debug: Pushing command to appium work queue: “au.tapById(‘5’)”
2014-11-06T20:33:21.246Z - debug: Sending command to instruments: au.tapById(‘5’)
2014-11-06T20:33:21.246Z - debug: Sending command to instruments: au.tapById(‘5’)
2014-11-06T20:33:21.256Z - debug: [INST] 2014-11-06 20:33:21 +0000 Debug: Got new command 20 from instruments: au.tapById(‘5’)

2014-11-06T20:33:21.260Z - debug: [INST] 2014-11-06 20:33:21 +0000 Debug: evaluating au.tapById(‘5’)

2014-11-06T20:33:21.264Z - debug: [INST] 2014-11-06 20:33:21 +0000 Debug: target.frontMostApp().elements()[0].elements()[1].elements()[3].elements()[0].tap()

2014-11-06T20:33:21.267Z - debug: [INST] 2014-11-06 20:33:21 +0000 Debug: target.frontMostApp().elements()[0].elements()[1].elements()[3].elements()[0].scrollToVisible()

2014-11-06T20:33:21.415Z - debug: [INST] 2014-11-06 20:33:21 +0000 Debug: evaluation finished

2014-11-06T20:33:21.420Z - debug: [INST] 2014-11-06 20:33:21 +0000 Debug: Running system command #21: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:null}…

2014-11-06T20:33:21.488Z - debug: Socket data received (27 bytes)
2014-11-06T20:33:21.488Z - debug: Socket data being routed.
2014-11-06T20:33:21.489Z - debug: Got result from instruments: {“status”:0,“value”:null}
2014-11-06T20:33:21.489Z - debug: Responding to client with success: {“status”:0,“value”:null,“sessionId”:“6f42936a-e757-4400-90b1-80abfc9f99cf”}
2014-11-06T20:33:21.490Z - info: <-- POST /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/element/5/click 200 244.837 ms - 76 {“status”:0,“value”:null,“sessionId”:“6f42936a-e757-4400-90b1-80abfc9f99cf”}
2014-11-06T20:33:21.499Z - info: --> POST /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/timeouts/implicit_wait {“ms”:5000}
2014-11-06T20:33:21.500Z - debug: Appium request initiated at /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/timeouts/implicit_wait
2014-11-06T20:33:21.500Z - debug: Request received with params: {“ms”:5000}
2014-11-06T20:33:21.501Z - debug: Set iOS implicit wait to 5000ms
2014-11-06T20:33:21.501Z - debug: Responding to client with success: {“status”:0,“value”:null,“sessionId”:“6f42936a-e757-4400-90b1-80abfc9f99cf”}
2014-11-06T20:33:21.503Z - info: <-- POST /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/timeouts/implicit_wait 200 1.790 ms - 76 {“status”:0,“value”:null,“sessionId”:“6f42936a-e757-4400-90b1-80abfc9f99cf”}
2014-11-06T20:33:21.506Z - info: --> POST /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/elements {“using”:“xpath”,“value”:"//UIANavigationBar/UIAButton[@name=‘:bomb:’]"}
2014-11-06T20:33:21.507Z - debug: Appium request initiated at /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/elements
2014-11-06T20:33:21.507Z - debug: Request received with params: {“using”:“xpath”,“value”:"//UIANavigationBar/UIAButton[@name=‘:bomb:’]"}
2014-11-06T20:33:21.507Z - debug: Pushing command to appium work queue: “au.mainApp().getTreeForXML()”
2014-11-06T20:33:21.508Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:33:21.508Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:33:21.518Z - debug: [INST] 2014-11-06 20:33:21 +0000 Debug: Got new command 21 from instruments: au.mainApp().getTreeForXML()

2014-11-06T20:33:21.522Z - debug: [INST] 2014-11-06 20:33:21 +0000 Debug: evaluating au.mainApp().getTreeForXML()

2014-11-06T20:33:21.786Z - debug: [INST] 2014-11-06 20:33:21 +0000 Debug: evaluation finished

2014-11-06T20:33:21.790Z - debug: [INST] 2014-11-06 20:33:21 +0000 Debug: Result is not protocol compliant, wrapping

2014-11-06T20:33:21.793Z - debug: [INST] 2014-11-06 20:33:21 +0000 Debug: Running system command #22: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:{“UIAApplication”:{"@":{“name”:“SodaDev”,“label”:“SodaDev”,“value”:null,“dom”:null,“enabled”:true,“valid”:true,"visi…

2014-11-06T20:33:21.853Z - debug: Socket data received (8192 bytes)
2014-11-06T20:33:21.853Z - debug: Socket data received (8091 bytes)
2014-11-06T20:33:21.853Z - debug: Socket data being routed.
2014-11-06T20:33:21.853Z - debug: Got result from instruments: {“status”:0,“value”:{“UIAApplication”:{"@":{“name”:“SodaDev”,“label”:“SodaDev”,“value”:null,“dom”:null,“enabled”:true,“valid”:true,“visible”:true,“hint”:null,“path”:"/0",“x”:0,“y”:20,“width”:320,“height”:548},">":[{“UIAWindow”:{"@":{“name”:null,“label”:null,“value”:null,“dom”:null,“enabled”:true,"va
2014-11-06T20:33:22.361Z - debug: Pushing command to appium work queue: “au.mainApp().getTreeForXML()”
2014-11-06T20:33:22.361Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:33:22.361Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:33:22.374Z - debug: [INST] 2014-11-06 20:33:22 +0000 Debug: Got new command 22 from instruments: au.mainApp().getTreeForXML()

2014-11-06T20:33:22.378Z - debug: [INST] 2014-11-06 20:33:22 +0000 Debug: evaluating au.mainApp().getTreeForXML()

2014-11-06T20:33:22.446Z - debug: [INST] 2014-11-06 20:33:22 +0000 Debug: evaluation finished

2014-11-06T20:33:22.450Z - debug: [INST] 2014-11-06 20:33:22 +0000 Debug: Result is not protocol compliant, wrapping

2014-11-06T20:33:22.455Z - debug: [INST] 2014-11-06 20:33:22 +0000 Debug: Running system command #23: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:{“UIAApplication”:{"@":{“name”:“SodaDev”,“label”:“SodaDev”,“value”:null,“dom”:null,“enabled”:true,“valid”:true,"visi…

2014-11-06T20:33:22.513Z - debug: Socket data received (8188 bytes)
2014-11-06T20:33:22.514Z - debug: Socket data received (1500 bytes)
2014-11-06T20:33:22.514Z - debug: Socket data being routed.
2014-11-06T20:33:22.514Z - debug: Got result from instruments: {“status”:0,“value”:{“UIAApplication”:{"@":{“name”:“SodaDev”,“label”:“SodaDev”,“value”:null,“dom”:null,“enabled”:true,“valid”:true,“visible”:true,“hint”:null,“path”:"/0",“x”:0,“y”:20,“width”:320,“height”:548},">":[{“UIAWindow”:{"@":{“name”:null,“label”:null,“value”:null,“dom”:null,“enabled”:true,“va
2014-11-06T20:33:22.519Z - debug: Pushing command to appium work queue: “au.getElementsByIndexPaths([”/0/0/0/4”])"
2014-11-06T20:33:22.519Z - debug: Sending command to instruments: au.getElementsByIndexPaths(["/0/0/0/4"])
2014-11-06T20:33:22.519Z - debug: Sending command to instruments: au.getElementsByIndexPaths(["/0/0/0/4"])
2014-11-06T20:33:22.530Z - debug: [INST] 2014-11-06 20:33:22 +0000 Debug: Got new command 23 from instruments: au.getElementsByIndexPaths(["/0/0/0/4"])

2014-11-06T20:33:22.533Z - debug: [INST] 2014-11-06 20:33:22 +0000 Debug: evaluating au.getElementsByIndexPaths(["/0/0/0/4"])

2014-11-06T20:33:22.577Z - debug: [INST] 2014-11-06 20:33:22 +0000 logElementTree:
UIAButton “:bomb:” {{290, 28}, {22, 30}}

2014-11-06T20:33:22.581Z - debug: [INST] 2014-11-06 20:33:22 +0000 Debug: Lookup returned [object UIAButton] with the name “:bomb:” (id: 6).

2014-11-06T20:33:22.584Z - debug: [INST] 2014-11-06 20:33:22 +0000 Debug: evaluation finished

2014-11-06T20:33:22.587Z - debug: [INST] 2014-11-06 20:33:22 +0000 Debug: Running system command #24: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:[{“ELEMENT”:“6”}]}…

2014-11-06T20:33:22.621Z - debug: Socket data received (40 bytes)
2014-11-06T20:33:22.621Z - debug: Socket data being routed.
2014-11-06T20:33:22.621Z - debug: Got result from instruments: {“status”:0,“value”:[{“ELEMENT”:“6”}]}
2014-11-06T20:33:22.621Z - debug: Responding to client with success: {“status”:0,“value”:[{“ELEMENT”:“6”}],“sessionId”:“6f42936a-e757-4400-90b1-80abfc9f99cf”}
2014-11-06T20:33:22.622Z - info: <-- POST /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/elements 200 1115.285 ms - 89 {“status”:0,“value”:[{“ELEMENT”:“6”}],“sessionId”:“6f42936a-e757-4400-90b1-80abfc9f99cf”}
2014-11-06T20:33:22.628Z - info: --> POST /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/timeouts/implicit_wait {“ms”:10000}
2014-11-06T20:33:22.628Z - debug: Appium request initiated at /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/timeouts/implicit_wait
2014-11-06T20:33:22.628Z - debug: Request received with params: {“ms”:10000}
2014-11-06T20:33:22.628Z - debug: Set iOS implicit wait to 10000ms
2014-11-06T20:33:22.628Z - debug: Responding to client with success: {“status”:0,“value”:null,“sessionId”:“6f42936a-e757-4400-90b1-80abfc9f99cf”}
2014-11-06T20:33:22.628Z - info: <-- POST /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/timeouts/implicit_wait 200 0.827 ms - 76 {“status”:0,“value”:null,“sessionId”:“6f42936a-e757-4400-90b1-80abfc9f99cf”}
2014-11-06T20:33:22.632Z - info: --> POST /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/timeouts/implicit_wait {“ms”:5000}
2014-11-06T20:33:22.632Z - debug: Appium request initiated at /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/timeouts/implicit_wait
2014-11-06T20:33:22.632Z - debug: Request received with params: {“ms”:5000}
2014-11-06T20:33:22.632Z - debug: Set iOS implicit wait to 5000ms
2014-11-06T20:33:22.632Z - debug: Responding to client with success: {“status”:0,“value”:null,“sessionId”:“6f42936a-e757-4400-90b1-80abfc9f99cf”}
2014-11-06T20:33:22.632Z - info: <-- POST /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/timeouts/implicit_wait 200 0.737 ms - 76 {“status”:0,“value”:null,“sessionId”:“6f42936a-e757-4400-90b1-80abfc9f99cf”}
2014-11-06T20:33:22.635Z - info: --> POST /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/elements {“using”:“xpath”,“value”:"//UIANavigationBar/UIAButton[@name=‘:bomb:’]"}
2014-11-06T20:33:22.636Z - debug: Appium request initiated at /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/elements
2014-11-06T20:33:22.636Z - debug: Request received with params: {“using”:“xpath”,“value”:"//UIANavigationBar/UIAButton[@name=‘:bomb:’]"}
2014-11-06T20:33:22.636Z - debug: Pushing command to appium work queue: “au.mainApp().getTreeForXML()”
2014-11-06T20:33:22.636Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:33:22.636Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:33:22.646Z - debug: [INST] 2014-11-06 20:33:22 +0000 Debug: Got new command 24 from instruments: au.mainApp().getTreeForXML()

2014-11-06T20:33:22.650Z - debug: [INST] 2014-11-06 20:33:22 +0000 Debug: evaluating au.mainApp().getTreeForXML()

2014-11-06T20:33:22.708Z - debug: [INST] 2014-11-06 20:33:22 +0000 Debug: evaluation finished

2014-11-06T20:33:22.712Z - debug: [INST] 2014-11-06 20:33:22 +0000 Debug: Result is not protocol compliant, wrapping

2014-11-06T20:33:22.715Z - debug: [INST] 2014-11-06 20:33:22 +0000 Debug: Running system command #25: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:{“UIAApplication”:{"@":{“name”:“SodaDev”,“label”:“SodaDev”,“value”:null,“dom”:null,“enabled”:true,“valid”:true,"visi…

2014-11-06T20:33:22.775Z - debug: Socket data received (8188 bytes)
2014-11-06T20:33:22.775Z - debug: Socket data received (1500 bytes)
2014-11-06T20:33:22.775Z - debug: Socket data being routed.
2014-11-06T20:33:22.775Z - debug: Got result from instruments: {“status”:0,“value”:{“UIAApplication”:{"@":{“name”:“SodaDev”,“label”:“SodaDev”,“value”:null,“dom”:null,“enabled”:true,“valid”:true,“visible”:true,“hint”:null,“path”:"/0",“x”:0,“y”:20,“width”:320,“height”:548},">":[{“UIAWindow”:{"@":{“name”:null,“label”:null,“value”:null,“dom”:null,“enabled”:true,“va
2014-11-06T20:33:22.781Z - debug: Pushing command to appium work queue: “au.getElementsByIndexPaths([”/0/0/0/4”])"
2014-11-06T20:33:22.781Z - debug: Sending command to instruments: au.getElementsByIndexPaths(["/0/0/0/4"])
2014-11-06T20:33:22.781Z - debug: Sending command to instruments: au.getElementsByIndexPaths(["/0/0/0/4"])
2014-11-06T20:33:22.794Z - debug: [INST] 2014-11-06 20:33:22 +0000 Debug: Got new command 25 from instruments: au.getElementsByIndexPaths(["/0/0/0/4"])

2014-11-06T20:33:22.798Z - debug: [INST] 2014-11-06 20:33:22 +0000 Debug: evaluating au.getElementsByIndexPaths(["/0/0/0/4"])

2014-11-06T20:33:22.814Z - debug: [INST] 2014-11-06 20:33:22 +0000 logElementTree:
UIAButton “:bomb:” {{290, 28}, {22, 30}}

2014-11-06T20:33:22.818Z - debug: [INST] 2014-11-06 20:33:22 +0000 Debug: Lookup returned [object UIAButton] with the name “:bomb:” (id: 7).

2014-11-06T20:33:22.822Z - debug: [INST] 2014-11-06 20:33:22 +0000 Debug: evaluation finished

2014-11-06T20:33:22.825Z - debug: [INST] 2014-11-06 20:33:22 +0000 Debug: Running system command #26: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:[{“ELEMENT”:“7”}]}…

2014-11-06T20:33:22.871Z - debug: Socket data received (40 bytes)
2014-11-06T20:33:22.871Z - debug: Socket data being routed.
2014-11-06T20:33:22.872Z - debug: Got result from instruments: {“status”:0,“value”:[{“ELEMENT”:“7”}]}
2014-11-06T20:33:22.872Z - debug: Responding to client with success: {“status”:0,“value”:[{“ELEMENT”:“7”}],“sessionId”:“6f42936a-e757-4400-90b1-80abfc9f99cf”}
2014-11-06T20:33:22.872Z - info: <-- POST /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/elements 200 236.556 ms - 89 {“status”:0,“value”:[{“ELEMENT”:“7”}],“sessionId”:“6f42936a-e757-4400-90b1-80abfc9f99cf”}
2014-11-06T20:33:22.876Z - info: --> POST /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/timeouts/implicit_wait {“ms”:10000}
2014-11-06T20:33:22.877Z - debug: Appium request initiated at /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/timeouts/implicit_wait
2014-11-06T20:33:22.877Z - debug: Request received with params: {“ms”:10000}
2014-11-06T20:33:22.877Z - debug: Set iOS implicit wait to 10000ms
2014-11-06T20:33:22.877Z - debug: Responding to client with success: {“status”:0,“value”:null,“sessionId”:“6f42936a-e757-4400-90b1-80abfc9f99cf”}
2014-11-06T20:33:22.877Z - info: <-- POST /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/timeouts/implicit_wait 200 1.576 ms - 76 {“status”:0,“value”:null,“sessionId”:“6f42936a-e757-4400-90b1-80abfc9f99cf”}
2014-11-06T20:33:24.883Z - info: --> POST /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/element {“using”:“xpath”,“value”:"//UIANavigationBar/UIAButton[@name=‘:bomb:’]"}
2014-11-06T20:33:24.883Z - debug: Appium request initiated at /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/element
2014-11-06T20:33:24.883Z - debug: Request received with params: {“using”:“xpath”,“value”:"//UIANavigationBar/UIAButton[@name=‘:bomb:’]"}
2014-11-06T20:33:24.883Z - debug: Pushing command to appium work queue: “au.mainApp().getTreeForXML()”
2014-11-06T20:33:24.883Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:33:24.884Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:33:24.897Z - debug: [INST] 2014-11-06 20:33:24 +0000 Debug: Got new command 26 from instruments: au.mainApp().getTreeForXML()

2014-11-06T20:33:24.901Z - debug: [INST] 2014-11-06 20:33:24 +0000 Debug: evaluating au.mainApp().getTreeForXML()

2014-11-06T20:33:24.959Z - debug: [INST] 2014-11-06 20:33:24 +0000 Debug: evaluation finished

2014-11-06T20:33:24.964Z - debug: [INST] 2014-11-06 20:33:24 +0000 Debug: Result is not protocol compliant, wrapping

2014-11-06T20:33:24.968Z - debug: [INST] 2014-11-06 20:33:24 +0000 Debug: Running system command #27: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:{“UIAApplication”:{"@":{“name”:“SodaDev”,“label”:“SodaDev”,“value”:null,“dom”:null,“enabled”:true,“valid”:true,"visi…

2014-11-06T20:33:25.025Z - debug: Socket data received (8188 bytes)
2014-11-06T20:33:25.025Z - debug: Socket data received (1500 bytes)
2014-11-06T20:33:25.025Z - debug: Socket data being routed.
2014-11-06T20:33:25.025Z - debug: Got result from instruments: {“status”:0,“value”:{“UIAApplication”:{"@":{“name”:“SodaDev”,“label”:“SodaDev”,“value”:null,“dom”:null,“enabled”:true,“valid”:true,“visible”:true,“hint”:null,“path”:"/0",“x”:0,“y”:20,“width”:320,“height”:548},">":[{“UIAWindow”:{"@":{“name”:null,“label”:null,“value”:null,“dom”:null,“enabled”:true,"va
2014-11-06T20:33:25.031Z - debug: Pushing command to appium work queue: “au.getElementByIndexPath(’/0/0/0/4’)”
2014-11-06T20:33:25.031Z - debug: Sending command to instruments: au.getElementByIndexPath(’/0/0/0/4’)
2014-11-06T20:33:25.031Z - debug: Sending command to instruments: au.getElementByIndexPath(’/0/0/0/4’)
2014-11-06T20:33:25.043Z - debug: [INST] 2014-11-06 20:33:25 +0000 Debug: Got new command 27 from instruments: au.getElementByIndexPath(’/0/0/0/4’)

2014-11-06T20:33:25.047Z - debug: [INST] 2014-11-06 20:33:25 +0000 Debug: evaluating au.getElementByIndexPath(’/0/0/0/4’)

2014-11-06T20:33:25.051Z - debug: [INST] 2014-11-06 20:33:25 +0000 Debug: Lookup returned [object UIAButton] with the name “:bomb:” (id: 8).

2014-11-06T20:33:25.054Z - debug: [INST] 2014-11-06 20:33:25 +0000 Debug: evaluation finished

2014-11-06T20:33:25.058Z - debug: [INST] 2014-11-06 20:33:25 +0000 Debug: Running system command #28: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:{“ELEMENT”:“8”}}…

2014-11-06T20:33:25.111Z - debug: Socket data received (38 bytes)
2014-11-06T20:33:25.111Z - debug: Socket data being routed.
2014-11-06T20:33:25.112Z - debug: Got result from instruments: {“status”:0,“value”:{“ELEMENT”:“8”}}
2014-11-06T20:33:25.113Z - debug: Responding to client with success: {“status”:0,“value”:{“ELEMENT”:“8”},“sessionId”:“6f42936a-e757-4400-90b1-80abfc9f99cf”}
2014-11-06T20:33:25.113Z - info: <-- POST /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/element 200 230.325 ms - 87 {“status”:0,“value”:{“ELEMENT”:“8”},“sessionId”:“6f42936a-e757-4400-90b1-80abfc9f99cf”}
2014-11-06T20:33:25.117Z - info: --> POST /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/element/8/click {“id”:“8”}
2014-11-06T20:33:25.117Z - debug: Appium request initiated at /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/element/8/click
2014-11-06T20:33:25.117Z - debug: Request received with params: {“id”:“8”}
2014-11-06T20:33:25.117Z - debug: Pushing command to appium work queue: “au.tapById(‘8’)”
2014-11-06T20:33:25.118Z - debug: Sending command to instruments: au.tapById(‘8’)
2014-11-06T20:33:25.118Z - debug: Sending command to instruments: au.tapById(‘8’)
2014-11-06T20:33:25.128Z - debug: [INST] 2014-11-06 20:33:25 +0000 Debug: Got new command 28 from instruments: au.tapById(‘8’)

2014-11-06T20:33:25.131Z - debug: [INST] 2014-11-06 20:33:25 +0000 Debug: evaluating au.tapById(‘8’)

2014-11-06T20:33:25.135Z - debug: [INST] 2014-11-06 20:33:25 +0000 Debug: target.frontMostApp().elements()[0].elements()[0].elements()[4].tap()

2014-11-06T20:33:25.283Z - debug: [INST] 2014-11-06 20:33:25 +0000 Debug: evaluation finished

2014-11-06T20:33:25.289Z - debug: [INST] 2014-11-06 20:33:25 +0000 Debug: Running system command #29: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:null}…

2014-11-06T20:33:25.374Z - debug: Socket data received (27 bytes)
2014-11-06T20:33:25.375Z - debug: Socket data being routed.
2014-11-06T20:33:25.375Z - debug: Got result from instruments: {“status”:0,“value”:null}
2014-11-06T20:33:25.375Z - debug: Responding to client with success: {“status”:0,“value”:null,“sessionId”:“6f42936a-e757-4400-90b1-80abfc9f99cf”}
2014-11-06T20:33:25.375Z - info: <-- POST /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/element/8/click 200 258.461 ms - 76 {“status”:0,“value”:null,“sessionId”:“6f42936a-e757-4400-90b1-80abfc9f99cf”}
2014-11-06T20:33:25.379Z - info: --> POST /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/timeouts/implicit_wait {“ms”:2000}
2014-11-06T20:33:25.379Z - debug: Appium request initiated at /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/timeouts/implicit_wait
2014-11-06T20:33:25.379Z - debug: Request received with params: {“ms”:2000}
2014-11-06T20:33:25.380Z - debug: Set iOS implicit wait to 2000ms
2014-11-06T20:33:25.380Z - debug: Responding to client with success: {“status”:0,“value”:null,“sessionId”:“6f42936a-e757-4400-90b1-80abfc9f99cf”}
2014-11-06T20:33:25.380Z - info: <-- POST /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/timeouts/implicit_wait 200 0.890 ms - 76 {“status”:0,“value”:null,“sessionId”:“6f42936a-e757-4400-90b1-80abfc9f99cf”}
2014-11-06T20:33:25.384Z - info: --> POST /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/elements {“using”:“xpath”,“value”:"//UIAButton[@name=‘fteCallToActionButton’]"}
2014-11-06T20:33:25.385Z - debug: Appium request initiated at /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/elements
2014-11-06T20:33:25.385Z - debug: Request received with params: {“using”:“xpath”,“value”:"//UIAButton[@name=‘fteCallToActionButton’]"}
2014-11-06T20:33:25.385Z - debug: Pushing command to appium work queue: “au.mainApp().getTreeForXML()”
2014-11-06T20:33:25.385Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:33:25.385Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:33:25.397Z - debug: [INST] 2014-11-06 20:33:25 +0000 Debug: Got new command 29 from instruments: au.mainApp().getTreeForXML()

2014-11-06T20:33:25.404Z - debug: [INST] 2014-11-06 20:33:25 +0000 Debug: evaluating au.mainApp().getTreeForXML()

2014-11-06T20:33:25.583Z - debug: [INST] 2014-11-06 20:33:25 +0000 Debug: evaluation finished

2014-11-06T20:33:25.589Z - debug: [INST] 2014-11-06 20:33:25 +0000 Debug: Result is not protocol compliant, wrapping

2014-11-06T20:33:25.595Z - debug: [INST] 2014-11-06 20:33:25 +0000 Debug: Running system command #30: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:{“UIAApplication”:{"@":{“name”:“SodaDev”,“label”:“SodaDev”,“value”:null,“dom”:null,“enabled”:true,“valid”:true,"visi…

2014-11-06T20:33:25.658Z - debug: Socket data received (8188 bytes)
2014-11-06T20:33:25.658Z - debug: Socket data received (6097 bytes)
2014-11-06T20:33:25.658Z - debug: Socket data being routed.
2014-11-06T20:33:25.658Z - debug: Got result from instruments: {“status”:0,“value”:{“UIAApplication”:{"@":{“name”:“SodaDev”,“label”:“SodaDev”,“value”:null,“dom”:null,“enabled”:true,“valid”:true,“visible”:true,“hint”:null,“path”:"/0",“x”:0,“y”:0,“width”:320,“height”:568},">":[{“UIAWindow”:{"@":{“name”:null,“label”:null,“value”:null,“dom”:null,“enabled”:true,"val
2014-11-06T20:33:26.173Z - debug: Pushing command to appium work queue: “au.mainApp().getTreeForXML()”
2014-11-06T20:33:26.173Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:33:26.173Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:33:26.188Z - debug: [INST] 2014-11-06 20:33:26 +0000 Debug: Got new command 30 from instruments: au.mainApp().getTreeForXML()

2014-11-06T20:33:26.194Z - debug: [INST] 2014-11-06 20:33:26 +0000 Debug: evaluating au.mainApp().getTreeForXML()

2014-11-06T20:33:26.240Z - debug: [INST] 2014-11-06 20:33:26 +0000 Debug: evaluation finished

2014-11-06T20:33:26.246Z - debug: [INST] 2014-11-06 20:33:26 +0000 Debug: Result is not protocol compliant, wrapping

2014-11-06T20:33:26.251Z - debug: [INST] 2014-11-06 20:33:26 +0000 Debug: Running system command #31: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:{“UIAApplication”:{"@":{“name”:“SodaDev”,“label”:“SodaDev”,“value”:null,“dom”:null,“enabled”:true,“valid”:true,"visi…

2014-11-06T20:33:26.308Z - debug: Socket data received (6913 bytes)
2014-11-06T20:33:26.308Z - debug: Socket data being routed.
2014-11-06T20:33:26.308Z - debug: Got result from instruments: {“status”:0,“value”:{“UIAApplication”:{"@":{“name”:“SodaDev”,“label”:“SodaDev”,“value”:null,“dom”:null,“enabled”:true,“valid”:true,“visible”:true,“hint”:null,“path”:"/0",“x”:0,“y”:0,“width”:320,“height”:568},">":[{“UIAWindow”:{"@":{“name”:null,“label”:null,“value”:null,“dom”:null,“enabled”:true,"val
2014-11-06T20:33:26.813Z - debug: Pushing command to appium work queue: “au.mainApp().getTreeForXML()”
2014-11-06T20:33:26.813Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:33:26.813Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:33:26.826Z - debug: [INST] 2014-11-06 20:33:26 +0000 Debug: Got new command 31 from instruments: au.mainApp().getTreeForXML()

2014-11-06T20:33:26.830Z - debug: [INST] 2014-11-06 20:33:26 +0000 Debug: evaluating au.mainApp().getTreeForXML()

2014-11-06T20:33:26.876Z - debug: [INST] 2014-11-06 20:33:26 +0000 Debug: evaluation finished

2014-11-06T20:33:26.880Z - debug: [INST] 2014-11-06 20:33:26 +0000 Debug: Result is not protocol compliant, wrapping

2014-11-06T20:33:26.884Z - debug: [INST] 2014-11-06 20:33:26 +0000 Debug: Running system command #32: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:{“UIAApplication”:{"@":{“name”:“SodaDev”,“label”:“SodaDev”,“value”:null,“dom”:null,“enabled”:true,“valid”:true,"visi…

2014-11-06T20:33:26.941Z - debug: Socket data received (6913 bytes)
2014-11-06T20:33:26.942Z - debug: Socket data being routed.
2014-11-06T20:33:26.942Z - debug: Got result from instruments: {“status”:0,“value”:{“UIAApplication”:{"@":{“name”:“SodaDev”,“label”:“SodaDev”,“value”:null,“dom”:null,“enabled”:true,“valid”:true,“visible”:true,“hint”:null,“path”:"/0",“x”:0,“y”:0,“width”:320,“height”:568},">":[{“UIAWindow”:{"@":{“name”:null,“label”:null,“value”:null,“dom”:null,“enabled”:true,"val
2014-11-06T20:33:27.447Z - debug: Pushing command to appium work queue: “au.mainApp().getTreeForXML()”
2014-11-06T20:33:27.447Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:33:27.447Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:33:27.461Z - debug: [INST] 2014-11-06 20:33:27 +0000 Debug: Got new command 32 from instruments: au.mainApp().getTreeForXML()

2014-11-06T20:33:27.468Z - debug: [INST] 2014-11-06 20:33:27 +0000 Debug: evaluating au.mainApp().getTreeForXML()

2014-11-06T20:33:27.575Z - debug: [INST] 2014-11-06 20:33:27 +0000 Debug: evaluation finished

2014-11-06T20:33:27.580Z - debug: [INST] 2014-11-06 20:33:27 +0000 Debug: Result is not protocol compliant, wrapping

2014-11-06T20:33:27.584Z - debug: [INST] 2014-11-06 20:33:27 +0000 Debug: Running system command #33: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:{“UIAApplication”:{"@":{“name”:“SodaDev”,“label”:“SodaDev”,“value”:null,“dom”:null,“enabled”:true,“valid”:true,"visi…

2014-11-06T20:33:27.632Z - debug: Socket data received (8192 bytes)
2014-11-06T20:33:27.632Z - debug: Socket data received (7166 bytes)
2014-11-06T20:33:27.632Z - debug: Socket data being routed.
2014-11-06T20:33:27.632Z - debug: Got result from instruments: {“status”:0,“value”:{“UIAApplication”:{"@":{“name”:“SodaDev”,“label”:“SodaDev”,“value”:null,“dom”:null,“enabled”:true,“valid”:true,“visible”:true,“hint”:null,“path”:"/0",“x”:0,“y”:0,“width”:320,“height”:568},">":[{“UIAWindow”:{"@":{“name”:null,“label”:null,“value”:null,“dom”:null,“enabled”:true,“val
2014-11-06T20:33:27.641Z - debug: Responding to client with success: {“status”:0,“value”:[],“sessionId”:“6f42936a-e757-4400-90b1-80abfc9f99cf”}
2014-11-06T20:33:27.641Z - info: <-- POST /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/elements 200 2256.874 ms - 74 {“status”:0,“value”:[],“sessionId”:“6f42936a-e757-4400-90b1-80abfc9f99cf”}
2014-11-06T20:33:27.645Z - info: --> POST /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/timeouts/implicit_wait {“ms”:10000}
2014-11-06T20:33:27.645Z - debug: Appium request initiated at /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/timeouts/implicit_wait
2014-11-06T20:33:27.645Z - debug: Request received with params: {“ms”:10000}
2014-11-06T20:33:27.646Z - debug: Set iOS implicit wait to 10000ms
2014-11-06T20:33:27.646Z - debug: Responding to client with success: {“status”:0,“value”:null,“sessionId”:“6f42936a-e757-4400-90b1-80abfc9f99cf”}
2014-11-06T20:33:27.646Z - info: <-- POST /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/timeouts/implicit_wait 200 1.155 ms - 76 {“status”:0,“value”:null,“sessionId”:“6f42936a-e757-4400-90b1-80abfc9f99cf”}
2014-11-06T20:33:28.651Z - info: --> POST /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/timeouts/implicit_wait {“ms”:2000}
2014-11-06T20:33:28.651Z - debug: Appium request initiated at /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/timeouts/implicit_wait
2014-11-06T20:33:28.651Z - debug: Request received with params: {“ms”:2000}
2014-11-06T20:33:28.651Z - debug: Set iOS implicit wait to 2000ms
2014-11-06T20:33:28.651Z - debug: Responding to client with success: {“status”:0,“value”:null,“sessionId”:“6f42936a-e757-4400-90b1-80abfc9f99cf”}
2014-11-06T20:33:28.652Z - info: <-- POST /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/timeouts/implicit_wait 200 0.958 ms - 76 {“status”:0,“value”:null,“sessionId”:“6f42936a-e757-4400-90b1-80abfc9f99cf”}
2014-11-06T20:33:28.655Z - info: --> POST /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/elements {“using”:“xpath”,“value”:”//UIATabBar/UIAButton[1][@name=‘Back to Game’]"}
2014-11-06T20:33:28.655Z - debug: Appium request initiated at /wd/hub/session/6f42936a-e757-4400-90b1-80abfc9f99cf/elements
2014-11-06T20:33:28.655Z - debug: Request received with params: {“using”:“xpath”,“value”:"//UIATabBar/UIAButton[1][@name=‘Back to Game’]"}
2014-11-06T20:33:28.655Z - debug: Pushing command to appium work queue: “au.mainApp().getTreeForXML()”
2014-11-06T20:33:28.656Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:33:28.656Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:33:28.671Z - debug: [INST] 2014-11-06 20:33:28 +0000 Debug: Got new command 33 from instruments: au.mainApp().getTreeForXML()

2014-11-06T20:33:28.677Z - debug: [INST] 2014-11-06 20:33:28 +0000 Debug: evaluating au.mainApp().getTreeForXML()

2014-11-06T20:33:28.765Z - debug: [INST] 2014-11-06 20:33:28 +0000 Debug: evaluation finished

2014-11-06T20:33:28.770Z - debug: [INST] 2014-11-06 20:33:28 +0000 Debug: Result is not protocol compliant, wrapping

2014-11-06T20:36:12.694Z - info: Welcome to Appium v1.2.0 (REV e53f49c706a25242e66d36685c268b599cc18da5)
2014-11-06T20:36:12.695Z - info: Appium REST http interface listener started on 0.0.0.0:4723
2014-11-06T20:36:12.697Z - debug: Non-default server args: {“sessionOverride”:true,“log”:"/Users/jblaze/a"}
2014-11-06T20:36:12.697Z - info: LogLevel: debug
2014-11-06T20:36:15.231Z - info: --> POST /wd/hub/session {“desiredCapabilities”:{“newCommandTimeout”:900,“platformVersion”:“7.1”,“app”:"/Users/jblaze/jenkins/workspace/sodaIos_2_build_app_run_tests/soda-ios/com/kabam/ios/build/SodaDev.app",“platformName”:“iOS”,“deviceName”:“iPhone Simulator”,“browserName”:"",“locale”:“en_US”,“language”:“en”}}
2014-11-06T20:36:15.231Z - debug: Appium request initiated at /wd/hub/session
2014-11-06T20:36:15.231Z - debug: Request received with params: {“desiredCapabilities”:{“newCommandTimeout”:900,“platformVersion”:“7.1”,“app”:"/Users/jblaze/jenkins/workspace/sodaIos_2_build_app_run_tests/soda-ios/com/kabam/ios/build/SodaDev.app",“platformName”:“iOS”,“deviceName”:“iPhone Simulator”,“browserName”:"",“locale”:“en_US”,“language”:“en”}}
2014-11-06T20:36:15.234Z - debug: Using local app from desired caps: /Users/jblaze/jenkins/workspace/sodaIos_2_build_app_run_tests/soda-ios/com/kabam/ios/build/SodaDev.app
2014-11-06T20:36:15.235Z - debug: Creating new appium session 62d3f427-7034-43c8-961b-fa99f6c367d6
2014-11-06T20:36:15.237Z - debug: Removing any remaining instruments sockets
2014-11-06T20:36:15.238Z - debug: Cleaned up instruments socket /tmp/instruments_sock
2014-11-06T20:36:15.238Z - debug: Cleaning up any tracedirs
2014-11-06T20:36:15.246Z - debug: Cleaned up /usr/local/share/npm/lib/node_modules/appium/instrumentscli0.trace
2014-11-06T20:36:15.246Z - debug: Setting Xcode folder
2014-11-06T20:36:15.255Z - debug: Setting Xcode version
2014-11-06T20:36:15.303Z - debug: Setting iOS SDK Version
2014-11-06T20:36:15.359Z - debug: iOS SDK Version set to 7.1
2014-11-06T20:36:15.359Z - debug: Detecting automation tracetemplate
2014-11-06T20:36:15.364Z - debug: Not auto-detecting udid, running on sim
2014-11-06T20:36:15.364Z - debug: No Localizable.strings for language ‘en’, getting default strings
2014-11-06T20:36:15.366Z - warn: Could not parse plist file at /Users/jblaze/jenkins/workspace/sodaIos_2_build_app_run_tests/soda-ios/com/kabam/ios/build/SodaDev.app/en.lproj/Localizable.strings
2014-11-06T20:36:15.368Z - debug: Setting locale with command /usr/local/share/npm/lib/node_modules/appium/build/ios-sim-locale -sdk 6.1 -language en -locale en_US
2014-11-06T20:36:15.385Z - debug: Setting locale with command /usr/local/share/npm/lib/node_modules/appium/build/ios-sim-locale -sdk 7.0 -language en -locale en_US
2014-11-06T20:36:15.401Z - debug: Setting locale with command /usr/local/share/npm/lib/node_modules/appium/build/ios-sim-locale -sdk 7.1 -language en -locale en_US
2014-11-06T20:36:15.418Z - debug: Setting locale with command /usr/local/share/npm/lib/node_modules/appium/build/ios-sim-locale -sdk 7.1-64 -language en -locale en_US
2014-11-06T20:36:15.434Z - debug: Locale was set
2014-11-06T20:36:15.434Z - debug: Creating instruments
2014-11-06T20:36:15.435Z - debug: Preparing uiauto bootstrap
2014-11-06T20:36:15.435Z - debug: Dynamic bootstrap dir: /Users/jblaze/Library/Application Support/appium/bootstrap
2014-11-06T20:36:15.435Z - debug: Dynamic env: {“nodePath”:"/usr/local/Cellar/node/0.10.18/bin/node",“commandProxyClientPath”:"/usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js"}
2014-11-06T20:36:15.436Z - debug: Dynamic bootstrap code: // This file is automatically generated. Do not manually modify!

#import “/usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/uiauto/bootstrap.js”;

bootstrap({

nodePath: “/usr/local/Cellar/node/0.10.18/bin/node”,

commandProxyClientPath: “/usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js”,

});
2014-11-06T20:36:15.436Z - debug: Dynamic bootstrap path: /Users/jblaze/Library/Application Support/appium/bootstrap/bootstrap-84502a623cd1caa2.js
2014-11-06T20:36:15.438Z - debug: Reusing dynamic bootstrap: /Users/jblaze/Library/Application Support/appium/bootstrap/bootstrap-84502a623cd1caa2.js
2014-11-06T20:36:15.439Z - debug: No iOS / app preferences to set
2014-11-06T20:36:15.440Z - debug: Starting iOS 7.* simulator log capture
2014-11-06T20:36:15.452Z - debug: Killing the simulator process
2014-11-06T20:36:15.460Z - debug: Killing any other simulator daemons
2014-11-06T20:36:15.491Z - debug: Checking whether instruments supports our device string
2014-11-06T20:36:15.491Z - debug: Getting list of devices instruments supports
2014-11-06T20:36:15.499Z - debug: Instruments is at: /Applications/Xcode.app/Contents/Developer/usr/bin/instruments
2014-11-06T20:36:19.173Z - debug: Cleaning app state.
2014-11-06T20:36:19.225Z - debug: Deleted /Users/jblaze/Library/Application Support/iPhone Simulator/7.1-64/Applications
2014-11-06T20:36:19.226Z - debug: Deleted /Users/jblaze/Library/Application Support/iPhone Simulator/7.1-64/Library/TCC
2014-11-06T20:36:19.227Z - debug: Deleted /Users/jblaze/Library/Application Support/iPhone Simulator/7.1-64/Library/Caches/locationd
2014-11-06T20:36:19.228Z - debug: Deleted /Users/jblaze/Library/Application Support/iPhone Simulator/7.1-64/Media
2014-11-06T20:36:19.229Z - debug: Deleted /Users/jblaze/Library/Application Support/iPhone Simulator/7.1-64/Library/Keychains
2014-11-06T20:36:19.229Z - debug: No device id or app, not installing to real device.
2014-11-06T20:36:19.229Z - debug: Starting command proxy.
2014-11-06T20:36:19.230Z - debug: Instruments socket server started at /tmp/instruments_sock
2014-11-06T20:36:19.230Z - debug: Starting instruments
2014-11-06T20:36:19.238Z - debug: Instruments is at: /Applications/Xcode.app/Contents/Developer/usr/bin/instruments
2014-11-06T20:36:19.238Z - info: Launching instruments
2014-11-06T20:36:19.240Z - debug: Instruments device was changed from:" iPhone - Simulator - iOS 7.1 " to:" iPhone Retina (4-inch 64-bit) - Simulator - iOS 7.1"
2014-11-06T20:36:19.240Z - debug: Attempting to run app on iPhone Retina (4-inch 64-bit) - Simulator - iOS 7.1
2014-11-06T20:36:19.242Z - 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 -w iPhone Retina (4-inch 64-bit) - Simulator - iOS 7.1 /Users/jblaze/jenkins/workspace/sodaIos_2_build_app_run_tests/soda-ios/com/kabam/ios/build/SodaDev.app -e UIASCRIPT /Users/jblaze/Library/Application Support/appium/bootstrap/bootstrap-84502a623cd1caa2.js -e UIARESULTSPATH /tmp/appium-instruments
2014-11-06T20:36:19.242Z - debug: And extra without-delay env: {“DYLD_INSERT_LIBRARIES”:"/usr/local/share/npm/lib/node_modules/appium/node_modules/appium-instruments/thirdparty/iwd/InstrumentsShim.dylib",“LIB_PATH”:"/usr/local/share/npm/lib/node_modules/appium/node_modules/appium-instruments/thirdparty/iwd"}
2014-11-06T20:36:19.242Z - debug: And launch timeouts (in ms): {“global”:90000}
2014-11-06T20:36:22.703Z - debug: [INST STDERR] 2014-11-06 12:36:22.702 ScriptAgent[87393:2e07] CLTilesManagerClient: initialize, sSharedTilesManagerClient

2014-11-06T20:36:22.703Z - debug: [INST STDERR] 2014-11-06 12:36:22.702 ScriptAgent[87393:2e07] CLTilesManagerClient: init
2014-11-06 12:36:22.702 ScriptAgent[87393:2e07] CLTilesManagerClient: reconnecting, 0x10c61b820

2014-11-06T20:36:23.354Z - info: Instruments is ready to receive commands
2014-11-06T20:36:23.354Z - debug: Instruments launched. Starting poll loop for new commands.
2014-11-06T20:36:23.355Z - debug: Setting bootstrap config keys/values
2014-11-06T20:36:23.355Z - debug: Pushing command to appium work queue: “target = $.target();\nau = $;\n$.isVerbose = true;\nautoAcceptAlerts = false;\n”
2014-11-06T20:36:23.356Z - debug: Sending command to instruments: target = $.target();
au = $;
$.isVerbose = true;
autoAcceptAlerts = false;

2014-11-06T20:36:23.357Z - debug: Socket data received (2 bytes)
2014-11-06T20:36:23.359Z - debug: Socket data being routed.
2014-11-06T20:36:23.359Z - debug: Sending command to instruments: target = $.target();
au = $;
$.isVerbose = true;
autoAcceptAlerts = false;

2014-11-06T20:36:23.376Z - debug: [INST] 2014-11-06 20:36:23 +0000 Debug: evaluation finished

2014-11-06T20:36:23.380Z - debug: [INST] 2014-11-06 20:36:23 +0000 Debug: Result is not protocol compliant, wrapping

2014-11-06T20:36:23.381Z - debug: [INST] 2014-11-06 20:36:23 +0000 Debug: Running system command #1: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:false}…

2014-11-06T20:36:23.438Z - debug: Socket data received (28 bytes)
2014-11-06T20:36:23.439Z - debug: Socket data being routed.
2014-11-06T20:36:23.439Z - debug: Got result from instruments: {“status”:0,“value”:false}
2014-11-06T20:36:23.439Z - debug: Pushing command to appium work queue: “au.bundleId()”
2014-11-06T20:36:23.439Z - debug: Sending command to instruments: au.bundleId()
2014-11-06T20:36:23.439Z - debug: Sending command to instruments: au.bundleId()
2014-11-06T20:36:23.447Z - debug: [INST] 2014-11-06 20:36:23 +0000 Debug: Got new command 1 from instruments: au.bundleId()

2014-11-06T20:36:23.447Z - debug: [INST] 2014-11-06 20:36:23 +0000 Debug: evaluating au.bundleId()

2014-11-06T20:36:23.453Z - debug: [INST] 2014-11-06 20:36:23 +0000 Debug: evaluation finished

2014-11-06T20:36:23.454Z - debug: [INST] 2014-11-06 20:36:23 +0000 Debug: Result is not protocol compliant, wrapping

2014-11-06T20:36:23.455Z - debug: [INST] 2014-11-06 20:36:23 +0000 Debug: Running system command #2: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:“com.kabam.SodaDev”}…

2014-11-06T20:36:23.523Z - debug: Socket data received (42 bytes)
2014-11-06T20:36:23.523Z - debug: Socket data being routed.
2014-11-06T20:36:23.524Z - debug: Got result from instruments: {“status”:0,“value”:“com.kabam.SodaDev”}
2014-11-06T20:36:23.524Z - debug: Bundle ID for open app is com.kabam.SodaDev
2014-11-06T20:36:23.524Z - debug: Setting initial orientation to PORTRAIT
2014-11-06T20:36:23.524Z - debug: Pushing command to appium work queue: “au.setScreenOrientation(‘PORTRAIT’)”
2014-11-06T20:36:23.524Z - debug: Sending command to instruments: au.setScreenOrientation(‘PORTRAIT’)
2014-11-06T20:36:23.525Z - debug: Sending command to instruments: au.setScreenOrientation(‘PORTRAIT’)
2014-11-06T20:36:23.533Z - debug: [INST] 2014-11-06 20:36:23 +0000 Debug: Got new command 2 from instruments: au.setScreenOrientation(‘PORTRAIT’)

2014-11-06T20:36:23.534Z - debug: [INST] 2014-11-06 20:36:23 +0000 Debug: evaluating au.setScreenOrientation(‘PORTRAIT’)

2014-11-06T20:36:23.534Z - debug: [INST] 2014-11-06 20:36:23 +0000 Debug: target.setDeviceOrientation(“1”)

2014-11-06T20:36:23.643Z - debug: [INST] 2014-11-06 20:36:23 +0000 Debug: evaluation finished

2014-11-06T20:36:23.644Z - debug: [INST] 2014-11-06 20:36:23 +0000 Debug: Running system command #3: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:“PORTRAIT”}…

2014-11-06T20:36:23.709Z - debug: Socket data received (33 bytes)
2014-11-06T20:36:23.709Z - debug: Socket data being routed.
2014-11-06T20:36:23.709Z - debug: Got result from instruments: {“status”:0,“value”:“PORTRAIT”}
2014-11-06T20:36:23.710Z - debug: Device launched! Ready for commands
2014-11-06T20:36:23.710Z - debug: Setting command timeout to 900 secs
2014-11-06T20:36:23.710Z - debug: Appium session started with sessionId 62d3f427-7034-43c8-961b-fa99f6c367d6
2014-11-06T20:36:23.714Z - info: <-- POST /wd/hub/session 303 8483.260 ms - 9
2014-11-06T20:36:23.726Z - info: --> GET /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6 {}
2014-11-06T20:36:23.727Z - debug: Appium request initiated at /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6
2014-11-06T20:36:23.727Z - debug: Request received with params: {}
2014-11-06T20:36:23.727Z - debug: Responding to client with success: {“status”:0,“value”:{“webStorageEnabled”:false,“locationContextEnabled”:false,“browserName”:"",“platform”:“MAC”,“javascriptEnabled”:true,“databaseEnabled”:false,“takesScreenshot”:true,“warnings”:{},“desired”:{“newCommandTimeout”:900,“platformVersion”:“7.1”,“app”:"/Users/jblaze/jenkins/workspace/sodaIos_2_build_app_run_tests/soda-ios/com/kabam/ios/build/SodaDev.app",“platformName”:“iOS”,“deviceName”:“iPhone Simulator”,“browserName”:"",“locale”:“en_US”,“language”:“en”},“newCommandTimeout”:900,“platformVersion”:“7.1”,“app”:"/Users/jblaze/jenkins/workspace/sodaIos_2_build_app_run_tests/soda-ios/com/kabam/ios/build/SodaDev.app",“platformName”:“iOS”,“deviceName”:“iPhone Simulator”,“locale”:“en_US”,“language”:“en”},“sessionId”:“62d3f427-7034-43c8-961b-fa99f6c367d6”}
2014-11-06T20:36:23.729Z - info: <-- GET /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6 200 3.154 ms - 769 {“status”:0,“value”:{“webStorageEnabled”:false,“locationContextEnabled”:false,“browserName”:"",“platform”:“MAC”,“javascriptEnabled”:true,“databaseEnabled”:false,“takesScreenshot”:true,“warnings”:{},“desired”:{“newCommandTimeout”:900,“platformVersion”:“7.1”,“app”:"/Users/jblaze/jenkins/workspace/sodaIos_2_build_app_run_tests/soda-ios/com/kabam/ios/build/SodaDev.app",“platformName”:“iOS”,“deviceName”:“iPhone Simulator”,“browserName”:"",“locale”:“en_US”,“language”:“en”},“newCommandTimeout”:900,“platformVersion”:“7.1”,“app”:"/Users/jblaze/jenkins/workspace/sodaIos_2_build_app_run_tests/soda-ios/com/kabam/ios/build/SodaDev.app",“platformName”:“iOS”,“deviceName”:“iPhone Simulator”,“locale”:“en_US”,“language”:“en”},“sessionId”:“62d3f427-7034-43c8-961b-fa99f6c367d6”}
2014-11-06T20:36:23.756Z - info: --> POST /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/timeouts/implicit_wait {“ms”:10000}
2014-11-06T20:36:23.756Z - debug: Appium request initiated at /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/timeouts/implicit_wait
2014-11-06T20:36:23.756Z - debug: Request received with params: {“ms”:10000}
2014-11-06T20:36:23.758Z - debug: Set iOS implicit wait to 10000ms
2014-11-06T20:36:23.758Z - debug: Responding to client with success: {“status”:0,“value”:null,“sessionId”:“62d3f427-7034-43c8-961b-fa99f6c367d6”}
2014-11-06T20:36:23.758Z - info: <-- POST /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/timeouts/implicit_wait 200 2.387 ms - 76 {“status”:0,“value”:null,“sessionId”:“62d3f427-7034-43c8-961b-fa99f6c367d6”}
2014-11-06T20:36:23.766Z - info: --> POST /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/element {“using”:“xpath”,“value”:"//UIATextField[@name=‘wskeUrlText’]"}
2014-11-06T20:36:23.766Z - debug: Appium request initiated at /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/element
2014-11-06T20:36:23.766Z - debug: Request received with params: {“using”:“xpath”,“value”:"//UIATextField[@name=‘wskeUrlText’]"}
2014-11-06T20:36:23.767Z - debug: Pushing command to appium work queue: “au.mainApp().getTreeForXML()”
2014-11-06T20:36:23.768Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:36:23.768Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:36:23.775Z - debug: [INST] 2014-11-06 20:36:23 +0000 Debug: Got new command 3 from instruments: au.mainApp().getTreeForXML()

2014-11-06T20:36:23.776Z - debug: [INST] 2014-11-06 20:36:23 +0000 Debug: evaluating au.mainApp().getTreeForXML()

2014-11-06T20:36:23.845Z - debug: [INST] 2014-11-06 20:36:23 +0000 Debug: evaluation finished

2014-11-06T20:36:23.846Z - debug: [INST] 2014-11-06 20:36:23 +0000 Debug: Result is not protocol compliant, wrapping

2014-11-06T20:36:23.848Z - debug: [INST] 2014-11-06 20:36:23 +0000 Debug: Running system command #4: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:{“UIAApplication”:{"@":{“name”:“SodaDev”,“label”:“SodaDev”,“value”:null,“dom”:null,“enabled”:true,“valid”:true,"visi…

2014-11-06T20:36:23.911Z - debug: Socket data received (7976 bytes)
2014-11-06T20:36:23.911Z - debug: Socket data being routed.
2014-11-06T20:36:23.911Z - debug: Got result from instruments: {“status”:0,“value”:{“UIAApplication”:{"@":{“name”:“SodaDev”,“label”:“SodaDev”,“value”:null,“dom”:null,“enabled”:true,“valid”:true,“visible”:true,“hint”:null,“path”:"/0",“x”:0,“y”:20,“width”:320,“height”:548},">":[{“UIAWindow”:{"@":{“name”:null,“label”:null,“value”:null,“dom”:null,“enabled”:true,"va
2014-11-06T20:36:23.930Z - debug: Pushing command to appium work queue: “au.getElementByIndexPath(’/0/0/1/1/0’)”
2014-11-06T20:36:23.930Z - debug: Sending command to instruments: au.getElementByIndexPath(’/0/0/1/1/0’)
2014-11-06T20:36:23.930Z - debug: Sending command to instruments: au.getElementByIndexPath(’/0/0/1/1/0’)
2014-11-06T20:36:23.938Z - debug: [INST] 2014-11-06 20:36:23 +0000 Debug: Got new command 4 from instruments: au.getElementByIndexPath(’/0/0/1/1/0’)

2014-11-06T20:36:23.938Z - debug: [INST] 2014-11-06 20:36:23 +0000 Debug: evaluating au.getElementByIndexPath(’/0/0/1/1/0’)

2014-11-06T20:36:23.948Z - debug: [INST] 2014-11-06 20:36:23 +0000 Debug: Lookup returned [object UIATextField] with the name “wskeUrlText” (id: 0).

2014-11-06T20:36:23.949Z - debug: [INST] 2014-11-06 20:36:23 +0000 Debug: evaluation finished

2014-11-06T20:36:23.949Z - debug: [INST] 2014-11-06 20:36:23 +0000 Debug: Running system command #5: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:{“ELEMENT”:“0”}}…

2014-11-06T20:36:24.011Z - debug: Socket data received (38 bytes)
2014-11-06T20:36:24.011Z - debug: Socket data being routed.
2014-11-06T20:36:24.011Z - debug: Got result from instruments: {“status”:0,“value”:{“ELEMENT”:“0”}}
2014-11-06T20:36:24.011Z - debug: Responding to client with success: {“status”:0,“value”:{“ELEMENT”:“0”},“sessionId”:“62d3f427-7034-43c8-961b-fa99f6c367d6”}
2014-11-06T20:36:24.012Z - info: <-- POST /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/element 200 246.402 ms - 87 {“status”:0,“value”:{“ELEMENT”:“0”},“sessionId”:“62d3f427-7034-43c8-961b-fa99f6c367d6”}
2014-11-06T20:36:24.020Z - info: --> POST /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/element/0/value {“id”:“0”,“value”:[“https://api-beta.wske.kabam.com”]}
2014-11-06T20:36:24.020Z - debug: Appium request initiated at /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/element/0/value
2014-11-06T20:36:24.020Z - debug: Request received with params: {“id”:“0”,“value”:[“https://api-beta.wske.kabam.com”]}
2014-11-06T20:36:24.021Z - debug: Pushing command to appium work queue: “au.getElement(‘0’).setValueByType(‘https:\/\/api-beta.wske.kabam.com’)”
2014-11-06T20:36:24.021Z - debug: Sending command to instruments: au.getElement(‘0’).setValueByType(‘https://api-beta.wske.kabam.com’)
2014-11-06T20:36:24.021Z - debug: Sending command to instruments: au.getElement(‘0’).setValueByType(‘https://api-beta.wske.kabam.com’)
2014-11-06T20:36:24.028Z - debug: [INST] 2014-11-06 20:36:24 +0000 Debug: Got new command 5 from instruments: au.getElement(‘0’).setValueByType(‘https://api-beta.wske.kabam.com’)

2014-11-06T20:36:24.030Z - debug: [INST] 2014-11-06 20:36:24 +0000 Debug: evaluating au.getElement(‘0’).setValueByType(‘https://api-beta.wske.kabam.com’)

2014-11-06T20:36:24.030Z - debug: [INST] 2014-11-06 20:36:24 +0000 Debug: target.frontMostApp().elements()[0].elements()[1].elements()[1].elements()[0].tap()

2014-11-06T20:36:24.631Z - debug: [INST] 2014-11-06 20:36:24 +0000 Debug: target.frontMostApp().keyboard().typeString(“https://api-beta.wske.kabam.com”)

2014-11-06T20:36:28.824Z - debug: [INST] 2014-11-06 20:36:28 +0000 Debug: evaluation finished

2014-11-06T20:36:28.826Z - debug: [INST] 2014-11-06 20:36:28 +0000 Debug: Command executed without response

2014-11-06T20:36:28.827Z - debug: [INST] 2014-11-06 20:36:28 +0000 Debug: Result is not protocol compliant, wrapping

2014-11-06T20:36:28.829Z - debug: [INST] 2014-11-06 20:36:28 +0000 Debug: Running system command #6: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:""}…

2014-11-06T20:36:28.890Z - debug: Socket data received (25 bytes)
2014-11-06T20:36:28.890Z - debug: Socket data being routed.
2014-11-06T20:36:28.890Z - debug: Got result from instruments: {“status”:0,“value”:""}
2014-11-06T20:36:28.890Z - debug: Responding to client with success: {“status”:0,“value”:"",“sessionId”:“62d3f427-7034-43c8-961b-fa99f6c367d6”}
2014-11-06T20:36:28.890Z - info: <-- POST /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/element/0/value 200 4871.056 ms - 74 {“status”:0,“value”:"",“sessionId”:“62d3f427-7034-43c8-961b-fa99f6c367d6”}
2014-11-06T20:36:28.895Z - info: --> POST /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/element {“using”:“xpath”,“value”:"//UIATextField[@name=‘clientIdText’]"}
2014-11-06T20:36:28.895Z - debug: Appium request initiated at /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/element
2014-11-06T20:36:28.895Z - debug: Request received with params: {“using”:“xpath”,“value”:"//UIATextField[@name=‘clientIdText’]"}
2014-11-06T20:36:28.895Z - debug: Pushing command to appium work queue: “au.mainApp().getTreeForXML()”
2014-11-06T20:36:28.895Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:36:28.896Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:36:28.903Z - debug: [INST] 2014-11-06 20:36:28 +0000 Debug: Got new command 6 from instruments: au.mainApp().getTreeForXML()

2014-11-06T20:36:28.905Z - debug: [INST] 2014-11-06 20:36:28 +0000 Debug: evaluating au.mainApp().getTreeForXML()

2014-11-06T20:36:28.994Z - debug: [INST] 2014-11-06 20:36:28 +0000 Debug: evaluation finished

2014-11-06T20:36:28.995Z - debug: [INST] 2014-11-06 20:36:28 +0000 Debug: Result is not protocol compliant, wrapping

2014-11-06T20:36:28.997Z - debug: [INST] 2014-11-06 20:36:28 +0000 Debug: Running system command #7: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:{“UIAApplication”:{"@":{“name”:“SodaDev”,“label”:“SodaDev”,“value”:null,“dom”:null,“enabled”:true,“valid”:true,"visi…

2014-11-06T20:36:29.061Z - debug: Socket data received (8192 bytes)
2014-11-06T20:36:29.062Z - debug: Socket data received (6637 bytes)
2014-11-06T20:36:29.062Z - debug: Socket data being routed.
2014-11-06T20:36:29.062Z - debug: Got result from instruments: {“status”:0,“value”:{“UIAApplication”:{"@":{“name”:“SodaDev”,“label”:“SodaDev”,“value”:null,“dom”:null,“enabled”:true,“valid”:true,“visible”:true,“hint”:null,“path”:"/0",“x”:0,“y”:20,“width”:320,“height”:548},">":[{“UIAWindow”:{"@":{“name”:null,“label”:null,“value”:null,“dom”:null,“enabled”:true,"va
2014-11-06T20:36:29.080Z - debug: Pushing command to appium work queue: “au.getElementByIndexPath(’/0/0/1/3/0’)”
2014-11-06T20:36:29.080Z - debug: Sending command to instruments: au.getElementByIndexPath(’/0/0/1/3/0’)
2014-11-06T20:36:29.080Z - debug: Sending command to instruments: au.getElementByIndexPath(’/0/0/1/3/0’)
2014-11-06T20:36:29.089Z - debug: [INST] 2014-11-06 20:36:29 +0000 Debug: Got new command 7 from instruments: au.getElementByIndexPath(’/0/0/1/3/0’)

2014-11-06T20:36:29.091Z - debug: [INST] 2014-11-06 20:36:29 +0000 Debug: evaluating au.getElementByIndexPath(’/0/0/1/3/0’)

2014-11-06T20:36:29.098Z - debug: [INST] 2014-11-06 20:36:29 +0000 Debug: Lookup returned [object UIATextField] with the name “clientIdText” (id: 1).

2014-11-06T20:36:29.099Z - debug: [INST] 2014-11-06 20:36:29 +0000 Debug: evaluation finished

2014-11-06T20:36:29.100Z - debug: [INST] 2014-11-06 20:36:29 +0000 Debug: Running system command #8: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:{“ELEMENT”:“1”}}…

2014-11-06T20:36:29.163Z - debug: Socket data received (38 bytes)
2014-11-06T20:36:29.163Z - debug: Socket data being routed.
2014-11-06T20:36:29.163Z - debug: Got result from instruments: {“status”:0,“value”:{“ELEMENT”:“1”}}
2014-11-06T20:36:29.163Z - debug: Responding to client with success: {“status”:0,“value”:{“ELEMENT”:“1”},“sessionId”:“62d3f427-7034-43c8-961b-fa99f6c367d6”}
2014-11-06T20:36:29.164Z - info: <-- POST /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/element 200 269.363 ms - 87 {“status”:0,“value”:{“ELEMENT”:“1”},“sessionId”:“62d3f427-7034-43c8-961b-fa99f6c367d6”}
2014-11-06T20:36:29.168Z - info: --> POST /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/element/1/value {“id”:“1”,“value”:[“gam1”]}
2014-11-06T20:36:29.168Z - debug: Appium request initiated at /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/element/1/value
2014-11-06T20:36:29.168Z - debug: Request received with params: {“id”:“1”,“value”:[“gam1”]}
2014-11-06T20:36:29.169Z - debug: Pushing command to appium work queue: “au.getElement(‘1’).setValueByType(‘gam1’)”
2014-11-06T20:36:29.169Z - debug: Sending command to instruments: au.getElement(‘1’).setValueByType(‘gam1’)
2014-11-06T20:36:29.169Z - debug: Sending command to instruments: au.getElement(‘1’).setValueByType(‘gam1’)
2014-11-06T20:36:29.177Z - debug: [INST] 2014-11-06 20:36:29 +0000 Debug: Got new command 8 from instruments: au.getElement(‘1’).setValueByType(‘gam1’)

2014-11-06T20:36:29.179Z - debug: [INST] 2014-11-06 20:36:29 +0000 Debug: evaluating au.getElement(‘1’).setValueByType(‘gam1’)

2014-11-06T20:36:29.180Z - debug: [INST] 2014-11-06 20:36:29 +0000 Debug: target.frontMostApp().elements()[0].elements()[1].elements()[3].elements()[0].tap()

2014-11-06T20:36:29.366Z - debug: [INST] 2014-11-06 20:36:29 +0000 Debug: target.frontMostApp().keyboard().typeString(“gam1”)

2014-11-06T20:36:30.095Z - debug: [INST] 2014-11-06 20:36:30 +0000 Debug: evaluation finished

2014-11-06T20:36:30.096Z - debug: [INST] 2014-11-06 20:36:30 +0000 Debug: Command executed without response

2014-11-06T20:36:30.099Z - debug: [INST] 2014-11-06 20:36:30 +0000 Debug: Result is not protocol compliant, wrapping

2014-11-06T20:36:30.100Z - debug: [INST] 2014-11-06 20:36:30 +0000 Debug: Running system command #9: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:""}…

2014-11-06T20:36:30.161Z - debug: Socket data received (25 bytes)
2014-11-06T20:36:30.161Z - debug: Socket data being routed.
2014-11-06T20:36:30.162Z - debug: Got result from instruments: {“status”:0,“value”:""}
2014-11-06T20:36:30.162Z - debug: Responding to client with success: {“status”:0,“value”:"",“sessionId”:“62d3f427-7034-43c8-961b-fa99f6c367d6”}
2014-11-06T20:36:30.162Z - info: <-- POST /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/element/1/value 200 994.617 ms - 74 {“status”:0,“value”:"",“sessionId”:“62d3f427-7034-43c8-961b-fa99f6c367d6”}
2014-11-06T20:36:30.166Z - info: --> POST /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/element {“using”:“xpath”,“value”:"//UIAApplication/UIAWindow/UIATableView/UIATableCell/UIATextField[@name=‘serverKeyText’]"}
2014-11-06T20:36:30.167Z - debug: Appium request initiated at /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/element
2014-11-06T20:36:30.167Z - debug: Request received with params: {“using”:“xpath”,“value”:"//UIAApplication/UIAWindow/UIATableView/UIATableCell/UIATextField[@name=‘serverKeyText’]"}
2014-11-06T20:36:30.168Z - debug: Pushing command to appium work queue: “au.mainApp().getTreeForXML()”
2014-11-06T20:36:30.168Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:36:30.168Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:36:30.176Z - debug: [INST] 2014-11-06 20:36:30 +0000 Debug: Got new command 9 from instruments: au.mainApp().getTreeForXML()

2014-11-06T20:36:30.178Z - debug: [INST] 2014-11-06 20:36:30 +0000 Debug: evaluating au.mainApp().getTreeForXML()

2014-11-06T20:36:30.268Z - debug: [INST] 2014-11-06 20:36:30 +0000 Debug: evaluation finished

2014-11-06T20:36:30.271Z - debug: [INST] 2014-11-06 20:36:30 +0000 Debug: Result is not protocol compliant, wrapping

2014-11-06T20:36:30.272Z - debug: [INST] 2014-11-06 20:36:30 +0000 Debug: Running system command #10: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:{“UIAApplication”:{"@":{“name”:“SodaDev”,“label”:“SodaDev”,“value”:null,“dom”:null,“enabled”:true,“valid”:true,"visi…

2014-11-06T20:36:30.335Z - debug: Socket data received (8192 bytes)
2014-11-06T20:36:30.335Z - debug: Socket data received (6364 bytes)
2014-11-06T20:36:30.336Z - debug: Socket data being routed.
2014-11-06T20:36:30.336Z - debug: Got result from instruments: {“status”:0,“value”:{“UIAApplication”:{"@":{“name”:“SodaDev”,“label”:“SodaDev”,“value”:null,“dom”:null,“enabled”:true,“valid”:true,“visible”:true,“hint”:null,“path”:"/0",“x”:0,“y”:20,“width”:320,“height”:548},">":[{“UIAWindow”:{"@":{“name”:null,“label”:null,“value”:null,“dom”:null,“enabled”:true,"va
2014-11-06T20:36:30.366Z - debug: Pushing command to appium work queue: “au.getElementByIndexPath(’/0/0/1/5/0’)”
2014-11-06T20:36:30.366Z - debug: Sending command to instruments: au.getElementByIndexPath(’/0/0/1/5/0’)
2014-11-06T20:36:30.366Z - debug: Sending command to instruments: au.getElementByIndexPath(’/0/0/1/5/0’)
2014-11-06T20:36:30.376Z - debug: [INST] 2014-11-06 20:36:30 +0000 Debug: Got new command 10 from instruments: au.getElementByIndexPath(’/0/0/1/5/0’)

2014-11-06T20:36:30.378Z - debug: [INST] 2014-11-06 20:36:30 +0000 Debug: evaluating au.getElementByIndexPath(’/0/0/1/5/0’)

2014-11-06T20:36:30.384Z - debug: [INST] 2014-11-06 20:36:30 +0000 Debug: Lookup returned [object UIATextField] with the name “serverKeyText” (id: 2).

2014-11-06T20:36:30.387Z - debug: [INST] 2014-11-06 20:36:30 +0000 Debug: evaluation finished

2014-11-06T20:36:30.390Z - debug: [INST] 2014-11-06 20:36:30 +0000 Debug: Running system command #11: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:{“ELEMENT”:“2”}}…

2014-11-06T20:36:30.455Z - debug: Socket data received (38 bytes)
2014-11-06T20:36:30.456Z - debug: Socket data being routed.
2014-11-06T20:36:30.456Z - debug: Got result from instruments: {“status”:0,“value”:{“ELEMENT”:“2”}}
2014-11-06T20:36:30.456Z - debug: Responding to client with success: {“status”:0,“value”:{“ELEMENT”:“2”},“sessionId”:“62d3f427-7034-43c8-961b-fa99f6c367d6”}
2014-11-06T20:36:30.456Z - info: <-- POST /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/element 200 290.196 ms - 87 {“status”:0,“value”:{“ELEMENT”:“2”},“sessionId”:“62d3f427-7034-43c8-961b-fa99f6c367d6”}
2014-11-06T20:36:30.460Z - info: --> POST /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/element/2/value {“id”:“2”,“value”:[“b1470ba3c0e695dcb451aa2835ea74e”]}
2014-11-06T20:36:30.460Z - debug: Appium request initiated at /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/element/2/value
2014-11-06T20:36:30.460Z - debug: Request received with params: {“id”:“2”,“value”:[“b1470ba3c0e695dcb451aa2835ea74e”]}
2014-11-06T20:36:30.461Z - debug: Pushing command to appium work queue: “au.getElement(‘2’).setValueByType(‘b1470ba3c0e695dcb451aa2835ea74e’)”
2014-11-06T20:36:30.461Z - debug: Sending command to instruments: au.getElement(‘2’).setValueByType(‘b1470ba3c0e695dcb451aa2835ea74e’)
2014-11-06T20:36:30.461Z - debug: Sending command to instruments: au.getElement(‘2’).setValueByType(‘b1470ba3c0e695dcb451aa2835ea74e’)
2014-11-06T20:36:30.470Z - debug: [INST] 2014-11-06 20:36:30 +0000 Debug: Got new command 11 from instruments: au.getElement(‘2’).setValueByType(‘b1470ba3c0e695dcb451aa2835ea74e’)

2014-11-06T20:36:30.472Z - debug: [INST] 2014-11-06 20:36:30 +0000 Debug: evaluating au.getElement(‘2’).setValueByType(‘b1470ba3c0e695dcb451aa2835ea74e’)

2014-11-06T20:36:30.474Z - debug: [INST] 2014-11-06 20:36:30 +0000 Debug: target.frontMostApp().elements()[0].elements()[1].elements()[5].elements()[0].tap()

2014-11-06T20:36:30.956Z - debug: [INST] 2014-11-06 20:36:30 +0000 Debug: target.frontMostApp().keyboard().typeString(“b1470ba3c0e695dcb451aa2835ea74e”)

2014-11-06T20:36:35.670Z - debug: [INST] 2014-11-06 20:36:35 +0000 Debug: evaluation finished

2014-11-06T20:36:35.672Z - debug: [INST] 2014-11-06 20:36:35 +0000 Debug: Command executed without response

2014-11-06T20:36:35.674Z - debug: [INST] 2014-11-06 20:36:35 +0000 Debug: Result is not protocol compliant, wrapping

2014-11-06T20:36:35.676Z - debug: [INST] 2014-11-06 20:36:35 +0000 Debug: Running system command #12: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:""}…

2014-11-06T20:36:35.732Z - debug: Socket data received (25 bytes)
2014-11-06T20:36:35.732Z - debug: Socket data being routed.
2014-11-06T20:36:35.732Z - debug: Got result from instruments: {“status”:0,“value”:""}
2014-11-06T20:36:35.732Z - debug: Responding to client with success: {“status”:0,“value”:"",“sessionId”:“62d3f427-7034-43c8-961b-fa99f6c367d6”}
2014-11-06T20:36:35.732Z - info: <-- POST /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/element/2/value 200 5272.425 ms - 74 {“status”:0,“value”:"",“sessionId”:“62d3f427-7034-43c8-961b-fa99f6c367d6”}
2014-11-06T20:36:35.736Z - info: --> POST /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/element {“using”:“xpath”,“value”:"//UIANavigationBar/UIAButton[@name=‘Log In’]"}
2014-11-06T20:36:35.736Z - debug: Appium request initiated at /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/element
2014-11-06T20:36:35.736Z - debug: Request received with params: {“using”:“xpath”,“value”:"//UIANavigationBar/UIAButton[@name=‘Log In’]"}
2014-11-06T20:36:35.737Z - debug: Pushing command to appium work queue: “au.mainApp().getTreeForXML()”
2014-11-06T20:36:35.737Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:36:35.737Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:36:35.745Z - debug: [INST] 2014-11-06 20:36:35 +0000 Debug: Got new command 12 from instruments: au.mainApp().getTreeForXML()

2014-11-06T20:36:35.747Z - debug: [INST] 2014-11-06 20:36:35 +0000 Debug: evaluating au.mainApp().getTreeForXML()

2014-11-06T20:36:35.833Z - debug: [INST] 2014-11-06 20:36:35 +0000 Debug: evaluation finished

2014-11-06T20:36:35.835Z - debug: [INST] 2014-11-06 20:36:35 +0000 Debug: Result is not protocol compliant, wrapping

2014-11-06T20:36:35.840Z - debug: [INST] 2014-11-06 20:36:35 +0000 Debug: Running system command #13: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:{“UIAApplication”:{"@":{“name”:“SodaDev”,“label”:“SodaDev”,“value”:null,“dom”:null,“enabled”:true,“valid”:true,"visi…

2014-11-06T20:36:35.899Z - debug: Socket data received (8192 bytes)
2014-11-06T20:36:35.900Z - debug: Socket data received (6534 bytes)
2014-11-06T20:36:35.900Z - debug: Socket data being routed.
2014-11-06T20:36:35.900Z - debug: Got result from instruments: {“status”:0,“value”:{“UIAApplication”:{"@":{“name”:“SodaDev”,“label”:“SodaDev”,“value”:null,“dom”:null,“enabled”:true,“valid”:true,“visible”:true,“hint”:null,“path”:"/0",“x”:0,“y”:20,“width”:320,“height”:548},">":[{“UIAWindow”:{"@":{“name”:null,“label”:null,“value”:null,“dom”:null,“enabled”:true,"va
2014-11-06T20:36:35.908Z - debug: Pushing command to appium work queue: “au.getElementByIndexPath(’/0/0/0/3’)”
2014-11-06T20:36:35.908Z - debug: Sending command to instruments: au.getElementByIndexPath(’/0/0/0/3’)
2014-11-06T20:36:35.908Z - debug: Sending command to instruments: au.getElementByIndexPath(’/0/0/0/3’)
2014-11-06T20:36:35.917Z - debug: [INST] 2014-11-06 20:36:35 +0000 Debug: Got new command 13 from instruments: au.getElementByIndexPath(’/0/0/0/3’)

2014-11-06T20:36:35.919Z - debug: [INST] 2014-11-06 20:36:35 +0000 Debug: evaluating au.getElementByIndexPath(’/0/0/0/3’)

2014-11-06T20:36:35.925Z - debug: [INST] 2014-11-06 20:36:35 +0000 Debug: Lookup returned [object UIAButton] with the name “Log In” (id: 3).

2014-11-06T20:36:35.927Z - debug: [INST] 2014-11-06 20:36:35 +0000 Debug: evaluation finished

2014-11-06T20:36:35.929Z - debug: [INST] 2014-11-06 20:36:35 +0000 Debug: Running system command #14: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:{“ELEMENT”:“3”}}…

2014-11-06T20:36:35.991Z - debug: Socket data received (38 bytes)
2014-11-06T20:36:35.992Z - debug: Socket data being routed.
2014-11-06T20:36:35.992Z - debug: Got result from instruments: {“status”:0,“value”:{“ELEMENT”:“3”}}
2014-11-06T20:36:35.992Z - debug: Responding to client with success: {“status”:0,“value”:{“ELEMENT”:“3”},“sessionId”:“62d3f427-7034-43c8-961b-fa99f6c367d6”}
2014-11-06T20:36:35.992Z - info: <-- POST /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/element 200 256.367 ms - 87 {“status”:0,“value”:{“ELEMENT”:“3”},“sessionId”:“62d3f427-7034-43c8-961b-fa99f6c367d6”}
2014-11-06T20:36:35.996Z - info: --> POST /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/element/3/click {“id”:“3”}
2014-11-06T20:36:35.996Z - debug: Appium request initiated at /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/element/3/click
2014-11-06T20:36:35.997Z - debug: Request received with params: {“id”:“3”}
2014-11-06T20:36:35.997Z - debug: Pushing command to appium work queue: “au.tapById(‘3’)”
2014-11-06T20:36:35.997Z - debug: Sending command to instruments: au.tapById(‘3’)
2014-11-06T20:36:35.997Z - debug: Sending command to instruments: au.tapById(‘3’)
2014-11-06T20:36:36.007Z - debug: [INST] 2014-11-06 20:36:36 +0000 Debug: Got new command 14 from instruments: au.tapById(‘3’)

2014-11-06T20:36:36.011Z - debug: [INST] 2014-11-06 20:36:36 +0000 Debug: evaluating au.tapById(‘3’)

2014-11-06T20:36:36.013Z - debug: [INST] 2014-11-06 20:36:36 +0000 Debug: target.frontMostApp().elements()[0].elements()[0].elements()[3].tap()

2014-11-06T20:36:36.163Z - debug: [INST] 2014-11-06 20:36:36 +0000 Debug: evaluation finished

2014-11-06T20:36:36.167Z - debug: [INST] 2014-11-06 20:36:36 +0000 Debug: Running system command #15: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:null}…

2014-11-06T20:36:36.233Z - debug: Socket data received (27 bytes)
2014-11-06T20:36:36.233Z - debug: Socket data being routed.
2014-11-06T20:36:36.233Z - debug: Got result from instruments: {“status”:0,“value”:null}
2014-11-06T20:36:36.233Z - debug: Responding to client with success: {“status”:0,“value”:null,“sessionId”:“62d3f427-7034-43c8-961b-fa99f6c367d6”}
2014-11-06T20:36:36.233Z - info: <-- POST /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/element/3/click 200 236.980 ms - 76 {“status”:0,“value”:null,“sessionId”:“62d3f427-7034-43c8-961b-fa99f6c367d6”}
2014-11-06T20:36:39.238Z - info: --> POST /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/element {“using”:“xpath”,“value”:"//UIAApplication/UIAWindow/UIATableView/UIATableCell/UIATextField[@name=‘playerIdTextField’]"}
2014-11-06T20:36:39.238Z - debug: Appium request initiated at /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/element
2014-11-06T20:36:39.238Z - debug: Request received with params: {“using”:“xpath”,“value”:"//UIAApplication/UIAWindow/UIATableView/UIATableCell/UIATextField[@name=‘playerIdTextField’]"}
2014-11-06T20:36:39.238Z - debug: Pushing command to appium work queue: “au.mainApp().getTreeForXML()”
2014-11-06T20:36:39.239Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:36:39.239Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:36:39.251Z - debug: [INST] 2014-11-06 20:36:39 +0000 Debug: Got new command 15 from instruments: au.mainApp().getTreeForXML()

2014-11-06T20:36:39.254Z - debug: [INST] 2014-11-06 20:36:39 +0000 Debug: evaluating au.mainApp().getTreeForXML()

2014-11-06T20:36:39.323Z - debug: [INST] 2014-11-06 20:36:39 +0000 Debug: evaluation finished

2014-11-06T20:36:39.325Z - debug: [INST] 2014-11-06 20:36:39 +0000 Debug: Result is not protocol compliant, wrapping

2014-11-06T20:36:39.329Z - debug: [INST] 2014-11-06 20:36:39 +0000 Debug: Running system command #16: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:{“UIAApplication”:{"@":{“name”:“SodaDev”,“label”:“SodaDev”,“value”:null,“dom”:null,“enabled”:true,“valid”:true,"visi…

2014-11-06T20:36:39.389Z - debug: Socket data received (8192 bytes)
2014-11-06T20:36:39.389Z - debug: Socket data received (1431 bytes)
2014-11-06T20:36:39.389Z - debug: Socket data being routed.
2014-11-06T20:36:39.389Z - debug: Got result from instruments: {“status”:0,“value”:{“UIAApplication”:{"@":{“name”:“SodaDev”,“label”:“SodaDev”,“value”:null,“dom”:null,“enabled”:true,“valid”:true,“visible”:true,“hint”:null,“path”:"/0",“x”:0,“y”:20,“width”:320,“height”:548},">":[{“UIAWindow”:{"@":{“name”:null,“label”:null,“value”:null,“dom”:null,“enabled”:true,"va
2014-11-06T20:36:39.395Z - debug: Pushing command to appium work queue: “au.getElementByIndexPath(’/0/0/1/1/0’)”
2014-11-06T20:36:39.396Z - debug: Sending command to instruments: au.getElementByIndexPath(’/0/0/1/1/0’)
2014-11-06T20:36:39.396Z - debug: Sending command to instruments: au.getElementByIndexPath(’/0/0/1/1/0’)
2014-11-06T20:36:39.405Z - debug: [INST] 2014-11-06 20:36:39 +0000 Debug: Got new command 16 from instruments: au.getElementByIndexPath(’/0/0/1/1/0’)

2014-11-06T20:36:39.408Z - debug: [INST] 2014-11-06 20:36:39 +0000 Debug: evaluating au.getElementByIndexPath(’/0/0/1/1/0’)

2014-11-06T20:36:39.414Z - debug: [INST] 2014-11-06 20:36:39 +0000 Debug: Lookup returned [object UIATextField] with the name “playerIdTextField” (id: 4).

2014-11-06T20:36:39.416Z - debug: [INST] 2014-11-06 20:36:39 +0000 Debug: evaluation finished

2014-11-06T20:36:39.419Z - debug: [INST] 2014-11-06 20:36:39 +0000 Debug: Running system command #17: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:{“ELEMENT”:“4”}}…

2014-11-06T20:36:39.478Z - debug: Socket data received (38 bytes)
2014-11-06T20:36:39.478Z - debug: Socket data being routed.
2014-11-06T20:36:39.478Z - debug: Got result from instruments: {“status”:0,“value”:{“ELEMENT”:“4”}}
2014-11-06T20:36:39.478Z - debug: Responding to client with success: {“status”:0,“value”:{“ELEMENT”:“4”},“sessionId”:“62d3f427-7034-43c8-961b-fa99f6c367d6”}
2014-11-06T20:36:39.479Z - info: <-- POST /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/element 200 240.818 ms - 87 {“status”:0,“value”:{“ELEMENT”:“4”},“sessionId”:“62d3f427-7034-43c8-961b-fa99f6c367d6”}
2014-11-06T20:36:39.482Z - info: --> POST /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/element/4/value {“id”:“4”,“value”:[“jblaze”]}
2014-11-06T20:36:39.483Z - debug: Appium request initiated at /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/element/4/value
2014-11-06T20:36:39.483Z - debug: Request received with params: {“id”:“4”,“value”:[“jblaze”]}
2014-11-06T20:36:39.483Z - debug: Pushing command to appium work queue: “au.getElement(‘4’).setValueByType(‘jblaze’)”
2014-11-06T20:36:39.483Z - debug: Sending command to instruments: au.getElement(‘4’).setValueByType(‘jblaze’)
2014-11-06T20:36:39.483Z - debug: Sending command to instruments: au.getElement(‘4’).setValueByType(‘jblaze’)
2014-11-06T20:36:39.493Z - debug: [INST] 2014-11-06 20:36:39 +0000 Debug: Got new command 17 from instruments: au.getElement(‘4’).setValueByType(‘jblaze’)

2014-11-06T20:36:39.496Z - debug: [INST] 2014-11-06 20:36:39 +0000 Debug: evaluating au.getElement(‘4’).setValueByType(‘jblaze’)

2014-11-06T20:36:39.498Z - debug: [INST] 2014-11-06 20:36:39 +0000 Debug: target.frontMostApp().elements()[0].elements()[1].elements()[1].elements()[0].tap()

2014-11-06T20:36:39.746Z - debug: [INST] 2014-11-06 20:36:39 +0000 Debug: target.frontMostApp().keyboard().typeString(“jblaze”)

2014-11-06T20:36:41.014Z - debug: [INST] 2014-11-06 20:36:41 +0000 Debug: evaluation finished

2014-11-06T20:36:41.017Z - debug: [INST] 2014-11-06 20:36:41 +0000 Debug: Command executed without response

2014-11-06T20:36:41.020Z - debug: [INST] 2014-11-06 20:36:41 +0000 Debug: Result is not protocol compliant, wrapping

2014-11-06T20:36:41.023Z - debug: [INST] 2014-11-06 20:36:41 +0000 Debug: Running system command #18: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:""}…

2014-11-06T20:36:41.076Z - debug: Socket data received (25 bytes)
2014-11-06T20:36:41.076Z - debug: Socket data being routed.
2014-11-06T20:36:41.076Z - debug: Got result from instruments: {“status”:0,“value”:""}
2014-11-06T20:36:41.076Z - debug: Responding to client with success: {“status”:0,“value”:"",“sessionId”:“62d3f427-7034-43c8-961b-fa99f6c367d6”}
2014-11-06T20:36:41.077Z - info: <-- POST /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/element/4/value 200 1594.289 ms - 74 {“status”:0,“value”:"",“sessionId”:“62d3f427-7034-43c8-961b-fa99f6c367d6”}
2014-11-06T20:36:41.081Z - info: --> POST /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/element {“using”:“xpath”,“value”:"//UIAButton[@name=‘logInButton’]"}
2014-11-06T20:36:41.081Z - debug: Appium request initiated at /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/element
2014-11-06T20:36:41.081Z - debug: Request received with params: {“using”:“xpath”,“value”:"//UIAButton[@name=‘logInButton’]"}
2014-11-06T20:36:41.081Z - debug: Pushing command to appium work queue: “au.mainApp().getTreeForXML()”
2014-11-06T20:36:41.081Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:36:41.081Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:36:41.090Z - debug: [INST] 2014-11-06 20:36:41 +0000 Debug: Got new command 18 from instruments: au.mainApp().getTreeForXML()

2014-11-06T20:36:41.093Z - debug: [INST] 2014-11-06 20:36:41 +0000 Debug: evaluating au.mainApp().getTreeForXML()

2014-11-06T20:36:41.194Z - debug: [INST] 2014-11-06 20:36:41 +0000 Debug: evaluation finished

2014-11-06T20:36:41.197Z - debug: [INST] 2014-11-06 20:36:41 +0000 Debug: Result is not protocol compliant, wrapping

2014-11-06T20:36:41.200Z - debug: [INST] 2014-11-06 20:36:41 +0000 Debug: Running system command #19: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:{“UIAApplication”:{"@":{“name”:“SodaDev”,“label”:“SodaDev”,“value”:null,“dom”:null,“enabled”:true,“valid”:true,"visi…

2014-11-06T20:36:41.259Z - debug: Socket data received (8192 bytes)
2014-11-06T20:36:41.259Z - debug: Socket data received (8192 bytes)
2014-11-06T20:36:41.259Z - debug: Socket data received (129 bytes)
2014-11-06T20:36:41.260Z - debug: Socket data being routed.
2014-11-06T20:36:41.260Z - debug: Got result from instruments: {“status”:0,“value”:{“UIAApplication”:{"@":{“name”:“SodaDev”,“label”:“SodaDev”,“value”:null,“dom”:null,“enabled”:true,“valid”:true,“visible”:true,“hint”:null,“path”:"/0",“x”:0,“y”:20,“width”:320,“height”:548},">":[{“UIAWindow”:{"@":{“name”:null,“label”:null,“value”:null,“dom”:null,“enabled”:true,"va
2014-11-06T20:36:41.267Z - debug: Pushing command to appium work queue: “au.getElementByIndexPath(’/0/0/1/3/0’)”
2014-11-06T20:36:41.268Z - debug: Sending command to instruments: au.getElementByIndexPath(’/0/0/1/3/0’)
2014-11-06T20:36:41.268Z - debug: Sending command to instruments: au.getElementByIndexPath(’/0/0/1/3/0’)
2014-11-06T20:36:41.279Z - debug: [INST] 2014-11-06 20:36:41 +0000 Debug: Got new command 19 from instruments: au.getElementByIndexPath(’/0/0/1/3/0’)

2014-11-06T20:36:41.285Z - debug: [INST] 2014-11-06 20:36:41 +0000 Debug: evaluating au.getElementByIndexPath(’/0/0/1/3/0’)

2014-11-06T20:36:41.292Z - debug: [INST] 2014-11-06 20:36:41 +0000 Debug: Lookup returned [object UIAButton] with the name “logInButton” (id: 5).

2014-11-06T20:36:41.295Z - debug: [INST] 2014-11-06 20:36:41 +0000 Debug: evaluation finished

2014-11-06T20:36:41.298Z - debug: [INST] 2014-11-06 20:36:41 +0000 Debug: Running system command #20: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:{“ELEMENT”:“5”}}…

2014-11-06T20:36:41.362Z - debug: Socket data received (38 bytes)
2014-11-06T20:36:41.362Z - debug: Socket data being routed.
2014-11-06T20:36:41.362Z - debug: Got result from instruments: {“status”:0,“value”:{“ELEMENT”:“5”}}
2014-11-06T20:36:41.362Z - debug: Responding to client with success: {“status”:0,“value”:{“ELEMENT”:“5”},“sessionId”:“62d3f427-7034-43c8-961b-fa99f6c367d6”}
2014-11-06T20:36:41.362Z - info: <-- POST /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/element 200 281.853 ms - 87 {“status”:0,“value”:{“ELEMENT”:“5”},“sessionId”:“62d3f427-7034-43c8-961b-fa99f6c367d6”}
2014-11-06T20:36:41.367Z - info: --> POST /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/element/5/click {“id”:“5”}
2014-11-06T20:36:41.367Z - debug: Appium request initiated at /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/element/5/click
2014-11-06T20:36:41.367Z - debug: Request received with params: {“id”:“5”}
2014-11-06T20:36:41.367Z - debug: Pushing command to appium work queue: “au.tapById(‘5’)”
2014-11-06T20:36:41.367Z - debug: Sending command to instruments: au.tapById(‘5’)
2014-11-06T20:36:41.368Z - debug: Sending command to instruments: au.tapById(‘5’)
2014-11-06T20:36:41.382Z - debug: [INST] 2014-11-06 20:36:41 +0000 Debug: Got new command 20 from instruments: au.tapById(‘5’)

2014-11-06T20:36:41.385Z - debug: [INST] 2014-11-06 20:36:41 +0000 Debug: evaluating au.tapById(‘5’)

2014-11-06T20:36:41.390Z - debug: [INST] 2014-11-06 20:36:41 +0000 Debug: target.frontMostApp().elements()[0].elements()[1].elements()[3].elements()[0].tap()

2014-11-06T20:36:41.394Z - debug: [INST] 2014-11-06 20:36:41 +0000 Debug: target.frontMostApp().elements()[0].elements()[1].elements()[3].elements()[0].scrollToVisible()

2014-11-06T20:36:41.942Z - debug: [INST] 2014-11-06 20:36:41 +0000 Debug: evaluation finished

2014-11-06T20:36:41.947Z - debug: [INST] 2014-11-06 20:36:41 +0000 Debug: Running system command #21: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:null}…

2014-11-06T20:36:42.004Z - debug: Socket data received (27 bytes)
2014-11-06T20:36:42.004Z - debug: Socket data being routed.
2014-11-06T20:36:42.005Z - debug: Got result from instruments: {“status”:0,“value”:null}
2014-11-06T20:36:42.005Z - debug: Responding to client with success: {“status”:0,“value”:null,“sessionId”:“62d3f427-7034-43c8-961b-fa99f6c367d6”}
2014-11-06T20:36:42.005Z - info: <-- POST /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/element/5/click 200 638.765 ms - 76 {“status”:0,“value”:null,“sessionId”:“62d3f427-7034-43c8-961b-fa99f6c367d6”}
2014-11-06T20:36:42.015Z - info: --> POST /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/timeouts/implicit_wait {“ms”:5000}
2014-11-06T20:36:42.015Z - debug: Appium request initiated at /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/timeouts/implicit_wait
2014-11-06T20:36:42.016Z - debug: Request received with params: {“ms”:5000}
2014-11-06T20:36:42.016Z - debug: Set iOS implicit wait to 5000ms
2014-11-06T20:36:42.018Z - debug: Responding to client with success: {“status”:0,“value”:null,“sessionId”:“62d3f427-7034-43c8-961b-fa99f6c367d6”}
2014-11-06T20:36:42.018Z - info: <-- POST /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/timeouts/implicit_wait 200 3.494 ms - 76 {“status”:0,“value”:null,“sessionId”:“62d3f427-7034-43c8-961b-fa99f6c367d6”}
2014-11-06T20:36:42.023Z - info: --> POST /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/elements {“using”:“xpath”,“value”:"//UIANavigationBar/UIAButton[@name=‘:bomb:’]"}
2014-11-06T20:36:42.023Z - debug: Appium request initiated at /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/elements
2014-11-06T20:36:42.023Z - debug: Request received with params: {“using”:“xpath”,“value”:"//UIANavigationBar/UIAButton[@name=‘:bomb:’]"}
2014-11-06T20:36:42.024Z - debug: Pushing command to appium work queue: “au.mainApp().getTreeForXML()”
2014-11-06T20:36:42.024Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:36:42.024Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:36:42.035Z - debug: [INST] 2014-11-06 20:36:42 +0000 Debug: Got new command 21 from instruments: au.mainApp().getTreeForXML()

2014-11-06T20:36:42.039Z - debug: [INST] 2014-11-06 20:36:42 +0000 Debug: evaluating au.mainApp().getTreeForXML()

2014-11-06T20:36:42.311Z - debug: [INST] 2014-11-06 20:36:42 +0000 Debug: evaluation finished

2014-11-06T20:36:42.316Z - debug: [INST] 2014-11-06 20:36:42 +0000 Debug: Result is not protocol compliant, wrapping

2014-11-06T20:36:42.321Z - debug: [INST] 2014-11-06 20:36:42 +0000 Debug: Running system command #22: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:{“UIAApplication”:{"@":{“name”:“SodaDev”,“label”:“SodaDev”,“value”:null,“dom”:null,“enabled”:true,“valid”:true,"visi…

2014-11-06T20:36:42.380Z - debug: Socket data received (8192 bytes)
2014-11-06T20:36:42.380Z - debug: Socket data received (8093 bytes)
2014-11-06T20:36:42.380Z - debug: Socket data being routed.
2014-11-06T20:36:42.380Z - debug: Got result from instruments: {“status”:0,“value”:{“UIAApplication”:{"@":{“name”:“SodaDev”,“label”:“SodaDev”,“value”:null,“dom”:null,“enabled”:true,“valid”:true,“visible”:true,“hint”:null,“path”:"/0",“x”:0,“y”:20,“width”:320,“height”:548},">":[{“UIAWindow”:{"@":{“name”:null,“label”:null,“value”:null,“dom”:null,“enabled”:true,"va
2014-11-06T20:36:42.887Z - debug: Pushing command to appium work queue: “au.mainApp().getTreeForXML()”
2014-11-06T20:36:42.888Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:36:42.888Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:36:42.901Z - debug: [INST] 2014-11-06 20:36:42 +0000 Debug: Got new command 22 from instruments: au.mainApp().getTreeForXML()

2014-11-06T20:36:42.904Z - debug: [INST] 2014-11-06 20:36:42 +0000 Debug: evaluating au.mainApp().getTreeForXML()

2014-11-06T20:36:42.971Z - debug: [INST] 2014-11-06 20:36:42 +0000 Debug: evaluation finished

2014-11-06T20:36:42.974Z - debug: [INST] 2014-11-06 20:36:42 +0000 Debug: Result is not protocol compliant, wrapping

2014-11-06T20:36:42.977Z - debug: [INST] 2014-11-06 20:36:42 +0000 Debug: Running system command #23: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:{“UIAApplication”:{"@":{“name”:“SodaDev”,“label”:“SodaDev”,“value”:null,“dom”:null,“enabled”:true,“valid”:true,"visi…

2014-11-06T20:36:43.038Z - debug: Socket data received (8188 bytes)
2014-11-06T20:36:43.038Z - debug: Socket data received (1500 bytes)
2014-11-06T20:36:43.038Z - debug: Socket data being routed.
2014-11-06T20:36:43.038Z - debug: Got result from instruments: {“status”:0,“value”:{“UIAApplication”:{"@":{“name”:“SodaDev”,“label”:“SodaDev”,“value”:null,“dom”:null,“enabled”:true,“valid”:true,“visible”:true,“hint”:null,“path”:"/0",“x”:0,“y”:20,“width”:320,“height”:548},">":[{“UIAWindow”:{"@":{“name”:null,“label”:null,“value”:null,“dom”:null,“enabled”:true,“va
2014-11-06T20:36:43.043Z - debug: Pushing command to appium work queue: “au.getElementsByIndexPaths([”/0/0/0/4”])"
2014-11-06T20:36:43.043Z - debug: Sending command to instruments: au.getElementsByIndexPaths(["/0/0/0/4"])
2014-11-06T20:36:43.043Z - debug: Sending command to instruments: au.getElementsByIndexPaths(["/0/0/0/4"])
2014-11-06T20:36:43.054Z - debug: [INST] 2014-11-06 20:36:43 +0000 Debug: Got new command 23 from instruments: au.getElementsByIndexPaths(["/0/0/0/4"])

2014-11-06T20:36:43.058Z - debug: [INST] 2014-11-06 20:36:43 +0000 Debug: evaluating au.getElementsByIndexPaths(["/0/0/0/4"])

2014-11-06T20:36:43.099Z - debug: [INST] 2014-11-06 20:36:43 +0000 logElementTree:
UIAButton “:bomb:” {{290, 28}, {22, 30}}

2014-11-06T20:36:43.103Z - debug: [INST] 2014-11-06 20:36:43 +0000 Debug: Lookup returned [object UIAButton] with the name “:bomb:” (id: 6).

2014-11-06T20:36:43.106Z - debug: [INST] 2014-11-06 20:36:43 +0000 Debug: evaluation finished

2014-11-06T20:36:43.110Z - debug: [INST] 2014-11-06 20:36:43 +0000 Debug: Running system command #24: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:[{“ELEMENT”:“6”}]}…

2014-11-06T20:36:43.143Z - debug: Socket data received (40 bytes)
2014-11-06T20:36:43.143Z - debug: Socket data being routed.
2014-11-06T20:36:43.143Z - debug: Got result from instruments: {“status”:0,“value”:[{“ELEMENT”:“6”}]}
2014-11-06T20:36:43.143Z - debug: Responding to client with success: {“status”:0,“value”:[{“ELEMENT”:“6”}],“sessionId”:“62d3f427-7034-43c8-961b-fa99f6c367d6”}
2014-11-06T20:36:43.144Z - info: <-- POST /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/elements 200 1120.918 ms - 89 {“status”:0,“value”:[{“ELEMENT”:“6”}],“sessionId”:“62d3f427-7034-43c8-961b-fa99f6c367d6”}
2014-11-06T20:36:43.150Z - info: --> POST /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/timeouts/implicit_wait {“ms”:10000}
2014-11-06T20:36:43.150Z - debug: Appium request initiated at /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/timeouts/implicit_wait
2014-11-06T20:36:43.150Z - debug: Request received with params: {“ms”:10000}
2014-11-06T20:36:43.150Z - debug: Set iOS implicit wait to 10000ms
2014-11-06T20:36:43.151Z - debug: Responding to client with success: {“status”:0,“value”:null,“sessionId”:“62d3f427-7034-43c8-961b-fa99f6c367d6”}
2014-11-06T20:36:43.151Z - info: <-- POST /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/timeouts/implicit_wait 200 0.806 ms - 76 {“status”:0,“value”:null,“sessionId”:“62d3f427-7034-43c8-961b-fa99f6c367d6”}
2014-11-06T20:36:43.154Z - info: --> POST /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/timeouts/implicit_wait {“ms”:5000}
2014-11-06T20:36:43.154Z - debug: Appium request initiated at /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/timeouts/implicit_wait
2014-11-06T20:36:43.155Z - debug: Request received with params: {“ms”:5000}
2014-11-06T20:36:43.155Z - debug: Set iOS implicit wait to 5000ms
2014-11-06T20:36:43.155Z - debug: Responding to client with success: {“status”:0,“value”:null,“sessionId”:“62d3f427-7034-43c8-961b-fa99f6c367d6”}
2014-11-06T20:36:43.155Z - info: <-- POST /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/timeouts/implicit_wait 200 0.745 ms - 76 {“status”:0,“value”:null,“sessionId”:“62d3f427-7034-43c8-961b-fa99f6c367d6”}
2014-11-06T20:36:43.158Z - info: --> POST /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/elements {“using”:“xpath”,“value”:"//UIANavigationBar/UIAButton[@name=‘:bomb:’]"}
2014-11-06T20:36:43.158Z - debug: Appium request initiated at /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/elements
2014-11-06T20:36:43.158Z - debug: Request received with params: {“using”:“xpath”,“value”:"//UIANavigationBar/UIAButton[@name=‘:bomb:’]"}
2014-11-06T20:36:43.159Z - debug: Pushing command to appium work queue: “au.mainApp().getTreeForXML()”
2014-11-06T20:36:43.159Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:36:43.159Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:36:43.171Z - debug: [INST] 2014-11-06 20:36:43 +0000 Debug: Got new command 24 from instruments: au.mainApp().getTreeForXML()

2014-11-06T20:36:43.175Z - debug: [INST] 2014-11-06 20:36:43 +0000 Debug: evaluating au.mainApp().getTreeForXML()

2014-11-06T20:36:43.244Z - debug: [INST] 2014-11-06 20:36:43 +0000 Debug: evaluation finished

2014-11-06T20:36:43.248Z - debug: [INST] 2014-11-06 20:36:43 +0000 Debug: Result is not protocol compliant, wrapping

2014-11-06T20:36:43.252Z - debug: [INST] 2014-11-06 20:36:43 +0000 Debug: Running system command #25: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:{“UIAApplication”:{"@":{“name”:“SodaDev”,“label”:“SodaDev”,“value”:null,“dom”:null,“enabled”:true,“valid”:true,"visi…

2014-11-06T20:36:43.299Z - debug: Socket data received (8188 bytes)
2014-11-06T20:36:43.299Z - debug: Socket data received (1500 bytes)
2014-11-06T20:36:43.299Z - debug: Socket data being routed.
2014-11-06T20:36:43.299Z - debug: Got result from instruments: {“status”:0,“value”:{“UIAApplication”:{"@":{“name”:“SodaDev”,“label”:“SodaDev”,“value”:null,“dom”:null,“enabled”:true,“valid”:true,“visible”:true,“hint”:null,“path”:"/0",“x”:0,“y”:20,“width”:320,“height”:548},">":[{“UIAWindow”:{"@":{“name”:null,“label”:null,“value”:null,“dom”:null,“enabled”:true,“va
2014-11-06T20:36:43.306Z - debug: Pushing command to appium work queue: “au.getElementsByIndexPaths([”/0/0/0/4”])"
2014-11-06T20:36:43.306Z - debug: Sending command to instruments: au.getElementsByIndexPaths(["/0/0/0/4"])
2014-11-06T20:36:43.306Z - debug: Sending command to instruments: au.getElementsByIndexPaths(["/0/0/0/4"])
2014-11-06T20:36:43.316Z - debug: [INST] 2014-11-06 20:36:43 +0000 Debug: Got new command 25 from instruments: au.getElementsByIndexPaths(["/0/0/0/4"])

2014-11-06T20:36:43.320Z - debug: [INST] 2014-11-06 20:36:43 +0000 Debug: evaluating au.getElementsByIndexPaths(["/0/0/0/4"])

2014-11-06T20:36:43.343Z - debug: [INST] 2014-11-06 20:36:43 +0000 logElementTree:
UIAButton “:bomb:” {{290, 28}, {22, 30}}

2014-11-06T20:36:43.347Z - debug: [INST] 2014-11-06 20:36:43 +0000 Debug: Lookup returned [object UIAButton] with the name “:bomb:” (id: 7).

2014-11-06T20:36:43.351Z - debug: [INST] 2014-11-06 20:36:43 +0000 Debug: evaluation finished

2014-11-06T20:36:43.354Z - debug: [INST] 2014-11-06 20:36:43 +0000 Debug: Running system command #26: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:[{“ELEMENT”:“7”}]}…

2014-11-06T20:36:43.402Z - debug: Socket data received (40 bytes)
2014-11-06T20:36:43.402Z - debug: Socket data being routed.
2014-11-06T20:36:43.402Z - debug: Got result from instruments: {“status”:0,“value”:[{“ELEMENT”:“7”}]}
2014-11-06T20:36:43.402Z - debug: Responding to client with success: {“status”:0,“value”:[{“ELEMENT”:“7”}],“sessionId”:“62d3f427-7034-43c8-961b-fa99f6c367d6”}
2014-11-06T20:36:43.402Z - info: <-- POST /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/elements 200 244.131 ms - 89 {“status”:0,“value”:[{“ELEMENT”:“7”}],“sessionId”:“62d3f427-7034-43c8-961b-fa99f6c367d6”}
2014-11-06T20:36:43.407Z - info: --> POST /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/timeouts/implicit_wait {“ms”:10000}
2014-11-06T20:36:43.407Z - debug: Appium request initiated at /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/timeouts/implicit_wait
2014-11-06T20:36:43.407Z - debug: Request received with params: {“ms”:10000}
2014-11-06T20:36:43.407Z - debug: Set iOS implicit wait to 10000ms
2014-11-06T20:36:43.407Z - debug: Responding to client with success: {“status”:0,“value”:null,“sessionId”:“62d3f427-7034-43c8-961b-fa99f6c367d6”}
2014-11-06T20:36:43.408Z - info: <-- POST /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/timeouts/implicit_wait 200 1.575 ms - 76 {“status”:0,“value”:null,“sessionId”:“62d3f427-7034-43c8-961b-fa99f6c367d6”}
2014-11-06T20:36:45.413Z - info: --> POST /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/element {“using”:“xpath”,“value”:"//UIANavigationBar/UIAButton[@name=‘:bomb:’]"}
2014-11-06T20:36:45.413Z - debug: Appium request initiated at /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/element
2014-11-06T20:36:45.414Z - debug: Request received with params: {“using”:“xpath”,“value”:"//UIANavigationBar/UIAButton[@name=‘:bomb:’]"}
2014-11-06T20:36:45.414Z - debug: Pushing command to appium work queue: “au.mainApp().getTreeForXML()”
2014-11-06T20:36:45.414Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:36:45.414Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:36:45.425Z - debug: [INST] 2014-11-06 20:36:45 +0000 Debug: Got new command 26 from instruments: au.mainApp().getTreeForXML()

2014-11-06T20:36:45.430Z - debug: [INST] 2014-11-06 20:36:45 +0000 Debug: evaluating au.mainApp().getTreeForXML()

2014-11-06T20:36:45.495Z - debug: [INST] 2014-11-06 20:36:45 +0000 Debug: evaluation finished

2014-11-06T20:36:45.498Z - debug: [INST] 2014-11-06 20:36:45 +0000 Debug: Result is not protocol compliant, wrapping

2014-11-06T20:36:45.503Z - debug: [INST] 2014-11-06 20:36:45 +0000 Debug: Running system command #27: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:{“UIAApplication”:{"@":{“name”:“SodaDev”,“label”:“SodaDev”,“value”:null,“dom”:null,“enabled”:true,“valid”:true,"visi…

2014-11-06T20:36:45.560Z - debug: Socket data received (8188 bytes)
2014-11-06T20:36:45.560Z - debug: Socket data received (1500 bytes)
2014-11-06T20:36:45.560Z - debug: Socket data being routed.
2014-11-06T20:36:45.560Z - debug: Got result from instruments: {“status”:0,“value”:{“UIAApplication”:{"@":{“name”:“SodaDev”,“label”:“SodaDev”,“value”:null,“dom”:null,“enabled”:true,“valid”:true,“visible”:true,“hint”:null,“path”:"/0",“x”:0,“y”:20,“width”:320,“height”:548},">":[{“UIAWindow”:{"@":{“name”:null,“label”:null,“value”:null,“dom”:null,“enabled”:true,"va
2014-11-06T20:36:45.566Z - debug: Pushing command to appium work queue: “au.getElementByIndexPath(’/0/0/0/4’)”
2014-11-06T20:36:45.566Z - debug: Sending command to instruments: au.getElementByIndexPath(’/0/0/0/4’)
2014-11-06T20:36:45.566Z - debug: Sending command to instruments: au.getElementByIndexPath(’/0/0/0/4’)
2014-11-06T20:36:45.576Z - debug: [INST] 2014-11-06 20:36:45 +0000 Debug: Got new command 27 from instruments: au.getElementByIndexPath(’/0/0/0/4’)

2014-11-06T20:36:45.579Z - debug: [INST] 2014-11-06 20:36:45 +0000 Debug: evaluating au.getElementByIndexPath(’/0/0/0/4’)

2014-11-06T20:36:45.583Z - debug: [INST] 2014-11-06 20:36:45 +0000 Debug: Lookup returned [object UIAButton] with the name “:bomb:” (id: 8).

2014-11-06T20:36:45.587Z - debug: [INST] 2014-11-06 20:36:45 +0000 Debug: evaluation finished

2014-11-06T20:36:45.591Z - debug: [INST] 2014-11-06 20:36:45 +0000 Debug: Running system command #28: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:{“ELEMENT”:“8”}}…

2014-11-06T20:36:45.645Z - debug: Socket data received (38 bytes)
2014-11-06T20:36:45.645Z - debug: Socket data being routed.
2014-11-06T20:36:45.645Z - debug: Got result from instruments: {“status”:0,“value”:{“ELEMENT”:“8”}}
2014-11-06T20:36:45.646Z - debug: Responding to client with success: {“status”:0,“value”:{“ELEMENT”:“8”},“sessionId”:“62d3f427-7034-43c8-961b-fa99f6c367d6”}
2014-11-06T20:36:45.647Z - info: <-- POST /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/element 200 233.641 ms - 87 {“status”:0,“value”:{“ELEMENT”:“8”},“sessionId”:“62d3f427-7034-43c8-961b-fa99f6c367d6”}
2014-11-06T20:36:45.651Z - info: --> POST /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/element/8/click {“id”:“8”}
2014-11-06T20:36:45.651Z - debug: Appium request initiated at /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/element/8/click
2014-11-06T20:36:45.651Z - debug: Request received with params: {“id”:“8”}
2014-11-06T20:36:45.651Z - debug: Pushing command to appium work queue: “au.tapById(‘8’)”
2014-11-06T20:36:45.651Z - debug: Sending command to instruments: au.tapById(‘8’)
2014-11-06T20:36:45.651Z - debug: Sending command to instruments: au.tapById(‘8’)
2014-11-06T20:36:45.661Z - debug: [INST] 2014-11-06 20:36:45 +0000 Debug: Got new command 28 from instruments: au.tapById(‘8’)

2014-11-06T20:36:45.665Z - debug: [INST] 2014-11-06 20:36:45 +0000 Debug: evaluating au.tapById(‘8’)

2014-11-06T20:36:45.669Z - debug: [INST] 2014-11-06 20:36:45 +0000 Debug: target.frontMostApp().elements()[0].elements()[0].elements()[4].tap()

2014-11-06T20:36:45.816Z - debug: [INST] 2014-11-06 20:36:45 +0000 Debug: evaluation finished

2014-11-06T20:36:45.820Z - debug: [INST] 2014-11-06 20:36:45 +0000 Debug: Running system command #29: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:null}…

2014-11-06T20:36:45.883Z - debug: Socket data received (27 bytes)
2014-11-06T20:36:45.883Z - debug: Socket data being routed.
2014-11-06T20:36:45.884Z - debug: Got result from instruments: {“status”:0,“value”:null}
2014-11-06T20:36:45.884Z - debug: Responding to client with success: {“status”:0,“value”:null,“sessionId”:“62d3f427-7034-43c8-961b-fa99f6c367d6”}
2014-11-06T20:36:45.884Z - info: <-- POST /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/element/8/click 200 233.642 ms - 76 {“status”:0,“value”:null,“sessionId”:“62d3f427-7034-43c8-961b-fa99f6c367d6”}
2014-11-06T20:36:45.889Z - info: --> POST /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/timeouts/implicit_wait {“ms”:2000}
2014-11-06T20:36:45.889Z - debug: Appium request initiated at /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/timeouts/implicit_wait
2014-11-06T20:36:45.889Z - debug: Request received with params: {“ms”:2000}
2014-11-06T20:36:45.889Z - debug: Set iOS implicit wait to 2000ms
2014-11-06T20:36:45.889Z - debug: Responding to client with success: {“status”:0,“value”:null,“sessionId”:“62d3f427-7034-43c8-961b-fa99f6c367d6”}
2014-11-06T20:36:45.889Z - info: <-- POST /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/timeouts/implicit_wait 200 0.943 ms - 76 {“status”:0,“value”:null,“sessionId”:“62d3f427-7034-43c8-961b-fa99f6c367d6”}
2014-11-06T20:36:45.893Z - info: --> POST /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/elements {“using”:“xpath”,“value”:"//UIAButton[@name=‘fteCallToActionButton’]"}
2014-11-06T20:36:45.894Z - debug: Appium request initiated at /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/elements
2014-11-06T20:36:45.894Z - debug: Request received with params: {“using”:“xpath”,“value”:"//UIAButton[@name=‘fteCallToActionButton’]"}
2014-11-06T20:36:45.894Z - debug: Pushing command to appium work queue: “au.mainApp().getTreeForXML()”
2014-11-06T20:36:45.894Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:36:45.894Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:36:45.906Z - debug: [INST] 2014-11-06 20:36:45 +0000 Debug: Got new command 29 from instruments: au.mainApp().getTreeForXML()

2014-11-06T20:36:45.912Z - debug: [INST] 2014-11-06 20:36:45 +0000 Debug: evaluating au.mainApp().getTreeForXML()

2014-11-06T20:36:46.077Z - debug: [INST] 2014-11-06 20:36:46 +0000 Debug: evaluation finished

2014-11-06T20:36:46.081Z - debug: [INST] 2014-11-06 20:36:46 +0000 Debug: Result is not protocol compliant, wrapping

2014-11-06T20:36:46.089Z - debug: [INST] 2014-11-06 20:36:46 +0000 Debug: Running system command #30: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:{“UIAApplication”:{"@":{“name”:“SodaDev”,“label”:“SodaDev”,“value”:null,“dom”:null,“enabled”:true,“valid”:true,"visi…

2014-11-06T20:36:46.143Z - debug: Socket data received (8188 bytes)
2014-11-06T20:36:46.143Z - debug: Socket data received (6097 bytes)
2014-11-06T20:36:46.143Z - debug: Socket data being routed.
2014-11-06T20:36:46.143Z - debug: Got result from instruments: {“status”:0,“value”:{“UIAApplication”:{"@":{“name”:“SodaDev”,“label”:“SodaDev”,“value”:null,“dom”:null,“enabled”:true,“valid”:true,“visible”:true,“hint”:null,“path”:"/0",“x”:0,“y”:0,“width”:320,“height”:568},">":[{“UIAWindow”:{"@":{“name”:null,“label”:null,“value”:null,“dom”:null,“enabled”:true,"val
2014-11-06T20:36:46.654Z - debug: Pushing command to appium work queue: “au.mainApp().getTreeForXML()”
2014-11-06T20:36:46.654Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:36:46.654Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:36:46.668Z - debug: [INST] 2014-11-06 20:36:46 +0000 Debug: Got new command 30 from instruments: au.mainApp().getTreeForXML()

2014-11-06T20:36:46.673Z - debug: [INST] 2014-11-06 20:36:46 +0000 Debug: evaluating au.mainApp().getTreeForXML()

2014-11-06T20:36:46.721Z - debug: [INST] 2014-11-06 20:36:46 +0000 Debug: evaluation finished

2014-11-06T20:36:46.725Z - debug: [INST] 2014-11-06 20:36:46 +0000 Debug: Result is not protocol compliant, wrapping

2014-11-06T20:36:46.729Z - debug: [INST] 2014-11-06 20:36:46 +0000 Debug: Running system command #31: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:{“UIAApplication”:{"@":{“name”:“SodaDev”,“label”:“SodaDev”,“value”:null,“dom”:null,“enabled”:true,“valid”:true,"visi…

2014-11-06T20:36:46.783Z - debug: Socket data received (6913 bytes)
2014-11-06T20:36:46.783Z - debug: Socket data being routed.
2014-11-06T20:36:46.783Z - debug: Got result from instruments: {“status”:0,“value”:{“UIAApplication”:{"@":{“name”:“SodaDev”,“label”:“SodaDev”,“value”:null,“dom”:null,“enabled”:true,“valid”:true,“visible”:true,“hint”:null,“path”:"/0",“x”:0,“y”:0,“width”:320,“height”:568},">":[{“UIAWindow”:{"@":{“name”:null,“label”:null,“value”:null,“dom”:null,“enabled”:true,"val
2014-11-06T20:36:47.288Z - debug: Pushing command to appium work queue: “au.mainApp().getTreeForXML()”
2014-11-06T20:36:47.289Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:36:47.289Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:36:47.302Z - debug: [INST] 2014-11-06 20:36:47 +0000 Debug: Got new command 31 from instruments: au.mainApp().getTreeForXML()

2014-11-06T20:36:47.308Z - debug: [INST] 2014-11-06 20:36:47 +0000 Debug: evaluating au.mainApp().getTreeForXML()

2014-11-06T20:36:47.416Z - debug: [INST] 2014-11-06 20:36:47 +0000 Debug: evaluation finished

2014-11-06T20:36:47.421Z - debug: [INST] 2014-11-06 20:36:47 +0000 Debug: Result is not protocol compliant, wrapping

2014-11-06T20:36:47.425Z - debug: [INST] 2014-11-06 20:36:47 +0000 Debug: Running system command #32: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:{“UIAApplication”:{"@":{“name”:“SodaDev”,“label”:“SodaDev”,“value”:null,“dom”:null,“enabled”:true,“valid”:true,"visi…

2014-11-06T20:36:47.481Z - debug: Socket data received (8192 bytes)
2014-11-06T20:36:47.481Z - debug: Socket data received (7166 bytes)
2014-11-06T20:36:47.481Z - debug: Socket data being routed.
2014-11-06T20:36:47.481Z - debug: Got result from instruments: {“status”:0,“value”:{“UIAApplication”:{"@":{“name”:“SodaDev”,“label”:“SodaDev”,“value”:null,“dom”:null,“enabled”:true,“valid”:true,“visible”:true,“hint”:null,“path”:"/0",“x”:0,“y”:0,“width”:320,“height”:568},">":[{“UIAWindow”:{"@":{“name”:null,“label”:null,“value”:null,“dom”:null,“enabled”:true,"val
2014-11-06T20:36:47.990Z - debug: Pushing command to appium work queue: “au.mainApp().getTreeForXML()”
2014-11-06T20:36:47.990Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:36:47.991Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:36:48.003Z - debug: [INST] 2014-11-06 20:36:47 +0000 Debug: Got new command 32 from instruments: au.mainApp().getTreeForXML()

2014-11-06T20:36:48.007Z - debug: [INST] 2014-11-06 20:36:47 +0000 Debug: evaluating au.mainApp().getTreeForXML()

2014-11-06T20:36:48.101Z - debug: [INST] 2014-11-06 20:36:48 +0000 Debug: evaluation finished

2014-11-06T20:36:48.105Z - debug: [INST] 2014-11-06 20:36:48 +0000 Debug: Result is not protocol compliant, wrapping

2014-11-06T20:36:48.110Z - debug: [INST] 2014-11-06 20:36:48 +0000 Debug: Running system command #33: /usr/local/Cellar/node/0.10.18/bin/node /usr/local/share/npm/lib/node_modules/appium/node_modules/appium-uiauto/bin/command-proxy-client.js /tmp/instruments_sock 2,{“status”:0,“value”:{“UIAApplication”:{"@":{“name”:“SodaDev”,“label”:“SodaDev”,“value”:null,“dom”:null,“enabled”:true,“valid”:true,"visi…

2014-11-06T20:36:48.165Z - debug: Socket data received (8192 bytes)
2014-11-06T20:36:48.165Z - debug: Socket data received (7166 bytes)
2014-11-06T20:36:48.166Z - debug: Socket data being routed.
2014-11-06T20:36:48.166Z - debug: Got result from instruments: {“status”:0,“value”:{“UIAApplication”:{"@":{“name”:“SodaDev”,“label”:“SodaDev”,“value”:null,“dom”:null,“enabled”:true,“valid”:true,“visible”:true,“hint”:null,“path”:"/0",“x”:0,“y”:0,“width”:320,“height”:568},">":[{“UIAWindow”:{"@":{“name”:null,“label”:null,“value”:null,“dom”:null,“enabled”:true,“val
2014-11-06T20:36:48.173Z - debug: Responding to client with success: {“status”:0,“value”:[],“sessionId”:“62d3f427-7034-43c8-961b-fa99f6c367d6”}
2014-11-06T20:36:48.174Z - info: <-- POST /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/elements 200 2280.530 ms - 74 {“status”:0,“value”:[],“sessionId”:“62d3f427-7034-43c8-961b-fa99f6c367d6”}
2014-11-06T20:36:48.178Z - info: --> POST /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/timeouts/implicit_wait {“ms”:10000}
2014-11-06T20:36:48.178Z - debug: Appium request initiated at /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/timeouts/implicit_wait
2014-11-06T20:36:48.178Z - debug: Request received with params: {“ms”:10000}
2014-11-06T20:36:48.178Z - debug: Set iOS implicit wait to 10000ms
2014-11-06T20:36:48.178Z - debug: Responding to client with success: {“status”:0,“value”:null,“sessionId”:“62d3f427-7034-43c8-961b-fa99f6c367d6”}
2014-11-06T20:36:48.179Z - info: <-- POST /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/timeouts/implicit_wait 200 1.085 ms - 76 {“status”:0,“value”:null,“sessionId”:“62d3f427-7034-43c8-961b-fa99f6c367d6”}
2014-11-06T20:36:49.184Z - info: --> POST /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/timeouts/implicit_wait {“ms”:2000}
2014-11-06T20:36:49.184Z - debug: Appium request initiated at /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/timeouts/implicit_wait
2014-11-06T20:36:49.184Z - debug: Request received with params: {“ms”:2000}
2014-11-06T20:36:49.184Z - debug: Set iOS implicit wait to 2000ms
2014-11-06T20:36:49.184Z - debug: Responding to client with success: {“status”:0,“value”:null,“sessionId”:“62d3f427-7034-43c8-961b-fa99f6c367d6”}
2014-11-06T20:36:49.185Z - info: <-- POST /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/timeouts/implicit_wait 200 1.168 ms - 76 {“status”:0,“value”:null,“sessionId”:“62d3f427-7034-43c8-961b-fa99f6c367d6”}
2014-11-06T20:36:49.188Z - info: --> POST /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/elements {“using”:“xpath”,“value”:"//UIATabBar/UIAButton[1][@name=‘Back to Game’]"}
2014-11-06T20:36:49.189Z - debug: Appium request initiated at /wd/hub/session/62d3f427-7034-43c8-961b-fa99f6c367d6/elements
2014-11-06T20:36:49.189Z - debug: Request received with params: {“using”:“xpath”,“value”:”//UIATabBar/UIAButton[1][@name=‘Back to Game’]"}
2014-11-06T20:36:49.189Z - debug: Pushing command to appium work queue: “au.mainApp().getTreeForXML()”
2014-11-06T20:36:49.189Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:36:49.189Z - debug: Sending command to instruments: au.mainApp().getTreeForXML()
2014-11-06T20:36:49.200Z - debug: [INST] 2014-11-06 20:36:49 +0000 Debug: Got new command 33 from instruments: au.mainApp().getTreeForXML()

2014-11-06T20:36:49.205Z - debug: [INST] 2014-11-06 20:36:49 +0000 Debug: evaluating au.mainApp().getTreeForXML()

2014-11-06T20:36:49.299Z - debug: [INST] 2014-11-06 20:36:49 +0000 Debug: evaluation finished

2014-11-06T20:36:49.303Z - debug: [INST] 2014-11-06 20:36:49 +0000 Debug: Result is not protocol compliant, wrapping

I got similar issues running my tests on saucelabs or jenkins. Locally they work fine, but on saucelabs I got errors like:

=> An unknown server-side error occurred while processing the command.
=> An element could not be located on the page using the given search parameters.

I know things like xpaths are ok, because they work fine locally, and the jenkins task is pointing to the same build version I use on my side.

having the same problem here :expressionless: initially found that i wasn’t launching appium using the native instruments library whereas I was locally… still 8 steps into my scenario jenkins + appium are still not able to find an element that appium can consistently find running locally…

@Jeffrey_Blaze @Neto18 @TuckerSherman
did you guys get anywhere with this? I am having th same issue running my tests on a cloud-based CI tool

Thanks