better error reporting needed

[individual-it]

I'm running tests with Mink on Saucelabs (Sauce Connect 4.4.6)
At some point tests with firefox started to fail with
Expected to be on "http://localhost/owncloud-core/index.php/login" but found "" instead (SensioLabs\Behat\PageObjectExtension\PageObject\Exception\UnexpectedPageException)

It took me a while and some network sniffing to find out that the Error Message send from Sauce Connect actually is:
The requested combination of browser, version and OS is unsupported by the requested Selenium version and would lead to a test failure. Please set a different Selenium version, or set none to get the default, working Selenium version for this platform: firefox 47.0. on Windows 2008 with Selenium 2.31.0

I had to set the selenium version. No idea why it did work automatically before. But a better error reporting on the console or log file would be good.
I did report this problem in MinkSelenium2Driver but was told the problem is in the PageObjectExtension, so I open this issue here

[jakzal]

@individual-it is this message actually returned in a page body?

[individual-it]

no, I only found the message looking into the network transfer and if I remember correctly it was in a HTTP return message. If you need I can try to reproduce it and send you a full network log

[jakzal]

Would be great, thanks!

Currently I'm not sure if we can do anything about it, especially if the error is only shown in sauselabs logs (like locally some errors are shown by selenium only in its console). We might not be able to retrieve the actual message.

[individual-it]

Without setting the selenium version is does not work.

very first HTTP request

POST /wd/hub/session HTTP/1.1
Authorization: Basic xxxxxxxxxxxxxxx=
Host: localhost:4445
Content-Type: application/json;charset=UTF-8
Accept: application/json;charset=UTF-8
Content-Length: 339

{"desiredCapabilities":{"browserName":"firefox","version":"47.0","platform":"","browserVersion":"9","browser":"firefox","name":" - ","deviceOrientation":"portrait","deviceType":"tablet","selenium-version":"2.31.0","tags":["localPC","PHP 7.1.5-1+0~20170522123046.25+jessie~1.gbpb8686b"],"maxDuration":"3600","ignoreZoomSetting":false}}

HTTP/1.1 404 Not Found
Transfer-Encoding: chunked
Date: Tue, 06 Jun 2017 15:02:21 GMT
Content-Type: text/plain
Server: monocle/0.38

123
The requested combination of browser, version and OS is unsupported by the requested Selenium version and would lead to a test failure. Please set a different Selenium version, or set none to get the default, working Selenium version for this platform: firefox 47.0. on  with Selenium 2.31.0
0

next request, actually trying to load the page:

POST /wd/hub/session/url HTTP/1.1
Authorization: Basic xxxxxxxxxxxxxxx=
Host: localhost:4445
Content-Type: application/json;charset=UTF-8
Accept: application/json;charset=UTF-8
Content-Length: 61

{"url":"http:\/\/localhost\/owncloud-core\/index.php\/login"}
HTTP/1.1 404 Not Found
Transfer-Encoding: chunked
Date: Tue, 06 Jun 2017 15:10:05 GMT
Content-Type: text/plain
Server: monocle/0.38

e6
ERROR The test with session id url has already finished, and can't receive further commands.
You can learn more at https://saucelabs.com/jobs/url
For help, please check https://wiki.saucelabs.com/display/DOCS/Common+Error+Messages
0

as you can see there is a 404 reply from saucelabs.
I wonder if the exception can be thrown already after the first 404 reply, and the error message being displayed

here is the full trace:

     SensioLabs\Behat\PageObjectExtension\PageObject\Exception\UnexpectedPageException: Expected to be on "http://localhost/owncloud-core/index.php/login" but found "" instead in /home/artur/www/owncloud-core/lib/composer/sensiolabs/behat-page-object-extension/src/SensioLabs/Behat/PageObjectExtension/PageObject/Page.php:217
      Stack trace:
      #0 /home/artur/www/owncloud-core/lib/composer/sensiolabs/behat-page-object-extension/src/SensioLabs/Behat/PageObjectExtension/PageObject/Page.php(186): SensioLabs\Behat\PageObjectExtension\PageObject\Page->verifyUrl(Array)
      #1 /home/artur/www/owncloud-core/lib/composer/sensiolabs/behat-page-object-extension/src/SensioLabs/Behat/PageObjectExtension/PageObject/Page.php(58): SensioLabs\Behat\PageObjectExtension\PageObject\Page->verify(Array)
      #2 /tmp/ProxyManagerGeneratedProxy__PM__PageLoginPageGeneratedb755cbf3bea1a48cfcd917422d91a2e8.php(134): SensioLabs\Behat\PageObjectExtension\PageObject\Page->open(Array)
      #3 /home/artur/www/owncloud-core/tests/ui/features/bootstrap/LoginContext.php(50): ProxyManagerGeneratedProxy\__PM__\Page\LoginPage\Generatedb755cbf3bea1a48cfcd917422d91a2e8->open()
      #4 [internal function]: LoginContext->iAmOnTheLoginPage()
      #5 /home/artur/www/owncloud-core/lib/composer/behat/behat/src/Behat/Testwork/Call/Handler/RuntimeCallHandler.php(103): call_user_func_array(Array, Array)
      #6 /home/artur/www/owncloud-core/lib/composer/behat/behat/src/Behat/Testwork/Call/Handler/RuntimeCallHandler.php(59): Behat\Testwork\Call\Handler\RuntimeCallHandler->executeCall(Object(Behat\Behat\Definition\Call\DefinitionCall))
      #7 /home/artur/www/owncloud-core/lib/composer/behat/behat/src/Behat/Testwork/Call/CallCenter.php(140): Behat\Testwork\Call\Handler\RuntimeCallHandler->handleCall(Object(Behat\Behat\Definition\Call\DefinitionCall))
      #8 /home/artur/www/owncloud-core/lib/composer/behat/behat/src/Behat/Testwork/Call/CallCenter.php(96): Behat\Testwork\Call\CallCenter->handleCall(Object(Behat\Behat\Definition\Call\DefinitionCall))
      #9 /home/artur/www/owncloud-core/lib/composer/behat/behat/src/Behat/Behat/Tester/Runtime/RuntimeStepTester.php(125): Behat\Testwork\Call\CallCenter->makeCall(Object(Behat\Behat\Definition\Call\DefinitionCall))
      #10 /home/artur/www/owncloud-core/lib/composer/behat/behat/src/Behat/Behat/Tester/Runtime/RuntimeStepTester.php(73): Behat\Behat\Tester\Runtime\RuntimeStepTester->testDefinition(Object(Behat\Behat\Context\Environment\InitializedContextEnvironment), Object(Behat\Gherkin\Node\FeatureNode), Object(Behat\Gherkin\Node\StepNode), Object(Behat\Behat\Definition\SearchResult), false)
      #11 /home/artur/www/owncloud-core/lib/composer/behat/behat/src/Behat/Behat/Hook/Tester/HookableStepTester.php(74): Behat\Behat\Tester\Runtime\RuntimeStepTester->test(Object(Behat\Behat\Context\Environment\InitializedContextEnvironment), Object(Behat\Gherkin\Node\FeatureNode), Object(Behat\Gherkin\Node\StepNode), false)
      #12 /home/artur/www/owncloud-core/lib/composer/behat/behat/src/Behat/Behat/EventDispatcher/Tester/TickingStepTester.php(59): Behat\Behat\Hook\Tester\HookableStepTester->test(Object(Behat\Behat\Context\Environment\InitializedContextEnvironment), Object(Behat\Gherkin\Node\FeatureNode), Object(Behat\Gherkin\Node\StepNode), false)
      #13 /home/artur/www/owncloud-core/lib/composer/behat/behat/src/Behat/Behat/EventDispatcher/Tester/EventDispatchingStepTester.php(73): Behat\Behat\EventDispatcher\Tester\TickingStepTester->test(Object(Behat\Behat\Context\Environment\InitializedContextEnvironment), Object(Behat\Gherkin\Node\FeatureNode), Object(Behat\Gherkin\Node\StepNode), false)
      #14 /home/artur/www/owncloud-core/lib/composer/behat/behat/src/Behat/Behat/Tester/StepContainerTester.php(59): Behat\Behat\EventDispatcher\Tester\EventDispatchingStepTester->test(Object(Behat\Behat\Context\Environment\InitializedContextEnvironment), Object(Behat\Gherkin\Node\FeatureNode), Object(Behat\Gherkin\Node\StepNode), false)
      #15 /home/artur/www/owncloud-core/lib/composer/behat/behat/src/Behat/Behat/Tester/Runtime/RuntimeScenarioTester.php(76): Behat\Behat\Tester\StepContainerTester->test(Object(Behat\Behat\Context\Environment\InitializedContextEnvironment), Object(Behat\Gherkin\Node\FeatureNode), Object(Behat\Gherkin\Node\ScenarioNode), false)
      #16 /home/artur/www/owncloud-core/lib/composer/behat/behat/src/Behat/Behat/Hook/Tester/HookableScenarioTester.php(74): Behat\Behat\Tester\Runtime\RuntimeScenarioTester->test(Object(Behat\Behat\Context\Environment\InitializedContextEnvironment), Object(Behat\Gherkin\Node\FeatureNode), Object(Behat\Gherkin\Node\ScenarioNode), false)
      #17 /home/artur/www/owncloud-core/lib/composer/behat/behat/src/Behat/Behat/EventDispatcher/Tester/EventDispatchingScenarioTester.php(103): Behat\Behat\Hook\Tester\HookableScenarioTester->test(Object(Behat\Behat\Context\Environment\InitializedContextEnvironment), Object(Behat\Gherkin\Node\FeatureNode), Object(Behat\Gherkin\Node\ScenarioNode), false)
      #18 /home/artur/www/owncloud-core/lib/composer/behat/behat/src/Behat/Behat/Tester/Runtime/IsolatingScenarioTester.php(69): Behat\Behat\EventDispatcher\Tester\EventDispatchingScenarioTester->test(Object(Behat\Behat\Context\Environment\InitializedContextEnvironment), Object(Behat\Gherkin\Node\FeatureNode), Object(Behat\Gherkin\Node\ScenarioNode), false)
      #19 /home/artur/www/owncloud-core/lib/composer/behat/behat/src/Behat/Behat/Tester/Runtime/RuntimeFeatureTester.php(84): Behat\Behat\Tester\Runtime\IsolatingScenarioTester->test(Object(Behat\Behat\Context\Environment\UninitializedContextEnvironment), Object(Behat\Gherkin\Node\FeatureNode), Object(Behat\Gherkin\Node\ScenarioNode), false)
      #20 /home/artur/www/owncloud-core/lib/composer/behat/behat/src/Behat/Behat/Hook/Tester/HookableFeatureTester.php(72): Behat\Behat\Tester\Runtime\RuntimeFeatureTester->test(Object(Behat\Behat\Context\Environment\UninitializedContextEnvironment), Object(Behat\Gherkin\Node\FeatureNode), false)
      #21 /home/artur/www/owncloud-core/lib/composer/behat/behat/src/Behat/Behat/EventDispatcher/Tester/EventDispatchingFeatureTester.php(71): Behat\Behat\Hook\Tester\HookableFeatureTester->test(Object(Behat\Behat\Context\Environment\UninitializedContextEnvironment), Object(Behat\Gherkin\Node\FeatureNode), false)
      #22 /home/artur/www/owncloud-core/lib/composer/behat/behat/src/Behat/Testwork/Tester/Runtime/RuntimeSuiteTester.php(63): Behat\Behat\EventDispatcher\Tester\EventDispatchingFeatureTester->test(Object(Behat\Behat\Context\Environment\UninitializedContextEnvironment), Object(Behat\Gherkin\Node\FeatureNode), false)
      #23 /home/artur/www/owncloud-core/lib/composer/behat/behat/src/Behat/Testwork/Hook/Tester/HookableSuiteTester.php(73): Behat\Testwork\Tester\Runtime\RuntimeSuiteTester->test(Object(Behat\Behat\Context\Environment\UninitializedContextEnvironment), Object(Behat\Testwork\Specification\GroupedSpecificationIterator), false)
      #24 /home/artur/www/owncloud-core/lib/composer/behat/behat/src/Behat/Testwork/EventDispatcher/Tester/EventDispatchingSuiteTester.php(72): Behat\Testwork\Hook\Tester\HookableSuiteTester->test(Object(Behat\Behat\Context\Environment\UninitializedContextEnvironment), Object(Behat\Testwork\Specification\GroupedSpecificationIterator), false)
      #25 /home/artur/www/owncloud-core/lib/composer/behat/behat/src/Behat/Testwork/Tester/Runtime/RuntimeExercise.php(71): Behat\Testwork\EventDispatcher\Tester\EventDispatchingSuiteTester->test(Object(Behat\Behat\Context\Environment\UninitializedContextEnvironment), Object(Behat\Testwork\Specification\GroupedSpecificationIterator), false)
      #26 /home/artur/www/owncloud-core/lib/composer/behat/behat/src/Behat/Testwork/EventDispatcher/Tester/EventDispatchingExercise.php(70): Behat\Testwork\Tester\Runtime\RuntimeExercise->test(Array, false)
      #27 /home/artur/www/owncloud-core/lib/composer/behat/behat/src/Behat/Testwork/Ordering/OrderedExercise.php(80): Behat\Testwork\EventDispatcher\Tester\EventDispatchingExercise->test(Array, false)
      #28 /home/artur/www/owncloud-core/lib/composer/behat/behat/src/Behat/Testwork/Tester/Cli/ExerciseController.php(149): Behat\Testwork\Ordering\OrderedExercise->test(Array, false)
      #29 /home/artur/www/owncloud-core/lib/composer/behat/behat/src/Behat/Testwork/Tester/Cli/ExerciseController.php(108): Behat\Testwork\Tester\Cli\ExerciseController->testSpecifications(Object(Symfony\Component\Console\Input\ArgvInput), Array)
      #30 /home/artur/www/owncloud-core/lib/composer/behat/behat/src/Behat/Testwork/Cli/Command.php(63): Behat\Testwork\Tester\Cli\ExerciseController->execute(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
      #31 /home/artur/www/owncloud-core/lib/composer/symfony/console/Command/Command.php(262): Behat\Testwork\Cli\Command->execute(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
      #32 /home/artur/www/owncloud-core/lib/composer/symfony/console/Application.php(826): Symfony\Component\Console\Command\Command->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
      #33 /home/artur/www/owncloud-core/lib/composer/symfony/console/Application.php(189): Symfony\Component\Console\Application->doRunCommand(Object(Behat\Testwork\Cli\Command), Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
      #34 /home/artur/www/owncloud-core/lib/composer/behat/behat/src/Behat/Testwork/Cli/Application.php(124): Symfony\Component\Console\Application->doRun(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
      #35 /home/artur/www/owncloud-core/lib/composer/symfony/console/Application.php(120): Behat\Testwork\Cli\Application->doRun(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
      #36 /home/artur/www/owncloud-core/lib/composer/behat/behat/bin/behat(34): Symfony\Component\Console\Application->run()
      #37 {main}

a request with selenium version set it does work

POST /wd/hub/session HTTP/1.1
Authorization: Basic xxxxxxxxxxxxxx=
Host: localhost:4445
Content-Type: application/json;charset=UTF-8
Accept: application/json;charset=UTF-8
Content-Length: 366

{"desiredCapabilities":{"browserName":"firefox","version":"47.0","platform":"","browserVersion":"9","browser":"firefox","name":" - ","deviceOrientation":"portrait","deviceType":"tablet","selenium-version":"2.31.0","tags":["localPC","PHP 7.1.5-1+0~20170522123046.25+jessie~1.gbpb8686b"],"seleniumVersion":"2.53.1","maxDuration":"3600","ignoreZoomSetting":false}}HTTP/1.1 200 OK
Transfer-Encoding: chunked
Date: Tue, 06 Jun 2017 15:06:17 GMT
Content-Type: application/json;charset=UTF-8
Server: monocle/0.38

258
{"status": 0, "sessionId": "7c71f1763ab945138191e3ae87079ace", "value": {"rotatable": false, "takesScreenshot": true, "acceptSslCerts": true, "cssSelectorsEnabled": true, "javascriptEnabled": true, "webdriver.remote.sessionid": "7c71f1763ab945138191e3ae87079ace", "databaseEnabled": true, "locationContextEnabled": true, "platform": "WINDOWS", "browserName": "firefox", "version": "47.0.1", "hasMetadata": true, "nativeEvents": false, "applicationCacheEnabled": true, "webStorageEnabled": true, "handlesAlerts": true}, "state": null, "hCode": 19076627, "class": "org.openqa.selenium.remote.Response"}
0

POST /wd/hub/session/7c71f1763ab945138191e3ae87079ace/url HTTP/1.1
Authorization: Basic xxxxxxxx=
Host: localhost:4445
Content-Type: application/json;charset=UTF-8
Accept: application/json;charset=UTF-8
Content-Length: 61

{"url":"http:\/\/localhost\/owncloud-core\/index.php\/login"}HTTP/1.1 200 OK
Transfer-Encoding: chunked
Date: Tue, 06 Jun 2017 15:06:25 GMT
Content-Type: application/json;charset=UTF-8
Server: monocle/0.38

a4
{"status": 0, "sessionId": "7c71f1763ab945138191e3ae87079ace", "value": null, "state": "success", "hCode": 19248061, "class": "org.openqa.selenium.remote.Response"}
0

[jakzal]

This is useful. What's the status code of the first POST /wd/hub/session (notice the session id is missing, so mink doesn't seem to be validating it)?

To me it looks like starting the session fails but, mink doesn't raise an exception and carries on.

[individual-it]

its HTTP/1.1 404 Not Found sorry the line-break was not in place.

yes some part of the code gets the 404 but does not react on it. Do you think its a Mink problem?

[jakzal]

Perhaps it's a problem with https://github.com/instaclick/php-webdriver

[individual-it]

what to do? report there?
I could open an issue there, but you might be able to give better comments as you are surly deeper into it

[jakzal]

imo the best thing to do would be to reproduce the issue with webdriver alone, and then report it to them or possibly fix it :)

I only had a brief look, but looks like the session id is empty after calling session() on the webdriver, and I don't think such a situation should be allowed. I might be wrong though.

[bartonhammond]

@individual-it What tool did you use for network sniffing?

[individual-it]

@bartonhammond it must have been wireshark, because that's what I'm always using

[bartonhammond]

@individual-it I installed wireshark and tried it. I don't see any HTTP requests. I capture events only when running the command line "vendor/bin/behat". As soon as the test fails, which is quick, I stop the capture. I guess I don't know what to look for. I'm suspecting that I'm not even making the request.

[jakzal]

@bartonhammond the actuall request is not made via behat, but the webdriver if this helps

[aik099]

I've checked and the instaclick/php-webdriver package is now considering any 4xx HTTP response as an error and throws an exception using this code:

throw WebDriverException::factory(
    WebDriverException::CURL_EXEC,
    'Webdriver http error: ' . $httpCode . ', payload :' . substr($rawResult, 0, 1000)
);

@individual-it , now you should be getting a proper error, when Sauce Labs wasn't able to start the session due to the impossible os/browser combination given.

[jakzal]

@aik099 if you wait long enough, the problem solves itself... 😂