Appium/Android Orientation Error

Hello All,

I am running into an issue when I try to run my tests against a physical Nexus 9. First, let me describe my environment:

Windows 8 OS
NodeJS, Selenium Webdriver JS, with Webstorm as the IDE
Nexus 9, attached via USB
The tests run successfully when I run against chrome on my PC, but when I try to run on the Nexus 9 with Appium I get the error below:

Launching Appium server with command: C:\Program Files (x86)\Appium\node.exe lib\server\main.js --address 127.0.0.1 --port 5567 --browser-name Chrome --platform-name Android --platform-version 23 --automation-name Appium --device-name “HT59AJT00220” --language en --log-no-color
info: Welcome to Appium v1.4.16 (REV ae6877eff263066b26328d457bd285c0cc62430d)
info: Appium REST http interface listener started on 127.0.0.1:5567
info: [debug] Non-default server args: {“address”:“127.0.0.1”,“port”:5567,“logNoColors”:true,“deviceName”:“HT59AJT00220”,“platformName”:“Android”,“platformVersion”:“23”,“automationName”:“Appium”,“browserName”:“Chrome”,“language”:“en”}
info: Console LogLevel: debug
info: → POST /wd/hub/session {“desiredCapabilities”:{“browserName”:“chrome”,“appiumVersion”:“1.4.16.1”,“platformName”:“Android”,“platformVersion”:“5.1.1”,“deviceName”:“”,“udid”:“”,“newCommandTimeout”:300,“autoDismissAlerts”:false,“autoAcceptAlerts”:true,“version”:“”,“javascriptEnabled”:true,“platform”:“ANY”}}
info: Client User-Agent string: admc/wd/0.3.12
info: [debug] The following desired capabilities were provided, but not recognized by appium. They will be passed on to any other services running on this server. : appiumVersion, version, javascriptEnabled, platform
info: Set mode: Proxying straight through to Chromedriver
info: [debug] Looks like we want chrome on android
info: [debug] Creating new appium session e17aca1d-8a18-439f-95ac-e0a53d2b46f8
info: [debug] Checking whether adb is present
info: [debug] Using adb from C:\Program Files (x86)\Android\android-sdk\platform-tools\adb.exe
info: [debug] Using fast reset? true
info: [debug] Preparing device for session
info: [debug] Not checking whether app is present since we are assuming it’s already on the device
info: [debug] executing cmd: “C:\Program Files (x86)\Android\android-sdk\platform-tools\adb.exe” shell “getprop persist.sys.language”
info: [debug] Current device persist.sys.language: en
info: [debug] executing cmd: “C:\Program Files (x86)\Android\android-sdk\platform-tools\adb.exe” shell “getprop persist.sys.country”
info: [debug] Current device persist.sys.country: US
info: Retrieving device
info: [debug] Trying to find a connected android device
info: [debug] Getting connected devices…
info: [debug] executing cmd: “C:\Program Files (x86)\Android\android-sdk\platform-tools\adb.exe” devices
info: [debug] 1 device(s) connected
info: Found device HT59AJT00220
info: [debug] Setting device id to HT59AJT00220
info: [debug] Waiting for device to be ready and to respond to shell commands (timeout = 5)
info: [debug] executing cmd: “C:\Program Files (x86)\Android\android-sdk\platform-tools\adb.exe” -s HT59AJT00220 wait-for-device
info: [debug] executing cmd: “C:\Program Files (x86)\Android\android-sdk\platform-tools\adb.exe” -s HT59AJT00220 shell “echo ‘ready’”
info: [debug] Starting logcat capture
info: [debug] Pushing unlock helper app to device…
info: [debug] executing cmd: “C:\Program Files (x86)\Android\android-sdk\platform-tools\adb.exe” -s HT59AJT00220 install “C:\Program Files (x86)\Appium\node_modules\appium\build\unlock_apk\unlock_apk-debug.apk”
info: [debug] executing cmd: “C:\Program Files (x86)\Android\android-sdk\platform-tools\adb.exe” -s HT59AJT00220 shell “dumpsys window”
info: [debug] Screen already unlocked, continuing.
info: [debug] Forwarding system:4724 to device:4724
info: [debug] executing cmd: “C:\Program Files (x86)\Android\android-sdk\platform-tools\adb.exe” -s HT59AJT00220 forward tcp:4724 tcp:4724
info: [debug] Pushing appium bootstrap to device…
info: [debug] executing cmd: “C:\Program Files (x86)\Android\android-sdk\platform-tools\adb.exe” -s HT59AJT00220 push “C:\Program Files (x86)\Appium\node_modules\appium\build\android_bootstrap\AppiumBootstrap.jar” /data/local/tmp/
info: Starting App
info: [debug] Attempting to kill all ‘uiautomator’ processes
info: [debug] Getting all processes with ‘uiautomator’
info: [debug] executing cmd: “C:\Program Files (x86)\Android\android-sdk\platform-tools\adb.exe” -s HT59AJT00220 shell “ps ‘uiautomator’”
info: [debug] No matching processes found
info: [debug] Running bootstrap
info: [debug] spawning: C:\Program Files (x86)\Android\android-sdk\platform-tools\adb.exe -s HT59AJT00220 shell uiautomator runtest AppiumBootstrap.jar -c io.appium.android.bootstrap.Bootstrap -e pkg com.android.chrome -e disableAndroidWatchers false
info: [debug] [UIAUTOMATOR STDOUT] INSTRUMENTATION_STATUS: numtests=1
info: [debug] [UIAUTOMATOR STDOUT] INSTRUMENTATION_STATUS: stream=
info: [debug] [UIAUTOMATOR STDOUT] io.appium.android.bootstrap.Bootstrap:
info: [debug] [UIAUTOMATOR STDOUT] INSTRUMENTATION_STATUS: id=UiAutomatorTestRunner
info: [debug] [UIAUTOMATOR STDOUT] INSTRUMENTATION_STATUS: test=testRunServer
info: [debug] [UIAUTOMATOR STDOUT] INSTRUMENTATION_STATUS: class=io.appium.android.bootstrap.Bootstrap
info: [debug] [UIAUTOMATOR STDOUT] INSTRUMENTATION_STATUS: current=1
info: [debug] [UIAUTOMATOR STDOUT] INSTRUMENTATION_STATUS_CODE: 1
info: [debug] [BOOTSTRAP] [debug] Socket opened on port 4724
info: [debug] [BOOTSTRAP] [debug] Appium Socket Server Ready
info: [debug] [BOOTSTRAP] [debug] Loading json…
info: [debug] [BOOTSTRAP] [debug] Registered crash watchers.
info: [debug] Pushing command to appium work queue: [“getDataDir”,{}]
info: [debug] [BOOTSTRAP] [debug] Client connected
info: [debug] [BOOTSTRAP] [debug] Got data from client: {“cmd”:“action”,“action”:“getDataDir”,“params”:{}}
info: [debug] [BOOTSTRAP] [debug] Got command of type ACTION
info: [debug] [BOOTSTRAP] [debug] Got command action: getDataDir
info: [debug] [BOOTSTRAP] [debug] Returning result: {“status”:0,“value”:“/data/local/tmp”}
info: [debug] dataDir set to: /data/local/tmp
info: Chromedriver: Changed state to ‘starting’
info: Chromedriver: Set chromedriver binary as: C:\Program Files (x86)\Appium\node_modules\appium\node_modules\appium-chromedriver\chromedriver\win\chromedriver.exe
info: Chromedriver: Killing any old chromedrivers, running: FOR /F “usebackq tokens=5” %a in (netstat -nao ^| findstr /R /C:"9515 ") do (FOR /F “usebackq” %b in (TASKLIST /FI "PID eq %a" ^| findstr /I chromedriver.exe) do (IF NOT %b==“” TASKKILL /F /PID %a))
info: Chromedriver: No old chromedrivers seemed to exist
info: Chromedriver: Spawning chromedriver with: C:\Program Files (x86)\Appium\node_modules\appium\node_modules\appium-chromedriver\chromedriver\win\chromedriver.exe --url-base=wd/hub --port=9515
info: Chromedriver: [STDOUT] Starting ChromeDriver 2.18.343845 (73dd713ba7fbfb73cbb514e62641d8c96a94682a) on port 9515
Only local connections are allowed.
info: JSONWP Proxy: Proxying [GET /status] to [GET http://127.0.0.1:9515/wd/hub/status] with no body
info: JSONWP Proxy: Got response with status 200: “{"sessionId":"","status":0,"value":{"build":{"version":"alpha"},"os":{"arch":"x86_64","name":"Windows NT","version":"6.3"}}}”
info: JSONWP Proxy: Proxying [POST /session] to [POST http://127.0.0.1:9515/wd/hub/session] with body: {“desiredCapabilities”:{“chromeOptions”:{“androidPackage”:“com.android.chrome”,“androidDeviceSerial”:“HT59AJT00220”}}}
info: JSONWP Proxy: Got response with status 200: {“sessionId”:“dac87178414fbbd8c09eaf0096b7c946”,“status”:0,“value”:{“acceptSslCerts”:true,“applicationCacheEnabled”:false,“browserConnectionEnabled”:false,“browserName”:“chrome”,“chrome”:{},"cssSel…
info: Chromedriver: Changed state to ‘online’
info: [debug] Overriding session id with “dac87178414fbbd8c09eaf0096b7c946”
info: [debug] Device launched! Ready for commands
info: [debug] Setting command timeout to 300 secs
info: [debug] Appium session started with sessionId dac87178414fbbd8c09eaf0096b7c946
info: ← POST /wd/hub/session 303 8357.963 ms - 70
info: → POST /wd/hub/session/dac87178414fbbd8c09eaf0096b7c946/timeouts/implicit_wait {“ms”:5000}
info: JSONWP Proxy: Proxying [POST /wd/hub/session/dac87178414fbbd8c09eaf0096b7c946/timeouts/implicit_wait] to [POST http://127.0.0.1:9515/wd/hub/session/dac87178414fbbd8c09eaf0096b7c946/timeouts/implicit_wait] with body: {“ms”:5000}
info: JSONWP Proxy: Got response with status 200: {“sessionId”:“dac87178414fbbd8c09eaf0096b7c946”,“status”:0,“value”:null}
info: JSONWP Proxy: Replacing sessionId dac87178414fbbd8c09eaf0096b7c946 with dac87178414fbbd8c09eaf0096b7c946
info: ← POST /wd/hub/session/dac87178414fbbd8c09eaf0096b7c946/timeouts/implicit_wait 200 10.420 ms - 72
info: → POST /wd/hub/session/dac87178414fbbd8c09eaf0096b7c946/log {“type”:“browser”}
info: JSONWP Proxy: Proxying [POST /wd/hub/session/dac87178414fbbd8c09eaf0096b7c946/log] to [POST http://127.0.0.1:9515/wd/hub/session/dac87178414fbbd8c09eaf0096b7c946/log] with body: {“type”:“browser”}
info: JSONWP Proxy: Got response with status 200: {“sessionId”:“dac87178414fbbd8c09eaf0096b7c946”,“status”:0,“value”:}
info: JSONWP Proxy: Replacing sessionId dac87178414fbbd8c09eaf0096b7c946 with dac87178414fbbd8c09eaf0096b7c946
info: ← POST /wd/hub/session/dac87178414fbbd8c09eaf0096b7c946/log 200 6.258 ms - 70
info: → POST /wd/hub/session/dac87178414fbbd8c09eaf0096b7c946/log {“type”:“driver”}
info: JSONWP Proxy: Proxying [POST /wd/hub/session/dac87178414fbbd8c09eaf0096b7c946/log] to [POST http://127.0.0.1:9515/wd/hub/session/dac87178414fbbd8c09eaf0096b7c946/log] with body: {“type”:“driver”}
info: JSONWP Proxy: Got response with status 200: {“sessionId”:“dac87178414fbbd8c09eaf0096b7c946”,“status”:0,“value”:}
info: JSONWP Proxy: Replacing sessionId dac87178414fbbd8c09eaf0096b7c946 with dac87178414fbbd8c09eaf0096b7c946
info: ← POST /wd/hub/session/dac87178414fbbd8c09eaf0096b7c946/log 200 4.087 ms - 70
info: → POST /wd/hub/session/dac87178414fbbd8c09eaf0096b7c946/url {“url”:“http://test26.mentoringmindsonline.com”}
info: JSONWP Proxy: Proxying [POST /wd/hub/session/dac87178414fbbd8c09eaf0096b7c946/url] to [POST http://127.0.0.1:9515/wd/hub/session/dac87178414fbbd8c09eaf0096b7c946/url] with body: {“url”:“http://test26.mentoringmindsonline.com”}
info: JSONWP Proxy: Got response with status 200: {“sessionId”:“dac87178414fbbd8c09eaf0096b7c946”,“status”:0,“value”:null}
info: JSONWP Proxy: Replacing sessionId dac87178414fbbd8c09eaf0096b7c946 with dac87178414fbbd8c09eaf0096b7c946
info: ← POST /wd/hub/session/dac87178414fbbd8c09eaf0096b7c946/url 200 7740.304 ms - 72
info: → POST /wd/hub/session/dac87178414fbbd8c09eaf0096b7c946/orientation {“orientation”:“PORTRAIT”}
info: JSONWP Proxy: Proxying [POST /wd/hub/session/dac87178414fbbd8c09eaf0096b7c946/orientation] to [POST http://127.0.0.1:9515/wd/hub/session/dac87178414fbbd8c09eaf0096b7c946/orientation] with body: {“orientation”:“PORTRAIT”}
error: Could not proxy command to remote server. Original error: 501 - unimplemented command: session/dac87178414fbbd8c09eaf0096b7c946/orientation

I am not setting the device orientation in my desired capabilities. Here is the code that does that:

function appiumLocalDesiredCapabilities() {
return {
browserName: env.SELENIUM_BROWSER,
appiumVersion: env.APPIUM_VERSION,
platformName: env.SELENIUM_PLATFORM,
platformVersion: env.SELENIUM_VERSION,
deviceName: env.SELENIUM_DEVICE,
udid: env.DEVICE_UDID,
//avd: env.APPIUM_AVD,
// How long (in seconds) Appium will wait for a new command from the client before assuming the
// client quit and ending the session
newCommandTimeout: Number(env.SAUCE_NEW_COMMAND_TIMEOUT),
autoDismissAlerts: false,
autoAcceptAlerts: true // automatically dismiss the apple dialogs. (see SauceLabs Appium configuration)
};
}

Any ideas on what could be the root cause? Thanks in advance for the help.