Closed Bug 1479014 Opened 7 years ago Closed 6 years ago

Intermittent /webdriver/tests/forward/user_prompts.py | test_handle_prompt_accept, test_ignore[capabilities0-alert] - setup error

Categories

(Remote Protocol :: Marionette, defect, P5)

Product:
Remote Protocol
Component:
Marionette
Version:
Version 3
Type:
defect

Tracking

(Not tracked)

Status:
RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

References

Details

(Keywords: intermittent-failure)

Filed by: ccoroiu [at] mozilla.com https://treeherder.mozilla.org/logviewer.html#?job_id=190542600&repo=autoland https://queue.taskcluster.net/v1/task/dOqiE9JKQpu_xS_JKIM-jg/runs/0/artifacts/public/logs/live_backing.log [task 2018-07-27T14:56:41.134Z] 14:56:41 INFO - STDOUT: tests/web-platform/tests/tools/webdriver/webdriver/client.py [task 2018-07-27T14:56:41.134Z] 14:56:41 INFO - STDOUT: :415: in start [task 2018-07-27T14:56:41.135Z] 14:56:41 INFO - STDOUT: value = self.send_command("POST", "session", body=body) [task 2018-07-27T14:56:41.136Z] 14:56:41 INFO - STDOUT: _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ [task 2018-07-27T14:56:41.137Z] 14:56:41 INFO - STDOUT: self = <Session (disconnected)>, method = 'POST', url = 'session' [task 2018-07-27T14:56:41.137Z] 14:56:41 INFO - STDOUT: body = {'capabilities': {'alwaysMatch': {'moz:firefoxOptions': {'binary': '/builds/worker/workspace/build/application/firefox...latform.test,www.web-platform.test,xn--n8j6ds53lwwkrqhv28a.web-platform.test'}}, 'unhandledPromptBehavior': 'accept'}}} [task 2018-07-27T14:56:41.138Z] 14:56:41 INFO - STDOUT: def send_command(self, method, url, body=None): [task 2018-07-27T14:56:41.173Z] 14:56:41 INFO - STDOUT: """ [task 2018-07-27T14:56:41.174Z] 14:56:41 INFO - STDOUT: Send a command to the remote end and validate its success. [task 2018-07-27T14:56:41.174Z] 14:56:41 INFO - STDOUT: [task 2018-07-27T14:56:41.175Z] 14:56:41 INFO - STDOUT: :param method: HTTP method to use in request. [task 2018-07-27T14:56:41.175Z] 14:56:41 INFO - STDOUT: :param uri: "Command part" of the HTTP request URL, [task 2018-07-27T14:56:41.175Z] 14:56:41 INFO - STDOUT: e.g. `window/rect`. [task 2018-07-27T14:56:41.176Z] 14:56:41 INFO - STDOUT: :param body: Optional body of the HTTP request. [task 2018-07-27T14:56:41.177Z] 14:56:41 INFO - STDOUT: [task 2018-07-27T14:56:41.178Z] 14:56:41 INFO - STDOUT: :return: `None` if the HTTP response body was empty, otherwise [task 2018-07-27T14:56:41.179Z] 14:56:41 INFO - STDOUT: the `value` field returned after parsing the response [task 2018-07-27T14:56:41.180Z] 14:56:41 INFO - STDOUT: body as JSON. [task 2018-07-27T14:56:41.180Z] 14:56:41 INFO - STDOUT: [task 2018-07-27T14:56:41.181Z] 14:56:41 INFO - STDOUT: :raises ValueError: If the response body does not contain a [task 2018-07-27T14:56:41.181Z] 14:56:41 INFO - STDOUT: `value` key. [task 2018-07-27T14:56:41.182Z] 14:56:41 INFO - STDOUT: :raises error.WebDriverException: If the remote end returns [task 2018-07-27T14:56:41.182Z] 14:56:41 INFO - STDOUT: an error. [task 2018-07-27T14:56:41.183Z] 14:56:41 INFO - STDOUT: """ [task 2018-07-27T14:56:41.184Z] 14:56:41 INFO - STDOUT: response = self.transport.send( [task 2018-07-27T14:56:41.184Z] 14:56:41 INFO - STDOUT: method, url, body, [task 2018-07-27T14:56:41.185Z] 14:56:41 INFO - STDOUT: encoder=protocol.Encoder, decoder=protocol.Decoder, [task 2018-07-27T14:56:41.185Z] 14:56:41 INFO - STDOUT: session=self) [task 2018-07-27T14:56:41.189Z] 14:56:41 INFO - STDOUT: [task 2018-07-27T14:56:41.190Z] 14:56:41 INFO - STDOUT: if response.status != 200: [task 2018-07-27T14:56:41.191Z] 14:56:41 INFO - STDOUT: err = error.from_response(response) [task 2018-07-27T14:56:41.192Z] 14:56:41 INFO - STDOUT: [task 2018-07-27T14:56:41.192Z] 14:56:41 INFO - STDOUT: if isinstance(err, error.SessionNotCreatedException): [task 2018-07-27T14:56:41.193Z] 14:56:41 INFO - STDOUT: # The driver could have already been deleted the session. [task 2018-07-27T14:56:41.194Z] 14:56:41 INFO - STDOUT: self.session_id = None [task 2018-07-27T14:56:41.195Z] 14:56:41 INFO - STDOUT: [task 2018-07-27T14:56:41.196Z] 14:56:41 INFO - STDOUT: > raise err [task 2018-07-27T14:56:41.197Z] 14:56:41 INFO - STDOUT: E UnknownErrorException: unknown error (500): connection refused [task 2018-07-27T14:56:41.198Z] 14:56:41 INFO - STDOUT: body = {'capabilities': {'alwaysMatch': {'moz:firefoxOptions': {'binary': '/builds/worker/workspace/build/application/firefox...latform.test,www.web-platform.test,xn--n8j6ds53lwwkrqhv28a.web-platform.test'}}, 'unhandledPromptBehavior': 'accept'}}} [task 2018-07-27T14:56:41.198Z] 14:56:41 INFO - STDOUT: err = <UnknownErrorException http_status=500> [task 2018-07-27T14:56:41.199Z] 14:56:41 INFO - STDOUT: method = 'POST' [task 2018-07-27T14:56:41.203Z] 14:56:41 INFO - STDOUT: response = <Response status=500 error=<UnknownErrorException http_status=500>> [task 2018-07-27T14:56:41.203Z] 14:56:41 INFO - STDOUT: self = <Session (disconnected)> [task 2018-07-27T14:56:41.204Z] 14:56:41 INFO - STDOUT: url = 'session' [task 2018-07-27T14:56:41.205Z] 14:56:41 INFO - STDOUT: tests/web-platform/tests/tools/webdriver/webdriver/client.py [task 2018-07-27T14:56:41.206Z] 14:56:41 INFO - STDOUT: :466: UnknownErrorException [task 2018-07-27T14:56:41.207Z] 14:56:41 INFO - STDOUT: =============================== warnings summary =============================== [task 2018-07-27T14:56:41.208Z] 14:56:41 INFO - STDOUT: <undetermined location> [task 2018-07-27T14:56:41.209Z] 14:56:41 INFO - STDOUT: Module already imported so cannot be rewritten: mozlog [task 2018-07-27T14:56:41.210Z] 14:56:41 INFO - STDOUT: -- Docs: http://doc.pytest.org/en/latest/warnings.html [task 2018-07-27T14:56:41.211Z] 14:56:41 INFO - STDOUT: =============== 15 passed, 1 warnings, 1 error in 111.68 seconds =============== [task 2018-07-27T14:56:41.215Z] 14:56:41 INFO - [task 2018-07-27T14:56:41.216Z] 14:56:41 INFO - TEST-UNEXPECTED-ERROR | /webdriver/tests/forward/user_prompts.py | test_handle_prompt_accept[capabilities0-alert] - setup error [task 2018-07-27T14:56:41.217Z] 14:56:41 INFO - capabilities = {'unhandledPromptBehavior': 'accept'} [task 2018-07-27T14:56:41.217Z] 14:56:41 INFO - configuration = {'capabilities': {'moz:firefoxOptions': {'binary': '/builds/worker/workspace/build/application/firefox/firefox', 'pref...b-platform.test,www.web-platform.test,xn--n8j6ds53lwwkrqhv28a.web-platform.test'}}}, 'host': '127.0.0.1', 'port': 4444} [task 2018-07-27T14:56:41.217Z] 14:56:41 INFO - request = <SubRequest 'session' for <Function 'test_handle_prompt_accept[capabilities0-alert]'>> [task 2018-07-27T14:56:41.217Z] 14:56:41 INFO - [task 2018-07-27T14:56:41.217Z] 14:56:41 INFO - def session(capabilities, configuration, request): [task 2018-07-27T14:56:41.218Z] 14:56:41 INFO - """Create and start a session for a test that does not itself test session creation. [task 2018-07-27T14:56:41.218Z] 14:56:41 INFO - [task 2018-07-27T14:56:41.218Z] 14:56:41 INFO - By default the session will stay open after each test, but we always try to start a [task 2018-07-27T14:56:41.218Z] 14:56:41 INFO - new one and assume that if that fails there is already a valid session. This makes it [task 2018-07-27T14:56:41.219Z] 14:56:41 INFO - possible to recover from some errors that might leave the session in a bad state, but [task 2018-07-27T14:56:41.219Z] 14:56:41 INFO - does not demand that we start a new session per test.""" [task 2018-07-27T14:56:41.219Z] 14:56:41 INFO - global _current_session [task 2018-07-27T14:56:41.219Z] 14:56:41 INFO - [task 2018-07-27T14:56:41.219Z] 14:56:41 INFO - # Update configuration capabilities with custom ones from the [task 2018-07-27T14:56:41.220Z] 14:56:41 INFO - # capabilities fixture, which can be set by tests [task 2018-07-27T14:56:41.220Z] 14:56:41 INFO - caps = copy.deepcopy(configuration["capabilities"]) [task 2018-07-27T14:56:41.220Z] 14:56:41 INFO - caps.update(capabilities) [task 2018-07-27T14:56:41.220Z] 14:56:41 INFO - caps = {"alwaysMatch": caps} [task 2018-07-27T14:56:41.220Z] 14:56:41 INFO - [task 2018-07-27T14:56:41.221Z] 14:56:41 INFO - # If there is a session with different capabilities active, end it now [task 2018-07-27T14:56:41.221Z] 14:56:41 INFO - if _current_session is not None and ( [task 2018-07-27T14:56:41.221Z] 14:56:41 INFO - caps != _current_session.requested_capabilities): [task 2018-07-27T14:56:41.221Z] 14:56:41 INFO - _current_session.end() [task 2018-07-27T14:56:41.221Z] 14:56:41 INFO - _current_session = None [task 2018-07-27T14:56:41.221Z] 14:56:41 INFO - [task 2018-07-27T14:56:41.222Z] 14:56:41 INFO - if _current_session is None: [task 2018-07-27T14:56:41.223Z] 14:56:41 INFO - _current_session = webdriver.Session( [task 2018-07-27T14:56:41.223Z] 14:56:41 INFO - configuration["host"], [task 2018-07-27T14:56:41.223Z] 14:56:41 INFO - configuration["port"], [task 2018-07-27T14:56:41.223Z] 14:56:41 INFO - capabilities=caps) [task 2018-07-27T14:56:41.223Z] 14:56:41 INFO - try: [task 2018-07-27T14:56:41.223Z] 14:56:41 INFO - > _current_session.start() [task 2018-07-27T14:56:41.223Z] 14:56:41 INFO - [task 2018-07-27T14:56:41.223Z] 14:56:41 INFO - capabilities = {'unhandledPromptBehavior': 'accept'} [task 2018-07-27T14:56:41.223Z] 14:56:41 INFO - caps = {'alwaysMatch': {'moz:firefoxOptions': {'binary': '/builds/worker/workspace/build/application/firefox/firefox', 'prefs...platform.test,www.web-platform.test,xn--n8j6ds53lwwkrqhv28a.web-platform.test'}}, 'unhandledPromptBehavior': 'accept'}} [task 2018-07-27T14:56:41.223Z] 14:56:41 INFO - configuration = {'capabilities': {'moz:firefoxOptions': {'binary': '/builds/worker/workspace/build/application/firefox/firefox', 'pref...b-platform.test,www.web-platform.test,xn--n8j6ds53lwwkrqhv28a.web-platform.test'}}}, 'host': '127.0.0.1', 'port': 4444} [task 2018-07-27T14:56:41.224Z] 14:56:41 INFO - request = <SubRequest 'session' for <Function 'test_handle_prompt_accept[capabilities0-alert]'>> [task 2018-07-27T14:56:41.224Z] 14:56:41 INFO - [task 2018-07-27T14:56:41.224Z] 14:56:41 INFO - tests/web-platform/tests/webdriver/tests/support/fixtures.py:212:
The log isn't that clear for me but as it looks like we get a "connection refused" failure during setup when creating the session. May have been a networking issue, or geckodriver not accepting connections? > [task 2018-07-27T14:56:41.197Z] 14:56:41 INFO - STDOUT: E UnknownErrorException: unknown error (500): connection refused > [task 2018-07-27T14:56:41.198Z] 14:56:41 INFO - STDOUT: body = {'capabilities': {'alwaysMatch': {'moz:firefoxOptions': {'binary': '/builds/worker/workspace/build/application/firefox...latform.test,www.web-platform.test,xn--n8j6ds53lwwkrqhv28a.web-platform.test'}}, 'unhandledPromptBehavior': 'accept'}}} > [task 2018-07-27T14:56:41.198Z] 14:56:41 INFO - STDOUT: err = <UnknownErrorException http_status=500> > [task 2018-07-27T14:56:41.199Z] 14:56:41 INFO - STDOUT: method = 'POST' > [task 2018-07-27T14:56:41.203Z] 14:56:41 INFO - STDOUT: response = <Response status=500 error=<UnknownErrorException http_status=500>> > [task 2018-07-27T14:56:41.203Z] 14:56:41 INFO - STDOUT: self = <Session (disconnected)> > [task 2018-07-27T14:56:41.204Z] 14:56:41 INFO - STDOUT: url = 'session'
Summary: Intermittent /webdriver/tests/forward/user_prompts.py | test_handle_prompt_accept[capabilities0-alert] - setup error → Intermittent /webdriver/tests/forward/user_prompts.py | test_handle_prompt_accept, test_ignore[capabilities0-alert] - setup error
This failure happens because there is no `sessionstore-windows-restored` notification sent for more than a minute: > INFO - PID 19194 | 1536907694879 geckodriver::marionette DEBUG Waiting 60s to connect to browser on 127.0.0.1:2828 > INFO - PID 19194 | 1536907696658 Marionette DEBUG Received observer notification profile-after-change > INFO - PID 19194 | 1536907696787 Marionette DEBUG Received observer notification command-line-startup > INFO - PID 19194 | 1536907696788 Marionette DEBUG Received observer notification nsPref:changed > INFO - PID 19194 | 1536907696788 Marionette DEBUG Init aborted (running=false, enabled=true, finalUIStartup=false) > INFO - PID 19194 | 1536907697156 Marionette DEBUG Received observer notification toplevel-window-ready > INFO - PID 19194 | 1536907754922 mozrunner::runner DEBUG Killing process 20162 > INFO - PID 19194 | 1536907754943 webdriver::server DEBUG <- 500 Internal Server Error {"value":{"error":"unknown error","message":"connection refused","stacktrace":""}}
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → INCOMPLETE
Moving bug to Remote Protocol::Marionette component per bug 1815831.
Component: geckodriver → Marionette
Product: Testing → Remote Protocol
You need to log in before you can comment on or make changes to this bug.