Error message when New Session failed lacks information

[shs96c]

In order to help us efficiently investigate your issue, please provide the following information:

Platform and application details

• Platform: OSX
• Firefox: 56.0a1 (2017-07-19) (64-bit)
• Selenium: 036b87c80b2f31808c628f21d07dbec965f2df70

Steps to reproduce

• Reproducable testcase:

Capabilities caps = new FirefoxOptions().setBinary("I like cheese").addTo(DesiredCapabilities.firefox());
    WebDriver driver = new RemoteWebDriver(
        new URL("http://localhost:4444/"),
        caps);

A SessionNotCreatedException is thrown (as expected), but the error message is simply:

Unable to find a matching set of capabilities

The only thing wrong with the payload is that the binary does not exist. This is detected by geckodriver, but not reported, which makes debugging hard.

In general, it would be useful if there was some indication of which parts of the New Session payload caused the match to fail, even if it's just the first failed match or failure of validation.

• A trace level log:

1500592410938	geckodriver	INFO	geckodriver 0.18.0 ( '5f44d10bacca'  '2017-07-16 09:18 -0700')
1500592410939	webdriver::httpapi	DEBUG	Creating routes
1500592410946	geckodriver	INFO	Listening on 127.0.0.1:4444
1500592417240	webdriver::server	DEBUG	-> POST /session {
  "desiredCapabilities": {
    "firefox_binary": "I like cheese",
    "acceptInsecureCerts": true,
    "browserName": "firefox",
    "moz:firefoxOptions": {
      "binary": "I like cheese",
      "prefs": {},
      "args": []
    },
    "version": "",
    "platform": "ANY"
  },
  "requiredCapabilities": {},
  "capabilities": {
    "desiredCapabilities": {
      "firefox_binary": "I like cheese",
      "acceptInsecureCerts": true,
      "browserName": "firefox",
      "moz:firefoxOptions": {
        "binary": "I like cheese",
        "prefs": {},
        "args": []
      },
      "version": "",
      "platform": "ANY"
    },
    "requiredCapabilities": {},
    "alwaysMatch": {
      "acceptInsecureCerts": true
    },
    "firstMatch": [
      {
        "browserName": "firefox",
        "moz:firefoxOptions": {
          "binary": "I like cheese",
          "prefs": {},
          "args": []
        }
      }
    ]
  }
}
1500592417399	geckodriver::capabilities	DEBUG	Trying to read firefox version from ini files
1500592417400	geckodriver::capabilities	DEBUG	Trying to read firefox version from binary
1500592417402	geckodriver::capabilities	DEBUG	Failed to get binary version
1500592417406	webdriver::server	DEBUG	<- 500 Internal Server Error {"value":{"error":"session not created","message":"Unable to find a matching set of capabilities","stacktrace":"stack backtrace:\n   0:        0x10f32d81e - backtrace::backtrace::trace<closure>\n                        at /Users/shs/src/mozilla-central/third_party/rust/backtrace/src/backtrace/mod.rs:42\n   1:        0x10f32d9bc - backtrace::capture::Backtrace::new::h23089c033eded8f0\n                        at /Users/shs/src/mozilla-central/third_party/rust/backtrace/src/capture.rs:64\n   2:        0x10f2c42cf - geckodriver::marionette::{{impl}}::create_connection\n                        at /Users/shs/src/mozilla-central/third_party/rust/webdriver/src/error.rs:232\n   3:        0x10f2cc0c5 - geckodriver::marionette::{{impl}}::handle_command\n                        at /Users/shs/src/mozilla-central/testing/geckodriver/src/marionette.rs:520\n   4:        0x10f2c020c - webdriver::server::start::{{closure}}<geckodriver::marionette::MarionetteHandler,geckodriver::marionette::GeckoExtensionRoute>\n                        at /Users/shs/src/mozilla-central/third_party/rust/webdriver/src/server.rs:65\n   5:        0x10f286e9d - std::panicking::try::do_call<std::panic::AssertUnwindSafe<closure>,()>\n                        at /private/tmp/rust-20170612-28767-g1b3at/rustc-1.18.0-src/src/libstd/panicking.rs:454\n   6:        0x10f44a9ba - __rust_maybe_catch_panic\n                        at /private/tmp/rust-20170612-28767-g1b3at/rustc-1.18.0-src/src/libpanic_unwind/lib.rs:98\n   7:        0x10f296f1c - alloc::boxed::{{impl}}::call_box<(),closure>\n                        at /private/tmp/rust-20170612-28767-g1b3at/rustc-1.18.0-src/src/libstd/panicking.rs:433\n   8:        0x10f446b84 - std::sys::imp::thread::{{impl}}::new::thread_start\n                        at /private/tmp/rust-20170612-28767-g1b3at/rustc-1.18.0-src/src/libstd/sys_common/thread.rs:21\n   9:     0x7fffb899f93a - _pthread_body\n  10:     0x7fffb899f886 - _pthread_start"}}

As can be seen, this returns when the trace indicates that the binary cannot be found --- invaluable information when debugging.

[jgraham]

Yeah, this is a known problem. I've discussed it before with @andreastt and I think we know what to do, but it's a little work to fix.

The problem is that because there are multiple possible matching capabilities sets, we need to collect the errors that stopped each one matching. That means changing some of the traits for handling capabilities matching to return something like a Result<(), Vec[String]> (or some kind of error enum) rather than an Option<()> (or whatever the current return type is). Then when we finally fail to match anything, we need to turn the list of error strings into a useful message. So it's not really hard, but there's a little plumbing that makes it not quite trivial to fix.

If anyone wants to have a go at this, I would be happy to mentor.

[jgraham]

Yeah, this is a known problem. I've discussed it before with @andreastt and I think we know what to do, but it's a little work to fix.

The problem is that because there are multiple possible matching capabilities sets, we need to collect the errors that stopped each one matching. That means changing some of the traits for handling capabilities matching to return something like a Result<(), Vec[String]> (or some kind of error enum) rather than an Option<()> (or whatever the current return type is). Then when we finally fail to match anything, we need to turn the list of error strings into a useful message. So it's not really hard, but there's a little plumbing that makes it not quite trivial to fix.

If anyone wants to have a go at this, I would be happy to mentor.

[shs96c]

My reading of the algorithm in the spec is that you can stop the moment there's something that doesn't match --- as a temporary first step, it would be useful to just return that first error.

[shs96c]

My reading of the algorithm in the spec is that you can stop the moment there's something that doesn't match --- as a temporary first step, it would be useful to just return that first error.

[whimboo]

Btw I filed bug 1410838 a couple days ago. Nearly missed this existent issue.

[whimboo]

Btw I filed bug 1410838 a couple days ago. Nearly missed this existent issue.

[NormanEdance]

No updates? Workarounds?

[NormanEdance]

No updates? Workarounds?