Closed Bug 1429391 Opened 6 years ago Closed 6 years ago

Intermittent /webdriver/tests/get_current_url/get.py | test_get_current_url_after_modified_location - AssertionError: assert 'file:///' == 'about:blank#wd_test_modification'

Categories

(Remote Protocol :: Marionette, defect, P2)

Version 3
defect

Tracking

(firefox60 disabled, firefox61 disabled, firefox62 disabled)

RESOLVED FIXED
mozilla62
Tracking Status
firefox60 --- disabled
firefox61 --- disabled
firefox62 --- disabled

People

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

References

Details

(Keywords: intermittent-failure, Whiteboard: [stockwell disabled])

Attachments

(5 files, 1 obsolete file)

[task 2018-01-10T11:40:58.412Z] 11:40:58     INFO - session = <webdriver.client.Session object at 0x7fb987f980d0>
[task 2018-01-10T11:40:58.413Z] 11:40:58     INFO - 
[task 2018-01-10T11:40:58.414Z] 11:40:58     INFO -     def test_get_current_url_after_modified_location(session):
[task 2018-01-10T11:40:58.414Z] 11:40:58     INFO -         start = session.transport.send("GET", "session/%s/url" % session.session_id)
[task 2018-01-10T11:40:58.415Z] 11:40:58     INFO -         session.execute_script("window.location.href = 'about:blank#wd_test_modification'")
[task 2018-01-10T11:40:58.416Z] 11:40:58     INFO -         wait(session,
[task 2018-01-10T11:40:58.417Z] 11:40:58     INFO -              lambda s: s.transport.send("GET", "session/%s/url" % session.session_id) != start.body["value"],
[task 2018-01-10T11:40:58.417Z] 11:40:58     INFO -              "URL did not change")
[task 2018-01-10T11:40:58.418Z] 11:40:58     INFO -         result = session.transport.send("GET", "session/%s/url" % session.session_id)
[task 2018-01-10T11:40:58.418Z] 11:40:58     INFO -     
[task 2018-01-10T11:40:58.419Z] 11:40:58     INFO - >       assert_success(result, "about:blank#wd_test_modification")
[task 2018-01-10T11:40:58.420Z] 11:40:58     INFO - 
[task 2018-01-10T11:40:58.420Z] 11:40:58     INFO - result     = <Responsetatus=200 body={"value": "file:///"}>
[task 2018-01-10T11:40:58.421Z] 11:40:58     INFO - session    = <webdriver.client.Session object at 0x7fb987f980d0>
[task 2018-01-10T11:40:58.422Z] 11:40:58     INFO - start      = <Responsetatus=200 body={"value": "file:///"}>
[task 2018-01-10T11:40:58.422Z] 11:40:58     INFO - 
[task 2018-01-10T11:40:58.423Z] 11:40:58     INFO - tests/web-platform/tests/webdriver/tests/navigation/current_url.py:86: 
[task 2018-01-10T11:40:58.424Z] 11:40:58     INFO - _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
[task 2018-01-10T11:40:58.424Z] 11:40:58     INFO - 
[task 2018-01-10T11:40:58.425Z] 11:40:58     INFO - response = <Responsetatus=200 body={"value": "file:///"}>
[task 2018-01-10T11:40:58.425Z] 11:40:58     INFO - value = 'about:blank#wd_test_modification'
[task 2018-01-10T11:40:58.426Z] 11:40:58     INFO - 
[task 2018-01-10T11:40:58.426Z] 11:40:58     INFO -     def assert_success(response, value=None):
[task 2018-01-10T11:40:58.426Z] 11:40:58     INFO -         """
[task 2018-01-10T11:40:58.427Z] 11:40:58     INFO -         Verify that the provided webdriver.Response instance described
[task 2018-01-10T11:40:58.427Z] 11:40:58     INFO -         a valid error response as defined by `dfn-send-an-error` and
[task 2018-01-10T11:40:58.427Z] 11:40:58     INFO -         the provided error code.
[task 2018-01-10T11:40:58.428Z] 11:40:58     INFO -     
[task 2018-01-10T11:40:58.428Z] 11:40:58     INFO -         :param response: ``webdriver.Response`` instance.
[task 2018-01-10T11:40:58.428Z] 11:40:58     INFO -         :param value: Expected value of the response body, if any.
[task 2018-01-10T11:40:58.429Z] 11:40:58     INFO -         """
[task 2018-01-10T11:40:58.429Z] 11:40:58     INFO -         assert response.status == 200, str(response.error)
[task 2018-01-10T11:40:58.429Z] 11:40:58     INFO -     
[task 2018-01-10T11:40:58.430Z] 11:40:58     INFO -         if value is not None:
[task 2018-01-10T11:40:58.430Z] 11:40:58     INFO - >           assert response.body["value"] == value
[task 2018-01-10T11:40:58.430Z] 11:40:58     INFO - E           AssertionError
[task 2018-01-10T11:40:58.430Z] 11:40:58     INFO - 
[task 2018-01-10T11:40:58.431Z] 11:40:58     INFO - response   = <Responsetatus=200 body={"value": "file:///"}>
[task 2018-01-10T11:40:58.431Z] 11:40:58     INFO - value      = 'about:blank#wd_test_modification'
[task 2018-01-10T11:40:58.431Z] 11:40:58     INFO - 
[task 2018-01-10T11:40:58.432Z] 11:40:58     INFO - tests/web-platform/tests/webdriver/tests/support/asserts.py:86: AssertionError
[task 2018-01-10T11:40:58.432Z] 11:40:58     INFO - ..
We have 33 failures in the last 7 days.
They occur mostly on Linux (debug and opt) and the rest of them on Linux x64 (opt and debug) and linux64-ccov (opt).

Recent log: https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-central&job_id=157294056&lineNumber=9260

relavant part of it:
[task 2018-01-18T23:15:25.400Z] 23:15:25     INFO - TEST-PASS | /webdriver/tests/navigation/current_url.py | test_set_malformed_url 
9260
[task 2018-01-18T23:15:25.401Z] 23:15:25     INFO - TEST-UNEXPECTED-FAIL | /webdriver/tests/navigation/current_url.py | test_get_current_url_after_modified_location 
9261
[task 2018-01-18T23:15:25.401Z] 23:15:25     INFO - session = <webdriver.client.Session object at 0x7fb48e0f1650>
9262
[task 2018-01-18T23:15:25.402Z] 23:15:25     INFO - 
9263
[task 2018-01-18T23:15:25.402Z] 23:15:25     INFO -     def test_get_current_url_after_modified_location(session):
9264
[task 2018-01-18T23:15:25.402Z] 23:15:25     INFO -         start = session.transport.send("GET", "session/%s/url" % session.session_id)
9265
[task 2018-01-18T23:15:25.403Z] 23:15:25     INFO -         session.execute_script("window.location.href = 'about:blank#wd_test_modification'")
9266
[task 2018-01-18T23:15:25.403Z] 23:15:25     INFO -         wait(session,
9267
[task 2018-01-18T23:15:25.404Z] 23:15:25     INFO -              lambda s: s.transport.send("GET", "session/%s/url" % session.session_id) != start.body["value"],
9268
[task 2018-01-18T23:15:25.404Z] 23:15:25     INFO -              "URL did not change")
9269
[task 2018-01-18T23:15:25.404Z] 23:15:25     INFO -         result = session.transport.send("GET", "session/%s/url" % session.session_id)
:whimboo, can you please have a look at this?
Flags: needinfo?(hskupin)
Whiteboard: [stockwell needswork]
We have 33 failures in the last 7 days.
For the failure pattern see Comment 3
Recent failure log: https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-inbound&job_id=159378918&lineNumber=3685

:whimboo As you are the triage owner of this component, can you please take a look into this?
Since my fix for assert introspection on bug 1433390 has been landed we see better failure messages:

[task 2018-02-03T20:17:47.339Z] 20:17:47     INFO - >           assert response.body["value"] == value
[task 2018-02-03T20:17:47.339Z] 20:17:47     INFO - E           AssertionError: assert 'file:///' == 'about:blank#wd_test_modification'
[task 2018-02-03T20:17:47.339Z] 20:17:47     INFO - E             - file:///
[task 2018-02-03T20:17:47.339Z] 20:17:47     INFO - E             + about:blank#wd_test_modification
[

I really wonder why a second call to `getURL` right after the call to `wait` returns the original value.  

David, you landed an improvement for this test already on bug 1407383, but it doesn't seem to have helped. Could you have a look at this test failure again?
Depends on: 1407383
Flags: needinfo?(hskupin) → needinfo?(dburns)
There are 35 failures in the past 7 days.
Platforms:
- Linux/Linux x64 all debug
- linux64-ccov	opt
Recent log failure:
https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-central&job_id=162504639&lineNumber=9536

Relevant part of the log:
[task 2018-02-15T20:41:57.098Z] 20:41:57     INFO - TEST-PASS | /webdriver/tests/navigation/current_url.py | test_get_current_url_no_browsing_context 
[task 2018-02-15T20:41:57.098Z] 20:41:57     INFO - TEST-PASS | /webdriver/tests/navigation/current_url.py | test_get_current_url_alert_prompt 
[task 2018-02-15T20:41:57.098Z] 20:41:57     INFO - TEST-PASS | /webdriver/tests/navigation/current_url.py | test_get_current_url_matches_location 
[task 2018-02-15T20:41:57.099Z] 20:41:57     INFO - TEST-PASS | /webdriver/tests/navigation/current_url.py | test_get_current_url_payload 
[task 2018-02-15T20:41:57.099Z] 20:41:57     INFO - TEST-PASS | /webdriver/tests/navigation/current_url.py | test_get_current_url_special_pages 
[task 2018-02-15T20:41:57.100Z] 20:41:57     INFO - TEST-PASS | /webdriver/tests/navigation/current_url.py | test_get_current_url_file_protocol 
[task 2018-02-15T20:41:57.100Z] 20:41:57     INFO - TEST-PASS | /webdriver/tests/navigation/current_url.py | test_set_malformed_url 
[task 2018-02-15T20:41:57.100Z] 20:41:57     INFO - TEST-UNEXPECTED-FAIL | /webdriver/tests/navigation/current_url.py | test_get_current_url_after_modified_location 
[task 2018-02-15T20:41:57.101Z] 20:41:57     INFO - session = <webdriver.client.Session object at 0x7fb93fc85050>
[task 2018-02-15T20:41:57.101Z] 20:41:57     INFO - 
[task 2018-02-15T20:41:57.102Z] 20:41:57     INFO -     def test_get_current_url_after_modified_location(session):
[task 2018-02-15T20:41:57.102Z] 20:41:57     INFO -         start = session.transport.send("GET", "session/%s/url" % session.session_id)
[task 2018-02-15T20:41:57.102Z] 20:41:57     INFO -         session.execute_script("window.location.href = 'about:blank#wd_test_modification'")
[task 2018-02-15T20:41:57.103Z] 20:41:57     INFO -         wait(session,
[task 2018-02-15T20:41:57.103Z] 20:41:57     INFO -              lambda s: s.transport.send("GET", "session/%s/url" % session.session_id) != start.body["value"],
[task 2018-02-15T20:41:57.104Z] 20:41:57     INFO -              "URL did not change")
[task 2018-02-15T20:41:57.104Z] 20:41:57     INFO -         result = session.transport.send("GET", "session/%s/url" % session.session_id)
[task 2018-02-15T20:41:57.104Z] 20:41:57     INFO -     
[task 2018-02-15T20:41:57.104Z] 20:41:57     INFO - >       assert_success(result, "about:blank#wd_test_modification")
[task 2018-02-15T20:41:57.105Z] 20:41:57     INFO - 
[task 2018-02-15T20:41:57.105Z] 20:41:57     INFO - result     = <Responsetatus=200 body={"value": "file:///"}>
[task 2018-02-15T20:41:57.105Z] 20:41:57     INFO - session    = <webdriver.client.Session object at 0x7fb93fc85050>
[task 2018-02-15T20:41:57.106Z] 20:41:57     INFO - start      = <Responsetatus=200 body={"value": "file:///"}>
[task 2018-02-15T20:41:57.106Z] 20:41:57     INFO - 
[task 2018-02-15T20:41:57.106Z] 20:41:57     INFO - tests/web-platform/tests/webdriver/tests/navigation/current_url.py:86: 
[task 2018-02-15T20:41:57.106Z] 20:41:57     INFO - _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

:whimboo :dburns  Can you please take a look at this?
Flags: needinfo?(hskupin)
In the last 7 days there are 41 failures, since 18th February a decrease can be observed. 
For failure pattern, please see comment 10

Recent failure log: https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-inbound&job_id=164027723&lineNumber=3894

:whimboo, :dburns do you have any updates?
Attached patch Disable on Linux (obsolete) — Splinter Review
Joel, could you please review this patch? Thanks.
Attachment #8955757 - Flags: review?(jmaher)
Comment on attachment 8955757 [details] [diff] [review]
Disable on Linux

Review of attachment 8955757 [details] [diff] [review]:
-----------------------------------------------------------------

thanks!
Attachment #8955757 - Flags: review?(jmaher) → review+
Pushed by csabou@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/1a2aa9cd5120
Disable /webdriver/tests/navigation/current_url.py on Linux for frequent failures. r=jmaher
Keywords: checkin-needed
Backout by csabou@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/d50f11db7d64
Backed out changeset 1a2aa9cd5120 for permafailing at web-platform/runtests.py on a CLOSED TREE
Backed out because of these wpt failures: https://treeherder.mozilla.org/#/jobs?repo=mozilla-inbound&filter-resultStatus=testfailed&filter-resultStatus=busted&filter-resultStatus=exception&noautoclassify&fromchange=5bd73dd9739efc2521252dd613964c6dca8c7c7e&tochange=d50f11db7d6479c39125a4db75a8a31daeb8fba3&filter-searchStr=wpt8&selectedJob=165759692

Failure log: https://goo.gl/7qaSa9

Joel, could you please shed some light here since I don't know what exactly have I done wrong. Did I edited the wrong manifest?
Created this new file in testing/web-platform/meta/webdriver/tests/current_url.py.ini 
Should I have put the new ini file in testing/web-platform/meta/webdriver/tests/navigation/current_url.py.ini?
Flags: needinfo?(jmaher)
oh, that is a good point- sorry for missing that in review, it should be in testing/web-platform/meta/webdriver/tests/navigation/current_url.py.ini

you can just do:
hg mv testing/web-platform/meta/webdriver/tests/current_url.py.ini testing/web-platform/meta/webdriver/tests/navigation/current_url.py.ini
Flags: needinfo?(jmaher)
Attached patch Disable on LinuxSplinter Review
Done. The thing is that the other 2 patches have failed too (bug 1437081, bug 1398179). I'm looking now over them.
Attachment #8955757 - Attachment is obsolete: true
Attachment #8955777 - Flags: review?(jmaher)
Comment on attachment 8955777 [details] [diff] [review]
Disable on Linux

Review of attachment 8955777 [details] [diff] [review]:
-----------------------------------------------------------------

lets give this a try
Attachment #8955777 - Flags: review?(jmaher) → review+
Pushed by csabou@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/ce01463870bd
Disable /webdriver/tests/navigation/current_url.py on Linux for frequent failures. r=jmaher
Whiteboard: [stockwell disable-recommended] → [stockwell disabled]
Flags: needinfo?(hskupin)
Priority: P5 → P2
https://hg.mozilla.org/mozilla-central/rev/ce01463870bd
Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla60
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
Flags: needinfo?(dburns)
Summary: Intermittent /webdriver/tests/navigation/current_url.py | test_get_current_url_after_modified_location → Intermittent /webdriver/tests/navigation/current_url.py | test_get_current_url_after_modified_location - AssertionError: assert 'file:///' == 'about:blank#wd_test_modification'
David, you haven't updated the bug for a while. Should I take care of this disabled test?
Flags: needinfo?(dburns)
The problematic code is here:

https://dxr.mozilla.org/mozilla-central/rev/28db2c96ac695ce77c532901f5431a18a1d44374/testing/web-platform/tests/webdriver/tests/navigation/current_url.py#79-83

`start` is the result of `session.transport.send()`, and inside wait we compare a different result of such a call with `.body["value"]`. That means this is always False and as such we return immediately. In case it's too fast the next assertion will fail.

I will get this fixed as part of my patch on bug 1455568.
Assignee: nobody → hskupin
Status: REOPENED → ASSIGNED
Depends on: 1455568
No longer depends on: 1407383
Flags: needinfo?(dburns)
Bug 1455568 fixed it.
Status: ASSIGNED → RESOLVED
Closed: 6 years ago6 years ago
Resolution: --- → FIXED
Target Milestone: mozilla60 → mozilla62
Sorry, I actually missed to remove the manifest file. Patch upcoming.
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
Summary: Intermittent /webdriver/tests/navigation/current_url.py | test_get_current_url_after_modified_location - AssertionError: assert 'file:///' == 'about:blank#wd_test_modification' → Intermittent /webdriver/tests/get_current_url/get.py | test_get_current_url_after_modified_location - AssertionError: assert 'file:///' == 'about:blank#wd_test_modification'
Attachment #8974273 - Flags: review?(ato)
Comment on attachment 8974273 [details]
Bug 1429391 - [wdspec] Re-enable /webdriver/tests/get_current_url/get.py.

https://reviewboard.mozilla.org/r/242584/#review248520
Attachment #8974273 - Flags: review?(ato) → review+
Comment on attachment 8974273 [details]
Bug 1429391 - [wdspec] Re-enable /webdriver/tests/get_current_url/get.py.

https://reviewboard.mozilla.org/r/242584/#review248520

I noticed that the MANIFEST file contains more changes as wanted. I will update the patch so that only the necessary pieces are getting updated.
Pushed by hskupin@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/4614964298a8
[wdspec] Re-enable /webdriver/tests/get_current_url/get.py. r=ato
https://hg.mozilla.org/mozilla-central/rev/4614964298a8
Status: REOPENED → RESOLVED
Closed: 6 years ago6 years ago
Resolution: --- → FIXED
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: