Incorrect error when unexpected alert open

[jugglinmike]

• Platform: GNU/Linux (Ubuntu 16.04)
• Firefox version: 53.0.2 (64-bit)
• GeckoDriver version: 0.16.1
• Selenium Python bindings version: 3.4.2

Given the following code, I would expect the final command to fail with an
error of type "unexpected alert open". Instead, the server responds with an
"unknown error" whose message states, "Failed to find value field".

Demo script:

from selenium import webdriver

browser = webdriver.Firefox()
browser.get('data:text/html,<h1>Hello world</h1><p>pasd</p>')
browser.execute_script('setTimeout(function() { alert("Hello"); }, 0);')

try:
    print browser.title()
finally:
    browser.quit()

GeckoDriver log (captured using option --log debug)

1495476768842	webdriver::httpapi	DEBUG	Creating routes
1495476768845	geckodriver	INFO	Listening on 127.0.0.1:34689
1495476769846	webdriver::server	DEBUG	→ POST /session {"capabilities": {"alwaysMatch": {"acceptInsecureCerts": true, "browserName": "firefox"}, "firstMatch": []}, "desiredCapabilities": {"acceptInsecureCerts": true, "browserName": "firefox"}}
1495476769846	geckodriver::capabilities	DEBUG	Trying to read firefox version from ini files
1495476769846	geckodriver::capabilities	DEBUG	Found version 53.0.2
1495476769904	geckodriver::marionette	INFO	Starting browser /usr/lib/firefox/firefox.sh with args ["-marionette"]
1495476770783	Marionette	DEBUG	Marionette enabled via command-line flag
1495476771995	Marionette	INFO	Listening on port 42295
1495476772012	geckodriver::marionette	DEBUG	Connected to Marionette on localhost:42295
1495476772024	Marionette	DEBUG	Accepted connection conn0 from 127.0.0.1:34246
1495476772038	Marionette	CONFIG	Matched capabilities: {"browserName":"firefox","browserVersion":"53.0.2","platformName":"linux","platformVersion":"4.8.0-49-generic","pageLoadStrategy":"normal","acceptInsecureCerts":true,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"rotatable":false,"specificationLevel":0,"moz:processID":646,"moz:profile":"/tmp/rust_mozprofile.AhEOclE0dONq","moz:accessibilityChecks":false}
1495476772039	Marionette	WARN	TLS certificate errors will be ignored for this session
1495476772399	webdriver::server	DEBUG	← 200 OK {"value": {"sessionId":"9c178a0f-f2e9-4606-bfde-0f13eeabef2d","capabilities":{"acceptInsecureCerts":true,"browserName":"firefox","browserVersion":"53.0.2","moz:accessibilityChecks":false,"moz:processID":646,"moz:profile":"/tmp/rust_mozprofile.AhEOclE0dONq","pageLoadStrategy":"normal","platformName":"linux","platformVersion":"4.8.0-49-generic","rotatable":false,"specificationLevel":0,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000}}}}
1495476772401	webdriver::server	DEBUG	→ POST /session/9c178a0f-f2e9-4606-bfde-0f13eeabef2d/url {"url": "data:text/html,<h1>Hello world</h1><p>pasd</p>", "sessionId": "9c178a0f-f2e9-4606-bfde-0f13eeabef2d"}
1495476772498	webdriver::server	DEBUG	← 200 OK {"value": {}}
1495476772499	webdriver::server	DEBUG	→ POST /session/9c178a0f-f2e9-4606-bfde-0f13eeabef2d/execute/sync {"sessionId": "9c178a0f-f2e9-4606-bfde-0f13eeabef2d", "args": [], "script": "setTimeout(function() { alert(\"Hello\"); }, 0);"}
1495476772516	webdriver::server	DEBUG	← 200 OK {"value":null}
1495476772518	webdriver::server	DEBUG	→ GET /session/9c178a0f-f2e9-4606-bfde-0f13eeabef2d/title 
1495476772554	webdriver::server	DEBUG	← 500 Internal Server Error {"value":{"error":"unknown error","message":"Failed to find value field","stacktrace":"stack backtrace:\n   0:           0x4fa94d - backtrace::backtrace::trace::h45ace4059cd74233\n   1:           0x4fae32 - backtrace::capture::Backtrace::new::hb5a725a088a2a2fc\n   2:           0x445fdf - geckodriver::marionette::MarionetteSession::response::hac27afe85c07f033\n   3:           0x443b14 - <geckodriver::marionette::MarionetteHandler as webdriver::server::WebDriverHandler<geckodriver::marionette::GeckoExtensionRoute>>::handle_command::hd89c5efbeb4c7cd5\n   4:           0x434e94 - webdriver::server::start::{{closure}}::h5e71183f67357de6\n   5:           0x408627 - std::panicking::try::do_call::h8c30e6af4c7f85af\n   6:           0x5b77fa - panic_unwind::__rust_maybe_catch_panic\n                        at /buildslave/rust-buildbot/slave/stable-dist-rustc-musl-linux/build/src/libpanic_unwind/lib.rs:98\n   7:           0x416e57 - <F as alloc::boxed::FnBox<A>>::call_box::h3f273b2445d78deb\n   8:           0x5b0014 - alloc::boxed::{{impl}}::call_once<(),()>\n                        at /buildslave/rust-buildbot/slave/stable-dist-rustc-musl-linux/build/src/liballoc/boxed.rs:624\n                         - std::sys_common::thread::start_thread\n                        at /buildslave/rust-buildbot/slave/stable-dist-rustc-musl-linux/build/src/libstd/sys_common/thread.rs:21\n                         - std::sys::imp::thread::{{impl}}::new::thread_start\n                        at /buildslave/rust-buildbot/slave/stable-dist-rustc-musl-linux/build/src/libstd/sys/unix/thread.rs:84"}}
1495476772557	webdriver::server	DEBUG	→ DELETE /session/9c178a0f-f2e9-4606-bfde-0f13eeabef2d 
1495476772567	Marionette	INFO	New connections will no longer be accepted
1495476772572	webdriver::server	DEBUG	Deleting session
1495476772572	geckodriver::marionette	DEBUG	Stopping browser process
1495476772587	webdriver::server	DEBUG	← 200 OK {"value": {}}

[AutomatedTester]

@jugglinmike I tried to recreate this with Nightly and I get

dburns in ~ λ export PATH=$PATH:/Users/dburns/development/mozilla-central/testing/geckodriver/target/release/
dburns in ~ λ export PATH=$PATH:/Users/dburns/development/mozilla-central/obj-ff-dbg.noindex/dist/Nightly.app/Contents/MacOS
dburns in ~ λ workon sel
(sel) dburns in ~ λ python
Python 2.7.13 (default, Jan  3 2017, 16:36:18)
[GCC 4.2.1 Compatible Apple LLVM 8.0.0 (clang-800.0.38)] on darwin
Type "help", "copyright", "credits" or "license" for more information.
>>> from selenium import webdriver
>>>
>>> browser = webdriver.Firefox()
>>> browser.get('data:text/html,<h1>Hello world</h1><p>pasd</p>')
>>> browser.execute_script('setTimeout(function() { alert("Hello"); }, 0);')
>>> print browser.title()
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "/Users/dburns/.virtualenvs/sel/lib/python2.7/site-packages/selenium/webdriver/remote/webdriver.py", line 273, in title
    resp = self.execute(Command.GET_TITLE)
  File "/Users/dburns/.virtualenvs/sel/lib/python2.7/site-packages/selenium/webdriver/remote/webdriver.py", line 252, in execute
    self.error_handler.check_response(response)
  File "/Users/dburns/.virtualenvs/sel/lib/python2.7/site-packages/selenium/webdriver/remote/errorhandler.py", line 194, in check_response
    raise exception_class(message, screen, stacktrace)
selenium.common.exceptions.UnexpectedAlertPresentException: Alert Text: None
Message:

>>> webdriver.__version__
'3.4.1'
>>>

[AutomatedTester]

I have tried it with 53.0.2 and get

dburns in ~ λ export PATH=$PATH:/Users/dburns/development/mozilla-central/testing/geckodriver/target/release/
dburns in ~ λ workon sel
(sel) dburns in ~ λ python
Python 2.7.13 (default, Jan  3 2017, 16:36:18)
[GCC 4.2.1 Compatible Apple LLVM 8.0.0 (clang-800.0.38)] on darwin
Type "help", "copyright", "credits" or "license" for more information.
>>> from selenium import webdriver
>>>
>>> browser = webdriver.Firefox()
>>> browser.get('data:text/html,<h1>Hello world</h1><p>pasd</p>')
>>> browser.execute_script('setTimeout(function() { alert("Hello"); }, 0);')
>>> print browser.title()
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
TypeError: 'unicode' object is not callable
>>> print browser.title

>>>

[AutomatedTester]

The lack of error with checking for title is because we didnt do prompt checks .

@jugglinmike since we can't reproduce, could you see if there is any missing information for us to look into this further.

[andreastt]

@jugglinmike Can you run this with -vv/--log trace? I suspect the issue here is that Marionette sends the wrong data format and that geckodriver is unable to deserialise it.

Also, would you mind testing with Nightly? As @AutomatedTester pointed out, the assert.noUserPrompt statements were added fairly recently, so they might not be in Firefox 53.

[jugglinmike]

@jugglinmike Can you run this with -vv/--log trace? I suspect the issue
here is that Marionette sends the wrong data format and that geckodriver is
unable to deserialise it.

Sure. Here's the log: https://gist.github.com/jugglinmike/e2e2ab580ccdcf3aaf7e6c1b52b2b70e

Also, would you mind testing with Nightly? As @AutomatedTester pointed out,
the assert.noUserPrompt statements were added fairly recently, so they
might not be in Firefox 53.

Running with 55.0a1 (2017-05-23) (64-bit), I receive the expected error:

Traceback (most recent call last):
  File "wd-unexpected-alert.py", line 10, in <module>
    print browser.title()
  File "/home/mike/.virtualenvs/wpt/local/lib/python2.7/site-packages/selenium/webdriver/remote/webdriver.py", line 273, in title
    resp = self.execute(Command.GET_TITLE)
  File "/home/mike/.virtualenvs/wpt/local/lib/python2.7/site-packages/selenium/webdriver/remote/webdriver.py", line 252, in execute
    self.error_handler.check_response(response)
  File "/home/mike/.virtualenvs/wpt/local/lib/python2.7/site-packages/selenium/webdriver/remote/errorhandler.py", line 194, in check_response
    raise exception_class(message, screen, stacktrace)
selenium.common.exceptions.UnexpectedAlertPresentException: Alert Text: None
Message: 

In light of the development schedule, this probably means that the issue may be
closed. I'll leave that to you folks, though, just in case the logs I've shared
are somehow relevant or in case there's any value in backporting this behavior.

Thanks for the quick response and the great tool :)

[AutomatedTester]

Going to close it and it will follow the trains. The patch that "fixed" this is a little hairy to uplift so we are not going to do this atm

[andreastt]

My suspicion was confirmed:

1495636453563	geckodriver::marionette	TRACE	← [1,4,null,{}]
1495636453564	webdriver::server	DEBUG	← 500 Internal Server Error {"value":{"error":"unknown error","message":"Failed to find value field","stacktrace":"stack backtrace:\n   0:           0x4fa94d - backtrace::backtrace::trace::h45ace4059cd74233\n   1:           0x4fae32 - backtrace::capture::Backtrace::new::hb5a725a088a2a2fc\n   2:           0x445fdf - geckodriver::marionette::MarionetteSession::response::hac27afe85c07f033\n   3:           0x443b14 - <geckodriver::marionette::MarionetteHandler as webdriver::server::WebDriverHandler<geckodriver::marionette::GeckoExtensionRoute>>::handle_command::hd89c5efbeb4c7cd5\n   4:           0x434e94 - webdriver::server::start::{{closure}}::h5e71183f67357de6\n   5:           0x408627 - std::panicking::try::do_call::h8c30e6af4c7f85af\n   6:           0x5b77fa - panic_unwind::__rust_maybe_catch_panic\n                        at /buildslave/rust-buildbot/slave/stable-dist-rustc-musl-linux/build/src/libpanic_unwind/lib.rs:98\n   7:           0x416e57 - <F as alloc::boxed::FnBox<A>>::call_box::h3f273b2445d78deb\n   8:           0x5b0014 - alloc::boxed::{{impl}}::call_once<(),()>\n                        at /buildslave/rust-buildbot/slave/stable-dist-rustc-musl-linux/build/src/liballoc/boxed.rs:624\n                         - std::sys_common::thread::start_thread\n                        at /buildslave/rust-buildbot/slave/stable-dist-rustc-musl-linux/build/src/libstd/sys_common/thread.rs:21\n                         - std::sys::imp::thread::{{impl}}::new::thread_start\n                        at /buildslave/rust-buildbot/slave/stable-dist-rustc-musl-linux/build/src/libstd/sys/unix/thread.rs:84"}}

Marionette sends back an empty JSON Object, {}, which geckodriver tries to get the value field from.

I’m not quite sure how GeckoDriver#getTitle is able to return that from https://searchfox.org/mozilla-central/rev/2933592c4a01b634ab53315ce2d0e43fccb82181/testing/marionette/driver.js#1040-1053, but it looks like the problem goes away if we check for a user prompt first. My best guess at this point is that assigning undefined to resp.body.value somehow gets serialised to {}.

Unfortunately we can’t uplift or backport a fix for this to Firefox 53 because it’s the release channel )-:

[lock]

This issue has been automatically locked since there has not been any recent activity after it was closed. If you have run into an issue you think is related, please open a new issue.