Closed Bug 1396185 Opened 7 years ago Closed 6 years ago

Intermittent /webdriver/tests/navigation/get_title.py | get_title.py::test_title_after_modification - AssertionError: assert 'Initial' == 'updated'

Categories

(Remote Protocol :: Marionette, defect, P2)

Version 3
defect

Tracking

(firefox-esr60 fixed, firefox59 wontfix, firefox60 wontfix, firefox61 fixed)

RESOLVED FIXED
mozilla61
Tracking Status
firefox-esr60 --- fixed
firefox59 --- wontfix
firefox60 --- wontfix
firefox61 --- fixed

People

(Reporter: intermittent-bug-filer, Assigned: whimboo)

References

Details

(Keywords: intermittent-failure)

Attachments

(4 files)

[task 2017-09-01T22:58:30.133049Z] 22:58:30     INFO - TEST-UNEXPECTED-FAIL | /webdriver/tests/navigation/get_title.py | get_title.py::test_title_after_modification 
[task 2017-09-01T22:58:30.133102Z] 22:58:30     INFO - session = <webdriver.client.Session object at 0x7fb48cafff10>
[task 2017-09-01T22:58:30.133139Z] 22:58:30     INFO - 
[task 2017-09-01T22:58:30.133190Z] 22:58:30     INFO -     def test_title_after_modification(session):
[task 2017-09-01T22:58:30.133245Z] 22:58:30     INFO -         session.url = inline("<title>Initial</title><h2>Hello</h2>")
[task 2017-09-01T22:58:30.133847Z] 22:58:30     INFO -         session.execute_script("document.title = 'updated'")
[task 2017-09-01T22:58:30.133939Z] 22:58:30     INFO -     
[task 2017-09-01T22:58:30.133987Z] 22:58:30     INFO -         result = session.transport.send("GET",
[task 2017-09-01T22:58:30.134132Z] 22:58:30     INFO -                                         "session/%s/title" % session.session_id)
[task 2017-09-01T22:58:30.134172Z] 22:58:30     INFO -     
[task 2017-09-01T22:58:30.134348Z] 22:58:30     INFO - >       assert_success(result, read_global(session, "document.title"))
[task 2017-09-01T22:58:30.134391Z] 22:58:30     INFO - 
[task 2017-09-01T22:58:30.134465Z] 22:58:30     INFO - tests/web-platform/tests/webdriver/tests/navigation/get_title.py:248: 
[task 2017-09-01T22:58:30.134525Z] 22:58:30     INFO - _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
[task 2017-09-01T22:58:30.134559Z] 22:58:30     INFO - 
[task 2017-09-01T22:58:30.134616Z] 22:58:30     INFO - response = wdclient.Response(status=200, body={u'value': u'Initial'})
[task 2017-09-01T22:58:30.134657Z] 22:58:30     INFO - value = 'updated'
[task 2017-09-01T22:58:30.134698Z] 22:58:30     INFO - 
[task 2017-09-01T22:58:30.134749Z] 22:58:30     INFO -     def assert_success(response, value=None):
[task 2017-09-01T22:58:30.134804Z] 22:58:30     INFO -         """Verify that the provided wdclient.Response instance described a valid
[task 2017-09-01T22:58:30.134865Z] 22:58:30     INFO -         error response as defined by `dfn-send-an-error` and the provided error
[task 2017-09-01T22:58:30.135052Z] 22:58:30     INFO -         code.
[task 2017-09-01T22:58:30.135115Z] 22:58:30     INFO -     
[task 2017-09-01T22:58:30.135164Z] 22:58:30     INFO -         :param response: wdclient.Response instance.
[task 2017-09-01T22:58:30.135217Z] 22:58:30     INFO -         :param value: Expected value of the response body, if any.
[task 2017-09-01T22:58:30.135251Z] 22:58:30     INFO -     
[task 2017-09-01T22:58:30.135292Z] 22:58:30     INFO -         """
[task 2017-09-01T22:58:30.135336Z] 22:58:30     INFO -         assert response.status == 200
[task 2017-09-01T22:58:30.135385Z] 22:58:30     INFO -         if value is not None:
[task 2017-09-01T22:58:30.135472Z] 22:58:30     INFO - >           assert response.body["value"] == value
[task 2017-09-01T22:58:30.135644Z] 22:58:30     INFO - E           assert 'Initial' == 'updated'
[task 2017-09-01T22:58:30.135719Z] 22:58:30     INFO - E             - Initial
[task 2017-09-01T22:58:30.135762Z] 22:58:30     INFO - E             + updated
https://wiki.mozilla.org/Bugmasters#Intermittent_Test_Failure_Cleanup
Status: NEW → RESOLVED
Closed: 7 years ago
Resolution: --- → INCOMPLETE
Failure log: https://treeherder.mozilla.org/logviewer.html#?job_id=150453362&repo=mozilla-inbound&lineNumber=4862
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Maybe tests vary a bit. I have seen a failure like:

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

[task 2018-03-09T13:07:57.694Z] 13:07:57     INFO - STDOUT: response   = <Response status=500 error=<UnexpectedAlertOpenException http_status=500>>
[task 2018-03-09T13:07:57.694Z] 13:07:57     INFO - STDOUT: value      = 'WD doc title'
[task 2018-03-09T13:07:57.694Z] 13:07:57     INFO - STDOUT: tests/web-platform/tests/webdriver/tests/support/asserts.py
[task 2018-03-09T13:07:57.695Z] 13:07:57     INFO - STDOUT: :83: AssertionError

It means we see an unexpected dialog open, which should not be the case for this test.
Summary: Intermittent /webdriver/tests/navigation/get_title.py | get_title.py::test_title_after_modification → Intermittent /webdriver/tests/navigation/get_title.py | get_title.py::test_title_after_modification - AssertionError: assert 'Initial' == 'updated'
This test got partially disabled by the sync bug 1444558.

What I think is that we get a race when the title is set, and as such we should use `wait()` or maybe better a MutationObserver in the script call, which will only return when the title has been updated.
Most likely the problem here is the that we now retrieve the title via the parent process, and that a change in the content process hasn't been propagated yet. So a MutationObserver won't help, and we should indeed using a call to `wait()` here.
Assignee: nobody → hskupin
Status: REOPENED → ASSIGNED
Priority: P5 → P2
Comment on attachment 8971392 [details]
Bug 1396185 - [wdspec] Fix race condition in test_title_after_modification.

https://reviewboard.mozilla.org/r/240156/#review246046

::: testing/web-platform/tests/webdriver/tests/navigation/get_title.py:157
(Diff revision 1)
>      session.url = inline("<title>Initial</title><h2>Hello</h2>")
> -    session.execute_script("document.title = 'updated'")
> +    session.execute_script("document.title = 'Updated'")
>  
> -    result = get_title(session)
> -    assert_success(result, read_global(session, "document.title"))
> +    wait(session,
> +         lambda s: assert_success(get_title(s)) == read_global(session, "document.title"),
> +         "Document title doesn't match '{}'".format(read_global(session, "document.title")))

I'm not sure if this might only be a problem with Firefox and the way how we retrieve the title, but IMHO using `execute_script` is always a source of races.

The actual failure rate is kinda low, and I was not able to reproduce it at all for my test jobs.
Attachment #8971389 - Flags: review?(ato)
Attachment #8971390 - Flags: review?(ato)
Attachment #8971391 - Flags: review?(ato)
Attachment #8971392 - Flags: review?(ato)
Comment on attachment 8971389 [details]
Bug 1396185 - [wdspec] Remove unwanted docstring references to the spec.

https://reviewboard.mozilla.org/r/240150/#review246996
Attachment #8971389 - Flags: review?(ato) → review+
Comment on attachment 8971390 [details]
Bug 1396185 - [wdspec] Use shared get_title function for making HTTP requests.

https://reviewboard.mozilla.org/r/240152/#review247000

::: commit-message-115f4:1
(Diff revision 1)
> +Bug 1396185 - [wdspec] Get title tests have to use a shared custom get_title command.

It would be better with a normative commit message, such as “Use
shared get_title function for making HTTP requests” or something.
Attachment #8971390 - Flags: review?(ato) → review+
Comment on attachment 8971391 [details]
Bug 1396185 - [wdspec] Fix linter failures in get_title.py.

https://reviewboard.mozilla.org/r/240154/#review247002
Attachment #8971391 - Flags: review?(ato) → review+
Comment on attachment 8971392 [details]
Bug 1396185 - [wdspec] Fix race condition in test_title_after_modification.

https://reviewboard.mozilla.org/r/240156/#review246046

> I'm not sure if this might only be a problem with Firefox and the way how we retrieve the title, but IMHO using `execute_script` is always a source of races.
> 
> The actual failure rate is kinda low, and I was not able to reproduce it at all for my test jobs.

Yes, I subscribe to that theory.
Comment on attachment 8971392 [details]
Bug 1396185 - [wdspec] Fix race condition in test_title_after_modification.

https://reviewboard.mozilla.org/r/240156/#review247006
Attachment #8971392 - Flags: review?(ato) → review+
hg error in cmd: hg push -r tip ssh://hg.mozilla.org/integration/autoland: pushing to ssh://hg.mozilla.org/integration/autoland
remote: *** failed to import extension vcsreplicator from /var/hg/version-control-tools/pylib/vcsreplicator/vcsreplicator/hgext.py: [Errno 2] No such file or directory: '/var/hg/version-control-tools/pylib/vcsreplicator/vcsreplicator/../bootstrap.py'
searching for changes
remote: adding changesets
remote: adding manifests
remote: adding file changes
remote: added 4 changesets with 5 changes to 2 files
remote: transaction abort!
remote: rollback completed
remote: pretxnchangegroup.d_webidl hook is invalid: import of "mozhghooks.prevent_webidl_changes" failed
remote: (run with --traceback for stack trace)
abort: push failed on remote
hg error in cmd: hg push -r tip ssh://hg.mozilla.org/integration/autoland: pushing to ssh://hg.mozilla.org/integration/autoland
remote: *** failed to import extension vcsreplicator from /var/hg/version-control-tools/pylib/vcsreplicator/vcsreplicator/hgext.py: [Errno 2] No such file or directory: '/var/hg/version-control-tools/pylib/vcsreplicator/vcsreplicator/../bootstrap.py'
searching for changes
remote: adding changesets
remote: adding manifests
remote: adding file changes
remote: added 4 changesets with 5 changes to 2 files
remote: transaction abort!
remote: rollback completed
remote: pretxnchangegroup.d_webidl hook is invalid: import of "mozhghooks.prevent_webidl_changes" failed
remote: (run with --traceback for stack trace)
abort: push failed on remote
Pushed by hskupin@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/8d074598b6ca
[wdspec] Remove unwanted docstring references to the spec. r=ato
https://hg.mozilla.org/integration/autoland/rev/9c47feeac73f
[wdspec] Use shared get_title function for making HTTP requests. r=ato
https://hg.mozilla.org/integration/autoland/rev/7c1c51eea533
[wdspec] Fix linter failures in get_title.py. r=ato
https://hg.mozilla.org/integration/autoland/rev/dc74ac930ef1
[wdspec] Fix race condition in test_title_after_modification. r=ato
Created web-platform-tests PR https://github.com/w3c/web-platform-tests/pull/10824 for changes under testing/web-platform/tests
Upstream web-platform-tests status checks passed, PR will merge once commit reaches central.
It would be good to see this test-only patch uplifted to esr60.
Keywords: test-disabled
Whiteboard: [checkin-needed-esr60]
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.

Attachment

General

Created:
Updated:
Size: