No more detailed error messages since 1.4.2 #64

m0ppers · 2015-06-10T10:29:03Z

I am using the webdriver in combination with behat. Since the release of 1.4.2 we are getting unusable error messages from the php web-driver

Example:

Feature: xxx

  Scenario: yyy                                  # features/test.feature:3
    Given I am on "http://dingo.local/hase.html" # FeatureContext::visit()
    When I press "b"                             # FeatureContext::pressButton()
      exception 'WebDriver\Exception\CurlExec' with message 'Curl error thrown for http POST to http://localhost:4444/wd/hub/session/93d71c50-df17-4c66-9c8e-86e4d5a7fd90/element/0/click

      The requested URL returned error: 500 Internal Server Error' in vendor/instaclick/php-webdriver/lib/WebDriver/Exception.php:155
      Stack trace:

This is not helpful at all. When i am locking the php-webdriver to 1.4.1 the same test does the following:

    When I press "b"                             # FeatureContext::pressButton()
      exception 'WebDriver\Exception\ElementNotVisible' with message 'Element is not currently visible and so may not be interacted with
      Build info: version: '2.45.0', revision: '5017cb8', time: '2015-02-26 23:59:50'
      System info: host: 'hans-guenther.local', ip: '192.168.10.118', os.name: 'Mac OS X', os.arch: 'x86_64', os.version: '10.10.3', java.version: '1.6.0_65'
      Driver info: driver.version: unknown' in vendor/instaclick/php-webdriver/lib/WebDriver/Exception.php:155
      Stack trace:

This is (my) desired result here.

I debugged a bit and can track down the error to this commit:

3b11d17

When removing this line everything is working again. I am not into the internals and don't know what problem that commit exactly solved but it makes debugging behat results nearly impossible as there are no error details at all anymore 🍶

The text was updated successfully, but these errors were encountered:

aik099 · 2015-06-10T10:43:27Z

The mentioned commit was part of #58 PR and it really does what it says it does: masks any WebDriver response with non 200 code as HTTP error response with not much details.

I personally prefer exception from underlying libraries (the WebDriver in this case) to bubble up so that you see exactly what went wrong instead of masking them with transport-layer (HTTP in this case) specific exceptions.

The easiest solution would be to revert mentioned commit, but I'm not sure what problem @gggeek was attempting to solve with it to be certain.

gggeek · 2015-06-10T12:12:06Z

Hello.
I do not remember the exact case (I can probably dig it out), but the problem we had was more or less that when communication with selenium was throwing errors for any reason, the errors were swallowed by webdriver.
This made it hard to troubleshoot problems in the communication with selenium or in the selenium configuration (eg. selenium behind a proxy), as they would appear to the test at hand as 'element not found in page' or such.

I am not very knowledgeable about the selenium protocol, but I would have expected selenium to return to the testing app any error of the type 'I can not execute your desired command' in other ways than via http error responses (this is a bit of a misfeature often implemented by designers of rest apis, where application errors and transport errors are mixed).

My fix was intended to not have any impact on any 'seleniun said that app or browser are misbehaving' error; if that is not the case, it can be rolled back and implemented in a better/safer way.

As for the bubbling/masking of exceptions: I fully agree with your general principle of bubbling up exceptions. In fact my fix intended to do just that: bubble up the faulty connection to selenium which was masked as 'element not found' error. It is just that the POV is reversed: the http layer sits below the the underlying libraries, not above :-D

gggeek · 2015-06-10T12:13:30Z

ps @m0ppers are you sure that your errors 500 are due to the element not being present in the page?

m0ppers · 2015-06-10T12:25:56Z

Yes:

<html>
    <body>
        <button style="display:none" id="b">bbb</button>
    </body>
</html>

This is a minimal, constructed testcase to reproduce the problem of not reporting the problem ;).

Just had a look at the spec:

https://w3c.github.io/webdriver/webdriver-spec.html#handling-errors

It seems they are using status code 500 to report back expected error messages like "out of bounds" etc. This seems wrong to me as well. 500 should be "wow something really unexpected is happening. Bailing out" whereas "element is not visible" is an expected error :s

maybe it is possible to distinguish between your proxy errors and expected webdriver errors?

gggeek · 2015-06-10T12:38:27Z

Aha, it starts to make sense.

The doc you linked to is better than the one I looked at (mentioned in the webdriver sources): https://code.google.com/p/selenium/wiki/JsonWireProtocol#Response_Status_Codes - from that one one could infer that selenium would send back an http-200 response with a json body with an error code in it, whereas reality is that selenium sends back a 4xx or 5xx response with a json body.

I'd say that, missing a hard rule, we can reach a reasonable separation between 4xx/5xx errors generated by selenium and unintentional ones with the following rule of thumb:

check that payload is json
check that it contains the 3 members: error, message, stracktrace (nb: these are already different between the 2 docs at hand...)

what do you think?

we would have to validate against different selenium versions of course, the oldest the merrier

aik099 · 2015-06-10T13:09:24Z

The https://github.com/instaclick/php-webdriver/blob/master/lib/WebDriver/Exception.php class actually transforms internal JSONWire protocol errors (0 - 34), that @gggeek mentioned to actual exceptions, that are thrown in https://github.com/instaclick/php-webdriver/blob/master/lib/WebDriver/AbstractWebDriver.php#L140.

Unfortunately it seems, that the internal JSON Wire error is also mapped to HTTP response code according to @m0ppers document. Before #58 merge it worked like a charm.

Maybe @gggeek was using CurlService directly or through SauceRest class and in there indeed the HTTP error should be reported. But not in case, when AbstractWebDriver is using it.

gggeek · 2015-06-10T13:57:43Z

Then I'd go for having CurlService throw exceptions on http errors (ie. keep it generic), and change AbstractWebDriver to catch the exceptions and properly decode them. Would you agree?

m0ppers · 2015-06-10T14:08:23Z

👍

robocoder · 2015-06-10T14:30:41Z

Sounds good. Can someone submit a PR? (I'm in meetings all day.)

gggeek · 2015-06-10T14:57:00Z

I can do, but most likely not before saturday

aik099 · 2015-06-10T15:34:36Z

👍 . If possible, then please also create a test to prove that this behavior (proper error is reported back) is working as well. I guess we need to mock both CurlService and SeleniumServer to make it happen.

gggeek · 2015-06-14T11:26:24Z

Here's the work in progress: https://github.com/gggeek/php-webdriver/tree/issue_57_bis.

It is not finished, but I thought you might want to validate the approach taken.

Besides the changes in the curl service, I am in the process of adding functional tests - no mock objects but rather a quick install of selenium + apache on Travis. In my opinion this gives more reliable results than plain unit tests when you have to debug http connetions between different apps.

aik099 · 2015-06-14T11:28:05Z

You can send PR anyway, but add [WIP] in front of it's title to indicate that it's not finished.

gggeek · 2015-06-15T09:46:29Z

PR sent.

The code has been reworked a bit. The changes are less intrusive now (no more throwing of exceptions on errors 4xx/5xx from Selenium to be caught immediately after, that is left as optional and is activated by the saucelabs client; the abstractwebdriver does instead more checking of the results).

There might be travis failures, as I introduced some changes to the Travis set up, but I know of no other way to debug Travis errors than to push to GitHub ;-)

gggeek · 2015-06-15T09:50:49Z

PS: side note: after a lot of reading and head scratching, it seems that the protocol described by the w3c (https://w3c.github.io/webdriver/webdriver-spec.html#the-webdriver-interface) is quite different from the one implemented by current selenium. And I changed my mind about it being more clear to understand - in fact it does not seem to correct the warts of the original, but gets even more obfuscated in its wording... :-O

gggeek · 2015-06-15T10:14:58Z

Ok, managed to appease Travis. Functional testing fully available now :-) It just has to be seen which version of Selenium to test against. Ideally we could pick a different selenium version for each php version, to get broader coverage...

robocoder · 2015-07-03T18:58:24Z

I finally got around to reviewing and leaving feedback on the PR.

WRT Selenium server versions, the php version is less of a concern that what Firefox version is installed since Selenium server releases lag behind Firefox updates. If we can't control which versions of Firefox+Selenium are installed for CI testing, then the tests have to be disabled.

gggeek · 2015-07-03T19:57:45Z

@robocoder thanks for the review, will apply changes. I can try to come up with a test matrix for Travis with different selenium versions (but Firefox is going to be harder). Any list of specific versions to start with?

aik099 · 2015-07-03T19:59:22Z

Travis allows you to install any firefox version you need. In worst case scenario we can use SauceLabs or BrowserStack free tier for open source projects to test on different browser versions.

gggeek · 2015-07-11T22:40:06Z

I have investigated the correspondence between Firefox versions and Selenium versions.
As per Selenium specs, it supports current FF ESR and previous FF ESR.

This currently means:
Selenium 2.46 (2015/6/4) ==> FF38ESR and FF31ESR.
The latter is the default one in Travis.

I can pin down these versions in travis.yml if you agree.

Otoh, I did not find a way to have different FF versions installed by Travis when doing a test matrix.
This means that we can run the tests against different php/selenium versions, but only one firefox.
Option a: only change the version of php, use a fixed version of selenium+ff
Option b: only change the version of php, use a fixed version of selenium but both ff and chrome (2 dimensional matrix)
Option c: use saucelabs instead => against how many selenium/browser combinations?

aik099 · 2015-07-12T07:53:43Z

Is this still relevant, because we reverted originally mentioned commit that was hiding the error message?

gggeek · 2015-07-12T10:25:43Z

@aik099 yes it is. The revert of my bad commit means that currently:

errors due to 'element not visible' and similar are correctly reported to the user
errors due to 'selenium not responding' are not flagged as such, and hard to troubleshoot

gggeek · 2015-07-12T10:27:33Z

ps: If what you meant otoh is to close issue #64 and keep open #67, I'm ok with it

gggeek mentioned this issue Jul 12, 2015

Issue 57 bis - Closes #64 #67

Merged

robocoder closed this as completed in 4f08bcd Jun 28, 2017

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

No more detailed error messages since 1.4.2 #64

No more detailed error messages since 1.4.2 #64

m0ppers commented Jun 10, 2015

aik099 commented Jun 10, 2015

gggeek commented Jun 10, 2015

gggeek commented Jun 10, 2015

m0ppers commented Jun 10, 2015

gggeek commented Jun 10, 2015

aik099 commented Jun 10, 2015

gggeek commented Jun 10, 2015

m0ppers commented Jun 10, 2015

robocoder commented Jun 10, 2015

gggeek commented Jun 10, 2015

aik099 commented Jun 10, 2015

gggeek commented Jun 14, 2015

aik099 commented Jun 14, 2015

gggeek commented Jun 15, 2015

gggeek commented Jun 15, 2015

gggeek commented Jun 15, 2015

robocoder commented Jul 3, 2015

gggeek commented Jul 3, 2015

aik099 commented Jul 3, 2015

gggeek commented Jul 11, 2015

aik099 commented Jul 12, 2015

gggeek commented Jul 12, 2015

gggeek commented Jul 12, 2015

No more detailed error messages since 1.4.2 #64

No more detailed error messages since 1.4.2 #64

Comments

m0ppers commented Jun 10, 2015

aik099 commented Jun 10, 2015

gggeek commented Jun 10, 2015

gggeek commented Jun 10, 2015

m0ppers commented Jun 10, 2015

gggeek commented Jun 10, 2015

aik099 commented Jun 10, 2015

gggeek commented Jun 10, 2015

m0ppers commented Jun 10, 2015

robocoder commented Jun 10, 2015

gggeek commented Jun 10, 2015

aik099 commented Jun 10, 2015

gggeek commented Jun 14, 2015

aik099 commented Jun 14, 2015

gggeek commented Jun 15, 2015

gggeek commented Jun 15, 2015

gggeek commented Jun 15, 2015

robocoder commented Jul 3, 2015

gggeek commented Jul 3, 2015

aik099 commented Jul 3, 2015

gggeek commented Jul 11, 2015

aik099 commented Jul 12, 2015

gggeek commented Jul 12, 2015

gggeek commented Jul 12, 2015