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

RESOLVED FIXED in Firefox -esr60

Status

P2
normal
RESOLVED FIXED
a year ago
8 months ago

People

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

Tracking

({intermittent-failure})

Version 3
mozilla61
intermittent-failure
Points:
---
Bug Flags:
in-testsuite +

Firefox Tracking Flags

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

Details

Attachments

(4 attachments)

Comment hidden (Intermittent Failures Robot)
[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
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
https://wiki.mozilla.org/Bugmasters#Intermittent_Test_Failure_Cleanup
Status: NEW → RESOLVED
Last Resolved: a year ago
Resolution: --- → INCOMPLETE
Comment hidden (Intermittent Failures Robot)
Failure log: https://treeherder.mozilla.org/logviewer.html#?job_id=150453362&repo=mozilla-inbound&lineNumber=4862
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
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.
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
(Assignee)

Updated

10 months ago
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'
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
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.
status-firefox60: --- → unaffected
status-firefox61: --- → disabled
Depends on: 1444558
Keywords: test-disabled
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
status-firefox59: --- → wontfix
status-firefox60: unaffected → affected
Priority: P5 → P2
Comment hidden (mozreview-request)
Comment hidden (mozreview-request)
Comment hidden (mozreview-request)
Comment hidden (mozreview-request)
(Assignee)

Comment 31

9 months ago
mozreview-review
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 hidden (Intermittent Failures Robot)

Comment 33

9 months ago
mozreview-review
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 34

9 months ago
mozreview-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 35

9 months ago
mozreview-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 36

9 months ago
mozreview-review-reply
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 37

9 months ago
mozreview-review
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+
Comment hidden (mozreview-request)
Comment hidden (mozreview-request)
Comment hidden (mozreview-request)

Comment 41

9 months ago
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
Comment hidden (mozreview-request)
Comment hidden (mozreview-request)
Comment hidden (mozreview-request)
Comment hidden (mozreview-request)

Comment 46

9 months ago
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

Comment 47

9 months ago
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.
Upstream PR merged
Comment hidden (Intermittent Failures Robot)
It would be good to see this test-only patch uplifted to esr60.
status-firefox60: affected → wontfix
status-firefox61: disabled → fixed
status-firefox-esr60: --- → affected
Keywords: test-disabled
Whiteboard: [checkin-needed-esr60]
Comment hidden (Intermittent Failures Robot)
You need to log in before you can comment on or make changes to this bug.