1485482 - Intermittent /webdriver/tests/actions/sequence.py | test_release_char_sequence_sends_keyup_events_in_reverse - setup error

Status: RESOLVED DUPLICATE of bug 1482029

(Remote Protocol :: Marionette, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: cbrindusan [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=195357417&repo=mozilla-central

https://queue.taskcluster.net/v1/task/Q2-oeeUDQ5i7sOw4QBQzWg/runs/0/artifacts/public/logs/live_backing.log

[task 2018-08-22T19:11:22.071Z] 19:11:22     INFO - TEST-PASS | /webdriver/tests/actions/sequence.py | test_no_actions_send_no_events 
[task 2018-08-22T19:11:22.072Z] 19:11:22     INFO - TEST-UNEXPECTED-ERROR | /webdriver/tests/actions/sequence.py | test_release_char_sequence_sends_keyup_events_in_reverse - setup error
[task 2018-08-22T19:11:22.072Z] 19:11:22     INFO - session = <Session d8b4817e-9b3a-47d8-b5d1-405929996441>
[task 2018-08-22T19:11:22.072Z] 19:11:22     INFO - test_actions_page = None
[task 2018-08-22T19:11:22.073Z] 19:11:22     INFO - request = <SubRequest 'key_reporter' for <Function 'test_release_char_sequence_sends_keyup_events_in_reverse'>>
[task 2018-08-22T19:11:22.073Z] 19:11:22     INFO - 
[task 2018-08-22T19:11:22.073Z] 19:11:22     INFO -     @pytest.fixture
[task 2018-08-22T19:11:22.074Z] 19:11:22     INFO -     def key_reporter(session, test_actions_page, request):
[task 2018-08-22T19:11:22.074Z] 19:11:22     INFO -         """Represents focused input element from `test_keys_page` fixture."""
[task 2018-08-22T19:11:22.074Z] 19:11:22     INFO - >       input_el = session.find.css("#keys", all=False)
[task 2018-08-22T19:11:22.074Z] 19:11:22     INFO - 
[task 2018-08-22T19:11:22.075Z] 19:11:22     INFO - request    = <SubRequest 'key_reporter' for <Function 'test_release_char_sequence_sends_keyup_events_in_reverse'>>
[task 2018-08-22T19:11:22.075Z] 19:11:22     INFO - session    = <Session d8b4817e-9b3a-47d8-b5d1-405929996441>
[task 2018-08-22T19:11:22.075Z] 19:11:22     INFO - test_actions_page = None
[task 2018-08-22T19:11:22.075Z] 19:11:22     INFO - 
[task 2018-08-22T19:11:22.075Z] 19:11:22     INFO - tests/web-platform/tests/webdriver/tests/actions/conftest.py:27: 
[task 2018-08-22T19:11:22.075Z] 19:11:22     INFO - _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
[task 2018-08-22T19:11:22.076Z] 19:11:22     INFO - tests/web-platform/tests/tools/webdriver/webdriver/client.py:20: in inner
[task 2018-08-22T19:11:22.076Z] 19:11:22     INFO -     return func(self, *args, **kwargs)
[task 2018-08-22T19:11:22.076Z] 19:11:22     INFO - tests/web-platform/tests/tools/webdriver/webdriver/client.py:312: in css
[task 2018-08-22T19:11:22.076Z] 19:11:22     INFO -     return self._find_element("css selector", selector, all)
[task 2018-08-22T19:11:22.077Z] 19:11:22     INFO - tests/web-platform/tests/tools/webdriver/webdriver/client.py:318: in _find_element
[task 2018-08-22T19:11:22.077Z] 19:11:22     INFO -     return self.session.send_session_command("POST", route, body)
[task 2018-08-22T19:11:22.078Z] 19:11:22     INFO - tests/web-platform/tests/tools/webdriver/webdriver/client.py:509: in send_session_command
[task 2018-08-22T19:11:22.078Z] 19:11:22     INFO -     return self.send_command(method, url, body)
[task 2018-08-22T19:11:22.078Z] 19:11:22     INFO - _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
[task 2018-08-22T19:11:22.078Z] 19:11:22     INFO - 
[task 2018-08-22T19:11:22.078Z] 19:11:22     INFO - self = <Session d8b4817e-9b3a-47d8-b5d1-405929996441>, method = 'POST'
[task 2018-08-22T19:11:22.078Z] 19:11:22     INFO - url = 'session/d8b4817e-9b3a-47d8-b5d1-405929996441/element'
[task 2018-08-22T19:11:22.079Z] 19:11:22     INFO - body = {'using': 'css selector', 'value': '#keys'}
[task 2018-08-22T19:11:22.079Z] 19:11:22     INFO - 
[task 2018-08-22T19:11:22.079Z] 19:11:22     INFO -     def send_command(self, method, url, body=None):
[task 2018-08-22T19:11:22.079Z] 19:11:22     INFO -         """
[task 2018-08-22T19:11:22.079Z] 19:11:22     INFO -             Send a command to the remote end and validate its success.
[task 2018-08-22T19:11:22.079Z] 19:11:22     INFO -     
[task 2018-08-22T19:11:22.080Z] 19:11:22     INFO -             :param method: HTTP method to use in request.
[task 2018-08-22T19:11:22.080Z] 19:11:22     INFO -             :param uri: "Command part" of the HTTP request URL,
[task 2018-08-22T19:11:22.080Z] 19:11:22     INFO -                 e.g. `window/rect`.
[task 2018-08-22T19:11:22.080Z] 19:11:22     INFO -             :param body: Optional body of the HTTP request.
[task 2018-08-22T19:11:22.080Z] 19:11:22     INFO -     
[task 2018-08-22T19:11:22.081Z] 19:11:22     INFO -             :return: `None` if the HTTP response body was empty, otherwise
[task 2018-08-22T19:11:22.081Z] 19:11:22     INFO -                 the `value` field returned after parsing the response
[task 2018-08-22T19:11:22.081Z] 19:11:22     INFO -                 body as JSON.
[task 2018-08-22T19:11:22.082Z] 19:11:22     INFO -     
[task 2018-08-22T19:11:22.082Z] 19:11:22     INFO -             :raises error.WebDriverException: If the remote end returns
[task 2018-08-22T19:11:22.082Z] 19:11:22     INFO -                 an error.
[task 2018-08-22T19:11:22.082Z] 19:11:22     INFO -             :raises ValueError: If the response body does not contain a
[task 2018-08-22T19:11:22.082Z] 19:11:22     INFO -                 `value` key.
[task 2018-08-22T19:11:22.083Z] 19:11:22     INFO -             """
[task 2018-08-22T19:11:22.083Z] 19:11:22     INFO -         response = self.transport.send(
[task 2018-08-22T19:11:22.083Z] 19:11:22     INFO -             method, url, body,
[task 2018-08-22T19:11:22.083Z] 19:11:22     INFO -             encoder=protocol.Encoder, decoder=protocol.Decoder,
[task 2018-08-22T19:11:22.083Z] 19:11:22     INFO -             session=self)
[task 2018-08-22T19:11:22.084Z] 19:11:22     INFO -     
[task 2018-08-22T19:11:22.084Z] 19:11:22     INFO -         if response.status != 200:
[task 2018-08-22T19:11:22.084Z] 19:11:22     INFO -             err = error.from_response(response)
[task 2018-08-22T19:11:22.084Z] 19:11:22     INFO -     
[task 2018-08-22T19:11:22.085Z] 19:11:22     INFO -             if isinstance(err, error.InvalidSessionIdException):
[task 2018-08-22T19:11:22.085Z] 19:11:22     INFO -                 # The driver could have already been deleted the session.
[task 2018-08-22T19:11:22.085Z] 19:11:22     INFO -                 self.session_id = None
[task 2018-08-22T19:11:22.085Z] 19:11:22     INFO -     
[task 2018-08-22T19:11:22.087Z] 19:11:22     INFO - >           raise err
[task 2018-08-22T19:11:22.088Z] 19:11:22     INFO - E           UnknownErrorException: unknown error (500): Failed to convert data to an object
[task 2018-08-22T19:11:22.088Z] 19:11:22     INFO - 
[task 2018-08-22T19:11:22.088Z] 19:11:22     INFO - body       = {'using': 'css selector', 'value': '#keys'}
[task 2018-08-22T19:11:22.088Z] 19:11:22     INFO - err        = <UnknownErrorException http_status=500>
[task 2018-08-22T19:11:22.088Z] 19:11:22     INFO - method     = 'POST'
[task 2018-08-22T19:11:22.089Z] 19:11:22     INFO - response   = <Response status=500 error=<UnknownErrorException http_status=500>>
[task 2018-08-22T19:11:22.089Z] 19:11:22     INFO - self       = <Session d8b4817e-9b3a-47d8-b5d1-405929996441>
[task 2018-08-22T19:11:22.089Z] 19:11:22     INFO - url        = 'session/d8b4817e-9b3a-47d8-b5d1-405929996441/element'
[task 2018-08-22T19:11:22.090Z] 19:11:22     INFO - 
[task 2018-08-22T19:11:22.090Z] 19:11:22     INFO - tests/web-platform/tests/tools/webdriver/webdriver/client.py:473: UnknownErrorException
[task 2018-08-22T19:11:22.090Z] 19:11:22     INFO - 
[task 2018-08-22T19:11:22.091Z] 19:11:22     INFO - TEST-UNEXPECTED-ERROR | /webdriver/tests/actions/sequence.py | test_release_char_sequence_sends_keyup_events_in_reverse - teardown error
[task 2018-08-22T19:11:22.091Z] 19:11:22     INFO - self = <webdriver.client.Actions object at 0x7fbe02c31810>, args = ()
[task 2018-08-22T19:11:22.091Z] 19:11:22     INFO - kwargs = {}, session = <Session daf811c0-4ce5-4268-90fb-49dd8a370906>
[task 2018-08-22T19:11:22.091Z] 19:11:22     INFO - 
[task 2018-08-22T19:11:22.092Z] 19:11:22     INFO -     def inner(self, *args, **kwargs):
[task 2018-08-22T19:11:22.092Z] 19:11:22     INFO -         if hasattr(self, "session"):
[task 2018-08-22T19:11:22.092Z] 19:11:22     INFO -             session = self.session
[task 2018-08-22T19:11:22.093Z] 19:11:22     INFO -         else:
[task 2018-08-22T19:11:22.093Z] 19:11:22     INFO -             session = self
[task 2018-08-22T19:11:22.094Z] 19:11:22     INFO -     
[task 2018-08-22T19:11:22.094Z] 19:11:22     INFO -         if session.session_id is None:
[task 2018-08-22T19:11:22.095Z] 19:11:22     INFO -             session.start()
[task 2018-08-22T19:11:22.095Z] 19:11:22     INFO -     
[task 2018-08-22T19:11:22.096Z] 19:11:22     INFO - >       return func(self, *args, **kwargs)
[task 2018-08-22T19:11:22.096Z] 19:11:22     INFO - 
[task 2018-08-22T19:11:22.096Z] 19:11:22     INFO - args       = ()
[task 2018-08-22T19:11:22.097Z] 19:11:22     INFO - func       = <function release at 0x7fbe02cd1500>
[task 2018-08-22T19:11:22.097Z] 19:11:22     INFO - kwargs     = {}
[task 2018-08-22T19:11:22.098Z] 19:11:22     INFO - self       = <webdriver.client.Actions object at 0x7fbe02c31810>
[task 2018-08-22T19:11:22.098Z] 19:11:22     INFO - session    = <Session daf811c0-4ce5-4268-90fb-49dd8a370906>
[task 2018-08-22T19:11:22.098Z] 19:11:22     INFO - 
[task 2018-08-22T19:11:22.098Z] 19:11:22     INFO - tests/web-platform/tests/tools/webdriver/webdriver/client.py:20: 
[task 2018-08-22T19:11:22.098Z] 19:11:22     INFO - _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
[task 2018-08-22T19:11:22.098Z] 19:11:22     INFO - tests/web-platform/tests/tools/webdriver/webdriver/client.py:225: in release
[task 2018-08-22T19:11:22.098Z] 19:11:22     INFO -     return self.session.send_session_command("DELETE", "actions")
[task 2018-08-22T19:11:22.099Z] 19:11:22     INFO - tests/web-platform/tests/tools/webdriver/webdriver/client.py:509: in send_session_command
[task 2018-08-22T19:11:22.099Z] 19:11:22     INFO -     return self.send_command(method, url, body)
[task 2018-08-22T19:11:22.099Z] 19:11:22     INFO - _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
[task 2018-08-22T19:11:22.099Z] 19:11:22     INFO - 
[task 2018-08-22T19:11:22.100Z] 19:11:22     INFO - self = <Session daf811c0-4ce5-4268-90fb-49dd8a370906>, method = 'DELETE'
[task 2018-08-22T19:11:22.100Z] 19:11:22     INFO - url = 'session/d8b4817e-9b3a-47d8-b5d1-405929996441/actions', body = None
[task 2018-08-22T19:11:22.100Z] 19:11:22     INFO - 
[task 2018-08-22T19:11:22.100Z] 19:11:22     INFO -     def send_command(self, method, url, body=None):
[task 2018-08-22T19:11:22.101Z] 19:11:22     INFO -         """
[task 2018-08-22T19:11:22.101Z] 19:11:22     INFO -             Send a command to the remote end and validate its success.
[task 2018-08-22T19:11:22.102Z] 19:11:22     INFO -     
[task 2018-08-22T19:11:22.102Z] 19:11:22     INFO -             :param method: HTTP method to use in request.
[task 2018-08-22T19:11:22.102Z] 19:11:22     INFO -             :param uri: "Command part" of the HTTP request URL,
[task 2018-08-22T19:11:22.102Z] 19:11:22     INFO -                 e.g. `window/rect`.
[task 2018-08-22T19:11:22.103Z] 19:11:22     INFO -             :param body: Optional body of the HTTP request.
[task 2018-08-22T19:11:22.103Z] 19:11:22     INFO -     
[task 2018-08-22T19:11:22.103Z] 19:11:22     INFO -             :return: `None` if the HTTP response body was empty, otherwise
[task 2018-08-22T19:11:22.104Z] 19:11:22     INFO -                 the `value` field returned after parsing the response
[task 2018-08-22T19:11:22.104Z] 19:11:22     INFO -                 body as JSON.
[task 2018-08-22T19:11:22.104Z] 19:11:22     INFO -     
[task 2018-08-22T19:11:22.105Z] 19:11:22     INFO -             :raises error.WebDriverException: If the remote end returns
[task 2018-08-22T19:11:22.105Z] 19:11:22     INFO -                 an error.
[task 2018-08-22T19:11:22.106Z] 19:11:22     INFO -             :raises ValueError: If the response body does not contain a
[task 2018-08-22T19:11:22.106Z] 19:11:22     INFO -                 `value` key.
[task 2018-08-22T19:11:22.106Z] 19:11:22     INFO -             """
[task 2018-08-22T19:11:22.106Z] 19:11:22     INFO -         response = self.transport.send(
[task 2018-08-22T19:11:22.107Z] 19:11:22     INFO -             method, url, body,
[task 2018-08-22T19:11:22.107Z] 19:11:22     INFO -             encoder=protocol.Encoder, decoder=protocol.Decoder,
[task 2018-08-22T19:11:22.108Z] 19:11:22     INFO -             session=self)
[task 2018-08-22T19:11:22.108Z] 19:11:22     INFO -     
[task 2018-08-22T19:11:22.108Z] 19:11:22     INFO -         if response.status != 200:
[task 2018-08-22T19:11:22.109Z] 19:11:22     INFO -             err = error.from_response(response)
[task 2018-08-22T19:11:22.109Z] 19:11:22     INFO -     
[task 2018-08-22T19:11:22.109Z] 19:11:22     INFO -             if isinstance(err, error.InvalidSessionIdException):
[task 2018-08-22T19:11:22.110Z] 19:11:22     INFO -                 # The driver could have already been deleted the session.
[task 2018-08-22T19:11:22.110Z] 19:11:22     INFO -                 self.session_id = None
[task 2018-08-22T19:11:22.110Z] 19:11:22     INFO -     
[task 2018-08-22T19:11:22.110Z] 19:11:22     INFO - >           raise err
[task 2018-08-22T19:11:22.110Z] 19:11:22     INFO - E           UnknownErrorException: unknown error (500): Failed to decode response from marionette
[task 2018-08-22T19:11:22.112Z] 19:11:22     INFO - 
[task 2018-08-22T19:11:22.112Z] 19:11:22     INFO - body       = None
[task 2018-08-22T19:11:22.112Z] 19:11:22     INFO - err        = <UnknownErrorException http_status=500>
[task 2018-08-22T19:11:22.112Z] 19:11:22     INFO - method     = 'DELETE'
[task 2018-08-22T19:11:22.113Z] 19:11:22     INFO - response   = <Response status=500 error=<UnknownErrorException http_status=500>>
[task 2018-08-22T19:11:22.114Z] 19:11:22     INFO - self       = <Session daf811c0-4ce5-4268-90fb-49dd8a370906>
[task 2018-08-22T19:11:22.114Z] 19:11:22     INFO - url        = 'session/d8b4817e-9b3a-47d8-b5d1-405929996441/actions'
[task 2018-08-22T19:11:22.114Z] 19:11:22     INFO - 
[task 2018-08-22T19:11:22.114Z] 19:11:22     INFO - tests/web-platform/tests/tools/webdriver/webdriver/client.py:473: UnknownErrorException

Comment 1

[Henrik Skupin [:whimboo][⌚️UTC+2]]

Content process crash:

> [task 2018-08-22T19:11:16.092Z] 19:11:16     INFO - PID 1127 | 1534965076079	Marionette	DEBUG	[20] Frame script loaded
> [task 2018-08-22T19:11:16.092Z] 19:11:16     INFO - PID 1127 | 1534965076079	Marionette	DEBUG	[20] Frame script registered
> [task 2018-08-22T19:11:16.108Z] 19:11:16     INFO - PID 1127 | A content process crashed and MOZ_CRASHREPORTER_SHUTDOWN is set, shutting down

So most likely because of bug 1482029. But I'm not sure due to bug 1485259.

Comment 2

[Intermittent Failures Robot]

1 failures in 2568 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-central: 1

Platform breakdown:
* linux64-qr: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1485482&startday=2018-08-20&endday=2018-08-26&tree=all

Comment 3

[Intermittent Failures Robot]

2 failures in 2545 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:
* autoland: 2

Platform breakdown:
* linux32: 1
* linux64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1485482&startday=2018-08-27&endday=2018-09-02&tree=all

Comment 5

[BMO Automation]

Moving bug to Remote Protocol::Marionette component per bug 1815831.