search

laurentj / slimerjs

A scriptable browser like PhantomJS, based on Firefox
http://slimerjs.org
Other
3k stars 259 forks source link

Webdriver doesn't work with Selenium #462

Open domderen opened 8 years ago

domderen commented 8 years ago

versions

I created a separate repository that describes my issue in detail. It is available here.

To give you just a gist of the information, I tried to run SlimerJS as a Selenium runner node inside Docker. Unfortunately it seems that currently SlimerJS is not implementing that properly, as it fails to communicate with Selenium Hub. I'm hoping that this issue can guide the discussion required to actually be able to use SlimerJS as a selenium runner. I'm also happy to help with the code required to do so.

Actual results:

SlimerJS fails to work as Selenium runner.

Expected results:

SlimerJS works fine as a selenium runner.

laurentj commented 8 years ago

With the implementation of phantom.aboutToExit, it seems it is ok. However, I don't know very well selenium, so don't hesitate to open new issues.

domderen commented 8 years ago

So I have ran SlimerJS in debug mode with and without Docker. The command I used when I ran it without Docker was:

./slimerjs --debug=yes --webdriver 0.0.0.0:8081 –error-log-file=/tmp/slimer-error.log --webdriver-logfile /tmp/webdriver.log --webdriver-loglevel DEBUG

The logs present the following:

2016-05-05T16:32:34.129Z [DEBUG] Gecko version: 40.0.3
2016-05-05T16:32:34.129Z [DEBUG] script args: file:///Users/dominik/Downloads/slimerjs-1.0.0-pre/vendors/ghostdriver/main.js –error-log-file=/tmp/slimer-error.log --ip=0.0.0.0 --port=8081 --logFile=/tmp/webdriver.log --logColor=false --logLevel=DEBUG
2016-05-05T16:32:34.129Z [DEBUG] Configuration: debug=yes
2016-05-05T16:32:34.129Z [DEBUG] Configuration: webdriver,wd,w=0.0.0.0:8081
2016-05-05T16:32:34.132Z [DEBUG] Configuration: webdriver-logfile=/tmp/webdriver.log
2016-05-05T16:32:34.132Z [DEBUG] Configuration: webdriver-loglevel=DEBUG
2016-05-05T16:32:34.132Z [DEBUG] Configuration: Script=/Users/dominik/Downloads/slimerjs-1.0.0-pre/vendors/ghostdriver/main.js
2016-05-05T16:32:34.132Z [DEBUG] Configuration: workingDirectory=/Users/dominik/Downloads/slimerjs-1.0.0-pre
JavaScript strict warning: resource://gre/modules/TelemetryEnvironment.jsm, line 397: ReferenceError: reference to undefined property this._environment._currentEnvironment.addons
[DEBUG - 2016-05-05T16:32:34.312Z] Config - config.init - {"ip":"0.0.0.0","port":"8081","hub":null,"logFile":"/tmp/webdriver.log","logLevel":"DEBUG","logColor":false}
[INFO  - 2016-05-05T16:32:34.335Z] GhostDriver - Main - running on port 8081
JavaScript strict warning: resource://gre/modules/ProfileAge.jsm, line 202: ReferenceError: reference to undefined property times.reset
JavaScript strict warning: jar:file:///Users/dominik/Downloads/slimerjs-1.0.0-pre/omni.ja!/components/httpd.js, line 796: ReferenceError: reference to undefined property this._stopCallback

I ran one of my tests utilizing webdriver-io and got the following result:

=======================================================================================
Selenium 2.0 / webdriver protocol bindings implementation with helper commands in nodejs.
For a complete list of commands, visit http://webdriver.io/docs.html.
=======================================================================================

[17:33:40]  COMMAND POST     "/wd/hub/session"
[17:33:40]  DATA        {"desiredCapabilities":{"javascriptEnabled":true,"locationContextEnabled":true,"handlesAlerts":true,"rotatable":true,"browserName":"phantomjs","maxInstances":1,"loggingPrefs":{"browser":"ALL","driver":"ALL"},"requestOrigins":{"url":"http://webdriver.io","version":"4.0.5","name":"webdriverio"}}}
ERROR: Bad request

phantomjs
    at new RuntimeError (/Users/dominik/dev/lightning-ui/node_modules/webdriverio/build/lib/utils/ErrorHandler.js:115:12)
    at Request._callback (/Users/dominik/dev/lightning-ui/node_modules/webdriverio/build/lib/utils/RequestHandler.js:241:32)
    at Request.self.callback (/Users/dominik/dev/lightning-ui/node_modules/webdriverio/node_modules/request/request.js:373:22)
    at emitTwo (events.js:87:13)
    at Request.emit (events.js:172:7)
    at Request.<anonymous> (/Users/dominik/dev/lightning-ui/node_modules/webdriverio/node_modules/request/request.js:1318:14)
    at emitOne (events.js:82:20)
    at Request.emit (events.js:169:7)
    at IncomingMessage.<anonymous> (/Users/dominik/dev/lightning-ui/node_modules/webdriverio/node_modules/request/request.js:1266:12)
    at emitNone (events.js:72:20)

The webdriver.log file's contents was:

[DEBUG - 2016-05-05T16:30:59.307Z] Config - config.init - {"ip":"127.0.0.1","port":"8081","hub":null,"logFile":"/tmp/webdriver.log","logLevel":"DEBUG","logColor":false}
[INFO  - 2016-05-05T16:30:59.323Z] GhostDriver - Main - running on port 8081
[DEBUG - 2016-05-05T16:32:34.312Z] Config - config.init - {"ip":"0.0.0.0","port":"8081","hub":null,"logFile":"/tmp/webdriver.log","logLevel":"DEBUG","logColor":false}
[INFO  - 2016-05-05T16:32:34.335Z] GhostDriver - Main - running on port 8081

There was no /tmp/slimer-error.log file, so I assume no error was registered on SlimerJS side.

Now, for running it inside the docker container, I used the command:

usr/bin/slimerjs --debug=yes --webdriver `hostname -I | awk '{print $1}'`:8080 ${PHANTOMJS_OPTS} --webdriver-selenium-grid-hub http://hub:4444 –error-log-file=/tmp/slimer-error.log --webdriver-logfile /tmp/webdriver.log --webdriver-loglevel DEBUG

The logs look like this:

Innophi SlimerJS 1.0.0-pre, Copyright 2012-2016 Laurent Jouanneau & Innophi
Xlib:  extension "RANDR" missing on display ":99".
process 74: D-Bus library appears to be incorrectly set up; failed to read machine uuid: Failed to open "/etc/machine-id": No such file or directory
See the manual page for dbus-uuidgen to correct this issue.
2016-05-05T19:23:15.665Z [DEBUG] Gecko version: 45.0
2016-05-05T19:23:15.665Z [DEBUG] script args: file:///srv/var/slimerjs/vendors/ghostdriver/main.js –error-log-file=/tmp/slimer-error.log --ip=172.17.0.3 --port=8080 --hub=http://hub:4444 --logFile=/tmp/webdriver.log --logColor=false --logLevel=DEBUG
2016-05-05T19:23:15.665Z [DEBUG] Configuration: debug=yes
2016-05-05T19:23:15.665Z [DEBUG] Configuration: webdriver,wd,w=172.17.0.3:8080
2016-05-05T19:23:15.666Z [DEBUG] Configuration: webdriver-logfile=/tmp/webdriver.log
2016-05-05T19:23:15.666Z [DEBUG] Configuration: webdriver-loglevel=DEBUG
2016-05-05T19:23:15.666Z [DEBUG] Configuration: webdriver-selenium-grid-hub=http://hub:4444
2016-05-05T19:23:15.666Z [DEBUG] Configuration: Script=/srv/var/slimerjs/vendors/ghostdriver/main.js
2016-05-05T19:23:15.666Z [DEBUG] Configuration: workingDirectory=/
JavaScript strict warning: resource://gre/modules/TelemetryEnvironment.jsm, line 488: ReferenceError: reference to undefined property this._environment._currentEnvironment.addons
[DEBUG - 2016-05-05T19:23:15.755Z] Config - config.init - {"ip":"172.17.0.3","port":"8080","hub":"http://hub:4444","logFile":"/tmp/webdriver.log","logLevel":"DEBUG","logColor":false}
[INFO  - 2016-05-05T19:23:15.767Z] GhostDriver - Main - running on port 8080
[INFO  - 2016-05-05T19:23:15.768Z] GhostDriver - Main - registering to Selenium HUB 'http://hub:4444' using '172.17.0.3:8080'
2016-05-05T19:23:15.837Z [DEBUG] webpage: openUrl http://hub:4444/grid/register conf:{operation: "post", data: "{\"capabilities\":[{\"browserName\":\"phantomjs\",\"maxInstances\":1,\"seleniumProtocol\":\"WebDriver\"}],\"configuration\":{\"hub\":\"http://hub:4444/\",\"hubHost\":\"hub\",\"hubPort\":4444,\"port\":8080,\"proxy\":\"org.openqa.grid.selenium.proxy.DefaultRemoteProxy\",\"maxSession\":1,\"register\":true,\"registerCycle\":5000,\"role\":\"wd\",\"url\":\"http://172.17.0.3:8080\",\"remoteHost\":\"http://172.17.0.3:8080\"}}", headers: {Content-Type: "application/json", } , }
2016-05-05T19:23:15.844Z [DEBUG] network: main request starting - http://hub:4444/grid/register flags:START,IS_REQ,IS_DOC,IS_NET,IS_WIN,
2016-05-05T19:23:15.845Z [DEBUG] network: resource request #1 started: POST - http://hub:4444/grid/register flags=DOCUMENT_URI, INITIAL_DOCUMENT_URI,
2016-05-05T19:23:15.863Z [DEBUG] network: status change for http://hub:4444/grid/register (2152398853): Sending request to hub…
2016-05-05T19:23:15.866Z [DEBUG] network: progress total:724/0; uri: 724/724 for http://hub:4444/grid/register
2016-05-05T19:23:15.866Z [DEBUG] network: status change for http://hub:4444/grid/register (2152398858): Waiting for hub…
2016-05-05T19:23:15.910Z [DEBUG] network: status change for http://hub:4444/grid/register (2152398858): Waiting for hub…
2016-05-05T19:23:15.912Z [DEBUG] network: resource #1 response 'start': http://hub:4444/grid/register flags=DOCUMENT_URI, INITIAL_DOCUMENT_URI, TARGETED,
2016-05-05T19:23:15.915Z [DEBUG] network: status change for http://hub:4444/grid/register (2152398854): Transferring data from hub…
2016-05-05T19:23:15.916Z [DEBUG] network: main request http://hub:4444/grid/register flags:TRANSFERRING,IS_REQ,IS_DOC,
2016-05-05T19:23:15.916Z [DEBUG] network: main request: transfer started
2016-05-05T19:23:15.916Z [DEBUG] network: progress total:2/2; uri: 2/2 for http://hub:4444/grid/register
2016-05-05T19:23:15.919Z [DEBUG] network: resource #1 response end status: http://hub:4444/grid/register
2016-05-05T19:23:15.921Z [DEBUG] network: main request http://hub:4444/grid/register flags:STOP,IS_REQ,
2016-05-05T19:23:15.921Z [DEBUG] network: main request: transfer done
2016-05-05T19:23:15.932Z [DEBUG] network: main request http://hub:4444/grid/register flags:STOP,IS_DOC,
2016-05-05T19:23:15.933Z [DEBUG] network: main request: ignored state
2016-05-05T19:23:15.933Z [DEBUG] network: main request http://hub:4444/grid/register flags:STOP,IS_NET,IS_WIN,
2016-05-05T19:23:15.934Z [DEBUG] network: main request: is loaded
[INFO  - 2016-05-05T19:23:15.937Z] HUB Register - register - Registered with grid hub: http://hub:4444/ (ok)
JavaScript strict warning: resource://gre/modules/ProfileAge.jsm, line 202: ReferenceError: reference to undefined property times.reset
[DEBUG - 2016-05-05T19:23:20.964Z] RouterReqHand - _handle - {"method":"GET","url":"/status","httpVersion":"1.1","headers":{"Host":"172.17.0.3:8080","Connection":"Keep-Alive","User-Agent":"Apache-HttpClient/4.5.1 (Java/1.8.0_03-Ubuntu)","Accept-Encoding":"gzip,deflate"},"post":"","postRaw":"","path":"/wd/hub/status","queryString":"","urlParsed":{"anchor":"","query":"","file":"status","directory":"/","path":"/status","relative":"/status","port":"","host":"","password":"","user":"","userInfo":"","authority":"","protocol":"","source":"/status","queryKey":{},"chunks":["status"]}}
[DEBUG - 2016-05-05T19:23:25.986Z] RouterReqHand - _handle - {"method":"GET","url":"/status","httpVersion":"1.1","headers":{"Host":"172.17.0.3:8080","Connection":"Keep-Alive","User-Agent":"Apache-HttpClient/4.5.1 (Java/1.8.0_03-Ubuntu)","Accept-Encoding":"gzip,deflate"},"post":"","postRaw":"","path":"/wd/hub/status","queryString":"","urlParsed":{"anchor":"","query":"","file":"status","directory":"/","path":"/status","relative":"/status","port":"","host":"","password":"","user":"","userInfo":"","authority":"","protocol":"","source":"/status","queryKey":{},"chunks":["status"]}}

I ran one of my test utilizing webdriver-io, first trying to connect to the the SlimerJS webdriver directly on port 8080 and got the following result:

=======================================================================================
Selenium 2.0 / webdriver protocol bindings implementation with helper commands in nodejs.
For a complete list of commands, visit http://webdriver.io/docs.html.
=======================================================================================

[20:24:13]  COMMAND POST     "/wd/hub/session"
[20:24:13]  DATA        {"desiredCapabilities":{"javascriptEnabled":true,"locationContextEnabled":true,"handlesAlerts":true,"rotatable":true,"browserName":"phantomjs","maxInstances":1,"loggingPrefs":{"browser":"ALL","driver":"ALL"},"requestOrigins":{"url":"http://webdriver.io","version":"4.0.5","name":"webdriverio"}}}
ERROR: Bad request

phantomjs
    at new RuntimeError (/Users/dominik/dev/lightning-ui/node_modules/webdriverio/build/lib/utils/ErrorHandler.js:115:12)
    at Request._callback (/Users/dominik/dev/lightning-ui/node_modules/webdriverio/build/lib/utils/RequestHandler.js:241:32)
    at Request.self.callback (/Users/dominik/dev/lightning-ui/node_modules/webdriverio/node_modules/request/request.js:373:22)
    at emitTwo (events.js:87:13)
    at Request.emit (events.js:172:7)
    at Request.<anonymous> (/Users/dominik/dev/lightning-ui/node_modules/webdriverio/node_modules/request/request.js:1318:14)
    at emitOne (events.js:82:20)
    at Request.emit (events.js:169:7)
    at IncomingMessage.<anonymous> (/Users/dominik/dev/lightning-ui/node_modules/webdriverio/node_modules/request/request.js:1266:12)
    at emitNone (events.js:72:20)

Than going through the Selenium Grid, that was also running in a Docker container on port 4444, and got following result:

=======================================================================================
Selenium 2.0 / webdriver protocol bindings implementation with helper commands in nodejs.
For a complete list of commands, visit http://webdriver.io/docs.html.
=======================================================================================

[20:24:14]  COMMAND POST     "/wd/hub/session"
[20:24:14]  DATA        {"desiredCapabilities":{"javascriptEnabled":true,"locationContextEnabled":true,"handlesAlerts":true,"rotatable":true,"browserName":"phantomjs","maxInstances":1,"loggingPrefs":{"browser":"ALL","driver":"ALL"},"requestOrigins":{"url":"http://webdriver.io","version":"4.0.5","name":"webdriverio"}}}
ERROR: Error forwarding the new session new session request for webdriver should contain a location header or an 'application/json;charset=UTF-8' response body with the session ID.
phantomjs
    at new RuntimeError (/Users/dominik/dev/lightning-ui/node_modules/webdriverio/build/lib/utils/ErrorHandler.js:115:12)
    at Request._callback (/Users/dominik/dev/lightning-ui/node_modules/webdriverio/build/lib/utils/RequestHandler.js:246:32)
    at Request.self.callback (/Users/dominik/dev/lightning-ui/node_modules/webdriverio/node_modules/request/request.js:373:22)
    at emitTwo (events.js:87:13)
    at Request.emit (events.js:172:7)
    at Request.<anonymous> (/Users/dominik/dev/lightning-ui/node_modules/webdriverio/node_modules/request/request.js:1318:14)
    at emitOne (events.js:82:20)
    at Request.emit (events.js:169:7)
    at IncomingMessage.<anonymous> (/Users/dominik/dev/lightning-ui/node_modules/webdriverio/node_modules/request/request.js:1266:12)
    at emitNone (events.js:72:20)

The /tmp/webdriver.log file contents were:

[DEBUG - 2016-05-05T19:32:53.453Z] Config - config.init - {"ip":"172.17.0.3","port":"8080","hub":"http://hub:4444","logFile":"/tmp/webdriver.log","logLevel":"DEBUG","logColor":false}
[INFO  - 2016-05-05T19:32:53.464Z] GhostDriver - Main - running on port 8080
[INFO  - 2016-05-05T19:32:53.464Z] GhostDriver - Main - registering to Selenium HUB 'http://hub:4444' using '172.17.0.3:8080'
[INFO  - 2016-05-05T19:32:53.664Z] HUB Register - register - Registered with grid hub: http://hub:4444/ (ok)
[DEBUG - 2016-05-05T19:32:58.712Z] RouterReqHand - _handle - {"method":"GET","url":"/status","httpVersion":"1.1","headers":{"Host":"172.17.0.3:8080","Connection":"Keep-Alive","User-Agent":"Apache-HttpClient/4.5.1 (Java/1.8.0_03-Ubuntu)","Accept-Encoding":"gzip,deflate"},"post":"","postRaw":"","path":"/wd/hub/status","queryString":"","urlParsed":{"anchor":"","query":"","file":"status","directory":"/","path":"/status","relative":"/status","port":"","host":"","password":"","user":"","userInfo":"","authority":"","protocol":"","source":"/status","queryKey":{},"chunks":["status"]}}
[DEBUG - 2016-05-05T19:33:03.751Z] RouterReqHand - _handle - {"method":"GET","url":"/status","httpVersion":"1.1","headers":{"Host":"172.17.0.3:8080","Connection":"Keep-Alive","User-Agent":"Apache-HttpClient/4.5.1 (Java/1.8.0_03-Ubuntu)","Accept-Encoding":"gzip,deflate"},"post":"","postRaw":"","path":"/wd/hub/status","queryString":"","urlParsed":{"anchor":"","query":"","file":"status","directory":"/","path":"/status","relative":"/status","port":"","host":"","password":"","user":"","userInfo":"","authority":"","protocol":"","source":"/status","queryKey":{},"chunks":["status"]}}

There was again no /tmp/slimer-error.log file.

When I run the same webdriver-io test using this phantom-js runner it seems to work fine, and execute the tests. Maybe there is a newer version of WebDriver that can be updated in SlimerJS or something like this?

Thanks in advance for your help.

laurentj commented 8 years ago

--webdriver 0.0.0.0:8081

the httpd server of SlimerJS doesn't support 0.0.0.0. Specify an existing ip.

[17:33:40] COMMAND POST "/wd/hub/session" [17:33:40] DATA {"desiredCapabilities":{"javascriptEnabled":true,"locationContextEnabled":true,"handlesAlerts":true,"rotatable":true,"browserName":"phantomjs","maxInstances":1,"loggingPrefs":{"browser":"ALL","driver":"ALL"},"requestOrigins":{"url":"http://webdriver.io","version":"4.0.5","name":"webdriverio"}}} ERROR: Bad request

phantomjs at new RuntimeError

I don't understand, because webdriver-io is executed by nodejs, not by phantomjs. Why there is an error in phantomjs?

domderen commented 8 years ago

I've re-ran it with:

./slimerjs --debug=yes --webdriver 127.0.0.1:8081 –error-log-file=/tmp/slimer-error.log --webdriver-logfile /tmp/webdriver.log --webdriver-loglevel DEBUG

Got log:

2016-05-05T20:51:10.328Z [DEBUG] Gecko version: 40.0.3
2016-05-05T20:51:10.328Z [DEBUG] script args: file:///Users/dominik/Downloads/slimerjs-1.0.0-pre/vendors/ghostdriver/main.js –error-log-file=/tmp/slimer-error.log --ip=127.0.0.1 --port=8081 --logFile=/tmp/webdriver.log --logColor=false --logLevel=DEBUG
2016-05-05T20:51:10.329Z [DEBUG] Configuration: debug=yes
2016-05-05T20:51:10.329Z [DEBUG] Configuration: webdriver,wd,w=127.0.0.1:8081
2016-05-05T20:51:10.330Z [DEBUG] Configuration: webdriver-logfile=/tmp/webdriver.log
2016-05-05T20:51:10.330Z [DEBUG] Configuration: webdriver-loglevel=DEBUG
2016-05-05T20:51:10.330Z [DEBUG] Configuration: Script=/Users/dominik/Downloads/slimerjs-1.0.0-pre/vendors/ghostdriver/main.js
2016-05-05T20:51:10.330Z [DEBUG] Configuration: workingDirectory=/Users/dominik/Downloads/slimerjs-1.0.0-pre
JavaScript strict warning: resource://gre/modules/TelemetryEnvironment.jsm, line 397: ReferenceError: reference to undefined property this._environment._currentEnvironment.addons
[DEBUG - 2016-05-05T20:51:10.560Z] Config - config.init - {"ip":"127.0.0.1","port":"8081","hub":null,"logFile":"/tmp/webdriver.log","logLevel":"DEBUG","logColor":false}
[INFO  - 2016-05-05T20:51:10.579Z] GhostDriver - Main - running on port 8081
JavaScript strict warning: resource://gre/modules/ProfileAge.jsm, line 202: ReferenceError: reference to undefined property times.reset

And test error:

=======================================================================================
Selenium 2.0 / webdriver protocol bindings implementation with helper commands in nodejs.
For a complete list of commands, visit http://webdriver.io/docs.html.
=======================================================================================

[21:51:46]  COMMAND POST     "/wd/hub/session"
[21:51:46]  DATA        {"desiredCapabilities":{"javascriptEnabled":true,"locationContextEnabled":true,"handlesAlerts":true,"rotatable":true,"browserName":"phantomjs","maxInstances":1,"loggingPrefs":{"browser":"ALL","driver":"ALL"},"requestOrigins":{"url":"http://webdriver.io","version":"4.0.5","name":"webdriverio"}}}
ERROR: Bad request

phantomjs
    at new RuntimeError (/Users/dominik/dev/lightning-ui/node_modules/webdriverio/build/lib/utils/ErrorHandler.js:115:12)
    at Request._callback (/Users/dominik/dev/lightning-ui/node_modules/webdriverio/build/lib/utils/RequestHandler.js:241:32)
    at Request.self.callback (/Users/dominik/dev/lightning-ui/node_modules/webdriverio/node_modules/request/request.js:373:22)
    at emitTwo (events.js:87:13)
    at Request.emit (events.js:172:7)
    at Request.<anonymous> (/Users/dominik/dev/lightning-ui/node_modules/webdriverio/node_modules/request/request.js:1318:14)
    at emitOne (events.js:82:20)
    at Request.emit (events.js:169:7)
    at IncomingMessage.<anonymous> (/Users/dominik/dev/lightning-ui/node_modules/webdriverio/node_modules/request/request.js:1266:12)
    at emitNone (events.js:72:20)

It presents the error as phantomjs because webdriver-io is configured to connect to phantomjs runner:

capabilities: [{
  browserName: 'phantomjs',
  maxInstances: 1,
}],

This is the capability that SlimerJS is exposing. Probably because of that: https://github.com/laurentj/slimerjs/blob/master/src/vendors/ghostdriver/hub_register.js#L38 or that https://github.com/laurentj/slimerjs/blob/b0cae30b443a30153994110d66801901d641a1db/src/vendors/ghostdriver/session.js#L48