1459549 - Intermittent TEST-UNEXPECTED-OK | /webdriver/tests/sessions/new_session/create_firstMatch.py | expected TIMEOUT

Status: RESOLVED FIXED

(Remote Protocol :: Marionette, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: archaeopteryx [at] coole-files.de

https://treeherder.mozilla.org/logviewer.html#?job_id=177157361&repo=autoland

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

[task 2018-05-06T10:06:58.949Z] 10:06:58     INFO - PID 4523 | nsStringStats
[task 2018-05-06T10:06:58.949Z] 10:06:58     INFO - PID 4523 |  => mAllocCount:          66165
[task 2018-05-06T10:06:58.951Z] 10:06:58     INFO - PID 4523 |  => mReallocCount:         5447
[task 2018-05-06T10:06:58.952Z] 10:06:58     INFO - PID 4523 |  => mFreeCount:           66164  --  LEAKED 1 !!!
[task 2018-05-06T10:06:58.952Z] 10:06:58     INFO - PID 4523 |  => mShareCount:          60457
[task 2018-05-06T10:06:58.953Z] 10:06:58     INFO - PID 4523 |  => mAdoptCount:           2785
[task 2018-05-06T10:06:58.954Z] 10:06:58     INFO - PID 4523 |  => mAdoptFreeCount:       2829
[task 2018-05-06T10:06:58.955Z] 10:06:58     INFO - PID 4523 |  => Process ID: 7789, Thread ID: 139980220323648
[task 2018-05-06T10:06:58.971Z] 10:06:58     INFO - PID 4523 | 1525601218965	geckodriver::marionette	DEBUG	Browser process stopped: exit code: 0
[task 2018-05-06T10:06:58.980Z] 10:06:58     INFO - STDOUT: =================================== FAILURES ===================================
[task 2018-05-06T10:06:58.980Z] 10:06:58     INFO - STDOUT: _________________________ test_valid[timeouts-value10] _________________________
[task 2018-05-06T10:06:58.980Z] 10:06:58     INFO - PID 4523 | 1525601218970	webdriver::server	DEBUG	<- 200 OK {"value": {}}
[task 2018-05-06T10:06:58.981Z] 10:06:58     INFO - STDOUT: new_session = <function create_session at 0x7f8516799050>
[task 2018-05-06T10:06:58.981Z] 10:06:58     INFO - STDOUT: add_browser_capabilites = <function update_capabilities at 0x7f8516799140>
[task 2018-05-06T10:06:58.982Z] 10:06:58     INFO - STDOUT: key = 'timeouts'
[task 2018-05-06T10:06:58.983Z] 10:06:58     INFO - STDOUT: value = {'implicit': 9007199254740991, 'pageLoad': 2.0, 'script': 0}
[task 2018-05-06T10:06:58.983Z] 10:06:58     INFO - STDOUT:     @pytest.mark.parametrize("key,value", flatten(product(*item) for item in valid_data))
[task 2018-05-06T10:06:58.984Z] 10:06:58     INFO - STDOUT:     def test_valid(new_session, add_browser_capabilites, key, value):
[task 2018-05-06T10:06:58.984Z] 10:06:58     INFO - STDOUT: >       resp = new_session({"capabilities": {"alwaysMatch": add_browser_capabilites({key: value})}})
[task 2018-05-06T10:06:58.984Z] 10:06:58     INFO - STDOUT: add_browser_capabilites = <function update_capabilities at 0x7f8516799140>
[task 2018-05-06T10:06:58.985Z] 10:06:58     INFO - STDOUT: key        = 'timeouts'
[task 2018-05-06T10:06:58.986Z] 10:06:58     INFO - STDOUT: new_session = <function create_session at 0x7f8516799050>
[task 2018-05-06T10:06:58.986Z] 10:06:58     INFO - STDOUT: value      = {'implicit': 9007199254740991, 'pageLoad': 2.0, 'script': 0}
[task 2018-05-06T10:06:58.987Z] 10:06:58     INFO - STDOUT: tests/web-platform/tests/webdriver/tests/sessions/new_session/create_alwaysMatch.py
[task 2018-05-06T10:06:58.987Z] 10:06:58     INFO - STDOUT: :12: 
[task 2018-05-06T10:06:58.987Z] 10:06:58     INFO - STDOUT: _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
[task 2018-05-06T10:06:58.988Z] 10:06:58     INFO - STDOUT: tests/web-platform/tests/webdriver/tests/support/fixtures.py
[task 2018-05-06T10:06:58.988Z] 10:06:58     INFO - STDOUT: :192: in create_session
[task 2018-05-06T10:06:58.988Z] 10:06:58     INFO - STDOUT:     value = _session.send_command("POST", "session", body=body)
[task 2018-05-06T10:06:58.989Z] 10:06:58     INFO - STDOUT: _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
[task 2018-05-06T10:06:58.990Z] 10:06:58     INFO - STDOUT: self = <Session (disconnected)>, method = 'POST', url = 'session'
[task 2018-05-06T10:06:58.991Z] 10:06:58     INFO - STDOUT: body = {'capabilities': {'alwaysMatch': {'moz:firefoxOptions': {'binary': '/builds/worker/workspace/build/application/firefox...eb-platform.test,www1.web-platform.test'}}, 'timeouts': {'implicit': 9007199254740991, 'pageLoad': 2.0, 'script': 0}}}}
[task 2018-05-06T10:06:58.991Z] 10:06:58     INFO - STDOUT:     def send_command(self, method, url, body=None):
[task 2018-05-06T10:06:58.991Z] 10:06:58     INFO - STDOUT:         """
[task 2018-05-06T10:06:58.992Z] 10:06:58     INFO - STDOUT:             Send a command to the remote end and validate its success.
[task 2018-05-06T10:06:58.992Z] 10:06:58     INFO - STDOUT:     
[task 2018-05-06T10:06:58.993Z] 10:06:58     INFO - STDOUT:             :param method: HTTP method to use in request.
[task 2018-05-06T10:06:58.993Z] 10:06:58     INFO - STDOUT:             :param uri: "Command part" of the HTTP request URL,
[task 2018-05-06T10:06:58.993Z] 10:06:58     INFO - STDOUT:                 e.g. `window/rect`.
[task 2018-05-06T10:06:58.994Z] 10:06:58     INFO - STDOUT:             :param body: Optional body of the HTTP request.
[task 2018-05-06T10:06:58.994Z] 10:06:58     INFO - STDOUT:     
[task 2018-05-06T10:06:58.995Z] 10:06:58     INFO - STDOUT:             :return: `None` if the HTTP response body was empty, otherwise
[task 2018-05-06T10:06:58.996Z] 10:06:58     INFO - STDOUT:                 the `value` field returned after parsing the response
[task 2018-05-06T10:06:58.996Z] 10:06:58     INFO - STDOUT:                 body as JSON.
[task 2018-05-06T10:06:58.997Z] 10:06:58     INFO - STDOUT:     
[task 2018-05-06T10:06:58.997Z] 10:06:58     INFO - STDOUT:             :raises ValueError: If the response body does not contain a
[task 2018-05-06T10:06:58.997Z] 10:06:58     INFO - STDOUT:                 `value` key.
[task 2018-05-06T10:06:58.998Z] 10:06:58     INFO - STDOUT:             :raises error.WebDriverException: If the remote end returns
[task 2018-05-06T10:06:58.998Z] 10:06:58     INFO - STDOUT:                 an error.
[task 2018-05-06T10:06:58.999Z] 10:06:58     INFO - STDOUT:             """
[task 2018-05-06T10:06:58.999Z] 10:06:58     INFO - STDOUT:         response = self.transport.send(
[task 2018-05-06T10:06:58.999Z] 10:06:58     INFO - STDOUT:             method, url, body,
[task 2018-05-06T10:06:59.000Z] 10:06:59     INFO - STDOUT:             encoder=protocol.Encoder, decoder=protocol.Decoder,
[task 2018-05-06T10:06:59.000Z] 10:06:59     INFO - STDOUT:             session=self)
[task 2018-05-06T10:06:59.000Z] 10:06:59     INFO - STDOUT:     
[task 2018-05-06T10:06:59.001Z] 10:06:59     INFO - STDOUT:         if response.status != 200:
[task 2018-05-06T10:06:59.002Z] 10:06:59     INFO - STDOUT: >           raise error.from_response(response)
[task 2018-05-06T10:06:59.002Z] 10:06:59     INFO - STDOUT: E           InvalidArgumentException: invalid argument (400): pageLoad timeouts value is not an integer: 2.0
[task 2018-05-06T10:06:59.003Z] 10:06:59     INFO - STDOUT: body       = {'capabilities': {'alwaysMatch': {'moz:firefoxOptions': {'binary': '/builds/worker/workspace/build/application/firefox...eb-platform.test,www1.web-platform.test'}}, 'timeouts': {'implicit': 9007199254740991, 'pageLoad': 2.0, 'script': 0}}}}
[task 2018-05-06T10:06:59.004Z] 10:06:59     INFO - STDOUT: method     = 'POST'
[task 2018-05-06T10:06:59.004Z] 10:06:59     INFO - STDOUT: response   = <Response status=400 error=<InvalidArgumentException http_status=400>>
[task 2018-05-06T10:06:59.004Z] 10:06:59     INFO - STDOUT: self       = <Session (disconnected)>
[task 2018-05-06T10:06:59.005Z] 10:06:59     INFO - STDOUT: url        = 'session'
[task 2018-05-06T10:06:59.005Z] 10:06:59     INFO - STDOUT: tests/web-platform/tests/tools/webdriver/webdriver/client.py
[task 2018-05-06T10:06:59.006Z] 10:06:59     INFO - STDOUT: :438: InvalidArgumentException
[task 2018-05-06T10:06:59.006Z] 10:06:59     INFO - STDOUT: =============================== warnings summary ===============================
[task 2018-05-06T10:06:59.006Z] 10:06:59     INFO - STDOUT: None
[task 2018-05-06T10:06:59.006Z] 10:06:59     INFO - STDOUT:   Module already imported so cannot be rewritten: mozlog
[task 2018-05-06T10:06:59.006Z] 10:06:59     INFO - STDOUT: -- Docs: http://doc.pytest.org/en/latest/warnings.html
[task 2018-05-06T10:06:59.006Z] 10:06:59     INFO - STDOUT: ============== 1 failed, 22 passed, 1 warnings in 362.84 seconds ===============
[task 2018-05-06T10:06:59.028Z] 10:06:59     INFO - TEST-UNEXPECTED-OK | /webdriver/tests/sessions/new_session/create_alwaysMatch.py | expected TIMEOUT

Comment 1

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

Similar to bug 1459548 for `create_alwaysMatch.py`. As it looks like we expect a timeout (bug 1419176) even with have a longer timeout requested, but due to the fix on bug 1411908 we might not see the timeout anymore.

The only solution I could see here would be to split-up the tests in different modules.

Comment 2

[Intermittent Failures Robot]

3 failures in 660 pushes (0.005 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* mozilla-inbound: 2
* try: 1

Platform breakdown:
* linux64-qr: 3

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1459549&startday=2018-05-07&endday=2018-05-13&tree=trunk

Comment 3

[Intermittent Failures Robot]

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

Repository breakdown:
* mozilla-inbound: 1

Platform breakdown:
* linux64-qr: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1459549&startday=2018-05-14&endday=2018-05-20&tree=trunk

Comment 4

[Intermittent Failures Robot]

10 failures in 632 pushes (0.016 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* mozilla-inbound: 5
* autoland: 4
* try: 1

Platform breakdown:
* linux64-qr: 10

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1459549&startday=2018-05-21&endday=2018-05-27&tree=trunk

Comment 5

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

This is blocked on bug 1464756.

Comment 6

[Kartikaya Gupta (email:[e-mail])]

See https://bugzilla.mozilla.org/show_bug.cgi?id=1459548#c9, same thing applies here.

Comment 7

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

The test is not disabled on beta, so it's a wontfix.

Comment 8

[Intermittent Failures Robot]

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

Repository breakdown:
* try: 1
* mozilla-central: 1

Platform breakdown:
* linux64-qr: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1459549&startday=2018-05-28&endday=2018-06-03&tree=trunk

Comment 9

[BMO Automation]

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