Details
-
Test
-
Status: Closed
-
Major
-
Resolution: Fixed
-
None
-
None
-
None
Description
Logs for reference:
Test logs:
[MEDIC LOG Thu, 21 Apr 2016 01:52:43 GMT] Spec passed: camera.ui.util Delete test image from device library [MEDIC LOG Thu, 21 Apr 2016 01:52:43 GMT] Suite done: Specs. [MEDIC LOG Thu, 21 Apr 2016 01:52:43 GMT] Result was: finished [MEDIC LOG Thu, 21 Apr 2016 01:52:43 GMT] Starting new spec: camera.ui.util Destroy the session > CALL quit() > DELETE /session/:sessionID [MEDIC LOG Thu, 21 Apr 2016 01:53:43 GMT] Spec failed: camera.ui.util Destroy the session [MEDIC LOG Thu, 21 Apr 2016 01:53:43 GMT] Suite done: Camera tests Android. [MEDIC LOG Thu, 21 Apr 2016 01:53:43 GMT] Result was: finished [MEDIC LOG Thu, 21 Apr 2016 01:53:43 GMT] Starting new spec: contacts.ui.util configuring driver and starting a session > CALL init({"browserName":"","appium-version":"1.5","platformName":"Android","platformVersion":19,"deviceName":"Galaxy_Nexus","app":"C:\\Users\\buildbot\\slaves\\apache\\cordova-android-win\\mobilespec\\platforms\\android\\build\\outputs\\apk\\android-debug.apk","autoAcceptAlerts":true}) > POST /session {"desiredCapabilities":{"browserName":"","appium-version":"1.5","platformName":"Android","platformVersion":19,"deviceName":"Galaxy_Nexus","app":"C:\\Users\\buildbot\\slaves\\apache\\cordova-android-win\\mobilespec\\platforms\\android\\build\\outputs\\apk\\android-debug.apk","autoAcceptAlerts":true}} Ending your web drivage.. > RESPONSE quit() [MEDIC LOG Thu, 21 Apr 2016 01:58:43 GMT] Spec failed: contacts.ui.util configuring driver and starting a session [MEDIC LOG Thu, 21 Apr 2016 01:58:43 GMT] Starting new spec: contacts.ui.spec.1 Pick a contact Driving the web on session: 9a9dd635-643a-43b1-a61c-c42225b79d35 > RESPONSE init({"browserName":"","appium-version":"1.5","platformName":"Android","platformVersion":19,"deviceName":"Galaxy_Nexus","app":"C:\\Users\\buildbot\\slaves\\apache\\cordova-android-win\\mobilespec\\platforms\\android\\build\\outputs\\apk\\android-debug.apk","autoAcceptAlerts":true}) "9a9dd635-643a-43b1-a61c-c42225b79d35",{"platform":"LINUX","webStorageEnabled":false,"takesScreenshot":true,"javascriptEnabled":true,"databaseEnabled":false,"networkConnectionEnabled":true,"locationContextEnabled":false,"warnings":{},"desired":{"browserName":"","appium-version":"1.5","platformName":"Android","platformVersion":19,"deviceName":"Galaxy_Nexus","app":"C:\\Users\\buildbot\\slaves\\apache\\cordova-android-win\\mobilespec\\platforms\\android\\build\\outputs\\apk\\android-debug.apk","autoAcceptAlerts":true,"automationName":"Appium","avd":"Galaxy_Nexus"},"browserName":"","appium-version":"1.5","platformName":"Android","platformVersion":"4.4.4","deviceName":"emulator-5554","app":"C:\\Users\\buildbot\\slaves\\apache\\cordova-android-win\\mobilespec\\platforms\\android\\build\\outputs\\apk\\android-debug.apk","autoAcceptAlerts":true,"automationName":"Appium","avd":"Galaxy_Nexus"} > CALL setImplicitWaitTimeout(10000) > POST /session/:sessionID/timeouts/implicit_wait {"ms":10000} > RESPONSE setImplicitWaitTimeout(10000) > CALL contexts() > GET /session/:sessionID/contexts > CALL context() > POST /session/:sessionID/context {} > CALL currentContext() > GET /session/:sessionID/context > RESPONSE contexts() ["NATIVE_APP"] Couldn't get webview context. Retries remaining: 2 > CALL sleep(5000) > RESPONSE currentContext() "NATIVE_APP" > CALL context("NATIVE_APP") > POST /session/:sessionID/context {"name":"NATIVE_APP"} > RESPONSE sleep(5000) > CALL contexts() > GET /session/:sessionID/contexts > RESPONSE context("NATIVE_APP") > CALL saveScreenshot("C:\\Users\\buildbot\\slaves\\apache\\cordova-android-win\\appium_screenshots\\2016-04-20_19.03.05.png") > GET /session/:sessionID/screenshot > CALL context() > POST /session/:sessionID/context {} [MEDIC LOG Thu, 21 Apr 2016 02:03:43 GMT] Spec failed: contacts.ui.spec.1 Pick a contact [MEDIC LOG Thu, 21 Apr 2016 02:03:43 GMT] Starting new spec: contacts.ui.spec.2 Update an existing contact > CALL context() > POST /session/:sessionID/context {} > CALL currentContext() > GET /session/:sessionID/context > RESPONSE contexts() ["NATIVE_APP"] Couldn't get webview context. Retries remaining: 1 > CALL sleep(5000) > RESPONSE sleep(5000) > CALL contexts() > GET /session/:sessionID/contexts > RESPONSE saveScreenshot("C:\\Users\\buildbot\\slaves\\apache\\cordova-android-win\\appium_screenshots\\2016-04-20_19.03.05.png") "C:\\Users\\buildbot\\slaves\\apache\\cordova-android-win\\appium_screenshots\\2016-04-20_19.03.05.png" > CALL context("NATIVE_APP") > POST /session/:sessionID/context {"name":"NATIVE_APP"} > RESPONSE currentContext() "NATIVE_APP" > CALL context("NATIVE_APP") > POST /session/:sessionID/context {"name":"NATIVE_APP"} > RESPONSE contexts() ["NATIVE_APP"] > RESPONSE context("NATIVE_APP") > CALL quit() > DELETE /session/:sessionID > RESPONSE context("NATIVE_APP") > CALL saveScreenshot("C:\\Users\\buildbot\\slaves\\apache\\cordova-android-win\\appium_screenshots\\2016-04-20_19.03.43.png") > GET /session/:sessionID/screenshot [MEDIC LOG Thu, 21 Apr 2016 02:05:16 GMT] Uncaught exception! Killing server and exiting in 2 seconds...
Appium server logs:
2016-04-21 01:52:29:939 - info: [AndroidBootstrap] [BOOTSTRAP LOG] [debug] Got command of type ACTION 2016-04-21 01:52:29:949 - info: [AndroidBootstrap] [BOOTSTRAP LOG] [debug] Got command action: find 2016-04-21 01:52:29:951 - info: [AndroidBootstrap] [BOOTSTRAP LOG] [debug] Finding //android.widget.TextView[@text="Delete"] using XPATH with the contextId: multiple: false 2016-04-21 01:52:31:856 - info: [AndroidBootstrap] [BOOTSTRAP LOG] [debug] Using: UiSelector[CLASS=android.widget.TextView, INSTANCE=4] 2016-04-21 01:52:32:163 - info: [AndroidBootstrap] [BOOTSTRAP LOG] [debug] Returning result: {"value":{"ELEMENT":"85"},"status":0} 2016-04-21 01:52:32:167 - info: [debug] [AndroidBootstrap] Received command result from bootstrap 2016-04-21 01:52:32:168 - info: [MJSONWP] Responding to client with driver.findElement() result: {"ELEMENT":"85"} 2016-04-21 01:52:32:169 - info: [HTTP] <-- POST /wd/hub/session/9d212f73-bd26-4613-afe4-f2f3a3744caf/element 200 3860 ms - 88 2016-04-21 01:52:32:177 - info: [HTTP] --> POST /wd/hub/session/9d212f73-bd26-4613-afe4-f2f3a3744caf/element/85/click 2016-04-21 01:52:32:178 - info: [MJSONWP] Calling AppiumDriver.click() with args: ["85","9d212f73-bd26-4613-afe4-f2f3a3744caf"] 2016-04-21 01:52:32:178 - info: [debug] [AndroidBootstrap] Sending command to android: {"cmd":"action","action":"element:click","params":{"elementId":"85"}} 2016-04-21 01:52:32:201 - info: [AndroidBootstrap] [BOOTSTRAP LOG] [debug] Got data from client: {"cmd":"action","action":"element:click","params":{"elementId":"85"}} 2016-04-21 01:52:32:201 - info: [AndroidBootstrap] [BOOTSTRAP LOG] [debug] Got command of type ACTION 2016-04-21 01:52:32:205 - info: [AndroidBootstrap] [BOOTSTRAP LOG] [debug] Got command action: click 2016-04-21 01:52:35:675 - info: [AndroidBootstrap] [BOOTSTRAP LOG] [debug] Returning result: {"value":true,"status":0} 2016-04-21 01:52:35:676 - info: [debug] [AndroidBootstrap] Received command result from bootstrap 2016-04-21 01:52:35:676 - info: [MJSONWP] Responding to client with driver.click() result: true 2016-04-21 01:52:35:677 - info: [HTTP] <-- POST /wd/hub/session/9d212f73-bd26-4613-afe4-f2f3a3744caf/element/85/click 200 3500 ms - 76 2016-04-21 01:52:35:682 - info: [HTTP] --> POST /wd/hub/session/9d212f73-bd26-4613-afe4-f2f3a3744caf/element 2016-04-21 01:52:35:683 - info: [MJSONWP] Calling AppiumDriver.findElement() with args: ["xpath","//android.widget.Button[@text=\"OK\"]","9d212f73-bd26-4613-afe4-f2f3a3744caf"] 2016-04-21 01:52:35:683 - info: [debug] [BaseDriver] Waiting up to 10000 ms for condition 2016-04-21 01:52:35:683 - info: [debug] [AndroidBootstrap] Sending command to android: {"cmd":"action","action":"find","params":{"strategy":"xpath","selector":"//android.widget.Button[@text=\"OK\"]","context":"","multiple":false}} 2016-04-21 01:52:35:712 - info: [AndroidBootstrap] [BOOTSTRAP LOG] [debug] Got data from client: {"cmd":"action","action":"find","params":{"strategy":"xpath","selector":"//android.widget.Button[@text=\"OK\"]","context":"","multiple":false}} 2016-04-21 01:52:35:717 - info: [AndroidBootstrap] [BOOTSTRAP LOG] [debug] Got command of type ACTION 2016-04-21 01:52:35:719 - info: [AndroidBootstrap] [BOOTSTRAP LOG] [debug] Got command action: find 2016-04-21 01:52:35:752 - info: [AndroidBootstrap] [BOOTSTRAP LOG] [debug] Finding //android.widget.Button[@text="OK"] using XPATH with the contextId: multiple: false 2016-04-21 01:52:36:207 - info: [AndroidBootstrap] [BOOTSTRAP LOG] [debug] Using: UiSelector[CLASS=android.widget.Button, INSTANCE=0] 2016-04-21 01:52:36:530 - info: [AndroidBootstrap] [BOOTSTRAP LOG] [debug] Returning result: {"value":{"ELEMENT":"86"},"status":0} 2016-04-21 01:52:36:533 - info: [debug] [AndroidBootstrap] Received command result from bootstrap 2016-04-21 01:52:36:534 - info: [MJSONWP] Responding to client with driver.findElement() result: {"ELEMENT":"86"} 2016-04-21 01:52:36:534 - info: [HTTP] <-- POST /wd/hub/session/9d212f73-bd26-4613-afe4-f2f3a3744caf/element 200 852 ms - 88 2016-04-21 01:52:36:541 - info: [HTTP] --> POST /wd/hub/session/9d212f73-bd26-4613-afe4-f2f3a3744caf/element/86/click 2016-04-21 01:52:36:542 - info: [MJSONWP] Calling AppiumDriver.click() with args: ["86","9d212f73-bd26-4613-afe4-f2f3a3744caf"] 2016-04-21 01:52:36:542 - info: [debug] [AndroidBootstrap] Sending command to android: {"cmd":"action","action":"element:click","params":{"elementId":"86"}} 2016-04-21 01:52:36:549 - info: [AndroidBootstrap] [BOOTSTRAP LOG] [debug] Got data from client: {"cmd":"action","action":"element:click","params":{"elementId":"86"}} 2016-04-21 01:52:36:549 - info: [AndroidBootstrap] [BOOTSTRAP LOG] [debug] Got command of type ACTION 2016-04-21 01:52:36:549 - info: [AndroidBootstrap] [BOOTSTRAP LOG] [debug] Got command action: click 2016-04-21 01:52:39:824 - info: [AndroidBootstrap] [BOOTSTRAP LOG] [debug] Returning result: {"value":true,"status":0} 2016-04-21 01:52:39:825 - info: [debug] [AndroidBootstrap] Received command result from bootstrap 2016-04-21 01:52:39:825 - info: [MJSONWP] Responding to client with driver.click() result: true 2016-04-21 01:52:39:826 - info: [HTTP] <-- POST /wd/hub/session/9d212f73-bd26-4613-afe4-f2f3a3744caf/element/86/click 200 3284 ms - 76 2016-04-21 01:52:39:832 - info: [HTTP] --> POST /wd/hub/session/9d212f73-bd26-4613-afe4-f2f3a3744caf/appium/device/keyevent 2016-04-21 01:52:39:832 - info: [MJSONWP] Calling AppiumDriver.keyevent() with args: [4,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,"9d212f73-bd26-4613-afe4-f2f3a3744caf"] 2016-04-21 01:52:39:833 - warn: [AndroidDriver] keyevent will be deprecated use pressKeyCode 2016-04-21 01:52:39:833 - info: [debug] [AndroidBootstrap] Sending command to android: {"cmd":"action","action":"pressKeyCode","params":{"keycode":4,"metastate":null}} 2016-04-21 01:52:39:839 - info: [AndroidBootstrap] [BOOTSTRAP LOG] [debug] Got data from client: {"cmd":"action","action":"pressKeyCode","params":{"keycode":4,"metastate":null}} 2016-04-21 01:52:39:850 - info: [AndroidBootstrap] [BOOTSTRAP LOG] [debug] Got command of type ACTION 2016-04-21 01:52:39:853 - info: [AndroidBootstrap] [BOOTSTRAP LOG] [debug] Got command action: pressKeyCode 2016-04-21 01:52:39:976 - info: [AndroidBootstrap] [BOOTSTRAP LOG] [debug] Returning result: {"value":true,"status":0} 2016-04-21 01:52:39:977 - info: [debug] [AndroidBootstrap] Received command result from bootstrap 2016-04-21 01:52:39:977 - info: [MJSONWP] Responding to client with driver.keyevent() result: true 2016-04-21 01:52:39:978 - info: [HTTP] <-- POST /wd/hub/session/9d212f73-bd26-4613-afe4-f2f3a3744caf/appium/device/keyevent 200 146 ms - 76 2016-04-21 01:52:40:985 - info: [HTTP] --> POST /wd/hub/session/9d212f73-bd26-4613-afe4-f2f3a3744caf/appium/device/keyevent 2016-04-21 01:52:40:985 - info: [MJSONWP] Calling AppiumDriver.keyevent() with args: [4,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,"9d212f73-bd26-4613-afe4-f2f3a3744caf"] 2016-04-21 01:52:40:986 - warn: [AndroidDriver] keyevent will be deprecated use pressKeyCode 2016-04-21 01:52:40:986 - info: [debug] [AndroidBootstrap] Sending command to android: {"cmd":"action","action":"pressKeyCode","params":{"keycode":4,"metastate":null}} 2016-04-21 01:52:40:997 - info: [AndroidBootstrap] [BOOTSTRAP LOG] [debug] Got data from client: {"cmd":"action","action":"pressKeyCode","params":{"keycode":4,"metastate":null}} 2016-04-21 01:52:40:997 - info: [AndroidBootstrap] [BOOTSTRAP LOG] [debug] Got command of type ACTION 2016-04-21 01:52:40:997 - info: [AndroidBootstrap] [BOOTSTRAP LOG] [debug] Got command action: pressKeyCode 2016-04-21 01:52:42:115 - info: [AndroidBootstrap] [BOOTSTRAP LOG] [debug] Returning result: {"value":true,"status":0} 2016-04-21 01:52:42:116 - info: [debug] [AndroidBootstrap] Received command result from bootstrap 2016-04-21 01:52:42:117 - info: [MJSONWP] Responding to client with driver.keyevent() result: true 2016-04-21 01:52:42:118 - info: [HTTP] <-- POST /wd/hub/session/9d212f73-bd26-4613-afe4-f2f3a3744caf/appium/device/keyevent 200 1131 ms - 76 2016-04-21 01:52:43:127 - info: [HTTP] --> POST /wd/hub/session/9d212f73-bd26-4613-afe4-f2f3a3744caf/appium/device/keyevent 2016-04-21 01:52:43:128 - info: [MJSONWP] Calling AppiumDriver.keyevent() with args: [4,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,"9d212f73-bd26-4613-afe4-f2f3a3744caf"] 2016-04-21 01:52:43:128 - warn: [AndroidDriver] keyevent will be deprecated use pressKeyCode 2016-04-21 01:52:43:129 - info: [debug] [AndroidBootstrap] Sending command to android: {"cmd":"action","action":"pressKeyCode","params":{"keycode":4,"metastate":null}} 2016-04-21 01:52:43:137 - info: [AndroidBootstrap] [BOOTSTRAP LOG] [debug] Got data from client: {"cmd":"action","action":"pressKeyCode","params":{"keycode":4,"metastate":null}} 2016-04-21 01:52:43:137 - info: [AndroidBootstrap] [BOOTSTRAP LOG] [debug] Got command of type ACTION 2016-04-21 01:52:43:137 - info: [AndroidBootstrap] [BOOTSTRAP LOG] [debug] Got command action: pressKeyCode 2016-04-21 01:52:43:817 - info: [AndroidBootstrap] [BOOTSTRAP LOG] [debug] Returning result: {"value":true,"status":0} 2016-04-21 01:52:43:817 - info: [debug] [AndroidBootstrap] Received command result from bootstrap 2016-04-21 01:52:43:818 - info: [MJSONWP] Responding to client with driver.keyevent() result: true 2016-04-21 01:52:43:818 - info: [HTTP] <-- POST /wd/hub/session/9d212f73-bd26-4613-afe4-f2f3a3744caf/appium/device/keyevent 200 691 ms - 76 2016-04-21 01:52:43:832 - info: [HTTP] --> DELETE /wd/hub/session/9d212f73-bd26-4613-afe4-f2f3a3744caf 2016-04-21 01:52:43:834 - info: [MJSONWP] Calling AppiumDriver.deleteSession() with args: ["9d212f73-bd26-4613-afe4-f2f3a3744caf"] 2016-04-21 01:52:43:835 - info: [debug] [AndroidDriver] Shutting down Android driver 2016-04-21 01:52:43:835 - info: [debug] [AndroidDriver] Stopping chromedriver for context WEBVIEW_org.apache.mobilespec 2016-04-21 01:52:43:836 - info: [debug] [Chromedriver] Changed state to 'stopping' 2016-04-21 01:52:43:836 - info: [JSONWP Proxy] Proxying [DELETE /] to [DELETE http://127.0.0.1:9515/wd/hub/session/b4f71f15914c88ded8a92a1dc3a6108e] with no body 2016-04-21 01:52:43:839 - info: [JSONWP Proxy] Got response with status 200: "{\"sessionId\":\"b4f71f15914c88ded8a92a1dc3a6108e\",\"status\":0,\"value\":null}" 2016-04-21 01:52:43:844 - info: [debug] [Chromedriver] Changed state to 'stopped' 2016-04-21 01:52:43:844 - info: [debug] [ADB] Getting connected devices... 2016-04-21 01:52:52:467 - info: [debug] [ADB] 1 device(s) connected 2016-04-21 01:52:52:467 - info: [debug] [ADB] Running C:\Android\android-sdk\platform-tools\adb.exe with args: ["-P",5037,"-s","emulator-5554","-s","emulator-5554","shell","am","force-stop","org.apache.mobilespec"] 2016-04-21 01:53:05:247 - info: [debug] [ADB] Pressing the HOME button 2016-04-21 01:53:05:248 - info: [debug] [ADB] Getting connected devices... 2016-04-21 01:53:14:083 - info: [debug] [ADB] 1 device(s) connected 2016-04-21 01:53:14:083 - info: [debug] [ADB] Running C:\Android\android-sdk\platform-tools\adb.exe with args: ["-P",5037,"-s","emulator-5554","-s","emulator-5554","shell","input","keyevent",3] 2016-04-21 01:53:26:808 - info: [debug] [Logcat] Stopping logcat capture 2016-04-21 01:53:27:062 - info: [debug] [AndroidBootstrap] Sending command to android: {"cmd":"shutdown"} 2016-04-21 01:53:27:071 - info: [AndroidBootstrap] [BOOTSTRAP LOG] [debug] Got data from client: {"cmd":"shutdown"} 2016-04-21 01:53:27:071 - info: [AndroidBootstrap] [BOOTSTRAP LOG] [debug] Got command of type SHUTDOWN 2016-04-21 01:53:27:082 - info: [AndroidBootstrap] [BOOTSTRAP LOG] [debug] Returning result: {"value":"OK, shutting down","status":0} 2016-04-21 01:53:27:086 - info: [debug] [AndroidBootstrap] Received command result from bootstrap 2016-04-21 01:53:27:086 - info: [debug] [UiAutomator] Shutting down UiAutomator 2016-04-21 01:53:27:087 - info: [debug] [UiAutomator] Moving to state 'stopping' 2016-04-21 01:53:27:258 - info: [AndroidBootstrap] [BOOTSTRAP LOG] [debug] Closed client connection 2016-04-21 01:53:27:258 - info: [debug] [AndroidBootstrap] [UIAUTO STDOUT] INSTRUMENTATION_STATUS: numtests=1 2016-04-21 01:53:27:258 - info: [debug] [AndroidBootstrap] [UIAUTO STDOUT] INSTRUMENTATION_STATUS: stream=. 2016-04-21 01:53:27:258 - info: [debug] [AndroidBootstrap] [UIAUTO STDOUT] INSTRUMENTATION_STATUS: id=UiAutomatorTestRunner 2016-04-21 01:53:27:258 - info: [debug] [AndroidBootstrap] [UIAUTO STDOUT] INSTRUMENTATION_STATUS: test=testRunServer 2016-04-21 01:53:27:258 - info: [debug] [AndroidBootstrap] [UIAUTO STDOUT] INSTRUMENTATION_STATUS: class=io.appium.android.bootstrap.Bootstrap 2016-04-21 01:53:27:259 - info: [debug] [AndroidBootstrap] [UIAUTO STDOUT] INSTRUMENTATION_STATUS: current=1 2016-04-21 01:53:27:259 - info: [debug] [AndroidBootstrap] [UIAUTO STDOUT] INSTRUMENTATION_STATUS_CODE: 0 2016-04-21 01:53:27:259 - info: [debug] [AndroidBootstrap] [UIAUTO STDOUT] INSTRUMENTATION_STATUS: stream= 2016-04-21 01:53:27:263 - info: [debug] [AndroidBootstrap] [UIAUTO STDOUT] Test results for WatcherResultPrinter=. 2016-04-21 01:53:27:263 - info: [debug] [AndroidBootstrap] [UIAUTO STDOUT] Time: 1060.744 2016-04-21 01:53:27:263 - info: [debug] [AndroidBootstrap] [UIAUTO STDOUT] OK (1 test) 2016-04-21 01:53:27:263 - info: [debug] [AndroidBootstrap] [UIAUTO STDOUT] INSTRUMENTATION_STATUS_CODE: -1 2016-04-21 01:53:27:339 - info: [debug] [UiAutomator] UiAutomator shut down normally 2016-04-21 01:53:27:339 - info: [debug] [UiAutomator] Moving to state 'stopped' 2016-04-21 01:53:27:339 - info: [debug] [ADB] Attempting to kill all uiautomator processes 2016-04-21 01:53:27:340 - info: [debug] [ADB] Getting all processes with uiautomator 2016-04-21 01:53:27:340 - info: [debug] [ADB] Getting connected devices... 2016-04-21 01:53:35:045 - info: [debug] [ADB] 1 device(s) connected 2016-04-21 01:53:35:045 - info: [debug] [ADB] Running C:\Android\android-sdk\platform-tools\adb.exe with args: ["-P",5037,"-s","emulator-5554","-s","emulator-5554","shell","ps","uiautomator"] 2016-04-21 01:53:43:845 - info: [HTTP] --> POST /wd/hub/session 2016-04-21 01:53:43:847 - info: [MJSONWP] Calling AppiumDriver.createSession() with args: [{"browserName":"","appium-version":"1.5","platformName":"Android","platformVersion":19,"deviceName":"Galaxy_Nexus","app":"C:\\Users\\buildbot\\sla... 2016-04-21 01:53:43:959 - info: [ADB] No uiautomator process found to kill, continuing... 2016-04-21 01:53:43:959 - info: [debug] [UiAutomator] Moving to state 'stopped' 2016-04-21 01:53:43:959 - info: [Appium] Removing session 9d212f73-bd26-4613-afe4-f2f3a3744caf from our master session list 2016-04-21 01:53:43:960 - info: [Appium] Creating new AndroidDriver session 2016-04-21 01:53:43:960 - info: [Appium] Capabilities: 2016-04-21 01:53:43:961 - info: [Appium] browserName: '' 2016-04-21 01:53:43:961 - info: [Appium] appium-version: '1.5' 2016-04-21 01:53:43:961 - info: [Appium] platformName: 'Android' 2016-04-21 01:53:43:961 - info: [Appium] platformVersion: 19 2016-04-21 01:53:43:961 - info: [Appium] deviceName: 'Galaxy_Nexus' 2016-04-21 01:53:43:961 - info: [Appium] app: 'C:\\Users\\buildbot\\slaves\\apache\\cordova-android-win\\mobilespec\\platforms\\android\\build\\outputs\\apk\\android-debug.apk' 2016-04-21 01:53:43:961 - info: [Appium] autoAcceptAlerts: true 2016-04-21 01:53:43:962 - info: [Appium] automationName: 'Appium' 2016-04-21 01:53:43:962 - info: [Appium] avd: 'Galaxy_Nexus' 2016-04-21 01:53:43:965 - warn: [BaseDriver] The following capabilities were provided, but are not recognized by appium: appium-version, autoAcceptAlerts. 2016-04-21 01:53:43:966 - info: [BaseDriver] Session created with session id: 9a9dd635-643a-43b1-a61c-c42225b79d35 2016-04-21 01:53:43:967 - info: [debug] [AndroidDriver] Getting Java version 2016-04-21 01:53:45:915 - info: [debug] [MJSONWP] Received response: null 2016-04-21 01:53:45:915 - info: [debug] [MJSONWP] But deleting session, so not returning 2016-04-21 01:53:45:915 - info: [MJSONWP] Responding to client with driver.deleteSession() result: null 2016-04-21 01:53:45:916 - info: [HTTP] <-- DELETE /wd/hub/session/9d212f73-bd26-4613-afe4-f2f3a3744caf 200 62083 ms - 76 2016-04-21 01:54:27:043 - info: [AndroidDriver] Java version is: 1.8.0_77 2016-04-21 01:54:27:044 - info: [ADB] Checking whether adb is present 2016-04-21 01:54:29:864 - info: [ADB] Using adb.exe from C:\Android\android-sdk\platform-tools\adb.exe 2016-04-21 01:54:29:865 - info: [AndroidDriver] Retrieving device list 2016-04-21 01:54:29:865 - info: [debug] [ADB] Trying to find a connected android device 2016-04-21 01:54:29:865 - info: [debug] [ADB] Getting connected devices... 2016-04-21 01:54:39:869 - info: [debug] [ADB] 1 device(s) connected 2016-04-21 01:54:39:870 - info: [AndroidDriver] Using device: emulator-5554 2016-04-21 01:54:39:870 - info: [ADB] Checking whether adb is present 2016-04-21 01:54:41:439 - info: [ADB] Using adb.exe from C:\Android\android-sdk\platform-tools\adb.exe 2016-04-21 01:54:41:439 - info: [debug] [ADB] Setting device id to emulator-5554 2016-04-21 01:54:41:440 - info: [BaseDriver] Using local app 'C:\Users\buildbot\slaves\apache\cordova-android-win\mobilespec\platforms\android\build\outputs\apk\android-debug.apk' 2016-04-21 01:54:41:440 - info: [debug] [AndroidDriver] Checking whether app is actually present 2016-04-21 01:54:41:688 - info: [AndroidDriver] Starting Android session 2016-04-21 01:54:41:689 - info: [debug] [ADB] Trying to find Galaxy_Nexus emulator 2016-04-21 01:54:41:689 - info: [debug] [ADB] Getting connected emulators 2016-04-21 01:54:41:689 - info: [debug] [ADB] Getting connected devices... 2016-04-21 01:54:50:815 - info: [debug] [ADB] 1 device(s) connected 2016-04-21 01:54:50:816 - info: [debug] [ADB] 1 emulator(s) connected 2016-04-21 01:54:50:816 - info: [debug] [ADB] Sending telnet command to device: avd name 2016-04-21 01:54:50:816 - info: [debug] [ADB] Getting running emulator port 2016-04-21 01:54:50:819 - info: [debug] [ADB] Socket connection to device created 2016-04-21 01:54:50:824 - info: [debug] [ADB] Socket connection to device ready 2016-04-21 01:54:50:828 - info: [debug] [ADB] Telnet command got response: Galaxy_Nexus 2016-04-21 01:54:50:829 - info: [debug] [ADB] Found emulator Galaxy_Nexus in port 5554 2016-04-21 01:54:50:829 - info: [debug] [ADB] Setting device id to emulator-5554 2016-04-21 01:54:50:830 - info: [debug] [AndroidDriver] Not launching AVD because it is already running. 2016-04-21 01:54:50:830 - info: [debug] [ADB] Running C:\Android\android-sdk\platform-tools\adb.exe with args: ["-P",5037,"-s","emulator-5554","-s","emulator-5554","wait-for-device"] 2016-04-21 01:55:00:276 - info: [debug] [ADB] Getting connected devices... 2016-04-21 01:55:07:806 - info: [debug] [ADB] 1 device(s) connected 2016-04-21 01:55:07:807 - info: [debug] [ADB] Running C:\Android\android-sdk\platform-tools\adb.exe with args: ["-P",5037,"-s","emulator-5554","-s","emulator-5554","shell","echo","ping"] 2016-04-21 01:55:16:242 - info: [debug] [Logcat] Starting logcat capture 2016-04-21 01:55:23:981 - info: [debug] [AndroidDriver] Pushing settings apk to device... 2016-04-21 01:55:23:981 - info: [debug] [ADB] Running C:\Android\android-sdk\platform-tools\adb.exe with args: ["-P",5037,"-s","emulator-5554","-s","emulator-5554","install","C:\\Users\\buildbot\\slaves\\apache\\cordova-android-win\\cordova-medic\\node_modules\\appium\\node_modules\\io.appium.settings\\bin\\settings_apk-debug.apk"] 2016-04-21 01:55:37:745 - info: [debug] [AndroidDriver] Pushing unlock helper app to device... 2016-04-21 01:55:37:746 - info: [debug] [ADB] Running C:\Android\android-sdk\platform-tools\adb.exe with args: ["-P",5037,"-s","emulator-5554","-s","emulator-5554","install","C:\\Users\\buildbot\\slaves\\apache\\cordova-android-win\\cordova-medic\\node_modules\\appium\\node_modules\\appium-unlock\\bin\\unlock_apk-debug.apk"] 2016-04-21 01:55:50:454 - info: [ADB] Getting device platform version 2016-04-21 01:55:50:455 - info: [debug] [ADB] Getting connected devices... 2016-04-21 01:55:59:727 - info: [debug] [ADB] 1 device(s) connected 2016-04-21 01:55:59:728 - info: [debug] [ADB] Running C:\Android\android-sdk\platform-tools\adb.exe with args: ["-P",5037,"-s","emulator-5554","-s","emulator-5554","shell","getprop","ro.build.version.release"] 2016-04-21 01:56:09:940 - info: [debug] [AndroidDriver] Parsing package and activity from app manifest 2016-04-21 01:56:09:940 - info: [ADB] Checking whether aapt is present 2016-04-21 01:56:12:455 - info: [ADB] Using aapt.exe from C:\Android\android-sdk\build-tools\23.0.2\aapt.exe 2016-04-21 01:56:12:455 - info: [ADB] Extracting package and launch activity from manifest 2016-04-21 01:56:16:980 - info: [debug] [ADB] badging package: org.apache.mobilespec 2016-04-21 01:56:16:980 - info: [debug] [ADB] badging act: org.apache.mobilespec.MainActivity 2016-04-21 01:56:16:980 - info: [debug] [AndroidDriver] Parsed package and activity are: org.apache.mobilespec/org.apache.mobilespec.MainActivity 2016-04-21 01:56:16:981 - info: [debug] [ADB] Uninstalling org.apache.mobilespec 2016-04-21 01:56:16:981 - info: [debug] [ADB] Getting connected devices... 2016-04-21 01:56:24:851 - info: [debug] [ADB] 1 device(s) connected 2016-04-21 01:56:24:851 - info: [debug] [ADB] Running C:\Android\android-sdk\platform-tools\adb.exe with args: ["-P",5037,"-s","emulator-5554","-s","emulator-5554","shell","am","force-stop","org.apache.mobilespec"] 2016-04-21 01:56:34:593 - info: [debug] [ADB] Running C:\Android\android-sdk\platform-tools\adb.exe with args: ["-P",5037,"-s","emulator-5554","-s","emulator-5554","uninstall","org.apache.mobilespec"] 2016-04-21 01:56:47:379 - info: [ADB] App was uninstalled 2016-04-21 01:56:49:390 - info: [AndroidDriver] Remote apk path is /data/local/tmp/0854e43c550c953b8c1cecbac58bb822.apk 2016-04-21 01:56:49:391 - info: [debug] [ADB] Getting connected devices... 2016-04-21 01:56:57:380 - info: [debug] [ADB] 1 device(s) connected 2016-04-21 01:56:57:380 - info: [debug] [ADB] Running C:\Android\android-sdk\platform-tools\adb.exe with args: ["-P",5037,"-s","emulator-5554","-s","emulator-5554","shell","ls","/data/local/tmp/0854e43c550c953b8c1cecbac58bb822.apk"] 2016-04-21 01:57:05:357 - info: [debug] [AndroidDriver] Checking if app is installed 2016-04-21 01:57:05:358 - info: [debug] [ADB] Getting install status for org.apache.mobilespec 2016-04-21 01:57:05:358 - info: [debug] [ADB] Getting connected devices... 2016-04-21 01:57:12:904 - info: [debug] [ADB] 1 device(s) connected 2016-04-21 01:57:12:904 - info: [debug] [ADB] Running C:\Android\android-sdk\platform-tools\adb.exe with args: ["-P",5037,"-s","emulator-5554","-s","emulator-5554","shell","getprop","ro.build.version.sdk"] 2016-04-21 01:57:20:907 - info: [debug] [ADB] Device API level: 19 2016-04-21 01:57:20:907 - info: [debug] [ADB] Getting connected devices... 2016-04-21 01:57:28:343 - info: [debug] [ADB] 1 device(s) connected 2016-04-21 01:57:28:343 - info: [debug] [ADB] Running C:\Android\android-sdk\platform-tools\adb.exe with args: ["-P",5037,"-s","emulator-5554","-s","emulator-5554","shell","pm","list","packages","-3","org.apache.mobilespec"] 2016-04-21 01:57:38:507 - info: [debug] [ADB] App is not installed 2016-04-21 01:57:38:508 - info: [AndroidDriver] Apk is not yet installed 2016-04-21 01:57:38:508 - info: [AndroidDriver] installing apk from remote 2016-04-21 01:57:38:508 - info: [debug] [ADB] Getting connected devices... 2016-04-21 01:57:46:244 - info: [debug] [ADB] 1 device(s) connected 2016-04-21 01:57:46:244 - info: [debug] [ADB] Running C:\Android\android-sdk\platform-tools\adb.exe with args: ["-P",5037,"-s","emulator-5554","-s","emulator-5554","shell","mkdir","-p","/data/local/tmp"] 2016-04-21 01:57:53:760 - info: [AndroidDriver] Clearing out any existing remote apks with the same hash 2016-04-21 01:57:53:761 - info: [debug] [AndroidDriver] Removing any old apks 2016-04-21 01:57:53:761 - info: [debug] [AndroidDriver] Except ["0854e43c550c953b8c1cecbac58bb822"] 2016-04-21 01:57:53:761 - info: [debug] [ADB] Getting connected devices... 2016-04-21 01:58:01:505 - info: [debug] [ADB] 1 device(s) connected 2016-04-21 01:58:01:505 - info: [debug] [ADB] Running C:\Android\android-sdk\platform-tools\adb.exe with args: ["-P",5037,"-s","emulator-5554","-s","emulator-5554","shell","ls","/data/local/tmp/*.apk"] 2016-04-21 01:58:09:480 - info: [debug] [ADB] Uninstalling org.apache.mobilespec 2016-04-21 01:58:09:480 - info: [debug] [ADB] Getting connected devices... 2016-04-21 01:58:17:269 - info: [debug] [ADB] 1 device(s) connected 2016-04-21 01:58:17:269 - info: [debug] [ADB] Running C:\Android\android-sdk\platform-tools\adb.exe with args: ["-P",5037,"-s","emulator-5554","-s","emulator-5554","shell","am","force-stop","org.apache.mobilespec"] 2016-04-21 01:58:27:358 - info: [debug] [ADB] Running C:\Android\android-sdk\platform-tools\adb.exe with args: ["-P",5037,"-s","emulator-5554","-s","emulator-5554","uninstall","org.apache.mobilespec"] 2016-04-21 01:58:37:466 - info: [ADB] App was not uninstalled, maybe it wasn't on device? 2016-04-21 01:58:37:466 - info: [debug] [ADB] Getting connected devices... 2016-04-21 01:58:46:090 - info: [debug] [ADB] 1 device(s) connected 2016-04-21 01:58:46:090 - info: [debug] [ADB] Running C:\Android\android-sdk\platform-tools\adb.exe with args: ["-P",5037,"-s","emulator-5554","-s","emulator-5554","shell","pm","install","-r","/data/local/tmp/0854e43c550c953b8c1cecbac58bb822.apk"] 2016-04-21 01:59:00:846 - info: [debug] [AndroidDriver] Extracting strings from apk C:\Users\buildbot\slaves\apache\cordova-android-win\mobilespec\platforms\android\build\outputs\apk\android-debug.apk null C:\Users\buildbot\AppData\Local\Temp\org.apache.mobilespec 2016-04-21 01:59:00:847 - info: [debug] [ADB] Extracting strings for language: default 2016-04-21 01:59:00:847 - info: [debug] [ADB] Getting connected devices... 2016-04-21 01:59:08:746 - info: [debug] [ADB] 1 device(s) connected 2016-04-21 01:59:08:747 - info: [debug] [ADB] Running C:\Android\android-sdk\platform-tools\adb.exe with args: ["-P",5037,"-s","emulator-5554","-s","emulator-5554","shell","getprop","persist.sys.language"] 2016-04-21 01:59:16:398 - info: [debug] [ADB] Current device property 'persist.sys.language': en 2016-04-21 02:00:19:858 - info: [debug] [ADB] No strings.xml for language 'en', getting default strings.xml 2016-04-21 02:01:23:713 - info: [debug] [ADB] Reading strings from converted strings.json 2016-04-21 02:01:24:566 - info: [debug] [ADB] Running C:\Android\android-sdk\platform-tools\adb.exe with args: ["-P",5037,"-s","emulator-5554","-s","emulator-5554","push","C:\\Users\\buildbot\\AppData\\Local\\Temp\\org.apache.mobilespec\\strings.json","/data/local/tmp"] 2016-04-21 02:01:33:805 - info: [debug] [AndroidBootstrap] Watching for bootstrap disconnect 2016-04-21 02:01:33:806 - info: [debug] [ADB] Forwarding system: 4724 to device: 4724 2016-04-21 02:01:33:806 - info: [debug] [ADB] Running C:\Android\android-sdk\platform-tools\adb.exe with args: ["-P",5037,"-s","emulator-5554","-s","emulator-5554","forward","tcp:4724","tcp:4724"] 2016-04-21 02:01:34:868 - info: [debug] [UiAutomator] Starting UiAutomator 2016-04-21 02:01:34:868 - info: [debug] [UiAutomator] Moving to state 'starting' 2016-04-21 02:01:34:869 - info: [debug] [UiAutomator] Parsing uiautomator jar 2016-04-21 02:01:34:869 - info: [debug] [UiAutomator] Found jar name: 'AppiumBootstrap.jar' 2016-04-21 02:01:34:869 - info: [debug] [ADB] Running C:\Android\android-sdk\platform-tools\adb.exe with args: ["-P",5037,"-s","emulator-5554","-s","emulator-5554","push","C:\\Users\\buildbot\\slaves\\apache\\cordova-android-win\\cordova-medic\\node_modules\\appium\\node_modules\\appium-android-bootstrap\\bootstrap\\bin\\AppiumBootstrap.jar","/data/local/tmp/"] 2016-04-21 02:01:44:673 - info: [debug] [ADB] Attempting to kill all uiautomator processes 2016-04-21 02:01:44:673 - info: [debug] [ADB] Getting all processes with uiautomator 2016-04-21 02:01:44:673 - info: [debug] [ADB] Getting connected devices... 2016-04-21 02:01:52:257 - info: [debug] [ADB] 1 device(s) connected 2016-04-21 02:01:52:257 - info: [debug] [ADB] Running C:\Android\android-sdk\platform-tools\adb.exe with args: ["-P",5037,"-s","emulator-5554","-s","emulator-5554","shell","ps","uiautomator"] 2016-04-21 02:01:59:764 - info: [ADB] No uiautomator process found to kill, continuing... 2016-04-21 02:01:59:764 - info: [debug] [UiAutomator] Starting UIAutomator 2016-04-21 02:01:59:764 - info: [debug] [ADB] Creating ADB subprocess with args: -P, 5037, -s, emulator-5554, -s, emulator-5554, shell, uiautomator, runtest, AppiumBootstrap.jar, -c, io.appium.android.bootstrap.Bootstrap, -e, pkg, org.apache.mobilespec, -e, disableAndroidWatchers, false, -e, acceptSslCerts, false 2016-04-21 02:02:10:266 - info: [debug] [UiAutomator] Moving to state 'online' 2016-04-21 02:02:10:268 - info: [AndroidBootstrap] Android bootstrap socket is now connected 2016-04-21 02:02:10:268 - info: [debug] [ADB] Getting connected devices... 2016-04-21 02:02:11:452 - info: [AndroidBootstrap] [BOOTSTRAP LOG] [debug] Loading json... 2016-04-21 02:02:11:452 - info: [AndroidBootstrap] [BOOTSTRAP LOG] [debug] json loading complete. 2016-04-21 02:02:11:452 - info: [AndroidBootstrap] [BOOTSTRAP LOG] [debug] Registered crash watchers. 2016-04-21 02:02:11:452 - info: [AndroidBootstrap] [BOOTSTRAP LOG] [debug] Client connected 2016-04-21 02:02:17:685 - info: [debug] [ADB] 1 device(s) connected 2016-04-21 02:02:17:686 - info: [debug] [ADB] Running C:\Android\android-sdk\platform-tools\adb.exe with args: ["-P",5037,"-s","emulator-5554","-s","emulator-5554","shell","dumpsys","window"] 2016-04-21 02:02:27:419 - info: [AndroidDriver] Screen already unlocked, doing nothing 2016-04-21 02:02:27:419 - info: [debug] [ADB] Device API level: 19 2016-04-21 02:02:27:420 - info: [debug] [ADB] Getting connected devices... 2016-04-21 02:02:35:356 - info: [debug] [ADB] 1 device(s) connected 2016-04-21 02:02:35:357 - info: [debug] [ADB] Running C:\Android\android-sdk\platform-tools\adb.exe with args: ["-P",5037,"-s","emulator-5554","-s","emulator-5554","shell","am","start","-n","org.apache.mobilespec/org.apache.mobilespec.MainActivity","-S","-a","android.intent.action.MAIN","-c","android.intent.category.LAUNCHER","-f","0x10200000"] 2016-04-21 02:02:49:055 - info: [debug] [ADB] Waiting for pkg: 'org.apache.mobilespec' and activity: 'org.apache.mobilespec.MainActivity' to be focused 2016-04-21 02:02:49:055 - info: [debug] [ADB] Possible activities, to be checked: org.apache.mobilespec.MainActivity, .MainActivity, .org.apache.mobilespec.MainActivity 2016-04-21 02:02:49:056 - info: [debug] [ADB] Getting focused package and activity 2016-04-21 02:02:49:056 - info: [debug] [ADB] Getting connected devices... 2016-04-21 02:02:57:528 - info: [debug] [ADB] 1 device(s) connected 2016-04-21 02:02:57:528 - info: [debug] [ADB] Running C:\Android\android-sdk\platform-tools\adb.exe with args: ["-P",5037,"-s","emulator-5554","-s","emulator-5554","shell","dumpsys","window","windows"] 2016-04-21 02:03:05:248 - info: [debug] [ADB] Found package: 'org.apache.mobilespec' and activity: '.MainActivity' 2016-04-21 02:03:05:249 - info: [Appium] New AndroidDriver session created successfully, session 9a9dd635-643a-43b1-a61c-c42225b79d35 added to master session list 2016-04-21 02:03:05:249 - info: [MJSONWP] Responding to client with driver.createSession() result: {"platform":"LINUX","webStorageEnabled":false,"takesScreenshot":true,"javascriptEnabled":true,"databaseEnabled":false,"networkConnectionEnabled":tr... 2016-04-21 02:03:05:250 - info: [HTTP] <-- POST /wd/hub/session 200 561389 ms - 929 2016-04-21 02:03:05:257 - info: [HTTP] --> POST /wd/hub/session/9a9dd635-643a-43b1-a61c-c42225b79d35/timeouts/implicit_wait 2016-04-21 02:03:05:258 - info: [MJSONWP] Calling AppiumDriver.implicitWait() with args: [10000,"9a9dd635-643a-43b1-a61c-c42225b79d35"] 2016-04-21 02:03:05:259 - info: [debug] [BaseDriver] Set implicit wait to 10000ms 2016-04-21 02:03:05:259 - info: [MJSONWP] Responding to client with driver.implicitWait() result: null 2016-04-21 02:03:05:260 - info: [HTTP] <-- POST /wd/hub/session/9a9dd635-643a-43b1-a61c-c42225b79d35/timeouts/implicit_wait 200 2 ms - 76 2016-04-21 02:03:05:288 - info: [HTTP] --> GET /wd/hub/session/9a9dd635-643a-43b1-a61c-c42225b79d35/contexts 2016-04-21 02:03:05:289 - info: [HTTP] --> POST /wd/hub/session/9a9dd635-643a-43b1-a61c-c42225b79d35/context 2016-04-21 02:03:05:290 - info: [debug] [MJSONWP] Bad parameters: BadParametersError: Parameters were incorrect. We wanted {"required":["name"]} and you sent [] 2016-04-21 02:03:05:291 - info: [HTTP] <-- POST /wd/hub/session/9a9dd635-643a-43b1-a61c-c42225b79d35/context 400 2 ms - 74 2016-04-21 02:03:05:508 - info: [MJSONWP] Calling AppiumDriver.getContexts() with args: ["9a9dd635-643a-43b1-a61c-c42225b79d35"] 2016-04-21 02:03:05:508 - info: [debug] [AndroidDriver] Getting a list of available webviews 2016-04-21 02:03:05:509 - info: [debug] [ADB] Getting connected devices... 2016-04-21 02:03:06:806 - info: [HTTP] --> GET /wd/hub/session/9a9dd635-643a-43b1-a61c-c42225b79d35/context 2016-04-21 02:03:07:063 - info: [MJSONWP] Calling AppiumDriver.getCurrentContext() with args: ["9a9dd635-643a-43b1-a61c-c42225b79d35"] 2016-04-21 02:03:12:973 - info: [debug] [ADB] 1 device(s) connected 2016-04-21 02:03:12:973 - info: [debug] [ADB] Running C:\Android\android-sdk\platform-tools\adb.exe with args: ["-P",5037,"-s","emulator-5554","-s","emulator-5554","shell","cat","/proc/net/unix"] 2016-04-21 02:03:21:515 - info: [debug] [AndroidDriver] Found webviews: [] 2016-04-21 02:03:21:516 - info: [debug] [AndroidDriver] Available contexts: ["NATIVE_APP"] 2016-04-21 02:03:21:516 - info: [MJSONWP] Responding to client with driver.getContexts() result: ["NATIVE_APP"] 2016-04-21 02:03:21:517 - info: [HTTP] <-- GET /wd/hub/session/9a9dd635-643a-43b1-a61c-c42225b79d35/contexts 200 16230 ms - 86 2016-04-21 02:03:21:517 - info: [MJSONWP] Responding to client with driver.getCurrentContext() result: "NATIVE_APP" 2016-04-21 02:03:21:518 - info: [HTTP] <-- GET /wd/hub/session/9a9dd635-643a-43b1-a61c-c42225b79d35/context 200 14712 ms - 84 2016-04-21 02:03:21:536 - info: [HTTP] --> POST /wd/hub/session/9a9dd635-643a-43b1-a61c-c42225b79d35/context 2016-04-21 02:03:21:537 - info: [MJSONWP] Calling AppiumDriver.setContext() with args: ["NATIVE_APP","9a9dd635-643a-43b1-a61c-c42225b79d35"] 2016-04-21 02:03:21:537 - info: [debug] [AndroidDriver] Getting a list of available webviews 2016-04-21 02:03:21:537 - info: [debug] [ADB] Getting connected devices... 2016-04-21 02:03:26:541 - info: [HTTP] --> GET /wd/hub/session/9a9dd635-643a-43b1-a61c-c42225b79d35/contexts 2016-04-21 02:03:26:634 - info: [MJSONWP] Calling AppiumDriver.getContexts() with args: ["9a9dd635-643a-43b1-a61c-c42225b79d35"] 2016-04-21 02:03:29:021 - info: [debug] [ADB] 1 device(s) connected 2016-04-21 02:03:29:021 - info: [debug] [ADB] Running C:\Android\android-sdk\platform-tools\adb.exe with args: ["-P",5037,"-s","emulator-5554","-s","emulator-5554","shell","cat","/proc/net/unix"] 2016-04-21 02:03:37:376 - info: [debug] [AndroidDriver] Found webviews: [] 2016-04-21 02:03:37:376 - info: [debug] [AndroidDriver] Available contexts: ["NATIVE_APP"] 2016-04-21 02:03:37:377 - info: [debug] [AndroidDriver] Getting a list of available webviews 2016-04-21 02:03:37:377 - info: [debug] [ADB] Getting connected devices... 2016-04-21 02:03:38:742 - info: [MJSONWP] Responding to client with driver.setContext() result: null 2016-04-21 02:03:38:743 - info: [HTTP] <-- POST /wd/hub/session/9a9dd635-643a-43b1-a61c-c42225b79d35/context 200 17206 ms - 76 2016-04-21 02:03:38:751 - info: [HTTP] --> GET /wd/hub/session/9a9dd635-643a-43b1-a61c-c42225b79d35/screenshot 2016-04-21 02:03:39:009 - info: [MJSONWP] Calling AppiumDriver.getScreenshot() with args: ["9a9dd635-643a-43b1-a61c-c42225b79d35"] 2016-04-21 02:03:43:878 - info: [HTTP] --> POST /wd/hub/session/9a9dd635-643a-43b1-a61c-c42225b79d35/context 2016-04-21 02:03:43:880 - info: [debug] [MJSONWP] Bad parameters: BadParametersError: Parameters were incorrect. We wanted {"required":["name"]} and you sent [] 2016-04-21 02:03:43:881 - info: [HTTP] <-- POST /wd/hub/session/9a9dd635-643a-43b1-a61c-c42225b79d35/context 400 3 ms - 74 2016-04-21 02:03:43:912 - info: [HTTP] --> POST /wd/hub/session/9a9dd635-643a-43b1-a61c-c42225b79d35/context 2016-04-21 02:03:43:913 - info: [debug] [MJSONWP] Bad parameters: BadParametersError: Parameters were incorrect. We wanted {"required":["name"]} and you sent [] 2016-04-21 02:03:43:914 - info: [HTTP] <-- POST /wd/hub/session/9a9dd635-643a-43b1-a61c-c42225b79d35/context 400 2 ms - 74 2016-04-21 02:03:43:934 - info: [HTTP] --> GET /wd/hub/session/9a9dd635-643a-43b1-a61c-c42225b79d35/context 2016-04-21 02:03:44:094 - info: [MJSONWP] Calling AppiumDriver.getCurrentContext() with args: ["9a9dd635-643a-43b1-a61c-c42225b79d35"] 2016-04-21 02:03:44:895 - info: [debug] [ADB] 1 device(s) connected 2016-04-21 02:03:44:896 - info: [debug] [ADB] Running C:\Android\android-sdk\platform-tools\adb.exe with args: ["-P",5037,"-s","emulator-5554","-s","emulator-5554","shell","cat","/proc/net/unix"] 2016-04-21 02:03:52:820 - info: [debug] [AndroidDriver] Found webviews: [] 2016-04-21 02:03:52:821 - info: [debug] [AndroidDriver] Available contexts: ["NATIVE_APP"] 2016-04-21 02:03:52:822 - info: [debug] [ADB] Getting connected devices... 2016-04-21 02:03:54:336 - info: [MJSONWP] Responding to client with driver.getContexts() result: ["NATIVE_APP"] 2016-04-21 02:03:54:337 - info: [HTTP] <-- GET /wd/hub/session/9a9dd635-643a-43b1-a61c-c42225b79d35/contexts 200 27795 ms - 86 2016-04-21 02:03:59:360 - info: [HTTP] --> GET /wd/hub/session/9a9dd635-643a-43b1-a61c-c42225b79d35/contexts 2016-04-21 02:03:59:611 - info: [MJSONWP] Calling AppiumDriver.getContexts() with args: ["9a9dd635-643a-43b1-a61c-c42225b79d35"] 2016-04-21 02:04:02:437 - info: [debug] [ADB] 1 device(s) connected 2016-04-21 02:04:02:438 - info: [debug] [ADB] Running C:\Android\android-sdk\platform-tools\adb.exe with args: ["-P",5037,"-s","emulator-5554","-s","emulator-5554","shell","/system/bin/rm","/data/local/tmp/screenshot.png;","/system/bin/screencap","-p","/data/local/tmp/screenshot.png"] 2016-04-21 02:04:13:515 - info: [debug] [ADB] Running C:\Android\android-sdk\platform-tools\adb.exe with args: ["-P",5037,"-s","emulator-5554","-s","emulator-5554","pull","/data/local/tmp/screenshot.png","C:\\Users\\buildbot\\AppData\\Local\\Temp\\appium116320-7464-1smu9fj.png"] 2016-04-21 02:04:26:187 - info: [MJSONWP] Responding to client with driver.getScreenshot() result: "iVBORw0KGgoAAAANSUhEUgAAAtAAAAUACAYAAABuzmU9AAAABHNCSVQICAgIfAhkiAAAIABJREFUeJzs3Xt0nXd56Plna0vbutmSfEscxw7O3bmdQAxJSEJIuEwhlDA9PdNCB1Y4hUWBFHrmdJ... 2016-04-21 02:04:26:188 - info: [HTTP] <-- GET /wd/hub/session/9a9dd635-643a-43b1-a61c-c42225b79d35/screenshot 200 47435 ms - 24766 2016-04-21 02:04:26:189 - info: [debug] [AndroidDriver] Getting a list of available webviews 2016-04-21 02:04:26:189 - info: [debug] [ADB] Getting connected devices... 2016-04-21 02:04:27:061 - info: [MJSONWP] Responding to client with driver.getCurrentContext() result: "NATIVE_APP" 2016-04-21 02:04:27:062 - info: [HTTP] <-- GET /wd/hub/session/9a9dd635-643a-43b1-a61c-c42225b79d35/context 200 43125 ms - 84 2016-04-21 02:04:27:067 - info: [HTTP] --> POST /wd/hub/session/9a9dd635-643a-43b1-a61c-c42225b79d35/context 2016-04-21 02:04:27:068 - info: [MJSONWP] Calling AppiumDriver.setContext() with args: ["NATIVE_APP","9a9dd635-643a-43b1-a61c-c42225b79d35"] 2016-04-21 02:04:27:068 - info: [HTTP] --> POST /wd/hub/session/9a9dd635-643a-43b1-a61c-c42225b79d35/context 2016-04-21 02:04:27:069 - info: [MJSONWP] Calling AppiumDriver.setContext() with args: ["NATIVE_APP","9a9dd635-643a-43b1-a61c-c42225b79d35"] 2016-04-21 02:04:33:845 - info: [debug] [ADB] 1 device(s) connected 2016-04-21 02:04:33:846 - info: [debug] [ADB] Running C:\Android\android-sdk\platform-tools\adb.exe with args: ["-P",5037,"-s","emulator-5554","-s","emulator-5554","shell","cat","/proc/net/unix"] 2016-04-21 02:04:42:137 - info: [debug] [AndroidDriver] Found webviews: [] 2016-04-21 02:04:42:137 - info: [debug] [AndroidDriver] Available contexts: ["NATIVE_APP"] 2016-04-21 02:04:42:138 - info: [debug] [AndroidDriver] Getting a list of available webviews 2016-04-21 02:04:42:138 - info: [debug] [ADB] Getting connected devices... 2016-04-21 02:04:43:513 - info: [MJSONWP] Responding to client with driver.getContexts() result: ["NATIVE_APP"] 2016-04-21 02:04:43:513 - info: [HTTP] <-- GET /wd/hub/session/9a9dd635-643a-43b1-a61c-c42225b79d35/contexts 200 44156 ms - 86 2016-04-21 02:04:50:544 - info: [debug] [ADB] 1 device(s) connected 2016-04-21 02:04:50:544 - info: [debug] [ADB] Running C:\Android\android-sdk\platform-tools\adb.exe with args: ["-P",5037,"-s","emulator-5554","-s","emulator-5554","shell","cat","/proc/net/unix"] 2016-04-21 02:04:58:744 - info: [debug] [AndroidDriver] Found webviews: [] 2016-04-21 02:04:58:745 - info: [debug] [AndroidDriver] Available contexts: ["NATIVE_APP"] 2016-04-21 02:04:58:745 - info: [debug] [AndroidDriver] Getting a list of available webviews 2016-04-21 02:04:58:745 - info: [debug] [ADB] Getting connected devices... 2016-04-21 02:05:00:105 - info: [MJSONWP] Responding to client with driver.setContext() result: null 2016-04-21 02:05:00:106 - info: [HTTP] <-- POST /wd/hub/session/9a9dd635-643a-43b1-a61c-c42225b79d35/context 200 33038 ms - 76 2016-04-21 02:05:00:112 - info: [HTTP] --> DELETE /wd/hub/session/9a9dd635-643a-43b1-a61c-c42225b79d35 2016-04-21 02:05:00:113 - info: [MJSONWP] Calling AppiumDriver.deleteSession() with args: ["9a9dd635-643a-43b1-a61c-c42225b79d35"] 2016-04-21 02:05:00:113 - info: [debug] [AndroidDriver] Shutting down Android driver 2016-04-21 02:05:00:114 - info: [debug] [ADB] Getting connected devices... 2016-04-21 02:05:07:356 - info: [debug] [ADB] 1 device(s) connected 2016-04-21 02:05:07:357 - info: [debug] [ADB] Running C:\Android\android-sdk\platform-tools\adb.exe with args: ["-P",5037,"-s","emulator-5554","-s","emulator-5554","shell","cat","/proc/net/unix"] 2016-04-21 02:05:08:715 - info: [debug] [ADB] 1 device(s) connected 2016-04-21 02:05:08:715 - info: [debug] [ADB] Running C:\Android\android-sdk\platform-tools\adb.exe with args: ["-P",5037,"-s","emulator-5554","-s","emulator-5554","shell","am","force-stop","org.apache.mobilespec"] 2016-04-21 02:05:15:824 - info: [debug] [AndroidDriver] Found webviews: [] 2016-04-21 02:05:15:824 - info: [debug] [AndroidDriver] Available contexts: ["NATIVE_APP"] 2016-04-21 02:05:15:824 - info: [MJSONWP] Responding to client with driver.setContext() result: null 2016-04-21 02:05:15:825 - info: [HTTP] <-- POST /wd/hub/session/9a9dd635-643a-43b1-a61c-c42225b79d35/context 200 48757 ms - 76 2016-04-21 02:05:15:830 - info: [HTTP] --> GET /wd/hub/session/9a9dd635-643a-43b1-a61c-c42225b79d35/screenshot 2016-04-21 02:05:16:099 - info: [HTTP] <-- GET /wd/hub/session/9a9dd635-643a-43b1-a61c-c42225b79d35/screenshot 404 268 ms - 131 2016-04-21 02:05:19:294 - info: [debug] [ADB] Pressing the HOME button 2016-04-21 02:05:19:295 - info: [debug] [ADB] Getting connected devices... 2016-04-21 02:05:27:907 - info: [debug] [ADB] 1 device(s) connected 2016-04-21 02:05:27:907 - info: [debug] [ADB] Running C:\Android\android-sdk\platform-tools\adb.exe with args: ["-P",5037,"-s","emulator-5554","-s","emulator-5554","shell","input","keyevent",3] 2016-04-21 02:05:40:170 - info: [debug] [Logcat] Stopping logcat capture 2016-04-21 02:05:40:664 - info: [debug] [AndroidBootstrap] Sending command to android: {"cmd":"shutdown"} 2016-04-21 02:05:40:684 - info: [AndroidBootstrap] [BOOTSTRAP LOG] [debug] Got data from client: {"cmd":"shutdown"} 2016-04-21 02:05:40:706 - info: [AndroidBootstrap] [BOOTSTRAP LOG] [debug] Got command of type SHUTDOWN 2016-04-21 02:05:40:716 - info: [AndroidBootstrap] [BOOTSTRAP LOG] [debug] Returning result: {"value":"OK, shutting down","status":0} 2016-04-21 02:05:40:718 - info: [debug] [AndroidBootstrap] Received command result from bootstrap 2016-04-21 02:05:40:719 - info: [debug] [UiAutomator] Shutting down UiAutomator 2016-04-21 02:05:40:719 - info: [debug] [UiAutomator] Moving to state 'stopping' 2016-04-21 02:05:41:087 - info: [AndroidBootstrap] [BOOTSTRAP LOG] [debug] Closed client connection 2016-04-21 02:05:41:087 - info: [debug] [AndroidBootstrap] [UIAUTO STDOUT] INSTRUMENTATION_STATUS: numtests=1 2016-04-21 02:05:41:088 - info: [debug] [AndroidBootstrap] [UIAUTO STDOUT] INSTRUMENTATION_STATUS: stream=. 2016-04-21 02:05:41:088 - info: [debug] [AndroidBootstrap] [UIAUTO STDOUT] INSTRUMENTATION_STATUS: id=UiAutomatorTestRunner 2016-04-21 02:05:41:088 - info: [debug] [AndroidBootstrap] [UIAUTO STDOUT] INSTRUMENTATION_STATUS: test=testRunServer 2016-04-21 02:05:41:088 - info: [debug] [AndroidBootstrap] [UIAUTO STDOUT] INSTRUMENTATION_STATUS: class=io.appium.android.bootstrap.Bootstrap 2016-04-21 02:05:41:088 - info: [debug] [AndroidBootstrap] [UIAUTO STDOUT] INSTRUMENTATION_STATUS: current=1 2016-04-21 02:05:41:088 - info: [debug] [AndroidBootstrap] [UIAUTO STDOUT] INSTRUMENTATION_STATUS_CODE: 0 2016-04-21 02:05:41:088 - info: [debug] [AndroidBootstrap] [UIAUTO STDOUT] INSTRUMENTATION_STATUS: stream= 2016-04-21 02:05:41:089 - info: [debug] [AndroidBootstrap] [UIAUTO STDOUT] Test results for WatcherResultPrinter=. 2016-04-21 02:05:41:089 - info: [debug] [AndroidBootstrap] [UIAUTO STDOUT] Time: 210.905 2016-04-21 02:05:41:089 - info: [debug] [AndroidBootstrap] [UIAUTO STDOUT] OK (1 test) 2016-04-21 02:05:41:089 - info: [debug] [AndroidBootstrap] [UIAUTO STDOUT] INSTRUMENTATION_STATUS_CODE: -1 2016-04-21 02:05:41:167 - info: [debug] [UiAutomator] UiAutomator shut down normally 2016-04-21 02:05:41:167 - info: [debug] [UiAutomator] Moving to state 'stopped' 2016-04-21 02:05:41:167 - info: [debug] [ADB] Attempting to kill all uiautomator processes 2016-04-21 02:05:41:168 - info: [debug] [ADB] Getting all processes with uiautomator 2016-04-21 02:05:41:168 - info: [debug] [ADB] Getting connected devices... 2016-04-21 02:05:50:266 - info: [debug] [ADB] 1 device(s) connected 2016-04-21 02:05:50:266 - info: [debug] [ADB] Running C:\Android\android-sdk\platform-tools\adb.exe with args: ["-P",5037,"-s","emulator-5554","-s","emulator-5554","shell","ps","uiautomator"] 2016-04-21 02:05:58:461 - info: [ADB] No uiautomator process found to kill, continuing... 2016-04-21 02:05:58:461 - info: [debug] [UiAutomator] Moving to state 'stopped' 2016-04-21 02:05:58:461 - info: [Appium] Removing session 9a9dd635-643a-43b1-a61c-c42225b79d35 from our master session list 2016-04-21 02:05:58:462 - info: [debug] [MJSONWP] Received response: null 2016-04-21 02:05:58:462 - info: [debug] [MJSONWP] But deleting session, so not returning 2016-04-21 02:05:58:462 - info: [MJSONWP] Responding to client with driver.deleteSession() result: null 2016-04-21 02:05:58:463 - info: [HTTP] <-- DELETE /wd/hub/session/9a9dd635-643a-43b1-a61c-c42225b79d35 200 58350 ms - 76 2016-04-21 02:05:58:480 - info: [HTTP] --> POST /wd/hub/session 2016-04-21 02:05:58:481 - info: [MJSONWP] Calling AppiumDriver.createSession() with args: [{"browserName":"","appium-version":"1.5","platformName":"Android","platformVersion":19,"deviceName":"Galaxy_Nexus","app":"C:\\Users\\buildbot\\sla... 2016-04-21 02:05:58:481 - info: [Appium] Creating new AndroidDriver session 2016-04-21 02:05:58:482 - info: [Appium] Capabilities: 2016-04-21 02:05:58:482 - info: [Appium] browserName: '' 2016-04-21 02:05:58:482 - info: [Appium] appium-version: '1.5' 2016-04-21 02:05:58:482 - info: [Appium] platformName: 'Android' 2016-04-21 02:05:58:482 - info: [Appium] platformVersion: 19 2016-04-21 02:05:58:482 - info: [Appium] deviceName: 'Galaxy_Nexus' 2016-04-21 02:05:58:483 - info: [Appium] app: 'C:\\Users\\buildbot\\slaves\\apache\\cordova-android-win\\mobilespec\\platforms\\android\\build\\outputs\\apk\\android-debug.apk' 2016-04-21 02:05:58:483 - info: [Appium] autoAcceptAlerts: true 2016-04-21 02:05:58:483 - info: [Appium] automationName: 'Appium' 2016-04-21 02:05:58:483 - info: [Appium] avd: 'Galaxy_Nexus' 2016-04-21 02:05:58:486 - warn: [BaseDriver] The following capabilities were provided, but are not recognized by appium: appium-version, autoAcceptAlerts. 2016-04-21 02:05:58:486 - info: [BaseDriver] Session created with session id: 9861e32d-e4b4-4beb-94dd-41b45e0b75e7 2016-04-21 02:05:58:487 - info: [debug] [AndroidDriver] Getting Java version 2016-04-21 02:06:15:827 - warn: [BaseDriver] Shutting down because we waited 60 seconds for a command 2016-04-21 02:06:15:828 - info: [debug] [AndroidDriver] Shutting down Android driver 2016-04-21 02:06:15:829 - warn: [Appium] Closing session, cause was 'New Command Timeout of 60 seconds expired. Try customizing the timeout using the 'newCommandTimeout' desired capability' 2016-04-21 02:06:15:829 - info: [Appium] Removing session 9a9dd635-643a-43b1-a61c-c42225b79d35 from our master session list 2016-04-21 02:06:15:829 - warn: [AndroidDriver] Cannot shut down Android driver; it has already shut down 2016-04-21 02:06:43:954 - info: [AndroidDriver] Java version is: 1.8.0_77 2016-04-21 02:06:43:954 - info: [ADB] Checking whether adb is present 2016-04-21 02:06:45:640 - info: [ADB] Using adb.exe from C:\Android\android-sdk\platform-tools\adb.exe 2016-04-21 02:06:45:640 - info: [AndroidDriver] Retrieving device list 2016-04-21 02:06:45:640 - info: [debug] [ADB] Trying to find a connected android device 2016-04-21 02:06:45:641 - info: [debug] [ADB] Getting connected devices... 2016-04-21 02:06:53:686 - info: [debug] [ADB] 1 device(s) connected 2016-04-21 02:06:53:686 - info: [AndroidDriver] Using device: emulator-5554 2016-04-21 02:06:53:686 - info: [ADB] Checking whether adb is present 2016-04-21 02:06:55:291 - info: [ADB] Using adb.exe from C:\Android\android-sdk\platform-tools\adb.exe 2016-04-21 02:06:55:291 - info: [debug] [ADB] Setting device id to emulator-5554 2016-04-21 02:06:55:291 - info: [BaseDriver] Using local app 'C:\Users\buildbot\slaves\apache\cordova-android-win\mobilespec\platforms\android\build\outputs\apk\android-debug.apk' 2016-04-21 02:06:55:292 - info: [debug] [AndroidDriver] Checking whether app is actually present 2016-04-21 02:06:55:551 - info: [AndroidDriver] Starting Android session 2016-04-21 02:06:55:551 - info: [debug] [ADB] Trying to find Galaxy_Nexus emulator 2016-04-21 02:06:55:551 - info: [debug] [ADB] Getting connected emulators 2016-04-21 02:06:55:552 - info: [debug] [ADB] Getting connected devices... 2016-04-21 02:07:03:860 - info: [debug] [ADB] 1 device(s) connected 2016-04-21 02:07:03:861 - info: [debug] [ADB] 1 emulator(s) connected 2016-04-21 02:07:03:861 - info: [debug] [ADB] Sending telnet command to device: avd name 2016-04-21 02:07:03:861 - info: [debug] [ADB] Getting running emulator port 2016-04-21 02:07:03:863 - info: [debug] [ADB] Socket connection to device created 2016-04-21 02:07:03:863 - info: [debug] [ADB] Socket connection to device ready 2016-04-21 02:07:03:864 - info: [debug] [ADB] Telnet command got response: Galaxy_Nexus 2016-04-21 02:07:03:865 - info: [debug] [ADB] Found emulator Galaxy_Nexus in port 5554 2016-04-21 02:07:03:865 - info: [debug] [ADB] Setting device id to emulator-5554 2016-04-21 02:07:03:865 - info: [debug] [AndroidDriver] Not launching AVD because it is already running. 2016-04-21 02:07:03:866 - info: [debug] [ADB] Running C:\Android\android-sdk\platform-tools\adb.exe with args: ["-P",5037,"-s","emulator-5554","-s","emulator-5554","wait-for-device"] 2016-04-21 02:07:12:629 - info: [debug] [ADB] Getting connected devices... 2016-04-21 02:07:21:034 - info: [debug] [ADB] 1 device(s) connected 2016-04-21 02:07:21:034 - info: [debug] [ADB] Running C:\Android\android-sdk\platform-tools\adb.exe with args: ["-P",5037,"-s","emulator-5554","-s","emulator-5554","shell","echo","ping"] 2016-04-21 02:07:28:995 - info: [debug] [Logcat] Starting logcat capture 2016-04-21 02:07:37:077 - info: [debug] [AndroidDriver] Pushing settings apk to device... 2016-04-21 02:07:37:077 - info: [debug] [ADB] Running C:\Android\android-sdk\platform-tools\adb.exe with args: ["-P",5037,"-s","emulator-5554","-s","emulator-5554","install","C:\\Users\\buildbot\\slaves\\apache\\cordova-android-win\\cordova-medic\\node_modules\\appium\\node_modules\\io.appium.settings\\bin\\settings_apk-debug.apk"] 2016-04-21 02:07:49:091 - info: [debug] [AndroidDriver] Pushing unlock helper app to device... 2016-04-21 02:07:49:092 - info: [debug] [ADB] Running C:\Android\android-sdk\platform-tools\adb.exe with args: ["-P",5037,"-s","emulator-5554","-s","emulator-5554","install","C:\\Users\\buildbot\\slaves\\apache\\cordova-android-win\\cordova-medic\\node_modules\\appium\\node_modules\\appium-unlock\\bin\\unlock_apk-debug.apk"] 2016-04-21 02:08:02:031 - info: [ADB] Getting device platform version 2016-04-21 02:08:02:031 - info: [debug] [ADB] Getting connected devices... program finished with exit code 0