appium/java-client

Java-client will throw exceptions - GridException: Cannot extract a capabilities xxx with webdriver 3.x

fionazj opened this issue · 8 comments

Description

Before the session of the simulator is started, some errors will show up in hub log as follow.

Environment

  • WebDriver version build version : webdriver 3.3.1 (Also tried with webdriver 3.3.4)
  • java client build version: java-client-5.0.0-BETA7
  • Appium : 1.6.5
  • Desktop OS/version used to run Appium if necessary: Mac OS 10.12.5
  • Node.js version : 4.2.0
  • Mobile platform/version under test: IPhone IOS 9.3
  • Real device or emulator/simulator: Simulator

Details

Since webdriver3.x is released, so we need to do a trail run on that, so I updated the webdriver in both our project and hub, also java-client in the project, and start the hub to execute cases. But when a session start, exception occurs, and seemed like the Appium is fine, but java-client 5.x with webdriver3.x is not, did i miss something?

And it was totally fine when I change back webdriver to 2.53.0

Code To Reproduce Issue [ Good To Have ]

Hub startup command line:

/usr/bin/java -Xdebug -Xrunjdwp:transport=dt_socket,server=y,suspend=n,address=5005 -jar -verbose /root/selenium-grid/selenium-server-standalone-3.3.1.jar -role hub -port 44442 >> bjdev3.log &

Node configuration of Appium

admins-Mac-mini:Desktop uia$ cat appium_node_config_ios.json
{
"capabilities":
[
{
"browserName": "Safari",
"platformVersion":"9.3",
"maxInstances": 1,
"platformName":"iOS",
"deviceName":"iPhone 6s",
"seleniumProtocol":"WebDriver"
}
],

"configuration":
{
"cleanUpCycle":2000,
"timeout":30000,
"proxy": "org.openqa.grid.selenium.proxy.DefaultRemoteProxy",
"url":"http://10.37.2.203:4723/wd/hub",
"maxSession": 1,
"port": 4723,
"host": "10.37.2.203",
"register": true,
"registerCycle": 5000,
"hubPort": 44442,
"hubHost": "10.37.10.37"
}
}

Ecxeption stacktraces

root@ubuntu:~/selenium-grid# 2017-06-12 07:54:04.737:WARN:osjs.HttpChannel:qtp1962826816-19: /wd/hub/session
java.io.IOException: org.openqa.grid.common.exception.GridException: Cannot extract a capabilities from the request: {"capabilities":[{"desiredCapabilities":{"app":"Safari","platformVersion":"9.3","automationName":"XCUITest","browserName":"Safari","javascriptEnabled":"true","autoWebview":"true","platformName":"iOS","deviceName":"iPhone 6"}},{"requiredCapabilities":{}}],"desiredCapabilities":{"app":"Safari","platformVersion":"9.3","automationName":"XCUITest","browserName":"Safari","javascriptEnabled":"true","autoWebview":"true","platformName":"iOS","deviceName":"iPhone 6"},"requiredCapabilities":{}}
at org.openqa.grid.web.servlet.DriverServlet.process(DriverServlet.java:126)
at org.openqa.grid.web.servlet.DriverServlet.doPost(DriverServlet.java:67)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:707)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
at org.seleniumhq.jetty9.servlet.ServletHolder.handle(ServletHolder.java:841)
at org.seleniumhq.jetty9.servlet.ServletHandler.doHandle(ServletHandler.java:543)
at org.seleniumhq.jetty9.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:188)
at org.seleniumhq.jetty9.server.session.SessionHandler.doHandle(SessionHandler.java:1584)
at org.seleniumhq.jetty9.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:188)
at org.seleniumhq.jetty9.server.handler.ContextHandler.doHandle(ContextHandler.java:1228)
at org.seleniumhq.jetty9.server.handler.ScopedHandler.nextScope(ScopedHandler.java:168)
at org.seleniumhq.jetty9.servlet.ServletHandler.doScope(ServletHandler.java:481)
at org.seleniumhq.jetty9.server.session.SessionHandler.doScope(SessionHandler.java:1553)
at org.seleniumhq.jetty9.server.handler.ScopedHandler.nextScope(ScopedHandler.java:166)
at org.seleniumhq.jetty9.server.handler.ContextHandler.doScope(ContextHandler.java:1130)
at org.seleniumhq.jetty9.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
at org.seleniumhq.jetty9.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
at org.seleniumhq.jetty9.server.Server.handle(Server.java:564)
at org.seleniumhq.jetty9.server.HttpChannel.handle(HttpChannel.java:320)
at org.seleniumhq.jetty9.server.HttpConnection.onFillable(HttpConnection.java:251)
at org.seleniumhq.jetty9.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:279)
at org.seleniumhq.jetty9.io.FillInterest.fillable(FillInterest.java:112)
at org.seleniumhq.jetty9.io.ChannelEndPoint$2.run(ChannelEndPoint.java:124)
at org.seleniumhq.jetty9.util.thread.Invocable.invokePreferred(Invocable.java:122)
at org.seleniumhq.jetty9.util.thread.strategy.ExecutingExecutionStrategy.invoke(ExecutingExecutionStrategy.java:58)
at org.seleniumhq.jetty9.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:201)
at org.seleniumhq.jetty9.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:133)
at org.seleniumhq.jetty9.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:672)
at org.seleniumhq.jetty9.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:590)
at java.lang.Thread.run(Thread.java:745)
Caused by:
org.openqa.grid.common.exception.GridException: Cannot extract a capabilities from the request: {"capabilities":[{"desiredCapabilities":{"app":"Safari","platformVersion":"9.3","automationName":"XCUITest","browserName":"Safari","javascriptEnabled":"true","autoWebview":"true","platformName":"iOS","deviceName":"iPhone 6"}},{"requiredCapabilities":{}}],"desiredCapabilities":{"app":"Safari","platformVersion":"9.3","automationName":"XCUITest","browserName":"Safari","javascriptEnabled":"true","autoWebview":"true","platformName":"iOS","deviceName":"iPhone 6"},"requiredCapabilities":{}}
at org.openqa.grid.web.servlet.handler.WebDriverRequest.extractDesiredCapability(WebDriverRequest.java:75)
at org.openqa.grid.web.servlet.handler.SeleniumBasedRequest.(SeleniumBasedRequest.java:102)
at org.openqa.grid.web.servlet.handler.WebDriverRequest.(WebDriverRequest.java:36)
at org.openqa.grid.web.servlet.handler.WebDriverRequestFactory.createFromRequest(WebDriverRequestFactory.java:30)
at org.openqa.grid.web.servlet.handler.SeleniumBasedRequest.createFromRequest(SeleniumBasedRequest.java:73)
at org.openqa.grid.web.servlet.DriverServlet.process(DriverServlet.java:81)
at org.openqa.grid.web.servlet.DriverServlet.doPost(DriverServlet.java:67)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:707)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
at org.seleniumhq.jetty9.servlet.ServletHolder.handle(ServletHolder.java:841)
at org.seleniumhq.jetty9.servlet.ServletHandler.doHandle(ServletHandler.java:543)
at org.seleniumhq.jetty9.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:188)
at org.seleniumhq.jetty9.server.session.SessionHandler.doHandle(SessionHandler.java:1584)
at org.seleniumhq.jetty9.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:188)
at org.seleniumhq.jetty9.server.handler.ContextHandler.doHandle(ContextHandler.java:1228)
at org.seleniumhq.jetty9.server.handler.ScopedHandler.nextScope(ScopedHandler.java:168)
at org.seleniumhq.jetty9.servlet.ServletHandler.doScope(ServletHandler.java:481)
at org.seleniumhq.jetty9.server.session.SessionHandler.doScope(SessionHandler.java:1553)
at org.seleniumhq.jetty9.server.handler.ScopedHandler.nextScope(ScopedHandler.java:166)
at org.seleniumhq.jetty9.server.handler.ContextHandler.doScope(ContextHandler.java:1130)
at org.seleniumhq.jetty9.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
at org.seleniumhq.jetty9.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
at org.seleniumhq.jetty9.server.Server.handle(Server.java:564)
at org.seleniumhq.jetty9.server.HttpChannel.handle(HttpChannel.java:320)
at org.seleniumhq.jetty9.server.HttpConnection.onFillable(HttpConnection.java:251)
at org.seleniumhq.jetty9.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:279)
at org.seleniumhq.jetty9.io.FillInterest.fillable(FillInterest.java:112)
at org.seleniumhq.jetty9.io.ChannelEndPoint$2.run(ChannelEndPoint.java:124)
at org.seleniumhq.jetty9.util.thread.Invocable.invokePreferred(Invocable.java:122)
at org.seleniumhq.jetty9.util.thread.strategy.ExecutingExecutionStrategy.invoke(ExecutingExecutionStrategy.java:58)
at org.seleniumhq.jetty9.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:201)
at org.seleniumhq.jetty9.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:133)
at org.seleniumhq.jetty9.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:672)
at org.seleniumhq.jetty9.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:590)
at java.lang.Thread.run(Thread.java:745)
Caused by:
java.lang.ClassCastException: com.google.gson.JsonArray cannot be cast to com.google.gson.JsonObject
at com.google.gson.JsonObject.getAsJsonObject(JsonObject.java:191)
at org.openqa.grid.web.servlet.handler.WebDriverRequest.extractDesiredCapability(WebDriverRequest.java:69)
at org.openqa.grid.web.servlet.handler.SeleniumBasedRequest.(SeleniumBasedRequest.java:102)
at org.openqa.grid.web.servlet.handler.WebDriverRequest.(WebDriverRequest.java:36)
at org.openqa.grid.web.servlet.handler.WebDriverRequestFactory.createFromRequest(WebDriverRequestFactory.java:30)
at org.openqa.grid.web.servlet.handler.SeleniumBasedRequest.createFromRequest(SeleniumBasedRequest.java:73)
at org.openqa.grid.web.servlet.DriverServlet.process(DriverServlet.java:81)
at org.openqa.grid.web.servlet.DriverServlet.doPost(DriverServlet.java:67)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:707)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
at org.seleniumhq.jetty9.servlet.ServletHolder.handle(ServletHolder.java:841)
at org.seleniumhq.jetty9.servlet.ServletHandler.doHandle(ServletHandler.java:543)
at org.seleniumhq.jetty9.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:188)
at org.seleniumhq.jetty9.server.session.SessionHandler.doHandle(SessionHandler.java:1584)
at org.seleniumhq.jetty9.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:188)
at org.seleniumhq.jetty9.server.handler.ContextHandler.doHandle(ContextHandler.java:1228)
at org.seleniumhq.jetty9.server.handler.ScopedHandler.nextScope(ScopedHandler.java:168)
at org.seleniumhq.jetty9.servlet.ServletHandler.doScope(ServletHandler.java:481)
at org.seleniumhq.jetty9.server.session.SessionHandler.doScope(SessionHandler.java:1553)
at org.seleniumhq.jetty9.server.handler.ScopedHandler.nextScope(ScopedHandler.java:166)
at org.seleniumhq.jetty9.server.handler.ContextHandler.doScope(ContextHandler.java:1130)
at org.seleniumhq.jetty9.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
at org.seleniumhq.jetty9.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
at org.seleniumhq.jetty9.server.Server.handle(Server.java:564)
at org.seleniumhq.jetty9.server.HttpChannel.handle(HttpChannel.java:320)
at org.seleniumhq.jetty9.server.HttpConnection.onFillable(HttpConnection.java:251)
at org.seleniumhq.jetty9.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:279)
at org.seleniumhq.jetty9.io.FillInterest.fillable(FillInterest.java:112)
at org.seleniumhq.jetty9.io.ChannelEndPoint$2.run(ChannelEndPoint.java:124)
at org.seleniumhq.jetty9.util.thread.Invocable.invokePreferred(Invocable.java:122)
at org.seleniumhq.jetty9.util.thread.strategy.ExecutingExecutionStrategy.invoke(ExecutingExecutionStrategy.java:58)
at org.seleniumhq.jetty9.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:201)
at org.seleniumhq.jetty9.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:133)
at org.seleniumhq.jetty9.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:672)
at org.seleniumhq.jetty9.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:590)
at java.lang.Thread.run(Thread.java:745)
07:54:04.778 INFO - Got a request to create a new session: Capabilities [{app=Safari, platformVersion=9.3, automationName=XCUITest, browserName=Safari, javascriptEnabled=true, autoWebview=true, platformName=iOS, deviceName=iPhone 6}]
07:54:04.779 INFO - Trying to create a new session on test slot {seleniumProtocol=WebDriver, platformVersion=9.3, browserName=Safari, maxInstances=1, platformName=iOS, deviceName=iPhone 6s}
07:54:23.100 INFO - Marking the node http://10.37.2.203:4723 as down: cannot reach the node for 2 tries

Link to Appium logs

admins-Mac-mini:tmp uia$ tail -200f appium.log
2017-06-12 05:59:36:206 - info: [Appium] Welcome to Appium v1.6.5
2017-06-12 05:59:36:209 - info: [Appium] Non-default server args:
2017-06-12 05:59:36:210 - info: [Appium] sessionOverride: true
2017-06-12 05:59:36:210 - info: [Appium] log: /tmp/appium.log
2017-06-12 05:59:36:210 - info: [Appium] loglevel: info
2017-06-12 05:59:36:210 - info: [Appium] nodeconfig: /Users/uia/Desktop/appium_node_config_ios.json
2017-06-12 05:59:36:210 - info: [Appium] debugLogSpacing: true
2017-06-12 05:59:36:210 - info: [Appium] platformName: iOS
2017-06-12 05:59:36:211 - info: [Appium] platformVersion: 9.3
2017-06-12 05:59:36:211 - info: [Appium] deviceName: iPhone 7
2017-06-12 05:59:36:211 - info: [Appium] browserName: Safari
2017-06-12 05:59:36:211 - info: [Appium] fullReset: true
2017-06-12 05:59:36:211 - info: [Appium] showIOSLog: true
2017-06-12 05:59:36:212 - warn: [Appium] Deprecated server args:
2017-06-12 05:59:36:212 - warn: [Appium] --platform-name => --default-capabilities '{"platformName":"iOS"}'
2017-06-12 05:59:36:212 - warn: [Appium] --platform-version => --default-capabilities '{"platformVersion":"9.3"}'
2017-06-12 05:59:36:212 - warn: [Appium] --device-name => --default-capabilities '{"deviceName":"iPhone 7"}'
2017-06-12 05:59:36:212 - warn: [Appium] --browser-name => --default-capabilities '{"browserName":"Safari"}'
2017-06-12 05:59:36:213 - warn: [Appium] --full-reset => --default-capabilities '{"fullReset":true}'
2017-06-12 05:59:36:213 - warn: [Appium] --show-ios-log => --default-capabilities '{"showIOSLog":true}'
2017-06-12 05:59:36:213 - info: [Appium] Default capabilities, which will be added to each request unless overridden by desired capabilities:
2017-06-12 05:59:36:215 - info: [Appium] platformName: 'iOS'
2017-06-12 05:59:36:216 - info: [Appium] platformVersion: '9.3'
2017-06-12 05:59:36:216 - info: [Appium] deviceName: 'iPhone 7'
2017-06-12 05:59:36:216 - info: [Appium] browserName: 'Safari'
2017-06-12 05:59:36:216 - info: [Appium] fullReset: true
2017-06-12 05:59:36:216 - info: [Appium] showIOSLog: true
2017-06-12 05:59:36:255 - info: [Appium] Appium REST http interface listener started on 0.0.0.0:4723
2017-06-12 05:59:46:292 - info: [HTTP] --> GET /wd/hub/status {}
2017-06-12 05:59:46:311 - info: [HTTP] <-- GET /wd/hub/status 200 17 ms - 83
2017-06-12 05:59:51:315 - info: [HTTP] --> GET /wd/hub/status {}
2017-06-12 05:59:51:329 - info: [HTTP] <-- GET /wd/hub/status 200 12 ms - 83
2017-06-12 05:59:56:335 - info: [HTTP] --> GET /wd/hub/status {}
2017-06-12 05:59:56:349 - info: [HTTP] <-- GET /wd/hub/status 200 14 ms - 83
2017-06-12 05:59:58:065 - info: [HTTP] --> POST /wd/hub/session {"desiredCapabilities":{"app":"Safari","platformVersion":"9.3","automationName":"XCUITest","browserName":"Safari","javascriptEnabled":"true","autoWebview":"true","platformName":"iOS","deviceName":"iPhone 6"},"requiredCapabilities":{}}
2017-06-12 05:59:58:068 - info: [Appium] Creating new XCUITestDriver (v2.30.0) session
2017-06-12 05:59:58:068 - info: [Appium] Capabilities:
2017-06-12 05:59:58:068 - info: [Appium] app: 'Safari'
2017-06-12 05:59:58:069 - info: [Appium] platformVersion: '9.3'
2017-06-12 05:59:58:069 - info: [Appium] automationName: 'XCUITest'
2017-06-12 05:59:58:069 - info: [Appium] browserName: 'Safari'
2017-06-12 05:59:58:069 - info: [Appium] javascriptEnabled: 'true'
2017-06-12 05:59:58:069 - info: [Appium] autoWebview: 'true'
2017-06-12 05:59:58:070 - info: [Appium] platformName: 'iOS'
2017-06-12 05:59:58:070 - info: [Appium] deviceName: 'iPhone 6'
2017-06-12 05:59:58:070 - info: [Appium] fullReset: true
2017-06-12 05:59:58:071 - info: [Appium] showIOSLog: true
2017-06-12 05:59:58:076 - warn: [BaseDriver] Capability 'autoWebview' changed from string to boolean. This may cause unexpected behavior
2017-06-12 05:59:58:082 - warn: [BaseDriver] The following capabilities were provided, but are not recognized by appium: javascriptEnabled.
2017-06-12 05:59:58:187 - info: [BaseDriver] Session created with session id: 3088b29c-c128-4326-ad65-98521c8b0363
2017-06-12 05:59:58:437 - info: [iOSSim] Constructing iOS simulator for Xcode version 7.3 with udid 'A54CEB4F-C2C3-47E5-8DCF-3A906B568894'
2017-06-12 05:59:58:438 - info: [XCUITest] Determining device to run tests on: udid: 'A54CEB4F-C2C3-47E5-8DCF-3A906B568894', real device: false
2017-06-12 05:59:58:438 - info: [XCUITest] Safari test requested
2017-06-12 06:00:01:357 - info: [HTTP] --> GET /wd/hub/status {}
2017-06-12 06:00:06:359 - info: [HTTP] <-- GET /wd/hub/status - - ms - -
2017-06-12 06:00:09:720 - info: [iOSSim] Cleaning simulator A54CEB4F-C2C3-47E5-8DCF-3A906B568894
2017-06-12 06:00:10:160 - info: [XCUITest] Setting up simulator
2017-06-12 06:00:10:237 - info: [XCUITest] Simulator with udid 'A54CEB4F-C2C3-47E5-8DCF-3A906B568894' not booted. Booting up now
2017-06-12 06:00:10:268 - info: [iOSSim] Starting simulator with command: open -Fn /Applications/Xcode_7.3.app/Contents/Developer/Applications/Simulator.app --args -CurrentDeviceUDID A54CEB4F-C2C3-47E5-8DCF-3A906B568894 -ConnectHardwareKeyboard 0
2017-06-12 06:00:10:374 - info: [iOSSim] Simulator log at '/Users/uia/Library/Logs/CoreSimulator/A54CEB4F-C2C3-47E5-8DCF-3A906B568894/system.log'
2017-06-12 06:00:10:375 - info: [iOSSim] Tailing simulator logs until we encounter the string "System app "com.apple.springboard" finished startup"
2017-06-12 06:00:10:377 - info: [iOSSim] We will time out after 60000ms

@fionazj Could you describe how do run hub/node?

WebDriver version build version : webdriver 3.3.1 (Also tried with webdriver 3.3.4)
And it was totally fine when I change back webdriver to 2.53.0

Do you mean Selenium server? Or do you use another Selenium client dependency?

@TikhomirovSergey , I mean the selenium server

And here's how I start hub and node:

The hub started by following command:
/usr/bin/java -jar /root/selenium-grid/selenium-server-standalone-3.3.1.jar -role hub -port 44442

For the node, just a config file, and Appium will load the config file
appium --session-override --debug-log-spacing --log "/tmp/appium.log" --log-level "info" --nodeconfig "/Users/uiatouch/Desktop/appium_node_config_ios.json" --platform-version "9.3" --platform-name "iOS" --browser-name "Safari" --full-reset --show-ios-log --device-name "iPhone 7" --launch-timeout "90000"

appium_node_config_ios.json:

{
"capabilities":
[
{
"browserName": "Safari",
"platformVersion":"9.3",
"maxInstances": 1,
"platformName":"iOS",
"deviceName":"iPhone 6s"
}
],

"configuration":
{
"cleanUpCycle":2000,
"timeout":30000,
"proxy": "org.openqa.grid.selenium.proxy.DefaultRemoteProxy",
"url":"http://10.37.2.204:4723/wd/hub",
"maxSession": 1,
"port": 4723,
"host": "10.37.2.204",
"register": true,
"registerCycle": 5000,
"hubPort": 44442,
"hubHost": "10.37.10.37"
}
}

It looks like a bug and it is related to #594 #597

@TikhomirovSergey issue is still there with BETA9 as well.

@fionazj any workaround you found ?

The bug was fixed at #682. For now it is recommended to use older selenium server. The fix is going to be available in 5.0.0 soon.

olyv commented

Hi,
can you guys please advise if there is an existing mapping of selenium server to appium java client version?

I am asking because I see "GridException: Cannot extract a capabilities" for a combination of appium java-client 6.1.0 and selenium 3.6.0. I assume the nature of the issue is the same as described in this thread.

One should always use the selenium version, which is set in the gradle config:

ext.seleniumVersion = '3.13.0'